sn_SetNetState: Unable to open accept socket on desired port xxxx, Trying next ports...

For all the help you need with Armagetron!
User avatar
Galaxip
Average Program
Posts: 57
Joined: Wed Aug 24, 2016 10:49 pm

sn_SetNetState: Unable to open accept socket on desired port xxxx, Trying next ports...

Post by Galaxip »

I have found an issue with armagetron dedicated server build 0.2.8-armagetronad-sty+ct/src

If the server spawns a script and the script is running when all players leave the game then the server loses its connection on the port specified by SERVER_PORT and starts trying port numbers and will make a connetion but on a different port number

I added code to the script to detect GAME_END from lagger log and issue an EXIT command to console so that the server will restart but it still cannot connect on the original SERVER_PORT , but after checking the console log I see that GAME_END is executed after the server attempts the connection so that doesnt really help

I even tried KILL $PPID from the script to kill the parent process (the server) and has the same effect as EXIT

As a test I made a basic server and spawned an infinite loop script that does nothing just to see if the echo to console for commands was the problem in my main game script but even this script that does nothing causes the same issue

Without any scripts running the server always will connect to SERVER_PORT after all players leave

This is the donothing.sh script I used to test the issue, I even tried it without the sleep just in case but it made no difference

Code: Select all

#!/bin/bash
while true;
do
sleep 1
done
I would like to solve this because rebooting the server doesnt fix the issue and I cant keep opening up more ports on my firewall because the server keeps incrementing the port number

Any ideas ? Thanks

BTW the other 5 servers that are running on the same raspberry pi but dont currently use scripts are working fine and never have a problem connecting to SERVER_PORT after all the players leave the game

Thanks

--------------------------

Update: if I connect to the server console screen with screen -r server6 and then press CTRL-C to shut down screen and the server, then start them back up I find that the server will connect to the correct SERVER_PORT
Last edited by Galaxip on Tue May 19, 2020 11:10 pm, edited 1 time in total.
Image Image Image

User avatar
Galaxip
Average Program
Posts: 57
Joined: Wed Aug 24, 2016 10:49 pm

Re: sn_SetNetState: Unable to open accept socket on desired port xxxx, Trying next ports...

Post by Galaxip »

Ive also found that if I kill the script and all players leave the game it randomly either stays on the SERVER_PORT or fails and trys a new port
Image Image Image

User avatar
Galaxip
Average Program
Posts: 57
Joined: Wed Aug 24, 2016 10:49 pm

Re: sn_SetNetState: Unable to open accept socket on desired port xxxx, Trying next ports...

Post by Galaxip »

I wrote a really dangerous bit of code and added it to src/render/rConsoleCout.cpp to test whats happening, this is the most simplest of script that uses the system() function to pass on a command to linux

I first tested it with /admin my_script ls and that gave a listing of the script directory contents on the console so I knew it was working

next I tested it with /admin my_script ./donothing.sh& and it showed up in htop as running

after that was confirmed I exited the server

the server did exactly the same thing it lost connection from SERVER_PORT and connected on the next available port number which is outside the range I have setup in my firewall

if anyone has any clue how to fix this please let me know because i am unable to develop any interesting scripted games, I cant even run my top ten players display script at the end of a match because of this issue

Thanks

Code: Select all

// myscript command WARNING: EXTREMELY DANGEROUS DONT TRY THIS AT HOME
static void myScript( std::istream & s )
{
        tString command;
        command.ReadLine(s);
        system( command );
}

static tConfItemFunc myScript_conf( "MY_SCRIPT", myScript );
Last edited by Galaxip on Wed May 20, 2020 1:37 am, edited 2 times in total.
Image Image Image

User avatar
kyle
Reverse Outside Corner Grinder
Posts: 1850
Joined: Thu Jun 08, 2006 3:33 pm
Location: Indiana, USA, Earth, Milky Way Galaxy, Universe, Multiverse
Contact:

Re: sn_SetNetState: Unable to open accept socket on desired port xxxx, Trying next ports...

Post by kyle »

I know this is just a workaround, but the way I ran servers was with a python script to force killing the full screen session and then restarting them.

I thought it was because a SIGHUP was being sent when the screen session was killed, which made the armagetron process reload

Code: Select all

