Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Simplify logging in boot sequence #2003

Merged
merged 9 commits into from
Jan 8, 2024
Merged

Simplify logging in boot sequence #2003

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
9 commits
Select commit Hold shift + click to select a range
870f23c
Use ILogger instead of SnLog in strtup sequence (part 1).
kavics Jan 3, 2024
4af033e
Use ILogger: DistributedIndexingActivityQueue, startup.
kavics Jan 3, 2024
2735cc5
Use ILogger instead of SnLog in startup sequence (part 3).
kavics Jan 4, 2024
65e885f
Use ILogger instead of SnLog in startup sequence (part 4).
kavics Jan 4, 2024
6eb2a74
Refactor: comments removed.
kavics Jan 4, 2024
6d9f65e
Do not echo console message to sntrace unconditionally.
kavics Jan 4, 2024
be4e383
Use ILogger instead of SnLog in startup sequence (part 5).
kavics Jan 4, 2024
c715136
refactor
kavics Jan 4, 2024
9fc7576
Merge branch 'develop' into improved-logging
tusmester Jan 8, 2024
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
27 changes: 20 additions & 7 deletions src/ContentRepository/LoggingSettings.cs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -2,7 +2,9 @@
using System.Collections.Generic;
using System.Linq;
using System.Threading;
using STT=System.Threading.Tasks;
using Microsoft.Extensions.Logging;
using Microsoft.Extensions.DependencyInjection;
using STT =System.Threading.Tasks;
using SenseNet.Communication.Messaging;
using SenseNet.Configuration;
using SenseNet.ContentRepository.Schema;
Expand Down Expand Up @@ -91,17 +93,15 @@ public static void UpdateCategoriesBySettings()
category.Enabled = value ?? _basicCategories[category.Name];
}

SnLog.WriteInformation("Trace settings were updated (from settings).", EventId.RepositoryRuntime,
properties: SnTrace.Categories.ToDictionary(c => c.Name, c => (object)c.Enabled.ToString()));
WriteInformation("settings");
}

public static void ConfigureCategories()
{
foreach (var category in SnTrace.Categories)
category.Enabled = Tracing.StartupTraceCategories.Contains(category.Name);

SnLog.WriteInformation("Trace settings were updated (from configuration).", EventId.RepositoryRuntime,
properties: SnTrace.Categories.ToDictionary(c => c.Name, c => (object)c.Enabled.ToString()));
WriteInformation("configuration");

UpdateBasicCategories();
}
Expand All @@ -127,14 +127,27 @@ internal static void UpdateCategories(string[] categoryNames)

UpdateBasicCategories();

SnLog.WriteInformation("Trace settings were updated (from assembly).", EventId.RepositoryRuntime,
properties: SnTrace.Categories.ToDictionary(c => c.Name, c => (object)c.Enabled.ToString()));
WriteInformation("assembly");
}

private static void UpdateBasicCategories()
{
_basicCategories = SnTrace.Categories.ToDictionary(c => c.Name, c => c.Enabled);
}

private static void WriteInformation(string source)
{
var logger = Providers.Instance?.Services.GetService<ILogger<LoggingSettings>>();
logger?.LogInformation($"Trace settings were updated (from {source}). " +
$"Enabled: {CategoriesToString(true)}. " +
$"Disabled: {CategoriesToString(false)}");
}
private static string CategoriesToString(bool isEnabled)
{
return string.Join(", ", SnTrace.Categories
.Where(x => x.Enabled == isEnabled)
.Select(x => x.Name));
}
}
}
}
119 changes: 64 additions & 55 deletions src/ContentRepository/RepositoryInstance.cs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -8,13 +8,15 @@
using System.IO;
using System.Threading;
using Microsoft.Extensions.DependencyInjection;
using Microsoft.Extensions.Logging;
using SenseNet.Communication.Messaging;
using SenseNet.Configuration;
using SenseNet.ContentRepository.Schema;
using SenseNet.ContentRepository.Storage.Security;
using SenseNet.Search.Querying;
using SenseNet.TaskManagement.Core;
using SenseNet.Tools;
using EventId = SenseNet.Diagnostics.EventId;

namespace SenseNet.ContentRepository
{
Expand Down Expand Up @@ -70,14 +72,15 @@ public class StartupInfo
/// Gets the started up instance or null.
/// </summary>
public static RepositoryInstance Instance { get { return _instance; } }

public TextWriter Console => _settings?.Console;

private RepositoryInstance()
{
_startupInfo = new StartupInfo { Starting = DateTime.UtcNow };
}

private ILogger<RepositoryInstance> _logger;
private static bool _started;
internal static RepositoryInstance Start(RepositoryStartSettings settings)
{
Expand All @@ -90,6 +93,7 @@ internal static RepositoryInstance Start(RepositoryStartSettings settings)
var instance = new RepositoryInstance();
instance._settings = new RepositoryStartSettings.ImmutableRepositoryStartSettings(settings);
_instance = instance;
_instance._logger = instance._settings.Services.GetService<ILogger<RepositoryInstance>>();
try
{
instance.DoStart();
Expand All @@ -107,9 +111,9 @@ internal static RepositoryInstance Start(RepositoryStartSettings settings)
}
internal void DoStart()
{
ConsoleWriteLine();
ConsoleWriteLine("Starting Repository...");
ConsoleWriteLine();
ConsoleWriteLine(false);
ConsoleWriteLine(true, "Starting Repository.");
ConsoleWriteLine(false);

LoggingSettings.SnTraceConfigurator.ConfigureCategories();
if (_settings.TraceCategories != null)
Expand Down Expand Up @@ -138,16 +142,15 @@ internal void DoStart()

// We have to log the access provider here because it cannot be logged
// during creation as it would lead to a circular reference.
SnLog.WriteInformation($"AccessProvider created: {AccessProvider.Current?.GetType().FullName}");

_logger.LogInformation($"AccessProvider created: {AccessProvider.Current?.GetType().FullName}");
using (new SystemAccount())
StartManagers();

LoggingSettings.SnTraceConfigurator.UpdateCategoriesBySettings();

ConsoleWriteLine();
ConsoleWriteLine("Repository has started.");
ConsoleWriteLine();
ConsoleWriteLine(false);
ConsoleWriteLine(true, "Repository has started.");
ConsoleWriteLine(false);

_startupInfo.Started = DateTime.UtcNow;
}
Expand All @@ -159,13 +162,13 @@ public void StartIndexingEngine()
{
if (IndexingEngineIsRunning)
{
ConsoleWrite("IndexingEngine has already started.");
ConsoleWrite(true, "IndexingEngine has already started.");
return;
}
ConsoleWriteLine("Starting IndexingEngine:");
ConsoleWriteLine(true, "Starting IndexingEngine.");
Providers.Instance.IndexManager.StartAsync(_settings.Console, CancellationToken.None).GetAwaiter().GetResult();
Providers.Instance.SearchManager.SearchEngine.SetIndexingInfo(ContentTypeManager.Instance.IndexingInfo);
ConsoleWriteLine("IndexingEngine has started.");
ConsoleWriteLine(true, "IndexingEngine has started.");
}

private bool _workflowEngineIsRunning;
Expand All @@ -176,21 +179,23 @@ public void StartWorkflowEngine()
{
if (_workflowEngineIsRunning)
{
ConsoleWrite("Workflow engine has already started.");
ConsoleWrite(true, "Workflow engine has already started.");
return;
}
ConsoleWrite("Starting Workflow subsystem ... ");
ConsoleWrite(false, "Starting Workflow subsystem ... ");
var t = TypeResolver.GetType("SenseNet.Workflow.InstanceManager", false);
if (t != null)
{
var m = t.GetMethod("StartWorkflowSystem", BindingFlags.Static | BindingFlags.Public);
m.Invoke(null, new object[0]);
_workflowEngineIsRunning = true;
ConsoleWriteLine("ok.");
ConsoleWriteLine(false, "ok.");
SnTrace.System.Write("Workflow subsystem started.");
}
else
{
ConsoleWriteLine("NOT STARTED");
ConsoleWriteLine(false, "NOT STARTED");
SnTrace.System.Write("Workflow subsystem NOT STARTED.");
}
}

Expand All @@ -203,25 +208,25 @@ private void LoadAssemblies(bool isWebContext)

if (!isWebContext)
{
ConsoleWriteLine("Loading Assemblies from ", localBin, ":");
ConsoleWriteLine(false, "Loading Assemblies from ", localBin, ":");
asmNames = TypeResolver.LoadAssembliesFrom(localBin);
foreach (string name in asmNames)
ConsoleWriteLine(" ", name);
ConsoleWriteLine(false, " ", name);
}

_startupInfo.ReferencedAssemblies = GetLoadedAsmNames().Except(_startupInfo.AssembliesBeforeStart).ToArray();

ConsoleWriteLine("Loading Assemblies from ", pluginsPath, ":");
ConsoleWriteLine(false, "Loading Assemblies from ", pluginsPath, ":");
asmNames = TypeResolver.LoadAssembliesFrom(pluginsPath);
_startupInfo.Plugins = GetLoadedAsmNames().Except(_startupInfo.AssembliesBeforeStart).Except(_startupInfo.ReferencedAssemblies).ToArray();

if (_settings.Console == null)
return;

foreach (string name in asmNames)
ConsoleWriteLine(" ", name);
ConsoleWriteLine("Ok.");
ConsoleWriteLine();
ConsoleWriteLine(false, " ", name);
ConsoleWriteLine(false, "Ok.");
ConsoleWriteLine(false);
}
private IEnumerable<string> GetLoadedAsmNames()
{
Expand All @@ -234,63 +239,68 @@ private void StartManagers()

try
{
ConsoleWrite("Initializing cache ... ");
ConsoleWrite(false, "Initializing cache ... ");
dummy = Cache.Count;

// Log this, because logging is switched off when creating the cache provider
// to avoid circular reference.
SnLog.WriteInformation($"CacheProvider created: {Cache.Instance?.GetType().FullName}");
ConsoleWriteLine("ok.");
_logger.LogInformation($"CacheProvider created: {Cache.Instance?.GetType().FullName}");
ConsoleWriteLine(false, "ok.");
SnTrace.System.Write("Cache initialized.");

ConsoleWrite("Starting message channel ... ");
ConsoleWrite(false, "Starting message channel ... ");
channel = Providers.Instance.ClusterChannelProvider;
channel.StartAsync(CancellationToken.None).GetAwaiter().GetResult();

ConsoleWriteLine("ok.");
SnLog.WriteInformation($"Message channel {channel.GetType().FullName} started." +
ConsoleWriteLine(false, "ok.");
_logger.LogInformation($"Message channel started: {channel.GetType().FullName}. " +
$"Instance id: {channel.ClusterMemberInfo.InstanceID}");

ConsoleWrite("Sending greeting message ... ");
ConsoleWrite(false, "Sending greeting message ... ");
new PingMessage(new string[0]).SendAsync(CancellationToken.None).GetAwaiter().GetResult();
ConsoleWriteLine("ok.");
ConsoleWriteLine(false, "ok.");
SnTrace.System.Write("Greeting message sent (PingMessage).");

ConsoleWrite("Starting NodeType system ... ");
ConsoleWrite(false, "Starting NodeType system ... ");
dummy = Providers.Instance.StorageSchema.NodeTypes[0];
ConsoleWriteLine("ok.");
ConsoleWriteLine(false, "ok.");
SnTrace.System.Write("NodeType system started.");

ConsoleWrite("Starting ContentType system ... ");
ConsoleWrite(false, "Starting ContentType system ... ");
dummy = ContentType.GetByName("GenericContent");
ConsoleWriteLine("ok.");
ConsoleWriteLine(false, "ok.");
SnTrace.System.Write("ContentType system started.");

ConsoleWrite("Starting AccessProvider ... ");
ConsoleWrite(false, "Starting AccessProvider ... ");
dummy = User.Current;
ConsoleWriteLine("ok.");
ConsoleWriteLine(false, "ok.");
SnTrace.System.Write("AccessProvider started.");

SnQuery.SetPermissionFilterFactory(Providers.Instance.PermissionFilterFactory);

if (_settings.StartIndexingEngine)
StartIndexingEngine();
else
ConsoleWriteLine("IndexingEngine is not started.");
ConsoleWriteLine(true, "IndexingEngine is not started.");

// switch on message processing after IndexingEngine was started.
channel.AllowMessageProcessing = true;

if (_settings.StartWorkflowEngine)
StartWorkflowEngine();
else
ConsoleWriteLine("Workflow subsystem is not started.");
ConsoleWriteLine(true, "Workflow subsystem is not started.");

ConsoleWrite("Loading string resources ... ");
ConsoleWrite(false, "Loading string resources ... ");
dummy = SenseNetResourceManager.Current;
ConsoleWriteLine("ok.");
ConsoleWriteLine(false, "ok.");
SnTrace.System.Write("String resources loaded.");

_serviceInstances = _settings.Services.GetServices<ISnService>().ToList();

foreach (var service in _serviceInstances)
{
service.Start();
ConsoleWriteLine("Service started: ", service.GetType().Name);
ConsoleWriteLine(true, "Service started: " + service.GetType().Name);
}

// register this application in the task management component
Expand Down Expand Up @@ -322,11 +332,9 @@ private static void InitializeLogger()
SnTrace.SnTracers.AddRange(tracers);
}

SnLog.WriteInformation("Loggers and tracers initialized.", properties: new Dictionary<string, object>
{
{ "Loggers", SnLog.Instance?.GetType().Name },
{ "Tracers", string.Join(", ", SnTrace.SnTracers.Select(snt => snt?.GetType().Name)) }
});
SnTrace.System.Write("Loggers and tracers initialized. " +
$"Loggers: {SnLog.Instance?.GetType().Name}. " +
$"Tracers: {string.Join(", ", SnTrace.SnTracers.Select(snt => snt?.GetType().Name))}");
}

private void RegisterAppdomainEventHandlers()
Expand Down Expand Up @@ -390,9 +398,9 @@ internal static void Shutdown()

SnTrace.Repository.Write("Sending a goodbye message.");

_instance.ConsoleWriteLine();
_instance.ConsoleWriteLine(false);

_instance.ConsoleWriteLine("Sending a goodbye message...");
_instance.ConsoleWriteLine(true, "Sending a goodbye message.");
var channel = Providers.Instance.ClusterChannelProvider;
channel.ClusterMemberInfo.NeedToRecover = false;
var pingMessage = new PingMessage();
Expand Down Expand Up @@ -421,26 +429,27 @@ internal static void Shutdown()
SnTrace.Repository.Write(msg);
SnTrace.Flush();

_instance.ConsoleWriteLine(msg);
_instance.ConsoleWriteLine();
_instance.ConsoleWriteLine(false, msg);
_instance.ConsoleWriteLine(false);
SnLog.WriteInformation(msg);

_instance = null;
_started = false;
}
}

public void ConsoleWrite(params string[] text)
public void ConsoleWrite(bool trace, params string[] text)
{
foreach (var s in text)
{
SnTrace.System.Write(s);
if(trace)
SnTrace.System.Write(s);
_settings.Console?.Write(s);
}
}
public void ConsoleWriteLine(params string[] text)
public void ConsoleWriteLine(bool trace, params string[] text)
{
ConsoleWrite(text);
ConsoleWrite(trace, text);
_settings.Console?.WriteLine();
}

Expand Down
8 changes: 7 additions & 1 deletion src/ContentRepository/Schema/ContentTypeManager.cs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -20,6 +20,9 @@
using SenseNet.Search.Indexing;
using SenseNet.Tools;
using STT=System.Threading.Tasks;
using Microsoft.Extensions.DependencyInjection;
using Microsoft.Extensions.Logging;
using EventId = SenseNet.Diagnostics.EventId;

namespace SenseNet.ContentRepository.Schema
{
Expand Down Expand Up @@ -49,6 +52,7 @@ public override STT.Task DoActionAsync(bool onRemote, bool isFromMe, Cancellatio
private static bool _initializing = false;

private const string ContentTypeManagerProviderKey = "ContentTypeManager";
private ILogger<ContentTypeManager> _logger;

[Obsolete("Use Instace instead.")]
public static ContentTypeManager Current => Instance;
Expand All @@ -71,7 +75,7 @@ public static ContentTypeManager Instance
contentTypeManager = ctm;
_initializing = false;
Providers.Instance.SetProvider(ContentTypeManagerProviderKey, ctm);
SnLog.WriteInformation("ContentTypeManager created. Content types: " + ctm._contentTypes.Count);
contentTypeManager._logger.LogInformation("ContentTypeManager created. Content types: " + ctm._contentTypes.Count);
}
}
}
Expand Down Expand Up @@ -149,6 +153,8 @@ private static void Node_AnyContentListDeleted(object sender, EventArgs e)

private void Initialize()
{
_logger = Providers.Instance.Services.GetRequiredService<ILogger<ContentTypeManager>>();

using (new SenseNet.ContentRepository.Storage.Security.SystemAccount())
{
_contentPaths = new Dictionary<string, string>();
Expand Down
Loading