Fix skipping half recording bug.

This commit is contained in:
yohan 2024-02-10 10:00:12 +01:00
parent 4e3c774d72
commit 2827cf47c7

View File

@ -32,23 +32,34 @@ parser.add_argument("-v", "--verbosity", help="Increase output verbosity",
args = parser.parse_args() args = parser.parse_args()
verbosity = args.verbosity verbosity = args.verbosity
if verbosity == 'DEBUG': logger = logging.getLogger('sensors-polling')
logging.basicConfig(level=logging.DEBUG)
elif verbosity == 'INFO':
logging.basicConfig(level=logging.INFO)
elif verbosity == 'WARNING':
logging.basicConfig(level=logging.WARNING)
logging.info("====== Starting ======") if verbosity == 'DEBUG':
logger.setLevel(logging.DEBUG)
elif verbosity == 'INFO':
logger.setLevel(logging.INFO)
elif verbosity == 'WARNING':
logger.setLevel(logging.WARNING)
# create console handler
ch = logging.StreamHandler()
# create formatter
formatter = logging.Formatter('[%(levelname)s] %(name)s: [%(threadName)s] %(message)s')
# add formatter to ch
ch.setFormatter(formatter)
# add ch to logger
logger.addHandler(ch)
logger.info("====== Starting ======")
stop = Event() stop = Event()
last_data = {} last_data = {}
def handler(signum, frame): def handler(signum, frame):
global stop global stop
logging.info("Got interrupt: "+str(signum)) logger.info("Got interrupt: "+str(signum))
stop.set() stop.set()
logging.info("Shutdown") logger.info("Shutdown")
signal.signal(signal.SIGTERM,handler) signal.signal(signal.SIGTERM,handler)
signal.signal(signal.SIGINT,handler) signal.signal(signal.SIGINT,handler)
@ -82,58 +93,68 @@ def sensors_polling(poller_conf):
while True: while True:
if stop.is_set(): if stop.is_set():
logging.info('Stopping thread '+poller_conf['name']) logger.info('Stopping thread '+poller_conf['name'])
break break
logging.debug('New while loop for '+poller_conf['name']) logger.debug('New while loop for '+poller_conf['name'])
utc_now = datetime.utcnow() utc_now = datetime.utcnow()
now = datetime.now() now = datetime.now()
current_time=time.time() current_time=time.time()
logger.debug('current_time: '+str(current_time))
# Polling # Polling
try: try:
logging.debug('Getting data for '+poller_conf['name']) logger.debug('Getting data for '+poller_conf['name'])
command = [poller_conf['executable']] + poller_conf['arguments'] command = [poller_conf['executable']] + poller_conf['arguments']
returned_output = subprocess.check_output(command) returned_output = subprocess.check_output(command)
data = json.loads(returned_output.decode("utf-8")) data = json.loads(returned_output.decode("utf-8"))
logging.debug('Got: '+returned_output.decode("utf-8")) logger.debug('Got: '+returned_output.decode("utf-8"))
for metric in poller_conf['metrics']: for metric in poller_conf['metrics']:
last_data[metric['name']] = {'value': data[metric['name']], 'timestamp': utc_now.isoformat()} last_data[metric['name']] = {'value': data[metric['name']], 'timestamp': utc_now.isoformat()}
last_polling_time=time.time() last_polling_time=time.time()
logger.debug('last_polling_time: '+str(last_polling_time))
except Exception as e: except Exception as e:
logging.error(e) logger.error(e)
if last_polling_time is None: if last_polling_time is None:
polling_missed = int((current_time - start_time) // polling_interval) polling_missed = int((current_time - start_time) // polling_interval)
else: else:
polling_missed = int((current_time - last_polling_time) // polling_interval) polling_missed = int((current_time - last_polling_time) // polling_interval)
if polling_missed > 0: if polling_missed > 0:
logging.warning("Missed "+str(polling_missed)+" polling iteration(s)") logger.warning("Missed "+str(polling_missed)+" polling iteration(s)")
# Recording # Recording
if last_polling_time is not None and (last_recording_time is None or (current_time - last_recording_time > recording_interval and last_polling_time > last_recording_time + recording_interval/2)): if last_polling_time is not None:
try: if last_recording_time is not None:
for metric in poller_conf['metrics']: recording_interval_elapsed = (current_time - last_recording_time > recording_interval)
logging.debug('Posting data for '+metric['name']) polling_recent_enough = (last_polling_time > last_recording_time + recording_interval/2)
r = s.post(post_url[metric['type']], logger.debug('recording_interval_elapsed: '+str(recording_interval_elapsed))
headers={'User-Agent': 'Mozilla/5.0 (X11; Linux x86_64; rv:75.0) Gecko/20100101 Firefox/75.0', logger.debug('polling_recent_enough: '+str(polling_recent_enough))
'X-API-KEY': recording_api_key}, if last_recording_time is None or (recording_interval_elapsed and polling_recent_enough):
json={'metric': metric['name'], try:
'value': last_data[metric['name']]['value'], for metric in poller_conf['metrics']:
'time': utc_now.isoformat()}) logger.debug('Posting data for '+metric['name'])
if r.status_code != 201: r = s.post(post_url[metric['type']],
logging.error(str(r.status_code)+" "+r.reason) headers={'User-Agent': 'Mozilla/5.0 (X11; Linux x86_64; rv:75.0) Gecko/20100101 Firefox/75.0',
last_recording_time=time.time() 'X-API-KEY': recording_api_key},
except Exception as e: json={'metric': metric['name'],
logging.error(e) 'value': last_data[metric['name']]['value'],
'time': utc_now.isoformat()})
if r.status_code != 201:
logger.error(str(r.status_code)+" "+r.reason)
# It has to be current_time variable so the interval check works correctly
last_recording_time=current_time
logger.debug('last_recording_time: '+str(last_recording_time))
except Exception as e:
logger.error(e)
if last_recording_time is None: if last_recording_time is None:
recording_missed = int((current_time - start_time) // recording_interval) recording_missed = int((current_time - start_time) // recording_interval)
else: else:
recording_missed = int((current_time - last_recording_time) // recording_interval) recording_missed = int((current_time - last_recording_time) // recording_interval)
if recording_missed > 0: if recording_missed > 0:
logging.warning("Missed "+str(recording_missed)+" recording iteration(s)") logger.warning("Missed "+str(recording_missed)+" recording iteration(s)")
# Sleeping # Sleeping
time_to_sleep = polling_interval - ((current_time - start_time) % polling_interval) time_to_sleep = polling_interval - ((current_time - start_time) % polling_interval)
logging.debug('Sleeping '+str(time_to_sleep)+' seconds for '+poller_conf['name']) logger.debug('Sleeping '+str(time_to_sleep)+' seconds for '+poller_conf['name'])
stop.wait(timeout=time_to_sleep) stop.wait(timeout=time_to_sleep)
def metric_list(): def metric_list():
@ -181,7 +202,7 @@ threads = []
for poller_conf in polling_conf: for poller_conf in polling_conf:
threads.append(executor.submit(sensors_polling, poller_conf)) threads.append(executor.submit(sensors_polling, poller_conf))
logging.info("Polling "+str(metric_list())) logger.info("Polling "+str(metric_list()))
while True: while True:
if stop.is_set(): if stop.is_set():
@ -194,11 +215,11 @@ while True:
try: try:
res = thread.exception(timeout=1) res = thread.exception(timeout=1)
if res is not None: if res is not None:
logging.error(res) logger.error(res)
except Exception as e: except Exception as e:
logging.error(e) logger.error(e)
stop.wait(timeout=0.5) stop.wait(timeout=0.5)
logging.info("====== Ended successfully ======") logger.info("====== Ended successfully ======")
# vim: set ts=4 sw=4 sts=4 et : # vim: set ts=4 sw=4 sts=4 et :