Please excuse the lengthy post as I’ve included verbose log file entries.
We’ve had a version of FreePBX for more than 12 years here which has been working well for the most part. I fumbled through it when first started with FreePBX back in 2014, but never got deep into troubleshooting as it was very reliable and other than performing updates and extension changes, never had an issue. So I apologize for not using all the correct terms, and not having an in-depth understanding of the inner-workings of this system. But I’m in desperate need of any suggestions to the problem I am having here at our company and hopefully some guidance on how I can zero in on the cause of this.
We’re a small commercial contracting business with approximately 15 desktop phones. We have 5 legacy analog phone lines on a rotary from Spectrum that are part of a bundled package that are connected via DAHDI with a Digium A8A00F board, X400M FXO quad, X100M FXO modules. I’m still at version 15 which I know is unsupported and was planning to move to 17 in the near future.
But within the past five days, incoming calls were not being processed by the system. Users can still make outgoing calls, so I know the modules are functional. Came in on Sunday and rebooted and it seemed to be working fine. Late Monday, I was told it was acting up again, so I had them reboot again. I came in on Tuesday and late in the afternoon, problem now is permanent.
I was watching the log files scroll by, and when I made a call to our number, I saw the following: (The 4075543187 number is the first line on port 1 Digium DAHDI board. It’s one of 4 lines that are part of the rotary for incoming calls to our main number)
I deleted much of the log file from this test call as indicated by the ……
Incoming call:
1991[2026-03-04 08:45:14] VERBOSE[24578][C-0000000d] sig_analog.c: Starting simple switch on ‘DAHDI/1-1’
1992[2026-03-04 08:45:15] VERBOSE[24578][C-0000000d] pbx.c: Executing [s@from-analog:1] NoOp(“DAHDI/1-1”, "Entering from-dahdi with DID == ") in new stack
1993[2026-03-04 08:45:15] VERBOSE[24578][C-0000000d] pbx.c: Executing [s@from-analog:2] Ringing(“DAHDI/1-1”, “”) in new stack
1994[2026-03-04 08:45:15] VERBOSE[24578][C-0000000d] pbx.c: Executing [s@from-analog:3] Set(“DAHDI/1-1”, “DID=s”) in new stack
1995[2026-03-04 08:45:15] VERBOSE[24578][C-0000000d] pbx.c: Executing [s@from-analog:4] NoOp(“DAHDI/1-1”, “DID is now s”) in new stack
1996[2026-03-04 08:45:15] VERBOSE[24578][C-0000000d] pbx.c: Executing [s@from-analog:5] GotoIf(“DAHDI/1-1”, “1?dahdiok:checkzap”) in new stack
1997[2026-03-04 08:45:15] VERBOSE[24578][C-0000000d] pbx_builtins.c: Goto (from-analog,s,9)
1998[2026-03-04 08:45:15] VERBOSE[24578][C-0000000d] pbx.c: Executing [s@from-analog:9] NoOp(“DAHDI/1-1”, “Is a DAHDi Channel”) in new stack
1999[2026-03-04 08:45:15] VERBOSE[24578][C-0000000d] pbx.c: Executing [s@from-analog:10] Set(“DAHDI/1-1”, “CHAN=1-1”) in new stack
2000[2026-03-04 08:45:15] VERBOSE[24578][C-0000000d] pbx.c: Executing [s@from-analog:11] Set(“DAHDI/1-1”, “CHAN=1”) in new stack
2001[2026-03-04 08:45:15] VERBOSE[24578][C-0000000d] pbx.c: Executing [s@from-analog:12] Macro(“DAHDI/1-1”, “from-dahdi-1,s,1”) in new stack
2002[2026-03-04 08:45:15] VERBOSE[24578][C-0000000d] pbx.c: Executing [s@macro-from-dahdi-1:1] NoOp(“DAHDI/1-1”, “Entering macro-from-dahdi-1 with DID = s and setting to: 4075543187”) in new stack
2003[2026-03-04 08:45:15] VERBOSE[24578][C-0000000d] pbx.c: Executing [s@macro-from-dahdi-1:2] Set(“DAHDI/1-1”, “__FROM_DID=4075543187”) in new stack
2004[2026-03-04 08:45:15] VERBOSE[24578][C-0000000d] pbx.c: Executing [s@macro-
………………………
2012[2026-03-04 08:45:15] VERBOSE[24578][C-0000000d] pbx.c: Executing [s@ext-did:2] Gosub(“DAHDI/1-1”, “sub-record-check,s,1(in,s,dontcare)”) in new stack
2013[2026-03-04 08:45:15] VERBOSE[24578][C-0000000d] pbx.c: Executing [s@sub-record-check:1] GotoIf(“DAHDI/1-1”, “0?initialized”) in new stack
2014[2026-03-04 08:45:15] VERBOSE[24578][C-0000000d] pbx.c: Executing [s@sub-record-check:2] Set(“DAHDI/1-1”, “__REC_STATUS=INITIALIZED”) in new stack
2015[2026-03-04 08:45:15] VERBOSE[24578][C-0000000d] pbx.c: Executing [s@sub-
record-check:13] ExecIf(“DAHDI/1-1”, “0?Set(REC_STATUS=NO)”) in new stack
2026[2026-03-04 08:45:15] VERBOSE[24578][C-0000000d] pbx.c: Executing [s@sub-record-check:14] GotoIf(“DAHDI/1-1”, “2?checkaction”) in new stack
…….
2034[2026-03-04 08:45:15] VERBOSE[24578][C-0000000d] pbx.c: Executing [recordcheck@sub-record-check:1] NoOp(“DAHDI/1-1”, “Starting recording check against dontcare”) in new stack
2035[2026-03-04 08:45:15] VERBOSE[24578][C-0000000d] pbx.c: Executing [recordcheck@sub-record-check:2] Goto(“DAHDI/1-1”, “dontcare”) in new stack
2036[2026-03-04 08:45:15] VERBOSE[24578][C-0000000d] pbx_builtins.c: Goto (sub-record-check,recordcheck,3)
2037[2026-03-04 08:45:15] VERBOSE[24578][C-0000000d] pbx.c: Executing [recordcheck@sub-record-check:3] Return(“DAHDI/1-1”, “”) in new stack
2038[2026-03-04 08:45:15] VERBOSE[24578][C-0000000d] pbx.c: Executing [in@sub-record-check:5] Return(“DAHDI/1-1”, “”) in new stack
2039[2026-03-04 08:45:15] VERBOSE[24578][C-0000000d] pbx.c: Executing [s@ext-did:3] Set(“DAHDI/1-1”, “CHANNEL(tonezone)=us”) in new stack
2040[2026-03-04 08:45:15] VERBOSE[24578][C-0000000d] pbx.c: Executing [s@ext-did:4] ExecIf(“DAHDI/1-1”, “0?Set(__FROM_DID=s)”) in new stack
2041[2026-03-04 08:45:15] VERBOSE[24578][C-0000000d] pbx.c: Executing [s@ext-did:5] Set(“DAHDI/1-1”, “returnhere=1”) in new stack
2042[2026-03-04 08:45:15] VERBOSE[24578][C-0000000d] pbx.c: Executing [s@ext-did:6] Gosub(“DAHDI/1-1”, “app-blacklist-check,s,1()”) in new stack
2043[2026-03-04 08:45:15] VERBOSE[24578][C-0000000d] pbx.c: Executing [s@app-blacklist-check:1] GotoIf(“DAHDI/1-1”, “0?blacklisted”) in new stack
2044[2026-03-04 08:45:15] VERBOSE[24578][C-0000000d] pbx.c: Executing [s@app-blacklist-check:2] Set(“DAHDI/1-1”, “CALLED_BLACKLIST=1”) in new stack
2045[2026-03-04 08:45:15] VERBOSE[24578][C-0000000d] pbx.c: Executing [s@app-blacklist-check:3] Return(“DAHDI/1-1”, “”) in new stack
………..
2050[2026-03-04 08:45:15] VERBOSE[24578][C-0000000d] pbx.c: Executing [s@ext-did:11] Set(“DAHDI/1-1”, “__REVERSAL_REJECT=FALSE”) in new stack
2051[2026-03-04 08:45:15] VERBOSE[24578][C-0000000d] pbx.c: Executing [s@ext-did:12] GotoIf(“DAHDI/1-1”, “1?post-reverse-charge”) in new stack
2052[2026-03-04 08:45:15] VERBOSE[24578][C-0000000d] pbx_builtins.c: Goto (ext-did,s,14)
2053[2026-03-04 08:45:15] VERBOSE[24578][C-0000000d] pbx.c: Executing [s@ext-did:14] NoOp(“DAHDI/1-1”, “”) in new stack
……….
Set(“DAHDI/1-1”, “__CRM_SOURCE=4074964550”) in new stack
2061[2026-03-04 08:45:15] VERBOSE[24578][C-0000000d] pbx.c: Executing [s@ext-did:22] Set(“DAHDI/1-1”, “__CRM_LINKEDID=1772631914.14”) in new stack
2062[2026-03-04 08:45:15] VERBOSE[24578][C-0000000d] pbx.c: Executing [s@ext-did:23] AGI(“DAHDI/1-1”, “agi://127.0.0.1/sangomacrm.agi,true”) in new stack
2063[2026-03-04 08:45:15] WARNING[24578][C-0000000d] res_agi.c: Connecting to ‘127.0.0.1:4573’ failed for url ‘agi://127.0.0.1/sangomacrm.agi’: Connection refused
2064[2026-03-04 08:45:15] WARNING[24578][C-0000000d] res_agi.c: Couldn’t connect to any host. FastAGI failed.
………………….
2072[2026-03-04 08:45:15] VERBOSE[24578][C-0000000d] pbx.c: Executing [s@macro-user-callerid:1] Set(“DAHDI/1-1”, “TOUCH_MONITOR=1772631914.14”) in new stack
2073[2026-03-04 08:45:15] VERBOSE[24578][C-0000000d] pbx.c: Executing [s@macro-user-callerid:2] Set(“DAHDI/1-1”, “CHANCONTEXT=”) in new stack
2074[2026-03-04 08:45:15] VERBOSE[24578][C-0000000d] pbx.c: Executing [s@macro-user-callerid:3] Progress(“DAHDI/1-1”, “”) in new stack
2075[2026-03-04 08:45:15] VERBOSE[24578][C-0000000d] pbx.c: Executing [s@macro-user-callerid:4] Set(“DAHDI/1-1”, “CHANCONTEXT=”) in new stack
2076[2026-03-04 08:45:15] VERBOSE[24578][C-0000000d] pbx.c: Executing [s@macro-user
……………
2084[2026-03-04 08:45:15] VERBOSE[24578][C-0000000d] pbx.c: Executing [s@macro-user-callerid:13] ExecIf(“DAHDI/1-1”, “0?Set(CALLERID(name)=)”) in new stack
2085[2026-03-04 08:45:15] VERBOSE[24578][C-0000000d] pbx.c: Executing [s@macro-user-callerid:14] GotoIf(“DAHDI/1-1”, “0?report”) in new stack
2086[2026-03-04 08:45:15] VERBOSE[24578][C-0000000d] pbx.c: Executing [s@macro-user-callerid:15] ExecIf(“DAHDI/1-1”, “1?Set(REALCALLERIDNUM=4074964550)”) in new stack
2087[2026-03-04 08:45:15] VERBOSE[24578][C-0000000d] pbx.c: Executing [s@macro-user-callerid:16] Set(“DAHDI/1-1”, “AMPUSER=”) in new stack
2088[2026-03-04 08:45:15] VERBOSE[24578][C-0000000d] pbx.c: Executing [s@macro-user-callerid:17] GotoIf(“DAHDI/1-1”, “0?limit”) in new stack
2089[2026-03-04 08:45:15] VERBOSE[24578][C-0000000d] pbx.c: Executing [s@macro-user-callerid:18] Set(“DAHDI/1-1”, “AMPUSERCIDNAME=”) in new stack
2090[2026-03-04 08:45:15] VERBOSE[24578][C-0000000d] pbx.c: Executing [s@macro-user-callerid:19] ExecIf(“DAHDI/1-1”, “0?Set(__CIDMASQUERADING=TRUE)”) in new stack
2091[2026-03-04 08:45:15] VERBOSE[24578][C-0000000d] pbx.c: Executing [s@macro-user-callerid:20] GotoIf(“DAHDI/1-1”, “1?report”) in new stack
2092[2026-03-04 08:45:15] VERBOSE[24578][C-0000000d] pbx_builtins.c: Goto (macro-user-callerid,s,29)
2093[2026-03-04 08:45:15] VERBOSE[24578][C-0000000d] pbx.c: Executing [s@macro-
Stack
……………………………
2147[2026-03-04 08:45:17] VERBOSE[24578][C-0000000d] pbx.c: Executing [s@macro-dial:1] NoOp(“DAHDI/1-1”, "Blind Transfer: , Attended Transfer: , User: , Alert Info: ") in new stack
2148[2026-03-04 08:45:17] VERBOSE[24578][C-0000000d] pbx.c: Executing [s@macro-dial:2] Set(“DAHDI/1-1”, “__CRM_SOURCE=4074964550”) in new stack
2149[2026-03-04 08:45:17] VERBOSE[24578][C-0000000d] pbx.c: Executing [s@macro-dial:3] ExecIf(“DAHDI/1-1”, “0?Set(ALERT_INFO=)”) in new stack
2172[2026-03-04 08:45:17] VERBOSE[24578][C-0000000d] pbx.c: Spawn extension (app-blackhole, hangup, 2) exited non-zero on ‘DAHDI/1-1’
2173[2026-03-04 08:45:17] VERBOSE[24578][C-0000000d] app_stack.c: DAHDI/1-1 Internal Gosub(crm-hangup,s,1) start
2174[2026-03-04 08:45:17] VERBOSE[24578][C-0000000d] pbx.c: Executing [s@crm-hangup:1] NoOp(“DAHDI/1-1”, “Sending Hangup to CRM”) in new stack
2175[2026-03-04 08:45:17] VERBOSE[24578][C-0000000d] pbx.c: Executing [s@crm-
2182[2026-03-04 08:45:17] WARNING[24578][C-0000000d] res_agi.c: Couldn’t connect to any host. FastAGI failed.
2183[2026-03-04 08:45:17] VERBOSE[24578][C-0000000d] pbx.c: Executing [s@crm-hangup:8] Return(“DAHDI/1-1”, “”) in new stack
2184[2026-03-04 08:45:17] VERBOSE[24578][C-0000000d] app_stack.c: Spawn extension (app-blackhole, hangup, 2) exited non-zero on ‘DAHDI/1-1’
2185[2026-03-04 08:45:17] VERBOSE[24578][C-0000000d] app_stack.c: DAHDI/1-1 Internal Gosub(crm-hangup,s,1) complete GOSUB_RETVAL=
2186[2026-03-04 08:45:17] VERBOSE[24578][C-0000000d] sig_analog.c: Hanging up on ‘DAHDI/1-1’
2187[2026-03-04 08:45:17] VERBOSE[24578][C-0000000d] chan_dahdi.c: Hungup ‘DAHDI/1-1’
2188[2026-03-04 08:45:20] VERBOSE[24595][C-0000000e] sig_analog.c: Starting simple switch on ‘DAHDI/1-1’