Basic implementation of application log

(cherry picked from commit 945783dc9c554227ece74e270fe9a08d5762659e)

Source commit: 1bac2aff6b3a190d2e4f97ea5ed2dc7092f256ce

source/WinSCP.cpp

@@ -17,6 +17,15 @@ USEFORM("forms\ScpExplorer.cpp", ScpExplorerForm);
 //---------------------------------------------------------------------------
 WINAPI wWinMain(HINSTANCE, HINSTANCE, LPWSTR, int)
 {
+  AppLog = new TApplicationLog();
+  TProgramParams * Params = TProgramParams::Instance();
+  UnicodeString AppLogPath;
+  if (Params->FindSwitch(L"applog", AppLogPath))
+  {
+    AppLog->Enable(AppLogPath);
+  }
+  AppLog->Log(L"Starting...");
+
   AddStartupSequence(L"M");
   DllHijackingProtection();
   AddStartupSequence(L"T");
@@ -30,6 +39,7 @@ WINAPI wWinMain(HINSTANCE, HINSTANCE, LPWSTR, int)
     SetEnvironmentVariable(L"WINSCP_PATH",
       ExcludeTrailingBackslash(ExtractFilePath(Application->ExeName)).c_str());
     CoreInitialize();
+    AppLog->AddStartupInfo(); // Needs Configuration
     InitializeWinHelp();
     InitializeSystemSettings();
     AddStartupSequence(L"S");
@@ -42,7 +52,9 @@ WINAPI wWinMain(HINSTANCE, HINSTANCE, LPWSTR, int)
         SetupInitialize();
 
         Application->Title = AppName;
+        AppLog->Log(L"Executing...");
         Result = Execute();
+        AppLog->Log(L"Execution done");
       }
       catch (Exception & E)
       {
@@ -56,11 +68,14 @@ WINAPI wWinMain(HINSTANCE, HINSTANCE, LPWSTR, int)
     }
     __finally
     {
+      AppLog->Log(L"Finalizing");
       GUIFinalize();
       FinalizeSystemSettings();
       FinalizeWinHelp();
       CoreFinalize();
       WinFinalize();
+      AppLog->Log(L"Finalizing done");
+      SAFE_DESTROY_EX(TApplicationLog, AppLog);
     }
   }
   catch (Exception &E)

source/core/CoreMain.cpp

@@ -18,6 +18,7 @@
 //---------------------------------------------------------------------------
 TConfiguration * Configuration = NULL;
 TStoredSessionList * StoredSessions = NULL;
+TApplicationLog * AppLog = NULL;
 bool AnySession = false;
 //---------------------------------------------------------------------------
 TQueryButtonAlias::TQueryButtonAlias()

source/core/CoreMain.h

@@ -9,6 +9,8 @@ extern TConfiguration *Configuration;
 class TStoredSessionList;
 extern TStoredSessionList *StoredSessions;
 extern bool AnySession;
+class TApplicationLog;
+extern TApplicationLog * AppLog;
 //---------------------------------------------------------------------------
 void CoreInitialize();
 void CoreFinalize();

source/core/SessionInfo.cpp

@@ -1104,11 +1104,11 @@ UnicodeString __fastcall TSessionLog::LogSensitive(const UnicodeString & Str)
   }
 }
 //---------------------------------------------------------------------------
-UnicodeString __fastcall TSessionLog::GetCmdLineLog()
+UnicodeString __fastcall TSessionLog::GetCmdLineLog(TConfiguration * AConfiguration)
 {
   UnicodeString Result = CmdLine;
 
-  if (!Configuration->LogSensitive)
+  if (!AConfiguration->LogSensitive)
   {
     TManagementScript Script(StoredSessions, false);
     Script.MaskPasswordInCommandLine(Result, true);
@@ -1135,76 +1135,88 @@ UnicodeString __fastcall EnumName(T Value, UnicodeString Names)
 
   return L"(unknown)";
 }
+#define ADSTR(S) AddLogEntry(S)
+#define ADF(S, F) ADSTR(FORMAT(S, F));
+//---------------------------------------------------------------------------
+void __fastcall TSessionLog::DoAddStartupInfo(TAddLogEntryEvent AddLogEntry, TConfiguration * AConfiguration)
+{
+  ADSTR(GetEnvironmentInfo());
+  THierarchicalStorage * Storage = AConfiguration->CreateConfigStorage();
+  try
+  {
+    ADF(L"Configuration: %s", (Storage->Source));
+  }
+  __finally
+  {
+    delete Storage;
+  }
+
+  wchar_t UserName[UNLEN + 1];
+  unsigned long UserNameSize = LENOF(UserName);
+  if (DebugAlwaysFalse(!GetUserNameEx(NameSamCompatible, UserName, &UserNameSize)))
+  {
+    wcscpy(UserName, L"<Failed to retrieve username>");
+  }
+  UnicodeString LogStr;
+  if (AConfiguration->LogProtocol <= -1)
+  {
+    LogStr = L"Reduced";
+  }
+  else if (AConfiguration->LogProtocol <= 0)
+  {
+    LogStr = L"Normal";
+  }
+  else if (AConfiguration->LogProtocol == 1)
+  {
+    LogStr = L"Debug 1";
+  }
+  else if (AConfiguration->LogProtocol >= 2)
+  {
+    LogStr = L"Debug 2";
+  }
+  if (AConfiguration->LogSensitive)
+  {
+    LogStr += L", Logging passwords";
+  }
+  if (AConfiguration->LogMaxSize > 0)
+  {
+    LogStr += FORMAT(L", Rotating after: %s", (SizeToStr(AConfiguration->LogMaxSize)));
+    if (AConfiguration->LogMaxCount > 0)
+    {
+      LogStr += FORMAT(L", Keeping at most %d logs", (AConfiguration->LogMaxCount));
+    }
+  }
+  ADF(L"Log level: %s", (LogStr));
+  ADF(L"Local account: %s", (UserName));
+  ADF(L"Working directory: %s", (GetCurrentDir()));
+  ADF(L"Process ID: %d", (int(GetCurrentProcessId())));
+  ADF(L"Ancestor processes: %s", (GetAncestorProcessNames()));
+  ADF(L"Command-line: %s", (GetCmdLineLog(AConfiguration)));
+  if (AConfiguration->ActualLogProtocol >= 1)
+  {
+    GetGlobalOptions()->LogOptions(AddLogEntry);
+  }
+  ADF(L"Time zone: %s", (GetTimeZoneLogString()));
+  if (!AdjustClockForDSTEnabled())
+  {
+    ADSTR(L"Warning: System option \"Automatically adjust clock for Daylight Saving Time\" is disabled, timestamps will not be represented correctly");
+  }
+}
 //---------------------------------------------------------------------------
+#undef ADSTR
 #define ADSTR(S) DoAdd(llMessage, S, DoAddToSelf);
-#define ADF(S, F) ADSTR(FORMAT(S, F));
+//---------------------------------------------------------------------------
+void __fastcall TSessionLog::DoAddStartupInfoEntry(const UnicodeString & S)
+{
+  ADSTR(S);
+}
 //---------------------------------------------------------------------------
 void __fastcall TSessionLog::DoAddStartupInfo(TSessionData * Data)
 {
   if (Data == NULL)
   {
     AddSeparator();
-    ADSTR(GetEnvironmentInfo());
-    THierarchicalStorage * Storage = FConfiguration->CreateConfigStorage();
-    try
-    {
-      ADF(L"Configuration: %s", (Storage->Source));
-    }
-    __finally
-    {
-      delete Storage;
-    }
-
-    wchar_t UserName[UNLEN + 1];
-    unsigned long UserNameSize = LENOF(UserName);
-    if (DebugAlwaysFalse(!GetUserNameEx(NameSamCompatible, UserName, &UserNameSize)))
-    {
-      wcscpy(UserName, L"<Failed to retrieve username>");
-    }
-    UnicodeString LogStr;
-    if (FConfiguration->LogProtocol <= -1)
-    {
-      LogStr = L"Reduced";
-    }
-    else if (FConfiguration->LogProtocol <= 0)
-    {
-      LogStr = L"Normal";
-    }
-    else if (FConfiguration->LogProtocol == 1)
-    {
-      LogStr = L"Debug 1";
-    }
-    else if (FConfiguration->LogProtocol >= 2)
-    {
-      LogStr = L"Debug 2";
-    }
-    if (FConfiguration->LogSensitive)
-    {
-      LogStr += L", Logging passwords";
-    }
-    if (FConfiguration->LogMaxSize > 0)
-    {
-      LogStr += FORMAT(L", Rotating after: %s", (SizeToStr(FConfiguration->LogMaxSize)));
-      if (FConfiguration->LogMaxCount > 0)
-      {
-        LogStr += FORMAT(L", Keeping at most %d logs", (FConfiguration->LogMaxCount));
-      }
-    }
-    ADF(L"Log level: %s", (LogStr));
-    ADF(L"Local account: %s", (UserName));
-    ADF(L"Working directory: %s", (GetCurrentDir()));
-    ADF(L"Process ID: %d", (int(GetCurrentProcessId())));
-    ADF(L"Ancestor processes: %s", (GetAncestorProcessNames()));
-    ADF(L"Command-line: %s", (GetCmdLineLog()));
-    if (FConfiguration->ActualLogProtocol >= 1)
-    {
-      AddOptions(GetGlobalOptions());
-    }
-    ADF(L"Time zone: %s", (GetTimeZoneLogString()));
-    if (!AdjustClockForDSTEnabled())
-    {
-      ADSTR(L"Warning: System option \"Automatically adjust clock for Daylight Saving Time\" is disabled, timestamps will not be represented correctly");
-    }
+    DoAddStartupInfo(DoAddStartupInfoEntry, FConfiguration);
     ADF(L"Login time: %s", (FormatDateTime(L"dddddd tt", Now())));
     AddSeparator();
   }
@@ -1461,16 +1473,6 @@ void __fastcall TSessionLog::DoAddStartupInfo(TSessionData * Data)
   }
 }
 //---------------------------------------------------------------------------
-void __fastcall TSessionLog::AddOption(const UnicodeString & LogStr)
-{
-  ADSTR(LogStr);
-}
-//---------------------------------------------------------------------------
-void __fastcall TSessionLog::AddOptions(TOptions * Options)
-{
-  Options->LogOptions(AddOption);
-}
-//---------------------------------------------------------------------------
 #undef ADF
 #undef ADSTR
 //---------------------------------------------------------------------------
@@ -1755,3 +1757,44 @@ void __fastcall TActionLog::SetEnabled(bool value)
     ReflectSettings();
   }
 }
+//---------------------------------------------------------------------------
+//---------------------------------------------------------------------------
+TApplicationLog::TApplicationLog()
+{
+  FFile = NULL;
+  FCriticalSection.reset(new TCriticalSection());
+}
+//---------------------------------------------------------------------------
+TApplicationLog::~TApplicationLog()
+{
+  if (FFile != NULL)
+  {
+    Log(L"Closing log");
+    fclose(static_cast<FILE *>(FFile));
+    FFile = NULL;
+  }
+}
+//---------------------------------------------------------------------------
+void TApplicationLog::Enable(const UnicodeString & Path)
+{
+  UnicodeString Dummy;
+  FFile = OpenFile(Path, Now(), NULL, false, Dummy);
+}
+//---------------------------------------------------------------------------
+void TApplicationLog::AddStartupInfo()
+{
+  TSessionLog::DoAddStartupInfo(Log, Configuration);
+}
+//---------------------------------------------------------------------------
+void __fastcall TApplicationLog::Log(const UnicodeString & S)
+{
+  if (FFile != NULL)
+  {
+    UnicodeString Timestamp = FormatDateTime(L"yyyy-mm-dd hh:nn:ss.zzz", Now());
+    UnicodeString Line = FORMAT(L"[%s] [%x] %s\r\n", (Timestamp, static_cast<int>(GetCurrentThreadId()), S));
+    UTF8String UtfLine = UTF8String(Line);
+    int Writting = UtfLine.Length();
+    TGuard Guard(FCriticalSection.get());
+    fwrite(UtfLine.c_str(), 1, Writting, static_cast<FILE *>(FFile));
+  }
+}

source/core/SessionInfo.h

@@ -246,8 +246,12 @@ public:
   __fastcall TDifferenceSessionAction(TActionLog * Log, const TSynchronizeChecklist::TItem * Item);
 };
 //---------------------------------------------------------------------------
+typedef void __fastcall (__closure *TAddLogEntryEvent)(const UnicodeString & S);
+//---------------------------------------------------------------------------
 class TSessionLog
 {
+friend class TApplicationLog;
+
 public:
   __fastcall TSessionLog(TSessionUI* UI, TDateTime Started, TSessionData * SessionData,
     TConfiguration * Configuration);
@@ -269,6 +273,7 @@ public:
 protected:
   void __fastcall CloseLogFile();
   bool __fastcall LogToFile();
+  static void __fastcall DoAddStartupInfo(TAddLogEntryEvent AddLogEntry, TConfiguration * AConfiguration);
 
 private:
   TConfiguration * FConfiguration;
@@ -295,11 +300,10 @@ private:
   void __fastcall DoAddStartupInfo(TSessionData * Data);
   UnicodeString __fastcall GetTlsVersionName(TTlsVersion TlsVersion);
   UnicodeString __fastcall LogSensitive(const UnicodeString & Str);
-  void __fastcall AddOption(const UnicodeString & LogStr);
-  void __fastcall AddOptions(TOptions * Options);
-  UnicodeString __fastcall GetCmdLineLog();
+  static UnicodeString __fastcall GetCmdLineLog(TConfiguration * AConfiguration);
   void __fastcall CheckSize(__int64 Addition);
   UnicodeString __fastcall LogPartFileName(const UnicodeString & BaseName, int Index);
+  void __fastcall DoAddStartupInfoEntry(const UnicodeString & S);
 };
 //---------------------------------------------------------------------------
 class TActionLog
@@ -354,4 +358,18 @@ private:
   void __fastcall SetEnabled(bool value);
 };
 //---------------------------------------------------------------------------
+class TApplicationLog
+{
+public:
+  TApplicationLog();
+  ~TApplicationLog();
+  void Enable(const UnicodeString & Path);
+  void AddStartupInfo();
+  void __fastcall Log(const UnicodeString & S);
+
+private:
+  void * FFile;
+  std::unique_ptr<TCriticalSection> FCriticalSection;
+};
+//---------------------------------------------------------------------------
 #endif