Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

[5.2] 200 Ok on Re-invite faces "transaction not found - (branch -1)" when topos module is used #1975

Closed
altanai opened this issue Jun 7, 2019 · 5 comments
Closed

[5.2] 200 Ok on Re-invite faces "transaction not found - (branch -1)" when topos module is used #1975

altanai opened this issue Jun 7, 2019 · 5 comments

Comments

@altanai
Copy link

altanai commented Jun 7, 2019 •
edited

[5.2] 200 Ok on Re-invite faces "transaction not found - (branch -1)" when topos module is used

Description

My setup is UAC --> Kamailio SBC --> External PBX
When external PBX sends 407 Proxy Autehtication required , the kamailio SBC sends another invite with auth header ( uac module ) and updated cseq ( from dialog modules track_cseq_updates ). To this the external PBX replies with 200 OK . However Kamailio SBC drops this 200 ok with "t_reply_matching(): failure to match a transaction" and "reply_received(): transaction not found - (branch -1)".

I am using Lua engine but problem is reproducible even with plain config file based routing configuration

Troubleshooting

Reproduction

Reproducible everytime with uac module working with uac and topos module from v5.1 and above.

Debugging Data

Sample parameters declaration I am using is like

modparam("dialog", "dlg_flag", 4)
modparam("dialog", "track_cseq_updates", 1)

modparam("uac","auth_username_avp","$avp(auser)")
modparam("uac","auth_password_avp","$avp(apass)")
modparam("uac","auth_realm_avp","$avp(arealm)")

modparam("topos", "storage", "redis")
modparam("topos", "sanity_checks", 1)
modparam("topos_redis", "serverid", "sbc")

Log Messages

Pasting some snippets from Kamailio in debug mode 3 ( mangled the ips and values of some private identities)

uac_auth_notworking_with_topos.txt

SIP Traffic

Not sure if the callflow will appear disfigured below. Primarily what it depicts is that 200 ok from External PBX is dropped by Kamailio and hence kamailio tries to resen the auth based invote multiple times till request timeout occurs

