using System; using System.Collections.Generic; using System.IO; using System.Linq; using Microsoft.AspNetCore.Hosting; using Microsoft.Extensions.Hosting; using Microsoft.Extensions.Configuration; using Microsoft.Extensions.Logging; using NLog.Web; using NLog.Targets; using NLog.Config; using AyaNova.Util; //using StackExchange.Profiling; namespace AyaNova { public class Program { public static void Main(string[] args) { //https://github.com/npgsql/efcore.pg/issues/2045 //https://www.npgsql.org/efcore/release-notes/6.0.html#breaking-changes //AppContext.SetSwitch("Npgsql.EnableLegacyTimestampBehavior", true); //first output Console.WriteLine($"AYANOVA SERVER {AyaNovaVersion.VersionString} BOOTING ..."); //Boot lock for generator ServerGlobalOpsSettingsCache.BOOTING = true; //Get config var config = new ConfigurationBuilder().AddJsonFile("config.json", true).AddEnvironmentVariables().AddCommandLine(args).Build(); //Set config or bail with error for missing items try { ServerBootConfig.SetConfiguration(config); } catch (Exception ex) { Console.WriteLine($"Unable to boot due to configuration error: {ex.Message}"); return; } try { FileUtil.EnsureUserAndUtilityFoldersExistAndAreNotIdentical(); } catch (Exception ex) { Console.WriteLine($"Unable to locate or create server file folders error was: {ex.Message}"); return; } //Human readable config output to console for diagnosis in case server wont' start var AyaNovaConfig = config.AsEnumerable().Where(z => z.Key.StartsWith("AYANOVA") && z.Key != "AYANOVA_JWT_SECRET" && z.Key != "AYANOVA_SET_SUPERUSER_PW").Select(z => z.Key + "=" + z.Value).ToList(); var DiagConfig = string.Join(",", AyaNovaConfig); DiagConfig = DbUtil.PasswordRedactedConnectionString(DiagConfig); Console.WriteLine($"Config {DiagConfig}"); #region Initialize Logging //NOTE: there is a logging issue that breaks all this with .net 3.1 hostbuilder vs webhostbuilder but webhostbuilder will be deprecated so we need to work around it //the discussion about that is here: https://github.com/aspnet/AspNetCore/issues/9337 //I think I worked around it //NLOG OFFICIAL GUIDELINES FOR .net core 3.x https://github.com/NLog/NLog/wiki/Getting-started-with-ASP.NET-Core-3 //default log level NLog.LogLevel NLogLevel = NLog.LogLevel.Info; bool FilterOutMicrosoftLogItems = true; switch (ServerBootConfig.AYANOVA_LOG_LEVEL.ToLowerInvariant()) { case "fatal": NLogLevel = NLog.LogLevel.Fatal; break; case "error": NLogLevel = NLog.LogLevel.Error; break; case "warn": NLogLevel = NLog.LogLevel.Warn; break; case "info": NLogLevel = NLog.LogLevel.Info; break; case "debug": NLogLevel = NLog.LogLevel.Debug; break; case "trace": NLogLevel = NLog.LogLevel.Trace; FilterOutMicrosoftLogItems = false;//Only at TRACE level do we want to see all the Microsoft logging stuff break; default: NLogLevel = NLog.LogLevel.Info; break; } // Step 1. Create configuration object var logConfig = new LoggingConfiguration(); // Step 2. Create targets and add them to the configuration var fileTarget = new FileTarget(); logConfig.AddTarget("file", fileTarget); //console target for really serious errors only var consoleTarget = new ConsoleTarget(); logConfig.AddTarget("console", consoleTarget); var nullTarget = new NLog.Targets.NullTarget(); logConfig.AddTarget("blackhole", nullTarget); // Step 3. Set target properties fileTarget.FileName = Path.Combine(ServerBootConfig.AYANOVA_LOG_PATH, "log-ayanova.txt"); fileTarget.Layout = "${longdate}|${uppercase:${level}}|${logger}|${message:exceptionSeparator==>:withException=true}"; fileTarget.ArchiveFileName = Path.Combine(ServerBootConfig.AYANOVA_LOG_PATH, "log-ayanova-{#}.txt"); fileTarget.ArchiveNumbering = ArchiveNumberingMode.Date; fileTarget.ArchiveEvery = FileArchivePeriod.Wednesday; fileTarget.MaxArchiveFiles = 3; // Step 4. Define rules //filter out all Microsoft INFO level logs as they are too much var logRuleFilterOutMicrosoft = new LoggingRule("Microsoft.*", NLog.LogLevel.Trace, NLog.LogLevel.Info, nullTarget); logRuleFilterOutMicrosoft.Final = true; //filter out httpclient logs at INFO level //2020-01-28 11:19:12.8767|INFO|System.Net.Http.HttpClient.Default.LogicalHandler|Start processing HTTP request GET https://rockfish.ayanova.com/rvf/a6d18a8a-5613-4979-99da-80d07641a2fe var logRuleFilterOutHttpClient = new LoggingRule("System.Net.Http.HttpClient.Default.*", NLog.LogLevel.Trace, NLog.LogLevel.Info, nullTarget); logRuleFilterOutHttpClient.Final = true; //filter out all Microsoft EF CORE concurrency exceptions, it's a nuisance unless debugging or something //This is what I have to filter because it's the top exception: Microsoft.EntityFrameworkCore.Update //But this is what I'm actually trying to filter: Microsoft.EntityFrameworkCore.DbUpdateConcurrencyException //however there doesn't appear to be a way to filter out based on content so... var logRuleFilterOutMicrosoftEfCoreConcurrencyExceptions = new LoggingRule("Microsoft.EntityFrameworkCore.Update", NLog.LogLevel.Trace, NLog.LogLevel.Error, nullTarget); logRuleFilterOutMicrosoftEfCoreConcurrencyExceptions.Final = true; var logRuleFilterOutMicrosoftEfCoreCommandExceptions = new LoggingRule("Microsoft.EntityFrameworkCore.Database.Command", NLog.LogLevel.Trace, NLog.LogLevel.Error, nullTarget); logRuleFilterOutMicrosoftEfCoreCommandExceptions.Final = true; var logRuleFilterOutMicrosoftEfCoreDbUpdateExceptions = new LoggingRule("Microsoft.EntityFrameworkCore.DbUpdateException", NLog.LogLevel.Trace, NLog.LogLevel.Error, nullTarget); logRuleFilterOutMicrosoftEfCoreDbUpdateExceptions.Final = true; //this rule is only intended to filter out this incorrect exception: //2019-01-16 16:13:03.4808|WARN|Microsoft.EntityFrameworkCore.Query|Query: '(from Widget _4 in DbSet select [_4]).Skip(__p_1).Take(__p_2)' uses a row limiting operation (Skip/Take) without OrderBy which may lead to unpredictable results. var logRuleFilterOutMicrosoftEfCoreQueryExceptions = new LoggingRule("Microsoft.EntityFrameworkCore.Query", NLog.LogLevel.Trace, NLog.LogLevel.Error, nullTarget); logRuleFilterOutMicrosoftEfCoreQueryExceptions.Final = true; //Log all other regular items at selected level var logRuleAyaNovaItems = new LoggingRule("*", NLogLevel, fileTarget); //Log error or above to console var logRuleForConsole = new LoggingRule("*", NLog.LogLevel.Error, consoleTarget); //add console serious error only log rule logConfig.LoggingRules.Add(logRuleForConsole); //only log microsoft stuff it log is debug level or lower if (FilterOutMicrosoftLogItems) { //filter OUT microsoft stuff logConfig.LoggingRules.Add(logRuleFilterOutMicrosoft); logConfig.LoggingRules.Add(logRuleFilterOutMicrosoftEfCoreConcurrencyExceptions); logConfig.LoggingRules.Add(logRuleFilterOutMicrosoftEfCoreCommandExceptions); logConfig.LoggingRules.Add(logRuleFilterOutMicrosoftEfCoreDbUpdateExceptions); logConfig.LoggingRules.Add(logRuleFilterOutMicrosoftEfCoreQueryExceptions); //also httpclient stuff logConfig.LoggingRules.Add(logRuleFilterOutHttpClient); } logConfig.LoggingRules.Add(logRuleAyaNovaItems); //Turn on internal logging: if (ServerBootConfig.AYANOVA_LOG_ENABLE_LOGGER_DIAGNOSTIC_LOG) { NLog.Common.InternalLogger.LogFile = "log-ayanova-logger.txt"; NLog.Common.InternalLogger.LogLevel = NLog.LogLevel.Debug; } // NLog: setup the logger first to catch all errors var logger = NLogBuilder.ConfigureNLog(logConfig).GetLogger("BOOT"); #endregion //This is the first log entry logger.Info($"AYANOVA SERVER {AyaNovaVersion.VersionString} BOOTING"); #if (DEBUG) logger.Info($"### DEBUG ONLY - Linker timestamp is {Util.FileUtil.GetLinkerTimestampUtc(System.Reflection.Assembly.GetExecutingAssembly())}"); #endif //log configuration logger.Info($"Config {DiagConfig}"); logger.Debug($"Full configuration is {config.GetDebugView()}"); if (ServerBootConfig.AYANOVA_LOG_ENABLE_LOGGER_DIAGNOSTIC_LOG) logger.Warn("AYANOVA_LOG_ENABLE_LOGGER_DIAGNOSTIC_LOG is enabled, this will cause the server to run very slowly"); //Log environmental settings long UtilityFilesAvailableSpace = 0; try { // Console.WriteLine($"##### program:about to call backupfilesdriveavailablespace, config is [{ServerBootConfig.AYANOVA_BACKUP_FILES_PATH}] ######"); UtilityFilesAvailableSpace = new System.IO.DriveInfo(Path.GetPathRoot(ServerBootConfig.AYANOVA_BACKUP_FILES_PATH)).AvailableFreeSpace; } catch (Exception ex) { logger.Error(ex, $"BOOT::FileUtil::UtilityFilesDriveAvailableSpace error getting available space from [{Path.GetPathRoot(ServerBootConfig.AYANOVA_BACKUP_FILES_PATH)}]"); } long AttachmentFilesAvailableSpace = 0; try { AttachmentFilesAvailableSpace = new System.IO.DriveInfo(Path.GetPathRoot(ServerBootConfig.AYANOVA_ATTACHMENT_FILES_PATH)).AvailableFreeSpace; } catch (Exception ex) { logger.Error(ex, $"BOOT::FileUtil::AttachmentFilesDriveAvailableSpace error getting available space from [{Path.GetPathRoot(ServerBootConfig.AYANOVA_ATTACHMENT_FILES_PATH)}]"); } //Get boot up folder for logging and later check for wwwroot string startFolder = Directory.GetCurrentDirectory(); logger.Info("Boot path - {0}", startFolder); logger.Info("OS - {0}", Environment.OSVersion.ToString()); logger.Info("TimeZone - {0}", TimeZoneInfo.Local.DisplayName); logger.Info("OS Locale - {0}", System.Globalization.CultureInfo.CurrentCulture.EnglishName); logger.Info("Machine - {0}", Environment.MachineName); logger.Info("User - {0}", Environment.UserName); logger.Info(".Net Version - {0}", Environment.Version.ToString()); logger.Debug("CPU count - {0}", Environment.ProcessorCount); logger.Debug("RAM - {0}", FileUtil.GetBytesReadable(GC.GetGCMemoryInfo().TotalAvailableMemoryBytes)); logger.Debug("Backup file space - {0}", FileUtil.GetBytesReadable(UtilityFilesAvailableSpace)); logger.Debug("Attachments file space - {0}", FileUtil.GetBytesReadable(AttachmentFilesAvailableSpace)); ServerBootConfig.BOOT_DIAGNOSTIC_INFO.Add("Boot path", startFolder); ServerBootConfig.BOOT_DIAGNOSTIC_INFO.Add("OS", Environment.OSVersion.ToString()); ServerBootConfig.BOOT_DIAGNOSTIC_INFO.Add("Machine", Environment.MachineName); ServerBootConfig.BOOT_DIAGNOSTIC_INFO.Add("User", Environment.UserName); ServerBootConfig.BOOT_DIAGNOSTIC_INFO.Add(".Net Version", Environment.Version.ToString()); ServerBootConfig.BOOT_DIAGNOSTIC_INFO.Add("CPU count", Environment.ProcessorCount.ToString()); ServerBootConfig.BOOT_DIAGNOSTIC_INFO.Add("AyaNova server boot local time", DateTime.Now.ToString("s")); ServerBootConfig.BOOT_DIAGNOSTIC_INFO.Add("Server up time", TimeSpan.FromTicks(Environment.TickCount64).ToString()); ServerBootConfig.BOOT_DIAGNOSTIC_INFO.Add("TimeZone", TimeZoneInfo.Local.DisplayName); ServerBootConfig.BOOT_DIAGNOSTIC_INFO.Add("OS Locale", System.Globalization.CultureInfo.CurrentCulture.EnglishName); ServerBootConfig.BOOT_DIAGNOSTIC_INFO.Add("RAM", FileUtil.GetBytesReadable(GC.GetGCMemoryInfo().TotalAvailableMemoryBytes)); ServerBootConfig.BOOT_DIAGNOSTIC_INFO.Add("Backup space", FileUtil.GetBytesReadable(UtilityFilesAvailableSpace)); ServerBootConfig.BOOT_DIAGNOSTIC_INFO.Add("Attachments space", FileUtil.GetBytesReadable(AttachmentFilesAvailableSpace)); //Test for web root path //If user starts AyaNova from folder that is not the contentRoot then //AyaNova won't be able to serve static files if (!Directory.Exists(Path.Combine(startFolder, "wwwroot"))) { var err = string.Format("E1010 - AyaNova was not started in the correct folder. AyaNova must be started from the folder that contains the \"wwwroot\" folder but was started instead from this folder: \"{0}\" which does not contain the wwwroot folder.", startFolder); logger.Fatal(err); throw new System.ApplicationException(err); } try { //BuildWebHost(args, logger).Run(); BuildHost(args, logger).Build().Run(); } catch (Exception e) { logger.Fatal(e, "E1090 - AyaNova server can't start due to unexpected exception during initialization"); //throw; } finally { // Ensure to flush and stop internal timers/threads before application-exit (Avoid segmentation fault on Linux) logger.Info("AyaNova server shutting down"); NLog.LogManager.Shutdown(); } } public static IHostBuilder BuildHost(string[] args, NLog.Logger logger) { logger.Trace("Building host"); var configuration = new ConfigurationBuilder().AddCommandLine(args).Build(); return Host.CreateDefaultBuilder(args) .ConfigureWebHostDefaults(webBuilder => { webBuilder .UseSetting("detailedErrors", "true") .UseUrls(ServerBootConfig.AYANOVA_USE_URLS)//default port and urls, set first can be overridden by any later setting here .UseConfiguration(configuration)//support command line override of port (dotnet run urls=http://*:8081) .UseIISIntegration()//support IIS integration just in case, it appears here to override prior settings if necessary (port) .UseStartup() .ConfigureLogging((context, logging) => { // clear all previously registered providers //https://stackoverflow.com/a/46336988/8939 logging.ClearProviders(); }) .UseNLog(); // NLog: setup NLog for Dependency injection }); } }//eoc }//eons