Incoming call to ring group randomly goes to voicemail

We have Grandstream GXP 2140 phones.

A Ringgroup for ‘0’

On random occasions when a call comes through on that ring group, both phones ring (as expected), one person lifts their handset but the call isn’t there, and the call continues to ring the other phone. Eventually the call goes to voicemail.

The CDR report shows the call was not answered.

Phone 1 call history shows the call was answered.
Phone 2 call history shows the call was missed.

This is happening on two different FreePBX servers - at two different locations.
Both locations use GXP 2140 phones - using recent (not latest) firmware

Have I misconfigured something?

Thanks in advance,
Jason

https://wiki.freepbx.org/display/SUP/Providing+Great+Debug#ProvidingGreatDebug-AsteriskLogs-PartII

Thanks for the link. It was helpful to find the details in the current log.

I was able to pull out the details of the specific call. All looks normal. These lines are relevant and indicate no phone answered - yet the phone’s call history indicates otherwise.

[2020-03-02 12:49:48] VERBOSE[25163][C-000024de] app_dial.c: PJSIP/1601-00002e06 connected line has changed. Saving it until answer for DAHDI/1-1
[2020-03-02 12:49:48] VERBOSE[25163][C-000024de] app_dial.c: PJSIP/1600-00002e05 connected line has changed. Saving it until answer for DAHDI/1-1
[2020-03-02 12:49:48] VERBOSE[25163][C-000024de] app_dial.c: PJSIP/1600-00002e05 is ringing
[2020-03-02 12:49:48] VERBOSE[25163][C-000024de] app_dial.c: PJSIP/1600-00002e05 is ringing
[2020-03-02 12:49:48] VERBOSE[25163][C-000024de] app_dial.c: PJSIP/1601-00002e06 is ringing
[2020-03-02 12:49:48] VERBOSE[25163][C-000024de] app_dial.c: PJSIP/1601-00002e06 is ringing
[2020-03-02 12:50:08] VERBOSE[25163][C-000024de] app_dial.c: Nobody picked up in 20000 ms

Sadly, I wasn’t able to push the full log into into pastebin because there’s some problem. The pastebin server is responding with “The requestedURL could not be retrieved.” but that’s a separate issue.

So it rang your ring group for 20 seconds and then stopped. That is a normal default.
You didn’t post where the call went next.
The ring group has a failover destination that you had to specify. What is it, and did the call go there?

Well, the issue is that within the 20-second period somebody did answer the phone. I have an eye witness and the call history on the phone indicates the call was answered.

It’s as if the phone is not telling freepbx the call was answered.

Or that freepbx didn’t get the message, or ignored the message.

The call ended up going to voicemail - which is how it’s programmed for when nobody answers. That part worked OK.

[2020-03-02 12:50:08] VERBOSE[25163][C-000024de] app_dial.c: Nobody picked up in 20000 ms
[2020-03-02 12:50:08] VERBOSE[25163][C-000024de] app_stack.c: PJSIP/1600-00002e05 Internal Gosub(crm-hangup,s,1) start
[2020-03-02 12:50:08] VERBOSE[25163][C-000024de] pbx.c: Executing [s@crm-hangup:1] NoOp("PJSIP/1600-00002e05", "Sending Hangup to CRM") in new stack
[2020-03-02 12:50:08] VERBOSE[25163][C-000024de] pbx.c: Executing [s@crm-hangup:2] NoOp("PJSIP/1600-00002e05", "HANGUP CAUSE: 0") in new stack
[2020-03-02 12:50:08] VERBOSE[25163][C-000024de] pbx.c: Executing [s@crm-hangup:3] ExecIf("PJSIP/1600-00002e05", "0?Set(__CRM_VOICEMAIL=)") in new stack
[2020-03-02 12:50:08] VERBOSE[25163][C-000024de] pbx.c: Executing [s@crm-hangup:4] NoOp("PJSIP/1600-00002e05", "MASTER CHANNEL: 1583171388.18452 = 1583171354.18451") in new stack
[2020-03-02 12:50:08] VERBOSE[25163][C-000024de] pbx.c: Executing [s@crm-hangup:5] GotoIf("PJSIP/1600-00002e05", "1?return") in new stack
[2020-03-02 12:50:08] VERBOSE[25163][C-000024de] pbx_builtins.c: Goto (crm-hangup,s,8)
[2020-03-02 12:50:08] VERBOSE[25163][C-000024de] pbx.c: Executing [s@crm-hangup:8] Return("PJSIP/1600-00002e05", "") in new stack
[2020-03-02 12:50:08] VERBOSE[25163][C-000024de] app_stack.c: Spawn extension (from-internal, 0, 1) exited non-zero on 'PJSIP/1600-00002e05'
[2020-03-02 12:50:08] VERBOSE[25163][C-000024de] app_stack.c: PJSIP/1600-00002e05 Internal Gosub(crm-hangup,s,1) complete GOSUB_RETVAL=
[2020-03-02 12:50:08] VERBOSE[25163][C-000024de] app_stack.c: PJSIP/1601-00002e06 Internal Gosub(crm-hangup,s,1) start
[2020-03-02 12:50:08] VERBOSE[25163][C-000024de] pbx.c: Executing [s@crm-hangup:1] NoOp("PJSIP/1601-00002e06", "Sending Hangup to CRM") in new stack
[2020-03-02 12:50:08] VERBOSE[25163][C-000024de] pbx.c: Executing [s@crm-hangup:2] NoOp("PJSIP/1601-00002e06", "HANGUP CAUSE: 0") in new stack
[2020-03-02 12:50:08] VERBOSE[25163][C-000024de] pbx.c: Executing [s@crm-hangup:3] ExecIf("PJSIP/1601-00002e06", "0?Set(__CRM_VOICEMAIL=)") in new stack
[2020-03-02 12:50:08] VERBOSE[25163][C-000024de] pbx.c: Executing [s@crm-hangup:4] NoOp("PJSIP/1601-00002e06", "MASTER CHANNEL: 1583171388.18453 = 1583171354.18451") in new stack
[2020-03-02 12:50:08] VERBOSE[25163][C-000024de] pbx.c: Executing [s@crm-hangup:5] GotoIf("PJSIP/1601-00002e06", "1?return") in new stack
[2020-03-02 12:50:08] VERBOSE[25163][C-000024de] pbx_builtins.c: Goto (crm-hangup,s,8)
[2020-03-02 12:50:08] VERBOSE[25163][C-000024de] pbx.c: Executing [s@crm-hangup:8] Return("PJSIP/1601-00002e06", "") in new stack
[2020-03-02 12:50:08] VERBOSE[25163][C-000024de] app_stack.c: Spawn extension (from-internal, 0, 1) exited non-zero on 'PJSIP/1601-00002e06'
[2020-03-02 12:50:08] VERBOSE[25163][C-000024de] app_stack.c: PJSIP/1601-00002e06 Internal Gosub(crm-hangup,s,1) complete GOSUB_RETVAL=
[2020-03-02 12:50:08] VERBOSE[25163][C-000024de] pbx.c: Executing [s@macro-dial:24] Set("DAHDI/1-1", "DIALSTATUS=NOANSWER") in new stack
[2020-03-02 12:50:08] VERBOSE[25163][C-000024de] pbx.c: Executing [s@macro-dial:25] GosubIf("DAHDI/1-1", "0?NOANSWER,1()") in new stack
[2020-03-02 12:50:08] VERBOSE[25163][C-000024de] pbx.c: Executing [s@macro-dial:26] NoOp("DAHDI/1-1", "Returning since nobody answered") in new stack
[2020-03-02 12:50:08] VERBOSE[25163][C-000024de] pbx.c: Executing [s@macro-dial:27] MacroExit("DAHDI/1-1", "") in new stack
[2020-03-02 12:50:08] VERBOSE[25163][C-000024de] pbx.c: Executing [0@ext-group:19] Gosub("DAHDI/1-1", "sub-record-cancel,s,1()") in new stack
[2020-03-02 12:50:08] VERBOSE[25163][C-000024de] pbx.c: Executing [s@sub-record-cancel:1] Return("DAHDI/1-1", "") in new stack
[2020-03-02 12:50:08] VERBOSE[25163][C-000024de] pbx.c: Executing [0@ext-group:20] Set("DAHDI/1-1", "RingGroupMethod=") in new stack
[2020-03-02 12:50:08] VERBOSE[25163][C-000024de] pbx.c: Executing [0@ext-group:21] GotoIf("DAHDI/1-1", "0?nodest") in new stack
[2020-03-02 12:50:08] VERBOSE[25163][C-000024de] pbx.c: Executing [0@ext-group:22] Set("DAHDI/1-1", "__NODEST=") in new stack
[2020-03-02 12:50:08] VERBOSE[25163][C-000024de] pbx.c: Executing [0@ext-group:23] Macro("DAHDI/1-1", "blkvm-clr,") in new stack
[2020-03-02 12:50:08] VERBOSE[25163][C-000024de] pbx.c: Executing [s@macro-blkvm-clr:1] Set("DAHDI/1-1", "SHARED(BLKVM,DAHDI/1-1)=") in new stack
[2020-03-02 12:50:08] VERBOSE[25163][C-000024de] pbx.c: Executing [s@macro-blkvm-clr:2] Set("DAHDI/1-1", "GOSUB_RETVAL=") in new stack
[2020-03-02 12:50:08] VERBOSE[25163][C-000024de] pbx.c: Executing [s@macro-blkvm-clr:3] MacroExit("DAHDI/1-1", "") in new stack
[2020-03-02 12:50:08] VERBOSE[25163][C-000024de] pbx.c: Executing [0@ext-group:24] Goto("DAHDI/1-1", "ext-local,vmu990,1") in new stack
[2020-03-02 12:50:08] VERBOSE[25163][C-000024de] pbx_builtins.c: Goto (ext-local,vmu990,1)

You have an intermittent signalling issue, the 200OK from the phone is not being received by the PBX. Possibly being blocked/misdirected by your router, assuming there is a router between the phone and the PBX. I guess it’s also possible it’s a phone issue, tho I would consider that unlikely.

No router between phone and PBX. There is at least one switch.

I suppose it could be some random packet loss at a switch.

This topic was automatically closed 31 days after the last reply. New replies are no longer allowed.