Merge "liblog: logd: support logd.timestamp = monotonic" am: 8897a3fffd am: 55316200b8 (4511ff1d) · Commits · e / os / android_system_core

liblog/logd_write.c

+5 −1

Original line number	Diff line number	Diff line
		@@ -191,7 +191,11 @@ static int __write_to_log_daemon(log_id_t log_id, struct iovec *vec, size_t nr)
		* };
		*/

		if (android_log_timestamp() == 'm') {
		clock_gettime(CLOCK_MONOTONIC, &ts);
		} else {
		clock_gettime(CLOCK_REALTIME, &ts);
		}

		pmsg_header.magic = LOGGER_MAGIC;
		pmsg_header.len = sizeof(pmsg_header) + sizeof(header);

liblog/logprint.c

+8 −5

Original line number	Diff line number	Diff line
		@@ -203,7 +203,7 @@ AndroidLogFormat *android_log_format_new()
		p_ret->year_output = false;
		p_ret->zone_output = false;
		p_ret->epoch_output = false;
		p_ret->monotonic_output = false;
		p_ret->monotonic_output = android_log_timestamp() == 'm';

		return p_ret;
		}
		@@ -1261,11 +1261,14 @@ char *android_log_formatLogLine (
		now = entry->tv_sec;
		nsec = entry->tv_nsec;
		if (p_format->monotonic_output) {
		// prevent convertMonotonic from being called if logd is monotonic
		if (android_log_timestamp() != 'm') {
		struct timespec time;
		convertMonotonic(&time, entry);
		now = time.tv_sec;
		nsec = time.tv_nsec;
		}
		}
		if (now < 0) {
		nsec = NS_PER_SEC - nsec;
		}

logcat/logcat.cpp

+9 −1

Original line number	Diff line number	Diff line
		@@ -399,6 +399,10 @@ static log_time lastLogTime(char *outputFileName) {
		}

		log_time now(CLOCK_REALTIME);
		bool monotonic = android_log_timestamp() == 'm';
		if (monotonic) {
		now = log_time(CLOCK_MONOTONIC);
		}

		std::string directory;
		char *file = strrchr(outputFileName, '/');
		@@ -417,7 +421,11 @@ static log_time lastLogTime(char *outputFileName) {
		struct dirent *dp;
		while ((dp = readdir(dir.get())) != NULL) {
		if ((dp->d_type != DT_REG)
		\|\| strncmp(dp->d_name, file, len)
		// If we are using realtime, check all files that match the
		// basename for latest time. If we are using monotonic time
		// then only check the main file because time cycles on
		// every reboot.
		\|\| strncmp(dp->d_name, file, len + monotonic)
		\|\| (dp->d_name[len]
		&& ((dp->d_name[len] != '.')
		\|\| !isdigit(dp->d_name[len+1])))) {

logcat/tests/logcat_test.cpp

+77 −63

Original line number	Diff line number	Diff line
		@@ -75,6 +75,12 @@ TEST(logcat, buckets) {
		}

		TEST(logcat, year) {

		if (android_log_timestamp() == 'm') {
		fprintf(stderr, "Skipping test, logd is monotonic time\n");
		return;
		}

		FILE *fp;

		char needle[32];
		@@ -108,7 +114,44 @@ TEST(logcat, year) {
		ASSERT_EQ(3, count);
		}

		// Return a pointer to each null terminated -v long time field.
		char fgetLongTime(char buffer, size_t buflen, FILE *fp) {
		while (fgets(buffer, buflen, fp)) {
		char *cp = buffer;
		if (*cp != '[') {
		continue;
		}
		while (*++cp == ' ') {
		;
		}
		char *ep = cp;
		while (isdigit(*ep)) {
		++ep;
		}
		if ((ep != '-') && (ep != '.')) {
		continue;
		}
		// Find PID field
		while (((ep = strchr(ep, ':'))) && (*++ep != ' ')) {
		;
		}
		if (!ep) {
		continue;
		}
		ep -= 7;
		*ep = '\0';
		return cp;
		}
		return NULL;
		}

		TEST(logcat, tz) {

		if (android_log_timestamp() == 'm') {
		fprintf(stderr, "Skipping test, logd is monotonic time\n");
		return;
		}

		FILE *fp;

		ASSERT_TRUE(NULL != (fp = popen(
		@@ -119,11 +162,8 @@ TEST(logcat, tz) {

		int count = 0;

		while (fgets(buffer, sizeof(buffer), fp)) {
		if ((buffer[0] == '[') && (buffer[1] == ' ')
		&& isdigit(buffer[2]) && isdigit(buffer[3])
		&& (buffer[4] == '-')
		&& (strstr(buffer, " -0700 ") \|\| strstr(buffer, " -0800 "))) {
		while (fgetLongTime(buffer, sizeof(buffer), fp)) {
		if (strstr(buffer, " -0700") \|\| strstr(buffer, " -0800")) {
		++count;
		}
		}
		@@ -144,11 +184,8 @@ TEST(logcat, ntz) {

		int count = 0;

		while (fgets(buffer, sizeof(buffer), fp)) {
		if ((buffer[0] == '[') && (buffer[1] == ' ')
		&& isdigit(buffer[2]) && isdigit(buffer[3])
		&& (buffer[4] == '-')
		&& (strstr(buffer, " -0700 ") \|\| strstr(buffer, " -0800 "))) {
		while (fgetLongTime(buffer, sizeof(buffer), fp)) {
		if (strstr(buffer, " -0700") \|\| strstr(buffer, " -0800")) {
		++count;
		}
		}
		@@ -169,13 +206,9 @@ TEST(logcat, tail_3) {

		int count = 0;

		while (fgets(buffer, sizeof(buffer), fp)) {
		if ((buffer[0] == '[') && (buffer[1] == ' ')
		&& isdigit(buffer[2]) && isdigit(buffer[3])
		&& (buffer[4] == '-')) {
		while (fgetLongTime(buffer, sizeof(buffer), fp)) {
		++count;
		}
		}

		pclose(fp);

		@@ -193,13 +226,9 @@ TEST(logcat, tail_10) {

		int count = 0;

		while (fgets(buffer, sizeof(buffer), fp)) {
		if ((buffer[0] == '[') && (buffer[1] == ' ')
		&& isdigit(buffer[2]) && isdigit(buffer[3])
		&& (buffer[4] == '-')) {
		while (fgetLongTime(buffer, sizeof(buffer), fp)) {
		++count;
		}
		}

		pclose(fp);

		@@ -217,13 +246,9 @@ TEST(logcat, tail_100) {

		int count = 0;

		while (fgets(buffer, sizeof(buffer), fp)) {
		if ((buffer[0] == '[') && (buffer[1] == ' ')
		&& isdigit(buffer[2]) && isdigit(buffer[3])
		&& (buffer[4] == '-')) {
		while (fgetLongTime(buffer, sizeof(buffer), fp)) {
		++count;
		}
		}

		pclose(fp);

		@@ -241,13 +266,9 @@ TEST(logcat, tail_1000) {

		int count = 0;

		while (fgets(buffer, sizeof(buffer), fp)) {
		if ((buffer[0] == '[') && (buffer[1] == ' ')
		&& isdigit(buffer[2]) && isdigit(buffer[3])
		&& (buffer[4] == '-')) {
		while (fgetLongTime(buffer, sizeof(buffer), fp)) {
		++count;
		}
		}

		pclose(fp);

		@@ -263,21 +284,15 @@ TEST(logcat, tail_time) {
		char *last_timestamp = NULL;
		char *first_timestamp = NULL;
		int count = 0;
		const unsigned int time_length = 18;
		const unsigned int time_offset = 2;

		while (fgets(buffer, sizeof(buffer), fp)) {
		if ((buffer[0] == '[') && (buffer[1] == ' ')
		&& isdigit(buffer[time_offset]) && isdigit(buffer[time_offset + 1])
		&& (buffer[time_offset + 2] == '-')) {
		char *cp;
		while ((cp = fgetLongTime(buffer, sizeof(buffer), fp))) {
		++count;
		buffer[time_length + time_offset] = '\0';
		if (!first_timestamp) {
		first_timestamp = strdup(buffer + time_offset);
		first_timestamp = strdup(cp);
		}
		free(last_timestamp);
		last_timestamp = strdup(buffer + time_offset);
		}
		last_timestamp = strdup(cp);
		}
		pclose(fp);

		@@ -292,28 +307,24 @@ TEST(logcat, tail_time) {
		int second_count = 0;
		int last_timestamp_count = -1;

		while (fgets(buffer, sizeof(buffer), fp)) {
		if ((buffer[0] == '[') && (buffer[1] == ' ')
		&& isdigit(buffer[time_offset]) && isdigit(buffer[time_offset + 1])
		&& (buffer[time_offset + 2] == '-')) {
		while ((cp = fgetLongTime(buffer, sizeof(buffer), fp))) {
		++second_count;
		buffer[time_length + time_offset] = '\0';
		if (first_timestamp) {
		// we can get a transitory extremely rare failure if hidden
		// underneath the time is exactly XX-XX XX:XX:XX.XXX000000
		EXPECT_STREQ(buffer + time_offset, first_timestamp);
		EXPECT_STREQ(cp, first_timestamp);
		free(first_timestamp);
		first_timestamp = NULL;
		}
		if (!strcmp(buffer + time_offset, last_timestamp)) {
		if (!strcmp(cp, last_timestamp)) {
		last_timestamp_count = second_count;
		}
		}
		}
		pclose(fp);

		free(last_timestamp);
		last_timestamp = NULL;
		free(first_timestamp);

		EXPECT_TRUE(first_timestamp == NULL);
		EXPECT_LE(count, second_count);
		@@ -601,6 +612,9 @@ TEST(logcat, logrotate) {
		}
		}
		pclose(fp);
		if ((count != 7) && (count != 8)) {
		fprintf(stderr, "count=%d\n", count);
		}
		EXPECT_TRUE(count == 7 \|\| count == 8);
		}
		}

logd/LogAudit.cpp

+11 −9

Original line number	Diff line number	Diff line
		@@ -123,17 +123,19 @@ int LogAudit::logPrint(const char *fmt, ...) {
		&& (*cp == ':')) {
		memcpy(timeptr + sizeof(audit_str) - 1, "0.0", 3);
		memmove(timeptr + sizeof(audit_str) - 1 + 3, cp, strlen(cp) + 1);
		//
		// We are either in 1970ish (MONOTONIC) or 2015+ish (REALTIME) so to
		// differentiate without prejudice, we use 1980 to delineate, earlier
		// is monotonic, later is real.
		//
		# define EPOCH_PLUS_10_YEARS (10 * 1461 / 4 * 24 * 60 * 60)
		if (now.tv_sec < EPOCH_PLUS_10_YEARS) {
		if (!isMonotonic()) {
		if (android::isMonotonic(now)) {
		LogKlog::convertMonotonicToReal(now);
		}
		} else {
		now.strptime("", ""); // side effect of setting CLOCK_REALTIME
		if (!android::isMonotonic(now)) {
		LogKlog::convertRealToMonotonic(now);
		}
		}
		} else if (isMonotonic()) {
		now = log_time(CLOCK_MONOTONIC);
		} else {
		now = log_time(CLOCK_REALTIME);
		}

		static const char pid_str[] = " pid=";