Improved debug logging

SMBLibrary/Server/ResponseHelpers/FileSystemResponseHelper.cs

@@ -31,11 +31,13 @@ namespace SMBLibrary.Server
             }
             catch (IOException)
             {
+                System.Diagnostics.Debug.Print("[{0}] CreateDirectory: Cannot create '{1}'", DateTime.Now.ToString("HH:mm:ss:ffff"), request.DirectoryName);
                 header.Status = NTStatus.STATUS_OBJECT_NAME_INVALID;
                 return new ErrorResponse(CommandName.SMB_COM_CREATE_DIRECTORY);
             }
             catch (UnauthorizedAccessException)
             {
+                System.Diagnostics.Debug.Print("[{0}] CreateDirectory: Cannot create '{1}', Access Denied", DateTime.Now.ToString("HH:mm:ss:ffff"), request.DirectoryName);
                 header.Status = NTStatus.STATUS_ACCESS_DENIED;
                 return new ErrorResponse(CommandName.SMB_COM_CREATE_DIRECTORY);
             }
@@ -73,11 +75,13 @@ namespace SMBLibrary.Server
             }
             catch (IOException)
             {
+                System.Diagnostics.Debug.Print("[{0}] DeleteDirectory: Cannot delete '{1}'", DateTime.Now.ToString("HH:mm:ss:ffff"), request.DirectoryName);
                 header.Status = NTStatus.STATUS_CANNOT_DELETE;
                 return new ErrorResponse(CommandName.SMB_COM_DELETE_DIRECTORY);
             }
             catch (UnauthorizedAccessException)
             {
+                System.Diagnostics.Debug.Print("[{0}] DeleteDirectory: Cannot delete '{1}', Access Denied", DateTime.Now.ToString("HH:mm:ss:ffff"), request.DirectoryName);
                 header.Status = NTStatus.STATUS_ACCESS_DENIED;
                 return new ErrorResponse(CommandName.SMB_COM_DELETE_DIRECTORY);
             }
@@ -127,11 +131,13 @@ namespace SMBLibrary.Server
             }
             catch (IOException)
             {
+                System.Diagnostics.Debug.Print("[{0}] Delete: Cannot delete '{1}'", DateTime.Now.ToString("HH:mm:ss:ffff"), request.FileName);
                 header.Status = NTStatus.STATUS_CANNOT_DELETE;
                 return new ErrorResponse(CommandName.SMB_COM_DELETE);
             }
             catch (UnauthorizedAccessException)
             {
+                System.Diagnostics.Debug.Print("[{0}] DeleteDirectory: Cannot delete '{1}', Access Denied", DateTime.Now.ToString("HH:mm:ss:ffff"), request.FileName);
                 header.Status = NTStatus.STATUS_ACCESS_DENIED;
                 return new ErrorResponse(CommandName.SMB_COM_DELETE);
             }
@@ -171,11 +177,13 @@ namespace SMBLibrary.Server
             }
             catch (IOException)
             {
+                System.Diagnostics.Debug.Print("[{0}] Rename: Sharing violation renaming '{1}'", DateTime.Now.ToString("HH:mm:ss:ffff"), request.OldFileName);
                 header.Status = NTStatus.STATUS_SHARING_VIOLATION;
                 return new ErrorResponse(CommandName.SMB_COM_RENAME);
             }
             catch (UnauthorizedAccessException)
             {
+                System.Diagnostics.Debug.Print("[{0}] Rename: Cannot rename '{1}', Access Denied", DateTime.Now.ToString("HH:mm:ss:ffff"), request.OldFileName);
                 header.Status = NTStatus.STATUS_ACCESS_DENIED;
                 return new ErrorResponse(CommandName.SMB_COM_RENAME);
             }

SMBLibrary/Server/ResponseHelpers/NTCreateHelper.cs

@@ -92,6 +92,7 @@ namespace SMBLibrary.Server
                     if (entry != null)
                     {
                         // File already exists, fail the request
+                        System.Diagnostics.Debug.Print("[{0}] NTCreate: File '{1}' already exist", DateTime.Now.ToString("HH:mm:ss:ffff"), path);
                         header.Status = NTStatus.STATUS_OBJECT_NAME_COLLISION;
                         return new ErrorResponse(CommandName.SMB_COM_NT_CREATE_ANDX);
                     }
@@ -106,10 +107,12 @@ namespace SMBLibrary.Server
                     {
                         if (forceDirectory)
                         {
+                            System.Diagnostics.Debug.Print("[{0}] NTCreate: Creating directory '{1}'", DateTime.Now.ToString("HH:mm:ss:ffff"), path);
                             entry = fileSystem.CreateDirectory(path);
                         }
                         else
                         {
+                            System.Diagnostics.Debug.Print("[{0}] NTCreate: Creating file '{1}'", DateTime.Now.ToString("HH:mm:ss:ffff"), path);
                             entry = fileSystem.CreateFile(path);
                         }
                     }
@@ -118,17 +121,20 @@ namespace SMBLibrary.Server
                         ushort errorCode = IOExceptionHelper.GetWin32ErrorCode(ex);
                         if (errorCode == (ushort)Win32Error.ERROR_SHARING_VIOLATION)
                         {
+                            System.Diagnostics.Debug.Print("[{0}] NTCreate: Sharing violation creating '{1}'", DateTime.Now.ToString("HH:mm:ss:ffff"), path);
                             header.Status = NTStatus.STATUS_SHARING_VIOLATION;
                             return new ErrorResponse(CommandName.SMB_COM_NT_CREATE_ANDX);
                         }
                         else
                         {
+                            System.Diagnostics.Debug.Print("[{0}] NTCreate: Error creating '{1}'", DateTime.Now.ToString("HH:mm:ss:ffff"), path);
                             header.Status = NTStatus.STATUS_DATA_ERROR;
                             return new ErrorResponse(CommandName.SMB_COM_NT_CREATE_ANDX);
                         }
                     }
                     catch (UnauthorizedAccessException)
                     {
+                        System.Diagnostics.Debug.Print("[{0}] NTCreate: Error creating '{1}', Access Denied", DateTime.Now.ToString("HH:mm:ss:ffff"), path);
                         header.Status = NTStatus.STATUS_ACCESS_DENIED;
                         return new ErrorResponse(CommandName.SMB_COM_NT_CREATE_ANDX);
                     }
@@ -157,10 +163,12 @@ namespace SMBLibrary.Server
                         {
                             if (forceDirectory)
                             {
+                                System.Diagnostics.Debug.Print("[{0}] NTCreate: Creating directory '{1}'", DateTime.Now.ToString("HH:mm:ss:ffff"), path);
                                 entry = fileSystem.CreateDirectory(path);
                             }
                             else
                             {
+                                System.Diagnostics.Debug.Print("[{0}] NTCreate: Creating file '{1}'", DateTime.Now.ToString("HH:mm:ss:ffff"), path);
                                 entry = fileSystem.CreateFile(path);
                             }
                         }
