Multiplayer slow game server

For topics that do not fit in another sub-forum.

Moderator: Oberlus

Message
Author
o01eg
Programmer
Posts: 2004
Joined: Sat Dec 10, 2011 5:46 am

Re: Multiplayer slow game server

#106 Post by o01eg »

Oberlus wrote: Mon Jun 10, 2019 5:52 am
Oberlus wrote: Wed Jun 05, 2019 2:05 pm I've installed last weekly test build for windows, I was able to connect to the game and do stuff, but when I pressed Turn FO crashed to desktop.
Then I tried loading a previous local game and it worked fine (issuing orders, pressing Turn, playing next turn, pressing Turn, no errors).
Then I tried connecting to the multiplayer server again and I didn't get to the lobby, just a black empty screen iddling forever (around 2 minutes now, I was expecting a Connection Time Out after 30 s).
Then I closed the window and tried connecting again and the iddling black screen happened again (closed it after 45 s).
Then I installed the previous weekly test build (that was installed before and I was using it to play the slow game), and tried to connect but black screen again, when I should have seen the password window (after changing FO version).
So I can't play anymore (like The Silent One).
This happened again. I pressed Turn 20 and FO immediately crashed to desktop.
This time I didn't update FO, I connected using the same installation I used yesterday.
So I guess that, like it happens for The Silent One, something in the game state after turn 19 makes the client crash.

Attached the log of that crash. Last lines:

Code: Select all

07:37:46.866024 [debug] client : HumanClientApp.cpp:380 : HumanClientApp exited cleanly.
07:37:46.981913 [debug] client : Universe.cpp:161 : Reset id allocators with highest object id = -1 and highest design id = 1631
07:37:46.981913 [error] client : chmain.cpp:316 : main() caught exception(std::exception): bad allocation
Looks like it has something with sending orders to the server.
Gentoo Linux x64, gcc-11.2, boost-1.78.0
Ubuntu Server 22.04 x64, gcc-12, boost-1.74.0
Welcome to the slow multiplayer game at freeorion-lt.dedyn.io.Version 2024-03-15.b3de094.
Donations're welcome:BTC:bc1q007qldm6eppqcukewtfkfcj0naut9njj7audnm

User avatar
Oberlus
Cosmic Dragon
Posts: 5714
Joined: Mon Apr 10, 2017 4:25 pm

Re: Multiplayer slow game server

#107 Post by Oberlus »

o01eg wrote: Sun Jun 09, 2019 10:43 am To build FO with debug symbols you need to use cmake flag -DCMAKE_BUILD_TYPE=Debug or =RelWithDebInfo.
I'm doing something wrong:

Code: Select all

freeorion-build$ cmake -DCMAKE_BUILD_TYPE=Debug ../freeorion
-- Build type CMAKE_BUILD_TYPE set to Debug
-- Use CCache for Unix Makefiles called with: ccache program  
CMake Error at CMakeLists.txt:199 (if):
  if given arguments:

    "WIN32" "AND" "MSVC" "AND" "MSVC_VERSION" "GREATER_EQUAL" "1900"

  Unknown arguments specified


-- Configuring incomplete, errors occurred!
See also "/home/lucas/Projects/FreeOrion/freeorion-build/CMakeFiles/CMakeOutput.log".
See also "/home/lucas/Projects/FreeOrion/freeorion-build/CMakeFiles/CMakeError.log".
Attachments
CMakeError.log
(2.73 KiB) Downloaded 81 times

o01eg
Programmer
Posts: 2004
Joined: Sat Dec 10, 2011 5:46 am

Re: Multiplayer slow game server

#108 Post by o01eg »

It looks strange. What cmake version you use?
Gentoo Linux x64, gcc-11.2, boost-1.78.0
Ubuntu Server 22.04 x64, gcc-12, boost-1.74.0
Welcome to the slow multiplayer game at freeorion-lt.dedyn.io.Version 2024-03-15.b3de094.
Donations're welcome:BTC:bc1q007qldm6eppqcukewtfkfcj0naut9njj7audnm

User avatar
Oberlus
Cosmic Dragon
Posts: 5714
Joined: Mon Apr 10, 2017 4:25 pm

Re: Multiplayer slow game server

#109 Post by Oberlus »

o01eg wrote: Mon Jun 10, 2019 11:19 am It looks strange. What cmake version you use?

