Unable to connect after some idle server time..

[robi]

Jan 01 17:09:32 2021-01-01 15:09:32.340302|ERROR |DatabaseQuery | |Could not connect to mariadb server: Can't connect to MySQL server on 'mysql' (107)
Jan 01 17:09:32 2021-01-01 15:09:32.340343|CRITICAL|ServerLibPriv | |Server() unable to initialize database
Jan 01 17:09:32 2021-01-01 15:09:32,343 INFO exited: teamspeak (exit status 1; not expected)
Jan 01 17:09:33 2021-01-01 15:09:33,344 INFO gave up: teamspeak entered FATAL state, too many start retries too quickly
Jan 08 00:24:16 2021-01-07 22:24:16,172 WARN received SIGTERM indicating exit request
Jan 08 00:24:16 2021-01-07 22:24:16,173 INFO waiting for nginx to die
Jan 08 00:24:17 2021-01-07 22:24:17,179 INFO stopped: nginx (exit status 0)

Seems to be a DB reconnect issue.. user reproducibly reports that at first start/connect it works fine, but after all parties leave and some time passes, like an hour or so, none of them can connect again until it is restarted.

Tested on 2-3 TS servers.

[nebulon]

@robi is it possible that the mysql addon ran out of memory or so?

[robi]

@nebulon does not appear so, all services are green and app mem usage is low.

[robi]

This is still a problem. (may have to reverify after all the CL & DB upgrades)

Additionally, after every Cloduron server restart, all the TS servers are unusable until each is restarted manually.

Does anyone else use TS regularly?

[nebulon]

@robi does restarting the server always reproduce the issue? This might make things easier to debug. It may be that TeamSpeak cannot deal with DB reconnection properly and during a server startup, the database is not yet accepting connections, while TeamSpeak already expects this?

[robi]

@nebulon yes, that is reproducible. And your theory is plausible.

Since it's a tiny fast app, it may start up too quickly.

[girish]

I tried to reproduce this with several reboots but couldn't . Even tries reloading mysql server when teamspeak was running and it seems to reconnect automatically. So, the issue seems to be something else. I did cleanup many bugs in the package though and made a new release.

[robi]

@girish ok will try new package.

[robi]

Still have the same issue, here's the log:

