[Freeswitch-dev] OZ: possible issue with false positives in Q931IsIEPresent macro
FYI, After much pain I am able to say that I can consistently reproduce this scenario: In zap_isdn.c, function zap_isdn_931_34, I can always get the Q931IsIEPresent macro to see a cause ie, whether one is present or not. I've added this snippet toward the beginning of the function: if (Q931IsIEPresent(gen->Cause)) { zap_log(ZAP_LOG_DEBUG, "Cause ie present [%x]\n",gen->Cause); } Raw output is as follows; note that all inbound q931 message say that a cause ie is present, even when one isn't: freeswitch@freeswitch2.fcnetwork.com> originate {origination_caller_id_number=80 05409011,dname='Busy',dnum='5898832',dialednum='5597332791',agentinfo='5 898832.2 791',bcast='Mikey_test'}openzap/1/a/5597332791 825597332791 2008-06-21 12:12:43 [DEBUG] zap_isdn.c:56 isdn_outgoing_call() Changing state on 1:1 from DOWN to DIALING 2008-06-21 12:12:43 [DEBUG] switch_core_state_machine.c:365 switch_core_session_ run() OpenZAP/1:1/5597332791 Running State Change CS_INIT 2008-06-21 12:12:43 [DEBUG] switch_core_state_machine.c:415 switch_core_session_ run() (OpenZAP/1:1/5597332791) State INIT 2008-06-21 12:12:43 [DEBUG] switch_core_state_machine.c:415 switch_core_session_ run() (OpenZAP/1:1/5597332791) State INIT going to sleep 2008-06-21 12:12:43 [DEBUG] switch_core_state_machine.c:365 switch_core_session_ run() OpenZAP/1:1/5597332791 Running State Change CS_ROUTING 2008-06-21 12:12:43 [DEBUG] switch_core_state_machine.c:420 switch_core_session_ run() (OpenZAP/1:1/5597332791) State ROUTING 2008-06-21 12:12:43 [DEBUG] switch_core_state_machine.c:420 switch_core_session_ run() (OpenZAP/1:1/5597332791) State ROUTING going to sleep 2008-06-21 12:12:43 [DEBUG] switch_core_state_machine.c:365 switch_core_session_ run() OpenZAP/1:1/5597332791 Running State Change CS_CONSUME_MEDIA 2008-06-21 12:12:43 [DEBUG] switch_core_state_machine.c:442 switch_core_session_ run() (OpenZAP/1:1/5597332791) State CONSUME_MEDIA 2008-06-21 12:12:44 [ERR] zap_isdn.c:589 state_advance() 1:1 STATE [DIALING] 2008-06-21 12:12:44 [DEBUG] zap_isdn.c:987 q931_rx_32() WRITE 58 ------------------------------------------------------------------------ -------- [00 01 00 00 08 02 00 02 05 04 03 80 90 a2 18 03 a1 83 81 28 0a 46 72 65 65 53 5 7 49 54 43 48 6c 0c 21 80 38 30 30 35 34 30 39 30 31 31 70 0b a1 35 35 39 37 33 33 32 37 39 31] 2008-06-21 12:12:44 [DEBUG] zap_isdn.c:556 zap_isdn_921_23() READ 13 ------------------------------------------------------------------------ -------- [08 02 80 02 7d 08 03 81 ab 28 14 01 01] 2008-06-21 12:12:44 [DEBUG] zap_isdn.c:284 zap_isdn_931_34() Yay I got an event! Type:[7d] Size:[114] 2008-06-21 12:12:44 [DEBUG] zap_isdn.c:287 zap_isdn_931_34() Cause ie present [8 000] 2008-06-21 12:12:44 [DEBUG] zap_isdn.c:556 zap_isdn_921_23() READ 10 ------------------------------------------------------------------------ -------- [08 02 80 02 02 18 03 a9 83 81] 2008-06-21 12:12:44 [DEBUG] zap_isdn.c:284 zap_isdn_931_34() Yay I got an event! Type:[02] Size:[137] 2008-06-21 12:12:44 [DEBUG] zap_isdn.c:287 zap_isdn_931_34() Cause ie present [8 000] 2008-06-21 12:12:44 [DEBUG] zap_isdn.c:556 zap_isdn_921_23() READ 9 ------------------------------------------------------------------------ -------- [08 02 80 02 03 1e 02 81 88] 2008-06-21 12:12:44 [DEBUG] zap_isdn.c:284 zap_isdn_931_34() Yay I got an event! Type:[03] Size:[108] 2008-06-21 12:12:44 [DEBUG] zap_isdn.c:287 zap_isdn_931_34() Cause ie present [8 000] 2008-06-21 12:12:44 [DEBUG] zap_isdn.c:428 zap_isdn_931_34() Cause info [8000] 2008-06-21 12:12:44 [DEBUG] zap_isdn.c:434 zap_isdn_931_34() PROGRESS message wi th cause value of '0' 2008-06-21 12:12:44 [DEBUG] zap_isdn.c:556 zap_isdn_921_23() READ 13 ------------------------------------------------------------------------ -------- [08 02 80 02 03 08 02 81 91 1e 02 81 88] 2008-06-21 12:12:44 [DEBUG] zap_isdn.c:284 zap_isdn_931_34() Yay I got an event! Type:[03] Size:[115] 2008-06-21 12:12:44 [DEBUG] zap_isdn.c:287 zap_isdn_931_34() Cause ie present [8 000] 2008-06-21 12:12:44 [DEBUG] zap_isdn.c:428 zap_isdn_931_34() Cause info [8000] 2008-06-21 12:12:44 [DEBUG] zap_isdn.c:434 zap_isdn_931_34() PROGRESS message wi th cause value of '17' 2008-06-21 12:12:44 [DEBUG] zap_isdn.c:436 zap_isdn_931_34() Changing state on 1 :1 from DIALING to TERMINATING 2008-06-21 12:12:44 [ERR] zap_isdn.c:589 state_advance() 1:1 STATE [TERMINATING] API CALL [originate({origination_caller_id_number=8005409011,dname='Busy',dnum=' 5898832',dialednum='5597332791',agentinfo='5898832.2791',bcast='Mikey_te st'}open zap/1/a/5597332791 825597332791)] output: -ERR USER_BUSY 2008-06-21 12:12:44 [DEBUG] zap_isdn.c:987 q931_rx_32() WRITE 21 ------------------------------------------------------------------------ -------- [00 01 02 08 08 02 00 02 4d 28 0a 46 72 65 65 53 57 49 54 43 48] 2008-06-21 12:12:44 [DEBUG] switch_core_state_machine.c:442 switch_core_session_ run() (OpenZAP/1:1/5597332791) State CONSUME_MEDIA going to sleep 2008-06-21 12:12:44 [DEBUG] switch_core_state_machine.c:365 switch_core_session_ run() OpenZAP/1:1/5597332791 Running State Change CS_HANGUP 2008-06-21 12:12:44 [DEBUG] switch_core_state_machine.c:393 switch_core_session_ run() (OpenZAP/1:1/5597332791) State HANGUP freeswitch@freeswitch2.fcnetwork.com> 2008-06-21 12:12:44 [DEBUG] switch_core_st ate_machine.c:46 switch_core_standard_on_hangup() Standard HANGUP OpenZAP/1:1/55 97332791, cause: USER_BUSY 2008-06-21 12:12:44 [DEBUG] switch_core_state_machine.c:393 switch_core_session_ run() (OpenZAP/1:1/5597332791) State HANGUP going to sleep 2008-06-21 12:12:45 [DEBUG] zap_isdn.c:556 zap_isdn_921_23() READ 10 ------------------------------------------------------------------------ -------- [08 02 80 02 5a 08 03 81 e0 08] 2008-06-21 12:12:45 [DEBUG] zap_isdn.c:284 zap_isdn_931_34() Yay I got an event! Type:[5a] Size:[110] 2008-06-21 12:12:45 [DEBUG] zap_isdn.c:287 zap_isdn_931_34() Cause ie present [8 000] 2008-06-21 12:12:45 [DEBUG] zap_isdn.c:386 zap_isdn_931_34() Changing state on 1 :1 from TERMINATING to HANGUP_COMPLETE 2008-06-21 12:12:45 [ERR] zap_isdn.c:589 state_advance() 1:1 STATE [HANGUP_COMPL ETE] 2008-06-21 12:12:45 [DEBUG] zap_isdn.c:761 state_advance() Changing state on 1:1 from HANGUP_COMPLETE to DOWN 2008-06-21 12:12:45 [ERR] zap_isdn.c:589 state_advance() 1:1 STATE [DOWN] 2008-06-21 12:12:45 [DEBUG] zap_io.c:1071 zap_channel_done() channel done 1:1 Anyway, I thought I'd share. If you think this is jira-worthy I'll post a new issue, otherwise if you know why the gen->Cause is always showing up as present I'd be happy to fix and test. For the record, the test is a bitwise AND, where the "cause" value is ANDed against 0x8000. Since the gen->Cause value seems always to be 0x8000, whether it is present or not, it always comes up as true. Thanks for your thoughts and suggestions. -MC
participants (1)
-
Michael Collins