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.
2026-03-21 22:53:37 +00:00 · 2019-03-22 16:24:25 +01:00
parent 70514dfaf1
commit f79129b8dc
8 changed files with 316 additions and 2 deletions
--- 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
--- 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
--- a/common/mltools/parse_tools_messages_test.py
+++ 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()
--- a/common/mltools/test-tools-messages.sh
+++ 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
--- a/common/mltools/tools_messages_tests.ml
+++ 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"
--- 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));
+}
--- 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);
--- 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.