The International Simutrans Forum

Development => Patches & Projects => Incorporated Patches and Solved Bug Reports => Topic started by: Ashley on February 06, 2011, 12:40:28 PM

Title: Network, r4269, desync whenever another player joins (fairly consistent)
Post by: Ashley on February 06, 2011, 12:40:28 PM
This seems to happen fairly consistently using r4269. I have some logs from the client with debug=3 for these incidents. It looks like an error is being raised to the effect that it is trying to close a network socket which is already open. This is using pak.brit 376.

Warning: karte_t::laden():      loaded savegame from 10/1954, next month=61865984, ticks=61708291 (p
er month=1<<20)
Message: karte_t::reset_timer():        called, mode=$5
Message: toolbar_t::update():   update toolbar
Message: toolbar_t::update():   update toolbar SLOPETOOLS
Message: toolbar_t::update():   update toolbar RAILTOOLS
Message: wayobj_t::fill_menu(): try to add TramElectrification(04C7CFB8)
Message: wayobj_t::fill_menu(): try to add DCThirdRail(04CA5A30)
Message: wayobj_t::fill_menu(): try to add DCRailCatenary(04C8E5F8)
Message: wayobj_t::fill_menu(): try to add TrollyBusElectrification(04C628F8)
Message: wayobj_t::fill_menu(): try to add DCThirdRailACCCatenary(04CB0D70)
Message: wayobj_t::fill_menu(): try to add DCThirdRailDCCCatenary(04CA8C68)
Message: wayobj_t::fill_menu(): try to add ACHighSpeedCatenary(04C9CD68)
Message: hausbauer_t::fill_menu():      maximum 75
Message: hausbauer_t::fill_menu():      maximum 75
Message: hausbauer_t::fill_menu():      maximum 75
Message: hausbauer_t::fill_menu():      maximum 75
Message: toolbar_t::update():   update toolbar MONORAILTOOLS
Message: wayobj_t::fill_menu(): try to add TramElectrification(04C7CFB8)
Message: wayobj_t::fill_menu(): try to add DCThirdRail(04CA5A30)
Message: wayobj_t::fill_menu(): try to add DCRailCatenary(04C8E5F8)
Message: wayobj_t::fill_menu(): try to add TrollyBusElectrification(04C628F8)
Message: wayobj_t::fill_menu(): try to add DCThirdRailACCCatenary(04CB0D70)
Message: wayobj_t::fill_menu(): try to add DCThirdRailDCCCatenary(04CA8C68)
Message: wayobj_t::fill_menu(): try to add ACHighSpeedCatenary(04C9CD68)
Message: hausbauer_t::fill_menu():      maximum 75
Message: hausbauer_t::fill_menu():      maximum 75
Message: toolbar_t::update():   update toolbar MAGLEVTOOLS
Message: wayobj_t::fill_menu(): try to add TramElectrification(04C7CFB8)
Message: wayobj_t::fill_menu(): try to add DCThirdRail(04CA5A30)
Message: wayobj_t::fill_menu(): try to add DCRailCatenary(04C8E5F8)
Message: wayobj_t::fill_menu(): try to add TrollyBusElectrification(04C628F8)
Message: wayobj_t::fill_menu(): try to add DCThirdRailACCCatenary(04CB0D70)
Message: wayobj_t::fill_menu(): try to add DCThirdRailDCCCatenary(04CA8C68)
Message: wayobj_t::fill_menu(): try to add ACHighSpeedCatenary(04C9CD68)
Message: hausbauer_t::fill_menu():      maximum 75
Message: hausbauer_t::fill_menu():      maximum 75
Message: hausbauer_t::fill_menu():      maximum 75
Message: hausbauer_t::fill_menu():      maximum 75
Message: toolbar_t::update():   update toolbar TRAMTOOLS
Message: wayobj_t::fill_menu(): try to add TramElectrification(04C7CFB8)
Message: wayobj_t::fill_menu(): try to add DCThirdRail(04CA5A30)
Message: wayobj_t::fill_menu(): try to add DCRailCatenary(04C8E5F8)
Message: wayobj_t::fill_menu(): try to add TrollyBusElectrification(04C628F8)
Message: wayobj_t::fill_menu(): try to add DCThirdRailACCCatenary(04CB0D70)
Message: wayobj_t::fill_menu(): try to add DCThirdRailDCCCatenary(04CA8C68)
Message: wayobj_t::fill_menu(): try to add ACHighSpeedCatenary(04C9CD68)
Message: hausbauer_t::fill_menu():      maximum 75
Message: hausbauer_t::fill_menu():      maximum 75
Message: toolbar_t::update():   update toolbar ROADTOOLS
Message: wayobj_t::fill_menu(): try to add TramElectrification(04C7CFB8)
Message: wayobj_t::fill_menu(): try to add DCThirdRail(04CA5A30)
Message: wayobj_t::fill_menu(): try to add DCRailCatenary(04C8E5F8)
Message: wayobj_t::fill_menu(): try to add TrollyBusElectrification(04C628F8)
Message: wayobj_t::fill_menu(): try to add DCThirdRailACCCatenary(04CB0D70)
Message: wayobj_t::fill_menu(): try to add DCThirdRailDCCCatenary(04CA8C68)
Message: wayobj_t::fill_menu(): try to add ACHighSpeedCatenary(04C9CD68)
Message: hausbauer_t::fill_menu():      maximum 75
Message: toolbar_t::update():   update toolbar AIRTOOLS
Message: wayobj_t::fill_menu(): try to add TramElectrification(04C7CFB8)
Message: wayobj_t::fill_menu(): try to add DCThirdRail(04CA5A30)
Message: wayobj_t::fill_menu(): try to add DCRailCatenary(04C8E5F8)
Message: wayobj_t::fill_menu(): try to add TrollyBusElectrification(04C628F8)
Message: wayobj_t::fill_menu(): try to add DCThirdRailACCCatenary(04CB0D70)
Message: wayobj_t::fill_menu(): try to add DCThirdRailDCCCatenary(04CA8C68)
Message: wayobj_t::fill_menu(): try to add ACHighSpeedCatenary(04C9CD68)
Message: hausbauer_t::fill_menu():      maximum 75
Message: hausbauer_t::fill_menu():      maximum 75
Message: hausbauer_t::fill_menu():      maximum 75
Message: hausbauer_t::fill_menu():      maximum 75
Message: toolbar_t::update():   update toolbar SPECIALTOOLS
Message: toolbar_t::update():   update toolbar EDITTOOLS
Message: toolbar_t::update():   update toolbar LISTTOOLS
Warning: karte_t::network_game_set_pause:       steps=6240 sync_steps=24960 pause=1
Message: karte_t::reset_timer():        called, mode=$5
Message: network_command_t::rdwr:       write packet_id=5, client_id=3
Message: network_command_t::rdwr:       read packet_id=6, client_id=0
Warning: nwc_tool_t::rdwr:      rdwr id=6 client=0 plnr=255 pos=koord3d invalid wkzid=8224 defpar=Right now 4 clients are connected. init=1 exec=1 flags=0
Warning: network_check_activity():      received cmd id=6 nwc_tool_t from socket[1388]
Message: nwc_tool_t::execute:   append sync_step=24965 current sync_step=24960  wkz=8224 init
Message: network_world_command_t::execute:      do_command 6 at sync_step 24965 world now at 24960
Message: packet_t::send:        sent 28 bytes to socket[1388]; id=5, size=28
ERROR: network_receive_data:    connection [1388] already closed
Please report all errors to
team@64.simutrans.com
Message: socket_list_t::remove_client:  remove client socket[1388]
Warning: karte_t::interactive:  lost connection to server
Warning: karte_t::network_disconnect(): Lost synchronisation with server.
Message: karte_t::reset_timer():        called, mode=$0
Message: simmain:       show banner
Message: karte_t::reset_timer():        called, mode=$0
Message: network_receive_file:  Game size 556
Message: event: 0,-16
Message: simmain:       banner closed
Message: simmain:       set_message_flags
Message: karte_t::reset_timer():        called, mode=$0
Message: event: 118,220
Message: event: 131,13
Message: gui_scrolled_list_t::show_selection(): sel=0, offset=0, groesse.y=86
Message: gui_scrolled_list_t::show_selection(): sel=0, offset=0, groesse.y=86
Message: gui_scrolled_list_t::infowin_event():  selected 0
Message: gui_combobox_t::infowin_event():       scroll selected 10
Message: gui_scrolled_list_t::show_selection(): sel=10, offset=39, groesse.y=86
Message: network_command_t::rdwr:       write packet_id=1, client_id=3
Message: packet_t::send:        sent 14 bytes to socket[1424]; id=1, size=14
Message: socket_list_t::add_client:     add client socket[1424]
Message: network_command_t::rdwr:       read packet_id=1, client_id=0
Warning: network_check_activity():      received cmd id=1 nwc_gameinfo_t from socket[1424]
Message: network_receive_file:  Game size 1989
Message: socket_list_t::remove_client:  remove client socket[1424]
Message: event: 150,171
Message: gui_combobox_t::infowin_event():       close
Message: karte_t::laden:        loading game from 'net:brit.simutrans.entropy.me.uk:13355'
Message: network_command_t::rdwr:       write packet_id=2, client_id=3
Message: packet_t::send:        sent 15 bytes to socket[1384]; id=2, size=15
Message: socket_list_t::add_client:     add client socket[1384]
Message: network_command_t::rdwr:       read packet_id=2, client_id=0