Apr 07 15:40:57 2021-04-07 15:40:57.807523|INFO |ServerLibPriv | |TeamSpeak 3 Server 3.13.3 (2020-12-16 14:17:05)
Apr 07 15:40:57 2021-04-07 15:40:57.807883|INFO |ServerLibPriv | |SystemInformation: Linux 5.4.0-70-generic #78~18.04.1-Ubuntu SMP Sat Mar 20 14:10:07 UTC 2021 x86_64 Binary: 64bit
Apr 07 15:40:57 2021-04-07 15:40:57.807964|INFO |ServerLibPriv | |Using hardware aes
Apr 07 15:40:57 2021-04-07 15:40:57.809134|INFO |DatabaseQuery | |dbPlugin name: MariaDB plugin, version 3, (c)TeamSpeak Systems GmbH
Apr 07 15:40:57 2021-04-07 15:40:57.809261|INFO |DatabaseQuery | |dbPlugin version: 2
Apr 07 15:40:57 2021-04-07 15:40:57.821263|ERROR |DatabaseQuery | |Could not connect to mariadb server: Can't connect to MySQL server on 'mysql' (107)
Apr 07 15:40:57 2021-04-07 15:40:57.821544|CRITICAL|ServerLibPriv | |Server() unable to initialize database
Apr 07 15:40:57 2021-04-07 15:40:57,822 INFO exited: teamspeak (exit status 1; not expected)
Apr 07 15:40:58 ==> Updating teamspeak server port
Apr 07 15:40:58 mysql: [Warning] Using a password on the command line interface can be insecure.
Apr 07 15:40:58 ERROR 2003 (HY000): Can't connect to MySQL server on 'mysql' (111)
Apr 07 15:40:58 2021-04-07 15:40:58,824 INFO spawned: 'teamspeak' with pid 34
Apr 07 15:40:58 2021-04-07 15:40:58,825 INFO reaped unknown pid 9
Apr 07 15:40:58 Warning - name 'query_ip_whitelist' from file /app/data/ts/ts3server.ini is deprecated (but understood), please use the new name 'query_ip_allowlist' instead.
Apr 07 15:40:58 Warning - name 'query_ip_blacklist' from file /app/data/ts/ts3server.ini is deprecated (but understood), please use the new name 'query_ip_denylist' instead.
Apr 07 15:40:58 2021-04-07 15:40:58.830537|INFO |ServerLibPriv | |TeamSpeak 3 Server 3.13.3 (2020-12-16 14:17:05)
Apr 07 15:40:58 2021-04-07 15:40:58.830599|INFO |ServerLibPriv | |SystemInformation: Linux 5.4.0-70-generic #78~18.04.1-Ubuntu SMP Sat Mar 20 14:10:07 UTC 2021 x86_64 Binary: 64bit
Apr 07 15:40:58 2021-04-07 15:40:58.830618|INFO |ServerLibPriv | |Using hardware aes
Apr 07 15:40:58 2021-04-07 15:40:58.830964|INFO |DatabaseQuery | |dbPlugin name: MariaDB plugin, version 3, (c)TeamSpeak Systems GmbH
Apr 07 15:40:58 2021-04-07 15:40:58.830979|INFO |DatabaseQuery | |dbPlugin version: 2
Apr 07 15:40:58 2021-04-07 15:40:58.831927|ERROR |DatabaseQuery | |Could not connect to mariadb server: Can't connect to MySQL server on 'mysql' (107)
Apr 07 15:40:58 2021-04-07 15:40:58.831961|CRITICAL|ServerLibPriv | |Server() unable to initialize database
Apr 07 15:40:58 2021-04-07 15:40:58,833 INFO exited: teamspeak (exit status 1; not expected)
Apr 07 15:41:00 2021-04-07 15:41:00,836 INFO spawned: 'teamspeak' with pid 37
Apr 07 15:41:00 2021-04-07 15:41:00.854202|INFO |ServerLibPriv | |TeamSpeak 3 Server 3.13.3 (2020-12-16 14:17:05)
Apr 07 15:41:00 2021-04-07 15:41:00.855016|INFO |ServerLibPriv | |SystemInformation: Linux 5.4.0-70-generic #78~18.04.1-Ubuntu SMP Sat Mar 20 14:10:07 UTC 2021 x86_64 Binary: 64bit
Apr 07 15:41:00 2021-04-07 15:41:00.855047|INFO |ServerLibPriv | |Using hardware aes
Apr 07 15:41:00 Warning - name 'query_ip_whitelist' from file /app/data/ts/ts3server.ini is deprecated (but understood), please use the new name 'query_ip_allowlist' instead.
Apr 07 15:41:00 Warning - name 'query_ip_blacklist' from file /app/data/ts/ts3server.ini is deprecated (but understood), please use the new name 'query_ip_denylist' instead.
Apr 07 15:41:00 2021-04-07 15:41:00.857479|INFO |DatabaseQuery | |dbPlugin name: MariaDB plugin, version 3, (c)TeamSpeak Systems GmbH
Apr 07 15:41:00 2021-04-07 15:41:00.857521|INFO |DatabaseQuery | |dbPlugin version: 2
Apr 07 15:41:00 2021-04-07 15:41:00.864716|ERROR |DatabaseQuery | |Could not connect to mariadb server: Can't connect to MySQL server on 'mysql' (107)
Apr 07 15:41:00 2021-04-07 15:41:00.865341|CRITICAL|ServerLibPriv | |Server() unable to initialize database
Apr 07 15:41:00 2021-04-07 15:41:00,872 INFO exited: teamspeak (exit status 1; not expected)
Apr 07 15:41:03 2021-04-07 15:41:03,884 INFO spawned: 'teamspeak' with pid 40
Apr 07 15:41:03 Warning - name 'query_ip_whitelist' from file /app/data/ts/ts3server.ini is deprecated (but understood), please use the new name 'query_ip_allowlist' instead.
Apr 07 15:41:03 Warning - name 'query_ip_blacklist' from file /app/data/ts/ts3server.ini is deprecated (but understood), please use the new name 'query_ip_denylist' instead.
Apr 07 15:41:03 2021-04-07 15:41:03.891895|INFO |ServerLibPriv | |TeamSpeak 3 Server 3.13.3 (2020-12-16 14:17:05)
Apr 07 15:41:03 2021-04-07 15:41:03.892276|INFO |ServerLibPriv | |SystemInformation: Linux 5.4.0-70-generic #78~18.04.1-Ubuntu SMP Sat Mar 20 14:10:07 UTC 2021 x86_64 Binary: 64bit
Apr 07 15:41:03 2021-04-07 15:41:03.892307|INFO |ServerLibPriv | |Using hardware aes
Apr 07 15:41:03 2021-04-07 15:41:03.892760|INFO |DatabaseQuery | |dbPlugin name: MariaDB plugin, version 3, (c)TeamSpeak Systems GmbH
Apr 07 15:41:03 2021-04-07 15:41:03.892778|INFO |DatabaseQuery | |dbPlugin version: 2
Apr 07 15:41:03 2021-04-07 15:41:03.893818|ERROR |DatabaseQuery | |Could not connect to mariadb server: Can't connect to MySQL server on 'mysql' (107)
Apr 07 15:41:03 2021-04-07 15:41:03.893840|CRITICAL|ServerLibPriv | |Server() unable to initialize database
Apr 07 15:41:03 2021-04-07 15:41:03,895 INFO exited: teamspeak (exit status 1; not expected)
Apr 07 15:41:03

An app restart fixes them up instantly once Cloudron is up.

Apr 07 15:41:03 2021-04-07 15:41:03,895 INFO exited: teamspeak (exit status 1; not expected)
Apr 07 15:41:03 2021-04-07 15:41:03,895 INFO gave up: teamspeak entered FATAL state, too many start retries too quickly
Apr 07 16:02:52 box:settings initCache: pre-load settings
Apr 07 16:02:52 box:taskworker Starting task 3755. Logs are at /home/yellowtent/platformdata/logs/1775b10f-de17-4e01-b925-d56d84ce869f/apptask.log
Apr 07 16:02:52 box:tasks 3755: {"percent":2,"error":null}
Apr 07 16:02:52 box:apptask ts.fbean.x.io startTask installationState: pending_restart runState: running
Apr 07 16:02:52 box:tasks 3755: {"percent":20,"message":"Restarting container"}
Apr 07 16:02:53 2021-04-07 16:02:53,133 WARN received SIGTERM indicating exit request
Apr 07 16:02:53 2021-04-07 16:02:53,133 INFO waiting for nginx to die
Apr 07 16:02:54 2021-04-07 16:02:54,139 INFO stopped: nginx (exit status 0)
Apr 07 16:02:56 DEFAULT_PORT is set to '9987'
Apr 07 16:02:56 => Ensuring permissions
Apr 07 16:02:56 box:tasks 3755: {"percent":100,"message":"Done"}
Apr 07 16:02:56 => Starting Teamspeak Server
Apr 07 16:02:56 box:apptask ts.fbean.x.io updating app with values: {"installationState":"installed","error":null,"health":null}
Apr 07 16:02:56 box:taskworker Task took 3.833 seconds
Apr 07 16:02:56 box:tasks setCompleted - 3755: {"result":null,"error":null}
Apr 07 16:02:56 box:tasks 3755: {"percent":100,"result":null,"error":null}
Apr 07 16:02:56 2021-04-07 16:02:56,434 CRIT Supervisor is running as root. Privileges were not dropped because no user is specified in the config file. If you intend to run as root, you can set user=root in the config file to avoid this message.
Apr 07 16:02:56 2021-04-07 16:02:56,435 INFO Included extra file "/etc/supervisor/conf.d/nginx.conf" during parsing
Apr 07 16:02:56 2021-04-07 16:02:56,436 INFO Included extra file "/etc/supervisor/conf.d/teamspeak.conf" during parsing
Apr 07 16:02:56 2021-04-07 16:02:56,446 INFO RPC interface 'supervisor' initialized
Apr 07 16:02:56 2021-04-07 16:02:56,447 CRIT Server 'unix_http_server' running without any HTTP authentication checking
Apr 07 16:02:56 2021-04-07 16:02:56,447 INFO supervisord started with pid 1
Apr 07 16:02:57 2021-04-07 16:02:57,449 INFO spawned: 'nginx' with pid 13
Apr 07 16:02:57 2021-04-07 16:02:57,450 INFO spawned: 'teamspeak' with pid 14
Apr 07 16:02:57 2021-04-07 16:02:57.479361|INFO |ServerLibPriv | |TeamSpeak 3 Server 3.13.3 (2020-12-16 14:17:05)
Apr 07 16:02:57 Warning - name 'query_ip_whitelist' from file /app/data/ts/ts3server.ini is deprecated (but understood), please use the new name 'query_ip_allowlist' instead.
Apr 07 16:02:57 Warning - name 'query_ip_blacklist' from file /app/data/ts/ts3server.ini is deprecated (but understood), please use the new name 'query_ip_denylist' instead.
Apr 07 16:02:57 2021-04-07 16:02:57.482193|INFO |ServerLibPriv | |SystemInformation: Linux 5.4.0-70-generic #78~18.04.1-Ubuntu SMP Sat Mar 20 14:10:07 UTC 2021 x86_64 Binary: 64bit
Apr 07 16:02:57 2021-04-07 16:02:57.483211|INFO |ServerLibPriv | |Using hardware aes
Apr 07 16:02:57 2021-04-07 16:02:57.487626|INFO |DatabaseQuery | |dbPlugin name: MariaDB plugin, version 3, (c)TeamSpeak Systems GmbH
Apr 07 16:02:57 2021-04-07 16:02:57.488158|INFO |DatabaseQuery | |dbPlugin version: 2
Apr 07 16:02:57 2021-04-07 16:02:57.662125|WARNING |Accounting | |Unable to open /app/data/licensekey.dat, falling back to limited functionality
Apr 07 16:02:57 2021-04-07 16:02:57.662904|INFO |Accounting | |Licensing Information
Apr 07 16:02:57 2021-04-07 16:02:57.663554|INFO |Accounting | |licensed to : Anonymous
Apr 07 16:02:57 2021-04-07 16:02:57.664434|INFO |Accounting | |type : No License
Apr 07 16:02:57 2021-04-07 16:02:57.664816|INFO |Accounting | |starting date : Thu Oct 1 00:00:00 2020
Apr 07 16:02:57 2021-04-07 16:02:57.665263|INFO |Accounting | |ending date : Tue Nov 1 00:00:00 2022
Apr 07 16:02:57 2021-04-07 16:02:57.665891|INFO |Accounting | |max virtualservers: 1
Apr 07 16:02:57 2021-04-07 16:02:57.667621|INFO |Accounting | |max slots : 32
Apr 07 16:02:58 2021-04-07 16:02:58,669 INFO success: nginx entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)
Apr 07 16:02:58 2021-04-07 16:02:58,669 INFO success: teamspeak entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)
Apr 07 16:02:58 2021-04-07 16:02:58.836196|INFO | | |Puzzle precompute time: 673
Apr 07 16:02:58 2021-04-07 16:02:58.836792|INFO |FileManager | |listening on 0.0.0.0:30033
Apr 07 16:02:58 2021-04-07 16:02:58.841152|INFO |Query | |Using a query thread pool size of 2
Apr 07 16:03:00 2021-04-07 16:03:00.204194|INFO |VirtualServerBase|1 |listening on 0.0.0.0:9987
Apr 07 16:03:00 2021-04-07 16:03:00.204350|INFO |Query | |listening for query on 0.0.0.0:10011
Apr 07 16:03:00 2021-04-07 16:03:00.204494|INFO |CIDRManager | |updated query_ip_allowlist ips: 127.0.0.1/32, ::1/128,
Apr 07 16:03:00 2021-04-07 16:03:00.204513|WARNING |ServerMain | |Warning - name 'query_ip_whitelist' from file /app/data/ts/ts3server.ini is deprecated (but understood), please use the new name 'query_ip_allowlist' instead.
Apr 07 16:03:00 2021-04-07 16:03:00.204524|WARNING |ServerMain | |Warning - name 'query_ip_blacklist' from file /app/data/ts/ts3server.ini is deprecated (but understood), please use the new name 'query_ip_denylist' instead.
Apr 07 16:03:06 ==> Updating teamspeak server port
Apr 07 16:03:06 mysql: [Warning] Using a password on the command line interface can be insecure.
Apr 07 16:03:06 2021-04-07 16:03:06,212 INFO reaped unknown pid 9

Can we add a better app monitor check, so it does this restart for us?

As right now it thinks it's running when it actually isn't.

[nebulon]

Thanks for the logs. This is interesting, since the first failing log indicate that the TeamSpeak process is being restarted at least twice.
So I think there are two fixes required:

1. Ensure the teamspeak process is always restarted probably with some delay to not overload the system.
2. Fixup the healthcheck to actually check for teamspeak and not the nginx process, serving up the index.html page

[nebulon]

@robi I've updated the package now to check the actual teamspeak daemon is running for the healthcheck, as well as restarting for longer. This should hopefully solve your case as well.

[robi]

@nebulon Thank you so much! This is awesome work & timing.

We'll test it at the next maintenance window

Lots of love

[robi]

@nebulon The fixes seem to work, but we found another instance where it doesn't.

As we clone an existing TS server, the new one autostarts and cannot be connected to until it is manually restarted.

Should be reproducible.

[nebulon]

@robi I can't reproduce this. A cloned app works just fine here, of course ports have to be adjusted. Also note that if you have multiple TS instances, client will always by default connect to the app with the default ports configured, regardless of domain.

[nebulon]

I believe I've fixed those things now with the latest just released package version.

[robi]

Looks good so far, thanks @nebulon