popen options for subprocessing (#32)

.github/workflows/build_nix.yml

@@ -27,7 +27,7 @@ jobs:
     - run: |
         curl -Lo mkn https://github.com/mkn/mkn/releases/download/latest/mkn_nix
         chmod +x mkn
-        ./mkn clean build -p scope_timer test -a "-fPIC -std=c++17"
+        ./mkn clean build test run -p scope_timer,threaded_scope_timer -Oa "-fPIC -std=c++20" -W 9
 
     - uses: actions/setup-python@v4
       with:

inc/phlop/timing/scope_timer.hpp

@@ -90,8 +90,8 @@ struct ScopeTimerMan
 
 struct RunTimerReportSnapshot
 {
-    RunTimerReportSnapshot(RunTimerReport* s, RunTimerReport* p, std::uint64_t const& st,
-                           std::uint64_t const& t)
+    RunTimerReportSnapshot(RunTimerReport* s, RunTimerReport* p, std::uint64_t const st,
+                           std::uint64_t const t)
         : self{s}
         , parent{p}
         , start{st}
@@ -167,17 +167,17 @@ struct scope_timer
 
 struct BinaryTimerFileNode
 {
-    BinaryTimerFileNode(std::uint16_t const& _fn_id, std::uint64_t const& _start,
-                        std::uint64_t const& _time)
+    BinaryTimerFileNode(std::uint16_t const& _fn_id, std::uint64_t const _start,
+                        std::uint64_t const _time)
         : fn_id{_fn_id}
         , start{_start}
         , time{_time}
     {
     }
 
-    std::uint16_t fn_id;
-    std::uint64_t start;
-    std::uint64_t time;
+    std::uint16_t const fn_id;
+    std::uint64_t const start;
+    std::uint64_t const time;
 
     std::vector<BinaryTimerFileNode> kinder{};
 };

inc/phlop/timing/threaded_scope_timer.hpp

@@ -141,9 +141,11 @@ struct ScopeTimerMan
 
 struct RunTimerReportSnapshot
 {
-    RunTimerReportSnapshot(RunTimerReport* s, RunTimerReport* p, std::uint64_t const& t)
+    RunTimerReportSnapshot(RunTimerReport* s, RunTimerReport* p, std::uint64_t const st,
+                           std::uint64_t const t)
         : self{s}
         , parent{p}
+        , start{st}
         , time{t}
     {
         childs.reserve(2);
@@ -152,6 +154,7 @@ struct RunTimerReportSnapshot
     RunTimerReport const* const self;
     RunTimerReport const* const parent;
 
+    std::uint64_t const start;
     std::uint64_t const time;
     std::vector<RunTimerReportSnapshot*> childs;
 };
@@ -190,7 +193,7 @@ struct scope_timer
     std::uint64_t static now()
     {
         return std::chrono::duration_cast<std::chrono::nanoseconds>(
-                   std::chrono::system_clock::now().time_since_epoch())
+                   std::chrono::steady_clock::now().time_since_epoch())
             .count();
     }
 
@@ -215,14 +218,17 @@ struct scope_timer
 
 struct BinaryTimerFileNode
 {
-    BinaryTimerFileNode(std::uint16_t _fn_id, std::uint64_t _time)
+    BinaryTimerFileNode(std::uint16_t const& _fn_id, std::uint64_t const _start,
+                        std::uint64_t const _time)
         : fn_id{_fn_id}
+        , start{_start}
         , time{_time}
     {
     }
 
-    std::uint16_t fn_id;
-    std::uint64_t time;
+    std::uint16_t const fn_id;
+    std::uint64_t const start;
+    std::uint64_t const time;
 
     std::vector<BinaryTimerFileNode> kinder{};
 };
@@ -240,8 +246,8 @@ struct BinaryTimerFile
             for (auto const& [reports, traces] : ScopeTimerMan::INSTANCE().thread_storage)
                 for (auto const& trace : traces)
                     recurse_traces_for_nodes(
-                        trace,
-                        roots.emplace_back(key_ids[std::string{trace->self->k}], trace->time));
+                        trace, roots.emplace_back(key_ids[std::string{trace->self->k}],
+                                                  trace->start, trace->time));
         }
     }
 
