Hello, world!, debugged¶

Info

See the full example source code on GitHub.

Let’s revisit aspects of the previous two “hello, world!” examples and introduce a variety of debugging techniques.

It’s not uncommon to wonder “why isn’t the audio I expect happening?” We have a variety of ways to debug this with Supriya (although your volume could always just be too low).

We’ll employ:

Server logging: Did it boot up? Has it reported any errors?
Server status: Is my sample rate correct? Do the counts of nodes, of synths, of synthdefs make sense to me?
Node tree queries: Is the structure of nodes on the server what I expect?
OSC transcripts: Did I send the messages I thought I sent? Did I receive the message I should have received?

Performance logic¶

The performance logic is almost exactly the same as in the Hello, world!, context-agnostic example:

def play_synths(context: supriya.Context) -> list[supriya.Synth]:
    """
    Play a C-major chord on ``context``.
    """
    # Start an OSC bundle to run immediately:
    with context.at():
        # A C-major chord
        frequencies = [261.63, 329.63, 392.00]
        # Create an empty list to store synths in:
        synths: list[supriya.Synth] = []
        # Add the default synthdef to the server and open a "completion" context
        # manager to group further commands for when the synthdef finishes loading:
        with context.add_synthdefs(supriya.default):
            # Loop over the frequencies:
            for frequency in frequencies:
                # Create a synth using the default synthdef and the frequency
                # and add it to the list of synths:
                synths.append(
                    context.add_synth(synthdef=supriya.default, frequency=frequency)
                )
    return synths

def stop_synths(context: supriya.Context, synths: list[supriya.Synth]) -> None:
    """
    Stop ``synths``.
    """
    # Start an OSC bundle to run immediately:
    with context.at():
        # Loop over the synths and free them
        for synth in synths:
            synth.free()

One small difference, just to save some vertical space in the main() function is to move the use of at() inside the two performance functions. Because we’re querying the context state, the context must be realtime, so we can rely on it supporting timestamp-free OSC bundling.

Debugging¶

OK, let’s debug our performance.

We’ll write a context manager, facilitated by Python’s contextlib.contextmanager() decorator, to debug the state of the server and (optionally!) any operations we performed against it:

@contextlib.contextmanager
def debug(
    header: str,
    server: supriya.Server,
) -> Generator[None, None, None]:
    """
    A context manager for printing debugging information.
    """
    # Capture any OSC messages sent or received
    with server.osc_protocol.capture() as transcript:
        # Yield to the with block body
        yield
    # Print a header
    print(header)
    # Print the server status
    print(f"    Status: {server.status}")
    # Filter out any /status or /status.reply messages from the transcript
    if len(entries := transcript.filtered()):
        print("    Transcript:")
    # Print the OSC transcript's filtered, captured messages
    for entry in entries:
        # A received message
        if entry.label == "R":
            print(f"        Received: {entry.message!r}")
        # A sent message
        else:
            print(f"        Sent:     {entry.message!r}")
    # Print the node tree
    for line in str(server.query_tree()).splitlines():
        print(f"    Tree: {line}")

The context manager will let us start capturing OSC messages sent and received into a transcript, yield so we can perform an action against the server if we wish, and when we’re done yielding we’ll print out:

a header string,
the server’s status,
any messages we sent to or received from the server, excluding the /status and /status.reply messages that are always coming and going during standard operations,
and the server’s node tree.

Integration¶

Now let’s sprinkle that debugging context manager throughout our main() function.

We’ll also turn on logging output (set to a base level of WARNING so we don’t see too much) and then dial in the supriya.scsynth logger to INFO so we can see info about the server during booting and quitting.

def main() -> None:
    """
    The example entry-point function.
    """

    # Turn on basic logging output interpreter-wide.
    # Explicitly set the stream to stdout so that the output looks the same in
    # your terminal as it does in the documentation! Normally you don't need to
    # worry about this.
    logging.basicConfig(level=logging.WARNING, stream=sys.stdout)

    # Set Supriya's supriya.scsynth logger level to INFO
    logging.getLogger("supriya.scsynth").setLevel(logging.INFO)

    # Create a server and boot it:
    server = supriya.Server().boot()

    # Print debug info before we play anything ...
    # Should be just an empty server with the default groups.
    with debug("BEFORE PLAYING:", server):
        pass

    # Print debug info immediately after we play the synths ...
    # No synths should be allocated yet because their SynthDef hasn't finished
    # allocation.
    with debug("IMMEDIATELY AFTER PLAYING:", server):
        synths = play_synths(context=server)

    # Print debug info after syncing with the server ...
    # The synths should now be present.
    with debug("PLAYING:", server):
        server.sync()

    # Print debug info after 4 seconds of waiting ...
    # Nothing should have changed since the synths allocated.
    with debug("JUST BEFORE STOPPING:", server):
        time.sleep(4)

    # Print debug info immediately after stopping the synths
    # The synths are still present, but their "gate" parameters have flipped to
    # zero.
    with debug("IMMEDIATELY AFTER STOPPING:", server):
        stop_synths(context=server, synths=synths)

    # Print debug info after 1 second of waiting ...
    # The synths should now be gone.
    with debug("AFTER RELEASING:", server):
        time.sleep(1)

    # Quit the server
    server.quit()

Note

While the with debug(...):` lines come before the operations we want to debug, their output actually comes after. Inside our debugging context manager, the body of our with block executes at the moment we yield, and everything after the yield keyword occurs when we exit that with block. This might look a little “backwards” in our main() function, but sit with it.

Invocation¶

You can invoke the script and see its (very verbose) output with …

josephine@laptop:~/supriya$ python -m examples.hello_world_debugged
INFO:supriya.scsynth:[127.0.0.1:57110/0x7f97f2f28830] booting ...
INFO:supriya.scsynth:[127.0.0.1:57110/0x7f97f2f28830] command: /usr/local/bin/scsynth -R 0 -l 1 -u 57110
INFO:supriya.scsynth:[127.0.0.1:57110/0x7f97f2f28830] received: Cannot lock down 107341340 byte memory area (Cannot allocate memory)
INFO:supriya.scsynth:[127.0.0.1:57110/0x7f97f2f28830] received: JackDriver: client name is 'SuperCollider'
INFO:supriya.scsynth:[127.0.0.1:57110/0x7f97f2f28830] received: SC_AudioDriver: sample rate = 44100.000000, driver's block size = 1024
INFO:supriya.scsynth:[127.0.0.1:57110/0x7f97f2f28830] received: SuperCollider 3 server ready.
INFO:supriya.scsynth:[127.0.0.1:57110/0x7f97f2f28830] ... booted!
BEFORE PLAYING:
    Status: StatusInfo(actual_sample_rate=44106.022607717845, average_cpu_usage=0.06155474856495857, group_count=2, peak_cpu_usage=0.22713929414749146, synth_count=0, synthdef_count=32, target_sample_rate=44100.0, ugen_count=0)
    Tree: NODE TREE 0 group
    Tree:     1 group
IMMEDIATELY AFTER PLAYING:
    Status: StatusInfo(actual_sample_rate=44106.022607717845, average_cpu_usage=0.06155474856495857, group_count=2, peak_cpu_usage=0.22713929414749146, synth_count=0, synthdef_count=32, target_sample_rate=44100.0, ugen_count=0)
    Transcript:
        Sent:     OscMessage('/d_recv', b'SCgf\x00\x00\x00\x02\x00\x01\x0fsupriya:default\x00\x00\x00\x0c\x00\x00\x00\x00>\x99\x99\x9a<#\xd7\n?333@\x00\x00\x00\xbe\xcc\xcc\xcd>\xcc\xcc\xcdEz\x00\x00E\x9c@\x00E\x1c@\x00EH\x00\x00?\x80\x00\x00\x00\x00\x00\x05\x00\x00\x00\x00=\xcc\xcc\xcdC\xdc\x00\x00?\x80\x00\x00?\x00\x00\x00\x00\x00\x00\x05\x03out\x00\x00\x00\x00\tamplitude\x00\x00\x00\x01\tfrequency\x00\x00\x00\x02\x04gate\x00\x00\x00\x03\x03pan\x00\x00\x00\x04\x00\x00\x00\x14\x07Control\x00\x00\x00\x00\x00\x00\x00\x00\x01\x00\x00\x00\x07Control\x01\x00\x00\x00\x00\x00\x00\x00\x04\x00\x01\x01\x01\x01\x01\x06VarSaw\x02\x00\x00\x00\x03\x00\x00\x00\x01\x00\x00\x00\x00\x00\x01\x00\x00\x00\x01\xff\xff\xff\xff\x00\x00\x00\x00\xff\xff\xff\xff\x00\x00\x00\x01\x02\x05Linen\x01\x00\x00\x00\x05\x00\x00\x00\x01\x00\x00\x00\x00\x00\x01\x00\x00\x00\x02\xff\xff\xff\xff\x00\x00\x00\x02\xff\xff\xff\xff\x00\x00\x00\x03\xff\xff\xff\xff\x00\x00\x00\x01\xff\xff\xff\xff\x00\x00\x00\x04\x01\x04Rand\x00\x00\x00\x00\x02\x00\x00\x00\x01\x00\x00\xff\xff\xff\xff\x00\x00\x00\x05\xff\xff\xff\xff\x00\x00\x00\x00\x00\x0cBinaryOpUGen\x01\x00\x00\x00\x02\x00\x00\x00\x01\x00\x00\x00\x00\x00\x01\x00\x00\x00\x01\x00\x00\x00\x04\x00\x00\x00\x00\x01\x06VarSaw\x02\x00\x00\x00\x03\x00\x00\x00\x01\x00\x00\x00\x00\x00\x05\x00\x00\x00\x00\xff\xff\xff\xff\x00\x00\x00\x00\xff\xff\xff\xff\x00\x00\x00\x01\x02\x04Rand\x00\x00\x00\x00\x02\x00\x00\x00\x01\x00\x00\xff\xff\xff\xff\x00\x00\x00\x00\xff\xff\xff\xff\x00\x00\x00\x06\x00\x0cBinaryOpUGen\x01\x00\x00\x00\x02\x00\x00\x00\x01\x00\x00\x00\x00\x00\x01\x00\x00\x00\x01\x00\x00\x00\x07\x00\x00\x00\x00\x01\x06VarSaw\x02\x00\x00\x00\x03\x00\x00\x00\x01\x00\x00\x00\x00\x00\x08\x00\x00\x00\x00\xff\xff\xff\xff\x00\x00\x00\x00\xff\xff\xff\xff\x00\x00\x00\x01\x02\x04Sum3\x02\x00\x00\x00\x03\x00\x00\x00\x01\x00\x00\x00\x00\x00\x02\x00\x00\x00\x00\x00\x00\x00\x06\x00\x00\x00\x00\x00\x00\x00\t\x00\x00\x00\x00\x02\x0cBinaryOpUGen\x02\x00\x00\x00\x02\x00\x00\x00\x01\x00\x02\x00\x00\x00\n\x00\x00\x00\x00\xff\xff\xff\xff\x00\x00\x00\x01\x02\x04Rand\x00\x00\x00\x00\x02\x00\x00\x00\x01\x00\x00\xff\xff\xff\xff\x00\x00\x00\x07\xff\xff\xff\xff\x00\x00\x00\x08\x00\x04Rand\x00\x00\x00\x00\x02\x00\x00\x00\x01\x00\x00\xff\xff\xff\xff\x00\x00\x00\t\xff\xff\xff\xff\x00\x00\x00\n\x00\x05XLine\x01\x00\x00\x00\x04\x00\x00\x00\x01\x00\x00\x00\x00\x00\x0c\x00\x00\x00\x00\x00\x00\x00\r\x00\x00\x00\x00\xff\xff\xff\xff\x00\x00\x00\x0b\xff\xff\xff\xff\x00\x00\x00\x00\x01\x03LPF\x02\x00\x00\x00\x02\x00\x00\x00\x01\x00\x00\x00\x00\x00\x0b\x00\x00\x00\x00\x00\x00\x00\x0e\x00\x00\x00\x00\x02\x0cBinaryOpUGen\x02\x00\x00\x00\x02\x00\x00\x00\x01\x00\x02\x00\x00\x00\x0f\x00\x00\x00\x00\x00\x00\x00\x03\x00\x00\x00\x00\x02\x0cBinaryOpUGen\x02\x00\x00\x00\x02\x00\x00\x00\x01\x00\x02\x00\x00\x00\x10\x00\x00\x00\x00\x00\x00\x00\x01\x00\x00\x00\x00\x02\x04Pan2\x02\x00\x00\x00\x03\x00\x00\x00\x02\x00\x00\x00\x00\x00\x11\x00\x00\x00\x00\x00\x00\x00\x01\x00\x00\x00\x03\xff\xff\xff\xff\x00\x00\x00\x0b\x02\x02\tOffsetOut\x02\x00\x00\x00\x03\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x12\x00\x00\x00\x00\x00\x00\x00\x12\x00\x00\x00\x01\x00\x00', OscBundle(contents=[OscMessage('/s_new', 'supriya:default', 1000, 0, 1, 'frequency', 261.63), OscMessage('/s_new', 'supriya:default', 1001, 0, 1, 'frequency', 329.63), OscMessage('/s_new', 'supriya:default', 1002, 0, 1, 'frequency', 392.0)]))
    Tree: NODE TREE 0 group
    Tree:     1 group
PLAYING:
    Status: StatusInfo(actual_sample_rate=44106.022607717845, average_cpu_usage=0.06155474856495857, group_count=2, peak_cpu_usage=0.22713929414749146, synth_count=0, synthdef_count=32, target_sample_rate=44100.0, ugen_count=0)
    Transcript:
        Sent:     OscMessage('/sync', 1)
        Received: OscMessage('/n_go', 1000, 1, -1, -1, 0)
        Received: OscMessage('/n_go', 1001, 1, -1, 1000, 0)
        Received: OscMessage('/n_go', 1002, 1, -1, 1001, 0)
        Received: OscMessage('/done', '/d_recv')
        Received: OscMessage('/synced', 1)
    Tree: NODE TREE 0 group
    Tree:     1 group
    Tree:         1002 supriya:default
    Tree:             out: 0.0, amplitude: 0.1, frequency: 392.0, gate: 1.0, pan: 0.5
    Tree:         1001 supriya:default
    Tree:             out: 0.0, amplitude: 0.1, frequency: 329.630005, gate: 1.0, pan: 0.5
    Tree:         1000 supriya:default
    Tree:             out: 0.0, amplitude: 0.1, frequency: 261.630005, gate: 1.0, pan: 0.5
JUST BEFORE STOPPING:
    Status: StatusInfo(actual_sample_rate=44105.22998562333, average_cpu_usage=0.39666128158569336, group_count=2, peak_cpu_usage=0.396695613861084, synth_count=3, synthdef_count=33, target_sample_rate=44100.0, ugen_count=60)
    Tree: NODE TREE 0 group
    Tree:     1 group
    Tree:         1002 supriya:default
    Tree:             out: 0.0, amplitude: 0.1, frequency: 392.0, gate: 1.0, pan: 0.5
    Tree:         1001 supriya:default
    Tree:             out: 0.0, amplitude: 0.1, frequency: 329.630005, gate: 1.0, pan: 0.5
    Tree:         1000 supriya:default
    Tree:             out: 0.0, amplitude: 0.1, frequency: 261.630005, gate: 1.0, pan: 0.5
IMMEDIATELY AFTER STOPPING:
    Status: StatusInfo(actual_sample_rate=44105.22998562333, average_cpu_usage=0.39666128158569336, group_count=2, peak_cpu_usage=0.396695613861084, synth_count=3, synthdef_count=33, target_sample_rate=44100.0, ugen_count=60)
    Transcript:
        Sent:     OscBundle(contents=[OscMessage('/n_set', 1000, 'gate', 0.0), OscMessage('/n_set', 1001, 'gate', 0.0), OscMessage('/n_set', 1002, 'gate', 0.0)])
    Tree: NODE TREE 0 group
    Tree:     1 group
    Tree:         1002 supriya:default
    Tree:             out: 0.0, amplitude: 0.1, frequency: 392.0, gate: 0.0, pan: 0.5
    Tree:         1001 supriya:default
    Tree:             out: 0.0, amplitude: 0.1, frequency: 329.630005, gate: 0.0, pan: 0.5
    Tree:         1000 supriya:default
    Tree:             out: 0.0, amplitude: 0.1, frequency: 261.630005, gate: 0.0, pan: 0.5
AFTER RELEASING:
    Status: StatusInfo(actual_sample_rate=44104.89029916077, average_cpu_usage=0.4097205400466919, group_count=2, peak_cpu_usage=0.42003315687179565, synth_count=0, synthdef_count=33, target_sample_rate=44100.0, ugen_count=0)
    Transcript:
        Received: OscMessage('/n_end', 1002, 1, -1, 1001, 0)
        Received: OscMessage('/n_end', 1001, 1, -1, 1000, 0)
        Received: OscMessage('/n_end', 1000, 1, -1, -1, 0)
    Tree: NODE TREE 0 group
    Tree:     1 group
INFO:supriya.scsynth:[127.0.0.1:57110/0x7f97f2f28830] quitting ...
INFO:supriya.scsynth:[127.0.0.1:57110/0x7f97f2f28830] ... quit!
INFO:supriya.scsynth:[127.0.0.1:57110/0x7f97f2f28830] quitting ...
INFO:supriya.scsynth:[127.0.0.1:57110/0x7f97f2f28830] ... already quit!

That’s a lot of output! Depending on your application, you may need to dial it down, or dial it up. Now you have the building blocks to do so.