diff --git a/ATXSerializables/ATXCommon.csproj b/ATXCommon/ATXCommon.csproj similarity index 81% rename from ATXSerializables/ATXCommon.csproj rename to ATXCommon/ATXCommon.csproj index a282202c7235ec24cbd0da42d25422625a62eb58..a2297d0690cc0df52a27fb4522b881d06eb3affd 100644 --- a/ATXSerializables/ATXCommon.csproj +++ b/ATXCommon/ATXCommon.csproj @@ -30,9 +30,15 @@ <WarningLevel>4</WarningLevel> </PropertyGroup> <ItemGroup> + <Reference Include="NLog, Version=4.0.0.0, Culture=neutral, PublicKeyToken=5120e14c03d0593c, processorArchitecture=MSIL"> + <HintPath>..\packages\NLog.4.3.11\lib\net45\NLog.dll</HintPath> + <Private>True</Private> + </Reference> <Reference Include="System" /> <Reference Include="System.Configuration" /> <Reference Include="System.Core" /> + <Reference Include="System.DirectoryServices.AccountManagement" /> + <Reference Include="System.Management" /> <Reference Include="System.Xml.Linq" /> <Reference Include="System.Data.DataSetExtensions" /> <Reference Include="Microsoft.CSharp" /> @@ -40,13 +46,20 @@ <Reference Include="System.Xml" /> </ItemGroup> <ItemGroup> + <Compile Include="ActiveDirectory.cs" /> + <Compile Include="Conv.cs" /> <Compile Include="FsUtils.cs" /> + <Compile Include="NLog\RateLimitWrapper.cs" /> <Compile Include="Serializables\DriveToCheck.cs" /> <Compile Include="Serializables\ServiceConfig.cs" /> <Compile Include="Properties\AssemblyInfo.cs" /> <Compile Include="Serializables\ServiceStatus.cs" /> + <Compile Include="SystemChecks.cs" /> <Compile Include="TimeUtils.cs" /> </ItemGroup> + <ItemGroup> + <None Include="packages.config" /> + </ItemGroup> <Import Project="$(MSBuildToolsPath)\Microsoft.CSharp.targets" /> <!-- To modify your build process, add your task inside one of the targets below and uncomment it. Other similar extension points exist, see Microsoft.Common.targets. diff --git a/ATXCommon/ActiveDirectory.cs b/ATXCommon/ActiveDirectory.cs new file mode 100644 index 0000000000000000000000000000000000000000..6fd6335713ca0d8fb04d3a5eae6bdf6a4def17fc --- /dev/null +++ b/ATXCommon/ActiveDirectory.cs @@ -0,0 +1,52 @@ +using System; +using System.DirectoryServices.AccountManagement; +using NLog; + +namespace ATXCommon +{ + public static class ActiveDirectory + { + private static readonly Logger Log = LogManager.GetCurrentClassLogger(); + + /// <summary> + /// Get the user email address from ActiveDirectory. + /// </summary> + /// <param name="username">The username.</param> + /// <returns>Email address of AD user, an empty string if not found.</returns> + public static string GetEmailAddress(string username) { + try { + using (var pctx = new PrincipalContext(ContextType.Domain)) { + using (var up = UserPrincipal.FindByIdentity(pctx, username)) { + if (up != null && !string.IsNullOrWhiteSpace(up.EmailAddress)) { + return up.EmailAddress; + } + } + } + } + catch (Exception ex) { + Log.Warn("Can't find email address for {0}: {1}", username, ex.Message); + } + return ""; + } + + /// <summary> + /// Get the full user name (human-friendly) from ActiveDirectory. + /// </summary> + /// <param name="username">The username.</param> + /// <returns>A human-friendly string representation of the user principal.</returns> + public static string GetFullUserName(string username) { + try { + using (var pctx = new PrincipalContext(ContextType.Domain)) { + using (var up = UserPrincipal.FindByIdentity(pctx, username)) { + if (up != null) + return up.GivenName + " " + up.Surname; + } + } + } + catch (Exception ex) { + Log.Warn("Can't find full name for {0}: {1}", username, ex.Message); + } + return ""; + } + } +} diff --git a/ATXCommon/Conv.cs b/ATXCommon/Conv.cs new file mode 100644 index 0000000000000000000000000000000000000000..b0516aa7de96a3d6d7dd32b62203ec4d8fd2e8a8 --- /dev/null +++ b/ATXCommon/Conv.cs @@ -0,0 +1,22 @@ +namespace ATXCommon +{ + public static class Conv + { + public const int MegaBytes = 1024 * 1024; + + /// <summary> + /// Convert bytes into a human-readable string with the appropriate suffix (up to TB). + /// </summary> + /// <param name="numBytes">The number of bytes.</param> + /// <returns>A formatted string with the size showing one decimal.</returns> + public static string BytesToString(long numBytes) { + string[] suffixes = {"Bytes", "KB", "MB", "GB", "TB"}; + var order = 0; + while (numBytes >= 1024 && order < suffixes.Length - 1) { + order++; + numBytes /= 1024; + } + return string.Format("{0:0.#} {1}", numBytes, suffixes[order]); + } + } +} diff --git a/ATXCommon/FsUtils.cs b/ATXCommon/FsUtils.cs new file mode 100644 index 0000000000000000000000000000000000000000..a9eb50bfdcd764b92273e1986df3bd4d44951efa --- /dev/null +++ b/ATXCommon/FsUtils.cs @@ -0,0 +1,281 @@ +using System; +using System.Collections.Generic; +using System.Globalization; +using System.IO; +using System.Linq; +using NLog; + +namespace ATXCommon +{ + public static class FsUtils + { + private static readonly Logger Log = LogManager.GetCurrentClassLogger(); + + /// <summary> + /// Create a directory with the given name if it doesn't exist yet, otherwise + /// (optionally) create a new one using a date suffix to distinguish it from + /// the existing one. + /// </summary> + /// <param name="dirPath">The full path of the directory to be created.</param> + /// <param name="unique">Add a time-suffix to the name if the directory exists.</param> + /// <returns>The name of the (created or pre-existing) directory. This will only + /// differ from the input parameter "dirPath" if the "unique" parameter is set + /// to true (then it will give the newly generated name) or if an error occured + /// (in which case it will return an empty string).</returns> + public static string CreateNewDirectory(string dirPath, bool unique) { + try { + if (Directory.Exists(dirPath)) { + // if unique was not requested, return the name of the existing dir: + if (unique == false) + return dirPath; + + dirPath = dirPath + "_" + TimeUtils.Timestamp(); + } + Directory.CreateDirectory(dirPath); + Log.Debug("Created directory: [{0}]", dirPath); + return dirPath; + } + catch (Exception ex) { + Log.Error("Error in CreateNewDirectory({0}): {1}", dirPath, ex.Message); + } + return ""; + } + + /// <summary> + /// Helper method to check if a directory exists, trying to create it if not. + /// </summary> + /// <param name="path">The full path of the directory to check / create.</param> + /// <returns>True if existing or creation was successful, false otherwise.</returns> + public static bool CheckForDirectory(string path) { + if (string.IsNullOrWhiteSpace(path)) { + Log.Error("ERROR: CheckForDirectory() parameter must not be empty!"); + return false; + } + return FsUtils.CreateNewDirectory(path, false) == path; + } + + /// <summary> + /// Recursively sum up size of all files under a given path. + /// </summary> + /// <param name="path">Full path of the directory.</param> + /// <returns>The total size in bytes.</returns> + public static long GetDirectorySize(string path) { + return new DirectoryInfo(path) + .GetFiles("*", SearchOption.AllDirectories) + .Sum(file => file.Length); + } + + /// <summary> + /// Convert the timestamp given by the NAME of a directory into the age in days. + /// </summary> + /// <param name="dir">The DirectoryInfo object to check for its name-age.</param> + /// <param name="baseTime">The DateTime object to compare to.</param> + /// <returns>The age in days, or -1 in case of an error.</returns> + public static int DirNameToAge(DirectoryInfo dir, DateTime baseTime) { + DateTime dirTimestamp; + try { + dirTimestamp = DateTime.ParseExact(dir.Name, "yyyy-MM-dd__HH-mm-ss", + CultureInfo.InvariantCulture); + } + catch (Exception ex) { + // TODO: discuss if this should be an "Error" message to trigger a mail + // notification to the AdminDebug address: + Log.Warn("Unable to parse time from name [{0}], skipping: {1}", + dir.Name, ex.Message); + return -1; + } + return (baseTime - dirTimestamp).Days; + } + + /// <summary> + /// Assemble a dictionary with information about expired directories. + /// </summary> + /// <param name="baseDir">The base directory to scan for subdirectories.</param> + /// <param name="thresh">The number of days used as expiration threshold.</param> + /// <returns>A dictionary having usernames as keys (of those users that actually do have + /// expired directories), where the values are lists of tuples with the DirInfo objects, + /// size (in bytes) and age (in days) of the expired directories.</returns> + public static Dictionary<string, List<Tuple<DirectoryInfo, long, int>>> + ExpiredDirs(DirectoryInfo baseDir,int thresh) { + + var collection = new Dictionary<string, List<Tuple<DirectoryInfo, long, int>>>(); + var now = DateTime.Now; + foreach (var userdir in baseDir.GetDirectories()) { + var expired = new List<Tuple<DirectoryInfo, long, int>>(); + foreach (var subdir in userdir.GetDirectories()) { + var age = DirNameToAge(subdir, now); + if (age < thresh) + continue; + long size = -1; + try { + size = GetDirectorySize(subdir.FullName); + } + catch (Exception ex) { + Log.Error("ERROR getting directory size of [{0}]: {1}", + subdir.FullName, ex.Message); + } + expired.Add(new Tuple<DirectoryInfo, long, int>(subdir, size, age)); + } + if (expired.Count > 0) + collection.Add(userdir.Name, expired); + } + return collection; + } + + /// <summary> + /// Generate a report on expired folders in the grace location. + /// + /// Check all user-directories in the grace location for subdirectories whose timestamp + /// (the directory name) exceeds the configured grace period and generate a summary + /// containing the age and size of those directories. + /// </summary> + /// <param name="graceLocation">The location to scan for expired folders.</param> + /// <param name="threshold">The number of days used as expiration threshold.</param> + public static string GraceLocationSummary(DirectoryInfo graceLocation, int threshold) { + var expired = ExpiredDirs(graceLocation, threshold); + var report = ""; + foreach (var userdir in expired.Keys) { + report += "\n - user '" + userdir + "'\n"; + foreach (var subdir in expired[userdir]) { + report += string.Format(" - {0} [age: {2}, size: {1}]\n", + subdir.Item1, Conv.BytesToString(subdir.Item2), + TimeUtils.DaysToHuman(subdir.Item3)); + } + } + if (string.IsNullOrEmpty(report)) + return ""; + + return "Expired folders in grace location:\n" + report; + } + + /// <summary> + /// Check if a given directory is empty. If a marker file is set in the config a + /// file with this name will be created inside the given directory and will be + /// skipped itself when checking for files and directories. + /// </summary> + /// <param name="dirInfo">The directory to check.</param> + /// <param name="ignoredName">A filename that will be ignored.</param> + /// <returns>True if access is denied or the dir is empty, false otherwise.</returns> + public static bool DirEmptyExcept(DirectoryInfo dirInfo, string ignoredName) { + try { + var filesInTree = dirInfo.GetFiles("*", SearchOption.AllDirectories); + if (string.IsNullOrEmpty(ignoredName)) + return filesInTree.Length == 0; + + // check if there is ONLY the marker file: + if (filesInTree.Length == 1 && + filesInTree[0].Name.Equals(ignoredName)) + return true; + + // make sure the marker file is there: + var markerFilePath = Path.Combine(dirInfo.FullName, ignoredName); + if (!File.Exists(markerFilePath)) + File.Create(markerFilePath); + + return filesInTree.Length == 0; + } + catch (Exception e) { + Log.Error("Error accessing directories: {0}", e.Message); + } + // if nothing triggered before, we pretend the dir is empty: + return true; + } + + /// <summary> + /// Collect individual files in the root of a given directory tree in a specific + /// sub-directory. A file name given as "ignoredName" will be skipped in the checks. + /// </summary> + /// <param name="userDir">The user directory to check for individual files.</param> + /// <param name="ignoredName">A filename that will be ignored.</param> + public static void CollectOrphanedFiles(DirectoryInfo userDir, string ignoredName) { + var fileList = userDir.GetFiles(); + var orphanedDir = Path.Combine(userDir.FullName, "orphaned"); + try { + if (fileList.Length > 1 || + (string.IsNullOrEmpty(ignoredName) && fileList.Length > 0)) { + if (Directory.Exists(orphanedDir)) { + Log.Info("Orphaned directory already exists, skipping individual files."); + return; + } + Log.Debug("Found individual files, collecting them in 'orphaned' folder."); + CreateNewDirectory(orphanedDir, false); + } + foreach (var file in fileList) { + if (file.Name.Equals(ignoredName)) + continue; + Log.Debug("Collecting orphan: [{0}]", file.Name); + file.MoveTo(Path.Combine(orphanedDir, file.Name)); + } + } + catch (Exception ex) { + Log.Error("Error collecting orphaned files: {0}\n{1}", ex.Message, ex.StackTrace); + } + } + + /// <summary> + /// Ensure the required spooling directories (managed/incoming) exist. + /// </summary> + /// <param name="incoming">The path to the incoming location.</param> + /// <param name="managed">The path to the managed location.</param> + /// <returns>True if all dirs exist or were created successfully.</returns> + public static bool CheckSpoolingDirectories(string incoming, string managed) { + var retval = CheckForDirectory(incoming); + retval &= CheckForDirectory(managed); + retval &= CheckForDirectory(Path.Combine(managed, "PROCESSING")); + retval &= CheckForDirectory(Path.Combine(managed, "DONE")); + retval &= CheckForDirectory(Path.Combine(managed, "UNMATCHED")); + return retval; + } + + /// <summary> + /// Move all subdirectories of a given path into a destination directory. The destination + /// will be created if it doesn't exist yet. If a subdirectory of the same name already + /// exists in the destination, a timestamp-suffix is added to the new one. + /// </summary> + /// <param name="sourceDir">The source path as DirectoryInfo object.</param> + /// <param name="destPath">The destination path as a string.</param> + /// <param name="resetAcls">Whether to reset the ACLs on the moved subdirectories.</param> + /// <returns>True on success, false otherwise.</returns> + public static bool MoveAllSubDirs(DirectoryInfo sourceDir, string destPath, bool resetAcls = false) { + // TODO: check whether _transferState should be adjusted while moving dirs! + Log.Debug("MoveAllSubDirs: [{0}] to [{1}]", sourceDir.FullName, destPath); + try { + // make sure the target directory that should hold all subdirectories to + // be moved is existing: + if (string.IsNullOrEmpty(FsUtils.CreateNewDirectory(destPath, false))) { + Log.Warn("WARNING: destination path doesn't exist: {0}", destPath); + return false; + } + + foreach (var subDir in sourceDir.GetDirectories()) { + var target = Path.Combine(destPath, subDir.Name); + // make sure NOT to overwrite the subdirectories: + if (Directory.Exists(target)) + target += "_" + TimeUtils.Timestamp(); + Log.Debug(" - [{0}] > [{1}]", subDir.Name, target); + subDir.MoveTo(target); + + if (!resetAcls) + continue; + + try { + var acl = Directory.GetAccessControl(target); + acl.SetAccessRuleProtection(false, false); + Directory.SetAccessControl(target, acl); + Log.Debug("Successfully reset inherited ACLs on [{0}]", target); + } + catch (Exception ex) { + Log.Error("Error resetting inherited ACLs on [{0}]:\n{1}", + target, ex.Message); + } + } + } + catch (Exception ex) { + Log.Error("Error moving directories: [{0}] > [{1}]\n{2}", + sourceDir.FullName, destPath, ex.Message); + return false; + } + return true; + } + } +} diff --git a/ATXCommon/NLog/RateLimitWrapper.cs b/ATXCommon/NLog/RateLimitWrapper.cs new file mode 100644 index 0000000000000000000000000000000000000000..b86dded2b94356dc2911d1696277da9074f28f22 --- /dev/null +++ b/ATXCommon/NLog/RateLimitWrapper.cs @@ -0,0 +1,34 @@ +using System; +using System.ComponentModel; +using NLog.Common; +using NLog.Targets; +using NLog.Targets.Wrappers; + +namespace ATXCommon.NLog +{ + /// <summary> + /// A wrapper target for NLog, limiting the rate of messages being logged. + /// + /// Meant to be used in conjunction with the MailTarget class, to avoid flooding the recipient + /// with too many emails and probably being banned by the SMTP server for spamming. + /// NOTE: should always be used in combination with another target (FileTarget) to ensure that + /// all messages are being logged, including those ones discarded by *this* target. + /// </summary> + [Target("FrequencyWrapper", IsWrapper = true)] + public class RateLimitWrapper : WrapperTargetBase + { + private DateTime _lastLogEvent = DateTime.MinValue; + + protected override void Write(AsyncLogEventInfo logEvent) { + if ((DateTime.Now - _lastLogEvent).TotalMinutes >= MinLogInterval) { + _lastLogEvent = DateTime.Now; + WrappedTarget.WriteAsyncLogEvent(logEvent); + } else { + logEvent.Continuation(null); + } + } + + [DefaultValue(30)] + public int MinLogInterval { get; set; } + } +} diff --git a/ATXSerializables/Properties/AssemblyInfo.cs b/ATXCommon/Properties/AssemblyInfo.cs similarity index 90% rename from ATXSerializables/Properties/AssemblyInfo.cs rename to ATXCommon/Properties/AssemblyInfo.cs index 3a2d27ee401fca56259fa9f20ac24763690f4a4c..6018b416f9f2a38309c6e2ab44e2fd2644885658 100644 --- a/ATXSerializables/Properties/AssemblyInfo.cs +++ b/ATXCommon/Properties/AssemblyInfo.cs @@ -5,11 +5,11 @@ using System.Runtime.InteropServices; // General Information about an assembly is controlled through the following // set of attributes. Change these attribute values to modify the information // associated with an assembly. -[assembly: AssemblyTitle("ATXSerializables")] -[assembly: AssemblyDescription("")] +[assembly: AssemblyTitle("ATXCommon")] +[assembly: AssemblyDescription("AutoTx Common Runtime Libraries")] [assembly: AssemblyConfiguration("")] [assembly: AssemblyCompany("Universitaet Basel")] -[assembly: AssemblyProduct("ATXSerializables")] +[assembly: AssemblyProduct("AutoTx")] [assembly: AssemblyCopyright("Copyright © Universitaet Basel 2018")] [assembly: AssemblyTrademark("")] [assembly: AssemblyCulture("")] diff --git a/ATXSerializables/Serializables/DriveToCheck.cs b/ATXCommon/Serializables/DriveToCheck.cs similarity index 51% rename from ATXSerializables/Serializables/DriveToCheck.cs rename to ATXCommon/Serializables/DriveToCheck.cs index 35a0242343bca5da9695bdb907eb5e117ebd7819..553f4750f543c43b19c4b4625e468daa217b2a19 100644 --- a/ATXSerializables/Serializables/DriveToCheck.cs +++ b/ATXCommon/Serializables/DriveToCheck.cs @@ -7,11 +7,16 @@ namespace ATXCommon.Serializables /// </summary> public class DriveToCheck { + /// <summary> + /// A drive name (single letter followed by a colon, e.g. "D:") to be monitored for space. + /// </summary> [XmlElement("DriveName")] public string DriveName { get; set; } - // the value is to be compared to System.IO.DriveInfo.TotalFreeSpace - // hence we use the same type (long) to avoid unnecessary casts later: + /// <summary> + /// Limit (in MB) of free space, lower values will trigger a notification. + /// </summary> + /// Value is to be compared to DriveInfo.TotalFreeSpace, hence the same type (long). [XmlElement("SpaceThreshold")] public long SpaceThreshold { get; set; } } diff --git a/ATXSerializables/Serializables/ServiceConfig.cs b/ATXCommon/Serializables/ServiceConfig.cs similarity index 59% rename from ATXSerializables/Serializables/ServiceConfig.cs rename to ATXCommon/Serializables/ServiceConfig.cs index 9f5e635c53a3fc2e1da3ccfd686c06ad9a693fb0..bb2a06605a9b2f6415fe96c01a6f3704961a7807 100644 --- a/ATXSerializables/Serializables/ServiceConfig.cs +++ b/ATXCommon/Serializables/ServiceConfig.cs @@ -3,19 +3,19 @@ using System.Collections.Generic; using System.Configuration; using System.IO; using System.Xml.Serialization; +using NLog; namespace ATXCommon.Serializables { /// <summary> - /// configuration class based on xml + /// AutoTx service configuration class. /// </summary> [Serializable] public class ServiceConfig { - [XmlIgnore] public string ValidationWarnings; + [XmlIgnore] private static readonly Logger Log = LogManager.GetCurrentClassLogger(); public ServiceConfig() { - ValidationWarnings = ""; // set values for the optional XML elements: SmtpHost = ""; SmtpPort = 25; @@ -76,13 +76,35 @@ namespace ATXCommon.Serializables /// </summary> public string TmpTransferDir { get; set; } + /// <summary> + /// The email address to be used as "From:" when sending mail notifications. + /// </summary> public string EmailFrom { get; set; } + /// <summary> + /// The interval (in ms) for checking for new files and system parameters. + /// </summary> public int ServiceTimer { get; set; } + /// <summary> + /// Maximum allowed CPU usage across all cores in percent. Running transfers will be paused + /// if this limit is exceeded. + /// </summary> public int MaxCpuUsage { get; set; } + + /// <summary> + /// Minimum amount of free RAM (in MB) required for the service to operate. + /// </summary> public int MinAvailableMemory { get; set; } + + /// <summary> + /// Minimum amount of time in minutes between two mail notifications to the admin address. + /// </summary> public int AdminNotificationDelta { get; set; } + + /// <summary> + /// Minimum amount of time in minutes between two low-storage-space notifications. + /// </summary> public int StorageNotificationDelta { get; set; } /// <summary> @@ -91,8 +113,19 @@ namespace ATXCommon.Serializables /// </summary> public int GracePeriod { get; set; } + /// <summary> + /// Flag whether to send explicit mail notifications to the admin on selected events. + /// </summary> public bool SendAdminNotification { get; set; } + + /// <summary> + /// Flag whether to send a mail notification to the user upon completed transfers. + /// </summary> public bool SendTransferNotification { get; set; } + + /// <summary> + /// Switch on debug log messages. + /// </summary> public bool Debug { get; set; } [XmlArray] @@ -108,17 +141,52 @@ namespace ATXCommon.Serializables #region optional configuration parameters + /// <summary> + /// SMTP server used to send mails (if configured) and Fatal/Error log messages. + /// + /// No mails will be sent if this is omitted. + /// </summary> public string SmtpHost { get; set; } + + /// <summary> + /// SMTP username to authenticate when sending emails (if required). + /// </summary> public string SmtpUserCredential { get; set; } + + /// <summary> + /// SMTP password to authenticate when sending emails (if required). + /// </summary> public string SmtpPasswortCredential { get; set; } + + /// <summary> + /// SMTP port for sending emails (25 will be used if this entry is omitted). + /// </summary> public int SmtpPort { get; set; } + /// <summary> + /// A string to be added as a prefix to the subject when sending emails. + /// </summary> public string EmailPrefix { get; set; } + + /// <summary> + /// The mail recipient address for admin notifications (including "Fatal" log messages). + /// </summary> public string AdminEmailAdress { get; set; } + + /// <summary> + /// The mail recipient address for debug notifications (including "Error" log messages). + /// </summary> public string AdminDebugEmailAdress { get; set; } + /// <summary> + /// Minimum time in minutes between two mails about expired folders in the grace location. + /// </summary> public int GraceNotificationDelta { get; set; } + /// <summary> + /// RoboCopy parameter for limiting the bandwidth (mostly for testing purposes). + /// </summary> + /// See the RoboCopy documentation for more details. public int InterPacketGap { get; set; } /// <summary> @@ -129,6 +197,51 @@ namespace ATXCommon.Serializables #endregion + + #region wrappers for derived parameters + + /// <summary> + /// The full path to the incoming directory. + /// </summary> + [XmlIgnore] + public string IncomingPath { + get { return Path.Combine(SourceDrive, IncomingDirectory); } + } + + /// <summary> + /// The full path to the managed directory. + /// </summary> + [XmlIgnore] + public string ManagedPath { + get { return Path.Combine(SourceDrive, ManagedDirectory); } + } + + /// <summary> + /// The full path to the processing directory. + /// </summary> + [XmlIgnore] + public string ProcessingPath { + get { return Path.Combine(ManagedPath, "PROCESSING"); } + } + + /// <summary> + /// The full path to the done directory / grace location. + /// </summary> + [XmlIgnore] + public string DonePath { + get { return Path.Combine(ManagedPath, "DONE"); } + } + + /// <summary> + /// The full path to the directory for unmatched user directories. + /// </summary> + [XmlIgnore] + public string UnmatchedPath { + get { return Path.Combine(ManagedPath, "UNMATCHED"); } + } + + #endregion + public static void Serialize(string file, ServiceConfig c) { // the config is never meant to be written by us, therefore: @@ -136,14 +249,20 @@ namespace ATXCommon.Serializables } public static ServiceConfig Deserialize(string file) { + Log.Debug("Trying to read service configuration XML file: [{0}]", file); var xs = new XmlSerializer(typeof(ServiceConfig)); var reader = File.OpenText(file); var config = (ServiceConfig) xs.Deserialize(reader); reader.Close(); ValidateConfiguration(config); + Log.Debug("Finished deserializing service configuration XML file."); return config; } + + /// <summary> + /// Validate the configuration, throwing exceptions on invalid parameters. + /// </summary> private static void ValidateConfiguration(ServiceConfig c) { if (string.IsNullOrEmpty(c.SourceDrive) || string.IsNullOrEmpty(c.IncomingDirectory) || @@ -179,12 +298,23 @@ namespace ATXCommon.Serializables throw new ConfigurationErrorsException("ServiceTimer must not be smaller than 1000 ms!"); - // NON-CRITICAL stuff just adds messages to ValidationWarnings: - // DestinationDirectory - if (!c.DestinationDirectory.StartsWith(@"\\")) - c.ValidationWarnings += " - <DestinationDirectory> is not a UNC path!\n"; + // NON-CRITICAL stuff is simply reported to the logs: + if (!c.DestinationDirectory.StartsWith(@"\\")) { + ReportNonOptimal("DestinationDirectory", c.DestinationDirectory, "is not a UNC path!"); + } } + /// <summary> + /// Print a standardized msg about a non-optimal configuration setting to the log. + /// </summary> + private static void ReportNonOptimal(string attribute, string value, string msg) { + Log.Warn(">>> Non-optimal setting detected: <{0}> [{1}] {2}", attribute, value, msg); + } + + /// <summary> + /// Generate a human-readable sumary of the current configuration. + /// </summary> + /// <returns>A string with details on the configuration.</returns> public string Summary() { var msg = "HostAlias: " + HostAlias + "\n" + @@ -192,20 +322,23 @@ namespace ATXCommon.Serializables "IncomingDirectory: " + IncomingDirectory + "\n" + "MarkerFile: " + MarkerFile + "\n" + "ManagedDirectory: " + ManagedDirectory + "\n" + - "GracePeriod: " + GracePeriod + "\n" + + "GracePeriod: " + GracePeriod + " (" + + TimeUtils.DaysToHuman(GracePeriod) + ")\n" + "DestinationDirectory: " + DestinationDirectory + "\n" + "TmpTransferDir: " + TmpTransferDir + "\n" + "EnforceInheritedACLs: " + EnforceInheritedACLs + "\n" + - "ServiceTimer: " + ServiceTimer + "\n" + + "ServiceTimer: " + ServiceTimer + " ms\n" + "InterPacketGap: " + InterPacketGap + "\n" + - "MaxCpuUsage: " + MaxCpuUsage + "\n" + + "MaxCpuUsage: " + MaxCpuUsage + "%\n" + "MinAvailableMemory: " + MinAvailableMemory + "\n"; foreach (var processName in BlacklistedProcesses) { msg += "BlacklistedProcess: " + processName + "\n"; } foreach (var driveToCheck in SpaceMonitoring) { msg += "Drive to check free space: " + driveToCheck.DriveName + - " (threshold: " + driveToCheck.SpaceThreshold + ")" + "\n"; + " (threshold: " + + Conv.BytesToString(driveToCheck.SpaceThreshold * Conv.MegaBytes) + + ")" + "\n"; } if (string.IsNullOrEmpty(SmtpHost)) { msg += "SmtpHost: ====== Not configured, disabling email! ======" + "\n"; @@ -215,9 +348,12 @@ namespace ATXCommon.Serializables "EmailFrom: " + EmailFrom + "\n" + "AdminEmailAdress: " + AdminEmailAdress + "\n" + "AdminDebugEmailAdress: " + AdminDebugEmailAdress + "\n" + - "StorageNotificationDelta: " + StorageNotificationDelta + "\n" + - "AdminNotificationDelta: " + AdminNotificationDelta + "\n" + - "GraceNotificationDelta: " + GraceNotificationDelta + "\n"; + "StorageNotificationDelta: " + StorageNotificationDelta + " (" + + TimeUtils.MinutesToHuman(StorageNotificationDelta) + ")\n" + + "AdminNotificationDelta: " + AdminNotificationDelta + " (" + + TimeUtils.MinutesToHuman(AdminNotificationDelta) + ")\n" + + "GraceNotificationDelta: " + GraceNotificationDelta + " (" + + TimeUtils.MinutesToHuman(GraceNotificationDelta) + ")\n"; } return msg; } diff --git a/ATXSerializables/Serializables/ServiceStatus.cs b/ATXCommon/Serializables/ServiceStatus.cs similarity index 54% rename from ATXSerializables/Serializables/ServiceStatus.cs rename to ATXCommon/Serializables/ServiceStatus.cs index 9d88b50b0949fa34673462e0f87441e5aaa2229d..cda77dedafa0321f9eb40fad5127887081543733 100644 --- a/ATXSerializables/Serializables/ServiceStatus.cs +++ b/ATXCommon/Serializables/ServiceStatus.cs @@ -1,15 +1,19 @@ using System; using System.IO; using System.Xml.Serialization; +using NLog; namespace ATXCommon.Serializables { + /// <summary> + /// AutoTx service status class. + /// </summary> [Serializable] public class ServiceStatus { - [XmlIgnore] string _storageFile; // remember where we came from + [XmlIgnore] private string _storageFile; // remember where we came from [XmlIgnore] private ServiceConfig _config; - [XmlIgnore] public string ValidationWarnings; + [XmlIgnore] private static readonly Logger Log = LogManager.GetCurrentClassLogger(); private DateTime _lastStatusUpdate; private DateTime _lastStorageNotification; @@ -17,21 +21,93 @@ namespace ATXCommon.Serializables private DateTime _lastGraceNotification; private string _limitReason; - string _currentTransferSrc; - string _currentTargetTmp; + private string _currentTransferSrc; + private string _currentTargetTmp; - bool _transferInProgress; + private bool _transferInProgress; private bool _serviceSuspended; private bool _cleanShutdown; private long _currentTransferSize; + + #region constructor, serializer and deserializer + + /// <summary> + /// The constructor, setting default values. + /// </summary> + public ServiceStatus() { + _currentTransferSrc = ""; + _currentTargetTmp = ""; + _transferInProgress = false; + } + + public void Serialize() { + /* During de-serialization, the setter methods get called as well but + * we should not serialize until the deserialization has completed. + * As the storage file name will only be set after this, it is sufficient + * to test for this (plus, we can't serialize anyway without it). + */ + if (_storageFile == null) { + Log.Trace("File name for XML serialization is not set, doing nothing!"); + return; + } + Log.Trace("Serializing status..."); + // update the timestamp: + LastStatusUpdate = DateTime.Now; + try { + var xs = new XmlSerializer(GetType()); + var writer = File.CreateText(_storageFile); + xs.Serialize(writer, this); + writer.Flush(); + writer.Close(); + } + catch (Exception ex) { + Log.Error("Error in Serialize(): {0}", ex.Message); + } + Log.Trace("Finished serializing [{0}].", _storageFile); + } + + public static ServiceStatus Deserialize(string file, ServiceConfig config) { + Log.Trace("Trying to deserialize status XML file [{0}].", file); + ServiceStatus status; + + var xs = new XmlSerializer(typeof(ServiceStatus)); + try { + var reader = File.OpenText(file); + status = (ServiceStatus) xs.Deserialize(reader); + reader.Close(); + Log.Trace("Finished deserializing service status XML file."); + } + catch (Exception) { + // if reading the status XML fails, we return an empty (new) one + status = new ServiceStatus(); + Log.Warn("Deserializing [{0}] failed, creating new status using defauls.", file); + } + status._config = config; + ValidateStatus(status); + // now set the storage filename: + status._storageFile = file; + return status; + } + + #endregion constructor, serializer and deserializer + + + #region getter / setter methods + + /// <summary> + /// Timestamp indicating when the status has been updated last ("heartbeat"). + /// </summary> [XmlElement("LastStatusUpdate", DataType = "dateTime")] public DateTime LastStatusUpdate { get { return _lastStatusUpdate; } set { _lastStatusUpdate = value; } } + /// <summary> + /// Timestamp indicating when the last storage notification has been sent. + /// </summary> [XmlElement("LastStorageNotification", DataType = "dateTime")] public DateTime LastStorageNotification { get { return _lastStorageNotification; } @@ -41,6 +117,9 @@ namespace ATXCommon.Serializables } } + /// <summary> + /// Timestamp indicating when the last admin notification has been sent. + /// </summary> [XmlElement("LastAdminNotification", DataType = "dateTime")] public DateTime LastAdminNotification { get { return _lastAdminNotification; } @@ -50,6 +129,9 @@ namespace ATXCommon.Serializables } } + /// <summary> + /// Timestamp indicating when the last notification on expired folders has been sent. + /// </summary> [XmlElement("LastGraceNotification", DataType = "dateTime")] public DateTime LastGraceNotification { get { return _lastGraceNotification; } @@ -59,47 +141,64 @@ namespace ATXCommon.Serializables } } + /// <summary> + /// String indicating why the service is currently suspended (empty if not suspended). + /// </summary> public string LimitReason { get { return _limitReason; } set { _limitReason = value; - // log("LimitReason was updated (" + value + "), calling Serialize()..."); + Log.Trace("LimitReason was updated ({0}).", value); Serialize(); } } + /// <summary> + /// The full path to the folder currently being transferred. + /// </summary> public string CurrentTransferSrc { get { return _currentTransferSrc; } set { _currentTransferSrc = value; - // log("CurrentTransferSrc was updated (" + value + "), calling Serialize()..."); + Log.Trace("CurrentTransferSrc was updated ({0}).", value); Serialize(); } } + /// <summary> + /// The name of the temporary folder being used for the currently running transfer, + /// relative to "DestinationDirectory\TmpTransferDir" (i.e. the target username). See also + /// <seealso cref="CurrentTargetTmpFull"/> on details for assembling the full path. + /// </summary> public string CurrentTargetTmp { get { return _currentTargetTmp; } set { _currentTargetTmp = value; - // log("CurrentTargetTmp was updated (" + value + "), calling Serialize()..."); + Log.Trace("CurrentTargetTmp was updated ({0}).", value); Serialize(); } } + /// <summary> + /// Flag indicating whether the service is currently suspended. + /// </summary> public bool ServiceSuspended { get { return _serviceSuspended; } set { _serviceSuspended = value; - // log("ServiceSuspended was updated (" + value + "), calling Serialize()..."); + Log.Trace("ServiceSuspended was updated ({0}).", value); Serialize(); } } + /// <summary> + /// Flag indicating whether a transfer is currently running. + /// </summary> public bool TransferInProgress { get { return _transferInProgress; } set { _transferInProgress = value; - // log("FilecopyFinished was updated (" + value + "), calling Serialize()..."); + Log.Trace("FilecopyFinished was updated ({0}).", value); Serialize(); } } @@ -115,98 +214,68 @@ namespace ATXCommon.Serializables } } + /// <summary> + /// The full size of the current transfer in bytes. + /// </summary> public long CurrentTransferSize { get { return _currentTransferSize; } set { _currentTransferSize = value; - // log("CurrentTransferSize was updated (" + value + "), calling Serialize()..."); + Log.Trace("CurrentTransferSize was updated ({0}).", value); Serialize(); } } - public ServiceStatus() { - _currentTransferSrc = ""; - _currentTargetTmp = ""; - _transferInProgress = false; - } - - public void Serialize() { - /* During de-serialization, the setter methods get called as well but - * we should not serialize until the deserialization has completed. - * As the storage file name will only be set after this, it is sufficient - * to test for this (plus, we can't serialize anyway without it). - */ - if (_storageFile == null) { - // log("File name for XML serialization is not set, doing nothing."); - return; - } - // update the timestamp: - LastStatusUpdate = DateTime.Now; - try { - var xs = new XmlSerializer(GetType()); - var writer = File.CreateText(_storageFile); - xs.Serialize(writer, this); - writer.Flush(); - writer.Close(); - } - catch (Exception ex) { - log("Error in Serialize(): " + ex.Message); - } - log("Finished serializing " + _storageFile); - } + #endregion getter / setter methods + - static void log(string message) { - // use Console.WriteLine until proper logging is there (running as a system - // service means those messages will disappear): - Console.WriteLine(message); - /* - using (var sw = File.AppendText(@"C:\Tools\AutoTx\console.log")) { - sw.WriteLine(message); - } - */ + /// <summary> + /// Helper method to generate the full path of the current temp directory. + /// </summary> + /// <returns>A string with the path to the last tmp dir.</returns> + public string CurrentTargetTmpFull() { + return Path.Combine(_config.DestinationDirectory, + _config.TmpTransferDir, + _currentTargetTmp); } + - public static ServiceStatus Deserialize(string file, ServiceConfig config) { - ServiceStatus status; - - var xs = new XmlSerializer(typeof(ServiceStatus)); - try { - var reader = File.OpenText(file); - status = (ServiceStatus) xs.Deserialize(reader); - reader.Close(); - } - catch (Exception) { - // if reading the status XML fails, we return an empty (new) one - status = new ServiceStatus(); - } - status._config = config; - ValidateStatus(status); - // now set the storage filename: - status._storageFile = file; - return status; - } + #region validate and report + /// <summary> + /// Validate the status and reset attributes with invalid values. + /// </summary> private static void ValidateStatus(ServiceStatus s) { // CurrentTransferSrc if (s.CurrentTransferSrc.Length > 0 && !Directory.Exists(s.CurrentTransferSrc)) { - s.ValidationWarnings += " - found non-existing source path of an unfinished " + - "transfer: " + s.CurrentTransferSrc + "\n"; + ReportInvalidStatus("CurrentTransferSrc", s.CurrentTransferSrc, + "invalid transfer source path"); s.CurrentTransferSrc = ""; } // CurrentTargetTmp - var currentTargetTmpPath = Path.Combine(s._config.DestinationDirectory, - s._config.TmpTransferDir, - s.CurrentTargetTmp); + var currentTargetTmpPath = s.CurrentTargetTmpFull(); if (s.CurrentTargetTmp.Length > 0 && !Directory.Exists(currentTargetTmpPath)) { - s.ValidationWarnings += " - found non-existing temporary path of an " + - "unfinished transfer: " + currentTargetTmpPath + "\n"; + ReportInvalidStatus("CurrentTargetTmpPath", currentTargetTmpPath, + "invalid temporary path of an unfinished transfer"); s.CurrentTargetTmp = ""; } } + /// <summary> + /// Print a standardized msg about an invalid status attribute to the log. + /// </summary> + private static void ReportInvalidStatus(string attribute, string value, string msg) { + Log.Warn(">>> Invalid status parameter detected, resetting:\n - <{0}> [{1}] {2}.", + attribute, value, msg); + } + + /// <summary> + /// Generate a human-readable sumary of the current transfer. + /// </summary> + /// <returns>A string with details on the transfer.</returns> public string Summary() { return "CurrentTransferSrc: " + CurrentTransferSrc + "\n" + @@ -214,13 +283,23 @@ namespace ATXCommon.Serializables "TransferInProgress: " + TransferInProgress + "\n" + "CurrentTransferSize: " + CurrentTransferSize + "\n" + "LastStatusUpdate: " + - LastStatusUpdate.ToString("yyyy-MM-dd HH:mm:ss") + "\n" + + LastStatusUpdate.ToString("yyyy-MM-dd HH:mm:ss") + " (" + + TimeUtils.SecondsToHuman(TimeUtils.SecondsSince(LastStatusUpdate)) + + " ago)\n" + "LastStorageNotification: " + - LastStorageNotification.ToString("yyyy-MM-dd HH:mm:ss") + "\n" + + LastStorageNotification.ToString("yyyy-MM-dd HH:mm:ss") + " (" + + TimeUtils.SecondsToHuman(TimeUtils.SecondsSince(LastStorageNotification)) + + " ago)\n" + "LastAdminNotification: " + - LastAdminNotification.ToString("yyyy-MM-dd HH:mm:ss") + "\n" + + LastAdminNotification.ToString("yyyy-MM-dd HH:mm:ss") + " (" + + TimeUtils.SecondsToHuman(TimeUtils.SecondsSince(LastAdminNotification)) + + " ago)\n" + "LastGraceNotification: " + - LastGraceNotification.ToString("yyyy-MM-dd HH:mm:ss") + "\n"; + LastGraceNotification.ToString("yyyy-MM-dd HH:mm:ss") + " (" + + TimeUtils.SecondsToHuman(TimeUtils.SecondsSince(LastGraceNotification)) + + " ago)\n"; } + + #endregion validate and report } } diff --git a/ATXCommon/SystemChecks.cs b/ATXCommon/SystemChecks.cs new file mode 100644 index 0000000000000000000000000000000000000000..b3832f5d5fd7fd83081bdc39cf7b288be8c91c8b --- /dev/null +++ b/ATXCommon/SystemChecks.cs @@ -0,0 +1,133 @@ +using System; +using System.Collections.Generic; +using System.Diagnostics; +using System.IO; +using System.Linq; +using System.Management; +using NLog; + +namespace ATXCommon +{ + public static class SystemChecks + { + private static readonly Logger Log = LogManager.GetCurrentClassLogger(); + + /// <summary> + /// Get the available physical memory in MB. + /// </summary> + /// <returns>The available physical memory in MB or -1 in case of an error.</returns> + public static long GetFreeMemory() { + try { + var searcher = + new ManagementObjectSearcher("SELECT * FROM Win32_OperatingSystem"); + foreach (var mo in searcher.Get()) { + var queryObj = (ManagementObject)mo; + return Convert.ToInt64(queryObj["FreePhysicalMemory"]) / 1024; + } + } + catch (Exception ex) { + Log.Warn("Error in GetFreeMemory: {0}", ex.Message); + } + return -1; + } + + /// <summary> + /// Get the CPU usage in percent over all cores. + /// </summary> + /// <returns>CPU usage in percent or -1 if an error occured.</returns> + public static int GetCpuUsage() { + try { + var searcher = new ManagementObjectSearcher("select * from Win32_PerfFormattedData_PerfOS_Processor"); + foreach (var mo in searcher.Get()) { + var obj = (ManagementObject)mo; + var usage = obj["PercentProcessorTime"]; + var name = obj["Name"]; + if (name.ToString().Equals("_Total")) + return Convert.ToInt32(usage); + } + } + catch (Exception ex) { + Log.Warn("Error in GetCpuUsage: {0}", ex.Message); + } + return -1; + } + + /// <summary> + /// Get the free space of a drive in bytes. + /// </summary> + /// /// <param name="drive">The drive name, e.g. "c:".</param> + /// <returns>Free space of a drive in bytes, zero if an error occured.</returns> + public static long GetFreeDriveSpace(string drive) { + try { + var dInfo = new DriveInfo(drive); + return dInfo.TotalFreeSpace; + } + catch (Exception ex) { + Log.Warn("Error in GetFreeDriveSpace({0}): {1}", drive, ex.Message); + } + return 0; + } + + /// <summary> + /// Check all configured disks for their free space and send a notification + /// if necessary (depending on the configured delta time). + /// </summary> + public static string CheckFreeDiskSpace(List<Serializables.DriveToCheck> drives) { + var msg = ""; + foreach (var driveToCheck in drives) { + var freeSpace = GetFreeDriveSpace(driveToCheck.DriveName); + if (freeSpace >= driveToCheck.SpaceThreshold) + continue; + + msg += "Drive '" + driveToCheck.DriveName + + "' - free space: " + Conv.BytesToString(freeSpace) + + " (threshold: " + Conv.BytesToString(driveToCheck.SpaceThreshold) + ")\n"; + } + return msg; + } + + /// <summary> + /// Compares all processes against the ProcessNames in the BlacklistedProcesses list. + /// </summary> + /// <returns>Returns the name of the first matching process, an empty string otherwise.</returns> + public static string CheckForBlacklistedProcesses(List<string> processNames) { + foreach (var running in Process.GetProcesses()) { + try { + foreach (var blacklisted in processNames) { + if (running.ProcessName.ToLower().Equals(blacklisted)) { + return blacklisted; + } + } + } + catch (Exception ex) { + Log.Warn("Error in checkProcesses(): {0}", ex.Message); + } + } + return ""; + } + + /// <summary> + /// Check if a user is currently logged into Windows. + /// + /// WARNING: this DOES NOT ACCOUNT for users logged in via RDP!! + /// </summary> + /// See https://stackoverflow.com/questions/5218778/ for the RDP problem. + public static bool NoUserIsLoggedOn() { + var username = ""; + try { + var searcher = new ManagementObjectSearcher("SELECT UserName " + + "FROM Win32_ComputerSystem"); + var collection = searcher.Get(); + username = (string)collection.Cast<ManagementBaseObject>().First()["UserName"]; + } + catch (Exception ex) { + // TODO / FIXME: combine log and admin-email! + var msg = string.Format("Error in getCurrentUsername(): {0}", ex.Message); + Log.Error(msg); + // TODO: FIXME! + // SendAdminEmail(msg); + } + return username == ""; + } + } +} diff --git a/ATXCommon/TimeUtils.cs b/ATXCommon/TimeUtils.cs new file mode 100644 index 0000000000000000000000000000000000000000..e334161f08708c8a42e240bbc65064ea6a57e3f7 --- /dev/null +++ b/ATXCommon/TimeUtils.cs @@ -0,0 +1,86 @@ +using System; + +namespace ATXCommon +{ + public static class TimeUtils + { + /// <summary> + /// Helper method to create timestamp strings in a consistent fashion. + /// </summary> + /// <returns>A timestamp string of the current time.</returns> + public static string Timestamp() { + return DateTime.Now.ToString("yyyy-MM-dd__HH-mm-ss"); + } + + /// <summary> + /// Calculate the time delta since the given date in minutes. + /// </summary> + /// <param name="refDate">The reference DateTime to check.</param> + /// <returns>The number of minutes between the reference date and now.</returns> + public static int MinutesSince(DateTime refDate) { + return (int)(DateTime.Now - refDate).TotalMinutes; + } + + /// <summary> + /// Calculate the time delta since the given date in seconds. + /// </summary> + /// <param name="refDate">The reference DateTime to check.</param> + /// <returns>The number of seconds between the reference date and now.</returns> + public static int SecondsSince(DateTime refDate) { + return (int)(DateTime.Now - refDate).TotalSeconds; + } + + /// <summary> + /// Convert a number of seconds to a human readable string. + /// </summary> + /// <param name="delta">The time span in seconds.</param> + /// <returns>A string describing the duration, e.g. "2 hours 34 minutes".</returns> + public static string SecondsToHuman(int delta) { + const int second = 1; + const int minute = second * 60; + const int hour = minute * 60; + const int day = hour * 24; + const int week = day * 7; + + if (delta < minute) + return delta + " seconds"; + + if (delta < 2 * minute) + return "a minute"; + + if (delta < hour) + return delta / minute + " minutes"; + + if (delta < day) { + var hours = delta / hour; + var mins = (delta - hours * hour) / minute; + if (mins > 0) + return hours + " hours " + mins + " minutes"; + return hours + " hours"; + } + + if (delta < 2 * week) + return delta / day + " days"; + + return delta / week + " weeks"; + } + + /// <summary> + /// Wrapper to use <see cref="SecondsToHuman"/> with minutes as input. + /// </summary> + /// <param name="delta">The time span in minutes.</param> + /// <returns>A string describing the duration, e.g. "2 hours 34 minutes".</returns> + public static string MinutesToHuman(int delta) { + return SecondsToHuman(delta * 60); + } + + /// <summary> + /// Wrapper to use <see cref="SecondsToHuman"/> with days as input. + /// </summary> + /// <param name="delta">The time span in days.</param> + /// <returns>A string describing the duration, e.g. "12 days" or "3 weeks".</returns> + public static string DaysToHuman(int delta) { + return MinutesToHuman(delta * 60 * 24); + } + } +} diff --git a/ATXCommon/packages.config b/ATXCommon/packages.config new file mode 100644 index 0000000000000000000000000000000000000000..8e85834c00cf96bfe4c3616778bd12559d331c59 --- /dev/null +++ b/ATXCommon/packages.config @@ -0,0 +1,4 @@ +<?xml version="1.0" encoding="utf-8"?> +<packages> + <package id="NLog" version="4.3.11" targetFramework="net45" /> +</packages> \ No newline at end of file diff --git a/ATXConfigTest/ATXConfigTest.csproj b/ATXConfigTest/ATXConfigTest.csproj index f5d0375002890d60e62c428dc611d562d468454f..08f32fb33144eaa114da6b425dffc80267e0073c 100644 --- a/ATXConfigTest/ATXConfigTest.csproj +++ b/ATXConfigTest/ATXConfigTest.csproj @@ -32,6 +32,10 @@ <WarningLevel>4</WarningLevel> </PropertyGroup> <ItemGroup> + <Reference Include="NLog, Version=4.0.0.0, Culture=neutral, PublicKeyToken=5120e14c03d0593c, processorArchitecture=MSIL"> + <HintPath>..\packages\NLog.4.3.11\lib\net45\NLog.dll</HintPath> + <Private>True</Private> + </Reference> <Reference Include="System" /> <Reference Include="System.Core" /> <Reference Include="System.Xml.Linq" /> @@ -46,9 +50,10 @@ </ItemGroup> <ItemGroup> <None Include="App.config" /> + <None Include="packages.config" /> </ItemGroup> <ItemGroup> - <ProjectReference Include="..\ATXSerializables\ATXCommon.csproj"> + <ProjectReference Include="..\ATXCommon\ATXCommon.csproj"> <Project>{166D65D5-EE10-4364-8AA3-4D86BA5CE244}</Project> <Name>ATXCommon</Name> </ProjectReference> diff --git a/ATXConfigTest/AutoTxConfigTest.cs b/ATXConfigTest/AutoTxConfigTest.cs index 100291fe1785b6e118a2fe5a4e6fb6d84314134d..47af5d81d1400d551c0ed2e88b1315d06b0036c6 100644 --- a/ATXConfigTest/AutoTxConfigTest.cs +++ b/ATXConfigTest/AutoTxConfigTest.cs @@ -1,5 +1,7 @@ using System; using System.IO; +using NLog; +using NLog.Config; using ATXCommon.Serializables; namespace ATXConfigTest diff --git a/ATXConfigTest/packages.config b/ATXConfigTest/packages.config new file mode 100644 index 0000000000000000000000000000000000000000..8e85834c00cf96bfe4c3616778bd12559d331c59 --- /dev/null +++ b/ATXConfigTest/packages.config @@ -0,0 +1,4 @@ +<?xml version="1.0" encoding="utf-8"?> +<packages> + <package id="NLog" version="4.3.11" targetFramework="net45" /> +</packages> \ No newline at end of file diff --git a/ATXSerializables/FsUtils.cs b/ATXSerializables/FsUtils.cs deleted file mode 100644 index c6dadb1103b511605dce2bc7fd5673d085aa7c2f..0000000000000000000000000000000000000000 --- a/ATXSerializables/FsUtils.cs +++ /dev/null @@ -1,19 +0,0 @@ -using System.IO; -using System.Linq; - -namespace ATXCommon -{ - public static class FsUtils - { - /// <summary> - /// Recursively sum up size of all files under a given path. - /// </summary> - /// <param name="path">Full path of the directory.</param> - /// <returns>The total size in bytes.</returns> - public static long GetDirectorySize(string path) { - return new DirectoryInfo(path) - .GetFiles("*", SearchOption.AllDirectories) - .Sum(file => file.Length); - } - } -} diff --git a/ATXSerializables/TimeUtils.cs b/ATXSerializables/TimeUtils.cs deleted file mode 100644 index 04cc8fa2817d8ea8504fd237c452e3e474ada3e6..0000000000000000000000000000000000000000 --- a/ATXSerializables/TimeUtils.cs +++ /dev/null @@ -1,15 +0,0 @@ -using System; - -namespace ATXCommon -{ - public static class TimeUtils - { - /// <summary> - /// Helper method to create timestamp strings in a consistent fashion. - /// </summary> - /// <returns>A timestamp string of the current time.</returns> - public static string Timestamp() { - return DateTime.Now.ToString("yyyy-MM-dd__HH-mm-ss"); - } - } -} diff --git a/ATXService.sln b/ATXService.sln index 7ce63be1fa780b2bed144be4ebed8a6ba76180e9..626d82345992c0be34ef79936c103ca162c18f8a 100644 --- a/ATXService.sln +++ b/ATXService.sln @@ -5,7 +5,7 @@ VisualStudioVersion = 12.0.40629.0 MinimumVisualStudioVersion = 10.0.40219.1 Project("{FAE04EC0-301F-11D3-BF4B-00C04F79EFBC}") = "ATXProject", "AutoTx\ATXProject.csproj", "{5CB67E3A-E63A-4791-B90B-8CEF0027AEAD}" EndProject -Project("{FAE04EC0-301F-11D3-BF4B-00C04F79EFBC}") = "ATXCommon", "ATXSerializables\ATXCommon.csproj", "{166D65D5-EE10-4364-8AA3-4D86BA5CE244}" +Project("{FAE04EC0-301F-11D3-BF4B-00C04F79EFBC}") = "ATXCommon", "ATXCommon\ATXCommon.csproj", "{166D65D5-EE10-4364-8AA3-4D86BA5CE244}" EndProject Project("{FAE04EC0-301F-11D3-BF4B-00C04F79EFBC}") = "ATXConfigTest", "ATXConfigTest\ATXConfigTest.csproj", "{81E0A5AC-0E0D-4F98-B399-41A58612EF33}" EndProject diff --git a/ATXTray/ATXTray.csproj b/ATXTray/ATXTray.csproj index 667121e89fab2f67985fc0fd4c524a9fcb09e2f6..e64ce3107a09b49b58117ae279f07b5fcc6e8fda 100644 --- a/ATXTray/ATXTray.csproj +++ b/ATXTray/ATXTray.csproj @@ -47,6 +47,10 @@ <HintPath>..\packages\Microsoft.WindowsAPICodePack-Shell.1.1.0.0\lib\Microsoft.WindowsAPICodePack.ShellExtensions.dll</HintPath> <Private>True</Private> </Reference> + <Reference Include="NLog, Version=4.0.0.0, Culture=neutral, PublicKeyToken=5120e14c03d0593c, processorArchitecture=MSIL"> + <HintPath>..\packages\NLog.4.3.11\lib\net45\NLog.dll</HintPath> + <Private>True</Private> + </Reference> <Reference Include="System" /> <Reference Include="System.Core" /> <Reference Include="System.Xml.Linq" /> @@ -89,7 +93,7 @@ <Content Include="AutoTx.ico" /> </ItemGroup> <ItemGroup> - <ProjectReference Include="..\ATXSerializables\ATXCommon.csproj"> + <ProjectReference Include="..\ATXCommon\ATXCommon.csproj"> <Project>{166D65D5-EE10-4364-8AA3-4D86BA5CE244}</Project> <Name>ATXCommon</Name> </ProjectReference> diff --git a/ATXTray/AutoTxTray.cs b/ATXTray/AutoTxTray.cs index 005212714490ea8709c7460c5fe54b85dba696e8..0f2a971ab4bffe52710f0fd64de77f454c506cea 100644 --- a/ATXTray/AutoTxTray.cs +++ b/ATXTray/AutoTxTray.cs @@ -6,12 +6,17 @@ using System.IO; using System.Windows.Forms; using ATXCommon.Serializables; using Microsoft.WindowsAPICodePack.Dialogs; +using NLog; +using NLog.Config; +using NLog.Targets; using Timer = System.Timers.Timer; namespace ATXTray { public class AutoTxTray : ApplicationContext { + private static readonly Logger Log = LogManager.GetCurrentClassLogger(); + private static readonly string AppTitle = Path.GetFileNameWithoutExtension(Application.ExecutablePath); private static readonly Timer AppTimer = new Timer(1000); private static bool _terminate = false; @@ -46,6 +51,26 @@ namespace ATXTray private readonly ToolStripMenuItem _miTxEnqueue = new ToolStripMenuItem(); public AutoTxTray() { + + #region logging configuration + + var logConfig = new LoggingConfiguration(); + var fileTarget = new FileTarget { + FileName = AppTitle + ".log", + Layout = @"${date:format=yyyy-MM-dd HH\:mm\:ss} [${level}] ${message}" + // Layout = @"${date:format=yyyy-MM-dd HH\:mm\:ss} [${level}] (${logger}) ${message}" + }; + logConfig.AddTarget("file", fileTarget); + var logRule = new LoggingRule("*", LogLevel.Debug, fileTarget); + logConfig.LoggingRules.Add(logRule); + LogManager.Configuration = logConfig; + + #endregion + + + Log.Info("{0} initializing...", AppTitle); + Log.Debug(" - config file: [{0}]", ConfigFile); + Log.Debug(" - status file: [{0}]", StatusFile); _notifyIcon.Icon = _tiStopped; _notifyIcon.Visible = true; @@ -54,13 +79,16 @@ namespace ATXTray // this doesn't work properly, the menu will not close etc. so we disable it for now: // _notifyIcon.Click += ShowContextMenu; + Log.Trace("Trying to read service config and status files..."); try { _config = ServiceConfig.Deserialize(ConfigFile); ReadStatus(); + Log.Trace("Completed reading service config and status files."); SetupContextMenu(); } catch (Exception ex) { var msg = "Error during initialization: " + ex.Message; + Log.Error(msg); _notifyIcon.ShowBalloonTip(5000, AppTitle, msg, ToolTipIcon.Error); // we cannot terminate the message loop (Application.Run()) while the constructor // is being run as it is not active yet - therefore we simply remember that we want @@ -71,9 +99,13 @@ namespace ATXTray AppTimer.Elapsed += AppTimerElapsed; AppTimer.Enabled = true; + Log.Trace("Enabled timer."); + + Log.Info("AutoTxTray initialization completed."); } private void SetupContextMenu() { + Log.Trace("Building context menu..."); _miExit.Text = @"Exit"; _miExit.Click += MiExitClick; @@ -108,9 +140,11 @@ namespace ATXTray }); _notifyIcon.ContextMenuStrip = _cmStrip; + Log.Trace("Finished building context menu."); } private void AutoTxTrayExit() { + Log.Info("Shutting down {0}.", AppTitle); _notifyIcon.Visible = false; Application.Exit(); } @@ -190,6 +224,7 @@ namespace ATXTray if (age == _statusAge) return; + Log.Debug("Status file was updated, trying to re-read..."); _statusAge = age; _status = ServiceStatus.Deserialize(StatusFile, _config); } diff --git a/ATXTray/packages.config b/ATXTray/packages.config index e06f06e7fa0552bd8975b1b653293aca0059d869..1aa4655a16531c979bf567ac4d2b9a8a2d6d25f6 100644 --- a/ATXTray/packages.config +++ b/ATXTray/packages.config @@ -2,4 +2,5 @@ <packages> <package id="Microsoft.WindowsAPICodePack-Core" version="1.1.0.0" targetFramework="net45" /> <package id="Microsoft.WindowsAPICodePack-Shell" version="1.1.0.0" targetFramework="net45" /> + <package id="NLog" version="4.3.11" targetFramework="net45" /> </packages> \ No newline at end of file diff --git a/AutoTx/ATXProject.csproj b/AutoTx/ATXProject.csproj index 15cfffa998cfbf6cd92f4988e80657a9b2fd6f1c..aa53c590e76de1b7ce51a8a289890b3c4d4ae538 100644 --- a/AutoTx/ATXProject.csproj +++ b/AutoTx/ATXProject.csproj @@ -50,6 +50,10 @@ <StartupObject>AutoTx.Program</StartupObject> </PropertyGroup> <ItemGroup> + <Reference Include="NLog, Version=4.0.0.0, Culture=neutral, PublicKeyToken=5120e14c03d0593c, processorArchitecture=MSIL"> + <HintPath>..\packages\NLog.4.3.11\lib\net45\NLog.dll</HintPath> + <Private>True</Private> + </Reference> <Reference Include="RoboSharp"> <HintPath>..\..\robosharp\RoboSharp\bin\Debug\RoboSharp.dll</HintPath> </Reference> @@ -83,9 +87,6 @@ <Compile Include="Email.cs"> <SubType>Component</SubType> </Compile> - <Compile Include="Logging.cs"> - <SubType>Component</SubType> - </Compile> <Compile Include="Program.cs" /> <Compile Include="ProjectInstaller.cs"> <SubType>Component</SubType> @@ -102,9 +103,6 @@ <Compile Include="RoboCommand.cs"> <SubType>Component</SubType> </Compile> - <Compile Include="SystemChecks.cs"> - <SubType>Component</SubType> - </Compile> </ItemGroup> <ItemGroup> <None Include="App.config" /> @@ -142,13 +140,14 @@ </BootstrapperPackage> </ItemGroup> <ItemGroup> + <None Include="packages.config" /> <None Include="Resources\BuildDate.txt" /> </ItemGroup> <ItemGroup> <None Include="Resources\BuildCommit.txt" /> </ItemGroup> <ItemGroup> - <ProjectReference Include="..\ATXSerializables\ATXCommon.csproj"> + <ProjectReference Include="..\ATXCommon\ATXCommon.csproj"> <Project>{166D65D5-EE10-4364-8AA3-4D86BA5CE244}</Project> <Name>ATXCommon</Name> </ProjectReference> diff --git a/AutoTx/AutoTx.cs b/AutoTx/AutoTx.cs index c6f7d84ce39dcb21d6cefc15b582ad35d2bf9d47..ee781ddb0c7d9e56c8df44892dd53d0dec3c0824 100644 --- a/AutoTx/AutoTx.cs +++ b/AutoTx/AutoTx.cs @@ -6,11 +6,12 @@ using System.Linq; using System.ServiceProcess; using System.IO; using System.Timers; -using System.DirectoryServices.AccountManagement; -using System.Globalization; -using System.Management; -using ATXCommon.Serializables; +using NLog; +using NLog.Config; +using NLog.Targets; using ATXCommon; +using ATXCommon.NLog; +using ATXCommon.Serializables; using RoboSharp; namespace AutoTx @@ -19,24 +20,20 @@ namespace AutoTx { #region global variables - // naming convention: variables ending with "Path" are strings, variables - // ending with "Dir" are DirectoryInfo objects - private string _configPath; - private string _statusPath; - private string _incomingPath; - private string _managedPath; + private static readonly Logger Log = LogManager.GetCurrentClassLogger(); + private const string LogFormatDefault = @"${date:format=yyyy-MM-dd HH\:mm\:ss} [${level}] ${message}"; + // private const string LogFormatDefault = @"${date:format=yyyy-MM-dd HH\:mm\:ss} [${level}] (${logger}) ${message}" - private string[] _remoteUserDirs; - private string[] _localUserDirs; + // naming convention: variables containing "Path" are strings, variables + // containing "Dir" are DirectoryInfo objects + private string _pathToConfig; + private string _pathToStatus; private List<string> _transferredFiles = new List<string>(); private int _txProgress; - private const int MegaBytes = 1024 * 1024; - private const int GigaBytes = 1024 * 1024 * 1024; - - private DateTime _lastUserDirCheck = DateTime.Now; + private DateTime _lastUserDirCheck = DateTime.MinValue; // the transfer state: private enum TxState @@ -71,11 +68,101 @@ namespace AutoTx public AutoTx() { InitializeComponent(); + SetupFileLogging(); + Log.Info("=========================================================================="); + Log.Info("Attempting to start {0} service...", ServiceName); CreateEventLog(); LoadSettings(); CreateIncomingDirectories(); } + /// <summary> + /// Set up NLog logging: targets, rules... + /// </summary> + private void SetupFileLogging() { + var logConfig = new LoggingConfiguration(); + var fileTarget = new FileTarget { + FileName = ServiceName + ".log", + ArchiveAboveSize = 1000000, + ArchiveFileName = ServiceName + ".{#}.log", + MaxArchiveFiles = 9, + KeepFileOpen = true, + Layout = LogFormatDefault, + }; + logConfig.AddTarget("file", fileTarget); + var logRuleFile = new LoggingRule("*", LogLevel.Debug, fileTarget); + logConfig.LoggingRules.Add(logRuleFile); + LogManager.Configuration = logConfig; + } + + /// <summary> + /// Configure logging to email targets. + /// + /// Depending on the configuration, set up the logging via email. If no SmtpHost or no + /// AdminEmailAdress is configured, nothing will be done. If they're set in the config file, + /// a log target for messages with level "Fatal" will be configured. In addition, if the + /// AdminDebugEmailAdress is set, another target for "Error" level messages is configured + /// using this address as recipient. + /// </summary> + private void SetupMailLogging() { + try { + if (string.IsNullOrWhiteSpace(_config.SmtpHost) || + string.IsNullOrWhiteSpace(_config.AdminEmailAdress)) + return; + + var subject = string.Format("{0} - {1} - Admin Notification", + ServiceName, Environment.MachineName); + var body = string.Format("Notification from '{0}' [{1}] (via NLog)\n\n{2}", + _config.HostAlias, Environment.MachineName, LogFormatDefault); + + var logConfig = LogManager.Configuration; + + // "Fatal" target + var mailTargetFatal = new MailTarget { + Name = "mailfatal", + SmtpServer = _config.SmtpHost, + SmtpPort = _config.SmtpPort, + From = _config.EmailFrom, + To = _config.AdminEmailAdress, + Subject = subject, + Body = body, + }; + var mailTargetFatalLimited = new RateLimitWrapper { + Name = "mailfatallimited", + MinLogInterval = _config.AdminNotificationDelta, + WrappedTarget = mailTargetFatal + }; + logConfig.AddTarget(mailTargetFatalLimited); + logConfig.AddRuleForOneLevel(LogLevel.Fatal, mailTargetFatalLimited); + + // "Error" target + if (!string.IsNullOrWhiteSpace(_config.AdminDebugEmailAdress)) { + var mailTargetError = new MailTarget { + Name = "mailerror", + SmtpServer = _config.SmtpHost, + SmtpPort = _config.SmtpPort, + From = _config.EmailFrom, + To = _config.AdminDebugEmailAdress, + Subject = subject, + Body = body, + }; + var mailTargetErrorLimited = new RateLimitWrapper { + Name = "mailerrorlimited", + MinLogInterval = _config.AdminNotificationDelta, + WrappedTarget = mailTargetError + }; + logConfig.AddTarget(mailTargetErrorLimited); + logConfig.AddRuleForOneLevel(LogLevel.Error, mailTargetErrorLimited); + Log.Info("Configured mail notification for 'Error' messages to {0}", mailTargetError.To); + } + Log.Info("Configured mail notification for 'Fatal' messages to {0}", mailTargetFatal.To); + LogManager.Configuration = logConfig; + } + catch (Exception ex) { + Log.Error("SetupMailLogging(): {0}", ex.Message); + } + } + /// <summary> /// Create the event log if it doesn't exist yet. /// </summary> @@ -89,7 +176,7 @@ namespace AutoTx eventLog.Log = ServiceName; } catch (Exception ex) { - writeLog("Error in createEventLog(): " + ex.Message, true); + Log.Error("Error in createEventLog(): " + ex.Message, true); } } @@ -100,9 +187,8 @@ namespace AutoTx try { _transferState = TxState.Stopped; var baseDir = AppDomain.CurrentDomain.BaseDirectory; - _logPath = Path.Combine(baseDir, "service.log"); - _configPath = Path.Combine(baseDir, "configuration.xml"); - _statusPath = Path.Combine(baseDir, "status.xml"); + _pathToConfig = Path.Combine(baseDir, "configuration.xml"); + _pathToStatus = Path.Combine(baseDir, "status.xml"); LoadConfigXml(); LoadStatusXml(); @@ -110,8 +196,7 @@ namespace AutoTx _roboCommand = new RoboCommand(); } catch (Exception ex) { - writeLog("Error in LoadSettings(): " + ex.Message + "\n" + - ex.StackTrace, true); + Log.Error("LoadSettings() failed: {0}\n{1}", ex.Message, ex.StackTrace); throw new Exception("Error in LoadSettings."); } // NOTE: this is explicitly called *outside* the try-catch block so an Exception @@ -119,55 +204,54 @@ namespace AutoTx CheckConfiguration(); } - /// <summary> /// Load the configuration xml file. /// </summary> private void LoadConfigXml() { try { - _config = ServiceConfig.Deserialize(_configPath); - _incomingPath = Path.Combine(_config.SourceDrive, _config.IncomingDirectory); - _managedPath = Path.Combine(_config.SourceDrive, _config.ManagedDirectory); - writeLogDebug("Loaded config from " + _configPath); + _config = ServiceConfig.Deserialize(_pathToConfig); + Log.Debug("Loaded config from [{0}]", _pathToConfig); } catch (ConfigurationErrorsException ex) { - writeLog("ERROR validating configuration file [" + _configPath + - "]: " + ex.Message); + Log.Error("ERROR validating configuration file [{0}]: {1}", + _pathToConfig, ex.Message); throw new Exception("Error validating configuration."); } catch (Exception ex) { - writeLog("Error loading configuration XML: " + ex.Message, true); + Log.Error("loading configuration XML failed: {0}", ex.Message); // this should terminate the service process: throw new Exception("Error loading config."); } } - /// <summary> /// Load the status xml file. /// </summary> private void LoadStatusXml() { try { - writeLogDebug("Trying to load status from " + _statusPath); - _status = ServiceStatus.Deserialize(_statusPath, _config); - writeLogDebug("Loaded status from " + _statusPath); + Log.Debug("Trying to load status from [{0}]", _pathToStatus); + _status = ServiceStatus.Deserialize(_pathToStatus, _config); + Log.Debug("Loaded status from [{0}]", _pathToStatus); } catch (Exception ex) { - writeLog("Error loading status XML from [" + _statusPath + "]: " - + ex.Message + "\n" + ex.StackTrace, true); + Log.Error("loading status XML from [{0}] failed: {1} {2}", + _pathToStatus, ex.Message, ex.StackTrace); // this should terminate the service process: throw new Exception("Error loading status."); } } - /// <summary> /// Check if loaded configuration is valid, print a summary to the log. /// </summary> - public void CheckConfiguration() { + private void CheckConfiguration() { + // non-critical / optional configuration parameters: + if (!string.IsNullOrWhiteSpace(_config.SmtpHost)) + SetupMailLogging(); + var configInvalid = false; - if (CheckSpoolingDirectories() == false) { - writeLog("ERROR checking spooling directories (incoming / managed)!"); + if (FsUtils.CheckSpoolingDirectories(_config.IncomingPath, _config.ManagedPath) == false) { + Log.Error("ERROR checking spooling directories (incoming / managed)!"); configInvalid = true; } @@ -179,8 +263,8 @@ namespace AutoTx // then set it to false while the service is running until it is properly // shut down via the OnStop() method: if (_status.CleanShutdown == false) { - writeLog("WARNING: " + ServiceName + " was not shut down properly last time!\n\n" + - "This could indicate the computer has crashed or was forcefully shut off.", true); + Log.Error("WARNING: {0} was not shut down properly last time!\n\nThis could " + + "indicate the computer has crashed or was forcefully shut off.", ServiceName); } _status.CleanShutdown = false; @@ -205,16 +289,17 @@ namespace AutoTx msg += "\n------ Current system parameters ------\n" + "Hostname: " + Environment.MachineName + "\n" + - "Free system memory: " + GetFreeMemory() + " MB" + "\n"; + "Free system memory: " + SystemChecks.GetFreeMemory() + " MB" + "\n"; foreach (var driveToCheck in _config.SpaceMonitoring) { msg += "Free space on drive '" + driveToCheck.DriveName + "': " + - GetFreeDriveSpace(driveToCheck.DriveName) + "\n"; + Conv.BytesToString(SystemChecks.GetFreeDriveSpace(driveToCheck.DriveName)) + "\n"; } - msg += "\n------ Grace location status (threshold: " + _config.GracePeriod + ") ------\n"; + msg += "\n------ Grace location status, threshold: " + _config.GracePeriod + " days " + + "(" + TimeUtils.DaysToHuman(_config.GracePeriod) + ") ------\n"; try { - var tmp = GraceLocationSummary(_config.GracePeriod); + var tmp = SendGraceLocationSummary(_config.GracePeriod); if (string.IsNullOrEmpty(tmp)) { msg += " -- NO EXPIRED folders in grace location! --\n"; } else { @@ -222,18 +307,10 @@ namespace AutoTx } } catch (Exception ex) { - writeLog("GraceLocationSummary() failed: " + ex.Message, true); + Log.Error("GraceLocationSummary() failed: {0}", ex.Message); } - if (!string.IsNullOrEmpty(_config.ValidationWarnings)) { - writeLog("WARNING: some configuration settings might not be optimal:\n" + - _config.ValidationWarnings); - } - if (!string.IsNullOrEmpty(_status.ValidationWarnings)) { - writeLog("WARNING: some status parameters were invalid and have been reset:\n" + - _status.ValidationWarnings); - } - writeLogDebug(msg); + Log.Debug(msg); } #endregion @@ -250,17 +327,18 @@ namespace AutoTx _mainTimer.Enabled = true; } catch (Exception ex) { - writeLog("Error in OnStart(): " + ex.Message, true); + Log.Error("Error in OnStart(): {0}", ex.Message); + throw; } // read the build timestamp from the resources: var buildTimestamp = Properties.Resources.BuildDate.Trim(); var buildCommitName = Properties.Resources.BuildCommit.Trim(); - writeLog("-----------------------"); - writeLog(ServiceName + " service started."); - writeLog("build: [" + buildTimestamp + "]"); - writeLog("commit: [" + buildCommitName + "]"); - writeLog("-----------------------"); + Log.Info("-----------------------"); + Log.Info("{0} service started.", ServiceName); + Log.Info("build: [{0}]", buildTimestamp); + Log.Info("commit: [{0}]", buildCommitName); + Log.Info("-----------------------"); } /// <summary> @@ -269,7 +347,7 @@ namespace AutoTx /// the OnShutdown() method is used! /// </summary> protected override void OnStop() { - writeLog(ServiceName + " service stop requested..."); + Log.Warn("{0} service stop requested...", ServiceName); if (_transferState != TxState.Stopped) { _transferState = TxState.DoNothing; // Stop() is calling Process.Kill() (immediately forcing a termination of the @@ -281,19 +359,19 @@ namespace AutoTx _roboCommand.Stop(); } catch (Exception ex) { - writeLog("Error terminating the RoboCopy process: " + ex.Message, true); + Log.Error("Error terminating the RoboCopy process: {0}", ex.Message); } _status.TransferInProgress = true; - writeLog("Not all files were transferred - will resume upon next start"); - writeLogDebug("CurrentTransferSrc: " + _status.CurrentTransferSrc); + Log.Info("Not all files were transferred - will resume upon next start"); + Log.Debug("CurrentTransferSrc: " + _status.CurrentTransferSrc); // should we delete an incompletely transferred file on the target? SendTransferInterruptedMail(); } // set the shutdown status to clean: _status.CleanShutdown = true; - writeLog("-----------------------"); - writeLog(ServiceName + " service stopped"); - writeLog("-----------------------"); + Log.Info("-----------------------"); + Log.Info("{0} service stopped", ServiceName); + Log.Info("-----------------------"); } /// <summary> @@ -301,7 +379,7 @@ namespace AutoTx /// it doesn't call the OnStop() method, so we have to do this explicitly. /// </summary> protected override void OnShutdown() { - writeLog("System is shutting down, requesting the service to stop."); + Log.Warn("System is shutting down, requesting the service to stop."); OnStop(); } @@ -309,9 +387,9 @@ namespace AutoTx /// Is executed when the service continues /// </summary> protected override void OnContinue() { - writeLog("-------------------------"); - writeLog(ServiceName + " service resuming"); - writeLog("-------------------------"); + Log.Info("-------------------------"); + Log.Info("{0} service resuming", ServiceName); + Log.Info("-------------------------"); } /// <summary> @@ -327,10 +405,24 @@ namespace AutoTx try { RunMainTasks(); GC.Collect(); + // if everything went fine, reset the timer interval to its default value, so the + // service can even recover from temporary problems itself (see below): + _mainTimer.Interval = _config.ServiceTimer; } catch (Exception ex) { - writeLog("Error in OnTimedEvent(): " + ex.Message, true); - writeLogDebug("Extended Error Info (StackTrace): " + ex.StackTrace); + // in case an Exception is reaching this level there is a good chance it is a + // permanent / recurring problem, therefore we increase the timer interval each + // time by a factor of ten (to avoid triggering the same issue every second and + // flooding the admins with emails): + _mainTimer.Interval *= 10; + // make sure the interval doesn't exceed half a day: + const int maxInterval = 1000 * 60 * 60 * 12; + if (_mainTimer.Interval > maxInterval) + _mainTimer.Interval = maxInterval; + Log.Error("Unhandled exception in OnTimedEvent(): {0}\n\n" + + "Trying exponential backoff, setting timer interval to {1} ms ({3}).\n\n" + + "StackTrace: {2}", ex.Message, _mainTimer.Interval, ex.StackTrace, + TimeUtils.SecondsToHuman((int)_mainTimer.Interval / 1000)); } finally { // make sure to enable the timer again: @@ -350,12 +442,13 @@ namespace AutoTx // check all system parameters for valid ranges and remember the reason in a string // if one of them is failing (to report in the log why we're suspended) - if (GetCpuUsage() >= _config.MaxCpuUsage) + if (SystemChecks.GetCpuUsage() >= _config.MaxCpuUsage) limitReason = "CPU usage"; - else if (GetFreeMemory() < _config.MinAvailableMemory) + else if (SystemChecks.GetFreeMemory() < _config.MinAvailableMemory) limitReason = "RAM usage"; else { - var blacklistedProcess = CheckForBlacklistedProcesses(); + var blacklistedProcess = SystemChecks.CheckForBlacklistedProcesses( + _config.BlacklistedProcesses); if (blacklistedProcess != "") { limitReason = "blacklisted process '" + blacklistedProcess + "'"; } @@ -366,17 +459,17 @@ namespace AutoTx _status.ServiceSuspended = false; if (!string.IsNullOrEmpty(_status.LimitReason)) { _status.LimitReason = ""; // reset to force a message on next service suspend - writeLog("Service resuming operation (all parameters in valid ranges)."); + Log.Info("Service resuming operation (all parameters in valid ranges)."); } return; } // set state to "Running" if no-one is logged on: - if (NoUserIsLoggedOn()) { + if (SystemChecks.NoUserIsLoggedOn()) { _status.ServiceSuspended = false; if (!string.IsNullOrEmpty(_status.LimitReason)) { _status.LimitReason = ""; // reset to force a message on next service suspend - writeLog("Service resuming operation (no user logged on)."); + Log.Info("Service resuming operation (no user logged on)."); } return; } @@ -385,21 +478,21 @@ namespace AutoTx _status.ServiceSuspended = true; if (limitReason == _status.LimitReason) return; - writeLog("Service suspended due to limitiations [" + limitReason + "]."); + Log.Info("Service suspended due to limitiations [{0}].", limitReason); _status.LimitReason = limitReason; } /// <summary> /// Do the main tasks of the service, check system state, trigger transfers, ... /// </summary> - public void RunMainTasks() { + private void RunMainTasks() { + // throw new Exception("just a test exception from RunMainTasks"); + // mandatory tasks, run on every call: - CheckLogSize(); - CheckFreeDiskSpace(); + SendLowSpaceMail(SystemChecks.CheckFreeDiskSpace(_config.SpaceMonitoring)); UpdateServiceState(); - var delta = (int)(DateTime.Now - _lastUserDirCheck).TotalSeconds; - if (delta >= 120) + if (TimeUtils.SecondsSince(_lastUserDirCheck) >= 120) CreateIncomingDirectories(); // tasks depending on the service state: @@ -416,82 +509,9 @@ namespace AutoTx #endregion - #region ActiveDirectory, email address, user name, ... - - /// <summary> - /// Check if a user is currently logged into Windows. - /// - /// WARNING: this DOES NOT ACCOUNT for users logged in via RDP!! - /// </summary> - /// See https://stackoverflow.com/questions/5218778/ for the RDP problem. - private bool NoUserIsLoggedOn() { - var username = ""; - try { - var searcher = new ManagementObjectSearcher("SELECT UserName " + - "FROM Win32_ComputerSystem"); - var collection = searcher.Get(); - username = (string) collection.Cast<ManagementBaseObject>().First()["UserName"]; - } - catch (Exception ex) { - writeLog("Error in getCurrentUsername(): " + ex.Message, true); - } - return username == ""; - } - - /// <summary> - /// Get the user email address from ActiveDirectory. - /// </summary> - /// <param name="username">The username.</param> - /// <returns>Email address of AD user, an empty string if not found.</returns> - public string GetEmailAddress(string username) { - try { - using (var pctx = new PrincipalContext(ContextType.Domain)) { - using (var up = UserPrincipal.FindByIdentity(pctx, username)) { - if (up != null && !String.IsNullOrEmpty(up.EmailAddress)) { - return up.EmailAddress; - } - } - } - } - catch (Exception ex) { - writeLog("Can't find email address for " + username + ": " + ex.Message); - } - return ""; - } - - /// <summary> - /// Get the full user name (human-friendly) from ActiveDirectory. - /// </summary> - /// <param name="username">The username.</param> - /// <returns>A human-friendly string representation of the user principal.</returns> - public string GetFullUserName(string username) { - try { - using (var pctx = new PrincipalContext(ContextType.Domain)) { - using (var up = UserPrincipal.FindByIdentity(pctx, username)) { - if (up != null) return up.GivenName + " " + up.Surname; - } - } - } - catch (Exception ex) { - writeLog("Can't find full name for " + username + ": " + ex.Message); - } - return ""; - } - - #endregion #region transfer tasks - /// <summary> - /// Helper method to generate the full path of the current temp directory. - /// </summary> - /// <returns>A string with the path to the last tmp dir.</returns> - private string ExpandCurrentTargetTmp() { - return Path.Combine(_config.DestinationDirectory, - _config.TmpTransferDir, - _status.CurrentTargetTmp); - } - /// <summary> /// Assemble the transfer destination path and check if it exists. /// </summary> @@ -508,7 +528,7 @@ namespace AutoTx /// <summary> /// Check for transfers to be finished, resumed or newly initiated. /// </summary> - public void RunTransferTasks() { + private void RunTransferTasks() { // only proceed when in a valid state: if (_transferState != TxState.Stopped && _transferState != TxState.Paused) @@ -539,8 +559,7 @@ namespace AutoTx return; // check the "processing" location for directories: - var processingDir = Path.Combine(_managedPath, "PROCESSING"); - var queued = new DirectoryInfo(processingDir).GetDirectories(); + var queued = new DirectoryInfo(_config.ProcessingPath).GetDirectories(); if (queued.Length == 0) return; @@ -548,13 +567,13 @@ namespace AutoTx // having no subdirectories should not happen in theory - in practice it could e.g. if // an admin is moving around stuff while the service is operating, so better be safe: if (subdirs.Length == 0) { - writeLog("WARNING: empty processing directory found: " + queued[0].Name); + Log.Warn("WARNING: empty processing directory found: {0}", queued[0].Name); try { queued[0].Delete(); - writeLogDebug("Removed empty directory: " + queued[0].Name); + Log.Debug("Removed empty directory: {0}", queued[0].Name); } catch (Exception ex) { - writeLog("Error deleting directory: " + queued[0].Name + " - " + ex.Message); + Log.Error("Error deleting directory: {0} - {1}", queued[0].Name, ex.Message); } return; } @@ -564,7 +583,7 @@ namespace AutoTx StartTransfer(subdirs[0].FullName); } catch (Exception ex) { - writeLog("Error checking for data to be transferred: " + ex.Message); + Log.Error("Error checking for data to be transferred: {0}", ex.Message); throw; } } @@ -574,11 +593,11 @@ namespace AutoTx /// </summary> private void CheckIncomingDirectories() { // iterate over all user-subdirectories: - foreach (var userDir in new DirectoryInfo(_incomingPath).GetDirectories()) { - if (IncomingDirIsEmpty(userDir)) + foreach (var userDir in new DirectoryInfo(_config.IncomingPath).GetDirectories()) { + if (FsUtils.DirEmptyExcept(userDir, _config.MarkerFile)) continue; - writeLog("Found new files in " + userDir.FullName); + Log.Info("Found new files in [{0}]", userDir.FullName); MoveToManagedLocation(userDir); } } @@ -597,17 +616,18 @@ namespace AutoTx return; if (_status.CurrentTargetTmp.Length > 0) { - writeLogDebug("Finalizing transfer, cleaning up target storage location..."); + Log.Debug("Finalizing transfer, cleaning up target storage location..."); var finalDst = DestinationPath(_status.CurrentTargetTmp); if (!string.IsNullOrWhiteSpace(finalDst)) { - if (MoveAllSubDirs(new DirectoryInfo(ExpandCurrentTargetTmp()), finalDst, true)) { + if (FsUtils.MoveAllSubDirs(new DirectoryInfo(_status.CurrentTargetTmpFull()), + finalDst, _config.EnforceInheritedACLs)) { _status.CurrentTargetTmp = ""; } } } if (_status.CurrentTransferSrc.Length > 0) { - writeLogDebug("Finalizing transfer, moving local data to grace location..."); + Log.Debug("Finalizing transfer, moving local data to grace location..."); MoveToGraceLocation(); SendTransferCompletedMail(); _status.CurrentTransferSrc = ""; // cleanup completed, so reset CurrentTransferSrc @@ -630,8 +650,8 @@ namespace AutoTx _status.TransferInProgress == false) return; - writeLogDebug("Resuming interrupted transfer from '" + _status.CurrentTransferSrc + - "' to '" + ExpandCurrentTargetTmp() + "'"); + Log.Debug("Resuming interrupted transfer from [{0}] to [{1}]", + _status.CurrentTransferSrc, _status.CurrentTargetTmpFull()); StartTransfer(_status.CurrentTransferSrc); } @@ -639,103 +659,39 @@ namespace AutoTx #region filesystem tasks (check, move, ...) - /// <summary> - /// Check if a given directory is empty. If a marker file is set in the config a - /// file with this name will be created inside the given directory and will be - /// skipped itself when checking for files and directories. - /// </summary> - /// <param name="dirInfo">The directory to check.</param> - /// <returns>True if access is denied or the dir is empty, false otherwise.</returns> - private bool IncomingDirIsEmpty(DirectoryInfo dirInfo) { - try { - var filesInTree = dirInfo.GetFiles("*", SearchOption.AllDirectories); - if (string.IsNullOrEmpty(_config.MarkerFile)) - return filesInTree.Length == 0; - - // check if there is ONLY the marker file: - if (filesInTree.Length == 1 && - filesInTree[0].Name.Equals(_config.MarkerFile)) - return true; - - // make sure the marker file is there: - var markerFilePath = Path.Combine(dirInfo.FullName, _config.MarkerFile); - if (! File.Exists(markerFilePath)) - File.Create(markerFilePath); - - return filesInTree.Length == 0; - } - catch (Exception e) { - writeLog("Error accessing directories: " + e.Message); - } - // if nothing triggered before, we pretend the dir is empty: - return true; - } - - /// <summary> - /// Collect individual files in a user dir in a specific sub-directory. If a marker - /// file is set in the configuration, this will be skipped in the checks. - /// </summary> - /// <param name="userDir">The user directory to check for individual files.</param> - private void CollectOrphanedFiles(DirectoryInfo userDir) { - var fileList = userDir.GetFiles(); - var orphanedDir = Path.Combine(userDir.FullName, "orphaned"); - try { - if (fileList.Length > 1 || - (string.IsNullOrEmpty(_config.MarkerFile) && fileList.Length > 0)) { - if (Directory.Exists(orphanedDir)) { - writeLog("Orphaned directory already exists, skipping individual files."); - return; - } - writeLogDebug("Found individual files, collecting them in 'orphaned' folder."); - CreateNewDirectory(orphanedDir, false); - } - foreach (var file in fileList) { - if (file.Name.Equals(_config.MarkerFile)) - continue; - writeLogDebug("Collecting orphan: " + file.Name); - file.MoveTo(Path.Combine(orphanedDir, file.Name)); - } - } - catch (Exception ex) { - writeLog("Error collecting orphaned files: " + ex.Message + ex.StackTrace); - } - } - /// <summary> /// Check the incoming directory for files and directories, move them over /// to the "processing" location (a sub-directory of ManagedDirectory). /// </summary> + /// CAUTION: this method is called as a consequence of the main timer being triggered, so + /// be aware that any message dispatched here could potentially show up every second! private void MoveToManagedLocation(DirectoryInfo userDir) { string errMsg; try { // first check for individual files and collect them: - CollectOrphanedFiles(userDir); + FsUtils.CollectOrphanedFiles(userDir, _config.MarkerFile); - // the default subdir inside the managed directory, where folders will be - // picked up later by the actual transfer method: - var target = "PROCESSING"; + // the default path where folders will be picked up by the actual transfer method: + var baseDir = _config.ProcessingPath; // if the user has no directory on the destination move to UNMATCHED instead: if (string.IsNullOrWhiteSpace(DestinationPath(userDir.Name))) { - writeLog("Found unmatched incoming dir: " + userDir.Name, true); - target = "UNMATCHED"; + Log.Error("Found unmatched incoming dir: {0}", userDir.Name); + baseDir = _config.UnmatchedPath; } // now everything that is supposed to be transferred is in a folder, // for example: D:\ATX\PROCESSING\2017-04-02__12-34-56\user00 - var targetDir = Path.Combine( - _managedPath, - target, - TimeUtils.Timestamp(), - userDir.Name); - if (MoveAllSubDirs(userDir, targetDir)) + var targetDir = Path.Combine(baseDir, TimeUtils.Timestamp(), userDir.Name); + if (FsUtils.MoveAllSubDirs(userDir, targetDir)) return; + errMsg = "unable to move " + userDir.FullName; } catch (Exception ex) { errMsg = ex.Message; } - writeLog("MoveToManagedLocation(" + userDir.FullName + ") failed: " + errMsg, true); + Log.Error("MoveToManagedLocation({0}) failed: {1}", userDir.FullName, errMsg); } /// <summary> @@ -743,26 +699,25 @@ namespace AutoTx /// a subdirectory with the current date and time as its name to denote the timepoint /// when the grace period for this data starts. /// </summary> - public void MoveToGraceLocation() { + private void MoveToGraceLocation() { string errMsg; // CurrentTransferSrc is e.g. D:\ATX\PROCESSING\2017-04-02__12-34-56\user00 var sourceDirectory = new DirectoryInfo(_status.CurrentTransferSrc); var dstPath = Path.Combine( - _managedPath, - "DONE", + _config.DonePath, sourceDirectory.Name, // the username directory TimeUtils.Timestamp()); - // writeLogDebug("MoveToGraceLocation: src(" + sourceDirectory.FullName + ") dst(" + dstPath + ")"); + Log.Trace("MoveToGraceLocation: src({0}) dst({1})", sourceDirectory.FullName, dstPath); try { - if (MoveAllSubDirs(sourceDirectory, dstPath)) { + if (FsUtils.MoveAllSubDirs(sourceDirectory, dstPath)) { // clean up the processing location: sourceDirectory.Delete(); if (sourceDirectory.Parent != null) sourceDirectory.Parent.Delete(); // check age and size of existing folders in the grace location after // a transfer has completed, trigger a notification if necessary: - writeLogDebug(GraceLocationSummary(_config.GracePeriod)); + Log.Debug(SendGraceLocationSummary(_config.GracePeriod)); return; } errMsg = "unable to move " + sourceDirectory.FullName; @@ -770,114 +725,7 @@ namespace AutoTx catch (Exception ex) { errMsg = ex.Message; } - writeLog("MoveToGraceLocation() failed: " + errMsg, true); - } - - /// <summary> - /// Move all subdirectories of a given path into a destination directory. The destination - /// will be created if it doesn't exist yet. If a subdirectory of the same name already - /// exists in the destination, a timestamp-suffix is added to the new one. - /// </summary> - /// <param name="sourceDir">The source path as DirectoryInfo object.</param> - /// <param name="destPath">The destination path as a string.</param> - /// <param name="resetAcls">Whether to reset the ACLs on the moved subdirectories.</param> - /// <returns>True on success, false otherwise.</returns> - private bool MoveAllSubDirs(DirectoryInfo sourceDir, string destPath, bool resetAcls = false) { - // TODO: check whether _transferState should be adjusted while moving dirs! - writeLogDebug("MoveAllSubDirs: " + sourceDir.FullName + " to " + destPath); - try { - // make sure the target directory that should hold all subdirectories to - // be moved is existing: - if (string.IsNullOrEmpty(CreateNewDirectory(destPath, false))) { - writeLog("WARNING: destination path doesn't exist: " + destPath); - return false; - } - - foreach (var subDir in sourceDir.GetDirectories()) { - var target = Path.Combine(destPath, subDir.Name); - // make sure NOT to overwrite the subdirectories: - if (Directory.Exists(target)) - target += "_" + TimeUtils.Timestamp(); - writeLogDebug(" - " + subDir.Name + " > " + target); - subDir.MoveTo(target); - - if (resetAcls && _config.EnforceInheritedACLs) { - try { - var acl = Directory.GetAccessControl(target); - acl.SetAccessRuleProtection(false, false); - Directory.SetAccessControl(target, acl); - writeLogDebug("Successfully reset inherited ACLs on " + target); - } - catch (Exception ex) { - writeLog("Error resetting inherited ACLs on " + target + ":\n" + - ex.Message); - } - } - } - } - catch (Exception ex) { - writeLog("Error moving directories: " + ex.Message + "\n" + - sourceDir.FullName + "\n" + - destPath, true); - return false; - } - return true; - } - - /// <summary> - /// Create a directory with the given name if it doesn't exist yet, otherwise - /// (optionally) create a new one using a date suffix to distinguish it from - /// the existing one. - /// </summary> - /// <param name="dirPath">The full path of the directory to be created.</param> - /// <param name="unique">Add a time-suffix to the name if the directory exists.</param> - /// <returns>The name of the (created or pre-existing) directory. This will only - /// differ from the input parameter "dirPath" if the "unique" parameter is set - /// to true (then it will give the newly generated name) or if an error occured - /// (in which case it will return an empty string).</returns> - private string CreateNewDirectory(string dirPath, bool unique) { - try { - if (Directory.Exists(dirPath)) { - // if unique was not requested, return the name of the existing dir: - if (unique == false) - return dirPath; - - dirPath = dirPath + "_" + TimeUtils.Timestamp(); - } - Directory.CreateDirectory(dirPath); - writeLogDebug("Created directory: " + dirPath); - return dirPath; - } - catch (Exception ex) { - writeLog("Error in CreateNewDirectory(" + dirPath + "): " + ex.Message, true); - } - return ""; - } - - /// <summary> - /// Helper method to check if a directory exists, trying to create it if not. - /// </summary> - /// <param name="path">The full path of the directory to check / create.</param> - /// <returns>True if existing or creation was successful, false otherwise.</returns> - private bool CheckForDirectory(string path) { - if (string.IsNullOrWhiteSpace(path)) { - writeLog("ERROR: CheckForDirectory() parameter must not be empty!"); - return false; - } - return CreateNewDirectory(path, false) == path; - } - - /// <summary> - /// Ensure the required spooling directories (managed/incoming) exist. - /// </summary> - /// <returns>True if all dirs exist or were created successfully.</returns> - private bool CheckSpoolingDirectories() { - var retval = CheckForDirectory(_incomingPath); - retval &= CheckForDirectory(_managedPath); - retval &= CheckForDirectory(Path.Combine(_managedPath, "PROCESSING")); - retval &= CheckForDirectory(Path.Combine(_managedPath, "DONE")); - retval &= CheckForDirectory(Path.Combine(_managedPath, "UNMATCHED")); - return retval; + Log.Error("MoveToGraceLocation() failed: {0}", errMsg); } /// <summary> @@ -885,116 +733,32 @@ namespace AutoTx /// user directory (C:\Users) AND in the DestinationDirectory. /// </summary> private void CreateIncomingDirectories() { - _localUserDirs = new DirectoryInfo(@"C:\Users") + var localUserDirs = new DirectoryInfo(@"C:\Users") .GetDirectories() .Select(d => d.Name) .ToArray(); - _remoteUserDirs = new DirectoryInfo(_config.DestinationDirectory) + var remoteUserDirs = new DirectoryInfo(_config.DestinationDirectory) .GetDirectories() .Select(d => d.Name) .ToArray(); - foreach (var userDir in _localUserDirs) { + foreach (var userDir in localUserDirs) { // don't create an incoming directory for the same name as the // temporary transfer location: if (_config.TmpTransferDir == userDir) continue; // don't create a directory if it doesn't exist on the target: - if (!_remoteUserDirs.Contains(userDir)) + if (!remoteUserDirs.Contains(userDir)) continue; - CreateNewDirectory(Path.Combine(_incomingPath, userDir), false); + FsUtils.CreateNewDirectory(Path.Combine(_config.IncomingPath, userDir), false); } _lastUserDirCheck = DateTime.Now; } - /// <summary> - /// Generate a report on expired folders in the grace location. - /// - /// Check all user-directories in the grace location for subdirectories whose timestamp - /// (the directory name) exceeds the configured grace period and generate a summary - /// containing the age and size of those directories. The summary will be sent to the admin - /// if the configured GraceNotificationDelta has passed since the last email. - /// </summary> - /// <param name="threshold">The number of days used as expiration threshold.</param> - public string GraceLocationSummary(int threshold) { - var expired = ExpiredDirs(threshold); - var report = ""; - foreach (var userdir in expired.Keys) { - report += "\n - user '" + userdir + "'\n"; - foreach (var subdir in expired[userdir]) { - report += string.Format(" - {0} [age: {2} days, size: {1} MB]\n", - subdir.Item1, subdir.Item2, subdir.Item3); - } - } - if (string.IsNullOrEmpty(report)) - return ""; - report = "Expired folders in grace location:\n" + report; - var delta = (int)(DateTime.Now - _status.LastGraceNotification).TotalMinutes; - report += "\nTime since last grace notification: " + delta + "\n"; - if (delta >= _config.GraceNotificationDelta) { - SendAdminEmail(report, "Grace location cleanup required."); - _status.LastGraceNotification = DateTime.Now; - report += "\nNotification sent to AdminEmailAdress.\n"; - } - return report; - } - - /// <summary> - /// Assemble a dictionary with information about expired directories. - /// </summary> - /// <param name="thresh">The number of days used as expiration threshold.</param> - /// <returns>A dictionary having usernames as keys (of those users that actually do have - /// expired directories), where the values are lists of tuples with the DirInfo objects, - /// size and age (in days) of the expired directories.</returns> - private Dictionary<string, List<Tuple<DirectoryInfo, long, int>>> ExpiredDirs(int thresh) { - var collection = new Dictionary<string, List<Tuple<DirectoryInfo, long, int>>>(); - var graceDir = new DirectoryInfo(Path.Combine(_managedPath, "DONE")); - var now = DateTime.Now; - foreach (var userdir in graceDir.GetDirectories()) { - var expired = new List<Tuple<DirectoryInfo, long, int>>(); - foreach (var subdir in userdir.GetDirectories()) { - var age = DirNameToAge(subdir, now); - if (age < thresh) - continue; - long size = -1; - try { - size = FsUtils.GetDirectorySize(subdir.FullName) / MegaBytes; - } - catch (Exception ex) { - writeLog("ERROR getting directory size of " + subdir.FullName + - " - " + ex.Message); - } - expired.Add(new Tuple<DirectoryInfo, long, int>(subdir, size, age)); - } - if (expired.Count > 0) - collection.Add(userdir.Name, expired); - } - return collection; - } - - /// <summary> - /// Convert the timestamp given by the NAME of a directory into the age in days. - /// </summary> - /// <param name="dir">The DirectoryInfo object to check for its name-age.</param> - /// <param name="baseTime">The DateTime object to compare to.</param> - /// <returns>The age in days, or -1 in case of an error.</returns> - private int DirNameToAge(DirectoryInfo dir, DateTime baseTime) { - DateTime dirTimestamp; - try { - dirTimestamp = DateTime.ParseExact(dir.Name, "yyyy-MM-dd__HH-mm-ss", - CultureInfo.InvariantCulture); - } - catch (Exception ex) { - writeLogDebug("ERROR parsing timestamp from directory name '" + - dir.Name + "', skipping: " + ex.Message); - return -1; - } - return (baseTime - dirTimestamp).Days; - } - #endregion } } + diff --git a/AutoTx/Email.cs b/AutoTx/Email.cs index 8cee0dde33bdd32b26c47ffd3d9ac7db5d0d53e1..c22fc3b40ae49d5a3ad9aa534dd64a133f690435 100644 --- a/AutoTx/Email.cs +++ b/AutoTx/Email.cs @@ -4,6 +4,7 @@ using System.IO; using System.Linq; using System.Net.Mail; using System.Text; +using ATXCommon; namespace AutoTx { @@ -15,19 +16,19 @@ namespace AutoTx /// <param name="recipient">A full email address OR a valid ActiveDirectory account.</param> /// <param name="subject">The subject, might be prefixed with a configurable string.</param> /// <param name="body">The email body.</param> - public void SendEmail(string recipient, string subject, string body) { + private void SendEmail(string recipient, string subject, string body) { subject = _config.EmailPrefix + subject; if (string.IsNullOrEmpty(_config.SmtpHost)) { - writeLogDebug("SendEmail: " + subject + "\n" + body); + Log.Debug("SendEmail: {0}\n{1}", subject, body); return; } if (!recipient.Contains(@"@")) { - writeLogDebug("Invalid recipient, trying to resolve via AD: " + recipient); - recipient = GetEmailAddress(recipient); + Log.Debug("Invalid recipient, trying to resolve via AD: {0}", recipient); + recipient = ActiveDirectory.GetEmailAddress(recipient); } if (string.IsNullOrWhiteSpace(recipient)) { - writeLogDebug("Invalid or empty recipient given, NOT sending email!"); - writeLogDebug("SendEmail: " + subject + "\n" + body); + Log.Info("Invalid or empty recipient given, NOT sending email!"); + Log.Debug("SendEmail: {0}\n{1}", subject, body); return; } try { @@ -47,9 +48,8 @@ namespace AutoTx smtpClient.Send(mail); } catch (Exception ex) { - writeLog("Error in SendEmail(): " + ex.Message + "\n" + - "InnerException: " + ex.InnerException + "\n" + - "StackTrace: " + ex.StackTrace); + Log.Error("Error in SendEmail(): {0}\nInnerException: {1}\nStackTrace: {2}", + ex.Message, ex.InnerException, ex.StackTrace); } } @@ -60,7 +60,7 @@ namespace AutoTx /// </summary> /// <param name="templateName">The file name of the template, without path.</param> /// <param name="substitions">A list of string-tuples to be used for the search-replace.</param> - /// <returns></returns> + /// <returns>The template with all patterns replaced by their substitution values.</returns> private static string LoadMailTemplate(string templateName, List<Tuple<string, string>> substitions) { var text = File.ReadAllText( Path.Combine(AppDomain.CurrentDomain.BaseDirectory, @@ -71,19 +71,32 @@ namespace AutoTx return text; } + /// <summary> + /// Wrapper method to send an email and log a message using a format string. + /// + /// TODO: Once logging has stabilized we can probably safely remove this method again! + /// </summary> + private void AdminDebugLog(string subject, string format, params object[] list) { + var msg = string.Format(format, list); + SendAdminEmail(msg, subject); + msg = subject + "\n" + msg; + Log.Error(msg); + } + /// <summary> /// Send a notification email to the AdminEmailAdress. /// </summary> /// <param name="body">The email text.</param> /// <param name="subject">Optional subject for the email.</param> - public void SendAdminEmail(string body, string subject = "") { + private void SendAdminEmail(string body, string subject = "") { if (_config.SendAdminNotification == false) return; - var delta = (int)(DateTime.Now - _status.LastAdminNotification).TotalMinutes; + var delta = TimeUtils.MinutesSince(_status.LastAdminNotification); if (delta < _config.AdminNotificationDelta) { - writeLogDebug("Suppressed admin email, interval too short (" + delta + " vs. " + - _config.AdminNotificationDelta + "):\n\n" + subject + "\n" + body); + Log.Warn("Suppressed admin email, interval too short ({0} vs. {1}):\n\n{2}\n{3}", + TimeUtils.MinutesToHuman(delta), + TimeUtils.MinutesToHuman(_config.AdminNotificationDelta), subject, body); return; } @@ -95,7 +108,7 @@ namespace AutoTx body = "Notification from: " + _config.HostAlias + " (" + Environment.MachineName + ")\n\n" + body; - // writeLog("Sending an admin notification email."); + Log.Debug("Sending an admin notification email."); SendEmail(_config.AdminEmailAdress, subject, body); _status.LastAdminNotification = DateTime.Now; @@ -105,12 +118,18 @@ namespace AutoTx /// Send a notification about low drive space to the admin. /// </summary> /// <param name="spaceDetails">String describing the drives being low on space.</param> - public void SendLowSpaceMail(string spaceDetails) { - var delta = (int)(DateTime.Now - _status.LastStorageNotification).TotalMinutes; - if (delta < _config.StorageNotificationDelta) + private void SendLowSpaceMail(string spaceDetails) { + if (string.IsNullOrWhiteSpace(spaceDetails)) return; - writeLog("WARNING: " + spaceDetails); + var delta = TimeUtils.MinutesSince(_status.LastStorageNotification); + if (delta < _config.StorageNotificationDelta) { + Log.Trace("Only {0} since last low-space-notification, skipping.", + TimeUtils.MinutesToHuman(delta)); + return; + } + + Log.Warn("WARNING: {0}", spaceDetails); _status.LastStorageNotification = DateTime.Now; var substitutions = new List<Tuple<string, string>> { @@ -125,7 +144,7 @@ namespace AutoTx SendEmail(_config.AdminEmailAdress, subject, body); } catch (Exception ex) { - writeLog("Error loading email template: " + ex.Message, true); + Log.Error("Error loading email template: {0}", ex.Message); } } @@ -133,7 +152,7 @@ namespace AutoTx /// Send a notification email to the file owner upon successful transfer. /// The recipient address is derived from the global variable CurrentTransferSrc. /// </summary> - public void SendTransferCompletedMail() { + private void SendTransferCompletedMail() { if (_config.SendTransferNotification == false) return; @@ -147,7 +166,7 @@ namespace AutoTx } var substitutions = new List<Tuple<string, string>> { - Tuple.Create("FACILITY_USER", GetFullUserName(userDir)), + Tuple.Create("FACILITY_USER", ActiveDirectory.GetFullUserName(userDir)), Tuple.Create("HOST_ALIAS", _config.HostAlias), Tuple.Create("HOST_NAME", Environment.MachineName), Tuple.Create("DESTINATION_ALIAS", _config.DestinationAlias), @@ -158,10 +177,10 @@ namespace AutoTx try { var body = LoadMailTemplate("Transfer-Success.txt", substitutions); SendEmail(userDir, ServiceName + " - Transfer Notification", body); - writeLogDebug("Sent transfer completed notification to " + userDir); + Log.Debug("Sent transfer completed notification to {0}", userDir); } catch (Exception ex) { - writeLog("Error loading email template: " + ex.Message, true); + Log.Error("Error loading email template: {0}", ex.Message); } } @@ -169,14 +188,14 @@ namespace AutoTx /// Send a notification email when a transfer has been interrupted before completion. /// Recipient address is derived from the global variable CurrentTransferSrc. /// </summary> - public void SendTransferInterruptedMail() { + private void SendTransferInterruptedMail() { if (_config.SendTransferNotification == false) return; var userDir = new DirectoryInfo(_status.CurrentTransferSrc).Name; var substitutions = new List<Tuple<string, string>> { - Tuple.Create("FACILITY_USER", GetFullUserName(userDir)), + Tuple.Create("FACILITY_USER", ActiveDirectory.GetFullUserName(userDir)), Tuple.Create("HOST_ALIAS", _config.HostAlias), Tuple.Create("HOST_NAME", Environment.MachineName), Tuple.Create("EMAIL_FROM", _config.EmailFrom) @@ -189,8 +208,33 @@ namespace AutoTx body); } catch (Exception ex) { - writeLog("Error loading email template: " + ex.Message, true); + Log.Error("Error loading email template: {0}", ex.Message); } } + + /// <summary> + /// Send a report on expired folders in the grace location if applicable. + /// + /// Create a summary of expired folders and send it to the admin address + /// if the configured GraceNotificationDelta has passed since the last email. + /// </summary> + /// <param name="threshold">The number of days used as expiration threshold.</param> + /// <returns>The summary report, empty if no expired folders exist.</returns> + private string SendGraceLocationSummary(int threshold) { + var report = FsUtils.GraceLocationSummary( + new DirectoryInfo(_config.DonePath), threshold); + if (string.IsNullOrEmpty(report)) + return ""; + + var delta = TimeUtils.MinutesSince(_status.LastGraceNotification); + report += "\nTime since last grace notification: " + + TimeUtils.MinutesToHuman(delta) + "\n"; + if (delta < _config.GraceNotificationDelta) + return report; + + _status.LastGraceNotification = DateTime.Now; + SendAdminEmail(report, "Grace location cleanup required."); + return report + "\nNotification sent to AdminEmailAdress.\n"; + } } } \ No newline at end of file diff --git a/AutoTx/Logging.cs b/AutoTx/Logging.cs deleted file mode 100644 index f438fd6aeb21ec0ddb0696428caf298df4d9f39c..0000000000000000000000000000000000000000 --- a/AutoTx/Logging.cs +++ /dev/null @@ -1,81 +0,0 @@ -using System; -using System.IO; - -namespace AutoTx -{ - public partial class AutoTx - { - #region global variables - - private string _logPath; - - #endregion - - /// <summary> - /// Write a message to the log file and optionally send a mail to the admin address. - /// </summary> - /// <param name="message">The text to write into the log.</param> - /// <param name="notify">Send the log message to the admin email as well.</param> - public void writeLog(string message, bool notify = false) { - message = DateTime.Now.ToString("yyyy-MM-dd HH:mm:ss") + ": " + message; - using (var sw = File.AppendText(_logPath)) { - sw.WriteLine(message); - } - if (notify) - SendAdminEmail(message); - } - - /// <summary> - /// Call writeLog() if debug mode is enabled, optionally send an admin notification. - /// </summary> - public void writeLogDebug(string logText, bool notify = false) { - if (_config.Debug) - writeLog("[DEBUG] " + logText, notify); - } - - /// <summary> - /// Check the size of the existing logfiles and trigger rotation if necessary. - /// </summary> - public void CheckLogSize() { - const long logSizeLimit = 1000000; // maximum log file size in bytes - FileInfo logInfo; - try { - logInfo = new FileInfo(_logPath); - } - catch (Exception ex) { - writeLog(ex.Message); - return; - } - if (logInfo.Length <= logSizeLimit) return; - try { - RotateLogFiles("log file size above threshold: " + logInfo.Length + " bytes\n"); - } - catch (Exception ex) { - writeLog(ex.Message); - } - } - - /// <summary> - /// Rotate the existing logfiles. - /// </summary> - /// <param name="message"></param> - public void RotateLogFiles(string message) { - const int maxToKeep = 10; // number of log files to keep - - for (var i = maxToKeep - 2; i >= 0; i--) { - var curName = _logPath + "." + i; - if (i == 0) curName = _logPath; // the current logfile (i==0) should not have a suffix - var newName = _logPath + "." + (i + 1); - if (!File.Exists(curName)) continue; - if (File.Exists(newName)) { - message += "deleting: " + newName + "\n"; - File.Delete(newName); - } - message += "moving " + curName + " to " + newName + "\n"; - File.Move(curName, newName); - } - // This will re-create the current log file: - writeLogDebug(message); - } - } -} \ No newline at end of file diff --git a/AutoTx/RoboCommand.cs b/AutoTx/RoboCommand.cs index 9c04350250e4c07fbf203f383ede0cc2c0a187cb..9fa02ede1c2c4f747d0fa870ded49bc3fc96fb73 100644 --- a/AutoTx/RoboCommand.cs +++ b/AutoTx/RoboCommand.cs @@ -17,6 +17,7 @@ namespace AutoTx /// false. The currently processed path is stored in the global status /// variable CurrentTransferSrc. /// </summary> + /// <param name="sourcePath">The full path to a folder.</param> private void StartTransfer(string sourcePath) { // only proceed when in a valid state: if (_transferState != TxState.Stopped) @@ -27,7 +28,7 @@ namespace AutoTx // the user name is expected to be the last part of the path: _status.CurrentTargetTmp = new DirectoryInfo(sourcePath).Name; - CreateNewDirectory(ExpandCurrentTargetTmp(), false); + FsUtils.CreateNewDirectory(_status.CurrentTargetTmpFull(), false); _transferState = TxState.Active; _status.TransferInProgress = true; @@ -39,7 +40,7 @@ namespace AutoTx // copy options _roboCommand.CopyOptions.Source = sourcePath; - _roboCommand.CopyOptions.Destination = ExpandCurrentTargetTmp(); + _roboCommand.CopyOptions.Destination = _status.CurrentTargetTmpFull(); // limit the transfer bandwidth by waiting between packets: _roboCommand.CopyOptions.InterPacketGap = _config.InterPacketGap; @@ -72,11 +73,11 @@ namespace AutoTx _roboCommand.RetryOptions.RetryCount = 0; _roboCommand.RetryOptions.RetryWaitTime = 2; _roboCommand.Start(); - writeLogDebug("Transfer started, total size: " + - _status.CurrentTransferSize / MegaBytes + " MB"); + Log.Info("Transfer started, total size: {0}", + Conv.BytesToString(_status.CurrentTransferSize)); } catch (ManagementException ex) { - writeLog("Error in StartTransfer(): " + ex.Message); + Log.Error("Error in StartTransfer(): {0}", ex.Message); } } @@ -88,10 +89,10 @@ namespace AutoTx if (_transferState != TxState.Active) return; - writeLog("Pausing the active transfer..."); + Log.Info("Pausing the active transfer..."); _roboCommand.Pause(); _transferState = TxState.Paused; - writeLogDebug("Transfer paused"); + Log.Debug("Transfer paused"); } /// <summary> @@ -102,10 +103,10 @@ namespace AutoTx if (_transferState != TxState.Paused) return; - writeLog("Resuming the paused transfer..."); + Log.Info("Resuming the paused transfer..."); _roboCommand.Resume(); _transferState = TxState.Active; - writeLogDebug("Transfer resumed"); + Log.Debug("Transfer resumed"); } #region robocommand callbacks @@ -123,7 +124,7 @@ namespace AutoTx } } catch (Exception ex) { - writeLog("Error in RsFileProcessed() " + ex.Message); + Log.Error("Error in RsFileProcessed(): {0}", ex.Message); } } @@ -135,7 +136,7 @@ namespace AutoTx return; _roboCommand.Stop(); - writeLogDebug("Transfer stopped"); + Log.Debug("Transfer stopped"); _transferState = TxState.Stopped; _roboCommand.Dispose(); _roboCommand = new RoboCommand(); @@ -153,7 +154,7 @@ namespace AutoTx return; _txProgress = progress; - writeLogDebug("Transfer progress " + progress + "%"); + Log.Debug("Transfer progress {0}%", progress); } #endregion diff --git a/AutoTx/SystemChecks.cs b/AutoTx/SystemChecks.cs deleted file mode 100644 index 6898c00e2b9f1b13bb67eb54ded9dbf0e83bca7d..0000000000000000000000000000000000000000 --- a/AutoTx/SystemChecks.cs +++ /dev/null @@ -1,104 +0,0 @@ -using System; -using System.Diagnostics; -using System.IO; -using System.Management; - -namespace AutoTx -{ - public partial class AutoTx - { - - /// <summary> - /// Get the available physical memory in MB. - /// </summary> - /// <returns>The available physical memory in MB or -1 in case of an error.</returns> - private long GetFreeMemory() { - try { - var searcher = - new ManagementObjectSearcher("SELECT * FROM Win32_OperatingSystem"); - foreach (var mo in searcher.Get()) { - var queryObj = (ManagementObject) mo; - return Convert.ToInt64(queryObj["FreePhysicalMemory"]) / 1024; - } - } - catch (Exception ex) { - writeLog("Error in GetFreeMemory: " + ex.Message); - } - return -1; - } - - /// <summary> - /// Get the CPU usage in percent over all cores. - /// </summary> - /// <returns>CPU usage in percent or -1 if an error occured.</returns> - private int GetCpuUsage() { - try { - var searcher = new ManagementObjectSearcher("select * from Win32_PerfFormattedData_PerfOS_Processor"); - foreach (var mo in searcher.Get()) { - var obj = (ManagementObject) mo; - var usage = obj["PercentProcessorTime"]; - var name = obj["Name"]; - if (name.ToString().Equals("_Total")) return Convert.ToInt32(usage); - } - } - catch (Exception ex) { - writeLog("Error in GetCpuUsage: " + ex.Message); - } - return -1; - } - - /// <summary> - /// Get the free space of a drive in megabytes. - /// </summary> - /// /// <param name="drive">The drive name, e.g. "c:".</param> - /// <returns>Free space of a drive in megabytes, zero if an error occured.</returns> - private long GetFreeDriveSpace(string drive) { - try { - var dInfo = new DriveInfo(drive); - return dInfo.TotalFreeSpace / MegaBytes; - } - catch (Exception ex) { - writeLog("Error in GetFreeDriveSpace(" + drive + "): " + ex.Message); - } - return 0; - } - - /// <summary> - /// Check all configured disks for their free space and send a notification - /// if necessary (depending on the configured delta time). - /// </summary> - public void CheckFreeDiskSpace() { - var msg = ""; - foreach (var driveToCheck in _config.SpaceMonitoring) { - var freeSpace = GetFreeDriveSpace(driveToCheck.DriveName); - if (freeSpace >= driveToCheck.SpaceThreshold) continue; - - msg += "Drive '" + driveToCheck.DriveName + - "' - free space: " + freeSpace + - " (threshold: " + driveToCheck.SpaceThreshold + ")\n"; - } - if (msg != "") - SendLowSpaceMail(msg); - } - - /// <summary> - /// Compares all processes against the ProcessNames in the BlacklistedProcesses list. - /// </summary> - /// <returns>Returns the name of the first matching process, an empty string otherwise.</returns> - public string CheckForBlacklistedProcesses() { - foreach (var running in Process.GetProcesses()) { - try { - foreach (var blacklisted in _config.BlacklistedProcesses) { - if (running.ProcessName.ToLower().Equals(blacklisted)) { - return blacklisted; - } - } - } - catch (Exception ex) { - writeLog("Error in checkProcesses() " + ex.Message); - } - } - return ""; - } - } -} \ No newline at end of file diff --git a/AutoTx/packages.config b/AutoTx/packages.config new file mode 100644 index 0000000000000000000000000000000000000000..8e85834c00cf96bfe4c3616778bd12559d331c59 --- /dev/null +++ b/AutoTx/packages.config @@ -0,0 +1,4 @@ +<?xml version="1.0" encoding="utf-8"?> +<packages> + <package id="NLog" version="4.3.11" targetFramework="net45" /> +</packages> \ No newline at end of file