Park Return issues

PitzKey · February 10, 2022, 1:54pm

Hello,

The issue:

When you have Return to Originator set to Yes, after it rings by the originator, the call just drops.

Logs… (Read them here for easer read: https://pastebin.com/raw/hUyu3hke)

The call reaches the parking context:

[2022-02-09 16:36:20] VERBOSE[50940][C-000488db] pbx.c: Executing [701@T52_cos-all-post:1] NoOp("Local/115@T52_ring-group-dial-0006e505;2", "Slot: 701") in new stack
[2022-02-09 16:36:20] VERBOSE[50940][C-000488db] pbx.c: Executing [701@T52_cos-all-post:2] Set("Local/115@T52_ring-group-dial-0006e505;2", "RECORD_PARKING_LOT=yes") in new stack
[2022-02-09 16:36:20] VERBOSE[50940][C-000488db] pbx.c: Executing [701@T52_cos-all-post:3] Gosub("Local/115@T52_ring-group-dial-0006e505;2", "sub-parking-lots,s,1(701,parking-52,parking-52-parkedcalls)") in new stack
[2022-02-09 16:36:20] VERBOSE[50940][C-000488db] pbx.c: Executing [s@sub-parking-lots:1] NoOp("Local/115@T52_ring-group-dial-0006e505;2", "Parking lots") in new stack
[2022-02-09 16:36:20] VERBOSE[50940][C-000488db] pbx.c: Executing [s@sub-parking-lots:2] Set("Local/115@T52_ring-group-dial-0006e505;2", "PARKING_LOT=701") in new stack
[2022-02-09 16:36:20] VERBOSE[50940][C-000488db] pbx.c: Executing [s@sub-parking-lots:3] Set("Local/115@T52_ring-group-dial-0006e505;2", "PARKING_NAME=parking-52") in new stack
[2022-02-09 16:36:20] VERBOSE[50940][C-000488db] pbx.c: Executing [s@sub-parking-lots:4] Set("Local/115@T52_ring-group-dial-0006e505;2", "PARKING_HINT_CTXT=parking-52-parkedcalls") in new stack
[2022-02-09 16:36:20] VERBOSE[50940][C-000488db] pbx.c: Executing [s@sub-parking-lots:5] Set("Local/115@T52_ring-group-dial-0006e505;2", "PARKING_LOT_STATE=NOT_INUSE") in new stack
[2022-02-09 16:36:20] VERBOSE[50940][C-000488db] pbx.c: Executing [s@sub-parking-lots:6] GotoIf("Local/115@T52_ring-group-dial-0006e505;2", "1?park_call") in new stack
[2022-02-09 16:36:20] VERBOSE[50940][C-000488db] pbx_builtins.c: Goto (sub-parking-lots,s,18)
[2022-02-09 16:36:20] VERBOSE[50940][C-000488db] pbx.c: Executing [s@sub-parking-lots:18] NoOp("Local/115@T52_ring-group-dial-0006e505;2", "Parking Call on Slot 701") in new stack
[2022-02-09 16:36:20] VERBOSE[50940][C-000488db] pbx.c: Executing [s@sub-parking-lots:19] Set("Local/115@T52_ring-group-dial-0006e505;2", "PARKINGEXTEN=701") in new stack
[2022-02-09 16:36:20] VERBOSE[50940][C-000488db] pbx.c: Executing [s@sub-parking-lots:20] Park("Local/115@T52_ring-group-dial-0006e505;2", "parking-52") in new stack

The caller gets parked:

[2022-02-09 16:36:20] VERBOSE[50940][C-000488db] parking/parking_bridge.c: Parking 'Local/115@T52_ring-group-dial-0006e505;2' in 'parking-52' at space 701
[2022-02-09 16:36:20] VERBOSE[50940][C-000488db] bridge_channel.c: Channel Local/115@T52_ring-group-dial-0006e505;2 joined 'holding_bridge' parking-bridge <933dbc9a-fa94-4f78-8655-fb06fd50a6a7>
[2022-02-09 16:36:20] VERBOSE[50940][C-000488db] res_musiconhold.c: Started music on hold, class 'default', on channel 'Local/115@T52_ring-group-dial-0006e505;2'

After two minutes, the call returns to the originator:

[2022-02-09 16:38:20] VERBOSE[50940][C-000488db] bridge_channel.c: Channel Local/115@T52_ring-group-dial-0006e505;2 left 'holding_bridge' parking-bridge <933dbc9a-fa94-4f78-8655-fb06fd50a6a7>
[2022-02-09 16:38:20] VERBOSE[50940][C-000488db] res_musiconhold.c: Stopped music on hold on Local/115@T52_ring-group-dial-0006e505;2
[2022-02-09 16:38:20] VERBOSE[50940][C-000488db] pbx.c: Executing [PJSIP_T52_115@park-dial:1] Dial("Local/115@T52_ring-group-dial-0006e505;2", "PJSIP/T52_115,20") in new stack
[2022-02-09 16:38:20] VERBOSE[50940][C-000488db] app_dial.c: Called PJSIP/T52_115
[2022-02-09 16:38:20] VERBOSE[50940][C-000488db] app_dial.c: PJSIP/T52_115-00052df8 is ringing

But when the originator fails to answer, the call drops:

[2022-02-09 16:38:40] VERBOSE[50940][C-000488db] app_dial.c: Nobody picked up in 20000 ms
[2022-02-09 16:38:40] VERBOSE[50940][C-000488db] pbx.c: Channel 'Local/115@T52_ring-group-dial-0006e505;2' sent to invalid extension: context,exten,priority=park-dial,PJSIP_T52_115,2
[2022-02-09 16:38:40] VERBOSE[50940][C-000488db] pbx.c: Executing [i@park-dial:1] NoOp("Local/115@T52_ring-group-dial-0006e505;2", "End of the line for a timed-out parked call.") in new stack
[2022-02-09 16:38:40] VERBOSE[50940][C-000488db] pbx.c: Executing [i@park-dial:2] Playback("Local/115@T52_ring-group-dial-0006e505;2", "sorry2&vm-goodbye") in new stack

Understanding the issue:

Quoting from: asterisk/configs/samples/res_parking.conf.sample at master · asterisk/asterisk · GitHub

When the parked call times out, attempt to send the call back to the peer that parked this call. This is done by saving off the name of the channel that parked the call. The call will return to the context ‘park-dial’ and an extension created based on the name of the channel that originally parked the call. This extension will be created automatically to do a Dial() to the device that originally parked the call for comebacktodialtime seconds. If the call is not answered, the call will proceed to the next priority (usually none unless you deliberately set up a catch-all second priority in the park-call context) in the dialplan for extension matching the peer name (same as how peer names are flattened into extensions when comebacktoorigin is ‘no’).

Looking at the VitalPBX context:

[root@vitalpbx1 ~]# asterisk -x"dialplan show park-dial"
[ Context 'park-dial' created by 'pbx_config' ]
  'i' =>            1. NoOp(End of the line for a timed-out parked call.) [extensions__20-baseplan.conf:2435]
                    2. Playback(sorry2&vm-goodbye)                [extensions__20-baseplan.conf:2436]
                    3. Hangup()                                   [extensions__20-baseplan.conf:2437]
  't' =>            1. NoOp(End of the line for a timed-out parked call.) [extensions__20-baseplan.conf:2431]
                    2. Playback(sorry2&vm-goodbye)                [extensions__20-baseplan.conf:2432]
                    3. Hangup()                                   [extensions__20-baseplan.conf:2433]

Looking again at the quoted text:

the call will proceed to the next priority (usually none unless you deliberately set up a catch-all second priority in the park-call context) in the dialplan for extension matching the peer name

This explains this line in the log:

[2022-02-09 16:38:40] VERBOSE[50940][C-000488db] pbx.c: Channel 'Local/115@T52_ring-group-dial-0006e505;2' sent to invalid extension: context,exten,priority=park-dial,PJSIP_T52_115,2

There must be a catchall priority 2 in the park-dial context. Perhaps something like:

[park-dial]
exten => _.,2,Noop(Failed to reach the party...)
...
...

This explains why calls are failing. It dials the actual device (PJSIP/DEVICE) - not the local channel, so there’s no way the call actually ends up to the parkers voicemail. And then there’s no catchall extension to handle failover properly, for example to send the call to a queue/ring group or any failover destination.

This is super annoying to callers.

Suggested solutions:

Solution 1 - Setting a failover destination:

Allow setting in the park settings a “Failed Return to Originator Destination” and set that destination as priority 2.

[park-dial]
exten => _.,2,Goto(T52_cos-all,200,1); This is a queue or ring group let's say...

Note: This destination will have to be fetched from the database so it can handle tenants…

Solution 2 - not using the built in comeback to origin:

In the park config, set comebacktoorigin to no.
Then, in the sub-parking-lots context set a variable something like COMEBACK_DESTINATION=T52_cos-all,115,1 (this, is in my example, is the extension of the originator. So it will need to be dynamically set through the call variables)

Then, replace:

same => n,Park(${PARKING_NAME})

with:

same => n,Park(${PARKING_NAME},c(${COMEBACK_DESTINATION}))

You can even take this a step further and set COMEBACK_DESTINATION=${TENANT_ID}_comback-context,s,1 and in that context handle the return destination.

Solution 3 - changing the peer to the local channel (my least favorite solution):

Simple. Instead of returning to PJSIP/DEVICE, return to local/ext@context

I personally think, that solution 2 will be the best option, since you can also do solution 1 via solution 2.

Let me know if you have any questions

Thank you

miguel · February 10, 2022, 3:11pm

First thing first, a bunch of thanks for your detailed report and suggestions.

We will get down to business on this as soon as possible.

PitzKey · February 28, 2022, 5:17pm

We did the following for now:

in [park-dial] we added the following line:

exten => _.,2,GotoIf($[${DIALPLAN_EXISTS(${PARKING_NAME}-parkedcallstimeout,s,1)}]?${PARKING_NAME}-parkedcallstimeout,s,1:i,1)

(Note: is MUST be with the 2 priority, _.,n, won’t work)

What that does, once it rang by the Originator and they failed to answer, then the call goes to the Timeout Destination defined in the parking lot. If for some reason it cannot find such a context, then it will go to the failed extension. This is working fine. See log:

;Call enters park
[2022-02-28 12:04:43] VERBOSE[108996][C-0005ecd7] parking/parking_bridge.c: Parking 'SIP/SIPProvider-00073df0' in 'parking-37' at space 703
[2022-02-28 12:04:43] VERBOSE[108996][C-0005ecd7] bridge_channel.c: Channel SIP/SIPProvider-00073df0 joined 'holding_bridge' parking-bridge <8942b96e-17f6-4084-b9bc-1668212af64f>
[2022-02-28 12:04:43] VERBOSE[108996][C-0005ecd7] res_musiconhold.c: Started music on hold, class 'default', on channel 'SIP/SIPProvider-00073df0'
[2022-02-28 12:05:03] VERBOSE[108996][C-0005ecd7] bridge_channel.c: Channel SIP/SIPProvider-00073df0 left 'holding_bridge' parking-bridge <8942b96e-17f6-4084-b9bc-1668212af64f>
[2022-02-28 12:05:03] VERBOSE[108996][C-0005ecd7] res_musiconhold.c: Stopped music on hold on SIP/SIPProvider-00073df0

;The PBX calls the originator
[2022-02-28 12:05:03] VERBOSE[108996][C-0005ecd7] pbx.c: Executing [PJSIP_T37_6406@park-dial:1] Dial("SIP/SIPProvider-00073df0", "PJSIP/T37_6406,5") in new stack
[2022-02-28 12:05:03] VERBOSE[108996][C-0005ecd7] app_dial.c: Called PJSIP/T37_6406
[2022-02-28 12:05:03] VERBOSE[108996][C-0005ecd7] app_dial.c: PJSIP/T37_6406-0006e8ec is ringing

;Originator failed to answer
[2022-02-28 12:05:08] VERBOSE[108996][C-0005ecd7] app_dial.c: Nobody picked up in 5000 ms

;We catch the call with the catchall extension of _. along with the priority 2
[2022-02-28 12:05:08] VERBOSE[108996][C-0005ecd7] pbx.c: Executing [PJSIP_T37_6406@park-dial:2] GotoIf("SIP/SIPProvider-00073df0", "1?parking-37-parkedcallstimeout,s,1:i,1") in new stack

;It found the dialplan
[2022-02-28 12:05:08] VERBOSE[108996][C-0005ecd7] pbx_builtins.c: Goto (parking-37-parkedcallstimeout,s,1)
[2022-02-28 12:05:08] VERBOSE[108996][C-0005ecd7] pbx.c: Executing [s@parking-37-parkedcallstimeout:1] NoOp("SIP/SIPProvider-00073df0", "Parking Timeout has been reached") in new stack
[2022-02-28 12:05:08] VERBOSE[108996][C-0005ecd7] pbx.c: Executing [s@parking-37-parkedcallstimeout:2] Gosub("SIP/SIPProvider-00073df0", "T37_app-ivr,IVR-138,1") in new stack
[2022-02-28 12:05:08] VERBOSE[108996][C-0005ecd7] pbx.c: Executing [IVR-138@T37_app-ivr:1] Goto("SIP/SIPProvider-00073df0", "IVR-138,s,1") in new stack
[2022-02-28 12:05:08] VERBOSE[108996][C-0005ecd7] pbx_builtins.c: Goto (IVR-138,s,1)

Let me know if you need any further feedback

Thanks

PitzKey · March 9, 2022, 2:31pm

Hello,

Looking at the latest update, it says:

Parking: unpicked calls from parking lots with the option “Return to Originator” enabled got hung up instead of ringing the number that parked the call.

This is incorrect. The call did ring by the originator! But if the originator failed to answer, then the call got lost. (See logs and details above)

This is still an issue in the latest update. See logs:

;Getting to the parking lot
[2022-03-09 09:19:27] VERBOSE[74712][C-0000000e] pbx.c: Executing [703@cos-all-post:1] NoOp("PJSIP/6413-0000000d", "Slot: 703") in new stack
[2022-03-09 09:19:27] VERBOSE[74712][C-0000000e] pbx.c: Executing [703@cos-all-post:2] Set("PJSIP/6413-0000000d", "RECORD_PARKING_LOT=yes") in new stack
[2022-03-09 09:19:27] VERBOSE[74712][C-0000000e] pbx.c: Executing [703@cos-all-post:3] Gosub("PJSIP/6413-0000000d", "sub-parking-lots,s,1(703,parking-1,parking-1-parkedcalls)") in new stack
[2022-03-09 09:19:27] VERBOSE[74712][C-0000000e] pbx.c: Executing [s@sub-parking-lots:1] NoOp("PJSIP/6413-0000000d", "Parking lots") in new stack
[2022-03-09 09:19:27] VERBOSE[74712][C-0000000e] pbx.c: Executing [s@sub-parking-lots:2] Set("PJSIP/6413-0000000d", "PARKING_LOT=703") in new stack
[2022-03-09 09:19:27] VERBOSE[74712][C-0000000e] pbx.c: Executing [s@sub-parking-lots:3] Set("PJSIP/6413-0000000d", "PARKING_NAME=parking-1") in new stack
[2022-03-09 09:19:27] VERBOSE[74712][C-0000000e] pbx.c: Executing [s@sub-parking-lots:4] Set("PJSIP/6413-0000000d", "PARKING_HINT_CTXT=parking-1-parkedcalls") in new stack
[2022-03-09 09:19:27] VERBOSE[74712][C-0000000e] pbx.c: Executing [s@sub-parking-lots:5] Set("PJSIP/6413-0000000d", "PARKING_LOT_STATE=NOT_INUSE") in new stack
[2022-03-09 09:19:27] VERBOSE[74712][C-0000000e] pbx.c: Executing [s@sub-parking-lots:6] GotoIf("PJSIP/6413-0000000d", "1?park_call") in new stack
[2022-03-09 09:19:27] VERBOSE[74712][C-0000000e] pbx_builtins.c: Goto (sub-parking-lots,s,18)
[2022-03-09 09:19:27] VERBOSE[74712][C-0000000e] pbx.c: Executing [s@sub-parking-lots:18] NoOp("PJSIP/6413-0000000d", "Parking Call on Slot 703") in new stack
[2022-03-09 09:19:27] VERBOSE[74712][C-0000000e] pbx.c: Executing [s@sub-parking-lots:19] Set("PJSIP/6413-0000000d", "PARKINGEXTEN=703") in new stack
[2022-03-09 09:19:27] VERBOSE[74712][C-0000000e] pbx.c: Executing [s@sub-parking-lots:20] Park("PJSIP/6413-0000000d", "parking-1") in new stack
[2022-03-09 09:19:27] VERBOSE[74712][C-0000000e] parking/parking_applications.c: Setting Parker dial string to PJSIP/6406 from BLINDTRANSFER value

;Call got parked
[2022-03-09 09:19:27] VERBOSE[74712][C-0000000e] parking/parking_bridge.c: Parking 'PJSIP/6413-0000000d' in 'parking-1' at space 703
[2022-03-09 09:19:27] VERBOSE[74712][C-0000000e] bridge_channel.c: Channel PJSIP/6413-0000000d joined 'holding_bridge' parking-bridge <6fadefb1-6bf2-4bcd-93f3-2c2e8f6b271b>
[2022-03-09 09:19:27] VERBOSE[74712][C-0000000e] res_musiconhold.c: Started music on hold, class 'default', on channel 'PJSIP/6413-0000000d'

;Timeout, so the call leaves park
[2022-03-09 09:20:03] VERBOSE[74712][C-0000000e] bridge_channel.c: Channel PJSIP/6413-0000000d left 'holding_bridge' parking-bridge <6fadefb1-6bf2-4bcd-93f3-2c2e8f6b271b>
[2022-03-09 09:20:03] VERBOSE[74712][C-0000000e] res_musiconhold.c: Stopped music on hold on PJSIP/6413-0000000d

;Call is being returned to the originator
[2022-03-09 09:20:03] VERBOSE[74712][C-0000000e] pbx.c: Executing [PJSIP_6406@park-dial:1] Dial("PJSIP/6413-0000000d", "PJSIP/6406,5") in new stack
[2022-03-09 09:20:03] VERBOSE[74712][C-0000000e] app_dial.c: Called PJSIP/6406
[2022-03-09 09:20:03] VERBOSE[74712][C-0000000e] app_dial.c: PJSIP/6406-0000000f is ringing

;Originator failed to answer
[2022-03-09 09:20:08] VERBOSE[74712][C-0000000e] app_dial.c: Nobody picked up in 5000 ms

;Call getting disconnected
[2022-03-09 09:20:08] VERBOSE[74712][C-0000000e] pbx.c: Auto fallthrough, channel 'PJSIP/6413-0000000d' status is 'NOANSWER'

@VitalPBX Team. What am I missing?

Thanks

PitzKey · March 14, 2022, 11:58am

Hello,

Bump… Bump…

miguel · March 24, 2022, 9:47pm

I have something for you to test.

In the file extensions__20-baseplan.conf modify the context sub-local-dialing. Almost at the end of the file, replace the lines below.

same => n,GotoIf($[$["${SKIP_CONTACT_SERVICES}"="TRUE"]&$["${BLINDTRANSFER}"=""]]?end_call)
 same => n,GotoIf($[$["${NO_POST_SERVICES}"="TRUE"]&$["${BLINDTRANSFER}"=""]]?end_call)

With

same => n,GotoIf($[$[$["${SKIP_CONTACT_SERVICES}"="TRUE"]&$["${BLINDTRANSFER}"=""]]&$["${LEN(${PARKER})}"="0"]]?end_call)
same => n,GotoIf($[$[$["${NO_POST_SERVICES}"="TRUE"]&$["${BLINDTRANSFER}"=""]]&$["${LEN(${PARKER})}"="0"]]?end_call)

I found out that the issue only happens when the call comes through a Ring Group. So, if you call internally or the call comes from any application but Ring Group, it should work with the current version.

With this new modification that I am proposing, it should work flawlessly with Ring Groups.

PitzKey · March 30, 2022, 3:20pm

Hi Jose,

Sorry about the delayed response.

I modified the dialplan per your suggestions and I tested the following call.

Incoming call → IVR → Extension → Extension Answer → Extension Transfer to park → Park Timeout → Return to Originator → Originator fails to answer → Call lost.

See call log: pastebin link

Let me know if you have any questions

Thanks

miguel · March 30, 2022, 3:36pm

I saw a context that’s not present on VitalPBX “stop-call-timer.” I see it is executed a couple of times during the call.

I will send you a call log with the development version that I have.

PitzKey · April 5, 2022, 1:36pm

This is because we have added a custom hangup handler. I have tried now on an outgoing call.

Outbound call → Callee Answered → Transfer to Park → Park Timeout → Return to Originator → Originator fails to answer → Call lost.

See log:

[2022-04-05 09:24:10] VERBOSE[6524][C-00000002] pbx.c: Executing [702@cos-all-post:1] NoOp("PJSIP/SIPProvider-00000003", "Slot: 702") in new stack
[2022-04-05 09:24:10] VERBOSE[6524][C-00000002] pbx.c: Executing [702@cos-all-post:2] Set("PJSIP/SIPProvider-00000003", "RECORD_PARKING_LOT=no") in new stack
[2022-04-05 09:24:10] VERBOSE[6524][C-00000002] pbx.c: Executing [702@cos-all-post:3] Gosub("PJSIP/SIPProvider-00000003", "sub-parking-lots,s,1(702,parking-1,parking-1-parkedcalls)") in new stack
[2022-04-05 09:24:10] VERBOSE[6524][C-00000002] pbx.c: Executing [s@sub-parking-lots:1] NoOp("PJSIP/SIPProvider-00000003", "Parking lots") in new stack
[2022-04-05 09:24:10] VERBOSE[6524][C-00000002] pbx.c: Executing [s@sub-parking-lots:2] Set("PJSIP/SIPProvider-00000003", "PARKING_LOT=702") in new stack
[2022-04-05 09:24:10] VERBOSE[6524][C-00000002] pbx.c: Executing [s@sub-parking-lots:3] Set("PJSIP/SIPProvider-00000003", "PARKING_NAME=parking-1") in new stack
[2022-04-05 09:24:10] VERBOSE[6524][C-00000002] pbx.c: Executing [s@sub-parking-lots:4] Set("PJSIP/SIPProvider-00000003", "PARKING_HINT_CTXT=parking-1-parkedcalls") in new stack
[2022-04-05 09:24:10] VERBOSE[6524][C-00000002] pbx.c: Executing [s@sub-parking-lots:5] Set("PJSIP/SIPProvider-00000003", "PARKING_LOT_STATE=NOT_INUSE") in new stack
[2022-04-05 09:24:10] VERBOSE[6524][C-00000002] pbx.c: Executing [s@sub-parking-lots:6] GotoIf("PJSIP/SIPProvider-00000003", "1?park_call") in new stack
[2022-04-05 09:24:10] VERBOSE[6524][C-00000002] pbx_builtins.c: Goto (sub-parking-lots,s,18)
[2022-04-05 09:24:10] VERBOSE[6524][C-00000002] pbx.c: Executing [s@sub-parking-lots:18] NoOp("PJSIP/SIPProvider-00000003", "Parking Call on Slot 702") in new stack
[2022-04-05 09:24:10] VERBOSE[6524][C-00000002] pbx.c: Executing [s@sub-parking-lots:19] Set("PJSIP/SIPProvider-00000003", "PARKINGEXTEN=702") in new stack
[2022-04-05 09:24:10] VERBOSE[6524][C-00000002] pbx.c: Executing [s@sub-parking-lots:20] Park("PJSIP/SIPProvider-00000003", "parking-1") in new stack
[2022-04-05 09:24:10] VERBOSE[6524][C-00000002] parking/parking_bridge.c: Parking 'PJSIP/SIPProvider-00000003' in 'parking-1' at space 702
[2022-04-05 09:24:10] VERBOSE[6524][C-00000002] bridge_channel.c: Channel PJSIP/SIPProvider-00000003 joined 'holding_bridge' parking-bridge <b9a4394e-0788-4f6f-ad42-c192afa436b7>
[2022-04-05 09:24:10] VERBOSE[6524][C-00000002] res_musiconhold.c: Started music on hold, class 'default', on channel 'PJSIP/SIPProvider-00000003'
[2022-04-05 09:24:30] VERBOSE[6524][C-00000002] bridge_channel.c: Channel PJSIP/SIPProvider-00000003 left 'holding_bridge' parking-bridge <b9a4394e-0788-4f6f-ad42-c192afa436b7>
[2022-04-05 09:24:30] VERBOSE[6524][C-00000002] res_musiconhold.c: Stopped music on hold on PJSIP/SIPProvider-00000003
[2022-04-05 09:24:30] VERBOSE[6524][C-00000002] pbx.c: Executing [PJSIP_6406@park-dial:1] Dial("PJSIP/SIPProvider-00000003", "PJSIP/6406,10") in new stack
[2022-04-05 09:24:30] VERBOSE[6524][C-00000002] app_dial.c: Called PJSIP/6406
[2022-04-05 09:24:30] VERBOSE[6524][C-00000002] app_dial.c: PJSIP/6406-00000004 is ringing
[2022-04-05 09:24:40] VERBOSE[6524][C-00000002] app_dial.c: Nobody picked up in 10000 ms
[2022-04-05 09:24:40] VERBOSE[6524][C-00000002] pbx.c: Auto fallthrough, channel 'PJSIP/SIPProvider-00000003' status

miguel · April 5, 2022, 4:07pm

This is the call log generated by our lab system. The call goes to voicemail as expected. I guess it could be something with your phone device, you can try decreasing the ring time of your phone, try with 10 seconds.

  -- Channel PJSIP/104-00000000 left 'holding_bridge' parking-bridge <ffe89b02-e7b6-4c6e-ace7-256500fa977e>
    -- Stopped music on hold on PJSIP/104-00000000
    -- Executing [s@parking-1-callback:1] NoOp("PJSIP/104-00000000", "Returning Call") in new stack
    -- Executing [s@parking-1-callback:2] Set("PJSIP/104-00000000", "CALLBACK_EXT=101") in new stack
    -- Executing [s@parking-1-callback:3] Set("PJSIP/104-00000000", "CALLBACK_CTXT=cos-all") in new stack
    -- Executing [s@parking-1-callback:4] GotoIf("PJSIP/104-00000000", "0?end") in new stack
    -- Executing [s@parking-1-callback:5] Goto("PJSIP/104-00000000", "cos-all,101,1") in new stack
    -- Goto (cos-all,101,1)
    -- Executing [101@cos-all:1] NoOp("PJSIP/104-00000000", "More than on digit pattern") in new stack
    -- Executing [101@cos-all:2] Gosub("PJSIP/104-00000000", "s,1(101)") in new stack
    -- Executing [s@cos-all:1] Set("PJSIP/104-00000000", "EXTENSION=101") in new stack
    -- Executing [s@cos-all:2] NoOp("PJSIP/104-00000000", "Dialing 101 from 2023010010104") in new stack
    -- Executing [s@cos-all:3] Gosub("PJSIP/104-00000000", "sub-set-global-vars,s,1(713b0732d7b683af,101,parking-1)") in new stack
    -- Executing [s@sub-set-global-vars:1] NoOp("PJSIP/104-00000000", "Setting Global Vars") in new stack
    -- Executing [s@sub-set-global-vars:2] Set("PJSIP/104-00000000", "TENANT_PATH=713b0732d7b683af") in new stack
    -- Executing [s@sub-set-global-vars:3] Set("PJSIP/104-00000000", "PREFIX=") in new stack
    -- Executing [s@sub-set-global-vars:4] Set("PJSIP/104-00000000", "__PICKUPMARK=101") in new stack
    -- Executing [s@sub-set-global-vars:5] Set("PJSIP/104-00000000", "__PARKINGLOT=parking-1") in new stack
    -- Executing [s@sub-set-global-vars:6] Set("PJSIP/104-00000000", "__DYNAMIC_FEATURES=custom-features") in new stack
    -- Executing [s@sub-set-global-vars:7] Set("PJSIP/104-00000000", "ICALL=no") in new stack
    -- Executing [s@sub-set-global-vars:8] Return("PJSIP/104-00000000", "") in new stack
    -- Executing [s@cos-all:4] Gosub("PJSIP/104-00000000", "sub-set-call-vars,s,1(713b0732d7b683af,101,1,cos-all,ARS-all)") in new stack
    -- Executing [s@sub-set-call-vars:1] NoOp("PJSIP/104-00000000", "Setting Call Vars") in new stack
    -- Executing [s@sub-set-call-vars:2] Set("PJSIP/104-00000000", "_TENANT=713b0732d7b683af") in new stack
    -- Executing [s@sub-set-call-vars:3] Set("PJSIP/104-00000000", "_CALL_DESTINATION=101") in new stack
    -- Executing [s@sub-set-call-vars:4] Set("PJSIP/104-00000000", "_COS_ID=1") in new stack
    -- Executing [s@sub-set-call-vars:5] Set("PJSIP/104-00000000", "_COS_NAME=cos-all") in new stack
    -- Executing [s@sub-set-call-vars:6] Set("PJSIP/104-00000000", "__TRANSFER_CONTEXT=cos-all") in new stack
    -- Executing [s@sub-set-call-vars:7] Set("PJSIP/104-00000000", "_ARS=ARS-all") in new stack
    -- Executing [s@sub-set-call-vars:8] Set("PJSIP/104-00000000", "CDR(tenant)=vitalpbx") in new stack
    -- Executing [s@sub-set-call-vars:9] Set("PJSIP/104-00000000", "CDR(destination)=101") in new stack
    -- Executing [s@sub-set-call-vars:10] Set("PJSIP/104-00000000", "CDR(trunk)=") in new stack
    -- Executing [s@sub-set-call-vars:11] Set("PJSIP/104-00000000", "CDR(did)=") in new stack
    -- Executing [s@sub-set-call-vars:12] Set("PJSIP/104-00000000", "__CALLID=1649174655.10") in new stack
    -- Executing [s@sub-set-call-vars:13] ExecIf("PJSIP/104-00000000", "0?Set(CHANNEL(language)=)") in new stack
    -- Executing [s@sub-set-call-vars:14] ExecIf("PJSIP/104-00000000", "1?Set(CHANNEL(language)=en)") in new stack
    -- Executing [s@sub-set-call-vars:15] Return("PJSIP/104-00000000", "") in new stack
    -- Executing [s@cos-all:5] Gosub("PJSIP/104-00000000", "sub-construct-cid,s,1") in new stack
    -- Executing [s@sub-construct-cid:1] NoOp("PJSIP/104-00000000", "Building CID") in new stack
    -- Executing [s@sub-construct-cid:2] Set("PJSIP/104-00000000", "_CALL_SOURCE=2023010010104") in new stack
    -- Executing [s@sub-construct-cid:3] Set("PJSIP/104-00000000", "_CS=2023010010104") in new stack
    -- Executing [s@sub-construct-cid:4] GotoIf("PJSIP/104-00000000", "1?return") in new stack
    -- Goto (sub-construct-cid,s,11)
    -- Executing [s@sub-construct-cid:11] NoOp("PJSIP/104-00000000", "") in new stack
    -- Executing [s@sub-construct-cid:12] Set("PJSIP/104-00000000", "CDR(source)=2023010010104") in new stack
    -- Executing [s@sub-construct-cid:13] Return("PJSIP/104-00000000", "") in new stack
    -- Executing [s@cos-all:6] Gosub("PJSIP/104-00000000", "set-global-tenant-vars,s,1") in new stack
    -- Executing [s@set-global-tenant-vars:1] NoOp("PJSIP/104-00000000", "Setting Global Vars for vitalpbx Tenant") in new stack
    -- Executing [s@set-global-tenant-vars:2] Set("PJSIP/104-00000000", "__TENANT_PATH=713b0732d7b683af") in new stack
    -- Executing [s@set-global-tenant-vars:3] Set("PJSIP/104-00000000", "__TENANT_PREFIX=") in new stack
    -- Executing [s@set-global-tenant-vars:4] Set("PJSIP/104-00000000", "__QUEUE_AGENTS_CONTEXT=queue-call-to-agents") in new stack
    -- Executing [s@set-global-tenant-vars:5] Set("PJSIP/104-00000000", "__FOLLOWME_CONTEXT=ext-followme") in new stack
    -- Executing [s@set-global-tenant-vars:6] Set("PJSIP/104-00000000", "__HINTS_CONTEXT=extension-hints") in new stack
    -- Executing [s@set-global-tenant-vars:7] Set("PJSIP/104-00000000", "__DEFAULT_COS=cos-all") in new stack
    -- Executing [s@set-global-tenant-vars:8] Return("PJSIP/104-00000000", "") in new stack
    -- Executing [s@cos-all:7] GotoIf("PJSIP/104-00000000", "0?local-dialing") in new stack
    -- Executing [s@cos-all:8] NoOp("PJSIP/104-00000000", "Check if is an Emergency Call") in new stack
    -- Executing [s@cos-all:9] GotoIf("PJSIP/104-00000000", "0?emergency-calls,101,1") in new stack
    -- Executing [s@cos-all:10] Gosub("PJSIP/104-00000000", "sub-lockphone-check,s,1") in new stack
    -- Executing [s@sub-lockphone-check:1] NoOp("PJSIP/104-00000000", "SUB: LOCK PHONE CHECK") in new stack
    -- Executing [s@sub-lockphone-check:2] GotoIf("PJSIP/104-00000000", "0?unlock") in new stack
    -- Executing [s@sub-lockphone-check:3] GotoIf("PJSIP/104-00000000", "0?unlock") in new stack
    -- Executing [s@sub-lockphone-check:4] GotoIf("PJSIP/104-00000000", "0?unlock") in new stack
    -- Executing [s@sub-lockphone-check:5] GotoIf("PJSIP/104-00000000", "0?unlock") in new stack
    -- Executing [s@sub-lockphone-check:6] GotoIf("PJSIP/104-00000000", "0?:unlock") in new stack
    -- Goto (sub-lockphone-check,s,12)
    -- Executing [s@sub-lockphone-check:12] Return("PJSIP/104-00000000", "") in new stack
    -- Executing [s@cos-all:11] Gosub("PJSIP/104-00000000", "sub-local-dialing,s,1") in new stack
    -- Executing [s@sub-local-dialing:1] NoOp("PJSIP/104-00000000", "Trying to determine if is a local extension") in new stack
    -- Executing [s@sub-local-dialing:2] GotoIf("PJSIP/104-00000000", "1?:return") in new stack
    -- Executing [s@sub-local-dialing:3] Set("PJSIP/104-00000000", "EXTENSION_TO_DIAL=101") in new stack
    -- Executing [s@sub-local-dialing:4] Goto("PJSIP/104-00000000", "101,1") in new stack
    -- Goto (sub-local-dialing,101,1)
    -- Executing [101@sub-local-dialing:1] NoOp("PJSIP/104-00000000", "Dialing Local Extension") in new stack
    -- Executing [101@sub-local-dialing:2] ExecIf("PJSIP/104-00000000", "0?NoCDR()") in new stack
    -- Executing [101@sub-local-dialing:3] Gosub("PJSIP/104-00000000", "sub-setup-call-type,s,1(internal)") in new stack
    -- Executing [s@sub-setup-call-type:1] NoOp("PJSIP/104-00000000", "Determinating Call Type") in new stack
    -- Executing [s@sub-setup-call-type:2] GotoIf("PJSIP/104-00000000", "1?return") in new stack
    -- Goto (sub-setup-call-type,s,5)
    -- Executing [s@sub-setup-call-type:5] Set("PJSIP/104-00000000", "CDR(calltype)=1") in new stack
    -- Executing [s@sub-setup-call-type:6] Return("PJSIP/104-00000000", "") in new stack
    -- Executing [101@sub-local-dialing:4] Set("PJSIP/104-00000000", "_DESTINATION_STATE=NOT_INUSE") in new stack
    -- Executing [101@sub-local-dialing:5] Set("PJSIP/104-00000000", "_DESTINATION_NUMBER=101") in new stack
    -- Executing [101@sub-local-dialing:6] Set("PJSIP/104-00000000", "_DESTINATION_COS_NAME=cos-all") in new stack
    -- Executing [101@sub-local-dialing:7] Gosub("PJSIP/104-00000000", "sub-check-cos-privacy,s,1(cos-all,1,cos-all)") in new stack
    -- Executing [s@sub-check-cos-privacy:1] NoOp("PJSIP/104-00000000", "Checking Privacy of CoS: cos-all") in new stack
    -- Executing [s@sub-check-cos-privacy:2] GotoIf("PJSIP/104-00000000", "1?:no_local") in new stack
    -- Executing [s@sub-check-cos-privacy:3] Set("PJSIP/104-00000000", "CALLER_COS_ID=1") in new stack
    -- Executing [s@sub-check-cos-privacy:4] Set("PJSIP/104-00000000", "CALLER_COS_NAME=cos-all") in new stack
    -- Executing [s@sub-check-cos-privacy:5] Set("PJSIP/104-00000000", "CALLED_COS_ID=1") in new stack
    -- Executing [s@sub-check-cos-privacy:6] GotoIf("PJSIP/104-00000000", "1?same_cos") in new stack
    -- Goto (sub-check-cos-privacy,s,17)
    -- Executing [s@sub-check-cos-privacy:17] NoOp("PJSIP/104-00000000", "The caller CoS and Callee CoS are the same") in new stack
    -- Executing [s@sub-check-cos-privacy:18] Goto("PJSIP/104-00000000", "return") in new stack
    -- Goto (sub-check-cos-privacy,s,22)
    -- Executing [s@sub-check-cos-privacy:22] Return("PJSIP/104-00000000", "") in new stack
    -- Executing [101@sub-local-dialing:8] Set("PJSIP/104-00000000", "DIAL_STRING=PJSIP/101&PJSIP/mobile-101") in new stack
    -- Executing [101@sub-local-dialing:9] Set("PJSIP/104-00000000", "DB(713b0732d7b683af/LASTCALLER/101)=2023010010104") in new stack
    -- Executing [101@sub-local-dialing:10] Set("PJSIP/104-00000000", "IGNORE_DIVERSIONS=yes") in new stack
    -- Executing [101@sub-local-dialing:11] Set("PJSIP/104-00000000", "QUEUE_CALL=") in new stack
    -- Executing [101@sub-local-dialing:12] GosubIf("PJSIP/104-00000000", "0?sub-queue-members,s,1") in new stack
    -- Executing [101@sub-local-dialing:13] GosubIf("PJSIP/104-00000000", "1?:sub-check-diversions,s,1(predialing)") in new stack
    -- Executing [101@sub-local-dialing:14] GotoIf("PJSIP/104-00000000", "0?post-dial") in new stack
    -- Executing [101@sub-local-dialing:15] Gosub("PJSIP/104-00000000", "parse-dial-string,s,1") in new stack
    -- Executing [s@parse-dial-string:1] NoOp("PJSIP/104-00000000", "Parsing dial string: PJSIP/101&PJSIP/mobile-101") in new stack
    -- Executing [s@parse-dial-string:2] Set("PJSIP/104-00000000", "NEW_DIAL_STRING=") in new stack
    -- Executing [s@parse-dial-string:3] Set("PJSIP/104-00000000", "COUNTER=1") in new stack
    -- Executing [s@parse-dial-string:4] Set("PJSIP/104-00000000", "CURRENT_DEVICE=PJSIP/101") in new stack
    -- Executing [s@parse-dial-string:5] While("PJSIP/104-00000000", "1") in new stack
    -- Executing [s@parse-dial-string:6] Set("PJSIP/104-00000000", "TECHNOLOGY=PJSIP") in new stack
    -- Executing [s@parse-dial-string:7] Set("PJSIP/104-00000000", "USER=101") in new stack
    -- Executing [s@parse-dial-string:8] GotoIf("PJSIP/104-00000000", "1?:regular") in new stack
    -- Executing [s@parse-dial-string:9] Goto("PJSIP/104-00000000", "regular-pjsip") in new stack
    -- Goto (parse-dial-string,s,12)
    -- Executing [s@parse-dial-string:12] Set("PJSIP/104-00000000", "PARSED_DEV=PJSIP/101/sip:[email protected]:50492;ob") in new stack
    -- Executing [s@parse-dial-string:13] ExecIf("PJSIP/104-00000000", "0?Set(PARSED_DEV=PJSIP/101)") in new stack
    -- Executing [s@parse-dial-string:14] Goto("PJSIP/104-00000000", "append") in new stack
    -- Goto (parse-dial-string,s,16)
    -- Executing [s@parse-dial-string:16] GotoIf("PJSIP/104-00000000", "1?:concatenate") in new stack
    -- Executing [s@parse-dial-string:17] Set("PJSIP/104-00000000", "NEW_DIAL_STRING=PJSIP/101/sip:[email protected]:50492;ob") in new stack
    -- Executing [s@parse-dial-string:18] Goto("PJSIP/104-00000000", "next") in new stack
    -- Goto (parse-dial-string,s,21)
    -- Executing [s@parse-dial-string:21] Set("PJSIP/104-00000000", "COUNTER=2") in new stack
    -- Executing [s@parse-dial-string:22] Set("PJSIP/104-00000000", "CURRENT_DEVICE=PJSIP/mobile-101") in new stack
    -- Executing [s@parse-dial-string:23] EndWhile("PJSIP/104-00000000", "") in new stack
    -- Executing [s@parse-dial-string:5] While("PJSIP/104-00000000", "1") in new stack
    -- Executing [s@parse-dial-string:6] Set("PJSIP/104-00000000", "TECHNOLOGY=PJSIP") in new stack
    -- Executing [s@parse-dial-string:7] Set("PJSIP/104-00000000", "USER=mobile-101") in new stack
    -- Executing [s@parse-dial-string:8] GotoIf("PJSIP/104-00000000", "1?:regular") in new stack
    -- Executing [s@parse-dial-string:9] Goto("PJSIP/104-00000000", "regular-pjsip") in new stack
    -- Goto (parse-dial-string,s,12)
    -- Executing [s@parse-dial-string:12] Set("PJSIP/104-00000000", "PARSED_DEV=") in new stack
    -- Executing [s@parse-dial-string:13] ExecIf("PJSIP/104-00000000", "1?Set(PARSED_DEV=PJSIP/mobile-101)") in new stack
    -- Executing [s@parse-dial-string:14] Goto("PJSIP/104-00000000", "append") in new stack
    -- Goto (parse-dial-string,s,16)
    -- Executing [s@parse-dial-string:16] GotoIf("PJSIP/104-00000000", "0?:concatenate") in new stack
    -- Goto (parse-dial-string,s,19)
    -- Executing [s@parse-dial-string:19] GotoIf("PJSIP/104-00000000", "1?:next") in new stack
    -- Executing [s@parse-dial-string:20] Set("PJSIP/104-00000000", "NEW_DIAL_STRING=PJSIP/101/sip:[email protected]:50492;ob&PJSIP/mobile-101") in new stack
    -- Executing [s@parse-dial-string:21] Set("PJSIP/104-00000000", "COUNTER=3") in new stack
    -- Executing [s@parse-dial-string:22] Set("PJSIP/104-00000000", "CURRENT_DEVICE=") in new stack
    -- Executing [s@parse-dial-string:23] EndWhile("PJSIP/104-00000000", "") in new stack
    -- Executing [s@parse-dial-string:5] While("PJSIP/104-00000000", "0") in new stack
    -- Executing [s@parse-dial-string:24] NoOp("PJSIP/104-00000000", "New dialstring: PJSIP/101/sip:[email protected]:50492;ob&PJSIP/mobile-101") in new stack
    -- Executing [s@parse-dial-string:25] Set("PJSIP/104-00000000", "DIAL_STRING=PJSIP/101/sip:[email protected]:50492;ob&PJSIP/mobile-101") in new stack
    -- Executing [s@parse-dial-string:26] Return("PJSIP/104-00000000", "") in new stack
    -- Executing [101@sub-local-dialing:16] NoOp("PJSIP/104-00000000", "Configuring Dial Settings") in new stack
    -- Executing [101@sub-local-dialing:17] Set("PJSIP/104-00000000", "RING_TIME=5") in new stack
    -- Executing [101@sub-local-dialing:18] Set("PJSIP/104-00000000", "RING_TIME=5") in new stack
    -- Executing [101@sub-local-dialing:19] Set("PJSIP/104-00000000", "RING_TIME=5") in new stack
    -- Executing [101@sub-local-dialing:20] Set("PJSIP/104-00000000", "DIAL_OPTIONS=kKtrQ(ANSWERED_ELSEWHERE)") in new stack
    -- Executing [101@sub-local-dialing:21] Set("PJSIP/104-00000000", "DIAL_OPTIONS=kKtrQ(ANSWERED_ELSEWHERE)") in new stack
    -- Executing [101@sub-local-dialing:22] GotoIf("PJSIP/104-00000000", "0?:answermode") in new stack
    -- Goto (sub-local-dialing,101,26)
    -- Executing [101@sub-local-dialing:26] Set("PJSIP/104-00000000", "ANSWER_MODE=disable") in new stack
    -- Executing [101@sub-local-dialing:27] Set("PJSIP/104-00000000", "ANSWER_MODE=disable") in new stack
    -- Executing [101@sub-local-dialing:28] GotoIf("PJSIP/104-00000000", "0?check-hd") in new stack
    -- Executing [101@sub-local-dialing:29] ExecIf("PJSIP/104-00000000", "0?Set(EXEC_AA=yes)") in new stack
    -- Executing [101@sub-local-dialing:30] ExecIf("PJSIP/104-00000000", "0?Set(EXEC_AA=yes)") in new stack
    -- Executing [101@sub-local-dialing:31] Set("PJSIP/104-00000000", "IS_HOT_DESK=no") in new stack
    -- Executing [101@sub-local-dialing:32] Set("PJSIP/104-00000000", "MOH_CLASS=moh5") in new stack
    -- Executing [101@sub-local-dialing:33] GosubIf("PJSIP/104-00000000", "0?sub-set-moh,s,1(moh5)") in new stack
    -- Executing [101@sub-local-dialing:34] GotoIf("PJSIP/104-00000000", "0?busy-here") in new stack
    -- Executing [101@sub-local-dialing:35] Set("PJSIP/104-00000000", "FORCE_RECORDING=no") in new stack
    -- Executing [101@sub-local-dialing:36] Set("PJSIP/104-00000000", "DIAL_OPTIONS=kKtrQ(ANSWERED_ELSEWHERE)b(before-connecting-call^s^1(713b0732d7b683af^2023010010104^101^^))") in new stack
    -- Executing [101@sub-local-dialing:37] Set("PJSIP/104-00000000", "DIAL_OPTIONS=kKtrQ(ANSWERED_ELSEWHERE)b(before-connecting-call^s^1(713b0732d7b683af^2023010010104^101^^))U(sub-call-recording^713b0732d7b683af^2023010010104^101^no)") in new stack
    -- Executing [101@sub-local-dialing:38] Set("PJSIP/104-00000000", "__TRANSFERED_CALL=TRUE") in new stack
    -- Executing [101@sub-local-dialing:39] NoOp("PJSIP/104-00000000", "Enable Follow-Me Ring Time If needed") in new stack
    -- Executing [101@sub-local-dialing:40] GotoIf("PJSIP/104-00000000", "0?:check-rt") in new stack
    -- Goto (sub-local-dialing,101,47)
    -- Executing [101@sub-local-dialing:47] GotoIf("PJSIP/104-00000000", "0?post-dial") in new stack
    -- Executing [101@sub-local-dialing:48] GotoIf("PJSIP/104-00000000", "0?end_call") in new stack
    -- Executing [101@sub-local-dialing:49] Gosub("PJSIP/104-00000000", "sub-udpate-virtual-dev-state,s,1(101,BUSY)") in new stack
    -- Executing [s@sub-udpate-virtual-dev-state:1] NoOp("PJSIP/104-00000000", "Update Virtual Devices State") in new stack
    -- Executing [s@sub-udpate-virtual-dev-state:2] Set("PJSIP/104-00000000", "EXT_NUM=101") in new stack
    -- Executing [s@sub-udpate-virtual-dev-state:3] Set("PJSIP/104-00000000", "NEW_STATUS=BUSY") in new stack
    -- Executing [s@sub-udpate-virtual-dev-state:4] Set("PJSIP/104-00000000", "EXTENSION_ID=288") in new stack
       > Found no rows [SELECT `device_id` FROM ombu_devices WHERE extension_id='288' and technology='virtual' and tenant_id=(SELECT tenant_id from ombu_tenants WHERE path='713b0732d7b683af')]
    -- Executing [s@sub-udpate-virtual-dev-state:5] Set("PJSIP/104-00000000", "ODBC_ID=") in new stack
    -- Executing [s@sub-udpate-virtual-dev-state:6] GotoIf("PJSIP/104-00000000", "1?no_rows") in new stack
    -- Goto (sub-udpate-virtual-dev-state,s,14)
    -- Executing [s@sub-udpate-virtual-dev-state:14] Return("PJSIP/104-00000000", "") in new stack
    -- Executing [101@sub-local-dialing:50] Dial("PJSIP/104-00000000", "PJSIP/101/sip:[email protected]:50492;ob&PJSIP/mobile-101,5,kKtrQ(ANSWERED_ELSEWHERE)b(before-connecting-call^s^1(713b0732d7b683af^2023010010104^101^^))U(sub-call-recording^713b0732d7b683af^2023010010104^101^no)") in new stack
[2022-04-06 02:05:03] ERROR[2173]: res_pjsip.c:4096 ast_sip_create_dialog_uac: Endpoint 'mobile-101': Could not create dialog to invalid URI 'mobile-101'.  Is endpoint registered and reachable?
[2022-04-06 02:05:03] ERROR[2173]: chan_pjsip.c:2657 request: Failed to create outgoing session to endpoint 'mobile-101'
[2022-04-06 02:05:03] WARNING[8342][C-00000001]: app_dial.c:2663 dial_exec_full: Unable to create channel of type 'PJSIP' (cause 3 - No route to destination)
    -- PJSIP/101-00000002 Internal Gosub(before-connecting-call,s,1(713b0732d7b683af,2023010010104,101,,)) start
    -- Executing [s@before-connecting-call:1] NoOp("PJSIP/101-00000002", "Executing routines in the newly created channel before initiaing the call") in new stack
    -- Executing [s@before-connecting-call:2] Set("PJSIP/101-00000002", "TENANT=713b0732d7b683af") in new stack
    -- Executing [s@before-connecting-call:3] Set("PJSIP/101-00000002", "CALLER=2023010010104") in new stack
    -- Executing [s@before-connecting-call:4] Set("PJSIP/101-00000002", "CALLEE=101") in new stack
    -- Executing [s@before-connecting-call:5] Set("PJSIP/101-00000002", "EXEC_AA=") in new stack
    -- Executing [s@before-connecting-call:6] Set("PJSIP/101-00000002", "CUSTOM_ALERT_INFO=") in new stack
    -- Executing [s@before-connecting-call:7] Set("PJSIP/101-00000002", "APP_TYPE=NONE") in new stack
    -- Executing [s@before-connecting-call:8] GosubIf("PJSIP/101-00000002", "0?sub-auto-answer,s,1") in new stack
    -- Executing [s@before-connecting-call:9] GosubIf("PJSIP/101-00000002", "0?sub-set-custom-header,s,1(Alert-Info,)") in new stack
    -- Executing [s@before-connecting-call:10] GosubIf("PJSIP/101-00000002", "0?sub-set-custom-header,s,1(Call-Info,)") in new stack
    -- Executing [s@before-connecting-call:11] Gosub("PJSIP/101-00000002", "sub-set-custom-header,s,1(CALL-TYPE,LOCAL)") in new stack
    -- Executing [s@sub-set-custom-header:1] NoOp("PJSIP/101-00000002", "Setting up custom header") in new stack
    -- Executing [s@sub-set-custom-header:2] GotoIf("PJSIP/101-00000002", "0?set-sip") in new stack
    -- Executing [s@sub-set-custom-header:3] NoOp("PJSIP/101-00000002", "Add PJSIP Headers") in new stack
    -- Executing [s@sub-set-custom-header:4] Set("PJSIP/101-00000002", "PJSIP_HEADER(add,CALL-TYPE)=LOCAL") in new stack
    -- Executing [s@sub-set-custom-header:5] Goto("PJSIP/101-00000002", "end") in new stack
    -- Goto (sub-set-custom-header,s,8)
    -- Executing [s@sub-set-custom-header:8] Return("PJSIP/101-00000002", "") in new stack
    -- Executing [s@before-connecting-call:12] Gosub("PJSIP/101-00000002", "sub-set-custom-header,s,1(APPLICATION,NONE)") in new stack
    -- Executing [s@sub-set-custom-header:1] NoOp("PJSIP/101-00000002", "Setting up custom header") in new stack
    -- Executing [s@sub-set-custom-header:2] GotoIf("PJSIP/101-00000002", "0?set-sip") in new stack
    -- Executing [s@sub-set-custom-header:3] NoOp("PJSIP/101-00000002", "Add PJSIP Headers") in new stack
    -- Executing [s@sub-set-custom-header:4] Set("PJSIP/101-00000002", "PJSIP_HEADER(add,APPLICATION)=NONE") in new stack
    -- Executing [s@sub-set-custom-header:5] Goto("PJSIP/101-00000002", "end") in new stack
    -- Goto (sub-set-custom-header,s,8)
    -- Executing [s@sub-set-custom-header:8] Return("PJSIP/101-00000002", "") in new stack
    -- Executing [s@before-connecting-call:13] GosubIf("PJSIP/101-00000002", "0?sub-set-custom-header,s,1(QUEUE-NAME,)") in new stack
    -- Executing [s@before-connecting-call:14] GosubIf("PJSIP/101-00000002", "0?before-connecting-call-hook,s,1") in new stack
    -- Executing [s@before-connecting-call:15] Return("PJSIP/101-00000002", "") in new stack
  == Spawn extension (cos-all, 101, 1) exited non-zero on 'PJSIP/101-00000002'
    -- PJSIP/101-00000002 Internal Gosub(before-connecting-call,s,1(713b0732d7b683af,2023010010104,101,,)) complete GOSUB_RETVAL=
    -- Called PJSIP/101/sip:[email protected]:50492;ob
    -- PJSIP/101-00000002 is ringing
    -- Nobody picked up in 5000 ms
    -- Executing [101@sub-local-dialing:51] Set("PJSIP/104-00000000", "_CALL_STATUS=NOANSWER") in new stack
    -- Executing [101@sub-local-dialing:52] Set("PJSIP/104-00000000", "_CALL_STATUS=NOANSWER") in new stack
    -- Executing [101@sub-local-dialing:53] Gosub("PJSIP/104-00000000", "sub-udpate-virtual-dev-state,s,1(101,NOT_INUSE)") in new stack
    -- Executing [s@sub-udpate-virtual-dev-state:1] NoOp("PJSIP/104-00000000", "Update Virtual Devices State") in new stack
    -- Executing [s@sub-udpate-virtual-dev-state:2] Set("PJSIP/104-00000000", "EXT_NUM=101") in new stack
    -- Executing [s@sub-udpate-virtual-dev-state:3] Set("PJSIP/104-00000000", "NEW_STATUS=NOT_INUSE") in new stack
    -- Executing [s@sub-udpate-virtual-dev-state:4] Set("PJSIP/104-00000000", "EXTENSION_ID=288") in new stack
       > Found no rows [SELECT `device_id` FROM ombu_devices WHERE extension_id='288' and technology='virtual' and tenant_id=(SELECT tenant_id from ombu_tenants WHERE path='713b0732d7b683af')]
    -- Executing [s@sub-udpate-virtual-dev-state:5] Set("PJSIP/104-00000000", "ODBC_ID=") in new stack
    -- Executing [s@sub-udpate-virtual-dev-state:6] GotoIf("PJSIP/104-00000000", "1?no_rows") in new stack
    -- Goto (sub-udpate-virtual-dev-state,s,14)
    -- Executing [s@sub-udpate-virtual-dev-state:14] Return("PJSIP/104-00000000", "") in new stack
    -- Executing [101@sub-local-dialing:54] Goto("PJSIP/104-00000000", "check-post-diversions") in new stack
    -- Goto (sub-local-dialing,101,56)
    -- Executing [101@sub-local-dialing:56] GosubIf("PJSIP/104-00000000", "1?:sub-check-diversions,s,1(postdialing)") in new stack
    -- Executing [101@sub-local-dialing:57] GotoIf("PJSIP/104-00000000", "0?end_call") in new stack
    -- Executing [101@sub-local-dialing:58] GotoIf("PJSIP/104-00000000", "0?end_call") in new stack
    -- Executing [101@sub-local-dialing:59] GotoIf("PJSIP/104-00000000", "0?end_call") in new stack
    -- Executing [101@sub-local-dialing:60] Gosub("PJSIP/104-00000000", "sub-leave-vm,s,1") in new stack
    -- Executing [s@sub-leave-vm:1] NoOp("PJSIP/104-00000000", "Leave Voicemail") in new stack
    -- Executing [s@sub-leave-vm:2] Set("PJSIP/104-00000000", "VM_OPTIONS=u") in new stack
    -- Executing [s@sub-leave-vm:3] Set("PJSIP/104-00000000", "VM_OPTIONS=u") in new stack
    -- Executing [s@sub-leave-vm:4] GotoIf("PJSIP/104-00000000", "1?:vm_disabled") in new stack
    -- Executing [s@sub-leave-vm:5] Set("PJSIP/104-00000000", "MAILBOX=101@vitalpbx-voicemail") in new stack
    -- Executing [s@sub-leave-vm:6] Answer("PJSIP/104-00000000", "") in new stack
    -- Executing [s@sub-leave-vm:7] Gosub("PJSIP/104-00000000", "sub-vm,s,1(101@vitalpbx-voicemail,u)") in new stack
    -- Executing [s@sub-vm:1] NoOp("PJSIP/104-00000000", "Leave a Voicemail") in new stack
    -- Executing [s@sub-vm:2] VoiceMail("PJSIP/104-00000000", "101@vitalpbx-voicemail,u") in new stack
    -- <PJSIP/104-00000000> Playing '/var/spool/asterisk/voicemail/vitalpbx-voicemail/101/unavail.slin' (language 'en')
    -- <PJSIP/104-00000000> Playing 'vm-intro.ulaw' (language 'en')
    -- <PJSIP/104-00000000> Playing 'beep.ulaw' (language 'en')
    -- Recording the message
    -- x=0, open writing:  /var/spool/asterisk/voicemail/vitalpbx-voicemail/101/tmp/MvoBvN format: wav, 0x7fd2d800c360
    -- User hung up
  == Spawn extension (sub-vm, s, 2) exited non-zero on 'PJSIP/104-00000000'

PitzKey · April 13, 2022, 1:03pm

Just tested this on a 3.1.7-1 system.

It does not return the call to the originator, nor to the timeout destination. The call simply gets lost.

The value of this is empty:

[2022-04-13 08:07:41] VERBOSE[47043][C-00000559] pbx.c: Executing [s@parking-5-callback:2] Set("PJSIP/SIPProvider-00000bfc", "CALLBACK_EXT=") in new stack

Log of the parking and failed to return: https://pastebin.com/iRw90mJY (Raw version)
Full log: https://pastebin.com/bBYKRsrL (Raw version)

Parking lot in the GUI:

Asterisk config:

[root@lab1 ~]# asterisk -x"parking show parking-5"

Parking Lot: parking-5
--------------------------------------------------------------------------
Parking Extension   :  725
Parking Context     :  parking-5-parkedcalls
Parking Spaces      :  726-727
Parking Time        :  20 sec
Comeback to Origin  :  no
Comeback Context    :  parking-5-callback
Comeback Dial Time  :  5 sec
MusicOnHold Class   :  default
Enabled             :  yes
Dynamic             :  no

Parked Calls
------------
  (none)


[root@lab1 ~]# cat res_parking__50-1-extensions.conf
[parking-5]
parkext=>725
context=>parking-5-parkedcalls
comebackcontext=parking-5-callback
courtesytone=beep
parkpos=>726-727
parkedmusicclass=default
parkingtime=>20
comebackdialtime=5
parkedplay=caller
parkedcalltransfers=both
parkedcallreparking=both
parkedcallhangup=both
findslot=>next
comebacktoorigin=no
parkext_exclusive=yes

[root@lab1 ~]# cat extensions__50-1-dialplan.conf
exten => _726,1,NoOp(Slot: ${CALL_DESTINATION})
 same => n,Set(RECORD_PARKING_LOT=no)
 same => n,Gosub(sub-parking-lots,s,1(${CALL_DESTINATION},parking-5,parking-5-parkedcalls))

Please advise

EINM · April 13, 2022, 2:40pm

The CALLBACK_EXT is populated from the DESTINATION_NUMBER variable, which is only set on calls to a local extension, in the sub-local-dialing context, so it will currently only work on internal or incoming calls, not on outgoing calls.

The solution is probably to modify the dialplan as below

 same => n,Set(CALLBACK_EXT=${IF($["${CALL_TYPE}"="3"]?${CALLER}:${DESTINATION_NUMBER})})

miguel · April 13, 2022, 3:42pm

I would like to know the steps to reproduce this issue.

On the other hand, the call only goes to the Timeout Destination if the parameter “Return to Originator” is set to “No.”

PitzKey · April 13, 2022, 3:46pm

Place an outgoing call
Blind transfer the call to a parking slot (eg 702)
Wait for the call to drop

Right, but if the call fails to return to the originator, then it should go to the timeout destination. I can’t think of a reason it shouldn’t be that way.