[ovs-dev] [PATCH 1/2] ovsdb-server: Don't log closing session at program termination.

[Ben Pfaff]

This series still needs reviews.

On Fri, Jun 15, 2018 at 03:11:09PM -0700, Ben Pfaff wrote:
> When ovsdb-server closes a remote connection, it logs a message about it
> that includes the reason.  Until now this has included sessions that it
> closes when it exits.  That meant that, when --run was used, there was a
> race between noticing that the subprocess exited and noticing that the
> session that that subprocess (presumably) had open had been closed.  If
> it noticed the latter first, nothing was logged (because it didn't log
> anything if a session was closed in the ordinary way by the client).  If
> it noticed the former first, it logged a message about closing the session
> itself.
> 
> This is a benign race that causes no real problems--except that the tests
> didn't expect to see the log message from the former case and fail with
> errors like the following:
> 
>     1826. ovsdb-server.at:92: testing truncating database log with bad transaction ...
>     ./ovsdb-server.at:96: ovsdb-tool create db schema
>     stderr:
>     stdout:
>     ./ovsdb-server.at:104: ovsdb-server --remote=punix:socket db --run="sh txnfile"
>     --- /dev/null   2018-04-24 08:50:58.769000000 +0000
>     +++ /root/openvswitch-2.9.2/rpm/rpmbuild/BUILD/openvswitch-2.9.2/tests/testsuite.dir/at-groups/1826/stderr      2018-05-29 14:29:56.529257295 +0000
>     @@ -0,0 +1,2 @@
>     +2018-05-29T14:29:56Z|00001|ovsdb_jsonrpc_server|INFO|unix#0: disconnecting (removing ordinals database due to server termination)
>     +2018-05-29T14:29:56Z|00002|ovsdb_jsonrpc_server|INFO|unix#0: disconnecting (removing _Server database due to server termination)
> 
> This fixes the race.  This particular log message isn't too useful since
> it's pretty obvious that ovsdb-server is closing those sessions, since
> after all it's exiting!
> 
> Reported-by: Sanket Sudake <sanket at infracloud.io>
> Reported-at: https://mail.openvswitch.org/pipermail/ovs-discuss/2018-May/046840.html
> Signed-off-by: Ben Pfaff <blp at ovn.org>
> ---
>  ovsdb/jsonrpc-server.c | 12 +++++++-----
>  ovsdb/ovsdb-server.c   |  4 +---
>  2 files changed, 8 insertions(+), 8 deletions(-)
> 
> diff --git a/ovsdb/jsonrpc-server.c b/ovsdb/jsonrpc-server.c
> index 6c58f4102e29..7c7a277f0d49 100644
> --- a/ovsdb/jsonrpc-server.c
> +++ b/ovsdb/jsonrpc-server.c
> @@ -173,8 +173,9 @@ ovsdb_jsonrpc_server_add_db(struct ovsdb_jsonrpc_server *svr, struct ovsdb *db)
>  
>  /* Removes 'db' from the set of databases served out by 'svr'.
>   *
> - * 'comment' should be a human-readable reason for removing the database.  This
> - * function frees it. */
> + * 'comment' should be a human-readable reason for removing the database, for
> + * use in log messages, or NULL to suppress logging.  This function frees
> + * it. */
>  void
>  ovsdb_jsonrpc_server_remove_db(struct ovsdb_jsonrpc_server *svr,
>                                 struct ovsdb *db, char *comment)
> @@ -339,7 +340,7 @@ ovsdb_jsonrpc_server_free_remote_status(
>  
>  /* Makes all of the JSON-RPC sessions managed by 'svr' disconnect.  (They
>   * will then generally reconnect.).  Uses 'comment' as a human-readable comment
> - * for logging.  Frees 'comment'.
> + * for logging (it may be NULL to suppress logging).  Frees 'comment'.
>   *
>   * If 'force' is true, disconnects all sessions.  Otherwise, disconnects only
>   * sesions that aren't database change aware. */
> @@ -644,7 +645,8 @@ ovsdb_jsonrpc_session_close_all(struct ovsdb_jsonrpc_remote *remote)
>  
>  /* Makes all of the JSON-RPC sessions managed by 'remote' disconnect.  (They
>   * will then generally reconnect.).  'comment' should be a human-readable
> - * explanation of the reason for disconnection, for use in log messages.
> + * explanation of the reason for disconnection, for use in log messages, or
> + * NULL to suppress logging.
>   *
>   * If 'force' is true, disconnects all sessions.  Otherwise, disconnects only
>   * sesions that aren't database change aware. */
> @@ -657,7 +659,7 @@ ovsdb_jsonrpc_session_reconnect_all(struct ovsdb_jsonrpc_remote *remote,
>      LIST_FOR_EACH_SAFE (s, next, node, &remote->sessions) {
>          if (force || !s->db_change_aware) {
>              jsonrpc_session_force_reconnect(s->js);
> -            if (jsonrpc_session_is_connected(s->js)) {
> +            if (comment && jsonrpc_session_is_connected(s->js)) {
>                  VLOG_INFO("%s: disconnecting (%s)",
>                            jsonrpc_session_get_name(s->js), comment);
>              }
> diff --git a/ovsdb/ovsdb-server.c b/ovsdb/ovsdb-server.c
> index 68f7acae9fa3..8d213b27aae1 100644
> --- a/ovsdb/ovsdb-server.c
> +++ b/ovsdb/ovsdb-server.c
> @@ -459,9 +459,7 @@ main(int argc, char *argv[])
>  
>      SHASH_FOR_EACH_SAFE(node, next, &all_dbs) {
>          struct db *db = node->data;
> -        close_db(&server_config, db,
> -                 xasprintf("removing %s database due to server termination",
> -                           db->db->name));
> +        close_db(&server_config, db, NULL);
>          shash_delete(&all_dbs, node);
>      }
>      ovsdb_jsonrpc_server_destroy(jsonrpc);
> -- 
> 2.16.1
>