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 }
View Code

 

.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 }
View Code

 

 根据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);
            }

        }
View Code

 

重点优化地方已经讲解完毕;

测试

在双缓冲输出日志的情况下性能测试;

 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     }
View Code

 

输出结果:

文件大小:

以上是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);
            }
        }
    }
View Code

 

结果:稍微比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地址,↓↓↓↓↓↓↓↓↓↓↓↓↓↓↓↓↓↓↓↓↓↓↓↓

posted on 2017-03-23 17:36  無心道(失足程序员)  阅读(10083)  评论(37编辑  收藏  举报