[Home]

Summary:ASTERISK-19554: chan_unistim notes warnings about retransmissions of ACK and multiple ACKs received
Reporter:Stefano Villani (playlife82)Labels:
Date Opened:2012-03-16 10:48:17Date Closed:2012-07-16 02:39:20
Priority:MajorRegression?
Status:Closed/CompleteComponents:Channels/chan_unistim
Versions:SVN Frequency of
Occurrence		Frequent
Related
Issues:
Environment:Centos 6 - Latest SVNAttachments:( 0) 1120E-flash-hs-twice.txt
( 1) ASTERISK-19554-rev368681-v1.patch
Description:Suddenly a lot of errors appear "chan_unistim.c: Error : send queue overflow", phones (i2002 phase0 and i2004 phase0) display "server unreachable" before, it has been running ok for a week, now one or two days only. after an asterisk restart everything goes ok.

Suddenly a lot of warning like this

[2012-03-16 16:29:13] WARNING[19682]: chan_unistim.c:1431 send_retransmit: Asked to retransmit an ACKed slot ! last_buf_available=50, seq_server = #0x0133 last_seq_ack = #0x00e3
[2012-03-16 16:29:13] WARNING[19682]: chan_unistim.c:1431 send_retransmit: Asked to retransmit an ACKed slot ! last_buf_available=50, seq_server = #0x0133 last_seq_ack = #0x00e3
[2012-03-16 16:29:13] WARNING[19682]: chan_unistim.c:1431 send_retransmit: Asked to retransmit an ACKed slot ! last_buf_available=50, seq_server = #0x0133 last_seq_ack = #0x00e3
[2012-03-16 16:29:13] NOTICE[19682]: chan_unistim.c:4553 parsing: 192.168.19.41 Warning : ACK received for an already ACKed packet : #0x00c5 we are at #0x00e3
[2012-03-16 16:29:13] NOTICE[19682]: chan_unistim.c:4553 parsing: 192.168.19.41 Warning : ACK received for an already ACKed packet : #0x00c6 we are at #0x00e3
[2012-03-16 16:29:13] NOTICE[19682]: chan_unistim.c:4553 parsing: 192.168.19.41 Warning : ACK received for an already ACKed packet : #0x00c7 we are at #0x00e3
[2012-03-16 16:29:13] NOTICE[19682]: chan_unistim.c:4553 parsing: 192.168.19.41 Warning : ACK received for an already ACKed packet : #0x00c8 we are at #0x00e3
[2012-03-16 16:29:13] NOTICE[19682]: chan_unistim.c:4553 parsing: 192.168.19.41 Warning : ACK received for an already ACKed packet : #0x00c9 we are at #0x00e3
[2012-03-16 16:29:13] NOTICE[19682]: chan_unistim.c:4553 parsing: 192.168.19.41 Warning : ACK received for an already ACKed packet : #0x00ca we are at #0x00e3
[2012-03-16 16:29:13] NOTICE[19682]: chan_unistim.c:4553 parsing: 192.168.19.41 Warning : ACK received for an already ACKed packet : #0x00cb we are at #0x00e3
[2012-03-16 16:29:13] NOTICE[19682]: chan_unistim.c:4553 parsing: 192.168.19.41 Warning : ACK received for an already ACKed packet : #0x00cc we are at #0x00e3
[2012-03-16 16:29:13] NOTICE[19682]: chan_unistim.c:4553 parsing: 192.168.19.41 Warning : ACK received for an already ACKed packet : #0x00cd we are at #0x00e3
[2012-03-16 16:29:13] NOTICE[19682]: chan_unistim.c:4553 parsing: 192.168.19.41 Warning : ACK received for an already ACKed packet : #0x00ce we are at #0x00e3
[2012-03-16 16:29:13] NOTICE[19682]: chan_unistim.c:4553 parsing: 192.168.19.41 Warning : ACK received for an already ACKed packet : #0x00cf we are at #0x00e3
[2012-03-16 16:29:13] NOTICE[19682]: chan_unistim.c:4553 parsing: 192.168.19.41 Warning : ACK received for an already ACKed packet : #0x00d0 we are at #0x00e3
[2012-03-16 16:29:13] NOTICE[19682]: chan_unistim.c:4553 parsing: 192.168.19.41 Warning : ACK received for an already ACKed packet : #0x00d1 we are at #0x00e3
[2012-03-16 16:29:13] NOTICE[19682]: chan_unistim.c:4553 parsing: 192.168.19.41 Warning : ACK received for an already ACKed packet : #0x00d2 we are at #0x00e3
[2012-03-16 16:29:13] NOTICE[19682]: chan_unistim.c:4553 parsing: 192.168.19.41 Warning : ACK received for an already ACKed packet : #0x00d3 we are at #0x00e3
[2012-03-16 16:29:13] NOTICE[19682]: chan_unistim.c:4553 parsing: 192.168.19.41 Warning : ACK received for an already ACKed packet : #0x00d4 we are at #0x00e3
[2012-03-16 16:29:13] NOTICE[19682]: chan_unistim.c:4553 parsing: 192.168.19.41 Warning : ACK received for an already ACKed packet : #0x00d5 we are at #0x00e3
[2012-03-16 16:29:13] NOTICE[19682]: chan_unistim.c:4553 parsing: 192.168.19.41 Warning : ACK received for an already ACKed packet : #0x00d6 we are at #0x00e3
[2012-03-16 16:29:13] NOTICE[19682]: chan_unistim.c:4553 parsing: 192.168.19.41 Warning : ACK received for an already ACKed packet : #0x00d7 we are at #0x00e3
[2012-03-16 16:29:13] NOTICE[19682]: chan_unistim.c:4553 parsing: 192.168.19.41 Warning : ACK received for an already ACKed packet : #0x00d8 we are at #0x00e3
[2012-03-16 16:29:13] NOTICE[19682]: chan_unistim.c:4553 parsing: 192.168.19.41 Warning : ACK received for an already ACKed packet : #0x00d9 we are at #0x00e3
[2012-03-16 16:29:13] NOTICE[19682]: chan_unistim.c:4553 parsing: 192.168.19.41 Warning : ACK received for an already ACKed packet : #0x00da we are at #0x00e3
[2012-03-16 16:29:13] NOTICE[19682]: chan_unistim.c:4553 parsing: 192.168.19.41 Warning : ACK received for an already ACKed packet : #0x00db we are at #0x00e3
[2012-03-16 16:29:13] NOTICE[19682]: chan_unistim.c:4553 parsing: 192.168.19.41 Warning : ACK received for an already ACKed packet : #0x00dc we are at #0x00e3
[2012-03-16 16:29:13] NOTICE[19682]: chan_unistim.c:4553 parsing: 192.168.19.41 Warning : ACK received for an already ACKed packet : #0x00dd we are at #0x00e3
[2012-03-16 16:29:13] NOTICE[19682]: chan_unistim.c:4553 parsing: 192.168.19.41 Warning : ACK received for an already ACKed packet : #0x00de we are at #0x00e3
[2012-03-16 16:29:13] NOTICE[19682]: chan_unistim.c:4553 parsing: 192.168.19.41 Warning : ACK received for an already ACKed packet : #0x00df we are at #0x00e3
[2012-03-16 16:29:13] NOTICE[19682]: chan_unistim.c:4553 parsing: 192.168.19.41 Warning : ACK received for an already ACKed packet : #0x00e0 we are at #0x00e3
[2012-03-16 16:29:13] NOTICE[19682]: chan_unistim.c:4553 parsing: 192.168.19.41 Warning : ACK received for an already ACKed packet : #0x00e1 we are at #0x00e3
[2012-03-16 16:29:13] NOTICE[19682]: chan_unistim.c:4553 parsing: 192.168.19.41 Warning : ACK received for an already ACKed packet : #0x00e2 we are at #0x00e3
[2012-03-16 16:29:15] WARNING[19682]: chan_unistim.c:1431 send_retransmit: Asked to retransmit an ACKed slot ! last_buf_available=50, seq_server = #0x0133 last_seq_ack = #0x00e3
[2012-03-16 16:29:15] WARNING[19682]: chan_unistim.c:1431 send_retransmit: Asked to retransmit an ACKed slot ! last_buf_available=50, seq_server = #0x0133 last_seq_ack = #0x00e3
[2012-03-16 16:29:15] WARNING[19682]: chan_unistim.c:1431 send_retransmit: Asked to retransmit an ACKed slot ! last_buf_available=50, seq_server = #0x0133 last_seq_ack = #0x00e3
[2012-03-16 16:29:15] WARNING[19682]: chan_unistim.c:1431 send_retransmit: Asked to retransmit an ACKed slot ! last_buf_available=50, seq_server = #0x0133 last_seq_ack = #0x00e3
[2012-03-16 16:29:15] WARNING[19682]: chan_unistim.c:1431 send_retransmit: Asked to retransmit an ACKed slot ! last_buf_available=50, seq_server = #0x0133 last_seq_ack = #0x00e3
[2012-03-16 16:29:15] WARNING[19682]: chan_unistim.c:1431 send_retransmit: Asked to retransmit an ACKed slot ! last_buf_available=50, seq_server = #0x0133 last_seq_ack = #0x00e3

