29 Oct
2020
29 Oct
'20
10:37 p.m.
Sorry to have missed your other question:
The “resource temporarily unavailable” is a normal occurrence in a nonblocking connect(),
and nothing to worry about.
Unless the socket literally connects instantaneously, EAGAIN is what it’ll throw out when
polled until connection is established.
—
Sent from mobile, with due apologies for brevity and errors.
On Oct 29, 2020, at 3:27 PM, Alex Balashov
<abalashov(a)evaristesys.com> wrote:
Internally generated requests are a little quirky in that they’re generated by outside
timer processes or tasks in core timers — activity that takes place outside the SIP worker
pool. However, the expectation is that any replies will be processed (in this case,
absorbed) by the SIP workers.
Asymmetric signalling is permitted in SIP, so sending from source port X while specifying
a return port of Y in the top Via hop is perfectly acceptable.
— Alex
—
Sent from mobile, with due apologies for brevity and errors.
>> On Oct 29, 2020, at 3:21 PM, Noah Mehl <noahmehl(a)gmail.com> wrote:
>>
> Hey all,
>
> I’m a little stuck on an implementation of a set of dispatchers via TCP. There are
some oddities about the behavior of the TCP source port of the Kamailio tcp worker/s, and
maybe this is expected, but it doesn’t seem valid. For instance, I have a dispatcher:
>
> "RECORDS": [{
> "SET": {
> "ID": 1,
> "TARGETS": [{
> "DEST": {
> "URI": “sip:2.2.2.2:5060;transport=tcp",
> "FLAGS": "AP",
> "PRIORITY": 5
> }
> }]
> }
> }]
>
> But when Kamailio sends an OPTIONS keep alive, the source port for the worker is
33940, and not 5060 (which is the TCP listen port), as received by Freeswitch:
>
> recv 447 bytes from tcp/[1.1.1.1]:33940 at 18:58:24.958720:
> ------------------------------------------------------------------------
> OPTIONS sip:2.2.2.2:5060;transport=tcp SIP/2.0
> Via: SIP/2.0/TCP 1.1.1.1;branch=z9hG4bK1525.80a9e442000000000000000000000000.0
> To: <sip:2.2.2.2:5060;transport=tcp>
> From:
<sip:inbound-kamailio-01>;tag=3c52ba62ee4c4621b9660728159919d3-cda8066f
> CSeq: 10 OPTIONS
> Call-ID: 3aa18693487268dc-2790(a)1.1.1.1
> Max-Forwards: 70
> Content-Length: 0
> User-Agent: kamailio (5.4.2 (x86_64/linux))
>
> ------------------------------------------------------------------------
>
> Also, I get weird debug messages when this tcp worker is spun up (specifically about
Resource temporarily unavailable):
>
> 11(2790) DEBUG: dispatcher [dispatch.c:3340]: ds_ping_result_helper(): probe all,
mode DS_PROBE_ALL
> 11(2790) DEBUG: dispatcher [dispatch.c:3383]: ds_ping_set(): probing set #1, URI
sip:2.2.2.2:5060;transport=tcp
> 11(2790) DEBUG: dispatcher [dispatch.c:3414]: ds_ping_set(): Default ping_from:
sip:inbound-kamailio-01
> 11(2790) DEBUG: dispatcher [dispatch.c:3424]: ds_ping_set(): Default outbound proxy:
> 11(2790) DEBUG: tm [uac.c:450]: t_uac_prepare():
next_hop=<sip:2.2.2.2:5060;transport=tcp>
> 11(2790) DEBUG: tm [uac.c:158]: dlg2hash(): hashid 21073
> 11(2790) DEBUG: <core> [core/tcp_main.c:1993]: tcp_send(): no open tcp
connection found, opening new one
> 11(2790) DEBUG: <core> [core/ip_addr.c:229]: print_ip(): tcpconn_new: new tcp
connection: 2.2.2.2
> 11(2790) DEBUG: <core> [core/tcp_main.c:1175]: tcpconn_new(): on port 5060,
type 2, socket -1
> 11(2790) DEBUG: <core> [core/tcp_main.c:1494]: tcpconn_add(): hashes: 2712:0:0,
1
> 11(2790) DEBUG: <core> [core/tcp_main.c:2886]: tcpconn_1st_send(): pending
write on new connection 0x7f24e64c1e18 sock 8 (-1/447 bytes written) (err: 11 - Resource
temporarily unavailable)
> 11(2790) DEBUG: tm [uac.c:678]: send_prepared_request_impl(): uac: 0x7f24e65285a8
branch: 0 to 2.2.2.2:5060
> 11(2790) DEBUG: <core> [core/onsend.c:50]: run_onsend(): required parameters
are not available - ignoring
> 27(2806) DEBUG: <core> [core/tcp_main.c:3792]: handle_ser_child(): read
response= 7f24e64c1e18, 5, fd 46 from 11 (2790)
> 27(2806) DEBUG: <core> [core/io_wait.h:375]: io_watch_add(): DBG:
io_watch_add(0x56490f0f8060, 46, 2, 0x7f24e64c1e18), fd_no=37
> 27(2806) DEBUG: <core> [core/io_wait.h:782]: io_watch_chg(): DBG: io_watch_chg
(0x56490f0f8060, 46, 0x1, 0xffffffff) fd_no=38 called
> 27(2806) DEBUG: <core> [core/io_wait.h:600]: io_watch_del(): DBG: io_watch_del
(0x56490f0f8060, 46, -1, 0x0) fd_no=38 called
> 27(2806) DEBUG: <core> [core/tcp_main.c:4457]: handle_tcpconn_ev(): sending to
child, events 1
> 27(2806) DEBUG: <core> [core/tcp_main.c:4127]: send2child(): selected tcp
worker idx:0 proc:19 pid:2798 for activity on [tcp:1.1.1.1:5060], 0x7f24e64c1e18
> 19(2798) DEBUG: <core> [core/tcp_read.c:1749]: handle_io(): received n=8
con=0x7f24e64c1e18, fd=8
> 19(2798) DEBUG: <core> [core/tcp_read.c:1548]: tcp_read_req():
content-length=0
> 19(2798) DEBUG: <core> [core/parser/msg_parser.c:620]: parse_msg(): SIP Reply
(status):
> 19(2798) DEBUG: <core> [core/parser/msg_parser.c:622]: parse_msg(): version:
<SIP/2.0>
> 19(2798) DEBUG: <core> [core/parser/msg_parser.c:624]: parse_msg(): status:
<200>
> 19(2798) DEBUG: <core> [core/parser/msg_parser.c:626]: parse_msg(): reason:
<OK>
> 19(2798) DEBUG: <core> [core/parser/parse_via.c:1303]: parse_via_param(): Found
param type 232, <branch> = <z9hG4bK1525.80a9e442000000000000000000000000.0>;
state=6
> 19(2798) DEBUG: <core> [core/parser/parse_via.c:1303]: parse_via_param(): Found
param type 235, <rport> = <33940>; state=16
> 19(2798) DEBUG: <core> [core/parser/parse_via.c:2639]: parse_via(): end of
header reached, state=5
> 19(2798) DEBUG: <core> [core/parser/msg_parser.c:498]: parse_headers(): Via
found, flags=2
> 19(2798) DEBUG: <core> [core/parser/msg_parser.c:500]: parse_headers(): this is
the first via
> 19(2798) DEBUG: <core> [core/parser/parse_addr_spec.c:185]: parse_to_param():
add param: tag=1mB9HryQ8ZBFc
> 19(2798) DEBUG: <core> [core/parser/parse_addr_spec.c:864]: parse_addr_spec():
end of header reached, state=29
> 19(2798) DEBUG: <core> [core/parser/msg_parser.c:171]: get_hdr_field():
<To> [59]; uri=[sip:2.2.2.2:5060;transport=tcp]
> 19(2798) DEBUG: <core> [core/parser/msg_parser.c:174]: get_hdr_field(): to body
(39)[<sip:2.2.2.2:5060;transport=tcp>], to tag (13)[1mB9HryQ8ZBFc]
> 19(2798) DEBUG: <core> [core/parser/msg_parser.c:152]: get_hdr_field(): cseq
<CSeq>: <10> <OPTIONS>
> 19(2798) DEBUG: <core> [core/receive.c:319]: receive_msg(): --- received sip
message - reply - call-id: [3aa18693487268dc-2790(a)1.1.1.1] - cseq: [10 OPTIONS]
> 19(2798) DEBUG: <core> [core/parser/msg_parser.c:185]: get_hdr_field():
content_length=0
> 19(2798) DEBUG: <core> [core/parser/msg_parser.c:89]: get_hdr_field(): found
end of header
>
> Are these SIP messages expected to come from other ports than the listen port (5060
in this case)? Also, if the worker source port is not 5060, shouldn’t the SIP message get
updated with the correct port?
>
> In the case of OPTIONS, Freeswitch is replying correctly to the source port: 33940.
>
> However, in the case of an in dialog BYE, Freeswitch is NOT replying to the source
port of the Kamailio messages, but only to port 5060. Here is an example (relayed from
web sockets to freeswitch over TCP) INVITE (as received from Freeswitch):
>
> recv 1481 bytes from tcp/[1.1.1.1]:33940 at 16:56:47.920698:
> ------------------------------------------------------------------------
> INVITE sip:991012@sip.domain.com SIP/2.0
> Record-Route: <sip:1.1.1.1;transport=tcp;r2=on;lr;nat=yes>
> Record-Route: <sip:1.1.1.1:5061;transport=tls;r2=on;lr;nat=yes>
> Via: SIP/2.0/TCP
1.1.1.1;branch=z9hG4bKd408.3f53e940ccb20c1033df4b3a8ebd8a34.0;i=1
> Via: SIP/2.0/TLS
172.22.199.110:55304;received=5.5.5.5;rport=39518;branch=z9hG4bKPj5Css6JomCt9Cli2cCINbXi4FbPM5wewG;alias
> Max-Forwards: 69
> From: "Noah Mehl"
<sip:5135555555@inbound-jail>;tag=s3i3y2tiOCgnUId5TD4Vp0UChf9GyEy9
> To: <sip:991012@inbound-jail>
> Contact:
<sip:74895612@172.22.199.110:54887;transport=tls;alias=5.5.5.5~39518~3>
> Call-ID: 5aoRBMBHahxqSLzrIpFnlfRz.UcGsmfq
> CSeq: 27271 INVITE
> Allow: SUBSCRIBE, NOTIFY, INVITE, ACK, BYE, CANCEL, UPDATE, MESSAGE, REFER
> Supported: replaces, norefersub, gruu
> User-Agent: Blink Pro 4.6.0 (MacOSX)
> Content-Type: application/sdp
> Content-Length: 528
>
> v=0
> o=- 3812979407 3812979407 IN IP4 5.5.5.5
> s=Blink Pro 4.6.0 (MacOSX)
> t=0 0
> m=audio 50016 RTP/SAVP 113 0 101
> c=IN IP4 5.5.5.5
> a=rtcp:50017
> a=rtpmap:113 opus/48000/2
> a=fmtp:113 useinbandfec=1
> a=rtpmap:0 PCMU/8000
> a=rtpmap:101 telephone-event/8000
> a=fmtp:101 0-16
> a=crypto:1 AES_CM_128_HMAC_SHA1_80
inline:UhHq6hth9HqALmiJ3AEeoGkixObBzkLURG60wJKT
> a=crypto:2 AES_CM_128_HMAC_SHA1_32
inline:VKYaSCVwgvXCPaRvudTrgLORhWmOA7wyDJVeGjcu
> a=sendrecv
> a=oldmediaip:172.22.199.110
> a=oldmediaip:172.22.199.110
> ------------------------------------------------------------------------
>
> This doesn’t seem valid, as the top Via doesn’t have a port specified?
>
> For reference, just rebuilt form the 5.4 branch today:
>
> commit 62dff5b8b157236cae7defe64291a6e4a8ae27b5 (upstream/5.4)
> Author: Kamailio Dev <kamailio.dev(a)kamailio.org>
> Date: Wed Oct 28 20:16:28 2020 +0100
>
> modules: readme files regenerated - modules ... [skip ci]
>
> Thanks!
>
> ~Noah
>
> _______________________________________________
> Kamailio (SER) - Users Mailing List
> sr-users(a)lists.kamailio.org
> https://lists.kamailio.org/cgi-bin/mailman/listinfo/sr-users