http://qs321.pair.com?node_id=1230173

nysus has asked for the wisdom of the Perl Monks concerning the following question:

Got an odd problem that I'm scratching my head over. I submitted a module where the test fails sometimes, but not all the time: Here are the smoke tests. The last test in this test file, line 68, is the one that is sometimes failing. Note: I changed the cleanup method for deleting the files to skip over directories:

foreach my $file (@files) { $file = File::Spec->catfile($configdir, $file); next if (-d $file); unlink $file if -M $file >= $age; } }

It doesn't help, though. I also tried inserting a delay of one second in the test file to let the file age a little bit. That didn't help either. Not sure what else can be going on.

$PM = "Perl Monk's";
$MCF = "Most Clueless Friar Abbot Bishop Pontiff Deacon Curate Priest Vicar";
$nysus = $PM . ' ' . $MCF;
Click here if you love Perl Monks

Replies are listed 'Best First'.
Re: Intermittent bug in module: File not getting deleted as expected
by haukex (Archbishop) on Feb 19, 2019 at 18:11 UTC

    In addition to what stevieb said about the -M test, which does seem a likely candidate (remember it depends on the behavior of the filesystem), I also see you aren't checking unlink for success or failure. For the former issue, you might want to add some kind of "force" parameter to cleanup to skip the -M test overall and just delete all files, that way the test will be more deterministic.

      Good catch on the unlink checking, I had completely overlooked that. In cleanup(), OP should be doing something like:

      if (-M $file >= $age){ unlink $file or die "can't delete the damned file!: $!"; }

      ...even if your suggested "force" param is introduced.

Re: Intermittent bug in module: File not getting deleted as expected
by haukex (Archbishop) on Feb 19, 2019 at 20:49 UTC

    Although tybalt89 has already said several of these things, just to summarize: -M is the "Script start time minus file modification time, in days." The "Script start time" is kept in $^T, which is in seconds since the epoch. The file's mtime is also reported in seconds. So internally, Perl is doing a division and subtraction - it's too late in the evening here for me to go digging around in the Perl sources, but maybe there's some inaccuracy happening there.

    My opinion: just don't use -M in the first place. Use stat or File::stat to get the mtime and do the comparisons to time and/or $^T yourself, then you've got everything in seconds and can do the calculations on your terms. Since you're already using -M, I assume you don't need to-the-nanosecond precision, so calculating with 1 day = 86400 seconds is probably good enough.

      I was also thinking of using stat(). I even spent a fraction of time searching through my code to see where I've used it, but too many answers were flying in to bother continuing.

      Ironically, throughout this thread, I've been dealing with a timing issue in one of my Arduino projects, so I truly understand the frustration here :D

Re: Intermittent bug in module: File not getting deleted as expected
by stevieb (Canon) on Feb 19, 2019 at 18:05 UTC

    Could your test be failing due to a timing issue, here, due to this param?

    It doesn't really look like it because it does appear as though you're handling and sending in the $age param correctly, but printing out the variables wouldn't hurt (ie. my $x = -M $file; print "$x: $age\n";) to see what's going on there for real.

    Can you reproduce it on a local machine at all?

    You could try adding a delay of a second after the cleanup() routine (eg: sleep 1;), and before the file-exists test. Perhaps the full cleanup of the file isn't quite complete in some systems before checking if the file is really gone.

      So, I found the issue, but not the solution. When the test fails, -M $file is a negative value like -1.15740740740741e-05.

      I can reproduce on a local machine, yes. It happens maybe 10% of the time, which is weird. I had tried adding a delay already. I just tried increasing the delay to a full 2 seconds and that didn't help.

      When the test fails, I do see the file pop up momentarily in the directory. So it definitely exists (and the previous test proves it).

      $PM = "Perl Monk's";
      $MCF = "Most Clueless Friar Abbot Bishop Pontiff Deacon Curate Priest Vicar";
      $nysus = $PM . ' ' . $MCF;
      Click here if you love Perl Monks

        By the way, the time value appears to always be the same: -1.15740740740741e-05

        Interestingly, that appears to be exactly 1 second. But why is it negative?

        $PM = "Perl Monk's";
        $MCF = "Most Clueless Friar Abbot Bishop Pontiff Deacon Curate Priest Vicar";
        $nysus = $PM . ' ' . $MCF;
        Click here if you love Perl Monks

Re: Intermittent bug in module: File not getting deleted as expected
by Perlbotics (Archbishop) on Feb 19, 2019 at 18:15 UTC
Re: Intermittent bug in module: File not getting deleted as expected
by bliako (Monsignor) on Feb 19, 2019 at 21:04 UTC
                   -M  Script start time minus file modification time, in days.

    So, it can be negative if you modified the file within(=after execution) the script, as per:

    sleep 1; `touch xbxbx`; my $x = -M "xbxbx"; print "x=$x\n";

    Furthermore, the output of -M is fractional Earth days and 1 Earth second is that much of a 24hr Earth day: print sprintf "1 Earth second is %e of an Earth day\n", 1/(24*60*60); ... => 1.157407e-05, which btw is roughly PI/20 millions^-1.

    Gosh Larry! My Perl code on Mars is buggy!

    bw, bliako

Re: Intermittent bug in module: File not getting deleted as expected
by nysus (Parson) on Feb 19, 2019 at 18:47 UTC

    OK, I'm beginning to think this is some kind of bug with -M, or the OS (happening on Linux and Mac, though). If I add a delay into the test script of a whole 5 seconds, the file age will sometimes be reported as a negative value -1.15740740740741e-05.

    I think I'm going to solve this by simply changing it from -M $file > 0 to -M $file > -1 as suggested above.

    Thanks!

    But curious to know why it's reporting a negative value at all.

    $PM = "Perl Monk's";
    $MCF = "Most Clueless Friar Abbot Bishop Pontiff Deacon Curate Priest Vicar";
    $nysus = $PM . ' ' . $MCF;
    Click here if you love Perl Monks

      If I understand your problem (which is very iffy).

      -M measures from start of program (kept in $^T). sleep() just make things worse. Adjust start of program. $^T = time; at or after creation of file will fix;

        - M reports the age of the file in days.

        $PM = "Perl Monk's";
        $MCF = "Most Clueless Friar Abbot Bishop Pontiff Deacon Curate Priest Vicar";
        $nysus = $PM . ' ' . $MCF;
        Click here if you love Perl Monks

      I think you mean:

      if (-M $file > -2)

      In other words, -1.15 is less than -1, not greater than ;)

      Either way, it would be nice to find out exactly what's happening here. I'll play around later. If you happen to find anything, post back please.

        I think we have the answer for this behavior. See the comment further down and this. It seems that the time the script starts is factored into the age of the file. Still trying to wrap my head around it, though. Seems weird.

        $PM = "Perl Monk's";
        $MCF = "Most Clueless Friar Abbot Bishop Pontiff Deacon Curate Priest Vicar";
        $nysus = $PM . ' ' . $MCF;
        Click here if you love Perl Monks

        Well, it's to the power of 10^-5, so -.000015.

        $PM = "Perl Monk's";
        $MCF = "Most Clueless Friar Abbot Bishop Pontiff Deacon Curate Priest Vicar";
        $nysus = $PM . ' ' . $MCF;
        Click here if you love Perl Monks