search

omrikiei / ktunnel

A cli that exposes your local resources to kubernetes
GNU General Public License v3.0
928 stars 71 forks source link

Pydevd protocol issues #21

Closed jonastim closed 4 years ago

jonastim commented 4 years ago

I've encountered a couple of debugger parsing issues where evidently different field types were expected than what was delivered, some seemingly cutting of a single character or scrambling up file paths. Sometimes the debugging sessions continue fine but other times things get stuck.

Screen Shot 2020-04-27 at 8 57 47 PM

with pydevd-pycharm (201.6668.115) installed in the local and remote venv, Python 3.6.5 and PyCharm 2020.1.

When connecting to the debugger:

Connected to pydev debugger (build 201.6668.115)
Traceback (most recent call last):
  File "/srv/venvs/service/trusty/service_venv_python3.6/lib/python3.6/site-packages/_pydevd_bundle/pydevd_comm.py", line 311, in _on_run
    cmd_id = int(args[0])
ValueError: invalid literal for int() with base 10: 'ce/current/app/scripts/modelconfig_sync.py'
Can't process net command: ce/current/app/scripts/modelconfig_sync.py   109 sync    THREAD  None    None
pydev debugger: warning: trying to add breakpoint to file that does not exist: /srv/servi111 (will have no effect)

Corresponding inject logs

