[squid-users] squid-3.5.19 crash(Segment Violation)

asakura at ioc.dnp.co.jp asakura at ioc.dnp.co.jp
Thu Jun 9 08:09:48 UTC 2016


Hello,

I need help about squid-3.5.19 crash(Segment Violation)

I posted question at 2016 March(attached last sentence)
And at last month, I upgrade squid 3.5.1 to 3.5.19, then solved this
issue(Thank you!)

But other problem occured.
When I change squid.conf and reconfigure squid, sometimes
squid crashed(Problem occured 3 times between 2016/6/6 to 2016/6/9)

Can we prevent crash of squid by thise problem?

Dying-message is below,
----
2016/06/07 13:09:23 kid1| Reconfiguring Squid Cache (version 3.5.19)...
2016/06/07 13:09:23 kid1| Closing HTTP port 0.0.0.0:8080
2016/06/07 13:09:23 kid1| Logfile: closing log daemon:/var/log/squid.dir/access.log
2016/06/07 13:09:23 kid1| Logfile Daemon: closing log daemon:/var/log/squid.dir/access.log
2016/06/07 13:09:23 kid1| Startup: Initializing Authentication Schemes ...
2016/06/07 13:09:23 kid1| Startup: Initialized Authentication Scheme 'basic'
2016/06/07 13:09:23 kid1| Startup: Initialized Authentication Scheme 'digest'
2016/06/07 13:09:23 kid1| Startup: Initialized Authentication Scheme 'negotiate'
2016/06/07 13:09:23 kid1| Startup: Initialized Authentication Scheme 'ntlm'
2016/06/07 13:09:23 kid1| Startup: Initialized Authentication.
2016/06/07 13:09:23 kid1| Processing Configuration File: /usr/local/squid-3.5.19-errorpage-follow-x-forwarded-for/etc/squid.conf (depth 0)
2016/06/07 13:09:23 kid1| WARNING: HTTP requires the use of Via
2016/06/07 13:09:23 kid1| Logfile: opening log daemon:/var/log/squid.dir/access.log
2016/06/07 13:09:23 kid1| Logfile Daemon: opening log /var/log/squid.dir/access.log
2016/06/07 13:09:23 kid1| Squid plugin modules loaded: 0
2016/06/07 13:09:23 kid1| Adaptation support is off.
2016/06/07 13:09:23 kid1| Store logging disabled
2016/06/07 13:09:23 kid1| DNS Socket created at 0.0.0.0, FD 12
2016/06/07 13:09:23 kid1| Adding domain (sorry, masked) from /etc/resolv.conf
2016/06/07 13:09:23 kid1| Adding nameserver (sorry, masked) from /etc/resolv.conf
2016/06/07 13:09:23 kid1| Adding nameserver (sorry, masked) from /etc/resolv.conf
2016/06/07 13:09:23 kid1| helperOpenServers: Starting 100/400 'negotiate_wrapper_auth' processes
2016/06/07 13:09:24 kid1| helperOpenServers: Starting 100/400 'ntlm_auth' processes
2016/06/07 13:09:25 kid1| helperOpenServers: Starting 15/100 'ext_ldap_group_acl' processes
2016/06/07 13:09:25 kid1| helperOpenServers: Starting 15/100 'ext_ldap_group_acl' processes
2016/06/07 13:09:25 kid1| HTCP Disabled.
2016/06/07 13:09:25 kid1| Configuring Parent (sorry, masked)/8080/7
2016/06/07 13:09:25 kid1| Configuring Parent (sorry, masked)/8080/7
2016/06/07 13:09:25 kid1| Configuring Parent (sorry, masked)/8080/7
2016/06/07 13:09:25 kid1| Configuring Parent (sorry, masked)/8080/7
2016/06/07 13:09:25 kid1| Configuring Parent (sorry, masked)/8080/7
2016/06/07 13:09:25 kid1| Configuring Parent (sorry, masked)/8080/7
2016/06/07 13:09:25 kid1| Finished loading MIME types and icons.
2016/06/07 13:09:25 kid1| Accepting HTTP Socket connections at local=0.0.0.0:8080 remote=[::] FD 1398 flags=9
FATAL: Received Segment Violation...dying.
2016/06/07 13:09:25 kid1| Closing HTTP port 0.0.0.0:8080
2016/06/07 13:09:25 kid1| storeDirWriteCleanLogs: Starting...
2016/06/07 13:09:25 kid1|   Finished.  Wrote 0 entries.
2016/06/07 13:09:25 kid1|   Took 0.00 seconds (  0.00 entries/sec).
CPU Usage: 9659.361 seconds = 2433.226 user + 7226.134 sys
Maximum Resident Size: 528736 KB
Page faults with physical i/o: 0
----

I confirmed coredump by gdb command.

