Inbound calls randomly get fax tones

Hi All

I have a simple installation, it’s a dedicated HP Proliant DL360 server FreePBX 13.0.197 installed and all up to date. Asterisk version 13.12.1. I have one extension for my phone (ext 10) and one trunk line in (POTS5826). Both are routed through a genuine Digium 4 port modular analog PCI-Express x1 card. with one FXO and one FXS.

The overall reason for the system is to be able to screen out the robocalls and the telemarketers.

The big problem is that sometimes callers simply get a set of fax tones, I can reproduce it by calling in from my cell, hanging up and immediately calling again, the second call-in gets fax tones. I suspect that somehow the scripts from the first call aren’t all done but why that results in fax tones I don’t understand.

Pragmatically… I don’t care why I just need to get rid of the situation.

I own and have read Asterisk The Definitive Guide by Bryant, Madsen and Van Meggelen. I learned all the basics and then decided my installation was so simple it would be more appropriate to use FreePBX after all there is nothing so uncommon in my installation that it requires custom code.

The book indicates I should be able to build a simple dial plan in about 100 lines, but when I printed out the extensions_additional.conf I got 80 PAGES of code. Holy crap that has got to be the very definition of bloatware don’t you think?

When I look through the code there’s a ton I don’t use and a lot of sections I do use have lines that start:
exten => fax,1,

I don’t have any fax functions selected in the freepbx interface!

Can I delete these fax lines?

Will FreePBX just put them back? The header says it is auto generated.

How do I get rid of the bloatware and still retain usage of the FreePBX interface?

Jeff

Further info:
Here is the CDR list of the last three calls, note that the first two never got through, they just got fax tones. The third made it through.

Call Date Recording System CallerID Outbound CallerID DID App Destination Disposition Duration Userfield Account CDR Table CDR Graph
2019-09-20 13:13:12 Call recording Call recording 1569010392.11 “Brit. Columbia” <12506167017> s Dial 10 ANSWERED 02:10
2019-09-20 13:11:16 1569010276.9 7789823626 s BackGround s [ivr-1] ANSWERED 00:20
2019-09-20 13:10:22 1569010222.7 7789823626 s BackGround s [ivr-1] ANSWERED 00:20

Notice the app is “Background” why is it involved? I wonder if it’s still running from previous call?

Here’s the log entries for the middle call (it got fax tones)

[2019-09-20 13:11:16] VERBOSE[20775][C-00000008] sig_analog.c: Starting simple switch on 'DAHDI/1-1'
[2019-09-20 13:11:17] VERBOSE[20775][C-00000008] pbx.c: Executing [[email protected]:1] NoOp("DAHDI/1-1", "Entering from-dahdi with DID == ") in new stack
[2019-09-20 13:11:17] VERBOSE[20775][C-00000008] pbx.c: Executing [[email protected]:2] Ringing("DAHDI/1-1", "") in new stack
[2019-09-20 13:11:17] VERBOSE[20775][C-00000008] pbx.c: Executing [[email protected]:3] Set("DAHDI/1-1", "DID=s") in new stack
[2019-09-20 13:11:17] VERBOSE[20775][C-00000008] pbx.c: Executing [[email protected]:4] NoOp("DAHDI/1-1", "DID is now s") in new stack
[2019-09-20 13:11:17] VERBOSE[20775][C-00000008] pbx.c: Executing [[email protected]:5] GotoIf("DAHDI/1-1", "1?dahdiok:checkzap") in new stack
[2019-09-20 13:11:17] VERBOSE[20775][C-00000008] pbx_builtins.c: Goto (from-analog,s,9)
[2019-09-20 13:11:17] VERBOSE[20775][C-00000008] pbx.c: Executing [[email protected]:9] NoOp("DAHDI/1-1", "Is a DAHDi Channel") in new stack
[2019-09-20 13:11:17] VERBOSE[20775][C-00000008] pbx.c: Executing [[email protected]:10] Set("DAHDI/1-1", "CHAN=1-1") in new stack
[2019-09-20 13:11:17] VERBOSE[20775][C-00000008] pbx.c: Executing [[email protected]:11] Set("DAHDI/1-1", "CHAN=1") in new stack
[2019-09-20 13:11:17] VERBOSE[20775][C-00000008] pbx.c: Executing [[email protected]:12] Macro("DAHDI/1-1", "from-dahdi-1,s,1") in new stack
[2019-09-20 13:11:17] WARNING[20775][C-00000008] app_macro.c: No such context 'macro-from-dahdi-1' for macro 'from-dahdi-1'. Was called by [email protected]
[2019-09-20 13:11:17] VERBOSE[20775][C-00000008] pbx.c: Executing [[email protected]:13] NoOp("DAHDI/1-1", "Returned from Macro from-dahdi-1") in new stack
[2019-09-20 13:11:17] VERBOSE[20775][C-00000008] pbx.c: Executing [[email protected]:14] Goto("DAHDI/1-1", "from-pstn,s,1") in new stack
[2019-09-20 13:11:17] VERBOSE[20775][C-00000008] pbx_builtins.c: Goto (from-pstn,s,1)
[2019-09-20 13:11:17] VERBOSE[20775][C-00000008] pbx.c: Executing [[email protected]:1] Set("DAHDI/1-1", "__DIRECTION=INBOUND") in new stack
[2019-09-20 13:11:17] VERBOSE[20775][C-00000008] pbx.c: Executing [[email protected]:2] Gosub("DAHDI/1-1", "sub-record-check,s,1(in,s,dontcare)") in new stack
[2019-09-20 13:11:17] VERBOSE[20775][C-00000008] pbx.c: Executing [[email protected]:1] GotoIf("DAHDI/1-1", "0?initialized") in new stack
[2019-09-20 13:11:17] VERBOSE[20775][C-00000008] pbx.c: Executing [[email protected]:2] Set("DAHDI/1-1", "__REC_STATUS=INITIALIZED") in new stack
[2019-09-20 13:11:17] VERBOSE[20775][C-00000008] pbx.c: Executing [[email protected]:3] Set("DAHDI/1-1", "NOW=1569010277") in new stack
[2019-09-20 13:11:17] VERBOSE[20775][C-00000008] pbx.c: Executing [[email protected]:4] Set("DAHDI/1-1", "__DAY=20") in new stack
[2019-09-20 13:11:17] VERBOSE[20775][C-00000008] pbx.c: Executing [[email protected]:5] Set("DAHDI/1-1", "__MONTH=09") in new stack
[2019-09-20 13:11:17] VERBOSE[20775][C-00000008] pbx.c: Executing [[email protected]:6] Set("DAHDI/1-1", "__YEAR=2019") in new stack
[2019-09-20 13:11:17] VERBOSE[20775][C-00000008] pbx.c: Executing [[email protected]:7] Set("DAHDI/1-1", "__TIMESTR=20190920-131117") in new stack
[2019-09-20 13:11:17] VERBOSE[20775][C-00000008] pbx.c: Executing [[email protected]:8] Set("DAHDI/1-1", "__FROMEXTEN=unknown") in new stack
[2019-09-20 13:11:17] VERBOSE[20775][C-00000008] pbx.c: Executing [[email protected]:9] Set("DAHDI/1-1", "__MON_FMT=wav") in new stack
[2019-09-20 13:11:17] VERBOSE[20775][C-00000008] pbx.c: Executing [[email protected]:10] NoOp("DAHDI/1-1", "Recordings initialized") in new stack
[2019-09-20 13:11:17] VERBOSE[20775][C-00000008] pbx.c: Executing [[email protected]:11] ExecIf("DAHDI/1-1", "0?Set(ARG3=dontcare)") in new stack
[2019-09-20 13:11:17] VERBOSE[20775][C-00000008] pbx.c: Executing [[email protected]:12] Set("DAHDI/1-1", "REC_POLICY_MODE_SAVE=") in new stack
[2019-09-20 13:11:17] VERBOSE[20775][C-00000008] pbx.c: Executing [[email protected]:13] ExecIf("DAHDI/1-1", "0?Set(REC_STATUS=NO)") in new stack
[2019-09-20 13:11:17] VERBOSE[20775][C-00000008] pbx.c: Executing [[email protected]:14] GotoIf("DAHDI/1-1", "2?checkaction") in new stack
[2019-09-20 13:11:17] VERBOSE[20775][C-00000008] pbx_builtins.c: Goto (sub-record-check,s,17)
[2019-09-20 13:11:17] VERBOSE[20775][C-00000008] pbx.c: Executing [[email protected]:17] GotoIf("DAHDI/1-1", "1?sub-record-check,in,1") in new stack
[2019-09-20 13:11:17] VERBOSE[20775][C-00000008] pbx_builtins.c: Goto (sub-record-check,in,1)
[2019-09-20 13:11:17] VERBOSE[20775][C-00000008] pbx.c: Executing [[email protected]:1] NoOp("DAHDI/1-1", "Inbound Recording Check to s") in new stack
[2019-09-20 13:11:17] VERBOSE[20775][C-00000008] pbx.c: Executing [[email protected]:2] Set("DAHDI/1-1", "FROMEXTEN=unknown") in new stack
[2019-09-20 13:11:17] VERBOSE[20775][C-00000008] pbx.c: Executing [[email protected]:3] ExecIf("DAHDI/1-1", "10?Set(FROMEXTEN=7789823626)") in new stack
[2019-09-20 13:11:17] VERBOSE[20775][C-00000008] pbx.c: Executing [[email protected]:4] Gosub("DAHDI/1-1", "recordcheck,1(dontcare,in,s)") in new stack
[2019-09-20 13:11:17] VERBOSE[20775][C-00000008] pbx.c: Executing [[email protected]:1] NoOp("DAHDI/1-1", "Starting recording check against dontcare") in new stack
[2019-09-20 13:11:17] VERBOSE[20775][C-00000008] pbx.c: Executing [[email protected]:2] Goto("DAHDI/1-1", "dontcare") in new stack
[2019-09-20 13:11:17] VERBOSE[20775][C-00000008] pbx_builtins.c: Goto (sub-record-check,recordcheck,3)
[2019-09-20 13:11:17] VERBOSE[20775][C-00000008] pbx.c: Executing [[email protected]:3] Return("DAHDI/1-1", "") in new stack
[2019-09-20 13:11:17] VERBOSE[20775][C-00000008] pbx.c: Executing [[email protected]:5] Return("DAHDI/1-1", "") in new stack
[2019-09-20 13:11:17] VERBOSE[20775][C-00000008] pbx.c: Executing [[email protected]:3] ExecIf("DAHDI/1-1", "1?Set(__FROM_DID=s)") in new stack
[2019-09-20 13:11:17] VERBOSE[20775][C-00000008] pbx.c: Executing [[email protected]:4] Set("DAHDI/1-1", "returnhere=1") in new stack
[2019-09-20 13:11:17] VERBOSE[20775][C-00000008] pbx.c: Executing [[email protected]:5] Gosub("DAHDI/1-1", "app-blacklist-check,s,1()") in new stack
[2019-09-20 13:11:17] VERBOSE[20775][C-00000008] pbx.c: Executing [[email protected]:1] GotoIf("DAHDI/1-1", "0?blacklisted") in new stack
[2019-09-20 13:11:17] VERBOSE[20775][C-00000008] pbx.c: Executing [[email protected]:2] Set("DAHDI/1-1", "CALLED_BLACKLIST=1") in new stack
[2019-09-20 13:11:17] VERBOSE[20775][C-00000008] pbx.c: Executing [[email protected]:3] Return("DAHDI/1-1", "") in new stack
[2019-09-20 13:11:17] VERBOSE[20775][C-00000008] pbx.c: Executing [[email protected]:6] Set("DAHDI/1-1", "CDR(did)=s") in new stack
[2019-09-20 13:11:17] VERBOSE[20775][C-00000008] pbx.c: Executing [[email protected]:7] GotoIf("DAHDI/1-1", "0?") in new stack
[2019-09-20 13:11:17] VERBOSE[20775][C-00000008] pbx.c: Executing [[email protected]:8] ExecIf("DAHDI/1-1", "0 ?Set(CALLERID(name)=7789823626)") in new stack
[2019-09-20 13:11:17] VERBOSE[20775][C-00000008] pbx.c: Executing [[email protected]:9] Set("DAHDI/1-1", "CHANNEL(musicclass)=none") in new stack
[2019-09-20 13:11:17] VERBOSE[20775][C-00000008] pbx.c: Executing [[email protected]:10] Set("DAHDI/1-1", "__MOHCLASS=none") in new stack
[2019-09-20 13:11:17] VERBOSE[20775][C-00000008] pbx.c: Executing [[email protected]:11] Ringing("DAHDI/1-1", "") in new stack
[2019-09-20 13:11:17] VERBOSE[20775][C-00000008] pbx.c: Executing [[email protected]:12] Set("DAHDI/1-1", "__RINGINGSENT=TRUE") in new stack
[2019-09-20 13:11:17] VERBOSE[20775][C-00000008] pbx.c: Executing [[email protected]:13] Set("DAHDI/1-1", "__REVERSAL_REJECT=TRUE") in new stack
[2019-09-20 13:11:17] VERBOSE[20775][C-00000008] pbx.c: Executing [[email protected]:14] GotoIf("DAHDI/1-1", "0?post-reverse-charge") in new stack
[2019-09-20 13:11:17] WARNING[20775][C-00000008] func_channel.c: Unknown or unavailable item requested: 'reversecharge'
[2019-09-20 13:11:17] VERBOSE[20775][C-00000008] pbx.c: Executing [[email protected]:15] GotoIf("DAHDI/1-1", "0?macro-hangupcall") in new stack
[2019-09-20 13:11:17] VERBOSE[20775][C-00000008] pbx.c: Executing [[email protected]:16] NoOp("DAHDI/1-1", "") in new stack
[2019-09-20 13:11:17] VERBOSE[20775][C-00000008] pbx.c: Executing [[email protected]:17] Wait("DAHDI/1-1", "3") in new stack
[2019-09-20 13:11:20] VERBOSE[20775][C-00000008] pbx.c: Executing [[email protected]:18] Set("DAHDI/1-1", "__CALLINGNAMEPRES_SV=allowed_not_screened") in new stack
[2019-09-20 13:11:20] VERBOSE[20775][C-00000008] pbx.c: Executing [[email protected]:19] Set("DAHDI/1-1", "__CALLINGNUMPRES_SV=allowed_not_screened") in new stack
[2019-09-20 13:11:20] VERBOSE[20775][C-00000008] pbx.c: Executing [[email protected]:20] Set("DAHDI/1-1", "CALLERID(name-pres)=allowed_not_screened") in new stack
[2019-09-20 13:11:20] VERBOSE[20775][C-00000008] pbx.c: Executing [[email protected]:21] Set("DAHDI/1-1", "CALLERID(num-pres)=allowed_not_screened") in new stack
[2019-09-20 13:11:20] VERBOSE[20775][C-00000008] pbx.c: Executing [[email protected]:22] NoOp("DAHDI/1-1", "CallerID Entry Point") in new stack
[2019-09-20 13:11:20] VERBOSE[20775][C-00000008] pbx.c: Executing [[email protected]:23] Goto("DAHDI/1-1", "ivr-1,s,1") in new stack
[2019-09-20 13:11:20] VERBOSE[20775][C-00000008] pbx_builtins.c: Goto (ivr-1,s,1)
[2019-09-20 13:11:20] VERBOSE[20775][C-00000008] pbx.c: Executing [[email protected]:1] Set("DAHDI/1-1", "TIMEOUT_LOOPCOUNT=0") in new stack
[2019-09-20 13:11:20] VERBOSE[20775][C-00000008] pbx.c: Executing [[email protected]:2] Set("DAHDI/1-1", "INVALID_LOOPCOUNT=0") in new stack
[2019-09-20 13:11:20] VERBOSE[20775][C-00000008] pbx.c: Executing [[email protected]:3] Set("DAHDI/1-1", "_IVR_CONTEXT_ivr-1=") in new stack
[2019-09-20 13:11:20] VERBOSE[20775][C-00000008] pbx.c: Executing [[email protected]:4] Set("DAHDI/1-1", "_IVR_CONTEXT=ivr-1") in new stack
[2019-09-20 13:11:20] VERBOSE[20775][C-00000008] pbx.c: Executing [[email protected]:5] Set("DAHDI/1-1", "__IVR_RETVM=") in new stack
[2019-09-20 13:11:20] VERBOSE[20775][C-00000008] pbx.c: Executing [[email protected]:6] GotoIf("DAHDI/1-1", "0?skip") in new stack
[2019-09-20 13:11:20] VERBOSE[20775][C-00000008] pbx.c: Executing [[email protected]:7] Answer("DAHDI/1-1", "") in new stack
[2019-09-20 13:11:20] VERBOSE[20775][C-00000008] pbx.c: Executing [[email protected]:8] Wait("DAHDI/1-1", "1") in new stack
[2019-09-20 13:11:21] VERBOSE[20775][C-00000008] pbx.c: Executing [[email protected]:9] Set("DAHDI/1-1", "IVR_MSG=custom/welcome-to-jre") in new stack
[2019-09-20 13:11:21] VERBOSE[20775][C-00000008] pbx.c: Executing [[email protected]:10] Set("DAHDI/1-1", "TIMEOUT(digit)=3") in new stack
[2019-09-20 13:11:21] VERBOSE[20775][C-00000008] func_timeout.c: Digit timeout set to 3.000
[2019-09-20 13:11:21] VERBOSE[20775][C-00000008] pbx.c: Executing [[email protected]:11] ExecIf("DAHDI/1-1", "1?Background(custom/welcome-to-jre)") in new stack
[2019-09-20 13:11:21] VERBOSE[20775][C-00000008] file.c: &lt;DAHDI/1-1&gt; Playing 'custom/welcome-to-jre.slin' (language 'en')
[2019-09-20 13:11:29] VERBOSE[20775][C-00000008] pbx.c: Executing [[email protected]:12] WaitExten("DAHDI/1-1", "3,") in new stack
[2019-09-20 13:11:32] VERBOSE[20775][C-00000008] pbx_builtins.c: Timeout on DAHDI/1-1, going to 't'
[2019-09-20 13:11:32] VERBOSE[20775][C-00000008] pbx.c: Executing [[email protected]:1] Set("DAHDI/1-1", "TIMEOUT_LOOPCOUNT=1") in new stack
[2019-09-20 13:11:32] VERBOSE[20775][C-00000008] pbx.c: Executing [[email protected]:2] GotoIf("DAHDI/1-1", "0?final") in new stack
[2019-09-20 13:11:32] VERBOSE[20775][C-00000008] pbx.c: Executing [[email protected]:3] Set("DAHDI/1-1", "IVR_MSG=custom/timeout&amp;custom/welcome-to-jre") in new stack
[2019-09-20 13:11:32] VERBOSE[20775][C-00000008] pbx.c: Executing [[email protected]:4] Goto("DAHDI/1-1", "s,start") in new stack
[2019-09-20 13:11:32] VERBOSE[20775][C-00000008] pbx_builtins.c: Goto (ivr-1,s,10)
[2019-09-20 13:11:32] VERBOSE[20775][C-00000008] pbx.c: Executing [[email protected]:10] Set("DAHDI/1-1", "TIMEOUT(digit)=3") in new stack
[2019-09-20 13:11:32] VERBOSE[20775][C-00000008] func_timeout.c: Digit timeout set to 3.000
[2019-09-20 13:11:32] VERBOSE[20775][C-00000008] pbx.c: Executing [[email protected]:11] ExecIf("DAHDI/1-1", "1?Background(custom/timeout&amp;custom/welcome-to-jre)") in new stack
[2019-09-20 13:11:32] VERBOSE[20775][C-00000008] file.c: &lt;DAHDI/1-1&gt; Playing 'custom/timeout.slin' (language 'en')
[2019-09-20 13:11:36] VERBOSE[20775][C-00000008] pbx.c: Spawn extension (ivr-1, s, 11) exited non-zero on 'DAHDI/1-1'
[2019-09-20 13:11:36] VERBOSE[20775][C-00000008] pbx.c: Executing [[email protected]:1] Hangup("DAHDI/1-1", "") in new stack
[2019-09-20 13:11:36] VERBOSE[20775][C-00000008] pbx.c: Spawn extension (ivr-1, h, 1) exited non-zero on 'DAHDI/1-1'
[2019-09-20 13:11:36] VERBOSE[20775][C-00000008] sig_analog.c: Hanging up on 'DAHDI/1-1'
[2019-09-20 13:11:36] VERBOSE[20775][C-00000008] chan_dahdi.c: Hungup 'DAHDI/1-1'

This is most puzzling, as the log shows it playing the IVR prompt normally (and eventually timing out).

Please confirm:

  1. You don’t have a fax machine or other non-voice equipment, e.g. alarm system or medical alert device on this line.
  2. The FXO port is connected to a real copper POTS line, rather than e.g. a cable MTA or fiber ONT.
  3. The Fax tab for your Inbound Route (if it exists at all) has Detect Faxes set to No.
  4. Your /etc/asterisk/chan_dahdi.conf has faxdetect=no.

Do you have a way to monitor the POTS line, such as a butt set?

On a successful call, hang up the calling mobile but keep the called analog phone off hook. See whether Asterisk recognizes the disconnect almost immediately (one second or less), or there is a long delay.

Hi Stewart1

I don’t own a fax machine, at all.

The POTs line is copper and a real POTs line. It does branch into the alarm system but it’s a relay contact circuit such that the alarm system can break onto the line and cause the line to go off hook before it dials a pre programmed number to the alarm company. The alarm does not monitor or answer the line, all it can do is activate the relay to break into the line and dial out.

The fax tab on my inbound route has detect Faxes set to NO.

My /etc/asterisk/chan_dahdi.conf file has faxdetect=no

There is a long delay after I hang up the calling phone, almost 10 seconds, before asterisk puts a dial tone onto my extension set.

I just simulated it again, the middle call resulted in fax tones, notice the CDR reported it’s app as “Background”

Call Date Recording System CallerID Outbound CallerID DID App Destination Disposition Duration Userfield Account CDR Table CDR Graph
2019-09-20 16:24:11 Call recording Call recording 1569021851.26 “MICHELLE GAUTHI” <7789823626> s Dial 10 ANSWERED 00:28
2019-09-20 16:22:58 1569021778.25 UNKNOWN s BackGround s [ivr-1] ANSWERED 00:21
2019-09-20 16:22:14 Call recording Call recording 1569021734.23 “MICHELLE GAUTHI” <7789823626> s Dial 10 ANSWERED 00:37

Here is the log of the middle call:

[2019-09-20 16:22:58] VERBOSE[346][C-00000015] sig_analog.c: Starting simple switch on ‘DAHDI/1-1’
[2019-09-20 16:23:08] VERBOSE[346][C-00000015] pbx.c: Executing [[email protected]:1] NoOp(“DAHDI/1-1”, "Entering from-dahdi with DID == ") in new stack
[2019-09-20 16:23:08] VERBOSE[346][C-00000015] pbx.c: Executing [[email protected]:2] Ringing(“DAHDI/1-1”, “”) in new stack
[2019-09-20 16:23:08] VERBOSE[346][C-00000015] pbx.c: Executing [[email protected]:3] Set(“DAHDI/1-1”, “DID=s”) in new stack
[2019-09-20 16:23:08] VERBOSE[346][C-00000015] pbx.c: Executing [[email protected]:4] NoOp(“DAHDI/1-1”, “DID is now s”) in new stack
[2019-09-20 16:23:08] VERBOSE[346][C-00000015] pbx.c: Executing [[email protected]:5] GotoIf(“DAHDI/1-1”, “1?dahdiok:checkzap”) in new stack
[2019-09-20 16:23:08] VERBOSE[346][C-00000015] pbx_builtins.c: Goto (from-analog,s,9)
[2019-09-20 16:23:08] VERBOSE[346][C-00000015] pbx.c: Executing [[email protected]:9] NoOp(“DAHDI/1-1”, “Is a DAHDi Channel”) in new stack
[2019-09-20 16:23:08] VERBOSE[346][C-00000015] pbx.c: Executing [[email protected]:10] Set(“DAHDI/1-1”, “CHAN=1-1”) in new stack
[2019-09-20 16:23:08] VERBOSE[346][C-00000015] pbx.c: Executing [[email protected]:11] Set(“DAHDI/1-1”, “CHAN=1”) in new stack
[2019-09-20 16:23:08] VERBOSE[346][C-00000015] pbx.c: Executing [[email protected]:12] Macro(“DAHDI/1-1”, “from-dahdi-1,s,1”) in new stack
[2019-09-20 16:23:08] WARNING[346][C-00000015] app_macro.c: No such context ‘macro-from-dahdi-1’ for macro ‘from-dahdi-1’. Was called by [email protected]
[2019-09-20 16:23:08] VERBOSE[346][C-00000015] pbx.c: Executing [[email protected]:13] NoOp(“DAHDI/1-1”, “Returned from Macro from-dahdi-1”) in new stack
[2019-09-20 16:23:08] VERBOSE[346][C-00000015] pbx.c: Executing [[email protected]:14] Goto(“DAHDI/1-1”, “from-pstn,s,1”) in new stack
[2019-09-20 16:23:08] VERBOSE[346][C-00000015] pbx_builtins.c: Goto (from-pstn,s,1)
[2019-09-20 16:23:08] VERBOSE[346][C-00000015] pbx.c: Executing [[email protected]:1] Set(“DAHDI/1-1”, “__DIRECTION=INBOUND”) in new stack
[2019-09-20 16:23:08] VERBOSE[346][C-00000015] pbx.c: Executing [[email protected]:2] Gosub(“DAHDI/1-1”, “sub-record-check,s,1(in,s,dontcare)”) in new stack
[2019-09-20 16:23:08] VERBOSE[346][C-00000015] pbx.c: Executing [[email protected]:1] GotoIf(“DAHDI/1-1”, “0?initialized”) in new stack
[2019-09-20 16:23:08] VERBOSE[346][C-00000015] pbx.c: Executing [[email protected]:2] Set(“DAHDI/1-1”, “__REC_STATUS=INITIALIZED”) in new stack
[2019-09-20 16:23:08] VERBOSE[346][C-00000015] pbx.c: Executing [[email protected]:3] Set(“DAHDI/1-1”, “NOW=1569021788”) in new stack
[2019-09-20 16:23:08] VERBOSE[346][C-00000015] pbx.c: Executing [[email protected]:4] Set(“DAHDI/1-1”, “__DAY=20”) in new stack
[2019-09-20 16:23:08] VERBOSE[346][C-00000015] pbx.c: Executing [[email protected]:5] Set(“DAHDI/1-1”, “__MONTH=09”) in new stack
[2019-09-20 16:23:08] VERBOSE[346][C-00000015] pbx.c: Executing [[email protected]:6] Set(“DAHDI/1-1”, “__YEAR=2019”) in new stack
[2019-09-20 16:23:08] VERBOSE[346][C-00000015] pbx.c: Executing [[email protected]:7] Set(“DAHDI/1-1”, “__TIMESTR=20190920-162308”) in new stack
[2019-09-20 16:23:08] VERBOSE[346][C-00000015] pbx.c: Executing [[email protected]:8] Set(“DAHDI/1-1”, “__FROMEXTEN=unknown”) in new stack
[2019-09-20 16:23:08] VERBOSE[346][C-00000015] pbx.c: Executing [[email protected]:9] Set(“DAHDI/1-1”, “__MON_FMT=wav”) in new stack
[2019-09-20 16:23:08] VERBOSE[346][C-00000015] pbx.c: Executing [[email protected]:10] NoOp(“DAHDI/1-1”, “Recordings initialized”) in new stack
[2019-09-20 16:23:08] VERBOSE[346][C-00000015] pbx.c: Executing [[email protected]:11] ExecIf(“DAHDI/1-1”, “0?Set(ARG3=dontcare)”) in new stack
[2019-09-20 16:23:08] VERBOSE[346][C-00000015] pbx.c: Executing [[email protected]:12] Set(“DAHDI/1-1”, “REC_POLICY_MODE_SAVE=”) in new stack
[2019-09-20 16:23:08] VERBOSE[346][C-00000015] pbx.c: Executing [[email protected]:13] ExecIf(“DAHDI/1-1”, “0?Set(REC_STATUS=NO)”) in new stack
[2019-09-20 16:23:08] VERBOSE[346][C-00000015] pbx.c: Executing [[email protected]:14] GotoIf(“DAHDI/1-1”, “2?checkaction”) in new stack
[2019-09-20 16:23:08] VERBOSE[346][C-00000015] pbx_builtins.c: Goto (sub-record-check,s,17)
[2019-09-20 16:23:08] VERBOSE[346][C-00000015] pbx.c: Executing [[email protected]:17] GotoIf(“DAHDI/1-1”, “1?sub-record-check,in,1”) in new stack
[2019-09-20 16:23:08] VERBOSE[346][C-00000015] pbx_builtins.c: Goto (sub-record-check,in,1)
[2019-09-20 16:23:08] VERBOSE[346][C-00000015] pbx.c: Executing [[email protected]:1] NoOp(“DAHDI/1-1”, “Inbound Recording Check to s”) in new stack
[2019-09-20 16:23:08] VERBOSE[346][C-00000015] pbx.c: Executing [[email protected]:2] Set(“DAHDI/1-1”, “FROMEXTEN=unknown”) in new stack
[2019-09-20 16:23:08] VERBOSE[346][C-00000015] pbx.c: Executing [[email protected]:3] ExecIf(“DAHDI/1-1”, “0?Set(FROMEXTEN=)”) in new stack
[2019-09-20 16:23:08] VERBOSE[346][C-00000015] pbx.c: Executing [[email protected]:4] Gosub(“DAHDI/1-1”, “recordcheck,1(dontcare,in,s)”) in new stack
[2019-09-20 16:23:08] VERBOSE[346][C-00000015] pbx.c: Executing [[email protected]:1] NoOp(“DAHDI/1-1”, “Starting recording check against dontcare”) in new stack
[2019-09-20 16:23:08] VERBOSE[346][C-00000015] pbx.c: Executing [[email protected]:2] Goto(“DAHDI/1-1”, “dontcare”) in new stack
[2019-09-20 16:23:08] VERBOSE[346][C-00000015] pbx_builtins.c: Goto (sub-record-check,recordcheck,3)
[2019-09-20 16:23:08] VERBOSE[346][C-00000015] pbx.c: Executing [[email protected]:3] Return(“DAHDI/1-1”, “”) in new stack
[2019-09-20 16:23:08] VERBOSE[346][C-00000015] pbx.c: Executing [[email protected]:5] Return(“DAHDI/1-1”, “”) in new stack
[2019-09-20 16:23:08] VERBOSE[346][C-00000015] pbx.c: Executing [[email protected]:3] ExecIf(“DAHDI/1-1”, “1?Set(__FROM_DID=s)”) in new stack
[2019-09-20 16:23:08] VERBOSE[346][C-00000015] pbx.c: Executing [[email protected]:4] Set(“DAHDI/1-1”, “returnhere=1”) in new stack
[2019-09-20 16:23:08] VERBOSE[346][C-00000015] pbx.c: Executing [[email protected]:5] Gosub(“DAHDI/1-1”, “app-blacklist-check,s,1()”) in new stack
[2019-09-20 16:23:08] VERBOSE[346][C-00000015] pbx.c: Executing [[email protected]:1] GotoIf(“DAHDI/1-1”, “0?blacklisted”) in new stack
[2019-09-20 16:23:08] VERBOSE[346][C-00000015] pbx.c: Executing [[email protected]:2] Set(“DAHDI/1-1”, “CALLED_BLACKLIST=1”) in new stack
[2019-09-20 16:23:08] VERBOSE[346][C-00000015] pbx.c: Executing [[email protected]:3] Return(“DAHDI/1-1”, “”) in new stack
[2019-09-20 16:23:08] VERBOSE[346][C-00000015] pbx.c: Executing [[email protected]:6] Set(“DAHDI/1-1”, “CDR(did)=s”) in new stack
[2019-09-20 16:23:08] VERBOSE[346][C-00000015] pbx.c: Executing [[email protected]:7] GotoIf(“DAHDI/1-1”, “0?”) in new stack
[2019-09-20 16:23:08] VERBOSE[346][C-00000015] pbx.c: Executing [[email protected]:8] ExecIf(“DAHDI/1-1”, “1 ?Set(CALLERID(name)=)”) in new stack
[2019-09-20 16:23:08] VERBOSE[346][C-00000015] pbx.c: Executing [[email protected]:9] Set(“DAHDI/1-1”, “CHANNEL(musicclass)=none”) in new stack
[2019-09-20 16:23:08] VERBOSE[346][C-00000015] pbx.c: Executing [[email protected]:10] Set(“DAHDI/1-1”, “__MOHCLASS=none”) in new stack
[2019-09-20 16:23:08] VERBOSE[346][C-00000015] pbx.c: Executing [[email protected]:11] Ringing(“DAHDI/1-1”, “”) in new stack
[2019-09-20 16:23:08] VERBOSE[346][C-00000015] pbx.c: Executing [[email protected]:12] Set(“DAHDI/1-1”, “__RINGINGSENT=TRUE”) in new stack
[2019-09-20 16:23:08] VERBOSE[346][C-00000015] pbx.c: Executing [[email protected]:13] Set(“DAHDI/1-1”, “__REVERSAL_REJECT=TRUE”) in new stack
[2019-09-20 16:23:08] VERBOSE[346][C-00000015] pbx.c: Executing [[email protected]pstn:14] GotoIf(“DAHDI/1-1”, “0?post-reverse-charge”) in new stack
[2019-09-20 16:23:08] WARNING[346][C-00000015] func_channel.c: Unknown or unavailable item requested: ‘reversecharge’
[2019-09-20 16:23:08] VERBOSE[346][C-00000015] pbx.c: Executing [[email protected]:15] GotoIf(“DAHDI/1-1”, “0?macro-hangupcall”) in new stack
[2019-09-20 16:23:08] VERBOSE[346][C-00000015] pbx.c: Executing [[email protected]:16] NoOp(“DAHDI/1-1”, “”) in new stack
[2019-09-20 16:23:08] VERBOSE[346][C-00000015] pbx.c: Executing [[email protected]:17] Wait(“DAHDI/1-1”, “3”) in new stack
[2019-09-20 16:23:11] VERBOSE[346][C-00000015] pbx.c: Executing [[email protected]:18] Set(“DAHDI/1-1”, “__CALLINGNAMEPRES_SV=allowed_not_screened”) in new stack
[2019-09-20 16:23:11] VERBOSE[346][C-00000015] pbx.c: Executing [[email protected]:19] Set(“DAHDI/1-1”, “__CALLINGNUMPRES_SV=allowed_not_screened”) in new stack
[2019-09-20 16:23:11] VERBOSE[346][C-00000015] pbx.c: Executing [[email protected]:20] Set(“DAHDI/1-1”, “CALLERID(name-pres)=allowed_not_screened”) in new stack
[2019-09-20 16:23:11] VERBOSE[346][C-00000015] pbx.c: Executing [[email protected]:21] Set(“DAHDI/1-1”, “CALLERID(num-pres)=allowed_not_screened”) in new stack
[2019-09-20 16:23:11] VERBOSE[346][C-00000015] pbx.c: Executing [[email protected]:22] NoOp(“DAHDI/1-1”, “CallerID Entry Point”) in new stack
[2019-09-20 16:23:11] VERBOSE[346][C-00000015] pbx.c: Executing [[email protected]:23] Goto(“DAHDI/1-1”, “ivr-1,s,1”) in new stack
[2019-09-20 16:23:11] VERBOSE[346][C-00000015] pbx_builtins.c: Goto (ivr-1,s,1)
[2019-09-20 16:23:11] VERBOSE[346][C-00000015] pbx.c: Executing [[email protected]:1] Set(“DAHDI/1-1”, “TIMEOUT_LOOPCOUNT=0”) in new stack
[2019-09-20 16:23:11] VERBOSE[346][C-00000015] pbx.c: Executing [[email protected]:2] Set(“DAHDI/1-1”, “INVALID_LOOPCOUNT=0”) in new stack
[2019-09-20 16:23:11] VERBOSE[346][C-00000015] pbx.c: Executing [[email protected]:3] Set(“DAHDI/1-1”, “_IVR_CONTEXT_ivr-1=”) in new stack
[2019-09-20 16:23:11] VERBOSE[346][C-00000015] pbx.c: Executing [[email protected]:4] Set(“DAHDI/1-1”, “_IVR_CONTEXT=ivr-1”) in new stack
[2019-09-20 16:23:11] VERBOSE[346][C-00000015] pbx.c: Executing [[email protected]:5] Set(“DAHDI/1-1”, “__IVR_RETVM=”) in new stack
[2019-09-20 16:23:11] VERBOSE[346][C-00000015] pbx.c: Executing [[email protected]:6] GotoIf(“DAHDI/1-1”, “0?skip”) in new stack
[2019-09-20 16:23:11] VERBOSE[346][C-00000015] pbx.c: Executing [[email protected]:7] Answer(“DAHDI/1-1”, “”) in new stack
[2019-09-20 16:23:11] VERBOSE[346][C-00000015] pbx.c: Executing [[email protected]:8] Wait(“DAHDI/1-1”, “1”) in new stack
[2019-09-20 16:23:12] VERBOSE[346][C-00000015] pbx.c: Executing [[email protected]:9] Set(“DAHDI/1-1”, “IVR_MSG=custom/welcome-to-jre”) in new stack
[2019-09-20 16:23:12] VERBOSE[346][C-00000015] pbx.c: Executing [[email protected]:10] Set(“DAHDI/1-1”, “TIMEOUT(digit)=3”) in new stack
[2019-09-20 16:23:12] VERBOSE[346][C-00000015] func_timeout.c: Digit timeout set to 3.000
[2019-09-20 16:23:12] VERBOSE[346][C-00000015] pbx.c: Executing [[email protected]:11] ExecIf(“DAHDI/1-1”, “1?Background(custom/welcome-to-jre)”) in new stack
[2019-09-20 16:23:12] VERBOSE[346][C-00000015] file.c: <DAHDI/1-1> Playing ‘custom/welcome-to-jre.slin’ (language ‘en’)
[2019-09-20 16:23:13] WARNING[346][C-00000015] sig_analog.c: Ring/Off-hook in strange state 6 on channel 1
[2019-09-20 16:23:15] NOTICE[346][C-00000015] sig_analog.c: Alarm cleared on channel 1
[2019-09-20 16:23:20] VERBOSE[346][C-00000015] pbx.c: Spawn extension (ivr-1, s, 11) exited non-zero on ‘DAHDI/1-1’
[2019-09-20 16:23:20] VERBOSE[346][C-00000015] pbx.c: Executing [[email protected]:1] Hangup(“DAHDI/1-1”, “”) in new stack
[2019-09-20 16:23:20] VERBOSE[346][C-00000015] pbx.c: Spawn extension (ivr-1, h, 1) exited non-zero on ‘DAHDI/1-1’
[2019-09-20 16:23:20] VERBOSE[346][C-00000015] sig_analog.c: Hanging up on ‘DAHDI/1-1’
[2019-09-20 16:23:20] VERBOSE[346][C-00000015] chan_dahdi.c: Hungup ‘DAHDI/1-1’