|Time     | UAC               					  | Kamailio SBC      | External PBX      |                   
|6.649019 |         INVITE SDP (g711U te          |                   |SIP INVITE From: <sip:8887779996@<uac_address> To:<sip:18077881601@<uac_address> Call-ID:OWY3ZTQ3NGM3NTg0N2U3YmE2MTBiOTIxMTRkOGZmNjM CSeq:1
|         |   ------------------>     |                   |
|6.649538 |         100 trying -- your c          |                   |SIP Status 100 trying -- your call is important to us
|         |   <------------------     |                   |
|6.650087 |                   					  |         INVITE SDP (g711U te          |SIP INVITE From: <sip:8887779996@<uac_address> To:<sip:18077881601@<uac_address> CSeq:1
|         |                   |   ------------------>     |
|6.651861 |                   |         407 Proxy Authentica          |SIP Status 407 Proxy Authentication Required
|         |                   |   <------------------     |
|6.652194 |                   |         ACK       |                   |SIP ACK From: <sip:8887779996@<uac_address> To:<sip:18077881601@<uac_address> CSeq:1
|         |                   |   ------------------>     |
|6.653097 |                   |         INVITE SDP (g711U te          |SIP INVITE From: <sip:8887779996@<uac_address> To:<sip:18077881601@<uac_address> CSeq:2
|         |                   |   ------------------>     |
|6.673088 |                   |         100 Trying|                   |SIP Status 100 Trying
|         |                   |   <------------------     |
|6.676293 |                   |         200 OK SDP (g711U te          |SIP Status 200 OK
|         |                   |   <------------------     |
|7.109339 |                   |         INVITE SDP (g711U te          |SIP INVITE From: <sip:8887779996@<uac_address> To:<sip:18077881601@<uac_address> CSeq:2
|         |                   |   ------------------>     |
|7.110230 |                   |         200 OK SDP (g711U te          |SIP Status 200 OK
|         |                   |   <------------------     |
|7.176010 |                   |         200 OK SDP (g711U te          |SIP Status 200 OK
|         |                   |   <------------------     |
|8.109281 |                   |         INVITE SDP (g711U te          |SIP INVITE From: <sip:8887779996@<uac_address> To:<sip:18077881601@<uac_address> CSeq:2
|         |                   |   ------------------>     |
|8.110154 |                   |         200 OK SDP (g711U te          |SIP Status 200 OK
|         |                   |   <------------------     |
|8.176005 |                   |         200 OK SDP (g711U te          |SIP Status 200 OK
|         |                   |   <------------------     |

Possible Solutions

By monitoring redis, I can see that compacting headers by topos and tps storage C file on redis is only happening for the branch id of the first invite , such as

"HMSET" "b:x:z9hG4bK68dc.5ad386873790061ba2a8f1d254ec3300.0" "rectime" "1559887868" "a_callid" "OWY3ZTQ3NGM3NTg0N2U3YmE2MTBiOTIxMTRkOGZmNjM" "a_uuid" "atpsh-5cf9fea7-123a-1" "b_uuid" "btpsh-5cf9fea7-123a-1" "direction" "0" "x_via" "SIP/2.0/TCP <uac_pvt_address>:9364;received=<uac_pub_address>;branch=z9hG4bK-d8754z-e7184457335bac6a-1---d8754z-;rport=29567" "x_vbranch" "z9hG4bK68dc.5ad386873790061ba2a8f1d254ec3300.0" "s_rr" "<sip:<kamailio_pub_address>:5060;r2=on;lr;ftag=e0090423;did=508.39e1;nat=yes>,<sip:<kamailio_pub_address>;transport=tcp;r2=on;lr;ftag=e0090423;did=f4d.fe9;nat=yes>" "x_tag" "45a56f2c" "s_method" "INVITE" "s_cseq" "1" "a_contact" "sip:6666666666@<uac_pvt_address>:9364;transport=tcp;alias=<uac_pub_address>~29567~2" "as_contact" "<sip:atpsh-5cf9fea7-123a-1@<kamailio_pub_address>;transport=tcp>" "bs_contact" "<sip:btpsh-5cf9fea7-123a-1@<kamailio_pub_address>:5060>" "a_tag" "45a56f2c"

But when the 200 ok for re-invite comes back after authentication, the topos module tries to extract the records for new branch cseq such as
"HGETALL" "b:x:5ad386873790061ba2a8f1d254ec3300.1.cs1"
which is obviously not set and hence not fetched resulting in transaction not matched error and 200 ok being dropped.

If topos storage can HMSET for newer branch id as they are created, I presumme it should fix things up and matching transactions will be ok

Additional Information

  • Kamailio Version - output of kamailio -v
version: kamailio 5.1.8 (x86_64/linux) 5534c0
flags: STATS: Off, USE_TCP, USE_TLS, USE_SCTP, TLS_HOOKS, USE_RAW_SOCKS, DISABLE_NAGLE, USE_MCAST, DNS_IP_HACK, SHM_MEM, SHM_MMAP, PKG_MALLOC, Q_MALLOC, F_MALLOC, TLSF_MALLOC, DBG_SR_MEMORY, USE_FUTEX, FAST_LOCK-ADAPTIVE_WAIT, USE_DNS_CACHE, USE_DNS_FAILOVER, USE_NAPTR, USE_DST_BLACKLIST, HAVE_RESOLV_RES
ADAPTIVE_WAIT_LOOPS=1024, MAX_RECV_BUFFER_SIZE 262144 MAX_URI_SIZE 1024, BUF_SIZE 65535, DEFAULT PKG_SIZE 8MB
poll method support: poll, epoll_lt, epoll_et, sigio_rt, select.
id: 5534c0 
compiled on 09:32:39 Jun  7 2019 with gcc 4.8.4
  • Operating System:
My OS is 
Distributor ID:	Ubuntu
Description:	Ubuntu 14.04.5 LTS
Release:	14.04
Codename:	trusty
```[](url)
@altanai
Copy link
Author

altanai commented Jun 7, 2019

I have gone through #1496 and #1038 , but the issue persists

@miconda
Copy link
Member

miconda commented Jun 7, 2019

Can you get all log messages printed with debug=3 in kamailio.cfg from the moment of receiving the INVITE till finishing the processing of the 200ok?

@altanai
Copy link
Author

altanai commented Jun 7, 2019

Sure here they are
sbc_auth.txt

and the associated redis creating keys
redis_auth_sbc.txt

( ips and creds hidden )
please search for "t_reply_matching(): failure to match a transaction" after 200 OK to see the issue I am pointing at

@altanai
Copy link
Author

altanai commented Jun 10, 2019

Self fixed the problem by rearranging the order of module imports between dialog , uac, topos and topos_redis. Perhaps the same could be mentioned in developer doc somewhere . closing this for now

@altanai altanai closed this as completed Jun 10, 2019
@henningw
Copy link
Contributor

@altanai this can be added to the docs if you give some hints about the non-working and working order of modules . :-)

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
3 participants
@miconda @altanai @henningw