Unintuitive debug/3 - format/2 interaction

I have reduced my confusion on the fillowing situation:

run :-
    debug(foo),

    debug(foo, 'd1', []),
    format('baz', []),
    debug(foo, 'd2', []),
    format('~n', []),
    
    debug(foo, 'd1', []),
    ansi_format([], 'foo', []),
    debug(foo, 'd2', []),
    format('~n', []).
101 ?- run.
Warning: foo: no matching debug topic (yet)
% d1

% d2
baz
% d1

% d2
foo
true.

Why does the terminal leave a line between % d1 and % d2 even if everything is just buffered?

Could it be something about teaminals and streams I don’t understand or is it something related to Prolog? (debug/3 writes to user_error, format/2 and ansi_format/3 write to current_output)

If this is not the right place to ask this, please point me to where I can learn about this interaction.

Thanks :smiley:

Edit: Changed the category to Help! as I think this fits better

It is indeed about the streams. debug/3 writes to user_error, format/2 to current_output, which is normally user_output. user_error is unbuffered, while user_output is line buffered (when talking to a terminal; fully buffered otherwise). So, the debug/3 write immediately. the baz is buffered until the ~n. To get what you want, use flush_output/1 or change user_output to be unbuffered using set_stream/2.

Thank you for your response.

So debug/3 writes to user_error which is unbuffered (and if I see correctly, it also terminates with an newline so the unbuffered nature doesn’t really make a difference).
But as format/2 is buffered entirely and nothing is emitted to the terminal,
why doesn’t the terminal just print the two debug statements below each other like normal?

When I change the debug/3 to format/3 (to user_error):

run :-

    format(user_error, 'd1~n', []),
    format('foo', []),
    format(user_error, 'd2~n', []),
    format('~n', []).
101 ?- run.
d1
d2
foo
true.

The output does not leave a line between the two statements to user_error.
The documentation states:

Format a message if debug topic is enabled. Similar to format/3 to user_error, but only prints if Topic is activated through debug/1.

What is going on here, what could be the difference between debug/3 and format/3 that I am missing?

debug/3 uses format(user_error, '~N<your format>~n', Args), a little simplified. There is a dubious feature that writing unbuffered output does update the notion of the current column, so ~N inserts a newline. In most cases doing the column arithmetic before the buffering is correct, but user_output and user_error normally share the same position storage and flush independently.

I wonder whether it could be a solution to make writing to user_error flush user_output first. That would fix these cases. What would go wrong?

Ah that’s what I was missing, thank you very much.

I personally think that always flushing user_output would not always be practical behavior as it could break outputs that buffer intentionally even when user_error is not routed to the same terminal as user_output.

But some documentation for this behavior would be good for everyone after me wondering about this.