[Home]

Summary:ASTERISK-24695: Unable to get 'B' function of MixMonitor to work with ChanSpy
Reporter:xrobau (xrobau)Labels:
Date Opened:2015-01-15 17:12:54.000-0600Date Closed:
Priority:MajorRegression?
Status:Open/NewComponents:Applications/app_chanspy Applications/app_mixmonitor
Versions:13.1.0 Frequency of
Occurrence
Related
Issues:
Environment:Attachments:
Description:The new 'B' Param to MixMonitor is having difficulty when running Chanspy.

{code}localhost*CLI> sip show channels
Peer             User/ANR         Call ID          Format           Hold     Last Message    Expiry     Peer
10.46.80.100     303              acc0a6e9-697af0  (ulaw)           No       Rx: ACK                    303
192.168.15.125   300              181cb63801a2ec8  (g722)           No       Tx: ACK                    300
2 active SIP dialogs
localhost*CLI>{code}

When enabling MixMonitor on that channel, the hook is loaded and triggered, but each time it runs...
{code}
   -- Executing [s@macro-one-touch-record:1] Set("SIP/303-00000016", "ONETOUCH_REC_SCRIPT_STATUS=") in new stack
   -- Executing [s@macro-one-touch-record:2] System("SIP/303-00000016", "/var/lib/asterisk/bin/one_touch_record.php "SIP/303-00000016"") in new stack
 == Begin MixMonitor Recording SIP/303-00000016
   -- Called hook@__func_periodic_hook_context__
   -- Executing [hook@__func_periodic_hook_context__:1] Set("Local/hook@__func_periodic_hook_context__-00000023;2", "EncodedChannel=SIP/303-00000016") in new stack
   -- Executing [hook@__func_periodic_hook_context__:2] Set("Local/hook@__func_periodic_hook_context__-00000023;2", "GROUP_NAME=SIP/303-000000166") in new stack
   -- Executing [hook@__func_periodic_hook_context__:3] Set("Local/hook@__func_periodic_hook_context__-00000023;2", "GROUP(periodic-hook)=SIP/303-000000166") in new stack
   -- Executing [hook@__func_periodic_hook_context__:4] ExecIf("Local/hook@__func_periodic_hook_context__-00000023;2", "0?Hangup()") in new stack
   -- Executing [hook@__func_periodic_hook_context__:5] Set("Local/hook@__func_periodic_hook_context__-00000023;2", "ChannelToSpy=SIP/303-00000016") in new stack
   -- Executing [hook@__func_periodic_hook_context__:6] ChanSpy("Local/hook@__func_periodic_hook_context__-00000023;2", "SIP/303-00000016,qEB") in new stack
 == Spawn extension (__func_periodic_hook_context__, hook, 6) exited non-zero on 'Local/hook@__func_periodic_hook_context__-00000023;2'
{code}

Chanspy crashes with a spurious codec translation error

{code}
[2015-01-16 09:08:42] DEBUG[24244][C-00000031] pbx.c: Launching 'ChanSpy'
[2015-01-16 09:08:42] VERBOSE[24244][C-00000031] pbx.c: Executing [hook@__func_periodic_hook_context__:6] ChanSpy("Local/hook@__func_periodic_hook_context__-00000024;2", "SIP/303-00000016,qEB") in new stack
[2015-01-16 09:08:42] WARNING[24244][C-00000031] channel.c: Unable to find a codec translation path from (slin) to (slin)
[2015-01-16 09:08:42] ERROR[24244][C-00000031] app_chanspy.c: Could Not Set Write Format.
[2015-01-16 09:08:42] DEBUG[24244][C-00000031] pbx.c: Spawn extension (__func_periodic_hook_context__,hook,6) exited non-zero on 'Local/hook@__func_periodic_hook_context__-00000024;2'
[2015-01-16 09:08:42] VERBOSE[24244][C-00000031] pbx.c: Spawn extension (__func_periodic_hook_context__, hook, 6) exited non-zero on 'Local/hook@__func_periodic_hook_context__-00000024;2'
[2015-01-16 09:08:42] DEBUG[24244][C-00000031] channel.c: Soft-Hanging (0x10) up channel 'Local/hook@__func_periodic_hook_context__-00000024;2'
[2015-01-16 09:08:42] DEBUG[24244][C-00000031] channel.c: Hanging up channel 'Local/hook@__func_periodic_hook_context__-00000024;2'
[2015-01-16 09:08:42] DEBUG[27629] cdr.c: Finalized CDR for Local/hook@__func_periodic_hook_context__-00000024;2 - start 1421363322.708113 answer 0.000000 end 1421363322.709825 dispo FAILED
[2015-01-16 09:08:42] DEBUG[24243] channel.c: Hanging up channel 'Local/hook@__func_periodic_hook_context__-00000024;1'
[2015-01-16 09:08:42] DEBUG[27629] cdr.c: Finalized CDR for Local/hook@__func_periodic_hook_context__-00000024;1 - start 1421363322.708073 answer 0.000000 end 1421363322.709928 dispo NO ANSWER
[2015-01-16 09:08:42] DEBUG[27629] cdr.c: Skipping CDR  for Local/hook@__func_periodic_hook_context__-00000024;1 since we weren't answered
[2015-01-16 09:08:42] DEBUG[27629] cdr.c: Skipping CDR  for Local/hook@__func_periodic_hook_context__-00000024;2 since we weren't answered
{code}

