ASTERISK 16.5 and PJSIP 2.9 PROBLEMS

Hello I have a problem with asterisk 16.5 and PJSIP 2.9

Many times we can’t make a calls, we received CONGESTION,

look debug log.

we received “TRANSPORT ERROR” in log.

[Aug 21 21:24:48] DEBUG[19557]: netsock2.c:170 ast_sockaddr_split_hostport: Splitting ‘131.196.225.254’ into…
[Aug 21 21:24:48] DEBUG[19557]: netsock2.c:224 ast_sockaddr_split_hostport: …host ‘131.196.225.254’ and port ‘’.
[Aug 21 21:24:48] DEBUG[19557]: netsock2.c:170 ast_sockaddr_split_hostport: Splitting ‘131.196.225.254’ into…
[Aug 21 21:24:48] DEBUG[19557]: netsock2.c:224 ast_sockaddr_split_hostport: …host ‘’ and port ‘’.
[Aug 21 21:24:48] DEBUG[19557]: rtp_engine.c:543 ast_rtp_instance_new: RTP instance ‘0x7fb82c0379f0’ is setup and ready to go
[Aug 21 21:24:48] DEBUG[19557]: netsock2.c:170 ast_sockaddr_split_hostport: Splitting ‘SERVER’ into…
[Aug 21 21:24:48] DEBUG[19557]: netsock2.c:224 ast_sockaddr_split_hostport: …host ‘SERVER’ and port ‘’.
[Aug 21 21:24:48] DEBUG[19557]: res_rtp_asterisk.c:7783 ast_rtp_prop_set: Setup RTCP on RTP instance ‘0x7fb82c0379f0’
[Aug 21 21:24:48] DEBUG[19557]: res_pjsip_session.c:3444 handle_outgoing_request: Method is INVITE
[Aug 21 21:24:48] DEBUG[19557]: res_pjsip/pjsip_resolver.c:477 sip_resolve: Performing SIP DNS resolution of target ‘131.196.224.6’
[Aug 21 21:24:48] DEBUG[19557]: res_pjsip/pjsip_resolver.c:504 sip_resolve: Transport type for target ‘131.196.224.6’ is ‘UDP’
[Aug 21 21:24:48] DEBUG[19557]: res_pjsip/pjsip_resolver.c:525 sip_resolve: Target ‘131.196.224.6’ is an IP address, skipping resolution
[Aug 21 21:24:48] DEBUG[19557]: res_pjsip_session.c:3315 __print_debug_details: Function session_inv_on_state_changed called on event TSX_STATE
[Aug 21 21:24:48] DEBUG[19557]: res_pjsip_session.c:3329 __print_debug_details: The state change pertains to the endpoint ‘SIPROVIDER(PJSIP/SIPROVIDER-00000009)’
[Aug 21 21:24:48] DEBUG[19557]: res_pjsip_session.c:3334 __print_debug_details: The inv session still has an invite_tsx (0x7fb82c0203c8)
[Aug 21 21:24:48] DEBUG[19557]: res_pjsip_session.c:3349 __print_debug_details: There is no transaction involved in this state change
[Aug 21 21:24:48] DEBUG[19557]: res_pjsip_session.c:3351 __print_debug_details: The current inv state is DISCONNCTD
[Aug 21 21:24:48] DEBUG[19557]: res_pjsip_session.c:3590 session_inv_on_state_changed: Source of transaction state change is TRANSPORT_ERROR
[Aug 21 21:24:48] DEBUG[19557]: res_pjsip_session.c:3315 __print_debug_details: Function session_inv_on_tsx_state_changed called on event TSX_STATE
[Aug 21 21:24:48] DEBUG[19557]: res_pjsip_session.c:3329 __print_debug_details: The state change pertains to the endpoint ‘SIPROVIDER(PJSIP/SIPROVIDER-00000009)’
[Aug 21 21:24:48] DEBUG[19557]: res_pjsip_session.c:3337 __print_debug_details: The inv session does NOT have an invite_tsx
[Aug 21 21:24:48] DEBUG[19557]: res_pjsip_session.c:3340 __print_debug_details: The UAC INVITE transaction involved in this state change is 0x7fb82c0203c8
[Aug 21 21:24:48] DEBUG[19557]: res_pjsip_session.c:3344 __print_debug_details: The current transaction state is Terminated
[Aug 21 21:24:48] DEBUG[19557]: res_pjsip_session.c:3346 __print_debug_details: The transaction state change event is TRANSPORT_ERROR
[Aug 21 21:24:48] DEBUG[19557]: res_pjsip_session.c:3351 __print_debug_details: The current inv state is DISCONNCTD
[Aug 21 21:24:48] DEBUG[20592][C-00000005]: channel.c:2566 ast_hangup: Channel 0x7fb8c0001230 ‘PJSIP/SIPROVIDER-00000009’ hanging up. Refs: 2
[Aug 21 21:24:48] DEBUG[19546]: cdr.c:1474 cdr_object_finalize: Finalized CDR for PJSIP/9301-00000008 - start 1566433488.689594 answer 0.000000 end 1566433488.778006 dispo CONGESTION
== Everyone is busy/congested at this time (1:0/1/0)

