eClamAV crashes after a cl_load() error

[Yuri]

Squid 2.4.12 built with 64 bit on Solaris 10 kernel 150401-16 x86_64.
ClamAV 0.98.6 also built with 64 bit.
libecap 0.2.0 built with 64 bit.
ecap_clamav_adapter 0.2.1 also built with 64 bit.

This is production environment used 24x7 over 4 years.

eClamav cannot initialize and crashes Squid repeatedly with following error:

2015/02/26 17:45:40 kid1| Loading Squid module from
'/usr/local/lib/ecap_adapter_gzip.so'
2015/02/26 17:45:40 kid1| Loading Squid module from
'/usr/local/lib/ecap_clamav_adapter.so'
2015/02/26 17:45:40 kid1| Squid plugin modules loaded: 2
2015/02/26 17:45:40 kid1| Adaptation support is on
2015/02/26 17:45:40 kid1| Starting eCAP service:
ecap://www.vigos.com/ecap_gzip
2015/02/26 17:45:40 kid1| eClamAV: Initializing ClamAV engine #1.
FATAL: Received Segment Violation...dying.
2015/02/26 17:45:40 kid1| Closing HTTP port [::]:3127
2015/02/26 17:45:40 kid1| Closing HTTP port [::]:3128
2015/02/26 17:45:40 kid1| Closing HTTPS port [::]:3129
2015/02/26 17:45:40 kid1| Stop receiving ICP on [::]:3130
2015/02/26 17:45:40 kid1| assertion failed: icp_v2.cc:780:
"Comm::IsConnOpen(icpOutgoingConn)"

Note: core not produced - suid operations disabled die to security reasons.

Squid is compiled with 64 bit, ClamAV compiled with 64 bit, libecap
compiled with 64 bit, clamav ecap adapter compiled with 64 bit.

Squid config fragment related to ecap is:

ecap_enable on

loadable_modules /usr/local/lib/ecap_clamav_adapter.so
ecap_service clamav_service_req reqmod_precache uri=ecap://e-cap.org/ecap/services/clamav?mode=REQMOD bypass=off
ecap_service clamav_service_resp respmod_precache uri=ecap://e-cap.org/ecap/services/clamav?mode=RESPMOD bypass=on
adaptation_access clamav_service_req allow all
adaptation_access clamav_service_resp allow all

Looks like ok.

All runtime 64-bit libraries is available for linker:

root @ cthulhu /patch # crle -64

Configuration file [version 4]: /var/ld/64/ld.config
  Platform: 64-bit LSB AMD64
  Default Library Path (ELF):
/lib/64:/usr/lib/64:/opt/csw/lib/64:/usr/sfw/lib/64
  Trusted Directories (ELF): /lib/secure/64:/usr/lib/secure/64
(system default)

Command line:
  crle -64 -c /var/ld/64/ld.config -l
/lib/64:/usr/lib/64:/opt/csw/lib/64:/usr/sfw/lib/64

Installation prefix for all ecap related modules is /usr/local.

libecap successfully used on this installation with GZip adapter 1.3.0 and works perfectly.

When I comment out ecap_clamav_adapter lines in Squid.conf, all works perfectly.

We plan to replace c-icap + squidclamav AV checking framework with eCAP due to latency issues.

Need to solve problem.

Thank you.

[Alex Rousskov (rousskov)]

Have you patched ecap_clamav_adapter v0.2.1 to fix bug #1025567? If not, you should (or upgrade to v1.0.0 where the bug is fixed). https://bugs.launchpad.net/ecap/+bug/1025567

There is also fixed bug #800281. https://bugs.launchpad.net/ecap/+bug/800281

For a better chance of improving performance, consider eCAP ClamAV v1.0.0, with its support for asynchronous scans.

I am going to mark this bug as a duplicate but please feel free to add more comments if patching does not help. Posting a backtrace would be essential in that case.

[Yuri (yvoinov)]

I've patched it, but it cannot help.

The same error.

Squid dies with this:

root @ cthulhu /var/core # gdb /usr/local/squid/sbin/squid core.squid.37265
GNU gdb (GDB) 7.7
Copyright (C) 2014 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 "i386-pc-solaris2.10".
Type "show configuration" for configuration details.
For bug reporting instructions, please see:
<http://www.gnu.org/software/gdb/bugs/>.
Find the GDB manual and other documentation resources online at:
<http://www.gnu.org/software/gdb/documentation/>.
For help, type "help".
Type "apropos word" to search for commands related to "word"...
Reading symbols from /usr/local/squid/sbin/squid...(no debugging symbols found)...done.
[New LWP 1]

warning: Could not load shared library symbols for /usr/local/lib/ecap_clamav_adapter.so.
Do you need "set solib-search-path" or "set sysroot"?
[Thread debugging using libthread_db enabled]
[New Thread 1 (LWP 1)]
Core was generated by `(squid-1) -Y'.
Program terminated with signal SIGABRT, Aborted.
#0 0xfffffd7ffeb235da in _lwp_kill () from /lib/64/libc.so.1
(gdb) bt
#0 0xfffffd7ffeb235da in _lwp_kill () from /lib/64/libc.so.1
#1 0xfffffd7ffeb1bed3 in thr_kill () from /lib/64/libc.so.1
#2 0xfffffd7ffeac81a9 in raise () from /lib/64/libc.so.1
#3 0xfffffd7ffeaa6ba0 in abort () from /lib/64/libc.so.1
#4 0x000000000059e52f in xassert ()
#5 0x0000000000624b94 in icpConnectionShutdown() ()
#6 0x0000000000624c00 in icpClosePorts() ()
#7 0x00000000006a538c in death(int) ()
#8 0xfffffd7ffeb1ddd6 in __sighndlr () from /lib/64/libc.so.1
#9 0xfffffd7ffeb126a2 in call_user_handler () from /lib/64/libc.so.1
#10 0xfffffd7ffeb128ce in sigacthandler () from /lib/64/libc.so.1
#11 0xffffffffffffffff in ?? ()
#12 0x000000000000000b in ?? ()
#13 0x0000000000000000 in ?? ()
(gdb)

I know, this built stripped - this is production.

[Yuri (yvoinov)]

Will try to get complete debug trace on testing box. Now tries to reproduce bug.

[Yuri (yvoinov)]

Core exists, but contains no meaningful info. All components built with debug info:

root @ fhtagn /var/core # gdb /usr/local/squid/sbin/squid core.squid.49305
GNU gdb (GDB) 7.7
Copyright (C) 2014 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 "i386-pc-solaris2.10".
Type "show configuration" for configuration details.
For bug reporting instructions, please see:
<http://www.gnu.org/software/gdb/bugs/>.
Find the GDB manual and other documentation resources online at:
<http://www.gnu.org/software/gdb/documentation/>.
For help, type "help".
Type "apropos word" to search for commands related to "word"...
Reading symbols from /usr/local/squid/sbin/squid...(no debugging symbols found)...done.
[New LWP 1]
Core was generated by `(squid-1) -Y'.
Program terminated with signal SIGABRT, Aborted.
#0 0xfffffd7ffeb935da in ?? ()
(gdb) bt
#0 0xfffffd7ffeb935da in ?? ()
Cannot access memory at address 0xfffffd7fffdfe988
(gdb)

[Yuri (yvoinov)]

Tries to forceful debug info into Squid binaries. Enable stacktraces and cbdata.

The same:

2015/02/27 19:40:45 kid1| Starting eCAP service: ecap://www.vigos.com/ecap_gzip
2015/02/27 19:40:45 kid1| eClamAV: Initializing ClamAV engine #1.
FATAL: Received Segment Violation...dying.
2015/02/27 19:40:45 kid1| Closing HTTP port [::]:3127

