Stack trace on connect #60

Closed
kkuchta opened this Issue Mar 9, 2013 · 30 comments

5 participants

@kkuchta

I'm getting the following error when connecting:

Error

The text is:

Waiting for a connection (Ctrl-C to cancel, this message will self-destruct in  20  seconds...)
An error occured: <type 'exceptions.ValueError'>
Traceback (most recent call last):
  File "/Users/kevin/main_dotfiles/dotvim/bundle/vdebug/plugin/python/start_vdebug.py", line 31, in run
    self.runner.run()
  File "/Users/kevin/main_dotfiles/dotvim/bundle/vdebug/plugin/python/vdebug/runner.py", line 160, in run
    self.open()
  File "/Users/kevin/main_dotfiles/dotvim/bundle/vdebug/plugin/python/vdebug/runner.py", line 74, in open
    raise e
ValueError: invalid literal for int() with base 10: ''  

The setup I have is: an Ubuntu VM running PHP + xdebug (running in virtualbox). The host machine is OS X (10.8) with the latest version of MacVim. When I hit <F5> in macvim, the UI hangs for a bit until either it times out or I run curl https://www.vmUrl.com?XDEBUG_SESSION=true, at which point the above stack trace bops up in macvim (and curl returns curl: (35) Unknown SSL protocol error in connection to www.expensify.com:443).

Is this an issue with xdebug and ssl, or is that ssl error just a byproduct of something going wrong with the connection to vdebug (as evidenced by the stack trace)? Or any other ideas?

@joonty
Owner

Hmm, never seen that one before. Could you create a log file for your session? There's information on how to do that here. The log probably won't contain very much, so it should be OK to paste directly into a reply. Hopefully that'll give us a bit more info.

Cheers

@kkuchta

Oddly, just the following lines. I set the two debug_file options immediately after opening macvim (and before starting debugging), so presumably there are no previous lines missing.

- [Debug] {Mon 11 2013 11:43:40} Closing the socket
- [ERROR] {Mon 11 2013 11:43:40} An error occured: <type 'exceptions.ValueError'>
Traceback (most recent call last):
  File "/Users/kevin/main_dotfiles/dotvim/bundle/vdebug/plugin/python/start_vdebug.py", line 31, in run
    self.runner.run()
  File "/Users/kevin/main_dotfiles/dotvim/bundle/vdebug/plugin/python/vdebug/runner.py", line 160, in run
    self.open()
  File "/Users/kevin/main_dotfiles/dotvim/bundle/vdebug/plugin/python/vdebug/runner.py", line 74, in open
    raise e
ValueError: invalid literal for int() with base 10: ''
@joonty
Owner

Hmm, I was afraid of that. The error is occurring so close to the log file creation that there's no information we can really glean from it. Could you print your Vdebug options?

:echo g:vdebug_options

It looks like an input problem, so I'm going to first rule out the options array. Also, could you let me know which version of Vdebug you're using? If you're unsure there's a VERSION file in the Vdebug directory. Could you also let me know which version of Python is compiled into Vim?

Thanks

@joonty
Owner

Hi, just a quick bump on this. When you've got a moment could you provide the info in the message above? Cheers

@kkuchta

Ah, sorry for the delay and thanks for the bump:

{'debug_file': '', 'debug_file_level': 0, 'watch_window_style': 'expanded', 'marker_default': '⬦', 'continuous_mode': 0, 'ide_key': '', 'break_on_open': 1, 'on_close': 'detach', 'path_maps': {}, 'marker_closed_tree': '▸', 'timeout': 20, 'port': 9000, 'marker_open_tree': '▾', 'debug_window_level': 0, 'server': 'localhost'}     
@joonty
Owner

Thanks, that all looks OK.

What version of Vdebug and Python are you using? Thanks

@kkuchta

Python: 2.7.2

:python << EOF
import sys;
print(sys.version);
EOF

2.7.2 (default, Oct 11 2012, 20:14:37)
[GCC 4.2.1 Compatible Apple Clang 4.0 (tags/Apple/clang-418.0.60)]  

VDebug: 1.4.0

➜  ~  cd ~/.vim/bundle/vdebug
➜  vdebug git:(master) head -n 1 HISTORY
=== Vdebug 1.4.0 / 2013-03-06
➜  vdebug git:(master)
@joonty
Owner

Thanks again - all looks fine!

I've created a branch that I'll be able to use to put some useful debug information in to try and get this sorted. Sorry, it will probably mean a lot of pulling and retrying, but I'd really appreciate it if you have the time.

If you checkout the branch fix/issue-60, I'll use that to make updates that will be specific to debugging this issue. The first update removes an exception catch which seems to be fooling the Python interpreter into losing some information.

If you could paste the same error that you pasted at the start of this issue then hopefully there will be a bit more info!

Thanks

@kkuchta

Thanks for sticking with this bug- someday I'll be able to use xdebug with vim. :)

Anyway, the new error on that branch is:

Screen Shot 2013-04-02 at 10 59 44 AM

An error occured: <type 'exceptions.ValueError'>
Traceback (most recent call last):
  File "/Users/kevin/main_dotfiles/dotvim/bundle/vdebug/plugin/python/start_vdebug.py", line 31, in run
    self.runner.run()
  File "/Users/kevin/main_dotfiles/dotvim/bundle/vdebug/plugin/python/vdebug/runner.py", line 156, in run
    self.open()
  File "/Users/kevin/main_dotfiles/dotvim/bundle/vdebug/plugin/python/vdebug/runner.py", line 44, in open
    vdebug.opts.Options.get('timeout',int))
  File "/Users/kevin/main_dotfiles/dotvim/bundle/vdebug/plugin/python/vdebug/runner.py", line 272, in listen
    self.api = vdebug.dbgp.Api(connection)
  File "/Users/kevin/main_dotfiles/dotvim/bundle/vdebug/plugin/python/vdebug/dbgp.py", line 196, in __init__
    self.__parse_init_msg(self.conn.recv_msg())
  File "/Users/kevin/main_dotfiles/dotvim/bundle/vdebug/plugin/python/vdebug/dbgp.py", line 501, in recv_msg
    length = self.__recv_length()
  File "/Users/kevin/main_dotfiles/dotvim/bundle/vdebug/plugin/python/vdebug/dbgp.py", line 467, in __recv_length
    return int(length)
ValueError: invalid literal for int() with base 10: ''  
@joonty
Owner

Great, that's much more helpful! Thanks for doing that.

I don't know why, but it appears that the length of the message returned by the socket is empty, presumably meaning that the message is empty. I can't see why that would happen, so it might be that you will have another issue here, but I've hopefully fixed the specific exception you're receiving in the fix/issue-60 branch that I've just updated.

Give that a go and let me know if you experience any other problems.

Thanks

@kkuchta

Getting a new exception now:

An error occured: <class 'xml.etree.ElementTree.ParseError'>
Traceback (most recent call last):
  File "/Users/kevin/main_dotfiles/dotvim/bundle/vdebug/plugin/python/start_vdebug.py", line 31, in run
    self.runner.run()
  File "/Users/kevin/main_dotfiles/dotvim/bundle/vdebug/plugin/python/vdebug/runner.py", line 156, in run
    self.open()
  File "/Users/kevin/main_dotfiles/dotvim/bundle/vdebug/plugin/python/vdebug/runner.py", line 44, in open
    vdebug.opts.Options.get('timeout',int))
  File "/Users/kevin/main_dotfiles/dotvim/bundle/vdebug/plugin/python/vdebug/runner.py", line 272, in listen
    self.api = vdebug.dbgp.Api(connection)
  File "/Users/kevin/main_dotfiles/dotvim/bundle/vdebug/plugin/python/vdebug/dbgp.py", line 196, in __init__
    self.__parse_init_msg(self.conn.recv_msg())
  File "/Users/kevin/main_dotfiles/dotvim/bundle/vdebug/plugin/python/vdebug/dbgp.py", line 200, in __parse_init_msg
    xml = ET.fromstring(msg)
  File "/System/Library/Frameworks/Python.framework/Versions/2.7/lib/python2.7/xml/etree/ElementTree.py", line 1283, in XML
    return parser.close()
  File "/System/Library/Frameworks/Python.framework/Versions/2.7/lib/python2.7/xml/etree/ElementTree.py", line 1636, in close
    self._raiseerror(v)
  File "/System/Library/Frameworks/Python.framework/Versions/2.7/lib/python2.7/xml/etree/ElementTree.py", line 1488, in _raiseerror
    raise err
ParseError: no element found: line 1, column 0     
@joonty
Owner

Hi, thanks for that.

What version of Xdebug are you using? It appears that it's sending an empty message for the initial communication, and it should be XML. That's why there's a parser error there. I'm wondering whether it's an older version of Xdebug...

@kkuchta

