bpo-46742: Add "-d 123" / "--trace_fd 123" option to the trace module… #31319

PenelopeFudd · 2022-02-13T22:23:54Z

… to send trace logs to a different file descriptor.

Note: this does an fdopen on every write, because I could not find a way to do self.trace_fp = os.fdopen(trace_fd,"w",closefd=False) without triggering a warning from pytest about an unclosed file pointer (e.g. a file pointer leak). Creating an exit() function to close self.trace_fp didn't appear to work. Fortunately, os.fdopen() is not a very cpu-intensive function.

https://bugs.python.org/issue46742

… to send trace logs to a different file descriptor.

the-knights-who-say-ni · 2022-02-13T22:23:58Z

Hello, and thanks for your contribution!

I'm a bot set up to make sure that the project can legally accept this contribution by verifying everyone involved has signed the PSF contributor agreement (CLA).

CLA Missing

Our records indicate the following people have not signed the CLA:

@PenelopeFudd

For legal reasons we need all the people listed to sign the CLA before we can look at your contribution. Please follow the steps outlined in the CPython devguide to rectify this issue.

If you have recently signed the CLA, please wait at least one business day
before our records are updated.

You can check yourself to see if the CLA has been received.

Thanks again for the contribution, we look forward to reviewing it!

PenelopeFudd · 2022-02-22T17:42:04Z

Ping...?

PenelopeFudd · 2022-03-01T20:41:42Z

Ping?

PenelopeFudd · 2022-03-25T22:01:11Z

Ok, it's been 40 days, the automated checks appear to be jammed. :-(

PenelopeFudd · 2022-03-25T22:46:21Z

If you can see a way to eliminate the "calling-fdopen-on-every-message" while keeping pytest happy, I'll gladly incorporate it.

PenelopeFudd · 2022-03-30T16:47:39Z

Ping?

PenelopeFudd · 2022-04-04T21:32:19Z

¿ƃuıԀ

PenelopeFudd · 2022-04-11T17:48:54Z

I apologize, but I don't actually know what the next step is to get this approved and merged. Can you tell me?

PenelopeFudd · 2022-04-26T19:26:49Z

@abalkin , are you available for a code review? :-)

AlexWaygood · 2022-04-26T19:38:41Z

@serhiy-storchaka, it looks like you've done a fair bit of work on the trace module over the years -- could you possibly take a look at this, if you have the time?

AlexWaygood · 2022-04-26T19:41:01Z

Apologies for the delay, @PenelopeFudd -- the truth of the matter is that there is a sizeable PR backlog, that CPython is maintained by volunteers, and that there aren't enough maintainers to review all of the PRs that come through. The lack of response is not necessarily a comment on the merits of your PR :)

(I don't know enough about the trace module to review, I'm afraid.)

PenelopeFudd · 2022-04-27T01:18:07Z

Fortunately, it was a straightforward change: Before this, the trace gets sent to standard output, where it swamps the program's regular output.

With bash, the trace function's output is written to stderr (fd=2), with an option to write to another file descriptor by setting a reserved shell variable:

$ man bash
...
       BASH_XTRACEFD
              If set to an integer corresponding to a valid file
              descriptor, bash will write the trace output generated
              when set -x is enabled to that file descriptor.  The file
              descriptor is closed when BASH_XTRACEFD is unset or
              assigned a new value.  Unsetting BASH_XTRACEFD or
              assigning it the empty string causes the trace output to
              be sent to the standard error.  Note that setting
              BASH_XTRACEFD to 2 (the standard error file descriptor)
              and then unsetting it will result in the standard error
              being closed.

I didn't want the program's output to be swamped, and redirecting to a specified file descriptor seems to be an acceptable method. Setting a reserved variable like bash does seemed like a hack, so I made it a CLI option instead:

# Before:
python -m trace -t somefile.py ...

# After:
python -m trace -t -d 123 somefile.py ...  123>my-trace-file.out

I was tempted to change the default behaviour to send the trace output to stderr (like bash), but there are lots of people whose trace-handling programs would stop working because of that change.

PenelopeFudd · 2022-04-27T01:38:36Z

There's only one thing about my code that I am not happy about.

Initially I called fdopen once (to make a file object out of the file descriptor), and put the resulting file object into an instance variable, but pylint objected strongly because I wasn't freeing the file object afterwards. I did have code that said "if the file object is already defined, don't run fdopen", but pylint didn't care, or perhaps didn't notice.

I googled a fair bit, but wasn't able to find a good way to satisfy pylint. I resorted to running fdopen for every print statement. I could only justify it to myself by realizing that fdopen is not calling the operating system; it's taking an already-open file descriptor and making a file object out of it, which should be a fairly fast function.

However, if you've got a better way, I'd love to implement it.

serhiy-storchaka · 2022-04-27T06:10:25Z

Doc/library/trace.rst

@@ -96,6 +96,15 @@ Modifiers
   Directory where the report files go.  The coverage report for
   ``package.module`` is written to file :file:`{dir}/{package}/{module}.cover`.

+.. cmdoption:: -d, --trace_fd


Mixing - and _ looks weird. Either use minus, --trace-fd (like --no-report) or omit the separator, --tracefd (like --listfuncs, --trackcalls, --coverdir).

Also specify that the option takes an argument: --tracefd=<fd>.

I am not sure that it is necessary to add a short option. The set of letters is limited, and -d could be used for more popular option ("directory" or "description" or "delete").

serhiy-storchaka · 2022-04-27T06:14:58Z

Lib/trace.py

@@ -385,14 +385,16 @@ def _find_executable_linenos(filename):
    return _find_lines(code, strs)

 class Trace:
-    def __init__(self, count=1, trace=1, countfuncs=0, countcallers=0,
+    def __init__(self, count=1, trace=1, trace_fd=1, countfuncs=0, countcallers=0,


Adding a parameter before other positional parameters is a breaking change. It will break a code which calls Trace() with 3 or more positional arguments.

Add it at the end of parameters, and better make it keyword-only. 10 positional parameters is too much.

Also not that no other parameter has _ in the name, even if they are a combination of words.

Ok, fixing this.

serhiy-storchaka · 2022-04-27T06:25:15Z

Lib/trace.py

@@ -559,8 +563,9 @@ def localtrace_trace_and_count(self, frame, why, arg):
            if self.start_time:
                print('%.2f' % (_time() - self.start_time), end=' ')
            bname = os.path.basename(filename)
-            print("%s(%d): %s" % (bname, lineno,
-                                  linecache.getline(filename, lineno)), end='')
+            with os.fdopen(self.trace_fd, "w", closefd=False) as trace_fp:


It uses the default encoding by default. Therefore it changes the behavior even if trace_fd=1, because the encoding of stdout can be different.

I afraid also that it can interfere with buffering user's output. Flush the standard streams before output.

How could the code be made smarter, so that it doesn't alter the encoding of stdout?

serhiy-storchaka · 2022-04-27T06:25:48Z

Lib/trace.py

@@ -559,8 +563,9 @@ def localtrace_trace_and_count(self, frame, why, arg):
            if self.start_time:
                print('%.2f' % (_time() - self.start_time), end=' ')


It goes to the stdout.

bpo-46742: Add "-d 123" / "--trace_fd 123" option to the trace module…

e07bade

… to send trace logs to a different file descriptor.

bedevere-bot added the awaiting review label Feb 13, 2022

the-knights-who-say-ni added the CLA not signed label Feb 13, 2022

the-knights-who-say-ni added CLA signed and removed CLA not signed labels Feb 17, 2022

PenelopeFudd mentioned this pull request Mar 25, 2022

PRs that need a CLA don't get resubmitted for checks python/the-knights-who-say-ni#316

Closed

JelleZijlstra closed this Mar 25, 2022

JelleZijlstra reopened this Mar 25, 2022

AlexWaygood requested a review from abalkin April 11, 2022 17:56

serhiy-storchaka reviewed Apr 27, 2022

View reviewed changes

ezio-melotti removed the CLA signed label Jul 13, 2022

		@@ -559,8 +563,9 @@ def localtrace_trace_and_count(self, frame, why, arg):
		if self.start_time:
		print('%.2f' % (_time() - self.start_time), end=' ')

Uh oh!

bpo-46742: Add "-d 123" / "--trace_fd 123" option to the trace module… #31319

Are you sure you want to change the base?

bpo-46742: Add "-d 123" / "--trace_fd 123" option to the trace module… #31319

Uh oh!

Conversation

PenelopeFudd commented Feb 13, 2022 • edited by bedevere-bot Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

the-knights-who-say-ni commented Feb 13, 2022

CLA Missing

Uh oh!

PenelopeFudd commented Feb 22, 2022

Uh oh!

PenelopeFudd commented Mar 1, 2022

Uh oh!

PenelopeFudd commented Mar 25, 2022

Uh oh!

PenelopeFudd commented Mar 25, 2022

Uh oh!

PenelopeFudd commented Mar 30, 2022

Uh oh!

PenelopeFudd commented Apr 4, 2022

Uh oh!

PenelopeFudd commented Apr 11, 2022

Uh oh!

PenelopeFudd commented Apr 26, 2022

Uh oh!

AlexWaygood commented Apr 26, 2022

Uh oh!

AlexWaygood commented Apr 26, 2022 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

PenelopeFudd commented Apr 27, 2022 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

PenelopeFudd commented Apr 27, 2022

Uh oh!

serhiy-storchaka Apr 27, 2022

Choose a reason for hiding this comment

Uh oh!

serhiy-storchaka Apr 27, 2022

Choose a reason for hiding this comment

Uh oh!

PenelopeFudd Apr 28, 2022

Choose a reason for hiding this comment

Uh oh!

serhiy-storchaka Apr 27, 2022

Choose a reason for hiding this comment

Uh oh!

PenelopeFudd Apr 28, 2022

Choose a reason for hiding this comment

Uh oh!

serhiy-storchaka Apr 27, 2022

Choose a reason for hiding this comment

Uh oh!

Uh oh!

PenelopeFudd commented Feb 13, 2022 •

edited by bedevere-bot

Loading

AlexWaygood commented Apr 26, 2022 •

edited

Loading

PenelopeFudd commented Apr 27, 2022 •

edited

Loading