rc.localで実行されたPythonスクリプトは、ゼロ以外のコードが使用されていない限り記録されません。

rc.localで実行されたPythonスクリプトは、ゼロ以外のコードが使用されていない限り記録されません。

私のrc.localサービスは起動時にPythonスクリプトを実行します。正しく動作しますが、エラーが発生してゼロ以外のコードで終了しない限り、どこにも書き込まれません。スクリプトはスケジュールされたジョブを実行するため、エラーが発生した場合や手動で停止しない限り、バックグラウンドで中断されます。

私の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の世界に初めて遭遇したので、設定エラーがあるかもしれません。

openvpnPS: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接続のメソッドも変更されています)。まったくよくわかりません。

ベストアンサー1

次のように出力をログファイルに手動でパイピングしてみましたか? python3 main.py 1> output.log 2> errors.logまたは単にpython3 main.py > everything.log (これを行うには、スクリプトを呼び出すファイルを見つける必要があります)

Pythonコードを読んだ後、print()出力はstdout(ログではありません!)に移動します。 rc.localエントリがない場合は、ログにstdoutを保存する方法がわかりません。

おすすめ記事