Setting SCONS_MSCOMMON_DEBUG to a full path throws exception #4605
Comments
|
I'm struggling to reproduce. Will keep trying... However, the quotes around the filename argument will eventually cause a problem as they are never removed (i.e., not processed like a command-line argument):
EDITED: the second case still had quotes in the assignment (the console test did not). |
|
The double-quoted argument is the problem. The standard python library logging code is: # Issue #27493: add support for Path objects to be passed in
filename = os.fspath(filename)
#keep the absolute path, otherwise derived classes which use this
#may come a cropper when the current directory changes
self.baseFilename = os.path.abspath(filename)Calling absolute path with a filename in quotes goes awry: |
|
If your path has spaces in it, wouldn't you need the quotes when specifying? |
|
The quotes go around the variable and assignment (from the third bullet above): |
|
Let's put it another way.. if some user does what I did, getting a stack trace is pretty unfriendly way of handling that error.. ;) |
|
Sure. AFAIK, # SCONS_MSCOMMON_DEBUG is internal-use so undocumented:
# set to '-' to print to console, else set to filename to log to
LOGFILE = os.environ.get('SCONS_MSCOMMON_DEBUG')I didn't write it: don't shoot the messenger :) An issue (soon to be opened coincidentally) is for sconsflags = os.environ.get('SCONSFLAGS', '')
all_args = sconsflags.split() + sys.argv[1:]
...A user-defined option expecting a windows path with spaces (
Simply splitting |
|
The quoting story continues to be a mess... I just spent a while down that rathole, when I discovered the "quoting rules" in the test framework are different, that is, if you do |
|
And... the code comment about intentionally undocumented (that is, in external docs) is mine, a reminder for times such as this. The concept is not mine :-) |
|
The comments regarding quoting the variable assignment above may be misleading. The quotes need to go around the variable assignment when quotes are needed. However, in many instances, quotes are not needed even when the path contains spaces.
For discussion purposes, a candidate solution is offered. Changes:
Known issues:
Branch https://github.com/jcbrill/scons/tree/jbrill-mscommon-debug: Limited tests https://github.com/jcbrill/scons-prototypes/tree/main/scons/scons-issue-4605:
Examples:
Enjoy |
|
@jcbrill - probably worth promoting such issue to be an error. No one wants to set it wrong, run a non-trivial build and then find out the log wasn't created? (under the fail fast if you're going to fail category).. |
I'm not clear which issue is worth promoting to an error. The biggest fear is that there are false positives in the invalid path/file detection. That is, a file name path is declared to be invalid but the logging file handler does not raise an exception upon creation. Originally, the code only issued an invalid file name warning after an exception was raised (i.e., the exception was caught, a warning issued if necessary, and the exception was re-raised). I was surprised by the behavior with the colon in the file name and learned a bit about ntfs alternate data streams. The sequence changed to: issue a warning if necessary, create the file handler which might fail. It might take a bit of work to isolate individual causes and treat them as errors instead of warnings. There are a whole class of errors where there will be no warning and the logging file handler will fail resulting in only a traceback. The most prominent of these is due to lack of permissions (i.e., the file name path is valid, but attempts to write to a location for which the process does not have sufficient permissions). |
|
I'm getting a headache, which is not unusual when Windows is involved. The problem comes from the way an environment variable is set in the |
|
@jcbrill - any time the specified SCONS_MSCOMMON_DEBUG is invalid for any reason, it's not going to log, so best to error? |
That is my understanding as well.
Yes. Occasionally, end users are asked to define SCONS_MSCOMMON_DEBUG and post the log. Anecdotally, it seems more typical to set it to a file name like
If the SCONS_MSCOMMON_DEBUG specification is truly invalid, an exception will be raised by the standard python logging module when the file handler is created due to the file open invocation failing. The exception is not suppressed. As noted in the top post, this may not be particularly illuminating. From the top post: The error message is somewhat confusing, but the double quotes are a clue. The standard library is simply calling The intent of the warning in the demonstration is to give more diagnostic information on the way out. Hopefully providing just enough information to know why it failed. So instead of just a traceback like this: One would get a warning message first, like this: Demonstration code alternatives:
A file specification enclosed in double quotes will yield a warning that the quotes were stripped. This does not guarantee success, just that the leading and trailing quotes were removed. It is entirely possible another warning and logging exception will occur when the log file handler is created. I'm also onboard with doing nothing. False Positive - Alternate Data Streams The case that was new to me, involves alternate data streams. This was the motivation for moving the warning out of the exception handler and before the log file creation call. This was before I understood what exactly was happening with the alternate data streams. Since this actually behaves in a manner that is consistent with the file specification, it may be worth changing back to just producing invalid file name warnings inside the exception handler on the way out (i.e., the original method). Example: A warning is produced, but the file open succeeds (false positive). The only file that appears in File Explorer and a However, The log file was actually written to the alternate data stream. When file
The warning really is a false positive. But unless you are aware of the alternate data stream behavior, it looks like an empty partially named output file was created. There does not seem to be any compelling reason why you would intentionally want this behavior. Other than the drive specification, I'm not sure a typo using a colon would be very frequent. |
|
Below are the simplest possible standalone code examples to illustrate the concepts raised in the discussion above. In all source code examples below, and in current SCons, when The outstanding question is if, and when, a warning message issued prior to the exception message and traceback might be useful to an end user. The branch referenced above is similar to method 2 [Item 4 below]. However, I am now strongly leaning towards method 1 [Item 3 below]. I'm also OK with chalking this and similar future issues up to invalid input and doing nothing. A. Mininal Standalone Source Code ExamplesAll source code examples are module-level code executed when the module is loaded mirroring the current SCons behavior. Annotated source code examples:
B. Sample Console SessionsTests:
|
|
|
|
I'd also say we have the option of catching the logging module's exception and re-raising it as a |
|
I think there are three exceptions that can occur - as shown above, what's eventually deduced as invalid gets an |
My current view is if we can't give the user a reason for WHY the logging module couldn't open the file, we shouldn't do anything. If there is no value added by catching an exception and raising it again (different exception class or not) without any new relevant information, what's the point? In this case, it might be preferable to know exactly where it emanated from in the logging module. The first line of the issue report above (kudos to @bdbaddog for including the relevant detail) included the actual input value used:
Upon initial reading, the root cause was hinted at:
The issue report exception is: In this case, the double quote characters are a red flag as would some other characters (e.g., "?", "|", "<", ">", etc). The logging module is simply using an absolute path (pseudo-code): Since the user file name is not an absolute or network path, it is treated as relative to the current directory. The root cause was determined pretty quickly from first read using the bug report and the traceback. Common reasons for failure are:
In order to tell a user why the open failed, one has to evaluate the absolute path of the input value. As mentioned, the error class can provide clues. Easy enough to determine after-the-fact:
Harder and probably not worth the effort:
Issuing a warning just prior to the exception may provide enough information for an end user to figure out the problem by themselves. If this can't be done or deemed not worth the effort, then I'm not sure anything else is particularly useful to an end user (or a developer). The irony being that we can't use the debug log to figure it out. There may be peculiarities to the windows rules that may not exist on other platforms. P.S.: I'm not grumpy, I swear. Interest in this particular problem is waning though which is a me problem. |
Yeah, it's not worth doing much more here. A simple quote stripper for the Windows case might be worthwhile; I can't make the same thing happen on Linux at all. Let's wait to see how @bdbaddog wants to proceed.
I think a message like "malformed settings, unable to create logging file" is better than the current long backtrace, but only marginally so. |
Probably a good idea to propagate the underlying error code (and possibly the class name) from the original logging exception as that is generally really useful information. Possibly 19 (original) vs 17 (new) stack levels (might be off by 1). It doesn't help that this is module-level code executed when imported/loaded which lengthens the call chain. |
|
C:\Users\mats\Documents\github\scons\exp\envdump>py ../../scripts/scons.py
scons: Reading SConscript files ...
scons: *** Could not create logfile, check SCONS_MSCOMMON_DEBUG
File "<frozen importlib._bootstrap>", line 241, in _call_with_frames_removed |
|
Changes inspired by previous post:
Warning and Error examples:
|
|
Code fragments for above:
|
|
Those two are fine by me. Guess the style question is:
Probably this is minor enough it makes little difference in practice which is chosen. @bdbaddog ? |
@jcbrill option 2, simpler, and can handle other user errors in specifying the log file |
|
Just to be clear... The following two questions take place at different times/locations in the code. The are not mutually exclusive. Q1: Is there a desire to auto-remove leading and trailing quotes and issue a warning upon reading SCONS_MSCOMMON_DEBUG?
Q1 is strictly about detecting a value enclosed in double quotes. Both the leading and trailing double quote characters are removed, a warning is issued, proceed with the modified value (which may end up being an empty string which would bypass log creation). From the initial comments from @bdbaddog, I thought this was desired. I'm ambivalent about Q1. Anecdote: Never with files, but I am pretty sure that at least once I have enclosed the stdout file value ("-") in quotes (i.e., Q2: Is there a desire to rewrite the logging module exception into a UserError exception presenting the SCONS_MSCOMMON_DEBUG value and preserving the logging module exception information?
Q2 is strictly about making the logging module exception and traceback more palatable: catch the exception, format an SCons UserError message containing the value of SCONS_MSCOMMON_DEBUG value, the logging module exception class name, and the logging module exception string (error code and text). This is effectively all of the pertinent information that the logging module exception and traceback would provide in a far more compact and readable format. Thanks to @mwichmann for the example above. No attempt is made to fix the issue or detect why the file name may be invalid. The lengthy traceback is eliminated. This matches the box check by @bdbaddog above. The post above (#4605 (comment)) shows most of the typical logging exceptions that arise: OSError (e.g., invalid file name), FileNotFoundError (e.g., reserved name), and PermissionError (e.g., directory path instead of file path). I think this is far more useful to an end user. I'm pretty sure we all want Q2.
EDIT: didn't actually answer @mwichmann question Q1 SCONS_MSCOMMON_DEBUG value enclosed in double quotes:
Q2 Logging module exceptions:
|
|
Revised
Revised style question for
Changes to main branch:
Possible enhancements:
|
Describe the bug
set SCONS_MSCOMMON_DEBUG="C:\builds\scons\debug.txt"
And you'll get an exception like this.
Apparently the logic is trying to add the debug file to the path of the current SConscript.
Required information
n/a
4.8.0
3.11.4
Python.org
pip
Win 10
See above
py -3 -mSCons
The text was updated successfully, but these errors were encountered: