Author Topic: [fixed] r3625: OoS on localhost / infinite loop at end of game  (Read 772 times)

tomreyn

  • Local Moderator
  • Airship
  • ********
  • Posts: 2,764
    • View Profile
    • MegaGlest - the free and open source cross platform 3D real-time strategy game
I was just hosting a headless server with Titi, TitiSon, Jammy, and myself connecting form a second instance of MG running on the same computer (same configuration / data / log directories, too).
When the (rather massive) game was over and everyone except my own client had disconnected, I kept it running for some minutes. A few minutes later, I ran into "game is out of synch" (OoS)  and an infinite loop, where this message kept repeating on screen, and the game kept being saved to disk every ~ 1 second.

Titi and I were wondering whether this infinite loop may actually have started earlier and be the root cause of this OoS (due to game saving delaying the game client). When trying to reproduce it, no write access to the savegame file took place, though. So we assume the savegame is only created in the case of an error.

So there are really two issues here: Clearly this OoS on a loopback interface link should not have happened in the first place. And then there shouldn't be any loop when you run into an out of synch situation, i.e. record / state the error situation once in a savegame and on screen, but do not repeat it, instead, pause the game and quit it as soon as all on-screen messages have been confirmed.

Some statistics about the OoS:
* none of my 4 CPU cores was at 100% load
* both file and verbose logging were disabled
* I had no special features activated (or can't think of any)
* my physical RAM was never in use by more than 50%
* there was little disk I/O

The server had been started using ./start_megaglest --headless-server-mode=vps,exit, the client using ./megaglest --connecthost=127.0.0.1. I noticed (using iotop) that MegaGlest would cause a 9 MB/sec write troughput on disk after the OoS had occurred, that's how I learnt about it writing the savegame: megaglest-saved.xml and megaglest-saved.xml.jpg are written about every one second when the game is in this state.

The savegame was 8.4 MB. that seems ather large, maybe it would be an option to look through it if this happens again, to tell whether incorrect data is stored.
When on the end of game stats screen, 1.7 GB RAM (of 8 GB physical) were in use and there were 15% of 400% CPU load sustained.
Back to the main menu, it was 1.5 GB RAM and 60% (of 400%) CPU load.
On the "video info" screen, CPU load increased to 90% (of 400%).
« Last Edit: 2 October 2012, 11:46:31 by tomreyn »
atibox: Ryzen 1800X (8 cores @3.6GHz), 32 GB RAM, MSI Radeon RX 580 Gaming X 8G, PCI subsystem ID [1462:3417], (Radeon RX 580 chipset, POLARIS10) @3440x1440; latest stable Ubuntu release, (open source) radeon (amdgpu) / mesa video driver
atibox (old): Core2Quad Q9400 (4 cores @2.66GHz), 8 GB RAM, XFX HD-467X-DDF2, PCI subsystem ID [1682:2931], (Radeon HD 4670, RV730 XT) @1680x1050; latest stable Ubuntu release, (open source) radeon / mesa video driver
notebook: HP envy13d020ng
internet access: VDSL2+

· · · How YOU can contribute to MG · Latest development snapshot · How to build yourself · Megapack techtree · Currently hosted MG games · · ·

softcoder

  • MegaGlest Team
  • Battle Machine
  • ********
  • Posts: 2,239
    • View Profile
Re: r3625: OoS on localhost / loopback at end of game
« Reply #1 on: 1 October 2012, 15:18:39 »
To address this properly I would like to see the exact error message text. There are multiple places oos can occur (was it client or server that actually had the error).

Thanks

tomreyn

  • Local Moderator
  • Airship
  • ********
  • Posts: 2,764
    • View Profile
    • MegaGlest - the free and open source cross platform 3D real-time strategy game
Re: r3625: OoS on localhost / loopback at end of game
« Reply #2 on: 1 October 2012, 18:18:30 »
I'm afraid the exact error message is gone. It was about "game is out of synch" and "command not found for unit..." which related to an ibis, and I had a bunch of ibises attacking other other units on screen when it happened. That's all I remember unfortunately.

While in that infinite loop, I ran gdb three times. Twice the normal way ('bt'), and once with all info available ('thread apply all bt full'), and got:

Code: [Select]
0x00007f2acefff556 in std::ostream& std::ostream::_M_insert<long>(long) () from /usr/lib/x86_64-linux-gnu/libstdc++.so.6
#0  0x00007f2acefff556 in std::ostream& std::ostream::_M_insert<long>(long) () from /usr/lib/x86_64-linux-gnu/libstdc++.so.6
#1  0x0000000000832c04 in getString (this=0x8409630) at /home/tomreyn/SCM/megaglest-trunk/source/glest_game/../shared_lib/include/graphics/vec.h:228
#2  Glest::Game::Resource::saveGame (this=0x84095f0, rootNode=<optimized out>) at /home/tomreyn/SCM/megaglest-trunk/source/glest_game/type_instances/resource.cpp:114
#3  0x000000000086ab03 in Glest::Game::Faction::saveGame (this=0x96fbae0, rootNode=<optimized out>) at /home/tomreyn/SCM/megaglest-trunk/source/glest_game/type_instances/faction.cpp:1919
#4  0x000000000091d8fc in Glest::Game::World::saveGame (this=0x2bb2eb0, rootNode=<optimized out>) at /home/tomreyn/SCM/megaglest-trunk/source/glest_game/world/world.cpp:2327
#5  0x000000000057cc20 in Glest::Game::Game::saveGame (this=0x2bb2e70, name=...) at /home/tomreyn/SCM/megaglest-trunk/source/glest_game/game/game.cpp:4724
#6  0x000000000091cfab in Glest::Game::World::DumpWorldToLog (this=0x2bb2eb0, consoleBasicInfoOnly=<optimized out>) at /home/tomreyn/SCM/megaglest-trunk/source/glest_game/world/world.cpp:2292
#7  0x0000000000547c14 in Glest::Game::Commander::buildCommand (this=0x2bb41e0, networkCommand=0xf03f9d0) at /home/tomreyn/SCM/megaglest-trunk/source/glest_game/game/commander.cpp:1089
#8  0x000000000054bea6 in Glest::Game::Commander::giveNetworkCommand (this=0x2bb41e0, networkCommand=0xf03f9d0) at /home/tomreyn/SCM/megaglest-trunk/source/glest_game/game/commander.cpp:935
#9  0x000000000054f13f in Glest::Game::Commander::updateNetwork (this=0x2bb41e0, game=<optimized out>) at /home/tomreyn/SCM/megaglest-trunk/source/glest_game/game/commander.cpp:618
#10 0x000000000059f4ad in Glest::Game::Game::update (this=0x2bb2e70) at /home/tomreyn/SCM/megaglest-trunk/source/glest_game/game/game.cpp:1535
#11 0x0000000000692ca6 in Glest::Game::Program::loopWorker (this=0x1632bb0) at /home/tomreyn/SCM/megaglest-trunk/source/glest_game/main/program.cpp:432
#12 0x00000000006796f1 in Glest::Game::glestMain (argc=<optimized out>, argv=<optimized out>) at /home/tomreyn/SCM/megaglest-trunk/source/glest_game/main/main.cpp:4742
#13 0x000000000067d886 in Glest::Game::glestMainWrapper (argc=2, argv=0x7fff0a65e0a8) at /home/tomreyn/SCM/megaglest-trunk/source/glest_game/main/main.cpp:4920
#14 0x00007f2ace6bd76d in __libc_start_main (main=0x4ebc20 <main(int, char**)>, argc=2, ubp_av=0x7fff0a65e0a8, init=<optimized out>, fini=<optimized out>, rtld_fini=<optimized out>, stack_end=0x7fff0a65e098) at libc-start.c:226
#15 0x00000000004f1069 in _start ()

Code: [Select]
0x00007f2ace6e3b3f in _IO_vfprintf_internal (s=<optimized out>, format=<optimized out>, ap=<optimized out>) at vfprintf.c:1623
#0  0x00007f2ace6e3b3f in _IO_vfprintf_internal (s=<optimized out>, format=<optimized out>, ap=<optimized out>) at vfprintf.c:1623
#1  0x00007f2ace7a3460 in ___vsnprintf_chk (s=0x7fff0a64b6e0 "1", maxlen=<optimized out>, flags=1, slen=<optimized out>, format=0xb45205 "%lld", args=0x7fff0a64b5f8) at vsnprintf_chk.c:65
#2  0x00007f2ace7a33a8 in ___snprintf_chk (s=<optimized out>, maxlen=<optimized out>, flags=<optimized out>, slen=<optimized out>, format=<optimized out>) at snprintf_chk.c:36
#3  0x00000000009be7b9 in snprintf (__fmt=0xb45205 "%lld", __n=255, __s=0x7fff0a64b6e0 "1") at /usr/include/x86_64-linux-gnu/bits/stdio2.h:66
#4  Shared::Util::intToStr (i=<optimized out>) at /home/tomreyn/SCM/megaglest-trunk/source/shared_lib/sources/util/conversion.cpp:137
#5  0x000000000050e732 in Glest::Game::PathFinder::saveGame (this=0x8c10620, rootNode=<optimized out>) at /home/tomreyn/SCM/megaglest-trunk/source/glest_game/ai/path_finder.cpp:1484
#6  0x0000000000908225 in Glest::Game::UnitUpdater::saveGame (this=0x2bb36b0, rootNode=<optimized out>) at /home/tomreyn/SCM/megaglest-trunk/source/glest_game/world/unit_updater.cpp:2493
#7  0x000000000091d8ae in Glest::Game::World::saveGame (this=0x2bb2eb0, rootNode=<optimized out>) at /home/tomreyn/SCM/megaglest-trunk/source/glest_game/world/world.cpp:2317
#8  0x000000000057cc20 in Glest::Game::Game::saveGame (this=0x2bb2e70, name=...) at /home/tomreyn/SCM/megaglest-trunk/source/glest_game/game/game.cpp:4724
#9  0x000000000091cfab in Glest::Game::World::DumpWorldToLog (this=0x2bb2eb0, consoleBasicInfoOnly=<optimized out>) at /home/tomreyn/SCM/megaglest-trunk/source/glest_game/world/world.cpp:2292
#10 0x0000000000547c14 in Glest::Game::Commander::buildCommand (this=0x2bb41e0, networkCommand=0xf03f9d0) at /home/tomreyn/SCM/megaglest-trunk/source/glest_game/game/commander.cpp:1089
#11 0x000000000054bea6 in Glest::Game::Commander::giveNetworkCommand (this=0x2bb41e0, networkCommand=0xf03f9d0) at /home/tomreyn/SCM/megaglest-trunk/source/glest_game/game/commander.cpp:935
#12 0x000000000054f13f in Glest::Game::Commander::updateNetwork (this=0x2bb41e0, game=<optimized out>) at /home/tomreyn/SCM/megaglest-trunk/source/glest_game/game/commander.cpp:618
#13 0x000000000059f4ad in Glest::Game::Game::update (this=0x2bb2e70) at /home/tomreyn/SCM/megaglest-trunk/source/glest_game/game/game.cpp:1535
#14 0x0000000000692ca6 in Glest::Game::Program::loopWorker (this=0x1632bb0) at /home/tomreyn/SCM/megaglest-trunk/source/glest_game/main/program.cpp:432
#15 0x00000000006796f1 in Glest::Game::glestMain (argc=<optimized out>, argv=<optimized out>) at /home/tomreyn/SCM/megaglest-trunk/source/glest_game/main/main.cpp:4742
#16 0x000000000067d886 in Glest::Game::glestMainWrapper (argc=2, argv=0x7fff0a65e0a8) at /home/tomreyn/SCM/megaglest-trunk/source/glest_game/main/main.cpp:4920
#17 0x00007f2ace6bd76d in __libc_start_main (main=0x4ebc20 <main(int, char**)>, argc=2, ubp_av=0x7fff0a65e0a8, init=<optimized out>, fini=<optimized out>, rtld_fini=<optimized out>, stack_end=0x7fff0a65e098) at libc-start.c:226
#18 0x00000000004f1069 in _start ()

... and this one (the full one)
http://paste.ubuntu.com/1254447/
atibox: Ryzen 1800X (8 cores @3.6GHz), 32 GB RAM, MSI Radeon RX 580 Gaming X 8G, PCI subsystem ID [1462:3417], (Radeon RX 580 chipset, POLARIS10) @3440x1440; latest stable Ubuntu release, (open source) radeon (amdgpu) / mesa video driver
atibox (old): Core2Quad Q9400 (4 cores @2.66GHz), 8 GB RAM, XFX HD-467X-DDF2, PCI subsystem ID [1682:2931], (Radeon HD 4670, RV730 XT) @1680x1050; latest stable Ubuntu release, (open source) radeon / mesa video driver
notebook: HP envy13d020ng
internet access: VDSL2+

· · · How YOU can contribute to MG · Latest development snapshot · How to build yourself · Megapack techtree · Currently hosted MG games · · ·

softcoder

  • MegaGlest Team
  • Battle Machine
  • ********
  • Posts: 2,239
    • View Profile
Re: r3625: OoS on localhost / loopback at end of game
« Reply #3 on: 2 October 2012, 06:21:21 »
Try out svn rev#3626, should be fixed.

Thanks

tomreyn

  • Local Moderator
  • Airship
  • ********
  • Posts: 2,764
    • View Profile
    • MegaGlest - the free and open source cross platform 3D real-time strategy game
Re: r3625: OoS on localhost / loopback at end of game
« Reply #4 on: 2 October 2012, 11:45:51 »
Thanks for fixing the infinite loop. It will be very difficult to reproduce so I'll just tag this as [fixed], even though it remains unclear, due to lack of information I could provide, what caused the out of synch initially.
atibox: Ryzen 1800X (8 cores @3.6GHz), 32 GB RAM, MSI Radeon RX 580 Gaming X 8G, PCI subsystem ID [1462:3417], (Radeon RX 580 chipset, POLARIS10) @3440x1440; latest stable Ubuntu release, (open source) radeon (amdgpu) / mesa video driver
atibox (old): Core2Quad Q9400 (4 cores @2.66GHz), 8 GB RAM, XFX HD-467X-DDF2, PCI subsystem ID [1682:2931], (Radeon HD 4670, RV730 XT) @1680x1050; latest stable Ubuntu release, (open source) radeon / mesa video driver
notebook: HP envy13d020ng
internet access: VDSL2+

· · · How YOU can contribute to MG · Latest development snapshot · How to build yourself · Megapack techtree · Currently hosted MG games · · ·

 

anything