I'm guessing that the mixin works when you choose to shutdown from the OctoPrint system menu.
Here is the stop section of OctoPrint's service handler /etc/init.d/octoprint:
# 0 if daemon has been stopped
# 1 if daemon was already stopped
# 2 if daemon could not be stopped
# other if a failure occurred
start-stop-daemon --stop --quiet --retry=TERM/30/KILL/5 --user $OCTOPRINT_USER --pidfile $PIDFILE
[ "$RETVAL" = "2" ] && return 2
rm -f $PIDFILE
[ "$RETVAL" = "0" ] && return 0 || return 1
This means that the service handler already uses SIGTERM with a 30-second timeout then changes to SIGKILL if that didn't work.
Here's a bit of code which isn't firing off within my own class. So the plugin isn't getting asked to die, for example. Earlier, this was just def on_shutdown(self): and the mixin mentioned was added in the class creation line.
self._logger.info('Setting stop flag and closing USB receiver...')
self.bStop = True
It is using the event mixin as well and it's not firing off the shutdown message unless you choose the restart on the web interface. If you choose the service handler for OctoPrint, it's not firing off.
Alright, I turned on DEBUG logging for octoprint.server and octoprint.events, restarting OP from the system menu option:
As seen from the system menu version:
2020-04-20 09:39:26,776 - octoprint.server.api.system - INFO - Performing command for core:restart: sudo service octoprint restart
2020-04-20 09:39:26,981 - octoprint.server - DEBUG - SIGTERM received...
2020-04-20 09:39:26,983 - octoprint.server - DEBUG - Shutting down tornado's IOLoop...
2020-04-20 09:39:26,984 - octoprint.server - DEBUG - Tornado's IOLoop stopped
2020-04-20 09:39:26,985 - octoprint.server - INFO - Shutting down...
2020-04-20 09:39:27,349 - octoprint.events - INFO - Processing shutdown event, this will be our last event
2020-04-20 09:39:27,350 - octoprint.events.fire - DEBUG - Firing event: Shutdown (Payload: None)
2020-04-20 09:39:27,350 - octoprint.events - DEBUG - Sending action to <bound method PrinterStateConnection._onEvent of <octoprint.server.util.sockjs.PrinterStateConnection object at 0x6af4c9f0>>
2020-04-20 09:39:27,355 - octoprint.events - INFO - Event loop shut down
2020-04-20 09:39:27,366 - octoprint.server - INFO - Goodbye!
As seen from the service handler:
# This is my promiscuously-logging on_event() handler to log all events seen
2020-04-20 09:39:48,711 - octoprint.plugins.xbox - INFO - on_event FirmwareData
# I then sudo service octoprint stop from the command line:
2020-04-20 09:40:21,082 - octoprint.server - DEBUG - SIGTERM received...
2020-04-20 09:40:21,083 - octoprint.server - DEBUG - Shutting down tornado's IOLoop...
2020-04-20 09:40:21,084 - octoprint.server - DEBUG - Tornado's IOLoop stopped
So the shutdown events/hooks are done here. I can't seem to make the problem happen but am also having an issue with the debugger at that point in the process. Perhaps there is a race condition that is occurring but am not sure yet.
Basically, I think that my earlier post was the smoking gun: externally SIGTERM'ing the octoprint service doesn't reach the on_shutdown() code so it doesn't fire the related event. Exercising the web interface instead starts with on_shutdown() so everything fires as expected.