Problem with CallerID in Grandstream HT813

bug

#1

Product Model:HT813
Hardware Version:V1.1A Part Number – 9610006311A
Software Version:Program – 1.0.3.12 Bootloader – 1.0.3.1 Core – 1.0.3.6 Base – 1.0.3.11
CPE – 1.0.1.137
Sometimes the function of determining the number does not work.

The first part of the log in the case when the number is determined. The second part, when the number was not decrypted, although events of the form GSDSP :: event_handler_chan, detected DTMF 2 from cordless on port 1 were.

Part first

2019-12-25 23:18:12	Local7.Debug	127.0.0.1	HT813 [00:0b:82:e6:ce:fe] [1.0.3.12]GSDSP::event_handler_chan, detected DTMF 8 from cordless on port 1
2019-12-25 23:18:12	Local7.Debug	127.0.0.1	HT813 [00:0b:82:e6:ce:fe] [1.0.3.12]EventManager::run: Dispatching event 16 (PHONE_DTMF_DETECTED) on port 1:0
2019-12-25 23:18:12	Local7.Debug	127.0.0.1	HT813 [00:0b:82:e6:ce:fe] [1.0.3.12] LIBGSDSP: CSS: 541080969, In API callback event = 161, inst = 2054
2019-12-25 23:18:12	Local7.Debug	127.0.0.1	HT813 [00:0b:82:e6:ce:fe] [1.0.3.12] LIBGSDSP: CSS: 541102969, In API callback event = 143, inst = 2054
2019-12-25 23:18:13	Local7.Debug	127.0.0.1	HT813 [00:0b:82:e6:ce:fe] [1.0.3.12] LIBGSDSP: CSS: 541153003, In API callback event = 162, inst = 2054
2019-12-25 23:18:13	Local7.Debug	127.0.0.1	HT813 [00:0b:82:e6:ce:fe] [1.0.3.12] LIBGSDSP: CSS: 541153055, p_suppressFxoTone:118 Warning:: new SIG_ON received before timer for previous SIG_ON has expired
2019-12-25 23:18:13	Local7.Debug	127.0.0.1	HT813 [00:0b:82:e6:ce:fe] [1.0.3.12] LIBGSDSP: CSS: 541175002, In API callback event = 146, inst = 2054
2019-12-25 23:18:13	Local7.Debug	127.0.0.1	HT813 [00:0b:82:e6:ce:fe] [1.0.3.12]GSDSP::event_handler_chan, detected DTMF 2 from cordless on port 1
2019-12-25 23:18:13	Local7.Debug	127.0.0.1	HT813 [00:0b:82:e6:ce:fe] [1.0.3.12]EventManager::run: Dispatching event 16 (PHONE_DTMF_DETECTED) on port 1:0
2019-12-25 23:18:13	Local7.Debug	127.0.0.1	HT813 [00:0b:82:e6:ce:fe] [1.0.3.12] LIBGSDSP: CSS: 541215003, In API callback event = 161, inst = 2054
2019-12-25 23:18:13	Local7.Debug	127.0.0.1	HT813 [00:0b:82:e6:ce:fe] [1.0.3.12] LIBGSDSP: CSS: 541235005, In API callback event = 143, inst = 2054
2019-12-25 23:18:13	Local7.Debug	127.0.0.1	HT813 [00:0b:82:e6:ce:fe] [1.0.3.12] LIBGSDSP: CSS: 541297263, In API callback event = 162, inst = 2054
2019-12-25 23:18:13	Local7.Debug	127.0.0.1	HT813 [00:0b:82:e6:ce:fe] [1.0.3.12] LIBGSDSP: CSS: 541297313, p_suppressFxoTone:118 Warning:: new SIG_ON received before timer for previous SIG_ON has expired
2019-12-25 23:18:13	Local7.Debug	127.0.0.1	HT813 [00:0b:82:e6:ce:fe] [1.0.3.12] LIBGSDSP: CSS: 541317263, In API callback event = 156, inst = 2054
2019-12-25 23:18:13	Local7.Debug	127.0.0.1	HT813 [00:0b:82:e6:ce:fe] [1.0.3.12]GSDSP::event_handler_chan, detected DTMF C from cordless on port 1
2019-12-25 23:18:13	Local7.Debug	127.0.0.1	HT813 [00:0b:82:e6:ce:fe] [1.0.3.12]EventManager::run: Dispatching event 16 (PHONE_DTMF_DETECTED) on port 1:0
2019-12-25 23:18:13	Local7.Debug	127.0.0.1	HT813 [00:0b:82:e6:ce:fe] [1.0.3.12] LIBGSDSP: CSS: 541358997, In API callback event = 161, inst = 2054
2019-12-25 23:18:13	Local7.Debug	127.0.0.1	HT813 [00:0b:82:e6:ce:fe] [1.0.3.12] LIBGSDSP: CSS: 541378995, In API callback event = 143, inst = 2054
2019-12-25 23:18:13	Local7.Debug	127.0.0.1	HT813 [00:0b:82:e6:ce:fe] [1.0.3.12]Nuvoton::run(), FXO_RING_START event received on port 1 ch 0
2019-12-25 23:18:13	Local7.Debug	127.0.0.1	HT813 [00:0b:82:e6:ce:fe] [1.0.3.12]EventManager::run: Dispatching event 36 (LINE_RING_START) on port 1:0
2019-12-25 23:18:13	Local7.Debug	127.0.0.1	HT813 [00:0b:82:e6:ce:fe] [1.0.3.12]ATACtrl::processFxoLineRingStart on port 1:0, Cancel PSTN Hangup Detect Timer
2019-12-25 23:18:13	Local7.Debug	127.0.0.1	HT813 [00:0b:82:e6:ce:fe] [1.0.3.12]ATACtrl::processFxoLineRingStart on port 1:0, Start PSTN Hangup Detect Timer = 6
2019-12-25 23:18:13	Local7.Debug	127.0.0.1	HT813 [00:0b:82:e6:ce:fe] [1.0.3.12]ATACtrl::processFxoLineRingStart on port 1:0, status = FXO_INCOMING_RING/CALL_IDLE, fxoRingCnt[1] = 1
2019-12-25 23:18:13	Local7.Debug	127.0.0.1	HT813 [00:0b:82:e6:ce:fe] [1.0.3.12] LIBGSDSP: CSS: 541908971, In API callback event = 137, inst = 2053
2019-12-25 23:18:13	Local7.Debug	127.0.0.1	HT813 [00:0b:82:e6:ce:fe] [1.0.3.12] LIBGSDSP: CSS: 542048969, In API callback event = 140, inst = 2053
2019-12-25 23:18:14	Local7.Debug	127.0.0.1	HT813 [00:0b:82:e6:ce:fe] [1.0.3.12] LIBGSDSP: CSS: 542378985, In API callback event = 139, inst = 2053
2019-12-25 23:18:14	Local7.Debug	127.0.0.1	HT813 [00:0b:82:e6:ce:fe] [1.0.3.12] LIBGSDSP: CSS: 542678977, In API callback event = 140, inst = 2053
2019-12-25 23:18:14	Local7.Debug	127.0.0.1	HT813 [00:0b:82:e6:ce:fe] [1.0.3.12]Nuvoton::decodeDtmfCidNumber, CID Caller Number *******82
2019-12-25 23:18:14	Local7.Debug	127.0.0.1	HT813 [00:0b:82:e6:ce:fe] [1.0.3.12]EventManager::run: Dispatching event 42 (FXO_CID_RECEIVED) on port 1:0
2019-12-25 23:18:14	Local7.Debug	127.0.0.1	HT813 [00:0b:82:e6:ce:fe] [1.0.3.12]SigCtrl::processFxoCallerIdReceived, number = ********82
2019-12-25 23:18:14	Local7.Debug	127.0.0.1	HT813 [00:0b:82:e6:ce:fe] [1.0.3.12]SigCtrl::processFxoCallerIdReceived, Update FXO CID is disabled
2019-12-25 23:18:14	Local7.Debug	127.0.0.1	HT813 [00:0b:82:e6:ce:fe] [1.0.3.12]ATACtrl::processFxoCallerIdReceived on port 1:0, status = FXO_INCOMING_RING/CALL_IDLE
2019-12-25 23:18:14	Local7.Debug	127.0.0.1	HT813 [00:0b:82:e6:ce:fe] [1.0.3.12]ATACtrl::processFxoCallerIdReceived, cidInfo[1].callerNumber = ********82
2019-12-25 23:18:14	Local7.Debug	127.0.0.1	HT813 [00:0b:82:e6:ce:fe] [1.0.3.12] LIBGSDSP: CSS: 543007289, In API callback event = 139, inst = 2053
2019-12-25 23:18:14	Local7.Debug	127.0.0.1	HT813 [00:0b:82:e6:ce:fe] [1.0.3.12] LIBGSDSP: CSS: 543091009, In API callback event = 162, inst = 2054
2019-12-25 23:18:14	Local7.Debug	127.0.0.1	HT813 [00:0b:82:e6:ce:fe] [1.0.3.12] LIBGSDSP: CSS: 543091068, p_suppressFxoTone:118 Warning:: new SIG_ON received before timer for previous SIG_ON has expired
2019-12-25 23:18:14	Local7.Debug	127.0.0.1	HT813 [00:0b:82:e6:ce:fe] [1.0.3.12] LIBGSDSP: CSS: 543111007, In API callback event = 154, inst = 2054
2019-12-25 23:18:14	Local7.Debug	127.0.0.1	HT813 [00:0b:82:e6:ce:fe] [1.0.3.12]GSDSP::event_handler_chan, detected DTMF A from cordless on port 1
2019-12-25 23:18:14	Local7.Debug	127.0.0.1	HT813 [00:0b:82:e6:ce:fe] [1.0.3.12]EventManager::run: Dispatching event 16 (PHONE_DTMF_DETECTED) on port 1:0

Part second

2019-12-26 03:36:37	Local7.Debug	127.0.0.1	HT813 [00:0b:82:e6:ce:fe] [1.0.3.12]GSDSP::event_handler_chan, detected DTMF 6 from cordless on port 1
2019-12-26 03:36:37	Local7.Debug	127.0.0.1	HT813 [00:0b:82:e6:ce:fe] [1.0.3.12]EventManager::run: Dispatching event 16 (PHONE_DTMF_DETECTED) on port 1:0
2019-12-26 03:36:37	Local7.Debug	127.0.0.1	HT813 [00:0b:82:e6:ce:fe] [1.0.3.12] LIBGSDSP: CSS: 3160604082, In API callback event = 161, inst = 2054
2019-12-26 03:36:37	Local7.Debug	127.0.0.1	HT813 [00:0b:82:e6:ce:fe] [1.0.3.12] LIBGSDSP: CSS: 3160624348, In API callback event = 143, inst = 2054
2019-12-26 03:36:37	Local7.Debug	127.0.0.1	HT813 [00:0b:82:e6:ce:fe] [1.0.3.12] LIBGSDSP: CSS: 3160674350, In API callback event = 162, inst = 2054
2019-12-26 03:36:37	Local7.Debug	127.0.0.1	HT813 [00:0b:82:e6:ce:fe] [1.0.3.12] LIBGSDSP: CSS: 3160674432, p_suppressFxoTone:118 Warning:: new SIG_ON received before timer for previous SIG_ON has expired
2019-12-26 03:36:37	Local7.Debug	127.0.0.1	HT813 [00:0b:82:e6:ce:fe] [1.0.3.12] LIBGSDSP: CSS: 3160696079, In API callback event = 145, inst = 2054
2019-12-26 03:36:37	Local7.Debug	127.0.0.1	HT813 [00:0b:82:e6:ce:fe] [1.0.3.12]GSDSP::event_handler_chan, detected DTMF 1 from cordless on port 1
2019-12-26 03:36:37	Local7.Debug	127.0.0.1	HT813 [00:0b:82:e6:ce:fe] [1.0.3.12]EventManager::run: Dispatching event 16 (PHONE_DTMF_DETECTED) on port 1:0
2019-12-26 03:36:37	Local7.Debug	127.0.0.1	HT813 [00:0b:82:e6:ce:fe] [1.0.3.12] LIBGSDSP: CSS: 3160746083, In API callback event = 161, inst = 2054
2019-12-26 03:36:37	Local7.Debug	127.0.0.1	HT813 [00:0b:82:e6:ce:fe] [1.0.3.12] LIBGSDSP: CSS: 3160768079, In API callback event = 143, inst = 2054
2019-12-26 03:36:37	Local7.Debug	127.0.0.1	HT813 [00:0b:82:e6:ce:fe] [1.0.3.12] LIBGSDSP: CSS: 3160818078, In API callback event = 162, inst = 2054
2019-12-26 03:36:37	Local7.Debug	127.0.0.1	HT813 [00:0b:82:e6:ce:fe] [1.0.3.12] LIBGSDSP: CSS: 3160818170, p_suppressFxoTone:118 Warning:: new SIG_ON received before timer for previous SIG_ON has expired
2019-12-26 03:36:37	Local7.Debug	127.0.0.1	HT813 [00:0b:82:e6:ce:fe] [1.0.3.12] LIBGSDSP: CSS: 3160840078, In API callback event = 145, inst = 2054
2019-12-26 03:36:37	Local7.Debug	127.0.0.1	HT813 [00:0b:82:e6:ce:fe] [1.0.3.12]GSDSP::event_handler_chan, detected DTMF 1 from cordless on port 1
2019-12-26 03:36:37	Local7.Debug	127.0.0.1	HT813 [00:0b:82:e6:ce:fe] [1.0.3.12]EventManager::run: Dispatching event 16 (PHONE_DTMF_DETECTED) on port 1:0
2019-12-26 03:36:37	Local7.Debug	127.0.0.1	HT813 [00:0b:82:e6:ce:fe] [1.0.3.12] LIBGSDSP: CSS: 3160880114, In API callback event = 161, inst = 2054
2019-12-26 03:36:37	Local7.Debug	127.0.0.1	HT813 [00:0b:82:e6:ce:fe] [1.0.3.12] LIBGSDSP: CSS: 3160900121, In API callback event = 143, inst = 2054
2019-12-26 03:36:37	Local7.Debug	127.0.0.1	HT813 [00:0b:82:e6:ce:fe] [1.0.3.12] LIBGSDSP: CSS: 3160962116, In API callback event = 162, inst = 2054
2019-12-26 03:36:37	Local7.Debug	127.0.0.1	HT813 [00:0b:82:e6:ce:fe] [1.0.3.12] LIBGSDSP: CSS: 3160962173, p_suppressFxoTone:118 Warning:: new SIG_ON received before timer for previous SIG_ON has expired
2019-12-26 03:36:37	Local7.Debug	127.0.0.1	HT813 [00:0b:82:e6:ce:fe] [1.0.3.12] LIBGSDSP: CSS: 3160982124, In API callback event = 146, inst = 2054
2019-12-26 03:36:37	Local7.Debug	127.0.0.1	HT813 [00:0b:82:e6:ce:fe] [1.0.3.12]GSDSP::event_handler_chan, detected DTMF 2 from cordless on port 1
2019-12-26 03:36:37	Local7.Debug	127.0.0.1	HT813 [00:0b:82:e6:ce:fe] [1.0.3.12]EventManager::run: Dispatching event 16 (PHONE_DTMF_DETECTED) on port 1:0
2019-12-26 03:36:37	Local7.Debug	127.0.0.1	HT813 [00:0b:82:e6:ce:fe] [1.0.3.12] LIBGSDSP: CSS: 3161024374, In API callback event = 161, inst = 2054
2019-12-26 03:36:37	Local7.Debug	127.0.0.1	HT813 [00:0b:82:e6:ce:fe] [1.0.3.12] LIBGSDSP: CSS: 3161044382, In API callback event = 143, inst = 2054
2019-12-26 03:36:38	Local7.Debug	127.0.0.1	HT813 [00:0b:82:e6:ce:fe] [1.0.3.12] LIBGSDSP: CSS: 3161096096, In API callback event = 162, inst = 2054
2019-12-26 03:36:38	Local7.Debug	127.0.0.1	HT813 [00:0b:82:e6:ce:fe] [1.0.3.12] LIBGSDSP: CSS: 3161096148, p_suppressFxoTone:118 Warning:: new SIG_ON received before timer for previous SIG_ON has expired
2019-12-26 03:36:38	Local7.Debug	127.0.0.1	HT813 [00:0b:82:e6:ce:fe] [1.0.3.12] LIBGSDSP: CSS: 3161116098, In API callback event = 146, inst = 2054
2019-12-26 03:36:38	Local7.Debug	127.0.0.1	HT813 [00:0b:82:e6:ce:fe] [1.0.3.12]GSDSP::event_handler_chan, detected DTMF 2 from cordless on port 1
2019-12-26 03:36:38	Local7.Debug	127.0.0.1	HT813 [00:0b:82:e6:ce:fe] [1.0.3.12]EventManager::run: Dispatching event 16 (PHONE_DTMF_DETECTED) on port 1:0
2019-12-26 03:36:38	Local7.Debug	127.0.0.1	HT813 [00:0b:82:e6:ce:fe] [1.0.3.12] LIBGSDSP: CSS: 3161168106, In API callback event = 161, inst = 2054
2019-12-26 03:36:38	Local7.Debug	127.0.0.1	HT813 [00:0b:82:e6:ce:fe] [1.0.3.12] LIBGSDSP: CSS: 3161188095, In API callback event = 143, inst = 2054
2019-12-26 03:36:38	Local7.Debug	127.0.0.1	HT813 [00:0b:82:e6:ce:fe] [1.0.3.12] LIBGSDSP: CSS: 3161238079, In API callback event = 162, inst = 2054
2019-12-26 03:36:38	Local7.Debug	127.0.0.1	HT813 [00:0b:82:e6:ce:fe] [1.0.3.12] LIBGSDSP: CSS: 3161238131, p_suppressFxoTone:118 Warning:: new SIG_ON received before timer for previous SIG_ON has expired
2019-12-26 03:36:38	Local7.Debug	127.0.0.1	HT813 [00:0b:82:e6:ce:fe] [1.0.3.12] LIBGSDSP: CSS: 3161260078, In API callback event = 156, inst = 2054
2019-12-26 03:36:38	Local7.Debug	127.0.0.1	HT813 [00:0b:82:e6:ce:fe] [1.0.3.12]GSDSP::event_handler_chan, detected DTMF C from cordless on port 1
2019-12-26 03:36:38	Local7.Debug	127.0.0.1	HT813 [00:0b:82:e6:ce:fe] [1.0.3.12]EventManager::run: Dispatching event 16 (PHONE_DTMF_DETECTED) on port 1:0
2019-12-26 03:36:38	Local7.Debug	127.0.0.1	HT813 [00:0b:82:e6:ce:fe] [1.0.3.12] LIBGSDSP: CSS: 3161300080, In API callback event = 161, inst = 2054
2019-12-26 03:36:38	Local7.Debug	127.0.0.1	HT813 [00:0b:82:e6:ce:fe] [1.0.3.12] LIBGSDSP: CSS: 3161320078, In API callback event = 143, inst = 2054
2019-12-26 03:36:38	Local7.Debug	127.0.0.1	HT813 [00:0b:82:e6:ce:fe] [1.0.3.12]Nuvoton::run(), FXO_RING_START event received on port 1 ch 0
2019-12-26 03:36:38	Local7.Debug	127.0.0.1	HT813 [00:0b:82:e6:ce:fe] [1.0.3.12]EventManager::run: Dispatching event 36 (LINE_RING_START) on port 1:0
2019-12-26 03:36:38	Local7.Debug	127.0.0.1	HT813 [00:0b:82:e6:ce:fe] [1.0.3.12]ATACtrl::processFxoLineRingStart on port 1:0, Cancel PSTN Hangup Detect Timer
2019-12-26 03:36:38	Local7.Debug	127.0.0.1	HT813 [00:0b:82:e6:ce:fe] [1.0.3.12]ATACtrl::processFxoLineRingStart on port 1:0, Start PSTN Hangup Detect Timer = 6
2019-12-26 03:36:38	Local7.Debug	127.0.0.1	HT813 [00:0b:82:e6:ce:fe] [1.0.3.12]ATACtrl::processFxoLineRingStart on port 1:0, status = FXO_INCOMING_RING/CALL_IDLE, fxoRingCnt[1] = 1
2019-12-26 03:36:38	Local7.Debug	127.0.0.1	HT813 [00:0b:82:e6:ce:fe] [1.0.3.12] LIBGSDSP: CSS: 3161856120, In API callback event = 137, inst = 2053
2019-12-26 03:36:38	Local7.Debug	127.0.0.1	HT813 [00:0b:82:e6:ce:fe] [1.0.3.12] LIBGSDSP: CSS: 3161876112, In API callback event = 140, inst = 2053
2019-12-26 03:36:39	Local7.Debug	127.0.0.1	HT813 [00:0b:82:e6:ce:fe] [1.0.3.12] LIBGSDSP: CSS: 3162166087, In API callback event = 139, inst = 2053
2019-12-26 03:36:39	Local7.Debug	127.0.0.1	HT813 [00:0b:82:e6:ce:fe] [1.0.3.12] LIBGSDSP: CSS: 3162486084, In API callback event = 140, inst = 2053

**As far as I understand, an event should appear here Nuvoton::decodeDtmfCidNumber, CID Caller Number *******61122**

2019-12-26 03:36:39	Local7.Debug	127.0.0.1	HT813 [00:0b:82:e6:ce:fe] [1.0.3.12] LIBGSDSP: CSS: 3162816116, In API callback event = 139, inst = 2053
2019-12-26 03:36:39	Local7.Debug	127.0.0.1	HT813 [00:0b:82:e6:ce:fe] [1.0.3.12] LIBGSDSP: CSS: 3163042113, In API callback event = 162, inst = 2054
2019-12-26 03:36:39	Local7.Debug	127.0.0.1	HT813 [00:0b:82:e6:ce:fe] [1.0.3.12] LIBGSDSP: CSS: 3163042218, p_suppressFxoTone:118 Warning:: new SIG_ON received before timer for previous SIG_ON has expired
2019-12-26 03:36:39	Local7.Debug	127.0.0.1	HT813 [00:0b:82:e6:ce:fe] [1.0.3.12] LIBGSDSP: CSS: 3163064097, In API callback event = 154, inst = 2054
2019-12-26 03:36:39	Local7.Debug	127.0.0.1	HT813 [00:0b:82:e6:ce:fe] [1.0.3.12]GSDSP::event_handler_chan, detected DTMF A from cordless on port 1
2019-12-26 03:36:39	Local7.Debug	127.0.0.1	HT813 [00:0b:82:e6:ce:fe] [1.0.3.12]EventManager::run: Dispatching event 16 (PHONE_DTMF_DETECTED) on port 1:0

