Misconfigured TLS endpoint takes down entire PBX

rootadmin108 · September 20, 2022, 3:38pm

Running FreePBX 16.0.21.18 on an Azure VM w/ 100 endpoints
PJSIP w/ TLS + SRTP is configured and working with multiple endpoints w/ TLS v1.2

While attempting to register some legacy devices (Polycom IP 650, Cisco SPA112) via TLS, we’d see multiple endpoints that are registered drop out, then re-register. Log is filled with:

WARNING[14554]: pjproject: <?>: SSL SSL_ERROR_SSL (Read): Level: 0 err: <336151576> len: 65535 peer: x.x.x.x:53597 WARNING[14554]: pjproject: <?>: SSL SSL_ERROR_SSL (Read): Level: 0 err: <336151576> len: 65535 peer: x.x.x.x:14923
WARNING[14554]: pjproject: <?>: SSL SSL_ERROR_SSL (Read): Level: 0 err: <336151576> len: 65535 peer: x.x.x.x:44431 WARNING[14554]: pjproject: <?>: SSL SSL_ERROR_SSL (Read): Level: 0 err: <336151576> len: 65535 peer: x.x.x.x:49130
WARNING[14554]: pjproject: <?>: SSL SSL_ERROR_SSL (Read): Level: 0 err: <336151576> len: 65535 peer: x.x.x.x:12093 WARNING[14554]: pjproject: <?>: SSL SSL_ERROR_SSL (Read): Level: 0 err: <336151576> len: 65535 peer: x.x.x.x:29304

I believe the “tlsv1 alert unknown ca” error is coming from the miss-configured endpoint and not the endpoints that are dropping as they correct CA cert and are on TLS 1.2. Registration is only lost when a misconfigured legacy endpoint attempts registration.

rootadmin108 · September 21, 2022, 6:16pm

I’m able to re-create this and take down other FreePBX boxes.

Am I the only one who has run into this?

jcolp · September 21, 2022, 6:26pm

I haven’t seen any reports of this elsewhere, but this would be a problem in PJSIP that Asterisk is using. What version of Asterisk is in use? If it’s the latest then an issue should be reported on the Asterisk issue tracker[1].

[1] System Dashboard - Digium/Asterisk JIRA

billsimon · September 21, 2022, 7:59pm

Are all your phones on the same network and registering from the same public IP address (through NAT)? And do you have fail2ban & firewall enabled? Good registrations should keep responsive firewall open but failed registrations will trigger fail2ban which comes earlier in the chain. Just a thought. It might not be a pjsip problem but rather a fail2ban problem, and that could probably be solved by whitelisting your network’s public IP address.

rootadmin108 · September 22, 2022, 3:36pm

Phones are registering from several remote locations, ~10-20 endpoints per location.
Nothing banned by fail2ban, and the WAN IP of each location is whitelisted.
Responsive firewall is enabled.

Asterisk v 18.9-cert1, this also occurred on Asterisk v 16 LTS

When the issue occurs, we will see task processor warnings in the logs, followed by whitelisted extensions dropping and re-registering. Initially I suspected the server did not have enough compute to handle the TLS handshakes but the server doesn’t appear to be overloaded.

Larger log output:

