<p>I am testing commit <a href="https://github.com/kamailio/kamailio/commit/1dc6da87180a01f21554f2e857ec280814ba05e5" class="commit-link"><tt>1dc6da8</tt></a> compiled from source on Debian unstable/amd64.</p>
<p>When the parameter <a href="http://www.kamailio.org/docs/modules/devel/modules/uac.html#uac.p.reg-keep-callid">uac.reg_keep_callid</a> is enabled to refresh registrations reusing the same Call-Id, attempts to update the registration fail with a timeout [<code>uac_reg_tm_callback(): got sip response 408 while registering</code>], which causes kamailio to subsequently register (successfully) using a new Call-Id.</p>
<p>This is the first registration after starting kamilio. Note how the <code>From:</code> header contains a <code>tag=</code>.</p>
<pre><code>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.
</code></pre>
<p>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 <code>From:</code> header is missing the above <code>tag=</code>. I suspect that the incomplete <code>From:</code> is the reason the upstream provider is not answering.</p>
<pre><code>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.
</code></pre>
<p>Each registration attempt coincides with a log entry by the dialog module:</p>
<pre><code>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]
</code></pre>
<p>After a minute kamilio successfully registers using a new Call-id and a <code>From:</code> with <code>tag=</code>.</p>
<pre><code>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.
</code></pre>
<p><code>/etc/kamailio/kamailio.cfg</code></p>
<pre><code>#!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;
}
</code></pre>
<p><code>/etc/kamailio/dbtext/uacreg</code></p>
<pre><code>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
</code></pre>

<p style="font-size:small;-webkit-text-size-adjust:none;color:#666;">—<br />You are receiving this because you are subscribed to this thread.<br />Reply to this email directly, <a href="https://github.com/kamailio/kamailio/issues/931">view it on GitHub</a>, or <a href="https://github.com/notifications/unsubscribe-auth/AF36ZZT8GSuWFKYYFbxNbfh5_umpBTp1ks5rSskSgaJpZM4LkGiY">mute the thread</a>.<img alt="" height="1" src="https://github.com/notifications/beacon/AF36ZUzvGX6wLwM5rBISf_-5dX0zSQogks5rSskSgaJpZM4LkGiY.gif" width="1" /></p>
<div itemscope itemtype="http://schema.org/EmailMessage">
<div itemprop="action" itemscope itemtype="http://schema.org/ViewAction">
  <link itemprop="url" href="https://github.com/kamailio/kamailio/issues/931"></link>
  <meta itemprop="name" content="View Issue"></meta>
</div>
<meta itemprop="description" content="View this Issue on GitHub"></meta>
</div>

<script type="application/json" data-scope="inboxmarkup">{"api_version":"1.0","publisher":{"api_key":"05dde50f1d1a384dd78767c55493e4bb","name":"GitHub"},"entity":{"external_key":"github/kamailio/kamailio","title":"kamailio/kamailio","subtitle":"GitHub repository","main_image_url":"https://cloud.githubusercontent.com/assets/143418/17495839/a5054eac-5d88-11e6-95fc-7290892c7bb5.png","avatar_image_url":"https://cloud.githubusercontent.com/assets/143418/15842166/7c72db34-2c0b-11e6-9aed-b52498112777.png","action":{"name":"Open in GitHub","url":"https://github.com/kamailio/kamailio"}},"updates":{"snippets":[{"icon":"DESCRIPTION","message":"[uac.reg_keep_callid] attempts to refresh registration reusing Call-ID fail with timeout (#931)"}],"action":{"name":"View Issue","url":"https://github.com/kamailio/kamailio/issues/931"}}}</script>