Server terminating: Package {"hexpm", "spandex"} not prefetched, please report this issue

Hi all 👋

I'm one of the maintainers of dependabot and recently we're starting to see errors like this in our logs:

10:06:11.478 [error] GenServer Hex.Registry.Server terminating
** (Mix.Error) Package {"hexpm", "spandex"} not prefetched, please report this issue
    (mix 1.11.4) lib/mix.ex:436: Mix.raise/1
    (stdlib 3.14.1) gen_server.erl:715: :gen_server.try_handle_call/4
    (stdlib 3.14.1) gen_server.erl:744: :gen_server.handle_msg/6
    (stdlib 3.14.1) proc_lib.erl:226: :proc_lib.init_p_do_apply/3
Last message (from #PID<0.1557.0>): {:outer_checksum, "hexpm", "spandex", "3.0.3"}
State: %{closing_fun: nil, ets: nil, fetched: #MapSet<[]>, path: nil, pending: #MapSet<[]>, waiting: %{}}
Client #PID<0.1557.0> is alive

    (stdlib 3.14.1) gen.erl:208: :gen.do_call/4
    (elixir 1.11.4) lib/gen_server.ex:1024: GenServer.call/3
    (hex 0.21.2) lib/hex/scm.ex:397: Hex.SCM.fetch/3
    (elixir 1.11.4) lib/task/supervised.ex:90: Task.Supervised.invoke_mfa/2
    (elixir 1.11.4) lib/task/supervised.ex:35: Task.Supervised.reply/5
    (stdlib 3.14.1) proc_lib.erl:226: :proc_lib.init_p_do_apply/3

10:06:11.493 [error] Task #PID<0.1559.0> started from :hex_fetcher terminating
** (stop) exited in: GenServer.call(Hex.Registry.Server, {:outer_checksum, "hexpm", "jsx", "2.11.0"}, 60000)
    ** (EXIT) an exception was raised:
        ** (Mix.Error) Package {"hexpm", "spandex"} not prefetched, please report this issue
            (mix 1.11.4) lib/mix.ex:436: Mix.raise/1
            (stdlib 3.14.1) gen_server.erl:715: :gen_server.try_handle_call/4
            (stdlib 3.14.1) gen_server.erl:744: :gen_server.handle_msg/6
            (stdlib 3.14.1) proc_lib.erl:226: :proc_lib.init_p_do_apply/3
    (elixir 1.11.4) lib/gen_server.ex:1027: GenServer.call/3
    (hex 0.21.2) lib/hex/scm.ex:397: Hex.SCM.fetch/3
    (elixir 1.11.4) lib/task/supervised=> nil

Where the second dependency on the second line of the error (spandex in the one above) will differ from case to case.

The error seems to originate here.

We're running hex v0.21.1, Elixir v1.11.4 and Erlang/OTP 23.

Now, I should mention that we run hex/mix in a slightly odd way, see here, but I'm a little lost what might be causing this error and was hoping someone here could point me in the right direction.

Since these jobs run on our customers configuration, it's a little hard for me to find a reliable way to reproduce it, but if that's needed to dig into this, please let me know and I'll try to find a way.

Thanks, and thanks for Hex! 💛

Judging from this:

State: %{closing_fun: nil, ets: nil, fetched: #MapSet<[]>, path: nil, pending: #MapSet<[]>, waiting: %{}}

it looks like the state of the registry server is completely fresh which it definitely shouldn't be after having performed resolution. Is there anything earlier in the logs that indicates it has already crashed once and been restarted?

Thanks for looking into this @ericmj 🙇

Is there anything earlier in the logs that indicates it has already crashed once and been restarted?

There's nothing in the logs that indicates that, we also currently don't retry this process on failure (but we could if that'd be a good way to handle this).

Unfortunately we haven't been able to reproduce this and haven't had any reports of it happening so it seems to be specific to how you are invoking Hex. Are you still seeing this error?

You are using a lot of private API so ideally we should try to see if there is a way to only use public API. Have you tried using the mix tasks instead of calling private APIs, is there anything we can do to help you move in this direction?

Hey, I was gonna take a crack at seeing if I could fix this (I had this issue reproducible about a month ago, but alas, it no longer reproduces (my early thoughts are perhaps something rate limiting related)), could you give me a list of functions that dependabot shouldn't be calling? and then I can take a look and try to replace them with public apis or mix tasks. Thanks!

No functions under the Hex namespace should be called and functions under the Mix namespace should only be called if they are documented here https://hexdocs.pm/mix/Mix.html.

I think the best solution would be to call the mix tasks, either by running the mix executable: mix deps.update foo or by calling: Mix.Task.run("deps.update", ["foo"]).

Unfortunately we haven't been able to reproduce this and haven't had any reports of it happening so it seems to be specific to how you are invoking Hex. Are you still seeing this error?

You are using a lot of private API so ideally we should try to see if there is a way to only use public API. Have you tried using the mix tasks instead of calling private APIs, is there anything we can do to help you move in this direction?

Yeah unfortunately we're still seeing this error.

We're currently working with the dart/pub folks to try and define the API that a package manager would need to expose to support dependabot's functionality natively, once that's fleshed out a bit more I'll loop y'all in as well and hopefully we can figure out a way we can avoid using any private APIs and/or custom code in Dependabot. It's definitely something we'd love to avoid if at all possible so I think we're on the same page 👍

This issue is pretty stale and I have never been able to reproduce it so I am closing it. Let us know if you are still having this issue.