gh-91513: Add 'asyncio' taskName to logging LogRecord attributes. (GH-93193) #93193

jackh-ncl · 2022-05-25T00:12:38Z

Continuing on from carlbordum@6e7dc2c 😃

Can test using:

import asyncio
import logging

FORMAT = '%(processName)s - %(process)s - %(threadName)s - %(thread)d - %(taskName)s - %(pathname)s - %(asctime)s - %(message)s'
logging.basicConfig(format=FORMAT)
logger = logging.getLogger(__name__)
logger.setLevel(logging.INFO)


async def log_some_stuff(name):
    logger.info(name)
    await asyncio.sleep(1)


async def spawn_tasks():
    await asyncio.gather(
        log_some_stuff('hello'),
        log_some_stuff('cheese')
    )


if __name__ == '__main__':
    asyncio.run(spawn_tasks())
    logger.info('Finished')

$ uname -a
Darwin ... 21.4.0 Darwin Kernel Version 21.4.0: Fri Mar 18 00:47:26 PDT 2022; root:xnu-8020.101.4~15/RELEASE_ARM64_T8101 arm64

$ ./python.exe -m test -j8
...
== Tests result: SUCCESS ==

407 tests OK.

29 tests skipped:
    test_curses test_dbm_gnu test_devpoll test_epoll test_gdb
    test_idle test_ioctl test_launcher test_msilib
    test_multiprocessing_fork test_ossaudiodev test_smtpnet
    test_socketserver test_spwd test_ssl test_startfile test_tcl
    test_tix test_tk test_ttk_guionly test_ttk_textonly test_turtle
    test_urllib2net test_urllibnet test_winconsoleio test_winreg
    test_winsound test_xmlrpc_net test_zipfile64

Total duration: 3 min 35 sec
Tests result: SUCCESS

Teardown after test_taskName.

bedevere-bot · 2022-05-25T00:12:41Z

Most changes to Python require a NEWS entry.

Please add it using the blurb_it web app or the blurb command-line tool.

jackh-ncl · 2022-05-25T00:30:08Z

Lib/test/test_logging.py

+                logging.logAsyncioTasks = False
+                runner.run(log_record(self.assertIsNone))
+        finally:
+            asyncio.set_event_loop_policy(None)


Tearing down, else we end up with:

== Tests result: SUCCESS == 406 tests OK. 1 test altered the execution environment: test_logging 29 tests skipped: test_curses test_dbm_gnu test_devpoll test_epoll test_gdb test_idle test_ioctl test_launcher test_msilib test_multiprocessing_fork test_ossaudiodev test_smtpnet test_socketserver test_spwd test_ssl test_startfile test_tcl test_tix test_tk test_ttk_guionly test_ttk_textonly test_turtle test_urllib2net test_urllibnet test_winconsoleio test_winreg test_winsound test_xmlrpc_net test_zipfile64

Doc/library/logging.rst

Lib/logging/__init__.py

Lib/test/test_logging.py

bedevere-bot · 2022-05-25T07:05:55Z

A Python core developer has requested some changes be made to your pull request before we can consider merging it. If you could please address their requests along with any other requests in other reviews from core developers that would be appreciated.

Once you have made the requested changes, please leave a comment on this pull request containing the phrase I have made the requested changes; please review again. I will then notify any core developers who have left a review that you're ready for them to take another look at this pull request.

Minor refactor in LogRecord.__init__ as per suggestions. Fixed typo in docs.

Lib/test/test_logging.py

vsajip

Just one suggested minor change, and one question.

vsajip · 2022-05-25T14:53:31Z

Lib/test/test_logging.py

+            with open('test.log', encoding='utf-8') as f:
+                data = f.read().strip()
+            os.remove('test.log')
+            self.assertEqual('Task-1 - hello world', data)


How can we be sure the task name will always be Task-1? What if more asyncio tasks are added in other tests which run before this one? Will the numbering still start at 1?

Have changed it to an assertRegex, similar to:

cpython/Lib/test/test_asyncio/test_tasks.py

Lines 393 to 394 in 1f134e9

match1 = re.match(r"^<Task pending name='Task-(\d+)'", repr(t1))

self.assertIsNotNone(match1)

Misc/NEWS.d/next/Library/2022-05-25-00-21-28.gh-issue-91513.9VyCT4.rst

…istent. Removed percent styling from News entry.

vsajip

The Azure pipeline check is failing - this is usually due to whitespace normalization issues. Can you please run make patchcheck and fixup anything that's found?

jackh-ncl · 2022-05-25T17:26:53Z

Pipelines looking green after pulling most recent main branch.

gst · 2022-05-26T11:20:23Z

Lib/test/test_logging.py

+            with open('test.log', encoding='utf-8') as f:
+                data = f.read().strip()
+            os.remove('test.log')
+            self.assertRegex(data, r'Task-\d+ - hello world')


