Text.find slows down with the number of invocations

[4e6]

I encountered the issue when solving Advent Of Code day 13.

I created a project reproducing the issue Text_Find_Bench.zip It contains a bench.txt file with a sequence of lines to parse:

Button A: X+46, Y+89
Button B: X+99, Y+32
Prize: X=5826, Y=7443

Button ...

Then the function parse_input parses those lines, printing how many lines is left to parse:

parse_input lines =
    go input acc =
        if input.is_empty then acc else
            p = input.take 4
            m = Main.parse_machine p
            IO.println ('lines remain: ' + input.length.to_text)
            @Tail_Call go (input.drop 4) acc+1
    go lines 0

When running the program, you can see how the lines remain output slows down with the number of lines parsed:

Text_Find_Bench.mp4

[JaroslavTulach]

@4e6, I am converting your code to a benchmark like this:

diff --git test/Benchmarks/src/Text/Contains.enso test/Benchmarks/src/Text/Contains.enso
index 75b7694c31..dd682d668a 100644
--- test/Benchmarks/src/Text/Contains.enso
+++ test/Benchmarks/src/Text/Contains.enso
@@ -1,4 +1,5 @@
 from Standard.Base import all
+from Standard.Base.Runtime import assert
 
 from Standard.Test import Bench, Faker
 
@@ -33,7 +34,7 @@ create_big_random character_template faker =
     Vector.new 200 _-> faker.text_value big_template
 
 
-collect_benches = Bench.build builder->
+collect_benches aoc_count=2 = Bench.build builder->
     bench_contains group_name character_template =
 
         data = Data.create character_template Faker.new
@@ -47,5 +48,66 @@ collect_benches = Bench.build builder->
 
     bench_contains "Text_Contains" (Faker.upper_case_letters + Faker.lower_case_letters + 'ąę\u{301}\u{302}\u{303}\u{321}'.char_vector)
 
-
-main = collect_benches . run_main
+    aoc_options = Bench.options . set_warmup (Bench.phase_conf 10 3) . set_measure (Bench.phase_conf aoc_count 3)
+
+    builder.group "AoC_2024_Day_13" aoc_options group_builder->
+        parse_button node1 =
+            any2 = node1.find 'Button \\w: X[+](\\d+), Y[+](\\d+)'
+            vector2 = any2.groups
+            node2 = vector2.at 1
+            node3 = vector2.at 2
+            vector3 = [node2, node3]
+            vector3
+
+        parse_prize node3 =
+            any3 = node3.find 'Prize: X=(\\d+), Y=(\\d+)'
+            vector2 = any3.groups
+            node4 = vector2.at 1
+            node5 = vector2.at 2
+            vector4 = [node4, node5]
+            vector4
+
+        parse_machine any1 =
+            node1 = any1.at 0
+            node2 = any1.at 1
+            any2 = parse_button node2
+            node3 = any1.at 2
+            vector4 = parse_prize node3
+            vector3 = parse_button node1
+            vector1 = [vector3, any2, vector4]
+            vector2 = vector1.flatten
+            node4 = vector2.map .parse_integer
+            node4
+
+        parse_input (lines:Vector Text) -> Vector =
+            go input acc:Vector =
+                if input.is_empty then acc else
+                    p = input.take 4
+                    m = parse_machine p
+                    @Tail_Call go (input.drop 4) acc+[m]
+            go lines []
+
+        group_builder.specify "find" <|
+            lines = """
+                Button A: X+94, Y+34
+                Button B: X+22, Y+67
+                Prize: X=8400, Y=5400
+
+                Button A: X+26, Y+66
+                Button B: X+67, Y+21
+                Prize: X=12748, Y=12176
+
+                Button A: X+17, Y+86
+                Button B: X+84, Y+37
+                Prize: X=7870, Y=6450
+
+                Button A: X+69, Y+23
+                Button B: X+27, Y+71
+                Prize: X=18641, Y=10279
+
+            res = parse_input (lines.split '\n')
+
+            assert res.length==4 "Expecting four "+res.to_text
+
+main filter=Nothing aoc_count=2 =
+    collect_benches aoc_count . run_main filter

the benchmark is configurable - one can specify the amount of iterations to perform. The following is result of ten iterations:

sbt:enso> runEngineDistribution --run test/Benchmarks/src/Text/Contains.enso .*find.* 10
Measurement avg time:    0.292 ms (+-0.178)

the following is result of one hundred iterations:

sbt:enso> runEngineDistribution --run test/Benchmarks/src/Text/Contains.enso .*find.* 100
Measurement avg time:    0.257 ms (+-0.166)

e.g. I see no slowdown with additional iterations. Btw. this is the output from VisualVM polyglot profiler:

I am not sure what else to investigate. Passing back.

[4e6]

I am converting your code to a benchmark like this
I see no slowdown with additional iterations.

@JaroslavTulach well, have you tried to run the original program? I can still reproduce the issue there