I’m using Digium TDM11b card here in sweden and Asterisk 1.4 for incoming calls.
Now and then a incoming call shows me the wrong number.
If the incoming number is:
123456789
it will show up on the phone, cli and cdr like this:
1234567899
It duplicates the last digit!
Anyboddy having any idea on this!
What do you get on the CLI when you execute code similar to this:
exten => s,1,NoOp(CallerID is “${CALLERID(num)}”)
Doesn’t Europe use DTMF for Caller ID?
Ike
Hi Ike, and thanks for you reply!
Yes, Europe uses DTMF
I found this in </var/log/asterisk/debug> (I have just changed the number)
The incoming number should be “0123456789” instead it is “01234567899”
[Mar 5 04:34:44] DEBUG[3085] codec_zap.c: No Zaptel transcoder support!
[Mar 5 04:34:59] DEBUG[20695] chan_zap.c: Receiving DTMF cid on channel Zap/4-1
[Mar 5 04:35:00] DEBUG[20695] chan_zap.c: CID got digit ‘D’
[Mar 5 04:35:00] DEBUG[20695] chan_zap.c: CID got digit ‘0’
[Mar 5 04:35:00] DEBUG[20695] chan_zap.c: CID got digit ‘1’
[Mar 5 04:35:00] DEBUG[20695] chan_zap.c: CID got digit ‘2’
[Mar 5 04:35:00] DEBUG[20695] chan_zap.c: CID got digit ‘3’
[Mar 5 04:35:00] DEBUG[20695] chan_zap.c: CID got digit ‘4’
[Mar 5 04:35:01] DEBUG[20695] chan_zap.c: CID got digit ‘5’
[Mar 5 04:35:01] DEBUG[20695] chan_zap.c: CID got digit ‘6’
[Mar 5 04:35:01] DEBUG[20695] chan_zap.c: CID got digit ‘7’
[Mar 5 04:35:01] DEBUG[20695] chan_zap.c: CID got digit ‘8’
[Mar 5 04:35:01] DEBUG[20695] chan_zap.c: CID got digit ‘9’
[Mar 5 04:35:01] DEBUG[20695] chan_zap.c: Ignoring Polarity switch to IDLE on channel 4, state 9
[Mar 5 04:35:01] DEBUG[20695] chan_zap.c: Polarity Reversal event occured - DEBUG 2: channel 4, state 9, pol= 0, aonp= 0, honp= 1, pdelay= 600, tv= 2097258833
[Mar 5 04:35:01] DEBUG[20695] chan_zap.c: CID got digit ‘9’
[Mar 5 04:35:01] DEBUG[20695] chan_zap.c: CID got digit ‘C’
[Mar 5 04:35:03] DEBUG[20695] chan_zap.c: CID got string ‘D01234567899C’
[Mar 5 04:35:03] DEBUG[20695] chan_zap.c: CID is ‘01234567899’, flags -1210112206
[Mar 5 04:35:04] DEBUG[20695] chan_zap.c: Took Zap/4-1 off hook
[Mar 5 04:35:04] DEBUG[20695] chan_zap.c: Engaged echo training on channel 4
[Mar 5 04:35:04] DEBUG[20695] chan_zap.c: Ignore switch to REVERSED Polarity on channel 4, state 6
[Mar 5 04:35:04] DEBUG[20695] chan_zap.c: Polarity Reversal event occured - DEBUG 1: channel 4, state 6, pol= 1, aonp= 0, honp= 1, pdelay= 600, tv= 149
[Mar 5 04:35:04] DEBUG[20695] chan_zap.c: Polarity Reversal detected but NOT hanging up (too close to answer event) on channel 4, state 6
[Mar 5 04:35:04] DEBUG[20695] chan_zap.c: Polarity Reversal event occured - DEBUG 2: channel 4, state 6, pol= 1, aonp= 0, honp= 1, pdelay= 600, tv= 150
[Mar 5 04:35:05] DEBUG[20695] chan_zap.c: Polarity Reversal event occured - DEBUG 1: channel 4, state 6, pol= 1, aonp= 0, honp= 1, pdelay= 600, tv= 1573
[Mar 5 04:35:05] DEBUG[20695] chan_zap.c: Polarity Reversal detected and now Hanging up on channel 4
[Mar 5 04:35:05] DEBUG[20695] chan_zap.c: Polarity Reversal event occured - DEBUG 2: channel 4, state 6, pol= 0, aonp= 0, honp= 1, pdelay= 600, tv= 1573
// Nypon
nypon,
The polarity reversal bothers me. It sounds like when this extension was punched down on the 66 block (or other termination/distribution block you may have) tip and ring were punched down backwards. Usually PBX’s, switches, and telephones can handle reversed polarity with no problem but I am curious if this may be causing your problem. Remember, when encountering an unusual error in the computing world you should first suspect the physical layer.
I suggest that you trace this extension back to the punch block, reverse tip and ring, try it again, and post the results.
Regards,
Ike
Hi Ike and thanks for all of your help!
To start with I changed tip ring and got this when I called in.
Called in number is: 0123456789
== Starting post polarity CID detection on channel 4
[Apr 7 20:48:49] DEBUG[29893]: dsp.c:1682 ast_dsp_set_busy_pattern: dsp busy pattern set to 0,0
– Starting simple switch on ‘Zap/4-1’
[Apr 7 20:48:49] DEBUG[30014]: chan_zap.c:6109 ss_thread: Receiving DTMF cid on channel Zap/4-1
[Apr 7 20:48:50] DEBUG[30014]: chan_zap.c:6127 ss_thread: CID got digit ‘D’
[Apr 7 20:48:50] DEBUG[30014]: chan_zap.c:6127 ss_thread: CID got digit ‘0’
[Apr 7 20:48:50] DEBUG[30014]: chan_zap.c:6127 ss_thread: CID got digit ‘1’
[Apr 7 20:48:50] DEBUG[30014]: chan_zap.c:6127 ss_thread: CID got digit ‘2’
[Apr 7 20:48:51] DEBUG[30014]: chan_zap.c:6127 ss_thread: CID got digit ‘3’
[Apr 7 20:48:51] DEBUG[30014]: chan_zap.c:6127 ss_thread: CID got digit ‘4’
[Apr 7 20:48:51] DEBUG[30014]: chan_zap.c:6127 ss_thread: CID got digit ‘6’
[Apr 7 20:48:51] DEBUG[30014]: chan_zap.c:6127 ss_thread: CID got digit ‘5’
[Apr 7 20:48:51] DEBUG[30014]: chan_zap.c:6127 ss_thread: CID got digit ‘7’
[Apr 7 20:48:51] DEBUG[30014]: chan_zap.c:6127 ss_thread: CID got digit ‘8’
[Apr 7 20:48:52] DEBUG[30014]: chan_zap.c:4489 zt_handle_event: Ignoring Polarity switch to IDLE on channel 4, state 9
[Apr 7 20:48:52] DEBUG[30014]: chan_zap.c:4492 zt_handle_event: Polarity Reversal event occured - DEBUG 2: channel 4, state 9, pol= 0, aonp= 1, honp= 0, pdelay= 600, tv= 708321912
[Apr 7 20:48:52] DEBUG[30014]: chan_zap.c:6127 ss_thread: CID got digit ‘9’
[Apr 7 20:48:52] DEBUG[30014]: chan_zap.c:6127 ss_thread: CID got digit ‘C’
[Apr 7 20:48:53] DEBUG[30014]: chan_zap.c:6138 ss_thread: CID got string ‘D0123465789C’
[Apr 7 20:48:53] DEBUG[30014]: chan_zap.c:6140 ss_thread: CID is ‘0123465789’, flags -1209907406
– Executing [s@pts_incoming:1] Set(“Zap/4-1”, “CALLERID(all)=”" <0123465789>") in new stack
As you can see, it could not get digit 5 and 6 in correct order!
Next in <zapata.conf> file I added:
answeronpolarityswitch=yes ; Default = no
hanguponpolarityswitch=yes ; with only this it ended the call when the called answered the phone (SIP=>ZAP)!
I restarted * and called in again.
Connected to Asterisk 1.4.17 currently running on asterisk (pid = 3048)
Verbosity was 3 and is now 10
== Starting post polarity CID detection on channel 4
[Apr 7 20:50:47] DEBUG[30117]: dsp.c:1682 ast_dsp_set_busy_pattern: dsp busy pattern set to 0,0
– Starting simple switch on ‘Zap/4-1’
[Apr 7 20:50:47] DEBUG[30151]: chan_zap.c:6109 ss_thread: Receiving DTMF cid on channel Zap/4-1
[Apr 7 20:50:47] DEBUG[30151]: chan_zap.c:6127 ss_thread: CID got digit ‘D’
[Apr 7 20:50:48] DEBUG[30151]: chan_zap.c:6127 ss_thread: CID got digit ‘0’
[Apr 7 20:50:48] DEBUG[30151]: chan_zap.c:6127 ss_thread: CID got digit ‘1’
[Apr 7 20:50:48] DEBUG[30151]: chan_zap.c:6127 ss_thread: CID got digit ‘2’
[Apr 7 20:50:48] DEBUG[30151]: chan_zap.c:6127 ss_thread: CID got digit ‘3’
[Apr 7 20:50:48] DEBUG[30151]: chan_zap.c:6127 ss_thread: CID got digit ‘4’
[Apr 7 20:50:48] DEBUG[30151]: chan_zap.c:6127 ss_thread: CID got digit ‘5’
[Apr 7 20:50:49] DEBUG[30151]: chan_zap.c:6127 ss_thread: CID got digit ‘6’
[Apr 7 20:50:49] DEBUG[30151]: chan_zap.c:6127 ss_thread: CID got digit ‘7’
[Apr 7 20:50:49] DEBUG[30151]: chan_zap.c:6127 ss_thread: CID got digit ‘8’
[Apr 7 20:50:49] DEBUG[30151]: chan_zap.c:4489 zt_handle_event: Ignoring Polarity switch to IDLE on channel 4, state 9
[Apr 7 20:50:49] DEBUG[30151]: chan_zap.c:4492 zt_handle_event: Polarity Reversal event occured - DEBUG 2: channel 4, state 9, pol= 0, aonp= 1, honp= 1, pdelay= 600, tv= 708439410
[Apr 7 20:50:49] DEBUG[30151]: chan_zap.c:6127 ss_thread: CID got digit ‘9’
[Apr 7 20:50:49] DEBUG[30151]: chan_zap.c:6127 ss_thread: CID got digit ‘C’
[Apr 7 20:50:51] DEBUG[30151]: chan_zap.c:6138 ss_thread: CID got string ‘D0123456789C’
[Apr 7 20:50:51] DEBUG[30151]: chan_zap.c:6140 ss_thread: CID is ‘0123456789’, flags -1210017998
– Executing [s@pts_incoming:1] Set(“Zap/4-1”, “CALLERID(all)=”" <0123456789>") in new stack
Now it looks like it gives me the correct number of digits and in correct order.
But stil the “Polarity Reversal event” is there!
When I called out I could see this:
-- Executing [0123456789@internal-call-profile-pre:1] NoOp("SIP/5507-082157d8", "AccountCode:call-in-house - HostIP:192.168.0.10 - Exten:0123456789 - SipDomain:192.168.0.10") in new stack
-- Executing [0123456789@internal-call-profile-pre:2] GotoIf("SIP/5507-082157d8", "0?call-in-house-call-profile|0123456789|1") in new stack
-- Executing [0123456789@internal-call-profile-pre:3] GotoIf("SIP/5507-082157d8", "1?call-in-house-call-profile|0123456789|1") in new stack
-- Goto (call-in-house-call-profile,0123456789,1)
-- Executing [0123456789@call-in-house-call-profile:1] NoOp("SIP/5507-082157d8", "Out Ovrigtid kvallar natter - PTS!") in new stack
-- Executing [0123456789@call-in-house-call-profile:2] Macro("SIP/5507-082157d8", "zapout") in new stack
-- Executing [s@macro-zapout:1] NoOp("SIP/5507-082157d8", "zapout - ZAP/4/0123456789") in new stack
[Apr 7 20:51:31] DEBUG[30192]: app_macro.c:337 _macro_exec: Executed application: NoOp
– Executing [s@macro-zapout:2] Festival(“SIP/5507-082157d8”, “Normal Phone Line”) in new stack
== Parsing ‘/etc/asterisk/festival.conf’: Found
[Apr 7 20:51:31] DEBUG[30192]: app_festival.c:378 festival_exec: Text passed to festival server : Normal Phone Line
[Apr 7 20:51:31] DEBUG[30192]: app_festival.c:462 festival_exec: Passing text to festival…
[Apr 7 20:51:31] DEBUG[30192]: app_festival.c:481 festival_exec: Passing data to channel…
[Apr 7 20:51:31] DEBUG[30192]: app_festival.c:506 festival_exec: Festival WV command
[Apr 7 20:51:33] DEBUG[30192]: app_festival.c:252 send_waveform_to_channel: Last frame
[Apr 7 20:51:33] DEBUG[30192]: app_macro.c:337 _macro_exec: Executed application: Festival
– Executing [s@macro-zapout:3] Dial(“SIP/5507-082157d8”, “ZAP/4/0123456789|20|tTr”) in new stack
[Apr 7 20:51:33] DEBUG[30192]: dsp.c:1682 ast_dsp_set_busy_pattern: dsp busy pattern set to 0,0
[Apr 7 20:51:33] DEBUG[30192]: chan_zap.c:1954 zt_call: Dialing ‘0123456789’
[Apr 7 20:51:33] DEBUG[30192]: chan_zap.c:2030 zt_call: Deferring dialing…
– Called 4/0123456789
[Apr 7 20:51:36] DEBUG[30192]: chan_zap.c:1457 zt_train_ec: Engaged echo training on channel 4
[Apr 7 20:51:38] DEBUG[30192]: chan_zap.c:1420 zt_enable_ec: Echo cancellation already on
and when I answered the call this comes up:
[Apr 7 20:51:44] DEBUG[30192]: chan_zap.c:4463 zt_handle_event: Answering on polarity switch!
[Apr 7 20:51:44] DEBUG[30192]: chan_zap.c:4478 zt_handle_event: Polarity Reversal event occured - DEBUG 1: channel 4, state 6, pol= 1, aonp= 1, honp= 1, pdelay= 600, tv= 0
[Apr 7 20:51:44] DEBUG[30192]: chan_zap.c:4485 zt_handle_event: Polarity Reversal detected but NOT hanging up (too close to answer event) on channel 4, state 6
[Apr 7 20:51:44] DEBUG[30192]: chan_zap.c:4492 zt_handle_event: Polarity Reversal event occured - DEBUG 2: channel 4, state 6, pol= 1, aonp= 1, honp= 1, pdelay= 600, tv= 0
– Zap/4-1 answered SIP/5507-082157d8
[Apr 7 20:51:53] DEBUG[30192]: chan_zap.c:4478 zt_handle_event: Polarity Reversal event occured - DEBUG 1: channel 4, state 6, pol= 1, aonp= 1, honp= 1, pdelay= 600, tv= 9408
[Apr 7 20:51:53] DEBUG[30192]: chan_zap.c:4481 zt_handle_event: Polarity Reversal detected and now Hanging up on channel 4
[Apr 7 20:51:53] DEBUG[30192]: chan_zap.c:4492 zt_handle_event: Polarity Reversal event occured - DEBUG 2: channel 4, state 6, pol= 0, aonp= 1, honp= 1, pdelay= 600, tv= 9408
– Hungup ‘Zap/4-1’
== Spawn extension (macro-zapout, s, 3) exited non-zero on ‘SIP/5507-0821e008’ in macro ‘zapout’
== Spawn extension (macro-zapout, s, 3) exited non-zero on ‘SIP/5507-0821e008’
== Starting post polarity CID detection on channel 4
[Apr 7 21:30:04] DEBUG[30307]: dsp.c:1682 ast_dsp_set_busy_pattern: dsp busy pattern set to 0,0
– Starting simple switch on ‘Zap/4-1’
[Apr 7 21:30:04] DEBUG[32298]: chan_zap.c:6109 ss_thread: Receiving DTMF cid on channel Zap/4-1
[Apr 7 21:30:07] WARNING[32298]: chan_zap.c:6117 ss_thread: DTMFCID timed out waiting for ring. Exiting simple switch
– Hungup ‘Zap/4-1’
Several “Polarity Reversal” lines!!!
I change the tip and ring back, but with the same result!
// Nypon
Forget what I said about reversed polarity regardsing tip and ring. I should have looked deeper into DTMF callerid. Polarity reversal should be expected.
[quote]7.2.1 A Normal call
Call against a vacant line can be separated in the following phases:
The exchange occupies the line and changes the lines polarity
and possibly makes a line test (see SS 63 63 25 section 5.2.1.3)
The exchange transmits the number information. The transmission
starts after at least 200 ms after the polarity has changed.
Number information is transmitted for every call.
The exchange transmits the ring signal, i.e. a normal call
to the B-subscriber. This can be made in either polarity.
A possible return to rest polarity is made when
the ring signal is being sent. The ring signal is sent within
1 second from when the stop signal “C” has been sent.
[/quote]
Ok.
I’m not som good to read these logfiles, but should I consider
this as a normal behavior that I can see in the log?
[Apr 7 20:50:49] DEBUG[30151]: chan_zap.c:4489 zt_handle_event: Ignoring Polarity switch to IDLE on channel 4, state 9
[Apr 7 20:50:49] DEBUG[30151]: chan_zap.c:4492 zt_handle_event: Polarity Reversal event occured - DEBUG 2: channel 4, state 9, pol= 0, aonp= 1, honp= 1, pdelay= 600, tv= 708439410
But, I did get a change after I added to the <zapata.conf> file.
answeronpolarityswitch=yes
hanguponpolarityswitch=yes
Hopfully this solve my duplicate digit problem.
Thanks Ike for all the help I got from you!
answeronpolarityswitch=yes
hanguponpolarityswitch=yes
Did not help me with my problem.
It gets
DTMF end ‘C’ received on Zap/4-1, duration 0 ms
twice!
I’m not sure, but I think the same problem is happening in India to!
http://bugs.digium.com/view.php?id=9096#74732
Below is what a incoming call looks like in the log:
[Apr 10 13:51:07] VERBOSE[29240] logger.c: == Starting post polarity CID detection on channel 4
[Apr 10 13:51:07] VERBOSE[14859] logger.c: – Starting simple switch on ‘Zap/4-1’
[Apr 10 13:51:07] DEBUG[14859] chan_zap.c: Receiving DTMF cid on channel Zap/4-1
[Apr 10 13:51:07] DTMF[14859] channel.c: DTMF end ‘D’ received on Zap/4-1, duration 0 ms
[Apr 10 13:51:07] DTMF[14859] channel.c: DTMF begin emulation of ‘D’ with duration 100 queued on Zap/4-1
[Apr 10 13:51:07] DTMF[14859] channel.c: DTMF end emulation of ‘D’ queued on Zap/4-1
[Apr 10 13:51:07] DEBUG[14859] chan_zap.c: CID got digit ‘D’
[Apr 10 13:51:07] DTMF[14859] channel.c: DTMF end ‘0’ received on Zap/4-1, duration 0 ms
[Apr 10 13:51:07] DTMF[14859] channel.c: DTMF end ‘0’ put into dtmf queue on Zap/4-1
[Apr 10 13:51:07] DTMF[14859] channel.c: DTMF begin emulation of ‘0’ with duration 100 queued on Zap/4-1
[Apr 10 13:51:07] DTMF[14859] channel.c: DTMF end ‘1’ received on Zap/4-1, duration 0 ms
[Apr 10 13:51:07] DTMF[14859] channel.c: DTMF end ‘1’ put into dtmf queue on Zap/4-1
[Apr 10 13:51:07] DTMF[14859] channel.c: DTMF end emulation of ‘0’ queued on Zap/4-1
[Apr 10 13:51:07] DEBUG[14859] chan_zap.c: CID got digit ‘0’
[Apr 10 13:51:08] DTMF[14859] channel.c: DTMF begin emulation of ‘1’ with duration 100 queued on Zap/4-1
[Apr 10 13:51:08] DTMF[14859] channel.c: DTMF end ‘9’ received on Zap/4-1, duration 0 ms
[Apr 10 13:51:08] DTMF[14859] channel.c: DTMF end ‘9’ put into dtmf queue on Zap/4-1
[Apr 10 13:51:08] DTMF[14859] channel.c: DTMF end emulation of ‘1’ queued on Zap/4-1
[Apr 10 13:51:08] DEBUG[14859] chan_zap.c: CID got digit ‘1’
[Apr 10 13:51:08] DTMF[14859] channel.c: DTMF begin emulation of ‘9’ with duration 100 queued on Zap/4-1
[Apr 10 13:51:08] DTMF[14859] channel.c: DTMF end ‘6’ received on Zap/4-1, duration 0 ms
[Apr 10 13:51:08] DTMF[14859] channel.c: DTMF end ‘6’ put into dtmf queue on Zap/4-1
[Apr 10 13:51:08] DTMF[14859] channel.c: DTMF end emulation of ‘9’ queued on Zap/4-1
[Apr 10 13:51:08] DEBUG[14859] chan_zap.c: CID got digit ‘9’
[Apr 10 13:51:08] DTMF[14859] channel.c: DTMF begin emulation of ‘6’ with duration 100 queued on Zap/4-1
[Apr 10 13:51:08] DTMF[14859] channel.c: DTMF end ‘0’ received on Zap/4-1, duration 0 ms
[Apr 10 13:51:08] DTMF[14859] channel.c: DTMF end ‘0’ put into dtmf queue on Zap/4-1
[Apr 10 13:51:08] DTMF[14859] channel.c: DTMF end emulation of ‘6’ queued on Zap/4-1
[Apr 10 13:51:08] DEBUG[14859] chan_zap.c: CID got digit ‘6’
[Apr 10 13:51:08] DTMF[14859] channel.c: DTMF begin emulation of ‘0’ with duration 100 queued on Zap/4-1
[Apr 10 13:51:08] DTMF[14859] channel.c: DTMF end ‘1’ received on Zap/4-1, duration 0 ms
[Apr 10 13:51:08] DTMF[14859] channel.c: DTMF end ‘1’ put into dtmf queue on Zap/4-1
[Apr 10 13:51:08] DTMF[14859] channel.c: DTMF end emulation of ‘0’ queued on Zap/4-1
[Apr 10 13:51:08] DEBUG[14859] chan_zap.c: CID got digit ‘0’
[Apr 10 13:51:08] DTMF[14859] channel.c: DTMF end ‘2’ received on Zap/4-1, duration 0 ms
[Apr 10 13:51:08] DTMF[14859] channel.c: DTMF end ‘2’ put into dtmf queue on Zap/4-1
[Apr 10 13:51:08] DTMF[14859] channel.c: DTMF begin emulation of ‘1’ with duration 100 queued on Zap/4-1
[Apr 10 13:51:08] DTMF[14859] channel.c: DTMF end ‘4’ received on Zap/4-1, duration 0 ms
[Apr 10 13:51:08] DTMF[14859] channel.c: DTMF end ‘4’ put into dtmf queue on Zap/4-1
[Apr 10 13:51:08] DTMF[14859] channel.c: DTMF end emulation of ‘1’ queued on Zap/4-1
[Apr 10 13:51:08] DEBUG[14859] chan_zap.c: CID got digit ‘1’
[Apr 10 13:51:08] DTMF[14859] channel.c: DTMF begin emulation of ‘2’ with duration 100 queued on Zap/4-1
[Apr 10 13:51:09] DTMF[14859] channel.c: DTMF end ‘0’ received on Zap/4-1, duration 0 ms
[Apr 10 13:51:09] DTMF[14859] channel.c: DTMF end ‘0’ put into dtmf queue on Zap/4-1
[Apr 10 13:51:09] DTMF[14859] channel.c: DTMF end emulation of ‘2’ queued on Zap/4-1
[Apr 10 13:51:09] DEBUG[14859] chan_zap.c: CID got digit ‘2’
[Apr 10 13:51:09] DTMF[14859] channel.c: DTMF begin emulation of ‘4’ with duration 100 queued on Zap/4-1
[Apr 10 13:51:09] DTMF[14859] channel.c: DTMF end ‘0’ received on Zap/4-1, duration 0 ms
[Apr 10 13:51:09] DTMF[14859] channel.c: DTMF end ‘0’ put into dtmf queue on Zap/4-1
[Apr 10 13:51:09] DTMF[14859] channel.c: DTMF end emulation of ‘4’ queued on Zap/4-1
[Apr 10 13:51:09] DEBUG[14859] chan_zap.c: CID got digit ‘4’
[Apr 10 13:51:09] DTMF[14859] channel.c: DTMF begin emulation of ‘0’ with duration 100 queued on Zap/4-1
[Apr 10 13:51:09] DTMF[14859] channel.c: DTMF end ‘C’ received on Zap/4-1, duration 0 ms
[Apr 10 13:51:09] DTMF[14859] channel.c: DTMF end ‘C’ put into dtmf queue on Zap/4-1
[Apr 10 13:51:09] DTMF[14859] channel.c: DTMF end emulation of ‘0’ queued on Zap/4-1
[Apr 10 13:51:09] DEBUG[14859] chan_zap.c: CID got digit ‘0’
[Apr 10 13:51:09] DEBUG[14859] chan_zap.c: Ignoring Polarity switch to IDLE on channel 4, state 9
[Apr 10 13:51:09] DEBUG[14859] chan_zap.c: Polarity Reversal event occured - DEBUG 2: channel 4, state 9, pol= 0, aonp= 1, honp= 1, pdelay= 600, tv= 942459269
[Apr 10 13:51:09] DTMF[14859] channel.c: DTMF begin emulation of ‘0’ with duration 100 queued on Zap/4-1
[Apr 10 13:51:09] DTMF[14859] channel.c: DTMF end emulation of ‘0’ queued on Zap/4-1
[Apr 10 13:51:09] DEBUG[14859] chan_zap.c: CID got digit ‘0’
[Apr 10 13:51:09] DTMF[14859] channel.c: DTMF begin emulation of ‘C’ with duration 100 queued on Zap/4-1
[Apr 10 13:51:09] DTMF[14859] channel.c: DTMF end emulation of ‘C’ queued on Zap/4-1
[Apr 10 13:51:09] DEBUG[14859] chan_zap.c: CID got digit ‘C’
[Apr 10 13:51:10] DEBUG[14859] chan_zap.c: CID got string ‘D0196012400C’
[Apr 10 13:51:10] DEBUG[14859] chan_zap.c: CID is ‘0196012400’, flags -1210263758
In this call it looks like it gets the number, digits by digits!
But at the end there is no number!
[Apr 10 17:35:21] VERBOSE[29240] logger.c: == Starting post polarity CID detection on channel 4
[Apr 10 17:35:21] VERBOSE[26821] logger.c: – Starting simple switch on ‘Zap/4-1’
[Apr 10 17:35:21] DEBUG[26821] chan_zap.c: Receiving DTMF cid on channel Zap/4-1
[Apr 10 17:35:21] DEBUG[26821] chan_zap.c: CID got string ‘’
[Apr 10 17:35:21] DEBUG[26821] callerid.c: No cid detected
[Apr 10 17:35:21] DEBUG[26821] chan_zap.c: CID is ‘’, flags 8
[Apr 10 17:35:21] VERBOSE[26821] logger.c: – Executing [s@pts_incoming:1] Set(“Zap/4-1”, “CALLERID(all)=”" <>") in new stack
[Apr 10 17:35:21] VERBOSE[26821] logger.c: – Executing [s@pts_incoming:2] Dial(“Zap/4-1”, “SIP/5507&SIP/Micke_Helen&SIP/Nypon_Fring|20|tTr”) in new stack
[Apr 10 17:35:21] VERBOSE[26821] logger.c: – Called 5507
[Apr 10 17:35:21] WARNING[26821] app_dial.c: Unable to create channel of type ‘SIP’ (cause 3 - No route to destination)
[Apr 10 17:35:21] WARNING[26821] app_dial.c: Unable to create channel of type ‘SIP’ (cause 3 - No route to destination)
[Apr 10 17:35:21] VERBOSE[26821] logger.c: – SIP/5507-08219d20 is ringing
[Apr 10 17:35:21] DTMF[26821] channel.c: DTMF end ‘D’ received on Zap/4-1, duration 0 ms
[Apr 10 17:35:21] DTMF[26821] channel.c: DTMF begin emulation of ‘D’ with duration 100 queued on Zap/4-1
[Apr 10 17:35:22] DTMF[26821] channel.c: DTMF end emulation of ‘D’ queued on Zap/4-1
[Apr 10 17:35:22] DTMF[26821] channel.c: DTMF end ‘0’ received on Zap/4-1, duration 0 ms
[Apr 10 17:35:22] DTMF[26821] channel.c: DTMF end ‘0’ put into dtmf queue on Zap/4-1
[Apr 10 17:35:22] DTMF[26821] channel.c: DTMF begin emulation of ‘0’ with duration 100 queued on Zap/4-1
[Apr 10 17:35:22] DTMF[26821] channel.c: DTMF end ‘4’ received on Zap/4-1, duration 0 ms
[Apr 10 17:35:22] DTMF[26821] channel.c: DTMF end ‘4’ put into dtmf queue on Zap/4-1
[Apr 10 17:35:22] DTMF[26821] channel.c: DTMF end emulation of ‘0’ queued on Zap/4-1
[Apr 10 17:35:22] DTMF[26821] channel.c: DTMF begin emulation of ‘4’ with duration 100 queued on Zap/4-1
[Apr 10 17:35:22] DTMF[26821] channel.c: DTMF end ‘9’ received on Zap/4-1, duration 0 ms
[Apr 10 17:35:22] DTMF[26821] channel.c: DTMF end ‘9’ put into dtmf queue on Zap/4-1
[Apr 10 17:35:22] DTMF[26821] channel.c: DTMF end emulation of ‘4’ queued on Zap/4-1
[Apr 10 17:35:22] DTMF[26821] channel.c: DTMF begin emulation of ‘9’ with duration 100 queued on Zap/4-1
[Apr 10 17:35:22] DTMF[26821] channel.c: DTMF end ‘2’ received on Zap/4-1, duration 0 ms
[Apr 10 17:35:22] DTMF[26821] channel.c: DTMF end ‘2’ put into dtmf queue on Zap/4-1
[Apr 10 17:35:22] DTMF[26821] channel.c: DTMF end emulation of ‘9’ queued on Zap/4-1
[Apr 10 17:35:22] DTMF[26821] channel.c: DTMF begin emulation of ‘2’ with duration 100 queued on Zap/4-1
[Apr 10 17:35:22] DTMF[26821] channel.c: DTMF end ‘3’ received on Zap/4-1, duration 0 ms
[Apr 10 17:35:22] DTMF[26821] channel.c: DTMF end ‘3’ put into dtmf queue on Zap/4-1
[Apr 10 17:35:22] DTMF[26821] channel.c: DTMF end emulation of ‘2’ queued on Zap/4-1
[Apr 10 17:35:22] DTMF[26821] channel.c: DTMF begin emulation of ‘3’ with duration 100 queued on Zap/4-1
[Apr 10 17:35:22] DTMF[26821] channel.c: DTMF end ‘0’ received on Zap/4-1, duration 0 ms
[Apr 10 17:35:22] DTMF[26821] channel.c: DTMF end ‘0’ put into dtmf queue on Zap/4-1
[Apr 10 17:35:22] DTMF[26821] channel.c: DTMF end emulation of ‘3’ queued on Zap/4-1
[Apr 10 17:35:22] DTMF[26821] channel.c: DTMF end ‘3’ received on Zap/4-1, duration 0 ms
[Apr 10 17:35:22] DTMF[26821] channel.c: DTMF end ‘3’ put into dtmf queue on Zap/4-1
[Apr 10 17:35:22] DTMF[26821] channel.c: DTMF begin emulation of ‘0’ with duration 100 queued on Zap/4-1
[Apr 10 17:35:23] DTMF[26821] channel.c: DTMF end ‘5’ received on Zap/4-1, duration 0 ms
[Apr 10 17:35:23] DTMF[26821] channel.c: DTMF end ‘5’ put into dtmf queue on Zap/4-1
[Apr 10 17:35:23] DTMF[26821] channel.c: DTMF end emulation of ‘0’ queued on Zap/4-1
[Apr 10 17:35:23] DTMF[26821] channel.c: DTMF begin emulation of ‘3’ with duration 100 queued on Zap/4-1
[Apr 10 17:35:23] DTMF[26821] channel.c: DTMF end ‘1’ received on Zap/4-1, duration 0 ms
[Apr 10 17:35:23] DTMF[26821] channel.c: DTMF end ‘1’ put into dtmf queue on Zap/4-1
[Apr 10 17:35:23] DTMF[26821] channel.c: DTMF end emulation of ‘3’ queued on Zap/4-1
[Apr 10 17:35:23] DTMF[26821] channel.c: DTMF begin emulation of ‘5’ with duration 100 queued on Zap/4-1
[Apr 10 17:35:23] DTMF[26821] channel.c: DTMF end ‘C’ received on Zap/4-1, duration 0 ms
[Apr 10 17:35:23] DTMF[26821] channel.c: DTMF end ‘C’ put into dtmf queue on Zap/4-1
[Apr 10 17:35:23] DTMF[26821] channel.c: DTMF end emulation of ‘5’ queued on Zap/4-1
[Apr 10 17:35:23] DTMF[26821] channel.c: DTMF begin emulation of ‘1’ with duration 100 queued on Zap/4-1
[Apr 10 17:35:23] DEBUG[26821] chan_zap.c: Polarity Reversal event occured - DEBUG 1: channel 4, state 4, pol= 1, aonp= 1, honp= 1, pdelay= 600, tv= 5407365
[Apr 10 17:35:23] DEBUG[26821] chan_zap.c: Polarity Reversal detected and now Hanging up on channel 4
[Apr 10 17:35:23] DEBUG[26821] chan_zap.c: Polarity Reversal event occured - DEBUG 2: channel 4, state 4, pol= 0, aonp= 1, honp= 1, pdelay= 600, tv= 5407366
[Apr 10 17:35:23] VERBOSE[26821] logger.c: == Spawn extension (pts_incoming, s, 2) exited non-zero on ‘Zap/4-1’
[Apr 10 17:35:23] VERBOSE[26821] logger.c: – Executing [h@pts_incoming:1] Hangup(“Zap/4-1”, “”) in new stack
[Apr 10 17:35:23] VERBOSE[26821] logger.c: == Spawn extension (pts_incoming, h, 1) exited non-zero on ‘Zap/4-1’
[Apr 10 17:35:23] VERBOSE[26821] logger.c: – Hungup ‘Zap/4-1’
[Apr 10 17:35:31] VERBOSE[26829] logger.c: – Starting simple switch on ‘Zap/4-1’
[Apr 10 17:35:31] VERBOSE[26829] logger.c: – Executing [s@pts_incoming:1] Set(“Zap/4-1”, “CALLERID(all)=”" <>") in new stack
[Apr 10 17:35:31] VERBOSE[26829] logger.c: – Executing [s@pts_incoming:2] Dial(“Zap/4-1”, “SIP/5507&SIP/Micke_Helen&SIP/Nypon_Fring|20|tTr”) in new stack
[Apr 10 17:35:31] VERBOSE[26829] logger.c: – Called 5507
[Apr 10 17:35:31] WARNING[26829] app_dial.c: Unable to create channel of type ‘SIP’ (cause 3 - No route to destination)
[Apr 10 17:35:31] WARNING[26829] app_dial.c: Unable to create channel of type ‘SIP’ (cause 3 - No route to destination)
[Apr 10 17:35:31] VERBOSE[26829] logger.c: – SIP/5507-08219d20 is ringing
[Apr 10 17:35:51] VERBOSE[26829] logger.c: == Spawn extension (pts_incoming, s, 2) exited non-zero on ‘Zap/4-1’
[Apr 10 17:35:51] VERBOSE[26829] logger.c: – Executing [h@pts_incoming:1] Hangup(“Zap/4-1”, “”) in new stack
[Apr 10 17:35:51] VERBOSE[26829] logger.c: == Spawn extension (pts_incoming, h, 1) exited non-zero on ‘Zap/4-1’
[Apr 10 17:35:51] VERBOSE[26829] logger.c: – Hungup ‘Zap/4-1’