[lacks info] r4021: Linux64 game host freezes after first command

[tomreyn]

I would not know how to reproduce it, but for completeness I'll report this anyways and tag it with [lacks info]:

I was hosting a game today on my atibox (specs below) with the EnableNewThreadManager option set. The host was using r4021 and there was a single client which was using 3.7.1. The game (with the other player against AI players) started up fine, but as soon as I had given my workers the command to dig some gold (I'm not sure whether or not this worked as a trigger), the game froze. The OS mouse pointer was still moving but I could not interact with anything in the game, and the workers had frozen, too. The music continued to play. I needed to kill -9  it to make the megaglest process stop (plain 'kill' did not work).

Here's a backtrace on the frozen process (I did 5 in a row, and they all looked exactly the same):

Code: [Select]

0x00007f6816497303 in __GI___poll (fds=<optimized out>, fds@entry=0x7fffdef0ff80, nfds=<optimized out>, nfds@entry=1, timeout=<optimized out>, timeout@entry=-1) at ../sysdeps/unix/sysv/linux/poll.c:87
#0  0x00007f6816497303 in __GI___poll (fds=<optimized out>, fds@entry=0x7fffdef0ff80, nfds=<optimized out>, nfds@entry=1, timeout=<optimized out>, timeout@entry=-1) at ../sysdeps/unix/sysv/linux/poll.c:87
#1  0x00007f6814b3d972 in _xcb_conn_wait (c=c@entry=0x139a790, cond=cond@entry=0x7fffdef0fff0, vector=vector@entry=0x0, count=count@entry=0x0) at ../../src/xcb_conn.c:400
#2  0x00007f6814b3ee47 in wait_for_reply (c=c@entry=0x139a790, request=54220, e=e@entry=0x7fffdef100a8) at ../../src/xcb_in.c:390
#3  0x00007f6814b3f06b in xcb_wait_for_reply (c=0x139a790, request=54220, e=0x7fffdef100a8) at ../../src/xcb_in.c:420
#4  0x00007f68199a7289 in _XReply () from /usr/lib/x86_64-linux-gnu/libX11.so.6
#5  0x00007f6819ce6e03 in DRI2GetBuffersWithFormat (dpy=0x1399400, drawable=44040207, width=width@entry=0x150a558, height=height@entry=0x150a55c, attachments=0x7fffdef10240, count=2, outCount=outCount@entry=0x7fffdef1022c) at dri2.c:483
#6  0x00007f6819ce48dc in dri2GetBuffersWithFormat (driDrawable=<optimized out>, width=0x150a558, height=0x150a55c, attachments=<optimized out>, count=<optimized out>, out_count=0x7fffdef1022c, loaderPrivate=0x150a450) at dri2_glx.c:782
#7  0x00007f680b3e821d in dri2_drawable_get_buffers (count=<synthetic pointer>, statts=<optimized out>, drawable=0x150a570) at dri2.c:184
#8  dri2_allocate_textures (drawable=0x150a570, statts=<optimized out>, count=<optimized out>) at dri2.c:389
#9  0x00007f680b3e9750 in dri_st_framebuffer_validate (stfbi=<optimized out>, statts=0x150ab60, count=2, out=0x7fffdef10340) at dri_drawable.c:78
#10 0x00007f680b423e96 in st_framebuffer_validate (stfb=stfb@entry=0x150a720, st=0x1502c00, st=0x1502c00) at ../../../../src/mesa/state_tracker/st_manager.c:195
#11 0x00007f680b4253c5 in st_manager_validate_framebuffers (st=st@entry=0x1502c00) at ../../../../src/mesa/state_tracker/st_manager.c:829
#12 0x00007f680b58e66c in st_validate_state (st=st@entry=0x1502c00) at ../../../../src/mesa/state_tracker/st_atom.c:170
#13 0x00007f680b59b317 in st_readpixels (ctx=0x1495300, x=<optimized out>, y=<optimized out>, width=1, height=<optimized out>, format=<optimized out>, type=5126, pack=0x149bb70, dest=0x7fffdef10560) at ../../../../src/mesa/state_tracker/st_cb_readpixels.c:52
#14 0x00007f680b48d3bc in _mesa_ReadnPixelsARB (x=999, y=483, width=1, height=1, format=6402, type=5126, bufSize=bufSize@entry=2147483647, pixels=pixels@entry=0x7fffdef10560) at ../../../../src/mesa/main/readpix.c:800
#15 0x00007f680b48d44a in _mesa_ReadPixels (x=<optimized out>, y=<optimized out>, width=<optimized out>, height=<optimized out>, format=<optimized out>, type=<optimized out>, pixels=0x7fffdef10560) at ../../../../src/mesa/main/readpix.c:808
#16 0x00000000006068a4 in Glest::Game::Renderer::computePosition (this=0xdf2f60 <Glest::Game::Renderer::getInstance()::renderer>, screenPos=..., worldPos=..., exactCoords=<optimized out>) at /home/tomreyn/SCM/megaglest-trunk/source/glest_game/graphics/renderer.cpp:6617
#17 0x000000000058cb50 in Glest::Game::Game::mouseMove (this=0x1a2de30, x=595, y=345, ms=<optimized out>) at /home/tomreyn/SCM/megaglest-trunk/source/glest_game/game/game.cpp:3479
#18 0x0000000000647a89 in Glest::Game::MainWindow::eventMouseMove (this=0x1418ad0, x=<optimized out>, y=566, ms=0xdf7a00 <Shared::Platform::Window::mouseState>) at /home/tomreyn/SCM/megaglest-trunk/source/glest_game/main/main.cpp:917
#19 0x00000000009afd25 in Shared::Platform::Window::handleEvent () at /home/tomreyn/SCM/megaglest-trunk/source/shared_lib/sources/platform/sdl/window.cpp:188
#20 0x00000000006766a5 in Glest::Game::glestMain (argc=argc@entry=2, argv=argv@entry=0x7fffdef168e8) at /home/tomreyn/SCM/megaglest-trunk/source/glest_game/main/main.cpp:4905
#21 0x0000000000678d69 in Glest::Game::glestMainWrapper (argc=2, argv=0x7fffdef168e8) at /home/tomreyn/SCM/megaglest-trunk/source/glest_game/main/main.cpp:5171
#22 0x00007f68163d076d in __libc_start_main (main=0x502dd0 <main(int, char**)>, argc=2, ubp_av=0x7fffdef168e8, init=<optimized out>, fini=<optimized out>, rtld_fini=<optimized out>, stack_end=0x7fffdef168d8) at libc-start.c:226
#23 0x0000000000509289 in _start ()

The client just received a "timeout waiting for server" message (as expected).

I guess this can be a mesa issue, it's hard to tell. After this game I played another game with similar setup (i was hosting on the same revision and with the same INI setting, and there was one other human player on 3.7.1 as well as some CPU's) and there were no such issues

[softcoder]

Let me know if this happens again and as many details around when it occurred as possible.

[tomreyn]

We reproduced this yesterday, playing a game i was hosting with several players including nig. We were are to reproduce it repeatedly with different players. The only static factors were (a) me hosting, (b) nig and TotalNoob playing. When we tried once more without nig connected there was no issue, so it wasn't reprodcible then.

What happened is this: I start a game with nig and several other network players, it initializes as always, the game starts, but roughly 3 seconds later it freezes (roman idle worker animation stops, mouse clicks and chat are not possible, the game does not react to any input, the music continues, though. About a minute later, the initialization screen shows again (why is this still in memory at all at this point?) for ~ 10 seconds. Then I'm back to the game, it's still frozen, but now i get disconnect messages for all players. Once all players are disconnected the game continues on high speed.

I've made verbose and network debug logs available to softcoder. Thanks for looking into it.

This as well as the initial report above was with the new thread manager. I have't had a chance to try this with Nig (and possibly others) without the new thread manager, yet. But I have it enabled now and next time I canplay a game with nig it should show whether it makes a difference.

[nig]

was this on 16.1.  around 20:21? then you can get my (windows client) debuglog here: http://www.fastshare.org/download/timeoutdebug.log

greets

[tomreyn]

Yes, that's the very same game. Thanks for providing your log file, which I have copied and compressed (decreasing the file size from 149 MB to 7 MB) and made available on another server. Could you also provide your glestuser.ini, please (has anything changed in it since we were playing?)?

[nig]

yes, sorry I forget to compress that one.

ini-files here: http://megaglest.pzt.me/050s   I added one line after the game, as I told you on irc. its marked in glestuser.ini

greets

[softcoder]

Do you still have this problem with the latest svn?

[tomreyn]

I don't hink it ever happened to me again, but it would be better to hear from Nig.

[nig]

the instant error never appeared again for me, although it was reproducable in those days.
But my activity playing glest have become less during the last week and I took the windows-dev headless urg offline again because i think its too frustrating that games break after 15 Min or longer quite often.
So the dissapearing of that bug might be not representative.

Greets

[nig]

Ladys and Gentleman!
There it is again:

I did three network games today with 4064.
All on headless Linux 3.7.1 and one other player.

In first one i was thrown out with Time out after 15 minutes or so.
then iplayed around with the "anarchy setting" mentioned in the other thread.

then I did another networkgame, which came to an end, but had some strange laggy moments (freeze for 1 to 5 secs and then hunting to sync in ultra speed ). Happened round about 5 times.

after that i tried again to log in headless for another game: bang!
 immidiate crash

restart glest try to login in headless: bang!
immidiate crash!

thats the exact behaviour for me like the days tom reported above.
In those days I reinstalled MG complete new and that does the trick.

Funny: there are two errors showing up: first:



if you press ok on the error window of OS, the second error appears:



after that Iwrote this post and tried to start a local game. that worked.
after that I tried to login on headless again without changing anything.

and it worked!

So may be, i just had to wait for windows to settle down after that crash? Anyway, looks for me quite similar to the event we had those days.

Greets

 

[softcoder]

This last error seems to come from the file transfer client. I tried a fix in svn, let me know if the crash on connect happens again.

[nig]

today on 4065:

First network game was on that thai-headless with nevsky. Got disconnected after some laggy seconds as described above.
disconnect window was the same like server is quitting on slf hosted game. "error detected, player nig disconnected"

MG did not crash

In Memory of yesterday i tried log in on headless. that worked.

Than I fumbled around with Graphic card drivers.

than i wanted to start a game on german headless.... bang! immediate crash! logs: http://www.datafilehost.com/download-1a986d7f.html
tried again.. bang! immediate crash! logs: http://www.datafilehost.com/download-e815f9f4.html
tried again ... bang! immediate crash! too tired for more logs ...

then I cleared the cache - directory in the logpath directory , did nothing else    and tried again    .... working!

Is the immidiate crash just a bug in the loggingroutine after disconncecting?

Greets

[tomreyn]

This, taken from the very bottom of the first network.log (when you tried to do stuff on summoner), looks unhealthy to me:

Code: [Select]

[2013-01-29 21:21:25] Connecting to host [78.47.225.60] on port = 61357
[2013-01-29 21:21:25] In [..\..\source\shared_lib\sources\platform\posix\socket.cpp::Shared::Platform::ClientSocket::connect Line: 1821] #2 Error connecting socket for IP: 78.47.225.60 for Port: 61357 err = -1 error = (Error: 10035 - [: Operation would block (10035)])
[2013-01-29 21:21:25] In [..\..\source\shared_lib\sources\platform\posix\socket.cpp::Shared::Platform::ClientSocket::connect Line: 1832] PLATFORM_SOCKET_INPROGRESS in connect() - selecting
[2013-01-29 21:21:25] In [..\..\source\shared_lib\sources\platform\posix\socket.cpp::Shared::Platform::ClientSocket::connect Line: 1877] Apparent recovery for connection sock = 2064, err = 1
[2013-01-29 21:21:25] In [..\..\source\shared_lib\sources\platform\posix\socket.cpp::Shared::Platform::ClientSocket::connect Line: 1898] Valid recovery for connection sock = 2064, err = 1, error = (Error: 0 - [: No error (0)])
[2013-01-29 21:21:25] In [client_interface.cpp::Glest::Game::ClientInterface::connect] END - socket = 2064
[2013-01-29 21:21:25] In [..\..\source\shared_lib\sources\platform\posix\socket.cpp::Shared::Platform::Socket::peek Line: 1546] #2 SOCKET appears to be invalid [2064]
[2013-01-29 21:21:25] In [..\..\source\shared_lib\sources\platform\posix\socket.cpp::Shared::Platform::Socket::peek Line: 1546] #2 SOCKET appears to be invalid [2064]
[2013-01-29 21:21:25] In [..\..\source\shared_lib\sources\platform\posix\socket.cpp::Shared::Platform::Socket::peek Line: 1546] #2 SOCKET appears to be invalid [2064]
[2013-01-29 21:21:25] In [..\..\source\shared_lib\sources\platform\posix\socket.cpp::Shared::Platform::Socket::peek Line: 1546] #2 SOCKET appears to be invalid [2064]
[2013-01-29 21:21:25] In [network_interface.cpp::Glest::Game::NetworkInterface::getNextMessageType Line: 59] socket->getDataToRead() dataSize = 236
[2013-01-29 21:21:25] In [..\..\source\shared_lib\sources\platform\posix\socket.cpp::Shared::Platform::Socket::peek Line: 1546] #2 SOCKET appears to be invalid [2064]

[nig]

well, I did nothing to "summoner", I just pressed the button "join game" in the lobby. What do you mean?

[tomreyn]

I'm just trying to identify a relevant position in the log. This is mostly directed at Softcoder.

[nig]

i had the sudden closing by connecting to headless again yesterday with 4080. It happened two times one after each other. I saved the cache to try to reproduce this error.
Then I cleared the cache and there was no problem to connect to headless.

After that I restored the cache and tried to connect with the headless again. That worked with no problems.

Although clearing the cache seems to help if you cannot connect  to headless, is this error not reproducable with just the content of the cache. I am not sure, but I think this connction issues only appear after a crash by ZwGet or the sudden closing. I will have an eye on that.

Greets

[softcoder]

Ok try svn now and lets see if the crashes are finally fixed or not.

[tomreyn]

This report seems to mix a whole lot of different issues, and I'm not aware of any of them still being present in current revisions. There also was no reply to the request to re-test for months, so I'll tag this as [lacks info] and move it to closed bugs.