unistim.conf
[general]
port=5000                    ; UDP port
[i2004]
device=000ae405c349
rtp_port=10001
rtp_method=3
titledefault=Test       ; default = "TimeZone (your time zone)". 12 characters max
maintext0="Sala Riunioni"  ; default = "Welcome", 24 characters max
maintext1=" "   ; default = the name of the device, 24 characters max
maintext2=" "     ; default = the public IP of the phone, 24 characters max
callerid="Test" <302>
dateformat=1
timeformat=2
ringstyle=0
callhistory=1
context=from-internal
;context=3001_2
linelabel="302"
extension=line
line => 302
;line => 208
bookmark=3@Voicemail@*97@54

[i2002]
rtp_port=10001              ; RTP port used by the phone, default = 10000. RTCP = rtp_port+1
rtp_method=3
device=000ae402ebf1
ringstyle=7
language=it
;bookmark=Support@123 ; Every phone will have a softkey Support
status_method=1             ; If you don't see status text, try 1, default = 0
maintext0="Contabilita"  ; default = "Welcome", 24 characters max
maintext1=" "   ; default = the name of the device, 24 characters max
maintext2=" "     ; default = the public IP of the phone, 24 characters max
dateformat=1                ; 0 = month/day, 1 (default) = day/month
callerid="Contabilita" <309>
;timeformat=1                ; 0 = 0:00am ; 1 (default) = 0h00, 2 = 0:00
;contrast=8                  ; define the contrast of the LCD. From 0 to 15. Default = 8
;context=from-internal
country=ch
linelabel="309"
callgroup=1
pickupgroup=1
context=from-internal
;context=3001_2
extension=line
line => 309
;line => 204
bookmark=3@Voicemail@*97@54





