Uploaded image for project: 'RHEL'
  1. RHEL
  2. RHEL-64320

reposync fails to download all packages due to checksum errors

Linking RHIVOS CVEs to...Migration: Automation ...SWIFT: POC ConversionSync from "Extern...XMLWordPrintable

    • dnf-plugins-core-4.3.0-21.el9
    • No
    • Moderate
    • rhel-swm
    • ssg_core_services
    • 8
    • 10
    • 0
    • False
    • False
    • Hide

      None

      Show
      None
    • No
    • Red Hat Enterprise Linux
    • None
    • Unspecified Release Note Type - Unknown
    • None

      What were you trying to do that didn't work?

      Please read carefully, this is a tough bug.

      When syncing AppStream, as of Oct 23, 2024, the syncing fails on various packages, especially grafana-9.2.10-17.el9_4.x86_64.rpm, due to checksum error.
      It's not always failing, it depends on the dynamic of reposync.
      Still, in all cases, we can see the following error message, which is key to this issue:

      [MIRROR] grafana-9.2.10-17.el9_4.x86_64.rpm: Interrupted by header callback: Inconsistent server data, reported file Content-Length: 60485191, repository metadata states file length: 77536839 (please report to repository maintainer)
      

      Checking on the HTTP side, the length in the repository is correct, it's some kind of false-positive showing up, due to libcurl downloading partially the package while it was already downloading fully the package through another connection.
      The strace shows this clearly:

      1. Request sent to download the package fully
        6744  11:15:14.539975 sendto(19<TCP:[127.0.0.1:45870->127.0.0.1:80]>, "GET /minimal-app-os/Packages/g/grafana-9.2.10-17.el9_4.x86_64.rpm HTTP/1.1\r\nHost: 127.0.0.1\r\nUser-Agent: libdnf (Red Hat Enterprise Linux 9.4; generic; Linux.x86_64)\r\nAccept: */*\r\n\r\n", 182, MSG_NOSIGNAL, NULL, 0) = 182 <0.000093>
         :
        6744  11:15:14.540833 recvfrom(19<TCP:[127.0.0.1:45870->127.0.0.1:80]>, "HTTP/1.1 200 OK\r\nDate: Wed, 23 Oct 2024 09:15:14 GMT\r\nServer: Apache/2.4.57 (Red Hat Enterprise Linux)\r\nLast-Modified: Wed, 23 Oct 2024 08:35:23 GMT\r\nETag: \"49f1e47-62520c45189b6\"\r\nAccept-Ranges: bytes\r\nContent-Length: 77536839\r\nContent-Type: application/x-rpm
        

        Here above size of the file is 77536839.

      2. Later a new request is made while package is downloading, but on partial content
        6744  11:15:15.358251 sendto(17<TCP:[127.0.0.1:45856->127.0.0.1:80]>, "GET /minimal-app-os/Packages/g/grafana-9.2.10-17.el9_4.x86_64.rpm HTTP/1.1\r\nHost: 127.0.0.1\r\nRange: bytes=17035264-\r\nUser-Agent: libdnf (Red Hat Enterprise Linux 9.4; generic; Linux.x86_64)\r\nAccept: */*\r\n\r\n", 206, MSG_NOSIGNAL, NULL, 0) = 206 <0.000479>
        

        See above "Range: bytes=17035264-" which tells us it's a partial transfer being requested.

      3. Because of the partial transfer, the MIRROR message gets printed
        6744  11:15:15.602893 write(1</dev/pts/0<char 136:0>>, "[MIRROR] grafana-9.2.10-17.el9_4.x86_64.rpm: Interrupted by header callback: Inconsistent server data, reported file Content-Length: 60501575, repository metadata states file length: 77536839 (please report to repository maintainer)\n", 233) = 233 <0.000037>
        

        Here above, the "Content-Length: 60501575" is exactly the total size minus requested range (77536839 - 17035264).

      This 2nd download messes up with the first download, causing librepo to potentially truncate the file while it's being downloaded, causing the checksum error.
      With the minimal reproducer below no checksum error shows up, but through downloading more packages, it will show up easily.
      Note that there is no issue on Repos end.

      I'm not sure whether the issue is libcurl or librepo, so for now I filed it on librepo.

      What is the impact of this issue to you?

      Breaks repo syncing.

      Please provide the package NVR for which the bug is seen:

      dnf-plugins-core-4.3.0-13.el9.noarch
      libcurl-7.76.1-29.el9_4.1.x86_64
      librepo-1.14.5-2.el9.x86_64

      How reproducible is this bug?:

      Always

      Steps to reproduce

      1. Create a repository through downloading newest packages of AppStream as of Oct 23, 2024
        # reposync --newest-only --disablerepo="*" --enablerepo="rhel-9-for-x86_64-appstream-rpms" --download-metadata --downloadcomps
      2. Export the repository on a local HTTP server (e.g. as /var/www/html/local-app-os)
      3. TEST1 - Create a "minimal" repository to reproduce the MIRROR error message only
        # rm -fr local-app-os; reposync --newest-only --disablerepo="*" --setopt includepkgs="gcc-toolset-12-offload-nvptx,grafana" --repofrompath local-app-os,http://127.0.0.1/local-app-os
      4. TEST2 - Create a "minimal" repository to reproduce the MIRROR error message AND checksum errors
        # rm -fr local-app-os; reposync --newest-only --disablerepo="*" --setopt excludepkgs="[a-fh-zA-Z]*" --repofrompath local-app-os,http://127.0.0.1/local-app-os

      Expected results

      TEST1 and TEST2: no MIRROR errors nor checksum errors.

      Actual results

      1. TEST1
        (1/4): gcc-toolset-12-offload-nvptx-12.2.1-7.7.el9_4.x86_64.rpm                        22 MB/s |  16 MB     00:00    
        (1/4): gcc-toolset-12-offload-nvptx-12.2.1-7.7.el9_4.x86_64.rpm                       0.0  B/s |   0  B     00:00    
        [MIRROR] grafana-9.2.10-17.el9_4.x86_64.rpm: Interrupted by header callback: Inconsistent server data, reported file Content-Length: 60501575, repository metadata states file length: 77536839 (please report to repository maintainer)
        (2/4): grafana-9.2.10-17.el9_4.x86_64.rpm                                             2.5 MB/s |  58 MB     00:23    
        (3/4): grafana-9.2.10-17.el9_4.x86_64.rpm                                             105 MB/s |  74 MB     00:00
        
      2. TEST2
         :
        (447/508): gcc-toolset-12-libgccjit-devel-12.2.1-7.7.el9_4.i686.rpm                   6.8 MB/s |  31 kB     00:00    
        [MIRROR] gcc-toolset-12-libgccjit-12.2.1-7.7.el9_4.x86_64.rpm: Interrupted by header callback: Inconsistent server data, reported file Content-Length: 4172731, repository metadata states file length: 10296251 (please report to repository maintainer)
        [MIRROR] gcc-toolset-12-libgccjit-12.2.1-7.7.el9_4.x86_64.rpm: Downloading successful, but checksum doesn't match. Calculated: e7ec3d70f5c3c8acc70b5c82e95838ae27e5a3723e23b16731756dc93fd6c370(sha256)  Expected: efe0de3f4860f6767ed435e8747ddea7dd141ca4441491fd9216b131e94f45a0(sha256) 
        (448/508): gcc-toolset-12-gcc-gfortran-12.2.1-7.7.el9_4.x86_64.rpm                     56 MB/s |  14 MB     00:00    
         :
        (490/508): gcc-toolset-13-offload-nvptx-13.3.1-2.1.el9_4.x86_64.rpm                    92 MB/s |  18 MB     00:00    
        [MIRROR] grafana-9.2.10-17.el9_4.x86_64.rpm: Interrupted by header callback: Inconsistent server data, reported file Content-Length: 76787271, repository metadata states file length: 77536839 (please report to repository maintainer)
        [FAILED] grafana-9.2.10-17.el9_4.x86_64.rpm: No more mirrors to try - All mirrors were already tried without success 
        (492/508): grafana-selinux-9.2.10-17.el9_4.x86_64.rpm                                 6.0 MB/s |  28 kB     00:00    
         :
        

      Additional informations

      I collected a coredump of reposync when the 2nd download request (the partial one) is submitted, it seems deep into libcurl:

      (gdb) bt
      #0  0x00007f1aaad0f860 in __libc_send (fd=17, buf=0x558cd6050b20, len=206, flags=flags@entry=16384)
          at ../sysdeps/unix/sysv/linux/send.c:28
      #1  0x00007f1aa946f717 in Curl_send_plain (data=0x558cd6060210, num=<optimized out>, mem=<optimized out>, 
          len=<optimized out>, code=0x7ffcdd9fd2f4) at ../../lib/sendf.c:364
      #2  0x00007f1aa946c165 in Curl_write (data=<optimized out>, sockfd=<optimized out>, mem=<optimized out>, 
          len=<optimized out>, written=0x7ffcdd9fd330) at ../../lib/sendf.c:312
      #3  0x00007f1aa944b38b in Curl_buffer_send (in=in@entry=0x7ffcdd9fd400, data=data@entry=0x558cd6060210, 
          bytes_written=bytes_written@entry=0x558cd60615e0, included_body_bytes=included_body_bytes@entry=0, 
          socketindex=socketindex@entry=0) at ../../lib/http.c:1335
      #4  0x00007f1aa9450762 in Curl_http_bodysend (httpreq=HTTPREQ_GET, r=0x7ffcdd9fd400, conn=0x558cd5d3a200, 
          data=0x558cd6060210) at ../../lib/http.c:2688
      #5  Curl_http (data=<optimized out>, done=<optimized out>) at ../../lib/http.c:3231
      #6  0x00007f1aa9467f0e in multi_do (done=0x7ffcdd9fd4c6, data=0x558cd6060210) at ../../lib/multi.c:1398
      #7  multi_runsingle (multi=<optimized out>, nowp=<optimized out>, data=0x558cd6060210) at ../../lib/multi.c:1890
      #8  0x00007f1aa946a1be in curl_multi_perform (multi=multi@entry=0x558cd6400ed0, 
          running_handles=running_handles@entry=0x7ffcdd9fd700) at ../../lib/multi.c:2403
      #9  0x00007f1aaa24fc6e in lr_perform (err=0x7ffcdd9fd708, dd=0x7ffcdd9fd750)
          at /usr/src/debug/librepo-1.14.5-2.el9.x86_64/librepo/downloader.c:2568
      #10 lr_download (targets=<optimized out>, failfast=<optimized out>, err=0x7ffcdd9fd9e0)
          at /usr/src/debug/librepo-1.14.5-2.el9.x86_64/librepo/downloader.c:2743
      #11 0x00007f1aaa257af8 in lr_download_packages (targets=<optimized out>, flags=0, err=0x7ffcdd9fd9e0)
          at /usr/src/debug/librepo-1.14.5-2.el9.x86_64/librepo/package_downloader.c:422
      #12 0x00007f1aa9eefdfa in libdnf::PackageTarget::downloadPackages (
          targets=std::vector of length 4, capacity 4 = {...}, failFast=<optimized out>)
          at /usr/src/debug/libdnf-0.69.0-8.el9_4.1.x86_64/libdnf/repo/Repo.cpp:1863
       :
      

      You may collect your own coredump through using the systemtap script attached, then execute reposync command from another shell:

      # stap -g -G syscall_string_trunc=200 -v ./take_core_on_partial_download.stp
      

      I'm attaching an strace showing the "MIRROR" error message from grafana package download (reposync.mirror_message.strace.gz).

              mblaha@redhat.com Marek Blaha
              rhn-support-rmetrich Renaud Métrich
              packaging-team-maint packaging-team-maint
              Eva Mrakova Eva Mrakova
              Votes:
              1 Vote for this issue
              Watchers:
              7 Start watching this issue

                Created:
                Updated: