"Lost synchronisation with server" report thread

[freddyhayward]

Moderator note: please do not post reports of crashes here, even if the crashes cause loss of synchronisation errors. Bugs relating to crashes should be reported on their own thread. Thank you.

The purpose of this thread is to allow users to report any losses of synchronisation without needing to locate or create an issue-specific thread. I would be grateful if James could pin this (or a similar thread).

How to generate checklist mismatch messages
1) Run simutrans-extended with the options (at least on linux, can someone let me know about Windows?) " -debug 2 -log simu.log" to generate checklist mismatch messages when they occur.
1a) If you are running a server, run it with server_frames_between_checks = 0 in simuconf.tab to ensure that mismatches are detected as soon as they occur.
2) Your client will pause upon a loss of synchronisation. If you can, please keep it paused and open! There might be further useful information hidden in the game state.
3) After you lose synchronisation, search for "disconnecting due to checklist mismatch" and post the message below here. The message should look something like this image (credit to Phystam):


How to investigate convoy mismatches
1) When individual convoys go out of sync, this will manifest in mismatching debug sums, shown here:


2) Open a calculator and divide the difference of the right-hand sum by the difference of the left-hand sum to get the ID of the convoy. If the numbers don't divide evenly, there might be multiple convoys involved, or there might be a problem with the logging system.


2) On your client, search for the ID found in the previous step by opening the vehicle list (Shift-V), click the checkbox to enable filter, click "Settings" to open the filter window, click the "Filter names:" checkbox and type in the ID. You may need to do this for multiple companies before finding it, so start with the largest companies first to speed up the process.


Additional notes
* Please let me know if I should add any more information or clarification.
* I'm keeping a tally of the types of mismatches here: https://docs.google.com/spreadsheets/d/1Jwa-5G6aXfkrCrPYLQvDbYt7LqYMgYapW8hyOF9IB3s/edit?usp=sharing. There's no detailed information, but it gives a general idea as to where they most frequently occur. (Update 21/11/21: I no longer maintain that spreadsheet. If anyone else wants to create and maintain one, please let me know so I can link it here.)

[Phystam]

sum[0] and sum[2] have differences.

[Phystam]

And double post... This is from a participant in my server. He reported that there are "no route" messages because of low axle load just after disconnection.

[freddyhayward]

The first convoy identified under the new debug sum system: a train departing from a station after a signal displays clear. It's unclear what the actual problem is, but hopefully a noticeable pattern will emerge in time.

[Matthew]

Freddy, thank you for reworking the debug sums system to get more useful results. I take it that this can be combined with the new pause-on-desync feature to identify the convoy that caused that desync (where that is the cause). Could you please post a simple explanation of how to join the dots in the log file?

[freddyhayward]

Freddy, thank you for reworking the debug sums system to get more useful results. I take it that this can be combined with the new pause-on-desync feature to identify the convoy that caused that desync (where that is the cause). Could you please post a simple explanation of how to join the dots in the log file?

I have edited this into the original post. Please let me know whether anything there needs clarification.

[Matthew]

I have edited this into the original post. Please let me know whether anything there needs clarification.

Thank you! That looks crystal clear, but the proof of the pudding is in the eating, which will happen when I desync.

[jamespetts]

I should note that I have just incorporated some fixes by Ceeac to possible undefined behaviour. These fixes should appear in to-morrow's nightly build. It is possible that these may affect loss of synchronisation errors.

[Phystam]

How to output the log file (Windows10):
1) Make a shortcut for Simutrans-Extended.
2) Open the shortcut property and edit this section as the following picture:

[jamespetts]

Thank you very much to Freddy for compiling the spreadsheet of loss of synchronisation causes. As will be appreciated, the less frequent the loss of synchronisation, the more difficult that it is to test (as there is no reliable way to know whether any given change fixed the problem if it occurs only infrequently without waiting an extremely long time). Also, the less frequent the loss of synchronisation, the less important that remedying the problem is.

Nonetheless, it is worthwhile to try to remedy these if possible, especially the most common types. The most common types so far seem to be convoy movement based losses of synchronisation (debug sums) and halt based losses of synchronisation (rands[23]).

As to the latter, the code in the haltestelle_t::step() function most likely to show a divergence of random numbers is check_transferring_cargoes, which, when dealing with passengers, invokes the RNG by generating local pedestrians whenever passengers are released from their transferring state.

However, this means that we have very little idea of where the problem is originating, as its expression in this place could mean an origin in a vast number of different places in the code.

We already have a system to check part f this, being debug sums 6 and 7 for checking the number of transferring cargoes before and after the passenger and mail generation have run.

May I suggest that future loss of synchronisation logging should explicitly check whether there is any divergence in debug sums 6 and 7 when recording a loss of synchronisation at rands[23]?

[Matthew]

After several weeks generally free of desyncs, I have had several this evening (Europe). They have this pattern:

server=[ss=432121 st=36010 nfc=1 rand=2601725695 halt=1415 line=1 cnvy=2049
   ssr=2031812834,0,2031812834,2031812834,2601725695,2601725695,2601725695,0
   str=963854789,963854789,963854789,963854789,963854789,963854789,963854789,963854789,963854789,963854789,963854789,963854789,963854789,963854789,963854789,4175980762
   exr=4175980762,2031812834,2031812834,0,0,0,0,0
   sums=505501,924070409,24433,25200,6,0,0,0,94234,94022]
client=[ss=432121 st=36010 nfc=1 rand=4025026073 halt=1415 line=1 cnvy=2049
   ssr=2031812834,0,2031812834,2031812834,4025026073,4025026073,4025026073,0
   str=963854789,963854789,963854789,963854789,963854789,963854789,963854789,963854789,963854789,963854789,963854789,963854789,963854789,963854789,963854789,4175980762
   exr=4175980762,2031812834,2031812834,0,0,0,0,0
   sums=505501,924070409,24433,25200,6,0,0,0,94234,94022]

Freddy also had desynchs following this pattern a few days ago (17 June).

I think that indicates that the desync is between debug sums 3 and 4, whicb contains these lines of code:

Code Select Expand

clear_random_mode( INTERACTIVE_RANDOM );

sync.sync_step( delta_t );

That second line appears to be the convoy movement code. But the game does not report a particular convoy as having problems in the last line of the 'desync report'. So I am not sure how to investigate further.

[freddyhayward]

After several weeks generally free of desyncs, I have had several this evening (Europe). They have this pattern:

Freddy also had desynchs following this pattern a few days ago (17 June).

I think that indicates that the desync is between debug sums 3 and 4, whicb contains these lines of code:

Code Select Expand

clear_random_mode( INTERACTIVE_RANDOM );

sync.sync_step( delta_t );

That second line appears to be the convoy movement code. But the game does not report a particular convoy as having problems in the last line of the 'desync report'. So I am not sure how to investigate further.

The last two debug sums were added to track the size of the sync list before and after the step. Your report oddly shows no discrepancy.

[Matthew]

As of today's update (#f00df43) I am desynching about every 15 minutes, which is worse than before. So far the desync is always between rands 3 and 4, i.e. in sync.sync_step, but obviously that doesn't tell us much. I'm on Linux. I realize this unlikely to be fixed immediately, but thought it might be useful data.

By the way, I can't find commit #f00df43 in the repo, so maybe last night's build included something that has subsequently been reverted?

[jamespetts]

As of today's update (#f00df43) I am desynching about every 15 minutes, which is worse than before. So far the desync is always between rands 3 and 4, i.e. in sync.sync_step, but obviously that doesn't tell us much. I'm on Linux. I realize this unlikely to be fixed immediately, but thought it might be useful data.

By the way, I can't find commit #f00df43 in the repo, so maybe last night's build included something that has subsequently been reverted?

I believe that the reason that the build numbers on the compiled binaries is different to the numbers on the Github repository is that there has to be a merge to the build server because some configuration files have changed sligthly.

Can I ask how frequent the losses of synchronisation were before the latest update?

[Matthew]

I believe that the reason that the build numbers on the compiled binaries is different to the numbers on the Github repository is that there has to be a merge to the build server because some configuration files have changed sligthly.

That's unfortunate, as it was useful to be able to reproduce the B-B build, though I don't doubt that you had good reasons for the change.

Can I ask how frequent the losses of synchronisation were before the latest update?

In July and earlier in August I logged 20 desyncs in 71 sessions (and some of those were due to the Internet cutting out). So before today, maybe one buggy desync every 4-5 hours?

[jamespetts]

Thank you for confirming. Can I check whether anybody else has noticed a marked increase in losses of synchronisation with to-day's build in particular?

[zook2]

More like the opposite. Several days ago I had frequent desynchs, but yesterday I played quite a bit and remember only one, while Matt seemed to be logging on and off all the time.

[Matthew]

The last couple of days I have gone back to the old frequency of desyncs (i.e. rare). But I haven't been logged on at the same time as Zook.

So I suspect that this may be related to Linux clients and Windows clients being connected to a server at the same time, which has been a longstanding area of concern.

[zook2]

I've been offline since Tuesday. Today I'm back, find Huitsi also logged in, and I desynch within a few minutes or less.

[Matthew]

This afternoon I am back to constant desyncs (every 2-3 minutes). I have asked in the chat and apparently no one else is logged on, so that does not seem be the issue.

Looking at the desyncs reported in this thread and in #extended-desync-logs on Discord, I am beginning to wonder whether time of day might be a factor here. My frequent desyncs seem to happen around 1500-1700 GMT. If Zook made his last post when he encountered the issue, then he had problems at the same time. I didn't have such problems last night, but the server had been restarted after the crash at 1534 GMT.

Maybe the problem is at my end and the Internet connection is less reliable at that time??  But I don't have these problems with PHNS4 (the Solomon Islands server). It's specific to B-B.

Or maybe B-B is slower at that time of day (maybe another VM on the same rack is busier??). Or has a memory leak? Would it be possible to auto-restart the game more frequently? I know that is a pain for Australians and others who have to wait a long time to download saves, but the save files are much smaller than they were a year ago (thanks to hard work by Freddy, Freahk, James and others).

Or this might just be a case of 'if you look hard enough for a pattern, then you will find one'. 

[jamespetts]

Losses of synchronisation should not occur as a result of the server running slowly: I believe that Dr. Supergood fixed that a few years ago. What will instead happen is that the client will be paused until the server catches up. Therefore, if you are seeing a loss of synchronisation, the problem is a bug somewhere in the game. Unfortunately, as you will be aware, these can be almost unimaginably difficult to track down.

[zook2]

I had a desynch at about 13:00 GMT. I pinged the server a few times; average times were between 120ms and 230ms. I have no idea what a good latency would be.

[jamespetts]

I had a desynch at about 13:00 GMT. I pinged the server a few times; average times were between 120ms and 230ms. I have no idea what a good latency would be.

The latency that you describe would be considered high for an action game that requires quick responses but is well within the acceptable range for Simutrans - the latency does not appear to be a cause of this issue.

[Matthew]

Further to the posts above, I kept some notes on ping times and how often I was desynched from Bridgewater-Brunel. There does not seem to be any obvious correlation.

[zook2]

Just an observation that could be a random effect: tonight I cut a rail line, causing an incoming train to stop with a "No route" message. I desynched before I could rebuild that one tile. My next four or five attempts to log in failed with immediate or almost immediate desynchs. That was pretty late and, after Freddy left, with no other player on the server for hours. Finally, I managed to quickly fix the line, the "No route" nagging stopped and so did the desynchs.

[freddyhayward]

Just an observation that could be a random effect: tonight I cut a rail line, causing an incoming train to stop with a "No route" message. I desynched before I could rebuild that one tile. My next four or five attempts to log in failed with immediate or almost immediate desynchs. That was pretty late and, after Freddy left, with no other player on the server for hours. Finally, I managed to quickly fix the line, the "No route" nagging stopped and so did the desynchs.

Have you been recording the desync logs? This would be very useful.

[zook2]

I'll start now. Where do I find the logfiles?

[zook2]

Warning: NWC_CHECK:    time difference to server 1600
Warning: NWC_CHECK:    time difference to server 1600
Warning: NWC_CHECK:    time difference to server 1600
Warning: NWC_CHECK:    time difference to server 1600
Warning: NWC_CHECK:    time difference to server 1500
Warning: void convoi_t::hat_gehalten(halthandle_t halt):    Arrival time in the future for (9330) Clydesdale horse (single) at Tannacaber High Street Stop
Warning: NWC_CHECK:    time difference to server 1500
Warning: NWC_CHECK:    time difference to server 1500
Warning: NWC_CHECK:    time difference to server 1500
Warning: NWC_CHECK:    time difference to server 1500
Warning: NWC_CHECK:    time difference to server 1500
Warning: NWC_CHECK:    time difference to server 1400
Warning: NWC_CHECK:    time difference to server 1400
Warning: NWC_CHECK:    time difference to server 1400
Warning: NWC_CHECK:    time difference to server 1400
Warning: NWC_CHECK:    time difference to server 1400
Warning: haltestelle_t::liefere_an():    5 Passengers delivered to Highwell were intended for a building that has been deleted.
Warning: NWC_CHECK:    time difference to server 1300
Warning: NWC_CHECK:    time difference to server 1300
Warning: NWC_CHECK:    time difference to server 1300
Warning: NWC_CHECK:    time difference to server 1300
Warning: NWC_CHECK:    time difference to server 1300
Warning: NWC_CHECK:    time difference to server 1300
Warning: NWC_CHECK:    time difference to server 1300
Warning: NWC_CHECK:    time difference to server 1000
Warning: NWC_CHECK:    time difference to server 1000
Warning: NWC_CHECK:    time difference to server 1000
Warning: NWC_CHECK:    time difference to server 1000
Warning: NWC_CHECK:    time difference to server 1000
Warning: NWC_CHECK:    time difference to server 1000
Warning: NWC_CHECK:    time difference to server 1000
Warning: NWC_CHECK:    time difference to server 1000
Warning: NWC_CHECK:    time difference to server 1000
Warning: NWC_CHECK:    time difference to server 1000
Warning: NWC_CHECK:    time difference to server 1000
Warning: NWC_CHECK:    time difference to server 1000
Warning: haltestelle_t::liefere_an():    3 Passengers delivered to Wood Bovgrave were intended for a building that has been deleted.
Warning: void convoi_t::hat_gehalten(halthandle_t halt):    Arrival time in the future for (4232) Friesian horses (pair) at Neddbury Pleasant Hill Stop
Warning: void convoi_t::hat_gehalten(halthandle_t halt):    Arrival time in the future for (4539) Friesian horses (pair) at Stokbourne Spinner's cottage Stop
Warning: haltestelle_t::liefere_an():    7 Passengers delivered to Tannacaber Village Railway Station were intended for a building that has been deleted.
Warning: void convoi_t::hat_gehalten(halthandle_t halt):    Arrival time in the future for (9359) IC "Iron Horse" 1831 stock at Kingserpool Barns Railway Station
Warning: void convoi_t::hat_gehalten(halthandle_t halt):    Arrival time in the future for (9684) Yorkshire coach horses (pair) at Hayford Bassett Apothecary dock
Warning: sint64 convoi_t::calc_revenue:    Average speed (19) for (7951) Yorkshire coach horses (pair) exceeded maximum speed (18); falling back to overall average
Warning: sint64 convoi_t::calc_revenue:    Average speed (19) for (7951) Yorkshire coach horses (pair) exceeded maximum speed (18); falling back to overall average
Warning: haltestelle_t::liefere_an():    5 Passengers delivered to Hayford Victoria East were intended for a building that has been deleted.
Warning: void convoi_t::hat_gehalten(halthandle_t halt):    Arrival time in the future for (10237) IC "Iron Horse" 1839 stock at Covhill Street Railway Station
Warning: sint64 convoi_t::calc_revenue:    Average speed (31) for (10008) Fly-boat horses exceeded maximum speed (18); falling back to overall average
Warning: void convoi_t::hat_gehalten(halthandle_t halt):    Arrival time in the future for (6331) Shire horses (pair) at Carneggy Lane Stop
Warning: nwc_tool_t::rdwr:    rdwr id=8 client=2 plnr=3 pos=4052,182,4 tool_id=4100 defpar=83 #all down slope init=0 flags=0
Warning: void convoi_t::hat_gehalten(halthandle_t halt):    Arrival time in the future for (1447) Friesian horses (four-in-hand) with short stage coach at Zenlyn King George Street Stop
Warning: sint64 convoi_t::calc_revenue:    Average speed (17) for (1018) Friesian horses (six-in-hand) with rigid stage coach exceeded maximum speed (12); falling back to overall average
Warning: sint64 convoi_t::calc_revenue:    Average speed (17) for (1018) Friesian horses (six-in-hand) with rigid stage coach exceeded maximum speed (12); falling back to overall average
Warning: haltestelle_t::liefere_an():    7 Passengers delivered to Thirlburn Dock were intended for a building that has been deleted.
Warning: void convoi_t::laden():    (7534) Post boy trying to load at Sherhill St Patrick's Road Inn when not at a halt; rerouting
Warning: haltestelle_t::liefere_an():    4 Passengers delivered to Stronbreck Trinity College Railway Station were intended for a building that has been deleted.
Warning: void convoi_t::hat_gehalten(halthandle_t halt):    Arrival time in the future for (6534) Yorkshire coach horses (pair) at Alnington Street Stop
Warning: void convoi_t::hat_gehalten(halthandle_t halt):    Arrival time in the future for (5288) Friesian horses (four-in-hand) with braked mail coach at Carneggy Market Stop
Warning: nwc_tool_t::rdwr:    rdwr id=8 client=2 plnr=3 pos=4052,182,4 tool_id=4115 defpar=StagingPost init=0 flags=0
Warning: void convoi_t::hat_gehalten(halthandle_t halt):    Arrival time in the future for (8684) Friesian horses (pair) at Norburn dock
Warning: sint64 convoi_t::calc_revenue:    Average speed (14) for (4627) Friesian horses (pair) exceeded maximum speed (12); falling back to overall average
Warning: void convoi_t::hat_gehalten(halthandle_t halt):    Arrival time in the future for (5497) Cleveland bay horses (pair) at Thealworth Gate Stop
Warning: void convoi_t::hat_gehalten(halthandle_t halt):    Arrival time in the future for (4442) Short stage coach at Pewton Coal merchant Stop
Warning: nwc_tool_t::rdwr:    rdwr id=8 client=0 plnr=8 pos=2284,811,3 tool_id=8218 defpar=b,876,1678,0,8676,0 init=1 flags=0
Warning: nwc_tool_t::rdwr:    rdwr id=8 client=3 plnr=8 pos=2284,811,3 tool_id=8218 defpar=b,876,1678,0,8676,0 init=1 flags=0
Warning: sint64 convoi_t::calc_revenue:    Average speed (21) for (8033) Yorkshire coach horses (pair) exceeded maximum speed (18); falling back to overall average
Warning: void convoi_t::hat_gehalten(halthandle_t halt):    Arrival time in the future for (4220) Friesian horses (pair) at Finerminster Piccadilly Stop
Warning: void convoi_t::hat_gehalten(halthandle_t halt):    Arrival time in the future for (905) Friesian horses (six-in-hand) with rigid stage coach at Pollveor East Bank Stop
ERROR: float32e8_t::operator / (const float32e8_t & x) const:    Division by zero in: 2255.5295 / 0
For help with this error or to file a bug report please see the Simutrans forum:
https://forum.simutrans.com
ERROR: float32e8_t::operator / (const float32e8_t & x) const:    Division by zero in: 36000 / 0
For help with this error or to file a bug report please see the Simutrans forum:
https://forum.simutrans.com
Warning: haltestelle_t::liefere_an():    3 Passengers delivered to Tannacaber Corner Railway Station were intended for a building that has been deleted.
Warning: void convoi_t::hat_gehalten(halthandle_t halt):    Arrival time in the future for (10065) Clydesdale horses (pair) with small horse omnibus at Safle Tynydd Y Llan Ioan Sant
Warning: haltestelle_t::liefere_an():    5 Passengers delivered to Kingserpool Broadway dock were intended for a building that has been deleted.
Warning: nwc_tool_t::rdwr:    rdwr id=8 client=0 plnr=8 pos=2284,811,3 tool_id=8216 defpar=f,9521 init=1 flags=0
Warning: nwc_tool_t::rdwr:    rdwr id=8 client=3 plnr=8 pos=2284,811,3 tool_id=8216 defpar=f,9521 init=1 flags=0
Warning: sint64 convoi_t::calc_revenue:    Average speed (19) for (1419) Fly-boat horses exceeded maximum speed (18); falling back to overall average
Warning: sint64 convoi_t::calc_revenue:    Average speed (19) for (1419) Fly-boat horses exceeded maximum speed (18); falling back to overall average
Warning: sint64 convoi_t::calc_revenue:    Average speed (19) for (1419) Fly-boat horses exceeded maximum speed (18); falling back to overall average
Warning: void convoi_t::hat_gehalten(halthandle_t halt):    Arrival time in the future for (5757) Irish draught horses (pair) at Cookport Cooper Stop
Warning: haltestelle_t::liefere_an():    6 Passengers delivered to Hayford Bassett Tuffington Park Stop were intended for a building that has been deleted.
Warning: nwc_tool_t::rdwr:    rdwr id=8 client=2 plnr=3 pos=4052,182,4 tool_id=4115 defpar=StagingInn init=0 flags=0
Warning: void convoi_t::hat_gehalten(halthandle_t halt):    Arrival time in the future for (2099) Boat horse with market narrowboat at Zenlyn Bridge XX Quay
Warning: nwc_tool_t::rdwr:    rdwr id=8 client=0 plnr=8 pos=2284,811,3 tool_id=8216 defpar=g,9521,1,0,0,0,1|3|1032,1631,0,0,0,0,-1,0|1110,1695,0,0,0,0,-1,0| init=1 flags=0
Warning: nwc_tool_t::rdwr:    rdwr id=8 client=3 plnr=8 pos=2284,811,3 tool_id=8216 defpar=g,9521,1,0,0,0,1|3|1032,1631,0,0,0,0,-1,0|1110,1695,0,0,0,0,-1,0| init=1 flags=0
Warning: karte_t:::do_network_world_command:    disconnecting due to checklist mismatch:
server=[ss=288499 st=24041 nfc=7 rand=2126688056 halt=3952 line=1025 cnvy=8193
    ssr=1221388209,0,1221388209,1221388209,2126688056,2126688056,2126688056,0
    str=2979526732,2979526732,2979526732,2979526732,2979526732,2979526732,1545239459,1545239459,1545239459,1545239459,1545239459,1545239459,1545239459,1545239459,1545239459,124099349
    exr=124099349,2040328237,2040328237,0,0,0,0,0
    sums=1016167,1070413991,74969,88151,6,0,0,0,722,46]
client=[ss=288499 st=24041 nfc=7 rand=2126688056 halt=3952 line=1025 cnvy=8193
    ssr=1221388209,0,1221388209,1221388209,2126688056,2126688056,2126688056,0
    str=2979526732,2979526732,2979526732,2979526732,2979526732,2979526732,1545239459,1545239459,1545239459,1545239459,1545239459,1545239459,1545239459,1545239459,1545239459,124099349
    exr=124099349,2040328237,2040328237,0,0,0,0,0
    sums=1016167,1070413991,74969,88151,6,0,0,0,722,45]

Warning: karte_t::network_disconnect():    Lost synchronisation with server. Random flags: 0
Warning: nwc_routesearch_t::reset:    all static variables are reset
Warning: zstd_file_rdwr_stream_t::zstd_file_rdwr_stream_t:    Cannot set workers: Unsupported parameter
Warning: nwc_routesearch_t::reset:    all static variables are reset

[zook2]

And an immediate desynch.: I joined ~21:30 GMT, with one other player being online, then after loading the map the game was immediately saved (I kicked him out and he rejoined?), then upon map load I desynched.

...
ERROR: tool_build_tunnel_t::tool_build_tunnel_t():   Tunnel builder object could not be retrieved; using default tunnel waytype (road), but this may cause errors
For help with this error or to file a bug report please see the Simutrans forum:
https://forum.simutrans.com
Warning: obj_reader_t::resolve_xrefs():   cannot resolve 'GOOD-bulk'
Warning: tool_t::read_menu():   toolbar[11][5]: replaced way-builder(id=14) with default param=cityroad by cityroad builder(id=36)
Warning: tabfile_t::read:   No data in "<<<<<<< HEAD"
Warning: midi_init():   can't open file 'C:\Users\MK Löhne\Downloads\Simutrans-Extended-Complete\simutrans\Pak128.Britain-Ex/music\music.tab' for reading.
Warning: midi_init():   can't open file 'C:\Users\MK Löhne\Documents\Simutrans\music\music.tab' for reading.
Warning: karte_t::load:   File version: 120004, Extended version: 12, Extended revision: 21
Warning: karte_t::load():   loaded savegame from 4/1945, next month=146800640, ticks=142606446 (per month=1<<22)
Warning: nwc_routesearch_t::reset:   all static variables are reset
Warning: nwc_routesearch_t::reset:   all static variables are reset
Warning: nwc_routesearch_t::rdwr:   rdwr limits=(1024, 35392, 24438, 11289728, 212352) apply_limits=1
Warning: nwc_routesearch_t::do_command:   apply limits=(1024, 35392, 24438, 11289728, 212352)
Warning: karte_t::load:   File version: 120007, Extended version: 14, Extended revision: 45
Warning: karte_t::load():   loaded savegame from 9/1840, next month=276824064, ticks=275639108 (per month=1<<22)
Warning: nwc_ready_t::execute:   set sync_step=416729 where map_counter=48334285
Warning: karte_t::network_game_set_pause:   steps=34727 sync_steps=416729 pause=0
Warning: nwc_tool_t::rdwr:   rdwr id=8 client=0 plnr=255 pos=koord3d invalid tool_id=8224 defpar=32768,Welcome, Zook! init=1 flags=0
Warning: nwc_sync_t::do_command:   sync_steps 416730
Warning: zstd_file_rdwr_stream_t::zstd_file_rdwr_stream_t:   Cannot set workers: Unsupported parameter
Warning: karte_t::load:   File version: 120007, Extended version: 14, Extended revision: 45
Warning: karte_t::load():   loaded savegame from 9/1840, next month=276824064, ticks=275639208 (per month=1<<22)
Warning: karte_t::network_game_set_pause:   steps=34727 sync_steps=416730 pause=1
Warning: nwc_ready_t::execute:   set sync_step=416730 where map_counter=48409433
Warning: karte_t::network_game_set_pause:   steps=34727 sync_steps=416730 pause=0
Warning: nwc_tool_t::rdwr:   rdwr id=8 client=0 plnr=255 pos=koord3d invalid tool_id=8224 defpar=32768,Welcome, Client no. 1! init=1 flags=0
Warning: network_world_command_t::execute:   wanted to execute( from another world (mpc=48437730)
Warning: network_world_command_t::execute:   wanted to execute(9) from another world (mpc=48437730)
Warning: network_world_command_t::execute:   wanted to execute(9) from another world (mpc=48437730)
Warning: network_world_command_t::execute:   wanted to execute(9) from another world (mpc=48437730)
Warning: network_world_command_t::execute:   wanted to execute(9) from another world (mpc=48437730)
Warning: nwc_sync_t::do_command:   sync_steps 416731
Warning: zstd_file_rdwr_stream_t::zstd_file_rdwr_stream_t:   Cannot set workers: Unsupported parameter
Warning: karte_t::load:   File version: 120007, Extended version: 14, Extended revision: 45
Warning: karte_t::load():   loaded savegame from 9/1840, next month=276824064, ticks=275639308 (per month=1<<22)
Warning: karte_t::network_game_set_pause:   steps=34727 sync_steps=416731 pause=1
Warning: nwc_tool_t::rdwr:   rdwr id=8 client=0 plnr=255 pos=koord3d invalid tool_id=8224 defpar=16384,Now 3 clients connected. init=1 flags=0
Warning: NWC_CHECK:   time difference to server 1000
Warning: NWC_CHECK:   time difference to server 1100
Warning: NWC_CHECK:   time difference to server 1200
Warning: NWC_CHECK:   time difference to server 1300
Warning: NWC_CHECK:   time difference to server 1400
Warning: NWC_CHECK:   time difference to server 1500
Warning: NWC_CHECK:   time difference to server 1600
Warning: NWC_CHECK:   time difference to server 1700
Warning: NWC_CHECK:   time difference to server 1800
Warning: NWC_CHECK:   time difference to server 1900
Warning: NWC_CHECK:   time difference to server 2000
Warning: NWC_CHECK:   time difference to server 2100
Warning: NWC_CHECK:   time difference to server 2200
Warning: NWC_CHECK:   time difference to server 2300
Warning: NWC_CHECK:   time difference to server 2400
Warning: NWC_CHECK:   time difference to server 2500
Warning: nwc_tool_t::rdwr:   rdwr id=8 client=0 plnr=255 pos=koord3d invalid tool_id=8224 defpar=32768,Client no. 1 has left. init=1 flags=0
Warning: nwc_tool_t::rdwr:   rdwr id=8 client=0 plnr=255 pos=koord3d invalid tool_id=8224 defpar=16384,Now 2 clients connected. init=1 flags=0
Warning: NWC_CHECK:   time difference to server 2600
Warning: NWC_CHECK:   time difference to server 2700
Warning: NWC_CHECK:   time difference to server 2800
Warning: NWC_CHECK:   time difference to server 2900
Warning: NWC_CHECK:   time difference to server 3000
Warning: NWC_CHECK:   time difference to server 3100
Warning: NWC_CHECK:   time difference to server 3200
Warning: NWC_CHECK:   time difference to server 3300
Warning: NWC_CHECK:   time difference to server 3400
Warning: NWC_CHECK:   time difference to server 3500
Warning: NWC_CHECK:   time difference to server 3600

<snip>

Warning: NWC_CHECK:   time difference to server 33400
Warning: NWC_CHECK:   time difference to server 33500
Warning: nwc_ready_t::execute:   set sync_step=416731 where map_counter=48437730
Warning: karte_t::network_game_set_pause:   steps=34727 sync_steps=416731 pause=0
Warning: NWC_CHECK:   time difference to server 33600
Warning: NWC_CHECK:   time difference to server 33600
Warning: NWC_CHECK:   time difference to server 33600
Warning: NWC_CHECK:   time difference to server 33600
Warning: NWC_CHECK:   time difference to server 33600
Warning: sint64 convoi_t::calc_revenue:   Average speed (56) for (9228) Yorkshire coach horse exceeded maximum speed (18); falling back to overall average
Warning: sint64 convoi_t::calc_revenue:   Average speed (56) for (9228) Yorkshire coach horse exceeded maximum speed (18); falling back to overall average
Warning: sint64 convoi_t::calc_revenue:   Average speed (56) for (9228) Yorkshire coach horse exceeded maximum speed (18); falling back to overall average
Warning: sint64 convoi_t::calc_revenue:   Average speed (15) for (1761) Friesian horses (four-in-hand) with short stage coach exceeded maximum speed (12); falling back to overall average
Warning: sint64 convoi_t::calc_revenue:   Average speed (67) for (2478) Fly-boat horses exceeded maximum speed (18); falling back to overall average
Warning: sint64 convoi_t::calc_revenue:   Average speed (67) for (2478) Fly-boat horses exceeded maximum speed (18); falling back to overall average
Warning: sint64 convoi_t::calc_revenue:   Average speed (67) for (2478) Fly-boat horses exceeded maximum speed (18); falling back to overall average
Warning: NWC_CHECK:   time difference to server 33600
Warning: NWC_CHECK:   time difference to server 33600
Warning: NWC_CHECK:   time difference to server 33600
Warning: NWC_CHECK:   time difference to server 33600
Warning: NWC_CHECK:   time difference to server 33600
Warning: karte_t:::do_network_world_command:   disconnecting due to checklist mismatch:
server=[ss=416739 st=34728 nfc=3 rand=139503783 halt=3952 line=1025 cnvy=8193
   ssr=296161633,0,296161633,296161633,139503783,139503783,139503783,0
   str=1656216518,1656216518,1656216518,1656216518,1656216518,1656216518,95024530,95024530,95024530,95024530,95024530,95024530,95024530,95024530,95024530,2502182557
   exr=2502182557,2380493911,2380493911,0,0,0,0,0
   sums=1020345,1069082998,76453,83433,6,0,0,0,708,41]
client=[ss=416739 st=34728 nfc=3 rand=139503783 halt=3952 line=1025 cnvy=8193
   ssr=296161633,0,296161633,296161633,139503783,139503783,139503783,0
   str=1656216518,1656216518,1656216518,1656216518,1656216518,1656216518,95024530,95024530,95024530,95024530,95024530,95024530,95024530,95024530,95024530,2502182557
   exr=2502182557,2380493911,2380493911,0,0,0,0,0
   sums=1020345,1069082998,76453,83433,6,0,0,0,708,40]

Warning: karte_t::network_disconnect():   Lost synchronisation with server. Random flags: 0
Warning: nwc_routesearch_t::reset:   all static variables are reset
Warning: nwc_routesearch_t::reset:   all static variables are reset
Warning: zstd_file_rdwr_stream_t::zstd_file_rdwr_stream_t:   Cannot set workers: Unsupported parameter
Warning: nwc_routesearch_t::reset:   all static variables are reset

[Matthew]

I know several of us have been feeling that we desynch more often when playing alongside some players than some other players. This might not be a real phenomenon at all: I guess humans always want to blame our problems on somebody else (me included!). But I guess the only way to find out if this is an issue is to gather some data.

So I have made a simple spreadsheet that Bridgewater-Brunel players could edit to report their experiences when playing alongside each other if they want to. For simplicity, it only deals with pairs.



Maybe people more experienced than me will see some flaws in this idea, so please speak up if you see them!

This exercise is almost less useful than the collecting the checklist data (see the first post in this thread) and I hope this won't be a distraction from that.

Just because we often desynch with another player doesn't mean either person is doing something wrong. It could be something about the OS, the latency, how much cache they have, all kinds of things most of us can't change easily.

Warning: NWC_CHECK:   time difference to server 33600

This suggests that your PC is not fast enough to keep up with the server. This is the situation that I was in last year, and I was disappointed to see it appear. However, James did slow the server down to help me, so I am surprised that it is still too fast for others.

[zook2]

Nonetheless, it is worthwhile to try to remedy these if possible, especially the most common types. The most common types so far seem to be convoy movement based losses of synchronisation (debug sums) and halt based losses of synchronisation (rands[23]).

As to the latter, the code in the haltestelle_t::step() function most likely to show a divergence of random numbers is check_transferring_cargoes, which, when dealing with passengers, invokes the RNG by generating local pedestrians whenever passengers are released from their transferring state.

We already have a system to check part f this, being debug sums 6 and 7 for checking the number of transferring cargoes before and after the passenger and mail generation have run.

May I suggest that future loss of synchronisation logging should explicitly check whether there is any divergence in debug sums 6 and 7 when recording a loss of synchronisation at rands[23]?

What if the server switched pedestrians off completely to see if that makes a difference? Personally I'd have done that already client-side if it were possible (which apparently it isn't), as they consume resources and add nothing for me.

