unixctl: Log commands received and their replies (at debug level).

These commands are also visible through the "jsonrpc" module, but turning
up the log level there also exposes a lot of OVSDB traffic that usually
isn't interesting.

Also, enable this logging for the tests.

Signed-off-by: Ben Pfaff <blp@ovn.org>
Acked-by: Justin Pettit <jpettit@ovn.org>

diff --git a/lib/unixctl.c b/lib/unixctl.c
index b47f35a..c1a5048 100644 (file)
--- a/lib/unixctl.c
+++ b/lib/unixctl.c
@@ -1,5 +1,5 @@
 /*
- * Copyright (c) 2008, 2009, 2010, 2011, 2012, 2013, 2014 Nicira, Inc.
+ * Copyright (c) 2008, 2009, 2010, 2011, 2012, 2013, 2014, 2016 Nicira, Inc.
  *
  * Licensed under the Apache License, Version 2.0 (the "License");
  * you may not use this file except in compliance with the License.
@@ -151,6 +151,13 @@ unixctl_command_reply__(struct unixctl_conn *conn,
         reply = jsonrpc_create_error(body_json, conn->request_id);
     }
 
+    if (VLOG_IS_DBG_ENABLED()) {
+        char *id = json_to_string(conn->request_id, 0);
+        VLOG_DBG("replying with %s, id=%s: \"%s\"",
+                 success ? "success" : "error", id, body);
+        free(id);
+    }
+
     /* If jsonrpc_send() returns an error, the run loop will take care of the
      * problem eventually. */
     jsonrpc_send(conn->rpc, reply);
@@ -268,6 +275,15 @@ process_command(struct unixctl_conn *conn, struct jsonrpc_msg *request)
     COVERAGE_INC(unixctl_received);
     conn->request_id = json_clone(request->id);
 
+    if (VLOG_IS_DBG_ENABLED()) {
+        char *params_s = json_to_string(request->params, 0);
+        char *id_s = json_to_string(request->id, 0);
+        VLOG_DBG("received request %s%s, id=%s",
+                 request->method, params_s, id_s);
+        free(params_s);
+        free(id_s);
+    }
+
     params = json_array(request->params);
     command = shash_find_data(&commands, request->method);
     if (!command) {

diff --git a/tests/ofproto-macros.at b/tests/ofproto-macros.at
index 1b22c44..18114d9 100644 (file)
--- a/tests/ofproto-macros.at
+++ b/tests/ofproto-macros.at
@@ -96,7 +96,7 @@ sim_add () {
    as $1 ovs-vsctl --no-wait -- init || return 1
 
    # Start ovs-vswitchd
-   as $1 start_daemon ovs-vswitchd --enable-dummy=system -vvconn -vofproto_dpif
+   as $1 start_daemon ovs-vswitchd --enable-dummy=system -vvconn -vofproto_dpif -vunixctl
 }
 
 # "as $1" sets the OVS_*DIR environment variables to point to $ovs_base/$1.
@@ -272,7 +272,7 @@ m4_define([_OVS_VSWITCHD_START],
    AT_CHECK([ovs-vsctl --no-wait init])
 
    dnl Start ovs-vswitchd.
-   AT_CHECK([ovs-vswitchd $1 --detach --no-chdir --pidfile --log-file -vvconn -vofproto_dpif], [0], [], [stderr])
+   AT_CHECK([ovs-vswitchd $1 --detach --no-chdir --pidfile --log-file -vvconn -vofproto_dpif -vunixctl], [0], [], [stderr])
    AT_CAPTURE_FILE([ovs-vswitchd.log])
    on_exit "kill `cat ovs-vswitchd.pid`"
    AT_CHECK([[sed < stderr '