libera-chat / sable Goto Github PK

View Code? Open in Web Editor NEW

78.0 78.0 8.0 1.42 MB

License: GNU Affero General Public License v3.0

Rust 100.00%

sable's People

Contributors

Stargazers

Watchers

Forkers

thedaemoness aoeixsz4 raitobezarius mquin progval 0xmatt1

sable's Issues

Check that forward DNS matches reverse

Empty trailing parameter

Currently, Sable treats empty trailing parameters as if the trailing was absent:

https://github.com/Libera-Chat/sable/blob/5be1f25bd1e89bcb2f8f5de39ce96b6d0e0487cd/sable_ircd/src/client_message.rs#L81-84

This means that, like irc2, PRIVMSG #chan : returns ERR_NEEDMOREPARAMS, as opposed to Charybdis/Hybrid/Plexus4/Solanum, Ergo, InspIRCd, ircu2/Nefarious/(probably snircd too), and UnrealIRCd, which use ERR_NOTEXTTOSEND instead. (while ngIRCd prefers to silently drop the message).

It also means that, like ircu2/Nefarious/snircd MODE #chan +k : returns ERR_NEEDMOREPARAMS, as opposed to Charybdis/Hybrid/Plexus4/Solanum, Ergo, InspIRCd, irc2, and UnrealIRCd which return either ERR_INVALIDMODEPARAM or ERR_INVALIDKEY. (while ngIRCd allows the key change).

Is this intended behavior? I assume so given that it makes command handlers easier to write (in particular, no need for special handling in KICK/PART/QUIT where the lack of trailing is equivalent to an empty trailing); I'd just like to check.

Echoing state changes

There are a couple of IRC features that require servers to keep track of which connection caused a particular state change:

PRIVMSG should be sent to other connections within the same session, even if they don't have echo-message. Otherwise if a client shares a session with other clients and sends a message, other clients won't see the message at all
If echo-message and labeled-response are enabled, PRIVMSG echoes must have the label sent by the client. This is required by clients that implement local echos in order to deduplicate
it would be nice if JOIN/PART/MODE/... echoes could have the label provided by the client

Joining two channels at once sometimes does not use a labeled-response batch

Client's logs:

1695066315.429 1 -> S: @label=label1 JOIN #valid,inv@lid
1695066315.529 1 -> S: PING synchronize256.066149989
1695066316.034 S -> 1: :foo!username@localhost JOIN #valid
1695066316.034 S -> 1: :foo!username@localhost MODE #valid +o foo
1695066316.034 S -> 1: :My.Little.Server 353 foo = #valid :@foo 
1695066316.034 S -> 1: :My.Little.Server 366 foo #valid :End of names list
1695066316.034 S -> 1: @label=label1 :My.Little.Server 479 foo inv@lid :Illegal channel name
1695066317.040 S -> 1: :My.Little.Server PONG My.Little.Server :synchronize256.066149989

Server's logs:

2023-09-18T19:45:15.429227Z TRACE do_run: sable_ircd::server: ...from connection_events
2023-09-18T19:45:15.429307Z TRACE do_run:process_connection_event{source=ConnectionId(ListenerId(0), 2)}: sable_ircd::server: Got message msg="@label=label1 JOIN #valid,inv@lid"
2023-09-18T19:45:15.529543Z TRACE do_run: sable_ircd::server: ...from connection_events
2023-09-18T19:45:15.529621Z TRACE do_run:process_connection_event{source=ConnectionId(ListenerId(0), 2)}: sable_ircd::server: Got message msg="PING synchronize256.066149989"
2023-09-18T19:45:16.032219Z  INFO sync_task: sable_network::sync::network: No peers available to propagate message
2023-09-18T19:45:16.032612Z TRACE do_run: sable_ircd::server: ...from history_receiver res=Some(NewEntry(5))
2023-09-18T19:45:16.032647Z TRACE do_run: sable_ircd::server::update_handler: Got history update update=NewEntry(5)
2023-09-18T19:45:16.032753Z  INFO sync_task: sable_network::sync::network: No peers available to propagate message
2023-09-18T19:45:16.032989Z TRACE do_run: sable_ircd::server: ...from history_receiver res=Some(NewEntry(6))
2023-09-18T19:45:16.033015Z TRACE do_run: sable_ircd::server::update_handler: Got history update update=NewEntry(6)
2023-09-18T19:45:16.033047Z TRACE do_run: sable_ircd::server: ...from history_receiver res=Some(NotifyUsers([UserId(ServerId(1), EpochId(1695066311), 1)], 6))
2023-09-18T19:45:16.033065Z TRACE do_run: sable_ircd::server::update_handler: Got history update update=NotifyUsers([UserId(ServerId(1), EpochId(1695066311), 1)], 6)
2023-09-18T19:45:16.033121Z TRACE do_run: sable_ircd::client: Sending to ConnectionId(ListenerId(0), 2): :foo!username@localhost JOIN #valid
2023-09-18T19:45:16.033156Z TRACE do_run: sable_ircd::client: Sending to ConnectionId(ListenerId(0), 2): :foo!username@localhost MODE #valid +o foo
2023-09-18T19:45:16.033209Z TRACE do_run: sable_ircd::client: Sending to ConnectionId(ListenerId(0), 2): :My.Little.Server 353 foo = #valid :@foo 
2023-09-18T19:45:16.033229Z TRACE do_run: sable_ircd::client: Sending to ConnectionId(ListenerId(0), 2): :My.Little.Server 366 foo #valid :End of names list
2023-09-18T19:45:16.033317Z TRACE do_run: sable_ircd::server: ...from async_handlers
2023-09-18T19:45:16.033356Z TRACE do_run: sable_ircd::server: ...from history_receiver res=Some(NewEntry(7))
2023-09-18T19:45:16.033378Z TRACE do_run: sable_ircd::server::update_handler: Got history update update=NewEntry(7)
2023-09-18T19:45:16.033402Z TRACE do_run: sable_ircd::client: Sending to ConnectionId(ListenerId(0), 2): @label=label1 :My.Little.Server 479 foo inv@lid :Illegal channel name

This seems to be a pretty rare bug, irctest ran this test a dozen times on Github alone, and it's the first time it shows up.

Logging/auditing needs to be better

Files, not stdout
Files split by category
Context reporting for async events
Error events being reported to opers on IRC

The tracing crate (https://docs.rs/tracing/latest/tracing/) and its associated subscribers seems to handle the first three; a custom subscriber should be able to do the last one.

Move client connections into their own process

PART fails to notify the last user who leaves a channel

If the last user leaves, then the channel gets removed before the handler gets triggered to notify, and so looking up the channel to get the name fails.

NetworkTaskState should check peer address before accepting TLS handshake

It's cheaper to reject spammy connection based on just the IP address instead of accepting the TLS handshake and rejecting. Additionally, it lowers the risk of vulnerabilities in rustls being exploited.

<spb> val: the NetworkTaskState could build a big list of authorised IP addresses and have handle_connection test against that
[...]
<spb> i'm not sure it's a massive priority right now, but might be nice to improve
<spb> though i think if i were doing that, i'd be inclined to rework that a bit more
<val> it's a little annoying because I first need to check in handle_connection() that it's in the allowlist, but read_and_handle_message still needs to check it's the right address for that particular peer
<val> so yeah it needs more rearchitecturing
<spb> that's what i meant by reworking more
<spb> read_and_handle_message isn't really the right place for that because it's also called to handle responses after we send an outbound message
<spb> so it ends up doing all the peer authentication on a connection that we opened ourselves, after we sent network events to it

WHOIS on a nonexistent user does not send RPL_ENDOFWHOIS

I didn't reproduce this manually, but progval/irctest#258 should be a repro case against Sable commit dcf8b53

Cargo Build on new project install fails to compile

Description
I tried to install this project in a new install using rustc 1.72.0-nightly. Instead of cargo compiling, there were several errors during build.

Details of Error

warning: unused import: `FromRawFd`
  --> sable_server/src/run.rs:10:24
   |
10 |         io::{IntoRawFd,FromRawFd},
   |                        ^^^^^^^^^
   |
   = note: `#[warn(unused_imports)]` on by default

warning: unused import: `memfd::*`
  --> sable_server/src/run.rs:19:5
   |
19 | use memfd::*;
   |     ^^^^^^^^

error[E0433]: failed to resolve: use of undeclared type `Memfd`
  --> sable_server/src/run.rs:25:26
   |
25 |     let memfd = unsafe { Memfd::from_raw_fd(fd) };
   |                          ^^^^^ use of undeclared type `Memfd`

error[E0433]: failed to resolve: use of undeclared type `MemfdOptions`
  --> sable_server/src/run.rs:33:17
   |
33 |     let memfd = MemfdOptions::default().close_on_exec(false).create("upgrade_state").expect("Failed to create upgrade memfd");
   |                 ^^^^^^^^^^^^ use of undeclared type `MemfdOptions`

warning: unused import: `io::Seek`
  --> sable_server/src/run.rs:14:5
   |
14 |     io::Seek,
   |     ^^^^^^^^

warning: unused import: `IntoRawFd`
  --> sable_server/src/run.rs:10:14
   |
10 |         io::{IntoRawFd,FromRawFd},
   |              ^^^^^^^^^

For more information about this error, try `rustc --explain E0433`.
warning: `sable_server` (lib) generated 4 warnings
error: could not compile `sable_server` (lib) due to 2 previous errors; 4 warnings emitted
warning: build failed, waiting for other jobs to finish...

Hostnames all have a trailing .

Sometimes it crashes with a Full error when submitting new events

It looks like the replicated log task stops reading the new events channel. Why?

Support in-place upgrades

Sort out what to do with channel renames in chathistory

Currently renames are never sent as part of history.

Currently also history messages are looked up by string target, so messages before (or after, depending) a rename won't be found.

Both parts should probably be fixed as part of the same operation. There's an open question over which channel name to send when replaying history around a rename (see ircv3/ircv3-specifications#532).

Extra NICK command gets sent out before 001

<< CAP LS
<< NICK aaron
<< USER aaron aaron circle.secret-net.work :Aaron Jones
>> :temple.secret-net.work NOTICE * :*** Looking up your hostname
>> :temple.secret-net.work 421 * CAP :Unknown command
>> :temple.secret-net.work NOTICE * :*** Found your hostname: cpc77355-stav19-2-0-cust7.17-3.cable.virginm.net.
>> :[email protected]. NICK aaron
>> :temple.secret-net.work 001 aaron :Welcome to the test Internet Relay Chat network, aaron
<< MODE aaron +i
>> :temple.secret-net.work 005 aaron  EXCEPTS INVEX FNC CASEMAPPING=ascii CHANMODES=bqeI,k,,ntsi PREFIX=(ov)@+ :are supported by this server
>> :[email protected]. MODE aaron +
>> :[email protected]. MODE aaron +i
<< PING temple.secret-net.work
>> :temple.secret-net.work PONG temple.secret-net.work :temple.secret-net.work

uid=1001
2023-10-03T17:58:50.587719Z  INFO sync_task: sable_network::sync::network: No peers available to propagate message
2023-10-03T17:58:50.588581Z DEBUG run:apply_event{event=Event { id: EventId(ServerId(1), EpochId(1696355929), 0), timestamp: 1696355930, clock: EventClock({}), target: Server(ServerId(1)), details: NewServer(NewServer { epoch: EpochId(1696355929), name: ServerName("My.Little.Server"), ts: 1696355930, flags: (empty), version: "sable-0.1.0-dcf8b53cac54f460b86861908d36d67969cf1eb2" }) }}:handle_new_server{entry=HistoryLogEntry { id: 0, timestamp: 1696355930, source_event: EventId(ServerId(1), EpochId(1696355929), 0), details: NewServer(NewServer { server: Server { id: ServerId(1), epoch: EpochId(1696355929), name: ServerName("My.Little.Server"), last_ping: 1696355930, flags: (empty), version: "sable-0.1.0-dcf8b53cac54f460b86861908d36d67969cf1eb2" } }) } detail=NewServer { server: Server { id: ServerId(1), epoch: EpochId(1696355929), name: ServerName("My.Little.Server"), last_ping: 1696355930, flags: (empty), version: "sable-0.1.0-dcf8b53cac54f460b86861908d36d67969cf1eb2" } }}: sable_network::sync::network: enabling peer My.Little.Server
2023-10-03T17:58:50.588804Z  INFO sync_task: sable_network::sync::network: No peers available to propagate message
2023-10-03T17:58:50.588865Z TRACE do_run: sable_ircd::server: ...from history_receiver res=Some(NewEntry(0))
2023-10-03T17:58:50.588957Z TRACE do_run: sable_ircd::server::update_handler: Got history update update=NewEntry(0)
2023-10-03T17:58:50.589007Z TRACE do_run: sable_ircd::server: ...from history_receiver res=Some(NewEntry(1))
2023-10-03T17:58:50.589032Z TRACE do_run: sable_ircd::server::update_handler: Got history update update=NewEntry(1)
2023-10-03T17:58:50.589096Z TRACE do_run: sable_ircd::server: ...from history_receiver res=Some(NewEntry(2))
2023-10-03T17:58:50.589124Z TRACE do_run: sable_ircd::server::update_handler: Got history update update=NewEntry(2)
2023-10-03T17:58:50.593977Z TRACE do_run: sable_ircd::server: ...from reap_preclients_timer
2023-10-03T17:58:51.535965Z DEBUG run_communication_task: client_listener::listener_collection: got new connection data=ConnectionData { id: ConnectionId(ListenerId(0), 1), remote_addr: 127.0.0.1, tls_info: None }
2023-10-03T17:58:51.536125Z TRACE do_run: sable_ircd::server: ...from connection_events
2023-10-03T17:58:51.536282Z TRACE do_run:process_connection_event{source=ConnectionId(ListenerId(0), 1)}: sable_ircd::server: Got new connection
2023-10-03T17:58:51.536358Z TRACE do_run:process_connection_event{source=ConnectionId(ListenerId(0), 1)}: sable_ircd::client: Sending to ConnectionId(ListenerId(0), 1): :My.Little.Server NOTICE * :*** Looking up your hostname
2023-10-03T17:58:51.536686Z TRACE do_run: sable_ircd::server: ...from connection_events
2023-10-03T17:58:51.536761Z TRACE do_run:process_connection_event{source=ConnectionId(ListenerId(0), 1)}: sable_ircd::server: Got message msg="QUIT :chkport"
2023-10-03T17:58:51.536920Z TRACE do_run: sable_ircd::client: Sending to ConnectionId(ListenerId(0), 1): ERROR :Client quit
2023-10-03T17:58:51.537034Z TRACE do_run: sable_ircd::server: Got pending CommandAction act=CloseConnection(ConnectionId(ListenerId(0), 1))
2023-10-03T17:58:51.537073Z TRACE do_run: sable_ircd::connection_collection: Removing connection ConnectionId(ListenerId(0), 1)
2023-10-03T17:58:51.537796Z TRACE do_run: sable_ircd::server: ...from auth_events
2023-10-03T17:58:51.538007Z DEBUG run_communication_task: client_listener::listener_collection: Connection error connection=ConnectionId(ListenerId(0), 1) error=Closed
2023-10-03T17:58:51.538089Z TRACE do_run: sable_ircd::server: ...from connection_events
1696355931.548 1: connects to server.
1696355931.548 2: connects to server.
1696355931.548 2 -> S: NICK sender
1696355931.548 2 -> S: USER username * * :Realname
2023-10-03T17:58:51.548713Z DEBUG run_communication_task: client_listener::listener_collection: got new connection data=ConnectionData { id: ConnectionId(ListenerId(0), 3), remote_addr: 127.0.0.1, tls_info: None }
2023-10-03T17:58:51.548780Z DEBUG run_communication_task: client_listener::listener_collection: got new connection data=ConnectionData { id: ConnectionId(ListenerId(0), 2), remote_addr: 127.0.0.1, tls_info: None }
2023-10-03T17:58:51.548890Z TRACE do_run: sable_ircd::server: ...from connection_events
2023-10-03T17:58:51.548958Z TRACE do_run:process_connection_event{source=ConnectionId(ListenerId(0), 3)}: sable_ircd::server: Got new connection
2023-10-03T17:58:51.548997Z TRACE do_run:process_connection_event{source=ConnectionId(ListenerId(0), 3)}: sable_ircd::client: Sending to ConnectionId(ListenerId(0), 3): :My.Little.Server NOTICE * :*** Looking up your hostname
2023-10-03T17:58:51.549127Z TRACE do_run: sable_ircd::server: ...from connection_events
2023-10-03T17:58:51.549178Z TRACE do_run:process_connection_event{source=ConnectionId(ListenerId(0), 2)}: sable_ircd::server: Got new connection
2023-10-03T17:58:51.549220Z TRACE do_run:process_connection_event{source=ConnectionId(ListenerId(0), 2)}: sable_ircd::client: Sending to ConnectionId(ListenerId(0), 2): :My.Little.Server NOTICE * :*** Looking up your hostname
2023-10-03T17:58:51.549322Z TRACE do_run: sable_ircd::server: ...from connection_events
2023-10-03T17:58:51.549387Z TRACE do_run:process_connection_event{source=ConnectionId(ListenerId(0), 3)}: sable_ircd::server: Got message msg="NICK sender"
2023-10-03T17:58:51.549526Z TRACE do_run: sable_ircd::client: PreClient::can_register self=PreClient { connected_at: Instant { tv_sec: 313, tv_nsec: 820830686 }, user: OnceLock(<uninit>), nick: OnceLock(Nickname("sender")), realname: OnceLock(<uninit>), hostname: OnceLock(<uninit>), sasl_session: OnceLock(<uninit>), sasl_account: OnceLock(<uninit>), progress_flags: 0 } result=false
2023-10-03T17:58:51.549594Z TRACE do_run: sable_ircd::server: ...from async_handlers
2023-10-03T17:58:51.549646Z TRACE do_run: sable_ircd::server: ...from connection_events
2023-10-03T17:58:51.549691Z TRACE do_run:process_connection_event{source=ConnectionId(ListenerId(0), 3)}: sable_ircd::server: Got message msg="USER username * * :Realname"
2023-10-03T17:58:51.549778Z TRACE do_run: sable_ircd::client: PreClient::can_register self=PreClient { connected_at: Instant { tv_sec: 313, tv_nsec: 820830686 }, user: OnceLock(Username("username")), nick: OnceLock(Nickname("sender")), realname: OnceLock(Realname("Realname")), hostname: OnceLock(<uninit>), sasl_session: OnceLock(<uninit>), sasl_account: OnceLock(<uninit>), progress_flags: 0 } result=false
2023-10-03T17:58:51.550542Z TRACE do_run: sable_ircd::server: ...from auth_events
2023-10-03T17:58:51.550587Z TRACE do_run: sable_ircd::server: DNS lookup finished for ConnectionId(ListenerId(0), 3): 127.0.0.1/Some(Hostname("localhost"))
2023-10-03T17:58:51.550626Z TRACE do_run: sable_ircd::client: Sending to ConnectionId(ListenerId(0), 3): :My.Little.Server NOTICE * :*** Found your hostname: localhost
2023-10-03T17:58:51.550674Z TRACE do_run: sable_ircd::client: PreClient::can_register self=PreClient { connected_at: Instant { tv_sec: 313, tv_nsec: 820830686 }, user: OnceLock(Username("username")), nick: OnceLock(Nickname("sender")), realname: OnceLock(Realname("Realname")), hostname: OnceLock(Hostname("localhost")), sasl_session: OnceLock(<uninit>), sasl_account: OnceLock(<uninit>), progress_flags: 0 } result=true
2023-10-03T17:58:51.550724Z TRACE do_run: sable_ircd::server: Got pending CommandAction act=RegisterClient(ConnectionId(ListenerId(0), 3))
2023-10-03T17:58:51.550911Z  INFO sync_task: sable_network::sync::network: No peers available to propagate message
2023-10-03T17:58:51.551310Z TRACE do_run: sable_ircd::server: ...from history_receiver res=Some(NewEntry(3))
2023-10-03T17:58:51.551346Z TRACE do_run: sable_ircd::server::update_handler: Got history update update=NewEntry(3)
2023-10-03T17:58:51.551421Z TRACE do_run: sable_ircd::client: Sending to ConnectionId(ListenerId(0), 3): :My.Little.Server 001 sender :Welcome to the test Internet Relay Chat network, sender
2023-10-03T17:58:51.551479Z TRACE do_run: sable_ircd::client: Sending to ConnectionId(ListenerId(0), 3): :My.Little.Server 002 sender :Your host is My.Little.Server, running version sable-0.1.0-dcf8b53cac54f460b86861908d36d67969cf1eb2
2023-10-03T17:58:51.551556Z TRACE do_run: sable_ircd::client: Sending to ConnectionId(ListenerId(0), 3): :My.Little.Server 003 sender :This server was created 2023-10-03 17:58:51.551503601 UTC
2023-10-03T17:58:51.551589Z TRACE do_run: sable_ircd::client: Sending to ConnectionId(ListenerId(0), 3): :My.Little.Server 004 sender My.Little.Server sable-0.1.0-dcf8b53cac54f460b86861908d36d67969cf1eb2 ioZ ntsim bqeIkov
2023-10-03T17:58:51.551638Z TRACE do_run: sable_ircd::client: Sending to ConnectionId(ListenerId(0), 3): :My.Little.Server 005 sender EXCEPTS INVEX FNC CASEMAPPING=ascii HOSTLEN=64 NICKLEN=15 USERLEN=10 CHANMODES=bqeI,k,,ntsim PREFIX=(ov)@+ :are supported by this server
2023-10-03T17:58:51.551681Z TRACE do_run: sable_ircd::client: Sending to ConnectionId(ListenerId(0), 3): :My.Little.Server 422 sender :MOTD File is missing
2023-10-03T17:58:51.551714Z TRACE do_run: sable_ircd::client: Sending to ConnectionId(ListenerId(0), 3): :sender!username@localhost MODE sender +
2023-10-03T17:58:51.551740Z TRACE do_run: sable_ircd::client: Sending to ConnectionId(ListenerId(0), 3): :My.Little.Server NOTICE sender :The network is currently running in debug mode. Do not send any sensitive information such as passwords.
2023-10-03T17:58:51.551785Z TRACE do_run: sable_ircd::server: ...from history_receiver res=Some(NewEntry(4))
2023-10-03T17:58:51.551809Z TRACE do_run: sable_ircd::server::update_handler: Got history update update=NewEntry(4)
1696355931.552 S -> 2: :My.Little.Server NOTICE * :*** Looking up your hostname
1696355931.553 S -> 2: :My.Little.Server NOTICE * :*** Found your hostname: localhost
1696355931.553 S -> 2: :My.Little.Server 001 sender :Welcome to the test Internet Relay Chat network, sender
1696355931.553 S -> 2: :My.Little.Server 002 sender :Your host is My.Little.Server, running version sable-0.1.0-dcf8b53cac54f460b86861908d36d67969cf1eb2
1696355931.553 S -> 2: :My.Little.Server 003 sender :This server was created 2023-10-03 17:58:51.551503601 UTC
1696355931.553 S -> 2: :My.Little.Server 004 sender My.Little.Server sable-0.1.0-dcf8b53cac54f460b86861908d36d67969cf1eb2 ioZ ntsim bqeIkov
1696355931.553 S -> 2: :My.Little.Server 005 sender EXCEPTS INVEX FNC CASEMAPPING=ascii HOSTLEN=64 NICKLEN=15 USERLEN=10 CHANMODES=bqeI,k,,ntsim PREFIX=(ov)@+ :are supported by this server
1696355931.553 S -> 2: :My.Little.Server 422 sender :MOTD File is missing
1696355931.553 S -> 2: :sender!username@localhost MODE sender +
1696355931.553 S -> 2: :My.Little.Server NOTICE sender :The network is currently running in debug mode. Do not send any sensitive information such as passwords.
1696355931.553 2 -> S: PING foo
2023-10-03T17:58:51.553070Z TRACE do_run: sable_ircd::server: ...from connection_events
2023-10-03T17:58:51.553130Z TRACE do_run:process_connection_event{source=ConnectionId(ListenerId(0), 3)}: sable_ircd::server: Got message msg="PING foo"
2023-10-03T17:58:51.553229Z TRACE do_run: sable_ircd::client: Sending to ConnectionId(ListenerId(0), 3): :My.Little.Server PONG My.Little.Server :foo
1696355932.357 2 -> S: PING synchronize314.628550171
1696355932.357 S -> 2: :My.Little.Server PONG My.Little.Server :foo
2023-10-03T17:58:52.359207Z TRACE do_run: sable_ircd::server: ...from connection_events
2023-10-03T17:58:52.359295Z TRACE do_run:process_connection_event{source=ConnectionId(ListenerId(0), 3)}: sable_ircd::server: Got message msg="PING synchronize314.628550171"
2023-10-03T17:58:52.359443Z TRACE do_run: sable_ircd::client: Sending to ConnectionId(ListenerId(0), 3): :My.Little.Server PONG My.Little.Server :synchronize314.628550171
1696355932.362 S -> 2: :My.Little.Server PONG My.Little.Server :synchronize314.628550171
1696355932.362 1 -> S: CAP LS 302
1696355932.362 S -> 1: :My.Little.Server NOTICE * :*** Looking up your hostname
2023-10-03T17:58:52.362407Z TRACE do_run: sable_ircd::server: ...from connection_events
2023-10-03T17:58:52.362508Z TRACE do_run:process_connection_event{source=ConnectionId(ListenerId(0), 2)}: sable_ircd::server: Got message msg="CAP LS 302"
2023-10-03T17:58:52.362664Z TRACE do_run: sable_ircd::client: Sending to ConnectionId(ListenerId(0), 2): :My.Little.Server CAP * LS :server-time echo-message batch labeled-response userhost-in-names away-notify account-tag draft/chathistory sable.libera.chat/persistent-session draft/account-registration draft/channel-rename
1696355932.363 S -> 1: :My.Little.Server CAP * LS :server-time echo-message batch labeled-response userhost-in-names away-notify account-tag draft/chathistory sable.libera.chat/persistent-session draft/account-registration draft/channel-rename
1696355932.363 1 -> S: CAP REQ :echo-message server-time
1696355932.363 1 -> S: nick bar
1696355932.363 1 -> S: user user 0 * realname
1696355932.363 1 -> S: CAP END
2023-10-03T17:58:52.363581Z TRACE do_run: sable_ircd::server: ...from connection_events
2023-10-03T17:58:52.363638Z TRACE do_run:process_connection_event{source=ConnectionId(ListenerId(0), 2)}: sable_ircd::server: Got message msg="CAP REQ :echo-message server-time"
2023-10-03T17:58:52.363808Z TRACE do_run: sable_ircd::client: Sending to ConnectionId(ListenerId(0), 2): :My.Little.Server CAP * ACK :echo-message server-time
2023-10-03T17:58:52.363856Z TRACE do_run: sable_ircd::server: Got pending CommandAction act=UpdateConnectionCaps(ConnectionId(ListenerId(0), 2), ClientCapabilitySet(6))
2023-10-03T17:58:52.363907Z TRACE do_run: sable_ircd::server: ...from connection_events
2023-10-03T17:58:52.363960Z TRACE do_run:process_connection_event{source=ConnectionId(ListenerId(0), 2)}: sable_ircd::server: Got message msg="nick bar"
2023-10-03T17:58:52.364277Z TRACE do_run: sable_ircd::client: PreClient::can_register self=PreClient { connected_at: Instant { tv_sec: 313, tv_nsec: 821049387 }, user: OnceLock(<uninit>), nick: OnceLock(Nickname("bar")), realname: OnceLock(<uninit>), hostname: OnceLock(<uninit>), sasl_session: OnceLock(<uninit>), sasl_account: OnceLock(<uninit>), progress_flags: 1 } result=false
2023-10-03T17:58:52.364342Z TRACE do_run: sable_ircd::server: ...from async_handlers
2023-10-03T17:58:52.364391Z TRACE do_run: sable_ircd::server: ...from connection_events
2023-10-03T17:58:52.364439Z TRACE do_run:process_connection_event{source=ConnectionId(ListenerId(0), 2)}: sable_ircd::server: Got message msg="user user 0 * realname"
2023-10-03T17:58:52.364820Z TRACE do_run: sable_ircd::client: PreClient::can_register self=PreClient { connected_at: Instant { tv_sec: 313, tv_nsec: 821049387 }, user: OnceLock(Username("user")), nick: OnceLock(Nickname("bar")), realname: OnceLock(Realname("realname")), hostname: OnceLock(<uninit>), sasl_session: OnceLock(<uninit>), sasl_account: OnceLock(<uninit>), progress_flags: 1 } result=false
2023-10-03T17:58:52.364906Z TRACE do_run: sable_ircd::server: ...from connection_events
2023-10-03T17:58:52.364957Z TRACE do_run:process_connection_event{source=ConnectionId(ListenerId(0), 2)}: sable_ircd::server: Got message msg="CAP END"
1696355932.368 S -> 1: :My.Little.Server CAP * ACK :echo-message server-time
2023-10-03T17:58:53.118337Z TRACE do_run: sable_ircd::client: PreClient::complete_progress self=PreClient { connected_at: Instant { tv_sec: 313, tv_nsec: 821049387 }, user: OnceLock(Username("user")), nick: OnceLock(Nickname("bar")), realname: OnceLock(Realname("realname")), hostname: OnceLock(<uninit>), sasl_session: OnceLock(<uninit>), sasl_account: OnceLock(<uninit>), progress_flags: 0 } flag=CapNegotiation result=false
1696355933.368 1: waiting…
1696355934.369 1: waiting…
1696355935.370 1: waiting…
1696355936.371 1: waiting…
1696355937.372 1: waiting…
1696355938.373 1: waiting…
1696355939.374 1: waiting…
1696355940.375 1: waiting…
1696355941.377 1: waiting…
1696355942.378 1: waiting…
1696355943.379 1: waiting…
1696355944.381 1: waiting…
1696355945.382 1: waiting…
1696355946.384 1: waiting…
1696355947.384 1: waiting…
1696355948.385 1: waiting…
1696355949.386 1: waiting…
1696355950.388 1: waiting…
1696355951.388 1: waiting…
1696355952.389 1: waiting…
1696355953.390 1: waiting…
1696355954.391 1: waiting…
1696355955.393 1: waiting…
1696355956.394 1: waiting…
1696355957.397 1: waiting…
1696355958.398 1: waiting…
1696355959.399 1: waiting…
1696355960.400 1: waiting…
1696355961.402 1: waiting…
1696355962.403 1: waiting…
1696355963.404 1: waiting…
1696355964.406 1: waiting…
1696355965.407 1: waiting…
1696355966.408 1: waiting…
1696355967.409 1: waiting…
1696355968.410 1: waiting…
1696355969.412 1: waiting…
1696355970.412 1: waiting…
1696355971.413 1: waiting…
1696355972.414 1: waiting…
1696355973.415 1: waiting…
1696355974.416 1: waiting…
1696355975.416 1: waiting…
1696355976.417 1: waiting…
1696355977.418 1: waiting…
1696355978.420 1: waiting…
1696355979.421 1: waiting…
1696355980.422 1: waiting…
1696355981.423 1: waiting…
1696355982.424 1: waiting…
1696355983.424 1: waiting…
1696355984.425 1: waiting…
1696355985.426 1: waiting…
1696355986.428 1: waiting…
1696355987.428 1: waiting…
1696355988.429 1: waiting…
1696355989.431 1: waiting…
1696355990.432 1: waiting…
2023-10-03T17:59:50.588555Z  INFO sync_task: sable_network::sync::network: No peers available to propagate message
2023-10-03T17:59:50.589050Z TRACE do_run: sable_ircd::server: ...from history_receiver res=Some(NewEntry(5))
2023-10-03T17:59:50.589086Z TRACE do_run: sable_ircd::server::update_handler: Got history update update=NewEntry(5)
2023-10-03T17:59:50.590089Z TRACE do_run: sable_ircd::server: ...from reap_preclients_timer
1696355991.432 1: waiting…
1696355992.433 1: waiting…
1696355993.435 1: waiting…
1696355994.436 1: waiting…
1696355995.437 1: waiting…
1696355996.438 1: waiting…
1696355997.439 1: waiting…
1696355998.440 1: waiting…
1696355999.442 1: waiting…
1696356000.443 1: waiting…
1696356001.444 1: waiting…
1696356002.445 1: waiting…
1696356003.447 1: waiting…
1696356004.448 1: waiting…
1696356005.448 1: waiting…
1696356006.450 1: waiting…
1696356007.451 1: waiting…
1696356008.451 1: waiting…
1696356009.453 1: waiting…
1696356010.454 1: waiting…
1696356011.455 1: waiting…
1696356012.456 1: waiting…
1696356013.457 1: waiting…
1696356014.459 1: waiting…
1696356015.460 1: waiting…
1696356016.461 1: waiting…
1696356017.462 1: waiting…
1696356018.463 1: waiting…
1696356019.465 1: waiting…
1696356020.465 1: waiting…
1696356021.466 1: waiting…
1696356022.467 1: waiting…
1696356023.469 1: waiting…
1696356024.470 1: waiting…
1696356025.471 1: waiting…
1696356026.472 1: waiting…
1696356027.473 1: waiting…
1696356028.475 1: waiting…
1696356029.476 1: waiting…
1696356030.477 1: waiting…
1696356031.478 1: waiting…
1696356032.479 1: waiting…
1696356033.481 1: waiting…
1696356034.482 1: waiting…
1696356035.483 1: waiting…
1696356036.484 1: waiting…
1696356037.486 1: waiting…
1696356038.487 1: waiting…
1696356039.488 1: waiting…
1696356040.489 1: waiting…
1696356041.490 1: waiting…
1696356042.491 1: waiting…
1696356043.493 1: waiting…
1696356044.494 1: waiting…
1696356045.495 1: waiting…
1696356046.496 1: waiting…
1696356047.497 1: waiting…
1696356048.498 1: waiting…
1696356049.500 1: waiting…
1696356050.501 1: waiting…
2023-10-03T18:00:50.588767Z  INFO sync_task: sable_network::sync::network: No peers available to propagate message
2023-10-03T18:00:50.589271Z TRACE do_run: sable_ircd::server: ...from history_receiver res=Some(NewEntry(6))
2023-10-03T18:00:50.589311Z TRACE do_run: sable_ircd::server::update_handler: Got history update update=NewEntry(6)
2023-10-03T18:00:50.590290Z TRACE do_run: sable_ircd::server: ...from reap_preclients_timer
1696356051.502 1: waiting…
1696356052.503 1: waiting…
1696356053.504 1: waiting…
1696356054.505 1: waiting…
1696356055.506 1: waiting…
1696356056.507 1: waiting…
1696356057.508 1: waiting…
1696356058.510 1: waiting…
1696356059.511 1: waiting…
1696356060.512 1: waiting…
1696356061.513 1: waiting…
1696356062.514 1: waiting…
1696356063.516 1: waiting…
1696356064.517 1: waiting…
1696356065.518 1: waiting…
1696356066.519 1: waiting…
1696356067.520 1: waiting…
1696356068.522 1: waiting…
1696356069.523 1: waiting…
1696356070.524 1: waiting…
1696356071.525 1: waiting…
1696356072.526 1: waiting…
1696356073.528 1: waiting…
1696356074.529 1: waiting…
1696356075.530 1: waiting…
1696356076.531 1: waiting…
1696356077.533 1: waiting…
1696356078.534 1: waiting…
1696356079.535 1: waiting…
1696356080.536 1: waiting…
1696356081.537 1: waiting…
1696356082.539 1: waiting…
1696356083.540 1: waiting…
1696356084.541 1: waiting…
1696356085.542 1: waiting…
1696356086.543 1: waiting…
1696356087.545 1: waiting…
1696356088.546 1: waiting…
1696356089.547 1: waiting…
1696356090.548 1: waiting…
1696356091.549 1: waiting…
1696356092.551 1: waiting…
1696356093.552 1: waiting…
1696356094.553 1: waiting…
1696356095.554 1: waiting…
1696356096.555 1: waiting…
1696356097.557 1: waiting…
1696356098.558 1: waiting…
1696356099.559 1: waiting…
1696356100.560 1: waiting…
1696356101.562 1: waiting…
1696356102.563 1: waiting…
1696356103.564 1: waiting…
1696356104.565 1: waiting…
1696356105.567 1: waiting…
1696356106.568 1: waiting…
1696356107.568 1: waiting…
1696356108.570 1: waiting…
1696356109.571 1: waiting…
1696356110.572 1: waiting…
2023-10-03T18:01:50.589090Z  INFO sync_task: sable_network::sync::network: No peers available to propagate message
2023-10-03T18:01:50.589600Z TRACE do_run: sable_ircd::server: ...from history_receiver res=Some(NewEntry(7))
2023-10-03T18:01:50.589656Z TRACE do_run: sable_ircd::server::update_handler: Got history update update=NewEntry(7)
2023-10-03T18:01:50.590553Z TRACE do_run: sable_ircd::server: ...from reap_preclients_timer
2023-10-03T18:01:50.590712Z DEBUG reap_preclients: sable_ircd::server: ConnectionId(ListenerId(0), 2) registration timed out
2023-10-03T18:01:50.590757Z TRACE reap_preclients: sable_ircd::client: Sending to ConnectionId(ListenerId(0), 2): ERROR :Registration timed out
1696356110.591 S -> 1: ERROR :Registration timed out
2023-10-03T18:01:50.841824Z TRACE do_run: sable_ircd::server: Got pending CommandAction act=CloseConnection(ConnectionId(ListenerId(0), 2))
2023-10-03T18:01:50.841917Z TRACE do_run: sable_ircd::connection_collection: Removing connection ConnectionId(ListenerId(0), 2)
2023-10-03T18:01:50.842769Z DEBUG run_communication_task: client_listener::listener_collection: Connection error connection=ConnectionId(ListenerId(0), 2) error=Closed
2023-10-03T18:01:50.842891Z TRACE do_run: sable_ircd::server: ...from connection_events

Given that the last line before hanging is:

2023-10-03T17:58:53.118337Z TRACE do_run: sable_ircd::client: PreClient::complete_progress self=PreClient { connected_at: Instant { tv_sec: 313, tv_nsec: 821049387 }, user: OnceLock(Username("user")), nick: OnceLock(Nickname("bar")), realname: OnceLock(Realname("realname")), hostname: OnceLock(), sasl_session: OnceLock(), sasl_account: OnceLock(), progress_flags: 0 } flag=CapNegotiation result=false

it looks like Sable never manages to resolve the hostname or abort the resolution

There's currently no way to close (e.g. timeout) unregistered connections

Management interface

An out-of-band interface (i.e. not IRC) for server management operations:

Metric collection
Rehash/restart/shutdown commands
Maybe listener control?
etc.

Open question is what form this should take - HTTP-style, IPC channel exchanging serde objects with dedicated command line utilities, ...?

Recommend Projects

React

A declarative, efficient, and flexible JavaScript library for building user interfaces.
Vue.js

🖖 Vue.js is a progressive, incrementally-adoptable JavaScript framework for building UI on the web.
Typescript

TypeScript is a superset of JavaScript that compiles to clean JavaScript output.
TensorFlow

An Open Source Machine Learning Framework for Everyone
Django

The Web framework for perfectionists with deadlines.
Laravel

A PHP framework for web artisans
D3

Bring data to life with SVG, Canvas and HTML. 📊📈🎉

Recommend Topics

javascript

JavaScript (JS) is a lightweight interpreted programming language with first-class functions.
web

Some thing interesting about web. New door for the world.
server

A server is a program made to process requests and deliver data to clients.
Machine learning

Machine learning is a way of modeling and interpreting data that allows a piece of software to respond intelligently.
Visualization

Some thing interesting about visualization, use data art
Game

Some thing interesting about game, make everyone happy.

Recommend Org

Facebook

We are working to build community through open source technology. NB: members must have two-factor auth.
Microsoft

Open source projects and samples from Microsoft.
Google

Google ❤️ Open Source for everyone.
Alibaba

Alibaba Open Source for everyone
D3

Data-Driven Documents codes.
Tencent

China tencent open source team.