Apart from that: Surely a modern computer can subtract large numbers from other large numbers. Could the debug code be modified as to automagically print the offending convoy's ID? I'm glad to help, if only out of self-interest, but doing arithmetics is just asking too much.

[zook2]

Maybe people more experienced than me will see some flaws in this idea, so please speak up if you see them!

I'm on glorious Windows, and Huitsi is either a demon or a witch (we know that because it's been said many times).

This suggests that your PC is not fast enough to keep up with the server.

That's an exception in the logs I've looked at so far, usually it never gets beyond 2000 or so. I have a dual-core with 3.something Ghz in turbo mode and 8 GB RAM. I've had many hours of uninterrupted gameplay over the weeks (with lag getting worse if more than one other player is present), but recently the desynchs are getting bad. It could be the number of convoys, which has grown steadily. I remember 5000+ some deacdes ago, now we're probably at >8000. The most obvious candidate seems to be railroads, though, because they've multiplied exponentially over the past 15 game-years, and I'd say that's when the current trouble began. How many desynchs did you get in 1790?

[Ranran]

What if the server switched pedestrians off completely to see if that makes a difference?

Unfortunately, Extended cannot exterminate pedestrians by change its setting. The display option can reduce pedestrian spawning a bit.
Especially, "Pedestrians at stop" option is almost broken and makes little sense.
These seems to have changed that way over 10 years ago, but I don't know why.

Certainly removing pedestrians will greatly reduce the burden on your computer. Especially large maps and fast forwards mode.
But we need to change the code to completely remove the pedestrian. So the easiest change is to remove pedestrians.pak from pakset...

[zook2]

Best Simutrans night I had in weeks. No other player, no desynch. Then I deleted a bridge and lost synch immediately:

Warning: void convoi_t::laden():    (3674) Shire horse (five-in-hand) with goods stage wagon trying to load at Maesffordd Cei Y Llyn when not at a halt; rerouting
Warning: sint64 convoi_t::calc_revenue:    Average speed (28) for (10036) Fly-boat horses exceeded maximum speed (18); falling back to overall average
Warning: sint64 convoi_t::calc_revenue:    Average speed (28) for (10036) Fly-boat horses exceeded maximum speed (18); falling back to overall average
Warning: nwc_tool_t::rdwr:    rdwr id=8 client=0 plnr=8 pos=668,1694,5 tool_id=4110 defpar=cobblestone_road init=0 flags=0
Warning: nwc_tool_t::rdwr:    rdwr id=8 client=3 plnr=8 pos=668,1694,5 tool_id=4110 defpar=cobblestone_road init=0 flags=0
Warning: sint64 convoi_t::calc_revenue:    Average speed (23) for (10144) Fly-boat horses exceeded maximum speed (18); falling back to overall average
Warning: sint64 convoi_t::calc_revenue:    Average speed (23) for (10144) Fly-boat horses exceeded maximum speed (18); falling back to overall average
Warning: void convoi_t::hat_gehalten(halthandle_t halt):    Arrival time in the future for (4382) Friesian horses (pair) at Norburn MacCallum Street Stop
Warning: void convoi_t::hat_gehalten(halthandle_t halt):    Arrival time in the future for (3626) Cleveland bay horses (pair) at Pewton Gate Stop
Warning: void convoi_t::hat_gehalten(halthandle_t halt):    Arrival time in the future for (1472) Friesian horses (six-in-hand) with rigid stage coach at Wulerpool Stockerbourne Street Inn
Warning: sint64 convoi_t::calc_revenue:    Average speed (15) for (6407) Shire horses (pair) exceeded maximum speed (10); falling back to overall average
Warning: sint64 convoi_t::calc_revenue:    Average speed (15) for (6407) Shire horses (pair) exceeded maximum speed (10); falling back to overall average
Warning: sint64 convoi_t::calc_revenue:    Average speed (15) for (6407) Shire horses (pair) exceeded maximum speed (10); falling back to overall average
Warning: haltestelle_t::liefere_an():    3 Passengers delivered to Wallow Gate Railway Station were intended for a building that has been deleted.
Warning: nwc_tool_t::rdwr:    rdwr id=8 client=0 plnr=8 pos=668,1699,5 tool_id=4110 defpar=cobblestone_road init=0 flags=0
Warning: nwc_tool_t::rdwr:    rdwr id=8 client=3 plnr=8 pos=668,1699,5 tool_id=4110 defpar=cobblestone_road init=0 flags=0
Warning: void convoi_t::hat_gehalten(halthandle_t halt):    Arrival time in the future for (9579) Yorkshire coach horses (pair) at Norburn Prince Dennis the Doubtful Dock
Warning: haltestelle_t::liefere_an():    6 Passengers delivered to Tannacaber Town Railway Station were intended for a building that has been deleted.
Warning: void convoi_t::hat_gehalten(halthandle_t halt):    Arrival time in the future for (7356) Shire horses (pair) at Finerminster Princess Loreley Dock
Warning: nwc_tool_t::rdwr:    rdwr id=8 client=0 plnr=8 pos=668,1698,5 tool_id=4111 defpar=BrickViaductEarlyRoad init=0 flags=0
Warning: nwc_tool_t::rdwr:    rdwr id=8 client=3 plnr=8 pos=668,1698,5 tool_id=4111 defpar=BrickViaductEarlyRoad init=0 flags=0
Warning: void convoi_t::hat_gehalten(halthandle_t halt):    Arrival time in the future for (5279) Cleveland bay horses (six-in-hand) with sprung stage coach at Safle Dwycawl Trindod Sanctaidd
Warning: nwc_tool_t::rdwr:    rdwr id=8 client=0 plnr=8 pos=666,1695,5 tool_id=4097 defpar=(null) init=0 flags=0
Warning: nwc_tool_t::rdwr:    rdwr id=8 client=3 plnr=8 pos=666,1695,5 tool_id=4097 defpar=(null) init=0 flags=0
Warning: nwc_tool_t::rdwr:    rdwr id=8 client=0 plnr=8 pos=666,1694,5 tool_id=4097 defpar=(null) init=0 flags=0
Warning: nwc_tool_t::rdwr:    rdwr id=8 client=0 plnr=8 pos=665,1694,5 tool_id=4097 defpar=(null) init=0 flags=0
Warning: nwc_tool_t::rdwr:    rdwr id=8 client=0 plnr=8 pos=666,1699,5 tool_id=4097 defpar=(null) init=0 flags=0
Warning: network_receive_data:    error 10054 while receiving from [1864]
Warning: karte_t::process_network_commands:    lost connection to server
Warning: karte_t::network_disconnect():    Lost synchronisation with server. Random flags: 0
Warning: nwc_routesearch_t::reset:    all static variables are reset
Warning: zstd_file_rdwr_stream_t::zstd_file_rdwr_stream_t:    Cannot set workers: Unsupported parameter

