Merge lp:~sforshee/powerd/clean-up-cli-output into lp:powerd

[Seth Forshee]

Clean up powerd-cli output

Clean up powerd-cli output

[Matt Fischer (mfisch)]

Looks cleaner, to reiterate what I said on IRC, I had someone look for "We Get Signal" when a MMS was sent, he didn't see it. When MMS does work, we may need to bring that back because it might be a different signal. tl;dr: We need to test screen on with MMS once it works.

review: Approve

[Seth Forshee (sforshee)]

> Looks cleaner, to reiterate what I said on IRC, I had someone look for "We Get
> Signal" when a MMS was sent, he didn't see it. When MMS does work, we may need
> to bring that back because it might be a different signal. tl;dr: We need to
> test screen on with MMS once it works.

If you look down to the else block for the if statement which follows, you'll see that as long as you enable debug output you will get the same information for any unknown signal.

[PS Jenkins bot (ps-jenkins)]

PASSED: Continuous integration, rev:75
http://jenkins.qa.ubuntu.com/job/powerd-ci/91/
Executed test runs:
    SUCCESS: http://jenkins.qa.ubuntu.com/job/powerd-saucy-armhf-ci/45
        deb: http://jenkins.qa.ubuntu.com/job/powerd-saucy-armhf-ci/45/artifact/work/output/*zip*/output.zip

Click here to trigger a rebuild:
http://s-jenkins:8080/job/powerd-ci/91/rebuild

review: Approve (continuous-integration)

=== modified file 'cli/powerd-cli.c'
--- cli/powerd-cli.c	2013-07-02 14:50:36 +0000
+++ cli/powerd-cli.c	2013-07-17 18:59:33 +0000
@@ -32,15 +32,21 @@
 #define do_test(test)                                               \
     ({                                                              \
         gboolean result;                                            \
-        g_message("Test: " #test);                                  \
+        printf("Test: " #test "\n");                                \
         result = (test);                                            \
-        g_message("    result: %s", result ? "PASSED" : "FAILED");  \
+        printf("    result: %s\n", result ? "PASSED" : "FAILED");   \
         result;                                                     \
     })
 
 #define TEST_NUM_SYS_REQUESTS 5
 #define TEST_NUM_DISP_REQUESTS POWERD_NUM_DISPLAY_STATES * POWERD_NUM_DISPLAY_BRIGHTNESS_STATES
 
+/* Set to TRUE during tests to silence expected errors */
+static gboolean silent_errors = FALSE;
+
+#define cli_warn(f, a...)   do { if (!silent_errors) g_warning(f, ##a); } while (0)
+#define cli_debug(f, a...)  g_debug(f, ##a)
+
 GDBusProxy *powerd_proxy = NULL;
 char test_dbusname[128] = "";
 
@@ -67,6 +73,12 @@
 static void sig_handler(int signum);
 
 static void
+silence_errors(gboolean silent)
+{
+    silent_errors = silent;
+}
+
+static void
 on_powerd_signal (GDBusProxy *proxy,
            gchar      *sender_name,
            gchar      *signal_name,
@@ -78,20 +90,18 @@
     int display_brightness;
     guint32 display_flags;
 
-    g_warning("we get signal from %s: %s", sender_name, signal_name);
-
     if (!strcmp(signal_name,"SysPowerStateChange")) {
         g_variant_get(parameters, "(i)", &system_state);
-        g_warning("System State is now: %d", system_state);
+        printf("Received %s: state=%d\n", signal_name, system_state);
     }
     else if (!strcmp(signal_name,"DisplayPowerStateChange")) {
         g_variant_get(parameters, "(iiu)", &display_state,
             &display_brightness, &display_flags);
-        g_warning("Display State is now: %d, Brightness: %d, Flags: %u",
-            display_state, display_brightness, display_flags);
+        printf("Received %s: state=%d brightness=%d flags=%#08x\n",
+            signal_name, display_state, display_brightness, display_flags);
     }
     else {
-        g_warning("Unknown signal from powerd");
+        cli_debug("Unknown signal from %s: %s", sender_name, signal_name);
     }
 }
 
@@ -105,7 +115,7 @@
     gboolean success = TRUE;
 
     if (cookie == NULL) {
-        g_warning("requires a valid pointer for cookie");
+        cli_warn("NULL cookie passed to %s", __func__);
         return FALSE;
     }
 
@@ -117,18 +127,18 @@
             NULL,
             &error);
     if (ret == NULL) {
-        g_warning("Error when calling requestSysState: %s", error->message);
+        cli_warn("requestSysState failed: %s", error->message);
         g_error_free(error);
         return FALSE;
     }
 
     g_variant_get(ret, "(&s)", &cookie_ptr);
     if (strlen(cookie_ptr) != sizeof(powerd_cookie_t) - 1) {
-        g_warning("Returned cookie has incorrect size");
+        cli_warn("Returned cookie has incorrect size");
         success = FALSE;
     } else {
         strncpy(*cookie, cookie_ptr, sizeof(powerd_cookie_t));
-        g_message("Got cookie: %s", *cookie);
+        cli_debug("Got cookie: %s", *cookie);
     }
 
     g_variant_unref(ret);
@@ -145,7 +155,7 @@
     gboolean success = TRUE;
 
     if (cookie == NULL) {
-        g_warning("requires a valid pointer for cookie");
+        cli_warn("NULL cookie passed to %s", __func__);
         return FALSE;
     }
 
@@ -157,18 +167,18 @@
             NULL,
             &error);
     if (ret == NULL) {
-        g_warning("Error when calling requestDisplayState: %s", error->message);
+        cli_warn("requestDisplayState failed: %s", error->message);
         g_error_free(error);
         return FALSE;
     }
 
     g_variant_get(ret, "(&s)", &cookie_ptr);
     if (strlen(cookie_ptr) != sizeof(powerd_cookie_t) - 1) {
-        g_warning("Returned cookie has incorrect size");
+        cli_warn("Returned cookie has incorrect size");
         success = FALSE;
     } else {
         strncpy(*cookie, cookie_ptr, sizeof(powerd_cookie_t));
-        g_message("Got cookie: %s", *cookie);
+        cli_debug("Got cookie: %s", *cookie);
     }
 
     g_variant_unref(ret);
