Stop a bad log file path from taking the system down with it - #235
Closed
iTechMedic wants to merge 3 commits into
Closed
iTechMedic wants to merge 3 commits into
iTechMedic wants to merge 3 commits into
Conversation
A user reported a Pi that had gone slow and had no log file. His log path was "0:/SD:/usbode-logs.txt" - which the web form built for him out of "SD:/usbode-logs.txt", by pasting "0:/" on the front of anything that did not already start with it. That path cannot be opened, and everything that follows from a failed open was wrong. The cost. Run() backed off 20 ms whenever a message failed to reach the file, which is right for a write that might succeed next time and useless when there is no file at all: every message failed, so the log queue retired 50 events a second, on a scheduler task, and dragged the rest of the system along with it. The daemon now distinguishes a transient write failure from having no file to write to, and only pays for the first. The hazard. m_bFileInitialized had no initializer and was not in the constructor's init list, so on the failing path it held whatever was in that memory. Non-zero meant LogMessage() wrote to an unopened FIL and the destructor closed one. The silence. Initialize()'s result was discarded by the constructor, which was itself discarded by the caller, and the message it did log named neither the path nor the reason. Boot now says which file it could not open, with the FatFs error, and where to go and fix it. The path itself was borrowed rather than copied, from the config store, which is free to replace it while the daemon is still running - and does, when the log path is edited from the web UI. Validation moves to where the bad value came from. The form now strips whatever volume the user typed, refuses one that is not the boot partition (only 0: is mounted when the daemon starts), refuses a directory or a leftover colon, and checks that the parent directory exists - FatFs will not create one, so a path under a missing directory is accepted and then fails at every boot with nothing to show for it. An empty value now means "off", which the page already displayed but the write path ignored, so the setting could not be cleared. The daemon is now compiled into the host test suite, which needed a real event queue on the logger stub, a sleep counter on the scheduler stub, and write support in the FatFs shim. Four of the five fixes are pinned by a test that goes red when the fix is reverted; the uninitialised flag is a bool, so reading a poisoned one is undefined and no assertion can pin it - the sanitizer build names all three read sites instead, and the README now says so. Also drops an unused LOG_FILE define in kernel.cpp that named a different file from the actual default.
The help text still promised the old behaviour - that whatever you type gets 0:/ pasted on the front - which is exactly how the reported bad value was produced. It now says what is actually accepted.
Found by David testing the reported bad path on hardware: he set logfile=0:/SD:/usbode-logs.txt, rebooted, and "didn't see any warning". The warning was emitted - to the serial console, which is the only target a SCREEN_HEADLESS build has. So the config page went on presenting a log path that was doing nothing, which is the situation this whole fix exists to end. The config page now shows the daemon's live status next to the path, in red when the file could not be opened, naming the path and the FatFs error. The log viewer had two problems of its own. It opened a hardcoded "/usbode-logs.txt" regardless of what was configured, so anyone who set a different path got a blank page and no hint they were looking in the wrong place; it now reads the configured file. And a missing log file rendered exactly like an empty one - nothing at all - so it now says why there is nothing to show. Both take the text from the daemon rather than working it out for themselves, so the two pages cannot drift apart or from what the daemon actually did.
Collaborator
Author
|
Superseded by #238, which combines this with the rest of the batch into a single branch. Same commits, no changes dropped. Closing this one. |
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
1 participant
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
Three commits. This started from a user report: a Pi that had gone slow and had no log file.
His log path was
0:/SD:/usbode-logs.txt, which the web form built for him out ofSD:/usbode-logs.txtby pasting0:/on the front of anything that did not already start with it. That path cannot be opened, and everything that followed from the failed open was wrong.The cost.
Run()backed off 20 ms whenever a message failed to reach the file. That is right for a write that might succeed next time and useless when there is no file at all: every message failed, so the log queue retired 50 events a second, on a scheduler task, and dragged the rest of the system along with it. That is the reported slowness. The daemon now distinguishes a transient write failure from having no file to write to, and only pays for the first.The hazard.
m_bFileInitializedhad no initializer and was not in the constructor's init list, so on the failing path it held whatever was in that memory. Non zero meantLogMessage()wrote to an unopenedFILand the destructor closed one.The silence.
Initialize()'s result was discarded by the constructor, which was itself discarded by the caller, and the message it did log named neither the path nor the reason. Boot now says which file it could not open, with the FatFs error, and where to go and fix it.The form. It now normalises what you type rather than prefixing it blindly, rejects a volume other than 0 (only 0: is mounted when the daemon starts), rejects a parent directory that does not exist, and honours an empty value as "logging off" instead of ignoring it.
Making it visible. Testing the fix on hardware found the last gap: the boot warning went only to the serial console, which is the only target a SCREEN_HEADLESS build has, so from the web UI nothing had changed. The config page now shows the daemon's live status next to the path, in red when the file could not be opened. The log viewer had opened a hardcoded
/usbode-logs.txtregardless of configuration, so anyone with a different path saw a blank page and no hint why; it now reads the configured file and says when there is nothing to show.Both pages take their text from the daemon rather than working it out themselves, so they cannot drift from what it actually did.
Six new tests, including one that pins the specific regression: 200 events against an unopenable path must drain without a single scheduler sleep. This needed some harness work to compile the daemon on the host, which is included.
Host suite 153/153.