More info on "Callers randomly being put on hold, callee drops"

Related to this:

Every office has their own block of 4-digit extensions.
For example, everything in the Seattle office would be in the format 25XX. Everything in Portland, OR would be 26XX.

Based on that format, ring groups are XX00 and XX01 and the parking lot is XX50 with slots from XX51 to XX55.

All the lots are set as “private” (including the default lot) and all phones are assigned to their appropriate lot. For example, Extension 25XX is assigned to the private 2550 lot.

To try and mitigate this problem and do further testing, I removed the parking app from their phones and told them they now need to park calls by dialing *2 (attended transfer) and then 2550. They hear the parking slot number and then can hang up.

While they complained that it was “too complex”, I asked them to suffer through it for a week in order to see what would happen.

Here’s what happened:

  • Even though all lots are private and all phones have been assigned to a specific parking lot, calls get parked into the default lot (70) and get assigned a slot (usually 71) when they should be assigned 2551. Seems like a bug.

  • The office was suffering from the “random parking” issue “at least 10 times per day”. Over the last week, they’ve had exactly zero calls randomly park and looking at the logs they parked a similar number of calls using the star code as opposed to previously using the parking phone app.

I think it’s clear there’s a bug in Digium/Sangoma’s code, and while this has been posted about several times (not just be me), Digium/Sangoma doesn’t seem to be paying attention or they just might not care.

If someone from Sangoma/Digium wants to look into this, I have a good chunk of testing data and a fairly good idea of where the issue lies.

If not, I’ll just be sitting here continuing working on a set of SaltStack automations that cover all my client use-cases along with one of our devs who is currently writing a set of PhoneApps to replace the paid-for EPM apps.

You need to provide actual debugs that show this from the start and everything involved. Not a snippet of this one part of the call or something that shows half of what is happening. Not a single one of your posted debugs in other threads was a full call or showed what you described. I don’t even see a transfer happening in a call you said was transferred.

I have provided logs in previous posts.

In this report, I provided the most detailed debugging info possible:

Additionally, I provided info that the work-around (parking the call using *2 XXXX) causes the issue to disappear entirely. This pretty well isolates the problem to Digium/Sangoma’s proprietary code.

The phones don’t provide a lot of debugging info to tell why the issue is occurring, and honestly…it’s not realistic to expect anyone to debug their proprietary code.

I know but as I started you have posted incomplete debugs and snippets of output. In the one example that you said a call was transferred, as I previously said, nothing in the debug showed the transfer of the call or the call on the transferred channel.

The debug needs to be from the start to the finish and have everything in between. So if the agent parks the call in their private lot and then transfers said call, I should see that call be parked, that call get transferred and then see what happens with the transferred destination/channel.

The logs aren’t the entire call. It doesn’t include the session setup, them hearing the IVR and pressing 1 or 2. It starts just after that when it gets transferred to the ring group.

