How Can I Determine Why My Python Script Is Terminating?

Question

I'm running Raspbian Jessie 4.9.35-v7+ on a Pi 3 Model B. I cobbled together a basic python script to monitor a GPIO pin and send a network signal to a remote application and made two copies of the script to correlate to two different GPIO pins and network signals. Both scripts are called in rc.local from /usr/local/bin, so rc.local ends like this:

/usr/local/bin/script1.py &
/usr/local/bin/script2.pf &

exit 0

When I originally did this, the scripts just ran and worked for months on end. Here is an example of the scripts at that point (the only difference between script1 and script2 would have been the GPIO pin ["thiscontact"] and the network signal [s.send]):

#!/usr/bin/env python
import RPi.GPIO as GPIO
import signal
import socket
import time
#Define GPIO pin here:
thiscontact = 2
GPIO.setmode(GPIO.BCM)
GPIO.setup(thiscontact, GPIO.IN, pull_up_down=GPIO.PUD_UP)
def watchopen():
    thisposition = GPIO.input(thiscontact)
    if thisposition == True:
        while thisposition == True:
            time.sleep(0.1)
            thisposition = GPIO.input(thiscontact)
         watchclose()
    watchclose()
def watchclose():
    thisposition = GPIO.input(thiscontact)
    if thisposition == False:
        while thisposition == False:
            s = socket.socket(socket.AF_INET, socket.SOCK_STREAM)
            #Define network server here:
            s.connect(("192.0.2.248", 6802))
            #Define network signal here:
            s.send("1|do+3|255")
            s.close()
            time.sleep(0.9)
            thisposition = GPIO.input(thiscontact)
        watchopen()
    watchopen()
def exit_handler(signal, frame):
    GPIO.cleanup()
    raise SystemExit
signal.signal(signal.SIGTERM, exit_handler)
signal.signal(signal.SIGINT, exit_handler)
watchopen()

Unfortunately, the network signal needs have changed. I'm still monitoring the same two GPIO pins for the same conditions, but the remote application has changed, so I modified the scripts accordingly, tested them, and found them to be working. Here is an example of the modified scripts (again, the only differences between script1 and script2 are the GPIO pin ["thiscontact"] and the parameters in the network signal [https.get]):

#!/usr/bin/env python
import RPi.GPIO as GPIO
import signal
import socket
import time
import requests
#Define GPIO pin here:
thiscontact = 2
GPIO.setmode(GPIO.BCM)
GPIO.setup(thiscontact, GPIO.IN, pull_up_down=GPIO.PUD_UP)
def watchopen():
    thisposition = GPIO.input(thiscontact)
    if thisposition == True:
        while thisposition == True:
            time.sleep(0.1)
            thisposition = GPIO.input(thiscontact)
        watchclose()
    watchclose()
def watchclose():
    thisposition = GPIO.input(thiscontact)
    if thisposition == False:
        while thisposition == False:
            #Send Trigger
            requests.get('https://192.0.2.248:55756/Srv/Api/TriggerFacade/ActivateDeactivateTrigger?{"triggerName":"SignalOne","deactivateAfterSeconds":"3"}', auth=('Username', 'Password'), verify=False, timeout=1)
            time.sleep(0.9)
            thisposition = GPIO.input(thiscontact)
        watchopen()
    watchopen()
def exit_handler(signal, frame):
    GPIO.cleanup()
    raise SystemExit
signal.signal(signal.SIGTERM, exit_handler)
signal.signal(signal.SIGINT, exit_handler)
watchopen()

The problem I have now is that these scripts don't run for months. In fact, last week on Monday, I noticed they weren't running at all and rebooted the Pi to start them back up. This isn't the first time this has happened, but it is the first time I decided to try and straighten it out. I did some searching to see how I should deal with this and set a reminder to check weekly to see if they were still running. When I checked yesterday, one of them was running, but the other had already stopped. My research only suggested checking system logs, which hasn't been helpful at all (I've removed x-info from the logs because it was preventing me from posting):

$ cat /var/log/dmesg  
(Nothing has been logged yet.)  
$ dmesg  
 ****SNIP****  
[   20.559238] Bluetooth: BNEP (Ethernet Emulation) ver 1.3  
[   20.559248] Bluetooth: BNEP filters: protocol multicast  
[   20.559271] Bluetooth: BNEP socket layer initialized  
$ tail /var/log/messages  
May 12 06:25:04 dcu002pi rsyslogd: [origin software="rsyslogd" swVersion="8.4.2" x-pid="530"] rsyslogd was HUPed  
May 13 06:25:04 dcu002pi rsyslogd: [origin software="rsyslogd" swVersion="8.4.2" x-pid="530"] rsyslogd was HUPed  
May 14 06:25:04 dcu002pi rsyslogd: [origin software="rsyslogd" swVersion="8.4.2" x-pid="530"] rsyslogd was HUPed  
$ tail /var/log/messages.1  
May  6 08:16:16 dcu002pi kernel: [   20.559271] Bluetooth: BNEP socket layer initialized  
May  7 06:25:06 dcu002pi rsyslogd: [origin software="rsyslogd" swVersion="8.4.2" x-pid="530"] rsyslogd was HUPed  
May  7 06:25:06 dcu002pi rsyslogd: [origin software="rsyslogd" swVersion="8.4.2" x-pid="530"] rsyslogd was HUPed  
May  8 06:25:04 dcu002pi rsyslogd: [origin software="rsyslogd" swVersion="8.4.2" x-pid="530"] rsyslogd was HUPed  
May  9 06:25:04 dcu002pi rsyslogd: [origin software="rsyslogd" swVersion="8.4.2" x-pid="530"] rsyslogd was HUPed  
May 10 06:25:04 dcu002pi rsyslogd: [origin software="rsyslogd" swVersion="8.4.2" x-pid="530"] rsyslogd was HUPed  
May 11 06:25:04 dcu002pi rsyslogd: [origin software="rsyslogd" swVersion="8.4.2" x-pid="530"] rsyslogd was HUPed  
May 12 06:25:04 dcu002pi rsyslogd: [origin software="rsyslogd" swVersion="8.4.2" x-pid="530"] rsyslogd was HUPed  

In case it's not obvious, I'm actually not that well-versed in Python or Linux, but I can find my way around. My searching skills also leave something to be desired, but once I'm past that hurdle, I can read and follow instructions. I'd prefer a best practice, but regardless of whether or not it is, how can I determine why these scripts seem to be randomly terminating?

Answer 1

To determine what your program is doing, you need to save the output of the program to a file. Use this type of call to start the program

/path/to/script >> /path/to/log/file 2>&1 &

This will start the program in the background, and send all output (both stdout and stderr) to a file of your choice.

Keep in mind that if the script is long running and/or outputs a lot of text, you should include the log file in the log rotate conf file so it can be compressed/archived and old ones can be removed. This way the log file does not fill up your disk over time.

Another useful thing in python is to print what happened when you catch an exception. Many of your functions should include a try/except block. This way if some piece of data is not what you expect it to be, it can fail, print the issue, but doesnt kill the program.

This sample program:

#!/usr/bin/env python

import sys

print("Starting")
print("")

try:
    print(3+"a")

except:
    print(sys.exc_info())

print("Program still running")
print("done")

will output this:

Starting

(<type 'exceptions.TypeError'>, TypeError("unsupported operand type(s) for +: 'int' and 'str'",), <traceback object at 0x7f47a17bb5f0>)
Program still running
done