ARK-Builders / ark-core

The core of the ARK framework
MIT License
4 stars 3 forks source link

Weird bug in file metadata modified timestamp returned by OS #71

Closed twitu closed 3 months ago

twitu commented 3 months ago

The file metadata modified timestamp returns different values for reading the same file without any changes :exploding_head:. Which is causing the bug in #63.

This is a separate PR to discuss and debug it. Here's output from the modified test that's failing for me locally. It has two different timestamps for the same file even though there is no modification between the two readings.

---- file_storage::tests::test_file_storage_is_storage_updated stdout ----
thread 'file_storage::tests::test_file_storage_is_storage_updated' panicked at fs-storage/src/file_storage.rs:397:9:
assertion `left == right` failed
  left: SystemTime { tv_sec: 1717951936, tv_nsec: 537150997 }
 right: SystemTime { tv_sec: 1717951936, tv_nsec: 529151011 }

Can others reproduce this locally as well?

twitu commented 3 months ago

I've reproduced the issue with an even smaller test. The os is returning different metadata for the same file.

    #[test]
    fn test_file_timestamp_bug() {
        let temp_dir =
            TempDir::new("tmp").expect("Failed to create temporary directory");
        let storage_path = temp_dir.path().join("teststorage.txt");
        let mut file_storage =
            FileStorage::new("TestStorage".to_string(), &storage_path).unwrap();
        file_storage.set("key1".to_string(), "value1".to_string());
        let updated = file_storage.write_fs().unwrap();
        let file_updated = fs::metadata(&file_storage.path)
            .unwrap()
            .modified()
            .unwrap();
        assert_eq!(file_updated, updated);
    }
thread 'file_storage::tests::test_file_timestamp_bug' panicked at fs-storage/src/file_storage.rs:376:9:
assertion `left == right` failed
  left: SystemTime { tv_sec: 1718003019, tv_nsec: 328495061 }
 right: SystemTime { tv_sec: 1718003019, tv_nsec: 324495101 }
tareknaser commented 3 months ago

The issue seems to be related to BufWriter buffering the writes and not immediately flushing the data to disk. This means the file's timestamp might not be updated right after writer.write_all(value_data.as_bytes())? is called, as the data is still in the buffer.

For reference, see the BufWriter documentation.

To resolve this, I've added a call to writer.flush() to ensure the data is written to the file immediately. This should correctly update the file's metadata and timestamp.

I've pushed a commit with this fix.

twitu commented 3 months ago

That was a very tricky bug. Thanks for the fix. Reading the documentation I realize that BufWriter is not a good fit for our purpose since we want to write the whole mapping to disk at once.

It does not help when writing very large amounts at once, or writing just one or a few times.

I'll remove the BufWriter and use just a writer which will avoid such tricky bugs later.