Queue TRANSFER events, PJSIP and MixMonitor

Hello and Happy New Year’s Eve!

I have the following for the community’s consideration (Asterisk 16.7.0):

[agents]
exten => 123,1,Dial(${PJSIP_DIAL_CONTACTS(peer)},,B(mixmonitor,s,1))

[mixmonitor]
exten => s,1,MixMonitor(...)

And in my queues.conf:

member=> Local/123@agents,,Agent,PJSIP/peer

When I use MixMonitor here the Queue does not logo any TRANSFER events. When I remove MixMonitor the TRANSFER events are logged.

I’m at a loss as to why … I think it’s the local channel not optimizing out because of MixMonitor … any advice appreciated!

Edit: That /b channel modifier looks like it would have been perfect here … seems to have been removed.

What’s the complete console output when this occurs?

    -- Executing [202@mycontext:5] Queue("PJSIP/inbound-000000c5", "myqueue,tTxIik,,,90") in new stack
    -- Started music on hold, class 'mycontext', on channel 'PJSIP/inbound-000000c5'
    -- Called Local/800@registered
    -- Executing [800@registered:1] Set("Local/800@registered-000000c8;2", "CDR_PROP(disable)=1") in new stack
    -- Called Local/802@registered
    -- Executing [802@registered:1] Set("Local/802@registered-000000c9;2", "CDR_PROP(disable)=1") in new stack
    -- Called Local/803@registered
    -- Executing [803@registered:1] Set("Local/803@registered-000000ca;2", "CDR_PROP(disable)=1") in new stack
    -- Called Local/809@registered
    -- Executing [800@registered:4] ExecIf("Local/800@registered-000000c8;2", "1?Set(__MONITOR=1)") in new stack
    -- Executing [809@registered:1] Set("Local/809@registered-000000cb;2", "CDR_PROP(disable)=1") in new stack
    -- Executing [800@registered:5] Set("Local/800@registered-000000c8;2", "__MONITOR_FILE=1577811366.1156-1577811365.1150") in new stack
    -- Executing [802@registered:4] ExecIf("Local/802@registered-000000c9;2", "1?Set(__MONITOR=1)") in new stack
    -- Executing [802@registered:5] Set("Local/802@registered-000000c9;2", "__MONITOR_FILE=1577811366.1158-1577811365.1150") in new stack
    -- Executing [802@registered:6] Dial("Local/802@registered-000000c9;2", "PJSIP/mycontext.802/sip:mycontext.802@192.168.1.2:62276;rinstance=be43d1d39d89b49c,,B(monitor,s,1)") in new stack
    -- Executing [800@registered:6] Dial("Local/800@registered-000000c8;2", "PJSIP/mycontext.800/sip:mycontext.800@192.168.1.127:63157;rinstance=151f5d0fe76b6c61,,B(monitor,s,1)") in new stack
    -- Executing [809@registered:4] ExecIf("Local/809@registered-000000cb;2", "1?Set(__MONITOR=1)") in new stack
    -- Executing [809@registered:5] Set("Local/809@registered-000000cb;2", "__MONITOR_FILE=1577811366.1162-1577811365.1150") in new stack
    -- Local/802@registered-000000c9;2 Internal Gosub(monitor,s,1) start
    -- Local/800@registered-000000c8;2 Internal Gosub(monitor,s,1) start
    -- Executing [s@monitor:1] NoOp("Local/802@registered-000000c9;2", "*** MONITOR:1 RECORDING: ***") in new stack
    -- Executing [s@monitor:1] NoOp("Local/800@registered-000000c8;2", "*** MONITOR:1 RECORDING: ***") in new stack
    -- Executing [809@registered:6] Dial("Local/809@registered-000000cb;2", "PJSIP/mycontext.809/sip:mycontext.809@192.168.1.2:57087;rinstance=f23d11cfb7fb1ba6,,B(monitor,s,1)") in new stack
    -- Executing [s@monitor:2] ExecIf("Local/800@registered-000000c8;2", "0?Return") in new stack
    -- Executing [s@monitor:2] ExecIf("Local/802@registered-000000c9;2", "0?Return") in new stack
    -- Executing [s@monitor:3] ExecIf("Local/800@registered-000000c8;2", "0?Return") in new stack
    -- Executing [s@monitor:3] ExecIf("Local/802@registered-000000c9;2", "0?Return") in new stack
    -- Executing [s@monitor:4] Set("Local/800@registered-000000c8;2", "__MONITOR_FILE=1577811366.1156-1577811365.1150") in new stack
    -- Executing [s@monitor:4] Set("Local/802@registered-000000c9;2", "__MONITOR_FILE=1577811366.1158-1577811365.1150") in new stack
    -- Executing [s@monitor:5] Set("Local/800@registered-000000c8;2", "__RECORDING=1") in new stack
    -- Local/809@registered-000000cb;2 Internal Gosub(monitor,s,1) start
    -- Executing [s@monitor:1] NoOp("Local/809@registered-000000cb;2", "*** MONITOR:1 RECORDING: ***") in new stack
    -- Executing [s@monitor:5] Set("Local/802@registered-000000c9;2", "__RECORDING=1") in new stack
    -- Executing [s@monitor:2] ExecIf("Local/809@registered-000000cb;2", "0?Return") in new stack
    -- Executing [s@monitor:3] ExecIf("Local/809@registered-000000cb;2", "0?Return") in new stack
    -- Executing [s@monitor:4] Set("Local/809@registered-000000cb;2", "__MONITOR_FILE=1577811366.1162-1577811365.1150") in new stack
    -- Executing [s@monitor:5] Set("Local/809@registered-000000cb;2", "__RECORDING=1") in new stack
    -- Executing [s@monitor:6] MixMonitor("Local/800@registered-000000c8;2", "/ram/1577811366.1156-1577811365.1150.sln16,a,/some/path/bin/monitor 1577811366.1156-1577811365.1150 mycontext") in new stack
    -- Executing [803@registered:4] ExecIf("Local/803@registered-000000ca;2", "1?Set(__MONITOR=1)") in new stack
    -- Executing [803@registered:5] Set("Local/803@registered-000000ca;2", "__MONITOR_FILE=1577811366.1160-1577811365.1150") in new stack
    -- Executing [803@registered:6] Dial("Local/803@registered-000000ca;2", "PJSIP/mycontext.803/sip:mycontext.803@192.168.1.108:5060,,B(monitor,s,1)") in new stack
    -- Local/803@registered-000000ca;2 Internal Gosub(monitor,s,1) start
    -- Executing [s@monitor:1] NoOp("Local/803@registered-000000ca;2", "*** MONITOR:1 RECORDING: ***") in new stack
    -- Executing [s@monitor:2] ExecIf("Local/803@registered-000000ca;2", "0?Return") in new stack
    -- Executing [s@monitor:7] Return("Local/800@registered-000000c8;2", "") in new stack
  == Spawn extension (registered, 800, 6) exited non-zero on 'Local/800@registered-000000c8;2'
    -- Local/800@registered-000000c8;2 Internal Gosub(monitor,s,1) complete GOSUB_RETVAL=
    -- Executing [s@monitor:3] ExecIf("Local/803@registered-000000ca;2", "0?Return") in new stack
  == Begin MixMonitor Recording Local/800@registered-000000c8;2
    -- Executing [s@monitor:4] Set("Local/803@registered-000000ca;2", "__MONITOR_FILE=1577811366.1160-1577811365.1150") in new stack
    -- Executing [s@monitor:5] Set("Local/803@registered-000000ca;2", "__RECORDING=1") in new stack
    -- Executing [s@monitor:6] MixMonitor("Local/802@registered-000000c9;2", "/ram/1577811366.1158-1577811365.1150.sln16,a,/some/path/bin/monitor 1577811366.1158-1577811365.1150 mycontext") in new stack
    -- Executing [s@monitor:7] Return("Local/802@registered-000000c9;2", "") in new stack
  == Spawn extension (registered, 802, 6) exited non-zero on 'Local/802@registered-000000c9;2'
    -- Local/802@registered-000000c9;2 Internal Gosub(monitor,s,1) complete GOSUB_RETVAL=
  == Begin MixMonitor Recording Local/802@registered-000000c9;2
    -- Executing [s@monitor:6] MixMonitor("Local/809@registered-000000cb;2", "/ram/1577811366.1162-1577811365.1150.sln16,a,/some/path/bin/monitor 1577811366.1162-1577811365.1150 mycontext") in new stack
    -- Executing [s@monitor:7] Return("Local/809@registered-000000cb;2", "") in new stack
  == Spawn extension (registered, 809, 6) exited non-zero on 'Local/809@registered-000000cb;2'
    -- Local/809@registered-000000cb;2 Internal Gosub(monitor,s,1) complete GOSUB_RETVAL=
  == Begin MixMonitor Recording Local/809@registered-000000cb;2
    -- Called PJSIP/mycontext.800/sip:mycontext.800@192.168.1.127:63157;rinstance=151f5d0fe76b6c61
    -- Called PJSIP/mycontext.802/sip:mycontext.802@192.168.1.2:62276;rinstance=be43d1d39d89b49c
  == Using SIP RTP Audio TOS bits 184
  == Using SIP RTP Audio TOS bits 184 in TCLASS field.
    -- Connected line update to PJSIP/inbound-000000c5 prevented.
    -- Connected line update to PJSIP/inbound-000000c5 prevented.
    -- Called PJSIP/mycontext.809/sip:mycontext.809@192.168.1.2:57087;rinstance=f23d11cfb7fb1ba6
    -- Executing [s@monitor:6] MixMonitor("Local/803@registered-000000ca;2", "/ram/1577811366.1160-1577811365.1150.sln16,a,/some/path/bin/monitor 1577811366.1160-1577811365.1150 mycontext") in new stack
    -- Connected line update to PJSIP/inbound-000000c5 prevented.
    -- Executing [s@monitor:7] Return("Local/803@registered-000000ca;2", "") in new stack
  == Spawn extension (registered, 803, 6) exited non-zero on 'Local/803@registered-000000ca;2'
    -- Local/803@registered-000000ca;2 Internal Gosub(monitor,s,1) complete GOSUB_RETVAL=
  == Begin MixMonitor Recording Local/803@registered-000000ca;2
  == Using SIP RTP Audio TOS bits 184
  == Using SIP RTP Audio TOS bits 184 in TCLASS field.
    -- Called PJSIP/mycontext.803/sip:mycontext.803@192.168.1.108:5060
    -- Connected line update to PJSIP/inbound-000000c5 prevented.
  == Using SIP RTP Audio TOS bits 184
  == Using SIP RTP Audio TOS bits 184 in TCLASS field.
  == Using SIP RTP Audio TOS bits 184
  == Using SIP RTP Audio TOS bits 184 in TCLASS field.
    -- PJSIP/mycontext.803-000000c9 is ringing
    -- Local/803@registered-000000ca;1 is ringing
    -- PJSIP/mycontext.803-000000c9 is ringing
    -- PJSIP/mycontext.802-000000c6 is ringing
    -- PJSIP/mycontext.802-000000c6 is ringing
    -- Local/802@registered-000000c9;1 is ringing
    -- PJSIP/mycontext.800-000000c7 is ringing
    -- PJSIP/mycontext.800-000000c7 is ringing
    -- Local/800@registered-000000c8;1 is ringing
    -- PJSIP/mycontext.809-000000c8 is ringing
    -- PJSIP/mycontext.809-000000c8 is ringing
    -- PJSIP/mycontext.809-000000c8 is ringing
    -- PJSIP/mycontext.809-000000c8 is ringing
    -- Local/809@registered-000000cb;1 is ringing
    -- PJSIP/mycontext.802-000000c6 answered Local/802@registered-000000c9;2
    -- Local/802@registered-000000c9;1 answered PJSIP/inbound-000000c5
  == Spawn extension (registered, 800, 6) exited non-zero on 'Local/800@registered-000000c8;2'
  == Spawn extension (registered, 809, 6) exited non-zero on 'Local/809@registered-000000cb;2'
    -- Stopped music on hold on PJSIP/inbound-000000c5
  == Spawn extension (registered, 803, 6) exited non-zero on 'Local/803@registered-000000ca;2'
  == MixMonitor close filestream (mixed)
  == Executing [/some/path/bin/monitor 1577811366.1162-1577811365.1150 mycontext]
  == MixMonitor close filestream (mixed)
  == MixMonitor close filestream (mixed)
  == Executing [/some/path/bin/monitor 1577811366.1156-1577811365.1150 mycontext]
  == Executing [/some/path/bin/monitor 1577811366.1160-1577811365.1150 mycontext]
    -- Channel PJSIP/mycontext.802-000000c6 joined 'simple_bridge' basic-bridge <2ab5ccbd-19e5-4ccf-bd78-07880a554c54>
    -- Channel Local/802@registered-000000c9;2 joined 'simple_bridge' basic-bridge <2ab5ccbd-19e5-4ccf-bd78-07880a554c54>
    -- Channel Local/802@registered-000000c9;1 joined 'simple_bridge' basic-bridge <1d22b9e0-c0ec-4296-880c-611edb09c30f>
    -- Channel PJSIP/inbound-000000c5 joined 'simple_bridge' basic-bridge <1d22b9e0-c0ec-4296-880c-611edb09c30f>
  == End MixMonitor Recording Local/809@registered-000000cb;2
  == End MixMonitor Recording Local/800@registered-000000c8;2
  == End MixMonitor Recording Local/803@registered-000000ca;2
    -- Started music on hold, class 'mycontext', on channel 'Local/802@registered-000000c9;2'
    -- Stopped music on hold on Local/802@registered-000000c9;2
    -- Channel Local/802@registered-000000c9;2 left 'simple_bridge' basic-bridge <2ab5ccbd-19e5-4ccf-bd78-07880a554c54>
    -- Channel PJSIP/mycontext.802-000000c6 left 'simple_bridge' basic-bridge <2ab5ccbd-19e5-4ccf-bd78-07880a554c54>
    -- Executing [809@mycontext:1] CELGenUserEvent("Local/802@registered-000000c9;2", "EXTENSION,809") in new stack
    -- Executing [809@mycontext:2] Set("Local/802@registered-000000c9;2", "TIMEOUT(absolute)=21600") in new stack
    -- Channel will hangup at 2019-12-31 22:56:15.661 UTC.
    -- Executing [809@mycontext:3] Set("Local/802@registered-000000c9;2", "PEER=") in new stack
    -- Executing [809@mycontext:4] Set("Local/802@registered-000000c9;2", "PEER=") in new stack
    -- Executing [809@mycontext:5] Set("Local/802@registered-000000c9;2", "CHANNEL(accountcode)=mycontext") in new stack
    -- Executing [809@mycontext:6] GotoIf("Local/802@registered-000000c9;2", "0?mycontext,i,1") in new stack
    -- Executing [809@mycontext:7] ExecIf("Local/802@registered-000000c9;2", "0?Set(CALLERID(num)=)") in new stack
    -- Executing [809@mycontext:8] Set("Local/802@registered-000000c9;2", "CDR(userfield)=") in new stack
    -- Executing [809@mycontext:9] ExecIf("Local/802@registered-000000c9;2", "0?Set(GROUP()=mycontext)") in new stack
    -- Executing [809@mycontext:10] GotoIf("Local/802@registered-000000c9;2", "0?notrunks,s,1") in new stack
    -- Executing [809@mycontext:11] Gosub("Local/802@registered-000000c9;2", "mycontext,blocked,1") in new stack
    -- Executing [blocked@mycontext:1] Return("Local/802@registered-000000c9;2", "") in new stack
    -- Executing [809@mycontext:13] Gosub("Local/802@registered-000000c9;2", "mycontext.extensions,809,1") in new stack
    -- Executing [809@mycontext.extensions:1] ExecIf("Local/802@registered-000000c9;2", "1?Set(CHANNEL(musicclass)=mycontext)") in new stack
    -- Executing [809@mycontext.extensions:2] Set("Local/802@registered-000000c9;2", "__MONITOR=1") in new stack
    -- Executing [809@mycontext.extensions:3] ExecIf("Local/802@registered-000000c9;2", "0?Goto(dial)") in new stack
    -- Executing [809@mycontext.extensions:4] Dial("Local/802@registered-000000c9;2", "Local/809@registered,10,xktT") in new stack
    -- Called Local/809@registered
    -- Executing [809@registered:1] Set("Local/809@registered-000000cc;2", "CDR_PROP(disable)=1") in new stack
    -- Executing [809@registered:4] ExecIf("Local/809@registered-000000cc;2", "0?Set(__MONITOR=1)") in new stack
    -- Executing [809@registered:5] Set("Local/809@registered-000000cc;2", "__MONITOR_FILE=1577811375.1169-1577811365.1150") in new stack
    -- Executing [809@registered:6] Dial("Local/809@registered-000000cc;2", "PJSIP/mycontext.809/sip:mycontext.809@192.168.1.2:57087;rinstance=f23d11cfb7fb1ba6,,B(monitor,s,1)") in new stack
    -- Local/809@registered-000000cc;2 Internal Gosub(monitor,s,1) start
    -- Executing [s@monitor:1] NoOp("Local/809@registered-000000cc;2", "*** MONITOR:1 RECORDING:1 ***") in new stack
    -- Executing [s@monitor:2] ExecIf("Local/809@registered-000000cc;2", "0?Return") in new stack
    -- Executing [s@monitor:3] ExecIf("Local/809@registered-000000cc;2", "1?Return") in new stack
  == Spawn extension (registered, 809, 6) exited non-zero on 'Local/809@registered-000000cc;2'
    -- Local/809@registered-000000cc;2 Internal Gosub(monitor,s,1) complete GOSUB_RETVAL=
    -- Called PJSIP/mycontext.809/sip:mycontext.809@192.168.1.2:57087;rinstance=f23d11cfb7fb1ba6
  == Using SIP RTP Audio TOS bits 184
  == Using SIP RTP Audio TOS bits 184 in TCLASS field.
    -- PJSIP/mycontext.809-000000ca is ringing
    -- Local/809@registered-000000cc;1 is ringing
    -- PJSIP/mycontext.809-000000ca is ringing
    -- PJSIP/mycontext.809-000000ca answered Local/809@registered-000000cc;2
    -- Local/809@registered-000000cc;1 answered Local/802@registered-000000c9;2
    -- Channel PJSIP/mycontext.809-000000ca joined 'simple_bridge' basic-bridge <9c390429-dc14-4207-9cb7-d0ad1a94a3dd>
    -- Channel Local/809@registered-000000cc;1 joined 'simple_bridge' basic-bridge <4233c75b-e332-4d86-91e6-169fd5fbc4a2>
    -- Channel Local/809@registered-000000cc;2 joined 'simple_bridge' basic-bridge <9c390429-dc14-4207-9cb7-d0ad1a94a3dd>
    -- Channel Local/802@registered-000000c9;2 joined 'simple_bridge' basic-bridge <4233c75b-e332-4d86-91e6-169fd5fbc4a2>
    -- Channel Local/802@registered-000000c9;2 left 'simple_bridge' basic-bridge <4233c75b-e332-4d86-91e6-169fd5fbc4a2>
    -- Channel Local/809@registered-000000cc;2 left 'simple_bridge' basic-bridge <9c390429-dc14-4207-9cb7-d0ad1a94a3dd>
    -- Channel Local/802@registered-000000c9;2 swapped with Local/809@registered-000000cc;2 into 'simple_bridge' basic-bridge <9c390429-dc14-4207-9cb7-d0ad1a94a3dd>
    -- Channel Local/809@registered-000000cc;1 left 'simple_bridge' basic-bridge <4233c75b-e332-4d86-91e6-169fd5fbc4a2>
  == Spawn extension (registered, 809, 6) exited non-zero on 'Local/809@registered-000000cc;2'
    -- Channel PJSIP/mycontext.809-000000ca left 'simple_bridge' basic-bridge <9c390429-dc14-4207-9cb7-d0ad1a94a3dd>
    -- Channel Local/802@registered-000000c9;2 left 'simple_bridge' basic-bridge <9c390429-dc14-4207-9cb7-d0ad1a94a3dd>
  == Spawn extension (mycontext.extensions, 809, 4) exited non-zero on 'Local/802@registered-000000c9;2'
    -- Executing [h@mycontext.extensions:1] Gosub("Local/802@registered-000000c9;2", "hangup,s,1") in new stack
    -- Executing [s@hangup:1] ExecIf("Local/802@registered-000000c9;2", "0?CELGenUserEvent(HANGUP)") in new stack
    -- Executing [s@hangup:2] Hangup("Local/802@registered-000000c9;2", "") in new stack
  == Spawn extension (hangup, s, 2) exited non-zero on 'Local/802@registered-000000c9;2'
    -- Channel Local/802@registered-000000c9;1 left 'simple_bridge' basic-bridge <1d22b9e0-c0ec-4296-880c-611edb09c30f>
  == MixMonitor close filestream (mixed)
  == Executing [/some/path/bin/monitor 1577811366.1158-1577811365.1150 mycontext]
    -- Channel PJSIP/inbound-000000c5 left 'simple_bridge' basic-bridge <1d22b9e0-c0ec-4296-880c-611edb09c30f>
  == Spawn extension (mycontext, 202, 5) exited non-zero on 'PJSIP/inbound-000000c5'
    -- Executing [h@mycontext:1] Gosub("PJSIP/inbound-000000c5", "hangup,s,1") in new stack
    -- Executing [s@hangup:1] ExecIf("PJSIP/inbound-000000c5", "1?CELGenUserEvent(HANGUP)") in new stack
    -- Executing [s@hangup:2] Hangup("PJSIP/inbound-000000c5", "") in new stack
  == Spawn extension (hangup, s, 2) exited non-zero on 'PJSIP/inbound-000000c5'
  == End MixMonitor Recording Local/802@registered-000000c9;2

@jcolp you are always helpful and it’s appreciated … beers on me … I tried to de-clutter it as much as practicable.

What happens if you place the recording on the outbound PJSIP channel, and not the Local channel?

Happy New Year!

What happens if you place the recording on the outbound PJSIP channel, and not the Local channel?

It logs the TRANSFER events normally in that case, however, the requirement I’m up against here is to get a cumulative recording including any MOH or ringing. Basically, what the caller hears from that point forward. It works beautifully, except for the queue TRANSFER events, which is a show stopper right now for me.

Just for a data point, TRANSFER events are logged in the CEL doing it this way.

I guess being one full channel away the QUEUE can’t see the transfers.

Any ideas how to overcome? (thanks, as always, for any help)

Does calling MixMonitor on the channel before it goes into Queue not suffice? Otherwise, nothing springs to mind.