设计一套完整的日志系统

需求
日志对于线上排查问题是非常重要的,很多问题其实是很偶现的,同样的系统版本,同样的设备,可能就是用户的复现,而开发通过相同的操作和设备就是不复现。但是这个问题也不能一直不解决,所以可以通过日志的方式排查问题。可能是后台导致的问题,也可能是客户端逻辑问题,在关键点记录日志可以快速定位问题。
假设我们的用户量是一百万日活,其中有1%的用户使用出现问题,即使这个问题并不是崩溃,就是业务上或播放出现问题。那这部分用户就是一万的用户,一万的用户数量是很庞大的。而且大多数用户在遇到问题后,并不会主动去联系客服,而是转到其他平台上。
虽然我们现在有Kibana网络监控,但是只能排查网络请求是否有问题,用户是否在某个时间请求了服务器,服务器下发的数据是否正确,但是如果定位业务逻辑的问题,还是要客户端记录日志。
现状
【设计一套完整的日志系统】我们项目中之前有日志系统,但是从业务和技术的角度来说,存在两个问题。现有的日志系统从业务层角度,需要用户手动导出并发给客服,对用户有不必要的打扰。而且大多数用户并不会答应客服的请求,不会导出日志给客服。从技术的角度,现有的日志系统代码很乱,而且性能很差,导致线上不敢持续记录日志,会导致播放器卡顿。
而且现有的日志系统仅限于debug环境开启主动记录,线上是不开启的,线上出问题后需要用户手动打开,并且记录时长只有三分钟。正是由于现在存在的诸多问题,所以大家对日志的使用并不是很积极,线上排查问题就比较困难。
方案设计
思路 正是针对现在存在的问题,我准备做一套新的日志系统,来替代现有的日志系统。新的日志系统定位很简单,就是纯粹的记录业务日志。Crash、埋点这些,我们都不记录在里面,这些可以当做以后的扩展。日志系统就记录三种日志,业务日志、网络日志、播放器日志。
日志收集我们采用的主动回捞策略,在日志平台上填写用户的uid,通过uid对指定设备下发回捞指令,回捞指令通过长连接的方式下发。客户端收到回捞指令后,根据筛选条件对日志进行筛选,随后以天为单位写入到不同的文件中,压缩后上传到后端。
在日志平台可以根据指定的条件进行搜索,并下载文件查看日志。为了便于开发者查看日志,从数据库取出的日志都会写成.txt形式,并上传此文件。
API设计 对于调用的API设计,应该足够简单,业务层使用时就像调用NSLog一样。所以对于API的设计方案,我采用的是宏定义的方式,调用方法和NSLog一样,调用很简单。

#if DEBUG #define SVLogDebug(frmt, ...)[[SVLogManager sharedInstance] mobileLogContent:(frmt), ##__VA_ARGS__] #else #define SVLogDebug(frmt, ...)NSLog(frmt, ...) #endif

日志总共分为三种类型,业务日志、播放器日志、网络日志,对于三种日志分别对应着不同的宏定义。不同的宏定义,写入数据库的类型也不一样,可以用户日志筛选。
  • 业务日志:SVLogDebug
  • 播放器日志:SVLogDebugPlayer
  • 网络日子:SVLogDebugQUIC
淘汰策略 不光是要往数据库里写,还需要考虑淘汰策略。淘汰策略需要平衡记录的日志数量,以及时效性的问题,日志数量尽量够排查问题,并且还不会占用过多的磁盘空间。所以,在日志上传之后会将已上传日志删除掉,除此之外日志淘汰策略有以下两种。
  1. 日志最多只保存三天,三天以前的日志都会被删掉。在应用启动后进行检查,并后台线程执行这个过程。
  2. 日志增加一个最大阈值,超过阈值的日志部分,以时间为序,从前往后删除。我们定义的阈值大小为200MB,一般不会超过这个大小。
记录基础信息 在排查问题时一些关键信息也很重要,例如用户当时的网络环境,以及一些配置项,这些因素对代码的执行都会有一些影响。对于这个问题,我们也会记录一些用户的配置信息及网络环境,方便排查问题,但不会涉及用户经纬度等隐私信息。
数据库
旧方案 之前的日志方案是通过DDLog实现的,这种方案有很严重的性能问题。其写入日志的方式,是通过NSData来实现的,在沙盒创建一个txt文件,通过一个句柄来向本地写文件,每次写完之后把句柄seek到文件末尾,下次直接在文件末尾继续写入日志。日志是以NSData的方式进行处理的,相当于一直在频繁的进行本地文件写入操作,还要在内存中维持一个或者多个句柄对象。
这种方式还有个问题在于,因为是直接进行二进制写入,在本地存储的是txt文件。这种方式是没有办法做筛选之类的操作的,扩展性很差,所以新的日志方案我们打算采用数据库来实现。
方案选择 我对比了一下iOS平台主流的数据库,发现WCDB是综合性能最好的,某些方面比FMDB都要好,而且由于是C++实现的代码,所以从代码执行的层面来讲,也不会有OC的消息发送和转发的额外消耗。
根据WCDB官网的统计数据,WCDBFMDB进行对比,FMDB是对SQLite进行简单封装的框架,和直接用SQLite差别不是很大。而WCDB则在sqlcipher的基础上进行的深度优化,综合性能比FMDB要高,以下是性能对比,数据来自WCDB官方文档。
单次读操作WCDB要比FMDB5%左右,在for循环内一直读。
设计一套完整的日志系统
文章图片

单次写操作WCDB要比FMDB28%,一个for循环一直写。
设计一套完整的日志系统
文章图片

批量写操作比较明显,WCDB要比FMDB180%,一个批量任务写入一批数据。
设计一套完整的日志系统
文章图片

从数据可以看出,WCDB在写操作这块性能要比FMDB要快很多,而本地日志最频繁的就是写操作,所以这正好符合我们的需求,所以选择WCDB作为新的数据库方案是最合适的。而且项目中曝光模块已经用过WCDB,证明这个方案是可行并且性能很好的。
表设计 我们数据库的表设计很简单,就下面四个字段,不同类型的日志用type做区分。如果想增加新的日志类型,也可以在项目中扩展。因为使用的是数据库,所以扩展性很好。
  • index:主键,用来做索引。
  • content:日志内容,记录日志内容。
  • createTime:创建时间,日志入库的时间。
  • type:日志类型,用来区分三种类型。
