rc.local에서 실행된 Python 스크립트는 0이 아닌 코드가 사용되지 않는 한 기록되지 않습니다.

내 rc.local서비스는 시작 시 Python 스크립트를 실행합니다. 제대로 작동하지만 오류가 발생하여 0이 아닌 코드로 종료되지 않는 한 어디에도 기록되지 않습니다. 스크립트는 예약된 작업을 실행하므로 오류가 발생하거나 수동으로 중지되지 않는 한 백그라운드에서 중단됩니다.

내 rc.local은 다음과 같습니다.

#!/bin/sh -e
#
# rc.local
#
# This script is executed at the end of each multiuser runlevel.
# Make sure that the script will "exit 0" on success or any other
# value on error.
#
# In order to enable or disable this script just change the execution
# bits.
#
# By default this script does nothing.


cd /root/path/to/script
/root/path/to/script/venv/bin/python /root/path/to/script/main.py &
exit 0

syslog파일을 확인했지만 cat /var/log/syslog | grep rc.local스레드가 시작되거나 중지될 때만 기록됩니다(정보와 동일 systemctl status rc-local.service).

Mar 28 12:49:07 machine-hostname systemd[1]: Starting /etc/rc.local Compatibility...
Mar 28 12:49:07 machine-hostname systemd[1]: Started /etc/rc.local Compatibility.

Python 스크립트를 재정의하여 출력을 외부 파일로 리디렉션하려고 시도했지만 stdout작동하지 않았습니다. 다양한 필수 Python 종속성(예: requests또는 schedule) 설치를 피하기 위해 가상 환경을 사용하고 있습니다. 이것이 문제의 원인이 될 수 있습니까? 저는 Python과 Linux 세계를 처음 접했기 때문에 구성 오류가 있을 수 있습니다.

openvpn추신: Python 스크립트가 내부적으로 명령을 실행하고 스크립트 실행 폴더에 구성 파일이 필요하기 때문에 스크립트 실행 폴더로 이동해야 합니다 . 다음은 systemctl status rc-local.service명령 출력의 예입니다.

● rc-local.service - /etc/rc.local Compatibility
   Loaded: loaded (/lib/systemd/system/rc-local.service; enabled-runtime; vendor preset: enabled)
  Drop-In: /lib/systemd/system/rc-local.service.d
           └─debian.conf
   Active: active (running) since Sun 2021-03-28 12:49:07 CEST; 1h 32min ago
     Docs: man:systemd-rc-local-generator(8)
  Process: 10033 ExecStart=/etc/rc.local start (code=exited, status=0/SUCCESS)
    Tasks: 2 (limit: 4915)
   CGroup: /system.slice/rc-local.service
           ├─10038 /root/path/to/script/venv/bin/python /root/path/to/script/main.py
           └─10068 openvpn configuration-file.ovpn

mar 28 12:49:07 machine-hostname systemd[1]: Starting /etc/rc.local Compatibility...
mar 28 12:49:07 machine-hostname systemd[1]: Started /etc/rc.local Compatibility.

다음은 스크립트 조각입니다.

import requests
import os
import subprocess
import shutil
import fileinput
import schedule
import time
from urllib.request import urlopen


# global variables declaration
...

# functions declaration
...


if __name__ == '__main__':
    print('Starting VPN connection...')
    server_list = get_server_list(max_servers_limit) # calls a public api
    connect(server_list) # executes openvpn command

    print('Scheduling VPN connection change every {} hours'.format(change_vpn_every_hours))
    schedule.every(change_vpn_every_hours).hours.do(change_vpn_connection)

    print('Scheduling internet connection checking every {} minutes'.format(check_internet_connection_minutes))
    schedule.every(check_internet_connection_minutes).minutes.do(check_internet_connection)
    while True:
        schedule.run_pending()
        time.sleep(1)

