Kitchen Kiosk

-""") - f.write(f'{pageid} @ {age} ago.') - f.write( """ + ) + f.write(f"{pageid} @ {age} ago.") + f.write( + """

""" + ) +def renderer_update_internal_stats_page( + last_render: Dict[str, datetime], + render_counts: collections.Counter, + render_times: Dict[str, np.array], +) -> None: + logger.info("Updating internal render statistics page.") + with file_writer.file_writer(kiosk_constants.render_stats_pagename) as f: + f.write( + """ + + + + + + + + +""" + ) + for n, r in enumerate(renderer_catalog.get_renderers()): + if n % 2 == 0: + style = 'style="margin: 0; padding: 0; background: #c6b0b0;"' + else: + style = 'style="margin: 0; padding: 0; background: #eeeeee;"' + name = r.get_name() + last = last_render.get(name, None) + if last is None: + last = "never" + else: + last = last.strftime("%Y/%m/%d %I:%M:%S%P") + count = render_counts.get(name, 0) + latency = render_times.get(name, np.array([])) + p25 = p50 = p75 = p90 = p99 = "N/A" + try: + p25 = np.percentile(latency, 25) + p50 = np.percentile(latency, 50) + p75 = np.percentile(latency, 75) + p90 = np.percentile(latency, 90) + p99 = np.percentile(latency, 99) + f.write( + f""" + + + + + + +""" + ) + except IndexError: + pass + f.write("

Renderer Name	Last Run	Num Invocations	Render Latency
{name}	{last}	{count}	p25={p25:5.2f}, p50={p50:5.2f}, p75={p75:5.2f}, p90={p90:5.2f}, p99={p99:5.2f}

") + + +@logging_utils.LoggingContext(logger, prefix="renderer:") def thread_invoke_renderers() -> None: render_times: Dict[str, np.array] = {} render_counts: collections.Counter = collections.Counter() last_render: Dict[str, datetime] = {} + # Touch the internal render page now to signal that we're alive. + renderer_update_internal_stats_page(last_render, render_counts, render_times) + + # Main renderer loop while True: - print(f'renderer[{utils.timestamp()}]: invoking all overdue renderers in catalog...') + logger.info("invoking all overdue renderers in catalog...") for r in renderer_catalog.get_renderers(): name = r.get_name() now = time.time() + logger.info(f"Invoking {name}'s render method.") try: r.render() except Exception as e: - traceback.print_exc(file=sys.stdout) logger.exception(e) - print( - f"renderer[{utils.timestamp()}] Unknown exception ({e}) in {name}, swallowing it." + logger.error( + f"Unexpected and unhandled exception ({e}) in {name}, swallowing it." ) + continue # Increment the count of render operations per renderer. render_counts[name] += 1 # Keep track of the last time we invoked each renderer. - last_render[name] = datetime.now(tz=pytz.timezone("US/Pacific")) + last_render[name] = datetime_utils.now_pacific() # Record how long each render operation takes and warn if very long. delta = time.time() - now @@ -539,101 +694,88 @@ def thread_invoke_renderers() -> None: times = np.insert(times, 0, delta) render_times[name] = times if delta > 1.0: - hdr = f'renderer[{utils.timestamp()}]:' - print( -f''' -{hdr} Warning: {name}'s rendering took {delta:5.2f}s. -{hdr} FYI: {name}'s render times: p25={np.percentile(times, 25):5.2f}, p50={np.percentile(times, 50):5.2f}, p75={np.percentile(times, 75):5.2f}, p90={np.percentile(times, 90):5.2f}, p99={np.percentile(times, 99):5.2f} -''') - - # Render a page about internal stats of renderers. - print(f'renderer[{utils.timestamp()}]: Updating internal statistics page.') - with file_writer.file_writer(constants.internal_stats_pagename) as f: - f.write( -f''' - - - - - - - - -''') - for n, r in enumerate(renderer_catalog.get_renderers()): - if n % 2 == 0: - style = 'style="margin: 0; padding: 0; background: #c6b0b0;"' - else: - style = 'style="margin: 0; padding: 0; background: #eeeeee;"' - name = r.get_name() - last = last_render.get(name, None) - if last is None: - last = 'never' - else: - last = last.strftime('%Y/%m/%d %I:%M:%S%P') - count = render_counts.get(name, 0) - latency = render_times.get(name, np.array([])) - p25 = p50 = p75 = p90 = p99 = 'N/A' - try: - p25 = np.percentile(latency, 25) - p50 = np.percentile(latency, 50) - p75 = np.percentile(latency, 75) - p90 = np.percentile(latency, 90) - p99 = np.percentile(latency, 99) - except IndexError: - pass - f.write( -f''' - - - - - - -''') - f.write('

Renderer Name	Last Run	Num Invocations	Render Latency
{name}	{last}	{count}	p25={p25:5.2f}, p50={p50:5.2f}, p75={p75:5.2f}, p90={p90:5.2f}, p99={p99:5.2f}

') + logger.warning( + f""" +Warning: {name}'s rendering took {delta:5.2f}s. +FYI: {name}'s render times: p25={np.percentile(times, 25):5.2f}, p50={np.percentile(times, 50):5.2f}, p75={np.percentile(times, 75):5.2f}, p90={np.percentile(times, 90):5.2f}, p99={np.percentile(times, 99):5.2f} +""" + ) - print( - f"renderer[{utils.timestamp()}]: " + - f"thread having a little break for {constants.render_period_sec}s..." - ) - time.sleep(constants.render_period_sec) + # Update a page about internal stats of renderers. + renderer_update_internal_stats_page(last_render, render_counts, render_times) + logger.info("Having a little nap...") + time.sleep(kiosk_constants.render_period_sec) -if __name__ == "__main__": - logging.basicConfig() +@bootstrap.initialize +def main() -> None: command_queue: Queue = Queue() changer_thread: Optional[Thread] = None renderer_thread: Optional[Thread] = None janitor_thread: Optional[Thread] = None hotword_thread: Optional[Thread] = None - while True: - if hotword_thread is None or not hotword_thread.is_alive(): - keyword_paths = [pvporcupine.KEYWORD_PATHS[x] for x in ["bumblebee"]] - sensitivities = [0.7] * len(keyword_paths) - listener = listen.HotwordListener( - command_queue, - keyword_paths, - sensitivities, - ) - hotword_thread = Thread(target=listener.listen_forever, args=()) - hotword_thread.start() - if changer_thread is None or not changer_thread.is_alive(): - print( - f"MAIN[{utils.timestamp()}] - (Re?)initializing chooser thread... (wtf?!)" - ) - changer_thread = Thread(target=thread_change_current, args=(command_queue,)) - changer_thread.start() - if renderer_thread is None or not renderer_thread.is_alive(): - print( - f"MAIN[{utils.timestamp()}] - (Re?)initializing render thread... (wtf?!)" - ) - renderer_thread = Thread(target=thread_invoke_renderers, args=()) - renderer_thread.start() - if janitor_thread is None or not janitor_thread.is_alive(): - print( - f"MAIN[{utils.timestamp()}] - (Re?)initializing janitor thread... (wtf?!)" - ) - janitor_thread = Thread(target=thread_janitor, args=()) - janitor_thread.start() - time.sleep(60) + + with logging_utils.LoggingContext(logger, prefix="watchdog:"): + while True: + if hotword_thread is None or not hotword_thread.is_alive(): + if hotword_thread is None: + logger.info("Starting up the hotword detector thread...") + else: + logger.warning( + "The hotword detector thread seems to have died; restarting it and hoping for the best." + ) + keyword_paths = [pvporcupine.KEYWORD_PATHS[x] for x in ["bumblebee"]] + + # Sensitivity is the parameter that enables trading + # miss rate for the false alarm rate. It is a floating + # point number within [0, 1]. A higher sensitivity + # reduces the miss rate at the cost of increased false + # alarm rate. + sensitivities = [0.4] * len(keyword_paths) + listener = listen.HotwordListener( + command_queue, + keyword_paths, + sensitivities, + ) + hotword_thread = Thread(target=listener.listen_forever, args=()) + hotword_thread.start() + + if changer_thread is None or not changer_thread.is_alive(): + if changer_thread is None: + logger.info("Starting up the current page changer thread...") + else: + logger.warning( + "The current page changer thread seems to have died; restarting it and hoping for the best." + ) + changer_thread = Thread( + target=thread_change_current, args=(command_queue,) + ) + changer_thread.start() + + if renderer_thread is None or not renderer_thread.is_alive(): + if renderer_thread is None: + logger.info("Starting up the page renderer thread...") + else: + logger.warning( + "The page renderer thread seems to have died; restarting it and hoping for the best." + ) + renderer_thread = Thread(target=thread_invoke_renderers, args=()) + renderer_thread.start() + + if janitor_thread is None or not janitor_thread.is_alive(): + if janitor_thread is None: + logger.info("Starting up the memory janitor thread...") + else: + logger.warning( + "The memory janitor thread seems to have died; restarting it and hoping for the best." + ) + janitor_thread = Thread(target=thread_janitor, args=()) + janitor_thread.start() + + # Have a little break and then check to make sure all threads are still alive. + logger.debug("Having a little nap...") + time.sleep(kiosk_constants.check_threads_period_sec) + + +if __name__ == "__main__": + main()