Xdebug session results in gateway timeout

Created October 19, 2018 11:22

i created a new vagrant vm using www.puphpet.com as i always do. Normally when installing this and starting a new project i can enable listening in PHPstorm and set the cookie and it starts debugging. now however i do get a first message in phpstorm about the path mappings. I then set these correctly. Then refresh the browser and get a gatway timeout.

I have uploaded files to

Uploading...
File uploaded: willem_xdebug_remote_log.txt
Uploading...
File uploaded: willem_idea.log
Upload complete!

here is also the contents of idea.loh

2018-10-19 13:09:19,601 [2782262] DEBUG - il.connection.ServerConnection - Incoming connection on port 9000 from 192.168.56.203
2018-10-19 13:09:19,622 [2782283] DEBUG - .connection.PhpDebugConnection - 1274796095#----connection started
2018-10-19 13:12:05,945 [2948606] DEBUG - il.connection.ServerConnection - Incoming connection on port 9000 from 192.168.56.203
2018-10-19 13:12:05,952 [2948613] DEBUG - .connection.PhpDebugConnection - 1216666414#----connection started
2018-10-19 13:14:46,830 [3109491] DEBUG - il.connection.ServerConnection - Stopping 'Xdebug Server' on port 9000
2018-10-19 13:14:46,831 [3109492] DEBUG - il.connection.ServerConnection - Stopping 'Zend Debugger Server' on port 10137
2018-10-19 13:14:46,831 [3109492] INFO - il.connection.ServerConnection - Stopped listening on port 9000
2018-10-19 13:14:46,831 [3109492] DEBUG - il.connection.ServerConnection - Stopping 'Zend Debugger Settings Broadcasting' on port 20080
2018-10-19 13:14:46,831 [3109492] INFO - il.connection.ServerConnection - Stopped listening on port 10137
2018-10-19 13:14:46,832 [3109493] INFO - il.connection.ServerConnection - Stopped listening on port 20080
2018-10-19 13:14:46,832 [3109493] DEBUG - .connection.PhpDebugConnection - 501814643#---Start detaching
2018-10-19 13:14:46,832 [3109493] DEBUG - .connection.PhpDebugConnection - 1274796095#---Start detaching
2018-10-19 13:14:46,832 [3109493] DEBUG - .connection.PhpDebugConnection - 1216666414#---Start detaching
2018-10-19 13:14:46,921 [3109582] DEBUG - .connection.PhpDebugConnection - 1274796095#---input stream is finished
2018-10-19 13:14:46,921 [3109582] DEBUG - .connection.PhpDebugConnection - 1274796095#---stop reading
2018-10-19 13:14:46,921 [3109582] DEBUG - .connection.PhpDebugConnection - 1274796095#---stop writing
2018-10-19 13:14:46,921 [3109582] DEBUG - .connection.PhpDebugConnection - 1274796095#----connection stopped
2018-10-19 13:14:46,921 [3109582] DEBUG - .connection.PhpDebugConnection - 1274796095#---Stop detaching
2018-10-19 13:14:46,922 [3109583] DEBUG - il.connection.ServerConnection - ----socket closed
2018-10-19 13:14:47,358 [3110019] DEBUG - .connection.PhpDebugConnection - 1216666414#---input stream is finished
2018-10-19 13:14:47,358 [3110019] DEBUG - .connection.PhpDebugConnection - 1216666414#---stop reading
2018-10-19 13:14:47,358 [3110019] DEBUG - .connection.PhpDebugConnection - 1216666414#---stop writing
2018-10-19 13:14:47,359 [3110020] DEBUG - .connection.PhpDebugConnection - 1216666414#----connection stopped
2018-10-19 13:14:47,359 [3110020] DEBUG - .connection.PhpDebugConnection - 1216666414#---Stop detaching
2018-10-19 13:14:47,359 [3110020] DEBUG - il.connection.ServerConnection - ----socket closed
2018-10-19 13:14:47,362 [3110023] DEBUG - .connection.PhpDebugConnection - 501814643#---input stream is finished
2018-10-19 13:14:47,362 [3110023] DEBUG - .connection.PhpDebugConnection - 501814643#---stop reading
2018-10-19 13:14:47,362 [3110023] DEBUG - .connection.PhpDebugConnection - 501814643#---stop writing
2018-10-19 13:14:47,362 [3110023] DEBUG - .connection.PhpDebugConnection - 501814643#----connection stopped
2018-10-19 13:14:47,362 [3110023] DEBUG - .connection.PhpDebugConnection - 501814643#---Stop detaching
2018-10-19 13:14:47,362 [3110023] DEBUG - il.connection.ServerConnection - ----socket closed

