Using Fly Volumes for Mnesia / Phoenix / Pow

Questions / Help Build debugging
1

I’m currently working on setting up the Mnesia backend for the Pow authentication library, and I keep running into a problem in which the Mnesia directory either can’t be found or can’t be created.

It looks like this issue has been brought up before, but the OP never posted the solution: Using fly volumes with Mnesia, Phoenix and Pow

Any advice would be very much appreciated.

Output:

2022-03-11T15:30:58Z   [info]15:30:58.457 [info] Access AppWeb.Endpoint at http://url.fly.dev:443
2022-03-11T15:30:58Z   [info]15:30:58.466 [error] Couldn't initialize mnesia cluster because: {'no such file or directory', 'mnesia.app'}
2022-03-11T15:30:58Z   [info]15:30:58.468 [notice] Application appy exited: App.Application.start(:normal, []) returned an error: shutdown: failed to start child: Pow.Store.Backend.MnesiaCache
2022-03-11T15:30:58Z   [info]    ** (EXIT) {'no such file or directory', 'mnesia.app'}
2022-03-11T15:30:59Z   [info]Reaped child process with pid: 585 and signal: SIGUSR1, core dumped? false
2022-03-11T15:30:59Z   [info]{"Kernel pid terminated",application_controller,"{application_start_failure,app,{{shutdown,{failed_to_start_child,'Elixir.Pow.Store.Backend.MnesiaCache',{\"no such file or directory\",\"mnesia.app\"}}},{'Elixir.App.Application',start,[normal,[]]}}}"}
2022-03-11T15:30:59Z   [info]Kernel pid terminated (application_controller) ({application_start_failure,app,{{shutdown,{failed_to_start_child,'Elixir.Pow.Store.Backend.MnesiaCache',{"no such file or directory","mnesia.app"}}},{'Elixir.App.Application',start,[normal,[]]}}})
2022-03-11T15:31:00Z   [info]Crash dump is being written to: erl_crash.dump...done
2022-03-11T15:31:00Z   [info]Main child exited normally with code: 1
2022-03-11T15:31:00Z   [info]Starting clean up.
2022-03-11T15:31:00Z   [info]Umounting /dev/vdc from /mnesia
--> v61 failed - Failed due to unhealthy allocations - rolling back to job version 60 and deploying as v62
2

Have you verified that you are mounting your volume at the correct directory that your app is expecting for the mnesia DB? Also double check permissions on the volume. You can check both of these using fly ssh console and standard ls to take a look at things. Note, your mount path with be configured in your fly.toml, such as:

[mounts]
  source="data"
  destination="/app"
3

Thanks for the response, Chris. Sadly fly ssh console results in the following error:

 % fly ssh console                                 
Error host unavailable: host was not found in DNS
4

Oh ssh commands will only work if the app is running. You may need to deploy without mnesia configured. Is that doable?

5

OK So I temporarily disabled mnesia requirements and was able to get into the ssh console. I opened up all permissions on the /mnesia directory I created with a fly volume and now the error has changed:

2022-03-11T22:03:54Z   [info]22:03:54.442 [info] Running AppWeb.Endpoint with cowboy 2.9.0 at :::8080 (http)
2022-03-11T22:03:54Z   [info]22:03:54.444 [info] Access AppWeb.Endpoint at http://app.fly.dev:443
2022-03-11T22:03:54Z   [info]22:03:54.449 [error] Couldn't initialize mnesia cluster because: {'no such file or directory', 'mnesia.app'}
2022-03-11T22:03:54Z   [info]22:03:54.452 [notice] Application app exited: App.Application.start(:normal, []) returned an error: shutdown: failed to start child: Pow.Store.Backend.MnesiaCache
2022-03-11T22:03:54Z   [info]    ** (EXIT) {'no such file or directory', 'mnesia.app'}
2022-03-11T22:03:55Z   [info]Reaped child process with pid: 585 and signal: SIGUSR1, core dumped? false
2022-03-11T22:03:55Z   [info]{"Kernel pid terminated",application_controller,"{application_start_failure,app,{{shutdown,{failed_to_start_child,'Elixir.Pow.Store.Backend.MnesiaCache',{\"no such file or directory\",\"mnesia.app\"}}},{'Elixir.App.Application',start,[normal,[]]}}}"}
2022-03-11T22:03:55Z   [info]Kernel pid terminated (application_controller) ({application_start_failure,app,{{shutdown,{failed_to_start_child,'Elixir.Pow.Store.Backend.MnesiaCache',{"no such file or directory","mnesia.app"}}},{'Elixir.App.Application',start,[normal,[]]}}})
2022-03-11T22:03:56Z   [info]Crash dump is being written to: erl_crash.dump...done
2022-03-11T22:03:56Z   [info]Main child exited normally with code: 1
2022-03-11T22:03:56Z   [info]Starting clean up.
2022-03-11T22:03:56Z   [info]Umounting /dev/vdc from /mnesia
--> v64 failed - Failed due to unhealthy allocations - rolling back to job version 63 and deploying as v65

I’ve redacted the name of my application with App in the logs. Sorry if that’s confusing.

6

It looks like it wants a directory named mnesia.app. Do you know if it’s trying to put that in the working directory, or have you configured it to use /mnesia somehow?

7

This is the guide I followed from Pow to get its Mnesia cache working:

https://hexdocs.pm/pow/Pow.Store.Backend.MnesiaCache.html#content

My config contains the following:

config :mnesia,
 dir: "/mnesia"
8

From the link, did you follow the bit about adding :mnesia to :extra_applications in your mix.exs’s application function?

The directory path should be accessible, otherwise MnesiaCache will crash on startup.

:mnesia should be added to :extra_applications in mix.exs for it to be included in releases.

It should look like:

  def application do
    [
      mod: {YourApp.Application, []},
      extra_applications: [:logger, :runtime_tools, :mnesia]
    ]
  end
9

Gotcha. Looks like that may have been one of my problems as well. I very much appreciate you taking the time to help!

Once I corrected that, it appears as though the application’s started crashing over and over pertaining to mnesia. I found the following in the logs:

2022-03-12T01:22:34.095 app[f41cf0c2] sea [info] Preparing to run: `/app/bin/server` as nobody

2022-03-12T01:22:34.122 app[f41cf0c2] sea [info] 2022/03/12 01:22:34 listening on [fdaa:0:4179:a7b:2d30:0:a70b:2]:22 (DNS: [fdaa::3]:53)

2022-03-12T01:22:35.104 app[f41cf0c2] sea [info] Reaped child process with pid: 562, exit code: 0

2022-03-12T01:22:37.354 app[f41cf0c2] sea [info] 01:22:37.328 [info] Access AppWeb.Endpoint at http://app.fly.dev:443

2022-03-12T01:22:39.476 app[f41cf0c2] sea [info] 01:22:39.476 [error] Mnesia(:"app@fdaa:0:4179:a7b:2d30:0:a70b:2"): ** ERROR ** (ignoring core) ** FATAL ** :mnesia_tm crashed: {:badarg,

2022-03-12T01:22:39.476 app[f41cf0c2] sea [info] {:erlang, :send, [:mnesia_locker, {:release_tid, {:tid, 3, #PID<0.2468.0>}}],

2022-03-12T01:22:39.476 app[f41cf0c2] sea [info] {:mnesia_locker, :release_tid, 1, [file: 'mnesia_locker.erl', line: 125]},

2022-03-12T01:22:39.476 app[f41cf0c2] sea [info] {:mnesia_sp, :init_proc, 4, [file: 'mnesia_sp.erl', line: 34]},

2022-03-12T01:22:39.476 app[f41cf0c2] sea [info] {:proc_lib, :init_p_do_apply, 3, [file: 'proc_lib.erl', line: 226]}

2022-03-12T01:22:39.476 app[f41cf0c2] sea [info] ]} state: [#PID<0.2243.0>]

2022-03-12T01:22:49.479 app[f41cf0c2] sea [info] Last message: {:EXIT, #PID<0.2243.0>, :killed}

2022-03-12T01:22:49.479 app[f41cf0c2] sea [info] 01:22:49.478 [notice] Application mnesia exited: normal

2022-03-12T01:22:50.125 app[f41cf0c2] sea [info] Reaped child process with pid: 585 and signal: SIGUSR1, core dumped? false

2022-03-12T01:22:51.011 app[f41cf0c2] sea [info] {"Kernel pid terminated",application_controller,"{application_terminated,mnesia,normal}"}

2022-03-12T01:22:51.014 app[f41cf0c2] sea [info] Kernel pid terminated (application_controller) ({application_terminated,mnesia,normal})

2022-03-12T01:22:51.159 app[f41cf0c2] sea [info] Crash dump is being written to: erl_crash.dump...done

2022-03-12T01:22:52.148 app[f41cf0c2] sea [info] Umounting /dev/vdc from /mnesia

2022-03-12T01:22:59.226 runner[f41cf0c2] sea [info] Starting instance

2022-03-12T01:22:59.372 runner[f41cf0c2] sea [info] Configuring virtual machine

2022-03-12T01:22:59.373 runner[f41cf0c2] sea [info] Pulling container image

2022-03-12T01:22:59.855 runner[f41cf0c2] sea [info] Unpacking image

2022-03-12T01:22:59.860 runner[f41cf0c2] sea [info] Preparing kernel init

2022-03-12T01:23:00.006 runner[f41cf0c2] sea [info] Setting up volume 'mnesia'

2022-03-12T01:23:00.009 runner[f41cf0c2] sea [info] Opening encrypted volume

2022-03-12T01:23:01.289 runner[f41cf0c2] sea [info] Configuring firecracker

2022-03-12T01:23:01.378 runner[f41cf0c2] sea [info] Starting virtual machine

2022-03-12T01:23:01.558 app[f41cf0c2] sea [info] Mounting /dev/vdc at /mnesia w/ uid: 65534, gid: 65534 and chmod 0755

2022-03-12T01:23:01.595 app[f41cf0c2] sea [info] 2022/03/12 01:23:01 listening on [fdaa:0:4179:a7b:2d30:0:a70b:2]:22 (DNS: [fdaa::3]:53)

2022-03-12T01:23:04.956 app[f41cf0c2] sea [info] 01:23:04.956 [info] Running AppWeb.Endpoint with cowboy 2.9.0 at :::8080 (http)

2022-03-12T01:23:04.959 app[f41cf0c2] sea [info] 01:23:04.958 [info] Access AppWeb.Endpoint at http://app.fly.dev:443

2022-03-12T01:23:04.961 app[f41cf0c2] sea [info] Mnesia('app@fdaa:0:4179:a7b:2d30:0:a70b:2'): Data may be missing, Corrupt logfile deleted: <<"/mnesia/LATEST.LOG">>, {badarg,

2022-03-12T01:23:04.961 app[f41cf0c2] sea [info] [{file,

2022-03-12T01:23:04.961 app[f41cf0c2] sea [info] <<"/mnesia/LATEST.LOG">>},

2022-03-12T01:23:04.961 app[f41cf0c2] sea [info] {name,

2022-03-12T01:23:04.961 app[f41cf0c2] sea [info] latest_log},

2022-03-12T01:23:04.961 app[f41cf0c2] sea [info] {repair,

2022-03-12T01:23:04.961 app[f41cf0c2] sea [info] true},

2022-03-12T01:23:04.961 app[f41cf0c2] sea [info] {mode,

2022-03-12T01:23:04.961 app[f41cf0c2] sea [info] read_write}]}

2022-03-12T01:23:05.001 app[f41cf0c2] sea [info] 01:23:05.000 [error] Mnesia(:"app@fdaa:0:4179:a7b:2d30:0:a70b:2"): ** ERROR ** (core dumped to file: '/app/bin/MnesiaCore.app@fdaa:0:4179:a7b:2d30:0:a70b:2_1647_48184_986453')

2022-03-12T01:23:05.001 app[f41cf0c2] sea [info] ** FATAL ** Cannot open log file "/mnesia/LATEST.LOG": {:badarg,

2022-03-12T01:23:05.001 app[f41cf0c2] sea [info] [

2022-03-12T01:23:05.001 app[f41cf0c2] sea [info] file: "/mnesia/LATEST.LOG",

2022-03-12T01:23:05.001 app[f41cf0c2] sea [info] name: :latest_log,

2022-03-12T01:23:05.001 app[f41cf0c2] sea [info] repair: false,

2022-03-12T01:23:05.001 app[f41cf0c2] sea [info] mode: :read_write

2022-03-12T01:23:05.001 app[f41cf0c2] sea [info] ]}

2022-03-12T01:23:05.581 app[f41cf0c2] sea [info] Reaped child process with pid: 583 and signal: SIGUSR1, core dumped? false

2022-03-12T01:23:06.337 app[f41cf0c2] sea [info] 01:23:06.336 [info] Plug.SSL is redirecting GET / to https://app.com with status 301

2022-03-12T01:23:07.028 app[f41cf0c2] sea [info] {:erlang, :send, [:mnesia_locker, {:release_tid, {:tid, 3, #PID<0.2469.0>}}],

2022-03-12T01:23:07.028 app[f41cf0c2] sea [info] [error_info: %{module: :erl_erts_errors}]},

2022-03-12T01:23:07.028 app[f41cf0c2] sea [info] {:mnesia_locker, :release_tid, 1, [file: 'mnesia_locker.erl', line: 125]},

2022-03-12T01:23:07.028 app[f41cf0c2] sea [info] {:mnesia_tm, :handle_exit, 3, [file: 'mnesia_tm.erl', line: 575]},

2022-03-12T01:23:07.028 app[f41cf0c2] sea [info] {:mnesia_sp, :init_proc, 4, [file: 'mnesia_sp.erl', line: 34]},

2022-03-12T01:23:07.028 app[f41cf0c2] sea [info] ]} state: [#PID<0.2243.0>]

This seems much more opaque than the previous issues.

10

I just spent hours debugging this issue :slight_smile:

So instead of config :mnesia, dir: "/mnesia",
we should do config :mnesia, dir: '/mnesia' ← notice the single quote, it must be a char list not a string.

The example from the doc:

config :mnesia, dir: '/path/to/dir'

And by looking at the Distribution section, it says:

config :mnesia, dir: to_charlist(System.get_env("MNESIA_DIR"))
11

Holy moly, thanks for sharing this very easy to miss