ASTERISK-08793: ExtensionState remains 'Hold' after putting a call off hold

[Home]

Summary: ASTERISK-08793: ExtensionState remains 'Hold' after putting a call off hold

Reporter: Christoph Stadlmann (cstadlmann) Labels:

Date Opened: 2007-02-13 10:05:51.000-0600 Date Closed: 2007-05-22 09:34:08

Priority: Minor Regression? No

Status: Closed/Complete Components: Channels/chan_sip/Subscriptions

Versions: Frequency of
Occurrence

Related
Issues:

Environment: Attachments: ( 0) [mackey]chan_sip.c.1-4-4.patch
( 1) [mackey]chan_sip.c.1-4-4.v2.patch
( 2) [mackey]chan_sip.c.1-4-4.v3.patch
( 3) [mackey]chan_sip.c.1-4-4.v4.patch
( 4) [mackey]chan_sip.c.patch
( 5) [mackey]chan_sip.c.v2.patch.txt
( 6) extensions-r56095.conf
( 7) sip.conf
( 8) sip-r56095.conf
( 9) verbosedebug1.txt
(10) verbosedebug-r56095.txt
(11) verbosedebug-SJPhone_holds.txt
(12) verbosedebug-Snom_holds.txt

Description: When an extension put's a call on-hold, the devicestate changes to 'Hold' as it should be, but after the extension resumes the call, the state remains unchanged and never changes back.

asterisktest*CLI> sip show inuse
* User name In use Limit
* Peer name In use Limit
103 0/0/0 2
102 0/0/0 2
101 0/0/0 2
asterisktest*CLI> core show hints
asterisktest*CLI>
-= Registered Asterisk Dial Plan Hints =-
103@from-sip : SIP/103 State:Idle Watchers 0
102@from-sip : SIP/102 State:Unavailable Watchers 0
101@from-sip : SIP/101 State:Idle Watchers 0
----------------
- 3 hints registered
-- Executing [103@from-sip:1] Dial("SIP/101-0818d5d8", "SIP/103") in new stack
-- Called 103
-- SIP/103-08192ab8 is ringing
-- Call on SIP/103-08192ab8 left from hold
-- SIP/103-08192ab8 answered SIP/101-0818d5d8
-- Packet2Packet bridging SIP/101-0818d5d8 and SIP/103-08192ab8
asterisktest*CLI> sip show inuse
* User name In use Limit
* Peer name In use Limit
103 1/0/0 2
102 0/0/0 2
101 1/0/0 2
-- Started music on hold, class 'default', on SIP/103-08192ab8
asterisktest*CLI> sip show inuse
* User name In use Limit
* Peer name In use Limit
103 1/0/0 2
102 0/0/0 2
101 1/0/1 2
-- Stopped music on hold on SIP/103-08192ab8
asterisktest*CLI> sip show inuse
* User name In use Limit
* Peer name In use Limit
103 1/0/0 2
102 0/0/0 2
101 1/0/1 2
== Spawn extension (from-sip, 103, 1) exited non-zero on 'SIP/101-0818d5d8'
asterisktest*CLI> sip show inuse
* User name In use Limit
* Peer name In use Limit
103 0/0/0 2
102 0/0/0 2
101 0/0/1 2
asterisktest*CLI> core show hints
asterisktest*CLI>
-= Registered Asterisk Dial Plan Hints =-
103@from-sip : SIP/103 State:Idle Watchers 0
102@from-sip : SIP/102 State:Unavailable Watchers 0
101@from-sip : SIP/101 State:Hold Watchers 0
----------------
- 3 hints registered

Comments: By: Serge Vecher (serge-v) 2007-02-13 10:24:23.000-0600

ok, something is missing from verbosedebug.txt -- I think "sip set debug" was not on --> can you please redo the debug as per instructions that I usually post. Thanks.
By: Christoph Stadlmann (cstadlmann) 2007-02-14 01:53:02.000-0600

Sorry, you were right. SIP debugging was not enabled. Please see attached file verbosedebug1.txt
FYI, I put the call on hold two times (and also resumed it).
By: Serge Vecher (serge-v) 2007-02-14 13:00:18.000-0600

does the branch by oej mentioned in bug 8848 note ASTERISK-5772278 impact this?
By: Olle Johansson (oej) 2007-02-14 14:51:57.000-0600

No, it doesn't affect hold states.

if you are using type=friend, can you please check what happens if you change those to type=peer

(I am not mad, please test :-)

If that does not fix it, please check if you have re-invites enabled. If you have, then disable it and test again.

Thank you for doing these tests and giving us feedback!
By: Christoph Stadlmann (cstadlmann) 2007-02-15 01:52:13.000-0600

All devices are having type=peer, otherwise device states don't work at all (See bug 8800)...
Also, canreinvite=no.
I've uploaded the sip.conf located at my test asterisk server.
By: Christoph Stadlmann (cstadlmann) 2007-02-20 10:30:19.000-0600

Any updates yet? Please advise if you need further information.
By: Joshua C. Colp (jcolp) 2007-02-21 11:37:46.000-0600

Please try 1.4 as of revision 55914. Thanks!
By: Christoph Stadlmann (cstadlmann) 2007-02-22 01:17:33.000-0600

Sorry to say... Still doesn't work. Devicestate still remains 'Hold' after putting call off hold. Should I provide a verbosedebug?

asterisktest*CLI>
-- Executing [1566@from-sip:1] NoCDR("SIP/101-081cdac0", "") in new stack
[Feb 22 08:11:57] NOTICE[16518]: cdr.c:429 ast_cdr_free: CDR on channel 'SIP/101-081cdac0' not posted
[Feb 22 08:11:57] NOTICE[16518]: cdr.c:431 ast_cdr_free: CDR on channel 'SIP/101-081cdac0' lacks end
-- Executing [1566@from-sip:2] PlayTones("SIP/101-081cdac0", "ring") in new stack
-- Executing [1566@from-sip:3] Wait("SIP/101-081cdac0", "5") in new stack
asterisktest*CLI> sip show inuse
* User name In use Limit
* Peer name In use Limit
103 0/0/0 2
102 0/0/0 2
101 1/0/0 2
-- Executing [1566@from-sip:4] StopPlayTones("SIP/101-081cdac0", "") in new stack
-- Executing [1566@from-sip:5] Answer("SIP/101-081cdac0", "") in new stack
-- Executing [1566@from-sip:6] Playback("SIP/101-081cdac0", "/var/lib/asterisk/moh/fpm-calm-river") in new stack
-- <SIP/101-081cdac0> Playing '/var/lib/asterisk/moh/fpm-calm-river' (language 'de')
asterisktest*CLI> sip show inuse
* User name In use Limit
* Peer name In use Limit
103 0/0/0 2
102 0/0/0 2
101 1/0/0 2
RTCP SR transmission error, rtcp halted
[Feb 22 08:12:12] NOTICE[16518]: sched.c:284 ast_sched_del: Attempted to delete nonexistent schedule entry 20!
asterisktest*CLI> sip show inuse
* User name In use Limit
* Peer name In use Limit
103 0/0/0 2
102 0/0/0 2
101 1/0/1 2
asterisktest*CLI> core show hints
asterisktest*CLI>
-= Registered Asterisk Dial Plan Hints =-
103@from-sip : SIP/103 State:Idle Watchers 0
102@from-sip : SIP/102 State:Unavailable Watchers 0
101@from-sip : SIP/101 State:Hold Watchers 0
----------------
- 3 hints registered
== Spawn extension (from-sip, 1566, 6) exited non-zero on 'SIP/101-081cdac0'
asterisktest*CLI> core show hints
asterisktest*CLI>
-= Registered Asterisk Dial Plan Hints =-
103@from-sip : SIP/103 State:Idle Watchers 0
102@from-sip : SIP/102 State:Unavailable Watchers 0
101@from-sip : SIP/101 State:Hold Watchers 0
----------------
- 3 hints registered
asterisktest*CLI> sip show inuse
* User name In use Limit
* Peer name In use Limit
103 0/0/0 2
102 0/0/0 2
101 0/0/1 2
asterisktest*CLI> core show version
Asterisk SVN-trunk-r56095 built by root @ asterisktest on a i686 running Linux on 2007-02-22 07:04:43 UTC
By: Serge Vecher (serge-v) 2007-02-22 09:09:14.000-0600