[2022-08-31 13:57:39] WARNING[14554]: pjproject: <?>:                      SSL SSL_ERROR_SSL (Read): Level: 0 err: <336151576> <SSL routines-ssl3_read_bytes-tlsv1 alert unknown ca> len: 65535 peer: x.x.x.x:52622
[2022-08-31 13:57:45] WARNING[14554]: pjproject: <?>:                      SSL SSL_ERROR_SSL (Read): Level: 0 err: <336151576> <SSL routines-ssl3_read_bytes-tlsv1 alert unknown ca> len: 65535 peer: x.x.x.x:40443
[2022-08-31 13:57:45] WARNING[11077]: pjproject: <?>:        tsx0x7fb1787ad258 .......Error sending Response msg 200/SUBSCRIBE/cseq=3 (tdta0x7fb180018018): Invalid operation (PJ_EINVALIDOP)
[2022-08-31 13:57:47] WARNING[14554]: pjproject: <?>:                      SSL 6 [SSL_ERROR_ZERO_RETURN] (Read) ret: 0 len: 65535
[2022-08-31 13:57:48] WARNING[14554]: pjproject: <?>:                      SSL 6 [SSL_ERROR_ZERO_RETURN] (Read) ret: 0 len: 65535
[2022-08-31 13:57:49] WARNING[14554]: pjproject: <?>:                      SSL 6 [SSL_ERROR_ZERO_RETURN] (Read) ret: 0 len: 65535
[2022-08-31 13:58:00] WARNING[14554]: pjproject: <?>:                      SSL SSL_ERROR_SSL (Read): Level: 0 err: <336151576> <SSL routines-ssl3_read_bytes-tlsv1 alert unknown ca> len: 65535 peer: x.x.x.x:33405
[2022-08-31 13:58:28] WARNING[14554]: pjproject: <?>:                      SSL SSL_ERROR_SSL (Read): Level: 0 err: <336151576> <SSL routines-ssl3_read_bytes-tlsv1 alert unknown ca> len: 65535 peer: x.x.x.x:64374
[2022-08-31 13:58:39] WARNING[14554]: pjproject: <?>:                      SSL SSL_ERROR_SSL (Read): Level: 0 err: <336151576> <SSL routines-ssl3_read_bytes-tlsv1 alert unknown ca> len: 65535 peer: y.y.y.y:29665
[2022-08-31 13:58:42] WARNING[14554]: pjproject: <?>:                      SSL SSL_ERROR_SSL (Read): Level: 0 err: <336151576> <SSL routines-ssl3_read_bytes-tlsv1 alert unknown ca> len: 65535 peer: x.x.x.x:40806
[2022-08-31 13:59:14] WARNING[14554]: pjproject: <?>:                      SSL 6 [SSL_ERROR_ZERO_RETURN] (Read) ret: 0 len: 65535
[2022-08-31 13:59:18] WARNING[14554]: pjproject: <?>:                      SSL 6 [SSL_ERROR_ZERO_RETURN] (Read) ret: 0 len: 65535
[2022-08-31 13:59:18] WARNING[22384]: pjproject: <?>:        tsx0x7fb18c008268 ...Error sending Response msg 200/SUBSCRIBE/cseq=2 (tdta0x7fb1783cc418): Invalid operation (PJ_EINVALIDOP)
[2022-08-31 13:59:21] WARNING[14554]: pjproject: <?>:                      SSL 6 [SSL_ERROR_ZERO_RETURN] (Read) ret: 0 len: 65535
[2022-08-31 13:59:22] WARNING[14554]: pjproject: <?>:                      SSL 6 [SSL_ERROR_ZERO_RETURN] (Read) ret: 0 len: 65535
[2022-08-31 13:59:14] WARNING[14554]: pjproject: <?>:                      SSL 6 [SSL_ERROR_ZERO_RETURN] (Read) ret: 0 len: 65535
[2022-08-31 13:59:18] WARNING[14554]: pjproject: <?>:                      SSL 6 [SSL_ERROR_ZERO_RETURN] (Read) ret: 0 len: 65535
[2022-08-31 13:59:18] WARNING[22384]: pjproject: <?>:        tsx0x7fb18c008268 ...Error sending Response msg 200/SUBSCRIBE/cseq=2 (tdta0x7fb1783cc418): Invalid operation (PJ_EINVALIDOP)
[2022-08-31 13:59:21] WARNING[14554]: pjproject: <?>:                      SSL 6 [SSL_ERROR_ZERO_RETURN] (Read) ret: 0 len: 65535
[2022-08-31 13:59:22] WARNING[14554]: pjproject: <?>:                      SSL 6 [SSL_ERROR_ZERO_RETURN] (Read) ret: 0 len: 65535
[2022-08-31 13:59:39] WARNING[14554]: pjproject: <?>:                      SSL SSL_ERROR_SSL (Read): Level: 0 err: <336151576> <SSL routines-ssl3_read_bytes-tlsv1 alert unknown ca> len: 65535 peer: x.x.x.x:34461
[2022-08-31 13:59:47] WARNING[14554]: pjproject: <?>:                      SSL 6 [SSL_ERROR_ZERO_RETURN] (Read) ret: 0 len: 65535
[2022-08-31 13:59:59] WARNING[14554]: pjproject: <?>:                      SSL SSL_ERROR_SSL (Read): Level: 0 err: <336151576> <SSL routines-ssl3_read_bytes-tlsv1 alert unknown ca> len: 65535 peer: x.x.x.x:43086
[2022-08-31 14:00:02] WARNING[14554]: pjproject: <?>:                      SSL 6 [SSL_ERROR_ZERO_RETURN] (Read) ret: 0 len: 65535
[2022-08-31 14:00:12] WARNING[14554]: pjproject: <?>:                      SSL 6 [SSL_ERROR_ZERO_RETURN] (Read) ret: 0 len: 65535
[2022-08-31 14:00:20] WARNING[14554]: pjproject: <?>:                      SSL SSL_ERROR_SSL (Read): Level: 0 err: <336151576> <SSL routines-ssl3_read_bytes-tlsv1 alert unknown ca> len: 65535 peer: a.a.a.a:53597
[2022-08-31 14:00:49] WARNING[14554]: pjproject: <?>:                      SSL SSL_ERROR_SSL (Read): Level: 0 err: <336151576> <SSL routines-ssl3_read_bytes-tlsv1 alert unknown ca> len: 65535 peer: d.d.d.d:14923
[2022-08-31 14:01:02] WARNING[14554]: pjproject: <?>:                      SSL SSL_ERROR_SSL (Read): Level: 0 err: <336151576> <SSL routines-ssl3_read_bytes-tlsv1 alert unknown ca> len: 65535 peer: x.x.x.x:44431
[2022-08-31 14:01:10] WARNING[14554]: pjproject: <?>:                      SSL SSL_ERROR_SSL (Read): Level: 0 err: <336151576> <SSL routines-ssl3_read_bytes-tlsv1 alert unknown ca> len: 65535 peer: x.x.x.x:49130
[2022-08-31 14:01:16] WARNING[14554]: pjproject: <?>:                      SSL SSL_ERROR_SSL (Read): Level: 0 err: <336151576> <SSL routines-ssl3_read_bytes-tlsv1 alert unknown ca> len: 65535 peer: y.y.y.y:12093
[2022-08-31 14:01:30] WARNING[14554]: pjproject: <?>:                      SSL SSL_ERROR_SSL (Read): Level: 0 err: <336151576> <SSL routines-ssl3_read_bytes-tlsv1 alert unknown ca> len: 65535 peer: g.g.g.g:29304
[2022-08-31 14:01:39] WARNING[14554]: pjproject: <?>:                      SSL 6 [SSL_ERROR_ZERO_RETURN] (Read) ret: 0 len: 65535
[2022-08-31 14:01:45] WARNING[14554]: pjproject: <?>:                      SSL SSL_ERROR_SSL (Read): Level: 0 err: <336151576> <SSL routines-ssl3_read_bytes-tlsv1 alert unknown ca> len: 65535 peer: x.x.x.x:35193
[2022-08-31 14:01:46] WARNING[14554]: pjproject: <?>:                      SSL 6 [SSL_ERROR_ZERO_RETURN] (Read) ret: 0 len: 65535
[2022-08-31 14:01:47] WARNING[14554]: pjproject: <?>:                      SSL 6 [SSL_ERROR_ZERO_RETURN] (Read) ret: 0 len: 65535
[2022-08-31 14:01:48] WARNING[14554]: pjproject: <?>:                      SSL 6 [SSL_ERROR_ZERO_RETURN] (Read) ret: 0 len: 65535
[2022-08-31 14:01:51] WARNING[14554]: pjproject: <?>:                      SSL SSL_ERROR_SSL (Read): Level: 0 err: <336151576> <SSL routines-ssl3_read_bytes-tlsv1 alert unknown ca> len: 65535 peer: x.x.x.x:35666
[2022-08-31 14:02:13] WARNING[14554]: pjproject: <?>:                      SSL SSL_ERROR_SSL (Read): Level: 0 err: <336151576> <SSL routines-ssl3_read_bytes-tlsv1 alert unknown ca> len: 65535 peer: g.g.g.g:60779
[2022-08-31 14:02:13] WARNING[24144]: pjproject: <?>:        tsx0x7fb1841029d8 ..Error sending Response msg 200/REGISTER/cseq=2 (tdta0x24d69f8): Invalid operation (PJ_EINVALIDOP)
[2022-08-31 14:02:26] WARNING[14554]: pjproject: <?>:                      SSL SSL_ERROR_SSL (Read): Level: 0 err: <336151576> <SSL routines-ssl3_read_bytes-tlsv1 alert unknown ca> len: 65535 peer: f.f.f.f:40252
[2022-08-31 14:03:01] WARNING[14554]: pjproject: <?>:                      SSL SSL_ERROR_SSL (Read): Level: 0 err: <336151576> <SSL routines-ssl3_read_bytes-tlsv1 alert unknown ca> len: 65535 peer: c.c.c.c:57403
[2022-08-31 14:03:43] WARNING[14554]: pjproject: <?>:                      SSL SSL_ERROR_SSL (Read): Level: 0 err: <336151576> <SSL routines-ssl3_read_bytes-tlsv1 alert unknown ca> len: 65535 peer: g.g.g.g:50017
[2022-08-31 14:03:57] WARNING[14554]: pjproject: <?>:                      SSL SSL_ERROR_SSL (Read): Level: 0 err: <336151576> <SSL routines-ssl3_read_bytes-tlsv1 alert unknown ca> len: 65535 peer: g.g.g.g:60025
[2022-08-31 14:03:57] WARNING[3214]: pjproject: <?>:         tsx0x7fb17851c6e8 ...Error sending Response msg 200/SUBSCRIBE/cseq=2 (tdta0x7fb19c0e1f08): Invalid operation (PJ_EINVALIDOP)
[2022-08-31 14:04:12] WARNING[14554]: pjproject: <?>:                      SSL SSL_ERROR_SSL (Read): Level: 0 err: <336151576> <SSL routines-ssl3_read_bytes-tlsv1 alert unknown ca> len: 65535 peer: y.y.y.y:15599
[2022-08-31 14:04:33] WARNING[14554]: pjproject: <?>:                      SSL SSL_ERROR_SSL (Read): Level: 0 err: <336151576> <SSL routines-ssl3_read_bytes-tlsv1 alert unknown ca> len: 65535 peer: g.g.g.g:58542
[2022-08-31 14:04:33] WARNING[32568]: pjproject: <?>:        tsx0x7fb18c0a6f38 ..Error sending Response msg 200/REGISTER/cseq=2 (tdta0x7fb18006dde8): Invalid operation (PJ_EINVALIDOP)
[2022-08-31 14:04:47] WARNING[14554]: pjproject: <?>:                      SSL SSL_ERROR_SSL (Read): Level: 0 err: <336151576> <SSL routines-ssl3_read_bytes-tlsv1 alert unknown ca> len: 65535 peer: c.c.c.c:48150
[2022-08-31 14:05:01] WARNING[14554]: pjproject: <?>:                      SSL SSL_ERROR_SSL (Read): Level: 0 err: <336151576> <SSL routines-ssl3_read_bytes-tlsv1 alert unknown ca> len: 65535 peer: x.x.x.x:32917
[2022-08-31 14:05:21] WARNING[14554]: pjproject: <?>:                      SSL SSL_ERROR_SSL (Read): Level: 0 err: <336151576> <SSL routines-ssl3_read_bytes-tlsv1 alert unknown ca> len: 65535 peer: f.f.f.f:18389
[2022-08-31 14:05:42] WARNING[14554]: pjproject: <?>:                      SSL SSL_ERROR_SSL (Read): Level: 0 err: <336151576> <SSL routines-ssl3_read_bytes-tlsv1 alert unknown ca> len: 65535 peer: d.d.d.d:12335
[2022-08-31 14:05:48] WARNING[14554]: pjproject: <?>:                      SSL SSL_ERROR_SSL (Read): Level: 0 err: <336151576> <SSL routines-ssl3_read_bytes-tlsv1 alert unknown ca> len: 65535 peer: i.i.i.i:5061
[2022-08-31 14:05:56] WARNING[14554]: pjproject: <?>:                      SSL SSL_ERROR_SSL (Read): Level: 0 err: <336151576> <SSL routines-ssl3_read_bytes-tlsv1 alert unknown ca> len: 65535 peer: x.x.x.x:61180
[2022-08-31 14:06:17] WARNING[14554]: pjproject: <?>:                      SSL SSL_ERROR_SSL (Read): Level: 0 err: <336151576> <SSL routines-ssl3_read_bytes-tlsv1 alert unknown ca> len: 65535 peer: f.f.f.f:32749
[2022-08-31 14:06:45] WARNING[14554]: pjproject: <?>:                      SSL SSL_ERROR_SSL (Read): Level: 0 err: <336151576> <SSL routines-ssl3_read_bytes-tlsv1 alert unknown ca> len: 65535 peer: x.x.x.x:37297
[2022-08-31 14:06:47] WARNING[14554]: pjproject: <?>:                      SSL 6 [SSL_ERROR_ZERO_RETURN] (Read) ret: 0 len: 65535
[2022-08-31 14:06:48] WARNING[14554]: pjproject: <?>:                      SSL 6 [SSL_ERROR_ZERO_RETURN] (Read) ret: 0 len: 65535
[2022-08-31 14:06:49] WARNING[14554]: pjproject: <?>:                      SSL 6 [SSL_ERROR_ZERO_RETURN] (Read) ret: 0 len: 65535
[2022-08-31 14:06:50] WARNING[14554]: pjproject: <?>:                      SSL 6 [SSL_ERROR_ZERO_RETURN] (Read) ret: 0 len: 65535
[2022-08-31 14:07:20] WARNING[14554]: pjproject: <?>:                      SSL SSL_ERROR_SSL (Read): Level: 0 err: <336151576> <SSL routines-ssl3_read_bytes-tlsv1 alert unknown ca> len: 65535 peer: h.h.h.h:50809
[2022-08-31 14:07:28] WARNING[14554]: pjproject: <?>:                      SSL SSL_ERROR_SSL (Read): Level: 0 err: <336151576> <SSL routines-ssl3_read_bytes-tlsv1 alert unknown ca> len: 65535 peer: i.i.i.i:5061
[2022-08-31 14:07:34] WARNING[14554]: pjproject: <?>:                      SSL SSL_ERROR_SSL (Read): Level: 0 err: <336151576> <SSL routines-ssl3_read_bytes-tlsv1 alert unknown ca> len: 65535 peer: x.x.x.x:39038
[2022-08-31 14:07:56] WARNING[14554]: pjproject: <?>:                      SSL SSL_ERROR_SSL (Read): Level: 0 err: <336151576> <SSL routines-ssl3_read_bytes-tlsv1 alert unknown ca> len: 65535 peer: x.x.x.x:33007
[2022-08-31 14:08:02] WARNING[14554]: pjproject: <?>:                      SSL SSL_ERROR_SSL (Read): Level: 0 err: <336151576> <SSL routines-ssl3_read_bytes-tlsv1 alert unknown ca> len: 65535 peer: e.e.e.e:33708
[2022-08-31 14:08:04] WARNING[14554]: pjproject: <?>:                      SSL 6 [SSL_ERROR_ZERO_RETURN] (Read) ret: 0 len: 65535
[2022-08-31 14:08:05] WARNING[14554]: pjproject: <?>:                      SSL 6 [SSL_ERROR_ZERO_RETURN] (Read) ret: 0 len: 65535
[2022-08-31 14:08:32] WARNING[18129][C-000000f1]: taskprocessor.c:1225 taskprocessor_push: The 'stasis/m:channel:all-000000a6' task processor queue reached 500 scheduled tasks again.
[2022-08-31 14:08:42] WARNING[14554]: pjproject: <?>:                      SSL SSL_ERROR_SSL (Read): Level: 0 err: <336151576> <SSL routines-ssl3_read_bytes-tlsv1 alert unknown ca> len: 65535 peer: y.y.y.y:15599
[2022-08-31 14:08:50] WARNING[14554]: pjproject: <?>:                      SSL SSL_ERROR_SSL (Read): Level: 0 err: <336151576> <SSL routines-ssl3_read_bytes-tlsv1 alert unknown ca> len: 65535 peer: x.x.x.x:44276
[2022-08-31 14:08:51] WARNING[14554]: pjproject: <?>:                      SSL 6 [SSL_ERROR_ZERO_RETURN] (Read) ret: 0 len: 65535
[2022-08-31 14:08:52] WARNING[14554]: pjproject: <?>:                      SSL 6 [SSL_ERROR_ZERO_RETURN] (Read) ret: 0 len: 65535
[2022-08-31 14:08:53] WARNING[14554]: pjproject: <?>:                      SSL 6 [SSL_ERROR_ZERO_RETURN] (Read) ret: 0 len: 65535
[2022-08-31 14:08:55] WARNING[14554]: pjproject: <?>:                      SSL 6 [SSL_ERROR_ZERO_RETURN] (Read) ret: 0 len: 65535
[2022-08-31 14:08:56] WARNING[14554]: pjproject: <?>:                      SSL SSL_ERROR_SSL (Read): Level: 0 err: <336151576> <SSL routines-ssl3_read_bytes-tlsv1 alert unknown ca> len: 65535 peer: x.x.x.x:53403
[2022-08-31 14:09:46] WARNING[14554]: pjproject: <?>:                      SSL SSL_ERROR_SSL (Read): Level: 0 err: <336151576> <SSL routines-ssl3_read_bytes-tlsv1 alert unknown ca> len: 65535 peer: x.x.x.x:61094
[2022-08-31 14:09:52] WARNING[14554]: pjproject: <?>:                      SSL SSL_ERROR_SSL (Read): Level: 0 err: <336151576> <SSL routines-ssl3_read_bytes-tlsv1 alert unknown ca> len: 65535 peer: c.c.c.c:40666

dicko · September 22, 2022, 3:54pm

Good point, if
" will trigger fail2ban which comes earlier in the chain."
but Fail2Ban can be configured to insert it’s ‘chains’ anywhere in iptables, why does FreePBX defer to fail2ban ?

(Reference in all current jail.conf

# Specify chain where jumps would need to be added in iptables-* actions
chain = INPUT

)

Replace INPUT with the cleverer FreePBX exit chain.

michaelp713 · October 17, 2022, 7:58pm

Anyone else seeing this issue, had it happen on a production system as well, all phones went to showing log entires:
WARNING[8007]: pjproject: <?>: SSL 6 [SSL_ERROR_ZERO_RETURN] (Read) ret: 0 len: 65535

I diid show all registered phones dropped and a few rejoined, but the majority of phones just threw the SSL error in the asterisk log.

An asterisk restart fixed the problem, but causes the system to lose all queued calls.

Using LE cert. Was not expired, but was seeing log messages like:
WARNING[8007] pjproject: SSL SSL_ERROR_SSL (Read): Level: 0 err: <336151570> SSL routines-ssl3_read_bytes-sslv3 alert bad certificate - len: 65535 peer: 24.95.112.22:12486

rootadmin108 · October 20, 2022, 9:03pm

We never found a solution to this issue. I can recreate it by registering 1-2 Polycom VVX 301s or IP650 phones with TLS enabled. After 30s - 1min, endpoints start to drop off.

system · November 20, 2022, 9:04pm

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