lastAccessed and lastModified timestamps sometimes are off by 1 second

[jamesderlin]

package:file has tests to verify that lastAccessed and lastModified timestamps are within an expected range, and those tests have been flaky for local filesystems.

Reproduction code that creates a new File and sanity-checks its lastModified time, repeating as many times as it can for 1 second:

import 'dart:io' as io;

/// Returns a [DateTime] with an exact second-precision by removing the
/// milliseconds and microseconds from the specified [time].
DateTime floor(DateTime time) => DateTime(
      time.year,
      time.month,
      time.day,
      time.hour,
      time.minute,
      time.second,
    );

void main() {
  String filePath = '/tmp/file-time-test';

  DateTime stopTime = DateTime.now().add(const Duration(seconds: 1));
  DateTime now;
  do {
    io.File? f;
    try {
      now = DateTime.now();

      DateTime before = floor(now);
      f = io.File(filePath)..createSync();
      DateTime modified = f.lastModifiedSync();

      if (before.compareTo(modified) > 0) {
        print('Unexpected mtime:\n'
            'now: $now\n'
            'modified: $modified\n'
            'floor: $before\n');
        break;
      }
    } finally {
      if (f != null && f.existsSync()) {
        f.deleteSync();
      }
    }
  } while (now.isBefore(stopTime));
}

Output from an example failure:

Unexpected mtime:
now: 2020-06-22 17:02:28.000022
modified: 2020-06-22 17:02:27.000
floor: 2020-06-22 17:02:28.000

Since it seems that lastAccessed and lastModified have a resolution of 1s, I could understand if the modification time in the above case were rounded down to 17:02:28 or rounded up to 17:02:29, but the reported time of 17:02:27 seems baffling. (Did some optimization reorder statements?)

One interesting thing that I've observed is that all of the failures I've seen occur when the fractional seconds are <5ms.

I thought that it might be a bug in the underlying filesystem, but I have been unsuccessful reproducing this bug with analogous C code:

#include <errno.h>
#include <stdio.h>
#include <string.h>
#include <time.h>

#include <sys/stat.h>
#include <unistd.h>

static void printError(const char* message, int err) {
  fprintf(stderr, "%s: %s (%d)\n", message, strerror(err), err);
}

int main(void) {
  // Run for up to 10 seconds.
  time_t stopTime = time(NULL) + 10;
  time_t now;

  const char* filePath = "/tmp/file-time-test";

  do {
    FILE* fp;
    struct stat statBuf = { 0 };

    now = time(NULL);

    fp = fopen(filePath, "wb");
    if (fp == NULL) {
      printError("fopen failed", errno);
      break;
    }
    fclose(fp);

    if (stat(filePath, &statBuf) != 0) {
      printError("stat failed", errno);
      break;
    }

    if (now > statBuf.st_mtime) {
      printf("Unexpected mtime:\n"
             "now: %lld\n"
             "mtime: %lld\n",
             (long long) now,
             (long long) statBuf.st_mtime);
      break;
    }
  } while (now < stopTime);

  return 0;
}

(I tested with Dart SDK 2.8.4 on a 64-bit Linux system.)

[jamesderlin]

FWIW, I am unable to reproduce this problem with the above Dart code on macOS (10.15.3).

[brianquinlan]

So this is a Linux-only issue as far as you know?

[jamesderlin]

Yes, AFAIK it seems to be Linux-specific.