After a hidden callerid incomming call, callerid not working

Asterisk Asterisk Support
1

It looks like if a call with correct callerid is comming in, it looks OK in the log
and on the handset: Set(“Zap/4-1”, “CALLERID(all)=”" <0406654556>")

But if next call got a hidden callerid, and the next call after that with callerid
on, it will give me the callerid: Set(“Zap/4-1”, “CALLERID(all)=”" <>")

Is the blank callerid destroying something?

Below is three incomming call, the incomming number on the first an the last is the
same and the one in the middle is a hidden (I think) callerid call!

[b]#########################

Here is a call with correct callerid

#########################
Incomming call number = 0406654556[/b]

[Apr 22 19:40:15] VERBOSE[3844] logger.c: == Starting post polarity CID detection on channel 4
[Apr 22 19:40:15] DEBUG[3844] dsp.c: dsp busy pattern set to 0,0
[Apr 22 19:40:15] VERBOSE[5412] logger.c: – Starting simple switch on ‘Zap/4-1’
[Apr 22 19:40:15] DEBUG[5412] chan_zap.c: Receiving DTMF cid on channel Zap/4-1
[Apr 22 19:40:16] DTMF[5412] channel.c: DTMF end ‘D’ received on Zap/4-1, duration 0 ms
[Apr 22 19:40:16] DTMF[5412] channel.c: DTMF begin emulation of ‘D’ with duration 100 queued on Zap/4-1
[Apr 22 19:40:16] DTMF[5412] channel.c: DTMF end emulation of ‘D’ queued on Zap/4-1
[Apr 22 19:40:16] DEBUG[5412] chan_zap.c: CID got digit ‘D’
[Apr 22 19:40:16] DTMF[5412] channel.c: DTMF end ‘0’ received on Zap/4-1, duration 0 ms
[Apr 22 19:40:16] DTMF[5412] channel.c: DTMF end ‘0’ put into dtmf queue on Zap/4-1
[Apr 22 19:40:16] DTMF[5412] channel.c: DTMF begin emulation of ‘0’ with duration 100 queued on Zap/4-1
[Apr 22 19:40:16] DTMF[5412] channel.c: DTMF end ‘4’ received on Zap/4-1, duration 0 ms
[Apr 22 19:40:16] DTMF[5412] channel.c: DTMF end ‘4’ put into dtmf queue on Zap/4-1
[Apr 22 19:40:16] DTMF[5412] channel.c: DTMF end emulation of ‘0’ queued on Zap/4-1
[Apr 22 19:40:16] DEBUG[5412] chan_zap.c: CID got digit ‘0’
[Apr 22 19:40:16] DTMF[5412] channel.c: DTMF begin emulation of ‘4’ with duration 100 queued on Zap/4-1
[Apr 22 19:40:16] DTMF[5412] channel.c: DTMF end ‘0’ received on Zap/4-1, duration 0 ms
[Apr 22 19:40:16] DTMF[5412] channel.c: DTMF end ‘0’ put into dtmf queue on Zap/4-1
[Apr 22 19:40:16] DTMF[5412] channel.c: DTMF end emulation of ‘4’ queued on Zap/4-1
[Apr 22 19:40:16] DEBUG[5412] chan_zap.c: CID got digit ‘4’
[Apr 22 19:40:16] DTMF[5412] channel.c: DTMF begin emulation of ‘0’ with duration 100 queued on Zap/4-1
[Apr 22 19:40:16] DTMF[5412] channel.c: DTMF end ‘6’ received on Zap/4-1, duration 0 ms
[Apr 22 19:40:16] DTMF[5412] channel.c: DTMF end ‘6’ put into dtmf queue on Zap/4-1
[Apr 22 19:40:16] DTMF[5412] channel.c: DTMF end emulation of ‘0’ queued on Zap/4-1
[Apr 22 19:40:16] DEBUG[5412] chan_zap.c: CID got digit ‘0’
[Apr 22 19:40:16] DTMF[5412] channel.c: DTMF begin emulation of ‘6’ with duration 100 queued on Zap/4-1
[Apr 22 19:40:16] DTMF[5412] channel.c: DTMF end ‘6’ received on Zap/4-1, duration 0 ms
[Apr 22 19:40:16] DTMF[5412] channel.c: DTMF end ‘6’ put into dtmf queue on Zap/4-1
[Apr 22 19:40:17] DTMF[5412] channel.c: DTMF end emulation of ‘6’ queued on Zap/4-1
[Apr 22 19:40:17] DEBUG[5412] chan_zap.c: CID got digit ‘6’
[Apr 22 19:40:17] DTMF[5412] channel.c: DTMF begin emulation of ‘6’ with duration 100 queued on Zap/4-1
[Apr 22 19:40:17] DTMF[5412] channel.c: DTMF end ‘5’ received on Zap/4-1, duration 0 ms
[Apr 22 19:40:17] DTMF[5412] channel.c: DTMF end ‘5’ put into dtmf queue on Zap/4-1
[Apr 22 19:40:17] DTMF[5412] channel.c: DTMF end emulation of ‘6’ queued on Zap/4-1
[Apr 22 19:40:17] DEBUG[5412] chan_zap.c: CID got digit ‘6’
[Apr 22 19:40:17] DTMF[5412] channel.c: DTMF begin emulation of ‘5’ with duration 100 queued on Zap/4-1
[Apr 22 19:40:17] DTMF[5412] channel.c: DTMF end ‘4’ received on Zap/4-1, duration 0 ms
[Apr 22 19:40:17] DTMF[5412] channel.c: DTMF end ‘4’ put into dtmf queue on Zap/4-1
[Apr 22 19:40:17] DTMF[5412] channel.c: DTMF end emulation of ‘5’ queued on Zap/4-1
[Apr 22 19:40:17] DEBUG[5412] chan_zap.c: CID got digit ‘5’
[Apr 22 19:40:17] DTMF[5412] channel.c: DTMF end ‘5’ received on Zap/4-1, duration 0 ms
[Apr 22 19:40:17] DTMF[5412] channel.c: DTMF end ‘5’ put into dtmf queue on Zap/4-1
[Apr 22 19:40:17] DTMF[5412] channel.c: DTMF begin emulation of ‘4’ with duration 100 queued on Zap/4-1
[Apr 22 19:40:17] DTMF[5412] channel.c: DTMF end ‘5’ received on Zap/4-1, duration 0 ms
[Apr 22 19:40:17] DTMF[5412] channel.c: DTMF end ‘5’ put into dtmf queue on Zap/4-1
[Apr 22 19:40:17] DTMF[5412] channel.c: DTMF end emulation of ‘4’ queued on Zap/4-1
[Apr 22 19:40:17] DEBUG[5412] chan_zap.c: CID got digit ‘4’
[Apr 22 19:40:17] DTMF[5412] channel.c: DTMF begin emulation of ‘5’ with duration 100 queued on Zap/4-1
[Apr 22 19:40:17] DTMF[5412] channel.c: DTMF end ‘6’ received on Zap/4-1, duration 0 ms
[Apr 22 19:40:17] DTMF[5412] channel.c: DTMF end ‘6’ put into dtmf queue on Zap/4-1
[Apr 22 19:40:17] DTMF[5412] channel.c: DTMF end emulation of ‘5’ queued on Zap/4-1
[Apr 22 19:40:17] DEBUG[5412] chan_zap.c: CID got digit ‘5’
[Apr 22 19:40:17] DTMF[5412] channel.c: DTMF begin emulation of ‘5’ with duration 100 queued on Zap/4-1
[Apr 22 19:40:17] DTMF[5412] channel.c: DTMF end ‘C’ received on Zap/4-1, duration 0 ms
[Apr 22 19:40:17] DTMF[5412] channel.c: DTMF end ‘C’ put into dtmf queue on Zap/4-1
[Apr 22 19:40:17] DTMF[5412] channel.c: DTMF end emulation of ‘5’ queued on Zap/4-1
[Apr 22 19:40:17] DEBUG[5412] chan_zap.c: CID got digit ‘5’
[Apr 22 19:40:17] DTMF[5412] channel.c: DTMF begin emulation of ‘6’ with duration 100 queued on Zap/4-1
[Apr 22 19:40:17] DEBUG[5412] chan_zap.c: Ignoring Polarity switch to IDLE on channel 4, state 9
[Apr 22 19:40:17] DEBUG[5412] chan_zap.c: Polarity Reversal event occured - DEBUG 2: channel 4, state 9, pol= 0, aonp= 1, honp= 1, pdelay= 600, tv= 2000207786
[Apr 22 19:40:18] DTMF[5412] channel.c: DTMF end emulation of ‘6’ queued on Zap/4-1
[Apr 22 19:40:18] DEBUG[5412] chan_zap.c: CID got digit ‘6’
[Apr 22 19:40:18] DTMF[5412] channel.c: DTMF begin emulation of ‘C’ with duration 100 queued on Zap/4-1
[Apr 22 19:40:18] DTMF[5412] channel.c: DTMF end emulation of ‘C’ queued on Zap/4-1
[Apr 22 19:40:18] DEBUG[5412] chan_zap.c: CID got digit ‘C’
[Apr 22 19:40:19] DEBUG[5412] chan_zap.c: CID got string ‘D0406654556C’
[Apr 22 19:40:19] DEBUG[5412] chan_zap.c: CID is ‘0406654556’, flags -1210140878
[Apr 22 19:40:19] VERBOSE[5412] logger.c: – Executing [s@pts_incoming:1] Wait(“Zap/4-1”, “0.3”) in new stack
[Apr 22 19:40:19] VERBOSE[5412] logger.c: – Executing [s@pts_incoming:2] Set(“Zap/4-1”, “CALLERID(all)=”" <0406654556>") in new stack
[Apr 22 19:40:19] VERBOSE[5412] logger.c: – Executing [s@pts_incoming:3] Dial(“Zap/4-1”, “SIP/5507&SIP/Micke_Helen&SIP/Nypon_Fring|20|tTr”) in new stack
[Apr 22 19:40:19] VERBOSE[5412] logger.c: – Called 5507
[Apr 22 19:40:19] VERBOSE[5412] logger.c: – Called Micke_Helen
[Apr 22 19:40:19] WARNING[5412] app_dial.c: Unable to create channel of type ‘SIP’ (cause 3 - No route to destination)
[Apr 22 19:40:19] VERBOSE[5412] logger.c: – SIP/Micke_Helen-082221f8 is ringing
[Apr 22 19:40:19] VERBOSE[5412] logger.c: – SIP/5507-08218bf8 is ringing
[Apr 22 19:40:35] VERBOSE[5412] logger.c: – SIP/5507-08218bf8 answered Zap/4-1
[Apr 22 19:40:35] DEBUG[5412] chan_zap.c: Took Zap/4-1 off hook
[Apr 22 19:40:35] DEBUG[5412] chan_zap.c: Engaged echo training on channel 4
[Apr 22 19:40:35] DEBUG[5412] chan_zap.c: Ignore switch to REVERSED Polarity on channel 4, state 6
[Apr 22 19:40:35] DEBUG[5412] chan_zap.c: Polarity Reversal event occured - DEBUG 1: channel 4, state 6, pol= 1, aonp= 1, honp= 1, pdelay= 600, tv= 154
[Apr 22 19:40:35] DEBUG[5412] chan_zap.c: Polarity Reversal detected but NOT hanging up (too close to answer event) on channel 4, state 6
[Apr 22 19:40:35] DEBUG[5412] chan_zap.c: Polarity Reversal event occured - DEBUG 2: channel 4, state 6, pol= 1, aonp= 1, honp= 1, pdelay= 600, tv= 154
[Apr 22 19:40:54] DEBUG[5412] chan_zap.c: Polarity Reversal event occured - DEBUG 1: channel 4, state 6, pol= 1, aonp= 1, honp= 1, pdelay= 600, tv= 19621
[Apr 22 19:40:54] DEBUG[5412] chan_zap.c: Polarity Reversal detected and now Hanging up on channel 4
[Apr 22 19:40:54] DEBUG[5412] chan_zap.c: Polarity Reversal event occured - DEBUG 2: channel 4, state 6, pol= 0, aonp= 1, honp= 1, pdelay= 600, tv= 19621
[Apr 22 19:40:54] VERBOSE[5412] logger.c: == Spawn extension (pts_incoming, s, 3) exited non-zero on ‘Zap/4-1’
[Apr 22 19:40:54] VERBOSE[5412] logger.c: – Executing [h@pts_incoming:1] Hangup(“Zap/4-1”, “”) in new stack
[Apr 22 19:40:54] VERBOSE[5412] logger.c: == Spawn extension (pts_incoming, h, 1) exited non-zero on ‘Zap/4-1’
[Apr 22 19:40:54] VERBOSE[5412] logger.c: – Hungup ‘Zap/4-1’

[b]###########################################

Before next call it was 2 incoming calls with correct callerid.

I only pasted one of the two incoming call log in this topic.

###########################################
Next incomming call number = Hidden callerid[/b]

[Apr 23 12:50:05] VERBOSE[3167] logger.c: == Starting post polarity CID detection on channel 4
[Apr 23 12:50:05] DEBUG[3167] dsp.c: dsp busy pattern set to 0,0
[Apr 23 12:50:05] VERBOSE[8880] logger.c: – Starting simple switch on ‘Zap/4-1’
[Apr 23 12:50:05] DEBUG[8880] chan_zap.c: Receiving DTMF cid on channel Zap/4-1
[Apr 23 12:50:06] DTMF[8880] channel.c: DTMF end ‘B’ received on Zap/4-1, duration 0 ms
[Apr 23 12:50:06] DTMF[8880] channel.c: DTMF begin emulation of ‘B’ with duration 100 queued on Zap/4-1
[Apr 23 12:50:06] DTMF[8880] channel.c: DTMF end emulation of ‘B’ queued on Zap/4-1
[Apr 23 12:50:06] DEBUG[8880] chan_zap.c: CID got digit ‘B’
[Apr 23 12:50:06] DTMF[8880] channel.c: DTMF end ‘1’ received on Zap/4-1, duration 0 ms
[Apr 23 12:50:06] DTMF[8880] channel.c: DTMF end ‘1’ put into dtmf queue on Zap/4-1
[Apr 23 12:50:06] DTMF[8880] channel.c: DTMF begin emulation of ‘1’ with duration 100 queued on Zap/4-1
[Apr 23 12:50:06] DTMF[8880] channel.c: DTMF end ‘0’ received on Zap/4-1, duration 0 ms
[Apr 23 12:50:06] DTMF[8880] channel.c: DTMF end ‘0’ put into dtmf queue on Zap/4-1
[Apr 23 12:50:06] DTMF[8880] channel.c: DTMF end emulation of ‘1’ queued on Zap/4-1
[Apr 23 12:50:06] DEBUG[8880] chan_zap.c: CID got digit ‘1’
[Apr 23 12:50:06] DTMF[8880] channel.c: DTMF begin emulation of ‘0’ with duration 100 queued on Zap/4-1
[Apr 23 12:50:06] DTMF[8880] channel.c: DTMF end ‘C’ received on Zap/4-1, duration 0 ms
[Apr 23 12:50:06] DTMF[8880] channel.c: DTMF end ‘C’ put into dtmf queue on Zap/4-1
[Apr 23 12:50:06] DTMF[8880] channel.c: DTMF end emulation of ‘0’ queued on Zap/4-1
[Apr 23 12:50:06] DEBUG[8880] chan_zap.c: CID got digit ‘0’
[Apr 23 12:50:06] DTMF[8880] channel.c: DTMF begin emulation of ‘C’ with duration 100 queued on Zap/4-1
[Apr 23 12:50:06] DEBUG[8880] chan_zap.c: Ignoring Polarity switch to IDLE on channel 4, state 9
[Apr 23 12:50:06] DEBUG[8880] chan_zap.c: Polarity Reversal event occured - DEBUG 2: channel 4, state 9, pol= 0, aonp= 1, honp= 1, pdelay= 600, tv= 3294127
[Apr 23 12:50:06] DTMF[8880] channel.c: DTMF end emulation of ‘C’ queued on Zap/4-1
[Apr 23 12:50:06] DEBUG[8880] chan_zap.c: CID got digit ‘C’
[Apr 23 12:50:08] DEBUG[8880] chan_zap.c: CID got string ‘B10C’
[Apr 23 12:50:08] DEBUG[8880] chan_zap.c: CID is ‘’, flags 2
[Apr 23 12:50:08] VERBOSE[8880] logger.c: – Executing [s@pts_incoming:1] Wait(“Zap/4-1”, “0.3”) in new stack
[Apr 23 12:50:08] VERBOSE[8880] logger.c: – Executing [s@pts_incoming:2] Set(“Zap/4-1”, “CALLERID(all)=”" <>") in new stack
[Apr 23 12:50:08] VERBOSE[8880] logger.c: – Executing [s@pts_incoming:3] Dial(“Zap/4-1”, “SIP/5507&SIP/Micke_Helen&SIP/Nypon_Fring|20|tTr”) in new stack
[Apr 23 12:50:08] VERBOSE[8880] logger.c: – Called 5507
[Apr 23 12:50:08] VERBOSE[8880] logger.c: – Called Micke_Helen
[Apr 23 12:50:08] WARNING[8880] app_dial.c: Unable to create channel of type ‘SIP’ (cause 3 - No route to destination)
[Apr 23 12:50:08] VERBOSE[8880] logger.c: – SIP/Micke_Helen-08229260 is ringing
[Apr 23 12:50:08] VERBOSE[8880] logger.c: – SIP/5507-081a6c48 is ringing
[Apr 23 12:50:25] VERBOSE[8880] logger.c: – SIP/5507-081a6c48 answered Zap/4-1
[Apr 23 12:50:25] DEBUG[8880] chan_zap.c: Took Zap/4-1 off hook
[Apr 23 12:50:25] DEBUG[8880] chan_zap.c: Engaged echo training on channel 4
[Apr 23 12:50:25] DEBUG[8880] chan_zap.c: Ignore switch to REVERSED Polarity on channel 4, state 6
[Apr 23 12:50:25] DEBUG[8880] chan_zap.c: Polarity Reversal event occured - DEBUG 1: channel 4, state 6, pol= 1, aonp= 1, honp= 1, pdelay= 600, tv= 128
[Apr 23 12:50:25] DEBUG[8880] chan_zap.c: Polarity Reversal detected but NOT hanging up (too close to answer event) on channel 4, state 6
[Apr 23 12:50:25] DEBUG[8880] chan_zap.c: Polarity Reversal event occured - DEBUG 2: channel 4, state 6, pol= 1, aonp= 1, honp= 1, pdelay= 600, tv= 129
[Apr 23 12:50:45] DEBUG[8880] chan_zap.c: Polarity Reversal event occured - DEBUG 1: channel 4, state 6, pol= 1, aonp= 1, honp= 1, pdelay= 600, tv= 19808
[Apr 23 12:50:45] DEBUG[8880] chan_zap.c: Polarity Reversal detected and now Hanging up on channel 4
[Apr 23 12:50:45] DEBUG[8880] chan_zap.c: Polarity Reversal event occured - DEBUG 2: channel 4, state 6, pol= 0, aonp= 1, honp= 1, pdelay= 600, tv= 19809
[Apr 23 12:50:45] VERBOSE[8880] logger.c: == Spawn extension (pts_incoming, s, 3) exited non-zero on ‘Zap/4-1’
[Apr 23 12:50:45] VERBOSE[8880] logger.c: – Executing [h@pts_incoming:1] Hangup(“Zap/4-1”, “”) in new stack
[Apr 23 12:50:45] VERBOSE[8880] logger.c: == Spawn extension (pts_incoming, h, 1) exited non-zero on ‘Zap/4-1’
[Apr 23 12:50:45] VERBOSE[8880] logger.c: – Hungup ‘Zap/4-1’

[b]##################################################################

After the blank callerid call a call from 0406654556 comes in but it could not get the nummber.

##################################################################
Next incomming call number = 0406654556[/b]

Why is it in the next call saying:

CID got string ''
No cid detected
CID is ‘’, flags 8

before the “DTMF end emulation” of the callerid

When it works OK it starts with the “DTMF end emulation” and after it got the whole number it say:
CID got string '012345678’
CID is ‘012345678’
…
…

[Apr 23 13:14:27] VERBOSE[3167] logger.c: == Starting post polarity CID detection on channel 4
[Apr 23 13:14:27] DEBUG[3167] dsp.c: dsp busy pattern set to 0,0
[Apr 23 13:14:27] VERBOSE[10162] logger.c: – Starting simple switch on ‘Zap/4-1’
[Apr 23 13:14:27] DEBUG[10162] chan_zap.c: Receiving DTMF cid on channel Zap/4-1
[Apr 23 13:14:27] DEBUG[10162] chan_zap.c: CID got string ‘’
[Apr 23 13:14:27] DEBUG[10162] callerid.c: No cid detected
[Apr 23 13:14:27] DEBUG[10162] chan_zap.c: CID is ‘’, flags 8
[Apr 23 13:14:27] VERBOSE[10162] logger.c: – Executing [s@pts_incoming:1] Wait(“Zap/4-1”, “0.3”) in new stack
[Apr 23 13:14:27] DTMF[10162] channel.c: DTMF end ‘D’ received on Zap/4-1, duration 0 ms
[Apr 23 13:14:27] DTMF[10162] channel.c: DTMF begin emulation of ‘D’ with duration 100 queued on Zap/4-1
[Apr 23 13:14:27] VERBOSE[10162] logger.c: – Executing [s@pts_incoming:2] Set(“Zap/4-1”, “CALLERID(all)=”" <>") in new stack
[Apr 23 13:14:27] VERBOSE[10162] logger.c: – Executing [s@pts_incoming:3] Dial(“Zap/4-1”, “SIP/5507&SIP/Micke_Helen&SIP/Nypon_Fring|20|tTr”) in new stack
[Apr 23 13:14:27] VERBOSE[10162] logger.c: – Called 5507
[Apr 23 13:14:27] VERBOSE[10162] logger.c: – Called Micke_Helen
[Apr 23 13:14:27] WARNING[10162] app_dial.c: Unable to create channel of type ‘SIP’ (cause 3 - No route to destination)
[Apr 23 13:14:27] VERBOSE[10162] logger.c: – SIP/Micke_Helen-0821dea8 is ringing
[Apr 23 13:14:27] VERBOSE[10162] logger.c: – SIP/5507-0821c918 is ringing
[Apr 23 13:14:27] DTMF[10162] channel.c: DTMF end emulation of ‘D’ queued on Zap/4-1
[Apr 23 13:14:27] DTMF[10162] channel.c: DTMF end ‘0’ received on Zap/4-1, duration 0 ms
[Apr 23 13:14:27] DTMF[10162] channel.c: DTMF end ‘0’ put into dtmf queue on Zap/4-1
[Apr 23 13:14:27] DTMF[10162] channel.c: DTMF begin emulation of ‘0’ with duration 100 queued on Zap/4-1
[Apr 23 13:14:27] DTMF[10162] channel.c: DTMF end ‘4’ received on Zap/4-1, duration 0 ms
[Apr 23 13:14:27] DTMF[10162] channel.c: DTMF end ‘4’ put into dtmf queue on Zap/4-1
[Apr 23 13:14:27] DTMF[10162] channel.c: DTMF end emulation of ‘0’ queued on Zap/4-1
[Apr 23 13:14:27] DTMF[10162] channel.c: DTMF begin emulation of ‘4’ with duration 100 queued on Zap/4-1
[Apr 23 13:14:27] DTMF[10162] channel.c: DTMF end ‘0’ received on Zap/4-1, duration 0 ms
[Apr 23 13:14:27] DTMF[10162] channel.c: DTMF end ‘0’ put into dtmf queue on Zap/4-1
[Apr 23 13:14:28] DTMF[10162] channel.c: DTMF end emulation of ‘4’ queued on Zap/4-1
[Apr 23 13:14:28] DTMF[10162] channel.c: DTMF begin emulation of ‘0’ with duration 100 queued on Zap/4-1
[Apr 23 13:14:28] DTMF[10162] channel.c: DTMF end ‘6’ received on Zap/4-1, duration 0 ms
[Apr 23 13:14:28] DTMF[10162] channel.c: DTMF end ‘6’ put into dtmf queue on Zap/4-1
[Apr 23 13:14:28] DTMF[10162] channel.c: DTMF end emulation of ‘0’ queued on Zap/4-1
[Apr 23 13:14:28] DTMF[10162] channel.c: DTMF begin emulation of ‘6’ with duration 100 queued on Zap/4-1
[Apr 23 13:14:28] DTMF[10162] channel.c: DTMF end ‘6’ received on Zap/4-1, duration 0 ms
[Apr 23 13:14:28] DTMF[10162] channel.c: DTMF end ‘6’ put into dtmf queue on Zap/4-1
[Apr 23 13:14:28] DTMF[10162] channel.c: DTMF end emulation of ‘6’ queued on Zap/4-1
[Apr 23 13:14:28] DTMF[10162] channel.c: DTMF begin emulation of ‘6’ with duration 100 queued on Zap/4-1
[Apr 23 13:14:28] DTMF[10162] channel.c: DTMF end ‘5’ received on Zap/4-1, duration 0 ms
[Apr 23 13:14:28] DTMF[10162] channel.c: DTMF end ‘5’ put into dtmf queue on Zap/4-1
[Apr 23 13:14:28] DTMF[10162] channel.c: DTMF end emulation of ‘6’ queued on Zap/4-1
[Apr 23 13:14:28] DTMF[10162] channel.c: DTMF end ‘4’ received on Zap/4-1, duration 0 ms
[Apr 23 13:14:28] DTMF[10162] channel.c: DTMF end ‘4’ put into dtmf queue on Zap/4-1
[Apr 23 13:14:28] DTMF[10162] channel.c: DTMF begin emulation of ‘5’ with duration 100 queued on Zap/4-1
[Apr 23 13:14:28] DTMF[10162] channel.c: DTMF end ‘5’ received on Zap/4-1, duration 0 ms
[Apr 23 13:14:28] DTMF[10162] channel.c: DTMF end ‘5’ put into dtmf queue on Zap/4-1
[Apr 23 13:14:28] DTMF[10162] channel.c: DTMF end emulation of ‘5’ queued on Zap/4-1
[Apr 23 13:14:28] DTMF[10162] channel.c: DTMF begin emulation of ‘4’ with duration 100 queued on Zap/4-1
[Apr 23 13:14:28] DTMF[10162] channel.c: DTMF end ‘9’ received on Zap/4-1, duration 0 ms
[Apr 23 13:14:28] DTMF[10162] channel.c: DTMF end ‘9’ put into dtmf queue on Zap/4-1
[Apr 23 13:14:28] DTMF[10162] channel.c: DTMF end emulation of ‘4’ queued on Zap/4-1
[Apr 23 13:14:28] DTMF[10162] channel.c: DTMF begin emulation of ‘5’ with duration 100 queued on Zap/4-1
[Apr 23 13:14:29] DTMF[10162] channel.c: DTMF end ‘6’ received on Zap/4-1, duration 0 ms
[Apr 23 13:14:29] DTMF[10162] channel.c: DTMF end ‘6’ put into dtmf queue on Zap/4-1
[Apr 23 13:14:29] DTMF[10162] channel.c: DTMF end emulation of ‘5’ queued on Zap/4-1
[Apr 23 13:14:29] DTMF[10162] channel.c: DTMF begin emulation of ‘9’ with duration 100 queued on Zap/4-1
[Apr 23 13:14:29] DTMF[10162] channel.c: DTMF end ‘C’ received on Zap/4-1, duration 0 ms
[Apr 23 13:14:29] DTMF[10162] channel.c: DTMF end ‘C’ put into dtmf queue on Zap/4-1
[Apr 23 13:14:29] DTMF[10162] channel.c: DTMF end emulation of ‘9’ queued on Zap/4-1
[Apr 23 13:14:29] DTMF[10162] channel.c: DTMF begin emulation of ‘6’ with duration 100 queued on Zap/4-1
[Apr 23 13:14:29] DEBUG[10162] chan_zap.c: Polarity Reversal event occured - DEBUG 1: channel 4, state 4, pol= 1, aonp= 1, honp= 1, pdelay= 600, tv= 1444052
[Apr 23 13:14:29] DEBUG[10162] chan_zap.c: Polarity Reversal detected and now Hanging up on channel 4
[Apr 23 13:14:29] DEBUG[10162] chan_zap.c: Polarity Reversal event occured - DEBUG 2: channel 4, state 4, pol= 0, aonp= 1, honp= 1, pdelay= 600, tv= 1444052
[Apr 23 13:14:29] VERBOSE[10162] logger.c: == Spawn extension (pts_incoming, s, 3) exited non-zero on ‘Zap/4-1’
[Apr 23 13:14:29] VERBOSE[10162] logger.c: – Executing [h@pts_incoming:1] Hangup(“Zap/4-1”, “”) in new stack
[Apr 23 13:14:29] VERBOSE[10162] logger.c: == Spawn extension (pts_incoming, h, 1) exited non-zero on ‘Zap/4-1’
[Apr 23 13:14:29] VERBOSE[10162] logger.c: – Hungup ‘Zap/4-1’
[Apr 23 13:14:36] DEBUG[3167] dsp.c: dsp busy pattern set to 0,0
[Apr 23 13:14:36] VERBOSE[10171] logger.c: – Starting simple switch on ‘Zap/4-1’
[Apr 23 13:14:36] VERBOSE[10171] logger.c: – Executing [s@pts_incoming:1] Wait(“Zap/4-1”, “0.3”) in new stack
[Apr 23 13:14:37] VERBOSE[10171] logger.c: – Executing [s@pts_incoming:2] Set(“Zap/4-1”, “CALLERID(all)=”" <>") in new stack
[Apr 23 13:14:37] VERBOSE[10171] logger.c: – Executing [s@pts_incoming:3] Dial(“Zap/4-1”, “SIP/5507&SIP/Micke_Helen&SIP/Nypon_Fring|20|tTr”) in new stack
[Apr 23 13:14:37] VERBOSE[10171] logger.c: – Called 5507
[Apr 23 13:14:37] VERBOSE[10171] logger.c: – Called Micke_Helen
[Apr 23 13:14:37] WARNING[10171] app_dial.c: Unable to create channel of type ‘SIP’ (cause 3 - No route to destination)
[Apr 23 13:14:37] VERBOSE[10171] logger.c: – SIP/Micke_Helen-0821dea8 is ringing
[Apr 23 13:14:37] VERBOSE[10171] logger.c: – SIP/5507-0821c918 is ringing
[Apr 23 13:14:41] VERBOSE[10171] logger.c: – SIP/Micke_Helen-0821dea8 answered Zap/4-1
[Apr 23 13:14:41] DEBUG[10171] chan_zap.c: Took Zap/4-1 off hook
[Apr 23 13:14:41] DEBUG[10171] chan_zap.c: Engaged echo training on channel 4
[Apr 23 13:14:41] DEBUG[10171] chan_zap.c: Ignore switch to REVERSED Polarity on channel 4, state 6
[Apr 23 13:14:41] DEBUG[10171] chan_zap.c: Polarity Reversal event occured - DEBUG 1: channel 4, state 6, pol= 1, aonp= 1, honp= 1, pdelay= 600, tv= 152
[Apr 23 13:14:41] DEBUG[10171] chan_zap.c: Polarity Reversal detected but NOT hanging up (too close to answer event) on channel 4, state 6
[Apr 23 13:14:41] DEBUG[10171] chan_zap.c: Polarity Reversal event occured - DEBUG 2: channel 4, state 6, pol= 1, aonp= 1, honp= 1, pdelay= 600, tv= 152
[Apr 23 13:14:54] DEBUG[10171] chan_zap.c: Polarity Reversal event occured - DEBUG 1: channel 4, state 6, pol= 1, aonp= 1, honp= 1, pdelay= 600, tv= 12903
[Apr 23 13:14:54] DEBUG[10171] chan_zap.c: Polarity Reversal detected and now Hanging up on channel 4
[Apr 23 13:14:54] DEBUG[10171] chan_zap.c: Polarity Reversal event occured - DEBUG 2: channel 4, state 6, pol= 0, aonp= 1, honp= 1, pdelay= 600, tv= 12904
[Apr 23 13:14:54] VERBOSE[10171] logger.c: == Spawn extension (pts_incoming, s, 3) exited non-zero on ‘Zap/4-1’
[Apr 23 13:14:54] VERBOSE[10171] logger.c: – Executing [h@pts_incoming:1] Hangup(“Zap/4-1”, “”) in new stack
[Apr 23 13:14:54] VERBOSE[10171] logger.c: == Spawn extension (pts_incoming, h, 1) exited non-zero on ‘Zap/4-1’
[Apr 23 13:14:54] VERBOSE[10171] logger.c: – Hungup ‘Zap/4-1’