Code: Select all

freeorion$ cmake --version 
cmake version 3.5.1
Also, now I can't compile. After having use "-DCMAKE_BUILD_TYPE=Debug", that variable is set to Debug even if I don't write it, and using "-DCMAKE_BUILD_TYPE=Release" (should it be Test or something else?) I get the same error than above. Can it be the problem comes from some recent change in master?

o01eg
Programmer
Posts: 2004
Joined: Sat Dec 10, 2011 5:46 am

Re: Multiplayer slow game server

#110 Post by o01eg »

Oberlus wrote: Mon Jun 10, 2019 11:22 am
o01eg wrote: Mon Jun 10, 2019 11:19 am It looks strange. What cmake version you use?

Code: Select all

freeorion$ cmake --version 
cmake version 3.5.1
Also, now I can't compile. After having use "-DCMAKE_BUILD_TYPE=Debug", that variable is set to Debug even if I don't write it, and using "-DCMAKE_BUILD_TYPE=Release" (should it be Test or something else?) I get the same error than above. Can it be the problem comes from some recent change in master?
Looks like I've introduced GREATER_EQUAL too early: https://stackoverflow.com/questions/166 ... -statement
Gentoo Linux x64, gcc-11.2, boost-1.78.0
Ubuntu Server 22.04 x64, gcc-12, boost-1.74.0
Welcome to the slow multiplayer game at freeorion-lt.dedyn.io.Version 2024-03-15.b3de094.
Donations're welcome:BTC:bc1q007qldm6eppqcukewtfkfcj0naut9njj7audnm

o01eg
Programmer
Posts: 2004
Joined: Sat Dec 10, 2011 5:46 am

Re: Multiplayer slow game server

#111 Post by o01eg »

Oberlus wrote: Mon Jun 10, 2019 11:22 am
o01eg wrote: Mon Jun 10, 2019 11:19 am It looks strange. What cmake version you use?

Code: Select all

freeorion$ cmake --version 
cmake version 3.5.1
Also, now I can't compile. After having use "-DCMAKE_BUILD_TYPE=Debug", that variable is set to Debug even if I don't write it, and using "-DCMAKE_BUILD_TYPE=Release" (should it be Test or something else?) I get the same error than above. Can it be the problem comes from some recent change in master?
Apply this PR https://github.com/freeorion/freeorion/pull/2471
Gentoo Linux x64, gcc-11.2, boost-1.78.0
Ubuntu Server 22.04 x64, gcc-12, boost-1.74.0
Welcome to the slow multiplayer game at freeorion-lt.dedyn.io.Version 2024-03-15.b3de094.
Donations're welcome:BTC:bc1q007qldm6eppqcukewtfkfcj0naut9njj7audnm

User avatar
Oberlus
Cosmic Dragon
Posts: 5714
Joined: Mon Apr 10, 2017 4:25 pm

Re: Multiplayer slow game server

#112 Post by Oberlus »

o01eg wrote: Mon Jun 10, 2019 12:05 pmApply this PR https://github.com/freeorion/freeorion/pull/2471
Great, thanks. Compiling Debug right now.

User avatar
Oberlus
Cosmic Dragon
Posts: 5714
Joined: Mon Apr 10, 2017 4:25 pm

Re: Multiplayer slow game server

#113 Post by Oberlus »

I've compiled master (with the GREATER_THAN fix) with Debug flag, connected to server and crashed to desktop.

freeorion.log has the the "same" output than when not using the Debug flag:

Code: Select all

17:49:22.523791 [info] log : Logger.cpp:198 : Added logger named "network"
17:49:22.524185 [info] log : Logger.cpp:330 : Setting "network" logger threshold to "debug".
17:49:22.524308 [debug] log : LoggerWithOptionsDB.cpp:105 : Configure log source "network" from optionsDB using threshold debug
17:49:22.524377 [debug] network : ClientNetworking.cpp:349 : Attempt to connect to server at one of these addresses:
17:49:22.616916 [debug] network : ClientNetworking.cpp:351 :   tcp::resolver::iterator host_name: freeorion-lt.dedyn.io  address: 147.135.99.147  port: 12346
17:49:22.811956 [debug] network : ClientNetworking.cpp:375 : Connected to server at host_name: freeorion-lt.dedyn.io  address: 147.135.99.147  port: 12346
17:49:22.812076 [debug] network : ClientNetworking.cpp:399 : Connecting to server took 288 ms.
17:49:22.812111 [debug] network : ClientNetworking.cpp:402 : ConnectToServer() : starting networking thread
17:49:22.853705 [warn] client : HumanClientApp.cpp:684 : Cann't get cookie for server freeorion-lt.dedyn.io. Get error messageinvalid uuid string
17:49:34.002288 [debug] client : HumanClientApp.cpp:1095 : HumanClientApp::HandleFocusChange(Lost Focus)
17:50:43.671435 [debug] client : HumanClientApp.cpp:1095 : HumanClientApp::HandleFocusChange(Gained Focus)
17:50:53.018085 [debug] client : HumanClientApp.cpp:1038 : New roles: 00100
17:50:53.221134 [debug] network : ClientNetworking.cpp:461 : ClientNetworking::SetPlayerID: player id set to: 1
17:50:53.321543 [debug] client : Building.cpp:407 : BuildingTypeManager checksum: 4916521
17:50:53.322730 [debug] client : Field.cpp:226 : FieldTypeManager checksum: 7794237
17:50:53.323304 [debug] client : Field.cpp:226 : FieldTypeManager checksum: 2061208
17:50:53.323849 [debug] client : Field.cpp:226 : FieldTypeManager checksum: 8041779
17:50:53.325824 [debug] client : Field.cpp:226 : FieldTypeManager checksum: 2424510
17:50:53.327925 [debug] client : Field.cpp:226 : FieldTypeManager checksum: 2416347
17:50:53.328133 [debug] client : Field.cpp:226 : FieldTypeManager checksum: 6092622
17:50:53.393421 [debug] client : ShipDesign.cpp:776 : HullTypeManager checksum: 8001017
17:50:53.426188 [debug] client : ShipDesign.cpp:265 : PartTypeManager checksum: 8722648
17:50:53.426259 [debug] client : ShipDesign.cpp:1613 : Populating pre-defined ships with ship designs.
17:50:53.428687 [debug] client : ShipDesign.cpp:1613 : Populating pre-defined ships with monster designs.
17:50:53.432793 [debug] client : ShipDesign.cpp:1550 : PredefinedShipDesignManager checksum: 877965
17:50:53.732940 [debug] client : Species.cpp:632 : SpeciesManager checksum: 1510427
17:50:53.760642 [debug] client : Tech.cpp:716 : TechManager checksum: 2634808
17:50:53.760675 [info] client : ClientApp.cpp:172 : Checksum received from server matches client checksum.
17:50:55.700514 [debug] client : SitRepPanel.cpp:766 : SitRepPanel::Update()
17:50:55.710084 [debug] client : Message.cpp:855 : ExtractGameStartMessage empire deserialization time 7.622
17:50:55.712146 [debug] client : Universe.cpp:161 : Reset id allocators with highest object id = -1 and highest design id = -1
17:50:55.712278 [debug] client : SerializeUniverse.cpp:84 : Universe::serialize : deserializing universe width: 566.827
17:50:55.721422 [debug] client : SerializeUniverse.cpp:89 : Universe::serialize : deserializing 0 ship designs
17:50:55.723865 [debug] client : SerializeUniverse.cpp:98 : Universe::serialize : deserializing empire object visibility for 1, 1, 1, 1 empires
17:50:55.739978 [debug] client : SerializeUniverse.cpp:113 : Universe::serialize : deserializing 132 objects
17:50:55.740050 [debug] client : SerializeUniverse.cpp:119 : Universe::serialize : deserializing 22 destroyed object ids
17:50:55.740333 [debug] client : SerializeUniverse.cpp:126 : Universe::serialize : deserializing empire known objects for 0 empires
17:50:55.740365 [debug] client : SerializeUniverse.cpp:132 : Universe::serialize : deserializing id allocator version = 1
17:50:55.740384 [debug] IDallocator : IDAllocator.cpp:288 : Deserialize IDAllocator()  server id = -1 empire id = 3
17:50:55.740473 [debug] IDallocator : IDAllocator.cpp:307 : Deserialized [empire = 3 next id = 2169, ]
17:50:55.740504 [debug] IDallocator : IDAllocator.cpp:288 : Deserialize IDAllocator()  server id = -1 empire id = 3
17:50:55.740545 [debug] IDallocator : IDAllocator.cpp:307 : Deserialized [empire = 3 next id = 2168, ]
17:50:55.740583 [debug] client : SerializeUniverse.cpp:161 : Universe::serialize : deserializing 0 types of statistic
17:50:55.740603 [debug] client : SerializeUniverse.cpp:164 : Universe::serialize : deserializing done
17:50:55.740619 [debug] client : SerializeUniverse.cpp:175 : Universe::serialize : updating empires' latest known object destruction states
17:50:55.740635 [debug] client : SerializeUniverse.cpp:184 : Universe::serialize done
17:50:55.740673 [debug] client : Message.cpp:864 : ExtractGameStartMessage universe deserialization time 28.843
17:50:55.825524 [error] client : Message.cpp:885 : ExtractGameStartMessageData(...) failed!  Message probably long, so not outputting to log.
Error: input stream error
I've tried running it with gdb:

Code: Select all

(gdb) run
Starting program: /home/Oberlus/Projects/FreeOrion/freeorion-build/freeorion 
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".
[New Thread 0x7fffe696c700 (LWP 3272)]
[Thread 0x7fffe696c700 (LWP 3272) exited]
[New Thread 0x7fffe696c700 (LWP 3273)]
[New Thread 0x7ffff7f18700 (LWP 3275)]
[New Thread 0x7fffd7cbd700 (LWP 3276)]
[New Thread 0x7fffd74bc700 (LWP 3277)]
[New Thread 0x7fffd6cbb700 (LWP 3278)]
[New Thread 0x7fffd64ba700 (LWP 3279)]
[New Thread 0x7fffd5cb9700 (LWP 3280)]
[New Thread 0x7fffd54b8700 (LWP 3281)]
[New Thread 0x7fffd4cb7700 (LWP 3282)]
[New Thread 0x7fffb7fff700 (LWP 3283)]
[New Thread 0x7fffb77fe700 (LWP 3284)]
[New Thread 0x7fffb6ffd700 (LWP 3285)]
[New Thread 0x7fffb67fc700 (LWP 3286)]
[Thread 0x7fffd74bc700 (LWP 3277) exited]
[Thread 0x7fffb6ffd700 (LWP 3285) exited]
[Thread 0x7fffd6cbb700 (LWP 3278) exited]
[Thread 0x7fffb77fe700 (LWP 3284) exited]
[Thread 0x7fffb7fff700 (LWP 3283) exited]
[Thread 0x7fffd64ba700 (LWP 3279) exited]
[Thread 0x7fffd54b8700 (LWP 3281) exited]
[Thread 0x7fffb67fc700 (LWP 3286) exited]
[Thread 0x7fffd4cb7700 (LWP 3282) exited]
[Thread 0x7fffd7cbd700 (LWP 3276) exited]
[Thread 0x7fffd5cb9700 (LWP 3280) exited]
[New Thread 0x7fffb6ffd700 (LWP 3288)]
terminate called after throwing an instance of 'std::exception'
  what():  std::exception

Thread 1 "freeorion" received signal SIGABRT, Aborted.
0x00007ffff2346428 in __GI_raise (sig=sig@entry=6)
    at ../sysdeps/unix/sysv/linux/raise.c:54
54	../sysdeps/unix/sysv/linux/raise.c: No such file or directory.
(gdb) bt
#0  0x00007ffff2346428 in __GI_raise (sig=sig@entry=6)
    at ../sysdeps/unix/sysv/linux/raise.c:54
#1  0x00007ffff234802a in __GI_abort () at abort.c:89
#2  0x00007ffff2c8984d in __gnu_cxx::__verbose_terminate_handler() ()
   from /usr/lib/x86_64-linux-gnu/libstdc++.so.6
#3  0x00007ffff2c876b6 in ?? () from /usr/lib/x86_64-linux-gnu/libstdc++.so.6
#4  0x00007ffff2c87701 in std::terminate() ()
   from /usr/lib/x86_64-linux-gnu/libstdc++.so.6
#5  0x00007ffff2c87919 in __cxa_throw ()
   from /usr/lib/x86_64-linux-gnu/libstdc++.so.6
