new llvm3.9 breaking freshclam bytecode execution

[Edson T. Marques]

none

ProblemType: Crash
DistroRelease: Ubuntu 17.10
Package: clamav-freshclam 0.99.2+dfsg-6ubuntu2
ProcVersionSignature: Ubuntu 4.13.0-11.12-generic 4.13.1
Uname: Linux 4.13.0-11-generic x86_64
ApportVersion: 2.20.7-0ubuntu1
Architecture: amd64
Date: Fri Sep 15 15:14:59 2017
ExecutablePath: /usr/bin/freshclam
InstallationDate: Installed on 2017-08-12 (33 days ago)
InstallationMedia: Ubuntu 17.10 "Artful Aardvark" - Alpha amd64 (20170812)
ProcCmdline: BOOT_IMAGE=/boot/vmlinuz-4.13.0-11-generic root=UUID=dc283744-d6ae-456e-add5-b57366aabd43 ro quiet splash vt.handoff=7
ProcEnviron:
 LANG=pt_BR.UTF-8
 LANGUAGE=pt_BR:pt:en
 PATH=(custom, no user)
Signal: 6
SourcePackage: clamav
Title: freshclam crashed with SIGABRT in __assert_fail_base()
UpgradeStatus: No upgrade log present (probably fresh install)
UserGroups:

[Launchpad Janitor (janitor)]

Status changed to 'Confirmed' because the bug affects multiple users.

[Christian Ehrhardt  (paelzer)]

Hmm,
this was published on 16th of August but we got 6 crash reports (all the same, but different reporters) in the last 3 days.

Something must be going on...

Subscribing Mark who did the last upload if he would know anything that might have been expected.
At the same time I'll be running it in an artful container to check if it is reproducible.

[Christian Ehrhardt  (paelzer)]

Ok, just installing on artful seems to be enough to crash this.

After install:
root@artful-test:~# systemctl status clamav-freshclam --full --no-pager
● clamav-freshclam.service - ClamAV virus database updater
   Loaded: loaded (/lib/systemd/system/clamav-freshclam.service; enabled; vendor preset: enabled)
   Active: active (running) since Tue 2017-09-19 13:05:15 UTC; 7min ago
     Docs: man:freshclam(1)
           man:freshclam.conf(5)
           http://www.clamav.net/lang/en/doc/
 Main PID: 5138 (freshclam)
    Tasks: 1 (limit: 4915)
   Memory: 149.8M
      CPU: 13.838s
   CGroup: /system.slice/clamav-freshclam.service
           └─5138 /usr/bin/freshclam -d --foreground=true

