The problem
UPDATE: Currently investigating with strace. It seems problem is a HTTP 400 error when accessing the repository
UPDATE2: More weird errors in the server (a .so lib file corrupted, database engine displaying 'Unknown error') so it seems this problem is due to a hardware error.
Unknown error executing apt-key
For example, an fragment of a apt update
execution:
[...]
Get:3 http://deb.debian.org/debian buster-updates InRelease [56,6 kB]
[...]
Err:3 http://deb.debian.org/debian buster-updates InRelease
Unknown error executing apt-key
[...]
W: GPG error: http://deb.debian.org/debian buster-updates InRelease: Unknown error executing apt-key
E: The repository 'http://deb.debian.org/debian buster-updates InRelease' is not signed.
[...]
This was working perfectly since long ago and started to happen overnight. Nothing special was done to the server.
I have other servers with almost the same configuration and they are working ok.
I see no relevant entries in apt and system logs.
What I've tried
There are some posts that say I've to delete /var/lib/apt
, check the trusted keys and similar approaches. None worked.
I've checked the output of apt-key list
: the list is almost the same as another server that works ok, the other server just has one more key for the Jenkins repository.
The output is something like this:
/etc/apt/trusted.gpg.d/debian-archive-bullseye-security-automatic.gpg
---------------------------------------------------------------------
pub rsa4096 2021-01-17 [SC] [expires: 2029-01-15]
AC53 0D52 0F2F 3269 F5E9 8313 A484 4904 4AAD 5C5D
uid [ unknown] Debian Security Archive Automatic Signing Key (11/bullseye) <[email protected]>
sub rsa4096 2021-01-17 [S] [expires: 2029-01-15]
/etc/apt/trusted.gpg.d/debian-archive-bullseye-stable.gpg
---------------------------------------------------------
pub rsa4096 2021-02-13 [SC] [expires: 2029-02-11]
A428 5295 FC7B 1A81 6000 62A9 605C 66F0 0D6C 9793
uid [ unknown] Debian Stable Release Key (11/bullseye) <[email protected]>
/etc/apt/trusted.gpg.d/debian-archive-buster-automatic.gpg
----------------------------------------------------------
pub rsa4096 2019-04-14 [SC] [expires: 2027-04-12]
80D1 5823 B7FD 1561 F9F7 BCDD DC30 D7C2 3CBB ABEE
uid [ unknown] Debian Archive Automatic Signing Key (10/buster) <[email protected]>
sub rsa4096 2019-04-14 [S] [expires: 2027-04-12]
/etc/apt/trusted.gpg.d/debian-archive-buster-security-automatic.gpg
-------------------------------------------------------------------
pub rsa4096 2019-04-14 [SC] [expires: 2027-04-12]
5E61 B217 265D A980 7A23 C5FF 4DFA B270 CAA9 6DFA
uid [ unknown] Debian Security Archive Automatic Signing Key (10/buster) <[email protected]>
sub rsa4096 2019-04-14 [S] [expires: 2027-04-12]
Because I have other servers with almost the same configuration (same Debian 10 OS, very similar installed packages, etc) I desperately tried copying their /var/lib/apt
and /ec/apt
folders to this faulty server: the error persists.
Because I suspect GPG could be wrong, I tried to reinstall it. I downloaded the package from Debian repository and installed using dpkg: same result, issue persists.
Enabling apt debugging: what is different from a working server
You can enable apt debugging. In my case I use:
apt -o Debug::Acquire::http=false -o Debug::Hashes=true -o Debug::pkgAcquire::Auth=true -o Debug::sourceList=true update
This is interesting. I've commented all sources but deb http://deb.debian.org/debian buster main contrib non-free
. The faulty server yields:
# apt -o Debug::Acquire::http=false -o Debug::Hashes=true -o Debug::pkgAcquire::Auth=true -o Debug::sourceList=true update
Get:1 http://deb.debian.org/debian buster InRelease [122 kB]
201 URI Done: http://deb.debian.org/debian/dists/buster/InRelease
ReceivedHash:
- SHA512:c65abc258e9ecc7e506133502add58d9c451bc11c3dd9bf7f23a0d58fb0f7747cc75bee22e58dece5af63f6a1cc7dd7c150a383fbd79ce23655c7aca6c32b78c
- SHA256:45420bba913bb4d35b98319d893d9db2bc0c4034a12c65f07118dd36ee4cea86
- SHA1:dcbc9207da6730f5a268f7c8f452ad62f0fd9705
- MD5Sum:2f497e0885083bf377d7f5cafe9b1762
- Checksum-FileSize:121570
ExpectedHash:
Err:1 http://deb.debian.org/debian buster InRelease
Unknown error executing apt-key
Reading package lists... Done
W: GPG error: http://deb.debian.org/debian buster InRelease: Unknown error executing apt-key
E: The repository 'http://deb.debian.org/debian buster InRelease' is not signed.
N: Updating from such a repository can't be done securely, and is therefore disabled by default.
N: See apt-secure(8) manpage for repository creation and user configuration details.
However, the working servers outputs:
# apt -o Debug::Acquire::http=false -o Debug::Hashes=true -o Debug::pkgAcquire::Auth=true -o Debug::sourceList=true update
0% [Working]201 URI Done: http://deb.debian.org/debian/dists/buster/InRelease
ReceivedHash:
ExpectedHash:
Hit:1 http://deb.debian.org/debian buster InRelease
0% [Working]201 URI Done: http://deb.debian.org/debian/dists/buster/InRelease
ReceivedHash:
ExpectedHash:
Signature verification succeeded: /var/lib/apt/lists/deb.debian.org_debian_dists_buster_InRelease
Got Codename: buster
Got Suite: oldstable
Expecting Dist: buster
Reading package lists... Done
Building dependency tree
Reading state information... Done
All packages are up to date.
As you can see, the faulty server seems to receive some hashes and has no expected hash while the working sever has no hashes at all?
What about other sources? If I try with deb http://deb.debian.org/debian buster-updates main contrib non-free
, the fault servers outputs:
# apt -o Debug::Acquire::http=false -o Debug::Hashes=true -o Debug::pkgAcquire::Auth=true -o Debug::sourceList=true update
Get:1 http://deb.debian.org/debian buster-updates InRelease [56,6 kB]
0% [1 InRelease 56,6 kB/56,6 kB 100%]201 URI Done: http://deb.debian.org/debian/dists/buster-updates/InRelease
ReceivedHash:
- SHA512:3542a4de41bdffba0631f27efdf2dd69602b77b1dd7362285527d3e96d22daaae1165979fc83a740049e2c54de455f798c07f0120baeafd316dd2e9efd68faab
- SHA256:65d8f69e329505a4abdc3968778e36adae20b8542eed9745c60c47bc90ea4c05
- SHA1:e901931cf25b06819fe1a653b39621b5e42a0109
- MD5Sum:db7403e0f919a66b1e05ed537962d333
- Checksum-FileSize:56621
ExpectedHash:
Err:1 http://deb.debian.org/debian buster-updates InRelease
Unknown error executing apt-key
Reading package lists... Done
W: GPG error: http://deb.debian.org/debian buster-updates InRelease: Unknown error executing apt-key
E: The repository 'http://deb.debian.org/debian buster-updates InRelease' is not signed.
N: Updating from such a repository can't be done securely, and is therefore disabled by default.
N: See apt-secure(8) manpage for repository creation and user configuration details.
More or less the same error than before. It includes several keys in ReceivedHash but empty value in ExpectedHash.
What about the working server? It outputs:
# apt -o Debug::Acquire::http=false -o Debug::Hashes=true -o Debug::pkgAcquire::Auth=true -o Debug::sourceList=true update
Get:1 http://deb.debian.org/debian buster-updates InRelease [56,6 kB]
0% [1 InRelease 16,4 kB/56,6 kB 29%]201 URI Done: http://deb.debian.org/debian/dists/buster-updates/InRelease
ReceivedHash:
- SHA512:3542a4de41bdffba0631f27efdf2dd69602b77b1dd7362285527d3e96d22daaae1165979fc83a740049e2c54de455f798c07f0120baeafd316dd2e9efd68faab
- SHA256:65d8f69e329505a4abdc3968778e36adae20b8542eed9745c60c47bc90ea4c05
- SHA1:e901931cf25b06819fe1a653b39621b5e42a0109
- MD5Sum:db7403e0f919a66b1e05ed537962d333
- Checksum-FileSize:56621
ExpectedHash:
0% [Working]201 URI Done: http://deb.debian.org/debian/dists/buster-updates/InRelease
ReceivedHash:
ExpectedHash:
Signature verification succeeded: /var/lib/apt/lists/partial/deb.debian.org_debian_dists_buster-updates_InRelease
....and lot of other lines about other files it downloads, but I guess they are not interesting for this issue.
In this case, the working server also receives hashes in ReceivedHash and empty value in ExpectedHash.
Error 400 accessing repository
Ok, let's dig more into this. Let's use strace
. This is the interesting part:
lchown("/var/lib/apt/lists/partial/deb.debian.org_debian_dists_buster-updates_InRelease", 100, 0) = 0
lstat("/var/lib/apt/lists/partial/deb.debian.org_debian_dists_buster-updates_InRelease", {st_mode=S_IFREG|0644, st_size=56621, ...}) = 0
chmod("/var/lib/apt/lists/partial/deb.debian.org_debian_dists_buster-updates_InRelease", 0600) = 0
rt_sigprocmask(SIG_BLOCK, [WINCH], [], 8) = 0
rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
0% [Working]) = 18% [Working]", 18
write(1, "\33[0m", 4) = 4
select(11, [5 6], [10], NULL, {tv_sec=0, tv_usec=500000}) = 1 (out [10], left {tv_sec=0, tv_usec=499997})
write(10, "601 Configuration\nConfig-Item: A"..., 11121) = 11121
select(7, [5 6], [], NULL, {tv_sec=0, tv_usec=499997}) = 1 (in [6], left {tv_sec=0, tv_usec=364398})
read(6, "400 URI Failure\nMessage: Unknown"..., 64000) = 148
stat("/var/lib/apt/lists/partial/deb.debian.org_debian_dists_buster-updates_InRelease", {st_mode=S_IFREG|0600, st_size=56621, ...}) = 0
getuid() = 0
socket(AF_UNIX, SOCK_STREAM|SOCK_CLOEXEC|SOCK_NONBLOCK, 0) = 7
connect(7, {sa_family=AF_UNIX, sun_path="/var/run/nscd/socket"}, 110) = 0
sendto(7, "\2\0\0\0\0\0\0\0\5\0\0\0root\0", 17, MSG_NOSIGNAL, NULL, 0) = 17
poll([{fd=7, events=POLLIN|POLLERR|POLLHUP}], 1, 5000) = 1 ([{fd=7, revents=POLLIN}])
Specifically, this line:
read(6, "400 URI Failure\nMessage: Unknown"..., 64000) = 148
It seems there's an error during transfer.
What to do now?
How I can dig more into the HTTP error? Can I use apt-key to mimic the request that returns 400? What could I do to fix this (apart form ignoring the GPG sign checks)? Or what other checks can I do to locate the root cause of the issue?
apt-key list
show?