Re: [ovs-dev] [PATCH 1/2] ovsdb-server: Don't log closing session at program termination.
On Fri, Jul 13, 2018 at 5:04 AM Ben Pfaff wrote:
> 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.76900 +
> > +++
> /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 +
> > @@ -0,0 +1,2 @@
> > +2018-05-29T14:29:56Z|1|ovsdb_jsonrpc_server|INFO|unix#0:
> disconnecting (removing ordinals database due to server termination)
> > +2018-05-29T14:29:56Z|2|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
> > Reported-at:
> https://mail.openvswitch.org/pipermail/ovs-discuss/2018-May/046840.html
> > Signed-off-by: Ben Pfaff
>
Acked-by: Numan Siddique
> > ---
> > 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, >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[])
> >
> >
Re: [ovs-dev] [PATCH 1/2] ovsdb-server: Don't log closing session at program termination.
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.76900 +
> +++
> /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 +
> @@ -0,0 +1,2 @@
> +2018-05-29T14:29:56Z|1|ovsdb_jsonrpc_server|INFO|unix#0:
> disconnecting (removing ordinals database due to server termination)
> +2018-05-29T14:29:56Z|2|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
> Reported-at:
> https://mail.openvswitch.org/pipermail/ovs-discuss/2018-May/046840.html
> Signed-off-by: Ben Pfaff
> ---
> 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, >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, _dbs) {
> struct db *db = node->data;
> -close_db(_config, db,
> - xasprintf("removing %s database due to server termination",
> - db->db->name));
> +close_db(_config, db, NULL);
[ovs-dev] [PATCH 1/2] ovsdb-server: Don't log closing session at program termination.
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.76900 +
+++
/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 +
@@ -0,0 +1,2 @@
+2018-05-29T14:29:56Z|1|ovsdb_jsonrpc_server|INFO|unix#0: disconnecting
(removing ordinals database due to server termination)
+2018-05-29T14:29:56Z|2|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
Reported-at:
https://mail.openvswitch.org/pipermail/ovs-discuss/2018-May/046840.html
Signed-off-by: Ben Pfaff
---
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, >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, _dbs) {
struct db *db = node->data;
-close_db(_config, db,
- xasprintf("removing %s database due to server termination",
- db->db->name));
+close_db(_config, db, NULL);
shash_delete(_dbs, node);
}
ovsdb_jsonrpc_server_destroy(jsonrpc);
--
2.16.1
___
dev mailing list
d...@openvswitch.org
https://mail.openvswitch.org/mailman/listinfo/ovs-dev
