- 最終更新日
- 記事公開日
cronのときだけプログラムが正常に動かない【ラズパイ】
SSHで繋いでプログラムを起動したときは、正常に動くのに、cronで動かしたときだけなぜか正常に動かないトラブルが発生。
結論から言うと、原因は「pythonで書いたプログラム側」でした。
cronやラズパイ側の設定側に問題あると思い、かなり無駄な時間を費やしてしました。
本来、プログラムで何かしらの問題があれば、cronでない場合でもエラーが出るはずなんです。
ところが、そのエラーが表示されなかった・・・
その理由は、threadingモジュールでした。
threadingを使って配列処理を行っていたのですが、一つのプロセスは正常、もう一つのプロセスに問題がありました。
普通のプログラムなら、『CTRL』＋『C』でプログラムを停止させるのですが、threadingモジュールを使っているときは、２個のプロセスが動いているので、２回続けて『CTRL』＋『C』を押さないと、コマンド入力画面に戻りません。
実はここがミソで、２回目の『CTRL』＋『C』を押す前に、たまたまハード側の入力をいじったんです。
すると、エラーが発生。
どうやら、このタイミングないと、２個目のプロセスのエラーは表示されなかったようです。
UnboundLocalError: local variable 'speed' referenced before assignment
Exception KeyboardInterrupt in <module 'threading' from '/usr/lib/python2.7/threading.pyc'> ignoredエラーの原因は、単純な変数の未定義ミスでした。
解決のために試したこと
今回、このハマりによって、原因追及のために色々試したことがあります。
少なくとも解決のヒントになったこともあるので、情報として残しておきます。
１．ステータス確認用のLEDを取り付けた
ラズパイのGPIOラインにLEDを取り付け、プログラムでテスト信号を発信。
間違いなくcronは動いてるし、プログラムも起動自体はしていることを確認できました。
２．「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 restartcronの起動ログ確認
cat /var/log/cron.log３．「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
たしかに関係性もあるエラーが出てはいるものの、これは解決の糸口とはなりませんでした。