Note that it's trying to translate from slin to slin.
Comments:By: xrobau (xrobau) 2015-01-15 17:32:26.007-0600

This fails when both extens are the same codec, as well. I tried ulaw/ulaw, with the same result ('unable to convert from slin to slin')

{code}localhost*CLI> core show channel SIP/300-0000001f
-- General --
          Name: SIP/300-0000001f
          Type: SIP
      UniqueID: 1421364398.624
      LinkedID: 1421364398.622
     Caller ID: 300
Caller ID Name: Rob Desk
Connected Line ID: 303
Connected Line ID Name: 303
Eff. Connected Line ID: 303
Eff. Connected Line ID Name: 303
   DNID Digits: (N/A)
      Language: en
         State: Up (6)
 NativeFormats: (ulaw)
   WriteFormat: ulaw
    ReadFormat: ulaw
WriteTranscode: No
 ReadTranscode: No
Time to Hangup: 0
  Elapsed Time: 0h0m10s
     Bridge ID: 2cfdc37a-1528-48a9-abe9-f31e1140a38b
--   PBX   --
       Context: from-internal
     Extension:
      Priority: 1
    Call Group: 0
  Pickup Group: 0
   Application: AppDial
          Data: (Outgoing Line)
Call Identifer: [C-0000003a]
     Variables:
BRIDGEPVTCALLID=b6d6835d-7ec1c5e5@10.46.80.100
BRIDGEPEER=SIP/303-0000001e
DIALEDPEERNUMBER=300
SIPCALLID=6ee0f0a263cc9e531c027615275ea43c@192.168.15.5:5060
KEEPCID=TRUE
CWIGNORE=
REC_STATUS=RECORDING
RECORD_ID=SIP/303-0000001e
MIXMON_ID=0x7fb300930c10
CALLFILENAME=internal-300-303-20150116-092638-1421364398.622
REC_POLICY_MODE=YES
MON_FMT=wav
FROMEXTEN=303
TIMESTR=20150116-092638
YEAR=2015
MONTH=01
DAY=16
PICKUPMARK=300
EXTTOCALL=300
TTL=64
CALLEE_ACCOUNCODE=
DIAL_OPTIONS=Ttr
RINGTIMER=15
 CDR Variables:
level 1: calledsubaddr=
level 1: callingsubaddr=
level 1: dnid=
level 1: clid="Rob De
level 1: src=300
level 1: dcontext=from-in
level 1: channel=SIP/300
level 1: lastapp=AppDial
level 1: lastdata=(Outgoi
level 1: start=1421364
level 1: answer=1421364
level 1: end=1421364
level 1: duration=1
level 1: billsec=0
level 1: disposition=8
level 1: amaflags=3
level 1: uniqueid=1421364
level 1: linkedid=1421364
level 1: sequence=117
{code}

By: xrobau (xrobau) 2015-01-15 17:34:04.724-0600

More details of the original call
{code}localhost*CLI> core show channel SIP/300-00000021
-- General --
          Name: SIP/300-00000021
          Type: SIP
      UniqueID: 1421364747.685
      LinkedID: 1421364747.683
     Caller ID: 300
Caller ID Name: Rob Desk
Connected Line ID: 303
Connected Line ID Name: 303
Eff. Connected Line ID: 303
Eff. Connected Line ID Name: 303
   DNID Digits: (N/A)
      Language: en
         State: Up (6)
 NativeFormats: (g722)
   WriteFormat: ulaw
    ReadFormat: ulaw
WriteTranscode: Yes (ulaw@8000)->(slin@8000)->(g722@16000)
 ReadTranscode: Yes (g722@16000)->(slin@8000)->(ulaw@8000)
Time to Hangup: 0
  Elapsed Time: 0h0m16s
     Bridge ID: 7c28bc65-21bf-41c0-bb07-edaafd30b67d
--   PBX   --
       Context: from-internal
     Extension:
      Priority: 1
    Call Group: 0
  Pickup Group: 0
   Application: AppDial
          Data: (Outgoing Line)
Call Identifer: [C-00000040]
     Variables:
BRIDGEPVTCALLID=4203b1f3-21520088@10.46.80.100
BRIDGEPEER=SIP/303-00000020
DIALEDPEERNUMBER=300
SIPCALLID=683781fd62d5bbeb41a441b117c7644e@192.168.15.5:5060
KEEPCID=TRUE
CWIGNORE=
REC_STATUS=RECORDING
RECORD_ID=SIP/303-00000020
MIXMON_ID=0x7fb300922900
CALLFILENAME=internal-300-303-20150116-093227-1421364747.683
REC_POLICY_MODE=YES
MON_FMT=wav
FROMEXTEN=303
TIMESTR=20150116-093227
YEAR=2015
MONTH=01
DAY=16
PICKUPMARK=300
EXTTOCALL=300
TTL=64
CALLEE_ACCOUNCODE=
DIAL_OPTIONS=Ttr
RINGTIMER=15
 CDR Variables:
level 1: calledsubaddr=
level 1: callingsubaddr=
level 1: dnid=
level 1: clid="Rob De
level 1: src=300
level 1: dcontext=from-in
level 1: channel=SIP/300
level 1: lastapp=AppDial
level 1: lastdata=(Outgoi
level 1: start=1421364
level 1: answer=1421364
level 1: end=1421364
level 1: duration=1
level 1: billsec=0
level 1: disposition=8
level 1: amaflags=3
level 1: uniqueid=1421364
level 1: linkedid=1421364
level 1: sequence=129

   -- Called hook@__func_periodic_hook_context__
   -- Executing [hook@__func_periodic_hook_context__:1] Set("Local/hook@__func_periodic_hook_context__-00000030;2", "EncodedChannel=SIP/303-00000020") in new stack
   -- Executing [hook@__func_periodic_hook_context__:2] Set("Local/hook@__func_periodic_hook_context__-00000030;2", "GROUP_NAME=SIP/303-0000002011") in new stack
   -- Executing [hook@__func_periodic_hook_context__:3] Set("Local/hook@__func_periodic_hook_context__-00000030;2", "GROUP(periodic-hook)=SIP/303-0000002011") in new stack
   -- Executing [hook@__func_periodic_hook_context__:4] ExecIf("Local/hook@__func_periodic_hook_context__-00000030;2", "0?Hangup()") in new stack
   -- Executing [hook@__func_periodic_hook_context__:5] Set("Local/hook@__func_periodic_hook_context__-00000030;2", "ChannelToSpy=SIP/303-00000020") in new stack
   -- Executing [hook@__func_periodic_hook_context__:6] ChanSpy("Local/hook@__func_periodic_hook_context__-00000030;2", "SIP/303-00000020,qEB") in new stack
 == Spawn extension (__func_periodic_hook_context__, hook, 6) exited non-zero on 'Local/hook@__func_periodic_hook_context__-00000030;2'
   -- Called hook@__func_periodic_hook_context__
   -- Executing [hook@__func_periodic_hook_context__:1] Set("Local/hook@__func_periodic_hook_context__-00000031;2", "EncodedChannel=SIP/303-00000020") in new stack
   -- Executing [hook@__func_periodic_hook_context__:2] Set("Local/hook@__func_periodic_hook_context__-00000031;2", "GROUP_NAME=SIP/303-0000002011") in new stack
   -- Executing [hook@__func_periodic_hook_context__:3] Set("Local/hook@__func_periodic_hook_context__-00000031;2", "GROUP(periodic-hook)=SIP/303-0000002011") in new stack
   -- Executing [hook@__func_periodic_hook_context__:4] ExecIf("Local/hook@__func_periodic_hook_context__-00000031;2", "0?Hangup()") in new stack
   -- Executing [hook@__func_periodic_hook_context__:5] Set("Local/hook@__func_periodic_hook_context__-00000031;2", "ChannelToSpy=SIP/303-00000020") in new stack
   -- Executing [hook@__func_periodic_hook_context__:6] ChanSpy("Local/hook@__func_periodic_hook_context__-00000031;2", "SIP/303-00000020,qEB") in new stack
 == Spawn extension (__func_periodic_hook_context__, hook, 6) exited non-zero on 'Local/hook@__func_periodic_hook_context__-00000031;2'
   -- Channel SIP/300-00000021 left 'simple_bridge' basic-bridge <7c28bc65-21bf-41c0-bb07-edaafd30b67d>
   -- Channel SIP/303-00000020 left 'simple_bridge' basic-bridge <7c28bc65-21bf-41c0-bb07-edaafd30b67d>
 == Spawn extension (macro-dial-one, s, 44) exited non-zero on 'SIP/303-00000020' in macro 'dial-one'
 == Spawn extension (macro-exten-vm, s, 16) exited non-zero on 'SIP/303-00000020' in macro 'exten-vm'
 == Spawn extension (from-internal, 300, 2) exited non-zero on 'SIP/303-00000020'
   -- Executing [h@from-internal:1] Hangup("SIP/303-00000020", "") in new stack
 == Spawn extension (from-internal, h, 1) exited non-zero on 'SIP/303-00000020'
 == MixMonitor close filestream (mixed)
 == End MixMonitor Recording SIP/303-00000020
localhost*CLI> quit
{code}
By: Rusty Newton (rnewton) 2015-01-15 18:42:43.145-0600

Rob can you also post the configuration for the involved SIP peers? "sip show peer <x>"  , or just their sip.conf configs thanks!  Remember to hit Send Back so we'll see the issue right away.
By: xrobau (xrobau) 2015-01-15 19:48:29.044-0600

They're standard FreePBX Peers
{code}
[300]
deny=0.0.0.0/0.0.0.0
secret=300
dtmfmode=rfc2833
canreinvite=no
context=from-internal
host=dynamic
trustrpid=yes
sendrpid=no
type=friend
nat=no
port=5060
qualify=yes
qualifyfreq=60
transport=udp,tcp,tls
avpf=no
force_avp=no
icesupport=no
encryption=no
callgroup=
pickupgroup=
allow=ulaw
dial=SIP/300
mailbox=300@device
permit=0.0.0.0/0.0.0.0
callerid=Rob Desk <300>
callcounter=yes
faxdetect=no
cc_monitor_policy=generic



[303]
deny=0.0.0.0/0.0.0.0
secret=303
dtmfmode=rfc2833
canreinvite=no
context=from-internal
host=dynamic
trustrpid=yes
sendrpid=no
type=friend
nat=no
port=5060
qualify=yes
qualifyfreq=60
transport=udp,tcp,tls
avpf=no
force_avp=no
icesupport=no
encryption=no
callgroup=
pickupgroup=
allow=ulaw
dial=SIP/303
mailbox=303@device
permit=0.0.0.0/0.0.0.0
callerid=303 <303>
callcounter=yes
faxdetect=no
cc_monitor_policy=generic
{code}
By: xrobau (xrobau) 2015-01-15 19:49:32.338-0600

As previous comment..

By: Joshua C. Colp (jcolp) 2015-02-27 13:59:58.313-0600

Per a discussion in #freepbx I think this is indeed a bug but the underlying cause is a lack of codec_resample. Installing the "asterisk13-resample" package does fix it. The question remains: Why does it need to resample? We'll see.