Temporarily turn off output to the console window?

I’m using: SWI-Prolog version 8.1.9 on Windows 8.1.

I use the logging to a file feature a lot to copy write statement output to the logging file. My log sessions have become quite long so the output is quite verbose (which I want verbose). However, it takes about 15 to 30 seconds to complete the logging after executing the Prolog goal that I’m iterating during a programming session. My belief is that if I could temporarily turn off the output to the console so only the logging file receives the output from write statements, things would execute a lot faster. I base that opinion on Windows apps I’ve written that write to a console window. Once I turned off echo to the screen the operations typically executed many times faster.

Is there an SWI-Prolog flag I can set to turn off output to the screen, while I’m outputting to a file, and then turn back on once I’m done outputting to the log file so that the console works normally again?

I previously asked the question below, which his how I learned to use protocol to output to a disk file, but I don’t see anything about stopping output to the console in this post:

Writing to the screen is a lot faster than writing to a disk file.

If you are using this for debugging, instead of using write/1 I would suggest you use debug/3 to print messages. So you do something like:

:- debug(my_pred).
%:- nodebug(my_pred).
my_pred(A) :-
    debug(my_pred, "My pred received ~w",[A]),
    write('just a dumb pred').

Then you can run :

2 ?- prolog_ide(debug_monitor).
true.

And you’ll see a window with debug topics on the left. Click on my_pred and you will see your debug output.

You can also interactively turn debug on and off on the debug_monitor window by right-clicking on the debug topic.

2 Likes

Is your statement based on Linux or Windows? For example, there is a console app I use on Windows and Linux that when performing verbose output to the console runs 100 times slower on Windows than on Linux. Of course it might be due to the source of that app, but although I didn’t write that app I have spent a lot of the time with the source code and it uses low-level C stream output on both platforms so I don’t think that’s the cause. I believe that there is something about the way the I/O code in the standard C run-time library is written that works a lot faster on Linux than Windows (or said differently, there’s something Windows is doing that is very inefficient when it comes to that I/O code compared to Linux). My personal experience.

Either way, thanks for the debug tip. I’ll give that a try. But I still would like to know how to turn off output to the console if that’s at all possible.

If you use write/1 or any output predicate without an explicit stream there is the good old

?- tell(myfile), run, told.

If you use debug/3 statements you can use

?- debug(Channel > myfile).

On the other hand, I think you have missed some debug facilities if you think that creating huge log files is the answer. It rarely is.

1 Like

:slight_smile: It was based on Linux/Unix, I think I remember experiencing that windoze console output is very very slow.

1 Like

If you’re running in an Emacs terminal window or compilation window, output can be slow, especially if you have font-lock-mode turned on.
When I have a lot of output, I either use a command-line to output to a file (2>&1 >myfile) or use the script(1) command to capture the output. Maybe my output isn’t as voluminous as yours, but I seem to be able to use 100% CPU with script.

1 Like

A big thanks Jan.

@swi

Using Jan’s method to simply redirect output completely to a file, the time it takes to execute the goal went from 15 seconds to less than 1/4 a second (maybe faster). Windows console output is definitely broken. Jan, when I say Windows console output I mean Windows is to blame, not SWI-Prolog. Unfortunately, my main dev tool suite is on Windows so I’m stuck there. At least when I go to production it’s all Linux from that point on.

I’ve found WSL (Windows Subsystem for Linux) is an acceptable environment for running SWI-Prolog (it can even do X-windows, with some coaxing), but I/O is significantly slower than native Linux, and the Windows anti-spyware process uses up quite a bit of CPU. Native Linux is much better (I often ssh from my Windows machine to my Linux machine - and can do X11 of course that way).

Wow…that’s quite a change. Surely windoze console is broken. The code probably has not been touched since the windows 3 days, because very few use the console heavily in windows.

EDIT: BTW, I found this video and script very useful to debloat a windows 10 guest (I also used it with windows 8.1). It makes it faster and it comes from a guy with some 20 years working with windows clients.

1 Like

I’m totally speculating here, but the most likely culprit is the way the O/S writes to the console window area. Perhaps some main thread semaphore, hell maybe it’s some ancient legacy thing like DDE messaging or who knows what. But it’s obvious that every time a write goes to the console window area the O/S is waiting on something, perhaps even involving a process switch and a message queue lock. Ugh.

