envoy -p fails: "envoy: agent failed to start, check envoyd's log"

[blueyed]

From time to time envoy -p starts to fail for me. I am using it in ~/.zshrc:

envoy: agent failed to start, check envoyd's log

journalctl /usr/bin/envoyd gives me:

Dec 18 20:06:45 a.example.com envoyd[1336]: Agent gpg-agent for uid=1000 has terminated. Restarting...
Dec 18 20:06:45 a.example.com envoyd[1336]: Starting gpg-agent for uid=1000.
Dec 18 20:06:45 a.example.com envoyd[1336]: Unit envoy-gpg-agent-monitor-1000.scope already exists.gpg-agent[4488]: enabled debug flags: command mpi crypto memory cache memstat hashing ipc
Dec 18 20:06:45 a.example.com envoyd[1336]: gpg-agent: a gpg-agent is already running - not starting a new one
Dec 18 20:06:45 a.example.com envoyd[1336]: gpg-agent: random usage: poolsize=600 mixed=0 polls=0/0 added=0/0
Dec 18 20:06:45 a.example.com envoyd[1336]: outmix=0 getlvl1=0/0 getlvl2=0/0
Dec 18 20:06:45 a.example.com envoyd[1336]: gpg-agent: secmem usage: 0/32768 bytes in 0 blocks
Dec 18 20:06:45 a.example.com envoyd[1336]: gpg-agent exited with status 2.

And with debug-level guru in ~/.gnupg/gpg-agent.conf I get this in the log-file:

2015-12-18 20:06:45 gpg-agent[1339] handler 0x7f76c8b7f700 for fd 9 started
2015-12-18 20:06:45 gpg-agent[1339] DBG: chan_9 -> OK Pleased to meet you, process 4488
2015-12-18 20:06:45 gpg-agent[4488] DBG: chan_5 <- OK Pleased to meet you, process 4488
2015-12-18 20:06:45 gpg-agent[4488] DBG: chan_5 -> BYE
2015-12-18 20:06:45 gpg-agent[1339] DBG: chan_9 <- BYE
2015-12-18 20:06:45 gpg-agent[1339] DBG: chan_9 -> OK closing connection
2015-12-18 20:06:45 gpg-agent[1339] handler 0x7f76c8b7f700 for fd 9 terminated

The journalctl after a reboot:

-- Reboot --
Dec 18 19:47:04 a.example.com envoyd[1336]: Starting gpg-agent for uid=1000.
Dec 18 19:47:04 a.example.com envoyd[1336]: gpg-agent[1337]: enabled debug flags: command mpi crypto memory cache memstat hashing ipc
Dec 18 19:59:40 a.example.com envoyd[1336]: Agent gpg-agent for uid=1000 has terminated. Restarting...
Dec 18 19:59:40 a.example.com envoyd[1336]: Starting gpg-agent for uid=1000.
Dec 18 19:59:40 a.example.com envoyd[1336]: Unit envoy-gpg-agent-monitor-1000.scope already exists.gpg-agent[2000]: enabled debug flags: command mpi crypto memory cache memstat hashing ipc
Dec 18 19:59:40 a.example.com envoyd[1336]: gpg-agent: a gpg-agent is already running - not starting a new one
Dec 18 19:59:40 a.example.com envoyd[1336]: gpg-agent: random usage: poolsize=600 mixed=0 polls=0/0 added=0/0
Dec 18 19:59:40 a.example.com envoyd[1336]: outmix=0 getlvl1=0/0 getlvl2=0/0
Dec 18 19:59:40 a.example.com envoyd[1336]: gpg-agent: secmem usage: 0/32768 bytes in 0 blocks
Dec 18 19:59:40 a.example.com envoyd[1336]: gpg-agent exited with status 2.

From the gpg-agent.log:

2015-12-18 19:47:07 gpg-agent[1339] DBG: rsa_verify    => Good
2015-12-18 19:47:07 gpg-agent[1339] ssh request handler for sign_request (13) ready
2015-12-18 19:47:09 gpg-agent[1339] handler 0x7f76c9380700 for fd 9 started
2015-12-18 19:47:09 gpg-agent[1339] DBG: chan_9 -> OK Pleased to meet you, process 1488
2015-12-18 19:47:09 gpg-agent[1339] DBG: chan_9 <- RESET
2015-12-18 19:47:09 gpg-agent[1339] DBG: chan_9 -> OK
2015-12-18 19:47:09 gpg-agent[1339] DBG: chan_9 <- OPTION ttyname=/dev/pts/0
2015-12-18 19:47:09 gpg-agent[1339] DBG: chan_9 -> OK
2015-12-18 19:47:09 gpg-agent[1339] DBG: chan_9 <- OPTION ttytype=rxvt-unicode-256color
2015-12-18 19:47:09 gpg-agent[1339] DBG: chan_9 -> OK
2015-12-18 19:47:09 gpg-agent[1339] DBG: chan_9 <- OPTION display=:0
2015-12-18 19:47:09 gpg-agent[1339] DBG: chan_9 -> OK
2015-12-18 19:47:09 gpg-agent[1339] DBG: chan_9 <- OPTION xauthority=/home/user/.Xauthority
2015-12-18 19:47:09 gpg-agent[1339] DBG: chan_9 -> OK
2015-12-18 19:47:09 gpg-agent[1339] DBG: chan_9 <- UPDATESTARTUPTTY
2015-12-18 19:47:09 gpg-agent[1339] DBG: chan_9 -> OK
2015-12-18 19:47:09 gpg-agent[1339] DBG: chan_9 <- [eof]
2015-12-18 19:47:09 gpg-agent[1339] handler 0x7f76c9380700 for fd 9 terminated
2015-12-18 19:48:06 gpg-agent[1339] handler 0x7f76c8b7f700 for fd 11 started
2015-12-18 19:48:06 gpg-agent[1339] DBG: chan_11 -> OK Pleased to meet you, process 1339
2015-12-18 19:48:06 gpg-agent[1339] DBG: chan_9 <- OK Pleased to meet you, process 1339
2015-12-18 19:48:06 gpg-agent[1339] DBG: chan_9 -> GETINFO pid
2015-12-18 19:48:06 gpg-agent[1339] DBG: chan_11 <- GETINFO pid
2015-12-18 19:48:06 gpg-agent[1339] DBG: chan_11 -> D 1339
2015-12-18 19:48:06 gpg-agent[1339] DBG: chan_11 -> OK
2015-12-18 19:48:06 gpg-agent[1339] DBG: chan_9 <- D 1339
2015-12-18 19:48:06 gpg-agent[1339] DBG: chan_9 <- OK
2015-12-18 19:48:06 gpg-agent[1339] DBG: chan_9 -> BYE
2015-12-18 19:48:06 gpg-agent[1339] DBG: chan_11 <- BYE
2015-12-18 19:48:06 gpg-agent[1339] DBG: chan_11 -> OK closing connection
2015-12-18 19:48:06 gpg-agent[1339] handler 0x7f76c8b7f700 for fd 11 terminated
2015-12-18 19:49:06 gpg-agent[1339] handler 0x7f76c9380700 for fd 11 started
2015-12-18 19:49:06 gpg-agent[1339] DBG: chan_11 -> OK Pleased to meet you, process 1339
2015-12-18 19:49:06 gpg-agent[1339] DBG: chan_9 <- OK Pleased to meet you, process 1339
2015-12-18 19:49:06 gpg-agent[1339] DBG: chan_9 -> GETINFO pid
2015-12-18 19:49:06 gpg-agent[1339] DBG: chan_11 <- GETINFO pid
2015-12-18 19:49:06 gpg-agent[1339] DBG: chan_11 -> D 1339
2015-12-18 19:49:06 gpg-agent[1339] DBG: chan_11 -> OK
2015-12-18 19:49:06 gpg-agent[1339] DBG: chan_9 <- D 1339
2015-12-18 19:49:06 gpg-agent[1339] DBG: chan_9 <- OK
2015-12-18 19:49:06 gpg-agent[1339] DBG: chan_9 -> BYE
2015-12-18 19:49:06 gpg-agent[1339] DBG: chan_11 <- BYE
2015-12-18 19:49:06 gpg-agent[1339] DBG: chan_11 -> OK closing connection
2015-12-18 19:49:06 gpg-agent[1339] handler 0x7f76c9380700 for fd 11 terminated
2015-12-18 19:50:06 gpg-agent[1339] handler 0x7f76c8b7f700 for fd 11 started
2015-12-18 19:50:06 gpg-agent[1339] DBG: chan_11 -> OK Pleased to meet you, process 1339
2015-12-18 19:50:06 gpg-agent[1339] DBG: chan_9 <- OK Pleased to meet you, process 1339
2015-12-18 19:50:06 gpg-agent[1339] DBG: chan_9 -> GETINFO pid
2015-12-18 19:50:06 gpg-agent[1339] DBG: chan_11 <- GETINFO pid
2015-12-18 19:50:06 gpg-agent[1339] DBG: chan_11 -> D 1339
2015-12-18 19:50:06 gpg-agent[1339] DBG: chan_11 -> OK
2015-12-18 19:50:06 gpg-agent[1339] DBG: chan_9 <- D 1339
2015-12-18 19:50:06 gpg-agent[1339] DBG: chan_9 <- OK
2015-12-18 19:50:06 gpg-agent[1339] DBG: chan_9 -> BYE
2015-12-18 19:50:06 gpg-agent[1339] DBG: chan_11 <- BYE
2015-12-18 19:50:06 gpg-agent[1339] DBG: chan_11 -> OK closing connection
2015-12-18 19:50:06 gpg-agent[1339] handler 0x7f76c8b7f700 for fd 11 terminated
2015-12-18 19:51:06 gpg-agent[1339] handler 0x7f76c9380700 for fd 11 started
2015-12-18 19:51:06 gpg-agent[1339] DBG: chan_11 -> OK Pleased to meet you, process 1339
2015-12-18 19:51:06 gpg-agent[1339] DBG: chan_9 <- OK Pleased to meet you, process 1339
2015-12-18 19:51:06 gpg-agent[1339] DBG: chan_9 -> GETINFO pid
2015-12-18 19:51:06 gpg-agent[1339] DBG: chan_11 <- GETINFO pid
2015-12-18 19:51:06 gpg-agent[1339] DBG: chan_11 -> D 1339
2015-12-18 19:51:06 gpg-agent[1339] DBG: chan_11 -> OK
2015-12-18 19:51:06 gpg-agent[1339] DBG: chan_9 <- D 1339
2015-12-18 19:51:06 gpg-agent[1339] DBG: chan_9 <- OK
2015-12-18 19:51:06 gpg-agent[1339] DBG: chan_9 -> BYE
2015-12-18 19:51:06 gpg-agent[1339] DBG: chan_11 <- BYE
2015-12-18 19:51:06 gpg-agent[1339] DBG: chan_11 -> OK closing connection
2015-12-18 19:51:06 gpg-agent[1339] handler 0x7f76c9380700 for fd 11 terminated
2015-12-18 19:52:06 gpg-agent[1339] handler 0x7f76c8b7f700 for fd 11 started
2015-12-18 19:52:06 gpg-agent[1339] DBG: chan_11 -> OK Pleased to meet you, process 1339
2015-12-18 19:52:06 gpg-agent[1339] DBG: chan_9 <- OK Pleased to meet you, process 1339
2015-12-18 19:52:06 gpg-agent[1339] DBG: chan_9 -> GETINFO pid
2015-12-18 19:52:06 gpg-agent[1339] DBG: chan_11 <- GETINFO pid
2015-12-18 19:52:06 gpg-agent[1339] DBG: chan_11 -> D 1339
2015-12-18 19:52:06 gpg-agent[1339] DBG: chan_11 -> OK
2015-12-18 19:52:06 gpg-agent[1339] DBG: chan_9 <- D 1339
2015-12-18 19:52:06 gpg-agent[1339] DBG: chan_9 <- OK
2015-12-18 19:52:06 gpg-agent[1339] DBG: chan_9 -> BYE
2015-12-18 19:52:06 gpg-agent[1339] DBG: chan_11 <- BYE
2015-12-18 19:52:06 gpg-agent[1339] DBG: chan_11 -> OK closing connection
2015-12-18 19:52:06 gpg-agent[1339] handler 0x7f76c8b7f700 for fd 11 terminated
2015-12-18 19:53:06 gpg-agent[1339] handler 0x7f76c9380700 for fd 11 started
2015-12-18 19:53:06 gpg-agent[1339] DBG: chan_11 -> OK Pleased to meet you, process 1339
2015-12-18 19:53:06 gpg-agent[1339] DBG: chan_9 <- OK Pleased to meet you, process 1339
2015-12-18 19:53:06 gpg-agent[1339] DBG: chan_9 -> GETINFO pid
2015-12-18 19:53:06 gpg-agent[1339] DBG: chan_11 <- GETINFO pid
2015-12-18 19:53:06 gpg-agent[1339] DBG: chan_11 -> D 1339
2015-12-18 19:53:06 gpg-agent[1339] DBG: chan_11 -> OK
2015-12-18 19:53:06 gpg-agent[1339] DBG: chan_9 <- D 1339
2015-12-18 19:53:06 gpg-agent[1339] DBG: chan_9 <- OK
2015-12-18 19:53:06 gpg-agent[1339] DBG: chan_9 -> BYE
2015-12-18 19:53:06 gpg-agent[1339] DBG: chan_11 <- BYE
2015-12-18 19:53:06 gpg-agent[1339] DBG: chan_11 -> OK closing connection
2015-12-18 19:53:06 gpg-agent[1339] handler 0x7f76c9380700 for fd 11 terminated
2015-12-18 19:54:06 gpg-agent[1339] handler 0x7f76c8b7f700 for fd 11 started
2015-12-18 19:54:06 gpg-agent[1339] DBG: chan_11 -> OK Pleased to meet you, process 1339
2015-12-18 19:54:06 gpg-agent[1339] DBG: chan_9 <- OK Pleased to meet you, process 1339
2015-12-18 19:54:06 gpg-agent[1339] DBG: chan_9 -> GETINFO pid
2015-12-18 19:54:06 gpg-agent[1339] DBG: chan_11 <- GETINFO pid
2015-12-18 19:54:06 gpg-agent[1339] DBG: chan_11 -> D 1339
2015-12-18 19:54:06 gpg-agent[1339] DBG: chan_11 -> OK
2015-12-18 19:54:06 gpg-agent[1339] DBG: chan_9 <- D 1339
2015-12-18 19:54:06 gpg-agent[1339] DBG: chan_9 <- OK
2015-12-18 19:54:06 gpg-agent[1339] DBG: chan_9 -> BYE
2015-12-18 19:54:06 gpg-agent[1339] DBG: chan_11 <- BYE
2015-12-18 19:54:06 gpg-agent[1339] DBG: chan_11 -> OK closing connection
2015-12-18 19:54:06 gpg-agent[1339] handler 0x7f76c8b7f700 for fd 11 terminated
2015-12-18 19:55:06 gpg-agent[1339] handler 0x7f76c9380700 for fd 11 started
2015-12-18 19:55:06 gpg-agent[1339] DBG: chan_11 -> OK Pleased to meet you, process 1339
2015-12-18 19:55:06 gpg-agent[1339] DBG: chan_9 <- OK Pleased to meet you, process 1339
2015-12-18 19:55:06 gpg-agent[1339] DBG: chan_9 -> GETINFO pid
2015-12-18 19:55:06 gpg-agent[1339] DBG: chan_11 <- GETINFO pid
2015-12-18 19:55:06 gpg-agent[1339] DBG: chan_11 -> D 1339
2015-12-18 19:55:06 gpg-agent[1339] DBG: chan_11 -> OK
2015-12-18 19:55:06 gpg-agent[1339] DBG: chan_9 <- D 1339
2015-12-18 19:55:06 gpg-agent[1339] DBG: chan_9 <- OK
2015-12-18 19:55:06 gpg-agent[1339] DBG: chan_9 -> BYE
2015-12-18 19:55:06 gpg-agent[1339] DBG: chan_11 <- BYE
2015-12-18 19:55:06 gpg-agent[1339] DBG: chan_11 -> OK closing connection
2015-12-18 19:55:06 gpg-agent[1339] handler 0x7f76c9380700 for fd 11 terminated
2015-12-18 19:56:06 gpg-agent[1339] handler 0x7f76c8b7f700 for fd 11 started
2015-12-18 19:56:06 gpg-agent[1339] DBG: chan_11 -> OK Pleased to meet you, process 1339
2015-12-18 19:56:06 gpg-agent[1339] DBG: chan_9 <- OK Pleased to meet you, process 1339
2015-12-18 19:56:06 gpg-agent[1339] DBG: chan_9 -> GETINFO pid
2015-12-18 19:56:06 gpg-agent[1339] DBG: chan_11 <- GETINFO pid
2015-12-18 19:56:06 gpg-agent[1339] DBG: chan_11 -> D 1339
2015-12-18 19:56:06 gpg-agent[1339] DBG: chan_11 -> OK
2015-12-18 19:56:06 gpg-agent[1339] DBG: chan_9 <- D 1339
2015-12-18 19:56:06 gpg-agent[1339] DBG: chan_9 <- OK
2015-12-18 19:56:06 gpg-agent[1339] DBG: chan_9 -> BYE
2015-12-18 19:56:06 gpg-agent[1339] DBG: chan_11 <- BYE
2015-12-18 19:56:06 gpg-agent[1339] DBG: chan_11 -> OK closing connection
2015-12-18 19:56:06 gpg-agent[1339] handler 0x7f76c8b7f700 for fd 11 terminated
2015-12-18 19:57:06 gpg-agent[1339] handler 0x7f76c9380700 for fd 11 started
2015-12-18 19:57:06 gpg-agent[1339] DBG: chan_11 -> OK Pleased to meet you, process 1339
2015-12-18 19:57:06 gpg-agent[1339] DBG: chan_9 <- OK Pleased to meet you, process 1339
2015-12-18 19:57:06 gpg-agent[1339] DBG: chan_9 -> GETINFO pid
2015-12-18 19:57:06 gpg-agent[1339] DBG: chan_11 <- GETINFO pid
2015-12-18 19:57:06 gpg-agent[1339] DBG: chan_11 -> D 1339
2015-12-18 19:57:06 gpg-agent[1339] DBG: chan_11 -> OK
2015-12-18 19:57:06 gpg-agent[1339] DBG: chan_9 <- D 1339
2015-12-18 19:57:06 gpg-agent[1339] DBG: chan_9 <- OK
2015-12-18 19:57:06 gpg-agent[1339] DBG: chan_9 -> BYE
2015-12-18 19:57:06 gpg-agent[1339] DBG: chan_11 <- BYE
2015-12-18 19:57:06 gpg-agent[1339] DBG: chan_11 -> OK closing connection
2015-12-18 19:57:06 gpg-agent[1339] handler 0x7f76c9380700 for fd 11 terminated
2015-12-18 19:58:07 gpg-agent[1339] handler 0x7f76c8b7f700 for fd 11 started
2015-12-18 19:58:07 gpg-agent[1339] DBG: chan_11 -> OK Pleased to meet you, process 1339
2015-12-18 19:58:07 gpg-agent[1339] DBG: chan_9 <- OK Pleased to meet you, process 1339
2015-12-18 19:58:07 gpg-agent[1339] DBG: chan_9 -> GETINFO pid
2015-12-18 19:58:07 gpg-agent[1339] DBG: chan_11 <- GETINFO pid
2015-12-18 19:58:07 gpg-agent[1339] DBG: chan_11 -> D 1339
2015-12-18 19:58:07 gpg-agent[1339] DBG: chan_11 -> OK
2015-12-18 19:58:07 gpg-agent[1339] DBG: chan_9 <- D 1339
2015-12-18 19:58:07 gpg-agent[1339] DBG: chan_9 <- OK
2015-12-18 19:58:07 gpg-agent[1339] DBG: chan_9 -> BYE
2015-12-18 19:58:07 gpg-agent[1339] DBG: chan_11 <- BYE
2015-12-18 19:58:07 gpg-agent[1339] DBG: chan_11 -> OK closing connection
2015-12-18 19:58:07 gpg-agent[1339] handler 0x7f76c8b7f700 for fd 11 terminated
2015-12-18 19:59:07 gpg-agent[1339] handler 0x7f76c9380700 for fd 11 started
2015-12-18 19:59:07 gpg-agent[1339] DBG: chan_11 -> OK Pleased to meet you, process 1339
2015-12-18 19:59:07 gpg-agent[1339] DBG: chan_9 <- OK Pleased to meet you, process 1339
2015-12-18 19:59:07 gpg-agent[1339] DBG: chan_9 -> GETINFO pid
2015-12-18 19:59:07 gpg-agent[1339] DBG: chan_11 <- GETINFO pid
2015-12-18 19:59:07 gpg-agent[1339] DBG: chan_11 -> D 1339
2015-12-18 19:59:07 gpg-agent[1339] DBG: chan_11 -> OK
2015-12-18 19:59:07 gpg-agent[1339] DBG: chan_9 <- D 1339
2015-12-18 19:59:07 gpg-agent[1339] DBG: chan_9 <- OK
2015-12-18 19:59:07 gpg-agent[1339] DBG: chan_9 -> BYE
2015-12-18 19:59:07 gpg-agent[1339] DBG: chan_11 <- BYE
2015-12-18 19:59:07 gpg-agent[1339] DBG: chan_11 -> OK closing connection
2015-12-18 19:59:07 gpg-agent[1339] handler 0x7f76c9380700 for fd 11 terminated
2015-12-18 19:59:40 gpg-agent[1339] handler 0x7f76c9380700 for fd 9 started
2015-12-18 19:59:40 gpg-agent[1339] DBG: chan_9 -> OK Pleased to meet you, process 2000
2015-12-18 19:59:40 gpg-agent[2000] DBG: chan_5 <- OK Pleased to meet you, process 2000
2015-12-18 19:59:40 gpg-agent[2000] DBG: chan_5 -> BYE
2015-12-18 19:59:40 gpg-agent[1339] DBG: chan_9 <- BYE
2015-12-18 19:59:40 gpg-agent[1339] DBG: chan_9 -> OK closing connection
2015-12-18 19:59:40 gpg-agent[1339] handler 0x7f76c9380700 for fd 9 terminated
2015-12-18 20:00:07 gpg-agent[1339] handler 0x7f76c8b7f700 for fd 11 started
2015-12-18 20:00:07 gpg-agent[1339] DBG: chan_11 -> OK Pleased to meet you, process 1339
2015-12-18 20:00:07 gpg-agent[1339] DBG: chan_9 <- OK Pleased to meet you, process 1339
2015-12-18 20:00:07 gpg-agent[1339] DBG: chan_9 -> GETINFO pid
2015-12-18 20:00:07 gpg-agent[1339] DBG: chan_11 <- GETINFO pid
2015-12-18 20:00:07 gpg-agent[1339] DBG: chan_11 -> D 1339
2015-12-18 20:00:07 gpg-agent[1339] DBG: chan_11 -> OK

I am using envoy-git 14.34.g963b231-1 on Arch Linux.