add a an timing parameter to enable logtiming option in Pipeline invocations

Author: hobu

README.rst

@@ -73,6 +73,9 @@ sorts it by the ``X`` dimension:
     metadata = pipeline.metadata
     log = pipeline.log
 
+Pass ``timing=True`` when creating a pipeline to include PDAL timing
+information in ``pipeline.log`` after execution.
+
 Programmatic Pipeline Construction
 ................................................................................
 

src/pdal/PyPipeline.cpp

@@ -56,12 +56,12 @@ void CountPointTable::reset()
 
 
 PipelineExecutor::PipelineExecutor(
-    std::string const& json, std::vector<std::shared_ptr<Array>> arrays, int level)
+    std::string const& json, std::vector<std::shared_ptr<Array>> arrays, int level, bool timing)
 {
     if (level < 0 || level > 8)
         throw pdal_error("log level must be between 0 and 8!");
 
-    LogPtr log(Log::makeLog("pypipeline", &m_logStream));
+    LogPtr log(Log::makeLog("pypipeline", &m_logStream, timing));
     log->setLevel(static_cast<pdal::LogLevel>(level));
     m_manager.setLog(log);
 

src/pdal/PyPipeline.hpp

@@ -58,7 +58,7 @@ class Array;
 
 class PDAL_EXPORT PipelineExecutor {
 public:
-    PipelineExecutor(std::string const& json, std::vector<std::shared_ptr<Array>> arrays, int level);
+    PipelineExecutor(std::string const& json, std::vector<std::shared_ptr<Array>> arrays, int level, bool timing);
     virtual ~PipelineExecutor() = default;
 
     point_count_t execute(pdal::StringList allowedDims);

src/pdal/StreamableExecutor.cpp

@@ -186,10 +186,11 @@ char *PythonPointTable::getPoint(PointId idx)
 StreamableExecutor::StreamableExecutor(std::string const& json,
                                        std::vector<std::shared_ptr<Array>> arrays,
                                        int level,
+                                       bool timing,
                                        point_count_t chunkSize,
                                        int prefetch,
                                        pdal::StringList allowedDims)
-    : PipelineExecutor(json, arrays, level)
+    : PipelineExecutor(json, arrays, level, timing)
     , m_table(chunkSize, prefetch)
     , m_exc(nullptr)
 {

src/pdal/StreamableExecutor.hpp

@@ -80,6 +80,7 @@ class StreamableExecutor : public PipelineExecutor
     StreamableExecutor(std::string const& json,
                        std::vector<std::shared_ptr<Array>> arrays,
                        int level,
+                       bool timing,
                        point_count_t chunkSize,
                        int prefetch,
                        pdal::StringList allowedDim);

src/pdal/libpdalpython.cpp

@@ -186,7 +186,7 @@ namespace pdal {
 
         std::unique_ptr<PipelineIterator> iterator(int chunk_size, int prefetch, pdal::StringList allowedDims) {
             return std::unique_ptr<PipelineIterator>(new PipelineIterator(
-                getJson(), _inputs, _loglevel, chunk_size, prefetch, allowedDims
+                getJson(), _inputs, _loglevel, _timing, chunk_size, prefetch, allowedDims
             ));
         }
 
@@ -214,6 +214,10 @@ namespace pdal {
 
         void setLogLevel(int level) { _loglevel = level; delExecutor(); }
 
+        bool getTiming() { return _timing; }
+
+        void setTiming(bool timing) { _timing = timing; delExecutor(); }
+
         std::string getLog() { return getExecutor()->getLog(); }
 
         std::string getPipeline() { return getExecutor()->getPipeline(); }
@@ -291,14 +295,15 @@ namespace pdal {
             // does for all of the other methods it knows about
             py::gil_scoped_acquire acquire;
             if (!_executor)
-                _executor.reset(new PipelineExecutor(getJson(), _inputs, _loglevel));
+                _executor.reset(new PipelineExecutor(getJson(), _inputs, _loglevel, _timing));
             return _executor.get();
         }
 
     private:
         std::unique_ptr<PipelineExecutor> _executor;
         std::vector<std::shared_ptr<pdal::python::Array>> _inputs;
-        int _loglevel;
+        int _loglevel = 0;
+        bool _timing = false;
     };
 
 
@@ -324,6 +329,7 @@ namespace pdal {
         .def("iterator", &Pipeline::iterator, "chunk_size"_a=10000, "prefetch"_a=0, py::arg("allowed_dims") =py::list())
         .def_property("inputs", nullptr, &Pipeline::setInputs)
         .def_property("loglevel", &Pipeline::getLoglevel, &Pipeline::setLogLevel)
+        .def_property("timing", &Pipeline::getTiming, &Pipeline::setTiming)
         .def_property_readonly("log", &Pipeline::getLog)
         .def_property_readonly("schema", &Pipeline::getSchema)
         .def_property_readonly("srswkt2", &Pipeline::getSrsWKT2)

src/pdal/pipeline.py

@@ -49,6 +49,8 @@ def __init__(
         json: Optional[str] = None,
         dataframes: Sequence[DataFrame] = (),
         stream_handlers: Sequence[Callable[[], int]] = (),
+        *,
+        timing: bool = False,
     ):
 
         if json:
@@ -75,6 +77,7 @@ def __init__(
             self.inputs = [(a, None) for a in arrays]
 
         self.loglevel = loglevel
+        self.timing = timing
 
     def __getstate__(self):
         state = self.pipeline
@@ -104,6 +107,14 @@ def loglevel(self, value: int) -> None:
         # super() property setter is not supported
         libpdalpython.Pipeline.loglevel.__set__(self, loglevel)
 
+    @property
+    def timing(self) -> bool:
+        return super().timing
+
+    @timing.setter
+    def timing(self, value: bool) -> None:
+        libpdalpython.Pipeline.timing.__set__(self, bool(value))
+
     def __ior__(self, other: Union[Stage, Pipeline]) -> Pipeline:
         if isinstance(other, Stage):
             self._stages.append(other)
@@ -124,7 +135,7 @@ def __or__(self, other: Union[Stage, Pipeline]) -> Pipeline:
         return new
 
     def __copy__(self) -> Pipeline:
-        clone = self.__class__(loglevel=self.loglevel)
+        clone = self.__class__(loglevel=self.loglevel, timing=self.timing)
         clone._copy_inputs(self)
         clone |= self
         return clone
@@ -214,8 +225,13 @@ def inputs(self) -> List[Union[Stage, str]]:
     def options(self) -> Dict[str, Any]:
         return dict(self._options)
 
-    def pipeline(self, *arrays: np.ndarray, loglevel: int = logging.ERROR) -> Pipeline:
-        return Pipeline((self,), arrays, loglevel)
+    def pipeline(
+        self,
+        *arrays: np.ndarray,
+        loglevel: int = logging.ERROR,
+        timing: bool = False,
+    ) -> Pipeline:
+        return Pipeline((self,), arrays, loglevel=loglevel, timing=timing)
 
     def __or__(self, other: Union[Stage, Pipeline]) -> Pipeline:
         return Pipeline((self, other))

test/test_pipeline.py

@@ -1,6 +1,7 @@
 import json
 import logging
 import os
+import re
 import sys
 
 from itertools import product
@@ -53,6 +54,21 @@ def test_construction(self, filename):
             assert isinstance(p, pdal.Pipeline)
             assert len(p.stages) == 2
 
+    def test_timing_is_optional_public_api(self):
+        with open(os.path.join(DATADIRECTORY, "chip.json"), "r") as f:
+            pipeline_json = f.read()
+
+        p = pdal.Pipeline(None, (), logging.ERROR, pipeline_json)
+        assert p.timing is False
+        assert p.execute() == 1065
+
+        with pytest.raises(TypeError):
+            pdal.Pipeline(None, (), logging.ERROR, pipeline_json, (), (), True)
+
+        reader = pdal.Reader(os.path.join(DATADIRECTORY, "1.2-with-color.las"))
+        assert reader.pipeline().timing is False
+        assert reader.pipeline(timing=True).timing is True
+
     @pytest.mark.parametrize(
         "pipeline",
         [
@@ -338,6 +354,7 @@ def test_logging(self, filename):
         """Can we fetch log output"""
         r = get_pipeline(filename)
         assert r.loglevel == logging.ERROR
+        assert r.timing is False
         assert r.log == ""
 
         for loglevel in logging.CRITICAL, -1:
@@ -356,6 +373,17 @@ def test_logging(self, filename):
         assert "(pypipeline Debug) Executing pipeline in standard mode" in r.log
         assert "(pypipeline writers.las Debug)" in r.log
 
+    def test_logging_timing(self):
+        """Can we fetch log output decorated with timing information"""
+        with open(os.path.join(DATADIRECTORY, "chip.json"), "r") as f:
+            r = pdal.Pipeline(f.read(), loglevel=logging.DEBUG, timing=True)
+
+        assert r.timing is True
+        count = r.execute()
+        assert count == 1065
+        assert re.search(r"\(pypipeline readers\.las Debug [0-9.]+\)", r.log)
+        assert re.search(r"\(pypipeline Debug [0-9.]+\) Executing pipeline in standard mode", r.log)
+
     @pytest.mark.skipif(
         not hasattr(pdal.Filter, "python"),
         reason="filters.python PDAL plugin is not available",
@@ -904,4 +932,3 @@ def invalid_stream_handler():
         with pytest.raises(RuntimeError,
                            match=f"Stream chunk size not in the range of array length: {invalid_chunk_size}"):
             p.execute()
-