@@ -252,7 +258,7 @@ struct BinaryTimerFile
         for (std::size_t i = 0; i < c->childs.size(); ++i)
             recurse_traces_for_nodes(
                 c->childs[i], node.kinder.emplace_back(key_ids[std::string{c->childs[i]->self->k}],
-                                                       c->childs[i]->time));
+                                                       c->childs[i]->start, c->childs[i]->time));
     }
 
     template<typename Trace>
@@ -322,7 +328,7 @@ struct BinaryTimerFile
     {
         for (std::size_t ti = 0; ti < tabs; ++ti)
             file << " ";
-        file << node.fn_id << " " << node.time << std::endl;
+        file << node.fn_id << " " << node.start << ":" << node.time << std::endl;
         for (auto const& n : node.kinder)
             _write(file, n, tabs + 1);
     }

mkn.yaml

@@ -1,3 +1,4 @@
+#! clean build test run -p scope_timer,threaded_scope_timer -Oa "-fPIC -std=c++20" -W 9
 
 name: phlop
 parent: base
@@ -8,6 +9,12 @@ profile:
 
 - name: scope_timer
   parent: base
-  src: src/phlop/timing/scope_timer.cpp # static instance lives here
+  src: src/phlop/timing/scope_timer.cpp
   mode: shared
   test: tests/timing/test_scope_timer.cpp
+
+- name: threaded_scope_timer
+  parent: base
+  src: src/phlop/timing/threaded_scope_timer.cpp
+  mode: shared
+  test: tests/timing/test_threaded_scope_timer.cpp

phlop/os.py

@@ -48,5 +48,21 @@ def write_to_file(file, contents, mode="w", skip_if_empty=True):
             raise RuntimeError(f"Failed to write to file {file}: {e}")
 
 
+def read_file(file):
+    try:
+        with open(file, "r") as f:
+            return f.read()
+    except IOError as e:
+        raise RuntimeError(f"Failed to read file {file}: {e}")
+
+
+def read_last_lines_of(file, n=10):
+    try:
+        with open(file, "r") as f:
+            return f.readlines()[:10]
+    except IOError as e:
+        raise RuntimeError(f"Failed to read file {file}: {e}")
+
+
 def env_sep():
     return ";" if any(platform.win32_ver()) else ":"

phlop/proc.py

@@ -2,6 +2,7 @@
 #
 #
 #
+
 import subprocess
 import sys
 

phlop/procs/runtimer.py

@@ -2,13 +2,11 @@
 #
 #
 #
-#
 
 
 import os
 import subprocess
 import time
-from copy import deepcopy
 
 from phlop.os import pushd, write_to_file
 from phlop.string import decode_bytes
@@ -26,63 +24,99 @@ def __init__(
         working_dir=None,
         log_file_path=None,
         logging=2,
+        popen=True,
         **kwargs,
     ):
         self.cmd = cmd
-        start = time.time()
-
-        self.run_time = None
         self.stdout = ""
         self.stderr = ""
+        self.run_time = None
+        self.logging = logging
+        self.log_file_path = log_file_path
+        self.capture_output = capture_output
         benv = os.environ.copy()
         benv.update(env)
-        self.logging = logging
-
-        ekwargs = {}
+        ekwargs = dict(
+            shell=shell,
+            env=benv,
+            close_fds=True,
+            stdout=subprocess.DEVNULL,
+            stderr=subprocess.DEVNULL,
+        )
         if not capture_output and log_file_path:
             ekwargs.update(
                 dict(
                     stdout=open(f"{log_file_path}.stdout", "w"),
                     stderr=open(f"{log_file_path}.stderr", "w"),
                 ),
             )
+        else:
+            ekwargs.update(
+                dict(stdout=subprocess.PIPE, stderr=subprocess.PIPE),
+            )
 
-        def run():
-            logging = deepcopy(self.logging)
-            try:
-                self.run = subprocess.run(
-                    self.cmd,
-                    shell=shell,
-                    check=check,
-                    env=benv,
-                    capture_output=capture_output,
-                    close_fds=True,
-                    **kwargs,
-                    **ekwargs,
+        def go():
+            if popen:
+                self._popen(**ekwargs, **kwargs)
+            else:
+                self._run(
+                    check=check, capture_output=capture_output, **ekwargs, **kwargs
                 )
-                self.run_time = time.time() - start
-                self.exitcode = self.run.returncode
-                if logging == 2 and capture_output:
-                    self.stdout = decode_bytes(self.run.stdout)
-                    self.stderr = decode_bytes(self.run.stderr)
-            except (
-                subprocess.CalledProcessError
-            ) as e:  # only triggers on failure if check=True
-                self.exitcode = e.returncode
-                self.run_time = time.time() - start
-                if logging >= 1 and capture_output:
-                    self.stdout = decode_bytes(e.stdout)
-                    self.stderr = decode_bytes(e.stderr)
-                    logging = 2  # force logging as exception occurred
-            if logging == 2 and capture_output and log_file_path:
-                write_to_file(f"{log_file_path}.stdout", self.stdout)
-                write_to_file(f"{log_file_path}.stderr", self.stderr)
 
         if working_dir:
             with pushd(working_dir):
-                run()
+                go()
         else:
-            run()
+            go()
+
+    def _locals(self):
+        return self.capture_output, self.log_file_path, self.logging
+
+    def _run(self, **kwargs):
+        capture_output, log_file_path, logging = self._locals()
+        try:
+            start = time.time()
+            self.run = subprocess.run(self.cmd, **kwargs)
+            self.run_time = time.time() - start
+            self.exitcode = self.run.returncode
+            if logging == 2 and capture_output:
+                self.stdout = decode_bytes(self.run.stdout)
+                self.stderr = decode_bytes(self.run.stderr)
+        except subprocess.CalledProcessError as e:
+            # only triggers on failure if check=True
+            self.run_time = time.time() - start
+            self.exitcode = e.returncode
+            if logging >= 1 and capture_output:
+                self.stdout = decode_bytes(e.stdout)
+                self.stderr = decode_bytes(e.stderr)
+                logging = 2  # force logging as exception occurred
+        if logging == 2 and capture_output and log_file_path:
+            write_to_file(f"{log_file_path}.stdout", self.stdout)
+            write_to_file(f"{log_file_path}.stderr", self.stderr)
+
+    def _popen(self, **kwargs):
+        capture_output, log_file_path, logging = self._locals()
+        start = time.time()
+        p = subprocess.Popen(self.cmd, **kwargs)
+        self.stdout, self.stderr = p.communicate()
+        self.run_time = time.time() - start
+        self.exitcode = p.returncode
+        if not capture_output and log_file_path:
+            kwargs["stdout"].close()
+            kwargs["stderr"].close()
+        elif capture_output:
+            p.stdout.close()
+            p.stderr.close()
+        p = None
+
+        if self.exitcode > 0 and capture_output:
+            logging = 2  # force logging as exception occurred
+        if logging == 2 and capture_output:
+            self.stdout = decode_bytes(self.stdout)
+            self.stderr = decode_bytes(self.stderr)
+        if logging == 2 and capture_output and log_file_path:
+            write_to_file(f"{log_file_path}.stdout", self.stdout)
+            write_to_file(f"{log_file_path}.stderr", self.stderr)
 
     def out(self, ignore_exit_code=False):
         if not ignore_exit_code and self.exitcode > 0:

phlop/reflection.py

@@ -2,7 +2,6 @@
 #
 #
 #
-#
 
 import importlib
 import inspect
@@ -17,7 +16,7 @@
 ).lower() in ("true", "1", "t")
 
 
-def classes_in_file(file_path, subclasses_only=None, fail_on_import_error=False):
+def classes_in_file(file_path, subclasses_only=None, fail_on_import_error=True):
     file = Path(file_path)
     module = str(file).replace(os.path.sep, ".")[:-3]
     assert module