inlinable function call in a function with debug info must have a !dbg location

[jirislaby]

It looks like the linking rework introduced a bug in later LLVM versions. LLVM 3.9 added a check if calls to inline functions contain debuginfo (cf. https://github.com/llvm-mirror/llvm/commit/522b700b9bdb32529b923cba196e0cd580267dfb). And if not, LLVM aborts. One of 2 tests causing this:

******************** TEST 'KLEE :: Runtime/FreeStanding/freestanding_only.c' FAILED ********************
Script:
--
/tmp/llvm-40-install_O_ND_A/bin/clang -I/tmp/klee_src/include /tmp/klee_src/test/Runtime/FreeStanding/freestanding_only.c -emit-llvm -O0 -g -c  -D_FORTIFY_SOURCE=0 -o /tmp/klee_build40_O_ND_A_stp2.1.2_z34.4.1_klee_uclibc_v1.0.0/test/Runtime/FreeStanding/Output/freestanding_only.c.tmp2.bc
rm -rf /tmp/klee_build40_O_ND_A_stp2.1.2_z34.4.1_klee_uclibc_v1.0.0/test/Runtime/FreeStanding/Output/freestanding_only.c.tmp.klee-out
/tmp/klee_build40_O_ND_A_stp2.1.2_z34.4.1_klee_uclibc_v1.0.0/bin/klee --output-dir=/tmp/klee_build40_O_ND_A_stp2.1.2_z34.4.1_klee_uclibc_v1.0.0/test/Runtime/FreeStanding/Output/freestanding_only.c.tmp.klee-out /tmp/klee_build40_O_ND_A_stp2.1.2_z34.4.1_klee_uclibc_v1.0.0/test/Runtime/FreeStanding/Output/freestanding_only.c.tmp2.bc 2> /tmp/klee_build40_O_ND_A_stp2.1.2_z34.4.1_klee_uclibc_v1.0.0/test/Runtime/FreeStanding/Output/freestanding_only.c.tmp.log
FileCheck /tmp/klee_src/test/Runtime/FreeStanding/freestanding_only.c --input-file=/tmp/klee_build40_O_ND_A_stp2.1.2_z34.4.1_klee_uclibc_v1.0.0/test/Runtime/FreeStanding/Output/freestanding_only.c.tmp.log
rm -rf /tmp/klee_build40_O_ND_A_stp2.1.2_z34.4.1_klee_uclibc_v1.0.0/test/Runtime/FreeStanding/Output/freestanding_only.c.tmp.klee-out
/tmp/klee_build40_O_ND_A_stp2.1.2_z34.4.1_klee_uclibc_v1.0.0/bin/klee --optimize --output-dir=/tmp/klee_build40_O_ND_A_stp2.1.2_z34.4.1_klee_uclibc_v1.0.0/test/Runtime/FreeStanding/Output/freestanding_only.c.tmp.klee-out /tmp/klee_build40_O_ND_A_stp2.1.2_z34.4.1_klee_uclibc_v1.0.0/test/Runtime/FreeStanding/Output/freestanding_only.c.tmp2.bc 2> /tmp/klee_build40_O_ND_A_stp2.1.2_z34.4.1_klee_uclibc_v1.0.0/test/Runtime/FreeStanding/Output/freestanding_only.c.tmp.log
FileCheck /tmp/klee_src/test/Runtime/FreeStanding/freestanding_only.c --input-file=/tmp/klee_build40_O_ND_A_stp2.1.2_z34.4.1_klee_uclibc_v1.0.0/test/Runtime/FreeStanding/Output/freestanding_only.c.tmp.log
--
Exit Code: 1
Command Output (stdout):
--
$ "/tmp/llvm-40-install_O_ND_A/bin/clang" "-I/tmp/klee_src/include" "/tmp/klee_src/test/Runtime/FreeStanding/freestanding_only.c" "-emit-llvm" "-O0" "-g" "-c" "-D_FORTIFY_SOURCE=0" "-o" "/tmp/klee_build40_O_ND_A_stp2.1.2_z34.4.1_klee_uclibc_v1.0.0/test/Runtime/FreeStanding/Output/freestanding_only.c.tmp2.bc"
$ "rm" "-rf" "/tmp/klee_build40_O_ND_A_stp2.1.2_z34.4.1_klee_uclibc_v1.0.0/test/Runtime/FreeStanding/Output/freestanding_only.c.tmp.klee-out"
$ "/tmp/klee_build40_O_ND_A_stp2.1.2_z34.4.1_klee_uclibc_v1.0.0/bin/klee" "--output-dir=/tmp/klee_build40_O_ND_A_stp2.1.2_z34.4.1_klee_uclibc_v1.0.0/test/Runtime/FreeStanding/Output/freestanding_only.c.tmp.klee-out" "/tmp/klee_build40_O_ND_A_stp2.1.2_z34.4.1_klee_uclibc_v1.0.0/test/Runtime/FreeStanding/Output/freestanding_only.c.tmp2.bc"
$ "FileCheck" "/tmp/klee_src/test/Runtime/FreeStanding/freestanding_only.c" "--input-file=/tmp/klee_build40_O_ND_A_stp2.1.2_z34.4.1_klee_uclibc_v1.0.0/test/Runtime/FreeStanding/Output/freestanding_only.c.tmp.log"
$ "rm" "-rf" "/tmp/klee_build40_O_ND_A_stp2.1.2_z34.4.1_klee_uclibc_v1.0.0/test/Runtime/FreeStanding/Output/freestanding_only.c.tmp.klee-out"
$ "/tmp/klee_build40_O_ND_A_stp2.1.2_z34.4.1_klee_uclibc_v1.0.0/bin/klee" "--optimize" "--output-dir=/tmp/klee_build40_O_ND_A_stp2.1.2_z34.4.1_klee_uclibc_v1.0.0/test/Runtime/FreeStanding/Output/freestanding_only.c.tmp.klee-out" "/tmp/klee_build40_O_ND_A_stp2.1.2_z34.4.1_klee_uclibc_v1.0.0/test/Runtime/FreeStanding/Output/freestanding_only.c.tmp2.bc"
# redirected output from '/tmp/klee_build40_O_ND_A_stp2.1.2_z34.4.1_klee_uclibc_v1.0.0/test/Runtime/FreeStanding/Output/freestanding_only.c.tmp.log':
KLEE: output directory is "/tmp/klee_build40_O_ND_A_stp2.1.2_z34.4.1_klee_uclibc_v1.0.0/test/Runtime/FreeStanding/Output/freestanding_only.c.tmp.klee-out"
KLEE: Using STP solver backend
inlinable function call in a function with debug info must have a !dbg location
  call void @klee_overshift_check(i64 64, i64 %int_cast_to_i64)
inlinable function call in a function with debug info must have a !dbg location
  call void @klee_overshift_check(i64 64, i64 %int_cast_to_i641)
LLVM ERROR: Broken function found, compilation aborted!
note: command had no output on stdout or stderr
error: command failed with exit status: 1

I cannot reproduce locally (no assert-enabled build of LLVM here). And I don't see how this can happen. I see https://github.com/klee/klee/blob/master/lib/Module/Checks.cpp#L130 copies the debuginfo and locally, I also see the debuginfo is in assembly.ll. It is interesting, that it happens in travis only in the --optimize run of klee (the test runs both non-optimized and optimized version).

[jirislaby]

So, @MartinNowack, doesn't it ring a bell?

[jirislaby]

Or maybe it is the rework of the travis' build script? Do you enable assertions in LLVM now?

[MartinNowack]

@jirislaby Woooow good to know. So, yes - there are also LLVM builds with assertions enabled as well. I think there is a bug in KLEE for debug information. It should be neither the linking nor the new build infrastructure. It just triggers it as LLVM is sometimes build with debug+assertions as well. I would like to fix the cause in the first place instead of disabling LLVM assertion builds.

[MartinNowack]

@jirislaby By the way, to build this locally you now have two options:

• build a docker image
• build it in a local directory

Just provide the options you want (e.g. picking them up from .travis.yml like LLVM_VERSION=3.7 SOLVERS=STP:Z3 STP_VERSION=2.1.2 Z3_VERSION=4.4.1 KLEE_UCLIBC=klee_uclibc_v1.0.0 DISABLE_ASSERTIONS=0 ENABLE_OPTIMIZED=1 COVERAGE=0 USE_TCMALLOC=1) and prefix them with the scripts:

• For docker: ./scripts/build/build-docker.sh

• Local installation: ./scripts/build/install-local.sh

For the local installation you should provide a BASE directory as well where all the components are build and installed. The scripts are developed in a way that different versions and setups can coexist in the same base directory. I tried to keep the scripts distribution agnostic.

To test with LLVM 6.0:

export BASE=$HOME/klee_dependencies
LLVM_VERSION=6.0 SOLVERS=STP:Z3 STP_VERSION=2.1.2 Z3_VERSION=4.4.1 \
KLEE_UCLIBC=klee_uclibc_v1.0.0 DISABLE_ASSERTIONS=0 ENABLE_OPTIMIZED=1 \
COVERAGE=0 USE_TCMALLOC=1 ./scripts/build/install-local.sh

[MartinNowack]

@jirislaby I debugged the case a bit. First, it wasn't me. Yeah. And as I suspected, using LLVM with assertions makes this problem explicit, which is a good thing.

The reason this fault is triggered is the following: We compile the runtime libraries (using -O2 and -g) therefore every function itself has debug information. Still, instructions inside of a function might not have this information if they are newly added and are a result of optimisation, e.g. due to vectorisation.

With the instrumentation (e.g. div/shift check), a call might be inserted (klee_overshift_check) surrounded by instructions without debug information. Therefore, the inserted call won't have debug information either. Still, the called function itself contains debug information. This might become a problem if that call should be inlined as the destination is unclear.

There are a couple of solutions:

• guess the debug information: add a close-enough debug information to the call: this is not necessarily correct
• compile the libraries with -O1 or -O0 and optimise later after the call has been inserted. The downside: this will hinder some optimisations (e.g. vectorisation) and optimisations might add new instructions for which checks should be inserted
• Implement that check as part of the executor.

Here an example:

vector.memcheck:                                  ; preds = %min.iters.checked
  %scevgep = getelementptr i8, i8* %destaddr, i64 %len, !dbg !34
  %scevgep9 = getelementptr i8, i8* %srcaddr, i64 %len, !dbg !34
  %bound0 = icmp ugt i8* %scevgep9, %destaddr, !dbg !34
  %bound1 = icmp ugt i8* %scevgep, %srcaddr, !dbg !34
  %memcheck.conflict = and i1 %bound0, %bound1, !dbg !34
  %ind.end = getelementptr i8, i8* %srcaddr, i64 %n.vec, !dbg !34
  %ind.end11 = getelementptr i8, i8* %destaddr, i64 %n.vec, !dbg !34
  %ind.end13 = sub i64 %len, %n.vec, !dbg !34
  br i1 %memcheck.conflict, label %while.body.preheader76, label %vector.body.preheader, !dbg !34

vector.body.preheader:                            ; preds = %vector.memcheck
;##### The following instructions do not have a debug information attached
  %0 = add i64 %n.vec, -16
;#### Here, a call will be inserted to check the shift
  %1 = lshr exact i64 %0, 4
  %2 = add nuw nsw i64 %1, 1
  %xtraiter77 = and i64 %2, 7
  %3 = icmp ult i64 %0, 112
  br i1 %3, label %middle.block.unr-lcssa, label %vector.body.preheader.new

The following patch makes the tests pass:

diff --git a/runtime/Makefile.cmake.bitcode.rules b/runtime/Makefile.cmake.bitcode.rules
index 41b2814..baeef25 100644
--- a/runtime/Makefile.cmake.bitcode.rules
+++ b/runtime/Makefile.cmake.bitcode.rules
@@ -38,7 +38,7 @@ endif
 #
 # Handle build mode flags
 ifeq ($(IS_RELEASE),1)
-LLVMCC.Flags += -O2
+LLVMCC.Flags += -O1
 else
 LLVMCC.Flags += -O0
 endif

I start to lean towards option number 3.

[MartinNowack]

@jirislaby #945, #946, #949 are a concerted effort to fix this issue.

As a sidenote, we currently have that problem already with LLVM 3.8, as soon as --optimize is used with coreutils. Using #949 solves that problem.

[MartinNowack]

@jirislaby #945, #946, #949 is merged now. We can close this.

[kren1]

Note that this can still hapen when llvm.memcpy intrinsic (which doesn't get dbg info), gets lowered to memcpy

[ccadar]

@kren1 do you have a small test? Can you open a new issue?

[kren1]

Here is a small example:

typedef struct _DDSVector3
{
  float  x, y, z;
} DDSVector3;

static inline void VectorSubtract3(const DDSVector3 left,
  const DDSVector3 right, DDSVector3 *destination)
{
  destination->x = left.x - right.x;
  destination->y = left.y - right.y;
  destination->z = left.z - right.z;
}

int main() {
  DDSVector3 l = {1.0,1.0,1.0};
  DDSVector3 r = {1.0,1.0,1.0};
  DDSVector3 res;
  VectorSubtract3(l,r,&res);
  return 0;

}

Compiled with clang-7 -c -emit-llvm -g error.c

I get

KLEE: Using STP solver backend
inlinable function call in a function with debug info must have a !dbg location
  %4 = call i8* @memcpy(i8* %2, i8* %3, i64 12)
inlinable function call in a function with debug info must have a !dbg location
  %9 = call i8* @memcpy(i8* %7, i8* %8, i64 12)
LLVM ERROR: Broken module found, compilation aborted!

[ccadar]

Thanks, @kren1 . let's reopen this.

[aytey]

Not a huge deal, but I've also just come across this issue.

This issue (for me) goes away if I remove -g from the call to clang -emit-llvm -- is this expected/desirable/a workaround? What's the disadvantage of removing -g?

Some things that don't work:

• -g
• -g -O0

Some things that do work:

• -g -O1

Alternatively, are there any other suggestions to resolve this issue (maybe compiling LLVM with different options)? Is it enough to pass in -DLLVM_ENABLE_ASSERTIONS:BOOL=OFF when compiling LLVM/clang?

After reading some of the other comments in this issue (e.g., https://github.com/klee/klee/issues/937#issuecomment-404095591), I'm not sure if assertions are the issue (and disabling them is the solution) or if assertions just make this problem explicit and the issue still exists after disabling them.

KLEE info

$ klee --version:

KLEE 2.2-pre (https://klee.github.io)
  Build mode: RelWithDebInfo (Asserts: ON)
  Build revision: 4030052bbd3f8a4682590ca6fb3a9faf5aec483d

LLVM (http://llvm.org/):
  LLVM version 6.0.1
  DEBUG build with assertions.
  Default target: x86_64-unknown-linux-gnu
  Host CPU: broadwell

$ git rev-parse --short HEAD:

4030052

LLVM info

$ clang --version

clang version 6.0.1
Target: x86_64-unknown-linux-gnu
Thread model: posix
InstalledDir: /opt/klee/llvm-project/llvm/build/bin

$ git rev-parse --short HEAD:

d359f209685

Error info

$ klee foo_klee_test.bc:

KLEE: output directory is "/home/apm/klee_examples/klee-out-3"
KLEE: Using STP solver backend
inlinable function call in a function with debug info must have a !dbg location
  %4 = call i8* @memcpy(i8* %2, i8* %3, i64 12)
LLVM ERROR: Broken module found, compilation aborted!

I'll try to create a cut-down example and update this issue when I have some more time

Thanks for your help!

[aytey]

Other things that do work:

klee foo_klee_test.bc  # <-- this will fail
opt -strip-debug foo_klee_test.bc -o stripped.bc
klee stripped.bc

Again, any disadvantages of doing this?

[aytey]

Here's our minimal example:

#include <klee/klee.h>

typedef struct
{
  int x;
  int y;
  struct
  {
    int a;
  } w;
} sta;

void foo(sta s)
{
}

int main(void)
{
  sta s;

  // Still crashes without the following call:
  klee_make_symbolic(&s, sizeof(s), "s");

  foo(s);
  return 0;
}

//EOF

I think clang is doing an optimisation here when the structure is of a certain size, and opts for a memcpy over a "direct" field-by-field assignment.

If you remove one of int x or int y inside of sta, the issue goes away.

[kren1]

Well the problem here is debug information, so if you strip it, it will work ofcourse. The problem is that you lose the debug information. That means that if you get an error, KLEE won't be able to tell you where in the source code it is.

[aytey]

@kren1 Hmm, good point.

Is it correct then to think that this impacts KLEE's ability to print stuff like "potential NULL pointer dereference", rather than the capability to generate test-cases via symbolic execution?

[kren1]

It still prints stuff like "potential NULL pointer derefernce", but doesn't tell you: "at myprogram.c:12". The actuall symbolic execution is not impacted as you say.

[aytey]

I'm sure other people have found this, but in relation to this issue, the LLVM code is here:

• https://github.com/llvm/llvm-project/blob/release/6.x/llvm/lib/IR/Verifier.cpp#L2777

  if (I->getFunction()->getSubprogram() && CS.getCalledFunction() &&
      CS.getCalledFunction()->getSubprogram())
    AssertDI(I->getDebugLoc(), "inlinable function call in a function with "
                               "debug info must have a !dbg location",
             I);

where AssertDI ends-up calling DebugInfoCheckFailed, which then sets:

Broken |= TreatBrokenDebugInfoAsError;

So I presume that building a non-asserting version of LLVM does resolve this issue.

I wonder if KLEE is able to turn DebugInfoCheckFailed off when setting-up its compiler passes?

[aytey]

I think the answer is yes: KLEE calls createVerifierPass which has a default argument of bool FatalErrors = true.

If KLEE were to call createVerifierPass (inside of lib/Module/Optimize.cpp) with an argument of false then these errors would not be treated as fatal (I think).

Do any of the KLEE maintainers have any thoughts on that? If this is a reasonable change, I'd be happy to make a PR.

[ccadar]

@andrewvaughanj thanks for the useful info! I'm afraid that change doesn't help (I've tried it quickly), but even if it did, I think we need to understand better what goes wrong here. @MartinNowack has put a lot of effort into fixing debug info in KLEE, so I think he's in the best position to debug this. I know it's on his todo list, but I'm not sure when he'll get to it (we have a few older issues to attend to as well). In the meantime, if you're hitting this a lot, you can try LLVM 3.8, which I believe doesn't have these issues.

[kren1]

My workaround patch for this is just to add some random debug info to these calls. I guess the challenge is to find the "right" debug info to attach.

[aytey]

@ccadar actually, I think it does help:

With the change:

KLEE: output directory is "/home/avj/klee_build/klee/build/../klee-out-1"
KLEE: Using STP solver backend
inlinable function call in a function with debug info must have a !dbg location
  %4 = call i8* @memcpy(i8* %2, i8* %3, i64 12)

KLEE: done: total instructions = 413
KLEE: done: completed paths = 1
KLEE: done: generated tests = 1

Without the change:

KLEE: output directory is "/home/avj/klee_build/klee/build/../klee-out-2"
KLEE: Using STP solver backend
inlinable function call in a function with debug info must have a !dbg location
  %4 = call i8* @memcpy(i8* %2, i8* %3, i64 12)
LLVM ERROR: Broken module found, compilation aborted!

[MartinNowack]

@andrewvaughanj Can you run KLEE with the following option: --disable-verify this should workaround your problem without recompiling anything. Please let me know if this works.

[aytey]

@MartinNowack result!!!

$ klee --disable-verify ../test.bc:

KLEE: output directory is "/home/avj/klee_build/klee/build/../klee-out-5"
KLEE: Using STP solver backend

KLEE: done: total instructions = 413
KLEE: done: completed paths = 1
KLEE: done: generated tests = 1

[MartinNowack]

@andrewvaughanj I'm glad this works. I had a look at yours and @kren1 examples. A couple of optimisation (e.g. initialisation of stack-local structs) do not generate debug information for memory intrinsics, although they should. This problem persists also with LLVM 9. The original issue reported by @jirislaby is already fixed. I'm not yet sure if this is an issue with KLEE or LLVM.

[ccadar]

Great to see several workarounds here. @MartinNowack I guess it would be useful to understand whether this is an LLVM issue, and if so, to report it.

We should also think if for now we want to enable by default --disable-verify (I would say no), or @andrewvaughanj 's suggestion of calling createVerifierPass(false).

[kren1]

I guess this is an LLVM issue, that LLVM project doesn't have, so I doubt they will fix it. I guess in clang something deals with these memcpy intrinsics before it becomes a problem.

[liuhaibohyde]

@andrewvaughanj Can you run KLEE with the following option: --disable-verify this should workaround your problem without recompiling anything. Please let me know if this works.

some

@andrewvaughanj Can you run KLEE with the following option: --disable-verify this should workaround your problem without recompiling anything. Please let me know if this works.

amazing, it works for me too, thanks!