Probably error in ping-pong logic

[recoilme]

I see disconnect timeout in this log. Sending 21 ping, got 20 response.
Doubled ping on 555 port was sended at 2020-01-11_16:10:32 and after that connection was closed.

2020-01-11_16:10:32.239446 : 'V/tgvoip: Sending UDP ping to 134.209.178.131:555, id -3602320821221394583'
2020-01-11_16:10:32.239446 : 'V/tgvoip: Sending UDP ping to 134.209.178.131:555, id -3602320821221394583'

At first - doubled ping - looks strange. I see one reply on it.
At second - no 10 sec timeout in this case.
Full log:

2020-01-11_16:10:22.237224 : 'W/tgvoip: Set remote endpoints, allowP2P=1, connectionMaxLayer=92'
2020-01-11_16:10:22.237884 : 'V/tgvoip: Adding endpoint: 134.209.178.88:558, UDP'
2020-01-11_16:10:22.237973 : 'V/tgvoip: Adding endpoint: 91.108.8.2:524, UDP'
2020-01-11_16:10:22.238036 : 'V/tgvoip: Adding endpoint: 91.108.8.5:523, UDP'
2020-01-11_16:10:22.238083 : 'V/tgvoip: Adding endpoint: 134.209.178.131:555, UDP'
2020-01-11_16:10:22.238129 : 'V/tgvoip: Adding endpoint: 134.209.176.124:552, UDP'
2020-01-11_16:10:22.238175 : 'I/tgvoip: update data saving mode, config 0, enabled 0, reqd by peer 0'
2020-01-11_16:10:22.238221 : 'I/tgvoip: update data saving mode, config 0, enabled 0, reqd by peer 0'
2020-01-11_16:10:22.238269 : 'I/tgvoip: set network type: ethernet, active interface eth0'
2020-01-11_16:10:22.238321 : 'I/tgvoip: Local IPv6 address: 2a03:a140:10:891::1'
2020-01-11_16:10:22.238369 : 'I/tgvoip: Active network interface changed:  -> eth0'
2020-01-11_16:10:22.238417 : 'W/tgvoip: Starting voip controller'
2020-01-11_16:10:22.238817 : 'V/tgvoip: trying bind to port 26531'
2020-01-11_16:10:22.238872 : 'D/tgvoip: Bound to local UDP port 26531'
2020-01-11_16:10:22.238949 : 'I/tgvoip: before create audio io'
2020-01-11_16:10:22.239228 : 'I/tgvoip: AEC: 0 NS: 0 AGC: 0'
2020-01-11_16:10:22.240041 : 'I/tgvoip: Audio initialization took 0.000230 seconds'
2020-01-11_16:10:22.240073 : 'W/tgvoip: Not ready to send - enqueueing'
2020-01-11_16:10:22.240123 : 'W/tgvoip: Not ready to send - enqueueing'
2020-01-11_16:10:22.240490 : 'W/tgvoip: Not ready to send - enqueueing'
2020-01-11_16:10:22.240546 : 'W/tgvoip: Not ready to send - enqueueing'
2020-01-11_16:10:22.240591 : 'W/tgvoip: Not ready to send - enqueueing'
2020-01-11_16:10:22.240637 : 'V/tgvoip: Call state changed to 2'
2020-01-11_16:10:22.240681 : 'I/tgvoip: === send thread exiting ==='
2020-01-11_16:10:22.240724 : 'I/tgvoip: Receive thread starting'
2020-01-11_16:10:22.240976 : 'V/tgvoip: Socket 9 is ready to send'
2020-01-11_16:10:22.241029 : 'I/tgvoip: Sending queued packet'
2020-01-11_16:10:22.241079 : 'I/tgvoip: Sending queued packet'
2020-01-11_16:10:22.241137 : 'I/tgvoip: Sending queued packet'
2020-01-11_16:10:22.241181 : 'I/tgvoip: Sending queued packet'
2020-01-11_16:10:22.241410 : 'I/tgvoip: Sending queued packet'
2020-01-11_16:10:22.241463 : 'W/tgvoip: Send udp pings'
2020-01-11_16:10:22.241506 : 'V/tgvoip: Sending UDP ping to 91.108.8.5:523, id -3817415755165323969'
2020-01-11_16:10:22.241550 : 'V/tgvoip: Sending UDP ping to 91.108.8.2:524, id 6901368930608868445'
2020-01-11_16:10:22.241713 : 'V/tgvoip: Sending UDP ping to 134.209.176.124:552, id 1755996362657760226'
2020-01-11_16:10:22.241770 : 'V/tgvoip: Sending UDP ping to 134.209.178.131:555, id 2645042903637372986'
2020-01-11_16:10:22.241819 : 'V/tgvoip: Sending UDP ping to 134.209.178.88:558, id -4869043572370612716'
2020-01-11_16:10:32.236691 : 'I/tgvoip: Detected IPv4 connectivity, will not try IPv6'
2020-01-11_16:10:32.239234 : 'V/tgvoip: Received UDP ping reply from 91.108.8.5:523: date=1578755422, queryID=-3817415755165323969, my IP=86.105.52.145, my port=26531'
2020-01-11_16:10:32.239264 : 'V/tgvoip: Received UDP ping reply from 91.108.8.2:524: date=1578755422, queryID=6901368930608868445, my IP=86.105.52.145, my port=26531'
2020-01-11_16:10:32.239282 : 'V/tgvoip: Received UDP ping reply from 134.209.178.131:555: date=1578755333, queryID=2645042903637372986, my IP=86.105.52.145, my port=26531'
2020-01-11_16:10:32.239344 : 'V/tgvoip: Received UDP ping reply from 134.209.178.88:558: date=1578755025, queryID=-4869043572370612716, my IP=86.105.52.145, my port=26531'
2020-01-11_16:10:32.239362 : 'V/tgvoip: Received UDP ping reply from 134.209.176.124:552: date=1578754712, queryID=1755996362657760226, my IP=86.105.52.145, my port=26531'
2020-01-11_16:10:32.239380 : 'W/tgvoip: Send udp pings'
2020-01-11_16:10:32.239396 : 'V/tgvoip: Sending UDP ping to 91.108.8.5:523, id -6427060238848443264'
2020-01-11_16:10:32.239413 : 'V/tgvoip: Sending UDP ping to 91.108.8.2:524, id -694658261907644342'
2020-01-11_16:10:32.239429 : 'V/tgvoip: Sending UDP ping to 134.209.176.124:552, id -9190746633918223979'
2020-01-11_16:10:32.239446 : 'V/tgvoip: Sending UDP ping to 134.209.178.131:555, id -3602320821221394583'
2020-01-11_16:10:32.239446 : 'V/tgvoip: Sending UDP ping to 134.209.178.131:555, id -3602320821221394583'
2020-01-11_16:10:32.239462 : 'V/tgvoip: Sending UDP ping to 134.209.178.88:558, id -1557779231005966908'
2020-01-11_16:10:32.239479 : 'V/tgvoip: Received UDP ping reply from 91.108.8.5:523: date=1578755422, queryID=-6427060238848443264, my IP=86.105.52.145, my port=26531'
2020-01-11_16:10:32.239515 : 'V/tgvoip: Received UDP ping reply from 91.108.8.2:524: date=1578755422, queryID=-694658261907644342, my IP=86.105.52.145, my port=26531'
2020-01-11_16:10:32.239556 : 'V/tgvoip: Received UDP ping reply from 134.209.176.124:552: date=1578754713, queryID=-9190746633918223979, my IP=86.105.52.145, my port=26531'
2020-01-11_16:10:32.239962 : 'V/tgvoip: Received UDP ping reply from 134.209.178.131:555: date=1578755333, queryID=-3602320821221394583, my IP=86.105.52.145, my port=26531'
2020-01-11_16:10:32.239983 : 'V/tgvoip: Received UDP ping reply from 134.209.178.88:558: date=1578755026, queryID=-1557779231005966908, my IP=86.105.52.145, my port=26531'
2020-01-11_16:10:32.240000 : 'W/tgvoip: Send udp pings'
2020-01-11_16:10:32.240016 : 'V/tgvoip: Sending UDP ping to 91.108.8.5:523, id -8736267458746041368'
2020-01-11_16:10:32.240032 : 'V/tgvoip: Sending UDP ping to 91.108.8.2:524, id 8608741114975086036'
2020-01-11_16:10:32.240069 : 'V/tgvoip: Sending UDP ping to 134.209.176.124:552, id -2114693216985638656'
2020-01-11_16:10:32.240089 : 'V/tgvoip: Sending UDP ping to 134.209.178.131:555, id -4128303154435647207'
2020-01-11_16:10:32.240105 : 'V/tgvoip: Sending UDP ping to 134.209.178.88:558, id 7747231581407896919'
2020-01-11_16:10:32.240121 : 'V/tgvoip: Received UDP ping reply from 91.108.8.5:523: date=1578755423, queryID=-8736267458746041368, my IP=86.105.52.145, my port=26531'
2020-01-11_16:10:32.240138 : 'V/tgvoip: Received UDP ping reply from 91.108.8.2:524: date=1578755423, queryID=8608741114975086036, my IP=86.105.52.145, my port=26531'
2020-01-11_16:10:32.240155 : 'V/tgvoip: Received UDP ping reply from 134.209.178.88:558: date=1578755026, queryID=7747231581407896919, my IP=86.105.52.145, my port=26531'
2020-01-11_16:10:32.240172 : 'V/tgvoip: Received UDP ping reply from 134.209.176.124:552: date=1578754713, queryID=-2114693216985638656, my IP=86.105.52.145, my port=26531'
2020-01-11_16:10:32.240188 : 'V/tgvoip: Received UDP ping reply from 134.209.178.131:555: date=1578755334, queryID=-4128303154435647207, my IP=86.105.52.145, my port=26531'
2020-01-11_16:10:32.240205 : 'W/tgvoip: Send udp pings'
2020-01-11_16:10:32.240221 : 'V/tgvoip: Sending UDP ping to 91.108.8.5:523, id 7012775788596422607'
2020-01-11_16:10:32.240237 : 'V/tgvoip: Sending UDP ping to 91.108.8.2:524, id 1131485709082541546'
2020-01-11_16:10:32.240637 : 'V/tgvoip: Sending UDP ping to 134.209.176.124:552, id 5533250358792255060'
2020-01-11_16:10:32.240664 : 'V/tgvoip: Sending UDP ping to 134.209.178.131:555, id -8262545997127981128'
2020-01-11_16:10:32.240686 : 'V/tgvoip: Sending UDP ping to 134.209.178.88:558, id -1935282131501892829'
2020-01-11_16:10:32.240708 : 'V/tgvoip: Received UDP ping reply from 91.108.8.5:523: date=1578755423, queryID=7012775788596422607, my IP=86.105.52.145, my port=26531'
2020-01-11_16:10:32.240751 : 'V/tgvoip: Received UDP ping reply from 91.108.8.2:524: date=1578755423, queryID=1131485709082541546, my IP=86.105.52.145, my port=26531'
2020-01-11_16:10:32.240772 : 'V/tgvoip: Received UDP ping reply from 134.209.176.124:552: date=1578754714, queryID=5533250358792255060, my IP=86.105.52.145, my port=26531'
2020-01-11_16:10:32.240789 : 'V/tgvoip: Received UDP ping reply from 134.209.178.131:555: date=1578755334, queryID=-8262545997127981128, my IP=86.105.52.145, my port=26531'
2020-01-11_16:10:32.240807 : 'V/tgvoip: Received UDP ping reply from 134.209.178.88:558: date=1578755027, queryID=-1935282131501892829, my IP=86.105.52.145, my port=26531'
2020-01-11_16:10:32.240824 : 'I/tgvoip: UDP ping reply count: 4.00'
2020-01-11_16:10:32.241204 : 'W/tgvoip: Init timeout, disconnecting'
2020-01-11_16:10:32.241230 : 'V/tgvoip: Call state changed to 4'
2020-01-11_16:10:32.241247 : 'D/tgvoip: Entered VoIPController::Stop'
2020-01-11_16:10:32.241285 : 'D/tgvoip: before shutdown socket'
2020-01-11_16:10:32.241302 : 'D/tgvoip: before join sendThread'
2020-01-11_16:10:32.241318 : 'D/tgvoip: before join recvThread'
2020-01-11_16:10:32.241334 : 'V/tgvoip: Select canceled'
2020-01-11_16:10:32.241350 : 'I/tgvoip: === recv thread exiting ==='
2020-01-11_16:10:32.241611 : 'D/tgvoip: before stop messageThread'
2020-01-11_16:10:32.241630 : 'D/tgvoip: Before stop audio I/O'
2020-01-11_16:10:32.241646 : 'D/tgvoip: Left VoIPController::Stop [need rate = 0]'
2020-01-11_16:10:32.241662 : 'D/tgvoip: Entered VoIPController::~VoIPController'
2020-01-11_16:10:32.241678 : 'D/tgvoip: before close socket'
2020-01-11_16:10:32.241904 : 'D/tgvoip: before delete audioIO'
2020-01-11_16:10:32.241922 : 'D/tgvoip: before delete encoder'
2020-01-11_16:10:32.241945 : 'D/tgvoip: before delete echo canceller'
2020-01-11_16:10:32.242122 : 'D/tgvoip: Left VoIPController::~VoIPController'

This log was published by @@avegorov at https://t.me/contests_ru
Link on message https://t.me/contests_ru/28424