包教包会：设计一套完整日志系统

发表于 3年以前 | 总阅读数：206 次

需求

日志对于线上排查问题是非常重要的，很多问题其实是很偶现的，同样的系统版本，同样的设备，可能就是用户的复现，而开发通过相同的操作和设备就是不复现。但是这个问题也不能一直不解决，所以可以通过日志的方式排查问题。可能是后台导致的问题，也可能是客户端逻辑问题，在关键点记录日志可以快速定位问题。

假设我们的用户量是一百万日活，其中有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。

淘汰策略

不光是要往数据库里写，还需要考虑淘汰策略。淘汰策略需要平衡记录的日志数量，以及时效性的问题，日志数量尽量够排查问题，并且还不会占用过多的磁盘空间。所以，在日志上传之后会将已上传日志删除掉，除此之外日志淘汰策略有以下两种。

日志最多只保存三天，三天以前的日志都会被删掉。在应用启动后进行检查，并后台线程执行这个过程。
日志增加一个最大阈值，超过阈值的日志部分，以时间为序，从前往后删除。我们定义的阈值大小为200MB，一般不会超过这个大小。

记录基础信息

在排查问题时一些关键信息也很重要，例如用户当时的网络环境，以及一些配置项，这些因素对代码的执行都会有一些影响。对于这个问题，我们也会记录一些用户的配置信息及网络环境，方便排查问题，但不会涉及用户经纬度等隐私信息。

数据库

旧方案

之前的日志方案是通过DDLog实现的，这种方案有很严重的性能问题。其写入日志的方式，是通过NSData来实现的，在沙盒创建一个txt文件，通过一个句柄来向本地写文件，每次写完之后把句柄seek到文件末尾，下次直接在文件末尾继续写入日志。日志是以NSData的方式进行处理的，相当于一直在频繁的进行本地文件写入操作，还要在内存中维持一个或者多个句柄对象。

这种方式还有个问题在于，因为是直接进行二进制写入，在本地存储的是txt文件。这种方式是没有办法做筛选之类的操作的，扩展性很差，所以新的日志方案我们打算采用数据库来实现。

方案选择

我对比了一下iOS平台主流的数据库，发现WCDB是综合性能最好的，某些方面比FMDB都要好，而且由于是C++实现的代码，所以从代码执行的层面来讲，也不会有OC的消息发送和转发的额外消耗。

根据WCDB官网的统计数据，WCDB和FMDB进行对比，FMDB是对SQLite进行简单封装的框架，和直接用SQLite差别不是很大。而WCDB则在sqlcipher的基础上进行的深度优化，综合性能比FMDB要高，以下是性能对比，数据来自WCDB官方文档。

单次读操作WCDB要比FMDB慢5%左右，在for循环内一直读。

单次写操作WCDB要比FMDB快28%，一个for循环一直写。

批量写操作比较明显，WCDB要比FMDB快180%，一个批量任务写入一批数据。

从数据可以看出，WCDB在写操作这块性能要比FMDB要快很多，而本地日志最频繁的就是写操作，所以这正好符合我们的需求，所以选择WCDB作为新的数据库方案是最合适的。而且项目中曝光模块已经用过WCDB，证明这个方案是可行并且性能很好的。

表设计

我们数据库的表设计很简单，就下面四个字段，不同类型的日志用type做区分。如果想增加新的日志类型，也可以在项目中扩展。因为使用的是数据库，所以扩展性很好。

index：主键，用来做索引。
content：日志内容，记录日志内容。
createTime：创建时间，日志入库的时间。
type：日志类型，用来区分三种类型。

数据库优化

我们是视频类应用，会涉及播放、下载、上传等主要功能，这些功能都会大量记录日志，来方便排查线上问题。所以，避免数据库太大就成了我在设计日志系统时，比较看重的一点。

根据日志规模，我对播放、下载、上传三个模块进行了大量测试，播放一天两夜、下载40集电视剧、上传多个高清视频，累计记录的日志数量大概五万多条。我发现数据库文件夹已经到200MB+的大小，这个大小已经是比较大的，所以需要对数据库进行优化。

我观察了一下数据库文件夹，有三个文件，db、shm、wal，主要是数据库的日志文件太大，db文件反而并不大。所以需要调用sqlite3_wal_checkpoint将wal内容写入到数据库中，这样可以减少wal和shm文件的大小。但WCDB并没有提供直接checkpoint的方法，所以经过调研发现，执行database的关闭操作时，可以触发checkpoint。

我在应用程序退出时，监听了terminal通知，并且把处理实际尽量靠后。这样可以保证日志不被遗漏，而且还可以在程序退出时关闭数据库。经过验证，优化后的数据库磁盘占用很小。143,987条数据库，数据库文件大小为34.8MB，压缩后的日志大小为1.4MB，解压后的日志大小为13.6MB。

wal模式

这里顺带讲一下wal模式，以方便对数据库有更深入的了解。SQLite在3.7版本加入了wal模式，但默认是不开启的，iOS版的WCDB将wal模式自动开启，并且做了一些优化。

wal文件负责优化多线程下的并发操作，如果没有wal文件，在传统的delete模式下，数据库的读写操作是互斥的，为了防止写到一半的数据被读到，会等到写操作执行完成后，再执行读操作。而wal文件就是为了解决并发读写的情况，shm文件是对wal文件进行索引的。

SQLite比较常用的delete和wal两种模式，这两种模式各有优势。delete是直接读写db-page，读写操作的都是同一份文件，所以读写是互斥的，不支持并发操作。而wal是append新的db-page，这样写入速度比较快，而且可以支持并发操作，在写入的同时不读取正在操作的db-page即可。

由于delete模式操作的db-page是离散的，所以在执行批量写操作时，delete模式的性能会差很多，这也就是为什么WCDB的批量写入性能比较好的原因。而wal模式读操作会读取db和wal两个文件，这样会一定程度影响读数据的性能，所以wal的查询性能相对delete模式要差。

使用wal模式需要控制wal文件的db-page数量，如果page数量太大，会导致文件大小不受控制。wal文件并不是一直增加的，根据SQLite的设计，通过checkpoint操作可以将wal文件合并到db文件中。但同步的时机会导致查询操作被阻塞，所以不能频繁执行checkpoint。在WCDB中设置了一个1000的阈值，当page达到1000后才会执行一次checkpoint。

这个1000是微信团队的一个经验值，太大会影响读写性能，而且占用过多的磁盘空间。太小会频繁执行checkpoint，导致读写受阻。

# define SQLITE_DEFAULT_WAL_AUTOCHECKPOINT  1000

sqlite3_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进行查询。如上图，下发指令时可以选择下面的日志类型和时间区间，客户端收到指令后会根据这些参数做筛选，如果没选择则是默认参数。搜索时也可以使用这三个参数。

日志平台对应一个服务，点击按钮下发上传指令时，服务会给长连接通道下发一个json，json中包含上面的参数，以后也可以用来扩展其他字段。上传日志是以天为单位的，所以在这里可以根据天为单位进行搜索，点击下载可以直接预览日志内容。

长连接通道

指令下发这块我们利用了现有的长连接，当用户反馈问题后，我们会记录下用户的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%左右，成功率上来后也会推动更多人接入日志模块，方便排查线上问题。