资讯详情

资讯详情

log4net-1.2.10 老项目文件日志配置、排错与性能实践

简介log4net-1.2.10 是 Apache 软件基金会维护的经典 .NET 日志框架对应版本包面向需要在 ASP.NET、Windows 服务、WPF 或 WinForms 项目中建立稳定日志体系的开发者也适合希望研读源码、理解日志框架设计的中高级读者。它围绕声明式配置、多级别记录与多目标输出帮助解决调试追踪、异常上报、性能分析和系统监控等问题。压缩包为 rar 格式约 6.79MB内含源码与 DLL 文件既可直接引用也便于对照实现文件总数及类型明细上游暂未提供故不作推断。目前已有 270 人学习下载说明其在 .NET 日志学习与选型中具有一定参考价值。读者可从中掌握 XML 配置、DEBUG 至 FATAL 级别使用、Appender 与 Layout 扩展思路以及文件、控制台、数据库、SMTP 等多输出目标的配置方法并理解多线程环境下的性能与线程安全取舍借助示例代码快速落地到实际项目。1. log4net-1.2.10 值不值得翻出来三类项目能用一类直接劝退上周帮人看一个跑了八年的老站点需求很朴素把订单链路的日志落成文件方便事后对账。运维只提一条硬要求——不许动现有依赖。翻完整个 solution能用的还是包里的 log4net-1.2.10。这个版本的定位很清楚.NET Framework 时代的标准日志组件配置项少、行为可预期、出问题能靠内部调试日志摸到根上装完不到 1MB不拉一堆传递依赖。它适合三类人接手老 WebForm/MVC 站点的维护者、要给 WinForm 客户端补文件日志的开发者、需要把散落各处的Console.WriteLine统一成一套格式的小团队。反过来.NET Core / .NET 5 以上的项目别在这上面花时间包里没有 netstandard 产物这条路是死的。下面按「认包 → 配起来 → 排错 → 压测」拆。2. 拆包与引用三个目录、一条强名称、一个死路2.1 先把目录认清再决定拖哪个 dll 进项目解压之后别急着把 dll 往引用里拖。这个年代的发布包是按目标框架分目录的同一个log4net.dll在多个文件夹里躺着名字一模一样选错轻则编译警告重则运行时抛TypeLoadException。大致结构如下以手上这个包的实际目录为准路径目标框架什么时候用bin/net/1.0/release.NET Framework 1.0只在维护极老项目时才会碰bin/net/1.1/release.NET Framework 1.1同上bin/net/2.0/release.NET Framework 2.0 / 3.0老 MVC、WebForm 的常见落点bin/net/3.5/release.NET Framework 3.5用到了 LINQ、扩展方法的项目bin/net/4.0/release.NET Framework 4.x新一点的老系统优先选这份bin/netcf/2.0/release.NET Compact Framework工控机、老式手持终端doc/文档与 SDK 参考查 appender 的完整参数表examples/示例配置抄配置骨架最快的地方三件事确认完再动手。第一项目的 TargetFramework 落在哪一行就引哪一行4.5/4.6/4.8 的项目直接引 4.0 那一份向下兼容不出问题。第二记下强名称里的Version1.2.10.0和PublicKeyToken这一版是1b44e1d426115821以你实际引用的 dll 属性为准后面查版本冲突全靠这两个值。第三也是最容易翻车的一条——整个包里没有任何 netstandard 产物。提示项目如果是 .NET Core 或 .NET 5 以上1.2.10 根本引不进来包管理器会直接报框架不兼容。这条路上只能换 2.0.8 之后的版本配置语法基本一致迁移成本集中在少数 API 上。第三点值得多说两句。不少人拿着老项目的 dll 硬塞进新项目编译期看着能过有时是靠手工改 csproj 的引用路径运行到LogManager.GetLogger那一行直接炸报的还不是配置错误是找不到程序集。新手第一反应是去查配置文件写没写对方向一开始就偏了。2.2 三种配置入口先选对再谈参数log4net 的配置来源有三条路选哪条直接决定你后面怎么调参、怎么热更新入口写法适合场景代价独立配置文件程序集特性 log4net.config生产环境改配置不发版配置文件要随程序走app.config / web.config 内嵌configSections 注册 section配置项极少的客户端改配置要动主配置容易误伤纯代码XmlConfigurator.Configure/ConfigureAndWatch单元测试、临时脚本改一次要改代码我的习惯桌面端和站点用第一种测试和命令行小工具用第三种第二种基本不碰——主配置被各种连接串塞满之后再往里加 appender改错一个节点整站起不来。第一种的原理值得掰开XmlConfiguratorAttribute是程序集级别的特性log4net 在被标注的那个程序集里挂了一个钩子真正加载发生在该程序集第一次被用到的时候。这就解释了为什么把特性写在类库的AssemblyInfo.cs里经常不生效——类库在第一次写日志之前压根没被加载钩子没机会跑。血泪经验特性永远挂在入口程序集上类库只负责GetLogger。2.3 最小可跑样例控制台加文件双通道先把最小闭环跑通再加东西。第一步项目根目录建log4net.config?xml version1.0 encodingutf-8? log4net !-- 控制台通道本地调试看输出 -- appender nameConsole typelog4net.Appender.ConsoleAppender layout typelog4net.Layout.PatternLayout conversionPattern value%date{HH:mm:ss.fff} [%thread] %-5level %logger - %message%newline / /layout /appender !-- 文件通道file 用相对路径时以当前工作目录为基准 -- appender nameFileAppender typelog4net.Appender.FileAppender file valuelogs/app.log / appendToFile valuetrue / encoding valueutf-8 / layout typelog4net.Layout.PatternLayout conversionPattern value%date{yyyy-MM-dd HH:mm:ss,fff} [%thread] %-5level %logger - %message%newline / /layout /appender root level valueDEBUG / appender-ref refConsole / appender-ref refFileAppender / /root /log4net两个细节。encoding必须显式写 utf-81.2.10 在部分区域设置下默认编码不是 UTF-8中文直接变问号而且这个坑不会报错只会让你在排查业务问题时发现日志没法看。file用相对路径时基准是当前工作目录IIS 下这个目录往往跟你想的不是一回事生产配置建议直接给绝对路径。第二步入口程序集的AssemblyInfo.cs挂特性// ConfigFile 相对“程序集所在目录”解析不是工作目录 // Watchtrue 打开文件变更监听改配置不用重启进程 [assembly: log4net.Config.XmlConfigurator( ConfigFile log4net.config, Watch true)]ConfigFile的解析基准是程序集所在目录比file参数好理解得多这也是我推荐独立配置文件的原因之一。Watch true会让 log4net 起一个文件系统监视器改了配置立刻生效调参阶段很舒服。注意Watch 在网络共享目录、部分容器挂载卷上会失效监视器收不到变更通知。线上改了配置没生效先怀疑这个别急着怀疑语法。第三步写日志using log4net; using log4net.Config; class Program { // 用类型取 logger名字即类的全名天然带命名空间层级 private static readonly ILog Log LogManager.GetLogger(typeof(Program)); static void Main(string[] args) { // 兜底特性没跑起来时手动初始化一次重复调用无害 XmlConfigurator.Configure(new System.IO.FileInfo(log4net.config)); Log.Info(服务启动); Log.DebugFormat(参数个数{0}, args.Length); try { throw new System.InvalidOperationException(演示异常记录); } catch (System.Exception ex) { // 异常对象必须作为最后一个参数传入才会走 %exception Log.Error(处理失败, ex); } // 进程退出前把缓冲区冲掉否则最后几条会丢 LogManager.Shutdown(); } }GetLogger(typeof(Program))和GetLogger(Program)拿到的 logger 名字不同前者是命名空间.Program后者就是裸字符串。名字决定层级继承关系用类型写法能让MyApp.Data自动继承MyApp上配的级别第 3 章细讲。LogManager.Shutdown()这句很多人省掉本地跑没事服务里被Environment.Exit或者任务计划强杀时就丢尾巴。吃过两次亏之后我把它写进了项目模板。3. 配置骨架从 appender 到 logger 的三层参数怎么落3.1 RollingFileAppender 的必调参数与文件名生成规则单文件 appender 只够跑 demo真实项目上手第一个换的就是滚动。这张表是我每次新项目都要对着核一遍的参数常用取值说明filelogs/app.log基础文件名静态模式下就是实际文件名appendToFiletrue设 false 每次启动清空只在调试期用rollingStyleSize / Date / Composite / Once生产一般用 CompositemaximumFileSize10MBSize 与 Composite 下生效maxSizeRollBackups10保留的历史文件数-1 表示不限staticLogFileNametrue当前文件名固定历史文件靠改名保留datePatternyyyyMMddDate 与 Composite 下生效lockingModelExclusiveLock / MinimalLock / InterProcessLock见第 5 章bufferSize512 ~ 8192字节越大越快丢日志风险越高immediateFlushtrue每条刷盘安全性最高thresholdALL / DEBUG / WARN该 appender 的入口级别比 logger 级别更靠前最容易踩的是文件名生成这块文档写得散我按实际跑出来的结果总结三条CompositestaticLogFileNametrue当前文件永远叫app.log滚动时旧文件在基础名后追加按datePattern格式化的后缀大小滚动再加序号。CompositestaticLogFileNamefalse当前文件名里直接带日期file要写成logs/app_%date{yyyyMMdd}.log这种模板。Size纯按大小滚产出app.log.1、app.log.2这样的编号文件。对应的配置骨架appender nameRollingFile typelog4net.Appender.RollingFileAppender !-- 静态文件名 复合滚动当前文件固定历史文件带日期 -- file valueD:\logs\app.log / appendToFile valuetrue / rollingStyle valueComposite / datePattern valueyyyyMMdd / staticLogFileName valuetrue / maximumFileSize value10MB / maxSizeRollBackups value30 / lockingModel typelog4net.Appender.FileAppenderExclusiveLock / encoding valueutf-8 / layout typelog4net.Layout.PatternLayout conversionPattern value%date{yyyy-MM-dd HH:mm:ss,fff} [%thread] %-5level %logger - %message%newline / /layout /appendermaxSizeRollBackups在复合模式下的含义要说清它管的是「同一时间段内」的备份数量跟日期滚动叠加时上限会比你写的小。想让历史留够 30 天就把它设成 30 以上别设 7 再奇怪为什么只留了一周。3.2 PatternLayout 转换符与它们的性能代价conversionPattern是这套配置里唯一天天要改的东西。常用转换符转换符输出备注%date{...}时间毫秒用逗号HH:mm:ss,fff不是点%thread线程取Thread.CurrentThread.Name没命名时是编号%level / %-5level级别加负号左对齐日志好读很多%loggerlogger 名太长可以配%logger{1}只留最后一段%message消息含换行的消息会打散成多行后面排错章节讲%exception异常堆栈只有Log.Error(msg, ex)这种写法才有%property{Key}上下文属性配合ThreadContext.Properties打请求号%appdomain应用程序域多域场景区分来源%file / %line / %method调用位置需要 PDBRelease 下拿不到且开销大最后一行是重点。%file和%line靠堆栈帧反射拿信息每条日志多几微秒到几十微秒还会因为 Release 编译丢掉 PDB 而输出(unknown)。我在两个项目里见过有人把这两个塞进生产模板日志量一大 CPU 直接顶上去删掉之后曲线立刻平了。真需要定位到行用%method或者干脆把关键上下文塞进%property。带上下文的模板长这样// 每条请求进来时塞一个追踪号日志里就能按请求串起来 log4net.ThreadContext.Properties[traceId] Guid.NewGuid().ToString(N).Substring(0, 8); Log.Info(进入下单流程);!-- 对应模板traceId 不存在时输出占位符 -- conversionPattern value%date{HH:mm:ss,fff} [%thread] %-5level [%property{traceId}] %logger - %message%newline /ThreadContext的数据按线程隔离同步代码里用没问题异步、线程池切换之后会丢这是它和现代链路追踪最大的差距。老项目里能接受就把请求号放在方法入参里显式往下传别指望它跨线程。3.3 logger 层级、additivity 与 root 的关系这一层是配置里最抽象的部分但搞懂了能省掉一半的重复配置。规则就两条日志级别沿名字的点分层级向上继承appender 沿父链累积由additivity控制。!-- 数据访问层只关心警告以上且额外写一份慢 SQL 专用文件 -- logger nameMyApp.Data level valueWARN / appender-ref refSlowSqlAppender / /logger !-- 业务层整体 INFO -- logger nameMyApp level valueINFO / /logger !-- 兜底未匹配到上面任何 logger 的走这里 -- root level valueERROR / appender-ref refRollingFile / /root按上面的配置MyApp.Data.OrderRepository这条链上的实际级别是 WARN最近的带level的祖先是MyApp.DataMyApp.OrderService是 INFOSomeOtherLib.Foo是 ERROR。注意root的级别只对没有匹配到具体 logger 的名字生效不会覆盖子 logger 已经设定的级别这一点跟很多人的直觉相反。appender 的累积规则不同additivity默认 true意味着MyApp.Data产生的日志除了进SlowSqlAppender还会继续往上冒泡进root上挂的RollingFile。想让它只进自己的文件加一句additivity valuefalse /。忘了这一句的典型症状是——同一条日志在两个文件里各出现一次排查半天以为 appender 重复注册了。root不写level时默认是 DEBUG这是个隐蔽的性能隐患。新项目上线前我固定检查一遍生产配置里 root 必须是 INFO 或 WARNDEBUG 只允许出现在本地配置里。4. 排查清单日志写了却看不到的五个现场4.1 现象程序跑完了日志目录一个文件都没有原因九成是配置根本没加载。要么XmlConfiguratorAttribute写在类库的AssemblyInfo.cs里该类库直到第一次写日志前都没被加载要么log4net.config在项目里的「复制到输出目录」设成了「不复制」编译输出目录里压根没这个文件。解决特性移到入口程序集配置文件属性设成「较新则复制」。想确认到底是哪种在启动第一行加log4net.Util.LogLog.InternalDebugging true;log4net 会把内部错误打到System.Diagnostics.Trace上用调试器一看就知道配置找没找到、解析有没有报错。这个开关是排查配置问题的后悔药建议背下来。4.2 现象文件生成了但内容是空的或者最后几条丢失原因bufferSize设得大 immediateFlushfalse进程被强杀或Environment.Exit提前退出时缓冲区里的内容还没落盘。另一种情况是日志框架本身没错是进程在日志写入前就崩了。解决业务日志可以把bufferSize调到 512~2048、immediateFlushfalse换吞吐审计、支付、对账这类日志保持immediateFlushtrue。无论哪种进程退出路径上必须调LogManager.Shutdown()把它挂到Application_End、ProcessExit、Windows 服务的OnStop里都行。4.3 现象配了保留 30 份备份实际只留了一两份原因rollingStyle用了Size文件名模板里又没有日期进程每次重启编号从 1 重新开始算昨天的备份被今天的第一份覆盖。或者用了复合模式但maxSizeRollBackups设得比预期小跨天时计数按当前时间段归零。解决改rollingStyleCompositestaticLogFileNametruedatePatternyyyyMMdd让日期进文件名同时把maxSizeRollBackups设成「天数 × 每天份数」而不是只写天数。改完别急着上线本地把maximumFileSize临时调到10KB跑几千条日志验证命名和保留策略两分钟就能验完。4.4 现象IIS 站点跑几天后日志停更事件日志里是写入失败原因应用程序池身份对日志目录没有写权限初期能写是因为目录被手动建过、权限来自另一个账户或者站点开了多个工作进程、多台机器挂同一个网络路径多个进程抢同一个文件句柄。解决给应用程序池标识显式授写权限别依赖「Everyone」。多进程写同一文件时把lockingModel换成InterProcessLock1.2.10 里已经带上它用命名互斥体做跨进程互斥比MinimalLock那种每条日志开关一次文件的写法安全得多。最省事的做法还是按进程分文件用%property{pid}把进程号拼进文件名。4.5 现象升级某个第三方库后一启动就抛「Could not load file or assembly log4net」原因强名称版本冲突。A 库编译时引用 1.2.13.0你的项目引用 1.2.10.0两者在 GAC 之外不能并行加载运行时按引用链上的最高版本要求去找找不到就抛。解决在app.config/web.config里加绑定重定向统一到高版本低版本调用会被重定向过去log4net 在 1.2.x 内部 API 基本稳定重定向一般不炸runtime assemblyBinding xmlnsurn:schemas-microsoft-com:asm.v1 dependentAssembly assemblyIdentity namelog4net publicKeyToken1b44e1d426115821 cultureneutral / !-- 统一重定向到项目实际引用的版本 -- bindingRedirect oldVersion1.0.0.0-1.2.13.0 newVersion1.2.13.0 / /dependentAssembly /assemblyBinding /runtime改完清理重建别只按 F5。bin目录里残留的旧 dll 会让这个错误反复出现我一般直接删掉bin和obj重来。5. 性能与并发同步写盘的代价和三种锁模型怎么选5.1 一条日志到底多贵bufferSize 该怎么定默认配置下FileAppender是每条日志一次 Write 加一次 Flush落到磁盘层面就是一次系统调用。这个开销在 QPS 几十的系统里完全无感但把它放进每秒几千次的请求链路性能曲线会肉眼可见地垂下去。粗略量级机械盘上单条同步写几十到几百微秒SSD 明显好一些但锁竞争和上下文切换的成本跑不掉。调优手段就一组参数bufferSize把「每条刷一次」变成「攒够 N 字节刷一次」immediateFlushfalse让框架别强制刷。两个一起用吞吐能上去一个数量级。代价是崩溃丢日志。这里有个判断标准我一直用这份日志丢了之后能不能通过别的数据源还原。能还原的访问日志、调试日志、监控打点尽管开缓冲不能还原的资金流水、审核记录、对账凭证老老实实immediateFlushtrue几毫秒的延迟换来的是数据完整性。另外一个常被忽略的成本是字符串格式化。%date{...}每次都要格式化时间%thread要取线程对象模板越长单条开销越大。生产模板我一般控制在 6 个转换符以内。5.2 三种锁模型选错比不配还难受lockingModel决定了文件句柄怎么拿、拿多久锁模型行为适用风险ExclusiveLock进程内独占文件句柄单进程应用默认选项其他进程完全打不开MinimalLock每条日志开/关文件临时排障、多进程写同一文件每条一次打开开销并发下内容可能交错InterProcessLock命名互斥体跨进程互斥多个进程写同一文件性能低于独占但不会互相踩默认的ExclusiveLock在绝大多数单进程场景下是最优解句柄一直握着写入最快也最不容易出乱子。真正需要动它的场景只有两个——多进程IIS 的 Web Garden、桌面程序多开、多个 Windows 服务和需要边跑边看日志文件ExclusiveLock下用记事本打开会因为共享模式冲突失败MinimalLock能打开但会拖慢写入。1.2.10 里新增的InterProcessLock解决的就是多进程这个场景代价是每次写入要走一次跨进程同步原语。我的实测经验两三个进程写同一文件InterProcessLock的吞吐大约是ExclusiveLock的六到七成比MinimalLock稳定得多。进程数再多就该换方案了——按进程拆文件或者干脆上集中式日志采集。5.3 IsDebugEnabled 到底该不该写这条是老生常谈但我在代码评审里仍然每周都能看到反例// 反例无论级别开不开字符串拼接和序列化都会执行 Log.Debug(订单快照 Serialize(order)); // 正例先判级别再决定要不要付序列化的代价 if (Log.IsDebugEnabled) { Log.Debug(订单快照 Serialize(order)); } // 参数化写法省掉手工拼接但参数是 object值类型仍会装箱 Log.DebugFormat(订单号{0} 金额{1}, order.Id, order.Amount);判断标准很简单拼接或序列化的成本如果高于一次布尔判断几乎总是高于就加IsDebugEnabled。DebugFormat只省掉了拼接装箱和数组分配还在热路径上依然建议加守卫。至于「代码里到处是 if 很难看」这种说法跟生产环境 CPU 被打满比起来难看一点完全可以接受。再补一条并发相关的ILog实例本身是线程安全的appender 内部有锁所以多线程直接共用静态字段没问题。但日志量大的本文还有配套的精品资源点击获取
觉得有用,分享给同行:

为您的企业打造数字门面

稳重轻奢商务风格,端正雅致视觉,长效耐看不易过时。

立即咨询 →