From 96ae6bc47414194a477bf95a1f5a360b555884b3 Mon Sep 17 00:00:00 2001 From: Tor Lillqvist Date: Fri, 3 Apr 2020 19:35:53 +0300 Subject: Show what pathname a fd was opened from in the SAL_INFO("sal.file") calls The pathname is logged in abbreviated form. This, like the two preceding commits, is not claimed to be perfect, MT-safe, etc. It is for debugging output, for SAL_LOG=+INFO.sal.file. If you don't like it, don't use it. Or improve it. Or revert it, I promise not to bother again. Just don't start bike-shedding. Change-Id: Ie8fcea5f5f2373671eebf9ee54d32143e7ed68e9 Reviewed-on: https://gerrit.libreoffice.org/c/core/+/91679 Tested-by: Jenkins Reviewed-by: Tor Lillqvist --- sal/osl/unx/file.cxx | 80 +++++++++++++++++++++++++++---------------------- sal/osl/unx/profile.cxx | 10 ++++++- sal/osl/unx/uunxapi.cxx | 55 ++++++++++++++++++++++++++++++++-- sal/osl/unx/uunxapi.hxx | 30 +++++++++++++++++++ 4 files changed, 137 insertions(+), 38 deletions(-) (limited to 'sal') diff --git a/sal/osl/unx/file.cxx b/sal/osl/unx/file.cxx index b79fd415b214..a2b6f84266ce 100644 --- a/sal/osl/unx/file.cxx +++ b/sal/osl/unx/file.cxx @@ -276,32 +276,32 @@ oslFileError FileHandle_Impl::setSize(sal_uInt64 uSize) if (nCurPos == off_t(-1)) { int e = errno; - SAL_INFO("sal.file", "lseek(" << m_fd << ",0,SEEK_CUR): " << UnixErrnoString(e)); + SAL_INFO("sal.file", "lseek(" << osl::fdAndPath(m_fd) << ",0,SEEK_CUR): " << UnixErrnoString(e)); return result; } else - SAL_INFO("sal.file", "lseek(" << m_fd << ",0,SEEK_CUR): OK"); + SAL_INFO("sal.file", "lseek(" << osl::fdAndPath(m_fd) << ",0,SEEK_CUR): OK"); /* Try 'expand' via 'lseek()' and 'write()' */ if (lseek(m_fd, static_cast(nSize - 1), SEEK_SET) == -1) { int e = errno; - SAL_INFO("sal.file", "lseek(" << m_fd << "," << nSize - 1 << ",SEEK_SET): " << UnixErrnoString(e)); + SAL_INFO("sal.file", "lseek(" << osl::fdAndPath(m_fd) << "," << nSize - 1 << ",SEEK_SET): " << UnixErrnoString(e)); return result; } else - SAL_INFO("sal.file", "lseek(" << m_fd << "," << nSize - 1 << ",SEEK_SET): OK"); + SAL_INFO("sal.file", "lseek(" << osl::fdAndPath(m_fd) << "," << nSize - 1 << ",SEEK_SET): OK"); if (write(m_fd, "", size_t(1)) == -1) { /* Failure. Restore saved position */ int e = errno; - SAL_INFO("sal.file", "write(" << m_fd << ",\"\",1): " << UnixErrnoString(e)); + SAL_INFO("sal.file", "write(" << osl::fdAndPath(m_fd) << ",\"\",1): " << UnixErrnoString(e)); (void) lseek(m_fd, nCurPos, SEEK_SET); return result; } else - SAL_INFO("sal.file", "write(" << m_fd << ",\"\",1): OK"); + SAL_INFO("sal.file", "write(" << osl::fdAndPath(m_fd) << ",\"\",1): OK"); /* Success. Restore saved position */ if (lseek(m_fd, nCurPos, SEEK_SET) == -1) @@ -354,16 +354,16 @@ oslFileError FileHandle_Impl::readAt( * end-of-file, different from 'lseek() + read()' behaviour. * Returning '0 bytes read' and 'osl_File_E_None' instead. */ - SAL_INFO("sal.file", "pread(" << m_fd << "," << pBuffer << "," << nBytesRequested << "," << nOffset << "): " << UnixErrnoString(saved_errno)); + SAL_INFO("sal.file", "pread(" << osl::fdAndPath(m_fd) << "," << pBuffer << "," << nBytesRequested << "," << nOffset << "): " << UnixErrnoString(saved_errno)); nBytes = 0; } else if (nBytes == -1) { - SAL_INFO("sal.file", "pread(" << m_fd << "," << pBuffer << "," << nBytesRequested << "," << nOffset << "): " << UnixErrnoString(saved_errno)); + SAL_INFO("sal.file", "pread(" << osl::fdAndPath(m_fd) << "," << pBuffer << "," << nBytesRequested << "," << nOffset << "): " << UnixErrnoString(saved_errno)); } else { - SAL_INFO("sal.file", "pread(" << m_fd << "," << pBuffer << "," << nBytesRequested << "," << nOffset << ") => " << nBytes); + SAL_INFO("sal.file", "pread(" << osl::fdAndPath(m_fd) << "," << pBuffer << "," << nBytesRequested << "," << nOffset << ") => " << nBytes); } if (nBytes == -1) @@ -392,12 +392,12 @@ oslFileError FileHandle_Impl::writeAt( int saved_errno = errno; if (nBytes == -1) { - SAL_INFO("sal.file", "pwrite(" << m_fd << "," << pBuffer << "," << nBytesToWrite << "," << nOffset << "): " << UnixErrnoString(saved_errno)); + SAL_INFO("sal.file", "pwrite(" << osl::fdAndPath(m_fd) << "," << pBuffer << "," << nBytesToWrite << "," << nOffset << "): " << UnixErrnoString(saved_errno)); return oslTranslateFileError(saved_errno); } else { - SAL_INFO("sal.file", "pwrite(" << m_fd << "," << pBuffer << "," << nBytesToWrite << "," << nOffset << ") => " << nBytes); + SAL_INFO("sal.file", "pwrite(" << osl::fdAndPath(m_fd) << "," << pBuffer << "," << nBytesToWrite << "," << nOffset << ") => " << nBytes); } m_size = std::max(m_size, sal::static_int_cast< sal_uInt64 >(nOffset + nBytes)); @@ -420,12 +420,12 @@ oslFileError FileHandle_Impl::readFileAt( int saved_errno = errno; if (nBytes == -1) { - SAL_INFO("sal.file", "read(" << m_fd << "," << pBuffer << "," << nBytesRequested << "): " << UnixErrnoString(saved_errno)); + SAL_INFO("sal.file", "read(" << osl::fdAndPath(m_fd) << "," << pBuffer << "," << nBytesRequested << "): " << UnixErrnoString(saved_errno)); return oslTranslateFileError(saved_errno); } else { - SAL_INFO("sal.file", "read(" << m_fd << "," << pBuffer << "," << nBytesRequested << ") => " << nBytes); + SAL_INFO("sal.file", "read(" << osl::fdAndPath(m_fd) << "," << pBuffer << "," << nBytesRequested << ") => " << nBytes); } *pBytesRead = nBytes; @@ -509,12 +509,12 @@ oslFileError FileHandle_Impl::writeFileAt( int saved_errno = errno; if (nBytes == -1) { - SAL_INFO("sal.file", "write(" << m_fd << "," << pBuffer << "," << nBytesToWrite << "): " << UnixErrnoString(saved_errno)); + SAL_INFO("sal.file", "write(" << osl::fdAndPath(m_fd) << "," << pBuffer << "," << nBytesToWrite << "): " << UnixErrnoString(saved_errno)); return oslTranslateFileError(saved_errno); } else { - SAL_INFO("sal.file", "write(" << m_fd << "," << pBuffer << "," << nBytesToWrite << ") => " < " <m_fd); - SAL_INFO("sal.file", "close(" << pImpl->m_fd << ")"); + SAL_INFO("sal.file", "close(" << osl::fdAndPath(pImpl->m_fd) << ")"); + osl::unregisterPathForFd(pImpl->m_fd); } else if (close(pImpl->m_fd) == -1) { int e = errno; - SAL_INFO("sal.file", "close(" << pImpl->m_fd << "): " << UnixErrnoString(e)); + SAL_INFO("sal.file", "close(" << osl::fdAndPath(pImpl->m_fd) << "): " << UnixErrnoString(e)); /* translate error code */ result = oslTranslateFileError(e); } else - SAL_INFO("sal.file", "close(" << pImpl->m_fd << "): OK"); + { + SAL_INFO("sal.file", "close(" << osl::fdAndPath(pImpl->m_fd) << "): OK"); + osl::unregisterPathForFd(pImpl->m_fd); + } (void) pthread_mutex_unlock(&(pImpl->m_mutex)); delete pImpl; @@ -1245,11 +1255,11 @@ oslFileError SAL_CALL osl_syncFile(oslFileHandle Handle) if (fsync(pImpl->m_fd) == -1) { int e = errno; - SAL_INFO("sal.file", "fsync(" << pImpl->m_fd << "): " << UnixErrnoString(e)); + SAL_INFO("sal.file", "fsync(" << osl::fdAndPath(pImpl->m_fd) << "): " << UnixErrnoString(e)); return oslTranslateFileError(e); } else - SAL_INFO("sal.file", "fsync(" << pImpl->m_fd << "): OK"); + SAL_INFO("sal.file", "fsync(" << osl::fdAndPath(pImpl->m_fd) << "): OK"); return osl_File_E_None; } diff --git a/sal/osl/unx/profile.cxx b/sal/osl/unx/profile.cxx index edb76019ff5d..db5c50717e14 100644 --- a/sal/osl/unx/profile.cxx +++ b/sal/osl/unx/profile.cxx @@ -21,6 +21,7 @@ #include "readwrite_helper.hxx" #include "file_url.hxx" #include "unixerrnostring.hxx" +#include "uunxapi.hxx" #include #include @@ -947,7 +948,10 @@ static osl_TFile* openFileImpl(const char* pszFilename, oslProfileOption Profile SAL_INFO("sal.file", "open(" << pszFilename << ",O_RDONLY): " << UnixErrnoString(e)); } else + { SAL_INFO("sal.file", "open(" << pszFilename << ",O_RDONLY) => " << pFile->m_Handle); + osl::registerPathForFd(pFile->m_Handle, pszFilename); + } /* mfe: argghh!!! do not check if the file could be opened */ /* default mode expects it that way!!! */ @@ -963,7 +967,10 @@ static osl_TFile* openFileImpl(const char* pszFilename, oslProfileOption Profile return nullptr; } else + { SAL_INFO("sal.file", "open(" << pszFilename << ",...) => " << pFile->m_Handle); + osl::registerPathForFd(pFile->m_Handle, pszFilename); + } } /* set close-on-exec flag */ @@ -1007,7 +1014,8 @@ static osl_TStamp closeFileImpl(osl_TFile* pFile, oslProfileOption Flags) } close(pFile->m_Handle); - SAL_INFO("sal.file", "close(" << pFile->m_Handle << ")"); + SAL_INFO("sal.file", "close(" << osl::fdAndPath(pFile->m_Handle) << ")"); + osl::unregisterPathForFd(pFile->m_Handle); pFile->m_Handle = -1; } diff --git a/sal/osl/unx/uunxapi.cxx b/sal/osl/unx/uunxapi.cxx index 3c358c8523a8..57f983ccf65d 100644 --- a/sal/osl/unx/uunxapi.cxx +++ b/sal/osl/unx/uunxapi.cxx @@ -24,9 +24,12 @@ #include "unixerrnostring.hxx" #include #include +#include #include #include +#include + #ifdef ANDROID #include #endif @@ -362,7 +365,10 @@ int open_c(const char *cpPath, int oflag, int mode) if (result == -1) SAL_INFO("sal.file", "open(" << cpPath << "," << osl::openFlagsToString(oflag) << "," << osl::openModeToString(mode) << "): " << UnixErrnoString(saved_errno)); else + { SAL_INFO("sal.file", "open(" << cpPath << "," << osl::openFlagsToString(oflag) << "," << osl::openModeToString(mode) << ") => " << result); + osl::registerPathForFd(result, cpPath); + } #if HAVE_FEATURE_MACOSX_SANDBOX if (isSandboxed && result != -1 && (oflag & O_CREAT) && (oflag & O_EXCL)) @@ -431,9 +437,9 @@ int ftruncate_with_name(int fd, sal_uInt64 uSize, rtl_String* path) int result = ftruncate(fd, uSize); int saved_errno = errno; if (result < 0) - SAL_INFO("sal.file", "ftruncate(" << fd << "," << uSize << "): " << UnixErrnoString(saved_errno)); + SAL_INFO("sal.file", "ftruncate(" << osl::fdAndPath(fd) << "," << uSize << "): " << UnixErrnoString(saved_errno)); else - SAL_INFO("sal.file", "ftruncate(" << fd << "," << uSize << "): OK"); + SAL_INFO("sal.file", "ftruncate(" << osl::fdAndPath(fd) << "," << uSize << "): OK"); done_accessing_file_path(fn.getStr(), state); @@ -893,4 +899,49 @@ std::string UnixErrnoString(int nErrno) } } +namespace osl +{ +#if defined SAL_LOG_INFO + static std::map fdToPathMap; + + void registerPathForFd(int fd, const char *path) + { + OUString systemPath(OUString::fromUtf8(OString(path))); + OUString abbreviatedPath; + + oslFileError error = osl_abbreviateSystemPath(systemPath.pData, &abbreviatedPath.pData, 40, nullptr); + if (!error) + fdToPathMap[fd] = abbreviatedPath; + else + fdToPathMap[fd] = systemPath; + } + + void unregisterPathForFd(int fd) + { + fdToPathMap.erase(fd); +#if 1 + // Experimentation... + if (fdToPathMap.size() < 5) + dumpFdToPathMap(); +#endif + } + + OUString fdAndPath(int fd) + { + auto path = fdToPathMap.find(fd); + if (path != fdToPathMap.end()) + return OUString::number(fd) + "<" + path->second + ">"; + else + return OUString::number(fd); + } + + void dumpFdToPathMap() + { + SAL_INFO("sal.file", "Fd to path map (" << fdToPathMap.size() << "):"); + for (auto &i : fdToPathMap) + SAL_INFO("sal.file", " " << i.first << ": " << i.second); + } +#endif +} + /* vim:set shiftwidth=4 softtabstop=4 expandtab: */ diff --git a/sal/osl/unx/uunxapi.hxx b/sal/osl/unx/uunxapi.hxx index 867443b45746..1c7a022a7c9a 100644 --- a/sal/osl/unx/uunxapi.hxx +++ b/sal/osl/unx/uunxapi.hxx @@ -28,6 +28,7 @@ #include #include +#include int stat_c(const char *cpPath, struct stat* buf); @@ -74,6 +75,7 @@ namespace osl int mkdir(const OString& aPath, mode_t aMode); + // The following are for debugging output only, don't bother getting upset about performance etc. inline OString openFlagsToString(int flags) { OString result; @@ -194,6 +196,34 @@ namespace osl return result; } +#if defined SAL_LOG_INFO + void registerPathForFd(int fd, const char *path); + + void unregisterPathForFd(int fd); + + OUString fdAndPath(int fd); + + void dumpFdToPathMap(); +#else + inline void registerPathForFd(int, const char *) + { + } + + inline void unregisterPathForFd(int) + { + } + + inline OUString fdAndPath(int) + { + return ""; + } + + inline void dumpFdToPathMap() + { + } +#endif + + } // end namespace osl #endif // INCLUDED_SAL_OSL_UNX_UUNXAPI_HXX -- cgit