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 Sockeye.Util; //using StackExchange.Profiling; namespace Sockeye { 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($"SOCKEYE SERVER {SockeyeVersion.VersionString} BOOTING ..."); //Boot lock for generator ServerGlobalOpsSettingsCache.BOOTING = true; //preset, we don't know yet ServerGlobalOpsSettingsCache.DBAVAILABLE = false; //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 SockeyeConfig = config.AsEnumerable().Where(z => z.Key.StartsWith("SOCKEYE") && z.Key != "SOCKEYE_JWT_SECRET" && z.Key != "SOCKEYE_SET_SUPERUSER_PW").Select(z => z.Key + "=" + z.Value).ToList(); var DiagConfig = string.Join(",", SockeyeConfig); 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.SOCKEYE_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); //removed redundant in production use and duplicates lot unnecessarily // //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.SOCKEYE_LOG_PATH, "log-sockeye.txt"); fileTarget.Layout = "${longdate}|${uppercase:${level}}|${logger}|${message:exceptionSeparator==>:withException=true}"; fileTarget.ArchiveFileName = Path.Combine(ServerBootConfig.SOCKEYE_LOG_PATH, "log-sockeye-{#}.txt"); fileTarget.ArchiveNumbering = ArchiveNumberingMode.Rolling;//so expect to see 1 to 10 or 0 to ten as may be fileTarget.ArchiveAboveSize = 1000000;//1mb maximum file size fileTarget.MaxArchiveFiles = 9;//max 10 files totalling 10mb, the current log-sockeye.txt and log-sockeye-[0-9].txt // 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 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 logRuleSockeyeItems = new LoggingRule("*", NLogLevel, fileTarget); //Removed due to filling up redundently a system log like systemd in linux // //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(logRuleSockeyeItems); //Turn on internal logging: if (ServerBootConfig.SOCKEYE_LOG_ENABLE_LOGGER_DIAGNOSTIC_LOG) { NLog.Common.InternalLogger.LogFile = "log-sockeye-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($"SOCKEYE SERVER {SockeyeVersion.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.SOCKEYE_LOG_ENABLE_LOGGER_DIAGNOSTIC_LOG) logger.Warn("SOCKEYE_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.SOCKEYE_BACKUP_FILES_PATH}] ######"); UtilityFilesAvailableSpace = new System.IO.DriveInfo(Path.GetPathRoot(ServerBootConfig.SOCKEYE_BACKUP_FILES_PATH)).AvailableFreeSpace; } catch (Exception ex) { logger.Error(ex, $"BOOT::FileUtil::UtilityFilesDriveAvailableSpace error getting available space from [{Path.GetPathRoot(ServerBootConfig.SOCKEYE_BACKUP_FILES_PATH)}]"); } long AttachmentFilesAvailableSpace = 0; try { AttachmentFilesAvailableSpace = new System.IO.DriveInfo(Path.GetPathRoot(ServerBootConfig.SOCKEYE_ATTACHMENT_FILES_PATH)).AvailableFreeSpace; } catch (Exception ex) { logger.Error(ex, $"BOOT::FileUtil::AttachmentFilesDriveAvailableSpace error getting available space from [{Path.GetPathRoot(ServerBootConfig.SOCKEYE_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("Available data storage - {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("Sockeye 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("Available data storage", FileUtil.GetBytesReadable(AttachmentFilesAvailableSpace)); //Test for web root path //If user starts Sockeye from folder that is not the contentRoot then //Sockeye won't be able to serve static files if (!Directory.Exists(Path.Combine(startFolder, "wwwroot"))) { var err = string.Format("E1010 - Sockeye was not started in the correct folder. Sockeye 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 - Sockeye 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("Sockeye 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.SOCKEYE_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