I was using squid 3.3.4 on FreeBSD 8.3 with transparent interception (via ipfw) and ssl bump with success.
After upgrading FreeBSD to 9.1 (and all add-on software completely rebuilt under 9.1), now squid is failing with segmentation violations and the ssl_crtd helpers are dying. I have removed and re-created the SSL certificate cache to no effect.
Any guidance as to what to try to diagnose or resolve this?
One of the sample coredumps results in this backtrace:
build92-i386:/usr/ports/www/squid33/work/squid-3.3.4/src (510) gdb squid ~/squid.core.0
GNU gdb 6.1.1 [FreeBSD]
Copyright 2004 Free Software Foundation, Inc.
GDB is free software, covered by the GNU General Public License, and you are
welcome to change it and/or distribute copies of it under certain conditions.
Type "show copying" to see the conditions.
There is absolutely no warranty for GDB. Type "show warranty" for details.
This GDB was configured as "i386-marcel-freebsd"...
Core was generated by `squid'.
Program terminated with signal 6, Aborted.
Reading symbols from /usr/lib/librt.so.1...done.
Loaded symbols for /usr/lib/librt.so.1
Reading symbols from /usr/lib/libssl.so.6...done.
Loaded symbols for /usr/lib/libssl.so.6
Reading symbols from /usr/lib/libgssapi.so.10...done.
Loaded symbols for /usr/lib/libgssapi.so.10
Reading symbols from /usr/lib/libheimntlm.so.10...done.
Loaded symbols for /usr/lib/libheimntlm.so.10
Reading symbols from /usr/lib/libkrb5.so.10...done.
Loaded symbols for /usr/lib/libkrb5.so.10
Reading symbols from /usr/lib/libhx509.so.10...done.
Loaded symbols for /usr/lib/libhx509.so.10
Reading symbols from /usr/lib/libcom_err.so.5...done.
Loaded symbols for /usr/lib/libcom_err.so.5
Reading symbols from /lib/libcrypto.so.6...done.
Loaded symbols for /lib/libcrypto.so.6
Reading symbols from /usr/lib/libasn1.so.10...done.
Loaded symbols for /usr/lib/libasn1.so.10
Reading symbols from /usr/lib/libroken.so.10...done.
Loaded symbols for /usr/lib/libroken.so.10
Reading symbols from /lib/libcrypt.so.5...done.
Loaded symbols for /lib/libcrypt.so.5
Reading symbols from /usr/lib/libstdc++.so.6...done.
Loaded symbols for /usr/lib/libstdc++.so.6
Reading symbols from /lib/libm.so.5...done.
Loaded symbols for /lib/libm.so.5
Reading symbols from /lib/libgcc_s.so.1...done.
Loaded symbols for /lib/libgcc_s.so.1
Reading symbols from /lib/libthr.so.3...done.
Loaded symbols for /lib/libthr.so.3
Reading symbols from /lib/libc.so.7...done.
Loaded symbols for /lib/libc.so.7
Reading symbols from /usr/lib/libsupc++.so.1...done.
Loaded symbols for /usr/lib/libsupc++.so.1
Reading symbols from /libexec/ld-elf.so.1...done.
Loaded symbols for /libexec/ld-elf.so.1
#0 0x48954b4b in thr_new () from /lib/libc.so.7
[New Thread 48c04300 (LWP 100106/squid)]
(gdb) where
#0 0x48954b4b in thr_new () from /lib/libc.so.7
#1 0x488e9986 in pthread_sigmask () from /lib/libthr.so.3
#2 0x488ea05b in raise () from /lib/libthr.so.3
#3 0x489ff13a in mpool_open () from /lib/libc.so.7
#4 0x08267d86 in death (sig=11) at tools.cc:397
#5 0x488e9bd0 in pthread_sigmask () from /lib/libthr.so.3
#6 0x488e9ca5 in pthread_sigmask () from /lib/libthr.so.3
#7 0xbfbff044 in ?? ()
#8 0x0000000b in ?? ()
#9 0x484eb5c8 in ssl_get_server_send_pkey () from /usr/lib/libssl.so.6
#10 0x484eb68d in ssl_get_server_send_cert () from /usr/lib/libssl.so.6
#11 0x484eb6c4 in SSL_get_certificate () from /usr/lib/libssl.so.6
#12 0x083cb5ef in Ssl::verifySslCertificate (sslContext=0x4a259340,
properties=@0xbfbfd9d8) at support.cc:1422
#13 0x0813d20d in ConnStateData::getSslContextStart (this=0x4a257cd0)
at client_side.cc:3820
#14 0x0814a89e in ConnStateData::httpsPeeked (this=0x4a257cd0,
serverConnection=@0xbfbfdadc) at client_side.cc:3968
#15 0x0819bdec in UnaryMemFunT<ConnStateData, RefCount<Comm::Connection>, RefCount<Comm::Connection> >::doDial (this=0x49ff91dc) at AsyncJobCalls.h:113
#16 0x08158669 in JobDialer<ConnStateData>::dial (this=0x49ff91dc,
call=@0x49ff91c0) at AsyncJobCalls.h:166
#17 0x0819c7a8 in AsyncCallT<UnaryMemFunT<ConnStateData, RefCount<Comm::Connection>,---Type <return> to continue, or q <return> to quit---
RefCount<Comm::Connection> > >::fire (this=0x49ff91c0) at AsyncCall.h:137
#18 0x082e9e6b in AsyncCall::make (this=0x49ff91c0) at AsyncCall.cc:32
#19 0x082edbb1 in AsyncCallQueue::fireNext (this=0x48e3a800)
at AsyncCallQueue.cc:52
#20 0x082eddbb in AsyncCallQueue::fire (this=0x48e3a800) at AsyncCallQueue.cc:38
#21 0x0818a103 in EventLoop::dispatchCalls (this=0xbfbfdc38) at EventLoop.cc:155
#22 0x0818a3c4 in EventLoop::runOnce (this=0xbfbfdc38) at EventLoop.cc:132
#23 0x0818a55a in EventLoop::run (this=0xbfbfdc38) at EventLoop.cc:96
#24 0x08209471 in SquidMain (argc=3, argv=0xbfbfdd3c) at main.cc:1520
#25 0x08209811 in SquidMainSafe (argc=3, argv=0xbfbfdd3c) at main.cc:1242
#26 0x08209ad2 in main (argc=Cannot access memory at address 0x3
) at main.cc:1234
(gdb) frame 12
#12 0x083cb5ef in Ssl::verifySslCertificate (sslContext=0x4a259340,
properties=@0xbfbfd9d8) at support.cc:1422
1422 X509 * cert = SSL_get_certificate(ssl.get());
(gdb) frame 13
#13 0x0813d20d in ConnStateData::getSslContextStart (this=0x4a257cd0)
at client_side.cc:3820
3820 if (Ssl::verifySslCertificate(dynCtx, certProperties)) {
(gdb) print dynCtx
$1 = (SSL_CTX *) 0x4a259340
(gdb) print certProperties
$2 = {mimicCert = {<TidyPointer<x509_st,Ssl::X509_free_cpp>> = {
raw = 0x4a2b0470}, <No data fields>},
signWithX509 = {<TidyPointer<x509_st,Ssl::X509_free_cpp>> = {
raw = 0x48e3c240}, <No data fields>},
signWithPkey = {<TidyPointer<evp_pkey_st,Ssl::EVP_PKEY_free_cpp>> = {
raw = 0x48e3f540}, <No data fields>}, setValidAfter = false,
setValidBefore = false, setCommonName = false, commonName = {
static npos = 4294967295,
_M_dataplus = {<std::allocator<char>> = {<__gnu_cxx::new_allocator<char>> = {<No data fields>}, <No data fields>}, _M_p = 0x49ff738c "r.twimg.com"}},
signAlgorithm = Ssl::algSignTrusted}
(gdb) print *this
$3 = {<BodyProducer> = {<AsyncJob> = {_vptr$AsyncJob = 0x83f1f4c,
stopReason = 0x0, typeName = 0x83ef96a "ConnStateData", inCall = {
p_ = 0x49ff91c0}, id = {static Prefix = 0x841e6cb "job", value = 58,
static Last = 62}},
_vptr$BodyProducer = 0x83f1eec}, <HttpControlMsgSink> = {
_vptr$HttpControlMsgSink = 0x83f1f18}, clientConnection = {p_ = 0x4a3ec900},
in = {bodyParser = 0x0, buf = 0x48d34000 "", notYetUsed = 0,
allocatedSize = 4096}, auth_user_request = {p_ = 0x0}, currentobject = {
p_ = 0x0}, log_addr = {m_SocketAddr = {sin6_len = 0 '\0',
sin6_family = 28 '\034', sin6_port = 43456, sin6_flowinfo = 0, sin6_addr = {
__u6_addr = {
__u6_addr8 = "\000\000\000\000\000\000\000\000\000\000????\001m",
__u6_addr16 = {0, 0, 0, 0, 0, 65535, 43200, 27905}, __u6_addr32 = {0, 0,
4294901760, 1828825280}}}, sin6_scope_id = 0},
static STRLEN_IP4A = <optimized out>, static STRLEN_IP4R = 28,
static STRLEN_IP4S = <optimized out>, static MAX_IP4_STRLEN = <optimized out>,
static STRLEN_IP6A = <optimized out>, static STRLEN_IP6R = 75,
static STRLEN_IP6S = <optimized out>, static MAX_IP6_STRLEN = <optimized out>,
static v4_localhost = {__u6_addr = {
__u6_addr8 = "\000\000\000\000\000\000\000\000\000\000??\177\000\000\001",
__u6_addr16 = {0, 0, 0, 0, 0, 65535, 127, 256}, __u6_addr32 = {0, 0,
4294901760, 16777343}}}, static v4_anyaddr = {__u6_addr = {
__u6_addr8 = "\000\000\000\000\000\000\000\000\000\000??\000\000\000",
---Type <return> to continue, or q <return> to quit---
__u6_addr16 = {0, 0, 0, 0, 0, 65535, 0, 0}, __u6_addr32 = {0, 0,
4294901760, 0}}}, static v4_noaddr = {__u6_addr = {
__u6_addr8 = "\000\000\000\000\000\000\000\000\000\000??????",
__u6_addr16 = {0, 0, 0, 0, 0, 65535, 65535, 65535}, __u6_addr32 = {0, 0,
4294901760, 4294967295}}}, static v6_noaddr = {__u6_addr = {
__u6_addr8 = '?' <repeats 16 times>, __u6_addr16 = {65535, 65535, 65535,
65535, 65535, 65535, 65535, 65535}, __u6_addr32 = {4294967295,
4294967295, 4294967295, 4294967295}}}}, nrequests = 0, flags = {
readMore = true, swanSang = false}, pinning = {serverConnection = {
p_ = 0x4a3eca80}, host = 0x0, port = 443, pinned = true, auth = false,
zeroReply = false, peer = 0x0, closeHandler = {p_ = 0x48d781f0}},
port = 0x48c68510, sslBumpMode = Ssl::bumpServerFirst, parser_ = {
state = 0 '\0', buf = 0x0, bufsiz = 0, req = {start = -1, end = -1,
m_start = -1, m_end = -1, u_start = -1, u_end = -1, v_start = -1,
v_end = -1, v_maj = 0, v_min = 0}, hdr_start = -1, hdr_end = -1,
request_parse_status = HTTP_STATUS_NONE}, switchedToHttps_ = false,
sslConnectHostOrIp = {static npos = <optimized out>, size_ = 36, len_ = 13,
buf_ = 0x4a300f40 "199.59.150.43"}, sslCommonName = {
static npos = <optimized out>, size_ = 36, len_ = 11,
buf_ = 0x4a300df0 "r.twimg.com"}, sslBumpCertKey = {
static npos = <optimized out>, size_ = 128, len_ = 95,
buf_ = 0x49ffb200 "/C=US/ST=CA/L=San Francisco/O=Twitter, Inc./OU=Twitter Security/CN=r.twimg.com+Sign=signTrusted"}, sslServerBump = 0x4a3efaa0,
---Type <return> to continue, or q <return> to quit---
signAlgorithm = Ssl::algSignTrusted, stoppedSending_ = 0x0,
stoppedReceiving_ = 0x0, reader = {p_ = 0x0}, bodyPipe = {p_ = 0x0},
static CBDATA_ConnStateData = 19}
From the cache.log with debug_options ALL,1 83,9:
FATAL: Received Segment Violation...dying.
2013/05/08 17:17:38.618 kid1| Closing HTTP port 0.0.0.0:3128
2013/05/08 17:17:38.618 kid1| Closing HTTP port 0.0.0.0:6128
2013/05/08 17:17:38.618 kid1| Closing HTTPS port 0.0.0.0:3129
2013/05/08 17:17:38.618 kid1| storeDirWriteCleanLogs: Starting...
2013/05/08 17:17:38.618 kid1| Finished. Wrote 0 entries.
2013/05/08 17:17:38.618 kid1| Took 0.00 seconds ( 0.00 entries/sec).
CPU Usage: 0.273 seconds = 0.212 user + 0.061 sys
Maximum Resident Size: 68000 KB
Page faults with physical i/o: 1
2013/05/08 17:17:42 kid1| Starting Squid Cache version 3.3.4 for i386-portbld-freebsd9.1...
2013/05/08 17:17:42 kid1| Process ID 12126
2013/05/08 17:17:42 kid1| Process Roles: worker
2013/05/08 17:17:42 kid1| With 36864 file descriptors available
2013/05/08 17:17:42 kid1| Initializing IP Cache...
2013/05/08 17:17:42 kid1| DNS Socket created at 0.0.0.0, FD 7
2013/05/08 17:17:42 kid1| Adding domain internal.ghelmer.homeunix.com from /etc/resolv.conf
2013/05/08 17:17:42 kid1| Adding nameserver 10.1.1.11 from /etc/resolv.conf
2013/05/08 17:17:42 kid1| Adding nameserver 205.171.3.65 from /etc/resolv.conf
2013/05/08 17:17:42 kid1| Adding nameserver 205.171.2.65 from /etc/resolv.conf
2013/05/08 17:17:42 kid1| helperOpenServers: Starting 5/5 'ssl_crtd' processes
2013/05/08 17:17:42 kid1| WARNING: no_suid: setuid(0): (1) Operation not permitted
2013/05/08 17:17:42 kid1| WARNING: no_suid: setuid(0): (1) Operation not permitted
2013/05/08 17:17:42 kid1| WARNING: no_suid: setuid(0): (1) Operation not permitted
2013/05/08 17:17:42 kid1| WARNING: no_suid: setuid(0): (1) Operation not permitted
2013/05/08 17:17:42 kid1| WARNING: no_suid: setuid(0): (1) Operation not permitted
2013/05/08 17:17:42.082 kid1| ErrorDetailManager.cc(251) parse: Remain size: 72 Content: name: X509_V_ERR_AKID_ISSUER_SERIAL_MISMATCH
detail: "%ssl_error_descr:
2013/05/08 17:17:42.083 kid1| ErrorDetailManager.cc(251) parse: Remain size: 125 Content: name: X509_V_ERR_APPLICATION_VERIFICATION
detail: "%ssl_error_descr: %ssl_subject"
descr: "Application verification failure"
2013/05/08 17:17:42.083 kid1| ErrorDetailManager.cc(251) parse: Remain size: 0 Content:
2013/05/08 17:17:42.083 kid1| Logfile: opening log daemon:/var/log/squid/access.log
2013/05/08 17:17:42.083 kid1| Logfile Daemon: opening log /var/log/squid/access.log
2013/05/08 17:17:42.083 kid1| WARNING: no_suid: setuid(0): (1) Operation not permitted
2013/05/08 17:17:42.083 kid1| Store logging disabled
2013/05/08 17:17:42.083 kid1| Swap maxSize 0 + 262144 KB, estimated 20164 objects
2013/05/08 17:17:42.083 kid1| Target number of buckets: 1008
2013/05/08 17:17:42.083 kid1| Using 8192 Store buckets
2013/05/08 17:17:42.083 kid1| Max Mem size: 262144 KB
2013/05/08 17:17:42.083 kid1| Max Swap size: 0 KB
2013/05/08 17:17:42.083 kid1| Using Least Load store dir selection
2013/05/08 17:17:42.083 kid1| Set Current Directory to /var/log/squid
2013/05/08 17:17:42.083 kid1| Loaded Icons.
2013/05/08 17:17:42.083 kid1| HTCP Disabled.
2013/05/08 17:17:42.083 kid1| Squid plugin modules loaded: 0
2013/05/08 17:17:42.083 kid1| Adaptation support is on
2013/05/08 17:17:42.083 kid1| Accepting NAT intercepted HTTP Socket connections at local=0.0.0.0:3128 remote=[::] FD 20 flags=41
2013/05/08 17:17:42.083 kid1| Accepting HTTP Socket connections at local=0.0.0.0:6128 remote=[::] FD 21 flags=9
2013/05/08 17:17:42.083 kid1| Accepting NAT intercepted SSL bumped HTTPS Socket connections at local=0.0.0.0:3129 remote=[::] FD 22 flags=41
2013/05/08 17:17:43 kid1| storeLateRelease: released 0 objects
2013/05/08 17:17:44.100 kid1| support.cc(242) ssl_verify_cb: SSL Certificate signature OK: /C=US/ST=California/L=Mountain View/O=Google Inc/CN=mail.google.com
2013/05/08 17:17:44.101 kid1| support.cc(242) ssl_verify_cb: SSL Certificate signature OK: /C=US/ST=California/L=Mountain View/O=Google Inc/CN=mail.google.com
2013/05/08 17:17:44.101 kid1| support.cc(242) ssl_verify_cb: SSL Certificate signature OK: /C=US/ST=California/L=Mountain View/O=Google Inc/CN=mail.google.com
2013/05/08 17:17:44.129 kid1| support.cc(798) configureSslContext: Setting RSA key generation callback.
2013/05/08 17:17:44.129 kid1| support.cc(801) configureSslContext: Setting CA certificate locations.
2013/05/08 17:17:44.130 kid1| support.cc(844) configureSslContext: Not requiring any client certificates
2013/05/08 17:17:44.130 kid1| client_side.cc(3461) clientNegotiateSSL: clientNegotiateSSL: Error negotiating SSL connection on FD 9: Aborted by client
2013/05/08 17:17:44.136 kid1| support.cc(242) ssl_verify_cb: SSL Certificate signature OK: /C=US/ST=California/L=Mountain View/O=Google Inc/CN=mail.google.com
2013/05/08 17:17:44.136 kid1| support.cc(242) ssl_verify_cb: SSL Certificate signature OK: /C=US/ST=California/L=Mountain View/O=Google Inc/CN=mail.google.com
2013/05/08 17:17:44.136 kid1| support.cc(242) ssl_verify_cb: SSL Certificate signature OK: /C=US/ST=California/L=Mountain View/O=Google Inc/CN=mail.google.com
FATAL: Received Segment Violation...dying.
2013/05/08 17:17:44.136 kid1| Closing HTTP port 0.0.0.0:3128
2013/05/08 17:17:44.136 kid1| Closing HTTP port 0.0.0.0:6128
2013/05/08 17:17:44.136 kid1| Closing HTTPS port 0.0.0.0:3129
2013/05/08 17:17:44.136 kid1| storeDirWriteCleanLogs: Starting...
2013/05/08 17:17:44.136 kid1| Finished. Wrote 0 entries.
2013/05/08 17:17:44.136 kid1| Took 0.00 seconds ( 0.00 entries/sec).
CPU Usage: 0.140 seconds = 0.121 user + 0.019 sys
Maximum Resident Size: 63936 KB
Page faults with physical i/o: 0
2013/05/08 17:17:47 kid1| Starting Squid Cache version 3.3.4 for i386-portbld-freebsd9.1...
2013/05/08 17:17:47 kid1| Process ID 12135
2013/05/08 17:17:47 kid1| Process Roles: worker
2013/05/08 17:17:47 kid1| With 36864 file descriptors available
2013/05/08 17:17:47 kid1| Initializing IP Cache...
2013/05/08 17:17:47 kid1| DNS Socket created at 0.0.0.0, FD 7
2013/05/08 17:17:47 kid1| Adding domain internal.ghelmer.homeunix.com from /etc/resolv.conf
2013/05/08 17:17:47 kid1| Adding nameserver 10.1.1.11 from /etc/resolv.conf
2013/05/08 17:17:47 kid1| Adding nameserver 205.171.3.65 from /etc/resolv.conf
2013/05/08 17:17:47 kid1| Adding nameserver 205.171.2.65 from /etc/resolv.conf
2013/05/08 17:17:47 kid1| helperOpenServers: Starting 5/5 'ssl_crtd' processes
2013/05/08 17:17:47 kid1| WARNING: no_suid: setuid(0): (1) Operation not permitted
2013/05/08 17:17:47 kid1| WARNING: no_suid: setuid(0): (1) Operation not permitted
2013/05/08 17:17:47 kid1| WARNING: no_suid: setuid(0): (1) Operation not permitted
2013/05/08 17:17:47 kid1| WARNING: no_suid: setuid(0): (1) Operation not permitted
2013/05/08 17:17:47 kid1| WARNING: no_suid: setuid(0): (1) Operation not permitted
2013/05/08 17:17:47.601 kid1| ErrorDetailManager.cc(251) parse: Remain size: 72 Content: name: X509_V_ERR_AKID_ISSUER_SERIAL_MISMATCH
detail: "%ssl_error_descr:
2013/05/08 17:17:47.602 kid1| ErrorDetailManager.cc(251) parse: Remain size: 125 Content: name: X509_V_ERR_APPLICATION_VERIFICATION
detail: "%ssl_error_descr: %ssl_subject"
descr: "Application verification failure"
2013/05/08 17:17:47.602 kid1| ErrorDetailManager.cc(251) parse: Remain size: 0 Content:
2013/05/08 17:17:47.602 kid1| Logfile: opening log daemon:/var/log/squid/access.log
2013/05/08 17:17:47.602 kid1| Logfile Daemon: opening log /var/log/squid/access.log
2013/05/08 17:17:47.602 kid1| WARNING: no_suid: setuid(0): (1) Operation not permitted
2013/05/08 17:17:47.602 kid1| Store logging disabled
2013/05/08 17:17:47.602 kid1| Swap maxSize 0 + 262144 KB, estimated 20164 objects
2013/05/08 17:17:47.602 kid1| Target number of buckets: 1008
2013/05/08 17:17:47.602 kid1| Using 8192 Store buckets
2013/05/08 17:17:47.602 kid1| Max Mem size: 262144 KB
2013/05/08 17:17:47.602 kid1| Max Swap size: 0 KB
2013/05/08 17:17:47.602 kid1| Using Least Load store dir selection
2013/05/08 17:17:47.602 kid1| Set Current Directory to /var/log/squid
2013/05/08 17:17:47.602 kid1| Loaded Icons.
2013/05/08 17:17:47.602 kid1| HTCP Disabled.
2013/05/08 17:17:47.602 kid1| Squid plugin modules loaded: 0
2013/05/08 17:17:47.602 kid1| Adaptation support is on
2013/05/08 17:17:47.602 kid1| Accepting NAT intercepted HTTP Socket connections at local=0.0.0.0:3128 remote=[::] FD 20 flags=41
2013/05/08 17:17:47.602 kid1| Accepting HTTP Socket connections at local=0.0.0.0:6128 remote=[::] FD 21 flags=9
2013/05/08 17:17:47.602 kid1| Accepting NAT intercepted SSL bumped HTTPS Socket connections at local=0.0.0.0:3129 remote=[::] FD 22 flags=41
2013/05/08 17:17:48 kid1| storeLateRelease: released 0 objects
Received on Wed May 08 2013 - 22:31:41 MDT
This archive was generated by hypermail 2.2.0 : Thu May 09 2013 - 12:00:07 MDT