之前我们分析过关于android log机制,在这里我们再详细说下,log丢失的原理。
一、统计log
logd监听了logdw的socket来保存从log打印函数通过logdw socket传过来的log,最后会调用LogBuffer::log函数,在log函数最后会调用如下两个函数。
stats.add(elem);
maybePrune(log_id);
这里的log_id就是radio,main,event等。
我们先来看LogStatistics::add函数
void LogStatistics::add(LogBufferElement *e) {
log_id_t log_id = e->getLogId();
unsigned short size = e->getMsgLen();//获取消息长度
mSizes[log_id] += size;//对每个log_id做长度累计
++mElements[log_id];//对每个log_id做消息个数累计
mSizesTotal[log_id] += size;
++mElementsTotal[log_id];
if (log_id == LOG_ID_KERNEL) {
return;
}
uidTable[log_id].add(e->getUid(), e);
if (!enable) {
return;
}
pidTable.add(e->getPid(), e);
tidTable.add(e->getTid(), e);
uint32_t tag = e->getTag();
if (tag) {
tagTable.add(tag, e);
}
}
这个函数,对每个log_id的消息长度做统计,消息数量也做了统计。
二、删除log判定
我们再来看下这个maybePrune函数
// Prune at most 10% of the log entries or 256, whichever is less.
//
// mLogElementsLock must be held when this function is called.
void LogBuffer::maybePrune(log_id_t id) {
size_t sizes = stats.sizes(id);//每个log_id统计的所有消息长度
unsigned long maxSize = log_buffer_size(id);//每个log_id缓存的最大值,之前在init函数里面初始化的
if (sizes > maxSize) {
size_t sizeOver = sizes - ((maxSize * 9) / 10);//超过90%size的那部分
size_t elements = stats.elements(id);
size_t minElements = elements / 10;//10%的elements
unsigned long pruneRows = elements * sizeOver / sizes;//超过90%size的elements
if (pruneRows <= minElements) {
pruneRows = minElements;
}
if (pruneRows > 256) {
pruneRows = 256;
}
prune(id, pruneRows);
}
}
在之前的博客中我们分析过了,每个log_id的size是如何而来的。可以通过属性获取。
这里保存elements的是mLogElements,只是保存的LogBufferElement 的指针而已,实际不会占用多大的内存。
typedef std::list<LogBufferElement *> LogBufferElementCollection;
class LogBuffer {
LogBufferElementCollection mLogElements;
而且只有每个element被调用erase,才会被真正销毁内存。
LogBufferElementCollection::iterator LogBuffer::erase(
LogBufferElementCollection::iterator it, bool engageStats) {
LogBufferElement *e = *it;
log_id_t id = e->getLogId();
LogBufferIteratorMap::iterator f = mLastWorstUid[id].find(e->getUid());
if ((f != mLastWorstUid[id].end()) && (it == f->second)) {
mLastWorstUid[id].erase(f);
}
it = mLogElements.erase(it);
if (engageStats) {
stats.subtract(e);
} else {
stats.erase(e);
}
delete e;//销毁内存
return it;
}
所以每个log_id设定的值,不是一个缓存,而是一个警戒值。超过这个值,就要对特定log删除。
三、prune函数
prune函数主要就是删除log,在删除log的时候也做了白名单和黑名单的机制。
3.1 白名单 & 黑名单
这里我们先来看看LogBuffer的initPrune函数,这是用来设定白名单和黑名单的。
int initPrune(char *cp) { return mPrune.init(cp); }
至于init这个函数我们就不看了,主要是解析字符串,把uid,pid保存下来。
那么又在哪里设定白名单和黑名单呢?我们可以通过如下命令,最后就调用了initPrune函数来设定白黑名单了。
int CommandListener::SetPruneListCmd::runCommand(SocketClient *cli,
int argc, char **argv) {
setname();
if (!clientHasLogCredentials(cli)) {
cli->sendMsg("Permission Denied");
return 0;
}
char *cp = NULL;
for (int i = 1; i < argc; ++i) {
char *p = cp;
if (p) {
cp = NULL;
asprintf(&cp, "%s %s", p, argv[i]);
free(p);
} else {
asprintf(&cp, "%s", argv[i]);
}
}
int ret = mBuf.initPrune(cp);
free(cp);
if (ret) {
cli->sendMsg("Invalid");
return 0;
}
cli->sendMsg("success");
return 0;
}
而每个白名单和黑名单的匹配就是看uid和pid的。这块就不细看了。
3.2 黑名单处理 & log最多的uid处理
下面我们就来看下prune这个函数的黑名单部分处理:
void LogBuffer::prune(log_id_t id, unsigned long pruneRows, uid_t caller_uid) {
......
// prune by worst offender by uid
bool hasBlacklist = mPrune.naughty();//这块是黑名单部分
while (pruneRows > 0) {
// recalculate the worst offender on every batched pass
uid_t worst = (uid_t) -1;
size_t worst_sizes = 0;
size_t second_worst_sizes = 0;
if (worstUidEnabledForLogid(id) && mPrune.worstUidEnabled()) {
std::unique_ptr<const UidEntry *[]> sorted = stats.sort(2, id);//得到log最多的2个uid
if (sorted.get()) {
if (sorted[0] && sorted[1]) {
worst_sizes = sorted[0]->getSizes();
// Calculate threshold as 12.5% of available storage
size_t threshold = log_buffer_size(id) / 8;
if ((worst_sizes > threshold)//大于阈值
// Allow time horizon to extend roughly tenfold, assume
// average entry length is 100 characters.
&& (worst_sizes > (10 * sorted[0]->getDropped()))) {
worst = sorted[0]->getKey();//最多lod uid的size
second_worst_sizes = sorted[1]->getSizes();
if (second_worst_sizes < threshold) {
second_worst_sizes = threshold;
}
}
}
}
}
// skip if we have neither worst nor naughty filters
if ((worst == (uid_t) -1) && !hasBlacklist) {//如果没有这样的uid,也没有黑名单,直接跳过
break;
}
bool kick = false;
bool leading = true;
it = mLogElements.begin();
// Perform at least one mandatory garbage collection cycle in following
// - clear leading chatty tags
// - merge chatty tags
// - check age-out of preserved logs
bool gc = pruneRows <= 1;
if (!gc && (worst != (uid_t) -1)) {
LogBufferIteratorMap::iterator f = mLastWorstUid[id].find(worst);//查找这uid
if ((f != mLastWorstUid[id].end())
&& (f->second != mLogElements.end())) {
leading = false;//找到了,leading为false
it = f->second;
}
}
static const timespec too_old = {
EXPIRE_HOUR_THRESHOLD * 60 * 60, 0
};
LogBufferElementCollection::iterator lastt;
lastt = mLogElements.end();
--lastt;
LogBufferElementLast last;
while (it != mLogElements.end()) {
LogBufferElement *e = *it;
if (oldest && (oldest->mStart <= e->getSequence())) {
break;
}
if (e->getLogId() != id) {//log_id不对 continue
++it;
continue;
}
unsigned short dropped = e->getDropped();//是否被free过mMsg
// remove any leading drops
if (leading && dropped) {
it = erase(it);
continue;
}
// merge any drops
if (dropped && last.merge(e, dropped)) {// 合并之前删除的element
it = erase(it, false);
continue;
}
if (hasBlacklist && mPrune.naughty(e)) {//如果满足黑名单,删除这条element
last.clear(e);
it = erase(it);
if (dropped) {//如果当前是dropoed,直接continue
continue;
}
pruneRows--;//删除log的计数
if (pruneRows == 0) {
break;
}
if (e->getUid() == worst) {
kick = true;
if (worst_sizes < second_worst_sizes) {//最差值,小于第二个直接跳过
break;
}
worst_sizes -= e->getMsgLen();//最差的值累减
}
continue;
}
if ((e->getRealTime() < ((*lastt)->getRealTime() - too_old))
|| (e->getRealTime() > (*lastt)->getRealTime())) {
break;
}
// unmerged drop message
if (dropped) {
last.add(e);
if ((!gc && (e->getUid() == worst))
|| (mLastWorstUid[id].find(e->getUid())
== mLastWorstUid[id].end())) {
mLastWorstUid[id][e->getUid()] = it;
}
++it;
continue;
}
if (e->getUid() != worst) {
leading = false;
last.clear(e);
++it;
continue;
}
pruneRows--;
if (pruneRows == 0) {
break;
}
kick = true;
unsigned short len = e->getMsgLen();
// do not create any leading drops
if (leading) {
it = erase(it);
} else {
stats.drop(e);
e->setDropped(1);//setDropped函数,这里就是普通的是worst这个uid的log,但不是黑名单中。就把它的消息清空
if (last.merge(e, 1)) {//合并
it = erase(it, false);//合并之后,删除现有log
} else {
last.add(e);
if (!gc || (mLastWorstUid[id].find(worst)
== mLastWorstUid[id].end())) {
mLastWorstUid[id][worst] = it;
}
++it;
}
}
if (worst_sizes < second_worst_sizes) {//最差值小于第二差就跳过
break;
}
worst_sizes -= len;
}
last.clear();
if (!kick || !mPrune.worstUidEnabled()) {
break; // the following loop will ask bad clients to skip/drop
}
}
.....
上面就是对黑名单以及log最多的那个uid的处理,我们先来看看每个LogBufferElement的setDropped函数
unsigned short setDropped(unsigned short value) {
if (mMsg) {
free(mMsg);//消息清空
mMsg = NULL;
}
return mDropped = value;//第一次为1
}
这个函数直接把消息清空了,然后把mDropped设为1,我们再来看看last.merge(e, 1)函数
class LogBufferElementLast {
typedef std::unordered_map<uint64_t, LogBufferElement *> LogBufferElementMap;
LogBufferElementMap map;
public:
bool merge(LogBufferElement *e, unsigned short dropped) {
LogBufferElementKey key(e->getUid(), e->getPid(), e->getTid());
LogBufferElementMap::iterator it = map.find(key.getKey());
if (it != map.end()) {
LogBufferElement *l = it->second;
unsigned short d = l->getDropped();
if ((dropped + d) > USHRT_MAX) {
map.erase(it);
} else {
l->setDropped(dropped + d);//将两个element合并
return true;
}
}
return false;
}
通过merge,element的mDropped可以不为1了。
3.3 白名单处理
下面我们再看下白名单处理:
bool whitelist = false;
bool hasWhitelist = mPrune.nice();
it = mLogElements.begin();
while((pruneRows > 0) && (it != mLogElements.end())) {
LogBufferElement *e = *it;
if (e->getLogId() != id) {
it++;
continue;
}
if (oldest && (oldest->mStart <= e->getSequence())) {
if (whitelist) {
break;
}
if (stats.sizes(id) > (2 * log_buffer_size(id))) {
// kick a misbehaving log reader client off the island
oldest->release_Locked();
} else {
oldest->triggerSkip_Locked(id, pruneRows);
}
break;
}
if (hasWhitelist && !e->getDropped() && mPrune.nice(e)) { // WhiteListed
whitelist = true;
it++;
continue;
}
it = erase(it);
pruneRows--;
}
白名单的处理比较简单,只要是白名单的不删除,其他都删除,直到满足条件。
四、logcat取log
之前的博客分析过当logcat进程到logd中取log时,会最终调用LogBufferElement::flushTo函数
uint64_t LogBufferElement::flushTo(SocketClient *reader, LogBuffer *parent) {
struct logger_entry_v3 entry;
memset(&entry, 0, sizeof(struct logger_entry_v3));
entry.hdr_size = sizeof(struct logger_entry_v3);
entry.lid = mLogId;
entry.pid = mPid;
entry.tid = mTid;
entry.sec = mRealTime.tv_sec;
entry.nsec = mRealTime.tv_nsec;
struct iovec iovec[2];
iovec[0].iov_base = &entry;
iovec[0].iov_len = sizeof(struct logger_entry_v3);
char *buffer = NULL;
if (!mMsg) {//如果mMsg为null了,就是之前prune里面setPropped函数把mMsg设为null
entry.len = populateDroppedMessage(buffer, parent);
if (!entry.len) {
return mSequence;
}
iovec[1].iov_base = buffer;
} else {
entry.len = mMsgLen;
iovec[1].iov_base = mMsg;
}
iovec[1].iov_len = entry.len;
uint64_t retval = reader->sendDatav(iovec, 2) ? FLUSH_ERROR : mSequence;//发送给调用者
if (buffer) {
free(buffer);
}
return retval;
}
调用populateDroppedMessage函数最终会把消息设为类似:
chatty : uid=1000(system) RenderThread expire 3 lines
五、总结 & 解决方案
最后总结,在logd中如果有丢失log,可以设置log_id的缓冲设置再大写。如果是调试的话可以增加调试的白名单。而且在logd中丢失log肯定会有类似chatty这样的log,那就是删除了log最多的那个uid的log。而且会合并。
我们可以通过设置系统属性persist.logd.size来设置每个log id的最大缓存值(在开发者选项中也有这个设置,开发者选项中设置就不用重启设备了),或者persist.logd.size.radio设置每个id的最大缓存值。
步骤:
将手机连上电脑并且进入root
setproppersist.logd.size.radio 1024k
reboot 重启
另外可以用getprop | grep logd查看设置的属性是否生效
logcat -g 可以查看每个id 的缓存大小
当然这是通过属性的方法设置,我们还可以通过logcat的命令,logcat -G 10m是设置所有的id的大小,logcat -b radio -G 10m是设置radio的log的缓存大小
在logcat中有如下代码,处理设置缓存大小
如果logd中没有chatty这样的log,但是又有log丢失,那么就要怀疑在写log时,logdw的socket就有丢失。因为我们看下logdw是dgram类型的,这种socket是一种不可靠的报文传递保证效率但会有丢失。所有这样情况我们可以看把socket改成stream试试,看看是否有效果?
service logd /system/bin/logd
class core
socket logd stream 0666 logd logd
socket logdr seqpacket 0666 logd logd
socket logdw dgram 0222 logd logd
group root system
writepid /dev/cpuset/system-background/tasks
但是试了以后好像socket在连接的时候就有问题。
后续我们使用android4.4的的机制 kernel的log机制,这样就不会有丢失问题。