From 40b68a710236f0076854ff9bb68ee22fd6e70bdb Mon Sep 17 00:00:00 2001 From: bplu4t2f Date: Thu, 8 Oct 2026 21:26:14 +0200 Subject: [PATCH] Experimental hot path optimization in XML test. --- tests/core/encoding/xml/test_core_xml.odin | 132 ++++++++++++++++----- 1 file changed, 101 insertions(+), 31 deletions(-) diff --git a/tests/core/encoding/xml/test_core_xml.odin b/tests/core/encoding/xml/test_core_xml.odin index 564ee05d6..4b9a13c94 100644 --- a/tests/core/encoding/xml/test_core_xml.odin +++ b/tests/core/encoding/xml/test_core_xml.odin @@ -4,10 +4,10 @@ import "core:encoding/entity" import "core:encoding/xml" import "core:testing" import "core:strings" -import "core:io" import "core:fmt" import "core:log" import "core:hash" +import "core:time" Silent :: proc(pos: xml.Pos, format: string, args: ..any) {} @@ -196,14 +196,34 @@ run_test :: proc(t: ^testing.T, test: TEST, loc := #caller_location) { path := strings.concatenate({TEST_SUITE_PATH, test.filename}) defer delete(path) - doc, err := xml.load_from_file(path, test.options, Silent) - defer xml.destroy(doc) + sw: time.Stopwatch - tree_string := doc_to_string(doc) + log.infof("Starting xml.load_from_file...") + time.stopwatch_reset(&sw) + time.stopwatch_start(&sw) + doc, err := xml.load_from_file(path, test.options, Silent) + log.infof("Finished xml.load_from_file: %v", time.stopwatch_duration(sw)) + defer { + log.infof("Starting xml.destroy...") + time.stopwatch_reset(&sw) + time.stopwatch_start(&sw) + xml.destroy(doc) + log.infof("Finished xml.destroy: %v", time.stopwatch_duration(sw)) + } + + log.infof("Starting doc_to_string...") + time.stopwatch_reset(&sw) + time.stopwatch_start(&sw) + tree_string := doc_to_string(doc, capacity = 20_000_000) + log.infof("Finished doc_to_string: %v", time.stopwatch_duration(sw)) tree_bytes := transmute([]u8)tree_string defer delete(tree_bytes) + log.infof("Starting hash.crc32...") + time.stopwatch_reset(&sw) + time.stopwatch_start(&sw) crc32 := hash.crc32(tree_bytes) + log.infof("Finished hash.crc32: %v", time.stopwatch_duration(sw)) failed := err != test.err testing.expectf(t, err == test.err, "%v: Expected return value %v, got %v", test.filename, test.err, err, loc=loc) @@ -241,8 +261,31 @@ test_normalize_whitespace :: proc(t: ^testing.T) { testing.expect_value(t, attr[0].val, "A & B") } +doc_to_string_indent := [?]string { + "\t", + "\t\t", + "\t\t\t", + "\t\t\t\t", + "\t\t\t\t\t", + "\t\t\t\t\t\t", + "\t\t\t\t\t\t\t", // I am having fun :) + "\t\t\t\t\t\t\t\t", + "\t\t\t\t\t\t\t\t\t", + "\t\t\t\t\t\t\t\t\t\t", + "\t\t\t\t\t\t\t\t\t\t\t", + "\t\t\t\t\t\t\t\t\t\t\t\t", + "\t\t\t\t\t\t\t\t\t\t\t\t\t", + "\t\t\t\t\t\t\t\t\t\t\t\t\t\t", + "\t\t\t\t\t\t\t\t\t\t\t\t\t\t\t", + "\t\t\t\t\t\t\t\t\t\t\t\t\t\t\t\t", + "\t\t\t\t\t\t\t\t\t\t\t\t\t\t\t\t\t", + "\t\t\t\t\t\t\t\t\t\t\t\t\t\t\t\t\t\t", + "\t\t\t\t\t\t\t\t\t\t\t\t\t\t\t\t\t\t\t", + "\t\t\t\t\t\t\t\t\t\t\t\t\t\t\t\t\t\t\t\t", +} + @(private) -doc_to_string :: proc(doc: ^xml.Document) -> (result: string) { +doc_to_string :: proc(doc: ^xml.Document, capacity: int) -> (result: string) { /* Effectively a clone of the debug printer in the xml package. We duplicate it here so that the way it prints an XML document to a string is stable. @@ -250,43 +293,43 @@ doc_to_string :: proc(doc: ^xml.Document) -> (result: string) { This way we can hash the output. If it changes, it means that the document or how it was parsed changed, not how it was printed. One less source of variability. */ - print :: proc(writer: io.Writer, doc: ^xml.Document) -> (written: int, err: io.Error) { + print :: proc(writer: ^strings.Builder, doc: ^xml.Document) { if doc == nil { return } - written += fmt.wprintf(writer, "[XML Prolog]\n") + fmt.sbprintf(writer, "[XML Prolog]\n") for attr in doc.prologue { - written += fmt.wprintf(writer, "\t%v: %v\n", attr.key, attr.val) + fmt.sbprintf(writer, "\t%v: %v\n", attr.key, attr.val) } - written += fmt.wprintf(writer, "[Encoding] %v\n", doc.encoding) + fmt.sbprintf(writer, "[Encoding] %v\n", doc.encoding) if len(doc.doctype.ident) > 0 { - written += fmt.wprintf(writer, "[DOCTYPE] %v\n", doc.doctype.ident) + fmt.sbprintf(writer, "[DOCTYPE] %v\n", doc.doctype.ident) if len(doc.doctype.rest) > 0 { - fmt.wprintf(writer, "\t%v\n", doc.doctype.rest) + fmt.sbprintf(writer, "\t%v\n", doc.doctype.rest) } } for comment in doc.comments { - written += fmt.wprintf(writer, "[Pre-root comment] %v\n", comment) + fmt.sbprintf(writer, "[Pre-root comment] %v\n", comment) } if doc.element_count > 0 { - fmt.wprintln(writer, " --- ") + fmt.sbprintln(writer, " --- ") print_element(writer, doc, 0) - fmt.wprintln(writer, " --- ") + fmt.sbprintln(writer, " --- ") } - - return written, .None } - print_element :: proc(writer: io.Writer, doc: ^xml.Document, element_id: xml.Element_ID, indent := 0) -> (written: int, err: io.Error) { - tab :: proc(writer: io.Writer, indent: int) { - for _ in 0..=indent { - fmt.wprintf(writer, "\t") - } + print_element :: proc(writer: ^strings.Builder, doc: ^xml.Document, element_id: xml.Element_ID, indent := 0) { + tab :: #force_inline proc(writer: ^strings.Builder, indent: int) { + // PERF: Hot + strings.write_string(writer, doc_to_string_indent[indent]) + //for _ in 0..=indent { + // fmt.wprintf(writer, "\t") + //} } tab(writer, indent) @@ -294,32 +337,59 @@ doc_to_string :: proc(doc: ^xml.Document) -> (result: string) { element := doc.elements[element_id] if element.kind == .Element { - fmt.wprintf(writer, "<%v>\n", element.ident) + // PERF: lukewarm + //fmt.wprintf(writer, "%v<%v>\n", doc_to_string_indent[indent], element.ident) + strings.write_string(writer, "<") + strings.write_string(writer, element.ident) + strings.write_string(writer, ">\n") for value in element.value { switch v in value { case string: + // PERF: A little bit hot tab(writer, indent + 1) - fmt.wprintf(writer, "[Value] %v\n", v) + //fmt.wprintf(writer, "[Value] %v\n", v) + strings.write_string(writer, "[Value] ") + strings.write_string(writer, v) + strings.write_string(writer, "\n") case xml.Element_ID: print_element(writer, doc, v, indent + 1) } } for attr in element.attribs { + // PERF: Hot tab(writer, indent + 1) - fmt.wprintf(writer, "[Attr] %v: %v\n", attr.key, attr.val) + //fmt.wprintf(writer, "[Attr] %v: %v\n", attr.key, attr.val) + strings.write_string(writer, "[Attr] ") + strings.write_string(writer, attr.key) + strings.write_string(writer, ": ") + strings.write_string(writer, attr.val) + strings.write_string(writer, "\n") } } else if element.kind == .Comment { - fmt.wprintf(writer, "[COMMENT] %v\n", element.value) + // PERF: Cold + fmt.sbprintf(writer, "[COMMENT] %v\n", element.value) } - - return written, .None } - buf: strings.Builder - defer strings.builder_destroy(&buf) + // TODO: strings.write_rune is way slower than strings.write_string + // TODO: fmt.sbprintf is slower than fmt.wprintf - print(strings.to_writer(&buf), doc) - return strings.clone(strings.to_string(buf)) + buf: strings.Builder + if capacity > 0 { + strings.builder_init_len_cap(&buf, 0, capacity) + } else { + assert(false) + } + + print(&buf, doc) + + result = strings.to_string(buf) + if len(result) < capacity - 1000 { + log.infof("Document converted to debug string - result length: %v", len(result)) + } else { + log.warnf("Document converted to debug string - result length: %v - initial string builder capacity: %v - please increase capacity for better performance.", len(result), capacity) + } + return } \ No newline at end of file