Libera-Chat / sable

GNU Affero General Public License v3.0
84 stars 8 forks source link

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

Closed progval closed 5 months ago

progval commented 1 year ago

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.

progval commented 5 months ago

Seems to be resolved