add some logs for updating inode atime

Summary:
inode atime is not accurate on macOS. NFS GC use atime for invalidation and only invalidate inodes if its atime is less than a cutoff.
However, I found some conditions that inodes get invalidates which they are recently accessed. It means that we don't update atime correctly on NFS.
I add some logs to the InodeBase and GC to find out when we skip updating atime.

Reviewed By: taidaii

Differential Revision: D75720812

fbshipit-source-id: 45d372b48ad01257e4d5b84de67655f74addf81b

Author: kavehahmadi60

eden/fs/inodes/InodeBase.cpp

@@ -60,8 +60,22 @@ InodeBase::InodeBase(
 #ifndef _WIN32
   mount_->getInodeMetadataTable()->populateIfNotSet(ino_, [&] {
     auto metadata = mount_->getInitialInodeMetadata(initialMode);
+    auto now = getNow();
     if (initialTimestamps) {
       metadata.timestamps = *initialTimestamps;
+      XLOGF(
+          DBG9,
+          "Setting initial timestamps for inode {} atime: {} while now time: {}",
+          ino_,
+          metadata.timestamps.atime.toTimespec().tv_sec,
+          now.toTimespec().tv_sec);
+    } else {
+      XLOGF(
+          DBG9,
+          "Initial timestamps was NULL for inode {} then the atime remains unchanged. atime: {} while now time: {}",
+          ino_,
+          metadata.timestamps.atime.toTimespec().tv_sec,
+          now.toTimespec().tv_sec);
     }
     return metadata;
   });
@@ -357,6 +371,11 @@ void InodeBase::updateAtime() {
   auto now = getNow();
   getMount()->getInodeMetadataTable()->modifyOrThrow(
       getNodeId(), [&](auto& metadata) { metadata.timestamps.atime = now; });
+  XLOGF(
+      DBG9,
+      "Updated atime for inode {} to now: {}",
+      ino_,
+      now.toTimespec().tv_sec);
 #endif
 }
 

eden/fs/inodes/TreeInode.cpp

@@ -3973,6 +3973,14 @@ folly::Try<folly::Unit> TreeInode::nfsInvalidateCacheEntryForGC(
               for (auto& entry : state.entries) {
                 auto ino = entry.second.getInodeNumber();
                 if (inodeMap->isInodeLoadedOrRemembered(ino)) {
+                  XLOGF(
+                      DBG5,
+                      "GC invalidated inode {} with atime: {}",
+                      ino,
+                      entry.second.getInode()
+                          ->getMetadata()
+                          .timestamps.atime.toTimespec()
+                          .tv_sec);
                   inodeMap->decFsRefcount(ino);
                 }
               }
@@ -4449,6 +4457,15 @@ ImmediateFuture<uint64_t> TreeInode::invalidateChildrenNotMaterialized(
                       .timestamps.atime.toTimespec()
                       .tv_sec);
               shouldInvalidate = (atime < cutoff);
+              XLOGF(
+                  DBG5,
+                  "For path: {}, atime: {}, cutoff: {}, shouldInvalidate by GC is {}",
+                  self->getPath().value().asString(),
+                  self->getMetadataLocked(contents->entries)
+                      .timestamps.atime.toTimespec()
+                      .tv_sec,
+                  cutoff.time_since_epoch().count(),
+                  shouldInvalidate);
             }
             if (shouldInvalidate) {
               // Attempt to invalidate the directory, and then delete all of its