Some consoles do on purpose slow down the output. For example in my console I have a setting “Settings…” | “Terminal” | “Scroll Delay”. For optimal user experience, this is only applied at line breaks. The default setting is 20ms, but you can also set it to 0ms. The difference in wall time while executing goals is then:

/* with scroll delay = 20ms */
?- time((between(1,100,N),M is N*N,write(M),nl,fail; true)).
1
4
9
...
% Up 3,114 ms, GC 15 ms, Threads 49 ms (Current 08/07/19 08:38:59)
Yes

/* with scroll delay = 0ms */
?- time((between(1,100,N),M is N*N,write(M),nl,fail; true)).
1
4
9
...
% Up 511 ms, GC 0 ms, Threads 18 ms (Current 08/07/19 08:41:23)
Yes

The wall time is “Up”. So the console is faster with scroll delay=0ms, still not that fast. So setting the scroll delay to 0ms doesn’t give an infinite baud rate. But the console wait does not impact what is measured as “Threads” time. This is the Prolog threads CPU time and it is not affected by the scroll delay.

The scroll delay is also in effect when using protocol/1. How to change the scroll delay for other makes of console, I don’t know. A minimum scroll delay will always be present, since the console has to append a last line, then if the buffer size is exceeded it has to remove a first line, and it has also to update the screen.

Edit 07.08.2019:
The above measurement was from an old slow Mac Machine. On a Windows Machine, now also comparing with SWI-Prolog, I get the following:

/* my system, now on windows, scroll delay=0ms */
% Up 183 ms, GC 0 ms, Threads 0 ms (Current 08/07/19 10:05:33)
Yes

/* SWI Prolog, Windoz GUI console */
% 400 inferences, 0.000 CPU in 0.181 seconds (0% CPU, Infinite Lips)
true.

/* SWI Prolog, Windoz console */
% 400 inferences, 0.000 CPU in 0.062 seconds (0% CPU, Infinite Lips)
true.
1 Like

Writing to a console is typically slow anyway. Just try this:

jack(N) :-
    time(forall(between(1, N, _),
                format('All work and no play makes Jack a dull boy~n', []))).

On Linux, using terminator (a version of gnome terminal with some more features) we get:

102 ?- jack(100 000).
All work and no play makes Jack a dull boy
...
 200,000 inferences, 0.402 CPU in 0.637 seconds (63% CPU, 497001 Lips)

Writing to file:

103 ?- tell(x), jack(100 000), told.
% 200,000 inferences, 0.099 CPU in 0.100 seconds (99% CPU, 2013206 Lips)

I tried swipl-win.exe under Wine: jack(1 000) --> 2.469 sec. swipl.exe under Wine gives
jack(100 000) --> 3.190 sec. Under Wine to a file: jack(100 000) --> 2.256 sec. No clue how this would work under native Windows. I only have a VM running Windows, which isn’t very representative for I/O.

All on Intel NUC, i7-5557U, 16Gb memory, ssd.

Two more points: MacOS on a Macbook air: to terminal 0.397, to file 0.098.

1 Like

as long as we’re playing :slight_smile:

it depends quite a bit on the terminal emulator (and perhaps the font?):
all running jack(100 000).

For alacritty (an opengl enhanced terminal emulator):

% 200,001 inferences, 0.378 CPU in 0.393 seconds (96% CPU, 529246 Lips)
true.

for kitty (also opengl);

% 200,001 inferences, 0.397 CPU in 0.530 seconds (75% CPU, 504293 Lips)
true.

for neovim-gtk’s terminal (non-opengl, using fira code font with ligatures):

% 200,000 inferences, 0.379 CPU in 1.122 seconds (34% CPU, 527064 Lips)
true.

brace yourselves for this one :grimacing: plain linux VT console (no X):

% 200,000 inferences, 5.325 CPU in 5.329 seconds (100% CPU, 37560 Lips)
true.

My guess is that the VT is just using the bios or plain old VGA calls, no video acceleration.

Writing to a file:

?- tell(x), jack(100 000), told.
% 200,000 inferences, 0.113 CPU in 0.113 seconds (100% CPU, 1767232 Lips)

non-ssd drive (but heavily cached, cause I have a good amount of free ram), intel i7.

We are allowed to play a little here on the forum :slight_smile: