Tor sometimes loses the last few log lines on shutdown on macOS
There seems to be a race condition between writing log lines to log files, and some other tor shutdown/free/process termination.
When I'm using chutney on macOS 10.12, I see these log lines in 000a:
Sep 19 10:53:00.280 [notice] Interrupt: we have stopped accepting new connections, and will shut down in 2 seconds. Interrupt again to exit now.
Sep 19 10:53:00.870 [notice] Time to fetch any signatures that we're missing.
Sep 19 10:53:01.871 [notice] Time to publish the consensus and discard old votes
Sep 19 10:53:01.874 [notice] Published ns consensus
Sep 19 10:53:01.876 [notice] Choosing expected valid-after time as 2017-09-19 00:53:10: consensus_set=1, interval=10
Sep 19 10:53:01.876 [notice] Published microdesc consensus
Sep 19 10:53:01.879 [notice] Choosing expected valid-after time as 2017-09-19 00:53:10: consensus_set=1, interval=10
Sep 19 10:53:01.879 [notice] Choosing expected valid-after time as 2017-09-19 00:53:10: consensus_set=1, interval=10
But these lines in 001a:
Sep 19 10:53:00.281 [notice] Interrupt: we have stopped accepting new connections, and will shut down in 2 seconds. Interrupt again to exit now.
Sep 19 10:53:01.037 [notice] Time to publish the consensus and discard old votes
Sep 19 10:53:01.039 [notice] Published ns consensus
Sep 19 10:53:01.040 [notice] Choosing expected valid-after time as 2017-09-19 00:53:10: consensus_set=1, interval=10
Sep 19 10:53:01.041 [notice] Published microdesc consensus
Sep 19 10:53:01.043 [notice] Choosing expected valid-after time as 2017-09-19 00:53:10: consensus_set=1, interval=10
Sep 19 10:53:01.043 [notice] Choosing expected valid-after time as 2017-09-19 00:53:10: consensus_set=1, interval=10
Sep 19 10:53:02.038 [notice] Clean shutdown finished. Exiting.
Sep 19 10:53:02.038 [notice] SIGINT received a second time; exiting now.
But as far as I can tell, both are executing exactly the same code.