and remote xdebug log:

[13359] Log opened at 2018-10-19 11:09:19
[13359] I: Checking remote connect back address.
[13359] I: Checking header 'HTTP_X_FORWARDED_FOR'.
[13359] I: Checking header 'REMOTE_ADDR'.
[13359] I: Remote address found, connecting to 192.168.56.1:9000.
[13359] I: Connected to client. :-)
[13359] -> <init xmlns="urn:debugger_protocol_v1" xmlns:xdebug="https://xdebug.org/dbgp/xdebug" fileuri="file:///var/www/mcb_v2/api.creatieveboekhouding.local/webroot/index.php" language="PHP" xdebug:language_version="7.2.10-1+ubuntu16.04.1+deb.sury.org+1" protocol_version="1.0" appid="13359" idekey="XDEBUG_ECLIPSE"><engine version="2.7.0beta1"><![CDATA[Xdebug]]></engine><author><![CDATA[Derick Rethans]]></author><url><![CDATA[https://xdebug.org]]></url><copyright><![CDATA[Copyright (c) 2002-2018 by Derick Rethans]]></copyright></init>
[13359]
[13359] <- feature_set -i 1 -n show_hidden -v 1
[13359] -> <response xmlns="urn:debugger_protocol_v1" xmlns:xdebug="https://xdebug.org/dbgp/xdebug" command="feature_set" transaction_id="1" feature="show_hidden" success="1"></response>
[13359]
[13359] <- feature_set -i 2 -n max_depth -v 1
[13359] -> <response xmlns="urn:debugger_protocol_v1" xmlns:xdebug="https://xdebug.org/dbgp/xdebug" command="feature_set" transaction_id="2" feature="max_depth" success="1"></response>
[13359]
[13359] <- feature_set -i 3 -n max_children -v 100
[13359] -> <response xmlns="urn:debugger_protocol_v1" xmlns:xdebug="https://xdebug.org/dbgp/xdebug" command="feature_set" transaction_id="3" feature="max_children" success="1"></response>
[13359]
[13359] <- feature_set -i 4 -n extended_properties -v 1
[13359] -> <response xmlns="urn:debugger_protocol_v1" xmlns:xdebug="https://xdebug.org/dbgp/xdebug" command="feature_set" transaction_id="4" feature="extended_properties" success="1"></response>
[13359]
[13359] <- status -i 5
[13359] -> <response xmlns="urn:debugger_protocol_v1" xmlns:xdebug="https://xdebug.org/dbgp/xdebug" command="status" transaction_id="5" status="starting" reason="ok"></response>
[13359]
[13359] <- step_into -i 6
[13359] -> <response xmlns="urn:debugger_protocol_v1" xmlns:xdebug="https://xdebug.org/dbgp/xdebug" command="step_into" transaction_id="6" status="break" reason="ok"><xdebug:message filename="file:///var/www/mcb_v2/api.creatieveboekhouding.local/webroot/index.php" lineno="19"></xdebug:message></response>
[13359]
[13359] <- eval -i 7 -- aXNzZXQoJF9TRVJWRVJbJ1BIUF9JREVfQ09ORklHJ10p
[13359] -> <response xmlns="urn:debugger_protocol_v1" xmlns:xdebug="https://xdebug.org/dbgp/xdebug" command="eval" transaction_id="7"><property type="bool"><![CDATA[0]]></property></response>
[13359]
[13359] <- eval -i 8 -- aXNzZXQoJF9TRVJWRVJbJ1NFUlZFUl9OQU1FJ10p
[13359] -> <response xmlns="urn:debugger_protocol_v1" xmlns:xdebug="https://xdebug.org/dbgp/xdebug" command="eval" transaction_id="8"><property type="bool"><![CDATA[1]]></property></response>
[13359]
[13359] <- eval -i 9 -- KHN0cmluZykoJF9TRVJWRVJbJ1NFUlZFUl9OQU1FJ10p
[13359] -> <response xmlns="urn:debugger_protocol_v1" xmlns:xdebug="https://xdebug.org/dbgp/xdebug" command="eval" transaction_id="9"><property type="string" size="30" encoding="base64"><![CDATA[YXBpLmNyZWF0aWV2ZWJvZWtob3VkaW5nLmxvY2Fs]]></property></response>
[13359]
[13359] <- eval -i 10 -- KHN0cmluZykoJF9TRVJWRVJbJ1NFUlZFUl9QT1JUJ10p
[13359] -> <response xmlns="urn:debugger_protocol_v1" xmlns:xdebug="https://xdebug.org/dbgp/xdebug" command="eval" transaction_id="10"><property type="string" size="3" encoding="base64"><![CDATA[NDQz]]></property></response>
[13359]
[13359] <- eval -i 11 -- KHN0cmluZykoJF9TRVJWRVJbJ1JFUVVFU1RfVVJJJ10p
[13359] -> <response xmlns="urn:debugger_protocol_v1" xmlns:xdebug="https://xdebug.org/dbgp/xdebug" command="eval" transaction_id="11"><property type="string" size="12" encoding="base64"><![CDATA[L21vbmV5dGVzdHMv]]></property></response>
[13359]
[13360] Log opened at 2018-10-19 11:12:05
[13360] I: Checking remote connect back address.
[13360] I: Checking header 'HTTP_X_FORWARDED_FOR'.
[13360] I: Checking header 'REMOTE_ADDR'.
[13360] I: Remote address found, connecting to 192.168.56.1:9000.
[13360] I: Connected to client. :-)
[13360] -> <init xmlns="urn:debugger_protocol_v1" xmlns:xdebug="https://xdebug.org/dbgp/xdebug" fileuri="file:///var/www/mcb_v2/api.creatieveboekhouding.local/webroot/index.php" language="PHP" xdebug:language_version="7.2.10-1+ubuntu16.04.1+deb.sury.org+1" protocol_version="1.0" appid="13360" idekey="XDEBUG_ECLIPSE"><engine version="2.7.0beta1"><![CDATA[Xdebug]]></engine><author><![CDATA[Derick Rethans]]></author><url><![CDATA[https://xdebug.org]]></url><copyright><![CDATA[Copyright (c) 2002-2018 by Derick Rethans]]></copyright></init>
[13360]
[13360] <- feature_set -i 1 -n show_hidden -v 1
[13360] -> <response xmlns="urn:debugger_protocol_v1" xmlns:xdebug="https://xdebug.org/dbgp/xdebug" command="feature_set" transaction_id="1" feature="show_hidden" success="1"></response>
[13360]
[13360] <- feature_set -i 2 -n max_depth -v 1
[13360] -> <response xmlns="urn:debugger_protocol_v1" xmlns:xdebug="https://xdebug.org/dbgp/xdebug" command="feature_set" transaction_id="2" feature="max_depth" success="1"></response>
[13360]
[13360] <- feature_set -i 3 -n max_children -v 100
[13360] -> <response xmlns="urn:debugger_protocol_v1" xmlns:xdebug="https://xdebug.org/dbgp/xdebug" command="feature_set" transaction_id="3" feature="max_children" success="1"></response>
[13360]
[13360] <- feature_set -i 4 -n extended_properties -v 1
[13360] -> <response xmlns="urn:debugger_protocol_v1" xmlns:xdebug="https://xdebug.org/dbgp/xdebug" command="feature_set" transaction_id="4" feature="extended_properties" success="1"></response>
[13360]
[13360] <- status -i 5
[13360] -> <response xmlns="urn:debugger_protocol_v1" xmlns:xdebug="https://xdebug.org/dbgp/xdebug" command="status" transaction_id="5" status="starting" reason="ok"></response>
[13360]
[13360] <- step_into -i 6
[13360] -> <response xmlns="urn:debugger_protocol_v1" xmlns:xdebug="https://xdebug.org/dbgp/xdebug" command="step_into" transaction_id="6" status="break" reason="ok"><xdebug:message filename="file:///var/www/mcb_v2/api.creatieveboekhouding.local/webroot/index.php" lineno="19"></xdebug:message></response>
[13360]
[13360] <- eval -i 7 -- aXNzZXQoJF9TRVJWRVJbJ1BIUF9JREVfQ09ORklHJ10p
[13360] -> <response xmlns="urn:debugger_protocol_v1" xmlns:xdebug="https://xdebug.org/dbgp/xdebug" command="eval" transaction_id="7"><property type="bool"><![CDATA[0]]></property></response>
[13360]
[13360] <- eval -i 8 -- aXNzZXQoJF9TRVJWRVJbJ1NFUlZFUl9OQU1FJ10p
[13360] -> <response xmlns="urn:debugger_protocol_v1" xmlns:xdebug="https://xdebug.org/dbgp/xdebug" command="eval" transaction_id="8"><property type="bool"><![CDATA[1]]></property></response>
[13360]
[13360] <- eval -i 9 -- KHN0cmluZykoJF9TRVJWRVJbJ1NFUlZFUl9OQU1FJ10p
[13360] -> <response xmlns="urn:debugger_protocol_v1" xmlns:xdebug="https://xdebug.org/dbgp/xdebug" command="eval" transaction_id="9"><property type="string" size="30" encoding="base64"><![CDATA[YXBpLmNyZWF0aWV2ZWJvZWtob3VkaW5nLmxvY2Fs]]></property></response>
[13360]
[13360] <- eval -i 10 -- KHN0cmluZykoJF9TRVJWRVJbJ1NFUlZFUl9QT1JUJ10p
[13360] -> <response xmlns="urn:debugger_protocol_v1" xmlns:xdebug="https://xdebug.org/dbgp/xdebug" command="eval" transaction_id="10"><property type="string" size="3" encoding="base64"><![CDATA[NDQz]]></property></response>
[13360]
[13360] <- eval -i 11 -- KHN0cmluZykoJF9TRVJWRVJbJ1JFUVVFU1RfVVJJJ10p
[13360] -> <response xmlns="urn:debugger_protocol_v1" xmlns:xdebug="https://xdebug.org/dbgp/xdebug" command="eval" transaction_id="11"><property type="string" size="12" encoding="base64"><![CDATA[L21vbmV5dGVzdHMv]]></property></response>
[13360]
[13359] <- run -i 12
[13359] -> <response xmlns="urn:debugger_protocol_v1" xmlns:xdebug="https://xdebug.org/dbgp/xdebug" command="run" transaction_id="12" status="stopping" reason="ok"></response>
[13359]
[13359] <- stop -i 13
[13359] -> <response xmlns="urn:debugger_protocol_v1" xmlns:xdebug="https://xdebug.org/dbgp/xdebug" command="stop" transaction_id="13" status="stopped" reason="ok"></response>
[13359]
[13359] Log closed at 2018-10-19 11:14:46
[13359]
[13360] <- run -i 12
[13572] <- run -i 12
[13360] -> <response xmlns="urn:debugger_protocol_v1" xmlns:xdebug="https://xdebug.org/dbgp/xdebug" command="run" transaction_id="12" status="stopping" reason="ok"></response>
[13360]
[13572] -> <response xmlns="urn:debugger_protocol_v1" xmlns:xdebug="https://xdebug.org/dbgp/xdebug" command="run" transaction_id="12" status="stopping" reason="ok"></response>
[13572]
[13360] <- stop -i 13
[13360] -> <response xmlns="urn:debugger_protocol_v1" xmlns:xdebug="https://xdebug.org/dbgp/xdebug" command="stop" transaction_id="13" status="stopped" reason="ok"></response>
[13360]
[13360] Log closed at 2018-10-19 11:14:47
[13360]
[13572] <- stop -i 13
[13572] -> <response xmlns="urn:debugger_protocol_v1" xmlns:xdebug="https://xdebug.org/dbgp/xdebug" command="stop" transaction_id="13" status="stopped" reason="ok"></response>
[13572]
[13572] Log closed at 2018-10-19 11:14:47

what could be the cause of the issue?

4 comments

Andriy Bazanov

Created October 19, 2018 21:12

Hi there,

So far it looks like you have not finished the first debug session and started 2nd one already (e.g. making a subrequest etc)...

How many tabs do you see in Debugger panel when this happens?

If that's the case .. then you may need to increase max debug connections limit in PhpStorm settings (by default it's just 1).

Need to see details to say something more concrete than this.

Willem

Created October 20, 2018 05:52

The log shows two sessions ([13359] [13360] ) you mean? That is because i forgot the erase one. these are two different tries.

I have no debug panel it does not get that far even.

i tried with a single php file with phpinfo(); and next line $var = 'test'; Than debugger will break at phpinof() if i put a breakpoint on it. But then pressing F8 for step next, it will hang again.

What more details would you need to see?

Andriy Bazanov

Created October 20, 2018 13:29

If it happens in a simple file with few instructions only .. then it's not the case that I had in mind.

Anyway: does it happen in a simple file without phpinfo() call (which produces a lot of output). I'm thinking about a simple case like:

<?php
$a = 1;
$b = 3;
$c = $a + $b;
echo $c;

Can you debug this simple code?

>I have no debug panel it does not get that far even.

If PhpStorm gets debug connection and it tells to break here ... then IDE will show Debugger panel.

Can you provide some screencast if you do not see the panel?

Other than that: maybe it's xdebug version? Can you downgrade to the previous stable version (2.6.x)?

Willem

Created October 22, 2018 10:10

See link to a screencast (sry for the low quality) but it shows what is happening.

https://drive.google.com/file/d/12uwBlPcs0syWDosqSirIIIJingeNC5UO/view

so, the breakpoint is hit. Pressing 'play' is all fine. Pressing F8 (step) will cause the timeout hangs phpstorm.

UPDATE:

I downgraded xdebug to 2_6_1 and now debugging is working as normal.

Please sign in to leave a comment.