UploadWriter fails silently with System.cmd (or I'm holding it wrong)

I’ve written a custom UploadWriter to handle some tasks that can be done during upload and very quickly on close. It passes tests ands leaves behind the correct artifacts (upload to an external store, DB changes, telemetry, and files) on form submission. That’s awesome!

What’s not awesome is that it fails silently (I’m not seeing any logs) such that the upload entry is missing when I get to handle_event("save"...). I’ve narrowed down what’s failing to the use of System.cmd (System.shell also fails in the same way, not surprising) and have created a repro that looks the same in the phoenix_live_view codebase. My code does more than echo, but this is the minimal repro.

    @impl true
    def close(test_name, reason) do
      send(test_name, {:close, reason})
      System.cmd("echo", ["hi"])
      {:ok, test_name}
    end

Example failure:

2) test lv with valid token writer can be configured (Phoenix.LiveView.UploadChannelTest)
     test/phoenix_live_view/upload/channel_test.exs:753
     Assertion with =~ failed
     code:  assert render_upload(avatar, "foo.jpeg", 50) =~ "#{@context}:foo.jpeg:100%"
     left:  "<div id=\"phx-F_yS5mRy8ZF98QDk\" data-phx-session=\"SFMyNTY.g2gDaAJhBXQAAAAIZAACaWRtAAAAFHBoeC1GX3lTNW1SeThaRjk4UURrZAAMbGl2ZV9zZXNzaW9uZAADbmlsZAAKcGFyZW50X3BpZGQAA25pbGQACHJvb3RfcGlkZAADbmlsZAAJcm9vdF92aWV3ZAAuRWxpeGlyLlBob2VuaXguTGl2ZVZpZXdUZXN0LlN1cHBvcnQuVXBsb2FkTGl2ZWQABnJvdXRlcmQAA25pbGQAB3Nlc3Npb250AAAAAGQABHZpZXdkAC5FbGl4aXIuUGhvZW5peC5MaXZlVmlld1Rlc3QuU3VwcG9ydC5VcGxvYWRMaXZlbgYAHMW7bZIBYgABUYA.gcGGKYV-ZmdfvdFKFWZ9F9vdxp3mtEjOJIkg3xptyqI\" data-phx-static=\"SFMyNTY.g2gDaAJhBXQAAAADZAAKYXNzaWduX25ld2pkAAVmbGFzaHQAAAAAZAACaWRtAAAAFHBoeC1GX3lTNW1SeThaRjk4UURrbgYAHMW7bZIBYgABUYA.5yoXxILzwUvoaZtt7-eAGLUW9kFRUP3hnI9WDKiScgQ\"><form phx-change=\"validate\" phx-submit=\"save\"><input id=\"phx-F_yS5mSWgbz5wQEE\" type=\"file\" name=\"avatar\" data-phx-hook=\"Phoenix.LiveFileUpload\" data-phx-update=\"ignore\" data-phx-upload-ref=\"phx-F_yS5mSWgbz5wQEE\" data-phx-active-refs=\"\" data-phx-done-refs=\"\" data-phx-preflighted-refs=\"\"/><button type=\"submit\">save</button></form></div>"
     right: "lv:foo.jpeg:100%"
     stacktrace:
       test/phoenix_live_view/upload/channel_test.exs:764: (test)

cmd can be called in either close, meta, or write_chunk and cause the silent failure. meta does actually cause an error about a server PID being missing, but I’m not familiar enough with Elixir to interpret that.

Any suggestions on where to look next or what I might be doing wrong? I didn’t see anything in Phoenix.LiveView.UploadChannel that looked particularly relevant, but my guess is the process is getting closed prematurely somehow.

Oh and to clarify the problem with it missing as an upload_entry is that any consumer_upload_entries call fails, so I can’t get that metadata out of the UploadWriter :confused:

Okay. Finally came up with a (hacky?) solution. System.cmd uses Port, which will, usefully, tell you when it finishes with nice messages (docs). Unfortunately, that message ends up in the UploadChannel inbox. That causes an exit we didn’t want for the writer :grimacing:

If I wrap the System.cmd usage in a GenServer not linked to the writer, then that message isn’t received. Wonderful. In testing, I did this with GenServer.start(SimpleSystemRunner, []). In production, I’m going to write a simple GenServer for my system calls (all to ffmpeg in this case) so it can sit under the app’s supervision tree. I think that’s less hacky.