cstadlmann: thank you for testing and continuing to help us track this down! If the issue is not resolved, you can safely assume that we will need an updated verbosedebug log to track down the problem further.
By: Christoph Stadlmann (cstadlmann) 2007-02-22 10:23:43.000-0600

The phenomenon is even worse now. In the attached file 'verbosedebug-r56095.txt' I made the following sequence:

1) 101 calls 103
2) 103 picks up and talks to 101
3) 101 puts the call on hold, 103 hears moh
4) 103 hangs up
5) 101 suddenly hears moh (!!!), call is not ended
6) 101 hangs up

After that sequence, both parties are on 'Hold'...
By: Joshua C. Colp (jcolp) 2007-02-22 10:42:09.000-0600

Here is what the SIP signalling is showing:

SIP/101 calls SIP/103
SIP/103 rings
SIP/103 answers
SIP/101 puts SIP/103 on hold
SIP/101 takes SIP/103 off hold
SIP/103 puts SIP/101 on hold
SIP/103 hangs up

What steps and devices are you doing to test this? From what I gathered SJphone and an SPA941?
By: Christoph Stadlmann (cstadlmann) 2007-02-23 01:14:08.000-0600

For the latest test you are right. The current setup is just a simple lab environment and we are testing with multiple devices, even softphones. If you want me to test with other devices, I could provide Snom 190, Snom 220, Snom 360, Patton SmartNode, Linksys SPA 901, Linksys SPA 921, Linksys SPA941, Linksys PAP-2, Linksys PAP2-T, Grandstream GXP2000, Grandstream HT286, Grandstream HT486.

Just tell me, or even better, set up an asterisk server with the attached sip.conf and extensions.conf if you like and I'm sure you can reproduce the bug.

Anyway, if we pressed the wrong button during the latest test and 103 really put the call on hold... After both parties hang up, the devicestate should be 'Idle' again for both devices. Don't you agree?
By: Serge Vecher (serge-v) 2007-02-23 09:33:25.000-0600

Yeah, devicestate changes that follow this line do not look right:

I wonder if it's possible to add what the actual state change is to the following debugging line:
__ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/101

By: Joshua C. Colp (jcolp) 2007-02-23 11:50:43.000-0600

Here's something that may help...

You have both the options "limitpeersonly=yes" and "limitonpeer=yes" while the correct option is "limitonpeers=yes".
By: Christoph Stadlmann (cstadlmann) 2007-02-24 03:21:05.000-0600

Tried with Asterisk SVN-trunk-r56594, still doesn't work. Also tried the options in sip.conf mentioned by file. No change.
Please don't tell me you can't reproduce that bug in your own lab...
By: Joshua C. Colp (jcolp) 2007-02-26 14:47:53.000-0600

Using the configurations provided I was still unable to reproduce. Can I get access to the box where this happens?
By: Serge Vecher (serge-v) 2007-03-20 09:24:12

cstadlmann: what's the status here?
By: Christoph Stadlmann (cstadlmann) 2007-03-26 10:16:04

@serge-v:
Sorry for not responding for a while, but currently I have another project running. As soon as have a little extra time I will resume tests with the lastest svn.
By: pkempgen (pkempgen) 2007-03-31 01:58:36

I have seen this go wrong with 1.4.2 (using Snom 360) yesterday
but I am currently unable to reproduce this bug with the trunk.

By: pkempgen (pkempgen) 2007-03-31 15:37:47

I have just seen this happen twice even for the trunk but
still do not now what it takes to reproduce the bug.
By: Serge Vecher (serge-v) 2007-04-02 09:49:43