DEBU[2020-04-27 17:57:28] ce7e715a-b5cb-49d0-9141-6e11bdbe31bc; got session from server:
INFO[2020-04-27 17:57:28] ce7e715a-b5cb-49d0-9141-6e11bdbe31bc; new session; connecting to port 21000
DEBU[2020-04-27 17:57:28] ce7e715a-b5cb-49d0-9141-6e11bdbe31bc got 0 bytes
DEBU[2020-04-27 17:57:28] attempting to receive from stream
DEBU[2020-04-27 17:57:28] started reading from session ce7e715a-b5cb-49d0-9141-6e11bdbe31bc
DEBU[2020-04-27 17:57:28] read 15 bytes from conn on session ce7e715a-b5cb-49d0-9141-6e11bdbe31bc; err: <nil>
DEBU[2020-04-27 17:57:28] locking: ce7e715a-b5cb-49d0-9141-6e11bdbe31bc
DEBU[2020-04-27 17:57:28] unlocked: ce7e715a-b5cb-49d0-9141-6e11bdbe31bc
DEBU[2020-04-27 17:57:28] ce7e715a-b5cb-49d0-9141-6e11bdbe31bc; got session from server: 501    1   201.6668.115
DEBU[2020-04-27 17:57:28] ce7e715a-b5cb-49d0-9141-6e11bdbe31bc got 19 bytes
DEBU[2020-04-27 17:57:28] attempting to receive from stream
DEBU[2020-04-27 17:57:28] read 96 bytes from conn on session ce7e715a-b5cb-49d0-9141-6e11bdbe31bc; err: <nil>
DEBU[2020-04-27 17:57:28] locking: ce7e715a-b5cb-49d0-9141-6e11bdbe31bc
DEBU[2020-04-27 17:57:28] unlocked: ce7e715a-b5cb-49d0-9141-6e11bdbe31bc
DEBU[2020-04-27 17:57:28] read 320 bytes from conn on session ce7e715a-b5cb-49d0-9141-6e11bdbe31bc; err: <nil>
DEBU[2020-04-27 17:57:28] locking: ce7e715a-b5cb-49d0-9141-6e11bdbe31bc
DEBU[2020-04-27 17:57:28] unlocked: ce7e715a-b5cb-49d0-9141-6e11bdbe31bc
DEBU[2020-04-27 17:57:28] read 28 bytes from conn on session ce7e715a-b5cb-49d0-9141-6e11bdbe31bc; err: <nil>
DEBU[2020-04-27 17:57:28] locking: ce7e715a-b5cb-49d0-9141-6e11bdbe31bc
DEBU[2020-04-27 17:57:28] unlocked: ce7e715a-b5cb-49d0-9141-6e11bdbe31bc
DEBU[2020-04-27 17:57:28] read 97 bytes from conn on session ce7e715a-b5cb-49d0-9141-6e11bdbe31bc; err: <nil>
DEBU[2020-04-27 17:57:28] locking: ce7e715a-b5cb-49d0-9141-6e11bdbe31bc
DEBU[2020-04-27 17:57:28] unlocked: ce7e715a-b5cb-49d0-9141-6e11bdbe31bc
DEBU[2020-04-27 17:57:28] read 44 bytes from conn on session ce7e715a-b5cb-49d0-9141-6e11bdbe31bc; err: <nil>
DEBU[2020-04-27 17:57:28] locking: ce7e715a-b5cb-49d0-9141-6e11bdbe31bc
DEBU[2020-04-27 17:57:28] unlocked: ce7e715a-b5cb-49d0-9141-6e11bdbe31bc
DEBU[2020-04-27 17:57:28] read 90 bytes from conn on session ce7e715a-b5cb-49d0-9141-6e11bdbe31bc; err: <nil>
DEBU[2020-04-27 17:57:28] locking: ce7e715a-b5cb-49d0-9141-6e11bdbe31bc
DEBU[2020-04-27 17:57:28] unlocked: ce7e715a-b5cb-49d0-9141-6e11bdbe31bc
DEBU[2020-04-27 17:57:28] read 8 bytes from conn on session ce7e715a-b5cb-49d0-9141-6e11bdbe31bc; err: <nil>
DEBU[2020-04-27 17:57:28] locking: ce7e715a-b5cb-49d0-9141-6e11bdbe31bc
DEBU[2020-04-27 17:57:28] unlocked: ce7e715a-b5cb-49d0-9141-6e11bdbe31bc
DEBU[2020-04-27 17:57:29] ce7e715a-b5cb-49d0-9141-6e11bdbe31bc; got session from server: 116    2   <xml><io s="Traceback %2528most recent call last%2529%253A%250A" ctx="2"/></xml>
116 4   <xml><io s="  File %2522/srv/venvs/service/trusty/service_venv_python3.6/lib/python3.6/site-packages/_pydevd_bundle/pydevd_comm.py%2522%252C line 311%252C in _on_run%250A    cmd_id = int%2528args%255B0%255D%2529%250A" ctx="2"/></xml>
116 6   <xml><io s="ValueError%253A invalid literal for int%2528%2529 with base 10%253A %2527ce/current/app/scripts/modelconfig_sync.py%2527%250A" ctx="2"/></xml>
116 8   <xml><io s="Can%2527t process net command%253A ce/current/app/scripts/modelconfig_sync.py%2509109%2509sync%2509THREAD%2509None%2509None%250A" ctx="2"/></xml>
DEBU[2020-04-27 17:57:29] ce7e715a-b5cb-49d0-9141-6e11bdbe31bc got 652 bytes
DEBU[2020-04-27 17:57:29] attempting to receive from stream
DEBU[2020-04-27 17:57:29] ce7e715a-b5cb-49d0-9141-6e11bdbe31bc; got session from server:
DEBU[2020-04-27 17:57:29] ce7e715a-b5cb-49d0-9141-6e11bdbe31bc got 0 bytes
DEBU[2020-04-27 17:57:29] attempting to receive from stream
DEBU[2020-04-27 17:57:29] ce7e715a-b5cb-49d0-9141-6e11bdbe31bc; got session from server: 116    10  <xml><io s="pydev debugger%253A warning%253A trying to add breakpoint to file that does not exist%253A /srv/servi111 %2528will have no effect%2529%250A" ctx="2"/></xml>
DEBU[2020-04-27 17:57:29] ce7e715a-b5cb-49d0-9141-6e11bdbe31bc got 176 bytes
DEBU[2020-04-27 17:57:29] attempting to receive from stream
DEBU[2020-04-27 17:57:29] ce7e715a-b5cb-49d0-9141-6e11bdbe31bc; got session from server: 103    12  <xml><thread name="MainThread" id="pid_1308_id_140361090732384" /></xml>
DEBU[2020-04-27 17:57:29] ce7e715a-b5cb-49d0-9141-6e11bdbe31bc got 80 bytes
DEBU[2020-04-27 17:57:29] attempting to receive from stream
DEBU[2020-04-27 17:57:29] ce7e715a-b5cb-49d0-9141-6e11bdbe31bc; got session from server: 103    14  <xml><thread name="Thread-1" id="pid_1308_id_140360240746392" /></xml>
DEBU[2020-04-27 17:57:29] ce7e715a-b5cb-49d0-9141-6e11bdbe31bc got 78 bytes
DEBU[2020-04-27 17:57:29] attempting to receive from stream
DEBU[2020-04-27 17:57:29] ce7e715a-b5cb-49d0-9141-6e11bdbe31bc; got session from server: 103    16  <xml><thread name="DummyThread-2" id="pid_1308_id_140360231815824" /></xml>
DEBU[2020-04-27 17:57:29] ce7e715a-b5cb-49d0-9141-6e11bdbe31bc got 83 bytes
DEBU[2020-04-27 17:57:29] attempting to receive from stream
DEBU[2020-04-27 17:57:29] ce7e715a-b5cb-49d0-9141-6e11bdbe31bc; got session from server: 103    18  <xml><thread name="DummyThread-9" id="pid_1308_id_140360229536208" /></xml>
DEBU[2020-04-27 17:57:29] ce7e715a-b5cb-49d0-9141-6e11bdbe31bc got 83 bytes
DEBU[2020-04-27 17:57:29] attempting to receive from stream

Another example from executing a test via pytest

Traceback (most recent call last):
  File "/srv/venvs/service/trusty/service_venv_python3.6/lib/python3.6/site-packages/_pydevd_bundle/pydevd_comm.py", line 311, in _on_run
    cmd_id = int(args[0])
