[lldb-dev] Lldb-server spins forever in ptrace with 100% CPU on Linux Ubuntu 16.04

Wed Dec 7 11:36:49 PST 2016

> could you get a backtrace of lldb-server when it is in the "stuck"

state (just attach with lldb/gdb after it hangs and do "bt")?

You wish [☹]  The lldb-server does not react to any signals including SIGSTOP, so gdb just hangs forever.

> If you can get me reasonably detailed repro steps, I can try to investigate

Unfortunately I do not have repro myself. It happens semi-randomly on some machines and I need to borrow the machine with the problem. Here are some details from my records:

  *   It is pretty big piece of RX memory, /proc/<pid>/maps shows this:
409701000-40b49c000 r-xp 00000000 00:00 0
  *   Writing into some locations within that VMA works
  *   When it repros, it is pretty consistent, but changing in the target may shift it - i.e. make no repro or fail at different address.

> are you able to still reproduce the bug with logging enabled?

Yes. Here are a few last lines from the log:

1481139040.768961000 0x7fff253c9780 Communication::Write (src = 0x7fff253c8f48, src_len = 7) connection = 0x24a6bd0
1481139040.768963000 0x24a6bd0 ConnectionFileDescriptor::Write (src = 0x7fff253c8f48, src_len = 7)
1481139040.768973000 0x24a6cc0 Socket::Write() (socket = 6, src = 0x7fff253c8f48, src_len = 7, flags = 0) => 7 (error = (null))
1481139040.768976000 0x24a6bd0 ConnectionFileDescriptor::Write(fd = 6, src = 0x7fff253c8f48, src_len = 7) => 7 (error = (null))
1481139040.768979000 0x7fff253c9780 Communication::Read (dst = 0x7fff253c7140, dst_len = 8192, timeout = 0 usec) connection = 0x24a6bd0
1481139040.768982000 0x24a6bd0 ConnectionFileDescriptor::BytesAvailable (timeout_usec = 0)
1481139040.768984000 0x24a6bd0 ConnectionFileDescriptor::BytesAvailable()  ::select (nfds=7, fds={6, 4}, NULL, NULL, timeout=0x7fff253c6d80)...
1481139040.768986000 0x24a6bd0 ConnectionFileDescriptor::BytesAvailable()  ::select (nfds=7, fds={6, 4}, NULL, NULL, timeout=0x7fff253c6d80) => 0, error = (null)
1481139090.788317000 0x7fff253c9780 Communication::Read (dst = 0x7fff253c7140, dst_len = 8192, timeout = 0 usec) connection = 0x24a6bd0
1481139090.788356000 0x24a6bd0 ConnectionFileDescriptor::BytesAvailable (timeout_usec = 0)
1481139090.788364000 0x24a6bd0 ConnectionFileDescriptor::BytesAvailable()  ::select (nfds=7, fds={6, 4}, NULL, NULL, timeout=0x7fff253c6d80)...
1481139090.788368000 0x24a6bd0 ConnectionFileDescriptor::BytesAvailable()  ::select (nfds=7, fds={6, 4}, NULL, NULL, timeout=0x7fff253c6d80) => 1, error = (null)
1481139090.788378000 0x24a6cc0 Socket::Read() (socket = 6, src = 0x7fff253c7140, src_len = 25, flags = 0) => 25 (error = (null))
1481139090.788382000 0x24a6bd0 ConnectionFileDescriptor::Read()  fd = 6, dst = 0x7fff253c7140, dst_len = 8192) => 25, error = (null)
1481139090.788395000 NativeProcessLinux::WriteMemory(0x409d5a7d0, 0x25271d0, 4)
1481139090.788409000 NativeProcessLinux::ReadMemory using process_vm_readv to read 8 bytes from inferior address 0x409d5a7d0: Success
1481139090.788414000 PTRACE_POKEDATA [1][0][0][0][57][41][54][41]

Thanks,

Eugene

Sent from Outlook<http://aka.ms/weboutlook>

________________________________
From: Pavel Labath <labath at google.com>
Sent: Wednesday, December 7, 2016 2:34 AM
To: Eugene Birukov
Cc: LLDB
Subject: Re: [lldb-dev] Lldb-server spins forever in ptrace with 100% CPU on Linux Ubuntu 16.04

Hello Eugene,

this sounds troubling, and I'd like to get to the bottom of this. If
you can get me a bit more information about this, I believe we can
figure it out:

- could you get a backtrace of lldb-server when it is in the "stuck"
state (just attach with lldb/gdb after it hangs and do "bt")? I want
to see the where is it spinning, as I don't see any obvious infinite
loop there.

- are you able to still reproduce the bug with logging enabled? If so,
I'd like to see the log file to understand this better. (You can
enable logging by starting lldb-server with: --log-file XXX.log
--log-channels "lldb all:linux all". If you're starting it via lldb
client you can set the LLDB_DEBUGSERVER_LOG_FILE and
LLDB_SERVER_LOG_CHANNELS environment vars to achieve this)

- If you can get me reasonably detailed repro steps, I can try to
investigate (I am fine with the first step being "install ubuntu 16.04
in virtualbox")

On 6 December 2016 at 23:41, Eugene Birukov via lldb-dev
<lldb-dev at lists.llvm.org> wrote:
> Hi,
> 1. I believe that lldb-server spins inside ptrace. I put breakpoint on the
> highlighted line, and it does not hit. If I put breakpoint on line before,
> it hits but lldb-server hangs.

Do you mean actually inside the ptrace(2) syscall? Your description
would certainly fit that, but that sounds scary, as it would mean a
kernel bug. If that's the case, then we have to start looking in the
kernel. I have some experience with that, but If we can boil this down
to a simple use case, we can also ask the kernel ptrace folks for
help.

> 2. It seems that hang is caused by the client trying to read response too
> fast. I mean, if I step through the client code it works - i.e. there is
> significant delay between client writing into pipe and issuing ::select to
> wait for response.

I am not sure how this fits in with the item above. I find it hard to
believe that the presence of select(2) in one process would affect the
outcome of ptrace() in another. Unless we are actually encountering a
kernel scheduler bug, which I find unlikely. Hopefully we can get more
insight here with additional logging information.

> Any advice how to deal with the situation except putting random sleeps in
> random places?
Inserting sleeps in various places is a valid (albeit very slow)
strategy for debugging races. If you can push the sleep down, you will
eventually reach the place where it will be obvious what is racing
(or, at least, which component is to blame). Hopefully we can do
something smarter though.

If you are suspecting a kernel bug, I'd recommend recreating it in a
simple standalone application (fork, trace the child, write its
memory), as then it is easy to ask for help

pl
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.llvm.org/pipermail/lldb-dev/attachments/20161207/5d9f1e39/attachment-0001.html>
-------------- next part --------------
A non-text attachment was scrubbed...
Name: OutlookEmoji-☹.png
Type: image/png
Size: 506 bytes
Desc: OutlookEmoji-☹.png
URL: <http://lists.llvm.org/pipermail/lldb-dev/attachments/20161207/5d9f1e39/attachment-0001.png>