[Libguestfs] [PATCH v2 4/4] OCaml tools: output messages into JSON for machine readable

When the machine readable mode is enabled, print all the messages (progress, info, warning, and errors) also as JSON in the machine readable stream: this way, users can easily parse the status of the OCaml tool, and report that back. The formatting of the current date time into the RFC 3999 format is done in C, because of the lack of OCaml APIs for this. --- .gitignore | 1 + common/mltools/Makefile.am | 39 ++++++- common/mltools/parse_tools_messages_test.py | 118 ++++++++++++++++++++ common/mltools/test-tools-messages.sh | 28 +++++ common/mltools/tools_messages_tests.ml | 46 ++++++++ common/mltools/tools_utils-c.c | 51 +++++++++ common/mltools/tools_utils.ml | 16 +++ lib/guestfs.pod | 19 ++++ 8 files changed, 316 insertions(+), 2 deletions(-) create mode 100644 common/mltools/parse_tools_messages_test.py create mode 100755 common/mltools/test-tools-messages.sh create mode 100644 common/mltools/tools_messages_tests.ml diff --git a/.gitignore b/.gitignore index 9a448fc4e..bfe44cd97 100644 --- a/.gitignore +++ b/.gitignore @@ -147,6 +147,7 @@ Makefile.in /common/mltools/JSON_tests /common/mltools/JSON_parser_tests /common/mltools/machine_readable_tests +/common/mltools/tools_messages_tests /common/mltools/tools_utils_tests /common/mltools/oUnit-* /common/mlutils/.depend diff --git a/common/mltools/Makefile.am b/common/mltools/Makefile.am index 37d10e610..ae78b84b7 100644 --- a/common/mltools/Makefile.am +++ b/common/mltools/Makefile.am @@ -27,6 +27,8 @@ EXTRA_DIST = \ machine_readable_tests.ml \ test-getopt.sh \ test-machine-readable.sh \ + test-tools-messages.sh \ + tools_messages_tests.ml \ tools_utils_tests.ml SOURCES_MLI = \ @@ -45,12 +47,12 @@ SOURCES_MLI = \ SOURCES_ML = \ getopt.ml \ + JSON.ml \ tools_utils.ml \ URI.ml \ planner.ml \ registry.ml \ regedit.ml \ - JSON.ml \ JSON_parser.ml \ curl.ml \ checksums.ml \ @@ -196,6 +198,15 @@ machine_readable_tests_CPPFLAGS = \ machine_readable_tests_BOBJECTS = machine_readable_tests.cmo machine_readable_tests_XOBJECTS = $(machine_readable_tests_BOBJECTS:.cmo=.cmx) +tools_messages_tests_SOURCES = dummy.c +tools_messages_tests_CPPFLAGS = \ + -I. \ + -I$(top_builddir) \ + -I$(shell $(OCAMLC) -where) \ + -I$(top_srcdir)/lib +tools_messages_tests_BOBJECTS = tools_messages_tests.cmo +tools_messages_tests_XOBJECTS = $(tools_messages_tests_BOBJECTS:.cmo=.cmx) + # Can't call the following as <test>_OBJECTS because automake gets confused. if !HAVE_OCAMLOPT tools_utils_tests_THEOBJECTS = $(tools_utils_tests_BOBJECTS) @@ -212,6 +223,9 @@ JSON_parser_tests.cmo: OCAMLPACKAGES += $(OCAMLPACKAGES_TESTS) machine_readable_tests_THEOBJECTS = $(machine_readable_tests_BOBJECTS) machine_readable_tests.cmo: OCAMLPACKAGES += $(OCAMLPACKAGES_TESTS) + +tools_messages_tests_THEOBJECTS = $(tools_messages_tests_tests_BOBJECTS) +tools_messages_tests.cmo: OCAMLPACKAGES += $(OCAMLPACKAGES_TESTS) else tools_utils_tests_THEOBJECTS = $(tools_utils_tests_XOBJECTS) tools_utils_tests.cmx: OCAMLPACKAGES += $(OCAMLPACKAGES_TESTS) @@ -227,6 +241,9 @@ JSON_parser_tests.cmx: OCAMLPACKAGES += $(OCAMLPACKAGES_TESTS) machine_readable_tests_THEOBJECTS = $(machine_readable_tests_XOBJECTS) machine_readable_tests.cmx: OCAMLPACKAGES += $(OCAMLPACKAGES_TESTS) + +tools_messages_tests_THEOBJECTS = $(tools_messages_tests_XOBJECTS) +tools_messages_tests.cmx: OCAMLPACKAGES += $(OCAMLPACKAGES_TESTS) endif OCAMLLINKFLAGS = \ @@ -302,14 +319,32 @@ machine_readable_tests_LINK = \ $(OCAMLPACKAGES) $(OCAMLPACKAGES_TESTS) \ $(machine_readable_tests_THEOBJECTS) -o $@ +tools_messages_tests_DEPENDENCIES = \ + $(tools_messages_tests_THEOBJECTS) \ + ../mlstdutils/mlstdutils.$(MLARCHIVE) \ + ../mlgettext/mlgettext.$(MLARCHIVE) \ + ../mlpcre/mlpcre.$(MLARCHIVE) \ + $(MLTOOLS_CMA) \ + $(top_srcdir)/ocaml-link.sh +tools_messages_tests_LINK = \ + $(top_srcdir)/ocaml-link.sh -cclib '-lutils -lgnu' -- \ + $(OCAMLFIND) $(BEST) $(OCAMLFLAGS) $(OCAMLLINKFLAGS) \ + $(OCAMLPACKAGES) $(OCAMLPACKAGES_TESTS) \ + $(tools_messages_tests_THEOBJECTS) -o $@ + TESTS_ENVIRONMENT = $(top_builddir)/run --test TESTS = \ test-getopt.sh \ test-machine-readable.sh +if HAVE_PYTHON +TESTS += \ + test-tools-messages.sh +endif check_PROGRAMS = \ getopt_tests \ - machine_readable_tests + machine_readable_tests \ + tools_messages_tests if HAVE_OCAML_PKG_OUNIT check_PROGRAMS += JSON_tests JSON_parser_tests tools_utils_tests diff --git a/common/mltools/parse_tools_messages_test.py b/common/mltools/parse_tools_messages_test.py new file mode 100644 index 000000000..9dcd6cae6 --- /dev/null +++ b/common/mltools/parse_tools_messages_test.py @@ -0,0 +1,118 @@ +# Copyright (C) 2019 Red Hat Inc. +# +# This program is free software; you can redistribute it and/or modify +# it under the terms of the GNU General Public License as published by +# the Free Software Foundation; either version 2 of the License, or +# (at your option) any later version. +# +# This program is distributed in the hope that it will be useful, +# but WITHOUT ANY WARRANTY; without even the implied warranty of +# MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the +# GNU General Public License for more details. +# +# You should have received a copy of the GNU General Public License +# along with this program; if not, write to the Free Software +# Foundation, Inc., 51 Franklin Street, Fifth Floor, Boston, MA 02110-1301 USA. + +import datetime +import json +import os +import sys +import unittest + +exe = "tools_messages_tests" + +if sys.version_info >= (3, 4): + def set_fd_inheritable(fd): + os.set_inheritable(fd, True) +else: + def set_fd_inheritable(fd): + pass + + +if sys.version_info >= (3, 0): + def fdopen(fd, mode): + return open(fd, mode) + + def isModuleInstalled(mod): + import importlib + return bool(importlib.util.find_spec(mod)) +else: + def fdopen(fd, mode): + return os.fdopen(fd, mode) + + def isModuleInstalled(mod): + import imp + try: + imp.find_module(mod) + return True + except ImportError: + return False + + +def skipUnlessHasModule(mod): + if not isModuleInstalled(mod): + return unittest.skip("%s not available" % mod) + return lambda func: func + + +def iterload(stream): + dec = json.JSONDecoder() + for line in stream: + yield dec.raw_decode(line) + + +def loadJsonFromCommand(extraargs): + r, w = os.pipe() + set_fd_inheritable(r) + r = fdopen(r, "r") + set_fd_inheritable(w) + w = fdopen(w, "w") + pid = os.fork() + if pid: + w.close() + l = list(iterload(r)) + l = [o[0] for o in l] + r.close() + return l + else: + r.close() + args = ["tools_messages_tests", + "--machine-readable=fd:%d" % w.fileno()] + extraargs + os.execvp("./" + exe, args) + + +@skipUnlessHasModule('iso8601') +class TestParseToolsMessages(unittest.TestCase): + def check_json(self, json, typ, msg): + import iso8601 + # Check the type. + jsontype = json.pop("type") + self.assertEqual(jsontype, typ) + # Check the message. + jsonmsg = json.pop("message") + self.assertEqual(jsonmsg, msg) + # Check the timestamp. + jsonts = json.pop("timestamp") + dt = iso8601.parse_date(jsonts) + now = datetime.datetime.now(dt.tzinfo) + self.assertGreater(now, dt) + # Check there are no more keys left (and thus not previously tested). + self.assertEqual(len(json), 0) + + def test_messages(self): + objects = loadJsonFromCommand([]) + self.assertEqual(len(objects), 4) + self.check_json(objects[0], "message", "Starting") + self.check_json(objects[1], "info", "An information message") + self.check_json(objects[2], "warning", "Warning: message here") + self.check_json(objects[3], "message", "Finishing") + + def test_error(self): + objects = loadJsonFromCommand(["--error"]) + self.assertEqual(len(objects), 1) + self.check_json(objects[0], "error", "Error!") + + +if __name__ == '__main__': + unittest.main() diff --git a/common/mltools/test-tools-messages.sh b/common/mltools/test-tools-messages.sh new file mode 100755 index 000000000..0e24d6ce9 --- /dev/null +++ b/common/mltools/test-tools-messages.sh @@ -0,0 +1,28 @@ +#!/bin/bash - +# libguestfs +# Copyright (C) 2019 Red Hat Inc. +# +# This program is free software; you can redistribute it and/or modify +# it under the terms of the GNU General Public License as published by +# the Free Software Foundation; either version 2 of the License, or +# (at your option) any later version. +# +# This program is distributed in the hope that it will be useful, +# but WITHOUT ANY WARRANTY; without even the implied warranty of +# MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the +# GNU General Public License for more details. +# +# You should have received a copy of the GNU General Public License +# along with this program; if not, write to the Free Software +# Foundation, Inc., 51 Franklin Street, Fifth Floor, Boston, MA 02110-1301 USA. + +# Test the --machine-readable functionality of the module Tools_utils. +# See also: machine_readable_tests.ml + +set -e +set -x + +$TEST_FUNCTIONS +skip_if_skipped + +$PYTHON parse_tools_messages_test.py diff --git a/common/mltools/tools_messages_tests.ml b/common/mltools/tools_messages_tests.ml new file mode 100644 index 000000000..d5f9be89b --- /dev/null +++ b/common/mltools/tools_messages_tests.ml @@ -0,0 +1,46 @@ +(* + * Copyright (C) 2019 Red Hat Inc. + * + * This program is free software; you can redistribute it and/or modify + * it under the terms of the GNU General Public License as published by + * the Free Software Foundation; either version 2 of the License, or + * (at your option) any later version. + * + * This program is distributed in the hope that it will be useful, + * but WITHOUT ANY WARRANTY; without even the implied warranty of + * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the + * GNU General Public License for more details. + * + * You should have received a copy of the GNU General Public License along + * with this program; if not, write to the Free Software Foundation, Inc., + * 51 Franklin Street, Fifth Floor, Boston, MA 02110-1301 USA. + *) + +(* Test the message output for tools of the module Tools_utils. + * The tests are controlled by the test-tools-messages.sh script. + *) + +open Printf + +open Std_utils +open Tools_utils +open Getopt.OptionName + +let is_error = ref false + +let args = [ + [ L "error" ], Getopt.Set is_error, "Only print the error"; +] +let usage_msg = sprintf "%s: test the message outputs" prog + +let opthandle = create_standard_options args ~machine_readable:true usage_msg +let () = + Getopt.parse opthandle.getopt; + + if !is_error then + error "Error!"; + + message "Starting"; + info "An information message"; + warning "Warning: message here"; + message "Finishing" diff --git a/common/mltools/tools_utils-c.c b/common/mltools/tools_utils-c.c index c88c95082..b015dcace 100644 --- a/common/mltools/tools_utils-c.c +++ b/common/mltools/tools_utils-c.c @@ -23,6 +23,8 @@ #include <unistd.h> #include <errno.h> #include <error.h> +#include <time.h> +#include <string.h> #include <caml/alloc.h> #include <caml/fail.h> @@ -37,6 +39,7 @@ extern value guestfs_int_mllib_inspect_decrypt (value gv, value gpv, value keysv); extern value guestfs_int_mllib_set_echo_keys (value unitv); extern value guestfs_int_mllib_set_keys_from_stdin (value unitv); +extern value guestfs_int_mllib_rfc3999_date_time_string (value unitv); /* Interface with the guestfish inspection and decryption code. */ int echo_keys = 0; @@ -103,3 +106,51 @@ guestfs_int_mllib_set_keys_from_stdin (value unitv) keys_from_stdin = 1; return Val_unit; } + +value +guestfs_int_mllib_rfc3999_date_time_string (value unitv) +{ + CAMLparam1 (unitv); + char buf[64]; + struct timespec ts; + struct tm tm; + size_t ret; + size_t total = 0; + + if (clock_gettime (CLOCK_REALTIME, &ts) == -1) + unix_error (errno, (char *) "clock_gettime", Val_unit); + + if (localtime_r (&ts.tv_sec, &tm) == NULL) + unix_error (errno, (char *) "localtime_r", caml_copy_int64 (ts.tv_sec)); + + /* Sadly strftime does not support nanoseconds, so what we do is: + * - stringify everything before the nanoseconds + * - print the nanoseconds + * - stringify the rest (i.e. the timezone) + * then place ':' between the hours, and the minutes of the + * timezone offset. + */ + + ret = strftime (buf, sizeof (buf), "%Y-%m-%dT%H:%M:%S.", &tm); + if (ret == 0) + unix_error (errno, (char *) "strftime", Val_unit); + total += ret; + + ret = snprintf (buf + total, sizeof (buf) - total, "%09ld", ts.tv_nsec); + if (ret == 0) + unix_error (errno, (char *) "sprintf", caml_copy_int64 (ts.tv_nsec)); + total += ret; + + ret = strftime (buf + total, sizeof (buf) - total, "%z", &tm); + if (ret == 0) + unix_error (errno, (char *) "strftime", Val_unit); + total += ret; + + /* Move the timezone minutes one character to the right, moving the + * null character too. + */ + memmove (buf + total - 1, buf + total - 2, 3); + buf[total - 2] = ':'; + + CAMLreturn (caml_copy_string (buf)); +} diff --git a/common/mltools/tools_utils.ml b/common/mltools/tools_utils.ml index 35478f39e..de42df600 100644 --- a/common/mltools/tools_utils.ml +++ b/common/mltools/tools_utils.ml @@ -32,6 +32,7 @@ and key_store_key = external c_inspect_decrypt : Guestfs.t -> int64 -> (string * key_store_key) list -> unit = "guestfs_int_mllib_inspect_decrypt" external c_set_echo_keys : unit -> unit = "guestfs_int_mllib_set_echo_keys" "noalloc" external c_set_keys_from_stdin : unit -> unit = "guestfs_int_mllib_set_keys_from_stdin" "noalloc" +external c_rfc3999_date_time_string : unit -> string = "guestfs_int_mllib_rfc3999_date_time_string" type machine_readable_fn = { pr : 'a. ('a, unit, string, unit) format4 -> 'a; @@ -86,12 +87,24 @@ let ansi_magenta ?(chan = stdout) () = let ansi_restore ?(chan = stdout) () = if colours () || istty chan then output_string chan "\x1b[0m" +let log_as_json msgtype msg = + match machine_readable () with + | None -> () + | Some { pr } -> + let json = [ + "message", JSON.String msg; + "timestamp", JSON.String (c_rfc3999_date_time_string ()); + "type", JSON.String msgtype; + ] in + pr "%s\n" (JSON.string_of_doc ~fmt:JSON.Compact json) + (* Timestamped progress messages, used for ordinary messages when not * --quiet. *) let start_t = Unix.gettimeofday () let message fs = let display str = + log_as_json "message" str; if not (quiet ()) then ( let t = sprintf "%.1f" (Unix.gettimeofday () -. start_t) in printf "[%6s] " t; @@ -106,6 +119,7 @@ let message fs = (* Error messages etc. *) let error ?(exit_code = 1) fs = let display str = + log_as_json "error" str; let chan = stderr in ansi_red ~chan (); wrap ~chan (sprintf (f_"%s: error: %s") prog str); @@ -124,6 +138,7 @@ let error ?(exit_code = 1) fs = let warning fs = let display str = + log_as_json "warning" str; let chan = stdout in ansi_blue ~chan (); wrap ~chan (sprintf (f_"%s: warning: %s") prog str); @@ -134,6 +149,7 @@ let warning fs = let info fs = let display str = + log_as_json "info" str; let chan = stdout in ansi_magenta ~chan (); wrap ~chan (sprintf (f_"%s: %s") prog str); diff --git a/lib/guestfs.pod b/lib/guestfs.pod index f11028466..3c1d635c5 100644 --- a/lib/guestfs.pod +++ b/lib/guestfs.pod @@ -3279,6 +3279,25 @@ Some of the tools support a I<--machine-readable> option, which is generally used to make the output more machine friendly, for easier parsing for example. By default, this output goes to stdout. +When using the I<--machine-readable> option, the progress, +information, warning, and error messages are also printed in JSON +format for easier log tracking. Thus, it is highly recommended to +redirect the machine-readable output to a different stream. The +format of these JSON messages is like the following (actually printed +within a single line, below it is indented for readability): + + { + "message": "Finishing off", + "timestamp": "2019-03-22T14:46:49.067294446+01:00", + "type": "message" + } + +C<type> can be: C<message> for progress messages, C<info> for +information messages, C<warning> for warning messages, and C<error> +for error message. +C<timestamp> is the L<RFC 3999|https://www.ietf.org/rfc/rfc3339.txt> +timestamp of the message. + In addition to that, a subset of these tools support an extra string passed to the I<--machine-readable> option: this string specifies where the machine-readable output will go. -- 2.20.1