(CaseClauseError) no case clause matching: {:done, 1} in SSHKit.SCP.Download.process_data/3

[d4rk5eed]

Hello
Can't get the reason for matching failure in channel loop.
It's some sort of heisenbug cause encounter it in 3-4 case of 90.
And yes, source file is unavailable, but it shoud be {:error, reason} result.

13:53:26.842 [error] Task #PID<0.379.0> started from #PID<0.326.0> terminating                                                                                                                                                               
** (CaseClauseError) no case clause matching: {:done, 1}                                                                                                                                                                                     
    (sshkit) lib/sshkit/scp/download.ex:54: SSHKit.SCP.Download.process_data/3                                                                                                                                                               
    (sshkit) lib/sshkit/ssh/channel.ex:224: SSHKit.SSH.Channel.loop/4                                                                                                                                                                        
    (sshkit) lib/sshkit/ssh.ex:125: SSHKit.SSH.run/3                                                                                                                                                                                         
    (zc_connector) lib/zc_connector/fetcher.ex:84: ZcConnector.Fetcher.send_file/2                                                                                                                                                           
    (elixir) lib/task/supervised.ex:85: Task.Supervised.do_apply/2                                                                                                                                                                           
    (elixir) lib/task/supervised.ex:36: Task.Supervised.reply/5                                                                                                                                                                              
    (stdlib) proc_lib.erl:247: :proc_lib.init_p_do_apply/3                                                                                                                                                                                   
Function: &ZcConnector.Fetcher.send_file/2                                                                                                                                                                                                   
    Args: [%SSHKit.SSH.Connection{host: 'X.X.X.X', options: [user_interaction: false, user: 'admin'], port: 22, ref: #PID<0.372.0>, ssh_modules: %{ssh: :ssh, ssh_connection: :ssh_connection}}, %ZcConnector.Couples{__meta__: #Ecto.Schema.Metadata<:loaded, "callrec", "couples">, callid: 34, callingnr: "6557", created_ts: #DateTime<2017-10-27 10:51:18.891499Z>, direction: "UNKNOWN", id: 34, length: 20, originalcallednr: "6566", start_ts: #DateTime<2017-10-27 10:50:58.383000Z>, stop_ts: #DateTime<2017-10-27 10:51:18.859000Z>, timeofday: 49858}]  

reproducible on sshkit ~> 0.0.3 (Hex package)

[pmeinhardt]

Hi there @d4rk5eed 👋 Sorry for the late reply, we are quite busy at the moment.
Thanks a lot for using SSHKit.ex and reporting this issue 🤘

To make sure I understand the scenario:

You are trying to download a file from a remote path which does not exist to your local host.
When you do that, you get the above error.
Instead, of getting an error expect the result of the download call to be {:error, reason}.

Is that correct?

I tried to recreate that behaviour using a functional test case:

diff --git a/test/sshkit/scp_functional_test.exs b/test/sshkit/scp_functional_test.exs
index a3d2821..f2327dc 100644
--- a/test/sshkit/scp_functional_test.exs
+++ b/test/sshkit/scp_functional_test.exs
@@ -73,6 +73,19 @@ defmodule SSHKit.SCPFunctionalTest do
       end
     end

+    @tag boot: 1
+    test "gracefully fails if the remove path does not exist", %{hosts: [host]} do
+      options = @defaults ++ [port: host.port, user: host.user, password: host.password]
+      remote = "/fixtures/nothere.txt"
+      local = create_local_tmp_path()
+      on_exit fn -> File.rm(local) end
+
+      SSH.connect host.ip, options, fn(conn) ->
+        assert {:error, reason} = SCP.download(conn, remote, local)
+        IO.puts reason
+      end
+    end
+
     @tag boot: 1
     test "recursive: true", %{hosts: [host]} do
       options = @defaults ++ [port: host.port, user: host.user, password: host.password]

Unfortunately, I was not able to reproduce the error you describe yet.
The assertion is successful (the download fails with {:error, reason}) and the IO.puts reports:

Invalid SCP directive received: scp: /fixtures/nothere.txt: No such file or directory

I am probably missing some detail or misunderstood the scenario. Please correct me!

Maybe you can take the test case above as a starting point and and adapt it to reproduce your issue as an automated test? It is also possible, that the test environment behaves differently from what you are seeing, so more details on the host operating systems, SSH versions and other context information could really help.

Thank you 🙂

[pmeinhardt]

Hi @d4rk5eed, I am still not sure what we can do here at the moment since we cannot reproduce the issue reliably. If I had to guess, I'd say it sounds a bit like the server might be sending control messages in a different order than what we expect?

As a brief update: I am planning to work on SCP unit tests in the following weeks and will see if I can reproduce it reliably there (with the functional tests it is apparently difficult like you pointed out: "in 3-4 cases out of 90").

If you have any additional insights in the meanwhile, I'd be super happy if you could share them (e.g. try logging SCP transfer state and incoming message?).

Cheers 👋

PS: I'm obviously curious to hear what you're building with SSHKit as well 🙂