[Bug debuginfod/27399] New: dpkg-deb/lzma error when indexing .debs

[Bug debuginfod/27399] New: dpkg-deb/lzma error when indexing .debs

[sergiodj at sergiodj dot net]

https://sourceware.org/bugzilla/show_bug.cgi?id=27399

            Bug ID: 27399
           Summary: dpkg-deb/lzma error when indexing .debs
           Product: elfutils
           Version: unspecified
            Status: NEW
          Severity: normal
          Priority: P2
         Component: debuginfod
          Assignee: unassigned at sourceware dot org
          Reporter: sergiodj at sergiodj dot net
                CC: elfutils-devel at sourceware dot org
  Target Milestone: ---

I'm running debuginfod in a test VM with a bunch of .deb dbgsym files and I
noticed some errors like the one below when indexing the packages:

...
Feb 12 00:33:04 debian-unstable debuginfod[92513]: dpkg-deb (subprocess):
decompressing archive
'/srv/mirrors/debian/debug.mirrors.debian.org/debian-debug/pool/main/a/anope/anope-dbgsym_2.0.6-1+b1_amd64.deb'
(size=64353340) member 'data.tar': lzma write error: Broken pipe
Feb 12 00:33:04 debian-unstable debuginfod[92511]: dpkg-deb: error:
<decompress> subprocess returned error exit status 2
...

This happens sporadically, when I start/restart the service, and with different
files every time.  Also, the number of errors varies: sometimes it's just one
error, sometimes it's as many as 4 or 5.  I have around 1841 .deb files here
(this is just a very small subset of the whole Debian mirror), so I assume that
if I try to index several thousand files I will see a bunch more of these
errors popping up.

The debuginfod.service I'm using is pretty much the same as the one shipped by
upstream.  I've done a minor modification to the /etc/default/debuginfod file
in order to make it index Debian files:

...
DEBUGINFOD_PATHS="-t43200 -U
/srv/mirrors/debian/debug.mirrors.debian.org/debian-debug/pool/main/a/"
...

Otherwise, it's also the same as the one shipped in the tarball.  I've tested
this with Debian's latest elfutils from unstable (0.183-1), and also built
debuginfod from git HEAD (d358f6329945c96b25f777377055ee44133810fa, at the time
of this writing).

I haven't gotten the chance to do proper debugging yet, but I'm happy to
provide more info meanwhile.  TIA.

-- 
You are receiving this mail because:
You are on the CC list for the bug.

[Bug debuginfod/27399] dpkg-deb/lzma error when indexing .debs

[fche at redhat dot com]

https://sourceware.org/bugzilla/show_bug.cgi?id=27399

Frank Ch. Eigler <fche at redhat dot com> changed:

           What    |Removed                     |Added
----------------------------------------------------------------------------
                 CC|                            |fche at redhat dot com
             Status|NEW                         |WAITING

--- Comment #1 from Frank Ch. Eigler <fche at redhat dot com> ---
Can you check whether dpkg-deb is decompressing all of its content onto some
RAM-backed filesystem, and running out of space via that (or via consuming
machine free ram)?

You can try a few things:

- run debuginfod with a smaller concurrency limit (-c NNN), because the
  decompression etc. activities aggressively use all your CPUs and thus
  #CPU * memory, if they can

- instead of 'debuginfod -U' (which uses dpkg-deb as the decompression
  streamer), use 
  % debuginfod -Z.deb="(bsdtar -O -x -f - data.tar.xz)<"
  which causes deb files to be processed with libarchive's frontend
  (or equivalently, temporarily rename /usr/bin/dpkg-deb while starting
  debuginfod, so it makes the same inference)

- monitor resource usage - particularly ram - during the indexing process

- try running elfutils 0.183 debuginfod, which does a touch more
  filesystem-space monitoring, related self-protection, more 
  prometheus error metrics

-- 
You are receiving this mail because:
You are on the CC list for the bug.

[Bug debuginfod/27399] dpkg-deb/lzma error when indexing .debs

[fche at redhat dot com]

https://sourceware.org/bugzilla/show_bug.cgi?id=27399

--- Comment #2 from Frank Ch. Eigler <fche at redhat dot com> ---
Sergio, are the messages you're worried about happening AT THE MOMENT of a
start / stop?  Or just intermittently sometime during the normal operating
lifetime of the process?

-- 
You are receiving this mail because:
You are on the CC list for the bug.

[Bug debuginfod/27399] dpkg-deb/lzma error when indexing .debs

[sergiodj at sergiodj dot net]

https://sourceware.org/bugzilla/show_bug.cgi?id=27399

Sergio Durigan Junior <sergiodj at sergiodj dot net> changed:

           What    |Removed                     |Added
----------------------------------------------------------------------------
             Status|WAITING                     |NEW

--- Comment #3 from Sergio Durigan Junior <sergiodj at sergiodj dot net> ---
(In reply to Frank Ch. Eigler from comment #1)
> Can you check whether dpkg-deb is decompressing all of its content onto some
> RAM-backed filesystem, and running out of space via that (or via consuming
> machine free ram)?

It doesn't seem to be doing that.  My /tmp is not mounted 

> You can try a few things:
> 
> - run debuginfod with a smaller concurrency limit (-c NNN), because the
>   decompression etc. activities aggressively use all your CPUs and thus
>   #CPU * memory, if they can

For completeness sake, I'm running my tests using a VM with 8GB RAM and access
to 10 host CPUs.

Having said that, I've tried specifying "-c 4", and it seems to have mitigated
the problem.

> - instead of 'debuginfod -U' (which uses dpkg-deb as the decompression
>   streamer), use 
>   % debuginfod -Z.deb="(bsdtar -O -x -f - data.tar.xz)<"
>   which causes deb files to be processed with libarchive's frontend
>   (or equivalently, temporarily rename /usr/bin/dpkg-deb while starting
>   debuginfod, so it makes the same inference)

This also seems to work, even without limiting the concurrency.  So far, I
think it's the best workaround/solution.

> - monitor resource usage - particularly ram - during the indexing process

I'm monitoring RAM usage, and it's interesting to notice that in the "normal
case" (i.e., using "-U" and not limiting concurrency), the usage is pretty much
the same as it is when using bsdtar, and it stays well below the limit of the
VM.

> - try running elfutils 0.183 debuginfod, which does a touch more
>   filesystem-space monitoring, related self-protection, more 
>   prometheus error metrics

Yeah, I'm using elfutils 0.183 here already.

-- 
You are receiving this mail because:
You are on the CC list for the bug.

[Bug debuginfod/27399] dpkg-deb/lzma error when indexing .debs

[sergiodj at sergiodj dot net]

https://sourceware.org/bugzilla/show_bug.cgi?id=27399

--- Comment #4 from Sergio Durigan Junior <sergiodj at sergiodj dot net> ---
(In reply to Frank Ch. Eigler from comment #2)
> Sergio, are the messages you're worried about happening AT THE MOMENT of a
> start / stop?  Or just intermittently sometime during the normal operating
> lifetime of the process?

I'm seeing the messages when debuginfod is indexing the files.  They don't show
up after I leave the service running.

-- 
You are receiving this mail because:
You are on the CC list for the bug.

[Bug debuginfod/27399] dpkg-deb/lzma error when indexing .debs

[sergiodj at sergiodj dot net]

https://sourceware.org/bugzilla/show_bug.cgi?id=27399

--- Comment #5 from Sergio Durigan Junior <sergiodj at sergiodj dot net> ---
(In reply to Sergio Durigan Junior from comment #3)
> (In reply to Frank Ch. Eigler from comment #1)
> > Can you check whether dpkg-deb is decompressing all of its content onto some
> > RAM-backed filesystem, and running out of space via that (or via consuming
> > machine free ram)?
> 
> It doesn't seem to be doing that.  My /tmp is not mounted 

... using tmpfs.

-- 
You are receiving this mail because:
You are on the CC list for the bug.

[Bug debuginfod/27399] dpkg-deb/lzma error when indexing .debs

[fche at redhat dot com]

https://sourceware.org/bugzilla/show_bug.cgi?id=27399

--- Comment #6 from Frank Ch. Eigler <fche at redhat dot com> ---
OK, my best guess is a transient low-memory condition.  Just today we found bug
#27405, which can cause some impressive momentary memory binges in elfutils. 
Reducing concurrency is one way to limit its impact, as you found.  Giving the
VM more memory is another: I run it on 16GB 8CPU class VMs, scanning even many
huge debuginfo files, without a complaint.

It might also help reassure here is that if you let debuginfod keep going,
it'll know that it didn't finish indexing those problematic files, and will
just retry later.  In the long term (past rescan time), such momentary ENOMEMs
are not particularly harmful.

I can't think of any debuginfod per se changes or bugs in effect here.  Maybe
scale the default concurrency more conservatively to machine RAM rather than
solely CPU count?

-- 
You are receiving this mail because:
You are on the CC list for the bug.

[Bug debuginfod/27399] dpkg-deb/lzma error when indexing .debs

[sergiodj at sergiodj dot net]

https://sourceware.org/bugzilla/show_bug.cgi?id=27399

--- Comment #7 from Sergio Durigan Junior <sergiodj at sergiodj dot net> ---
(In reply to Frank Ch. Eigler from comment #6)
> OK, my best guess is a transient low-memory condition.  Just today we found
> bug #27405, which can cause some impressive momentary memory binges in
> elfutils.  Reducing concurrency is one way to limit its impact, as you
> found.  Giving the VM more memory is another: I run it on 16GB 8CPU class
> VMs, scanning even many huge debuginfo files, without a complaint.

I was also considering that this could be a temporarily low-memory thing, but I
don't think so anymore.  I've expanded the VM memory to 32GB now, and I'm still
seeing the errors.

> It might also help reassure here is that if you let debuginfod keep going,
> it'll know that it didn't finish indexing those problematic files, and will
> just retry later.  In the long term (past rescan time), such momentary
> ENOMEMs are not particularly harmful.

OK, good, I thought this would be the case but I did not know for sure.  That's
good to know.

> I can't think of any debuginfod per se changes or bugs in effect here. 
> Maybe scale the default concurrency more conservatively to machine RAM
> rather than solely CPU count?

My current plan is to use the "bsdtar" workaround above, which seems to work
even when I max out the concurrency.  But the debugger in me still wants to
know what is happening...

Anyway, while I agree that this is not a high priority issue (since there are
two known workarounds for it), I think it may be worth mentioning the "bsdtar"
solution more explicitly in the documentation.

-- 
You are receiving this mail because:
You are on the CC list for the bug.

[Bug debuginfod/27399] dpkg-deb/lzma error when indexing .debs

[fche at redhat dot com]

https://sourceware.org/bugzilla/show_bug.cgi?id=27399

Frank Ch. Eigler <fche at redhat dot com> changed:

           What    |Removed                     |Added
----------------------------------------------------------------------------
             Status|NEW                         |RESOLVED
         Resolution|---                         |FIXED

--- Comment #8 from Frank Ch. Eigler <fche at redhat dot com> ---
Resolved under bug #27413 by deprecating use of dpkg-deb in favor of bsdtar.

-- 
You are receiving this mail because:
You are on the CC list for the bug.