file_date updates from package-release-nodes.php not always saved to the DB.

I had this problem too, but it just solved itself after about a day and a half after my last updated commit.

Strange I thought, but hey it works for me now

a) you're not supposed to be able to edit those parts of a release node. that's by design.

b) see http://drupal.org/node/89699 for my ideas on the very small subset of things should should be able to edit on an older HEAD release node which you can't yet do. no, that's not a bug either, it's a feature request. ;)

what missing info are you trying to change on these old HEAD nodes?

yeah, i see what you mean about having those fields a) blank, b) disabled and c) required that isn't particularly friendly. ;) however, it's certainly not critical (the release nodes are still there and working fine). just because they're not showing up on the table of downloads on your project node doesn't mean they don't exist. see http://drupal.org/node/90450/release.

just to make sure i'm not crazy, i ran a version of the packaging script manually, and it correctly noticed there was no work to do repackaging your HEAD release, since it thinks the most recent copy is from 2006-12-28, and that's the last time you changed any code in HEAD. so, it's not generating newer releases since you haven't changed anything since then.

however, i saw the release node saying it was from 2006-11-13, which makes no sense. then i noticed that an old minor bug i had fixed in http://drupal.org/node/97780 had resurfaced during the D5 port. the "Last updated" wasn't getting printed correctly in a few rare cases. i just installed the fix and it seems to have resolved the trouble with directory-HEAD.

i'll leave this open about the minorly weird/annonying thing about the old HEAD nodes that have fields you can't change which are blank yet the validation expects something there, but this is far from critical.

crap, but it's still showing the wrong date for http://drupal.org/node/96367 :(

the good news is that if you actually download the tarballs, the files *are* the most recent code. the bad news is that the DB doesn't always appear to be getting the updated info about file date and md5hash when new tarballs are generated. :( grrr.

this is the Nth time i've suspected that the db updates from package-release-nodes.php aren't always getting saved, which is *most* annoying and troubling. i didn't think db_query() could fail like that. :( wtf? maybe killes can look at this with me some time and we can try to figure out how these updates could fail and what we could do to make sure that never, ever happens.

*sigh*

just to clarify: the majority of the time, everything works fine, and the DB has the accurate values. but, there appears to be a handful of cases where these db_query() updates fail or for whatever other brain-dead reason, the {project_release_nodes} table in the DB doesn't match reality.

i guess we could have another cron job that scans this directory every day or so to make sure this table is in sync, just to be extra paranoid. but i'd rather be able to just trust the damn packaging script when it updates the DB in the first place... moreover, this directory scan would be pretty expensive -- tons of stat() calls and md5_file() calls, plus about 4500 individual UPDATE queries to run. yuck.

As a follow-up to the 'date not being reflected accurately' - I'm wondering if there is different behavior for this between official releases and developer releases. I have noted several developer release that have inaccurate dates over the past few weeks, but I can't recollect seeing this happen on an official release.

Maybe there is something in the script for official releases which could solve this problem for the developer releases (assuming that the bad behavior really is unique to them)?

i think the big difference between the official and developer releases is that for the official releases, we do 1 query to get a small (0-5) result set of official releases that exist, but have no file and are not published yet. we run this every 5 minutes, the packaging job is tiny, and we generate at most 2-6 watchdog entries, 0-5 updates to {node} and {project_release_nodes}.

OTOH, the devel snapshot invocation does a query with a huge result set of all development snapshot release nodes (~2350), and does a ton of filesystem I/O for each one (exporting from CVS, finding the youngest file in the resulting directory tree, and comparing that to the file date on the existing tarball), and generates at least 2 watchdog entries per release node (even if just to say "foo-5.x-1.x-dev is unchanged, not re-packaging") and another couple of DB updates if any are actually re-built.

so, the comparitive load on the DB is about 3 orders of magnitude different between the 2 cases. :( i suspect that's the problem... the DB is just getting overwhelmed, and then some of the updates are just silently getting dropped.

see http://drupal.org/node/105223 for more on just trying to optimize the script. maybe these 2 issues are intimately related.

however, even if the script was less expensive, the DB could be getting pounded by other means, so it'd still be good to both check all return values from db_query(), and perhaps still write this fall-back script to periodically (like 1/day) scan the directory where the tarballs live and update the md5 and file dates for each one in the DB (which would be another potentially very expensive operation on the DB, but is required right now for correctness, and might still be good to have even if these other issues are improved/resolved).

ok, i modified the packaging script to understand some additional command-line arguments: 'check' and 'repair'. if invoked with either arg, the script doesn't package anything, but instead queries the DB for the file_path, date, and md5hash of all published release nodes. it iterates over them all, comparing what's in the DB with what's really in the file system. for any files where the data on disk doesn't match what's in the DB, it logs a message to the watchdog, and keeps a running total. if invoked with 'repair', it will update the stale release nodes in the DB.

i tested this heavily on s.d.o, and then ran it once in 'check' mode on d.o. the results are almost horrifying:

Done checking releases: 2164 need repairing, 2994 considered.
ERROR: 30 files are in the database but do not exist on disk.

these 30 files in the DB that aren't on disk are all from projects that have been unpublished. i should probably modify my script to just ignore release nodes from projects that aren't published.

however, the 2164 nodes that need repairing is a staggering figure. :(

my plan:
1) commit these changes to the packaging script and officially install it on d.o
2) run it in 'repair' mode for real on d.o
3) add it to the drupal-cron users's crontab to at least spawn it in 'check' mode maybe 1/day. the messages go to a different watchdog type ('package_check') so we can filter on that and get a sense over time how often things are getting out of sync.
4) consider how often to run it in repair mode...

of course, there's the deeper question of why things are getting out of sync at all. for that, i'm planning to at least check the return value of db_query() every time we invoke it in the packaging script to update this meta data, and attempt to watchdog() about it in case of any failures. perhaps i'll make it so the script attempts to sleep() and then retry or something. input on this aspect of the problem would be much appreciated.

based on some feedback from heine and dries, new version of the checking/repairing stuff, to print out some more useful info.

Done checking releases: 2164 need repairing, 2164 invalid dates, 7 invalid md5 hashes, 2994 considered.

also, the individual watchdog entries now are a little more friendly:

File date for files/projects/spamspan-5.x-1.x-dev.tar.gz is incorrect: saved date: January 18, 2007 - 00:14 (1169079242) real date: January 19, 2007 - 00:13 (1169165590)

the big news is that in IM, dries asked the right questions, which got me to see something i had been overlooking, and i'm pretty sure i now see what might be causing the problem! ;) i need to test/investigate a little more, but a new patch for that will hopefully be coming soon. for now, this patch is just the improved logging for the checking stuff. stay tuned as this develops...

commited #15 to HEAD and DRUPAL-4-7--2, and installed on d.o.
backed up the stable {project_release_nodes} table for later analysis
ran the script in repair mode. everything should be happy (for now) on d.o.

i'll continue to investigate what i believe is the source of the bug, and add better error reporting and robustness into the packaging script itself, so hopefully we won't have to run the repair script in the future...

backed up the stable {project_release_nodes} table for later analysis

hehe, i meant: the "stale" table, not "stable"... it's 2am here, forgive me. ;)

i haven't tested this yet, nor verified that our suspicion about the source of the problem is correct, but this should certainly help.

currently, after we generate the tarball, we try to remove the tmp directory where we had checked out the source. if this fails, we consider it a fatal error and do not update the DB about the new tarball(!). i looked on d.o, and the tmp dir where we build development snapshots is full of subdirectories that haven't been cleaned up. :( it's not immediately obvious what's going wrong here. what's even weirder is that there don't appear to be the errors in the watchdog() about failures to run rm.

however, it's obvious that we should treat failure to remove this directory as a non-fatal error, and at least attempt to update the DB as soon as tar completes successfully. attached patch does this. it also tries to clean up the tmp directory before and after it runs to attempt to be more tidy.

please review carefully, as this is messing with dangerous commands. ;)

thanks,
-derek

so, between when i repaired things last night and right now, we had another dev snapshot packaging run:

Done packaging releases from branches: 35 built, 2344 considered.

i just ran the check script again, and nearly all of those new packages have the wrong date:

Done checking releases: 34 need repairing, 34 invalid dates, 1 invalid md5 hashes, 2997 considered.

:(

(btw, the difference in the # considered is from 2 things: 1) the check script is looking at all releases, including official releases, while the branch-only packaging run is just looking at dev snapshots, 2) the packaging script ignores projects that are unpublished, whereas the check script only ignores release nodes that are unpublished).

i haven't installed my patch to move the rm and see if that changes anything... however, i doubt that's going to solve things, since we *never* see errors in the watchdog about rm failing.

HOWEVER, in IRC, drewish pointed out clearstatcache() http://us2.php.net/manual/en/function.clearstatcache.php i had *NO* idea that php was caching the results of stat() unless you manually tell it otherwise. :( this almost certainly explains most, if not all, of the problems!

so, i'll roll a new patch that calls clearstatcache() before it's trying to compute the info about the new package to update into the DB, and this nightmare should soon be over... ;)

new patch with a well-placed clearstatcache(). i have high hopes. ;) also includes the changes to when/how we rm the tmp dirs, and a minor code re-org when we're initializing to not create a tmp dir for check and repair runs.

killes reviewed the patch in IRC, so i committed to HEAD and DRUPAL-4-7--2 and installed on d.o. then, i did the following:
- backed up {project_release_nodes} again
- repaired the DB from last night's run
- ran the new improved packaging script to generate dev snapshots
- re-checked

everything worked perfectly. there's only 1 release node with trouble, but that's because 2 release nodes are trying to use the same filename (i though the code prevented this, hehe), so things are confused. see http://drupal.org/node/110841 for more on that.

so, i think this issue is hereby resolved. WOO HOO!