PJSIP SSL errors every few seconds after enabling TLS

Hi all,
Facing the same issue as here:


[2020-10-13 12:10:28] WARNING[3672]: pjproject: <?>:                       SSL 6 [SSL_ERROR_ZERO_RETURN] (Read) ret: 0 len: 65535
[2020-10-13 12:10:29] WARNING[3672]: pjproject: <?>:                       SSL 6 [SSL_ERROR_ZERO_RETURN] (Read) ret: 0 len: 65535
[2020-10-13 12:10:32] WARNING[3672]: pjproject: <?>:                       SSL 6 [SSL_ERROR_ZERO_RETURN] (Read) ret: 0 len: 65535
[2020-10-13 12:10:33] WARNING[3672]: pjproject: <?>:                       SSL 6 [SSL_ERROR_ZERO_RETURN] (Read) ret: 0 len: 65535
[2020-10-13 12:10:35] WARNING[3672]: pjproject: <?>:                       SSL 6 [SSL_ERROR_ZERO_RETURN] (Read) ret: 0 len: 65535
[2020-10-13 12:10:35] WARNING[3672]: pjproject: <?>:                       SSL 6 [SSL_ERROR_ZERO_RETURN] (Read) ret: 0 len: 65535
[2020-10-13 12:10:36] WARNING[3672]: pjproject: <?>:                       SSL 6 [SSL_ERROR_ZERO_RETURN] (Read) ret: 0 len: 65535

After enabling a TLS transport using the web gui.
I don’t see any issues with calls or registrations or anything but I’d like to fix the issue - anyone have any ideas?

I see this was moved to “Providers” but these errors occur when extensions are registered using TLS. I’m using TLS to bypass some routers’s awful ALG and port fiddling.

OK, sadly this is causing issues. Phones are constantly dropping registration and quickly re-registering. I would appreciate any pointers on how I can identify the root cause here please :slight_smile:

Debug

[2020-10-29 13:03:55] DEBUG[111850]: res_mwi_devstate.c:51 mwi_update_cb: Sending not inuse devstate change for MWI:[email protected]
[2020-10-29 13:03:55] WARNING[111811]: pjproject: <?>:                     SSL 6 [SSL_ERROR_ZERO_RETURN] (Read) ret: 0 len: 65535
[2020-10-29 13:03:55] DEBUG[111811]: res_pjsip/pjsip_transport_events.c:159 transport_state_callback: Reliable transport 'tlss0x7f936c653aa8' state:DISCONNECTED
[2020-10-29 13:03:55] DEBUG[111811]: res_pjsip/pjsip_transport_events.c:159 transport_state_callback: Reliable transport 'tlss0x7f936c653aa8' state:SHUTDOWN
[2020-10-29 13:03:55] DEBUG[111811]: res_pjsip/pjsip_transport_events.c:140 transport_state_do_reg_callbacks: running callback 0x7f9304272cf6(0x7f92c0001e10) for transport tlss0x7f936c653aa8

Another instance

[2020-10-29 13:05:36] DEBUG[111812]: res_pjsip/pjsip_transport_events.c:349 ast_sip_transport_monitor_register_replace: Registered monitor 0x7f9304272cf6(0x7f92c034da20) to transport tlss0x7f936c653aa8
[2020-10-29 13:05:36] DEBUG[111812]: res_pjsip_nat.c:348 restore_orig_contact_host: Restoring contact 144.130.99.250:46890  to 192.168.111.85:12449
[2020-10-29 13:05:36] DEBUG[111812]: res_pjsip/pjsip_options.c:2111 sip_options_contact_add_task: Starting scheduled callback on AOR '110' for qualifying as there is now a contact on it
[2020-10-29 13:05:36] DEBUG[111813]: res_pjsip/pjsip_options.c:927 sip_options_qualify_aor: Qualifying all contacts on AOR '110'
[2020-10-29 13:05:36] DEBUG[111813]: res_pjsip/pjsip_options.c:857 sip_options_qualify_contact: Qualifying contact '110;@761ed8c37e59b3be6bc85c817116cc03' on AOR '110'
[2020-10-29 13:05:36] DEBUG[111813]: res_pjsip.c:4237 endpt_send_request: 0x7f92cc0065f0: Wrapper created
[2020-10-29 13:05:36] DEBUG[111813]: res_pjsip.c:4252 endpt_send_request: 0x7f92cc0065f0: Set timer to 3000 msec
[2020-10-29 13:05:36] DEBUG[111813]: res_pjsip/pjsip_resolver.c:479 sip_resolve: Performing SIP DNS resolution of target '144.130.99.250'
[2020-10-29 13:05:36] DEBUG[111813]: res_pjsip/pjsip_resolver.c:506 sip_resolve: Transport type for target '144.130.99.250' is 'TLS transport'
[2020-10-29 13:05:36] DEBUG[111813]: res_pjsip/pjsip_resolver.c:527 sip_resolve: Target '144.130.99.250' is an IP address, skipping resolution
[2020-10-29 13:05:36] DEBUG[112216]: manager.c:6200 match_filter: Examining AMI event:
Event: ContactStatus
Privilege: system,all
URI: sips:[email protected]:46890;transport=TLS;x-ast-orig-host=192.168.111.85:12449
ContactStatus: NonQualified
AOR: 110
EndpointName: 110
RoundtripUsec: 0


[2020-10-29 13:05:36] DEBUG[111961]: manager.c:6200 match_filter: Examining AMI event:
Event: ContactStatus
Privilege: system,all
URI: sips:[email protected]:46890;transport=TLS;x-ast-orig-host=192.168.111.85:12449
ContactStatus: NonQualified
AOR: 110
EndpointName: 110
RoundtripUsec: 0