#6  0x00007ffff6e99dac in ExtractGameStartMessageData (msg=..., 
    single_player_game=@0x7fffffffc46e: false, empire_id=@0x7fffffffc488: 3, 
    current_turn=@0x7fffffffc48c: 20, empires=..., universe=..., species=..., 
    combat_logs=..., supply=..., players=std::map with 1 elements = {...}, 
    orders=..., loaded_game_data=@0x7fffffffc46b: true, 
    ui_data_available=@0x7fffffffc46c: true, ui_data=..., 
    save_state_string_available=@0x7fffffffc46d: 127, save_state_string="", 
    galaxy_setup_data=...)
    at /home/Oberlus/Projects/FreeOrion/freeorion/network/Message.cpp:887
#7  0x00000000007e4877 in WaitingForGameStart::react (this=0x37dfe80, msg=...)
    at /home/Oberlus/Projects/FreeOrion/freeorion/client/human/HumanClientFSM.cpp:852
#8  0x00000000007ff675 in boost::statechart::custom_reaction<GameStart>::react<W--------Type <return> to continue, or q <return> to quit---
aitingForGameStart, boost::statechart::event_base, void const*> (stt=..., evt=..., 
    eventType=@0x7fffffffc718: 0x1840330 <boost::statechart::detail::id_holder<GameStart>::idProvider_>) at /usr/include/boost/statechart/custom_reaction.hpp:41
#9  0x00000000007fe866 in boost::statechart::simple_state<WaitingForGameStart, PlayingGame, boost::mpl::list<mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na>, (boost::statechart::history_mode)0>::local_react_impl_non_empty::local_react_impl<boost::mpl::list<boost::statechart::custom_reaction<GameStart>, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na>, boost::statechart::simple_state<WaitingForGameStart, PlayingGame, boost::mpl::list<mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na>, (boost::statechart::history_mode)0> > (stt=..., evt=..., 
    eventType=0x1840330 <boost::statechart::detail::id_holder<GameStart>::idProvider_>) at /usr/include/boost/statechart/simple_state.hpp:816
#10 0x00000000007fd7db in boost::statechart::simple_state<WaitingForGameStart, PlayingGame, boost::mpl::list<mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na>, (boost::statechart::history_mode)0>::local_react<boost::mpl::list<boost::statechart::custom_reaction<GameStart>, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na> > (this=0x37dfe80, evt=..., 
    eventType=0x1840330 <boost::statechart::detail::id_holder<GameStart>::idProvider_>) at /usr/include/boost/statechart/simple_state.hpp:851
#11 0x00000000007fc393 in boost::statechart::simple_state<WaitingForGameStart, PlayingGame, boost::mpl::list<mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na>, (boost::statechart::history_mode)0>::react_impl (this=0x37dfe80, evt=..., 
    eventType=0x1840330 <boost::statechart::detail::id_holder<GameStart>::idProvider_>) at /usr/include/boost/statechart/simple_state.hpp:489
#12 0x00000000007a22cc in boost::statechart::detail::send_function<boost::statechart::detail::state_base<std::allocator<void>, boost::statechart::detail::rtti_policy>, boost::statechart::event_base, void const*>::operator() (this=0x7fffffffc830)
    at /usr/include/boost/statechart/state_machine.hpp:87
#13 0x0000000000799247 in boost::statechart::null_exception_translator::operator()<boost::statechart::detail::send_function<boost::statechart::detail::state_base<std::allocator<void>, boost::statechart::detail::rtti_policy>, boost::statechart::event_base, void const*>, boost::statechart::state_machine<HumanClientFSM, IntroMenu, std::allocator<void>, boost::statechart::null_exception_translator>::exception_event_handler>
    (this=0x1af34c0, action=...)
    at /usr/include/boost/statechart/null_exception_translator.hpp:33
#14 0x000000000078ff7e in boost::statechart::state_machine<HumanClientFSM, IntroMenu, std::allocator<void>, boost::statechart::null_exception_translator>::send_event (
    this=0x1af3450, evt=...) at /usr/include/boost/statechart/state_machine.hpp:885
#15 0x000000000078eae5 in boost::statechart::state_machine<HumanClientFSM, IntroMenu, std::allocator<void>, boost::statechart::null_exception_translator>::process_queued_events (this=0x1af3450) at /usr/include/boost/statechart/state_machine.hpp:910
#16 0x0000000000788187 in boost::statechart::state_machine<HumanClientFSM, IntroMenu, std::allocator<void>, boost::statechart::null_exception_translator>::process_event
    (this=0x1af3450, evt=...) at /usr/include/boost/statechart/state_machine.hpp:280