Warning: nwc_tool_t::rdwr:      rdwr id=6 client=0 plnr=255 pos=koord3d invalid wkzid=8224 defpar=Right now 4 clients are connected. init=1 exec=1 flags=0
Warning: network_check_activity():      received cmd id=6 nwc_tool_t from socket[1384]
Message: nwc_tool_t::execute:   append sync_step=25517 current sync_step=25514  wkz=8224 init
Message: network_world_command_t::execute:      do_command 6 at sync_step 25517 world now at 25514
Message: packet_t::send:        sent 28 bytes to socket[1384]; id=5, size=28
Message: network_command_t::rdwr:       read packet_id=6, client_id=0
Warning: nwc_tool_t::rdwr:      rdwr id=6 client=4 plnr=14 pos=220,291,3 wkzid=4100 defpar=17 #all down slope init=0 exec=1 flags=0
Warning: network_check_activity():      received cmd id=6 nwc_tool_t from socket[1384]
Message: nwc_tool_t::execute:   append sync_step=25592 current sync_step=25514  wkz=4100 work
Message: network_world_command_t::execute:      do_command 6 at sync_step 25592 world now at 25514
Message: network_command_t::rdwr:       read packet_id=7, client_id=0
Warning: network_check_activity():      received cmd id=7 nwc_check_t from socket[1384]
Message: NWC_CHECK:     time difference to server 2723
Message: network_world_command_t::execute:      do_command 7 at sync_step 25601 world now at 25514
Message: network_command_t::rdwr:       read packet_id=6, client_id=0
Warning: nwc_tool_t::rdwr:      rdwr id=6 client=4 plnr=14 pos=220,289,3 wkzid=4100 defpar=17 #all down slope init=0 exec=1 flags=0
Warning: network_check_activity():      received cmd id=6 nwc_tool_t from socket[1384]
Message: nwc_tool_t::execute:   append sync_step=25616 current sync_step=25514  wkz=4100 work
Message: network_world_command_t::execute:      do_command 6 at sync_step 25616 world now at 25514
ERROR: network_receive_data:    connection [1384] already closed
Please report all errors to
team@64.simutrans.com
Message: socket_list_t::remove_client:  remove client socket[1384]
Warning: karte_t::interactive:  lost connection to server
Warning: karte_t::network_disconnect(): Lost synchronisation with server.
Message: karte_t::reset_timer():        called, mode=$0


Warning: karte_t::network_game_set_pause:       steps=7697 sync_steps=30788 pause=1
Message: karte_t::reset_timer():        called, mode=$5
Message: network_command_t::rdwr:       write packet_id=5, client_id=3
Message: network_command_t::rdwr:       read packet_id=7, client_id=0
Warning: network_check_activity():      received cmd id=7 nwc_check_t from socket[1376]
Message: NWC_CHECK:     time difference to server 1699
Message: network_world_command_t::execute:      do_command 7 at sync_step 30849 world now at 30788
Message: packet_t::send:        sent 28 bytes to socket[1376]; id=5, size=28
Message: network_command_t::rdwr:       read packet_id=6, client_id=0
Warning: nwc_tool_t::rdwr:      rdwr id=6 client=4 plnr=14 pos=248,250,1 wkzid=4116 defpar=Signals,2,1,1 init=0 exec=1 flags=0
Warning: network_check_activity():      received cmd id=6 nwc_tool_t from socket[1376]
Message: nwc_tool_t::execute:   append sync_step=30862 current sync_step=30788  wkz=4116 work
Message: network_world_command_t::execute:      do_command 6 at sync_step 30862 world now at 30788
Message: network_command_t::rdwr:       read packet_id=6, client_id=0
Warning: nwc_tool_t::rdwr:      rdwr id=6 client=2 plnr=2 pos=562,150,2 wkzid=4097 defpar=(null) init=0 exec=1 flags=0
Warning: network_check_activity():      received cmd id=6 nwc_tool_t from socket[1376]
Message: nwc_tool_t::execute:   append sync_step=30898 current sync_step=30788  wkz=4097 work
Message: network_world_command_t::execute:      do_command 6 at sync_step 30898 world now at 30788
ERROR: network_receive_data:    connection [1376] already closed
Please report all errors to
team@64.simutrans.com
Message: socket_list_t::remove_client:  remove client socket[1376]
Warning: karte_t::interactive:  lost connection to server
Warning: karte_t::network_disconnect(): Lost synchronisation with server.
Message: karte_t::reset_timer():        called, mode=$0
Message: simmain:       show banner
Message: karte_t::reset_timer():        called, mode=$0
Title: Re: Network, r4269, desync whenever another player joins (fairly consistent)
Post by: RichardG on February 06, 2011, 01:18:48 PM
Title: Re: Network, r4269, desync whenever another player joins (fairly consistent)
Post by: Dwachs on February 06, 2011, 03:43:43 PM
@Timothy: do you have a log from the server?

Edit: could you please retest with rev 4275?
Title: Re: Network, r4269, desync whenever another player joins (fairly consistent)
Post by: Ashley on February 06, 2011, 11:00:10 PM
I'll recompile tomorrow and update the server version. Need to wait for a new nightly to come out so people can easily upgrade. I'll collect server logs on debug 3 when I do that :)
Title: Re: Network, r4269, desync whenever another player joins (fairly consistent)
Post by: wernieman on February 10, 2011, 09:32:25 AM
The Problem is, that the nightly-Server don't work at the moment.

So you get no new nightlys ...
(O.K. at the moment I make a manually run)
Title: Re: Network, r4269, desync whenever another player joins (fairly consistent)
Post by: Ashley on February 14, 2011, 07:21:10 PM
Ah ok, is it hard to fix?

What cross-compiler does the nightly build server use?
Title: Re: Network, r4269, desync whenever another player joins (fairly consistent)
Post by: wernieman on February 15, 2011, 09:26:31 PM
It run mingw32 on a Linux-System.

I yust must make the room ready for the Server, than whe will have the nightlys back ....
Title: Re: Network, r4269, desync whenever another player joins (fairly consistent)
Post by: Ashley on February 15, 2011, 09:41:17 PM
Glad to hear it :)