고쳐 쓰다: 종료 코드를 반환하여 실행을 종료할 때가 아니라 VPN 연결을 변경할 때와 같이 거의 "무작위로" 기록되거나 특정 상황에서 기록되는 것 같습니다. 다음은 journalctl -u rc-local.service명령의 출력입니다(내 설명은 "로 시작합니다. # 정확히 무슨 일이 일어났는지 설명하기 위해 "##으로 시작":

-- Reboot --
mar 28 20:59:27 machine-hostname systemd[1]: Starting /etc/rc.local Compatibility...
mar 28 20:59:27 machine-hostname systemd[1]: Started /etc/rc.local Compatibility.
mar 29 03:05:14 machine-hostname rc.local[1063]: Starting VPN connection: connecting to [...]   ### This was happened at 20:59:27, when the script execution started
mar 29 03:05:14 machine-hostname rc.local[1063]: Searching configuration file of server with hostname XXX
mar 29 03:05:14 machine-hostname rc.local[1063]: Found server with hostname XXX
mar 29 03:05:14 machine-hostname rc.local[1063]: IP address: XXX
mar 29 03:05:14 machine-hostname rc.local[1063]: Load: 23
mar 29 03:05:14 machine-hostname rc.local[1063]: Country: Italy, City: Milan
mar 29 03:05:14 machine-hostname rc.local[1063]: Latitude: XX.X, Longitude: X.X
mar 29 03:05:14 machine-hostname rc.local[1063]: Launching openvpn...
mar 29 03:05:14 machine-hostname rc.local[1063]: ###### [COMMAND OUTPUT] ######
mar 29 03:05:14 machine-hostname rc.local[1063]: Sun Mar 28 20:59:28 2021 OpenVPN 2.4.4 x86_64-pc-linux-gnu [SSL (OpenSSL)] [LZO] [LZ4] [EPOLL] [PKCS11] [MH/PKTINFO] [A
mar 29 03:05:14 machine-hostname rc.local[1063]: Sun Mar 28 20:59:28 2021 library versions: OpenSSL 1.1.1  11 Sep 2018, LZO 2.08
mar 29 03:05:14 machine-hostname rc.local[1063]: [...] 
mar 29 03:05:14 machine-hostname rc.local[1063]: Sun Mar 28 20:59:31 2021 Initialization Sequence Completed
mar 29 03:05:14 machine-hostname rc.local[1063]: ##############################
mar 29 03:05:14 machine-hostname rc.local[1063]: Connected successfully
mar 29 03:05:14 machine-hostname rc.local[1063]: Pid: 1592
mar 29 03:05:14 machine-hostname rc.local[1063]: Scheduling VPN connection change every 12 hours
mar 29 03:05:14 machine-hostname rc.local[1063]: Scheduling internet connection checking every 5 minutes     ### The two schedulers have started
mar 29 03:05:14 machine-hostname rc.local[1063]: Checking internet connection ### This was happened at 21:05, 5 minutes after the execution
mar 29 03:05:14 machine-hostname rc.local[1063]: Internet is up
mar 29 03:05:14 machine-hostname rc.local[1063]: [...]    ### It goes on this way for 12 hours: no connection problem occurred so it hasn't restarted the connection and changed VPN...
mar 29 09:05:57 machine-hostname rc.local[1063]: Checking internet connection
mar 29 09:05:57 machine-hostname rc.local[1063]: Internet is up
mar 29 09:05:57 machine-hostname rc.local[1063]: [SCHEDULER]: Changing VPN connection    ### First change vpn scheduler execution: it really happened at 09:05
mar 29 09:05:57 machine-hostname rc.local[1063]: [SCHEDULER]: Killing process 1592
mar 29 09:05:57 machine-hostname rc.local[1063]: [SCHEDULER]: Restarting network manager
mar 29 09:05:57 machine-hostname rc.local[1063]: [SCHEDULER]: Retrieving server list
mar 29 09:05:57 machine-hostname rc.local[1063]: [SCHEDULER]: Connecting to new server
mar 29 09:05:57 machine-hostname rc.local[1063]: Searching configuration file of server with hostname XXX
mar 29 09:05:57 machine-hostname rc.local[1063]: Found server with hostname XXX
mar 29 09:05:57 machine-hostname rc.local[1063]: [...]    ### Same stuff as before...
mar 29 09:05:57 machine-hostname rc.local[1063]: Connected successfully
mar 29 09:05:57 machine-hostname rc.local[1063]: Pid: 27188
mar 29 09:05:57 machine-hostname rc.local[1063]: Checking internet connection
mar 29 09:05:57 machine-hostname rc.local[1063]: Internet is up
mar 29 09:05:57 machine-hostname rc.local[1063]: Checking internet connection

"무작위"라고 말한 이유는 로그의 시간이 03:05(특별한 일이 없을 때 인터넷이 연결되어 있는지 확인합니다...)와 VPN 연결이 변경되는 09:05에 변경되기 때문입니다. VPN 변경 연결 스케줄러를 다시 트리거할 때 불과 몇 분 전에 기록되었습니다... 제 생각에는 분명히 무작위 로깅이 time.sleep()Python 스크립트의 함수 호출로 인해 발생한 것일 수 있다고 생각합니다(또한 호출된 VPN 연결의 메서드도 변경됨). 전혀 잘 모르겠습니다.