I discovered , For any changes in pjsip.conf I need execute : pjsip send register *all . always,

if I change any configuration in endpoint. I need execute the command.

if I change any configuration in other pjsip settings I need execute command "pjsip send register *all)

In version of Asterisk 16.4.1 dont need, the trunk keep register on

If you issue “pjsip set logger on”, does that give more information?

Yes I can do that.

In logger I Received 503

<— Transmitting SIP response (544 bytes) to UDP:187.122.124.227:22582 —>
SIP/2.0 503 Service Unavailable
Via: SIP/2.0/UDP 187.122.124.227:22582;rport=22582;received=187.122.124.227;branch=z9hG4bKPjYm8Wala7WFZZaRCggldc60A2aFe1eGGQ
Call-ID: r866bGwqSk1lvR.M1RfZcjqhY5UsDdZf
From: “9301” sip:9301@131.196.225.2;tag=rIF1mXAy8MhQ73ThYBY-9zL0T6lyYBfO
To: sip:08007727271@131.196.225.2;tag=ef9963aa-28ff-497b-ba74-dbe05e1b424e
CSeq: 4510 INVITE
Server: asterisk
Allow: OPTIONS, REGISTER, SUBSCRIBE, NOTIFY, PUBLISH, INVITE, ACK, BYE, CANCEL, UPDATE, MESSAGE, REFER
Reason: Q.850;cause=34
Content-Length: 0

The TRUNK is registration:

pjsip show registrations

<Registration/ServerURI…> <Auth…> <Status…>

SIPROVIDER/sip:1001@131.196.224.6:5060 auth_SIPROVIDER Registered

But 503 return to my endpoint , the asterisk don’t create channel to SIPPROVIDER

503 means “Service Unavailable”, maybe due to maintenance. Did you check with the provider whether their system is still working, or whether they see something unusual with your account?

Yes, I am provider. The problem is in Asterisk, I did make many tests always we change anything in pjsip.conf and after pjesip reload, I need make pjsip send register *all again .

503 is the catchall error response. However, without the failing request, and more detailed logging, I don’t see how we can go further.

This log from asterisk

[Aug 22 14:10:33] DEBUG [31610]: res_pjsip_session.c : 3444 handle_outgoing_request : Method is INVITE

[Aug 22 14:10:33] DEBUG [31610]: res_pjsip/pjsip_resolver.c : 477 sip_resolve : Performing SIP DNS resolution of target '131.196.224.6’

[Aug 22 14:10:33] DEBUG [31610]: res_pjsip/pjsip_resolver.c : 504 sip_resolve : Transport type for target ‘131.196.224.6’ is 'UDP’

[Aug 22 14:10:33] DEBUG [31610]: res_pjsip/pjsip_resolver.c : 525 sip_resolve : Target ‘131.196.224.6’ is an IP address, skipping resolution

[Aug 22 14:10:33] DEBUG [31610]: res_pjsip_session.c : 3315 __print_debug_details : Function session_inv_on_state_changed called on event TSX_STATE

[Aug 22 14:10:33] DEBUG [31610]: res_pjsip_session.c : 3329 __print_debug_details : The state change pertains to the endpoint 'SIPROVIDER(PJSIP/SIPROVIDER-00000022)'

[Aug 22 14:10:33] DEBUG [31610]: res_pjsip_session.c : 3334 __print_debug_details : The inv session still has an invite_tsx (0x7f86c80a2de8)

[Aug 22 14:10:33] DEBUG [31610]: res_pjsip_session.c : 3349 __print_debug_details : There is no transaction involved in this state change

[Aug 22 14:10:33] DEBUG [31610]: res_pjsip_session.c : 3351 __print_debug_details : The current inv state is DISCONNCTD

[Aug 22 14:10:33] DEBUG [31610]: res_pjsip_session.c : 3590 session_inv_on_state_changed : Source of transaction state change is TRANSPORT_ERROR

[Aug 22 14:10:33] DEBUG [31610]: res_pjsip_session.c : 3315 __print_debug_details : Function session_inv_on_tsx_state_changed called on event TSX_STATE

[Aug 22 14:10:33] DEBUG [31610]: res_pjsip_session.c : 3329 __print_debug_details : The state change pertains to the endpoint 'SIPROVIDER(PJSIP/SIPROVIDER-00000022)'

[Aug 22 14:10:33] DEBUG [31610]: res_pjsip_session.c : 3337 __print_debug_details : The inv session does NOT have an invite_tsx

[Aug 22 14:10:33] DEBUG [31610]: res_pjsip_session.c : 3340 __print_debug_details : The UAC INVITE transaction involved in this state change is 0x7f86c80a2de8

[Aug 22 14:10:33] DEBUG [31610]: res_pjsip_session.c : 3344 __print_debug_details : The current transaction state is Terminated

[Aug 22 14:10:33] DEBUG [31610]: res_pjsip_session.c : 3346 __print_debug_details : The transaction state change event is TRANSPORT_ERROR

[Aug 22 14:10:33] DEBUG [31610]: res_pjsip_session.c : 3351 __print_debug_details : The current inv state is DISCONNCTD

[Aug 22 14:10:33] DEBUG [19476][C-00000012]: channel.c : 2566 ast_hangup : Channel 0x7f8728003f40 ‘PJSIP/SIPROVIDER-00000022’ hanging up. Refs: 2

[Aug 22 14:10:33] DEBUG [24873]: cdr.c : 1474 cdr_object_finalize : Finalized CDR for PJSIP/9301-00000021 - start 1566493833.002813 answer 0.000000 end 1566493833.055137 dispo CONGESTION

== Everyone is busy/congested at this time (1:0/1/0)

sounds interesting. Can you post an entire SIP-Session?

The problem is the asterisk don’t create channel with SIPPROVIDER,

ENDPOINT: 9301
TRUNK: SIPPROVIDER

When a make a call we have sessions with 9301 but we don’t have session with SIPPROVIDER, only work if I execute command:" pjsip send register *all" so the asterisk register trunks again.

After this commando Asterisk register trunks again and all sessions sip work

But if you change anynthing in pjsip.conf and execute : pjsip reload,
The trunks stop, and you dont have any session SIP with this trunk. you need register again all trunks for go back work.

Log from pjproject level 3

[Aug 24 19:56:38] DEBUG[7254]: pjproject: <?>: stun_session.c STUN session 0x7f041402afc8 destroyed
[Aug 24 19:56:38] DEBUG[7254]: pjproject: <?>: endpoint Request msg INVITE/cseq=32633 (tdta0x7f03f4018828) created.
[Aug 24 19:56:38] DEBUG[7254]: pjproject: <?>: dlg0x7f03f403b558 Module WebSocket Transport Module added as dialog usage, data=(nil)
[Aug 24 19:56:38] DEBUG[7254]: pjproject: <?>: dlg0x7f03f403b558 Module NAT added as dialog usage, data=(nil)
[Aug 24 19:56:38] DEBUG[7254]: pjproject: <?>: inv0x7f03f403b558 .Sending Request msg INVITE/cseq=32633 (tdta0x7f03f4018828)
[Aug 24 19:56:38] DEBUG[7254]: pjproject: <?>: dlg0x7f03f403b558 …Sending Request msg INVITE/cseq=32633 (tdta0x7f03f4018828)
[Aug 24 19:56:38] DEBUG[7254]: pjproject: <?>: tsx0x7f03f401b838 …Transaction created for Request msg INVITE/cseq=32632 (tdta0x7f03f4018828)
[Aug 24 19:56:38] DEBUG[7254]: pjproject: <?>: tsx0x7f03f401b838 …Sending Request msg INVITE/cseq=32632 (tdta0x7f03f4018828) in state Null
[Aug 24 19:56:38] DEBUG[7254]: pjproject: <?>: tsx0x7f03f401b838 …Failed to send Request msg INVITE/cseq=32632 (tdta0x7f03f4018828)! err=171060 (Unsupported transport (PJSIP_EUNSUPTRANSPORT))
[Aug 24 19:56:38] DEBUG[7254]: pjproject: <?>: tsx0x7f03f401b838 …State changed from Null to Terminated, event=TRANSPORT_ERROR
[Aug 24 19:56:38] DEBUG[7254]: pjproject: <?>: dlg0x7f03f403b558 …Transaction tsx0x7f03f401b838 state changed to Terminated
[Aug 24 19:56:38] DEBUG[7254]: pjproject: <?>: dlg0x7f03f403b558 …Session count dec to 3 by mod-invite

After more tests, I discovered always I execute pjsip reload, the trunk fail.

and i receive

’Unsupported transport (PJSIP_EUNSUPTRANSPORT)’ sending OPTIONS request to endpoint

Finally , if in transport configuration have

allow_reload=yes

after any changes in PJSIP.conf after pjsip reload, the trunks stop

in version 16.4.1 this don’t happens.

This happen in versions asterisk 16.5 and 17-rc0

The solution is allow_reload=no, and after any changes in transports we restart asterisk for validate

Reloading transports in the PJSIP library isn’t really supported, the functionality is a hacked up approach (thus why it’s an option and disabled by default). I really don’t recommend using it in general.