最終更新日
記事公開日

cronのときだけプログラムが正常に動かない【ラズパイ】

SSHで繋いでプログラムを起動したときは、正常に動くのに、cronで動かしたときだけなぜか正常に動かないトラブルが発生。

結論から言うと、原因は「pythonで書いたプログラム側」でした。

cronやラズパイ側の設定側に問題あると思い、かなり無駄な時間を費やしてしました。

本来、プログラムで何かしらの問題があれば、cronでない場合でもエラーが出るはずなんです。

ところが、そのエラーが表示されなかった・・・

その理由は、threadingモジュールでした。

threadingを使って配列処理を行っていたのですが、一つのプロセスは正常、もう一つのプロセスに問題がありました。

普通のプログラムなら、『CTRL』+『C』でプログラムを停止させるのですが、threadingモジュールを使っているときは、2個のプロセスが動いているので、2回続けて『CTRL』+『C』を押さないと、コマンド入力画面に戻りません。

実はここがミソで、2回目の『CTRL』+『C』を押す前に、たまたまハード側の入力をいじったんです。

すると、エラーが発生。

どうやら、このタイミングないと、2個目のプロセスのエラーは表示されなかったようです。

UnboundLocalError: local variable 'speed' referenced before assignment

Exception KeyboardInterrupt in <module 'threading' from '/usr/lib/python2.7/threading.pyc'> ignored

エラーの原因は、単純な変数の未定義ミスでした。

解決のために試したこと

今回、このハマりによって、原因追及のために色々試したことがあります。

少なくとも解決のヒントになったこともあるので、情報として残しておきます。

1.ステータス確認用のLEDを取り付けた

ラズパイZEROに取り付けたLED

ラズパイのGPIOラインにLEDを取り付け、プログラムでテスト信号を発信。

間違いなくcronは動いてるし、プログラムも起動自体はしていることを確認できました。

2.「sudo /etc/init.d/cron status」でcronが走っているかのチェック

実際に「sudo /etc/init.d/cron status」コマンドを打ってみた結果↓

Apr 19 09:24:22 raspberrypi systemd[1]: Started Regular background program processing daemon.
Apr 19 09:24:22 raspberrypi cron[279]: (CRON) INFO (pidfile fd = 3)
Apr 19 09:24:22 raspberrypi cron[279]: (CRON) INFO (Running @reboot jobs)
Apr 19 09:24:23 raspberrypi CRON[281]: pam_unix(cron:session): session opened for user pi by (uid=0)
Apr 19 09:24:23 raspberrypi CRON[286]: (pi) CMD (python3 /home/pi/elec.py)

エラーなども表示されておらず、cronは正常に走ってました。

cronの再起動

sudo /etc/init.d/cron restart

cronの起動ログ確認

cat /var/log/cron.log

3.「sudo journalctl -xe」でシステム全体の起動ログを表示

実際に「sudo journalctl -xe」コマンドを打ってみた結果↓

Apr 19 13:25:10 raspberrypi thd[299]: Error reading device '/dev/input/event0'

Apr 19 13:25:10 raspberrypi kernel: usb 1-1: USB disconnect, device number 2

Apr 19 13:25:13 raspberrypi kernel: usb 1-1: new full-speed USB device number 3 using dwc2

Apr 19 13:25:13 raspberrypi kernel: usb 1-1: New USB device found, idVendor=0079, idProduct=0126, bcdDevice=10.03

Apr 19 13:25:13 raspberrypi kernel: usb 1-1: New USB device strings: Mfr=0, Product=2, SerialNumber=0

Apr 19 13:25:13 raspberrypi kernel: usb 1-1: Product: Controller

Apr 19 13:25:13 raspberrypi kernel: input: Controller as /devices/platform/soc/20980000.usb/usb1/1-1/1-1:1.0/0003:0079:0126.0002/input/input1
Apr 19 13:25:13 raspberrypi kernel: hid-generic 0003:0079:0126.0002: input,hidraw0: USB HID v1.11 Gamepad [Controller] on usb-20980000.usb-1/input0

Apr 19 13:25:13 raspberrypi mtp-probe[804]: checking bus 1, device 3: "/sys/devices/platform/soc/20980000.usb/usb1/1-1"

Apr 19 13:25:14 raspberrypi mtp-probe[804]: bus: 1, device: 3 was not an MTP device

Apr 19 13:25:14 raspberrypi kernel: usb 1-1: input irq status -5 received

Apr 19 13:25:15 raspberrypi systemd-udevd[802]: Process '/usr/bin/jscal-restore /dev/input/js0' failed with exit code 1.

Apr 19 13:25:15 raspberrypi systemd-udevd[802]: Process '/usr/sbin/th-cmd --socket /var/run/thd.socket --passfd --udev' failed with exit code 1.

Apr 19 13:25:15 raspberrypi systemd-udevd[803]: Process '/usr/sbin/th-cmd --socket /var/run/thd.socket --passfd --udev' failed with exit code 1.

Apr 19 13:25:15 raspberrypi mtp-probe[812]: checking bus 1, device 3: "/sys/devices/platform/soc/20980000.usb/usb1/1-1"

Apr 19 13:25:15 raspberrypi mtp-probe[812]: bus: 1, device: 3 was not an MTP device

Apr 19 13:28:05 raspberrypi sshd[814]: Accepted password for pi from 2001:a452:78a4:8000:c132:a785:842b:b58a port 49513 ssh2

Apr 19 13:28:05 raspberrypi sshd[814]: pam_unix(sshd:session): session opened for user pi by (uid=0)

Apr 19 13:28:05 raspberrypi systemd-logind[327]: New session 5 of user pi.
-- Subject: A new session 5 has been created for user pi

たしかに関係性もあるエラーが出てはいるものの、これは解決の糸口とはなりませんでした。

この記事のURLをコピー

メールアドレスは公開されませんのでご安心ください。また、* が付いている欄は必須項目となります。

内容に問題なければ、下記の「コメントを送信する」ボタンを押してください。

関連情報

運営者プロフィール
コダマ

職業はIT系フリーランス。過去、電子配線業務の経験が10年ある為、はんだづけも得意です。宮崎県在住、30代・2児の父親。

プロが教える!イチからわかるハンダ付けのコツ(工学社)の著者です。

カテゴリー