diff --git a/config.ini b/config.ini index 2697288..6f84c84 100644 --- a/config.ini +++ b/config.ini @@ -2,7 +2,7 @@ refresh camera local = 10 refresh camera transmit = 15 -refresh barometer local = 1 +refresh barometer local = 2 refresh barometer transmit = 2 refresh gps local = 2 @@ -22,11 +22,11 @@ baud rate = 9600 [server settings] use_lan = True -url = "http://home.ascorrea.com" +url = http://home.ascorrea.com server_port = 5010 -data_path = "upload-data" -image_path = "missions" -ping_path = "ping" +data_path = upload-data +image_path = missions +ping_path = ping [local storage settings] photo path = /home/pi/scripts/spaceballoon/photos diff --git a/datahandling.py b/datahandling.py index 011c229..0fd3e36 100644 --- a/datahandling.py +++ b/datahandling.py @@ -79,7 +79,7 @@ class Datalogger(): else: l = self._record[k] for item in l: - logger.debug("item: {}".format(self._record)) + logger.debug("item: {}".format(self._record), extra={'MISSION_TIME': self._mt.now(), 'MISSION_ID':self._mt.name}) item['at']=self._mt.to_absolutetime(item['mt']) item['mid']=self._mt.name header = add_keys_if_necessary(self.log_path, item) @@ -88,6 +88,7 @@ class Datalogger(): writer = csv.DictWriter(log, keys, extrasaction='ignore') writer.writerow(item) log.close() + logger.info('Barometer data recorded',extra={'MISSION_TIME': self._mt.now(), 'MISSION_ID':self._mt.name}) elif k is 'i': if self._record[k] is tuple: l = [self._record[k]] @@ -95,19 +96,19 @@ class Datalogger(): l = self._record[k] for item in l: # Form is ('name', file object, 'type') - logger.info('item is {}'.format(type(item))) filename = item[0] file = base64.b64decode(bytes(item[1],'ascii')) folder = os.path.join(self.photo_path, self._mt.mid) - file_path = os.path.join(self.photo_path, folder , filename) + file_path = os.path.join(self.photo_path, folder, filename) if not os.path.exists(folder): os.makedirs(folder) - with open(os.path.join(self.photo_path, filename), 'wb') as f: + with open(file_path, 'wb') as f: f.write(file) # file.save(os.path.join(self.photo_path, filename)) + logger.info('Image data recorded',extra={'MISSION_TIME': self._mt.now(), 'MISSION_ID':self._mt.name}) return 'success' @@ -145,12 +146,12 @@ class Datareporter(): self.inet = self.SimInetGSM(self.port, logger) - logger.info('ip = {0}'.format(self.inet.ip)) + logger.info('ip = {0}'.format(self.inet.ip), extra={'MISSION_TIME': self.mt.now(), 'MISSION_ID':self.mt.name}) - logger.debug('attaching GPRS') + logger.debug('attaching GPRS', extra={'MISSION_TIME': self.mt.now(), 'MISSION_ID':self.mt.name}) if not self.inet.attachGPRS('wholesale', '', '', 1): - logger.error('error attaching GPRS') + logger.error('error attaching GPRS', extra={'MISSION_TIME': self.mt.now(), 'MISSION_ID':self.mt.name}) return False #register mission number to server @@ -178,20 +179,20 @@ class Datareporter(): path = '{0}/{1}'.format(self.image_path,self.mt.mid) if self.use_lan: - logger.info ('Sending transpondence using LAN') + logger.info ('Sending transpondence using LAN', extra={'MISSION_TIME': self.mt.now(), 'MISSION_ID':self.mt.name}) response = requests.post('{0}:{1}/{2}'.format(self.url, self.server_port, path), data=m.read(), headers={'Content-Type': m.content_type}) pass elif not self.use_lan: - logger.info ('Sending transpondence using modem') + logger.info ('Sending transpondence using modem', extra={'MISSION_TIME': self.mt.now(), 'MISSION_ID':self.mt.name}) # logger.debug('attaching GPRS') # if not self.inet.attachGPRS('wholesale', '', '', 1): # logger.error('error attaching GPRS') # return False - logger.debug('ip = {0}'.format(self.inet.ip)) + logger.debug('ip = {0}'.format(self.inet.ip), extra={'MISSION_TIME': self.mt.now(), 'MISSION_ID':self.mt.name}) - logger.debug('making HTTP POST request') + logger.debug('making HTTP POST request', extra={'MISSION_TIME': self.mt.now(), 'MISSION_ID':self.mt.name}) if not self.inet.httpPOST( self.url, @@ -200,7 +201,7 @@ class Datareporter(): m.to_string(), contentType=m.content_type ): - logger.error('error making HTTP POST: {0}'.format(self.inet.errorText)) + logger.error('error making HTTP POST: {0}'.format(self.inet.errorText), extra={'MISSION_TIME': self.mt.now(), 'MISSION_ID':self.mt.name}) return False if self.inet.httpResponse is not None: diff --git a/instruments.py b/instruments.py index 40cd055..945bcf1 100644 --- a/instruments.py +++ b/instruments.py @@ -1,7 +1,7 @@ __author__ = 'asc' debug = True from random import random -import Adafruit_BMP.BMP085 as BMP085 + import configparser import time import logging @@ -17,7 +17,7 @@ class Camera: high_quality_compression_pct=85, debug = False, **kwargs): - logger.debug("Initializing camera") + logger.info("Initializing camera", extra={'MISSION_TIME': "", 'MISSION_ID':""}) time.sleep(1) self.low_quality_resolution = low_quality_resolution self.low_quality_compression_pct = low_quality_compression_pct @@ -25,14 +25,14 @@ class Camera: self.high_quality_compression_pct = high_quality_compression_pct self.kwargs=kwargs self._debug = debug - if self._debug == False: + if not self._debug: import picamera self._cam = picamera.PiCamera(resolution=high_quality_resolution) # if "vflip" in kwargs.keys(): for k in kwargs.keys(): setattr(self._cam, k, kwargs.get(k)) - logger.debug("Camera intialized") + logger.debug("Camera intialized", extra={'MISSION_TIME': "", 'MISSION_ID':""}) pass @property @@ -46,7 +46,7 @@ class Camera: r = {} if not self._debug: if not no_high_quality: - logger.debug('Taking high quality photo') + logger.debug('Taking high quality photo', extra={'MISSION_TIME': "", 'MISSION_ID':""}) self._cam.capture("temp_img_hi.jpg", resize=self.high_quality_resolution, quality=self.high_quality_compression_pct, @@ -56,7 +56,7 @@ class Camera: # img_hi = base64.b64encode(f.read()) img_hi = str(base64.b64encode(f.read()),'ascii') r['hi']=("{}_hi.jpg".format(name), img_hi, "image/jpeg") - logger.debug('High quality photo taken') + logger.debug('High quality photo taken', extra={'MISSION_TIME': "", 'MISSION_ID':""}) if not no_low_quality: time.sleep(1) @@ -70,29 +70,31 @@ class Camera: img_lo = str(base64.b64encode(f.read()),'ascii') # img_lo = str(f.read()) r['lo']=("{}_lo.jpg".format(name), img_lo, "image/jpeg") - logger.debug('Low quality photo taken') + logger.debug('Low quality photo taken', extra={'MISSION_TIME': "", 'MISSION_ID':""}) else: if not no_high_quality: with open("temp_img_hi.jpg", 'rb') as f: img_hi = str(base64.b64encode(f.read()),'ascii') # img_hi = str(f.read(),'ascii') r['hi']=("{}_hi.jpg".format(name), img_hi, "image/jpeg") - logger.info('High quality photo taken') + logger.info('High quality photo taken', extra={'MISSION_TIME': "", 'MISSION_ID':""}) if not no_low_quality: with open("temp_img_lo.jpg", 'rb') as f: img_lo = str(base64.b64encode(f.read()),'ascii') # img_lo = str(f.read()) r['lo']=("{}_lo.jpg".format(name), img_lo, "image/jpeg") - logger.info('Low quality photo taken') + logger.info('Low quality photo taken', extra={'MISSION_TIME': "", 'MISSION_ID':""}) return r class Barometer: - def __init__(self): - logger.debug("Intializing barometer") - self.bmp = BMP085.BMP085() - logger.debug("Barometer intilized") + def __init__(self, debug=False): + logger.debug("Intializing barometer", extra={'MISSION_TIME': "", 'MISSION_ID':""}) + if not debug: + import Adafruit_BMP.BMP085 as BMP085 + self.bmp = BMP085.BMP085() + logger.debug("Barometer intilized", extra={'MISSION_TIME': "", 'MISSION_ID':""}) pass @property @@ -126,16 +128,21 @@ class Barometer: return alt def read(self): - logger.debug("Reading from barometer") + logger.debug("Reading from barometer", extra={'MISSION_TIME': "", 'MISSION_ID':""}) #refresh each instrument - alt = self.altitude - press = self.pressure - temp = self.temperature + if not debug: + alt = self.altitude + press = self.pressure + temp = self.temperature + else: + temp = random()*100 + press = random() + alt = random()*100000 result = {"a":alt, "t":temp, "p":press, } - logger.debug("Barometer reads {}".format(result)) + logger.debug("Barometer reads {}".format(result), extra={'MISSION_TIME': "", 'MISSION_ID':""}) return result diff --git a/logging.ini b/logging.ini index 0d4ff62..cb13717 100644 --- a/logging.ini +++ b/logging.ini @@ -2,23 +2,23 @@ keys=root,datahandling,instruments [handlers] -keys=fileHandler, consoleHandler +keys=consoleHandler, rootHandler, instrumentsHandler, datahandlingHandler [formatters] keys=myFormatter [logger_root] level=DEBUG -handlers=consoleHandler, fileHandler +handlers=consoleHandler, rootHandler [logger_datahandling] level=INFO -handlers=fileHandler +handlers=datahandlingHandler qualname=datahandling [logger_instruments] level=INFO -handlers=fileHandler +handlers=instrumentsHandler qualname=instruments [handler_consoleHandler] @@ -32,6 +32,21 @@ class=FileHandler formatter=myFormatter args=("config.log",) +[handler_rootHandler] +class=FileHandler +formatter=myFormatter +args=("main_log.txt",) + +[handler_instrumentsHandler] +class=FileHandler +formatter=myFormatter +args=("instruments_log.txt",) + +[handler_datahandlingHandler] +class=FileHandler +formatter=myFormatter +args=("datahandling_log.txt",) + [formatter_myFormatter] -format=[%(asctime)-15s] %(name)-25s %(levelname)-8s %(message)s -datefmt= \ No newline at end of file +format=[%(asctime)-15s] [%(MISSION_TIME)-10s] %(MISSION_ID)-10s %(name)-25s %(levelname)-8s %(message)s +datefmt=%Y-%m-%d %H:%M:%S \ No newline at end of file diff --git a/main.py b/main.py index 3444d4f..46e5e90 100644 --- a/main.py +++ b/main.py @@ -6,29 +6,25 @@ import logging.handlers,logging.config from instruments import Barometer, Camera from datahandling import Datalogger, Datareporter from system import System as System -import threading +from threading import Timer from datahandling import Record from mission import Mission import random import string +# class ContextFilter(logging.Filter): +# """ +# This is a filter which injects contextual information into the log. +# """ +# def filter(self, record): +# record.MYVAR = MYVAR +# return True + logging.config.fileConfig('logging.ini') -log = logging.getLogger(__name__) -# log = logging.basicConfig() -# log1 = logging.getLogger("instruments") -# log2 = logging.getLogger("datahandling") -# handler = logging.handlers.RotatingFileHandler('spaceballoon.log', backupCount=5) - -formatter = logging.Formatter('[%(asctime)-25s] %(name)-15s %(levelname)-8s %(message)s') -# handler.setFormatter(formatter) -# log.addHandler(handler) -# log1.addHandler(handler) -# log2.addHandler(handler) -log.setLevel(logging.DEBUG) -# log1.setLevel(logging.DEBUG) -# log2.setLevel(logging.INFO) - +log = logging.getLogger('root') +log.addFilter(logging.Filter('root')) +# log.addFilter(ContextFilter()) #start-up #log denotes write to local, report denotes sending to server @@ -41,13 +37,13 @@ mission = Mission() reporter = Datareporter ( missiontime = mission, use_lan = True, - url = "http://home.ascorrea.com", + url = url, server_port = 5010, - data_path = "upload-data", - image_path = "missions", - ping_path = "ping", - com_port_name="/dev/ttyAMA0", - baud_rate = 9600 + data_path = data_path, + image_path = image_path, + ping_path = ping_path, + com_port_name=com_port_name, + baud_rate = baud_rate ) t = Record({'zt':mission.timezero}) @@ -61,15 +57,15 @@ notebook = Datalogger ( log_path=log_path, photo_path=photo_path) -log.debug ("System started") +log.debug ("System started", extra={'MISSION_TIME': "", 'MISSION_ID':""}) #system check system = System() -log.debug (system.stats) +log.debug (system.stats, extra={'MISSION_TIME': "", 'MISSION_ID':""}) #set mission time -log.info("Mission {} started, time zero is {}".format(mission.name, mission.timezero)) +log.info("Mission {} started, time zero is {}".format(mission.name, mission.timezero), extra={'MISSION_TIME': mission.now(), 'MISSION_ID':mission.name}) #intiate mission @@ -86,37 +82,55 @@ camera = Camera (low_quality_compression_pct=low_quality_compression_pct, vflip=False, hflip=False, exposure_mode='sports', - # debug=True + debug=True ) #todo test barometer -barometer = Barometer() +barometer = Barometer(debug=True) #todo test GPS, log, report #todo check for errors, throw exception if error -def scheduler (interval, worker_func, iterations = 0): - if iterations != 1: - threading.Timer ( - interval, - scheduler, [interval, worker_func, 0 if iterations == 0 else iterations-1] - ).start () +class scheduler (): - worker_func () + def __init__(self, interval, function, *args, **kwargs): + self._timer = None + self.interval = interval + self.function = function + self.args = args + self.kwargs = kwargs + self.is_running = False + self.start() + def _run(self): + self.is_running = False + self.start() + self.function(*self.args, **self.kwargs) + + def start(self): + if not self.is_running: + self._timer = Timer(self.interval, self._run) + self._timer.start() + self.is_running = True + + def stop(self): + self._timer.cancel() + self.is_running = False def update_barometer_local(): global bar bar = barometer.read() bar.update({'mt':mission.now()}) record = Record(bar.copy(),'b') + log.info('Updating barometer...',extra={'MISSION_TIME': mission.now(), 'MISSION_ID':mission.name}) notebook.log(record) def update_image_local(): global img img = camera.capture(name=mission.now()) record = Record([img.get('hi'), img.get('lo')], 'i') + log.info('Updating image...', extra={'MISSION_TIME': mission.now(), 'MISSION_ID':mission.name}) notebook.log(record) def submit_report(): @@ -128,17 +142,21 @@ def submit_report(): # reporter.create_transpondence() if not transpondence: + log.info('Creating transpondence',extra={'MISSION_TIME': mission.now(), 'MISSION_ID':mission.name}) transpondence = Record() if (counter % refresh_barometer_transmit) == 0: + log.info('Adding barometer data to transpondence',extra={'MISSION_TIME': mission.now(), 'MISSION_ID':mission.name}) transpondence.add(bar,'b') if (counter % refresh_camera_transmit) == 0: + log.info('Adding image to transpondence',extra={'MISSION_TIME': mission.now(), 'MISSION_ID':mission.name}) transpondence.add(img.get('lo'),'i') + log.info('Sending transpondence', extra={'MISSION_TIME': mission.now(), 'MISSION_ID':mission.name}) transpondence = reporter.send(transpondence) #returns none on success, (bad practice?) counter += 1 - log.info('Counter = {}'.format(counter)) + log.debug('Counter = {}'.format(counter), extra={'MISSION_TIME': mission.now(), 'MISSION_ID':mission.name}) counter=1