[squid-users] FATAL: The ssl_crtd helpers are crashing too rapidly, need help!

Hi all, Amos.

I've been running 3.2.1 for 2-3 of weeks in production. All was well for
a couple of weeks, but over the last few days, approximately every 2
days we get people saying they have lost web access. This coincided with
the above error message repeating and squid workers constantly restarting.

This morning I had a look back in the logs and it seemingly started just
after this point:

2012/09/11 10:13:32 kid1| WARNING: ssl_crtd #1 exited
2012/09/11 10:13:32 kid1| Too few ssl_crtd processes are running (need 1/32)
2012/09/11 10:13:32 kid1| Starting new helpers
2012/09/11 10:13:32 kid1| helperOpenServers: Starting 1/32 'ssl_crtd'
processes
2012/09/11 10:13:32 kid1| client_side.cc(3477) sslCrtdHandleReply:
"ssl_crtd" helper return <NULL> reply
2012/09/11 10:13:33 kid1| clientNegotiateSSL: Error negotiating SSL
connection on FD 315: error:14094412:SSL routines:SSL3_READ_BYTES:sslv3
alert bad certificate (1/0)
(ssl_crtd): Cannot create ssl certificate or private key.
2012/09/11 10:19:08 kid1| WARNING: ssl_crtd #1 exited
2012/09/11 10:19:08 kid1| Too few ssl_crtd processes are running (need 1/32)
2012/09/11 10:19:08 kid1| Starting new helpers
2012/09/11 10:19:08 kid1| helperOpenServers: Starting 1/32 'ssl_crtd'
processes
(ssl_crtd): Cannot create ssl certificate or private key.
2012/09/11 10:19:08 kid1| client_side.cc(3477) sslCrtdHandleReply:
"ssl_crtd" helper return <NULL> reply
2012/09/11 10:19:08 kid1| WARNING: ssl_crtd #1 exited
2012/09/11 10:19:08 kid1| Too few ssl_crtd processes are running (need 1/32)
2012/09/11 10:19:08 kid1| Starting new helpers
2012/09/11 10:19:08 kid1| helperOpenServers: Starting 1/32 'ssl_crtd'
processes
2012/09/11 10:19:09 kid1| client_side.cc(3477) sslCrtdHandleReply:
"ssl_crtd" helper return <NULL> reply
2012/09/11 10:19:09 kid1| clientNegotiateSSL: Error negotiating SSL
connection on FD 692: error:14094412:SSL routines:SSL3_READ_BYTES:sslv3
alert bad certificate (1/0)
2012/09/11 10:19:09 kid1| clientNegotiateSSL: Error negotiating SSL
connection on FD 694: error:14094412:SSL routines:SSL3_READ_BYTES:sslv3
alert bad certificate (1/0)
2012/09/11 10:19:21 kid1| fwdNegotiateSSL: Error negotiating SSL
connection on FD 936: error:14090086:SSL
routines:SSL3_GET_SERVER_CERTIFICATE:certificate verify failed (1/-1/0)
(ssl_crtd): Cannot create ssl certificate or private key.
2012/09/11 10:19:38 kid1| WARNING: ssl_crtd #1 exited
2012/09/11 10:19:38 kid1| Too few ssl_crtd processes are running (need 1/32)
2012/09/11 10:19:38 kid1| Starting new helpers
2012/09/11 10:19:38 kid1| helperOpenServers: Starting 1/32 'ssl_crtd'
processes
2012/09/11 10:19:38 kid1| client_side.cc(3477) sslCrtdHandleReply:
"ssl_crtd" helper return <NULL> reply
2012/09/11 10:19:38 kid1| clientNegotiateSSL: Error negotiating SSL
connection on FD 192: error:14094412:SSL routines:SSL3_READ_BYTES:sslv3
alert bad certificate (1/0)
2012/09/11 10:20:03 kid1| UserRequest.cc(200) authenticate: need to ask
helper
2012/09/11 10:28:32 kid1| clientNegotiateSSL: Error negotiating SSL
connection on FD 198: error:140760FC:SSL
routines:SSL23_GET_CLIENT_HELLO:unknown protocol (1/-1)
2012/09/11 10:28:32 kid1| clientNegotiateSSL: Error negotiating SSL
connection on FD 200: error:140760FC:SSL
routines:SSL23_GET_CLIENT_HELLO:unknown protocol (1/-1)
2012/09/11 10:38:27 kid1| fwdNegotiateSSL: Error negotiating SSL
connection on FD 714: error:14090086:SSL
routines:SSL3_GET_SERVER_CERTIFICATE:certificate verify failed (1/-1/0)
2012/09/11 10:38:28 kid1| fwdNegotiateSSL: Error negotiating SSL
connection on FD 537: error:14090086:SSL
routines:SSL3_GET_SERVER_CERTIFICATE:certificate verify failed (1/-1/0)
2012/09/11 10:38:28 kid1| fwdNegotiateSSL: Error negotiating SSL
connection on FD 767: error:14090086:SSL
routines:SSL3_GET_SERVER_CERTIFICATE:certificate verify failed (1/-1/0)
2012/09/11 10:40:40 kid1| fwdNegotiateSSL: Error negotiating SSL
connection on FD 551: error:14090086:SSL
routines:SSL3_GET_SERVER_CERTIFICATE:certificate verify failed (1/-1/0)
2012/09/11 10:40:52 kid1| fwdNegotiateSSL: Error negotiating SSL
connection on FD 198: error:14090086:SSL
routines:SSL3_GET_SERVER_CERTIFICATE:certificate verify failed (1/-1/0)
2012/09/11 10:40:53 kid1| fwdNegotiateSSL: Error negotiating SSL
connection on FD 296: error:14090086:SSL
routines:SSL3_GET_SERVER_CERTIFICATE:certificate verify failed (1/-1/0)
2012/09/11 10:40:59 kid1| fwdNegotiateSSL: Error negotiating SSL
connection on FD 682: error:140770FC:SSL
routines:SSL23_GET_SERVER_HELLO:unknown protocol (1/-1/0)
2012/09/11 10:41:11 kid1| assertion failed: forward.cc:199: "err"
2012/09/11 10:41:14 kid1| Starting Squid Cache version 3.2.1 for
x86_64-pc-linux-gnu...

You can see that I'm constantly getting "2012/09/11 10:13:32 kid1| Too
few ssl_crtd processes are running (need 1/32)". From then on I get
something like this:

2012/09/11 10:43:01 kid1| 4128768 entries written so far.
2012/09/11 10:43:01 kid1| 4194304 entries written so far.
2012/09/11 10:43:01 kid1| 4259840 entries written so far.
2012/09/11 10:43:01 kid1| 4325376 entries written so far.
2012/09/11 10:43:01 kid1| 4390912 entries written so far.
2012/09/11 10:43:01 kid1| 4456448 entries written so far.
2012/09/11 10:43:01 kid1| 4521984 entries written so far.
2012/09/11 10:43:02 kid1| Finished. Wrote 4538089 entries.
2012/09/11 10:43:02 kid1| Took 2.41 seconds (1882012.41 entries/sec).
FATAL: The ssl_crtd helpers are crashing too rapidly, need help!

Squid Cache (Version 3.2.1): Terminated abnormally.
CPU Usage: 39.810 seconds = 22.169 user + 17.641 sys
Maximum Resident Size: 3916864 KB
Page faults with physical i/o: 3
Memory usage for squid via mallinfo():
         total space in arena: 893156 KB
         Ordinary blocks: 892739 KB 35 blks
         Small blocks: 0 KB 1 blks
         Holding blocks: 120768 KB 17 blks
         Free Small blocks: 0 KB
         Free Ordinary blocks: 416 KB
         Total in use: 1013507 KB 113%
         Total free: 416 KB 0%
2012/09/11 10:43:08 kid1| Starting Squid Cache version 3.2.1 for
x86_64-pc-linux-gnu...
2012/09/11 10:43:08 kid1| Process ID 19777

...

2012/09/11 10:44:03 kid1| fwdNegotiateSSL: Error negotiating SSL
connection on FD 275: error:14090086:SSL
routines:SSL3_GET_SERVER_CERTIFICATE:certificate verify failed (1/-1/0)
2012/09/11 10:44:14 kid1| fwdNegotiateSSL: Error negotiating SSL
connection on FD 324: error:14090086:SSL
routines:SSL3_GET_SERVER_CERTIFICATE:certificate verify failed (1/-1/0)
2012/09/11 10:44:35 kid1| Starting new ntlmauthenticator helpers...
2012/09/11 10:44:35 kid1| helperOpenServers: Starting 1/30 'ntlm_auth'
processes
2012/09/11 10:44:35 kid1| Starting new ntlmauthenticator helpers...
2012/09/11 10:44:35 kid1| helperOpenServers: Starting 1/30 'ntlm_auth'
processes
[2012/09/11 10:44:56.783409, 1] libsmb/ntlmssp.c:342(ntlmssp_update)
   got NTLMSSP command 1, expected 3
