View Issue Details

IDProjectCategoryView StatusLast Update
0002044XdebugUncategorizedpublic2021-11-24 10:30
ReporterJeremyDunn Assigned Toderick  
PrioritynormalSeverityminorReproducibilityalways
Status feedbackResolutionopen 
PlatformWindowsOSWindows 10 
Product Version3.1.1 
Summary0002044: every PHP request gives 4x "time-out connecting to client" in xdebug log
Descriptionevery PHP request results in the following in xdebug.log

[10916] Log opened at 2021-11-09 14:12:20.546902
[10916] [Step Debug] ERR: Time-out connecting to debugging client, waited: 200 ms. Tried: localhost:9000 (through xdebug.client_host/xdebug.client_port) :-(
[10916] [Step Debug] ERR: Time-out connecting to debugging client, waited: 200 ms. Tried: localhost:9000 (through xdebug.client_host/xdebug.client_port) :-(
[10916] [Step Debug] ERR: Time-out connecting to debugging client, waited: 200 ms. Tried: localhost:9000 (through xdebug.client_host/xdebug.client_port) :-(
[10916] [Step Debug] ERR: Time-out connecting to debugging client, waited: 200 ms. Tried: localhost:9000 (through xdebug.client_host/xdebug.client_port) :-(
[10916] Log closed at 2021-11-09 14:12:22.627397

here is my complete xdebug configuration from php.ini

[xdebug]
xdebug.output_dir="C:\temp"
xdebug.log="C:\temp\xdebug.log"
xdebug.log_level=1
xdebug.mode=debug
xdebug.client_host=localhost
xdebug.client_port=9000
;xdebug.idekey="netbeans-xdebug"
xdebug.var_display_max_depth=20
xdebug.var_display_max_children=-1
xdebug.var_display_max_data=-1

note that I have log_level=1 to try to suppress this error but it still comes; and commented-out the idekey (from response in 0001953) also did not affect the problem

setting log_level=0 does suppress the errors. is this the expected result ?
Steps To Reproduceexecute any PHP script
Additional Informationrunning a file with only phpinfo(); results in a *single* instance of the "ERR: time-out connecting..." message, not four instances. but otherwise it's the same.

also note I'm on PHP 8.0.11 but the Mantis PHP-version-selector only goes to 8.0.9

attached is the output from xdebug_info();
TagsNo tags attached.
Operating SystemWindows 10 Pro 21H1
PHP Version8.0.10-8.0.19

Activities

JeremyDunn

2021-11-09 14:32

reporter  

xdebug_info.pdf (422,352 bytes)

derick

2021-11-10 15:18

administrator   ~0006150

Hi Jeremy,

There are a few questions / items in your report:

1. Xdebug thinks it needs to connect to an IDE, although I can not see which trigger was active for it to want to do that. You need to set log_level to 10 to figure that out.
2. If Xdebug can not connect to the IDE, it will show an error in the log. This is considered an "error" and hence will show up if log_level is set to 1 (or higher).
3. Xdebug wants to connect *four* times to the IDE. This could either be because there is perhaps a shutdown error handler? Or does any code perhaps call the xdebug_connect_to_client() function? There might be a hint in the log, if you set the log level to 10 for this one too.

cheers,
Derick

JeremyDunn

2021-11-10 15:52

reporter   ~0006155

here are the results after changing xdebug.log_level=10, restarting apache, and navigating to the login page of my application
this is ONE request, resulting in TWO log entries (because there's a redirect in the index page), both of which try to connect FOUR times each:

====
[25744] Log opened at 2021-11-10 15:45:41.329596
[25744] [Config] DEBUG: Checking if trigger 'XDEBUG_TRIGGER' is enabled for mode 'debug'
[25744] [Config] INFO: Trigger value for 'XDEBUG_TRIGGER' not found, falling back to 'XDEBUG_SESSION'
[25744] [Config] INFO: No shared secret: Activating
[25744] [Step Debug] INFO: Connecting to configured address/port: localhost:9000.
[25744] [Step Debug] ERR: Time-out connecting to debugging client, waited: 200 ms. Tried: localhost:9000 (through xdebug.client_host/xdebug.client_port) :-(
[25744] [Config] DEBUG: Checking if trigger 'XDEBUG_TRIGGER' is enabled for mode 'debug'
[25744] [Config] INFO: Trigger value for 'XDEBUG_TRIGGER' not found, falling back to 'XDEBUG_SESSION'
[25744] [Config] INFO: No shared secret: Activating
[25744] [Step Debug] INFO: Connecting to configured address/port: localhost:9000.
[25744] [Step Debug] ERR: Time-out connecting to debugging client, waited: 200 ms. Tried: localhost:9000 (through xdebug.client_host/xdebug.client_port) :-(
[25744] [Config] DEBUG: Checking if trigger 'XDEBUG_TRIGGER' is enabled for mode 'debug'
[25744] [Config] INFO: Trigger value for 'XDEBUG_TRIGGER' not found, falling back to 'XDEBUG_SESSION'
[25744] [Config] INFO: No shared secret: Activating
[25744] [Step Debug] INFO: Connecting to configured address/port: localhost:9000.
[25744] [Step Debug] ERR: Time-out connecting to debugging client, waited: 200 ms. Tried: localhost:9000 (through xdebug.client_host/xdebug.client_port) :-(
[25744] [Config] DEBUG: Checking if trigger 'XDEBUG_TRIGGER' is enabled for mode 'debug'
[25744] [Config] INFO: Trigger value for 'XDEBUG_TRIGGER' not found, falling back to 'XDEBUG_SESSION'
[25744] [Config] INFO: No shared secret: Activating
[25744] [Step Debug] INFO: Connecting to configured address/port: localhost:9000.
[25744] [Step Debug] ERR: Time-out connecting to debugging client, waited: 200 ms. Tried: localhost:9000 (through xdebug.client_host/xdebug.client_port) :-(
[25744] Log closed at 2021-11-10 15:45:43.129720

[25744] Log opened at 2021-11-10 15:45:43.237602
[25744] [Config] DEBUG: Checking if trigger 'XDEBUG_TRIGGER' is enabled for mode 'debug'
[25744] [Config] INFO: Trigger value for 'XDEBUG_TRIGGER' not found, falling back to 'XDEBUG_SESSION'
[25744] [Config] INFO: No shared secret: Activating
[25744] [Step Debug] INFO: Connecting to configured address/port: localhost:9000.
[25744] [Step Debug] ERR: Time-out connecting to debugging client, waited: 200 ms. Tried: localhost:9000 (through xdebug.client_host/xdebug.client_port) :-(
[25744] [Config] DEBUG: Checking if trigger 'XDEBUG_TRIGGER' is enabled for mode 'debug'
[25744] [Config] INFO: Trigger value for 'XDEBUG_TRIGGER' not found, falling back to 'XDEBUG_SESSION'
[25744] [Config] INFO: No shared secret: Activating
[25744] [Step Debug] INFO: Connecting to configured address/port: localhost:9000.
[25744] [Step Debug] ERR: Time-out connecting to debugging client, waited: 200 ms. Tried: localhost:9000 (through xdebug.client_host/xdebug.client_port) :-(
[25744] [Config] DEBUG: Checking if trigger 'XDEBUG_TRIGGER' is enabled for mode 'debug'
[25744] [Config] INFO: Trigger value for 'XDEBUG_TRIGGER' not found, falling back to 'XDEBUG_SESSION'
[25744] [Config] INFO: No shared secret: Activating
[25744] [Step Debug] INFO: Connecting to configured address/port: localhost:9000.
[25744] [Step Debug] ERR: Time-out connecting to debugging client, waited: 200 ms. Tried: localhost:9000 (through xdebug.client_host/xdebug.client_port) :-(
[25744] [Config] DEBUG: Checking if trigger 'XDEBUG_TRIGGER' is enabled for mode 'debug'
[25744] [Config] INFO: Trigger value for 'XDEBUG_TRIGGER' not found, falling back to 'XDEBUG_SESSION'
[25744] [Config] INFO: No shared secret: Activating
[25744] [Step Debug] INFO: Connecting to configured address/port: localhost:9000.
[25744] [Step Debug] ERR: Time-out connecting to debugging client, waited: 200 ms. Tried: localhost:9000 (through xdebug.client_host/xdebug.client_port) :-(
[25744] Log closed at 2021-11-10 15:45:45.322920

=====
> This could either be because there is perhaps a shutdown error handler? Or does any code perhaps call the xdebug_connect_to_client() function?

yes, I have a shutdown error handler in my index.php script:

<code>
register_shutdown_function('check_for_fatal_errors');
....
function check_for_fatal_errors() {
    $error = error_get_last();
    if (null !== $error && isset($error['type']) && $error['type'] == 1) {
        $message = "\n\n" . 'File: ' . $error["file"] . "\n". 'Line: ' . $error["line"] . "\n". 'Message: ' . $error["message"] ;
        Yii::log($message, 'error', 'FATAL PHP ERROR');
    }
}
</code>

no, I have no calls to any xdebug* functions in the PHP code

JeremyDunn

2021-11-10 16:20

reporter   ~0006156

p.s. there is an XDEBUG_SESSION cookie in my browser, which maybe the cause of xdebug trying to autoconnect. I guess it might have been placed there by previously starting my application in debug mode, from NetBeans?

if I delete the cookie then this is what I see in the log at level=10:

[23140] Log opened at 2021-11-10 16:11:52.698737
[23140] [Config] DEBUG: Checking if trigger 'XDEBUG_TRIGGER' is enabled for mode 'debug'
[23140] [Config] INFO: Trigger value for 'XDEBUG_TRIGGER' not found, falling back to 'XDEBUG_SESSION'
[23140] [Config] INFO: Trigger value for 'XDEBUG_SESSION' not found, so not activating
[23140] [Config] DEBUG: Checking if trigger 'XDEBUG_TRIGGER' is enabled for mode 'debug'
[23140] [Config] INFO: Trigger value for 'XDEBUG_TRIGGER' not found, falling back to 'XDEBUG_SESSION'
[23140] [Config] INFO: Trigger value for 'XDEBUG_SESSION' not found, so not activating
[23140] [Config] DEBUG: Checking if trigger 'XDEBUG_TRIGGER' is enabled for mode 'debug'
[23140] [Config] INFO: Trigger value for 'XDEBUG_TRIGGER' not found, falling back to 'XDEBUG_SESSION'
[23140] [Config] INFO: Trigger value for 'XDEBUG_SESSION' not found, so not activating
[23140] [Config] DEBUG: Checking if trigger 'XDEBUG_TRIGGER' is enabled for mode 'debug'
[23140] [Config] INFO: Trigger value for 'XDEBUG_TRIGGER' not found, falling back to 'XDEBUG_SESSION'
[23140] [Config] INFO: Trigger value for 'XDEBUG_SESSION' not found, so not activating
[23140] Log closed at 2021-11-10 16:11:52.825368

short version - it appears to be the cookie.

BUT - if I restart the debugger through NetBeans; then stop it through NB, the cookie gets recreated. Then if I navigate to the site otherwise, it tries to connect.

I'm running NetBeans 12.3 and the PHP Debugger *requires* a Session-ID, which is used to create a cookie. The debug-config is invalid without it.

So - what do you recommend given these facts?

something

2021-11-12 00:37

reporter   ~0006157

I have the same issue. I'm preventing the logs with `log_level=0` and I'm selectively setting the cookie. However it's still an issue for when I have the cookie set, but am not debugging right then. Then each request is greatly slowed down as Xdebug tries to connect 4 (sometimes 5) times. 200 ms wouldn't be so bad, but 800 ms is quite bad (and for some reason it ends up actually adding about 2 seconds). I'd rather not have to keep enabling and disabling the cookie while I'm working on something that requires me to start and stop debugging.

Is there any way we can limit the number of connection attempts?

Also, I would suggest that a failed connection not be considered a full-fledged error to avoid stuffing the logs. It's a normal state of affairs when using `start_with_request=yes`, which is the easiest way to get started with Xdebug.

Thanks.

derick

2021-11-24 10:22

administrator   ~0006162

@something That is a different (and expected issue, see: https://bugs.xdebug.org/view.php?id=1948 and https://bugs.xdebug.org/view.php?id=1920) — I'll make your comment (and mine) private, as they don't belong here.

derick

2021-11-24 10:30

administrator   ~0006163

Last edited: 2021-11-24 10:30

> p.s. there is an XDEBUG_SESSION cookie in my browser, which maybe the cause of xdebug trying to autoconnect.

Yes, that most definitely will do it. It still shouldn't do that four times though.

> I guess it might have been placed there by previously starting my application in debug mode, from NetBeans?

Yes, I think NetBeans does that.

> if I delete the cookie then this is what I see in the log at level=10:

[23140] Log opened at 2021-11-10 16:11:52.698737
[23140] [Config] DEBUG: Checking if trigger 'XDEBUG_TRIGGER' is enabled for mode 'debug'
[23140] [Config] INFO: Trigger value for 'XDEBUG_TRIGGER' not found, falling back to 'XDEBUG_SESSION'
[23140] [Config] INFO: Trigger value for 'XDEBUG_SESSION' not found, so not activating
[23140] [Config] DEBUG: Checking if trigger 'XDEBUG_TRIGGER' is enabled for mode 'debug'
[23140] [Config] INFO: Trigger value for 'XDEBUG_TRIGGER' not found, falling back to 'XDEBUG_SESSION'
[23140] [Config] INFO: Trigger value for 'XDEBUG_SESSION' not found, so not activating
[23140] [Config] DEBUG: Checking if trigger 'XDEBUG_TRIGGER' is enabled for mode 'debug'
[23140] [Config] INFO: Trigger value for 'XDEBUG_TRIGGER' not found, falling back to 'XDEBUG_SESSION'
[23140] [Config] INFO: Trigger value for 'XDEBUG_SESSION' not found, so not activating
[23140] [Config] DEBUG: Checking if trigger 'XDEBUG_TRIGGER' is enabled for mode 'debug'
[23140] [Config] INFO: Trigger value for 'XDEBUG_TRIGGER' not found, falling back to 'XDEBUG_SESSION'
[23140] [Config] INFO: Trigger value for 'XDEBUG_SESSION' not found, so not activating
[23140] Log closed at 2021-11-10 16:11:52.825368


> short version - it appears to be the cookie.

But that doesn't explain that it checks four times...

> BUT - if I restart the debugger through NetBeans; then stop it through NB, the cookie gets recreated. Then if I navigate to the site otherwise, it tries to connect.

Yes, that's how it supposed to work. I'm not sure if NetBeans supports putting the debugger in "listening mode" like PhpStorm and VS Code can, which would allow you to use a browser extension (https://xdebug.org/docs/step_debug#browser-extensions) to decided whether you want to debug a request (or not), and not rely on the Xdebug SESSION cookies at all. From a quick glance at the documentation (https://netbeans.apache.org/kb/docs/php/debugging.html#debuggingSession) it does not.

NetBeans makes assumptions about the required values of the session ID as well. In the documentation it says "Session ID Arbitrary name of the debugging session. By default it is netbeans-xdebug. This value is important to note in cases where you have to set the xdebug.idekey property in php.ini, such as some remote debugging scenarios." — which is nonsense, as Xdebug really doesn't care what it is. Although NetBeans rejects anything with a different value :-/

> I'm running NetBeans 12.3 and the PHP Debugger *requires* a Session-ID, which is used to create a cookie. The debug-config is invalid without it.
> So - what do you recommend given these facts?

I'd still like to figure out why it tries it four times. As to the issues with NetBeans, I would probably recommend you switch to VS Code (or PhpStorm), or convince the NetBeans folk to implement a "listen" mode for debugging.

Issue History

Date Modified Username Field Change
2021-11-09 14:32 JeremyDunn New Issue
2021-11-09 14:32 JeremyDunn File Added: xdebug_info.pdf
2021-11-10 14:56 derick PHP Version 8.0.5-8.0.9 => 8.0.10-8.0.19
2021-11-10 15:18 derick Assigned To => derick
2021-11-10 15:18 derick Status new => feedback
2021-11-10 15:18 derick Note Added: 0006150
2021-11-10 15:52 JeremyDunn Note Added: 0006155
2021-11-10 15:52 JeremyDunn Status feedback => assigned
2021-11-10 16:20 JeremyDunn Note Added: 0006156
2021-11-12 00:37 something Note Added: 0006157
2021-11-24 10:22 derick Note Added: 0006162
2021-11-24 10:30 derick Status assigned => feedback
2021-11-24 10:30 derick Note Added: 0006163
2021-11-24 10:30 derick Note Edited: 0006163