Bug 1637: Low logging level (S3 and partly WebDAV)

https://winscp.net/tracker/1637

Source commit: 6dc112edd1eae10916bc25717ec6581948db1abb

libs/neon/src/ne_openssl.c

@@ -345,7 +345,7 @@ static int check_identity(const ne_uri *server, X509 *cert, char **identity)
         ne_buffer_destroy(cname);
     }
 
-    NE_DEBUG(NE_DBG_SSL, "Identity match for '%s': %s\n", hostname, 
+    NE_DEBUG(match ? NE_DBG_SSL : NE_DBG_WINSCP_HTTP_DETAIL, "Identity match for '%s': %s\n", hostname, 
              match ? "good" : "bad");
     return match ? 0 : 1;
 }
@@ -382,7 +382,7 @@ static int verify_callback(int ok, X509_STORE_CTX *ctx)
     /* If there's no error, nothing to do here. */
     if (ok) return ok;
 
-    NE_DEBUG(NE_DBG_SSL, "ssl: Verify callback @ %d => %d\n", depth, err);
+    NE_DEBUG(NE_DBG_WINSCP_HTTP_DETAIL, "ssl: Verify callback @ %d => %d\n", depth, err);
 
     /* Map the error code onto any of the exported cert validation
      * errors, if possible. */
@@ -414,7 +414,7 @@ static int verify_callback(int ok, X509_STORE_CTX *ctx)
 
     sess->ssl_context->failures |= failures;
 
-    NE_DEBUG(NE_DBG_SSL, "ssl: Verify failures |= %d => %d\n", failures,
+    NE_DEBUG(NE_DBG_WINSCP_HTTP_DETAIL, "ssl: Verify failures |= %d => %d\n", failures,
              sess->ssl_context->failures);
     
     return 1;
@@ -426,7 +426,7 @@ static ne_ssl_certificate *make_chain(STACK_OF(X509) *chain)
     int n, count = sk_X509_num(chain);
     ne_ssl_certificate *top = NULL, *current = NULL;
     
-    NE_DEBUG(NE_DBG_SSL, "Chain depth: %d\n", count);
+    NE_DEBUG(NE_DBG_WINSCP_HTTP_DETAIL, "Chain depth: %d\n", count);
 
     for (n = 0; n < count; n++) {
         ne_ssl_certificate *cert = ne_malloc(sizeof *cert);

libs/neon/src/ne_session.c

@@ -611,7 +611,7 @@ int ne__ssl_match_hostname(const char *cn, size_t cnlen, const char *hostname)
 {
     const char *dot;
 
-    NE_DEBUG(NE_DBG_SSL, "ssl: Match common name '%s' against '%s'\n",
+    NE_DEBUG(NE_DBG_WINSCP_HTTP_DETAIL, "ssl: Match common name '%s' against '%s'\n",
              cn, hostname);
 
     if (strncmp(cn, "*.", 2) == 0 && cnlen > 2

source/core/NeonIntf.cpp

@@ -356,7 +356,7 @@ void ne_debug(void * Context, int Channel, const char * Format, ...)
       FLAGSET(Channel, NE_DBG_HTTPAUTH) ||
       FLAGSET(Channel, NE_DBG_SSL))
   {
-    DoLog = true;
+    DoLog = (Configuration->ActualLogProtocol >= 0);
   }
   else if (FLAGSET(Channel, NE_DBG_XML) ||
            FLAGSET(Channel, NE_DBG_WINSCP_HTTP_DETAIL))

source/core/S3FileSystem.cpp

@@ -211,7 +211,7 @@ bool TS3FileSystem::VerifyCertificate(TNeonCertificateData Data)
   }
   else
   {
-    FTerminal->LogEvent(CertificateVerificationMessage(Data));
+    FTerminal->LogEvent(0, CertificateVerificationMessage(Data));
 
     UnicodeString SiteKey = TSessionData::FormatSiteKey(FTerminal->SessionData->HostNameExpanded, FTerminal->SessionData->PortNumber);
     Result =
@@ -225,7 +225,7 @@ bool TS3FileSystem::VerifyCertificate(TNeonCertificateData Data)
     {
       UnicodeString Message;
       Result = NeonWindowsValidateCertificateWithMessage(Data, Message);
-      FTerminal->LogEvent(Message);
+      FTerminal->LogEvent(0, Message);
     }
 
     FSessionInfo.Certificate = CertificateSummary(Data, FTerminal->SessionData->HostNameExpanded);
@@ -254,7 +254,7 @@ void TS3FileSystem::CollectTLSSessionInfo()
   // Have to cache the value as the connection (the neon HTTP session, not "our" session)
   // can be closed at the time we need it in CollectUsage().
   UnicodeString Message = NeonTlsSessionInfo(FNeonSession, FSessionInfo, FTlsVersionStr);
-  FTerminal->LogEvent(Message);
+  FTerminal->LogEvent(0, Message);
 }
 //---------------------------------------------------------------------------
 S3Status TS3FileSystem::LibS3ResponsePropertiesCallback(const S3ResponseProperties * /*Properties*/, void * /*CallbackData*/)
@@ -329,7 +329,7 @@ void TS3FileSystem::LibS3ResponseCompleteCallback(S3Status Status, const S3Error
     }
   }
 
-  if (!FileSystem->FResponse.IsEmpty())
+  if (!FileSystem->FResponse.IsEmpty() && (FileSystem->FTerminal->Configuration->ActualLogProtocol >= 0))
   {
     FileSystem->FTerminal->Log->Add(llOutput, FileSystem->FResponse);
   }

source/core/ScpFileSystem.cpp

@@ -2101,10 +2101,7 @@ void __fastcall TSCPFileSystem::CopyToLocal(TStrings * FilesToCopy,
 
   FTerminal->LogEvent(FORMAT(L"Copying %d files/directories to local directory "
     "\"%s\"", (FilesToCopy->Count, TargetDir)));
-  if (FTerminal->Configuration->ActualLogProtocol >= 0)
-  {
-    FTerminal->LogEvent(CopyParam->LogStr);
-  }
+  FTerminal->LogEvent(0, CopyParam->LogStr);
 
   try
   {
@@ -2523,11 +2520,9 @@ void __fastcall TSCPFileSystem::SCPSink(const UnicodeString TargetDir,
               // Will we use ASCII of BINARY file transfer?
               OperationProgress->SetAsciiTransfer(
                 CopyParam->UseAsciiTransfer(BaseFileName, osRemote, MaskParams));
-              if (FTerminal->Configuration->ActualLogProtocol >= 0)
-              {
-                FTerminal->LogEvent(UnicodeString((OperationProgress->AsciiTransfer ? L"Ascii" : L"Binary")) +
+              FTerminal->LogEvent(
+                0, UnicodeString((OperationProgress->AsciiTransfer ? L"Ascii" : L"Binary")) +
                   L" transfer mode selected.");
-              }
 
               try
               {

source/core/SftpFileSystem.cpp

@@ -2576,18 +2576,12 @@ int __fastcall TSFTPFileSystem::ReceivePacket(TSFTPPacket * Packet,
               IsReserved = true;
               if (ReservedPacket)
               {
-                if (FTerminal->Configuration->ActualLogProtocol >= 0)
-                {
-                  FTerminal->LogEvent(L"Storing reserved response");
-                }
+                FTerminal->LogEvent(0, L"Storing reserved response");
                 *ReservedPacket = *Packet;
               }
               else
               {
-                if (FTerminal->Configuration->ActualLogProtocol >= 0)
-                {
-                  FTerminal->LogEvent(L"Discarding reserved response");
-                }
+                FTerminal->LogEvent(0, L"Discarding reserved response");
                 RemoveReservation(Index);
                 if ((Reservation >= 0) && (Reservation > Index))
                 {
@@ -2722,10 +2716,7 @@ UnicodeString __fastcall TSFTPFileSystem::RealPath(const UnicodeString Path)
 {
   try
   {
-    if (FTerminal->Configuration->ActualLogProtocol >= 0)
-    {
-      FTerminal->LogEvent(FORMAT(L"Getting real path for '%s'", (Path)));
-    }
+    FTerminal->LogEvent(0, FORMAT(L"Getting real path for '%s'", (Path)));
 
     TSFTPPacket Packet(SSH_FXP_REALPATH);
     AddPathString(Packet, Path);
@@ -2772,10 +2763,7 @@ UnicodeString __fastcall TSFTPFileSystem::RealPath(const UnicodeString Path)
     RealDir = FTerminal->DecryptFileName(RealDir);
     // ignore rest of SSH_FXP_NAME packet
 
-    if (FTerminal->Configuration->ActualLogProtocol >= 0)
-    {
-      FTerminal->LogEvent(FORMAT(L"Real path is '%s'", (RealDir)));
-    }
+    FTerminal->LogEvent(0, FORMAT(L"Real path is '%s'", (RealDir)));
 
     return RealDir;
   }
@@ -3159,11 +3147,7 @@ void __fastcall TSFTPFileSystem::DoStartup()
       }
       else
       {
-        if (FTerminal->Configuration->ActualLogProtocol >= 0)
-        {
-          FTerminal->LogEvent(FORMAT(L"Unknown server extension %s=%s",
-            (ExtensionName, ExtensionDisplayData)));
-        }
+        FTerminal->LogEvent(0, FORMAT(L"Unknown server extension %s=%s", (ExtensionName, ExtensionDisplayData)));
       }
       FExtensions->Values[ExtensionName] = ExtensionDisplayData;
     }
@@ -4623,10 +4607,7 @@ void __fastcall TSFTPFileSystem::Source(
   OpenParams.FileParams = &FileParams;
   OpenParams.Confirmed = false;
 
-  if (FTerminal->Configuration->ActualLogProtocol >= 0)
-  {
-    FTerminal->LogEvent(L"Opening remote file.");
-  }
+  FTerminal->LogEvent(0, L"Opening remote file.");
   FTerminal->FileOperationLoop(SFTPOpenRemote, OperationProgress, folAllowSkip,
     FMTLOAD(SFTP_CREATE_FILE_ERROR, (OpenParams.RemoteFileName)),
     &OpenParams);

source/core/Terminal.cpp

@@ -3072,6 +3072,14 @@ void __fastcall inline TTerminal::LogEvent(const UnicodeString & Str)
   }
 }
 //---------------------------------------------------------------------------
+void __fastcall inline TTerminal::LogEvent(int Level, const UnicodeString & Str)
+{
+  if (Log->Logging && (Configuration->ActualLogProtocol >= Level))
+  {
+    Log->Add(llMessage, Str);
+  }
+}
+//---------------------------------------------------------------------------
 void __fastcall TTerminal::RollbackAction(TSessionAction & Action,
   TFileOperationProgressType * OperationProgress, Exception * E)
 {
@@ -5577,19 +5585,13 @@ void __fastcall TTerminal::DoSynchronizeCollectDirectory(const UnicodeString Loc
           FileData->New = true;
           FileData->Modified = false;
           Data.LocalFileList->AddObject(FileName, reinterpret_cast<TObject*>(FileData));
-          if (Configuration->ActualLogProtocol >= 0)
-          {
-            LogEvent(FORMAT(L"Local file %s included to synchronization",
-              (FormatFileDetailsForLog(FullLocalFileName, SearchRec.GetLastWriteTime(), SearchRec.Size))));
-          }
+          LogEvent(0, FORMAT(L"Local file %s included to synchronization",
+            (FormatFileDetailsForLog(FullLocalFileName, SearchRec.GetLastWriteTime(), SearchRec.Size))));
         }
         else
         {
-          if (Configuration->ActualLogProtocol >= 0)
-          {
-            LogEvent(FORMAT(L"Local file %s excluded from synchronization",
-              (FormatFileDetailsForLog(FullLocalFileName, SearchRec.GetLastWriteTime(), SearchRec.Size))));
-          }
+          LogEvent(0, FORMAT(L"Local file %s excluded from synchronization",
+            (FormatFileDetailsForLog(FullLocalFileName, SearchRec.GetLastWriteTime(), SearchRec.Size))));
         }
 
       }
@@ -5928,11 +5930,8 @@ void __fastcall TTerminal::DoSynchronizeCollectFile(const UnicodeString FileName
   }
   else
   {
-    if (Configuration->ActualLogProtocol >= 0)
-    {
-      LogEvent(FORMAT(L"Remote file %s excluded from synchronization",
-        (FormatFileDetailsForLog(FullRemoteFileName, File->Modification, File->Size))));
-    }
+    LogEvent(0, FORMAT(L"Remote file %s excluded from synchronization",
+      (FormatFileDetailsForLog(FullRemoteFileName, File->Modification, File->Size))));
   }
 }
 //---------------------------------------------------------------------------
@@ -6637,10 +6636,7 @@ void __fastcall TTerminal::LogTotalTransferDetails(
       S += FORMAT(L" - total size: %s", (FormatSize(OperationProgress->TotalSize)));
     }
     LogEvent(S);
-    if (Configuration->ActualLogProtocol >= 0)
-    {
-      LogEvent(CopyParam->LogStr);
-    }
+    LogEvent(0, CopyParam->LogStr);
   }
 }
 //---------------------------------------------------------------------------
@@ -6994,11 +6990,8 @@ void __fastcall TTerminal::SelectTransferMode(
 {
   bool AsciiTransfer = IsCapable[fcTextMode] && CopyParam->UseAsciiTransfer(BaseFileName, Side, MaskParams);
   OperationProgress->SetAsciiTransfer(AsciiTransfer);
-  if (Configuration->ActualLogProtocol >= 0)
-  {
-    UnicodeString ModeName = (OperationProgress->AsciiTransfer ? L"Ascii" : L"Binary");
-    LogEvent(FORMAT(L"%s transfer mode selected.", (ModeName)));
-  }
+  UnicodeString ModeName = (OperationProgress->AsciiTransfer ? L"Ascii" : L"Binary");
+  LogEvent(0, FORMAT(L"%s transfer mode selected.", (ModeName)));
 }
 //---------------------------------------------------------------------------
 void __fastcall TTerminal::SelectSourceTransferMode(const TLocalFileHandle & Handle, const TCopyParamType * CopyParam)

source/core/Terminal.h

@@ -605,6 +605,7 @@ public:
 
   const TSessionInfo & __fastcall GetSessionInfo();
   const TFileSystemInfo & __fastcall GetFileSystemInfo(bool Retrieve = false);
+  void __fastcall inline LogEvent(int Level, const UnicodeString & Str);
   void __fastcall inline LogEvent(const UnicodeString & Str);
   void __fastcall GetSupportedChecksumAlgs(TStrings * Algs);
   UnicodeString __fastcall ChangeFileName(const TCopyParamType * CopyParam,

source/core/WebDAVFileSystem.cpp

@@ -1732,7 +1732,7 @@ bool TWebDAVFileSystem::VerifyCertificate(TNeonCertificateData Data, bool Aux)
   }
   else
   {
-    FTerminal->LogEvent(CertificateVerificationMessage(Data));
+    FTerminal->LogEvent(0, CertificateVerificationMessage(Data));
 
     UnicodeString SiteKey = TSessionData::FormatSiteKey(FHostName, FPortNumber);
     Result =
@@ -1746,7 +1746,7 @@ bool TWebDAVFileSystem::VerifyCertificate(TNeonCertificateData Data, bool Aux)
     {
       UnicodeString Message;
       Result = NeonWindowsValidateCertificateWithMessage(Data, Message);
-      FTerminal->LogEvent(Message);
+      FTerminal->LogEvent(0, Message);
     }
 
     FSessionInfo.Certificate = CertificateSummary(Data, FHostName);
@@ -1775,7 +1775,7 @@ void __fastcall TWebDAVFileSystem::CollectTLSSessionInfo()
   // Have to cache the value as the connection (the neon HTTP session, not "our" session)
   // can be closed at the time we need it in CollectUsage().
   UnicodeString Message = NeonTlsSessionInfo(FNeonSession, FSessionInfo, FTlsVersionStr);
-  FTerminal->LogEvent(Message);
+  FTerminal->LogEvent(0, Message);
 }
 //------------------------------------------------------------------------------
 // A neon-session callback to validate the SSL certificate when the CA