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.

Sign up for GitHub

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

[uac.reg_keep_callid] attempts to refresh registration reusing Call-ID fail with timeout #931

Closed
petercolberg opened this issue Jan 16, 2017 · 2 comments
Closed

[uac.reg_keep_callid] attempts to refresh registration reusing Call-ID fail with timeout #931

petercolberg opened this issue Jan 16, 2017 · 2 comments

Comments

@petercolberg
Copy link

I am testing commit 1dc6da8 compiled from source on Debian unstable/amd64.

When the parameter uac.reg_keep_callid is enabled to refresh registrations reusing the same Call-Id, attempts to update the registration fail with a timeout [uac_reg_tm_callback(): got sip response 408 while registering], which causes kamailio to subsequently register (successfully) using a new Call-Id.

This is the first registration after starting kamilio. Note how the From: header contains a tag=.

U 2017/01/15 18:57:18.338380 1.2.3.4:5060 -> 5.6.7.8:5060
REGISTER sip:sip.example.org SIP/2.0.
Via: SIP/2.0/UDP 1.2.3.4;branch=z9hG4bKc4d5.b35f6627000000000000000000000000.0.
To: <sip:11111111@sip.example.org>.
From: <sip:11111111@sip.example.org>;tag=533cb9e91f4b999cf76861cbb9ed54ed-48c9.
CSeq: 10 REGISTER.
Call-ID: 705a8b605d872669-5747@127.0.0.1.
Max-Forwards: 70.
Content-Length: 0.
User-Agent: kamailio (5.0.0-pre0 (x86_64/linux)).
Contact: <sip:12345678@1.2.3.4:5060>.
Expires: 600.

U 2017/01/15 18:57:18.436734 5.6.7.8:5060 -> 1.2.3.4:5060
SIP/2.0 401 Unauthorized.
Via: SIP/2.0/UDP 1.2.3.4;branch=z9hG4bKc4d5.b35f6627000000000000000000000000.0;received=1.2.3.4;rport=5060.
From: <sip:11111111@sip.example.org>;tag=533cb9e91f4b999cf76861cbb9ed54ed-48c9.
To: <sip:11111111@sip.example.org>;tag=as4c52c89f.
Call-ID: 705a8b605d872669-5747@127.0.0.1.
CSeq: 10 REGISTER.
Server: example.org.
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE.
Supported: replaces, timer.
WWW-Authenticate: Digest algorithm=MD5, realm="sip.example.org", nonce="7cdc4b7e".
Content-Length: 0.

U 2017/01/15 18:57:18.438460 1.2.3.4:5060 -> 5.6.7.8:5060
REGISTER sip:sip.example.org SIP/2.0.
Via: SIP/2.0/UDP 1.2.3.4;branch=z9hG4bKd4d5.73d1add4000000000000000000000000.0.
To: <sip:11111111@sip.example.org>.
From: <sip:11111111@sip.example.org>;tag=533cb9e91f4b999cf76861cbb9ed54ed-48c9.
CSeq: 11 REGISTER.
Call-ID: 705a8b605d872669-5747@127.0.0.1.
Max-Forwards: 70.
Content-Length: 0.
User-Agent: kamailio (5.0.0-pre0 (x86_64/linux)).
Contact: <sip:12345678@1.2.3.4:5060>.
Expires: 600.
Authorization: Digest username="11111111", realm="sip.example.org", nonce="7cdc4b7e", uri="sip:sip.example.org", response="30f31eaf139730e8f54e043a53ddbc1e", algorithm=MD5.

U 2017/01/15 18:57:18.537370 5.6.7.8:5060 -> 1.2.3.4:5060
SIP/2.0 200 OK.
Via: SIP/2.0/UDP 1.2.3.4;branch=z9hG4bKd4d5.73d1add4000000000000000000000000.0;received=1.2.3.4;rport=5060.
From: <sip:11111111@sip.example.org>;tag=533cb9e91f4b999cf76861cbb9ed54ed-48c9.
To: <sip:11111111@sip.example.org>;tag=as4c52c89f.
Call-ID: 705a8b605d872669-5747@127.0.0.1.
CSeq: 11 REGISTER.
Server: example.org.
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE.
Supported: replaces, timer.
Expires: 600.
Contact: <sip:12345678@1.2.3.4:5060>;expires=600.
Date: Sun, 15 Jan 2017 23:57:18 GMT.
Content-Length: 0.

After 9 minutes (or 1 minute before expiry), kamilio attempts to update the registration, sending out 10 requests of which none is answered by the upstream provider. Note how the From: header is missing the above tag=. I suspect that the incomplete From: is the reason the upstream provider is not answering.