What does this mean?

[2019-09-20 16:23:13] WARNING[346][C-00000015] sig_analog.c: Ring/Off-hook in strange state 6 on channel 1

it’s near the very end of the log just after where background is playing the welcome message.

It means that the fxo port detected an abnormal state of the line, either related to unexpected voltage or current values for the actual real status of the line, be it onhook, ringing or offhook.

Thanks Arielfrin, that gives me something to work with.

I’ve changed the FXO module - no change in symptoms so that’s not it.

It is usually a problem on the line, not on the fxo port.
Regarding fax tones, by any chance have you enabled tone detection when you configured your card? I don’t know if Digium has that option, but Sangoma cards do.

Many alarm systems are set up so the installer can remotely bypass zones or even program the system. The usual protocol for this is the installer calls in, lets it ring once, hangs up, then calls back 10 to 30 seconds later. When the alarm system sees this sequence, its modem answers the line and after authenticating, the installer can make changes.

I’m fairly sure that your testing is inadvertently causing the alarm to answer. Your calls are always ‘answered’ after one ring, because once DAHDI has collected the caller ID, the IVR picks up the line. I’m guessing that the alarm panel is not smart enough to detect the off hook in this case, so it just sees the single ring and ‘arms’ itself to answer the next call if it comes within the appropriate window.

You can confirm all this by connecting an analog phone in parallel with the FXO card. When an inbound call fails and the caller hears modem tones, pick up the analog phone and listen. My bet is that you’ll hear nothing, because the panel has seized the line.

If this is indeed your issue and you don’t need this remote access to the panel, just disable it (if you don’t know the installer code, ask the alarm company to do so). Some panels can be set up to answer after e.g. 15 rings, so by temporarily disabling the PBX from answering, remote access to the panel is still possible.

If you still have trouble, please post: Alarm panel make/model? Do you have the installer code?

3 Likes

You sir are a GENIUS!

OK, Solved! the sounds were from the alarm not asterisk.

The function is called Ans. Mach. Overide/Double Call Enabled.
Section 401 - option 1 (DSC 832 model PC5010)
(I have the installer code and all the manuals, I put this alarm in myself)

I think what was happening was that the line would ring and both would try to answer but when the alarm grabs the line everything after it (asterisk) goes dead so then asterisk threw a warning because the POTS line had no voltage on it. In the meantime the caller is listening to the modem from the alarm trying to communicate with what it thinks is the base station.

Thanks to everyone who helped, especially Stewart1 !

1 Like

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