<p>My websocket TLS server is full of these kinds of messages:</p>
<pre><code>Jan 18 18:10:26 ws0 /usr/sbin/kamailio[19701]: NOTICE: <script>:
http:217.120.x.x:55386: WS connection closed
...
Jan 18 18:10:26 ws0 /usr/sbin/kamailio[19689]: WARNING: <core>
[msg_translator.c:2506]: via_builder(): TCP/TLS connection (id: 0) for WebSocket could not be found
Jan 18 18:10:26 ws0 /usr/sbin/kamailio[19689]: ERROR: <core>
[msg_translator.c:1722]: build_req_buf_from_sip_req(): could not create Via header
Jan 18 18:10:26 ws0 /usr/sbin/kamailio[19689]: ERROR: tm
[t_fwd.c:527]: prepare_new_uac(): could not build request
Jan 18 18:10:26 ws0 /usr/sbin/kamailio[19689]: ERROR: tm
[t_fwd.c:1773]: t_forward_nonack(): ERROR: t_forward_nonack: failure to add branches
Jan 18 18:10:26 ws0 /usr/sbin/kamailio[19689]: ERROR: sl
[sl_funcs.c:387]: sl_reply_error(): ERROR: sl_reply_error used: No error (2/SL)
(repeat these last errors for a bunch of attempted NOTIFY forwards)
</code></pre>
<p>The route block does basically something like this:</p>
<pre><code> # add_contact_alias(); # only for requests from the outside
loose_route();
if (!t_relay()) {
sl_reply_error();
}
</code></pre>
<p>The problem arises here:</p>
<pre><code>}else if (send_info->proto==PROTO_WS){
...
con = tcpconn_get(send_info->id, &ip, port, from, 0)
...
if (con == NULL) {
LM_WARN("TCP/TLS connection (id: %d) for WebSocket could not be found\n", send_info->id);
</code></pre>
<p>The NULL failure status gets returned up to <code>prepare_new_uac</code> in <code>t_fwd.c</code>:</p>
<pre><code> shbuf=build_req_buf_from_sip_req( i_req, &len, dst, BUILD_IN_SHM);
if (!shbuf) {
LM_ERR("could not build request\n");
ret=E_OUT_OF_MEM;
goto error01;
}
</code></pre>
<p>At this point, ser_error will become <code>E_OUT_OF_MEM</code> while it should be something like <code>E_SEND</code>.</p>
<p>And <code>E_OUT_OF_MEM</code> gets translated to <code>500 No Error</code> because we're not running in DEBUG mode.</p>
<p>What causes the connection to drop in the first place, you ask?</p>
<pre><code>18:10:18.690738 IP 217.120.x.x.55386 > 195.35.x.x.443: Flags [S], seq 1323983240, win 8192, options [mss 1460,nop,wscale 8,nop,nop,sackOK], length 0
18:10:18.690863 IP 195.35.x.x.443 > 217.120.x.x.55386: Flags [S.], seq 4077761781, ack 1323983241, win 14600, options [mss 1460,nop,nop,sackOK,nop,wscale 3], length 0
18:10:18.710846 IP 217.120.x.x.55386 > 195.35.x.x.443: Flags [.], ack 1, win 256, length 0
18:10:18.808751 IP 217.120.x.x.55386 > 195.35.x.x.443: Flags [P.], seq 1:246, ack 1, win 256, length 245
...
18:10:19.233415 IP 195.35.x.x.443 > 217.120.x.x.55386: Flags [.], ack 31348, win 5126, length 0
18:10:26.489764 IP 217.120.x.x.55386 > 195.35.x.x.443: Flags [P.], seq 31348:32473, ack 34578, win 255, length 1125
...
18:10:26.501409 IP 195.35.x.x.443 > 217.120.x.x.55386: Flags [P.], seq 42255:42916, ack 46010, win 5046, length 661
18:10:26.527755 IP 217.120.x.x.55386 > 195.35.x.x.443: Flags [.], ack 36993, win 252, length 0
18:10:26.527860 IP 195.35.x.x.443 > 217.120.x.x.55386: Flags [.], seq 42916:47296, ack 46010, win 5278, length 4380
18:10:26.527888 IP 195.35.x.x.443 > 217.120.x.x.55386: Flags [FP.], seq 47296:48663, ack 46010, win 5278, length 1367
18:10:26.529179 IP 217.120.x.x.55386 > 195.35.x.x.443: Flags [.], ack 40501, win 254, length 0
18:10:26.529200 IP 217.120.x.x.55386 > 195.35.x.x.443: Flags [.], ack 42916, win 251, length 0
18:10:26.547276 IP 217.120.x.x.55386 > 195.35.x.x.443: Flags [.], ack 48664, win 251, length 0
18:10:26.549712 IP 217.120.x.x.55386 > 195.35.x.x.443: Flags [F.], seq 46010, ack 48664, win 251, length 0
18:10:26.549750 IP 195.35.x.x.443 > 217.120.x.x.55386: Flags [.], ack 46011, win 5278, length 0
</code></pre>
<p>Where you see that the FIN is initiated by <code>195.35.x.x</code> which is the Kamailio websocket server.</p>
<p>The cause (probably) is the WS client closing the connection. In this case after re-subscribing with Expires:0. The presence server attempts to reply with a bunch of NOTIFYs with <code>Subscription-State: terminated;reason=timeout</code> but they bounce on the broken connection. If Kamailio would return a nice "477 Unfortunately error on sending to next hop occurred" it'd be prettier.</p>
<p>Getting less "error" messages (a total of 6 <em>per</em> expired/unsubscribed subscription) after this error --which is apparently very common -- would be beneficial too.</p>
<p>As for fixing:</p>
<ul class="task-list">
<li>We could change the <code>via_builder</code> to set <code>ser_error</code> (and check that in <code>build_req_buf_from_sip_req</code>), or</li>
<li>add error-code-out-parameters to all calls from <code>build_req_buf_from_sip_req</code> and down.
I'm not sure if either is the best way.</li>
</ul>
<p>As for the excessive error reporting, would looking at <code>ser_error</code> before printing (another) error be an acceptable fix?</p>
<p>Cheers,<br>
Walter Doekes<br>
OSSO B.V.</p>
<p style="font-size:small;-webkit-text-size-adjust:none;color:#666;">—<br>Reply to this email directly or <a href="https://github.com/kamailio/kamailio/issues/47">view it on GitHub</a>.<img alt="" height="1" src="https://github.com/notifications/beacon/AF36ZR5Ccj--_dJum3iAi8pJkTUVlg32ks5njP-WgaJpZM4DUJGs.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/47"></link>
<meta itemprop="name" content="View Issue"></meta>
</div>
<meta itemprop="description" content="View this Issue on GitHub"></meta>
</div>