ChanSpy Ends Call

Asterisk Asterisk Support
1

When using ChanSpy to monitor a call I more often than not experience an issue where the call is ended. Here is the scenario.

context for ChanSpy
[myspy]
exten = *76,1,Answer()
exten = *76,2,Chanspy(SIP/5002,qb)

If I dial *76 before there is a call active on 5002 and then a call comes in or goes out everything works fine, but if a call is already in progress on 5002 and I use ChanSpy it ends the call (the ChanSpy call stays up).

Here is what I see on the console, starting with the call starting on the extension and then using ChanSpy from another phone.

-- Executing [nomirror@macro-tlfxcallmanager:1] Dial("SIP/rf-HVC-0000001f", "SIP/ewrfauto5002,25") in new stack

== Using SIP RTP CoS mark 5
– Called ewrfauto5002
– SIP/ewrfauto5002-00000020 is ringing
– SIP/ewrfauto5002-00000020 answered SIP/rf-HVC-0000001f
– Packet2Packet bridging SIP/rf-HVC-0000001f and SIP/ewrfauto5002-00000020
== Using SIP RTP CoS mark 5
– Executing [*76@teleflex_phones:1] Answer(“SIP/ewrfauto5001-00000021”, “”) in new stack
– Executing [*76@teleflex_phones:2] Read(“SIP/ewrfauto5001-00000021”, “EXT,agent-newlocation”) in new stack
– <SIP/ewrfauto5001-00000021> Playing ‘agent-newlocation.ulaw’ (language ‘en’)
– User entered ‘5002’
– Executing [*76@teleflex_phones:3] ChanSpy(“SIP/ewrfauto5001-00000021”, “SIP/ewrfauto5002,q”) in new stack
== Spying on channel SIP/ewrfauto5002-00000020
[Nov 17 02:50:34] NOTICE[3190]: app_chanspy.c:414 start_spying: Attaching SIP/ewrfauto5001-00000021 to SIP/ewrfauto5002-00000020
[Nov 17 02:50:34] NOTICE[3190]: app_chanspy.c:414 start_spying: Attaching SIP/ewrfauto5001-00000021 to SIP/ewrfauto5002-00000020
[Nov 17 02:50:34] NOTICE[3190]: app_chanspy.c:414 start_spying: Attaching SIP/ewrfauto5001-00000021 to SIP/rf-HVC-0000001f
– Native bridging SIP/rf-HVC-0000001f and SIP/ewrfauto5002-00000020 ended
== Spawn extension (macro-tlfxcallmanager, nomirror, 1) exited non-zero on ‘SIP/rf-HVC-0000001f’ in macro ‘tlfxcallmanager’
== Spawn extension (tel01_internal, 5002, 2) exited non-zero on ‘SIP/rf-HVC-0000001f’
== Done Spying on channel SIP/ewrfauto5002-00000020
== Spawn extension (teleflex_phones, *76, 3) exited non-zero on ‘SIP/ewrfauto5001-00000021’

What is particularly odd is the behavior is not 100%. Sometimes I can succesfully ChanSpy without killing the call; though most of the time it does kill it. The main difference that sticks out when looking at the console is the “Native bridging … ended” This only appears in the cases where the call is killed.

I have tried setting the “transmit_silence” parameters in asterisk.conf for good measure, but that doesn’t seem to make a difference.

I have also tried to use ExtenSpy with the same results.

Asterisk version is : Asterisk 1.6.2.11 built by on a x86_64 running Linux on 2010-08-28 21:36:52 UTC

Any help would be greatly appreciated.

2

I’m having the same issue on Asterisk 1.6.2.7 x86_64. The issue rarely occurs for us, but when it does, I’m noticing the same,
channel.c: – Native bridging SIP/contextremoved-000676f4 and SIP/extenremoved-000676f8 ended.

Has anyone else encountered this?

3

I am having the same issue on Asterisk 1.6.2.9-2+squeeze3 (Debian package). Abount 50% (or more) of calls get dropped. When it works, it tends to work for some times. When it starts to fail, it fails all times.

This is a debug trace of a dropped call:

[Jul 21 13:05:59] VERBOSE[7781] app_chanspy.c: == Spying on channel SIP/1050000019-000000f2
[Jul 21 13:05:59] NOTICE[7781] app_chanspy.c: Attaching SIP/1050000001-000000f1 to SIP/1050000019-000000f2
[Jul 21 13:05:59] DEBUG[7781] channel.c: Soft-Hanging up channel ‘SIP/ehiweb-000000f3’
[Jul 21 13:05:59] NOTICE[7781] app_chanspy.c: Attaching SIP/1050000001-000000f1 to SIP/1050000019-000000f2
[Jul 21 13:05:59] DEBUG[7781] channel.c: Soft-Hanging up channel ‘SIP/ehiweb-000000f3’
[Jul 21 13:05:59] NOTICE[7781] app_chanspy.c: Attaching SIP/1050000001-000000f1 to SIP/ehiweb-000000f3
[Jul 21 13:05:59] DEBUG[7781] channel.c: Soft-Hanging up channel ‘SIP/1050000019-000000f2’
[Jul 21 13:05:59] DEBUG[7781] channel.c: Scheduling timer at (50 requested / 50 actual) timer ticks per second
[Jul 21 13:05:59] NOTICE[7784] rtp.c: p2p-rtp-bridge: Ooh, empty read…
[Jul 21 13:05:59] VERBOSE[7784] channel.c: – Native bridging SIP/1050000019-000000f2 and SIP/ehiweb-000000f3 ended
[Jul 21 13:05:59] DEBUG[7784] channel.c: Didn’t get a frame from channel: SIP/ehiweb-000000f3
[Jul 21 13:05:59] DEBUG[7784] channel.c: Bridge stops bridging channels SIP/1050000019-000000f2 and SIP/ehiweb-000000f3

This is a debug trace of a call that worked:

[Jul 21 12:47:38] VERBOSE[7656] app_chanspy.c: == Spying on channel SIP/1050000019-000000d9
[Jul 21 12:47:38] NOTICE[7656] app_chanspy.c: Attaching SIP/1050000001-000000d6 to SIP/1050000019-000000d9
[Jul 21 12:47:38] NOTICE[7656] app_chanspy.c: Attaching SIP/1050000001-000000d6 to SIP/1050000019-000000d9
[Jul 21 12:47:38] DEBUG[7656] channel.c: Scheduling timer at (50 requested / 50 actual) timer ticks per second

4

Chan spy requires that the RTP stream go through the Asterisk core. Any form of native bridging is incompatible with that, so, if native bridging is otherwise possible, it will have to be undone before spying is started.

SIP native bridges tend to be external bridges, where the RTP flows directly between the two parties, without touchin any part of Asterisk.

If there is a bug in this area (there have been recent ones, but the versions referenced here are not recent!) using directmedia=no (canreinvite=no for older systems) will prevent native bridging, at the cost of an increased CPU load.

5

I have found that if I spy a call between two sip channels and both use the same codec, Asterisk does a “packet to packet bridge”, as it needs no transcoding.

When packet to packet bridge is in use, asterisk quite always drop calls as seen when trying to spy.

If I set one of the sip peers to use a different codec, Asterisk has to transcode RTP traffic, and this makes chan spy work perfectly.

Try it.

6

issues.asterisk.org/jira/browse/ASTERISK-16346

7

Dear David,

I have found that the issue is surely with packet2packet bridging, and not direct media.

I do not use direct media (I have natted phones and I have set canreinvite=no), but my Asterisk uses packet2packet bridging, that (if I unserstand correctly) means that rtp traffic enters asterisk and leaves it without entering the “core” of Asterisk, but is managed only as “network packets”. This makes it possible (in theory) to mess with RTP if needed (for music on hold, monitoring, etc) while still keeping CPU use at a minimum when not needed.

The issue is that if my asterisk uses packet2packet bridging, chanspy fails to work as stated before. I suppose that it does not “tap” properly on the p2p bridge. I can also see an error in the debug log about it, as you can see here:

[Jul 21 13:05:59] NOTICE[7784] rtp.c: p2p-rtp-bridge: Ooh, empty read…

If I force the two phones to use different codecs, then packet2packet bridging cannot be used, RTP gets in the “core” of Asterisk to be transcoded, and in this situation chanspy works perfectly as expected.

Now, if I could avoid packet2packet (and also direct media, of course) without having to use different codecs to “force” asterisk to manage the RTP data “in depth”, I could make chanspy work without actually fixing the bug.

Or else, we could try to fix the bug… but I need a QUICK solution, even if it’s dirty.

8

Please read the Asterisk bug report I pointed out to you. This does mention that a problem with packet to packet native bridging, and also includes a fix.