Asterisk 20 not answer sip options request

ftardini · January 8, 2025, 5:57pm

Yes, i know, i read a lot of different post, everything i found on internet, including asked to chatgpt, not so clever,and nothing.
My problem is next, Asterisk 20, with a provider that have a huawey pbx and as soon as i start a call that work excellent, the call finish after 6 minutes becouse asterisk does not respond the sip options request from the provider. Why? i have no idea, i read everything.

I updated asterisk to the last version, asterisk 20.11

i created tcpdump, core debug, etc, and nothing. The client send me this

<— Received SIP request (403 bytes) from UDP:154.0.185.4:5060 —>
OPTIONS sip:1140124000@154.2.76.218:5060 SIP/2.0
Via: SIP/2.0/UDP 154.0.185.4:5060;branch=z9hG4bK1besnm30380qn2ktneg0sh0000g00.1
Call-ID: 87355b46-5f96-4ae3-8090-c778ae3a4ff7
From: sip:0348915620932@154.0.185.4;tag=g41x6604-CC-24
To: 1140124000sip:1140124000@154.2.76.218;tag=c1a7f6e6-8057-4ab2-9a87-5ce3dcc53e88
CSeq: 1 OPTIONS
Accept: application/sdp
Max-Forwards: 69
Content-Length: 0

and asterisk is like it does not understand or does not want to do nothing.

In this call flow, the options came from the providers and nothing confirm asterisk.

ftardini · January 8, 2025, 5:59pm

this is the transport

[transport-udp]
type = transport
protocol = udp
bind = 0.0.0.0:5060
local_net = 10.200.10.0/24
local_net = 10.200.9.0/24
local_net = 10.200.5.0/24
local_net = 10.200.2.0/24
local_net = 154.2.76.0/24
symmetric_transport=yes

this is the endpoint with the provider, is private so it does not require resgitration o that kind of settings.

[provider]
type = endpoint
context = from-provider
dtmf_mode = rfc4733
disallow = all
allow = g729
allow_transfer = yes
aors = provider
transport = transport-udp
direct_media = no
send_pai=no
send_rpid=no

[provider]
type = aor
contact=sip:154.2.76.218:5060
qualify_timeout = 20
qualify_frequency = 30

[provider]
type = identify
endpoint = provider
match = 154.0.185.4

jcolp · January 8, 2025, 6:00pm

You’ve provided a packet capture. Does it show in Asterisk with “pjsip set logger on”? What does an actual log in Asterisk show[1]?

[1] Collecting Debug Information - Asterisk Documentation

ftardini · January 8, 2025, 6:13pm

Hi jcolp, just what i put.

Of course there is a lot of info in the logs, but is everything abount the extensions registering, and doing different checks with asterisk. But when i put
core set debug 4
core set verbose 4
pjsip set logger on

nothing else appear, no error, nothing nothing, is like asterisk receive that request and don’t want to attend it.

i read in different post to put an extension like exten => s,1,… but nothing happend.

jcolp · January 8, 2025, 6:15pm

Does the SIP OPTIONS appear in the output of “pjsip set logger on”? If the answer is no, then it never got to Asterisk.

ftardini · January 8, 2025, 6:17pm

yes, appear when i put “pjsip set logger on”, so i see that asterisk receive the request.

jcolp · January 8, 2025, 6:18pm

Okay, provide a log.

ftardini · January 8, 2025, 6:39pm

here is it, this is all the info from a call out from asterisk.
I ended the call soon becouse nothing else appear. this is all what i can get from the logger on


NVITE sip:nro-privado@154.0.185.4 SIP/2.0
Via: SIP/2.0/UDP 154.2.76.218:5060;rport;branch=z9hG4bKPje217d4d2-2d8a-48dd-b7d5-16212aba2942
From: "nro-empresa" <sip:10.200.2.38>;tag=4c0f8063-1184-4172-bb85-efe172374894
To: <sip:nro-privado@154.0.185.4>
Contact: <sip:asterisk@154.2.76.218:5060>
Call-ID: f0b2c01b-eb7f-4fff-8b71-b9a649cac890
CSeq: 24723 INVITE
Allow: OPTIONS, REGISTER, SUBSCRIBE, NOTIFY, PUBLISH, INVITE, ACK, BYE, CANCEL, UPDATE, PRACK, INFO, MESSAGE, REFER
Supported: 100rel, timer, replaces, norefersub, histinfo
Session-Expires: 1800
Min-SE: 90
Max-Forwards: 70
User-Agent: Asterisk PBX 20.11.0
Content-Type: application/sdp
Content-Length:   239

v=0
o=- 2039065983 2039065983 IN IP4 154.2.76.218
s=Asterisk
c=IN IP4 154.2.76.218
t=0 0
m=audio 19522 RTP/AVP 18 101
a=rtpmap:18 G729/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=maxptime:220
a=sendrecv

<--- Transmitting SIP response (505 bytes) to UDP:10.200.9.64:5060 --->
SIP/2.0 180 Ringing
Via: SIP/2.0/UDP 10.200.9.64:5060;rport=5060;received=10.200.9.64;branch=z9hG4bK-524287-1---a4e838b4d06682a4
Call-ID: CiBTj7nT0nqN243O4NaFHg..
From: <sip:2004@10.200.2.38>;tag=535e4809
To: <sip:nro-privado@10.200.2.38>;tag=fa0bfd5a-b127-464f-bc09-41591873b77e
CSeq: 2 INVITE
Server: Asterisk PBX 20.11.0
Contact: <sip:10.200.2.38:5060>
Allow: OPTIONS, REGISTER, SUBSCRIBE, NOTIFY, PUBLISH, INVITE, ACK, BYE, CANCEL, UPDATE, PRACK, INFO, MESSAGE, REFER
Content-Length:  0


<--- Received SIP response (346 bytes) from UDP:154.0.185.4:5060 --->
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 154.2.76.218:5060;received=154.2.76.218;branch=z9hG4bKPje217d4d2-2d8a-48dd-b7d5-16212aba2942;rport=5060
From: "nro-empresa" <sip:10.200.2.38>;tag=4c0f8063-1184-4172-bb85-efe172374894
To: <sip:nro-privado@154.0.185.4>
Call-ID: f0b2c01b-eb7f-4fff-8b71-b9a649cac890
CSeq: 24723 INVITE
Content-Length: 0


<--- Received SIP response (832 bytes) from UDP:154.0.185.4:5060 --->
SIP/2.0 183 Session Progress
Via: SIP/2.0/UDP 154.2.76.218:5060;received=154.2.76.218;branch=z9hG4bKPje217d4d2-2d8a-48dd-b7d5-16212aba2942;rport=5060
From: "nro-empresa" <sip:10.200.2.38>;tag=4c0f8063-1184-4172-bb85-efe172374894
To: <sip:nro-privado@154.0.185.4>;tag=xxg4aw62-CC-32
Call-ID: f0b2c01b-eb7f-4fff-8b71-b9a649cac890
CSeq: 24723 INVITE
Contact: <sip:nro-privado@154.0.185.4:5060;user=phone;transport=udp>
Allow: INVITE,ACK,OPTIONS,BYE,CANCEL,REGISTER,INFO,PRACK,SUBSCRIBE,NOTIFY,UPDATE,MESSAGE,REFER
Require: 100rel
RSeq: 1
Content-Length: 230
Content-Type: application/sdp

v=0
o=HuaweiSoftX3000 333487687 333487687 IN IP4 154.0.185.4
s=Sip Call
c=IN IP4 154.0.185.4
t=0 0
m=audio 45620 RTP/AVP 18 101
a=rtpmap:18 G729/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=fmtp:18 annexb=no

       > 0x7f1a84003f50 -- Strict RTP learning after remote address set to: 154.0.185.4:45620
<--- Transmitting SIP request (467 bytes) to UDP:154.0.185.4:5060 --->
PRACK sip:nro-privado@154.0.185.4:5060;user=phone;transport=udp SIP/2.0
Via: SIP/2.0/UDP 154.2.76.218:5060;rport;branch=z9hG4bKPja6fcceaf-58ba-4aab-8681-a16e1f749a51
From: "nro-empresa" <sip:10.200.2.38>;tag=4c0f8063-1184-4172-bb85-efe172374894
To: <sip:nro-privado@154.0.185.4>;tag=xxg4aw62-CC-32
Call-ID: f0b2c01b-eb7f-4fff-8b71-b9a649cac890
CSeq: 24724 PRACK
RAck: 1 24723 INVITE
Max-Forwards: 70
User-Agent: Asterisk PBX 20.11.0
Content-Length:  0


    -- PJSIP/claro-00000001 is making progress passing it to PJSIP/2004-00000000
<--- Received SIP response (360 bytes) from UDP:154.0.185.4:5060 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 154.2.76.218:5060;received=154.2.76.218;branch=z9hG4bKPja6fcceaf-58ba-4aab-8681-a16e1f749a51;rport=5060
From: "nro-empresa" <sip:10.200.2.38>;tag=4c0f8063-1184-4172-bb85-efe172374894
To: <sip:nro-privado@154.0.185.4>;tag=xxg4aw62-CC-32
Call-ID: f0b2c01b-eb7f-4fff-8b71-b9a649cac890
CSeq: 24724 PRACK
Content-Length: 0


       > 0x7f1a84003f50 -- Strict RTP switching to RTP target address 154.0.185.4:45620 as source
<--- Received SIP response (433 bytes) from UDP:154.0.185.4:5060 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 154.2.76.218:5060;received=154.2.76.218;branch=z9hG4bKPje217d4d2-2d8a-48dd-b7d5-16212aba2942;rport=5060
From: "nro-empresa" <sip:10.200.2.38>;tag=4c0f8063-1184-4172-bb85-efe172374894
To: <sip:nro-privado@154.0.185.4>;tag=xxg4aw62-CC-32
Call-ID: f0b2c01b-eb7f-4fff-8b71-b9a649cac890
CSeq: 24723 INVITE
Contact: <sip:nro-privado@154.0.185.4:5060;user=phone;transport=udp>
Content-Length: 0


<--- Transmitting SIP request (441 bytes) to UDP:154.0.185.4:5060 --->
ACK sip:nro-privado@154.0.185.4:5060;user=phone;transport=udp SIP/2.0
Via: SIP/2.0/UDP 154.2.76.218:5060;rport;branch=z9hG4bKPj935d568a-a66e-4b05-a656-cfc3608d3168
From: "nro-empresa" <sip:10.200.2.38>;tag=4c0f8063-1184-4172-bb85-efe172374894
To: <sip:nro-privado@154.0.185.4>;tag=xxg4aw62-CC-32
Call-ID: f0b2c01b-eb7f-4fff-8b71-b9a649cac890
CSeq: 24723 ACK
Max-Forwards: 70
User-Agent: Asterisk PBX 20.11.0
Content-Length:  0


    -- PJSIP/claro-00000001 answered PJSIP/2004-00000000
       > 0x7f1a88051e80 -- Strict RTP learning after remote address set to: 10.200.9.64:46697
<--- Transmitting SIP response (893 bytes) to UDP:10.200.9.64:5060 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 10.200.9.64:5060;rport=5060;received=10.200.9.64;branch=z9hG4bK-524287-1---a4e838b4d06682a4
Call-ID: CiBTj7nT0nqN243O4NaFHg..
From: <sip:2004@10.200.2.38>;tag=535e4809
To: <sip:nro-privado@10.200.2.38>;tag=fa0bfd5a-b127-464f-bc09-41591873b77e
CSeq: 2 INVITE
Server: Asterisk PBX 20.11.0
Allow: OPTIONS, REGISTER, SUBSCRIBE, NOTIFY, PUBLISH, INVITE, ACK, BYE, CANCEL, UPDATE, PRACK, INFO, MESSAGE, REFER
Contact: <sip:10.200.2.38:5060>
Supported: 100rel, timer, replaces, norefersub
Content-Type: application/sdp
Content-Length:   311

v=0
o=- 0 252807886 IN IP4 10.200.2.38
s=Asterisk
c=IN IP4 10.200.2.38
t=0 0
m=audio 16476 RTP/AVP 8 0 3 101
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:3 GSM/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=maxptime:140
a=sendrecv
m=audio 0 RTP/AVPF 106 9 98 101 0 8 3

    -- Channel PJSIP/claro-00000001 joined 'simple_bridge' basic-bridge <8fe93e93-98d4-4c68-aea9-090574bd1125>
    -- Channel PJSIP/2004-00000000 joined 'simple_bridge' basic-bridge <8fe93e93-98d4-4c68-aea9-090574bd1125>
       > 0x7f1a88051e80 -- Strict RTP switching to RTP target address 10.200.9.64:46697 as source
<--- Received SIP request (403 bytes) from UDP:154.0.185.4:5060 --->
OPTIONS sip:nro-empresa@154.2.76.218:5060 SIP/2.0
Via: SIP/2.0/UDP 154.0.185.4:5060;branch=z9hG4bKupu6ho309orkeg3v4s80sh0000g00.1
Call-ID: f0b2c01b-eb7f-4fff-8b71-b9a649cac890
From: <sip:nro-privado@154.0.185.4>;tag=xxg4aw62-CC-32
To: nro-empresa<sip:nro-empresa@154.2.76.218>;tag=4c0f8063-1184-4172-bb85-efe172374894
CSeq: 1 OPTIONS
Accept: application/sdp
Max-Forwards: 69
Content-Length: 0


<--- Received SIP request (410 bytes) from UDP:10.200.9.64:5060 --->
ACK sip:10.200.2.38:5060 SIP/2.0
Via: SIP/2.0/UDP 10.200.9.64:5060;branch=z9hG4bK-524287-1---10ce51338a1eec79;rport
Max-Forwards: 70
Contact: <sip:2004@10.200.9.64:5060;transport=UDP>
To: <sip:nro-privado@10.200.2.38>;tag=fa0bfd5a-b127-464f-bc09-41591873b77e
From: <sip:2004@10.200.2.38>;tag=535e4809
Call-ID: CiBTj7nT0nqN243O4NaFHg..
CSeq: 2 ACK
User-Agent: Z 5.6.6 v2.10.20.5
Content-Length: 0


<--- Received SIP request (403 bytes) from UDP:154.0.185.4:5060 --->
OPTIONS sip:nro-empresa@154.2.76.218:5060 SIP/2.0
Via: SIP/2.0/UDP 154.0.185.4:5060;branch=z9hG4bKupu6ho309orkeg3v4s80sh0000g00.1
Call-ID: f0b2c01b-eb7f-4fff-8b71-b9a649cac890
From: <sip:nro-privado@154.0.185.4>;tag=xxg4aw62-CC-32
To: nro-empresa<sip:nro-empresa@154.2.76.218>;tag=4c0f8063-1184-4172-bb85-efe172374894
CSeq: 1 OPTIONS
Accept: application/sdp
Max-Forwards: 69
Content-Length: 0


       > 0x7f1a84003f50 -- Strict RTP learning complete - Locking on source address 154.0.185.4:45620
<--- Received SIP request (403 bytes) from UDP:154.0.185.4:5060 --->
OPTIONS sip:nro-empresa@154.2.76.218:5060 SIP/2.0
Via: SIP/2.0/UDP 154.0.185.4:5060;branch=z9hG4bKupu6ho309orkeg3v4s80sh0000g00.1
Call-ID: f0b2c01b-eb7f-4fff-8b71-b9a649cac890
From: <sip:nro-privado@154.0.185.4>;tag=xxg4aw62-CC-32
To: nro-empresa<sip:nro-empresa@154.2.76.218>;tag=4c0f8063-1184-4172-bb85-efe172374894
CSeq: 1 OPTIONS
Accept: application/sdp
Max-Forwards: 69
Content-Length: 0


<--- Received SIP request (403 bytes) from UDP:154.0.185.4:5060 --->
OPTIONS sip:nro-empresa@154.2.76.218:5060 SIP/2.0
Via: SIP/2.0/UDP 154.0.185.4:5060;branch=z9hG4bKupu6ho309orkeg3v4s80sh0000g00.1
Call-ID: f0b2c01b-eb7f-4fff-8b71-b9a649cac890
From: <sip:nro-privado@154.0.185.4>;tag=xxg4aw62-CC-32
To: nro-empresa<sip:nro-empresa@154.2.76.218>;tag=4c0f8063-1184-4172-bb85-efe172374894
CSeq: 1 OPTIONS
Accept: application/sdp
Max-Forwards: 69
Content-Length: 0


       > 0x7f1a88051e80 -- Strict RTP learning complete - Locking on source address 10.200.9.64:46697
<--- Received SIP request (403 bytes) from UDP:154.0.185.4:5060 --->
OPTIONS sip:nro-empresa@154.2.76.218:5060 SIP/2.0
Via: SIP/2.0/UDP 154.0.185.4:5060;branch=z9hG4bKupu6ho309orkeg3v4s80sh0000g00.1
Call-ID: f0b2c01b-eb7f-4fff-8b71-b9a649cac890
From: <sip:nro-privado@154.0.185.4>;tag=xxg4aw62-CC-32
To: nro-empresa<sip:nro-empresa@154.2.76.218>;tag=4c0f8063-1184-4172-bb85-efe172374894
CSeq: 1 OPTIONS
Accept: application/sdp
Max-Forwards: 69
Content-Length: 0


<--- Received SIP request (403 bytes) from UDP:154.0.185.4:5060 --->
OPTIONS sip:nro-empresa@154.2.76.218:5060 SIP/2.0
Via: SIP/2.0/UDP 154.0.185.4:5060;branch=z9hG4bKupu6ho309orkeg3v4s80sh0000g00.1
Call-ID: f0b2c01b-eb7f-4fff-8b71-b9a649cac890
From: <sip:nro-privado@154.0.185.4>;tag=xxg4aw62-CC-32
To: nro-empresa<sip:nro-empresa@154.2.76.218>;tag=4c0f8063-1184-4172-bb85-efe172374894
CSeq: 1 OPTIONS
Accept: application/sdp
Max-Forwards: 69
Content-Length: 0


<--- Received SIP request (422 bytes) from UDP:154.0.185.4:5060 --->
BYE sip:nro-empresa@154.2.76.218:5060 SIP/2.0
Via: SIP/2.0/UDP 154.0.185.4:5060;branch=z9hG4bKupu6ho309orkeg3v4s80sd0000010.1
Call-ID: f0b2c01b-eb7f-4fff-8b71-b9a649cac890
From: <sip:nro-privado@154.0.185.4>;tag=xxg4aw62-CC-32
To: nro-empresa<sip:nro-empresa@154.2.76.218>;tag=4c0f8063-1184-4172-bb85-efe172374894
CSeq: 2 BYE
Reason: Q.850;cause=16;text="normal call clearing"
Max-Forwards: 69
Content-Length: 0


<--- Transmitting SIP response (388 bytes) to UDP:154.0.185.4:5060 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 154.0.185.4:5060;rport=5060;received=154.0.185.4;branch=z9hG4bKupu6ho309orkeg3v4s80sd0000010.1
Call-ID: f0b2c01b-eb7f-4fff-8b71-b9a649cac890
From: <sip:nro-privado@154.0.185.4>;tag=xxg4aw62-CC-32
To: "nro-empresa" <sip:nro-empresa@154.2.76.218>;tag=4c0f8063-1184-4172-bb85-efe172374894
CSeq: 2 BYE
Server: Asterisk PBX 20.11.0
Content-Length:  0


    -- Channel PJSIP/claro-00000001 left 'simple_bridge' basic-bridge <8fe93e93-98d4-4c68-aea9-090574bd1125>
    -- Channel PJSIP/2004-00000000 left 'simple_bridge' basic-bridge <8fe93e93-98d4-4c68-aea9-090574bd1125>
  == Spawn extension (dial-out-claro, s, 3) exited non-zero on 'PJSIP/2004-00000000'
<--- Transmitting SIP request (403 bytes) to UDP:10.200.9.64:5060 --->
BYE sip:2004@10.200.9.64:5060 SIP/2.0
Via: SIP/2.0/UDP 10.200.2.38:5060;rport;branch=z9hG4bKPj6d3cc756-a401-4b57-9d91-e17669bbf764
From: <sip:nro-privado@10.200.2.38>;tag=fa0bfd5a-b127-464f-bc09-41591873b77e
To: <sip:2004@10.200.2.38>;tag=535e4809
Call-ID: CiBTj7nT0nqN243O4NaFHg..
CSeq: 1923 BYE
Reason: Q.850;cause=16
Max-Forwards: 70
User-Agent: Asterisk PBX 20.11.0
Content-Length:  0


<--- Received SIP response (392 bytes) from UDP:10.200.9.64:5060 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 10.200.2.38:5060;rport=5060;branch=z9hG4bKPj6d3cc756-a401-4b57-9d91-e17669bbf764
Contact: <sip:2004@10.200.9.64:5060;transport=UDP>
To: <sip:2004@10.200.2.38>;tag=535e4809
From: <sip:nro-privado@10.200.2.38>;tag=fa0bfd5a-b127-464f-bc09-41591873b77e
Call-ID: CiBTj7nT0nqN243O4NaFHg..
CSeq: 1923 BYE
User-Agent: Z 5.6.6 v2.10.20.5
Content-Length: 0

i changed the numbers for private info.

jcolp · January 8, 2025, 6:42pm

I actually wanted a log according to the link I provided, because debug level information can provide insight into the underlying handling.

ftardini · January 8, 2025, 6:46pm

sorry, my first post i created. I do not understand. You mean that i had to respond only to you and not make it public?

jcolp · January 8, 2025, 6:48pm

No, I mean this link:

https://docs.asterisk.org/Operation/Logging/Collecting-Debug-Information/?h=collecting

Has documentation on collecting a debug level log, which can provide insight into why things are doing what they are doing.

ftardini · January 8, 2025, 6:48pm

i think i read it. I give another look and see if i can upload something with more info.

ftardini · January 8, 2025, 7:09pm

ok, now i could generate much more info. I create once, but i could not find nothing


[Jan  8 15:50:34] DEBUG[42435] res_pjsip_session.c:  PJSIP/2004-00000002 Event: TSX_STATE  Inv State: CONNECTING
[Jan  8 15:50:34] DEBUG[42435] res_pjsip_session.c: Function session_inv_on_state_changed called on event TSX_STATE
[Jan  8 15:50:34] DEBUG[42435] res_pjsip_session.c: The state change pertains to the endpoint '2004(PJSIP/2004-00000002)'
[Jan  8 15:50:34] DEBUG[42435] res_pjsip_session.c: The inv session still has an invite_tsx (0x7f1a88037fb8)
[Jan  8 15:50:34] DEBUG[42435] res_pjsip_session.c: There is no transaction involved in this state change
[Jan  8 15:50:34] DEBUG[42435] res_pjsip_session.c: The current inv state is CONNECTING
[Jan  8 15:50:34] DEBUG[42435] res_pjsip_session.c: PJSIP/2004-00000002: Source of transaction state change is TX_MSG
[Jan  8 15:50:34] DEBUG[42435] res_pjsip_session.c:  
[Jan  8 15:50:34] DEBUG[42435] res_pjsip_session.c:  PJSIP/2004-00000002 TSX State: Completed  Inv State: CONNECTING
[Jan  8 15:50:34] DEBUG[42435] res_pjsip_session.c: Function session_inv_on_tsx_state_changed called on event TSX_STATE
[Jan  8 15:50:34] DEBUG[42435] res_pjsip_session.c: The state change pertains to the endpoint '2004(PJSIP/2004-00000002)'
[Jan  8 15:50:34] DEBUG[42435] res_pjsip_session.c: The inv session still has an invite_tsx (0x7f1a88037fb8)
[Jan  8 15:50:34] DEBUG[42435] res_pjsip_session.c: The UAS INVITE transaction involved in this state change is 0x7f1a88037fb8
[Jan  8 15:50:34] DEBUG[42435] res_pjsip_session.c: The current transaction state is Completed
[Jan  8 15:50:34] DEBUG[42435] res_pjsip_session.c: The transaction state change event is TX_MSG
[Jan  8 15:50:34] DEBUG[42435] res_pjsip_session.c: The current inv state is CONNECTING
[Jan  8 15:50:34] DEBUG[42435] res_pjsip_session.c:  Nothing delayed
[Jan  8 15:50:34] DEBUG[42435] res_pjsip_session.c:  PJSIP/2004-00000002 TSX State: Completed  Inv State: CONNECTING
[Jan  8 15:50:34] DEBUG[42435] res_pjsip_session.c:  Topology: Pending: (null topology)  Active:  <0:audio-0:audio:sendrecv (alaw|ulaw|gsm)> <1:audio-1:audio:removed (nothing)>
[Jan  8 15:50:34] DEBUG[42435] res_pjsip_session.c:  
[Jan  8 15:50:34] DEBUG[42435] chan_pjsip.c:  
[Jan  8 15:50:34] DEBUG[42601][C-00000002] chan_pjsip.c:  
[Jan  8 15:50:34] DEBUG[42601][C-00000002] chan_pjsip.c:  PJSIP/2004-00000002: Indicated Stop generators
[Jan  8 15:50:34] DEBUG[42601][C-00000002] chan_pjsip.c:  PJSIP/2004-00000002
[Jan  8 15:50:34] DEBUG[42601][C-00000002] stasis.c: Creating topic. name: bridge:all/bridge:f4d2d4c4-5395-4fc7-aa88-b3ff40e3b361, detail: 
[Jan  8 15:50:34] DEBUG[42601][C-00000002] stasis.c: Topic 'bridge:all/bridge:f4d2d4c4-5395-4fc7-aa88-b3ff40e3b361': 0x7f1a6400d080 created
[Jan  8 15:50:34] DEBUG[42601][C-00000002] bridge_native_rtp.c: Bridge 'f4d2d4c4-5395-4fc7-aa88-b3ff40e3b361' can not use native RTP bridge as two channels are required
[Jan  8 15:50:34] DEBUG[42601][C-00000002] bridge.c: Bridge technology native_rtp is not compatible with properties of existing bridge.
[Jan  8 15:50:34] DEBUG[42601][C-00000002] bridge.c: Bridge technology holding_bridge does not have any capabilities we want.
[Jan  8 15:50:34] DEBUG[42601][C-00000002] bridge.c: Bridge technology softmix has less preference than simple_bridge (10 <= 50). Skipping.
[Jan  8 15:50:34] DEBUG[42601][C-00000002] bridge.c: Chose bridge technology simple_bridge
[Jan  8 15:50:34] DEBUG[42601][C-00000002] bridge.c: Bridge f4d2d4c4-5395-4fc7-aa88-b3ff40e3b361: calling simple_bridge technology constructor
[Jan  8 15:50:34] DEBUG[42601][C-00000002] bridge.c: Bridge f4d2d4c4-5395-4fc7-aa88-b3ff40e3b361: calling simple_bridge technology start
[Jan  8 15:50:34] DEBUG[42601][C-00000002] stasis_bridges.c: Update: 0x7f1a64036438  Old: <none>  New: f4d2d4c4-5395-4fc7-aa88-b3ff40e3b361
[Jan  8 15:50:34] DEBUG[42601][C-00000002] stasis_bridges.c: Update: 0x7f1a64036438  Old: <none>  New: f4d2d4c4-5395-4fc7-aa88-b3ff40e3b361
[Jan  8 15:50:34] DEBUG[42603][C-00000002] bridge_channel.c: Bridge f4d2d4c4-5395-4fc7-aa88-b3ff40e3b361: 0x7f1a64036d60(PJSIP/claro-00000003) is joining
[Jan  8 15:50:34] DEBUG[42603][C-00000002] bridge_channel.c: Bridge f4d2d4c4-5395-4fc7-aa88-b3ff40e3b361: pushing 0x7f1a64036d60(PJSIP/claro-00000003)
[Jan  8 15:50:34] VERBOSE[42603][C-00000002] bridge_channel.c: Channel PJSIP/claro-00000003 joined 'simple_bridge' basic-bridge <f4d2d4c4-5395-4fc7-aa88-b3ff40e3b361>
[Jan  8 15:50:34] DEBUG[42603][C-00000002] stasis_bridges.c: Update: 0x7f1a6c003c08  Old: f4d2d4c4-5395-4fc7-aa88-b3ff40e3b361  New: f4d2d4c4-5395-4fc7-aa88-b3ff40e3b361
[Jan  8 15:50:34] DEBUG[42603][C-00000002] stasis_bridges.c: Update: 0x7f1a6c003c08  Old: f4d2d4c4-5395-4fc7-aa88-b3ff40e3b361  New: f4d2d4c4-5395-4fc7-aa88-b3ff40e3b361
[Jan  8 15:50:34] DEBUG[42603][C-00000002] bridge_native_rtp.c: Bridge 'f4d2d4c4-5395-4fc7-aa88-b3ff40e3b361' can not use native RTP bridge as two channels are required
[Jan  8 15:50:34] DEBUG[42603][C-00000002] bridge.c: Bridge technology native_rtp is not compatible with properties of existing bridge.
[Jan  8 15:50:34] DEBUG[42603][C-00000002] bridge.c: Bridge technology holding_bridge does not have any capabilities we want.
[Jan  8 15:50:34] DEBUG[42603][C-00000002] bridge.c: Bridge technology softmix does not have any capabilities we want.
[Jan  8 15:50:34] DEBUG[42603][C-00000002] bridge.c: Chose bridge technology simple_bridge
[Jan  8 15:50:34] DEBUG[42603][C-00000002] bridge.c: Bridge f4d2d4c4-5395-4fc7-aa88-b3ff40e3b361 is already using the new technology.
[Jan  8 15:50:34] DEBUG[42603][C-00000002] bridge.c: Bridge f4d2d4c4-5395-4fc7-aa88-b3ff40e3b361: 0x7f1a64036d60(PJSIP/claro-00000003) is joining simple_bridge technology
[Jan  8 15:50:34] DEBUG[42603][C-00000002] stasis_bridges.c: Update: 0x7f1a6c006688  Old: f4d2d4c4-5395-4fc7-aa88-b3ff40e3b361  New: f4d2d4c4-5395-4fc7-aa88-b3ff40e3b361
[Jan  8 15:50:34] DEBUG[42603][C-00000002] stasis_bridges.c: Update: 0x7f1a6c006688  Old: f4d2d4c4-5395-4fc7-aa88-b3ff40e3b361  New: f4d2d4c4-5395-4fc7-aa88-b3ff40e3b361
[Jan  8 15:50:34] DEBUG[42603][C-00000002] chan_pjsip.c:  PJSIP/claro-00000003: Indicated Media SSRC change
[Jan  8 15:50:34] DEBUG[42603][C-00000002] chan_pjsip.c:  PJSIP/claro-00000003
[Jan  8 15:50:34] DEBUG[42424] devicestate.c: No provider found, checking channel drivers for PJSIP - claro
[Jan  8 15:50:34] DEBUG[42424] devicestate.c: Changing state for PJSIP/claro - state 2 (In use)
[Jan  8 15:50:34] DEBUG[42424] devicestate.c: No provider found, checking channel drivers for PJSIP - 2004
[Jan  8 15:50:34] DEBUG[42424] devicestate.c: Changing state for PJSIP/2004 - state 2 (In use)
[Jan  8 15:50:34] DEBUG[42412] threadpool.c: Increasing threadpool stasis/pool's size by 1
[Jan  8 15:50:35] DEBUG[42452] app_queue.c: Device 'PJSIP/claro' changed to state '2' (In use) but we don't care because they're not a member of any queue.
[Jan  8 15:50:35] DEBUG[42601][C-00000002] bridge_channel.c: Bridge f4d2d4c4-5395-4fc7-aa88-b3ff40e3b361: 0x7f1a640381f0(PJSIP/2004-00000002) is joining
[Jan  8 15:50:35] DEBUG[42601][C-00000002] bridge_channel.c: Bridge f4d2d4c4-5395-4fc7-aa88-b3ff40e3b361: pushing 0x7f1a640381f0(PJSIP/2004-00000002)
[Jan  8 15:50:35] VERBOSE[42601][C-00000002] bridge_channel.c: Channel PJSIP/2004-00000002 joined 'simple_bridge' basic-bridge <f4d2d4c4-5395-4fc7-aa88-b3ff40e3b361>
[Jan  8 15:50:35] DEBUG[42601][C-00000002] stasis_bridges.c: Update: 0x7f1a640064c8  Old: f4d2d4c4-5395-4fc7-aa88-b3ff40e3b361  New: f4d2d4c4-5395-4fc7-aa88-b3ff40e3b361
[Jan  8 15:50:35] DEBUG[42601][C-00000002] stasis_bridges.c: Update: 0x7f1a640064c8  Old: f4d2d4c4-5395-4fc7-aa88-b3ff40e3b361  New: f4d2d4c4-5395-4fc7-aa88-b3ff40e3b361
[Jan  8 15:50:35] DEBUG[42601][C-00000002] bridge_native_rtp.c: Bridge 'f4d2d4c4-5395-4fc7-aa88-b3ff40e3b361'.  Checking compatability for channels 'PJSIP/claro-00000003' and 'PJSIP/2004-00000002'
[Jan  8 15:50:35] DEBUG[42601][C-00000002] bridge_native_rtp.c: Bridge 'f4d2d4c4-5395-4fc7-aa88-b3ff40e3b361' can not use native RTP bridge as channel 'PJSIP/claro-00000003' has DTMF hooks
[Jan  8 15:50:35] DEBUG[42601][C-00000002] bridge.c: Bridge technology native_rtp is not compatible with properties of existing bridge.
[Jan  8 15:50:35] DEBUG[42601][C-00000002] bridge.c: Bridge technology holding_bridge does not have any capabilities we want.
[Jan  8 15:50:35] DEBUG[42601][C-00000002] bridge.c: Bridge technology softmix does not have any capabilities we want.
[Jan  8 15:50:35] DEBUG[42601][C-00000002] bridge.c: Chose bridge technology simple_bridge
[Jan  8 15:50:35] DEBUG[42601][C-00000002] bridge.c: Bridge f4d2d4c4-5395-4fc7-aa88-b3ff40e3b361 is already using the new technology.
[Jan  8 15:50:35] DEBUG[42601][C-00000002] bridge.c: Bridge f4d2d4c4-5395-4fc7-aa88-b3ff40e3b361: 0x7f1a640381f0(PJSIP/2004-00000002) is joining simple_bridge technology
[Jan  8 15:50:35] DEBUG[42601][C-00000002] stream.c:  Topology Create
[Jan  8 15:50:35] DEBUG[42601][C-00000002] stream.c:  Created: 0x7f1a64011188
[Jan  8 15:50:35] DEBUG[42601][C-00000002] chan_pjsip.c:  PJSIP/claro-00000003: Indicated Stream topology request change
[Jan  8 15:50:35] DEBUG[42601][C-00000002] chan_pjsip.c:  PJSIP/claro-00000003: New topology:  <0:audio-0:audio:sendrecv (g729)> <1:audio-1:audio:removed (nothing)>
[Jan  8 15:50:35] DEBUG[42601][C-00000002] chan_pjsip.c:  
[Jan  8 15:50:35] DEBUG[42601][C-00000002] stream.c:  Topology Create
[Jan  8 15:50:35] DEBUG[42601][C-00000002] stream.c:  Created: 0x7f1a64011c58
[Jan  8 15:50:35] DEBUG[42601][C-00000002] chan_pjsip.c:  RC: 0
[Jan  8 15:50:35] DEBUG[42601][C-00000002] chan_pjsip.c:  PJSIP/claro-00000003
[Jan  8 15:50:35] DEBUG[42601][C-00000002] stream.c:  Topology: 0x7f1a64011188:  <0:audio-0:audio:sendrecv (g729)> <1:audio-1:audio:removed (nothing)>
[Jan  8 15:50:35] DEBUG[42601][C-00000002] stream.c:  Destroyed: 0x7f1a64011188
[Jan  8 15:50:35] DEBUG[42601][C-00000002] stream.c:  Topology Create
[Jan  8 15:50:35] DEBUG[42601][C-00000002] stream.c:  Created: 0x7f1a64011188
[Jan  8 15:50:35] DEBUG[42601][C-00000002] chan_pjsip.c:  PJSIP/claro-00000003: Indicated Stream topology request change
[Jan  8 15:50:35] DEBUG[42601][C-00000002] chan_pjsip.c:  PJSIP/claro-00000003: New topology:  <0:audio-0:audio:sendrecv (g729)> <1:audio-1:audio:removed (nothing)>
[Jan  8 15:50:35] DEBUG[42601][C-00000002] chan_pjsip.c:  
[Jan  8 15:50:35] DEBUG[42601][C-00000002] stream.c:  Topology Create
[Jan  8 15:50:35] DEBUG[42601][C-00000002] stream.c:  Created: 0x7f1a6403ccb8
[Jan  8 15:50:35] DEBUG[42601][C-00000002] chan_pjsip.c:  RC: 0
[Jan  8 15:50:35] DEBUG[42601][C-00000002] chan_pjsip.c:  PJSIP/claro-00000003
[Jan  8 15:50:35] DEBUG[42601][C-00000002] stream.c:  Topology: 0x7f1a64011188:  <0:audio-0:audio:sendrecv (g729)> <1:audio-1:audio:removed (nothing)>
[Jan  8 15:50:35] DEBUG[42601][C-00000002] stream.c:  Destroyed: 0x7f1a64011188
[Jan  8 15:50:35] DEBUG[42601][C-00000002] stasis_bridges.c: Update: 0x7f1a6403f8d8  Old: f4d2d4c4-5395-4fc7-aa88-b3ff40e3b361  New: f4d2d4c4-5395-4fc7-aa88-b3ff40e3b361
[Jan  8 15:50:35] DEBUG[42601][C-00000002] stasis_bridges.c: Update: 0x7f1a6403f8d8  Old: f4d2d4c4-5395-4fc7-aa88-b3ff40e3b361  New: f4d2d4c4-5395-4fc7-aa88-b3ff40e3b361
[Jan  8 15:50:35] DEBUG[42601][C-00000002] chan_pjsip.c:  PJSIP/2004-00000002: Indicated Media SSRC change
[Jan  8 15:50:35] DEBUG[42601][C-00000002] chan_pjsip.c:  PJSIP/2004-00000002
[Jan  8 15:50:35] DEBUG[42435] chan_pjsip.c:  PJSIP/claro-00000003:  <0:audio-0:audio:sendrecv (g729)> <1:audio-1:audio:removed (nothing)>
[Jan  8 15:50:35] DEBUG[42435] res_pjsip_session.c:  PJSIP/claro-00000003: New SDP? yes  Queued? no DP:  <0:audio-0:audio:sendrecv (g729)> <1:audio-1:audio:removed (nothing)>  DA: none
[Jan  8 15:50:35] DEBUG[42435] res_pjsip_session.c:  PJSIP/claro-00000003: Pending media state exists
[Jan  8 15:50:35] DEBUG[42435] res_pjsip_session.c:  PJSIP/claro-00000003: Pruning and checking formats of streams
[Jan  8 15:50:35] DEBUG[42435] res_pjsip_session.c:  PJSIP/claro-00000003: Checking stream audio-0
[Jan  8 15:50:35] DEBUG[42435] res_pjsip_session.c:  PJSIP/claro-00000003: Found existing stream audio-0
[Jan  8 15:50:35] DEBUG[42435] res_pjsip_session.c:  
[Jan  8 15:50:35] DEBUG[42435] res_pjsip_session.c:  PJSIP/claro-00000003: Checking stream audio-1
[Jan  8 15:50:35] DEBUG[42435] res_pjsip_session.c:  PJSIP/claro-00000003: Dropped overlimit stream audio-1
[Jan  8 15:50:35] DEBUG[42435] res_pjsip_session.c:  
[Jan  8 15:50:35] DEBUG[42435] res_pjsip_session.c:  PJSIP/claro-00000003: CA:  <0:audio-0:audio:sendrecv (g729)>
[Jan  8 15:50:35] DEBUG[42435] res_pjsip_session.c:  PJSIP/claro-00000003: NP:  <0:audio-0:audio:sendrecv (g729)>
[Jan  8 15:50:35] DEBUG[42435] stream.c:  Topology: 0x7f1a64011c58:  <0:audio-0:audio:sendrecv (g729)>
[Jan  8 15:50:35] DEBUG[42435] stream.c:  Destroyed: 0x7f1a64011c58
[Jan  8 15:50:35] DEBUG[42435] res_pjsip_session.c:  PJSIP/claro-00000003: Topologies are equal. Not sending re-invite
[Jan  8 15:50:35] DEBUG[42435] chan_pjsip.c:  PJSIP/claro-00000003
[Jan  8 15:50:35] DEBUG[42435] chan_pjsip.c:  PJSIP/claro-00000003:  <0:audio-0:audio:sendrecv (g729)> <1:audio-1:audio:removed (nothing)>
[Jan  8 15:50:35] DEBUG[42435] res_pjsip_session.c:  PJSIP/claro-00000003: New SDP? yes  Queued? no DP:  <0:audio-0:audio:sendrecv (g729)> <1:audio-1:audio:removed (nothing)>  DA: none
[Jan  8 15:50:35] DEBUG[42435] res_pjsip_session.c:  PJSIP/claro-00000003: Pending media state exists
[Jan  8 15:50:35] DEBUG[42435] res_pjsip_session.c:  PJSIP/claro-00000003: Pruning and checking formats of streams
[Jan  8 15:50:35] DEBUG[42435] res_pjsip_session.c:  PJSIP/claro-00000003: Checking stream audio-0
[Jan  8 15:50:35] DEBUG[42435] res_pjsip_session.c:  PJSIP/claro-00000003: Found existing stream audio-0
[Jan  8 15:50:35] DEBUG[42435] res_pjsip_session.c:  
[Jan  8 15:50:35] DEBUG[42435] res_pjsip_session.c:  PJSIP/claro-00000003: Checking stream audio-1
[Jan  8 15:50:35] DEBUG[42435] res_pjsip_session.c:  PJSIP/claro-00000003: Dropped overlimit stream audio-1
[Jan  8 15:50:35] DEBUG[42435] res_pjsip_session.c:  
[Jan  8 15:50:35] DEBUG[42431] cdr.c: Finalized CDR for PJSIP/claro-00000003 - start 1736362227.371669 answer 1736362234.997742 end 1736362234.999594 dur 7.627 bill 0.001 dispo ANSWERED
[Jan  8 15:50:35] DEBUG[42435] res_pjsip_session.c:  PJSIP/claro-00000003: CA:  <0:audio-0:audio:sendrecv (g729)>
[Jan  8 15:50:35] DEBUG[42435] res_pjsip_session.c:  PJSIP/claro-00000003: NP:  <0:audio-0:audio:sendrecv (g729)>
[Jan  8 15:50:35] DEBUG[42435] stream.c:  Topology: 0x7f1a6403ccb8:  <0:audio-0:audio:sendrecv (g729)>
[Jan  8 15:50:35] DEBUG[42435] stream.c:  Destroyed: 0x7f1a6403ccb8
[Jan  8 15:50:35] DEBUG[42435] res_pjsip_session.c:  PJSIP/claro-00000003: Topologies are equal. Not sending re-invite
[Jan  8 15:50:35] DEBUG[42435] chan_pjsip.c:  PJSIP/claro-00000003
[Jan  8 15:50:35] DEBUG[42412] threadpool.c: Increasing threadpool stasis/pool's size by 1
[Jan  8 15:50:35] DEBUG[42603][C-00000002] res_rtp_asterisk.c: 1736362227.3: pkt:   226 Arrival sec:   4.220  Arrival ts:      33759  RX ts:      58880 Transit samp: -25121 Last transit samp: -25120 d:    1 Curr jitter:       0(  0.000) Prev Jitter:       0(  0.000) New Jitter:       0(  0.000)
[Jan  8 15:50:35] DEBUG[42601][C-00000002] res_rtp_asterisk.c: (1736362227.2) RTP ooh, format changed from none to alaw
[Jan  8 15:50:35] DEBUG[42601][C-00000002] res_rtp_asterisk.c: (1736362227.2) RTCP starting transmission in 5000 ms
[Jan  8 15:50:35] DEBUG[42603][C-00000002] res_rtp_asterisk.c: 1736362227.3: pkt:   227 Arrival sec:   4.240  Arrival ts:      33919  RX ts:      59040 Transit samp: -25121 Last transit samp: -25121 d:    0 Curr jitter:      -0(  0.000) Prev Jitter:       0(  0.000) New Jitter:       0(  0.000)
[Jan  8 15:50:35] DEBUG[42603][C-00000002] res_rtp_asterisk.c: 1736362227.3: pkt:   228 Arrival sec:   4.260  Arrival ts:      34079  RX ts:      59200 Transit samp: -25121 Last transit samp: -25121 d:    0 Curr jitter:      -0(  0.000) Prev Jitter:       0(  0.000) New Jitter:       0(  0.000)
[Jan  8 15:50:35] VERBOSE[42434] res_pjsip_logger.c: <--- Received SIP request (403 bytes) from UDP:154.0.185.4:5060 --->
OPTIONS sip:nro-empresa@154.2.76.218:5060 SIP/2.0
Via: SIP/2.0/UDP 154.0.185.4:5060;branch=z9hG4bKs8bo2h00886e9qr01mb0sh0000g00.1
Call-ID: f899175b-b9f1-4920-8f77-5f8677a4c5c2
From: <sip:nro-empresa@154.0.185.4>;tag=x0g2g03b-CC-37
To: nro-empresa<sip:nro-empresa@154.2.76.218>;tag=58797f05-84c0-40d8-b51f-7e15cd2068b8
CSeq: 1 OPTIONS
Accept: application/sdp
Max-Forwards: 69
Content-Length: 0


[Jan  8 15:50:35] DEBUG[42434] netsock2.c: Splitting '154.0.185.4' into...
[Jan  8 15:50:35] DEBUG[42434] netsock2.c: ...host '154.0.185.4' and port ''.
[Jan  8 15:50:35] DEBUG[42434] res_pjsip/pjsip_distributor.c: Searching for serializer associated with dialog dlg0x7f1a8803bb48 for Request msg OPTIONS/cseq=1 (rdata0x7f1a8c0015c8)
[Jan  8 15:50:35] DEBUG[42434] res_pjsip/pjsip_distributor.c: Found serializer pjsip/outsess/claro-00000077 associated with dialog dlg0x7f1a8803bb48
[Jan  8 15:50:35] DEBUG[42435] res_pjsip_session.c:  PJSIP/claro-00000003 Request: OPTIONS 
[Jan  8 15:50:35] DEBUG[42435] res_pjsip_session.c:  PJSIP/claro-00000003 Handled request OPTIONS  ? yes
[Jan  8 15:50:35] DEBUG[42435] res_pjsip_session.c:  PJSIP/claro-00000003 TSX State: Trying  Inv State: CONFIRMED
[Jan  8 15:50:35] DEBUG[42435] res_pjsip_session.c: Function session_inv_on_tsx_state_changed called on event TSX_STATE
[Jan  8 15:50:35] DEBUG[42435] res_pjsip_session.c: The state change pertains to the endpoint 'claro(PJSIP/claro-00000003)'
[Jan  8 15:50:35] DEBUG[42435] res_pjsip_session.c: The inv session does NOT have an invite_tsx
[Jan  8 15:50:35] DEBUG[42435] res_pjsip_session.c: The UAS OPTIONS transaction involved in this state change is 0x7f1a88022158
[Jan  8 15:50:35] DEBUG[42435] res_pjsip_session.c: The current transaction state is Trying
[Jan  8 15:50:35] DEBUG[42435] res_pjsip_session.c: The transaction state change event is RX_MSG
[Jan  8 15:50:35] DEBUG[42435] res_pjsip_session.c: The current inv state is CONFIRMED
[Jan  8 15:50:35] DEBUG[42435] res_pjsip_session.c:  PJSIP/claro-00000003: Method is OPTIONS
[Jan  8 15:50:35] DEBUG[42435] res_pjsip_session.c:  PJSIP/claro-00000003
[Jan  8 15:50:35] DEBUG[42435] res_pjsip_session.c:  Nothing delayed
[Jan  8 15:50:35] DEBUG[42435] res_pjsip_session.c:  PJSIP/claro-00000003 TSX State: Trying  Inv State: CONFIRMED
[Jan  8 15:50:35] DEBUG[42435] res_pjsip_session.c:  Topology: Pending: (null topology)  Active:  <0:audio-0:audio:sendrecv (g729)>

[Jan  8 15:50:35] VERBOSE[42434] res_pjsip_logger.c: <--- Received SIP request (410 bytes) from UDP:10.200.9.64:5060 --->
ACK sip:10.200.2.38:5060 SIP/2.0
Via: SIP/2.0/UDP 10.200.9.64:5060;branch=z9hG4bK-524287-1---ce0c1dfcfb8d4532;rport
Max-Forwards: 70
Contact: <sip:2004@10.200.9.64:5060;transport=UDP>
To: <sip:nro-empresa@10.200.2.38>;tag=282bd376-08f3-4e05-ba2d-c1ad1424ae96
From: <sip:2004@10.200.2.38>;tag=64f4d036
Call-ID: 3dd9TVF5ta9wqcQaeFpz4Q..
CSeq: 2 ACK
User-Agent: Z 5.6.6 v2.10.20.5
Content-Length: 0


[Jan  8 15:50:35] DEBUG[42434] netsock2.c: Splitting '10.200.9.64' into...
[Jan  8 15:50:35] DEBUG[42434] netsock2.c: ...host '10.200.9.64' and port ''.
[Jan  8 15:50:35] DEBUG[42434] res_pjsip/pjsip_message_filter.c: Set transport 'transport-udp' on ACK from 10.200.9.64:5060
[Jan  8 15:50:35] DEBUG[42434] res_pjsip/pjsip_distributor.c: Searching for serializer associated with dialog dlg0x7f1a88034098 for Request msg ACK/cseq=2 (rdata0x7f1a8c0015c8)
[Jan  8 15:50:35] DEBUG[42434] res_pjsip/pjsip_distributor.c: Found serializer pjsip/distributor-0000003f associated with dialog dlg0x7f1a88034098
[Jan  8 15:50:35] DEBUG[42435] res_pjsip_session.c:  PJSIP/2004-00000002 TSX State: Terminated  Inv State: CONNECTING
[Jan  8 15:50:35] DEBUG[42435] res_pjsip_session.c: Function session_inv_on_tsx_state_changed called on event TSX_STATE
[Jan  8 15:50:35] DEBUG[42435] res_pjsip_session.c: The state change pertains to the endpoint '2004(PJSIP/2004-00000002)'
[Jan  8 15:50:35] DEBUG[42435] res_pjsip_session.c: The inv session does NOT have an invite_tsx
[Jan  8 15:50:35] DEBUG[42435] res_pjsip_session.c: The UAS INVITE transaction involved in this state change is 0x7f1a88037fb8
[Jan  8 15:50:35] DEBUG[42435] res_pjsip_session.c: The current transaction state is Terminated
[Jan  8 15:50:35] DEBUG[42435] res_pjsip_session.c: The transaction state change event is USER
[Jan  8 15:50:35] DEBUG[42435] res_pjsip_session.c: The current inv state is CONNECTING
[Jan  8 15:50:35] DEBUG[42435] res_pjsip_session.c:  Nothing delayed
[Jan  8 15:50:35] DEBUG[42435] res_pjsip_session.c:  PJSIP/2004-00000002 TSX State: Terminated  Inv State: CONNECTING
[Jan  8 15:50:35] DEBUG[42435] res_pjsip_session.c:  Topology: Pending: (null topology)  Active:  <0:audio-0:audio:sendrecv (alaw|ulaw|gsm)> <1:audio-1:audio:removed (nothing)>
[Jan  8 15:50:35] DEBUG[42435] res_pjsip_session.c:  
[Jan  8 15:50:35] DEBUG[42435] res_pjsip_session.c:  PJSIP/2004-00000002 Event: RX_MSG  Inv State: CONFIRMED
[Jan  8 15:50:35] DEBUG[42435] res_pjsip_session.c: Function session_inv_on_state_changed called on event RX_MSG
[Jan  8 15:50:35] DEBUG[42435] res_pjsip_session.c: The state change pertains to the endpoint '2004(PJSIP/2004-00000002)'
[Jan  8 15:50:35] DEBUG[42435] res_pjsip_session.c: The inv session does NOT have an invite_tsx
[Jan  8 15:50:35] DEBUG[42435] res_pjsip_session.c: There is no transaction involved in this state change
[Jan  8 15:50:35] DEBUG[42435] res_pjsip_session.c: The current inv state is CONFIRMED
[Jan  8 15:50:35] DEBUG[42435] res_pjsip_session.c: PJSIP/2004-00000002: Received request
[Jan  8 15:50:35] DEBUG[42435] res_pjsip_session.c:  PJSIP/2004-00000002: Method is ACK
[Jan  8 15:50:35] DEBUG[42435] chan_pjsip.c:  PJSIP/2004-00000002
[Jan  8 15:50:35] DEBUG[42435] chan_pjsip.c:  PJSIP/2004-00000002
[Jan  8 15:50:35] DEBUG[42435] chan_pjsip.c:  PJSIP/2004-00000002
[Jan  8 15:50:35] DEBUG[42435] chan_pjsip.c:  PJSIP/2004-00000002
[Jan  8 15:50:35] DEBUG[42435] res_pjsip_session.c:  PJSIP/2004-00000002
[Jan  8 15:50:35] DEBUG[42435] res_pjsip_session.c:  
[Jan  8 15:50:35] DEBUG[42435] res_pjsip_session.c:  PJSIP/2004-00000002 Request: ACK 
[Jan  8 15:50:35] DEBUG[42435] res_pjsip_session.c:  PJSIP/2004-00000002 Handled request ACK  ? yes

[Jan  8 15:50:35] DEBUG[42601][C-00000002] res_rtp_asterisk.c: 1736362227.2: Seed ts: 3750036434 current time: 1736362235.238578
[Jan  8 15:50:35] DEBUG[42603][C-00000002] res_rtp_asterisk.c: (1736362227.3) RTP ooh, format changed from none to g729
[Jan  8 15:50:35] DEBUG[42434] res_pjsip_session.c:  PJSIP/claro-00000003 TSX State: Terminated  Inv State: CONFIRMED
[Jan  8 15:50:35] DEBUG[42434] res_pjsip_session.c: Function session_inv_on_tsx_state_changed called on event TSX_STATE
[Jan  8 15:50:35] DEBUG[42434] res_pjsip_session.c: The state change pertains to the endpoint 'claro(PJSIP/claro-00000003)'
[Jan  8 15:50:35] DEBUG[42434] res_pjsip_session.c: The inv session does NOT have an invite_tsx
[Jan  8 15:50:35] DEBUG[42434] res_pjsip_session.c: The UAC PRACK transaction involved in this state change is 0x7f1a8806ebb8
[Jan  8 15:50:35] DEBUG[42434] res_pjsip_session.c: The current transaction state is Terminated
[Jan  8 15:50:35] DEBUG[42434] res_pjsip_session.c: The transaction state change event is TIMER
[Jan  8 15:50:35] DEBUG[42434] res_pjsip_session.c: The current inv state is CONFIRMED
[Jan  8 15:50:35] DEBUG[42434] res_pjsip_session.c:  Nothing delayed
[Jan  8 15:50:35] DEBUG[42434] res_pjsip_session.c:  PJSIP/claro-00000003 TSX State: Terminated  Inv State: CONFIRMED
[Jan  8 15:50:35] DEBUG[42434] res_pjsip_session.c:  Topology: Pending: (null topology)  Active:  <0:audio-0:audio:sendrecv (g729)>
[Jan  8 15:50:35] DEBUG[42434] res_pjsip_session.c:

it just a part becouse i see is limited, but appear the sip options request.

jcolp · January 8, 2025, 7:11pm

Is the res_pjsip_dlg_options module loaded?

ftardini · January 8, 2025, 7:18pm

i can’t believe it, i couldn’t find information about this anywhere. I also tryed to find if there was a module pendig to get loaded.
Now i can response to the provider.

OPTIONS sip:nro-empresa@154.2.76.218:5060 SIP/2.0
Via: SIP/2.0/UDP 154.0.185.4:5060;branch=z9hG4bKhr118210e0ihb39kf7p0sh0000g00.1
Call-ID: b27b6e8d-9767-4775-b5da-1f873a266b49
From: <sip:nro-empresa@154.0.185.4>;tag=z6szw00g-CC-24
To: nro-empresa<sip:nro-empresa@154.2.76.218>;tag=104ef0f2-63c2-4ae8-b019-7afed2738621
CSeq: 1 OPTIONS
Accept: application/sdp
Max-Forwards: 69
Content-Length: 0


<--- Transmitting SIP response (883 bytes) to UDP:154.0.185.4:5060 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 154.0.185.4:5060;rport=5060;received=154.0.185.4;branch=z9hG4bKhr118210e0ihb39kf7p0sh0000g00.1
Call-ID: b27b6e8d-9767-4775-b5da-1f873a266b49
From: <sip:nro-empresa@154.0.185.4>;tag=z6szw00g-CC-24
To: "nro-empresa" <sip:nro-empresa@154.2.76.218>;tag=104ef0f2-63c2-4ae8-b019-7afed2738621
CSeq: 1 OPTIONS
Accept: application/xpidf+xml, application/cpim-pidf+xml, application/dialog-info+xml, application/simple-message-summary, application/pidf+xml, application/pidf+xml, application/dialog-info+xml, application/simple-message-summary, application/sdp, message/sipfrag;version=2.0
Allow: OPTIONS, REGISTER, SUBSCRIBE, NOTIFY, PUBLISH, INVITE, ACK, BYE, CANCEL, UPDATE, PRACK, INFO, MESSAGE, REFER
Supported: 100rel, timer, replaces, norefersub
Accept-Encoding: identity
Accept-Language: en
Server: Asterisk PBX 20.11.0
Content-Length:  0


Thank you so much.

Topic		Replies	Views
Help with response to "OPTIONS" request issues Asterisk SIP	6	1892	April 21, 2018
Answer to "Request Options" Asterisk Support	0	238	September 1, 2008
Incorrect SIP Options Responses Asterisk Support	1	322	January 28, 2007
Asterisk 16.1.1 not responding to SIP options request from SIP provider Asterisk SIP	9	4593	May 9, 2020
Asterisk responds with 404 to OPTIONS even when an endpoint is matched Asterisk SIP	4	8528	May 13, 2020

Asterisk 20 not answer sip options request

Related topics