Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Unable to join existing chatrooms #21

Open
jgknight opened this issue May 17, 2024 · 1 comment
Open

Unable to join existing chatrooms #21

jgknight opened this issue May 17, 2024 · 1 comment
Labels
bug Something isn't working

Comments

@jgknight
Copy link
Contributor

Subject of the issue

When trying to join an existing chatroom by name, a new chatroom is created instead of joining the existing one.

Deployment environment

  • version: retro_aim_server.0.4.0.linux.arm64

  • Install method: pre-built

  • Clients used: AIM 5.1.3036 on MacOS/wine

  • Other relevant details: Using two MacOS/wine clients, each in their own VM. VMs are NAT'd behind my laptop, so both show up as the same IP in the server logs but with separate tcp sessions.

Steps to reproduce

  1. Trace logging enabled on retro_aim_server, running the binary directly on a rpi, with auth disabled
  2. Login to AIM client A as Alice
  3. Login to AIM client B as Bob
  4. From Alice to Bob, send an instant message with a hyperlink aim:gochat?roomname=testroom&exchange=4
  5. As Alice, click on the link
  6. As Bob, click on the link
  7. Observe that Alice and Bob are each in separate chatrooms but both are named testroom. Neither client show up in the 'Person Here' window for each other, and messages sent in the chat are not delivered to each other

Expected behaviour

Users joining the same chatroom with the same name and exchange should be entered into the same chatroom instance. This is how AIM behaved back in the day. The name of the chatroom was what kept a room secret or private, hence why the client generates such a long random chatroom name when creating one from the Chat button in the client.

Actual behaviour

Each user ends up in a separate chatroom.

Troubleshooting data

The client behavior is different when accepting a chatroom invite, which does work correctly, from when a new room is created or the gochat link is clicked.

In the problem case, each client clicking the gochat link ends up sending a ChatNavCreateRoom message to the server. Some speculation on my part, but it seems that the server is treating these as new separate rooms, instead of tying the rooms together by name/exchange/instance, so the list of sessions for each room remain separate.

Essentially, I think the server behavior for ChatNavCreateRoom should be looking up whether the chatroom already exists, and then treating the second client as if it has accepted an invite to the existing room.

I notice that the chatrooms work fine if Alice invites Bob to the chatroom. In this working case, Bob's client does not send a ChatNavCreateRoom message, but a series of different msgs that include OService, ChatRoomInfoUpdate, and a ChatUsersJoined for each client.

Logs, working case with invite + accept + message sent

Alice invites Bob to testroom, Bob accepts. Alice sends a message 'AAAAAAthisisatestAAAAAA'

time=2024-05-17T21:58:49.736Z level=INFO msg="user started a chat room" svc=BOS roomName=testroom screenName=Alice ip=192.168.144.208:48927
time=2024-05-17T21:58:49.736Z level=TRACE msg="client request -> server response" svc=BOS request.food_group=ChatNav request.sub_group=ChatNavCreateRoom request.snac_frame="{FoodGroup:13 SubGroup:8 Flags:0 RequestID:655368}" request.snac_payload="{Exchange:4 Cookie:create InstanceNumber:65535 DetailLevel:1 TLVBlock:{TLVList:[{Tag:215 Value:[101 110]} {Tag:214 Value:[117 115 45 97 115 99 105 105]} {Tag:211 Value:[116 101 115 116 114 111 111 109]}]}}" response.food_group=ChatNav response.sub_group=ChatNavNavInfo response.snac_frame="{FoodGroup:13 SubGroup:9 Flags:0 RequestID:655368}" response.snac_payload="{TLVRestBlock:{TLVList:[{Tag:4 Value:[0 4 36 101 100 53 57 102 55 48 100 45 57 51 98 100 45 52 53 50 102 45 56 102 51 51 45 49 97 50 99 48 98 48 98 49 102 48 102 255 255 1 0 7 0 201 0 2 0 15 0 202 0 4 102 71 211 25 0 209 0 2 4 0 0 210 0 2 0 100 0 213 0 1 2 0 106 0 8 116 101 115 116 114 111 111 109 0 211 0 8 116 101 115 116 114 111 111 109]}]}}" screenName=Alice ip=192.168.144.208:48927
time=2024-05-17T21:58:49.769Z level=TRACE msg="client request -> server response" svc=BOS request.food_group=OService request.sub_group=OServiceServiceRequest request.snac_frame="{FoodGroup:1 SubGroup:4 Flags:0 RequestID:524292}" request.snac_payload="{FoodGroup:14 TLVRestBlock:{TLVList:[{Tag:1 Value:[0 4 36 101 100 53 57 102 55 48 100 45 57 51 98 100 45 52 53 50 102 45 56 102 51 51 45 49 97 50 99 48 98 48 98 49 102 48 102 255 255]}]}}" response.food_group=OService response.sub_group=OServiceServiceResponse response.snac_frame="{FoodGroup:1 SubGroup:5 Flags:0 RequestID:524292}" response.snac_payload="{TLVRestBlock:{TLVList:[{Tag:5 Value:[49 57 50 46 49 54 56 46 49 52 52 46 49 49 51 58 53 49 57 50]} {Tag:6 Value:[36 101 100 53 57 102 55 48 100 45 57 51 98 100 45 52 53 50 102 45 56 102 51 51 45 49 97 50 99 48 98 48 98 49 102 48 102 0 36 52 100 55 98 52 55 98 53 45 101 53 54 51 45 52 101 53 101 45 56 49 51 100 45 52 102 55 51 52 49 55 55 102 55 53 97]} {Tag:13 Value:[0 14]} {Tag:141 Value:[]} {Tag:142 Value:[0]}]}}" screenName=Alice ip=192.168.144.208:48927
time=2024-05-17T21:58:49.799Z level=DEBUG msg="accepted connection" svc=CHAT ip=192.168.144.208:38975
time=2024-05-17T21:58:49.900Z level=TRACE msg="client request -> server response" svc=CHAT request.food_group=OService request.sub_group=ClientVersions request.snac_frame="{FoodGroup:1 SubGroup:23 Flags:0 RequestID:23}" request.snac_payload="{Versions:[1 3 14 1]}" response.food_group=OService response.sub_group=OServiceHostVersions response.snac_frame="{FoodGroup:1 SubGroup:24 Flags:0 RequestID:23}" response.snac_payload="{Versions:[1 3 14 1]}" screenName=Alice ip=192.168.144.208:38975
time=2024-05-17T21:58:49.917Z level=TRACE msg="client request -> server response" svc=CHAT request.food_group=OService request.sub_group=OServiceRateParamsQuery request.snac_frame="{FoodGroup:1 SubGroup:6 Flags:0 RequestID:6}" request.snac_payload=<nil> response.food_group=OService response.sub_group=OServiceRateParamsReply response.snac_frame="{FoodGroup:1 SubGroup:7 Flags:0 RequestID:6}" response.snac_payload="{RateClasses:[{ID:1 WindowSize:80 ClearLevel:2500 AlertLevel:2000 LimitLevel:1500 DisconnectLevel:800 CurrentLevel:3433 MaxLevel:6000 LastTime:0 CurrentState:0}] RateGroups:[{ID:1 Pairs:[{FoodGroup:3 SubGroup:2} {FoodGroup:14 SubGroup:5} {FoodGroup:13 SubGroup:2} {FoodGroup:13 SubGroup:4} {FoodGroup:13 SubGroup:8} {FoodGroup:19 SubGroup:2} {FoodGroup:19 SubGroup:4} {FoodGroup:19 SubGroup:5} {FoodGroup:19 SubGroup:7} {FoodGroup:19 SubGroup:8} {FoodGroup:19 SubGroup:9} {FoodGroup:19 SubGroup:10} {FoodGroup:19 SubGroup:17} {FoodGroup:19 SubGroup:18} {FoodGroup:4 SubGroup:2} {FoodGroup:4 SubGroup:4} {FoodGroup:4 SubGroup:6} {FoodGroup:4 SubGroup:8} {FoodGroup:4 SubGroup:11} {FoodGroup:4 SubGroup:20} {FoodGroup:2 SubGroup:2} {FoodGroup:2 SubGroup:4} {FoodGroup:2 SubGroup:9} {FoodGroup:2 SubGroup:11} {FoodGroup:2 SubGroup:15} {FoodGroup:2 SubGroup:21} {FoodGroup:1 SubGroup:4} {FoodGroup:1 SubGroup:2} {FoodGroup:1 SubGroup:6} {FoodGroup:1 SubGroup:8} {FoodGroup:1 SubGroup:14} {FoodGroup:1 SubGroup:17} {FoodGroup:1 SubGroup:23} {FoodGroup:1 SubGroup:30} {FoodGroup:16 SubGroup:2} {FoodGroup:16 SubGroup:4}]}]}" screenName=Alice ip=192.168.144.208:38975
time=2024-05-17T21:58:49.938Z level=TRACE msg="client request" svc=CHAT request.food_group=OService request.sub_group=OServiceRateParamsSubAdd request.snac_frame="{FoodGroup:1 SubGroup:8 Flags:0 RequestID:8}" request.snac_payload={TLVRestBlock:{TLVList:[]}} screenName=Alice ip=192.168.144.208:38975
time=2024-05-17T21:58:49.940Z level=INFO msg="user sent an IM" svc=BOS recipient=Bob screenName=Alice ip=192.168.144.208:48927
time=2024-05-17T21:58:49.940Z level=TRACE msg="client request -> server response" svc=BOS request.food_group=ICBM request.sub_group=ICBMChannelMsgToHost request.snac_frame="{FoodGroup:4 SubGroup:6 Flags:0 RequestID:327686}" request.snac_payload="{Cookie:7124583583287869440 ChannelID:2 ScreenName:Bob TLVRestBlock:{TLVList:[{Tag:5 Value:[0 0 98 223 155 5 118 116 0 0 116 143 36 32 98 135 17 209 130 34 68 69 83 84 0 0 0 10 0 2 0 1 0 15 0 0 0 14 0 2 101 110 0 13 0 8 117 115 45 97 115 99 105 105 0 12 0 21 74 111 105 110 32 109 101 32 105 110 32 116 104 105 115 32 67 104 97 116 46 39 17 0 41 0 4 36 101 100 53 57 102 55 48 100 45 57 51 98 100 45 52 53 50 102 45 56 102 51 51 45 49 97 50 99 48 98 48 98 49 102 48 102 255 255]} {Tag:3 Value:[]}]}}" response.food_group=ICBM response.sub_group=ICBMHostAck response.snac_frame="{FoodGroup:4 SubGroup:12 Flags:0 RequestID:327686}" response.snac_payload="{Cookie:7124583583287869440 ChannelID:2 ScreenName:Bob}" screenName=Alice ip=192.168.144.208:48927
time=2024-05-17T21:58:49.944Z level=TRACE msg="client request" svc=BOS request.food_group=ICBM request.sub_group=ICBMChannelMsgToClient request.snac_frame="{FoodGroup:4 SubGroup:7 Flags:0 RequestID:0}" request.snac_payload="{Cookie:7124583583287869440 ChannelID:2 TLVUserInfo:{ScreenName:Alice WarningLevel:0 TLVBlock:{TLVList:[]}} TLVRestBlock:{TLVList:[{Tag:11 Value:[]} {Tag:5 Value:[0 0 98 223 155 5 118 116 0 0 116 143 36 32 98 135 17 209 130 34 68 69 83 84 0 0 0 10 0 2 0 1 0 15 0 0 0 14 0 2 101 110 0 13 0 8 117 115 45 97 115 99 105 105 0 12 0 21 74 111 105 110 32 109 101 32 105 110 32 116 104 105 115 32 67 104 97 116 46 39 17 0 41 0 4 36 101 100 53 57 102 55 48 100 45 57 51 98 100 45 52 53 50 102 45 56 102 51 51 45 49 97 50 99 48 98 48 98 49 102 48 102 255 255]} {Tag:3 Value:[]}]}}" screenName=Bob ip=192.168.144.208:40527
time=2024-05-17T21:58:49.959Z level=TRACE msg="client request -> server response" svc=BOS request.food_group=ChatNav request.sub_group=ChatNavRequestRoomInfo request.snac_frame="{FoodGroup:13 SubGroup:4 Flags:0 RequestID:983044}" request.snac_payload="{Exchange:4 Cookie:ed59f70d-93bd-452f-8f33-1a2c0b0b1f0f InstanceNumber:65535 DetailLevel:2}" response.food_group=ChatNav response.sub_group=ChatNavNavInfo response.snac_frame="{FoodGroup:13 SubGroup:9 Flags:0 RequestID:983044}" response.snac_payload="{TLVRestBlock:{TLVList:[{Tag:4 Value:[0 4 36 101 100 53 57 102 55 48 100 45 57 51 98 100 45 52 53 50 102 45 56 102 51 51 45 49 97 50 99 48 98 48 98 49 102 48 102 255 255 1 0 7 0 201 0 2 0 15 0 202 0 4 102 71 211 25 0 209 0 2 4 0 0 210 0 2 0 100 0 213 0 1 2 0 106 0 8 116 101 115 116 114 111 111 109 0 211 0 8 116 101 115 116 114 111 111 109]}]}}" screenName=Bob ip=192.168.144.208:40527
time=2024-05-17T21:58:49.989Z level=INFO msg="user signed on" svc=CHAT screenName=Alice ip=192.168.144.208:38975
time=2024-05-17T21:58:49.989Z level=TRACE msg="client request" svc=CHAT request.food_group=OService request.sub_group=OServiceClientOnline request.snac_frame="{FoodGroup:1 SubGroup:2 Flags:0 RequestID:2}" request.snac_payload="{GroupVersions:[{FoodGroup:1 Version:3 ToolID:16 ToolVersion:1577} {FoodGroup:14 Version:1 ToolID:16 ToolVersion:1577}]}" screenName=Alice ip=192.168.144.208:38975
time=2024-05-17T21:58:49.993Z level=TRACE msg="client request" svc=CHAT request.food_group=Chat request.sub_group=ChatRoomInfoUpdate request.snac_frame="{FoodGroup:14 SubGroup:2 Flags:0 RequestID:0}" request.snac_payload="{Exchange:4 Cookie:ed59f70d-93bd-452f-8f33-1a2c0b0b1f0f InstanceNumber:65535 DetailLevel:1 TLVBlock:{TLVList:[{Tag:201 Value:[0 15]} {Tag:202 Value:[102 71 211 25]} {Tag:209 Value:[4 0]} {Tag:210 Value:[0 100]} {Tag:213 Value:[2]} {Tag:106 Value:[116 101 115 116 114 111 111 109]} {Tag:211 Value:[116 101 115 116 114 111 111 109]}]}}" screenName=Alice ip=192.168.144.208:38975
time=2024-05-17T21:58:49.996Z level=TRACE msg="client request" svc=CHAT request.food_group=Chat request.sub_group=ChatUsersJoined request.snac_frame="{FoodGroup:14 SubGroup:3 Flags:0 RequestID:0}" request.snac_payload="{Users:[{ScreenName:Alice WarningLevel:0 TLVBlock:{TLVList:[{Tag:3 Value:[102 71 211 25]} {Tag:1 Value:[0 16]} {Tag:6 Value:[0 0]} {Tag:4 Value:[0 0]}]}}]}" screenName=Alice ip=192.168.144.208:38975
time=2024-05-17T21:58:51.662Z level=TRACE msg="client request -> server response" svc=BOS request.food_group=OService request.sub_group=OServiceServiceRequest request.snac_frame="{FoodGroup:1 SubGroup:4 Flags:0 RequestID:786436}" request.snac_payload="{FoodGroup:14 TLVRestBlock:{TLVList:[{Tag:1 Value:[0 4 36 101 100 53 57 102 55 48 100 45 57 51 98 100 45 52 53 50 102 45 56 102 51 51 45 49 97 50 99 48 98 48 98 49 102 48 102 255 255]}]}}" response.food_group=OService response.sub_group=OServiceServiceResponse response.snac_frame="{FoodGroup:1 SubGroup:5 Flags:0 RequestID:786436}" response.snac_payload="{TLVRestBlock:{TLVList:[{Tag:5 Value:[49 57 50 46 49 54 56 46 49 52 52 46 49 49 51 58 53 49 57 50]} {Tag:6 Value:[36 101 100 53 57 102 55 48 100 45 57 51 98 100 45 52 53 50 102 45 56 102 51 51 45 49 97 50 99 48 98 48 98 49 102 48 102 0 36 98 51 100 48 52 97 50 55 45 97 50 48 101 45 52 55 54 55 45 97 53 52 100 45 51 55 53 55 99 54 48 54 49 48 53 101]} {Tag:13 Value:[0 14]} {Tag:141 Value:[]} {Tag:142 Value:[0]}]}}" screenName=Bob ip=192.168.144.208:40527
time=2024-05-17T21:58:51.843Z level=DEBUG msg="accepted connection" svc=CHAT ip=192.168.144.208:38494
time=2024-05-17T21:58:51.888Z level=TRACE msg="client request -> server response" svc=CHAT request.food_group=OService request.sub_group=ClientVersions request.snac_frame="{FoodGroup:1 SubGroup:23 Flags:0 RequestID:23}" request.snac_payload="{Versions:[1 3 14 1]}" response.food_group=OService response.sub_group=OServiceHostVersions response.snac_frame="{FoodGroup:1 SubGroup:24 Flags:0 RequestID:23}" response.snac_payload="{Versions:[1 3 14 1]}" screenName=Bob ip=192.168.144.208:38494
time=2024-05-17T21:58:51.904Z level=TRACE msg="client request -> server response" svc=CHAT request.food_group=OService request.sub_group=OServiceRateParamsQuery request.snac_frame="{FoodGroup:1 SubGroup:6 Flags:0 RequestID:6}" request.snac_payload=<nil> response.food_group=OService response.sub_group=OServiceRateParamsReply response.snac_frame="{FoodGroup:1 SubGroup:7 Flags:0 RequestID:6}" response.snac_payload="{RateClasses:[{ID:1 WindowSize:80 ClearLevel:2500 AlertLevel:2000 LimitLevel:1500 DisconnectLevel:800 CurrentLevel:3433 MaxLevel:6000 LastTime:0 CurrentState:0}] RateGroups:[{ID:1 Pairs:[{FoodGroup:3 SubGroup:2} {FoodGroup:14 SubGroup:5} {FoodGroup:13 SubGroup:2} {FoodGroup:13 SubGroup:4} {FoodGroup:13 SubGroup:8} {FoodGroup:19 SubGroup:2} {FoodGroup:19 SubGroup:4} {FoodGroup:19 SubGroup:5} {FoodGroup:19 SubGroup:7} {FoodGroup:19 SubGroup:8} {FoodGroup:19 SubGroup:9} {FoodGroup:19 SubGroup:10} {FoodGroup:19 SubGroup:17} {FoodGroup:19 SubGroup:18} {FoodGroup:4 SubGroup:2} {FoodGroup:4 SubGroup:4} {FoodGroup:4 SubGroup:6} {FoodGroup:4 SubGroup:8} {FoodGroup:4 SubGroup:11} {FoodGroup:4 SubGroup:20} {FoodGroup:2 SubGroup:2} {FoodGroup:2 SubGroup:4} {FoodGroup:2 SubGroup:9} {FoodGroup:2 SubGroup:11} {FoodGroup:2 SubGroup:15} {FoodGroup:2 SubGroup:21} {FoodGroup:1 SubGroup:4} {FoodGroup:1 SubGroup:2} {FoodGroup:1 SubGroup:6} {FoodGroup:1 SubGroup:8} {FoodGroup:1 SubGroup:14} {FoodGroup:1 SubGroup:17} {FoodGroup:1 SubGroup:23} {FoodGroup:1 SubGroup:30} {FoodGroup:16 SubGroup:2} {FoodGroup:16 SubGroup:4}]}]}" screenName=Bob ip=192.168.144.208:38494
time=2024-05-17T21:58:51.928Z level=TRACE msg="client request" svc=CHAT request.food_group=OService request.sub_group=OServiceRateParamsSubAdd request.snac_frame="{FoodGroup:1 SubGroup:8 Flags:0 RequestID:8}" request.snac_payload={TLVRestBlock:{TLVList:[]}} screenName=Bob ip=192.168.144.208:38494
time=2024-05-17T21:58:51.979Z level=INFO msg="user signed on" svc=CHAT screenName=Bob ip=192.168.144.208:38494
time=2024-05-17T21:58:51.979Z level=TRACE msg="client request" svc=CHAT request.food_group=OService request.sub_group=OServiceClientOnline request.snac_frame="{FoodGroup:1 SubGroup:2 Flags:0 RequestID:2}" request.snac_payload="{GroupVersions:[{FoodGroup:1 Version:3 ToolID:16 ToolVersion:1577} {FoodGroup:14 Version:1 ToolID:16 ToolVersion:1577}]}" screenName=Bob ip=192.168.144.208:38494
time=2024-05-17T21:58:51.984Z level=TRACE msg="client request" svc=CHAT request.food_group=Chat request.sub_group=ChatRoomInfoUpdate request.snac_frame="{FoodGroup:14 SubGroup:2 Flags:0 RequestID:0}" request.snac_payload="{Exchange:4 Cookie:ed59f70d-93bd-452f-8f33-1a2c0b0b1f0f InstanceNumber:65535 DetailLevel:1 TLVBlock:{TLVList:[{Tag:201 Value:[0 15]} {Tag:202 Value:[102 71 211 25]} {Tag:209 Value:[4 0]} {Tag:210 Value:[0 100]} {Tag:213 Value:[2]} {Tag:106 Value:[116 101 115 116 114 111 111 109]} {Tag:211 Value:[116 101 115 116 114 111 111 109]}]}}" screenName=Bob ip=192.168.144.208:38494
time=2024-05-17T21:58:51.985Z level=TRACE msg="client request" svc=CHAT request.food_group=Chat request.sub_group=ChatUsersJoined request.snac_frame="{FoodGroup:14 SubGroup:3 Flags:0 RequestID:0}" request.snac_payload="{Users:[{ScreenName:Bob WarningLevel:0 TLVBlock:{TLVList:[{Tag:3 Value:[102 71 211 27]} {Tag:1 Value:[0 16]} {Tag:6 Value:[0 0]} {Tag:4 Value:[0 0]}]}}]}" screenName=Alice ip=192.168.144.208:38975
time=2024-05-17T21:58:51.989Z level=TRACE msg="client request" svc=CHAT request.food_group=Chat request.sub_group=ChatUsersJoined request.snac_frame="{FoodGroup:14 SubGroup:3 Flags:0 RequestID:0}" request.snac_payload="{Users:[{ScreenName:Alice WarningLevel:0 TLVBlock:{TLVList:[{Tag:3 Value:[102 71 211 25]} {Tag:1 Value:[0 16]} {Tag:6 Value:[0 0]} {Tag:4 Value:[0 0]}]}} {ScreenName:Bob WarningLevel:0 TLVBlock:{TLVList:[{Tag:3 Value:[102 71 211 27]} {Tag:1 Value:[0 16]} {Tag:6 Value:[0 0]} {Tag:4 Value:[0 0]}]}}]}" screenName=Bob ip=192.168.144.208:38494
time=2024-05-17T21:58:59.024Z level=INFO msg="user sent a chat message" svc=CHAT screenName=Alice ip=192.168.144.208:38975
time=2024-05-17T21:58:59.027Z level=TRACE msg="client request" svc=CHAT request.food_group=Chat request.sub_group=ChatChannelMsgToClient request.snac_frame="{FoodGroup:14 SubGroup:6 Flags:0 RequestID:0}" request.snac_payload="{Cookie:3835169418653284096 Channel:3 TLVRestBlock:{TLVList:[{Tag:1 Value:[]} {Tag:6 Value:[]} {Tag:5 Value:[0 2 0 8 117 115 45 97 115 99 105 105 0 3 0 2 101 110 0 1 0 89 60 72 84 77 76 62 60 66 79 68 89 32 66 71 67 79 76 79 82 61 34 35 102 102 102 102 102 102 34 62 60 70 79 78 84 32 76 65 78 71 61 34 48 34 62 65 65 65 65 65 65 116 104 105 115 105 115 97 116 101 115 116 65 65 65 65 65 65 60 47 70 79 78 84 62 60 47 66 79 68 89 62 60 47 72 84 77 76 62]} {Tag:3 Value:[5 65 108 105 99 101 0 0 0 4 0 3 0 4 102 71 211 25 0 1 0 2 0 16 0 6 0 2 0 0 0 4 0 2 0 0]}]}}" screenName=Bob ip=192.168.144.208:38494
time=2024-05-17T21:58:59.025Z level=TRACE msg="client request -> server response" svc=CHAT request.food_group=Chat request.sub_group=ChatChannelMsgToHost request.snac_frame="{FoodGroup:14 SubGroup:5 Flags:0 RequestID:5}" request.snac_payload="{Cookie:3835169418653284096 Channel:3 TLVRestBlock:{TLVList:[{Tag:1 Value:[]} {Tag:6 Value:[]} {Tag:5 Value:[0 2 0 8 117 115 45 97 115 99 105 105 0 3 0 2 101 110 0 1 0 89 60 72 84 77 76 62 60 66 79 68 89 32 66 71 67 79 76 79 82 61 34 35 102 102 102 102 102 102 34 62 60 70 79 78 84 32 76 65 78 71 61 34 48 34 62 65 65 65 65 65 65 116 104 105 115 105 115 97 116 101 115 116 65 65 65 65 65 65 60 47 70 79 78 84 62 60 47 66 79 68 89 62 60 47 72 84 77 76 62]}]}}" response.food_group=Chat response.sub_group=ChatChannelMsgToClient response.snac_frame="{FoodGroup:14 SubGroup:6 Flags:0 RequestID:5}" response.snac_payload="{Cookie:3835169418653284096 Channel:3 TLVRestBlock:{TLVList:[{Tag:1 Value:[]} {Tag:6 Value:[]} {Tag:5 Value:[0 2 0 8 117 115 45 97 115 99 105 105 0 3 0 2 101 110 0 1 0 89 60 72 84 77 76 62 60 66 79 68 89 32 66 71 67 79 76 79 82 61 34 35 102 102 102 102 102 102 34 62 60 70 79 78 84 32 76 65 78 71 61 34 48 34 62 65 65 65 65 65 65 116 104 105 115 105 115 97 116 101 115 116 65 65 65 65 65 65 60 47 70 79 78 84 62 60 47 66 79 68 89 62 60 47 72 84 77 76 62]} {Tag:3 Value:[5 65 108 105 99 101 0 0 0 4 0 3 0 4 102 71 211 25 0 1 0 2 0 16 0 6 0 2 0 0 0 4 0 2 0 0]}]}}" screenName=Alice ip=192.168.144.208:38975
time=2024-05-17T21:59:00.589Z level=DEBUG msg="keepalive heartbeat" svc=BOS screenName=Alice ip=192.168.144.208:48927

Logs, broken case - gochat link + sending message

Alice clicks on gochat hyperlink for testroom. Bob also clicks gochat hyperlink for testroom. Alice sends a message 'AAAAAAthisisatestAAAAAA'

time=2024-05-17T22:00:37.727Z level=INFO msg="user started a chat room" svc=BOS roomName=testchat screenName=Alice ip=192.168.144.208:48927
time=2024-05-17T22:00:37.728Z level=TRACE msg="client request -> server response" svc=BOS request.food_group=ChatNav request.sub_group=ChatNavCreateRoom request.snac_frame="{FoodGroup:13 SubGroup:8 Flags:0 RequestID:720904}" request.snac_payload="{Exchange:4 Cookie:create InstanceNumber:65535 DetailLevel:1 TLVBlock:{TLVList:[{Tag:215 Value:[101 110]} {Tag:214 Value:[117 115 45 97 115 99 105 105]} {Tag:211 Value:[116 101 115 116 99 104 97 116]}]}}" response.food_group=ChatNav response.sub_group=ChatNavNavInfo response.snac_frame="{FoodGroup:13 SubGroup:9 Flags:0 RequestID:720904}" response.snac_payload="{TLVRestBlock:{TLVList:[{Tag:4 Value:[0 4 36 51 52 56 52 56 52 102 97 45 99 98 51 99 45 52 52 54 52 45 97 98 57 52 45 55 51 55 97 56 99 57 51 48 56 97 99 255 255 1 0 7 0 201 0 2 0 15 0 202 0 4 102 71 211 133 0 209 0 2 4 0 0 210 0 2 0 100 0 213 0 1 2 0 106 0 8 116 101 115 116 99 104 97 116 0 211 0 8 116 101 115 116 99 104 97 116]}]}}" screenName=Alice ip=192.168.144.208:48927
time=2024-05-17T22:00:37.742Z level=TRACE msg="client request -> server response" svc=BOS request.food_group=OService request.sub_group=OServiceServiceRequest request.snac_frame="{FoodGroup:1 SubGroup:4 Flags:0 RequestID:589828}" request.snac_payload="{FoodGroup:14 TLVRestBlock:{TLVList:[{Tag:1 Value:[0 4 36 51 52 56 52 56 52 102 97 45 99 98 51 99 45 52 52 54 52 45 97 98 57 52 45 55 51 55 97 56 99 57 51 48 56 97 99 255 255]}]}}" response.food_group=OService response.sub_group=OServiceServiceResponse response.snac_frame="{FoodGroup:1 SubGroup:5 Flags:0 RequestID:589828}" response.snac_payload="{TLVRestBlock:{TLVList:[{Tag:5 Value:[49 57 50 46 49 54 56 46 49 52 52 46 49 49 51 58 53 49 57 50]} {Tag:6 Value:[36 51 52 56 52 56 52 102 97 45 99 98 51 99 45 52 52 54 52 45 97 98 57 52 45 55 51 55 97 56 99 57 51 48 56 97 99 0 36 52 100 55 98 52 55 98 53 45 101 53 54 51 45 52 101 53 101 45 56 49 51 100 45 52 102 55 51 52 49 55 55 102 55 53 97]} {Tag:13 Value:[0 14]} {Tag:141 Value:[]} {Tag:142 Value:[0]}]}}" screenName=Alice ip=192.168.144.208:48927
time=2024-05-17T22:00:37.770Z level=DEBUG msg="accepted connection" svc=CHAT ip=192.168.144.208:33805
time=2024-05-17T22:00:37.801Z level=TRACE msg="client request -> server response" svc=CHAT request.food_group=OService request.sub_group=ClientVersions request.snac_frame="{FoodGroup:1 SubGroup:23 Flags:0 RequestID:23}" request.snac_payload="{Versions:[1 3 14 1]}" response.food_group=OService response.sub_group=OServiceHostVersions response.snac_frame="{FoodGroup:1 SubGroup:24 Flags:0 RequestID:23}" response.snac_payload="{Versions:[1 3 14 1]}" screenName=Alice ip=192.168.144.208:33805
time=2024-05-17T22:00:37.823Z level=TRACE msg="client request -> server response" svc=CHAT request.food_group=OService request.sub_group=OServiceRateParamsQuery request.snac_frame="{FoodGroup:1 SubGroup:6 Flags:0 RequestID:6}" request.snac_payload=<nil> response.food_group=OService response.sub_group=OServiceRateParamsReply response.snac_frame="{FoodGroup:1 SubGroup:7 Flags:0 RequestID:6}" response.snac_payload="{RateClasses:[{ID:1 WindowSize:80 ClearLevel:2500 AlertLevel:2000 LimitLevel:1500 DisconnectLevel:800 CurrentLevel:3433 MaxLevel:6000 LastTime:0 CurrentState:0}] RateGroups:[{ID:1 Pairs:[{FoodGroup:3 SubGroup:2} {FoodGroup:14 SubGroup:5} {FoodGroup:13 SubGroup:2} {FoodGroup:13 SubGroup:4} {FoodGroup:13 SubGroup:8} {FoodGroup:19 SubGroup:2} {FoodGroup:19 SubGroup:4} {FoodGroup:19 SubGroup:5} {FoodGroup:19 SubGroup:7} {FoodGroup:19 SubGroup:8} {FoodGroup:19 SubGroup:9} {FoodGroup:19 SubGroup:10} {FoodGroup:19 SubGroup:17} {FoodGroup:19 SubGroup:18} {FoodGroup:4 SubGroup:2} {FoodGroup:4 SubGroup:4} {FoodGroup:4 SubGroup:6} {FoodGroup:4 SubGroup:8} {FoodGroup:4 SubGroup:11} {FoodGroup:4 SubGroup:20} {FoodGroup:2 SubGroup:2} {FoodGroup:2 SubGroup:4} {FoodGroup:2 SubGroup:9} {FoodGroup:2 SubGroup:11} {FoodGroup:2 SubGroup:15} {FoodGroup:2 SubGroup:21} {FoodGroup:1 SubGroup:4} {FoodGroup:1 SubGroup:2} {FoodGroup:1 SubGroup:6} {FoodGroup:1 SubGroup:8} {FoodGroup:1 SubGroup:14} {FoodGroup:1 SubGroup:17} {FoodGroup:1 SubGroup:23} {FoodGroup:1 SubGroup:30} {FoodGroup:16 SubGroup:2} {FoodGroup:16 SubGroup:4}]}]}" screenName=Alice ip=192.168.144.208:33805
time=2024-05-17T22:00:37.844Z level=TRACE msg="client request" svc=CHAT request.food_group=OService request.sub_group=OServiceRateParamsSubAdd request.snac_frame="{FoodGroup:1 SubGroup:8 Flags:0 RequestID:8}" request.snac_payload={TLVRestBlock:{TLVList:[]}} screenName=Alice ip=192.168.144.208:33805
time=2024-05-17T22:00:37.899Z level=INFO msg="user signed on" svc=CHAT screenName=Alice ip=192.168.144.208:33805
time=2024-05-17T22:00:37.899Z level=TRACE msg="client request" svc=CHAT request.food_group=OService request.sub_group=OServiceClientOnline request.snac_frame="{FoodGroup:1 SubGroup:2 Flags:0 RequestID:2}" request.snac_payload="{GroupVersions:[{FoodGroup:1 Version:3 ToolID:16 ToolVersion:1577} {FoodGroup:14 Version:1 ToolID:16 ToolVersion:1577}]}" screenName=Alice ip=192.168.144.208:33805
time=2024-05-17T22:00:37.902Z level=TRACE msg="client request" svc=CHAT request.food_group=Chat request.sub_group=ChatRoomInfoUpdate request.snac_frame="{FoodGroup:14 SubGroup:2 Flags:0 RequestID:0}" request.snac_payload="{Exchange:4 Cookie:348484fa-cb3c-4464-ab94-737a8c9308ac InstanceNumber:65535 DetailLevel:1 TLVBlock:{TLVList:[{Tag:201 Value:[0 15]} {Tag:202 Value:[102 71 211 133]} {Tag:209 Value:[4 0]} {Tag:210 Value:[0 100]} {Tag:213 Value:[2]} {Tag:106 Value:[116 101 115 116 99 104 97 116]} {Tag:211 Value:[116 101 115 116 99 104 97 116]}]}}" screenName=Alice ip=192.168.144.208:33805
time=2024-05-17T22:00:37.905Z level=TRACE msg="client request" svc=CHAT request.food_group=Chat request.sub_group=ChatUsersJoined request.snac_frame="{FoodGroup:14 SubGroup:3 Flags:0 RequestID:0}" request.snac_payload="{Users:[{ScreenName:Alice WarningLevel:0 TLVBlock:{TLVList:[{Tag:3 Value:[102 71 211 133]} {Tag:1 Value:[0 16]} {Tag:6 Value:[0 0]} {Tag:4 Value:[0 0]}]}}]}" screenName=Alice ip=192.168.144.208:33805
time=2024-05-17T22:00:40.289Z level=INFO msg="user started a chat room" svc=BOS roomName=testchat screenName=Bob ip=192.168.144.208:40527
time=2024-05-17T22:00:40.289Z level=TRACE msg="client request -> server response" svc=BOS request.food_group=ChatNav request.sub_group=ChatNavCreateRoom request.snac_frame="{FoodGroup:13 SubGroup:8 Flags:0 RequestID:1048584}" request.snac_payload="{Exchange:4 Cookie:create InstanceNumber:65535 DetailLevel:1 TLVBlock:{TLVList:[{Tag:215 Value:[101 110]} {Tag:214 Value:[117 115 45 97 115 99 105 105]} {Tag:211 Value:[116 101 115 116 99 104 97 116]}]}}" response.food_group=ChatNav response.sub_group=ChatNavNavInfo response.snac_frame="{FoodGroup:13 SubGroup:9 Flags:0 RequestID:1048584}" response.snac_payload="{TLVRestBlock:{TLVList:[{Tag:4 Value:[0 4 36 101 50 98 51 54 55 54 99 45 54 99 100 51 45 52 97 99 99 45 97 98 52 56 45 52 55 101 99 97 97 100 56 102 55 99 101 255 255 1 0 7 0 201 0 2 0 15 0 202 0 4 102 71 211 136 0 209 0 2 4 0 0 210 0 2 0 100 0 213 0 1 2 0 106 0 8 116 101 115 116 99 104 97 116 0 211 0 8 116 101 115 116 99 104 97 116]}]}}" screenName=Bob ip=192.168.144.208:40527
time=2024-05-17T22:00:40.308Z level=TRACE msg="client request -> server response" svc=BOS request.food_group=OService request.sub_group=OServiceServiceRequest request.snac_frame="{FoodGroup:1 SubGroup:4 Flags:0 RequestID:851972}" request.snac_payload="{FoodGroup:14 TLVRestBlock:{TLVList:[{Tag:1 Value:[0 4 36 101 50 98 51 54 55 54 99 45 54 99 100 51 45 52 97 99 99 45 97 98 52 56 45 52 55 101 99 97 97 100 56 102 55 99 101 255 255]}]}}" response.food_group=OService response.sub_group=OServiceServiceResponse response.snac_frame="{FoodGroup:1 SubGroup:5 Flags:0 RequestID:851972}" response.snac_payload="{TLVRestBlock:{TLVList:[{Tag:5 Value:[49 57 50 46 49 54 56 46 49 52 52 46 49 49 51 58 53 49 57 50]} {Tag:6 Value:[36 101 50 98 51 54 55 54 99 45 54 99 100 51 45 52 97 99 99 45 97 98 52 56 45 52 55 101 99 97 97 100 56 102 55 99 101 0 36 98 51 100 48 52 97 50 55 45 97 50 48 101 45 52 55 54 55 45 97 53 52 100 45 51 55 53 55 99 54 48 54 49 48 53 101]} {Tag:13 Value:[0 14]} {Tag:141 Value:[]} {Tag:142 Value:[0]}]}}" screenName=Bob ip=192.168.144.208:40527
time=2024-05-17T22:00:40.337Z level=DEBUG msg="accepted connection" svc=CHAT ip=192.168.144.208:38244
time=2024-05-17T22:00:40.364Z level=TRACE msg="client request -> server response" svc=CHAT request.food_group=OService request.sub_group=ClientVersions request.snac_frame="{FoodGroup:1 SubGroup:23 Flags:0 RequestID:23}" request.snac_payload="{Versions:[1 3 14 1]}" response.food_group=OService response.sub_group=OServiceHostVersions response.snac_frame="{FoodGroup:1 SubGroup:24 Flags:0 RequestID:23}" response.snac_payload="{Versions:[1 3 14 1]}" screenName=Bob ip=192.168.144.208:38244
time=2024-05-17T22:00:40.379Z level=TRACE msg="client request -> server response" svc=CHAT request.food_group=OService request.sub_group=OServiceRateParamsQuery request.snac_frame="{FoodGroup:1 SubGroup:6 Flags:0 RequestID:6}" request.snac_payload=<nil> response.food_group=OService response.sub_group=OServiceRateParamsReply response.snac_frame="{FoodGroup:1 SubGroup:7 Flags:0 RequestID:6}" response.snac_payload="{RateClasses:[{ID:1 WindowSize:80 ClearLevel:2500 AlertLevel:2000 LimitLevel:1500 DisconnectLevel:800 CurrentLevel:3433 MaxLevel:6000 LastTime:0 CurrentState:0}] RateGroups:[{ID:1 Pairs:[{FoodGroup:3 SubGroup:2} {FoodGroup:14 SubGroup:5} {FoodGroup:13 SubGroup:2} {FoodGroup:13 SubGroup:4} {FoodGroup:13 SubGroup:8} {FoodGroup:19 SubGroup:2} {FoodGroup:19 SubGroup:4} {FoodGroup:19 SubGroup:5} {FoodGroup:19 SubGroup:7} {FoodGroup:19 SubGroup:8} {FoodGroup:19 SubGroup:9} {FoodGroup:19 SubGroup:10} {FoodGroup:19 SubGroup:17} {FoodGroup:19 SubGroup:18} {FoodGroup:4 SubGroup:2} {FoodGroup:4 SubGroup:4} {FoodGroup:4 SubGroup:6} {FoodGroup:4 SubGroup:8} {FoodGroup:4 SubGroup:11} {FoodGroup:4 SubGroup:20} {FoodGroup:2 SubGroup:2} {FoodGroup:2 SubGroup:4} {FoodGroup:2 SubGroup:9} {FoodGroup:2 SubGroup:11} {FoodGroup:2 SubGroup:15} {FoodGroup:2 SubGroup:21} {FoodGroup:1 SubGroup:4} {FoodGroup:1 SubGroup:2} {FoodGroup:1 SubGroup:6} {FoodGroup:1 SubGroup:8} {FoodGroup:1 SubGroup:14} {FoodGroup:1 SubGroup:17} {FoodGroup:1 SubGroup:23} {FoodGroup:1 SubGroup:30} {FoodGroup:16 SubGroup:2} {FoodGroup:16 SubGroup:4}]}]}" screenName=Bob ip=192.168.144.208:38244
time=2024-05-17T22:00:40.396Z level=TRACE msg="client request" svc=CHAT request.food_group=OService request.sub_group=OServiceRateParamsSubAdd request.snac_frame="{FoodGroup:1 SubGroup:8 Flags:0 RequestID:8}" request.snac_payload={TLVRestBlock:{TLVList:[]}} screenName=Bob ip=192.168.144.208:38244
time=2024-05-17T22:00:40.456Z level=INFO msg="user signed on" svc=CHAT screenName=Bob ip=192.168.144.208:38244
time=2024-05-17T22:00:40.456Z level=TRACE msg="client request" svc=CHAT request.food_group=OService request.sub_group=OServiceClientOnline request.snac_frame="{FoodGroup:1 SubGroup:2 Flags:0 RequestID:2}" request.snac_payload="{GroupVersions:[{FoodGroup:1 Version:3 ToolID:16 ToolVersion:1577} {FoodGroup:14 Version:1 ToolID:16 ToolVersion:1577}]}" screenName=Bob ip=192.168.144.208:38244
time=2024-05-17T22:00:40.460Z level=TRACE msg="client request" svc=CHAT request.food_group=Chat request.sub_group=ChatRoomInfoUpdate request.snac_frame="{FoodGroup:14 SubGroup:2 Flags:0 RequestID:0}" request.snac_payload="{Exchange:4 Cookie:e2b3676c-6cd3-4acc-ab48-47ecaad8f7ce InstanceNumber:65535 DetailLevel:1 TLVBlock:{TLVList:[{Tag:201 Value:[0 15]} {Tag:202 Value:[102 71 211 136]} {Tag:209 Value:[4 0]} {Tag:210 Value:[0 100]} {Tag:213 Value:[2]} {Tag:106 Value:[116 101 115 116 99 104 97 116]} {Tag:211 Value:[116 101 115 116 99 104 97 116]}]}}" screenName=Bob ip=192.168.144.208:38244
time=2024-05-17T22:00:40.464Z level=TRACE msg="client request" svc=CHAT request.food_group=Chat request.sub_group=ChatUsersJoined request.snac_frame="{FoodGroup:14 SubGroup:3 Flags:0 RequestID:0}" request.snac_payload="{Users:[{ScreenName:Bob WarningLevel:0 TLVBlock:{TLVList:[{Tag:3 Value:[102 71 211 136]} {Tag:1 Value:[0 16]} {Tag:6 Value:[0 0]} {Tag:4 Value:[0 0]}]}}]}" screenName=Bob ip=192.168.144.208:38244
time=2024-05-17T22:00:45.880Z level=INFO msg="user sent a chat message" svc=CHAT screenName=Alice ip=192.168.144.208:33805
time=2024-05-17T22:00:45.880Z level=TRACE msg="client request -> server response" svc=CHAT request.food_group=Chat request.sub_group=ChatChannelMsgToHost request.snac_frame="{FoodGroup:14 SubGroup:5 Flags:0 RequestID:5}" request.snac_payload="{Cookie:3835171565851523072 Channel:3 TLVRestBlock:{TLVList:[{Tag:1 Value:[]} {Tag:6 Value:[]} {Tag:5 Value:[0 2 0 8 117 115 45 97 115 99 105 105 0 3 0 2 101 110 0 1 0 89 60 72 84 77 76 62 60 66 79 68 89 32 66 71 67 79 76 79 82 61 34 35 102 102 102 102 102 102 34 62 60 70 79 78 84 32 76 65 78 71 61 34 48 34 62 65 65 65 65 65 65 116 104 105 115 105 115 97 116 101 115 116 65 65 65 65 65 65 60 47 70 79 78 84 62 60 47 66 79 68 89 62 60 47 72 84 77 76 62]}]}}" response.food_group=Chat response.sub_group=ChatChannelMsgToClient response.snac_frame="{FoodGroup:14 SubGroup:6 Flags:0 RequestID:5}" response.snac_payload="{Cookie:3835171565851523072 Channel:3 TLVRestBlock:{TLVList:[{Tag:1 Value:[]} {Tag:6 Value:[]} {Tag:5 Value:[0 2 0 8 117 115 45 97 115 99 105 105 0 3 0 2 101 110 0 1 0 89 60 72 84 77 76 62 60 66 79 68 89 32 66 71 67 79 76 79 82 61 34 35 102 102 102 102 102 102 34 62 60 70 79 78 84 32 76 65 78 71 61 34 48 34 62 65 65 65 65 65 65 116 104 105 115 105 115 97 116 101 115 116 65 65 65 65 65 65 60 47 70 79 78 84 62 60 47 66 79 68 89 62 60 47 72 84 77 76 62]} {Tag:3 Value:[5 65 108 105 99 101 0 0 0 4 0 3 0 4 102 71 211 133 0 1 0 2 0 16 0 6 0 2 0 0 0 4 0 2 0 0]}]}}" screenName=Alice ip=192.168.144.208:33805
@mk6i
Copy link
Owner

mk6i commented May 17, 2024

Thanks for the detailed write-up, will look into this soon.

@mk6i mk6i added the bug Something isn't working label May 17, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
bug Something isn't working
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
2 participants
@jgknight @mk6i