quiet flag should be the first thing the print (and related) methods check

[eblis]

I'm using rich.print() to print some pretty stuff to console for Advent of Code, but when I'm running with the final version I usually set quiet=True for the rich.console.Console() object I've created.

But there's a huge performance issue with using rich, even if in quiet mode.
I've run today's problem in 10!!!! minutes with rich.console.Console with quiet=True whereas if I put all the calls to console.print() in a wrapper method that check the quiet flag and only delegates to console.print() if not quiet I get the execution down to 10-12 seconds.

[willmcgugan]

What are you doing that is taking 10 minutes to execute?

[eblis]

This is the code

import datetime
import time
from math import prod

import rich.console

console = rich.console.Console(color_system="truecolor", soft_wrap=True, force_terminal=True, legacy_windows=False, quiet=True)

CHECK_FOR_QUIET = True

INPUT = """Monkey 0:
  Starting items: 89, 84, 88, 78, 70
  Operation: new = old * 5
  Test: divisible by 7
    If true: throw to monkey 6
    If false: throw to monkey 7

Monkey 1:
  Starting items: 76, 62, 61, 54, 69, 60, 85
  Operation: new = old + 1
  Test: divisible by 17
    If true: throw to monkey 0
    If false: throw to monkey 6

Monkey 2:
  Starting items: 83, 89, 53
  Operation: new = old + 8
  Test: divisible by 11
    If true: throw to monkey 5
    If false: throw to monkey 3

Monkey 3:
  Starting items: 95, 94, 85, 57
  Operation: new = old + 4
  Test: divisible by 13
    If true: throw to monkey 0
    If false: throw to monkey 1

Monkey 4:
  Starting items: 82, 98
  Operation: new = old + 7
  Test: divisible by 19
    If true: throw to monkey 5
    If false: throw to monkey 2

Monkey 5:
  Starting items: 69
  Operation: new = old + 2
  Test: divisible by 2
    If true: throw to monkey 1
    If false: throw to monkey 3

Monkey 6:
  Starting items: 82, 70, 58, 87, 59, 99, 92, 65
  Operation: new = old * 11
  Test: divisible by 5
    If true: throw to monkey 7
    If false: throw to monkey 4

Monkey 7:
  Starting items: 91, 53, 96, 98, 68, 82
  Operation: new = old * old
  Test: divisible by 3
    If true: throw to monkey 4
    If false: throw to monkey 2"""


def pprint(message):
    if not (console.quiet and CHECK_FOR_QUIET):
        console.print(message)


class Measure:
    def __init__(self, name):
        self.console = console
        self.name = name
        self.start = None
        self.end = None

    def __enter__(self):
        self.console.rule(f"Starting {self.name}")
        self.start = time.perf_counter()

    def __exit__(self, exc_type, exc_val, exc_tb):
        self.end = time.perf_counter()
        dur = datetime.timedelta(seconds=self.end - self.start)
        if self.console.quiet:
            print(f"{self.name} took {dur}")
        else:
            self.console.rule(f"{self.name} took {dur}")


class Operation:
    def __init__(self, line):
        s = line.split("= ")
        p = s[1].split(" ")
        self.op = p[1]
        self.value = p[2]

    def _with(self, value):
        if self.value == "old":
            return value
        else:
            return int(self.value)

    def apply(self, value):
        w = self._with(value)

        if self.op == "*":
            return value * w
        elif self.op == "+":
            return value + w
        elif self.op == "-":
            return value - w
        elif self.op == "/":
            return value // w

    def __str__(self):
        return f"{self.op}:{self.value}"

    def __repr__(self):
        return self.__str__()


class Test:
    def __init__(self, lines):
        s = lines[0].split(": ")
        p = s[1].split(" ")
        self.test = p[0]
        self.value = int(p[2])
        self.yes = int(lines[1].split("monkey ")[1])
        self.no = int(lines[2].split("monkey ")[1])

    def check(self, value):
        divisible = self.yes if value % self.value == 0 else self.no
        str = "is" if divisible else "is NOT"
        pprint(f"\tCurrent worry level {value} {str} by {self.value}")
        return divisible

    def __str__(self):
        return f"{self.test}:{self.value}->{self.yes} vs {self.no}"

    def __repr__(self):
        return self.__str__()


class Monkey:
    def __init__(self, lines):
        self.name = int(lines[0].split(" ")[1].split(":")[0])
        self.count = 0
        s = lines[1].split(": ")
        it = s[1].split(", ")
        self.items = [int(x) for x in it]
        self.operation = Operation(lines[2])

        self.test = Test(lines[3:])

    def inspect(self):
        new_items = []
        for item in self.items:
            self.count += 1
            pprint(f"\tMonkey {self.name} inspects an item with a worry level of {item}")
            new_items.append(self.operation.apply(item))
            pprint(f"\tWorry level is multiplied by {self.operation.value} to {new_items[-1]}")
        self.items = new_items

    def relief(self, divisor):
        self.items = [x % divisor for x in self.items]

    def throw(self):
        recipients = []
        for item in self.items:
            recipients.append(self.test.check(item))
        return recipients

    def __str__(self):
        return f"{self.name}:{self.items}->{self.operation} and {self.test}"

    def __repr__(self):
        return self.__str__()


class Puzzle:
    def __init__(self, monkeys):
        self.monkeys = monkeys

    def compute(self, count):
        turn = 0
        divisor = prod([x.test.value for x in self.monkeys])
        while turn < count:
            pprint(f"Turn {turn}")
            for monkey in self.monkeys:
                pprint(f"Monkey {monkey.name}")
                monkey.inspect()
                monkey.relief(divisor)
                self.throw(monkey)

            turn += 1
        for monkey in self.monkeys:
            pprint(f"Monkey {monkey.name} inspected {monkey.count}")
        x = sorted([monkey.count for monkey in self.monkeys])
        business = x[-2] * x[-1]
        print(f"Monkey business is {business}")

    def get_monkey(self, name):
        for monkey in self.monkeys:
            if monkey.name == name:
                return monkey
        raise Exception(f"Could not find monkey {name}")

    def throw(self, monkey: Monkey):
        recipients = monkey.throw()
        for recipient in recipients:
            item = monkey.items.pop(0)
            new = self.get_monkey(recipient)
            new.items.append(item)
            pprint(f"Item with worry level {item} is thrown to monkey {recipient}")


def get_data(path):
    monkeys = []
    lines = []
    for line in INPUT.split("\n"):
        line = line.strip()
        if not line or len(line) <= 0:
            monkeys.append(Monkey(lines))
            lines.clear()
            continue

        lines.append(line)
    monkeys.append(Monkey(lines))

    return Puzzle(monkeys)


def compute_1(puzzle):
    with Measure("Round 1"):
        puzzle.compute(20)


def compute_2(puzzle):
    with Measure("Round 2"):
        puzzle.compute(10_000)


def main(path):
    compute_1(get_data(path))
    compute_2(get_data(path))


if __name__ == "__main__":
    main("12.txt")

This is the result with CHECK_FOR_QUIET = False

Monkey business is 58804
Round 1 took 0:00:01.185680
Monkey business is 14636993466
Round 2 took 0:09:19.726046

and this is the result if CHECK_FOR_QUIET = True

Monkey business is 58804
Round 1 took 0:00:00.002637
Monkey business is 14636993466
Round 2 took 0:00:01.311456

The flag is used in pprint to check if it should call console.print() or not.

[eblis]

These are some statistics from a profiling run:

[eblis]

Moving the check for quiet higher up the call seems to be resulting in a huge performance improvement.
Am i missing a reason why this can't be easily done ?