Bug 1222338 - [MEDIANET] curl 8.7.1 and libzypp cause curl error 92 on fetching updates
Summary: [MEDIANET] curl 8.7.1 and libzypp cause curl error 92 on fetching updates
Status: NEW
Alias: None
Product: openSUSE Tumbleweed
Classification: openSUSE
Component: Upgrade Problems (show other bugs)
Version: Current
Hardware: Other Other
: P5 - None : Normal (vote)
Target Milestone: ---
Assignee: David Anes
QA Contact: Jiri Srain
URL:
Whiteboard:
Keywords:
Depends on:
Blocks:
 
Reported: 2024-04-04 17:53 UTC by Dirk Mueller
Modified: 2024-07-02 08:29 UTC (History)
7 users (show)

See Also:
Found By: ---
Services Priority:
Business Priority:
Blocker: ---
Marketing QA Status: ---
IT Deployment: ---


Attachments
zypper.log (104.00 KB, text/plain)
2024-04-05 18:55 UTC, Dirk Mueller
Details

Note You need to log in before you can comment on or make changes to this bug.
Description Dirk Mueller 2024-04-04 17:53:24 UTC
I can no longer refresh some 3rd party repositories after the curl 8.7.1 upgrade in tumbleweed. curl 8.6.0 works fine. 

the errors point out a http/2 protocol error. here's the snippet from the log: 

2024-04-04 19:43:42 <1> magnolia(30993) [zypp-curl++] curlhelper.cc(log_curl):119 0x564be956d140 * Found bundle for host: 0x564be94f55c0 [can multiplex]
2024-04-04 19:43:42 <1> magnolia(30993) [zypp-curl++] curlhelper.cc(log_curl):119 0x564be956d140 * Re-using existing connection with host dl.google.com
2024-04-04 19:43:42 <1> magnolia(30993) [zypp-curl++] curlhelper.cc(log_curl):119 0x564be956d140 * [HTTP/2] [17] OPENED stream for https://dl.google.com/linux/chrome/rpm/stable/x86_64/repodata/repomd.xml
2024-04-04 19:43:42 <1> magnolia(30993) [zypp-curl++] curlhelper.cc(log_curl):119 0x564be956d140 * [HTTP/2] [17] [:method: GET]
2024-04-04 19:43:42 <1> magnolia(30993) [zypp-curl++] curlhelper.cc(log_curl):119 0x564be956d140 * [HTTP/2] [17] [:scheme: https]
2024-04-04 19:43:42 <1> magnolia(30993) [zypp-curl++] curlhelper.cc(log_curl):119 0x564be956d140 * [HTTP/2] [17] [:authority: dl.google.com]
2024-04-04 19:43:42 <1> magnolia(30993) [zypp-curl++] curlhelper.cc(log_curl):119 0x564be956d140 * [HTTP/2] [17] [:path: /linux/chrome/rpm/stable/x86_64/repodata/repomd.xml]
2024-04-04 19:43:42 <1> magnolia(30993) [zypp-curl++] curlhelper.cc(log_curl):119 0x564be956d140 * [HTTP/2] [17] [user-agent: ZYpp 17.31.15 (curl 8.7.1)]
2024-04-04 19:43:42 <1> magnolia(30993) [zypp-curl++] curlhelper.cc(log_curl):119 0x564be956d140 * [HTTP/2] [17] [accept: */*, application/x-zsync, application/metalink+xml, application/metalink4+xml]
2024-04-04 19:43:42 <1> magnolia(30993) [zypp-curl++] curlhelper.cc(log_curl):119 0x564be956d140 > GET /linux/chrome/rpm/stable/x86_64/repodata/repomd.xml HTTP/2
2024-04-04 19:43:42 <1> magnolia(30993) [zypp-curl++] curlhelper.cc(log_curl):119 0x564be956d140 > Host: dl.google.com
2024-04-04 19:43:42 <1> magnolia(30993) [zypp-curl++] curlhelper.cc(log_curl):119 0x564be956d140 > User-Agent: ZYpp 17.31.15 (curl 8.7.1)
2024-04-04 19:43:42 <1> magnolia(30993) [zypp-curl++] curlhelper.cc(log_curl):119 0x564be956d140 > Accept: */*, application/x-zsync, application/metalink+xml, application/metalink4+xml
2024-04-04 19:43:42 <1> magnolia(30993) [zypp-curl++] curlhelper.cc(log_curl):119 0x564be956d140 > 
2024-04-04 19:43:42 <1> magnolia(30993) [zypp-curl++] curlhelper.cc(log_curl):119 0x564be956d140 * Request completely sent off
2024-04-04 19:43:42 <1> magnolia(30993) [zypp-curl++] curlhelper.cc(log_curl):119 0x564be956d140 < HTTP/2 200 
2024-04-04 19:43:42 <1> magnolia(30993) [zypp-curl++] curlhelper.cc(log_curl):119 0x564be956d140 < content-length: 1356
2024-04-04 19:43:42 <1> magnolia(30993) [ZYPP_MEDIA_CURL++] request.cc(headerfunction):653 0x564be956d140 Got Content-Length Header: 1356
2024-04-04 19:43:42 <1> magnolia(30993) [zypp-curl++] curlhelper.cc(log_curl):119 0x564be956d140 < content-security-policy: default-src 'none'
2024-04-04 19:43:42 <1> magnolia(30993) [zypp-curl++] curlhelper.cc(log_curl):119 0x564be956d140 < server: downloads
2024-04-04 19:43:42 <1> magnolia(30993) [zypp-curl++] curlhelper.cc(log_curl):119 0x564be956d140 < x-content-type-options: nosniff
2024-04-04 19:43:42 <1> magnolia(30993) [zypp-curl++] curlhelper.cc(log_curl):119 0x564be956d140 < x-frame-options: SAMEORIGIN
2024-04-04 19:43:42 <1> magnolia(30993) [zypp-curl++] curlhelper.cc(log_curl):119 0x564be956d140 < x-xss-protection: 0
2024-04-04 19:43:42 <1> magnolia(30993) [zypp-curl++] curlhelper.cc(log_curl):119 0x564be956d140 < cache-control: public,max-age=0
2024-04-04 19:43:42 <1> magnolia(30993) [zypp-curl++] curlhelper.cc(log_curl):119 0x564be956d140 < last-modified: Wed, 03 Apr 2024 16:46:55 GMT
2024-04-04 19:43:42 <1> magnolia(30993) [zypp-curl++] curlhelper.cc(log_curl):119 0x564be956d140 < date: Thu, 04 Apr 2024 17:44:16 GMT
2024-04-04 19:43:42 <1> magnolia(30993) [zypp-curl++] curlhelper.cc(log_curl):119 0x564be956d140 < etag: "26973aa"
2024-04-04 19:43:42 <1> magnolia(30993) [zypp-curl++] curlhelper.cc(log_curl):119 0x564be956d140 * Invalid HTTP header field was received: frame type: 1, stream: 17, name: [content-length], value: [1449]
2024-04-04 19:43:42 <1> magnolia(30993) [zypp-curl++] curlhelper.cc(log_curl):119 0x564be956d140 * HTTP/2 stream 17 was not closed cleanly: PROTOCOL_ERROR (err 1)
2024-04-04 19:43:42 <1> magnolia(30993) [zypp-curl++] curlhelper.cc(log_curl):119 0x564be956d140 * Connection #0 to host dl.google.com left intact
2024-04-04 19:43:42 <1> magnolia(30993) [ZYPP_MEDIA_CURL] basicdownloader_p.cc(onRequestFinished):201 0x564be956d140 Downloading on https://dl.google.com/linux/chrome/rpm/stable/x86_64/repodata/repomd.xml failed with error Server returned a HTTP/2 strea
m error. Curl error (92) Invalid HTTP header field was received: frame type: 1, stream: 17, name: [content-length], value: [1449]
2024-04-04 19:43:42 <1> magnolia(30993) [zypp-core] PathInfo.cc(unlink):705 unlink /var/tmp/AP_0xzr4SK4/repodata/repomd.xml
2024-04-04 19:43:42 <1> magnolia(30993) [ZYPP_MEDIA_CURL] metalinkinfo_p.cc(transitionToFinished):36 Downloading on https://dl.google.com/linux/chrome/rpm/stable/x86_64/repodata/repomd.xml transition to final state. 
2024-04-04 19:43:42 <1> magnolia(30993) [ZYPP_MEDIA_CURL] final_p.cc(FinishedState):20 About to enter FinishedState for url https://dl.google.com/linux/chrome/rpm/stable/x86_64/repodata/repomd.xml
2024-04-04 19:43:42 <1> magnolia(30993) [ZYPP_MEDIA_CURL] initial_p.cc(enter):20 Entering initial state
2024-04-04 19:43:42 <1> magnolia(30993) [ZYPP_MEDIA_CURL] initial_p.cc(initiate):44 No zchunk data available but metalink requested, going to download metalink directly.
2024-04-04 19:43:42 <1> magnolia(30993) [ZYPP_MEDIA_CURL] metalinkinfo_p.cc(DlMetaLinkInfoState):25 Downloading metalink/zsync on https://dl.google.com/linux/chrome/rpm/stable/x86_64/repodata/repomd.xml
2024-04-04 19:43:42 <1> magnolia(30993) [ZYPP_MEDIA_CURL] initial_p.cc(exit):22 Leaving initial state
2024-04-04 19:43:42 <1> magnolia(30993) [ZYPP_MEDIA_CURL] metalinkinfo_p.cc(initializeRequest):51 Requesting Metadata info from server!
2024-04-04 19:43:42 <1> magnolia(30993) [zypp-core] PathInfo.cc(chmod):1099 assert_file_mode 00600 /var/lib/YaST2/cookieschmod /var/lib/YaST2/cookies 00600
2024-04-04 19:43:42 <1> magnolia(30993) [ZYPP_MEDIA_CURL++] request.cc(aboutToStart):469 0x564be956d140 Setting activity timeout to: 180
2024-04-04 19:43:42 <1> magnolia(30993) [zypp-curl++] curlhelper.cc(log_curl):119 0x564be956d140 * Found bundle for host: 0x564be94f55c0 [can multiplex]
2024-04-04 19:43:42 <1> magnolia(30993) [zypp-curl++] curlhelper.cc(log_curl):119 0x564be956d140 * Re-using existing connection with host dl.google.com
2024-04-04 19:43:42 <1> magnolia(30993) [zypp-curl++] curlhelper.cc(log_curl):119 0x564be956d140 * [HTTP/2] [19] OPENED stream for https://dl.google.com/linux/chrome/rpm/stable/x86_64/repodata/repomd.xml
2024-04-04 19:43:42 <1> magnolia(30993) [zypp-curl++] curlhelper.cc(log_curl):119 0x564be956d140 * [HTTP/2] [19] [:method: GET]
2024-04-04 19:43:42 <1> magnolia(30993) [zypp-curl++] curlhelper.cc(log_curl):119 0x564be956d140 * [HTTP/2] [19] [:scheme: https]
2024-04-04 19:43:42 <1> magnolia(30993) [zypp-curl++] curlhelper.cc(log_curl):119 0x564be956d140 * [HTTP/2] [19] [:authority: dl.google.com]
2024-04-04 19:43:42 <1> magnolia(30993) [zypp-curl++] curlhelper.cc(log_curl):119 0x564be956d140 * [HTTP/2] [19] [:path: /linux/chrome/rpm/stable/x86_64/repodata/repomd.xml]
2024-04-04 19:43:42 <1> magnolia(30993) [zypp-curl++] curlhelper.cc(log_curl):119 0x564be956d140 * [HTTP/2] [19] [user-agent: ZYpp 17.31.15 (curl 8.7.1)]
2024-04-04 19:43:42 <1> magnolia(30993) [zypp-curl++] curlhelper.cc(log_curl):119 0x564be956d140 * [HTTP/2] [19] [accept: */*, application/x-zsync, application/metalink+xml, application/metalink4+xml]
2024-04-04 19:43:42 <1> magnolia(30993) [zypp-curl++] curlhelper.cc(log_curl):119 0x564be956d140 > GET /linux/chrome/rpm/stable/x86_64/repodata/repomd.xml HTTP/2
2024-04-04 19:43:42 <1> magnolia(30993) [zypp-curl++] curlhelper.cc(log_curl):119 0x564be956d140 > Host: dl.google.com
2024-04-04 19:43:42 <1> magnolia(30993) [zypp-curl++] curlhelper.cc(log_curl):119 0x564be956d140 > User-Agent: ZYpp 17.31.15 (curl 8.7.1)
2024-04-04 19:43:42 <1> magnolia(30993) [zypp-curl++] curlhelper.cc(log_curl):119 0x564be956d140 > Accept: */*, application/x-zsync, application/metalink+xml, application/metalink4+xml
2024-04-04 19:43:42 <1> magnolia(30993) [zypp-curl++] curlhelper.cc(log_curl):119 0x564be956d140 > 
2024-04-04 19:43:42 <1> magnolia(30993) [zypp-curl++] curlhelper.cc(log_curl):119 0x564be956d140 * Request completely sent off
2024-04-04 19:43:42 <1> magnolia(30993) [zypp-curl++] curlhelper.cc(log_curl):119 0x564be956d140 < HTTP/2 200 
2024-04-04 19:43:42 <1> magnolia(30993) [zypp-curl++] curlhelper.cc(log_curl):119 0x564be956d140 < content-length: 1356
2024-04-04 19:43:42 <1> magnolia(30993) [ZYPP_MEDIA_CURL++] request.cc(headerfunction):653 0x564be956d140 Got Content-Length Header: 1356
2024-04-04 19:43:42 <1> magnolia(30993) [zypp-curl++] curlhelper.cc(log_curl):119 0x564be956d140 < content-security-policy: default-src 'none'
2024-04-04 19:43:42 <1> magnolia(30993) [zypp-curl++] curlhelper.cc(log_curl):119 0x564be956d140 < server: downloads
2024-04-04 19:43:42 <1> magnolia(30993) [zypp-curl++] curlhelper.cc(log_curl):119 0x564be956d140 < x-content-type-options: nosniff
2024-04-04 19:43:42 <1> magnolia(30993) [zypp-curl++] curlhelper.cc(log_curl):119 0x564be956d140 < x-frame-options: SAMEORIGIN
2024-04-04 19:43:42 <1> magnolia(30993) [zypp-curl++] curlhelper.cc(log_curl):119 0x564be956d140 < x-xss-protection: 0
2024-04-04 19:43:42 <1> magnolia(30993) [zypp-curl++] curlhelper.cc(log_curl):119 0x564be956d140 < cache-control: public,max-age=0
2024-04-04 19:43:42 <1> magnolia(30993) [zypp-curl++] curlhelper.cc(log_curl):119 0x564be956d140 < last-modified: Wed, 03 Apr 2024 16:46:55 GMT
2024-04-04 19:43:42 <1> magnolia(30993) [zypp-curl++] curlhelper.cc(log_curl):119 0x564be956d140 < date: Thu, 04 Apr 2024 17:44:16 GMT
2024-04-04 19:43:42 <1> magnolia(30993) [zypp-curl++] curlhelper.cc(log_curl):119 0x564be956d140 < etag: "26973aa"
2024-04-04 19:43:42 <1> magnolia(30993) [zypp-curl++] curlhelper.cc(log_curl):119 0x564be956d140 * Invalid HTTP header field was received: frame type: 1, stream: 19, name: [content-length], value: [1449]
2024-04-04 19:43:42 <1> magnolia(30993) [zypp-curl++] curlhelper.cc(log_curl):119 0x564be956d140 * HTTP/2 stream 19 was not closed cleanly: PROTOCOL_ERROR (err 1)
2024-04-04 19:43:42 <1> magnolia(30993) [zypp-curl++] curlhelper.cc(log_curl):119 0x564be956d140 * Connection #0 to host dl.google.com left intact
2024-04-04 19:43:42 <1> magnolia(30993) [ZYPP_MEDIA_CURL] basicdownloader_p.cc(onRequestFinished):201 0x564be956d140 Downloading on https://dl.google.com/linux/chrome/rpm/stable/x86_64/repodata/repomd.xml failed with error Server returned a HTTP/2 stream error. Curl error (92) Invalid HTTP header field was received: frame type: 1, stream: 19, name: [content-length], value: [1449]
2024-04-04 19:43:42 <1> magnolia(30993) [zypp-core] PathInfo.cc(unlink):705 unlink /var/tmp/AP_0xzr4SK4/repodata/repomd.xml
Comment 1 Dirk Mueller 2024-04-04 17:57:38 UTC
repository is

[google-chrome]
enabled=1
autorefresh=1
baseurl=https://dl.google.com/linux/chrome/rpm/stable/x86_64
gpgcheck=1


but it actually happens with almost all repositories
Comment 2 Georg Pfuetzenreuter 2024-04-04 22:59:03 UTC
I just tried this out of curiosity, and it seems to work:

```
$ podman run --rm --pull=always -it opensuse/tumbleweed
7fe8f2c44dad:/ # tee /etc/zypp/repos.d/chrome.repo <<EOF
> [google-chrome]
> enabled=1
> autorefresh=1
> baseurl=https://dl.google.com/linux/chrome/rpm/stable/x86_64
> gpgcheck=1
> EOF
...
7fe8f2c44dad:/ # zypper ref
Looking for gpg key ID 9B30ACF2 in cache /var/cache/zypp/pubkeys.
Repository google-chrome does not define additional 'gpgkey=' URLs.
Warning: File 'repomd.xml' from repository 'google-chrome' is signed with an unknown key 'E88979FB9B30ACF2'.

    Note: Signing data enables the recipient to verify that no modifications occurred after the data
    were signed. Accepting data with no, wrong or unknown signature can lead to a corrupted system
    and in extreme cases even to a system compromise.

    Note: File 'repomd.xml' is the repositories master index file. It ensures the integrity of the
    whole repo.

    Warning: We can't verify that no one meddled with this file, so it might not be trustworthy
    anymore! You should not continue unless you know it's safe.

File 'repomd.xml' from repository 'google-chrome' is signed with an unknown key 'E88979FB9B30ACF2'. Continue? [yes/no] (no): yes
Retrieving repository 'google-chrome' metadata ....................[done]
Building repository 'google-chrome' cache .........................[done]
Retrieving repository 'openSUSE-Tumbleweed-Non-Oss' metadata ......[done]
Building repository 'openSUSE-Tumbleweed-Non-Oss' cache ...........[done]
Retrieving repository 'Open H.264 Codec (openSUSE Tumbleweed)' metadata [done]
Building repository 'Open H.264 Codec (openSUSE Tumbleweed)' cache [done]
Retrieving repository 'openSUSE-Tumbleweed-Oss' metadata ..........[done]
Building repository 'openSUSE-Tumbleweed-Oss' cache ...............[done]
Retrieving repository 'openSUSE-Tumbleweed-Update' metadata .......[done]
Building repository 'openSUSE-Tumbleweed-Update' cache ............[done]
All repositories have been refreshed.

7fe8f2c44dad:/ # rpm -q curl
curl-8.7.1-1.1.x86_64
7fe8f2c44dad:/ # rpm -q libzypp
libzypp-17.32.2-1.1.x86_64
```

No occurrences of the mentioned error in zypper.log either.
Comment 3 Michael Andres 2024-04-05 06:03:46 UTC
@Dirk, does ZYPP_MEDIA_CURL_DEBUG=2 reveal more info?

Error 92 was e.g. due to header fields ending with a space. You don't happen to use an old libzypp version?
Comment 4 Michael Andres 2024-04-05 08:23:04 UTC
I can't spot any issue on TW for me with
> # rpm -q libzypp curl
> libzypp-17.32.2-1.1.x86_64
> curl-8.7.1-1.1.x86_64
Comment 5 Dirk Mueller 2024-04-05 18:00:07 UTC
> Error 92 was e.g. due to header fields ending with a space. You don't happen
> to use an old libzypp version?

I used 17.31.15. now that I circumvented this http/2 problem I'm on 17.31.2 and will revalidate.
Comment 6 Dirk Mueller 2024-04-05 18:55:18 UTC
Created attachment 874095 [details]
zypper.log
Comment 7 Dirk Mueller 2024-04-05 18:56:55 UTC
I've attached the log with ZYPP_MEDIA_CURL_DEBUG=2 set. I can reproduce inside a tumbleweed container as well, the missing piece was 

techpreview.ZYPP_MEDIANETWORK=1

in /etc/zypp/zypp.conf

turning off medianetwork as well as downgrading curl avoids the issue.
Comment 8 Michael Pujos 2024-04-08 12:16:28 UTC
With curl 8.7.1, downloading debuggerd info in gdb systematically fails with

Download failed: Connection reset by peer.  Continuing without separate debug info for /lib64/libudev.so.1.


It works with 8.6.0.
Comment 9 Michael Andres 2024-04-09 16:49:54 UTC
> [zypper.log from c#6]
> /linux/chrome/rpm/stable/x86_64/repodata/repomd.xml
> < content-length: 1356
> 
> /linux/chrome/rpm/stable/x86_64/media.1/media
> < content-length: 1449
> * The requested URL returned error: 404
> * process_pending_input: nghttp2_session_mem_recv() returned -902:The user callback function failed
> 
> /linux/chrome/rpm/stable/x86_64/repodata/repomd.xml.asc
> < content-length: 1356
> * Invalid HTTP header field was received: frame type: 1, stream: 5, name: [content-length], value: [833]
> * HTTP/2 stream 5 was not closed cleanly: PROTOCOL_ERROR (err 1)

> [in my TW container]
> /linux/chrome/rpm/stable/x86_64/repodata/repomd.xml
> < content-length: 1356
> 
> /linux/chrome/rpm/stable/x86_64/media.1/media
> < content-length: 1449
> * The requested URL returned error: 404
> * process_pending_input: nghttp2_session_mem_recv() returned -902:The user callback function failed
> 
> /linux/chrome/rpm/stable/x86_64/repodata/repomd.xml.asc
> < content-length: 1356
> * Invalid HTTP header field was received: frame type: 1, stream: 5, name: [content-length], value: [833]
> * HTTP/2 stream 5 was not closed cleanly: PROTOCOL_ERROR (err 1)

Looks like with the nghttp2_session_mem_recv error the content-length header are messed up. 833 would be the correct size for repomd.xml.asc. Looks as if we were reading old data from previous streams.
Comment 10 David Anes 2024-07-01 14:09:39 UTC
I'm not sure how to debug this. Is this a curl issue or a server issue?
Comment 11 Dirk Mueller 2024-07-02 08:29:08 UTC
It's a client side issue, either in libcurl or in libzypp