bug#18504: 24.3.93; posn-at-point intermittently returns wrong value for a valid buffer position

bug#18504: 24.3.93; posn-at-point intermittently returns wrong value for a valid buffer position

[Dmitry]

(Not a regression, same in Emacs 24.3).

I've been trying to understand what triggers this and create a smaller
repro case, but so far had no luck. So we'll use the company package.

1. git clone https://github.com/company-mode/company-mode.git

2. cd company-mode; git checkout foofoofoo

(Note that the last commit in this branch adds a `message' call that
outputs a multiline string. This doesn't seem to be mandatory, but makes
reproduction easier).

3. emacs -L . -Q

4. (require 'company)
M-x global-company-mode
;; Pick another binding if you're in tty
(global-set-key (kbd "C-/") 'company-complete-common)

5. Type `C-o' several times, so that there are a few empty lines under
the current one.

6. Type `  a'. Again not mandatory, but I've had better odds of
reproduction with this line content.

7. Quickly and repeatedly mash `C-/' and `C-g', a lot.

You'll see the popup appearing under the current line and column, but
sometimes noticeably displaced to the right (like by 15 columns). If it
doesn't happen, try mashing the keys in different rhythms, faster or
slower, and kind of simultaneously (not alternating).

After you've seen it, eval (setq bidi-display-reordering nil).

Mash the keys again, now the popup will occasionally be displayed below
its intended position, by 11 lines or so.

If you add some debugging output to `company--col-row', you'll see that,
for the same value of POS, (posn-at-point pos) returns in these odd
moments "position objects" with very different X and Y coordinates.

This bug is most likely related to the `company-pseudo-tooltip-overlay'
now being positioned starting with the end of the current line (before
the newline), because if I add a space after the current point, I can't
reproduce it anymore. This was at one point suggested by Eli
(http://lists.gnu.org/archive/html/emacs-devel/2014-08/msg00328.html),
or at least hinted at.

I'd be happy to help debugging this further, if someone tells me how.

In GNU Emacs 24.3.93.3 (x86_64-unknown-linux-gnu, GTK+ Version 3.10.8)
 of 2014-09-05 on axl
Repository revision: 117482 monnier@iro.umontreal.ca-20140904161426-2072ebabqpyhaadw
Windowing system distributor `The X.Org Foundation', version 11.0.11501000
System Description:	Ubuntu 14.04.1 LTS

bug#18504: 24.3.93; posn-at-point intermittently returns wrong value for a valid buffer position

[Eli Zaretskii]

> From: Dmitry <dgutov@yandex.ru>
> Date: Fri, 19 Sep 2014 04:56:04 +0400
> 
> I'd be happy to help debugging this further, if someone tells me how.

I have no idea, since the recipe includes too many factors, and the
problem is intermittent and timing dependent.  Need a simpler recipe.

Sorry.

bug#18504: 24.3.93; posn-at-point intermittently returns wrong value for a valid buffer position

[Dmitry Gutov]

On 09/19/2014 10:21 AM, Eli Zaretskii wrote:

 > I have no idea, since the recipe includes too many factors, and the
> problem is intermittent and timing dependent.  Need a simpler recipe.

That's too bad.

Wouldn't setting a conditional breakpoint help? For example, when the 
return value is right, returned position's X coordinate is non-zero. 
However, when the bug manifests, and `bidi-display-reordering' is nil, 
the X coordinate of the returned position is zero.

bug#18504: 24.3.93; posn-at-point intermittently returns wrong value for a valid buffer position

[Eli Zaretskii]

> Date: Fri, 19 Sep 2014 14:25:05 +0400
> From: Dmitry Gutov <dgutov@yandex.ru>
> CC: 18504@debbugs.gnu.org
> 
> On 09/19/2014 10:21 AM, Eli Zaretskii wrote:
> 
>  > I have no idea, since the recipe includes too many factors, and the
> > problem is intermittent and timing dependent.  Need a simpler recipe.
> 
> That's too bad.

Indeed.  But it's impossible to debug what you described, at least I
don't know how to do that, not without a recipe that can reliably
trigger the problem.

> Wouldn't setting a conditional breakpoint help?

Conditional breakpoint where?

With these issues, the only way to find the bug is to step through the
offending code _before_ it produces the wrong values.  So we need a
condition that happens at the beginning of that code, not where it
produces the final wrong results.

bug#18504: 24.3.93; posn-at-point intermittently returns wrong value for a valid buffer position

[Dmitry Gutov]

On 09/19/2014 05:12 PM, Eli Zaretskii wrote:

>> Wouldn't setting a conditional breakpoint help?
>
> Conditional breakpoint where?

In the "call a function" routine, maybe? If the function is 
"posn-at-point", and if its returned X coord is zero, halt!

Doing it in Elisp doesn't seem to produce the desired result, because 
edebug doesn't exactly stop Emacs in place.

> With these issues, the only way to find the bug is to step through the
> offending code _before_ it produces the wrong values.  So we need a
> condition that happens at the beginning of that code, not where it
> produces the final wrong results.

If `posn-at-point' is itself stateless (and doesn't modify any relevant 
caches), why not call it again at that point?

bug#18504: 24.3.93; posn-at-point intermittently returns wrong value for a valid buffer position

[Eli Zaretskii]

> Date: Fri, 19 Sep 2014 17:29:31 +0400
> From: Dmitry Gutov <dgutov@yandex.ru>
> CC: 18504@debbugs.gnu.org
> 
> On 09/19/2014 05:12 PM, Eli Zaretskii wrote:
> 
> >> Wouldn't setting a conditional breakpoint help?
> >
> > Conditional breakpoint where?
> 
> In the "call a function" routine, maybe? If the function is 
> "posn-at-point", and if its returned X coord is zero, halt!

And then do what?  The damage was already done, and the debugger
cannot tell you how the code got to that wrong result post-factum.

Btw, why is it important what happens when the user types C-g, i.e. if
she abandons the completion?  Or does the problem happen without C-g
as well?

> > With these issues, the only way to find the bug is to step through the
> > offending code _before_ it produces the wrong values.  So we need a
> > condition that happens at the beginning of that code, not where it
> > produces the final wrong results.
> 
> If `posn-at-point' is itself stateless (and doesn't modify any relevant 
> caches), why not call it again at that point?

Because it will most probably produce the correct result.

But you can try that yourself: insert a second call under the
conditions that you know are evidence of the problem.  If that is
repeatable, i.e. if that second call always produces the wrong result,
then I have what I need.

bug#18504: 24.3.93; posn-at-point intermittently returns wrong value for a valid buffer position

[Dmitry Gutov]

On 09/19/2014 05:35 PM, Eli Zaretskii wrote:

> Btw, why is it important what happens when the user types C-g, i.e. if
> she abandons the completion?  Or does the problem happen without C-g
> as well?

I'm not quite sure how we get to that point, to be honest. The code gets 
called from `company-post-command' (which is in post-command-hook), but 
this-command is nil when that happens.

>> If `posn-at-point' is itself stateless (and doesn't modify any relevant
>> caches), why not call it again at that point?
>
> Because it will most probably produce the correct result.
>
> But you can try that yourself: insert a second call under the
> conditions that you know are evidence of the problem.  If that is
> repeatable, i.e. if that second call always produces the wrong result,
> then I have what I need.

It is. Try this:

diff --git a/company.el b/company.el
index fdf09f7..01a3cb5 100644
--- a/company.el
+++ b/company.el
@@ -782,7 +782,13 @@ means that `company-mode' is always turned on 
except in `message-mode' buffers."
      (cons (+ col (window-hscroll)) row)))

  (defun company--col-row (&optional pos)
-  (company--posn-col-row (posn-at-point pos)))
+  (let ((posn (posn-at-point pos)))
+    ;; Completion should be invoked at column > 1.
+    (when (zerop (car (posn-x-y posn)))
+      (message "company--col-row zero!")
+      (message "then:")
+      (message "%s" (posn-x-y (posn-at-point pos))))
+    (company--posn-col-row posn)))

  (defun company--row (&optional pos)
    (cdr (company--col-row pos)))

I get:

company--col-row zero!
then:
(0 . 198)

bug#18504: 24.3.93; posn-at-point intermittently returns wrong value for a valid buffer position

[Eli Zaretskii]

> Date: Fri, 19 Sep 2014 17:46:57 +0400
> From: Dmitry Gutov <dgutov@yandex.ru>
> CC: 18504@debbugs.gnu.org
> 
> On 09/19/2014 05:35 PM, Eli Zaretskii wrote:
> 
> > Btw, why is it important what happens when the user types C-g, i.e. if
> > she abandons the completion?  Or does the problem happen without C-g
> > as well?
> 
> I'm not quite sure how we get to that point, to be honest.

