Caller ID Issue with BT Featurelines

I have a customer with two BT Featurelines and a standard fax line using Elastix 1.6 (64bit). The fax line works perfectly but the BT Featurelines have stopped working. The server was actually installed about a year ago and I remember when the server was first installed there was an issue with Caller ID being received so I made some changes to the chan_dahdi module as described here and that fixed things. However, without making any changes to the system inbound calls on the BT Featurelines have stopped working. I can see the call coming in if I look at the logs, but it times out and Asterisk hangs up the call. However, the person calling still hears ringing even though Asterisk has hung up. If the caller doesn’t hangup then Asterisk detects another call, which times out and Asterisk hangs up again.

The weirdest thing is that when the call first comes in Asterisk detects the Caller ID and it gets a ring event afterwards, but it still times out and hangs up the call! Here is a sample log of a failed call with Caller ID enabled:

[Nov 23 00:51:18] DEBUG[27567] chan_dahdi.c: Monitor doohicky got event Polarity Reversal on channel 12 [Nov 23 00:51:18] VERBOSE[27567] logger.c: == Starting post polarity CID detection on channel 12 [Nov 23 00:51:18] VERBOSE[10845] logger.c: -- Starting simple switch on 'DAHDI/12-1' [Nov 23 00:51:19] NOTICE[10845] chan_dahdi.c: CallerID number: 01904XXXXXX, name: (null), flags=4 [Nov 23 00:51:19] DEBUG[10845] chan_dahdi.c: Exception on 23, channel 12 [Nov 23 00:51:19] DEBUG[10845] chan_dahdi.c: Got event Ring Begin(18) on channel 12 (index 0) [Nov 23 00:51:23] WARNING[10845] chan_dahdi.c: CID timed out waiting for ring. Exiting simple switch [Nov 23 00:51:23] DEBUG[10845] channel.c: Hanging up channel 'DAHDI/12-1' [Nov 23 00:51:23] DEBUG[10845] chan_dahdi.c: dahdi_hangup(DAHDI/12-1) [Nov 23 00:51:23] DEBUG[10845] chan_dahdi.c: Hangup: channel: 12 index = 0, normal = 23, callwait = -1, thirdcall = -1 [Nov 23 00:51:23] DEBUG[10845] chan_dahdi.c: disabled echo cancellation on channel 12 [Nov 23 00:51:23] DEBUG[10845] chan_dahdi.c: Set option TDD MODE, value: OFF(0) on DAHDI/12-1 [Nov 23 00:51:23] DEBUG[10845] chan_dahdi.c: Updated conferencing on 12, with 0 conference users [Nov 23 00:51:23] VERBOSE[10845] logger.c: -- Hungup 'DAHDI/12-1' [Nov 23 00:51:23] DEBUG[10845] devicestate.c: Notification of state change to be queued on device/channel DAHDI/12 [Nov 23 00:51:23] DEBUG[27557] devicestate.c: No provider found, checking channel drivers for DAHDI - 12 [Nov 23 00:51:23] DEBUG[27557] devicestate.c: Changing state for DAHDI/12 - state 0 (Unknown) [Nov 23 00:51:23] DEBUG[27562] app_queue.c: Device 'DAHDI/12' changed to state '0' (Unknown) but we don't care because they're not a member of any [Nov 23 00:51:34] DEBUG[27567] chan_dahdi.c: Monitor doohicky got event Polarity Reversal on channel 12 [Nov 23 00:51:34] VERBOSE[27567] logger.c: == Starting post polarity CID detection on channel 12 [Nov 23 00:51:34] VERBOSE[10847] logger.c: -- Starting simple switch on 'DAHDI/12-1' [Nov 23 00:51:34] NOTICE[10847] chan_dahdi.c: Ignoring event 2 (Ring/Answered) due to waiting for CID, samples=1920

I have upgraded the server from Elastix 1.5 to 1.6 so the server is using a newer Kernel (2.6.18-164) and Asterisk (1.4.36) / Dahdi (2.3.0.1-3) versions but this hasn’t fixed the problem. I have tried modifying the chan_dahdi module as described in the link above but this hasn’t made any difference. Also, the CID wait time is already set to 4000 now by default in chan_dahdi.c. I have also tried using the fwringdtect=1 option, but again this hasn’t made any difference. The only way I can get incoming calls to work is if I disable Caller ID. This fixes the ringing issue as calls are received but obviously creates a new issue as Caller ID doesn’t work anymore. Here is a sample chan_dahdi.c log of a successful call with Caller ID disabled (Call hungup after about 15secs):

[Nov 24 17:39:48] DEBUG[11512] chan_dahdi.c: Monitor doohicky got event Polarity Reversal on channel 10 [Nov 24 17:39:48] DEBUG[18810] chan_dahdi.c: Requested indication 3 on channel DAHDI/10-1 [Nov 24 17:39:48] DEBUG[18810] chan_dahdi.c: Took DAHDI/10-1 off hook [Nov 24 17:39:48] DEBUG[18810] chan_dahdi.c: Enabled echo cancellation on channel 10 [Nov 24 17:39:48] DEBUG[18810] chan_dahdi.c: No echo training requested [Nov 24 17:39:48] DEBUG[18810] chan_dahdi.c: Requested indication -1 on channel DAHDI/10-1 [Nov 24 17:39:49] DEBUG[18810] chan_dahdi.c: Exception on 21, channel 10 [Nov 24 17:39:49] DEBUG[18810] chan_dahdi.c: Got event Polarity Reversal(17) on channel 10 (index 0) [Nov 24 17:39:49] DEBUG[18810] chan_dahdi.c: Ignoring Polarity switch to IDLE on channel 10, state 6 [Nov 24 17:39:49] DEBUG[18810] chan_dahdi.c: Polarity Reversal event occured - DEBUG 2: channel 10, state 6, pol= 0, aonp= 0, honp= 0, pdelay= 600, tv= 2130200338 [Nov 24 17:40:02] DEBUG[18810] chan_dahdi.c: Exception on 21, channel 10 [Nov 24 17:40:02] DEBUG[18810] chan_dahdi.c: Got event On hook(1) on channel 10 (index 0) [Nov 24 17:40:02] DEBUG[18810] chan_dahdi.c: disabled echo cancellation on channel 10 [Nov 24 17:40:02] DEBUG[18810] chan_dahdi.c: dahdi_hangup(DAHDI/10-1) [Nov 24 17:40:02] DEBUG[18810] chan_dahdi.c: Hangup: channel: 10 index = 0, normal = 21, callwait = -1, thirdcall = -1 [Nov 24 17:40:02] DEBUG[18810] chan_dahdi.c: disabled echo cancellation on channel 10

Its strange because about the same time that Asterisk detects a ring event with CID enabled, with CID disabled Asterisk detects a polarity reversal event instead. For information, the dahdi Caller ID settings are set to ‘cidsignalling=v23’ and ‘cidstart=polarity’, and the signalling is set to ‘signalling=fxs_ks’.

If anyone has any ideas what the issue could be then I would be grateful for any assistance offered!

Thanks,
Richard

[I have also posted this issue on the Elastix forum]