[zook2]

Needless to say, it crashed the server.

[zook2]

I think I was just sending a "no Route/too complex" ship to another waypoint when I crashed:

Warning: sint64 convoi_t::calc_revenue:   Average speed (33) for (9411) Fly-boat horses exceeded maximum speed (18); falling back to overall average
Warning: void convoi_t::hat_gehalten(halthandle_t halt):   Arrival time in the future for (616) Friesian horses  (four-in-hand) with short stage coach at Sherhill Town Hall Stop
Warning: nwc_tool_t::rdwr:   rdwr id=8 client=0 plnr=8 pos=4231,1469,0 tool_id=8216 defpar=f,10547 init=1 flags=0
Warning: nwc_tool_t::rdwr:   rdwr id=8 client=2 plnr=8 pos=4231,1469,0 tool_id=8216 defpar=f,10547 init=1 flags=0
ERROR: float32e8_t::operator / (const float32e8_t & x) const:   Division by zero in: 14709.975 / 0
For help with this error or to file a bug report please see the Simutrans forum:
https://forum.simutrans.com
ERROR: float32e8_t::operator / (const float32e8_t & x) const:   Division by zero in: 400000 / 0
For help with this error or to file a bug report please see the Simutrans forum:
https://forum.simutrans.com
ERROR: float32e8_t::operator / (const float32e8_t & x) const:   Division by zero in: 5883.98999 / 0
For help with this error or to file a bug report please see the Simutrans forum:
https://forum.simutrans.com
ERROR: float32e8_t::operator / (const float32e8_t & x) const:   Division by zero in: 400000 / 0
For help with this error or to file a bug report please see the Simutrans forum:
https://forum.simutrans.com
Warning: sint64 convoi_t::calc_revenue:   Average speed (19) for (4451) Friesian horses (pair) exceeded maximum speed (12); falling back to overall average
Warning: sint64 convoi_t::calc_revenue:   Average speed (19) for (4451) Friesian horses (pair) exceeded maximum speed (12); falling back to overall average
Warning: sint64 convoi_t::calc_revenue:   Average speed (13) for (4451) Friesian horses (pair) exceeded maximum speed (12); falling back to overall average
ERROR: float32e8_t::operator / (const float32e8_t & x) const:   Division by zero in: 14709.975 / 0
<snip>

https://forum.simutrans.com
ERROR: float32e8_t::operator / (const float32e8_t & x) const:   Division by zero in: 14709.975 / 0
For help with this error or to file a bug report please see the Simutrans forum:
https://forum.simutrans.com
ERROR: float32e8_t::operator / (const float32e8_t & x) const:   Division by zero in: 400000 / 0
For help with this error or to file a bug report please see the Simutrans forum:
https://forum.simutrans.com
ERROR: float32e8_t::operator / (const float32e8_t & x) const:   Division by zero in: 5883.98999 / 0
For help with this error or to file a bug report please see the Simutrans forum:
https://forum.simutrans.com
ERROR: float32e8_t::operator / (const float32e8_t & x) const:   Division by zero in: 400000 / 0
For help with this error or to file a bug report please see the Simutrans forum:
https://forum.simutrans.com
ERROR: float32e8_t::operator / (const float32e8_t & x) const:   Division by zero in: 14709.975 / 0
For help with this error or to file a bug report please see the Simutrans forum:
https://forum.simutrans.com
ERROR: float32e8_t::operator / (const float32e8_t & x) const:   Division by zero in: 400000 / 0
For help with this error or to file a bug report please see the Simutrans forum:
https://forum.simutrans.com
ERROR: float32e8_t::operator / (const float32e8_t & x) const:   Division by zero in: 5883.98999 / 0
For help with this error or to file a bug report please see the Simutrans forum:
https://forum.simutrans.com
ERROR: float32e8_t::operator / (const float32e8_t & x) const:   Division by zero in: 400000 / 0
For help with this error or to file a bug report please see the Simutrans forum:
https://forum.simutrans.com
Warning: void convoi_t::hat_gehalten(halthandle_t halt):   Arrival time in the future for (3828) Friesian horses (four-in-hand) with strap stage coach at Zenlyn Lilac Road Stop
Warning: void convoi_t::hat_gehalten(halthandle_t halt):   Arrival time in the future for (9352) Shire horses (pair) at Wallow River Markets & DIY
Warning: void convoi_t::laden():   (6473) Yorkshire coach horses (six-in-hand) with braked mail coach trying to load at Gwesty'r Dwycawl Abbey when not at a halt; rerouting
Warning: nwc_tool_t::rdwr:   rdwr id=8 client=0 plnr=8 pos=4226,1471,1 tool_id=8216 defpar=V,10547 init=1 flags=0
Warning: nwc_tool_t::rdwr:   rdwr id=8 client=2 plnr=8 pos=4226,1471,1 tool_id=8216 defpar=V,10547 init=1 flags=0
Warning: void convoi_t::hat_gehalten(halthandle_t halt):   Arrival time in the future for (7679) Shire horses (pair) at Fen Sixdale Hardware & DIY
Warning: sint64 convoi_t::calc_revenue:   Average speed (19) for (8461) Yorkshire coach horses (pair) exceeded maximum speed (18); falling back to overall average
Warning: void convoi_t::hat_gehalten(halthandle_t halt):   Arrival time in the future for (3310) Hackney horses (pair) at Pewton Monument Stop
Warning: nwc_routesearch_t::rdwr:   rdwr limits=(1024, 98304, 34880, 16777216, 256) apply_limits=0
Warning: karte_t::interactive:   nwc_routesearch_t object created and sent to server: sync_step=59977 map_counter=8671108 limits=(1024, 98304, 34880, 16777216, 256)
Warning: void convoi_t::hat_gehalten(halthandle_t halt):   Arrival time in the future for (3795) Friesian horses (four-in-hand) with strap stage coach at Zenlyn County Hall Stop
Warning: nwc_routesearch_t::rdwr:   rdwr limits=(1024, 98304, 34880, 5558528, 256) apply_limits=0
Warning: karte_t::interactive:   nwc_routesearch_t object created and sent to server: sync_step=59990 map_counter=8671108 limits=(1024, 98304, 34880, 5558528, 256)
Warning: void convoi_t::hat_gehalten(halthandle_t halt):   Arrival time in the future for (10052) Fly-boat horses at Kingserpool Bridge dock
Warning: nwc_routesearch_t::rdwr:   rdwr limits=(1024, 98304, 34880, 5558528, 212672) apply_limits=0
Warning: karte_t::interactive:   nwc_routesearch_t object created and sent to server: sync_step=60000 map_counter=8671108 limits=(1024, 98304, 34880, 5558528, 212672)
Warning: void convoi_t::laden():   (6473) Yorkshire coach horses (six-in-hand) with braked mail coach trying to load at Gwesty'r Dwycawl Abbey when not at a halt; rerouting
Warning: void convoi_t::laden():   (6201) Irish draught horses (pair) trying to load at Moel-y-Groes Dairy & Pub when not at a halt; rerouting
Warning: void convoi_t::hat_gehalten(halthandle_t halt):   Arrival time in the future for (3213) Friesian horses (four-in-hand) with strap stage coach at Zenlyn Broadway Inn
Warning: void convoi_t::hat_gehalten(halthandle_t halt):   Arrival time in the future for (4133) Friesian horses (four-in-hand) with short stage coach at Safle Dwycawl Trindod Sanctaidd
Warning: nwc_routesearch_t::rdwr:   rdwr limits=(1024, 26584, 22144, 5558528, 212672) apply_limits=1
Warning: nwc_routesearch_t::execute:   to be applied: limits=(1024, 26584, 22144, 5558528, 212672)
Warning: nwc_routesearch_t::execute:   add to world command queue (sync step: command=60057 world=60052)
Warning: nwc_routesearch_t::do_command:   apply limits=(1024, 26584, 22144, 5558528, 212672)
Warning: sint64 convoi_t::calc_revenue:   Average speed (26) for (8469) Yorkshire coach horses (pair) exceeded maximum speed (18); falling back to overall average
Warning: sint64 convoi_t::calc_revenue:   Average speed (20) for (8469) Yorkshire coach horses (pair) exceeded maximum speed (18); falling back to overall average
Warning: sint64 convoi_t::calc_revenue:   Average speed (20) for (8469) Yorkshire coach horses (pair) exceeded maximum speed (18); falling back to overall average
Warning: sint64 convoi_t::calc_revenue:   Average speed (20) for (8469) Yorkshire coach horses (pair) exceeded maximum speed (18); falling back to overall average
Warning: sint64 convoi_t::calc_revenue:   Average speed (26) for (8469) Yorkshire coach horses (pair) exceeded maximum speed (18); falling back to overall average
Warning: sint64 convoi_t::calc_revenue:   Average speed (26) for (8469) Yorkshire coach horses (pair) exceeded maximum speed (18); falling back to overall average
Warning: void convoi_t::hat_gehalten(halthandle_t halt):   Arrival time in the future for (8342) Yorkshire coach horses (pair) at Pewton Town Stop
Warning: void convoi_t::hat_gehalten(halthandle_t halt):   Arrival time in the future for (5416) Cleveland bay horses (six-in-hand) with mail coach at Safle Neuadd Plwyf Y Maesffordd | Maesffordd Parish Hall Stop
Warning: void convoi_t::hat_gehalten(halthandle_t halt):   Arrival time in the future for (8502) Friesian horses (four-in-hand) with short stage coach at Sherhill Town Hall Stop
Warning: void convoi_t::hat_gehalten(halthandle_t halt):   Arrival time in the future for (4763) Friesian horses (pair) at Neddbury Jones Gardens Stop
Warning: void convoi_t::hat_gehalten(halthandle_t halt):   Arrival time in the future for (8624) Yorkshire coach horses (pair) at Wallow Hill Stop
Warning: void convoi_t::hat_gehalten(halthandle_t halt):   Arrival time in the future for (3940) Friesian horses (four-in-hand) with short stage coach at Moel-y-Groes Parish Hall Stop
Warning: sint64 convoi_t::calc_revenue:   Average speed (34) for (9861) Fly-boat horses exceeded maximum speed (18); falling back to overall average
Warning: sint64 convoi_t::calc_revenue:   Average speed (34) for (9861) Fly-boat horses exceeded maximum speed (18); falling back to overall average
Warning: sint64 convoi_t::calc_revenue:   Average speed (34) for (9861) Fly-boat horses exceeded maximum speed (18); falling back to overall average
Warning: void convoi_t::hat_gehalten(halthandle_t halt):   Arrival time in the future for (939) Friesian horses (six-in-hand) with rigid stage coach at Pollveor East Bank Stop
Warning: void convoi_t::hat_gehalten(halthandle_t halt):   Arrival time in the future for (7249) Friesian horses (four-in-hand) with short stagecoach at Safle Dwycawl Trindod Sanctaidd
Warning: void convoi_t::hat_gehalten(halthandle_t halt):   Arrival time in the future for (4393) Friesian horses (pair) at Norburn Balgownie Street Stop
Warning: void convoi_t::hat_gehalten(halthandle_t halt):   Arrival time in the future for (9644) Friesian horses (pair) at Norburn dock
Warning: nwc_routesearch_t::rdwr:   rdwr limits=(1024, 98304, 18680, 5558528, 212672) apply_limits=0
Warning: karte_t::interactive:   nwc_routesearch_t object created and sent to server: sync_step=60194 map_counter=8671108 limits=(1024, 98304, 18680, 5558528, 212672)
Warning: sint64 convoi_t::calc_revenue:   Average speed (17) for (6563) Cleveland bay horses (six-in-hand) with braked stage coach exceeded maximum speed (14); falling back to overall average
Warning: nwc_routesearch_t::rdwr:   rdwr limits=(1024, 98304, 18680, 1660672, 212672) apply_limits=0
Warning: karte_t::interactive:   nwc_routesearch_t object created and sent to server: sync_step=60205 map_counter=8671108 limits=(1024, 98304, 18680, 1660672, 212672)
Warning: void convoi_t::hat_gehalten(halthandle_t halt):   Arrival time in the future for (10522) Tayleur express engine 2-2-2 at Finerminster Princess Loreley Dock
Warning: void convoi_t::hat_gehalten(halthandle_t halt):   Arrival time in the future for (9454) Friesian horses (pair) at Norburn Balgownie Street Stop
Warning: void convoi_t::hat_gehalten(halthandle_t halt):   Arrival time in the future for (5520) Friesian horses (four-in-hand) with short stage coach at Philron Dukesgate Stop
Warning: sint64 convoi_t::calc_revenue:   Average speed (18) for (4418) Short stage coach exceeded maximum speed (12); falling back to overall average
Warning: haltestelle_t::liefere_an():   6 Passengers delivered to Tannacaber Fields dock were intended for a building that has been deleted.
Warning: nwc_routesearch_t::rdwr:   rdwr limits=(1024, 35445, 18680, 1660672, 212672) apply_limits=0
Warning: karte_t::interactive:   nwc_routesearch_t object created and sent to server: sync_step=60252 map_counter=8671108 limits=(1024, 35445, 18680, 1660672, 212672)
Warning: void convoi_t::hat_gehalten(halthandle_t halt):   Arrival time in the future for (3838) Friesian horses (four-in-hand) with short stage coach at Zenlyn Canal Street Quay
Warning: nwc_routesearch_t::rdwr:   rdwr limits=(1024, 35445, 34278, 1660672, 212672) apply_limits=0
Warning: karte_t::interactive:   nwc_routesearch_t object created and sent to server: sync_step=60265 map_counter=8671108 limits=(1024, 35445, 34278, 1660672, 212672)
Warning: void convoi_t::hat_gehalten(halthandle_t halt):   Arrival time in the future for (4263) Short stage coach at Pewton Town Stop
Warning: void convoi_t::hat_gehalten(halthandle_t halt):   Arrival time in the future for (6396) Shire horses (pair) at Hayford Princess Victoria (Vicky) Railway Station
Warning: void convoi_t::hat_gehalten(halthandle_t halt):   Arrival time in the future for (10469) Fly-boat horses at Finerminster Town dock
Warning: void convoi_t::hat_gehalten(halthandle_t halt):   Arrival time in the future for (7376) Shire horses (pair) at Zenlyn Royal Railway Station of the Century
Warning: sint64 convoi_t::calc_revenue:   Average speed (12) for (1246) Norfolk wherry (passengers) exceeded maximum speed (10); falling back to overall average
Warning: nwc_routesearch_t::rdwr:   rdwr limits=(1024, 30381, 34278, 1660672, 212672) apply_limits=1
Warning: nwc_routesearch_t::execute:   to be applied: limits=(1024, 30381, 34278, 1660672, 212672)
Warning: nwc_routesearch_t::execute:   add to world command queue (sync step: command=60322 world=60316)
Warning: nwc_routesearch_t::do_command:   apply limits=(1024, 30381, 34278, 1660672, 212672)
Warning: void convoi_t::laden():   (5404) Yorkshire coach horses (six-in-hand) with braked mail coach trying to load at Moel-y-Groes Cambrian Dock when not at a halt; rerouting
Warning: void convoi_t::hat_gehalten(halthandle_t halt):   Arrival time in the future for (7151) Shire horses (pair) at Norburn Prince Dennis the Doubtful Dock
Warning: nwc_tool_t::rdwr:   rdwr id=8 client=0 plnr=8 pos=4239,1471,0 tool_id=8218 defpar=b,4231,1469,0,10550,0 init=1 flags=0
Warning: nwc_tool_t::rdwr:   rdwr id=8 client=2 plnr=8 pos=4239,1471,0 tool_id=8218 defpar=b,4231,1469,0,10550,0 init=1 flags=0
ERROR: float32e8_t::operator / (const float32e8_t & x) const:   Division by zero in: 14709.975 / 0
For help with this error or to file a bug report please see the Simutrans forum:
https://forum.simutrans.com
ERROR: float32e8_t::operator / (const float32e8_t & x) const:   Division by zero in: 400000 / 0
For help with this error or to file a bug report please see the Simutrans forum:
https://forum.simutrans.com
Warning: route_t::intern_calc_route():   Too many steps (1500000>=max 1500000) in route (too long/complex)