Does anybody know why this is happening?
Have I missed something?

Hopefully someone of you understand these logs!

Thanks in advanced!

// Nypon

2

The funny thing is that the next call after the one in the prev post, the caller id worked again!!!

[b]##########################

And now the callerid works again!

##########################
Incomming call number = 0406654546 [/b]

[Apr 23 19:38:56] VERBOSE[3167] logger.c: == Starting post polarity CID detection on channel 4
[Apr 23 19:38:56] DEBUG[3167] dsp.c: dsp busy pattern set to 0,0
[Apr 23 19:38:56] VERBOSE[30936] logger.c: – Starting simple switch on ‘Zap/4-1’
[Apr 23 19:38:56] DEBUG[30936] chan_zap.c: Receiving DTMF cid on channel Zap/4-1
[Apr 23 19:38:56] DTMF[30936] channel.c: DTMF end ‘D’ received on Zap/4-1, duration 0 ms
[Apr 23 19:38:56] DTMF[30936] channel.c: DTMF begin emulation of ‘D’ with duration 100 queued on Zap/4-1
[Apr 23 19:38:56] DTMF[30936] channel.c: DTMF end emulation of ‘D’ queued on Zap/4-1
[Apr 23 19:38:56] DEBUG[30936] chan_zap.c: CID got digit ‘D’
[Apr 23 19:38:56] DTMF[30936] channel.c: DTMF end ‘0’ received on Zap/4-1, duration 0 ms
[Apr 23 19:38:56] DTMF[30936] channel.c: DTMF end ‘0’ put into dtmf queue on Zap/4-1
[Apr 23 19:38:56] DTMF[30936] channel.c: DTMF begin emulation of ‘0’ with duration 100 queued on Zap/4-1
[Apr 23 19:38:56] DTMF[30936] channel.c: DTMF end ‘4’ received on Zap/4-1, duration 0 ms
[Apr 23 19:38:56] DTMF[30936] channel.c: DTMF end ‘4’ put into dtmf queue on Zap/4-1
[Apr 23 19:38:56] DTMF[30936] channel.c: DTMF end emulation of ‘0’ queued on Zap/4-1
[Apr 23 19:38:56] DEBUG[30936] chan_zap.c: CID got digit ‘0’
[Apr 23 19:38:56] DTMF[30936] channel.c: DTMF begin emulation of ‘4’ with duration 100 queued on Zap/4-1
[Apr 23 19:38:56] DTMF[30936] channel.c: DTMF end ‘0’ received on Zap/4-1, duration 0 ms
[Apr 23 19:38:56] DTMF[30936] channel.c: DTMF end ‘0’ put into dtmf queue on Zap/4-1
[Apr 23 19:38:56] DTMF[30936] channel.c: DTMF end emulation of ‘4’ queued on Zap/4-1
[Apr 23 19:38:56] DEBUG[30936] chan_zap.c: CID got digit ‘4’
[Apr 23 19:38:57] DTMF[30936] channel.c: DTMF begin emulation of ‘0’ with duration 100 queued on Zap/4-1
[Apr 23 19:38:57] DTMF[30936] channel.c: DTMF end ‘6’ received on Zap/4-1, duration 0 ms
[Apr 23 19:38:57] DTMF[30936] channel.c: DTMF end ‘6’ put into dtmf queue on Zap/4-1
[Apr 23 19:38:57] DTMF[30936] channel.c: DTMF end emulation of ‘0’ queued on Zap/4-1
[Apr 23 19:38:57] DEBUG[30936] chan_zap.c: CID got digit ‘0’
[Apr 23 19:38:57] DTMF[30936] channel.c: DTMF begin emulation of ‘6’ with duration 100 queued on Zap/4-1
[Apr 23 19:38:57] DTMF[30936] channel.c: DTMF end ‘6’ received on Zap/4-1, duration 0 ms
[Apr 23 19:38:57] DTMF[30936] channel.c: DTMF end ‘6’ put into dtmf queue on Zap/4-1
[Apr 23 19:38:57] DTMF[30936] channel.c: DTMF end emulation of ‘6’ queued on Zap/4-1
[Apr 23 19:38:57] DEBUG[30936] chan_zap.c: CID got digit ‘6’
[Apr 23 19:38:57] DTMF[30936] channel.c: DTMF end ‘5’ received on Zap/4-1, duration 0 ms
[Apr 23 19:38:57] DTMF[30936] channel.c: DTMF end ‘5’ put into dtmf queue on Zap/4-1
[Apr 23 19:38:57] DTMF[30936] channel.c: DTMF begin emulation of ‘6’ with duration 100 queued on Zap/4-1
[Apr 23 19:38:57] DTMF[30936] channel.c: DTMF end ‘4’ received on Zap/4-1, duration 0 ms
[Apr 23 19:38:57] DTMF[30936] channel.c: DTMF end ‘4’ put into dtmf queue on Zap/4-1
[Apr 23 19:38:57] DTMF[30936] channel.c: DTMF end emulation of ‘6’ queued on Zap/4-1
[Apr 23 19:38:57] DEBUG[30936] chan_zap.c: CID got digit ‘6’
[Apr 23 19:38:57] DTMF[30936] channel.c: DTMF begin emulation of ‘5’ with duration 100 queued on Zap/4-1
[Apr 23 19:38:57] DTMF[30936] channel.c: DTMF end ‘5’ received on Zap/4-1, duration 0 ms
[Apr 23 19:38:57] DTMF[30936] channel.c: DTMF end ‘5’ put into dtmf queue on Zap/4-1
[Apr 23 19:38:57] DTMF[30936] channel.c: DTMF end emulation of ‘5’ queued on Zap/4-1
[Apr 23 19:38:57] DEBUG[30936] chan_zap.c: CID got digit ‘5’
[Apr 23 19:38:57] DTMF[30936] channel.c: DTMF begin emulation of ‘4’ with duration 100 queued on Zap/4-1
[Apr 23 19:38:57] DTMF[30936] channel.c: DTMF end ‘4’ received on Zap/4-1, duration 0 ms
[Apr 23 19:38:57] DTMF[30936] channel.c: DTMF end ‘4’ put into dtmf queue on Zap/4-1
[Apr 23 19:38:57] DTMF[30936] channel.c: DTMF end emulation of ‘4’ queued on Zap/4-1
[Apr 23 19:38:57] DEBUG[30936] chan_zap.c: CID got digit ‘4’
[Apr 23 19:38:57] DTMF[30936] channel.c: DTMF begin emulation of ‘5’ with duration 100 queued on Zap/4-1
[Apr 23 19:38:57] DTMF[30936] channel.c: DTMF end ‘6’ received on Zap/4-1, duration 0 ms
[Apr 23 19:38:57] DTMF[30936] channel.c: DTMF end ‘6’ put into dtmf queue on Zap/4-1
[Apr 23 19:38:58] DTMF[30936] channel.c: DTMF end emulation of ‘5’ queued on Zap/4-1
[Apr 23 19:38:58] DEBUG[30936] chan_zap.c: CID got digit ‘5’
[Apr 23 19:38:58] DTMF[30936] channel.c: DTMF begin emulation of ‘4’ with duration 100 queued on Zap/4-1
[Apr 23 19:38:58] DTMF[30936] channel.c: DTMF end ‘C’ received on Zap/4-1, duration 0 ms
[Apr 23 19:38:58] DTMF[30936] channel.c: DTMF end ‘C’ put into dtmf queue on Zap/4-1
[Apr 23 19:38:58] DEBUG[30936] chan_zap.c: Ignoring Polarity switch to IDLE on channel 4, state 9
[Apr 23 19:38:58] DEBUG[30936] chan_zap.c: Polarity Reversal event occured - DEBUG 2: channel 4, state 9, pol= 0, aonp= 1, honp= 1, pdelay= 600, tv= 23056970
[Apr 23 19:38:58] DTMF[30936] channel.c: DTMF end emulation of ‘4’ queued on Zap/4-1
[Apr 23 19:38:58] DEBUG[30936] chan_zap.c: CID got digit ‘4’
[Apr 23 19:38:58] DTMF[30936] channel.c: DTMF begin emulation of ‘6’ with duration 100 queued on Zap/4-1
[Apr 23 19:38:58] DTMF[30936] channel.c: DTMF end emulation of ‘6’ queued on Zap/4-1
[Apr 23 19:38:58] DEBUG[30936] chan_zap.c: CID got digit ‘6’
[Apr 23 19:38:58] DTMF[30936] channel.c: DTMF begin emulation of ‘C’ with duration 100 queued on Zap/4-1
[Apr 23 19:38:58] DTMF[30936] channel.c: DTMF end emulation of ‘C’ queued on Zap/4-1
[Apr 23 19:38:58] DEBUG[30936] chan_zap.c: CID got digit ‘C’
[Apr 23 19:38:59] DEBUG[30936] chan_zap.c: CID got string ‘D0406654546C’
[Apr 23 19:38:59] DEBUG[30936] chan_zap.c: CID is ‘0406654546’, flags -1209563342
[Apr 23 19:38:59] VERBOSE[30936] logger.c: – Executing [s@pts_incoming:1] Wait(“Zap/4-1”, “0.3”) in new stack
[Apr 23 19:39:00] VERBOSE[30936] logger.c: – Executing [s@pts_incoming:2] Set(“Zap/4-1”, “CALLERID(all)=”" <0406654546>") in new stack
[Apr 23 19:39:00] VERBOSE[30936] logger.c: – Executing [s@pts_incoming:3] Dial(“Zap/4-1”, “SIP/5507&SIP/Micke_Helen&SIP/Nypon_Fring|20|tTr”) in new stack
[Apr 23 19:39:00] VERBOSE[30936] logger.c: – Called 5507
[Apr 23 19:39:00] VERBOSE[30936] logger.c: – Called Micke_Helen
[Apr 23 19:39:00] WARNING[30936] app_dial.c: Unable to create channel of type ‘SIP’ (cause 3 - No route to destination)
[Apr 23 19:39:00] VERBOSE[30936] logger.c: – SIP/Micke_Helen-0822b020 is ringing
[Apr 23 19:39:00] VERBOSE[30936] logger.c: – SIP/5507-081a7b70 is ringing
[Apr 23 19:39:17] VERBOSE[30936] logger.c: – SIP/5507-081a7b70 answered Zap/4-1
[Apr 23 19:39:17] DEBUG[30936] chan_zap.c: Took Zap/4-1 off hook
[Apr 23 19:39:17] DEBUG[30936] chan_zap.c: Engaged echo training on channel 4
[Apr 23 19:39:18] VERBOSE[30936] logger.c: == Spawn extension (pts_incoming, s, 3) exited non-zero on ‘Zap/4-1’
[Apr 23 19:39:18] VERBOSE[30936] logger.c: – Executing [h@pts_incoming:1] Hangup(“Zap/4-1”, “”) in new stack
[Apr 23 19:39:18] VERBOSE[30936] logger.c: == Spawn extension (pts_incoming, h, 1) exited non-zero on ‘Zap/4-1’
[Apr 23 19:39:18] VERBOSE[30936] logger.c: – Hungup ‘Zap/4-1’

