{"thread":{"id":"44964","subject":"[PATCH] gpg-interface: Add some output from gpg when it errors out.","startedAt":"2017-01-25T03:04:56Z","lastAt":"2017-01-26T18:33:38Z","messageCount":7,"participants":["Mike Hommey","Junio C Hamano","Jeff King"],"isPatch":true,"patchVersion":1,"patchTotal":null},"messages":[{"id":"310136","messageId":"20170125030434.26448-1-mh@glandium.org","threadId":"44964","inReplyTo":null,"subject":"[PATCH] gpg-interface: Add some output from gpg when it errors out.","fromName":"Mike Hommey","fromEmail":"mh@glandium.org","sentAt":"2017-01-25T03:04:34Z","receivedAt":"2017-01-25T03:04:56Z","isPatch":true,"sender":{"key":"mh@glandium.org","avatar":"https://avatars.githubusercontent.com/u/1038527?v=4"},"body":"When e.g. signing a tag fails, the user is left with the following\noutput on their console:\n error: gpg failed to sign the data\n error: unable to sign the tag\n\nThere is no indication of what specifically failed, and no indication\nhow they might solve the problem.\n\nIt turns out, gpg still does output some messages without a [GNUPG:]\nprefix. The same messages it outputs when run standalone, in fact.\n\nThose messages can be helpful to find what made the gpg command fail.\n\nFor instance, after changing my laptop for a new one, I copied my\nconfigs, but had some environment differences that broke gpg.\nWith this change applied, the output becomes, on this new machine:\n gpg: keyblock resource '/usr/share/keyrings/debian-keyring.gpg': No\nsuch file or directory\n error: gpg failed to sign the data\n error: unable to sign the tag\n\nwhich makes it clearer what's wrong.\n\nSigned-off-by: Mike Hommey \n---\n gpg-interface.c | 28 ++++++++++++++++++++++++----\n 1 file changed, 24 insertions(+), 4 deletions(-)\n\ndiff --git a/gpg-interface.c b/gpg-interface.c\nindex e44cc27da..2768bb307 100644\n--- a/gpg-interface.c\n+++ b/gpg-interface.c\n@@ -149,6 +149,26 @@ const char *get_signing_key(void)\n \treturn git_committer_info(IDENT_STRICT|IDENT_NO_DATE);\n }\n \n+static int pipe_gpg_command(struct child_process *cmd,\n+\t\t\t const char *in, size_t in_len,\n+\t\t\t struct strbuf *out, size_t out_hint,\n+\t\t\t struct strbuf *err, size_t err_hint)\n+{\n+\tint ret = pipe_command(cmd, in, in_len, out, out_hint, err, err_hint);\n+\t/* Print out any line that doesn't start with [GNUPG:] if the gpg\n+\t * command failed. */\n+\tif (ret) {\n+\t\tstruct strbuf **err_lines = strbuf_split(err, '\\n');\n+\t\tfor (struct strbuf **line = err_lines; *line; line++) {\n+\t\t\tif (memcmp((*line)->buf, \"[GNUPG:]\", 8)) {\n+\t\t\t\tstrbuf_rtrim(*line);\n+\t\t\t\tfprintf(stderr, \"%s\\n\", (*line)->buf);\n+\t\t\t}\n+\t\t}\n+\t\tstrbuf_list_free(err_lines);\n+\t}\n+\treturn ret;\n+}\n /*\n * Create a detached signature for the contents of \"buffer\" and append\n * it after \"signature\"; \"buffer\" and \"signature\" can be the same\n@@ -175,8 +195,8 @@ int sign_buffer(struct strbuf *buffer, struct strbuf *signature, const char *sig\n \t * because gpg exits without reading and then write gets SIGPIPE.\n \t */\n \tsigchain_push(SIGPIPE, SIG_IGN);\n-\tret = pipe_command(&gpg, buffer->buf, buffer->len,\n-\t\t\t signature, 1024, &gpg_status, 0);\n+\tret = pipe_gpg_command(&gpg, buffer->buf, buffer->len,\n+\t\t\t signature, 1024, &gpg_status, 0);\n \tsigchain_pop(SIGPIPE);\n \n \tret |= !strstr(gpg_status.buf, \"\\n[GNUPG:] SIG_CREATED \");\n@@ -232,8 +252,8 @@ int verify_signed_buffer(const char *payload, size_t payload_size,\n \t\tgpg_status = &buf;\n \n \tsigchain_push(SIGPIPE, SIG_IGN);\n-\tret = pipe_command(&gpg, payload, payload_size,\n-\t\t\t gpg_status, 0, gpg_output, 0);\n+\tret = pipe_gpg_command(&gpg, payload, payload_size,\n+\t\t\t gpg_status, 0, gpg_output, 0);\n \tsigchain_pop(SIGPIPE);\n \n \tdelete_tempfile(&temp);\n-- \n2.11.0.dirty\n\n"},{"id":"310254","messageId":"xmqqtw8m7ncp.fsf@gitster.mtv.corp.google.com","threadId":"44964","inReplyTo":"20170125030434.26448-1-mh@glandium.org","subject":"Re: [PATCH] gpg-interface: Add some output from gpg when it errors out.","fromName":"Junio C Hamano","fromEmail":"gitster@pobox.com","sentAt":"2017-01-25T23:04:38Z","receivedAt":"2017-01-25T23:04:46Z","isPatch":true,"sender":{"key":"gitster@pobox.com","avatar":"https://avatars.githubusercontent.com/u/54884?v=4"},"body":"Mike Hommey writes:\n\n> For instance, after changing my laptop for a new one, I copied my\n> configs, but had some environment differences that broke gpg.\n> With this change applied, the output becomes, on this new machine:\n> gpg: keyblock resource '/usr/share/keyrings/debian-keyring.gpg': No\n> such file or directory\n> error: gpg failed to sign the data\n> error: unable to sign the tag\n>\n> which makes it clearer what's wrong.\n\nOverall I think this is a good thing to do. Instead of eating the\nstatus output, showing what we got, especially when we know the\ncommand failed, would make the bug-hunting of user's environment\neasier, like you showed above.\n\nThe only thing in the design that makes me wonder is the filtering\nout based on \"[GNUPG:]\" prefix. Why do we need to filter them out?\n\nImplementation-wise, I'd be happier if we do not add any new\ncallsites of strbuf_split(), which is a horrible interface. But\nthat is a minor detail.\n\nThanks.\n"},{"id":"310270","messageId":"20170125235410.byxwmo7o7zdszzot@glandium.org","threadId":"44964","inReplyTo":"xmqqtw8m7ncp.fsf@gitster.mtv.corp.google.com","subject":"Re: [PATCH] gpg-interface: Add some output from gpg when it errors out.","fromName":"Mike Hommey","fromEmail":"mh@glandium.org","sentAt":"2017-01-25T23:54:10Z","receivedAt":"2017-01-25T23:54:19Z","isPatch":true,"sender":{"key":"mh@glandium.org","avatar":"https://avatars.githubusercontent.com/u/1038527?v=4"},"body":"On Wed, Jan 25, 2017 at 03:04:38PM -0800, Junio C Hamano wrote:\n> Mike Hommey writes:\n> \n> > For instance, after changing my laptop for a new one, I copied my\n> > configs, but had some environment differences that broke gpg.\n> > With this change applied, the output becomes, on this new machine:\n> > gpg: keyblock resource '/usr/share/keyrings/debian-keyring.gpg': No\n> > such file or directory\n> > error: gpg failed to sign the data\n> > error: unable to sign the tag\n> >\n> > which makes it clearer what's wrong.\n> \n> Overall I think this is a good thing to do. Instead of eating the\n> status output, showing what we got, especially when we know the\n> command failed, would make the bug-hunting of user's environment\n> easier, like you showed above.\n> \n> The only thing in the design that makes me wonder is the filtering\n> out based on \"[GNUPG:]\" prefix. Why do we need to filter them out?\n\nThe [GNUPG:] lines are part of the status-fd protocol. They show details\nthat don't really seem interesting to the user. In fact, they even\ncontain the signed message (yes, in my case, it turns out gpg was\nactually still signing, but returned an error code...).\n\nFor instance, in that failed run above, the entire output looks like:\n\ngpg: keyblock resource '/usr/share/keyrings/debian-keyring.gpg': No\nsuch file or directory\n[GNUPG:] ERROR add_keyblock_resource ...\n[GNUPG:] KEY_CONSIDERED ...\n[GNUPG:] BEGIN_SIGNING H2\n[GNUPG:] SIG_CREATED ...\n\nAll the [GNUPG:] lines are implementation details that don't seem\nparticularly useful. A case could be made for the ERROR one, though,\nalthough it's also implementation detail-y.\n\n> Implementation-wise, I'd be happier if we do not add any new\n> callsites of strbuf_split(), which is a horrible interface. But\n> that is a minor detail.\n\nWhat would you suggest otherwise?\n\nMike\n"},{"id":"310280","messageId":"xmqq8tpy7dh8.fsf@gitster.mtv.corp.google.com","threadId":"44964","inReplyTo":"20170125235410.byxwmo7o7zdszzot@glandium.org","subject":"Re: [PATCH] gpg-interface: Add some output from gpg when it errors out.","fromName":"Junio C Hamano","fromEmail":"gitster@pobox.com","sentAt":"2017-01-26T02:37:55Z","receivedAt":"2017-01-26T02:46:03Z","isPatch":true,"sender":{"key":"gitster@pobox.com","avatar":"https://avatars.githubusercontent.com/u/54884?v=4"},"body":"Mike Hommey writes:\n\n> On Wed, Jan 25, 2017 at 03:04:38PM -0800, Junio C Hamano wrote:\n> ...\n>> Overall I think this is a good thing to do. Instead of eating the\n>> status output, showing what we got, especially when we know the\n>> command failed, would make the bug-hunting of user's environment\n>> easier, like you showed above.\n>> \n>> The only thing in the design that makes me wonder is the filtering\n>> out based on \"[GNUPG:]\" prefix. Why do we need to filter them out?\n>\n> The [GNUPG:] lines are part of the status-fd protocol. They show details\n> that don't really seem interesting to the user. In fact, they even\n> contain the signed message (yes, in my case, it turns out gpg was\n> actually still signing, but returned an error code...).\n\nOK, that detail was what was missing in the proposed log message.\nWithout that \"why do we filter?\", readers cannot correctly assess\nwhy it is a good idea. I wasn't arguing against filtering it; I\njust wanted to make sure \"git log\" readers (and \"git show\" user\nafter \"git blame\" identifies this change in the history) will know\nhow we decided to filter lines with the prefix. \n\nWith that information recorded in the log (or in-code comment, or\nboth), if it turns out that some lines with the prefix are useful\n(or some other lines without the prefix are not very useful), they\ncan tweak the filtering criteria as appropriate, with confidence\nthat they _know_ for what purpose the initial \"filter lines with the\nprefix\" was trying to serve, and their update is still in the same\nspirit as the original, only executed better.\n\nThanks.\n"},{"id":"310282","messageId":"20170126025530.r4fesye447do5wdx@glandium.org","threadId":"44964","inReplyTo":"xmqq8tpy7dh8.fsf@gitster.mtv.corp.google.com","subject":"Re: [PATCH] gpg-interface: Add some output from gpg when it errors out.","fromName":"Mike Hommey","fromEmail":"mh@glandium.org","sentAt":"2017-01-26T02:55:30Z","receivedAt":"2017-01-26T02:55:40Z","isPatch":true,"sender":{"key":"mh@glandium.org","avatar":"https://avatars.githubusercontent.com/u/1038527?v=4"},"body":"On Wed, Jan 25, 2017 at 06:37:55PM -0800, Junio C Hamano wrote:\n> Mike Hommey writes:\n> \n> > On Wed, Jan 25, 2017 at 03:04:38PM -0800, Junio C Hamano wrote:\n> > ...\n> >> Overall I think this is a good thing to do. Instead of eating the\n> >> status output, showing what we got, especially when we know the\n> >> command failed, would make the bug-hunting of user's environment\n> >> easier, like you showed above.\n> >> \n> >> The only thing in the design that makes me wonder is the filtering\n> >> out based on \"[GNUPG:]\" prefix. Why do we need to filter them out?\n> >\n> > The [GNUPG:] lines are part of the status-fd protocol. They show details\n> > that don't really seem interesting to the user. In fact, they even\n> > contain the signed message (yes, in my case, it turns out gpg was\n> > actually still signing, but returned an error code...).\n> \n> OK, that detail was what was missing in the proposed log message.\n> Without that \"why do we filter?\", readers cannot correctly assess\n> why it is a good idea. I wasn't arguing against filtering it; I\n> just wanted to make sure \"git log\" readers (and \"git show\" user\n> after \"git blame\" identifies this change in the history) will know\n> how we decided to filter lines with the prefix. \n> \n> With that information recorded in the log (or in-code comment, or\n> both), if it turns out that some lines with the prefix are useful\n> (or some other lines without the prefix are not very useful), they\n> can tweak the filtering criteria as appropriate, with confidence\n> that they _know_ for what purpose the initial \"filter lines with the\n> prefix\" was trying to serve, and their update is still in the same\n> spirit as the original, only executed better.\n\nCome to think of it, and considering that mutt happily signs emails in\nthe same conditions, maybe it would make sense to just ignore gpg return\ncode as long as there is a SIG_CREATED message...\n\nMike\n"},{"id":"310294","messageId":"20170126052103.mpudt63l7dynf3h6@sigill.intra.peff.net","threadId":"44964","inReplyTo":"20170125235410.byxwmo7o7zdszzot@glandium.org","subject":"Re: [PATCH] gpg-interface: Add some output from gpg when it errors out.","fromName":"Jeff King","fromEmail":"peff@peff.net","sentAt":"2017-01-26T05:21:03Z","receivedAt":"2017-01-26T05:21:10Z","isPatch":true,"sender":{"key":"peff@peff.net","avatar":"https://avatars.githubusercontent.com/u/45925?v=4"},"body":"On Thu, Jan 26, 2017 at 08:54:10AM +0900, Mike Hommey wrote:\n\n> > Implementation-wise, I'd be happier if we do not add any new\n> > callsites of strbuf_split(), which is a horrible interface. But\n> > that is a minor detail.\n> \n> What would you suggest otherwise?\n\nTry string_list_split() (or its in_place() variant, since it is probably\nOK to hack up the string for your use case). Like this:\n\ndiff --git a/gpg-interface.c b/gpg-interface.c\nindex 2768bb307..051bb7d3e 100644\n--- a/gpg-interface.c\n+++ b/gpg-interface.c\n@@ -158,14 +158,16 @@ static int pipe_gpg_command(struct child_process *cmd,\n \t/* Print out any line that doesn't start with [GNUPG:] if the gpg\n \t * command failed. */\n \tif (ret) {\n-\t\tstruct strbuf **err_lines = strbuf_split(err, '\\n');\n-\t\tfor (struct strbuf **line = err_lines; *line; line++) {\n-\t\t\tif (memcmp((*line)->buf, \"[GNUPG:]\", 8)) {\n-\t\t\t\tstrbuf_rtrim(*line);\n-\t\t\t\tfprintf(stderr, \"%s\\n\", (*line)->buf);\n-\t\t\t}\n+\t\tstruct string_list lines = STRING_LIST_INIT_NODUP;\n+\t\tint i;\n+\n+\t\tstring_list_split_in_place(&lines, err->buf, '\\n', 0);\n+\t\tfor (i = 0; i < lines.nr; i++) {\n+\t\t\tconst char *line = lines.items[i].string;\n+\t\t\tif (!starts_with(line, \"[GNUPG:]\"))\n+\t\t\t\tfprintf(stderr, \"%s\\n\", line);\n \t\t}\n-\t\tstrbuf_list_free(err_lines);\n+\t\tstring_list_clear(&lines, 0);\n \t}\n \treturn ret;\n }\n\nNote that I also replaced the memcmp with starts_with(). That avoids the\nmagic number \"8\". I also suspect your original can read off the end of\nthe buffer when the line is shorter than 8 characters (e.g., if memcmp\ndoes 64-bit loads).\n\n-Peff\n"},{"id":"310341","messageId":"xmqqh94l65fn.fsf@gitster.mtv.corp.google.com","threadId":"44964","inReplyTo":"20170126025530.r4fesye447do5wdx@glandium.org","subject":"Re: [PATCH] gpg-interface: Add some output from gpg when it errors out.","fromName":"Junio C Hamano","fromEmail":"gitster@pobox.com","sentAt":"2017-01-26T18:29:16Z","receivedAt":"2017-01-26T18:33:38Z","isPatch":true,"sender":{"key":"gitster@pobox.com","avatar":"https://avatars.githubusercontent.com/u/54884?v=4"},"body":"Mike Hommey writes:\n\n>> With that information recorded in the log (or in-code comment, or\n>> both), if it turns out that some lines with the prefix are useful\n>> (or some other lines without the prefix are not very useful), they\n>> can tweak the filtering criteria as appropriate, with confidence\n>> that they _know_ for what purpose the initial \"filter lines with the\n>> prefix\" was trying to serve, and their update is still in the same\n>> spirit as the original, only executed better.\n>\n> Come to think of it, and considering that mutt happily signs emails in\n> the same conditions, maybe it would make sense to just ignore gpg return\n> code as long as there is a SIG_CREATED message...\n\nI do not think we want to go there. If GPG reports failure, there\nis something funny going on.\n"}]}