Using download.fedoraproject.org to add images to vagrant doesn't work anymore:
download.fedoraproject.org
$ vagrant box add f37-test https://download.fedoraproject.org/pub/fedora/linux/releases/37/Cloud/x86_64/images/Fedora-Cloud-Base-Vagrant-37-1.7.x86_64.vagrant-libvirt.box There was an error while downloading the metadata for this box. The error message is shown below: HTTP/2 stream 0 was not closed cleanly: PROTOCOL_ERROR (err 1)
I think there is some incompatibility between vagrant and the redirection applied by download.fedoraproject.org because using a real URL works:
$ vagrant box add f37-test https://fedora.ip-connect.info/linux/releases/37/Cloud/x86_64/images/Fedora-Cloud-Base-Vagrant-37-1.7.x86_64.vagrant-libvirt.box ==> box: Box file was not detected as metadata. Adding it directly... ==> box: Adding box 'f37-test' (v0) for provider: box: Downloading: https://fedora.ip-connect.info/linux/releases/37/Cloud/x86_64/images/Fedora-Cloud-Base-Vagrant-37-1.7.x86_64.vagrant-libvirt.box ==> box: Successfully added box 'f37-test' (v0) for 'libvirt'!
I suppose the redirection is made by mirrormanager, am I right? I've opened a ticket upstream, but I'm not sure if this is something wrong vagrant side, mirrormanager side or infrastructure side as when I run the command with --debug I think I'm seeing certificates errors:
--debug
... INFO downloader: HEAD: https://download.fedoraproject.org/pub/fedora/linux/releases/37/Cloud/x86_64/images/Fedora-Cloud-Base-Vagrant-37-1.7.x86_64.vagrant-libvirt.box INFO subprocess: Starting process: ["/usr/bin/curl", "-q", "-I", "--fail", "--location", "--max-redirs", "10", "--verbose", "--user-agent", "Vagrant/2.2.19 (+https://www.vagrantup.com; ruby3.1.3) ", "--continue-at", "-", "-H", "Accept: application/json", "https://download.fedoraproject.org/pub/fedora/linux/releases/37/Cloud/x86_64/images/Fedora-Cloud-Base-Vagrant-37-1.7.x86_64.vagrant-libvirt.box"] INFO subprocess: Command not in installer, restoring original environment... DEBUG subprocess: Selecting on IO DEBUG subprocess: stderr: % Total % Received % Xferd Average Speed Time Time Time Current Dload Upload Total Spent Left Speed 0 0 0 0 0 0 0 0 --:--:-- --:--:-- --:--:-- 0 DEBUG subprocess: stderr: * Trying 185.141.165.254:443... DEBUG subprocess: stderr: * Connected to download.fedoraproject.org (185.141.165.254) port 443 (#0) DEBUG subprocess: stderr: * ALPN: offers h2 * ALPN: offers http/1.1 DEBUG subprocess: stderr: * CAfile: /etc/pki/tls/cert.pem * CApath: none DEBUG subprocess: stderr: * TLSv1.0 (OUT), TLS header, Certificate Status (22): } [5 bytes data] * TLSv1.3 (OUT), TLS handshake, Client hello (1): } [512 bytes data] DEBUG subprocess: stderr: * TLSv1.2 (IN), TLS header, Certificate Status (22): { [5 bytes data] * TLSv1.3 (IN), TLS handshake, Server hello (2): { [122 bytes data] DEBUG subprocess: stderr: * TLSv1.2 (IN), TLS header, Finished (20): { [5 bytes data] * TLSv1.2 (IN), TLS header, Supplemental data (23): { [5 bytes data] * TLSv1.3 (IN), TLS handshake, Encrypted Extensions (8): { [19 bytes data] DEBUG subprocess: stderr: * TLSv1.2 (IN), TLS header, Supplemental data (23): { [5 bytes data] DEBUG subprocess: stderr: * TLSv1.3 (IN), TLS handshake, Certificate (11): { [2788 bytes data] DEBUG subprocess: stderr: * TLSv1.2 (IN), TLS header, Supplemental data (23): { [5 bytes data] * TLSv1.3 (IN), TLS handshake, CERT verify (15): { [520 bytes data] DEBUG subprocess: stderr: * TLSv1.2 (IN), TLS header, Supplemental data (23): { [5 bytes data] * TLSv1.3 (IN), TLS handshake, Finished (20): { [52 bytes data] DEBUG subprocess: stderr: * TLSv1.2 (OUT), TLS header, Finished (20): } [5 bytes data] * TLSv1.3 (OUT), TLS change cipher, Change cipher spec (1): } [1 bytes data] * TLSv1.2 (OUT), TLS header, Supplemental data (23): } [5 bytes data] * TLSv1.3 (OUT), TLS handshake, Finished (20): } [52 bytes data] DEBUG subprocess: stderr: * SSL connection using TLSv1.3 / TLS_AES_256_GCM_SHA384 * ALPN: server accepted h2 * Server certificate: * subject: C=US; ST=North Carolina; L=Raleigh; O=Red Hat, Inc.; CN=*.fedoraproject.org * start date: Jan 16 00:00:00 2023 GMT * expire date: Jan 16 23:59:59 2024 GMT * subjectAltName: host "download.fedoraproject.org" matched cert's "*.fedoraproject.org" DEBUG subprocess: stderr: * issuer: C=US; O=DigiCert Inc; CN=DigiCert Global G3 TLS ECC SHA384 2020 CA1 * SSL certificate verify ok. * Using HTTP2, server supports multiplexing * Copying HTTP/2 data in stream buffer to connection buffer after upgrade: len=0 * TLSv1.2 (OUT), TLS header, Supplemental data (23): } [5 bytes data] * TLSv1.2 (OUT), TLS header, Supplemental data (23): } [5 bytes data] DEBUG subprocess: stderr: * TLSv1.2 (OUT), TLS header, Supplemental data (23): } [5 bytes data] * h2h3 [:method: HEAD] * h2h3 [:path: /pub/fedora/linux/releases/37/Cloud/x86_64/images/Fedora-Cloud-Base-Vagrant-37-1.7.x86_64.vagrant-libvirt.box] * h2h3 [:scheme: https] * h2h3 [:authority: download.fedoraproject.org] * h2h3 [user-agent: Vagrant/2.2.19 (+https://www.vagrantup.com; ruby3.1.3) ] * h2h3 [accept: application/json] * Using Stream ID: 1 (easy handle 0x564f5be26460) * TLSv1.2 (OUT), TLS header, Supplemental data (23): } [5 bytes data] DEBUG subprocess: stderr: > HEAD /pub/fedora/linux/releases/37/Cloud/x86_64/images/Fedora-Cloud-Base-Vagrant-37-1.7.x86_64.vagrant-libvirt.box HTTP/2 > Host: download.fedoraproject.org > user-agent: Vagrant/2.2.19 (+https://www.vagrantup.com; ruby3.1.3) > accept: application/json > DEBUG subprocess: stderr: * TLSv1.2 (IN), TLS header, Supplemental data (23): { [5 bytes data] DEBUG subprocess: stderr: * TLSv1.3 (IN), TLS handshake, Newsession Ticket (4): { [297 bytes data] * TLSv1.2 (IN), TLS header, Supplemental data (23): { [5 bytes data] * TLSv1.3 (IN), TLS handshake, Newsession Ticket (4): { [297 bytes data] * old SSL session ID is stale, removing * TLSv1.2 (IN), TLS header, Supplemental data (23): { [5 bytes data] DEBUG subprocess: stderr: * TLSv1.2 (OUT), TLS header, Supplemental data (23): } [5 bytes data] * TLSv1.2 (IN), TLS header, Supplemental data (23): { [5 bytes data] * TLSv1.2 (IN), TLS header, Supplemental data (23): { [5 bytes data] * HTTP/2 stream 0 was not closed cleanly: PROTOCOL_ERROR (err 1) 0 0 0 0 0 0 0 0 --:--:-- --:--:-- --:--:-- 0 DEBUG subprocess: stderr: * Connection #0 to host download.fedoraproject.org left intact curl: (92) HTTP/2 stream 0 was not closed cleanly: PROTOCOL_ERROR (err 1) DEBUG subprocess: Waiting for process to exit. Remaining to timeout: 31999 DEBUG subprocess: Exit status: 92 WARN downloader: Downloader exit code: 92 ERROR warden: Error occurred: There was an error while downloading the metadata for this box. The error message is shown below: HTTP/2 stream 0 was not closed cleanly: PROTOCOL_ERROR (err 1) INFO warden: Beginning recovery process... INFO warden: Recovery complete. INFO environment: Running hook: environment_unload INFO runner: Running action: environment_unload #<Vagrant::Action::Builder:0x00007f6a79edede8> ERROR vagrant: Vagrant experienced an error! Details: ERROR vagrant: #<Vagrant::Errors::BoxMetadataDownloadError: There was an error while downloading the metadata for this box. The error message is shown below: HTTP/2 stream 0 was not closed cleanly: PROTOCOL_ERROR (err 1)> ERROR vagrant: There was an error while downloading the metadata for this box. The error message is shown below: HTTP/2 stream 0 was not closed cleanly: PROTOCOL_ERROR (err 1)
Can you check that output and look if it's a certificate problem?
There's nothing wrong with the cert I don't think, this smells like a http/2 problem. ;(
What versions of vagrant/curl do you have? Is there some way to tell vagrant to use http/1.1 instead of /2 ? if so, that would be a good test...
cc: @kdudka
Oh, and... did it used to work? what changed since then? updates or upgrades on your client end?
I'm not sure about when it stopped working, I've reported the upstream ticket in December when I first noticed the problem while trying to update a vm to f37 base image. But maybe it was already broken before, it was a while I didn't download a base image.
FWIW using a direct link (not passing through download.fedoraproject.org redirection) uses HTTP/2 and works.
what does running the command as seen in the debug but by hand do? [Pieced together from :
"/usr/bin/curl", "-q", "-I", "--fail", "--location", "--max-redirs", "10", "--verbose", "--user-agent", "Mattia-testing ", "--continue-at", "-", "-H", "Accept: application/json", "https://download.fedoraproject.org/pub/fedora/linux/releases/37/Cloud/x86_64/images/Fedora-Cloud-Base-Vagrant-37-1.7.x86_64.vagrant-libvirt.box"
Metadata Update from @phsmoura: - Issue priority set to: Waiting on Assignee (was: Needs Review) - Issue tagged with: low-gain, low-trouble, ops
what does running the command as seen in the debug but by hand do? [Pieced together from : "/usr/bin/curl", "-q", "-I", "--fail", "--location", "--max-redirs", "10", "--verbose", "--user-agent", "Mattia-testing ", "--continue-at", "-", "-H", "Accept: application/json", "https://download.fedoraproject.org/pub/fedora/linux/releases/37/Cloud/x86_64/images/Fedora-Cloud-Base-Vagrant-37-1.7.x86_64.vagrant-libvirt.box"
$ /usr/bin/curl -q -I --fail --location --max-redirs 10 --verbose --user-agent "Vagrant/2.2.19 (+https://www.vagrantup.com; ruby3.1.3)" --continue-at - -H "Accept: application/json" https://download.fedoraproject.org/pub/fedora/linux/releases/37/Cloud/x86_64/images/Fedora-Cloud-Base-Vagrant-37-1.7.x86_64.vagrant-libvirt.box * Trying 38.145.60.20:443... * Connected to download.fedoraproject.org (38.145.60.20) port 443 (#0) * ALPN: offers h2 * ALPN: offers http/1.1 * CAfile: /etc/pki/tls/certs/ca-bundle.crt * CApath: none * TLSv1.0 (OUT), TLS header, Certificate Status (22): * TLSv1.3 (OUT), TLS handshake, Client hello (1): * TLSv1.2 (IN), TLS header, Certificate Status (22): * TLSv1.3 (IN), TLS handshake, Server hello (2): * TLSv1.2 (IN), TLS header, Finished (20): * TLSv1.2 (IN), TLS header, Supplemental data (23): * TLSv1.3 (IN), TLS handshake, Encrypted Extensions (8): * TLSv1.2 (IN), TLS header, Supplemental data (23): * TLSv1.3 (IN), TLS handshake, Certificate (11): * TLSv1.2 (IN), TLS header, Supplemental data (23): * TLSv1.3 (IN), TLS handshake, CERT verify (15): * TLSv1.2 (IN), TLS header, Supplemental data (23): * TLSv1.3 (IN), TLS handshake, Finished (20): * TLSv1.2 (OUT), TLS header, Finished (20): * TLSv1.3 (OUT), TLS change cipher, Change cipher spec (1): * TLSv1.2 (OUT), TLS header, Supplemental data (23): * TLSv1.3 (OUT), TLS handshake, Finished (20): * SSL connection using TLSv1.3 / TLS_AES_256_GCM_SHA384 * ALPN: server accepted h2 * Server certificate: * subject: C=US; ST=North Carolina; L=Raleigh; O=Red Hat, Inc.; CN=*.fedoraproject.org * start date: Jan 16 00:00:00 2023 GMT * expire date: Jan 16 23:59:59 2024 GMT * subjectAltName: host "download.fedoraproject.org" matched cert's "*.fedoraproject.org" * issuer: C=US; O=DigiCert Inc; CN=DigiCert Global G3 TLS ECC SHA384 2020 CA1 * SSL certificate verify ok. * Using HTTP2, server supports multiplexing * Copying HTTP/2 data in stream buffer to connection buffer after upgrade: len=0 * TLSv1.2 (OUT), TLS header, Supplemental data (23): * TLSv1.2 (OUT), TLS header, Supplemental data (23): * TLSv1.2 (OUT), TLS header, Supplemental data (23): * h2h3 [:method: HEAD] * h2h3 [:path: /pub/fedora/linux/releases/37/Cloud/x86_64/images/Fedora-Cloud-Base-Vagrant-37-1.7.x86_64.vagrant-libvirt.box] * h2h3 [:scheme: https] * h2h3 [:authority: download.fedoraproject.org] * h2h3 [user-agent: Vagrant/2.2.19 (+https://www.vagrantup.com; ruby3.1.3)] * h2h3 [accept: application/json] * Using Stream ID: 1 (easy handle 0x55d02a59e460) * TLSv1.2 (OUT), TLS header, Supplemental data (23): > HEAD /pub/fedora/linux/releases/37/Cloud/x86_64/images/Fedora-Cloud-Base-Vagrant-37-1.7.x86_64.vagrant-libvirt.box HTTP/2 > Host: download.fedoraproject.org > user-agent: Vagrant/2.2.19 (+https://www.vagrantup.com; ruby3.1.3) > accept: application/json > * TLSv1.2 (IN), TLS header, Supplemental data (23): * TLSv1.3 (IN), TLS handshake, Newsession Ticket (4): * TLSv1.2 (IN), TLS header, Supplemental data (23): * TLSv1.3 (IN), TLS handshake, Newsession Ticket (4): * old SSL session ID is stale, removing * TLSv1.2 (IN), TLS header, Supplemental data (23): * TLSv1.2 (OUT), TLS header, Supplemental data (23): * TLSv1.2 (IN), TLS header, Supplemental data (23): * TLSv1.2 (IN), TLS header, Supplemental data (23): < HTTP/2 302 HTTP/2 302 < x-frame-options: SAMEORIGIN x-frame-options: SAMEORIGIN < x-xss-protection: 1; mode=block x-xss-protection: 1; mode=block < x-content-type-options: nosniff x-content-type-options: nosniff < referrer-policy: same-origin referrer-policy: same-origin < location: https://mirror.netsite.dk/fedora/linux/releases/37/Cloud/x86_64/images/Fedora-Cloud-Base-Vagrant-37-1.7.x86_64.vagrant-libvirt.box location: https://mirror.netsite.dk/fedora/linux/releases/37/Cloud/x86_64/images/Fedora-Cloud-Base-Vagrant-37-1.7.x86_64.vagrant-libvirt.box < content-type: text/plain content-type: text/plain < date: Tue, 14 Mar 2023 07:32:17 GMT date: Tue, 14 Mar 2023 07:32:17 GMT < apptime: D=14429 apptime: D=14429 < x-fedora-proxyserver: proxy01.iad2.fedoraproject.org x-fedora-proxyserver: proxy01.iad2.fedoraproject.org < x-fedora-requestid: ZBAjAtekAQvvwYRkZCmX5QAAihg x-fedora-requestid: ZBAjAtekAQvvwYRkZCmX5QAAihg < server: Apache server: Apache < * Connection #0 to host download.fedoraproject.org left intact * Issue another request to this URL: 'https://mirror.netsite.dk/fedora/linux/releases/37/Cloud/x86_64/images/Fedora-Cloud-Base-Vagrant-37-1.7.x86_64.vagrant-libvirt.box' * Trying 185.224.16.132:443... * Connected to mirror.netsite.dk (185.224.16.132) port 443 (#1) * ALPN: offers h2 * ALPN: offers http/1.1 * CAfile: /etc/pki/tls/certs/ca-bundle.crt * CApath: none * TLSv1.0 (OUT), TLS header, Certificate Status (22): * TLSv1.3 (OUT), TLS handshake, Client hello (1): * TLSv1.2 (IN), TLS header, Certificate Status (22): * TLSv1.3 (IN), TLS handshake, Server hello (2): * TLSv1.2 (IN), TLS header, Certificate Status (22): * TLSv1.2 (IN), TLS handshake, Certificate (11): * TLSv1.2 (IN), TLS header, Certificate Status (22): * TLSv1.2 (IN), TLS handshake, Server key exchange (12): * TLSv1.2 (IN), TLS header, Certificate Status (22): * TLSv1.2 (IN), TLS handshake, Server finished (14): * TLSv1.2 (OUT), TLS header, Certificate Status (22): * TLSv1.2 (OUT), TLS handshake, Client key exchange (16): * TLSv1.2 (OUT), TLS header, Finished (20): * TLSv1.2 (OUT), TLS change cipher, Change cipher spec (1): * TLSv1.2 (OUT), TLS header, Certificate Status (22): * TLSv1.2 (OUT), TLS handshake, Finished (20): * TLSv1.2 (IN), TLS header, Finished (20): * TLSv1.2 (IN), TLS header, Certificate Status (22): * TLSv1.2 (IN), TLS handshake, Finished (20): * SSL connection using TLSv1.2 / ECDHE-RSA-AES256-GCM-SHA384 * ALPN: server accepted h2 * Server certificate: * subject: CN=mirror.netsite.dk * start date: Mar 3 05:45:18 2023 GMT * expire date: Jun 1 05:45:17 2023 GMT * subjectAltName: host "mirror.netsite.dk" matched cert's "mirror.netsite.dk" * issuer: C=US; O=Let's Encrypt; CN=R3 * SSL certificate verify ok. * Using HTTP2, server supports multiplexing * Copying HTTP/2 data in stream buffer to connection buffer after upgrade: len=0 * TLSv1.2 (OUT), TLS header, Supplemental data (23): * TLSv1.2 (OUT), TLS header, Supplemental data (23): * TLSv1.2 (OUT), TLS header, Supplemental data (23): * h2h3 [:method: HEAD] * h2h3 [:path: /fedora/linux/releases/37/Cloud/x86_64/images/Fedora-Cloud-Base-Vagrant-37-1.7.x86_64.vagrant-libvirt.box] * h2h3 [:scheme: https] * h2h3 [:authority: mirror.netsite.dk] * h2h3 [user-agent: Vagrant/2.2.19 (+https://www.vagrantup.com; ruby3.1.3)] * h2h3 [accept: application/json] * Using Stream ID: 1 (easy handle 0x55d02a59e460) * TLSv1.2 (OUT), TLS header, Supplemental data (23): > HEAD /fedora/linux/releases/37/Cloud/x86_64/images/Fedora-Cloud-Base-Vagrant-37-1.7.x86_64.vagrant-libvirt.box HTTP/2 > Host: mirror.netsite.dk > user-agent: Vagrant/2.2.19 (+https://www.vagrantup.com; ruby3.1.3) > accept: application/json > * TLSv1.2 (IN), TLS header, Supplemental data (23): * Connection state changed (MAX_CONCURRENT_STREAMS == 128)! * TLSv1.2 (OUT), TLS header, Supplemental data (23): * TLSv1.2 (IN), TLS header, Supplemental data (23): * TLSv1.2 (IN), TLS header, Supplemental data (23): < HTTP/2 200 HTTP/2 200 < server: nginx/1.20.1 server: nginx/1.20.1 < date: Tue, 14 Mar 2023 07:32:18 GMT date: Tue, 14 Mar 2023 07:32:18 GMT < content-type: off content-type: off < content-length: 484924118 content-length: 484924118 < last-modified: Sat, 05 Nov 2022 09:01:24 GMT last-modified: Sat, 05 Nov 2022 09:01:24 GMT < etag: "63662664-1ce75ad6" etag: "63662664-1ce75ad6" < strict-transport-security: max-age=15768000 strict-transport-security: max-age=15768000 < accept-ranges: bytes accept-ranges: bytes < * Connection #1 to host mirror.netsite.dk left intact
The difference I see is that in direct curl output < HTTP/2 302 translates in * HTTP/2 stream 0 was not closed cleanly: PROTOCOL_ERROR (err 1)
< HTTP/2 302
* HTTP/2 stream 0 was not closed cleanly: PROTOCOL_ERROR (err 1)
when run by vagrant. So it seems a vagrant or maybe ruby fault.
Could it be: https://github.com/hashicorp/vagrant/issues/12921 ?
(which says it was fixed, but you might not have the fixed version?)
It is, indeed. Sadly, latest vagrant stable release is 2.3.4 and we have 2.2.19 in Koji... the fix was released in 2.3.1.
Thanks for your help.
:(
Ok, at least we sorted it out. :)
Metadata Update from @kevin: - Issue close_status updated to: Upstream - Issue status updated to: Closed (was: Open)
Log in to comment on this ticket.