@@ -246,7 +254,7 @@ namespace SMBLibrary.Server
                 else
                 {
                     bool buffered = (request.CreateOptions & CreateOptions.FILE_SEQUENTIAL_ONLY) > 0 && (request.CreateOptions & CreateOptions.FILE_NO_INTERMEDIATE_BUFFERING) == 0;
-                    System.Diagnostics.Debug.Print("[{0}] Opening {1}, Access={2}, Share={3}, Buffered={4}", DateTime.Now.ToString("HH:mm:ss:ffff"), path, fileAccess, fileShare, buffered);
+                    System.Diagnostics.Debug.Print("[{0}] NTCreate: Opening '{1}', Access={2}, Share={3}, Buffered={4}", DateTime.Now.ToString("HH:mm:ss:ffff"), path, fileAccess, fileShare, buffered);
                     try
                     {
                         stream = fileSystem.OpenFile(path, FileMode.Open, fileAccess, fileShare);
@@ -256,6 +264,7 @@ namespace SMBLibrary.Server
                         ushort errorCode = IOExceptionHelper.GetWin32ErrorCode(ex);
                         if (errorCode == (ushort)Win32Error.ERROR_SHARING_VIOLATION)
                         {
+                            System.Diagnostics.Debug.Print("[{0}] NTCreate: Sharing violation opening '{1}'", DateTime.Now.ToString("HH:mm:ss:ffff"), path);
                             header.Status = NTStatus.STATUS_SHARING_VIOLATION;
                             return new ErrorResponse(CommandName.SMB_COM_NT_CREATE_ANDX);
                         }

SMBLibrary/Server/ResponseHelpers/OpenAndXHelper.cs

@@ -104,10 +104,12 @@ namespace SMBLibrary.Server
 
                     if ((request.FileAttrs & SMB1.FileAttributes.Directory) > 0)
                     {
+                        System.Diagnostics.Debug.Print("[{0}] OpenAndX: Creating directory '{1}'", DateTime.Now.ToString("HH:mm:ss:ffff"), path);
                         entry = fileSystem.CreateDirectory(path);
                     }
                     else
                     {
+                        System.Diagnostics.Debug.Print("[{0}] OpenAndX: Creating file '{1}'", DateTime.Now.ToString("HH:mm:ss:ffff"), path);
                         entry = fileSystem.CreateFile(path);
                     }
                     openResult = OpenResult.NotExistedAndWasCreated;
@@ -119,7 +121,7 @@ namespace SMBLibrary.Server
                 if (!entry.IsDirectory)
                 {
                     bool buffered = (request.AccessMode.CachedMode == CachedMode.CachingAllowed && request.AccessMode.WriteThroughMode == WriteThroughMode.Disabled);
-                    System.Diagnostics.Debug.Print("[{0}] Opening {1}, Access={2}, Share={3}, Buffered={4}", DateTime.Now.ToString("HH:mm:ss:ffff"), path, fileAccess, fileShare, buffered);
+                    System.Diagnostics.Debug.Print("[{0}] OpenAndX: Opening '{1}', Access={2}, Share={3}, Buffered={4}", DateTime.Now.ToString("HH:mm:ss:ffff"), path, fileAccess, fileShare, buffered);
                     stream = fileSystem.OpenFile(path, FileMode.Open, fileAccess, fileShare);
                     if (buffered)
                     {

SMBLibrary/Server/ResponseHelpers/ReadWriteResponseHelper.cs

@@ -103,6 +103,7 @@ namespace SMBLibrary.Server
                     if (errorCode == (ushort)Win32Error.ERROR_SHARING_VIOLATION)
                     {
                         // Returning STATUS_SHARING_VIOLATION is undocumented but apparently valid
+                        System.Diagnostics.Debug.Print("[{0}] ReadAndX: Cannot read '{1}'. Sharing Violation.", DateTime.Now.ToString("HH:mm:ss:ffff"), openedFilePath);
                         header.Status = NTStatus.STATUS_SHARING_VIOLATION;
                         return null;
                     }
@@ -119,6 +120,7 @@ namespace SMBLibrary.Server
                 }
                 catch (UnauthorizedAccessException)
                 {
+                    System.Diagnostics.Debug.Print("[{0}] ReadAndX: Cannot read '{1}', Access Denied.", DateTime.Now.ToString("HH:mm:ss:ffff"), openedFilePath);
                     header.Status = NTStatus.STATUS_ACCESS_DENIED;
                     return null;
                 }

SMBLibrary/Server/ResponseHelpers/Transaction2SubcommandHelper.cs

@@ -240,6 +240,7 @@ namespace SMBLibrary.Server
             {
                 // Windows Server 2003 will return STATUS_OBJECT_NAME_NOT_FOUND
                 // Returning STATUS_NO_SUCH_FILE caused an issue when executing ImageX.exe from WinPE 3.0 (32-bit)
+                System.Diagnostics.Debug.Print("[{0}] Transaction2QueryPathInformation: File not found, Path: '{1}'", DateTime.Now.ToString("HH:mm:ss:ffff"), path);
                 header.Status = NTStatus.STATUS_OBJECT_NAME_NOT_FOUND;
                 return null;
             }
@@ -340,6 +341,7 @@ namespace SMBLibrary.Server
                         if (errorCode == (ushort)Win32Error.ERROR_SHARING_VIOLATION)
                         {
                             // Returning STATUS_SHARING_VIOLATION is undocumented but apparently valid
+                            System.Diagnostics.Debug.Print("[{0}] Transaction2SetFileInformation: Sharing violation setting file attributes, Path: '{1}'", DateTime.Now.ToString("HH:mm:ss:ffff"), openedFilePath);
                             header.Status = NTStatus.STATUS_SHARING_VIOLATION;
                             return null;
                         }
@@ -374,6 +376,7 @@ namespace SMBLibrary.Server
                         }
                         catch (IOException)
                         {
+                            System.Diagnostics.Debug.Print("[{0}] NTCreate: Error creating '{1}'", DateTime.Now.ToString("HH:mm:ss:ffff"), openedFilePath);
                             header.Status = NTStatus.STATUS_FILE_LOCK_CONFLICT;
                             return null;
                         }
@@ -396,8 +399,13 @@ namespace SMBLibrary.Server
                         stream.SetLength((long)allocationSize);
                         stream.Close();
                     }
-                    catch
+                    catch (IOException)
                     {
+                        System.Diagnostics.Debug.Print("[{0}] SMB_SET_FILE_ALLOCATION_INFO: Cannot set allocation for '{1}'", DateTime.Now.ToString("HH:mm:ss:ffff"), openedFilePath);
+                    }
+                    catch (UnauthorizedAccessException)
+                    {
+                        System.Diagnostics.Debug.Print("[{0}] SMB_SET_FILE_ALLOCATION_INFO: Cannot set allocation for '{1}'. Access Denied", DateTime.Now.ToString("HH:mm:ss:ffff"), openedFilePath);
                     }
                     return response;
                 }
@@ -410,8 +418,13 @@ namespace SMBLibrary.Server
                         stream.SetLength((long)endOfFile);
                         stream.Close();
                     }
-                    catch
+                    catch (IOException)
+                    {
+                        System.Diagnostics.Debug.Print("[{0}] SMB_SET_FILE_END_OF_FILE_INFO: Cannot set end of file for '{1}'", DateTime.Now.ToString("HH:mm:ss:ffff"), openedFilePath);
+                    }
+                    catch (UnauthorizedAccessException)
                     {
+                        System.Diagnostics.Debug.Print("[{0}] SMB_SET_FILE_END_OF_FILE_INFO: Cannot set end of file for '{1}'. Access Denied", DateTime.Now.ToString("HH:mm:ss:ffff"), openedFilePath);
                     }
                     return response;
                 }

SMBLibrary/Server/StateObject.cs

@@ -230,6 +230,7 @@ namespace SMBLibrary.Server
             Stream stream = m_openedFiles[fileID].Stream;
             if (stream != null)
             {
+                System.Diagnostics.Debug.Print("[{0}] Closing file '{1}'", DateTime.Now.ToString("HH:mm:ss:ffff"), m_openedFiles[fileID].Path);
                 stream.Close();
             }
             m_openedFiles.Remove(fileID);