)]}'
{"/COMMIT_MSG":[{"author":{"_account_id":7847,"name":"Alistair Coles","email":"alistairncoles@gmail.com","username":"acoles"},"change_message_id":"b7b5fe80814e2e780aa7a7c1c2dc103f8a5d9224","unresolved":true,"context_lines":[{"line_number":5,"context_line":"CommitDate: 2025-08-21 22:18:32 -0700"},{"line_number":6,"context_line":""},{"line_number":7,"context_line":"Object: log breakdown timings for slow DELETE requests."},{"line_number":8,"context_line":""},{"line_number":9,"context_line":"Change-Id: If590482a376aeed02391627931bd5b1f24569c6a"},{"line_number":10,"context_line":"Co-Authored-By: Alistair Coles \u003calistairncoles@gmail.com\u003e"},{"line_number":11,"context_line":"Signed-off-by: Jianjian Huo \u003cjhuo@nvidia.com\u003e"}],"source_content_type":"text/x-gerrit-commit-message","patch_set":14,"id":"d96cbfde_100fe0ee","line":8,"updated":"2025-08-22 10:49:48.000000000","message":"nit: please add\n\n```\nRelated-Change-Id: I73f1a03818157dc76938cbffd520c5c38941e2b6\n```\n\nto point back to the decorator patch","commit_id":"4e96a00fee3d6aa3434249f112ba52cd78e9c285"},{"author":{"_account_id":34930,"name":"Jianjian Huo","email":"jhuo@nvidia.com","username":"jhuo"},"change_message_id":"95556eb3fa51a200043d8b197d8085d443501c10","unresolved":false,"context_lines":[{"line_number":5,"context_line":"CommitDate: 2025-08-21 22:18:32 -0700"},{"line_number":6,"context_line":""},{"line_number":7,"context_line":"Object: log breakdown timings for slow DELETE requests."},{"line_number":8,"context_line":""},{"line_number":9,"context_line":"Change-Id: If590482a376aeed02391627931bd5b1f24569c6a"},{"line_number":10,"context_line":"Co-Authored-By: Alistair Coles \u003calistairncoles@gmail.com\u003e"},{"line_number":11,"context_line":"Signed-off-by: Jianjian Huo \u003cjhuo@nvidia.com\u003e"}],"source_content_type":"text/x-gerrit-commit-message","patch_set":14,"id":"8bc55491_609c6f3e","line":8,"in_reply_to":"d96cbfde_100fe0ee","updated":"2025-08-23 01:17:32.000000000","message":"Done","commit_id":"4e96a00fee3d6aa3434249f112ba52cd78e9c285"}],"/PATCHSET_LEVEL":[{"author":{"_account_id":7233,"name":"Matthew Oliver","email":"matt@oliver.net.au","username":"mattoliverau"},"change_message_id":"951adafb9c1ee5692018ce2e49b468ffffc2046f","unresolved":false,"context_lines":[],"source_content_type":"","patch_set":7,"id":"55ae24d8_8f7e9d9f","updated":"2025-07-04 04:05:33.000000000","message":"@jian, if you feel brave, you can try and add a follow up to the tracing chain to add the same thing so you can get a feel for it and see if it\u0027s also useful.\n\nThis might be a little better, becuase it\u0027ll log when we have a slow request, no tagging requests required. So maybe we have both, in anycase could be nice to get someone to have a go at tracing 😊","commit_id":"45dcc34f99c9c1d650cc554465defe9fb959af87"},{"author":{"_account_id":7233,"name":"Matthew Oliver","email":"matt@oliver.net.au","username":"mattoliverau"},"change_message_id":"57e63c9a7abe87d19119f45508b97c75197ac09c","unresolved":false,"context_lines":[],"source_content_type":"","patch_set":7,"id":"9d797cee_75bf6b1e","updated":"2025-07-04 04:03:27.000000000","message":"Nice, setting `slow_delete_log_threshold_seconds` to 0 and then deleting something in my SAIO:\n\n```\nJul 04 03:58:33 saio7 object-server-6030[7316]: Slow DELETE (0.008s) for /sdb7/873/AUTH_test/cont/prometheus-2.48.1.linux-amd64/LICENSE, status 204, diskfile_acquisition\u003d0.000s, metadata_read\u003d0.000s, delete_at_update\u003d0.000s, tombstone_write\u003d0.002s, container_update\u003d0.006s (txn: txaa4298113d3548f9be8f8-0068675169)\nJul 04 03:58:33 saio7 object-server-6010[7320]: Slow DELETE (0.009s) for /sdb5/873/AUTH_test/cont/prometheus-2.48.1.linux-amd64/LICENSE, status 204, diskfile_acquisition\u003d0.000s, metadata_read\u003d0.000s, delete_at_update\u003d0.000s, tombstone_write\u003d0.002s, container_update\u003d0.005s (txn: txaa4298113d3548f9be8f8-0068675169)\nJul 04 03:58:33 saio7 object-server-6010[7320]: 127.0.0.1 - - [04/Jul/2025:03:58:33 +0000] \"DELETE \nJul 04 03:58:33 saio7 object-server-6020[7309]: Slow DELETE (0.010s) for /sdb2/873/AUTH_test/cont/prometheus-2.48.1.linux-amd64/LICENSE, status 204, diskfile_acquisition\u003d0.000s, metadata_read\u003d0.000s, delete_at_update\u003d0.000s, tombstone_write\u003d0.002s, container_update\u003d0.007s (txn: txaa4298113d3548f9be8f8-0068675169)\n```\n\nSo in this case the container update was the slowest bit.\n\nWe\u0027ll be able to get similar info from the spans in tracing.. although I probably haven\u0027t instrumented all of delete the same way... yet.","commit_id":"45dcc34f99c9c1d650cc554465defe9fb959af87"},{"author":{"_account_id":7847,"name":"Alistair Coles","email":"alistairncoles@gmail.com","username":"acoles"},"change_message_id":"31716740b9e2727fcce63c8db6fa0ea27a735a54","unresolved":false,"context_lines":[],"source_content_type":"","patch_set":7,"id":"7c103d6e_3c46afb5","updated":"2025-07-07 12:04:28.000000000","message":"Tried this out in my vsaio and all looked good with a threshold of 0\n```\nJul  7 11:06:45 vagrant object-server-6040: Slow DELETE (0.011s) for /sdb4/951/AUTH_test/junk/LICENSE, status 204, diskfile_acquisition\u003d0.000s, metadata_read\u003d0.000s, delete_at_update\u003d0.000s, tombstone_write\u003d0.008s, container_update\u003d0.002s (txn: tx0ee9bc6be7c84b31b7e7f-00686baa45)\n```\n\nSome suggestions here https://review.opendev.org/c/openstack/swift/+/954233","commit_id":"45dcc34f99c9c1d650cc554465defe9fb959af87"},{"author":{"_account_id":34930,"name":"Jianjian Huo","email":"jhuo@nvidia.com","username":"jhuo"},"change_message_id":"d97286ae290d26465c11bda7133be6ef6d5990dc","unresolved":false,"context_lines":[],"source_content_type":"","patch_set":12,"id":"ea6ebfdc_ad7eae13","updated":"2025-08-20 05:39:38.000000000","message":"thanks for the reviews!","commit_id":"1bd8db907d3985849e2de06e54dfb0d9d33c6652"},{"author":{"_account_id":7847,"name":"Alistair Coles","email":"alistairncoles@gmail.com","username":"acoles"},"change_message_id":"b7b5fe80814e2e780aa7a7c1c2dc103f8a5d9224","unresolved":false,"context_lines":[],"source_content_type":"","patch_set":14,"id":"81907587_76a11cc7","updated":"2025-08-22 10:49:48.000000000","message":"The refactoring worked out quite nicely.\n\nchecked on my vsaio with threshold\u003d0:\n```\nAug 22 10:33:15 saio object-server-6030: Slow DELETE (0.022s) for /sdb3/99/AUTH_test/test/LICENSE, status 404, start_time\u003d1755858795.816, diskfile_acquisition\u003d0.000s, metadata_read\u003d0.000s, delete_at_update\u003d0.000s, tpool_scheduling\u003d0.004s, tombstone_write\u003d0.016s, container_update\u003d0.002s (txn: tx551c54065991497ba7efe-0068a8476b)\n```\n\nI think it\u0027s worth considering plumbing the timing_breakdown down to Diskfile, and adding some directed tests once ``Diskfile.__init__`` supports a timing_breakdown arg.","commit_id":"4e96a00fee3d6aa3434249f112ba52cd78e9c285"},{"author":{"_account_id":34930,"name":"Jianjian Huo","email":"jhuo@nvidia.com","username":"jhuo"},"change_message_id":"12b1b02fd2c1560ade510d5fe29aef49c20d5b48","unresolved":false,"context_lines":[],"source_content_type":"","patch_set":16,"id":"c9dc4c93_fdf82e17","updated":"2026-02-18 17:11:48.000000000","message":"recheck","commit_id":"ac67a7601ace5b02d4104e49f9b989fa861805c1"},{"author":{"_account_id":1179,"name":"Clay Gerrard","email":"clay.gerrard@gmail.com","username":"clay-gerrard"},"change_message_id":"28a2f9377e1497f42efe1cae034f00530df68a3f","unresolved":false,"context_lines":[],"source_content_type":"","patch_set":17,"id":"bd6e9d30_7034d5d9","updated":"2026-03-10 20:23:06.000000000","message":"I\u0027m more interested in getting better telemetry around the distribution of `tpool_scheduling timing` than I am on figuring out how to merge the very-specific/purpose-built \"slow delete\" log message specifically.","commit_id":"549761e841a264ef13f1d65876bb65e84e4da66a"},{"author":{"_account_id":7847,"name":"Alistair Coles","email":"alistairncoles@gmail.com","username":"acoles"},"change_message_id":"2fd1be80d7fd2c5b5b81a2c41b4399fc746a87fd","unresolved":false,"context_lines":[],"source_content_type":"","patch_set":17,"id":"3c141e82_846c93e8","updated":"2026-03-10 15:06:20.000000000","message":"We\u0027ve been carrying this in production for a while and it has revealed that pool scheduling can take quite some time:\n\n```\nstatus 404, start_time\u003d1773144173.364, diskfile_acquisition\u003d0.000s, metadata_read\u003d0.000s, delete_at_update\u003d0.000s, tpool_scheduling\u003d125.134s, tombstone_write\u003d0.519s, container_update\u003d0.000s\n```","commit_id":"549761e841a264ef13f1d65876bb65e84e4da66a"},{"author":{"_account_id":7847,"name":"Alistair Coles","email":"alistairncoles@gmail.com","username":"acoles"},"change_message_id":"5f253890ce915d4dd0c88523de9a6f3f878ed560","unresolved":false,"context_lines":[],"source_content_type":"","patch_set":17,"id":"cc68507b_2af04765","updated":"2026-03-10 14:34:29.000000000","message":"recheck","commit_id":"549761e841a264ef13f1d65876bb65e84e4da66a"},{"author":{"_account_id":1179,"name":"Clay Gerrard","email":"clay.gerrard@gmail.com","username":"clay-gerrard"},"change_message_id":"65ef969682056fab34bdfbd529aba81035ae22d4","unresolved":false,"context_lines":[],"source_content_type":"","patch_set":25,"id":"b3c06dc0_008674a1","updated":"2026-04-15 17:00:31.000000000","message":"I still don\u0027t like the \"point-based\" timing (as opposed to context based) - but great is the enemy of good or something.","commit_id":"f1e1ab317506b2feb5d8574c1f5cba9e861b13ee"}],"etc/object-server.conf-sample":[{"author":{"_account_id":7847,"name":"Alistair Coles","email":"alistairncoles@gmail.com","username":"acoles"},"change_message_id":"6dd3550ae7576c0e5fa8a4ee663580b6e03a5346","unresolved":true,"context_lines":[{"line_number":161,"context_line":"# instead rely on the object-auditor to detect and quarantine corrupted objects."},{"line_number":162,"context_line":"# etag_validate_pct \u003d 100"},{"line_number":163,"context_line":"#"},{"line_number":164,"context_line":"# The threshold to print out logs of breakdown timings for any slow delete request."},{"line_number":165,"context_line":"# slow_delete_log_threshold_seconds \u003d 120"},{"line_number":166,"context_line":"#"},{"line_number":167,"context_line":"# on PUTs, sync data every n MB"}],"source_content_type":"application/octet-stream","patch_set":7,"id":"88c559e0_4f04748d","line":164,"updated":"2025-07-04 17:52:30.000000000","message":"nit: line wrap","commit_id":"45dcc34f99c9c1d650cc554465defe9fb959af87"},{"author":{"_account_id":34930,"name":"Jianjian Huo","email":"jhuo@nvidia.com","username":"jhuo"},"change_message_id":"d97286ae290d26465c11bda7133be6ef6d5990dc","unresolved":false,"context_lines":[{"line_number":161,"context_line":"# instead rely on the object-auditor to detect and quarantine corrupted objects."},{"line_number":162,"context_line":"# etag_validate_pct \u003d 100"},{"line_number":163,"context_line":"#"},{"line_number":164,"context_line":"# The threshold to print out logs of breakdown timings for any slow delete request."},{"line_number":165,"context_line":"# slow_delete_log_threshold_seconds \u003d 120"},{"line_number":166,"context_line":"#"},{"line_number":167,"context_line":"# on PUTs, sync data every n MB"}],"source_content_type":"application/octet-stream","patch_set":7,"id":"fc692daa_4b285866","line":164,"in_reply_to":"88c559e0_4f04748d","updated":"2025-08-20 05:39:38.000000000","message":"Done","commit_id":"45dcc34f99c9c1d650cc554465defe9fb959af87"},{"author":{"_account_id":7847,"name":"Alistair Coles","email":"alistairncoles@gmail.com","username":"acoles"},"change_message_id":"b7b5fe80814e2e780aa7a7c1c2dc103f8a5d9224","unresolved":true,"context_lines":[{"line_number":170,"context_line":"#"},{"line_number":171,"context_line":"# The threshold to print out logs of breakdown timings for any slow delete"},{"line_number":172,"context_line":"# request. Set to -1 to disable slow operation logging entirely."},{"line_number":173,"context_line":"# slow_delete_log_threshold_seconds \u003d 120"},{"line_number":174,"context_line":"#"},{"line_number":175,"context_line":"# on PUTs, sync data every n MB"},{"line_number":176,"context_line":"# mb_per_sync \u003d 512"}],"source_content_type":"application/octet-stream","patch_set":14,"id":"2e058dba_2c3a017f","line":173,"updated":"2025-08-22 10:49:48.000000000","message":"hmmm, now we have -1 \u003d\u003d disable, should *that* be the default?","commit_id":"4e96a00fee3d6aa3434249f112ba52cd78e9c285"},{"author":{"_account_id":34930,"name":"Jianjian Huo","email":"jhuo@nvidia.com","username":"jhuo"},"change_message_id":"95556eb3fa51a200043d8b197d8085d443501c10","unresolved":true,"context_lines":[{"line_number":170,"context_line":"#"},{"line_number":171,"context_line":"# The threshold to print out logs of breakdown timings for any slow delete"},{"line_number":172,"context_line":"# request. Set to -1 to disable slow operation logging entirely."},{"line_number":173,"context_line":"# slow_delete_log_threshold_seconds \u003d 120"},{"line_number":174,"context_line":"#"},{"line_number":175,"context_line":"# on PUTs, sync data every n MB"},{"line_number":176,"context_line":"# mb_per_sync \u003d 512"}],"source_content_type":"application/octet-stream","patch_set":14,"id":"c06d1407_ad7ae9aa","line":173,"in_reply_to":"2e058dba_2c3a017f","updated":"2025-08-23 01:17:32.000000000","message":"``120`` is what we intend to use on prod for everyday monitoring, which should be the default?","commit_id":"4e96a00fee3d6aa3434249f112ba52cd78e9c285"}],"swift/obj/diskfile.py":[{"author":{"_account_id":7847,"name":"Alistair Coles","email":"alistairncoles@gmail.com","username":"acoles"},"change_message_id":"b7b5fe80814e2e780aa7a7c1c2dc103f8a5d9224","unresolved":true,"context_lines":[{"line_number":1956,"context_line":"    def _finalize_put(self, metadata, target_path, cleanup,"},{"line_number":1957,"context_line":"                      logger_thread_locals):"},{"line_number":1958,"context_line":"        # Access timing_breakdown from the parent diskfile"},{"line_number":1959,"context_line":"        timing_breakdown \u003d getattr(self._diskfile, \u0027timing_breakdown\u0027, None)"},{"line_number":1960,"context_line":"        if timing_breakdown:"},{"line_number":1961,"context_line":"            timing_breakdown.record(\u0027tpool_scheduling\u0027)"},{"line_number":1962,"context_line":""}],"source_content_type":"text/x-python","patch_set":14,"id":"6931a0dd_69273b94","line":1959,"updated":"2025-08-22 10:49:48.000000000","message":"see comment in server.py - we could just pass ``timing_breakdown`` to the Diskfile constructor.\n\nAlso, I have a slight concern that we have a diff for diskfile.py but not test_diskfile.py. Clearly it is covered in test_server, but it\u0027s nice to have the diskfile unit independently covered.\n\nPerhaps if we passed the ``timing_breakdown`` as a kwarg it would be more obvious where to add a tests to test_diskfile.py as well.","commit_id":"4e96a00fee3d6aa3434249f112ba52cd78e9c285"},{"author":{"_account_id":34930,"name":"Jianjian Huo","email":"jhuo@nvidia.com","username":"jhuo"},"change_message_id":"95556eb3fa51a200043d8b197d8085d443501c10","unresolved":false,"context_lines":[{"line_number":1956,"context_line":"    def _finalize_put(self, metadata, target_path, cleanup,"},{"line_number":1957,"context_line":"                      logger_thread_locals):"},{"line_number":1958,"context_line":"        # Access timing_breakdown from the parent diskfile"},{"line_number":1959,"context_line":"        timing_breakdown \u003d getattr(self._diskfile, \u0027timing_breakdown\u0027, None)"},{"line_number":1960,"context_line":"        if timing_breakdown:"},{"line_number":1961,"context_line":"            timing_breakdown.record(\u0027tpool_scheduling\u0027)"},{"line_number":1962,"context_line":""}],"source_content_type":"text/x-python","patch_set":14,"id":"cd0caa91_0ae2492b","line":1959,"in_reply_to":"6931a0dd_69273b94","updated":"2025-08-23 01:17:32.000000000","message":"Acknowledged","commit_id":"4e96a00fee3d6aa3434249f112ba52cd78e9c285"},{"author":{"_account_id":1179,"name":"Clay Gerrard","email":"clay.gerrard@gmail.com","username":"clay-gerrard"},"change_message_id":"28a2f9377e1497f42efe1cae034f00530df68a3f","unresolved":true,"context_lines":[{"line_number":1956,"context_line":"    def _finalize_put(self, metadata, target_path, cleanup,"},{"line_number":1957,"context_line":"                      logger_thread_locals):"},{"line_number":1958,"context_line":"        if self._diskfile.timing_breakdown:"},{"line_number":1959,"context_line":"            self._diskfile.timing_breakdown.record(\u0027tpool_scheduling\u0027)"},{"line_number":1960,"context_line":""},{"line_number":1961,"context_line":"        if logger_thread_locals is not None:"},{"line_number":1962,"context_line":"            self.logger.thread_locals \u003d logger_thread_locals"}],"source_content_type":"text/x-python","patch_set":17,"id":"e13db306_05562a96","line":1959,"updated":"2026-03-10 20:23:06.000000000","message":"given that this is THE problem:\n\n```\n2026-03-10T12:05:20.287192+00:00 s8k-sjc11-a01-obj-06 object-server: warning Slow DELETE (145.505s) for /d40597/196706/..., status 404, start_time\u003d1773144174.782, diskfile_acquisition\u003d0.000s, metadata_read\u003d0.000s, delete_at_update\u003d0.000s, tpool_scheduling\u003d145.383s, tombstone_write\u003d0.122s, container_update\u003d0.000s (txn: tx0ad03521a1e04e16a56cd-0069b0086e-s8k-sjc11-b24-pxy-01)\n```\n\nI wonder if we couldn\u0027t find a way to throw a timing_since stat around it so we could see the *distribution* of the tpool scheduling delay instead of just the outliers","commit_id":"549761e841a264ef13f1d65876bb65e84e4da66a"},{"author":{"_account_id":1179,"name":"Clay Gerrard","email":"clay.gerrard@gmail.com","username":"clay-gerrard"},"change_message_id":"65ef969682056fab34bdfbd529aba81035ae22d4","unresolved":true,"context_lines":[{"line_number":1956,"context_line":"    def _finalize_put(self, metadata, target_path, cleanup,"},{"line_number":1957,"context_line":"                      logger_thread_locals):"},{"line_number":1958,"context_line":"        if self._diskfile.timing_breakdown:"},{"line_number":1959,"context_line":"            self._diskfile.timing_breakdown.record(\u0027tpool_scheduling\u0027)"},{"line_number":1960,"context_line":""},{"line_number":1961,"context_line":"        if logger_thread_locals is not None:"},{"line_number":1962,"context_line":"            self.logger.thread_locals \u003d logger_thread_locals"}],"source_content_type":"text/x-python","patch_set":17,"id":"d9b07e5a_078e7a7d","line":1959,"in_reply_to":"e13db306_05562a96","updated":"2026-04-15 17:00:31.000000000","message":"turns out this isn\u0027t always the ONLY slow part\n\nIn another recent production investigation we saw that the timing between the object server and here was \"only\" ~2s","commit_id":"549761e841a264ef13f1d65876bb65e84e4da66a"},{"author":{"_account_id":1179,"name":"Clay Gerrard","email":"clay.gerrard@gmail.com","username":"clay-gerrard"},"change_message_id":"28a2f9377e1497f42efe1cae034f00530df68a3f","unresolved":true,"context_lines":[{"line_number":2483,"context_line":"        self._dirs_created \u003d 0"},{"line_number":2484,"context_line":"        self.policy \u003d policy"},{"line_number":2485,"context_line":"        self.next_part_power \u003d next_part_power"},{"line_number":2486,"context_line":"        self.timing_breakdown \u003d kwargs.get(\u0027timing_breakdown\u0027)"},{"line_number":2487,"context_line":"        if account and container and obj:"},{"line_number":2488,"context_line":"            self._name \u003d \u0027/\u0027 + \u0027/\u0027.join((account, container, obj))"},{"line_number":2489,"context_line":"            self._account \u003d account"}],"source_content_type":"text/x-python","patch_set":17,"id":"f5d4d262_8af9a1c6","line":2486,"updated":"2026-03-10 20:23:06.000000000","message":"probably BaseDiskFile instances should create an empty trace object if it\u0027s not provided so that we don\u0027t have to make the record calls conditional.","commit_id":"549761e841a264ef13f1d65876bb65e84e4da66a"}],"swift/obj/server.py":[{"author":{"_account_id":34930,"name":"Jianjian Huo","email":"jhuo@nvidia.com","username":"jhuo"},"change_message_id":"7d28b7edb6160969ca0be4989b171aee87ba590a","unresolved":true,"context_lines":[{"line_number":1264,"context_line":"    @public"},{"line_number":1265,"context_line":"    @timing_stats()"},{"line_number":1266,"context_line":"    @labeled_timing_stats(metric\u003dLABELED_METRIC_NAME)"},{"line_number":1267,"context_line":"    def DELETE(self, request, timing_stats_labels):"},{"line_number":1268,"context_line":"        \"\"\"Handle HTTP DELETE requests for the Swift Object Server.\"\"\""},{"line_number":1269,"context_line":"        device, partition, account, container, obj, policy \u003d \\"},{"line_number":1270,"context_line":"            get_obj_name_and_placement(request)"}],"source_content_type":"text/x-python","patch_set":2,"id":"2833c8ed_91a72501","line":1267,"updated":"2025-05-29 01:14:29.000000000","message":"still need to add similar timing breakdown logging for REPLICATE","commit_id":"6d46fafa5ded9edcbe106ebf6a166ff4ad8db0ea"},{"author":{"_account_id":34930,"name":"Jianjian Huo","email":"jhuo@nvidia.com","username":"jhuo"},"change_message_id":"d97286ae290d26465c11bda7133be6ef6d5990dc","unresolved":false,"context_lines":[{"line_number":1264,"context_line":"    @public"},{"line_number":1265,"context_line":"    @timing_stats()"},{"line_number":1266,"context_line":"    @labeled_timing_stats(metric\u003dLABELED_METRIC_NAME)"},{"line_number":1267,"context_line":"    def DELETE(self, request, timing_stats_labels):"},{"line_number":1268,"context_line":"        \"\"\"Handle HTTP DELETE requests for the Swift Object Server.\"\"\""},{"line_number":1269,"context_line":"        device, partition, account, container, obj, policy \u003d \\"},{"line_number":1270,"context_line":"            get_obj_name_and_placement(request)"}],"source_content_type":"text/x-python","patch_set":2,"id":"5589848c_ccbe82dc","line":1267,"in_reply_to":"2833c8ed_91a72501","updated":"2025-08-20 05:39:38.000000000","message":"Done","commit_id":"6d46fafa5ded9edcbe106ebf6a166ff4ad8db0ea"},{"author":{"_account_id":34930,"name":"Jianjian Huo","email":"jhuo@nvidia.com","username":"jhuo"},"change_message_id":"7d28b7edb6160969ca0be4989b171aee87ba590a","unresolved":true,"context_lines":[{"line_number":1375,"context_line":"        # Logging total time and timing breakdown if slow"},{"line_number":1376,"context_line":"        total_time \u003d time.time() - start_time"},{"line_number":1377,"context_line":""},{"line_number":1378,"context_line":"        if total_time \u003e 10.0:"},{"line_number":1379,"context_line":"            timing_parts \u003d []"},{"line_number":1380,"context_line":"            for operation, duration in sorted(timings.items()):"},{"line_number":1381,"context_line":"                timing_parts.append(\u0027%s\u003d%.3fs\u0027 % (operation, duration))"}],"source_content_type":"text/x-python","patch_set":2,"id":"0aa53daa_122640ed","line":1378,"updated":"2025-05-29 01:14:29.000000000","message":"this can be a new config and put into a helper function.","commit_id":"6d46fafa5ded9edcbe106ebf6a166ff4ad8db0ea"},{"author":{"_account_id":34930,"name":"Jianjian Huo","email":"jhuo@nvidia.com","username":"jhuo"},"change_message_id":"d5e0d3f127394fdfe043723fd4079139c2afdb10","unresolved":false,"context_lines":[{"line_number":1375,"context_line":"        # Logging total time and timing breakdown if slow"},{"line_number":1376,"context_line":"        total_time \u003d time.time() - start_time"},{"line_number":1377,"context_line":""},{"line_number":1378,"context_line":"        if total_time \u003e 10.0:"},{"line_number":1379,"context_line":"            timing_parts \u003d []"},{"line_number":1380,"context_line":"            for operation, duration in sorted(timings.items()):"},{"line_number":1381,"context_line":"                timing_parts.append(\u0027%s\u003d%.3fs\u0027 % (operation, duration))"}],"source_content_type":"text/x-python","patch_set":2,"id":"da2c57f7_ba0db58b","line":1378,"in_reply_to":"0aa53daa_122640ed","updated":"2025-06-12 20:08:37.000000000","message":"Done","commit_id":"6d46fafa5ded9edcbe106ebf6a166ff4ad8db0ea"},{"author":{"_account_id":7847,"name":"Alistair Coles","email":"alistairncoles@gmail.com","username":"acoles"},"change_message_id":"31716740b9e2727fcce63c8db6fa0ea27a735a54","unresolved":true,"context_lines":[{"line_number":167,"context_line":"        self.etag_validate_frac \u003d config_percent_value("},{"line_number":168,"context_line":"            conf.get(\"etag_validate_pct\", 100))"},{"line_number":169,"context_line":"        self.slow_delete_log_threshold \u003d float("},{"line_number":170,"context_line":"            conf.get(\u0027slow_delete_log_threshold_seconds\u0027, 120))"},{"line_number":171,"context_line":""},{"line_number":172,"context_line":"        default_allowed_headers \u003d \u0027\u0027\u0027"},{"line_number":173,"context_line":"            content-disposition,"}],"source_content_type":"text/x-python","patch_set":7,"id":"3ddc9c7d_4cc45da8","line":170,"updated":"2025-07-07 12:04:28.000000000","message":"so this default is different from the ``DEFAULT_SLOW_REQUEST_THRESHOLD \u003d 60.0`` which makes me wonder when the DEFAULT_SLOW_REQUEST_THRESHOLD is ever appropriate","commit_id":"45dcc34f99c9c1d650cc554465defe9fb959af87"},{"author":{"_account_id":34930,"name":"Jianjian Huo","email":"jhuo@nvidia.com","username":"jhuo"},"change_message_id":"d97286ae290d26465c11bda7133be6ef6d5990dc","unresolved":false,"context_lines":[{"line_number":167,"context_line":"        self.etag_validate_frac \u003d config_percent_value("},{"line_number":168,"context_line":"            conf.get(\"etag_validate_pct\", 100))"},{"line_number":169,"context_line":"        self.slow_delete_log_threshold \u003d float("},{"line_number":170,"context_line":"            conf.get(\u0027slow_delete_log_threshold_seconds\u0027, 120))"},{"line_number":171,"context_line":""},{"line_number":172,"context_line":"        default_allowed_headers \u003d \u0027\u0027\u0027"},{"line_number":173,"context_line":"            content-disposition,"}],"source_content_type":"text/x-python","patch_set":7,"id":"4130d0a3_fd9881c4","line":170,"in_reply_to":"3ddc9c7d_4cc45da8","updated":"2025-08-20 05:39:38.000000000","message":"good suggestion, I got ``DEFAULT_SLOW_REQUEST_THRESHOLD`` removed.","commit_id":"45dcc34f99c9c1d650cc554465defe9fb959af87"},{"author":{"_account_id":7847,"name":"Alistair Coles","email":"alistairncoles@gmail.com","username":"acoles"},"change_message_id":"6dd3550ae7576c0e5fa8a4ee663580b6e03a5346","unresolved":true,"context_lines":[{"line_number":1286,"context_line":"                policy\u003dpolicy, next_part_power\u003dnext_part_power)"},{"line_number":1287,"context_line":"        except DiskFileDeviceUnavailable:"},{"line_number":1288,"context_line":"            record_slow_timing("},{"line_number":1289,"context_line":"                timing_breakdown, \u0027diskfile_acquisition\u0027, timing_start)"},{"line_number":1290,"context_line":"            return HTTPInsufficientStorage(drive\u003ddevice, request\u003drequest)"},{"line_number":1291,"context_line":"        timing_start \u003d record_slow_timing("},{"line_number":1292,"context_line":"            timing_breakdown, \u0027diskfile_acquisition\u0027, timing_start)"}],"source_content_type":"text/x-python","patch_set":7,"id":"16c36bb9_9ce08920","line":1289,"updated":"2025-07-04 17:52:30.000000000","message":"IMHO it would be nicer for timing_breaksown to be an instance of a TimingBreakdown (or whatever name) class that provides a single method:\n\n```\nTimingBreakdown.record(event)\n```\n\nwhich reduces the burden on the caller to create and manage the timing_start variable.\n\nAll the caller needs to do is call e.g.:\n\n```\ntiming_breakdown.record(\u0027diskfile_acquisition\u0027)\n```\n\nIf we really don\u0027t want timing to start when the TimingBreakdown is instantiated then provide a TimingBreakdown.start() method too","commit_id":"45dcc34f99c9c1d650cc554465defe9fb959af87"},{"author":{"_account_id":34930,"name":"Jianjian Huo","email":"jhuo@nvidia.com","username":"jhuo"},"change_message_id":"d97286ae290d26465c11bda7133be6ef6d5990dc","unresolved":false,"context_lines":[{"line_number":1286,"context_line":"                policy\u003dpolicy, next_part_power\u003dnext_part_power)"},{"line_number":1287,"context_line":"        except DiskFileDeviceUnavailable:"},{"line_number":1288,"context_line":"            record_slow_timing("},{"line_number":1289,"context_line":"                timing_breakdown, \u0027diskfile_acquisition\u0027, timing_start)"},{"line_number":1290,"context_line":"            return HTTPInsufficientStorage(drive\u003ddevice, request\u003drequest)"},{"line_number":1291,"context_line":"        timing_start \u003d record_slow_timing("},{"line_number":1292,"context_line":"            timing_breakdown, \u0027diskfile_acquisition\u0027, timing_start)"}],"source_content_type":"text/x-python","patch_set":7,"id":"b4c5941e_bb330cf1","line":1289,"in_reply_to":"16c36bb9_9ce08920","updated":"2025-08-20 05:39:38.000000000","message":"Done","commit_id":"45dcc34f99c9c1d650cc554465defe9fb959af87"},{"author":{"_account_id":7847,"name":"Alistair Coles","email":"alistairncoles@gmail.com","username":"acoles"},"change_message_id":"31716740b9e2727fcce63c8db6fa0ea27a735a54","unresolved":true,"context_lines":[{"line_number":1323,"context_line":"                response_class \u003d HTTPNoContent"},{"line_number":1324,"context_line":"            else:"},{"line_number":1325,"context_line":"                response_class \u003d HTTPConflict"},{"line_number":1326,"context_line":"        timing_start \u003d record_slow_timing("},{"line_number":1327,"context_line":"            timing_breakdown, \u0027metadata_read\u0027, timing_start)"},{"line_number":1328,"context_line":""},{"line_number":1329,"context_line":"        response_timestamp \u003d max(orig_timestamp, req_timestamp)"}],"source_content_type":"text/x-python","patch_set":7,"id":"bcef21e9_b859777b","line":1326,"updated":"2025-07-07 12:04:28.000000000","message":"if you put this in a ``finally`` clause then the previous ``record_slow_timing`` calls with \u0027metadata_read\u0027 aren\u0027t needed - the finally handles all cases.\n\nsee https://review.opendev.org/c/openstack/swift/+/954233","commit_id":"45dcc34f99c9c1d650cc554465defe9fb959af87"},{"author":{"_account_id":34930,"name":"Jianjian Huo","email":"jhuo@nvidia.com","username":"jhuo"},"change_message_id":"d97286ae290d26465c11bda7133be6ef6d5990dc","unresolved":false,"context_lines":[{"line_number":1323,"context_line":"                response_class \u003d HTTPNoContent"},{"line_number":1324,"context_line":"            else:"},{"line_number":1325,"context_line":"                response_class \u003d HTTPConflict"},{"line_number":1326,"context_line":"        timing_start \u003d record_slow_timing("},{"line_number":1327,"context_line":"            timing_breakdown, \u0027metadata_read\u0027, timing_start)"},{"line_number":1328,"context_line":""},{"line_number":1329,"context_line":"        response_timestamp \u003d max(orig_timestamp, req_timestamp)"}],"source_content_type":"text/x-python","patch_set":7,"id":"3a1e68f9_5df1abea","line":1326,"in_reply_to":"bcef21e9_b859777b","updated":"2025-08-20 05:39:38.000000000","message":"Done","commit_id":"45dcc34f99c9c1d650cc554465defe9fb959af87"},{"author":{"_account_id":7847,"name":"Alistair Coles","email":"alistairncoles@gmail.com","username":"acoles"},"change_message_id":"31716740b9e2727fcce63c8db6fa0ea27a735a54","unresolved":true,"context_lines":[{"line_number":1369,"context_line":"                    timing_breakdown, \u0027tombstone_write\u0027, timing_start)"},{"line_number":1370,"context_line":"                return HTTPInsufficientStorage(drive\u003ddevice, request\u003drequest)"},{"line_number":1371,"context_line":"            timing_start \u003d record_slow_timing("},{"line_number":1372,"context_line":"                timing_breakdown, \u0027tombstone_write\u0027, timing_start)"},{"line_number":1373,"context_line":""},{"line_number":1374,"context_line":"            self.container_update("},{"line_number":1375,"context_line":"                \u0027DELETE\u0027, account, container, obj, request,"}],"source_content_type":"text/x-python","patch_set":7,"id":"8cbbeab2_81ef5bd2","line":1372,"updated":"2025-07-07 12:04:28.000000000","message":"you can use a finally clause here to record \u0027tombstone_write\u0027 just once (finally is executed even when the try returns https://docs.python.org/3/tutorial/errors.html#defining-clean-up-actions)","commit_id":"45dcc34f99c9c1d650cc554465defe9fb959af87"},{"author":{"_account_id":34930,"name":"Jianjian Huo","email":"jhuo@nvidia.com","username":"jhuo"},"change_message_id":"d97286ae290d26465c11bda7133be6ef6d5990dc","unresolved":false,"context_lines":[{"line_number":1369,"context_line":"                    timing_breakdown, \u0027tombstone_write\u0027, timing_start)"},{"line_number":1370,"context_line":"                return HTTPInsufficientStorage(drive\u003ddevice, request\u003drequest)"},{"line_number":1371,"context_line":"            timing_start \u003d record_slow_timing("},{"line_number":1372,"context_line":"                timing_breakdown, \u0027tombstone_write\u0027, timing_start)"},{"line_number":1373,"context_line":""},{"line_number":1374,"context_line":"            self.container_update("},{"line_number":1375,"context_line":"                \u0027DELETE\u0027, account, container, obj, request,"}],"source_content_type":"text/x-python","patch_set":7,"id":"7be34225_eaed85d2","line":1372,"in_reply_to":"8cbbeab2_81ef5bd2","updated":"2025-08-20 05:39:38.000000000","message":"Done","commit_id":"45dcc34f99c9c1d650cc554465defe9fb959af87"},{"author":{"_account_id":7847,"name":"Alistair Coles","email":"alistairncoles@gmail.com","username":"acoles"},"change_message_id":"b7b5fe80814e2e780aa7a7c1c2dc103f8a5d9224","unresolved":true,"context_lines":[{"line_number":1301,"context_line":"        req_timestamp \u003d valid_timestamp(request)"},{"line_number":1302,"context_line":"        next_part_power \u003d request.headers.get(\u0027X-Backend-Next-Part-Power\u0027)"},{"line_number":1303,"context_line":"        try:"},{"line_number":1304,"context_line":"            disk_file \u003d self.get_diskfile("},{"line_number":1305,"context_line":"                device, partition, account, container, obj,"},{"line_number":1306,"context_line":"                policy\u003dpolicy, next_part_power\u003dnext_part_power)"},{"line_number":1307,"context_line":"            disk_file.timing_breakdown \u003d timing_breakdown"}],"source_content_type":"text/x-python","patch_set":14,"id":"a567f341_1f78d23d","line":1304,"range":{"start_line":1304,"start_character":29,"end_line":1304,"end_character":41},"updated":"2025-08-22 10:49:48.000000000","message":"``get_diskfile`` accepts kwargs that are passed all the way through to the Diskfile constructor, so you could pass ``timing_breakdown`` in that way and avoid the getattr in ``_finalize_put``\n\n```\ndiff --git a/swift/obj/diskfile.py b/swift/obj/diskfile.py\nindex 8d3cb3cf4..44efcc718 100644\n--- a/swift/obj/diskfile.py\n+++ b/swift/obj/diskfile.py\n@@ -1955,10 +1955,8 @@ class BaseDiskFileWriter(object):\n \n     def _finalize_put(self, metadata, target_path, cleanup,\n                       logger_thread_locals):\n-        # Access timing_breakdown from the parent diskfile\n-        timing_breakdown \u003d getattr(self._diskfile, \u0027timing_breakdown\u0027, None)\n-        if timing_breakdown:\n-            timing_breakdown.record(\u0027tpool_scheduling\u0027)\n+        if self._diskfile.timing_breakdown:\n+            self._diskfile.timing_breakdown.record(\u0027tpool_scheduling\u0027)\n \n         if logger_thread_locals is not None:\n             self.logger.thread_locals \u003d logger_thread_locals\n@@ -2467,7 +2465,8 @@ class BaseDiskFile(object):\n     def __init__(self, mgr, device_path, partition,\n                  account\u003dNone, container\u003dNone, obj\u003dNone, _datadir\u003dNone,\n                  policy\u003dNone, use_splice\u003dFalse, pipe_size\u003dNone,\n-                 open_expired\u003dFalse, next_part_power\u003dNone, **kwargs):\n+                 open_expired\u003dFalse, next_part_power\u003dNone,\n+                 timing_breakdown\u003dNone, **kwargs):\n         self._manager \u003d mgr\n         self._device_path \u003d device_path\n         self._logger \u003d mgr.logger\n@@ -2485,6 +2484,7 @@ class BaseDiskFile(object):\n         self._dirs_created \u003d 0\n         self.policy \u003d policy\n         self.next_part_power \u003d next_part_power\n+        self.timing_breakdown \u003d timing_breakdown\n         if account and container and obj:\n             self._name \u003d \u0027/\u0027 + \u0027/\u0027.join((account, container, obj))\n             self._account \u003d account\ndiff --git a/swift/obj/server.py b/swift/obj/server.py\nindex bed14fd64..8ddde4f9d 100644\n--- a/swift/obj/server.py\n+++ b/swift/obj/server.py\n@@ -1303,8 +1303,8 @@ class ObjectController(BaseStorageServer):\n         try:\n             disk_file \u003d self.get_diskfile(\n                 device, partition, account, container, obj,\n-                policy\u003dpolicy, next_part_power\u003dnext_part_power)\n-            disk_file.timing_breakdown \u003d timing_breakdown\n+                policy\u003dpolicy, next_part_power\u003dnext_part_power,\n+                timing_breakdown\u003dtiming_breakdown)\n         except DiskFileDeviceUnavailable:\n             return HTTPInsufficientStorage(drive\u003ddevice, request\u003drequest)\n         finally:\n\n```","commit_id":"4e96a00fee3d6aa3434249f112ba52cd78e9c285"},{"author":{"_account_id":34930,"name":"Jianjian Huo","email":"jhuo@nvidia.com","username":"jhuo"},"change_message_id":"95556eb3fa51a200043d8b197d8085d443501c10","unresolved":false,"context_lines":[{"line_number":1301,"context_line":"        req_timestamp \u003d valid_timestamp(request)"},{"line_number":1302,"context_line":"        next_part_power \u003d request.headers.get(\u0027X-Backend-Next-Part-Power\u0027)"},{"line_number":1303,"context_line":"        try:"},{"line_number":1304,"context_line":"            disk_file \u003d self.get_diskfile("},{"line_number":1305,"context_line":"                device, partition, account, container, obj,"},{"line_number":1306,"context_line":"                policy\u003dpolicy, next_part_power\u003dnext_part_power)"},{"line_number":1307,"context_line":"            disk_file.timing_breakdown \u003d timing_breakdown"}],"source_content_type":"text/x-python","patch_set":14,"id":"041b7ef8_6725ccd1","line":1304,"range":{"start_line":1304,"start_character":29,"end_line":1304,"end_character":41},"in_reply_to":"a567f341_1f78d23d","updated":"2025-08-23 01:17:32.000000000","message":"good suggestion, I will pass ``timing_breakdown`` as a kwargs parameter.","commit_id":"4e96a00fee3d6aa3434249f112ba52cd78e9c285"},{"author":{"_account_id":7847,"name":"Alistair Coles","email":"alistairncoles@gmail.com","username":"acoles"},"change_message_id":"2fd1be80d7fd2c5b5b81a2c41b4399fc746a87fd","unresolved":true,"context_lines":[{"line_number":129,"context_line":"    eventlet.wsgi to force the headers out, so we use an"},{"line_number":130,"context_line":"    EventletPlungerString to empty out all of Eventlet\u0027s buffers."},{"line_number":131,"context_line":"    \"\"\""},{"line_number":132,"context_line":""},{"line_number":133,"context_line":"    def __len__(self):"},{"line_number":134,"context_line":"        return wsgi.MINIMUM_CHUNK_SIZE + 1"},{"line_number":135,"context_line":""}],"source_content_type":"text/x-python","patch_set":17,"id":"85f87b2d_48c99b49","line":132,"updated":"2026-03-10 15:06:20.000000000","message":"nit: unrelated whitespace change","commit_id":"549761e841a264ef13f1d65876bb65e84e4da66a"},{"author":{"_account_id":1179,"name":"Clay Gerrard","email":"clay.gerrard@gmail.com","username":"clay-gerrard"},"change_message_id":"28a2f9377e1497f42efe1cae034f00530df68a3f","unresolved":true,"context_lines":[{"line_number":1353,"context_line":"            request, device, account, container, obj, policy, {},"},{"line_number":1354,"context_line":"            orig_delete_at, 0"},{"line_number":1355,"context_line":"        )"},{"line_number":1356,"context_line":"        timing_breakdown.record(\u0027delete_at_update\u0027)"},{"line_number":1357,"context_line":""},{"line_number":1358,"context_line":"        if orig_timestamp \u003c req_timestamp:"},{"line_number":1359,"context_line":"            try:"}],"source_content_type":"text/x-python","patch_set":17,"id":"67432736_3b749757","line":1356,"updated":"2026-03-10 20:23:06.000000000","message":"I think there\u0027s an implicit assumption here that everything between `metadata_read` and `_conditional_delete_at_update` is \"fast\"\n\n... that\u0027s probably true today, but if we *added* some new behavior up there it and it hits some kind of lock contention the slowness get \"bundled into\" the `delete_at_update` timing even if happened *before* we called `_conditional_delete_at_update` (and we won\u0027t know which one it is)","commit_id":"549761e841a264ef13f1d65876bb65e84e4da66a"},{"author":{"_account_id":1179,"name":"Clay Gerrard","email":"clay.gerrard@gmail.com","username":"clay-gerrard"},"change_message_id":"28a2f9377e1497f42efe1cae034f00530df68a3f","unresolved":true,"context_lines":[{"line_number":1359,"context_line":"            try:"},{"line_number":1360,"context_line":"                disk_file.delete(req_timestamp)"},{"line_number":1361,"context_line":"            except DiskFileNoSpace:"},{"line_number":1362,"context_line":"                return HTTPInsufficientStorage(drive\u003ddevice, request\u003drequest)"},{"line_number":1363,"context_line":"            finally:"},{"line_number":1364,"context_line":"                timing_breakdown.record(\u0027tombstone_write\u0027)"},{"line_number":1365,"context_line":"            self.container_update("}],"source_content_type":"text/x-python","patch_set":17,"id":"de5b1e11_04ecc5e4","line":1362,"updated":"2026-03-10 20:23:06.000000000","message":"b/c the record happens in `finally` we always record tombstone_write - but I don\u0027t think 507 is doing that.","commit_id":"549761e841a264ef13f1d65876bb65e84e4da66a"},{"author":{"_account_id":1179,"name":"Clay Gerrard","email":"clay.gerrard@gmail.com","username":"clay-gerrard"},"change_message_id":"28a2f9377e1497f42efe1cae034f00530df68a3f","unresolved":true,"context_lines":[{"line_number":1361,"context_line":"            except DiskFileNoSpace:"},{"line_number":1362,"context_line":"                return HTTPInsufficientStorage(drive\u003ddevice, request\u003drequest)"},{"line_number":1363,"context_line":"            finally:"},{"line_number":1364,"context_line":"                timing_breakdown.record(\u0027tombstone_write\u0027)"},{"line_number":1365,"context_line":"            self.container_update("},{"line_number":1366,"context_line":"                \u0027DELETE\u0027, account, container, obj, request,"},{"line_number":1367,"context_line":"                HeaderKeyDict({\u0027x-timestamp\u0027: req_timestamp.internal}),"}],"source_content_type":"text/x-python","patch_set":17,"id":"c9916e70_a6541889","line":1364,"updated":"2026-03-10 20:23:06.000000000","message":"I think it\u0027s weird that this code outside of the context of `disk_file.delete()` has to say what the traced module *did* in order to record how long it took.\n\nI think the otel pattern looks better:\n\n```\nwith trace.span(\u0027disk_file.delete\u0027):\n    disk_file.delete(req_timestamp)\n```\n\nwith the assumption being that \"if disk_file.delete takes \u003e120s: you can instrument it with a nested-sub-span!\"","commit_id":"549761e841a264ef13f1d65876bb65e84e4da66a"},{"author":{"_account_id":1179,"name":"Clay Gerrard","email":"clay.gerrard@gmail.com","username":"clay-gerrard"},"change_message_id":"65ef969682056fab34bdfbd529aba81035ae22d4","unresolved":true,"context_lines":[{"line_number":1361,"context_line":"            except DiskFileNoSpace:"},{"line_number":1362,"context_line":"                return HTTPInsufficientStorage(drive\u003ddevice, request\u003drequest)"},{"line_number":1363,"context_line":"            finally:"},{"line_number":1364,"context_line":"                timing_breakdown.record(\u0027tombstone_write\u0027)"},{"line_number":1365,"context_line":"            self.container_update("},{"line_number":1366,"context_line":"                \u0027DELETE\u0027, account, container, obj, request,"},{"line_number":1367,"context_line":"                HeaderKeyDict({\u0027x-timestamp\u0027: req_timestamp.internal}),"}],"source_content_type":"text/x-python","patch_set":17,"id":"4a789b6d_d53c6d9e","line":1364,"in_reply_to":"c9916e70_a6541889","updated":"2026-04-15 17:00:31.000000000","message":".. while as the timing between the diskfile tpool and this finally block back in the object server was \u003e100s (!!)\n\n... so we *suspect* it was probably IO/disk-utilization (but there MAY be some myster with tpool return (as opposed to start) scheduling that is not fully understood)","commit_id":"549761e841a264ef13f1d65876bb65e84e4da66a"},{"author":{"_account_id":1179,"name":"Clay Gerrard","email":"clay.gerrard@gmail.com","username":"clay-gerrard"},"change_message_id":"28a2f9377e1497f42efe1cae034f00530df68a3f","unresolved":true,"context_lines":[{"line_number":1422,"context_line":"    def __call__(self, env, start_response):"},{"line_number":1423,"context_line":"        \"\"\"WSGI Application entry point for the Swift Object Server.\"\"\""},{"line_number":1424,"context_line":"        start_time \u003d time.time()"},{"line_number":1425,"context_line":"        req \u003d Request(env)"},{"line_number":1426,"context_line":"        self.logger.txn_id \u003d req.headers.get(\u0027x-trans-id\u0027, None)"},{"line_number":1427,"context_line":""},{"line_number":1428,"context_line":"        if not check_utf8(wsgi_to_str(req.path_info), internal\u003dTrue):"}],"source_content_type":"text/x-python","patch_set":17,"id":"1473f822_ef4e9701","line":1425,"updated":"2026-03-10 20:23:06.000000000","message":"I feel like this would be the ideal place to start the trace.","commit_id":"549761e841a264ef13f1d65876bb65e84e4da66a"},{"author":{"_account_id":1179,"name":"Clay Gerrard","email":"clay.gerrard@gmail.com","username":"clay-gerrard"},"change_message_id":"28a2f9377e1497f42efe1cae034f00530df68a3f","unresolved":true,"context_lines":[{"line_number":1448,"context_line":"        if self.log_requests:"},{"line_number":1449,"context_line":"            log_line \u003d get_log_line(req, res, trans_time, \u0027\u0027, self.log_format,"},{"line_number":1450,"context_line":"                                    self.anonymization_method,"},{"line_number":1451,"context_line":"                                    self.anonymization_salt)"},{"line_number":1452,"context_line":"            if req.method in (\u0027REPLICATE\u0027, \u0027SSYNC\u0027) or \\"},{"line_number":1453,"context_line":"                    \u0027X-Backend-Replication\u0027 in req.headers:"},{"line_number":1454,"context_line":"                self.logger.debug(log_line)"}],"source_content_type":"text/x-python","patch_set":17,"id":"02133c58_d965f436","line":1451,"updated":"2026-03-10 20:23:06.000000000","message":"I feel like this would be the ideal time to a warning on slow responses.","commit_id":"549761e841a264ef13f1d65876bb65e84e4da66a"}],"test/unit/obj/test_diskfile.py":[{"author":{"_account_id":7847,"name":"Alistair Coles","email":"alistairncoles@gmail.com","username":"acoles"},"change_message_id":"bb1424b6fb2434a70a1cd452b61a9dbbff6ec77b","unresolved":true,"context_lines":[{"line_number":6260,"context_line":""},{"line_number":6261,"context_line":"        self.assertFalse(_m_renamer.called)"},{"line_number":6262,"context_line":""},{"line_number":6263,"context_line":"    def test_diskfile_writer_timing_breakdown(self):"},{"line_number":6264,"context_line":"        timing_breakdown \u003d TimingBreakdown()"},{"line_number":6265,"context_line":"        df \u003d self._simple_get_diskfile(timing_breakdown\u003dtiming_breakdown)"},{"line_number":6266,"context_line":""}],"source_content_type":"text/x-python","patch_set":15,"id":"d6486086_00653f6c","line":6263,"updated":"2025-09-01 14:44:39.000000000","message":"+1 for adding this test","commit_id":"b404f5634eabc8e2d9c89f838e0838ce1321c589"},{"author":{"_account_id":7847,"name":"Alistair Coles","email":"alistairncoles@gmail.com","username":"acoles"},"change_message_id":"2fd1be80d7fd2c5b5b81a2c41b4399fc746a87fd","unresolved":false,"context_lines":[{"line_number":6260,"context_line":""},{"line_number":6261,"context_line":"        self.assertFalse(_m_renamer.called)"},{"line_number":6262,"context_line":""},{"line_number":6263,"context_line":"    def test_diskfile_writer_timing_breakdown(self):"},{"line_number":6264,"context_line":"        timing_breakdown \u003d TimingBreakdown()"},{"line_number":6265,"context_line":"        df \u003d self._simple_get_diskfile(timing_breakdown\u003dtiming_breakdown)"},{"line_number":6266,"context_line":""}],"source_content_type":"text/x-python","patch_set":15,"id":"0aa22eff_92380545","line":6263,"in_reply_to":"d6486086_00653f6c","updated":"2026-03-10 15:06:20.000000000","message":"Done","commit_id":"b404f5634eabc8e2d9c89f838e0838ce1321c589"},{"author":{"_account_id":7847,"name":"Alistair Coles","email":"alistairncoles@gmail.com","username":"acoles"},"change_message_id":"bb1424b6fb2434a70a1cd452b61a9dbbff6ec77b","unresolved":true,"context_lines":[{"line_number":6264,"context_line":"        timing_breakdown \u003d TimingBreakdown()"},{"line_number":6265,"context_line":"        df \u003d self._simple_get_diskfile(timing_breakdown\u003dtiming_breakdown)"},{"line_number":6266,"context_line":""},{"line_number":6267,"context_line":"        # Mock the record method to verify it\u0027s called"},{"line_number":6268,"context_line":"        with mock.patch.object(timing_breakdown, \u0027record\u0027) as mock_record:"},{"line_number":6269,"context_line":"            with df.create() as writer:"},{"line_number":6270,"context_line":"                writer.write(b\u0027test data\u0027)"}],"source_content_type":"text/x-python","patch_set":15,"id":"625aa9c9_cdbb1134","line":6267,"updated":"2025-09-01 14:44:39.000000000","message":"nit: or just assert the content to timing_breakdown,breakdonw:\n\n```\ndiff --git a/test/unit/obj/test_diskfile.py b/test/unit/obj/test_diskfile.py\nindex 3c1079e67..f3c565022 100644\n--- a/test/unit/obj/test_diskfile.py\n+++ b/test/unit/obj/test_diskfile.py\n@@ -6265,16 +6265,16 @@ class DiskFileMixin(BaseDiskFileTestMixin):\n         df \u003d self._simple_get_diskfile(timing_breakdown\u003dtiming_breakdown)\n \n         # Mock the record method to verify it\u0027s called\n-        with mock.patch.object(timing_breakdown, \u0027record\u0027) as mock_record:\n-            with df.create() as writer:\n-                writer.write(b\u0027test data\u0027)\n-                metadata \u003d {\n-                    \u0027ETag\u0027: \u0027test_etag\u0027,\n-                    \u0027X-Timestamp\u0027: Timestamp.now().internal,\n-                    \u0027Content-Length\u0027: \u00279\u0027,\n-                }\n-                writer.put(metadata)\n-        mock_record.assert_called_with(\u0027tpool_scheduling\u0027)\n+        with df.create() as writer:\n+            writer.write(b\u0027test data\u0027)\n+            metadata \u003d {\n+                \u0027ETag\u0027: \u0027test_etag\u0027,\n+                \u0027X-Timestamp\u0027: Timestamp.now().internal,\n+                \u0027Content-Length\u0027: \u00279\u0027,\n+            }\n+            writer.put(metadata)\n+        self.assertEqual([(\u0027tpool_scheduling\u0027, mock.ANY)],\n+                         timing_breakdown.breakdown)\n \n \n @patch_policies(test_policies)\n\n```","commit_id":"b404f5634eabc8e2d9c89f838e0838ce1321c589"}],"test/unit/obj/test_server.py":[{"author":{"_account_id":7847,"name":"Alistair Coles","email":"alistairncoles@gmail.com","username":"acoles"},"change_message_id":"31716740b9e2727fcce63c8db6fa0ea27a735a54","unresolved":true,"context_lines":[{"line_number":5729,"context_line":"            \u0027warning\u0027)"},{"line_number":5730,"context_line":"        self.assertEqual(len(error_lines), 0)"},{"line_number":5731,"context_line":""},{"line_number":5732,"context_line":"    def test_DELETE_slow_request_log(self):"},{"line_number":5733,"context_line":"        # Test with a slow DELETE"},{"line_number":5734,"context_line":"        req \u003d Request.blank(\u0027/sda1/p/a/c/o_slow\u0027,"},{"line_number":5735,"context_line":"                            environ\u003d{\u0027REQUEST_METHOD\u0027: \u0027PUT\u0027},"}],"source_content_type":"text/x-python","patch_set":7,"id":"a2b1dd4b_be272703","line":5732,"updated":"2025-07-07 12:04:28.000000000","message":"this test probably should have the sanity check\n\n```\nself.assertEqual(self.object_controller.slow_delete_log_threshold, 120)\n```","commit_id":"45dcc34f99c9c1d650cc554465defe9fb959af87"},{"author":{"_account_id":34930,"name":"Jianjian Huo","email":"jhuo@nvidia.com","username":"jhuo"},"change_message_id":"d97286ae290d26465c11bda7133be6ef6d5990dc","unresolved":false,"context_lines":[{"line_number":5729,"context_line":"            \u0027warning\u0027)"},{"line_number":5730,"context_line":"        self.assertEqual(len(error_lines), 0)"},{"line_number":5731,"context_line":""},{"line_number":5732,"context_line":"    def test_DELETE_slow_request_log(self):"},{"line_number":5733,"context_line":"        # Test with a slow DELETE"},{"line_number":5734,"context_line":"        req \u003d Request.blank(\u0027/sda1/p/a/c/o_slow\u0027,"},{"line_number":5735,"context_line":"                            environ\u003d{\u0027REQUEST_METHOD\u0027: \u0027PUT\u0027},"}],"source_content_type":"text/x-python","patch_set":7,"id":"e024a97e_feca5f5f","line":5732,"in_reply_to":"a2b1dd4b_be272703","updated":"2025-08-20 05:39:38.000000000","message":"Done","commit_id":"45dcc34f99c9c1d650cc554465defe9fb959af87"},{"author":{"_account_id":7847,"name":"Alistair Coles","email":"alistairncoles@gmail.com","username":"acoles"},"change_message_id":"31716740b9e2727fcce63c8db6fa0ea27a735a54","unresolved":true,"context_lines":[{"line_number":5757,"context_line":"                         \u0027tombstone_write\u003d15.000s, container_update\u003d5.100s\u0027,"},{"line_number":5758,"context_line":"                         error_lines[0])"},{"line_number":5759,"context_line":""},{"line_number":5760,"context_line":"    def test_DELETE_log_slow_503(self):"},{"line_number":5761,"context_line":""},{"line_number":5762,"context_line":"        def mock_read_metadata(self, current_time):"},{"line_number":5763,"context_line":"            raise DiskFileStateChanged()"}],"source_content_type":"text/x-python","patch_set":7,"id":"4ac1d97c_59409fb5","line":5760,"updated":"2025-07-07 12:04:28.000000000","message":"this test could be extended to cover more of the exception cases\n\nsee https://review.opendev.org/c/openstack/swift/+/954233","commit_id":"45dcc34f99c9c1d650cc554465defe9fb959af87"},{"author":{"_account_id":34930,"name":"Jianjian Huo","email":"jhuo@nvidia.com","username":"jhuo"},"change_message_id":"d97286ae290d26465c11bda7133be6ef6d5990dc","unresolved":false,"context_lines":[{"line_number":5757,"context_line":"                         \u0027tombstone_write\u003d15.000s, container_update\u003d5.100s\u0027,"},{"line_number":5758,"context_line":"                         error_lines[0])"},{"line_number":5759,"context_line":""},{"line_number":5760,"context_line":"    def test_DELETE_log_slow_503(self):"},{"line_number":5761,"context_line":""},{"line_number":5762,"context_line":"        def mock_read_metadata(self, current_time):"},{"line_number":5763,"context_line":"            raise DiskFileStateChanged()"}],"source_content_type":"text/x-python","patch_set":7,"id":"c4676382_ae8fed75","line":5760,"in_reply_to":"4ac1d97c_59409fb5","updated":"2025-08-20 05:39:38.000000000","message":"Done","commit_id":"45dcc34f99c9c1d650cc554465defe9fb959af87"},{"author":{"_account_id":7847,"name":"Alistair Coles","email":"alistairncoles@gmail.com","username":"acoles"},"change_message_id":"b7b5fe80814e2e780aa7a7c1c2dc103f8a5d9224","unresolved":true,"context_lines":[{"line_number":5782,"context_line":"        self.assertEqual(1, len(error_lines))"},{"line_number":5783,"context_line":"        self.assertEqual(\u0027Slow DELETE (120.100s) for /sda1/p/a/c/o_slow, \u0027"},{"line_number":5784,"context_line":"                         \u0027status 204, start_time\u003d1000.000, \u0027"},{"line_number":5785,"context_line":"                         \u0027diskfile_acquisition\u003d0.000s, metadata_read\u003d40.000s, \u0027"},{"line_number":5786,"context_line":"                         \u0027delete_at_update\u003d10.000s, tpool_scheduling\u003d50.000s, \u0027"},{"line_number":5787,"context_line":"                         \u0027tombstone_write\u003d15.000s, container_update\u003d5.100s\u0027,"},{"line_number":5788,"context_line":"                         error_lines[0])"}],"source_content_type":"text/x-python","patch_set":14,"id":"db3dc8a0_e9c0d986","line":5785,"range":{"start_line":5785,"start_character":47,"end_line":5785,"end_character":52},"updated":"2025-08-22 10:49:48.000000000","message":"I can\u0027t work out where the extra call to time() has been added that has caused this","commit_id":"4e96a00fee3d6aa3434249f112ba52cd78e9c285"},{"author":{"_account_id":34930,"name":"Jianjian Huo","email":"jhuo@nvidia.com","username":"jhuo"},"change_message_id":"95556eb3fa51a200043d8b197d8085d443501c10","unresolved":true,"context_lines":[{"line_number":5782,"context_line":"        self.assertEqual(1, len(error_lines))"},{"line_number":5783,"context_line":"        self.assertEqual(\u0027Slow DELETE (120.100s) for /sda1/p/a/c/o_slow, \u0027"},{"line_number":5784,"context_line":"                         \u0027status 204, start_time\u003d1000.000, \u0027"},{"line_number":5785,"context_line":"                         \u0027diskfile_acquisition\u003d0.000s, metadata_read\u003d40.000s, \u0027"},{"line_number":5786,"context_line":"                         \u0027delete_at_update\u003d10.000s, tpool_scheduling\u003d50.000s, \u0027"},{"line_number":5787,"context_line":"                         \u0027tombstone_write\u003d15.000s, container_update\u003d5.100s\u0027,"},{"line_number":5788,"context_line":"                         error_lines[0])"}],"source_content_type":"text/x-python","patch_set":14,"id":"fb00cf74_35ddf6e2","line":5785,"range":{"start_line":5785,"start_character":47,"end_line":5785,"end_character":52},"in_reply_to":"db3dc8a0_e9c0d986","updated":"2025-08-23 01:17:32.000000000","message":"there is time() called within other path in the middle of DELETE(), and my latest change actually reduced number of time() called for the slow logging decorator.","commit_id":"4e96a00fee3d6aa3434249f112ba52cd78e9c285"},{"author":{"_account_id":7847,"name":"Alistair Coles","email":"alistairncoles@gmail.com","username":"acoles"},"change_message_id":"2fd1be80d7fd2c5b5b81a2c41b4399fc746a87fd","unresolved":false,"context_lines":[{"line_number":5782,"context_line":"        self.assertEqual(1, len(error_lines))"},{"line_number":5783,"context_line":"        self.assertEqual(\u0027Slow DELETE (120.100s) for /sda1/p/a/c/o_slow, \u0027"},{"line_number":5784,"context_line":"                         \u0027status 204, start_time\u003d1000.000, \u0027"},{"line_number":5785,"context_line":"                         \u0027diskfile_acquisition\u003d0.000s, metadata_read\u003d40.000s, \u0027"},{"line_number":5786,"context_line":"                         \u0027delete_at_update\u003d10.000s, tpool_scheduling\u003d50.000s, \u0027"},{"line_number":5787,"context_line":"                         \u0027tombstone_write\u003d15.000s, container_update\u003d5.100s\u0027,"},{"line_number":5788,"context_line":"                         error_lines[0])"}],"source_content_type":"text/x-python","patch_set":14,"id":"588d54ca_54f7fc26","line":5785,"range":{"start_line":5785,"start_character":47,"end_line":5785,"end_character":52},"in_reply_to":"e8680b74_1be27b2e","updated":"2026-03-10 15:06:20.000000000","message":"Done","commit_id":"4e96a00fee3d6aa3434249f112ba52cd78e9c285"},{"author":{"_account_id":7847,"name":"Alistair Coles","email":"alistairncoles@gmail.com","username":"acoles"},"change_message_id":"bb1424b6fb2434a70a1cd452b61a9dbbff6ec77b","unresolved":true,"context_lines":[{"line_number":5782,"context_line":"        self.assertEqual(1, len(error_lines))"},{"line_number":5783,"context_line":"        self.assertEqual(\u0027Slow DELETE (120.100s) for /sda1/p/a/c/o_slow, \u0027"},{"line_number":5784,"context_line":"                         \u0027status 204, start_time\u003d1000.000, \u0027"},{"line_number":5785,"context_line":"                         \u0027diskfile_acquisition\u003d0.000s, metadata_read\u003d40.000s, \u0027"},{"line_number":5786,"context_line":"                         \u0027delete_at_update\u003d10.000s, tpool_scheduling\u003d50.000s, \u0027"},{"line_number":5787,"context_line":"                         \u0027tombstone_write\u003d15.000s, container_update\u003d5.100s\u0027,"},{"line_number":5788,"context_line":"                         error_lines[0])"}],"source_content_type":"text/x-python","patch_set":14,"id":"e8680b74_1be27b2e","line":5785,"range":{"start_line":5785,"start_character":47,"end_line":5785,"end_character":52},"in_reply_to":"fb00cf74_35ddf6e2","updated":"2025-09-01 14:44:39.000000000","message":"OIC it\u0027s one *less* call, so ``diskfile_acquisition`` is at ``now``. Thanks for explaining.","commit_id":"4e96a00fee3d6aa3434249f112ba52cd78e9c285"},{"author":{"_account_id":7847,"name":"Alistair Coles","email":"alistairncoles@gmail.com","username":"acoles"},"change_message_id":"b7b5fe80814e2e780aa7a7c1c2dc103f8a5d9224","unresolved":true,"context_lines":[{"line_number":5886,"context_line":"                         \u0027status 503, start_time\u003d1000.000, \u0027"},{"line_number":5887,"context_line":"                         \u0027diskfile_acquisition\u003d10.000s, \u0027"},{"line_number":5888,"context_line":"                         \u0027metadata_read\u003d40.000s\u0027,"},{"line_number":5889,"context_line":"                         error)"},{"line_number":5890,"context_line":""},{"line_number":5891,"context_line":"    def test_object_update_with_offset(self):"},{"line_number":5892,"context_line":"        container_updates \u003d []"}],"source_content_type":"text/x-python","patch_set":14,"id":"05fcd968_1ff28c2f","line":5889,"updated":"2025-08-22 10:49:48.000000000","message":"ok this one returns early from ``DELETE``","commit_id":"4e96a00fee3d6aa3434249f112ba52cd78e9c285"},{"author":{"_account_id":34930,"name":"Jianjian Huo","email":"jhuo@nvidia.com","username":"jhuo"},"change_message_id":"95556eb3fa51a200043d8b197d8085d443501c10","unresolved":false,"context_lines":[{"line_number":5886,"context_line":"                         \u0027status 503, start_time\u003d1000.000, \u0027"},{"line_number":5887,"context_line":"                         \u0027diskfile_acquisition\u003d10.000s, \u0027"},{"line_number":5888,"context_line":"                         \u0027metadata_read\u003d40.000s\u0027,"},{"line_number":5889,"context_line":"                         error)"},{"line_number":5890,"context_line":""},{"line_number":5891,"context_line":"    def test_object_update_with_offset(self):"},{"line_number":5892,"context_line":"        container_updates \u003d []"}],"source_content_type":"text/x-python","patch_set":14,"id":"e1a9196d_939041f5","line":5889,"in_reply_to":"05fcd968_1ff28c2f","updated":"2025-08-23 01:17:32.000000000","message":"Acknowledged","commit_id":"4e96a00fee3d6aa3434249f112ba52cd78e9c285"}]}