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='5898832.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_test'}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