)]}'
{"/PATCHSET_LEVEL":[{"author":{"_account_id":1179,"name":"Clay Gerrard","email":"clay.gerrard@gmail.com","username":"clay-gerrard"},"change_message_id":"d11dbe187ef9b714a388e45521ad94df5ef41678","unresolved":false,"context_lines":[],"source_content_type":"","patch_set":1,"id":"8f980aab_fa5fe044","updated":"2023-07-19 15:13:22.000000000","message":"i\u0027m sure this works and is necessary - but I don\u0027t understand it","commit_id":"af3cf63d80508e78015c4ea08c5b3133e78162ed"},{"author":{"_account_id":7847,"name":"Alistair Coles","email":"alistairncoles@gmail.com","username":"acoles"},"change_message_id":"62e4e0e1d83738df51e8af9d20fbfd2dddcc4f66","unresolved":false,"context_lines":[],"source_content_type":"","patch_set":1,"id":"5c6670e5_4de76200","updated":"2023-07-18 14:41:38.000000000","message":"on master I see stats like:\n\ns3api.account.info.cache.miss:1|c\n\nwith this patch I see:\n\nproxy-server.account.info.cache.miss:1|c","commit_id":"af3cf63d80508e78015c4ea08c5b3133e78162ed"},{"author":{"_account_id":1179,"name":"Clay Gerrard","email":"clay.gerrard@gmail.com","username":"clay-gerrard"},"change_message_id":"762e7f8db97243338186945a26fccefcc01e0f7c","unresolved":false,"context_lines":[],"source_content_type":"","patch_set":2,"id":"dcaf5d2e_c9c04578","updated":"2023-07-20 15:40:26.000000000","message":"i was sort of on the right track, but had the wrong expecations - the additional behavioral assertions help me out; thanks for taking the time.","commit_id":"bdbe8ce9f821a6809f19d7aefa8c1e9a7d1328de"}],"swift/common/middleware/s3api/s3api.py":[{"author":{"_account_id":1179,"name":"Clay Gerrard","email":"clay.gerrard@gmail.com","username":"clay-gerrard"},"change_message_id":"d11dbe187ef9b714a388e45521ad94df5ef41678","unresolved":true,"context_lines":[{"line_number":293,"context_line":"            wsgi_conf.get(\u0027ratelimit_as_client_error\u0027, False))"},{"line_number":294,"context_line":""},{"line_number":295,"context_line":"        self.logger \u003d get_logger("},{"line_number":296,"context_line":"            wsgi_conf, log_route\u003d\u0027s3api\u0027, statsd_tail_prefix\u003d\u0027s3api\u0027)"},{"line_number":297,"context_line":"        self.check_pipeline(wsgi_conf)"},{"line_number":298,"context_line":""},{"line_number":299,"context_line":"    def is_s3_cors_preflight(self, env):"}],"source_content_type":"text/x-python","patch_set":1,"id":"84eb1dba_d38df80e","line":296,"updated":"2023-07-19 15:13:22.000000000","message":"it makes sense to me that s3api should use it\u0027s own logger - I don\u0027t really know why we wanted mw to be able to hijack the proxy-server log_route","commit_id":"af3cf63d80508e78015c4ea08c5b3133e78162ed"},{"author":{"_account_id":1179,"name":"Clay Gerrard","email":"clay.gerrard@gmail.com","username":"clay-gerrard"},"change_message_id":"762e7f8db97243338186945a26fccefcc01e0f7c","unresolved":true,"context_lines":[{"line_number":293,"context_line":"            wsgi_conf.get(\u0027ratelimit_as_client_error\u0027, False))"},{"line_number":294,"context_line":""},{"line_number":295,"context_line":"        self.logger \u003d get_logger("},{"line_number":296,"context_line":"            wsgi_conf, log_route\u003d\u0027s3api\u0027, statsd_tail_prefix\u003d\u0027s3api\u0027)"},{"line_number":297,"context_line":"        self.check_pipeline(wsgi_conf)"},{"line_number":298,"context_line":""},{"line_number":299,"context_line":"    def is_s3_cors_preflight(self, env):"}],"source_content_type":"text/x-python","patch_set":1,"id":"81cedf17_7bdcb72a","line":296,"in_reply_to":"84eb1dba_d38df80e","updated":"2023-07-20 15:40:26.000000000","message":"lots of prior art on log_route being explicit per-mw value being the correct thing to do:\n\nswift/swift/common/middleware/versioned_writes/legacy.py\n701:        self.logger \u003d get_logger(conf, log_route\u003d\u0027versioned_writes\u0027)\n\nswift/swift/common/middleware/tempurl.py\n429:        self.logger \u003d logger or get_logger(conf, log_route\u003d\u0027tempurl\u0027)","commit_id":"af3cf63d80508e78015c4ea08c5b3133e78162ed"}],"test/unit/common/middleware/s3api/test_s3api.py":[{"author":{"_account_id":1179,"name":"Clay Gerrard","email":"clay.gerrard@gmail.com","username":"clay-gerrard"},"change_message_id":"d11dbe187ef9b714a388e45521ad94df5ef41678","unresolved":true,"context_lines":[{"line_number":226,"context_line":""},{"line_number":227,"context_line":"        s3api \u003d S3ApiMiddleware(None, {\u0027log_name\u0027: \u0027proxy-server\u0027,"},{"line_number":228,"context_line":"                                       \u0027log_statsd_host\u0027: \u00271.2.3.4\u0027})"},{"line_number":229,"context_line":"        self.assertEqual(\u0027s3api\u0027, s3api.logger.name)"},{"line_number":230,"context_line":"        self.assertEqual(\u0027s3api\u0027, s3api.logger.logger.name)"},{"line_number":231,"context_line":"        self.assertIsNot(s3api.logger.logger, proxy_logger)"},{"line_number":232,"context_line":"        self.assertEqual(\u0027proxy-server\u0027, s3api.logger.server)"}],"source_content_type":"text/x-python","patch_set":1,"id":"2bc6c1ec_0c9d53c8","line":229,"updated":"2023-07-19 15:13:22.000000000","message":"hrm, i reverted the fix in the mw setup/config and kind fo expected this test to fail different:\n\n\tself \u003d \u003ctest.unit.common.middleware.s3api.test_s3api.TestS3ApiMiddleware testMethod\u003dtest_init_logger\u003e\n\n\t    def test_init_logger(self):\n\t\tproxy_logger \u003d get_logger({}, log_route\u003d\u0027proxy-server\u0027).logger\n\t    \n\t\ts3api \u003d S3ApiMiddleware(None, {})\n\t\tself.assertEqual(\u0027s3api\u0027, s3api.logger.name)\n\t\tself.assertEqual(\u0027s3api\u0027, s3api.logger.logger.name)\n\t\tself.assertIsNot(s3api.logger.logger, proxy_logger)\n\t\tself.assertEqual(\u0027swift\u0027, s3api.logger.server)\n\t\tself.assertIsNone(s3api.logger.logger.statsd_client)\n\t    \n\t\ts3api \u003d S3ApiMiddleware(None, {\u0027log_name\u0027: \u0027proxy-server\u0027,\n\t\t\t\t\t       \u0027log_statsd_host\u0027: \u00271.2.3.4\u0027})\n\t\u003e       self.assertEqual(\u0027s3api\u0027, s3api.logger.name)\n\tE       AssertionError: \u0027s3api\u0027 !\u003d \u0027proxy-server\u0027\n\tE       - s3api\n\tE       + proxy-server\n\n\tswift/test/unit/common/middleware/s3api/test_s3api.py:229: AssertionError\n\n\nthe \"bug\" was that the s3api prefix was set on the proxy-server logger; but w/o loding the wsgi config from a file with paste it\u0027s probably hard to see that the [DEFAULT] section was causing the log_route in the mw to still be proxy-server\n\n... or maybe I\u0027m still not understanding the bug fix","commit_id":"af3cf63d80508e78015c4ea08c5b3133e78162ed"},{"author":{"_account_id":7847,"name":"Alistair Coles","email":"alistairncoles@gmail.com","username":"acoles"},"change_message_id":"babd8868322f7ad035f4aa842d62be5ffe7f0c1e","unresolved":true,"context_lines":[{"line_number":226,"context_line":""},{"line_number":227,"context_line":"        s3api \u003d S3ApiMiddleware(None, {\u0027log_name\u0027: \u0027proxy-server\u0027,"},{"line_number":228,"context_line":"                                       \u0027log_statsd_host\u0027: \u00271.2.3.4\u0027})"},{"line_number":229,"context_line":"        self.assertEqual(\u0027s3api\u0027, s3api.logger.name)"},{"line_number":230,"context_line":"        self.assertEqual(\u0027s3api\u0027, s3api.logger.logger.name)"},{"line_number":231,"context_line":"        self.assertIsNot(s3api.logger.logger, proxy_logger)"},{"line_number":232,"context_line":"        self.assertEqual(\u0027proxy-server\u0027, s3api.logger.server)"}],"source_content_type":"text/x-python","patch_set":1,"id":"19e2d4b1_1a0b1789","line":229,"in_reply_to":"2bc6c1ec_0c9d53c8","updated":"2023-07-20 09:25:28.000000000","message":"On master, the config \u0027log_name\u0027 determined the s3api MW log_route, which in turn selects the global Logger instance. \n\nThis test mimics what run_wsgi does i.e set log_name\u003dproxy-server. So on master this test forces s3api to use log_route\u003dproxy-server, which gets it the Logger instance named \u0027proxy-server\u0027, which is the same one the proxy app has. \n\nThe fix is to stop s3api using the config log_name as its log_route.\n\nThe root cause of much confusion is the use of log_name in config, vs name and log_route in get_logger(). The \u0027log_name\u0027 config option and the \u0027name\u0027 arg of get_logger actually defines the \u0027server\u0027 part of the formatted log message, but can sometimes (e.g. in s3api on master) also be used as the log_route (which is the Logger name !?!), and that\u0027s how we end up sharing Logger instances.\n\nI imagine that there may once have been a thought that all proxy MWs could share a single Logger instance and all have server\u003dproxy-server in their log messages.\n\nBut the shared Logger idea is broken by the fact that each MW could have different configured, or hard-coded, get_logger parameters which mutate the shared Logger e.g. each call to get_logger() replaces the formatter and handler with whatever that MW has configured. \n\nIn this case, it\u0027s the statsd_client attribute of the shared logger that was being mutated.\n\nSo in practice, it\u0027s best for MWs not to share a common Logger instance, and we achieve that by hard-coding log_route\u003ds3api.","commit_id":"af3cf63d80508e78015c4ea08c5b3133e78162ed"}],"test/unit/common/test_utils.py":[{"author":{"_account_id":1179,"name":"Clay Gerrard","email":"clay.gerrard@gmail.com","username":"clay-gerrard"},"change_message_id":"d11dbe187ef9b714a388e45521ad94df5ef41678","unresolved":true,"context_lines":[{"line_number":1043,"context_line":"        self.assertEqual(\u0027swift\u0027, logger.server)"},{"line_number":1044,"context_line":"        with add_log_handler(logger) as sio:"},{"line_number":1045,"context_line":"            logger.info(\u0027testing\u0027)"},{"line_number":1046,"context_line":"            self.assertEqual(\u0027swift: testing\\n\u0027, sio.getvalue())"},{"line_number":1047,"context_line":""},{"line_number":1048,"context_line":"    @with_tempdir"},{"line_number":1049,"context_line":"    def test_get_logger_sysloghandler_plumbing(self, tempdir):"}],"source_content_type":"text/x-python","patch_set":1,"id":"78120ea6_9eb97a70","line":1046,"updated":"2023-07-19 15:13:22.000000000","message":"ok, yeah I definately don\u0027t understand this bug:\n\n\tself \u003d \u003ctest.unit.common.test_utils.TestUtils testMethod\u003dtest_same_log_route_shares_config\u003e\n\n\t    def test_same_log_route_shares_config(self):\n\t\tlogger1 \u003d utils.get_logger({}, name\u003d\u0027name1\u0027, log_route\u003d\u0027route\u0027)\n\t\twith self.add_log_handler(logger1) as sio:\n\t\t    logger1.info(\u0027testing\u0027)\n\t\t    self.assertEqual(\u0027name1: testing\\n\u0027, sio.getvalue())\n\t\tlogger2 \u003d utils.get_logger({}, name\u003d\u0027name2\u0027, log_route\u003d\u0027route\u0027)\n\t\twith self.add_log_handler(logger2) as sio:\n\t\t    logger2.info(\u0027testing\u0027)\n\t\t    self.assertEqual(\u0027name2: testing\\n\u0027, sio.getvalue())\n\t\t# I expected logger1\u0027s name to change too?!\n\t\twith self.add_log_handler(logger1) as sio:\n\t\t    logger1.info(\u0027testing\u0027)\n\t\u003e           self.assertEqual(\u0027name2: testing\\n\u0027, sio.getvalue())\n\tE           AssertionError: \u0027name2: testing\\n\u0027 !\u003d \u0027name1: testing\\n\u0027\n\tE           - name2: testing\n\tE           ?     ^\n\tE           + name1: testing\n\tE           ?     ^\n\n\tswift/test/unit/common/test_utils.py:1016: AssertionError","commit_id":"af3cf63d80508e78015c4ea08c5b3133e78162ed"},{"author":{"_account_id":7847,"name":"Alistair Coles","email":"alistairncoles@gmail.com","username":"acoles"},"change_message_id":"babd8868322f7ad035f4aa842d62be5ffe7f0c1e","unresolved":true,"context_lines":[{"line_number":1043,"context_line":"        self.assertEqual(\u0027swift\u0027, logger.server)"},{"line_number":1044,"context_line":"        with add_log_handler(logger) as sio:"},{"line_number":1045,"context_line":"            logger.info(\u0027testing\u0027)"},{"line_number":1046,"context_line":"            self.assertEqual(\u0027swift: testing\\n\u0027, sio.getvalue())"},{"line_number":1047,"context_line":""},{"line_number":1048,"context_line":"    @with_tempdir"},{"line_number":1049,"context_line":"    def test_get_logger_sysloghandler_plumbing(self, tempdir):"}],"source_content_type":"text/x-python","patch_set":1,"id":"64e4b7c3_ae26a391","line":1046,"in_reply_to":"78120ea6_9eb97a70","updated":"2023-07-20 09:25:28.000000000","message":"Your get_logger calls have different names but the same log_route. Those get_logger calls both get a Logger instance whose name is log_route. (Yes, isn\u0027t that confusing?!).\n\nThe name that you passed to get_logger is passed to the LogAdapter \u0027server\u0027 attribute. The LogAdapter server attribute is used to populate the \u0027server\u0027 item of the SwiftFormatter message formatter, which is the first item in the log messages.\n\nThe logging.Logger.name (in this case \u0027route\u0027) never appears in the formatted log message.\n\nI\u0027ll add some more test cases (they may at least illustrate the behaviour).","commit_id":"af3cf63d80508e78015c4ea08c5b3133e78162ed"},{"author":{"_account_id":1179,"name":"Clay Gerrard","email":"clay.gerrard@gmail.com","username":"clay-gerrard"},"change_message_id":"762e7f8db97243338186945a26fccefcc01e0f7c","unresolved":true,"context_lines":[{"line_number":1059,"context_line":"        self.assertEqual(\u0027name1\u0027, logger1.server)"},{"line_number":1060,"context_line":"        # oh dear, the statsd client on the common logging.Logger instance got"},{"line_number":1061,"context_line":"        # mutated when logger2 was created"},{"line_number":1062,"context_line":"        self.assertEqual(\u0027name2.\u0027, logger1.logger.statsd_client._prefix)"},{"line_number":1063,"context_line":"        self.assertEqual(\u0027route\u0027, logger2.name)"},{"line_number":1064,"context_line":"        self.assertEqual(\u0027route\u0027, logger2.logger.name)"},{"line_number":1065,"context_line":"        self.assertEqual(\u0027name2\u0027, logger2.server)"}],"source_content_type":"text/x-python","patch_set":2,"id":"7b059288_7b758799","line":1062,"updated":"2023-07-20 15:40:26.000000000","message":"ding ding ding!!!","commit_id":"bdbe8ce9f821a6809f19d7aefa8c1e9a7d1328de"},{"author":{"_account_id":1179,"name":"Clay Gerrard","email":"clay.gerrard@gmail.com","username":"clay-gerrard"},"change_message_id":"762e7f8db97243338186945a26fccefcc01e0f7c","unresolved":true,"context_lines":[{"line_number":1084,"context_line":"        self.assertEqual(\u0027route2\u0027, logger2.name)"},{"line_number":1085,"context_line":"        self.assertEqual(\u0027route2\u0027, logger2.logger.name)"},{"line_number":1086,"context_line":"        self.assertEqual(\u0027name2\u0027, logger2.server)"},{"line_number":1087,"context_line":"        self.assertEqual(\u0027name2.\u0027, logger2.logger.statsd_client._prefix)"},{"line_number":1088,"context_line":"        self.assertIsNot(logger2.logger, logger1.logger)"},{"line_number":1089,"context_line":"        with add_log_handler(logger1) as sio:"},{"line_number":1090,"context_line":"            logger1.info(\u0027testing\u0027)"}],"source_content_type":"text/x-python","patch_set":2,"id":"df53bf93_9f719d0a","line":1087,"updated":"2023-07-20 15:40:26.000000000","message":"bingo","commit_id":"bdbe8ce9f821a6809f19d7aefa8c1e9a7d1328de"}]}