bug#40323: 28.0.50; error in process filter: Invalid search bound (wrong side of point)

bug#40323: 28.0.50; error in process filter: Invalid search bound (wrong side of point)

[Jacob Lagares Pozo]

I am currently using EXMW as my main window manager, and I have been
having some problems with ansi-color-apply-on-region.

I originally posted an issue to the EXWM github repository
(https://github.com/ch11ng/exwm/issues/729), where I got pointed to
submit a bug report here (because that is probably an Emacs bug, and not
an EXWM one).

My *Messages* buffer gets spammed all over with the two following error 
messages,
which freeze Emacs for a few seconds each time.

error in process filter: ansi-color-apply-on-region: Invalid search 
bound (wrong side of point)
error in process filter: Invalid search bound (wrong side of point)

This makes it really difficult to type commands or really do
anything. It happens when I open an EXWM window. I think when the
window outputs text (which goes to the *Async Shell Command* buffer) and
Emacs tries to colorize it, it fails for (possibly) a bug in
ansi-color-apply-on-region. Here is the backtrace if I enable
debug-on-error:

Debugger entered--Lisp error: (error "Invalid search bound (wrong side 
of point)")
re-search-forward("\33\\[[0-?]*[ -/]*[@-~]" #<marker at 1 in *Async 
Shell Command*> t)
ansi-color-apply-on-region(#<marker at 152 in *Async Shell Command*> 
#<marker at 1 in *Async Shell Command*>)
ansi-color-process-output("[03/29/20, 16:21:53:387] info: [FOCUS-EVENT] 
Clien...")
run-hook-with-args(ansi-color-process-output "[03/29/20, 16:21:53:387] 
info: [FOCUS-EVENT] Clien...")
comint-output-filter(#<process Shell> "[03/29/20, 16:21:53:387] info: 
[FOCUS-EVENT] Clien...")

I don't know if I can provide much more information than this, mainly
because my elisp-fu is not really something you can consider to be
"great". If there is anything else I could provide that could
potentially help solved the problem, please let me know about it.

Many thanks,
Jacob


In GNU Emacs 28.0.50 (build 1, x86_64-pc-linux-gnu, GTK+ Version 
3.24.14, cairo version 1.16.0)
of 2020-03-28 built on neocomputery
Repository revision: dceba13ce57ed0cb726e89566197f77359a38d91
Repository branch: master
Windowing system distributor 'The X.Org Foundation', version 11.0.12007000
System Description: Debian GNU/Linux bullseye/sid

Recent messages:
error in process filter: Invalid search bound (wrong side of point)
error in process filter: ansi-color-apply-on-region: Invalid search 
bound (wrong side of point)
error in process filter: Invalid search bound (wrong side of point)
error in process filter: ansi-color-apply-on-region: Invalid search 
bound (wrong side of point)
error in process filter: Invalid search bound (wrong side of point)
error in process filter: ansi-color-apply-on-region: Invalid search 
bound (wrong side of point)
error in process filter: Invalid search bound (wrong side of point)
error in process filter: ansi-color-apply-on-region: Invalid search 
bound (wrong side of point)
error in process filter: Invalid search bound (wrong side of point)
user-error: End of history; no default available

Configured using:
'configure --prefix=/usr/local'

Configured features:
XPM JPEG TIFF GIF PNG RSVG CAIRO SOUND DBUS GSETTINGS GLIB NOTIFY
INOTIFY LIBSELINUX GNUTLS LIBXML2 FREETYPE HARFBUZZ ZLIB
TOOLKIT_SCROLL_BARS GTK3 X11 XDBE XIM MODULES THREADS JSON PDUMPER LCMS2
GMP

Important settings:
value of $LC_ALL: POSIX
value of $LANG: en_US.UTF-8
locale-coding-system: nil

Major mode: EXWM

Minor modes in effect:
global-linum-mode: t
linum-mode: t
global-hl-line-mode: t
display-time-mode: t
delete-selection-mode: t
helm--remap-mouse-mode: t
smartparens-global-mode: t
smartparens-mode: t
pyvenv-mode: t
company-quickhelp-mode: t
company-quickhelp-local-mode: t
global-company-mode: t
company-mode: t
shell-dirtrack-mode: t
tooltip-mode: t
global-eldoc-mode: t
electric-indent-mode: t
mouse-wheel-mode: t
menu-bar-mode: t
file-name-shadow-mode: t
global-font-lock-mode: t
font-lock-mode: t
blink-cursor-mode: t
auto-composition-mode: t
auto-encryption-mode: t
auto-compression-mode: t
buffer-read-only: t
transient-mark-mode: t

Load-path shadows:
None found.

Features:
(shadow sort mail-extr emacsbug message rmc puny rfc822 mml mml-sec epa
epg epg-config gnus-util rmail rmail-loaddefs mm-decode mm-bodies
mm-encode mail-parse rfc2231 mailabbrev gmm-utils mailheader sendmail
rfc2047 rfc2045 ietf-drums mm-util mail-prsvr mail-utils helm-command
helm-elisp helm-eval edebug backtrace find-func helm-info helm-mode
helm-files helm-tags helm-locate winner dired dired-loaddefs
helm-buffers helm-occur helm-grep helm-regexp helm-utils helm-help
helm-types disp-table init appareance linum hl-line atom-one-dark-theme
keybinds key-chord welcome misc time utility swiper ivy delsel colir
ivy-overlay helm derived helm-source eieio-compat helm-multi-match
helm-lib async dockerfile-mode sh-script smie executable smartparens
powerline powerline-separators color powerline-themes align glsl-mode
easy-mmode python-elpy cl-extra yasnippet highlight-indentation
flymake-proc flymake warnings help-fns radix-tree help-mode elpy advice
elpy-rpc pyvenv eshell esh-cmd esh-ext esh-opt esh-proc esh-io esh-arg
esh-module esh-groups esh-util elpy-shell elpy-profile elpy-django
elpy-refactor python tramp-sh grep cus-edit cus-start cus-load wid-edit
cpp-ide company-oddmuse company-keywords company-etags etags fileloop
generator xref project company-gtags company-dabbrev-code
company-dabbrev company-files company-capf company-cmake company-xcode
company-clang company-semantic company-eclim company-template
company-bbdb company-quickhelp pos-tip company pcase rtags popup repeat
compile tramp tramp-loaddefs trampver tramp-integration files-x
tramp-compat shell pcomplete comint ansi-color ring parse-time iso8601
time-date ls-lisp format-spec asm-mode cc-mode cc-fonts cc-guess
cc-menus cc-cmds cc-styles cc-align cc-engine cc-vars cc-defs bookmark
text-property-search pp cmake-ide dash s levenshtein find-file
cmake-mode thingatpt rx code-style edmacro exwm-config ido exwm
exwm-input xcb-keysyms xcb-xkb exwm-manage exwm-floating xcb-cursor
xcb-render exwm-layout exwm-workspace exwm-core xcb-ewmh xcb-icccm xcb
xcb-xproto xcb-types xcb-debug kmacro server finder-inf info package
easymenu browse-url url-handlers url-parse auth-source cl-seq eieio
eieio-core cl-macs eieio-loaddefs password-cache json subr-x map
url-vars seq byte-opt gv bytecomp byte-compile cconv cl-loaddefs cl-lib
tooltip eldoc electric uniquify ediff-hook vc-hooks lisp-float-type
mwheel term/x-win x-win term/common-win x-dnd tool-bar dnd fontset image
regexp-opt fringe tabulated-list replace newcomment text-mode elisp-mode
lisp-mode prog-mode register page tab-bar menu-bar rfn-eshadow isearch
timer select scroll-bar mouse jit-lock font-lock syntax facemenu
font-core term/tty-colors frame minibuffer cl-generic cham georgian
utf-8-lang misc-lang vietnamese tibetan thai tai-viet lao korean
japanese eucjp-ms cp51932 hebrew greek romanian slovak czech european
ethiopic indian cyrillic chinese composite charscript charprop
case-table epa-hook jka-cmpr-hook help simple abbrev obarray
cl-preloaded nadvice loaddefs button faces cus-face macroexp files
text-properties overlay sha1 md5 base64 format env code-pages mule
custom widget hashtable-print-readable backquote threads dbusbind
inotify lcms2 dynamic-setting system-font-setting font-render-setting
cairo move-toolbar gtk x-toolkit x multi-tty make-network-process emacs)

Memory information:
((conses 16 485189 55779)
(symbols 48 38590 1)
(strings 32 137640 4402)
(string-bytes 1 4451964)
(vectors 16 63773)
(vector-slots 8 948631 40542)
(floats 8 296 541)
(intervals 56 1884 1420)
(buffers 1000 21))

bug#40323: 28.0.50; error in process filter: Invalid search bound (wrong side of point)

[Noam Postavsky]

Jacob Lagares Pozo <jlagarespo@iebesalu.cat> writes:

> Debugger entered--Lisp error: (error "Invalid search bound (wrong side of point)")
>   re-search-forward("\33\\[[0-?]*[ -/]*[@-~]" #<marker at 1 in *Async Shell Command*> t)
>   ansi-color-apply-on-region(#<marker at 152 in *Async Shell Command*> #<marker at 1 in *Async Shell Command*>)
>   ansi-color-process-output("[03/29/20, 16:21:53:387] info: [FOCUS-EVENT] Clien...")
>   run-hook-with-args(ansi-color-process-output "[03/29/20, 16:21:53:387] info: [FOCUS-EVENT] Clien...")
>   comint-output-filter(#<process Shell> "[03/29/20, 16:21:53:387] info: [FOCUS-EVENT] Clien...")

It looks like the start and end markers are the wrong way around.  Does
the patch below help?  If yes, the next question would be how they got
that way.  Perhaps that indicates a problem in comint.el?

--- i/lisp/ansi-color.el
+++ w/lisp/ansi-color.el
@@ -222,6 +222,10 @@ ansi-color-process-output
 			  comint-last-output-start
 			(point-min-marker)))
 	(end-marker (process-mark (get-buffer-process (current-buffer)))))
+    (when (> start-marker end-marker)
+      (let ((s start-marker))
+        (setq start-marker end-marker
+              end-marker s)))
     (cond ((eq ansi-color-for-comint-mode nil))
 	  ((eq ansi-color-for-comint-mode 'filter)
 	   (ansi-color-filter-region start-marker end-marker))

bug#40323: 28.0.50; error in process filter: Invalid search bound (wrong side of point)

[Andreas Schwab]

On Mär 30 2020, Noam Postavsky wrote:

> Jacob Lagares Pozo <jlagarespo@iebesalu.cat> writes:
>
>> Debugger entered--Lisp error: (error "Invalid search bound (wrong side of point)")
>>   re-search-forward("\33\\[[0-?]*[ -/]*[@-~]" #<marker at 1 in *Async Shell Command*> t)
>>   ansi-color-apply-on-region(#<marker at 152 in *Async Shell Command*> #<marker at 1 in *Async Shell Command*>)
>>   ansi-color-process-output("[03/29/20, 16:21:53:387] info: [FOCUS-EVENT] Clien...")
>>   run-hook-with-args(ansi-color-process-output "[03/29/20, 16:21:53:387] info: [FOCUS-EVENT] Clien...")
>>   comint-output-filter(#<process Shell> "[03/29/20, 16:21:53:387] info: [FOCUS-EVENT] Clien...")
>
> It looks like the start and end markers are the wrong way around.  Does
> the patch below help?  If yes, the next question would be how they got
> that way.  Perhaps that indicates a problem in comint.el?

Or another filter has moved the process mark.

Andreas.

-- 
Andreas Schwab, schwab@linux-m68k.org
GPG Key fingerprint = 7578 EB47 D4E5 4D69 2510  2552 DF73 E780 A9DA AEC1
"And now for something completely different."

bug#40323: 28.0.50; error in process filter: Invalid search bound (wrong side of point)

[Drew Adams]

> +      (let ((s start-marker))
> +        (setq start-marker end-marker
> +              end-marker s)))

A perhaps less clear but common cliche for that:

(setq start-marker (prog1 end-marker (setq end-marker start-marker)))

bug#40323: 28.0.50; error in process filter: Invalid search bound (wrong side of point)

[Noam Postavsky]

[-- Attachment #1: Type: text/plain, Size: 82 bytes --]

[forwarding to list, please use "Reply All" to keep 40323@debbugs.gnu.org on Cc]


[-- Attachment #2: Type: message/rfc822, Size: 3205 bytes --]

[-- Attachment #2.1.1: Type: text/plain, Size: 2595 bytes --]

Hello Noam (and everyone else),

Thanks for your quick response.

The patch you provided does indeed seem to fix the issue, or at least it 
hasn't happened for the time I tested it (I can verify various processes 
were running and outputting things to the async buffer).

I do not have any idea as to why did those markers get swapped around. 
Is there any specific place that deals with them that I could check? 
Could this be a bug with comint mode, maybe clashing with another package?

This is my list of installed packages, directly from package-list-packages:

|  atom-dark-theme    20181022.1602 installed             An Emacs port 
of the Atom Dark theme from Atom.io.
   atom-one-dark-theme 20190705.554  installed             Atom One Dark 
color theme
   avy                20200311.1106 installed             Jump to 
arbitrary positions in visible text and select text quickly.
   cmake-ide          20190731.1009 installed             Calls CMake to 
find out include paths and other compiler flags
   cmake-mode         20190710.1319 installed major-mode for editing 
CMake sources
   company-quickhelp  20180525.1003 installed             Popup 
documentation for completion candidates
   company-rtags      20191222.920  installed             RTags back-end 
for company
   dockerfile-mode    20200106.2126 installed             Major mode for 
editing Docker's Dockerfiles
   elpy               20200326.2207 installed             Emacs Python 
Development Environment
   exwm               0.23          installed             Emacs X Window 
Manager
   glsl-mode          20191017.2148 installed             major mode for 
Open GLSL shader files
   gruvbox-theme      20200307.1522 installed             A retro-groove 
colour theme for Emacs
   helm               20200325.757  installed             Helm is an 
Emacs incremental and narrowing framework
   key-chord          20160227.1238 installed             map pairs of 
simultaneously pressed keys to commands
   powerline          20200105.2053 installed             Rewrite of 
Powerline
   smartparens        20200324.2147 installed             Automatic 
insertion, wrapping and paredit-like navigation with user defined pairs.
   sudo-edit          20180731.1908 installed             Open files as 
another user
   swiper             20200319.1334 installed             Isearch with 
an overview. Oh, man!
   zerodark-theme     20190528.923  installed             A dark, medium 
contrast theme for Emacs
|

If needed I can post (potentially) relevant fragments of my 
configuration files.

Kind regards,

Jacob

bug#40323: 28.0.50; error in process filter: Invalid search bound (wrong side of point)

[Noam Postavsky]

> The patch you provided does indeed seem to fix the issue, or at least
> it hasn't happened for the time I tested it (I can verify various
> processes were running and outputting things to the async buffer).
>
> I do not have any idea as to why did those markers get swapped
> around. Is there any specific place that deals with them that I could
> check? Could this be a bug with comint mode, maybe clashing with
> another package?

Try reproducing the issue after evaluating the code below, perhaps
*trace-output* will have some useful clues.

    (load-library "comint.el") ;; Can only trace set-marker from Lisp source.

    (defun bug-40323-get-comint-output-marker ()
      (list :comint-pmark
            (and (markerp comint-last-output-start)
                 (eq (marker-buffer comint-last-output-start)
                     (current-buffer))
                 (process-mark (get-buffer-process (current-buffer))))))

    (dolist (fun '(set-marker
                   comint-send-input
                   comint-output-filter
                   comint-adjust-window-point
                   comint-adjust-point
                   ansi-color-process-output))
      (trace-function fun nil #'bug-40323-get-comint-output-marker))

bug#40323: 28.0.50; error in process filter: Invalid search bound (wrong side of point)

[Jacob Lagares Pozo]

Hello Noam,

I'm sorry for the late response.

It looks like your patch does indeed work and logs a bunch of stuff to 
the *trace-output* buffer every time a program running on the async 
buffer outputs something.

For brevity, I'll just post just a single one of them, because the whole 
buffer is 172k characters and growing. I hope it's enough; if it is not, 
please let me know and I'll post the whole thing.

Jacob

On 2020-04-15 04:25, Noam Postavsky wrote:
>> The patch you provided does indeed seem to fix the issue, or at least
>> it hasn't happened for the time I tested it (I can verify various
>> processes were running and outputting things to the async buffer).
>>
>> I do not have any idea as to why did those markers get swapped
>> around. Is there any specific place that deals with them that I could
>> check? Could this be a bug with comint mode, maybe clashing with
>> another package?
> Try reproducing the issue after evaluating the code below, perhaps
> *trace-output* will have some useful clues.
>
>      (load-library "comint.el") ;; Can only trace set-marker from Lisp source.
>
>      (defun bug-40323-get-comint-output-marker ()
>        (list :comint-pmark
>              (and (markerp comint-last-output-start)
>                   (eq (marker-buffer comint-last-output-start)
>                       (current-buffer))
>                   (process-mark (get-buffer-process (current-buffer))))))
>
>      (dolist (fun '(set-marker
>                     comint-send-input
>                     comint-output-filter
>                     comint-adjust-window-point
>                     comint-adjust-point
>                     ansi-color-process-output))
>        (trace-function fun nil #'bug-40323-get-comint-output-marker))

bug#40323: 28.0.50; error in process filter: Invalid search bound (wrong side of point)

[Jacob Lagares Pozo]

Also, I should mention that I tried reinstalling Emacs and a few 
packages, just in case something was corrupted. Doesn't seem like the 
case, it seems like a legitimate bug.

On 2020-04-17 13:39, Jacob Lagares Pozo wrote:
> Hello Noam,
>
> I'm sorry for the late response.
>
> It looks like your patch does indeed work and logs a bunch of stuff to 
> the *trace-output* buffer every time a program running on the async 
> buffer outputs something.
>
> For brevity, I'll just post just a single one of them, because the 
> whole buffer is 172k characters and growing. I hope it's enough; if it 
> is not, please let me know and I'll post the whole thing.
>
> Jacob
>
> On 2020-04-15 04:25, Noam Postavsky wrote:
>>> The patch you provided does indeed seem to fix the issue, or at least
>>> it hasn't happened for the time I tested it (I can verify various
>>> processes were running and outputting things to the async buffer).
>>>
>>> I do not have any idea as to why did those markers get swapped
>>> around. Is there any specific place that deals with them that I could
>>> check? Could this be a bug with comint mode, maybe clashing with
>>> another package?
>> Try reproducing the issue after evaluating the code below, perhaps
>> *trace-output* will have some useful clues.
>>
>>      (load-library "comint.el") ;; Can only trace set-marker from 
>> Lisp source.
>>
>>      (defun bug-40323-get-comint-output-marker ()
>>        (list :comint-pmark
>>              (and (markerp comint-last-output-start)
>>                   (eq (marker-buffer comint-last-output-start)
>>                       (current-buffer))
>>                   (process-mark (get-buffer-process 
>> (current-buffer))))))
>>
>>      (dolist (fun '(set-marker
>>                     comint-send-input
>>                     comint-output-filter
>>                     comint-adjust-window-point
>>                     comint-adjust-point
>>                     ansi-color-process-output))
>>        (trace-function fun nil #'bug-40323-get-comint-output-marker))

bug#40323: 28.0.50; error in process filter: Invalid search bound (wrong side of point)

[Noam Postavsky]

Jacob Lagares Pozo <jlagarespo@iebesalu.cat> writes:

> For brevity, I'll just post just a single one of them, because the
> whole buffer is 172k characters and growing. I hope it's enough; if it
> is not, please let me know and I'll post the whole thing.

Please compress before posting.  If you can find a spot where the
comint-last-output-start goes from a large number to 1, I think that
would probably be where the interesting part is.

bug#40323: 28.0.50; error in process filter: Invalid search bound (wrong side of point)

[Jacob Lagares Pozo]

[-- Attachment #1: Type: text/plain, Size: 1962 bytes --]

OK, not sure if this is what we want, but this is an example output that 
looks interesting.

If needed I'll dump the whole thing to a file, compress, it and post it 
here.

Many thanks,

Jacob

|======================================================================
1 -> (comint-output-filter #<process slack> "[04/17/20, 16:06:12:068] 
info: [CHECK-FOR-OLD-IMS] (TAVFB00JW) Within limit: 4
")(:comint-pmark nil)
| 2 -> (set-marker #<marker at 238540 in *slack*<4>> 
238595)(:comint-pmark #<marker at 238595 in *slack*<4>>)
| 2 <- set-marker: #<marker at 238595 in *slack*<4>>(:comint-pmark 
#<marker at 238595 in *slack*<4>>)
| 2 -> (set-marker #<marker at 238595 in *slack*<4>> 
238675)(:comint-pmark #<marker at 238595 in *slack*<4>>)
| 2 <- set-marker: #<marker at 238675 in *slack*<4>>(:comint-pmark 
#<marker at 238675 in *slack*<4>>)
| 2 -> (ansi-color-process-output "[04/17/20, 16:06:12:068] info: 
[CHECK-FOR-OLD-IMS] (TAVFB00JW) Within limit: 4
")(:comint-pmark #<marker at 238675 in *slack*<4>>)
| 2 <- ansi-color-process-output: nil(:comint-pmark #<marker at 238675 
in *slack*<4>>)
| 2 -> (set-marker #<marker (moves after insertion) at 238675 in 
*slack*<4>> 238675)(:comint-pmark #<marker at 238675 in *slack*<4>>)
| 2 <- set-marker: #<marker (moves after insertion) at 238675 in 
*slack*<4>>(:comint-pmark #<marker at 238675 in *slack*<4>>)
1 <- comint-output-filter: #<marker (moves after insertion) at 238675 in 
*slack*<4>>(:comint-pmark nil)
|

On 2020-04-17 13:49, Noam Postavsky wrote:
> Jacob Lagares Pozo <jlagarespo@iebesalu.cat> writes:
>
>> For brevity, I'll just post just a single one of them, because the
>> whole buffer is 172k characters and growing. I hope it's enough; if it
>> is not, please let me know and I'll post the whole thing.
> Please compress before posting.  If you can find a spot where the
> comint-last-output-start goes from a large number to 1, I think that
> would probably be where the interesting part is.

[-- Attachment #2: Type: text/html, Size: 3044 bytes --]

bug#40323: 28.0.50; error in process filter: Invalid search bound (wrong side of point)

[Noam Postavsky]

Jacob Lagares Pozo <jlagarespo@iebesalu.cat> writes:

> OK, not sure if this is what we want, but this is an example output
> that looks interesting.
>
> If needed I'll dump the whole thing to a file, compress, it and post
> it here.

> *slack*<4>>(:comint-pmark #<marker at 238675 in *slack*<4>>)
> 1 <- comint-output-filter: #<marker (moves after insertion) at 238675
> in *slack*<4>>(:comint-pmark nil)

I think this just shows the process ending normally.  And I made a
mistake in the tracing function, better to see both markers, as in:

    (defun bug-40323-get-comint-output-marker ()
      (list :comint-pmark
            (and (markerp comint-last-output-start)
                 (eq (marker-buffer comint-last-output-start)
                     (current-buffer))
                 (cons
                  comint-last-output-start
                  (process-mark (get-buffer-process (current-buffer)))))))

bug#40323: 28.0.50; error in process filter: Invalid search bound (wrong side of point)

[Jacob Lagares Pozo]

[-- Attachment #1: Type: text/plain, Size: 2715 bytes --]

OK, I replaced the old function and now it outputs this:

|======================================================================
1 -> (comint-output-filter #<process slack> "[04/20/20, 12:00:53:017] 
info: Store: FOREGROUND_APP
")(:comint-pmark nil)
| 2 -> (set-marker #<marker at 34155 in *slack*> 34261)(:comint-pmark 
(#<marker at 34155 in *slack*> . #<marker at 34261 in *slack*>))
| 2 <- set-marker: #<marker at 34261 in *slack*>(:comint-pmark (#<marker 
at 34261 in *slack*> . #<marker at 34261 in *slack*>))
| 2 -> (set-marker #<marker at 34261 in *slack*> 34316)(:comint-pmark 
(#<marker at 34261 in *slack*> . #<marker at 34261 in *slack*>))
| 2 <- set-marker: #<marker at 34316 in *slack*>(:comint-pmark (#<marker 
at 34261 in *slack*> . #<marker at 34316 in *slack*>))
| 2 -> (ansi-color-process-output "[04/20/20, 12:00:53:017] info: Store: 
FOREGROUND_APP
")(:comint-pmark (#<marker at 34261 in *slack*> . #<marker at 34316 in 
*slack*>))
| 2 <- ansi-color-process-output: nil(:comint-pmark (#<marker at 34261 
in *slack*> . #<marker at 34316 in *slack*>))
| 2 -> (set-marker #<marker (moves after insertion) at 34316 in *slack*> 
34316)(:comint-pmark (#<marker at 34261 in *slack*> . #<marker at 34316 
in *slack*>))
| 2 <- set-marker: #<marker (moves after insertion) at 34316 in 
*slack*>(:comint-pmark (#<marker at 34261 in *slack*> . #<marker at 
34316 in *slack*>))
1 <- comint-output-filter: #<marker (moves after insertion) at 34316 in 
*slack*>(:comint-pmark nil)
|

I should probably make a simple program that prints a bunch of stuff and 
then hangs, so I can have predictable and reproducible output, that 
might help.

So what do you exactly mean by that the process is ending normally?

Jacob

On 2020-04-19 14:57, Noam Postavsky wrote:
> Jacob Lagares Pozo <jlagarespo@iebesalu.cat> writes:
>
>> OK, not sure if this is what we want, but this is an example output
>> that looks interesting.
>>
>> If needed I'll dump the whole thing to a file, compress, it and post
>> it here.
>> *slack*<4>>(:comint-pmark #<marker at 238675 in *slack*<4>>)
>> 1 <- comint-output-filter: #<marker (moves after insertion) at 238675
>> in *slack*<4>>(:comint-pmark nil)
> I think this just shows the process ending normally.  And I made a
> mistake in the tracing function, better to see both markers, as in:
>
>      (defun bug-40323-get-comint-output-marker ()
>        (list :comint-pmark
>              (and (markerp comint-last-output-start)
>                   (eq (marker-buffer comint-last-output-start)
>                       (current-buffer))
>                   (cons
>                    comint-last-output-start
>                    (process-mark (get-buffer-process (current-buffer)))))))

[-- Attachment #2: Type: text/html, Size: 3891 bytes --]

bug#40323: 28.0.50; error in process filter: Invalid search bound (wrong side of point)

[Noam Postavsky]

Jacob Lagares Pozo <jlagarespo@iebesalu.cat> writes:

> I should probably make a simple program that prints a bunch of stuff
> and then hangs, so I can have predictable and reproducible output,
> that might help.

It occurs to me that you should see a "non-local exit" in the trace when
the error triggers, and the traces just before that should hopefully
show the swapping of marker positions occuring.

> So what do you exactly mean by that the process is ending normally?

Oh, hmm, I was still a bit confused.  I thought the (:comint-pmark nil)
meant the marker was deleted, but actually it's just because around the
call to comint-output-filter a different buffer is current (which makes
the check in the tracing function fail).  Maybe one more tweak to the
tracing function:

    (defun bug-40323-get-comint-output-marker ()
      (list :comint-pmark
            (let ((buf (and (markerp comint-last-output-start)
                            (marker-buffer comint-last-output-start))))
              (when (buffer-live-p buf)
                (cons
                 comint-last-output-start
                 (process-mark (get-buffer-process buf)))))))

bug#40323: 28.0.50; error in process filter: Invalid search bound (wrong side of point)

[Jacob Lagares Pozo]

[-- Attachment #1: Type: text/plain, Size: 4452 bytes --]

Hello Noam,

I'm sorry for the late reply. I have been having some problems with the 
power source of my computer as of lately. Everything seems to be doing 
fine now though, so I'll get back to this.

I made a very simple program that just prints a bunch of stuff to stdout 
and stderr:

If I run it without your patches, it works surprisingly just fine (I 
noticed the original errors pop up most commonly on Slack I guess 
because it prints a lot more?), whereas if I evaluate said patches, this 
is the output of the trace buffer:

|======================================================================
1 -> (comint-output-filter #<process Shell> "stdout:
hello, world
Im gonna print some stuff
0, 1, 2, 3, 4, 5, 6, 7, 8, 9, 10, 11, 12, 13, 14, 15
stderr:
AHHHH PANIC CATASTROPHIC FAILIURE!!!
The quick brown fox jumps over the lazy dog.
")(:comint-pmark nil)
| 2 -> (set-marker #<marker in no buffer> 1)(:comint-pmark nil)
| 2 <- set-marker: #<marker at 1 in *Async Shell Command*>(:comint-pmark 
(#<marker at 1 in *Async Shell Command*> . #<marker at 1 in *Async Shell 
Command*>))
| 2 -> (set-marker #<marker at 1 in *Async Shell Command*> 
191)(:comint-pmark (#<marker at 1 in *Async Shell Command*> . #<marker 
at 1 in *Async Shell Command*>))
| 2 <- set-marker: #<marker at 191 in *Async Shell 
Command*>(:comint-pmark (#<marker at 1 in *Async Shell Command*> . 
#<marker at 191 in *Async Shell Command*>))
| 2 -> (ansi-color-process-output "stdout:
hello, world
Im gonna print some stuff
0, 1, 2, 3, 4, 5, 6, 7, 8, 9, 10, 11, 12, 13, 14, 15
stderr:
AHHHH PANIC CATASTROPHIC FAILIURE!!!
The quick brown fox jumps over the lazy dog.
")(:comint-pmark (#<marker at 1 in *Async Shell Command*> . #<marker at 
191 in *Async Shell Command*>))
| 2 <- ansi-color-process-output: nil(:comint-pmark (#<marker at 1 in 
*Async Shell Command*> . #<marker at 191 in *Async Shell Command*>))
| 2 -> (comint-adjust-window-point #<window 31 on *Async Shell Command*> 
#<process Shell>)(:comint-pmark (#<marker at 1 in *Async Shell Command*> 
. #<marker at 191 in *Async Shell Command*>))
| 2 <- comint-adjust-window-point: nil(:comint-pmark (#<marker at 1 in 
*Async Shell Command*> . #<marker at 191 in *Async Shell Command*>))
| 2 -> (set-marker #<marker (moves after insertion) at 191 in *Async 
Shell Command*> 191)(:comint-pmark (#<marker at 1 in *Async Shell 
Command*> . #<marker at 191 in *Async Shell Command*>))
| 2 <- set-marker: #<marker (moves after insertion) at 191 in *Async 
Shell Command*>(:comint-pmark (#<marker at 1 in *Async Shell Command*> . 
#<marker at 191 in *Async Shell Command*>))
1 <- comint-output-filter: #<marker (moves after insertion) at 191 in 
*Async Shell Command*>(:comint-pmark nil)
|

I am not sure what does this mean, perhaps it is some special character 
Slack uses for logging that messes with those markers, I don't know. 
Maybe I could try printing all of the ASCII characters sequentially and 
see what happens.

Regardless, I'm still not entirely sure what your code is doing anyway.

Thanks, Jacob

PS: I don't know if I might have accidentally sent the message halfway 
writing it; if you see anything weird in another message, that might be 
the reason why.

On 21/04/2020 04:29, Noam Postavsky wrote:
> Jacob Lagares Pozo <jlagarespo@iebesalu.cat> writes:
>
>> I should probably make a simple program that prints a bunch of stuff
>> and then hangs, so I can have predictable and reproducible output,
>> that might help.
> It occurs to me that you should see a "non-local exit" in the trace when
> the error triggers, and the traces just before that should hopefully
> show the swapping of marker positions occuring.
>
>> So what do you exactly mean by that the process is ending normally?
> Oh, hmm, I was still a bit confused.  I thought the (:comint-pmark nil)
> meant the marker was deleted, but actually it's just because around the
> call to comint-output-filter a different buffer is current (which makes
> the check in the tracing function fail).  Maybe one more tweak to the
> tracing function:
>
>      (defun bug-40323-get-comint-output-marker ()
>        (list :comint-pmark
>              (let ((buf (and (markerp comint-last-output-start)
>                              (marker-buffer comint-last-output-start))))
>                (when (buffer-live-p buf)
>                  (cons
>                   comint-last-output-start
>                   (process-mark (get-buffer-process buf)))))))

[-- Attachment #2.1: Type: text/html, Size: 5941 bytes --]

[-- Attachment #2.2: bbndlgkhocibkjda.png --]
[-- Type: image/png, Size: 4264 bytes --]

bug#40323: 28.0.50; error in process filter: Invalid search bound (wrong side of point)

[Noam Postavsky]

Jacob Lagares Pozo <jlagarespo@iebesalu.cat> writes:

> If I run it without your patches, it works surprisingly just fine (I
> noticed the original errors pop up most commonly on Slack I guess
> because it prints a lot more?), whereas if I evaluate said patches,
> this is the output of the trace buffer:

I don't see anything unexpected in the trace either.

> I am not sure what does this mean, perhaps it is some special
> character Slack uses for logging that messes with those markers, I
> don't know. Maybe I could try printing all of the ASCII characters
> sequentially and see what happens.

Well, ideally we would want a trace from something that does trigger the
error.

> Regardless, I'm still not entirely sure what your code is doing anyway.

It's basically just printing out the values of the markers, so we might
hopefully notice when they get changed in an unexpected way.

bug#40323: 28.0.50; error in process filter: Invalid search bound (wrong side of point)

[Jacob Lagares Pozo]

[-- Attachment #1: Type: text/plain, Size: 3330 bytes --]

Here is an example output from Slack, even though weirdly enough nothing 
seemed to trigger the error:

|======================================================================<br 
/>
1 -&gt; (comint-output-filter #&lt;process Shell&gt; &quot;[05/12/20, 
13:06:14:636] info: [DESKTOP-SIDE-EFFECT] Update from desktop for keys 
&nbsp;[\&quot;settings\&quot;]&nbsp;<br />
&quot;)(:comint-pmark nil)<br />
| 2 -&gt; (set-marker #&lt;marker at 37370 in *Async Shell Command*&gt; 
37469)(:comint-pmark (#&lt;marker at 37370 in *Async Shell Command*&gt; 
. #&lt;marker at 37469 in *Async Shell Command*&gt;))<br />
| 2 &lt;- set-marker: #&lt;marker at 37469 in *Async Shell 
Command*&gt;(:comint-pmark (#&lt;marker at 37469 in *Async Shell 
Command*&gt; . #&lt;marker at 37469 in *Async Shell Command*&gt;))<br />
| 2 -&gt; (set-marker #&lt;marker at 37469 in *Async Shell Command*&gt; 
37566)(:comint-pmark (#&lt;marker at 37469 in *Async Shell Command*&gt; 
. #&lt;marker at 37469 in *Async Shell Command*&gt;))<br />
| 2 &lt;- set-marker: #&lt;marker at 37566 in *Async Shell 
Command*&gt;(:comint-pmark (#&lt;marker at 37469 in *Async Shell 
Command*&gt; . #&lt;marker at 37566 in *Async Shell Command*&gt;))<br />
| 2 -&gt; (ansi-color-process-output &quot;[05/12/20, 13:06:14:636] 
info: [DESKTOP-SIDE-EFFECT] Update from desktop for keys 
&nbsp;[\&quot;settings\&quot;]&nbsp;<br />
&quot;)(:comint-pmark (#&lt;marker at 37469 in *Async Shell Command*&gt; 
. #&lt;marker at 37566 in *Async Shell Command*&gt;))<br />
| 2 &lt;- ansi-color-process-output: nil(:comint-pmark (#&lt;marker at 
37469 in *Async Shell Command*&gt; . #&lt;marker at 37566 in *Async 
Shell Command*&gt;))<br />
| 2 -&gt; (set-marker #&lt;marker (moves after insertion) at 37566 in 
*Async Shell Command*&gt; 37566)(:comint-pmark (#&lt;marker at 37469 in 
*Async Shell Command*&gt; . #&lt;marker at 37566 in *Async Shell 
Command*&gt;))<br />
| 2 &lt;- set-marker: #&lt;marker (moves after insertion) at 37566 in 
*Async Shell Command*&gt;(:comint-pmark (#&lt;marker at 37469 in *Async 
Shell Command*&gt; . #&lt;marker at 37566 in *Async Shell 
Command*&gt;))<br />
1 &lt;- comint-output-filter: #&lt;marker (moves after insertion) at 
37566 in *Async Shell Command*&gt;(:comint-pmark nil)<br />|

Because I am on the testing branch of Debian, is there any chance Emacs 
got updated and this bug fixed?

On 05/05/2020 19:33, Noam Postavsky wrote:
> Jacob Lagares Pozo <jlagarespo@iebesalu.cat> writes:
>
>> If I run it without your patches, it works surprisingly just fine (I
>> noticed the original errors pop up most commonly on Slack I guess
>> because it prints a lot more?), whereas if I evaluate said patches,
>> this is the output of the trace buffer:
> I don't see anything unexpected in the trace either.
>
>> I am not sure what does this mean, perhaps it is some special
>> character Slack uses for logging that messes with those markers, I
>> don't know. Maybe I could try printing all of the ASCII characters
>> sequentially and see what happens.
> Well, ideally we would want a trace from something that does trigger the
> error.
>
>> Regardless, I'm still not entirely sure what your code is doing anyway.
> It's basically just printing out the values of the markers, so we might
> hopefully notice when they get changed in an unexpected way.

[-- Attachment #2: Type: text/html, Size: 4783 bytes --]

bug#40323: 28.0.50; error in process filter: Invalid search bound (wrong side of point)

[Noam Postavsky]

On Tue, 12 May 2020 at 07:11, Jacob Lagares Pozo
<jlagarespo@iebesalu.cat> wrote:
>
> Here is an example output from Slack, even though weirdly enough nothing seemed to trigger the error:

Do you mean you're not able to trigger the error at all now?

> Because I am on the testing branch of Debian, is there any chance Emacs got updated and this bug fixed?

Doubtful, but I thought you are running an Emacs from master (hence
the 28.0.50)? Or is it some snapshot package? I didn't think Debian
provided those.

bug#40323: 28.0.50; error in process filter: Invalid search bound (wrong side of point)

[Jacob Lagares Pozo]

Oh, I just realized what might have happened.

Do you remember I said earlier I had some problems with my computer? 
Well, before I had just built Emacs from master, but now, I think I 
installed it from the Debian repositories. My config is pretty much 
still the same (with some reorganization) but probably that's a bug with 
a newer version of Emacs.

Should I install the newer version with another prefix and try to 
reproduce it there?

On 13/05/2020 03:21, Noam Postavsky wrote:
> On Tue, 12 May 2020 at 07:11, Jacob Lagares Pozo
> <jlagarespo@iebesalu.cat> wrote:
>> Here is an example output from Slack, even though weirdly enough nothing seemed to trigger the error:
> Do you mean you're not able to trigger the error at all now?
>
>> Because I am on the testing branch of Debian, is there any chance Emacs got updated and this bug fixed?
> Doubtful, but I thought you are running an Emacs from master (hence
> the 28.0.50)? Or is it some snapshot package? I didn't think Debian
> provided those.

bug#40323: 28.0.50; error in process filter: Invalid search bound (wrong side of point)

[Noam Postavsky]

Jacob Lagares Pozo <jlagarespo@iebesalu.cat> writes:

> Should I install the newer version with another prefix and try to
> reproduce it there?

Yes please.

bug#40323: 28.0.50; error in process filter: Invalid search bound (wrong side of point)

[Jacob Lagares Pozo]

[-- Attachment #1: Type: text/plain, Size: 2906 bytes --]

|======================================================================
1 -> (comint-output-filter #<process Shell> "Initializing 
local storage instance at path: /home/sheep/.co\
nfig/Slack/local-settings.json
")(:comint-pmark nil)
| 2 -> (set-marker #<marker in no buffer> 1)(:comint-pmark nil)
| 2 <- set-marker: #<marker at 1 in *Async Shell 
Command*>(:comint-pmark (#<marker at 1 in *Async Shell C\
ommand*> . #<marker at 1 in *Async Shell Command*>))
| 2 -> (set-marker #<marker at 1 in *Async Shell Command*> 
92)(:comint-pmark (#<marker at 1 in *Async She\
ll Command*> . #<marker at 1 in *Async Shell Command*>))
| 2 <- set-marker: #<marker at 92 in *Async Shell 
Command*>(:comint-pmark (#<marker at 1 in *Async Shell \
Command*> . #<marker at 92 in *Async Shell Command*>))
| 2 -> (ansi-color-process-output "Initializing local storage 
instance at path: /home/sheep/.config/Slack\
/local-settings.json
")(:comint-pmark (#<marker at 1 in *Async Shell Command*> . 
#<marker at 92 in *Async Shell Command*>))
| 2 <- ansi-color-process-output: #<marker in no 
buffer>(:comint-pmark (#<marker at 1 in *Async Shell Com\
mand*> . #<marker at 92 in *Async Shell Command*>))
| 2 -> (comint-adjust-window-point #<window 8 on *Async Shell 
Command*> #<process Shell>)(:comint-pmark (\
#<marker at 1 in *Async Shell Command*> . #<marker at 92 in 
*Async Shell Command*>))
| 2 <- comint-adjust-window-point: nil(:comint-pmark (#<marker at 
1 in *Async Shell Command*> . #<marker \
at 92 in *Async Shell Command*>))
| 2 -> (set-marker #<marker (moves after insertion) at 92 in 
*Async Shell Command*> 92)(:comint-pmark (#<\
marker at 1 in *Async Shell Command*> . #<marker at 92 in *Async 
Shell Command*>))
| 2 <- set-marker: #<marker (moves after insertion) at 92 in 
*Async Shell Command*>(:comint-pmark (#<mark\
er at 1 in *Async Shell Command*> . #<marker at 92 in *Async Shell 
Command*>))
1 <- comint-output-filter: #<marker (moves after insertion) at 92 
in *Async Shell Command*>(:comint-pmark\
  nil)
|

This is on master, I can't seem to reproduce the bug, with or without 
the patch. This is getting progressively weirder; I remember perfectly 
how I launched just about anything and the error would start triggering 
immediately and it was super annoying.

All the packages are still the same. I am doing all the tests on Slack 
because it is the one I remembered that would trigger it more often. I 
have no clue what could be different this time around.

On 15/05/2020 17:45, Noam Postavsky wrote:
> Jacob Lagares Pozo <jlagarespo@iebesalu.cat> writes:
>
>> Should I install the newer version with another prefix and try to
>> reproduce it there?
> Yes please.

[-- Attachment #2: Type: text/html, Size: 5844 bytes --]

bug#40323: 28.0.50; error in process filter: Invalid search bound (wrong side of point)

[Noam Postavsky]

Jacob Lagares Pozo <jlagarespo@iebesalu.cat> writes:

> This is on master, I can't seem to reproduce the bug, with or without
> the patch. This is getting progressively weirder; I remember perfectly 
> how I launched just about anything and the error would start
> triggering immediately and it was super annoying.

Have you tried also without the tracing code enabled?  It's possible the
tracing changes the timing which could affect the reproduction.

bug#40323: 28.0.50; error in process filter: Invalid search bound (wrong side of point)

[Lars Ingebrigtsen]

Noam Postavsky <npostavs@gmail.com> writes:

>> This is on master, I can't seem to reproduce the bug, with or without
>> the patch. This is getting progressively weirder; I remember perfectly 
>> how I launched just about anything and the error would start
>> triggering immediately and it was super annoying.
>
> Have you tried also without the tracing code enabled?  It's possible the
> tracing changes the timing which could affect the reproduction.

(I'm going through old bug reports that unfortunately weren't resolved
at the time.)

This was a couple years ago -- Jacob, do you see this problem in more
recent versions of Emacs, or is it still apparently gone?  Parts of the
ansi code has been substantially rewritten over the past years...

-- 
(domestic pets only, the antidote for overdose, milk.)
   bloggy blog: http://lars.ingebrigtsen.no

bug#40323: 28.0.50; error in process filter: Invalid search bound (wrong side of point)

[Lars Ingebrigtsen]

Lars Ingebrigtsen <larsi@gnus.org> writes:

> This was a couple years ago -- Jacob, do you see this problem in more
> recent versions of Emacs, or is it still apparently gone?  Parts of the
> ansi code has been substantially rewritten over the past years...

More information was requested, but no response was given within a
month, so I'm closing this bug report.  If the problem still exists,
please respond to this email and we'll reopen the bug report.

-- 
(domestic pets only, the antidote for overdose, milk.)
   bloggy blog: http://lars.ingebrigtsen.no