Sep 19 13:05:15 artful-test freshclam[5138]: Trying again in 5 secs...
Sep 19 13:05:20 artful-test freshclam[5138]: ClamAV update process started at Tue Sep 19 13:05:20 2017
Sep 19 13:05:40 artful-test freshclam[5138]: Downloading main.cvd [100%]
Sep 19 13:05:48 artful-test freshclam[5138]: main.cvd updated (version: 58, sigs: 4566249, f-level: 60, builder: sigmgr)
Sep 19 13:05:54 artful-test freshclam[5138]: Downloading daily.cvd [100%]
Sep 19 13:05:58 artful-test freshclam[5138]: daily.cvd updated (version: 23852, sigs: 1743054, f-level: 63, builder: neo)
Sep 19 13:05:59 artful-test freshclam[5138]: Downloading bytecode.cvd [100%]
Sep 19 13:06:01 artful-test freshclam[5138]: ERROR: During database load : freshclam: /build/llvm-toolchain-3.9-hPFDdS/llvm-toolchain-3.9-3.9.1/lib/IR/Constants.cpp:1902: static llvm::Constant* llvm::ConstantExpr::getGetElementPtr(llvm::Type*, llvm::Constant*, llvm::ArrayRef<llvm::Value*>, bool, llvm::Type*): Assertion `Ty == ca [...] st<PointerType>(C->getType()->getScalarType())->getContainedType(0u)' failed.
Sep 19 13:06:01 artful-test freshclam[5138]: ERROR: Database load killed by signal 6
Sep 19 13:06:01 artful-test freshclam[5138]: ERROR: Failed to load new database

A few debugging symbols later it looks like this - see attached retrace

@Mark - any idea, did that work on the upload?

[Christian Ehrhardt  (paelzer)]

Crash report with debug infos installed

[Christian Ehrhardt  (paelzer)]

There is nothing private in these dumps, removing flag from the bug.

[Christian Ehrhardt  (paelzer)]

As I was initially wondering having so much reports in such a short tie and formerly 3 weeks nothing that is suspicious.
It downloads the cvd and pushes that into a bytecode excution.
It seems to me that this fails now.

Did the format change or anything like that?

@Mark - any idea, did that work on the upload?

[Marc Deslauriers (mdeslaur)]

I'm pretty sure it worked when I uploaded it.

Perhaps it's related to the llvm-toolchain-3.9 uploads?

[Christian Ehrhardt  (paelzer)]

Would match [1] in terms of dates since the bugs show up.

We can't easily go back as it is a generated depends:
apt install libllvm3.9=1:3.9.1-5ubuntu1
Reading package lists... Done
Building dependency tree
Reading state information... Done
The following packages were automatically installed and are no longer required:
  clamav-base clamdscan libltdl7 libtfm1
Use 'apt autoremove' to remove them.
The following packages will be REMOVED:
  clamav clamav-daemon clamav-daemon-dbgsym clamav-dbgsym clamav-freshclam clamav-freshclam-dbgsym libclamav7 libclamav7-dbgsym
The following packages will be DOWNGRADED:
  libllvm3.9

Instead upgrading to 1:3.9.1-16ubuntu1 from artful proposed was easy but did not resolve the issue.
Subscribing Locutus who did the last llvm uploads - since this is easy to test he might have a ppa to easily do so or anything like it.

[1]: https://launchpad.net/ubuntu/+source/llvm-toolchain-3.9/1:3.9.1-13ubuntu1

[Gianfranco Costamagna (costamagnagianfranco)]

Can you please try a no-change rebuild against the new llvm?
My wild guess is that something caused symbols to change, or some miscompilation.
what changed in the llvm-3.9 in the last few uploads was just fixing builds with new glibc, and reducing size of debug symbols, because the new gcc-7/binutils increased it a lot, making the build fail.

So, I can't debug it further because the toolchain changed too much, would be nice a no-change rebuild in a ppa, to spot some ABI changes in the underlying libraries.
1) gcc switch
2) binutils fixes
3) dwarf changes
4) size of debug symbols reduced
5) glibc fixes.

This is the list, and the reason because we can't easily test an older llvm.
(I can backport it to zesty and see if it happens there, probably it won't because of older toolchain)

[Gianfranco Costamagna (costamagnagianfranco)]

Probably doko might have better clues, BTW this bug appeared first on i386 on 12 september and this llvm build
https://launchpad.net/ubuntu/+source/llvm-toolchain-3.9/1:3.9.1-13ubuntu5/+build/13356670
https://bugs.launchpad.net/ubuntu/+source/clamav/+bug/1716722

[Gianfranco Costamagna (costamagnagianfranco)]

Hopefully Matthias has some better clue for this regression/ABI sadness

[Christian Ehrhardt  (paelzer)]

I was working on rebuilds:
- new clamav for zesty
- rebuild of new clamav on artful
- unittests local in lxd containers

It turns out that it is no more building in artful (but still in zesty).
But it all matches our current assumptions, as also this is on bytecode execution.

FAIL: check_clamav
==================

Using test case timeout of 900 seconds set by user
Running suite(s): cl_api
 cli
 jsnorm
 str
 regex
 disasm
 unique
 matchers
 htmlnorm
 bytecode
98%: Checks: 964, Failures: 0, Errors: 12
check_bytecode.c:93:E:arithmetic:test_lsig_jit:0: (after this point) Received signal 6 (Aborted)
check_bytecode.c:93:E:arithmetic:test_matchwithread_jit:0: (after this point) Received signal 6 (Aborted)
check_bytecode.c:93:E:arithmetic:test_pdf_jit:0: (after this point) Received signal 6 (Aborted)
check_bytecode.c:93:E:arithmetic:test_bswap_jit:0: (after this point) Received signal 6 (Aborted)
check_bytecode.c:93:E:arithmetic:test_inflate_int:0: (after this point) Received signal 6 (Aborted)
check_bytecode.c:93:E:arithmetic:test_api_files_jit:0: (after this point) Received signal 6 (Aborted)
check_bytecode.c:93:E:arithmetic:test_arith_7_jit:0: (after this point) Received signal 6 (Aborted)
check_bytecode.c:93:E:arithmetic:test_debug_jit:0: (after this point) Received signal 6 (Aborted)
check_bytecode.c:93:E:arithmetic:test_lsig_7_jit:0: (after this point) Received signal 6 (Aborted)
check_bytecode.c:93:E:arithmetic:test_testadt_jit:0: (after this point) Received signal 6 (Aborted)
check_bytecode.c:496:E:arithmetic:test_load_bytecode_jit:0: (after this point) Received signal 6 (Aborted)
check_bytecode.c:496:E:arithmetic:test_parallel_load:0: (after this point) Received signal 6 (Aborted)
NOTICE: Use the 'T' environment variable to adjust testcase timeout
FAIL check_clamav (exit status: 1)

Now on the "rebuild" we have to consider that the bytecode.cvd in the test is part of the package, and the one failing in the real system is downloaded.
If there are toolchain ABI breaks (which should not happen) then the incompatibility might be between what clamac builds their bytecode.cvd with vs the one now in Ubuntu.

[Christian Ehrhardt  (paelzer)]

Local repro possible with:
$ apt build-dep clamav
$ apt source clamav
$ cd clamav-0.99.2+dfsg
$ debuild -uc -us

Works on Zesty but fails on Artful.

They fail on the same bytecode test/sample file that is part of the unit test:
17076af1234ae2fa2e108ee234e9c578 /root/clamav-0.99.2+dfsg/unit_tests/input/bytecode.cvd

Rerun just the test with:
$ ./unit_tests/check_clamav --lt-debug

It will fail with the same signal 6 errors as "the real case", to debug you can use the libtool wrapper mode and need to get to the right fork (it does a lot):
$ libtool --mode=execute gdb ./unit_tests/check_clamav
+ some tricks to get to the right fork

It might be easier than fork hopping to drop all but:
srunner_add_suite(sr, test_bytecode_suite());
And then run "make check" to rebuild.

On that you can switch llvm's for debugging as you want (no dependencies of the packages, just rebuild clamav and retest)

Forcing in the zesty llvm via:
$ apt install llvm-3.9=1:3.9.1-5ubuntu1 llvm-3.9-runtime=1:3.9.1-5ubuntu1 llvm-3.9-dev=1:3.9.1-5ubuntu1 libllvm3.9=1:3.9.1-5ubuntu1
That makes it work (after doing a debuild again).

So I wondered what if I do "build" it against the old 1:3.9.1-5ubuntu1, but then upgrade to 1:3.9.1-16ubuntu1 - but that fails as well (actually that matches our case as clamav was build for artful before the upgrades)

Summarize:
- a regression due to the llvm updates
- executing the same bytecode from the unittest
- makes clamav fail in artful and being an FTBFS
- rebuilds against new llvm do not un-break it
- it could be an ABI change between the clamav delivered bytecode.cvd vs our change

Maybe some of the symbol mangling you mentioned to downsize it again was destructive?
You can now at least hop through llvm versions/builds and test it easily.
I hope this gives you enough repro steps to look into it with the llvm-expert POV.

[Gianfranco Costamagna (costamagnagianfranco)]

FWIW the latest clamav fails anyway
https://launchpad.net/~costamagnagianfranco/+archive/ubuntu/costamagnagianfranco-ppa

Can you please grab some llvm binaries and dpkg install them to bisect the first llvm that has failed?
https://launchpad.net/ubuntu/+source/llvm-toolchain-3.9/+publishinghistory

[Christian Ehrhardt  (paelzer)]

As I said the llvm changes made it FTBFS which is what you see on your rebuild.
I'll check if I can quickly bisect which broke it.

[Christian Ehrhardt  (paelzer)]

check_clamav.c:424:S:cl_scan:test_cl_scanmap_callback_mem_allscan:47: testfiles: 46 != 48
That was 1:3.9.1-5ubuntu1-12119810
--
check_clamav.c:424:S:cl_scan:test_cl_scanmap_callback_mem_allscan:47: testfiles: 46 != 48
That was 1:3.9.1-7ubuntu1-12460604
--
check_clamav.c:424:S:cl_scan:test_cl_scanmap_callback_mem_allscan:47: testfiles: 46 != 48
That was 1:3.9.1-8ubuntu1-12480621
--
check_clamav.c:424:S:cl_scan:test_cl_scanmap_callback_mem_allscan:47: testfiles: 46 != 48
That was 1:3.9.1-9ubuntu1-12691282
--
check_clamav.c:424:S:cl_scan:test_cl_scanmap_callback_mem_allscan:47: testfiles: 46 != 48
That was 1:3.9.1-10ubuntu1-12772374
--
check_clamav.c:424:S:cl_scan:test_cl_scanmap_callback_mem_allscan:47: testfiles: 46 != 48
That was 1:3.9.1-10ubuntu2-12845302
--
check_bytecode.c:496:E:arithmetic:test_parallel_load:0: (after this point) Received signal 6 (Aborted)
That was 1:3.9.1-13ubuntu6-13377849
--
check_bytecode.c:496:E:arithmetic:test_parallel_load:0: (after this point) Received signal 6 (Aborted)
That was 1:3.9.1-13ubuntu7-13380349
--
check_bytecode.c:496:E:arithmetic:test_parallel_load:0: (after this point) Received signal 6 (Aborted)
That was 1:3.9.1-16ubuntu1-13392514

The changelogs since the last working version is:
llvm-toolchain-3.9 (1:3.9.1-13ubuntu6) artful; urgency=medium

  * Try to build with -g1 instead of -g on amd64 as well.

 -- Matthias Klose <email address hidden> Fri, 15 Sep 2017 07:25:22 +0200

llvm-toolchain-3.9 (1:3.9.1-13ubuntu5) artful; urgency=medium

  * build using gold on arm64 and s390x. For backports, arm64 might still
    need the BFD linker, and building with only one or two processes in
    parallel.
  * On arm64 and ppc64el, build with -g1 instead of -g.
  * Set CMAKE_CXX_FLAGS_RELWITHDEBINFO and pass opt_flags.

 -- Matthias Klose <email address hidden> Sun, 10 Sep 2017 11:06:24 +0200

llvm-toolchain-3.9 (1:3.9.1-13ubuntu4) artful; urgency=medium

  * Fix sanitizer build failure with glibc-2.26.

 -- Matthias Klose <email address hidden> Fri, 08 Sep 2017 15:34:29 +0200

llvm-toolchain-3.9 (1:3.9.1-13ubuntu2) artful; urgency=medium

  * Link with --no-keep-files-mapped --no-map-whole-files when using
    gold.

 -- Matthias Klose <email address hidden> Fri, 08 Sep 2017 13:05:29 +0100

llvm-toolchain-3.9 (1:3.9.1-13ubuntu1) artful; urgency=medium

  * Merge from Debian unstable. Remaining changes:
    - libllvm3.9-dbg, libllvm3.9: Add breaks/replaces for the 16.04 backport.
    - Drop python-lldb-3.9 from lldb-3.9 depends because it's in universe.
llvm-toolchain-3.9 (1:3.9.1-13) unstable; urgency=medium

  * Fix the previous declaration, incorrect gcc comparison

 -- Sylvestre Ledru <email address hidden> Fri, 01 Sep 2017 09:00:10 +0200

llvm-toolchain-3.9 (1:3.9.1-12ubuntu1) artful; urgency=medium

  * Merge from Debian unstable. Remaining changes:
    - libllvm3.9-dbg, libllvm3.9: Add breaks/replaces for the 16.04 backport.
    - Drop python-lldb-3.9 from lldb-3.9 depends because it's in universe.

 -- Gianfranco Costamagna <email address hidden> Thu, 31 Aug 2017 22:27:12 +0200

llvm-toolchain-3.9 (1:3.9.1-12) unstable; urgency=medium

  * Fix the FTBFS because of -gsplit-dwarf:
    - Only enable it on archs wh...

[Christian Ehrhardt  (paelzer)]

I was formerly only testing those released.
But LP had some uploads which e.g. failed on arm or something like that.
I now tested all in between those I identified so far.

The upload that broke it was:
1:3.9.1-13ubuntu4-13351809 -> 1:3.9.1-13ubuntu6-13377849

Excluding non amd64 changes between those makes it "only":
  * Try to build with -g1 instead of -g on amd64 as well.
  * Set CMAKE_CXX_FLAGS_RELWITHDEBINFO and pass opt_flags.

Does that make sense to you?
You could throw me a ppa with things changed, but IIRC 1:3.9.1-13ubuntu5 didn't build - maybe because of the -g, so reverting the first change might not be an option?
CMAKE_CXX_FLAGS_RELWITHDEBINFO is "-O2 -g" I think not sure how that might collide with the other, but in any case it seems related to the debug info settings.

[Christian Ehrhardt  (paelzer)]

i386 didn't serve as testbed to check if ubuntu5 (failed on amd64) was the breaking version.
Waiting for [1] to build (or fail as Locutus expects it to break by needing too much memory).

[1]: https://launchpad.net/~costamagnagianfranco/+archive/ubuntu/costamagnagianfranco-ppa/+build/13396394

[Gianfranco Costamagna (costamagnagianfranco)]

please try the 16ubuntu2 upload when is available
https://launchpad.net/ubuntu/+source/llvm-toolchain-3.9/1:3.9.1-16ubuntu2

[Christian Ehrhardt  (paelzer)]

The build from the ppa 1:3.9.1-16ubuntu2 works

[Christian Ehrhardt  (paelzer)]

The ubuntu2 from the artful upload works as well but failed s390x upload.
Ubuntu3 failed amd64 build, ...

But it seems we know the fix for this issue, just one has to get a valid build through - is that the summary?

[Matthias Klose (doko)]

this is doctoring around at the wrong ends. please find out why clamav can't work with the debug information provided by -g1. Note that even that is stripped away in package builds.

[Christian Ehrhardt  (paelzer)]

Reported Upstream at clamav to also get their POV on it - linked the bug above.

[Christian Ehrhardt  (paelzer)]

From IRC as documentation of the next steps:

TL;DR: rebuild llvm with -g1 but with -DNDEBUG and retry then

[09:05] <doko> LocutusOfBorg, cpaelzer: what are you trying? we are back with two one gigabyte debug builds on ppc64el and s390x, and of course the failing amd64 build
[09:09] <LocutusOfBorg> doko, -g1 is breaking clamav
[09:09] <LocutusOfBorg> -g works
[09:09] <LocutusOfBorg> I'm doing a -g -NDEBUG to see what happens
[09:12] <cpaelzer> doko: bug 1717574
[09:12] <ubottu> bug 1717574 in clamav (Ubuntu) "new llvm3.9 breaking freshclam bytecode execution" [Medium,Confirmed] https://launchpad.net/bugs/1717574
[09:14] <doko> cpaelzer: is this upstreamed to clamav, or are we trying to change things which we don't understand? why is a change for the debug information responsible for that?
[09:15] <cpaelzer> doko: I only rerun the test and found the link of the issue to llvm - there is no clamav change
[09:16] <cpaelzer> doko: so nothing to upstream there that we'd know yet
[09:16] <cpaelzer> doko: it is just that their bytecode worked before a certina llvm upload and fails since then
[09:16] <doko> cpaelzer: did you try to rebuild clamav with the same flags as llvm?
[09:17] <doko> cpaelzer: or did you try to rebuild clamav at all?
[09:17] <cpaelzer> we rebuilt clamav with old and new llvm, but not change flags
[09:17] <cpaelzer> none of the rebuilds had any effect
[09:17] <LocutusOfBorg> we also tried a new clamav just to be sure
[09:17] <LocutusOfBorg> but yeah, no changes in flags, except for llvm
[09:18] <doko> please can you report that upstream?
[09:25] <doko> cpaelzer: we can't accomodate these builds if they take too much disk space to build, and even if, each of these packages take 1 gb, that makes 4gb for every upload ...
[09:28] <cpaelzer> doko: I did never say "please make them big" I'm only naively debugged a clamav crash and found that it is broken since these llvm uploads
[09:28] <cpaelzer> I beg your pardon if that got to you differently
[09:29] <cpaelzer> I'm reporting to clamav and will link it up
[09:30] <cpaelzer> doko: if you follow the bug I linked maybe you can see what the actual root cause might be the reason for that incompatibility
[09:31] <doko> cpaelzer: what is the change in compiler and linker flags?
[09:32] <LocutusOfBorg> cpaelzer, https://launchpad.net/~costamagnagianfranco/+archive/ubuntu/costamagnagianfranco-ppa/+packages
[09:32] <LocutusOfBorg> I uploaded a new llvm with -g1 (to make doko and infra happy) and with -DNDEBUG
[09:32] <LocutusOfBorg> what I discovered, is that ppassing RELWITHDEBINFO flags, overrides the cmake default ones
[09:32] <LocutusOfBorg> and that -DNDEBUG is stripped then
[09:32] <LocutusOfBorg> so the change has probably been a side-effect of that -g1, but not directly related
[09:34] <cpaelzer> I'll test that once it is built LocutusOfBorg
[09:34] <doko> cpaelzer: there's nothing about this -DNDEBUG in the bug report
[09:35] <doko> and then find out why clamav is relying on that ...
[09:35] <LocutusOfBorg> I discovered it some minutes ago, melding the failed amd64 and the succeeded one
[09:36] <LocutusOfBorg> because in my ppa it was good that build
[09:36] <doko> you should turn on...

[Christian Ehrhardt  (paelzer)]

FYI 1:3.9.1-16ubuntu4 from the current build in a-p is not working
1:3.9.1-16ubuntu2 from the same place did work
So while -DNDEBUG was a nice idea, that wasn't it
No reply on the upstream report yet.

[Gianfranco Costamagna (costamagnagianfranco)]

Can anybody test llvm 3.9.1-16ubuntu5 from artful?

[Christian Ehrhardt  (paelzer)]

Looking at similar output I thought it might be the fix we added for:
- https://bugs.launchpad.net/ubuntu/+source/clamav/+bug/1692073
- https://bugzilla.clamav.net/show_bug.cgi?id=11742
- https://bugzilla.clamav.net/show_bug.cgi?id=11898
But according to Marc the patch added is what upstream committed - I can't access all their bugs / changes. This change is [1].

Upstream asked to try 99.3-beta1 as there such an issue would be resolved, but that didn't turn out to help - I'd assume they meant the signal 11 issue fixed by [1] and not this new signal 6 issue.

99.3-beta1:
- without [1] and with new OR old llvm build:
check_bytecode.c:108:E:arithmetic:test_inflate_int:0: (after this point) Received signal 11 (Segmentation fault)
See [2] for more

- With [1] and new llvmbuild:
check_bytecode.c:93:E:arithmetic:test_lsig_jit:0: (after this point) Received signal 6 (Aborted)
See [3] for more

So while it seems similar it seems to be a new issue.
We have also tried a few more llvm builds (more on that in the referred LP bug).

Finally we yesterday also had the theory that the addigion of -g1 had killed the former -DNDEBUG.
Which would have eliminated some asserts and that is what is sending the sig 6.
That was the 3.9.1-16ubuntu5 build locutus is referring to in c#31.
Now this is complete and I can confirm that with this the issue is gone.

Since it is already in Artful I'm setting Fix Released.

[1]: zlib fix http://paste.ubuntu.com/25587433/
[2]: https://launchpadlibrarian.net/337810323/buildlog_ubuntu-artful-amd64.clamav_0.99.3~beta1+dfsg-2ubuntu1~ppa5_BUILDING.txt.gz
[3]: https://launchpadlibrarian.net/337803964/buildlog_ubuntu-artful-amd64.clamav_0.99.3~beta1+dfsg-2ubuntu1~ppa4_BUILDING.txt.gz

[Christian Ehrhardt  (paelzer)]

I also updated the linked clamav bug to make them aware that this is trigggered due to the additional asserts when llvm is built without -DNDEBUG.

Thank you all for your help!