ASTERISK 16.5 and PJSIP 2.9 PROBLEMS

Asterisk Asterisk SIP
1

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)

2

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

3

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

4

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

5

The TRUNK is registration:

pjsip show registrations

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

SIPROVIDER/sip:1001@131.196.224.6:5060 auth_SIPROVIDER Registered

6

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

7

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?

8

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 .

9

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

10

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)

11

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

12

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.

13

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
14

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

15

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

16

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.

17

This topic was automatically closed 30 days after the last reply. New replies are no longer allowed.