common-lisp/sbcl.sbcl
1
0
Fork 0
mirror of git://git.code.sf.net/p/sbcl/sbcl synced 2026-09-10 07:26:40 -04:00
Code Issues Actions 8 Packages Projects Releases Wiki Activity

Less verbosity, more error reporting in SB-EXT:SEARCH-ROOTS

Browse source 
* Disable output on stderr unless heap_trace_verbose is true.

* Turn errors reported by gc_prove_liveness into Lisp errors.
This commit is contained in:
Jan Moringen 2019-08-12 20:43:48 +02:00
parent 8d50da1d69
commit 7ec9a8836e
3 changed files with 84 additions and 77 deletions
Show stats Download patch file Download diff file Expand all files Collapse all files

32
doc/manual/beyond-ansi.texinfo
View file

@ -247,36 +247,19 @@ An example of using this could look like this:
*MY-STRING*
* (sb-ext:search-roots (sb-ext:make-weak-pointer (third *my-string*)))
; Liveness tracking: 1/1 live watched objects
Pass 1: Counting heap objects... 602789 objs, 1637358 ptrs, 894478 immediates
Pass 2: Inverting heap. Initial size=1048576 objects
Scratchpad: 13099008 bytes
Inverted heap: ct=599785, cap=1048607, LF=57.198265 ET=3831+125697 sys+usr
Stopping at 0x10004e9ea0: tenured
Anchor object is @ 0x10004e9ea0. word[2]
-> ((SIMPLE-VECTOR 3)) #x10004E9EAF[2] -> (SYMBOL) #x5044100F[1] -> (CONS) #x100181FAE7[1] -> (CONS) #x100181FAF7[1] -> (CONS) #x100181FB07[0] -> #x100181F9AF
@end lisp
The indented output appears on @code{sb-sys:*stdout*} (i.e. would not be
visible in SLIME) while the non-indented output appears on
@code{cl:*standard-output*}. The single line of output on
@code{cl:*standard-output*} shows the path from a root to @t{"my
string"}: the path starts with SBCL's internal package system data
structures followed by the symbol (@t{cl-user:*my-string*}) followed the
three cons cells of the list.
The single line of output on @code{cl:*standard-output*} shows the path
from a root to @t{"my string"}: the path starts with SBCL's internal
package system data structures followed by the symbol
(@t{cl-user:*my-string*}) followed the three cons cells of the list.
The @code{:print :verbose} argument produces similar behavior but
describe the path elements in more detail:
@lisp
* (sb-ext:search-roots (sb-ext:make-weak-pointer (third *my-string*)) :print :verbose)
; Liveness tracking: 1/1 live watched objects
Pass 1: Counting heap objects... 601937 objs, 1635802 ptrs, 893142 immediates
Pass 2: Inverting heap. Initial size=1048576 objects
Scratchpad: 13086720 bytes
Inverted heap: ct=599133, cap=1048607, LF=57.136086 ET=0+124554 sys+usr
Stopping at 0x10004e9ea0: tenured
Anchor object is @ 0x10004e9ea0. word[2]
Path to "my string":
6 10004E9EAF [ 2] a (simple-vector 3)
0 5044100F [ 1] COMMON-LISP-USER::*MY-STRING*
@ -289,13 +272,6 @@ The @code{:print nil} argument is a bit different:
@lisp
* (sb-ext:search-roots (sb-ext:make-weak-pointer (third *my-string*)) :print nil)
; Liveness tracking: 1/1 live watched objects
Pass 1: Counting heap objects... 602802 objs, 1637375 ptrs, 894487 immediates
Pass 2: Inverting heap. Initial size=1048576 objects
Scratchpad: 13099008 bytes
Inverted heap: ct=599796, cap=1048607, LF=57.199314 ET=3937+150556 sys+usr
Stopping at 0x10004e9ea0: tenured
Anchor object is @ 0x10004e9ea0. word[2]
(("my string" :STATIC (#(*MY-STRING* 0 0) . 2) (*MY-STRING* . 1)
((1 2 "my string") . 1) ((2 "my string") . 1) (("my string") . 0)))
@end lisp

19
src/code/traceroot.lisp
View file

@ -222,11 +222,11 @@ printed. Possible values are
Experimental: subject to change without prior notice."
(let* ((input (ensure-list weak-pointers))
(output (make-array (length input)))
(param (cons input output))
(param (cons input (cons :result output)))
(criterion-value (ecase criterion
(:oldest 0)
(:pseudo-static 1)
(:static 2)) ))
(:static 2))))
(cond (gc
(setf gc-traceroot-criterion criterion-value)
(sb-sys:with-pinned-objects (param)
@ -235,12 +235,15 @@ Experimental: subject to change without prior notice."
(setf gc-object-watcher 0))
(t
(sb-sys:without-gcing
(alien-funcall (extern-alien "prove_liveness" (function int unsigned int))
(sb-kernel:get-lisp-obj-address param)
criterion-value))))
(let ((results (preprocess-traceroot-results input output)))
(alien-funcall
(extern-alien "prove_liveness" (function int unsigned int))
(sb-kernel:get-lisp-obj-address param)
criterion-value))))
(case (cadr param)
(-1 (error "Input is not a proper list of weak pointers.")))
(let ((paths (preprocess-traceroot-results input output)))
(cond (print
(print-traceroot-paths results :multiline (eq print :verbose))
(print-traceroot-paths paths :multiline (eq print :verbose))
(values))
(t
results)))))
paths)))))

110
src/runtime/traceroot.c
View file

@ -1,4 +1,3 @@
#include "sbcl.h"
#include "arch.h"
#include "runtime.h"
@ -522,8 +521,10 @@ static lispobj trace1(lispobj object,
continue;
int wordindex = find_ref((lispobj*)ptr, target);
if (wordindex == -1) {
fprintf(stderr, "Strange: no ref from %p to %p\n",
(void*)ptr, (void*)target);
if (heap_trace_verbose) {
fprintf(stderr, "Strange: no ref from %p to %p\n",
(void*)ptr, (void*)target);
}
continue;
}
hopscotch_insert(visited, ptr, 1);
@ -531,21 +532,25 @@ static lispobj trace1(lispobj object,
top_layer, &layer_capacity);
// Stop if the object at 'ptr' is tenured.
if (root_p(ptr, criterion)) {
fprintf(stderr, "Stopping at %p: tenured\n", (void*)ptr);
if (heap_trace_verbose) {
fprintf(stderr, "Stopping at %p: tenured\n", (void*)ptr);
}
anchor = &top_layer->nodes[top_layer->count-1];
}
}
}
if (!top_layer->count) {
fprintf(stderr, "Failure tracing from %p. Current targets:\n", (void*)object);
for_each_hopscotch_key(i, target, (*targets)) {
fprintf(stderr, "%p", (void*)target);
fprintf(stderr, "(g%d,", traceroot_gen_of(target));
fputs(classify_obj(target), stderr);
maybe_show_object_name(target, stderr);
fprintf(stderr,") ");
if (heap_trace_verbose) {
fprintf(stderr, "Failure tracing from %p. Current targets:\n", (void*)object);
for_each_hopscotch_key(i, target, (*targets)) {
fprintf(stderr, "%p", (void*)target);
fprintf(stderr, "(g%d,", traceroot_gen_of(target));
fputs(classify_obj(target), stderr);
maybe_show_object_name(target, stderr);
fprintf(stderr,") ");
}
putc('\n', stderr);
}
putc('\n', stderr);
free_graph(top_layer);
return 0;
}
@ -591,8 +596,10 @@ static lispobj trace1(lispobj object,
make_sap(thread_pc));
}
} else { // Stopped at (pseudo)static object
fprintf(stderr, "Anchor object is @ %p. word[%d]\n",
native_pointer(anchor->object), anchor->wordindex);
if (heap_trace_verbose) {
fprintf(stderr, "Anchor object is @ %p. word[%d]\n",
native_pointer(anchor->object), anchor->wordindex);
}
path_node = liststar3(0, 0, 0);
}
@ -782,15 +789,21 @@ static void compute_heap_inverse(struct hopscotch_table* inverted_heap,
{
struct scan_state ss;
memset(&ss, 0, sizeof ss);
fprintf(stderr, "Pass 1: Counting heap objects... ");
if (heap_trace_verbose) {
fprintf(stderr, "Pass 1: Counting heap objects... ");
}
scan_spaces(&ss);
fprintf(stderr, "%ld objs, %ld ptrs, %ld immediates\n",
ss.n_objects, ss.n_pointers,
ss.n_scanned_words - ss.n_pointers);
if (heap_trace_verbose) {
fprintf(stderr, "%ld objs, %ld ptrs, %ld immediates\n",
ss.n_objects, ss.n_pointers,
ss.n_scanned_words - ss.n_pointers);
}
// Guess at the initial size of ~ .5 million objects.
int size = 1<<19; // flsl(tot_n_objects); this would work if you have it
while (ss.n_objects > size) size <<= 1;
fprintf(stderr, "Pass 2: Inverting heap. Initial size=%d objects\n", size);
if (heap_trace_verbose) {
fprintf(stderr, "Pass 2: Inverting heap. Initial size=%d objects\n", size);
}
hopscotch_create(&ss.inverted_heap, HASH_FUNCTION,
4, // XXX: half the word size if 64-bit
size /* initial size */, 0 /* default hop range */);
@ -803,7 +816,9 @@ static void compute_heap_inverse(struct hopscotch_table* inverted_heap,
gc_assert(ss.scratchpad.base);
ss.scratchpad.free = ss.scratchpad.base + 2 * sizeof(uint32_t);
ss.scratchpad.end = ss.scratchpad.base + scratchpad_size;
fprintf(stderr, "Scratchpad: %lu bytes\n", (long unsigned)scratchpad_size);
if (heap_trace_verbose) {
fprintf(stderr, "Scratchpad: %lu bytes\n", (long unsigned)scratchpad_size);
}
#if HAVE_GETRUSAGE
struct rusage before, after;
getrusage(RUSAGE_SELF, &before);
@ -815,16 +830,18 @@ static void compute_heap_inverse(struct hopscotch_table* inverted_heap,
#if HAVE_GETRUSAGE
getrusage(RUSAGE_SELF, &after);
// We're done building the necessary structure. Show some memory stats.
if (heap_trace_verbose) {
#define timediff(b,a,field) \
((a.field.tv_sec-b.field.tv_sec)*1000000+(a.field.tv_usec-b.field.tv_usec))
fprintf(stderr,
"Inverted heap: ct=%d, cap=%d, LF=%f ET=%ld+%ld sys+usr\n",
inverted_heap->count,
1+hopscotch_max_key_index(*inverted_heap),
100*(float)inverted_heap->count / (1+hopscotch_max_key_index(*inverted_heap)),
timediff(before, after, ru_stime),
timediff(before, after, ru_utime));
((a.field.tv_sec-b.field.tv_sec)*1000000+(a.field.tv_usec-b.field.tv_usec))
fprintf(stderr,
"Inverted heap: ct=%d, cap=%d, LF=%f ET=%ld+%ld sys+usr\n",
inverted_heap->count,
1+hopscotch_max_key_index(*inverted_heap),
100*(float)inverted_heap->count / (1+hopscotch_max_key_index(*inverted_heap)),
timediff(before, after, ru_stime),
timediff(before, after, ru_utime));
#endif
}
};
/* Find any shortest path from a thread or tenured object
@ -888,9 +905,10 @@ int gc_prove_liveness(void(*context_scanner)(),
int n_pins, uword_t* pins,
int criterion)
{
int n_watched = 0, n_live = 0, n_bad = 0, n_imm = 0;
int n_watched = 0, n_live = 0, n_bad = 0, n_imm = 0, n_paths = 0;
lispobj input = CONS(objects)->car,
output = CONS(objects)->cdr;
output = CONS(objects)->cdr,
paths = CONS(output)->cdr;
lispobj list;
for (list = input ; list != NIL && listp(list) ; list = CONS(list)->cdr) {
++n_watched;
@ -906,18 +924,26 @@ int gc_prove_liveness(void(*context_scanner)(),
else if (wpval != UNBOUND_MARKER_WIDETAG)
++n_imm;
}
if (!listp(list) || n_bad || lowtag_of(output) != OTHER_POINTER_LOWTAG
|| widetag_of(native_pointer(output)) != SIMPLE_VECTOR_WIDETAG) {
fprintf(stderr, "; Bad value in liveness tracker\n");
if (!listp(list) || n_bad || lowtag_of(paths) != OTHER_POINTER_LOWTAG
|| widetag_of(native_pointer(paths)) != SIMPLE_VECTOR_WIDETAG) {
if (heap_trace_verbose) {
fprintf(stderr, "; Bad value in liveness tracker\n");
}
CONS(output)->car = make_fixnum(-1);
return -1;
}
fprintf(stderr, "; Liveness tracking: %d/%d live watched objects",
n_live, n_watched);
if (n_imm)
fprintf(stderr, " (ignored %d non-pointers)", n_imm);
putc('\n', stderr);
if (!n_live)
if (heap_trace_verbose) {
fprintf(stderr, "; Liveness tracking: %d/%d live watched objects",
n_live, n_watched);
if (n_imm)
fprintf(stderr, " (ignored %d non-pointers)", n_imm);
putc('\n', stderr);
}
if (!n_live) {
CONS(output)->car = make_fixnum(0);
return 0;
}
// Put back lowtags on pinned objects, since wipe_nonpinned_words() removed
// them. But first test whether lowtags were already repaired
// in case prove_liveness() is called after gc_prove_liveness().
@ -927,8 +953,10 @@ int gc_prove_liveness(void(*context_scanner)(),
pins[i] = compute_lispobj((lispobj*)pins[i]);
}
}
return trace_paths(context_scanner, input, output,
n_pins, (lispobj*)pins, criterion);
n_paths = trace_paths(context_scanner, input, paths,
n_pins, (lispobj*)pins, criterion);
CONS(output)->car = make_fixnum(n_paths);
return n_paths;
}
/* This should be called inside WITHOUT-GCING so that the set