[Home]

Summary:ASTERISK-15077: [regression] Whisper mode in ChanSpy() has delays and gaps in audio (sometimes not working at all)
Reporter:Marcin Kowalczyk (kowalma)Labels:
Date Opened:2009-11-04 14:12:20.000-0600Date Closed:2011-07-27 13:31:22
Priority:MajorRegression?Yes
Status:Closed/CompleteComponents:Applications/app_chanspy
Versions:Frequency of
Occurrence
Related
Issues:
Environment:Attachments:
Description:Hi,

I found out bug in whisper mode in 1.6.1.8
A = agent

A calls B

C dials in and stats chanspy in whisper mode. When C says sth to A then B hears delayed "gaps" in audio from "A"
Comments:By: Marcin Kowalczyk (kowalma) 2009-11-04 15:33:39.000-0600

I've just got email that 1.6.1.9 is released.
In this version whisper does not work at all.

Call scenario.

originate call from A to B via .call files. A is called via Local channel with /n flag.

C dials into chanspy/extenspy with "w" and tries to speak to active spied channel without luck.
I tried to speak all channels related to this call switching over with *

By: Leif Madsen (lmadsen) 2009-11-04 16:03:17.000-0600

1.6.1.8 is only a security release, as per the release announcement. It is the same code + security fixes as 1.6.1.6. Same thing with newly released 1.6.1.9. Please find the change in the next full release.

By: Marcin Kowalczyk (kowalma) 2009-11-09 14:34:57.000-0600

Hi,

Just checked with 1.6.10-rc2 and whisper is still corrupted.

By: Leif Madsen (lmadsen) 2009-11-09 15:27:47.000-0600

