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 <tml@collabora.com>

4 files changed, 137 insertions, 38 deletions

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<off_t>(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 << ") => " <<nBytes);
+            SAL_INFO("sal.file", "write(" << osl::fdAndPath(m_fd) << "," << pBuffer << "," << nBytesToWrite << ") => " <<nBytes);
         }
 
         *pBytesWritten = nBytes;
@@ -1053,26 +1053,28 @@ oslFileError openFilePath(const char *cpFilePath, oslFileHandle* pHandle,
         if (f == -1)
         {
             int e = errno;
-            SAL_INFO("sal.file", "fcntl(" << fd << ",F_GETFL,0): " << UnixErrnoString(e));
+            SAL_INFO("sal.file", "fcntl(" << osl::fdAndPath(fd) << ",F_GETFL,0): " << UnixErrnoString(e));
             eRet = oslTranslateFileError(e);
             (void) close(fd);
-            SAL_INFO("sal.file", "close(" << fd << ")");
+            SAL_INFO("sal.file", "close(" << osl::fdAndPath(fd) << ")");
+            osl::unregisterPathForFd(fd);
             return eRet;
         }
         else
-            SAL_INFO("sal.file", "fcntl(" << fd << ",F_GETFL,0): OK");
+            SAL_INFO("sal.file", "fcntl(" << osl::fdAndPath(fd) << ",F_GETFL,0): OK");
 
         if (fcntl(fd, F_SETFL, (f & ~O_NONBLOCK)) == -1)
         {
             int e = errno;
-            SAL_INFO("sal.file", "fcntl(" << fd << ",F_SETFL,(f & ~O_NONBLOCK)): " << UnixErrnoString(e));
+            SAL_INFO("sal.file", "fcntl(" << osl::fdAndPath(fd) << ",F_SETFL,(f & ~O_NONBLOCK)): " << UnixErrnoString(e));
             eRet = oslTranslateFileError(e);
             (void) close(fd);
-            SAL_INFO("sal.file", "close(" << fd << ")");
+            SAL_INFO("sal.file", "close(" << osl::fdAndPath(fd) << ")");
+            osl::unregisterPathForFd(fd);
             return eRet;
         }
         else
-            SAL_INFO("sal.file", "fcntl(" << fd << ",F_SETFL,(f & ~O_NONBLOCK)): OK");
+            SAL_INFO("sal.file", "fcntl(" << osl::fdAndPath(fd) << ",F_SETFL,(f & ~O_NONBLOCK)): OK");
     }
 #endif
 
@@ -1081,21 +1083,23 @@ oslFileError openFilePath(const char *cpFilePath, oslFileHandle* pHandle,
     if (fstat(fd, &aFileStat) == -1)
     {
         int e = errno;
-        SAL_INFO("sal.file", "fstat(" << fd << "): " << UnixErrnoString(e));
+        SAL_INFO("sal.file", "fstat(" << osl::fdAndPath(fd) << "): " << UnixErrnoString(e));
         eRet = oslTranslateFileError(e);
         (void) close(fd);
-        SAL_INFO("sal.file", "close(" << fd << ")");
+        SAL_INFO("sal.file", "close(" << osl::fdAndPath(fd) << ")");
+        osl::unregisterPathForFd(fd);
         return eRet;
     }
     else
-        SAL_INFO("sal.file", "fstat(" << fd << "): OK");
+        SAL_INFO("sal.file", "fstat(" << osl::fdAndPath(fd) << "): OK");
 
     if (!S_ISREG(aFileStat.st_mode))
     {
         /* we only open regular files here */
         SAL_INFO("sal.file", "osl_openFile(" << cpFilePath << "): not a regular file");
         (void) close(fd);
-        SAL_INFO("sal.file", "close(" << fd << ")");
+        SAL_INFO("sal.file", "close(" << osl::fdAndPath(fd) << ")");
+        osl::unregisterPathForFd(fd);
         return osl_File_E_INVAL;
     }
 
@@ -1105,7 +1109,7 @@ oslFileError openFilePath(const char *cpFilePath, oslFileHandle* pHandle,
         if (flock(fd, LOCK_EX | LOCK_NB) == -1)
         {
             int e = errno;
-            SAL_INFO("sal.file", "flock(" << fd << ",LOCK_EX|LOCK_NB): " << UnixErrnoString(e));
+            SAL_INFO("sal.file", "flock(" << osl::fdAndPath(fd) << ",LOCK_EX|LOCK_NB): " << UnixErrnoString(e));
             /* Mac OSX returns ENOTSUP for webdav drives. We should try read lock */
 
             // Restore errno after possibly having been overwritten by the SAL_INFO above...
@@ -1114,12 +1118,13 @@ oslFileError openFilePath(const char *cpFilePath, oslFileHandle* pHandle,
             {
                 eRet = oslTranslateFileError(errno);
                 (void) close(fd);
-                SAL_INFO("sal.file", "close(" << fd << ")");
+                SAL_INFO("sal.file", "close(" << osl::fdAndPath(fd) << ")");
+                osl::unregisterPathForFd(fd);
                 return eRet;
             }
         }
         else
-            SAL_INFO("sal.file", "flock(" << fd << ",LOCK_EX|LOCK_NB): OK");
+            SAL_INFO("sal.file", "flock(" << osl::fdAndPath(fd) << ",LOCK_EX|LOCK_NB): OK");
 #else   /* F_SETLK */
         struct flock aflock;
 
@@ -1131,10 +1136,11 @@ oslFileError openFilePath(const char *cpFilePath, oslFileHandle* pHandle,
         if (fcntl(fd, F_SETLK, &aflock) == -1)
         {
             int e = errno;
-            SAL_INFO("sal.file", "fcntl(" << fd << ",F_SETLK): " << UnixErrnoString(e));
+            SAL_INFO("sal.file", "fcntl(" << osl::fdAndPath(fd) << ",F_SETLK): " << UnixErrnoString(e));
             eRet = oslTranslateFileError(e);
             (void) close(fd);
-            SAL_INFO("sal.file", "close(" << fd << ")");
+            SAL_INFO("sal.file", "close(" << osl::fdAndPath(fd) << ")");
+            osl::unregisterPathForFd(fd);
             return eRet;
         }
 #endif  /* F_SETLK */
@@ -1208,17 +1214,21 @@ oslFileError SAL_CALL osl_closeFile(oslFileHandle Handle)
     {
         /* close, ignoring double failure */
         (void) close(pImpl->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 <osl/diagnose.h>
 #include <osl/profile.h>
@@ -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 <limits.h>
 #include <rtl/ustring.hxx>
+#include <osl/file.h>
 #include <osl/thread.h>
 #include <sal/log.hxx>
 
+#include <map>
+
 #ifdef ANDROID
 #include <osl/detail/android-bootstrap.h>
 #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<int, OUString> 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 <rtl/ustring.h>
 
 #include <rtl/ustring.hxx>
+#include <sal/log.hxx>
 
 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