数据库优化 我们是视频类应用,会涉及播放、下载、上传等主要功能,这些功能都会大量记录日志,来方便排查线上问题。所以,避免数据库太大就成了我在设计日志系统时,比较看重的一点。
根据日志规模,我对播放、下载、上传三个模块进行了大量测试,播放一天两夜、下载40集电视剧、上传多个高清视频,累计记录的日志数量大概五万多条。我发现数据库文件夹已经到200MB+的大小,这个大小已经是比较大的,所以需要对数据库进行优化。
我观察了一下数据库文件夹,有三个文件,dbshmwal,主要是数据库的日志文件太大,db文件反而并不大。所以需要调用sqlite3_wal_checkpointwal内容写入到数据库中,这样可以减少walshm文件的大小。但WCDB并没有提供直接checkpoint的方法,所以经过调研发现,执行database的关闭操作时,可以触发checkpoint
我在应用程序退出时,监听了terminal通知,并且把处理实际尽量靠后。这样可以保证日志不被遗漏,而且还可以在程序退出时关闭数据库。经过验证,优化后的数据库磁盘占用很小。143,987条数据库,数据库文件大小为34.8MB,压缩后的日志大小为1.4MB,解压后的日志大小为13.6MB
wal模式 这里顺带讲一下wal模式,以方便对数据库有更深入的了解。SQLite3.7版本加入了wal模式,但默认是不开启的,iOS版的WCDBwal模式自动开启,并且做了一些优化。
wal文件负责优化多线程下的并发操作,如果没有wal文件,在传统的delete模式下,数据库的读写操作是互斥的,为了防止写到一半的数据被读到,会等到写操作执行完成后,再执行读操作。而wal文件就是为了解决并发读写的情况,shm文件是对wal文件进行索引的。
SQLite比较常用的deletewal两种模式,这两种模式各有优势。delete是直接读写db-page,读写操作的都是同一份文件,所以读写是互斥的,不支持并发操作。而walappend新的db-page,这样写入速度比较快,而且可以支持并发操作,在写入的同时不读取正在操作的db-page即可。
由于delete模式操作的db-page是离散的,所以在执行批量写操作时,delete模式的性能会差很多,这也就是为什么WCDB的批量写入性能比较好的原因。而wal模式读操作会读取dbwal两个文件,这样会一定程度影响读数据的性能,所以wal的查询性能相对delete模式要差。
使用wal模式需要控制wal文件的db-page数量,如果page数量太大,会导致文件大小不受控制。wal文件并不是一直增加的,根据SQLite的设计,通过checkpoint操作可以将wal文件合并到db文件中。但同步的时机会导致查询操作被阻塞,所以不能频繁执行checkpoint。在WCDB中设置了一个1000的阈值,当page达到1000后才会执行一次checkpoint
这个1000是微信团队的一个经验值,太大会影响读写性能,而且占用过多的磁盘空间。太小会频繁执行checkpoint,导致读写受阻。
# define SQLITE_DEFAULT_WAL_AUTOCHECKPOINT1000sqlite3_wal_autocheckpoint(db, SQLITE_DEFAULT_WAL_AUTOCHECKPOINT); int sqlite3_wal_autocheckpoint(sqlite3 *db, int nFrame){ #ifdef SQLITE_OMIT_WAL UNUSED_PARAMETER(db); UNUSED_PARAMETER(nFrame); #else #ifdef SQLITE_ENABLE_API_ARMOR if( !sqlite3SafetyCheckOk(db) ) return SQLITE_MISUSE_BKPT; #endif if( nFrame>0 ){ sqlite3_wal_hook(db, sqlite3WalDefaultHook, SQLITE_INT_TO_PTR(nFrame)); }else{ sqlite3_wal_hook(db, 0, 0); } #endif return SQLITE_OK; }

也可以设置日志文件的大小限制,默认是-1,也就是没限制,journalSizeLimit的意思是,超出的部分会被覆写。尽量不要修改这个文件,可能会导致wal文件损坏。
i64 sqlite3PagerJournalSizeLimit(Pager *pPager, i64 iLimit){ if( iLimit>=-1 ){ pPager->journalSizeLimit = iLimit; sqlite3WalLimit(pPager->pWal, iLimit); } return pPager->journalSizeLimit; }

下发指令
日志平台 日志上报应该做到用户无感知,不需要用户主动配合即可进行日志的自动上传。而且并不是所有的用户日志都需要上报,只有出问题的用户日志才是我们需要的,这样也可以避免服务端的存储资源浪费。对于这些问题,我们开发了日志平台,通过下发上传指令的方式告知客户端上传日志。
设计一套完整的日志系统
文章图片

我们的日志平台做的比较简单,输入uid对指定的用户下发上传指令,客户端上传日志之后,也可以通过uid进行查询。如上图,下发指令时可以选择下面的日志类型和时间区间,客户端收到指令后会根据这些参数做筛选,如果没选择则是默认参数。搜索时也可以使用这三个参数。
日志平台对应一个服务,点击按钮下发上传指令时,服务会给长连接通道下发一个jsonjson中包含上面的参数,以后也可以用来扩展其他字段。上传日志是以天为单位的,所以在这里可以根据天为单位进行搜索,点击下载可以直接预览日志内容。
长连接通道 指令下发这块我们利用了现有的长连接,当用户反馈问题后,我们会记录下用户的uid,如果技术需要日志进行排查问题时,我们会通过日志平台下发指令。
指令会发送到公共的长连接服务后台,服务会通过长连接通道下发指令,如果指令下发到客户端之后,客户端会回复一个ack消息回复,告知通道已经收到指令,通道会将这条指令从队列中移除。如果此时用户未打开App,则这条指令会在下次用户打开App,和长连接通道建立连接时重新下发。
未完成的上传指令会在队列中,但最多不超过三天,因为超过三天的指令就已经失去其时效性,问题当时可能已经通过其他途径解决。
静默push 用户如果打开App时,日志指令的下发可以通过长连接通道下发。还有一种场景,也是最多的一种场景,用户未打开App怎么解决日志上报的问题,这块我们还在探索中。
当时也调研了美团的日志回捞,美团的方案中包含了静默push的策略,但是经过我们调研之后,发现静默push基本意义不大,只能覆盖一些很小的场景。例如用户App被系统kill掉,或者在后台被挂起等,这种场景对于我们来说并不多见。另外和push组的人也沟通了一下,push组反馈说静默push的到达率有些问题,所以就没采用静默push的策略。
日志上传
分片上传 进行方案设计的时候,由于后端不支持直接展示日志,只能以文件的方式下载下来。所以当时和后端约定的是以天为单位上传日志文件,例如回捞的时间点是,开始时间4月21日19:00,结束时间4月23日21:00。对于这种情况会被分割为三个文件,即每天为一个文件,第一天的文件只包含19:00开始的日志,最后一天的文件只包含到21:00的日志。
这种方案也是分片上传的一种策略,上传时以每个日志文件压缩一个zip文件后上传。这样一方面是保证上传成功率,文件太大会导致成功率下降,另一方面是为了做文件分割。经过观察,每个文件压缩成zip后,文件大小可以控制在500kb以内,500kb这个是我们之前做视频切片上传时的一个经验值,这个经验值是上传成功率和分片数量的一个平衡点。
日志命名使用时间戳为组合,时间单位应该精确到分钟,以方便服务端做时间筛选操作。上传以表单的方式进行提交,上传完成后会删除对应的本地日志。如果上传失败则使用重试策略,每个分片最多上传三次,如果三次都上传失败,则这次上传失败,在其他时机再重新上传。
安全性 为了保证日志的数据安全性,日志上传的请求我们通过https进行传输,但这还是不够的,https依然可以通过其他方式获取到SSL管道的明文信息。所以对于传输的内容,也需要进行加密,选择加密策略时,考虑到性能问题,加密方式采用的对称加密策略。
但对称加密的秘钥是通过非对称加密的方式下发的,并且每个上传指令对应一个唯一的秘钥。客户端先对文件进行压缩,对压缩后的文件进行加密,加密后分片再上传。服务端收到加密文件后,通过秘钥解密得到zip并解压缩。
主动上报 新的日志系统上线后,我们发现回捞成功率只有40%,因为有的用户反馈问题后就失去联系,或者反馈问题后一直没有打开App。对于这个问题,我分析用户反馈问题的途径主要有两大类,一种是用户从系统设置里进去反馈问题,并且和客服沟通后,技术介入排查问题。另一种是用户发生问题后,通过反馈群、App Store评论区、运营等渠道反馈的问题。
这两种方式都适用于日志回捞,但第一种由于有特定的触发条件,也就是用户点击进入反馈界面。所以,对于这种场景反馈问题的用户,我们增加了主动上报的方式。即用户点击反馈时,主动上报以当前时间为结束点,三天内的日志。这样可以把日志上报的成功率提升到90%左右,成功率上来后也会推动更多人接入日志模块,方便排查线上问题。
手动导出 日志上传的方式还包含手动导出,手动导出就是通过某种方式进入调试页面,在调试页面选择对应的日志分享,并且调起系统分享面板,通过对应的渠道分享出去。在新的日志系统之前,就是通过这种方式让用户手动导出日志给客服的,可想而知对用户的打扰有多严重吧。
现在手动导出的方式依然存在,但只用于debug阶段测试和开发同学,手动导出日志来排查问题,线上是不需要用户手动操作的。
设计一套完整的日志系统
文章图片

    推荐阅读