Comments:By: Matt Jordan (mjordan) 2012-03-16 13:04:44.093-0500

chan_unistim in trunk did just receive a major patch.  I've assigned this to Igor, as he is the maintainer of chan_unistim.
By: Igor Goncharovsky (igorg) 2012-03-17 00:27:35.927-0500

Stefano, I'll need some time to run constantrly chan_unistim at office. I need to know what hardware you use and architecture ti run asterisk?
By: Stefano Villani (playlife82) 2012-03-19 08:41:37.756-0500

Igor,

so installation is based on Centos 6 and Vmware Vsphere 5, server is an Intel QuadCore based with 10 giga of ram.

Do you need another info?

Thanks.
Stefano
By: Igor Goncharovsky (igorg) 2012-03-19 10:48:19.673-0500

No additional information now needed, I'll try to reproduce it first
By: Daniel Bohling (dbohling) 2012-03-20 21:10:22.895-0500

I'm seeing this issue also. Here's how to reproduce. Lift handset, dial 4-5 digits, press and release handset cradle rocker (as if user has decided to use the handset cradle to cancel call and re-enter digits). About 40% of the time the phone attempts to dial despite the hangup attempt causing the phone to hang (eventually rebooting itself) and the flood of messages in the logs. HTH.

These messages an be triggered by picking up and hanging up the physical handset during the hang:

