PBX dials ring group for 0 seconds

Calls work their way through the time conditions and eventually get to the ring group. Sometimes calls only ring for a very short period of time and then end up at the “destination if no answer”. Some relevant details:

-The phones are online and were on calls shortly before and after the call.

  • The ring group is not set to skip busy agents
  • Each of the five extensions in the group have Call Waiting enabled
  • There is no evidence in the logs that the phones were unregistered at the time of the call
  • The callers are claiming that they are “going straight to voicemail” which is actually the greeting for the IVR.
  • The log makes it look like the call hung up before it could go to the IVR but the callers swear that they’ve heard the IVR greeting.

Any ideas what could be causing this?

PBX Firmware: 6.12.65-27
FreePBX 12.0.67
Asterisk Ver. 11.17.1

From the CDR it looks like the PBX got some response back from the phones that it didn’t like but I cant really tell. It starts 5 different channels and then goes through each phone one by one and hangs up and ends the channel.

Here is a snippet of the asterisk Full log, where you can see all 5 extensions being called and in the same second the call hanging up, yet the caller says they heard the IVR greeting. This is more confusing than the phones not being reachable. Normally the log would show that the recording was playing but it doesn’t.

[2015-06-29 11:12:28] VERBOSE[24819][C-000050c2] app_dial.c: – SIP/505-00001d3f is ringing
[2015-06-29 11:12:28] VERBOSE[24819][C-000050c2] app_dial.c: – SIP/505-00001d3f is ringing
[2015-06-29 11:12:28] VERBOSE[24819][C-000050c2] app_dial.c: – SIP/500-00001d3e is ringing
[2015-06-29 11:12:28] VERBOSE[24819][C-000050c2] app_dial.c: – SIP/500-00001d3e is ringing
[2015-06-29 11:12:28] VERBOSE[24819][C-000050c2] app_dial.c: – SIP/510-00001d40 is ringing
[2015-06-29 11:12:28] VERBOSE[24819][C-000050c2] app_dial.c: – SIP/510-00001d40 is ringing
[2015-06-29 11:12:28] VERBOSE[24819][C-000050c2] app_dial.c: – SIP/520-00001d42 is ringing
[2015-06-29 11:12:28] VERBOSE[24819][C-000050c2] app_dial.c: – SIP/520-00001d42 is ringing
[2015-06-29 11:12:28] VERBOSE[24819][C-000050c2] app_dial.c: – SIP/515-00001d41 is ringing
[2015-06-29 11:12:28] VERBOSE[24819][C-000050c2] app_dial.c: – SIP/515-00001d41 is ringing
[2015-06-29 11:12:28] VERBOSE[24819][C-000050c2] app_macro.c: == Spawn extension (macro-dial, s, 7) exited non-zero on ‘SIP/telepacific-00001d3d’ in macro ‘dial’
[2015-06-29 11:12:28] VERBOSE[24819][C-000050c2] app_macro.c: == Spawn extension (macro-dial, s, 7) exited non-zero on ‘SIP/telepacific-00001d3d’ in macro ‘dial’
[2015-06-29 11:12:28] VERBOSE[24819][C-000050c2] pbx.c: == Spawn extension (ext-group, 599, 11) exited non-zero on ‘SIP/telepacific-00001d3d’
[2015-06-29 11:12:28] VERBOSE[24819][C-000050c2] pbx.c: == Spawn extension (ext-group, 599, 11) exited non-zero on ‘SIP/telepacific-00001d3d’
[2015-06-29 11:12:28] VERBOSE[24819][C-000050c2] pbx.c: – Executing [h@ext-group:1] Macro(“SIP/telepacific-00001d3d”, “hangupcall,”) in new stack
[2015-06-29 11:12:28] VERBOSE[24819][C-000050c2] pbx.c: – Executing [h@ext-group:1] Macro(“SIP/telepacific-00001d3d”, “hangupcall,”) in new stack
[2015-06-29 11:12:28] VERBOSE[24819][C-000050c2] pbx.c: – Executing [s@macro-hangupcall:1] ExecIf(“SIP/telepacific-00001d3d”, “0?Set(CDR(recordingfile)=.wav)”) in new stack
[2015-06-29 11:12:28] VERBOSE[24819][C-000050c2] pbx.c: – Executing [s@macro-hangupcall:1] ExecIf(“SIP/telepacific-00001d3d”, “0?Set(CDR(recordingfile)=.wav)”) in new stack
[2015-06-29 11:12:28] VERBOSE[24819][C-000050c2] pbx.c: – Executing [s@macro-hangupcall:2] GotoIf(“SIP/telepacific-00001d3d”, “1?theend”) in new stack
[2015-06-29 11:12:28] VERBOSE[24819][C-000050c2] pbx.c: – Executing [s@macro-hangupcall:2] GotoIf(“SIP/telepacific-00001d3d”, “1?theend”) in new stack
[2015-06-29 11:12:28] VERBOSE[24819][C-000050c2] pbx.c: – Goto (macro-hangupcall,s,4)
[2015-06-29 11:12:28] VERBOSE[24819][C-000050c2] pbx.c: – Goto (macro-hangupcall,s,4)
[2015-06-29 11:12:28] VERBOSE[24819][C-000050c2] pbx.c: – Executing [s@macro-hangupcall:4] Hangup(“SIP/telepacific-00001d3d”, “”) in new stack
[2015-06-29 11:12:28] VERBOSE[24819][C-000050c2] pbx.c: – Executing [s@macro-hangupcall:4] Hangup(“SIP/telepacific-00001d3d”, “”) in new stack
[2015-06-29 11:12:28] VERBOSE[24819][C-000050c2] app_macro.c: == Spawn extension (macro-hangupcall, s, 4) exited non-zero on ‘SIP/telepacific-00001d3d’ in macro ‘hangupcall’
[2015-06-29 11:12:28] VERBOSE[24819][C-000050c2] app_macro.c: == Spawn extension (macro-hangupcall, s, 4) exited non-zero on ‘SIP/telepacific-00001d3d’ in macro ‘hangupcall’
[2015-06-29 11:12:28] VERBOSE[24819][C-000050c2] pbx.c: == Spawn extension (ext-group, h, 1) exited non-zero on ‘SIP/telepacific-00001d3d’
[2015-06-29 11:12:28] VERBOSE[24819][C-000050c2] pbx.c: == Spawn extension (ext-group, h, 1) exited non-zero on ‘SIP/telepacific-00001d3d’