Page MenuHome GnuPG

Checksum Errors and Assertions when working with a specific homedir
Closed, ResolvedPublic

Description

Maybe the homedir is corrupted but I wonder how. It was my test homedir for DE-VS testing.

Today I tried some tests and for signing from stdin I get either an assertion when trying to encrypt, or a Checksum Error when trying to sign.

echo foo | /opt/gnupg/bin/gpg2 -seau foo@bar.baz -r foo@bar.baz -r foo@bar.baz2 > /tmp/foo.gpg
gpg: WARNING: unsafe permissions on homedir '/home/aheinecke/vsnfdhome'
gpg: NOTE: THIS IS A DEVELOPMENT VERSION!
gpg: It is only intended for test purposes and should NOT be
gpg: used in a production environment or with production keys!
gpg: Ohhhh jeeee: Assertion "uid->ref > 0" in free_user_id failed (../../../src/gnupg/g10/free-packet.c:315)
[1]    20319 done       echo foo | 
       20320 abort      /opt/gnupg/bin/gpg2 -seau foo@bar.baz -r foo@bar.baz -r foo@bar.baz2 >

Or for sign only:

echo foo | /opt/gnupg/bin/gpg2 -sau foo@bar.baz > /tmp/foo.gpg                
gpg: WARNING: unsafe permissions on homedir '/home/aheinecke/vsnfdhome'
gpg: NOTE: THIS IS A DEVELOPMENT VERSION!
gpg: It is only intended for test purposes and should NOT be
gpg: used in a production environment or with production keys!
gpg: signing failed: Checksum error
gpg: signing failed: Checksum error

The homedir used for the test is attached. All passphrases are "test".

I could not find a determining factor. With my productive keyring brainpool keys work. If I remove the compliance setting from the vsnfdhome dir it still does not work. So for now no Idea what's wrong here. Needs Triage because I have no idea how important this is. Maybe my SSD just corrupted the keybox? But keylist etc. works.

Event Timeline

I only get checksum errors:

$ echo foo | g10/gpg -seau foo@bar.baz -r foo@bar.baz -r foo@bar.baz2 > /tmp/foo.gpg
gpg: WARNING: unsafe permissions on homedir '/home/teythoon/repos/g10/vsnfdhome'
gpg: NOTE: THIS IS A DEVELOPMENT VERSION!
gpg: It is only intended for test purposes and should NOT be
gpg: used in a production environment or with production keys!
gpg: signing failed: Checksum error
gpg: [stdin]: sign+encrypt failed: Checksum error
$ echo foo | g10/gpg -sau foo@bar.baz > /tmp/foo.gpg
gpg: WARNING: unsafe permissions on homedir '/home/teythoon/repos/g10/vsnfdhome'
gpg: NOTE: THIS IS A DEVELOPMENT VERSION!
gpg: It is only intended for test purposes and should NOT be
gpg: used in a production environment or with production keys!
gpg: signing failed: Checksum error
gpg: signing failed: Checksum error

I used the passphrase 'test', but get the same result no matter what passphrase I enter. Do we have a special error code for bad passphrase?

Yes, signing failed: Bad Passphrase but that may be later.

FWIW here is a guru log from a run that hits the assertion.

justus triaged this task as Normal priority.Jul 11 2017, 1:55 PM

This is very odd indeed. Here is my guru log, it is the same as yours, but except of dying of the assertion, it just continues:

I'm in a checksum error scenario again.

My homedir worked. Then I did

gpg2 --gen-key
gpg: WARNING: unsafe permissions on homedir '/home/aheinecke/vsnfdhome2'
gpg (GnuPG) 2.1.22-beta86; Copyright (C) 2017 Free Software Foundation, Inc.
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law.

Note: Use "gpg2 --full-generate-key" for a full featured key generation dialog.

GnuPG needs to construct a user ID to identify your key.

Real name: RSA test
Email address: rsatest@foo.bar.baz
You selected this USER-ID:
    "RSA test <rsatest@foo.bar.baz>"

Change (N)ame, (E)mail, or (O)kay/(Q)uit? O
echo foo | gpg2 -e -r 74FFCB27888AF3DEC139BF3F15538A71D5BD1C32 > enc_to_rsa.gpg
gpg: WARNING: unsafe permissions on homedir '/home/aheinecke/vsnfdhome2'
gpg2 --decrypt enc_to_rsa.gpg 
gpg: WARNING: unsafe permissions on homedir '/home/aheinecke/vsnfdhome2'
gpg: NOTE: THIS IS A DEVELOPMENT VERSION!
gpg: It is only intended for test purposes and should NOT be
gpg: used in a production environment or with production keys!
gpg: encrypted with 3072-bit RSA key, ID 86F7E3FF3D951F88, created 2017-07-27
      "RSA test <rsatest@foo.bar.baz>"
gpg: public key decryption failed: Checksum error
gpg: decryption failed: No secret key

I don't understand the GPG_ERR_CHECKSUM coming according to Justus' log from Pinentry. A likeley reason for that error is an OCB decrypt failure in Libgcrypt (e.g. extended protected key format) - but from Pinentry?

The ref count assertion should of course never happen and is a bug of its own.

Andre, can you you run gpg again with --debug ipc and disable the guru thing. A gpg-agent log with --debug ipx and --debug-pinentry would also be helpful

With the vsnfdhome attached to this report:

First test:

echo foo | /opt/gnupg/bin/gpg2 -seau foo@bar.baz -r foo@bar.baz -r foo@bar.baz2 > /tmp/foo.gpg
gpg: WARNING: unsafe permissions on homedir '/home/aheinecke/vsnfdhome'
gpg: NOTE: THIS IS A DEVELOPMENT VERSION!
gpg: It is only intended for test purposes and should NOT be
gpg: used in a production environment or with production keys!
gpg: enabled debug flags: ipc
gpg: DBG: chan_4 <- OK Pleased to meet you, process 24232
gpg: DBG: connection to agent established
gpg: DBG: chan_4 -> RESET
gpg: DBG: chan_4 <- OK
gpg: DBG: chan_4 -> OPTION ttytype=xterm-256color
gpg: DBG: chan_4 <- OK
gpg: DBG: chan_4 -> OPTION display=:0
gpg: DBG: chan_4 <- OK
gpg: DBG: chan_4 -> OPTION putenv=DBUS_SESSION_BUS_ADDRESS=unix:path=/run/user/1000/bus
gpg: DBG: chan_4 <- OK
gpg: DBG: chan_4 -> GETINFO version
gpg: DBG: chan_4 <- D 2.1.22-beta164
gpg: DBG: chan_4 <- OK
gpg: DBG: chan_4 -> OPTION allow-pinentry-notify
gpg: DBG: chan_4 <- OK
gpg: DBG: chan_4 -> OPTION agent-awareness=2.1.0
gpg: DBG: chan_4 <- OK
gpg: DBG: chan_4 -> HAVEKEY 12D8258797E0A5713011F4A2837E143B51D3F979 0C7CE46B739921A4DE509EC52CE8453E78F55F2A
gpg: DBG: chan_4 <- OK
gpg: Ohhhh jeeee: Assertion "uid->ref > 0" in free_user_id failed (../../../src/gnupg/g10/free-packet.c:321)
[1]    24231 done       echo foo | 
       24232 abort      /opt/gnupg/bin/gpg2 -seau foo@bar.baz -r foo@bar.baz -r foo@bar.baz2 >

The agent log with debug pinentry and debug ipc:

2017-07-27 13:13:46 gpg-agent[24421] gpg-agent (GnuPG) 2.1.22-beta164 started
2017-07-27 13:13:47 gpg-agent[24421] DBG: chan_10 -> OK Pleased to meet you, process 24418
2017-07-27 13:13:47 gpg-agent[24421] DBG: chan_10 <- RESET
2017-07-27 13:13:47 gpg-agent[24421] DBG: chan_10 -> OK
2017-07-27 13:13:47 gpg-agent[24421] DBG: chan_10 <- OPTION ttytype=xterm-256color
2017-07-27 13:13:47 gpg-agent[24421] DBG: chan_10 -> OK
2017-07-27 13:13:47 gpg-agent[24421] DBG: chan_10 <- OPTION display=:0
2017-07-27 13:13:47 gpg-agent[24421] DBG: chan_10 -> OK
2017-07-27 13:13:47 gpg-agent[24421] DBG: chan_10 <- OPTION putenv=DBUS_SESSION_BUS_ADDRESS=unix:path=/run/user/1000/bus
2017-07-27 13:13:47 gpg-agent[24421] DBG: chan_10 -> OK
2017-07-27 13:13:47 gpg-agent[24421] DBG: chan_10 <- GETINFO version
2017-07-27 13:13:47 gpg-agent[24421] DBG: chan_10 -> D 2.1.22-beta164
2017-07-27 13:13:47 gpg-agent[24421] DBG: chan_10 -> OK
2017-07-27 13:13:47 gpg-agent[24421] DBG: chan_10 <- OPTION allow-pinentry-notify
2017-07-27 13:13:47 gpg-agent[24421] DBG: chan_10 -> OK
2017-07-27 13:13:47 gpg-agent[24421] DBG: chan_10 <- OPTION agent-awareness=2.1.0
2017-07-27 13:13:47 gpg-agent[24421] DBG: chan_10 -> OK
2017-07-27 13:13:47 gpg-agent[24421] DBG: chan_10 <- HAVEKEY 12D8258797E0A5713011F4A2837E143B51D3F979 0C7CE46B739921A4DE509EC52CE8453E78F55F2A
2017-07-27 13:13:47 gpg-agent[24421] DBG: chan_10 -> OK
2017-07-27 13:13:47 gpg-agent[24421] DBG: chan_10 <- [eof]

Second test:

echo foo | /opt/gnupg/bin/gpg2 -sau foo@bar.baz > /tmp/foo.gpg   
gpg: WARNING: unsafe permissions on homedir '/home/aheinecke/vsnfdhome'
gpg: NOTE: THIS IS A DEVELOPMENT VERSION!
gpg: It is only intended for test purposes and should NOT be
gpg: used in a production environment or with production keys!
gpg: enabled debug flags: ipc
gpg: DBG: chan_4 <- OK Pleased to meet you, process 24733
gpg: DBG: connection to agent established
gpg: DBG: chan_4 -> RESET
gpg: DBG: chan_4 <- OK
gpg: DBG: chan_4 -> OPTION ttytype=xterm-256color
gpg: DBG: chan_4 <- OK
gpg: DBG: chan_4 -> OPTION display=:0
gpg: DBG: chan_4 <- OK
gpg: DBG: chan_4 -> OPTION putenv=DBUS_SESSION_BUS_ADDRESS=unix:path=/run/user/1000/bus
gpg: DBG: chan_4 <- OK
gpg: DBG: chan_4 -> GETINFO version
gpg: DBG: chan_4 <- D 2.1.22-beta164
gpg: DBG: chan_4 <- OK
gpg: DBG: chan_4 -> OPTION allow-pinentry-notify
gpg: DBG: chan_4 <- OK
gpg: DBG: chan_4 -> OPTION agent-awareness=2.1.0
gpg: DBG: chan_4 <- OK
gpg: DBG: chan_4 -> HAVEKEY 12D8258797E0A5713011F4A2837E143B51D3F979 0C7CE46B739921A4DE509EC52CE8453E78F55F2A
gpg: DBG: chan_4 <- OK
gpg: DBG: chan_4 -> RESET
gpg: DBG: chan_4 <- OK
gpg: DBG: chan_4 -> SIGKEY 12D8258797E0A5713011F4A2837E143B51D3F979
gpg: DBG: chan_4 <- OK
gpg: DBG: chan_4 -> SETKEYDESC Please+enter+the+passphrase+to+unlock+the+OpenPGP+secret+key:%0A%22foo@bar.baz%22%0A256-bit+ECDSA+key,+ID+9EFD1A5ED36ECD0D,%0Acreated+2017-04-05.%0A
gpg: DBG: chan_4 <- OK
gpg: DBG: chan_4 -> SETHASH 8 34E7E29F9DD756176BACAE3C5F47FA5355402C23F1122189BC615BC771BD0F04
gpg: DBG: chan_4 <- OK
gpg: DBG: chan_4 -> PKSIGN
gpg: DBG: chan_4 <- INQUIRE PINENTRY_LAUNCHED 24738 qt 1.0.1-beta17 - xterm-256color :0
gpg: DBG: chan_4 -> END
gpg: DBG: chan_4 <- ERR 83886090 Checksum error <Pinentry>
gpg: signing failed: Checksum error
gpg: signing failed: Checksum error
gpg: secmem usage: 1344/32768 bytes in 2 blocks

Agent log:

