Openzap bridge and DTMF issue
Hi, I wants to bridge calls with particular DID, which landing on one PRI span (Span_1) to another PRI span (Span_2). I'm able to bridge the calls between PRI span and able to talk to each other. My problem is that sometimes DTMF which received on Span_1 is not sending to Span2 and vice-verse. DTMF tones are hearing partially on receving end. Sometimes after a some delay (30-60 seconds) am getting the DTMF, but that's too some dtmf are missing. If I hangup the line while the dtmf is in queue then the dtmf are generating on the next call on the same line. But when I bridge the call on PRI with sip channel then am not getting any problem. I think the following log in freeswitch is usefull 2012-06-12 18:58:38.379506 [DEBUG] mod_openzap.c:725 queue DTMF [1] 2012-06-12 18:58:38.019513 [DEBUG] switch_ivr_bridge.c:391 Send signal OpenZAP/1:1/8040327325 [BREAK] after this it takes a while to generate dtmf 2012-06-12 18:58:38.019513 [DEBUG] zap_io.c:2137 1:1 GENERATE DTMF [1] Any suggestions on places to look or things to try would be most appreciated. See the log below. 2012-06-12 18:58:32.017050 [DEBUG] ozmod_isdn.c:1115 READ 44 ------------------------------------------------------------------------ -------- [08 02 1d 81 05 a1 04 03 80 90 a3 18 03 a1 83 82 1e 02 80 83 6c 0c 21 81 38 30 34 30 33 32 37 33 32 34 70 04 c1 33 32 35 7d 02 91 81] 2012-06-12 18:58:32.017050 [DEBUG] ozmod_isdn.c:584 Yay I got an event! Type:[05] Size:[187] CRV: 7553 (0x1d81, CTX: Originator) 2012-06-12 18:58:32.017050 [DEBUG] ozmod_isdn.c:616 zchan 0 (-1:-1) source isdn_data->channels_remote_crv[0x1d81] 2012-06-12 18:58:32.017050 [DEBUG] ozmod_isdn.c:954 Changing state on 1:2 from DOWN to RING 2012-06-12 18:58:32.117048 [DEBUG] ozmod_isdn.c:1163 1:2 STATE [RING] 2012-06-12 18:58:32.117048 [DEBUG] mod_openzap.c:1937 got clear channel sig [START] 2012-06-12 18:58:32.117048 [DEBUG] mod_openzap.c:407 Set codec PCMA 20ms 2012-06-12 18:58:32.117048 [DEBUG] mod_openzap.c:1440 Connect inbound channel OpenZAP/1:2/325 2012-06-12 18:58:32.117048 [NOTICE] switch_channel.c:816 New Channel OpenZAP/1:2/325 [e74d979f-6689-4345-836c-c7dc087e210a] 2012-06-12 18:58:32.117048 [DEBUG] mod_openzap.c:1451 (OpenZAP/1:2/325) State Change CS_NEW -> CS_INIT 2012-06-12 18:58:32.117048 [DEBUG] switch_core_session.c:1114 Send signal OpenZAP/1:2/325 [BREAK] 2012-06-12 18:58:32.117048 [DEBUG] switch_core_state_machine.c:325 (OpenZAP/1:2/325) Running State Change CS_INIT 2012-06-12 18:58:32.117048 [DEBUG] switch_core_state_machine.c:361 (OpenZAP/1:2/325) State INIT 2012-06-12 18:58:32.117048 [DEBUG] mod_openzap.c:435 (OpenZAP/1:2/325) State Change CS_INIT -> CS_ROUTING 2012-06-12 18:58:32.117048 [DEBUG] switch_core_session.c:1114 Send signal OpenZAP/1:2/325 [BREAK] 2012-06-12 18:58:32.117048 [DEBUG] switch_core_state_machine.c:361 (OpenZAP/1:2/325) State INIT going to sleep 2012-06-12 18:58:32.117048 [DEBUG] switch_core_state_machine.c:325 (OpenZAP/1:2/325) Running State Change CS_ROUTING 2012-06-12 18:58:32.117048 [DEBUG] switch_channel.c:1687 (OpenZAP/1:2/325) Callstate Change DOWN -> RINGING 2012-06-12 18:58:32.117048 [DEBUG] switch_core_state_machine.c:364 (OpenZAP/1:2/325) State ROUTING 2012-06-12 18:58:32.117048 [DEBUG] mod_openzap.c:458 OpenZAP/1:2/325 CHANNEL ROUTING 2012-06-12 18:58:32.117048 [DEBUG] switch_core_state_machine.c:77 OpenZAP/1:2/325 Standard ROUTING 2012-06-12 18:58:32.117048 [INFO] mod_dialplan_xml.c:331 Processing 8040327324 <8040327324>->325 in context default Dialplan: OpenZAP/1:2/325 parsing [default->Span2] continue=false Dialplan: OpenZAP/1:2/325 Regex (PASS) [Span2] destination_number(325) =~ /^325$/ break=on-false Dialplan: OpenZAP/1:2/325 Action set(call_timeout=45) Dialplan: OpenZAP/1:2/325 Action set(hangup_after_bridge=true) Dialplan: OpenZAP/1:2/325 Action set(continue_on_fail=true) Dialplan: OpenZAP/1:2/325 Action set(inherit_codec=true) Dialplan: OpenZAP/1:2/325 Action bridge(Openzap/2/a/8040327325) Dialplan: OpenZAP/1:2/325 Action hangup() 2012-06-12 18:58:32.117048 [DEBUG] switch_core_state_machine.c:119 (OpenZAP/1:2/325) State Change CS_ROUTING -> CS_EXECUTE 2012-06-12 18:58:32.117048 [DEBUG] switch_core_session.c:1114 Send signal OpenZAP/1:2/325 [BREAK] 2012-06-12 18:58:32.117048 [DEBUG] switch_core_state_machine.c:364 (OpenZAP/1:2/325) State ROUTING going to sleep 2012-06-12 18:58:32.117048 [DEBUG] switch_core_state_machine.c:325 (OpenZAP/1:2/325) Running State Change CS_EXECUTE 2012-06-12 18:58:32.117048 [DEBUG] switch_core_state_machine.c:371 (OpenZAP/1:2/325) State EXECUTE 2012-06-12 18:58:32.117048 [DEBUG] mod_openzap.c:475 OpenZAP/1:2/325 CHANNEL EXECUTE 2012-06-12 18:58:32.117048 [DEBUG] switch_core_state_machine.c:157 OpenZAP/1:2/325 Standard EXECUTE EXECUTE OpenZAP/1:2/325 set(call_timeout=45) 2012-06-12 18:58:32.117048 [DEBUG] mod_dptools.c:1060 OpenZAP/1:2/325 SET [call_timeout]=[45] EXECUTE OpenZAP/1:2/325 set(hangup_after_bridge=true) 2012-06-12 18:58:32.117048 [DEBUG] mod_dptools.c:1060 OpenZAP/1:2/325 SET [hangup_after_bridge]=[true] EXECUTE OpenZAP/1:2/325 set(continue_on_fail=true) 2012-06-12 18:58:32.117048 [DEBUG] mod_dptools.c:1060 OpenZAP/1:2/325 SET [continue_on_fail]=[true] EXECUTE OpenZAP/1:2/325 set(inherit_codec=true) 2012-06-12 18:58:32.117048 [DEBUG] mod_dptools.c:1060 OpenZAP/1:2/325 SET [inherit_codec]=[true] EXECUTE OpenZAP/1:2/325 bridge(Openzap/2/a/8040327325) 2012-06-12 18:58:32.117048 [DEBUG] switch_ivr_originate.c:1873 Parsing global variables 2012-06-12 18:58:32.117048 [INFO] ozmod_zt.c:638 Setting echo cancel to 64 taps for 2:1 2012-06-12 18:58:32.117048 [INFO] ozmod_zt.c:638 Setting echo cancel to 64 taps for 2:1 2012-06-12 18:58:32.117048 [DEBUG] mod_openzap.c:407 Set codec PCMA 20ms 2012-06-12 18:58:32.117048 [DEBUG] mod_openzap.c:1319 Connect outbound channel OpenZAP/2:1/8040327325 2012-06-12 18:58:32.117048 [NOTICE] switch_channel.c:816 New Channel OpenZAP/2:1/8040327325 [668e6166-40a0-4b3d-a575-16de89668282] 2012-06-12 18:58:32.117048 [DEBUG] mod_openzap.c:1332 (OpenZAP/2:1/8040327325) State Change CS_NEW -> CS_INIT 2012-06-12 18:58:32.117048 [DEBUG] switch_core_session.c:1114 Send signal OpenZAP/2:1/8040327325 [BREAK] 2012-06-12 18:58:32.117048 [DEBUG] ozmod_isdn.c:299 Changing state on 2:1 from DOWN to DIALING 2012-06-12 18:58:32.117048 [DEBUG] switch_core_state_machine.c:325 (OpenZAP/2:1/8040327325) Running State Change CS_INIT 2012-06-12 18:58:32.117048 [DEBUG] switch_core_state_machine.c:361 (OpenZAP/2:1/8040327325) State INIT 2012-06-12 18:58:32.117048 [DEBUG] mod_openzap.c:435 (OpenZAP/2:1/8040327325) State Change CS_INIT -> CS_ROUTING 2012-06-12 18:58:32.117048 [DEBUG] switch_core_session.c:1114 Send signal OpenZAP/2:1/8040327325 [BREAK] 2012-06-12 18:58:32.117048 [DEBUG] switch_core_state_machine.c:361 (OpenZAP/2:1/8040327325) State INIT going to sleep 2012-06-12 18:58:32.117048 [DEBUG] switch_core_state_machine.c:325 (OpenZAP/2:1/8040327325) Running State Change CS_ROUTING 2012-06-12 18:58:32.117048 [DEBUG] switch_channel.c:1687 (OpenZAP/2:1/8040327325) Callstate Change DOWN -> RINGING 2012-06-12 18:58:32.117048 [DEBUG] switch_core_state_machine.c:364 (OpenZAP/2:1/8040327325) State ROUTING 2012-06-12 18:58:32.117048 [DEBUG] mod_openzap.c:458 OpenZAP/2:1/8040327325 CHANNEL ROUTING 2012-06-12 18:58:32.117048 [DEBUG] switch_ivr_originate.c:66 (OpenZAP/2:1/8040327325) State Change CS_ROUTING -> CS_CONSUME_MEDIA 2012-06-12 18:58:32.117048 [DEBUG] switch_core_session.c:1114 Send signal OpenZAP/2:1/8040327325 [BREAK] 2012-06-12 18:58:32.117048 [DEBUG] switch_core_state_machine.c:364 (OpenZAP/2:1/8040327325) State ROUTING going to sleep 2012-06-12 18:58:32.117048 [DEBUG] switch_core_state_machine.c:325 (OpenZAP/2:1/8040327325) Running State Change CS_CONSUME_MEDIA 2012-06-12 18:58:32.117048 [DEBUG] switch_core_state_machine.c:383 (OpenZAP/2:1/8040327325) State CONSUME_MEDIA 2012-06-12 18:58:32.117048 [DEBUG] switch_core_state_machine.c:383 (OpenZAP/2:1/8040327325) State CONSUME_MEDIA going to sleep 2012-06-12 18:58:32.196997 [DEBUG] ozmod_isdn.c:1163 2:1 STATE [DIALING] 2012-06-12 18:58:32.196997 [DEBUG] ozmod_isdn.c:1938 WRITE 62 ------------------------------------------------------------------------ -------- [08 02 00 05 05 04 03 80 90 a3 18 03 a1 83 81 1e 02 80 83 28 0a 38 30 34 30 33 32 37 33 32 34 6c 0c 01 80 38 30 34 30 33 32 37 33 32 34 70 0b 81 38 30 34 30 33 32 37 33 32 35 7d 02 91 81] 2012-06-12 18:58:32.236939 [DEBUG] ozmod_isdn.c:1115 READ 10 ------------------------------------------------------------------------ -------- [08 02 80 05 02 18 03 a9 83 81] 2012-06-12 18:58:32.236939 [DEBUG] ozmod_isdn.c:584 Yay I got an event! Type:[02] Size:[115] CRV: 5 (0x5, CTX: Terminator) 2012-06-12 18:58:32.236939 [DEBUG] ozmod_isdn.c:616 zchan b750c4f0 (2:1) source isdn_data->channels_local_crv[0x5] 2012-06-12 18:58:32.236939 [CRIT] ozmod_isdn.c:963 Received CALL PROCEEDING message for channel 1 2012-06-12 18:58:32.236939 [DEBUG] ozmod_isdn.c:964 Changing state on 2:1 from DIALING to PROGRESS 2012-06-12 18:58:32.236939 [DEBUG] ozmod_isdn.c:1163 2:1 STATE [PROGRESS] 2012-06-12 18:58:32.236939 [DEBUG] mod_openzap.c:1937 got clear channel sig [PROGRESS] 2012-06-12 18:58:32.236939 [NOTICE] mod_openzap.c:1996 Ring-Ready OpenZAP/2:1/8040327325! 2012-06-12 18:58:32.236939 [DEBUG] ozmod_isdn.c:1115 READ 5 ------------------------------------------------------------------------ -------- [08 02 80 05 01] 2012-06-12 18:58:32.236939 [DEBUG] ozmod_isdn.c:584 Yay I got an event! Type:[01] Size:[103] CRV: 5 (0x5, CTX: Terminator) 2012-06-12 18:58:32.236939 [DEBUG] ozmod_isdn.c:616 zchan b750c4f0 (2:1) source isdn_data->channels_local_crv[0x5] 2012-06-12 18:58:32.236939 [DEBUG] ozmod_isdn.c:728 Changing state on 2:1 from PROGRESS to PROGRESS_MEDIA 2012-06-12 18:58:32.337864 [DEBUG] ozmod_isdn.c:1163 1:2 STATE [PROGRESS] 2012-06-12 18:58:32.337864 [DEBUG] ozmod_isdn.c:1938 WRITE 23 ------------------------------------------------------------------------ -------- [08 02 9d 81 02 04 03 80 90 a3 18 03 a1 83 82 1e 02 80 83 7d 02 91 81] 2012-06-12 18:58:32.337864 [DEBUG] switch_core_session.c:707 Send signal OpenZAP/1:2/325 [BREAK] 2012-06-12 18:58:32.337864 [NOTICE] switch_ivr_originate.c:479 Ring Ready OpenZAP/1:2/325! 2012-06-12 18:58:32.337864 [NOTICE] switch_ivr_originate.c:479 Ring-Ready OpenZAP/1:2/325! 2012-06-12 18:58:32.337864 [DEBUG] ozmod_isdn.c:1163 2:1 STATE [PROGRESS_MEDIA] 2012-06-12 18:58:32.337864 [DEBUG] mod_openzap.c:1937 got clear channel sig [PROGRESS_MEDIA] 2012-06-12 18:58:32.337864 [NOTICE] mod_openzap.c:1982 Pre-Answer OpenZAP/2:1/8040327325! 2012-06-12 18:58:32.337864 [DEBUG] switch_channel.c:2668 (OpenZAP/2:1/8040327325) Callstate Change RINGING -> EARLY 2012-06-12 18:58:32.337864 [DEBUG] switch_channel.c:2707 Send signal OpenZAP/1:2/325 [BREAK] 2012-06-12 18:58:32.337864 [DEBUG] switch_ivr_originate.c:404 Codec string PCMA@8000h@20i not supported on OpenZAP/1:2/325, skipping inheritance 2012-06-12 18:58:32.357863 [DEBUG] ozmod_isdn.c:1163 1:2 STATE [PROGRESS_MEDIA] 2012-06-12 18:58:32.357863 [INFO] ozmod_zt.c:638 Setting echo cancel to 64 taps for 1:2 2012-06-12 18:58:32.357863 [DEBUG] ozmod_isdn.c:1938 WRITE 23 ------------------------------------------------------------------------ -------- [08 02 9d 81 01 04 03 80 90 a3 18 03 a1 83 82 1e 02 80 83 7d 02 91 81] 2012-06-12 18:58:32.378867 [DEBUG] switch_core_session.c:707 Send signal OpenZAP/1:2/325 [BREAK] 2012-06-12 18:58:32.378867 [NOTICE] switch_ivr_originate.c:3163 Pre-Answer OpenZAP/1:2/325! 2012-06-12 18:58:32.378867 [DEBUG] switch_channel.c:2668 (OpenZAP/1:2/325) Callstate Change RINGING -> EARLY 2012-06-12 18:58:32.378867 [DEBUG] switch_ivr_originate.c:3206 Originate Resulted in Success: [OpenZAP/2:1/8040327325] 2012-06-12 18:58:32.378867 [DEBUG] switch_core_session.c:707 Send signal OpenZAP/2:1/8040327325 [BREAK] 2012-06-12 18:58:32.378867 [DEBUG] switch_core_session.c:707 Send signal OpenZAP/1:2/325 [BREAK] 2012-06-12 18:58:32.378867 [DEBUG] switch_ivr_bridge.c:1239 (OpenZAP/2:1/8040327325) State Change CS_CONSUME_MEDIA -> CS_EXCHANGE_MEDIA 2012-06-12 18:58:32.378867 [DEBUG] switch_core_session.c:1114 Send signal OpenZAP/2:1/8040327325 [BREAK] 2012-06-12 18:58:32.378867 [DEBUG] switch_core_state_machine.c:325 (OpenZAP/2:1/8040327325) Running State Change CS_EXCHANGE_MEDIA 2012-06-12 18:58:32.378867 [DEBUG] switch_core_state_machine.c:374 (OpenZAP/2:1/8040327325) State EXCHANGE_MEDIA 2012-06-12 18:58:32.378867 [DEBUG] mod_openzap.c:599 CHANNEL EXCHANGE_MEDIA 2012-06-12 18:58:32.438740 [DEBUG] ozmod_isdn.c:1115 READ 22 ------------------------------------------------------------------------ -------- [08 02 80 04 03 04 03 80 90 a3 1e 02 80 83 1e 02 80 83 7d 02 91 81] 2012-06-12 18:58:32.438740 [DEBUG] ozmod_isdn.c:584 Yay I got an event! Type:[03] Size:[155] CRV: 4 (0x4, CTX: Terminator) 2012-06-12 18:58:32.438740 [DEBUG] ozmod_isdn.c:616 zchan 8e082e8 (1:1) source isdn_data->channels_local_crv[0x4] 2012-06-12 18:58:32.438740 [WARNING] ozmod_isdn.c:737 Why bother changing state on 1:1 from PROGRESS to PROGRESS 2012-06-12 18:58:32.458799 [DEBUG] ozmod_isdn.c:1115 READ 17 ------------------------------------------------------------------------ -------- [08 02 80 04 01 1e 02 80 83 1e 02 82 88 7d 02 91 81] 2012-06-12 18:58:32.458799 [DEBUG] ozmod_isdn.c:584 Yay I got an event! Type:[01] Size:[121] CRV: 4 (0x4, CTX: Terminator) 2012-06-12 18:58:32.458799 [DEBUG] ozmod_isdn.c:616 zchan 8e082e8 (1:1) source isdn_data->channels_local_crv[0x4] 2012-06-12 18:58:32.458799 [DEBUG] ozmod_isdn.c:728 Changing state on 1:1 from PROGRESS to PROGRESS_MEDIA 2012-06-12 18:58:32.558735 [DEBUG] ozmod_isdn.c:1163 1:1 STATE [PROGRESS_MEDIA] 2012-06-12 18:58:32.558735 [DEBUG] mod_openzap.c:1937 got clear channel sig [PROGRESS_MEDIA] 2012-06-12 18:58:32.558735 [NOTICE] mod_openzap.c:1982 Pre-Answer OpenZAP/1:1/8040327325! 2012-06-12 18:58:32.558735 [DEBUG] switch_channel.c:2668 (OpenZAP/1:1/8040327325) Callstate Change RINGING -> EARLY 2012-06-12 18:58:32.558735 [DEBUG] switch_channel.c:2707 Send signal sofia/internal/324@192.168.1.155:5060 [BREAK] 2012-06-12 18:58:32.578743 [DEBUG] switch_core_codec.c:141 sofia/internal/324@192.168.1.155:5060 Restore previous codec PCMU:0. 2012-06-12 18:58:32.578743 [DEBUG] switch_ivr_originate.c:3206 Originate Resulted in Success: [OpenZAP/1:1/8040327325] 2012-06-12 18:58:32.578743 [DEBUG] switch_core_session.c:707 Send signal OpenZAP/1:1/8040327325 [BREAK] 2012-06-12 18:58:32.578743 [DEBUG] switch_core_session.c:707 Send signal sofia/internal/324@192.168.1.155:5060 [BREAK] 2012-06-12 18:58:32.578743 [DEBUG] switch_ivr_bridge.c:1239 (OpenZAP/1:1/8040327325) State Change CS_CONSUME_MEDIA -> CS_EXCHANGE_MEDIA 2012-06-12 18:58:32.578743 [DEBUG] switch_core_session.c:1114 Send signal OpenZAP/1:1/8040327325 [BREAK] 2012-06-12 18:58:32.578743 [DEBUG] switch_core_state_machine.c:325 (OpenZAP/1:1/8040327325) Running State Change CS_EXCHANGE_MEDIA 2012-06-12 18:58:32.578743 [DEBUG] switch_core_state_machine.c:374 (OpenZAP/1:1/8040327325) State EXCHANGE_MEDIA 2012-06-12 18:58:32.578743 [DEBUG] mod_openzap.c:599 CHANNEL EXCHANGE_MEDIA 2012-06-12 18:58:33.758609 [DEBUG] ozmod_isdn.c:1115 READ 5 ------------------------------------------------------------------------ -------- [08 02 80 05 07] 2012-06-12 18:58:33.758609 [DEBUG] ozmod_isdn.c:584 Yay I got an event! Type:[07] Size:[103] CRV: 5 (0x5, CTX: Terminator) 2012-06-12 18:58:33.758609 [DEBUG] ozmod_isdn.c:616 zchan b750c4f0 (2:1) source isdn_data->channels_local_crv[0x5] 2012-06-12 18:58:33.758609 [DEBUG] ozmod_isdn.c:746 Changing state on 2:1 from PROGRESS_MEDIA to UP 2012-06-12 18:58:33.758609 [DEBUG] ozmod_isdn.c:1938 WRITE 5 ------------------------------------------------------------------------ -------- [08 02 00 05 0f] 2012-06-12 18:58:33.758609 [DEBUG] ozmod_isdn.c:1163 2:1 STATE [UP] 2012-06-12 18:58:33.758609 [DEBUG] mod_openzap.c:1937 got clear channel sig [UP] 2012-06-12 18:58:33.758609 [DEBUG] switch_channel.c:2859 (OpenZAP/2:1/8040327325) Callstate Change EARLY -> ACTIVE 2012-06-12 18:58:33.758609 [DEBUG] switch_channel.c:2871 Send signal OpenZAP/1:2/325 [BREAK] 2012-06-12 18:58:33.758609 [NOTICE] mod_openzap.c:1968 Channel [OpenZAP/2:1/8040327325] has been answered 2012-06-12 18:58:33.818609 [DEBUG] ozmod_isdn.c:1163 1:2 STATE [UP] 2012-06-12 18:58:33.818609 [DEBUG] ozmod_isdn.c:1938 WRITE 18 ------------------------------------------------------------------------ -------- [08 02 9d 81 07 18 03 a1 83 82 1e 02 80 83 7d 02 91 81] 2012-06-12 18:58:33.838610 [DEBUG] switch_core_session.c:707 Send signal OpenZAP/1:2/325 [BREAK] 2012-06-12 18:58:33.838610 [DEBUG] switch_channel.c:2859 (OpenZAP/1:2/325) Callstate Change EARLY -> ACTIVE 2012-06-12 18:58:33.838610 [NOTICE] switch_ivr_bridge.c:417 Channel [OpenZAP/1:2/325] has been answered 2012-06-12 18:58:33.918607 [DEBUG] ozmod_isdn.c:1115 READ 26 ------------------------------------------------------------------------ -------- [08 02 80 04 07 04 03 80 90 a3 1e 02 80 83 29 06 0c 06 0c 13 0d 2a 7d 02 91 81] 2012-06-12 18:58:33.918607 [DEBUG] ozmod_isdn.c:584 Yay I got an event! Type:[07] Size:[159] CRV: 4 (0x4, CTX: Terminator) 2012-06-12 18:58:33.918607 [DEBUG] ozmod_isdn.c:616 zchan 8e082e8 (1:1) source isdn_data->channels_local_crv[0x4] 2012-06-12 18:58:33.918607 [DEBUG] ozmod_isdn.c:746 Changing state on 1:1 from PROGRESS_MEDIA to UP 2012-06-12 18:58:33.918607 [DEBUG] ozmod_isdn.c:1938 WRITE 5 ------------------------------------------------------------------------ -------- [08 02 00 04 0f] 2012-06-12 18:58:33.918607 [DEBUG] ozmod_isdn.c:1163 1:1 STATE [UP] 2012-06-12 18:58:33.918607 [DEBUG] mod_openzap.c:1937 got clear channel sig [UP] 2012-06-12 18:58:33.918607 [DEBUG] switch_channel.c:2859 (OpenZAP/1:1/8040327325) Callstate Change EARLY -> ACTIVE 2012-06-12 18:58:33.918607 [DEBUG] switch_channel.c:2871 Send signal sofia/internal/324@192.168.1.155:5060 [BREAK] 2012-06-12 18:58:33.918607 [NOTICE] mod_openzap.c:1968 Channel [OpenZAP/1:1/8040327325] has been answered 2012-06-12 18:58:33.939272 [DEBUG] mod_sofia.c:683 Local SDP sofia/internal/324@192.168.1.155:5060: v=0 o=FreeSWITCH 1339477129 1339477131 IN IP4 192.168.1.155 s=FreeSWITCH c=IN IP4 192.168.1.155 t=0 0 m=audio 30582 RTP/AVP 0 110 a=rtpmap:0 PCMU/8000 a=rtpmap:110 telephone-event/8000 a=fmtp:110 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv 2012-06-12 18:58:33.939272 [DEBUG] switch_core_session.c:707 Send signal sofia/internal/324@192.168.1.155:5060 [BREAK] 2012-06-12 18:58:33.939272 [DEBUG] switch_channel.c:2859 (sofia/internal/324@192.168.1.155:5060) Callstate Change EARLY -> ACTIVE 2012-06-12 18:58:33.939272 [NOTICE] switch_ivr_bridge.c:417 Channel [sofia/internal/324@192.168.1.155:5060] has been answered 2012-06-12 18:58:33.939272 [DEBUG] sofia.c:4770 Channel sofia/internal/324@192.168.1.155:5060 entering state [completed][200] 2012-06-12 18:58:33.939272 [DEBUG] ozmod_isdn.c:1115 READ 5 ------------------------------------------------------------------------ -------- [08 02 1d 81 0f] 2012-06-12 18:58:33.939272 [DEBUG] ozmod_isdn.c:584 Yay I got an event! Type:[0f] Size:[103] CRV: 7553 (0x1d81, CTX: Originator) 2012-06-12 18:58:33.939272 [DEBUG] ozmod_isdn.c:616 zchan 8e0dc38 (1:2) source isdn_data->channels_remote_crv[0x1d81] 2012-06-12 18:58:33.939272 [DEBUG] ozmod_isdn.c:973 Received CONNECT_ACK message for channel 0 2012-06-12 18:58:33.959605 [DEBUG] switch_core_media_bug.c:360 Attaching BUG to sofia/internal/324@192.168.1.155:5060 2012-06-12 18:58:33.999606 [DEBUG] switch_rtp.c:3104 Correct ip/port confirmed. 2012-06-12 18:58:34.039603 [DEBUG] sofia.c:4770 Channel sofia/internal/324@192.168.1.155:5060 entering state [ready][200] 2012-06-12 18:58:38.019513 [DEBUG] switch_rtp.c:3302 RTP RECV DTMF 1:2240 2012-06-12 18:58:38.019513 [DEBUG] zap_io.c:1469 Created DTMF Buffer! 2012-06-12 18:58:38.019513 [DEBUG] switch_ivr_bridge.c:391 Send signal OpenZAP/1:1/8040327325 [BREAK] 2012-06-12 18:58:38.019513 [DEBUG] zap_io.c:2137 1:1 GENERATE DTMF [1] 2012-06-12 18:58:38.079514 [DEBUG] zap_io.c:2031 [s1c2][1:2] Queuing DTMF 2012-06-12 18:58:38.079514 [DEBUG] zap_io.c:1469 Created DTMF Buffer! 1 2012-06-12 18:58:38.079514 [DEBUG] mod_openzap.c:725 queue DTMF [1] 2012-06-12 18:58:38.079514 [DEBUG] switch_ivr_bridge.c:391 Send signal OpenZAP/2:1/8040327325 [BREAK] 2012-06-12 18:58:38.099512 [DEBUG] zap_io.c:2137 2:1 GENERATE DTMF [1] 2012-06-12 18:58:38.299508 [DEBUG] switch_rtp.c:3302 RTP RECV DTMF 2:2240 2012-06-12 18:58:38.299508 [DEBUG] switch_ivr_bridge.c:391 Send signal OpenZAP/1:1/8040327325 [BREAK] 2012-06-12 18:58:38.299508 [DEBUG] zap_io.c:2137 1:1 GENERATE DTMF [2] 2012-06-12 18:58:38.379506 [DEBUG] zap_io.c:2031 [s1c2][1:2] Queuing DTMF 2 2012-06-12 18:58:38.379506 [DEBUG] mod_openzap.c:725 queue DTMF [2] 2012-06-12 18:58:38.379506 [DEBUG] switch_ivr_bridge.c:391 Send signal OpenZAP/2:1/8040327325 [BREAK] 2012-06-12 18:58:40.819450 [DEBUG] switch_rtp.c:3302 RTP RECV DTMF 3:2240 2012-06-12 18:58:40.819450 [DEBUG] switch_ivr_bridge.c:391 Send signal OpenZAP/1:1/8040327325 [BREAK] 2012-06-12 18:58:40.819450 [DEBUG] zap_io.c:2137 1:1 GENERATE DTMF [3] 2012-06-12 18:58:40.879452 [DEBUG] zap_io.c:2031 [s1c2][1:2] Queuing DTMF 3 2012-06-12 18:58:40.879452 [DEBUG] mod_openzap.c:725 queue DTMF [3] 2012-06-12 18:58:40.879452 [DEBUG] switch_ivr_bridge.c:391 Send signal OpenZAP/2:1/8040327325 [BREAK] 2012-06-12 18:58:41.099444 [DEBUG] switch_rtp.c:3302 RTP RECV DTMF 4:2240 2012-06-12 18:58:41.099444 [DEBUG] switch_ivr_bridge.c:391 Send signal OpenZAP/1:1/8040327325 [BREAK] 2012-06-12 18:58:41.099444 [DEBUG] zap_io.c:2137 1:1 GENERATE DTMF [4] 2012-06-12 18:58:41.199442 [DEBUG] zap_io.c:2031 [s1c2][1:2] Queuing DTMF 4 2012-06-12 18:58:41.199442 [DEBUG] mod_openzap.c:725 queue DTMF [4] 2012-06-12 18:58:41.199442 [DEBUG] switch_ivr_bridge.c:391 Send signal OpenZAP/2:1/8040327325 [BREAK] 2012-06-12 18:58:41.379438 [DEBUG] switch_rtp.c:3302 RTP RECV DTMF 5:2240 2012-06-12 18:58:41.379438 [DEBUG] switch_ivr_bridge.c:391 Send signal OpenZAP/1:1/8040327325 [BREAK] 2012-06-12 18:58:41.379438 [DEBUG] zap_io.c:2137 1:1 GENERATE DTMF [5] 2012-06-12 18:58:41.479436 [DEBUG] zap_io.c:2031 [s1c2][1:2] Queuing DTMF 5 2012-06-12 18:58:41.479436 [DEBUG] mod_openzap.c:725 queue DTMF [5] 2012-06-12 18:58:41.479436 [DEBUG] switch_ivr_bridge.c:391 Send signal OpenZAP/2:1/8040327325 [BREAK] 2012-06-12 18:58:41.659431 [DEBUG] switch_rtp.c:3302 RTP RECV DTMF 6:2240 2012-06-12 18:58:41.659431 [DEBUG] switch_ivr_bridge.c:391 Send signal OpenZAP/1:1/8040327325 [BREAK] 2012-06-12 18:58:41.659431 [DEBUG] zap_io.c:2137 1:1 GENERATE DTMF [6] 2012-06-12 18:58:41.799429 [DEBUG] zap_io.c:2031 [s1c2][1:2] Queuing DTMF 6 2012-06-12 18:58:41.799429 [DEBUG] mod_openzap.c:725 queue DTMF [6] 2012-06-12 18:58:41.799429 [DEBUG] switch_ivr_bridge.c:391 Send signal OpenZAP/2:1/8040327325 [BREAK] 2012-06-12 18:58:41.939425 [DEBUG] switch_rtp.c:3302 RTP RECV DTMF 7:2240 2012-06-12 18:58:41.939425 [DEBUG] switch_ivr_bridge.c:391 Send signal OpenZAP/1:1/8040327325 [BREAK] 2012-06-12 18:58:41.939425 [DEBUG] zap_io.c:2137 1:1 GENERATE DTMF [7] 2012-06-12 18:58:42.079422 [DEBUG] zap_io.c:2031 [s1c2][1:2] Queuing DTMF 7 2012-06-12 18:58:42.079422 [DEBUG] mod_openzap.c:725 queue DTMF [7] 2012-06-12 18:58:42.079422 [DEBUG] switch_ivr_bridge.c:391 Send signal OpenZAP/2:1/8040327325 [BREAK] 2012-06-12 18:58:42.159421 [WARNING] sofia_reg.c:1241 SIP auth challenge (REGISTER) on sofia profile 'internal' for [324@192.168.1.155] from ip 192.168.1.32 2012-06-12 18:58:42.219421 [DEBUG] switch_rtp.c:3302 RTP RECV DTMF 8:2240 2012-06-12 18:58:42.219421 [DEBUG] switch_ivr_bridge.c:391 Send signal OpenZAP/1:1/8040327325 [BREAK] 2012-06-12 18:58:42.219421 [DEBUG] zap_io.c:2137 1:1 GENERATE DTMF [8] 2012-06-12 18:58:42.400415 [DEBUG] zap_io.c:2031 [s1c2][1:2] Queuing DTMF 8 2012-06-12 18:58:42.400415 [DEBUG] mod_openzap.c:725 queue DTMF [8] 2012-06-12 18:58:42.400415 [DEBUG] switch_ivr_bridge.c:391 Send signal OpenZAP/2:1/8040327325 [BREAK] 2012-06-12 18:58:42.500413 [DEBUG] switch_rtp.c:3302 RTP RECV DTMF 9:2240 2012-06-12 18:58:42.500413 [DEBUG] switch_ivr_bridge.c:391 Send signal OpenZAP/1:1/8040327325 [BREAK] 2012-06-12 18:58:42.500413 [DEBUG] zap_io.c:2137 1:1 GENERATE DTMF [9] 2012-06-12 18:58:42.680409 [DEBUG] zap_io.c:2031 [s1c2][1:2] Queuing DTMF 9 2012-06-12 18:58:42.680409 [DEBUG] mod_openzap.c:725 queue DTMF [9] 2012-06-12 18:58:42.680409 [DEBUG] switch_ivr_bridge.c:391 Send signal OpenZAP/2:1/8040327325 [BREAK] 2012-06-12 18:58:50.242296 [DEBUG] switch_rtp.c:3302 RTP RECV DTMF *:2240 2012-06-12 18:58:50.242296 [DEBUG] switch_ivr_bridge.c:391 Send signal OpenZAP/1:1/8040327325 [BREAK] 2012-06-12 18:58:50.242296 [DEBUG] zap_io.c:2137 1:1 GENERATE DTMF [*] 2012-06-12 18:58:50.304238 [DEBUG] zap_io.c:2031 [s1c2][1:2] Queuing DTMF * 2012-06-12 18:58:50.304238 [DEBUG] mod_openzap.c:725 queue DTMF [*] 2012-06-12 18:58:50.304238 [DEBUG] switch_ivr_bridge.c:391 Send signal OpenZAP/2:1/8040327325 [BREAK] 2012-06-12 18:59:22.692383 [DEBUG] zap_io.c:2137 2:1 GENERATE DTMF [23456789*] 2012-06-12 18:59:22.892378 [DEBUG] mod_openzap.c:784 Dropping frame! (write not ready) 2012-06-12 18:59:23.332368 [DEBUG] mod_openzap.c:784 Dropping frame! (write not ready) 2012-06-12 18:59:23.832357 [DEBUG] mod_openzap.c:784 Dropping frame! (write not ready) 2012-06-12 18:59:32.440788 [DEBUG] switch_rtp.c:3302 RTP RECV DTMF *:2240 2012-06-12 18:59:32.440788 [DEBUG] switch_ivr_bridge.c:391 Send signal OpenZAP/1:1/8040327325 [BREAK] 2012-06-12 18:59:32.440788 [DEBUG] zap_io.c:2137 1:1 GENERATE DTMF [*] 2012-06-12 18:59:32.501788 [DEBUG] zap_io.c:2031 [s1c2][1:2] Queuing DTMF * 2012-06-12 18:59:32.501788 [DEBUG] mod_openzap.c:725 queue DTMF [*] 2012-06-12 18:59:32.521799 [DEBUG] switch_ivr_bridge.c:391 Send signal OpenZAP/2:1/8040327325 [BREAK] 2012-06-12 18:59:32.563816 [DEBUG] zap_io.c:2137 2:1 GENERATE DTMF [*] 2012-06-12 18:59:34.845735 [DEBUG] switch_rtp.c:3302 RTP RECV DTMF 1:2240 2012-06-12 18:59:34.845735 [DEBUG] switch_ivr_bridge.c:391 Send signal OpenZAP/1:1/8040327325 [BREAK] 2012-06-12 18:59:34.845735 [DEBUG] zap_io.c:2137 1:1 GENERATE DTMF [1] 2012-06-12 18:59:34.885760 [DEBUG] zap_io.c:2031 [s1c2][1:2] Queuing DTMF 1 2012-06-12 18:59:34.885760 [DEBUG] mod_openzap.c:725 queue DTMF [1] 2012-06-12 18:59:34.885760 [DEBUG] switch_ivr_bridge.c:391 Send signal OpenZAP/2:1/8040327325 [BREAK] 2012-06-12 19:00:25.244664 [DEBUG] switch_rtp.c:3302 RTP RECV DTMF 1:2240 2012-06-12 19:00:25.244664 [DEBUG] switch_ivr_bridge.c:391 Send signal OpenZAP/1:1/8040327325 [BREAK] 2012-06-12 19:00:25.244664 [DEBUG] zap_io.c:2137 1:1 GENERATE DTMF [1] 2012-06-12 19:00:25.284665 [DEBUG] zap_io.c:2031 [s1c2][1:2] Queuing DTMF 1 2012-06-12 19:00:25.284665 [DEBUG] mod_openzap.c:725 queue DTMF [1] 2012-06-12 19:00:25.284665 [DEBUG] switch_ivr_bridge.c:391 Send signal OpenZAP/2:1/8040327325 [BREAK] 2012-06-12 19:00:25.524657 [DEBUG] switch_rtp.c:3302 RTP RECV DTMF 2:2240 2012-06-12 19:00:25.524657 [DEBUG] switch_ivr_bridge.c:391 Send signal OpenZAP/1:1/8040327325 [BREAK] 2012-06-12 19:00:25.524657 [DEBUG] zap_io.c:2137 1:1 GENERATE DTMF [2] 2012-06-12 19:00:25.604656 [DEBUG] zap_io.c:2031 [s1c2][1:2] Queuing DTMF 2 2012-06-12 19:00:25.604656 [DEBUG] mod_openzap.c:725 queue DTMF [2] 2012-06-12 19:00:25.604656 [DEBUG] switch_ivr_bridge.c:391 Send signal OpenZAP/2:1/8040327325 [BREAK] 2012-06-12 19:00:25.804651 [DEBUG] switch_rtp.c:3302 RTP RECV DTMF 3:2240 2012-06-12 19:00:25.804651 [DEBUG] switch_ivr_bridge.c:391 Send signal OpenZAP/1:1/8040327325 [BREAK] 2012-06-12 19:00:25.804651 [DEBUG] zap_io.c:2137 1:1 GENERATE DTMF [3] 2012-06-12 19:00:25.884663 [DEBUG] zap_io.c:2031 [s1c2][1:2] Queuing DTMF 3 2012-06-12 19:00:25.884663 [DEBUG] mod_openzap.c:725 queue DTMF [3] 2012-06-12 19:00:25.884663 [DEBUG] switch_ivr_bridge.c:391 Send signal OpenZAP/2:1/8040327325 [BREAK] 2012-06-12 19:00:26.084646 [DEBUG] switch_rtp.c:3302 RTP RECV DTMF 4:2240 2012-06-12 19:00:26.084646 [DEBUG] switch_ivr_bridge.c:391 Send signal OpenZAP/1:1/8040327325 [BREAK] 2012-06-12 19:00:26.084646 [DEBUG] zap_io.c:2137 1:1 GENERATE DTMF [4] 2012-06-12 19:00:26.204663 [DEBUG] zap_io.c:2031 [s1c2][1:2] Queuing DTMF 4 2012-06-12 19:00:26.204663 [DEBUG] mod_openzap.c:725 queue DTMF [4] 2012-06-12 19:00:26.204663 [DEBUG] switch_ivr_bridge.c:391 Send signal OpenZAP/2:1/8040327325 [BREAK] 2012-06-12 19:00:26.364640 [DEBUG] switch_rtp.c:3302 RTP RECV DTMF 5:2240 2012-06-12 19:00:26.364640 [DEBUG] switch_ivr_bridge.c:391 Send signal OpenZAP/1:1/8040327325 [BREAK] 2012-06-12 19:00:26.364640 [DEBUG] zap_io.c:2137 1:1 GENERATE DTMF [5] 2012-06-12 19:00:26.484637 [DEBUG] zap_io.c:2031 [s1c2][1:2] Queuing DTMF 5 2012-06-12 19:00:26.484637 [DEBUG] mod_openzap.c:725 queue DTMF [5] 2012-06-12 19:00:26.484637 [DEBUG] switch_ivr_bridge.c:391 Send signal OpenZAP/2:1/8040327325 [BREAK] 2012-06-12 19:00:26.644633 [DEBUG] switch_rtp.c:3302 RTP RECV DTMF 6:2240 2012-06-12 19:00:26.644633 [DEBUG] switch_ivr_bridge.c:391 Send signal OpenZAP/1:1/8040327325 [BREAK] 2012-06-12 19:00:26.644633 [DEBUG] zap_io.c:2137 1:1 GENERATE DTMF [6] 2012-06-12 19:00:26.804630 [DEBUG] zap_io.c:2031 [s1c2][1:2] Queuing DTMF 6 2012-06-12 19:00:26.804630 [DEBUG] mod_openzap.c:725 queue DTMF [6] 2012-06-12 19:00:26.804630 [DEBUG] switch_ivr_bridge.c:391 Send signal OpenZAP/2:1/8040327325 [BREAK] 2012-06-12 19:00:26.924642 [DEBUG] switch_rtp.c:3302 RTP RECV DTMF 7:2240 2012-06-12 19:00:26.924642 [DEBUG] switch_ivr_bridge.c:391 Send signal OpenZAP/1:1/8040327325 [BREAK] 2012-06-12 19:00:26.924642 [DEBUG] zap_io.c:2137 1:1 GENERATE DTMF [7] 2012-06-12 19:00:27.084623 [DEBUG] zap_io.c:2031 [s1c2][1:2] Queuing DTMF 7 2012-06-12 19:00:27.084623 [DEBUG] mod_openzap.c:725 queue DTMF [7] 2012-06-12 19:00:27.084623 [DEBUG] switch_ivr_bridge.c:391 Send signal OpenZAP/2:1/8040327325 [BREAK] 2012-06-12 19:00:27.204621 [DEBUG] switch_rtp.c:3302 RTP RECV DTMF 8:2240 2012-06-12 19:00:27.204621 [DEBUG] switch_ivr_bridge.c:391 Send signal OpenZAP/1:1/8040327325 [BREAK] 2012-06-12 19:00:27.204621 [DEBUG] zap_io.c:2137 1:1 GENERATE DTMF [8] 2012-06-12 19:00:27.404626 [DEBUG] zap_io.c:2031 [s1c2][1:2] Queuing DTMF 8 2012-06-12 19:00:27.404626 [DEBUG] mod_openzap.c:725 queue DTMF [8] 2012-06-12 19:00:27.404626 [DEBUG] switch_ivr_bridge.c:391 Send signal OpenZAP/2:1/8040327325 [BREAK] 2012-06-12 19:00:27.484615 [DEBUG] switch_rtp.c:3302 RTP RECV DTMF 9:2240 2012-06-12 19:00:27.484615 [DEBUG] switch_ivr_bridge.c:391 Send signal OpenZAP/1:1/8040327325 [BREAK] 2012-06-12 19:00:27.484615 [DEBUG] zap_io.c:2137 1:1 GENERATE DTMF [9] 2012-06-12 19:00:27.684610 [DEBUG] zap_io.c:2031 [s1c2][1:2] Queuing DTMF 9 2012-06-12 19:00:27.684610 [DEBUG] mod_openzap.c:725 queue DTMF [9] 2012-06-12 19:00:27.684610 [DEBUG] switch_ivr_bridge.c:391 Send signal OpenZAP/2:1/8040327325 [BREAK] 2012-06-12 19:00:27.764608 [DEBUG] switch_rtp.c:3302 RTP RECV DTMF *:2240 2012-06-12 19:00:27.764608 [DEBUG] switch_ivr_bridge.c:391 Send signal OpenZAP/1:1/8040327325 [BREAK] 2012-06-12 19:00:27.764608 [DEBUG] zap_io.c:2137 1:1 GENERATE DTMF [*] 2012-06-12 19:00:28.004603 [DEBUG] zap_io.c:2031 [s1c2][1:2] Queuing DTMF * 2012-06-12 19:00:28.004603 [DEBUG] mod_openzap.c:725 queue DTMF [*] 2012-06-12 19:00:28.004603 [DEBUG] switch_ivr_bridge.c:391 Send signal OpenZAP/2:1/8040327325 [BREAK] 2012-06-12 19:00:28.924597 [DEBUG] switch_rtp.c:3302 RTP RECV DTMF #:2240 2012-06-12 19:00:28.924597 [DEBUG] switch_ivr_bridge.c:391 Send signal OpenZAP/1:1/8040327325 [BREAK] 2012-06-12 19:00:28.924597 [DEBUG] zap_io.c:2137 1:1 GENERATE DTMF [#] 2012-06-12 19:00:28.984582 [DEBUG] zap_io.c:2031 [s1c2][1:2] Queuing DTMF # 2012-06-12 19:00:28.984582 [DEBUG] mod_openzap.c:725 queue DTMF [#] 2012-06-12 19:00:28.984582 [DEBUG] switch_ivr_bridge.c:391 Send signal OpenZAP/2:1/8040327325 [BREAK] 2012-06-12 19:00:30.444548 [WARNING] sofia_reg.c:1241 SIP auth challenge (REGISTER) on sofia profile 'internal' for [324@192.168.1.155] from ip 192.168.1.32 2012-06-12 19:00:30.744532 [DEBUG] zap_io.c:2137 2:1 GENERATE DTMF [1123456789*#] 2012-06-12 19:00:33.304329 [DEBUG] mod_openzap.c:784 Dropping frame! (write not ready) 2012-06-12 19:00:33.504324 [DEBUG] mod_openzap.c:784 Dropping frame! (write not ready) 2012-06-12 19:00:33.704320 [DEBUG] mod_openzap.c:784 Dropping frame! (write not ready) 2012-06-12 19:00:33.904315 [DEBUG] mod_openzap.c:784 Dropping frame! (write not ready) 2012-06-12 19:00:34.104311 [DEBUG] mod_openzap.c:784 Dropping frame! (write not ready) 2012-06-12 19:00:34.304306 [DEBUG] mod_openzap.c:784 Dropping frame! (write not ready) 2012-06-12 19:00:45.025232 [DEBUG] switch_channel.c:2592 (sofia/internal/324@192.168.1.155:5060) Callstate Change ACTIVE -> HANGUP 2012-06-12 19:00:45.025232 [NOTICE] sofia.c:546 Hangup sofia/internal/324@192.168.1.155:5060 [CS_EXECUTE] [NORMAL_CLEARING] 2012-06-12 19:00:45.025232 [DEBUG] switch_channel.c:2608 Send signal sofia/internal/324@192.168.1.155:5060 [KILL] 2012-06-12 19:00:45.025232 [DEBUG] switch_core_session.c:1114 Send signal sofia/internal/324@192.168.1.155:5060 [BREAK] 2012-06-12 19:00:45.045374 [DEBUG] switch_ivr_bridge.c:503 sofia/internal/324@192.168.1.155:5060 ending bridge by request from read function 2012-06-12 19:00:45.045374 [DEBUG] switch_ivr_bridge.c:584 BRIDGE THREAD DONE [sofia/internal/324@192.168.1.155:5060] 2012-06-12 19:00:45.045374 [DEBUG] switch_ivr_bridge.c:604 Send signal OpenZAP/1:1/8040327325 [BREAK] 2012-06-12 19:00:45.045374 [DEBUG] switch_ivr_bridge.c:497 sofia/internal/324@192.168.1.155:5060 ending bridge by request from write function 2012-06-12 19:00:45.045374 [DEBUG] switch_ivr_bridge.c:584 BRIDGE THREAD DONE [OpenZAP/1:1/8040327325] 2012-06-12 19:00:45.045374 [DEBUG] switch_ivr_bridge.c:604 Send signal sofia/internal/324@192.168.1.155:5060 [BREAK] 2012-06-12 19:00:45.045374 [DEBUG] switch_channel.c:2592 (OpenZAP/1:1/8040327325) Callstate Change ACTIVE -> HANGUP 2012-06-12 19:00:45.045374 [NOTICE] switch_ivr_bridge.c:656 Hangup OpenZAP/1:1/8040327325 [CS_EXCHANGE_MEDIA] [NORMAL_CLEARING] 2012-06-12 19:00:45.045374 [DEBUG] switch_channel.c:2608 Send signal OpenZAP/1:1/8040327325 [KILL] 2012-06-12 19:00:45.045374 [DEBUG] switch_core_session.c:1114 Send signal OpenZAP/1:1/8040327325 [BREAK] 2012-06-12 19:00:45.045374 [DEBUG] switch_core_state_machine.c:374 (OpenZAP/1:1/8040327325) State EXCHANGE_MEDIA going to sleep 2012-06-12 19:00:45.045374 [DEBUG] switch_core_state_machine.c:325 (OpenZAP/1:1/8040327325) Running State Change CS_HANGUP 2012-06-12 19:00:45.045374 [DEBUG] switch_core_state_machine.c:565 (OpenZAP/1:1/8040327325) State HANGUP 2012-06-12 19:00:45.045374 [DEBUG] mod_openzap.c:544 Changing state on 1:1 from UP to HANGUP 2012-06-12 19:00:45.045374 [DEBUG] mod_openzap.c:560 OpenZAP/1:1/8040327325 CHANNEL HANGUP 2012-06-12 19:00:45.045374 [DEBUG] switch_core_state_machine.c:46 OpenZAP/1:1/8040327325 Standard HANGUP, cause: NORMAL_CLEARING 2012-06-12 19:00:45.045374 [DEBUG] switch_core_state_machine.c:565 (OpenZAP/1:1/8040327325) State HANGUP going to sleep 2012-06-12 19:00:45.045374 [DEBUG] switch_ivr_bridge.c:1310 OpenZAP/1:1/8040327325 skip receive message [UNBRIDGE] (channel is hungup already) 2012-06-12 19:00:45.045374 [DEBUG] switch_ivr_bridge.c:1313 sofia/internal/324@192.168.1.155:5060 skip receive message [UNBRIDGE] (channel is hungup already) 2012-06-12 19:00:45.045374 [DEBUG] switch_core_state_machine.c:356 (OpenZAP/1:1/8040327325) State Change CS_HANGUP -> CS_REPORTING 2012-06-12 19:00:45.045374 [DEBUG] switch_core_session.c:1114 Send signal OpenZAP/1:1/8040327325 [BREAK] 2012-06-12 19:00:45.045374 [DEBUG] switch_core_state_machine.c:325 (OpenZAP/1:1/8040327325) Running State Change CS_REPORTING 2012-06-12 19:00:45.045374 [DEBUG] switch_core_state_machine.c:625 (OpenZAP/1:1/8040327325) State REPORTING 2012-06-12 19:00:45.045374 [DEBUG] switch_core_state_machine.c:53 OpenZAP/1:1/8040327325 Standard REPORTING, cause: NORMAL_CLEARING 2012-06-12 19:00:45.045374 [DEBUG] switch_core_state_machine.c:625 (OpenZAP/1:1/8040327325) State REPORTING going to sleep 2012-06-12 19:00:45.045374 [DEBUG] switch_core_session.c:2059 sofia/internal/324@192.168.1.155:5060 skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already) 2012-06-12 19:00:45.045374 [DEBUG] switch_core_state_machine.c:350 (OpenZAP/1:1/8040327325) State Change CS_REPORTING -> CS_DESTROY 2012-06-12 19:00:45.045374 [DEBUG] switch_core_session.c:1114 Send signal OpenZAP/1:1/8040327325 [BREAK] 2012-06-12 19:00:45.045374 [DEBUG] switch_core_session.c:1286 Session 6 (OpenZAP/1:1/8040327325) Locked, Waiting on external entities 2012-06-12 19:00:45.045374 [NOTICE] switch_core_session.c:1304 Session 6 (OpenZAP/1:1/8040327325) Ended 2012-06-12 19:00:45.045374 [NOTICE] switch_core_session.c:1306 Close Channel OpenZAP/1:1/8040327325 [CS_DESTROY] 2012-06-12 19:00:45.045374 [DEBUG] switch_core_state_machine.c:454 (OpenZAP/1:1/8040327325) Callstate Change HANGUP -> DOWN 2012-06-12 19:00:45.045374 [DEBUG] switch_core_session.c:2059 sofia/internal/324@192.168.1.155:5060 skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already) 2012-06-12 19:00:45.045374 [DEBUG] switch_core_state_machine.c:371 (sofia/internal/324@192.168.1.155:5060) State EXECUTE going to sleep 2012-06-12 19:00:45.045374 [DEBUG] switch_core_state_machine.c:325 (sofia/internal/324@192.168.1.155:5060) Running State Change CS_HANGUP 2012-06-12 19:00:45.045374 [DEBUG] switch_ivr_async.c:936 Stop recording file /usr/local/freeswitch/recordings/324/Jun-12/77-185333046.wav 2012-06-12 19:00:45.045374 [DEBUG] switch_core_media_bug.c:439 Removing BUG from sofia/internal/324@192.168.1.155:5060 2012-06-12 19:00:45.045374 [DEBUG] switch_core_state_machine.c:457 (OpenZAP/1:1/8040327325) Running State Change CS_DESTROY 2012-06-12 19:00:45.045374 [DEBUG] switch_core_state_machine.c:467 (OpenZAP/1:1/8040327325) State DESTROY 2012-06-12 19:00:45.045374 [DEBUG] switch_core_state_machine.c:565 (sofia/internal/324@192.168.1.155:5060) State HANGUP 2012-06-12 19:00:45.045374 [DEBUG] mod_sofia.c:453 sofia/internal/324@192.168.1.155:5060 Overriding SIP cause 480 with 200 from the other leg 2012-06-12 19:00:45.045374 [DEBUG] mod_sofia.c:459 Channel sofia/internal/324@192.168.1.155:5060 hanging up, cause: NORMAL_CLEARING 2012-06-12 19:00:45.045374 [DEBUG] switch_core_state_machine.c:46 sofia/internal/324@192.168.1.155:5060 Standard HANGUP, cause: NORMAL_CLEARING 2012-06-12 19:00:45.045374 [DEBUG] switch_core_state_machine.c:565 (sofia/internal/324@192.168.1.155:5060) State HANGUP going to sleep 2012-06-12 19:00:45.045374 [DEBUG] switch_core_state_machine.c:356 (sofia/internal/324@192.168.1.155:5060) State Change CS_HANGUP -> CS_REPORTING 2012-06-12 19:00:45.045374 [DEBUG] switch_core_session.c:1114 Send signal sofia/internal/324@192.168.1.155:5060 [BREAK] 2012-06-12 19:00:45.045374 [DEBUG] switch_core_state_machine.c:325 (sofia/internal/324@192.168.1.155:5060) Running State Change CS_REPORTING 2012-06-12 19:00:45.045374 [DEBUG] switch_core_state_machine.c:625 (sofia/internal/324@192.168.1.155:5060) State REPORTING 2012-06-12 19:00:45.045374 [DEBUG] switch_core_state_machine.c:53 sofia/internal/324@192.168.1.155:5060 Standard REPORTING, cause: NORMAL_CLEARING 2012-06-12 19:00:45.045374 [DEBUG] switch_core_state_machine.c:625 (sofia/internal/324@192.168.1.155:5060) State REPORTING going to sleep 2012-06-12 19:00:45.045374 [DEBUG] switch_core_state_machine.c:350 (sofia/internal/324@192.168.1.155:5060) State Change CS_REPORTING -> CS_DESTROY 2012-06-12 19:00:45.045374 [DEBUG] switch_core_session.c:1114 Send signal sofia/internal/324@192.168.1.155:5060 [BREAK] 2012-06-12 19:00:45.045374 [DEBUG] switch_core_session.c:1286 Session 5 (sofia/internal/324@192.168.1.155:5060) Locked, Waiting on external entities 2012-06-12 19:00:45.045374 [DEBUG] switch_core_state_machine.c:60 OpenZAP/1:1/8040327325 Standard DESTROY 2012-06-12 19:00:45.045374 [DEBUG] switch_core_state_machine.c:467 (OpenZAP/1:1/8040327325) State DESTROY going to sleep 2012-06-12 19:00:45.107225 [DEBUG] ozmod_isdn.c:1163 1:1 STATE [HANGUP] 2012-06-12 19:00:45.107225 [DEBUG] ozmod_isdn.c:1413 Hangup: Direction Outbound 2012-06-12 19:00:45.107225 [DEBUG] ozmod_isdn.c:1938 WRITE 29 ------------------------------------------------------------------------ -------- [08 02 00 04 45 08 02 81 90 1e 02 80 83 28 0e 44 65 76 20 54 65 61 6d 20 40 20 33 32 34] 2012-06-12 19:00:45.168168 [NOTICE] switch_core_session.c:1304 Session 5 (sofia/internal/324@192.168.1.155:5060) Ended 2012-06-12 19:00:45.168168 [NOTICE] switch_core_session.c:1306 Close Channel sofia/internal/324@192.168.1.155:5060 [CS_DESTROY] 2012-06-12 19:00:45.168168 [DEBUG] switch_core_state_machine.c:454 (sofia/internal/324@192.168.1.155:5060) Callstate Change HANGUP -> DOWN 2012-06-12 19:00:45.168168 [DEBUG] switch_core_state_machine.c:457 (sofia/internal/324@192.168.1.155:5060) Running State Change CS_DESTROY 2012-06-12 19:00:45.168168 [DEBUG] switch_core_state_machine.c:467 (sofia/internal/324@192.168.1.155:5060) State DESTROY 2012-06-12 19:00:45.168168 [DEBUG] mod_sofia.c:364 sofia/internal/324@192.168.1.155:5060 SOFIA DESTROY 2012-06-12 19:00:45.168168 [DEBUG] switch_core_state_machine.c:60 sofia/internal/324@192.168.1.155:5060 Standard DESTROY 2012-06-12 19:00:45.168168 [DEBUG] switch_core_state_machine.c:467 (sofia/internal/324@192.168.1.155:5060) State DESTROY going to sleep 2012-06-12 19:00:45.229192 [DEBUG] ozmod_isdn.c:1115 READ 17 ------------------------------------------------------------------------ -------- [08 02 1d 81 45 08 06 81 90 00 00 00 00 1e 02 80 83] 2012-06-12 19:00:45.229192 [DEBUG] ozmod_isdn.c:584 Yay I got an event! Type:[45] Size:[115] CRV: 7553 (0x1d81, CTX: Originator) 2012-06-12 19:00:45.229192 [DEBUG] ozmod_isdn.c:616 zchan 8e0dc38 (1:2) source isdn_data->channels_remote_crv[0x1d81] 2012-06-12 19:00:45.229192 [DEBUG] ozmod_isdn.c:719 Changing state on 1:2 from UP to TERMINATING 2012-06-12 19:00:45.289082 [DEBUG] ozmod_isdn.c:1163 1:2 STATE [TERMINATING] 2012-06-12 19:00:45.289082 [DEBUG] ozmod_isdn.c:1473 Terminating: Direction Inbound 2012-06-12 19:00:45.289082 [DEBUG] mod_openzap.c:1937 got clear channel sig [STOP] 2012-06-12 19:00:45.289082 [DEBUG] switch_channel.c:2592 (OpenZAP/1:2/325) Callstate Change ACTIVE -> HANGUP 2012-06-12 19:00:45.289082 [NOTICE] mod_openzap.c:1958 Hangup OpenZAP/1:2/325 [CS_EXECUTE] [NORMAL_CLEARING] 2012-06-12 19:00:45.289082 [DEBUG] switch_channel.c:2608 Send signal OpenZAP/1:2/325 [KILL] 2012-06-12 19:00:45.289082 [DEBUG] switch_core_session.c:1114 Send signal OpenZAP/1:2/325 [BREAK] 2012-06-12 19:00:45.289082 [DEBUG] ozmod_isdn.c:1938 WRITE 5 ------------------------------------------------------------------------ -------- [08 02 9d 81 4d] 2012-06-12 19:00:45.289082 [DEBUG] switch_ivr_bridge.c:584 BRIDGE THREAD DONE [OpenZAP/1:2/325] 2012-06-12 19:00:45.289082 [DEBUG] switch_ivr_bridge.c:604 Send signal OpenZAP/2:1/8040327325 [BREAK] 2012-06-12 19:00:45.289082 [DEBUG] switch_ivr_bridge.c:584 BRIDGE THREAD DONE [OpenZAP/2:1/8040327325] 2012-06-12 19:00:45.289082 [DEBUG] switch_ivr_bridge.c:604 Send signal OpenZAP/1:2/325 [BREAK] 2012-06-12 19:00:45.289082 [DEBUG] switch_channel.c:2592 (OpenZAP/2:1/8040327325) Callstate Change ACTIVE -> HANGUP 2012-06-12 19:00:45.289082 [NOTICE] switch_ivr_bridge.c:656 Hangup OpenZAP/2:1/8040327325 [CS_EXCHANGE_MEDIA] [NORMAL_CLEARING] 2012-06-12 19:00:45.289082 [DEBUG] switch_channel.c:2608 Send signal OpenZAP/2:1/8040327325 [KILL] 2012-06-12 19:00:45.289082 [DEBUG] switch_core_session.c:1114 Send signal OpenZAP/2:1/8040327325 [BREAK] 2012-06-12 19:00:45.289082 [DEBUG] switch_core_state_machine.c:374 (OpenZAP/2:1/8040327325) State EXCHANGE_MEDIA going to sleep 2012-06-12 19:00:45.289082 [DEBUG] switch_core_state_machine.c:325 (OpenZAP/2:1/8040327325) Running State Change CS_HANGUP 2012-06-12 19:00:45.289082 [DEBUG] switch_core_state_machine.c:565 (OpenZAP/2:1/8040327325) State HANGUP 2012-06-12 19:00:45.289082 [DEBUG] mod_openzap.c:544 Changing state on 2:1 from UP to HANGUP 2012-06-12 19:00:45.289082 [DEBUG] mod_openzap.c:560 OpenZAP/2:1/8040327325 CHANNEL HANGUP 2012-06-12 19:00:45.289082 [DEBUG] switch_core_state_machine.c:46 OpenZAP/2:1/8040327325 Standard HANGUP, cause: NORMAL_CLEARING 2012-06-12 19:00:45.289082 [DEBUG] switch_core_state_machine.c:565 (OpenZAP/2:1/8040327325) State HANGUP going to sleep 2012-06-12 19:00:45.289082 [DEBUG] switch_core_state_machine.c:356 (OpenZAP/2:1/8040327325) State Change CS_HANGUP -> CS_REPORTING 2012-06-12 19:00:45.289082 [DEBUG] switch_core_session.c:1114 Send signal OpenZAP/2:1/8040327325 [BREAK] 2012-06-12 19:00:45.289082 [DEBUG] switch_core_state_machine.c:325 (OpenZAP/2:1/8040327325) Running State Change CS_REPORTING 2012-06-12 19:00:45.289082 [DEBUG] switch_core_state_machine.c:625 (OpenZAP/2:1/8040327325) State REPORTING 2012-06-12 19:00:45.289082 [DEBUG] switch_core_state_machine.c:53 OpenZAP/2:1/8040327325 Standard REPORTING, cause: NORMAL_CLEARING 2012-06-12 19:00:45.289082 [DEBUG] switch_core_state_machine.c:625 (OpenZAP/2:1/8040327325) State REPORTING going to sleep 2012-06-12 19:00:45.289082 [DEBUG] switch_core_state_machine.c:350 (OpenZAP/2:1/8040327325) State Change CS_REPORTING -> CS_DESTROY 2012-06-12 19:00:45.289082 [DEBUG] switch_core_session.c:1114 Send signal OpenZAP/2:1/8040327325 [BREAK] 2012-06-12 19:00:45.289082 [DEBUG] switch_core_session.c:1286 Session 8 (OpenZAP/2:1/8040327325) Locked, Waiting on external entities 2012-06-12 19:00:45.289082 [DEBUG] switch_ivr_bridge.c:1313 OpenZAP/1:2/325 skip receive message [UNBRIDGE] (channel is hungup already) 2012-06-12 19:00:45.289082 [DEBUG] switch_core_session.c:2059 OpenZAP/1:2/325 skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already) 2012-06-12 19:00:45.289082 [DEBUG] switch_core_state_machine.c:371 (OpenZAP/1:2/325) State EXECUTE going to sleep 2012-06-12 19:00:45.289082 [DEBUG] switch_core_state_machine.c:325 (OpenZAP/1:2/325) Running State Change CS_HANGUP 2012-06-12 19:00:45.289082 [DEBUG] switch_core_state_machine.c:565 (OpenZAP/1:2/325) State HANGUP 2012-06-12 19:00:45.289082 [DEBUG] mod_openzap.c:560 OpenZAP/1:2/325 CHANNEL HANGUP 2012-06-12 19:00:45.289082 [DEBUG] switch_core_state_machine.c:46 OpenZAP/1:2/325 Standard HANGUP, cause: NORMAL_CLEARING 2012-06-12 19:00:45.289082 [DEBUG] switch_core_state_machine.c:565 (OpenZAP/1:2/325) State HANGUP going to sleep 2012-06-12 19:00:45.289082 [DEBUG] switch_core_state_machine.c:356 (OpenZAP/1:2/325) State Change CS_HANGUP -> CS_REPORTING 2012-06-12 19:00:45.289082 [DEBUG] switch_core_session.c:1114 Send signal OpenZAP/1:2/325 [BREAK] 2012-06-12 19:00:45.289082 [DEBUG] switch_core_state_machine.c:325 (OpenZAP/1:2/325) Running State Change CS_REPORTING 2012-06-12 19:00:45.289082 [DEBUG] switch_core_state_machine.c:625 (OpenZAP/1:2/325) State REPORTING 2012-06-12 19:00:45.289082 [DEBUG] switch_core_state_machine.c:53 OpenZAP/1:2/325 Standard REPORTING, cause: NORMAL_CLEARING 2012-06-12 19:00:45.289082 [DEBUG] switch_core_state_machine.c:625 (OpenZAP/1:2/325) State REPORTING going to sleep 2012-06-12 19:00:45.289082 [DEBUG] switch_core_state_machine.c:350 (OpenZAP/1:2/325) State Change CS_REPORTING -> CS_DESTROY 2012-06-12 19:00:45.289082 [DEBUG] switch_core_session.c:1114 Send signal OpenZAP/1:2/325 [BREAK] 2012-06-12 19:00:45.289082 [DEBUG] switch_core_session.c:1286 Session 7 (OpenZAP/1:2/325) Locked, Waiting on external entities 2012-06-12 19:00:45.289082 [NOTICE] switch_core_session.c:1304 Session 7 (OpenZAP/1:2/325) Ended 2012-06-12 19:00:45.289082 [NOTICE] switch_core_session.c:1306 Close Channel OpenZAP/1:2/325 [CS_DESTROY] 2012-06-12 19:00:45.289082 [DEBUG] switch_core_state_machine.c:454 (OpenZAP/1:2/325) Callstate Change HANGUP -> DOWN 2012-06-12 19:00:45.289082 [DEBUG] switch_core_state_machine.c:457 (OpenZAP/1:2/325) Running State Change CS_DESTROY 2012-06-12 19:00:45.289082 [DEBUG] switch_core_state_machine.c:467 (OpenZAP/1:2/325) State DESTROY 2012-06-12 19:00:45.289082 [DEBUG] switch_core_state_machine.c:60 OpenZAP/1:2/325 Standard DESTROY 2012-06-12 19:00:45.289082 [DEBUG] switch_core_state_machine.c:467 (OpenZAP/1:2/325) State DESTROY going to sleep 2012-06-12 19:00:45.289082 [NOTICE] switch_core_session.c:1304 Session 8 (OpenZAP/2:1/8040327325) Ended 2012-06-12 19:00:45.289082 [NOTICE] switch_core_session.c:1306 Close Channel OpenZAP/2:1/8040327325 [CS_DESTROY] 2012-06-12 19:00:45.289082 [DEBUG] switch_core_state_machine.c:454 (OpenZAP/2:1/8040327325) Callstate Change HANGUP -> DOWN 2012-06-12 19:00:45.289082 [DEBUG] switch_core_state_machine.c:457 (OpenZAP/2:1/8040327325) Running State Change CS_DESTROY 2012-06-12 19:00:45.289082 [DEBUG] switch_core_state_machine.c:467 (OpenZAP/2:1/8040327325) State DESTROY 2012-06-12 19:00:45.289082 [DEBUG] switch_core_state_machine.c:60 OpenZAP/2:1/8040327325 Standard DESTROY 2012-06-12 19:00:45.289082 [DEBUG] switch_core_state_machine.c:467 (OpenZAP/2:1/8040327325) State DESTROY going to sleep 2012-06-12 19:00:45.289082 [DEBUG] ozmod_isdn.c:1115 READ 5 ------------------------------------------------------------------------ -------- [08 02 80 04 4d] 2012-06-12 19:00:45.289082 [DEBUG] ozmod_isdn.c:584 Yay I got an event! Type:[4d] Size:[103] CRV: 4 (0x4, CTX: Terminator) 2012-06-12 19:00:45.289082 [DEBUG] ozmod_isdn.c:616 zchan 8e082e8 (1:1) source isdn_data->channels_local_crv[0x4] 2012-06-12 19:00:45.289082 [DEBUG] ozmod_isdn.c:680 Changing state on 1:1 from HANGUP to HANGUP_COMPLETE 2012-06-12 19:00:45.289082 [DEBUG] ozmod_isdn.c:1938 WRITE 5 ------------------------------------------------------------------------ -------- [08 02 00 04 5a] 2012-06-12 19:00:45.289082 [DEBUG] ozmod_isdn.c:1120 931 parse error [1] [Q931E_NO_ERROR] 2012-06-12 19:00:45.329082 [DEBUG] ozmod_isdn.c:1163 1:1 STATE [HANGUP_COMPLETE] 2012-06-12 19:00:45.329082 [DEBUG] ozmod_isdn.c:1406 Changing state on 1:1 from HANGUP_COMPLETE to DOWN 2012-06-12 19:00:45.329082 [DEBUG] ozmod_isdn.c:1163 2:1 STATE [HANGUP] 2012-06-12 19:00:45.329082 [DEBUG] ozmod_isdn.c:1413 Hangup: Direction Outbound 2012-06-12 19:00:45.329082 [DEBUG] ozmod_isdn.c:1938 WRITE 25 ------------------------------------------------------------------------ -------- [08 02 00 05 45 08 02 81 90 1e 02 80 83 28 0a 38 30 34 30 33 32 37 33 32 34] 2012-06-12 19:00:45.349081 [DEBUG] ozmod_isdn.c:1115 READ 5 ------------------------------------------------------------------------ -------- [08 02 80 05 4d] 2012-06-12 19:00:45.349081 [DEBUG] ozmod_isdn.c:584 Yay I got an event! Type:[4d] Size:[103] CRV: 5 (0x5, CTX: Terminator) 2012-06-12 19:00:45.349081 [DEBUG] ozmod_isdn.c:616 zchan b750c4f0 (2:1) source isdn_data->channels_local_crv[0x5] 2012-06-12 19:00:45.349081 [DEBUG] ozmod_isdn.c:680 Changing state on 2:1 from HANGUP to HANGUP_COMPLETE 2012-06-12 19:00:45.349081 [DEBUG] ozmod_isdn.c:1938 WRITE 5 ------------------------------------------------------------------------ -------- [08 02 00 05 5a] 2012-06-12 19:00:45.349081 [DEBUG] ozmod_isdn.c:1120 931 parse error [1] [Q931E_NO_ERROR] 2012-06-12 19:00:45.368996 [DEBUG] ozmod_isdn.c:1163 2:1 STATE [HANGUP_COMPLETE] 2012-06-12 19:00:45.368996 [DEBUG] ozmod_isdn.c:1406 Changing state on 2:1 from HANGUP_COMPLETE to DOWN 2012-06-12 19:00:45.428780 [DEBUG] ozmod_isdn.c:1163 1:1 STATE [DOWN] 2012-06-12 19:00:45.428780 [DEBUG] zap_io.c:1415 channel done 1:1 2012-06-12 19:00:45.428780 [DEBUG] ozmod_isdn.c:1115 READ 5 ------------------------------------------------------------------------ -------- [08 02 1d 81 5a] 2012-06-12 19:00:45.428780 [DEBUG] ozmod_isdn.c:584 Yay I got an event! Type:[5a] Size:[103] CRV: 7553 (0x1d81, CTX: Originator) 2012-06-12 19:00:45.428780 [DEBUG] ozmod_isdn.c:616 zchan 8e0dc38 (1:2) source isdn_data->channels_remote_crv[0x1d81] 2012-06-12 19:00:45.428780 [DEBUG] ozmod_isdn.c:682 Changing state on 1:2 from TERMINATING to DOWN 2012-06-12 19:00:45.468782 [DEBUG] ozmod_isdn.c:1163 2:1 STATE [DOWN] 2012-06-12 19:00:45.468782 [DEBUG] zap_io.c:1415 channel done 2:1 2012-06-12 19:00:45.528782 [DEBUG] ozmod_isdn.c:1163 1:2 STATE [DOWN] 2012-06-12 19:00:45.528782 [DEBUG] zap_io.c:1415 channel done 1:2
On Tue, Jun 12, 2012 at 10:07 AM, George D'mithrov < george.d@telesoftlabs.com> wrote:
**
Hi,
I wants to bridge calls with particular DID, which landing on one PRI span (Span_1) to another PRI span (Span_2).
I'm able to bridge the calls between PRI span and able to talk to each other.
My problem is that sometimes DTMF which received on Span_1 is not sending to Span2 and vice-verse. DTMF tones are hearing partially on receving end.
Sometimes after a some delay (30-60 seconds) am getting the DTMF, but that's too some dtmf are missing.
If I hangup the line while the dtmf is in queue then the dtmf are generating on the next call on the same line.
But when I bridge the call on PRI with sip channel then am not getting any problem.
I think the following log in freeswitch is usefull
2012-06-12 18:58:38.379506 [DEBUG] mod_openzap.c:725 queue DTMF [1] 2012-06-12 18:58:38.019513 [DEBUG] switch_ivr_bridge.c:391 Send signal OpenZAP/1:1/8040327325 [BREAK] after this it takes a while to generate dtmf
Any reason you're using a deprecated module? you should be using mod_freetdm and not mod_openzap. I think it's been 2 years since we renamed openzap to freetdm and did all new development on freetdm. I don't particularly remember if the issue you mention is fixed, but before I would even look at the logs to see if there is an issue indeed you need to upgrade to FreeTDM. *Moises Silva **Manager, Software Engineering*** msilva@sangoma.com Sangoma Technologies 100 Renfrew Drive, Suite 100, Markham, ON L3R 9R6 Canada t. +1 800 388 2475 (N. America) t. +1 905 474 1990 x128 f. +1 905 474 9223 **<http://www.sangoma.com/contact?utm_source=signature&utm_medium=email&utm_campaign=email+signatures> Products<http://sangoma.com/products?utm_source=signature&utm_medium=email&utm_campaign=email%2Bsignatures> | Solutions<http://sangoma.com/solutions?utm_source=signature&utm_medium=email&utm_campaign=email%2Bsignatures> | Events<http://sangoma.com/about_us/events?utm_source=signature&utm_medium=email&utm_campaign=email%2Bsignatures> | Contact<http://www.sangoma.com/contact?utm_source=signature&utm_medium=email&utm_campaign=email%2Bsignatures> | Wiki<http://wiki.sangoma.com/?utm_source=signature&utm_medium=email&utm_campaign=email%2Bsignatures> | Facebook<http://www.facebook.com/pages/Sangoma-VoIP-Cards/43578453335?utm_source=signature&utm_medium=email&utm_campaign=email%2Bsignatures> | Twitter<http://www.twitter.com/sangoma?utm_source=signature&utm_medium=email&utm_campaign=email%2Bsignatures>`| | YouTube<http://www.youtube.com/sangomatechnologies?utm_source=signature&utm_medium=email&utm_campaign=email%2Bsignatures>
participants (2)
-
George D'mithrov
-
Moises Silva