App_followme not waiting for Local/ Dial with AGI script


#1

Using Asterisk 13.23.1/ Realtime/ chan_sip/ agi script
Have issue where followme N switch not being honored when followme calls Local/ Dialplan. My _0. exten within Local enters agi script which dials the outbound followme number but before this new channel progress’ followme has already started playing call-from as soon as the AGI script started. Has anyone any pointers?

[2018-12-07 16:29:25] VERBOSE[43534][C-00007e92] pbx_realtime.c: Executing [followme329@10989-1143-routes:1] Set("SIP/peer1-4e76d4-00012078", "_SO=1")
[2018-12-07 16:29:25] VERBOSE[43534][C-00007e92] pbx_realtime.c: Executing [followme329@10989-1143-routes:2] Set("SIP/peer1-4e76d4-00012078", "CHANNEL(userfield)=followme329")
[2018-12-07 16:29:25] VERBOSE[43534][C-00007e92] pbx_realtime.c: Executing [followme329@10989-1143-routes:3] FollowMe("SIP/peer1-4e76d4-00012078", "10989-1143-followme329,N")
[2018-12-07 16:29:25] VERBOSE[43534][C-00007e92] app_followme.c: calling Local/07XXXXXXXXX@10989-1143-local/m
[2018-12-07 16:29:25] WARNING[43535][C-00007e92] func_channel.c: Unknown or unavailable item requested: 'peername'
[2018-12-07 16:29:25] VERBOSE[43535][C-00007e92] pbx_realtime.c: Executing [07XXXXXXXXX@10989-1143-local:1] GotoIf("Local/07XXXXXXXXX@10989-1143-local-00000f62;2", "0?10989-1143-outbound,_0.,8")
[2018-12-07 16:29:25] VERBOSE[43535][C-00007e92] pbx_realtime.c: Executing [07XXXXXXXXX@10989-1143-local:2] Set("Local/07XXXXXXXXX@10989-1143-local-00000f62;2", "GROUP()=10989-1143")
[2018-12-07 16:29:25] VERBOSE[43535][C-00007e92] pbx_realtime.c: Executing [07XXXXXXXXX@10989-1143-local:3] Set("Local/07XXXXXXXXX@10989-1143-local-00000f62;2", "TRUNK_MAX_CHANNELS=10")
[2018-12-07 16:29:25] VERBOSE[43535][C-00007e92] pbx_realtime.c: Executing [07XXXXXXXXX@10989-1143-local:4] Noop("Local/07XXXXXXXXX@10989-1143-local-00000f62;2", "Number of concurrent calls for 10989-1143 are 1")
[2018-12-07 16:29:25] VERBOSE[43535][C-00007e92] pbx_realtime.c: Executing [07XXXXXXXXX@10989-1143-local:5] GotoIf("Local/07XXXXXXXXX@10989-1143-local-00000f62;2", "0?peers,reject-call-limit,1")
[2018-12-07 16:29:25] VERBOSE[43535][C-00007e92] pbx_realtime.c: Executing [07XXXXXXXXX@10989-1143-local:6] Set("Local/07XXXXXXXXX@10989-1143-local-00000f62;2", "SHOWORIG=1")
[2018-12-07 16:29:25] VERBOSE[43535][C-00007e92] pbx_realtime.c: Executing [07XXXXXXXXX@10989-1143-local:7] Goto("Local/07XXXXXXXXX@10989-1143-local-00000f62;2", "12")
[2018-12-07 16:29:25] VERBOSE[43535][C-00007e92] pbx_builtins.c: Goto (10989-1143-local,07XXXXXXXXX,12)
[2018-12-07 16:29:25] VERBOSE[43535][C-00007e92] pbx_realtime.c: Executing [07XXXXXXXXX@10989-1143-local:12] AGI("Local/07XXXXXXXXX@10989-1143-local-00000f62;2", "outboundnew,1143, Local/07XXXXXXXXX@10989-1143-local-00000f62;2, 07XXXXXXXXX,1, 01XXXXXXXXX, ")
[2018-12-07 16:29:25] VERBOSE[43535][C-00007e92] res_agi.c: Launched AGI Script /var/lib/asterisk/agi-bin/outboundnew
[2018-12-07 16:29:25] VERBOSE[43534][C-00007e92] app_followme.c: Local/07XXXXXXXXX@10989-1143-local-00000f62;1 answered SIP/peer1-4e76d4-00012078
[2018-12-07 16:29:25] VERBOSE[43534][C-00007e92] app_followme.c: Starting playback of followme/call-from
[2018-12-07 16:29:25] VERBOSE[43534][C-00007e92] file.c: <Local/07XXXXXXXXX@10989-1143-local-00000f62;1> Playing 'followme/no-recording.alaw' (language 'uk')
[2018-12-07 16:29:25] VERBOSE[43535][C-00007e92] res_agi.c: outboundnew,1143, Local/07XXXXXXXXX@10989-1143-local-00000f62;2, 07XXXXXXXXX,1, 01XXXXXXXXX, : New Outbound Call :: SITE ID: 1143
[2018-12-07 16:29:25] VERBOSE[43535][C-00007e92] res_agi.c: outboundnew,1143, Local/07XXXXXXXXX@10989-1143-local-00000f62;2, 07XXXXXXXXX,1, 01XXXXXXXXX, : New Outbound Call :: CUSTOMER ID: 10989 (10989-1143)
[2018-12-07 16:29:25] VERBOSE[43535][C-00007e92] res_agi.c: outboundnew,1143, Local/07XXXXXXXXX@10989-1143-local-00000f62;2, 07XXXXXXXXX,1, 01XXXXXXXXX, : New Outbound Call :: CHANNEL: Local/07XXXXXXXXX@10989-1143-local-00000f62;2
[2018-12-07 16:29:25] VERBOSE[43535][C-00007e92] res_agi.c: outboundnew,1143, Local/07XXXXXXXXX@10989-1143-local-00000f62;2, 07XXXXXXXXX,1, 01XXXXXXXXX, : New Outbound Call :: ROUTE OUT: UK
[2018-12-07 16:29:25] VERBOSE[43535][C-00007e92] res_agi.c: outboundnew,1143, Local/07XXXXXXXXX@10989-1143-local-00000f62;2, 07XXXXXXXXX,1, 01XXXXXXXXX, : New Outbound Call :: CALL CHECKED:
[2018-12-07 16:29:25] VERBOSE[43535][C-00007e92] res_agi.c: AGI Script Executing Application: (Set) Options: (CDR(calltype)=Outgoing)
[2018-12-07 16:29:25] VERBOSE[43535][C-00007e92] res_agi.c: outboundnew,1143, Local/07XXXXXXXXX@10989-1143-local-00000f62;2, 07XXXXXXXXX,1, 01XXXXXXXXX, : New Outbound Call :: This is Local Channel Call
[2018-12-07 16:29:25] VERBOSE[43535][C-00007e92] res_agi.c: outboundnew,1143, Local/07XXXXXXXXX@10989-1143-local-00000f62;2, 07XXXXXXXXX,1, 01XXXXXXXXX, : New Outbound Call :: NUMBER DIALLED: 07XXXXXXXXX
[2018-12-07 16:29:25] VERBOSE[43535][C-00007e92] res_agi.c: outboundnew,1143, Local/07XXXXXXXXX@10989-1143-local-00000f62;2, 07XXXXXXXXX,1, 01XXXXXXXXX, : New Outbound Call :: OOUBOUND PROFILE: Allow All (Profile ID: 3)
[2018-12-07 16:29:25] VERBOSE[43535][C-00007e92] res_agi.c: outboundnew,1143, Local/07XXXXXXXXX@10989-1143-local-00000f62;2, 07XXXXXXXXX,1, 01XXXXXXXXX, : New Outbound Call :: SHOW ORIG: 1
[2018-12-07 16:29:25] VERBOSE[43535][C-00007e92] res_agi.c: outboundnew,1143, Local/07XXXXXXXXX@10989-1143-local-00000f62;2, 07XXXXXXXXX,1, 01XXXXXXXXX, : New Outbound Call :: SHOW ORIG IS YES
[2018-12-07 16:29:25] VERBOSE[43535][C-00007e92] res_agi.c: AGI Script Executing Application: (Set) Options: (CDR(outbound_number)=07XXXXXXXXX)
[2018-12-07 16:29:25] VERBOSE[43535][C-00007e92] res_agi.c: AGI Script Executing Application: (Set) Options: (CDR(out_clid)=07XXXXXXXXX)
[2018-12-07 16:29:25] VERBOSE[43535][C-00007e92] res_agi.c: AGI Script Executing Application: (Set) Options: (CALLERID(num)=07XXXXXXXXX)
[2018-12-07 16:29:25] VERBOSE[43535][C-00007e92] res_agi.c: AGI Script Executing Application: (Set) Options: (CDR(exten)=07XXXXXXXXX)
[2018-12-07 16:29:25] VERBOSE[43535][C-00007e92] res_agi.c: outboundnew,1143, Local/07XXXXXXXXX@10989-1143-local-00000f62;2, 07XXXXXXXXX,1, 01XXXXXXXXX, : New Outbound Call :: Checking TC ::
[2018-12-07 16:29:25] VERBOSE[43535][C-00007e92] res_agi.c: outboundnew,1143, Local/07XXXXXXXXX@10989-1143-local-00000f62;2, 07XXXXXXXXX,1, 01XXXXXXXXX, : New Outbound Call :: Today is Friday ::
[2018-12-07 16:29:25] VERBOSE[43535][C-00007e92] res_agi.c: outboundnew,1143, Local/07XXXXXXXXX@10989-1143-local-00000f62;2, 07XXXXXXXXX,1, 01XXXXXXXXX, : New Outbound Call :: Checking TC :: Its the Weekday And Profile is allowed to Dial All Weekday. Continuing ...
[2018-12-07 16:29:25] VERBOSE[43535][C-00007e92] res_agi.c: outboundnew,1143, Local/07XXXXXXXXX@10989-1143-local-00000f62;2, 07XXXXXXXXX,1, 01XXXXXXXXX, : New Outbound Call :: Continuing To Dial..
[2018-12-07 16:29:25] VERBOSE[43535][C-00007e92] res_agi.c: AGI Script Executing Application: (Set) Options: (CDR(destination_real)=UK)
[2018-12-07 16:29:25] VERBOSE[43535][C-00007e92] res_agi.c: outboundnew,1143, Local/07XXXXXXXXX@10989-1143-local-00000f62;2, 07XXXXXXXXX,1, 01XXXXXXXXX, : New Outbound Call :: Checking General :: This is a UK Breakout Call
[2018-12-07 16:29:25] VERBOSE[43535][C-00007e92] res_agi.c: outboundnew,1143, Local/07XXXXXXXXX@10989-1143-local-00000f62;2, 07XXXXXXXXX,1, 01XXXXXXXXX, : New Outbound Call :: Checking General :: This is a National UK Call
[2018-12-07 16:29:25] VERBOSE[43535][C-00007e92] res_agi.c: outboundnew,1143, Local/07XXXXXXXXX@10989-1143-local-00000f62;2, 07XXXXXXXXX,1, 01XXXXXXXXX, : New Outbound Call :: Checking General :: This is a National Mobile (07) Call
[2018-12-07 16:29:25] VERBOSE[43535][C-00007e92] res_agi.c: outboundnew,1143, Local/07XXXXXXXXX@10989-1143-local-00000f62;2, 07XXXXXXXXX,1, 01XXXXXXXXX, : New Outbound Call :: Checking General :: National Mobile Call Allowed
[2018-12-07 16:29:25] VERBOSE[43535][C-00007e92] res_agi.c: outboundnew,1143, Local/07XXXXXXXXX@10989-1143-local-00000f62;2, 07XXXXXXXXX,1, 01XXXXXXXXX, : New Outbound Call :: Checking General :: Dialled No: 07XXXXXXXXX :: New No: 447XXXXXXXXXX
[2018-12-07 16:29:25] VERBOSE[43535][C-00007e92] res_agi.c: outboundnew,1143, Local/07XXXXXXXXX@10989-1143-local-00000f62;2, 07XXXXXXXXX,1, 01XXXXXXXXX, : New Outbound Call :: Checking General :: Rate Name: Uk Vodafone Mobile Rate :: Sell: 0.031219999999999998
[2018-12-07 16:29:25] VERBOSE[43535][C-00007e92] res_agi.c: outboundnew,1143, Local/07XXXXXXXXX@10989-1143-local-00000f62;2, 07XXXXXXXXX,1, 01XXXXXXXXX, : New Outbound Call :: Dialling Out Now ::
[2018-12-07 16:29:25] VERBOSE[43535][C-00007e92] res_agi.c: AGI Script Executing Application: (SIPAddHeader) Options: (X-accountcode:10989-1143)
[2018-12-07 16:29:25] VERBOSE[43535][C-00007e92] res_agi.c: AGI Script Executing Application: (Dial) Options: (SIP/GW01-UK/07XXXXXXXXX)
[2018-12-07 16:29:25] VERBOSE[43535][C-00007e92] netsock2.c: Using SIP RTP CoS mark 5
[2018-12-07 16:29:25] VERBOSE[43535][C-00007e92] app_dial.c: Called SIP/GW01-UK/07XXXXXXXXX
[2018-12-07 16:29:27] VERBOSE[43534][C-00007e92] app_followme.c: <Local/07XXXXXXXXX@10989-1143-local-00000f62;1> Playback of name file appears to be done.
[2018-12-07 16:29:27] VERBOSE[43534][C-00007e92] file.c: <Local/07XXXXXXXXX@10989-1143-local-00000f62;1> Playing 'followme/options.alaw' (language 'uk')
[2018-12-07 16:29:28] VERBOSE[65737][C-00007e92] res_rtp_asterisk.c: 0x7f3228014730 -- Strict RTP learning after remote address set to: xxx.xxx.xxx.xxx:16384
[2018-12-07 16:29:28] VERBOSE[43535][C-00007e92] app_dial.c: SIP/GW01-UK-00012079 is making progress passing it to Local/07XXXXXXXXX@10989-1143-local-00000f62;2
[2018-12-07 16:29:28] VERBOSE[43534][C-00007e92] app_followme.c: Local/07XXXXXXXXX@10989-1143-local-00000f62;1 is making progress
[2018-12-07 16:29:28] VERBOSE[43535][C-00007e92] res_rtp_asterisk.c: 0x7f3228014730 -- Strict RTP switching to RTP target address xxx.xxx.xxx.xxx:16384 as source
[2018-12-07 16:29:31] VERBOSE[43534][C-00007e92] app_followme.c: <Local/07XXXXXXXXX@10989-1143-local-00000f62;1> Playback of the next step file appears to be done.
[2018-12-07 16:29:33] VERBOSE[43535][C-00007e92] res_rtp_asterisk.c: 0x7f3228014730 -- Strict RTP learning complete - Locking on source address xxx.xxx.xxx.xxx:16384
[2018-12-07 16:29:35] VERBOSE[43535][C-00007e92] app_dial.c: SIP/GW01-UK-00012079 answered Local/07XXXXXXXXX@10989-1143-local-00000f62;2
[2018-12-07 16:29:35] VERBOSE[43583][C-00007e92] bridge_channel.c: Channel SIP/GW01-UK-00012079 joined 'simple_bridge' basic-bridge <3a61a3f5-3180-4448-bcf2-0e881e55dd51>
[2018-12-07 16:29:35] VERBOSE[43535][C-00007e92] bridge_channel.c: Channel Local/07XXXXXXXXX@10989-1143-local-00000f62;2 joined 'simple_bridge' basic-bridge <3a61a3f5-3180-4448-bcf2-0e881e55dd51>

#2

Found my issue. Was answering channel at start of AGI Script. :see_no_evil: