Rhadamanthys
Posts: 9
Joined: Wed Nov 22, 2017 5:40 pm

Re: Scripts dying every night at 0:00-01:00'ish

Fri Nov 24, 2017 3:35 pm

1st, let me thank you for drawing my attention to supervisor.

There is no need to stay awake to follow my proposals.

Assuming the issue is lack of internet access, I'm proposing to pull the dsl line. Can be done in seconds any time of day.

Unless specified otherwise, supervisor expects a started program to run for at least one second and make 3 attempts to restart if this fails. Simply have a looks supervisor's status to see why it does no longer restart your script. You can also tell supervisor to write your program's stderr output to a logfile.

As long as just your script stops executing and you can still access your RPi (locally or by VNC Viewer) you can happily take a glance on the Python shell to read the nightly messages after you gracefully awake next morning.

Imho all that far more convienient than writing tons of monitoring code into your script but, it's up to you.

georgelza
Posts: 81
Joined: Sun Oct 09, 2016 2:17 pm

Re: Scripts dying every night at 0:00-01:00'ish

Fri Nov 24, 2017 4:09 pm

My turn, thanks... reading your response I went and read some more of the possible configuration possibilities, set the debug level to debug and had a look at where the supervisor.log file is written to. Will be eye balling it.

Also extended my logging a bit, so lets see tomorrow, and ye, guess I can just pull the network cable and see what happens.

:) and writing code is why I'm doing this so at the moment don't mind writing more, to try and catch/find the error.

G

Rhadamanthys
Posts: 9
Joined: Wed Nov 22, 2017 5:40 pm

Re: Scripts dying every night at 0:00-01:00'ish

Fri Nov 24, 2017 4:29 pm

Look at my learning curve!
One line is supervisor's conf file and you know what hickups your script. See screenshot.
supervisor staus reponses:
EXITED: a script sleeping for 10s
FATAL: divzero.py without logfile
BACKUP: same with
Attachments
screenshot.JPG
screenshot.JPG (163.29 KiB) Viewed 1467 times

georgelza
Posts: 81
Joined: Sun Oct 09, 2016 2:17 pm

Re: Scripts dying every night at 0:00-01:00'ish

Fri Nov 24, 2017 6:48 pm

how do I return a value from a python script, don't think my auto restart using supervisorctl is working correctly...

also discovered my writing out to syslog was not working, confirmed its working now so maybe I'll have some log messages tonight.

G

NotRequired
Posts: 190
Joined: Sat Apr 29, 2017 10:36 am
Location: Denmark

Re: Scripts dying every night at 0:00-01:00'ish

Fri Nov 24, 2017 6:57 pm

georgelza wrote:
Fri Nov 24, 2017 6:48 pm
how do I return a value from a python script
What do you mean by "returning a value"? Usually you would either "sys.exit(...)" or just "print(...)"
Please do not ask questions in private messages, they will not help others.

georgelza
Posts: 81
Joined: Sun Oct 09, 2016 2:17 pm

Re: Scripts dying every night at 0:00-01:00'ish

Fri Nov 24, 2017 7:09 pm

http://www.supervisord.org/configuratio ... n-settings touches on auto restart and exit codes and its all handled via exit codes returned by the application

G

NotRequired
Posts: 190
Joined: Sat Apr 29, 2017 10:36 am
Location: Denmark

Re: Scripts dying every night at 0:00-01:00'ish

Fri Nov 24, 2017 7:17 pm

georgelza wrote:
Fri Nov 24, 2017 7:09 pm
http://www.supervisord.org/configuratio ... n-settings touches on auto restart and exit codes and its all handled via exit codes returned by the application

G
To exit with exitcode 1, you do "sys.exit(1)"
Please do not ask questions in private messages, they will not help others.

Rhadamanthys
Posts: 9
Joined: Wed Nov 22, 2017 5:40 pm

Re: Scripts dying every night at 0:00-01:00'ish

Fri Nov 24, 2017 9:01 pm

georgelza wrote:
Fri Nov 24, 2017 6:48 pm
how do I return a value from a python script
Linux executables return a code when they exit. Does this answer your question?
Based on this code supervisor decides what to depending on the configuration.
Unless specified otherwise supervisor restarts your script only if it exits with an error code.

As usual, if everything else fails read the manual, eg.
http://supervisord.org/configuration.ht ... n-settings
:roll:

georgelza
Posts: 81
Joined: Sun Oct 09, 2016 2:17 pm

Re: Scripts dying every night at 0:00-01:00'ish

Sat Nov 25, 2017 5:30 am

thanks, what i was looking for.

have eventually/finally determined that it is definitely associated with the network being unavailable, so now just need to return a error code and then have supervisor restart it. And still nothing in syslog or text log file :( this error just does not want to get caught.

G
NotRequired wrote:
Fri Nov 24, 2017 7:17 pm
georgelza wrote:
Fri Nov 24, 2017 7:09 pm
http://www.supervisord.org/configuratio ... n-settings touches on auto restart and exit codes and its all handled via exit codes returned by the application

G
To exit with exitcode 1, you do "sys.exit(1)"

georgelza
Posts: 81
Joined: Sun Oct 09, 2016 2:17 pm

Re: Scripts dying every night at 0:00-01:00'ish

Sun Nov 26, 2017 3:27 pm

...

so disabled the router reboot last night, and all still working, so now just need to figure out the exception catching a bit better and then manage the exception, as nothing is currently being thrown out to my syslog catch.

Below is the newest version of the code: (turning into a little bit of spaghetti though...)

Code: Select all

#
#	George
#	[email protected]
#	
#	Lets try our hand at Python
#


from envirophat import weather
import requests
import time
import csv
import httplib, urllib
import sys

import logging
import logging.handlers

# constants
URL 						= 'https://corlysis.com:8086/write'
READING_DATA_PERIOD_MS 	= 5000.0
SENDING_PERIOD 			= 2
MAX_LINES_HISTORY 		= 1000
EXIT_SUCCESS 				= 0
EXIT_FAILURE 				= 1

db				= "environmental"
token			= "a99bcfd491a15xxxxa10a3530f152f"
csvfile 			= "/home/pi/projects/source/corlysis/temp.csv"
barometric 		= 0

def writetofile(csvfile, logmsg, logger):
    try:

        with open(csvfile, "a") as output:
            writer = csv.writer(output, delimiter=",", lineterminator='\n')
            writer.writerow(logmsg)

    except Exception, e:
        # Build up 'data' to be used as a array to write to Syslogd
        data = ["ERROR writing to logfile : " + csvfile + " : " + e]
	logger.setLevel(logging.ERROR)
        # Write message to SysLog instead
	writetosyslog(logger, data)

    #End Try
#End writetofile

def writetosyslog(logger, data):

	logger.info(data)

#End writetosyslog

def main():

    logger = logging.getLogger('myRead_Temp_humidity_DHT22')
    handler = logging.handlers.SysLogHandler('/dev/log')
    formatter = logging.Formatter('Python: { "loggerName":"%(name)s", "message":"%(message)s"}')
    handler.formatter = formatter
    logger.addHandler(handler)

    timeC = time.strftime('%Y/%m/%d %H:%M:%S')
    data = ["Barometric STARTING at: ", timeC]
    logger.setLevel(logging.INFO)
    writetosyslog(logger, data)

    corlysis_params = {"db": DB, "u": "token", "p": TOKEN, "precision": "ms"}

    payload = ""
    counter = 1
    problem_counter = 0

    # infinite loop
    while True:
        unix_time_ms = int(time.time()*1000)

        timeC = time.strftime('%Y/%m/%d %H:%M:%S')

        try:
            # read sensor data and convert it to line protocol
		    barometric = weather.pressure()
		    barometric = round(barometric, 2)
		    barometric = barometric / 100

        except Exception, e:
            # Build up 'data' to be used as a array to write to Syslogd
            data = ["Exception, Read weather.*: ", e]

            # Write message to SysLog
            logger.setLevel(logging.ERROR)
            writetosyslog(logger, data)

            # Write to csv log file
            writetofile(csvfile, data, logger)

        #End Try

        line = "sensors_data pressure={} {}\n".format(barometric, unix_time_ms)

	data = ["Study EnviroPhat", timeC, barometric ]

        writetofile(csvfile, data, logger)

		params = urllib.urlencode({'field3': barometric,'key': 'SFF0xxxx0I4YE'})  # use your API key generated in the thingspeak channels for the value of 'key'
		headers = {"Content-typZZe": "application/x-www-form-urlencoded", "Accept": "text/plain"}

		try:
            conn = httplib.HTTPConnection("api.thingspeak.com:80")
			conn.request("POST", "/update", params, headers)
			response = conn.getresponse()
			print response.status, response.reason
			data = response.read()
			conn.close()
			sys.exit(EXIT_FAILURE)

        except Exception, e:
            # Build up 'data' to be used as a array to write to Syslogd
            data = ["Exception, Post to api.thingspeak: ", e]

            # Write message to SysLog
            logger.setLevel(logging.ERROR)
            writetosyslog(logger, data)

            # Write to csv log file
            writetofile(csvfile, data, logger)
            
            conn.close()
            sys.exit(EXIT_FAILURE)

        #End Try


	    payload += line

        if counter % SENDING_PERIOD == 0:
            try:
                # try to send data to cloud
                r = requests.post(URL, params=corlysis_params, data=payload)
                if r.status_code != 204:
                    raise Exception("data not written")
                payload = ""
            except Exception, e:
                problem_counter += 1

                # Build up 'data' to be used as a array to write to Syslogd
                data = ["Exception, Cannot write to InfluxDB: ", e]

                # Write message to SysLog
                logger.setLevel(logging.ERROR)
                writetosyslog(logger, data)
                
                # Write to csv log file
                writetofile(csvfile, data, logger)
                
		# Exit with error so that supervisor can restart us
		sys.exit(EXIT_FAILURE)

                if problem_counter == MAX_LINES_HISTORY:
                    problem_counter = 0
                    payload = ""

            # End Try

        counter += 1

        # wait for selected time
        time_diff_ms = int(time.time()*1000) - unix_time_ms
        print(time_diff_ms)
        if time_diff_ms < READING_DATA_PERIOD_MS:
            time.sleep((READING_DATA_PERIOD_MS - time_diff_ms)/1000.0)


if __name__ == "__main__":
    main()

Rhadamanthys
Posts: 9
Joined: Wed Nov 22, 2017 5:40 pm

Re: Scripts dying every night at 0:00-01:00'ish

Wed Nov 29, 2017 11:41 am

Glad to hear it's indeed the missing internet accessibility that causes your script to die.
But why do you want to handle possible errors and write your own error messages?
Did you have a look at my simple script that produces unhandled divide by zero errors frome time to time?
Supervisor starts it over and over again.
Throw out all your error handling attempts and just add a 10 seconds grace period at the very beginning to make sure your scripts does not run into your router reboot (or what ever causes a internet timeout) too often.

georgelza
Posts: 81
Joined: Sun Oct 09, 2016 2:17 pm

Re: Scripts dying every night at 0:00-01:00'ish

Wed Nov 29, 2017 12:40 pm

Problem was caused by missing network, and this was caused by router reboot.

So when it tried to post, it could not because network was dead, causing script to die.

I have 2 options, add exception handling, so that instead of the script dying, it handles it, and just try posting data 1 minute later at the next run, ye will loose some data points, or catch exception, throw a sys.exit(1) out and have supervisor restart it minute later.

At the moment it just dies and supervisor does not restart it, haven't implemented the sys.exit(1) on error. at the moment it just dies and supervisor has not been told to restart.

G

User avatar
DougieLawson
Posts: 34387
Joined: Sun Jun 16, 2013 11:19 pm
Location: Basingstoke, UK
Contact: Website

Re: Scripts dying every night at 0:00-01:00'ish

Thu Nov 30, 2017 6:25 am

Isn't the simplest solution to leave your router running 24/365?

My router and/or VDSL2 modem only get rebooted when British Telecom disconnect my line at the exchange and a reboot is needed for recovery.
Note:Having anything remotely humorous in your signature is completely banned on this forum.

Any DMs sent on Twitter will be answered next month.

georgelza
Posts: 81
Joined: Sun Oct 09, 2016 2:17 pm

Re: Scripts dying every night at 0:00-01:00'ish

Thu Nov 30, 2017 7:27 am

It would be the simplest to just leave it, but I had a problem with my ISP and this reboot was the only solution, as directed by the ISP.

I"m in the process to change ISP's. but as previously stated, this entire exercise is to get more experience with Python on the Rpi, so this error/problem and working on different solutions is not un welcome as it is teaching me, if it was not for this reboot I would not have known/experienced the problem and now sitting working on multiple solutions, which is experience...

G

User avatar
DougieLawson
Posts: 34387
Joined: Sun Jun 16, 2013 11:19 pm
Location: Basingstoke, UK
Contact: Website

Re: Scripts dying every night at 0:00-01:00'ish

Thu Nov 30, 2017 7:40 am

Fair comment. This thread is a good example of problem determination and source identification. We've all learned something from your problems.
Note:Having anything remotely humorous in your signature is completely banned on this forum.

Any DMs sent on Twitter will be answered next month.


georgelza
Posts: 81
Joined: Sun Oct 09, 2016 2:17 pm

Re: Scripts dying every night at 0:00-01:00'ish

Thu Nov 30, 2017 12:33 pm

Interesting...

the logging.ERROR makes the message not show in syslog.
setting it to INFO and it's being writing to /var/log/syslog

G

Code: Select all

	logger.setLevel(logging.ERROR)
        # Write message to SysLog instead
	writetosyslog(logger, data)

User avatar
DougieLawson
Posts: 34387
Joined: Sun Jun 16, 2013 11:19 pm
Location: Basingstoke, UK
Contact: Website

Re: Scripts dying every night at 0:00-01:00'ish

Thu Nov 30, 2017 3:52 pm

What's in /etc/rsyslogd.conf? That's where logging destinations are defined (there's no definition for error or ERROR in my config).
Note:Having anything remotely humorous in your signature is completely banned on this forum.

Any DMs sent on Twitter will be answered next month.

georgelza
Posts: 81
Joined: Sun Oct 09, 2016 2:17 pm

Re: Scripts dying every night at 0:00-01:00'ish

Thu Nov 30, 2017 5:27 pm

can't find any mention of anything "error" related, thanks for the pointer, will go google a bit.

G

Rhadamanthys
Posts: 9
Joined: Wed Nov 22, 2017 5:40 pm

Re: Scripts dying every night at 0:00-01:00'ish

Thu Nov 30, 2017 8:57 pm

Guess you overcomplicate things.
I run a script which includes a statement like this:

Code: Select all

urlopen(homematic+str(round(avg,0)),timeout=5)
NO ERROR HANDLING included!!!

supervisor uses this configuration file (/etc/supervisor/superisord.conf), generated at supervisor installation

Code: Select all

; supervisor config file

[unix_http_server]
file=/var/run/supervisor.sock   ; (the path to the socket file)
chmod=0700                       ; sockef file mode (default 0700)

[supervisord]
logfile=/var/log/supervisor/supervisord.log ; (main log file;default $CWD/supervisord.log)
pidfile=/var/run/supervisord.pid ; (supervisord pidfile;default supervisord.pid)
childlogdir=/var/log/supervisor            ; ('AUTO' child log dir, default $TEMP)

; the below section must remain in the config file for RPC
; (supervisorctl/web interface) to work, additional interfaces may be
; added by defining them in separate rpcinterface: sections
[rpcinterface:supervisor]
supervisor.rpcinterface_factory = supervisor.rpcinterface:make_main_rpcinterface

[supervisorctl]
serverurl=unix:///var/run/supervisor.sock ; use a unix:// URL  for a unix socket

; The [include] section can just contain the "files" setting.  This
; setting can list multiple files (separated by whitespace or
; newlines).  It can also contain wildcards.  The filenames are
; interpreted as relative to this file.  Included files *cannot*
; include files themselves.

[include]
files = /etc/supervisor/conf.d/*.conf
My individual configuration file looks like this:

Code: Select all

[program:oelstand]
command = python3 /home/pi/Python/oelstand.py
directory = /home/pi
user = pi
environment=HOME="/home/pi", USER="pi"
stderr_logfile=/home/pi/Python/oelstand_err.log
So when oelstand.py produces an error I shall find it in oelstand_err.log:

Code: Select all

Traceback (most recent call last):
  File "/usr/lib/python3.4/urllib/request.py", line 1174, in do_open
    h.request(req.get_method(), req.selector, req.data, headers)
  File "/usr/lib/python3.4/http/client.py", line 1090, in request
    self._send_request(method, url, body, headers)
  File "/usr/lib/python3.4/http/client.py", line 1128, in _send_request
    self.endheaders(body)
  File "/usr/lib/python3.4/http/client.py", line 1086, in endheaders
    self._send_output(message_body)
  File "/usr/lib/python3.4/http/client.py", line 924, in _send_output
    self.send(msg)
  File "/usr/lib/python3.4/http/client.py", line 859, in send
    self.connect()
  File "/usr/lib/python3.4/http/client.py", line 836, in connect
    self.timeout, self.source_address)
  File "/usr/lib/python3.4/socket.py", line 509, in create_connection
    raise err
  File "/usr/lib/python3.4/socket.py", line 500, in create_connection
    sock.connect(sa)
OSError: [Errno 101] Network is unreachable

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/home/pi/Python/oelstand.py", line 98, in <module>
    urlopen(homematic+str(round(avg,0)),timeout=5)
  File "/usr/lib/python3.4/urllib/request.py", line 153, in urlopen
    return opener.open(url, data, timeout)
  File "/usr/lib/python3.4/urllib/request.py", line 455, in open
    response = self._open(req, data)
  File "/usr/lib/python3.4/urllib/request.py", line 473, in _open
    '_open', req)
  File "/usr/lib/python3.4/urllib/request.py", line 433, in _call_chain
    result = func(*args)
  File "/usr/lib/python3.4/urllib/request.py", line 1202, in http_open
    return self.do_open(http.client.HTTPConnection, req)
  File "/usr/lib/python3.4/urllib/request.py", line 1176, in do_open
    raise URLError(err)
urllib.error.URLError: <urlopen error [Errno 101] Network is unreachable>
And here is what supervisor logs:

Code: Select all

2017-11-30 14:49:36,935 INFO supervisord started with pid 650
2017-11-30 14:49:38,011 INFO spawned: 'oelstand' with pid 678
2017-11-30 14:49:39,029 INFO success: oelstand entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)
2017-11-30 16:50:11,700 INFO exited: oelstand (exit status 1; not expected)
2017-11-30 16:50:12,714 INFO spawned: 'oelstand' with pid 4618
2017-11-30 16:50:13,730 INFO success: oelstand entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)
As you can see oelstand went well from power up ("supervisord started") until it ran into an error ("exited: oelstand (exit status 1; not expected)") but 2 seconds later supervisor started it again successfully.
What else are you looking for?

georgelza
Posts: 81
Joined: Sun Oct 09, 2016 2:17 pm

Re: Scripts dying every night at 0:00-01:00'ish

Fri Dec 01, 2017 3:38 am

I know about supervisor's error output, and ye I'm catching errors there,

But the idea here was to learn about syslog, first throwing/catching errors the local syslog and also into a remote syslog,

the entire idea here was to over complicate things to have errors, problems and then find solutions, otherwise I could just have copy pasted code from GitHub and walked away, learning nothing.

btw, for supervisor, you can actually put those [program:xxxx] blocks in the main supervisor.conf file also.

G

User avatar
DougieLawson
Posts: 34387
Joined: Sun Jun 16, 2013 11:19 pm
Location: Basingstoke, UK
Contact: Website

Re: Scripts dying every night at 0:00-01:00'ish

Fri Dec 01, 2017 9:37 am

If you log to the debug channel the logging should appear in /var/log/debug

Code: Select all

#
# Some "catch-all" log files.
#
*.=debug;\
        auth,authpriv.none;\
        news.none;mail.none     -/var/log/debug
*.=info;*.=notice;*.=warn;\
        auth,authpriv.none;\
        cron,daemon.none;\
        mail,news.none          -/var/log/messages

Note:Having anything remotely humorous in your signature is completely banned on this forum.

Any DMs sent on Twitter will be answered next month.

georgelza
Posts: 81
Joined: Sun Oct 09, 2016 2:17 pm

Re: Scripts dying every night at 0:00-01:00'ish

Fri Dec 01, 2017 10:00 am

I'm assuming this is your rsyslogd.conf configuration file?

going to guess *.=error;\ will follow the same structure.

will have a look tonight.

G
DougieLawson wrote:
Fri Dec 01, 2017 9:37 am
If you log to the debug channel the logging should appear in /var/log/debug

Code: Select all

#
# Some "catch-all" log files.
#
*.=debug;\
        auth,authpriv.none;\
        news.none;mail.none     -/var/log/debug
*.=info;*.=notice;*.=warn;\
        auth,authpriv.none;\
        cron,daemon.none;\
        mail,news.none          -/var/log/messages


User avatar
DougieLawson
Posts: 34387
Joined: Sun Jun 16, 2013 11:19 pm
Location: Basingstoke, UK
Contact: Website

Re: Scripts dying every night at 0:00-01:00'ish

Fri Dec 01, 2017 11:22 am

I just lifted the last few lines of the stock standard rsyslogd package version.
Note:Having anything remotely humorous in your signature is completely banned on this forum.

Any DMs sent on Twitter will be answered next month.

georgelza
Posts: 81
Joined: Sun Oct 09, 2016 2:17 pm

Re: Scripts dying every night at 0:00-01:00'ish

Fri Dec 01, 2017 11:57 am

So I have:

*.*;auth,authpriv.none -/var/log/syslog

#
# Some "catch-all" log files.
#
*.=debug;\
auth,authpriv.none;\
news.none;mail.none -/var/log/debug
*.=info;*.=notice;*.=warn;\
auth,authpriv.none;\
cron,daemon.none;\
mail,news.none -/var/log/messages

Now it's curious... as it implies INFO is suppose to go to /var/log/messages, but they're going/showing up in /var/log/syslog...

G

Return to “General discussion”