[jamespetts]

If we can get a reproduction case for the float3288_t divisions by zero, that would be helpful. I have no idea whether or not this relates to the losses of synchronisation, but it would certainly be helpful to try to fix this and see whether that assists.

[Matthew]

I have tried to join B-B several times since today's (2022-02-20) Nightly and reset. I desync as soon as the game unpauses.

I am using the latest B-B Nightly client (#36c9cd5) on Ubuntu 20.04.

Each time the checklist differences are debug_sums[5] ("Passengers/mail generated this step") and [7] ("Transferring cargoes after passenger generation"). For example:

   sums=761526,690114314,89800,111679,6,969,50834,50958,28,112
   sums=761526,690114314,89800,111679,6,971,50834,50961,28,112

BTW I noticed that some of the code for producing the checklists also changed yesterday. I don't understand all those changes, but I guess that makes it possible that the bug is in the checklist itself? I don't how plausible that is.

P.S. My client number incremented every time I tried to join. Is that expected? As far as I could see from the in-game interface and list.extended.simutrans.org, no other clients were connected. Probably a total red herring.

P.P.S. I could reproduce the desyncs on a Windows 10 VPS.

[jamespetts]

Confirmed reproducible with my Linux client. I think that this may be related to the "heavy mode" changes from yesterday, but I will have to undertake further testing to narrow down when this occurred.

[jamespetts]

Testing has produced some very odd results: I will consistently lose synchronisation with the server seconds after unpausing on both Bridgewater-Brunel and Stephenson-Siemens servers. However, running a client/server pair locally, no such issue arises, whether the server be a command line server or a graphical server. I have been able to remain connected for >20 minutes with a local client/server pair.

Edit: Further testing shows that downloading the binary compiled on the Bridgewater-Brunel server and running that locally, connecting a client to it locally, still does not reproduce the loss of synchronisation - this only seems to occur when client and server are on different computers.

[jamespetts]

I have now attempted testing running a server/client pair on two different physical computers on the same home network. Using demo.sve, I cannot reproduce the loss of synchronisation in this environment. Note that the other computer's Simutrans was built from source from the latest commits on the master branch of the Github repository.

[jamespetts]

I think that I have managed to narrow this down and solve the immediate problem, albeit I have not yet found where exactly in the code that this problem was manifested. Updating en.tab on the server (the base version, not the pakset version) to the latest version has allowed me to connect stably without losing synchronisation for >10 minutes. I encourage others to connect and to test this.

[Mariculous]

updated to latest nightly, doesn't seem to work.

[Ranran]

Is it possible to check the difference in the existence of all files such as en.tab?
In that case, the difference in font files and city namelist may be taken into consideration. The missing Chinese font has recently been revived in extended. So some people may not have it.

[jamespetts]

updated to latest nightly, doesn't seem to work.

Can I clarify - are you losing synchronisation the moment that you connect?

Is it possible to check the difference in the existence of all files such as en.tab?
In that case, the difference in font files and city namelist may be taken into consideration. The missing Chinese font has recently been revived in extended. So some people may not have it.

This is possible in theory, but very difficult in practice, as there are many files (e.g. config.default) which need to differ, and there is no straightforward interface for checking this automatically.

[Mariculous]

Can I clarify - are you losing synchronisation the moment that you connect?

Exactly.

Seems to be working now.

[prissi]

At least in standard, the city and stop names are provided by the servers, so different citylists should not matter. It it possible to play in Japanese and German together, while all ingame automatic names are in English. Local settings should not matter for servergames, unless there is a setting that was forgotten to be seved with the servergame and was instead added to the enviromnet.

[jamespetts]

Further testing shows that it is not any divergence in en.tab that causes losses of synchronisation: adding "Test 1" and "Test 2" strings to the bottom of my local en.tab and then connecting results in no loss of synchronisation.

Edit: Further testing shows that adding a single town name syllable locally does not lead to losses of synchronisation.

Edit 2: Further testing shows that adding a number of additional town name syllables locally does not lead to losses of synchronisation. This suggests that there is some specific part of the en.tab file difference in which causes loss of synchronisation.

Edit 3: In further testing, I have not been able to find any modification to my local en.tab that will cause losses of synchronisation with the server. The problem appears to be reproducible only in very particular circumstances. As such, I am discontinuing further investigations and noting this issue as dormant for the present. However, if anyone does manage to find the cause of this, that would be helpful.

[prissi]

The town name and everything else is generated in the game on the server and sent as command to the clients. As such the local langugae tab is irrelevant, since I can even join an English server with German or Japanese langugage selected. (and have all error messages etc. in my language.)

[Matthew]

The town name and everything else is generated in the game on the server and sent as command to the clients. As such the local langugae tab is irrelevant, since I can even join an English server with German or Japanese langugage selected. (and have all error messages etc. in my language.)

That is not how it works in Extended network games. Both client and server generate town names, so there is an inconsistency until the client fully disconnects and a savegame is sent from the server.

But as far as I know that doesn't cause desyncs.

[zook2]

An hour ago I had a desynch when deleting three tiles of road in Alnington, single clicks (not the road removal tool). Freakh was online, too; maybe he did something else that could have caused it. I rejoined a few minutes later and the server had reverted to an earlier save.

[Mariculous]

I suspect, I was sleeping at that time 

[Matthew]

Hi James. I have a couple of comments relating to the multiplayer mystery bug. I'm not sure if this the best thread but it was the closest one I could find.

Firstly, TransShipmentEnvoy has said on Discord that when his(?) server goes down, Extended has usually filled the memory, so he suspects a memory leak. If you have not already ruled this out as a symptom of the B-B server freezes, then you might want to check the memory situation next time you have to reset the server.

Secondly, does anyone know whether an update is sent to the server list when a player desyncs?

[neroden]

Bridgewater-brunel is consistently desyncing (probably crashing?) and resetting to previous save at 1 PM in December 2012.  No idea why, it doesn't seem to be related do doing anything.  Memory leak?

Now doing the crash at Feb 2013.  Not sure what's going wrong, but it's impossible to play right now.

[jamespetts]

Apologies for not having had a chance to look at this sooner. This does not seem to be fully consistent or reproducible, since the list server records one client connected and the date at May 2015.

If we can get a reproduction case for this, that would be helpful.

[neroden]

OK, I have a log trace for your during a desync

Code Select Expand

Warning: karte_t:::do_network_world_command:    sync_step=196751  server=[ss=196751 st=98375 nfc=1 hash=0 rand=3120262428 halt=385 line=1 cnvy=1
        ssr=2410088546,0,2410088546,2410088546,3120262428,3120262428,3120262428,0
        str=4163797894,4163797894,4163797894,4163797894,4163797894,4163797894,4163797894,4163797894,4163797894,4163797894,4163797894,4163797894,4163797894,4163797894,4163797894,4163797894
        exr=4163797894,2410088546,2410088546,0,0,0,0,0
        sums=129712,50607159,6307,6599,6,0,0,0,7,26]
client=[ss=196751 st=98375 nfc=1 hash=0 rand=3120262428 halt=385 line=1 cnvy=1
        ssr=2410088546,0,2410088546,2410088546,3120262428,3120262428,3120262428,0
        str=4163797894,4163797894,4163797894,4163797894,4163797894,4163797894,4163797894,4163797894,4163797894,4163797894,4163797894,4163797894,4163797894,4163797894,4163797894,4163797894
        exr=4163797894,2410088546,2410088546,0,0,0,0,0
        sums=129712,50607159,6307,6599,6,0,0,0,7,26]

Warning: karte_t:::do_network_world_command:    sync_step=196752  server=[ss=196752 st=98376 nfc=0 hash=0 rand=170881881 halt=385 line=1 cnvy=1
        ssr=3120262428,0,3120262428,3120262428,3928131591,3928131591,3928131591,0
        str=3928131591,3928131591,3928131591,3928131591,3928131591,3928131591,3928131591,3928131591,3928131591,3928131591,3928131591,3928131591,3928131591,3928131591,3928131591,3928131591
        exr=3928131591,170881881,170881881,0,0,0,0,0
        sums=128469,50317759,6307,6599,6,91,25606,25623,16,20]
client=[ss=196752 st=98376 nfc=0 hash=0 rand=1689447484 halt=385 line=1 cnvy=1
        ssr=3120262428,0,3120262428,3120262428,3928131591,3928131591,3928131591,0
        str=3928131591,3928131591,3928131591,3928131591,3928131591,3928131591,3928131591,3928131591,3928131591,3928131591,3928131591,3928131591,3928131591,3928131591,3928131591,356449376
        exr=356449376,1689447484,1689447484,0,0,0,0,0
        sums=128469,50317759,6307,6599,6,91,25606,25623,16,20]

I don't know what to make of this -- a bit cryptic.

I've also been getting some really weird things where the server is claiming I have a mismatch even though I *just* downloaded both pak and executable.  This is not reproduceable yet.  I'm trying re-downloading the themes and config directories.

[neroden]

Here's another desync.  And I was the only one logged in.  This happened when trying to use the station relocation tool

Code Select Expand

Warning: karte_t:::do_network_world_command:    sync_step=218863  server=[ss=218863 st=109431 nfc=1 hash=0 rand=2619890734 halt=385 line=1 cnvy=1
        ssr=790818943,0,790818943,790818943,2619890734,2619890734,2619890734,0
        str=790818943,790818943,790818943,790818943,790818943,790818943,790818943,790818943,790818943,790818943,790818943,790818943,790818943,790818943,790818943,790818943
        exr=790818943,790818943,790818943,0,0,0,0,0
        sums=136393,54160268,6684,6899,6,0,0,0,6,31]
client=[ss=218863 st=109431 nfc=1 hash=0 rand=2619890734 halt=385 line=1 cnvy=1
        ssr=790818943,0,790818943,790818943,2619890734,2619890734,2619890734,0
        str=790818943,790818943,790818943,790818943,790818943,790818943,790818943,790818943,790818943,790818943,790818943,790818943,790818943,790818943,790818943,790818943
        exr=790818943,790818943,790818943,0,0,0,0,0
        sums=136393,54160268,6684,6899,6,0,0,0,6,31]

Warning: karte_t:::do_network_world_command:    sync_step=218864  server=[ss=218864 st=109432 nfc=0 hash=0 rand=3670556178 halt=385 line=1 cnvy=1
        ssr=2619890734,0,2619890734,2619890734,2104222973,2104222973,2104222973,0
        str=2104222973,2104222973,2104222973,2104222973,2104222973,2104222973,2104222973,2104222973,2104222973,2104222973,2104222973,2104222973,2104222973,2104222973,2104222973,2104222973
        exr=2104222973,3670556178,3670556178,0,0,0,0,0
        sums=136204,53876190,6686,6899,6,103,25058,25068,11,34]
client=[ss=218864 st=109432 nfc=0 hash=0 rand=669551320 halt=385 line=1 cnvy=1
        ssr=2619890734,0,2619890734,2619890734,2104222973,2104222973,2104222973,0
        str=2104222973,2104222973,2104222973,2104222973,2104222973,2104222973,2104222973,2104222973,2104222973,2104222973,2104222973,2104222973,2104222973,2104222973,2104222973,3711126139
        exr=3711126139,669551320,669551320,0,0,0,0,0
        sums=136204,53876190,6686,6899,6,103,25058,25068,11,34]

Warning: karte_t::network_disconnect(): Lost synchronisation with server. Random flags: 0
Warning: nwc_routesearch_t::reset:      all static variables are reset
Warning: karte_t:::do_network_world_command:    Disconnected due to checklist mismatch
I have no idea what to make of any of this since I haven't looked through the code to understand what the log messages mean.

[TurfIt]

Look in checklist_t::print() to decode which rand index. For your desync, first difference is between rand[22] and rand[23] - last number printed in str= line.
Look in simworld. cc to find rands[22] and rands[23] surrounding haltestelle_t::step_all();
Your desync was due to your computer calling simrand() while stepping the halts, the server did not - mismatch.
IIRC the only thing halts call randoms for is generating pedestrians...

[neroden]

Well *that's* interesting.  Perhaps halts call randoms for something other than generating pedestrians now.

But if not... then it's worth noting that the setting for whether halts generate pedestrians is in simuconf.tab under display settings and not in the pak.  Hmmmmm.

[ceeac]

There were also lots of thread synchronization bugs (data races) the last time I checked (which was more than a year ago I think) - to reproduce, just compile and link the headless server with -fsanitize=thread and load a savegame of your choice. There are also some data races in the display subsystem, but those are also in Standard and don't affect the synchronization of the simulation.

[Ranran]

Simutrans Extended cannot completely suppress the occurrence of pedestrians by changing the display settings. They seem to occur based on arrival.
In another case, even when a private car arrives at its destination, it is destroyed and then purged two.
Also, as Freddy previously reported, the location of pedestrians differs depending on the client, so blowing it up with the remove tool will cause a dysync.

EDIT:

Hence, r10664+10660+10659 made passengers independent from the game state. So a client can switch off passengers (or the server can switch off them.)

r10664 may not have been merged yet. It might be worth looking into it.

[jamespetts]

Thank you all for your posts and analysis. As to the pedestrians: the problem is very unlikely to be just the display of pedestrians itself. Rather, losing synchronisation on the display of pedestrians is likely to be a symptom of the problem: this is likely simply to be the first call to simrand() after the game states on client and server have diverged. Those game states could have diverged anywhere between the simrand() call that triggered the loss of synchronisation and an arbitrary point in the past. It need not even have occurred since the last simrand() call if the state divergence had no direct effect on the part of the game that effected the previous simrand() call such that the game state affecting when that call was made remained undiverged. This is what makes debugging these loss of synchronisation problems so challenging. What I have found that works in the past is laboriously narrowing it down to a particular part of the code by disabling that part of the code for testing and seeing whether the losses of synchronisation still occur, and then examining that part of the code carefully and making educated guesses as to what in that code might be the cause of the problem.

In this case, the fact that some of the losses of synchronisation at least fairly reliably occur after doing something on a stop and the divergence is first detected in code relating to stops suggests that we should probably be looking at something in the code relating to stops first.

[jamespetts]

There were also lots of thread synchronization bugs (data races) the last time I checked (which was more than a year ago I think) - to reproduce, just compile and link the headless server with -fsanitize=thread and load a savegame of your choice. There are also some data races in the display subsystem, but those are also in Standard and don't affect the synchronization of the simulation.

Thank you for this suggestion. I have been attempting to do this, but, unfortunately, I get the error,

Code Select Expand

FATAL: ThreadSanitizer: unexpected memory mapping 0x57a2c0f6b000-0x57a2c107a000


[jamespetts]

Note for those interested in looking into the losses of synchronisation immediately on connexion in some cases: a possible cause was identified a few months ago here, but was not able to be fixed at the time.

[neroden]

Simutrans Extended cannot completely suppress the occurrence of pedestrians by changing the display settings. They seem to occur based on arrival.
In another case, even when a private car arrives at its destination, it is destroyed and then purged two.
Also, as Freddy previously reported, the location of pedestrians differs depending on the client, so blowing it up with the remove tool will cause a dysync.

EDIT:r10664 may not have been merged yet. It might be worth looking into it.

It hasn't been.  It doesn't merge cleanly; the first problem is that r10520 hasn't been merged.  *sigh*  These are all after the directory structure reorg, so I'm going to go back to attempting to clean up the merges from standard from before r10440

[Ranran]

https://github.com/Ranran-the-JuicyPork/simutrans-ex-fix/commit/71764efd7111550b4466874b287d79452f0238fd
I tried incorporating it before. However, the consecutive commits from r10520 did not work properly, so they were left alone.
But I think this itself is just related to the folder structure.

https://github.com/Ranran-the-JuicyPork/simutrans/commit/4f4c9e947c2380593ed631f5975efed59f756e45
As for r10664, it is after the folder structure has been changed and lot of changes and doesn't seem to be related to the UI(and chat window/font stuff), so I'm basically skipping stuff like this as declared.
But I suspect this commit is not that related to r10520.

[ceeac]

Thank you for this suggestion. I have been attempting to do this, but, unfortunately, I get the error,

Code Select Expand

FATAL: ThreadSanitizer: unexpected memory mapping 0x57a2c0f6b000-0x57a2c107a000


That is a known issue: https://stackoverflow.com/questions/77850769/fatal-threadsanitizer-unexpected-memory-mapping-when-running-on-linux-kernels
On current Arch stable setting sysctl vm.mmap_rnd_bits=30 temporarily is sufficient, but depending on the distribution ASLR needs to (temporarily!) disabled entirely.

[neroden]

Looks like the answer in here for turning off address randomization for one program is still valid:

https://stackoverflow.com/questions/5194666/disable-randomization-of-memory-addresses

Code Select Expand

setarch `uname -m` -R ./yourProgram

[jamespetts]

Thank you both for that - I will look into that when I get a moment. 

In the meantime, I should note one particular observation: when testing the 2403-std branch just now, loading an old saved game from before piers were introduced and then connecting to that as a client resulted in the same loss of synchronisation immediately on connexion and then remaining in synchronisation stably for some time on the second attempt as we have often seen elsewhere, suggesting that the piers may not be responsible - or at least, not exclusively responsible - for this issue.

[Ranran]

The problem that the game time does not progress after the first connection was introduced at some point in Standard, and it was the same in Standard. That may be related.
It's possible that I introduced an error in the merge regarding the flag that advances game time.

[jamespetts]

The problem that the game time does not progress after the first connection was introduced at some point in Standard, and it was the same in Standard. That may be related.
It's possible that I introduced an error in the merge regarding the flag that advances game time.

Interesting - do you think that game time not advancing is related to this issue?

[Ranran]

Interesting - do you think that game time not advancing is related to this issue?

Even if the game is paused and connected to the server, the convoy's position clearly changes over time, so I think it will quickly lose synchronization.

[neroden]

I now have a largely-reproduceable desync from bridgewater-brunel with a picture as well as a log and a save file.  And indeed, the game clock freezes.

This happens each time I launch a ship on this line.  It gets ONE tile from the depot and then desyncs and stops.

If I log back in, the ship is moving and active.

The log:

Code Select Expand

Warning: karte_t:::do_network_world_command:    sync_step=227207  server=[ss=227207 st=113603 nfc=1 hash=0 rand=2584969612 halt=448 line=1 cnvy=1
        ssr=3160238729,0,3160238729,3160238729,2584969612,2584969612,2584969612,0
        str=2902126355,2902126355,2902126355,2902126355,2902126355,2902126355,2902126355,2902126355,2902126355,2902126355,2902126355,2902126355,2902126355,2902126355,2902126355,2902126355
        exr=2902126355,3160238729,3160238729,0,0,0,0,0
        sums=161868,74283538,8079,8326,6,0,0,0,7,49]
client=[ss=227207 st=113603 nfc=1 hash=0 rand=2584969612 halt=448 line=1 cnvy=1
        ssr=3160238729,0,3160238729,3160238729,2584969612,2584969612,2584969612,0
        str=2902126355,2902126355,2902126355,2902126355,2902126355,2902126355,2902126355,2902126355,2902126355,2902126355,2902126355,2902126355,2902126355,2902126355,2902126355,2902126355
        exr=2902126355,3160238729,3160238729,0,0,0,0,0
        sums=161868,74283538,8079,8326,6,0,0,0,7,49]

Warning: nwc_routesearch_t::do_command: apply limits=(1024, 26368, 23360, 7205760, 24896)
Warning: karte_t:::do_network_world_command:    sync_step=227208  server=[ss=227208 st=113604 nfc=0 hash=0 rand=1685711413 halt=448 line=1 cnvy=1
        ssr=2584969612,0,2584969612,2584969612,1393767618,1393767618,1393767618,0
        str=1393767618,1393767618,1393767618,1393767618,1393767618,1393767618,1393767618,1393767618,1393767618,1393767618,1393767618,1393767618,1393767618,1393767618,1393767618,1393767618
        exr=1393767618,1685711413,1685711413,0,0,0,0,0
        sums=161228,74269235,8084,8326,6,91,31969,31985,4,42]
client=[ss=227208 st=113604 nfc=0 hash=0 rand=1685711413 halt=448 line=1 cnvy=1
        ssr=2584969612,0,2584969612,2584969612,1393767618,1393767618,1393767618,0
        str=1393767618,1393767618,1393767618,1393767618,1393767618,1393767618,1393767618,1393767618,1393767618,1393767618,1393767618,1393767618,1393767618,1393767618,1393767618,1393767618
        exr=1393767618,1685711413,1685711413,0,0,0,0,0
        sums=161228,74269235,8084,8326,6,91,31969,31985,4,42]

Warning: karte_t:::do_network_world_command:    sync_step=227209  server=[ss=227209 st=113604 nfc=1 hash=0 rand=25813312 halt=448 line=1 cnvy=1
        ssr=1685711413,0,1685711413,1685711413,25813312,25813312,25813312,0
        str=1393767618,1393767618,1393767618,1393767618,1393767618,1393767618,1393767618,1393767618,1393767618,1393767618,1393767618,1393767618,1393767618,1393767618,1393767618,1393767618
        exr=1393767618,1685711413,1685711413,0,0,0,0,0
        sums=160757,74078986,8085,8314,6,0,0,0,9,36]
client=[ss=227209 st=113604 nfc=1 hash=0 rand=25813312 halt=448 line=1 cnvy=1
        ssr=1685711413,0,1685711413,1685711413,25813312,25813312,25813312,0
        str=1393767618,1393767618,1393767618,1393767618,1393767618,1393767618,1393767618,1393767618,1393767618,1393767618,1393767618,1393767618,1393767618,1393767618,1393767618,1393767618
        exr=1393767618,1685711413,1685711413,0,0,0,0,0
        sums=160757,74078986,8085,8314,6,0,0,0,9,36]

Warning: karte_t:::do_network_world_command:    sync_step=227210  server=[ss=227210 st=113605 nfc=0 hash=0 rand=2333571511 halt=448 line=1 cnvy=1
        ssr=25813312,0,25813312,25813312,2379738658,2379738658,2379738658,0
        str=2379738658,2379738658,2379738658,2379738658,2379738658,2379738658,2379738658,2379738658,2379738658,2379738658,2379738658,2379738658,2379738658,2379738658,2379738658,2379738658
        exr=2379738658,2333571511,2333571511,0,0,0,0,0
        sums=162393,74759842,8087,8314,6,98,31971,31986,4,26]
client=[ss=227210 st=113605 nfc=0 hash=0 rand=3052961707 halt=448 line=1 cnvy=1
        ssr=25813312,0,25813312,25813312,2379738658,2379738658,2379738658,0
        str=2379738658,2379738658,2379738658,2379738658,2379738658,2379738658,2379738658,2379738658,2379738658,2379738658,2379738658,2379738658,2379738658,2379738658,2379738658,4140898091
        exr=4140898091,3052961707,3052961707,0,0,0,0,0
        sums=162393,74759842,8087,8314,6,98,31971,31986,4,26]

Warning: karte_t::network_disconnect(): Lost synchronisation with server. Random flags: 0
Warning: nwc_routesearch_t::reset:      all static variables are reset
Warning: karte_t:::do_network_world_command:    Disconnected due to checklist mismatch


I'm not up to figuring out how to upload the save and screenshot right now (simutrans-germany file hosting is not working) but anyway.

[jamespetts]

Interesting - thank you for that. Do we know which commit fixed this in Standard? We might want to expedite incorporating that fix.

[Ranran]

I don't understand what causes PAUSE_FLAG to remain standing.
The only obvious difference was around the part marked

Code Select Expand

// time for the next step? in simworld.cc

[neroden]

Could you point to the commits which you think might be relevant?

If this doesn't track it down we may have to go the whole hog and `git bisect` James's master branch to find where the desyncs were introduced.  That would be a pain but sometimes it's the only way.  I know we weren't getting them with the previous bridgewater-brunel game, and we started getting them quite early in the new bridgewater-brunel game, but that's a LOT of months and a LOT of code to bisect through...

[Ranran]

For reference, here is a bug report I posted previously to the standard board.
https://forum.simutrans.com/index.php/topic,21444.0.html

[neroden]

I don't think that's going to be it, because at this point I think -pause isn't being passed to the server or the client or configured in the server or the client.  I'm taking a look at it though.