Project

General

Profile

Bug #3053

pacman reports “maximum file size exceeded” on a number of Parabola libre systems during system upgrade

Drag0nFly - 3 months ago - . Updated 12 days ago.

Status:
confirmed
Priority:
bug
Assignee:
-
% Done:

0%


Description

  • steps to reproduce:

pacman -Syyu

  • expected result:

Packages download and install successfully

  • actual result:

error: failed retrieving file 'dovecot-2.3.15-2-x86_64.pkg.tar.zst' from redirector.parabola.nu : Operation timed out after 10001 milliseconds with 0 out of 0 bytes received
error: failed retrieving file 'dovecot-2.3.15-2-x86_64.pkg.tar.zst?noredirect.sig' from repo.parabola.nu : Maximum file size exceeded

This issue started occurring within the last couple of days, and has been verified on a number of systems.


Files

got_it.log (2.83 KB) got_it.log Partial pacman log catching the described errors with debug output freemor, 2021-06-29 01:07 AM

History

#1

Updated by Drag0nFly 3 months ago

System #2:

sudo pacman -Syyyu
[sudo] password for martin:
:: Synchronizing package databases...
 nonprism                                                                                                    24.5 KiB  18.9 KiB/s 00:01 [##################################################################################] 100%
 nonsystemd                                                                                                  39.3 KiB   176 KiB/s 00:00 [##################################################################################] 100%
 libre                                                                                                      340.1 KiB  1030 KiB/s 00:00 [##################################################################################] 100%
 core                                                                                                       119.9 KiB   508 KiB/s 00:00 [##################################################################################] 100%
 extra                                                                                                     1440.3 KiB  4.90 MiB/s 00:00 [##################################################################################] 100%
 community                                                                                                    5.3 MiB  11.6 MiB/s 00:00 [##################################################################################] 100%
 pcr                                                                                                        524.8 KiB   524 KiB/s 00:01 [##################################################################################] 100%
:: Starting full system upgrade...
warning: flac: ignoring package upgrade (1.3.2-2 => 1.3.3-3)
warning: libp11-kit: local (0.24.0-1) is newer than nonsystemd (0.23.20-5.nonsystemd1)
warning: netpbm: local (10.73.33-1) is newer than libre (10.73.31-1.parabola1)
warning: p11-kit: local (0.24.0-1) is newer than nonsystemd (0.23.20-5.nonsystemd1)
warning: shntool: local (3.0.10-6) is newer than libre (3.0.10-5.parabola1)
resolving dependencies...
looking for conflicting packages...

Packages (10) iceweasel-1:89.0.2-1.parabola1  libcanberra-0.30+2+gc0620e4-5  libldap-2.4.59-1  libmediainfo-21.03-1  libzen-0.4.39-1  mediainfo-21.03-1  python-docutils-0.17.1-1  ruby-irb-1.3.6-1  tinyxml2-9.0.0-1
              torbrowser-launcher-0.3.4-2

Total Download Size:    55.66 MiB
Total Installed Size:  226.67 MiB
Net Upgrade Size:        0.19 MiB

:: Proceed with installation? [Y/n]
:: Retrieving packages...
 libldap-2.4.59-1-x86_64                                                                                    303.5 KiB   273 KiB/s 00:01 [##################################################################################] 100%
 libcanberra-0.30+2+gc0620e4-5-x86_64                                                                        91.6 KiB   168 KiB/s 00:01 [##################################################################################] 100%
 iceweasel-1:89.0.2-1.parabola1-x86_64                                                                       51.8 MiB  32.0 MiB/s 00:02 [##################################################################################] 100%
 libzen-0.4.39-1-x86_64                                                                                     126.5 KiB   178 KiB/s 00:01 [##################################################################################] 100%
 Total ( 4/10)                                                                                               55.7 MiB  12.9 MiB/s 00:04 [##################################################################################] 100%
error: failed retrieving file 'libzen-0.4.39-1-x86_64.pkg.tar.zst?noredirect.sig' from repo.parabola.nu : Maximum file size exceeded
warning: failed to retrieve some files
error: failed to commit transaction (download library error)
Errors occurred, no packages were upgraded.
#2

Updated by bill-auger 3 months ago

i had no problem installing dovecot and libzen today - this URL
looks peculiar though
'dovecot-2.3.15-2-x86_64.pkg.tar.zst?noredirect.sig'

could you clear your cache and try again?

# pacman -Scc
# pacman -Syyuu

#3

Updated by Drag0nFly 3 months ago

I'd rather not remove all downloaded packages, as the issue does not seem to be related to a specific package.

The issue does not only occur with dovecot, but with libzen as well.

When performing a manual upgrade of the same package pacman complains about, it works.

#4

Updated by Drag0nFly 3 months ago

I agree that the issue appears to be related to the ?noredirect suffix, which I presume is added by the mirror. I use the standard (system-defined) revolving mirror on all my systems, btw.

#5

Updated by Drag0nFly 3 months ago

Same for dovecot, the actual downloaded file is ok, but something trips up pacman during “pacman -Syyu” into thinking there is corruption/too-large-file issue.

#6

Updated by Drag0nFly 3 months ago

I'm pretty sure this is related to the redirector service, as repository sync is sometimes painfully slow. (and no, there is no issue with the Internet connection)

error: failed retrieving file 'extra.db' from redirector.parabola.nu : Operation too slow. Less than 1 bytes/sec transferred the last 10 seconds
error: failed retrieving file 'extra.db' from redirector.parabola.nu : Operation too slow. Less than 1 bytes/sec transferred the last 10 seconds
error: failed retrieving file 'extra.db' from redirector.parabola.nu : Operation too slow. Less than 1 bytes/sec transferred the last 10 seconds
warning: too many errors from redirector.parabola.nu, skipping for the remainder of this transaction
error: failed to synchronize all databases (download library error)
#7

Updated by freemor 3 months ago

  • File pacman.log added

I've been poking at this trying to reproduce and was finally able. Including the pacman debug log of the event. I caught the "file size to large error and the "?noredirect" thing.

I'll dig into it tomorrow.. to late here now and it's been far too long a day. Posting the log here for others.

#8

Updated by freemor 3 months ago

  • File deleted (pacman.log)
#9

Updated by freemor 3 months ago

apologies.. first attempt didn't capture the debug output. Then couldn't reproduce again.
deleted the useless file.
will keep trying.

#10

Updated by freemor 3 months ago

The revelant bit was still on my CLI screen.. cut/pasted it into a file.
pasting that here. not as nice as a complete log. but probably good info

#11

Updated by bill-auger 3 months ago

so is this ticket 'confirmed'?

in case this is related to the new pacman v6, a pacman v5 is still in the repos

https://repo.parabola.nu/pool/parabola/pacman-5.1.1-1.parabola6-x86_64.pkg.tar.xz
https://repo.parabola.nu/pool/parabola/pacman-5.1.1-1.parabola6-x86_64.pkg.tar.xz.sig

#12

Updated by freemor 3 months ago

  • Status changed from unconfirmed to confirmed

Yep, just forgot to mark it as such. Confirmed but hard to catch.

The timing out part definitely seems to be about trying to -Suyy while winston is rsync'ing from Arch. For some reason that is causing a more noticable lagginess than it used to.

The wrong size. Seems to be some weird edge case. I'll try tonight to see if it happens if one -Suys just prior to the Rsync with arch (because that is when it happened last night). From the debug log it looks like it might be a case of pacman, gpgme, or curl getting confused by the 304 response from the redirector and sticking the ?noredirect parameter between the basename and the .sig extension

it tries to fetch:

https://repo.parabola.nu/core/os/x86_64/gpgme-1.16.0-1-x86_64.pkg.tar.zst?noredirect.sig

Which I suspect should be

https://repo.parabola.nu/core/os/x86_64/gpgme-1.16.0-1-x86_64.pkg.tar.zst.sig?noredirect

or just

https://repo.parabola.nu/core/os/x86_64/gpgme-1.16.0-1-x86_64.pkg.tar.zst.sig

I just tried curling

https://repo.parabola.nu/core/os/x86_64/gpgme-1.16.0-1-x86_64.pkg.tar.zst?noredirect.sig

As one would expect it it fetches the package again instead of the .sig That would definitely explain the size mismatch thing.

So it's down to which part of the process is sticking the ?noredirect in the wrong spot.

#13

Updated by freemor 3 months ago

Ran a few more tests.

redirector normally responds 302 as expected to redirect to the mirror

it what I caught last night it responded 304 (not changed). I was hoping to catch a 304 response to see if that is where the noredirect comes from as greping through the pacman source there is no reference to "noredirect"

#14

Updated by bill-auger 3 months ago

i got this error on beefcake - it was during a sync with arch ~50mbps - maybe that is the cap - the shell was super laggy during the entire sync - the error was not persistent though - i got the package on the next run

can anyone reproduce this consistently, with a specific package?

we could try to correlate with a running sync job, if people note the times of future errors

#15

Updated by bill-auger 3 months ago

the "noredirect" is probably injected by the redirector nginx config, to ensure that all signatures are downloaded from winston

that URL is not right though - it should be:

https://repo.parabola.nu/core/os/x86_64/gpgme-1.16.0-1-x86_64.pkg.tar.zst.sig?noredirect

#16

Updated by Drag0nFly 2 months ago

Also getting "server is busy" when trying to submit these updates to labs.parabola.nu

#17

Updated by Drag0nFly 2 months ago

Things appear to have normalized now. Main issue was yesterday, Sunday 11th, when the timeouts encompassed a few hours in the middle of the day (CEST).

#18

Updated by bill-auger 2 months ago

the "server busy" message is #2297

thanks for following-up on it; but your last few posts added nothing new, so i deleted them for brevity - i can only think of two things which would be relevant to add now

  • can anyone reproduce this consistently, with any specific package?
  • if people note the times of future errors, we could try to correlate with a running sync job

your pacman log will indicate the time - that alone may be an interesting bit of information

for example, this command will show each time `pacman -Sy` has been run

$ grep synchronizing /var/log/pacman.log
#19

Updated by Drag0nFly 2 months ago

Occurring again with ca-certificates-mozilla. (Although I doubt this is related to a single or specific packages.)

#20

Updated by Drag0nFly 2 months ago

At the same time the "server busy" error is also re-occurring.

As for the pacman synchronizing timestamps–

[2021-07-11T00:21:10+0200] [PACMAN] synchronizing package lists
[2021-07-11T22:18:43+0200] [PACMAN] synchronizing package lists
[2021-07-11T22:19:56+0200] [PACMAN] synchronizing package lists
[2021-07-11T22:21:39+0200] [PACMAN] synchronizing package lists
[2021-07-12T15:01:15+0200] [PACMAN] synchronizing package lists
[2021-07-15T02:27:50+0200] [PACMAN] synchronizing package lists
[2021-07-15T02:28:12+0200] [PACMAN] synchronizing package lists
#21

Updated by Drag0nFly 2 months ago

And again the downloaded package itself is ok – ca-certificates-mozilla

#22

Updated by Drag0nFly 2 months ago

Same issue for nss

#23

Updated by bill-auger 2 months ago

[2021-07-11T22:19:56+0200] [PACMAN] synchronizing package lists

but which of those corresponds to the timeouts?

i was not asking for every package which timeouts - only if some package ALWAYS does ("consistently" eg: an hour later, AND a day later) - i suspect that it is not a problem with any specific package - the main server is over-worked - we are working on getting a new one to supplement it - that is the most likely cause of any intermittent problems

#24

Updated by Drag0nFly 2 months ago

That would be the last one/two entries from July 15th (incorrect rewrite affecting ca-certificates-mozilla & nss pkgs) –

[2021-07-15T02:27:50+0200] [PACMAN] synchronizing package lists
[2021-07-15T02:28:12+0200] [PACMAN] synchronizing package lists

Redmine does not supply the timezone or UTC time, which would make this easier to pinpoint.

For the instance reported earlier on June 24th: (libzen)

[2021-06-24T23:15:28+0200] [PACMAN] synchronizing package lists

If anything special happened on your server-end during that time it could give some clues. But it does sound like this is caused by a bottleneck which would be addressed by some load-sharing and dedicated systems. Nevertheless strange that nginx would put these suffices on the packages due to this.

There are no packages that this has consistently happened with hours or days after it started. I can re-test from one of the systems if this happens again. On the main server the packages affected were simply upgraded manually from /var/cache/pacman/pkg

#25

Updated by bill-auger 2 months ago

that 500 error from redmine is a completely separate issue; and i
know how to fix it already - dont worry about that - it is only a
harmless nuisance

#26

Updated by bill-auger 2 months ago

the ones on 2021-07-15 were definitely during a sync with arch

#27

Updated by Drag0nFly 2 months ago

What 500 error? I was talking about the timestamps and how best correlate those between different timezones, as Redmine only appears to show the local time.

#28

Updated by bill-auger 2 months ago

the 500 error is the "server is busy" web page youve mentioned twice - its not related or even important

any timestamps on redmine are also not relevant - only the timestamp in the pacman log is

[2021-07-15T02:28:12+0200] [PACMAN] synchronizing package lists

that was july 15 2021 at 02:28 AM, your local time, which is UTC + 2 hours
so the UTC time was 00:28 AM, which was during a daily rsync

#29

Updated by Drag0nFly 2 months ago

Again: the reason I mentioned Redmine was solely due to its timestamps not having timezone information on them. This was in order to correlate the issue reported with the Pacman sync log, which are in CEST against the issue tracker - nothing else.

I did not mention anything relating to a 500 error from Redmine, which your comment addressed in response to the information I provided today. It is correct that I mentioned a server busy error many posts back, and I sincerely apologize if this offended you in some way. It was mentioned as these issues appeared to be capacity-related, which they now have been confirmed as being.

#30

Updated by bill-auger 2 months ago

gotcha - i didnt know why you mentioned the times that redmine
shows

no worries - i was not offended - you are trying to help
parabola - thats all that is important - your help is greatly
appreciated

#31

Updated by Drag0nFly 2 months ago

Good to have that sorted; and that at least one occurrence falls within a daily rsync job.
This weekend appears to have been normal so far though; with none of the “operation too slow” or “maximum file size exceeded” errors being reported.

I'll report back in if there are any further issues – or if any other information comes up that would be of use.

#32

Updated by Drag0nFly about 2 months ago

Experienced similar slowness today, this time with the upgraded perl package (the only package slated for upgrade)

It upgrades, despite the “failed retrieving file” error.

error: failed retrieving file 'perl-5.34.0-2-x86_64.pkg.tar.zst' from redirector.parabola.nu : Operation too slow. Less than 1 bytes/sec transferred the last 10 seconds
(1/1) checking keys in keyring                                                                                                           [####################################################################################] 100%
(1/1) checking package integrity                                                                                                         [####################################################################################] 100%
(1/1) loading package files                                                                                                              [####################################################################################] 100%
(1/1) checking for file conflicts                                                                                                        [####################################################################################] 100%
(1/1) checking available disk space                                                                                                      [####################################################################################] 100%
:: Running pre-transaction hooks...
(1/1) etckeeper: pre-transaction commit
[master fb4dba1] saving uncommitted changes in /etc prior to pacman run
 2 files changed, 930 insertions(+)
:: Processing package changes...
(1/1) upgrading perl                                                                                                                     [####################################################################################] 100%
:: Running post-transaction hooks...
(1/2) Warn about old perl modules
(2/2) etckeeper: post-transaction commit
root@dragonfly ~#
root@dragonfly ~# pacman -Q perl
perl 5.34.0-2

Last two pacman sync events from pacman.log

[2021-07-25T15:50:32+0200] [PACMAN] synchronizing package lists
[2021-07-26T14:21:39+0200] [PACMAN] synchronizing package lists
#33

Updated by Drag0nFly about 2 months ago

Quite some slowness today.

error: failed retrieving file 'extra.db' from redirector.parabola.nu : SSL connection timeout

...
error: failed retrieving file 'nonprism.db' from redirector.parabola.nu : Operation too slow. Less than 1 bytes/sec transferred the last 10 seconds
error: failed retrieving file 'nonsystemd.db' from redirector.parabola.nu : Operation too slow. Less than 1 bytes/sec transferred the last 10 seconds
...

error: failed retrieving file 'libcap-ng-0.8.2-3-x86_64.pkg.tar.zst' from redirector.parabola.nu : Operation too slow. Less than 1 bytes/sec transferred the last 10 seconds
warning: too many errors from redirector.parabola.nu, skipping for the remainder of this transaction
warning: failed to retrieve some files
error: failed to commit transaction (download library error)
Errors occurred, no packages were upgraded.

Latest pacman sync:

[2021-07-31T14:13:57+0200] [PACMAN] synchronizing package lists
#34

Updated by Drag0nFly about 2 months ago

Today there were some 404 errors instead of the usual 'operation too slow' messages. (The packages still upgrade though in the same step, despite of this.)

error: failed retrieving file 'mkvtoolnix-gui-60.0.0-1-x86_64.pkg.tar.zst' from redirector.parabola.nu : The requested URL returned error: 404
error: failed retrieving file 'mkvtoolnix-gui-60.0.0-1-x86_64.pkg.tar.zst' from redirector.parabola.nu : The requested URL returned error: 404
error: failed retrieving file 'pacman-mirrorlist-20210803-1.parabola1-any.pkg.tar.xz' from redirector.parabola.nu : The requested URL returned error: 404
warning: too many errors from redirector.parabola.nu, skipping for the remainder of this transaction
#35

Updated by Drag0nFly 12 days ago

Things have worked flawlessly for quite a while, but the same same issue occurred today with —

error: failed retrieving file 'imagemagick-7.1.0.6-1-x86_64.pkg.tar.zst?noredirect.sig' from repo.parabola.nu : Maximum file size exceeded

and

error: failed retrieving file 'libsamplerate-0.2.2-1-x86_64.pkg.tar.zst?noredirect.sig' from repo.parabola.nu : Maximum file size exceeded

grep synchronizing /var/log/pacman.log|tail -2
[2021-09-06T02:30:39+0200] [PACMAN] synchronizing package lists
[2021-09-06T02:32:36+0200] [PACMAN] synchronizing package lists

Also available in: Atom PDF