Index: src/ch/ch.cpp =================================================================== diff -u -N -rb165add706c4fab9d783f0564b1dd398492da491 -rf8fcbbd1d2321cf0c8be79526c449384af654e49 --- src/ch/ch.cpp (.../ch.cpp) (revision b165add706c4fab9d783f0564b1dd398492da491) +++ src/ch/ch.cpp (.../ch.cpp) (revision f8fcbbd1d2321cf0c8be79526c449384af654e49) @@ -316,6 +316,7 @@ m_spEngineLoggerConfig->SetLogLevel(L"default", (logger::ESeverityLevel)GetPropValue(rCfg)); m_spEngineLoggerConfig->SetLogLevel(L"Filesystem", (logger::ESeverityLevel)GetPropValue(rCfg)); m_spEngineLoggerConfig->SetLogLevel(L"Filesystem-File", (logger::ESeverityLevel)GetPropValue(rCfg)); + m_spEngineLoggerConfig->SetLogLevel(L"DataBuffer", (logger::ESeverityLevel)GetPropValue(rCfg)); m_spEngineLoggerConfig->SetLogLevel(L"Task", (logger::ESeverityLevel)GetPropValue(rCfg)); m_spEngineLoggerConfig->SetLogLevel(L"ST-FastMove", (logger::ESeverityLevel)GetPropValue(rCfg)); m_spEngineLoggerConfig->SetLogLevel(L"ST-CopyMove", (logger::ESeverityLevel)GetPropValue(rCfg)); @@ -690,9 +691,11 @@ if(setPropNames.HasValue(PropData::GetPropertyName())) m_spEngineLoggerConfig->SetLogLevel(L"default", (logger::ESeverityLevel)GetPropValue(rCfg)); if(setPropNames.HasValue(PropData::GetPropertyName())) + { m_spEngineLoggerConfig->SetLogLevel(L"Filesystem", (logger::ESeverityLevel)GetPropValue(rCfg)); - if(setPropNames.HasValue(PropData::GetPropertyName())) m_spEngineLoggerConfig->SetLogLevel(L"Filesystem-File", (logger::ESeverityLevel)GetPropValue(rCfg)); + m_spEngineLoggerConfig->SetLogLevel(L"DataBuffer", (logger::ESeverityLevel)GetPropValue(rCfg)); + } if(setPropNames.HasValue(PropData::GetPropertyName())) m_spEngineLoggerConfig->SetLogLevel(L"Task", (logger::ESeverityLevel)GetPropValue(rCfg)); if(setPropNames.HasValue(PropData::GetPropertyName())) Index: src/libchcore/StreamingHelpers.h =================================================================== diff -u -N --- src/libchcore/StreamingHelpers.h (revision 0) +++ src/libchcore/StreamingHelpers.h (revision f8fcbbd1d2321cf0c8be79526c449384af654e49) @@ -0,0 +1,30 @@ +// ============================================================================ +// Copyright (C) 2001-2015 by Jozef Starosczyk +// ixen@copyhandler.com +// +// This program is free software; you can redistribute it and/or modify +// it under the terms of the GNU Library General Public License +// (version 2) as published by the Free Software Foundation; +// +// This program is distributed in the hope that it will be useful, +// but WITHOUT ANY WARRANTY; without even the implied warranty of +// MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the +// GNU General Public License for more details. +// +// You should have received a copy of the GNU Library General Public +// License along with this program; if not, write to the +// Free Software Foundation, Inc., +// 59 Temple Place - Suite 330, Boston, MA 02111-1307, USA. +// ============================================================================ +#ifndef __STREAMINGHELPERS_H__ +#define __STREAMINGHELPERS_H__ + +#include + +inline std::wostream& operator<<(std::wostream& os, const FILETIME& rFileTime) +{ + unsigned long long ullTime = ((unsigned long long)(rFileTime.dwHighDateTime)) << 32 | rFileTime.dwLowDateTime; + return os << ullTime; +} + +#endif Index: src/libchcore/TLocalFilesystem.cpp =================================================================== diff -u -N -r8a2ff3b2b71b45fb525e030167e62f316cb32869 -rf8fcbbd1d2321cf0c8be79526c449384af654e49 --- src/libchcore/TLocalFilesystem.cpp (.../TLocalFilesystem.cpp) (revision 8a2ff3b2b71b45fb525e030167e62f316cb32869) +++ src/libchcore/TLocalFilesystem.cpp (.../TLocalFilesystem.cpp) (revision f8fcbbd1d2321cf0c8be79526c449384af654e49) @@ -26,30 +26,22 @@ #include #include "TAutoHandles.h" #include "TFileInfo.h" -// disable "warning C4201: nonstandard extension used : nameless struct/union" -// for standard VS2008 with SDK 6.0A where winioctl.h generates some warnings -// converted to errors by the project settings. -#pragma warning(push) -#pragma warning(disable: 4201) #include -#pragma warning(pop) #include "TCoreException.h" #include "ErrorCodes.h" #include "TPathContainer.h" #include "TFileTime.h" -#include "TOverlappedDataBuffer.h" -#include "RoundingFunctions.h" -#include "TBufferSizes.h" #include "TLocalFilesystemFile.h" #include #include "TLocalFilesystemFind.h" #include "TFileException.h" -#include "TDateTime.h" #include +#include "StreamingHelpers.h" namespace chcore { - TLocalFilesystem::TLocalFilesystem() + TLocalFilesystem::TLocalFilesystem(const logger::TLogFileDataPtr& spLogFileData) : + m_spLog(logger::MakeLogger(spLogFileData, L"Filesystem")) { } @@ -92,49 +84,83 @@ findPath.AppendIfNotExists(_T("*"), false); } - HANDLE hFind = FindFirstFile(PrependPathExtensionIfNeeded(findPath).ToString(), &fd); + findPath = PrependPathExtensionIfNeeded(findPath); + + LOG_DEBUG(m_spLog) << L"Checking for path existence: " << pathToCheck << L" (using search pattern: " << findPath << L")"; + + HANDLE hFind = FindFirstFile(findPath.ToString(), &fd); if (hFind != INVALID_HANDLE_VALUE) { ::FindClose(hFind); + LOG_DEBUG(m_spLog) << L"Path: " << pathToCheck << L" exists"; return true; } - else - return false; + + LOG_DEBUG(m_spLog) << L"Path: " << pathToCheck << L" does not exist"; + return false; } void TLocalFilesystem::SetFileDirectoryTime(const TSmartPath& pathFileDir, const TFileTime& ftCreationTime, const TFileTime& ftLastAccessTime, const TFileTime& ftLastWriteTime) { - TAutoFileHandle hFile = TAutoFileHandle(CreateFile(PrependPathExtensionIfNeeded(pathFileDir).ToString(), GENERIC_READ | GENERIC_WRITE, FILE_SHARE_READ, nullptr, OPEN_EXISTING, FILE_ATTRIBUTE_NORMAL | FILE_FLAG_BACKUP_SEMANTICS, nullptr)); + TSmartPath fullPath = PrependPathExtensionIfNeeded(pathFileDir); + + LOG_TRACE(m_spLog) << L"Setting file/directory times for " << fullPath << + L", creation-time: " << ftCreationTime.GetAsFiletime() << + L", last-access-time: " << ftLastAccessTime.GetAsFiletime() << + L", last-write-time: " << ftLastWriteTime.GetAsFiletime(); + + TAutoFileHandle hFile = TAutoFileHandle(CreateFile(fullPath.ToString(), GENERIC_READ | GENERIC_WRITE, FILE_SHARE_READ, nullptr, OPEN_EXISTING, FILE_ATTRIBUTE_NORMAL | FILE_FLAG_BACKUP_SEMANTICS, nullptr)); if (hFile == INVALID_HANDLE_VALUE) { DWORD dwLastError = GetLastError(); + LOG_ERROR(m_spLog) << L"Open file failed with error: " << dwLastError << L". Cannot set file/directory times."; + throw TFileException(eErr_CannotOpenFile, dwLastError, pathFileDir, L"Cannot open file for setting file/directory times", LOCATION); } if (!SetFileTime(hFile, &ftCreationTime.GetAsFiletime(), &ftLastAccessTime.GetAsFiletime(), &ftLastWriteTime.GetAsFiletime())) { DWORD dwLastError = GetLastError(); + LOG_ERROR(m_spLog) << L"Failed to set file/directory times. Error: " << dwLastError; throw TFileException(eErr_CannotSetFileTimes, dwLastError, pathFileDir, L"Cannot set file/directory times", LOCATION); } + LOG_TRACE(m_spLog) << L"File/directory times set successfully"; } void TLocalFilesystem::SetAttributes(const TSmartPath& pathFileDir, DWORD dwAttributes) { - if (!::SetFileAttributes(PrependPathExtensionIfNeeded(pathFileDir).ToString(), dwAttributes)) + TSmartPath fullPath = PrependPathExtensionIfNeeded(pathFileDir); + + LOG_TRACE(m_spLog) << L"Setting file/directory attributes for " << fullPath << + L", attributes: " << dwAttributes; + + if (!::SetFileAttributes(fullPath.ToString(), dwAttributes)) { DWORD dwLastError = GetLastError(); + LOG_ERROR(m_spLog) << L"Failed to set file/directory attributes. Error: " << dwLastError; throw TFileException(eErr_CannotSetFileAttributes, dwLastError, pathFileDir, L"Cannot set file/directory attributes", LOCATION); } + LOG_TRACE(m_spLog) << L"File/directory attributes set successfully"; } void TLocalFilesystem::CreateDirectory(const TSmartPath& pathDirectory, bool bCreateFullPath) { + LOG_DEBUG(m_spLog) << L"Creating directory " << pathDirectory << + L", create-full-path: " << bCreateFullPath; + if (!bCreateFullPath) { if (!::CreateDirectory(PrependPathExtensionIfNeeded(pathDirectory).ToString(), nullptr)) { DWORD dwLastError = GetLastError(); - throw TFileException(eErr_CannotCreateDirectory, dwLastError, pathDirectory, L"Cannot create directory", LOCATION); + if(dwLastError != ERROR_ALREADY_EXISTS) + { + LOG_ERROR(m_spLog) << L"Creating directory " << pathDirectory << L" failed with error " << dwLastError; + throw TFileException(eErr_CannotCreateDirectory, dwLastError, pathDirectory, L"Cannot create directory", LOCATION); + } + + LOG_DEBUG(m_spLog) << L"Directory " << pathDirectory << L" already exists, nothing to do"; + return; } } else @@ -146,47 +172,71 @@ for (size_t stIndex = 0; stIndex < vComponents.GetCount(); ++stIndex) { const TSmartPath& pathComponent = vComponents.GetAt(stIndex); - pathToTest += pathComponent; + + LOG_DEBUG(m_spLog) << L"Creating " << pathDirectory << L" - partial path: " << pathToTest; + // try to create subsequent paths - if (!pathToTest.IsDrive() && !pathToTest.IsServerName()) + if(!pathToTest.IsDrive() && !pathToTest.IsServerName()) { // try to create the specified path BOOL bRes = ::CreateDirectory(PrependPathExtensionIfNeeded(pathToTest).ToString(), nullptr); - if (!bRes) + if(!bRes) { DWORD dwLastError = GetLastError(); - if (dwLastError != ERROR_ALREADY_EXISTS) + if(dwLastError != ERROR_ALREADY_EXISTS) + { + LOG_ERROR(m_spLog) << L"Creating directory " << pathToTest << L" failed with error " << dwLastError; throw TFileException(eErr_CannotCreateDirectory, dwLastError, pathToTest, L"Cannot create directory", LOCATION); + } } } + else + LOG_DEBUG(m_spLog) << L"Skipping drive/server part of a path when creating directory " << pathToTest; } } + + LOG_DEBUG(m_spLog) << L"Directory " << pathDirectory << L" created successfully"; } void TLocalFilesystem::RemoveDirectory(const TSmartPath& pathDirectory) { - if (!::RemoveDirectory(PrependPathExtensionIfNeeded(pathDirectory).ToString())) + TSmartPath fullPath = PrependPathExtensionIfNeeded(pathDirectory); + LOG_DEBUG(m_spLog) << L"Removing directory " << fullPath; + + if (!::RemoveDirectory(fullPath.ToString())) { DWORD dwLastError = GetLastError(); + LOG_ERROR(m_spLog) << L"Failed to remove directory " << fullPath << L". Error: " << dwLastError; throw TFileException(eErr_CannotRemoveDirectory, dwLastError, pathDirectory, L"Cannot delete directory", LOCATION); } + + LOG_DEBUG(m_spLog) << L"Directory " << fullPath << L" removed successfully"; } void TLocalFilesystem::DeleteFile(const TSmartPath& pathFile) { - if (!::DeleteFile(PrependPathExtensionIfNeeded(pathFile).ToString())) + TSmartPath fullPath = PrependPathExtensionIfNeeded(pathFile); + LOG_DEBUG(m_spLog) << L"Removing file " << fullPath; + + if (!::DeleteFile(fullPath.ToString())) { DWORD dwLastError = GetLastError(); + LOG_ERROR(m_spLog) << L"Failed to remove file " << fullPath << L". Error: " << dwLastError; throw TFileException(eErr_CannotDeleteFile, dwLastError, pathFile, L"Cannot delete file", LOCATION); } + + LOG_DEBUG(m_spLog) << L"File " << fullPath << L" removed successfully"; } void TLocalFilesystem::GetFileInfo(const TSmartPath& pathFile, TFileInfoPtr& spFileInfo, const TBasePathDataPtr& spBasePathData) { if (!spFileInfo) throw TCoreException(eErr_InvalidArgument, L"spFileInfo", LOCATION); + LOG_DEBUG(m_spLog) << L"Retrieving file information for " << pathFile << + L" with base path data: " << TSmartPath(spBasePathData ? spBasePathData->GetSrcPath() : TSmartPath()); + WIN32_FIND_DATA wfd; TSmartPath findPath = pathFile; @@ -198,6 +248,8 @@ findPath.AppendIfNotExists(_T("*"), false); } + LOG_DEBUG(m_spLog) << L"Retrieving file information for " << pathFile << L". Using search pattern: " << findPath; + HANDLE hFind = FindFirstFileEx(PrependPathExtensionIfNeeded(findPath).ToString(), FindExInfoStandard, &wfd, FindExSearchNameMatch, nullptr, 0); if (hFind != INVALID_HANDLE_VALUE) { @@ -209,46 +261,69 @@ ftTime.SetCurrentTime(); spFileInfo->Init(spBasePathData, pathFile, FILE_ATTRIBUTE_DIRECTORY, 0, ftTime, ftTime, ftTime, 0); + LOG_DEBUG(m_spLog) << L"Retrieved information for drive - using current timestamp file information for " << pathFile; } else { // new instance of path to accommodate the corrected path (i.e. input path might have lower case names, but we'd like to // preserve the original case contained in the file system) TSmartPath pathNew(pathFile); pathNew.DeleteFileName(); + pathNew += PathFromString(wfd.cFileName); + unsigned long long ullFullSize = (((unsigned long long)wfd.nFileSizeHigh) << 32) + wfd.nFileSizeLow; + // copy data from W32_F_D - spFileInfo->Init(spBasePathData, pathNew + PathFromString(wfd.cFileName), - wfd.dwFileAttributes, (((ULONGLONG)wfd.nFileSizeHigh) << 32) + wfd.nFileSizeLow, wfd.ftCreationTime, + spFileInfo->Init(spBasePathData, pathNew, + wfd.dwFileAttributes, ullFullSize, wfd.ftCreationTime, wfd.ftLastAccessTime, wfd.ftLastWriteTime, 0); + + LOG_DEBUG(m_spLog) << L"Retrieved information for file/directory " << pathFile << + L", full-path: " << pathNew << + L", attributes: " << wfd.dwFileAttributes << + L", size: " << ullFullSize << + L", creation-time: " << wfd.ftCreationTime << + L", last-access-time: " << wfd.ftLastAccessTime << + L", last-write-time: " << wfd.ftLastWriteTime; } } else { DWORD dwLastError = GetLastError(); + LOG_ERROR(m_spLog) << L"Failed to retrieve file information for " << pathFile << L". Error: " << dwLastError; throw TFileException(eErr_CannotGetFileInfo, dwLastError, pathFile, L"Cannot retrieve file information", LOCATION); } } void TLocalFilesystem::FastMove(const TSmartPath& pathSource, const TSmartPath& pathDestination) { - if (!::MoveFileEx(PrependPathExtensionIfNeeded(pathSource).ToString(), PrependPathExtensionIfNeeded(pathDestination).ToString(), 0)) + TSmartPath pathMoveFrom = PrependPathExtensionIfNeeded(pathSource); + TSmartPath pathMoveTo = PrependPathExtensionIfNeeded(pathDestination); + + LOG_DEBUG(m_spLog) << L"Trying to fast-move file " << pathMoveFrom << L" to " << pathMoveTo; + + if (!::MoveFileEx(pathMoveFrom.ToString(), pathMoveTo.ToString(), 0)) { DWORD dwLastError = GetLastError(); - // there is also the destination path that is important; tracking that would require adding a new exception class - // complicating the solution. For now it's not necessary to have that information in the exception. + + LOG_ERROR(m_spLog) << L"Failed to fast-move file " << pathMoveFrom << L" to " << pathMoveTo << L". Error: " << dwLastError; throw TFileException(eErr_CannotFastMove, dwLastError, pathSource, L"Cannot fast move file/directory", LOCATION); } + + LOG_DEBUG(m_spLog) << L"Successfully fast-moved file " << pathMoveFrom << L" to " << pathMoveTo; } IFilesystemFindPtr TLocalFilesystem::CreateFinderObject(const TSmartPath& pathDir, const TSmartPath& pathMask) { - return std::shared_ptr(new TLocalFilesystemFind(pathDir, pathMask)); + LOG_TRACE(m_spLog) << L"Creating file finder object for path " << pathDir << L" with mask " << pathMask; + + return std::shared_ptr(new TLocalFilesystemFind(pathDir, pathMask, m_spLog->GetLogFileData())); } IFilesystemFilePtr TLocalFilesystem::CreateFileObject(const TSmartPath& pathFile, bool bNoBuffering) { - return std::shared_ptr(new TLocalFilesystemFile(pathFile, bNoBuffering)); + LOG_TRACE(m_spLog) << L"Creating file object for path " << pathFile << L" with no-buffering set to " << bNoBuffering; + return std::shared_ptr(new TLocalFilesystemFile(pathFile, bNoBuffering, m_spLog->GetLogFileData())); } TSmartPath TLocalFilesystem::PrependPathExtensionIfNeeded(const TSmartPath& pathInput) @@ -268,12 +343,13 @@ if(pathSecond.IsEmpty()) throw TCoreException(eErr_InvalidArgument, L"pathSecond", LOCATION); + LOG_DEBUG(m_spLog) << L"Trying to find relation between paths: " << pathFirst << L" and " << pathSecond; + // get information about both paths - UINT uiFirstDriveType = 0; - uiFirstDriveType = GetDriveData(pathFirst); + UINT uiFirstDriveType = GetDriveData(pathFirst); + UINT uiSecondDriveType = GetDriveData(pathSecond); - UINT uiSecondDriveType = 0; - uiSecondDriveType = GetDriveData(pathSecond); + LOG_TRACE(m_spLog) << L"Drive type for " << pathFirst << L" is " << uiFirstDriveType << L", drive type for " << pathSecond << L" is " << uiSecondDriveType; // what kind of relation... EPathsRelation eRelation = eRelation_Other; @@ -296,6 +372,9 @@ { DWORD dwFirstPhysicalDisk = GetPhysicalDiskNumber(wchFirstDrive); DWORD dwSecondPhysicalDisk = GetPhysicalDiskNumber(wchSecondDrive); + + LOG_TRACE(m_spLog) << L"Physical disk for " << pathFirst << L" is " << dwFirstPhysicalDisk << L", physical disk for " << pathSecond << L" is " << dwSecondPhysicalDisk; + if (dwFirstPhysicalDisk == std::numeric_limits::max() || dwSecondPhysicalDisk == std::numeric_limits::max()) { // NOTE: disabled throwing an exception here - when testing, it came out that some DRIVE_FIXED @@ -311,35 +390,53 @@ } } + LOG_DEBUG(m_spLog) << L"Drive relation for " << pathFirst << L" and " << pathSecond << L" is " << eRelation; + return eRelation; } DWORD TLocalFilesystem::GetPhysicalDiskNumber(wchar_t wchDrive) { + LOG_TRACE(m_spLog) << L"Checking physical disk number for drive " << wchDrive; + { boost::shared_lock lock(m_lockDriveLetterToPhysicalDisk); std::map::iterator iterMap = m_mapDriveLetterToPhysicalDisk.find(wchDrive); if (iterMap != m_mapDriveLetterToPhysicalDisk.end()) + { + LOG_TRACE(m_spLog) << L"Physical disk number for drive " << wchDrive << L" is " << (*iterMap).second << L" (cached)"; return (*iterMap).second; + } } wchar_t szDrive[] = { L'\\', L'\\', L'.', L'\\', wchDrive, L':', L'\0' }; + LOG_DEBUG(m_spLog) << L"Creating handle for drive " << szDrive; + HANDLE hDevice = CreateFile(szDrive, FILE_READ_ATTRIBUTES, FILE_SHARE_READ | FILE_SHARE_WRITE, nullptr, OPEN_EXISTING, 0, nullptr); if (hDevice == INVALID_HANDLE_VALUE) + { + DWORD dwLastError = GetLastError(); + LOG_DEBUG(m_spLog) << L"Failed to create handle for drive " << szDrive << L". Error: " << dwLastError; return std::numeric_limits::max(); + } // buffer for data (cannot make member nor static because this function might be called by many threads at once) // buffer is larger than one extent to allow getting information in multi-extent volumes (raid?) const int stSize = sizeof(VOLUME_DISK_EXTENTS) + 20 * sizeof(DISK_EXTENT); boost::shared_array spData(new BYTE[stSize]); + LOG_DEBUG(m_spLog) << L"Retrieving volume disk extents for drive " << szDrive; + VOLUME_DISK_EXTENTS* pVolumeDiskExtents = (VOLUME_DISK_EXTENTS*)spData.get(); DWORD dwBytesReturned = 0; BOOL bResult = DeviceIoControl(hDevice, IOCTL_VOLUME_GET_VOLUME_DISK_EXTENTS, nullptr, 0, pVolumeDiskExtents, stSize, &dwBytesReturned, nullptr); if (!bResult) { + DWORD dwLastError = GetLastError(); + LOG_ERROR(m_spLog) << L"Failed to retrieve volume disk extents for drive " << szDrive << L". Error: " << dwLastError; + CloseHandle(hDevice); // NOTE: when ERROR_INVALID_FUNCTION is reported here, it probably means that underlying volume @@ -350,10 +447,15 @@ CloseHandle(hDevice); if (pVolumeDiskExtents->NumberOfDiskExtents == 0) + { + LOG_DEBUG(m_spLog) << L"No disk extents available for drive " << szDrive; return std::numeric_limits::max(); + } DISK_EXTENT* pDiskExtent = &pVolumeDiskExtents->Extents[0]; + LOG_DEBUG(m_spLog) << L"Retrieved disk number for drive " << szDrive << L": " << pDiskExtent->DiskNumber; + boost::unique_lock lock(m_lockDriveLetterToPhysicalDisk); m_mapDriveLetterToPhysicalDisk.insert(std::make_pair(wchDrive, pDiskExtent->DiskNumber)); @@ -362,14 +464,20 @@ void TLocalFilesystem::GetDynamicFreeSpace(const TSmartPath& path, unsigned long long& rullFree) { + LOG_DEBUG(m_spLog) << L"Retrieving free space for path " << path; + rullFree = 0; ULARGE_INTEGER ui64Available, ui64Total; if (GetDiskFreeSpaceEx(path.ToString(), &ui64Available, &ui64Total, nullptr)) + { rullFree = ui64Available.QuadPart; + LOG_DEBUG(m_spLog) << L"Free space for path " << path << L" is " << rullFree; + } else { DWORD dwLastError = GetLastError(); + LOG_ERROR(m_spLog) << L"Failed to retrieve free space for path " << path << L". Error: " << dwLastError; throw TFileException(eErr_CannotGetFreeSpace, dwLastError, path, L"Failed to retrieve free space information", LOCATION); } } Index: src/libchcore/TLocalFilesystem.h =================================================================== diff -u -N -rd468098a278a0d16c5b700236ea276b9c9677c9f -rf8fcbbd1d2321cf0c8be79526c449384af654e49 --- src/libchcore/TLocalFilesystem.h (.../TLocalFilesystem.h) (revision d468098a278a0d16c5b700236ea276b9c9677c9f) +++ src/libchcore/TLocalFilesystem.h (.../TLocalFilesystem.h) (revision f8fcbbd1d2321cf0c8be79526c449384af654e49) @@ -28,6 +28,7 @@ #include "TBasePathData.h" #include "TFileInfoFwd.h" #include "IFilesystem.h" +#include "..\liblogger\TLogger.h" namespace chcore { @@ -41,7 +42,7 @@ class LIBCHCORE_API TLocalFilesystem : public IFilesystem { public: - TLocalFilesystem(); + TLocalFilesystem(const logger::TLogFileDataPtr& spLogFileData); virtual ~TLocalFilesystem(); virtual bool PathExist(const TSmartPath& strPath) override; // check for file or folder existence @@ -66,13 +67,14 @@ private: static TSmartPath PrependPathExtensionIfNeeded(const TSmartPath& pathInput); static UINT GetDriveData(const TSmartPath& spPath); - DWORD GetPhysicalDiskNumber(wchar_t wchDrive); + DWORD GetPhysicalDiskNumber(wchar_t wchDrive); private: #pragma warning(push) #pragma warning(disable: 4251) std::map m_mapDriveLetterToPhysicalDisk; // caches drive letter -> physical disk number boost::shared_mutex m_lockDriveLetterToPhysicalDisk; + logger::TLoggerPtr m_spLog; #pragma warning(pop) friend class TLocalFilesystemFind; Index: src/libchcore/TLocalFilesystemFile.cpp =================================================================== diff -u -N -r8068e0c351055554340ac9755d1bc846893bf2b8 -rf8fcbbd1d2321cf0c8be79526c449384af654e49 --- src/libchcore/TLocalFilesystemFile.cpp (.../TLocalFilesystemFile.cpp) (revision 8068e0c351055554340ac9755d1bc846893bf2b8) +++ src/libchcore/TLocalFilesystemFile.cpp (.../TLocalFilesystemFile.cpp) (revision f8fcbbd1d2321cf0c8be79526c449384af654e49) @@ -28,16 +28,18 @@ #include "TCoreWin32Exception.h" #include "TFileException.h" #include "TFileInfo.h" +#include "StreamingHelpers.h" namespace chcore { // compile-time check - ensure the buffer granularity used for transfers are bigger than expected sector size static_assert(TLocalFilesystemFile::MaxSectorSize <= TBufferSizes::BufferGranularity, "Buffer granularity must be equal to or bigger than the max sector size"); - TLocalFilesystemFile::TLocalFilesystemFile(const TSmartPath& pathFile, bool bNoBuffering) : + TLocalFilesystemFile::TLocalFilesystemFile(const TSmartPath& pathFile, bool bNoBuffering, const logger::TLogFileDataPtr& spLogFileData) : m_pathFile(TLocalFilesystem::PrependPathExtensionIfNeeded(pathFile)), m_hFile(INVALID_HANDLE_VALUE), - m_bNoBuffering(bNoBuffering) + m_bNoBuffering(bNoBuffering), + m_spLog(logger::MakeLogger(spLogFileData, L"Filesystem-File")) { if (pathFile.IsEmpty()) throw TCoreException(eErr_InvalidArgument, L"pathFile", LOCATION); @@ -63,24 +65,34 @@ { Close(); + LOG_DEBUG(m_spLog) << L"Opening existing file for reading" << GetFileInfoForLog(m_bNoBuffering); + m_hFile = ::CreateFile(m_pathFile.ToString(), GENERIC_READ, FILE_SHARE_READ | FILE_SHARE_WRITE, nullptr, OPEN_EXISTING, GetFlagsAndAttributes(m_bNoBuffering), nullptr); if (m_hFile == INVALID_HANDLE_VALUE) { DWORD dwLastError = GetLastError(); + LOG_ERROR(m_spLog) << "Opening file for reading failed with error: " << dwLastError << GetFileInfoForLog(m_bNoBuffering); + throw TFileException(eErr_CannotOpenFile, dwLastError, m_pathFile, L"Cannot open for reading", LOCATION); } + + LOG_DEBUG(m_spLog) << "Opening file for reading succeeded. New handle: " << m_hFile << GetFileInfoForLog(m_bNoBuffering); } void TLocalFilesystemFile::CreateNewForWriting() { Close(); + LOG_DEBUG(m_spLog) << "Creating new file for writing" << GetFileInfoForLog(m_bNoBuffering); + m_hFile = ::CreateFile(m_pathFile.ToString(), GENERIC_WRITE, FILE_SHARE_READ, nullptr, CREATE_NEW, GetFlagsAndAttributes(m_bNoBuffering), nullptr); if (m_hFile == INVALID_HANDLE_VALUE) { DWORD dwLastError = GetLastError(); + LOG_ERROR(m_spLog) << "CreateNewForWriting failed with error: " << dwLastError << GetFileInfoForLog(m_bNoBuffering); throw TFileException(eErr_CannotOpenFile, dwLastError, m_pathFile, L"Cannot create file.", LOCATION); } + LOG_DEBUG(m_spLog) << "CreateNewForWriting succeeded. New handle: " << m_hFile << GetFileInfoForLog(m_bNoBuffering); } void TLocalFilesystemFile::OpenExistingForWriting() @@ -92,24 +104,36 @@ { Close(); + LOG_DEBUG(m_spLog) << "OpenExistingForWriting" << GetFileInfoForLog(bNoBuffering); + m_hFile = CreateFile(m_pathFile.ToString(), GENERIC_WRITE, FILE_SHARE_READ, nullptr, OPEN_EXISTING, GetFlagsAndAttributes(bNoBuffering), nullptr); if (m_hFile == INVALID_HANDLE_VALUE) { DWORD dwLastError = GetLastError(); + LOG_ERROR(m_spLog) << "OpenExistingForWriting failed with error: " << dwLastError << GetFileInfoForLog(bNoBuffering); + throw TFileException(eErr_CannotOpenFile, dwLastError, m_pathFile, L"Cannot open for reading.", LOCATION); } + LOG_DEBUG(m_spLog) << "OpenExistingForWriting succeeded. New handle: " << m_hFile << GetFileInfoForLog(bNoBuffering); } file_size_t TLocalFilesystemFile::GetSeekPositionForResume(file_size_t fsLastAvailablePosition) { file_size_t fsMove = (m_bNoBuffering ? RoundDown(fsLastAvailablePosition, MaxSectorSize) : fsLastAvailablePosition); + LOG_DEBUG(m_spLog) << "Calculated seek position for last-available-pos: " << fsLastAvailablePosition << L" = " << fsMove << GetFileInfoForLog(m_bNoBuffering); + return fsMove; } void TLocalFilesystemFile::Truncate(file_size_t fsNewSize) { + LOG_TRACE(m_spLog) << "Truncating file to: " << fsNewSize << GetFileInfoForLog(m_bNoBuffering); + if (!IsOpen()) + { + LOG_ERROR(m_spLog) << L"Cannot truncate - file not open" << GetFileInfoForLog(m_bNoBuffering); throw TFileException(eErr_FileNotOpen, ERROR_INVALID_HANDLE, m_pathFile, L"File not open yet. Cannot truncate.", LOCATION); + } // when no-buffering is used, there are cases where we'd need to switch to buffered ops // to adjust file size @@ -119,6 +143,8 @@ file_size_t fsNewAlignedSize = RoundUp(fsNewSize, MaxSectorSize); if (fsNewAlignedSize != fsNewSize) { + LOG_TRACE(m_spLog) << "Truncating to non-aligned size. Requested: " << fsNewSize << L", aligned: " << fsNewAlignedSize << L". Will reopen file in buffering mode." << GetFileInfoForLog(m_bNoBuffering); + Close(); OpenExistingForWriting(false); @@ -131,39 +157,58 @@ li.QuadPart = fsNewSize; + LOG_TRACE(m_spLog) << L"Setting file pointer to: " << li.QuadPart << GetFileInfoForLog(m_bNoBuffering); if (!SetFilePointerEx(m_hFile, li, &liNew, FILE_BEGIN)) { DWORD dwLastError = GetLastError(); + LOG_ERROR(m_spLog) << L"Setting file pointer to: " << li.QuadPart << L" failed." << GetFileInfoForLog(m_bNoBuffering); + throw TFileException(eErr_SeekFailed, dwLastError, m_pathFile, L"Cannot seek to appropriate position", LOCATION); } + LOG_TRACE(m_spLog) << L"Setting EOF" << GetFileInfoForLog(m_bNoBuffering); if(!::SetEndOfFile(m_hFile)) { DWORD dwLastError = GetLastError(); + LOG_ERROR(m_spLog) << L"Setting EOF failed" << GetFileInfoForLog(m_bNoBuffering); throw TFileException(eErr_CannotTruncate, dwLastError, m_pathFile, L"Cannot mark the end of file", LOCATION); } // close the file that was open in inappropriate mode if(bFileSettingsChanged) + { + LOG_DEBUG(m_spLog) << L"Closing file due to mode change in truncate function" << GetFileInfoForLog(m_bNoBuffering); + Close(); + } } void TLocalFilesystemFile::ReadFile(TOverlappedDataBuffer& rBuffer) { + LOG_TRACE(m_spLog) << L"Requesting read of " << rBuffer.GetRequestedDataSize() << + L" bytes at position " << rBuffer.GetFilePosition() << + L"; buffer-order: " << rBuffer.GetBufferOrder() << + GetFileInfoForLog(m_bNoBuffering); + if (!IsOpen()) + { + LOG_ERROR(m_spLog) << L"Read request failed - file not open" << L"; buffer-order: " << rBuffer.GetBufferOrder() << GetFileInfoForLog(m_bNoBuffering); throw TFileException(eErr_FileNotOpen, ERROR_INVALID_HANDLE, m_pathFile, L"Cannot read from closed file", LOCATION); + } - //ATLTRACE(_T("Reading %lu bytes\n"), rBuffer.GetRequestedDataSize()); if (!::ReadFileEx(m_hFile, rBuffer.GetBufferPtr(), rBuffer.GetRequestedDataSize(), &rBuffer, OverlappedReadCompleted)) { DWORD dwLastError = GetLastError(); switch (dwLastError) { case ERROR_IO_PENDING: + LOG_TRACE(m_spLog) << L"Read requested and is pending" << L"; buffer-order: " << rBuffer.GetBufferOrder() << GetFileInfoForLog(m_bNoBuffering); return; case ERROR_HANDLE_EOF: { + LOG_TRACE(m_spLog) << L"Read request marked as EOF" << L"; buffer-order: " << rBuffer.GetBufferOrder() << GetFileInfoForLog(m_bNoBuffering); + rBuffer.SetBytesTransferred(0); rBuffer.SetStatusCode(0); rBuffer.SetErrorCode(ERROR_SUCCESS); @@ -174,47 +219,80 @@ } default: - throw TFileException(eErr_CannotReadFile, dwLastError, m_pathFile, L"Error reading data from file", LOCATION); + { + LOG_ERROR(m_spLog) << L"Read request failed with error " << dwLastError << L"; buffer-order: " << rBuffer.GetBufferOrder() << GetFileInfoForLog(m_bNoBuffering); + + throw TFileException(eErr_CannotReadFile, dwLastError, m_pathFile, L"Error reading data from file", LOCATION); + } } } + else + LOG_TRACE(m_spLog) << L"Read request succeeded" << L"; buffer-order: " << rBuffer.GetBufferOrder() << GetFileInfoForLog(m_bNoBuffering); } void TLocalFilesystemFile::WriteFile(TOverlappedDataBuffer& rBuffer) { + LOG_TRACE(m_spLog) << L"Requesting writing of " << rBuffer.GetRealDataSize() << + L" bytes at position " << rBuffer.GetFilePosition() << + L"; buffer-order: " << rBuffer.GetBufferOrder() << + GetFileInfoForLog(m_bNoBuffering); + if (!IsOpen()) + { + LOG_ERROR(m_spLog) << L"Write request failed - file not open" << L"; buffer-order: " << rBuffer.GetBufferOrder() << GetFileInfoForLog(m_bNoBuffering); throw TFileException(eErr_FileNotOpen, ERROR_INVALID_HANDLE, m_pathFile, L"Cannot write to closed file", LOCATION); + } DWORD dwToWrite = boost::numeric_cast(rBuffer.GetRealDataSize()); if (m_bNoBuffering && rBuffer.IsLastPart()) + { dwToWrite = RoundUp(dwToWrite, MaxSectorSize); + LOG_TRACE(m_spLog) << L"Writing last part of file in no-buffering mode. Rounding up last write to " << dwToWrite << L"; buffer-order: " << rBuffer.GetBufferOrder() << GetFileInfoForLog(m_bNoBuffering); + } - //ATLTRACE(_T("Writing %lu bytes\n"), dwToWrite); if (!::WriteFileEx(m_hFile, rBuffer.GetBufferPtr(), dwToWrite, &rBuffer, OverlappedWriteCompleted)) { DWORD dwLastError = GetLastError(); if (dwLastError != ERROR_IO_PENDING) + { + LOG_ERROR(m_spLog) << L"Write request failed with error " << dwLastError << L"; buffer-order: " << rBuffer.GetBufferOrder() << GetFileInfoForLog(m_bNoBuffering); throw TFileException(eErr_CannotWriteFile, dwLastError, m_pathFile, L"Error while writing to file", LOCATION); + } + + LOG_TRACE(m_spLog) << L"Write requested and is pending" << L"; buffer-order: " << rBuffer.GetBufferOrder() << GetFileInfoForLog(m_bNoBuffering); } + else + LOG_TRACE(m_spLog) << L"Write request succeeded" << L"; buffer-order: " << rBuffer.GetBufferOrder() << GetFileInfoForLog(m_bNoBuffering); } void TLocalFilesystemFile::FinalizeFile(TOverlappedDataBuffer& rBuffer) { + LOG_TRACE(m_spLog) << L"Finalizing file" << + L"; buffer-order: " << rBuffer.GetBufferOrder() << + GetFileInfoForLog(m_bNoBuffering); + if (!IsOpen()) + { + LOG_ERROR(m_spLog) << L"Cannot finalize file - file not open" << L"; buffer-order: " << rBuffer.GetBufferOrder() << GetFileInfoForLog(m_bNoBuffering); throw TFileException(eErr_FileNotOpen, ERROR_INVALID_HANDLE, m_pathFile, L"Cannot write to closed file", LOCATION); + } if (m_bNoBuffering && rBuffer.IsLastPart()) { DWORD dwToWrite = boost::numeric_cast(rBuffer.GetRealDataSize()); DWORD dwReallyWritten = RoundUp(dwToWrite, MaxSectorSize); - //ATLTRACE(_T("Finalize file - size diff: written: %I64u, required: %I64u\n"), dwReallyWritten, dwToWrite); if (dwToWrite != dwReallyWritten) { file_size_t fsNewFileSize = rBuffer.GetFilePosition() + dwToWrite; // new size - //seek - //ATLTRACE(_T("Truncating file to %I64u bytes\n"), fsNewFileSize); + LOG_TRACE(m_spLog) << L"File need truncating - really written " << dwReallyWritten << + L", should write " << dwToWrite << + L". Truncating file to " << fsNewFileSize << + L"; buffer-order: " << rBuffer.GetBufferOrder() << + GetFileInfoForLog(m_bNoBuffering); + Truncate(fsNewFileSize); } } @@ -223,42 +301,70 @@ void TLocalFilesystemFile::InternalClose() { if (m_hFile != INVALID_HANDLE_VALUE) + { + LOG_DEBUG(m_spLog) << L"Closing file" << GetFileInfoForLog(m_bNoBuffering); ::CloseHandle(m_hFile); + } m_hFile = INVALID_HANDLE_VALUE; } + std::wstring TLocalFilesystemFile::GetFileInfoForLog(bool bNoBuffering) const + { + std::wstringstream wss; + wss << L" (handle: " << m_hFile << ", path : " << m_pathFile << L", no-buffering : " << bNoBuffering << L")"; + return wss.str(); + } + void TLocalFilesystemFile::Close() { InternalClose(); } file_size_t TLocalFilesystemFile::GetFileSize() const { + LOG_DEBUG(m_spLog) << L"Retrieving file size" << GetFileInfoForLog(m_bNoBuffering); + if (!IsOpen()) + { + LOG_ERROR(m_spLog) << L"Retrieving file size failed - file not open" << GetFileInfoForLog(m_bNoBuffering); return 0; + } BY_HANDLE_FILE_INFORMATION bhfi; if (!::GetFileInformationByHandle(m_hFile, &bhfi)) + { + DWORD dwLastError = GetLastError(); + LOG_ERROR(m_spLog) << L"Retrieving file size failed with error " << dwLastError << GetFileInfoForLog(m_bNoBuffering); + return 0; + } ULARGE_INTEGER uli; uli.HighPart = bhfi.nFileSizeHigh; uli.LowPart = bhfi.nFileSizeLow; + LOG_DEBUG(m_spLog) << L"File size retrieved -> " << uli.QuadPart << GetFileInfoForLog(m_bNoBuffering); + return uli.QuadPart; } void TLocalFilesystemFile::GetFileInfo(TFileInfo& tFileInfo) const { + LOG_DEBUG(m_spLog) << L"Retrieving file information" << GetFileInfoForLog(m_bNoBuffering); + if (!IsOpen()) + { + LOG_ERROR(m_spLog) << L"Retrieving file information failed - file not open" << GetFileInfoForLog(m_bNoBuffering); throw TFileException(eErr_FileNotOpen, ERROR_INVALID_HANDLE, m_pathFile, L"File not open. Cannot get file info.", LOCATION); + } BY_HANDLE_FILE_INFORMATION bhfi; if (!::GetFileInformationByHandle(m_hFile, &bhfi)) { DWORD dwLastError = GetLastError(); + LOG_ERROR(m_spLog) << L"Retrieving file information failed with error " << dwLastError << GetFileInfoForLog(m_bNoBuffering); throw TFileException(eErr_CannotGetFileInfo, dwLastError, m_pathFile, L"Retrieving file info from handle failed.", LOCATION); } @@ -270,6 +376,14 @@ tFileInfo.SetAttributes(bhfi.dwFileAttributes); tFileInfo.SetFileTimes(TFileTime(bhfi.ftCreationTime), TFileTime(bhfi.ftLastAccessTime), TFileTime(bhfi.ftLastWriteTime)); tFileInfo.SetLength64(uli.QuadPart); + + LOG_DEBUG(m_spLog) << L"Retrieving file information succeeded. Attributes: " << + bhfi.dwFileAttributes << + L", creation-time: " << bhfi.ftCreationTime << + L", last-access-time: " << bhfi.ftLastAccessTime<< + L", last-write-time: " << bhfi.ftLastWriteTime << + L", size: " << uli.QuadPart << + GetFileInfoForLog(m_bNoBuffering); } TSmartPath TLocalFilesystemFile::GetFilePath() const Index: src/libchcore/TLocalFilesystemFile.h =================================================================== diff -u -N -r4fe995b304ea342b50293f92d3c1992b43b820f7 -rf8fcbbd1d2321cf0c8be79526c449384af654e49 --- src/libchcore/TLocalFilesystemFile.h (.../TLocalFilesystemFile.h) (revision 4fe995b304ea342b50293f92d3c1992b43b820f7) +++ src/libchcore/TLocalFilesystemFile.h (.../TLocalFilesystemFile.h) (revision f8fcbbd1d2321cf0c8be79526c449384af654e49) @@ -23,6 +23,7 @@ #include "TPath.h" #include "TOverlappedDataBuffer.h" #include "IFilesystemFile.h" +#include "..\liblogger\TLogger.h" namespace chcore { @@ -53,17 +54,23 @@ virtual file_size_t GetSeekPositionForResume(file_size_t fsLastAvailablePosition) override; private: - TLocalFilesystemFile(const TSmartPath& pathFile, bool bNoBuffering); + TLocalFilesystemFile(const TSmartPath& pathFile, bool bNoBuffering, const logger::TLogFileDataPtr& spLogFileData); DWORD GetFlagsAndAttributes(bool bNoBuffering) const; void OpenExistingForWriting(bool bNoBuffering); void InternalClose(); + std::wstring TLocalFilesystemFile::GetFileInfoForLog(bool bNoBuffering) const; + private: TSmartPath m_pathFile; HANDLE m_hFile; bool m_bNoBuffering; +#pragma warning(push) +#pragma warning(disable: 4251) + logger::TLoggerPtr m_spLog; +#pragma warning(pop) friend class TLocalFilesystem; }; Index: src/libchcore/TLocalFilesystemFind.cpp =================================================================== diff -u -N -r4fe995b304ea342b50293f92d3c1992b43b820f7 -rf8fcbbd1d2321cf0c8be79526c449384af654e49 --- src/libchcore/TLocalFilesystemFind.cpp (.../TLocalFilesystemFind.cpp) (revision 4fe995b304ea342b50293f92d3c1992b43b820f7) +++ src/libchcore/TLocalFilesystemFind.cpp (.../TLocalFilesystemFind.cpp) (revision f8fcbbd1d2321cf0c8be79526c449384af654e49) @@ -20,13 +20,15 @@ #include "TLocalFilesystemFind.h" #include "TLocalFilesystem.h" #include "TFileInfo.h" +#include "StreamingHelpers.h" namespace chcore { - TLocalFilesystemFind::TLocalFilesystemFind(const TSmartPath& pathDir, const TSmartPath& pathMask) : + TLocalFilesystemFind::TLocalFilesystemFind(const TSmartPath& pathDir, const TSmartPath& pathMask, const logger::TLogFileDataPtr& spLogFileData) : m_pathDir(pathDir), m_pathMask(pathMask), - m_hFind(INVALID_HANDLE_VALUE) + m_hFind(INVALID_HANDLE_VALUE), + m_spLog(logger::MakeLogger(spLogFileData, L"Filesystem-Find")) { } @@ -38,32 +40,55 @@ bool TLocalFilesystemFind::FindNext(TFileInfoPtr& rspFileInfo) { WIN32_FIND_DATA wfd; - TSmartPath pathCurrent = m_pathDir + m_pathMask; + TSmartPath pathCurrent = TLocalFilesystem::PrependPathExtensionIfNeeded(m_pathDir + m_pathMask); // Iterate through dirs & files bool bContinue = true; if (m_hFind != INVALID_HANDLE_VALUE) + { + LOG_TRACE(m_spLog) << "Find next" << GetFindLogData(); bContinue = (FindNextFile(m_hFind, &wfd) != FALSE); + } else { - m_hFind = FindFirstFileEx(TLocalFilesystem::PrependPathExtensionIfNeeded(pathCurrent).ToString(), FindExInfoStandard, &wfd, FindExSearchNameMatch, nullptr, 0); + LOG_TRACE(m_spLog) << "Find first" << GetFindLogData(); + + m_hFind = FindFirstFileEx(pathCurrent.ToString(), FindExInfoStandard, &wfd, FindExSearchNameMatch, nullptr, 0); bContinue = (m_hFind != INVALID_HANDLE_VALUE); } if (bContinue) { do { + unsigned long long ullObjectSize = (((unsigned long long)wfd.nFileSizeHigh) << 32) + wfd.nFileSizeLow; + if (!(wfd.dwFileAttributes & FILE_ATTRIBUTE_DIRECTORY)) { - rspFileInfo->Init(m_pathDir + PathFromString(wfd.cFileName), wfd.dwFileAttributes, (((ULONGLONG)wfd.nFileSizeHigh) << 32) + wfd.nFileSizeLow, wfd.ftCreationTime, + LOG_TRACE(m_spLog) << "Found directory: " << wfd.cFileName << + L", attrs: " << wfd.dwFileAttributes << + L", size: " << ullObjectSize << + L", created: " << wfd.ftCreationTime << + L", last-access: " << wfd.ftLastAccessTime << + L", last-write: " << wfd.ftLastWriteTime << + GetFindLogData(); + + rspFileInfo->Init(m_pathDir + PathFromString(wfd.cFileName), wfd.dwFileAttributes, ullObjectSize, wfd.ftCreationTime, wfd.ftLastAccessTime, wfd.ftLastWriteTime, 0); return true; } else if (wfd.cFileName[0] != _T('.') || (wfd.cFileName[1] != _T('\0') && (wfd.cFileName[1] != _T('.') || wfd.cFileName[2] != _T('\0')))) { + LOG_TRACE(m_spLog) << "Found file: " << wfd.cFileName << + L", attrs: " << wfd.dwFileAttributes << + L", size: " << ullObjectSize << + L", created: " << wfd.ftCreationTime << + L", last-access: " << wfd.ftLastAccessTime << + L", last-write: " << wfd.ftLastWriteTime << + GetFindLogData(); + // Add directory itself rspFileInfo->Init(m_pathDir + PathFromString(wfd.cFileName), - wfd.dwFileAttributes, (((ULONGLONG)wfd.nFileSizeHigh) << 32) + wfd.nFileSizeLow, wfd.ftCreationTime, + wfd.dwFileAttributes, ullObjectSize, wfd.ftCreationTime, wfd.ftLastAccessTime, wfd.ftLastWriteTime, 0); return true; } @@ -78,10 +103,20 @@ void TLocalFilesystemFind::InternalClose() { if(m_hFind != INVALID_HANDLE_VALUE) + { + LOG_TRACE(m_spLog) << "Closing finder" << GetFindLogData(); FindClose(m_hFind); + } m_hFind = INVALID_HANDLE_VALUE; } + std::wstring TLocalFilesystemFind::GetFindLogData() const + { + std::wstringstream wss; + wss << L" (directory: " << m_pathDir << L", mask: " << m_pathMask << L", handle: " << m_hFind << L")"; + return wss.str(); + } + void TLocalFilesystemFind::Close() { InternalClose(); Index: src/libchcore/TLocalFilesystemFind.h =================================================================== diff -u -N -r4fe995b304ea342b50293f92d3c1992b43b820f7 -rf8fcbbd1d2321cf0c8be79526c449384af654e49 --- src/libchcore/TLocalFilesystemFind.h (.../TLocalFilesystemFind.h) (revision 4fe995b304ea342b50293f92d3c1992b43b820f7) +++ src/libchcore/TLocalFilesystemFind.h (.../TLocalFilesystemFind.h) (revision f8fcbbd1d2321cf0c8be79526c449384af654e49) @@ -23,6 +23,7 @@ #include "TFileInfoFwd.h" #include "TPath.h" #include "IFilesystemFind.h" +#include "..\liblogger\TLogger.h" namespace chcore { @@ -35,15 +36,21 @@ virtual void Close() override; private: - TLocalFilesystemFind(const TSmartPath& pathDir, const TSmartPath& pathMask); + TLocalFilesystemFind(const TSmartPath& pathDir, const TSmartPath& pathMask, const logger::TLogFileDataPtr& spLogFileData); void InternalClose(); + std::wstring GetFindLogData() const; private: TSmartPath m_pathDir; TSmartPath m_pathMask; HANDLE m_hFind; +#pragma warning(push) +#pragma warning(disable: 4251) + logger::TLoggerPtr m_spLog; +#pragma warning(pop) + friend class TLocalFilesystem; }; } Index: src/libchcore/TOverlappedDataBuffer.cpp =================================================================== diff -u -N -r8068e0c351055554340ac9755d1bc846893bf2b8 -rf8fcbbd1d2321cf0c8be79526c449384af654e49 --- src/libchcore/TOverlappedDataBuffer.cpp (.../TOverlappedDataBuffer.cpp) (revision 8068e0c351055554340ac9755d1bc846893bf2b8) +++ src/libchcore/TOverlappedDataBuffer.cpp (.../TOverlappedDataBuffer.cpp) (revision f8fcbbd1d2321cf0c8be79526c449384af654e49) @@ -22,13 +22,9 @@ // ============================================================================ #include "stdafx.h" #include "TOverlappedDataBuffer.h" -#include #include "TCoreException.h" #include "ErrorCodes.h" #include "IOverlappedDataBufferQueue.h" -#include "RoundingFunctions.h" -#include -#include #define STATUS_END_OF_FILE 0xc0000011 Index: src/libchcore/TOverlappedDataBufferQueue.cpp =================================================================== diff -u -N -r7e407d35b44ec7482a112ef382e4619cf5d96172 -rf8fcbbd1d2321cf0c8be79526c449384af654e49 --- src/libchcore/TOverlappedDataBufferQueue.cpp (.../TOverlappedDataBufferQueue.cpp) (revision 7e407d35b44ec7482a112ef382e4619cf5d96172) +++ src/libchcore/TOverlappedDataBufferQueue.cpp (.../TOverlappedDataBufferQueue.cpp) (revision f8fcbbd1d2321cf0c8be79526c449384af654e49) @@ -22,7 +22,6 @@ #include "TCoreException.h" #include "ErrorCodes.h" #include -#include namespace chcore { @@ -31,7 +30,8 @@ return pBufferA->GetBufferOrder() < pBufferB->GetBufferOrder(); } - TOverlappedDataBufferQueue::TOverlappedDataBufferQueue() : + TOverlappedDataBufferQueue::TOverlappedDataBufferQueue(const logger::TLogFileDataPtr& spLogFileData) : + m_spLog(logger::MakeLogger(spLogFileData, L"DataBuffer")), m_eventReadPossible(true, false), m_eventWritePossible(true, false), m_eventWriteFinished(true, false), @@ -44,7 +44,8 @@ { } - TOverlappedDataBufferQueue::TOverlappedDataBufferQueue(size_t stCount, size_t stBufferSize) : + TOverlappedDataBufferQueue::TOverlappedDataBufferQueue(const logger::TLogFileDataPtr& spLogFileData, size_t stCount, size_t stBufferSize) : + m_spLog(logger::MakeLogger(spLogFileData, L"DataBuffer")), m_eventReadPossible(true, false), m_eventWritePossible(true, false), m_eventWriteFinished(true, false), @@ -85,6 +86,8 @@ if (!pBuffer) throw TCoreException(eErr_InvalidPointer, L"pBuffer", LOCATION); + LOG_TRACE(m_spLog) << L"Queuing buffer as empty; buffer-order: " << pBuffer->GetBufferOrder(); + m_listEmptyBuffers.push_back(pBuffer); UpdateReadPossibleEvent(); UpdateAllBuffersAccountedFor(); @@ -131,6 +134,14 @@ if (!pBuffer) throw TCoreException(eErr_InvalidPointer, L"pBuffer", LOCATION); + LOG_TRACE(m_spLog) << L"Queuing buffer as full; buffer-order: " << pBuffer->GetBufferOrder() << + L", requested-data-size: " << pBuffer->GetRequestedDataSize() << + L", real-data-size: " << pBuffer->GetRealDataSize() << + L", file-position: " << pBuffer->GetFilePosition() << + L", error-code: " << pBuffer->GetErrorCode() << + L", status-code: " << pBuffer->GetStatusCode() << + L", is-last-part: " << pBuffer->IsLastPart(); + std::pair pairInsertInfo = m_setFullBuffers.insert(pBuffer); if (!pairInsertInfo.second) throw TCoreException(eErr_InvalidOverlappedPosition, L"Tried to re-insert same buffer into queue", LOCATION); @@ -190,6 +201,14 @@ if (!pBuffer) throw TCoreException(eErr_InvalidPointer, L"pBuffer", LOCATION); + LOG_TRACE(m_spLog) << L"Queuing buffer as finished; buffer-order: " << pBuffer->GetBufferOrder() << + L", requested-data-size: " << pBuffer->GetRequestedDataSize() << + L", real-data-size: " << pBuffer->GetRealDataSize() << + L", file-position: " << pBuffer->GetFilePosition() << + L", error-code: " << pBuffer->GetErrorCode() << + L", status-code: " << pBuffer->GetStatusCode() << + L", is-last-part: " << pBuffer->IsLastPart(); + std::pair pairInsertInfo = m_setFinishedBuffers.insert(pBuffer); if (!pairInsertInfo.second) throw TCoreException(eErr_InvalidOverlappedPosition, L"Tried to re-insert same buffer into queue", LOCATION); @@ -332,7 +351,6 @@ switch (dwResult) { case STATUS_USER_APC: - ATLTRACE(_T("STATUS_USER_APC while waiting for missing buffers\n")); break; case WAIT_OBJECT_0 + eAllBuffersReturned: Index: src/libchcore/TOverlappedDataBufferQueue.h =================================================================== diff -u -N -r4fe995b304ea342b50293f92d3c1992b43b820f7 -rf8fcbbd1d2321cf0c8be79526c449384af654e49 --- src/libchcore/TOverlappedDataBufferQueue.h (.../TOverlappedDataBufferQueue.h) (revision 4fe995b304ea342b50293f92d3c1992b43b820f7) +++ src/libchcore/TOverlappedDataBufferQueue.h (.../TOverlappedDataBufferQueue.h) (revision f8fcbbd1d2321cf0c8be79526c449384af654e49) @@ -22,6 +22,8 @@ #include #include "TEvent.h" #include "IOverlappedDataBufferQueue.h" +#include "../liblogger/TLogFileData.h" +#include "../liblogger/TLogger.h" namespace chcore { @@ -35,8 +37,8 @@ class TOverlappedDataBufferQueue : public IOverlappedDataBufferQueue { public: - TOverlappedDataBufferQueue(); - TOverlappedDataBufferQueue(size_t stCount, size_t stBufferSize); + TOverlappedDataBufferQueue(const logger::TLogFileDataPtr& spLogFileData); + TOverlappedDataBufferQueue(const logger::TLogFileDataPtr& spLogFileData, size_t stCount, size_t stBufferSize); ~TOverlappedDataBufferQueue(); void ReinitializeBuffers(size_t stCount, size_t stBufferSize); @@ -77,6 +79,8 @@ void UpdateAllBuffersAccountedFor(); private: + logger::TLoggerPtr m_spLog; + std::deque> m_listAllBuffers; std::list m_listEmptyBuffers; Index: src/libchcore/TPath.h =================================================================== diff -u -N -rcca174e74e108de1f5729e4cc6c46d2b9a5e25a7 -rf8fcbbd1d2321cf0c8be79526c449384af654e49 --- src/libchcore/TPath.h (.../TPath.h) (revision cca174e74e108de1f5729e4cc6c46d2b9a5e25a7) +++ src/libchcore/TPath.h (.../TPath.h) (revision f8fcbbd1d2321cf0c8be79526c449384af654e49) @@ -130,6 +130,11 @@ LIBCHCORE_API TSmartPath PathFromString(const wchar_t* pszPath); LIBCHCORE_API TSmartPath PathFromWString(const TString& strPath); + + inline std::wostream& operator<<(std::wostream& os, const TSmartPath& rPath) + { + return os << std::wstring(rPath.ToString()); + } } #endif Index: src/libchcore/TSubTaskCopyMove.cpp =================================================================== diff -u -N -r8a2ff3b2b71b45fb525e030167e62f316cb32869 -rf8fcbbd1d2321cf0c8be79526c449384af654e49 --- src/libchcore/TSubTaskCopyMove.cpp (.../TSubTaskCopyMove.cpp) (revision 8a2ff3b2b71b45fb525e030167e62f316cb32869) +++ src/libchcore/TSubTaskCopyMove.cpp (.../TSubTaskCopyMove.cpp) (revision f8fcbbd1d2321cf0c8be79526c449384af654e49) @@ -34,7 +34,6 @@ #include "TFileInfoArray.h" #include "ErrorCodes.h" #include "TCoreException.h" -#include "TCoreWin32Exception.h" #include "TPathContainer.h" #include "TScopedRunningTimeTracker.h" #include "TFeedbackHandlerWrapper.h" @@ -52,6 +51,10 @@ { struct CUSTOM_COPY_PARAMS { + CUSTOM_COPY_PARAMS(const logger::TLogFileDataPtr& spFileData) : dbBuffer(spFileData) + { + } + TFileInfoPtr spSrcFile; // CFileInfo - src file TSmartPath pathDstFile; // dest path with filename @@ -138,7 +141,7 @@ bool bCurrentFileSilentResume = m_tSubTaskStats.CanCurrentItemSilentResume(); // create a buffer of size m_nBufferSize - CUSTOM_COPY_PARAMS ccp; + CUSTOM_COPY_PARAMS ccp(m_spLog->GetLogFileData()); ccp.bProcessed = false; ccp.bOnlyCreate = GetTaskPropValue(rConfig); Index: src/libchcore/TTask.cpp =================================================================== diff -u -N -r8a2ff3b2b71b45fb525e030167e62f316cb32869 -rf8fcbbd1d2321cf0c8be79526c449384af654e49 --- src/libchcore/TTask.cpp (.../TTask.cpp) (revision 8a2ff3b2b71b45fb525e030167e62f316cb32869) +++ src/libchcore/TTask.cpp (.../TTask.cpp) (revision f8fcbbd1d2321cf0c8be79526c449384af654e49) @@ -56,7 +56,7 @@ m_bContinue(false), m_tSubTaskContext(m_tConfiguration, m_spSrcPaths, m_afFilters, m_cfgTracker, m_spLog->GetLogFileData(), m_workerThread, - std::make_shared()), + std::make_shared(m_spLog->GetLogFileData())), m_tSubTasksArray(m_tSubTaskContext), m_spSerializer(spSerializer) { @@ -77,7 +77,7 @@ m_bContinue(false), m_tSubTaskContext(m_tConfiguration, m_spSrcPaths, m_afFilters, m_cfgTracker, m_spLog->GetLogFileData(), m_workerThread, - std::make_shared()), + std::make_shared(m_spLog->GetLogFileData())), m_tSubTasksArray(m_tSubTaskContext), m_spSerializer(spSerializer) { Index: src/libchcore/libchcore.vc140.vcxproj =================================================================== diff -u -N -rcca174e74e108de1f5729e4cc6c46d2b9a5e25a7 -rf8fcbbd1d2321cf0c8be79526c449384af654e49 --- src/libchcore/libchcore.vc140.vcxproj (.../libchcore.vc140.vcxproj) (revision cca174e74e108de1f5729e4cc6c46d2b9a5e25a7) +++ src/libchcore/libchcore.vc140.vcxproj (.../libchcore.vc140.vcxproj) (revision f8fcbbd1d2321cf0c8be79526c449384af654e49) @@ -482,6 +482,7 @@ + Index: src/libchcore/libchcore.vc140.vcxproj.filters =================================================================== diff -u -N -rcca174e74e108de1f5729e4cc6c46d2b9a5e25a7 -rf8fcbbd1d2321cf0c8be79526c449384af654e49 --- src/libchcore/libchcore.vc140.vcxproj.filters (.../libchcore.vc140.vcxproj.filters) (revision cca174e74e108de1f5729e4cc6c46d2b9a5e25a7) +++ src/libchcore/libchcore.vc140.vcxproj.filters (.../libchcore.vc140.vcxproj.filters) (revision f8fcbbd1d2321cf0c8be79526c449384af654e49) @@ -461,6 +461,9 @@ Source Files\Library files + + Source Files\Tools +