• Hey Guest, we're evolving the future of TeaSpeak.
    You're invited to join the discussion here!

Server Disconnected from server (invalid clientID)

REDOSS

TeaSpeak Team
Staff member
TeaTeam
I think it is necessary to create a topic with a discussion of this error and supplement it with information as much as possible.

In this case I one and a half days sat on the server and did nothing as suddenly the server disconnected me.
Code:
[2019-10-17 21:53:49] [DEBUG]     5 | [IP:1976/REDOSS | 58] Failed to execute packet resend: Failed to receive acknowledge for packet 2675 of type Command
[2019-10-17 21:53:49] [DEBUG]     5 | [IP:1976/REDOSS | 58] Client move timings: timings for : 1ms
[2019-10-17 21:53:49] [DEBUG]   - chan tree l: @0ms: 0ms
[2019-10-17 21:53:49] [DEBUG]   - channel res: @0ms: 0ms
[2019-10-17 21:53:49] [DEBUG]   - target show: @0ms: 0ms
[2019-10-17 21:53:49] [DEBUG]   - notify view: @1ms: 1ms
[2019-10-17 21:53:49] [DEBUG]   - lock own tr: @1ms: 0ms
[2019-10-17 21:53:49] [DEBUG]   - src chan up: @1ms: 0ms
[2019-10-17 21:53:49] [DEBUG]   - notify cpro: @1ms: 0ms
[2019-10-17 21:53:50] [DEBUG]     5 | [IP:1976/REDOSS | 58] Failed to execute packet resend: Failed to receive acknowledge for packet 2675 of type Command
[2019-10-17 21:53:50] [DEBUG]     5 | [IP:1976/REDOSS | 58] Closing voice client connection. (Flush: true)
[2019-10-17 21:53:50] [DEBUG]     5 | [IP:1976/REDOSS | 58] Awaiting write prepare, write and acknowledge queue flushed
[2019-10-17 21:53:50] [DEBUG]     5 | [IP:1976/REDOSS | 58] Write prepare queue progressed
[2019-10-17 21:53:51] [DEBUG]     5 | [IP:1976/REDOSS | 58] Failed to execute packet resend: Failed to receive acknowledge for packet 2675 of type Command
[2019-10-17 21:53:51] [DEBUG]     5 | [IP:1976/REDOSS | 58] Tried to disconnect, but isn't connected anymore! State: 4
[2019-10-17 21:53:51] [DEBUG]     5 | [IP:1976/REDOSS | 58] Cant flush io!
[2019-10-17 21:53:51] [DEBUG]     5 | [IP:1976/REDOSS | 58] Could not get acknowledge for all commands before disconnecting. Acknowledges left: 7
[2019-10-17 21:53:51] [INFO]      5 | Voice client 2/rZxCzsRdkwgKx3/SdoQES9hGm3M= (REDOSS) from IP:1976 left.
[2019-10-17 21:53:51] [DEBUG]     5 |  Deleting VoiceClient instance at 0x7f701bb15c10
 
Last edited:

darksoon

New member
here too, my member random disconnected with invalid ClientID

Code:
[2019-10-20 15:15:49] [WARNING]     1 | Found varianzes within the server tick! (Supposed: 500ms Hold: 513ms)
[2019-10-20 15:15:51] [DEBUG]     1 | [45213/Wabe | 9] Got a ping timeout. (Last successful ping: 20447ms ago. Last request 500ms. Last response 20947ms). Trying to recover via command acknowledge.
[2019-10-20 15:16:07] [DEBUG]     1 | [45213/Wabe | 9] Failed to execute packet resend: Failed to receive acknowledge for packet 119 of type Command
[2019-10-20 15:16:07] [DEBUG]     1 | [45213/Wabe | 9] Client move timings: timings for : 0ms
[2019-10-20 15:16:07] [DEBUG]   - chan tree l: @0ms: 0ms
[2019-10-20 15:16:07] [DEBUG]   - channel res: @0ms: 0ms
[2019-10-20 15:16:07] [DEBUG]   - target show: @0ms: 0ms
[2019-10-20 15:16:07] [DEBUG]   - notify view: @0ms: 0ms
[2019-10-20 15:16:07] [DEBUG]   - lock own tr: @0ms: 0ms
[2019-10-20 15:16:07] [DEBUG]   - src chan up: @0ms: 0ms
[2019-10-20 15:16:07] [DEBUG]   - notify cpro: @0ms: 0ms
[2019-10-20 15:16:08] [DEBUG]     1 | [45213/Wabe | 9] Failed to execute packet resend: Failed to receive acknowledge for packet 119 of type Command
[2019-10-20 15:16:08] [DEBUG]     1 | [45213/Wabe | 9] Closing voice client connection. (Flush: true)
[2019-10-20 15:16:08] [DEBUG]     1 | [45213/Wabe | 9] Awaiting write prepare, write and acknowledge queue flushed
[2019-10-20 15:16:08] [DEBUG]     1 | [45213/Wabe | 9] Write prepare queue progressed
[2019-10-20 15:16:09] [DEBUG]     1 | [45213/Wabe | 9] Failed to execute packet resend: Failed to receive acknowledge for packet 119 of type Command
[2019-10-20 15:16:09] [DEBUG]     1 | [45213/Wabe | 9] Tried to disconnect, but isn't connected anymore! State: 4
[2019-10-20 15:16:09] [DEBUG]     1 | [45213/Wabe | 9] Cant flush io!
[2019-10-20 15:16:09] [DEBUG]     1 | [45213/Wabe | 9] Could not get acknowledge for all commands before disconnecting. Acknowledges left: 2
[2019-10-20 15:16:09] [INFO]      1 | Voice client 20/7fHpQmssTixUdgfhe6pGhn+3ROV/w= (Wabe) from 45213 left.
[2019-10-20 15:16:09] [DEBUG]     1 |  Deleting VoiceClient instance at 0x7f0db2847210
 
Last edited:

REDOSS

TeaSpeak Team
Staff member
TeaTeam
I would suggest enabling trace mode in the config file and catching these disconnection.

confg.yml
Code:
level: 0
 

darksoon

New member
hey,

here is the log with trace enable:

Code:
[2019-10-20 16:36:10] [DEBUG]     1 | [IP:45148/Rufus01 | 8] Client move timings: timings for : 0ms
[2019-10-20 16:36:10] [DEBUG]   - chan tree l: @0ms: 0ms
[2019-10-20 16:36:10] [DEBUG]   - channel res: @0ms: 0ms
[2019-10-20 16:36:10] [DEBUG]   - target show: @0ms: 0ms
[2019-10-20 16:36:10] [DEBUG]   - notify view: @0ms: 0ms
[2019-10-20 16:36:10] [DEBUG]   - lock own tr: @0ms: 0ms
[2019-10-20 16:36:10] [DEBUG]   - src chan up: @0ms: 0ms
[2019-10-20 16:36:10] [DEBUG]   - notify cpro: @0ms: 0ms
[2019-10-20 16:36:10] [TRACE]     1 | [IP:45148/Rufus01 | 8][Command][Server -> Client] Sending command notifyclientleftview. Command low: false. Full command: notifyclientleftview reasonmsg=connection\slost reasonid=3 clid=8 cfid=36 ctid=0
[2019-10-20 16:36:10] [TRACE]     1 | [Property] Not saving property 'client_flag_talking', changed for 7 (New value: 0)
[2019-10-20 16:36:11] [TRACE]     1 | [95.90.191.168:22502/Grisu | Chip | 4][Command][Client -> Server] Processing command: connectioninfoautoupdate connection_server2client_packetloss_speech='0.0000' connection_server2client_packetloss_keepalive='0.0279' connection_server2client_packetloss_control='0.0000' connection_server2client_packetloss_total='0.0277'
[2019-10-20 16:36:11] [TRACE]     1 | [Property] Not saving property 'connection_server2client_packetloss_keepalive', changed for 22 (New value: 0.0279)
[2019-10-20 16:36:11] [TRACE]     1 | [Property] Not saving property 'connection_server2client_packetloss_total', changed for 22 (New value: 0.0277)
[2019-10-20 16:36:11] [DEBUG]     1 | [IP:45148/Rufus01 | 8] Failed to execute packet resend: Failed to receive acknowledge for packet 184 of type Command
[2019-10-20 16:36:11] [DEBUG]     1 | [IP:45148/Rufus01 | 8] Closing voice client connection. (Flush: true)
[2019-10-20 16:36:11] [DEBUG]     1 | [IP:45148/Rufus01 | 8] Awaiting write prepare, write and acknowledge queue flushed
[2019-10-20 16:36:11] [DEBUG]     1 | [IP:45148/Rufus01 | 8] Write prepare queue progressed
[2019-10-20 16:36:12] [DEBUG]     1 | [IP:45148/Rufus01 | 8] Failed to execute packet resend: Failed to receive acknowledge for packet 184 of type Command
[2019-10-20 16:36:12] [DEBUG]     1 | [IP:45148/Rufus01 | 8] Tried to disconnect, but isn't connected anymore! State: 4
[2019-10-20 16:36:12] [DEBUG]     1 | [IP:45148/Rufus01 | 8] Cant flush io!
[2019-10-20 16:36:12] [DEBUG]     1 | [IP:45148/Rufus01 | 8] Could not get acknowledge for all commands before disconnecting. Acknowledges left: 2
[2019-10-20 16:36:12] [INFO]      1 | Voice client 13/AQjPIfkepsReW2tm/WB4Eu/2emw= (Rufus01) from IP:45148 left.
[2019-10-20 16:36:12] [TRACE]     1 | Updating server property: virtualserver_last_client_disconnect. New value: 1571589372. Query: UPDATE `properties` SET `value` = :value WHERE `serverId` = :sid AND `type` = :type AND `id` = :id AND `key` = :key
[2019-10-20 16:36:12] [TRACE]     1 | [Property] Not saving property 'clid', changed for 13 (New value: 0)
[2019-10-20 16:36:12] [DEBUG]     1 |  Deleting VoiceClient instance at 0x7f7b4ac12210
[2019-10-20 16:36:12] [TRACE]     1 | [Property] Changed property in db key: client_month_online_time value: 319680
[2019-10-20 16:36:12] [TRACE]     1 | [Property] Changed property in db key: client_total_online_time value: 355680
 

WolverinDEV

TeaSpeak Team
Staff member
Administrator
hey,

here is the log with trace enable:

Code:
[2019-10-20 16:36:10] [DEBUG]     1 | [IP:45148/Rufus01 | 8] Client move timings: timings for : 0ms
[2019-10-20 16:36:10] [DEBUG]   - chan tree l: @0ms: 0ms
[2019-10-20 16:36:10] [DEBUG]   - channel res: @0ms: 0ms
[2019-10-20 16:36:10] [DEBUG]   - target show: @0ms: 0ms
[2019-10-20 16:36:10] [DEBUG]   - notify view: @0ms: 0ms
[2019-10-20 16:36:10] [DEBUG]   - lock own tr: @0ms: 0ms
[2019-10-20 16:36:10] [DEBUG]   - src chan up: @0ms: 0ms
[2019-10-20 16:36:10] [DEBUG]   - notify cpro: @0ms: 0ms
[2019-10-20 16:36:10] [TRACE]     1 | [IP:45148/Rufus01 | 8][Command][Server -> Client] Sending command notifyclientleftview. Command low: false. Full command: notifyclientleftview reasonmsg=connection\slost reasonid=3 clid=8 cfid=36 ctid=0
[2019-10-20 16:36:10] [TRACE]     1 | [Property] Not saving property 'client_flag_talking', changed for 7 (New value: 0)
[2019-10-20 16:36:11] [TRACE]     1 | [95.90.191.168:22502/Grisu | Chip | 4][Command][Client -> Server] Processing command: connectioninfoautoupdate connection_server2client_packetloss_speech='0.0000' connection_server2client_packetloss_keepalive='0.0279' connection_server2client_packetloss_control='0.0000' connection_server2client_packetloss_total='0.0277'
[2019-10-20 16:36:11] [TRACE]     1 | [Property] Not saving property 'connection_server2client_packetloss_keepalive', changed for 22 (New value: 0.0279)
[2019-10-20 16:36:11] [TRACE]     1 | [Property] Not saving property 'connection_server2client_packetloss_total', changed for 22 (New value: 0.0277)
[2019-10-20 16:36:11] [DEBUG]     1 | [IP:45148/Rufus01 | 8] Failed to execute packet resend: Failed to receive acknowledge for packet 184 of type Command
[2019-10-20 16:36:11] [DEBUG]     1 | [IP:45148/Rufus01 | 8] Closing voice client connection. (Flush: true)
[2019-10-20 16:36:11] [DEBUG]     1 | [IP:45148/Rufus01 | 8] Awaiting write prepare, write and acknowledge queue flushed
[2019-10-20 16:36:11] [DEBUG]     1 | [IP:45148/Rufus01 | 8] Write prepare queue progressed
[2019-10-20 16:36:12] [DEBUG]     1 | [IP:45148/Rufus01 | 8] Failed to execute packet resend: Failed to receive acknowledge for packet 184 of type Command
[2019-10-20 16:36:12] [DEBUG]     1 | [IP:45148/Rufus01 | 8] Tried to disconnect, but isn't connected anymore! State: 4
[2019-10-20 16:36:12] [DEBUG]     1 | [IP:45148/Rufus01 | 8] Cant flush io!
[2019-10-20 16:36:12] [DEBUG]     1 | [IP:45148/Rufus01 | 8] Could not get acknowledge for all commands before disconnecting. Acknowledges left: 2
[2019-10-20 16:36:12] [INFO]      1 | Voice client 13/AQjPIfkepsReW2tm/WB4Eu/2emw= (Rufus01) from IP:45148 left.
[2019-10-20 16:36:12] [TRACE]     1 | Updating server property: virtualserver_last_client_disconnect. New value: 1571589372. Query: UPDATE `properties` SET `value` = :value WHERE `serverId` = :sid AND `type` = :type AND `id` = :id AND `key` = :key
[2019-10-20 16:36:12] [TRACE]     1 | [Property] Not saving property 'clid', changed for 13 (New value: 0)
[2019-10-20 16:36:12] [DEBUG]     1 |  Deleting VoiceClient instance at 0x7f7b4ac12210
[2019-10-20 16:36:12] [TRACE]     1 | [Property] Changed property in db key: client_month_online_time value: 319680
[2019-10-20 16:36:12] [TRACE]     1 | [Property] Changed property in db key: client_total_online_time value: 355680
I'll need the full log because the actual error happend round about 15seconds earlier :) :D

---- Automatically Merged Double Post ----

Okey I now got a hint where the issue is rooted and as expected... its a nasty issue :D

---- Automatically Merged Double Post ----

Please checkout TeaSpeak-1.3.26-beta-1.tar.gz
 
Last edited:

REDOSS

TeaSpeak Team
Staff member
TeaTeam
I'll need the full log because the actual error happend round about 15seconds earlier :) :D

---- Automatically Merged Double Post ----

Okey I now got a hint where the issue is rooted and as expected... its a nasty issue :D

---- Automatically Merged Double Post ----

Please checkout TeaSpeak-1.3.26-beta-1.tar.gz
Okey. I've already scheduled an update and really hope the issue is fixed.