Failed to open pipe in plugin clnrest

[nolash]

Issue and Steps to Reproduce

Version 23.08 when running with clnrest:

2024-11-23T19:27:45.116Z DEBUG   plugin-manager: started(3952) /home/lash/src/lightning/build/libexec/c-lightning/plugins/commando
2024-11-23T19:27:45.121Z DEBUG   plugin-manager: started(3953) /home/lash/src/lightning/build/libexec/c-lightning/plugins/fetchinvoice
2024-11-23T19:27:45.127Z DEBUG   plugin-manager: started(3954) /home/lash/src/lightning/build/libexec/c-lightning/plugins/funder
2024-11-23T19:27:45.131Z DEBUG   plugin-manager: started(3955) /home/lash/src/lightning/build/libexec/c-lightning/plugins/topology
2024-11-23T19:27:45.137Z DEBUG   plugin-manager: started(3956) /home/lash/src/lightning/build/libexec/c-lightning/plugins/keysend
2024-11-23T19:27:45.142Z DEBUG   plugin-manager: started(3957) /home/lash/src/lightning/build/libexec/c-lightning/plugins/offers
2024-11-23T19:27:45.148Z DEBUG   plugin-manager: started(3958) /home/lash/src/lightning/build/libexec/c-lightning/plugins/pay
2024-11-23T19:27:45.153Z DEBUG   plugin-manager: started(3959) /home/lash/src/lightning/build/libexec/c-lightning/plugins/txprepare
2024-11-23T19:27:45.158Z DEBUG   plugin-manager: started(3960) /home/lash/src/lightning/build/libexec/c-lightning/plugins/cln-renepay
2024-11-23T19:27:45.163Z DEBUG   plugin-manager: started(3961) /home/lash/src/lightning/build/libexec/c-lightning/plugins/spenderp
2024-11-23T19:27:45.170Z DEBUG   plugin-manager: started(3962) /home/lash/src/lightning/build/libexec/c-lightning/plugins/sql
2024-11-23T19:27:45.174Z DEBUG   plugin-manager: started(3963) /home/lash/src/lightning/build/libexec/c-lightning/plugins/bookkeeper
2024-11-23T19:27:45.180Z DEBUG   plugin-manager: started(3964) /home/lash/src/lightning/build/libexec/c-lightning/plugins/clnrest/clnrest.py
error starting plugin '/home/lash/src/lightning/build/libexec/c-lightning/plugins/clnrest': opening pipe: Permission denied
(.venv) lash@maestoso:~$ Traceback (most recent call last):
  File "/home/lash/src/lightning/build/libexec/c-lightning/plugins/clnrest/clnrest.py", line 23, in <module>
    getmanifest = json.loads(sys.stdin.readline())
  File "/usr/lib/python3.7/json/__init__.py", line 348, in loads
    return _default_decoder.decode(s)
  File "/usr/lib/python3.7/json/decoder.py", line 337, in decode
    obj, end = self.raw_decode(s, idx=_w(s, 0).end())
  File "/usr/lib/python3.7/json/decoder.py", line 355, in raw_decode
    raise JSONDecodeError("Expecting value", s, err.value) from None
json.decoder.JSONDecodeError: Expecting value: line 1 column 1 (char 0)

python environment:

$ pip freeze
aniso8601==9.0.1
asn1crypto==1.5.1
attrs==22.1.0
backports.cached-property==1.0.2
base58==2.1.1
bidict==0.22.1
bitstring==3.1.9
CacheControl==0.12.12
cachy==0.3.0
certifi==2022.9.24
cffi==1.15.1
charset-normalizer==2.1.1
cleo==1.0.0a5
click==8.1.7
coincurve==18.0.0
crashtest==0.3.1
cryptography==41.0.7
distlib==0.3.6
dulwich==0.20.46
filelock==3.8.0
Flask==2.2.5
Flask-Cors==5.0.0
flask-restx==1.3.0
Flask-SocketIO==5.4.1
gevent==22.10.2
gevent-websocket==0.10.1
greenlet==3.1.1
gunicorn==23.0.0
h11==0.14.0
html5lib==1.1
idna==3.4
importlib-metadata==4.13.0
importlib-resources==5.10.0
itsdangerous==2.1.2
jaraco.classes==3.2.3
jeepney==0.8.0
Jinja2==3.1.4
json5==0.9.16
jsonschema==4.16.0
keyring==23.9.3
Mako==1.2.3
MarkupSafe==2.1.1
more-itertools==9.0.0
msgpack==1.0.4
packaging==21.3
pexpect==4.8.0
pkg_resources==0.0.0
pkginfo==1.8.3
pkgutil_resolve_name==1.3.10
platformdirs==2.5.2
poetry==1.2.2
poetry-core==1.3.2
poetry-plugin-export==1.1.2
ptyprocess==0.7.0
pycparser==2.21
pylev==1.4.0
pyln-bolt7==1.0.246
pyln-client==23.5.2
pyln-proto==23.5.2
pyparsing==3.0.9
pyrsistent==0.18.1
PySocks==1.7.1
python-engineio==4.10.1
python-socketio==5.11.0
pytz==2024.2
requests==2.28.1
requests-toolbelt==0.9.1
SecretStorage==3.3.3
shellingham==1.5.0
simple-websocket==1.1.0
six==1.16.0
tomlkit==0.11.5
typing_extensions==4.4.0est interface
urllib3==1.26.12
virtualenv==20.16.5
webencodings==0.5.1
Werkzeug==2.2.3
wsproto==1.2.0
zipp==3.9.0
zope.event==5.0
zope.interface==6.4.post2

getinfo output

... cant start node

[nolash]

Doesn't work with 3.7. Changed to 3.8. Now getting:

$ ./build/bin/lightning-cli -k plugin subcommand=start plugin=/home/lash/src/lightning/build/libexec/c-lightning/plugins/clnrest rest-port=3010
{
   "code": -3,
   "message": "/home/lash/src/lightning/build/libexec/c-lightning/plugins/clnrest: opening pipe: Permission denied"
}

starting the plugin with lightningd with strace:

openat(AT_FDCWD, "/proc/29600/fd", O_RDONLY|O_NONBLOCK|O_CLOEXEC|O_DIRECTORY) = 3
fstat(3, {st_mode=S_IFDIR|0500, st_size=0, ...}) = 0
brk(0x56133a3c7000)                     = 0x56133a3c7000
brk(0x56133a3bf000)                     = 0x56133a3bf000
close(3)                                = 0
getpid()                                = 29600
pipe([3, 4])                            = 0
fcntl(4, F_GETFL)                       = 0x1 (flags O_WRONLY) 
fcntl(4, F_SETFL, O_WRONLY|O_NONBLOCK)  = 0
rt_sigaction(SIGCHLD, {sa_handler=0x561339dcac53, sa_mask=[], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x7f7ee2e7a840}, NULL, 8) = 0

[...]

lstat("/home/lash/src/lightning/build/libexec/c-lightning/plugins/clnrest/clnrest.py", {st_mode=S_IFREG|0755, st_size=6128, ...}) = 0
openat(AT_FDCWD, "/home/lash/src/lightning/build/libexec/c-lightning/plugins/clnrest/clnrest.py", O_RDONLY) = 5
fstat(5, {st_mode=S_IFREG|0755, st_size=6128, ...}) = 0
read(5, "#!/usr/bin/env python3\n# For --h"..., 6128) = 6128
read(5, "", 6128)                       = 0 
close(5)                                = 0

[...]

fcntl(35, F_GETFL)                      = 0 (flags O_RDONLY)
fcntl(35, F_SETFL, O_RDONLY|O_NONBLOCK) = 0
fcntl(34, F_GETFL)                      = 0x1 (flags O_WRONLY)
fcntl(34, F_SETFL, O_WRONLY|O_NONBLOCK) = 0
pipe([5, 36])                           = 0
pipe([37, 38])                          = 0
pipe([39, 40])                          = 0
fcntl(40, F_GETFD)                      = 0
fcntl(40, F_SETFD, FD_CLOEXEC)          = 0
clone(child_stack=NULL, flags=CLONE_CHILD_CLEARTID|CLONE_CHILD_SETTID|SIGCHLD, child_tidptr=0x7f7ee20e5c50) = 29616
close(5)                                = 0
close(38)                               = 0
close(40)                               = 0
read(39, "", 4)                         = 0
close(39)                               = 0
write(1, "2024-11-24T00:36:14.065Z DEBUG  "..., 1422024-11-24T00:36:14.065Z DEBUG   plugin-manager: started(29616) /home/lash/src/lightning/build/libexec/c-lightning/plugins/clnrest/clnrest.py
) = 142
fcntl(37, F_GETFL)                      = 0 (flags O_RDONLY)
fcntl(37, F_SETFL, O_RDONLY|O_NONBLOCK) = 0
fcntl(36, F_GETFL)                      = 0x1 (flags O_WRONLY)
fcntl(36, F_SETFL, O_WRONLY|O_NONBLOCK) = 0
pipe([5, 38])                           = 0
pipe([39, 40])                          = 0
pipe([41, 42])                          = 0
fcntl(42, F_GETFD)                      = 0
fcntl(42, F_SETFD, FD_CLOEXEC)          = 0
clone(child_stack=NULL, flags=CLONE_CHILD_CLEARTID|CLONE_CHILD_SETTID|SIGCHLD, child_tidptr=0x7f7ee20e5c50) = 29617
close(5)                                = 0
close(40)                               = 0
close(42)                               = 0
read(41, "\r\0\0\0", 4)                 = 4
close(41)                               = 0
wait4(29617, NULL, 0, NULL)             = 29617
--- SIGCHLD {si_signo=SIGCHLD, si_code=CLD_EXITED, si_pid=29617, si_uid=1000, si_status=127, si_utime=0, si_stime=0} ---
write(4, "\0", 1)                       = 1
rt_sigreturn({mask=[]})                 = 29617
write(2, "error starting plugin '/home/las"..., 123error starting plugin '/home/lash/src/lightning/build/libexec/c-lightning/plugins/clnrest': opening pipe: Permission denied) = 123
write(2, "\n", 1
)                       = 1
exit_group(1)                           = ?
+++ exited with 1 +++

[nolash]

same problem in 24.05

[rustyrussell]

Hmm, this strace doesn't show the failure, as it's in the Python code. If you run /home/lash/src/lightning/build/libexec/c-lightning/plugins/clnrest manually, does it work?