??? Your recipe includes fast presses on C-/ and C-g.  Or did I
misunderstand?

> --- a/company.el
> +++ b/company.el
> @@ -782,7 +782,13 @@ means that `company-mode' is always turned on 
> except in `message-mode' buffers."
>       (cons (+ col (window-hscroll)) row)))
> 
>   (defun company--col-row (&optional pos)
> -  (company--posn-col-row (posn-at-point pos)))
> +  (let ((posn (posn-at-point pos)))
> +    ;; Completion should be invoked at column > 1.
> +    (when (zerop (car (posn-x-y posn)))
> +      (message "company--col-row zero!")
> +      (message "then:")
> +      (message "%s" (posn-x-y (posn-at-point pos))))
> +    (company--posn-col-row posn)))
> 
>   (defun company--row (&optional pos)
>     (cdr (company--col-row pos)))
> 
> I get:
> 
> company--col-row zero!
> then:
> (0 . 198)

Thanks, but with what sequence of commands do you get that?

bug#18504: 24.3.93; posn-at-point intermittently returns wrong value for a valid buffer position

[Dmitry Gutov]

On 09/19/2014 06:00 PM, Eli Zaretskii wrote:

>> I'm not quite sure how we get to that point, to be honest.
>
> ??? Your recipe includes fast presses on C-/ and C-g.  Or did I
> misunderstand?

Yes. I'm not sure how we get there code-wise, though.

>> I get:
>>
>> company--col-row zero!
>> then:
>> (0 . 198)
>
> Thanks, but with what sequence of commands do you get that?

Same as previously described, no change there. Just make sure to (setq 
bidi-display-reordering nil). When it's t, `posn-at-point' (likewise 
intermittently) returns a differentl wrong value.

bug#18504: 24.3.93; posn-at-point intermittently returns wrong value for a valid buffer position

[Eli Zaretskii]

> Date: Fri, 19 Sep 2014 18:06:47 +0400
> From: Dmitry Gutov <dgutov@yandex.ru>
> CC: 18504@debbugs.gnu.org
> On 09/19/2014 06:00 PM, Eli Zaretskii wrote:
> 
> >> I'm not quite sure how we get to that point, to be honest.
> >
> > ??? Your recipe includes fast presses on C-/ and C-g.  Or did I
> > misunderstand?
> 
> Yes. I'm not sure how we get there code-wise, though.

So I'm asking again: why does it matter what happens after a C-g,
i.e. after the user abandons the completion?

> >> I get:
> >>
> >> company--col-row zero!
> >> then:
> >> (0 . 198)
> >
> > Thanks, but with what sequence of commands do you get that?
> 
> Same as previously described, no change there. Just make sure to (setq 
> bidi-display-reordering nil).

Can you show the full value of posn-at-point in that case?

bug#18504: 24.3.93; posn-at-point intermittently returns wrong value for a valid buffer position

[Eli Zaretskii]

> Date: Fri, 19 Sep 2014 18:06:47 +0400
> From: Dmitry Gutov <dgutov@yandex.ru>
> CC: 18504@debbugs.gnu.org
> 
> On 09/19/2014 06:00 PM, Eli Zaretskii wrote:
> 
> >> I'm not quite sure how we get to that point, to be honest.
> >
> > ??? Your recipe includes fast presses on C-/ and C-g.  Or did I
> > misunderstand?
> 
> Yes. I'm not sure how we get there code-wise, though.
> 
> >> I get:
> >>
> >> company--col-row zero!
> >> then:
> >> (0 . 198)
> >
> > Thanks, but with what sequence of commands do you get that?
> 
> Same as previously described, no change there. Just make sure to (setq 
> bidi-display-reordering nil). When it's t, `posn-at-point' (likewise 
> intermittently) returns a differentl wrong value.

I tried that, but the probability of getting the problem is too low on
my system.  I see it maybe once in many hundreds of attempts.

What I did see is that the coordinates returned in that case are for
the end of buffer (or maybe the last visible glyph in the window, if
EOB is beyond that).  So the first thing I'd try to do is print the
argument POS you pass to posn-at-point in those cases -- could it be t
or some other incorrect/unexpected value?

bug#18504: 24.3.93; posn-at-point intermittently returns wrong value for a valid buffer position

[Dmitry Gutov]

On 09/19/2014 06:54 PM, Eli Zaretskii wrote:

> I tried that, but the probability of getting the problem is too low on
> my system.  I see it maybe once in many hundreds of attempts.

Have you tried that with the foofoofoo branch? The message output raises 
the odds on my machine considerably (1 in 5-10 attempts).

> What I did see is that the coordinates returned in that case are for
> the end of buffer (or maybe the last visible glyph in the window, if
> EOB is beyond that).

Have you tried adding more lines at the end of the buffer? Even in a 
tall window, and with eob far away, the incorrect value is only off by 
~10 lines here. Which, incidentally, is close to how many lines the 
popup overlay takes up.

> So the first thing I'd try to do is print the
> argument POS you pass to posn-at-point in those cases -- could it be t
> or some other incorrect/unexpected value?

Nope. POS is always the same.

bug#18504: 24.3.93; posn-at-point intermittently returns wrong value for a valid buffer position

[Dmitry Gutov]

On 09/19/2014 06:21 PM, Eli Zaretskii wrote:

>> Yes. I'm not sure how we get there code-wise, though.
>
> So I'm asking again: why does it matter what happens after a C-g,
> i.e. after the user abandons the completion?

1. I'm not 100% sure yet if the problem happens after C-/ or C-g. Just 
that both need to be pressed at least once.

2. Apparently, one of the last C-g presses (probably the last one) calls 
`keyboard-quit' instead of `company-abort', which in the command, bound 
in `company-active-map', that aborts completion.

So, I haven't wrapped my head around it yet, but on the odd chance I 
won't manage to do that before Emacs 24.4 release and it's not actually 
a bug in company-mode, maybe it's worth investigating whether 
`posn-at-point' behaves improperly anyway, first.

>> Same as previously described, no change there. Just make sure to (setq
>> bidi-display-reordering nil).
>
> Can you show the full value of posn-at-point in that case?

With this code:

diff --git a/company.el b/company.el
index fdf09f7..5c901c6 100644
--- a/company.el
+++ b/company.el
@@ -782,7 +782,12 @@ means that `company-mode' is always turned on 
except in `message-mode' buffers."
      (cons (+ col (window-hscroll)) row)))

  (defun company--col-row (&optional pos)
-  (company--posn-col-row (posn-at-point pos)))
+  (message "foofoo\nfoo")
+  (let ((posn (posn-at-point pos)))
+    (when (zerop (car (posn-x-y posn)))
+      (message "posn at %s #1 %s" pos posn)
+      (message "posn at %s #2 %s" pos (posn-at-point pos)))
+    (company--posn-col-row posn)))

  (defun company--row (&optional pos)
    (cdr (company--col-row pos)))

I get the following output:

<...>
foofoo
foo
posn at nil #1 (#<window 16 on *scratch*> 206 (0 . 270) 0 nil 206 (0 . 
15) nil (0 . 0) (9 . 18))
posn at nil #2 (#<window 16 on *scratch*> 206 (0 . 270) 0 nil 206 (0 . 
15) nil (0 . 0) (0 . 0))
foofoo
foo
posn at 195 #1 (#<window 16 on *scratch*> 206 (0 . 270) 0 nil 206 (0 . 
15) nil (0 . 0) (0 . 0))
posn at 195 #2 (#<window 16 on *scratch*> 206 (0 . 270) 0 nil 206 (0 . 
15) nil (0 . 0) (0 . 0))
<...>
foofoo
foo
posn at nil #1 (#<window 16 on *scratch*> 206 (0 . 270) 0 nil 206 (0 . 
15) nil (0 . 0) (0 . 0))
posn at nil #2 (#<window 16 on *scratch*> 206 (0 . 270) 0 nil 206 (0 . 
15) nil (0 . 0) (0 . 0))
foofoo
foo
posn at 195 #1 (#<window 16 on *scratch*> 206 (0 . 270) 0 nil 206 (0 . 
15) nil (0 . 0) (0 . 0))
posn at 195 #2 (#<window 16 on *scratch*> 206 (0 . 270) 0 nil 206 (0 . 
15) nil (0 . 0) (0 . 0))
<...>

Point is indeed at 195. Note that the last element is sometimes 
different between `posn-at-point' invocations ((9 . 18) vs (0 . 0)), but 
sometimes not (both pairs of zeros)).

bug#18504: 24.3.93; posn-at-point intermittently returns wrong value for a valid buffer position

[Eli Zaretskii]

> Date: Fri, 19 Sep 2014 21:52:29 +0400
> From: Dmitry Gutov <dgutov@yandex.ru>
> CC: 18504@debbugs.gnu.org
> 
> On 09/19/2014 06:54 PM, Eli Zaretskii wrote:
> 
> > I tried that, but the probability of getting the problem is too low on
> > my system.  I see it maybe once in many hundreds of attempts.
> 
> Have you tried that with the foofoofoo branch?

Of course.

> > So the first thing I'd try to do is print the
> > argument POS you pass to posn-at-point in those cases -- could it be t
> > or some other incorrect/unexpected value?
> 
> Nope. POS is always the same.

I sometimes see nil there.

bug#18504: 24.3.93; posn-at-point intermittently returns wrong value for a valid buffer position

[Dmitry Gutov]

On 09/19/2014 11:35 PM, Eli Zaretskii wrote:

>> Nope. POS is always the same.
>
> I sometimes see nil there.

True (there are two code paths that call the function, and one of them 
without the optional argument): but it just means "value of point", 
which is the same.

And anyway the bug gets triggered in both situations, with nil, and with 
integer equal to point.

bug#18504: 24.3.93; posn-at-point intermittently returns wrong value for a valid buffer position

[Eli Zaretskii]

> Date: Fri, 19 Sep 2014 23:33:58 +0400
> From: Dmitry Gutov <dgutov@yandex.ru>
> CC: 18504@debbugs.gnu.org
> 
> posn at nil #1 (#<window 16 on *scratch*> 206 (0 . 270) 0 nil 206 (0 . 
> 15) nil (0 . 0) (9 . 18))
> posn at nil #2 (#<window 16 on *scratch*> 206 (0 . 270) 0 nil 206 (0 . 
> 15) nil (0 . 0) (0 . 0))
> foofoo
> foo
> posn at 195 #1 (#<window 16 on *scratch*> 206 (0 . 270) 0 nil 206 (0 . 
> 15) nil (0 . 0) (0 . 0))
> posn at 195 #2 (#<window 16 on *scratch*> 206 (0 . 270) 0 nil 206 (0 . 
> 15) nil (0 . 0) (0 . 0))
> <...>
> foofoo
> foo
> posn at nil #1 (#<window 16 on *scratch*> 206 (0 . 270) 0 nil 206 (0 . 
> 15) nil (0 . 0) (0 . 0))
> posn at nil #2 (#<window 16 on *scratch*> 206 (0 . 270) 0 nil 206 (0 . 
> 15) nil (0 . 0) (0 . 0))
> foofoo
> foo
> posn at 195 #1 (#<window 16 on *scratch*> 206 (0 . 270) 0 nil 206 (0 . 
> 15) nil (0 . 0) (0 . 0))
> posn at 195 #2 (#<window 16 on *scratch*> 206 (0 . 270) 0 nil 206 (0 . 
> 15) nil (0 . 0) (0 . 0))
> <...>
> 
> Point is indeed at 195. Note that the last element is sometimes 
> different between `posn-at-point' invocations ((9 . 18) vs (0 . 0)), but 
> sometimes not (both pairs of zeros)).

This happens when posn-at-point is called with the company-mode
overlay still (or already?) in place at that position.  That overlay
has the invisible property, so it hides the buffer text starting at
the position with which you call posn-at-point.  Therefore,
posn-at-point returns information about the first visible buffer
position after the overlay string.

So I think you need to make sure inside company--col-row that the
overlay is popped down, before you call posn-at-point.  Evidently, in
some scenarios it isn't.  The buffer position returned by
posn-at-point can serve as your control variable: if it is different
from the position that is the argument to company--col-row, you have
this situation.

bug#18504: 24.3.93; posn-at-point intermittently returns wrong value for a valid buffer position

[Dmitry Gutov]

On 09/20/2014 11:13 AM, Eli Zaretskii wrote:

> This happens when posn-at-point is called with the company-mode
> overlay still (or already?) in place at that position.  That overlay
> has the invisible property, so it hides the buffer text starting at
> the position with which you call posn-at-point.  Therefore,
> posn-at-point returns information about the first visible buffer
> position after the overlay string.

I see, thanks. But does the fact that we get a different return value 
with different values of bidi-display-reordering, look right to you?

> So I think you need to make sure inside company--col-row that the
> overlay is popped down, before you call posn-at-point.  Evidently, in
> some scenarios it isn't.

Yes, seems to be a bug with the way we set the "current" keymap when 
completion is performed (the popup is displayed only during that time). 
Thank you for confirming, I'm looking into it.

> The buffer position returned by
> posn-at-point can serve as your control variable: if it is different
> from the position that is the argument to company--col-row, you have
> this situation.

Ok. I can just directly check if the overlay has the `invisible' 
property set to t or not, though. We keep a reference to the overlay.

bug#18504: 24.3.93; posn-at-point intermittently returns wrong value for a valid buffer position

[Eli Zaretskii]

> Date: Tue, 23 Sep 2014 22:39:49 +0400
> From: Dmitry Gutov <dgutov@yandex.ru>
> CC: 18504-done@debbugs.gnu.org
> 
> On 09/20/2014 11:13 AM, Eli Zaretskii wrote:
> 
> > This happens when posn-at-point is called with the company-mode
> > overlay still (or already?) in place at that position.  That overlay
> > has the invisible property, so it hides the buffer text starting at
> > the position with which you call posn-at-point.  Therefore,
> > posn-at-point returns information about the first visible buffer
> > position after the overlay string.
> 
> I see, thanks. But does the fact that we get a different return value 
> with different values of bidi-display-reordering, look right to you?

You are not supposed to change the value of bidi-display-reordering.
This variable exists only for debugging.  So what happens when it is
nil is "undefined behavior" ;-)