Skip to content

Instantly share code, notes, and snippets.

@grekko

grekko/error.md

Last active February 15, 2017 14:50
Show Gist options
  • Save grekko/e87917555d4c74bad760f4bb7f1f9163 to your computer and use it in GitHub Desktop.
Save grekko/e87917555d4c74bad760f4bb7f1f9163 to your computer and use it in GitHub Desktop.
Download ZIP
Mailpile DEV: Error when creating GPG keypair
Raw
error.md

I am using the docker dev setup (slightly updated Dockerfile and docker-compose.yml).

When I try to generate a GPG keypair (via the web UI) I can observe the following error in the mailpile process:

Traceback (most recent call last):sage
mailpile_dev |   File "/Mailpile/mailpile/crypto/gpgi.py", line 1514, in run
mailpile_dev |     gpg.chat(self.gpg_args(), self.run_script, self.main_script)
mailpile_dev |   File "/Mailpile/mailpile/crypto/gpgi.py", line 1303, in chat
mailpile_dev |     return callback(proc, *args, **kwargs)
mailpile_dev |   File "/Mailpile/mailpile/crypto/gpgi.py", line 1500, in run_script
mailpile_dev |     self.expect_exact(proc, exp, timeout=tmo)
mailpile_dev |   File "/Mailpile/mailpile/crypto/gpgi.py", line 1489, in expect_exact
mailpile_dev |     if RunTimed(timeout, self._expecter, proc, exp, timebox):
mailpile_dev |   File "/Mailpile/mailpile/util.py", line 1009, in RunTimed
mailpile_dev |     RunTimedThread(func.__name__, work).run_timed(timeout)
mailpile_dev |   File "/Mailpile/mailpile/util.py", line 998, in run_timed
mailpile_dev |     raise TimedOut('Timed out: %s' % self.name)
mailpile_dev | TimedOut: Timed out: _expecter

So tried to create a gpg keypair on the commandline. I start a bash inside the docker container and perform the following commands:

$ gpg --gen-key

gpg (GnuPG) 2.1.15; Copyright (C) 2016 Free Software Foundation, Inc.
…
GnuPG needs to construct a user ID to identify your key.

Real name: Peter
Email address: [email protected]
You selected this USER-ID:
    "Peter <[email protected]>"

Change (N)ame, (E)mail, or (O)kay/(Q)uit? o
We need to generate a lot of random bytes. It is a good idea to perform
some other action (type on the keyboard, move the mouse, utilize the
disks) during the prime generation; this gives the random number
generator a better chance to gain enough entropy.
gpg: agent_genkey failed: Inappropriate ioctl for device
Key generation failed: Inappropriate ioctl for device

I wondered about the "Inappropriate ioctl for device" and found some hint about exporting a proper GPG_TTY.

export GPG_TTY=$(tty)

When re-running the $ gpg --gen-key command I observe this:

$ gpg --gen-key

…
Real name: Peter
Email address: [email protected]
You selected this USER-ID:
    "Peter <[email protected]>"

Change (N)ame, (E)mail, or (O)kay/(Q)uit? o
We need to generate a lot of random bytes. It is a good idea to perform
some other action (type on the keyboard, move the mouse, utilize the
disks) during the prime generation; this gives the random number
generator a better chance to gain enough entropy.
gpg: agent_genkey failed: No such file or directory
Key generation failed: No such file or directory

Now instead I see the error agent_genkey failed: No such file or directory.

I am not sure wether this is at all related with the timeout problem mailpile is reporting. Any idea how to proceed with debugging?

Update

I enabled debugging via set sys.debug = log http gnupg.

When creating a new key I can see the following via stdout/stderr of the mp process.

Running gpg --utf8-strings --pinentry-mode=loopback --no-tty --command-fd=0 --status-fd=1 --yes --full-generate-key
58a469c7-0016c-33=EditProfile:i Generating new 2048 bit PGP key. This may take some time!
58a469c3-00169-33=EditProfile:c profiles/edit: Account Updated!
bg/log(20): Elapsed: 0.001s (profiles/edit: Account Updated!)
jinja/log(20): Elapsed: 0.003s (tags: Listed 4 tags)
jinja/log(20): Elapsed: 0.020s (tags: Listed 50 tags)
Expect: GET_LINE keygen.algo-refresh
58a469c7-0016f-33=UrlRedirect:c http/redirect: http/redirect
http/log(20): Elapsed: 0.001s (http/redirect: http/redirect)
bg/log(20): Elapsed: 3.736s (Starting: post-refresh)
bg/log(50): GET: /profiles/ qs = {} post = {}
bg/log(20): Elapsed: 0.000s (output: Set output mode to: html)
58a469c7-00171-33=ListProfiles:c profiles: Listed 1/1 results
bg/log(20): Elapsed: 0.002s (profiles: Listed 1/1 results)
bg/log(20): Elapsed: 0.007s (tags: Listed 1 tags)
jinja/log(20): Elapsed: 0.004s (tags: Listed 4 tags)
jinja/log(20): Elapsed: 0.071s (tags: Listed 50 tags)
58a469c7-00175-33=Search:c search: Found 0 results in 0.029s
bg/log(20): Elapsed: 0.038s (search: Found 0 results in 0.029s)
http/log(20): Elapsed: 0.007s (tags: Listed 1 tags)
58a469c7-00177-33=MessageOfTheDay:c motd:
http/log(20): Elapsed: 0.004s (motd: )
58a469c7-00178-33=Search:c search: Found 5 results in 0.018s
bg/log(20): Elapsed: 0.020s (search: Found 5 results in 0.018s)
bg/log(20): http://0.0.0.0:33411 "GET /profiles/ HTTP/1.1" 200 57758
58a469c7-00179-33=CommandCache:c New results are available
58a46921-000b7-33=ImapMailSource:R Connected to IMAP server secureimap.t-online.de
bg/log(20): Elapsed: 0.307s (Sending response)
bg/log(50): GET: /jsapi/as.css qs = {'ts': ['1.0.0rc0-5ad32489-1487169987']} post = {}
bg/log(20): Elapsed: 0.002s (output: Set output mode to: as.css)
bg/log(50): GET: /api/0/jsapi/as.js qs = {'ts': ['1.0.0rc0-5ad32489-1487169987']} post = {}
bg/log(20): Elapsed: 0.001s (output: Set output mode to: as.js)
bg/log(50): GET: /api/0/jsapi/app.js qs = {'ts': ['1.0.0rc0-5ad32489-1487169987']} post = {}
58a469c7-0017b-33=JsApi:c jsapi: Generated Javascript API
bg/log(20): Elapsed: 0.019s (jsapi: Generated Javascript API)
58a469c7-0017d-33=JsApi:c jsapi: Generated Javascript API
bg/log(20): Elapsed: 0.017s (jsapi: Generated Javascript API)
bg/log(20): Elapsed: 0.003s (output: Set output mode to: app.js)
58a469c7-0017f-33=JsApi:c jsapi: Generated Javascript API
bg/log(20): Elapsed: 0.017s (jsapi: Generated Javascript API)
bg/log(20): http://0.0.0.0:33411 "GET /jsapi/as.css?ts=1.0.0rc0-5ad32489-1487169987 HTTP/1.1" 200 5655
bg/log(20): Elapsed: 0.074s (Sending response)
58a46921-000b7-33=ImapMailSource:R Copying up to 67 e-mails from Sent
58a46921-000b7-33=ImapMailSource:R Updating search engine for Sent
bg/log(20): http://0.0.0.0:33411 "GET /api/0/jsapi/as.js?ts=1.0.0rc0-5ad32489-1487169987 HTTP/1.1" 200 128161
bg/log(20): Elapsed: 0.318s (Sending response)
bg/log(20): Elapsed: 90.148s (Starting: Wait)
58a46921-000b7-33=ImapMailSource:R Checking for new mailboxes
bg/log(20): http://0.0.0.0:33411 "GET /api/0/jsapi/app.js?ts=1.0.0rc0-5ad32489-1487169987 HTTP/1.1" 200 128082
58a46921-000b7-33=ImapMailSource:R Checking for new mailboxes
bg/log(20): Elapsed: 0.443s (Sending response)
bg/log(20): Elapsed: 12.345s (eventlog: Found 12 events)
bg/log(20): http://0.0.0.0:33411 "GET /api/0/logs/events/?since=1487169978.750782&gather=1&wait=30&context=search:e6846877b74377ece4308b2b478a3838 HTTP/1.1" 200 10083
bg/log(20): Elapsed: 12.361s (Sending response)
bg/log(50): GET: /api/0/logs/events/ qs = {'incomplete': ['true']} post = {}
bg/log(20): Elapsed: 0.001s (output: Set output mode to: json)
bg/log(20): Elapsed: 0.002s (eventlog: Found 3 events)
bg/log(20): http://0.0.0.0:33411 "GET /api/0/logs/events/?incomplete=true HTTP/1.1" 200 3981
bg/log(20): Elapsed: 0.011s (Sending response)
58a46921-000b7-33=ImapMailSource:R Processed 1 mailboxes
bg/log(50): GET: /api/0/logs/events/ qs = {'incomplete': ['true']} post = {}
bg/log(50): GET: /api/0/logs/events/ qs = {'since': ['1487169978.750782'], 'wait': ['30'], 'gather': ['1']} post = {}
bg/log(20): Elapsed: 0.001s (output: Set output mode to: json)
bg/log(20): Elapsed: 0.003s (output: Set output mode to: json)
bg/log(20): Elapsed: 0.002s (eventlog: Found 3 events)
bg/log(20): http://0.0.0.0:33411 "GET /api/0/logs/events/?incomplete=true HTTP/1.1" 200 3973
bg/log(20): Elapsed: 0.016s (Sending response)
bg/log(20): Elapsed: 0.005s (tags: Listed 1 tags)
bg/log(20): Elapsed: 0.005s (tags: Listed 4 tags)
bg/log(20): Elapsed: 0.032s (tags: Listed 50 tags)
58a469c9-00189-33=Search:c search: Found 5 results in 0.013s
bg/log(20): Elapsed: 0.015s (search: Found 5 results in 0.013s)
58a46921-000b7-33=ImapMailSource:R Connected to IMAP server secureimap.t-online.de
bg/log(20): Elapsed: 1.002s (eventlog: Found 13 events)
bg/log(20): http://0.0.0.0:33411 "GET /api/0/logs/events/?since=1487169978.750782&gather=1&wait=30 HTTP/1.1" 200 10440
bg/log(20): Elapsed: 1.015s (Sending response)
58a469c9-0018a-33=Search:c search: Found 0 results in 0.008s
bg/log(50): GET: /api/0/logs/events/ qs = {'since': ['1487169993.508345'], 'wait': ['30'], 'gather': ['1']} post = {}
bg/log(20): Elapsed: 0.011s (search: Found 0 results in 0.008s)
58a469c9-0018b-33=CommandCache:c New results are available
bg/log(20): Elapsed: 0.001s (output: Set output mode to: json)
58a46921-000b7-33=ImapMailSource:R Checking for new mailboxes
58a46921-000b7-33=ImapMailSource:R Checking for new mailboxes
58a46921-000b7-33=ImapMailSource:R No new mail at 14:46
58a469ca-0018e-33=EmptyOutbox:c sendmail: The outbox is empty
bg/log(20): Elapsed: 0.003s (sendmail: The outbox is empty)
bg/log(20): Elapsed: 1.004s (eventlog: Found 4 events)
bg/log(20): http://0.0.0.0:33411 "GET /api/0/logs/events/?since=1487169993.508345&gather=1&wait=30 HTTP/1.1" 200 3928
bg/log(20): Elapsed: 1.014s (Sending response)
bg/log(50): GET: /api/0/logs/events/ qs = {'since': ['1487169994.053585'], 'wait': ['30'], 'gather': ['1']} post = {}
bg/log(20): Elapsed: 0.001s (output: Set output mode to: json)
bg/log(50): GET: /api/0/cached/sidebar.jhtml!minimal qs = {'id': ['-tags--404363d14ff439eeb1a5f9333d4a8c9f']} post = {}
bg/log(20): Elapsed: 0.001s (output: Set output mode to: sidebar.jhtml!minimal)
bg/log(20): http://0.0.0.0:33411 "GET /api/0/cached/sidebar.jhtml!minimal?id=-tags--404363d14ff439eeb1a5f9333d4a8c9f HTTP/1.1" 200 8516
bg/log(20): Elapsed: 0.076s (Sending response)
Timed out
Boo! GET_LINE keygen.algo not found in
Traceback (most recent call last):
  File "/Mailpile/mailpile/crypto/gpgi.py", line 1562, in run
    gpg.chat(self.gpg_args(), self.run_script, self.main_script)
  File "/Mailpile/mailpile/crypto/gpgi.py", line 1347, in chat
    return callback(proc, *args, **kwargs)
  File "/Mailpile/mailpile/crypto/gpgi.py", line 1548, in run_script
    self.expect_exact(proc, exp, timeout=tmo)
  File "/Mailpile/mailpile/crypto/gpgi.py", line 1536, in expect_exact
    if RunTimed(timeout, self._expecter, proc, exp, timebox):
  File "/Mailpile/mailpile/util.py", line 1010, in RunTimed
    RunTimedThread(func.__name__, work).run_timed(timeout)
  File "/Mailpile/mailpile/util.py", line 999, in run_timed
    raise TimedOut('Timed out: %s' % self.name)
TimedOut: Timed out: _expecter
58a469c7-0016c-33=EditProfile:c PGP key generation failed!
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment