debuginfod: speed up extraction from kernel debuginfo packages by 200x
Omar Sandoval
maintainerv2 cover debuginfod: speed up extraction from kernel debuginfo packages by 200x
From: Omar Sandoval <[email protected]>
This is v2 of my patch series optimizing debuginfod for kernel debuginfo. v1 is here [7].
The main change from v1 is reworking the database changes to be backward compatible and therefore not require reindexing.
Patch 1 is a preparatory refactor. Patch 2 makes the schema changes. Patch 3 implements the seekable xz extraction. Patch 4 populates the table of seekable entries at scan time. Patch 5 does it for pre-existing files at request time.
Here is the background copied and pasted from v1:
drgn [1] currently uses debuginfod with great success for debugging userspace processes. However, for debugging the Linux kernel (drgn's main use case), we have had some performance issues with debuginfod, so we intentionally avoid using it. Specifically, it sometimes takes over a minute for debuginfod to respond to queries for vmlinux and kernel modules (not including the actual download time).
The reason for the slowness is that Linux kernel debuginfo packages are very large and contain lots of files. To respond to a query for a Linux kernel debuginfo file, debuginfod has to decompress and iterate through the whole package until it finds that file. If the file is towards the end of the package, this can take a very long time. This was previously reported for vdso files [2][3], which debuginfod was able to mitigate with improved caching and prefetching. However, kernel modules are far greater in number, vary drastically by hardware and workload, and can be spread all over the package, so in practice I've still been seeing long delays. This was also discussed on the drgn issue tracker [4].
The fundamental limitation is that Linux packages, which are essentially compressed archives with extra metadata headers, don't support random access to specific files. However, the multi-threaded xz compression format does actually support random access. And, luckily, the kernel debuginfo packages on Fedora, Debian, and Ubuntu all happen to use multi-threaded xz compression!
debuginfod can take advantage of this: when it scans a package, if it is a seekable xz archive, it can save the uncompressed offset and size of each file. Then, when it needs a file, it can seek to that offset and extract it from there. This requires some understanding of the xz format and low-level liblzma code, but the speedup is massive: where the worst case was previously about 50 seconds just to find a file in a kernel debuginfo package, with this change the worst case is 0.25 seconds, a ~200x improvement! This works for both .rpm and .deb files.
I tested this by requesting and verifying the digest of every file from a few kernel debuginfo rpms and debs [5].
P.S. The biggest downside of this change is that it depends on a very specific compression format that is only used by kernel packages incidentally. I think this is something we should formalize with Linux
distributions: large debuginfo packages should use a seekable format. Currently, xz in multi-threaded mode is the only option, but Zstandard also has an experimental seekable format that is worth looking into [6].
Thanks,
Omar
1: https://github.com/osandov/drgn
2: https://sourceware.org/bugzilla/show_bug.cgi?id=29478
3: https://bugzilla.redhat.com/show_bug.cgi?id=1970578
4: https://github.com/osandov/drgn/pull/380
5: https://gist.github.com/osandov/89d521fdc6c9a07aa8bb0ebf91974346
6: https://github.com/facebook/zstd/tree/dev/contrib/seekable_format
7: https://sourceware.org/pipermail/elfutils-devel/2024q3/007191.html
Omar Sandoval (5):
debuginfod: factor out common code for responding from an archive
debugifod: add new table and views for seekable archives
debuginfod: optimize extraction from seekable xz archives
debuginfod: populate _r_seekable on scan
debuginfod: populate _r_seekable on request
configure.ac | 5 + debuginfod/Makefile.am | 2 +- debuginfod/debuginfod.cxx | 921 ++++++++++++++++++++++++++++++++------ 3 files changed, 788 insertions(+), 140 deletions(-)
Signature · 1 line
2.45.2
Omar Sandoval
maintainerPATCH v2 1/5 debuginfod: factor out common code for responding from an archive
From: Omar Sandoval <[email protected]>
handle_buildid_r_match has two very similar branches where it optionally extracts a section and then creates a microhttpd response. In preparation for adding a third one, factor it out into a function.
--- debuginfod/debuginfod.cxx | 213 +++++++++++++++++--------------------- 1 file changed, 96 insertions(+), 117 deletions(-)
debuginfod/debuginfod.cxx +96 -117
@@ -1965,6 +1965,81 @@ string canonicalized_archive_entry_pathname(struct archive_entry *e) } +// NB: takes ownership of, and may reassign, fd. +static struct MHD_Response* +create_buildid_r_response (int64_t b_mtime0, + const string& b_source0, + const string& b_source1, + const string& section, + const string& ima_sig, + const char* tmppath, + int& fd, + off_t size, + time_t mtime, + const string& metric, + const struct timespec& extract_begin) +{ + if (tmppath != NULL) + { + struct timespec extract_end; + clock_gettime (CLOCK_MONOTONIC, &extract_end); + double extract_time = (extract_end.tv_sec - extract_begin.tv_sec) + + (extract_end.tv_nsec - extract_begin.tv_nsec)/1.e9; + fdcache.intern(b_source0, b_source1, tmppath, size, true, extract_time); + } + + if (!section.empty ()) + { + int scn_fd = extract_section (fd, b_mtime0, + b_source0 + ":" + b_source1, + section, extract_begin); + close (fd); + if (scn_fd >= 0) + fd = scn_fd; + else + { + if (verbose) + obatched (clog) << "cannot find section " << section + << " for archive " << b_source0 + << " file " << b_source1 << endl; + return 0; + } + + struct stat fs; + if (fstat (fd, &fs) < 0) + { + close (fd); + throw libc_exception (errno, + string ("fstat ") + b_source0 + string (" ") + section); + } + size = fs.st_size; + } + + struct MHD_Response* r = MHD_create_response_from_fd (size, fd); + if (r == 0) + { + if (verbose) + obatched(clog) << "cannot create fd-response for " << b_source0 << endl; + close(fd); + } + else + { + inc_metric ("http_responses_total","result",metric); + add_mhd_response_header (r, "Content-Type", "application/octet-stream"); + add_mhd_response_header (r, "X-DEBUGINFOD-SIZE", to_string(size).c_str()); + add_mhd_response_header (r, "X-DEBUGINFOD-ARCHIVE", b_source0.c_str()); + add_mhd_response_header (r, "X-DEBUGINFOD-FILE", b_source1.c_str()); + if(!ima_sig.empty()) add_mhd_response_header(r, "X-DEBUGINFOD-IMASIGNATURE", ima_sig.c_str()); + add_mhd_last_modified (r, mtime); + if (verbose > 1) + obatched(clog) << "serving " << metric << " " << b_source0 + << " file " << b_source1 + << " section=" << section + << " IMA signature=" << ima_sig << endl; + /* libmicrohttpd will close fd. */ + } + return r; +} static struct MHD_Response* handle_buildid_r_match (bool internal_req_p,
@@ -2142,57 +2217,15 @@ handle_buildid_r_match (bool internal_req_p, break; // branch out of if "loop", to try new libarchive fetch attempt } - if (!section.empty ()) - { - int scn_fd = extract_section (fd, fs.st_mtime, - b_source0 + ":" + b_source1, - section, extract_begin); - close (fd); - if (scn_fd >= 0) - fd = scn_fd; - else - { - if (verbose) - obatched (clog) << "cannot find section " << section - << " for archive " << b_source0 - << " file " << b_source1 << endl; - return 0; - } - - rc = fstat(fd, &fs); - if (rc < 0) - { - close (fd); - throw libc_exception (errno, - string ("fstat archive ") + b_source0 + string (" file ") + b_source1 - + string (" section ") + section); - } - } - - struct MHD_Response* r = MHD_create_response_from_fd (fs.st_size, fd); + struct MHD_Response* r = create_buildid_r_response (b_mtime, b_source0, + b_source1, section, + ima_sig, NULL, fd, + fs.st_size, + fs.st_mtime, + "archive fdcache", + extract_begin); if (r == 0) - { - if (verbose) - obatched(clog) << "cannot create fd-response for " << b_source0 << endl; - close(fd); - break; // branch out of if "loop", to try new libarchive fetch attempt - } - - inc_metric ("http_responses_total","result","archive fdcache"); - - add_mhd_response_header (r, "Content-Type", "application/octet-stream"); - add_mhd_response_header (r, "X-DEBUGINFOD-SIZE", - to_string(fs.st_size).c_str()); - add_mhd_response_header (r, "X-DEBUGINFOD-ARCHIVE", b_source0.c_str()); - add_mhd_response_header (r, "X-DEBUGINFOD-FILE", b_source1.c_str()); - if(!ima_sig.empty()) add_mhd_response_header(r, "X-DEBUGINFOD-IMASIGNATURE", ima_sig.c_str()); - add_mhd_last_modified (r, fs.st_mtime); - if (verbose > 1) - obatched(clog) << "serving fdcache archive " << b_source0 - << " file " << b_source1 - << " section=" << section - << " IMA signature=" << ima_sig << endl; - /* libmicrohttpd will close it. */ + break; // branch out of if "loop", to try new libarchive fetch attempt if (result_fd) *result_fd = fd; return r;
@@ -2307,13 +2340,12 @@ handle_buildid_r_match (bool internal_req_p, tvs[1].tv_nsec = archive_entry_mtime_nsec(e); (void) futimens (fd, tvs); /* best effort */ - struct timespec extract_end; - clock_gettime (CLOCK_MONOTONIC, &extract_end); - double extract_time = (extract_end.tv_sec - extract_begin.tv_sec) - + (extract_end.tv_nsec - extract_begin.tv_nsec)/1.e9; - if (r != 0) // stage 3 { + struct timespec extract_end; + clock_gettime (CLOCK_MONOTONIC, &extract_end); + double extract_time = (extract_end.tv_sec - extract_begin.tv_sec) + + (extract_end.tv_nsec - extract_begin.tv_nsec)/1.e9; // NB: now we know we have a complete reusable file; make fdcache // responsible for unlinking it later. fdcache.intern(b_source0, fn,
@@ -2324,69 +2356,16 @@ handle_buildid_r_match (bool internal_req_p, continue; } - // NB: now we know we have a complete reusable file; make fdcache - // responsible for unlinking it later. - fdcache.intern(b_source0, b_source1, - tmppath, archive_entry_size(e), - true, extract_time); // requested ones go to the front of the line - - if (!section.empty ()) - { - int scn_fd = extract_section (fd, b_mtime, - b_source0 + ":" + b_source1, - section, extract_begin); - close (fd); - if (scn_fd >= 0) - fd = scn_fd; - else - { - if (verbose) - obatched (clog) << "cannot find section " << section - << " for archive " << b_source0 - << " file " << b_source1 << endl; - return 0; - } - - rc = fstat(fd, &fs); - if (rc < 0) - { - close (fd); - throw libc_exception (errno, - string ("fstat ") + b_source0 + string (" ") + section); - } - r = MHD_create_response_from_fd (fs.st_size, fd); - } - else - r = MHD_create_response_from_fd (archive_entry_size(e), fd); - - inc_metric ("http_responses_total","result",archive_extension + " archive"); + r = create_buildid_r_response (b_mtime, b_source0, b_source1, section, + ima_sig, tmppath, fd, + archive_entry_size(e), + archive_entry_mtime(e), + archive_extension + " archive", + extract_begin); if (r == 0) - { - if (verbose) - obatched(clog) << "cannot create fd-response for " << b_source0 << endl; - close(fd); - break; // assume no chance of better luck around another iteration; no other copies of same file - } - else - { - add_mhd_response_header (r, "Content-Type", - "application/octet-stream"); - add_mhd_response_header (r, "X-DEBUGINFOD-SIZE", - to_string(archive_entry_size(e)).c_str()); - add_mhd_response_header (r, "X-DEBUGINFOD-ARCHIVE", b_source0.c_str()); - add_mhd_response_header (r, "X-DEBUGINFOD-FILE", b_source1.c_str()); - if(!ima_sig.empty()) add_mhd_response_header(r, "X-DEBUGINFOD-IMASIGNATURE", ima_sig.c_str()); - add_mhd_last_modified (r, archive_entry_mtime(e)); - if (verbose > 1) - obatched(clog) << "serving archive " << b_source0 - << " file " << b_source1 - << " section=" << section - << " IMA signature=" << ima_sig << endl; - /* libmicrohttpd will close it. */ - if (result_fd) - *result_fd = fd; - continue; - } + break; // assume no chance of better luck around another iteration; no other copies of same file + if (result_fd) + *result_fd = fd; } // XXX: rpm/file not found: delete this R entry?
Signature · 1 line
2.45.2
Omar Sandoval
maintainerPATCH v2 2/5 debugifod: add new table and views for seekable archives
In reply to Omar SandovalFrom: Omar Sandoval <[email protected]>
In order to extract a file from a seekable archive, we need to know where in the uncompressed archive the file data starts and its size. Additionally, in order to populate the response headers, we need the file modification time (since we won't be able to get it from the archive metadata). Add a new table, _r_seekable, keyed on the archive file id and entry file id and containing the size, offset, and mtime. It also contains the compression type just in case new seekable formats are supported in the future.
In order to search this table when we get a request, we need the file ids available. Add the ids to the _query_d and _query_e views, and rename them to _query_d2 and _query_e2.
This schema change is backward compatible and doesn't require reindexing. _query_d2 and _query_e2 can be renamed back the next time BUILDIDS needs to be bumped.
Before this change, the database for a single kernel debuginfo RPM (kernel-debuginfo-6.9.6-200.fc40.x86_64.rpm) was about 15MB. This change increases that by about 70kB, only a 0.5% increase.
--- debuginfod/debuginfod.cxx | 34 ++++++++++++++++++++++++---------- 1 file changed, 24 insertions(+), 10 deletions(-)
debuginfod/debuginfod.cxx +24 -10
@@ -265,25 +265,39 @@ static const char DEBUGINFOD_SQLITE_DDL[] = " foreign key (content) references " BUILDIDS "_files(id) on update cascade on delete cascade,\n" " primary key (content, file, mtime)\n" " ) " WITHOUT_ROWID ";\n" + "create table if not exists " BUILDIDS "_r_seekable (\n" // seekable rpm contents + " file integer not null,\n" + " content integer not null,\n" + " type text not null,\n" + " size integer not null,\n" + " offset integer not null,\n" + " mtime integer not null,\n" + " foreign key (file) references " BUILDIDS "_files(id) on update cascade on delete cascade,\n" + " foreign key (content) references " BUILDIDS "_files(id) on update cascade on delete cascade,\n" + " primary key (file, content)\n" + " ) " WITHOUT_ROWID ";\n" // create views to glue together some of the above tables, for webapi D queries - "create view if not exists " BUILDIDS "_query_d as \n" + // NB: _query_d2 and _query_e2 were added to replace _query_d and _query_e + // without updating BUILDIDS. They can be renamed back the next time BUILDIDS + // is updated. + "create view if not exists " BUILDIDS "_query_d2 as \n" "select\n" - " b.hex as buildid, n.mtime, 'F' as sourcetype, f0.name as source0, n.mtime as mtime, null as source1\n" + " b.hex as buildid, 'F' as sourcetype, n.file as id0, f0.name as source0, n.mtime as mtime, null as id1, null as source1\n" " from " BUILDIDS "_buildids b, " BUILDIDS "_files_v f0, " BUILDIDS "_f_de n\n" " where b.id = n.buildid and f0.id = n.file and n.debuginfo_p = 1\n" "union all select\n" - " b.hex as buildid, n.mtime, 'R' as sourcetype, f0.name as source0, n.mtime as mtime, f1.name as source1\n" + " b.hex as buildid, 'R' as sourcetype, n.file as id0, f0.name as source0, n.mtime as mtime, n.content as id1, f1.name as source1\n" " from " BUILDIDS "_buildids b, " BUILDIDS "_files_v f0, " BUILDIDS "_files_v f1, " BUILDIDS "_r_de n\n" " where b.id = n.buildid and f0.id = n.file and f1.id = n.content and n.debuginfo_p = 1\n" ";" // ... and for E queries - "create view if not exists " BUILDIDS "_query_e as \n" + "create view if not exists " BUILDIDS "_query_e2 as \n" "select\n" - " b.hex as buildid, n.mtime, 'F' as sourcetype, f0.name as source0, n.mtime as mtime, null as source1\n" + " b.hex as buildid, 'F' as sourcetype, n.file as id0, f0.name as source0, n.mtime as mtime, null as id1, null as source1\n" " from " BUILDIDS "_buildids b, " BUILDIDS "_files_v f0, " BUILDIDS "_f_de n\n" " where b.id = n.buildid and f0.id = n.file and n.executable_p = 1\n" "union all select\n" - " b.hex as buildid, n.mtime, 'R' as sourcetype, f0.name as source0, n.mtime as mtime, f1.name as source1\n" + " b.hex as buildid, 'R' as sourcetype, n.file as id0, f0.name as source0, n.mtime as mtime, n.content as id1, f1.name as source1\n" " from " BUILDIDS "_buildids b, " BUILDIDS "_files_v f0, " BUILDIDS "_files_v f1, " BUILDIDS "_r_de n\n" " where b.id = n.buildid and f0.id = n.file and f1.id = n.content and n.executable_p = 1\n" ";"
@@ -2557,7 +2571,7 @@ handle_buildid (MHD_Connection* conn, if (atype_code == "D") { pp = new sqlite_ps (thisdb, "mhd-query-d", - "select mtime, sourcetype, source0, source1 from " BUILDIDS "_query_d where buildid = ? " + "select mtime, sourcetype, source0, source1 from " BUILDIDS "_query_d2 where buildid = ? " "order by mtime desc"); pp->reset(); pp->bind(1, buildid);
@@ -2565,7 +2579,7 @@ handle_buildid (MHD_Connection* conn, else if (atype_code == "E") { pp = new sqlite_ps (thisdb, "mhd-query-e", - "select mtime, sourcetype, source0, source1 from " BUILDIDS "_query_e where buildid = ? " + "select mtime, sourcetype, source0, source1 from " BUILDIDS "_query_e2 where buildid = ? " "order by mtime desc"); pp->reset(); pp->bind(1, buildid);
@@ -2589,9 +2603,9 @@ handle_buildid (MHD_Connection* conn, else if (atype_code == "I") { pp = new sqlite_ps (thisdb, "mhd-query-i", - "select mtime, sourcetype, source0, source1, 1 as debug_p from " BUILDIDS "_query_d where buildid = ? " + "select mtime, sourcetype, source0, source1, 1 as debug_p from " BUILDIDS "_query_d2 where buildid = ? " "union all " - "select mtime, sourcetype, source0, source1, 0 as debug_p from " BUILDIDS "_query_e where buildid = ? " + "select mtime, sourcetype, source0, source1, 0 as debug_p from " BUILDIDS "_query_e2 where buildid = ? " "order by debug_p desc, mtime desc"); pp->reset(); pp->bind(1, buildid);
Signature · 1 line
2.45.2
Omar Sandoval
maintainerPATCH v2 3/5 debuginfod: optimize extraction from seekable xz archives
In reply to Omar SandovalFrom: Omar Sandoval <[email protected]>
The kernel debuginfo packages on Fedora, Debian, and Ubuntu, and many of their downstreams, are all compressed with xz in multi-threaded mode, which allows random access. We can use this to bypass the full archive extraction and dramatically speed up kernel debuginfo requests (from ~50 seconds in the worst case to < 0.25 seconds).
This works because multi-threaded xz compression splits up the stream into many independently compressed blocks. The stream ends with an index of blocks. So, to seek to an offset, we find the block containing that offset in the index and then decompress and throw away data until we reach the offset within the block. We can then decompress the desired amount of data, possibly from subsequent blocks. There's no high-level API in liblzma to do this, but we can do it by stitching together a few low-level APIs.
We need to pass down the file ids then look up the size, uncompressed offset, and mtime in the _r_seekable table. Note that this table is not yet populated, so this commit has no functional change on its own.
--- configure.ac | 5 + debuginfod/Makefile.am | 2 +- debuginfod/debuginfod.cxx | 452 +++++++++++++++++++++++++++++++++++++- 3 files changed, 453 insertions(+), 6 deletions(-)
configure.ac +5 -0
@@ -441,8 +441,13 @@ eu_ZIPLIB(bzlib,BZLIB,bz2,BZ2_bzdopen,bzip2) # We need this since bzip2 doesn't have a pkgconfig file. BZ2_LIB="$LIBS" AC_SUBST([BZ2_LIB]) +save_LIBS="$LIBS" +LIBS= eu_ZIPLIB(lzma,LZMA,lzma,lzma_auto_decoder,[LZMA (xz)]) +lzma_LIBS="$LIBS" +LIBS="$lzma_LIBS $save_LIBS" AS_IF([test "x$with_lzma" = xyes], [LIBLZMA="liblzma"], [LIBLZMA=""]) +AC_SUBST([lzma_LIBS]) AC_SUBST([LIBLZMA]) eu_ZIPLIB(zstd,ZSTD,zstd,ZSTD_decompress,[ZSTD (zst)]) AS_IF([test "x$with_zstd" = xyes], [LIBZSTD="libzstd"], [LIBLZSTD=""])
debuginfod/Makefile.am +1 -1
@@ -70,7 +70,7 @@ bin_PROGRAMS += debuginfod-find endif debuginfod_SOURCES = debuginfod.cxx -debuginfod_LDADD = $(libdw) $(libelf) $(libeu) $(libdebuginfod) $(argp_LDADD) $(fts_LIBS) $(libmicrohttpd_LIBS) $(sqlite3_LIBS) $(libarchive_LIBS) $(rpm_LIBS) $(jsonc_LIBS) $(libcurl_LIBS) -lpthread -ldl +debuginfod_LDADD = $(libdw) $(libelf) $(libeu) $(libdebuginfod) $(argp_LDADD) $(fts_LIBS) $(libmicrohttpd_LIBS) $(sqlite3_LIBS) $(libarchive_LIBS) $(rpm_LIBS) $(jsonc_LIBS) $(libcurl_LIBS) $(lzma_LIBS) -lpthread -ldl debuginfod_find_SOURCES = debuginfod-find.c debuginfod_find_LDADD = $(libdw) $(libelf) $(libeu) $(libdebuginfod) $(argp_LDADD) $(fts_LIBS) $(jsonc_LIBS)
debuginfod/debuginfod.cxx +447 -5
512 lines not on this page · raw message
Signature · 1 line
2.45.2
Omar Sandoval
maintainerPATCH v2 4/5 debuginfod: populate _r_seekable on scan
In reply to Omar SandovalFrom: Omar Sandoval <[email protected]>
Whenever a new archive is scanned, check if it is seekable with a little liblzma magic, and populate _r_seekable if so. With this, newly scanned seekable archives will used the optimized extraction path added in the previous commit.
--- debuginfod/debuginfod.cxx | 150 +++++++++++++++++++++++++++++++++++++- 1 file changed, 147 insertions(+), 3 deletions(-)
debuginfod/debuginfod.cxx +147 -3
@@ -1998,6 +1998,109 @@ struct lzma_exception: public reportable_exception // // 1: https://xz.tukaani.org/format/xz-file-format.txt +// Return whether an archive supports seeking. +static bool +is_seekable_archive (const string& rps, struct archive* a) +{ + // Only xz supports seeking. + if (archive_filter_code (a, 0) != ARCHIVE_FILTER_XZ) + return false; + + int fd = open (rps.c_str(), O_RDONLY); + if (fd < 0) + return false; + defer_dtor<int,int> fd_closer (fd, close); + + // Seek to the xz Stream Footer. We assume that it's the last thing in the + // file, which is true for RPM and deb files. + off_t footer_pos = -LZMA_STREAM_HEADER_SIZE; + if (lseek (fd, footer_pos, SEEK_END) == -1) + return false; + + // Decode the Stream Footer. + uint8_t footer[LZMA_STREAM_HEADER_SIZE]; + size_t footer_read = 0; + while (footer_read < sizeof (footer)) + { + ssize_t bytes_read = read (fd, footer + footer_read, + sizeof (footer) - footer_read); + if (bytes_read < 0) + { + if (errno == EINTR) + continue; + return false; + } + if (bytes_read == 0) + return false; + footer_read += bytes_read; + } + + lzma_stream_flags stream_flags; + lzma_ret ret = lzma_stream_footer_decode (&stream_flags, footer); + if (ret != LZMA_OK) + return false; + + // Seek to the xz Index. + if (lseek (fd, footer_pos - stream_flags.backward_size, SEEK_END) == -1) + return false; + + // Decode the Number of Records in the Index. liblzma doesn't have an API for + // this if you don't want to decode the whole Index, so we have to do it + // ourselves. + // + // We need 1 byte for the Index Indicator plus 1-9 bytes for the + // variable-length integer Number of Records. + uint8_t index[10]; + size_t index_read = 0; + while (index_read == 0) { + ssize_t bytes_read = read (fd, index, sizeof (index)); + if (bytes_read < 0) + { + if (errno == EINTR) + continue; + return false; + } + if (bytes_read == 0) + return false; + index_read += bytes_read; + } + // The Index Indicator must be 0. + if (index[0] != 0) + return false; + + lzma_vli num_records; + size_t pos = 0; + size_t in_pos = 1; + while (true) + { + if (in_pos >= index_read) + { + ssize_t bytes_read = read (fd, index, sizeof (index)); + if (bytes_read < 0) + { + if (errno == EINTR) + continue; + return false; + } + if (bytes_read == 0) + return false; + index_read = bytes_read; + in_pos = 0; + } + ret = lzma_vli_decode (&num_records, &pos, index, &in_pos, index_read); + if (ret == LZMA_STREAM_END) + break; + else if (ret != LZMA_OK) + return false; + } + + if (verbose > 3) + obatched(clog) << rps << " has " << num_records << " xz Blocks" << endl; + + // The file is only seekable if it has more than one Block. + return num_records > 1; +} + // Read the Index at the end of an xz file. static lzma_index* read_xz_index (int fd)
@@ -2330,6 +2433,11 @@ extract_from_seekable_archive (const string& srcpath, } } #else +static bool +is_seekable_archive (const string& rps, struct archive* a) +{ + return false; +} static int extract_from_seekable_archive (const string& srcpath, char* tmppath,
@@ -4277,6 +4385,7 @@ archive_classify (const string& rps, string& archive_extension, int64_t archivei sqlite_ps& ps_upsert_buildids, sqlite_ps& ps_upsert_fileparts, sqlite_ps& ps_upsert_file, sqlite_ps& ps_lookup_file, sqlite_ps& ps_upsert_de, sqlite_ps& ps_upsert_sref, sqlite_ps& ps_upsert_sdef, + sqlite_ps& ps_upsert_seekable, time_t mtime, unsigned& fts_executable, unsigned& fts_debuginfo, unsigned& fts_sref, unsigned& fts_sdef, bool& fts_sref_complete_p)
@@ -4331,6 +4440,10 @@ archive_classify (const string& rps, string& archive_extension, int64_t archivei if (verbose > 3) obatched(clog) << "libarchive scanning " << rps << " id " << archiveid << endl; + bool seekable = is_seekable_archive (rps, a); + if (verbose> 2 && seekable) + obatched(clog) << rps << " is seekable" << endl; + bool any_exceptions = false; while(1) // parse archive entries {
@@ -4352,6 +4465,15 @@ archive_classify (const string& rps, string& archive_extension, int64_t archivei if (verbose > 3) obatched(clog) << "libarchive checking " << fn << endl; + int64_t seekable_size, seekable_offset; + time_t seekable_mtime; + if (seekable) + { + seekable_size = archive_entry_size (e); + seekable_offset = archive_filter_bytes (a, 0); + seekable_mtime = archive_entry_mtime (e); + } + // extract this file to a temporary file char* tmppath = NULL; rc = asprintf (&tmppath, "%s/debuginfod-classify.XXXXXX", tmpdir.c_str());
@@ -4443,6 +4565,15 @@ archive_classify (const string& rps, string& archive_extension, int64_t archivei .bind(5, mtime) .bind(6, fileid) .step_ok_done(); + if (seekable) + ps_upsert_seekable + .reset() + .bind(1, archiveid) + .bind(2, fileid) + .bind(3, seekable_size) + .bind(4, seekable_offset) + .bind(5, seekable_mtime) + .step_ok_done(); } else // potential source - sdef record {
@@ -4456,11 +4587,19 @@ archive_classify (const string& rps, string& archive_extension, int64_t archivei } if ((verbose > 2) && (executable_p || debuginfo_p)) - obatched(clog) << "recorded buildid=" << buildid << " rpm=" << rps << " file=" << fn + { + obatched ob(clog); + auto& o = ob << "recorded buildid=" << buildid << " rpm=" << rps << " file=" << fn << " mtime=" << mtime << " atype=" << (executable_p ? "E" : "") << (debuginfo_p ? "D" : "") - << " sourcefiles=" << sourcefiles.size() << endl; + << " sourcefiles=" << sourcefiles.size(); + if (seekable) + o << " seekable size=" << seekable_size + << " offset=" << seekable_offset + << " mtime=" << seekable_mtime; + o << endl; + } } catch (const reportable_exception& e)
@@ -4491,6 +4630,7 @@ scan_archive_file (const string& rps, const stat_t& st, sqlite_ps& ps_upsert_de, sqlite_ps& ps_upsert_sref, sqlite_ps& ps_upsert_sdef, + sqlite_ps& ps_upsert_seekable, sqlite_ps& ps_query, sqlite_ps& ps_scan_done, unsigned& fts_cached,
@@ -4528,7 +4668,7 @@ scan_archive_file (const string& rps, const stat_t& st, string archive_extension; archive_classify (rps, archive_extension, archiveid, ps_upsert_buildids, ps_upsert_fileparts, ps_upsert_file, ps_lookup_file, - ps_upsert_de, ps_upsert_sref, ps_upsert_sdef, // dalt + ps_upsert_de, ps_upsert_sref, ps_upsert_sdef, ps_upsert_seekable, // dalt st.st_mtime, my_fts_executable, my_fts_debuginfo, my_fts_sref, my_fts_sdef, my_fts_sref_complete_p);
@@ -4634,6 +4774,9 @@ scan () sqlite_ps ps_r_upsert_sdef (db, "rpm-sdef-insert", "insert or ignore into " BUILDIDS "_r_sdef (file, mtime, content) values (" "?, ?, ?);"); + sqlite_ps ps_r_upsert_seekable (db, "rpm-seekable-insert", + "insert or ignore into " BUILDIDS "_r_seekable (file, content, type, size, offset, mtime) " + "values (?, ?, 'xz', ?, ?, ?);"); sqlite_ps ps_r_query (db, "rpm-negativehit-query", "select 1 from " BUILDIDS "_file_mtime_scanned where " "sourcetype = 'R' and file = ? and mtime = ?;");
@@ -4676,6 +4819,7 @@ scan () ps_r_upsert_de, ps_r_upsert_sref, ps_r_upsert_sdef, + ps_r_upsert_seekable, ps_r_query, ps_r_scan_done, fts_cached,
Signature · 1 line
2.45.2
Omar Sandoval
maintainerPATCH v2 5/5 debuginfod: populate _r_seekable on request
In reply to Omar SandovalFrom: Omar Sandoval <[email protected]>
Since the schema change adding _r_seekable was done in a backward compatible way, seekable archives that were previously scanned will not be in _r_seekable. Whenever an archive is going to be extracted to satisfy a request, check if it is seekable. If so, populate _r_seekable while extracting it so that future requests use the optimized path.
The next time that BUILDIDS is bumped, all archives will be checked at scan time. At that point, checking again will be unnecessary and this commit can be reverted.
--- debuginfod/debuginfod.cxx | 76 +++++++++++++++++++++++++++++++++++---- 1 file changed, 70 insertions(+), 6 deletions(-)
debuginfod/debuginfod.cxx +70 -6
@@ -2737,6 +2737,7 @@ handle_buildid_r_match (bool internal_req_p, } // no match ... look for a seekable entry + bool populate_seekable = true; unique_ptr<sqlite_ps> pp (new sqlite_ps (db, "rpm-seekable-query", "select type, size, offset, mtime from " BUILDIDS "_r_seekable " "where file = ? and content = ?"));
@@ -2745,6 +2746,9 @@ handle_buildid_r_match (bool internal_req_p, { if (rc != SQLITE_ROW) throw sqlite_exception(rc, "step"); + // if we found a match in _r_seekable but we fail to extract it, don't + // bother populating it again + populate_seekable = false; const char* seekable_type = (const char*) sqlite3_column_text (*pp, 0); if (seekable_type != NULL && strcmp (seekable_type, "xz") == 0) {
@@ -2836,16 +2840,39 @@ handle_buildid_r_match (bool internal_req_p, throw archive_exception(a, "cannot open archive from pipe"); } - // archive traversal is in three stages, no, four stages: - // 1) skip entries whose names do not match the requested one - // 2) extract the matching entry name (set r = result) - // 3) extract some number of prefetched entries (just into fdcache) - // 4) abort any further processing + // If the archive was scanned in a version without _r_seekable, then we may + // need to populate _r_seekable now. This can be removed the next time + // BUILDIDS is updated. + if (populate_seekable) + { + populate_seekable = is_seekable_archive (b_source0, a); + if (populate_seekable) + { + // NB: the names are already interned + pp.reset(new sqlite_ps (db, "rpm-seekable-insert2", + "insert or ignore into " BUILDIDS "_r_seekable (file, content, type, size, offset, mtime) " + "values (?, " + "(select id from " BUILDIDS "_files " + "where dirname = (select id from " BUILDIDS "_fileparts where name = ?) " + "and basename = (select id from " BUILDIDS "_fileparts where name = ?) " + "), 'xz', ?, ?, ?)")); + } + } + + // archive traversal is in five stages: + // 1) before we find a matching entry, insert it into _r_seekable if needed or + // skip it otherwise + // 2) extract the matching entry (set r = result). Also insert it into + // _r_seekable if needed + // 3) extract some number of prefetched entries (just into fdcache). Also + // insert them into _r_seekable if needed + // 4) if needed, insert all of the remaining entries into _r_seekable + // 5) abort any further processing struct MHD_Response* r = 0; // will set in stage 2 unsigned prefetch_count = internal_req_p ? 0 : fdcache_prefetch; // will decrement in stage 3 - while(r == 0 || prefetch_count > 0) // stage 1, 2, or 3 + while(r == 0 || prefetch_count > 0 || populate_seekable) // stage 1-4 { if (interrupted) break;
@@ -2859,6 +2886,43 @@ handle_buildid_r_match (bool internal_req_p, continue; string fn = canonicalized_archive_entry_pathname (e); + + if (populate_seekable) + { + string dn, bn; + size_t slash = fn.rfind('/'); + if (slash == std::string::npos) { + dn = ""; + bn = fn; + } else { + dn = fn.substr(0, slash); + bn = fn.substr(slash + 1); + } + + int64_t seekable_size = archive_entry_size (e); + int64_t seekable_offset = archive_filter_bytes (a, 0); + time_t seekable_mtime = archive_entry_mtime (e); + + pp->reset(); + pp->bind(1, b_id0); + pp->bind(2, dn); + pp->bind(3, bn); + pp->bind(4, seekable_size); + pp->bind(5, seekable_offset); + pp->bind(6, seekable_mtime); + rc = pp->step(); + if (rc != SQLITE_DONE) + obatched(clog) << "recording seekable file=" << fn + << " sqlite3 error: " << (sqlite3_errstr(rc) ?: "?") << endl; + else if (verbose > 2) + obatched(clog) << "recorded seekable file=" << fn + << " size=" << seekable_size + << " offset=" << seekable_offset + << " mtime=" << seekable_mtime << endl; + if (r != 0 && prefetch_count == 0) // stage 4 + continue; + } + if ((r == 0) && (fn != b_source1)) // stage 1 continue;
Signature · 1 line
2.45.2
Hi -
Quoted 2 lines
This is v2 of my patch series optimizing debuginfod for kernel debuginfo. v1 is here [7].
This generally looks great to me. I'll send it through the testsuite trybots here. But there isn't an xz-y test case yet. Is there a smallish seekable-xz rpm file that you have or could make that we could jam into the elfutils testsuite? (A prometheus metric counting seeked-xz attempts/successes would be cool to assist testing and to monitor it on deployed servers.)
- FChE
Omar Sandoval
maintainerQuoted 7 lines · Frank Ch. Eigler
Hi -
Quoted 2 lines
This is v2 of my patch series optimizing debuginfod for kernel debuginfo. v1 is here [7].
This generally looks great to me. I'll send it through the testsuite trybots here.
Great, thank you!
Quoted 3 lines
But there isn't an xz-y test case yet. Is there a smallish seekable-xz rpm file that you have or could make that we could jam into the elfutils testsuite?
Good point, I'll add one.
Quoted 3 lines
(A prometheus metric counting
seeked-xz attempts/successes would be cool to assist testing and to monitor it on deployed servers.)
I do have:
inc_metric("error_count","lzma",to_string(rc));in lzma_exception and:
inc_metric ("http_responses_total","result",metric);in create_buildid_r_response, which gets called with
metric = "seekable archive". But I'll add another metric for attempts, and name the existing one "seekable xz archive" to be more explicit.
Thanks,
Omar
Hi -
Quoted 2 lines
[...] I'll send it through the testsuite
trybots here. [...]
There was some success and there was some failure. :-)
all 11 runs:
in a grid view:
e.g. failure:
- FChE
Omar Sandoval
maintainerQuoted 11 lines · Frank Ch. Eigler
Hi -
Quoted 2 lines
[...] I'll send it through the testsuite
trybots here. [...]There was some success and there was some failure. :-)
all 11 runs:
Quoted 7 lines
in a grid view:
e.g. failure:
Yup, that was a goof, and I don't know why I missed it on my local test run. This is the fix:
debuginfod/debuginfod.cxx +3 -2
@@ -2737,8 +2737,9 @@ handle_buildid_r_match (bool internal_req_p, } // no match ... look for a seekable entry - bool populate_seekable = true; - unique_ptr<sqlite_ps> pp (new sqlite_ps (db, "rpm-seekable-query", + bool populate_seekable = ! passive_p; + unique_ptr<sqlite_ps> pp (new sqlite_ps (internal_req_p ? db : dbq, + "rpm-seekable-query", "select type, size, offset, mtime from " BUILDIDS "_r_seekable " "where file = ? and content = ?")); rc = pp->reset().bind(1, b_id0).bind(2, b_id1).step();
I'll fold that in and include it in the next version.