Slow cursor on reMarkable 2 on Ubuntu 18.04

[jonahweissman]

I'm using the rm2 branch for my reMarkable2, and I seem to be experiencing some sort of lag. My cursor does not move as quickly as my marker does. As a result if I move my marker for a long time, my cursor will keep moving even after my marker has stopped. I tried the script from #37 (comment), and it seemed normal, total = 2.32. My suspicion is that processing the input from the reMarkable happens slower than real time.

As a work around, I changed the script to update the cursor less often and the lag disappeared, but the mouse movement got more choppy. Here's the change I made.

diff --git a/remarkable_mouse/pynput.py b/remarkable_mouse/pynput.py
index c9734d8..d4e1ccf 100644
--- a/remarkable_mouse/pynput.py
+++ b/remarkable_mouse/pynput.py
@@ -1,4 +1,5 @@
 import logging
+import random
 import struct
 from screeninfo import get_monitors
 
@@ -103,7 +104,7 @@ def read_tablet(args, remote_device):
 
 
             # only move when x and y are updated for smoother mouse
-            if new_x and new_y:
+            if new_x and new_y and random.randrange(20) == 0:
                 mapped_x, mapped_y = remap(
                     x, y,
                     wacom_width, wacom_height,

I have previously used remarkable_mouse on my same computer with a reMarkable 1 with no lag.

There's no need to make any changes if I'm the only one having this problem; I'm mostly posting this to see if others are dealing with the same thing.

[michalopler]

The same happens to me. Moreover, while your fix helps a bit it is still far from removing all the lag.

[Evidlo]

I made a stripped down version of the script here which should aid in debugging this problem.

[jonahweissman]

I made a stripped down version of the script here which should aid in debugging this problem.

I have the simple branch running, and I'm still getting the same lag. Should I try profiling the script?

[Evidlo]

Sure. Just post your method and I can compare it to rm1+Debian where I don't get any lag.

[jonahweissman]

I ran this on the simple branch (the cat is to keep my password out of my command line history):

> python3 -m cProfile -s tottime remouse.py $(cat) > profile

and here is the first 30 or so lines of the output:

connected
         2179670 function calls (2145399 primitive calls) in 22.282 seconds

   Ordered by: internal time

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
   168393    6.078    0.000    6.078    0.000 {method 'acquire' of '_thread.lock' objects}
    30189    3.906    0.000    3.906    0.000 {built-in method select.select}
    15102    2.148    0.000    2.148    0.000 {method 'send' of '_socket.socket' objects}
    15095    1.255    0.000   10.582    0.001 display.py:387(send_and_recv)
    17246    1.012    0.000    1.607    0.000 rq.py:983(to_binary)
15112/15096    0.570    0.000    0.925    0.000 rq.py:1135(parse_binary)
    15092    0.395    0.000    1.940    0.000 display.py:782(parse_request_response)
    15094    0.361    0.000    2.423    0.000 display.py:677(parse_response)
    15098    0.310    0.000    0.310    0.000 {method 'recv' of '_socket.socket' objects}
   461424    0.295    0.000    0.295    0.000 {built-in method builtins.isinstance}
    15092    0.270    0.000   12.517    0.001 rq.py:1358(__init__)
     6456    0.231    0.000   10.632    0.002 _xorg.py:78(_position_get)
    15090    0.208    0.000    0.231    0.000 display.py:63(__getitem__)
    15092    0.192    0.000   10.797    0.001 rq.py:1371(reply)
    15092    0.184    0.000    0.232    0.000 display.py:922(get_waiting_replyrequest)
249040/218729    0.178    0.000    0.222    0.000 {built-in method builtins.len}
    53126    0.177    0.000    0.177    0.000 {built-in method _struct.unpack}
        1    0.171    0.171   22.283   22.283 remouse.py:1(<module>)
     7621    0.164    0.000    5.860    0.001 buffered_pipe.py:126(read)
    15092    0.147    0.000    1.085    0.000 rq.py:1391(_parse_response)
      253    0.141    0.001    0.141    0.001 {method 'read' of '_io.FileIO' objects}
    17244    0.140    0.000    0.186    0.000 display.py:353(send_request)

I'm beginning to think that some part of the script is especially CPU intensive on my computer because the lag is drastically reduced when remouse is the only program running. I also see huge spikes in CPU usage when I move my marker (although I am using an older laptop, so it's not a particularly capable chip).

[Evidlo]

@jonahweissman Can you try out the simple_evsync branch? It is a bit more intelligent about when to process events. Also I added a @Profile decorator so we can get line-by-line profiling.

kernprof -l remouse.py password
python -m line_profiler remouse.py.lprof

Line #      Hits         Time  Per Hit   % Time  Line Contents
==============================================================
    98                                           @profile
    99                                           def loop():
   100         1          3.0      3.0      0.0      x = y = 0
   101         1          1.0      1.0      0.0      event_log = []
   102                                               while True:
   103                                                   # read one evdev event at a time
   104     18906   10643896.0    563.0     46.0          _, _, e_type, e_code, e_value = struct.unpack('2IHHi', stdout.read(16))
   105                                           
   106                                                   # if sync event, process all previously logged events
   107     18906      38517.0      2.0      0.2          if e_type == e_type_sync:
   108     18906      22776.0      1.2      0.1              for log_type, log_code, log_value in event_log:
   109                                           
   110                                                           # handle stylus coordinates
   111     14229      14598.0      1.0      0.1                  if log_type == e_type_abs:
   112     14229      14561.0      1.0      0.1                      if log_code == e_code_stylus_xpos:
   113      4645       4450.0      1.0      0.0                          x = log_value
   114     14229      14601.0      1.0      0.1                      if log_code == e_code_stylus_ypos:
   115      4655       4703.0      1.0      0.0                          y = log_value
   116                                                           # handle stylus press/release
   117     14229      15415.0      1.1      0.1                  if log_type == e_type_key:
   118                                                               if log_code == e_code_touch:
   119                                                                   if log_value == 1:
   120                                                                       mouse.press(Button.left)
   121                                                                   else:
   122                                                                       mouse.release(Button.left)
   123                                           
   124      9354      57133.0      6.1      0.2              mapped_x, mapped_y = remap(
   125      4677       4718.0      1.0      0.0                  x, y,
   126      4677       5088.0      1.1      0.0                  wacom_width, wacom_height,
   127      4677       6398.0      1.4      0.0                  monitor.width, monitor.height,
   128      4677       5089.0      1.1      0.0                  mode, orientation
   129                                                       )
   130      9353    5825139.0    622.8     25.2              mouse.move(
   131      4677    3379800.0    722.6     14.6                  monitor.x + mapped_x - mouse.position[0],
   132      4677    3024786.0    646.7     13.1                  monitor.y + mapped_y - mouse.position[1]
   133                                                       )
   134      4676      13226.0      2.8      0.1              event_log = []
   135                                                   # otherwise, log the event
   136                                                   else:
   137     14229      26573.0      1.9      0.1              event_log.append((e_type, e_code, e_value))

Also try to be drawing circles before you start the program until you kill it so the profiler doesn't get stuck waiting for more events.

[Evidlo]

I made a bit of progress debugging this problem on Windows: paramiko/paramiko#1801

It may be related.

[jonahweissman]

Here's my output from simple_evsync:

Timer unit: 1e-06 s

Total time: 9.49778 s
File: remouse.py
Function: loop at line 100

Line #      Hits         Time  Per Hit   % Time  Line Contents
==============================================================
   100                                           @profile
   101                                           def loop():
   102                                               global event_log
   103                                               while True:
   104                                                   # read one evdev event at a time
   105      8412     517572.0     61.5      5.4          _, _, e_type, e_code, e_value = struct.unpack('2IHHi', stdout.read(16))
   106                                           
   107                                                   # if sync event, process all previously logged events
   108      8412      18574.0      2.2      0.2          if e_type == e_type_sync:
   109      8412      15865.0      1.9      0.2              for log_type, log_code, log_value in event_log:
   110                                           
   111                                                           # handle stylus coordinates
   112      6315      10899.0      1.7      0.1                  if log_type == e_type_abs:
   113      6315       9765.0      1.5      0.1                      if log_code == e_code_stylus_xpos:
   114      2079       2718.0      1.3      0.0                          x = log_value
   115      6315      10228.0      1.6      0.1                      if log_code == e_code_stylus_ypos:
   116      2066       2975.0      1.4      0.0                          y = log_value
   117                                                           # handle stylus press/release
   118      6315       9343.0      1.5      0.1                  if log_type == e_type_key:
   119                                                               if log_code == e_code_touch:
   120                                                                   if log_value == 1:
   121                                                                       mouse.press(Button.left)
   122                                                                   else:
   123                                                                       mouse.release(Button.left)
   124                                           
   125      4194      43780.0     10.4      0.5              mapped_x, mapped_y = remap(
   126      2097       3542.0      1.7      0.0                  x, y,
   127      2097       4028.0      1.9      0.0                  wacom_width, wacom_height,
   128      2097       5709.0      2.7      0.1                  monitor.width, monitor.height,
   129      2097       3552.0      1.7      0.0                  mode, orientation
   130                                                       )
   131      4193    4355363.0   1038.7     45.9              mouse.move(
   132      2097    2347439.0   1119.4     24.7                  monitor.x + mapped_x - mouse.position[0],
   133      2097    2108640.0   1005.6     22.2                  monitor.y + mapped_y - mouse.position[1]
   134                                                       )
   135      2096      11643.0      5.6      0.1              event_log = []
   136                                                   # otherwise, log the event
   137                                                   else:
   138      6315      16144.0      2.6      0.2              event_log.append((e_type, e_code, e_value))

I made sure to continuously draw circles the entire time remouse.py was running.

I made a bit of progress debugging this problem on Windows: paramiko/paramiko#1801

I think this could explain my experience. If the big dumps of input take longer to consume than the time spent waiting for them, then the cursor would get farther and farther behind the movements of the marker.

[jonahweissman]

I tried the rm2 branch with the same hardware but with a different Linux distro installed, and I still had lag. I think it might just be that the processor is too old.

[nils-werner]

Using pyinstrument I noticed that remouse is spending a lot of time in read(), and inside that, wait() and lock.acquire(). So it seemed like a waiting issue for me.

5.881 <module>  <string>:1
└─ 5.881 run_module  runpy.py:195
      [2 frames hidden]  runpy
         5.881 _run_code  runpy.py:62
         └─ 5.881 <module>  remarkable_mouse/__main__.py:1
            ├─ 5.817 main  remarkable_mouse/remarkable_mouse.py:106
            │  ├─ 5.401 read_tablet  remarkable_mouse/pynput.py:60
            │  │  ├─ 1.847 read  paramiko/file.py:172
            │  │  │     [5 frames hidden]  paramiko, threading
            │  │  │        1.847 wait  threading.py:264
            │  │  │        └─ 1.847 lock.acquire  <built-in>:0

I can improve performance significantly by setting bufsize=16 and timeout=0, which eliminates that wait time almost entirely

5.905 <module>  <string>:1
└─ 5.905 run_module  runpy.py:195
      [2 frames hidden]  runpy
         5.905 _run_code  runpy.py:62
         └─ 5.905 <module>  remarkable_mouse/__main__.py:1
            ├─ 5.835 main  remarkable_mouse/remarkable_mouse.py:104
            │  ├─ 5.321 read_tablet  remarkable_mouse/pynput.py:61
            │  │  ├─ 3.097 read  paramiko/file.py:172
            │  │  │     [12 frames hidden]  paramiko
            │  │  │        0.910 read  paramiko/buffered_pipe.py:126
            │  │  │        └─ 0.096 lock.acquire  <built-in>:0
            │  │  │        0.243 max  <built-in>:0
            │  │  │        0.089 len  <built-in>:0

[Evidlo]

Are these issues still present in 7.0.1?

[jonahweissman]

I'm no longer using remarkable_mouse (just don't have a need for it anymore), so I can't say

[pgassmann]

Are these issues still present in 7.0.1?

I tried remarkable-mouse now on Ubuntu 20.04. I also experienced the lagging and catching up. the ssh connection was over usb, not wifi.