Unintuitive debug/3 - format/2 interaction

Help!
,
1

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

2

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.

3

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?

4

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?

5

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.

6

It gets a very complicated story :frowning: The implementation is basically wrong as it merges the position of all three “standard” streams. That is fine if this is a physical device, but wrong if some of these streams are not connected to the same physical device. I doubt there is a portable way to figure out what is connected to the streams 0,1,2 …

Note that reading user_input also flushes user_output, so some interaction is already there …

If there is some de-facto acknowledged way of doing position sharing and flush coordination between the standard streams, please share. Given how ill it is currently defined, documentation seems a bad idea …

7

Interleaved stderr and stdout (with various flavours of buffering) have been a problem for Unix developers since the beginning. If somebody had discovered/invented a solution, I’m sure it would be in common use (the only one I know is 2>&1 on the command line; and that has its own problems).

Having debug/3 affect user_output is likely to produce some other unexpected behaviour.

Instead, I would suggest having a user:debug_hook/3 that is called first and if it fails, the current behaviour is used. It could do a flush of user_output then fail, to get the results you suggest, but in a user-controlled manner.
I don’t particularly like having lots of hooks (e.g., portray/1 requires some care) but this is something that can be put in init.pl, together with setting debugger_write_options, etc.

8

You can already do that. debug/3 uses print_message/2, which calls user:message_hook/3. All in all, I think there is no clean universal solution and users will have to live with it, calling flush_output/1 when there are synchronization issues between the two streams.

On the other hand, the implication of flushing user_output before user_error if both are connected to a terminal is probably fairly harmless and may reduce confusion. I’m willing to give it a try. I guess I’m a little more willing to take risks than some other developers :slight_smile: