Pjsip TLS ERROR[XXX]: pjproject:0 <?>

jokantor · March 21, 2018, 10:07am

PJSIP TLS register extensions problem
according to the documentations I have following specification and placed following configuration into pjsip.conf
###pjsip.conf###
…
[transport-tls]
type=transport
protocol=tls
bind=0.0.0.0:5062
local_net=192.168.13.0/255.255.255.0
cert_file=/etc/asterisk/keys/asterisk.crt
priv_key_file=/etc/asterisk/keys/asterisk.key
ca_list_file=/etc/asterisk/keys/ca.txt
ca_list_path=/etc/asterisk/keys
cipher=ADH-AES256-SHA256,ADH-AES128-SHA256,ADH-AES128-GCM-SHA256,ADH-CAMELLIA256-SHA256
method=TLSv1
…

in the return I have got an error from asterisk CLI console following lines:
####CLI#####
…
[Mar 21 09:43:32] WARNING[455]: pjproject:0 <?>: SSL STATUS_FROM_SSL_ERR (status): Level: 0 err: <151441516> len: 0 [Mar 21 09:43:32] ERROR[455]: pjproject:0 <?>: ssl0x7f9b64000f70 Error loading certificate chain file ‘/etc/asterisk/keys’
[Mar 21 09:43:34] WARNING[455]: pjproject:0 <?>: SSL STATUS_FROM_SSL_ERR (status): Level: 0 err: <151441516> len: 0 [Mar 21 09:43:34] ERROR[455]: pjproject:0 <?>: ssl0x7f9b64000f70 Error loading certificate chain file ‘/etc/asterisk/keys’
…

Conclusion the extensions based on tls transport never got registered.
Any others unsecured registrations (udp, tcp ) works fine.
opensssl ver:OpenSSL 1.1.0f 25 May 2017
system debian 9.4 64bit

david551 · March 21, 2018, 10:11am

So what is your evidence that that file is present and correct?

jokantor · March 21, 2018, 10:23am

the same certificate works without any problems with any extensions on the classic sip.conf configurations (registration, calls - all works fine).
extensions registration fails (on pjsip.conf)
CLI terminal and logs shows the same error all over again.

I just looked almost everywhere and read all available documentation. So far no luck.

jcolp · March 21, 2018, 10:25am

And if you remove the ca_list_path and ca_list_file options to start with? Start simple like the tutorial[1] and then add options.

[1] https://wiki.asterisk.org/wiki/display/AST/Secure+Calling+Tutorial

jokantor · March 21, 2018, 10:35am

I did at least three times all ready.
after removing ca_list_path and ca_list_file:

pjsip reload
Module ‘res_pjsip.so’ reloaded successfully.
Module ‘res_pjsip_authenticator_digest.so’ reloaded successfully.
Module ‘res_pjsip_endpoint_identifier_ip.so’ reloaded successfully.
Module ‘res_pjsip_mwi.so’ reloaded successfully.
Module ‘res_pjsip_notify.so’ reloaded successfully.
Module ‘res_pjsip_outbound_publish.so’ reloaded successfully.
Module ‘res_pjsip_publish_asterisk.so’ reloaded successfully.
Module ‘res_pjsip_outbound_registration.so’ reloaded successfully.
– Reloading module ‘res_pjsip.so’ (Basic SIP resource)
[Mar 21 10:28:33] NOTICE[6849]: sorcery.c:1266 sorcery_object_load: Type ‘system’ is not reloadable, maintaining previous values
– Reloading module ‘res_pjsip_authenticator_digest.so’ (PJSIP authentication resource)
– Reloading module ‘res_pjsip_endpoint_identifier_ip.so’ (PJSIP IP endpoint identifier)
– Reloading module ‘res_pjsip_mwi.so’ (PJSIP MWI resource)
– Reloading module ‘res_pjsip_notify.so’ (CLI/AMI PJSIP NOTIFY Support)
– Reloading module ‘res_pjsip_outbound_publish.so’ (PJSIP Outbound Publish Support)
– Reloading module ‘res_pjsip_publish_asterisk.so’ (PJSIP Asterisk Event PUBLISH Support)
– Reloading module ‘res_pjsip_outbound_registration.so’ (PJSIP Outbound Registration Support)
[Mar 21 10:29:17] WARNING[455]: pjproject:0 <?>: SSL STATUS_FROM_SSL_ERR (status): Level: 0 err: <151441516> len: 0 [Mar 21 10:29:17] ERROR[455]: pjproject:0 <?>: ssl0x7f9b64000f70 Error loading certificate chain file ‘/etc/asterisk/keys’
[Mar 21 10:29:20] WARNING[455]: pjproject:0 <?>: SSL STATUS_FROM_SSL_ERR (status): Level: 0 err: <151441516> len: 0 [Mar 21 10:29:20] ERROR[455]: pjproject:0 <?>: ssl0x7f9b64000f70 Error loading certificate chain file ‘/etc/asterisk/keys’
[Mar 21 10:29:21] WARNING[455]: pjproject:0 <?>: SSL STATUS_FROM_SSL_ERR (status): Level: 0 err: <151441516> len: 0 [Mar 21 10:29:21] ERROR[455]: pjproject:0 <?>: ssl0x7f9b64002690 Error loading certificate chain file ‘/etc/asterisk/keys’
[Mar 21 10:29:22] WARNING[455]: pjproject:0 <?>: SSL STATUS_FROM_SSL_ERR (status): Level: 0 err: <151441516> len: 0 [Mar 21 10:29:22] ERROR[455]: pjproject:0 <?>: ssl0x7f9b64002690 Error loading certificate chain file ‘/etc/asterisk/keys’