[2020-10-29 13:05:36] DEBUG[111813]: res_pjsip_sips_contact.c:57 sips_contact_on_tx_request: Upgrading contact URI on outgoing SIP request to SIPS due to SIPS Request URI
[2020-10-29 13:05:36] WARNING[111811]: pjproject: <?>:                     SSL 6 [SSL_ERROR_ZERO_RETURN] (Read) ret: 0 len: 65535
[2020-10-29 13:05:36] DEBUG[111811]: res_pjsip/pjsip_transport_events.c:159 transport_state_callback: Reliable transport 'tlss0x7f936c7b1f68' state:DISCONNECTED
[2020-10-29 13:05:36] DEBUG[111811]: res_pjsip/pjsip_transport_events.c:159 transport_state_callback: Reliable transport 'tlss0x7f936c7b1f68' state:SHUTDOWN
[2020-10-29 13:05:36] DEBUG[111811]: res_pjsip/pjsip_transport_events.c:140 transport_state_do_reg_callbacks: running callback 0x7f9304272cf6(0x7f92c02efd70) for transport tlss0x7f936c7b1f68

This occurs with Asterisk 13, 15 and 16.

TLS setup can be tricky. What kind of certificate do you have installed? You will need a legitimate certificate tied to your domain name, either from Let’s Encrypt or a cert that you purchase.

Verify your cert by using a tool like testssl.sh (https://github.com/drwetter/testssl.sh). Make sure no errors appear, particularly related to the certificate chain.

Thanks for the tool, although it didn’t pick up and major issues. It’s a LE certificate and the FreePBX generated transport ends up looking like this

[0.0.0.0-tls]
type=transport
protocol=tls
bind=0.0.0.0:5061
external_media_address=x.x.x.141
external_signaling_address=x.x.x.141
ca_list_file=/etc/pki/tls/certs/ca-bundle.crt
cert_file=/etc/asterisk/keys/some.fqdn.net.au.pem
priv_key_file=/etc/asterisk/keys/some.fqdn.net.au.key
method=tlsv1_1
verify_client=no
verify_server=yes
allow_reload=no
tos=cs3
cos=3
local_net=x.x.x.128/26

I suspect it’s something on the user’s end, either their NAT is doing something weird to the TCP connections or their UACs are mis-configured in some way.

Hi @bpbp,

stop verifying the server (verify_server=no) and check if this changes the logs. If not, we need to verify if this is an issue from the local extensions or from the SIP trunk to your provider:

[2020-10-29 13:05:36] DEBUG[111813]: res_pjsip_sips_contact.c:57 sips_contact_on_tx_request: Upgrading contact URI on outgoing SIP request to SIPS due to SIPS Request URI

Thank you,

Daniel Friedman
Trixton LTD.

Hi @danielf,
Thanks for the reply. Disabling verification didn’t help. The trunk is not configured with SSL/TLS so this is an endpoint thing. Interestingly I only see it when multiple extensions are registered from a single phone (Grandstreams in this case) which again makes me think there is some issue with TCP socket reuse and NAT… but I have no idea how to fix it

Hi @bpbp,

Do your Grandstream ip phone work with TCP or TLS?
Can you remove your other endpoint registrations from the Grandstream?

Thank you,

Daniel Friedman
Trixton LTD

We;'ve seen the same issues with Yealink T4x phones and TLS/TCP with FreePBX 14/Asterisk 16, using the Let’s Encrypt certs generated by FreePBX. No solution yet…an Asterisk restart seems to solve the problem for a couple of days, but the error returns.

There is an almost 3.5 year old issue with Yealink T4xG series phones and the LE cert generated by FreePBX. If you, instead, generate a cert manually with certbot and import it, it works perfectly.

No one from Sangoma has chosen to do anything about it, and it was beyond my skill to troubleshoot.
Original thread: Yealink T4XG phones will not autoprovision over HTTPS with FreePBX 14
Issue made later: https://issues.freepbx.org/browse/FREEPBX-21011

1 Like

I haven’t looked at all the links in any detail, but looking at the differences in a default certbot cert and a fpbx cert, can you try the following and test again after generating a new fpbx cert?

sed -i 's/4096/2048/g' /var/www/html/admin/modules/certman/vendor/analogic/lescript/Lescript.php

If key length is the problem, I wouldn’t hold out much hope for the current certman being fixed, as it would mean hacking a 3rd party lib, but would be an argument to move away from that lib to acme.sh or certbot.

That does not seem to make any difference.

But I did it on a live system :stuck_out_tongue: Nothing like testing in production.

I’ll try and spin up a new instance for a better test in the next few days.

I’ll try and look it over in more detail. Key size was an obvious difference. May not be the only one.

Idea:
Did you do any long term tcpdump for one of those affected connections? I wouldn’t be surprised if there is a problem with the max packet size - TLS packets tend to be pretty big sometimes and there could be problems with mtu in consequence of if not configured correctly.

@sorvani:

The certbot and FreePBX certs look to be as close as any two certs can be. FreePBX does append the LE cross-signed root to the chain file though. Certbot does not.

Another thing to try if you’re game. Test a newly generated FreePBX cert after making the below change:

sed  -i 's|$bundle = $b|//$bundle = $b|g' /var/www/html/admin/modules/certman/Certman.class.php

Also, for reference, I am using the certbot command:

certbot certonly --agree-tos --non-interactive --email [email protected] --no-eff-email --preferred-challenges http --domains testle.jerrmdomain.com--webroot --webroot-path /var/www/html
1 Like

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