场景面试题:怎么写一个 Android 日志库?
原标题:场景面试题:怎么写一个 Android 日志库?
安卓进阶涨薪训练营,让一部分人先进大厂
大家好,我是皇叔,最近开了一个安卓进阶涨薪训练营,可以帮助大家突破技术&职场瓶颈,从而度过难关,进入心仪的公司。
详情见文章: 没错!皇叔开了个训练营
在面试中,这类题目称为场景题,即就一个实际业务场景给出解决方案,难度较高,若无与之相关的实战经验,非常考验临场应变及综合运用储备知识的能力。这篇就来分析下“写一个 Log 需要考虑些哪些方面?”
先抛一个砖
简单是任何一个库设计都要考虑的首要问题。
接口设计
如果库接口设计不合理,造成理解、接入、使用的高复杂度。那。。。这个库就没人用呗~
先来看这样一个设计:
abstractclassULogBase: IULog {
privatevallogger bylazy {
ULogCore(initConfig)
}
overridefunv(tag: String, message: String) {
logger.printLog(Log.VERBOSE, tag, message)
}
overridefunv(tag: String, message: String, throwable: Throwable) {
logger.printLog(Log.VERBOSE, tag, message)
}
overridefuni(tag: String, message: String) {
logger.printLog(Log.INFO, tag, message)
}
overridefuni(tag: String, message: String, throwable: Throwable) {
logger.printLog(Log.INFO, tag, message, throwable)
}
overridefund(tag: String, message: String) {
logger.printLog(Log.DEBUG, tag, message)
}
overridefund(tag: String, message: String, throwable: Throwable) {
logger.printLog(Log.DEBUG, tag, message, throwable)
}
overridefunw(tag: String, message: String) {
logger.printLog(Log.WARN, tag, message)
}
overridefunw(tag: String, message: String, throwable: Throwable) {
logger.printLog(Log.WARN, tag, message, throwable)
}
overridefune(tag: String, message: String) {
logger.printLog(Log.ERROR, tag, message)
}
overridefune(tag: String, message: String, throwable: Throwable) {
logger.printLog(Log.ERROR, tag, message,throwable)
}
overridefuna(tag: String, message: String, tagReport: String) {
logger.printLog(Log.ASSERT, tag, message, tagReport = tagReport)
}
overridefuna(tag: String, message: String, throwable: Throwable, tagReport: String) {
logger.printLog(Log.ASSERT, tag, message, throwable, tagReport = tagReport)
}
abstractfuninitConfig: ULogConfig
}
这是 Log 库对外公布的接口。它尊重了 Android 端打 Log 的习俗。毕竟 android.util.Log 已经习以为常。使用新库时,平滑过渡,不会有陌生感。
但这个接口设计有优化的地方。
overridefunv(tag: String, message: String) {
logger.printLog(Log.VERBOSE, tag, message)
}
overridefunv(tag: String, message: String, throwable: Throwable) {
logger.printLog(Log.VERBOSE, tag, message, throwable)
}
同级别的 Log 输出,声明了2个方法。在 Java 中不得不这样做,因参数不同而进行 方法重载。
运用 Kotlin 的语法特性 参数默认值和 可空类型,就能降低接口复杂度:
// 声明参数 throwable 是可空类型,并默认赋予空值
overridefunv(tag: String, message: String, throwable: Throwable? = null) {
logger.printLog(Log.VERBOSE, tag, message, throwable)
}
把2个接口变为1个接口,而调用效果保持不变:
ULog.v( "test", "log")
ULog.v( "test", "log",Exception( "error"))
当调用第一条语句时,Kotlin 默认给 throwable 参数传递 null 值。
接入难度
这个接口设计,第二个尴尬点是 ULogBase 是抽象的,业务层不得不实例化才能使用。。。
这无疑增加了使用负担。而这样做的目的仅仅是为了“配置”,即根据不同的业务场景传入不同的参数:
objectNimLogger : ULogBase {
overridefuninitConfig: ULogConfig {
returnULogConfig.Builder(requireNotNull(NimConfig.context)) // 和 context 耦合
.module( "nim")
.debug(NimConfig.isDebug) // 和编译类型耦合
.build
}
}
业务端必须重写 initConfig 方法生成一个 ULogConfig 对象,用来表示业务配置。
看看业务配置包括哪些:
classULogConfigprivateconstructor(builder: Builder) {
valmodule = builder.mModule // 模块名
valisDebug = builder.mIsDebug // 编译类型
valcontext = builder.context // 上下文
vallogModulePath = builder.mLogModulePath // 路径名
vallogRootPath = builder.mLogRootPath // 根路径名
valenableToFile = builder.enableToFile // 是否写文件
valisValidPath : Boolean
get{
return!TextUtils.isEmpty(logModulePath) && !TextUtils.isEmpty(logRootPath)
}
classBuilder( valcontext: Context) {
lateinitvarmModule: String
privateset
varmIsDebug: Boolean= true
privateset
varenableToFile: Boolean= true
privateset
varmLogModulePath: String = ""
privateset
varmLogRootPath: String = ""
privateset
funmodule(name: String) : Builder {
mModule = name
returnthis
}
fundebug(debug: Boolean) : Builder {
mIsDebug = debug
returnthis
}
funenableToFile(enable : Boolean) : Builder {
enableToFile = enable
returnthis
}
funbuild: ULogConfig {
if(mModule == null) {
throwIllegalArgumentException( "Be sure to set the module name")
}
if(TextUtils.isEmpty(mLogModulePath)) {
mLogModulePath = getLogPath(mModule)
}
if(TextUtils.isEmpty(mLogRootPath)) {
mLogRootPath = getLogPath
}
returnULogConfig( this)
}
privatefungetLogPath(module : String= "") : String {
returnif(mIsDebug) {
File(context.filesDir, "uLog/debug/ $module" ).absolutePath
} else{
File(context.filesDir, "uLog/release/ $module" ).absolutePath
}
}
}
}
业务配置信息包括,模块名、编译类型、上下文、路径名、是否写文件。
其中前 4 个参数是为了给不同模块的日志生成不同的日志路径。这个设计,见仁见智~
优点是信息降噪,只关注想关注模块的日志。缺点是,大部分业务模块都和多个底层功能模块耦合,大部分问题是综合性问题,需要关注整个链路上所有模块的日志。
我偏好的策略是,将所有日志打入一个文件,通过 tag 来区分模块,如果只想关注某个模块的日志,sublime 可以方便地选中包含指定 tag 的所有行,一个复制粘贴就完成了信息降噪。毕竟想分开是轻而易举的事情,但是想合并就很难了~
复杂度(建造者模式)
Kotlin 相较于 Java 的最大优势就是降低复杂度。在库接口设计及内部实现时就要充分发挥 Kotlin 的优势,比如 Kotlin 的世界里已不需要 Builder 模式了。
Builder 模式有如下优势:
为参数标注语义:在Builder模式中,每个属性的赋值都是一个函数,函数名标注了属性语义。
可选参数&分批赋值:Builder模式中,除了必选参数,其他参数是可选的,可分批赋值。而直接使用构造函数必须一下子为所有参数赋值。
增加参数约束条件:可以在参数不符合要求时,抛出异常。
但 Builder 模式也有代价,新增了一个中间类 Builder 。
使用 Kotlin 的命名参数+参数默认值+require语法,在没有任何副作用的情况下就能实现 Builder 模式:
classPerson(
valname: String,
//为以下可选参数设置默认值
valgender: Int= 1,
valage: Int= 0,
valheight: Int= 0,
valweight: Int= 0
)
//使用命名参数构建 Person 实例
valp = Person(name = “taylor”,gender = 1,weight = 43)
命名参数为每个实参赋予了语义,而且不需要按构造方法中声明的顺序来赋值,可以跳着来。
如果想增加参数约束条件可以调用 require 方法:
dataclassPerson(
// 这个是必选参数
valname: String,
valgender: Int= 1,
valage: Int= 0,
valheight: Int= 0,
valweight: Int= 0
){
//在构造函数被调用的时候执行参数合法检查
init{
require(name.isNotEmpty){”name cant be empty“}
}
}
此时如果像下面这样构造 Person,则会抛出异常:
valp = Person(name= "",gender = 1)
java.lang.IllegalArgumentException: name cant be empty
本来在 build 方法中执行的额外初始化逻辑也可以全部写在 init 代码块中。
最后这个库,在具体打印日志时的操作也及其复杂(不知道你能不能一下子看明白这 log 是怎么打的?):
internalclassULogCore( privatevalconfig: ULogConfig) {
companionobject{
constvalDELETE_DAY_NUMBER = 7
constvalTAG_LOG = "ULogCore"
constvalSUFFIX = ".java"
constvalTAG_PARAM = "param"
constvalKEY_ASSET_MSG = "key_asset_message"
constvalSTACK_TRACK_INDEX = 7
valtag_log_type = arrayOf( "VERBOSE", "DEBUG", "INFO", "WARN", "ERROR", "ASSERT")
varinitOperation = AtomicBoolean( false)
varlogDateFormat = SimpleDateFormat( "yyyy-MM-dd", Locale.CHINA)
}
funprintLog(
type: Int,
tagText: String,
message: String,
throwable: Throwable? = null,
tagReport: String? = ""
) {
valstackTrace = Thread.currentThread.stackTrace
CoroutineScope(Dispatchers.Default).launch {
valfinalMessage = processMessage(type, message, stackTrace)
valtagFinal = if(TextUtils.isEmpty(tagText)) TAG_LOG elsetagText
if(config.isDebug) {
when(type) {
Log.VERBOSE -> Log.v(tagFinal, finalMessage, throwable)
Log.DEBUG -> Log.d(tagFinal, finalMessage, throwable)
Log.INFO -> Log.i(tagFinal, finalMessage, throwable)
Log.WARN -> Log.w(tagFinal, finalMessage, throwable)
Log.ERROR -> Log.e(tagFinal, finalMessage, throwable)
Log.ASSERT -> Log.e(tagFinal, finalMessage, throwable)
else-> {
}
}
}
vallogDir = File(config.logModulePath)
if(!logDir.exists || logDir.isFile) {
logDir.mkdirs
}
if(!initOperation.getAndSet( true)) {
valfilterDates = ArrayList<String>.apply {
for(i in0..DELETE_DAY_NUMBER) {
valcalendar = Calendar.getInstance
calendar.add(Calendar.DAY_OF_MONTH, -i)
valdate = logDateFormat.format(calendar.time)
Log.i(TAG_LOG, date)
add(date)
}
}
config.logRootPath.takeIf { !TextUtils.isEmpty(it) }?.run {
vallist = ArrayList<File>
File( this).listFiles?.forEach { file ->
Log.i(TAG_LOG, "module $this" )
file.listFiles?.filter { child ->
!child.isMatchDateFile(filterDates)
}?.apply {
list.addAll( this)
}
}
list
}?.run {
forEach {
Log.i(TAG_LOG, "delete file ${it.name}" )
it.delete
}
}
if(!ULogFwHThread.isAlive) {
ULogFwHThread.start
}
}
if(config.enableToFile) {
if(config.isValidPath) {
varformatReportTag = ""
if(type == Log.ASSERT && tagReport != null&& tagReport.isNotEmpty) {
varassetMsgSet = MMKV.defaultMMKV.getStringSet(KEY_ASSET_MSG, HashSet)
valrawMsg = message+tagReport
Log.i(TAG_LOG, "asset md5 raw message $rawMsg" )
valkey = ULogUtils.getMD5(rawMsg, false)
Log.i(TAG_LOG, "assetMsgSet is $assetMsgSet, asset message key is $key" )
formatReportTag = "[# $tagReport#]"
if(assetMsgSet?.contains(key) == true) {
Log.i(TAG_LOG, "This log is asset mode and has save to file once, so ignore it.")
} else{
assetMsgSet?.add(key)
MMKV.defaultMMKV.putStringSet(KEY_ASSET_MSG, assetMsgSet)
EventBus.getDefault.post(
ULogTagEvent(
tagReport,
logDateFormat.format(Date(System.currentTimeMillis))
)
)
}
}
ULogFwHThread.addEntry(
ULogEntry(
config,
type,
"[ $tagFinal] $formatReportTag: $message" ,
throwable
)
)
} else{
Log.i(TAG_LOG, "printLog invalid log file path logRootPath : "+
" ${config.logRootPath}logModulePath : ${config.logModulePath}" )
}
} else{
Log.i(TAG_LOG, "enableToFile is closed")
}
}
}
privatefunprocessMessage(
type: Int,
msg: String,
stackTraceElement: Array< StackTraceElement>
) : String {
funtypeTag(logType: Int) : String? {
returnif(logType >= Log.VERBOSE && logType <= Log.ASSERT) tag_log_type[logType - 2] else"LOG"
}
valtargetElement = stackTraceElement[STACK_TRACK_INDEX]
varfileName = targetElement.fileName
if(TextUtils.isEmpty(fileName)) {
varclassName = targetElement.className
valclassNameInfo = className.split( "\.".toRegex).toTypedArray
if(classNameInfo.isNotEmpty) {
className = classNameInfo[classNameInfo.size - 1]
}
if(className.contains( "$")) {
className = className.split( "\$".toRegex).toTypedArray[ 0]
}
fileName = className + SUFFIX
}
valmethodName = targetElement.methodName
varlineNumber = targetElement.lineNumber
if(lineNumber < 0) {
lineNumber = 0
}
valheadString = String.format( "[ (%s:%s) => %s ]", fileName, lineNumber, methodName)
valthreadInfo = String.format( "thread - {{ %s }}", Thread.currentThread.name)
valsb = StringBuilder(headString).apply {
append( "\n╔═════════════════════════════════════════════════════════════════════════════════════════")
append( "\n║ ").append(threadInfo)
append( "\n╟┈┈┈┈┈┈┈┈┈┈┈┈┈┈┈┈┈┈┈┈┈┈┈┈┈┈┈┈┈┈┈┈┈┈┈┈┈┈┈┈┈┈┈┈┈┈┈┈┈┈┈┈┈┈┈")
append( "\n║ [").append(typeTag(type)).append( "] - ").append(msg)
append( "\n╚═════════════════════════════════════════════════════════════════════════════════════════")
}
returnsb.toString
}
}
printLog 是每次打日志都会调用的方法,在这个方法里面做了很多很多事情~,包括美化日志、向 Logcat 输出日志、创建日志文件夹、删除过期日志、写日志到文件、将日志上传云。
先不说违反了单一职责原则造成的高复杂度,高理解成本,同时也不能满足下面这些需求:
自定义我的日志美化样式。(毕竟我们不一样,有不同的审美)
在不改库的前提下,更换写文件方式(比如更高性能的I/O库)。
在不改库的前提下,更换上传云逻辑。(从阿里云换成亚马逊云)
在不改库的前提下,增加本地日志加密。
在不改库的前提下,修改日志文件的根目录。
这些动态的配置效果,应该是一个库具备的弹性。如果动不动就要改库,它还配叫库?
如果一定要给 “一个库的基本修养”提两条纲领的话,我愿意把 “简单”和 “弹性”放在首位。
高可扩展看完刚才的砖之后,我再抛一个砖。
objectEasyLog {
privateconstvalVERBOSE = 2
privateconstvalDEBUG = 3
privateconstvalINFO = 4
privateconstvalWARN = 5
privateconstvalERROR = 6
privateconstvalASSERT = 7
// 拦截器列表
privatevallogInterceptors = mutableListOf<LogInterceptor>
fund(message: String, tag: String= "", varargargs: Any) {
log(DEBUG, message, tag, *args)
}
fune(message: String, tag: String= "", varargargs: Any, throwable: Throwable? = null) {
log(ERROR, message, tag, *args, throwable = throwable)
}
funw(message: String, tag: String= "", varargargs: Any) {
log(WARN, message, tag, *args)
}
funi(message: String, tag: String= "", varargargs: Any) {
log(INFO, message, tag, *args)
}
funv(message: String, tag: String= "", varargargs: Any) {
log(VERBOSE, message, tag, *args)
}
funwtf(message: String, tag: String= "", varargargs: Any) {
log(ASSERT, message, tag, *args)
}
// 注入拦截器
funaddInterceptor(interceptor: LogInterceptor) {
logInterceptors.add(interceptor)
}
// 从头部注入拦截器
funaddFirstInterceptor(interceptor: LogInterceptor) {
logInterceptors.add( 0, interceptor)
}
}
日志库对上层的接口封装在一个单例 EasyLog 里。
日志库提供了和 android.util.Log 几乎一样的打印接口,但增加了一个可变参数 args ,这是为了方便地为字串的通配符赋值。
假责任链模式
日志库还提供了一个新接口 addInterceptor ,用于动态地注入日志拦截器:
interfaceLogInterceptor{
// 进行日志
funlog(priority: Int, tag: String, log: String)
// 是否允许进行日志
funenable: Boolean
}
日志拦截器是一个接口,定义了两个抽象的行,为分别是进行日志和是否允许日志。
所有的日志接口都将打印日志委托给了 log 方法:
objectEasyLog {
@Synchronized
privatefunlog(
priority: Int,
message: String,
tag: String,
varargargs: Any,
throwable: Throwable? = null
) {
// 为日志通配符赋值
varlogMessage = message.format(*args)
// 如果有异常,则读取异常堆栈拼接在日志字串后面
if(throwable != null) {
logMessage += getStackTraceString(throwable)
}
// 遍历日志拦截器,将日志打印分发给所有拦截器
logInterceptors.forEach { interceptor ->
if(interceptor.enable) interceptor.log(priority, tag, logMessage)
}
}
// 对 String.format 的封装,以求简洁
funString. format( varargargs: Any) =
if(args.isNullOrEmpty) thiselseString.format( this, *args)
// 读取堆栈
privatefungetStackTraceString(tr: Throwable?) : String {
if(tr == null) {
return""
}
vart = tr
while(t != null) {
if(t isUnknownHostException) {
return""
}
t = t.cause
}
valsw = StringWriter
valpw = PrintWriter(sw)
tr.printStackTrace(pw)
pw.flush
returnsw.toString
}
}
这里用了同步方法,为了防止多线程调用时日志乱序。
这里还运用了 责任链模式(假的),使得 EasyLog 和日志处理的具体逻辑解耦,它只是持有一组日志拦截器,当有日志请求时,就分发给所有的拦截器。
这样做的好处就是,可以在业务层动态地为日志组件提供新的功能。
当然日志库得提供一些基本的拦截器,比如将日志输出到 Logcat:
openclassLogcatInterceptor: LogInterceptor {
overridefunlog(priority: Int, tag: String, log: String) {
Log.println(priority, tag, log)
}
overridefunenable: Boolean{
returntrue
}
}
Log.println(priority, tag, log) 是 android.util.Log 提供的,按优先级将日志输出到 Logcat 的方法。使用这个方法可以降低复杂度,因为不用写类似下面的代码:
when(priority){
VERBOSE -> Log.v(...)
ERROR -> Log.e(...)
}
之所以要将 LogcatInterceptor 声明为 open,是因为业务层有动态重写 enable 方法的需求:
EasyLog.addInterceptor( object: LogcatInterceptor {
overridefunenable: Boolean{
returnBuildConfig.DEBUG
}
})
这样就把日志输出到 Logcat 的开关 和 build type 联系起来了,就不需要将 build type 作为 EasyLog 的一个配置字段了。
除了输出到 Logcat,另一个基本需求就是日志文件化,新建一个拦截器:
classFileWriterLogInterceptor
privateconstructor( privatevardir: String) : LogInterceptor {
privatevalhandlerThread = HandlerThread( "log_to_file_thread")
privatevalhandler: Handler
privatevaldispatcher: CoroutineDispatcher
// 带参单例
companionobject{
@Volatile
privatevarINSTANCE: FileWriterLogInterceptor? = null
fungetInstance(dir: String) : FileWriterLogInterceptor =
INSTANCE ?: synchronized( this) {
INSTANCE ?: FileWriterLogInterceptor(dir).apply { INSTANCE = this}
}
}
init{
// 启动日志线程
handlerThread.start
handler = Handler(handlerThread.looper)
// 将 handler 转换成 Dispatcher
dispatcher = handler.asCoroutineDispatcher( "log_to_file_dispatcher")
}
overridefunlog(priority: Int, tag: String, log: String) {
// 启动协程串行地将日志写入文件
if(!handlerThread.isAlive) handlerThread.start
GlobalScope.launch(dispatcher) {
FileWriter(getFileName, true).use {
it.append( "[ $tag] $log" )
it.append( "\n")
it.flush
}
}
}
overridefunenable: Boolean{
returntrue
}
privatefungetToday: String =
SimpleDateFormat( "yyyy-MM-dd").format(Calendar.getInstance.time)
privatefungetFileName= " $dir${File.separator}${getToday}.log"
}
日志写文件的思路是: “异步串行地将字串通过流输出到文件中”。
异步化是为了不阻塞主线程,串行化是为了保证日志顺序。HandlerThread 就很好地满足了异步化串行的要求。
为了简化“将日志作为消息发送到异步线程中”这段代码,使用了协程,这样代码就转变成:每次日志请求到来时,启动协程,在其中完成创建流、输出到流、关闭流。隐藏了收发消息的复杂度。
日志拦截器被设计为单例,目的是让 App 内存中只存在一个写日志的线程。
日志文件的路径由构造方法传入,这样就避免了日志拦截器和 Context 的耦合。
use 是 Closeable 的扩展方法,它隐藏了流操作的 try-catch,降低了复杂度
然后业务层就可以像这样动态地为日志组件添加写文件功能:
classMyApplication: Application{
overridefunonCreate{
super.onCreate
// 日志文件路径
valdir = this.filesDir.absolutePath
// 构造日志拦截器单例
valinterceptor = FileWriterLogInterceptor.getInstance(dir)
// 注入日志拦截器单例
EasyLog.addInterceptor(interceptor)
}
}
真责任链模式
还有一个对日志库的基本诉求就是“美化日志”。
还是重新定义一个拦截器:
// 调用堆栈拦截器
classCallStackLogInterceptor: LogInterceptor {
companionobject{
privateconstvalHEADER =
"┌──────────────────────────────────────────────────────────────────────────────────────────────────────"
privateconstvalFOOTER =
"└──────────────────────────────────────────────────────────────────────────────────────────────────────"
privateconstvalLEFT_BORDER = │
// 用于过滤日志调用栈(将EasyLog中的类过滤)
privatevalblackList = listOf(
CallStackLogInterceptor:: class. java. name,
EasyLog::class.java.name
)
}
overridefunlog(priority: Int, tag: String, log: String) {
// 打印头部
Log.println(priority, tag, HEADER)
// 打印日志
Log.println(priority, tag, " $LEFT_BORDER$log" )
// 打印堆栈信息
getCallStack(blackList).forEach {
valcallStack = StringBuilder
.append(LEFT_BORDER)
.append( "\t ${it}" ).toString
Log.println(priority, tag, callStack)
}
// 打印尾部
Log.println(priority, tag, FOOTER)
}
overridefunenable: Boolean{
returntrue
}
}
对于业务层的一条日志,调用堆栈拦截器输出了好几条日志,依次是头部、日志、堆栈、尾部。
为了降低复杂度,把获取调用栈的逻辑单独抽象为一个方法:
fungetCallStack(blackList: List< String>) : List<String> {
returnThread.currentThread
.stackTrace.drop( 3) // 获取调用堆栈,过滤上面的3个,因为它们就是这里看到3个方法
.filter { it.className ! inblackList } // 过滤黑名单
.map { " ${it.className}. ${it.methodName}( ${it.fileName}: ${it.lineNumber})" }
}
按照上面 map 中那样的格式,在 Logcat 中就能有点击跳转效果。
然后把调用堆栈拦截器插入到所有拦截器的头部:
EasyLog.addFirstInterceptor(CallStackLogInterceptor)
打印效果是这样的:
看上去还不错~,但当我打开日志文件后,却只有 DemoActivity.onCreate 这一行日志,并没有堆栈信息。。。
原因就在于我用了一个 假的责任链模式!!
责任链模式就好比“老师发考卷”:
真责任链是这样发考卷的:老师将考卷递给排头同学,排头同学再传递给第二个同学,如此往复,直到考卷最终递到我的手里。
假责任链是这样发考卷的:老师站讲台不动,叫到谁的名字,谁就走上去拿自己的考卷。
学生时代当然希望老师用假责任链模式发考卷,因为若用真责任链,前排的每一个同学都可以看到我的分数,还能在我的考卷上乱涂乱画。
但在打日志这个场景中,用假责任链模式的后果就是, 后续拦截器拿不到前序拦截器的处理结果。
其实它根本称不上责任链,因为就不存在“链”,至多是一个“策略模式的遍历”
所以只能用真责任链重构,为了向后传递拦截器的处理结果, 拦截器就得持有其后续拦截器:
interfaceLogInterceptor{
// 后续拦截器
varnextInterceptor:LogInterceptor?
funlog(priority: Int, tag: String, log: String)
funenable: Boolean
}
然后在具体的拦截器实例中实现这个抽象属性:
openclassLogcatInterceptor: LogInterceptor {
overridevarnextInterceptor: LogInterceptor? = null
get= field
set(value) {
field = value
}
overridefunlog(priority: Int, tag: String, log: String) {
if(enable) {
Log.println(priority, tag, log)
}
// 将log请求传递给下一个拦截器
nextInterceptor?.log(priority, tag, log)
}
overridefunenable: Boolean{
returntrue
}
}
因为所有的拦截器都通过链的方式连接,所以 EasyLog 就不需要再持有一组拦截器,而只需要持有头拦截器就好了:
objectEasyLog {
// 头拦截器
privatevallogInterceptor : LogInterceptor? = null
// 注入拦截器
funsetInterceptor(interceptor: LogInterceptor) {
logInterceptor = interceptor
}
}
注入拦截器的代码也需要做相应的变化:
classMyApplication: Application{
overridefunonCreate{
super.onCreate
// 构建所有拦截器
valdir = this.filesDir.absolutePath
valfileInterceptor = FileWriterLogInterceptor.getInstance(dir)
vallogcatInterceptor = LogcatInterceptor
valcallStackLogInterceptor = CallStackLogInterceptor
// 安排拦截器链接顺序
callStackLogInterceptor.nextInterceptor = logcatInterceptor
logcatInterceptor.nextInterceptor = fileInterceptor
// 将头部拦截器注入
EasyLog.setInterceptor(callStackLogInterceptor)
}
}
这个设计能满足功能要求,但是对于接入方来说,复杂度有点高,因为不得不手动安排拦截器的顺序,而且如果想改动拦截器的顺序也非常麻烦。
我想到了 OkHttp,它也采用了真拦截器模式,但并不需要手动安排拦截器的顺序。它是怎么做到的?由于篇幅原因,源码分析不展开了,感兴趣的同学可以点开 okhttp3.internal.http.RealInterceptorChain 。
下面运用这个思想,重构一下 EasyLog。
首先要新建一条链:
classChain(
// 持有一组拦截器
privatevalinterceptors: List<LogInterceptor>,
// 当前拦截器索引
privatevalindex: Int= 0
) {
// 将日志请求在链上传递
funproceed(priority: Int, tag: String, log: String) {
// 用一条新的链包裹链上的下一个拦截器
valnext = Chain(interceptors, index + 1)
// 执行链上当前的拦截器
valinterceptor = interceptors.getOrNull(index)
// 执行当前拦截器逻辑,并传入新建的链
interceptor?.log(priority, tag, log, next)
}
}
链持有一组拦截器和索引,其中索引表示当前需要执行的是哪个拦截器。
链包含一个 procee 方法,它是让日志请求在链上传递起来的关键。每次执行该方法都会新建一个链条并将索引+1,下次通过该链条获取的拦截器就是“下一个拦截器”。紧接着根据当前索引获取当前拦截器,将日志请求传递给它的同时,将“下一个拦截器”以链条的形式也传递给它。
重构之后的调用栈拦截器如下:
classCallStackLogInterceptor: LogInterceptor {
companionobject{
privateconstvalHEADER =
"┌──────────────────────────────────────────────────────────────────────────────────────────────────────"
privateconstvalFOOTER =
"└──────────────────────────────────────────────────────────────────────────────────────────────────────"
privateconstvalLEFT_BORDER = │
privatevalblackList = listOf(
CallStackLogInterceptor:: class. java. name,
EasyLog::class.java.name,
Chain::class.java.name,
)
}
overridefunlog(priority: Int, tag: String, log: String, chain: Chain) {
// 将日志请求传递给下一个拦截器
chain.proceed(priority, tag, HEADER)
// 将日志请求传递给下一个拦截器
chain.proceed(priority, tag, " $LEFT_BORDER$log" )
getCallStack(blackList).forEach {
valcallStack = StringBuilder
.append(LEFT_BORDER)
.append( "\t ${it}" ).toString
// 将日志请求传递给下一个拦截器
chain.proceed(priority, tag, callStack)
}
// 将日志请求传递给下一个拦截器
chain.proceed(priority, tag, FOOTER)
}
overridefunenable: Boolean{
returntrue
}
}
和之前假责任链的区别在于,将已经美化过的日志传递给了后续拦截器,其中就包括文件日志拦截器,这样写入文件的日志也被美化了。
EasyLog 也需要做相应的改动:
objectEasyLog {
// 持有一组拦截器
privatevallogInterceptors = mutableListOf<LogInterceptor>
// 将所有日志拦截器传递给链条
privatevalinterceptorChain = Chain(logInterceptors)
funaddInterceptor(interceptor: LogInterceptor) {
logInterceptors.add(interceptor)
}
funaddFirstInterceptor(interceptor: LogInterceptor) {
logInterceptors.add( 0, interceptor)
}
funremoveInterceptor(interceptor: LogInterceptor) {
logInterceptors.remove(interceptor)
}
@Synchronized
privatefunlog(
priority: Int,
message: String,
tag: String,
varargargs: Any,
throwable: Throwable? = null
) {
varlogMessage = message.format(*args)
if(throwable != null) {
logMessage += getStackTraceString(throwable)
}
// 日志请求传递给链条
interceptorChain.proceed(priority, tag, logMessage)
}
}
这样一来上层注入拦截的代码不需要更改,还是按序 add 就好,将拦截器形成链条的复杂度被隐藏在 EasyLog 的内部。
高性能 I/O
有时候为了排查线上偶现问题,会尽可能地在关键业务点打 Log 并文件化,再上传到云以便排查。在一些高强度业务场景中的高频模块,比如直播间中的 IM,瞬间产生几百上千条 Log 是家常便饭,这就对 Log 库的性能提出了要求(CPU 和内存)。
Okio
如何高性能地 I/O?
第一个想到的是Okio。关于为啥 Okio 的性能与好于 java.io 包的流,之后会专门写一篇分析文章。
重新写一个 Okio 版本的日志拦截器:
class OkioLogInterceptor private constructor(private var dir: String) : LogInterceptor {
private val handlerThread = HandlerThread( "log_to_file_thread")
private val handler: Handler
private val dispatcher: CoroutineDispatcher
// 写日志的开始时间
var startTime = System.currentTimeMillis
companion object {
@Volatile
private var INSTANCE: OkioLogInterceptor? = null
fun getInstance(dir: String): OkioLogInterceptor =
INSTANCE ?: synchronized(this) {
INSTANCE ?: OkioLogInterceptor(dir).apply { INSTANCE = this }
}
}
init {
handlerThread.start
handler = Handler(handlerThread.looper)
dispatcher = handler.asCoroutineDispatcher( "log_to_file_dispatcher")
}
override fun log(priority: Int, tag: String, log: String){
if(!handlerThread.isAlive) handlerThread.start
GlobalScope.launch(dispatcher) {
// 使用 Okio 写文件
val file = File(getFileName)
file.sink( true).buffer.use {
it.writeUtf8( "[ $tag] $log" )
it.writeUtf8( "\n")
}
// 写日志结束时间
if( log== "work done") Log.v( "ttaylor1", "log work is done= ${System.currentTimeMillis - startTime}" )
}
returnfalse
}
private fun getToday: String =
SimpleDateFormat( "yyyy-MM-dd").format(Calendar.getInstance.time)
private fun getFileName = " $dir${File.separator}${getToday}.log"
}
FileWriter vs Okio 性能 PK
为了测试 Okio 和 FileWriter 的性能差异,编写了如下测试代码:
classLogActivity: AppCompatActivity{
overridefunonCreate(savedInstanceState: Bundle?) {
super.onCreate(savedInstanceState)
// 添加 FileWriter 或者 Okio 日志拦截器
EasyLog.addInterceptor(OkioLogInterceptor.getInstance( this.filesDir.absolutePath))
// EasyLog.addInterceptor(FileWriterLogInterceptor.getInstance(this.filesDir.absolutePath))
// 重复输出 1 万条短 log
MainScope.launch(Dispatchers.Default) { count ->
repeat( 10000){
EasyLog.v( "test log count= $count" )
}
EasyLog.v( "work done")
}
}
}
测试方案:重复输入 1 万条短 log,并且从写第一条 log 开始计时,直到最后一条 log 的 I/O 完成时输出耗时。
Okio 和 FileWriter 三次测试的对比耗时如下:
// okio
ttaylor1: log work is done=9600
ttaylor1: log work is done=9822
ttaylor1: log work is done=9411
// FileWriter
ttaylor1: log work is done=10688
ttaylor1: log work is done=10816
ttaylor1: log work is done=11928
看上去 Okio 在耗时上有微弱的优势。但当我把单条 Log 的长度增加 300 倍之后,测试结果出现了反转:
// FileWriter
ttaylor1: logwork is done=13569
ttaylor1: logwork is done=12654
ttaylor1: logwork is done=13152
// okio
ttaylor1: logwork is done=14136
ttaylor1: logwork is done=15451
ttaylor1: logwork is done=15292
也就是说 Okio 在高频少量 I/O 场景性能好于 FileWriter,而高频大量 I/O 场景下没有性能优势。这个结果让我很困惑,于是乎我在 Github 上提了 issue:
Okio is slower when writing long strings into file frequently compared with FileWriter · Issue #1098 · square/okio
没想到瞬间就被回复了:
我的提问的本意是想确认下使用 Okio 的姿势是否得当,但没想到官方回答却是:“Okio 库就是这样的,你的测试数据是符合预期的。我们在“用自己的 UTF-8 编码以减少大量垃圾回收”和性能上做了权衡。所以导致有些测试场景下性能好,有些场景下性能没那么好。我们的期望是在真实的业务场景下 Okio 的性能会表现的好。”
不知道我翻译的准不准确,若有误翻望英语大佬指点~
这样的结果不能让我满意,隐约觉得 Okio 的使用方式有优化空间,于是我一直凝视下面这段代码:
overridefunlog(priority: Int, tag: String, log: String) {
GlobalScope.launch(dispatcher) {
valfile = File(getFileName)
file.sink( true).buffer.use {
it.writeUtf8( "[ $tag] $log" )
it.writeUtf8( "\n")
}
}
returnfalse
}
代码洁癖告诉我,这里有几个可以优化的地方:
不用每次打 Log 都新建 File 对象。不用每次打 Log 都新建输出流,每次打完就关闭流。
于是我改造了 Okio 日志拦截器:
classOkioLogInterceptorprivateconstructor( privatevardir: String) : LogInterceptor {
privatevalhandlerThread = HandlerThread( "log_to_file_thread")
privatevalhandler: Handler
privatevaldispatcher: CoroutineDispatcher
privatevarbufferedSink: BufferedSink? = null
// 初始化时,只新建一次文件
privatevarlogFile = File(getFileName)
varstartTime = System.currentTimeMillis
companionobject{
@Volatile
privatevarINSTANCE: OkioLogInterceptor? = null
fungetInstance(dir: String) : OkioLogInterceptor =
INSTANCE ?: synchronized( this) {
INSTANCE ?: OkioLogInterceptor(dir).apply { INSTANCE = this}
}
}
init{
handlerThread.start
handler = Handler(handlerThread.looper)
dispatcher = handler.asCoroutineDispatcher( "log_to_file_dispatcher")
}
overridefunlog(priority: Int, tag: String, log: String) {
if(!handlerThread.isAlive) handlerThread.start
GlobalScope.launch(dispatcher) {
valsink = checkSink
sink.writeUtf8( "[ $tag] $log" )
sink.writeUtf8( "\n")
if(log == "work done") Log.v( "ttaylor1", "log work is ok done= ${System.currentTimeMillis - startTime}" )
}
returnfalse
}
privatefungetToday: String =
SimpleDateFormat( "yyyy-MM-dd").format(Calendar.getInstance.time)
privatefungetFileName= " $dir${File.separator}${getToday}.log"
// 不关流,复用 bufferedSink 对象
privatefuncheckSink: BufferedSink {
if(bufferedSink == null) {
bufferedSink = logFile.appendingSink.buffer
}
returnbufferedSink!!
}
}
新增了成员变量 logFile 和 bufferedSink,避免了每次打 Log 时重新构建它们。而且我没有在每次打完 Log 就把输出流关闭掉。重新跑一下测试代码,奇迹发生了:
ttaylor1: log work isdone= 832
1万条 Log 写入的时间从 9411 ms 缩短到 832 ms,整整缩短了 11 倍!!
这个结果有点难以置信,我连忙从手机中拉取了日志文件,非常担心是因为程序 bug 导致日志输出不全。
果不其然,正确的日志文件应该包含 1 万行,而现在只有 9901 行。
转念一下,不对啊,一次flush都没有调用,为啥文件中会有日志?
哦~,肯定是因为内存中的输出缓冲区满了之后自动进行了 flush 操作。
然后我用同样的思路写了一个 FileWriter 的版本,跑了一下测试代码:
ttaylor1: FileWriter log work isdone= 1439
这下可把 FileWriter 和 Okio 的差距显现出来了,将近一倍的速度差距。算是为技术选型 Okio 提供了有利的数据支持!
感知日志打印结束?
但还有一个问题急需解决:Log 输出不全。
这是因为当最后一条日志写入缓冲区时,若缓冲区未满就不会执行 flush 操作。这种情况下需要手动 flush。
如何感知到最后一条 Log?做不到!因为打 Log 是业务层行为,底层 Log 库无法感知上层行为。
这个场景让我联想到 “搜索框防抖”,即当你在键入关键词后,自动发起搜索的行为。
用流的思想理解上面的场景:输入框是流数据的生产者,其内容每变化一次,就是在流上生产了一个新数据。但并不是每一个数据都需要被消费,所以得做“限流”,即丢弃一切发射间隔过短的数据,直到生产出某个数据之后一段时间内不再有新数据。
Flow 的操作符 debounce 就非常契合这个场景。
它的背后机制是:每当流产生新数据时,开启倒计时,如果在倒计时归零之前没有新数据,则将最后那个数据发射出去,否则重新开启倒计时。
知道了背后的机制,就不需要拘泥于具体的实现方式,使用 Android 中的消息机制也能实现同样的效果(日志拦截器正好使用了 HandlerThread,现成的消息机制)。
每当新日志到来时,将其封装为一条消息发送给 Handler,紧接着再发送一条延迟消息,若有后续日志,则移除延迟消息,并重发一条新延迟消息。若无后续日志,Handler 终将收到延迟消息,此时就执行 flush 操作。
(Android 中判定 Activity 生命周期超时也是用这套机制,感兴趣的可以搜索 com.android.server.wm.ActivityStack.STOP_TIMEOUT_MSG)
改造后的日志拦截器如下:
classOkioLogInterceptorprivateconstructor( privatevardir: String) : LogInterceptor {
privatevalhandlerThread = HandlerThread( "log_to_file_thread")
privatevalhandler: Handler
privatevarstartTime = System.currentTimeMillis
privatevarbufferedSink: BufferedSink? = null
privatevarlogFile = File(getFileName)
// 日志消息处理器
valcallback = Handler.Callback { message ->
valsink = checkSink
when(message.what) {
// flush 日志
TYPE_FLUSH -> {
sink.use {
it.flush
bufferedSink = null
}
}
// 写日志
TYPE_LOG -> {
vallog = message.obj asString
sink.writeUtf8(log)
sink.writeUtf8( "\n")
}
}
// 统计耗时
if(message.obj as? String == "work done") Log.v(
"ttaylor1",
"log work is done= ${System.currentTimeMillis - startTime}"
)
false
}
companionobject{
privateconstvalTYPE_FLUSH = - 1
privateconstvalTYPE_LOG = 1
// 若 3000 ms 内没有新日志请求,则执行 flush
privateconstvalFLUSH_LOG_DELAY_MILLIS = 3000L
@Volatile
privatevarINSTANCE: OkioLogInterceptor? = null
fungetInstance(dir: String) : OkioLogInterceptor =
INSTANCE ?: synchronized( this) {
INSTANCE ?: OkioLogInterceptor(dir).apply { INSTANCE = this}
}
}
init{
handlerThread.start
handler = Handler(handlerThread.looper, callback)
}
overridefunlog(priority: Int, tag: String, log: String) {
if(!handlerThread.isAlive) handlerThread.start
handler.run {
// 移除上一个延迟消息
removeMessages(TYPE_FLUSH)
// 将日志作为一条消息发送出去
obtainMessage(TYPE_LOG, "[ $tag] log" ).sendToTarget
// 构建延迟消息并发送
valflushMessage = handler.obtainMessage(TYPE_FLUSH)
sendMessageDelayed(flushMessage, FLUSH_LOG_DELAY_MILLIS)
}
returnfalse
}
privatefungetToday: String =
SimpleDateFormat( "yyyy-MM-dd").format(Calendar.getInstance.time)
privatefungetFileName= " $dir${File.separator}${getToday}.log"
privatefuncheckSink: BufferedSink {
if(bufferedSink == null) {
bufferedSink = logFile.appendingSink.buffer
}
returnbufferedSink!!
}
}
Talk is cheap, show me the code
EasyLog 已上传 GitHub,链接 https://github.com/wisdomtl/EasyLog
总结
“简单”和“弹性”是库设计中首要关注的两个方面。
Kotlin 有诸多语法特性能极大地降低代码的复杂度。
真责任链模式非常适用于为日志库提供弹性。它使得动态为日志库新增功能成为可能,它使得每次的处理结果得以在传递给后续处理者。
用HandlerThread实现异步串行日志输出。
用Okio实现高性能的日志文件化。
在高频日志文件化的场景下,复用输出流能极大地提高性能。同时需要延迟消息机制保证日志的完整性。
为了防止失联,欢迎关注我防备的小号
微信改了推送机制,真爱请星标本公号👇 返回搜狐,查看更多
责任编辑: