* Fixed my fix for make_space() wrapping. It's always a good idea to

write code aligned to what one has written in the comment (or the
  other way around).
* Made trace_entry structure doubly linked, by introducing a
  previous_size member. By using bit fields, shrinking the flags field
  to 4 bits, and not saving the lower two bits of size and previous_size
  (which are always 0 due to alignment), the structure remains 4 byte
  sized and can still address the same entry size.
* kBufferSize is no longer one less than it could be.
* "traced" command:
  - Use static variable for the iteration state rather then cluttering
    the temporary debug variable name space.
  - The <count> parameter can now be negative, in which case the entries
    before (and including) <start> are printed.
  - Added a new optional parameter, specifying the maximal number of
    entries to be filtered. Filtered iteration is beautifully
    comfortable now.


git-svn-id: file:///srv/svn/repos/haiku/haiku/trunk@23678 a95241bf-73f2-0310-859d-f6bbb57e9c96

headers/private/kernel/tracing.h

@@ -11,8 +11,9 @@
 
 
 struct trace_entry {
-	uint16  size;
+	uint32	size			: 14;		// actual size is *4
-	uint16  flags;
+	uint32	previous_size	: 14;		// actual size is *4
+	uint32	flags			: 4;
 };
 
 #ifdef __cplusplus
@@ -37,7 +38,7 @@ class TraceOutput {
 		size_t	fSize;
 };
 
-class TraceEntry : trace_entry {
+class TraceEntry : public trace_entry {
 	public:
 		TraceEntry();
 		virtual ~TraceEntry();

src/system/kernel/debug/tracing.cpp

@@ -31,7 +31,7 @@ enum {
 	BUFFER_ENTRY		= 0x04
 };
 
-static const size_t kBufferSize = MAX_TRACE_SIZE / 4 - 1;
+static const size_t kBufferSize = MAX_TRACE_SIZE / 4;
 
 static trace_entry* sBuffer;
 static trace_entry* sFirstEntry;
@@ -44,7 +44,7 @@ static spinlock sLock;
 static trace_entry*
 next_entry(trace_entry* entry)
 {
-	entry += entry->size >> 2;
+	entry += entry->size;
 	if ((entry->flags & WRAP_ENTRY) != 0)
 		entry = sBuffer;
 
@@ -55,10 +55,25 @@ next_entry(trace_entry* entry)
 }
 
 
+static trace_entry*
+previous_entry(trace_entry* entry)
+{
+	if (entry == sFirstEntry)
+		return NULL;
+
+	if (entry == sBuffer) {
+		// beginning of buffer -- previous entry is a wrap entry
+		entry = sBuffer + kBufferSize - entry->previous_size;
+	}
+
+	return entry - entry->previous_size;
+}
+
+
 static bool
 free_first_entry()
 {
-	TRACE(("  skip start %p, %u bytes\n", sFirstEntry, sFirstEntry->size));
+	TRACE(("  skip start %p, %lu*4 bytes\n", sFirstEntry, sFirstEntry->size));
 
 	trace_entry* newFirst = next_entry(sFirstEntry);
 
@@ -88,34 +103,41 @@ free_first_entry()
 }
 
 
+/*!	Makes sure we have needed * 4 bytes of memory at sAfterLastEntry.
+	Returns \c false, if unable to free that much.
+*/
 static bool
 make_space(size_t needed)
 {
 	// we need space for sAfterLastEntry, too (in case we need to wrap around
 	// later)
-	needed += 4;
+	needed++;
 
 	// If there's not enough space (free or occupied) after sAfterLastEntry,
 	// we free all entries in that region and wrap around.
-	if (sAfterLastEntry + needed / 4 > sBuffer + kBufferSize) {
+	if (sAfterLastEntry + needed > sBuffer + kBufferSize) {
 		TRACE(("make_space(%lu), wrapping around: after last: %p\n", needed,
 			sAfterLastEntry));
 
 		// Free all entries after sAfterLastEntry and one more at the beginning
 		// of the buffer.
-		do {
+		while (sFirstEntry > sAfterLastEntry) {
 			if (!free_first_entry())
 				return false;
-		} while (sFirstEntry > sAfterLastEntry);
+		}
+		if (sAfterLastEntry != sBuffer && !free_first_entry())
+			return false;
 
 		// just in case free_first_entry() freed the very last existing entry
 		if (sAfterLastEntry == sBuffer)
 			return true;
 
 		// mark as wrap entry and actually wrap around
-		sAfterLastEntry->size = 0;
+		trace_entry* wrapEntry = sAfterLastEntry;
-		sAfterLastEntry->flags = WRAP_ENTRY;
+		wrapEntry->size = 0;
+		wrapEntry->flags = WRAP_ENTRY;
 		sAfterLastEntry = sBuffer;
+		sAfterLastEntry->previous_size = sBuffer + kBufferSize - wrapEntry;
 	}
 
 	if (sFirstEntry <= sAfterLastEntry) {
@@ -124,7 +146,7 @@ make_space(size_t needed)
 	}
 
 	// free the first entries, until there's enough space
-	size_t space = (sFirstEntry - sAfterLastEntry) * 4;
+	size_t space = sFirstEntry - sAfterLastEntry;
 
 	if (space < needed) {
 		TRACE(("make_space(%lu), left %ld\n", needed, space));
@@ -151,9 +173,10 @@ allocate_entry(size_t size, uint16 flags)
 
 	InterruptsSpinLocker _(sLock);
 
-	size = (size + 3) & ~3;
+	size = (size + 3) >> 2;
+		// 4 byte aligned, don't store the lower 2 bits
 
-	TRACE(("allocate_entry(%lu), start %p, end %p, buffer %p\n", size,
+	TRACE(("allocate_entry(%lu), start %p, end %p, buffer %p\n", size * 4,
 		sFirstEntry, sAfterLastEntry, sBuffer));
 
 	if (!make_space(size))
@@ -162,7 +185,8 @@ allocate_entry(size_t size, uint16 flags)
 	trace_entry* entry = sAfterLastEntry;
 	entry->size = size;
 	entry->flags = flags;
-	sAfterLastEntry += size >> 2;
+	sAfterLastEntry += size;
+	sAfterLastEntry->previous_size = size;
 
 	if (!(flags & BUFFER_ENTRY))
 		sEntries++;
@@ -484,14 +508,132 @@ TraceFilterParser TraceFilterParser::sParser;
 #if ENABLE_TRACING
 
 
+class TraceEntryIterator {
+public:
+	TraceEntryIterator(bool startFront)
+		:
+		fEntry(NULL),
+		fIndex(startFront ? 0 : sEntries + 1)
+	{
+	}
+
+	int32 Index() const
+	{
+		return fIndex;
+	}
+
+	TraceEntry* Current() const
+	{
+		return (TraceEntry*)fEntry;
+	}
+
+	TraceEntry* Next()
+	{
+		if (fIndex == 0) {
+			fEntry = _NextNonBufferEntry(sFirstEntry);
+			fIndex = 1;
+		} else if (fEntry != NULL) {
+			fEntry = _NextNonBufferEntry(next_entry(fEntry));
+			fIndex++;
+		}
+
+		return Current();
+	}
+
+	TraceEntry* Previous()
+	{
+		if (fIndex == (int32)sEntries + 1)
+			fEntry = sAfterLastEntry;
+
+		if (fEntry != NULL) {
+			fEntry = _PreviousNonBufferEntry(previous_entry(fEntry));
+			fIndex--;
+		}
+
+		return Current();
+	}
+
+	TraceEntry* MoveTo(int32 index)
+	{
+		if (index == fIndex)
+			return Current();
+
+		if (index <= 0 || index > (int32)sEntries) {
+			fIndex = (index <= 0 ? 0 : sEntries + 1);
+			fEntry = NULL;
+			return NULL;
+		}
+
+		// get the shortest iteration path
+		int32 distance = index - fIndex;
+		int32 direction = distance < 0 ? -1 : 1;
+		distance *= direction;
+
+		if (index < distance) {
+			distance = index;
+			direction = 1;
+			fEntry = NULL;
+			fIndex = 0;
+		}
+		if ((int32)sEntries + 1 - fIndex < distance) {
+			distance = sEntries + 1 - fIndex;
+			direction = -1;
+			fEntry = NULL;
+			fIndex = sEntries + 1;
+		}
+
+		// iterate to the index
+		if (direction < 0) {
+			while (fIndex != index)
+				Previous();
+		} else {
+			while (fIndex != index)
+				Next();
+		}
+
+		return Current();
+	}
+
+private:
+	trace_entry* _NextNonBufferEntry(trace_entry* entry)
+	{
+		while (entry != NULL && (entry->flags & BUFFER_ENTRY) != 0)
+			entry = next_entry(entry);
+
+		return entry;
+	}
+
+	trace_entry* _PreviousNonBufferEntry(trace_entry* entry)
+	{
+		while (entry != NULL && (entry->flags & BUFFER_ENTRY) != 0)
+			entry = previous_entry(entry);
+
+		return entry;
+	}
+
+private:
+	trace_entry*	fEntry;
+	int32			fIndex;
+};
+
+
 int
 dump_tracing(int argc, char** argv)
 {
 	int argi = 1;
 
+	// variables in which we store our state to be continuable
+	static int32 _previousCount = 0;
+	static bool _previousHasFilter = false;
+	static int32 _previousMaxToCheck = 0;
+	static int32 _previousFirstChecked = 1;
+	static int32 _previousLastChecked = -1;
+	static uint32 _previousWritten = 0;
+
 	// Note: start and index are Pascal-like indices (i.e. in [1, sEntries]).
-	int32 count = 30;
 	int32 start = 0;	// special index: print the last count entries
+	int32 count = 0;
+	int32 maxToCheck = 0;
 	int32 cont = 0;
 
 	bool hasFilter = false;
@@ -506,33 +648,29 @@ dump_tracing(int argc, char** argv)
 		}
 	}
 
-	if (cont != 0 && argi < argc) {
+	if (cont != 0) {
-		print_debugger_command_usage(argv[0]);
+		if (argi < argc) {
-		return 0;
+			print_debugger_command_usage(argv[0]);
-	}
+			return 0;
-
+		}
-	// start
+		if (sWritten == 0 || sWritten != _previousWritten) {
-	if (argi < argc) {
+			kprintf("Can't continue iteration. \"%s\" has not been invoked "
-		if (strcmp(argv[argi], "filter") == 0) {
+				"before, or there were new entries written since the last "
-			hasFilter = true;
+				"invocation.\n", argv[0]);
-			argi++;
+			return 0;
-		} else if (argv[argi][0] == '#') {
-			hasFilter = true;
-		} else {
-			start = parse_expression(argv[argi]);
-			argi++;
 		}
 	}
 
-	// count
+	// get start, count, maxToCheck
-	if (!hasFilter && argi < argc) {
+	int32* params[3] = { &start, &count, &maxToCheck };
+	for (int i = 0; i < 3 && !hasFilter && argi < argc; i++) {
 		if (strcmp(argv[argi], "filter") == 0) {
 			hasFilter = true;
 			argi++;
 		} else if (argv[argi][0] == '#') {
 			hasFilter = true;
 		} else {
-			count = parse_expression(argv[argi]);
+			*params[i] = parse_expression(argv[argi]);
 			argi++;
 		}
 	}
@@ -549,56 +687,126 @@ dump_tracing(int argc, char** argv)
 		}
 	}
 
+	int32 direction;
+	int32 firstToCheck;
+	int32 lastToCheck;
+
 	if (cont != 0) {
-		start = get_debug_variable("_tracingStart", start);
+		// get values from the previous iteration
-		count = get_debug_variable("_tracingCount", count);
+		direction = cont;
-		start = max_c(1, start + count * cont);
+		count = _previousCount;
-		hasFilter = get_debug_variable("_tracingFilter", count);
+		maxToCheck = _previousMaxToCheck;
+		hasFilter = _previousHasFilter;
+
+		if (direction < 0)
+			start = _previousFirstChecked - 1;
+		else
+			start = _previousLastChecked + 1;
+	} else {
+		// defaults for count and maxToCheck
+		if (count == 0)
+			count = 30;
+		if (maxToCheck == 0 || !hasFilter)
+			maxToCheck = count;
+		else if (maxToCheck < 0)
+			maxToCheck = sEntries;
+
+		// determine iteration direction
+		direction = (start <= 0 || count < 0 ? -1 : 1);
+
+		// validate count and maxToCheck
+		if (count < 0)
+			count = -count;
+		if (maxToCheck < 0)
+			maxToCheck = -maxToCheck;
+		if (maxToCheck > (int32)sEntries)
+			maxToCheck = sEntries;
+		if (count > maxToCheck)
+			count = maxToCheck;
+
+		// validate start
+		if (start <= 0 || start > (int32)sEntries)
+			start = max_c(1, sEntries);
 	}
 
-	if ((uint32)count > sEntries)
+	if (direction < 0) {
-		count = sEntries;
+		firstToCheck = max_c(1, start - maxToCheck + 1);
-	if (start <= 0)
+		lastToCheck = start;
-		start = max_c(1, sEntries - count + 1);
+	} else {
-	if (uint32(start + count) > sEntries)
+		firstToCheck = start;
-		count = sEntries - start + 1;
+		lastToCheck = min_c((int32)sEntries, start + maxToCheck - 1);
+	}
+
+	TraceEntryIterator iterator(true);
+
+	char buffer[256];
+	LazyTraceOutput out(buffer, sizeof(buffer));
+
+	if (direction < 0 && hasFilter && lastToCheck - firstToCheck >= count) {
+		// iteration direction is backwards
+
+		// From the last entry to check iterate backwards to check filter
+		// matches.
+		int32 matching = 0;
+
+		// move to the entry after the last entry to check
+		iterator.MoveTo(lastToCheck + 1);
+
+		// iterate backwards
+		while (iterator.Index() > firstToCheck) {
+			TraceEntry* entry = iterator.Previous();
+			if ((entry->flags & ENTRY_INITIALIZED) != 0) {
+				out.Clear();
+				if (TraceFilterParser::Default()->Filter(entry, out)) {
+					matching++;
+					if (matching >= count)
+						break;
+				}
+			}
+		}
+
+		firstToCheck = iterator.Index();
+
+		// iterate to the previous entry, so that the next loop starts at the
+		// right one
+		iterator.Previous();
+	}
 
-	int32 index = 1;
 	int32 dumped = 0;
 
-	for (trace_entry* current = sFirstEntry; current != NULL;
+	while (TraceEntry* entry = iterator.Next()) {
-			current = next_entry(current), index++) {
+		int32 index = iterator.Index();
-		if ((current->flags & BUFFER_ENTRY) != 0) {
+		if (index < firstToCheck)
-			// skip buffer entries
-			index--;
 			continue;
-		}
+		if (index > lastToCheck || dumped >= count) {
-		if (index < start)
+			if (direction > 0)
-			continue;
+				lastToCheck = index - 1;
-		if (index >= start + count)
 			break;
+		}
 
-		if ((current->flags & ENTRY_INITIALIZED) != 0) {
+		if ((entry->flags & ENTRY_INITIALIZED) != 0) {
-			char buffer[256];
+			out.Clear();
-			LazyTraceOutput out(buffer, sizeof(buffer));
-			
-			TraceEntry* entry = (TraceEntry*)current;
 			if (hasFilter && !TraceFilterParser::Default()->Filter(entry, out))
 				continue;
 
 			kprintf("%5ld. %s\n", index, out.DumpEntry(entry));
-		} else
+		} else if (!hasFilter)
 			kprintf("%5ld. ** uninitialized entry **\n", index);
 
 		dumped++;
 	}
 
-	kprintf("entries %ld to %ld (%ld of %ld). %ld entries written\n", start,
+	kprintf("printed %ld entries within range %ld to %ld (%ld of %ld total, "
-		start + count - 1, dumped, sEntries, sWritten);
+		"%ld ever)\n", dumped, firstToCheck, lastToCheck,
+		lastToCheck - firstToCheck + 1, sEntries, sWritten);
 
-	set_debug_variable("_tracingStart", start);
+	// store iteration state
-	set_debug_variable("_tracingCount", count);
+	_previousCount = count;
-	set_debug_variable("_tracingFilter", hasFilter);
+	_previousMaxToCheck = maxToCheck;
+	_previousHasFilter = hasFilter;
+	_previousFirstChecked = firstToCheck;
+	_previousLastChecked = lastToCheck;
+	_previousWritten = sWritten;
 
 	return cont != 0 ? B_KDEBUG_CONT : 0;
 }
@@ -691,18 +899,33 @@ tracing_init(void)
 
 	add_debugger_command_etc("traced", &dump_tracing,
 		"Dump recorded trace entries",
-		"(\"forward\" | \"backward\") | ([ <start> [ <count> ] ] "
+		"(\"forward\" | \"backward\") | ([ <start> [ <count> [ <range> ] ] ] "
 			"[ #<pattern> | (\"filter\" <filter>) ])\n"
 		"Prints recorded trace entries. If \"backward\" or \"forward\" is\n"
 		"specified, the command continues where the previous invocation left\n"
 		"off, i.e. printing the previous respectively next entries (as many\n"
 		"as printed before). In this case the command is continuable, that is\n"
 		"afterwards entering an empty line in the debugger will reinvoke it.\n"
-		"  <start>    - The index of the first entry to print. The index of\n"
+		"  <start>    - The base index of the entries to print. Depending on\n"
-		"               the first recorded entry is 1. If 0 is specified, the\n"
+		"               whether the iteration direction is forward or\n"
-		"               last <count> recorded entries are printed. Defaults \n"
+		"               backward this will be the first or last entry printed\n"
+		"               (potentially, if a filter is specified). The index of\n"
+		"               the first entry in the trace buffer is 1. If 0 is\n"
+		"               specified, the last <count> recorded entries are\n"
+		"               printed (iteration direction is backward). Defaults \n"
 		"               to 0.\n"
 		"  <count>    - The number of entries to be printed. Defaults to 30.\n"
+		"               If negative, the -<count> entries before and\n"
+		"               including <start> will be printed.\n"
+		"  <range>    - Only relevant if a filter is specified. Specifies the\n"
+		"               number of entries to be filtered -- depending on the\n"
+		"               iteration direction the entries before or after\n"
+		"               <start>. If more than <count> entries match the\n"
+		"               filter, only the first (forward) or last (backward)\n"
+		"               <count> matching entries will be printed. If 0 is\n"
+		"               specified <range> will be set to <count>. If -1,\n"
+		"               <range> will be set to the number of recorded\n"
+		"               entries.\n"
 		"  <pattern>  - If specified only entries containing this string are\n"
 		"               printed.\n"
 		"  <filter>   - If specified only entries matching this filter\n"