public inbox for elfutils@sourceware.org
 help / color / mirror / Atom feed
* [Bug debuginfod/29474] New: Server returns 404 for concurrent requests when leading to a same .rpm
@ 2022-08-11 16:48 mliska at suse dot cz
  2022-08-11 20:17 ` [Bug debuginfod/29474] " mliska at suse dot cz
                   ` (5 more replies)
  0 siblings, 6 replies; 7+ messages in thread
From: mliska at suse dot cz @ 2022-08-11 16:48 UTC (permalink / raw)
  To: elfutils-devel

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

            Bug ID: 29474
           Summary: Server returns 404 for concurrent requests when
                    leading to a same .rpm
           Product: elfutils
           Version: unspecified
            Status: NEW
          Severity: normal
          Priority: P2
         Component: debuginfod
          Assignee: unassigned at sourceware dot org
          Reporter: mliska at suse dot cz
                CC: elfutils-devel at sourceware dot org, fche at redhat dot com
  Target Milestone: ---

Reproducer:

$ mkdir /tmp/test && cd /tmp/test && wget wget
https://ftp5.gwdg.de/pub/opensuse/tumbleweed/repo/debug/x86_64/cross-aarch64-gcc12-debuginfo-12.1.1%2Bgit287-1.1.x86_64.rpm

Clone:
https://github.com/marxin/script-misc.git

Index the folder:
./debuginfod/debuginfod -F -Z '.rpm=(rpm2cpio|zstdcat)<' /tmp/test -C 32

And then run:
$ ./debuginfod-stress.py data/files-local2.txt http://localhost:8002
Running stress test of 5 binaries in 8 threads:
Attemp #0 4 666d857e7318e96a79ac1eb6850e47027a644695 <Response [404]>
Attemp #1 4 666d857e7318e96a79ac1eb6850e47027a644695 <Response [200]>

and server reports:

[Thu 11 Aug 2022 04:47:43 PM GMT] (28119/28122): ::1:50958
UA:pythonrequests/2.28.1 XFF: GET
/buildid/671e2a753d37fe5a8e9979c25bbdedef5fa11606/debuginfo 200 3565448
0+1010ms
[Thu 11 Aug 2022 04:47:43 PM GMT] (28119/28138): not found
[Thu 11 Aug 2022 04:47:43 PM GMT] (28119/28138): ::1:50998
UA:pythonrequests/2.28.1 XFF: GET
/buildid/666d857e7318e96a79ac1eb6850e47027a644695/debuginfo 404 9 0+1034ms
[Thu 11 Aug 2022 04:47:43 PM GMT] (28119/28124): ::1:50960
UA:pythonrequests/2.28.1 XFF: GET
/buildid/4fec8709140eee9d594f6c81823fc481a7464780/debuginfo 200 304712 0+1247ms
[Thu 11 Aug 2022 04:47:43 PM GMT] (28119/28149): ::1:50944
UA:pythonrequests/2.28.1 XFF: GET
/buildid/c4ad4bb208047e2f7020b0f64f1324ce21600e12/debuginfo 200 3562688
0+1321ms
[Thu 11 Aug 2022 04:47:43 PM GMT] (28119/28126): ::1:50990
UA:pythonrequests/2.28.1 XFF: GET
/buildid/85b1a85f235f4a3a0e4f1cfc27e480ae89e6c02a/debuginfo 200 1298415
0+1332ms
[Thu 11 Aug 2022 04:47:44 PM GMT] (28119/28151): ::1:51004
UA:pythonrequests/2.28.1 XFF: GET
/buildid/666d857e7318e96a79ac1eb6850e47027a644695/debuginfo 200 67192 0+0ms

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

^ permalink raw reply	[flat|nested] 7+ messages in thread

* [Bug debuginfod/29474] Server returns 404 for concurrent requests when leading to a same .rpm
  2022-08-11 16:48 [Bug debuginfod/29474] New: Server returns 404 for concurrent requests when leading to a same .rpm mliska at suse dot cz