handler = None try: ... finally: asyncio.set_event_loop_policy(None) if handler is not None: handler.close() if os.path.exists('test.log'): ....

to prevent sub-exceptions in the finally block if there is an exception/assertion error in the try block ?

I would have put the self.assertRegex(data, r'Task-\d+ - hello world') at the end of the try block too.

Yes, that's a fair point. This test probably needs tidying up a little.

I was following the pattern of the encoding tests above this one.
Happy to raise a new PR and fix it up along with the others.

That's OK, I've just done it. I'm working on logging tests for something else.

It's #93265.

jackh-ncl added 3 commits May 24, 2022 23:38

Add taskName to logging attributes

a4ce6aa

Merge branch 'main' into 91513

b0203c9

Make taskName a @Property of LogRecord.

1b99b1d

Teardown after test_taskName.

bedevere-bot added the awaiting review label May 25, 2022

📜🤖 Added by blurb_it.

c099bcb

jackh-ncl commented May 25, 2022

View reviewed changes

jackh-ncl changed the title ~~Add 'asyncio' taskName to logging attributes~~ 91513 - Add 'asyncio' taskName to logging attributes May 25, 2022

jackh-ncl changed the title ~~91513 - Add 'asyncio' taskName to logging attributes~~ #91513 - Add 'asyncio' taskName to logging attributes May 25, 2022

jackh-ncl added 2 commits May 25, 2022 01:52

Revert taskName @Property change

354dec9

Merge remote-tracking branch 'origin/91513' into 91513

77fb315

jackh-ncl changed the title ~~#91513 - Add 'asyncio' taskName to logging attributes~~ gh-91513: Add 'asyncio' taskName to logging attributes May 25, 2022

Adding a test for formatting of taskName attribute

3c72703

jackh-ncl marked this pull request as ready for review May 25, 2022 06:33

jackh-ncl requested a review from vsajip as a code owner May 25, 2022 06:33

vsajip requested changes May 25, 2022

View reviewed changes

bedevere-bot added awaiting changes and removed awaiting review labels May 25, 2022

vsajip mentioned this pull request May 25, 2022

gh-91513: add taskname to logging.LogRecord attributes #92646

Closed

Added test for path where asyncio is not imported.

57abfdc

Minor refactor in LogRecord.__init__ as per suggestions. Fixed typo in docs.

jackh-ncl commented May 25, 2022

View reviewed changes

Lib/test/test_logging.py Show resolved Hide resolved

jackh-ncl requested a review from vsajip May 25, 2022 08:36

vsajip requested changes May 25, 2022

View reviewed changes

Changing taskName assertion to regex in case numbering becomes incons…

12d2f45

…istent. Removed percent styling from News entry.

jackh-ncl requested a review from vsajip May 25, 2022 15:41

vsajip requested changes May 25, 2022

View reviewed changes

Merge branch 'main' into 91513

33a2166

jackh-ncl requested a review from vsajip May 25, 2022 17:27

vsajip changed the title ~~gh-91513: Add 'asyncio' taskName to logging attributes~~ gh-91513: Add 'asyncio' taskName to logging LogRecord attributes. (GH-93193) May 26, 2022

vsajip merged commit cc37706 into python:main May 26, 2022

bedevere-bot removed the awaiting changes label May 26, 2022

gst reviewed May 26, 2022

View reviewed changes

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

gh-91513: Add 'asyncio' taskName to logging LogRecord attributes. (GH-93193) #93193

gh-91513: Add 'asyncio' taskName to logging LogRecord attributes. (GH-93193) #93193

jackh-ncl commented May 25, 2022 •

edited

Loading

bedevere-bot commented May 25, 2022

jackh-ncl May 25, 2022

bedevere-bot commented May 25, 2022

vsajip left a comment

vsajip May 25, 2022

jackh-ncl May 25, 2022

vsajip left a comment

jackh-ncl commented May 25, 2022

gst May 26, 2022

gst May 26, 2022

vsajip May 26, 2022

jackh-ncl May 26, 2022

vsajip May 26, 2022

vsajip May 26, 2022

	match1 = re.match(r"^<Task pending name='Task-(\d+)'", repr(t1))
	self.assertIsNotNone(match1)

gh-91513: Add 'asyncio' taskName to logging LogRecord attributes. (GH-93193) #93193

gh-91513: Add 'asyncio' taskName to logging LogRecord attributes. (GH-93193) #93193

Conversation

jackh-ncl commented May 25, 2022 • edited Loading

bedevere-bot commented May 25, 2022

Choose a reason for hiding this comment

bedevere-bot commented May 25, 2022

vsajip left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

vsajip left a comment

Choose a reason for hiding this comment

jackh-ncl commented May 25, 2022

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

jackh-ncl commented May 25, 2022 •

edited

Loading