----
# pwd /var/spool/abrt/ccpp-2016-06-07-13:09:25-11730
# ls -l
total 104720
-rw-r----- 1 abrt squid         5 Jun  7 13:09 abrt_version
-rw-r----- 1 abrt squid         4 Jun  7 13:09 analyzer
-rw-r----- 1 abrt squid         6 Jun  7 13:09 architecture
-rw-r----- 1 abrt squid         0 Jun  7 13:09 cgroup
-rw-r----- 1 abrt squid         9 Jun  7 13:09 cmdline
-rw-r----- 1 abrt squid 143380480 Jun  7 13:09 coredump
-rw-r----- 1 abrt squid         1 Jun  7 13:11 count
-rw-r----- 1 abrt squid      1681 Jun  7 13:11 dso_list
-rw-r----- 1 abrt squid       183 Jun  7 13:09 environ
-rw-r----- 1 abrt squid        67 Jun  7 13:09 executable
-rw-r----- 1 abrt squid        15 Jun  7 13:09 hostname
-rw-r----- 1 abrt squid        26 Jun  7 13:09 kernel
-rw-r----- 1 abrt squid        10 Jun  7 13:09 last_occurrence
-rw-r----- 1 abrt squid      1323 Jun  7 13:09 limits
-rw-r----- 1 abrt squid      8865 Jun  7 13:09 maps
-rw-r----- 1 abrt squid       416 Jun  7 13:09 open_fds
-rw-r----- 1 abrt squid        54 Jun  7 13:09 os_release
-rw-r----- 1 abrt squid         5 Jun  7 13:09 pid
-rw-r----- 1 abrt squid        56 Jun  7 13:09 pwd
-rw-r----- 1 abrt squid       108 Jun  7 13:09 reason
-rw-r----- 1 abrt squid   2352400 Jun  7 13:11 sosreport.tar.xz
-rw-r----- 1 abrt squid        10 Jun  7 13:09 time
-rw-r----- 1 abrt squid         5 Jun  7 13:09 uid
-rw-r----- 1 abrt squid         6 Jun  7 13:09 username
-rw-r----- 1 abrt squid        40 Jun  7 13:11 uuid
# gdb /usr/local/squid-3.5.19-errorpage-follow-x-forwarded-for/sbin/squid coredump
GNU gdb (GDB) Red Hat Enterprise Linux (7.2-75.el6)
Copyright (C) 2010 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-redhat-linux-gnu".
For bug reporting instructions, please see:
<http://www.gnu.org/software/gdb/bugs/>...
Reading symbols from /usr/local/squid-3.5.19-errorpage-follow-x-forwarded-for/sbin/squid...done.
[New Thread 11730]
Missing separate debuginfo for
Try: yum --enablerepo='*-debug*' install /usr/lib/debug/.build-id/b7/4f8095168b93495573fcca21245eb3900f05ea
Reading symbols from /lib64/libpthread.so.0...(no debugging symbols found)...done.
[Thread debugging using libthread_db enabled]
Loaded symbols for /lib64/libpthread.so.0
Reading symbols from /lib64/libcrypt.so.1...(no debugging symbols found)...done.
Loaded symbols for /lib64/libcrypt.so.1
Reading symbols from /lib64/libgssapi_krb5.so.2...(no debugging symbols found)...done.
Loaded symbols for /lib64/libgssapi_krb5.so.2
Reading symbols from /lib64/libkrb5.so.3...(no debugging symbols found)...done.
Loaded symbols for /lib64/libkrb5.so.3
Reading symbols from /lib64/libk5crypto.so.3...(no debugging symbols found)...done.
Loaded symbols for /lib64/libk5crypto.so.3
Reading symbols from /lib64/libcom_err.so.2...(no debugging symbols found)...done.
Loaded symbols for /lib64/libcom_err.so.2
Reading symbols from /lib64/libnsl.so.1...(no debugging symbols found)...done.
Loaded symbols for /lib64/libnsl.so.1
Reading symbols from /lib64/libresolv.so.2...(no debugging symbols found)...done.
Loaded symbols for /lib64/libresolv.so.2
Reading symbols from /lib64/librt.so.1...(no debugging symbols found)...done.
Loaded symbols for /lib64/librt.so.1
Reading symbols from /lib64/libdl.so.2...(no debugging symbols found)...done.
Loaded symbols for /lib64/libdl.so.2
Reading symbols from /usr/lib64/libstdc++.so.6...(no debugging symbols found)...done.
Loaded symbols for /usr/lib64/libstdc++.so.6
Reading symbols from /lib64/libm.so.6...(no debugging symbols found)...done.
Loaded symbols for /lib64/libm.so.6
Reading symbols from /lib64/libgcc_s.so.1...(no debugging symbols found)...done.
Loaded symbols for /lib64/libgcc_s.so.1
Reading symbols from /lib64/libc.so.6...(no debugging symbols found)...done.
Loaded symbols for /lib64/libc.so.6
Reading symbols from /lib64/ld-linux-x86-64.so.2...(no debugging symbols found)...done.
Loaded symbols for /lib64/ld-linux-x86-64.so.2
Reading symbols from /lib64/libfreebl3.so...(no debugging symbols found)...done.
Loaded symbols for /lib64/libfreebl3.so
Reading symbols from /lib64/libkrb5support.so.0...(no debugging symbols found)...done.
Loaded symbols for /lib64/libkrb5support.so.0
Reading symbols from /lib64/libkeyutils.so.1...(no debugging symbols found)...done.
Loaded symbols for /lib64/libkeyutils.so.1
Reading symbols from /lib64/libselinux.so.1...(no debugging symbols found)...done.
Loaded symbols for /lib64/libselinux.so.1
Reading symbols from /lib64/libnss_files.so.2...(no debugging symbols found)...done.
Loaded symbols for /lib64/libnss_files.so.2
Core was generated by `(squid-1)'.
Program terminated with signal 6, Aborted.
#0  0x000000353e432625 in raise () from /lib64/libc.so.6
Missing separate debuginfos, use: debuginfo-install glibc-2.12-1.149.el6_6.7.x86_64 keyutils-libs-1.4-5.el6.x86_64 krb5-libs-1.10.3-37.el6_6.x86_64 libcom_err-1.41.12-21.el6.x86_64 libgcc-4.4.7-11.el6.x86_64 libselinux-2.0.94-5.8.el6.x86_64 libstdc++-4.4.7-11.el6.x86_64 nss-softokn-freebl-3.14.3-22.el6_6.x86_64
(gdb) bt full
#0  0x000000353e432625 in raise () from /lib64/libc.so.6
No symbol table info available.
#1  0x000000353e433e05 in abort () from /lib64/libc.so.6
No symbol table info available.
#2  0x00000000006676cf in death (sig=<value optimized out>) at tools.cc:356
No locals.
#3  <signal handler called>
No symbol table info available.
#4  0x000000000066fcac in TunnelStateData::handleConnectResponse (
    this=0x7d7f7c8, chunkSize=<value optimized out>) at tunnel.cc:478
        rep = {<HttpMsg> = {<Lock> = {_vptr.Lock = 0x853aa8, count_ = 0},
            _vptr.HttpMsg = 0x853a38, http_ver = {<AnyP::ProtocolVersion> = {
                protocol = AnyP::PROTO_HTTP, major = 1,
                minor = 0}, <No data fields>}, header = {
              entries = std::vector of length 0, capacity 0,
              mask = '\000' <repeats 11 times>, owner = hoReply, len = 0,
              conflictingContentLength_ = false}, cache_control = 0x0,
            hdr_sz = 39, content_length = -1, pstate = psParsed, body_pipe = {
              p_ = 0x0}}, date = -1, last_modified = -1, expires = -1,
          content_type = {static npos = 18446744073709551615, size_ = 0,
            len_ = 0, static SizeMax_ = 18446744073709551615, buf_ = 0x0},
          surrogate_control = 0x0, content_range = 0x0, keep_alive = 0,
          sline = {protocol = AnyP::PROTO_HTTP,
            version = {<AnyP::ProtocolVersion> = {protocol = AnyP::PROTO_HTTP,
                major = 1, minor = 0}, <No data fields>},
            status_ = Http::scOkay, reason_ = 0x0}, body = {mb = 0x48d2688},
          protoPrefix = {static npos = 18446744073709551615, size_ = 40,
            len_ = 5, static SizeMax_ = 18446744073709551615,
            buf_ = 0x37e3720 "HTTP/"}, do_clean = true, bodySizeMax = -2}
        parseErr = Http::scNone
        pwd = <value optimized out>
        relay = <value optimized out>
        eof = false
        parsed = <value optimized out>
#5  0x00000000006702cb in TunnelStateData::readConnectResponseDone (
    this=0x7d7f7c8, buf=<value optimized out>, len=39, errcode=Comm::OK,
    xerrno=0) at tunnel.cc:389
        __FUNCTION__ = "readConnectResponseDone"
#6  0x00000000006f6598 in AsyncCall::make (this=0x6c53d10) at AsyncCall.cc:40
        __FUNCTION__ = "make"
#7  0x00000000006f9c2e in AsyncCallQueue::fireNext (this=<value optimized out>)
    at AsyncCallQueue.cc:56
        call = {p_ = 0x6c53d10}
        __FUNCTION__ = "fireNext"
#8  0x00000000006f9fa0 in AsyncCallQueue::fire (this=0x2ab69f0)
    at AsyncCallQueue.cc:42
        made = true
#9  0x00000000005853fc in EventLoop::runOnce (this=0x7fffa0626350)
    at EventLoop.cc:120
        sawActivity = <value optimized out>
        waitingEngine = 0x7fffa0626400
        __FUNCTION__ = "runOnce"
#10 0x00000000005855a0 in EventLoop::run (this=0x7fffa0626350)
    at EventLoop.cc:82
No locals.
#11 0x00000000005ef5cd in SquidMain (argc=<value optimized out>,
    argv=<value optimized out>) at main.cc:1539
        WIN32_init_err = 0
        __FUNCTION__ = "SquidMain"
        signalEngine = {<AsyncEngine> = {
            _vptr.AsyncEngine = 0x856a90}, <No data fields>}
        store_engine = {<AsyncEngine> = {
            _vptr.AsyncEngine = 0x856af0}, <No data fields>}
        comm_engine = {<AsyncEngine> = {
            _vptr.AsyncEngine = 0xb251f0}, <No data fields>}
        mainLoop = {errcount = 0, static Running = 0x7fffa0626350,
          last_loop = false, engines = std::vector of length 4, capacity 4 = {
            0x7fffa0626420, 0xb50150, 0x7fffa0626410, 0x7fffa0626400},
          timeService = 0x7fffa06263f0, primaryEngine = 0x7fffa0626400,
          loop_delay = 0, error = false, runOnceResult = false}
        time_engine = {_vptr.TimeEngine = 0x865eb0}
#12 0x00000000005f02a8 in SquidMainSafe (argc=<value optimized out>,
    argv=<value optimized out>) at main.cc:1263
No locals.
#13 main (argc=<value optimized out>, argv=<value optimized out>)
    at main.cc:1256
No locals.
(gdb) quit
----

Our environment is below,
- squid-3.5.19 with squid_kerb_auth x10 server
  (currently, three server crashed by this problem)
- using BIG-IP LTM load balancer
- enable "follow_x_fowarded_for" option
- User ID number is about 6600
- IP address number is about 7600
- Most user authentication is ActiveDirectory(Kerberos), NTLM is only a little
- Normaly, CPU load is about 20%

Regards,
Kazuhiro


From: asakura at ioc.dnp.co.jp
Subject: Re: [squid-users] access from same ID and different IP addresses.
Date: Thu, 17 Mar 2016 21:50:43 +0900 (JST)

> Thank you Amos,
>
> I will consider squid version up of squid.
>
> By the way, the UserID and IP segment of problem is not currently used.
> They are scheduled to be used again in May 2016.
>
> It will report if there is any good news.
>
>
> Regards,
> Kazuhiro
>
>
> From: Amos Jeffries <squid3 at treenet.co.nz>
> Subject: Re: [squid-users] access from same ID and different IP addresses.
> Date: Thu, 17 Mar 2016 01:35:07 +1300
>
> > On 16/03/2016 5:06 p.m., asakura at ioc.dnp.co.jp wrote:
> > > Hello,
> > >
> > > Recently, in our environment, CPU load on the squid proxy server
> > > is happening trouble to become a 100%.
> > >
> > > example----
> > > PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM    TIME+  COMMAND
> > > 29767 squid     20   0 1430m 1.3g 5332 R 99.1 17.4   6836:56 squid
> > > 16856 squid     20   0 29764 3280 1620 S  2.0  0.0  68:46.34 squid_kerb_auth
> > > 16860 squid     20   0 29760 3272 1616 S  1.7  0.0  43:53.67 squid_kerb_auth
> > > 16855 squid     20   0 22636 1244 1000 S  0.3  0.0   2:57.66 negotiate_wrapp
> > > 21437 asakura   20   0 15432 1632  932 R  0.3  0.0   0:01.02 top
> > > 26167 root      20   0 19088 2248 1060 S  0.3  0.0   1016:14 syslog-ng
> > > ---
> > >
> > > As a result of investigation, We suspect that CPU load become a 100%
> > > when user attempts to log in from more than different ip addresses.
> > >
> >
> > All that CPU has to be spent doing something. So what is that something?
> >
> >
> > > This time, squid has been accessed from 20 or more units of
> > > the PC with the same user ID.
> > > When we disable user authentication from target segment, CPU load be low.
> > >
> > > We want to know whether CPU load goes up when squid is accessed from
> > > a large number of different IP addresses with the same user ID.
> > >
> > > Our environment is below,
> > > - squid-3.5.1 with squid_kerb_auth(sorry old version...) x5 server
> >
> > First step is upgrading. So you can see if it is one of the thousand or
> > so bugs already fixed since that old version.
> >
> > There have been at least 2 bugs whose claimed symptom was "100% CPU
> > usage" that got fixed this past year.
> >
> >
> > Amos


More information about the squid-users mailing list