frandallfarmer / neohabitat

Repository for the NeoClassical Habitat Server Project
http://neohabitat.org
MIT License
229 stars 41 forks source link

Fix server end handler #433

Closed kevzettler closed 1 year ago

kevzettler commented 1 year ago

This adds a process.nextTick handler to the server.on end event in Habitat2Elkobridge

This was a suggested fix from Keith at The MADE https://github.com/frandallfarmer/neohabitat/issues/393#issuecomment-1648805836

This should address #393 #431 and others

kevzettler commented 1 year ago

@frandallfarmer @StuBlad could one of you test and confirm if this fixes the issue? I can't seem to install the current docker-compose on my Apple Silicon machine to test and don't have a staging environment setup on the MADE resources yet

frandallfarmer commented 1 year ago

This fix did not work as intended. The test that breaks it is to use the web-client (port 1701) and try to change regions. It still breaks the wrong connection from the habiproxy... Message trace here:

neohabitat_1         | debug: client (5:Randy) ->  [noid:20 request:9 seq:9 ... [0,1]]
neohabitat_1         | debug: {"to":"user-randy-6521498718037631309","op":"NEWREGION","direction":0,"passage_id":1} -> server (5:Randy)
neohabitat_1         | debug: Processing Client message for Client 172.18.0.4:50746 (Randy): {"to":"user-randy-6521498718037631309","op":"NEWREGION","direction":0,"passage_id":1}
neohabitat_1         | - 2023/07/25 19:07:20.358 MSG comm-cli : TCP(3) -> {"to":"user-randy-6521498718037631309","op":"NEWREGION","direction":0,"passage_id":1}
neohabitat_1         | - 2023/07/25 19:07:20.359 MSG comm-cli : TCP(3) <- {"type":"reply", "noid":20, "filler":1, "err":1}
neohabitat_1         | - 2023/07/25 19:07:20.359 WRN habitat (HabitatMod.trace_msg:HabitatMod.java:2092) Avatar user-randy-6521498718037631309 changing regions to context=context-Downtown_5e, direction=0, type=0
neohabitat_1         | - 2023/07/25 19:07:20.360 MSG comm-cli : TCP(0) <- {"type":"neighbor", "noid":0, "op":"WAITFOR_$", "who":20}
neohabitat_1         | debug: server (5:Randy) -> {"type":"reply","noid":20,"filler":1,"err":1}
neohabitat_1         | debug: Processing Server message for Client 172.18.0.4:50746 (Randy): {"type":"reply","noid":20,"filler":1,"err":1}
neohabitat_1         | debug: [85,233,20,1,1] -> client (5:Randy)
neohabitat_1         | - 2023/07/25 19:07:20.360 MSG comm-cli : TCP(3) <- {"type":"changeContext", "context":"context-Downtown_5e", "immediate":false}
neohabitat_1         | debug: Processing Server message for Client 172.18.0.4:43682 (ElizaBot): {"type":"neighbor","noid":0,"op":"WAITFOR_$","who":20}
neohabitat_1         | debug: server (1:ElizaBot) -> {"type":"neighbor","noid":0,"op":"WAITFOR_$","who":20} -> client (1:ElizaBot)
neohabitat_1         | debug: Processing Server message for Client 172.18.0.4:50746 (Randy): {"type":"changeContext","context":"context-Downtown_5e","immediate":false}
neohabitat_1         | debug: Client 172.18.0.4:50746 (Randy) received changeContext, disconnecting...
neohabitat_1         | debug: Disconnecting Habiproxy connection on: 172.18.0.4:50746 (Randy)
neohabitat_1         | debug: Destroying connection: 172.18.0.4:50746
neohabitat_1         | debug: Elko port disconnected...
neohabitat_1         | debug: {Bridge being shutdown...}
neohabitat_1         | - 2023/07/25 19:07:20.362 EVN comm-cli : TCP(3) remote disconnect
neohabitat_1         | - 2023/07/25 19:07:20.362 EVN comm-cli : TCP(3) died: java.io.EOFException
neohabitat_1         | - 2023/07/25 19:07:20.363 EVN cont (User.disconnect:User.java:186) exiting User 'user-randy-6521498718037631309'
neohabitat_1         | - 2023/07/25 19:07:20.363 EVN cont : User 'user-randy-6521498718037631309' exits Context 'context-Downtown_5f'
neohabitat_1         | debug: Connecting: 172.18.0.4:1337 <-> 172.18.0.4:39226
bots_1               | 2023-07-25T19:07:20.364Z - debug: <-RCVD@neohabitat:1337: {"type":"neighbor","noid":0,"op":"WAITFOR_$","who":20}
neohabitat_1         | - 2023/07/25 19:07:20.363 MSG comm-cli : TCP(0) <- {"to":"user-randy-6521498718037631309", "op":"delete"}
neohabitat_1         | - 2023/07/25 19:07:20.364 EVN cont (User.connectionDied:User.java:159) User 'user-randy-6521498718037631309' connection died: TCP(3)
neohabitat_1         | debug: Habiproxy client connected at: 172.18.0.4:39226
neohabitat_1         | debug: Habitat client disconnected.
neohabitat_1         | debug: server (1:ElizaBot) -> {"to":"user-randy-6521498718037631309","op":"delete"} -> client (1:ElizaBot)
neohabitat_1         | debug: Processing Server message for Client 172.18.0.4:43682 (ElizaBot): {"to":"user-randy-6521498718037631309","op":"delete"}
bots_1               | 2023-07-25T19:07:20.365Z - debug: <-RCVD@neohabitat:1337: {"to":"user-randy-6521498718037631309","op":"delete"}
bots_1               | 2023-07-25T19:07:20.366Z - debug: Running callbacks for op: delete
neohabitat_1         | debug: Running server callbacks for delete on: 172.18.0.4:43682 (ElizaBot)
neohabitat_1         | debug: Client disconnected for Client 172.18.0.4:39226 (unknown), moving session to ASLEEP
neohabitat_1         | debug: Disconnecting Habiproxy connection on: 172.18.0.4:39226 (unknown)
neohabitat_1         | debug: Elko port disconnected...
neohabitat_1         | debug: {Bridge being shutdown...}