liblog: logprint supports number of seconds time event field

Add s to report time in seconds.  The time could be a period, duration
or monotonic, expanded to seconds, minutes, hours and days.  gTest has
to acquire a dynamic tag allocation as there are no users of this
feature yet.

Looking to the future, audio media logging has binary content similar
to the binary events structures Android logging uses and they have
a definition of a duration field in their internal binary logging, so
may be of use when we unify the logs.

Test: gTest logcat-unit-tests --gtest_filter=*.descriptive
Bug: 31456426
Change-Id: I262c03775983b3bc7b1b00227ce2bb2b0f357bec
This commit is contained in:
Mark Salyzyn 2016-11-10 10:24:44 -08:00
parent 46186a7238
commit 5768d3d976
5 changed files with 87 additions and 2 deletions

View file

@ -29,6 +29,7 @@
# 4: Number of allocations
# 5: Id
# 6: Percent
# s: Number of seconds (monotonic time)
# Default value for data of type int/long is 2 (bytes).
#
# TODO: generate ".java" and ".h" files with integer constants from this file.

View file

@ -326,6 +326,7 @@ android_log_formatFromString(const char* formatString) {
else if (!strcmp(formatString, "uid")) format = FORMAT_MODIFIER_UID;
else if (!strcmp(formatString, "descriptive")) format = FORMAT_MODIFIER_DESCRIPT;
/* clang-format on */
#ifndef __MINGW32__
else {
extern char* tzname[2];
@ -637,7 +638,8 @@ enum objectType {
TYPE_MILLISECONDS = '3',
TYPE_ALLOCATIONS = '4',
TYPE_ID = '5',
TYPE_PERCENT = '6'
TYPE_PERCENT = '6',
TYPE_MONOTONIC = 's'
};
static int android_log_printBinaryEvent(const unsigned char** pEventData,
@ -651,7 +653,7 @@ static int android_log_printBinaryEvent(const unsigned char** pEventData,
size_t outBufLen = *pOutBufLen;
size_t outBufLenSave = outBufLen;
unsigned char type;
size_t outCount;
size_t outCount = 0;
int result = 0;
const char* cp;
size_t len;
@ -690,6 +692,7 @@ static int android_log_printBinaryEvent(const unsigned char** pEventData,
* 4: Number of allocations
* 5: Id
* 6: Percent
* s: Number of seconds (monotonic time)
* Default value for data of type int/long is 2 (bytes).
*/
if (!cp || !findChar(&cp, &len, '(')) {
@ -921,6 +924,42 @@ static int android_log_printBinaryEvent(const unsigned char** pEventData,
outCount = snprintf(outBuf, outBufLen, "ms");
}
break;
case TYPE_MONOTONIC: {
static const uint64_t minute = 60;
static const uint64_t hour = 60 * minute;
static const uint64_t day = 24 * hour;
/* Repaint as unsigned seconds, minutes, hours ... */
outBuf -= outCount;
outBufLen += outCount;
uint64_t val = lval;
if (val >= day) {
outCount = snprintf(outBuf, outBufLen, "%" PRIu64 "d ", val / day);
if (outCount >= outBufLen) break;
outBuf += outCount;
outBufLen -= outCount;
val = (val % day) + day;
}
if (val >= minute) {
if (val >= hour) {
outCount = snprintf(outBuf, outBufLen, "%" PRIu64 ":",
(val / hour) % (day / hour));
if (outCount >= outBufLen) break;
outBuf += outCount;
outBufLen -= outCount;
}
outCount =
snprintf(outBuf, outBufLen,
(val >= hour) ? "%02" PRIu64 ":" : "%" PRIu64 ":",
(val / minute) % (hour / minute));
if (outCount >= outBufLen) break;
outBuf += outCount;
outBufLen -= outCount;
}
outCount = snprintf(outBuf, outBufLen,
(val >= minute) ? "%02" PRIu64 : "%" PRIu64 "s",
val % minute);
} break;
case TYPE_ALLOCATIONS:
outCount = 0;
/* outCount = snprintf(outBuf, outBufLen, " allocations"); */

View file

@ -30,6 +30,7 @@
# 4: Number of allocations
# 5: Id
# 6: Percent
# s: Number of seconds (monotonic time)
# Default value for data of type int/long is 2 (bytes).
#
# TODO: generate ".java" and ".h" files with integer constants from this file.

View file

@ -32,6 +32,7 @@
#include <android-base/file.h>
#include <gtest/gtest.h>
#include <log/event_tag_map.h>
#include <log/log.h>
#include <log/log_event_list.h>
@ -1671,6 +1672,48 @@ TEST(logcat, descriptive) {
EXPECT_LE(0, ret);
EXPECT_TRUE(End_to_End(sync.tagStr, ""));
}
{
// Invent new entries because existing can not serve
EventTagMap* map = android_openEventTagMap(nullptr);
ASSERT_TRUE(nullptr != map);
static const char name[] = ___STRING(logcat) "_descriptive_monotonic";
int myTag = android_lookupEventTagNum(map, name, "(new|1|s)",
ANDROID_LOG_UNKNOWN);
android_closeEventTagMap(map);
ASSERT_NE(-1, myTag);
const struct tag sync = { (uint32_t)myTag, name };
{
android_log_event_list ctx(sync.tagNo);
ctx << (uint32_t)7;
for (ret = -EBUSY; ret == -EBUSY; rest()) ret = ctx.write();
EXPECT_LE(0, ret);
EXPECT_TRUE(End_to_End(sync.tagStr, "new=7s"));
}
{
android_log_event_list ctx(sync.tagNo);
ctx << (uint32_t)62;
for (ret = -EBUSY; ret == -EBUSY; rest()) ret = ctx.write();
EXPECT_LE(0, ret);
EXPECT_TRUE(End_to_End(sync.tagStr, "new=1:02"));
}
{
android_log_event_list ctx(sync.tagNo);
ctx << (uint32_t)3673;
for (ret = -EBUSY; ret == -EBUSY; rest()) ret = ctx.write();
EXPECT_LE(0, ret);
EXPECT_TRUE(End_to_End(sync.tagStr, "new=1:01:13"));
}
{
android_log_event_list ctx(sync.tagNo);
ctx << (uint32_t)(86400 + 7200 + 180 + 58);
for (ret = -EBUSY; ret == -EBUSY; rest()) ret = ctx.write();
EXPECT_LE(0, ret);
EXPECT_TRUE(End_to_End(sync.tagStr, "new=1d 2:03:58"));
}
}
}
static bool reportedSecurity(const char* command) {

View file

@ -29,6 +29,7 @@
# 4: Number of allocations
# 5: Id
# 6: Percent
# s: Number of seconds (monotonic time)
# Default value for data of type int/long is 2 (bytes).
#
# TODO: generate ".java" and ".h" files with integer constants from this file.