Thanks


#2

CallerD settings on the device


#3

I can’t tell if your problem is the DTMF tones or the incoming caller id,
for the tones you have to set RFC2833 for the incoming caller id try the various drop-down items (I normally use ETSI-FSK during ringing) do the same with “Caller ID Transport Type”.


#4

I can’t use the FSK format, because our PBX provides the caller ID in DTMF format. Basically, we determine the number, but there are cases when in the log after the lines

    GSDSP :: event_handler_chan, detected DTMF 8 from cordless on port 1
    GSDSP :: event_handler_chan, detected DTMF 2 from cordless on port 1
    GSDSP :: event_handler_chan, detected DTMF C from cordless on port 1

event does not appear
Nuvoton :: decodeDtmfCidNumber, CID Caller Number ****
that is, the numbers I see in the interval between events
GSDSP :: event_handler_chan, detected DTMF A from cordless on port 1
and
GSDSP :: event_handler_chan, detected DTMF C from cordless on port 1
But the event
Nuvoton :: decodeDtmfCidNumber, CID Caller Number ****
for some reason does not appear. And this happens somewhere in 5-10 percent of cases.
It happens that after a minute the same number rings and the device determines it. or vice versa, on the first call it determines, on subsequent calls it happens not.
In 1 part of the log, it is reflected when it determines, in 2 parts of the log, after the “detected DTMF C”, the detection event does not occur.
Thanks


#5

“Caller ID Transport Type”, as I understand it, is responsible for the transmission mode of the caller ID to our PBX. But the problem itself is that the device does not always decode the DTMF caller ID


#6

mine were just examples, if you think there’s a bug you should open a ticket.


#7

Thanks, I’ll try SysLog Extra Debug mode, maybe in this case I’ll be shown more detailed information about the operation of this function, and possible errors, after which I will write to the support service