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
Debug
[2020-10-29 13:03:55] DEBUG[111850]: res_mwi_devstate.c:51 mwi_update_cb: Sending not inuse devstate change for MWI:101@device
[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
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
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.
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
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
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.
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.
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.
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: