******************************************************************************************************************* ******************************************************************************************************************* ****** Test: #1 ****** Result: SUCCESS ****** Phone: Aastra IP phone connected directly to Asterisk ****** DTMF Entered: 123 ****** DTMF Recieved by Read application: 123 ****** Notes: This scenario worked fine in 1.4.24 ******************************************************************************************************************* ******************************************************************************************************************* -- Executing [INBOUND@acd_inbound_call:3] Read("SIP/connectfirst.com-15e30e80", "test") in new stack [May 4 14:24:55] DEBUG[3655]: rtp.c:792 process_rfc2833: START, dur=20 [May 4 14:24:55] DEBUG[3655]: rtp.c:795 process_rfc2833: ..... begin=2058957879, timeout=2058958029, duration=0 [May 4 14:24:55] DTMF[3655]: channel.c:2297 __ast_read: DTMF begin '1' received on SIP/connectfirst.com-15e30e80 [May 4 14:24:55] DTMF[3655]: channel.c:2301 __ast_read: DTMF begin ignored '1' on SIP/connectfirst.com-15e30e80 [May 4 14:24:55] DEBUG[3655]: rtp.c:795 process_rfc2833: ..... begin=2058957879, timeout=2058958049, duration=20 [May 4 14:24:55] DEBUG[3655]: rtp.c:795 process_rfc2833: ..... begin=2058957879, timeout=2058958069, duration=40 [May 4 14:24:55] DEBUG[3655]: rtp.c:795 process_rfc2833: ..... begin=2058957879, timeout=2058958089, duration=60 [May 4 14:24:55] DEBUG[3655]: rtp.c:766 process_rfc2833: normalend, dur=80 [May 4 14:24:55] DTMF[3655]: channel.c:2229 __ast_read: DTMF end '1' received on SIP/connectfirst.com-15e30e80, duration 80 ms [May 4 14:24:55] DTMF[3655]: channel.c:2282 __ast_read: DTMF end passthrough '1' on SIP/connectfirst.com-15e30e80 [May 4 14:24:56] DEBUG[3655]: rtp.c:792 process_rfc2833: START, dur=20 [May 4 14:24:56] DEBUG[3655]: rtp.c:795 process_rfc2833: ..... begin=2058962679, timeout=2058962829, duration=0 [May 4 14:24:56] DTMF[3655]: channel.c:2297 __ast_read: DTMF begin '2' received on SIP/connectfirst.com-15e30e80 [May 4 14:24:56] DTMF[3655]: channel.c:2301 __ast_read: DTMF begin ignored '2' on SIP/connectfirst.com-15e30e80 [May 4 14:24:56] DEBUG[3655]: rtp.c:795 process_rfc2833: ..... begin=2058962679, timeout=2058962849, duration=20 [May 4 14:24:56] DEBUG[3655]: rtp.c:795 process_rfc2833: ..... begin=2058962679, timeout=2058962869, duration=40 [May 4 14:24:56] DEBUG[3655]: rtp.c:795 process_rfc2833: ..... begin=2058962679, timeout=2058962889, duration=60 [May 4 14:24:56] DEBUG[3655]: rtp.c:766 process_rfc2833: normalend, dur=80 [May 4 14:24:56] DTMF[3655]: channel.c:2229 __ast_read: DTMF end '2' received on SIP/connectfirst.com-15e30e80, duration 80 ms [May 4 14:24:56] DTMF[3655]: channel.c:2282 __ast_read: DTMF end passthrough '2' on SIP/connectfirst.com-15e30e80 [May 4 14:24:56] DEBUG[3655]: rtp.c:792 process_rfc2833: START, dur=20 [May 4 14:24:56] DEBUG[3655]: rtp.c:795 process_rfc2833: ..... begin=2058967479, timeout=2058967629, duration=0 [May 4 14:24:56] DTMF[3655]: channel.c:2297 __ast_read: DTMF begin '3' received on SIP/connectfirst.com-15e30e80 [May 4 14:24:56] DTMF[3655]: channel.c:2301 __ast_read: DTMF begin ignored '3' on SIP/connectfirst.com-15e30e80 [May 4 14:24:56] DEBUG[3655]: rtp.c:795 process_rfc2833: ..... begin=2058967479, timeout=2058967649, duration=20 [May 4 14:24:56] DEBUG[3655]: rtp.c:795 process_rfc2833: ..... begin=2058967479, timeout=2058967669, duration=40 [May 4 14:24:56] DEBUG[3655]: rtp.c:795 process_rfc2833: ..... begin=2058967479, timeout=2058967689, duration=60 [May 4 14:24:56] DEBUG[3655]: rtp.c:766 process_rfc2833: normalend, dur=80 [May 4 14:24:56] DTMF[3655]: channel.c:2229 __ast_read: DTMF end '3' received on SIP/connectfirst.com-15e30e80, duration 80 ms [May 4 14:24:56] DTMF[3655]: channel.c:2282 __ast_read: DTMF end passthrough '3' on SIP/connectfirst.com-15e30e80 -- User entered '123' ******************************************************************************************************************* ******************************************************************************************************************* ****** Test: #2 ****** Result: FAILURE ****** Phone: Landline Home Phone ****** DTMF Entered: 123# ****** DTMF Recieved by Read application: 111222333 ****** Notes: This scenario worked fine in 1.4.24 but is now BROKEN in 1.4.24.1 w/ supplied patch ******************************************************************************************************************* ******************************************************************************************************************* -- Executing [INBOUND@acd_inbound_call:3] Read("SIP/4.68.250.148-15e30e80", "test") in new stack [May 4 14:27:06] DEBUG[3662]: rtp.c:792 process_rfc2833: START, dur=20 [May 4 14:27:06] DEBUG[3662]: rtp.c:795 process_rfc2833: ..... begin=1043006231, timeout=1043006401, duration=20 [May 4 14:27:06] DTMF[3662]: channel.c:2297 __ast_read: DTMF begin '1' received on SIP/4.68.250.148-15e30e80 [May 4 14:27:06] DTMF[3662]: channel.c:2301 __ast_read: DTMF begin ignored '1' on SIP/4.68.250.148-15e30e80 [May 4 14:27:06] DTMF[3662]: channel.c:2229 __ast_read: DTMF end '1' received on SIP/4.68.250.148-15e30e80, duration 20 ms [May 4 14:27:06] DTMF[3662]: channel.c:2282 __ast_read: DTMF end passthrough '1' on SIP/4.68.250.148-15e30e80 [May 4 14:27:06] DEBUG[3662]: rtp.c:792 process_rfc2833: START, dur=80 [May 4 14:27:06] DEBUG[3662]: rtp.c:795 process_rfc2833: ..... begin=1043006231, timeout=1043006413, duration=32 [May 4 14:27:06] DTMF[3662]: channel.c:2297 __ast_read: DTMF begin '1' received on SIP/4.68.250.148-15e30e80 [May 4 14:27:06] DTMF[3662]: channel.c:2301 __ast_read: DTMF begin ignored '1' on SIP/4.68.250.148-15e30e80 [May 4 14:27:06] DTMF[3662]: channel.c:2229 __ast_read: DTMF end '1' received on SIP/4.68.250.148-15e30e80, duration 32 ms [May 4 14:27:06] DTMF[3662]: channel.c:2282 __ast_read: DTMF end passthrough '1' on SIP/4.68.250.148-15e30e80 [May 4 14:27:06] DEBUG[3662]: rtp.c:792 process_rfc2833: START, dur=80 [May 4 14:27:06] DEBUG[3662]: rtp.c:795 process_rfc2833: ..... begin=1043006231, timeout=1043006431, duration=50 [May 4 14:27:06] DTMF[3662]: channel.c:2297 __ast_read: DTMF begin '1' received on SIP/4.68.250.148-15e30e80 [May 4 14:27:06] DTMF[3662]: channel.c:2301 __ast_read: DTMF begin ignored '1' on SIP/4.68.250.148-15e30e80 [May 4 14:27:06] DEBUG[3662]: rtp.c:795 process_rfc2833: ..... begin=1043006231, timeout=1043006450, duration=69 [May 4 14:27:06] DEBUG[3662]: rtp.c:795 process_rfc2833: ..... begin=1043006231, timeout=1043006473, duration=92 [May 4 14:27:06] DEBUG[3662]: rtp.c:795 process_rfc2833: ..... begin=1043006231, timeout=1043006493, duration=112 [May 4 14:27:06] DEBUG[3662]: rtp.c:795 process_rfc2833: ..... begin=1043006231, timeout=1043006512, duration=131 [May 4 14:27:06] DEBUG[3662]: rtp.c:795 process_rfc2833: ..... begin=1043006231, timeout=1043006530, duration=149 [May 4 14:27:06] DEBUG[3662]: rtp.c:766 process_rfc2833: normalend, dur=160 [May 4 14:27:06] DTMF[3662]: channel.c:2229 __ast_read: DTMF end '1' received on SIP/4.68.250.148-15e30e80, duration 160 ms [May 4 14:27:06] DTMF[3662]: channel.c:2282 __ast_read: DTMF end passthrough '1' on SIP/4.68.250.148-15e30e80 [May 4 14:27:06] DEBUG[3662]: rtp.c:792 process_rfc2833: START, dur=20 [May 4 14:27:06] DEBUG[3662]: rtp.c:795 process_rfc2833: ..... begin=1043010391, timeout=1043010561, duration=20 [May 4 14:27:06] DTMF[3662]: channel.c:2297 __ast_read: DTMF begin '2' received on SIP/4.68.250.148-15e30e80 [May 4 14:27:06] DTMF[3662]: channel.c:2301 __ast_read: DTMF begin ignored '2' on SIP/4.68.250.148-15e30e80 [May 4 14:27:06] DTMF[3662]: channel.c:2229 __ast_read: DTMF end '2' received on SIP/4.68.250.148-15e30e80, duration 20 ms [May 4 14:27:06] DTMF[3662]: channel.c:2282 __ast_read: DTMF end passthrough '2' on SIP/4.68.250.148-15e30e80 [May 4 14:27:06] DEBUG[3662]: rtp.c:792 process_rfc2833: START, dur=80 [May 4 14:27:06] DEBUG[3662]: rtp.c:795 process_rfc2833: ..... begin=1043010391, timeout=1043010568, duration=27 [May 4 14:27:06] DTMF[3662]: channel.c:2297 __ast_read: DTMF begin '2' received on SIP/4.68.250.148-15e30e80 [May 4 14:27:06] DTMF[3662]: channel.c:2301 __ast_read: DTMF begin ignored '2' on SIP/4.68.250.148-15e30e80 [May 4 14:27:06] DTMF[3662]: channel.c:2229 __ast_read: DTMF end '2' received on SIP/4.68.250.148-15e30e80, duration 27 ms [May 4 14:27:06] DTMF[3662]: channel.c:2282 __ast_read: DTMF end passthrough '2' on SIP/4.68.250.148-15e30e80 [May 4 14:27:06] DEBUG[3662]: rtp.c:792 process_rfc2833: START, dur=80 [May 4 14:27:06] DEBUG[3662]: rtp.c:795 process_rfc2833: ..... begin=1043010391, timeout=1043010590, duration=49 [May 4 14:27:06] DTMF[3662]: channel.c:2297 __ast_read: DTMF begin '2' received on SIP/4.68.250.148-15e30e80 [May 4 14:27:06] DTMF[3662]: channel.c:2301 __ast_read: DTMF begin ignored '2' on SIP/4.68.250.148-15e30e80 [May 4 14:27:06] DEBUG[3662]: rtp.c:795 process_rfc2833: ..... begin=1043010391, timeout=1043010611, duration=70 [May 4 14:27:06] DEBUG[3662]: rtp.c:795 process_rfc2833: ..... begin=1043010391, timeout=1043010629, duration=88 [May 4 14:27:06] DEBUG[3662]: rtp.c:795 process_rfc2833: ..... begin=1043010391, timeout=1043010651, duration=110 [May 4 14:27:06] DEBUG[3662]: rtp.c:795 process_rfc2833: ..... begin=1043010391, timeout=1043010669, duration=128 [May 4 14:27:06] DEBUG[3662]: rtp.c:795 process_rfc2833: ..... begin=1043010391, timeout=1043010691, duration=150 [May 4 14:27:06] DEBUG[3662]: rtp.c:766 process_rfc2833: normalend, dur=160 [May 4 14:27:06] DTMF[3662]: channel.c:2229 __ast_read: DTMF end '2' received on SIP/4.68.250.148-15e30e80, duration 160 ms [May 4 14:27:06] DTMF[3662]: channel.c:2282 __ast_read: DTMF end passthrough '2' on SIP/4.68.250.148-15e30e80 [May 4 14:27:07] DEBUG[3662]: rtp.c:792 process_rfc2833: START, dur=20 [May 4 14:27:07] DEBUG[3662]: rtp.c:795 process_rfc2833: ..... begin=1043014711, timeout=1043014881, duration=20 [May 4 14:27:07] DTMF[3662]: channel.c:2297 __ast_read: DTMF begin '3' received on SIP/4.68.250.148-15e30e80 [May 4 14:27:07] DTMF[3662]: channel.c:2301 __ast_read: DTMF begin ignored '3' on SIP/4.68.250.148-15e30e80 [May 4 14:27:07] DTMF[3662]: channel.c:2229 __ast_read: DTMF end '3' received on SIP/4.68.250.148-15e30e80, duration 20 ms [May 4 14:27:07] DTMF[3662]: channel.c:2282 __ast_read: DTMF end passthrough '3' on SIP/4.68.250.148-15e30e80 [May 4 14:27:07] DEBUG[3662]: rtp.c:792 process_rfc2833: START, dur=80 [May 4 14:27:07] DEBUG[3662]: rtp.c:795 process_rfc2833: ..... begin=1043014711, timeout=1043014891, duration=30 [May 4 14:27:07] DTMF[3662]: channel.c:2297 __ast_read: DTMF begin '3' received on SIP/4.68.250.148-15e30e80 [May 4 14:27:07] DTMF[3662]: channel.c:2301 __ast_read: DTMF begin ignored '3' on SIP/4.68.250.148-15e30e80 [May 4 14:27:07] DTMF[3662]: channel.c:2229 __ast_read: DTMF end '3' received on SIP/4.68.250.148-15e30e80, duration 30 ms [May 4 14:27:07] DTMF[3662]: channel.c:2282 __ast_read: DTMF end passthrough '3' on SIP/4.68.250.148-15e30e80 [May 4 14:27:07] DEBUG[3662]: rtp.c:792 process_rfc2833: START, dur=80 [May 4 14:27:07] DEBUG[3662]: rtp.c:795 process_rfc2833: ..... begin=1043014711, timeout=1043014911, duration=50 [May 4 14:27:07] DTMF[3662]: channel.c:2297 __ast_read: DTMF begin '3' received on SIP/4.68.250.148-15e30e80 [May 4 14:27:07] DTMF[3662]: channel.c:2301 __ast_read: DTMF begin ignored '3' on SIP/4.68.250.148-15e30e80 [May 4 14:27:07] DEBUG[3662]: rtp.c:795 process_rfc2833: ..... begin=1043014711, timeout=1043014930, duration=69 [May 4 14:27:07] DEBUG[3662]: rtp.c:795 process_rfc2833: ..... begin=1043014711, timeout=1043014950, duration=89 [May 4 14:27:07] DEBUG[3662]: rtp.c:795 process_rfc2833: ..... begin=1043014711, timeout=1043014971, duration=110 [May 4 14:27:07] DEBUG[3662]: rtp.c:795 process_rfc2833: ..... begin=1043014711, timeout=1043014992, duration=131 [May 4 14:27:07] DEBUG[3662]: rtp.c:795 process_rfc2833: ..... begin=1043014711, timeout=1043015010, duration=149 [May 4 14:27:07] DEBUG[3662]: rtp.c:766 process_rfc2833: normalend, dur=160 [May 4 14:27:07] DTMF[3662]: channel.c:2229 __ast_read: DTMF end '3' received on SIP/4.68.250.148-15e30e80, duration 160 ms [May 4 14:27:07] DTMF[3662]: channel.c:2282 __ast_read: DTMF end passthrough '3' on SIP/4.68.250.148-15e30e80 [May 4 14:27:07] DEBUG[3662]: rtp.c:792 process_rfc2833: START, dur=20 [May 4 14:27:07] DEBUG[3662]: rtp.c:795 process_rfc2833: ..... begin=1043019671, timeout=1043019841, duration=20 [May 4 14:27:07] DTMF[3662]: channel.c:2297 __ast_read: DTMF begin '#' received on SIP/4.68.250.148-15e30e80 [May 4 14:27:07] DTMF[3662]: channel.c:2301 __ast_read: DTMF begin ignored '#' on SIP/4.68.250.148-15e30e80 [May 4 14:27:07] DTMF[3662]: channel.c:2229 __ast_read: DTMF end '#' received on SIP/4.68.250.148-15e30e80, duration 20 ms [May 4 14:27:07] DTMF[3662]: channel.c:2282 __ast_read: DTMF end passthrough '#' on SIP/4.68.250.148-15e30e80 -- User entered '111222333' ******************************************************************************************************************* ******************************************************************************************************************* ****** Test: #3 ****** Result: FAILURE ****** Phone: Cellular Phone - Blackberry Curve - T-Mobile ****** DTMF Entered: 123# ****** DTMF Recieved by Read application: 1122333 ****** Notes: This scenario did NOT work 1.4.24 and is still BROKEN in 1.4.24.1 w/ supplied patch ******************************************************************************************************************* ******************************************************************************************************************* -- Executing [INBOUND@acd_inbound_call:3] Read("SIP/4.68.250.148-15e30e80", "test") in new stack [May 4 14:31:09] DEBUG[3673]: rtp.c:792 process_rfc2833: START, dur=20 [May 4 14:31:09] DEBUG[3673]: rtp.c:795 process_rfc2833: ..... begin=1043002311, timeout=1043002481, duration=20 [May 4 14:31:09] DTMF[3673]: channel.c:2297 __ast_read: DTMF begin '1' received on SIP/4.68.250.148-15e30e80 [May 4 14:31:09] DTMF[3673]: channel.c:2301 __ast_read: DTMF begin ignored '1' on SIP/4.68.250.148-15e30e80 [May 4 14:31:09] DTMF[3673]: channel.c:2229 __ast_read: DTMF end '1' received on SIP/4.68.250.148-15e30e80, duration 20 ms [May 4 14:31:09] DTMF[3673]: channel.c:2282 __ast_read: DTMF end passthrough '1' on SIP/4.68.250.148-15e30e80 [May 4 14:31:09] DEBUG[3673]: rtp.c:792 process_rfc2833: START, dur=80 [May 4 14:31:09] DEBUG[3673]: rtp.c:795 process_rfc2833: ..... begin=1043002311, timeout=1043002501, duration=40 [May 4 14:31:09] DTMF[3673]: channel.c:2297 __ast_read: DTMF begin '1' received on SIP/4.68.250.148-15e30e80 [May 4 14:31:09] DTMF[3673]: channel.c:2301 __ast_read: DTMF begin ignored '1' on SIP/4.68.250.148-15e30e80 [May 4 14:31:09] DEBUG[3673]: rtp.c:795 process_rfc2833: ..... begin=1043002311, timeout=1043002521, duration=60 [May 4 14:31:09] DEBUG[3673]: rtp.c:795 process_rfc2833: ..... begin=1043002311, timeout=1043002541, duration=80 [May 4 14:31:09] DEBUG[3673]: rtp.c:795 process_rfc2833: ..... begin=1043002311, timeout=1043002560, duration=99 [May 4 14:31:09] DEBUG[3673]: rtp.c:795 process_rfc2833: ..... begin=1043002311, timeout=1043002581, duration=120 [May 4 14:31:09] DEBUG[3673]: rtp.c:795 process_rfc2833: ..... begin=1043002311, timeout=1043002600, duration=139 [May 4 14:31:09] DEBUG[3673]: rtp.c:795 process_rfc2833: ..... begin=1043002311, timeout=1043002622, duration=161 [May 4 14:31:09] DEBUG[3673]: rtp.c:795 process_rfc2833: ..... begin=1043002311, timeout=1043002641, duration=180 [May 4 14:31:09] DEBUG[3673]: rtp.c:795 process_rfc2833: ..... begin=1043002311, timeout=1043002661, duration=200 [May 4 14:31:09] DEBUG[3673]: rtp.c:795 process_rfc2833: ..... begin=1043002311, timeout=1043002681, duration=220 [May 4 14:31:09] DEBUG[3673]: rtp.c:795 process_rfc2833: ..... begin=1043002311, timeout=1043002701, duration=240 [May 4 14:31:09] DEBUG[3673]: rtp.c:795 process_rfc2833: ..... begin=1043002311, timeout=1043002721, duration=260 [May 4 14:31:09] DEBUG[3673]: rtp.c:795 process_rfc2833: ..... begin=1043002311, timeout=1043002740, duration=279 [May 4 14:31:09] DEBUG[3673]: rtp.c:795 process_rfc2833: ..... begin=1043002311, timeout=1043002760, duration=299 [May 4 14:31:09] DEBUG[3673]: rtp.c:795 process_rfc2833: ..... begin=1043002311, timeout=1043002781, duration=320 [May 4 14:31:09] DEBUG[3673]: rtp.c:795 process_rfc2833: ..... begin=1043002311, timeout=1043002801, duration=340 [May 4 14:31:09] DEBUG[3673]: rtp.c:766 process_rfc2833: normalend, dur=341 [May 4 14:31:09] DTMF[3673]: channel.c:2229 __ast_read: DTMF end '1' received on SIP/4.68.250.148-15e30e80, duration 341 ms [May 4 14:31:09] DTMF[3673]: channel.c:2282 __ast_read: DTMF end passthrough '1' on SIP/4.68.250.148-15e30e80 [May 4 14:31:10] DEBUG[3673]: rtp.c:792 process_rfc2833: START, dur=20 [May 4 14:31:10] DEBUG[3673]: rtp.c:795 process_rfc2833: ..... begin=1043007591, timeout=1043007761, duration=20 [May 4 14:31:10] DTMF[3673]: channel.c:2297 __ast_read: DTMF begin '2' received on SIP/4.68.250.148-15e30e80 [May 4 14:31:10] DTMF[3673]: channel.c:2301 __ast_read: DTMF begin ignored '2' on SIP/4.68.250.148-15e30e80 [May 4 14:31:10] DTMF[3673]: channel.c:2229 __ast_read: DTMF end '2' received on SIP/4.68.250.148-15e30e80, duration 20 ms [May 4 14:31:10] DTMF[3673]: channel.c:2282 __ast_read: DTMF end passthrough '2' on SIP/4.68.250.148-15e30e80 [May 4 14:31:10] DEBUG[3673]: rtp.c:792 process_rfc2833: START, dur=80 [May 4 14:31:10] DEBUG[3673]: rtp.c:795 process_rfc2833: ..... begin=1043007591, timeout=1043007780, duration=39 [May 4 14:31:10] DTMF[3673]: channel.c:2297 __ast_read: DTMF begin '2' received on SIP/4.68.250.148-15e30e80 [May 4 14:31:10] DTMF[3673]: channel.c:2301 __ast_read: DTMF begin ignored '2' on SIP/4.68.250.148-15e30e80 [May 4 14:31:10] DEBUG[3673]: rtp.c:795 process_rfc2833: ..... begin=1043007591, timeout=1043007799, duration=58 [May 4 14:31:10] DEBUG[3673]: rtp.c:795 process_rfc2833: ..... begin=1043007591, timeout=1043007819, duration=78 [May 4 14:31:10] DEBUG[3673]: rtp.c:795 process_rfc2833: ..... begin=1043007591, timeout=1043007839, duration=98 [May 4 14:31:10] DEBUG[3673]: rtp.c:795 process_rfc2833: ..... begin=1043007591, timeout=1043007861, duration=120 [May 4 14:31:10] DEBUG[3673]: rtp.c:795 process_rfc2833: ..... begin=1043007591, timeout=1043007879, duration=138 [May 4 14:31:10] DEBUG[3673]: rtp.c:795 process_rfc2833: ..... begin=1043007591, timeout=1043007899, duration=158 [May 4 14:31:10] DEBUG[3673]: rtp.c:795 process_rfc2833: ..... begin=1043007591, timeout=1043007919, duration=178 [May 4 14:31:10] DEBUG[3673]: rtp.c:795 process_rfc2833: ..... begin=1043007591, timeout=1043007939, duration=198 [May 4 14:31:10] DEBUG[3673]: rtp.c:795 process_rfc2833: ..... begin=1043007591, timeout=1043007960, duration=219 [May 4 14:31:10] DEBUG[3673]: rtp.c:795 process_rfc2833: ..... begin=1043007591, timeout=1043007979, duration=238 [May 4 14:31:10] DEBUG[3673]: rtp.c:795 process_rfc2833: ..... begin=1043007591, timeout=1043007999, duration=258 [May 4 14:31:10] DEBUG[3673]: rtp.c:795 process_rfc2833: ..... begin=1043007591, timeout=1043008019, duration=278 [May 4 14:31:10] DEBUG[3673]: rtp.c:795 process_rfc2833: ..... begin=1043007591, timeout=1043008039, duration=298 [May 4 14:31:10] DEBUG[3673]: rtp.c:795 process_rfc2833: ..... begin=1043007591, timeout=1043008058, duration=317 [May 4 14:31:10] DEBUG[3673]: rtp.c:795 process_rfc2833: ..... begin=1043007591, timeout=1043008079, duration=338 [May 4 14:31:10] DEBUG[3673]: rtp.c:795 process_rfc2833: ..... begin=1043007591, timeout=1043008098, duration=357 [May 4 14:31:10] DEBUG[3673]: rtp.c:795 process_rfc2833: ..... begin=1043007591, timeout=1043008118, duration=377 [May 4 14:31:10] DEBUG[3673]: rtp.c:795 process_rfc2833: ..... begin=1043007591, timeout=1043008141, duration=400 [May 4 14:31:10] DEBUG[3673]: rtp.c:795 process_rfc2833: ..... begin=1043007591, timeout=1043008159, duration=418 [May 4 14:31:10] DEBUG[3673]: rtp.c:766 process_rfc2833: normalend, dur=420 [May 4 14:31:10] DTMF[3673]: channel.c:2229 __ast_read: DTMF end '2' received on SIP/4.68.250.148-15e30e80, duration 420 ms [May 4 14:31:10] DTMF[3673]: channel.c:2282 __ast_read: DTMF end passthrough '2' on SIP/4.68.250.148-15e30e80 [May 4 14:31:11] DEBUG[3673]: rtp.c:792 process_rfc2833: START, dur=20 [May 4 14:31:11] DEBUG[3673]: rtp.c:795 process_rfc2833: ..... begin=1043013391, timeout=1043013561, duration=20 [May 4 14:31:11] DTMF[3673]: channel.c:2297 __ast_read: DTMF begin '3' received on SIP/4.68.250.148-15e30e80 [May 4 14:31:11] DTMF[3673]: channel.c:2301 __ast_read: DTMF begin ignored '3' on SIP/4.68.250.148-15e30e80 [May 4 14:31:11] DTMF[3673]: channel.c:2229 __ast_read: DTMF end '3' received on SIP/4.68.250.148-15e30e80, duration 20 ms [May 4 14:31:11] DTMF[3673]: channel.c:2282 __ast_read: DTMF end passthrough '3' on SIP/4.68.250.148-15e30e80 [May 4 14:31:11] DEBUG[3673]: rtp.c:792 process_rfc2833: START, dur=80 [May 4 14:31:11] DEBUG[3673]: rtp.c:795 process_rfc2833: ..... begin=1043013391, timeout=1043013574, duration=33 [May 4 14:31:11] DTMF[3673]: channel.c:2297 __ast_read: DTMF begin '3' received on SIP/4.68.250.148-15e30e80 [May 4 14:31:11] DTMF[3673]: channel.c:2301 __ast_read: DTMF begin ignored '3' on SIP/4.68.250.148-15e30e80 [May 4 14:31:11] DTMF[3673]: channel.c:2229 __ast_read: DTMF end '3' received on SIP/4.68.250.148-15e30e80, duration 33 ms [May 4 14:31:11] DTMF[3673]: channel.c:2282 __ast_read: DTMF end passthrough '3' on SIP/4.68.250.148-15e30e80 [May 4 14:31:11] DEBUG[3673]: rtp.c:792 process_rfc2833: START, dur=80 [May 4 14:31:11] DEBUG[3673]: rtp.c:795 process_rfc2833: ..... begin=1043013391, timeout=1043013594, duration=53 [May 4 14:31:11] DTMF[3673]: channel.c:2297 __ast_read: DTMF begin '3' received on SIP/4.68.250.148-15e30e80 [May 4 14:31:11] DTMF[3673]: channel.c:2301 __ast_read: DTMF begin ignored '3' on SIP/4.68.250.148-15e30e80 [May 4 14:31:11] DEBUG[3673]: rtp.c:795 process_rfc2833: ..... begin=1043013391, timeout=1043013613, duration=72 [May 4 14:31:11] DEBUG[3673]: rtp.c:795 process_rfc2833: ..... begin=1043013391, timeout=1043013633, duration=92 [May 4 14:31:11] DEBUG[3673]: rtp.c:795 process_rfc2833: ..... begin=1043013391, timeout=1043013653, duration=112 [May 4 14:31:11] DEBUG[3673]: rtp.c:795 process_rfc2833: ..... begin=1043013391, timeout=1043013674, duration=133 [May 4 14:31:11] DEBUG[3673]: rtp.c:795 process_rfc2833: ..... begin=1043013391, timeout=1043013694, duration=153 [May 4 14:31:11] DEBUG[3673]: rtp.c:795 process_rfc2833: ..... begin=1043013391, timeout=1043013714, duration=173 [May 4 14:31:11] DEBUG[3673]: rtp.c:795 process_rfc2833: ..... begin=1043013391, timeout=1043013733, duration=192 [May 4 14:31:11] DEBUG[3673]: rtp.c:795 process_rfc2833: ..... begin=1043013391, timeout=1043013755, duration=214 [May 4 14:31:11] DEBUG[3673]: rtp.c:795 process_rfc2833: ..... begin=1043013391, timeout=1043013774, duration=233 [May 4 14:31:11] DEBUG[3673]: rtp.c:795 process_rfc2833: ..... begin=1043013391, timeout=1043013794, duration=253 [May 4 14:31:11] DEBUG[3673]: rtp.c:795 process_rfc2833: ..... begin=1043013391, timeout=1043013814, duration=273 [May 4 14:31:11] DEBUG[3673]: rtp.c:795 process_rfc2833: ..... begin=1043013391, timeout=1043013833, duration=292 [May 4 14:31:11] DEBUG[3673]: rtp.c:795 process_rfc2833: ..... begin=1043013391, timeout=1043013854, duration=313 [May 4 14:31:11] DEBUG[3673]: rtp.c:795 process_rfc2833: ..... begin=1043013391, timeout=1043013874, duration=333 [May 4 14:31:11] DEBUG[3673]: rtp.c:795 process_rfc2833: ..... begin=1043013391, timeout=1043013894, duration=353 [May 4 14:31:11] DEBUG[3673]: rtp.c:795 process_rfc2833: ..... begin=1043013391, timeout=1043013913, duration=372 [May 4 14:31:11] DEBUG[3673]: rtp.c:795 process_rfc2833: ..... begin=1043013391, timeout=1043013934, duration=393 [May 4 14:31:11] DEBUG[3673]: rtp.c:795 process_rfc2833: ..... begin=1043013391, timeout=1043013953, duration=412 [May 4 14:31:11] DEBUG[3673]: rtp.c:766 process_rfc2833: normalend, dur=415 [May 4 14:31:11] DTMF[3673]: channel.c:2229 __ast_read: DTMF end '3' received on SIP/4.68.250.148-15e30e80, duration 415 ms [May 4 14:31:11] DTMF[3673]: channel.c:2282 __ast_read: DTMF end passthrough '3' on SIP/4.68.250.148-15e30e80 [May 4 14:31:11] DEBUG[3673]: rtp.c:792 process_rfc2833: START, dur=20 [May 4 14:31:11] DEBUG[3673]: rtp.c:795 process_rfc2833: ..... begin=1043019591, timeout=1043019761, duration=20 [May 4 14:31:11] DTMF[3673]: channel.c:2297 __ast_read: DTMF begin '#' received on SIP/4.68.250.148-15e30e80 [May 4 14:31:11] DTMF[3673]: channel.c:2301 __ast_read: DTMF begin ignored '#' on SIP/4.68.250.148-15e30e80 [May 4 14:31:11] DTMF[3673]: channel.c:2229 __ast_read: DTMF end '#' received on SIP/4.68.250.148-15e30e80, duration 20 ms [May 4 14:31:11] DTMF[3673]: channel.c:2282 __ast_read: DTMF end passthrough '#' on SIP/4.68.250.148-15e30e80 -- User entered '1122333'