[Home]

Summary:ASTERISK-17193: ChanSpy leaves channel in Up state behind, warnings
Reporter:Kirill Katsnelson (kkm)Labels:
Date Opened:2010-12-31 00:38:18.000-0600Date Closed:2011-06-07 14:04:41
Priority:MinorRegression?No
Status:Closed/CompleteComponents:Applications/app_chanspy
Versions:Frequency of
Occurrence
Related
Issues:
Environment:Attachments:
Description:ChanSpy leaves a channel behind after every time the spying phone hangs up, provided it has spied on at least one conversation.

pbx6*CLI> core show channels
Channel              Location             State   Application(Data)
SIP/250-00000006     s@app-chanspy:4      Up      ChanSpy(SIP/,s)
SIP/250-0000000d     s@app-chanspy:4      Up      ChanSpy(SIP/,s)
2 active channels
2 active calls

****** STEPS TO REPRODUCE ******

During a SIP call, with only 2 channels in the PBX, *7 is dialed on a SIP phone.

 *7 => {
   NoCDR();
   Answer();
   Wait(1);
   ChanSpy(SIP/,s);
   Hangup();
 };

Three notices are printed:

[2010-12-30 21:04:46.376] NOTICE[44714]: app_chanspy.c:479 start_spying: Attaching SIP/250-00000006 to SIP/trunk-00000004
[2010-12-30 21:04:46.376] NOTICE[44714]: app_chanspy.c:479 start_spying: Attaching SIP/250-00000006 to SIP/trunk-00000004
[2010-12-30 21:04:46.376] NOTICE[44714]: app_chanspy.c:479 start_spying: Attaching SIP/250-00000006 to SIP/dyn-Agent-13100-00000005

Here SIP/250 is the spying phone, and SIP/trunk and SIP/dyn-Agent-13100 are conversing parties. Spying proceeds nominally. Then the original call ends first. 2 notices are printed at that moment

[2010-12-30 21:06:07.799] NOTICE[44714]: app_chanspy.c:479 start_spying: Attaching SIP/250-00000006 to SIP/dyn-Agent-13100-00000005
[2010-12-30 21:06:07.800] NOTICE[44714]: app_chanspy.c:479 start_spying: Attaching SIP/250-00000006 to SIP/dyn-Agent-13100-00000005

The spying phone hangs up next. There are warnings printed 6 seconds after the spying phone hangs:

[2010-12-30 21:06:18.260] NOTICE[31304]: chan_sip.c:24298 check_rtp_timeout: Disconnecting call 'SIP/250-00000006' for lack of RTP activity in 6 seconds
[2010-12-30 21:06:19.064] WARNING[31304]: chan_sip.c:3621 __sip_autodestruct: Autodestruct on dialog '3e119b2c-8ee73b1f@192.168.0.90' with owner in place (Method: BYE)

192.168.0.90 is the address and SIP domain name for the spying phone. RTP inactivity timeout is set to 5 seconds globally in the PBX, so the 6 seconds timeout is understandable.

The spying channel sits in the PBX forever. `channel request hangup' does not help.

pbx6*CLI> channel request hangup SIP/250-00000006
Requested Hangup on channel 'SIP/250-00000006'
pbx6*CLI> core show channels
Channel              Location             State   Application(Data)
SIP/250-00000006     s@app-chanspy:4      Up      ChanSpy(SIP/,s)
SIP/250-0000000d     s@app-chanspy:4      Up      ChanSpy(SIP/,s)
2 active channels
2 active calls


****** ADDITIONAL INFORMATION ******

I can debug asterisk live, or catch it at nay interesting point and post traces, but have no idea where to start. Suggestions appreciated.
Comments:By: Kirill Katsnelson (kkm) 2010-12-31 00:53:35.000-0600

Addendum. That happens always on one particular trunk. This is a private trunk to one of our customers over a VPN, otherwise nothing special. Worst of all, I cannot reproduce the problem with an exact copy of that trunk and a lab copy of customer's PBX (Avaya IPO). But on the real trunk it happens every single time.
By: Leif Madsen (lmadsen) 2011-01-05 09:38:15.000-0600

I'd suggest posting a 'core show locks' and a backtrace from the running process.
By: Leif Madsen (lmadsen) 2011-01-05 09:43:25.000-0600

https://wiki.asterisk.org/wiki/display/AST/Getting+a+Backtrace
By: Kirill Katsnelson (kkm) 2011-01-13 09:47:36.000-0600

Amazing but I cannot reproduce that any more. Let me put the issue on hold until I roll 1.8 up to more servers.