Track and report unpack performance (distributed-system-analysis#3610)

I added a simple server.unpack-perf metadata, which is a JSON block like {"min": <seconds>, "max": <seconds>, "count": <unpack_count>}, and then played with the report generator to get some statistics.

I also wrote a report of the Audit table contents to summarize the operations, statuses, and users involved in the Pbench Server.

The sample below is for a runlocal, with a few small-ish tarballs. The big catch in deploying this would be that none of the existing datasets will have server.unpack-perf until they're unpacked again, which somewhat reduces the value of the statistics until they get unpacked again (e.g., for TOC or visualize).

Cache report:
  7 datasets currently unpacked, consuming 51.7 MB
  7 datasets have been unpacked a total of 7 times
  The least recently used cache was referenced today, fio_rw_2018.02.01T22.40.57
  The most recently used cache was referenced today, trafficgen_basic-forwarding-example_tg:trex-profile_pf:forwarding_test.json_ml:5_tt:bs__2019-08-27T14:58:38
  The smallest cache is 307.2 kB, linpack_mock_2020.02.28T19.10.55
  The biggest cache is 19.6 MB, trafficgen_basic-forwarding-example_tg:trex-profile_pf:forwarding_test.json_ml:5_tt:bs__2019-08-27T14:58:38
  The worst compression ratio is 22.156%, uperf_rhel8.1_4.18.0-107.el8_snap4_25gb_virt_2019.06.21T01.28.57
  The best compression ratio is 96.834%, pbench-user-benchmark_example-vmstat_2018.10.24T14.38.18
  The fastest cache unpack is 0.014 seconds, linpack_mock_2020.02.28T19.10.55
  The slowest cache unpack is 0.084 seconds, trafficgen_basic-forwarding-example_tg:trex-profile_pf:forwarding_test.json_ml:5_tt:bs__2019-08-27T14:58:38
  The fastest cache unpack streaming rate is 233.226 Mb/second, trafficgen_basic-forwarding-example_tg:trex-profile_pf:forwarding_test.json_ml:5_tt:bs__2019-08-27T14:58:38
  The slowest cache unpack streaming rate is 22.228 Mb/second, linpack_mock_2020.02.28T19.10.55
  1 datasets have no unpacked size, 1 are missing reference timestamps, 0 have bad size metadata
  1 datasets are missing unpack metric data, 0 have bad unpack metric data
  1 datasets are missing unpack performance data
Audit logs:
  138 audit log rows for 69 events
  0 unterminated root rows, 0 unmatched terminators
  Status summary:
                   BEGIN         69
                 SUCCESS         68
                 FAILURE          1
  Operation summary:
                template         36
                  upload          9
                   cache          7
                   index          6
                  apikey          1
                  update         10
  Object type summary:
                TEMPLATE         36
                 DATASET         32
                 API_KEY          1
  Users summary:
              BACKGROUND         49
                  tester         18
               testadmin          2

Author: dbutenhof

lib/pbench/cli/server/__init__.py

@@ -1,7 +1,129 @@
+import datetime
+from threading import Thread
+import time
+
+import click
+
 from pbench.server import PbenchServerConfig
 from pbench.server.database import init_db
 
 
+class Detail:
+    """Encapsulate generation of additional diagnostics"""
+
+    def __init__(self, detail: bool = False, errors: bool = False):
+        """Initialize the object.
+
+        Args:
+            detail: True if detailed messages should be generated
+            errors: True if individual file errors should be reported
+        """
+        self.detail = detail
+        self.errors = errors
+
+    def __bool__(self) -> bool:
+        """Report whether detailed messages are enabled
+
+        Returns:
+            True if details are enabled
+        """
+        return self.detail
+
+    def error(self, message: str):
+        """Write a message if details are enabled.
+
+        Args:
+            message: Detail string
+        """
+        if self.errors:
+            click.secho(f"|| {message}", fg="red")
+
+    def message(self, message: str):
+        """Write a message if details are enabled.
+
+        Args:
+            message: Detail string
+        """
+        if self.detail:
+            click.echo(f"|| {message}")
+
+
+class Verify:
+    """Encapsulate -v status messages."""
+
+    def __init__(self, verify: bool):
+        """Initialize the object.
+
+        Args:
+            verify: True to write status messages.
+        """
+        self.verify = verify
+
+    def __bool__(self) -> bool:
+        """Report whether verification is enabled.
+
+        Returns:
+            True if verification is enabled.
+        """
+        return self.verify
+
+    def status(self, message: str):
+        """Write a message if verification is enabled.
+
+        Args:
+            message: status string
+        """
+        if self.verify:
+            ts = datetime.datetime.now().astimezone()
+            click.secho(f"({ts:%H:%M:%S}) {message}", fg="green")
+
+
+class Watch:
+    """Encapsulate a periodic status update.
+
+    The active message can be updated at will; a background thread will
+    periodically print the most recent status.
+    """
+
+    def __init__(self, interval: float):
+        """Initialize the object.
+
+        Args:
+            interval: interval in seconds for status updates
+        """
+        self.start = time.time()
+        self.interval = interval
+        self.status = "starting"
+        if interval:
+            self.thread = Thread(target=self.watcher)
+            self.thread.setDaemon(True)
+            self.thread.start()
+
+    def update(self, status: str):
+        """Update status if appropriate.
+
+        Update the message to be printed at the next interval, if progress
+        reporting is enabled.
+
+        Args:
+            status: status string
+        """
+        self.status = status
+
+    def watcher(self):
+        """A worker thread to periodically write status messages."""
+
+        while True:
+            time.sleep(self.interval)
+            now = time.time()
+            delta = int(now - self.start)
+            hours, remainder = divmod(delta, 3600)
+            minutes, seconds = divmod(remainder, 60)
+            click.secho(
+                f"[{hours:02d}:{minutes:02d}:{seconds:02d}] {self.status}", fg="cyan"
+            )
+
+
 def config_setup(context: object) -> PbenchServerConfig:
     config = PbenchServerConfig.create(context.config)
     # We're going to need the DB to track dataset state, so setup DB access.

lib/pbench/cli/server/options.py

@@ -22,13 +22,15 @@ def _pbench_server_config(f: Callable) -> Callable:
 
     def callback(ctx, param, value):
         clictx = ctx.ensure_object(CliContext)
-        clictx.config = value
+        clictx.config = (
+            value if value else "/opt/pbench-server/lib/config/pbench-server.cfg"
+        )
         return value
 
     return click.option(
         "-C",
         "--config",
-        required=True,
+        required=False,
         envvar="_PBENCH_SERVER_CONFIG",
         type=click.Path(exists=True, readable=True),
         callback=callback,