diff --git a/roxie/ccd/ccdfile.cpp b/roxie/ccd/ccdfile.cpp index e9976005597..716515647cc 100644 --- a/roxie/ccd/ccdfile.cpp +++ b/roxie/ccd/ccdfile.cpp @@ -366,8 +366,11 @@ class CRoxieLazyFileIO : implements ILazyFileIO, implements IDelayedFile, public { try { + unsigned __int64 startCycles = get_cycles_now(); size32_t ret = active->read(pos, len, data); lastAccess = nsTick(); + if (doTrace(traceAllFileAccess)) + queryFileAccessRecorder().noteAccess(fileIdx, pos, len, get_cycles_now()-startCycles, AccessType::AccessTypeDisk ); if (cached && !remote) cached->noteRead(fileIdx, pos, ret); return ret; @@ -1041,7 +1044,9 @@ class CRoxieFileCache : implements IRoxieFileCache, implements ICopyFileProgress unsigned trackCache(const char *filename, unsigned channel) { // NOTE - called from openFile, with crit already held - if (!activeCacheReportingBuffer) + // This index/info is used to identify the file in the cache warming information and in + // any tracing of file access patterns. + if (!activeCacheReportingBuffer && !doTrace(traceAllFileAccess)) return (unsigned) -1; cacheIndexes.append(filename); cacheIndexChannels.append(channel); diff --git a/system/jlib/jthread.cpp b/system/jlib/jthread.cpp index 769f04e9595..463b5d1ead6 100644 --- a/system/jlib/jthread.cpp +++ b/system/jlib/jthread.cpp @@ -2776,6 +2776,86 @@ TraceFlags queryDefaultTraceFlags() //--------------------------- +class DummyFileAccessRecorder : public CInterfaceOf +{ + virtual void noteAccess(unsigned fileIdx, offset_t page, size32_t len, unsigned __int64 cycles, AccessType type) override {} + virtual void flush() override {} +} dummyFileAccessRecorder; + +static thread_local IFileAccessRecorder *threadFileAccessRecorder = nullptr; + +class FileAccessRecorder : public CInterfaceOf +{ + struct FileAccessRecord + { + unsigned fileIdx; + offset_t page; + size32_t len; + unsigned __int64 cycles; + AccessType type; + }; + + FileAccessRecord *currentBuffer = nullptr; + unsigned numStored = 0; + static constexpr unsigned capacity = 1000000; +public: + FileAccessRecorder() + { + currentBuffer = new FileAccessRecord[capacity]; + } + + virtual void noteAccess(unsigned fileIdx, offset_t page, size32_t len, unsigned __int64 cycles, AccessType type) + { + if (numStored == capacity) + flush(); + currentBuffer[numStored].fileIdx = fileIdx; + currentBuffer[numStored].page = page; + currentBuffer[numStored].len = len; + currentBuffer[numStored].cycles = cycles; + currentBuffer[numStored].type = type; + numStored++; + } + virtual void flush() override + { + // write out the current info to a file, ideally asynchronously. We can allocate a new buffer and return immediately + // translate info from cycles to nanoseconds as we do so (and potentially compress the info a bit). + numStored = 0; + } +}; + +// Retrieve file access recorder the active thread. Should never return null +static bool releaseFileAccessRecorder(bool isPooled) +{ + if (!isPooled) + { + if (threadFileAccessRecorder && threadFileAccessRecorder != &dummyFileAccessRecorder) + { + threadFileAccessRecorder->flush(); + ::Release(threadFileAccessRecorder); + threadFileAccessRecorder = nullptr; + } + return true; + } + return false; +} + +IFileAccessRecorder &queryFileAccessRecorder() +{ + if (!threadFileAccessRecorder) + { + if (doTrace(traceAllFileAccess)) + { + threadFileAccessRecorder = new FileAccessRecorder; + addThreadTermFunc(releaseFileAccessRecorder); + } + else + threadFileAccessRecorder = &dummyFileAccessRecorder; + } + return *threadFileAccessRecorder; +} + +//--------------------------- + LogContextScope::LogContextScope(const IContextLogger *ctx) { prevFlags = threadTraceFlags; diff --git a/system/jlib/jtrace.hpp b/system/jlib/jtrace.hpp index 9a0db0d7b8d..b2660b8f440 100644 --- a/system/jlib/jtrace.hpp +++ b/system/jlib/jtrace.hpp @@ -410,6 +410,7 @@ constexpr TraceFlags traceFilters = TraceFlags::flag6; constexpr TraceFlags traceKafka = TraceFlags::flag7; constexpr TraceFlags traceJava = TraceFlags::flag8; constexpr TraceFlags traceOptimizations = TraceFlags::flag9; // code generator, but IHqlExpressions also used by esp/engines +constexpr TraceFlags traceAllFileAccess = TraceFlags::flag10; // roxie, but referenced from jhtree code too // Specific to Roxie constexpr TraceFlags traceRoxieLock = TraceFlags::flag16; @@ -468,6 +469,7 @@ constexpr std::initializer_list roxieTraceOptions TRACEOPT(traceSmartStepping), TRACEOPT(traceAborts), TRACEOPT(traceAcknowledge), + TRACEOPT(traceAllFileAccess), }; constexpr std::initializer_list eclccTraceOptions @@ -498,4 +500,21 @@ extern jlib_decl TraceFlags queryDefaultTraceFlags(); extern jlib_decl TraceFlags loadTraceFlags(const IPropertyTree * globals, const std::initializer_list & y, TraceFlags dft); +// Interface for tracking all file access for subsequent analysis + +enum class AccessType : unsigned +{ + AccessTypeDisk = 0, + AccessTypeNodeCacheLookup = 1, +}; + +interface IFileAccessRecorder : public IInterface +{ + virtual void noteAccess(unsigned fileIdx, offset_t page, size32_t len, unsigned __int64 cycles, AccessType type) = 0; + virtual void flush() = 0; +}; + +// Retrieve file access recorder the active thread +extern jlib_decl IFileAccessRecorder &queryFileAccessRecorder(); + #endif