def killScreenPid(screenname):
    processes = getoutput("screen -ls "+screenname).split('\n')
    for  i in range(0, len(processes)):
        pid = processes[i].strip()
        if(search(compile("^\d+\."+screenname, I), pid)):
            test=pid.find("."+screenname)
            kill_process(int(pid.rsplit("."+screenname)[0]))
def kill_process(pid):
    print "process "+str(pid)
    pids = getoutput("ps -o pid --no-headers --ppid "+str(pid)).split('\n')
    if len(pids) > 0 and pids[0]!="":
        for kiddie in pids:
            kill_process(int(kiddie))
    print "killing process "+ str(pid)
    try:
        kill(pid, SIGKILL)
    except:
        print "could not kill"
This restart was triggered on the second time the console log said

Code: Select all

search(compile("^\[\d+\] Nobody there. Taking a nap\.\.\.", I), line)
I had a bit more to the code than that, as we also had some invalid commands handled to send errors and restart too. I'll see if I can clean it up a bit and post it on github or something.
Image

User avatar
Galaxip
Average Program
Posts: 57
Joined: Wed Aug 24, 2016 10:49 pm

Re: sn_SetNetState: Unable to open accept socket on desired port xxxx, Trying next ports...

Post by Galaxip »

thanks kyle i'll have a look into this, I have noticed that if I CTRL-C while on the screen session that the server and screen shuts down and after that i restart the server and it always connects to SERVER_PORT (well so far lol) so I had thought about killing screen

I alread have tried KILL $PPID from the script when GAME_END is detected but that only kills armagetron and i havent worked out how to find the PPID of the PPID to find the pid of the screen that started the server XD


do you possibly know what causes this issue in armagetron ?

ive been looking through the server sourcecode trying to get my head around it , its a horrible task

i would love to fix it so these workarounds wouldnt be needed

its such a strange bug i really cant understand whats going on
Image Image Image

User avatar
kyle
Reverse Outside Corner Grinder
Posts: 1850
Joined: Thu Jun 08, 2006 3:33 pm
Location: Indiana, USA, Earth, Milky Way Galaxy, Universe, Multiverse
Contact:

Re: sn_SetNetState: Unable to open accept socket on desired port xxxx, Trying next ports...

Post by kyle »

Not really, CT basically always would restart the servers when it emptied, I never questioned it or looked into it. I more or less added the recursive process killing to it when killing the screen session did not completely kill the process anymore. My understanding at the time of that was that the screen command was updates and they changed it from sending a SIGKILL to a SIGHUP signal when the screen session was closed. The SIGHUP is tied to the game reloading, I did have a change to make it kill it at that time, but from my understanding the SIGHUP is used for startup processes.

I believe gGame.cpp would be the place to start looking though.
Image

User avatar
Galaxip
Average Program
Posts: 57
Joined: Wed Aug 24, 2016 10:49 pm

Re: sn_SetNetState: Unable to open accept socket on desired port xxxx, Trying next ports...

Post by Galaxip »

I just ran pstree to see how nested this is, heres a snippet of its output

Code: Select all

|-screen(8298)---serverstart.sh(8300)-+-armagetronad-de(8318)
|                                     `-tee(8320)
|-screen(8314)---serverstart.sh(8316)-+-armagetronad-de(8340)
|                                     `-tee(8341)
|-screen(8332)---serverstart.sh(8335)-+-armagetronad-de(8356)
|                                     `-tee(8357)
|-screen(8352)---serverstart.sh(8354)-+-armagetronad-de(8375)
|                                     `-tee(8376)
|-screen(8371)---serverstart.sh(8374)-+-armagetronad-de(8391)
|                                     `-tee(8392)
|-screen(8393)---serverstart.sh(8394)-+-armagetronad-de(8402)
|                                     `-tee(8403)
I might be able to write something to grab the pid of the screen that is in the same path as the armagetron that matches the $PPID value read via the spawned script and then kill that pid which should kill everything, i'll have to rewrite the way I start the servers because currently i start the screen session from my server.sh like this server.sh start server1 4534 classic.game which starts a screen session called server1 then starts serverstart.sh with the port number and game config, servers are shutdown by server.sh stop server1 which also shuts down the screen session

if I move the screen code into serverstart.sh I think it will work
Image Image Image

User avatar
Galaxip
Average Program
Posts: 57
Joined: Wed Aug 24, 2016 10:49 pm

Re: sn_SetNetState: Unable to open accept socket on desired port xxxx, Trying next ports...

Post by Galaxip »

thanks kyle i didnt see your post until just now, I took too long typing all that stuff XD
Image Image Image

User avatar
kyle
Reverse Outside Corner Grinder
Posts: 1850
Joined: Thu Jun 08, 2006 3:33 pm
Location: Indiana, USA, Earth, Milky Way Galaxy, Universe, Multiverse
Contact:

Re: sn_SetNetState: Unable to open accept socket on desired port xxxx, Trying next ports...

Post by kyle »

This was CT's startup script on just about every service, the parser screen was were we ran the script manually. restart.py is the script I gave you part of, that set up the 2 screens to run. you should only need 1 the way you are strating a script

Code: Select all

#!/bin/bash
server=$(basename $(dirname `pwd`))
cdir=$(dirname `pwd`)
screen -XS ${server}_real quit
screen -XS ${server}_parser quit
tail -n1 -f ${cdir}/var/console_log.txt | ./restarter.py
Image

User avatar
Galaxip
Average Program
Posts: 57
Joined: Wed Aug 24, 2016 10:49 pm

Re: sn_SetNetState: Unable to open accept socket on desired port xxxx, Trying next ports...

Post by Galaxip »

ive just spent around 6 hours looking through the game source code to find this bug, i must be getting close :P
Image Image Image

User avatar
kyle
Reverse Outside Corner Grinder
Posts: 1850
Joined: Thu Jun 08, 2006 3:33 pm
Location: Indiana, USA, Earth, Milky Way Galaxy, Universe, Multiverse
Contact:

Re: sn_SetNetState: Unable to open accept socket on desired port xxxx, Trying next ports...

Post by kyle »

Ah those are the days :)

you never know how much longer until you find it, but when you do it's fixed in a few minutes.
Image

User avatar
Z-Man
God & Project Admin
Posts: 11292
Joined: Sun Jan 23, 2005 6:01 pm
Location: Cologne, Jabber: [email protected]
Contact:

Re: sn_SetNetState: Unable to open accept socket on desired port xxxx, Trying next ports...

Post by Z-Man »

Before you dig into it too deep, check the server's output. It logs what it's doing with the sockets. For example, I tend to see

Code: Select all

[0] Closing socket bound to *.*.*.*:4534
[0] Bound socket to *.*.*.*:4534.
That's the expected behavior: we close the socket, we reopen it right away.
There have been cases, though I don't remember any specifics, where we would close a socket, but then re-opening a socket on the same port would fail because the OS kept it reserved for some bit for whatever reason.

User avatar
Galaxip
Average Program
Posts: 57
Joined: Wed Aug 24, 2016 10:49 pm

Re: sn_SetNetState: Unable to open accept socket on desired port xxxx, Trying next ports...

Post by Galaxip »

heres a bit of the console log that shows the problem

[0] Bound socket to *.*.*.*:51667. <------- should this be here ?
[0] sn_SetNetState: Unable to open accept socket on desired port 4539, Trying next ports...
[0] Bound socket to *.*.*.*:4540.

see below

Code: Select all

[0] Closing socket bound to *.*.*.*:4539
[0] Bound socket to *.*.*.*:4539.
[0] Nobody there. Taking a nap...
[0] Timestamp: 2020/05/21 02:22:34
[0] Closing socket bound to *.*.*.*:4539
[0] Bound socket to *.*.*.*:4539.
[1] Received login from 192.168.0.1:49225 via socket *.*.*.*:4539, network version: 0.2.8.3.X (ID: 16).
[1] New user: 1
[1] fujipop entered the game.
[1] User 1 requests authentication as "[email protected]".
[0] Time:     27.2053 seconds
Sent:     21090 bytes in 216 packets (775.218 bytes/s)
Received: 8450 bytes in 150 packets (310.602 bytes/s)
[0] Timestamp: 2020/05/21 02:22:42
[0] Creating grid...
[0] Robby entered the game.
[0] Gort entered the game.
[0] R2D2 entered the game.
[0] Hal 9000 entered the game.
[0] done!
[0] Resetting scores...
[0] New Match
[0] Go (round 1 of 10)!
[0] 3
[0] 2
[0] 1
[0] 0
[1] Remote admin command by fujipop: delay_command +0 spawn_script loop.sh
[0] Launching external command '/home/pi/armagetronad/servers/server6//scripts/loop.sh'...
[0] spawn_script  loop.sh 0
[0] loop.sh : console_message infinite loop
[0] infinite loop
[0] loop.sh : console_message infinite loop
[0] infinite loop
[0] loop.sh : console_message infinite loop
[0] infinite loop
[0] loop.sh : console_message infinite loop
[0] infinite loop
[1] received logout from 1.
[1] fujipop left the game.
[1] Killing user 1, ping 0.0512739, IP 192.168.0.1:49225: You logged out regularly.
[0] loop.sh : console_message infinite loop
[0] infinite loop
[0] Closing socket bound to *.*.*.*:4539
[0] Closing socket bound to *.*.*.*:49257
[0] Hal 9000 left AI team.
[0] R2D2 left AI team.
[0] Gort left AI team.
[0] Robby left the game.
[0] Bound socket to *.*.*.*:51667.
[0] sn_SetNetState: Unable to open accept socket on desired port 4539, Trying next ports...
[0] Bound socket to *.*.*.*:4540.
[0] Setting CYCLE_INVULNERABLE_TIME (Group: Bumpy) deviates from its default value; clients older than 0.2.8_alpha20060414 will not be allowed in.
[0] Connecting to Master Server 1...
[0] Login information sent. Waiting for reply...
[0] Got address 151.227.52.155:4540.
[0] Login Succeeded. User Nr. 1 
[0] Syncing with server...
[0] Relabeling NetObjects...
[0] Syncing again...
[0] Done!
[0] Sending my server info...
[0] Logging out...
[0] Done!
[0] Closing socket bound to *.*.*.*:4540
[0] Bound socket to *.*.*.*:4540.
[0] Setting CYCLE_INVULNERABLE_TIME (Group: Bumpy) deviates from its default value; clients older than 0.2.8_alpha20060414 will not be allowed in.
Thanks
Image Image Image

User avatar
Galaxip
Average Program
Posts: 57
Joined: Wed Aug 24, 2016 10:49 pm

Re: sn_SetNetState: Unable to open accept socket on desired port xxxx, Trying next ports...

Post by Galaxip »

in src/tron/gGame.cpp the function sg_HostGame starting at line 2226 ive spotted something that looks out of place I might be wrong ?

down around line 2294 theres this #endif between the if and the own_game it just looks out of place

if (!uMenu::quickexit)
#endif
//#endif
own_game( nSERVER );
Image Image Image

User avatar
Z-Man
God & Project Admin
Posts: 11292
Joined: Sun Jan 23, 2005 6:01 pm
Location: Cologne, Jabber: [email protected]
Contact:

Re: sn_SetNetState: Unable to open accept socket on desired port xxxx, Trying next ports...

Post by Z-Man »

Galaxip wrote:
Thu May 21, 2020 2:06 pm
[0] Bound socket to *.*.*.*:51667. <------- should this be here ?
Yes. That's the socket the server uses to communicate with the master server.
Galaxip wrote:
Thu May 21, 2020 2:06 pm

Code: Select all

...
[0] Closing socket bound to *.*.*.*:4539
[0] Closing socket bound to *.*.*.*:49257
[0] Hal 9000 left AI team.
[0] R2D2 left AI team.
[0] Gort left AI team.
[0] Robby left the game.
[0] Bound socket to *.*.*.*:51667.
[0] sn_SetNetState: Unable to open accept socket on desired port 4539, Trying next ports...
[0] Bound socket to *.*.*.*:4540.
Well, that is your favorite port getting closed for sure, it should be available then again, but isn't.
Mitigation: Put

Code: Select all

SERVER_PORT 4549
into everytime.cfg, that should at least keep the port from increasing out of bounds, provided the ports are not permanently blocked.
Galaxip wrote:
Fri May 22, 2020 12:59 pm
in src/tron/gGame.cpp the function sg_HostGame starting at line 2226 ive spotted something that looks out of place I might be wrong ?

down around line 2294 theres this #endif between the if and the own_game it just looks out of place

if (!uMenu::quickexit)
#endif
//#endif
own_game( nSERVER );
Which one? The active one is the end of #ifdef DEDICATED above, it ends the "napping" section. Yeah, it's not really super clean style to have preprocessor stuff interact with code that way and you're right to be suspicious, but it's intended.

Post Reply