php log 行号 debug_backtrace,PHP 基于debug_backtrace的流程日志与日志分析

#PHP 基于debug_backtrace的流程日志与日志分析#

我们都知道php测试性能有一个叫xhprof的(不知道也没事儿的确挺消耗性能的)，执行后能看到全部函数的调用关系图，但是我压根不知道xhprof这个东西咋跑，每每看到那个图我往往是一脸懵x...

奥这个函数被调用了N多次....then去查查哪里调用的，花了大半天....？！

每每开发时‘我’其实是知道流程的，其实我就想看看

我跑到哪里了

这一步和下一步的运行时间看看性能，看看接口反应速度

记录执行流程防止背锅...

而已，最后希望就像在程序里打console.log()一样,能尽量少传参或者不传参，直接执行一个方法就能获得当前的执行日志；于是我们利用debug_backtrace生成的一个流程日志，只要在任意的流程中调用这PL::instance()->set()方法，记做一个采样点，在业务流程中有多个采样点的话，会形成一个流程日志方便监控整个流程的运行状况;

【依赖】PHP版本大于7.0

使用了一些P7新特性比如array改成了[]，list方法的改进，??的短路使用方式等等；

【非必须依赖】php安装apcu扩展

仅仅在开启了apcu缓存的时候才是必须的的

大并发环境下频繁访问磁盘对硬盘不友好，所以往往先存到了apcu共享缓存中，达到100条的时候才触发一次写磁盘的逻辑；注意默认的触发方式为直接写磁盘，启用apcu缓存逻辑，请务必安装PHP的apcu扩展之后触发开关，开关在PL类之前定义：

define('APCU_SWITCH',true); // 目前代码中已定义为false，用的时候只要修改为true即可；

初始日志格式为：

采样点1&采样点2&采样点3&采样点4&... // 第一次流程

调用处1&采样点&2采样点3&采样点4&... // 第二次流程

其中采样点描述为：

关于日志格式为啥不是个JSON的问题，其实在日志录入的时候，考虑到其不是主业务但也会占用资源，要尽可能少的占用资源和快速的写日志，而json_encode方法比字符拼接较慢一些，于是只采用了字符串拼接的方式，只要日志分割的好，分析起来问题还是不大的，所以目前用了一行一行记录的日志格式；

获取数据

通过一个流程一个流程的输出一次流程-》记录到apcu-》记录到磁盘，于是我们得到了一个初始化的日志，日志最终存在于文件中，并且这个流程日志支持多个流程，默认的流程名为defaultLine，也可以设定子流程，关于子流程这个这个后面说，如果有多个流程的话日志是分开记录的;

数据分析

php业务是流程化的(我知道PHP有线程但是大型业务妥妥的不会用到，因为过多插件线程压根就不安全导致无法使用多线程)，我们拿第一次流程来说，采样点2的时间减去采样点1的时间戳，会得到第1步到第2步的运行时间，之后可以沿着这个思路直到组后一个采样点，得到一个从哪一步到哪一步的一个运行时间，所以这个日志还是有很多东西可以分析的，目前的策略是弄一个定时任务，发现有data结尾的数据文件，立刻删掉源文件(每次落盘的时候还是会自动生成.data文件的)按行进行分析，分析后的数据直接附加(append)到.parse结尾的文件中去；

set方法和子流程

PL::instance()->set(string $lineName = false, string $message = false)

流程名

第一个参数为子流程名，一个大的流程中可以由更多的小流程组成，如果你有几组流程的话可以设置不同的子流程名，放心，各个流程都是各自独立的，包括最后的数据文件也是独立存放的有利于数据分析，，如果流程名为布尔值的false，代表使用默认的流程名也就是defaultLine，否则将使用你自定义的流程名；

日志信息

第二个参数为采样点的记录信息说明，也就是上面采样点描述中message字段对应的值，可以自己写点啥方便记忆和理解流程，但最好别太长,也不能包括|和&这两个符号，否则影响日志分析，毕竟日志是靠|和&进行分割的；

registerLines方法

一段代码可能会是多个流程的复用，可能里面会有很多采样点，有你的，有我的，当然还有他的，但是我只想记录我的流程，第一，先打开一个叫LINES_FILTER_CONTROLLER的开关：

define('LINES_FILTER_CONTROLLER', false);

平常是false代表关闭着着的，表示所有流程都会被记录下来，如果值为true则代表会对采样点过滤，在调用流程控制之前要先注册到底要监控哪几个流程，使用到了这个方法：

PL::instance()->registerLines(array $input);

输入举例：

$input = array(

PL::DEFAULTLINENAME=>false, // 关闭主线，默认是存在且打开的，这个值就是defaultLine；

'line2' => true, // 打开line2线，表示记录命名为line2的采样点，其余没提到的或者false的，都忽略；

'line3' => false, // 关闭line3线，当然你不写也没问题，line3线照样是关闭的；

);

PL::instance()->registerLines($input);

###日志输出### 其实，日志我是按照天来输出的，并没有太大的策略，在StreamScanner.php平级目录下建立data目录，并赋予0777权限(你懂得...)，会主动在这个目录下创建一个日期目录比如20161129，在这个目录下会创建出流程个数的流程日志，假如说我命名了两个流程，一个是默认的流程defaultLine，另一个line2，则会在这个地方生成两个文件defaultLine.data和line2.data；

###日志分析###

拿到原始日志，尝试进行了一次分析，文件所在目录直接执行php parseData.php ，会将data目录下日期文件夹下所有的data结尾的文件进行一次分析并得到.parse结尾的文件，比如上面的文件将命名为defaultLine.data.parse和line2.data.parse;

分析后的日志格式为：

(初始时间戳::调用次序:命名空间:方法名:行号)--到第二步的运行时间(百分比)--(调用次序:命名空间:方法名:行号)--...(调用次序:命名空间:方法名:行号::总耗时)

举例如下：

(初始时间戳::调用次序:命名空间:方法名:行号)--到第2步的运行时间(百分比)--(调用次序:命名空间:方法名:行号::总耗时)

(1480473080::1:AAA:test:13)---0.0003(59.99%)>>>(2:BBB:test:24)---0.0002(40.01%)>>>(3:BBB:test:26::0.0005)

(1480473080::1:AAA:test:13)---0.0003(74.97%)>>>(2:BBB:test:24)---0.0001(25.03%)>>>(3:BBB:test:26::0.0004)

(1480473080::1:AAA:test:13)---0.0003(60.04%)>>>(2:BBB:test:24)---0.0002(39.96%)>>>(3:BBB:test:26::0.0005)

(1480473080::1:AAA:test:13)---0.0003(75.01%)>>>(2:BBB:test:24)---0.0001(24.99%)>>>(3:BBB:test:26::0.0004)

(1480473080::1:AAA:test:13)---0.0003(74.97%)>>>(2:BBB:test:24)---0.0001(25.03%)>>>(3:BBB:test:26::0.0004)

(1480473080::1:AAA:test:13)---0.0003(75.01%)>>>(2:BBB:test:24)---0.0001(24.99%)>>>(3:BBB:test:26::0.0004)

(1480473080::1:AAA:test:13)---0.0003(75.03%)>>>(2:BBB:test:24)---0.0001(24.97%)>>>(3:BBB:test:26::0.0004)

(1480473080::1:AAA:test:13)---0.0003(59.99%)>>>(2:BBB:test:24)---0.0002(40.01%)>>>(3:BBB:test:26::0.0005)

(1480473080::1:AAA:test:13)---0.0003(75.03%)>>>(2:BBB:test:24)---0.0001(24.97%)>>>(3:BBB:test:26::0.0004)

(1480473080::1:AAA:test:13)---0.0003(75.01%)>>>(2:BBB:test:24)---0.0001(24.99%)>>>(3:BBB:test:26::0.0004)

(1480473080::1:AAA:test:13)---0.0002(49.97%)>>>(2:BBB:test:24)---0.0002(50.03%)>>>(3:BBB:test:26::0.0004)

(1480473081::1:AAA:test:13)---0.0003(75.03%)>>>(2:BBB:test:24)---0.0001(24.97%)>>>(3:BBB:test:26::0.0004)

(1480473081::1:AAA:test:13)---0.0003(74.97%)>>>(2:BBB:test:24)---0.0001(25.03%)>>>(3:BBB:test:26::0.0004)

(1480473081::1:AAA:test:13)---0.0003(75.03%)>>>(2:BBB:test:24)---0.0001(24.97%)>>>(3:BBB:test:26::0.0004)

(1480473081::1:AAA:test:13)---0.0003(74.97%)>>>(2:BBB:test:24)---0.0001(25.03%)>>>(3:BBB:test:26::0.0004)

php log 行号 debug_backtrace,PHP 基于debug_backtrace的流程日志与日志分析相关推荐

php log 行号 debug_backtrace,PHP debug_backtrace() 函数生成 backtrace（回溯跟踪）
debug_backtrace() 函数生成 backtrace(回溯跟踪). 该函数显示由 debug_backtrace() 函数代码生成的数据. 返回一个关联数组.可能返回的元素如下: 返回一个 ...
Android开发之带行号显示的Log工具类
import android.util.Log;/*** 日志控制*/ public class LogUtils {private final static String TAG = "L ...
Go 学习笔记（54）— Go 第三方库之 uber-go/zap/lumberjack（记录日志到文件、支持自动分割日志、支持日志级别、打印调用文件、函数和行号）
1. 简要说明 zap 是 uber 开源的 Go 高性能日志库,支持不同的日志级别, 能够打印基本信息等,但不支持日志的分割,这里我们可以使用 lumberjack 也是 zap 官方推荐用于日志分 ...
log4j2 pattern 行号_Springboot整合log4j2日志全解总结
在项目推进中,如果说第一件事是搭Spring框架的话,那么第二件事情就是在Sring基础上搭建日志框架,我想很多人都知道日志对于一个项目的重要性,尤其是线上Web项目,因为日志可能是我们了解应用如何执 ...
golang 打印函数名/文件名/行号 Callers
golang 的runtime库,提供Caller函数,可以返回运行时正在执行的文件名和行号: 函数定义: func Caller(skip int) (pc uintptr, file string ...
Linux之Less命令跳转到特定的行号
本文翻译自:Going to a specific line number using Less in Unix I have a file that has around million lines ...
tree的使用,显示行号，find命令应用
第1章 linux启动过程 1.开机自检bios 2.mbr引导 3.GRUB 菜单:选择不同的内核 4.加载内核 5.运行init进程 6.读取/etc/inittab运行级别配置文件 7.执行 / ...
Linux命令查看文件中指定行号的内容
前言有一个很大很大的文件,比如10G. 我想看看10000行到20000行之间的内容我想看看前100行的内容我想看看最后100行的内容 - 办法 Linux使用命令查看文件指定行号的内容,有下面 ...
python统计行号_如何使用Python脚本分析CPU使用情况的？
用以分析Python中CPU使用情况.CPU分析是通过分析CPU执行代码的方式来测量代码的性能,以此找到代码中的不妥之处,然后处理它们. 接下来我们将看看如何跟踪Python脚本使用时CPU使用情况, ...

php log 行号 debug_backtrace,PHP 基于debug_backtrace的流程日志与日志分析

php log 行号 debug_backtrace,PHP 基于debug_backtrace的流程日志与日志分析相关推荐

最新文章

热门文章