Hi *,
Here is the trace. One thing I have noticed is that the 180 Ringing being
returned from the Snom phone (behind the NAT) contains the contact header
still with the private IP (192.168.1.100). Theoretically though I don't see
how this can affect the transaction handling - maybe you can shed some
light.
********------------------------------------- ROUTE(5)
-----------------------------------********
********------------------------------------ PROXY-AUTH
-----------------------------------********
<snip>
********---------------------------------- PROXY-AUTH DONE
--------------------------------********
********---------------------------------- ROUTE(5) DONE
--------------------------------********
********---------------------------------- ROUTE(3)
-----------------------------------********
********--------------------------------- RECORD-ROUTE
---------------------------------********
********------------------------------- RECORD-ROUTE DONE
------------------------------********
********------------------------------- ROUTE(3) DONE
--------------------------------********
********---------------------------------- ROUTE(4)
-----------------------------------********
********------------------------------------ INVITE
------------------------------------********
Jan 30 11:31:34 [11258] INFO:dialog:dlg_created_cb: dialog created or
destroyed
Jan 30 11:31:34 [11258] INFO:dialog:dlg_created_cb: CALLID IS
[3c268b5bbf2d-mtnq42l2osup]------------------------------------------------------------------------------------------------------
********--------------------------------- INVITE DONE
----------------------------------********
********------------------------------- ROUTE(4) DONE
--------------------------------********
********------------------------------------- ROUTE(6)
--------------------------------------------********
********-------------------------------------- USRLOC
----------------------------------------------********
<snip>
********-------------------------------------- USRLOC DONE
-----------------------------------------********
********------------------------------------ ROUTE(6) DONE
---------------------------------------********
********---------------------------------- ROUTE(1)
------------------------------------********
********--------------------------------- INVITE
---------------------------------********
********---------------------------------- T_RELAY
-------------------------------------********
[INVITE] BRANCH-ROUTE[2] New branch at
[sip:S001e310003ee@41.2.192.203<sip%3AS001e310003ee@41.2.192.203>]
(RURI=[sip:0870000005@abcd.com <sip%3A0870000005(a)abcd.com>] F=[
sip:S000413292efd@abcd.com <sip%3AS000413292efd(a)abcd.com>]
T=[sip:0870000005*47942@abcd.com;user=phone] IP=[192.168.2.174]
ID=[3c268b5bbf2d-mtnq42l2osup])
********------------------------------- ROUTE(1) DONE
-----------------------------------********
[INVITE] INCOMING-REPLY[2]
(RURI=[sip:0870000005@abcd.com<sip%3A0870000005@abcd.com>]
F=[sip:S000413292efd@abcd.com <sip%3AS000413292efd(a)abcd.com>]
T=[sip:0870000005*47942@abcd.com;user=phone] IP=[192.168.2.174]
ID=[3c268b5bbf2d-mtnq42l2osup])
[INVITE] INCOMING-REPLY[2] DLG_TIMEOUT=[43199] (RURI=[
sip:0870000005@abcd.com <sip%3A0870000005(a)abcd.com>] F=[
sip:S000413292efd@abcd.com <sip%3AS000413292efd(a)abcd.com>]
T=[sip:0870000005*47942@abcd.com;user=phone] IP=[192.168.2.174]
ID=[3c268b5bbf2d-mtnq42l2osup])
Jan 30 11:31:34 [11258] INFO:dialog:dlg_onreply: dlg_onreply called
statistics: [tm_rld_rpls] : [1]
Jan 30 11:31:34 [11258] INFO:dialog:dlg_onreply: dlg_onreply called
Jan 30 11:31:34 [11258] INFO:dialog:dlg_onreply: new_state =
DLG_STATE_EARLY.
Jan 30 11:31:34 [11258] INFO:dialog:dlg_onreply: old_state!=DLG_STATE_EARLY.
Jan 30 11:31:34 [11258] INFO:dialog:dlg_onreply: Checking for RINGING [180]
PARAM-CODE [180].
<snip>
********---------------------------------- ROUTE(2)
-----------------------------------********
********------------------------------------ TO-TAG
-------------------------------------********
********---------------------------------- LOOSE-ROUTE
---------------------------------********
********---------------------------------- TO-TAG DONE
----------------------------------********
********-------------------------------- ROUTE(2) DONE
--------------------------------********
********---------------------------------- ROUTE(1)
------------------------------------********
********---------------------------------- T_RELAY
-------------------------------------********
********------------------------------- ROUTE(1) DONE
-----------------------------------********
[PRACK] INCOMING-REPLY[2] (RURI=[sip:S001e310003ee@192.168.1.100:5060] F=[
sip:S000413292efd@abcd.com <sip%3AS000413292efd(a)abcd.com>]
T=[sip:0870000005*47942@abcd.com;user=phone] IP=[192.168.2.174]
ID=[3c268b5bbf2d-mtnq42l2osup])
[PRACK] INCOMING-REPLY[2] DLG_TIMEOUT=[43199] (RURI=[
sip:S001e310003ee@192.168.1.100:5060]
F=[sip:S000413292efd@abcd.com<sip%3AS000413292efd@abcd.com>]
T=[sip:0870000005*47942@abcd.com;user=phone] IP=[192.168.2.174]
ID=[3c268b5bbf2d-mtnq42l2osup])
Jan 30 11:31:35 [11258] INFO:dialog:dlg_onreply: dlg_onreply called
statistics: [tm_rld_rpls] : [1]
Jan 30 11:31:35 [11258] INFO:dialog:dlg_onreply: dlg_onreply called
Jan 30 11:31:35 [11258] INFO:dialog:dlg_onreply: new_state =
DLG_STATE_EARLY.
statistics: [rcv_reqs] : [1]
********---------------------------------- ROUTE(2)
-----------------------------------********
********------------------------------------ TO-TAG
-------------------------------------********
********---------------------------------- LOOSE-ROUTE
---------------------------------********
********---------------------------------- TO-TAG DONE
----------------------------------********
********-------------------------------- ROUTE(2) DONE
--------------------------------********
********---------------------------------- ROUTE(1)
------------------------------------********
********---------------------------------- T_RELAY
-------------------------------------********
[PRACK] INCOMING-REPLY[2] (RURI=[sip:S001e310003ee@192.168.1.100:5060] F=[
sip:S000413292efd@abcd.com <sip%3AS000413292efd(a)abcd.com>]
T=[sip:0870000005*47942@abcd.com;user=phone] IP=[192.168.2.174]
ID=[3c268b5bbf2d-mtnq42l2osup])
[PRACK] INCOMING-REPLY[2] DLG_TIMEOUT=[43199] (RURI=[
sip:S001e310003ee@192.168.1.100:5060]
F=[sip:S000413292efd@abcd.com<sip%3AS000413292efd@abcd.com>]
T=[sip:0870000005*47942@abcd.com;user=phone] IP=[192.168.2.174]
ID=[3c268b5bbf2d-mtnq42l2osup])
Jan 30 11:31:36 [11258] INFO:dialog:dlg_onreply: dlg_onreply called
statistics: [tm_rld_rpls] : [1]
Jan 30 11:31:36 [11258] INFO:dialog:dlg_onreply: dlg_onreply called
Jan 30 11:31:36 [11258] INFO:dialog:dlg_onreply: new_state =
DLG_STATE_EARLY.
statistics: [rcv_reqs] : [1]
********---------------------------------- ROUTE(2)
-----------------------------------********
********------------------------------------ TO-TAG
-------------------------------------********
********---------------------------------- LOOSE-ROUTE
---------------------------------********
********---------------------------------- TO-TAG DONE
----------------------------------********
********-------------------------------- ROUTE(2) DONE
--------------------------------********
********---------------------------------- ROUTE(1)
------------------------------------********
********---------------------------------- T_RELAY
-------------------------------------********
[PRACK] INCOMING-REPLY[2] (RURI=[sip:S001e310003ee@192.168.1.100:5060] F=[
sip:S000413292efd@abcd.com <sip%3AS000413292efd(a)abcd.com>]
T=[sip:0870000005*47942@abcd.com;user=phone] IP=[192.168.2.174]
ID=[3c268b5bbf2d-mtnq42l2osup])
[PRACK] INCOMING-REPLY[2] DLG_TIMEOUT=[43199] (RURI=[
sip:S001e310003ee@192.168.1.100:5060]
F=[sip:S000413292efd@abcd.com<sip%3AS000413292efd@abcd.com>]
T=[sip:0870000005*47942@abcd.com;user=phone] IP=[192.168.2.174]
ID=[3c268b5bbf2d-mtnq42l2osup])
Jan 30 11:31:38 [11258] INFO:dialog:dlg_onreply: dlg_onreply called
statistics: [tm_rld_rpls] : [1]
Jan 30 11:31:38 [11258] INFO:dialog:dlg_onreply: dlg_onreply called
Jan 30 11:31:38 [11258] INFO:dialog:dlg_onreply: new_state =
DLG_STATE_EARLY.
statistics: [rcv_reqs] : [1]
********---------------------------------- ROUTE(2)
-----------------------------------********
********------------------------------------ TO-TAG
-------------------------------------********
********---------------------------------- LOOSE-ROUTE
---------------------------------********
********---------------------------------- TO-TAG DONE
----------------------------------********
********-------------------------------- ROUTE(2) DONE
--------------------------------********
********---------------------------------- ROUTE(1)
------------------------------------********
********---------------------------------- T_RELAY
-------------------------------------********
[PRACK] INCOMING-REPLY[2] (RURI=[sip:S001e310003ee@192.168.1.100:5060] F=[
sip:S000413292efd@abcd.com <sip%3AS000413292efd(a)abcd.com>]
T=[sip:0870000005*47942@abcd.com;user=phone] IP=[192.168.2.174]
ID=[3c268b5bbf2d-mtnq42l2osup])
[PRACK] INCOMING-REPLY[2] DLG_TIMEOUT=[43199] (RURI=[
sip:S001e310003ee@192.168.1.100:5060]
F=[sip:S000413292efd@abcd.com<sip%3AS000413292efd@abcd.com>]
T=[sip:0870000005*47942@abcd.com;user=phone] IP=[192.168.2.174]
ID=[3c268b5bbf2d-mtnq42l2osup])
Jan 30 11:31:42 [11258] INFO:dialog:dlg_onreply: dlg_onreply called
statistics: [tm_rld_rpls] : [1]
Jan 30 11:31:42 [11258] INFO:dialog:dlg_onreply: dlg_onreply called
Jan 30 11:31:42 [11258] INFO:dialog:dlg_onreply: new_state =
DLG_STATE_EARLY.
statistics: [rcv_reqs] : [1]
*******---------------------------------- ROUTE(2)
-----------------------------------********
********------------------------------------ TO-TAG
-------------------------------------********
********---------------------------------- LOOSE-ROUTE
---------------------------------********
********---------------------------------- TO-TAG DONE
----------------------------------********
********-------------------------------- ROUTE(2) DONE
--------------------------------********
********---------------------------------- ROUTE(1)
------------------------------------********
********---------------------------------- T_RELAY
-------------------------------------********
[PRACK] INCOMING-REPLY[2] (RURI=[sip:S001e310003ee@192.168.1.100:5060] F=[
sip:S000413292efd@abcd.com <sip%3AS000413292efd(a)abcd.com>]
T=[sip:0870000005*47942@abcd.com;user=phone] IP=[192.168.2.174]
ID=[3c268b5bbf2d-mtnq42l2osup])
[PRACK] INCOMING-REPLY[2] DLG_TIMEOUT=[43199] (RURI=[
sip:S001e310003ee@192.168.1.100:5060]
F=[sip:S000413292efd@abcd.com<sip%3AS000413292efd@abcd.com>]
T=[sip:0870000005*47942@abcd.com;user=phone] IP=[192.168.2.174]
ID=[3c268b5bbf2d-mtnq42l2osup])
Jan 30 11:31:42 [11258] INFO:dialog:dlg_onreply: dlg_onreply called
statistics: [tm_trans_2xx] : [1]
statistics: [tm_rld_rpls] : [1]
Jan 30 11:31:42 [11258] INFO:dialog:dlg_onreply: dlg_onreply called
Jan 30 11:31:42 [11258] INFO:dialog:dlg_onreply:
new_state==DLG_STATE_CONFIRMED_NA && old_state!=DLG_STATE_CONFIRMED_NA &&
old_state!=DLG_STATE_CONFIRMED.
Jan 30 11:31:42 [11258] INFO:dialog:dlg_update_cb:
######################dialog updated##############################
Jan 30 11:31:42 [11258] INFO:dialog:dlg_update_cb: Confirmed DID fbda14b0
session and source ip is [sip:S000413292efd@192.168.2.174:5060] and dst ip
is [sip:S001e310003ee@41.2.192.203:5060] and callid is
[3c268b5bbf2d-mtnq42l2osup]
*******---------------------------------- ROUTE(2)
-----------------------------------********
********------------------------------------ TO-TAG
-------------------------------------********
********---------------------------------- LOOSE-ROUTE
---------------------------------********
********---------------------------------- TO-TAG DONE
----------------------------------********
********-------------------------------- ROUTE(2) DONE
--------------------------------********
********---------------------------------- ROUTE(1)
------------------------------------********
********---------------------------------- T_RELAY
-------------------------------------********
********------------------------------- ROUTE(1) DONE
-----------------------------------********
On 01/30/2009 09:00 AM, Jason Penton wrote:
Hi *,
What is the logic behind the transation matching in Kamailio. I am finding
a problem whereby a call setup transaction (INVITE, 180 Ringing, PRACK,
200OK, ACK). between 2 Snom phones works in normal mode. However, when one
phone is behind a NAT with STUN support, everything works perfectly (i.e.
call setup, 2-way audio, etc), BUT the tm module doesnt match the
transaction between the original invite and the subsequent messages (180,
200ok, etc). the impact here is that the fr_inv_timer eventually fires even
though the call has been answered. Note: this only happens when the call is
destined for the device behind the NAT.
Any ideas.
Perhaps an explanation on how the tm module does transaction manager.
RFC3261 states that transaction matching is done based on the via branch
parameter.
it is the way tm does it. Can you paste the sip trace of such situation? It
will help to troubleshoot.
Cheers,
Daniel
--
Daniel-Constantin Mierla
http://www.asipto.com