log level configuration

This commit is contained in:
Blake Blackshear 2020-12-04 06:59:03 -06:00
parent d304718ea0
commit d60ca9d783
6 changed files with 130 additions and 20 deletions

View File

@ -66,6 +66,11 @@ class FrigateApp():
'frame_queue': mp.Queue(maxsize=2) 'frame_queue': mp.Queue(maxsize=2)
} }
def set_log_levels(self):
logging.getLogger().setLevel(self.config.logger.default)
for log, level in self.config.logger.logs.items():
logging.getLogger(log).setLevel(level)
def init_queues(self): def init_queues(self):
# Queues for clip processing # Queues for clip processing
self.event_queue = mp.Queue() self.event_queue = mp.Queue()
@ -149,6 +154,7 @@ class FrigateApp():
logger.error(f"Error parsing config: {e}") logger.error(f"Error parsing config: {e}")
self.log_process.terminate() self.log_process.terminate()
sys.exit(1) sys.exit(1)
self.set_log_levels()
self.init_queues() self.init_queues()
self.init_database() self.init_database()
self.init_mqtt() self.init_mqtt()

View File

@ -194,6 +194,10 @@ FRIGATE_CONFIG_SCHEMA = vol.Schema(
{ {
vol.Optional('detectors', default=DEFAULT_DETECTORS): DETECTORS_SCHEMA, vol.Optional('detectors', default=DEFAULT_DETECTORS): DETECTORS_SCHEMA,
'mqtt': MQTT_SCHEMA, 'mqtt': MQTT_SCHEMA,
vol.Optional('logger', default={'default': 'info', 'logs': {}}): {
vol.Optional('default', default='info'): vol.In(['info', 'debug', 'warning', 'error', 'critical']),
vol.Optional('logs', default={}): {str: vol.In(['info', 'debug', 'warning', 'error', 'critical']) }
},
vol.Optional('save_clips', default={}): SAVE_CLIPS_SCHEMA, vol.Optional('save_clips', default={}): SAVE_CLIPS_SCHEMA,
vol.Optional('record', default={}): { vol.Optional('record', default={}): {
vol.Optional('enabled', default=False): bool, vol.Optional('enabled', default=False): bool,
@ -224,6 +228,24 @@ class DetectorConfig():
'device': self.device 'device': self.device
} }
class LoggerConfig():
def __init__(self, config):
self._default = config['default'].upper()
self._logs = {k: v.upper() for k, v in config['logs'].items()}
@property
def default(self):
return self._default
@property
def logs(self):
return self._logs
def to_dict(self):
return {
'default': self.default,
'logs': self.logs
}
class MqttConfig(): class MqttConfig():
def __init__(self, config): def __init__(self, config):
@ -728,6 +750,7 @@ class FrigateConfig():
self._mqtt = MqttConfig(config['mqtt']) self._mqtt = MqttConfig(config['mqtt'])
self._save_clips = SaveClipsConfig(config['save_clips']) self._save_clips = SaveClipsConfig(config['save_clips'])
self._cameras = { name: CameraConfig(name, c, config) for name, c in config['cameras'].items() } self._cameras = { name: CameraConfig(name, c, config) for name, c in config['cameras'].items() }
self._logger = LoggerConfig(config['logger'])
def _sub_env_vars(self, config): def _sub_env_vars(self, config):
frigate_env_vars = {k: v for k, v in os.environ.items() if k.startswith('FRIGATE_')} frigate_env_vars = {k: v for k, v in os.environ.items() if k.startswith('FRIGATE_')}
@ -757,13 +780,18 @@ class FrigateConfig():
'detectors': {k: d.to_dict() for k, d in self.detectors.items()}, 'detectors': {k: d.to_dict() for k, d in self.detectors.items()},
'mqtt': self.mqtt.to_dict(), 'mqtt': self.mqtt.to_dict(),
'save_clips': self.save_clips.to_dict(), 'save_clips': self.save_clips.to_dict(),
'cameras': {k: c.to_dict() for k, c in self.cameras.items()} 'cameras': {k: c.to_dict() for k, c in self.cameras.items()},
'logger': self.logger.to_dict()
} }
@property @property
def detectors(self) -> Dict[str, DetectorConfig]: def detectors(self) -> Dict[str, DetectorConfig]:
return self._detectors return self._detectors
@property
def logger(self):
return self._logger
@property @property
def mqtt(self): def mqtt(self):
return self._mqtt return self._mqtt

View File

@ -58,11 +58,11 @@ class LocalObjectDetector(ObjectDetector):
if tf_device != 'cpu': if tf_device != 'cpu':
try: try:
logging.info(f"Attempting to load TPU as {device_config['device']}") logger.info(f"Attempting to load TPU as {device_config['device']}")
edge_tpu_delegate = load_delegate('libedgetpu.so.1.0', device_config) edge_tpu_delegate = load_delegate('libedgetpu.so.1.0', device_config)
logging.info("TPU found") logger.info("TPU found")
except ValueError: except ValueError:
logging.info("No EdgeTPU detected. Falling back to CPU.") logger.info("No EdgeTPU detected. Falling back to CPU.")
if edge_tpu_delegate is None: if edge_tpu_delegate is None:
self.interpreter = tflite.Interpreter( self.interpreter = tflite.Interpreter(
@ -108,7 +108,8 @@ class LocalObjectDetector(ObjectDetector):
def run_detector(name: str, detection_queue: mp.Queue, out_events: Dict[str, mp.Event], avg_speed, start, tf_device): def run_detector(name: str, detection_queue: mp.Queue, out_events: Dict[str, mp.Event], avg_speed, start, tf_device):
threading.current_thread().name = f"detector:{name}" threading.current_thread().name = f"detector:{name}"
logging.info(f"Starting detection process: {os.getpid()}") logger = logging.getLogger(f"detector.{name}")
logger.info(f"Starting detection process: {os.getpid()}")
listen() listen()
stop_event = mp.Event() stop_event = mp.Event()

View File

@ -1,6 +1,7 @@
# adapted from https://medium.com/@jonathonbao/python3-logging-with-multiprocessing-f51f460b8778 # adapted from https://medium.com/@jonathonbao/python3-logging-with-multiprocessing-f51f460b8778
import logging import logging
import threading import threading
import os
import signal import signal
import queue import queue
import multiprocessing as mp import multiprocessing as mp
@ -10,7 +11,7 @@ from logging import handlers
def listener_configurer(): def listener_configurer():
root = logging.getLogger() root = logging.getLogger()
console_handler = logging.StreamHandler() console_handler = logging.StreamHandler()
formatter = logging.Formatter('%(threadName)-25s %(name)-16s %(levelname)-8s: %(message)s') formatter = logging.Formatter('%(name)-30s %(levelname)-8s: %(message)s')
console_handler.setFormatter(formatter) console_handler.setFormatter(formatter)
root.addHandler(console_handler) root.addHandler(console_handler)
root.setLevel(logging.INFO) root.setLevel(logging.INFO)
@ -40,3 +41,35 @@ def log_process(log_queue):
continue continue
logger = logging.getLogger(record.name) logger = logging.getLogger(record.name)
logger.handle(record) logger.handle(record)
# based on https://codereview.stackexchange.com/a/17959
class LogPipe(threading.Thread):
def __init__(self, log_name, level):
"""Setup the object with a logger and a loglevel
and start the thread
"""
threading.Thread.__init__(self)
self.daemon = False
self.logger = logging.getLogger(log_name)
self.level = level
self.fdRead, self.fdWrite = os.pipe()
self.pipeReader = os.fdopen(self.fdRead)
self.start()
def fileno(self):
"""Return the write file descriptor of the pipe
"""
return self.fdWrite
def run(self):
"""Run the thread, logging everything.
"""
for line in iter(self.pipeReader.readline, ''):
self.logger.log(self.level, line.strip('\n'))
self.pipeReader.close()
def close(self):
"""Close the write end of the pipe.
"""
os.close(self.fdWrite)

View File

@ -279,5 +279,41 @@ class TestConfig(TestCase):
} }
self.assertRaises(vol.MultipleInvalid, lambda: FrigateConfig(config=config)) self.assertRaises(vol.MultipleInvalid, lambda: FrigateConfig(config=config))
def test_save_clips_should_default_to_global_objects(self):
config = {
'mqtt': {
'host': 'mqtt'
},
'save_clips': {
'retain': {
'default': 20,
'objects': {
'person': 30
}
}
},
'objects': {
'track': ['person', 'dog']
},
'cameras': {
'back': {
'ffmpeg': {
'inputs': [
{ 'path': 'rtsp://10.0.0.1:554/video', 'roles': ['detect'] }
]
},
'height': 1080,
'width': 1920,
'save_clips': {
'enabled': True
}
}
}
}
config = FrigateConfig(config=config)
assert(len(config.cameras['back'].save_clips.objects) == 2)
assert('dog' in config.cameras['back'].save_clips.objects)
assert('person' in config.cameras['back'].save_clips.objects)
if __name__ == '__main__': if __name__ == '__main__':
main(verbosity=2) main(verbosity=2)

View File

@ -20,6 +20,7 @@ import numpy as np
from frigate.config import CameraConfig from frigate.config import CameraConfig
from frigate.edgetpu import RemoteObjectDetector from frigate.edgetpu import RemoteObjectDetector
from frigate.log import LogPipe
from frigate.motion import MotionDetector from frigate.motion import MotionDetector
from frigate.objects import ObjectTracker from frigate.objects import ObjectTracker
from frigate.util import (EventsPerSecond, FrameManager, from frigate.util import (EventsPerSecond, FrameManager,
@ -73,7 +74,7 @@ def create_tensor_input(frame, region):
# Expand dimensions since the model expects images to have shape: [1, 300, 300, 3] # Expand dimensions since the model expects images to have shape: [1, 300, 300, 3]
return np.expand_dims(cropped_frame, axis=0) return np.expand_dims(cropped_frame, axis=0)
def stop_ffmpeg(ffmpeg_process): def stop_ffmpeg(ffmpeg_process, logger):
logger.info("Terminating the existing ffmpeg process...") logger.info("Terminating the existing ffmpeg process...")
ffmpeg_process.terminate() ffmpeg_process.terminate()
try: try:
@ -85,14 +86,14 @@ def stop_ffmpeg(ffmpeg_process):
ffmpeg_process.communicate() ffmpeg_process.communicate()
ffmpeg_process = None ffmpeg_process = None
def start_or_restart_ffmpeg(ffmpeg_cmd, frame_size=None, ffmpeg_process=None): def start_or_restart_ffmpeg(ffmpeg_cmd, logger, logpipe: LogPipe, frame_size=None, ffmpeg_process=None):
if not ffmpeg_process is None: if not ffmpeg_process is None:
stop_ffmpeg(ffmpeg_process) stop_ffmpeg(ffmpeg_process, logger)
if frame_size is None: if frame_size is None:
process = sp.Popen(ffmpeg_cmd, stdout = sp.DEVNULL, stdin = sp.DEVNULL, start_new_session=True) process = sp.Popen(ffmpeg_cmd, stdout = sp.DEVNULL, stderr=logpipe, stdin = sp.DEVNULL, start_new_session=True)
else: else:
process = sp.Popen(ffmpeg_cmd, stdout = sp.PIPE, stdin = sp.DEVNULL, bufsize=frame_size*10, start_new_session=True) process = sp.Popen(ffmpeg_cmd, stdout = sp.PIPE, stderr=logpipe, stdin = sp.DEVNULL, bufsize=frame_size*10, start_new_session=True)
return process return process
def capture_frames(ffmpeg_process, camera_name, frame_shape, frame_manager: FrameManager, def capture_frames(ffmpeg_process, camera_name, frame_shape, frame_manager: FrameManager,
@ -139,11 +140,12 @@ def capture_frames(ffmpeg_process, camera_name, frame_shape, frame_manager: Fram
class CameraWatchdog(threading.Thread): class CameraWatchdog(threading.Thread):
def __init__(self, camera_name, config, frame_queue, camera_fps, ffmpeg_pid, stop_event): def __init__(self, camera_name, config, frame_queue, camera_fps, ffmpeg_pid, stop_event):
threading.Thread.__init__(self) threading.Thread.__init__(self)
self.name = f"watchdog:{camera_name}" self.logger = logging.getLogger(f"watchdog.{camera_name}")
self.camera_name = camera_name self.camera_name = camera_name
self.config = config self.config = config
self.capture_thread = None self.capture_thread = None
self.ffmpeg_detect_process = None self.ffmpeg_detect_process = None
self.logpipe = LogPipe(f"ffmpeg.{self.camera_name}.detect", logging.ERROR)
self.ffmpeg_other_processes = [] self.ffmpeg_other_processes = []
self.camera_fps = camera_fps self.camera_fps = camera_fps
self.ffmpeg_pid = ffmpeg_pid self.ffmpeg_pid = ffmpeg_pid
@ -158,17 +160,21 @@ class CameraWatchdog(threading.Thread):
for c in self.config.ffmpeg_cmds: for c in self.config.ffmpeg_cmds:
if 'detect' in c['roles']: if 'detect' in c['roles']:
continue continue
logpipe = LogPipe(f"ffmpeg.{self.camera_name}.{'_'.join(sorted(c['roles']))}", logging.ERROR)
self.ffmpeg_other_processes.append({ self.ffmpeg_other_processes.append({
'cmd': c['cmd'], 'cmd': c['cmd'],
'process': start_or_restart_ffmpeg(c['cmd']) 'logpipe': logpipe,
'process': start_or_restart_ffmpeg(c['cmd'], self.logger, logpipe)
}) })
time.sleep(10) time.sleep(10)
while True: while True:
if self.stop_event.is_set(): if self.stop_event.is_set():
stop_ffmpeg(self.ffmpeg_detect_process) stop_ffmpeg(self.ffmpeg_detect_process, self.logger)
for p in self.ffmpeg_other_processes: for p in self.ffmpeg_other_processes:
stop_ffmpeg(p['process']) stop_ffmpeg(p['process'], self.logger)
p['logpipe'].close()
self.logpipe.close()
break break
now = datetime.datetime.now().timestamp() now = datetime.datetime.now().timestamp()
@ -176,13 +182,13 @@ class CameraWatchdog(threading.Thread):
if not self.capture_thread.is_alive(): if not self.capture_thread.is_alive():
self.start_ffmpeg_detect() self.start_ffmpeg_detect()
elif now - self.capture_thread.current_frame.value > 20: elif now - self.capture_thread.current_frame.value > 20:
logger.info(f"No frames received from {self.camera_name} in 20 seconds. Exiting ffmpeg...") self.logger.info(f"No frames received from {self.camera_name} in 20 seconds. Exiting ffmpeg...")
self.ffmpeg_detect_process.terminate() self.ffmpeg_detect_process.terminate()
try: try:
logger.info("Waiting for ffmpeg to exit gracefully...") self.logger.info("Waiting for ffmpeg to exit gracefully...")
self.ffmpeg_detect_process.communicate(timeout=30) self.ffmpeg_detect_process.communicate(timeout=30)
except sp.TimeoutExpired: except sp.TimeoutExpired:
logger.info("FFmpeg didnt exit. Force killing...") self.logger.info("FFmpeg didnt exit. Force killing...")
self.ffmpeg_detect_process.kill() self.ffmpeg_detect_process.kill()
self.ffmpeg_detect_process.communicate() self.ffmpeg_detect_process.communicate()
@ -190,14 +196,14 @@ class CameraWatchdog(threading.Thread):
poll = p['process'].poll() poll = p['process'].poll()
if poll == None: if poll == None:
continue continue
p['process'] = start_or_restart_ffmpeg(p['cmd'], ffmpeg_process=p['process']) p['process'] = start_or_restart_ffmpeg(p['cmd'], self.logger, p['logpipe'], ffmpeg_process=p['process'])
# wait a bit before checking again # wait a bit before checking again
time.sleep(10) time.sleep(10)
def start_ffmpeg_detect(self): def start_ffmpeg_detect(self):
ffmpeg_cmd = [c['cmd'] for c in self.config.ffmpeg_cmds if 'detect' in c['roles']][0] ffmpeg_cmd = [c['cmd'] for c in self.config.ffmpeg_cmds if 'detect' in c['roles']][0]
self.ffmpeg_detect_process = start_or_restart_ffmpeg(ffmpeg_cmd, self.frame_size) self.ffmpeg_detect_process = start_or_restart_ffmpeg(ffmpeg_cmd, self.logger, self.logpipe, self.frame_size)
self.ffmpeg_pid.value = self.ffmpeg_detect_process.pid self.ffmpeg_pid.value = self.ffmpeg_detect_process.pid
self.capture_thread = CameraCapture(self.camera_name, self.ffmpeg_detect_process, self.frame_shape, self.frame_queue, self.capture_thread = CameraCapture(self.camera_name, self.ffmpeg_detect_process, self.frame_shape, self.frame_queue,
self.camera_fps) self.camera_fps)