3秒钟完成50万条并发日志 文件写入
前言
目前本人从事 JAVA开发
之前讲过《你的日志组件记录够清晰嘛?--自己开发日志组件 Logger》 日志文件,当你是羡慕java下面的log4j,打印日志够清晰,可以很清晰定位打印日志所在文件,行号等;
于是尝试了重写了日志组件来模拟清晰打印;
序言
最近和群里大佬们研究游戏服务器架构的时候,讨论像魔兽,完美国际等游戏世界场景无缝地图实现方案;讨论两周后开始动手BB自己的服务器架构已经线程模型规划;
以上是最新服务器架构图;具体现在不BB,也不介绍具体关系,今天的重点是日志
然后出现一个问题,就是当服务器承载3000左右,log4j在高并发下 导致我的所有线程BLOCK了;咳咳;
也算是遇到了;当时想的是log4j比较是比较老的版本,很多东西肯定不是很适用了,想着换log4j2,再次进行测试,当服务器承载到5000的时候依然所有线程BLOCK;
当时在网上寻求各种解决办法依然未能解决我的线程BLOCK,于是我只能再一次走上重复造轮子的道路;
想起了以前的写的日志组件,翻页成java版本;
PS:本人有一个习惯,就是类似架构或者代码,习惯用java和C#各写一遍;
重点是代码,
C#.net重构
本次工作重点是对之前版本进行迭代和重构;
重点优化是代码的结构,让代码更清晰;思路更清晰;
重要的是加入磁盘io的双缓冲区来解决写入速度,提高io效率;
本次重点加入可读取配置文件模块
1 using System; 2 using System.Collections.Generic; 3 using System.IO; 4 using System.Linq; 5 using System.Text; 6 using System.Threading.Tasks; 7 8 /** 9 * 10 * @author 失足程序员 11 * @Blog http://www.cnblogs.com/ty408/ 12 * @mail 492794628@qq.com 13 * @phone 13882122019 14 * 15 */ 16 namespace Net.Sz.Framework.Szlog 17 { 18 19 /// <summary> 20 /// 初始化辅助函数 21 /// 22 /// <para>默认是不打印栈桢的,因为比较耗时:如果需要请设置 LOGSTACKTRACE = true 或者 ↓↓↓</para> 23 /// <para>AppSettings 设置 log_print_stackrace 日志是否输出调用栈桢 true or false</para> 24 /// <para>AppSettings 设置 log_print_console 日志是否输出到控制台 true or false</para> 25 /// <para>AppSettings 设置 log_print_level 日志的等级,忽律大小写 DEBUG INFO WARN ERROR</para> 26 /// <para>AppSettings 设置 log_print_path 日志的文件名带目录,log/sz.log</para> 27 /// <para>AppSettings 设置 log_print_file 日志是否输出到文件 true or false</para> 28 /// <para>AppSettings 设置 log_print_file_buffer 日志双缓冲输出到文件 true or false</para> 29 /// </summary> 30 public class CommUtil 31 { 32 /// <summary> 33 /// 日志路径存储 34 /// </summary> 35 internal static string LOGPATH = "log/sz.log"; 36 37 /// <summary> 38 /// 日志等级 39 /// <para>默认 LogLevel.DEBUG 打印</para> 40 /// </summary> 41 public static LogLevel LOG_PRINT_LEVEL = LogLevel.DEBUG; 42 43 /// <summary> 44 /// 是否显示控制台消息 45 /// <para>默认 true 打印</para> 46 /// </summary> 47 public static bool LOG_PRINT_CONSOLE = true; 48 49 /// <summary> 50 /// 是否输出文件消息 51 /// <para>默认 true 打印</para> 52 /// </summary> 53 public static bool LOG_PRINT_FILE = true; 54 /// <summary> 55 /// 输出日志到文件的时候使用buff双缓冲减少磁盘IO,可能导致日志打印不及时 56 /// <para>双缓冲对输出到控制台不受印象</para> 57 /// <para>默认 true</para> 58 /// </summary> 59 public static bool LOG_PRINT_FILE_BUFFER = true; 60 61 /// <summary> 62 /// 是否打印栈桢 63 /// <para>默认 false 不打印</para> 64 /// </summary> 65 public static bool LOG_PRINT_STACKTRACE = false; 66 67 68 /// <summary> 69 /// 设置日志输出目录 70 /// </summary> 71 /// <param name="path"></param> 72 static public void SetLogRootPath(string logPath) 73 { 74 ResetLogDirectory(logPath); 75 LOGPATH = logPath; 76 } 77 78 /// <summary> 79 /// 构建输出目录 80 /// </summary> 81 /// <param name="logPath"></param> 82 static public void ResetLogDirectory(string logPath) 83 { 84 string bpath = System.IO.Path.GetDirectoryName(logPath); 85 if (!Directory.Exists(bpath)) { Directory.CreateDirectory(bpath); } 86 } 87 88 89 /// <summary> 90 /// 友好方法,不对外,初始化 91 /// </summary> 92 internal static void InitConfig() 93 { 94 if (System.Configuration.ConfigurationManager.AppSettings.AllKeys.Contains("log_print_path")) 95 { 96 string log_print_path = System.Configuration.ConfigurationManager.AppSettings["log_print_path"].ToString(); 97 SetLogRootPath(log_print_path); 98 } 99 else SetLogRootPath(LOGPATH); 100 101 Console.WriteLine("当前日志存储路径:" + LOGPATH); 102 103 if (System.Configuration.ConfigurationManager.AppSettings.AllKeys.Contains("log_print_level")) 104 { 105 string log_print_level = System.Configuration.ConfigurationManager.AppSettings["log_print_level"].ToString(); 106 if (!Enum.TryParse(log_print_level, false, out LOG_PRINT_LEVEL)) 107 LOG_PRINT_LEVEL = LogLevel.DEBUG; 108 } 109 110 Console.WriteLine("当前日志级别:" + LOG_PRINT_LEVEL); 111 112 if (System.Configuration.ConfigurationManager.AppSettings.AllKeys.Contains("log_print_file")) 113 { 114 string log_print_file = System.Configuration.ConfigurationManager.AppSettings["log_print_file"].ToString(); 115 if (!Boolean.TryParse(log_print_file, out LOG_PRINT_FILE)) 116 LOG_PRINT_FILE = true; 117 } 118 119 Console.WriteLine("当前日志是否输出文件:" + LOG_PRINT_FILE); 120 121 if (System.Configuration.ConfigurationManager.AppSettings.AllKeys.Contains("log_print_file_buffer")) 122 { 123 string log_print_file_buffer = System.Configuration.ConfigurationManager.AppSettings["log_print_file_buffer"].ToString(); 124 if (!Boolean.TryParse(log_print_file_buffer, out LOG_PRINT_FILE_BUFFER)) 125 LOG_PRINT_FILE_BUFFER = true; 126 } 127 128 Console.WriteLine("当前日志buff双缓冲输出文件:" + LOG_PRINT_FILE_BUFFER); 129 130 if (System.Configuration.ConfigurationManager.AppSettings.AllKeys.Contains("log_print_console")) 131 { 132 string log_print_console = System.Configuration.ConfigurationManager.AppSettings["log_print_console"].ToString(); 133 if (!Boolean.TryParse(log_print_console, out LOG_PRINT_CONSOLE)) 134 LOG_PRINT_CONSOLE = true; 135 } 136 137 Console.WriteLine("当前日志是否输出控制台:" + LOG_PRINT_CONSOLE); 138 139 if (System.Configuration.ConfigurationManager.AppSettings.AllKeys.Contains("logs_print_tackrace")) 140 { 141 string logs_print_tackrace = System.Configuration.ConfigurationManager.AppSettings["logs_print_tackrace"].ToString(); 142 if (!Boolean.TryParse(logs_print_tackrace, out LOG_PRINT_STACKTRACE)) 143 LOG_PRINT_STACKTRACE = false; 144 } 145 146 Console.WriteLine("当前日志是否输出栈桢:" + LOG_PRINT_STACKTRACE); 147 } 148 149 } 150 }
.config文件AppSettings模块加入配置节点,可以设置日志输出参数
1 /// <para>默认是不打印栈桢的,因为比较耗时:如果需要请设置 LOGSTACKTRACE = true 或者 ↓↓↓</para> 2 /// <para>AppSettings 设置 log_print_stackrace 日志是否输出调用栈桢 true or false</para> 3 /// <para>AppSettings 设置 log_print_console 日志是否输出到控制台 true or false</para> 4 /// <para>AppSettings 设置 log_print_level 日志的等级,忽律大小写 DEBUG INFO WARN ERROR</para> 5 /// <para>AppSettings 设置 log_print_path 日志的文件名带目录,log/sz.log</para> 6 /// <para>AppSettings 设置 log_print_file 日志是否输出到文件 true or false</para> 7 /// <para>AppSettings 设置 log_print_file_buffer 日志双缓冲输出到文件 true or false</para>
日志级别枚举独立出来
1 using System; 2 using System.Collections.Generic; 3 using System.Linq; 4 using System.Text; 5 using System.Threading.Tasks; 6 7 8 /** 9 * 10 * @author 失足程序员 11 * @Blog http://www.cnblogs.com/ty408/ 12 * @mail 492794628@qq.com 13 * @phone 13882122019 14 * 15 */ 16 namespace Net.Sz.Framework.Szlog 17 { 18 19 /// <summary> 20 /// 日志级别 21 /// </summary> 22 public enum LogLevel 23 { 24 /// <summary> 25 /// 完全不输出任何日志 26 /// </summary> 27 Null = 0, 28 /// <summary> 29 /// 输出 DEBUG 以上级别 30 /// </summary> 31 DEBUG = 1, 32 /// <summary> 33 /// 输出 INFO 以上级别 34 /// </summary> 35 INFO = 2, 36 /// <summary> 37 /// 输出 WARN 以上级别 38 /// </summary> 39 WARN = 3, 40 /// <summary> 41 /// 输出 ERROR 以上级别 42 /// </summary> 43 ERROR = 4 44 } 45 46 }
根据log4j使用习惯加入,日志级别判断减少调用和创建,
public bool IsDebugEnabled() { return CommUtil.LOG_PRINT_LEVEL <= LogLevel.DEBUG; } public bool IsInfoEnabled() { return CommUtil.LOG_PRINT_LEVEL <= LogLevel.INFO; } public bool IsWarnEnabled() { return CommUtil.LOG_PRINT_LEVEL <= LogLevel.WARN; } public bool IsErrorEnabled() { return CommUtil.LOG_PRINT_LEVEL <= LogLevel.ERROR; }
这个大家都懂的,也就是为了减少无用执行的;
本次优化还有一个重点之处在于日志的构建调用线程执行,而不是写入线程执行;
并且加入在构建日志信息的时候是否打印堆栈信息,也就是调用栈桢情况;因测试这个比较耗时;所以默认不开放的;
/// <summary> /// /// </summary> /// <param name="level"></param> /// <param name="msg"></param> /// <param name="exception"></param> /// <param name="f">栈桢深度</param> /// <returns></returns> string GetLogString(string level, Object msg, Exception exception, int f) { string tmp1 = DateTime.Now.ToString("yyyy-MM-dd HH:mm:ss:fff: "); StringBuilder sb = new StringBuilder(); sb.Append("[") .Append(tmp1) .Append(level) .Append(":"); if (CommUtil.LOG_PRINT_STACKTRACE) { /*获取堆栈信息非常耗性能*/ StackFrame frame = new StackTrace(f, true).GetFrame(0); sb.Append(frame.GetMethod().DeclaringType.FullName); sb.Append("."); sb.Append(frame.GetMethod().Name); sb.Append("."); sb.Append(frame.GetFileLineNumber()); } sb.Append("] "); sb.AppendLine(msg.ToString()); if (exception != null) { sb .Append(exception.GetType().FullName) .Append(": ") .AppendLine(exception.Message) .AppendLine(exception.StackTrace) .AppendLine("----------------------Exception--------------------------"); } return sb.ToString(); }
StreamWriter wStream = null; FileStream fStream = null;
C#下面写入文件用流写入;streamwriter类;提供了write方法,这个函数值输入到基础流;需要调用Flush();才是把流写入文件中;
那么优化的双缓冲方案就来了;循环写入数据的时候,设置50次一个io,
注意:你的日志量并不大还是一条日志一个io,重点在于你日志量很大的时候,间隔50条日志一次文件io
while (msgs.Count > 0) { CreateFile(); if (CommUtil.LOG_PRINT_FILE_BUFFER) { /*双缓冲,减少磁盘IO*/ for (int i = 0; i < 50; i++) { String msg; if (msgs.TryDequeue(out msg)) { wStream.Write(msg); } else break; } /*输入流到文件*/ wStream.Flush(); fStream.Flush(); } else { String msg; if (msgs.TryDequeue(out msg)) { /*输入流到文件*/ wStream.Write(msg); wStream.Flush(); fStream.Flush(); } else break; } }
本次优化文件写入条件加入文件写入指定文件测试代码,但是不保证并发冲突,意图在于调试的时候,测试一些流程日志
/// <summary> /// 增加日志 /// </summary> /// <param name="level"></param> /// <param name="msg"></param> /// <param name="exception"></param> void AddLog(string level, Object msg, Exception exception) { string logmsg = GetLogString(level, msg, exception, 3); if (exception != null) { if (CommUtil.LOG_PRINT_FILE) { /*处理如果有异常,需要把异常信息打印到单独的文本文件*/ if (wfileerror == null) lock (typeof(WriterFile)) if (wfileerror == null) /*双重判定单例模式,防止并发*/ wfileerror = new WriterFile(CommUtil.LOGPATH, "log-error-file", true); wfileerror.Add(logmsg); } } if (CommUtil.LOG_PRINT_FILE) { /*处理到日志文件*/ if (wfile == null) lock (typeof(WriterFile)) if (wfile == null) /*双重判定单例模式,防止并发*/ wfile = new WriterFile(CommUtil.LOGPATH, "log-file", false); wfile.Add(logmsg); } if (CommUtil.LOG_PRINT_CONSOLE) { /*处理到控制台*/ if (wconsole == null) lock (typeof(WriterFile)) if (wconsole == null) /*双重判定单例模式,防止并发*/ wconsole = new WriterConsole("log-console"); wconsole.Add(logmsg); } }
日志线程,需要是才会创建;如果没有调用不会创建线程;
本次优化日志线程分为日志文件线程,错误日志文件线程和日志控制台线程;
加入如果有exception,把当前日志写入error文件进行备份,方便查询exception;(并未有关闭操作,一定会写)
本次在日志操作加入每天一个文件备份;
/// <summary> /// 创建文件以及备份文件操作 /// </summary> public void CreateFile() { String logPath = FileName; if (this.Error) { logPath += "_error.log"; } if (File.Exists(logPath)) { /*检查文件备份,每日一个备份*/ DateTime dtime = File.GetLastWriteTime(logPath); string day1 = dtime.ToString("yyyy-MM-dd"); string day2 = DateTime.Now.ToString("yyyy-MM-dd"); /*获取文件的上一次写入时间是否不是今天日期*/ if (!day1.Equals(day2)) { Close(); wStream = null; fStream = null; /*备份*/ File.Move(logPath, logPath + "_" + day1 + ".log"); } } if (fStream == null) { /*追加文本*/ fStream = new FileStream(logPath, System.IO.FileMode.Append); /*重建流*/ wStream = new System.IO.StreamWriter(fStream); } }
重点优化地方已经讲解完毕;
测试
在双缓冲输出日志的情况下性能测试;
1 class Program 2 { 3 4 static SzLogger log = null; 5 6 static void Main(string[] args) 7 { 8 CommUtil.LOG_PRINT_CONSOLE = false; 9 CommUtil.LOG_PRINT_FILE = true; 10 //CommUtil.LOG_PRINT_FILE_BUFFER = false; 11 log = SzLogger.getLogger(); 12 /*配置可以防在config里面*/ 13 CommUtil.LOG_PRINT_CONSOLE = true; 14 log.Debug("Debug"); 15 /*修改打印级别,不会输出info*/ 16 CommUtil.LOG_PRINT_LEVEL = LogLevel.WARN; 17 log.Info("Info"); 18 log.Warn("Warn"); 19 log.Error("Error"); 20 21 /*取消控制台打印*/ 22 CommUtil.LOG_PRINT_CONSOLE = false; 23 24 Console.WriteLine("准备好测试了请敲回车"); 25 Console.ReadLine(); 26 27 long time = TimeUtil.CurrentTimeMillis(); 28 for (int k = 0; k < 5; k++) 29 { 30 /*5个线程*/ 31 new System.Threading.Thread(() => 32 { 33 /*每个线程 10万 条日志*/ 34 for (int i = 0; i < 100000; i++) 35 { 36 Program.log.Error(i + " ssssssssssssssssssssssssssssssssssssssssssssssssssssssssssssss我测ssssssssssssssssssssssssssssssssssssssssssssssssssssssssssssssssssssssssssss"); 37 } 38 }).Start(); 39 } 40 System.Threading.Thread.Sleep(20); 41 while (Program.log.Count > 0) 42 { 43 44 } 45 Console.WriteLine("50万条日志并发写入结束" + (TimeUtil.CurrentTimeMillis() - time)); 46 Console.ReadLine(); 47 } 48 }
输出结果:
文件大小:
以上是C#版本介绍结束;
Java
java版本和C#版本其实都是翻译问题,思路都是一个思路;
采用NetBeans 8.2+ 工具,maven 项目管理;
java版本重点也还是在于日志写入思路;
采用流文件写入通道;之前也是对比了网上其他园友的写入文件方式来测试输出,可能不是最优方案如果园友有更高效的方式请告知;
BufferedWriter(new OutputStreamWriter(new FileOutputStream(file, true), "utf-8"));
java中统样采用50条日志的磁盘io操作
1 while (!logs.isEmpty()) { 2 if (System.currentTimeMillis() - bigen > 1000) { 3 /*一秒钟检查一次文件备份*/ 4 bigen = System.currentTimeMillis(); 5 createFileWriter(); 6 } 7 if (CommUtil.LOG_PRINT_FILE_BUUFER) { 8 for (int i = 0; i < 50; i++) { 9 String poll = logs.poll(); 10 if (poll == null) { 11 break; 12 } 13 write(poll); 14 } 15 flush(); 16 } else { 17 /*非缓存单次压入文件*/ 18 String poll = logs.poll(); 19 if (poll != null) { 20 write(poll); 21 flush(); 22 } 23 } 24 }
依然还是那个问题,如果日志并发不足,磁盘io可能会是一条日志一个io;
测试
测试代码
private static SzLogger log = null; public static void main(String[] args) throws Exception { CommUtil.LOG_PRINT_CONSOLE = false; log = SzLogger.getLogger(); System.out.print("准备就绪请敲回车"); System.in.read(); long bigen = System.currentTimeMillis(); ArrayList<Thread> threads = new ArrayList<>(); for (int i = 0; i < 5; i++) { Thread thread = new Thread(new Runnable() { @Override public void run() { for (int i = 0; i < 100000; i++) { log.error(i + " cssssssssssssssssdgdfgdfgdyrsbsfgsrtyhshstjhsrthsbsdhae063.00365ssssssssssssssssssssssssss"); } } }); thread.start(); threads.add(thread); } for (Thread thread : threads) { thread.join(); } while (true) { if (log.logSize() == 0) { System.out.println((System.currentTimeMillis() - bigen)); System.exit(0); } } }
结果:稍微比C#慢了一点;不排除是系统优化或者我使用不当的问题;
--- exec-maven-plugin:1.2.1:exec (default-cli) @ net.sz.game.engine.szlog --- [03-23 17:25:25:562:INFO :CommUtil.initConfig():75] 设置系统字符集sun.stdout.encoding:utf-8 [03-23 17:25:25:565:INFO :CommUtil.initConfig():76] 设置系统字符集sun.stderr.encoding:utf-8 [03-23 17:25:25:565:INFO :CommUtil.initConfig():128] 日志级别:DEBUG [03-23 17:25:25:566:INFO :CommUtil.initConfig():129] 输出文件日志目录:../log/sz.log [03-23 17:25:25:566:INFO :CommUtil.initConfig():130] 是否输出控制台日志:false [03-23 17:25:25:566:INFO :CommUtil.initConfig():131] 是否输出文件日志:true [03-23 17:25:25:566:INFO :CommUtil.initConfig():132] 是否使用双缓冲输出文件日志:true 准备就绪请敲回车 3779 ------------------------------------------------------------------------ BUILD SUCCESS ------------------------------------------------------------------------ Total time: 8.327s Finished at: Thu Mar 23 17:25:32 CST 2017 Final Memory: 8M/300M ------------------------------------------------------------------------
总结
本次优化在于解决高并发下日志冲突问题,导致线程BLOCK;增加系统稳定性;
再一次的重复造轮子;
本日志组件在于,异步写入文件和控制台输出;采用文件流加双缓冲的方式即时吸入文件方式;
没有更多缓存的目的是防止程序崩溃日志没有写入情况;
这种情况下,就算程序突然异常退出情况下,能保证极少数的日志没有写入文件中;
↓↓↓↓↓↓↓↓↓↓↓↓↓↓↓完整代码版本请注意下面的svn地址,↓↓↓↓↓↓↓↓↓↓↓↓↓↓↓↓↓↓↓↓↓↓↓↓
跪求保留标示符 /** * @author: Troy.Chen(失足程序员, 15388152619) * @version: 2021-07-20 10:55 **/ C#版本代码 vs2010及以上工具可以 java 开发工具是netbeans 和 idea 版本,只有项目导入如果出现异常,请根据自己的工具调整 提供免费仓储。 最新的代码地址:↓↓↓ https://gitee.com/wuxindao 觉得我还可以,打赏一下吧,你的肯定是我努力的最大动力