Wrong debug info generated at -O3 (-O0 is correct)


Bugzilla Link	PR43949
Status	CONFIRMED
Importance	P enhancement
Reported by	Shuo Ding (shuo.d@outlook.com)
Reported on	2019-11-08 17:38:23 -0800
Last modified on	2019-11-11 04:52:05 -0800
Version	trunk
Hardware	PC Linux
CC	aprantl@apple.com, dblaikie@gmail.com, ditaliano@apple.com, greg.bedwell@sony.com, jeremy.morse.llvm@gmail.com, llvm-bugs@lists.llvm.org, neeilans@live.com, paul.robinson@am.sony.com, richard-llvm@metafoo.co.uk, vsk@apple.com
Fixed by commit(s)
Attachments
Blocks	PR38768
Blocked by
See also

The expected output from lldb should be 0. However, compiled with "-O3", lldb
outputs 5.

$ clang-trunk -v
clang version 10.0.0 (trunk 375507)
Target: x86_64-unknown-linux-gnu
Thread model: posix
InstalledDir: /usr/local/bin
Found candidate GCC installation: /usr/lib/gcc/i686-linux-gnu/8
Found candidate GCC installation: /usr/lib/gcc/i686-linux-gnu/9
Found candidate GCC installation: /usr/lib/gcc/x86_64-linux-gnu/4.4
Found candidate GCC installation: /usr/lib/gcc/x86_64-linux-gnu/4.4.7
Found candidate GCC installation: /usr/lib/gcc/x86_64-linux-gnu/4.6
Found candidate GCC installation: /usr/lib/gcc/x86_64-linux-gnu/4.6.4
Found candidate GCC installation: /usr/lib/gcc/x86_64-linux-gnu/4.8
Found candidate GCC installation: /usr/lib/gcc/x86_64-linux-gnu/4.8.5
Found candidate GCC installation: /usr/lib/gcc/x86_64-linux-gnu/5
Found candidate GCC installation: /usr/lib/gcc/x86_64-linux-gnu/5.5.0
Found candidate GCC installation: /usr/lib/gcc/x86_64-linux-gnu/6
Found candidate GCC installation: /usr/lib/gcc/x86_64-linux-gnu/6.5.0
Found candidate GCC installation: /usr/lib/gcc/x86_64-linux-gnu/7
Found candidate GCC installation: /usr/lib/gcc/x86_64-linux-gnu/7.4.0
Found candidate GCC installation: /usr/lib/gcc/x86_64-linux-gnu/8
Found candidate GCC installation: /usr/lib/gcc/x86_64-linux-gnu/9
Selected GCC installation: /usr/lib/gcc/x86_64-linux-gnu/9
Candidate multilib: .;@m64
Candidate multilib: 32;@m32
Candidate multilib: x32;@mx32
Selected multilib: .;@m64

$ clang-trunk -g abc.c -O3
$ lldb-trunk -s cmds -b a.out
(lldb) target create "a.out"
Current executable set to '/home/sding/LLDB-testing/reduce/32221/report/a.out'
(x86_64).
(lldb) command source -s 0 'cmds'
Executing commands in '/home/sding/LLDB-testing/reduce/32221/report/cmds'.
(lldb) b 22
Breakpoint 1: where = a.out`main + 671 at abc.c:22:7, address =
0x00000000004007df
(lldb) r
Process 24738 stopped
* thread #1, name = 'a.out', stop reason = breakpoint 1.1
    frame #0: 0x00000000004007df a.out`main at abc.c:22:7
   19       h((char)i);
   20     i = 0;
   21     for (; i < 2; i++) {
-> 22       h(d[i]); // optimize_me_not0
   23     }
   24   }

Process 24738 launched: '/home/sding/LLDB-testing/reduce/32221/report/a.out'
(x86_64)
(lldb) p i
(int) $0 = 5

$ clang-trunk -g abc.c -O0
$ lldb-trunk -s cmds -b a.out
(lldb) target create "a.out"
Current executable set to '/home/sding/LLDB-testing/reduce/32221/report/a.out'
(x86_64).
(lldb) command source -s 0 'cmds'
Executing commands in '/home/sding/LLDB-testing/reduce/32221/report/cmds'.
(lldb) b 22
Breakpoint 1: where = a.out`main + 104 at abc.c:22:7, address =
0x00000000004005c8
(lldb) r
Process 30349 stopped
* thread #1, name = 'a.out', stop reason = breakpoint 1.1
    frame #0: 0x00000000004005c8 a.out`main at abc.c:22:7
   19       h((char)i);
   20     i = 0;
   21     for (; i < 2; i++) {
-> 22       h(d[i]); // optimize_me_not0
   23     }
   24   }

Process 30349 launched: '/home/sding/LLDB-testing/reduce/32221/report/a.out'
(x86_64)
(lldb) p i
(int) $0 = 0

$ cat abc.c
int a[256];
int b, c;
static int d[] = {0, -4L};
void e(f) { b = b & 4095 ^ a[(b ^ f) & 5]; }
void h(f) {
  unsigned long g = f;
  b = b & 4095 ^ a[(b ^ g) & 255];
  e(g >> 8);
  e(g >> 6);
  e(g >> 4);
  e(g >> 2);
  e(g >> 56);
}
int main() {
  int i = 0;
  if (c)
    d[1] = 3;
  for (; i < 5; i++)
    h((char)i);
  i = 0;
  for (; i < 2; i++) {
    h(d[i]); // optimize_me_not0
  }
}

$ cat cmds
b 22
r
p i
kill
q

Many thanks for the report -- this is a really interesting reproducer that
exhibits interesting debug behaviour. First thing to note is that everything in
the program gets inlined and completely unrolled. In gdb, there's no indication
that the first five (unrolled and inlined) calls to 'h' happen: entering "next"
steps over all of them:

  19          h((char)i);
  (gdb) n
  22          h(d[i]); // optimize_me_not0

And if you're inside of of the inlined function scope and enter "next", you
enter a new inlining instance without any indication from gdb, which surprised
me:

  (gdb) n
  8         e(g >> 8);
  (gdb) n
  7         b = b & 4095 ^ a[(b ^ g) & 255];
  (gdb) n
  8         e(g >> 8);
  (gdb) n
  7         b = b & 4095 ^ a[(b ^ g) & 255];
  (gdb) n
  8         e(g >> 8);
  (gdb) n
  7         b = b & 4095 ^ a[(b ^ g) & 255];
  (gdb) n
  8         e(g >> 8);

(Each pair of lines here is a different inlining instance).

I've added this to the "bad debug experiences" umbrella bug, as IMO this is
something we can use in dexter tests in the future.

On to the actual problem reported: it looks like the machine-scheduler pass re-
orders some of the DBG_VALUEs, llvm-dwarfdump --name=i gives me, at the end of
the location list:

   DW_OP_consts +5, DW_OP_stack_value
   DW_OP_consts +1, DW_OP_stack_value
   DW_OP_consts +0, DW_OP_stack_value
   DW_OP_consts +2, DW_OP_stack_value)

Which should of course be in the order {5, 0, 1, 2}.

I'm not familiar with the machine-scheduler pass, but I think there are related
bugs open about the fact that it re-orders CFI instructions in this way too.

(This might also be an example of variable-locations and line-numbers being
completely separate causing variable locations to cover line numbers they
shouldn't).

Quuxplusone / LLVMBugzillaTest

Wrong debug info generated at -O3 (-O0 is correct) #42919