[Serdev] BYE gets lost with call from Messenger over isdngw

[Jiri Kuthan]

At 10:36 PM 5/2/2004, Ulrich Holeschak wrote:
>Hallo,
>now after the CSeq BYE problem has been fixed, i found a new one with BYE, but this time i thinks it's more a problem in ser.
>When i call a PSTN phone with isdngw from Windows Messenger all works well, but the BYE in both directions gets lost (disconnect from Messenger or Phone). If i look in the log file i could see (In this case it's a disconnect from the phone):
> 
>May  2 21:31:59 router isdnlog: May 02 21:31:59   Call to tei 121 from phone on phone  HANGUP ( 0:00:34)  
>May  2 21:31:59 router Sems[3815]: Debug: IsdnCapiConnection::cb_disconnect_b3_ind (media ended) 
>May  2 21:31:59 router Sems[3815]: Debug: CALL: PSTN state (outbound): from (CONNECTED|CONNECTED) to (CONNECTED|DISCONNECTED) 
>May  2 21:31:59 router Sems[3815]: Debug: PSTN hangup CAPI device 
>May  2 21:31:59 router Sems[3815]: Debug: CALL: SIP  state (outbound): from (CONNECTED|DISCONNECTED) to (DISCONNECTED|DISCONNECTED) 
>May  2 21:31:59 router Sems[3815]: Debug: msg=<:t_uac_dlg:00000EE7071A00D3 BYE sip:494755 at router.local:11289;maddr=192.168.42.242;tr
>May  2 21:31:59 router ./ser[3793]: fifo_get_method: method: 'BYE' 
>May  2 21:31:59 router ./ser[3793]: DEBUG: fifo_get_ruri: 'sip:494755 at router.local:11289;maddr=192.168.42.242;transport=tcp' 
>May  2 21:31:59 router ./ser[3793]: DEBUG: fifo_get_nexthop: next hop empty 
>May  2 21:31:59 router ./ser[3793]: fifo_get_headers: headers: From: <sip:06151494755 at router.local>;tag=00000EE426C41045^M To: "4947
>May  2 21:31:59 router ./ser[3793]: parse_headers: flags=-1 
>May  2 21:31:59 router ./ser[3793]: DEBUG: add_param: tag=2f312d4f5fe840bbbce35c44375bd48b 
>May  2 21:31:59 router ./ser[3793]: end of header reached, state=29 
>May  2 21:31:59 router ./ser[3793]: DEBUG: get_hdr_field: <To> [86]; uri=[sip:494755 at router.local]  
>May  2 21:31:59 router ./ser[3793]: DEBUG: to body ["<mailto:494755 at router.local>494755 at router.local" <sip:494755 at router.local>] 
>May  2 21:31:59 router ./ser[3793]: get_hdr_field: cseq <CSeq>: <2> <BYE> 
>May  2 21:31:59 router ./ser[3793]: DEBUG: fifo_uac: parse_headers succeeded 
>May  2 21:31:59 router ./ser[3793]: fifo_get_body: body:  
>May  2 21:31:59 router ./ser[3793]: DEBUG: add_param: tag=00000EE426C41045 
>May  2 21:31:59 router ./ser[3793]: end of header reached, state=29 
>May  2 21:31:59 router ./ser[3793]: DEBUG: get_hfblock: one more hf processed 
>May  2 21:31:59 router ./ser[3793]: DEBUG: get_hfblock: one more hf processed 
>May  2 21:31:59 router ./ser[3793]: DEBUG: fifo_uac: EoL -- proceeding to transaction creation 
>May  2 21:31:59 router ./ser[3793]: DEBUG:tm:t_uac: next_hop=<sip:494755 at router.local:11289;maddr=192.168.42.242;transport=tcp> 
>May  2 21:31:59 router ./ser[3793]: DEBUG: mk_proxy: doing DNS lookup... 
>May  2 21:31:59 router ./ser[3793]: DEBUG: dlg2hash: 62111 
>May  2 21:31:59 router ./ser[3793]: tcp_send: no open tcp connection found, opening new one 
>May  2 21:31:59 router ./ser[3793]: ERROR: tcp_blocking_connect: SO_ERROR (111) Connection refused 
>May  2 21:31:59 router ./ser[3793]: ERROR: tcpconn_connect: tcp_blocking_connect failed 
>May  2 21:31:59 router ./ser[3793]: ERROR: tcp_send: connect failed 
>May  2 21:31:59 router ./ser[3793]: msg_send: ERROR: tcp_send failed 
>May  2 21:31:59 router ./ser[3793]: t_uac: Attempt to send to 'sip:494755 at router.local:11289;maddr=192.168.42.242;transport=tcp' fai
>May  2 21:31:59 router ./ser[3793]: DEBUG: add_timer_unsafe[0]: 0x402d47d0 
>May  2 21:31:59 router ./ser[3793]: **** done consume 
>May  2 21:31:59 router ./ser[3793]: INFO: fifo_server: command empty 
>May  2 21:31:59 router Sems[3815]: Debug: Write to fifo: completed 
> 
>You could see the error:
>    ERROR: tcp_blocking_connect: SO_ERROR (111) Connection refused 
>    ERROR: tcpconn_connect: tcp_blocking_connect failed 
>    msg_send: ERROR: tcp_send failed 
> 
>Something goes wrong here, what could that be?
>This only occures if the call is made from Windows Messenger!

Possibly it is caused by lack of support of maddr in SER/SEMS's UAC. What you did 
works for SER in proxy mode, but maddr is not handled in SER acting as UAC.

>May  2 21:31:59 router ./ser[3793]: DEBUG:tm:t_uac: next_hop=<sip:494755 at router.local:11289;maddr=192.168.42.242;transport=tcp> 

Here SER/isdngw tries to determine next hop to send a BYE. It supposingly fails, 
because maddr is ignored and a connection is attempted to router.local:11289:TCP
instead of 192.168.42.242:11289:TCP. If this is really the case, a solution could
be to split SER in proxy mode from SER acting as isdngw. Then the SER/SEMS/isdngw
would be fronted by proxy handling the maddr pain for it.

Does this explanation make sense? I would need to see network dumps too to be more
sure. (I can'tt promise to look at them though -- my backlog is too big.)

-jiri