@ 2022-08-11 20:17 ` mliska at suse dot cz
  2022-08-11 20:30 ` mliska at suse dot cz
                   ` (4 subsequent siblings)
  5 siblings, 0 replies; 7+ messages in thread
From: mliska at suse dot cz @ 2022-08-11 20:17 UTC (permalink / raw)
  To: elfutils-devel

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

--- Comment #1 from Martin Liska <mliska at suse dot cz> ---
Have a better knowledge of what happens. Let's assume the following debugging
patch:

diff --git a/debuginfod/debuginfod.cxx b/debuginfod/debuginfod.cxx
index a089d0bd..0320f289 100644
--- a/debuginfod/debuginfod.cxx
+++ b/debuginfod/debuginfod.cxx
@@ -1743,7 +1743,10 @@ handle_buildid_r_match (bool internal_req_p,
         continue;

       if (fdcache.probe (b_source0, fn)) // skip if already interned
+      {
+        obatched(clog) << "SKIPPING due to probe=" << b_source1 << "
filename=" << fn << " r=" << r << endl;
         continue;
+      }

       // extract this file to a temporary file
       char* tmppath = NULL;
@@ -1776,6 +1779,7 @@ handle_buildid_r_match (bool internal_req_p,
         {
           // NB: now we know we have a complete reusable file; make fdcache
           // responsible for unlinking it later.
+          obatched(clog) << "INTERN " << b_source1 << " filename=" << fn <<
endl;
           fdcache.intern(b_source0, fn,
                          tmppath, archive_entry_size(e),
                          false); // prefetched ones go to the prefetch cache
@@ -1792,6 +1796,7 @@ handle_buildid_r_match (bool internal_req_p,

       inc_metric ("http_responses_total","result",archive_extension + "
archive");
       r = MHD_create_response_from_fd (archive_entry_size(e), fd);
+      obatched(clog) << "ASSIGN " << b_source1 << " filename=" << fn << " r="
<< r << endl;
       if (r == 0)
         {
           if (verbose)
@@ -1820,6 +1825,7 @@ handle_buildid_r_match (bool internal_req_p,
     }

   // XXX: rpm/file not found: delete this R entry?
+  obatched(clog) << "RETURN" << b_source1 << " r=" << r << endl;
   return r;
 }


debuginfod log shows:
...
[Thu 11 Aug 2022 08:02:42 PM GMT] (21225/21257): found mtime=1659137364 stype=R
source0=/home/marxin/BIG/test/cross-aarch64-gcc12-debuginfo-12.1.1+git287-1.1.x86_64.rpm
source1=/usr/lib/debug/.dwz/cross-aarch64-gcc12-12.1.1+git287-1.1.x86_64
[Thu 11 Aug 2022 08:02:42 PM GMT] (21225/21251): found mtime=1659137364 stype=R
source0=/home/marxin/BIG/test/cross-aarch64-gcc12-debuginfo-12.1.1+git287-1.1.x86_64.rpm
source1=/usr/lib/debug/usr/aarch64-suse-linux/sys-root/lib64/libgcc_s.so.1-12.1.1+git287-1.1.x86_64.debug
...
[Thu 11 Aug 2022 08:02:42 PM GMT] (21225/21257): INTERN
/usr/lib/debug/.dwz/cross-aarch64-gcc12-12.1.1+git287-1.1.x86_64
filename=/usr/lib/debug/usr/aarch64-suse-linux/sys-root/lib64/libgcc_s.so.1-12.1.1+git287-1.1.x86_64.debug
<- so here 21257 request interns libgcc_s.so.1-12.1.1+git287-1.1.x86_64.debug
[Thu 11 Aug 2022 08:02:42 PM GMT] (21225/21251): SKIPPING due to
probe=/usr/lib/debug/usr/aarch64-suse-linux/sys-root/lib64/libgcc_s.so.1-12.1.1+git287-1.1.x86_64.debug
filename=/usr/lib/debug/usr/aarch64-suse-linux/sys-root/lib64/libgcc_s.so.1-12.1.1+git287-1.1.x86_64.debug
r=0 <- and due to that it's skipped here and we never assign r = ...
[Thu 11 Aug 2022 08:02:43 PM GMT] (21225/21251):
RETURN/usr/lib/debug/usr/aarch64-suse-linux/sys-root/lib64/libgcc_s.so.1-12.1.1+git287-1.1.x86_64.debug
r=0
...


Note in correct run the following happens:
[Thu 11 Aug 2022 08:16:42 PM GMT] (22289/22319): ASSIGN
/usr/lib/debug/usr/aarch64-suse-linux/sys-root/lib64/libgcc_s.so.1-12.1.1+git287-1.1.x86_64.debug
filename=/usr/lib/debug/usr/aarch64-suse-linux/sys-root/lib64/libgcc_s.so.1-12.1.1+git287-1.1.x86_64.debug
r=0x7fff740548c0
...
[Thu 11 Aug 2022 08:16:43 PM GMT] (22289/22319):
RETURN/usr/lib/debug/usr/aarch64-suse-linux/sys-root/lib64/libgcc_s.so.1-12.1.1+git287-1.1.x86_64.debug
r=0x7fff740548c0

So the problem is somehow related to fdcache.

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

^ permalink raw reply	[flat|nested] 7+ messages in thread

* [Bug debuginfod/29474] Server returns 404 for concurrent requests when leading to a same .rpm
  2022-08-11 16:48 [Bug debuginfod/29474] New: Server returns 404 for concurrent requests when leading to a same .rpm mliska at suse dot cz
  2022-08-11 20:17 ` [Bug debuginfod/29474] " mliska at suse dot cz
@ 2022-08-11 20:30 ` mliska at suse dot cz
  2022-08-11 20:39 ` mliska at suse dot cz
                   ` (3 subsequent siblings)
  5 siblings, 0 replies; 7+ messages in thread
From: mliska at suse dot cz @ 2022-08-11 20:30 UTC (permalink / raw)
  To: elfutils-devel

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

--- Comment #2 from Martin Liska <mliska at suse dot cz> ---
So it's the prefetching feature as documented here:

  // 3) extract some number of prefetched entries (just into fdcache)
...
      if (r != 0) // stage 3
        {
          // NB: now we know we have a complete reusable file; make fdcache
          // responsible for unlinking it later.
          obatched(clog) << "INTERN " << b_source1 << " filename=" << fn <<
endl;
          fdcache.intern(b_source0, fn,
                         tmppath, archive_entry_size(e),
                         false); // prefetched ones go to the prefetch cache
          prefetch_count --;
          close (fd); // we're not saving this fd to make a mhd-response from!
          continue;
        }

So what's bad is that
handle_buildid_r_match begins with:

  // check for a match in the fdcache first
  int fd = fdcache.lookup(b_source0, b_source1);
  while (fd >= 0) // got one!; NB: this is really an if() with a possible
branch out to the end
    {
...
    }

which was false, but happens to be true once another thread inters the file :/

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

^ permalink raw reply	[flat|nested] 7+ messages in thread

* [Bug debuginfod/29474] Server returns 404 for concurrent requests when leading to a same .rpm
  2022-08-11 16:48 [Bug debuginfod/29474] New: Server returns 404 for concurrent requests when leading to a same .rpm mliska at suse dot cz
  2022-08-11 20:17 ` [Bug debuginfod/29474] " mliska at suse dot cz
  2022-08-11 20:30 ` mliska at suse dot cz
@ 2022-08-11 20:39 ` mliska at suse dot cz
  2022-08-11 20:42 ` mliska at suse dot cz
                   ` (2 subsequent siblings)
  5 siblings, 0 replies; 7+ messages in thread
From: mliska at suse dot cz @ 2022-08-11 20:39 UTC (permalink / raw)
  To: elfutils-devel

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

--- Comment #3 from Martin Liska <mliska at suse dot cz> ---
Created attachment 14271
  --> https://sourceware.org/bugzilla/attachment.cgi?id=14271&action=edit
