/* * TextLogger.cs * * Copyright © 2010 * Diversified Technical Systems, Inc. * All Rights Reserved. */ using System; using System.Collections.Generic; using System.IO; using System.Threading; // ReSharper disable EmptyGeneralCatchClause namespace DTS.Common.Utilities.Logging { // DEVELOPMENT NOTES: // // -> Keeping the regular logging functionality in place, we will have another logger that simply // writes the same thing to a temporary file. At the point we commit to a test ID, the temp // file will be moved to the associated test directory and logging will resume at that location. // Once the test is finished, another not-yet-test-related temp file will be created and the // process will continue from there. // // -> Due to existing limitations of the current Logging.TextLogger class it will // be necessary to fundamentally revamp so that it will be able to synchronize log message input // with logger control state changes so that, for example, we don't lose log events that happen // while we're changing the location of the "temp" log file, which requires time to close the old // file, move it, and then open the new write handle. The simplest solution to me seems to be a // queue for the write queue, so that when the "test ID is known" event fires is invoked in the // logger it goes something like this: // // 1) Cut-off processing of the the "pre-write queue" queue so that any subsequent log messages // are held for the moment. // // 2) Wait until the "write" queue finishes writing to temp log file. // // 3) Close write handle. // // 4) Move temp log file to test-specific location. // // 5) Open write handle. // // 6) Let "pre-write queue" start feeding "write" queue again. // // -> Do we need to add parameters for the pre/write queues? Could make that part of the // mechanism to disconnect them from the feeders and let them evaporate when it's time to // switch filenames. Could we do that? Just alter the behavior to be evaporate on shutdown, // activate it, and then create a new instance of the cycle with the new filename. // // -> Everytime the filename is set, the object should just allocate a new write cycle, // after flaging the previous one for termination. // // -> Ok, we're going to associate a "handle" structure with the write cycle that will // contain the queue, control booleans, trigger events, etc. That way we really can just // set the "termination" bool to true, trigger a cycle and then just let go of the balloon // when we're ready to start another write cycle associated with another log pathname. The // expired queue closure will finish writing, then close the writer and wait for disposal. // This will also simplify things as we won't need to hammer the bugs out of this rather // baroque pausable two-queue system. // // -> Furthermore, the new write cycle closure will be created and launched (and the old // one set for disposal) by the set accessor of the TextWriter's LogPathname property. // That way you really don't have to think about anything; just change the name and keep // logging and all should be well. // /// /// /// A class to implement a threaded log file. /// Problems encountered by the writing thread will be reported thru the callback function. /// The logger is re/started whenever it is assigned a new log filepath. /// public partial class TextLogger : IDisposable { /// /// The associated with the current /// active log file. /// protected WriteCycleHandle CurrentLoggingCycle { get; set; } /// /// Shut down the current write cycle. /// protected void EndCurrentWriteCycle() { try { if (null == CurrentLoggingCycle) return; CurrentLoggingCycle.TerminateWriteCycle = true; CurrentLoggingCycle.CycleTrigger.Set(); } catch (Exception ex) { throw new ApplicationException("encountered problem ending current writing cycle", ex); } } /// /// Open a log file with the specified name and start processing log messages into it. If another /// log file is currently active, it will be closed, flushed and disposed. /// /// /// /// The pathname of the logfile to receive new log messages. /// /// protected void StartNewWriteCycle(string logPathname) { try { if (string.IsNullOrEmpty(logPathname)) throw new NullReferenceException("log pathname cannot be empty/null"); if (null != CurrentLoggingCycle) { lock (CurrentLoggingCycle.WriteQueue) { EndCurrentWriteCycle(); } QueueWriteCycle(CurrentLoggingCycle = new WriteCycleHandle(logPathname, new Queue(), null, OnWriteException, false)); } else QueueWriteCycle(CurrentLoggingCycle = new WriteCycleHandle(logPathname, new Queue(), null, OnWriteException, false)); } catch (Exception ex) { throw new ApplicationException("encounterd problem starting new logging cycle", ex); } } /// /// Change the name/location of the currently active log file without dropping any /// incoming messages. /// /// /// /// The new path name for the active log file. /// /// public void MoveLogTo(string newPathName) { try { APILogger.Log("Moving file"); // // Here's the plan: have a common lock around the old and new queues that result when you // add a new log file. When it comes time to do a "move", take the lock, mark the old queue handle // for termination, and on the termination callback return create the new file. Can it be that simple? // lock (this) { CurrentLoggingCycle.OnWriteCycleTermination = delegate { try { if (!Path.GetFullPath(LogPathname).Equals(Path.GetFullPath(newPathName)) && File.Exists(LogPathname)) { if (File.Exists(newPathName)) File.Delete(newPathName); File.Move(LogPathname, newPathName); } } catch (Exception ex) { OnWriteException?.Invoke(new ApplicationException("encountered problem moving log file to path " + (null != newPathName ? "\"" + newPathName + "\"" : ""), ex)); } finally { LogPathname = newPathName; } }; CurrentLoggingCycle.TerminateWriteCycle = true; } } catch (Exception ex) { throw new ApplicationException("encountered problem moving log to new path " + (null != newPathName ? "\"" + newPathName + "\"" : ""), ex); } } private static readonly object LogPathNameLock = new object(); /// /// Get/set the pathname of the currently active log file. /// public string LogPathname { get { if (null != _logPathname) { return _logPathname; } throw new LogPathnameNotInitializedException("the pathname has not been initialized"); } set { try { lock (LogPathNameLock) { // Do not use System.IO.Path.GetFullPath here to compare the new value to the old // because on XP SaveFileDialog temporarily changes the current directory // and GetFullPath uses GetCurrentDirectory. So, with an ECM connected, that will // cause errors from the text logger when CSV or ISO exports wait in SaveFileDialog. if (null == _logPathname || value != _logPathname) { // If we're actually changing the name/location of this thing, then let's stop writing the // old file and start in on the new one. // _logPathname = value; if (!ThreadPool.QueueUserWorkItem(delegate { StartNewWriteCycle(LogPathname); })) throw new ApplicationException(Properties.Resources.TextLogger_TextLogger_EnqueueWriterFailureString); } } } catch (Exception ex) { throw new ApplicationException("encountered problem setting log pathname", ex); } } } private string _logPathname = null; public static void CompressLogFilesIntoZip(string sourcedir, string destFile) { var z = new ICSharpCode.SharpZipLib.Zip.FastZip(); z.CreateZip(destFile, sourcedir, false, null); } /// /// Get the filename portion of the associated log's filename. /// public string LogFilename { get { try { // Consider the filename to be anything in the full log file name beyond the last path // separator character. // return Path.GetFileName(LogPathname); } catch (Exception ex) { throw new ApplicationException("encountered problem getting log file name", ex); } } } /// /// A callback type for write queue events. /// /// /// /// The write queue's queue. /// /// public delegate void WriteCycleCallback(Queue writeQueue); /// /// A callback type to be invoked when exceptions occur in the text writer's threaded /// writing method. /// /// public delegate void WriteCycleExceptionHandler(Exception ex); /// /// The that well be invoked /// whenever the logger encounters an exceptional condition within the write cycle method. /// public WriteCycleExceptionHandler OnWriteException { get; set; } /// /// text written to the start of a log (such as application version, etc) /// if null, no text is written /// public string LogStartMessage { get; set; } = null; /// /// The write loop that processes queued log messages. It is run in its own thread. /// /// /// /// The associated with the /// log file to receive processed log messages. /// /// private void QueueWriteCycle(WriteCycleHandle writeCycle) { try { var fullPath = Path.Combine(Path.GetDirectoryName(System.Reflection.Assembly.GetExecutingAssembly().Location), writeCycle.FullLogFileName); while (!writeCycle.TerminateWriteCycle) { writeCycle.CycleTrigger.WaitOne(); // Do not use System.IO.File.Exists without explicitly specifying the full path, // based on System.Reflection.Assembly.GetExecutingAssembly().Location, // because on XP SaveFileDialog temporarily changes the current directory // and File.Exists uses GetCurrentDirectory. So, with an ECM connected, that will // cause errors from the text logger when CSV or ISO exports wait in SaveFileDialog. var bFileExists = File.Exists(fullPath); if (!bFileExists) { using (var fs = new FileStream(writeCycle.FullLogFileName, FileMode.Create)) { fs.Close(); } try { File.SetCreationTime(writeCycle.FullLogFileName, DateTime.Now); } catch (Exception) { //ignore } } using (var fs = new FileStream(writeCycle.FullLogFileName, FileMode.Append)) { using (var gs = new StreamWriter(fs)) { lock (writeCycle.WriteQueue) { if (!bFileExists && null != LogStartMessage) { gs.Write(LogStartMessage); } while (writeCycle.WriteQueue.Count > 0) { try { _loggingMutex.WaitOne(); gs.Write(writeCycle.WriteQueue.Dequeue()); } catch { //ignore } finally { _loggingMutex.ReleaseMutex(); } } } } } try { _loggingMutex.WaitOne(); CheckForLargeLogFileAndRename(writeCycle.FullLogFileName); } catch (Exception) { //ignore } finally { _loggingMutex.ReleaseMutex(); } } writeCycle.CycleCompletionTrigger.Set(); writeCycle.OnWriteCycleTermination?.Invoke(writeCycle.WriteQueue); } catch (Exception ex) { if (null != writeCycle.OnWriteCycleException) { try { File.AppendAllText("LOGERROR.LOG", ex.StackTrace + Environment.NewLine + ex.Message); } catch (Exception) { //ignore } writeCycle.OnWriteCycleException(new ApplicationException("encountered problem processing text logger queue", ex)); } if (!writeCycle.TerminateCycleOnException) QueueWriteCycle(writeCycle); } } /// /// Initialize an instance of the class. /// /// /// /// The pathname of the log file that will be generated by /// this class. /// /// /// /// The to be invoked when /// an exception occurs in the queue processing loop. /// /// public TextLogger(string logPathname, WriteCycleExceptionHandler onWriteException) { try { OnWriteException = onWriteException; LogPathname = logPathname; } catch (Exception ex) { throw new ApplicationException("encountered problem constructing " + typeof(TextLogger).FullName + " object", ex); } } /// /// Initialize an instance of the class. /// /// /// /// The pathname of the log file that will be generated by /// this class. /// /// /// /// The to be invoked when /// an exception occurs in the queue processing loop. /// /// public TextLogger(string logPathname, WriteCycleExceptionHandler onWriteException, int maxLogFileSize) { try { OnWriteException = onWriteException; LogPathname = logPathname; MaximumLogFileSizeBytes = maxLogFileSize; } catch (Exception ex) { throw new ApplicationException("encountered problem constructing " + typeof(TextLogger).FullName + " object", ex); } } /// /// Write the specified string to the log file. /// /// /// /// The text to be written to the log file. /// /// public void LogMessage(string message) { try { if (null == CurrentLoggingCycle) { return; } lock (CurrentLoggingCycle.WriteQueue) { CurrentLoggingCycle.WriteQueue.Enqueue($"{message} {Environment.NewLine}"); CurrentLoggingCycle.CycleTrigger.Set(); } } catch (Exception ex) { throw new ApplicationException("encountered problem logging message " + (null != message ? "\"" + message + "\"" : ""), ex); } } /// /// Process the remaining items in the queue and then release all resources. /// public void Dispose() { try { lock (CurrentLoggingCycle.WriteQueue) EndCurrentWriteCycle(); } catch (Exception ex) { throw new ApplicationException("encountered problem disposing instance of " + typeof(TextLogger).FullName, ex); } } /// /// The byte-size at which the log file should be archived. /// public int MaximumLogFileSizeBytes { get; set; } = 1000000; private readonly Mutex _loggingMutex = new Mutex(false, "SLICEWare_Log"); public volatile bool ReRollLog = false; /// /// Check the size of the specified file and if it exceeds the maximum log file size /// then give it an archival name and open a new logfile for subsequent data. A /// cut 'n paste transplant from the original TextLogger. /// /// /// /// The new archival filename for the log file if it exceeds the /// maximum specified byte-size. /// /// protected void CheckForLargeLogFileAndRename(string fileName) { if (!File.Exists(fileName)) { return; } var logFileInfo = new FileInfo(fileName); if (MaximumLogFileSizeBytes >= logFileInfo.Length && !ReRollLog) return; try { ReRollLog = false; // Set the new file name to the time stamp of the file var baseFileName = Path.Combine(Path.GetDirectoryName(fileName), Path.GetFileNameWithoutExtension(fileName)); // Rather than rely on locale specific date/time strings, construct it ourself so // that it will always be yyyy-mm-dd hh.mm. This will cause the file names to sort // chronologically based on name, and should create a consistent file name result // for technical support var dateTimeStamp = logFileInfo.LastWriteTime.ToString("yyyy-MM-dd HH.mm.ss"); var tempFileName = baseFileName + "TEMP"; if (File.Exists(tempFileName)) { File.Delete(tempFileName); } File.Move(fileName, tempFileName); var newFileName = baseFileName + " " + dateTimeStamp + ".log.bz2"; try { using (var fs = new FileStream(newFileName, FileMode.Create)) { using (var fs2 = new FileStream(tempFileName, FileMode.Open)) { ICSharpCode.SharpZipLib.BZip2.BZip2.Compress(fs2, fs, true, 9); } } File.Delete(tempFileName); } catch (Exception) { newFileName = baseFileName + " " + dateTimeStamp + Path.GetExtension(fileName); try { File.Move(fileName, newFileName); } catch (Exception) { //ignore } } } catch (Exception) { var newName = fileName + ".LOGERROR"; try { File.Move(fileName, newName); } catch (Exception) { //ignore } } } } }