ValueError: invalid literal for int() with base 10: ''
Can't process net command:  None    None
Traceback (most recent call last):
  File "/srv/venvs/service/trusty/service_venv_python3.6/lib/python3.6/site-packages/_pydevd_bundle/pydevd_comm.py", line 311, in _on_run
    cmd_id = int(args[0])
ValueError: invalid literal for int() with base 10: 'srv/service/current/tests/integration/local_load_test.py'
Can't process net command: srv/service/current/tests/integration/local_load_test.py 20  test_load_model_from_local  THREAD  None    None

And some more

Connected to pydev debugger (build 201.6668.115)
Traceback (most recent call last):
  File "/srv/venvs/service/trusty/service_venv_python3.6/lib/python3.6/site-packages/_pydevd_bundle/pydevd_comm.py", line 311, in _on_run
    cmd_id = int(args[0])
ValueError: invalid literal for int() with base 10: 'one'
Can't process net command: one  None    0   1   0
---
Connected to pydev debugger (build 201.6668.115)
Traceback (most recent call last):
  File "/srv/venvs/service/trusty/service_venv_python3.6/lib/python3.6/site-packages/_pydevd_bundle/pydevd_comm.py", line 311, in _on_run
    cmd_id = int(args[0])
ValueError: invalid literal for int() with base 10: 'ne'
Can't process net command: ne
Traceback (most recent call last):
  File "/srv/venvs/service/trusty/service_venv_python3.6/lib/python3.6/site-packages/_pydevd_bundle/pydevd_process_net_command.py", line 339, in process_net_command
    breakpoint_id = line = int(line)
ValueError: invalid literal for int() with base 10: 'python-line'
---
Connected to pydev debugger (build 201.6668.115)
Traceback (most recent call last):
  File "/srv/venvs/service/trusty/service_venv_python3.6/lib/python3.6/site-packages/_pydevd_bundle/pydevd_comm.py", line 311, in _on_run
    cmd_id = int(args[0])
ValueError: invalid literal for int() with base 10: ''
Can't process net command:  None
Traceback (most recent call last):
  File "/srv/venvs/service/trusty/service_venv_python3.6/lib/python3.6/site-packages/_pydevd_bundle/pydevd_comm.py", line 311, in _on_run
    cmd_id = int(args[0])
ValueError: invalid literal for int() with base 10: 'om_local'
Can't process net command: om_local THREAD  None    None
Traceback (most recent call last):
  File "/srv/venvs/service/trusty/service_venv_python3.6/lib/python3.6/site-packages/_pydevd_bundle/pydevd_comm.py", line 311, in _on_run
    cmd_id = int(args[0])
ValueError: invalid literal for int() with base 10: 'ython-line'
Can't process net command: ython-line   /srv/service/current/tests/integration/s3_load_test.py  16  test_load_from_s3   THREAD  None    None
---
Connected to pydev debugger (build 201.6668.115)
Traceback (most recent call last):
  File "/srv/venvs/service/trusty/service_venv_python3.6/lib/python3.6/site-packages/_pydevd_bundle/pydevd_comm.py", line 311, in _on_run
    cmd_id = int(args[0])
ValueError: invalid literal for int() with base 10: 'ython-BaseException'
Can't process net command: ython-BaseException  None    None    0   1   0
---
Connected to pydev debugger (build 201.6668.115)
Traceback (most recent call last):
  File "/srv/venvs/service/trusty/service_venv_python3.6/lib/python3.6/site-packages/_pydevd_bundle/pydevd_comm.py", line 311, in _on_run
    cmd_id = int(args[0])
ValueError: invalid literal for int() with base 10: ''
Can't process net command:  None
Traceback (most recent call last):
  File "/srv/venvs/service/trusty/service_venv_python3.6/lib/python3.6/site-packages/_pydevd_bundle/pydevd_comm.py", line 311, in _on_run
    cmd_id = int(args[0])
ValueError: invalid literal for int() with base 10: 'om_local'
Can't process net command: om_local THREAD  None    None
Traceback (most recent call last):
  File "/srv/venvs/service/trusty/service_venv_python3.6/lib/python3.6/site-packages/_pydevd_bundle/pydevd_comm.py", line 311, in _on_run
    cmd_id = int(args[0])
ValueError: invalid literal for int() with base 10: 'ython-line'
Can't process net command: ython-line   /srv/service/current/tests/integration/s3_load_test.py  16  test_load_from_s3   THREAD  None    None

Have you encountered similar issues before or do you have an idea what might cause it?

omrikiei commented 4 years ago

Hi @jonastim, have not encountered such issues so far, but I've only been using this version of PyCharm for a couple of days... what instrumentation command are you using in your code to bind with the debugger? what configurations are you using to map paths from the container to your env?

omrikiei commented 4 years ago

Ok closing for now as this seems irrelevant..