| blob | 8adca72c8ae402524a293ba0dde8cca04dc56d01 |
1 ;;; Allocation profiler
3 ;;; Quick start: To enable this code, you must DECLAIM or DECLARE
4 ;;; (OPTIMIZE SB-C::INSTRUMENT-CONSING)
5 ;;; to affect functions in which instrumentation should be inserted.
6 ;;; After that, the simplest way to run the function under test is to pass
7 ;;; it to APROF-RUN. Alternatively, collection can be toggled with APROF-START
8 ;;; and APROF-STOP, but some setup is needed (as done by APROF-RUN).
9 ;;;
10 ;;; Note: This is x86-64 only at the moment.
12 ;;; Profiling works via compile-time instrumentation.
13 ;;; Each point in code emitted by ALLOCATION adds a few instructions
14 ;;; prior to the actual inline allocation sequence. The extra instructions
15 ;;; are normally disabled (there is a jump around them). When the profiler
16 ;;; is switched on, the instructions are modified to atomically increment
17 ;;; a counter (or two). If the allocation is a compile-time fixed size,
18 ;;; only one counter is needed. If the size is variable, then two counters
19 ;;; are used: hits and total bytes.
20 ;;; The array of counters is prepared by the profiler when first started.
21 ;;; The index into the array for any particular counter is determined
22 ;;; the first time that counter is hit. Subsequent hits are cheap.
24 ;;; On x86-64, instrumented code initially looks like this:
26 ;;; 9E98: 4D8B5D18 MOV R11, [R13+24] ; thread.profile-data
27 ;;; 9E9C: 4D85DB TEST R11, R11
28 ;;; 9E9F: EB17 JMP L21
29 ;;; 9EA1: 0F1F8000000000 NOP
30 ;;; 9EA8: E8D366FDFF CALL #x21B00580 ; ENABLE-SIZED-ALLOC-COUNTER
31 ;;; 9EAD: 0F1F00 NOP
32 ;;; 9EB0: 4885C9 TEST RCX, RCX
33 ;;; 9EB3: 0F1F440000 NOP
34 ;;; 9EB8: L21: 4D8B5D20 MOV R11, [R13+32] ; thread.alloc-region
35 ;;;
36 ;;; The first TEST instruction's result is ignored.
37 ;;; The second TEST conveys the register holding the size to allocate in bytes.
39 ;;; After enabling profiling, the first JMP becomes a JEQ so that
40 ;;; if the data buffer exists, the CALL is performed.
41 ;;; If this code is actually reached, and the call performed,
42 ;;; then the call instruction is modified to (something like):
43 ;;;
44 ;;; 9E98: 4D8B5D18 MOV R11, [R13+24] ; thread.profile-data
45 ;;; 9E9C: 4D85DB TEST R11, R11
46 ;;; 9E9F: 7417 JEQ L21
47 ;;; 9EA1: 0F1F8000000000 NOP
48 ;;; 9EA8: F049FF83C8020000 LOCK INC QWORD PTR [R11+712]
49 ;;; 9EB0: F049018BD0020000 LOCK ADD [R11+720], RCX
50 ;;; 9EB8: L21: 4D8B5D20 MOV R11, [R13+32] ; thread.alloc-region
52 ;;; All of the modifications to running code can be made safely
53 ;;; even if multiple threads are in that code at the same time, because:
54 ;;;
55 ;;; * changing a JMP to a JNE requires writing only 1 byte.
56 ;;; Instruction fetch will either see the new byte or the old,
57 ;;; and it doesn't matter which.
58 ;;;
59 ;;; * changing CALL to LOCK INC writes one naturally aligned octword.
60 ;;; Moreover, RIP gets decremented so that the next fetch won't read
61 ;;; the NOP or only part of the bytes of the LOCK INC.
63 ;;; See the example run at the bottom of this file.
81 bytes count type pc)
91 alloc-profile-buffer
92 0
122 ;; The C rountine looks at the return address to see where
123 ;; to patch in the new instructions, and it gets the return address
124 ;; from the stack, the pointer to which is supplied as the arg.
125 ;; So STACK is the simulated stack containing the return PC.
131 ;; Dynamic-space code can't encode call32 to an asm routine. Instead
132 ;; might see CALL to a JMP within the code blob so that we don't
133 ;; produce one absolute fixup per allocation site.
146 code loc)))))
149 code loc)))))
152 code loc)))))
156 ;; Fixed-size allocations consume 1 entry (hit count).
157 ;; Variable-size consume 2 (hit count and total bytes).
158 ;; Counters 0 and 1 are reserved for variable-size allocations
159 ;; (hit count and total size) that overflow the maximum counter index.
160 ;; Counter 2 is reserved for fixed-size allocations.
167 ;; Lisp metadata may or may not exist depending on whether you saved a core image
168 ;; with the metadata baked in.
179 ;;; Passing ENABLE presumes that you want to later use the profiler
180 ;;; without relying on self-modifying code. Everything can be patched now
181 ;;; and then the image dumped. This plays more nicely with some sandboxed
182 ;;; environments that forbid executable text segments, which is
183 ;;; predominantly a concern for ELFinated cores.
186 ;; Somewhat un-obviously, we have to "start" the profiler so that the C
187 ;; support figures out how many alloc site indices it can utilize
188 ;; based on the size of the profile data vector passed from lisp.
190 ;; Then stop, because we don't actually want to profile anything now.
198 ;; just being pedantic about pinning here for documentation
218 'structure
221 ;;; These EAs are s-expressions, not instances of EA or MACHINE-EA.
222 #-sb-safepoint
227 ;;; Templates to try in order. The one for unknown headered objects should be last
228 ;;; so that we try to match a store to the header word if possible.
230 ;;; Running sb-aprof with #+sb-show is not an important concern,
231 ;;; and I don't care to fix it. It gets an error here:
232 ;;; "don't know how to dump R13 (default MAKE-LOAD-FORM method called)."
233 #-sb-show
253 ;; after the xadd, SIZE holds the original value of free-ptr
254 ;; and free-ptr points to the end of the putative data block.
259 ;; Could have one or two stores prior to ORing in a lowtag.
266 ;; LEA with scale=1 can have base and index swapped
277 ;; LISTIFY-REST-ARG computes a tagged pointer to the _last_ cons in the memory block,
278 ;; not the first cons.
285 ?free ?nbytes))
295 ;; either non-headered object (cons) or unknown header or unknown nbytes
314 ;; not really "large" but same as preceding
327 code
340 ;; FIXME: this drops any LOCK prefix, but that seems to be ok
343 ;; This takes an instruction expressed thusly:
344 ;; (MOV (#S(MACHINE-EA :DISP n :BASE n) . :QWORD) RDX)
345 ;; and turns it into:
346 ;; (MOV :QWORD #S(MACHINE-EA :DISP n :BASE n) RDX)
351 ;; Figure out if we're looking at an allocation buffer
364 ;; There can be at most one EA per instruction, so we're done
367 inst))))
376 ;;; If INPUT matches PATTERN then return a potentially amended
377 ;;; list of BINDINGS, otherwise return :FAIL.
380 ;; Match the first thing possible. There is no backtracking.
403 ;; free variable binds to input, otherwise binding must match
408 ;; ignore the operand size I guess?
417 (?lowtag
435 reg)
455 (:optional
456 ;; :OPTIONAL is greedy, preferring to match if it can,
457 ;; but if the rest of the template fails, we'll backtrack
458 ;; and skip this pattern.
465 (:repeat
466 ;; :REPEAT matches zero or more instructions, as few as possible.
485 bindings)))
487 'instance
493 #+immobile-space
502 t)
503 bindings))
506 'closure
510 template-name)
514 ;; Expect an increment of the allocation point hit counter
521 ;; Optional: the total number of bytes at the allocation point
531 ;; Expect a store to the pseudo-atomic flag
532 #-sb-safepoint
561 ;; matchp converts NIL in a machine-ea to 0. The disassembler uses
562 ;; NIL to signify that there was no displacement, which makes sense
563 ;; when register indirect mode is used without a SIB byte.
587 ;;; Return a name for PC-OFFSET in CODE. PC-OFFSET is relative to
588 ;;; CODE-INSTRUCTIONS.
612 n-hit metadata-len))
629 pc-offset))
631 ;; Relativize to CODE-INSTRUCTIONS, not the base address
633 code)))
641 ;; The only allocator that determines TYPE at run-time
642 ;; is ALLOCATE-VECTOR-ON-HEAP. VAR-ALLOC uses a codegen
643 ;; arg, not a TN, for the widetag, but it looks like
644 ;; the type is dynamic because it kind of is: the
645 ;; header words is computed into a register and written
646 ;; in a single store.
660 ;; DETAIL NIL shows just function name and percent space consumption
661 ;; DETAIL T shows function, bytes, percent,
662 ;; and unless there is only one detail line, the detail lines
663 ;;
673 collection))
691 ;; In detailed view, each function takes up either one line or
692 ;; more than one line. In the interest of saving space, newlines are
693 ;; omitted between consecutive functions each of whose detail consists
694 ;; of a single line. But to avoid ambiguity, esure that there is always
695 ;; a blank line before and after each function having multiline detail.
707 ;; Show summary for the function
711 sum-pct
712 bytes
714 name))
718 bytes
723 name
725 )))
740 ; (assert (= sum-bytes total-bytes))
745 sum-pct sum-bytes)))
746 sum-bytes))
748 ;;; Call FUN and return the exact number of bytes it (an all descendant
749 ;;; calls) allocated, provided that they were instrumented for precise
750 ;;; cons profiling.
751 ;;; STREAM is where to report, defaulting to *standard-output*.
752 ;;; The convention is that of map-segment-instructions, meaning NIL is a sink.
766 nbytes)))
768 ;;;;
770 ;;; Example:
771 ;;; The default output is a report showing the top 20 allocators
772 ;;; (by function name) with a line of detail for each distinct
773 ;;; type of object allocated within the function.
774 ;;;
775 ;;; * (aprof-run (lambda () (compile-file "~/aprof")))
776 ;;; % Bytes Count Function
777 ;;; ------- ----------- --------- --------
778 ;;; 6.6 1980160 INIT-SB-VECTORS
779 ;;; 79.1 1565824 48880 SIMPLE-BIT-VECTOR
780 ;;; 20.9 414336 1872 SIMPLE-VECTOR
781 ;;;
782 ;;; 4.6 1368960 MAKE-TN
783 ;;; 83.3 1140800 7130 TN
784 ;;; 16.7 228160 7130 SIMPLE-BIT-VECTOR
786 ;;; The report can be made more detailed by not combining lines
787 ;;; for the same object type within a function:
788 ;;;
789 ;;; * (aprof-show :detail t :collapse nil)
790 ;;;
791 ;;; % Bytes Count PC Function
792 ;;; ------- ----------- --------- ---------- --------
793 ;;; 6.6 1980160 INIT-SB-VECTORS
794 ;;; 76.0 1504256 47008 21D07E88 SIMPLE-BIT-VECTOR
795 ;;; 20.9 414336 1872 21D07D28 SIMPLE-VECTOR
796 ;;; 3.1 61568 1872 21D07F30 SIMPLE-BIT-VECTOR
797 ;;;
798 ;;; 4.6 1368960 MAKE-TN
799 ;;; 83.3 1140800 7130 21C98638 TN
800 ;;; 16.7 228160 7130 21C985D8 SIMPLE-BIT-VECTOR
801 ;;;
802 ;;; 4.0 1204160 MAKE-HASH-TABLE
803 ;;; 39.3 473472 1644 21B2A008 SIMPLE-VECTOR
804 ;;; 37.1 447168 1644 21B29F50 (SIMPLE-ARRAY (UNSIGNED-BYTE 64) (*))
805 ;;; 21.8 263040 1644 21B29FA8 (SIMPLE-ARRAY (UNSIGNED-BYTE 64) (*))
806 ;;; 1.7 20480 128 21B2A098 (SIMPLE-ARRAY (UNSIGNED-BYTE 64) (*))
808 ;;; Or less detailed by combining all lines within a function:
809 ;;;
810 ;;; * (sb-aprof::aprof-show :detail nil :top-n 1000) ; or anything
811 ;;; % Sum % Bytes Allocations Function
812 ;;; ------- ------- ----------- ----------- --------
813 ;;; 6.6 6.6 1980160 50752 INIT-SB-VECTORS
814 ;;; 4.6 11.1 1368960 14260 MAKE-TN
815 ;;; 4.0 15.1 1204160 5060 MAKE-HASH-TABLE
816 ;;; 3.8 19.0 1154384 28727 CONSTRAIN-REF-TYPE
817 ;;; 3.8 22.8 1152160 13084 COPY-CONSET
818 ;;; 3.6 26.5 1094240 13678 MAKE-TN-REF
819 ;;; ... many more lines ...
820 ;;; 00.0 100.0 16 1 %ENTER-NEW-NICKNAMES
821 ;;; 00.0 100.0 16 1 UNIX-LSTAT
822 ;;; ===========
823 ;;; 30054816