root @ fhtagn /var/core # gdb /usr/local/squid/sbin/squid core.squid.22149
GNU gdb (GDB) 7.7
Copyright (C) 2014 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 "i386-pc-solaris2.10".
Type "show configuration" for configuration details.
For bug reporting instructions, please see:
<http://www.gnu.org/software/gdb/bugs/>.
Find the GDB manual and other documentation resources online at:
<http://www.gnu.org/software/gdb/documentation/>.
For help, type "help".
Type "apropos word" to search for commands related to "word"...
Reading symbols from /usr/local/squid/sbin/squid...(no debugging symbols found)...done.
[New LWP 1]
[Thread debugging using libthread_db enabled]
[New Thread 1 (LWP 1)]
Core was generated by `(squid-1) -Y'.
Program terminated with signal SIGABRT, Aborted.
#0 0xfffffd7ffeb935da in _lwp_kill () from /usr/lib/amd64/libc.so.1
(gdb) bt
#0 0xfffffd7ffeb935da in _lwp_kill () from /usr/lib/amd64/libc.so.1
#1 0xfffffd7ffeb8bed3 in thr_kill () from /usr/lib/amd64/libc.so.1
#2 0xfffffd7ffeb381a9 in raise () from /usr/lib/amd64/libc.so.1
#3 0xfffffd7ffeb16ba0 in abort () from /usr/lib/amd64/libc.so.1
#4 0x00000000005a17ef in xassert ()
#5 0x00000000006298e4 in icpConnectionShutdown() ()
#6 0x0000000000629960 in icpClosePorts() ()
#7 0x00000000006aacbc in death(int) ()
#8 0xfffffd7ffeb8ddd6 in __sighndlr () from /usr/lib/amd64/libc.so.1
#9 0xfffffd7ffeb826a2 in call_user_handler () from /usr/lib/amd64/libc.so.1
#10 0xfffffd7ffeb828ce in sigacthandler () from /usr/lib/amd64/libc.so.1
#11 0xffffffffffffffff in ?? ()
#12 0x000000000000000b in ?? ()
#13 0x0000000000000000 in ?? ()

No info. I don't know, what else can I do.

[Yuri (yvoinov)]

Even with forced -ggdb option has no info:

root @ fhtagn /var/core # gdb /usr/local/squid/sbin core.squid.61062
GNU gdb (GDB) 7.7
Copyright (C) 2014 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 "i386-pc-solaris2.10".
Type "show configuration" for configuration details.
For bug reporting instructions, please see:
<http://www.gnu.org/software/gdb/bugs/>.
Find the GDB manual and other documentation resources online at:
<http://www.gnu.org/software/gdb/documentation/>.
For help, type "help".
Type "apropos word" to search for commands related to "word"...
/usr/local/squid/sbin: No such file or directory.
[New LWP 1]
Core was generated by `(squid-1) -Y'.
Program terminated with signal SIGABRT, Aborted.
#0 0xfffffd7ffeb935da in ?? ()
(gdb) bt
#0 0xfffffd7ffeb935da in ?? ()
Cannot access memory at address 0xfffffd7fffdfe988

[Yuri (yvoinov)]

Oops, sorry. Wrong command line, that it:

root @ fhtagn /var/core # gdb /usr/local/squid/sbin/squid core.squid.61062
GNU gdb (GDB) 7.7
Copyright (C) 2014 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 "i386-pc-solaris2.10".
Type "show configuration" for configuration details.
For bug reporting instructions, please see:
<http://www.gnu.org/software/gdb/bugs/>.
Find the GDB manual and other documentation resources online at:
<http://www.gnu.org/software/gdb/documentation/>.
For help, type "help".
Type "apropos word" to search for commands related to "word"...
Reading symbols from /usr/local/squid/sbin/squid...done.
[New LWP 1]
Cannot access memory at address 0xfffffd7fff3fc4a8
Cannot access memory at address 0xfffffd7fff3fc4a0
(gdb) bt
#0 0xfffffd7ffeb935da in ?? ()
Cannot access memory at address 0xfffffd7fffdfe988

[Alex Rousskov (rousskov)]

You might be battling several problems here. One of them is probably related to the fact that Squid asserts while handling an earlier segfault -- you get a [useless] stack trace from the assertion instead of the stack trace from the earlier segfault. I can suggest two possible (untested in your environment) solutions, in the order of preference:

1. Start Squid from gdb itself.
2. Start Squid with command-line options -N and -C.

[Alex Rousskov (rousskov)]

And if you manage to start Squid from gdb, using -NC there would also help, of course.

[Yuri (yvoinov)]

[BEGIN] 27.02.15 21:23:49
Last login: Fri Feb 27 21:21:19 2015 from 5.251.46.63