(ssl_crtd): Cannot create ssl certificate or private key.
2012/09/11 10:45:26 kid1| WARNING: ssl_crtd #1 exited
2012/09/11 10:45:26 kid1| Too few ssl_crtd processes are running (need 1/32)
2012/09/11 10:45:26 kid1| Starting new helpers
2012/09/11 10:45:26 kid1| helperOpenServers: Starting 1/32 'ssl_crtd'
processes
2012/09/11 10:45:26 kid1| client_side.cc(3477) sslCrtdHandleReply:
"ssl_crtd" helper return <NULL> reply
2012/09/11 10:45:26 kid1| clientNegotiateSSL: Error negotiating SSL
connection on FD 113: error:14094412:SSL routines:SSL3_READ_BYTES:sslv3
alert bad certificate (1/0)
(ssl_crtd): Cannot create ssl certificate or private key.
2012/09/11 10:45:26 kid1| WARNING: ssl_crtd #2 exited
2012/09/11 10:45:26 kid1| Too few ssl_crtd processes are running (need 1/32)
2012/09/11 10:45:26 kid1| Closing HTTP port [::]:3128
2012/09/11 10:45:26 kid1| storeDirWriteCleanLogs: Starting...
2012/09/11 10:45:26 kid1| 65536 entries written so far.
2012/09/11 10:45:26 kid1| 131072 entries written so far.
2012/09/11 10:45:26 kid1| 196608 entries written so far.
2012/09/11 10:45:26 kid1| 262144 entries written so far.
2012/09/11 10:45:26 kid1| 327680 entries written so far.
2012/09/11 10:45:26 kid1| 393216 entries written so far.
2012/09/11 10:45:26 kid1| 458752 entries written so far.
2012/09/11 10:45:26 kid1| 524288 entries written so far.
2012/09/11 10:45:26 kid1| 589824 entries written so far.
2012/09/11 10:45:26 kid1| 655360 entries written so far.
2012/09/11 10:45:26 kid1| 720896 entries written so far.
2012/09/11 10:45:26 kid1| 786432 entries written so far.
2012/09/11 10:45:26 kid1| 851968 entries written so far.

...

2012/09/11 10:45:27 kid1| 4390912 entries written so far.
2012/09/11 10:45:27 kid1| 4456448 entries written so far.
2012/09/11 10:45:27 kid1| 4521984 entries written so far.
2012/09/11 10:45:28 kid1| Finished. Wrote 4538345 entries.
2012/09/11 10:45:28 kid1| Took 2.49 seconds (1822261.13 entries/sec).
FATAL: The ssl_crtd helpers are crashing too rapidly, need help!

Squid Cache (Version 3.2.1): Terminated abnormally.
CPU Usage: 35.454 seconds = 20.973 user + 14.481 sys
Maximum Resident Size: 3941264 KB
Page faults with physical i/o: 0
Memory usage for squid via mallinfo():
         total space in arena: 899484 KB
         Ordinary blocks: 899221 KB 334 blks
         Small blocks: 0 KB 1 blks
         Holding blocks: 120768 KB 17 blks
         Free Small blocks: 0 KB
         Free Ordinary blocks: 262 KB
         Total in use: 1019989 KB 113%
         Total free: 262 KB 0%
2012/09/11 10:45:34 kid1| Starting Squid Cache version 3.2.1 for
x86_64-pc-linux-gnu...
2012/09/11 10:45:34 kid1| Process ID 26455
2012/09/11 10:45:34 kid1| Process Roles: worker
2012/09/11 10:45:34 kid1| With 65535 file descriptors available
2012/09/11 10:45:34 kid1| Initializing IP Cache...

 From then on this seems to repeat until I do this:

/etc/init.d/squid3 stop
rm -rf /var/lib/ssl_db
/usr/lib/squid3/ssl_crtd -c -s /var/lib/ssl_db
chown -R proxy:proxy /var/lib/ssl_db
/etc/init.d/squid3 start

Sometimes I have to do this twice before squid settles down again and
the ssl_crtd processes stop being reported as crashing.

Any ideas?
Received on Tue Sep 11 2012 - 10:40:21 MDT