[asterisk-bugs] [JIRA] (ASTERISK-27071) chan_sip: MOH keeps playing on attended transfer to alcatel

Martin Nyström (JIRA) noreply at issues.asterisk.org
Sun Feb 25 14:38:25 CST 2018


    [ https://issues.asterisk.org/jira/browse/ASTERISK-27071?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=242380#comment-242380 ] 

Martin Nyström edited comment on ASTERISK-27071 at 2/25/18 2:37 PM:
--------------------------------------------------------------------

Perhaps a titel change to this issue is in order. This is NOT occuring on only Alcatel.


This may not appear to be an issue with the Bridge but rather something else. The attended transfer takes place at [2018-02-23 12:12:44].
I've looked through the Events as well. And the Event NewConnectedLine is sent then shortly after MusicOnHoldStart on all channels involved. These events are sent just before the bridge is destroyed.

[2018-02-23 12:10:26] VERBOSE[14021][C-000003ff] netsock2.c: Using SIP RTP CoS mark 5
[2018-02-23 12:10:26] VERBOSE[15363][C-000003ff] pbx_realtime.c: Executing [0651699650 at from-voip-provider:1] NoOp("SIP/siptrunk1.telavox.se-00000759", "Inbound Call")
[2018-02-23 12:10:26] VERBOSE[15363][C-000003ff] pbx_realtime.c: Executing [0651699650 at from-voip-provider:2] Set("SIP/siptrunk1.telavox.se-00000759", "CDR(type)=inbound")
[2018-02-23 12:10:26] VERBOSE[15363][C-000003ff] pbx_realtime.c: Executing [0651699650 at from-voip-provider:3] Set("SIP/siptrunk1.telavox.se-00000759", "CHANNEL(language)=se")
[2018-02-23 12:10:26] VERBOSE[15363][C-000003ff] pbx_realtime.c: Executing [0651699650 at from-voip-provider:4] AGI("SIP/siptrunk1.telavox.se-00000759", "agi://127.0.0.1/square,start_kronans_kundtjanst")
[2018-02-23 12:10:26] VERBOSE[15363][C-000003ff] res_agi.c: agi://127.0.0.1/square,start_kronans_kundtjanst: START CALLY SQUARE
[2018-02-23 12:10:26] VERBOSE[15363][C-000003ff] res_agi.c: agi://127.0.0.1/square,start_kronans_kundtjanst: Answer
[2018-02-23 12:10:26] VERBOSE[15363][C-000003ff] res_agi.c: agi://127.0.0.1/square,start_kronans_kundtjanst: IFTIME 08:00-18:00,mon-fri,*,* true
[2018-02-23 12:10:26] VERBOSE[15363][C-000003ff] res_agi.c: agi://127.0.0.1/square,start_kronans_kundtjanst: IFTIME *,*,25-26,dec-dec false
[2018-02-23 12:10:26] VERBOSE[15363][C-000003ff] res_agi.c: agi://127.0.0.1/square,start_kronans_kundtjanst: IFTIME *,*,31-31,dec-dec false
[2018-02-23 12:10:26] VERBOSE[15363][C-000003ff] res_agi.c: agi://127.0.0.1/square,start_kronans_kundtjanst: IFTIME *,*,1-1,jan-jan false
[2018-02-23 12:10:26] VERBOSE[15363][C-000003ff] res_agi.c: agi://127.0.0.1/square,start_kronans_kundtjanst: IFTIME *,*,6-6,jan-jan false
[2018-02-23 12:10:26] VERBOSE[15363][C-000003ff] file.c: <SIP/siptrunk1.telavox.se-00000759> Playing '/var/opt/motion2/server/files/sounds/converted/kronans_kundtjanst_Välkommstmedelande_kundservice_val_1_och_2-1505400240447.slin' (language 'se')
[2018-02-23 12:10:55] DTMF[15363][C-000003ff] channel.c: DTMF begin '1' received on SIP/siptrunk1.telavox.se-00000759
[2018-02-23 12:10:55] DTMF[15363][C-000003ff] channel.c: DTMF begin ignored '1' on SIP/siptrunk1.telavox.se-00000759
[2018-02-23 12:10:55] DTMF[15363][C-000003ff] channel.c: DTMF end '1' received on SIP/siptrunk1.telavox.se-00000759, duration 200 ms
[2018-02-23 12:10:55] DTMF[15363][C-000003ff] channel.c: DTMF end passthrough '1' on SIP/siptrunk1.telavox.se-00000759
[2018-02-23 12:10:55] VERBOSE[15363][C-000003ff] res_agi.c: agi://127.0.0.1/square,start_kronans_kundtjanst: no variable selected for the result
[2018-02-23 12:10:55] VERBOSE[15363][C-000003ff] res_agi.c: AGI Script Executing Application: (PLAYBACK) Options: (/var/opt/motion2/server/files/sounds/converted/kronans_kundtjanst_eviexa-1505400244202,)
[2018-02-23 12:10:55] VERBOSE[15363][C-000003ff] file.c: <SIP/siptrunk1.telavox.se-00000759> Playing '/var/opt/motion2/server/files/sounds/converted/kronans_kundtjanst_eviexa-1505400244202.slin' (language 'se')
[2018-02-23 12:11:07] VERBOSE[15363][C-000003ff] res_agi.c: agi://127.0.0.1/square,start_kronans_kundtjanst: Executed command PLAYBACK /var/opt/motion2/server/files/sounds/converted/kronans_kundtjanst_eviexa-1505400244202
[2018-02-23 12:11:07] VERBOSE[15363][C-000003ff] file.c: <SIP/siptrunk1.telavox.se-00000759> Playing '/var/opt/motion2/server/files/sounds/converted/kronans_kundtjanst_1_female-1505400237994.slin' (language 'se')
[2018-02-23 12:11:26] VERBOSE[15363][C-000003ff] res_agi.c: agi://127.0.0.1/square,start_kronans_kundtjanst: no variable selected for the result
[2018-02-23 12:11:26] VERBOSE[15363][C-000003ff] res_agi.c: agi://127.0.0.1/square,start_kronans_kundtjanst: EVAL CONDITION 0>0 false
[2018-02-23 12:11:26] VERBOSE[15363][C-000003ff] res_agi.c: agi://127.0.0.1/square,start_kronans_kundtjanst: sh command: echo Samtalet
[2018-02-23 12:11:26] VERBOSE[15363][C-000003ff] res_agi.c: AGI Script Executing Application: (QUEUE) Options: (Kronans_Kundtjanst,xX,,,3600,,,,,)
[2018-02-23 12:11:26] VERBOSE[15363][C-000003ff] res_musiconhold.c: Started music on hold, class 'queue_music', on channel 'SIP/siptrunk1.telavox.se-00000759'
[2018-02-23 12:11:26] VERBOSE[15363][C-000003ff] res_musiconhold.c: Stopped music on hold on SIP/siptrunk1.telavox.se-00000759
[2018-02-23 12:11:26] VERBOSE[15363][C-000003ff] app_queue.c: Hold time for Kronans_Kundtjanst is 1 minute(s) 0 seconds
[2018-02-23 12:11:26] VERBOSE[15363][C-000003ff] app_queue.c: Told SIP/siptrunk1.telavox.se-00000759 in Kronans_Kundtjanst their queue position (which was 1)
[2018-02-23 12:11:26] VERBOSE[15363][C-000003ff] file.c: <SIP/siptrunk1.telavox.se-00000759> Playing 'queue-thankyou.slin' (language 'se')
[2018-02-23 12:11:27] VERBOSE[15363][C-000003ff] res_musiconhold.c: Started music on hold, class 'queue_music', on channel 'SIP/siptrunk1.telavox.se-00000759'
[2018-02-23 12:11:37] VERBOSE[15363][C-000003ff] netsock2.c: Using SIP RTP CoS mark 5
[2018-02-23 12:11:37] VERBOSE[15363][C-000003ff] app_queue.c: Called SIP/jessica.karlstrom
[2018-02-23 12:11:38] VERBOSE[15363][C-000003ff] app_queue.c: SIP/jessica.karlstrom-00000760 is ringing
[2018-02-23 12:11:39] VERBOSE[15363][C-000003ff] app_queue.c: SIP/jessica.karlstrom-00000760 answered SIP/siptrunk1.telavox.se-00000759
[2018-02-23 12:11:39] VERBOSE[15363][C-000003ff] res_musiconhold.c: Stopped music on hold on SIP/siptrunk1.telavox.se-00000759
[2018-02-23 12:11:39] VERBOSE[15695][C-000003ff] app_mixmonitor.c: Begin MixMonitor Recording SIP/siptrunk1.telavox.se-00000759
[2018-02-23 12:11:39] VERBOSE[15696][C-000003ff] bridge_channel.c: Channel SIP/jessica.karlstrom-00000760 joined 'simple_bridge' basic-bridge <3e33d32a-6796-4f41-a51e-7dec814ee1db>
[2018-02-23 12:11:39] VERBOSE[15363][C-000003ff] bridge_channel.c: Channel SIP/siptrunk1.telavox.se-00000759 joined 'simple_bridge' basic-bridge <3e33d32a-6796-4f41-a51e-7dec814ee1db>
[2018-02-23 12:12:07] VERBOSE[15363][C-000003ff] res_musiconhold.c: Started music on hold, class 'default', on channel 'SIP/siptrunk1.telavox.se-00000759'
[2018-02-23 12:12:11] VERBOSE[14258][C-00000406] netsock2.c: Using SIP RTP CoS mark 5
[2018-02-23 12:12:11] VERBOSE[15827][C-00000406] pbx_realtime.c: Executing [046-128001 at from-sip:1] NoOp("SIP/jessica.karlstrom-00000766", "")
[2018-02-23 12:12:11] VERBOSE[15827][C-00000406] pbx_realtime.c: Executing [046-128001 at from-sip:2] Set("SIP/jessica.karlstrom-00000766", "CDR(type)=outbound")
[2018-02-23 12:12:11] VERBOSE[15827][C-00000406] pbx_realtime.c: Executing [046-128001 at from-sip:3] Set("SIP/jessica.karlstrom-00000766", "outboundrouteid=3")
[2018-02-23 12:12:11] VERBOSE[15827][C-00000406] pbx_realtime.c: Executing [046-128001 at from-sip:4] Set("SIP/jessica.karlstrom-00000766", "_XCALLY_MIXMONITOR_UNIQUEID=1519384331.5192")
[2018-02-23 12:12:11] VERBOSE[15827][C-00000406] pbx_realtime.c: Executing [046-128001 at from-sip:5] Set("SIP/jessica.karlstrom-00000766", "_XCALLY_MIXMONITOR_FORMAT=wav")
[2018-02-23 12:12:11] VERBOSE[15827][C-00000406] pbx_realtime.c: Executing [046-128001 at from-sip:6] Set("SIP/jessica.karlstrom-00000766", "DEST=046128001")
[2018-02-23 12:12:11] VERBOSE[15827][C-00000406] pbx_realtime.c: Executing [046-128001 at from-sip:7] Set("SIP/jessica.karlstrom-00000766", "CALLERID(name-pres)=prohib")
[2018-02-23 12:12:11] VERBOSE[15827][C-00000406] pbx_realtime.c: Executing [046-128001 at from-sip:8] Set("SIP/jessica.karlstrom-00000766", "CALLERID(num-pres)=prohib")
[2018-02-23 12:12:11] VERBOSE[15827][C-00000406] pbx_realtime.c: Executing [046-128001 at from-sip:9] Set("SIP/jessica.karlstrom-00000766", "CALLERID(all)=0771612612")
[2018-02-23 12:12:11] VERBOSE[15827][C-00000406] pbx_realtime.c: Executing [046-128001 at from-sip:10] Dial("SIP/jessica.karlstrom-00000766", "SIP/sip.telavox.se/046128001,,xXU(xcally-mixmonitor-context),")
[2018-02-23 12:12:11] VERBOSE[15827][C-00000406] netsock2.c: Using SIP RTP CoS mark 5
[2018-02-23 12:12:11] VERBOSE[15827][C-00000406] app_dial.c: Called SIP/sip.telavox.se/046128001
[2018-02-23 12:12:12] VERBOSE[15827][C-00000406] app_dial.c: SIP/sip.telavox.se-00000767 is ringing
[2018-02-23 12:12:29] VERBOSE[15827][C-00000406] app_dial.c: SIP/sip.telavox.se-00000767 answered SIP/jessica.karlstrom-00000766
[2018-02-23 12:12:29] VERBOSE[15827][C-00000406] app_stack.c: SIP/sip.telavox.se-00000767 Internal Gosub(xcally-mixmonitor-context,s,1) start
[2018-02-23 12:12:29] VERBOSE[15827][C-00000406] pbx_realtime.c: Executing [s at xcally-mixmonitor-context:1] NoOp("SIP/sip.telavox.se-00000767", "")
[2018-02-23 12:12:29] VERBOSE[15827][C-00000406] pbx_realtime.c: Executing [s at xcally-mixmonitor-context:2] MixMonitor("SIP/sip.telavox.se-00000767", "1519384331.5192.wav,ab")
[2018-02-23 12:12:29] VERBOSE[15848][C-00000406] app_mixmonitor.c: Begin MixMonitor Recording SIP/sip.telavox.se-00000767
[2018-02-23 12:12:29] VERBOSE[15827][C-00000406] pbx_realtime.c: Executing [s at xcally-mixmonitor-context:3] Return("SIP/sip.telavox.se-00000767", "")
[2018-02-23 12:12:29] VERBOSE[15827][C-00000406] app_stack.c: Spawn extension (from-voip-provider, , 1) exited non-zero on 'SIP/sip.telavox.se-00000767'
[2018-02-23 12:12:29] VERBOSE[15827][C-00000406] app_stack.c: SIP/sip.telavox.se-00000767 Internal Gosub(xcally-mixmonitor-context,s,1) complete GOSUB_RETVAL=
[2018-02-23 12:12:29] VERBOSE[15849][C-00000406] bridge_channel.c: Channel SIP/sip.telavox.se-00000767 joined 'simple_bridge' basic-bridge <48599f5a-ba75-4f66-9da7-822ab1aad496>
[2018-02-23 12:12:29] VERBOSE[15827][C-00000406] bridge_channel.c: Channel SIP/jessica.karlstrom-00000766 joined 'simple_bridge' basic-bridge <48599f5a-ba75-4f66-9da7-822ab1aad496>
[2018-02-23 12:12:44] VERBOSE[14021][C-000003ff] bridge_channel.c: Channel SIP/sip.telavox.se-00000767 left 'simple_bridge' basic-bridge <48599f5a-ba75-4f66-9da7-822ab1aad496>
[2018-02-23 12:12:44] VERBOSE[15363][C-000003ff] res_musiconhold.c: Stopped music on hold on SIP/siptrunk1.telavox.se-00000759
[2018-02-23 12:12:44] VERBOSE[14021][C-000003ff] bridge_channel.c: Channel SIP/jessica.karlstrom-00000760 left 'simple_bridge' basic-bridge <3e33d32a-6796-4f41-a51e-7dec814ee1db>
[2018-02-23 12:12:44] VERBOSE[14021][C-000003ff] bridge_channel.c: Channel SIP/sip.telavox.se-00000767 swapped with SIP/jessica.karlstrom-00000760 into 'simple_bridge' basic-bridge <3e33d32a-6796-4f41-a51e-7dec814ee1db>
[2018-02-23 12:12:44] VERBOSE[15827][C-00000406] bridge_channel.c: Channel SIP/jessica.karlstrom-00000766 left 'simple_bridge' basic-bridge <48599f5a-ba75-4f66-9da7-822ab1aad496>
[2018-02-23 12:12:44] VERBOSE[15849][C-00000406] res_musiconhold.c: Started music on hold, class 'default', on channel 'SIP/sip.telavox.se-00000767'
[2018-02-23 12:12:44] VERBOSE[15827][C-00000406] pbx.c: Spawn extension (from-sip, 046-128001, 10) exited non-zero on 'SIP/jessica.karlstrom-00000766'
[2018-02-23 12:12:44] VERBOSE[15363][C-000003ff] res_musiconhold.c: Started music on hold, class 'default', on channel 'SIP/siptrunk1.telavox.se-00000759'
[2018-02-23 12:12:44] VERBOSE[15827][C-00000406] pbx_realtime.c: Executing [h at from-sip:1] NoOp("SIP/jessica.karlstrom-00000766", "")
[2018-02-23 12:12:44] VERBOSE[15827][C-00000406] pbx_realtime.c: Executing [h at from-sip:2] Hangup("SIP/jessica.karlstrom-00000766", "")
[2018-02-23 12:12:44] VERBOSE[15827][C-00000406] pbx.c: Spawn extension (from-sip, h, 2) exited non-zero on 'SIP/jessica.karlstrom-00000766'
[2018-02-23 12:13:06] VERBOSE[15849][C-00000406] res_musiconhold.c: Stopped music on hold on SIP/sip.telavox.se-00000767
[2018-02-23 12:13:06] VERBOSE[15849][C-00000406] bridge_channel.c: Channel SIP/sip.telavox.se-00000767 left 'simple_bridge' basic-bridge <3e33d32a-6796-4f41-a51e-7dec814ee1db>
[2018-02-23 12:13:06] VERBOSE[15363][C-000003ff] bridge_channel.c: Channel SIP/siptrunk1.telavox.se-00000759 left 'simple_bridge' basic-bridge <3e33d32a-6796-4f41-a51e-7dec814ee1db>
[2018-02-23 12:13:06] VERBOSE[15363][C-000003ff] res_musiconhold.c: Stopped music on hold on SIP/siptrunk1.telavox.se-00000759
[2018-02-23 12:13:06] VERBOSE[15848][C-00000406] app_mixmonitor.c: MixMonitor close filestream (mixed)
[2018-02-23 12:13:06] VERBOSE[15848][C-00000406] app_mixmonitor.c: End MixMonitor Recording SIP/sip.telavox.se-00000767
[2018-02-23 12:13:06] VERBOSE[15363][C-000003ff] res_agi.c: agi://127.0.0.1/square,start_kronans_kundtjanst: GOTO from-voip-provider 0651699650 5
[2018-02-23 12:13:06] VERBOSE[15363][C-000003ff] res_agi.c: <SIP/siptrunk1.telavox.se-00000759>AGI Script agi://127.0.0.1/square completed, returning 0
[2018-02-23 12:13:06] VERBOSE[15363][C-000003ff] pbx_realtime.c: Executing [0651699650 at from-voip-provider:5] hangup("SIP/siptrunk1.telavox.se-00000759", "16")
[2018-02-23 12:13:06] VERBOSE[15363][C-000003ff] pbx.c: Spawn extension (from-voip-provider, 0651699650, 5) exited non-zero on 'SIP/siptrunk1.telavox.se-00000759'
[2018-02-23 12:13:06] VERBOSE[15695][C-000003ff] app_mixmonitor.c: MixMonitor close filestream (mixed)
[2018-02-23 12:13:06] VERBOSE[15695][C-000003ff] app_mixmonitor.c: End MixMonitor Recording SIP/siptrunk1.telavox.se-00000759


was (Author: martin.nystrom):
This may not appear to be an issue with the Bridge but rather something else. The attended transfer takes place at [2018-02-23 12:12:44].
I've looked through the Events as well. And the Event NewConnectedLine is sent then shortly after MusicOnHoldStart on all channels involved. These events are sent just before the bridge is destroyed.

[2018-02-23 12:10:26] VERBOSE[14021][C-000003ff] netsock2.c: Using SIP RTP CoS mark 5
[2018-02-23 12:10:26] VERBOSE[15363][C-000003ff] pbx_realtime.c: Executing [0651699650 at from-voip-provider:1] NoOp("SIP/siptrunk1.telavox.se-00000759", "Inbound Call")
[2018-02-23 12:10:26] VERBOSE[15363][C-000003ff] pbx_realtime.c: Executing [0651699650 at from-voip-provider:2] Set("SIP/siptrunk1.telavox.se-00000759", "CDR(type)=inbound")
[2018-02-23 12:10:26] VERBOSE[15363][C-000003ff] pbx_realtime.c: Executing [0651699650 at from-voip-provider:3] Set("SIP/siptrunk1.telavox.se-00000759", "CHANNEL(language)=se")
[2018-02-23 12:10:26] VERBOSE[15363][C-000003ff] pbx_realtime.c: Executing [0651699650 at from-voip-provider:4] AGI("SIP/siptrunk1.telavox.se-00000759", "agi://127.0.0.1/square,start_kronans_kundtjanst")
[2018-02-23 12:10:26] VERBOSE[15363][C-000003ff] res_agi.c: agi://127.0.0.1/square,start_kronans_kundtjanst: START CALLY SQUARE
[2018-02-23 12:10:26] VERBOSE[15363][C-000003ff] res_agi.c: agi://127.0.0.1/square,start_kronans_kundtjanst: Answer
[2018-02-23 12:10:26] VERBOSE[15363][C-000003ff] res_agi.c: agi://127.0.0.1/square,start_kronans_kundtjanst: IFTIME 08:00-18:00,mon-fri,*,* true
[2018-02-23 12:10:26] VERBOSE[15363][C-000003ff] res_agi.c: agi://127.0.0.1/square,start_kronans_kundtjanst: IFTIME *,*,25-26,dec-dec false
[2018-02-23 12:10:26] VERBOSE[15363][C-000003ff] res_agi.c: agi://127.0.0.1/square,start_kronans_kundtjanst: IFTIME *,*,31-31,dec-dec false
[2018-02-23 12:10:26] VERBOSE[15363][C-000003ff] res_agi.c: agi://127.0.0.1/square,start_kronans_kundtjanst: IFTIME *,*,1-1,jan-jan false
[2018-02-23 12:10:26] VERBOSE[15363][C-000003ff] res_agi.c: agi://127.0.0.1/square,start_kronans_kundtjanst: IFTIME *,*,6-6,jan-jan false
[2018-02-23 12:10:26] VERBOSE[15363][C-000003ff] file.c: <SIP/siptrunk1.telavox.se-00000759> Playing '/var/opt/motion2/server/files/sounds/converted/kronans_kundtjanst_Välkommstmedelande_kundservice_val_1_och_2-1505400240447.slin' (language 'se')
[2018-02-23 12:10:55] DTMF[15363][C-000003ff] channel.c: DTMF begin '1' received on SIP/siptrunk1.telavox.se-00000759
[2018-02-23 12:10:55] DTMF[15363][C-000003ff] channel.c: DTMF begin ignored '1' on SIP/siptrunk1.telavox.se-00000759
[2018-02-23 12:10:55] DTMF[15363][C-000003ff] channel.c: DTMF end '1' received on SIP/siptrunk1.telavox.se-00000759, duration 200 ms
[2018-02-23 12:10:55] DTMF[15363][C-000003ff] channel.c: DTMF end passthrough '1' on SIP/siptrunk1.telavox.se-00000759
[2018-02-23 12:10:55] VERBOSE[15363][C-000003ff] res_agi.c: agi://127.0.0.1/square,start_kronans_kundtjanst: no variable selected for the result
[2018-02-23 12:10:55] VERBOSE[15363][C-000003ff] res_agi.c: AGI Script Executing Application: (PLAYBACK) Options: (/var/opt/motion2/server/files/sounds/converted/kronans_kundtjanst_eviexa-1505400244202,)
[2018-02-23 12:10:55] VERBOSE[15363][C-000003ff] file.c: <SIP/siptrunk1.telavox.se-00000759> Playing '/var/opt/motion2/server/files/sounds/converted/kronans_kundtjanst_eviexa-1505400244202.slin' (language 'se')
[2018-02-23 12:11:07] VERBOSE[15363][C-000003ff] res_agi.c: agi://127.0.0.1/square,start_kronans_kundtjanst: Executed command PLAYBACK /var/opt/motion2/server/files/sounds/converted/kronans_kundtjanst_eviexa-1505400244202
[2018-02-23 12:11:07] VERBOSE[15363][C-000003ff] file.c: <SIP/siptrunk1.telavox.se-00000759> Playing '/var/opt/motion2/server/files/sounds/converted/kronans_kundtjanst_1_female-1505400237994.slin' (language 'se')
[2018-02-23 12:11:26] VERBOSE[15363][C-000003ff] res_agi.c: agi://127.0.0.1/square,start_kronans_kundtjanst: no variable selected for the result
[2018-02-23 12:11:26] VERBOSE[15363][C-000003ff] res_agi.c: agi://127.0.0.1/square,start_kronans_kundtjanst: EVAL CONDITION 0>0 false
[2018-02-23 12:11:26] VERBOSE[15363][C-000003ff] res_agi.c: agi://127.0.0.1/square,start_kronans_kundtjanst: sh command: echo Samtalet
[2018-02-23 12:11:26] VERBOSE[15363][C-000003ff] res_agi.c: AGI Script Executing Application: (QUEUE) Options: (Kronans_Kundtjanst,xX,,,3600,,,,,)
[2018-02-23 12:11:26] VERBOSE[15363][C-000003ff] res_musiconhold.c: Started music on hold, class 'queue_music', on channel 'SIP/siptrunk1.telavox.se-00000759'
[2018-02-23 12:11:26] VERBOSE[15363][C-000003ff] res_musiconhold.c: Stopped music on hold on SIP/siptrunk1.telavox.se-00000759
[2018-02-23 12:11:26] VERBOSE[15363][C-000003ff] app_queue.c: Hold time for Kronans_Kundtjanst is 1 minute(s) 0 seconds
[2018-02-23 12:11:26] VERBOSE[15363][C-000003ff] app_queue.c: Told SIP/siptrunk1.telavox.se-00000759 in Kronans_Kundtjanst their queue position (which was 1)
[2018-02-23 12:11:26] VERBOSE[15363][C-000003ff] file.c: <SIP/siptrunk1.telavox.se-00000759> Playing 'queue-thankyou.slin' (language 'se')
[2018-02-23 12:11:27] VERBOSE[15363][C-000003ff] res_musiconhold.c: Started music on hold, class 'queue_music', on channel 'SIP/siptrunk1.telavox.se-00000759'
[2018-02-23 12:11:37] VERBOSE[15363][C-000003ff] netsock2.c: Using SIP RTP CoS mark 5
[2018-02-23 12:11:37] VERBOSE[15363][C-000003ff] app_queue.c: Called SIP/jessica.karlstrom
[2018-02-23 12:11:38] VERBOSE[15363][C-000003ff] app_queue.c: SIP/jessica.karlstrom-00000760 is ringing
[2018-02-23 12:11:39] VERBOSE[15363][C-000003ff] app_queue.c: SIP/jessica.karlstrom-00000760 answered SIP/siptrunk1.telavox.se-00000759
[2018-02-23 12:11:39] VERBOSE[15363][C-000003ff] res_musiconhold.c: Stopped music on hold on SIP/siptrunk1.telavox.se-00000759
[2018-02-23 12:11:39] VERBOSE[15695][C-000003ff] app_mixmonitor.c: Begin MixMonitor Recording SIP/siptrunk1.telavox.se-00000759
[2018-02-23 12:11:39] VERBOSE[15696][C-000003ff] bridge_channel.c: Channel SIP/jessica.karlstrom-00000760 joined 'simple_bridge' basic-bridge <3e33d32a-6796-4f41-a51e-7dec814ee1db>
[2018-02-23 12:11:39] VERBOSE[15363][C-000003ff] bridge_channel.c: Channel SIP/siptrunk1.telavox.se-00000759 joined 'simple_bridge' basic-bridge <3e33d32a-6796-4f41-a51e-7dec814ee1db>
[2018-02-23 12:12:07] VERBOSE[15363][C-000003ff] res_musiconhold.c: Started music on hold, class 'default', on channel 'SIP/siptrunk1.telavox.se-00000759'
[2018-02-23 12:12:11] VERBOSE[14258][C-00000406] netsock2.c: Using SIP RTP CoS mark 5
[2018-02-23 12:12:11] VERBOSE[15827][C-00000406] pbx_realtime.c: Executing [046-128001 at from-sip:1] NoOp("SIP/jessica.karlstrom-00000766", "")
[2018-02-23 12:12:11] VERBOSE[15827][C-00000406] pbx_realtime.c: Executing [046-128001 at from-sip:2] Set("SIP/jessica.karlstrom-00000766", "CDR(type)=outbound")
[2018-02-23 12:12:11] VERBOSE[15827][C-00000406] pbx_realtime.c: Executing [046-128001 at from-sip:3] Set("SIP/jessica.karlstrom-00000766", "outboundrouteid=3")
[2018-02-23 12:12:11] VERBOSE[15827][C-00000406] pbx_realtime.c: Executing [046-128001 at from-sip:4] Set("SIP/jessica.karlstrom-00000766", "_XCALLY_MIXMONITOR_UNIQUEID=1519384331.5192")
[2018-02-23 12:12:11] VERBOSE[15827][C-00000406] pbx_realtime.c: Executing [046-128001 at from-sip:5] Set("SIP/jessica.karlstrom-00000766", "_XCALLY_MIXMONITOR_FORMAT=wav")
[2018-02-23 12:12:11] VERBOSE[15827][C-00000406] pbx_realtime.c: Executing [046-128001 at from-sip:6] Set("SIP/jessica.karlstrom-00000766", "DEST=046128001")
[2018-02-23 12:12:11] VERBOSE[15827][C-00000406] pbx_realtime.c: Executing [046-128001 at from-sip:7] Set("SIP/jessica.karlstrom-00000766", "CALLERID(name-pres)=prohib")
[2018-02-23 12:12:11] VERBOSE[15827][C-00000406] pbx_realtime.c: Executing [046-128001 at from-sip:8] Set("SIP/jessica.karlstrom-00000766", "CALLERID(num-pres)=prohib")
[2018-02-23 12:12:11] VERBOSE[15827][C-00000406] pbx_realtime.c: Executing [046-128001 at from-sip:9] Set("SIP/jessica.karlstrom-00000766", "CALLERID(all)=0771612612")
[2018-02-23 12:12:11] VERBOSE[15827][C-00000406] pbx_realtime.c: Executing [046-128001 at from-sip:10] Dial("SIP/jessica.karlstrom-00000766", "SIP/sip.telavox.se/046128001,,xXU(xcally-mixmonitor-context),")
[2018-02-23 12:12:11] VERBOSE[15827][C-00000406] netsock2.c: Using SIP RTP CoS mark 5
[2018-02-23 12:12:11] VERBOSE[15827][C-00000406] app_dial.c: Called SIP/sip.telavox.se/046128001
[2018-02-23 12:12:12] VERBOSE[15827][C-00000406] app_dial.c: SIP/sip.telavox.se-00000767 is ringing
[2018-02-23 12:12:29] VERBOSE[15827][C-00000406] app_dial.c: SIP/sip.telavox.se-00000767 answered SIP/jessica.karlstrom-00000766
[2018-02-23 12:12:29] VERBOSE[15827][C-00000406] app_stack.c: SIP/sip.telavox.se-00000767 Internal Gosub(xcally-mixmonitor-context,s,1) start
[2018-02-23 12:12:29] VERBOSE[15827][C-00000406] pbx_realtime.c: Executing [s at xcally-mixmonitor-context:1] NoOp("SIP/sip.telavox.se-00000767", "")
[2018-02-23 12:12:29] VERBOSE[15827][C-00000406] pbx_realtime.c: Executing [s at xcally-mixmonitor-context:2] MixMonitor("SIP/sip.telavox.se-00000767", "1519384331.5192.wav,ab")
[2018-02-23 12:12:29] VERBOSE[15848][C-00000406] app_mixmonitor.c: Begin MixMonitor Recording SIP/sip.telavox.se-00000767
[2018-02-23 12:12:29] VERBOSE[15827][C-00000406] pbx_realtime.c: Executing [s at xcally-mixmonitor-context:3] Return("SIP/sip.telavox.se-00000767", "")
[2018-02-23 12:12:29] VERBOSE[15827][C-00000406] app_stack.c: Spawn extension (from-voip-provider, , 1) exited non-zero on 'SIP/sip.telavox.se-00000767'
[2018-02-23 12:12:29] VERBOSE[15827][C-00000406] app_stack.c: SIP/sip.telavox.se-00000767 Internal Gosub(xcally-mixmonitor-context,s,1) complete GOSUB_RETVAL=
[2018-02-23 12:12:29] VERBOSE[15849][C-00000406] bridge_channel.c: Channel SIP/sip.telavox.se-00000767 joined 'simple_bridge' basic-bridge <48599f5a-ba75-4f66-9da7-822ab1aad496>
[2018-02-23 12:12:29] VERBOSE[15827][C-00000406] bridge_channel.c: Channel SIP/jessica.karlstrom-00000766 joined 'simple_bridge' basic-bridge <48599f5a-ba75-4f66-9da7-822ab1aad496>
[2018-02-23 12:12:44] VERBOSE[14021][C-000003ff] bridge_channel.c: Channel SIP/sip.telavox.se-00000767 left 'simple_bridge' basic-bridge <48599f5a-ba75-4f66-9da7-822ab1aad496>
[2018-02-23 12:12:44] VERBOSE[15363][C-000003ff] res_musiconhold.c: Stopped music on hold on SIP/siptrunk1.telavox.se-00000759
[2018-02-23 12:12:44] VERBOSE[14021][C-000003ff] bridge_channel.c: Channel SIP/jessica.karlstrom-00000760 left 'simple_bridge' basic-bridge <3e33d32a-6796-4f41-a51e-7dec814ee1db>
[2018-02-23 12:12:44] VERBOSE[14021][C-000003ff] bridge_channel.c: Channel SIP/sip.telavox.se-00000767 swapped with SIP/jessica.karlstrom-00000760 into 'simple_bridge' basic-bridge <3e33d32a-6796-4f41-a51e-7dec814ee1db>
[2018-02-23 12:12:44] VERBOSE[15827][C-00000406] bridge_channel.c: Channel SIP/jessica.karlstrom-00000766 left 'simple_bridge' basic-bridge <48599f5a-ba75-4f66-9da7-822ab1aad496>
[2018-02-23 12:12:44] VERBOSE[15849][C-00000406] res_musiconhold.c: Started music on hold, class 'default', on channel 'SIP/sip.telavox.se-00000767'
[2018-02-23 12:12:44] VERBOSE[15827][C-00000406] pbx.c: Spawn extension (from-sip, 046-128001, 10) exited non-zero on 'SIP/jessica.karlstrom-00000766'
[2018-02-23 12:12:44] VERBOSE[15363][C-000003ff] res_musiconhold.c: Started music on hold, class 'default', on channel 'SIP/siptrunk1.telavox.se-00000759'
[2018-02-23 12:12:44] VERBOSE[15827][C-00000406] pbx_realtime.c: Executing [h at from-sip:1] NoOp("SIP/jessica.karlstrom-00000766", "")
[2018-02-23 12:12:44] VERBOSE[15827][C-00000406] pbx_realtime.c: Executing [h at from-sip:2] Hangup("SIP/jessica.karlstrom-00000766", "")
[2018-02-23 12:12:44] VERBOSE[15827][C-00000406] pbx.c: Spawn extension (from-sip, h, 2) exited non-zero on 'SIP/jessica.karlstrom-00000766'
[2018-02-23 12:13:06] VERBOSE[15849][C-00000406] res_musiconhold.c: Stopped music on hold on SIP/sip.telavox.se-00000767
[2018-02-23 12:13:06] VERBOSE[15849][C-00000406] bridge_channel.c: Channel SIP/sip.telavox.se-00000767 left 'simple_bridge' basic-bridge <3e33d32a-6796-4f41-a51e-7dec814ee1db>
[2018-02-23 12:13:06] VERBOSE[15363][C-000003ff] bridge_channel.c: Channel SIP/siptrunk1.telavox.se-00000759 left 'simple_bridge' basic-bridge <3e33d32a-6796-4f41-a51e-7dec814ee1db>
[2018-02-23 12:13:06] VERBOSE[15363][C-000003ff] res_musiconhold.c: Stopped music on hold on SIP/siptrunk1.telavox.se-00000759
[2018-02-23 12:13:06] VERBOSE[15848][C-00000406] app_mixmonitor.c: MixMonitor close filestream (mixed)
[2018-02-23 12:13:06] VERBOSE[15848][C-00000406] app_mixmonitor.c: End MixMonitor Recording SIP/sip.telavox.se-00000767
[2018-02-23 12:13:06] VERBOSE[15363][C-000003ff] res_agi.c: agi://127.0.0.1/square,start_kronans_kundtjanst: GOTO from-voip-provider 0651699650 5
[2018-02-23 12:13:06] VERBOSE[15363][C-000003ff] res_agi.c: <SIP/siptrunk1.telavox.se-00000759>AGI Script agi://127.0.0.1/square completed, returning 0
[2018-02-23 12:13:06] VERBOSE[15363][C-000003ff] pbx_realtime.c: Executing [0651699650 at from-voip-provider:5] hangup("SIP/siptrunk1.telavox.se-00000759", "16")
[2018-02-23 12:13:06] VERBOSE[15363][C-000003ff] pbx.c: Spawn extension (from-voip-provider, 0651699650, 5) exited non-zero on 'SIP/siptrunk1.telavox.se-00000759'
[2018-02-23 12:13:06] VERBOSE[15695][C-000003ff] app_mixmonitor.c: MixMonitor close filestream (mixed)
[2018-02-23 12:13:06] VERBOSE[15695][C-000003ff] app_mixmonitor.c: End MixMonitor Recording SIP/siptrunk1.telavox.se-00000759

> chan_sip: MOH keeps playing on attended transfer to alcatel
> -----------------------------------------------------------
>
>                 Key: ASTERISK-27071
>                 URL: https://issues.asterisk.org/jira/browse/ASTERISK-27071
>             Project: Asterisk
>          Issue Type: Bug
>      Security Level: None
>          Components: Channels/chan_sip/General
>    Affects Versions: 13.13.0, 13.13.1, 13.15.0, 13.16.0
>         Environment: Centos 7
> Alcatel OXE
>            Reporter: Jason Tomlinson
>            Assignee: Unassigned
>         Attachments: alcatel_trf_problem.txt, full_sip_trace.txt, Trace transfert Alcatel.pcapng
>
>
> Since upgrading from asterisk 11 to asterisk 13 (I have tested up to the latest 13.16.0 release), we have a problem with attended transfers to an alcatel pbx in which the call being transferred still has music on hold even after the transfer has completed.



--
This message was sent by Atlassian JIRA
(v6.2#6252)



More information about the asterisk-bugs mailing list