@@ -184,7 +194,7 @@
     gboolean success = TRUE;
 
     if (cookie == NULL) {
-        g_warning("requires a valid pointer to a cookie");
+        cli_warn("NULL cookie passed to %s", __func__);
         return FALSE;
     }
 
@@ -197,7 +207,7 @@
             NULL,
             &error);
     if (!ret) {
-        g_warning("Error when calling requestDisplayState: %s", error->message);
+        cli_warn("requestDisplayState failed: %s", error->message);
         g_error_free(error);
         return FALSE;
     }
@@ -223,27 +233,38 @@
             NULL,
             &error);
     if (ret == NULL) {
-        g_warning("Error when calling listSysRequests: %s", error->message);
+        cli_warn("listSysRequests failed: %s", error->message);
         g_error_free(error);
     }
     else {
         g_variant_get(ret, "(a(si))", &iter);
-        g_message("Current Sys Requests:");
         while ((item = g_variant_iter_next_value (iter))) {
             g_variant_get_child (item, 0, "s", &psr.owner);
             g_variant_get_child (item, 1, "i", &psr.state);
-            g_message("    Owner: %s, State: %d", psr.owner, psr.state);
             g_array_append_val(retarray, psr);
             g_variant_unref(item);
         }
-        if (retarray->len == 0) {
-            g_message("    None");
-        }
         g_variant_unref(ret);
     }
     return retarray;
 }
 
+static void
+printSysRequests(GArray *requests)
+{
+    int i;
+    struct PublicSysRequest *psr;
+    printf("System State Requests:\n");
+    if (requests->len == 0) {
+        printf("  None\n");
+    } else {
+        for (i = 0; i < requests->len; i++) {
+            psr = &g_array_index(requests, struct PublicSysRequest, i);
+            printf("  Owner: %s, State: %d\n", psr->owner, psr->state);
+        }
+    }
+}
+
 static GArray*
 listDisplayRequests()
 {
@@ -261,30 +282,41 @@
             NULL,
             &error);
     if (ret == NULL) {
-        g_warning("Error when calling listDisplayRequests: %s", error->message);
+        cli_warn("listDisplayRequests failed: %s", error->message);
         g_error_free(error);
     }
     else {
         g_variant_get(ret, "(a(siiu))", &iter);
-        g_message("Current Display Requests:");
         while ((item = g_variant_iter_next_value (iter))) {
             g_variant_get_child(item, 0, "s", &pdr.owner);
             g_variant_get_child(item, 1, "i", &pdr.state);
             g_variant_get_child(item, 2, "i", &pdr.brightness);
             g_variant_get_child(item, 3, "u", &pdr.flags);
-            g_message("    Owner: %s, State: %d, Brightness: %d, "\
-                "Flags: %u", pdr.owner, pdr.state, pdr.brightness, pdr.flags);
             g_array_append_val(retarray, pdr);
             g_variant_unref(item);
         }
-        if (retarray->len == 0) {
-            g_message("    None");
-        }
         g_variant_unref(ret);
     }
     return retarray;
 }
 
