View Issue Details

IDProjectCategoryView StatusLast Update
0002044XdebugUncategorizedpublic2023-11-08 14:15
ReporterJeremyDunn Assigned Toderick  
PrioritynormalSeverityminorReproducibilityalways
Status assignedResolutionopen 
PlatformWindowsOSWindows 10 
Product Version3.1.1 
Summary0002044: every PHP request gives 4x "time-out connecting to client" in xdebug log
Description

every 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 Reproduce

execute any PHP script

Additional Information

running 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.
Attached Files
xdebug_info.pdf (422,352 bytes)
Operating SystemWindows 10 Pro 21H1
PHP Version8.0.10-8.0.19

Activities

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?

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:

<pre>
[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
</pre>

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.

derick

2022-02-22 18:10

administrator   ~0006215

I don't think there is anything to do here on my side. Would you agree?

JeremyDunn

2022-02-22 19:23

reporter   ~0006217

thanks for following up Derick

I don't think there is anything to do here on my side. Would you agree?
on 24-Nov-2021 you wrote:
I'd still like to figure out why it tries it four times.....
is that something you're still interested to do ?

I would probably recommend you switch to VS Code (or PhpStorm)....
I tried VS Code and have tried PhpStorm in the past...keep coming back to NetBeans. :-)

... or convince the NetBeans folk to implement a "listen" mode for debugging.
hmm....that's an interesting suggestion. If I knew the correct thing to ask, I'd be happy to create a NB ticket. No insight into how that request might get prioritized.

turns out NB 12.6 (the current version) has some "debugger Enhancements": https://netbeans.apache.org/download/nb126/#_debugger_enhancements
I'm running 12.3. Maybe I should upgrade and see if any help with this situation.

I'm not sure I know the correct-thing-to-ask. Would you be able to supply language (here) from which I'd create such a request?
Or alternately you, as the Xdebug author/maintainer, could open a ticket here: https://github.com/apache/netbeans/issues

JeremyDunn

2022-02-22 19:31

reporter   ~0006218

@Derick - see https://github.com/apache/netbeans/pull/3109

is this relevant to what we're discussing ?

kanehama

2022-11-02 05:14

reporter   ~0006418

Last edited: 2023-11-08 14:15

I am not sure if this is the same cause as this ticket, but a similar situation occurred with the following code.

&lt;?php

for ($i = 0; $i &lt; 10; $i++) {
    // &quot;ERR: Time-out connecting to debugging client&quot; is logged 11 times at finish of php.
    $hoge[] = new class($i) {
        public $id = 0;
        public function __construct(int $i) {
            $this->id = $i;
        }
        public function __destruct() {
            echo __METHOD__ .  ' : ' .  $this->id . PHP_EOL;
            unset($this->id);
        }
    };
}

// If uncommented out, &quot;ERR: Time-out connecting to debugging client&quot; is logged only once, as usual.
// $hoge = null;
&lt;/php>
[xdebug]
xdebug.mode = develop,debug
xdebug.idekey = &quot;PHPSTORM&quot;
xdebug.client_host=*******
xdebug.client_port=9003
xdebug.start_with_request=yes
xdebug.start_upon_error=no
xdebug.log=/var/log/httpd/xdebug_log
Copyright (c) The PHP Group
Zend Engine v4.1.11, Copyright (c) Zend Technologies
    with Zend OPcache v8.1.11, Copyright (c), by Zend Technologies
    with Xdebug v3.1.5, Copyright (c) 2002-2022, by Derick Rethans

kanehama

2022-11-02 05:20

reporter   ~0006419

The text is attached because it was broken due to the formatting syntax.

code.txt (1,105 bytes)   
I am not sure if this is the same cause as this ticket, but a similar situation occurred with the following code.<br>

<?php

for ($i = 0; $i < 10; $i++) {
    // "ERR: Time-out connecting to debugging client" is logged 11 times at finish of php.
    $hoge[] = new class($i) {
        public $id = 0;
        public function __construct(int $i) {
            $this->id = $i;
        }
        public function __destruct() {
            echo __METHOD__ .  ' : ' .  $this->id . '<br>' . PHP_EOL;
            unset($this->id);
        }
    };
}

// If uncommented out, "ERR: Time-out connecting to debugging client" is logged only once, as usual.
// $hoge = null;
?>

<pre>
[xdebug]
xdebug.mode = develop,debug
xdebug.idekey = "PHPSTORM"
xdebug.client_host=*******
xdebug.client_port=9003
xdebug.start_with_request=yes
xdebug.start_upon_error=no
xdebug.log=/var/log/httpd/xdebug_log


Copyright (c) The PHP Group
Zend Engine v4.1.11, Copyright (c) Zend Technologies
    with Zend OPcache v8.1.11, Copyright (c), by Zend Technologies
    with Xdebug v3.1.5, Copyright (c) 2002-2022, by Derick Rethan
</pre>

code.txt (1,105 bytes)   

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-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
2022-02-22 18:10 derick Note Added: 0006215
2022-02-22 19:23 JeremyDunn Note Added: 0006217
2022-02-22 19:23 JeremyDunn Status feedback => assigned
2022-02-22 19:31 JeremyDunn Note Added: 0006218
2022-11-02 05:14 kanehama Note Added: 0006418
2022-11-02 05:20 kanehama Note Added: 0006419
2022-11-02 05:20 kanehama File Added: code.txt
2023-11-08 14:15 derick Note Edited: 0006418