#17 0x0000000000774bac in HumanClientApp::HandleMessage (this=0x7fffffffcd50, 
    msg=...)
    at /home/Oberlus/Projects/FreeOrion/freeorion/client/human/HumanClientApp.cpp:989
Is this helpful?

o01eg
Programmer
Posts: 2004
Joined: Sat Dec 10, 2011 5:46 am

Re: Multiplayer slow game server

#114 Post by o01eg »

Yes, it helpful. Could you enter gdb command catch throw and find source of this rethrowed exception?
I suppose it could be caused boost.serialize incompatibility between versions.
Gentoo Linux x64, gcc-11.2, boost-1.78.0
Ubuntu Server 22.04 x64, gcc-12, boost-1.74.0
Welcome to the slow multiplayer game at freeorion-lt.dedyn.io.Version 2024-03-15.b3de094.
Donations're welcome:BTC:bc1q007qldm6eppqcukewtfkfcj0naut9njj7audnm

o01eg
Programmer
Posts: 2004
Joined: Sat Dec 10, 2011 5:46 am

Re: Multiplayer slow game server

#115 Post by o01eg »

Could you also apply https://github.com/freeorion/freeorion/pull/2472 and enable trace for logging.execs.client?
Gentoo Linux x64, gcc-11.2, boost-1.78.0
Ubuntu Server 22.04 x64, gcc-12, boost-1.74.0
Welcome to the slow multiplayer game at freeorion-lt.dedyn.io.Version 2024-03-15.b3de094.
Donations're welcome:BTC:bc1q007qldm6eppqcukewtfkfcj0naut9njj7audnm

User avatar
Oberlus
Cosmic Dragon
Posts: 5714
Joined: Mon Apr 10, 2017 4:25 pm

Re: Multiplayer slow game server

#116 Post by Oberlus »

o01eg wrote: Mon Jun 10, 2019 4:55 pmenable trace for logging.execs.client?
How do I do that?
I'll try later, I'm leaving now.

o01eg
Programmer
Posts: 2004
Joined: Sat Dec 10, 2011 5:46 am

Re: Multiplayer slow game server

#117 Post by o01eg »

Oberlus wrote: Mon Jun 10, 2019 5:05 pm
o01eg wrote: Mon Jun 10, 2019 4:55 pmenable trace for logging.execs.client?
How do I do that?
I'll try later, I'm leaving now.
fo.png
fo.png (289.74 KiB) Viewed 1207 times
Gentoo Linux x64, gcc-11.2, boost-1.78.0
Ubuntu Server 22.04 x64, gcc-12, boost-1.74.0
Welcome to the slow multiplayer game at freeorion-lt.dedyn.io.Version 2024-03-15.b3de094.
Donations're welcome:BTC:bc1q007qldm6eppqcukewtfkfcj0naut9njj7audnm

User avatar
Oberlus
Cosmic Dragon
Posts: 5714
Joined: Mon Apr 10, 2017 4:25 pm

Re: Multiplayer slow game server

#118 Post by Oberlus »

I attach the log with the changes you said. It's heavy.
The catch throw, I dunno if I did it right: I first did run, then the catch throw (that said something about "catch 1" and nothing else) and then continue (which crashed the program).
Attachments
freeorion.log.zip
(3.65 MiB) Downloaded 76 times

o01eg
Programmer
Posts: 2004
Joined: Sat Dec 10, 2011 5:46 am

Re: Multiplayer slow game server

#119 Post by o01eg »

Oberlus wrote: Mon Jun 10, 2019 8:47 pm I attach the log with the changes you said. It's heavy.
The catch throw, I dunno if I did it right: I first did run, then the catch throw (that said something about "catch 1" and nothing else) and then continue (which crashed the program).
I've anticipated it fails on orders but it looks like there should be other step failing. Could you update to master and apply https://github.com/freeorion/freeorion/pull/2474 and again get logs.

I think there should be next way to catch desired exception:

Code: Select all

(gdb) catch throw
(gdb) run
... some exception thrown
(gdb) bt 
... check if it desired exception, or continue to catch next
(gdb) c
... until catch exception within ExtractGameStartMessageData
Edit: If we found it was caused by UI data I think it better to move their serialization to the end and ignore exceptions here. UI data is something less important compared to the game itself.
Gentoo Linux x64, gcc-11.2, boost-1.78.0
Ubuntu Server 22.04 x64, gcc-12, boost-1.74.0
Welcome to the slow multiplayer game at freeorion-lt.dedyn.io.Version 2024-03-15.b3de094.
Donations're welcome:BTC:bc1q007qldm6eppqcukewtfkfcj0naut9njj7audnm

User avatar
Oberlus
Cosmic Dragon
Posts: 5714
Joined: Mon Apr 10, 2017 4:25 pm

Re: Multiplayer slow game server

#120 Post by Oberlus »

Following is, maybe, the first catch from ExtractGameStartMessageData. I can't assure it because it throws dozens of exceptions from start, all from libstdc++.so.6, and at some point I stopped calling bt after continuing, just hitting up arrow and return as if I was playing Bubble Bubble. And this is the first exception that appears when the multiplayer lobby shows up. It's also the one that crashes the game, so hopefully it's the right one.

Code: Select all

Thread 1 "freeorion" hit Catchpoint 1 (exception thrown), 0x00007ffff2c868bd in __cxa_throw () from /usr/lib/x86_64-linux-gnu/libstdc++.so.6
(gdb) bt
#0  0x00007ffff2c868bd in __cxa_throw ()
   from /usr/lib/x86_64-linux-gnu/libstdc++.so.6
#1  0x00007ffff6e99c0d in ExtractGameStartMessageData (msg=..., 
    single_player_game=@0x7fffffffc46e: false, empire_id=@0x7fffffffc488: 3, 
    current_turn=@0x7fffffffc48c: 21, empires=..., universe=..., species=..., 
    combat_logs=..., supply=..., players=std::map with 1 elements = {...}, 
    orders=..., loaded_game_data=@0x7fffffffc46b: true, 
    ui_data_available=@0x7fffffffc46c: true, ui_data=..., 
    save_state_string_available=@0x7fffffffc46d: 127, save_state_string="", 
    galaxy_setup_data=...)
    at /home/lucas/Projects/FreeOrion/freeorion/network/Message.cpp:893
#2  0x00000000007e4877 in WaitingForGameStart::react (this=0x38804e0, msg=...)
    at /home/lucas/Projects/FreeOrion/freeorion/client/human/HumanClientFSM.cpp:852
#3  0x00000000007ff675 in boost::statechart::custom_reaction<GameStart>::react<WaitingForGameStart, boost::statechart::event_base, void const*> (stt=..., 
    evt=..., 
    eventType=@0x7fffffffc718: 0x1840330 <boost::statechart::detail::id_holder<GameStart>::idProvider_>)
    at /usr/include/boost/statechart/custom_reaction.hpp:41
#4  0x00000000007fe866 in boost::statechart::simple_state<WaitingForGameStart, PlayingGame, boost::mpl::list<mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, m---Type <return> to continue, or q <return> to quit---
pl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na>, (boost::statechart::history_mode)0>::local_react_impl_non_empty::local_react_impl<boost::mpl::list<boost::statechart::custom_reaction<GameStart>, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na>, boost::statechart::simple_state<WaitingForGameStart, PlayingGame, boost::mpl::list<mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na>, (boost::statechart::history_mode)0> > (stt=..., evt=..., 
    eventType=0x1840330 <boost::statechart::detail::id_holder<GameStart>::idProvider_>) at /usr/include/boost/statechart/simple_state.hpp:816
#5  0x00000000007fd7db in boost::statechart::simple_state<WaitingForGameStart, PlayingGame, boost::mpl::list<mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na>, (boost::statechart::history_mode)0>::local_react<boost::mpl::list<boost::statechart::custom_reaction<GameStart>, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na> > (this=0x38804e0, 
    evt=..., 
    eventType=0x1840330 <boost::statechart::detail::id_holder<GameStart>::idProvider_>) at /usr/include/boost/statechart/simple_state.hpp:851
---Type <return> to continue, or q <return> to quit---
#6  0x00000000007fc393 in boost::statechart::simple_state<WaitingForGameStart, PlayingGame, boost::mpl::list<mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na>, (boost::statechart::history_mode)0>::react_impl (this=0x38804e0, evt=..., 
    eventType=0x1840330 <boost::statechart::detail::id_holder<GameStart>::idProvider_>) at /usr/include/boost/statechart/simple_state.hpp:489
#7  0x00000000007a22cc in boost::statechart::detail::send_function<boost::statechart::detail::state_base<std::allocator<void>, boost::statechart::detail::rtti_policy>, boost::statechart::event_base, void const*>::operator() (
    this=0x7fffffffc830) at /usr/include/boost/statechart/state_machine.hpp:87
#8  0x0000000000799247 in boost::statechart::null_exception_translator::operator()<boost::statechart::detail::send_function<boost::statechart::detail::state_base<std::allocator<void>, boost::statechart::detail::rtti_policy>, boost::statechart::event_base, void const*>, boost::statechart::state_machine<HumanClientFSM, IntroMenu, std::allocator<void>, boost::statechart::null_exception_translator>::exception_event_handler> (this=0x1af5d40, action=...)
    at /usr/include/boost/statechart/null_exception_translator.hpp:33
#9  0x000000000078ff7e in boost::statechart::state_machine<HumanClientFSM, IntroMenu, std::allocator<void>, boost::statechart::null_exception_translator>::send_event (this=0x1af5cd0, evt=...)
    at /usr/include/boost/statechart/state_machine.hpp:885
#10 0x000000000078eae5 in boost::statechart::state_machine<HumanClientFSM, Intro---Type <return> to continue, or q <return> to quit---
Menu, std::allocator<void>, boost::statechart::null_exception_translator>::process_queued_events (this=0x1af5cd0)
    at /usr/include/boost/statechart/state_machine.hpp:910
#11 0x0000000000788187 in boost::statechart::state_machine<HumanClientFSM, IntroMenu, std::allocator<void>, boost::statechart::null_exception_translator>::process_event (this=0x1af5cd0, evt=...)
    at /usr/include/boost/statechart/state_machine.hpp:280
#12 0x0000000000774bac in HumanClientApp::HandleMessage (this=0x7fffffffcd50, 
    msg=...)
    at /home/lucas/Projects/FreeOrion/freeorion/client/human/HumanClientApp.cpp:989
#13 0x00000000007745f0 in HumanClientApp::HandleSystemEvents (
    this=0x7fffffffcd50)
    at /home/lucas/Projects/FreeOrion/freeorion/client/human/HumanClientApp.cpp:967
#14 0x00007ffff4127514 in GG::ModalEventPump::operator() (this=0x7fffffffcb70)
    at /home/lucas/Projects/FreeOrion/freeorion/GG/src/EventPump.cpp:113
#15 0x00007ffff5c0eb4c in GG::SDLGUI::Run (this=0x7fffffffd968)
    at /home/lucas/Projects/FreeOrion/freeorion/GG/src/SDL/SDLGUI.cpp:877
#16 0x00007ffff419795f in GG::GUI::operator() (this=0x7fffffffd968)
    at /home/lucas/Projects/FreeOrion/freeorion/GG/src/GUI.cpp:1181
#17 0x00007ffff5c0d94a in GG::SDLGUI::operator() (this=0x7fffffffd968)
    at /home/lucas/Projects/FreeOrion/freeorion/GG/src/SDL/SDLGUI.cpp:527
---Type <return> to continue, or q <return> to quit---
#18 0x0000000000743f5c in mainSetupAndRun ()
    at /home/lucas/Projects/FreeOrion/freeorion/client/human/chmain.cpp:300
#19 0x000000000073f9cf in main (argc=1, argv=0x7fffffffdd18)
    at /home/lucas/Projects/FreeOrion/freeorion/client/human/chmain.cpp:104
(gdb) c
Continuing.
terminate called after throwing an instance of 'std::exception'
  what():  std::exception

Thread 1 "freeorion" received signal SIGABRT, Aborted.
0x00007ffff2345428 in __GI_raise (sig=sig@entry=6)
    at ../sysdeps/unix/sysv/linux/raise.c:54
54	../sysdeps/unix/sysv/linux/raise.c: No such file or directory.
(gdb)
Find attached the second half of the log with the changes from PR 2427 (if you need the first half let me know). But I'm sorry I failed to update to master first (I forgot that step, compiled with the PR and was too lazy to wait for a new compilation).
Attachments
2ndHalf_freeorion.log.zip
(3.61 MiB) Downloaded 78 times

Post Reply