+static void
+printDisplayRequests(GArray *requests)
+{
+    int i;
+    struct PublicDispRequest *pdr;
+    printf("Display State Requests:\n");
+    if (requests->len == 0) {
+        printf("  None\n");
+    } else {
+        for (i = 0; i < requests->len; i++) {
+            pdr = &g_array_index(requests, struct PublicDispRequest, i);
+            printf("  Owner: %s, State: %d, Brightness: %d, Flags: %#08x\n",
+                   pdr->owner, pdr->state, pdr->brightness, pdr->flags);
+        }
+    }
+}
+
 static gboolean
 clearSysState(powerd_cookie_t cookie)
 {
@@ -299,7 +331,7 @@
             NULL,
             &error);
     if (ret == NULL) {
-        g_warning("Error when calling clearSysState: %s", error->message);
+        cli_warn("clearSysState failed: %s", error->message);
         g_error_free(error);
         return FALSE;
     }
@@ -321,7 +353,7 @@
             NULL,
             &error);
     if (ret == NULL) {
-        g_warning("Error when calling clearDisplayState: %s", error->message);
+        cli_warn("clearDisplayState failed: %s", error->message);
         g_error_free(error);
         return FALSE;
     }
@@ -338,7 +370,7 @@
 
     g_signal_connect(proxy, "g-signal", G_CALLBACK (on_powerd_signal), NULL);
 
-    g_message("Waiting for events");
+    printf("Waiting for events, press ctrl-c to quit\n");
     g_main_loop_run(main_loop);
     g_main_loop_unref(main_loop);
 }
@@ -360,8 +392,8 @@
         g_array_free(requests, TRUE);
     }
     else {
-        g_warning("Did not find child's dbusname");
-        g_message("result:    FAILED");
+        printf("Did not find child's dbus name\n");
+        printf("    result: FAILED\n");
     }
 
     // Make sure clean-up didn't remove our request, note we don't pass
@@ -399,7 +431,7 @@
     status = g_io_channel_read_line(channel, &string, &size, NULL, NULL);
     if (status == G_IO_STATUS_NORMAL) {
         if (sscanf(string, "DBUSNAME: %s\n", test_dbusname) == 1) {
-            printf("Parent found child's dbusname as: %s\n", test_dbusname);
+            cli_debug("Parent found child's dbusname as: %s", test_dbusname);
         }
         g_free(string);
     }
@@ -426,7 +458,7 @@
         NULL, NULL, &pid, NULL, &out, NULL, NULL);
 
     if (!ret) {
-        printf("Failed to spawn test app\n");
+        cli_warn("Failed to spawn test app");
         return;
     }
 
@@ -446,6 +478,8 @@
     powerd_cookie_t cookie, cookies[TEST_NUM_SYS_REQUESTS];
     GArray *requests = NULL;
 
+    silence_errors(TRUE);
+
     // Hold active state request as long we're running tests
     requestSysState(POWERD_SYS_STATE_ACTIVE, &main_cookie);
 
@@ -491,6 +525,8 @@
     //cleanup
     do_test(clearSysState(main_cookie) == TRUE);
     do_test(checkForDbusName(powerd_cli_bus_name, 0, requests, TRUE));
+
+    silence_errors(FALSE);
 }
 
 static void
@@ -502,6 +538,8 @@
     GArray *requests = NULL;
     struct PublicDispRequest pdr = {0,};
 
