unfriendly error message when debugee does not start correctly

[emaste]

Bugzilla Link	48723
Version	unspecified
OS	All
CC	@JDevlieghere,@sylvestre

Extended Description

On FreeBSD, and I assume other operating systems, there are cases where the debugged application does not start correctly.

One recent case occurred on FreeBSD with W^X enabled (sysctl kern.elf64.allow_wx=0) and an attempt to execute a binary that requested an executable stack. Because W^X disallows mappings with simultaneous W & X protections the initial stack cannot be created and the kernel image activator reports SIGABRT from the target.

Similar cases occurred when attempting to execute a binary with a .text segment larger than a kernel limit.

The failure reported by LLDB in this case is not particularly clear:

$ lldb ./exec-stack
(lldb) target create "./exec-stack"
Current executable set to
'/home/emaste/src/freebsd-git/main/exec-stack' (x86_64).
(lldb) run
error: 'A' packet returned an error: 8

The old in-process target plugin handled this even more poorly:

(lldb) run
Assertion failed: (WIFSTOPPED(status) && wpid == (::pid_t)pid &&
"Could not sync with inferior process."), function Launch, file
/usr/home/emaste/src/freebsd-git/head/contrib/llvm-project/lldb/source/Plugins/Process/FreeBSD/ProcessMonitor.cpp,
line 930.
PLEASE submit a bug report to https://bugs.freebsd.org/submit/ and
include the crash backtrace.
#​0 0x0000000004444ade PrintStackTrace
/usr/home/emaste/src/freebsd-git/head/contrib/llvm-project/llvm/lib/Support/Unix/Signals.inc:564:13
#​1 0x0000000004442e11 RunSignalHandlers
/usr/home/emaste/src/freebsd-git/head/contrib/llvm-project/llvm/lib/Support/Signals.cpp:69:18
#​2 0x0000000004445335 SignalHandler
/usr/home/emaste/src/freebsd-git/head/contrib/llvm-project/llvm/lib/Support/Unix/Signals.inc:0:3
#​3 0x0000000805299b20 handle_signal
/usr/home/emaste/src/freebsd-git/head/lib/libthr/thread/thr_sig.c:0:3
Abort trap (core dumped)

Although a relatively minor issue it would be nice to have an error message along the lines of "Unable to start inferior process" or such. Taking this to root cause would likely require finding a log message in the kernel log.

(For reference, the FreeBSD code review that prompted this investigation: https://reviews.freebsd.org/D28050)

[llvmbot]

So lldb-server has a way to return better error messages. If lldb-server is being used in this case, LLDB will send a "QEnableErrorStrings" packet that allows errors that used to be returned as "E08" ("E" = error, with code = "08") to also have an error message as hex encoded ASCII like "E08;313233" where "313233" is the string "123".

The "A" packet seems to be returning only an error code with no error message. If you can get the native FreeBSD NativeProcessFreeBSD.cpp or NativeThreadFreeBSD.cpp to figure out this is the error, you can modify the error message that should be returned back up to LLDB and it should be propagated.

The first step is to see what is currently happening. Can you enable GDB remote packet logging with:

(lldb) log enable -f /tmp/packets.txt gdb-remote packets
(lldb) target create "./exec-stack"
(lldb) run

Then attach the packets so we can see what is currently happening?

[llvmbot]

Does FreeBSD debugging use lldb-server now? If so, can we remove the old native ProcessFreeBSD process plug-in?

[emaste]

packet log

[emaste]

Does FreeBSD debugging use lldb-server now? If so, can we remove the old
native ProcessFreeBSD process plug-in?

We now use lldb-server on FreeBSD/x86, but not yet other CPU architectures. Over the next few months the remaining architectures should be switched over and we can remove the native process plug-in.

As an aside, looking at the packet log I see another TODO for FreeBSD - disabling ASLR:

lldb < 21> send packet: $QSetDisableASLR:1#ce
lldb < 6> read packet: $OK#9a

I guess we're ignoring this at the moment.

Another TODO from looking at ktrace -i lldb ...:

12735 lldb-server CALL getrlimit(RLIMIT_NOFILE,0x7fffffe74d20)
12735 lldb-server RET getrlimit 0
12735 lldb-server CALL close(0x3)
12735 lldb-server RET close -1 errno 9 Bad file descriptor
12735 lldb-server CALL getrlimit(RLIMIT_NOFILE,0x7fffffe74d20)
12735 lldb-server RET getrlimit 0
12735 lldb-server CALL close(0x4)
12735 lldb-server RET close 0
12735 lldb-server CALL getrlimit(RLIMIT_NOFILE,0x7fffffe74d20)
12735 lldb-server RET getrlimit 0
12735 lldb-server CALL close(0x5)
12735 lldb-server RET close 0
12735 lldb-server CALL getrlimit(RLIMIT_NOFILE,0x7fffffe74d20)
12735 lldb-server RET getrlimit 0
12735 lldb-server CALL close(0x6)
12735 lldb-server RET close -1 errno 9 Bad file descriptor
...
12735 lldb-server CALL getrlimit(RLIMIT_NOFILE,0x7fffffe74d20)
12735 lldb-server RET getrlimit 0
12735 lldb-server CALL close(0x718f0)
12735 lldb-server RET close -1 errno 9 Bad file descriptor
12735 lldb-server CALL getrlimit(RLIMIT_NOFILE,0x7fffffe74d20)
12735 lldb-server RET getrlimit 0
12735 lldb-server CALL close(0x718f1)
12735 lldb-server RET close -1 errno 9 Bad file descriptor
12735 lldb-server CALL getrlimit(RLIMIT_NOFILE,0x7fffffe74d20)
12735 lldb-server RET getrlimit 0

we need to use closefrom or close_range instead of calling close() in a loop for about 1M syscalls to close fds

[emaste]

... to close fds before execve

The failed execve looks like:

12735 lldb-server CALL ptrace(PT_TRACE_ME,0,0,0)
12735 lldb-server RET ptrace 0
12735 lldb-server CALL execve(0x80e1739c0,0x80e1c4060,0x80e21d000)
12735 lldb-server NAMI "/usr/home/emaste/src/freebsd-git/head/exec-stack"
12734 lldb-server GIO fd 6 read 0 bytes
""
12734 lldb-server RET read 0
12734 lldb-server CALL close(0x6)
12734 lldb-server RET close 0
12734 lldb-server CALL wait4(0x31bf,0x7fffffe75804,0,0)
12734 lldb-server RET wait4 12735/0x31bf
12734 lldb-server CALL write(0x7,0x7fffffe75861,0x7)
12734 lldb-server GIO fd 7 wrote 7 bytes
"$E08#ad"
12734 lldb-server RET write 7

[llvmbot]

Looks like error strings are successfully enabled:

lldb < 23> send packet: $QEnableErrorStrings#8c
lldb < 6> read packet: $OK#9a

But there is no extra error info from the "A" packet which launches the executable:

lldb < 106> send packet: $A96,0,2f7573722f686f6d652f656d617374652f7372632f667265656273642d6769742f686561642f657865632d737461636b#85
lldb < 7> read packet: $E08#ad

[llvmbot]

So it should be an easy fix if you can make lldb-server figure out what went wrong and can add the error message.

[sylvestre]

I am experiencing this with lldb 13 on linux (debian unstable) in a chroot (/proc & /dev/shm are mounted):

$ /usr/bin/clang++-13 -g -o foo a.cpp
$ /usr/bin/lldb-13 -s cmd.in foo
(lldb) target create "/check/build/tests/Output/basic_lldb2.cpp.tmp"
Current executable set to '/check/build/tests/Output/basic_lldb2.cpp.tmp' (x86_64).
(lldb) command source -s 0 '/check/tests/basic_lldb2.in'
Executing commands in '/check/tests/basic_lldb2.in'.
(lldb) b main
Breakpoint 1: where = basic_lldb2.cpp.tmp`main + 16 at basic_lldb2.cpp:7:21, address = 0x00000000004011c0
(lldb) r
error: 'A' packet returned an error: 8

mounting /dev/pts fixed the issue ( mount --bind /dev/pts /srv/chroot/stretch/dev/pts )

[DavidSpickett]

This has improved in recent times, I'll let others judge if it is friendly enough now.

ec2-user@freebsd:~/build-llvm $ sysctl kern.elf64.allow_wx
kern.elf64.allow_wx: 0
ec2-user@freebsd:~/build-llvm $ cat /tmp/test.c
#include <stdio.h>
int main(int ac, char **av) {
        int localfn(int a) {
                return a+ac;
        }
        int (*fptr)(int) = localfn;

        printf("%d\n", fptr(-1));
        return 0;
}
ec2-user@freebsd:~/build-llvm $ gcc /tmp/test.c -o /tmp/test.o -g
/usr/local/bin/ld: warning: /tmp//ccuskEDk.o: requires executable stack (because the .note.GNU-stack section is executable)

Latest build:

ec2-user@freebsd:~/build-llvm $ ./bin/lldb --version
lldb version 19.0.0git (https://github.com/llvm/llvm-project.git revision 235332150d52d11b340a10be1bb88432d2cf4179)
  clang revision 235332150d52d11b340a10be1bb88432d2cf4179
  llvm revision 235332150d52d11b340a10be1bb88432d2cf4179
ec2-user@freebsd:~/build-llvm $ ./bin/lldb /tmp/test.o -o "run"
(lldb) target create "/tmp/test.o"
Current executable set to '/tmp/test.o' (aarch64).
(lldb) run
exec_new_vmspace: mapping stack size 0x40000000 prot 0x7 failed, mach error 2 errno 13
error: Cannot launch '/tmp/test.o': Could not sync with inferior process

The system lldb 16.0.6 gives the same result, so it's been around since at least then.

If I didn't know the cause my next step would be to look up that prot value. Can't find the definitive source but I assume 7 is PROT_READ | PROT_WRITE | PROT_EXEC. So in this specific case it has got easier to diagnose the issue.

[emaste]

I'll let others judge if it is friendly enough now.

I think it is. My original complaint was there wasn't really any clue to follow. The current message maybe isn't "friendly" but there is at least enough context to find a next step. Indeed, pasting exec_new_vmspace: mapping stack size 0x40000000 prot 0x7 failed, mach error 2 errno 13 into Google gives an AI summary that it's likely due to W^X (Write XOR Execute) Policy.

As the original submitter of this bug report, I think it can be closed.