OK, dvossel tested this, but was unable to reproduce immediately. He verified the initial issue he resolved is not back (where whisper mode didn't work at all), but did not obtain the same results as you are reporting here.

Can you provide the console output, along with debugging information, in addition to stating what platform you're using and some information on how best to reproduce this issue?

Thanks!

By: Marcin Kowalczyk (kowalma) 2009-11-09 15:41:48.000-0600

console output:

   -- Remote UNIX connection
   -- Attempting call on Local/agent@agent/n for 00241@out:1 (Retry 1)
   -- Executing [agent@agent:1] Set("Local/agent@agent-1b0c;2", "SPYGROUP=kons") in new stack
   -- Executing [agent@agent:2] GotoIf("Local/agent@agent-1b0c;2", "1?jedno") in new stack
   -- Goto (agent,agent,5)
   -- Executing [agent@agent:5] Set("Local/agent@agent-1b0c;2", "GROUP(KONS)=KONS") in new stack
   -- Executing [agent@agent:6] Answer("Local/agent@agent-1b0c;2", "") in new stack
   -- Executing [00241@out:1] Set("Local/agent@agent-1b0c;1", "spygroup=kons") in new stack
   -- Executing [00241@out:10] Set("Local/agent@agent-1b0c;1", "CALLFILENAME=2009.11.09-22:23:18-00-7172-71-72-27-241--00241-outgoing---root") in new stack
   -- Executing [00241@out:11] Monitor("Local/agent@agent-1b0c;1", "wav,2009.11.09-22:23:18-00-7172-71-72-27-241--00241-outgoing---root.wav,b") in new stack
   -- Executing [00241@out:12] Dial("Local/agent@agent-1b0c;1", "SIP/proxy/00241") in new stack
 == Using SIP RTP CoS mark 5
   -- Called proxy/00241
   -- Executing [agent@agent:7] Wait("Local/agent@agent-1b0c;2", "1") in new stack
   -- Executing [agent@agent:8] Dial("Local/agent@agent-1b0c;2", "SIP/agent") in new stack
 == Using SIP RTP CoS mark 5
   -- Called agent
   -- SIP/agent-00000006 answered Local/agent@agent-1b0c;2
   -- Local/agent@agent-1b0c;1 requested special control 20, passing it to SIP/proxy-00000005
   -- SIP/proxy-00000005 is making progress passing it to Local/agent@agent-1b0c;1
   -- Local/agent@agent-1b0c;1 requested special control 20, passing it to SIP/proxy-00000005
   -- Local/agent@agent-1b0c;1 requested special control 20, passing it to SIP/proxy-00000005
   -- SIP/proxy-00000005 is ringing
   -- Local/agent@agent-1b0c;1 requested special control 20, passing it to SIP/proxy-00000005
   -- Local/agent@agent-1b0c;1 requested special control 20, passing it to SIP/proxy-00000005
   -- SIP/proxy-00000005 answered Local/agent@agent-1b0c;1
 == Using SIP RTP CoS mark 5
   -- Executing [chanspywisper@incomming:1] ChanSpy("SIP/proxy_IN-00000007", ",wqv(0)") in new stack
 == Spying on channel SIP/agent-00000006
[Nov  9 22:23:32] NOTICE[26384]: app_chanspy.c:297 start_spying: Attaching SIP/proxy_IN-00000007 to SIP/agent-00000006
[Nov  9 22:23:32] NOTICE[26384]: app_chanspy.c:297 start_spying: Attaching SIP/proxy_IN-00000007 to SIP/agent-00000006
[Nov  9 22:23:32] NOTICE[26384]: app_chanspy.c:297 start_spying: Attaching SIP/proxy_IN-00000007 to SIP/agent-00000006
[Nov  9 22:23:32] NOTICE[26384]: app_chanspy.c:297 start_spying: Attaching SIP/proxy_IN-00000007 to SIP/agent-00000006
[Nov  9 22:23:32] NOTICE[26384]: app_chanspy.c:297 start_spying: Attaching SIP/proxy_IN-00000007 to Local/agent@agent-1b0c;2
[Nov  9 22:23:32] NOTICE[26384]: app_chanspy.c:297 start_spying: Attaching SIP/proxy_IN-00000007 to Local/agent@agent-1b0c;2
 == Done Spying on channel SIP/agent-00000006
 == Spying on channel SIP/proxy-00000005
[Nov  9 22:23:39] NOTICE[26384]: app_chanspy.c:297 start_spying: Attaching SIP/proxy_IN-00000007 to SIP/proxy-00000005
[Nov  9 22:23:39] NOTICE[26384]: app_chanspy.c:297 start_spying: Attaching SIP/proxy_IN-00000007 to SIP/proxy-00000005
[Nov  9 22:23:39] NOTICE[26384]: app_chanspy.c:297 start_spying: Attaching SIP/proxy_IN-00000007 to SIP/proxy-00000005
[Nov  9 22:23:39] NOTICE[26384]: app_chanspy.c:297 start_spying: Attaching SIP/proxy_IN-00000007 to SIP/proxy-00000005
[Nov  9 22:23:39] NOTICE[26384]: app_chanspy.c:297 start_spying: Attaching SIP/proxy_IN-00000007 to Local/agent@agent-1b0c;1
[Nov  9 22:23:39] NOTICE[26384]: app_chanspy.c:297 start_spying: Attaching SIP/proxy_IN-00000007 to Local/agent@agent-1b0c;1
 == Done Spying on channel SIP/proxy-00000005
 == Spawn extension (incomming, chanspywisper, 1) exited non-zero on 'SIP/proxy_IN-00000007'
   -- Executing [h@incomming:1] NoOp("SIP/proxy_IN-00000007", "0") in new stack
 == Spawn extension (incomming, h, 3) exited non-zero on 'SIP/proxy_IN-00000007'
CC15140*CLI>


call file used to orgiginate call:
Channel: Local/agent@agent/n
MaxRetries: 0
RetryTime: 60
WaitTime: 15
Context: out
Extension: 00241
Priority: 1

call flow scenario.

1. call is beeing origianted from asterisk to agent (A) sip client (sjPhone), agent picks-up and call is beeing setup to 00241 (B) (my internal phone connected on pap2t on proxy). Call setup OK
2. C is dialing in and starts spying. (22:23:32) on this channel whisper does not work (A or B does not hear C).  
3. C is pressing * to switchover to different channel. C says sth to the phone. A hears nothing, B hears choppy sound

I've tested whisper to all channels and on two of them and I think choppy audio for B side occurs time I see on console:

   -- Executing [chanspywisper@incomming:1] ChanSpy("SIP/proxy_IN-0000000a", "Local/,wqv(0)") in new stack
 == Spying on channel Local/agent@agent-3214;2
[Nov  9 22:33:10] NOTICE[26409]: app_chanspy.c:297 start_spying: Attaching SIP/proxy_IN-0000000a to Local/agent@agent-3214;2
[Nov  9 22:33:10] NOTICE[26409]: app_chanspy.c:297 start_spying: Attaching SIP/proxy_IN-0000000a to Local/agent@agent-3214;2
[Nov  9 22:33:10] NOTICE[26409]: app_chanspy.c:297 start_spying: Attaching SIP/proxy_IN-0000000a to Local/agent@agent-3214;2
[Nov  9 22:33:10] NOTICE[26409]: app_chanspy.c:297 start_spying: Attaching SIP/proxy_IN-0000000a to Local/agent@agent-3214;2
[Nov  9 22:33:10] NOTICE[26409]: app_chanspy.c:297 start_spying: Attaching SIP/proxy_IN-0000000a to SIP/agent-00000009
[Nov  9 22:33:10] NOTICE[26409]: app_chanspy.c:297 start_spying: Attaching SIP/proxy_IN-0000000a to SIP/agent-00000009

CC15140:~# uname -a
Linux CC15140 2.6.26-2-686 #1 SMP Sun Jun 21 04:57:38 UTC 2009 i686 GNU/Linux
CC15140:~# cat /proc/cpuinfo
processor       : 0
vendor_id       : GenuineIntel
cpu family      : 15
model           : 2
model name      : Intel(R) Pentium(R) 4 CPU 2.60GHz
stepping        : 9
cpu MHz         : 2593.550
cache size      : 512 KB
fdiv_bug        : no
hlt_bug         : no
f00f_bug        : no
coma_bug        : no
fpu             : yes
fpu_exception   : yes
cpuid level     : 2
wp              : yes
flags           : fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat pse36 clflush dts acpi mmx fxsr sse sse2 ss ht tm pbe up pebs bts cid xtpr
bogomips        : 5192.50
clflush size    : 64
power management:

CC15140:~# cat /etc/debian_version
5.0.2
CC15140:~#



Besides this choppy audio problem whisper does not work at all

Shall I add whireshark trace with RTP?



By: Leif Madsen (lmadsen) 2009-11-11 15:12:18.000-0600

Sure, more information is likely useful.

In addition, if you could provide the console output along with 'recordhistory', 'dumphistory' and 'sipdebug' enabled in sip.conf, and then in logger.conf:

full_info => notice,warning,error,verbose,debug

Then 'core set verbose 10' and 'core set debug 10' after you have reloaded the logging module. Then reproduce the issue and upload the relevant parts of the full_info log file to this issue.

Thanks!

By: Team Forrest (teamforrest) 2009-12-09 16:05:00.000-0600

I am also noticing a complete fail of whisper on 1.6.0 and 1.6.1 branches. Not a delay, but simply not working.

By: Leif Madsen (lmadsen) 2009-12-10 15:10:58.000-0600

Latest checked out branches?

By: Leif Madsen (lmadsen) 2009-12-10 15:21:39.000-0600

For anyone experiencing this; is there any sort of silence suppression (VAD) in use here? There are a few other issues related to that, which could be a culprit here.

By: Team Forrest (teamforrest) 2009-12-10 15:25:53.000-0600

In my case(s), I am not suppressing silence... I'm using SIP devices with:

nat=yes
canreinvite=no
diallow=all
allow=ulaw
allow=alaw
allow=gsm

99% of calls using ulaw.

By: Leif Madsen (lmadsen) 2009-12-10 16:10:41.000-0600

And the devices aren't attempting to suppress silence right? Because that's where the issue lies, in that the device isn't continually sending audio.

By: m0bius (m0bius) 2010-06-10 05:54:00

I've also noticed that whisper is not working on 1.6.x branches. Has this issue being resolved?

By: Leif Madsen (lmadsen) 2010-06-14 14:44:01

As the issue has not yet been closed, then I don't believe the issue has been resolved.

By: Ronald Chan (loloski) 2011-02-17 09:34:34.000-0600

any progress here... thanks

By: Jeremy Kister (jkister) 2011-02-17 10:26:53.000-0600

is this related to 0018382 ?

By: Russell Bryant (russell) 2011-07-27 13:31:14.880-0500

Per the Asterisk maintenance timeline page at http://www.asterisk.org/asterisk-versions maintenance (bug) support for the 1.4 and 1.6.x branches has ended. For continued maintenance support please move to the 1.8 branch which is a long term support (LTS) branch. For more information about branch support, please see https://wiki.asterisk.org/wiki/display/AST/Asterisk+Versions

If this is still an issue, please open a new issue so it can be re-triaged appropriately. Thanks!