I am sure is a tiny misconfiguration, however I tried google all does errors and find solutions not much luck.

jcolp · March 21, 2018, 10:38am

Restart Asterisk when changing transport properties to guarantee that they take effect. PJSIP internally doesn’t have a mechanism for reloading, so there is experimental code (disabled by default) to allow it but it does it in a way which may not work fully in all cases.

jokantor · March 21, 2018, 10:57am

I did
Here is the log after restarting:

###messages
…
[Mar 21 10:40:55] NOTICE[6963] loader.c: 297 modules will be loaded.
[Mar 21 10:40:55] WARNING[6963] loader.c: Error loading module ‘res_srtp.so’: /usr/lib/asterisk/modules/res_srtp.so: undefined symbol: crypto_policy_set_rtp_default
[Mar 21 10:40:55] NOTICE[6963] cdr.c: CDR simple logging enabled.
[Mar 21 10:40:55] WARNING[6963] res_phoneprov.c: Unable to find a valid server address or name.
[Mar 21 10:40:55] NOTICE[6963] sdp_translator.c: Placed ops 0x7f04a622f1e0 at slot 1
[Mar 21 10:40:55] NOTICE[6963] chan_skinny.c: Configuring skinny from skinny.conf
[Mar 21 10:40:55] ERROR[6963] ari/config.c: No configured users for ARI
[Mar 21 10:40:55] NOTICE[6963] confbridge/conf_config_parser.c: Adding default_menu menu to app_confbridge
[Mar 21 10:40:55] NOTICE[6963] cel_custom.c: No mappings found in cel_custom.conf. Not logging CEL to custom CSVs.
[Mar 21 10:40:56] WARNING[6963] res_hep_rtcp.c: res_hep is disabled; declining module load
[Mar 21 10:40:56] WARNING[6963] res_hep_pjsip.c: res_hep is disabled; declining module load
[Mar 21 10:41:15] NOTICE[7023] chan_sip.c: Peer ‘dom’ is now Reachable. (3ms / 2000ms)
[Mar 21 10:41:15] NOTICE[7023] chan_sip.c: Received SIP subscribe for peer without mailbox: dom
[Mar 21 10:41:23] WARNING[6989] pjproject: SSL SSL_ERROR_SSL (Handshake): Level: 0 err: <337092801> len: 0
[Mar 21 10:41:24] WARNING[6989] pjproject: SSL SSL_ERROR_SSL (Handshake): Level: 0 err: <337092801> len: 0
[Mar 21 10:41:25] WARNING[6989] pjproject: SSL SSL_ERROR_SSL (Handshake): Level: 0 err: <337092801> len: 0
[Mar 21 10:41:27] WARNING[6989] pjproject: SSL SSL_ERROR_SSL (Handshake): Level: 0 err: <337092801> len: 0
…

It could be related with a line:
WARNING[6963] res_phoneprov.c: Unable to find a valid server address or name.
Currently I have got two asterisk system:
Asterisk 15.3.0 built by root @ x-xxx on a x86_64 running Linux on 2018-03-19 16:36:53 UTC
Asterisk UNKNOWN__and_probably_unsupported built by root @ x-xxx on a x86_64 running Linux on 2018-03-20 19:32:37 UTC

The first one installed form source.
the other one (fresh version) form github
both shows the same error

jcolp · March 21, 2018, 11:01am

So the log is different now and the transport is created. Check the TLS negotiation using Wireshark and see if it provides any clues.

There are people using PJSIP with TLS so it does work, it just depends on the configuration of everything involved.

jokantor · March 21, 2018, 1:56pm

This is the typical communication based on the wireshark analysis.
unfortunately the system doesn’t allow me to upload any files, which I may share.

wireshark comment/info:
138 28 192.168.13.252 192.168.13.103 TCP 66 61255 → 5062 [SYN] Seq=0 Win=8192 Len=0 MSS=1460 WS=4 SACK_PERM=1
139 28 192.168.13.103 192.168.13.252 TCP 66 5062 → 61255 [SYN, ACK] Seq=0 Ack=1 Win=29200 Len=0 MSS=1460 SACK_PERM=1 WS=128
140 28 192.168.13.252 192.168.13.103 TCP 60 61255 → 5062 [ACK] Seq=1 Ack=1 Win=65700 Len=0
141 28 192.168.13.252 192.168.13.103 TCP 343 61255 → 5062 [PSH, ACK] Seq=1 Ack=1 Win=65700 Len=289
142 28 192.168.13.103 192.168.13.252 TCP 54 5062 → 61255 [ACK] Seq=1 Ack=290 Win=30336 Len=0
143 28 192.168.13.103 192.168.13.252 TCP 61 5062 → 61255 [PSH, ACK] Seq=1 Ack=290 Win=30336 Len=7
145 28 192.168.13.103 192.168.13.252 TCP 54 5062 → 61255 [FIN, ACK] Seq=8 Ack=291 Win=30336 Len=0
145 28 192.168.13.103 192.168.13.252 TCP 54 5062 → 61255 [FIN, ACK] Seq=8 Ack=291 Win=30336 Len=0
146 28 192.168.13.252 192.168.13.103 TCP 60 61255 → 5062 [ACK] Seq=291 Ack=9 Win=65692 Len=0

i seems like asterisk won’t share any info with the sip client.