Inbound calls from POTS Line - Missing CID

[ngzeng (Kevin)]

Issue: When calling from outside, the CID (phone number of the caller), doesn’t show neither on the call history nor on the phones.

Goal: Have CID info on Incomming calls on Analog Line

Current Setup (Testing Rig):
FreePBX
Sangoma A200 2FXO+2FXS PCIe Analog Card
GSM FWT using a TCL Linkhub HH42L
W60B + W56H Phone

First question: ¿Why?. Reason: Company’s cellphone number gets a lot of daily calls from clients, issue is, sometimes the cellphone is far away, someone is using the phone for other things, it’s charging or can’t find it. So, calls gets unanswered. Reason #2: Mobile to Mobile calling is way cheaper and our current plan includes unlimited calls, but for the reasons above mentioned, we can’t make use of it as we would like, so our plan is to have it set up as a trunk and be able to make calls through the SIM Card from any desk phone connected to the PBX.

The A200 card is detected, we have run through “setup-sangoma” via the CLI, the card is shown correctly on lspci, the channels are listed on “dahdi show channels”, RJ9 (FXO port on A200) <> RJ11 (Telephone port on HH42L) is connected, calls made to the cellphone number does ring on the W56H, can be answered and have two way communication, no prob.

But no CID… First troubleshooting step: use a regular old analog phone (ATT&T EL52145) to the RJ11 port on the HH42L and make a test call, result: the analog phone does display the caller phone number correctly.