U 2017/01/15 19:06:18.850555 1.2.3.4:5060 -> 5.6.7.8:5060
REGISTER sip:sip.example.org SIP/2.0.
Via: SIP/2.0/UDP 1.2.3.4;branch=z9hG4bKa4d5.c4f157d1000000000000000000000000.0.
To: <sip:11111111@sip.example.org>.
From: <sip:11111111@sip.example.org>.
CSeq: 12 REGISTER.
Call-ID: 705a8b605d872669-5747@127.0.0.1.
Max-Forwards: 70.
Content-Length: 0.
User-Agent: kamailio (5.0.0-pre0 (x86_64/linux)).
Contact: <sip:12345678@1.2.3.4:5060>.
Expires: 600.

U 2017/01/15 19:06:19.313086 1.2.3.4:5060 -> 5.6.7.8:5060
REGISTER sip:sip.example.org SIP/2.0.
Same headers as above.

U 2017/01/15 19:06:20.312741 1.2.3.4:5060 -> 5.6.7.8:5060
REGISTER sip:sip.example.org SIP/2.0.
Same headers as above.

U 2017/01/15 19:06:22.312706 1.2.3.4:5060 -> 5.6.7.8:5060
REGISTER sip:sip.example.org SIP/2.0.
Same headers as above.

U 2017/01/15 19:06:26.312796 1.2.3.4:5060 -> 5.6.7.8:5060
REGISTER sip:sip.example.org SIP/2.0.
Same headers as above.

U 2017/01/15 19:06:30.312725 1.2.3.4:5060 -> 5.6.7.8:5060
REGISTER sip:sip.example.org SIP/2.0.
Same headers as above.

U 2017/01/15 19:06:34.312725 1.2.3.4:5060 -> 5.6.7.8:5060
REGISTER sip:sip.example.org SIP/2.0.
Same headers as above.

U 2017/01/15 19:06:38.312711 1.2.3.4:5060 -> 5.6.7.8:5060
REGISTER sip:sip.example.org SIP/2.0.
Same headers as above.

U 2017/01/15 19:06:42.312710 1.2.3.4:5060 -> 5.6.7.8:5060
REGISTER sip:sip.example.org SIP/2.0.
Same headers as above.

U 2017/01/15 19:06:46.312701 1.2.3.4:5060 -> 5.6.7.8:5060
REGISTER sip:sip.example.org SIP/2.0.
Same headers as above.

Each registration attempt coincides with a log entry by the dialog module:

Jan 15 19:06:18 ERROR: dialog [dlg_handlers.c:676]: pre_match_parse(): failed to get From header
Jan 15 19:06:19 ERROR: dialog [dlg_handlers.c:676]: pre_match_parse(): failed to get From header
Jan 15 19:06:20 ERROR: dialog [dlg_handlers.c:676]: pre_match_parse(): failed to get From header
Jan 15 19:06:22 ERROR: dialog [dlg_handlers.c:676]: pre_match_parse(): failed to get From header
Jan 15 19:06:26 ERROR: dialog [dlg_handlers.c:676]: pre_match_parse(): failed to get From header
Jan 15 19:06:30 ERROR: dialog [dlg_handlers.c:676]: pre_match_parse(): failed to get From header
Jan 15 19:06:34 ERROR: dialog [dlg_handlers.c:676]: pre_match_parse(): failed to get From header
Jan 15 19:06:38 ERROR: dialog [dlg_handlers.c:676]: pre_match_parse(): failed to get From header
Jan 15 19:06:42 ERROR: dialog [dlg_handlers.c:676]: pre_match_parse(): failed to get From header
Jan 15 19:06:46 ERROR: dialog [dlg_handlers.c:676]: pre_match_parse(): failed to get From header
Jan 15 19:06:48 ERROR: uac [uac_reg.c:1031]: uac_reg_tm_callback(): got sip response 408 while registering [12345678]

After a minute kamilio successfully registers using a new Call-id and a From: with tag=.

U 2017/01/15 19:07:18.977094 1.2.3.4:5060 -> 5.6.7.8:5060
REGISTER sip:sip.example.org SIP/2.0.
Via: SIP/2.0/UDP 1.2.3.4;branch=z9hG4bKbfc5.0afdd3d1000000000000000000000000.0.
To: <sip:11111111@sip.example.org>.
From: <sip:11111111@sip.example.org>;tag=533cb9e91f4b999cf76861cbb9ed54ed-acbf.
CSeq: 10 REGISTER.
Call-ID: 705a8b605d87266a-5747@127.0.0.1.
Max-Forwards: 70.
Content-Length: 0.
User-Agent: kamailio (5.0.0-pre0 (x86_64/linux)).
Contact: <sip:12345678@1.2.3.4:5060>.
Expires: 600.

