no message

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"
+data_path = upload-data
-image_path = "missions"
+image_path = missions
-ping_path = "ping"
+ping_path = ping
 
 [local storage settings]
 photo path = /home/pi/scripts/spaceballoon/photos

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:

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):
+    def __init__(self, debug=False):
-        logger.debug("Intializing barometer")
+        logger.debug("Intializing barometer", extra={'MISSION_TIME': "", 'MISSION_ID':""})
-        self.bmp = BMP085.BMP085()
+        if not debug:
-        logger.debug("Barometer intilized")
+            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
+        if not debug:
-        press = self.pressure
+            alt = self.altitude
-        temp = self.temperature
+            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
 

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
+format=[%(asctime)-15s] [%(MISSION_TIME)-10s] %(MISSION_ID)-10s %(name)-25s %(levelname)-8s %(message)s
-datefmt=
+datefmt=%Y-%m-%d %H:%M:%S

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.getLogger('root')
-# log = logging.basicConfig()
+log.addFilter(logging.Filter('root'))
-# log1 = logging.getLogger("instruments")
+# log.addFilter(ContextFilter())
-# 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)
-
 #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",
+    data_path = data_path,
-    image_path = "missions",
+    image_path = image_path,
-    ping_path = "ping",
+    ping_path = ping_path,
-    com_port_name="/dev/ttyAMA0",
+    com_port_name=com_port_name,
-    baud_rate = 9600
+    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):
+class scheduler ():
-  if iterations != 1:
-    threading.Timer (
-      interval,
-      scheduler, [interval, worker_func, 0 if iterations == 0 else iterations-1]
-    ).start ()
 
-  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