)]}'
{"/COMMIT_MSG":[{"author":{"_account_id":7847,"name":"Alistair Coles","email":"alistairncoles@gmail.com","username":"acoles"},"change_message_id":"c9dd74a1e39160da60dd54a9308f40624f9550dd","unresolved":true,"context_lines":[{"line_number":4,"context_line":"Commit:     Tim Burke \u003ctim.burke@gmail.com\u003e"},{"line_number":5,"context_line":"CommitDate: 2024-02-27 09:49:50 -0800"},{"line_number":6,"context_line":""},{"line_number":7,"context_line":"tests: Clear txn id on init for all debug loggers"},{"line_number":8,"context_line":""},{"line_number":9,"context_line":"Since we fake out all the greenthread stuff to run in the main thread,"},{"line_number":10,"context_line":"we can (sometimes?) find that a transaction ID has already been set,"}],"source_content_type":"text/x-gerrit-commit-message","patch_set":2,"id":"41fb34ad_0679c34d","line":7,"updated":"2024-02-27 19:51:37.000000000","message":"I feel stupid but I don\u0027t understand where the txn_id is being previously set in test__bad_request_app_logging - can you help me understand the root cause, because I\u0027d love to merge this!","commit_id":"1ee9b1e3baf839975124619c91869fa9265ae963"},{"author":{"_account_id":597,"name":"Pete Zaitcev","email":"zaitcev@kotori.zaitcev.us","username":"zaitcev"},"change_message_id":"c68dbbc77df909a5e931428163ec5704c087d17f","unresolved":true,"context_lines":[{"line_number":4,"context_line":"Commit:     Tim Burke \u003ctim.burke@gmail.com\u003e"},{"line_number":5,"context_line":"CommitDate: 2024-02-27 09:49:50 -0800"},{"line_number":6,"context_line":""},{"line_number":7,"context_line":"tests: Clear txn id on init for all debug loggers"},{"line_number":8,"context_line":""},{"line_number":9,"context_line":"Since we fake out all the greenthread stuff to run in the main thread,"},{"line_number":10,"context_line":"we can (sometimes?) find that a transaction ID has already been set,"}],"source_content_type":"text/x-gerrit-commit-message","patch_set":2,"id":"dfbe522e_cb1e6302","line":7,"in_reply_to":"41fb34ad_0679c34d","updated":"2024-02-28 00:12:30.000000000","message":"Here\u0027s the answer:\n\n  File \"/home/zaitcev/hail/swift-tip/test/unit/common/test_http_protocol.py\", line 276, in test_bad_request_app_logging\n    ), app\u003dapp)\n  File \"/home/zaitcev/hail/swift-tip/test/unit/common/test_http_protocol.py\", line 142, in _run_bytes_through_protocol\n    log_output\u003dTrue,\n  File \"/home/zaitcev/hail/swift-tip/.tox/py37/lib/python3.7/site-packages/eventlet/wsgi.py\", line 1006, in server\n    (pool.spawn(serv.process_request, connection)\n  File \"/home/zaitcev/hail/swift-tip/test/unit/common/test_http_protocol.py\", line 108, in spawn\n    a_callable(*args, **kwargs)\n  File \"/home/zaitcev/hail/swift-tip/.tox/py37/lib/python3.7/site-packages/eventlet/wsgi.py\", line 837, in process_request\n    proto.__init__(conn_state, self)\n  File \"/home/zaitcev/hail/swift-tip/swift/common/http_protocol.py\", line 40, in __init__\n    wsgi.HttpProtocol.__init__(self, *args, **kwargs)\n  File \"/home/zaitcev/hail/swift-tip/.tox/py37/lib/python3.7/site-packages/eventlet/wsgi.py\", line 350, in __init__\n    self.handle()\n  File \"/home/zaitcev/hail/swift-tip/.tox/py37/lib/python3.7/site-packages/eventlet/wsgi.py\", line 383, in handle\n    self.handle_one_request()\n  File \"/home/zaitcev/hail/swift-tip/swift/common/http_protocol.py\", line 243, in handle_one_request\n    got \u003d wsgi.HttpProtocol.handle_one_request(self)\n  File \"/home/zaitcev/hail/swift-tip/.tox/py37/lib/python3.7/site-packages/eventlet/wsgi.py\", line 424, in handle_one_request\n    if not self.parse_request():\n  File \"/home/zaitcev/hail/swift-tip/swift/common/http_protocol.py\", line 131, in parse_request\n    \"Bad request syntax (%r)\" % requestline)\n  File \"/home/zaitcev/hail/swift-tip/swift/common/http_protocol.py\", line 287, in send_error\n    self.server.app.logger.txn_id \u003d txn_id\n\nNote that this on the unmodified code, before the patch in question.","commit_id":"1ee9b1e3baf839975124619c91869fa9265ae963"},{"author":{"_account_id":7847,"name":"Alistair Coles","email":"alistairncoles@gmail.com","username":"acoles"},"change_message_id":"c9dd74a1e39160da60dd54a9308f40624f9550dd","unresolved":true,"context_lines":[{"line_number":14,"context_line":"    in b\u0027X-Trans-Id: tx...\u0027"},{"line_number":15,"context_line":""},{"line_number":16,"context_line":"By resetting the logger\u0027s txn_id, we\u0027re assured that our mock will be"},{"line_number":17,"context_line":"run and the expected transaction ID will be used."},{"line_number":18,"context_line":""},{"line_number":19,"context_line":"Change-Id: I465eed5372a2a5e591f80a09676f4b7f091cd444"}],"source_content_type":"text/x-gerrit-commit-message","patch_set":2,"id":"b9429419_f8e8426d","line":17,"updated":"2024-02-27 19:51:37.000000000","message":"this para may be stale now the fix has moved to debug_logger....which mock?","commit_id":"1ee9b1e3baf839975124619c91869fa9265ae963"}],"/PATCHSET_LEVEL":[{"author":{"_account_id":597,"name":"Pete Zaitcev","email":"zaitcev@kotori.zaitcev.us","username":"zaitcev"},"change_message_id":"f0ef9529bd9b474ca89c7a6ffcda7c31271c5e79","unresolved":false,"context_lines":[],"source_content_type":"","patch_set":1,"id":"2e4da98d_e1d7e0f5","updated":"2024-02-14 20:35:59.000000000","message":"This seems asking to forget it elsewhere, as soon as running on the main thread is involved.\n\nWhy not fix it in DebugLogAdapter by overriding the getter and setter?","commit_id":"a8e348055edd842d6cf63ff40498c96996eb3a3e"},{"author":{"_account_id":15343,"name":"Tim Burke","email":"tburke@nvidia.com","username":"tburke"},"change_message_id":"db8213607ba43430857fa7bded1ec5fa3a2c5d59","unresolved":false,"context_lines":[],"source_content_type":"","patch_set":1,"id":"7f8ab3d7_ca18015d","in_reply_to":"2e4da98d_e1d7e0f5","updated":"2024-02-27 18:00:15.000000000","message":"Something like this, maybe?","commit_id":"a8e348055edd842d6cf63ff40498c96996eb3a3e"},{"author":{"_account_id":7847,"name":"Alistair Coles","email":"alistairncoles@gmail.com","username":"acoles"},"change_message_id":"ab2b12e39c92504081fb3fc8b30d2b31b4b12adf","unresolved":false,"context_lines":[],"source_content_type":"","patch_set":2,"id":"36fb297b_31092ec4","updated":"2024-02-28 12:41:15.000000000","message":"thanks @Pete, I could see how we\u0027d skip the call to generate_trans_id if  txn_id was already set, but not how it was already set. With fresh eyes I realised that the thread local is a class member, so persists between instances.\n\nI\u0027m also now surprised that the test doesn\u0027t fail more often - I guess we were lucky with test ordering most of the time?\n\nWith this change I can now make this change and the test still passes:\n\n```\ndiff --git a/test/unit/common/test_http_protocol.py b/test/unit/common/test_http_protocol.py\nindex cb9772dd2..268794c66 100644\n--- a/test/unit/common/test_http_protocol.py\n+++ b/test/unit/common/test_http_protocol.py\n@@ -264,6 +264,7 @@ class TestSwiftHttpProtocolSomeMore(ProtocolTest):\n             info_lines[1])\n\n     def test_bad_request_app_logging(self):\n+        debug_logger().txn_id \u003d \u0027foo\u0027\n         app_logger \u003d debug_logger()\n         app \u003d mock.MagicMock()\n         app.logger \u003d app_logger\n         ```\n         \nThe test also passes with this change:\n\n```\ndiff --git a/test/unit/common/test_http_protocol.py b/test/unit/common/test_http_protocol.py\nindex cb9772dd2..0b2bc4ca6 100644\n--- a/test/unit/common/test_http_protocol.py\n+++ b/test/unit/common/test_http_protocol.py\n@@ -265,6 +265,7 @@ class TestSwiftHttpProtocolSomeMore(ProtocolTest):\n\n     def test_bad_request_app_logging(self):\n         app_logger \u003d debug_logger()\n+        debug_logger().txn_id \u003d \u0027foo\u0027\n         app \u003d mock.MagicMock()\n         app.logger \u003d app_logger\n         with mock.patch(\u0027swift.common.http_protocol.generate_trans_id\u0027,\n         ```\n         \n...which is good, but confusing! Turns out there\u0027s another debug_logger instantiated in _run_bytes_through_protocol() so with this patch that resets txn_id on all debug loggers to None!\n\nMaybe we could clear up that potential source of confusion https://review.opendev.org/c/openstack/swift/+/910505","commit_id":"1ee9b1e3baf839975124619c91869fa9265ae963"}],"test/debug_logger.py":[{"author":{"_account_id":7847,"name":"Alistair Coles","email":"alistairncoles@gmail.com","username":"acoles"},"change_message_id":"c9dd74a1e39160da60dd54a9308f40624f9550dd","unresolved":true,"context_lines":[{"line_number":251,"context_line":"class DebugLogAdapter(utils.LogAdapter):"},{"line_number":252,"context_line":"    def __init__(self, *args, **kwargs):"},{"line_number":253,"context_line":"        super(DebugLogAdapter, self).__init__(*args, **kwargs)"},{"line_number":254,"context_line":"        self.txn_id \u003d None"},{"line_number":255,"context_line":""},{"line_number":256,"context_line":"    def __getattribute__(self, name):"},{"line_number":257,"context_line":"        try:"}],"source_content_type":"text/x-python","patch_set":2,"id":"95377f3a_d40df946","line":254,"updated":"2024-02-27 19:51:37.000000000","message":"so we\u0027re overriding the property getter, does that implicitly override the property setter? I think so, but need to remind myself.","commit_id":"1ee9b1e3baf839975124619c91869fa9265ae963"},{"author":{"_account_id":597,"name":"Pete Zaitcev","email":"zaitcev@kotori.zaitcev.us","username":"zaitcev"},"change_message_id":"c68dbbc77df909a5e931428163ec5704c087d17f","unresolved":true,"context_lines":[{"line_number":251,"context_line":"class DebugLogAdapter(utils.LogAdapter):"},{"line_number":252,"context_line":"    def __init__(self, *args, **kwargs):"},{"line_number":253,"context_line":"        super(DebugLogAdapter, self).__init__(*args, **kwargs)"},{"line_number":254,"context_line":"        self.txn_id \u003d None"},{"line_number":255,"context_line":""},{"line_number":256,"context_line":"    def __getattribute__(self, name):"},{"line_number":257,"context_line":"        try:"}],"source_content_type":"text/x-python","patch_set":2,"id":"7d2b8efa_a5ad2815","line":254,"in_reply_to":"95377f3a_d40df946","updated":"2024-02-28 00:12:30.000000000","message":"There may be some confusion here. I proposed that we override the getter and setter. But Tim rejected my idea and did not override them. Instead, he sets the txn_id early, using our normal setter, which is not test specific.\n\nMy idea was that if we override in test LogAdapter, then the thread-local storage goes away, and you can run safely on main. Tim\u0027s idea was, we just make sure it\u0027s None on thread-local.\n\nI may be wrong in my understanding. Something does not feel right. Namely: if we run on main, then why the problem only occurs sometimes, but not every time? I wrote it for green threads changing order of execution, but I don\u0027t know for sure.","commit_id":"1ee9b1e3baf839975124619c91869fa9265ae963"}]}