Hi there,
I have a strange delay in call processing. It takes a long time to place calls, no matter if internally or outbound. Log files state that it takes 9 (nine) seconds from dialing to ringing.
This has happened twice before, but that behavior stopped after a couple of hours. But this time it’s rather persistent. This time the delay started after I updated FreePBX Core a couple of days ago. The next update, a few days after the initial update, didn’t change anything. Rebooting did not help either.
I’m hoping someone out there can help me, getting really frustrated…
FreePBX 12.0.76.4 with Asterisk Ver. 11.17.1
PBX Firmware:6.12.65-27 PBX Service Pack:1.0.0.0
Following is an excerpt from the log file, showing the 9 second delay doing an internal sip to sip call.
[2016-08-10 10:48:35] VERBOSE[542][C-000035dc] pbx.c: -- Executing [s@sub-presencestate-display:1] Goto("SIP/66-00000ab8", "state-,1") in new stack [2016-08-10 10:48:35] VERBOSE[542][C-000035dc] pbx.c: -- Goto (sub-presencestate-display,state-,1) [2016-08-10 10:48:35] VERBOSE[542][C-000035dc] pbx.c: -- Executing [state-@sub-presencestate-display:1] Set("SIP/66-00000ab8", "PRESENCESTATE_DISPLAY=") in new stack [2016-08-10 10:48:35] VERBOSE[542][C-000035dc] pbx.c: -- Executing [state-@sub-presencestate-display:2] Return("SIP/66-00000ab8", "") in new stack [2016-08-10 10:48:35] VERBOSE[542][C-000035dc] pbx.c: -- Executing [s@macro-dial-one:40] Set("SIP/66-00000ab8", "CONNECTEDLINE(name,i)=XXX") in new stack [2016-08-10 10:48:35] VERBOSE[542][C-000035dc] pbx.c: -- Executing [s@macro-dial-one:41] Set("SIP/66-00000ab8", "CONNECTEDLINE(num)=34") in new stack [2016-08-10 10:48:35] VERBOSE[542][C-000035dc] pbx.c: -- Executing [s@macro-dial-one:42] Set("SIP/66-00000ab8", "D_OPTIONS=TtrI") in new stack [2016-08-10 10:48:35] VERBOSE[542][C-000035dc] pbx.c: -- Executing [s@macro-dial-one:43] Macro("SIP/66-00000ab8", "dialout-one-predial-hook,") in new stack [2016-08-10 10:48:35] VERBOSE[542][C-000035dc] pbx.c: -- Executing [s@macro-dialout-one-predial-hook:1] MacroExit("SIP/66-00000ab8", "") in new stack [2016-08-10 10:48:35] VERBOSE[542][C-000035dc] pbx.c: -- Executing [s@macro-dial-one:44] ExecIf("SIP/66-00000ab8", "0?Set(D_OPTIONS=trII)") in new stack [2016-08-10 10:48:35] VERBOSE[542][C-000035dc] pbx.c: -- Executing [s@macro-dial-one:45] Dial("SIP/66-00000ab8", "SIP/34,,TtrI") in new stack [2016-08-10 10:48:44] VERBOSE[542][C-000035dc] netsock2.c: == Using SIP RTP TOS bits 184 [2016-08-10 10:48:44] VERBOSE[542][C-000035dc] netsock2.c: == Using SIP RTP CoS mark 5 [2016-08-10 10:48:44] VERBOSE[542][C-000035dc] app_dial.c: -- Called SIP/34 [2016-08-10 10:48:44] VERBOSE[542][C-000035dc] app_dial.c: -- Connected line update to SIP/66-00000ab8 prevented. [2016-08-10 10:48:44] VERBOSE[542][C-000035dc] app_dial.c: -- SIP/34-00000ab9 is ringing [2016-08-10 10:48:46] VERBOSE[542][C-000035dc] app_dial.c: -- Connected line update to SIP/66-00000ab8 prevented. [2016-08-10 10:48:46] VERBOSE[542][C-000035dc] app_dial.c: -- SIP/34-00000ab9 answered SIP/66-00000ab8 [2016-08-10 10:49:30] VERBOSE[542][C-000035dc] pbx.c: -- Executing [h@macro-dial-one:1] Macro("SIP/66-00000ab8", "hangupcall,") in new stack [2016-08-10 10:49:30] VERBOSE[542][C-000035dc] pbx.c: -- Executing [s@macro-hangupcall:1] ExecIf("SIP/66-00000ab8", "0?Set(CDR(recordingfile)=.wav)") in new stack [2016-08-10 10:49:30] VERBOSE[542][C-000035dc] pbx.c: -- Executing [s@macro-hangupcall:2] GotoIf("SIP/66-00000ab8", "1?theend") in new stack [2016-08-10 10:49:30] VERBOSE[542][C-000035dc] pbx.c: -- Goto (macro-hangupcall,s,4) [2016-08-10 10:49:30] VERBOSE[542][C-000035dc] pbx.c: -- Executing [s@macro-hangupcall:4] Hangup("SIP/66-00000ab8", "") in new stack [2016-08-10 10:49:30] VERBOSE[542][C-000035dc] app_macro.c: == Spawn extension (macro-hangupcall, s, 4) exited non-zero on 'SIP/66-00000ab8' in macro 'hangupcall' [2016-08-10 10:49:30] VERBOSE[542][C-000035dc] pbx.c: == Spawn extension (macro-dial-one, h, 1) exited non-zero on 'SIP/66-00000ab8' [2016-08-10 10:49:30] VERBOSE[542][C-000035dc] app_macro.c: == Spawn extension (macro-dial-one, s, 45) exited non-zero on 'SIP/66-00000ab8' in macro 'dial-one' [2016-08-10 10:49:30] VERBOSE[542][C-000035dc] app_macro.c: == Spawn extension (macro-exten-vm, s, 14) exited non-zero on 'SIP/66-00000ab8' in macro 'exten-vm' [2016-08-10 10:49:30] VERBOSE[542][C-000035dc] pbx.c: == Spawn extension (ext-local, 34, 2) exited non-zero on 'SIP/66-00000ab8'