Re: [squid-users] problems with ssl_crtd

On 24/09/2012 8:44 p.m., Linos wrote:
> On 20/09/12 12:58, Ahmed Talha Khan wrote:
>> Hey Guy, All
>>
>> I have started facing a very similar issue now.I have been using
>> squid-3.HEAD-20120421-r12120 for about 5 months without any issues.
>> Suddenly from yesterday ive started getting crahses in ssl_crtd
>> process.
>>
>>
>> In my case i am the only user but i observe that the behaviour is
>> random. Sometimes it crashes and sometimes it works. Different https
>> pages give the crash. Even non https pages have caused the crash.
>>
>> These occur especially on google https pages like docs,mail,calender etc..
>>
>> The signing cert is also ok and has NOT expired.
>>
>>
>> My squid conf looks like this:
>> *******************************************************
>> sslproxy_cert_error allow all
>>
>> sslcrtd_program /usr/local/squid-3.3/libexec/ssl_crtd -s
>> /usr/local/squid-3.3/var/lib/ssl_db -M 4MB
>> sslcrtd_children 5
>>
>> http_port 192.168.8.134:3128 ssl-bump generate-host-certificates=on
>> dynamic_cert_mem_cache_size=4MB
>> cert=/home/asif/squid/www.sample.com.pem
>> key=/home/asif/squid/www.sample.com.pem
>>
>> http_port 192.168.8.134:8080
>>
>> https_port 192.168.8.134:3129 ssl-bump generate-host-certificates=on
>> dynamic_cert_mem_cache_size=4MB
>> cert=/home/asif/squid/www.sample.com.pem
>> key=/home/asif/squid/www.sample.com.pem
>> *******************************************************
>>
>> The ssl_db directory is initialized properly with correct permissions.
>>
>> ***********************************************************
>> [talha_at_localhost lib]$ pwd
>> /usr/local/squid-3.3/var/lib
>>
>> [talha_at_localhost lib]$ ls -al
>> total 24
>> drwxrwxrwx 3 root root 4096 Sep 20 15:31 .
>> drwxrwxrwx 6 root root 4096 Sep 20 15:05 ..
>> drwxrwxrwx 3 nobody talha 4096 Sep 20 15:31 ssl_db
>>
>> The size file also has some values in it and cert generation also
>> seems to work but suddenly it all crashes .
>> **************************************************************
>>
>>
>>
>> 2012/09/20 14:57:45| Starting Squid Cache version
>> 3.HEAD-20120425-r12120 for x86_64-unknown-linux-gnu...
>> 2012/09/20 14:57:45| Process ID 23826
>> 2012/09/20 14:57:45| Process Roles: master worker
>> 2012/09/20 14:57:45| With 1024 file descriptors available
>> 2012/09/20 14:57:45| Initializing IP Cache...
>> 2012/09/20 14:57:45| DNS Socket created at [::], FD 5
>> 2012/09/20 14:57:45| DNS Socket created at 0.0.0.0, FD 6
>> 2012/09/20 14:57:45| Adding nameserver 192.168.8.1 from /etc/resolv.conf
>> 2012/09/20 14:57:45| Adding domain localdomain from /etc/resolv.conf
>> 2012/09/20 14:57:45| helperOpenServers: Starting 5/5 'ssl_crtd' processes
>> 2012/09/20 14:57:45| Logfile: opening log
>> daemon:/usr/local/squid-3.3/var/logs/access.log
>> 2012/09/20 14:57:45| Logfile Daemon: opening log
>> /usr/local/squid-3.3/var/logs/access.log
>> 2012/09/20 14:57:45| Logfile: opening log /usr/local/squid-3.3/var/logs/icap-log
>> 2012/09/20 14:57:45| WARNING: log parameters now start with a module
>> name. Use 'stdio:/usr/local/squid-3.3/var/logs/icap-log'
>>
>>
>> 2012/09/20 14:57:45| Store logging disabled
>> 2012/09/20 14:57:45| Swap maxSize 0 + 262144 KB, estimated 20164 objects
>> 2012/09/20 14:57:45| Target number of buckets: 1008
>> 2012/09/20 14:57:45| Using 8192 Store buckets
>> 2012/09/20 14:57:45| Max Mem size: 262144 KB
>> 2012/09/20 14:57:45| Max Swap size: 0 KB
>> 2012/09/20 14:57:45| Using Least Load store dir selection
>> 2012/09/20 14:57:45| Set Current Directory to /usr/local/squid-3.3/var/cache
>> 2012/09/20 14:57:45| Loaded Icons.
>> 2012/09/20 14:57:45| HTCP Disabled.
>> 2012/09/20 14:57:45| /usr/local/squid-3.3/var/run/squid.pid: (13)
>> Permission denied
>> 2012/09/20 14:57:45| WARNING: Could not write pid file
>> 2012/09/20 14:57:45| Squid plugin modules loaded: 0
>> 2012/09/20 14:57:45| Adaptation support is on
>> 2012/09/20 14:57:45| Accepting SSL bumped HTTP Socket connections at
>> local=192.168.8.134:3128 remote=[::] FD 20 flags=9
>> 2012/09/20 14:57:45| Accepting HTTP Socket connections at
>> local=192.168.8.134:8080 remote=[::] FD 21 flags=9
>> 2012/09/20 14:57:45| Accepting SSL bumped HTTPS Socket connections at
>> local=192.168.8.134:3129 remote=[::] FD 22 flags=9
>> 2012/09/20 14:57:46| storeLateRelease: released 0 objects
>>
>> (ssl_crtd): Cannot create ssl certificate or private key.
>> 2012/09/20 14:58:23| WARNING: ssl_crtd #2 exited
>> 2012/09/20 14:58:23| Too few ssl_crtd processes are running (need 1/5)
>>
>> 2012/09/20 14:58:23| Starting new helpers
>> 2012/09/20 14:58:23| helperOpenServers: Starting 1/5 'ssl_crtd' processes
>> 2012/09/20 14:58:23| client_side.cc(3478) sslCrtdHandleReply:
>> "ssl_crtd" helper return <NULL> reply
>> (ssl_crtd): Cannot create ssl certificate or private key.
>>
>> 2012/09/20 14:58:23| WARNING: ssl_crtd #1 exited
>> 2012/09/20 14:58:23| Too few ssl_crtd processes are running (need 1/5)
>> 2012/09/20 14:58:23| storeDirWriteCleanLogs: Starting...
>> 2012/09/20 14:58:23| Finished. Wrote 0 entries.
>> 2012/09/20 14:58:23| Took 0.00 seconds ( 0.00 entries/sec).
>> FATAL: The ssl_crtd helpers are crashing too rapidly, need help!
>>
>> Squid Cache (Version 3.HEAD-20120425-r12120): Terminated abnormally.
>> CPU Usage: 0.355 seconds = 0.289 user + 0.066 sys
>> Maximum Resident Size: 71104 KB
>> Page faults with physical i/o: 0
>> Memory usage for squid via mallinfo():
>> total space in arena: 11924 KB
>> Ordinary blocks: 11818 KB 49 blks
>> Small blocks: 0 KB 0 blks
>> Holding blocks: 664 KB 2 blks
>> Free Small blocks: 0 KB
>> Free Ordinary blocks: 105 KB
>>
>>
>>
>>
>>
>>
>> On Thu, Sep 20, 2012 at 2:52 PM, Linos wrote:
>>> On 19/09/12 16:46, Guy Helmer wrote:
>>>>> Thanks for reply.
>>>>>
>>>>> i checked the squid_ssl_db/size because i found the empty file problem searching
>>>>> for my own problem in the mailing list, it's ok in my host, the file have the
>>>>> content "139264" right now.
>>>>>
>>>>> I can't found the core file, do i need to do something for it to generate? maybe
>>>>> a configure script option or squid.conf change to activate it?
>>>>>
>>>>> Regards,
>>>>> Miguel Angel.
>>>> I have
>>>>
>>>> coredump_dir /var/log/squid
>>>>
>>>> to get coredumps in my /var/log/squid directory. Now that I think about it, I don't remember if this works for ssl_crtd though -- seems like I have had to start "gdb ssl_crtd" and then attach to one of the ssl_crtd processes, then generate HTTPS traffic to trigger the request to ssl_crtd and get a backtrace when ssl_crtd gets the segfault signal…
>>>>
>>>> Guy
>>>>
>>> Hi,
>>> i have been trying to debug with gdb attaching existing process, the strange
>>> it's that ssl_ctrd seems to exit normally in this test, here you have it (sorry
>>> for the spanish locale, i will use english next time, the only file with symbols
>>> it's ssl_crtd itself):
>>>
>>> --------------------------------------------------------------------------------
>>> GNU gdb (Ubuntu/Linaro 7.4-2012.04-0ubuntu2) 7.4-2012.04
>>> Copyright (C) 2012 Free Software Foundation, Inc.
>>> License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html>
>>> This is free software: you are free to change and redistribute it.
>>> There is NO WARRANTY, to the extent permitted by law. Type "show copying"
>>> and "show warranty" for details.
>>> This GDB was configured as "x86_64-linux-gnu".
>>> Para las instrucciones de informe de errores, vea:
>>> <http://bugs.launchpad.net/gdb-linaro/>.
>>> (gdb) attach 10495
>>> Adjuntando a process 10495
>>> Leyendo símbolos desde /usr/lib/squid3/ssl_crtd...Leyendo símbolos desde
>>> /usr/lib/debug/usr/lib/squid3/ssl_crtd...hecho.
>>> hecho.
>>> Leyendo símbolos desde /lib/x86_64-linux-gnu/libcrypto.so.0.9.8...(no se
>>> encontraron símbolos de depuración)hecho.
>>> Símbolos cargados para /lib/x86_64-linux-gnu/libcrypto.so.0.9.8
>>> Leyendo símbolos desde /usr/lib/x86_64-linux-gnu/libstdc++.so.6...(no se
>>> encontraron símbolos de depuración)hecho.
>>> Símbolos cargados para /usr/lib/x86_64-linux-gnu/libstdc++.so.6
>>> Leyendo símbolos desde /lib/x86_64-linux-gnu/libgcc_s.so.1...(no se encontraron
>>> símbolos de depuración)hecho.
>>> Símbolos cargados para /lib/x86_64-linux-gnu/libgcc_s.so.1
>>> Leyendo símbolos desde /lib/x86_64-linux-gnu/libc.so.6...(no se encontraron
>>> símbolos de depuración)hecho.
>>> Símbolos cargados para /lib/x86_64-linux-gnu/libc.so.6
>>> Leyendo símbolos desde /lib/x86_64-linux-gnu/libdl.so.2...(no se encontraron
>>> símbolos de depuración)hecho.
>>> Símbolos cargados para /lib/x86_64-linux-gnu/libdl.so.2
>>> Leyendo símbolos desde /lib/x86_64-linux-gnu/libz.so.1...(no se encontraron
>>> símbolos de depuración)hecho.
>>> Símbolos cargados para /lib/x86_64-linux-gnu/libz.so.1
>>> Leyendo símbolos desde /lib/x86_64-linux-gnu/libm.so.6...(no se encontraron
>>> símbolos de depuración)hecho.
>>> Símbolos cargados para /lib/x86_64-linux-gnu/libm.so.6
>>> Leyendo símbolos desde /lib64/ld-linux-x86-64.so.2...(no se encontraron símbolos
>>> de depuración)hecho.
>>> Símbolos cargados para /lib64/ld-linux-x86-64.so.2
>>> 0x00007f3ef414f0a0 in read () from /lib/x86_64-linux-gnu/libc.so.6
>>> (gdb) continue
>>> Continuando.
>>> [Inferior 1 (process 10495) exited normally]
>>> (gdb) bt
>>> No stack.
>>>
>>> --------------------------------------------------------------------------------
>>>
>>> I have tried attaching to squid3 process itself and i have received a signal here:
>>>
>>> GNU gdb (Ubuntu/Linaro 7.4-2012.04-0ubuntu2) 7.4-2012.04
>>> Copyright (C) 2012 Free Software Foundation, Inc.
>>> License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html>
>>> This is free software: you are free to change and redistribute it.
>>> There is NO WARRANTY, to the extent permitted by law. Type "show copying"
>>> and "show warranty" for details.
>>> This GDB was configured as "x86_64-linux-gnu".
>>> Para las instrucciones de informe de errores, vea:
>>> <http://bugs.launchpad.net/gdb-linaro/>.
>>> (gdb) attach 10732
>>> Adjuntando a process 10732
>>> Leyendo símbolos desde /usr/sbin/squid3...coLeyendo símbolos desde
>>> /usr/lib/debug/usr/sbin/squid3...ntinue
>>> hecho.
>>> hecho.
>>> Leyendo símbolos desde /lib/x86_64-linux-gnu/libpthread.so.0...(no se
>>> encontraron símbolos de depuración)hecho.
>>> [Depuración de hilo usando libthread_db enabled]
>>> Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".
>>> Símbolos cargados para /lib/x86_64-linux-gnu/libpthread.so.0
>>> Leyendo símbolos desde /usr/lib/x86_64-linux-gnu/libxml2.so.2...(no se
>>> encontraron símbolos de depuración)hecho.
>>> Símbolos cargados para /usr/lib/x86_64-linux-gnu/libxml2.so.2
>>> Leyendo símbolos desde /lib/x86_64-linux-gnu/libexpat.so.1...(no se encontraron
>>> símbolos de depuración)hecho.
>>> Símbolos cargados para /lib/x86_64-linux-gnu/libexpat.so.1
>>> Leyendo símbolos desde /lib/x86_64-linux-gnu/libssl.so.0.9.8...(no se
>>> encontraron símbolos de depuración)hecho.
>>> Símbolos cargados para /lib/x86_64-linux-gnu/libssl.so.0.9.8
>>> Leyendo símbolos desde /lib/x86_64-linux-gnu/libcrypto.so.0.9.8...(no se
>>> encontraron símbolos de depuración)hecho.
>>> Símbolos cargados para /lib/x86_64-linux-gnu/libcrypto.so.0.9.8
>>> Leyendo símbolos desde /usr/lib/x86_64-linux-gnu/libgssapi_krb5.so.2...(no se
>>> encontraron símbolos de depuración)hecho.
>>> Símbolos cargados para /usr/lib/x86_64-linux-gnu/libgssapi_krb5.so.2
>>> Leyendo símbolos desde /usr/lib/x86_64-linux-gnu/libkrb5.so.3...(no se
>>> encontraron símbolos de depuración)hecho.
>>> Símbolos cargados para /usr/lib/x86_64-linux-gnu/libkrb5.so.3
>>> Leyendo símbolos desde /lib/x86_64-linux-gnu/libcom_err.so.2...(no se
>>> encontraron símbolos de depuración)hecho.
>>> Símbolos cargados para /lib/x86_64-linux-gnu/libcom_err.so.2
>>> Leyendo símbolos desde /lib/x86_64-linux-gnu/libcap.so.2...(no se encontraron
>>> símbolos de depuración)hecho.
>>> Símbolos cargados para /lib/x86_64-linux-gnu/libcap.so.2
>>> Leyendo símbolos desde /lib/x86_64-linux-gnu/librt.so.1...(no se encontraron
>>> símbolos de depuración)hecho.
>>> Símbolos cargados para /lib/x86_64-linux-gnu/librt.so.1
>>> Leyendo símbolos desde /usr/lib/x86_64-linux-gnu/libltdl.so.7...(no se
>>> encontraron símbolos de depuración)hecho.
>>> Símbolos cargados para /usr/lib/x86_64-linux-gnu/libltdl.so.7
>>> Leyendo símbolos desde /usr/lib/x86_64-linux-gnu/libstdc++.so.6...(no se
>>> encontraron símbolos de depuración)hecho.
>>> Símbolos cargados para /usr/lib/x86_64-linux-gnu/libstdc++.so.6
>>> Leyendo símbolos desde /lib/x86_64-linux-gnu/libm.so.6...(no se encontraron
>>> símbolos de depuración)hecho.
>>> Símbolos cargados para /lib/x86_64-linux-gnu/libm.so.6
>>> Leyendo símbolos desde /lib/x86_64-linux-gnu/libgcc_s.so.1...(no se encontraron
>>> símbolos de depuración)hecho.
>>> Símbolos cargados para /lib/x86_64-linux-gnu/libgcc_s.so.1
>>> Leyendo símbolos desde /lib/x86_64-linux-gnu/libc.so.6...(no se encontraron
>>> símbolos de depuración)hecho.
>>> Símbolos cargados para /lib/x86_64-linux-gnu/libc.so.6
>>> Leyendo símbolos desde /lib64/ld-linux-x86-64.so.2...(no se encontraron símbolos
>>> de depuración)hecho.
>>> Símbolos cargados para /lib64/ld-linux-x86-64.so.2
>>> Leyendo símbolos desde /lib/x86_64-linux-gnu/libdl.so.2...(no se encontraron
>>> símbolos de depuración)hecho.
>>> Símbolos cargados para /lib/x86_64-linux-gnu/libdl.so.2
>>> Leyendo símbolos desde /lib/x86_64-linux-gnu/libz.so.1...(no se encontraron
>>> símbolos de depuración)hecho.
>>> Símbolos cargados para /lib/x86_64-linux-gnu/libz.so.1
>>> Leyendo símbolos desde /usr/lib/x86_64-linux-gnu/libk5crypto.so.3...(no se
>>> encontraron símbolos de depuración)hecho.
>>> Símbolos cargados para /usr/lib/x86_64-linux-gnu/libk5crypto.so.3
>>> Leyendo símbolos desde /usr/lib/x86_64-linux-gnu/libkrb5support.so.0...(no se
>>> encontraron símbolos de depuración)hecho.
>>> Símbolos cargados para /usr/lib/x86_64-linux-gnu/libkrb5support.so.0
>>> Leyendo símbolos desde /lib/x86_64-linux-gnu/libkeyutils.so.1...(no se
>>> encontraron símbolos de depuración)hecho.
>>> Símbolos cargados para /lib/x86_64-linux-gnu/libkeyutils.so.1
>>> Leyendo símbolos desde /lib/x86_64-linux-gnu/libresolv.so.2...(no se encontraron
>>> símbolos de depuración)hecho.
>>> Símbolos cargados para /lib/x86_64-linux-gnu/libresolv.so.2
>>> Leyendo símbolos desde /lib/x86_64-linux-gnu/libnss_files.so.2...(no se
>>> encontraron símbolos de depuración)hecho.
>>> Símbolos cargados para /lib/x86_64-linux-gnu/libnss_files.so.2
>>> Leyendo símbolos desde /lib/x86_64-linux-gnu/libnss_compat.so.2...(no se
>>> encontraron símbolos de depuración)hecho.
>>> Símbolos cargados para /lib/x86_64-linux-gnu/libnss_compat.so.2
>>> Leyendo símbolos desde /lib/x86_64-linux-gnu/libnsl.so.1...(no se encontraron
>>> símbolos de depuración)hecho.
>>> Símbolos cargados para /lib/x86_64-linux-gnu/libnsl.so.1
>>> Leyendo símbolos desde /lib/x86_64-linux-gnu/libnss_nis.so.2...(no se
>>> encontraron símbolos de depuración)hecho.
>>> Símbolos cargados para /lib/x86_64-linux-gnu/libnss_nis.so.2
>>> 0x00007f7d6243dac8 in poll () from /lib/x86_64-linux-gnu/libc.so.6
>>> (gdb) continue
>>> Continuando.
>>>
>>> Program received signal SIGPIPE, Broken pipe.
>>> 0x00007f7d647becb0 in __write_nocancel () from /lib/x86_64-linux-gnu/libpthread.so.0
>>> (gdb) bt
>>> #0 0x00007f7d647becb0 in __write_nocancel () from
>>> /lib/x86_64-linux-gnu/libpthread.so.0
>>> #1 0x00007f7d63d075c5 in ?? () from /lib/x86_64-linux-gnu/libcrypto.so.0.9.8
>>> #2 0x00007f7d63d05247 in BIO_write () from /lib/x86_64-linux-gnu/libcrypto.so.0.9.8
>>> #3 0x00007f7d63ffafc4 in ssl3_write_pending () from
>>> /lib/x86_64-linux-gnu/libssl.so.0.9.8
>>> #4 0x00007f7d63ffc853 in ssl3_dispatch_alert () from
>>> /lib/x86_64-linux-gnu/libssl.so.0.9.8
>>> #5 0x00007f7d63ff9442 in ssl3_shutdown () from
>>> /lib/x86_64-linux-gnu/libssl.so.0.9.8
>>> #6 0x00007f7d64e8f0f4 in AsyncCall::make (this=0x7f7d687eb390) at AsyncCall.cc:36
>>> #7 0x00007f7d64e92117 in AsyncCallQueue::fireNext (this=<optimized out>) at
>>> AsyncCallQueue.cc:54
>>> #8 0x00007f7d64e92270 in AsyncCallQueue::fire (this=0x7f7d66f5f2c0) at
>>> AsyncCallQueue.cc:40
>>> #9 0x00007f7d64d7c494 in EventLoop::runOnce (this=0x7fff630b3e60) at
>>> EventLoop.cc:131
>>> #10 0x00007f7d64d7c568 in EventLoop::run (this=0x7fff630b3e60) at EventLoop.cc:95
>>> #11 0x00007f7d64ddc039 in SquidMain (argc=<optimized out>, argv=<optimized out>)
>>> at main.cc:1500
>>> #12 0x00007f7d64d10b76 in SquidMainSafe (argv=<optimized out>, argc=<optimized
>>> out>) at main.cc:1215
>>> #13 main (argc=<optimized out>, argv=<optimized out>) at main.cc:1207
>>>
>>> Any ideas what's going on with this information? Thansk!
>>>
>>> Regards,
>>> Miguel Angel.
>>
>>
> Hi Ahmed,
> did you found a way to fix or workaround this? i can't get a backtrace with the
> information needed and no matter what i try it keeps failing, i had to disable
> ssl and my users are a bit upset.
>
> Regards,
> Miguel Angel.

I've taken a quick look at these reports and tried to figure out if
anything obvious is going on.

 From what I can see, there is really no reason why the helper should be
exiting like this. Something it is doing produces an exception, fine,
but the method of handling that exception is to exit instead of
reporting the problem to Squid and continuing with further requests.

As a workaround you can probably patch out the FATAL and let Squid
continuously restart the helpers unless that spams the logs too much for
your liking.

Amos
Received on Mon Sep 24 2012 - 10:52:26 MDT