The rest of the log is complete (with a few private details replaced with ‘REDACTED’ and interspersed with the logs from the D60 itself from my syslog server.

So if the agent parks the call in their private lot and then transfers said call, I should see that call be parked

I mean…I posted it in the previous message:

# ext 4402 parks the caller:
[2022-09-14 11:33:51] VERBOSE[24619][C-00006628] bridge_channel.c: Channel PJSIP/Twilio-00014d03 left 'simple_bridge' basic-bridge <babb54f0-11a2-443f-ba89-28fab0f2423b>
[2022-09-14 11:33:51] VERBOSE[24619][C-00006628] parking/parking_bridge.c: Parking 'PJSIP/Twilio-00014d03' in 'parkinglot_34' at space 4451
[2022-09-14 11:33:51] VERBOSE[24619][C-00006628] bridge_channel.c: Channel PJSIP/Twilio-00014d03 joined 'holding_bridge' parking-bridge <7f445761-ff5a-4b86-96ad-6b5773c773e1>
[2022-09-14 11:33:51] VERBOSE[24619][C-00006628] res_musiconhold.c: Started music on hold, class 'default', on channel 'PJSIP/Twilio-00014d03'
[2022-09-14 11:33:51] VERBOSE[25799][C-00006628] file.c: <PJSIP/4402-00014d04> Playing 'digits/4.ulaw' (language 'en')
[2022-09-14 11:33:51] VERBOSE[25799][C-00006628] file.c: <PJSIP/4402-00014d04> Playing 'digits/4.ulaw' (language 'en')
[2022-09-14 11:33:51] VERBOSE[25799][C-00006628] file.c: <PJSIP/4402-00014d04> Playing 'digits/5.ulaw' (language 'en')
[2022-09-14 11:33:51] VERBOSE[25799][C-00006628] file.c: <PJSIP/4402-00014d04> Playing 'digits/1.ulaw' (language 'en')
[2022-09-14 11:33:51] VERBOSE[25799][C-00006628] bridge_channel.c: Channel PJSIP/4402-00014d04 left 'simple_bridge' basic-bridge <babb54f0-11a2-443f-ba89-28fab0f2423b>

# corresponding debug logs from ext 4402 during parking:
Sep 14 18:33:22 192.168.142.102 phone:  Unknown state in update_call(): call_status.CONNECTING.1.5247-46."REDACTED-CALLER-NAME" <sip:[email protected]\.ne\.svr\.ip>.<sip:[email protected]\.ne\.srv\.ip:5060>.200.OK.active.role.callee.local_info.<sip:[email protected]\.use\.r\.ip;ob
Sep 14 18:33:50 192.168.142.102 xyz:  KEY 99-[ c ] 1
Sep 14 18:33:50 192.168.142.102 xyz:  AppScreen::redraw()
Sep 14 18:33:50 192.168.142.102 ae:  app parking_freepbx shown.
Sep 14 18:33:50 192.168.142.102 ae:  cURL::init Method GET Url https://voice.customer.tld:3443/applications.php/parking/main?user=4402&linestate=CONNECTED SSL Secure
Sep 14 18:33:50 192.168.142.102 xyz:  KEY 99-[ c ] 0
Sep 14 18:33:51 192.168.142.102 ae:  parking_freepbx: Showing page of type action.
Sep 14 18:33:51 192.168.142.102 ae:  hiding apps per dbus request.
Sep 14 18:33:51 192.168.142.102 ae:  hiding app contacts show failed.
Sep 14 18:33:51 192.168.142.102 ae:  hiding app appscreen show failed.
Sep 14 18:33:51 192.168.142.102 ae:  hiding app phonemenu show failed.
Sep 14 18:33:51 192.168.142.102 ae:  hiding app parking_freepbx show failed.
Sep 14 18:33:51 192.168.142.102 ae:  hiding app contactmanager_freepbx show failed.
Sep 14 18:33:51 192.168.142.102 ae:  hiding app donotdisturb_freepbx show failed.
Sep 14 18:33:52 192.168.142.102 core[5247]:  callbridge: 12:33:52.233 src/broadcom_p  .....pjsua_check_snd_dev_idle no-op 
Sep 14 18:33:52 192.168.142.102 core[5247]:  callbridge: 12:33:52.240    src/state.c  .......validate_call_state: Error getting call info for call_id 25
Sep 14 18:33:52 192.168.142.102 ae:  parking_freepbx: builtin_callapi.js:65: TypeError: undefined is not a function
Sep 14 18:33:52 192.168.142.102 ae:  parking_freepbx:             handler(msg) ;
Sep 14 18:33:52 192.168.142.102 ae:  parking_freepbx:  
Sep 14 18:33:52 192.168.142.102 ae:  parking_freepbx:  
Sep 14 18:33:52 192.168.142.102 ae:  parking_freepbx:  
Sep 14 18:33:52 192.168.142.102 ae:  parking_freepbx:  
Sep 14 18:33:52 192.168.142.102 ae:  parking_freepbx:  
Sep 14 18:33:52 192.168.142.102 ae:  parking_freepbx:  
Sep 14 18:33:52 192.168.142.102 ae:  parking_freepbx:  
Sep 14 18:33:52 192.168.142.102 ae:  parking_freepbx:  
Sep 14 18:33:52 192.168.142.102 core[5247]:  callbridge: 12:33:52.298    src/state.c  .......validate_call_state: Error getting call info for call_id 25
Sep 14 18:33:52 192.168.142.102 ae:  parking_freepbx:  
Sep 14 18:33:52 192.168.142.102 ae:  parking_freepbx:  
Sep 14 18:33:52 192.168.142.102 ae:  parking_freepbx:  
Sep 14 18:33:52 192.168.142.102 ae:  parking_freepbx:  
Sep 14 18:33:52 192.168.142.102 ae:  parking_freepbx: ^
Sep 14 18:33:52 192.168.142.102 ae:  parking_freepbx: TypeError: undefined is not a function#012    at CALL_NON_FUNCTION (native)#012    at builtin_callapi.js:65:13#012    at Array.forEach (native)#012    at Object.<anonymous> (builtin_callapi.js:64:25)#012    at handle_handled_call
# ext 4402 starts making an outbound call:
Sep 14 18:33:52 192.168.142.102 xyz:  KEY 75-[ K ] 1
Sep 14 18:34:53 192.168.142.102 xyz:  KEY 52-[ 4 ] 1
Sep 14 18:34:53 192.168.142.102 xyz:  KEY 52-[ 4 ] 0

It shows everything logged on both the phone server and the D60’s syslog, and it looks like the call being parked.

Maybe you’re confusing one of the numerous reports from users I posted about with the complete log data I was able to gather from one particular incident? If I recall correctly, that particular incident didn’t have a transfer involved–just a call that came in, was parked, then unparked, and then it started randomly parking users.

I guess I’m just seeing a call parked. Was that supposed to happen?

Also, why are you using *2 / attended transfers for parking? That might be your issue right there. You should be using a blind transfer to send calls to a parking lot. Because when you use attended transfer you have the final step to actually transfer the channel properly. Here’s what happens:

  1. Press *2 – this is put the active call on hold and want digits to transfer to.
  2. 2551 is called, the lot answers
  3. User now needs to completely the transfer with a # to finish the call. They can’t just hang up at this point, call is answered and that’s not how an attended transfer will complete at that point.

Have you tried this with using a blind transfer? This seems to have been a solution for others on here with parking and doing via attended transfers that caused issues.

I guess you haven’t read the issues I linked.

When using the Digium Parking App on the D60 phones, we frequently have calls that randomly go “back on park”. i.e. someone in our office picks up a parked call and starts talking to the caller and mid-sentence the call disconnects and the caller finds themselves back on hold. If the office hits the park button again, they see the caller is back in the parking lot. They tap on the caller and re-answer the call, talk for a few seconds, then it drops again. This cycle can repeat itself as few as one or two time, or as many as 8 times during a call.

When removing the park button from their D60 phones and forcing them to manually transfer calls to the parking lot using *2 XXXX, and then they later pick up by dialing the extension that was read back to them during the manual parking, they never have calls magically re-park themselves.

When using the Digium parking app, calls will randomly re-park themselves mid-sentence.
When using *2 to manually transfer calls into parking lots, calls never randomly re-park themselves.

At my company we’re using Zulu (and Zulu has issues with transferring and merging calls and has no ‘attended transfer’ button only blind transfer), so everyone at my company uses *2 50 (then hang up) to transfer to our default lot (we only have one lot) and 51 (or 52 or whatever) to pick up the parked call. We don’t need to hit pound to complete the transfer, just hang up. Same with the customer I’m talking about.

But the customer I’m talking about doesn’t use star codes because…well…it’s difficult for them (being non-technical) to remember the *2 code and figure out which office they’re in and what the parking extension is…so they use the park app on the D60. That’s what’s having problems. That’s was causes the random, uncommanded re-parking of calls. I’m pretty sure the bug is in the parking app itself, NOT the Asterisk/FreePBX side of the equation.

There is a side bug that I noticed when I told one office to start using *2 2550 to park calls. The system reads back that the pick-up number is ‘71’ (the default lot) even though the extension is assigned to the 2550 parking lot, but that shouldn’t have anything to do with the park button causing random uncommanded re-parking of calls.