diff --git a/blueprints/assets/lock-ordering-cycle.diagram.py b/blueprints/assets/lock-ordering-cycle.diagram.py new file mode 100644 index 0000000..b609d77 --- /dev/null +++ b/blueprints/assets/lock-ordering-cycle.diagram.py @@ -0,0 +1,163 @@ +"""What the lock checker keeps, and the one moment it says no. + +The thing readers get wrong about lockdep is that they think it watches for a deadlock. It does +not. It keeps a directed graph whose nodes are lock classes and whose edges mean this one was held +while that one was taken, and every time it is about to add an edge it asks whether the edge would +close a cycle. That question is asked at the moment of an acquire, on one processor, with nothing +waiting for anything, which is why a report can arrive on a run that finished fine. + +This is the picture for the blueprint's section 3. The graph on the left is what is being kept. +The two threads on the right are what the module in the corpus does. The band across the bottom is +what happens after the report, which is the part that costs people a debugging session. +""" + +from kxdraw import Scene + +ALT = ( + "A picture in three parts. On the left, a small directed graph labelled the lock graph, with " + "two round-cornered nodes, lock_a and lock_b. A solid arrow runs from lock_a down to lock_b " + "labelled edge added by the first thread, meaning lock_a was held while lock_b was taken. A " + "dashed red arrow runs back up from lock_b to lock_a labelled the edge about to be added, and " + "beside it a red box reads adding this closes a cycle, so refuse it and print. In the middle, " + "two columns headed first thread and second thread, four steps in time order reading down: " + "first thread takes lock_a, first thread takes lock_b, first thread releases both, then " + "second thread takes lock_b and second thread takes lock_a. A note beside them says both " + "threads ran to completion and neither ever waited. On the right, a column of the four things " + "the checker does on every single acquire, in order: find or register the class for this " + "lock, push it onto this task's held lock stack, mix its class index into the chain key, and " + "look the chain key up in the chain cache. A note says a hit means this exact sequence has " + "been seen before and nothing else runs, which is why the checker is affordable at all. " + "Across the bottom is a red band reading debug_locks goes to zero on the first report of the " + "boot, and under it a line saying from that moment nothing is checked, a second bug loaded " + "afterwards is silent, and the only place this is visible is the debug_locks line of " + "/proc/lockdep_stats." +) + + +def scene() -> Scene: + s = Scene("How a lock ordering report happens", width=1240, height=780) + + s.note(40, 44, "How a lock ordering report happens", font_size=20) + s.note( + 40, + 70, + "No thread has to wait. The graph is what is checked, and it is checked on the acquire.", + font_size=13, + muted=True, + ) + + # -- the graph, on the left ------------------------------------------------------------------ + s.note(40, 118, "the lock graph", font_size=14) + a = s.box(96, 148, 200, 52, "lock_a", style="accent", font_size=16, mono=True) + b = s.box(96, 308, 200, 52, "lock_b", style="accent", font_size=16, mono=True) + + s.arrow(a, b, label="held while taking") + s.arrow(b, a, label="about to be added", dashed=True, sides=("left", "left")) + + refuse = s.box( + 40, + 400, + 312, + 68, + "adding this edge closes a cycle\nrefuse it, print, and switch off", + style="warn", + font_size=14, + ) + s.arrow((196, 360), refuse) + + s.note( + 40, + 494, + "A node is a lock class, which is a line of source rather\n" + "than an object. Every mutex initialised on one line is\n" + "one node here, however many of them exist.", + font_size=13, + muted=True, + ) + + # -- what the two threads did, in the middle ------------------------------------------------- + s.note(408, 118, "what the module in the corpus does", font_size=14) + s.note(408, 148, "first thread", font_size=13, muted=True) + s.note(628, 148, "second thread", font_size=13, muted=True) + + one = s.box(408, 172, 200, 44, "lock(lock_a)", font_size=14, mono=True) + two = s.box(408, 228, 200, 44, "lock(lock_b)", font_size=14, mono=True) + done = s.box(408, 284, 200, 44, "release both, exit", style="muted", font_size=14) + three = s.box(628, 340, 200, 44, "lock(lock_b)", font_size=14, mono=True) + four = s.box(628, 396, 200, 44, "lock(lock_a)", style="warn", font_size=14, mono=True) + + s.arrow(one, two) + s.arrow(two, done) + s.arrow(done, three) + s.arrow(three, four) + + s.note( + 408, + 468, + "Both threads ran to the end. Neither ever waited for\n" + "the other. The report came out anyway, because the\n" + "cycle is a property of the code and a hang is a\n" + "property of the timing.", + font_size=13, + muted=True, + ) + + # -- what runs on every acquire, on the right ------------------------------------------------ + s.note(880, 118, "on every acquire, always", font_size=14) + find = s.box(880, 148, 320, 44, "find or register the lock class", font_size=13) + push = s.box(880, 204, 320, 44, "push it on this task's held lock stack", font_size=13) + mix = s.box(880, 260, 320, 44, "mix the class index into the chain key", font_size=13) + look = s.box(880, 316, 320, 44, "look the chain key up in the chain cache", font_size=13) + miss = s.box( + 880, + 380, + 320, + 60, + "miss: walk the graph backwards\nlooking for a path home", + style="accent", + font_size=13, + ) + + s.arrow(find, push) + s.arrow(push, mix) + s.arrow(mix, look) + s.arrow(look, miss, label="miss") + + s.note( + 880, + 468, + "A hit means this exact sequence of held locks has\n" + "been seen before, and nothing below runs. That is\n" + "the whole reason the checker is affordable.", + font_size=13, + muted=True, + ) + + # -- the part that costs a debugging session ------------------------------------------------- + off = s.box( + 40, + 612, + 1160, + 60, + "debug_locks goes to 0 on the first report of the boot", + style="warn", + font_size=17, + ) + s.arrow(refuse, off) + + s.note( + 40, + 692, + "From that moment nothing is checked at all. A second bug loaded afterwards is silent, and " + "a quiet log means nothing.", + font_size=14, + ) + s.note( + 40, + 722, + "The only place it shows is the debug_locks line of /proc/lockdep_stats, which is why that " + "file is the thing to read after a report.", + font_size=13, + muted=True, + ) + return s diff --git a/blueprints/assets/lock-ordering-cycle.excalidraw b/blueprints/assets/lock-ordering-cycle.excalidraw new file mode 100644 index 0000000..2977699 --- /dev/null +++ b/blueprints/assets/lock-ordering-cycle.excalidraw @@ -0,0 +1,2063 @@ +{ + "type": "excalidraw", + "version": 2, + "source": "https://github.com/tamnd/linux-kernel-internals", + "elements": [ + { + "id": "note001", + "x": 40, + "y": 44, + "width": 374.00000000000006, + "height": 25.0, + "angle": 0, + "strokeColor": "#1e1e1e", + "backgroundColor": "transparent", + "fillStyle": "solid", + "strokeWidth": 2, + "strokeStyle": "solid", + "roughness": 1, + "opacity": 100, + "groupIds": [], + "frameId": null, + "roundness": null, + "seed": 1253060127, + "version": 1, + "versionNonce": 1253060127, + "isDeleted": false, + "boundElements": [], + "updated": 1, + "link": null, + "locked": false, + "type": "text", + "text": "How a lock ordering report happens", + "originalText": "How a lock ordering report happens", + "fontSize": 20, + "fontFamily": 1, + "textAlign": "left", + "verticalAlign": "top", + "containerId": null, + "autoResize": true, + "lineHeight": 1.25 + }, + { + "id": "note002", + "x": 40, + "y": 70, + "width": 614.9000000000001, + "height": 16.25, + "angle": 0, + "strokeColor": "#5c5f66", + "backgroundColor": "transparent", + "fillStyle": "solid", + "strokeWidth": 2, + "strokeStyle": "solid", + "roughness": 1, + "opacity": 100, + "groupIds": [], + "frameId": null, + "roundness": null, + "seed": 416753548, + "version": 1, + "versionNonce": 416753548, + "isDeleted": false, + "boundElements": [], + "updated": 1, + "link": null, + "locked": false, + "type": "text", + "text": "No thread has to wait. The graph is what is checked, and it is checked on the acquire.", + "originalText": "No thread has to wait. The graph is what is checked, and it is checked on the acquire.", + "fontSize": 13, + "fontFamily": 1, + "textAlign": "left", + "verticalAlign": "top", + "containerId": null, + "autoResize": true, + "lineHeight": 1.25 + }, + { + "id": "note003", + "x": 40, + "y": 118, + "width": 107.80000000000001, + "height": 17.5, + "angle": 0, + "strokeColor": "#1e1e1e", + "backgroundColor": "transparent", + "fillStyle": "solid", + "strokeWidth": 2, + "strokeStyle": "solid", + "roughness": 1, + "opacity": 100, + "groupIds": [], + "frameId": null, + "roundness": null, + "seed": 3139219713, + "version": 1, + "versionNonce": 3139219713, + "isDeleted": false, + "boundElements": [], + "updated": 1, + "link": null, + "locked": false, + "type": "text", + "text": "the lock graph", + "originalText": "the lock graph", + "fontSize": 14, + "fontFamily": 1, + "textAlign": "left", + "verticalAlign": "top", + "containerId": null, + "autoResize": true, + "lineHeight": 1.25 + }, + { + "id": "box004", + "x": 96, + "y": 148, + "width": 200, + "height": 52, + "angle": 0, + "strokeColor": "#1971c2", + "backgroundColor": "#d0ebff", + "fillStyle": "solid", + "strokeWidth": 2, + "strokeStyle": "solid", + "roughness": 1, + "opacity": 100, + "groupIds": [], + "frameId": null, + "roundness": { + "type": 3 + }, + "seed": 4129207805, + "version": 1, + "versionNonce": 4129207805, + "isDeleted": false, + "boundElements": [ + { + "type": "text", + "id": "box004-text" + } + ], + "updated": 1, + "link": null, + "locked": false, + "type": "rectangle" + }, + { + "id": "box004-text", + "x": 169.6, + "y": 164.0, + "width": 52.800000000000004, + "height": 20.0, + "angle": 0, + "strokeColor": "#1971c2", + "backgroundColor": "transparent", + "fillStyle": "solid", + "strokeWidth": 2, + "strokeStyle": "solid", + "roughness": 1, + "opacity": 100, + "groupIds": [], + "frameId": null, + "roundness": null, + "seed": 2426213173, + "version": 1, + "versionNonce": 2426213173, + "isDeleted": false, + "boundElements": [], + "updated": 1, + "link": null, + "locked": false, + "type": "text", + "text": "lock_a", + "originalText": "lock_a", + "fontSize": 16, + "fontFamily": 3, + "textAlign": "center", + "verticalAlign": "middle", + "containerId": "box004", + "autoResize": true, + "lineHeight": 1.25 + }, + { + "id": "box005", + "x": 96, + "y": 308, + "width": 200, + "height": 52, + "angle": 0, + "strokeColor": "#1971c2", + "backgroundColor": "#d0ebff", + "fillStyle": "solid", + "strokeWidth": 2, + "strokeStyle": "solid", + "roughness": 1, + "opacity": 100, + "groupIds": [], + "frameId": null, + "roundness": { + "type": 3 + }, + "seed": 811906495, + "version": 1, + "versionNonce": 811906495, + "isDeleted": false, + "boundElements": [ + { + "type": "text", + "id": "box005-text" + } + ], + "updated": 1, + "link": null, + "locked": false, + "type": "rectangle" + }, + { + "id": "box005-text", + "x": 169.6, + "y": 324.0, + "width": 52.800000000000004, + "height": 20.0, + "angle": 0, + "strokeColor": "#1971c2", + "backgroundColor": "transparent", + "fillStyle": "solid", + "strokeWidth": 2, + "strokeStyle": "solid", + "roughness": 1, + "opacity": 100, + "groupIds": [], + "frameId": null, + "roundness": null, + "seed": 3795827410, + "version": 1, + "versionNonce": 3795827410, + "isDeleted": false, + "boundElements": [], + "updated": 1, + "link": null, + "locked": false, + "type": "text", + "text": "lock_b", + "originalText": "lock_b", + "fontSize": 16, + "fontFamily": 3, + "textAlign": "center", + "verticalAlign": "middle", + "containerId": "box005", + "autoResize": true, + "lineHeight": 1.25 + }, + { + "id": "arrow006", + "x": 196.0, + "y": 200, + "width": 0.0, + "height": 108, + "angle": 0, + "strokeColor": "#1e1e1e", + "backgroundColor": "transparent", + "fillStyle": "solid", + "strokeWidth": 2, + "strokeStyle": "solid", + "roughness": 1, + "opacity": 100, + "groupIds": [], + "frameId": null, + "roundness": null, + "seed": 4268011819, + "version": 1, + "versionNonce": 4268011819, + "isDeleted": false, + "boundElements": [ + { + "type": "text", + "id": "arrow006-text" + } + ], + "updated": 1, + "link": null, + "locked": false, + "type": "arrow", + "points": [ + [ + 0, + 0 + ], + [ + 0.0, + 108 + ] + ], + "lastCommittedPoint": null, + "startBinding": null, + "endBinding": null, + "startArrowhead": null, + "endArrowhead": "arrow", + "elbowed": false + }, + { + "id": "arrow006-text", + "x": 135.225, + "y": 245.875, + "width": 121.55000000000001, + "height": 16.25, + "angle": 0, + "strokeColor": "#5c5f66", + "backgroundColor": "transparent", + "fillStyle": "solid", + "strokeWidth": 2, + "strokeStyle": "solid", + "roughness": 1, + "opacity": 100, + "groupIds": [], + "frameId": null, + "roundness": null, + "seed": 1888569525, + "version": 1, + "versionNonce": 1888569525, + "isDeleted": false, + "boundElements": [], + "updated": 1, + "link": null, + "locked": false, + "type": "text", + "text": "held while taking", + "originalText": "held while taking", + "fontSize": 13, + "fontFamily": 1, + "textAlign": "center", + "verticalAlign": "middle", + "containerId": "arrow006", + "autoResize": true, + "lineHeight": 1.25 + }, + { + "id": "arrow007", + "x": 96, + "y": 334.0, + "width": 0, + "height": -160.0, + "angle": 0, + "strokeColor": "#1e1e1e", + "backgroundColor": "transparent", + "fillStyle": "solid", + "strokeWidth": 2, + "strokeStyle": "dashed", + "roughness": 1, + "opacity": 100, + "groupIds": [], + "frameId": null, + "roundness": null, + "seed": 1591352816, + "version": 1, + "versionNonce": 1591352816, + "isDeleted": false, + "boundElements": [ + { + "type": "text", + "id": "arrow007-text" + } + ], + "updated": 1, + "link": null, + "locked": false, + "type": "arrow", + "points": [ + [ + 0, + 0 + ], + [ + 0, + -160.0 + ] + ], + "lastCommittedPoint": null, + "startBinding": null, + "endBinding": null, + "startArrowhead": null, + "endArrowhead": "arrow", + "elbowed": false + }, + { + "id": "arrow007-text", + "x": 35.224999999999994, + "y": 245.875, + "width": 121.55000000000001, + "height": 16.25, + "angle": 0, + "strokeColor": "#5c5f66", + "backgroundColor": "transparent", + "fillStyle": "solid", + "strokeWidth": 2, + "strokeStyle": "solid", + "roughness": 1, + "opacity": 100, + "groupIds": [], + "frameId": null, + "roundness": null, + "seed": 3099201683, + "version": 1, + "versionNonce": 3099201683, + "isDeleted": false, + "boundElements": [], + "updated": 1, + "link": null, + "locked": false, + "type": "text", + "text": "about to be added", + "originalText": "about to be added", + "fontSize": 13, + "fontFamily": 1, + "textAlign": "center", + "verticalAlign": "middle", + "containerId": "arrow007", + "autoResize": true, + "lineHeight": 1.25 + }, + { + "id": "box008", + "x": 40, + "y": 400, + "width": 312, + "height": 68, + "angle": 0, + "strokeColor": "#e03131", + "backgroundColor": "#ffe3e3", + "fillStyle": "solid", + "strokeWidth": 2, + "strokeStyle": "solid", + "roughness": 1, + "opacity": 100, + "groupIds": [], + "frameId": null, + "roundness": { + "type": 3 + }, + "seed": 1896352954, + "version": 1, + "versionNonce": 1896352954, + "isDeleted": false, + "boundElements": [ + { + "type": "text", + "id": "box008-text" + } + ], + "updated": 1, + "link": null, + "locked": false, + "type": "rectangle" + }, + { + "id": "box008-text", + "x": 72.79999999999998, + "y": 416.5, + "width": 246.40000000000003, + "height": 35.0, + "angle": 0, + "strokeColor": "#e03131", + "backgroundColor": "transparent", + "fillStyle": "solid", + "strokeWidth": 2, + "strokeStyle": "solid", + "roughness": 1, + "opacity": 100, + "groupIds": [], + "frameId": null, + "roundness": null, + "seed": 656236939, + "version": 1, + "versionNonce": 656236939, + "isDeleted": false, + "boundElements": [], + "updated": 1, + "link": null, + "locked": false, + "type": "text", + "text": "adding this edge closes a cycle\nrefuse it, print, and switch off", + "originalText": "adding this edge closes a cycle\nrefuse it, print, and switch off", + "fontSize": 14, + "fontFamily": 1, + "textAlign": "center", + "verticalAlign": "middle", + "containerId": "box008", + "autoResize": true, + "lineHeight": 1.25 + }, + { + "id": "arrow009", + "x": 196, + "y": 360, + "width": 0.0, + "height": 74.0, + "angle": 0, + "strokeColor": "#1e1e1e", + "backgroundColor": "transparent", + "fillStyle": "solid", + "strokeWidth": 2, + "strokeStyle": "solid", + "roughness": 1, + "opacity": 100, + "groupIds": [], + "frameId": null, + "roundness": null, + "seed": 2413180952, + "version": 1, + "versionNonce": 2413180952, + "isDeleted": false, + "boundElements": [], + "updated": 1, + "link": null, + "locked": false, + "type": "arrow", + "points": [ + [ + 0, + 0 + ], + [ + 0.0, + 74.0 + ] + ], + "lastCommittedPoint": null, + "startBinding": null, + "endBinding": null, + "startArrowhead": null, + "endArrowhead": "arrow", + "elbowed": false + }, + { + "id": "note010", + "x": 40, + "y": 494, + "width": 400.40000000000003, + "height": 48.75, + "angle": 0, + "strokeColor": "#5c5f66", + "backgroundColor": "transparent", + "fillStyle": "solid", + "strokeWidth": 2, + "strokeStyle": "solid", + "roughness": 1, + "opacity": 100, + "groupIds": [], + "frameId": null, + "roundness": null, + "seed": 3776694398, + "version": 1, + "versionNonce": 3776694398, + "isDeleted": false, + "boundElements": [], + "updated": 1, + "link": null, + "locked": false, + "type": "text", + "text": "A node is a lock class, which is a line of source rather\nthan an object. Every mutex initialised on one line is\none node here, however many of them exist.", + "originalText": "A node is a lock class, which is a line of source rather\nthan an object. Every mutex initialised on one line is\none node here, however many of them exist.", + "fontSize": 13, + "fontFamily": 1, + "textAlign": "left", + "verticalAlign": "top", + "containerId": null, + "autoResize": true, + "lineHeight": 1.25 + }, + { + "id": "note011", + "x": 408, + "y": 118, + "width": 261.8, + "height": 17.5, + "angle": 0, + "strokeColor": "#1e1e1e", + "backgroundColor": "transparent", + "fillStyle": "solid", + "strokeWidth": 2, + "strokeStyle": "solid", + "roughness": 1, + "opacity": 100, + "groupIds": [], + "frameId": null, + "roundness": null, + "seed": 4125620061, + "version": 1, + "versionNonce": 4125620061, + "isDeleted": false, + "boundElements": [], + "updated": 1, + "link": null, + "locked": false, + "type": "text", + "text": "what the module in the corpus does", + "originalText": "what the module in the corpus does", + "fontSize": 14, + "fontFamily": 1, + "textAlign": "left", + "verticalAlign": "top", + "containerId": null, + "autoResize": true, + "lineHeight": 1.25 + }, + { + "id": "note012", + "x": 408, + "y": 148, + "width": 85.80000000000001, + "height": 16.25, + "angle": 0, + "strokeColor": "#5c5f66", + "backgroundColor": "transparent", + "fillStyle": "solid", + "strokeWidth": 2, + "strokeStyle": "solid", + "roughness": 1, + "opacity": 100, + "groupIds": [], + "frameId": null, + "roundness": null, + "seed": 1516944292, + "version": 1, + "versionNonce": 1516944292, + "isDeleted": false, + "boundElements": [], + "updated": 1, + "link": null, + "locked": false, + "type": "text", + "text": "first thread", + "originalText": "first thread", + "fontSize": 13, + "fontFamily": 1, + "textAlign": "left", + "verticalAlign": "top", + "containerId": null, + "autoResize": true, + "lineHeight": 1.25 + }, + { + "id": "note013", + "x": 628, + "y": 148, + "width": 92.95, + "height": 16.25, + "angle": 0, + "strokeColor": "#5c5f66", + "backgroundColor": "transparent", + "fillStyle": "solid", + "strokeWidth": 2, + "strokeStyle": "solid", + "roughness": 1, + "opacity": 100, + "groupIds": [], + "frameId": null, + "roundness": null, + "seed": 295688683, + "version": 1, + "versionNonce": 295688683, + "isDeleted": false, + "boundElements": [], + "updated": 1, + "link": null, + "locked": false, + "type": "text", + "text": "second thread", + "originalText": "second thread", + "fontSize": 13, + "fontFamily": 1, + "textAlign": "left", + "verticalAlign": "top", + "containerId": null, + "autoResize": true, + "lineHeight": 1.25 + }, + { + "id": "box014", + "x": 408, + "y": 172, + "width": 200, + "height": 44, + "angle": 0, + "strokeColor": "#1e1e1e", + "backgroundColor": "transparent", + "fillStyle": "solid", + "strokeWidth": 2, + "strokeStyle": "solid", + "roughness": 1, + "opacity": 100, + "groupIds": [], + "frameId": null, + "roundness": { + "type": 3 + }, + "seed": 1857026505, + "version": 1, + "versionNonce": 1857026505, + "isDeleted": false, + "boundElements": [ + { + "type": "text", + "id": "box014-text" + } + ], + "updated": 1, + "link": null, + "locked": false, + "type": "rectangle" + }, + { + "id": "box014-text", + "x": 461.8, + "y": 185.25, + "width": 92.4, + "height": 17.5, + "angle": 0, + "strokeColor": "#1e1e1e", + "backgroundColor": "transparent", + "fillStyle": "solid", + "strokeWidth": 2, + "strokeStyle": "solid", + "roughness": 1, + "opacity": 100, + "groupIds": [], + "frameId": null, + "roundness": null, + "seed": 1853601184, + "version": 1, + "versionNonce": 1853601184, + "isDeleted": false, + "boundElements": [], + "updated": 1, + "link": null, + "locked": false, + "type": "text", + "text": "lock(lock_a)", + "originalText": "lock(lock_a)", + "fontSize": 14, + "fontFamily": 3, + "textAlign": "center", + "verticalAlign": "middle", + "containerId": "box014", + "autoResize": true, + "lineHeight": 1.25 + }, + { + "id": "box015", + "x": 408, + "y": 228, + "width": 200, + "height": 44, + "angle": 0, + "strokeColor": "#1e1e1e", + "backgroundColor": "transparent", + "fillStyle": "solid", + "strokeWidth": 2, + "strokeStyle": "solid", + "roughness": 1, + "opacity": 100, + "groupIds": [], + "frameId": null, + "roundness": { + "type": 3 + }, + "seed": 3441421429, + "version": 1, + "versionNonce": 3441421429, + "isDeleted": false, + "boundElements": [ + { + "type": "text", + "id": "box015-text" + } + ], + "updated": 1, + "link": null, + "locked": false, + "type": "rectangle" + }, + { + "id": "box015-text", + "x": 461.8, + "y": 241.25, + "width": 92.4, + "height": 17.5, + "angle": 0, + "strokeColor": "#1e1e1e", + "backgroundColor": "transparent", + "fillStyle": "solid", + "strokeWidth": 2, + "strokeStyle": "solid", + "roughness": 1, + "opacity": 100, + "groupIds": [], + "frameId": null, + "roundness": null, + "seed": 30491951, + "version": 1, + "versionNonce": 30491951, + "isDeleted": false, + "boundElements": [], + "updated": 1, + "link": null, + "locked": false, + "type": "text", + "text": "lock(lock_b)", + "originalText": "lock(lock_b)", + "fontSize": 14, + "fontFamily": 3, + "textAlign": "center", + "verticalAlign": "middle", + "containerId": "box015", + "autoResize": true, + "lineHeight": 1.25 + }, + { + "id": "box016", + "x": 408, + "y": 284, + "width": 200, + "height": 44, + "angle": 0, + "strokeColor": "#868e96", + "backgroundColor": "#f8f9fa", + "fillStyle": "solid", + "strokeWidth": 2, + "strokeStyle": "solid", + "roughness": 1, + "opacity": 100, + "groupIds": [], + "frameId": null, + "roundness": { + "type": 3 + }, + "seed": 4020938000, + "version": 1, + "versionNonce": 4020938000, + "isDeleted": false, + "boundElements": [ + { + "type": "text", + "id": "box016-text" + } + ], + "updated": 1, + "link": null, + "locked": false, + "type": "rectangle" + }, + { + "id": "box016-text", + "x": 438.7, + "y": 297.25, + "width": 138.60000000000002, + "height": 17.5, + "angle": 0, + "strokeColor": "#868e96", + "backgroundColor": "transparent", + "fillStyle": "solid", + "strokeWidth": 2, + "strokeStyle": "solid", + "roughness": 1, + "opacity": 100, + "groupIds": [], + "frameId": null, + "roundness": null, + "seed": 1634329792, + "version": 1, + "versionNonce": 1634329792, + "isDeleted": false, + "boundElements": [], + "updated": 1, + "link": null, + "locked": false, + "type": "text", + "text": "release both, exit", + "originalText": "release both, exit", + "fontSize": 14, + "fontFamily": 1, + "textAlign": "center", + "verticalAlign": "middle", + "containerId": "box016", + "autoResize": true, + "lineHeight": 1.25 + }, + { + "id": "box017", + "x": 628, + "y": 340, + "width": 200, + "height": 44, + "angle": 0, + "strokeColor": "#1e1e1e", + "backgroundColor": "transparent", + "fillStyle": "solid", + "strokeWidth": 2, + "strokeStyle": "solid", + "roughness": 1, + "opacity": 100, + "groupIds": [], + "frameId": null, + "roundness": { + "type": 3 + }, + "seed": 195849708, + "version": 1, + "versionNonce": 195849708, + "isDeleted": false, + "boundElements": [ + { + "type": "text", + "id": "box017-text" + } + ], + "updated": 1, + "link": null, + "locked": false, + "type": "rectangle" + }, + { + "id": "box017-text", + "x": 681.8, + "y": 353.25, + "width": 92.4, + "height": 17.5, + "angle": 0, + "strokeColor": "#1e1e1e", + "backgroundColor": "transparent", + "fillStyle": "solid", + "strokeWidth": 2, + "strokeStyle": "solid", + "roughness": 1, + "opacity": 100, + "groupIds": [], + "frameId": null, + "roundness": null, + "seed": 3548864052, + "version": 1, + "versionNonce": 3548864052, + "isDeleted": false, + "boundElements": [], + "updated": 1, + "link": null, + "locked": false, + "type": "text", + "text": "lock(lock_b)", + "originalText": "lock(lock_b)", + "fontSize": 14, + "fontFamily": 3, + "textAlign": "center", + "verticalAlign": "middle", + "containerId": "box017", + "autoResize": true, + "lineHeight": 1.25 + }, + { + "id": "box018", + "x": 628, + "y": 396, + "width": 200, + "height": 44, + "angle": 0, + "strokeColor": "#e03131", + "backgroundColor": "#ffe3e3", + "fillStyle": "solid", + "strokeWidth": 2, + "strokeStyle": "solid", + "roughness": 1, + "opacity": 100, + "groupIds": [], + "frameId": null, + "roundness": { + "type": 3 + }, + "seed": 4250918909, + "version": 1, + "versionNonce": 4250918909, + "isDeleted": false, + "boundElements": [ + { + "type": "text", + "id": "box018-text" + } + ], + "updated": 1, + "link": null, + "locked": false, + "type": "rectangle" + }, + { + "id": "box018-text", + "x": 681.8, + "y": 409.25, + "width": 92.4, + "height": 17.5, + "angle": 0, + "strokeColor": "#e03131", + "backgroundColor": "transparent", + "fillStyle": "solid", + "strokeWidth": 2, + "strokeStyle": "solid", + "roughness": 1, + "opacity": 100, + "groupIds": [], + "frameId": null, + "roundness": null, + "seed": 412260546, + "version": 1, + "versionNonce": 412260546, + "isDeleted": false, + "boundElements": [], + "updated": 1, + "link": null, + "locked": false, + "type": "text", + "text": "lock(lock_a)", + "originalText": "lock(lock_a)", + "fontSize": 14, + "fontFamily": 3, + "textAlign": "center", + "verticalAlign": "middle", + "containerId": "box018", + "autoResize": true, + "lineHeight": 1.25 + }, + { + "id": "arrow019", + "x": 508.0, + "y": 216, + "width": 0.0, + "height": 12, + "angle": 0, + "strokeColor": "#1e1e1e", + "backgroundColor": "transparent", + "fillStyle": "solid", + "strokeWidth": 2, + "strokeStyle": "solid", + "roughness": 1, + "opacity": 100, + "groupIds": [], + "frameId": null, + "roundness": null, + "seed": 4055946056, + "version": 1, + "versionNonce": 4055946056, + "isDeleted": false, + "boundElements": [], + "updated": 1, + "link": null, + "locked": false, + "type": "arrow", + "points": [ + [ + 0, + 0 + ], + [ + 0.0, + 12 + ] + ], + "lastCommittedPoint": null, + "startBinding": null, + "endBinding": null, + "startArrowhead": null, + "endArrowhead": "arrow", + "elbowed": false + }, + { + "id": "arrow020", + "x": 508.0, + "y": 272, + "width": 0.0, + "height": 12, + "angle": 0, + "strokeColor": "#1e1e1e", + "backgroundColor": "transparent", + "fillStyle": "solid", + "strokeWidth": 2, + "strokeStyle": "solid", + "roughness": 1, + "opacity": 100, + "groupIds": [], + "frameId": null, + "roundness": null, + "seed": 1565251283, + "version": 1, + "versionNonce": 1565251283, + "isDeleted": false, + "boundElements": [], + "updated": 1, + "link": null, + "locked": false, + "type": "arrow", + "points": [ + [ + 0, + 0 + ], + [ + 0.0, + 12 + ] + ], + "lastCommittedPoint": null, + "startBinding": null, + "endBinding": null, + "startArrowhead": null, + "endArrowhead": "arrow", + "elbowed": false + }, + { + "id": "arrow021", + "x": 608, + "y": 306.0, + "width": 20, + "height": 56.0, + "angle": 0, + "strokeColor": "#1e1e1e", + "backgroundColor": "transparent", + "fillStyle": "solid", + "strokeWidth": 2, + "strokeStyle": "solid", + "roughness": 1, + "opacity": 100, + "groupIds": [], + "frameId": null, + "roundness": null, + "seed": 2656516248, + "version": 1, + "versionNonce": 2656516248, + "isDeleted": false, + "boundElements": [], + "updated": 1, + "link": null, + "locked": false, + "type": "arrow", + "points": [ + [ + 0, + 0 + ], + [ + 20, + 56.0 + ] + ], + "lastCommittedPoint": null, + "startBinding": null, + "endBinding": null, + "startArrowhead": null, + "endArrowhead": "arrow", + "elbowed": false + }, + { + "id": "arrow022", + "x": 728.0, + "y": 384, + "width": 0.0, + "height": 12, + "angle": 0, + "strokeColor": "#1e1e1e", + "backgroundColor": "transparent", + "fillStyle": "solid", + "strokeWidth": 2, + "strokeStyle": "solid", + "roughness": 1, + "opacity": 100, + "groupIds": [], + "frameId": null, + "roundness": null, + "seed": 3355961440, + "version": 1, + "versionNonce": 3355961440, + "isDeleted": false, + "boundElements": [], + "updated": 1, + "link": null, + "locked": false, + "type": "arrow", + "points": [ + [ + 0, + 0 + ], + [ + 0.0, + 12 + ] + ], + "lastCommittedPoint": null, + "startBinding": null, + "endBinding": null, + "startArrowhead": null, + "endArrowhead": "arrow", + "elbowed": false + }, + { + "id": "note023", + "x": 408, + "y": 468, + "width": 371.8, + "height": 65.0, + "angle": 0, + "strokeColor": "#5c5f66", + "backgroundColor": "transparent", + "fillStyle": "solid", + "strokeWidth": 2, + "strokeStyle": "solid", + "roughness": 1, + "opacity": 100, + "groupIds": [], + "frameId": null, + "roundness": null, + "seed": 4194631712, + "version": 1, + "versionNonce": 4194631712, + "isDeleted": false, + "boundElements": [], + "updated": 1, + "link": null, + "locked": false, + "type": "text", + "text": "Both threads ran to the end. Neither ever waited for\nthe other. The report came out anyway, because the\ncycle is a property of the code and a hang is a\nproperty of the timing.", + "originalText": "Both threads ran to the end. Neither ever waited for\nthe other. The report came out anyway, because the\ncycle is a property of the code and a hang is a\nproperty of the timing.", + "fontSize": 13, + "fontFamily": 1, + "textAlign": "left", + "verticalAlign": "top", + "containerId": null, + "autoResize": true, + "lineHeight": 1.25 + }, + { + "id": "note024", + "x": 880, + "y": 118, + "width": 184.8, + "height": 17.5, + "angle": 0, + "strokeColor": "#1e1e1e", + "backgroundColor": "transparent", + "fillStyle": "solid", + "strokeWidth": 2, + "strokeStyle": "solid", + "roughness": 1, + "opacity": 100, + "groupIds": [], + "frameId": null, + "roundness": null, + "seed": 3285089457, + "version": 1, + "versionNonce": 3285089457, + "isDeleted": false, + "boundElements": [], + "updated": 1, + "link": null, + "locked": false, + "type": "text", + "text": "on every acquire, always", + "originalText": "on every acquire, always", + "fontSize": 14, + "fontFamily": 1, + "textAlign": "left", + "verticalAlign": "top", + "containerId": null, + "autoResize": true, + "lineHeight": 1.25 + }, + { + "id": "box025", + "x": 880, + "y": 148, + "width": 320, + "height": 44, + "angle": 0, + "strokeColor": "#1e1e1e", + "backgroundColor": "transparent", + "fillStyle": "solid", + "strokeWidth": 2, + "strokeStyle": "solid", + "roughness": 1, + "opacity": 100, + "groupIds": [], + "frameId": null, + "roundness": { + "type": 3 + }, + "seed": 739565523, + "version": 1, + "versionNonce": 739565523, + "isDeleted": false, + "boundElements": [ + { + "type": "text", + "id": "box025-text" + } + ], + "updated": 1, + "link": null, + "locked": false, + "type": "rectangle" + }, + { + "id": "box025-text", + "x": 929.175, + "y": 161.875, + "width": 221.65, + "height": 16.25, + "angle": 0, + "strokeColor": "#1e1e1e", + "backgroundColor": "transparent", + "fillStyle": "solid", + "strokeWidth": 2, + "strokeStyle": "solid", + "roughness": 1, + "opacity": 100, + "groupIds": [], + "frameId": null, + "roundness": null, + "seed": 3437557798, + "version": 1, + "versionNonce": 3437557798, + "isDeleted": false, + "boundElements": [], + "updated": 1, + "link": null, + "locked": false, + "type": "text", + "text": "find or register the lock class", + "originalText": "find or register the lock class", + "fontSize": 13, + "fontFamily": 1, + "textAlign": "center", + "verticalAlign": "middle", + "containerId": "box025", + "autoResize": true, + "lineHeight": 1.25 + }, + { + "id": "box026", + "x": 880, + "y": 204, + "width": 320, + "height": 44, + "angle": 0, + "strokeColor": "#1e1e1e", + "backgroundColor": "transparent", + "fillStyle": "solid", + "strokeWidth": 2, + "strokeStyle": "solid", + "roughness": 1, + "opacity": 100, + "groupIds": [], + "frameId": null, + "roundness": { + "type": 3 + }, + "seed": 1469063485, + "version": 1, + "versionNonce": 1469063485, + "isDeleted": false, + "boundElements": [ + { + "type": "text", + "id": "box026-text" + } + ], + "updated": 1, + "link": null, + "locked": false, + "type": "rectangle" + }, + { + "id": "box026-text", + "x": 904.15, + "y": 217.875, + "width": 271.70000000000005, + "height": 16.25, + "angle": 0, + "strokeColor": "#1e1e1e", + "backgroundColor": "transparent", + "fillStyle": "solid", + "strokeWidth": 2, + "strokeStyle": "solid", + "roughness": 1, + "opacity": 100, + "groupIds": [], + "frameId": null, + "roundness": null, + "seed": 4121209802, + "version": 1, + "versionNonce": 4121209802, + "isDeleted": false, + "boundElements": [], + "updated": 1, + "link": null, + "locked": false, + "type": "text", + "text": "push it on this task's held lock stack", + "originalText": "push it on this task's held lock stack", + "fontSize": 13, + "fontFamily": 1, + "textAlign": "center", + "verticalAlign": "middle", + "containerId": "box026", + "autoResize": true, + "lineHeight": 1.25 + }, + { + "id": "box027", + "x": 880, + "y": 260, + "width": 320, + "height": 44, + "angle": 0, + "strokeColor": "#1e1e1e", + "backgroundColor": "transparent", + "fillStyle": "solid", + "strokeWidth": 2, + "strokeStyle": "solid", + "roughness": 1, + "opacity": 100, + "groupIds": [], + "frameId": null, + "roundness": { + "type": 3 + }, + "seed": 2298052252, + "version": 1, + "versionNonce": 2298052252, + "isDeleted": false, + "boundElements": [ + { + "type": "text", + "id": "box027-text" + } + ], + "updated": 1, + "link": null, + "locked": false, + "type": "rectangle" + }, + { + "id": "box027-text", + "x": 904.15, + "y": 273.875, + "width": 271.70000000000005, + "height": 16.25, + "angle": 0, + "strokeColor": "#1e1e1e", + "backgroundColor": "transparent", + "fillStyle": "solid", + "strokeWidth": 2, + "strokeStyle": "solid", + "roughness": 1, + "opacity": 100, + "groupIds": [], + "frameId": null, + "roundness": null, + "seed": 3744536497, + "version": 1, + "versionNonce": 3744536497, + "isDeleted": false, + "boundElements": [], + "updated": 1, + "link": null, + "locked": false, + "type": "text", + "text": "mix the class index into the chain key", + "originalText": "mix the class index into the chain key", + "fontSize": 13, + "fontFamily": 1, + "textAlign": "center", + "verticalAlign": "middle", + "containerId": "box027", + "autoResize": true, + "lineHeight": 1.25 + }, + { + "id": "box028", + "x": 880, + "y": 316, + "width": 320, + "height": 44, + "angle": 0, + "strokeColor": "#1e1e1e", + "backgroundColor": "transparent", + "fillStyle": "solid", + "strokeWidth": 2, + "strokeStyle": "solid", + "roughness": 1, + "opacity": 100, + "groupIds": [], + "frameId": null, + "roundness": { + "type": 3 + }, + "seed": 408943806, + "version": 1, + "versionNonce": 408943806, + "isDeleted": false, + "boundElements": [ + { + "type": "text", + "id": "box028-text" + } + ], + "updated": 1, + "link": null, + "locked": false, + "type": "rectangle" + }, + { + "id": "box028-text", + "x": 897.0, + "y": 329.875, + "width": 286.0, + "height": 16.25, + "angle": 0, + "strokeColor": "#1e1e1e", + "backgroundColor": "transparent", + "fillStyle": "solid", + "strokeWidth": 2, + "strokeStyle": "solid", + "roughness": 1, + "opacity": 100, + "groupIds": [], + "frameId": null, + "roundness": null, + "seed": 183909983, + "version": 1, + "versionNonce": 183909983, + "isDeleted": false, + "boundElements": [], + "updated": 1, + "link": null, + "locked": false, + "type": "text", + "text": "look the chain key up in the chain cache", + "originalText": "look the chain key up in the chain cache", + "fontSize": 13, + "fontFamily": 1, + "textAlign": "center", + "verticalAlign": "middle", + "containerId": "box028", + "autoResize": true, + "lineHeight": 1.25 + }, + { + "id": "box029", + "x": 880, + "y": 380, + "width": 320, + "height": 60, + "angle": 0, + "strokeColor": "#1971c2", + "backgroundColor": "#d0ebff", + "fillStyle": "solid", + "strokeWidth": 2, + "strokeStyle": "solid", + "roughness": 1, + "opacity": 100, + "groupIds": [], + "frameId": null, + "roundness": { + "type": 3 + }, + "seed": 1144920722, + "version": 1, + "versionNonce": 1144920722, + "isDeleted": false, + "boundElements": [ + { + "type": "text", + "id": "box029-text" + } + ], + "updated": 1, + "link": null, + "locked": false, + "type": "rectangle" + }, + { + "id": "box029-text", + "x": 932.75, + "y": 393.75, + "width": 214.50000000000003, + "height": 32.5, + "angle": 0, + "strokeColor": "#1971c2", + "backgroundColor": "transparent", + "fillStyle": "solid", + "strokeWidth": 2, + "strokeStyle": "solid", + "roughness": 1, + "opacity": 100, + "groupIds": [], + "frameId": null, + "roundness": null, + "seed": 3442183999, + "version": 1, + "versionNonce": 3442183999, + "isDeleted": false, + "boundElements": [], + "updated": 1, + "link": null, + "locked": false, + "type": "text", + "text": "miss: walk the graph backwards\nlooking for a path home", + "originalText": "miss: walk the graph backwards\nlooking for a path home", + "fontSize": 13, + "fontFamily": 1, + "textAlign": "center", + "verticalAlign": "middle", + "containerId": "box029", + "autoResize": true, + "lineHeight": 1.25 + }, + { + "id": "arrow030", + "x": 1040.0, + "y": 192, + "width": 0.0, + "height": 12, + "angle": 0, + "strokeColor": "#1e1e1e", + "backgroundColor": "transparent", + "fillStyle": "solid", + "strokeWidth": 2, + "strokeStyle": "solid", + "roughness": 1, + "opacity": 100, + "groupIds": [], + "frameId": null, + "roundness": null, + "seed": 689792399, + "version": 1, + "versionNonce": 689792399, + "isDeleted": false, + "boundElements": [], + "updated": 1, + "link": null, + "locked": false, + "type": "arrow", + "points": [ + [ + 0, + 0 + ], + [ + 0.0, + 12 + ] + ], + "lastCommittedPoint": null, + "startBinding": null, + "endBinding": null, + "startArrowhead": null, + "endArrowhead": "arrow", + "elbowed": false + }, + { + "id": "arrow031", + "x": 1040.0, + "y": 248, + "width": 0.0, + "height": 12, + "angle": 0, + "strokeColor": "#1e1e1e", + "backgroundColor": "transparent", + "fillStyle": "solid", + "strokeWidth": 2, + "strokeStyle": "solid", + "roughness": 1, + "opacity": 100, + "groupIds": [], + "frameId": null, + "roundness": null, + "seed": 2732351340, + "version": 1, + "versionNonce": 2732351340, + "isDeleted": false, + "boundElements": [], + "updated": 1, + "link": null, + "locked": false, + "type": "arrow", + "points": [ + [ + 0, + 0 + ], + [ + 0.0, + 12 + ] + ], + "lastCommittedPoint": null, + "startBinding": null, + "endBinding": null, + "startArrowhead": null, + "endArrowhead": "arrow", + "elbowed": false + }, + { + "id": "arrow032", + "x": 1040.0, + "y": 304, + "width": 0.0, + "height": 12, + "angle": 0, + "strokeColor": "#1e1e1e", + "backgroundColor": "transparent", + "fillStyle": "solid", + "strokeWidth": 2, + "strokeStyle": "solid", + "roughness": 1, + "opacity": 100, + "groupIds": [], + "frameId": null, + "roundness": null, + "seed": 689538550, + "version": 1, + "versionNonce": 689538550, + "isDeleted": false, + "boundElements": [], + "updated": 1, + "link": null, + "locked": false, + "type": "arrow", + "points": [ + [ + 0, + 0 + ], + [ + 0.0, + 12 + ] + ], + "lastCommittedPoint": null, + "startBinding": null, + "endBinding": null, + "startArrowhead": null, + "endArrowhead": "arrow", + "elbowed": false + }, + { + "id": "arrow033", + "x": 1040.0, + "y": 360, + "width": 0.0, + "height": 20, + "angle": 0, + "strokeColor": "#1e1e1e", + "backgroundColor": "transparent", + "fillStyle": "solid", + "strokeWidth": 2, + "strokeStyle": "solid", + "roughness": 1, + "opacity": 100, + "groupIds": [], + "frameId": null, + "roundness": null, + "seed": 3098331888, + "version": 1, + "versionNonce": 3098331888, + "isDeleted": false, + "boundElements": [ + { + "type": "text", + "id": "arrow033-text" + } + ], + "updated": 1, + "link": null, + "locked": false, + "type": "arrow", + "points": [ + [ + 0, + 0 + ], + [ + 0.0, + 20 + ] + ], + "lastCommittedPoint": null, + "startBinding": null, + "endBinding": null, + "startArrowhead": null, + "endArrowhead": "arrow", + "elbowed": false + }, + { + "id": "arrow033-text", + "x": 1025.7, + "y": 361.875, + "width": 28.6, + "height": 16.25, + "angle": 0, + "strokeColor": "#5c5f66", + "backgroundColor": "transparent", + "fillStyle": "solid", + "strokeWidth": 2, + "strokeStyle": "solid", + "roughness": 1, + "opacity": 100, + "groupIds": [], + "frameId": null, + "roundness": null, + "seed": 4068539695, + "version": 1, + "versionNonce": 4068539695, + "isDeleted": false, + "boundElements": [], + "updated": 1, + "link": null, + "locked": false, + "type": "text", + "text": "miss", + "originalText": "miss", + "fontSize": 13, + "fontFamily": 1, + "textAlign": "center", + "verticalAlign": "middle", + "containerId": "arrow033", + "autoResize": true, + "lineHeight": 1.25 + }, + { + "id": "note034", + "x": 880, + "y": 468, + "width": 350.35, + "height": 48.75, + "angle": 0, + "strokeColor": "#5c5f66", + "backgroundColor": "transparent", + "fillStyle": "solid", + "strokeWidth": 2, + "strokeStyle": "solid", + "roughness": 1, + "opacity": 100, + "groupIds": [], + "frameId": null, + "roundness": null, + "seed": 3357408727, + "version": 1, + "versionNonce": 3357408727, + "isDeleted": false, + "boundElements": [], + "updated": 1, + "link": null, + "locked": false, + "type": "text", + "text": "A hit means this exact sequence of held locks has\nbeen seen before, and nothing below runs. That is\nthe whole reason the checker is affordable.", + "originalText": "A hit means this exact sequence of held locks has\nbeen seen before, and nothing below runs. That is\nthe whole reason the checker is affordable.", + "fontSize": 13, + "fontFamily": 1, + "textAlign": "left", + "verticalAlign": "top", + "containerId": null, + "autoResize": true, + "lineHeight": 1.25 + }, + { + "id": "box035", + "x": 40, + "y": 612, + "width": 1160, + "height": 60, + "angle": 0, + "strokeColor": "#e03131", + "backgroundColor": "#ffe3e3", + "fillStyle": "solid", + "strokeWidth": 2, + "strokeStyle": "solid", + "roughness": 1, + "opacity": 100, + "groupIds": [], + "frameId": null, + "roundness": { + "type": 3 + }, + "seed": 1315734118, + "version": 1, + "versionNonce": 1315734118, + "isDeleted": false, + "boundElements": [ + { + "type": "text", + "id": "box035-text" + } + ], + "updated": 1, + "link": null, + "locked": false, + "type": "rectangle" + }, + { + "id": "box035-text", + "x": 372.22499999999997, + "y": 631.375, + "width": 495.55000000000007, + "height": 21.25, + "angle": 0, + "strokeColor": "#e03131", + "backgroundColor": "transparent", + "fillStyle": "solid", + "strokeWidth": 2, + "strokeStyle": "solid", + "roughness": 1, + "opacity": 100, + "groupIds": [], + "frameId": null, + "roundness": null, + "seed": 1644848527, + "version": 1, + "versionNonce": 1644848527, + "isDeleted": false, + "boundElements": [], + "updated": 1, + "link": null, + "locked": false, + "type": "text", + "text": "debug_locks goes to 0 on the first report of the boot", + "originalText": "debug_locks goes to 0 on the first report of the boot", + "fontSize": 17, + "fontFamily": 1, + "textAlign": "center", + "verticalAlign": "middle", + "containerId": "box035", + "autoResize": true, + "lineHeight": 1.25 + }, + { + "id": "arrow036", + "x": 352, + "y": 434.0, + "width": -312, + "height": 208.0, + "angle": 0, + "strokeColor": "#1e1e1e", + "backgroundColor": "transparent", + "fillStyle": "solid", + "strokeWidth": 2, + "strokeStyle": "solid", + "roughness": 1, + "opacity": 100, + "groupIds": [], + "frameId": null, + "roundness": null, + "seed": 1425322740, + "version": 1, + "versionNonce": 1425322740, + "isDeleted": false, + "boundElements": [], + "updated": 1, + "link": null, + "locked": false, + "type": "arrow", + "points": [ + [ + 0, + 0 + ], + [ + -312, + 208.0 + ] + ], + "lastCommittedPoint": null, + "startBinding": null, + "endBinding": null, + "startArrowhead": null, + "endArrowhead": "arrow", + "elbowed": false + }, + { + "id": "note037", + "x": 40, + "y": 692, + "width": 893.2, + "height": 17.5, + "angle": 0, + "strokeColor": "#1e1e1e", + "backgroundColor": "transparent", + "fillStyle": "solid", + "strokeWidth": 2, + "strokeStyle": "solid", + "roughness": 1, + "opacity": 100, + "groupIds": [], + "frameId": null, + "roundness": null, + "seed": 1259376200, + "version": 1, + "versionNonce": 1259376200, + "isDeleted": false, + "boundElements": [], + "updated": 1, + "link": null, + "locked": false, + "type": "text", + "text": "From that moment nothing is checked at all. A second bug loaded afterwards is silent, and a quiet log means nothing.", + "originalText": "From that moment nothing is checked at all. A second bug loaded afterwards is silent, and a quiet log means nothing.", + "fontSize": 14, + "fontFamily": 1, + "textAlign": "left", + "verticalAlign": "top", + "containerId": null, + "autoResize": true, + "lineHeight": 1.25 + }, + { + "id": "note038", + "x": 40, + "y": 722, + "width": 936.6500000000001, + "height": 16.25, + "angle": 0, + "strokeColor": "#5c5f66", + "backgroundColor": "transparent", + "fillStyle": "solid", + "strokeWidth": 2, + "strokeStyle": "solid", + "roughness": 1, + "opacity": 100, + "groupIds": [], + "frameId": null, + "roundness": null, + "seed": 911293525, + "version": 1, + "versionNonce": 911293525, + "isDeleted": false, + "boundElements": [], + "updated": 1, + "link": null, + "locked": false, + "type": "text", + "text": "The only place it shows is the debug_locks line of /proc/lockdep_stats, which is why that file is the thing to read after a report.", + "originalText": "The only place it shows is the debug_locks line of /proc/lockdep_stats, which is why that file is the thing to read after a report.", + "fontSize": 13, + "fontFamily": 1, + "textAlign": "left", + "verticalAlign": "top", + "containerId": null, + "autoResize": true, + "lineHeight": 1.25 + } + ], + "appState": { + "gridSize": null, + "viewBackgroundColor": "#ffffff" + }, + "files": {} +} diff --git a/blueprints/assets/lock-ordering-cycle.svg b/blueprints/assets/lock-ordering-cycle.svg new file mode 100644 index 0000000..46f677a --- /dev/null +++ b/blueprints/assets/lock-ordering-cycle.svg @@ -0,0 +1,74 @@ + + How a lock ordering report happens + A picture in three parts. On the left, a small directed graph labelled the lock graph, with two round-cornered nodes, lock_a and lock_b. A solid arrow runs from lock_a down to lock_b labelled edge added by the first thread, meaning lock_a was held while lock_b was taken. A dashed red arrow runs back up from lock_b to lock_a labelled the edge about to be added, and beside it a red box reads adding this closes a cycle, so refuse it and print. In the middle, two columns headed first thread and second thread, four steps in time order reading down: first thread takes lock_a, first thread takes lock_b, first thread releases both, then second thread takes lock_b and second thread takes lock_a. A note beside them says both threads ran to completion and neither ever waited. On the right, a column of the four things the checker does on every single acquire, in order: find or register the class for this lock, push it onto this task's held lock stack, mix its class index into the chain key, and look the chain key up in the chain cache. A note says a hit means this exact sequence has been seen before and nothing else runs, which is why the checker is affordable at all. Across the bottom is a red band reading debug_locks goes to zero on the first report of the boot, and under it a line saying from that moment nothing is checked, a second bug loaded afterwards is silent, and the only place this is visible is the debug_locks line of /proc/lockdep_stats. + + + + + + + How a lock ordering report happens + No thread has to wait. The graph is what is checked, and it is checked on the acquire. + the lock graph + + lock_a + + lock_b + + held while taking + + about to be added + + adding this edge closes a cycle + refuse it, print, and switch off + + A node is a lock class, which is a line of source rather + than an object. Every mutex initialised on one line is + one node here, however many of them exist. + what the module in the corpus does + first thread + second thread + + lock(lock_a) + + lock(lock_b) + + release both, exit + + lock(lock_b) + + lock(lock_a) + + + + + Both threads ran to the end. Neither ever waited for + the other. The report came out anyway, because the + cycle is a property of the code and a hang is a + property of the timing. + on every acquire, always + + find or register the lock class + + push it on this task's held lock stack + + mix the class index into the chain key + + look the chain key up in the chain cache + + miss: walk the graph backwards + looking for a path home + + + + + miss + A hit means this exact sequence of held locks has + been seen before, and nothing below runs. That is + the whole reason the checker is affordable. + + debug_locks goes to 0 on the first report of the boot + + From that moment nothing is checked at all. A second bug loaded afterwards is silent, and a quiet log means nothing. + The only place it shows is the debug_locks line of /proc/lockdep_stats, which is why that file is the thing to read after a report. + diff --git a/blueprints/lock-ordering.md b/blueprints/lock-ordering.md new file mode 100644 index 0000000..3970318 --- /dev/null +++ b/blueprints/lock-ordering.md @@ -0,0 +1,527 @@ +--- +blueprint: lock-ordering +title: The lock ordering checker +status: partial +pin: v7.2.2 +arch: i386 +lessons: [] +generated: [2, 5, 7] +config-dependent: [CONFIG_LOCKDEP, CONFIG_PROVE_LOCKING, CONFIG_DEBUG_LOCK_ALLOC, CONFIG_LOCK_STAT, CONFIG_DEBUG_LOCKDEP, CONFIG_LOCKDEP_BITS, CONFIG_LOCKDEP_CHAINS_BITS, CONFIG_LOCKDEP_STACK_TRACE_BITS, CONFIG_LOCKDEP_CIRCULAR_QUEUE_BITS, CONFIG_PREEMPT_RT, CONFIG_PROVE_RAW_LOCK_NESTING, CONFIG_SMP, CONFIG_NR_CPUS] +structures: [lock_class, lockdep_map, held_lock, lock_list, lock_chain, lock_trace, lock_class_key] +interfaces: [lock_acquire, lock_release, lock_sync, lock_is_held_type, lockdep_init_map_type, lockdep_register_key, lockdep_unregister_key, lockdep_set_lock_cmp_fn, lockdep_reset_lock, lock_set_class, lock_downgrade, lock_pin_lock, lock_unpin_lock, lockdep_init_task, debug_check_no_locks_held, lockdep_rcu_suspicious, __lock_acquire, register_lock_class, look_up_lock_class, validate_chain, check_prev_add, check_prevs_add, check_noncircular, __bfs, print_circular_bug, lookup_chain_cache, add_chain_cache, iterate_chain_key, debug_locks_off, lock_acquired, lock_contended] +ops: [] +artefacts: [oops/tier0/lockdep-ab-ba, proc/tier0/lockdep-stats-before, proc/tier0/lockdep-stats-after] +--- + +# The lock ordering checker + +**Status is `partial`, and this is what that means here.** All fifty nine citations in `lock-ordering.refs.toml` resolve against the pinned 7.2.2 source and every anchor in it matches exactly one line in the file it names. Sections 2 and 7 come out of the BTF of the `D-lockdep` build, which is the profile that turns this mechanism on, and section 5 comes from three artefacts taken on one boot of that kernel. What is left is a person. `complete` needs a name in `reviewed-by`, and nobody has read this through yet. + +One thing about this mechanism is worth saying before anything else, because it is what readers get wrong and it is not a detail. This code does not watch for a deadlock. It never looks at a thread that is waiting, it has no timer, and nothing in it runs when the machine hangs. What it does is keep a directed graph whose nodes are lock classes and whose edges mean this one was held while that one was taken, and every time it is about to add an edge it asks whether that edge would close a cycle. The question is asked during an acquire, on one processor, with nothing waiting for anything at all. That is why a report can arrive from a run that finished perfectly, on a machine with one processor, from two threads that never overlapped in time. + +The second thing is the part that costs people an afternoon. The first report of a boot switches the whole mechanism off. Not the reporting, the mechanism. Everything after it is unchecked, and the only place that fact is written down is one line of a `/proc` file. + +The picture below is both of those in one frame. + +![A picture in three parts. On the left, a small directed graph labelled the lock graph, with two round-cornered nodes, lock_a and lock_b. A solid arrow runs from lock_a down to lock_b labelled held while taking, meaning lock_a was held while lock_b was taken. A dashed arrow runs back up from lock_b to lock_a labelled about to be added, and under it a red box reads that adding this edge closes a cycle, so refuse it, print, and switch off. A note underneath says a node is a lock class, which is a line of source rather than an object, so every mutex initialised on one line is one node here however many of them exist. In the middle, two columns headed first thread and second thread, with five steps in time order reading down: the first thread takes lock_a, takes lock_b, then releases both and exits, and only then the second thread takes lock_b and takes lock_a. A note beside them says both threads ran to the end, neither ever waited for the other, and the report came out anyway, because the cycle is a property of the code and a hang is a property of the timing. On the right, a column of the four things the checker does on every single acquire, in order: find or register the lock class, push it on this task's held lock stack, mix the class index into the chain key, and look the chain key up in the chain cache, with a fifth box below reading that a miss walks the graph backwards looking for a path home. A note says a hit means this exact sequence of held locks has been seen before and nothing below runs, and that this is the whole reason the checker is affordable. Across the bottom is a red band reading that debug_locks goes to 0 on the first report of the boot, and under it two lines saying that from that moment nothing is checked at all, a second bug loaded afterwards is silent, a quiet log means nothing, and the only place it shows is the debug_locks line of /proc/lockdep_stats.](assets/lock-ordering-cycle.svg) + +## §1 Purpose and boundary + +This mechanism owns the bookkeeping that happens around every lock operation in the kernel and the graph that bookkeeping feeds. It is responsible for turning a lock into a class, remembering which locks a task currently holds and in what order it took them, recording the pairs of classes that have ever been nested, refusing to record a pair that would close a cycle, and printing a report when it refuses. + +It deserves a specification of its own because it is the only part of the kernel that is asked to prove something about code it is not running. Everything else in the tree reacts to what happened. This reacts to what could happen on a machine with more processors, different timing and a different scheduler, from evidence gathered on the machine it is actually on. That difference is the source of every surprising thing about it, including the reports with no hang behind them and the silence after the first one. + +What it is not responsible for: + +- Making locks work. Waiting, wakeups, ownership handoff and the fast paths are each lock type's own mechanism, and this one is called from them rather than being part of them. +- Getting a machine out of a deadlock. Nothing here recovers, retries or breaks a cycle. When the cycle is real and the timing lines up, the machine hangs, and this code is not running when it does. +- Measuring contention. How long a lock was held and how often it was contended is `CONFIG_LOCK_STAT`, which reuses the same hooks and the same classes but answers a different question. Section 8 says what it costs. +- Deciding what is a valid order in the first place. The checker has no rules of its own about which lock should be outermost. It learns the order from whatever the kernel did first and treats every later disagreement as the bug. +- The read side critical section tracking that `lockdep_rcu_suspicious` sits on top of. That is the RCU blueprint. This mechanism supplies the held lock stack it reads and nothing more. +- Interrupt state tracking, which is a second graph problem layered on this one. It is named in section 6 where its report is, and it is a blueprint of its own. +- Anything about how a lock is initialised beyond the key. Which lock types exist and what their fast paths look like belongs with each type. + +## §2 Data structures + +Generated, and the block below says what from. Hand editing it fails the build. + + + + +Generated by bpc 0.2 from `kxbox/kernel/build/D-lockdep/vmlinux`, for i386 with 4 byte pointers. Offsets are byte offsets from the start of the structure. A hole is padding the compiler inserted and not a field you can use. + +### struct lock_class + +140 bytes, 26 field(s), 1 bytes of padding in 1 hole(s). + +| Offset | Size | Field | Type | +|---|---|---|---| +| 0 | 8 | `hash_entry` | `struct hlist_node` | +| 0 | 4 | `hash_entry.next` | `struct hlist_node *` | +| 4 | 4 | `hash_entry.pprev` | `struct hlist_node **` | +| 8 | 8 | `lock_entry` | `struct list_head` | +| 8 | 4 | `lock_entry.next` | `struct list_head *` | +| 12 | 4 | `lock_entry.prev` | `struct list_head *` | +| 16 | 8 | `locks_after` | `struct list_head` | +| 16 | 4 | `locks_after.next` | `struct list_head *` | +| 20 | 4 | `locks_after.prev` | `struct list_head *` | +| 24 | 8 | `locks_before` | `struct list_head` | +| 24 | 4 | `locks_before.next` | `struct list_head *` | +| 28 | 4 | `locks_before.prev` | `struct list_head *` | +| 32 | 4 | `key` | `const struct lockdep_subclass_key *` | +| 36 | 4 | `cmp_fn` | `lock_cmp_fn` | +| 40 | 4 | `print_fn` | `lock_print_fn` | +| 44 | 4 | `subclass` | `unsigned int` | +| 48 | 4 | `dep_gen_id` | `unsigned int` | +| 52 | 4 | `usage_mask` | `long unsigned int` | +| 56 | 40 | `usage_traces` | `const struct lock_trace *[10]` | +| 96 | 4 | `name` | `const char *` | +| 100 | 4 | `name_version` | `int` | +| 104 | 1 | `wait_type_inner` | `u8` | +| 105 | 1 | `wait_type_outer` | `u8` | +| 106 | 1 | `lock_type` | `u8` | +| 108 | 16 | `contention_point` | `long unsigned int[4]` | +| 124 | 16 | `contending_point` | `long unsigned int[4]` | + +- 1 byte hole at offset 107, after `lock_type`. + +### struct lockdep_map + +28 bytes, 8 field(s), 1 bytes of padding in 1 hole(s). + +| Offset | Size | Field | Type | +|---|---|---|---| +| 0 | 4 | `key` | `struct lock_class_key *` | +| 4 | 8 | `class_cache` | `struct lock_class *[2]` | +| 12 | 4 | `name` | `const char *` | +| 16 | 1 | `wait_type_outer` | `u8` | +| 17 | 1 | `wait_type_inner` | `u8` | +| 18 | 1 | `lock_type` | `u8` | +| 20 | 4 | `cpu` | `int` | +| 24 | 4 | `ip` | `long unsigned int` | + +- 1 byte hole at offset 19, after `lock_type`. + +### struct held_lock + +44 bytes, 15 field(s), no padding. + +| Offset | Size | Field | Type | +|---|---|---|---| +| 0 | 8 | `prev_chain_key` | `u64` | +| 8 | 4 | `acquire_ip` | `long unsigned int` | +| 12 | 4 | `instance` | `struct lockdep_map *` | +| 16 | 4 | `nest_lock` | `struct lockdep_map *` | +| 20 | 8 | `waittime_stamp` | `u64` | +| 28 | 8 | `holdtime_stamp` | `u64` | +| 36 | 13 bits | `class_idx` | `unsigned int` | +| 37 | 2 bits | `irq_context` | `unsigned int` | +| 37 | 1 bits | `trylock` | `unsigned int` | +| 38 | 2 bits | `read` | `unsigned int` | +| 38 | 1 bits | `check` | `unsigned int` | +| 38 | 1 bits | `hardirqs_off` | `unsigned int` | +| 38 | 1 bits | `sync` | `unsigned int` | +| 38 | 11 bits | `references` | `unsigned int` | +| 40 | 4 | `pin_count` | `unsigned int` | + +### struct lock_list + +28 bytes, 10 field(s), no padding. + +| Offset | Size | Field | Type | +|---|---|---|---| +| 0 | 8 | `entry` | `struct list_head` | +| 0 | 4 | `entry.next` | `struct list_head *` | +| 4 | 4 | `entry.prev` | `struct list_head *` | +| 8 | 4 | `class` | `struct lock_class *` | +| 12 | 4 | `links_to` | `struct lock_class *` | +| 16 | 4 | `trace` | `const struct lock_trace *` | +| 20 | 2 | `distance` | `u16` | +| 22 | 1 | `dep` | `u8` | +| 23 | 1 | `only_xr` | `u8` | +| 24 | 4 | `parent` | `struct lock_list *` | + +### struct lock_chain + +20 bytes, 7 field(s), no padding. + +| Offset | Size | Field | Type | +|---|---|---|---| +| 0 | 2 bits | `irq_context` | `unsigned int` | +| 0 | 6 bits | `depth` | `unsigned int` | +| 1 | 24 bits | `base` | `unsigned int` | +| 4 | 8 | `entry` | `struct hlist_node` | +| 4 | 4 | `entry.next` | `struct hlist_node *` | +| 8 | 4 | `entry.pprev` | `struct hlist_node **` | +| 12 | 8 | `chain_key` | `u64` | + +### struct lock_trace + +16 bytes, 6 field(s), no padding. + +| Offset | Size | Field | Type | +|---|---|---|---| +| 0 | 8 | `hash_entry` | `struct hlist_node` | +| 0 | 4 | `hash_entry.next` | `struct hlist_node *` | +| 4 | 4 | `hash_entry.pprev` | `struct hlist_node **` | +| 8 | 4 | `hash` | `u32` | +| 12 | 4 | `nr_entries` | `u32` | +| 16 | 0 | `entries` | `long unsigned int[0]` | + +### struct lock_class_key + +8 bytes, 4 field(s), no padding. + +| Offset | Size | Field | Type | +|---|---|---|---| +| 0 | 8 | `hash_entry` | `struct hlist_node` | +| 0 | 4 | `hash_entry.next` | `struct hlist_node *` | +| 0 | 8 | `subkeys` | `struct lockdep_subclass_key[8]` | +| 4 | 4 | `hash_entry.pprev` | `struct hlist_node **` | + + +## §3 Algorithms + +Numbered from the moment a lock is taken. Steps 1 to 8 run on every acquire of every lock on the machine, and their cost is the cost of running this kernel at all. Steps 9 to 16 run only when step 8 misses, which after boot is rare. Steps 17 to 19 are the report. + +1. The lock's own code calls one entry point, and every lock type in the kernel calls the same one [lock-ordering-R13]. Three things happen before any checking. A tracepoint fires, so a tracer can see the acquire whether or not any of this is compiled in. The master switch is tested, and if it is off the function returns immediately, which is the whole of what step 19 leaves behind. Then interrupts are disabled for the rest of the call, because everything below touches data that an interrupt handler taking a lock would re-enter. + +2. Read one byte of the lock's own memory on purpose [lock-ordering-R14]. Nothing is done with the value. This is the first thing in the kernel to touch a lock on the way in, so a lock in memory that has already been freed is caught here by the memory checker, which produces a report naming the free, rather than three steps later as a confusing complaint about a key. + +3. Find the class this lock belongs to [lock-ordering-R5]. A class is identified by a key, and a key is an address [lock-ordering-R2]. For a lock declared with the usual initialiser macro that address is a static variable the macro created next to the lock, which is why every lock initialised by one line of source is one class no matter how many of them exist [lock-ordering-R1]. That is the single fact behind most of the confusion a first report causes: the two locks named in it may be two of ten thousand objects, and the report is about the line they were created on. + +4. Refuse a key that is not in the kernel image or in the per cpu area [lock-ordering-R3]. A key in heap memory could be freed and the address reused for something else, at which point two unrelated locks would silently become one class. A lock that was never initialised at all has no key, and the fallback is to use the lock's own address [lock-ordering-R4], so a statically declared lock that nobody initialised still gets a class of its own. + +5. Do the lookup without taking anything [lock-ordering-R6]. This runs on every acquire on every processor, so a lock around it would instantly be the most contended lock in the kernel. It walks a hash table under RCU. Only a miss takes the graph lock and allocates, and the allocation is a pop off a free list filled once at boot [lock-ordering-R7], because this code runs with interrupts off and cannot call the allocator. The pool holds 8192 classes [lock-ordering-R8], and running out of it prints and switches off [lock-ordering-R9] rather than failing the acquire. Two shortcuts sit in front of the lookup: a lock can be given up to eight subclasses [lock-ordering-R10] to tell the checker apart two locks of one class it is legitimately nesting, and the first two subclasses have their class pointer cached in the lock itself [lock-ordering-R11], so everything above subclass 1 pays for the hash walk on every single acquire. + +6. Push the lock onto this task's held lock stack [lock-ordering-R12]. The stack is an array inside the task structure, forty eight entries deep [lock-ordering-R58], which is a fixed memory cost on every thread on a kernel built with this on. Going past the end dumps every lock held and switches off [lock-ordering-R57]. The entry is filled in before any checking runs, and one of its fields is the chain key the push is about to displace [lock-ordering-R15], which is how the release path restores the key without recomputing anything. + +7. Mix the class into the chain key [lock-ordering-R16]. The chain key is a running hash of every class currently held, in the order they were taken [lock-ordering-R17], and it lives in the task [lock-ordering-R18], so it costs nothing to maintain and needs no lock. An acquire that happens inside an interrupt does not extend the interrupted task's chain, it starts a new one [lock-ordering-R19], because the locks the interrupted code was holding are not locks the handler is nesting inside. + +8. Look the chain key up in the chain cache [lock-ordering-R20]. This is the step the whole design is built around. A hit means this exact sequence of held locks, in this exact order, has been validated before, and there is nothing left to do. Everything below is skipped. This is why the cost of the checker falls away as a machine finishes booting instead of growing with its uptime, and it is why the artefacts in section 5 show a machine that has settled at a few thousand chains rather than one still discovering them. + +9. On a miss, gate on what kind of acquire this was [lock-ordering-R23]. A `trylock` records nothing, because code that is allowed to fail is allowed to ask in any order it likes. A lock the caller explicitly asked not to be checked records nothing either. + +10. Ask the cheap question first: is this class already on this task's own held stack [lock-ordering-R24]. That is a deadlock with one thread and one lock and needs no graph at all. The exception is two read acquires of one reader-writer lock, which is allowed and is why the entry records whether the acquire was for reading [lock-ordering-R25]. + +11. Check the wait context [lock-ordering-R46], which is the second thing this mechanism does and has nothing to do with ordering. Wait types are an ordered list running from a lock that cannot even be preempted up to one that can sleep [lock-ordering-R48], and the rule is that a lock whose wait type is looser than the tightest one already held is a bug [lock-ordering-R47]. Taking a mutex inside a spinlock is caught here, immediately, without needing a second thread or a second run. + +12. Walk out from the innermost held lock and offer each one as the source of a new edge [lock-ordering-R27]. Not every held lock gets an edge to the new one, and the rule for which do is written down where it is applied [lock-ordering-R26]. The walk stops at the first entry that was a `trylock`, which is what keeps the number of edges from growing with the square of the stack depth. + +13. For each candidate pair, decide whether to add the edge [lock-ordering-R28]. Before adding it, search the graph for a path that already runs the other way [lock-ordering-R29]. The argument order there is worth reading twice: the search starts at the lock being taken now and looks for the lock already held, which is backwards from the way the edge is described in every sentence around it. The search itself is breadth first [lock-ordering-R31], which is not a performance choice, it is so that the cycle in the report is the shortest one that exists and the report stays small enough to read. Its queue is a fixed size ring [lock-ordering-R32], so the search can also give up, and giving up is a different outcome from finding nothing. + +14. Two filters run after the search rather than before it [lock-ordering-R30]. An edge that already exists is not added twice [lock-ordering-R33], and an edge already implied by a path through other edges is not added at all [lock-ordering-R34]. The second one is what keeps the graph from filling up on a machine that has been running for a month. + +15. Add the edge, twice [lock-ordering-R35]. Once forwards and once backwards, because both the forward search and the backward search have to be cheap, and the extra memory buys not having a slow direction. The insert is an RCU list add [lock-ordering-R36], so the lockless readers walking the graph never have to be stopped. How many edges fit is a build time choice [lock-ordering-R37], and it is fifteen bits on the profile this blueprint was generated from. Running out prints and switches off [lock-ordering-R38]. + +16. Record the sequence in the chain cache so it is never checked again [lock-ordering-R21], with its own ceiling and its own way of running out [lock-ordering-R22]. + +17. When step 13 found a path, print the report [lock-ordering-R39]. The first thing it does, before printing a single character, is switch the mechanism off and release the graph lock in one step [lock-ordering-R41]. That function returns whether this call was the one that did it, and every reporting path in the file is written as a test of it, which is why exactly one report comes out of a boot no matter how many bugs are on the machine. + +18. Print the chain highest number first [lock-ordering-R40]. That ordering is decided in the printing rather than anywhere in the data, and it is why `#0` in a report is the lock being taken at the moment the report happened and the highest number is the outermost lock held. + +19. Everything after that is the shape of a kernel with the checker off. The bookkeeping in steps 1 to 8 still runs, because the master switch is tested at the top of the entry point and not everywhere, but nothing is validated, no report can be printed, and the counters in section 5 stop moving. The internal limits reached in steps 5, 6, 15 and 16 print their own two line notice instead of a report [lock-ordering-R42], and the second of those two lines is the string to search a log for. The only durable, readable trace of any of this is one line of `/proc/lockdep_stats` [lock-ordering-R43]. + +The whole graph is protected by one lock, and it is a raw architecture spinlock rather than any of the lock types the kernel offers [lock-ordering-R44]. It has to be [lock-ordering-R45]. Every kernel lock calls into this file on acquire, so a kernel lock used here would call into the code it is protecting, from inside it, with interrupts already off. + +## §4 Invariants, locking and context + +### §4a Invariants + +1. A class key is an address that cannot be freed and reused while the class exists, so two live classes never share a key [lock-ordering-R3]. [checked: `static_obj` refuses a key that is neither in the image nor per cpu, and prints `trying to register non-static key`] +2. The chain key held in a task is the hash of exactly the classes in that task's held lock stack, in the order they were taken [lock-ordering-R15]. [checked: the displaced value is saved in the entry being pushed and restored on release rather than recomputed] +3. A task's held lock stack never has more than `MAX_LOCK_DEPTH` entries in it [lock-ordering-R58] [lock-ordering-R57]. [checked: `BUG_ON` on the depth at the top of the acquire] +4. The dependency graph has no cycle in it at any moment when the checker is on [lock-ordering-R30] [lock-ordering-R35]. [checked: the search runs before the edge is added rather than after] +5. Every edge in the graph is stored in both directions, so the forward and backward searches see the same graph. [checked: two calls to `add_lock_to_list` on the one success path] +6. No two acquires modify the graph at the same time, on any number of processors [lock-ordering-R44]. [checked: the raw spinlock is held across every modification] +7. When the master switch is off, nothing is added to the graph and no report is printed [lock-ordering-R13] [lock-ordering-R41]. [checked: the switch is tested at the top of the entry point, and it is cleared before printing rather than after] +8. At most one report is printed per boot [lock-ordering-R41]. [checked: every report path tests the return of the clear-and-unlock, which is true for exactly one caller] +9. A hit in the chain cache means every pair of classes in that sequence is already an edge in the graph. It follows from steps 12 to 16 running to completion before step 16 records the chain, and nothing verifies it afterwards. [unchecked] +10. Every edge that was added has a stack trace recorded with it [lock-ordering-R59]. [checked: the edge is not added when the trace cannot be saved] + +### §4b Locking discipline + +What protects each thing this mechanism touches: + +| Thing | Protected by | +|---|---| +| the class hash table, for lookup [lock-ordering-R6] | `rcu` | +| the class hash table, for insert [lock-ordering-R7] | `graph_lock` | +| the free list classes are allocated from | `graph_lock` | +| the edge lists that make up the graph, for reading [lock-ordering-R36] | `rcu` | +| the edge lists, for writing [lock-ordering-R35] | `graph_lock` | +| the chain cache | `graph_lock` | +| a task's held lock stack | `owner`, it is inside the task and only that task touches it | +| a task's chain key [lock-ordering-R18] | `owner`, same | +| the two cached class pointers in a lock [lock-ordering-R11] | `none`, defended below | +| the master switch | `atomic`, and it only ever goes one way | +| the breadth first search queue [lock-ordering-R32] | `graph_lock`, it is one shared ring and the search runs under the lock | + +The `none` needs its defence. The cached class pointer in a `lockdep_map` can be written by two processors at once, and the write is a single aligned pointer store of a value both of them computed from the same key, so both are writing the same address. Reading a stale null costs one hash lookup and reading the value costs nothing. This is a deliberate unlocked write, not an oversight, and it is the kind of thing that is worth writing down in a specification because a reader will otherwise find it and assume it is a bug. + +Acquisition order, written as a chain with `>` meaning taken before: + +`(any kernel lock) > graph_lock` + +That is the entire order, and it is the reason the graph lock has to be a raw architecture spinlock [lock-ordering-R45]. It is the innermost lock in the kernel by construction. Nothing can be taken while holding it, because taking anything would call back into this file, so there is no second pair to write down. + +### §4c Execution context + +`lock_acquire` [lock-ordering-R13] is called from everywhere in the kernel, which makes this the shortest table in the project. + +| Context | Allowed | What it may do | +|---|---|---| +| `P` | yes | everything below, and this is where nearly all class registration happens | +| `PP` | yes | the same, it disables interrupts itself | +| `A` | yes | the same, and this is the common case inside a spinlock | +| `SI` | yes | the same, with the chain starting fresh [lock-ordering-R19] | +| `HI` | yes | the same | +| `NMI` | yes | the same, and this is the one worth thinking about | + +Nothing here sleeps, nothing here allocates, and nothing here takes a lock the kernel would recognise as a lock. That is not a coincidence, it is the specification. Code called from inside every lock acquire in the kernel, including the ones in an interrupt handler, has no context left to be picky about. + +The NMI case earns its own paragraph because it looks impossible and is not. An NMI can land while a processor holds the graph lock, and code in that NMI can take a lock and arrive here. The graph lock is a plain spin, so spinning on it from an NMI on the same processor would hang the machine forever. What saves it is that acquiring the graph lock is not a blocking operation in this file: the callers test whether they got it and give up quietly when they did not, so an NMI that arrives at the wrong moment silently records nothing. That is a real hole in coverage, it is accepted deliberately, and it is a good example of what this mechanism trades away to be callable from anywhere. + +The `PREEMPT_RT` delta is larger here than in any other blueprint in this project so far, and it runs in the opposite direction to the usual one. On RT a `spin_lock` becomes a sleeping lock, so the wait context rules in step 11 change meaning entirely: a nesting that is legal on a mainline build becomes a bug on an RT build, and the same source file will produce a report on one and silence on the other. `CONFIG_PROVE_RAW_LOCK_NESTING` exists to make a mainline build enforce the RT rules, so that the bug is found by people who are not running RT. Section 8 says what it changes. + +## §5 Observable behaviour + +Generated, and the block below says what from. Hand editing it fails the build. + + + + +Generated by bpc 0.2 from 3 artefact(s) in `corpora/`. Every claim in this section points at a file that can be replayed, which is the difference between a specification of observable behaviour and a description of it. + +### `corpora/oops/tier0/lockdep-ab-ba.txt` + +Not a trace. Taken by `insmod /lib/modules/abba.ko`, recording a real circular locking dependency report, printed on a run where nothing blocked and nothing waited, taken off the pinned kernel with lockdep in it. + +`abba_second` at pid 40 on kernel 7.2.2, holding `lock_b` and asking for `lock_a`. A cycle of 2: `lock_a` -> `lock_b` -> `lock_a`. + +| | Class | Usage | Wait type | Address | Where the report caught it | +|---|---|---|---|---|---| +| holding | `lock_b` | `+.+.` | `4:4` | `c78250b8` | `abba_second_thread+0x1e/0x60 [abba]` | +| acquiring | `lock_a` | `+.+.` | `4:4` | `c7825118` | `abba_second_thread+0x2a/0x60 [abba]` | + +The addresses are printed by the kernel and are not what the report is about. The checker works in classes, and a class is a line of source rather than an object, so two locks at two addresses initialised on the same line are one class here. + +The chain, highest number first, which is the order the kernel prints it in. `#0` is the one being taken at the moment the report is printed. + +| Link | Class | Usage | First recorded at | Frames | +|---|---|---|---|---| +| #0 | `lock_a` | `+.+.` | `__lock_acquire+0x165d/0x2740` | 9 | +| #1 | `lock_b` | `+.+.` | `__mutex_lock+0x87/0xd30` | 7 | + +The interleaving the kernel says would deadlock, over 2 processor(s), rebuilt here from the parse rather than copied out of the file. + +``` +CPU0 CPU1 +---- ---- +lock(lock_b); + lock(lock_a); + lock(lock_b); +lock(lock_a); +``` + +Where `lock_a` was taken, as `#0` records it. + +``` +__lock_acquire+0x165d/0x2740 +lock_acquire+0x8c/0x230 +__mutex_lock+0x87/0xd30 +mutex_lock_nested+0x1a/0x20 +abba_second_thread+0x2a/0x60 [abba] +kthread+0xe8/0x130 +ret_from_fork+0x20d/0x270 +ret_from_fork_asm+0x12/0x20 +restore_all_switch_stack+0x0/0x81 +``` + +Where `lock_b` was taken, as `#1` records it. + +``` +__mutex_lock+0x87/0xd30 +mutex_lock_nested+0x1a/0x20 +abba_first_thread+0x20/0x50 [abba] +kthread+0xe8/0x130 +ret_from_fork+0x20d/0x270 +ret_from_fork_asm+0x12/0x20 +restore_all_switch_stack+0x0/0x81 +``` + +### `corpora/proc/tier0/lockdep-stats-before.txt` and `corpora/proc/tier0/lockdep-stats-after.txt` + +Not a trace. Taken by `cat /proc/lockdep_stats`, recording /proc/lockdep_stats read on a boot that has not had a lockdep report yet, so debug_locks is still one. + +51 counter(s) read, 1 line(s) skipped, 0 line(s) the parser could not read, and 51 counter(s), 1 skipped, 0 unread in the other. + +`debug_locks` in `lockdep-stats-before` is 1, which is the checker on, so every lock taken from here is checked. +In `lockdep-stats-after` it is 0, which is the checker off, so nothing taken from here is checked and there will be no second report. + +| Counter | `lockdep-stats-before` | `lockdep-stats-after` | Change | Ceiling | +|---|---|---|---|---| +| `lock_classes` | 391 | 401 | +10 | 8192, 4.8% used | +| `dynamic_keys` | 44 | 44 | none | none printed | +| `direct_dependencies` | 2268 | 2324 | +56 | 32768, 6.9% used | +| `indirect_dependencies` | 4141 | 4318 | +177 | none printed | +| `all_direct_dependencies` | 19132 | 19732 | +600 | none printed | +| `dependency_chains` | 1949 | 2011 | +62 | 65536, 3.0% used | +| `dependency_chain_hlocks_used` | 5937 | 6101 | +164 | 327680, 1.8% used | +| `dependency_chain_hlocks_lost` | 0 | 0 | none | none printed | +| `in_hardirq_chains` | 24 | 24 | none | none printed | +| `in_softirq_chains` | 40 | 40 | none | none printed | +| `in_process_chains` | 1885 | 1947 | +62 | none printed | +| `stack_trace_entries` | 31181 | 31872 | +691 | 524288, 5.9% used | +| `number_of_stack_traces` | 1560 | 1601 | +41 | none printed | +| `number_of_stack_hash_chains` | 1462 | 1497 | +35 | none printed | +| `combined_max_dependencies` | 1933150 | 1996700 | +63550 | none printed | +| `hardirq_safe_locks` | 25 | 25 | none | none printed | +| `hardirq_unsafe_locks` | 248 | 256 | +8 | none printed | +| `softirq_safe_locks` | 32 | 32 | none | none printed | +| `softirq_unsafe_locks` | 241 | 249 | +8 | none printed | +| `irq_safe_locks` | 43 | 43 | none | none printed | +| `irq_unsafe_locks` | 248 | 256 | +8 | none printed | +| `hardirq_read_safe_locks` | 1 | 1 | none | none printed | +| `hardirq_read_unsafe_locks` | 21 | 23 | +2 | none printed | +| `softirq_read_safe_locks` | 1 | 1 | none | none printed | +| `softirq_read_unsafe_locks` | 21 | 23 | +2 | none printed | +| `irq_read_safe_locks` | 1 | 1 | none | none printed | +| `irq_read_unsafe_locks` | 21 | 23 | +2 | none printed | +| `uncategorized_locks` | 90 | 91 | +1 | none printed | +| `unused_locks` | 1 | 1 | none | none printed | +| `max_locking_depth` | 10 | 10 | none | none printed | +| `max_bfs_queue_depth` | 52 | 52 | none | none printed | +| `max_lock_class_index` | 390 | 400 | +10 | none printed | +| `chain_lookup_misses` | 2060 | 2122 | +62 | none printed | +| `chain_lookup_hits` | 282409 | 289122 | +6713 | none printed | +| `cyclic_checks` | 1775 | 1827 | +52 | none printed | +| `redundant_checks` | 0 | 0 | none | none printed | +| `redundant_links` | 0 | 0 | none | none printed | +| `find_mask_forwards_checks` | 189 | 189 | none | none printed | +| `find_mask_backwards_checks` | 535 | 555 | +20 | none printed | +| `hardirq_on_events` | 147071 | 150692 | +3621 | none printed | +| `hardirq_off_events` | 147070 | 150691 | +3621 | none printed | +| `redundant_hardirq_ons` | 0 | 0 | none | none printed | +| `redundant_hardirq_offs` | 1 | 1 | none | none printed | +| `softirq_on_events` | 515 | 551 | +36 | none printed | +| `softirq_off_events` | 515 | 551 | +36 | none printed | +| `redundant_softirq_ons` | 0 | 0 | none | none printed | +| `redundant_softirq_offs` | 0 | 0 | none | none printed | +| `debug_locks` | 1 | 0 | -1 | none printed | +| `zapped_classes` | 2 | 2 | none | none printed | +| `zapped_lock_chains` | 111 | 111 | none | none printed | +| `large_chain_blocks` | 1 | 1 | none | none printed | + + +## §6 Edge cases and failure modes + +- **allocation-failure.** Nothing here calls the allocator, so the failure is running out of one of five fixed pools instead. Classes [lock-ordering-R9], edges [lock-ordering-R38], chains [lock-ordering-R22], stack trace storage [lock-ordering-R59] and the held stack depth [lock-ordering-R57] each have a limit and each end the same way, which is that the mechanism switches itself off for the rest of the boot. There is no degraded mode. A kernel that has exhausted any one of them is a kernel with no checking on it, and the way to tell is the first counter in section 5 that is at its ceiling. Four of the five limits are build time choices, so hitting one is usually a reason to rebuild rather than a bug. + +- **concurrent-entry.** Every processor is in this code constantly, which is why the read paths are lockless and the write paths take one raw spinlock. Two processors registering the same new class at the same time is resolved by the loser finding the class already present after it takes the lock. Two processors finding two different cycles at the same time is resolved by exactly one of them printing [lock-ordering-R41]. The interesting case is the one that produces no answer at all: a search that cannot get the graph lock records nothing and returns, so on a busy machine a small number of acquires go unchecked, and there is no counter for how many. + +- **wrong-context.** There is no wrong context, and that is the specification rather than an accident. The one situation the code cannot handle is an NMI arriving on a processor that already holds the graph lock, and section 4c says what happens then, which is that the acquire is silently not checked. + +- **signal.** Nothing here is interruptible and nothing here can be reached from a signal delivery path in a way that matters. The related failure is different and worth naming: a lock still held on the way back to userspace [lock-ordering-R55]. That is checked on the system call exit path, and it catches a class of bug that no acquire would ever see, because the code that leaked the lock has already returned successfully. + +- **object-freed.** Two separate cases, and both have their own report. Memory holding a lock that somebody still holds being freed [lock-ordering-R53] is detected because the allocator calls in to ask, so the report comes out of `kfree` and not out of an acquire. A class key being freed is the other one, and it is why step 4 refuses a key that is not in the image, since a freed and reused key would quietly merge two unrelated classes and produce reports that name locks with nothing to do with each other. + +- **refcount-zero.** There are no reference counts in this mechanism. Classes are never freed one at a time, only in ranges when a module unloads, and the held lock stack is owned by exactly one task for its whole life. The nearest thing to this failure is a release with no matching acquire [lock-ordering-R54], which is usually a lock taken on one thread and released on another. + +- **boundary-cases.** Zero locks held is the normal state and makes step 12 do nothing. One lock held is where the first edges come from. The maximum is forty eight [lock-ordering-R58], and a task that reaches it is almost always in a recursion rather than genuinely holding forty eight locks. On the size of the graph, the boundary that bites first in practice is not the number of classes but the number of edges, because a class is a line of source and there are only so many of those, while edges grow with the ways they get combined. + +- **hostile-input.** Nothing here reads anything from userspace, so the input under discussion is the kernel's own behaviour. An unprivileged program can still steer it: a workload that exercises many distinct lock orderings adds edges, and every edge is permanent for the life of the boot. Nothing is ever removed except by module unload. On a kernel built with this on, that is a way for a program to consume a fixed kernel resource until the checker switches itself off, which is one of the several reasons this is a debugging configuration and not a production one. + +- **bug-message.** The message this blueprint is mostly about is the circular dependency warning [lock-ordering-R50]. Six others come from the same file and mean quite different things, and telling them apart from the first line is most of the skill. Recursive locking [lock-ordering-R51] is one thread taking one class twice and needs no second thread to reproduce. The interrupt inversion report [lock-ordering-R52] has no cycle in it at all and is about a lock taken with interrupts on that is also taken from a handler. Invalid wait context [lock-ordering-R49] is the step 11 check and is the one that looks least like the others. Held lock freed [lock-ordering-R53], bad unlock balance [lock-ordering-R54] and a lock held returning to userspace [lock-ordering-R55] are each about lifetime rather than order. Suspicious RCU usage [lock-ordering-R56] is a different subsystem borrowing this one's held lock stack to answer a question about read side sections. And the two line notice with `turning off the locking correctness validator` in it [lock-ordering-R42] is not a bug report at all, it is this mechanism saying it has stopped working. + +## §7 Interfaces + +Generated, and the block below says what from. Hand editing it fails the build. + + + + +Generated by bpc 0.2 from `kxbox/kernel/build/D-lockdep/vmlinux`. Signatures are what the kernel's own type information records, so a parameter with no name here is a parameter BTF has no name for rather than one the blueprint forgot. + +### Functions + +| Symbol | Signature | +|---|---| +| `lock_acquire` | `static void lock_acquire(struct lockdep_map *lock, unsigned int subclass, int trylock, int read, int check, struct lockdep_map *nest_lock, long unsigned int ip)` | +| `lock_release` | `static void lock_release(struct lockdep_map *lock, long unsigned int ip)` | +| `lock_sync` | `static void lock_sync(struct lockdep_map *lock, unsigned int subclass, int read, int check, struct lockdep_map *nest_lock, long unsigned int ip)` | +| `lock_is_held_type` | `static int lock_is_held_type(const struct lockdep_map *lock, int read)` | +| `lockdep_init_map_type` | `static void lockdep_init_map_type(struct lockdep_map *lock, const char *name, struct lock_class_key *key, int subclass, u8 inner, u8 outer, u8 lock_type)` | +| `lockdep_register_key` | `static void lockdep_register_key(struct lock_class_key *key)` | +| `lockdep_unregister_key` | `static void lockdep_unregister_key(struct lock_class_key *key)` | +| `lockdep_set_lock_cmp_fn` | `static void lockdep_set_lock_cmp_fn(struct lockdep_map *lock, lock_cmp_fn cmp_fn, lock_print_fn print_fn)` | +| `lockdep_reset_lock` | `static void lockdep_reset_lock(struct lockdep_map *lock)` | +| `lock_set_class` | `static void lock_set_class(struct lockdep_map *lock, const char *name, struct lock_class_key *key, unsigned int subclass, long unsigned int ip)` | +| `lock_downgrade` | `static void lock_downgrade(struct lockdep_map *lock, long unsigned int ip)` | +| `lock_pin_lock` | `static struct pin_cookie lock_pin_lock(struct lockdep_map *lock)` | +| `lock_unpin_lock` | `static void lock_unpin_lock(struct lockdep_map *lock, struct pin_cookie cookie)` | +| `lockdep_init_task` | `static void lockdep_init_task(struct task_struct *task)` | +| `debug_check_no_locks_held` | `static void debug_check_no_locks_held(void)` | +| `lockdep_rcu_suspicious` | `static void lockdep_rcu_suspicious(const char *file, const int line, const char *s)` | +| `__lock_acquire` | `static int __lock_acquire(struct lockdep_map *lock, unsigned int subclass, int trylock, int read, int check, int hardirqs_off, struct lockdep_map *nest_lock, long unsigned int ip, int references, int pin_count, int sync)` | +| `register_lock_class` | `static struct lock_class * register_lock_class(struct lockdep_map *lock, unsigned int subclass, int force)` | +| `look_up_lock_class` | `static struct lock_class * look_up_lock_class(const struct lockdep_map *lock, unsigned int subclass)` | +| `validate_chain` | no symbol in this build, inlined or configured out | +| `check_prev_add` | no symbol in this build, inlined or configured out | +| `check_prevs_add` | no symbol in this build, inlined or configured out | +| `check_noncircular` | `static enum bfs_result check_noncircular(struct held_lock *src, struct held_lock *target, const struct lock_trace **trace)` | +| `__bfs` | `static enum bfs_result __bfs(struct lock_list *source_entry, void *data, bool (struct lock_list *, void *) *match, bool (struct lock_list *, void *) *skip, struct lock_list **target_entry, int offset)` | +| `print_circular_bug` | `static void print_circular_bug(struct lock_list *this, struct lock_list *target, struct held_lock *check_src, struct held_lock *check_tgt)` | +| `lookup_chain_cache` | no symbol in this build, inlined or configured out | +| `add_chain_cache` | no symbol in this build, inlined or configured out | +| `iterate_chain_key` | no symbol in this build, inlined or configured out | +| `debug_locks_off` | `static int debug_locks_off(void)` | +| `lock_acquired` | `static void lock_acquired(struct lockdep_map *lock, long unsigned int ip)` | +| `lock_contended` | `static void lock_contended(struct lockdep_map *lock, long unsigned int ip)` | + + +## §8 Configuration and architecture dependence + +Which symbols change what is written above: + +- `CONFIG_LOCKDEP` is the switch for the bookkeeping, which is steps 1 to 8 and the held lock stack in every task. Without it the entry point is an empty inline and forty eight entries come off every thread. Everything in this blueprint requires it. +- `CONFIG_PROVE_LOCKING` is the switch for the checking, which is steps 9 to 18. A kernel with the first and not the second keeps the held lock stack, so `lockdep_assert_held` and the RCU checks still work, and never builds a graph or prints an ordering report. This split is worth knowing because it is what several subsystems actually depend on. +- `CONFIG_DEBUG_LOCK_ALLOC` is what makes each lock type call in on acquire and release at all. It is selected by the two above rather than chosen on its own. +- `CONFIG_LOCK_STAT` adds contention and hold time accounting on the same hooks and the same classes. It is a different question answered by the same plumbing, and it makes every acquire more expensive whether or not anything is contended. The `D-lockdep` profile has it on, which is why the counters in section 5 include rows a `PROVE_LOCKING` only build would not have. +- `CONFIG_DEBUG_LOCKDEP` adds internal self checks and, more usefully, the extra rows in `/proc/lockdep_stats` that report how full each pool is. Without it the artefacts in section 5 would be missing exactly the numbers a reader needs to know whether they are about to run out. +- `CONFIG_LOCKDEP_BITS` [lock-ordering-R37], `CONFIG_LOCKDEP_CHAINS_BITS` and `CONFIG_LOCKDEP_STACK_TRACE_BITS` set three of the five ceilings in section 6. They are powers of two and they cost memory that is allocated at boot whether it is used or not. `CONFIG_LOCKDEP_CIRCULAR_QUEUE_BITS` sets the size of the search queue [lock-ordering-R32], and raising it lets the search run further before giving up on a large graph. +- `CONFIG_PREEMPT_RT` changes the wait type of nearly every lock in the kernel, so it changes which nestings step 11 refuses. `CONFIG_PROVE_RAW_LOCK_NESTING` applies the RT rules on a build that is not RT, which is how those bugs get found by everyone rather than by the few people running RT kernels. +- `CONFIG_SMP` and `CONFIG_NR_CPUS` change nothing about this mechanism, and that is the most important line in this section. The pinned machine has one processor. Every claim in this blueprint, and the report in section 5, was produced on a machine where two threads cannot run at the same time. A checker that needed two processors to find a cycle would be useless, and this one does not, which is why it works at all. + +Architecture dependence: + +Almost none. The graph, the classes, the chains and the searches are the same code everywhere. The architecture shows through in three places. The graph lock is a raw architecture spinlock [lock-ordering-R44], so it is the architecture's own primitive with nothing on top. The stack traces recorded with each edge come from the architecture's unwinder, and a build with a poor unwinder produces reports whose second half is much less useful. And the pointer size changes every structure in section 2, which on this 32-bit machine makes a `lock_class` 140 bytes where a 64-bit build would be closer to twice that, so the fixed memory this mechanism costs is not a constant across machines. + +### The functions section 7 cannot find + +Six of the functions named in the header of this blueprint have no symbol in the `D-lockdep` build, and section 7 says so in its table rather than leaving them out. They are `validate_chain`, `check_prev_add`, `check_prevs_add`, `lookup_chain_cache`, `add_chain_cache` and `iterate_chain_key`, which is to say most of steps 7 to 16. + +Every one of them is `static` with one caller, in a file the compiler has plenty of freedom in, and there is nothing surprising about the compiler inlining them. The work happens. Steps 7 to 16 run on the machine. There is no symbol, no frame, and no way to attach a tracer to any of them on this build. + +This is the second distinct reason a function can be missing from a build and it is worth keeping apart from the first. A symbol can be absent because the configuration removed the code, in which case the work does not happen. A symbol can be absent because the compiler inlined it, in which case the work happens and is unobservable. Both look identical from outside, and the only thing that can tell them apart for a given build is that build. That is the argument for generating section 7 from the kernel's own type information rather than typing a list of function names into a document. + +## §9 Reimplementation notes + +Forced by the problem rather than by Linux: + +- That checking has to happen at acquire time and not at wait time. A deadlock detector that waits for the deadlock finds one bug on one machine with one interleaving, which is worth very little. Any kernel that wants to find ordering bugs before they hang a machine has to check the order at the moment the order is created. +- That there has to be some unit coarser than an object. A graph with one node per lock object on a running kernel would have millions of nodes and would learn nothing, because the two objects that will one day deadlock are usually not the two that were nested during the test run. + +Choices Linux made that another kernel could make differently: + +- **The class is the initialisation site.** This is the choice everything else follows from, and it is the one that produces confusing reports, because the report names a line and the reader is thinking about an object. A kernel could make the class the type instead, which would be coarser and produce more false reports, or could let each subsystem define its own classes explicitly, which would be more accurate and would need every subsystem to do the work. Linux takes the site for free from a macro and then provides subclasses [lock-ordering-R10] as an escape hatch for the cases where the free answer is wrong. The escape hatch has eight slots and two of them are fast [lock-ordering-R11], which tells you how often it was expected to be needed. + +- **Refusing a dynamically allocated key** [lock-ordering-R3]. This is a real restriction and it is why subsystems that create locks at runtime have to register a key separately. A kernel could allow it and track key lifetime with a reference count, which would cost a count on an object that exists in the millions. Linux made the cheap check and pushed the work onto the few subsystems that need it. + +- **Switching everything off on the first report** [lock-ordering-R41]. The argument for it is sound: after a cycle is found the graph is known to be wrong, so every later report would be suspect, and a machine that is printing lock reports in a loop with the graph lock involved is a machine nobody can debug. The cost is that finding two bugs takes two boots, and that a clean log is not evidence of anything. A kernel could switch off only the reporting for a class already implicated, or could rate limit rather than stop. There is a good case for both of those, and this blueprint would be shorter if Linux had picked one of them. + +- **Never removing anything from the graph.** Edges are permanent for the life of the boot, and removal only happens in bulk when a module unloads. A kernel could age edges out, which would let a long running machine keep checking rather than fill up, at the price of forgetting an ordering it once knew and needing to relearn it. Linux chose to be exactly right about everything it has seen and to stop when it runs out of room. + +- **One global lock for the entire graph** [lock-ordering-R44]. On a machine with many processors this is a single point every unlocked acquire has to avoid touching, which is why so much effort went into the lockless read paths and the chain cache. A kernel could partition the graph, but the cycles it is looking for cross partitions by definition, so any partitioning scheme needs a way to search across the pieces and that way is the hard part. Linux made the read path free and accepted a global lock on the rare write path. + +- **The chain cache as the affordability mechanism** [lock-ordering-R20]. Everything about the cost profile of this mechanism comes from step 8. Checking is expensive and almost never runs, so the price of the whole thing is a hash, a push and a lookup on each acquire. A kernel could instead cache per pair of classes rather than per sequence, which is a smaller cache with a lower hit rate, or could sample rather than check every acquire, which would be cheaper and would miss orderings that only ever happen once. Caching the whole held sequence is what makes it possible to say that every acquire on the machine was checked, which is a much stronger claim than any sampling scheme can make. diff --git a/blueprints/lock-ordering.refs.toml b/blueprints/lock-ordering.refs.toml new file mode 100644 index 0000000..79a3149 --- /dev/null +++ b/blueprints/lock-ordering.refs.toml @@ -0,0 +1,618 @@ +schema = 1 + +# Citations for the lock ordering blueprint. +# +# Every sentence in `lock-ordering.md` that states something about Linux points at one of these by +# writing its id in square brackets, and `refcheck` fails the build on a marker with no entry here +# and on an entry nothing points at. +# +# These are confirmed against the pinned tree. Confirming one means running: +# +# ./kxbox/kernel/tree.sh +# python3 -m tools.refcheck --tree kxbox/kernel/build/tree/linux-7.2.2 --confirm +# +# which finds the anchor, writes down the line it landed on and flips the flag. The tree that gets +# unpacked is the pristine tarball from kernel.org, checked against the same sha256 the build +# checks. +# +# The anchor is a piece of text to find, never a line number. The line numbers below are output +# rather than input, and running the command again after a version bump is what finds the ones +# that moved. +# +# Two things about this set are worth knowing before reading it. Nearly all of it is one file, +# `kernel/locking/lockdep.c`, which is close to seven thousand lines and is the whole mechanism +# apart from the type definitions and the `/proc` file. And a large number of the anchors below +# are comments rather than code, which is unusual for this project and is deliberate here: the +# comments in this file state the rules the code enforces, several of them are the only written +# statement of a rule anywhere, and a comment that gets deleted is exactly the change a reader of +# this blueprint would want to know about. + +[[references]] +id = "lock-ordering-R1" +path = "Documentation/locking/lockdep-design.rst" +anchor = "The basic object the validator operates upon" +kernel = "7.2.2" +confirmed = true +line = 11 +context = "ab9ac16b28dc" +note = "The unit the whole mechanism works in. A class, not a lock. Everything that surprises people about a report comes back to this paragraph." + +[[references]] +id = "lock-ordering-R2" +path = "kernel/locking/lockdep.c" +anchor = "NOTE: the class-key must be unique. For dynamic locks, a static" +kernel = "7.2.2" +confirmed = true +line = 915 +context = "3d965d51bbc4" +note = "What identifies a class. The key is an address, and for a lock initialised by a macro it is the address of a static variable that macro created, which is why the class is a line of source." + +[[references]] +id = "lock-ordering-R3" +path = "kernel/locking/lockdep.c" +anchor = "static int static_obj(const void *obj)" +kernel = "7.2.2" +confirmed = true +line = 827 +context = "677c6604d7fd" +note = "The test for whether an address is in the kernel image or in the per cpu area rather than in something allocated. A key that is neither is refused, which is the check behind the trying to register non-static key complaint." + +[[references]] +id = "lock-ordering-R4" +path = "kernel/locking/lockdep.c" +anchor = "Static locks do not have their class-keys yet - for them the key is" +kernel = "7.2.2" +confirmed = true +line = 951 +context = "283a54f91774" +note = "The fallback when a lock was never given a key. The lock's own address becomes the key, so a statically declared lock is its own class." + +[[references]] +id = "lock-ordering-R5" +path = "kernel/locking/lockdep.c" +anchor = "register_lock_class(struct lockdep_map *lock, unsigned int subclass, int force)" +kernel = "7.2.2" +confirmed = true +line = 1285 +context = "d2fad0b141f0" +note = "Where a class comes into existence. Looks the key up, and only takes the graph lock and allocates when the lookup missed." + +[[references]] +id = "lock-ordering-R6" +path = "kernel/locking/lockdep.c" +anchor = "We do an RCU walk of the hash, see lockdep_free_key_range()." +kernel = "7.2.2" +confirmed = true +line = 928 +context = "c46c5e24f995" +note = "The lookup is lockless. It has to be, because it runs on every acquire on every processor, and a lock around it would be the busiest lock in the kernel." + +[[references]] +id = "lock-ordering-R7" +path = "kernel/locking/lockdep.c" +anchor = "nr_lock_classes++;" +kernel = "7.2.2" +confirmed = true +line = 1336 +context = "090ab717c660" +note = "The allocation. Classes come off a free list that was filled once at boot, so this never calls the allocator and can run with interrupts off." + +[[references]] +id = "lock-ordering-R8" +path = "include/linux/lockdep_types.h" +anchor = "#define MAX_LOCKDEP_KEYS_BITS" +kernel = "7.2.2" +confirmed = true +line = 202 +context = "39cdbd78efd1" +note = "Thirteen bits, so 8192 classes, and the same thirteen bits are the width of class_idx in a held_lock. The ceiling and the field are the same number by construction." + +[[references]] +id = "lock-ordering-R9" +path = "kernel/locking/lockdep.c" +anchor = "print_lockdep_off(\"BUG: MAX_LOCKDEP_KEYS too low!\");" +kernel = "7.2.2" +confirmed = true +line = 1331 +context = "45c09b079175" +note = "What running out of classes prints. It is not a failure of the acquire, it is the end of checking for the rest of the boot." + +[[references]] +id = "lock-ordering-R10" +path = "include/linux/lockdep_types.h" +anchor = "#define MAX_LOCKDEP_SUBCLASSES" +kernel = "7.2.2" +confirmed = true +line = 15 +context = "a2c6b396735f" +note = "Eight subclasses per key. A subclass is how code that legitimately takes two locks of one class in a fixed order tells the checker which is which." + +[[references]] +id = "lock-ordering-R11" +path = "include/linux/lockdep_types.h" +anchor = "#define NR_LOCKDEP_CACHING_CLASSES" +kernel = "7.2.2" +confirmed = true +line = 61 +context = "04a327ef7d02" +note = "Two cached class pointers in every lockdep_map. Subclass 0 and subclass 1 skip the hash lookup, everything above them pays for it every time." + +[[references]] +id = "lock-ordering-R12" +path = "kernel/locking/lockdep.c" +anchor = "static int __lock_acquire(struct lockdep_map *lock, unsigned int subclass," +kernel = "7.2.2" +confirmed = true +line = 5077 +context = "bbef916d8976" +note = "The body of an acquire, and the function every step in section 3 is inside. Eleven parameters, which is what it costs to describe an acquire completely." + +[[references]] +id = "lock-ordering-R13" +path = "kernel/locking/lockdep.c" +anchor = "void lock_acquire(struct lockdep_map *lock, unsigned int subclass," +kernel = "7.2.2" +confirmed = true +line = 5825 +context = "3b9d176de7e9" +note = "The entry point every lock in the kernel calls. It fires a tracepoint, checks the master switch, and disables interrupts before doing anything else." + +[[references]] +id = "lock-ordering-R14" +path = "kernel/locking/lockdep.c" +anchor = "kasan_check_byte(lock);" +kernel = "7.2.2" +confirmed = true +line = 5842 +context = "6cdada3c7561" +note = "A deliberate read of the lock's own memory, put here because this is usually the first thing to touch a lock and a freed lock should be caught by the memory checker rather than by a confusing report." + +[[references]] +id = "lock-ordering-R15" +path = "kernel/locking/lockdep.c" +anchor = "hlock->prev_chain_key = chain_key;" +kernel = "7.2.2" +confirmed = true +line = 5220 +context = "73f2b7af992b" +note = "The held_lock is filled in before the checking runs, and the chain key it displaces is saved in it, which is how the key is restored on release without recomputing anything." + +[[references]] +id = "lock-ordering-R16" +path = "kernel/locking/lockdep.c" +anchor = "static inline u64 iterate_chain_key(u64 key, u32 idx)" +kernel = "7.2.2" +confirmed = true +line = 447 +context = "dffaad62be8e" +note = "The mixing step. One class index into a 64 bit running hash, with jhash, once per acquire." + +[[references]] +id = "lock-ordering-R17" +path = "kernel/locking/lockdep.c" +anchor = "The hash key of the lock dependency chains is a hash itself too:" +kernel = "7.2.2" +confirmed = true +line = 442 +context = "6c7b762430df" +note = "What the chain key means. It identifies the whole sequence of locks held right now, not the last one, which is what makes one lookup able to skip all the work." + +[[references]] +id = "lock-ordering-R18" +path = "kernel/locking/lockdep.c" +anchor = "curr->curr_chain_key = chain_key;" +kernel = "7.2.2" +confirmed = true +line = 5244 +context = "4c8ed69c53de" +note = "The chain key lives in the task, so it costs nothing to keep and needs no lock. Every thread has its own." + +[[references]] +id = "lock-ordering-R19" +path = "kernel/locking/lockdep.c" +anchor = "if (separate_irq_context(curr, hlock)) {" +kernel = "7.2.2" +confirmed = true +line = 5221 +context = "29af536ccf65" +note = "An interrupt that lands mid sequence starts a fresh chain rather than extending the interrupted one, because the locks the interrupted code holds are not locks the handler is nesting inside." + +[[references]] +id = "lock-ordering-R20" +path = "kernel/locking/lockdep.c" +anchor = "static inline struct lock_chain *lookup_chain_cache(u64 chain_key)" +kernel = "7.2.2" +confirmed = true +line = 3796 +context = "8be6038f4a7f" +note = "The lookup that decides whether anything expensive happens. A hit means this exact sequence has been validated before and there is nothing to do." + +[[references]] +id = "lock-ordering-R21" +path = "kernel/locking/lockdep.c" +anchor = "static inline int add_chain_cache(struct task_struct *curr," +kernel = "7.2.2" +confirmed = true +line = 3730 +context = "90b57ebc96a5" +note = "Recording a sequence so it is never checked again. This is why the cost of the checker falls away after boot instead of growing with uptime." + +[[references]] +id = "lock-ordering-R22" +path = "kernel/locking/lockdep.c" +anchor = "print_lockdep_off(\"BUG: MAX_LOCKDEP_CHAINS too low!\");" +kernel = "7.2.2" +confirmed = true +line = 3752 +context = "6ccad8de7ce9" +note = "Running out of room for chains, which switches the checker off in the same way a report does." + +[[references]] +id = "lock-ordering-R23" +path = "kernel/locking/lockdep.c" +anchor = "if (!hlock->trylock && hlock->check &&" +kernel = "7.2.2" +confirmed = true +line = 3875 +context = "c8f22905db56" +note = "The gate on all the checking. A trylock adds no dependency, because failing is an option and code that can fail is allowed to take locks in any order." + +[[references]] +id = "lock-ordering-R24" +path = "kernel/locking/lockdep.c" +anchor = "check_deadlock(struct task_struct *curr, struct held_lock *next)" +kernel = "7.2.2" +confirmed = true +line = 3057 +context = "5fee3ab679ea" +note = "The cheap check first: is this class already on this task's own held stack. That is a deadlock with one thread and needs no graph walk to see." + +[[references]] +id = "lock-ordering-R25" +path = "kernel/locking/lockdep.c" +anchor = "Allow read-after-read recursion of the same" +kernel = "7.2.2" +confirmed = true +line = 3074 +context = "647913765f20" +note = "The exception to the previous check. Two readers of one reader-writer lock are not a deadlock, and the read field in the held_lock is what says which kind of acquire this was." + +[[references]] +id = "lock-ordering-R26" +path = "kernel/locking/lockdep.c" +anchor = "Add the dependency to all directly-previous locks that are 'relevant'." +kernel = "7.2.2" +confirmed = true +line = 3252 +context = "444b9ef2c022" +note = "Which held locks get an edge to the new one. Not all of them. The rule is stated here and it is the reason the graph does not have a quadratic number of edges in it." + +[[references]] +id = "lock-ordering-R27" +path = "kernel/locking/lockdep.c" +anchor = "check_prevs_add(struct task_struct *curr, struct held_lock *next)" +kernel = "7.2.2" +confirmed = true +line = 3258 +context = "9d06d591032e" +note = "The loop over the held stack that applies the rule above, walking outwards from the innermost held lock and stopping at the first one that was not a trylock." + +[[references]] +id = "lock-ordering-R28" +path = "kernel/locking/lockdep.c" +anchor = "check_prev_add(struct task_struct *curr, struct held_lock *prev," +kernel = "7.2.2" +confirmed = true +line = 3122 +context = "c9ce741d76ae" +note = "One candidate edge, and everything that has to be true before it is added. The comment above it lists the three questions in order." + +[[references]] +id = "lock-ordering-R29" +path = "kernel/locking/lockdep.c" +anchor = "ret = check_noncircular(next, prev, trace);" +kernel = "7.2.2" +confirmed = true +line = 3165 +context = "ba8b91ef66e0" +note = "The call, and the argument order is the thing to notice. The search starts at the lock being taken and looks for the lock already held, which is backwards from how the edge is described." + +[[references]] +id = "lock-ordering-R30" +path = "kernel/locking/lockdep.c" +anchor = "check_noncircular(struct held_lock *src, struct held_lock *target," +kernel = "7.2.2" +confirmed = true +line = 2149 +context = "0a3e6e13796a" +note = "The search itself. Before a new edge is added the checker walks the graph looking for a path back, and a path back is a cycle." + +[[references]] +id = "lock-ordering-R31" +path = "kernel/locking/lockdep.c" +anchor = "static enum bfs_result __bfs(struct lock_list *source_entry," +kernel = "7.2.2" +confirmed = true +line = 1733 +context = "c0c61b6b4368" +note = "The graph walk, breadth first, so that the cycle it reports is the shortest one and the report is as small as it can be." + +[[references]] +id = "lock-ordering-R32" +path = "kernel/locking/lockdep.c" +anchor = "The search is limited by the size of the circular queue (i.e.," +kernel = "7.2.2" +confirmed = true +line = 3161 +context = "b67d64d28147" +note = "The walk has a fixed size queue and can give up. Giving up is a separate outcome from finding nothing, and it is one of the ways checking stops." + +[[references]] +id = "lock-ordering-R33" +path = "kernel/locking/lockdep.c" +anchor = "Is the -> dependency already present?" +kernel = "7.2.2" +confirmed = true +line = 3173 +context = "25718edfb32b" +note = "The duplicate check, after the cycle search rather than before it. The comment explains why an edge can already exist even on a chain that is new." + +[[references]] +id = "lock-ordering-R34" +path = "kernel/locking/lockdep.c" +anchor = "Is the -> link redundant?" +kernel = "7.2.2" +confirmed = true +line = 3217 +context = "cbc3c3679c9a" +note = "An edge already implied by a path through other edges is not stored. This is what keeps the graph from growing without bound on a long running machine." + +[[references]] +id = "lock-ordering-R35" +path = "kernel/locking/lockdep.c" +anchor = "static int add_lock_to_list(struct lock_class *this," +kernel = "7.2.2" +confirmed = true +line = 1424 +context = "90f1493b8634" +note = "Adding an edge. Two calls, one forward and one backward, because the backward search and the forward search both have to be cheap." + +[[references]] +id = "lock-ordering-R36" +path = "kernel/locking/lockdep.c" +anchor = "list_add_tail_rcu(&entry->entry, head);" +kernel = "7.2.2" +confirmed = true +line = 1448 +context = "77c0da4112f0" +note = "The edge goes in under RCU, so the lockless readers walking the graph do not have to be stopped while it is modified." + +[[references]] +id = "lock-ordering-R37" +path = "kernel/locking/lockdep_internals.h" +anchor = "(1UL << CONFIG_LOCKDEP_BITS)" +kernel = "7.2.2" +confirmed = true +line = 104 +context = "c7c36bc65292" +note = "How many edges the graph can hold, chosen at build time. On the profile this blueprint was generated from that is fifteen bits, so 32768." + +[[references]] +id = "lock-ordering-R38" +path = "kernel/locking/lockdep.c" +anchor = "print_lockdep_off(\"BUG: MAX_LOCKDEP_ENTRIES too low!\");" +kernel = "7.2.2" +confirmed = true +line = 1411 +context = "bd06d31e499a" +note = "Running out of edges. Same ending as every other exhaustion in this file." + +[[references]] +id = "lock-ordering-R39" +path = "kernel/locking/lockdep.c" +anchor = "static noinline void print_circular_bug(struct lock_list *this," +kernel = "7.2.2" +confirmed = true +line = 2005 +context = "8e9080ed3131" +note = "The report. The first thing it does is switch the checker off, and it does that before printing a single line." + +[[references]] +id = "lock-ordering-R40" +path = "kernel/locking/lockdep.c" +anchor = "the existing dependency chain (in reverse order) is" +kernel = "7.2.2" +confirmed = true +line = 1973 +context = "0614bdf2cff7" +note = "Where the numbered chain in the middle of a report is printed, and where the order of the numbers is decided. The printing is what makes #0 the lock being acquired." + +[[references]] +id = "lock-ordering-R41" +path = "kernel/locking/lockdep.c" +anchor = "static inline int debug_locks_off_graph_unlock(void)" +kernel = "7.2.2" +confirmed = true +line = 198 +context = "18a86a3dd252" +note = "Switching off and releasing the graph lock in one step, and returning whether this call was the one that did it. Everything that reports uses this, which is why only the first report of a boot is printed." + +[[references]] +id = "lock-ordering-R42" +path = "kernel/locking/lockdep.c" +anchor = "static void print_lockdep_off(const char *bug_msg)" +kernel = "7.2.2" +confirmed = true +line = 522 +context = "8d8157e1a5f7" +note = "The two lines printed when an internal limit is hit. The second one, turning off the locking correctness validator, is the string to search a log for." + +[[references]] +id = "lock-ordering-R43" +path = "kernel/locking/lockdep_proc.c" +anchor = "seq_printf(m, \" debug_locks:" +kernel = "7.2.2" +confirmed = true +line = 378 +context = "40cab8d2cfe1" +note = "The one line of /proc/lockdep_stats that says whether anything above it is still being maintained." + +[[references]] +id = "lock-ordering-R44" +path = "kernel/locking/lockdep.c" +anchor = "static arch_spinlock_t __lock = (arch_spinlock_t)__ARCH_SPIN_LOCK_UNLOCKED;" +kernel = "7.2.2" +confirmed = true +line = 138 +context = "79c215dfb493" +note = "The one lock the whole graph is protected by, and it is a raw architecture spinlock rather than any of the kernel's own lock types." + +[[references]] +id = "lock-ordering-R45" +path = "kernel/locking/lockdep.c" +anchor = "This is one of the rare exceptions where it's justified" +kernel = "7.2.2" +confirmed = true +line = 134 +context = "4674841bac0d" +note = "Why it has to be a raw architecture spinlock. Any lock the kernel offers would call back into this file, and this file is the callee." + +[[references]] +id = "lock-ordering-R46" +path = "kernel/locking/lockdep.c" +anchor = "static int check_wait_context(struct task_struct *curr, struct held_lock *next)" +kernel = "7.2.2" +confirmed = true +line = 4852 +context = "882d7fdd7bbe" +note = "The second thing this mechanism checks, which is not about order at all. It asks whether a lock that can sleep is being taken inside one that cannot." + +[[references]] +id = "lock-ordering-R47" +path = "kernel/locking/lockdep.c" +anchor = "if (next_outer > curr_inner)" +kernel = "7.2.2" +confirmed = true +line = 4901 +context = "055de92bf5d4" +note = "The comparison. Wait types are ordered, and taking a lock whose wait type is looser than the tightest one already held is the violation." + +[[references]] +id = "lock-ordering-R48" +path = "include/linux/lockdep_types.h" +anchor = "enum lockdep_wait_type {" +kernel = "7.2.2" +confirmed = true +line = 17 +context = "c0e6a22460af" +note = "The ordered list of wait types, from a lock that cannot even be preempted up to one that can sleep. This is the enum the PREEMPT_RT rules are written in." + +[[references]] +id = "lock-ordering-R49" +path = "kernel/locking/lockdep.c" +anchor = "pr_warn(\"[ BUG: Invalid wait context ]\\n\");" +kernel = "7.2.2" +confirmed = true +line = 4815 +context = "7d29704f7ae4" +note = "What a wait context violation prints, and it looks nothing like a lock ordering report, which is worth knowing before searching for the wrong text." + +[[references]] +id = "lock-ordering-R50" +path = "kernel/locking/lockdep.c" +anchor = "pr_warn(\"WARNING: possible circular locking dependency detected\\n\");" +kernel = "7.2.2" +confirmed = true +line = 1962 +context = "9b2358582f6e" +note = "The banner of the report this blueprint is mostly about." + +[[references]] +id = "lock-ordering-R51" +path = "kernel/locking/lockdep.c" +anchor = "pr_warn(\"WARNING: possible recursive locking detected\\n\");" +kernel = "7.2.2" +confirmed = true +line = 3022 +context = "d7ff85731d9a" +note = "The one thread version, where the class is already on this task's own held stack." + +[[references]] +id = "lock-ordering-R52" +path = "kernel/locking/lockdep.c" +anchor = "pr_warn(\"WARNING: %s-safe -> %s-unsafe lock order detected\\n\"," +kernel = "7.2.2" +confirmed = true +line = 2565 +context = "1f41bac4878d" +note = "The interrupt inversion report, which has no cycle in it at all and is the reason the checker records which locks are ever taken with interrupts off." + +[[references]] +id = "lock-ordering-R53" +path = "kernel/locking/lockdep.c" +anchor = "pr_warn(\"WARNING: held lock freed!\\n\");" +kernel = "7.2.2" +confirmed = true +line = 6684 +context = "c1e6a38d339b" +note = "Memory containing a held lock being freed. The allocator calls in to ask, so this fires from kfree rather than from an acquire." + +[[references]] +id = "lock-ordering-R54" +path = "kernel/locking/lockdep.c" +anchor = "pr_warn(\"WARNING: bad unlock balance detected!\\n\");" +kernel = "7.2.2" +confirmed = true +line = 5285 +context = "bb593d3d33c5" +note = "A release with no matching acquire on the held stack, which is usually a lock released on a different thread from the one that took it." + +[[references]] +id = "lock-ordering-R55" +path = "kernel/locking/lockdep.c" +anchor = "pr_warn(\"WARNING: lock held when returning to user space!\\n\");" +kernel = "7.2.2" +confirmed = true +line = 6815 +context = "115f3ed92869" +note = "Checked on the way out of a system call, which catches a leak that no acquire would ever notice." + +[[references]] +id = "lock-ordering-R56" +path = "kernel/locking/lockdep.c" +anchor = "pr_warn(\"WARNING: suspicious RCU usage\\n\");" +kernel = "7.2.2" +confirmed = true +line = 6841 +context = "78f9f1b537a5" +note = "The same held lock bookkeeping used to answer a different question, which is whether the caller is inside an RCU read side section." + +[[references]] +id = "lock-ordering-R57" +path = "kernel/locking/lockdep.c" +anchor = "if (unlikely(curr->lockdep_depth >= MAX_LOCK_DEPTH)) {" +kernel = "7.2.2" +confirmed = true +line = 5251 +context = "6f8cfab68f63" +note = "The held stack is fixed size and per task, and going past the end switches the checker off after dumping every lock currently held." + +[[references]] +id = "lock-ordering-R58" +path = "include/linux/sched.h" +anchor = "define MAX_LOCK_DEPTH" +kernel = "7.2.2" +confirmed = true +line = 1287 +context = "b99e10d6fea6" +note = "Forty eight held locks per task, and the array is inside the task structure, so this is a fixed memory cost on every thread on a kernel built with the checker." + +[[references]] +id = "lock-ordering-R59" +path = "kernel/locking/lockdep.c" +anchor = "print_lockdep_off(\"BUG: MAX_STACK_TRACE_ENTRIES too low!\");" +kernel = "7.2.2" +confirmed = true +line = 581 +context = "85d25968c028" +note = "Running out of room for stack traces. An edge cannot be recorded without one, so this ends checking too." diff --git a/coverage.toml b/coverage.toml index cf5b11d..fff9f7a 100644 --- a/coverage.toml +++ b/coverage.toml @@ -85,11 +85,24 @@ paths = [ "Documentation/locking/", "include/linux/mutex.h", "include/linux/spinlock.h", + "include/linux/lockdep.h", + "include/linux/lockdep_types.h", ] lessons = ["C09"] -blueprints = [] +blueprints = ["lock-ordering"] note = "Lockdep is the way in, because it is the part of locking a reader can watch working." +[[subsystem]] +name = "scheduler" +status = "partial" +paths = [ + "kernel/sched/", + "include/linux/sched.h", +] +lessons = [] +blueprints = ["lock-ordering"] +note = "Nothing here is taught yet. The one thing reaching in is the held lock array the lock checker keeps in every task, which lives in this header rather than in its own." + [[subsystem]] name = "tracing" status = "partial" diff --git a/site/mkdocs.yml b/site/mkdocs.yml index e3a4317..c6d2403 100644 --- a/site/mkdocs.yml +++ b/site/mkdocs.yml @@ -86,5 +86,6 @@ nav: - Blueprints: - All blueprints: blueprints/index.md - Notation: blueprints/NOTATION.md + - "The lock ordering checker": blueprints/lock-ordering.md - "The page fault path": blueprints/page-fault.md - "The buffered write path": blueprints/write-path.md diff --git a/tests/test_bpc.py b/tests/test_bpc.py index ea256cf..8b54f47 100644 --- a/tests/test_bpc.py +++ b/tests/test_bpc.py @@ -399,6 +399,50 @@ def test_naming_no_artefacts_says_nothing_is_observed_rather_than_going_quiet(): assert rendered.source.evidence is False +def test_an_artefact_nothing_traced_says_how_it_was_taken_instead(): + # Before this, everything that was not a function_graph capture rendered as one line reading + # "Tracer `unknown`", which is the generator shrugging at a file whose provenance is written + # down two lines away in its own metadata. + request = bpcgen.Request(pin="v7.2.2", arch="i386", artefacts=("oops/tier0/lockdep-ab-ba",)) + rendered = bpcgen.render(5, request, root=ROOT) + assert "Tracer `unknown`" not in rendered.text + assert "Not a trace. Taken by `insmod /lib/modules/abba.ko`" in rendered.text + + +def test_section_five_draws_a_lock_report_in_the_shape_the_parser_read_it(): + request = bpcgen.Request(pin="v7.2.2", arch="i386", artefacts=("oops/tier0/lockdep-ab-ba",)) + rendered = bpcgen.render(5, request, root=ROOT) + + assert rendered.problems == [] + assert rendered.source.evidence is True + assert "`abba_second` at pid 40" in rendered.text + assert "A cycle of 2: `lock_a` -> `lock_b` -> `lock_a`" in rendered.text + assert "lock(lock_b);" in rendered.text + + +def test_a_before_and_after_pair_is_drawn_as_one_table_with_the_change_in_it(): + """Two readings of one file are only worth anything next to each other. + + Fifty counters in one column and fifty in another, pages apart, is not a specification of what + changed. Which two go together comes off the `pair` key each capture carries, and which is the + before is the order the blueprint lists them in, so nothing here guesses from a filename. + """ + request = bpcgen.Request( + pin="v7.2.2", + arch="i386", + artefacts=("proc/tier0/lockdep-stats-before", "proc/tier0/lockdep-stats-after"), + ) + rendered = bpcgen.render(5, request, root=ROOT) + + assert rendered.problems == [] + assert rendered.text.count("### ") == 1 + assert "lockdep-stats-before.txt` and `corpora/proc/tier0/lockdep-stats-after.txt`" in ( + rendered.text + ) + assert "| `lock_classes` | 391 | 401 | +10 |" in rendered.text + assert "which is the checker off" in rendered.text + + # -- the regeneration pass ---------------------------------------------------------------------- diff --git a/tests/test_coverage.py b/tests/test_coverage.py index 0a37a7c..090327b 100644 --- a/tests/test_coverage.py +++ b/tests/test_coverage.py @@ -301,7 +301,12 @@ def test_every_entry_says_something_about_itself(): def test_show_groups_by_status_and_counts(): printed = coverage.show(ENTRIES) assert "taught (0)" in printed - assert "partial (7)" in printed + # Counted off the ledger rather than typed in, because the number moves every time a blueprint + # reaches into a subsystem nobody had written about yet, and a test that has to be edited for + # that is a test that gets edited without being read. + partial = len([one for one in ENTRIES if one.status == "partial"]) + assert f"partial ({partial})" in printed + assert partial > 0 def test_show_says_when_there_is_nothing_behind_an_entry(): diff --git a/tools/bpcgen.py b/tools/bpcgen.py index 1397962..142c275 100644 --- a/tools/bpcgen.py +++ b/tools/bpcgen.py @@ -321,19 +321,69 @@ def section_5(request: Request, root: Path, btf_path: Path | None) -> Rendered: ) out.append("") + partners, hidden = _pair_up(real, metas) for one, path in real: - out.extend(_artefact_block(one, path, metas[one], root)) + if one in hidden: + continue + out.extend(_artefact_block(one, path, metas[one], root, partners.get(one))) return Rendered("\n".join(out).rstrip() + "\n", source, problems) -def _artefact_block(one: str, path: Path, meta: dict[str, object], root: Path) -> list[str]: +def _pair_up( + real: list[tuple[str, Path]], metas: dict[str, dict] +) -> tuple[dict[str, tuple[str, Path]], set[str]]: + """Which artefacts are two readings of one thing, so they get drawn beside each other. + + A `/proc` file read before something happened and again after it is two files whose numbers + only mean anything next to each other. Fifty counters in one column and fifty in another, + pages apart, is not a specification of what changed, it is homework. + + Which two go together is not worked out from the file names here. A capture that is half of a + pair says so in its own metadata under `pair`, because that is a fact about how it was taken. + Which of the two is the before is the order the blueprint lists them in, so the author decides + it and nothing here guesses from a word in a filename. + """ + by_name = {path.name: (one, path) for one, path in real} + partners: dict[str, tuple[str, Path]] = {} + hidden: set[str] = set() + for one, _path in real: + if one in hidden: + continue + named = str(metas[one].get("pair", "")) + found = by_name.get(named) + if found is None or found[0] == one: + continue + partners[one] = found + hidden.add(found[0]) + return partners, hidden + + +def _artefact_block( + one: str, + path: Path, + meta: dict[str, object], + root: Path, + partner: tuple[str, Path] | None = None, +) -> list[str]: relative = path.relative_to(root) if path.is_relative_to(root) else path - out = [f"### `{relative}`", ""] + heading = f"### `{relative}`" + if partner is not None: + other = partner[1].relative_to(root) if partner[1].is_relative_to(root) else partner[1] + heading = f"### `{relative}` and `{other}`" + out = [heading, ""] - tracer = str(meta.get("tracer", "unknown")) describes = str(meta.get("describes", "not described")) - out.append(f"Tracer `{tracer}`, recording {describes}.") + tracer = str(meta.get("tracer", "")) + if tracer: + out.append(f"Tracer `{tracer}`, recording {describes}.") + else: + # Nothing traced this one. Somebody read a file, or copied what the kernel printed, and + # the command that did it is in the metadata, so say that rather than printing the word + # `unknown` next to a capture whose provenance is written down two lines away. + how = str(meta.get("command", "")).strip() + taken = f"`{how}`" if how else "no command recorded" + out.append(f"Not a trace. Taken by {taken}, recording {describes}.") out.append("") if not meta.get("evidence"): @@ -342,9 +392,31 @@ def _artefact_block(one: str, path: Path, meta: dict[str, object], root: Path) - if tracer == "function_graph": out.extend(_function_graph_block(path)) + return out + + body = READERS.get(_route(path, root)) + if body is not None: + out.extend(body(path, partner[1] if partner else None)) return out +def _route(path: Path, root: Path) -> str: + """Which reader in `kxray` opens this artefact, by the same table the corpus tools use. + + Dispatching on the reader rather than on a new key in the metadata means a parser and the + blueprints that quote it never disagree about what a file is. `kxray/corpus/index.py` already + has to know, because `tools/baseline` accounts every line of every artefact through it, and a + second table here would be a second thing to keep in step. + """ + from kxray.corpus import index + + base = root / CORPORA + try: + return index.route(path, base) or "" + except ValueError: + return "" + + def _function_graph_block(path: Path) -> list[str]: """A capture as a blueprint reads it: the shape of the calls, then the drawing as a table. @@ -397,6 +469,162 @@ def _function_graph_block(path: Path) -> list[str]: return out +def _lockdep_splat_block(path: Path, partner: Path | None = None) -> list[str]: + """A lock ordering report as a blueprint reads it: who, the cycle, and the stacks behind it. + + The report is very nearly the whole of what this mechanism lets you observe. No counter goes up + when a cycle is found, no tracepoint fires, and the function that finds it returns into code + that carries on as if nothing happened. So printing the report back in the shape the parser + understood it is the section, and it doubles as proof that the shape is understood rather than + the words being quoted. + """ + from kxray.lockdep import parse_splat + + splat = parse_splat(path.read_text(encoding="utf-8")) + cycle = " -> ".join(f"`{name}`" for name in splat.cycle) + out = [ + f"`{splat.task}` at pid {splat.pid} on kernel {splat.kernel}, holding " + f"`{splat.holding.name}` and asking for `{splat.acquiring.name}`. " + f"A cycle of {splat.length}: {cycle}.", + "", + "| | Class | Usage | Wait type | Address | Where the report caught it |", + "|---|---|---|---|---|---|", + ] + for role, ref in (("holding", splat.holding), ("acquiring", splat.acquiring)): + out.append( + f"| {role} | `{ref.name}` | `{ref.usage}` | `{ref.wait}` | `{ref.address}` " + f"| `{ref.where}` |" + ) + out += [ + "", + "The addresses are printed by the kernel and are not what the report is about. The checker " + "works in classes, and a class is a line of source rather than an object, so two locks at " + "two addresses initialised on the same line are one class here.", + "", + "The chain, highest number first, which is the order the kernel prints it in. `#0` is the " + "one being taken at the moment the report is printed.", + "", + "| Link | Class | Usage | First recorded at | Frames |", + "|---|---|---|---|---|", + ] + for link in splat.chain: + where = link.stack[0] if link.stack else "no stack recorded" + out.append( + f"| #{link.index} | `{link.name}` | `{link.usage}` | `{where}` | {len(link.stack)} |" + ) + out.append("") + + if splat.scenario.steps: + columns = splat.scenario.columns + out += [ + f"The interleaving the kernel says would deadlock, over {len(columns)} processor(s), " + f"rebuilt here from the parse rather than copied out of the file.", + "", + "```", + ] + width = 20 + out.append("".join(name.ljust(width) for name in columns).rstrip()) + out.append("".join(("-" * len(name)).ljust(width) for name in columns).rstrip()) + for column, step in splat.scenario.steps: + out.append((" " * width * column + step).rstrip()) + out += ["```", ""] + + for link in splat.chain: + if not link.stack: + continue + out += [f"Where `{link.name}` was taken, as `#{link.index}` records it.", "", "```"] + out += list(link.stack) + out += ["```", ""] + return out + + +def _lockdep_stats_block(path: Path, partner: Path | None = None) -> list[str]: + """The counters `/proc/lockdep_stats` carries, and what they were on either side of an event. + + Every counter is in the table and none of them is chosen here, because a generator that picks + the interesting rows is a generator with an opinion, and an opinion in a generated section is + the thing the seal exists to keep out. The rows that moved are the ones a reader will look at, + and the change column makes them findable without anything here deciding which they are. + """ + from kxray.lockdep import account_stats, parse_stats + + def read(one: Path): + text = one.read_text(encoding="utf-8") + return parse_stats(text), account_stats(text) + + stats, lines = read(path) + other, other_lines = read(partner) if partner is not None else (None, None) + + left = path.stem + right = partner.stem if partner is not None else "" + counting = ( + f"{len(stats.values)} counter(s) read, {lines.skipped} line(s) skipped, " + f"{lines.unparsed} line(s) the parser could not read" + ) + if other is not None: + counting += ( + f", and {len(other.values)} counter(s), {other_lines.skipped} skipped, " + f"{other_lines.unparsed} unread in the other" + ) + out = [counting + ".", ""] + + on = "on, so every lock taken from here is checked" + gone = "off, so nothing taken from here is checked and there will be no second report" + out.append(f"`debug_locks` in `{left}` is {stats.debug_locks}, which is the checker {on}.") + if stats.off: + out[-1] = f"`debug_locks` in `{left}` is {stats.debug_locks}, which is the checker {gone}." + if other is not None: + state = gone if other.off else on + out.append(f"In `{right}` it is {other.debug_locks}, which is the checker {state}.") + out.append("") + + later = other.values if other else {} + names = list(stats.values) + [n for n in later if n not in stats.values] + if other is None: + out += ["| Counter | Value | Ceiling |", "|---|---|---|"] + for name in names: + out.append(f"| `{name}` | {stats.values[name]} | {_ceiling(stats, name)} |") + out.append("") + return out + + out += [f"| Counter | `{left}` | `{right}` | Change | Ceiling |", "|---|---|---|---|---|"] + for name in names: + was = stats.values.get(name) + now = other.values.get(name) + moved = "" if was is None or now is None else f"{now - was:+d}" + if moved == "+0": + moved = "none" + out.append( + f"| `{name}` | {'not in this one' if was is None else was} " + f"| {'not in this one' if now is None else now} | {moved} | {_ceiling(stats, name)} |" + ) + out.append("") + return out + + +def _ceiling(stats, name: str) -> str: + """The build time limit on a counter, when the file prints one, as a fraction used. + + Five of the counters come with the maximum the kernel was built for printed beside them, and + those five are the ones that can run out. The rest have no ceiling to report and say so, which + is different from having a ceiling nobody measured. + """ + if name not in stats.maxima: + return "none printed" + return f"{stats.maxima[name]}, {stats.headroom(name) * 100:.1f}% used" + + +# Which of the readers above draws which artefact. The tracer captures are dispatched a few lines +# up on the `tracer` key in their metadata, because that is a fact about how they were taken. +# Everything else in the corpus was taken by reading a file or by copying what the kernel printed, +# and what decides how to draw one of those is which parser understands it, which `kxray` already +# writes down. An artefact whose reader is not in here still gets its heading and its description. +READERS = { + "lockdep-splat": _lockdep_splat_block, + "lockdep-stats": _lockdep_stats_block, +} + + # -- section 7, the interfaces -------------------------------------------------------------------