From: Martin Mares Date: Tue, 11 Sep 2007 16:26:03 +0000 (+0200) Subject: Cleaned up tracing levels. Array sorter now has its own control knob. X-Git-Tag: holmes-import~506^2~13^2~12 X-Git-Url: http://mj.ucw.cz/gitweb/?a=commitdiff_plain;h=c5fbc7b75705d1f7a322ad73e6055284a3b94e73;p=libucw.git Cleaned up tracing levels. Array sorter now has its own control knob. --- diff --git a/lib/sorter/TODO b/lib/sorter/TODO index 79a60204..32bd56fe 100644 --- a/lib/sorter/TODO +++ b/lib/sorter/TODO @@ -1,11 +1,4 @@ -Testing: -o Giant runs. -o Records of odd lengths. -o Empty files. - Cleanups: -o Clean up data types and make sure they cannot overflow. (size_t vs. u64 vs. sh_off_t vs. uns) -o Clean up log levels. o Clean up introductory comments. o Log messages should show both original and new size of the data. The speed should be probably calculated from the former. diff --git a/lib/sorter/array.c b/lib/sorter/array.c index dd7659e7..68ada901 100644 --- a/lib/sorter/array.c +++ b/lib/sorter/array.c @@ -17,6 +17,9 @@ #define ASORT_MIN_SHIFT 2 +#define ASORT_TRACE(x...) ASORT_XTRACE(1, x) +#define ASORT_XTRACE(level, x...) do { if (sorter_trace_array >= level) msg(L_DEBUG, x); } while(0) + static void asort_radix(struct asort_context *ctx, void *array, void *buffer, uns num_elts, uns hash_bits, uns swapped_output) { @@ -79,7 +82,7 @@ asort_start_threads(uns run) asort_threads_use_count++; if (run && !asort_threads_ready) { - SORT_XTRACE(2, "Initializing thread pool (%d threads)", sorter_threads); + ASORT_TRACE("Initializing thread pool (%d threads)", sorter_threads); asort_thread_pool.num_threads = sorter_threads; worker_pool_init(&asort_thread_pool); asort_threads_ready = 1; @@ -93,7 +96,7 @@ asort_stop_threads(void) ucwlib_lock(); if (!--asort_threads_use_count && asort_threads_ready) { - SORT_XTRACE(2, "Shutting down thread pool"); + ASORT_TRACE("Shutting down thread pool"); worker_pool_cleanup(&asort_thread_pool); asort_threads_ready = 0; } @@ -407,7 +410,7 @@ predict_swap(struct asort_context *ctx) void asort_run(struct asort_context *ctx) { - SORT_XTRACE(10, "Array-sorting %d items per %d bytes, hash_bits=%d", ctx->num_elts, ctx->elt_size, ctx->hash_bits); + ASORT_TRACE("Array-sorting %d items per %d bytes, hash_bits=%d", ctx->num_elts, ctx->elt_size, ctx->hash_bits); uns allow_threads UNUSED = (sorter_threads > 1 && ctx->num_elts * ctx->elt_size >= sorter_thread_threshold && !(sorter_debug & SORT_DEBUG_ASORT_NO_THREADS)); @@ -420,12 +423,12 @@ asort_run(struct asort_context *ctx) #ifdef CONFIG_UCW_THREADS if (allow_threads) { - SORT_XTRACE(12, "Decided to use parallel quicksort"); + ASORT_XTRACE(2, "Decided to use parallel quicksort"); threaded_quicksort(ctx); return; } #endif - SORT_XTRACE(12, "Decided to use sequential quicksort"); + ASORT_XTRACE(2, "Decided to use sequential quicksort"); ctx->quicksort(ctx->array, ctx->num_elts); } else @@ -434,16 +437,16 @@ asort_run(struct asort_context *ctx) #ifdef CONFIG_UCW_THREADS if (allow_threads) { - SORT_XTRACE(12, "Decided to use parallel radix-sort (swap=%d)", swap); + ASORT_XTRACE(2, "Decided to use parallel radix-sort (swap=%d)", swap); threaded_radixsort(ctx, swap); return; } #endif - SORT_XTRACE(12, "Decided to use sequential radix-sort (swap=%d)", swap); + ASORT_XTRACE(2, "Decided to use sequential radix-sort (swap=%d)", swap); asort_radix(ctx, ctx->array, ctx->buffer, ctx->num_elts, ctx->hash_bits, swap); if (swap) ctx->array = ctx->buffer; } - SORT_XTRACE(11, "Array-sort finished"); + ASORT_XTRACE(2, "Array-sort finished"); } diff --git a/lib/sorter/common.h b/lib/sorter/common.h index 92423046..1b405a08 100644 --- a/lib/sorter/common.h +++ b/lib/sorter/common.h @@ -13,7 +13,7 @@ #include "lib/clists.h" /* Configuration, some of the variables are used by the old sorter, too. */ -extern uns sorter_trace, sorter_stream_bufsize; +extern uns sorter_trace, sorter_trace_array, sorter_stream_bufsize; extern uns sorter_debug, sorter_min_radix_bits, sorter_max_radix_bits, sorter_add_radix_bits; extern uns sorter_min_multiway_bits, sorter_max_multiway_bits; extern uns sorter_threads, sorter_thread_threshold, sorter_thread_chunk; diff --git a/lib/sorter/config.c b/lib/sorter/config.c index e0927ba8..5e3da8dd 100644 --- a/lib/sorter/config.c +++ b/lib/sorter/config.c @@ -13,6 +13,7 @@ #include "lib/sorter/common.h" uns sorter_trace; +uns sorter_trace_array; u64 sorter_bufsize = 65536; uns sorter_debug; uns sorter_min_radix_bits; @@ -31,6 +32,7 @@ u64 sorter_small_input; static struct cf_section sorter_config = { CF_ITEMS { CF_UNS("Trace", &sorter_trace), + CF_UNS("TraceArray", &sorter_trace_array), CF_SECTION("FileAccess", &sorter_fb_params, &fbpar_cf), CF_SECTION("SmallFileAccess", &sorter_fb_params, &fbpar_cf), CF_U64("SmallInput", &sorter_small_input), diff --git a/lib/sorter/govern.c b/lib/sorter/govern.c index 5ce88473..7231a5b7 100644 --- a/lib/sorter/govern.c +++ b/lib/sorter/govern.c @@ -105,7 +105,7 @@ sorter_join(struct sort_bucket *b) { // The final bucket doesn't have any file associated yet, so replace // it with the new bucket. - SORT_XTRACE(2, "Replaced final bucket"); + SORT_XTRACE(3, "Replaced final bucket"); b->flags |= SBF_FINAL; sbuck_drop(join); } @@ -136,7 +136,7 @@ sorter_twoway(struct sort_context *ctx, struct sort_bucket *b) { sorter_stop_timer(ctx, &ctx->total_pre_time); sh_off_t size = sbuck_ins_or_join(ins[0], list_pos, join, join_size); - SORT_XTRACE(((b->flags & SBF_SOURCE) ? 1 : 2), "Sorted in memory (%s, %dMB/s)", stk_fsize(size), sorter_speed(ctx, size)); + SORT_XTRACE(((b->flags & SBF_SOURCE) ? 1 : 3), "Sorted in memory (%s, %dMB/s)", stk_fsize(size), sorter_speed(ctx, size)); sbuck_drop(b); return; } @@ -201,7 +201,7 @@ sorter_multiway(struct sort_context *ctx, struct sort_bucket *b) cnode *list_pos = b->n.prev; sh_off_t join_size; struct sort_bucket *join = sbuck_join_to(b, &join_size); - uns trace_level = (b->flags & SBF_SOURCE) ? 1 : 2; + uns trace_level = (b->flags & SBF_SOURCE) ? 1 : 3; clist_init(&parts); ASSERT(!(sorter_debug & SORT_DEBUG_NO_PRESORT)); @@ -240,7 +240,7 @@ sorter_multiway(struct sort_context *ctx, struct sort_bucket *b) uns max_ways = 1 << sorter_max_multiway_bits; struct sort_bucket *ways[max_ways+1]; - SORT_XTRACE(2, "Starting up to %d-way merge", max_ways); + SORT_XTRACE(3, "Starting up to %d-way merge", max_ways); for (;;) { uns n = 0; @@ -287,7 +287,7 @@ sorter_radix(struct sort_context *ctx, struct sort_bucket *b, uns bits) bits = MIN(bits + sorter_add_radix_bits, sorter_max_radix_bits); uns nbuck = 1 << bits; - SORT_XTRACE(2, "Running radix split on %s with hash %d bits of %d (expecting %s buckets)", + SORT_XTRACE(3, "Running radix split on %s with hash %d bits of %d (expecting %s buckets)", F_BSIZE(b), bits, b->hash_bits, stk_fsize(sbuck_size(b) / nbuck)); sorter_free_buf(ctx); sorter_start_timer(ctx); @@ -325,7 +325,7 @@ sorter_decide(struct sort_context *ctx, struct sort_bucket *b) // Drop empty buckets if (!sbuck_have(b)) { - SORT_XTRACE(3, "Dropping empty bucket"); + SORT_XTRACE(4, "Dropping empty bucket"); sbuck_drop(b); return; } @@ -365,7 +365,7 @@ sorter_decide(struct sort_context *ctx, struct sort_bucket *b) multiway_bits = 0; } - SORT_XTRACE(2, "Decisions: size=%s max=%s runs=%d bits=%d hash=%d -> radix=%d multi=%d", + SORT_XTRACE(3, "Decisions: size=%s max=%s runs=%d bits=%d hash=%d -> radix=%d multi=%d", stk_fsize(insize), stk_fsize(mem), b->runs, bits, b->hash_bits, radix_bits, multiway_bits); diff --git a/lib/sorter/s-fixint.h b/lib/sorter/s-fixint.h index 9787a682..276194cb 100644 --- a/lib/sorter/s-fixint.h +++ b/lib/sorter/s-fixint.h @@ -58,7 +58,7 @@ static int P(internal)(struct sort_context *ctx, struct sort_bucket *bin, struct P(key) *buf = ctx->big_buf; uns maxkeys = P(internal_num_keys)(ctx); - SORT_XTRACE(4, "s-fixint: Reading (maxkeys=%u, hash_bits=%d)", maxkeys, bin->hash_bits); + SORT_XTRACE(5, "s-fixint: Reading (maxkeys=%u, hash_bits=%d)", maxkeys, bin->hash_bits); uns n = 0; while (n < maxkeys && P(read_key)(in, &buf[n])) n++; @@ -66,7 +66,7 @@ static int P(internal)(struct sort_context *ctx, struct sort_bucket *bin, struct return 0; void *workspace UNUSED = ALIGN_PTR(&buf[n], CPU_PAGE_SIZE); - SORT_XTRACE(3, "s-fixint: Sorting %u items (%s items, %s workspace)", + SORT_XTRACE(4, "s-fixint: Sorting %u items (%s items, %s workspace)", n, stk_fsize(n * sizeof(P(key))), stk_fsize(n * P(internal_workspace)())); @@ -79,7 +79,7 @@ static int P(internal)(struct sort_context *ctx, struct sort_bucket *bin, struct ); ctx->total_int_time += get_timer(&timer); - SORT_XTRACE(4, "s-fixint: Writing"); + SORT_XTRACE(5, "s-fixint: Writing"); if (n < maxkeys) bout = bout_only; struct fastbuf *out = sbuck_write(bout); @@ -111,7 +111,7 @@ static int P(internal)(struct sort_context *ctx, struct sort_bucket *bin, struct P(write_key)(out, &buf[i]); } #ifdef SORT_UNIFY - SORT_XTRACE(3, "Merging reduced %d records", merged); + SORT_XTRACE(4, "Merging reduced %d records", merged); #endif return (n == maxkeys); diff --git a/lib/sorter/s-internal.h b/lib/sorter/s-internal.h index ef2da240..5a560b14 100644 --- a/lib/sorter/s-internal.h +++ b/lib/sorter/s-internal.h @@ -115,7 +115,7 @@ static int P(internal)(struct sort_context *ctx, struct sort_bucket *bin, struct #ifdef SORT_VAR_DATA if (sizeof(key) + 2*CPU_PAGE_SIZE + SORT_DATA_SIZE(key) + P(internal_workspace)(&key) > bufsize) { - SORT_XTRACE(3, "s-internal: Generating a giant run"); + SORT_XTRACE(4, "s-internal: Generating a giant run"); struct fastbuf *out = sbuck_write(bout); P(copy_data)(&key, in, out); bout->runs++; @@ -123,7 +123,7 @@ static int P(internal)(struct sort_context *ctx, struct sort_bucket *bin, struct } #endif - SORT_XTRACE(4, "s-internal: Reading"); + SORT_XTRACE(5, "s-internal: Reading"); P(internal_item_t) *item_array = ctx->big_buf, *item = item_array, *last_item; byte *end = (byte *) ctx->big_buf + bufsize; size_t remains = bufsize - CPU_PAGE_SIZE; @@ -165,7 +165,7 @@ static int P(internal)(struct sort_context *ctx, struct sort_bucket *bin, struct uns count = last_item - item_array; void *workspace UNUSED = ALIGN_PTR(last_item, CPU_PAGE_SIZE); - SORT_XTRACE(3, "s-internal: Read %u items (%s items, %s workspace, %s data)", + SORT_XTRACE(4, "s-internal: Read %u items (%s items, %s workspace, %s data)", count, stk_fsize((byte*)last_item - (byte*)item_array), stk_fsize(end - (byte*)last_item - remains), @@ -179,7 +179,7 @@ static int P(internal)(struct sort_context *ctx, struct sort_bucket *bin, struct ); ctx->total_int_time += get_timer(&timer); - SORT_XTRACE(4, "s-internal: Writing"); + SORT_XTRACE(5, "s-internal: Writing"); if (!ctx->more_keys) bout = bout_only; struct fastbuf *out = sbuck_write(bout); @@ -217,7 +217,7 @@ static int P(internal)(struct sort_context *ctx, struct sort_bucket *bin, struct #endif } #ifdef SORT_UNIFY - SORT_XTRACE(3, "Merging reduced %u records", merged); + SORT_XTRACE(4, "Merging reduced %u records", merged); #endif return ctx->more_keys; diff --git a/lib/sorter/sbuck.c b/lib/sorter/sbuck.c index 1150c9d6..7f19f31e 100644 --- a/lib/sorter/sbuck.c +++ b/lib/sorter/sbuck.c @@ -143,7 +143,7 @@ sorter_alloc_buf(struct sort_context *ctx) if (ctx->big_buf) return; ctx->big_buf = big_alloc(ctx->big_buf_size); - SORT_XTRACE(2, "Allocated sorting buffer (%s)", stk_fsize(ctx->big_buf_size)); + SORT_XTRACE(3, "Allocated sorting buffer (%s)", stk_fsize(ctx->big_buf_size)); } void @@ -153,5 +153,5 @@ sorter_free_buf(struct sort_context *ctx) return; big_free(ctx->big_buf, ctx->big_buf_size); ctx->big_buf = NULL; - SORT_XTRACE(2, "Freed sorting buffer"); + SORT_XTRACE(3, "Freed sorting buffer"); }