Mute ws_discard_input()

When using the GUI debugger there’s often a continuous stream of messages from ws_discard_input() that seem to serve no useful purpose and make the terminal interface completely unusable. This patch fixes that. Patch is against 10.1.7. Submitted as .c because .patch won’t attach.

ws_discard_input.patch.c (2.7 KB)

Thanks for noting that and for uploading the file as .c.

The reason .patch files are not allowed here is that the official way to submit changes to the SWI-Prolog codebase is through a Git pull request.

How do I reproduce this? This message happens if the GUI is waiting for a user event but instead you type something in the terminal. It seems a good idea to warn the user that it is not waiting for the terminal, so there is no point typing there (possibly with a clearer messages).

I think this probably needs wrapping so the message is only output in debug mode or somesuch so I don’t think it is PR-ready, it’s more an indicator of where the problem is.

The problem is that there’s a long stream of them, not just one, which means if you’ve typed anything in the terminal, it’s gone. If it’s a GUI-wait shouldn’t it be displayed in the GUI rather than scribbling on the text console?

Patches can be emailed to bugs@swi-prolog.org as described in How to submit patches?

Thanks.

I can add patch so those files types can be uploaded in less than a minute. Just need Jan’s approval.

The route of choice is GitHub pull requests. If not the result of git format-patch sent to bugs@swi-prolog.org. All the rest is emergency only.

That should be fixed, but first I need to be able to reproduce it to access the context in which it needs fixing. So, what OS? swipl or swipl-win? What exactly are you doing?

Per Jan, will not be ading patch as a file type that can be uploaded here.

This is 10.1.7 on Linux, built from source, swipl rather than swipl-win. Stepping through code after a gspy. It seems to start randomly, but once it does I get a continuous stream of Confirmer running; discarding input ...failed messages that instantly overflow the terminal buffer,

If I ^C I see the following:

Action (h for help) ? goals
     [47] pce:xpce_console(_23378, _23380, _23382)
     [45] pce_principal:get(@11783562242084/prolog_debugger, confirm, _18800)
     [44] Get-method on @11783562242084/prolog_debugger: prolog_debugger<-action --> _18800
     [42] pce_principal:get(@11783562242084/prolog_debugger, action, _18780)
     [39] pce_prolog_tracer:action_(_1132)
Action (h for help) ? C-stack trace labeled "INT":
  [0] save_backtrace() at /data2/tmp/swipl-devel-10.1.7/src/os/pl-cstack.c:334 [0x7f0b67b5bf68]
  [1] interruptHandler() at /data2/tmp/swipl-devel-10.1.7/src/pl-trace.c:2023 [0x7f0b67a95ba0]
  [2] dispatch_signal() at /data2/tmp/swipl-devel-10.1.7/src/pl-setup.c:594 [0x7f0b67b451e2]
  [3] handleSignals___LD() at /data2/tmp/swipl-devel-10.1.7/src/pl-setup.c:1252 [0x7f0b67b1bed8]
  [4] PL_next_solution_guarded___LD() at /data2/tmp/swipl-devel-10.1.7/src/pl-vmi.c:1941 [0x7f0b67aff1b3]
  [5] PL_next_solution___LD() at /data2/tmp/swipl-devel-10.1.7/src/pl-wam.c:3574 [0x7f0b67afa2b6]
  [6] PL_call_predicate() at /data2/tmp/swipl-devel-10.1.7/src/pl-fli.c:4539 [0x7f0b67b2e614]
  [7] XPCE_OUTPUT() at /data2/tmp/swipl-devel-10.1.7/packages/xpce/swipl/interface.c:3026 (discriminator 1) [0x7f0b66003a23]
  [8] pl_Cvprintf() at /data2/tmp/swipl-devel-10.1.7/packages/xpce/swipl/interface.c:3060 [0x7f0b66003adf]
  [9] Cprintf() at /data2/tmp/swipl-devel-10.1.7/packages/xpce/src/itf/interface.c:904 [0x7f0b65f07816]
  [10] ws_discard_input() at /data2/tmp/swipl-devel-10.1.7/packages/xpce/src/sdl/sdlevent.c:864 [0x7f0b66001a61]
  [11] SdlWaitConfirmFrame() at /data2/tmp/swipl-devel-10.1.7/packages/xpce/src/win/frame.c:212 [0x7f0b65fe12c1]
  [12] pceExecuteGoal() at /data2/tmp/swipl-devel-10.1.7/packages/xpce/src/ker/passing.c:820 [0x7f0b65f20a84]
  [13] invoke() at /data2/tmp/swipl-devel-10.1.7/packages/xpce/swipl/interface.c:2142 (discriminator 1) [0x7f0b66008866]
  [14] pl_get() at /data2/tmp/swipl-devel-10.1.7/packages/xpce/swipl/interface.c:2190 [0x7f0b66009021]
  [15] PL_next_solution_guarded___LD() at /data2/tmp/swipl-devel-10.1.7/src/pl-vmi.c:4384 (discriminator 2) [0x7f0b67a543bc]
  [16] PL_next_solution___LD() at /data2/tmp/swipl-devel-10.1.7/src/pl-wam.c:3574 [0x7f0b67afa2b6]
  [17] PL_call_predicate() at /data2/tmp/swipl-devel-10.1.7/src/pl-fli.c:4539 [0x7f0b67b2e614]
  [18] invoke() at /data2/tmp/swipl-devel-10.1.7/packages/xpce/swipl/interface.c:2091 [0x7f0b66008cfa]
  [19] pl_get() at /data2/tmp/swipl-devel-10.1.7/packages/xpce/swipl/interface.c:2190 [0x7f0b66009021]
  [20] PL_next_solution_guarded___LD() at /data2/tmp/swipl-devel-10.1.7/src/pl-vmi.c:4384 (discriminator 2) [0x7f0b67a543bc]
  [21] PL_next_solution___LD() at /data2/tmp/swipl-devel-10.1.7/src/pl-wam.c:3574 [0x7f0b67afa2b6]
  [22] callProlog() at /data2/tmp/swipl-devel-10.1.7/src/pl-pro.c:535 [0x7f0b67b141fe]
  [23] pl_notrace1_va() at /data2/tmp/swipl-devel-10.1.7/src/pl-pro.c:403 [0x7f0b67a82119]
  [24] PL_next_solution_guarded___LD() at /data2/tmp/swipl-devel-10.1.7/src/pl-vmi.c:4343 [0x7f0b67afad07]
  [25] PL_next_solution___LD() at /data2/tmp/swipl-devel-10.1.7/src/pl-wam.c:3574 [0x7f0b67afa2b6]
  [26] traceInterception() at /data2/tmp/swipl-devel-10.1.7/src/pl-trace.c:1591 (discriminator 1) [0x7f0b67a96449]
  [27] PL_next_solution_guarded___LD() at /data2/tmp/swipl-devel-10.1.7/src/pl-vmi.c:2016 (discriminator 1) [0x7f0b67a50597]
  [28] PL_next_solution___LD() at /data2/tmp/swipl-devel-10.1.7/src/pl-wam.c:3574 [0x7f0b67afa2b6]
  [29] query_loop() at /data2/tmp/swipl-devel-10.1.7/src/pl-pro.c:171 [0x7f0b67b3ffe3]
  [30] prologToplevel() at /data2/tmp/swipl-devel-10.1.7/src/pl-pro.c:662 [0x7f0b67b3fe7d]
  [31] PL_toplevel() at /data2/tmp/swipl-devel-10.1.7/src/pl-fli.c:5005 [0x7f0b67b5493a]
  [32] ??? [0x55bc6eda60c0]
  [33] __libc_start_call_main() at ./csu/../sysdeps/nptl/libc_start_call_main.h:74 [0x7f0b6785cca8]
  [34] call_init() at ./csu/../csu/libc-start.c:128 [0x7f0b6785cd65]
  [35] ??? [0x55bc6eda6101]

Dunno if that helps any, I can’s spot any obvious trigger for it to start happening. Once it has started, moving focus to the debugger window seems to make it worse, but it’s difficult to tell as the messages are being produced so quickly.

The problem appears to be deeper than just the error message. I added diagnostics that print the fd on failure, and correlated this with strace output from the same run. What happens is:

  1. Some socket/HTTP activity uses fd 7.
  2. xpce’s ws_dispatch() is called with that stream/fd and records fd 7 as dispatch state: both in the static dispatch_fd and in the associated SDL fd watch.
  3. The TCP socket is closed.
  4. fd 7 is then reused for unrelated file loads and closed again.
    The debugger confirm loop later dispatches through DEFAULT, which reuses stale dispatch state for fd 7.
  5. The kernel correctly reports POLLNVAL, and the repeated messages result.

The root cause seems to be that ws_dispatch() persists the fd passed to it. That fd may be a borrowed external fd from SWI’s dispatch hook, for example a socket stream Prolog is waiting on. It is valid to poll such an fd during that specific dispatch call so the GUI remains responsive while Prolog waits for stream input. But it should not become persistent dispatch state used by later DEFAULT calls.

The default dispatch fd/watch should be kept separate from external fds that are only used for temporary wakeup. External fds can be closed by their owner and later report POLLNVAL; they should not be cached globally by xpce. Conversely, a failure on an xpce-owned fd/watch would probably indicate a bug.

One danger with the current implementation is that ws_discard_input() could conceivably be called on a non-console fd, thereby discarding input from a file or network stream. The current implementation attempts to guard against this by checking for a console, but that check is a) Windows-only and b) broken for the stale-fd case described above.

I think the least intrusive fix is to make the default dispatch fd/watch explicit, and only set the cached value there. Then remove persistent caching from ws_dispatch() itself. ws_dispatch(input, timeout) can still poll the supplied fd as a temporary wake condition, but it should not persist it for later DEFAULT calls.

No :robot: was permanently harmed in the making of this post, just taunted a bit.

Bug logged, PR to follow:

As I note in the PR, this was heavily AI-assisted - caveat emptor…

See also:

This was seen during testing of the patch, but I suspect is unrelated.

FYI

These GitHub posts that look like they’re from Jan are actually generated by Discourse when someone posts with a link to GitHub.

They confused me at first, because I thought Jan had created them manually.

@alanbur

FYI — for SEGVs or other major hard errors, if any output files are generated, such as a crash dump, please pass those along to Jan.

Some AI tools can read and decipher those files almost as easily as plain text. I learned this from experience while working through a SEGV issue a few months ago. I didn’t need to install all the tooling to inspect the files first; I just attached the file with an AI prompt, and it was able to analyze it.

I figured that out when the 2nd one arrived :laughing:

I don’t have core dumps enabled, I should probably change that…