Possible patch candidate (needs removal of extra debugging)

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

^ permalink raw reply	[flat|nested] 7+ messages in thread

* [Bug debuginfod/29474] Server returns 404 for concurrent requests when leading to a same .rpm
  2022-08-11 16:48 [Bug debuginfod/29474] New: Server returns 404 for concurrent requests when leading to a same .rpm mliska at suse dot cz
                   ` (2 preceding siblings ...)
  2022-08-11 20:39 ` mliska at suse dot cz
@ 2022-08-11 20:42 ` mliska at suse dot cz
  2022-08-15  7:55 ` mliska at suse dot cz
  2022-08-15 10:27 ` fche at redhat dot com
  5 siblings, 0 replies; 7+ messages in thread
From: mliska at suse dot cz @ 2022-08-11 20:42 UTC (permalink / raw)
  To: elfutils-devel

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

Martin Liska <mliska at suse dot cz> changed:

           What    |Removed                     |Added
----------------------------------------------------------------------------
  Attachment #14271|0                           |1
        is obsolete|                            |

--- Comment #4 from Martin Liska <mliska at suse dot cz> ---
Created attachment 14272
  --> https://sourceware.org/bugzilla/attachment.cgi?id=14272&action=edit
Possible patch candidate (needs removal of extra debugging) v2

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

^ permalink raw reply	[flat|nested] 7+ messages in thread

* [Bug debuginfod/29474] Server returns 404 for concurrent requests when leading to a same .rpm
  2022-08-11 16:48 [Bug debuginfod/29474] New: Server returns 404 for concurrent requests when leading to a same .rpm mliska at suse dot cz
                   ` (3 preceding siblings ...)
  2022-08-11 20:42 ` mliska at suse dot cz
@ 2022-08-15  7:55 ` mliska at suse dot cz
  2022-08-15 10:27 ` fche at redhat dot com
  5 siblings, 0 replies; 7+ messages in thread
From: mliska at suse dot cz @ 2022-08-15  7:55 UTC (permalink / raw)
  To: elfutils-devel

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

Martin Liska <mliska at suse dot cz> changed:

           What    |Removed                     |Added
----------------------------------------------------------------------------
           Assignee|unassigned at sourceware dot org   |mliska at suse dot cz

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

^ permalink raw reply	[flat|nested] 7+ messages in thread

* [Bug debuginfod/29474] Server returns 404 for concurrent requests when leading to a same .rpm
  2022-08-11 16:48 [Bug debuginfod/29474] New: Server returns 404 for concurrent requests when leading to a same .rpm mliska at suse dot cz
                   ` (4 preceding siblings ...)
  2022-08-15  7:55 ` mliska at suse dot cz
@ 2022-08-15 10:27 ` fche at redhat dot com
  5 siblings, 0 replies; 7+ messages in thread
From: fche at redhat dot com @ 2022-08-15 10:27 UTC (permalink / raw)
  To: elfutils-devel

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

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

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

--- Comment #5 from Frank Ch. Eigler <fche at redhat dot com> ---
elfutils-0.187-44-g31d6b1fe7 / debuginfod/ChangeLog debuginfod/debuginfod.cxx:
PR29474: debuginfod

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

^ permalink raw reply	[flat|nested] 7+ messages in thread

end of thread, other threads:[~2022-08-15 10:27 UTC | newest]

Thread overview: 7+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2022-08-11 16:48 [Bug debuginfod/29474] New: Server returns 404 for concurrent requests when leading to a same .rpm mliska at suse dot cz
2022-08-11 20:17 ` [Bug debuginfod/29474] " mliska at suse dot cz
2022-08-11 20:30 ` mliska at suse dot cz
2022-08-11 20:39 ` mliska at suse dot cz
2022-08-11 20:42 ` mliska at suse dot cz
2022-08-15  7:55 ` mliska at suse dot cz
2022-08-15 10:27 ` fche at redhat dot com

This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for read-only IMAP folder(s) and NNTP newsgroup(s).