Elvish: Daemon connectivity problems

[southpawflo]

after installing elvish on bash/windows subsystem for linux I am greeted with this warning:

warning: socket exists but not responding version RPC: dial unix /tmp/elvish-1000/sock: connect: connection refused

followed by this error:

Failed to initialize command history. Disabled.

this question is did I do something incorrectly, or does this stem from the wsl?

[vcg3rd]

Originally I got this error:
warning: cannot start daemon: cannot find elvish: not found cannot connect to daemon after 1s: dial unix /tmp/elvish-1000/sock: connect: no such file or directory

After creating the directory sock in /tmp/elvish-1000 I got your error above. When I exit I get the following, which may have nothing to do with anything--it's gibberish to me--but just in case:

panic: runtime error: invalid memory address or nil pointer dereference [recovered] panic: runtime error: invalid memory address or nil pointer dereference [signal SIGSEGV: segmentation violation code=0x1 addr=0x0 pc=0x74f586] goroutine 37 [running]: github.com/elves/elvish/eval.catch(0xc420041f80, 0xc420396500) /home/travis/gopath/src/github.com/elves/elvish/eval/eval.go:312 +0x241 panic(0x92ee40, 0xdf6080) /home/travis/.gimme/versions/go1.8.linux.amd64/src/runtime/panic.go:489 +0x2cf net/rpc.(*Client).Close(0x0, 0x10, 0xc4203922e0) /home/travis/.gimme/versions/go1.8.linux.amd64/src/net/rpc/client.go:280 +0x26 github.com/elves/elvish/daemon/api.(*Client).Close(0xc420121680, 0x7f5e64195e10, 0x0) /home/travis/gopath/src/github.com/elves/elvish/daemon/api/client.go:44 +0x43 github.com/elves/elvish/eval.preExit(0xc420396500) /home/travis/gopath/src/github.com/elves/elvish/eval/builtin_fn.go:1406 +0x36 github.com/elves/elvish/eval.exit.func1(0x0) /home/travis/gopath/src/github.com/elves/elvish/eval/builtin_fn.go:1280 +0x2a github.com/elves/elvish/eval.exit(0xc420396500, 0x0, 0x0, 0x0, 0xc420366300) /home/travis/gopath/src/github.com/elves/elvish/eval/builtin_fn.go:1285 +0x14c github.com/elves/elvish/eval.(*BuiltinFn).Call(0xc42012e660, 0xc420396500, 0x0, 0x0, 0x0, 0xc420366300) /home/travis/gopath/src/github.com/elves/elvish/eval/builtin_fn.go:55 +0x5c github.com/elves/elvish/eval.String.Call(0xc42016ba28, 0x4, 0xc420396500, 0x0, 0x0, 0x0, 0xc420366300) /home/travis/gopath/src/github.com/elves/elvish/eval/string.go:60 +0x89 github.com/elves/elvish/eval.(*String).Call(0xc420390100, 0xc420396500, 0x0, 0x0, 0x0, 0xc420366300) <autogenerated>:34 +0x88 github.com/elves/elvish/eval.(*compiler).form.func3(0xc420396500) /home/travis/gopath/src/github.com/elves/elvish/eval/compile_op.go:266 +0x8f5 github.com/elves/elvish/eval.Op.Exec(0xc4203a8000, 0x0, 0x4, 0xc420396500) /home/travis/gopath/src/github.com/elves/elvish/eval/compile_op.go:23 +0x45 github.com/elves/elvish/eval.(*EvalCtx).PEval(0xc420396500, 0xc4203a8000, 0x0, 0x4, 0x0, 0x0) /home/travis/gopath/src/github.com/elves/elvish/eval/eval.go:281 +0x98 github.com/elves/elvish/eval.(*compiler).pipeline.func1.1(0xc420396500, 0xc4203a8000, 0x0, 0x4, 0xc42039e030, 0xc420390120) /home/travis/gopath/src/github.com/elves/elvish/eval/compile_op.go:85 +0x4d created by github.com/elves/elvish/eval.(*compiler).pipeline.func1 /home/travis/gopath/src/github.com/elves/elvish/eval/compile_op.go:92 +0x2c7

OS: Linux Mint 18.1 Serena x86_64
Model: GA-78LMT-USB3
Kernel: 4.4.0-81-generic
CPU: AMD FX-6300 (6) @ 3.500GHz

[zhsj]

Did you put elvish binary at your PATH, eg /usr/bin, /usr/local/bin

I think this common error should be addressed somewhere or let elvish to find its binary. @xiaq

[southpawflo]

my path is correctly set up, and the shell works for me (at least, for the 10 min I had to play with at the time). I'm not entirely sure what the socket warning deals with, I haven't dealt in depth with sockets at all, but the command history definitely does not work for me right now. I have also installed elvish on my mac with homebrew and everything works fine there.

[narzeja]

Maybe related, but I also got this error:
warning: cannot start daemon: cannot find elvish: not found cannot connect to daemon after 1s: dial unix /tmp/elvish-1000/sock: connect: no such file or directory

I took a look in the latest /tmp/elvish-1000/daemon.log and saw this:
[daemon] 2017/07/11 10:48:16 failed to create storage: failed to initialize command history table: database is locked

Then removed the following directory $HOME/.elvish/db.lock. That seemed to solve it for now.

[zzamboni]

I have encountered this a couple of times, it would seem like the daemon dies leaving behind the socket but with no process behind it. Usually removing the elvish tmp directory makes it work again.

[markkuit]

This keeps happening to me whenever I don't use the shell for some time (at least several hours). Any way to permanently fix it rather than deleting the sock every time it happens?

[xiaq]

@markkuit Related code has changed several times; can you update to HEAD and start from clean state (kill all elvish processes, remove temp directories) and see if this still happens?

[xiaq]

More details: This bug is caused by either the daemon failing to start up, or the daemon crashing after startup. The former case is caused by #496 most of the time, which is now fixed.

In the latter case, the daemon may have left some logs in the temporary file: look at /tmp/elvish-(id -u) to see if there are files named daemon.log.* and paste the content here.

[adracea]

Okay , I'm able to easily replicate this on my phone running termux , boot elvish and then force remove termux from memory : this one is from normally exiting elvish before closing termux
[daemon] 2017/12/15 07:41:47 No active client, daemon exit
[daemon] 2017/12/15 07:41:47 listener closed, waiting to exit
[daemon] 2017/12/15 07:41:47 Failed to accept: &net.OpError{Op:"accept", Net:"unix", Source:net.Addr(nil), Addr:(net.UnixAddr)(0x44201a0c00), Err:(errors.errorString)(0x44200340f0)}
[daemon] 2017/12/15 07:41:47 exiting

This is how it looks like when I force close termux and don't exit elvish :
[daemon] 2017/12/15 18:49:47 pid is 4138
[daemon] 2017/12/15 18:49:47 going to listen /data/data/com.termux/files/usr/tmp/elvish-10201/sock
[store] 2017/12/15 18:49:47 initializing store
[store] 2017/12/15 18:49:47 initialized store
[daemon] 2017/12/15 18:49:47 starting to serve RPC calls

And then nothing . Hope this helps .

[adracea]

I think that the root cause is in the fact that when the parent process goes into a certain state or gets killed , the daemon fails to close the socket and then can't open it again .
From my 2nd termux instance I manually sent sigterm to the 1st termux process hosting and elvish that couldn't connect to the socket . Upon re-opening termux and starting elvish , apparently the socket got closed when sending manual sigterm even if it wasn't connected .

[adracea]

@xiaq The culprit seems to be the daemon getting killed before the elvish instances connected to it .The sock gets closed but the file remains there making it think that there is a daemon running, when a new elvish instance finds it , it can't connect . To easily reproduce : kill -s SIGKILL . I'll try to come up with a fix but I think that there's a few things to take into consideration like when and where the sock should be handled . Any suggestions ? I was currently thinking of handling it at runtime .

[xiaq]

Right, when the client tries to connect to the daemon, it only checks the existence of the socket file to determine a daemon should be spawned.

Normally, when the daemon gets terminated by SIGTERM or quits itself automatically, the socket file is removed; but if it is killed with SIGKILL the socket file is not, leaving the client thinking that a daemon is still running.

We can use a more sophisticated daemon status check; I can think of two ways:

1. Not only check the existence of the socket file but also attempt to connect to it: if connection fails, remove the socket and spawn a daemon. However, this may suffer from false negative where the daemon is running but unresponsive:

   i. A code bug causes daemons to become unresponsive shortly after startup. Now each Elvish instance will now start a daemon. This is quite unlikely though, given that the daemon implementation is basically handleFlags(); for { client = accept(); go handle(client) }.

   ii. The daemon has become overloaded. In this case, the newly spawned daemon will not have access to the database (boltdb does not support concurrent access from multiple processes). The new daemon won't quit, however; it just accepts connections and return errors for RPCs that need to access the database. The old daemon continues to serve Elvish instances that were talking to it but won't accept new connections. This is not exactly a good failure mode, but doesn't sound too problematic.

2. Write a PID file when daemon starts up. Instead of checking if the socket file exists, check if the process is running; if it is not, then remove the socket and PID file, and spawn a daemon. This, on the other hand, may have false positive as PIDs can be reused. It can be somewhat mitigated, however, by checking certain properties of the process (e.g. whether the command line contains elvish -daemon).

We can also use a combination of both techniques:

func autoSpawn() {
  if socket file does not exist {
    print to debug log "auto-spawned daemon"
    spawn()
    return
  }
  if connection to socket succeeds {
    return
  }
  if process with pid is running {
    if process looks elvish daemon {
      print to user "daemon is running but cannot be connected to"
      // don't spawn
      return
    }
    print to user "pid exists but does not look like elvish daemon, considering daemon dead"
  }
  print to user "daemon is dead, auto-spawning"
  remove socket and pid files
  spawn()
}

This eliminates the possibility of false negative of 1, although it has the same false positive problem of 2.

[adracea]

Hmm...I was thinking of making it simpler , I was looking at the runtime.go check where the os.Stat(sockpath) happens , the result of os.Stat(sockpath) seems to modify each time a new client opens on an active socket(os.Stat returns FileInfo , which has a Sys() component that seems to be the interface of the underlying data source ) , since anything we do results in a change in the output of os.Stat.Sys() while the daemon is active , but it is the same if it has no daemon attached to it. Ex :

Here is an active daemon :
&{sock 0 16777664 {641040709 63649206681 0xbbeaa0} {35 18648850 1 49600 0 0 0 0 0 4096 0{1513609897 857707376}{1513609881 641040709} {1513609881 641040709} [0 0 0]}}

&{sock 0 16777664 {641040709 63649206681 0xbbeaa0} {35 18648850 1 49600 0 0 0 0 0 4096 0{1513609917 941040709}{1513609881 641040709} {1513609881 641040709} [0 0 0]}}

For an inactive daemon , the socket remains unmodified so I was thinking we could use this to our advantage and "profile" the daemon's state that way ? Although , I think that we can just fix this by just adjusting the error handling . I already made a "fix" for just checking this case and it seems like even the initial elvish that had his daemon killed is able to reconnect :smile: . I'll make a pull request with my "sort-of" fix :) .

[xiaq]

Handling of dead daemons have been improved, closing as fixed.

[theAkito]

Experiencing exact same issue as OP as of v0.12-508-g14121baa a.k.a. 14121baa. Running rm -r /tmp/elvish-* works as a workaround, but it seems like the issue is not really _fixed_, after all.

[dangerousHobo]

I'm on HEAD and see this message still when I launch my first elvish shell, even after a reboot and no /tmp/elvish-*

Cannot connect to daemon: daemon unreachable after waiting for 1s
Daemon-related functions will likely not work.

[krader1961]

@dangerousHobo It's been my experience this only happens if you launch two elvish instances more or less simultaneously. For example, I use a shell script to setup multiple tmux sessions to all the systems I use for development. This involves starting six interactive shells on each system as quickly as possible. This would frequently result in the failure discussed in this issue on at least one system (typically my Windows+MSYS platform). After I modified that script to sleep one second after starting the first elvish instance on each platform I stopped seeing this failure.

Rather than fix this race condition in the long term I'd like to see the daemon eliminated. It appears to exist solely due to the database that is used for storing interactive history. If it were replaced with a database that allowed concurrent access from multiple clients the daemon wouldn't be necessary.

[s-oram]

I saw this or a similar problem on Windows.

Cannot connect to daemon: unexpected RPC error on socket C:\Users\John\AppData\Local\Temp\elvish-John\sock: dial .
Daemon-related functions will likely not work.

Deleting the C:\Users\John\AppData\Local\Temp\elvish-John directory resolved my daemon connectivity issues.