pkempgen: thanks for heads up. We will need a sip debug though to go forward though.
By: Christoph Stadlmann (cstadlmann) 2007-04-05 05:23:05

Found out something: This bug does not happen with Snom phones with latest release version 1.4.2 or latest svn. I could only reproduce the bug with SJphone, which seems to send something strange to the Asterisk server. Should I provide debug info?
By: Serge Vecher (serge-v) 2007-04-05 08:48:03

cstadlmann: yes, please produce a log from SJPHone and another from SNow, so we can contrast/compare the differences.
By: Christoph Stadlmann (cstadlmann) 2007-04-05 10:40:35

Attached 2 files as you requested:

'verbosedebug-SJPhone holds.txt': SJPhone initiates 'Hold' and resumes, state remains 'Hold', even after hangup -> wrong behavior.

'verbosedebug-Snom holds.txt': Snom initiates 'Hold' and resumes, state changes back to 'Inuse' and after hangup to 'Idle' -> correct behavior.

BTW, logs come from 1.4.2 release version, but same behavior with latest svn.

By: Joshua C. Colp (jcolp) 2007-04-08 19:51:15

Okay, I need access to a setup that has this... where I can modify code and see what stuff is doing.
By: Christoph Stadlmann (cstadlmann) 2007-04-09 02:00:53

file: How can I grant access without posting sentitive data here?
By: Joshua C. Colp (jcolp) 2007-04-09 07:00:54

Argh I keep doing that... forgetting to leave my email. It's file@digium.com or jcolp@digium.com
By: Christoph Stadlmann (cstadlmann) 2007-04-12 07:49:10

Any updates here?
By: Olle Johansson (oej) 2007-04-27 09:41:24

I've seen this happen. Haven't found the cause.
By: Brad Barnett (bbarnett) 2007-05-06 17:34:34

Hmm.

I'm wondering if the bug I'm seeing here, is related. I'm using Debian's 1.4.4 packages.

First, any time I place a SIP call, I see this:

-- Call on SIP/did.voip.les.net-081f0ca8 left from hold

Perhaps this is a workaround in 1.4.4 for the bug posted here? Regardless, it causes my 'm' flag when dialing to not work correctly. For example, I have a dial command that dials a ZAP and a SIP at the same time. As soon as progress is made with the SIP call, musiconhold-dialing disappears... such as:

-- Executing [s@macro-stdexten:2] Dial("Zap/4-1", "Zap/1&SIP/xxxxxxx@xxxxxxx.net|30|m") in new stack
-- Called 1
[May 6 18:32:56] WARNING[14691]: rtp.c:1946 ast_rtp_settos: Unable to set TOS to 184
-- Called xxxxxxx@xxxxxxxxxxx.net
-- Started music on hold, class 'default', on channel 'Zap/4-1'
-- Zap/1-2 is ringing
-- CPE supports Call Waiting Caller*ID. Sending '/xxxxxxxxxx'
-- Call on SIP/xxxxxxxxx.net-081c3608 left from hold
-- Stopped music on hold on Zap/4-1
-- SIP/xxxxxxxxxxxx.net-081c3608 is making progress passing it to Zap/4-1

Basically, as soon as the SIP call starts to ring (just as when I make a simple SIP call out) music-on-hold is forced off.

Ideas?
By: Joshua C. Colp (jcolp) 2007-05-07 16:51:24

I have fixed your issue bbarnett under 1.4 as of revision 63283.
By: mackey (mackey) 2007-05-08 08:58:03

Well, I found _a_ fix, not sure if it's the "right" one...

diff -u chan_sip.c\?rev\=63136 chan_sip.c
--- chan_sip.c?rev=63136 2007-05-08 09:55:14.000000000 -0400
+++ chan_sip.c 2007-05-08 09:47:28.000000000 -0400
@@ -5724,6 +5724,8 @@
ast_set_flag(&p->flags[1], SIP_PAGE2_CALL_ONHOLD_ONEDIR);
else if (sendonly == 2) /* Inactive stream */
ast_set_flag(&p->flags[1], SIP_PAGE2_CALL_ONHOLD_INACTIVE);
+ else
+ ast_set_flag(&p->flags[1], SIP_PAGE2_CALL_ONHOLD);
if (global_notifyhold)
sip_peer_hold(p, TRUE);
}

With that, it's working again! It seems SIP_PAGE2_CALL_ONHOLD was never set for 2-way calls...

By: mackey (mackey) 2007-05-09 12:46:23

Looking at the code a bit more, we either need another SIP_PAGE2_CALL_ONHOLD_* flag for active 2-way calls, or the "if" statement needs to be rewritten to not check SIP_PAGE2_CALL_ONHOLD . I also noticed there is no code to take sendonly/recvonly and inactive calls off hold.
By: mackey (mackey) 2007-05-12 02:57:28

Ok, cleaned it up a bit. Could a dev look at this patch please? So far it's working great on my system.
By: Christoph Stadlmann (cstadlmann) 2007-05-12 04:15:49

@mackey:
As our production servers are running Asterisk 1.4.4 I tried to patch against that version, didn't work. Also didn't patch against branch 1.4.
Seems that code changed too much...

Do you see any possibility to help me patch the release version?
By: mackey (mackey) 2007-05-12 05:16:22

patch for 1.4.4 added.

[mackey]chan_sip.c.patch <- svn trunk
[mackey]chan_sip.c.1-4-4.v3.patch <- 1.4.4

edit: Ugh, the 1.4.4 one was incomplete. Use the v2.
edit2: Crap, a typeo in v2. v3 coming up... >_>

By: mackey (mackey) 2007-05-12 07:01:27

Fixed a problem with the previous patches. Should work fine now.

svn-trunk => [mackey]chan_sip.c.v2.patch.txt
1.4.4 => [mackey]chan_sip.c.1-4-4.v4.patch

admin: all but those 2 can be deleted

By: Christoph Stadlmann (cstadlmann) 2007-05-12 09:31:17

@mackey:
Thanks for the patch. I just compiled it with no errors, will test in the next days if the problem has gone.

BTW, you seem to be very experienced with chan_sip and Asterisk. Maybe you could help me with another problem I've got which oej is refusing to solve. Please contact me at c.stadlmann(at)mywave.at. If you can solve the problem, I'm willing to pay a bounty.
By: jmls (jmls) 2007-05-12 12:29:53

please check the latest svn build for 1.4. It fixed my problem
By: mackey (mackey) 2007-05-12 15:46:23

The fix applied to the trunk was the first one I came up with. It fixes the hold problem, but it also sets both SIP_PAGE2_CALL_ONHOLD_ONEDIR and SIP_PAGE2_CALL_ONHOLD_INACTIVE, so testing for either of those flags won't get the results you're expecting.
By: Joshua C. Colp (jcolp) 2007-05-12 16:12:37

I've finished tweaking it as of revision 64086.
By: Christoph Stadlmann (cstadlmann) 2007-05-13 14:01:00

@mackey: Sorry to say, but after applying the patch I get one-way audio. Maybe it has something to do with the activated jitterbuffer (jbforce=yes), because I only get the jitterbuffer message for ONE channel. I will test it tomorrow, but maybe you can have a look at it yourself in the meantime.
By: Joshua C. Colp (jcolp) 2007-05-14 10:08:35

Please try with a clean version of Asterisk from subversion, reported issue here should be gone... if the jitterbuffer one still exists, I would prefer a new bug be opened for that with information.
By: Christoph Stadlmann (cstadlmann) 2007-05-22 02:17:23

One-way audio does not occur in branch-1.4. Don't know if it was related to jitterbuffer because I switched from release version to branch completely and don't have any release * anymore.
Nevertheless I guess that the patch for 1.4.4 is not working. Someone should check this.
By: Joshua C. Colp (jcolp) 2007-05-22 09:34:03

Since this has been fixed now in the 1.4 branch it will be in the next release. Peace!