New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Log subprocess input and output #4497

Merged

tothtamas28 merged 25 commits into develop from run-process-2

Jul 9, 2024

Contributor

tothtamas28 commented Jul 3, 2024 •

edited

Loading

This PR implements a helper function, run_process_2, that modifies the behavior of run_process in the following details:

run_process_2 does not stream to stderr (write_stderr=False) by default. run_process streams to stderr (pipe_stderr=False) by default.
run_process_2 does not allow the called process to inherit the parent's stdin.
run_process_2 logs stdin, stderr, stdout of the called process.
run_process_2 writes the PID with each log entry to correlate entries belonging to the same process.
run_process_2 logs if an exception is raised during the process (e.g. a KeyboardInterrupt).
run_process_2 has a more succinct and more structured log output.
run_process_2 always returns a CompletedProcess with stdout and stderr set. run_process only returns a non-None value if PIPE is passed for the corresponding argument.

These changes enable better integration of external tools into an application without compromising on debuggability (i.e. all information is logged but the caller's output streams are not polluted by the callee).

Example: log.txt

tothtamas28 self-assigned this

tothtamas28 commented

View reviewed changes

pyk/src/pyk/kllvm/compiler.py

                       args += ['--verbose']
                   _LOGGER.info(f'Compiling pythonast extension: {module_file.name}')
-                  run_process(args, logger=_LOGGER)
+                  run_process_2(args, logger=_LOGGER)

Contributor Author

tothtamas28 Jul 3, 2024

Breaking change: stderr is not written.

Contributor Author

tothtamas28 Jul 3, 2024 •

edited

Loading

New output:

In [0]: compile_kllvm('.', verbose=True)
INFO:pyk.kllvm.compiler:Compiling pythonast extension: _kllvm.cpython-310-x86_64-linux-gnu.so
INFO:pyk.kllvm.compiler:[PID=752090][exec] llvm-kompile pythonast --python /home/ttoth/.cache/pypoetry/virtualenvs/kframework-8Tiaz0lD-py3.10/bin/python --python-output-dir /home/ttoth/git/k/pyk --verbose
INFO:pyk.kllvm.compiler:[PID=752090][stde] +  /home/ttoth/git/k/k-distribution/bin/llvm-kompile-clang  python_ast nolto -fno-stack-protector -v /home/ttoth/git/k/k-distribution/target/release/k/lib/kllvm/python_src/ast.cpp --python /home/ttoth/.cache/pypoetry/virtualenvs/kframework-8Tiaz0lD-py3.10/bin/python -fuse-ld=lld --python-output-dir /home/ttoth/git/k/pyk
INFO:pyk.kllvm.compiler:[PID=752090][stde]   | +  /usr/bin/clang++-15 -Wno-override-module -Wno-return-type-c-linkage   /home/ttoth/git/k/k-distribution/bin/../lib/kllvm//libParser.a /home/ttoth/git/k/k-distribution/bin/../lib/kllvm//libAST.a /home/ttoth/git/k/k-distribution/bin/../lib/kllvm//libBinaryKore.a -Wl,-u,table_getArgumentSortsForTag -fPIC -shared -I/home/ttoth/git/k/k-distribution/bin/../include/ -fvisibility=hidden -I/home/ttoth/.pyenv/versions/3.10.13/include/python3.10 -I/home/ttoth/.cache/pypoetry/virtualenvs/kframework-8Tiaz0lD-py3.10/lib/python3.10/site-packages/pybind11/include -o /home/ttoth/git/k/pyk/_kllvm.cpython-310-x86_64-linux-gnu.so -ltinfo -lgmp -lgmpxx -lmpfr -lpthread -ldl -lffi -lunwind -I /home/ttoth/git/k/k-distribution/bin/../include/kllvm -I /home/ttoth/git/k/k-distribution/bin/../include --std=c++17 -fno-stack-protector /home/ttoth/git/k/k-distribution/target/release/k/lib/kllvm/python_src/ast.cpp -fuse-ld=lld
INFO:pyk.kllvm.compiler:[PID=752090][done] status=0 time=5.866s
Out[0]: PosixPath('/home/ttoth/git/k/pyk/_kllvm.cpython-310-x86_64-linux-gnu.so')

Contributor Author

tothtamas28 Jul 3, 2024

Old output:

In [0]: compile_kllvm('.', verbose=True)
INFO:pyk.kllvm.compiler:Compiling pythonast extension: _kllvm.cpython-310-x86_64-linux-gnu.so
INFO:pyk.kllvm.compiler:Running: llvm-kompile pythonast --python /home/ttoth/.cache/pypoetry/virtualenvs/kframework-8Tiaz0lD-py3.10/bin/python --python-output-dir /home/ttoth/git/k/pyk --verbose
+  /home/ttoth/git/k/k-distribution/bin/llvm-kompile-clang  python_ast nolto -fno-stack-protector -v /home/ttoth/git/k/k-distribution/target/release/k/lib/kllvm/python_src/ast.cpp --python /home/ttoth/.cache/pypoetry/virtualenvs/kframework-8Tiaz0lD-py3.10/bin/python -fuse-ld=lld --python-output-dir /home/ttoth/git/k/pyk
  | +  /usr/bin/clang++-15 -Wno-override-module -Wno-return-type-c-linkage   /home/ttoth/git/k/k-distribution/bin/../lib/kllvm//libParser.a /home/ttoth/git/k/k-distribution/bin/../lib/kllvm//libAST.a /home/ttoth/git/k/k-distribution/bin/../lib/kllvm//libBinaryKore.a -Wl,-u,table_getArgumentSortsForTag -fPIC -shared -I/home/ttoth/git/k/k-distribution/bin/../include/ -fvisibility=hidden -I/home/ttoth/.pyenv/versions/3.10.13/include/python3.10 -I/home/ttoth/.cache/pypoetry/virtualenvs/kframework-8Tiaz0lD-py3.10/lib/python3.10/site-packages/pybind11/include -o /home/ttoth/git/k/pyk/_kllvm.cpython-310-x86_64-linux-gnu.so -ltinfo -lgmp -lgmpxx -lmpfr -lpthread -ldl -lffi -lunwind -I /home/ttoth/git/k/k-distribution/bin/../include/kllvm -I /home/ttoth/git/k/k-distribution/bin/../include --std=c++17 -fno-stack-protector /home/ttoth/git/k/k-distribution/target/release/k/lib/kllvm/python_src/ast.cpp -fuse-ld=lld
INFO:pyk.kllvm.compiler:Completed in 5.706s with status 0: llvm-kompile pythonast --python /home/ttoth/.cache/pypoetry/virtualenvs/kframework-8Tiaz0lD-py3.10/bin/python --python-output-dir /home/ttoth/git/k/pyk --verbose
Out[0]: PosixPath('/home/ttoth/git/k/pyk/_kllvm.cpython-310-x86_64-linux-gnu.so')

pyk/src/pyk/kllvm/compiler.py

@@ @@ -87,7 +87,7 @@ def compile_runtime( @@
                       args += ccopts
                   _LOGGER.info(f'Compiling python extension: {module_file.name}')
-                  run_process(args, logger=_LOGGER)
+                  run_process_2(args, logger=_LOGGER)

Contributor Author

tothtamas28 Jul 3, 2024

Breaking change: stderr is not written.

pyk/src/pyk/kllvm/compiler.py

@@ @@ -123,7 +123,7 @@ def generate_hints( @@
                   args = [str(interpreter), str(input_kore_file), '-1', str(hints_file), '--proof-output']
                   _LOGGER.info(f'Generating hints: {hints_file.name}')
-                  run_process(args, logger=_LOGGER)
+                  run_process_2(args, logger=_LOGGER)

Contributor Author

tothtamas28 Jul 3, 2024

Breaking change: stderr is not written.

pyk/src/pyk/kllvm/load_static.py

    
            @@ -12,7 +12,7 @@
          
              def get_kllvm() -> Path:

                  args = ['llvm-kompile', '--bindings-path']

                  proc = run_process(args, pipe_stdout=True)

                  proc = run_process_2(args)

Contributor Author

tothtamas28 Jul 3, 2024

Breaking change: stderr is not written.

pyk/src/pyk/kore/tools.py

@@ @@ -79,5 +79,5 @@ def _kore_print( @@
                   if color is not None:
                       args += ['--color', 'on' if color else 'off']
-                  run_res = run_process(args, input=input)
+                  run_res = run_process_2(args, input=input)

Contributor Author

tothtamas28 Jul 3, 2024

Breaking change: stderr is not written.

tothtamas28 force-pushed the run-process-2 branch from ff2a3ae to 4bafaaf Compare

July 3, 2024 13:54

tothtamas28 requested review from Baltoli and gtrepta

July 3, 2024 15:23

tothtamas28 marked this pull request as ready for review

July 3, 2024 15:23

Contributor Author

tothtamas28 commented Jul 3, 2024

@dwightguth, this PR introduces some breaking changes in the pyk.kllvm module (listed above), please check if they're acceptable for the work you do. If not, I'll revert them.

tothtamas28 requested a review from dwightguth

July 3, 2024 15:26

Contributor

Baltoli commented Jul 4, 2024

I presume we'll want to eventually deprecate the old run_process and do a rename, once clients are no longer using it?

Baltoli approved these changes

View reviewed changes

Contributor Author

tothtamas28 commented Jul 4, 2024

I presume we'll want to eventually deprecate the old run_process and do a rename, once clients are no longer using it?

Exactly.

tothtamas28 force-pushed the run-process-2 branch 2 times, most recently from 3e6eded to c73fd15 Compare

July 5, 2024 15:30

gtrepta approved these changes

View reviewed changes

tothtamas28 added 16 commits

July 9, 2024 12:56


          Copy run_process to run_process_2

259afe3


          Remove parameter exec_process

23bd77e


          Copy subprocess.run from the standard library to subprocess_run

99d6c89


          Fix linting issues

d678d2f


          Replace subprocess.run by subprocess_run

1f3ca18


          Replace run_process by run_process_2

7efdc09


          Remove _mswindows

07c9c0f


          Remove parameter timeout

32f2c37


          Push parameter text

ecade95


          Remove default value of pipe_stdout

a9c820c


          Remove default value of pipe_stderr

e954b91


          Make subprocess_run private

bead972


          Slice on stdin

a120dd2


          Slice on capture_output

49d18ad


          Make kwargs explicit

9212b55


          Always PIPE

828e351

tothtamas28 added 9 commits

July 9, 2024 12:56


          Eliminate check

71366f8


          Push down logging

33bb1c6


          Improve logging: display PID, stream output

abd4e03


          Rename parameters, add default value

69ee0d0


          Unpack kwargs statically

b4a4071


          Log stdin

c005019


          Do not inherit the parent's stdin

7f709ec


          Log each line in command separately

5ff4008


          Flush on each line

722e4f1

tothtamas28 force-pushed the run-process-2 branch from ab0f045 to 722e4f1 Compare

July 9, 2024 12:57

tothtamas28 merged commit f6d64e9 into develop

18 checks passed

tothtamas28 deleted the run-process-2 branch

July 9, 2024 13:44

This was referenced Jul 11, 2024

Replace run_process by run_process_2 runtimeverification/evm-semantics#2524

Merged

Replace run_process by run_process_2 runtimeverification/kontrol#690

Merged

gtrepta mentioned this pull request

llvm_interpret logs are very verbose #4516

Closed

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet