I have Asterisk 11.8.1 running on Ubuntu Server 12.04 with a Digium 4 port analog card (1A4A00F) that I use for call filtering. It is configured as follows:
Port 1 FX0 connect to my provider (DAHDI/1)
Port 2 FXS connected to my home phones (DAHDI/2)
Port 3 FXS connected to a standalone answering machine (DAHDI/3)
Port 4 FXS not in use (DAHDI/4)
It has been running fine for about 10 months. The only software changes I have been making during that time are OS updates. Recently I have noticed that the caller ID is intermittently not being transmitted to my phones. Below is a debug log from both a call that successfully transmitted the caller ID and one that did not. Both calls took the same route through extensions.conf . I changed the caller ID names and numbers to protect the identity of the callers.
This call properly transmitted the caller ID number and name:
[Jan 19 18:27:56] DEBUG[1234] chan_dahdi.c: Monitor doohicky got event Ring Begin on channel 1
[Jan 19 18:27:56] DEBUG[1234] sig_analog.c: channel (1) - signaling (5) - event (ANALOG_EVENT_RINGBEGIN)
[Jan 19 18:27:59] DEBUG[1234] chan_dahdi.c: Monitor doohicky got event Ring/Answered on channel 1
[Jan 19 18:27:59] DEBUG[1234] sig_analog.c: channel (1) - signaling (5) - event (ANALOG_EVENT_RINGOFFHOOK)
[Jan 19 18:27:59] DEBUG[1234][C-00000000] dsp.c: Setup tone 1100 Hz, 500 ms, block_size=160, hits_required=21
[Jan 19 18:27:59] DEBUG[1234][C-00000000] dsp.c: Setup tone 2100 Hz, 2600 ms, block_size=160, hits_required=116
[Jan 19 18:27:59] DEBUG[1221] devicestate.c: Changing state for DAHDI/1 - state 2 (In use)
[Jan 19 18:27:59] DEBUG[1221] devicestate.c: device ‘DAHDI/1’ state ‘2’
[Jan 19 18:27:59] DEBUG[1529] sig_analog.c: __analog_ss_thread 1
[Jan 19 18:28:00] DEBUG[1529][C-00000000] chan_dahdi.c: CallerID number: 5555555555, name: SMITH JOHN , flags=0
[Jan 19 18:28:00] DEBUG[1529][C-00000000] pbx.c: Launching ‘NoOp’
[Jan 19 18:28:00] DEBUG[1529][C-00000000] pbx.c: Function CALLERID(number) result is ‘5555555555’
[Jan 19 18:28:00] DEBUG[1529][C-00000000] pbx.c: Function DB_EXISTS(whitelist/5555555555) result is ‘1’
[Jan 19 18:28:00] DEBUG[1529][C-00000000] pbx.c: Expression result is ‘1’
[Jan 19 18:28:00] DEBUG[1529][C-00000000] pbx.c: Launching ‘GotoIf’
[Jan 19 18:28:00] DEBUG[1529][C-00000000] pbx.c: Launching ‘Dial’
[Jan 19 18:28:00] DEBUG[1529][C-00000000] sig_analog.c: analog_available 2
[Jan 19 18:28:00] DEBUG[1529][C-00000000] chan_dahdi.c: Using channel 2
[Jan 19 18:28:00] DEBUG[1529][C-00000000] sig_analog.c: analog_request 2
[Jan 19 18:28:00] DEBUG[1529][C-00000000] dsp.c: Setup tone 1100 Hz, 500 ms, block_size=160, hits_required=21
[Jan 19 18:28:00] DEBUG[1529][C-00000000] dsp.c: Setup tone 2100 Hz, 2600 ms, block_size=160, hits_required=116
[Jan 19 18:28:00] DEBUG[1221] devicestate.c: Changing state for DAHDI/2 - state 2 (In use)
[Jan 19 18:28:00] DEBUG[1221] devicestate.c: device ‘DAHDI/2’ state ‘2’
[Jan 19 18:28:00] DEBUG[1529][C-00000000] channel_internal_api.c: Channel Call ID changing from [C-00000000] to [C-00000000]
[Jan 19 18:28:00] DEBUG[1529][C-00000000] rtp_engine.c: Can’t find native functions for channel ‘DAHDI/2-1’
[Jan 19 18:28:00] DEBUG[1529][C-00000000] sig_analog.c: CALLING CID_NAME: SMITH JOHN CID_NUM:: 5555555555
[Jan 19 18:28:00] DEBUG[1221] devicestate.c: Changing state for DAHDI/2 - n 19 18:28:00] DEBUG[1529][C-00000000] chan_dahdi.c: CallerID number: 5555555555, name: SMITH JOHN , flags=0
[Jan 19 18:28:00] DEBUG[1529][C-00000000] pbx.c: Launching ‘NoOp’
[Jan 19 18:28:00] DEBUG[1529][C-00000000] pbx.c: Function CALLERID(number) result is ‘5555555555’
[Jan 19 18:28:00] DEBUG[1529][C-00000000] pbx.c: Function DB_EXISTS(whitelist/5555555555) result is ‘1’
[Jan 19 18:28:00] DEBUG[1529][C-00000000] pbx.c: Expression result is ‘1’
[Jan 19 18:28:00] DEBUG[1529][C-00000000] pbx.c: Launching ‘GotoIf’
[Jan 19 18:28:00] DEBUG[1529][C-00000000] pbx.c: Launching ‘Dial’
[Jan 19 18:28:00] DEBUG[1529][C-00000000] sig_analog.c: analog_available 2
[Jan 19 18:28:00] DEBUG[1529][C-00000000] chan_dahdi.c: Using channel 2
[Jan 19 18:28:00] DEBUG[1529][C-00000000] sig_analog.c: analog_request 2
[Jan 19 18:28:00] DEBUG[1529][C-00000000] dsp.c: Setup tone 1100 Hz, 500 ms, block_size=160, hits_required=21
[Jan 19 18:28:00] DEBUG[1529][C-00000000] dsp.c: Setup tone 2100 Hz, 2600 ms, block_size=160, hits_required=116
[Jan 19 18:28:00] DEBUG[1221] devicestate.c: Changing state for DAHDI/2 - state 2 (In use)
[Jan 19 18:28:00] DEBUG[1221] devicestate.c: device ‘DAHDI/2’ state ‘2’
[Jan 19 18:28:00] DEBUG[1529][C-00000000] channel_internal_api.c: Channel Call ID changing from [C-00000000] to [C-00000000]
[Jan 19 18:28:00] DEBUG[1529][C-00000000] rtp_engine.c: Can’t find native functions for channel ‘DAHDI/2-1’
[Jan 19 18:28:00] DEBUG[1529][C-00000000] sig_analog.c: CALLING CID_NAME: SMITH JOHN CID_NUM:: 5555555555
[Jan 19 18:28:00] DEBUG[1221] devicestate.c: Changing state for DAHDI/2 - state 6 (Ringing)
[Jan 19 18:28:00] DEBUG[1221] devicestate.c: device ‘DAHDI/2’ state ‘6’
[Jan 19 18:28:00] DEBUG[1529][C-00000000] chan_dahdi.c: Requested indication 3 on channel DAHDI/1-1
[Jan 19 18:28:00] DEBUG[1529][C-00000000] chan_dahdi.c: Dropping frame since I’m still dialing on DAHDI/2-1…
[Jan 19 18:28:00] DEBUG[1529][C-00000000] chan_dahdi.c: Dropping frame since I’m still dialing on DAHDI/2-1…
[Jan 19 18:28:00] DEBUG[1529][C-00000000] chan_dahdi.c: Dropping frame since I’m still dialing on DAHDI/2-1…
This call failed to transmit the caller ID number. The caller ID name was null so it would be expected that there would be no caller ID name, but I would expect the number to be transmitted.
[Jan 20 10:18:09] DEBUG[1234] chan_dahdi.c: Monitor doohicky got event Ring Begin on channel 1
[Jan 20 10:18:09] DEBUG[1234] sig_analog.c: channel (1) - signaling (5) - event (ANALOG_EVENT_RINGBEGIN)
[Jan 20 10:18:11] DEBUG[1234] chan_dahdi.c: Monitor doohicky got event Ring/Answered on channel 1
[Jan 20 10:18:11] DEBUG[1234] sig_analog.c: channel (1) - signaling (5) - event (ANALOG_EVENT_RINGOFFHOOK)
[Jan 20 10:18:11] DEBUG[1234][C-00000009] dsp.c: Setup tone 1100 Hz, 500 ms, block_size=160, hits_required=21
[Jan 20 10:18:11] DEBUG[1234][C-00000009] dsp.c: Setup tone 2100 Hz, 2600 ms, block_size=160, hits_required=116
[Jan 20 10:18:11] DEBUG[1221] devicestate.c: Changing state for DAHDI/1 - state 2 (In use)
[Jan 20 10:18:11] DEBUG[1221] devicestate.c: device ‘DAHDI/1’ state ‘2’
[Jan 20 10:18:11] DEBUG[1881] sig_analog.c: __analog_ss_thread 1
[Jan 20 10:18:12] DEBUG[1881][C-00000009] chan_dahdi.c: CallerID number: 5555555555, name: (null), flags=4
[Jan 20 10:18:12] DEBUG[1881][C-00000009] pbx.c: Launching ‘NoOp’
[Jan 20 10:18:12] DEBUG[1881][C-00000009] pbx.c: Function CALLERID(number) result is ‘5555555555’
[Jan 20 10:18:12] DEBUG[1881][C-00000009] pbx.c: Function DB_EXISTS(whitelist/5555555555) result is ‘1’
[Jan 20 10:18:12] DEBUG[1881][C-00000009] pbx.c: Expression result is ‘1’
[Jan 20 10:18:12] DEBUG[1881][C-00000009] pbx.c: Launching ‘GotoIf’
[Jan 20 10:18:12] DEBUG[1881][C-00000009] pbx.c: Launching ‘Dial’
[Jan 20 10:18:12] DEBUG[1881][C-00000009] sig_analog.c: analog_available 2
[Jan 20 10:18:12] DEBUG[1881][C-00000009] chan_dahdi.c: Using channel 2
[Jan 20 10:18:12] DEBUG[1881][C-00000009] sig_analog.c: analog_request 2
[Jan 20 10:18:12] DEBUG[1881][C-00000009] dsp.c: Setup tone 1100 Hz, 500 ms, block_size=160, hits_required=21
[Jan 20 10:18:12] DEBUG[1881][C-00000009] dsp.c: Setup tone 2100 Hz, 2600 ms, block_size=160, hits_required=116
[Jan 20 10:18:12] DEBUG[1221] devicestate.c: Changing state for DAHDI/2 - state 2 (In use)
[Jan 20 10:18:12] DEBUG[1221] devicestate.c: device ‘DAHDI/2’ state ‘2’
[Jan 20 10:18:12] DEBUG[1881][C-00000009] channel_internal_api.c: Channel Call ID changing from [C-00000009] to [C-00000009]
[Jan 20 10:18:12] DEBUG[1881][C-00000009] rtp_engine.c: Can’t find native functions for channel ‘DAHDI/2-1’
[Jan 20 10:18:12] DEBUG[1881][C-00000009] sig_analog.c: CALLING CID_NAME: CID_NUM:: 5555555555
[Jan 20 10:18:12] DEBUG[1221] devicestate.c: Changing state for DAHDI/2 - state 6 (Ringing)
[Jan 20 10:18:12] DEBUG[1221] devicestate.c: device ‘DAHDI/2’ state ‘6’
[Jan 20 10:18:12] DEBUG[1881][C-00000009] chan_dahdi.c: Requested indication 3 on channel DAHDI/1-1
[Jan 20 10:18:12] DEBUG[1881][C-00000009] chan_dahdi.c: Dropping frame since I’m still dialing on DAHDI/2-1…
[Jan 20 10:18:12] DEBUG[1881][C-00000009] chan_dahdi.c: Dropping frame since I’m still dialing on DAHDI/2-1…
[Jan 20 10:18:12] DEBUG[1881][C-00000009] chan_dahdi.c: Dropping frame since I’m still dialing on DAHDI/2-1…
Any help in understanding why the second call did not transmitted the caller ID number and any suggestions on a fix is appreciated