U 2017/01/15 19:07:19.075665 5.6.7.8:5060 -> 1.2.3.4:5060
SIP/2.0 401 Unauthorized.
Via: SIP/2.0/UDP 1.2.3.4;branch=z9hG4bKbfc5.0afdd3d1000000000000000000000000.0;received=1.2.3.4;rport=5060.
From: <sip:11111111@sip.example.org>;tag=533cb9e91f4b999cf76861cbb9ed54ed-acbf.
To: <sip:11111111@sip.example.org>;tag=as76317b94.
Call-ID: 705a8b605d87266a-5747@127.0.0.1.
CSeq: 10 REGISTER.
Server: example.org.
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE.
Supported: replaces, timer.
WWW-Authenticate: Digest algorithm=MD5, realm="sip.example.org", nonce="3e3a497f".
Content-Length: 0.

U 2017/01/15 19:07:19.077029 1.2.3.4:5060 -> 5.6.7.8:5060
REGISTER sip:sip.example.org SIP/2.0.
Via: SIP/2.0/UDP 1.2.3.4;branch=z9hG4bKcfc5.78f00452000000000000000000000000.0.
To: <sip:11111111@sip.example.org>.
From: <sip:11111111@sip.example.org>;tag=533cb9e91f4b999cf76861cbb9ed54ed-acbf.
CSeq: 11 REGISTER.
Call-ID: 705a8b605d87266a-5747@127.0.0.1.
Max-Forwards: 70.
Content-Length: 0.
User-Agent: kamailio (5.0.0-pre0 (x86_64/linux)).
Contact: <sip:12345678@1.2.3.4:5060>.
Expires: 600.
Authorization: Digest username="11111111", realm="sip.example.org", nonce="3e3a497f", uri="sip:sip.example.org", response="21534c252e323cd1da8b44d5d8830743", algorithm=MD5.

U 2017/01/15 19:07:19.176499 5.6.7.8:5060 -> 1.2.3.4:5060
SIP/2.0 200 OK.
Via: SIP/2.0/UDP 1.2.3.4;branch=z9hG4bKcfc5.78f00452000000000000000000000000.0;received=1.2.3.4;rport=5060.
From: <sip:11111111@sip.example.org>;tag=533cb9e91f4b999cf76861cbb9ed54ed-acbf.
To: <sip:11111111@sip.example.org>;tag=as76317b94.
Call-ID: 705a8b605d87266a-5747@127.0.0.1.
CSeq: 11 REGISTER.
Server: example.org.
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE.
Supported: replaces, timer.
Expires: 600.
Contact: <sip:12345678@1.2.3.4:5060>;expires=600.
Date: Mon, 16 Jan 2017 00:07:19 GMT.
Content-Length: 0.

/etc/kamailio/kamailio.cfg

#!KAMAILIO

debug=3

loadmodule "kex.so"
loadmodule "corex.so"
loadmodule "tm.so"
loadmodule "tmx.so"
loadmodule "sl.so"
loadmodule "rr.so"
loadmodule "pv.so"
loadmodule "db_text.so"
loadmodule "dialog.so"
loadmodule "uac.so"

#!define DBURL "text:///etc/kamailio/dbtext"

modparam("rr", "append_fromtag", 1)
modparam("dialog", "dlg_flag", 4)
modparam("dialog", "track_cseq_updates", 1)
modparam("uac", "restore_dlg", 1)
modparam("uac", "reg_db_url", DBURL)
modparam("uac", "reg_timer_interval", 60)
modparam("uac", "reg_retry_interval", 60)
modparam("uac", "reg_contact_addr", "1.2.3.4:5060")
modparam("uac", "reg_keep_callid", 1)

request_route {
	exit;
}

/etc/kamailio/dbtext/uacreg

l_uuid(string) l_username(string) l_domain(string) r_username(string) r_domain(string) realm(string) auth_username(string) auth_password(string) auth_proxy(string) expires(int) flags(int) reg_delay(int) 
12345678:user:domain.local:11111111:sip.example.org:sip.example.org:11111111:XXXXXXXXXXXXXXXX:sip\:sip.example.org:600:0:0
miconda added a commit that referenced this issue Jan 17, 2017
@miconda
tm: generate from tag if not provided for request_within()
96ca5c9 
- related to GH #931
@miconda
Copy link
Member

miconda commented Jan 17, 2017

I just pushed a patch in tm to catch the situations when the modules don't provide a From tag when aiming at a request within a dialog. Can you pull the latest master and test?

miconda added a commit that referenced this issue Jan 17, 2017
@miconda
tm: generate from tag if not provided for request_within()
6dd3f8c 
- related to GH #931

(cherry picked from commit 96ca5c9)
@petercolberg
Copy link
Author

Thank you very much, commit 96ca5c9 works perfectly.

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
2 participants
@miconda @petercolberg