[2012-03-20 18:53:13] WARNING[6079]: chan_unistim.c:1431 send_retransmit: Asked to retransmit an ACKed slot ! last_buf_available=50, seq_server = #0x05d7 last_seq_ack = #0x03f7
[2012-03-20 18:53:13] WARNING[6079]: chan_unistim.c:1431 send_retransmit: Asked to retransmit an ACKed slot ! last_buf_available=50, seq_server = #0x05d7 last_seq_ack = #0x03f7


Otherwise messages in log during the hang are:
[2012-03-20 19:00:23] NOTICE[6079]: chan_unistim.c:4553 parsing: 10.10.110.123 Warning : ACK received for an already ACKed packet : #0x0176 we are at #0x0179
[2012-03-20 19:00:23] NOTICE[6079]: chan_unistim.c:4553 parsing: 10.10.110.123 Warning : ACK received for an already ACKed packet : #0x0177 we are at #0x0179
[2012-03-20 19:00:23] NOTICE[6079]: chan_unistim.c:4553 parsing: 10.10.110.123 Warning : ACK received for an already ACKed packet : #0x0178 we are at #0x0179
[2012-03-20 19:00:25] WARNING[6079]: chan_unistim.c:1431 send_retransmit: Asked to retransmit an ACKed slot ! last_buf_available=50, seq_server = #0x0214 last_seq_ack = #0x0179
[2012-03-20 19:00:25] WARNING[6079]: chan_unistim.c:1431 send_retransmit: Asked to retransmit an ACKed slot ! last_buf_available=50, seq_server = #0x0214 last_seq_ack = #0x0179



SVN-trunk-r360036, i2004 phase 2 phones
32bit Ubunutu 7.10 on Dual-Core Opteron
By: Jonn Taylor (jonnt) 2012-03-20 22:48:30.294-0500

I can reproduce this problem on an 1120E, SVN-trunk-r359857, by lifting the handset, dialing more than 3 numbers and them flashing the hook switch 2 times and then phone says calling..., phone stops responding and errors show in the log. I have attached a log file that unistim debug on.
By: Stefano Villani (playlife82) 2012-03-21 05:08:04.021-0500

Today all unistim phones stop to register to server "server is unreachable")

This is the error on asterisk console

[Mar 21 10:38:50] WARNING[13469] chan_unistim.c: Error : send queue overflow
[Mar 21 10:38:50] WARNING[13469] chan_unistim.c: Error : send queue overflow

after an asterisk restart everything goes ok.

Thanks.
Stefano

UPDATE: Before unistim crash in the log I found this, maybe is not important..

[Mar 21 10:30:28] ERROR[13430] astobj2.c: user_data is NULL
[Mar 21 10:31:50] WARNING[13431] chan_unistim.c: Error : send queue overflow

By: Jonn Taylor (jonnt) 2012-03-24 19:16:09.128-0500

In doing more testing it looks like the hook switch is behaving differently that the release key. If dial 4 or more digits and hangup the phone using the hook switch but keeping the phone to your ear the phone still tries to dial. If you use the release key this does not happen and the queue overflow does not happen either.
By: Igor Goncharovsky (igorg) 2012-06-08 03:56:48.946-0500

Please try this simple patch, it fixes cradle pressing and prevent unwanted dialing. I have not able to reproduce retransmission issue with i2002.
By: Daniel Bohling (dbohling) 2013-02-15 15:22:25.882-0600

I believe the issue reported by stefano requiring the asterisk restart is related to https://issues.asterisk.org/jira/browse/ASTERISK-21119 . Patch there should fix.