root @ fhtagn / # cd /usr/local/squid/sbin
root @ fhtagn /usr/local/squid/sbin # gdb squid
GNU gdb (GDB) 7.7
Copyright (C) 2014 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 "i386-pc-solaris2.10".
Type "show configuration" for configuration details.
For bug reporting instructions, please see:
<http://www.gnu.org/software/gdb/bugs/>.
Find the GDB manual and other documentation resources online at:
<http://www.gnu.org/software/gdb/documentation/>.
For help, type "help".
Type "apropos word" to search for commands related to "word"...
Reading symbols from squid...done.
(gdb) handle SIGPIPE pass nostop noprint
Signal Stop Print Pass to program Description
SIGPIPE No No Yes Broken pipe
(gdb) handle SIGTERM pass nostop noprint
Signal Stop Print Pass to program Description
SIGTERM No No Yes Terminated
(gdb) handle SIGUSR1 pass nostop noprint
Signal Stop Print Pass to program Description
SIGUSR1 No No Yes User defined signal 1
(gdb) handle SIGSEGV stop
Signal Stop Print Pass to program Description
SIGSEGV Yes Yes Yes Segmentation fault
(gdb) handle SIGABRT stop
Signal Stop Print Pass to program Description
SIGABRT Yes Yes Yes Aborted
(gdb) run -DNYCX
Starting program: /usr/local/squid/sbin/squid -DNYCX
[Thread debugging using libthread_db enabled]
2015/02/27 21:24:16| WARNING: -D command-line option is obsolete.
2015/02/27 21:24:16.528| debug.cc(425) parseOptions: command-line -X overrides: ALL,7
2015/02/27 21:24:16.528| cache_manager.cc(102) registerProfile: registering legacy mem
2015/02/27 21:24:16.528| cache_manager.cc(136) findAction: CacheManager::findAction: looking for action mem
2015/02/27 21:24:16.528| cache_manager.cc(144) findAction: Action not found.
2015/02/27 21:24:16.528| cache_manager.cc(87) registerProfile: registered profile: mem
2015/02/27 21:24:16.528| cache_manager.cc(102) registerProfile: registering legacy squidaio_counts
2015/02/27 21:24:16.528| cache_manager.cc(136) findAction: CacheManager::findAction: looking for action squidaio_counts
2015/02/27 21:24:16.528| cache_manager.cc(144) findAction: Action not found.
2015/02/27 21:24:16.528| cache_manager.cc(87) registerProfile: registered profile: squidaio_counts
2015/02/27 21:24:16.528| cache_manager.cc(136) findAction: CacheManager::findAction: looking for action diskd
2015/02/27 21:24:16.528| cache_manager.cc(144) findAction: Action not found.
2015/02/27 21:24:16.528| cache_manager.cc(87) registerProfile: registered profile: diskd
2015/02/27 21:24:16.528| Startup: Initializing Authentication Schemes ...
2015/02/27 21:24:16.528| Startup: Initialized Authentication Scheme 'basic'
2015/02/27 21:24:16.528| Startup: Initialized A...

[Yuri (yvoinov)]

BTW, is it clamav library path is hardcoded in module?

[Alex Rousskov (rousskov)]

Looks like you have your answer:

  LibClamAV Error: cl_load(): No such file or directory: /usr/local/clamav/share/clamav

The clamav library path is not hard-coded in the eCAP ClamAV adapter sources. The adapter is linked with "-lclamav" during build. Please note that the above error is not from the adapter. It is from your libclamav *library*. FWIW, the adapter uses a cl_retdbdir() function from that library for the first cl_load() parameter.

[Yuri (yvoinov)]

Heh, understand. Clamav for unclean reasons looks db in /usr/local/clamav/share/clamav. But why, if in clamd.conf specified another path?

This:

root @ fhtagn /usr/local/clamav/share # ln -s /var/lib/clamav clamav

root @ fhtagn /usr/local/clamav/share # ls -al
total 5
drwxr-xr-x 3 root root 4 Feb 27 21:59 .
drwxr-xr-x 8 root root 8 Feb 27 18:51 ..
lrwxrwxrwx 1 root root 15 Feb 27 21:59 clamav -> /var/lib/clamav
drwxr-xr-x 5 root root 5 Feb 27 18:51 man

solves problem.

[Alex Rousskov (rousskov)]

I do not think libclamav uses or knows about clamd.conf. The latter is a configuration file for clamd.

IIRC, libclamav does not use clamd, but clamd uses libclamav. The eCAP ClamAV adapter uses libclamav and does not know about clamd (yet?).

[Yuri (yvoinov)]

Another problem.

If ecap_gzip also enabled, HTTP request produces core dump:

Program received signal SIGSEGV, Segmentation fault.
[Switching to Thread 1 (LWP 1)]
0xfffffd7ffeb72242 in _Unwind_Resume () from /lib/64/libc.so.1
(gdb) backtrace
#0 0xfffffd7ffeb72242 in _Unwind_Resume () from /lib/64/libc.so.1
#1 0xfffffd7ffe457f22 in Adapter::Xaction::start() ()
   from /usr/local/lib/ecap_adapter_gzip.so
#2 0x00000000007cb622 in Adaptation::Ecap::XactionRep::start (this=0x2ddbfb8)
    at XactionRep.cc:243
#3 0x000000000072ba0d in AsyncCallT<NullaryMemFunT<AsyncJob> >::fire() ()
#4 0x0000000000727dd9 in AsyncCall::make (this=0x3876500) at AsyncCall.cc:32
#5 0x000000000072c0ff in AsyncCallQueue::fireNext (this=this@entry=0xa3d4f0)
    at AsyncCallQueue.cc:52
#6 0x000000000072c4fa in AsyncCallQueue::fire (this=0xa3d4f0)
    at AsyncCallQueue.cc:38
#7 0x00000000005b4a02 in dispatchCalls (this=0xfffffd7fffdff580)
    at EventLoop.cc:158
#8 EventLoop::runOnce (this=this@entry=0xfffffd7fffdff580) at EventLoop.cc:135
#9 0x00000000005b4bb8 in EventLoop::run (this=this@entry=0xfffffd7fffdff580)
    at EventLoop.cc:99
#10 0x0000000000637971 in SquidMain (argc=<optimized out>,
    argv=<optimized out>) at main.cc:1528
#11 0x000000000083205c in SquidMainSafe (argv=<optimized out>,
    argc=<optimized out>) at main.cc:1260
#12 main (argc=<optimized out>, argv=<optimized out>) at main.cc:1252

Config snippet is:

ecap_enable on
acl HTTP_STATUS_OK http_status 200

loadable_modules /usr/local/lib/ecap_adapter_gzip.so
ecap_service gzip_service respmod_precache ecap://www.vigos.com/ecap_gzip bypass=off
adaptation_access gzip_service allow HTTP_STATUS_OK

loadable_modules /usr/local/lib/ecap_clamav_adapter.so
ecap_service clamav_service_req reqmod_precache uri=ecap://e-cap.org/ecap/services/clamav?mode=REQMOD bypass=off
ecap_service clamav_service_resp respmod_precache uri=ecap://e-cap.org/ecap/services/clamav?mode=RESPMOD bypass=on
adaptation_access clamav_service_req allow all
adaptation_access clamav_service_resp allow all

What can be wrong? Without clamav adapter gzip works perfectly. clamav without gzip too. Does library support only one loadable module?

[Alex Rousskov (rousskov)]

In summary, it is my understanding that there are two eCAP-related bugs here:

1. The critical "LibClamAV Error" is not visible in cache.log unless Squid is started with elevated debugging levels.
2. Either the adapter or Squid itself crash with SIGSEGV when handling the exception thrown by the adapter.

I have removed the duplicate status to reflect this new understanding of this bug scope.

[Alex Rousskov (rousskov)]

eCAP supports multiple adapters in one host application. Squid should support that as well.

Since this issue is specific to an older eCAP library, it will get less attention. To improve your chances of getting this "multiple adapters" issue addressed, I recommend:

1. Re-arranging the order of the modules so that it is eClamAV that crashes instead of the Vigos gzip adapter (if that is possible).

2. Filing a separate "eClamAV incompatible with Vigos gzip adapter" bug. It would be specific to runtime (not startup) problems and problems when the two adapters are used together.

3. Testing whether the same issue exists when using eClamAV together with a modifying adapter sample (instead of Vigos gzip adapter).

4. If the same issue exists when using eClamAV together with a modifying adapter sample (#3 above), testing whether the same issue exists in Squid v3.5, with the latest libecap and eClamAV/sample adapter versions.

Alternatively, you can ask Vigos folks for support, of course.

[Yuri (yvoinov)]

Vigos seems died, Alex.

But, you absolutely right: order is matter. When I re-ordering modules in config, problem is gone:

ecap_enable on

loadable_modules /usr/local/lib/ecap_clamav_adapter.so
ecap_service clamav_service_req reqmod_precache uri=ecap://e-cap.org/ecap/services/clamav?mode=REQMOD bypass=off
ecap_service clamav_service_resp respmod_precache uri=ecap://e-cap.org/ecap/services/clamav?mode=RESPMOD bypass=on
adaptation_access clamav_service_req allow all
adaptation_access clamav_service_resp allow all

acl HTTP_STATUS_OK http_status 200
loadable_modules /usr/local/lib/ecap_adapter_gzip.so
ecap_service gzip_service respmod_precache ecap://www.vigos.com/ecap_gzip bypass=off
adaptation_access gzip_service allow HTTP_STATUS_OK

This config works.

[Alex Rousskov (rousskov)]

If Vigos folks (I hope they are alive and well even if their domain is gone!) are not going to update their adapter to work with modern libecap, somebody (who needs that adapter) should take the lead to update or replace it.

Glad you found a workaround for the multiple adapters problem.

[Yuri (yvoinov)]

Yep, me too. :)

Now I can drop out two services from my proxy :) And get less latency. ;)