Next, follow troubleshooting guide (https://sangomakb.atlassian.net/wiki/spaces/TC/pages/51741280/Analog-+Inbound+Caller+ID+Missing), usecallerid=yes, tested every single cidsignalling and every single cidstart variable available. Still no CID shown.

I NEED HELP please… I would appreciate any guidance of what other tests I should be doing or configs that I might be missing, also, I’m a bit lost on what logs to check or where can I see the call progress from the first ring, up to the hang-up, to see if either the CID is being lost somewhere or it isn’t being correctly decoded (either FSK or DTMF, still not sure how it’s sent from the HH42L), I’ve also exported multiple test call recordings taken with “dahdi_monitor”, but I’m not sure what to look for in the recordings.

[Stewart1 (Stewart)]

Possibly, you can connect the HH42L to Asterisk over the network, without the A200. Please post screenshots of it’s Voice pages (Call settings, VoIP, etc.)

If you must use the A200, match the caller ID settings to what you see in the HH42L, and use debug tools to see why caller ID isn’t being received or sent onward. Start with
core set debug 3
If insufficient detail, search DAHDI debugging.

If you still have trouble, post your DAHDI config and an audio recording that includes caller ID info.

[ngzeng (Kevin)]

Sadly, no VoIP Server on the HH42L, photos of settings pages:

Settings → Profile management:

Services → Call logs → Incoming call:

Services → Call settings:

Extract of “/etc/asterisk/chan_dahdi.conf”:

[root@freepbx asterisk]# cat chan_dahdi.conf
;--------------------------------------------------------------------------------;
;          Do NOT edit this file as it is auto-generated by FreePBX.             ;
;--------------------------------------------------------------------------------;
; For information on adding additional paramaters to this file, please visit the ;
; FreePBX.org wiki page, or ask on IRC. This file was created by the new FreePBX ;
; BMO - Big Module Object. Any similarity in naming with BMO from Adventure Time ;
; is totally deliberate.                                                         ;
;--------------------------------------------------------------------------------;
[general]

; generated by module
#include chan_dahdi_general.conf

; for user additions not provided by module
#include chan_dahdi_general_custom.conf

[channels]
language=es
busydetect=yes
busycount=6
usecallerid=yes
callwaiting=yes
usecallingpres=yes
threewaycalling=yes
transfer=yes
cancallforward=yes
callreturn=yes
echocancel=yes
echocancelwhenbridged=no
echotraining=no
immediate=no
faxdetect=no
rxgain=0.0
txgain=0.0
alawoverride=0
alawoverride_checkbox=0
boostringer=0
boostringer_checkbox=0
callerid=asreceived
cidsignalling=bell
cidstart=polarity
echocan_nlp_max_supp=
echocan_nlp_threshold=
echocan_nlp_type=0
fastringer=0
fastringer_checkbox=0
fxs_honor_mode=0
fxs_honor_mode_checkbox=0
lowpower=0
lowpower_checkbox=0
module_name=wctdm24xxp
mwi=none
mwi_checkbox=0
neon_offlimit=
neon_voltage=
opermode_checkbox=0
ringdetect=0
ringdetect_checkbox=0

; for user additions not provided by module
#include chan_dahdi_channels_custom.conf

; include dahdi groups defined by DAHDI module of FreePBX
#include chan_dahdi_groups.conf

; include dahdi extensions defined in FreePBX
#include chan_dahdi_additional.conf

Attached is the file created by dahdi_monitor with a test call, I think the tones before the rings should be the CID data, but I’m unsure about it.

[Stewart1 (Stewart)]

I can’t tell whether there is a polarity reversal before or immediately after the first ring (you could check with a voltmeter), but the CID is sent after the first ring, so you probably want cidstart=ring.

The modulation and general format is Bellcore, but the Channel Seizure signal is much shorter than standard so maybe DAHDI doesn’t recognize it.

Does anything useful appear in the Asterisk log with
core set debug 3
or other DAHDI debug tools?

It may be possible to adjust some parameter in the DAHDI code to make this work. Otherwise, would you consider a different GSM gateway (GoIP or similar) or receiving the calls on a VoIP line (though I don’t know whether Panama VoIP numbers can receive SMS/MMS)? If you are stuck with the HH42L, possibly a different FXO device (OBi110, HT813, etc.) will accept the unusual CID format.

[ngzeng (Kevin)]

@Stewart1 Thanks for your kind help. I’ve changed the cidstart to “ring” as advised and made a test call. This is the log taken with:

core set debug 3

---

…Too many characters to be able to post it here, had to upload the log to a pastebin link
Link: Asterisk debug from test call - Pastebin.com

---

Looking through the log (with my inexperienced eyes), I couldn’t find the culprit and CID number I made the call with for this test was nowhere to be found.

If you don’t mind, could you mention a DAHDI debug tool I could use, as of writing this post, I don’t really know what DAHDI debug tools exist in FreePBX or Asterisk.

@Stewart1

It may be possible to adjust some parameter in the DAHDI code to make this work.

I’m open to the challenge if this is a possibility. The HH42L currently also serves as the failover (“WAN2 on the router”) for Internet access for the company’s network, so that’s sort of why we are a bit stuck. I couldn’t find any GSM Gateway that could serve both as a “4G/LTE Modem” and “GSM VoIP Gateway” at the same time.

---

P.D.: For reference and if this is what your are referring to with modifying the DAHDI Code, our country’s analog line tone cadence should be (according to the TSB of ITU on this bulletin):

Panama (Republic of) Busy tone - 425 0.32 on 0.32 off
Congestion tone - 425 0.32 on 0.32 off
Dial tone - 425 continuous
Number unobtainable tone - 425 0.18 on 0.18 off 0.5 on 0.18 off
Ringing tone - 425 1.2 on 4.65 off
Special information tone - 425 0.4 on 0.4 off
Warning tone - operator intervening 425 0.18 on 0.18 off 0.5 on 0.18 off
Call waiting tone - 425 0.18 on 0.18 off 0.18 on

[Stewart1 (Stewart)]

There are several things in this log that I don’t understand. I hope that another reader who is more familiar with DAHDI and analog cards will chime in to help.

There are numerous posts complaining about a 10 second delay on incoming calls, when the caller ID is not present or can’t be decoded. Unlike most FXO devices that delay a user-configured time before sending the call to Asterisk, DAHDI sends immediately on successful caller ID reception, but gives up after 10 seconds.

In your log, we see 10 seconds between paste lines 27 and 28. However, the call is apparently answered on line 5, only one second after ringing start. Was it really? Check by when the calling phone shows connected, or by monitoring line voltage or current. Actually being off hook could certainly mess up decoding caller ID.

Then, we see more ring events on lines 1047 and 1052. Are these from a different call? Or from a retry from the calling phone or some other system element?

[ngzeng (Kevin)]

I appreciate all your help @Stewart1. I’ll be doing tests tomorrow with a voltmeter to monitor and check all the concerns you have mentioned until now (polarity reversal and off-hook signal after first ring). And in the meantime, hopefully someone can give some more insight and make this thread a useful one for anyone else having the same issue in the future.

Also, would you suggest any GSM Gateway as an alternate solution for this issue, taking in mind the requirements of being able to function as a 4G/LTE Modem as well. I’ve looked into the HT813 and Obi110 options you mentioned, however, in addition to not being able to use it as a internet failover, I would like to have as little “hops” as possible with the call, since I’m aware that calls are latency sensitive. (HH42L → Obi110/HT813 (Voice to IP) → Network Switch → FreePBX).

Have anyone had any experience using “Flying Voice’s Gateways”, it’s been the only brand I could find with a reasonable price. See FWR7302 4G-LTE VoIP Router.

[ngzeng (Kevin)]

Btw, just made another test call with debugging enabled, and your concern regarding the off-hook signal might be just the cause of this whole issue, this time, the log threw a warning just after the “EVENT_RINGBEGIN” that it must wait for the Caller ID and inmediately after, it got the “EVENT_RINGOFFHOOK” signal.

[2024-03-31 02:52:14] DEBUG[2737]: chan_dahdi.c:11896 do_monitor: Monitor doohicky got event Ring Begin on channel 3
[2024-03-31 02:52:14] DEBUG[2737]: sig_analog.c:3729 analog_handle_init_event: channel (3) - signaling (5) - event (ANALOG_EVENT_RINGBEGIN)
[2024-03-31 02:52:14] WARNING[2737]: sig_analog.c:3741 analog_handle_init_event: Can't start PBX immediately, must wait for Caller ID / distinctive ring
[2024-03-31 02:52:15] DEBUG[2737]: chan_dahdi.c:11896 do_monitor: Monitor doohicky got event Ring/Answered on channel 3
[2024-03-31 02:52:15] DEBUG[2737]: sig_analog.c:3729 analog_handle_init_event: channel (3) - signaling (5) - event (ANALOG_EVENT_RINGOFFHOOK)
[2024-03-31 02:52:15] DEBUG[2737][C-00000001]: channel_internal_api.c:703 ast_channel_nativeformats_set:  <initializing>: Formats: (none)
[2024-03-31 02:52:15] DEBUG[2737][C-00000001]: channel_internal_api.c:713 ast_channel_nativeformats_set:  Channel is being initialized or destroyed
[2024-03-31 02:52:15] DEBUG[2737][C-00000001]: stasis.c:580 stasis_topic_create_with_detail: Creating topic. name: channel:1711853535.0, detail:
[2024-03-31 02:52:15] DEBUG[2737][C-00000001]: stasis.c:614 stasis_topic_create_with_detail: Topic 'channel:1711853535.0': 0x7f6cac004300 created
[2024-03-31 02:52:15] DEBUG[2737][C-00000001]: channel.c:949 __ast_channel_alloc_ap: Channel 0x7f6cac001710 'DAHDI/3-1' allocated
[2024-03-31 02:52:15] DEBUG[2737][C-00000001]: channel_internal_api.c:703 ast_channel_nativeformats_set:  DAHDI/3-1: Formats: (ulaw)
[2024-03-31 02:52:15] DEBUG[2737][C-00000001]: channel_internal_api.c:721 ast_channel_nativeformats_set:  New topology set
[2024-03-31 02:52:15] DEBUG[2694]: stasis.c:580 stasis_topic_create_with_detail: Creating topic. name: channel:1711853535.1, detail:
[2024-03-31 02:52:15] DEBUG[2694]: stasis.c:614 stasis_topic_create_with_detail: Topic 'channel:1711853535.1': 0x7f6d50002530 created
[2024-03-31 02:52:15] DEBUG[2737][C-00000001]: dsp.c:510 ast_tone_detect_init: Setup tone 1100 Hz, 500 ms, block_size=160, hits_required=21
[2024-03-31 02:52:15] DEBUG[2737][C-00000001]: dsp.c:510 ast_tone_detect_init: Setup tone 2100 Hz, 2600 ms, block_size=160, hits_required=116
[2024-03-31 02:52:15] DEBUG[2737][C-00000001]: dsp.c:1797 ast_dsp_set_busy_pattern: dsp busy pattern set to 0,0,0,0
[2024-03-31 02:52:15] DEBUG[2694]: stasis.c:443 topic_dtor: Destroying topic. name: channel:1711853535.1, detail:
[2024-03-31 02:52:15] DEBUG[2694]: stasis.c:451 topic_dtor: Topic 'channel:1711853535.1': 0x7f6d50002530 destroyed
[2024-03-31 02:52:15] DEBUG[2694]: res_odbc.c:965 _ast_odbc_request_obj2: Reusing ODBC handle 0x1bf2680 from class 'asteriskcdrdb'
[2024-03-31 02:52:15] DEBUG[2682]: devicestate.c:466 do_state_change: Changing state for DAHDI/3 - state 2 (In use)
[2024-03-31 02:52:15] DEBUG[2694]: cel_odbc.c:782 odbc_log: Executing SQL statement: [INSERT INTO cel (eventtype, eventtime, cid_name, cid_num, cid_ani, cid_rdnis, cid_dnid, exten, context, channame, appname, appdata, amaflags, accountcode, uniqueid, linkedid, peer, userdeftype, extra) VALUES ('CHAN_START', {ts '2024-03-31 02:52:15.439706'}, '', '', '', '', '', 's', 'from-analog', 'DAHDI/3-1', '', '', 3, '', '1711853535.0', '1711853535.0', '', '', '')]
[2024-03-31 02:52:15] DEBUG[10051]: sig_analog.c:1742 __analog_ss_thread: __analog_ss_thread 3
    -- Starting simple switch on 'DAHDI/3-1'
[2024-03-31 02:52:15] DEBUG[2771]: app_queue.c:2721 device_state_cb: Device 'DAHDI/3' changed to state '2' (In use) but we don't care because they're not a member of any queue.
[2024-03-31 02:52:15] DEBUG[2694]: res_odbc.c:808 ast_odbc_release_obj: Releasing ODBC handle 0x1bf2680 into pool
[2024-03-31 02:52:25] DEBUG[10051][C-00000001]: pbx.c:2939 pbx_extension_helper: Launching 'NoOp'
    -- Executing [s@from-analog:1] NoOp("DAHDI/3-1", "Entering from-dahdi with DID == ") in new stack
[2024-03-31 02:52:25] DEBUG[10051][C-00000001]: pbx.c:2939 pbx_extension_helper: Launching 'Ringing'
    -- Executing [s@from-analog:2] Ringing("DAHDI/3-1", "") in new stack
... continues ...

If this is the issue, would it be possible to add a delay on FreePBX? Or this might be due to a wrong config somewhere that is causing the signal to go off-hook.

[david55]

@ngzeng

Ringing

This is not a meaningful thing to do on an unanswered analogue FXO line. I suppose it might cause DAHDI to go off hook, in order to be able to send the ringback tone, which is going to break CID after first ring.

[Stewart1 (Stewart)]

Just for laughs, I attempted to decode the caller ID info in your test call. Result was MDMF format, but with a message type 8 that I don’t recognize. Unrecognized sub-messages should be ignored, but perhaps Asterisk chokes on it. However, given that it’s properly formatted and has a correct checksum, I suspect that a small patch would enable Asterisk to read it.

(last 4 digits of calling number redacted)

[ngzeng (Kevin)]

Almost like you read my mind, you arrived just in time. I was reading a research paper on the topic and was about to dive into the world of spectrum analysis and try to decode the signal by myself.

From your results and following this table taken from the paper:

You are right, the formatting looks alright, even the date and time are correct. So, the HH42L is sending the Caller ID, but with a wrong or different “message type” code (I think the first 2 bytes/first hexadecimal?) that asterisk isn’t recognizing.

With this results, I feel that we are close to solving this issue. @Stewart1 What would you suggest, would you (I would like to help, but I think this is getting way over my abilities) be able to advise on a temporary fix on the code that I can apply to my testing rig and come back with the results?

Also, should this topic be a ticket on FreePBX or an issue on Github for the developers?

[Stewart1 (Stewart)]

Here is the perl script I made to read the output_rx.wav file and print the message in hex. It’s pretty dumb, so you need to ignore the 55s (seizure signal) at the front and noise garbage at the end.

#!/usr/bin/perl -w

open(IN, $ARGV[0]) or die;      # arg is wav file to read
binmode(IN);
read(IN, $buf, 44) or die;      # skip wav header, we assume 8 kHz 16bit mono
read(IN, $buf, 8000 * 2 * 20) or die; # assume CID in first 20 seconds
@sig = unpack("s*", $buf);            # list of sample values;
$lastbit = $lastup = $lastdn = 0;
for ($i = 0; $i < @sig - 1; ++$i) { # crude demodulator
    if ($sig[$i + 1] >= 0 && $sig[$i] < 0) {
        $lastbit = ($i - $lastup < 5) ? 0 : 1;
        $lastup = $i;
    }
    if ($sig[$i + 1] < 0 && $sig[$i] >= 0) {
        $lastbit = ($i - $lastdn < 5) ? 0 : 1;
        $lastdn = $i;
    }
    $demod[$i] = $lastbit;
}
$sseen = 0;                                    # seizure seen
for ($i = 0; $i < @demod - 80; ++$i) { # look for characters
    next unless $demod[$i] && !$demod[$i + 1]; # wait for start bit
    $ch = 0;
    for ($j = 0; $j < 8; ++$j) {
        $ch = ($ch >> 1) | ($demod[$i + int($j * 6.667 + 11)] << 7);
    }
    ++$sseen if $ch == 0x55;
    printf "%02X ", $ch if $sseen;
    $i += 61;
}

I know nothing about the caller ID decode in Asterisk but will take a look if I get a chance.