#7649 Empty file lists on master mirrors
Closed: Fixed 2 months ago by kevin. Opened 4 months ago by tibbs.

Occasionally the file lists on the mirrors (such as https://dl.fedoraproject.org/pub/fedora/fullfiletimelist-fedora) will show up on the mirrors with zero size. This has the effect that anyone running quick-fedora-mirror directly from the master mirrors will see errors like:

No end marker.  Corrupted file list?
Skipping fedora-enchilada.
No end marker.  Corrupted file list?
Skipping fedora-secondary.

and of course they won't pull any changes. Mirrors downstream of those don't see any errors but of course they don't see any changes, either.

So, I'm trying to track down why this might be happening. It used to happen very rarely but in the past couple of weeks it seems to have become much more common, so something must have changed to cause issues (though it could be as simple as a full disk condition somewhere).

One problem is that the file list generator might be failing, and the wrapper script (which takes care of locking and such) simply won't care. It may help to apply this upstream commit to files/scripts/updates-fullfiletimelist in ansible:

commit 767639f0627417a18bbb9dcf957f9afa0b31dfe8
Author: Jason Tibbitts <tibbs@math.uh.edu>
Date:   Wed Mar 13 10:03:14 2019 -0500

    Don't copy things if the generator failed.

diff --git a/example-create-filelist-wrapper b/example-create-filelist-wrapper
index 7b4e9fb..48efbd2 100755
--- a/example-create-filelist-wrapper
+++ b/example-create-filelist-wrapper
@@ -112,6 +112,11 @@ cd $tmpd

         $CREATE -c -s -d $TOPD/$mod -f $flname -t $tlname

+        if [[ $? -ne 0 ]]; then
+            (>&2 echo "File list generator failed?")
+            exit 1
+        fi
+
         # If a file list exsts and doesn't differ from what we just generated,
         # delete the latter.
         if [[ -f $currentfl ]] && diff -q $currentfl $flname > /dev/null; then

However, this won't help to diagnose why the generator might be failing. I don't know what ends up calling the update-fullfiletimelist script, but if its output gets sent anywhere (email or a log or whatnot) is it possible that someone could send me a sample?


Metadata Update from @bowlofeggs:
- Issue priority set to: Waiting on Assignee (was: Needs Review)

4 months ago

So, it's called in multiple places from different machines.

  • secondary01.phx2.fedoraproject.org:
    cron: name="update-fullfiletimelist" hour="*" minute="55" user="root"
        job="/usr/local/bin/lock-wrapper update-fullfiletimelist '/usr/local/bin/update-fullfiletimelist -l /tmp/update-fullfiletimelist.lock -t /srv/pub alt'"
        cron_file=update-fullfiletimelist
  • rawhide-compose01.phx2.fedoraproject.org runs after the rawhide compose finishes:
sudo -u ftpsync /usr/local/bin/update-fullfiletimelist -l /pub/fedora-secondary/update-fullfiletimelist.lock -t /pub fedora fedora-secondary
  • branched-composer01.phx2.fedoraproject.org runs after branched (f30) composes:
sudo -u ftpsync /usr/local/bin/update-fullfiletimelist -l /pub/fedora-secondary/update-fullfiletimelist.lock -t /pub fedora fedora-secondary
  • bodhi-backend01.phx2.fedoraproject.org runs it everytime it finishes a updates compose and has content to sync.
    cmd = ['/usr/local/bin/update-fullfiletimelist', '-l',
           '/tmp/update-fullfiletimelist.lock', '-t', '/pub']

So, I see the problem, two of them are using local tmp files for lock, which is wrong.

I'll send a patch to make them all use the same...

Actually the secondary01 one doesn't matter since it's only doing alt, but the bodhi-backend01one does need fixing.

ok. I have pushed my change to locking... lets hope this is solved, and re-open if it's not.

:video_game:

Metadata Update from @kevin:
- Issue close_status updated to: Fixed
- Issue status updated to: Closed (was: Open)

4 months ago

Well, I improved quick-fedora-mirror to log properly when it sees this condition and...

Mar 21 19:00:08 pubmirror1.math.uh.edu quick-fedora-mirror[30443]: Err: Invalid file list; skipping fedora-enchilada
Mar 21 19:00:11 pubmirror1.math.uh.edu quick-fedora-mirror[30443]: Err: Invalid file list; skipping fedora-secondary
Mar 21 19:10:12 pubmirror1.math.uh.edu quick-fedora-mirror[31076]: Err: Invalid file list; skipping fedora-enchilada
Mar 21 19:10:55 pubmirror1.math.uh.edu quick-fedora-mirror[31076]: Err: Invalid file list; skipping fedora-secondary
Mar 21 19:20:08 pubmirror1.math.uh.edu quick-fedora-mirror[31917]: Err: Invalid file list; skipping fedora-enchilada
Mar 21 19:20:11 pubmirror1.math.uh.edu quick-fedora-mirror[31917]: Err: Invalid file list; skipping fedora-secondary
Mar 21 19:30:08 pubmirror1.math.uh.edu quick-fedora-mirror[32554]: Err: Invalid file list; skipping fedora-enchilada
Mar 21 19:30:11 pubmirror1.math.uh.edu quick-fedora-mirror[32554]: Err: Invalid file list; skipping fedora-secondary
Mar 22 15:50:08 pubmirror1.math.uh.edu quick-fedora-mirror[19109]: Err: Invalid file list; skipping fedora-enchilada
Mar 22 15:50:10 pubmirror1.math.uh.edu quick-fedora-mirror[19109]: Err: Invalid file list; skipping fedora-secondary
Mar 22 16:00:08 pubmirror1.math.uh.edu quick-fedora-mirror[19886]: Err: Invalid file list; skipping fedora-enchilada
Mar 22 16:00:11 pubmirror1.math.uh.edu quick-fedora-mirror[19886]: Err: Invalid file list; skipping fedora-secondary
Mar 22 16:10:12 pubmirror1.math.uh.edu quick-fedora-mirror[20567]: Err: Invalid file list; skipping fedora-enchilada
Mar 22 16:10:55 pubmirror1.math.uh.edu quick-fedora-mirror[20567]: Err: Invalid file list; skipping fedora-secondary
Mar 22 16:20:08 pubmirror1.math.uh.edu quick-fedora-mirror[21465]: Err: Invalid file list; skipping fedora-enchilada
Mar 22 16:20:11 pubmirror1.math.uh.edu quick-fedora-mirror[21465]: Err: Invalid file list; skipping fedora-secondary
Mar 22 16:30:08 pubmirror1.math.uh.edu quick-fedora-mirror[22072]: Err: Invalid file list; skipping fedora-enchilada
Mar 22 16:30:10 pubmirror1.math.uh.edu quick-fedora-mirror[22072]: Err: Invalid file list; skipping fedora-secondary
Mar 22 16:40:08 pubmirror1.math.uh.edu quick-fedora-mirror[22710]: Err: Invalid file list; skipping fedora-enchilada
Mar 22 16:40:10 pubmirror1.math.uh.edu quick-fedora-mirror[22710]: Err: Invalid file list; skipping fedora-secondary
Mar 22 16:50:08 pubmirror1.math.uh.edu quick-fedora-mirror[23332]: Err: Invalid file list; skipping fedora-enchilada
Mar 22 16:50:11 pubmirror1.math.uh.edu quick-fedora-mirror[23332]: Err: Invalid file list; skipping fedora-secondary
Mar 22 17:00:08 pubmirror1.math.uh.edu quick-fedora-mirror[24063]: Err: Invalid file list; skipping fedora-enchilada
Mar 22 17:00:11 pubmirror1.math.uh.edu quick-fedora-mirror[24063]: Err: Invalid file list; skipping fedora-secondary
Mar 22 17:10:12 pubmirror1.math.uh.edu quick-fedora-mirror[24736]: Err: Invalid file list; skipping fedora-enchilada
Mar 22 17:10:56 pubmirror1.math.uh.edu quick-fedora-mirror[24736]: Err: Invalid file list; skipping fedora-secondary
Mar 22 17:20:08 pubmirror1.math.uh.edu quick-fedora-mirror[25538]: Err: Invalid file list; skipping fedora-enchilada
Mar 22 17:20:11 pubmirror1.math.uh.edu quick-fedora-mirror[25538]: Err: Invalid file list; skipping fedora-secondary
Mar 22 17:30:08 pubmirror1.math.uh.edu quick-fedora-mirror[26145]: Err: Invalid file list; skipping fedora-enchilada
Mar 22 17:30:10 pubmirror1.math.uh.edu quick-fedora-mirror[26145]: Err: Invalid file list; skipping fedora-secondary
Mar 22 17:40:08 pubmirror1.math.uh.edu quick-fedora-mirror[27143]: Err: Invalid file list; skipping fedora-enchilada
Mar 22 17:40:10 pubmirror1.math.uh.edu quick-fedora-mirror[27143]: Err: Invalid file list; skipping fedora-secondary
Mar 22 17:50:08 pubmirror1.math.uh.edu quick-fedora-mirror[27758]: Err: Invalid file list; skipping fedora-enchilada
Mar 22 17:50:11 pubmirror1.math.uh.edu quick-fedora-mirror[27758]: Err: Invalid file list; skipping fedora-secondary
Mar 22 18:00:08 pubmirror1.math.uh.edu quick-fedora-mirror[28376]: Err: Invalid file list; skipping fedora-enchilada
Mar 22 18:00:11 pubmirror1.math.uh.edu quick-fedora-mirror[28376]: Err: Invalid file list; skipping fedora-secondary
Mar 22 18:10:12 pubmirror1.math.uh.edu quick-fedora-mirror[29520]: Err: Invalid file list; skipping fedora-enchilada
Mar 22 18:10:55 pubmirror1.math.uh.edu quick-fedora-mirror[29520]: Err: Invalid file list; skipping fedora-secondary
Mar 22 18:20:09 pubmirror1.math.uh.edu quick-fedora-mirror[30386]: Err: Invalid file list; skipping fedora-enchilada
Mar 22 18:20:11 pubmirror1.math.uh.edu quick-fedora-mirror[30386]: Err: Invalid file list; skipping fedora-secondary
Mar 22 18:30:08 pubmirror1.math.uh.edu quick-fedora-mirror[31024]: Err: Invalid file list; skipping fedora-enchilada
Mar 22 18:30:10 pubmirror1.math.uh.edu quick-fedora-mirror[31024]: Err: Invalid file list; skipping fedora-secondary
Mar 22 18:40:08 pubmirror1.math.uh.edu quick-fedora-mirror[31635]: Err: Invalid file list; skipping fedora-enchilada
Mar 22 18:40:11 pubmirror1.math.uh.edu quick-fedora-mirror[31635]: Err: Invalid file list; skipping fedora-secondary

Times are in UTC. Your push was around 2019-03-20 22:00 so I guess this is still an issue.

If you also applied that check for the generator erroring out, then I should add a quick check that the file list at least has the end marker. I'll whip that up as soon as I finish putting out today's fires.

Metadata Update from @tibbs:
- Issue status updated to: Open (was: Closed)

4 months ago

well, so much for my theory as to what was causing it. ;(

I'll try and think of some other way to track it down.

Just a note that this seems to have gotten a bit rarer lately. One stretch from Mar 24 03:40:10 until17:20:11 and then for only 20 minutes at Mar 27 19:10:30. Nothing since then.

So, shall we call this fixed now? I wish I knew what was causing it...

@tibbs have things been good now? Shall we just close this?

The only thing I've seen in the past month is exactly one instance where alt had an invalid file list for about an hour (April 13 23:10 to 00:10 UTC). And I know the alt file lists are generated differently, so I don't think that would be related.

So I do think it's safe to close but of course I'll mane a note if it shows up again.

Thanks!

:open_file_folder:

Metadata Update from @kevin:
- Issue close_status updated to: Fixed
- Issue status updated to: Closed (was: Open)

2 months ago

Well guess what, it came back today at 0733Z. The file lists for enchilada and secondary are all zero length.

I still need to add some additional checks to the upstream script; just need to put some time together.

Metadata Update from @tibbs:
- Issue status updated to: Open (was: Closed)

2 months ago

Luckily here I know what caused this. I reinstalled the rawhide-composer machine with fedora-30 yesterday and apparently we changed the ansible playbook to install python3-productmd only, when it turns out the updating script needs python2-productmd. I installed that, re-ran the updater and fixed the ansible playbook.

:open_hands:

Metadata Update from @kevin:
- Issue close_status updated to: Fixed
- Issue status updated to: Closed (was: Open)

2 months ago

I kept create-filelist as python2 by default purely so that Fedora infra could run it. If it's safe to use python3 things then I would be more than happy to make it so.

Please do. We are trying to move as much to python3 as we can now...

It should perfectly fine now if you change the shebang line; this just frees me to use more modern python constructs. I didn't learn python until python3 already existed, so I didn't actually use any of the old python syntax.

I will avoid converting it to click, though.

Login to comment on this ticket.

Metadata