Debug on CVS source:
--------------------


Asterisk Ready.
*CLI>   == Starting post polarity CID detection on channel 4
Dec 12 15:53:52 DEBUG[26880]: app_queue.c:371 changethread: Device 'Zap/4' changed to state '2'
    -- Starting simple switch on 'Zap/4-1'
Dec 12 15:53:52 DEBUG[26880]: chan_zap.c:5263 ss_thread: Receiving DTMF cid on channel Zap/4-1
Dec 12 15:53:52 DEBUG[26880]: chan_zap.c:4115 zt_read: DTMF digit: D on Zap/4-1
Dec 12 15:53:52 DEBUG[26880]: chan_zap.c:5279 ss_thread: CID got digit 'D'
Dec 12 15:53:52 DEBUG[26880]: chan_zap.c:4115 zt_read: DTMF digit: 0 on Zap/4-1
Dec 12 15:53:52 DEBUG[26880]: chan_zap.c:5279 ss_thread: CID got digit '0'
Dec 12 15:53:52 DEBUG[26880]: chan_zap.c:4115 zt_read: DTMF digit: 7 on Zap/4-1
Dec 12 15:53:52 DEBUG[26880]: chan_zap.c:5279 ss_thread: CID got digit '7'
Dec 12 15:53:52 DEBUG[26880]: chan_zap.c:4115 zt_read: DTMF digit: 9 on Zap/4-1
Dec 12 15:53:52 DEBUG[26880]: chan_zap.c:5279 ss_thread: CID got digit '9'
Dec 12 15:53:53 DEBUG[26880]: chan_zap.c:4115 zt_read: DTMF digit: 9 on Zap/4-1
Dec 12 15:53:53 DEBUG[26880]: chan_zap.c:5279 ss_thread: CID got digit '9'
Dec 12 15:53:53 DEBUG[26880]: chan_zap.c:4115 zt_read: DTMF digit: 8 on Zap/4-1
Dec 12 15:53:53 DEBUG[26880]: chan_zap.c:5279 ss_thread: CID got digit '8'
Dec 12 15:53:53 DEBUG[26880]: chan_zap.c:4115 zt_read: DTMF digit: 3 on Zap/4-1
Dec 12 15:53:53 DEBUG[26880]: chan_zap.c:5279 ss_thread: CID got digit '3'
Dec 12 15:53:53 DEBUG[26880]: chan_zap.c:4115 zt_read: DTMF digit: 1 on Zap/4-1
Dec 12 15:53:53 DEBUG[26880]: chan_zap.c:5279 ss_thread: CID got digit '1'
Dec 12 15:53:53 DEBUG[26880]: chan_zap.c:4115 zt_read: DTMF digit: 2 on Zap/4-1
Dec 12 15:53:53 DEBUG[26880]: chan_zap.c:5279 ss_thread: CID got digit '2'
Dec 12 15:53:53 DEBUG[26880]: chan_zap.c:4115 zt_read: DTMF digit: 0 on Zap/4-1
Dec 12 15:53:53 DEBUG[26880]: chan_zap.c:5279 ss_thread: CID got digit '0'
Dec 12 15:53:53 DEBUG[26880]: chan_zap.c:4115 zt_read: DTMF digit: 0 on Zap/4-1
Dec 12 15:53:53 DEBUG[26880]: chan_zap.c:5279 ss_thread: CID got digit '0'
Dec 12 15:53:54 DEBUG[26880]: chan_zap.c:4115 zt_read: DTMF digit: C on Zap/4-1
Dec 12 15:53:54 DEBUG[26880]: chan_zap.c:5279 ss_thread: CID got digit 'C'
Dec 12 15:53:55 DEBUG[26880]: chan_zap.c:3837 __zt_exception: Exception on 13, channel 4
Dec 12 15:53:55 DEBUG[26880]: chan_zap.c:3105 zt_handle_event: Got event Polarity Reversal(17) on channel 4 (index 0)
Dec 12 15:53:55 DEBUG[26880]: chan_zap.c:3732 zt_handle_event: Ignore Reverse Polarity on channel 4, state 9
Dec 12 15:53:56 WARNING[26880]: chan_zap.c:5271 ss_thread: DTMFCID timed out waiting for ring. Exiting simple switch
Dec 12 15:53:56 DEBUG[26880]: chan_zap.c:1993 zt_hangup: Hangup: channel: 4 index = 0, normal = 13, callwait = -1, thirdcall = -1
Dec 12 15:53:56 DEBUG[26880]: chan_zap.c:1280 zt_disable_ec: disabled echo cancellation on channel 4
Dec 12 15:53:56 DEBUG[26880]: chan_zap.c:2399 zt_setoption: Set option TDD MODE, value: OFF(0) on Zap/4-1
Dec 12 15:53:56 DEBUG[26880]: chan_zap.c:1217 update_conf: Updated conferencing on 4, with 0 conference users
    -- Hungup 'Zap/4-1'
Dec 12 15:53:56 DEBUG[26880]: app_queue.c:371 changethread: Device 'Zap/4' changed to state '0'
Dec 12 15:54:02 DEBUG[26880]: app_queue.c:371 changethread: Device 'Zap/4' changed to state '2'
    -- Starting simple switch on 'Zap/4-1'
    -- Executing Dial("Zap/4-1", "SIP/101|15") in new stack
Dec 12 15:54:02 DEBUG[26880]: chan_sip.c:1258 create_addr: Setting NAT on RTP to 4
Dec 12 15:54:02 DEBUG[26880]: chan_sip.c:1262 create_addr: Setting NAT on VRTP to 4
Dec 12 15:54:02 DEBUG[26880]: chan_sip.c:1434 sip_call: Outgoing Call for 101
Dec 12 15:54:02 DEBUG[26880]: chan_sip.c:1574 update_user_counter: Call from user '101' is 1 out of 0
    -- Called 101
Dec 12 15:54:02 DEBUG[26880]: chan_sip.c:872 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '020606a55aa0e26a62f76403766090d3@kristiansson.se' Request 102: Found
Dec 12 15:54:02 DEBUG[26880]: chan_sip.c:872 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '020606a55aa0e26a62f76403766090d3@kristiansson.se' Request 102: Found
    -- SIP/101-31af is ringing




******************

Suggested patch:
---------------------



--- chan_zap.c		2004-12-11 12:23:19.000000000 +0100
+++ chan_zap.c.patch	2004-12-12 10:31:04.564455849 +0100
@@ -5263,10 +5263,9 @@
                                ast_log(LOG_DEBUG, "Receiving DTMF cid on "
                                        "channel %s\n", chan->name);
                                zt_setlinear(p->subs[index].zfd, 0);
-                               res = 2000;
                                for (;;) {
                                        struct ast_frame *f;
-                                       res = ast_waitfor(chan, res);
+                                       res = ast_waitfor(chan, 2000);
                                        if (res <= 0) {
                                                ast_log(LOG_WARNING, "DTMFCID timed out waiting for ring. "
                                                        "Exiting simple switch\n");
@@ -5277,7 +5276,6 @@
                                        if (f->frametype == AST_FRAME_DTMF) {
                                                dtmfbuf[i++] = f->subclass;
                                                ast_log(LOG_DEBUG, "CID got digit '%c'\n", f->subclass);
-                                               res = 2000;
                                        }
                                        ast_frfree(f);
                                        if (chan->_state == AST_STATE_RING ||






*******************



Debug after patch:
-----------------------


Asterisk Ready.
*CLI>   == Starting post polarity CID detection on channel 4
Dec 12 15:58:54 DEBUG[734]: app_queue.c:371 changethread: Device 'Zap/4' changed to state '2'
    -- Starting simple switch on 'Zap/4-1'
Dec 12 15:58:54 DEBUG[734]: chan_zap.c:5263 ss_thread: Receiving DTMF cid on channel Zap/4-1
Dec 12 15:58:54 DEBUG[734]: chan_zap.c:4115 zt_read: DTMF digit: D on Zap/4-1
Dec 12 15:58:54 DEBUG[734]: chan_zap.c:5278 ss_thread: CID got digit 'D'
Dec 12 15:58:54 DEBUG[734]: chan_zap.c:4115 zt_read: DTMF digit: 0 on Zap/4-1
Dec 12 15:58:54 DEBUG[734]: chan_zap.c:5278 ss_thread: CID got digit '0'
Dec 12 15:58:55 DEBUG[734]: chan_zap.c:4115 zt_read: DTMF digit: 7 on Zap/4-1
Dec 12 15:58:55 DEBUG[734]: chan_zap.c:5278 ss_thread: CID got digit '7'
Dec 12 15:58:55 DEBUG[734]: chan_zap.c:4115 zt_read: DTMF digit: 9 on Zap/4-1
Dec 12 15:58:55 DEBUG[734]: chan_zap.c:5278 ss_thread: CID got digit '9'
Dec 12 15:58:55 DEBUG[734]: chan_zap.c:4115 zt_read: DTMF digit: 9 on Zap/4-1
Dec 12 15:58:55 DEBUG[734]: chan_zap.c:5278 ss_thread: CID got digit '9'
Dec 12 15:58:55 DEBUG[734]: chan_zap.c:4115 zt_read: DTMF digit: 8 on Zap/4-1
Dec 12 15:58:55 DEBUG[734]: chan_zap.c:5278 ss_thread: CID got digit '8'
Dec 12 15:58:55 DEBUG[734]: chan_zap.c:4115 zt_read: DTMF digit: 3 on Zap/4-1
Dec 12 15:58:55 DEBUG[734]: chan_zap.c:5278 ss_thread: CID got digit '3'
Dec 12 15:58:55 DEBUG[734]: chan_zap.c:4115 zt_read: DTMF digit: 1 on Zap/4-1
Dec 12 15:58:55 DEBUG[734]: chan_zap.c:5278 ss_thread: CID got digit '1'
Dec 12 15:58:55 DEBUG[734]: chan_zap.c:4115 zt_read: DTMF digit: 2 on Zap/4-1
Dec 12 15:58:55 DEBUG[734]: chan_zap.c:5278 ss_thread: CID got digit '2'
Dec 12 15:58:56 DEBUG[734]: chan_zap.c:4115 zt_read: DTMF digit: 0 on Zap/4-1
Dec 12 15:58:56 DEBUG[734]: chan_zap.c:5278 ss_thread: CID got digit '0'
Dec 12 15:58:56 DEBUG[734]: chan_zap.c:4115 zt_read: DTMF digit: 0 on Zap/4-1
Dec 12 15:58:56 DEBUG[734]: chan_zap.c:5278 ss_thread: CID got digit '0'
Dec 12 15:58:56 DEBUG[734]: chan_zap.c:4115 zt_read: DTMF digit: C on Zap/4-1
Dec 12 15:58:56 DEBUG[734]: chan_zap.c:5278 ss_thread: CID got digit 'C'
Dec 12 15:58:58 DEBUG[734]: chan_sip.c:1258 create_addr: Setting NAT on RTP to 4
Dec 12 15:58:58 DEBUG[734]: chan_sip.c:1262 create_addr: Setting NAT on VRTP to 4
Dec 12 15:58:58 DEBUG[734]: chan_zap.c:3837 __zt_exception: Exception on 13, channel 4
Dec 12 15:58:58 DEBUG[734]: chan_zap.c:3105 zt_handle_event: Got event Polarity Reversal(17) on channel 4 (index 0)
Dec 12 15:58:58 DEBUG[734]: chan_zap.c:3732 zt_handle_event: Ignore Reverse Polarity on channel 4, state 9
Dec 12 15:59:04 DEBUG[734]: chan_zap.c:3837 __zt_exception: Exception on 13, channel 4
Dec 12 15:59:04 DEBUG[734]: chan_zap.c:3105 zt_handle_event: Got event Ring/Answered(2) on channel 4 (index 0)
Dec 12 15:59:04 DEBUG[734]: chan_zap.c:5288 ss_thread: CID got string 'D0799831200C'
Dec 12 15:59:04 DEBUG[734]: chan_zap.c:5290 ss_thread: CID is '0799831200', flags 0
    -- Executing Dial("Zap/4-1", "SIP/101|15") in new stack
Dec 12 15:59:04 DEBUG[734]: chan_sip.c:1258 create_addr: Setting NAT on RTP to 4
Dec 12 15:59:04 DEBUG[734]: chan_sip.c:1262 create_addr: Setting NAT on VRTP to 4
Dec 12 15:59:04 DEBUG[734]: chan_sip.c:1434 sip_call: Outgoing Call for 101
Dec 12 15:59:04 DEBUG[734]: chan_sip.c:1574 update_user_counter: Call from user '101' is 1 out of 0
    -- Called 101
Dec 12 15:59:04 DEBUG[734]: chan_sip.c:872 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '7dfe9c2640ac674f02c7852847592abc@kristiansson.se' Request 102: Found
Dec 12 15:59:04 DEBUG[734]: chan_sip.c:872 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '7dfe9c2640ac674f02c7852847592abc@kristiansson.se' Request 102: Found
    -- SIP/101-bd9a is ringing