pyrotorque in detach mode exits during startup

[Aqualie]

When running pyrotorque in default daemon/detached mode it simply just exits and doesn't start:

rtorrent [ / ]$ pyrotorque --debug --verbose
INFO:pyrosimple.scripts.pyrotorque.RtorrentQueueManager:Writing pid to <TimeoutPIDLockFile: PosixPath('/opt/rtorrent/.pyrosimple/run/pyrotorque.pid') -- PosixPath('/opt/rtorrent/.pyrosimple/run/pyrotorque.pid')> and detaching process...
INFO:pyrosimple.scripts.pyrotorque.RtorrentQueueManager:Logging stderr/stdout to None
rtorrent [ / ]$ pyrotorque --status
ERROR:pyrosimple.scripts.pyrotorque.RtorrentQueueManager:No pyrotorque process found.
rtorrent [ / ]$ ps -a
    PID TTY          TIME CMD
     54 pts/1    00:00:00 bash
     59 pts/1    00:03:10 rtorrent main
     99 pts/2    00:00:00 ps
rtorrent [ / ]$

--- SIGCHLD {si_signo=SIGCHLD, si_code=CLD_EXITED, si_pid=90, si_uid=1001, si_status=0, si_utime=0, si_stime=0} ---
newfstatat(4, "", {st_mode=S_IFIFO|0600, st_size=0, ...}, AT_EMPTY_PATH) = 0
read(4, "139 libs found in cache `/etc/ld"..., 8192) = 8192
read(4, "g (GNU libc) stable release vers"..., 8448) = 41
read(4, "", 8407)                       = 0
close(4)                                = 0
wait4(90, [{WIFEXITED(s) && WEXITSTATUS(s) == 0}], 0, NULL) = 90
uname({sysname="Linux", nodename="b382caa8a5d2", ...}) = 0
getpid()                                = 89
getuid()                                = 1001
getgid()                                = 1002
getpid()                                = 89
write(2, "INFO:pyrosimple.scripts.pyrotorq"..., 237INFO:pyrosimple.scripts.pyrotorque.RtorrentQueueManager:Writing pid to <TimeoutPIDLockFile: PosixPath('/opt/rtorrent/.pyrosimple/run/pyrotorque.pid') -- PosixPath('/opt/rtorrent/.pyrosimple/run/pyrotorque.pid')> and detaching process...
) = 237
getpid()                                = 89
write(2, "INFO:pyrosimple.scripts.pyrotorq"..., 86INFO:pyrosimple.scripts.pyrotorque.RtorrentQueueManager:Logging stderr/stdout to None
) = 86
prlimit64(0, RLIMIT_CORE, NULL, {rlim_cur=RLIM64_INFINITY, rlim_max=RLIM64_INFINITY}) = 0
prlimit64(0, RLIMIT_CORE, {rlim_cur=0, rlim_max=0}, NULL) = 0
umask(000)                              = 022
chdir("/")                              = 0
socket(AF_UNIX, SOCK_STREAM|SOCK_CLOEXEC|SOCK_NONBLOCK, 0) = 3
connect(3, {sa_family=AF_UNIX, sun_path="/var/run/nscd/socket"}, 110) = -1 ENOENT (No such file or directory)
close(3)                                = 0
socket(AF_UNIX, SOCK_STREAM|SOCK_CLOEXEC|SOCK_NONBLOCK, 0) = 3
connect(3, {sa_family=AF_UNIX, sun_path="/var/run/nscd/socket"}, 110) = -1 ENOENT (No such file or directory)
close(3)                                = 0
newfstatat(AT_FDCWD, "/etc/nsswitch.conf", {st_mode=S_IFREG|0644, st_size=199, ...}, 0) = 0
newfstatat(AT_FDCWD, "/", {st_mode=S_IFDIR|0755, st_size=4096, ...}, 0) = 0
openat(AT_FDCWD, "/etc/nsswitch.conf", O_RDONLY|O_CLOEXEC) = 3
newfstatat(3, "", {st_mode=S_IFREG|0644, st_size=199, ...}, AT_EMPTY_PATH) = 0
read(3, "#       Begin /etc/nsswitch.conf"..., 4096) = 199
read(3, "", 4096)                       = 0
newfstatat(3, "", {st_mode=S_IFREG|0644, st_size=199, ...}, AT_EMPTY_PATH) = 0
close(3)                                = 0
openat(AT_FDCWD, "/etc/passwd", O_RDONLY|O_CLOEXEC) = 3
newfstatat(3, "", {st_mode=S_IFREG|0644, st_size=759, ...}, AT_EMPTY_PATH) = 0
lseek(3, 0, SEEK_SET)                   = 0
read(3, "root:x:0:0:root:/root:/bin/bash\n"..., 4096) = 759
close(3)                                = 0
setgid(1002)                            = 0
setuid(1001)                            = 0
clone(child_stack=NULL, flags=CLONE_CHILD_CLEARTID|CLONE_CHILD_SETTID|SIGCHLD, child_tidptr=0x7f222c17da10) = 91
exit_group(0)                           = ?
+++ exited with 0 +++

