zef error message is confusing

[melezhik]

An initial error when I try to install module with zef is this:

03:47:50 02/26/2022 [repository] :: index updated from http://sparrowhub.io/repo//api/v1/index
run stage: raku-libs
03:47:52 02/26/2022 [repository] :: installing bash, version 0.002001
03:47:55 02/26/2022 [bash: zef --version || /opt/rakudo-pkg/bin/install-zef] :: stderr: bash: line 1: zef: command not found
03:47:57 02/26/2022 [bash: zef --version || /opt/rakudo-pkg/bin/install-zef] :: ===> Testing: zef:ver<0.13.7>:auth<github:ugexe>:api<0>
03:48:59 02/26/2022 [bash: zef --version || /opt/rakudo-pkg/bin/install-zef] :: ===> Testing [OK] for zef:ver<0.13.7>:auth<github:ugexe>:api<0>
03:48:59 02/26/2022 [bash: zef --version || /opt/rakudo-pkg/bin/install-zef] :: ===> Installing: zef:ver<0.13.7>:auth<github:ugexe>:api<0>
03:48:59 02/26/2022 [bash: zef --version || /opt/rakudo-pkg/bin/install-zef] :: 
03:48:59 02/26/2022 [bash: zef --version || /opt/rakudo-pkg/bin/install-zef] :: 1 bin/ script [zef] installed to:
03:48:59 02/26/2022 [bash: zef --version || /opt/rakudo-pkg/bin/install-zef] :: /home/sparky/.raku/bin
03:48:59 02/26/2022 [bash: zef --version || /opt/rakudo-pkg/bin/install-zef] :: Don't forget to add '~/.raku/bin' to your PATH,
03:48:59 02/26/2022 [bash: zef --version || /opt/rakudo-pkg/bin/install-zef] :: e.g. by adding this to .profile:
03:48:59 02/26/2022 [bash: zef --version || /opt/rakudo-pkg/bin/install-zef] :: export PATH=~/.raku/bin:$PATH
03:49:05 02/26/2022 [bash: zef install https://github.com/melezhik/sparrowdo. ...] :: ===> Installing: Sparrowdo:ver<0.1.16>:auth<zef:melezhik>
03:49:09 02/26/2022 [bash: zef install https://github.com/melezhik/sparrowdo. ...] :: 
03:49:09 02/26/2022 [bash: zef install https://github.com/melezhik/sparrowdo. ...] :: 1 bin/ script [sparrowdo] installed to:
03:49:09 02/26/2022 [bash: zef install https://github.com/melezhik/sparrowdo. ...] :: /home/sparky/.raku/bin
03:49:18 02/26/2022 [bash: zef install https://github.com/melezhik/sparky.git] :: ===> Searching for missing dependencies: DBIish, Time::Crontab, cro, Cro::HTTP::Server, Cro::HTTP::Router, Cro::WebApp::Template, Text::Markdown
03:49:18 02/26/2022 [bash: zef install https://github.com/melezhik/sparky.git] :: stderr: ===> Updating fez mirror: https://360.zef.pm/
03:49:49 02/26/2022 [bash: zef install https://github.com/melezhik/sparky.git] :: ===> Searching for missing dependencies: IO::Socket::Async::SSL, META6, Shell::Command, File::Find, Terminal::ANSIColor, OO::Monitors, Cro::WebSocket:ver<0.8.7>, Docker::File, File::Ignore, IO::Path::ChildSecure, Base64, HTTP::HPACK, Cro::Core:ver<0.8.7>, Cro::TLS:ver<0.8.7>, Crypt::Random, JSON::JWT, DateTime::Parse, Log::Timeline, NativeHelpers::Blob, NativeLibs, Test::META, HTML::Escape
03:49:49 02/26/2022 [bash: zef install https://github.com/melezhik/sparky.git] :: ===> Searching for missing dependencies: Digest::HMAC, URI, License::SPDX, File::Which, Digest::SHA1::Native, if, JSON::Class:ver<0.0.15+>, JSON::Name, CBOR::Simple
03:49:49 02/26/2022 [bash: zef install https://github.com/melezhik/sparky.git] :: ===> Searching for missing dependencies: LibraryMake, Digest, JSON::OptIn, JSON::Marshal:ver<0.0.23+>, JSON::Unmarshal:ver<0.08+>, TinyFloats:ver<0.0.3+>
03:49:49 02/26/2022 [bash: zef install https://github.com/melezhik/sparky.git] :: stderr: ===> Updated fez mirror: https://360.zef.pm/
===> Updating cpan mirror: https://raw.githubusercontent.com/ugexe/Perl6-ecosystems/master/cpan1.json
===> Updated cpan mirror: https://raw.githubusercontent.com/ugexe/Perl6-ecosystems/master/cpan1.json
===> Updating p6c mirror: https://raw.githubusercontent.com/ugexe/Perl6-ecosystems/master/p6c1.json
===> Updated p6c mirror: https://raw.githubusercontent.com/ugexe/Perl6-ecosystems/master/p6c1.json
Enabled extracting backends [git path tar p5tar] don't understan
03:49:49 02/26/2022 [bash: zef install https://github.com/melezhik/sparky.git] :: stderr: d /home/sparky/.zef/tmp/1645847384.23901.3041.813153971944/p6-file-ignore.git
You may need to configure one of the following backends, or install its underlying software - [unzip psunzip]
03:49:49 02/26/2022 [bash: zef install https://github.com/melezhik/sparky.git] :: task exit status: 1
03:49:49 02/26/2022 [bash: zef install https://github.com/melezhik/sparky.git] :: task bash: zef install https://github.com/melezhik/sparky.git FAILED

First it makes one think that there is no some dependency installed - [unzip psunzip]

But it's not true ( maybe the reason is that zef is trying to build all the decency tree and it fails for the first time ? ... Anyway - this is not what an issue about ... ).

Once I run THE SAME build second time ( without changing anything on a target machine ), everything works great:

03:51:28 02/26/2022 [repository] :: index updated from http://sparrowhub.io/repo//api/v1/index
run stage: raku-libs
03:51:34 02/26/2022 [bash: zef --version || /opt/rakudo-pkg/bin/install-zef] :: v0.13.7
03:51:40 02/26/2022 [bash: zef install https://github.com/melezhik/sparrowdo. ...] :: stderr: All candidates are currently installed
03:51:40 02/26/2022 [bash: zef install https://github.com/melezhik/sparrowdo. ...] :: No reason to proceed. Use --force-install to continue anyway
03:51:50 02/26/2022 [bash: zef install https://github.com/melezhik/sparky.git] :: ===> Searching for missing dependencies: DBIish, Time::Crontab, cro, Cro::HTTP::Server, Cro::HTTP::Router, Cro::WebApp::Template, Text::Markdown
03:57:03 02/26/2022 [bash: zef install https://github.com/melezhik/sparky.git] :: ===> Searching for missing dependencies: HTML::Escape, IO::Socket::Async::SSL, META6, Shell::Command, File::Find, Terminal::ANSIColor, OO::Monitors, Cro::WebSocket:ver<0.8.7>, Docker::File, File::Ignore, IO::Path::ChildSecure, Base64, HTTP::HPACK, Cro::Core:ver<0.8.7>, Cro::TLS:ver<0.8.7>, Crypt::Random, JSON::JWT, DateTime::Parse, Log::Timeline, NativeHelpers::Blob, NativeLibs, Test::META
03:57:03 02/26/2022 [bash: zef install https://github.com/melezhik/sparky.git] :: ===> Searching for missing dependencies: CBOR::Simple, File::Which, Digest::SHA1::Native, JSON::Class:ver<0.0.15+>, JSON::Name, URI, License::SPDX, Digest::HMAC, if
03:57:03 02/26/2022 [bash: zef install https://github.com/melezhik/sparky.git] :: ===> Searching for missing dependencies: JSON::OptIn, JSON::Marshal:ver<0.0.23+>, JSON::Unmarshal:ver<0.08+>, TinyFloats:ver<0.0.3+>, LibraryMake, Digest
03:57:03 02/26/2022 [bash: zef install https://github.com/melezhik/sparky.git] :: ===> Building: Digest::SHA1::Native:ver<0.05>
03:57:03 02/26/2022 [bash: zef install https://github.com/melezhik/sparky.git] :: ===> Building [OK] for Digest::SHA1::Native:ver<0.05>
03:57:03 02/26/2022 [bash: zef install https://github.com/melezhik/sparky.git] :: ===> Installing: NativeHelpers::Blob:ver<0.1.12>:auth<github:salortiz>
03:57:03 02/26/2022 [bash: zef install https://github.com/melezhik/sparky.git] :: ===> Installing: NativeLibs:ver<0.0.9>:auth<github:salortiz>
03:57:03 02/26/2022 [bash: zef install https://github.com/melezhik/sparky.git] :: ===> Installing: DBIish:ver<0.6.3>:auth<github:raku-community-modules>
03:57:03 02/26/2022 [bash: zef install https://github.com/melezhik/sparky.git] :: ===> Installing: JSON::OptIn:ver<0.0.1>:auth<github:jonathanstowe>
03:57:03 02/26/2022 [bash: zef install https://github.com/melezhik/sparky.git] :: ===> Installing: JSON::Name:ver<0.0.6>:auth<github:jonathanstowe>:api<1.0>
03:57:03 02/26/2022 [bash: zef install https://github.com/melezhik/sparky.git] :: ===> Installing: JSON::Marshal:ver<0.0.23>:auth<github:jonathanstowe>:api<1.0>
03:57:03 02/26/2022 [bash: zef install https://github.com/melezhik/sparky.git] :: ===> Installing: JSON::Unmarshal:ver<0.08>
03:57:03 02/26/2022 [bash: zef install https://github.com/melezhik/sparky.git] :: ===> Installing: JSON::Class:ver<0.0.18>:auth<github:jonathanstowe>:api<1.0>
03:57:03 02/26/2022 [bash: zef install https://github.com/melezhik/sparky.git] :: ===> Installing: META6:ver<0.0.26>:auth<github:jonathanstowe>:api<1.0>
03:57:03 02/26/2022 [bash: zef install https://github.com/melezhik/sparky.git] :: ===> Installing: URI:ver<0.3.5>
03:57:03 02/26/2022 [bash: zef install https://github.com/melezhik/sparky.git] :: ===> Installing: License::SPDX:ver<3.16.0>:auth<github:jonathanstowe>:api<1.0>
03:57:03 02/26/2022 [bash: zef install https://github.com/melezhik/sparky.git] :: ===> Installing: Test::META:ver<0.0.17>:auth<github:jonathanstowe>:api<1.0>
03:57:03 02/26/2022 [bash: zef install https://github.com/melezhik/sparky.git] :: ===> Installing: Time::Crontab:ver<1.0.0>
03:57:03 02/26/2022 [bash: zef install https://github.com/melezhik/sparky.git] :: ===> Installing: IO::Socket::Async::SSL:ver<0.7.10>:auth<jnthn>
03:57:03 02/26/2022 [bash: zef install https://github.com/melezhik/sparky.git] :: ===> Installing: File::Which:ver<1.0.1>
03:57:03 02/26/2022 [bash: zef install https://github.com/melezhik/sparky.git] :: ===> Installing: File::Find:ver<0.1.1>
03:57:03 02/26/2022 [bash: zef install https://github.com/melezhik/sparky.git] :: ===> Installing: Shell::Command
03:57:03 02/26/2022 [bash: zef install https://github.com/melezhik/sparky.git] :: ===> Installing: Terminal::ANSIColor:ver<0.5>
03:57:03 02/26/2022 [bash: zef install https://github.com/melezhik/sparky.git] :: ===> Installing: OO::Monitors:ver<1.1.1>
03:57:03 02/26/2022 [bash: zef install https://github.com/melezhik/sparky.git] :: ===> Installing: IO::Path::ChildSecure:ver<1.001011>
03:57:03 02/26/2022 [bash: zef install https://github.com/melezhik/sparky.git] :: ===> Installing: Base64:ver<0.0.2>:auth<github:ugexe>
03:57:03 02/26/2022 [bash: zef install https://github.com/melezhik/sparky.git] :: ===> Installing: HTTP::HPACK:ver<0.9.3>
03:57:03 02/26/2022 [bash: zef install https://github.com/melezhik/sparky.git] :: ===> Installing: Cro::Core:ver<0.8.7>
03:57:03 02/26/2022 [bash: zef install https://github.com/melezhik/sparky.git] :: ===> Installing: Cro::TLS:ver<0.8.7>
03:57:03 02/26/2022 [bash: zef install https://github.com/melezhik/sparky.git] :: ===> Installing: if:ver<0.1.1>
03:57:03 02/26/2022 [bash: zef install https://github.com/melezhik/sparky.git] :: ===> Installing: Crypt::Random:ver<0.4.1>
03:57:03 02/26/2022 [bash: zef install https://github.com/melezhik/sparky.git] :: ===> Installing: Digest:ver<0.5.0>
03:57:03 02/26/2022 [bash: zef install https://github.com/melezhik/sparky.git] :: compiling...
03:57:03 02/26/2022 [bash: zef install https://github.com/melezhik/sparky.git] :: ===> Installing: Digest::HMAC:ver<1.0.2>:auth<github:retupmoca>
03:57:03 02/26/2022 [bash: zef install https://github.com/melezhik/sparky.git] :: ===> Installing: JSON::JWT:ver<1.1.1>:auth<zef:raku-community-modules>
03:57:03 02/26/2022 [bash: zef install https://github.com/melezhik/sparky.git] :: ===> Installing: DateTime::Parse:ver<0.9.1>
03:57:03 02/26/2022 [bash: zef install https://github.com/melezhik/sparky.git] :: ===> Installing: TinyFloats:ver<0.0.4>:auth<zef:japhb>
03:57:03 02/26/2022 [bash: zef install https://github.com/melezhik/sparky.git] :: ===> Installing: CBOR::Simple:ver<0.1.1>:auth<zef:japhb>
03:57:03 02/26/2022 [bash: zef install https://github.com/melezhik/sparky.git] :: ===> Installing: Log::Timeline:ver<0.4>
03:57:03 02/26/2022 [bash: zef install https://github.com/melezhik/sparky.git] :: ===> Installing: Cro::HTTP:ver<0.8.7>
03:57:03 02/26/2022 [bash: zef install https://github.com/melezhik/sparky.git] :: ===> Installing: LibraryMake:ver<1.0.0>
03:57:03 02/26/2022 [bash: zef install https://github.com/melezhik/sparky.git] :: ===> Installing: Digest::SHA1::Native:ver<0.05>
03:57:03 02/26/2022 [bash: zef install https://github.com/melezhik/sparky.git] :: ===> Installing: Cro::WebSocket:ver<0.8.7>
03:57:03 02/26/2022 [bash: zef install https://github.com/melezhik/sparky.git] :: ===> Installing: Docker::File:ver<1.0>:auth<github:jnthn>
03:57:03 02/26/2022 [bash: zef install https://github.com/melezhik/sparky.git] :: ===> Installing: File::Ignore:ver<1.1>
03:57:03 02/26/2022 [bash: zef install https://github.com/melezhik/sparky.git] :: ===> Installing: cro:ver<0.8.7>
03:57:03 02/26/2022 [bash: zef install https://github.com/melezhik/sparky.git] :: ===> Installing: Cro::WebApp:ver<0.8.7>
03:57:03 02/26/2022 [bash: zef install https://github.com/melezhik/sparky.git] :: ===> Installing: HTML::Escape:ver<0.0.1>
03:57:03 02/26/2022 [bash: zef install https://github.com/melezhik/sparky.git] :: ===> Installing: Text::Markdown:ver<1.1.1>:auth<zef:JJMERELO>
03:57:03 02/26/2022 [bash: zef install https://github.com/melezhik/sparky.git] :: ===> Installing: Sparky:ver<0.1.5>:auth<zef:melezhik>
03:57:03 02/26/2022 [bash: zef install https://github.com/melezhik/sparky.git] :: 
03:57:03 02/26/2022 [bash: zef install https://github.com/melezhik/sparky.git] :: 4 bin/ scripts [cro sparkyd sparky-web.raku sparky-runner.raku] installed to:
03:57:03 02/26/2022 [bash: zef install https://github.com/melezhik/sparky.git] :: /home/sparky/.raku/bin
03:57:10 02/26/2022 [bash: zef install https://github.com/melezhik/sparky-job ...] :: stderr: All candidates are currently installed
03:57:10 02/26/2022 [bash: zef install https://github.com/melezhik/sparky-job ...] :: No reason to proceed. Use --force-install to continue anyway
03:57:11 02/26/2022 [repository] :: installing directory, version 0.002000
03:57:16 02/26/2022 [create directory /home/sparky/projects/] :: directory path: /home/sparky/projects/
03:57:16 02/26/2022 [create directory /home/sparky/projects/] :: directory owner: <sparky>
03:57:16 02/26/2022 [create directory /home/sparky/projects/] :: directory group: <sparky>
03:57:16 02/26/2022 [create directory /home/sparky/projects/] :: directory access rights: drwxr-xr-x
03:57:22 02/26/2022 [create directory /home/sparky/projects/Sparky] :: directory path: /home/sparky/projects/Sparky
03:57:22 02/26/2022 [create directory /home/sparky/projects/Sparky] :: directory owner: <sparky>
03:57:22 02/26/2022 [create directory /home/sparky/projects/Sparky] :: directory group: <sparky>
03:57:22 02/26/2022 [create directory /home/sparky/projects/Sparky] :: directory access rights: drwxr-xr-x

I've seen this issue many times with my Sparky installations, finally decided to describe it

HTH

[ugexe]

Unfortunately I'm really sure what to tell you. It says it can't match

/home/sparky/.zef/tmp/1645847384.23901.3041.813153971944/p6-file-ignore.git

but if you look at the code you'll see it should always match:

zef/lib/Zef/Service/Shell/git.rakumod

Lines 104 to 109 in 3edbbcf

	method fetch-matcher(Str() $uri --> Bool:D) {
	# $uri may contain non-uri-standard, git specific, uri parts (like a trailing @tag)
	my $clean-uri = self!repo-url($uri).lc;
	return False unless $clean-uri.ends-with('.git');
	return so <git http ssh>.first({ $clean-uri.starts-with($_) });
	}

A similar problem happens with other runtime plugins, too, so AFAICT its likely a rakudo bug. However if you are having luck reproducing the issue: it could be useful if you modified the zef you are installing (particularly the fetch-matcher method linked earlier) to see at which point it returns False instead of True. I'm not sure there is a better way to get to the root cause.

[melezhik]

Hi Nick. Thanks. I ll try do debug and let you know ...

[melezhik]

My hypothesis is that this type of error occurs when zef runs under low resources, for example for 4 GB memory VM I have this:

https://sparrowhub.io:4000/report/fastspec.notify/459

23:37:46 03/25/2022 [bash: git checkout https://github.com/vrurg/raku-Config- ...] :: /home/raku/.sparky/.cache/hsudnpixvfqyzocawgjm.302/.sparrowdo/scm
23:37:46 03/25/2022 [bash: git checkout https://github.com/vrurg/raku-Config- ...] :: stderr: Cloning into '.'...
23:37:55 03/25/2022 [bash: install deps] :: ===> Searching for missing dependencies: AttrX::Mooish:ver<0.8.1+>:auth<zef:vrurg>, IP::Addr, Test::Async:ver<0.1.2+>:auth<zef:vrurg>
23:37:57 03/25/2022 [bash: install deps] :: stderr: Enabled fetching backends [git path curl wget] don't understand https://360.zef.pm/I/P_/IP_ADDR/898819a6597b8cdfea519ea53406d13
23:37:57 03/25/2022 [bash: install deps] :: stderr: f86545b3d.tar.gz
You may need to configure one of the following backends, or install its underlying software - [pswebrequest]

maybe this is not relevant to the original issue, but here the same "confusing" error message

HTH

[melezhik]

It is not, it is what zef outputs shows, indeed you can see the SAME scenario successfully runs on different docker instance with 6 GB memory - https://sparrowhub.io:4000/report/fastspec.notify/451 We can exclude any VM state related effect as every scenario gets run a freshly spawned azure container instance which gets killed in the end.

…

On Fri, Mar 25, 2022 at 6:49 PM Nick Logan ***@***.***> wrote: Hmm, in your last example the url seems to be missing (at a minimum) the .tar.gz don't understand https://360.zef.pm/I/P_/IP_ADDR/898819a6597b8cdfea519ea53406d13 — Reply to this email directly, view it on GitHub <#446 (comment)>, or unsubscribe <https://github.com/notifications/unsubscribe-auth/AAHRHSMN4JTRJRAP4UFIG7DVBZGJBANCNFSM5PL6RS6Q> . You are receiving this because you authored the thread.Message ID: ***@***.***>

[ugexe]

The file name on stderr is broken onto two lines, which was confusing

23:37:57 03/25/2022 [bash: install deps] :: stderr: Enabled fetching backends [git path curl wget] don't understand https://360.zef.pm/I/P_/IP_ADDR/898819a6597b8cdfea519ea53406d13
23:37:57 03/25/2022 [bash: install deps] :: stderr: f86545b3d.tar.gz

[melezhik]

Oh, I see. Yes it’s old Sparrow disadvantage I always find hard to fix , anyway I hope you understand my idea …

…

On Fri, Mar 25, 2022 at 7:01 PM Nick Logan ***@***.***> wrote: The file name on stderr is broken onto two lines, which was confusing — Reply to this email directly, view it on GitHub <#446 (comment)>, or unsubscribe <https://github.com/notifications/unsubscribe-auth/AAHRHSIBRTVOZPOOI2SWW73VBZHV7ANCNFSM5PL6RS6Q> . You are receiving this because you authored the thread.Message ID: ***@***.***>