結論は、「エラーの内容さえわかるようになれば如何様にもできる」。
今回はcronに関するログの出力について、色々と勉強したのでまとめる。
デバッグは大変だと素人ながらに思い知る毎日。本職の皆様はいつも本当にお疲れ様と声掛けしたいところ。
なお、以下で出てくる「%%conda%%」という文字列は、berrycondaを入れたディレクトリの階層が深かったためそこを短縮する意図で入れている。「絶対参照で指定しているんだなコイツ」くらいで考えていただきたい。
【経緯】
rasspberry pi3でPython3を自動化しようとしているが、これが素人にはなかなか手ごわい。
OSはraspbianで、00時から06時くらいの夜のうちにWebをスクレイピングしてスプレッドシートに特定の要素を書き出す、というようなプログラムを走らせている。
数は約15。raspbianなので、cronを使って自動化設定。
ところがそのうち7つが走らない。残り8つは走ってる。
cronの設定はこんな感じ。
$sudo crontab –l 05 02 * * * %%conda%%/bin/python3 %%conda%%/scripts/crons/script_a_1.py 05 01 * * * %%conda%%/bin/python3 %%conda%%/scripts/crons/script_b_1.py 15 01 * * * %%conda%%/bin/python3 %%conda%%/scripts/crons/script_b_2.py 25 01 * * * %%conda%%/bin/python3 %%conda%%/scripts/crons/script_b_3.py 35 01 * * * %%conda%%/bin/python3 %%conda%%/scripts/crons/script_b_4.py 45 01 * * * %%conda%%/bin/python3 %%conda%%/scripts/crons/script_b_5.py 05 03 * * * %%conda%%/bin/python3 %%conda%%/scripts/crons/script_c_1.py 15 04 * * * %%conda%%/bin/python3 %%conda%%/scripts/crons/script_d_1.py 25 04 * * * %%conda%%/bin/python3 %%conda%%/scripts/crons/script_d_2.py 35 04 * * * %%conda%%/bin/python3 %%conda%%/scripts/crons/script_d_3.py 45 04 * * * %%conda%%/bin/python3 %%conda%%/scripts/crons/script_d_4.py 55 04 * * * %%conda%%/bin/python3 %%conda%%/scripts/crons/script_d_5.py 05 21 * * * %%conda%%/bin/python3 %%conda%%/scripts/crons/script_e_1.py 35 05 * * * %%conda%%/bin/python3 %%conda%%/scripts/crons/script_e_2.pyこの中でエラーが出るのがscript_b_1.py～script_b_5.pyとscript_e_1.py、script_e_2.pyの合計7つ。他は正常に動いているので何が悪いのやら、といったところ。
まずはcron.logを見る
そもそもの問題の切り分けとして、cronが悪いのかpythonが悪いのか自分のコードが悪いのか。
これらの7つのコード自体はVisual Studio Code上からsshで繋いで動かすと、最後まで走る。
そこで、以下サイトを見てcron.logにログを出力するようにしてみた。
cronのログを出すように設定する – もみあげあしめ
にてログを取る設定に変更。そうやってcron.logを見てみると、
$cat /var/log/cron.log Apr 21 01:05:02 pi CRON[1172]: (root) CMD (%%conda%%/bin/python3 %%conda%%/scripts/crons/script_b_1.py) Apr 21 01:15:01 pi CRON[1223]: (root) CMD (%%conda%%/bin/python3 %%conda%%/scripts/crons/script_b_2.py) Apr 21 01:17:01 pi CRON[1271]: (root) CMD (   cd / && run-parts --report /etc/cron.hourly) Apr 21 01:25:01 pi CRON[1290]: (root) CMD (%%conda%%/bin/python3 %%conda%%/scripts/crons/script_b_3.py) Apr 21 01:35:01 pi CRON[1349]: (root) CMD (%%conda%%/bin/python3 %%conda%%/scripts/crons/script_b_4.py) Apr 21 01:45:01 pi CRON[1401]: (root) CMD (%%conda%%/bin/python3 %%conda%%/scripts/crons/script_b_5.py)この通り、cronは実行されているのだ。
ここで実行されていなければ、crontabでcronの設定を見直せばよい。
しかし実行されている。では実行の結果を知らなければならぬ。
もう少しcron.logを詳しく見る
さらに上記の記事を参考に、ログレベルを設定してみる。
cron のログレベルを設定。全部記録する設定にする。
$ sudo <a href="http://d.hatena.ne.jp/keyword/vim">vim</a> /etc/default/cronそうすると、以下のエラーを得られた。
error (grandchild #1432 failed with exit status 1)
結局コードが間違っている、ということがわかった。
pythonのエラーを出力する
最後に、以下サイトを参考にログを出すようにしてみた。
【保存版】cronでPython3を定時実行する方法&注意すべき４つのポイント | たぬハック
https://tanuhack.com/cron/$sudo crontab –l LANG=ja_JP.UTF-8 05 02 * * * %%conda%%/bin/python3 %%conda%%/scripts/crons/script_a_1.py > %%conda%%/scripts/exec-error.log 2>&1 05 01 * * * %%conda%%/bin/python3 %%conda%%/scripts/crons/script_b_1.py > %%conda%%/scripts/exec-error.log 2>&1 15 01 * * * %%conda%%/bin/python3 %%conda%%/scripts/crons/script_b_2.py > %%conda%%/scripts/exec-error.log 2>&1 25 01 * * * %%conda%%/bin/python3 %%conda%%/scripts/crons/script_b_3.py > %%conda%%/scripts/exec-error.log 2>&1 35 01 * * * %%conda%%/bin/python3 %%conda%%/scripts/crons/script_b_4.py > %%conda%%/scripts/exec-error.log 2>&1 45 01 * * * %%conda%%/bin/python3 %%conda%%/scripts/crons/script_b_5.py > %%conda%%/scripts/exec-error.log 2>&1 05 03 * * * %%conda%%/bin/python3 %%conda%%/scripts/crons/script_c_1.py > %%conda%%/scripts/exec-error.log 2>&1 15 04 * * * %%conda%%/bin/python3 %%conda%%/scripts/crons/script_d_1.py > %%conda%%/scripts/exec-error.log 2>&1 25 04 * * * %%conda%%/bin/python3 %%conda%%/scripts/crons/script_d_2.py > %%conda%%/scripts/exec-error.log 2>&1 35 04 * * * %%conda%%/bin/python3 %%conda%%/scripts/crons/script_d_3.py > %%conda%%/scripts/exec-error.log 2>&1 45 04 * * * %%conda%%/bin/python3 %%conda%%/scripts/crons/script_d_4.py > %%conda%%/scripts/exec-error.log 2>&1 55 04 * * * %%conda%%/bin/python3 %%conda%%/scripts/crons/script_d_5.py > %%conda%%/scripts/exec-error.log 2>&1 05 21 * * * %%conda%%/bin/python3 %%conda%%/scripts/crons/script_e_1.py > %%conda%%/scripts/exec-error.log 2>&1 35 05 * * * %%conda%%/bin/python3 %%conda%%/scripts/crons/script_e_2.py > %%conda%%/scripts/exec-error.log 2>&1エラーになるスクリプトを走らせると、exec-error.log に以下の結果が出力された。
Traceback (most recent call last): File “%%conda%%/scripts/crons/script_e_1.py", line 105, in <module> number = function1(url,startnum) File “%%conda%%/scripts/crons/script_e_1.py", line 73, in function1 driver = webdriver.Chrome(options=options) File "%%conda%%/lib/python3.6/site-packages/selenium/webdriver/chrome/webdriver.py", line 81, in __init__ desired_capabilities=desired_capabilities) File "%%conda%%/lib/python3.6/site-packages/selenium/webdriver/remote/webdriver.py", line 157, in __init__ self.start_session(capabilities, browser_profile) File "%%conda%%/lib/python3.6/site-packages/selenium/webdriver/remote/webdriver.py", line 252, in start_session response = self.execute(Command.NEW_SESSION, parameters) File "%%conda%%/lib/python3.6/site-packages/selenium/webdriver/remote/webdriver.py", line 321, in execute self.error_handler.check_response(response) File "%%conda%%/lib/python3.6/site-packages/selenium/webdriver/remote/errorhandler.py", line 242, in check_response raise exception_class(message, screen, stacktrace) selenium.common.exceptions.WebDriverException: Message: unknown error: Chrome failed to start: exited abnormally (unknown error: DevToolsActivePort file doesn't exist) (The process started from chrome location /usr/bin/chromium-browser is no longer running, so ChromeDriver is assuming that Chrome has crashed.)なるほど、chromedriver周りが問題のようである。
こうやって調べていった結果、7つ中5つは
options.add_argument(‘–headless’)
と書くべきところを
options.add_argument(‘-headless’)
と書いてしまった間抜けが原因であることが判明。
もう2つについては
options.add_argument(‘–no-sandbox’)
をつけることで解決ができた。
ログを出すことのできる方法を調べるのが一番
やっている間は結構あたふたしていたものの、問題解決に至る道筋としては悪くなかったような気がする。
cron.logを見て実行されているか確認する
さらにcron.logを見て実行結果も確認する
pythonの実行結果を見てエラー内容を確認する
これらのやり方に関する知識を得られたのも本職の皆様の知見をネットで得られたから。
多謝。
コメント