Merge lp:~dandrader/mir/ainput-log-filtering into lp:~mir-team/mir/trunk

[Daniel d'Andrada]

Bring back android-input logging functionality

- prefix log message with the tag name from where the log function was called.
- filter log messages by tag name and priority with the ANDROID_LOG_TAGS
  environment var

Bring back android-input logging functionality

- prefix log message with the tag name from where the log function was called.
- filter log messages by tag name and priority with the ANDROID_LOG_TAGS
  environment var

[PS Jenkins bot (ps-jenkins)]

FAILED: Continuous integration, rev:1082
http://jenkins.qa.ubuntu.com/job/mir-ci/1566/
Executed test runs:
    SUCCESS: http://jenkins.qa.ubuntu.com/job/mir-android-saucy-i386-build/2102
    SUCCESS: http://jenkins.qa.ubuntu.com/job/mir-clang-saucy-amd64-build/1987
    FAILURE: http://jenkins.qa.ubuntu.com/job/mir-saucy-amd64-ci/804/console
    SUCCESS: http://jenkins.qa.ubuntu.com/job/mir-saucy-armhf-ci/66
        deb: http://jenkins.qa.ubuntu.com/job/mir-saucy-armhf-ci/66/artifact/work/output/*zip*/output.zip

Click here to trigger a rebuild:
http://s-jenkins:8080/job/mir-ci/1566/rebuild

review: Needs Fixing (continuous-integration)

[PS Jenkins bot (ps-jenkins)]

PASSED: Continuous integration, rev:1083
http://jenkins.qa.ubuntu.com/job/mir-ci/1567/
Executed test runs:
    SUCCESS: http://jenkins.qa.ubuntu.com/job/mir-android-saucy-i386-build/2104
    SUCCESS: http://jenkins.qa.ubuntu.com/job/mir-clang-saucy-amd64-build/1989
    SUCCESS: http://jenkins.qa.ubuntu.com/job/mir-saucy-amd64-ci/805
        deb: http://jenkins.qa.ubuntu.com/job/mir-saucy-amd64-ci/805/artifact/work/output/*zip*/output.zip
    SUCCESS: http://jenkins.qa.ubuntu.com/job/mir-saucy-armhf-ci/67
        deb: http://jenkins.qa.ubuntu.com/job/mir-saucy-armhf-ci/67/artifact/work/output/*zip*/output.zip

Click here to trigger a rebuild:
http://s-jenkins:8080/job/mir-ci/1567/rebuild

review: Approve (continuous-integration)

=== modified file '3rd_party/android-input/android/frameworks/base/services/input/MirLog.cpp'
--- 3rd_party/android-input/android/frameworks/base/services/input/MirLog.cpp	2013-05-04 00:50:30 +0000
+++ 3rd_party/android-input/android/frameworks/base/services/input/MirLog.cpp	2013-09-24 19:24:51 +0000
@@ -14,13 +14,143 @@
  * along with this program.  If not, see <http://www.gnu.org/licenses/>.
  *
  * Authored by: Alan Griffiths <[e-mail]>
- */
-
-#include <std/Log.h>
+ *              Daniel d'Andrada <[e-mail]>
+ */
+
+// License of the original configureInitialState() function:
+/*
+ * Copyright (C) 2008 The Android Open Source Project
+ *
+ * Licensed under the Apache License, Version 2.0 (the "License");
+ * you may not use this file except in compliance with the License.
+ * You may obtain a copy of the License at
+ *
+ *      http://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing, software
+ * distributed under the License is distributed on an "AS IS" BASIS,
+ * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+ * See the License for the specific language governing permissions and
+ * limitations under the License.
+ */
+
+#include <android/log.h>
 #include <std/MirLog.h>
+#include <cctype>
 #include <cstdarg>
 #include <cstdio>
-
+#include <cstdlib>
+#include <cstring>
+
+#define kMaxTagLen  16      /* from the long-dead utils/Log.cpp */
+#define kTagSetSize 16      /* arbitrary */
+
+namespace
+{
+    struct LogState {
+        /* global minimum priority */
+        int     globalMinPriority;
+
+        /* tags and priorities */
+        struct {
+            char    tag[kMaxTagLen];
+            int     minPriority;
+        } tagSet[kTagSetSize];
+    } gLogState = { .globalMinPriority = ANDROID_LOG_UNKNOWN };
+}
+
+/*
+ * Configure logging based on ANDROID_LOG_TAGS environment variable.  We
+ * need to parse a string that looks like
+ *
+ *   *:v jdwp:d dalvikvm:d dalvikvm-gc:i dalvikvmi:i
+ *
+ * The tag (or '*' for the global level) comes first, followed by a colon
+ * and a letter indicating the minimum priority level we're expected to log.
+ * This can be used to reveal or conceal logs with specific tags.
+ *
+ * We also want to check ANDROID_PRINTF_LOG to determine how the output
+ * will look.
+ */
+static void configureInitialState(struct LogState* logState)
+{
+    /* global min priority defaults to "info" level */
+    logState->globalMinPriority = ANDROID_LOG_INFO;
+
+    int entry = 0;
+
+    /*
+     * This is based on the the long-dead utils/Log.cpp code.
+     */
+    const char* tags = getenv("ANDROID_LOG_TAGS");
+    if (tags != NULL) {
+        while (*tags != '\0') {
+            char tagName[kMaxTagLen];
+            int i, minPrio;
+
+            while (isspace(*tags))
+                tags++;
+
+            i = 0;
+            while (*tags != '\0' && !isspace(*tags) && *tags != ':' &&
+                i < kMaxTagLen)
+            {
+                tagName[i++] = *tags++;
+            }
+            if (i == kMaxTagLen) {
+                break;
+            }
+            tagName[i] = '\0';
+
+            /* default priority, if there's no ":" part; also zero out '*' */
+            minPrio = ANDROID_LOG_VERBOSE;
+            if (tagName[0] == '*' && tagName[1] == '\0') {
+                minPrio = ANDROID_LOG_DEBUG;
+                tagName[0] = '\0';
+            }
+
+            if (*tags == ':') {
+                tags++;
+                if (*tags >= '0' && *tags <= '9') {
+                    if (*tags >= ('0' + ANDROID_LOG_SILENT))
+                        minPrio = ANDROID_LOG_VERBOSE;
+                    else
+                        minPrio = *tags - '\0';
+                } else {
+                    switch (*tags) {
+                    case 'v':   minPrio = ANDROID_LOG_VERBOSE;  break;
+                    case 'd':   minPrio = ANDROID_LOG_DEBUG;    break;
+                    case 'i':   minPrio = ANDROID_LOG_INFO;     break;
+                    case 'w':   minPrio = ANDROID_LOG_WARN;     break;
+                    case 'e':   minPrio = ANDROID_LOG_ERROR;    break;
+                    case 'f':   minPrio = ANDROID_LOG_FATAL;    break;
+                    case 's':   minPrio = ANDROID_LOG_SILENT;   break;
+                    default:    minPrio = ANDROID_LOG_DEFAULT;  break;
+                    }
+                }
+
+                tags++;
+                if (*tags != '\0' && !isspace(*tags)) {
+                    break;
+                }
+            }
+
+            if (tagName[0] == 0) {
+                logState->globalMinPriority = minPrio;
+            } else {
+                logState->tagSet[entry].minPriority = minPrio;
+                strcpy(logState->tagSet[entry].tag, tagName);
+                entry++;
+            }
+        }
+    }
+
+    if (entry < kTagSetSize) {
+        // Mark the end of this array
+        logState->tagSet[entry].minPriority = ANDROID_LOG_UNKNOWN;
+        logState->tagSet[entry].tag[0] = '\0';
+    }
+}
 
 extern "C" int __android_log_print(int prio, const char *tag, const char *fmt, ...)
 {
@@ -30,7 +160,29 @@
     int result = vsnprintf(buffer, sizeof buffer - 1, fmt, ap);
     va_end(ap);
 
-    mir::write_to_log(prio, buffer);
+    if (gLogState.globalMinPriority == ANDROID_LOG_UNKNOWN) {
+        configureInitialState(&gLogState);
+    }
+
+    /* see if this log tag is configured */
+    int minPrio = gLogState.globalMinPriority;
+    for (int i = 0; i < kTagSetSize; i++) {
+        if (gLogState.tagSet[i].minPriority == ANDROID_LOG_UNKNOWN)
+            break;      /* reached end of configured values */
+
+        if (strcmp(gLogState.tagSet[i].tag, tag) == 0) {
+            minPrio = gLogState.tagSet[i].minPriority;
+            break;
+        }
+    }
+
+    if (prio >= minPrio) {
+        char taggedBuffer[1024];
+        sprintf(taggedBuffer, "[%s]%s", tag, buffer);
+        mir::write_to_log(prio, taggedBuffer);
+    } else {
+        // filter out log message
+    }
 
     return result;
 }

=== modified file 'tests/unit-tests/logging/test_legacy_input_report.cpp'
--- tests/unit-tests/logging/test_legacy_input_report.cpp	2013-05-28 17:55:26 +0000
+++ tests/unit-tests/logging/test_legacy_input_report.cpp	2013-09-24 19:24:51 +0000
@@ -29,6 +29,8 @@
 namespace ml  = mir::logging;
 namespace mli = mir::logging::legacy_input_report;
 
+using testing::_;
+
 namespace
 {
 class MockLogger : public ml::Logger
@@ -49,69 +51,64 @@
 };
 
 char const* const component = "android-input";
-char const* const LOG_TAG = 0;
+char const* const LOG_TAG = "Foo";
 }
 
 TEST_F(InputReport, debug_message)
 {
-    EXPECT_CALL(logger, log(
-            ml::Logger::debug,
-            testing::HasSubstr(__PRETTY_FUNCTION__),
-            component));
+    // default minimum log priority is "informational". "debug" is lower than that.
+    EXPECT_CALL(logger, log(_, _, _)).Times(0);
 
-  ALOG(LOG_DEBUG, NULL, "Test function is %s", __PRETTY_FUNCTION__);
+    ALOG(LOG_DEBUG, NULL, "Test function is %s", __PRETTY_FUNCTION__);
 }
 
 TEST_F(InputReport, unknown_message)
 {
     char const* const unknown = "Unknown message";
 
-    EXPECT_CALL(logger, log(
-            ml::Logger::debug,
-            unknown,
-            component));
+    // default minimum log priority is "informational". "unknown" is lower than that.
+    // Actually, I don't think this is even a valid priority.
+    EXPECT_CALL(logger, log(_, _, _)).Times(0);
 
-  ALOG(LOG_UNKNOWN, NULL, unknown);
+    ALOG(LOG_UNKNOWN, NULL, unknown);
 }
 
 TEST_F(InputReport, verbose_message)
 {
     char const* const verbose = "A very long story. (OK, I lied.)";
 
-    EXPECT_CALL(logger, log(
-            ml::Logger::debug,
-            verbose,
-            component));
+    // default minimum log priority is "informational". "verbose" is lower than that.
+    EXPECT_CALL(logger, log(_, _, _)).Times(0);
 
-  ALOG(LOG_VERBOSE, NULL, verbose);
+    ALOG(LOG_VERBOSE, NULL, verbose);
 }
 
 TEST_F(InputReport, info_message)
 {
     EXPECT_CALL(logger, log(
             ml::Logger::informational,
-            __PRETTY_FUNCTION__,
+            "[Foo]Some informational message",
             component));
 
-    ALOGI(__PRETTY_FUNCTION__);
+    ALOGI("Some informational message");
 }
 
 TEST_F(InputReport, warning_message)
 {
     EXPECT_CALL(logger, log(
             ml::Logger::warning,
-            __PRETTY_FUNCTION__,
+            "[Foo]Warning!!!",
             component));
 
-    ALOGW(__PRETTY_FUNCTION__);
+    ALOGW("Warning!!!");
 }
 
 TEST_F(InputReport, error_message)
 {
     EXPECT_CALL(logger, log(
             ml::Logger::error,
-            __PRETTY_FUNCTION__,
+            "[Foo]An error occurred!",
             component));
 
-    ALOGE(__PRETTY_FUNCTION__);
+    ALOGE("An error occurred!");
 }