Running subprocess.run() works in REPL, but doesn't when running script from terminal

I have the following command that I need to run via the subprocess.run() method in Python3.8:

/home/greg/FreeCAD/FreeCAD-0.20.0-Linux-x86_64.AppImage --console UpdateGeometry.py arg1 arg2 arg3

I’ve implemented this with the following script, evaluate_iteration.py (I’ve removed fstrings and other boilerplate for simplicity):

import subprocess
def main( paramFile ):
    # do stuff
    params = readParamFile( paramFile )
    make_geometry( params )
    # do more stuff

def make_geometry( params ):
    subprocess.run( "/home/greg/FreeCAD/FreeCAD-0.20.0-Linux-x86_64.AppImage --console UpdateGeometry.py 20.83 114.9 8.3", shell=True, check=True )

if __name__ == "__main__":
    main( sys.argv[-1] )

If I launch Python REPL from the command line and paste the relevant methods from the above script, I can run either main() or make_geometry() and the subprocess executes as expected. However, if I run the evaluate_iteration.py script I get an error:

(conda_deps)greg /path/to/my/cwd $ python3.8 evaluate_iteration.py params_file.csv
Traceback (most recent call last):
  File "evaluate_iteration.py", line 94, in <module>
    main( paramFile )
  File "evaluate_iteration.py", line 14, in main
    make_geometry( params )
  File "evaluate_iteration.py", line 32, in make_geometry
    subprocess.run( "/home/greg/FreeCAD/FreeCAD-0.20.0-Linux-x86_64.AppImage --console UpdateGeometry.py 20.83 114.9 8.3", shell=True, check=True )
  File "/my/path/to/conda_deps/lib/python3.8/subprocess.py", line 516, in run
    raise CalledProcessError(retcode, process.args,
subprocess.CalledProcessError: Command '/home/greg/FreeCAD/FreeCAD-0.20.0-Linux-x86_64.AppImage --console UpdateGeometry.py 20.83 114.9 8.3' returned non-zero exit status 127.

From my experience and Google-fu, the exit status of 127 generally indicates “command not found”… I tried replacing the executable with a different software binary and it works fine. I’ve chmod-ed the FreeCAD directory to 777 recusively, my cwd to 777… I’m at a loss for why this isn’t working. Any thoughts?

By Greg Vernon via Discussions on Python.org at 06Aug2022 23:03:

I have the following command that I need to run via the
subprocess.run() method in Python3.8:

/home/greg/FreeCAD/FreeCAD-0.20.0-Linux-x86_64.AppImage --console UpdateGeometry.py arg1 arg2 arg3

I’ve implemented this with the following script, evaluate_iteration.py (I’ve removed fstrings and other boilerplate for simplicity):
[…]
def make_geometry( params ):
subprocess.run( “/home/greg/FreeCAD/FreeCAD-0.20.0-Linux-x86_64.AppImage --console UpdateGeometry.py 20.83 114.9 8.3”, shell=True, check=True )

This runs a shell command string "/home/greg/FreeCAD/FreeCAD-0.20.0-Linux-x86_64.AppImage --console UpdateGeometry.py 20.83 114.9 8.3".

It is generally better to supply the command as a list of strings, eg:

subprocess.run([
    "/home/greg/FreeCAD/FreeCAD-0.20.0-Linux-x86_64.AppImage",
    "--console",
    "UpdateGeometry.py",
    "20.83",
    "114.9",
    "8.3",
], check=True )

Note: drops shell=True. This is because if you run a shell command
you’re at risk of shell punctuation mangling your intended meaning.

However, to your actual problem:

If I launch Python REPL from the command line and paste the relevant
methods from the above script, I can run either main() or
make_geometry() and the subprocess executes as expected.

Ok…

However, if I run the evaluate_iteration.py script I get an error:

(conda_deps)greg /path/to/my/cwd $ python3.8 evaluate_iteration.py params_file.csv
Traceback (most recent call last):
 File "evaluate_iteration.py", line 94, in <module>
   main( paramFile )
 File "evaluate_iteration.py", line 14, in main
   make_geometry( params )
 File "evaluate_iteration.py", line 32, in make_geometry
   subprocess.run( "/home/greg/FreeCAD/FreeCAD-0.20.0-Linux-x86_64.AppImage --console UpdateGeometry.py 20.83 114.9 8.3", shell=True, check=True )
 File "/my/path/to/conda_deps/lib/python3.8/subprocess.py", line 516, in run
   raise CalledProcessError(retcode, process.args,
subprocess.CalledProcessError: Command '/home/greg/FreeCAD/FreeCAD-0.20.0-Linux-x86_64.AppImage --console UpdateGeometry.py 20.83 114.9 8.3' returned non-zero exit status 127.

From my experience and Google-fu, the exit status of 127 generally indicates “command not found”…

Perhaps so. But what happens if you run the command:

/home/greg/FreeCAD/FreeCAD-0.20.0-Linux-x86_64.AppImage --console UpdateGeometry.py 20.83 114.9 8.3

at your shell prompt, and not from within Python? Make sure to
copy/paste directly from the error message above to make sure you’re
trying exactly the same command.

I tried replacing the executable with a different software binary and
it works fine.

That may mean that the binary you’re trying to run is invalid, or lacks
execute permissions.

I’ve chmod-ed the FreeCAD directory to 777 recusively, my cwd to
777… I’m at a loss for why this isn’t working. Any thoughts?

Please do not randomly chmod 777 anything. It is almost always the
wrong thing to do.

Try executing the command directly from the UNIX shell. I’d expact that
to fail the same way. If it fails, you can possibly see why by
running:

strace -f -e trace=execve /home/greg/FreeCAD/FreeCAD-0.20.0-Linux-x86_64.AppImage

which may show you the actual underlying OS error.

Cheers,
Cameron Simpson cs@cskk.id.au

It executes just as it does from within the Python REPL:

(conda_deps)greg /path/to/my/cwd $ /home/greg/FreeCAD/FreeCAD-0.20.0-Linux-x86_64.AppImage --console UpdateGeometry.py 20.83 114.9 8.3
Importing project files......
Postprocessing......                            (100 %)
Opened Model
Recompute......                                 (100 %)
                                                (89 Updated Model
Exported Part
Closed Model                                    (100 %)
(conda_deps)greg /path/to/my/cwd $ 

Please do not randomly chmod 777 anything. It is almost always the
wrong thing to do.

I’m on a safe system, temporarily chmoded to 777 to make sure it wasn’t some wierd permission inheritance.

Try executing the command directly from the UNIX shell. I’d expact that
to fail the same way. If it fails, you can possibly see why by
running [ … ] which may show you the actual underlying OS error.

(conda_deps)greg /path/to/my/cwd $ strace -f -e trace=execve /home/greg/FreeCAD/FreeCAD-0.20.0-Linux-x86_64.AppImage --console UpdateGeometry.py 20.83 114.9 8.3
execve("/home/greg/FreeCAD/FreeCAD-0.20.0-Linux-x86_64.AppImage", ["/home/greg/FreeCAD/FreeCAD-0"..., "--console", "UpdateGeometry.py", "20.83", "114.9", "8.3"], 0x7ffcc7d7cf20 /* 82 vars */) = 0
strace: Process 1899166 attached
strace: Process 1899167 attached
[pid 1899167] execve("/bin/fusermount", ["fusermount", "-o", "ro,nosuid,nodev,subtype=FreeCAD-"..., "--", "/tmp/.mount_FreeCAxufSgv"], 0x1b01f40 /* 83 vars */) = 0
[pid 1899167] +++ exited with 1 +++
[pid 1899166] --- SIGCHLD {si_signo=SIGCHLD, si_code=CLD_EXITED, si_pid=1899167, si_uid=1010, si_status=1, si_utime=0, si_stime=0} ---
strace: Process 1899168 attached
[pid 1899168] execve("/bin/fusermount", ["fusermount", "-o", "ro,nosuid,nodev", "--", "/tmp/.mount_FreeCAxufSgv"], 0x1b01f40 /* 83 vars */) = 0
fusermount: mount failed: Operation not permitted
[pid 1899168] +++ exited with 1 +++
[pid 1899166] --- SIGCHLD {si_signo=SIGCHLD, si_code=CLD_EXITED, si_pid=1899168, si_uid=1010, si_status=1, si_utime=0, si_stime=0} ---

Cannot mount AppImage, please check your FUSE setup.
You might still be able to extract the contents of this AppImage 
if you run it with the --appimage-extract option. 
See https://github.com/AppImage/AppImageKit/wiki/FUSE 
for more information
[pid 1899166] +++ exited with 0 +++
--- SIGCHLD {si_signo=SIGCHLD, si_code=CLD_EXITED, si_pid=1899166, si_uid=1010, si_status=0, si_utime=0, si_stime=0} ---
open dir error: No such file or directory
+++ exited with 127 +++

By Greg Vernon via Discussions on Python.org at 07Aug2022 01:45:

It executes just as it does from within the Python REPL:

(conda_deps)greg /path/to/my/cwd $ /home/greg/FreeCAD/FreeCAD-0.20.0-Linux-x86_64.AppImage --console UpdateGeometry.py 20.83 114.9 8.3
Importing project files......
Postprocessing......                            (100 %)
Opened Model
Recompute......                                 (100 %)
                                               (89 Updated Model
Exported Part
Closed Model                                    (100 %)
(conda_deps)greg /path/to/my/cwd $

Hmm.

Please do not randomly chmod 777 anything. It is almost always the
wrong thing to do.

I’m on a safe system, temporarily chmoded to 777 to make sure it wasn’t some wierd permission inheritance.

Ok. Plenty of people do it willy nilly, glad to see you’re aware of the
context.

Try executing the command directly from the UNIX shell. I’d expact that
to fail the same way. If it fails, you can possibly see why by
running [ … ] which may show you the actual underlying OS error.

(conda_deps)greg /path/to/my/cwd $ strace -f -e trace=execve /home/greg/FreeCAD/FreeCAD-0.20.0-Linux-x86_64.AppImage --console UpdateGeometry.py 20.83 114.9 8.3
execve("/home/greg/FreeCAD/FreeCAD-0.20.0-Linux-x86_64.AppImage", ["/home/greg/FreeCAD/FreeCAD-0"..., "--console", "UpdateGeometry.py", "20.83", "114.9", "8.3"], 0x7ffcc7d7cf20 /* 82 vars */) = 0
strace: Process 1899166 attached
strace: Process 1899167 attached
[pid 1899167] execve("/bin/fusermount", ["fusermount", "-o", "ro,nosuid,nodev,subtype=FreeCAD-"..., "--", "/tmp/.mount_FreeCAxufSgv"], 0x1b01f40 /* 83 vars */) = 0
[pid 1899167] +++ exited with 1 +++
[pid 1899166] --- SIGCHLD {si_signo=SIGCHLD, si_code=CLD_EXITED, si_pid=1899167, si_uid=1010, si_status=1, si_utime=0, si_stime=0} ---
strace: Process 1899168 attached
[pid 1899168] execve("/bin/fusermount", ["fusermount", "-o", "ro,nosuid,nodev", "--", "/tmp/.mount_FreeCAxufSgv"], 0x1b01f40 /* 83 vars */) = 0
fusermount: mount failed: Operation not permitted
[pid 1899168] +++ exited with 1 +++
[pid 1899166] --- SIGCHLD {si_signo=SIGCHLD, si_code=CLD_EXITED, si_pid=1899168, si_uid=1010, si_status=1, si_utime=0, si_stime=0} ---

Cannot mount AppImage, please check your FUSE setup.
You might still be able to extract the contents of this AppImage
if you run it with the --appimage-extract option.
See https://github.com/AppImage/AppImageKit/wiki/FUSE
for more information
[pid 1899166] +++ exited with 0 +++
--- SIGCHLD {si_signo=SIGCHLD, si_code=CLD_EXITED, si_pid=1899166, si_uid=1010, si_status=0, si_utime=0, si_stime=0} ---
open dir error: No such file or directory
+++ exited with 127 +++

It looks like, under strace, a FUSE mount failed. Whereas it looks
like it went ok without strace. Odd. Notice this final error message:

open dir error: No such file or directory
+++ exited with 127 +++

with your 127 exit code.

See if using -e trace=execve,opendir shows you the directory open
which failed (I’d guess the directory which should have come from the
failed mount, but it might be something else). If that’s uninformative,
drop the -e option altogether - you’ll get a lot output, which is why
I suggested -e to start with.

I’ve never investigated how app images work - I’ve kind of assumed they
mount a self contained directory tree containing the app on the fly
(thus obviating some kind of “install” stage for the app). But I don’t
know.

Cheers,
Cameron Simpson cs@cskk.id.au