debug.odin (37935B)
1 /* 2 Debug allocator: finds allocation bugs and reports them so that a reader with no 3 context, human or AI agent, can locate and fix them from the output alone. 4 5 What it detects, and when: 6 7 OVERFLOW / UNDERFLOW guard bytes around every block are checked on free, on 8 resize, at every phase change, at every checkpoint, and at 9 exit. The report says how many bytes past which end were 10 clobbered and what was written there. 11 DOUBLE_FREE freed blocks sit in a quarantine instead of returning to the 12 backing allocator, so a second free is recognised and both 13 free sites are reported. 14 WRITE_AFTER_FREE freed memory is poisoned; when a block leaves quarantine, at 15 a phase change, at a checkpoint, or at exit, the poison is 16 verified. 17 BAD_FREE / BAD_RESIZE the pointer was never handed out by this allocator. 18 SIZE_MISMATCH delete() called with a length that differs from the one 19 allocated, the usual sign of a re-sliced slice. 20 stale after resize a resize always moves the block; the old address is 21 quarantined and poisoned, so a pointer kept across an append 22 surfaces as WRITE_AFTER_FREE or DOUBLE_FREE naming the resize. 23 LEAK blocks still live at exit, grouped by allocation site. 24 25 Every issue is printed in full the moment it is detected, because a corrupted heap 26 may crash the program before any exit report. The exit report indexes the issues, 27 lists leak groups, and prints per-site lifetime statistics: how many allocations a 28 site made, how long they lived (in allocation ticks, so the number is the same from 29 run to run), and whether they died in the phase they were born in. 30 31 Fresh non-zeroed memory is filled with 0xCD, freed memory with 0xDD, and guards with 32 0xFD. Seeing 0xCDCDCDCD or 0xDDDDDDDD in a value tells you which kind of bug you are 33 looking at. 34 35 With -sanitize:address the allocator also poisons its guards and every freed block 36 through base:sanitizer, so an instrumented read or write into them traps at the 37 faulting instruction instead of being noticed at the next check. That closes the gap 38 a pure allocator has: reads past the end and reads after free. On Windows this is the 39 only way ASan sees Odin heap blocks at all, because the default allocator uses 40 HeapAlloc rather than the libc malloc that ASan intercepts. When ASan reports, a 41 death callback appends which block the address belongs to, where it was allocated, 42 and where it was freed, since ASan itself only knows the address is poisoned. 43 44 Usage (debug builds only, compile with -debug so call chains symbolize): 45 46 import "core:debug/trace" 47 import "jm:debug" 48 49 main :: proc() { 50 when ODIN_DEBUG { 51 da: debug.Allocator 52 debug.init(&da, context.allocator) 53 defer debug.destroy(&da) 54 defer debug.report(&da) 55 context.allocator = debug.allocator(&da) 56 context.assertion_failure_proc = trace.assertion_failure_proc 57 } 58 run() 59 } 60 61 debug.set_phase(&da, "scan") // label program stages; each change is a checkpoint 62 debug.check(&da) // verify every live and quarantined block right now 63 64 Compile-time knobs: 65 66 -define:DEBUG_ALLOC_FAIL_FAST=true panic at the first issue, after printing it 67 -define:DEBUG_ALLOC_QUARANTINE=<bytes> freed memory held back (default 16 MiB) 68 -define:DEBUG_ALLOC_GUARD=<bytes> guard size each side of a block (default 16) 69 -define:DEBUG_ALLOC_BACKTRACES=false skip call-chain capture in allocation-heavy programs 70 71 Phase names must outlive the allocator; pass string literals. 72 */ 73 package debug 74 75 import "base:runtime" 76 import "base:sanitizer" 77 import "core:debug/trace" 78 import "core:fmt" 79 import "core:mem" 80 import "core:path/filepath" 81 import "core:slice" 82 import "core:strings" 83 import "core:sync" 84 85 GUARD :: #config(DEBUG_ALLOC_GUARD, 16) 86 QUARANTINE_BYTES :: #config(DEBUG_ALLOC_QUARANTINE, 16 * 1024 * 1024) 87 FAIL_FAST :: #config(DEBUG_ALLOC_FAIL_FAST, false) 88 BACKTRACES :: #config(DEBUG_ALLOC_BACKTRACES, true) 89 90 // True when the program was built with -sanitize:address. 91 ASAN :: .Address in ODIN_SANITIZER_FLAGS 92 93 PATTERN_GUARD :: 0xFD 94 PATTERN_DEAD :: 0xDD 95 PATTERN_FRESH :: 0xCD 96 97 #assert( 98 GUARD >= 8 && (GUARD & (GUARD - 1)) == 0, 99 "DEBUG_ALLOC_GUARD must be a power of two of at least 8", 100 ) 101 102 Issue_Kind :: enum { 103 Overflow, 104 Underflow, 105 Double_Free, 106 Write_After_Free, 107 Bad_Free, 108 Bad_Resize, 109 Size_Mismatch, 110 } 111 112 // Where and when something happened to a block. 113 Site :: struct { 114 loc: runtime.Source_Code_Location, 115 phase: string, 116 seq: u64, // allocation tick at the time 117 bt: trace.Capture_Const, 118 } 119 120 @(private) 121 Live_Block :: struct { 122 raw: rawptr, // start of the front guard 123 total: int, // front + size + GUARD 124 front: int, // front guard size; at least GUARD, grows to satisfy alignment 125 size: int, 126 alignment: int, 127 alloc: Site, 128 resizes: int, 129 last_resize: runtime.Source_Code_Location, 130 } 131 132 @(private) 133 Dead_Block :: struct { 134 raw: rawptr, 135 total: int, 136 front: int, 137 size: int, 138 alloc: Site, 139 free: Site, 140 by_resize: bool, // freed because a resize moved the block 141 } 142 143 Corruption :: struct { 144 offset: int, // first bad byte relative to the start of the user block; negative for underflow 145 count: int, 146 sample: [8]byte, 147 } 148 149 Issue :: struct { 150 id: int, 151 kind: Issue_Kind, 152 ptr: rawptr, 153 size: int, 154 alloc: Site, 155 has_alloc: bool, 156 first_free: Site, 157 has_first_free: bool, 158 by_resize: bool, 159 op: Site, // the operation during which the issue was detected 160 stage: string, // "free", "resize", "phase change", "checkpoint", "quarantine", "exit" 161 corruption: Corruption, 162 given_size: int, // Size_Mismatch 163 } 164 165 @(private) 166 Site_Key :: struct { 167 file: string, 168 line: i32, 169 } 170 171 Site_Stats :: struct { 172 loc: runtime.Source_Code_Location, 173 allocs: int, 174 frees: int, 175 resizes: int, 176 bytes: int, // total bytes ever allocated here 177 live: int, 178 live_bytes: int, 179 peak_live_bytes: int, 180 lifetime_min: u64, 181 lifetime_max: u64, 182 lifetime_sum: u64, 183 cross_phase: int, // frees that happened in a different phase than the allocation 184 last_death: string, // phase of the most recent free 185 } 186 187 Allocator :: struct { 188 backing: mem.Allocator, 189 internals: mem.Allocator, // bookkeeping; never the tracked allocator itself 190 live: map[rawptr]Live_Block, 191 dead: map[rawptr]Dead_Block, 192 dead_queue: [dynamic]rawptr, // FIFO for quarantine eviction 193 dead_head: int, 194 dead_bytes: int, 195 sites: map[Site_Key]Site_Stats, 196 issues: [dynamic]Issue, 197 phases: [dynamic]string, 198 phase: string, 199 seq: u64, 200 total_allocs: int, 201 total_frees: int, 202 live_bytes: int, 203 peak_bytes: int, 204 fail_fast: bool, 205 mutex: sync.Mutex, 206 root: string, // directory of the file that called init; paths print relative to it 207 } 208 209 init :: proc( 210 da: ^Allocator, 211 backing: mem.Allocator, 212 internals := context.allocator, 213 loc := #caller_location, 214 ) { 215 da.backing = backing 216 da.internals = internals 217 da.live.allocator = internals 218 da.dead.allocator = internals 219 da.dead_queue.allocator = internals 220 da.sites.allocator = internals 221 da.issues.allocator = internals 222 da.phases.allocator = internals 223 da.phase = "startup" 224 append(&da.phases, da.phase) 225 da.fail_fast = FAIL_FAST 226 da.root = normalize(filepath.dir(loc.file_path), internals) 227 when ASAN { 228 asan_owner = da 229 sanitizer.address_set_death_callback(asan_death) 230 } 231 } 232 233 // Release everything, including blocks the program never freed. Call report first. 234 destroy :: proc(da: ^Allocator) { 235 sync.guard(&da.mutex) 236 for _, l in da.live { 237 backing_free(da, l.raw, l.total) 238 } 239 for _, d in da.dead { 240 backing_free(da, d.raw, d.total) 241 } 242 when ASAN { 243 if asan_owner == da { 244 asan_owner = nil 245 } 246 } 247 delete(da.live) 248 delete(da.dead) 249 delete(da.dead_queue) 250 delete(da.sites) 251 delete(da.issues) 252 delete(da.phases) 253 delete(da.root, da.internals) 254 da^ = {} 255 } 256 257 allocator :: proc(da: ^Allocator) -> mem.Allocator { 258 return mem.Allocator{procedure = allocator_proc, data = da} 259 } 260 261 // Mark the start of a program stage. Every live and quarantined block is verified 262 // first, so corruption is pinned to the stage it happened in. Pass a string literal. 263 set_phase :: proc(da: ^Allocator, name: string, loc := #caller_location) { 264 context.allocator = da.internals 265 sync.guard(&da.mutex) 266 verify_all(da, "phase change", loc) 267 da.phase = name 268 append(&da.phases, name) 269 } 270 271 // Verify every live and quarantined block right now. Sprinkle calls to narrow down 272 // where a corruption happens. 273 check :: proc(da: ^Allocator, loc := #caller_location) { 274 context.allocator = da.internals 275 sync.guard(&da.mutex) 276 verify_all(da, "checkpoint", loc) 277 } 278 279 issue_count :: proc(da: ^Allocator) -> int { 280 sync.guard(&da.mutex) 281 return len(da.issues) 282 } 283 284 // ---- allocator ------------------------------------------------------------------ 285 286 allocator_proc :: proc( 287 data: rawptr, 288 mode: mem.Allocator_Mode, 289 size, alignment: int, 290 old_memory: rawptr, 291 old_size: int, 292 loc := #caller_location, 293 ) -> ( 294 result: []byte, 295 err: mem.Allocator_Error, 296 ) { 297 da := (^Allocator)(data) 298 // Anything this allocator does internally must not come back through itself. 299 context.allocator = da.internals 300 sync.guard(&da.mutex) 301 302 switch mode { 303 case .Alloc, .Alloc_Non_Zeroed: 304 return do_alloc(da, size, alignment, mode == .Alloc, loc) 305 case .Free: 306 return nil, do_free(da, old_memory, old_size, loc) 307 case .Free_All: 308 do_free_all(da, loc) 309 return nil, nil 310 case .Resize, .Resize_Non_Zeroed: 311 return do_resize(da, old_memory, old_size, size, alignment, mode == .Resize, loc) 312 case .Query_Features: 313 if set := (^mem.Allocator_Mode_Set)(old_memory); set != nil { 314 set^ = { 315 .Alloc, 316 .Alloc_Non_Zeroed, 317 .Free, 318 .Free_All, 319 .Resize, 320 .Resize_Non_Zeroed, 321 .Query_Features, 322 } 323 } 324 return nil, nil 325 case .Query_Info: 326 return nil, .Mode_Not_Implemented 327 } 328 return nil, .Mode_Not_Implemented 329 } 330 331 // Obtain a guarded block from the backing allocator. No bookkeeping. 332 @(private) 333 raw_alloc :: proc( 334 da: ^Allocator, 335 size, alignment: int, 336 zeroed: bool, 337 loc: runtime.Source_Code_Location, 338 ) -> ( 339 l: Live_Block, 340 user: []byte, 341 err: mem.Allocator_Error, 342 ) { 343 if size < 0 { 344 return {}, nil, .Invalid_Argument 345 } 346 align := max(alignment, 1) 347 // The front guard doubles as alignment padding: the backing block is aligned to 348 // max(align, GUARD) and the user block starts `front` bytes in, where `front` is a 349 // multiple of `align`. 350 front := max(GUARD, align) 351 total := front + size + GUARD 352 raw, alloc_err := mem.alloc_bytes_non_zeroed(total, max(align, GUARD), da.backing, loc) 353 if alloc_err != nil { 354 return {}, nil, alloc_err 355 } 356 mem.set(raw_data(raw), PATTERN_GUARD, front) 357 user = raw[front:front + size] 358 mem.set(raw_data(raw[front + size:]), PATTERN_GUARD, GUARD) 359 if zeroed { 360 mem.zero_slice(user) 361 } else { 362 mem.set(raw_data(user), PATTERN_FRESH, size) 363 } 364 sanitizer.address_poison(raw[:front]) 365 sanitizer.address_poison(raw[front + size:]) 366 l = Live_Block { 367 raw = raw_data(raw), 368 total = total, 369 front = front, 370 size = size, 371 alignment = align, 372 } 373 return l, user, nil 374 } 375 376 @(private) 377 do_alloc :: proc( 378 da: ^Allocator, 379 size, alignment: int, 380 zeroed: bool, 381 loc: runtime.Source_Code_Location, 382 ) -> ( 383 []byte, 384 mem.Allocator_Error, 385 ) { 386 l, user, alloc_err := raw_alloc(da, size, alignment, zeroed, loc) 387 if alloc_err != nil { 388 return nil, alloc_err 389 } 390 da.seq += 1 391 l.alloc = make_site(da, loc) 392 da.live[raw_data(user)] = l 393 da.total_allocs += 1 394 da.live_bytes += size 395 da.peak_bytes = max(da.peak_bytes, da.live_bytes) 396 397 st := site_stats(da, loc) 398 st.allocs += 1 399 st.bytes += size 400 st.live += 1 401 st.live_bytes += size 402 st.peak_live_bytes = max(st.peak_live_bytes, st.live_bytes) 403 return user, nil 404 } 405 406 @(private) 407 do_free :: proc( 408 da: ^Allocator, 409 ptr: rawptr, 410 given_size: int, 411 loc: runtime.Source_Code_Location, 412 ) -> mem.Allocator_Error { 413 if ptr == nil { 414 return nil 415 } 416 l, ok := da.live[ptr] 417 if !ok { 418 op := make_site(da, loc) 419 if d, dead_ok := da.dead[ptr]; dead_ok { 420 raise( 421 da, 422 Issue { 423 kind = .Double_Free, 424 ptr = ptr, 425 size = d.size, 426 alloc = d.alloc, 427 has_alloc = true, 428 first_free = d.free, 429 has_first_free = true, 430 by_resize = d.by_resize, 431 op = op, 432 stage = "free", 433 }, 434 ) 435 } else { 436 raise(da, Issue{kind = .Bad_Free, ptr = ptr, op = op, stage = "free"}) 437 } 438 return .Invalid_Pointer 439 } 440 if given_size != 0 && given_size != l.size { 441 raise( 442 da, 443 Issue { 444 kind = .Size_Mismatch, 445 ptr = ptr, 446 size = l.size, 447 given_size = given_size, 448 alloc = l.alloc, 449 has_alloc = true, 450 op = make_site(da, loc), 451 stage = "free", 452 }, 453 ) 454 } 455 verify_guards(da, l, "free", loc) 456 retire(da, l, ptr, loc, false) 457 return nil 458 } 459 460 @(private) 461 do_free_all :: proc(da: ^Allocator, loc: runtime.Source_Code_Location) { 462 for _, l in da.live { 463 verify_guards(da, l, "free_all", loc) 464 st := site_stats(da, l.alloc.loc) 465 st.frees += 1 466 st.live -= 1 467 st.live_bytes -= l.size 468 backing_free(da, l.raw, l.total) 469 } 470 da.total_frees += len(da.live) 471 da.live_bytes = 0 472 clear(&da.live) 473 flush_quarantine(da, "free_all", loc) 474 } 475 476 @(private) 477 do_resize :: proc( 478 da: ^Allocator, 479 ptr: rawptr, 480 old_size, size, alignment: int, 481 zeroed: bool, 482 loc: runtime.Source_Code_Location, 483 ) -> ( 484 []byte, 485 mem.Allocator_Error, 486 ) { 487 if ptr == nil { 488 return do_alloc(da, size, alignment, zeroed, loc) 489 } 490 if size == 0 { 491 return nil, do_free(da, ptr, old_size, loc) 492 } 493 l, ok := da.live[ptr] 494 if !ok { 495 op := make_site(da, loc) 496 if d, dead_ok := da.dead[ptr]; dead_ok { 497 raise( 498 da, 499 Issue { 500 kind = .Double_Free, 501 ptr = ptr, 502 size = d.size, 503 alloc = d.alloc, 504 has_alloc = true, 505 first_free = d.free, 506 has_first_free = true, 507 by_resize = d.by_resize, 508 op = op, 509 stage = "resize", 510 }, 511 ) 512 } else { 513 raise(da, Issue{kind = .Bad_Resize, ptr = ptr, op = op, stage = "resize"}) 514 } 515 return nil, .Invalid_Pointer 516 } 517 if old_size != 0 && old_size != l.size { 518 raise( 519 da, 520 Issue { 521 kind = .Size_Mismatch, 522 ptr = ptr, 523 size = l.size, 524 given_size = old_size, 525 alloc = l.alloc, 526 has_alloc = true, 527 op = make_site(da, loc), 528 stage = "resize", 529 }, 530 ) 531 } 532 verify_guards(da, l, "resize", loc) 533 534 // Always move. A stale pointer into the old block then shows up as a 535 // write-after-free or double-free that names this resize. 536 nl, user, alloc_err := raw_alloc(da, size, max(alignment, l.alignment), false, loc) 537 if alloc_err != nil { 538 return nil, alloc_err 539 } 540 copy(user, mem.byte_slice(ptr, min(size, l.size))) 541 if size > l.size { 542 tail := user[l.size:] 543 if zeroed { 544 mem.zero_slice(tail) 545 } else { 546 mem.set(raw_data(tail), PATTERN_FRESH, len(tail)) 547 } 548 } 549 // The new block inherits the identity of the original allocation so leak and 550 // lifetime reports point at where the object was created, not where it last grew. 551 nl.alloc = l.alloc 552 nl.resizes = l.resizes + 1 553 nl.last_resize = loc 554 da.live[raw_data(user)] = nl 555 da.live_bytes += size 556 da.peak_bytes = max(da.peak_bytes, da.live_bytes) 557 orig := site_stats(da, l.alloc.loc) 558 orig.resizes += 1 559 orig.bytes += size - l.size 560 orig.live_bytes += size 561 orig.peak_live_bytes = max(orig.peak_live_bytes, orig.live_bytes) 562 563 retire(da, l, ptr, loc, true) 564 return user, nil 565 } 566 567 // Move a live block into quarantine: poison it, record when and where it died. 568 @(private) 569 retire :: proc( 570 da: ^Allocator, 571 l: Live_Block, 572 ptr: rawptr, 573 loc: runtime.Source_Code_Location, 574 by_resize: bool, 575 ) { 576 mem.set(ptr, PATTERN_DEAD, l.size) 577 // From the user block to the end of the backing allocation is now off limits. 578 sanitizer.address_poison(ptr, l.total - l.front) 579 delete_key(&da.live, ptr) 580 da.live_bytes -= l.size 581 free_site := make_site(da, loc) 582 583 st := site_stats(da, l.alloc.loc) 584 st.live_bytes -= l.size 585 if !by_resize { 586 da.total_frees += 1 587 st.frees += 1 588 st.live -= 1 589 age := da.seq - l.alloc.seq 590 if st.frees == 1 || age < st.lifetime_min { 591 st.lifetime_min = age 592 } 593 st.lifetime_max = max(st.lifetime_max, age) 594 st.lifetime_sum += age 595 if da.phase != l.alloc.phase { 596 st.cross_phase += 1 597 } 598 st.last_death = da.phase 599 } 600 601 da.dead[ptr] = Dead_Block { 602 raw = l.raw, 603 total = l.total, 604 front = l.front, 605 size = l.size, 606 alloc = l.alloc, 607 free = free_site, 608 by_resize = by_resize, 609 } 610 append(&da.dead_queue, ptr) 611 da.dead_bytes += l.total 612 613 for da.dead_bytes > QUARANTINE_BYTES && da.dead_head < len(da.dead_queue) { 614 evict_oldest(da, "quarantine", loc) 615 } 616 // Compact the queue once the consumed prefix dominates. 617 if da.dead_head > 1024 && da.dead_head * 2 > len(da.dead_queue) { 618 n := copy(da.dead_queue[:], da.dead_queue[da.dead_head:]) 619 resize(&da.dead_queue, n) 620 da.dead_head = 0 621 } 622 } 623 624 @(private) 625 evict_oldest :: proc(da: ^Allocator, stage: string, loc: runtime.Source_Code_Location) { 626 ptr := da.dead_queue[da.dead_head] 627 da.dead_head += 1 628 d, ok := da.dead[ptr] 629 if !ok { 630 return 631 } 632 verify_poison(da, d, ptr, stage, loc) 633 backing_free(da, d.raw, d.total) 634 da.dead_bytes -= d.total 635 delete_key(&da.dead, ptr) 636 } 637 638 @(private) 639 flush_quarantine :: proc(da: ^Allocator, stage: string, loc: runtime.Source_Code_Location) { 640 for da.dead_head < len(da.dead_queue) { 641 evict_oldest(da, stage, loc) 642 } 643 clear(&da.dead_queue) 644 da.dead_head = 0 645 da.dead_bytes = 0 646 } 647 648 // The backing allocator will hand this memory out again to code that is not ours, 649 // so every trace of poison must be gone before it goes back. 650 @(private) 651 backing_free :: proc(da: ^Allocator, raw: rawptr, total: int) { 652 sanitizer.address_unpoison(raw, total) 653 da.backing.procedure(da.backing.data, .Free, 0, 0, raw, total) 654 } 655 656 // Overwrite a poisoned region without tripping the sanitizer, then re-poison it. 657 @(private) 658 refill :: proc(ptr: rawptr, len: int, pattern: byte) { 659 sanitizer.address_unpoison(ptr, len) 660 mem.set(ptr, pattern, len) 661 sanitizer.address_poison(ptr, len) 662 } 663 664 // ---- verification --------------------------------------------------------------- 665 666 @(private) 667 verify_all :: proc(da: ^Allocator, stage: string, loc: runtime.Source_Code_Location) { 668 for _, l in da.live { 669 verify_guards(da, l, stage, loc) 670 } 671 for ptr, d in da.dead { 672 verify_poison(da, d, ptr, stage, loc) 673 } 674 } 675 676 @(private) 677 verify_guards :: proc(da: ^Allocator, l: Live_Block, stage: string, loc: runtime.Source_Code_Location) { 678 block := mem.byte_slice(l.raw, l.total) 679 user_ptr := rawptr(uintptr(l.raw) + uintptr(l.front)) 680 if c, bad := scan(block[:l.front], PATTERN_GUARD); bad { 681 c.offset -= l.front 682 raise( 683 da, 684 Issue { 685 kind = .Underflow, 686 ptr = user_ptr, 687 size = l.size, 688 alloc = l.alloc, 689 has_alloc = true, 690 op = make_site(da, loc), 691 stage = stage, 692 corruption = c, 693 }, 694 ) 695 refill(l.raw, l.front, PATTERN_GUARD) // report each corruption once 696 } 697 if c, bad := scan(block[l.front + l.size:], PATTERN_GUARD); bad { 698 c.offset += l.size 699 raise( 700 da, 701 Issue { 702 kind = .Overflow, 703 ptr = user_ptr, 704 size = l.size, 705 alloc = l.alloc, 706 has_alloc = true, 707 op = make_site(da, loc), 708 stage = stage, 709 corruption = c, 710 }, 711 ) 712 refill(raw_data(block[l.front + l.size:]), GUARD, PATTERN_GUARD) 713 } 714 } 715 716 @(private) 717 verify_poison :: proc( 718 da: ^Allocator, 719 d: Dead_Block, 720 ptr: rawptr, 721 stage: string, 722 loc: runtime.Source_Code_Location, 723 ) { 724 if c, bad := scan(mem.byte_slice(ptr, d.size), PATTERN_DEAD); bad { 725 raise( 726 da, 727 Issue { 728 kind = .Write_After_Free, 729 ptr = ptr, 730 size = d.size, 731 alloc = d.alloc, 732 has_alloc = true, 733 first_free = d.free, 734 has_first_free = true, 735 by_resize = d.by_resize, 736 op = make_site(da, loc), 737 stage = stage, 738 corruption = c, 739 }, 740 ) 741 refill(ptr, d.size, PATTERN_DEAD) 742 } 743 } 744 745 // Find bytes that differ from `pattern`. Returns the first offset, how many differ, 746 // and up to eight of the offending values. 747 @(private, no_sanitize_address) 748 scan :: proc(b: []byte, pattern: byte) -> (c: Corruption, bad: bool) { 749 first := -1 750 for x, i in b { 751 if x == pattern { 752 continue 753 } 754 if first < 0 { 755 first = i 756 } 757 if c.count < len(c.sample) { 758 c.sample[c.count] = x 759 } 760 c.count += 1 761 } 762 if first < 0 { 763 return {}, false 764 } 765 c.offset = first 766 return c, true 767 } 768 769 // ---- bookkeeping helpers -------------------------------------------------------- 770 771 @(private) 772 make_site :: proc(da: ^Allocator, loc: runtime.Source_Code_Location) -> Site { 773 s := Site { 774 loc = loc, 775 phase = da.phase, 776 seq = da.seq, 777 } 778 when BACKTRACES { 779 s.bt = trace.capture() 780 } 781 return s 782 } 783 784 @(private) 785 site_stats :: proc(da: ^Allocator, loc: runtime.Source_Code_Location) -> ^Site_Stats { 786 key := Site_Key { 787 file = loc.file_path, 788 line = loc.line, 789 } 790 st, ok := &da.sites[key] 791 if !ok { 792 da.sites[key] = Site_Stats { 793 loc = loc, 794 } 795 st = &da.sites[key] 796 } 797 return st 798 } 799 800 @(private) 801 raise :: proc(da: ^Allocator, issue: Issue) { 802 iss := issue 803 iss.id = len(da.issues) + 1 804 append(&da.issues, iss) 805 print_issue(da, iss) 806 if da.fail_fast { 807 panic("debug allocator: allocation bug detected, see the issue printed above") 808 } 809 } 810 811 // ---- address sanitizer ---------------------------------------------------------- 812 813 // The allocator whose blocks the death callback describes. One debug allocator per 814 // process is the intended use. 815 @(private) 816 asan_owner: ^Allocator 817 818 /* 819 Runs while ASan is printing its report, before the process aborts. ASan knows the 820 address is poisoned but not what it was; this adds the block, its allocation site, 821 and its free site, which is what the reader needs to fix the bug. 822 */ 823 @(private) 824 asan_death :: proc "c" ( 825 pc, bp, sp, addr_unused: rawptr, 826 is_write_unused: i32, 827 access_size_unused: uint, 828 ) { 829 // The runtime invokes this without arguments; the parameters hold whatever was in 830 // the registers. The report accessors are the reliable source. 831 _, _, _, _, _, _ = pc, bp, sp, addr_unused, is_write_unused, access_size_unused 832 context = runtime.default_context() 833 da := asan_owner 834 if da == nil || !sanitizer.address_report_present() { 835 return 836 } 837 addr := sanitizer.address_get_report_address() 838 is_write := sanitizer.address_get_report_access_type() == .write 839 access_size := sanitizer.address_get_report_access_size() 840 context.allocator = da.internals 841 // The fault may have happened inside the allocator with the mutex held; describing 842 // the address is worth more than strict locking in a process that is about to die. 843 locked := sync.mutex_try_lock(&da.mutex) 844 defer if locked { 845 sync.mutex_unlock(&da.mutex) 846 } 847 848 fmt.eprintln() 849 fmt.eprintfln( 850 "== debug allocator: about the faulting address %p (%s of %d byte(s)) ==", 851 addr, 852 "write" if is_write else "read", 853 access_size, 854 ) 855 a := uintptr(addr) 856 for user, l in da.live { 857 lo := uintptr(l.raw) 858 if a < lo || a >= lo + uintptr(l.total) { 859 continue 860 } 861 describe_offset(a, uintptr(user), l.size) 862 fmt.eprintln(" the block is still live") 863 print_site(da, "allocated ", l.alloc) 864 if l.resizes > 0 { 865 fmt.eprintfln( 866 " resized %d time(s), last at %s:%d", 867 l.resizes, 868 display_path(da, l.last_resize.file_path), 869 l.last_resize.line, 870 ) 871 } 872 fmt.eprintln( 873 " meaning an access outside a live block's bounds. Check the index or length used for this access against the allocation size above.", 874 ) 875 return 876 } 877 for user, d in da.dead { 878 lo := uintptr(d.raw) 879 if a < lo || a >= lo + uintptr(d.total) { 880 continue 881 } 882 describe_offset(a, uintptr(user), d.size) 883 print_site(da, "allocated ", d.alloc) 884 print_site(da, "moved by " if d.by_resize else "freed ", d.free) 885 if d.by_resize { 886 fmt.eprintln( 887 " meaning the block was moved by a resize and this access used the old address. A pointer or slice into a dynamic array was kept across an append; re-fetch it after growing.", 888 ) 889 } else { 890 fmt.eprintln( 891 " meaning use after free. The accessor holds a dangling pointer to a block freed at the site above.", 892 ) 893 } 894 return 895 } 896 fmt.eprintln( 897 " not inside any block this allocator has handed out or is holding in quarantine", 898 ) 899 fmt.eprintfln(" phase=%s tick=%d issues so far=%d", da.phase, da.seq, len(da.issues)) 900 } 901 902 @(private) 903 describe_offset :: proc(a, user: uintptr, size: int) { 904 switch { 905 case a < user: 906 fmt.eprintfln(" %d byte(s) before the start of a %d-byte block", user - a, size) 907 case a >= user + uintptr(size): 908 fmt.eprintfln( 909 " %d byte(s) past the end of a %d-byte block", 910 a - (user + uintptr(size)), 911 size, 912 ) 913 case: 914 fmt.eprintfln(" %d byte(s) into a %d-byte block", a - user, size) 915 } 916 } 917 918 // ---- reporting ------------------------------------------------------------------ 919 920 @(private) 921 kind_name :: proc(k: Issue_Kind) -> string { 922 switch k { 923 case .Overflow: 924 return "OVERFLOW" 925 case .Underflow: 926 return "UNDERFLOW" 927 case .Double_Free: 928 return "DOUBLE_FREE" 929 case .Write_After_Free: 930 return "WRITE_AFTER_FREE" 931 case .Bad_Free: 932 return "BAD_FREE" 933 case .Bad_Resize: 934 return "BAD_RESIZE" 935 case .Size_Mismatch: 936 return "SIZE_MISMATCH" 937 } 938 return "UNKNOWN" 939 } 940 941 @(private) 942 print_issue :: proc(da: ^Allocator, iss: Issue) { 943 fmt.eprintfln( 944 "!! ALLOCATION ISSUE #%d: %s ptr=%p size=%d b detected during %s", 945 iss.id, 946 kind_name(iss.kind), 947 iss.ptr, 948 iss.size, 949 iss.stage, 950 ) 951 if iss.has_alloc { 952 print_site(da, "allocated ", iss.alloc) 953 } 954 if iss.has_first_free { 955 label := "moved by " if iss.by_resize else "freed " 956 print_site(da, label, iss.first_free) 957 } 958 op_label := "detected " 959 #partial switch iss.kind { 960 case .Double_Free, .Bad_Free: 961 op_label = "this free " 962 case .Bad_Resize: 963 op_label = "this resize" 964 case .Size_Mismatch: 965 op_label = "freed at " 966 } 967 print_site(da, op_label, iss.op) 968 969 c := iss.corruption 970 switch iss.kind { 971 case .Overflow: 972 fmt.eprintfln( 973 " damage %d byte(s) written starting %d byte(s) past the end of the block: %s (guard bytes should read %02x)", 974 c.count, 975 c.offset - iss.size, 976 hex(c), 977 PATTERN_GUARD, 978 ) 979 fmt.eprintln( 980 " meaning something wrote beyond the allocation's last byte between allocation and this check. Look for an off-by-one in a loop bound or a length computed from the wrong variable.", 981 ) 982 case .Underflow: 983 fmt.eprintfln( 984 " damage %d byte(s) written starting %d byte(s) before the block: %s (guard bytes should read %02x)", 985 c.count, 986 -c.offset, 987 hex(c), 988 PATTERN_GUARD, 989 ) 990 fmt.eprintln( 991 " meaning something wrote before the allocation's first byte. Look for a negative index or pointer arithmetic that steps back past the start.", 992 ) 993 case .Double_Free: 994 if iss.by_resize { 995 fmt.eprintln( 996 " meaning this address was invalidated when the block was resized (see 'moved by' above); the caller kept the old address across an append or resize. Re-fetch the pointer after growing the container, or reserve capacity up front.", 997 ) 998 } else { 999 fmt.eprintln( 1000 " meaning the block was already freed. Remove one of the two frees, or set the pointer to nil after the first so a second free is a no-op.", 1001 ) 1002 } 1003 case .Write_After_Free: 1004 fmt.eprintfln( 1005 " damage %d byte(s) written at offset %d after the block was freed: %s (freed memory should read %02x)", 1006 c.count, 1007 c.offset, 1008 hex(c), 1009 PATTERN_DEAD, 1010 ) 1011 if iss.by_resize { 1012 fmt.eprintln( 1013 " meaning the block was moved by a resize (see 'moved by' above) and the old address was written afterwards. A pointer or slice into a dynamic array was kept across an append.", 1014 ) 1015 } else { 1016 fmt.eprintln( 1017 " meaning memory was written after it was freed. The writer holds a dangling pointer; find who still references this block after the free above.", 1018 ) 1019 } 1020 case .Bad_Free, .Bad_Resize: 1021 fmt.eprintln( 1022 " meaning this pointer was never returned by this allocator. Common causes: freeing memory from an arena or temp allocator with the context allocator, freeing a pointer into the middle of a block, or freeing an uninitialised pointer.", 1023 ) 1024 case .Size_Mismatch: 1025 fmt.eprintfln( 1026 " damage freed with size %d b but %d b were allocated", 1027 iss.given_size, 1028 iss.size, 1029 ) 1030 fmt.eprintln( 1031 " meaning delete() was given a slice whose length differs from the allocation, usually a re-sliced or truncated slice. Delete the original slice, or keep the original length.", 1032 ) 1033 } 1034 } 1035 1036 @(private) 1037 hex :: proc(c: Corruption) -> string { 1038 sb := strings.builder_make(context.temp_allocator) 1039 for i in 0 ..< min(c.count, len(c.sample)) { 1040 if i > 0 { 1041 strings.write_byte(&sb, ' ') 1042 } 1043 fmt.sbprintf(&sb, "%02x", c.sample[i]) 1044 } 1045 if c.count > len(c.sample) { 1046 strings.write_string(&sb, " ...") 1047 } 1048 return strings.to_string(sb) 1049 } 1050 1051 @(private) 1052 print_site :: proc(da: ^Allocator, label: string, s: Site) { 1053 fmt.eprintfln( 1054 " %s %s:%d proc=%s phase=%s tick=%d", 1055 label, 1056 display_path(da, s.loc.file_path), 1057 s.loc.line, 1058 s.loc.procedure, 1059 s.phase, 1060 s.seq, 1061 ) 1062 when BACKTRACES { 1063 print_frames(da, s.bt, 8) 1064 } 1065 } 1066 1067 @(private) 1068 Leak_Group :: struct { 1069 loc: runtime.Source_Code_Location, 1070 phase: string, 1071 count: int, 1072 bytes: int, 1073 min_size: int, 1074 max_size: int, 1075 first_seq: u64, 1076 example: trace.Capture_Const, 1077 resizes: int, 1078 last_resize: runtime.Source_Code_Location, 1079 } 1080 1081 /* 1082 Print the exit report to stderr. Safe to call via defer after swapping 1083 context.allocator to this allocator. Verifies every block first, so corruption that 1084 happened after the last free or phase change is still caught. 1085 */ 1086 report :: proc( 1087 da: ^Allocator, 1088 max_groups := 20, 1089 max_sites := 15, 1090 max_frames := 8, 1091 loc := #caller_location, 1092 ) { 1093 context.allocator = da.internals 1094 sync.guard(&da.mutex) 1095 verify_all(da, "exit", loc) 1096 1097 leaks := len(da.live) 1098 fmt.eprintln("== debug allocator report ==") 1099 if len(da.issues) == 0 && leaks == 0 { 1100 fmt.eprintln("verdict: clean (no issues, no leaks)") 1101 } else { 1102 fmt.eprintfln( 1103 "verdict: %d issue(s), %d leaked block(s) totalling %d b", 1104 len(da.issues), 1105 leaks, 1106 da.live_bytes, 1107 ) 1108 } 1109 fmt.eprintfln( 1110 "allocs=%d frees=%d live=%d live_bytes=%d peak_bytes=%d quarantined=%d issues=%d", 1111 da.total_allocs, 1112 da.total_frees, 1113 leaks, 1114 da.live_bytes, 1115 da.peak_bytes, 1116 len(da.dead), 1117 len(da.issues), 1118 ) 1119 fmt.eprint("phases=") 1120 for p, i in da.phases { 1121 if i > 0 { 1122 fmt.eprint(" > ") 1123 } 1124 fmt.eprint(p) 1125 } 1126 fmt.eprintln() 1127 1128 if len(da.issues) > 0 { 1129 fmt.eprintfln( 1130 "-- issues (%d, each printed in full where it was detected) --", 1131 len(da.issues), 1132 ) 1133 for iss in da.issues { 1134 fmt.eprintf("#%d %s ptr=%p", iss.id, kind_name(iss.kind), iss.ptr) 1135 if iss.has_alloc { 1136 fmt.eprintf( 1137 " alloc %s:%d", 1138 display_path(da, iss.alloc.loc.file_path), 1139 iss.alloc.loc.line, 1140 ) 1141 } 1142 if iss.has_first_free { 1143 fmt.eprintf( 1144 " %s %s:%d", 1145 "resize" if iss.by_resize else "free", 1146 display_path(da, iss.first_free.loc.file_path), 1147 iss.first_free.loc.line, 1148 ) 1149 } 1150 fmt.eprintfln( 1151 " detected %s:%d (%s)", 1152 display_path(da, iss.op.loc.file_path), 1153 iss.op.loc.line, 1154 iss.stage, 1155 ) 1156 } 1157 } 1158 1159 if leaks > 0 { 1160 print_leaks(da, max_groups, max_frames) 1161 } 1162 print_sites(da, max_sites) 1163 } 1164 1165 @(private) 1166 print_leaks :: proc(da: ^Allocator, max_groups, max_frames: int) { 1167 groups := make(map[Site_Key]Leak_Group, da.internals) 1168 defer delete(groups) 1169 for _, l in da.live { 1170 key := Site_Key { 1171 file = l.alloc.loc.file_path, 1172 line = l.alloc.loc.line, 1173 } 1174 g, exists := &groups[key] 1175 if !exists { 1176 groups[key] = Leak_Group { 1177 loc = l.alloc.loc, 1178 phase = l.alloc.phase, 1179 min_size = l.size, 1180 max_size = l.size, 1181 first_seq = l.alloc.seq, 1182 example = l.alloc.bt, 1183 } 1184 g = &groups[key] 1185 } 1186 g.count += 1 1187 g.bytes += l.size 1188 g.min_size = min(g.min_size, l.size) 1189 g.max_size = max(g.max_size, l.size) 1190 g.resizes += l.resizes 1191 if l.resizes > 0 { 1192 g.last_resize = l.last_resize 1193 } 1194 if l.alloc.seq < g.first_seq { 1195 g.first_seq = l.alloc.seq 1196 g.example = l.alloc.bt 1197 g.phase = l.alloc.phase 1198 } 1199 } 1200 1201 list := make([dynamic]Leak_Group, 0, len(groups), da.internals) 1202 defer delete(list) 1203 for _, g in groups { 1204 append(&list, g) 1205 } 1206 slice.sort_by(list[:], proc(a, b: Leak_Group) -> bool { 1207 return a.bytes > b.bytes 1208 }) 1209 1210 fmt.eprintfln("-- leaks (%d group(s), %d block(s)) --", len(list), len(da.live)) 1211 for g, i in list { 1212 if i >= max_groups { 1213 fmt.eprintfln( 1214 "... %d more leak groups omitted (raise max_groups to see them)", 1215 len(list) - i, 1216 ) 1217 break 1218 } 1219 if g.min_size == g.max_size { 1220 fmt.eprintf("LEAK %d x %d b = %d b", g.count, g.min_size, g.bytes) 1221 } else { 1222 fmt.eprintf( 1223 "LEAK %d block(s), %d b total (sizes %d..%d b)", 1224 g.count, 1225 g.bytes, 1226 g.min_size, 1227 g.max_size, 1228 ) 1229 } 1230 fmt.eprintf( 1231 " phase=%s site=%s:%d proc=%s first_tick=%d", 1232 g.phase, 1233 display_path(da, g.loc.file_path), 1234 g.loc.line, 1235 g.loc.procedure, 1236 g.first_seq, 1237 ) 1238 if g.resizes > 0 { 1239 fmt.eprintf( 1240 " resized=%d (last at %s:%d)", 1241 g.resizes, 1242 display_path(da, g.last_resize.file_path), 1243 g.last_resize.line, 1244 ) 1245 } 1246 fmt.eprintln() 1247 when BACKTRACES { 1248 print_frames(da, g.example, max_frames) 1249 } 1250 } 1251 } 1252 1253 @(private) 1254 print_sites :: proc(da: ^Allocator, max_sites: int) { 1255 list := make([dynamic]Site_Stats, 0, len(da.sites), da.internals) 1256 defer delete(list) 1257 for _, st in da.sites { 1258 if st.allocs == 0 && st.resizes == 0 { 1259 continue 1260 } 1261 append(&list, st) 1262 } 1263 if len(list) == 0 { 1264 return 1265 } 1266 slice.sort_by(list[:], proc(a, b: Site_Stats) -> bool { 1267 return a.bytes > b.bytes 1268 }) 1269 fmt.eprintfln( 1270 "-- lifetimes by allocation site (top %d of %d by bytes; lifetime in allocation ticks) --", 1271 min(max_sites, len(list)), 1272 len(list), 1273 ) 1274 for st, i in list { 1275 if i >= max_sites { 1276 break 1277 } 1278 fmt.eprintf( 1279 "SITE %s:%d proc=%s allocs=%d frees=%d live=%d bytes=%d peak_live=%d", 1280 display_path(da, st.loc.file_path), 1281 st.loc.line, 1282 st.loc.procedure, 1283 st.allocs, 1284 st.frees, 1285 st.live, 1286 st.bytes, 1287 st.peak_live_bytes, 1288 ) 1289 if st.resizes > 0 { 1290 fmt.eprintf(" resizes=%d", st.resizes) 1291 } 1292 if st.frees > 0 { 1293 fmt.eprintf( 1294 " lifetime=%d..%d avg %d", 1295 st.lifetime_min, 1296 st.lifetime_max, 1297 st.lifetime_sum / u64(st.frees), 1298 ) 1299 if st.cross_phase > 0 { 1300 fmt.eprintf(" cross_phase=%d (last died in %s)", st.cross_phase, st.last_death) 1301 } 1302 } 1303 fmt.eprintln() 1304 } 1305 } 1306 1307 // ---- paths and frames ----------------------------------------------------------- 1308 1309 // Directory of this source file, used to drop this package's own frames. 1310 @(private) 1311 SELF_DIR :: #directory 1312 1313 // Frames from Odin's runtime are plumbing between the user's call and this allocator. 1314 @(private) 1315 RUNTIME_DIR :: ODIN_ROOT + "base" 1316 1317 @(private) 1318 print_frames :: proc(da: ^Allocator, bt: trace.Capture_Const, max_frames: int) { 1319 if bt.len == 0 { 1320 return 1321 } 1322 locs, err := trace.resolve(bt, da.internals, context.temp_allocator) 1323 if err != nil { 1324 fmt.eprintfln( 1325 " (call chain unavailable: %s; build with -debug)", 1326 trace.resolve_err_string(err), 1327 ) 1328 return 1329 } 1330 defer trace.locations_destroy(locs, da.internals) 1331 1332 self_dir := normalize(SELF_DIR, context.temp_allocator) 1333 runtime_dir := normalize(RUNTIME_DIR, context.temp_allocator) 1334 odin_root := normalize(ODIN_ROOT, context.temp_allocator) 1335 1336 shown := 0 1337 for l in locs { 1338 // Frames with no line number are OS or CRT entry code; nothing useful follows them. 1339 if l.line == 0 { 1340 break 1341 } 1342 path := normalize(l.file_path, context.temp_allocator) 1343 if strings.has_prefix(path, self_dir) || strings.has_prefix(path, runtime_dir) { 1344 continue 1345 } 1346 // The trace stops at the first frame outside the project and outside Odin's own tree: the 1347 // frames past it have been CRT or OS startup code in every trace seen so far. 1348 if !strings.has_prefix(path, da.root) && !strings.has_prefix(path, odin_root) { 1349 break 1350 } 1351 if shown >= max_frames { 1352 fmt.eprintln(" <- ...") 1353 break 1354 } 1355 fmt.eprintfln( 1356 " <- %s %s:%d", 1357 short_proc(l.procedure), 1358 display_path(da, l.file_path), 1359 l.line, 1360 ) 1361 shown += 1 1362 } 1363 } 1364 1365 // Polymorphic procs symbolize with their full signature appended; keep only the name. 1366 @(private) 1367 short_proc :: proc(p: string) -> string { 1368 if i := strings.index_byte(p, ':'); i >= 0 && i + 1 < len(p) && p[i + 1] == 'p' { 1369 return p[:i] 1370 } 1371 return p 1372 } 1373 1374 @(private) 1375 display_path :: proc(da: ^Allocator, path: string) -> string { 1376 n := normalize(path, context.temp_allocator) 1377 if da.root != "" && strings.has_prefix(n, da.root) { 1378 rest := n[len(da.root):] 1379 if len(rest) > 0 && rest[0] == '/' { 1380 rest = rest[1:] 1381 } 1382 return rest 1383 } 1384 return n 1385 } 1386 1387 /* 1388 Forward slashes so paths from different sources compare equal, and on Windows lowercase 1389 as well, because there the same file reaches us spelled both ways. Not elsewhere: on a 1390 case-sensitive filesystem lowercasing invents a path that does not exist, and the point 1391 of this output is that a reader can open what it names. 1392 1393 The result is always owned by allocator, which is not free to arrange. strings.replace_all 1394 hands back the input untouched when there is nothing to replace — which on a path with no 1395 backslashes is every time — and the caller's input can be a slice of a compile-time 1396 literal, since os.dir returns one. Owning it here is what lets destroy free da.root 1397 instead of calling free on rodata. 1398 */ 1399 @(private) 1400 normalize :: proc(path: string, allocator: mem.Allocator) -> string { 1401 fwd, replaced := strings.replace_all(path, "\\", "/", allocator) 1402 when ODIN_OS == .Windows { 1403 lowered := strings.to_lower(fwd, allocator) 1404 if replaced { 1405 delete(fwd, allocator) 1406 } 1407 return lowered 1408 } else { 1409 return replaced ? fwd : strings.clone(path, allocator) 1410 } 1411 }