2017-07-27 13:16:00 gpg-agent[24736] gpg-agent (GnuPG) 2.1.22-beta164 started
2017-07-27 13:16:01 gpg-agent[24736] DBG: chan_10 -> OK Pleased to meet you, process 24733
2017-07-27 13:16:01 gpg-agent[24736] DBG: chan_10 <- RESET
2017-07-27 13:16:01 gpg-agent[24736] DBG: chan_10 -> OK
2017-07-27 13:16:01 gpg-agent[24736] DBG: chan_10 <- OPTION ttytype=xterm-256color
2017-07-27 13:16:01 gpg-agent[24736] DBG: chan_10 -> OK
2017-07-27 13:16:01 gpg-agent[24736] DBG: chan_10 <- OPTION display=:0
2017-07-27 13:16:01 gpg-agent[24736] DBG: chan_10 -> OK
2017-07-27 13:16:01 gpg-agent[24736] DBG: chan_10 <- OPTION putenv=DBUS_SESSION_BUS_ADDRESS=unix:path=/run/user/1000/bus
2017-07-27 13:16:01 gpg-agent[24736] DBG: chan_10 -> OK
2017-07-27 13:16:01 gpg-agent[24736] DBG: chan_10 <- GETINFO version
2017-07-27 13:16:01 gpg-agent[24736] DBG: chan_10 -> D 2.1.22-beta164
2017-07-27 13:16:01 gpg-agent[24736] DBG: chan_10 -> OK
2017-07-27 13:16:01 gpg-agent[24736] DBG: chan_10 <- OPTION allow-pinentry-notify
2017-07-27 13:16:01 gpg-agent[24736] DBG: chan_10 -> OK
2017-07-27 13:16:01 gpg-agent[24736] DBG: chan_10 <- OPTION agent-awareness=2.1.0
2017-07-27 13:16:01 gpg-agent[24736] DBG: chan_10 -> OK
2017-07-27 13:16:01 gpg-agent[24736] DBG: chan_10 <- HAVEKEY 12D8258797E0A5713011F4A2837E143B51D3F979 0C7CE46B739921A4DE509EC52CE8453E78F55F2A
2017-07-27 13:16:01 gpg-agent[24736] DBG: chan_10 -> OK
2017-07-27 13:16:01 gpg-agent[24736] DBG: chan_10 <- RESET
2017-07-27 13:16:01 gpg-agent[24736] DBG: chan_10 -> OK
2017-07-27 13:16:01 gpg-agent[24736] DBG: chan_10 <- SIGKEY 12D8258797E0A5713011F4A2837E143B51D3F979
2017-07-27 13:16:01 gpg-agent[24736] DBG: chan_10 -> OK
2017-07-27 13:16:01 gpg-agent[24736] DBG: chan_10 <- SETKEYDESC Please+enter+the+passphrase+to+unlock+the+OpenPGP+secret+key:%0A%22foo@bar.baz%22%0A256-bit+ECDSA+key,+ID+9EFD1A5ED36ECD0D,%0Acreated+2017-04-05.%0A
2017-07-27 13:16:01 gpg-agent[24736] DBG: chan_10 -> OK
2017-07-27 13:16:01 gpg-agent[24736] DBG: chan_10 <- SETHASH 8 34E7E29F9DD756176BACAE3C5F47FA5355402C23F1122189BC615BC771BD0F04
2017-07-27 13:16:01 gpg-agent[24736] DBG: chan_10 -> OK
2017-07-27 13:16:01 gpg-agent[24736] DBG: chan_10 <- PKSIGN
2017-07-27 13:16:01 gpg-agent[24736] starting a new PIN Entry
2017-07-27 13:16:01 gpg-agent[24736] DBG: connection to PIN entry established
2017-07-27 13:16:01 gpg-agent[24736] DBG: chan_10 -> INQUIRE PINENTRY_LAUNCHED 24738 qt 1.0.1-beta17 - xterm-256color :0
2017-07-27 13:16:01 gpg-agent[24736] DBG: chan_10 <- END
2017-07-27 13:16:03 gpg-agent[24736] DBG: error calling pinentry: Checksum error <gcrypt>
2017-07-27 13:16:03 gpg-agent[24736] failed to unprotect the secret key: Checksum error
2017-07-27 13:16:03 gpg-agent[24736] failed to read the secret key
2017-07-27 13:16:03 gpg-agent[24736] command 'PKSIGN' failed: Checksum error <Pinentry>
2017-07-27 13:16:03 gpg-agent[24736] DBG: chan_10 -> ERR 83886090 Checksum error <Pinentry>
2017-07-27 13:16:03 gpg-agent[24736] DBG: chan_10 <- [eof]

From this I take it that the checksum error comes from gcrypt but is wrongly propagated as Pinentry error.

I tried to reproduce this through various scripts in variations of


but failed. So maybe interactive usage plays a role here or it was fixed.

Segv/ref-count error found. Now for the real bug ...

That real bug is not a bug but a wrong error message. Due to the use of OCB we catch passphrase by means of that AEAD mode and not by looking at the cleartext. That resulted in a wrong error message. Fixed to return Bad Passphrase instead.

Obviously the passphrase for the test was either not "test" or the protected key file was corrupted.