Servers stopped due to dedicated server login disconnection.. ?!

[Harest]

Hi,

Just saw by luck that yesterday the 2 servers i've were stopped for some reason, not sure why exactly. Anyone knows ?
I've only the logs for one of them and there's no error message like a disconnection from the master server or else. It just states that the dedicated server login disconnected... I'd like some details on this.
Latest lines in the console log :

Code: Select all

[2018/08/10 18:44:28] Loading map TM-141647.Map.Gbx (b0NWXqo7wVfGh3c9mRIBxCfSd7c)...
[2018/08/10 18:44:28] ...Load succeeds
[2018/08/10 18:44:30] Starting Match...
[2018/08/10 18:44:30] ...Synchronization
[2018/08/10 18:44:32] ...Play
[2018/08/10 18:53:48] ...Finish
[2018/08/10 18:53:48] ...Exit
[2018/08/10 18:53:48] Loading map Deep_Down_Remake.Map.Gbx (iev71qhLxKzDneBIfC_03uBa2qk)...
[2018/08/10 18:53:48] ...Load succeeds
[2018/08/10 18:53:50] Starting Match...
[2018/08/10 18:53:50] ...Synchronization
[2018/08/10 18:53:52] ...Play
[2018/08/10 19:02:29] Connection of a new player: kylianator(xx.xx.xx.xx:2350)
[2018/08/10 19:03:07] ...Finish
[2018/08/10 19:03:08] ...Exit
[2018/08/10 19:03:08] Loading map TM-111710.Map.Gbx (EzrGHGSHOYb6WVLu7pa2QSOJoUb)...
[2018/08/10 19:03:08] ...Load succeeds
[2018/08/10 19:03:10] Starting Match...
[2018/08/10 19:03:10] ...Synchronization
[2018/08/10 19:03:16] ...Play
[2018/08/10 19:09:35] ...Exit
[2018/08/10 19:09:36] Disconnection of _harest(5.135.188.23:2350)
[2018/08/10 19:09:36] Exiting...
[2018/08/10 19:09:36] Disconnection of _harest(5.135.188.23:2350)

I just restarted them without any issue.

Just to update the OP :

... I asked Jon from Drakonia (in french) and he basically told me that "server[s] crash after 21-22 days or so, it's a limitation for the time being".

[Harest]

It apparently happened again this morning. Do i need to do a cron task now to check if my servers are up (and if not start them again) because for currently unknown reason the servers stop when they want on their own ?

Code: Select all

[2018/09/05 09:21:37] Loading map TM-141807.Map.Gbx (PGpFdaIUIqu3Hxi4NWTcMlxNMj5)...
[2018/09/05 09:21:38] ...Load succeeds
[2018/09/05 09:21:39] Starting Match...
[2018/09/05 09:21:39] ...Synchronization
[2018/09/05 09:21:41] ...Play
[2018/09/05 09:38:37] ...Finish
[2018/09/05 09:38:37] ...Exit
[2018/09/05 09:38:37] Loading map TM-127299.Map.Gbx (0S28D96GdzJgSbPXb51WnswoWi)...
[2018/09/05 09:38:38] ...Load succeeds
[2018/09/05 09:38:39] Starting Match...
[2018/09/05 09:38:39] ...Synchronization
[2018/09/05 09:38:41] ...Play
[2018/09/05 09:41:59] ...Exit
[2018/09/05 09:41:59] Disconnection of _harest(5.135.188.23:2350)
[2018/09/05 09:42:00] Exiting...
[2018/09/05 09:42:00] Disconnection of _harest(5.135.188.23:2350)

I wish Nadeo staff would answer issues on this forum a bit more often. It's like the tm rpg major issue where mods are always re-downloaded... Nothing.

[fng_thatoneguy]

I’m not sure what could be going on either but I do have some questions to help isolate the cause:

1. Is the internet connection where the servers are hosted stable and working well? If there are pauses in service for a few seconds periodically, could that be causing the mysterious disconnects?

2. How often does this happen? Is there a time frame you can feel comfortable it won’t happen again if it stays connected for a certain timeframe (ex: 36 hours)?

3. Are you running a server controller? Have you tried running the server without the controller for the time frame mentioned above to make sure it isn’t contributing to the problem?

4. What game mode or script are you running the server on? Do other modes make a difference?

5. When the problem occurs, do all or your servers fail at the same time? Or does it only affect some of them?

[reaby]

And if i may also ask how did you setup your dedicated server account, do you use your normal login for the server as well ?
Since for trackmania2 there's dedicated server accounts different than normal playing accounts.

Please check the dedicated server setup tutorial for more info if you use your normal login for the dedicated server.

[Harest]

@fng_thatoneguy :

1. They're hosted on a dedicated server from OVH, so i assume the connection is great, yes. I tried to check if there was any disconnection but i'm not sure exactly where i could see that. From the log files i checked i saw nothing relevant. To be fair i think if there was any disconnection, i'd have received an email. This kind of stuff is monitored by default from OVH.
2. As often as listed in there, so 2 times in several months. Though this 2nd time ocurred in a bit less than a 1 month frame from the last one, cf. the logs i put there.
3. I'm, PyPlanet. I didn't but if there was an issue with the controller i'd have a log for it. There's nothing in there.
4. TA. I never changed the mode.
5. There's 2 servers and indeed both are apparently stopped. However for some reasons i didn't have any (console) logs generated by ManiaPlanetServer for the RPG server. It seems some are now created, not sure i'll have to check later on.

@Reaby : Servers are running for months, i know i had to create specific dedicated server accounts ^^. You can ever see the id in the logs i pasted. RPG server login is _Harest_RPG.

Edit : I also just saw at the start of the new ConsoleLog file that "Logs are disabled in the "production" environment.". Any way to activate it ? If there's a way to know more about this disconnection from nowhere, i'd take it. Better to fix this at the source rather than doing a cron task as a fail safe...

[fng_thatoneguy]

It is definitely near-impossible to troubleshoot when they stay running that long (I’m glad they aren’t crashing more often!)

Do you know if others hosting through OVH have similar issues?

It would definitely help to have more detailed logs. I’m sorry I don’t know how to enable that.

[Harest]

No idea. I asked on a french discord server (CxX), i may try on the official TM discord but i'm not sure i'll get anything there.

I had similar answer regarding the duration the server was on. Only responses i got was basically on this. Since when a server needs to be restarted ? You never restart a server in prod afaik. That's a bit lame.

Anyway, I did a script that check if the servers are running and restart them if not. I'll put it as a cron task executed every hour. Problem "solved".
Edit : I'll activate the debug mode of Pyplanet to get better logs and to be sure there's nothing wrong there when the servers stop.

[fng_thatoneguy]

Actually come to think of it, I have been seeing my own servers that run on Windows will randomly shut down periodically too (after long periods of time like yours). It has happened infrequently enough that I haven't thought much of it and just restarted them via Task Scheduler.

I'll clear my logs and do a fresh run of them and watch for them to go down again and see if I can see anything different.

If it's the same issue, it is related directly to the dedicated server and not a server controller, because mine don't use server controllers currently. And it's not operating system specific, which is interesting because most problems I've seen in the past have been related to one platform or the other, but not usually both at the same time. I wonder if it might be related to some of the base scripts?

[Harest]

I just had a new case here. Not directly related to the same error than in the OP but i still want to mention it.
I updated my cron task accordingly so if only one of the server is down, it'll restart it. Before it checked if any server was still running only and restart both if not (since it seemed if one server was down, both were).

So, apparently the RPG server stopped the 28/09/2018 at 14:26. And this time, there's nothing in the log, not even a dedicated account disconnection. Literally no way to know what went wrong here.
Last lines of Pyplanet log file :

Code: Select all

[2018-09-28 14:15:03,930][DEBUG][default] root: No callback registered for Script.Trackmania.Event.OnPlayerRemoved (manager.py:102)
[2018-09-28 14:15:03,944][DEBUG][<concurrent.futures.thread.ThreadPoolExecutor object at 0x7f572c7fa400>_15] urllib3.connectionpool: Resetting dropped connection: dedimania.net (connectionpool.py:243)
[2018-09-28 14:15:03,974][DEBUG][<concurrent.futures.thread.ThreadPoolExecutor object at 0x7f572c7fa400>_15] urllib3.connectionpool: http://dedimania.net:8082 "POST /Dedimania HTTP/1.1" 200 288 (connectionpool.py:396)
[2018-09-28 14:26:09,880][DEBUG][default] peewee.async: ('UPDATE `player` SET `created_at` = %s, `updated_at` = %s, `login` = %s, `nickname` = %s, `last_ip` = %s, `last_seen` = %s, `level` = %s WHERE (`player`.`id` = %s)', ([datetime.da$
[2018-09-28 14:26:10,010][DEBUG][<concurrent.futures.thread.ThreadPoolExecutor object at 0x7f572c7fa400>_8] urllib3.connectionpool: Resetting dropped connection: dedimania.net (connectionpool.py:243)
[2018-09-28 14:26:10,040][DEBUG][<concurrent.futures.thread.ThreadPoolExecutor object at 0x7f572c7fa400>_8] urllib3.connectionpool: http://dedimania.net:8082 "POST /Dedimania HTTP/1.1" 200 275 (connectionpool.py:396)
[2018-09-28 14:26:10,077][DEBUG][default] peewee.async: ('SELECT `t1`.`id`, `t1`.`app`, `t1`.`key`, `t1`.`category`, `t1`.`name`, `t1`.`description`, `t1`.`value` FROM `setting` AS t1 WHERE ((`t1`.`key` = %s) AND (`t1`.`app` = %s))', ([$
[2018-09-28 14:26:55,024][DEBUG][default] raven.base.Client: Sending message of length 6687 to https://sentry.s3.toffe.me/api/2/store/ (base.py:721)
[2018-09-28 14:26:55,053][DEBUG][default] raven.base.Client: Sending message of length 6379 to https://sentry.s3.toffe.me/api/2/store/ (base.py:721)

Last lines of the server Console Log file :

Code: Select all

[2018/09/28 14:15:03] Disconnection of kanzarsaiyajin(IP:2350)
[2018/09/28 14:26:09] Disconnection of tinat(IP:2350)
[2018/09/28 14:26:09] ...Finish

Last lines of the server Game Log file :

Code: Select all

[2018/09/28 14:14:48] <chat> [_harest_rpg ($i$s$o$e10RPG$g - $f50Beginners$g & $f40M$f30o$f20r$f10e$g)] $z$s$fff»» $fff$F00KaNZaR $00CSaiYaJiN$z$s$0f3 drove the $fff10.$0f3 Local Record: $fff↨ 44:32.859$0f3.
[2018/09/28 14:15:03] <chat> [_harest_rpg ($i$s$o$e10RPG$g - $f50Beginners$g & $f40M$f30o$f20r$f10e$g)] $z$s$fff»» $ff0Player $fff$F00KaNZaR $00CSaiYaJiN$z$s$ff0 left the server! Nation: $fffFrance

Maybe the api calls of PyPlanet contain some information but Toffe is so busy atm it seems that i don't think i could get that. Seems like a MP4 server crash... I wish we could get more verbose info from the MP4 server.

Edit : I asked Jon from Drakonia (in french) and he basically told me that "server[s] crash after 21-22 days or so, it's a limitation for the time being".

[PhantOM51]

Hi !
Same thing for me after 20-25 days all my servers go down on Maniaplanet.
Controller used : uaseco 0.9.6
Provider : Kimsufi (OVH).

This is similar to the existing problem on TM1, after 1 month of operation, it became impossible to connect to the server.
We had to restart the server and it started again for 1 month.