Looks like I was using 2.2.1. Updated to 2.2.2, but no change. :(

@joonty
Owner

This is really odd. Could you create an xdebug log? This can be done by adding a file with the following INI setting to your PHP or Xdebug INI:

xdebug.remote_log="/tmp/xdebug.log"

Then could you run through the same scenario with Vdebug and paste the log somewhere? E.g. a gist?

Thanks

@kkuchta

Odd- no such file created. I added that line to my php.ini (after to xdebug.remote_enable = 1 and the rest), restarted the web server, and did the above scenario. Vdebug got the same error and no file was written to at /tmp/xdebug.log

@joonty
Owner

This is looking more and more like an issue with your Xdebug/PHP installation, as it's connecting to Vdebug's socket server but writing zero bytes when it should be writing its init XML.

Have you got it working with any other debugger client, or is Vdebug the only one you tried?

@joonty
Owner

Hi, bumping on this. Let me know if you got any further.

Thanks

@kkuchta

You can probably close this bug- I've since changed jobs and stacks: rails instead of php. I might try to set up vdebug for ruby at some point, but since my setup is now totally different, this issue is no longer a problem I have.

Thanks for following up, though- you're a great example for project maintainers everywhere. 👍

@qstrahl qstrahl closed this Aug 16, 2013
@cdaringe

I get the parse error pretty regularly.

An error occured: <class 'xml.etree.ElementTree.ParseError'>
Traceback (most recent call last):
  File "/home/cdieringer/.vim/bundle/vdebug/plugin/python/start_vdebug.py", line 119, in handle_eval
    return self.runner.eval(args)
  File "/home/cdieringer/.vim/bundle/vdebug/plugin/python/vdebug/runner.py", line 288, in eval
    self.ui.watchwin.accept_renderer(rend)
  File "/home/cdieringer/.vim/bundle/vdebug/plugin/python/vdebug/ui/vimui.py", line 377, in accept_renderer
    self.write(renderer.render())
  File "/home/cdieringer/.vim/bundle/vdebug/plugin/python/vdebug/ui/vimui.py", line 560, in render
    properties = self.response.get_context()
  File "/home/cdieringer/.vim/bundle/vdebug/plugin/python/vdebug/dbgp.py", line 146, in get_context
    for c in list(self.as_xml()):
  File "/home/cdieringer/.vim/bundle/vdebug/plugin/python/vdebug/dbgp.py", line 71, in as_xml
    self.xml = ET.fromstring(self.response)
  File "/usr/lib/python2.7/xml/etree/ElementTree.py", line 1300, in XML
    parser.feed(text)
  File "/usr/lib/python2.7/xml/etree/ElementTree.py", line 1642, in feed
    self._raiseerror(v)
  File "/usr/lib/python2.7/xml/etree/ElementTree.py", line 1506, in _raiseerror
    raise err
ParseError: reference to invalid character number: line 2, column 239

For example, if i do :VdebugEval $v[0], it renders properly with my object breakdown, just as expected:

good

however, if i do a :VdebugEval (array) $v[0] (key take away there is that I tried to cast a StdClass to array):

bad

@joonty
Owner

Hi @cdaringe, could you provide a debug log according to the instructions here? That would show me the raw XML, so I can work out what's causing the error for you.

Thanks!

@cdaringe

thanks @joonty! i will do so. ATM i'm yakking my brains out with food poisoning, so post-TMI and passing of the the aforementioned circumstances, i'll get right on it ;) thanks so much. vdebug has been so critical to workflow i dont know what id do without it

@joonty
Owner
@cdaringe

here it is. I hope it has something helpful in there. note, i set a breakpoint next to the line where some offending code used to be, did a VdebugEval (array) $value to produce the error (as that's what the old code did), removed the breakpoint and continued.

@joonty
Owner

@cdaringe can you just try VdebugEval $value? I wonder whether the type prefix is causing weirdness.

It's falling over on the name attribute of this part of the return XML from Xdebug:

<property name="&#0;*&#0;dbObj" address="...

Not seen anything like that before, but that name doesn't decode properly (try it in this xml decoder), which is why it's collapsing.

@cdaringe

hey @joonty, if you take a peek above, I demonstrated that just VdebugEval $v[0] indeed works just fine. is this what you mean?

@joonty
Owner

@cdaringe sorry, you're right - it's been a while since I looked at this issue and I didn't read back up on it! It looks like this might be an issue in Xdebug, as I can see that it's receiving the correctly encoded eval string, but it's returning something garbled. If you make sure your Xdebug is up to date, it may be worth getting @derickr involved and seeing what his thoughts are.

@derickr

I will look at this, but instead of "eval", you really should be using "property_get".

@derickr

Okay. I check this, and it's not a "bug". What happens is the same as doing this:

<?php
class Foo {
    private $bar =42;
}

$a = new foo;
var_dump( (array) $a );
?>

Private properties in PHP are encoded with "\0\" in front of their name, and that shows up when you cast to an array. Standard PHP doesn't *show that \0, but it's there - check with php -n test.php | od -t x1.

Xdebug needs to convert \0foo\0bar into XML, and as XML doesn't allow for \0 characters, it turns it into "& # 0 ;" (had to add spaces in between because of a bug in this MD parser on GitHub ;-)). However, that's sadly not supported in the XML standard either... so I'm not sure what to do about that.

However, using "property_get -n $v" instead of "eval -- (array) $v" will fix this. Morale: don't use "eval" for variable value fetching.

@joonty
Owner

Thanks a lot for the insight @derickr, that's really helpful. I think this has come up before, where you've suggested using property_get. The thing is that in this context, vdebug allows the user to evaluate any valid php expression, not just a single property. I'd toyed with the idea of trying to determine whether it was a property and either eval or property_get as appropriate, but decided it was too much work for too little gain.

Makes sense about the null byte. Since the python library clearly doesn't support it I'm probably best doing a string sanitize on the raw xml before parsing.

Thanks again

@cdaringe

mystery revealed.

probably best doing a string sanitize on the raw xml before parsing

🎲 🎲 🎲 🎲 🎲 yahtzee!

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment