/*
* Measure the time it takes for __android_log_is_loggable.
*/
static void BM_is_loggable(int iters) {
StartBenchmarkTiming();
for (int i = 0; i < iters; ++i) {
__android_log_is_loggable(ANDROID_LOG_WARN, "logd", ANDROID_LOG_VERBOSE);
}
StopBenchmarkTiming();
}
static jboolean isLoggable(const char* tag, jint level) {
return __android_log_is_loggable(level, tag, ANDROID_LOG_INFO);
}
// assumption: mMsg == NULL
size_t LogBufferElement::populateDroppedMessage(char *&buffer,
LogBuffer *parent) {
static const char tag[] = "chatty";
if (!__android_log_is_loggable(ANDROID_LOG_INFO, tag,
ANDROID_LOG_VERBOSE |
ANDROID_LOGGABLE_FLAG_NOT_WITHIN_SIGNAL)) {
return 0;
}
static const char format_uid[] = "uid=%u%s%s expire %u line%s";
parent->lock();
const char *name = parent->uidToName(mUid);
parent->unlock();
const char *commName = android::tidToName(mTid);
if (!commName && (mTid != mPid)) {
commName = android::tidToName(mPid);
}
if (!commName) {
parent->lock();
commName = parent->pidToName(mPid);
parent->unlock();
}
if (name && name[0] && commName && (name[0] == commName[0])) {
size_t len = strlen(name + 1);
if (!strncmp(name + 1, commName + 1, len)) {
if (commName[len + 1] == '\0') {
free(const_cast<char *>(commName));
commName = NULL;
} else {
free(const_cast<char *>(name));
name = NULL;
}
}
}
if (name) {
char *buf = NULL;
asprintf(&buf, "(%s)", name);
if (buf) {
free(const_cast<char *>(name));
name = buf;
}
}
if (commName) {
char *buf = NULL;
asprintf(&buf, " %s", commName);
if (buf) {
free(const_cast<char *>(commName));
commName = buf;
}
}
// identical to below to calculate the buffer size required
size_t len = snprintf(NULL, 0, format_uid, mUid, name ? name : "",
commName ? commName : "",
mDropped, (mDropped > 1) ? "s" : "");
size_t hdrLen;
if (mLogId == LOG_ID_EVENTS) {
hdrLen = sizeof(android_log_event_string_t);
} else {
hdrLen = 1 + sizeof(tag);
}
buffer = static_cast<char *>(calloc(1, hdrLen + len + 1));
if (!buffer) {
free(const_cast<char *>(name));
free(const_cast<char *>(commName));
return 0;
}
size_t retval = hdrLen + len;
if (mLogId == LOG_ID_EVENTS) {
android_log_event_string_t *event =
reinterpret_cast<android_log_event_string_t *>(buffer);
event->header.tag = htole32(LOGD_LOG_TAG);
event->type = EVENT_TYPE_STRING;
event->length = htole32(len);
} else {
++retval;
buffer[0] = ANDROID_LOG_INFO;
strcpy(buffer + 1, tag);
}
snprintf(buffer + hdrLen, len + 1, format_uid, mUid, name ? name : "",
commName ? commName : "",
mDropped, (mDropped > 1) ? "s" : "");
free(const_cast<char *>(name));
free(const_cast<char *>(commName));
return retval;
}
TEST(liblog, is_loggable) {
static const char tag[] = "is_loggable";
static const char log_namespace[] = "persist.log.tag.";
static const size_t base_offset = 8; /* skip "persist." */
// sizeof("string") = strlen("string") + 1
char key[sizeof(log_namespace) + sizeof(tag) - 1];
char hold[4][PROP_VALUE_MAX];
static const struct {
int level;
char type;
} levels[] = {
{ ANDROID_LOG_VERBOSE, 'v' },
{ ANDROID_LOG_DEBUG , 'd' },
{ ANDROID_LOG_INFO , 'i' },
{ ANDROID_LOG_WARN , 'w' },
{ ANDROID_LOG_ERROR , 'e' },
{ ANDROID_LOG_FATAL , 'a' },
{ -1 , 's' },
{ -2 , 'g' }, // Illegal value, resort to default
};
// Set up initial test condition
memset(hold, 0, sizeof(hold));
snprintf(key, sizeof(key), "%s%s", log_namespace, tag);
property_get(key, hold[0], "");
property_set(key, "");
property_get(key + base_offset, hold[1], "");
property_set(key + base_offset, "");
strcpy(key, log_namespace);
key[sizeof(log_namespace) - 2] = '\0';
property_get(key, hold[2], "");
property_set(key, "");
property_get(key, hold[3], "");
property_set(key + base_offset, "");
// All combinations of level and defaults
for(size_t i = 0; i < (sizeof(levels) / sizeof(levels[0])); ++i) {
if (levels[i].level == -2) {
continue;
}
for(size_t j = 0; j < (sizeof(levels) / sizeof(levels[0])); ++j) {
if (levels[j].level == -2) {
continue;
}
fprintf(stderr, "i=%zu j=%zu\r", i, j);
if ((levels[i].level < levels[j].level)
|| (levels[j].level == -1)) {
EXPECT_FALSE(__android_log_is_loggable(levels[i].level, tag,
levels[j].level));
} else {
EXPECT_TRUE(__android_log_is_loggable(levels[i].level, tag,
levels[j].level));
}
}
}
// All combinations of level and tag and global properties
for(size_t i = 0; i < (sizeof(levels) / sizeof(levels[0])); ++i) {
if (levels[i].level == -2) {
continue;
}
for(size_t j = 0; j < (sizeof(levels) / sizeof(levels[0])); ++j) {
char buf[2];
buf[0] = levels[j].type;
buf[1] = '\0';
snprintf(key, sizeof(key), "%s%s", log_namespace, tag);
fprintf(stderr, "i=%zu j=%zu property_set(\"%s\",\"%s\")\r",
i, j, key, buf);
property_set(key, buf);
if ((levels[i].level < levels[j].level)
|| (levels[j].level == -1)
|| ((levels[i].level < ANDROID_LOG_DEBUG)
&& (levels[j].level == -2))) {
EXPECT_FALSE(__android_log_is_loggable(levels[i].level, tag,
ANDROID_LOG_DEBUG));
} else {
EXPECT_TRUE(__android_log_is_loggable(levels[i].level, tag,
ANDROID_LOG_DEBUG));
}
property_set(key, "");
fprintf(stderr, "i=%zu j=%zu property_set(\"%s\",\"%s\")\r",
i, j, key + base_offset, buf);
property_set(key + base_offset, buf);
if ((levels[i].level < levels[j].level)
|| (levels[j].level == -1)
|| ((levels[i].level < ANDROID_LOG_DEBUG)
&& (levels[j].level == -2))) {
EXPECT_FALSE(__android_log_is_loggable(levels[i].level, tag,
ANDROID_LOG_DEBUG));
} else {
EXPECT_TRUE(__android_log_is_loggable(levels[i].level, tag,
ANDROID_LOG_DEBUG));
}
property_set(key + base_offset, "");
strcpy(key, log_namespace);
key[sizeof(log_namespace) - 2] = '\0';
fprintf(stderr, "i=%zu j=%zu property_set(\"%s\",\"%s\")\r",
i, j, key, buf);
property_set(key, buf);
if ((levels[i].level < levels[j].level)
|| (levels[j].level == -1)
|| ((levels[i].level < ANDROID_LOG_DEBUG)
&& (levels[j].level == -2))) {
EXPECT_FALSE(__android_log_is_loggable(levels[i].level, tag,
ANDROID_LOG_DEBUG));
} else {
EXPECT_TRUE(__android_log_is_loggable(levels[i].level, tag,
ANDROID_LOG_DEBUG));
}
property_set(key, "");
fprintf(stderr, "i=%zu j=%zu property_set(\"%s\",\"%s\")\r",
i, j, key + base_offset, buf);
property_set(key + base_offset, buf);
if ((levels[i].level < levels[j].level)
|| (levels[j].level == -1)
|| ((levels[i].level < ANDROID_LOG_DEBUG)
&& (levels[j].level == -2))) {
EXPECT_FALSE(__android_log_is_loggable(levels[i].level, tag,
ANDROID_LOG_DEBUG));
} else {
EXPECT_TRUE(__android_log_is_loggable(levels[i].level, tag,
ANDROID_LOG_DEBUG));
}
property_set(key + base_offset, "");
}
}
// All combinations of level and tag properties, but with global set to INFO
strcpy(key, log_namespace);
key[sizeof(log_namespace) - 2] = '\0';
property_set(key, "I");
snprintf(key, sizeof(key), "%s%s", log_namespace, tag);
for(size_t i = 0; i < (sizeof(levels) / sizeof(levels[0])); ++i) {
if (levels[i].level == -2) {
continue;
}
for(size_t j = 0; j < (sizeof(levels) / sizeof(levels[0])); ++j) {
char buf[2];
buf[0] = levels[j].type;
buf[1] = '\0';
fprintf(stderr, "i=%zu j=%zu property_set(\"%s\",\"%s\")\r",
i, j, key, buf);
property_set(key, buf);
if ((levels[i].level < levels[j].level)
|| (levels[j].level == -1)
|| ((levels[i].level < ANDROID_LOG_INFO) // Yes INFO
&& (levels[j].level == -2))) {
EXPECT_FALSE(__android_log_is_loggable(levels[i].level, tag,
ANDROID_LOG_DEBUG));
} else {
EXPECT_TRUE(__android_log_is_loggable(levels[i].level, tag,
ANDROID_LOG_DEBUG));
}
property_set(key, "");
fprintf(stderr, "i=%zu j=%zu property_set(\"%s\",\"%s\")\r",
i, j, key + base_offset, buf);
property_set(key + base_offset, buf);
if ((levels[i].level < levels[j].level)
|| (levels[j].level == -1)
|| ((levels[i].level < ANDROID_LOG_INFO) // Yes INFO
&& (levels[j].level == -2))) {
EXPECT_FALSE(__android_log_is_loggable(levels[i].level, tag,
ANDROID_LOG_DEBUG));
} else {
EXPECT_TRUE(__android_log_is_loggable(levels[i].level, tag,
ANDROID_LOG_DEBUG));
}
property_set(key + base_offset, "");
}
}
// reset parms
snprintf(key, sizeof(key), "%s%s", log_namespace, tag);
property_set(key, hold[0]);
property_set(key + base_offset, hold[1]);
strcpy(key, log_namespace);
key[sizeof(log_namespace) - 2] = '\0';
property_set(key, hold[2]);
property_set(key + base_offset, hold[3]);
}
int LogBuffer::log(log_id_t log_id, log_time realtime,
uid_t uid, pid_t pid, pid_t tid,
const char *msg, unsigned short len) {
if ((log_id >= LOG_ID_MAX) || (log_id < 0)) {
return -EINVAL;
}
LogBufferElement *elem = new LogBufferElement(log_id, realtime,
uid, pid, tid, msg, len);
int prio = ANDROID_LOG_INFO;
const char *tag = NULL;
if (log_id == LOG_ID_EVENTS) {
tag = android::tagToName(elem->getTag());
} else {
prio = *msg;
tag = msg + 1;
}
if (!__android_log_is_loggable(prio, tag, ANDROID_LOG_VERBOSE)) {
// Log traffic received to total
pthread_mutex_lock(&mLogElementsLock);
stats.add(elem);
stats.subtract(elem);
pthread_mutex_unlock(&mLogElementsLock);
delete elem;
return -EACCES;
}
pthread_mutex_lock(&mLogElementsLock);
// Insert elements in time sorted order if possible
// NB: if end is region locked, place element at end of list
LogBufferElementCollection::iterator it = mLogElements.end();
LogBufferElementCollection::iterator last = it;
while (last != mLogElements.begin()) {
--it;
if ((*it)->getRealTime() <= realtime) {
break;
}
last = it;
}
if (last == mLogElements.end()) {
mLogElements.push_back(elem);
} else {
uint64_t end = 1;
bool end_set = false;
bool end_always = false;
LogTimeEntry::lock();
LastLogTimes::iterator t = mTimes.begin();
while(t != mTimes.end()) {
LogTimeEntry *entry = (*t);
if (entry->owned_Locked()) {
if (!entry->mNonBlock) {
end_always = true;
break;
}
if (!end_set || (end <= entry->mEnd)) {
end = entry->mEnd;
end_set = true;
}
}
t++;
}
if (end_always
|| (end_set && (end >= (*last)->getSequence()))) {
mLogElements.push_back(elem);
} else {
mLogElements.insert(last,elem);
}
LogTimeEntry::unlock();
}
stats.add(elem);
maybePrune(log_id);
pthread_mutex_unlock(&mLogElementsLock);
return len;
}