working in FG mode

rtorrent [ / ]$ pyrotorque --debug --verbose --fg
/opt/rtorrent/.local/lib/python3.11/site-packages/tzlocal/unix.py:192: UserWarning: Can not find any timezone configuration, defaulting to UTC.
  warnings.warn("Can not find any timezone configuration, defaulting to UTC.")
2023-07-15 16:35:18,956  INFO pyrosimple.pyrotorque.jobs.queue: Startable matcher is: is_ignored=0 done=0 message="" prio>0
2023-07-15 16:35:18,956  INFO pyrosimple.pyrotorque.jobs.queue: Downloading matcher is: OrNode["AndNode['BoolFilter', 'BoolFilter']"]

[kannibalox]

Can you check for me that /opt/rtorrent/.pyrosimple/run/pyrotorque.pid is writeable by the process? It looks like that can make it fail silently currently.

[Aqualie]

?  ~ pyrotorque
?  ~ pyrotorque --status
ERROR:pyrosimple.scripts.pyrotorque.RtorrentQueueManager:No pyrotorque process found.
?  ~ ls -lha /opt/rtorrent/.pyrosimple/run/
total 12K
drwxr-xr-x 1 rtorrent rtorrent 4.0K Jul 15 18:34 .
drwxr-xr-x 1 rtorrent rtorrent 4.0K Jul 15 18:33 ..
?  ~ touch /opt/rtorrent/.pyrosimple/run/123
?  ~ ls -lha /opt/rtorrent/.pyrosimple/run/
total 12K
drwxr-xr-x 1 rtorrent rtorrent 4.0K Jul 15 18:34 .
drwxr-xr-x 1 rtorrent rtorrent 4.0K Jul 15 18:33 ..
-rw-r----- 1 rtorrent rtorrent    0 Jul 15 18:34 123
?  ~

I presume it would be running as the same user I'm running the command as?

[kannibalox]

Correct, you can actually see it in the strace:

setgid(1002)                            = 0
setuid(1001)                            = 0

Can you try the latest code for me?

pip install -U https://github.com/kannibalox/pyrosimple/archive/refs/heads/main.tar.gz

I've added a more generic lockfile test prior to forking, and if that doesn't turn anything up, try the new --log-file <path> flag to set the stdout/stderr to a specific file.

[Aqualie]

Seems better now but failing on the rtorrent connection for some reason:

rtorrent [ ~ ]$ pyrotorque --debug --verbose --log-file /opt/rtorrent/pryotorque.log
INFO:pyrosimple.scripts.pyrotorque.RtorrentQueueManager:Writing pid to /opt/rtorrent/.pyrosimple/run/pyrotorque.pid and detaching process...
INFO:pyrosimple.scripts.pyrotorque.RtorrentQueueManager:Logging stderr/stdout to <_io.TextIOWrapper name='/opt/rtorrent/pryotorque.log' mode='w' encoding='UTF-8'>
rtorrent [ ~ ]$ cd^C
rtorrent [ ~ ]$ ps -a
    PID TTY          TIME CMD
     59 pts/1    00:00:00 bash
     64 pts/1    00:03:28 rtorrent main
     91 pts/2    00:00:00 ps
rtorrent [ ~ ]$ cat pyrotorque.log
/opt/rtorrent/.local/lib/python3.11/site-packages/tzlocal/unix.py:192: UserWarning: Can not find any timezone configuration, defaulting to UTC.
  warnings.warn("Can not find any timezone configuration, defaulting to UTC.")
Traceback (most recent call last):
  File "/opt/rtorrent/.local/bin/pyrotorque", line 8, in <module>
    sys.exit(run())
             ^^^^^
  File "/opt/rtorrent/.local/lib/python3.11/site-packages/pyrosimple/scripts/pyrotorque.py", line 292, in run
    RtorrentQueueManager().run()
  File "/opt/rtorrent/.local/lib/python3.11/site-packages/pyrosimple/scripts/base.py", line 177, in run
    self.mainloop()
  File "/opt/rtorrent/.local/lib/python3.11/site-packages/pyrosimple/scripts/pyrotorque.py", line 284, in mainloop
    self.add_jobs()
  File "/opt/rtorrent/.local/lib/python3.11/site-packages/pyrosimple/scripts/pyrotorque.py", line 122, in add_jobs
    self.classes[name] = params["__handler"](params)
                         ^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/rtorrent/.local/lib/python3.11/site-packages/pyrosimple/job/watch.py", line 50, in __init__
    self.engine.open()
  File "/opt/rtorrent/.local/lib/python3.11/site-packages/pyrosimple/torrent/rtorrent.py", line 698, in open
    self.properties = self.system_multicall(
                      ^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/rtorrent/.local/lib/python3.11/site-packages/pyrosimple/torrent/rtorrent.py", line 678, in system_multicall
    for index, r in enumerate(self.rpc.system.multicall(call)):
                              ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.11/xmlrpc/client.py", line 1122, in __call__
    return self.__send(self.__name, args)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/rtorrent/.local/lib/python3.11/site-packages/pyrosimple/util/rpc.py", line 244, in __request
    return self.__request_switch(methodname, params)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/rtorrent/.local/lib/python3.11/site-packages/pyrosimple/util/rpc.py", line 258, in __request_switch
    return self.__request_xml(methodname, params)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/rtorrent/.local/lib/python3.11/site-packages/pyrosimple/util/rpc.py", line 137, in __request_xml
    response = self.__transport.request(
               ^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/rtorrent/.local/lib/python3.11/site-packages/pyrosimple/io/scgi.py", line 136, in request
    sock.connect(target)
FileNotFoundError: [Errno 2] No such file or directory

[kannibalox]

And yet it's working fine when run in the foreground, or via simple rtxmlrpc commands? The pyrocore.job.watch:TreeWatch job is a little special in that it's one of the few ones that actually needs to check if rtorrent is running on initialization, but other than that it shouldn't connect differently in a backgrounded pyrotorque than any other setup.

Also specifying --debug --verbose in that order will make "verbose" override "debug". Just --debug will get you both levels.

[Aqualie]

Yes that's right when running in FG mode it works just fine:

rtorrent [ ~ ]$ pyrotorque --debug --fg
DEBUG:pyrosimple.scripts.pyrotorque.RtorrentQueueManager:Options: dry_run=False, log_file=None, log_level=10, no_fork=True, pid_file=PosixPath('~/.pyrosimple/run/pyrotorque.pid'), print_completion=None, restart=False, run_once=None, status=False, stop=False, url=None
DEBUG:pyrosimple.config:Configuration file '/opt/rtorrent/.config/pyrosimple/config.py' not found.
/opt/rtorrent/.local/lib/python3.11/site-packages/tzlocal/unix.py:192: UserWarning: Can not find any timezone configuration, defaulting to UTC.
  warnings.warn("Can not find any timezone configuration, defaulting to UTC.")
2023-07-15 23:55:18,270 DEBUG pyrosimple.config: Loading rtorrent config from '/opt/rtorrent/.rtorrent.rc'
2023-07-15 23:55:18,271 DEBUG pyrosimple.config: rtorrent.rc: network.scgi.open_local = /opt/rtorrent/.scgi_local
2023-07-15 23:55:18,271 DEBUG pyrosimple.pyrotorque.jobs.queue: pyrosimple.job.base:queue created with config {'handler': 'pyrocore.job.queue:QueueManager', 'schedule': {'second': '*/15'}, 'active': True, 'dry_run': False, 'sort_fields': '-prio,loaded,name', 'downloading_min': 1, 'downloading_max': 9, 'start_at_once': 4, 'intermission': 0, 'startable': 'is_ignored=0 done=0 message="" prio>0', '__handler': <class 'pyrosimple.job.queue.QueueManager'>, '__job_name': 'queue', 'matcher': 'is_ignored=0 done=0 message="" prio>0', 'sort': '-prio,loaded,name'}
2023-07-15 23:55:18,272 DEBUG pyrosimple.torrent.rtorrent: Validated key names: -prio, loaded, name
2023-07-15 23:55:18,272  INFO pyrosimple.pyrotorque.jobs.queue: Startable matcher is: is_ignored=0 done=0 message="" prio>0
2023-07-15 23:55:18,272  INFO pyrosimple.pyrotorque.jobs.queue: Downloading matcher is: OrNode["AndNode['BoolFilter', 'BoolFilter']"]
2023-07-15 23:55:18,370 DEBUG pyrosimple.pyrotorque.jobs.stats: pyrosimple.job.base:stats created with config {'handler': 'pyrocore.job.metrics:EngineStats', 'schedule': {'minute': '*'}, 'active': True, 'dry_run': False, '__handler': <class 'pyrosimple.job.metrics.EngineStats'>, '__job_name': 'stats'}
2023-07-15 23:55:18,370 DEBUG pyrosimple.pyrotorque.jobs.watch: pyrosimple.job.base:watch created with config {'handler': 'pyrocore.job.watch:TreeWatch', 'schedule': {'second': '*/5'}, 'active': True, 'dry_run': False, 'load_mode': 'start', 'cmd_queue': 'd.priority.set=0', 'path': '/media/tmp/watch/start', '__handler': <class 'pyrosimple.job.watch.TreeWatch'>, '__job_name': 'watch'}
2023-07-15 23:55:18,370 DEBUG pyrosimple.util.rpc: method 'system.multicall', params ([{'methodName': 'system.client_version', 'params': []}, {'methodName': 'system.library_version', 'params': []}, {'methodName': 'system.time_usec', 'params': []}, {'methodName': 'session.name', 'params': []}, {'methodName': 'directory.default', 'params': []}, {'methodName': 'session.path', 'params': []}],)
2023-07-15 23:55:18,371 DEBUG pyrosimple.util.rpc: method 'startup_time', params ()
2023-07-15 23:55:18,372 DEBUG pyrosimple.torrent.rtorrent.RtorrentEngine: RtorrentEngine connected to localhost:64 [rTorrent 0.13.8/0.9.8] via 'scgi+unix:///opt/rtorrent/.scgi_local'

Strange after this I ran it again and now it appears to be already working:

rtorrent [ ~ ]$ pyrotorque --debug --log-file /opt/rtorrent/pryotorque.log
DEBUG:pyrosimple.scripts.pyrotorque.RtorrentQueueManager:Options: dry_run=False, log_file=PosixPath('/opt/rtorrent/pryotorque.log'), log_level=10, no_fork=False, pid_file=PosixPath('~/.pyrosimple/run/pyrotorque.pid'), print_completion=None, restart=False, run_once=None, status=False, stop=False, url=None
DEBUG:pyrosimple.config:Configuration file '/opt/rtorrent/.config/pyrosimple/config.py' not found.
ERROR:pyrosimple.scripts.pyrotorque.RtorrentQueueManager:Cannot lock pidfile: /opt/rtorrent/.pyrosimple/run/pyrotorque.pid is already locked
INFO:pyrosimple.scripts.pyrotorque.RtorrentQueueManager:Total time: 0.235 seconds.
rtorrent [ ~ ]$ pyrotorque --status --debug
DEBUG:pyrosimple.scripts.pyrotorque.RtorrentQueueManager:Options: dry_run=False, log_file=None, log_level=10, no_fork=False, pid_file=PosixPath('~/.pyrosimple/run/pyrotorque.pid'), print_completion=None, restart=False, run_once=None, status=True, stop=False, url=None
DEBUG:pyrosimple.config:Configuration file '/opt/rtorrent/.config/pyrosimple/config.py' not found.
INFO:pyrosimple.scripts.pyrotorque.RtorrentQueueManager:Pyrotorque is running (PID 87).
INFO:pyrosimple.scripts.pyrotorque.RtorrentQueueManager:Total time: 0.186 seconds.
rtorrent [ ~ ]$ ps -A | grep pyrotorque
     87 ?        00:04:36 pyrotorque

[kannibalox]

Sorry, but it's not clear to me, are all your problems resolved now?

[Aqualie]

Hi I tested restarting the container and found the pyrotorque.pid file still existed so it prevented it from starting again.

ERROR:pyrosimple.scripts.pyrotorque.RtorrentQueueManager:Cannot lock pidfile: /opt/rtorrent/.pyrosimple/run/pyrotorque.pid is already locked

I guess I can just add a simple delete file command prior to lauching pyrotorque

[Aqualie]

I just added a simple clean-up script before starting pyrotorque does the trick.

[kannibalox]

I'm still doing some testing/other work so it's not released yet, but I've also added a --adopt-stale-pid-file flag for pyrotorque