+    silence_errors(TRUE);
+
     // Hold active state request as long we're running tests
     requestSysState(POWERD_SYS_STATE_ACTIVE, &main_cookie);
 
@@ -588,6 +626,8 @@
     //cleanup
     do_test(clearSysState(main_cookie) == TRUE);
     do_test(checkForDbusName(powerd_cli_bus_name, 0, requests, TRUE));
+
+    silence_errors(FALSE);
 }
 
 // Check that dbus owner appears count times in a list of sys/disp requests
@@ -603,7 +643,7 @@
     struct PublicDispRequest *pdr;
 
     if (requests == NULL) {
-        g_warning("requests is invalid");
+        cli_warn("NULL requests passed to %s", __func__);
         return FALSE;
     }
 
@@ -624,7 +664,7 @@
     }
 
     if (found != count) {
-        g_warning("Expected %d requests from DbusName (%s), found %d",
+        cli_debug("Expected %d requests from DbusName (%s), found %d",
             count, dbusname, found);
         return FALSE;
     }
@@ -647,11 +687,11 @@
 
     if (!strcasecmp(argv[2],"on")) {
         pdr->state = POWERD_DISPLAY_STATE_ON;
-        printf("Requesting Display On\n");
+        cli_debug("Requesting Display On");
     }
     else if (!strcasecmp(argv[2],"dc")) {
         pdr->state = POWERD_DISPLAY_STATE_DONT_CARE;
-        printf("Requesting Display Don't Care\n");
+        cli_debug("Requesting Display Don't Care");
     }
     else {
         fprintf(stderr,"invalid state %s, must be either on or dc\n",
@@ -661,14 +701,14 @@
 
     if (!strcasecmp(argv[3],"dc")) {
         pdr->brightness = POWERD_DISPLAY_BRIGHTNESS_DONT_CARE;
-        printf("Requesting Brightness Don't Care\n");
+        cli_debug("Requesting Brightness Don't Care");
     }
     else if (!strcasecmp(argv[3],"dim")) {
-        printf("Requesting Brightness Dim\n");
+        cli_debug("Requesting Brightness Dim");
         pdr->brightness = POWERD_DISPLAY_BRIGHTNESS_DIM;
     }
     else if (!strcasecmp(argv[3],"bright")) {
-        printf("Requesting Brightness Bright\n");
+        cli_debug("Requesting Brightness Bright");
         pdr->brightness = POWERD_DISPLAY_BRIGHTNESS_BRIGHT;
     }
     else {
@@ -682,11 +722,11 @@
     for (i=4; i<argc; i++) {
         if (!strcmp(argv[i],"proximity")) {
             pdr->flags |= POWERD_DISPLAY_FLAG_USE_PROXIMITY;
-            printf("Requesting Proximity Sensor Enabled\n");
+            cli_debug("Requesting Proximity Sensor Enabled");
         }
         else if (!strcmp(argv[i],"disableab")) {
             pdr->flags |= POWERD_DISPLAY_FLAG_DISABLE_AUTOBRIGHTNESS;
-            printf("Requesting Proximity Disable AutoBrightness\n");
+            cli_debug("Requesting Proximity Disable AutoBrightness");
         }
     }
 
@@ -779,16 +819,17 @@
                 &error);
 
     if (error != NULL) {
-        g_error("error, could not acquire system bus proxy for powerd: %s",
-            error->message);
+        cli_warn("could not connect to powerd: %s", error->message);
         g_error_free(error);
         return -1;
     }
 
     if (!strcmp(argv[1],"list")) {
         requests = listSysRequests();
+        printSysRequests(requests);
         g_array_free(requests, TRUE);
         requests = listDisplayRequests();
+        printDisplayRequests(requests);
         g_array_free(requests, TRUE);
     }
     else if (!strcmp(argv[1],"active-nc")) {
@@ -875,7 +916,7 @@
     else if (!strcmp(argv[1],"dbusnametest")) {
         bus = g_bus_get_sync(G_BUS_TYPE_SYSTEM, NULL, NULL);
         bus_name = g_dbus_connection_get_unique_name(bus);
-        g_message("Child dbus name is %s", bus_name);
+        cli_debug("Child dbus name is %s", bus_name);
         // This printf is read by the parent
         printf("DBUSNAME: %s\n", bus_name);
         // Grab some requests so we can see that they get cleared later