Jam*_*lls 5 c# log4net windows-services topshelf
我已经使用TopShelf创建了一个Windows 服务，使用Log4Net添加了日志记录，然后构建了项目，安装了服务并启动了服务。然后我的服务运行良好，但没有记录。该TopShelf日志出现，但不是我的日志添加到我的Windows服务。更奇怪的是，如果我重新启动Windows Service，日志记录开始工作。
我已经创建了一个小项目的GitHub 存储库，如果你想克隆它并自己重现问题，它会重现这个问题。
该服务应创建两个文件，一个只显示“Hello World”，另一个包含所有日志。如果日志文件成功记录了该行，它将起作用：Why is this line not logged?
如果该行没有出现在log.txt文件中，那么我的问题没有解决。
注意：如果您单击Visual Studio 中的开始按钮，则会显示此行，但我希望它在安装服务并启动服务时工作。如果服务启动，然后重新启动，它也可以工作，但这似乎更像是一个黑客而不是修复。
这就是我设置服务的方式。我使用.Net Framework 4.6.1创建了一个新的C# 控制台应用程序并安装了 3 个NuGet包：
<?xml version="1.0" encoding="utf-8"?>
<packages>
<package id="log4net" version="2.0.8" targetFramework="net461" />
<package id="Topshelf" version="4.0.4" targetFramework="net461" />
<package id="Topshelf.Log4Net" version="4.0.4" targetFramework="net461" />
</packages>
然后我创建了Windows 服务：
using log4net.Config;
using System.IO;
using Topshelf;
using Topshelf.HostConfigurators;
using Topshelf.Logging;
using Topshelf.ServiceConfigurators;
namespace LogIssue
{
public class Program
{
public const string Name = "LogIssue";
public static void Main(string[] args)
{
XmlConfigurator.Configure();
HostFactory.Run(ConfigureHost);
}
private static void ConfigureHost(HostConfigurator x)
{
x.UseLog4Net();
x.Service<WindowsService>(ConfigureService);
x.SetServiceName(Name);
x.SetDisplayName(Name);
x.SetDescription(Name);
x.RunAsLocalSystem();
x.StartAutomatically();
x.OnException(ex => HostLogger.Get(Name).Error(ex));
}
private static void ConfigureSystemRecovery(ServiceRecoveryConfigurator serviceRecoveryConfigurator) =>
serviceRecoveryConfigurator.RestartService(delayInMinutes: 1);
private static void ConfigureService(ServiceConfigurator<WindowsService> serviceConfigurator)
{
serviceConfigurator.ConstructUsing(() => new WindowsService(HostLogger.Get(Name)));
serviceConfigurator.WhenStarted(service => service.OnStart());
serviceConfigurator.WhenStopped(service => service.OnStop());
}
}
internal class WindowsService
{
private LogWriter _logWriter;
public WindowsService(LogWriter logWriter)
{
_logWriter = logWriter;
}
internal bool OnStart() {
new Worker(_logWriter).DoWork();
return true;
}
internal bool OnStop() => true;
}
internal class Worker
{
private LogWriter _logWriter;
public Worker(LogWriter logWriter)
{
_logWriter = logWriter;
}
public async void DoWork() {
_logWriter.Info("Why is this line not logged?");
File.WriteAllText("D:\\file.txt", "Hello, World!");
}
}
}
我在 app.config 中添加了Log4Net配置：
<log4net>
<appender name="RollingFileAppender" type="log4net.Appender.RollingFileAppender">
<file value="D:\log.txt" />
<appendToFile value="true" />
<rollingStyle value="Size" />
<maxSizeRollBackups value="10" />
<maximumFileSize value="100KB" />
<staticLogFileName value="true" />
<layout type="log4net.Layout.PatternLayout">
<conversionPattern value="%date [%thread] %-5level %logger [%property{NDC}] - %message%newline" />
</layout>
</appender>
<appender name="TraceAppender" type="log4net.Appender.TraceAppender">
<layout type="log4net.Layout.SimpleLayout" />
</appender>
<appender name="ColoredConsoleAppender" type="log4net.Appender.ColoredConsoleAppender">
<mapping>
<level value="FATAL" />
<foreColor value="Purple, HighIntensity" />
</mapping>
<mapping>
<level value="ERROR" />
<foreColor value="Red, HighIntensity" />
</mapping>
<mapping>
<level value="WARN" />
<foreColor value="Yellow, HighIntensity" />
</mapping>
<mapping>
<level value="INFO" />
<foreColor value="Green, HighIntensity" />
</mapping>
<mapping>
<level value="DEBUG" />
<foreColor value="Cyan, HighIntensity" />
</mapping>
<layout type="log4net.Layout.PatternLayout">
<conversionPattern value="%message%newline" />
</layout>
</appender>
<root>
<appender-ref ref="RollingFileAppender" />
<appender-ref ref="TraceAppender" />
<appender-ref ref="ColoredConsoleAppender" />
</root>
</log4net>
这样我就可以运行应用程序了。
那么，什么有效？好吧，我可以通过Visual Studio将应用程序作为控制台应用程序运行。这样，一切正常，特别是这一行：正确_logWriter.Info("Why is this line not logged?");记录。
当我安装服务时：
Release模式构建项目Path/To/Service.exe install在管理员命令提示符下运行Path/To/Service.exe start该应用程序可以正常启动和两个日志文件被创建（D:\file.txt和D:\log.txt），但是当我看到里面D:\log.txt的文件，我看不出有什么日志的"Why is this line not logged?"，并使其更奇怪的-重新启动服务（服务>右键点击LogIssue>重新启动），导致所有的日志重新开始完美工作。
此外，日志记录并不完全正常。日志文件充满了 TopShelf 日志，而不是我从应用程序中记录的内容。
我做错了什么，导致它无法正确登录？
如果您想尝试并重现此操作，您可以按照上面列出的步骤进行操作，也可以根据需要克隆该项目：https : //github.com/jamietwells/log-issue.git
进一步检查，这比我想象的更令人困惑。我确信这个问题与XmlConfigurator.Configure()调用位置错误有关，但是在测试时我发现：
安装Windows Service 时，调用如下所示：
启动Windows Service 时，调用如下所示：
SoMain肯定被调用（实际上它似乎被调用了两次！）。一个可能的问题是OnStart从不同的线程调用Main，但即使将XmlConfigurator.Configure()调用复制到以便OnStart从新线程调用它也会导致日志记录不起作用。
在这一点上，我想知道是否有人让Log4Net与TopShelf一起工作？
以下是我在安装服务时生成的日志文件示例：
2018-06-12 11:55:20,595 [1] INFO Topshelf.HostFactory [(null)] - Configuration Result:
[Success] Name LogIssue
[Success] ServiceName LogIssue
2018-06-12 11:55:20,618 [1] INFO Topshelf.HostConfigurators.HostConfiguratorImpl [(null)] - Topshelf v4.0.0.0, .NET Framework v4.0.30319.42000
2018-06-12 11:55:20,627 [1] DEBUG Topshelf.Hosts.InstallHost [(null)] - Attempting to install 'LogIssue'
2018-06-12 11:55:20,636 [1] INFO Topshelf.Runtime.Windows.HostInstaller [(null)] - Installing LogIssue service
2018-06-12 11:55:20,642 [1] DEBUG Topshelf.Runtime.Windows.HostInstaller [(null)] - Opening Registry
2018-06-12 11:55:20,642 [1] DEBUG Topshelf.Runtime.Windows.HostInstaller [(null)] - Service path: "D:\github\log-issue\LogIssue\bin\Release\LogIssue.exe"
2018-06-12 11:55:20,643 [1] DEBUG Topshelf.Runtime.Windows.HostInstaller [(null)] - Image path: "D:\github\log-issue\LogIssue\bin\Release\LogIssue.exe" -displayname "LogIssue" -servicename "LogIssue"
2018-06-12 11:55:20,644 [1] DEBUG Topshelf.Runtime.Windows.HostInstaller [(null)] - Closing Registry
2018-06-12 11:55:22,839 [1] INFO Topshelf.HostFactory [(null)] - Configuration Result:
[Success] Name LogIssue
[Success] ServiceName LogIssue
2018-06-12 11:55:22,862 [1] INFO Topshelf.HostConfigurators.HostConfiguratorImpl [(null)] - Topshelf v4.0.0.0, .NET Framework v4.0.30319.42000
2018-06-12 11:55:22,869 [1] DEBUG Topshelf.Hosts.StartHost [(null)] - Starting LogIssue
2018-06-12 11:55:23,300 [1] INFO Topshelf.Hosts.StartHost [(null)] - The LogIssue service was started.
此时在日志中，我重新启动了Windows 服务，您可以看到日志记录然后开始工作。特别Why is this line not logged?是这次记录了该行，但不是最后一次。
2018-06-12 12:09:43,525 [6] INFO Topshelf.Runtime.Windows.WindowsServiceHost [(null)] - [Topshelf] Stopping
2018-06-12 12:09:43,542 [6] INFO Topshelf.Runtime.Windows.WindowsServiceHost [(null)] - [Topshelf] Stopped
2018-06-12 12:09:45,033 [1] INFO Topshelf.HostFactory [(null)] - Configuration Result:
[Success] Name LogIssue
[Success] ServiceName LogIssue
2018-06-12 12:09:45,055 [1] INFO Topshelf.HostConfigurators.HostConfiguratorImpl [(null)] - Topshelf v4.0.0.0, .NET Framework v4.0.30319.42000
2018-06-12 12:09:45,071 [1] DEBUG Topshelf.Runtime.Windows.WindowsHostEnvironment [(null)] - Started by the Windows services process
2018-06-12 12:09:45,071 [1] DEBUG Topshelf.Builders.RunBuilder [(null)] - Running as a service, creating service host.
2018-06-12 12:09:45,072 [1] INFO Topshelf.Runtime.Windows.WindowsServiceHost [(null)] - Starting as a Windows service
2018-06-12 12:09:45,074 [1] DEBUG Topshelf.Runtime.Windows.WindowsServiceHost [(null)] - [Topshelf] Starting up as a windows service application
2018-06-12 12:09:45,076 [5] INFO Topshelf.Runtime.Windows.WindowsServiceHost [(null)] - [Topshelf] Starting
2018-06-12 12:09:45,076 [5] DEBUG Topshelf.Runtime.Windows.WindowsServiceHost [(null)] - [Topshelf] Current Directory: D:\github\log-issue\LogIssue\bin\Release
2018-06-12 12:09:45,076 [5] DEBUG Topshelf.Runtime.Windows.WindowsServiceHost [(null)] - [Topshelf] Arguments:
2018-06-12 12:09:45,078 [5] INFO LogIssue.Worker [(null)] - Why is this line not logged?
2018-06-12 12:09:45,083 [5] INFO Topshelf.Runtime.Windows.WindowsServiceHost [(null)] - [Topshelf] Started
我已经解决了这个问题。或者更确切地说，一个叫 Kvarv 的人在一年前在这里解决了这个问题：https : //github.com/Topshelf/Topshelf/issues/206#issuecomment-312581963
基本上，path/to/exe start在命令提示符窗口中运行时，TopShelf 将启动应用程序的两个实例。
第一个实例将进行一些设置和配置，第二个实例将是我们想要启动并继续运行的实际Windows 服务。
因为两者是同时运行的，所以对于能够首先访问日志文件并锁定它的任何人来说，都会引入竞争条件。这意味着 TopShelf 将记录或您的应用程序将记录，这取决于谁先锁定文件。
如果 TopShelf 首先锁定日志文件，则应用程序不会记录日志。
我意识到如果在启动服务之前延迟 1 秒，我可以修复日志记录，但直到现在才意识到为什么。第一个实例已经完成了它的配置，完成了日志文件并且锁定到期，然后我的应用程序可以出现并配置其日志记录并写入文件。
我还意识到我们可以重新启动服务并让它突然开始工作和记录。我不知道是这种情况，但我愿意打赌，当重新启动被称为 TopShelf 时，行为会有所不同，并且不会启动程序的第二个实例，它只是调用OnStop, then OnStart。如果有人在重新启动服务时有关于 TopShelf 行为的移动信息，我很想知道。
它还解释了这个问题似乎并不适用于所有人。竞争条件在不同的硬件上给出不同的结果。
有几种解决方案似乎可以解决该问题。
在上面链接的 TopShelf 问题上，第一个建议是使用PowerShell模块安装服务：
Start-Service <serviceName>
我们也可以sc start <serviceName>在命令提示符中使用if 而不是PowerShell
与通过执行以下操作启动服务的其他方法相比，这似乎不会启动多个实例并锁定文件，从而产生更一致和可预测的体验：
path/to/exe start
我们可以确保日志将文件锁定的时间尽可能短，以减少死锁的可能性。这会在使用日志记录时对性能产生影响，但它可以解决问题。我们可以简单地添加：
<lockingModel type="log4net.Appender.FileAppender+MinimalLock" />
对RollingFileAppender进行中App.config。
我们还可以在OnStart方法中添加一秒钟的延迟，以使第一个实例有时间完成。
我们还可以更改 Log4Net 的配置方式，这样它们就不会争夺文件。这是我寻求的解决方案。在 App.config 文件的 log4net 部分中，我添加了：
<appender name="RollingFileAppender" type="log4net.Appender.RollingFileAppender">
<file value="D:\log.txt" />
但只需将其更改为：
<appender name="RollingFileAppender" type="log4net.Appender.RollingFileAppender">
<file type="log4net.Util.PatternString" value="D:\Logs\%processid.log" />
将导致使用当前正在运行的进程的 ID 命名日志文件。这样每个实例都会获得自己的日志文件，锁定问题就不再存在了。
似乎包括XmlConfigurator.Configure();作为第一行之一在Main()某种程度上很重要。我仍然不完全理解为什么这很重要，但这可能是因为据我所知：x.UseLog4Net();不调用XmlConfigurator.Configure();，但是调用HostLogger.Get(Name))。这可以在 TopShelf 源（函数CreateLogWriterFactory）中看到。
| 归档时间： |
|
| 查看次数： |
4414 次 |
| 最近记录： |