On Freitag, 8. April 2022 22:59:55 CEST Mark Wielaard wrote: > Hi Milian, > > On Fri, Apr 08, 2022 at 10:45:10PM +0200, Milian Wolff wrote: > > In the off-CPU flame graphs I clearly see this callchain when > > DEBUGINFOD_URLS is set: > > > > ``` > > dwfl_standard_find_debuginfo > debuginfod_query_server > curl_multi_wait > > ``` > > > > This accounts for ~2.5s of off-CPU time in my case. If you are saying that > > negative lookups are cached, then what is this? Why would a second run of > > the same dwfl-using application with the same input data keep querying > > the server? > > That is certainly not what should happen once the cache is filled. > Could you run with DEBUGINFOD_VERBOSE=1 to see what is being fetched and > why?
My first mail showed this already. But here is one such block: ``` debuginfod_find_debuginfo 85766e9d8458b16e9c7ce6e07c712c02b8471dbc server urls "https://debuginfod.archlinux.org/"; checking build-id checking cache dir /home/milian/.cache/debuginfod_client using timeout 90 init server 0 https://debuginfod.archlinux.org/buildid url 0 https://debuginfod.archlinux.org/buildid/ 85766e9d8458b16e9c7ce6e07c712c02b8471dbc/debuginfo query 1 urls in parallel server response HTTP response code said error url 0 The requested URL returned error: 404 not found No such file or directory (err=-2) ``` I see this repeated multiple times - both for different files and for the same file. I.e.: ``` $ /home/milian/projects/compiled/other/lib/heaptrack/libexec/ heaptrack_interpret < heaptrack.kate.52068.raw |& egrep "^url 0 https" | sort | uniq -c | sort -n ``` Produces this output here locally for me: https://invent.kde.org/-/snippets/ 2153 I can reproduce it now suddenly with debuginfod-find too: ``` $ debuginfod-find debuginfo 85766e9d8458b16e9c7ce6e07c712c02b8471dbc debuginfod_find_debuginfo 85766e9d8458b16e9c7ce6e07c712c02b8471dbc server urls "https://debuginfod.archlinux.org/"; checking build-id checking cache dir /home/milian/.cache/debuginfod_client using timeout 90 init server 0 https://debuginfod.archlinux.org/buildid url 0 https://debuginfod.archlinux.org/buildid/ 85766e9d8458b16e9c7ce6e07c712c02b8471dbc/debuginfo query 1 urls in parallel server response HTTP response code said error url 0 The requested URL returned error: 404 not found No such file or directory (err=-2) Server query failed: No such file or directory ``` I do see an empty `/home/milian/.cache/debuginfod_client/ 85766e9d8458b16e9c7ce6e07c712c02b8471dbc/debuginfo` file. But the server is still queried (i.e. rerunning the above command always produces the same output for me). The lookup is costly too at ~70ms overall: ``` $ perf stat -r 5 debuginfod-find debuginfo 85766e9d8458b16e9c7ce6e07c712c02b8471dbc 7.83 msec task-clock # 0.114 CPUs utilized ( +- 4.75% ) ... 0.06857 +- 0.00187 seconds time elapsed ( +- 2.73% ) ``` Thanks -- Milian Wolff m...@milianw.de http://milianw.de
signature.asc
Description: This is a digitally signed message part.