Is this that I am in sweden and the zapata driver is not so good with the swedish telecom?
Can the “Ignoring Polarity switch to IDLE” part be the issue for me?

I forgott to add my <zapata.conf> settings, and here it is:

[code][channels]
rxgain=6.5
txgain=7.5
immediate=no
relaxdtmf=yes
echocancel=yes
echocancelwhenbridged=yes
echotraining=400
usecallerid=yes
hidecallerid=no
threewaycalling=yes
useincomingcalleridonzaptransfer=yes
progzone=se
transfer=yes
busydetect=yes
busycount=6
;faxdetect=both
;faxdetect=incoming

; Channel 1 FXS port to normal phone
signalling=fxo_ks
language=se
callerid=“Micke & Helen”<6000>
context=internal-call-profile-pre
accountcode=call-in-house
mailbox=6000@intern-ank
cidsignalling=dtmf ; Sweden
cidstart=polarity ; Sweden
channel => 1

; Channel 4 FXO port to incomming analog line
cidsignalling=dtmf ; Sweden
cidstart=polarity ; Sweden
signalling=fxs_ks
usecallerid=yes
callerid=asreceived
transfer=yes
context=pts_incoming
answeronpolarityswitch=yes
hanguponpolarityswitch=yes
channel => 4
[/code]

Have I missed or forgotten something?
The caller id is one of the things I really need!