search

xdebug / vscode-php-debug

PHP Debug Adapter for Visual Studio Code 🐞⛔
MIT License
763 stars 178 forks source link

Unknown thread ID #931

Open MitchTalmadge opened 8 months ago

MitchTalmadge commented 8 months ago

Recently I've been getting an Unknown thread ID error in my VSCode when hitting a breakpoint. It used to work, I don't know what changed.

PHP version: 7.4.16 Xdebug version: 3.1.5 VS Code extension version: 1.33.1

Your launch.json: Xdebug php.ini config:

{
  "version": "0.2.0",
  "configurations": [
    {
      "name": "xdebug",
      "type": "php",
      "request": "launch",
      "port": 9003,
      "pathMappings": {
        "/app": "${workspaceRoot}"
      },
      "xdebugSettings": {
        "max_data": 5000,
        "max_children": 300
      }
    },
  ]
}

Xdebug logfile (from setting xdebug.log in php.ini):

[8618] Log opened at 2023-11-02 00:13:05.355306
[8618] [Step Debug] INFO: Connecting to configured address/port: 10.4.0.1:9003.
[8618] [Step Debug] INFO: Connected to debugging client: 10.4.0.1:9003 (through xdebug.client_host/xdebug.client_port). :-)
[8618] [Step Debug] -> <init xmlns="urn:debugger_protocol_v1" xmlns:xdebug="https://xdebug.org/dbgp/xdebug" fileuri="file:///app/public/index.php" language="PHP" xdebug:language_version="7.4.16" protocol_version="1.0" appid="8618"><engine version="3.1.5"><![CDATA[Xdebug]]></engine><author><![CDATA[Derick Rethans]]></author><url><![CDATA[https://xdebug.org]]></url><copyright><![CDATA[Copyright (c) 2002-2022 by Derick Rethans]]></copyright></init>

[8618] [Step Debug] <- feature_set -i 1 -n resolved_breakpoints -v 1
[8618] [Step Debug] -> <response xmlns="urn:debugger_protocol_v1" xmlns:xdebug="https://xdebug.org/dbgp/xdebug" command="feature_set" transaction_id="1" feature="resolved_breakpoints" success="1"></response>

[8618] [Step Debug] <- feature_set -i 2 -n notify_ok -v 1
[8618] [Step Debug] -> <response xmlns="urn:debugger_protocol_v1" xmlns:xdebug="https://xdebug.org/dbgp/xdebug" command="feature_set" transaction_id="2" feature="notify_ok" success="1"></response>

[8618] [Step Debug] <- feature_set -i 3 -n extended_properties -v 1
[8618] [Step Debug] -> <response xmlns="urn:debugger_protocol_v1" xmlns:xdebug="https://xdebug.org/dbgp/xdebug" command="feature_set" transaction_id="3" feature="extended_properties" success="1"></response>

[8618] [Step Debug] <- feature_get -i 4 -n breakpoint_include_return_value
[8618] [Step Debug] -> <response xmlns="urn:debugger_protocol_v1" xmlns:xdebug="https://xdebug.org/dbgp/xdebug" command="feature_get" transaction_id="4" feature_name="breakpoint_include_return_value" supported="0"><![CDATA[0]]></response>

[8618] [Step Debug] <- feature_set -i 5 -n max_data -v 5000
[8618] [Step Debug] -> <response xmlns="urn:debugger_protocol_v1" xmlns:xdebug="https://xdebug.org/dbgp/xdebug" command="feature_set" transaction_id="5" feature="max_data" success="1"></response>

[8618] [Step Debug] <- feature_set -i 6 -n max_children -v 300
[8618] [Step Debug] -> <response xmlns="urn:debugger_protocol_v1" xmlns:xdebug="https://xdebug.org/dbgp/xdebug" command="feature_set" transaction_id="6" feature="max_children" success="1"></response>

[8618] [Step Debug] <- run -i 7
[8618] [Step Debug] -> <response xmlns="urn:debugger_protocol_v1" xmlns:xdebug="https://xdebug.org/dbgp/xdebug" command="run" transaction_id="7" status="stopping" reason="ok"></response>

[8618] [Step Debug] <- stop -i 8
[8618] [Step Debug] -> <response xmlns="urn:debugger_protocol_v1" xmlns:xdebug="https://xdebug.org/dbgp/xdebug" command="stop" transaction_id="8" status="stopped" reason="ok"></response>

[8618] Log closed at 2023-11-02 00:13:05.517521

VS Code extension logfile (from setting "log": true in launch.json):

Not sure how much to include but I think this covers it:

-> threadsRequest
{ command: 'threads', type: 'request', seq: 13 }

<- threadsResponse
Response {
  seq: 0,
  type: 'response',
  request_seq: 13,
  command: 'threads',
  success: true,
  body: { threads: [ Thread { id: 6, name: 'Request 6 (1:25:02 AM)' } ] } }

-> stackTraceRequest
{ command: 'stackTrace',
  arguments: { threadId: 6, startFrame: 0, levels: 20 },
  type: 'request',
  seq: 14 }

xd(6) <- stack_get -i 9
<- outputEvent
OutputEvent {
  seq: 0,
  type: 'event',
  event: 'output',
  body: { category: 'console', output: 'connection 6 closed\n' } }

connection 6 closed
<- continuedEvent
ContinuedEvent {
  seq: 0,
  type: 'event',
  event: 'continued',
  body: { threadId: 6, allThreadsContinued: false } }

<- threadEvent
ThreadEvent { seq: 0, type: 'event', event: 'thread', body: { reason: 'exited', threadId: 6 } }

-> stackTraceRequest
{ command: 'stackTrace',
  arguments: { threadId: 6, startFrame: 0, levels: 20 },
  type: 'request',
  seq: 15 }

<- stackTraceResponse
Response {
  seq: 0,
  type: 'response',
  request_seq: 15,
  command: 'stackTrace',
  success: false,
  message: 'Unknown thread ID',
  body: { error: { id: 0, format: 'Unknown thread ID', showUser: true } } }

Code snippet to reproduce: N/A, happens anywhere.

Seems to be related to this line:

https://github.com/xdebug/vscode-php-debug/blob/291181c5024a45415c90468552f4905a6febb36b/src/phpDebug.ts#L950-L952

I noticed that my connection was closed after hitting the breakpoint. I wonder if that is the cause, and how I might fix it.

I'm going to be researching a fix for this on my own, but I wanted to post the problem here to document my findings.

P.S. Thank you for your work on this plugin, it's very valuable.

zobo commented 8 months ago

Interesting. I can't really dive into this right now, so I had just a quick look.

  1. Unknown thread ID happens when the IDE requests something related to an Xdebug connection that is no longer there.
  2. I can see connection 6 closed as a result of stack_get

Your PHP is probably crashing or something else is going on that the connection is dropped. I suggest you remove max_children from your xdebugSettings as that should not be needed. The debug adapter can incrementally request pages of array/object children.

Second thing that might be an issue in the adapter (however this is not causing Xdebug to drop the connection) is that the DAP message sequence is a bit strange:

  1. threadsRequest
  2. threadsResponse
  3. stackTraceRequest
  4. outputEvent (connection 6 closed)
  5. threadEvent (exited 6)
  6. stackTraceRequest
  7. stackTraceResponse

The response from the stackTraceRequest in step 3 is missing, so the IDE is probably sending a re-try. I need to try to reproduce the issue where the connection is dropped mid response from Xdebug and catch this somehow and return a failed response for stackTraceRequest.

zobo commented 8 months ago

Also try to remove max_data, just in case.

zobo commented 8 months ago

Also. The xdebug.log and the VS Code log do not seem in sync. There is no stack_get in the xdebug.log.

MitchTalmadge commented 8 months ago

Thank you so much for your time and your help, it means a lot to me. The logs not being in sync was my fault, I don't think I got them from the same request. This time I have been more cautious and collected logs from xdebug, the extension, and PHP itself from the same request. These are with the following configs:

launch.json

{
  "version": "0.2.0",
  "configurations": [
    {
      "name": "xdebug",
      "type": "php",
      "log": true,
      "request": "launch",
      "port": 9003,
      "pathMappings": {
        "/app": "${workspaceRoot}",
      },
    },
  ]
}

xdebug.ini

[PHP]
post_max_size = 100M
upload_max_filesize = 100M

[xdebug]
xdebug.mode=debug
xdebug.log=/app/log/xdebug.log
xdebug.start_with_request=yes
xdebug.client_host=10.4.0.1
xdebug.client_port=9003

I renamed a few things in the configs and logs to placeholder values like app.com or whatever, to preserve privacy for the company I work for... hope you understand, let me know if it's an issue. The thing that is most interesting to me is that the PHP pool child is crashing as you suspected: WARNING: [pool www] child 8 exited on signal 11 (SIGSEGV) after 29.531151 seconds from start. I didn't include this before because I didn't notice it until now. I wonder why it is dying...

It sounds like this is not an issue with the VSCode extension, but I'll let you know when I find the root cause. Thank you again!

xdebug.log

[8] Log opened at 2023-11-06 06:36:34.598941
[8] [Step Debug] INFO: Connecting to configured address/port: 10.4.0.1:9003.
[8] [Step Debug] INFO: Connected to debugging client: 10.4.0.1:9003 (through xdebug.client_host/xdebug.client_port). :-)
[8] [Step Debug] -> <init xmlns="urn:debugger_protocol_v1" xmlns:xdebug="https://xdebug.org/dbgp/xdebug" fileuri="file:///app/public/index.php" language="PHP" xdebug:language_version="7.4.16" protocol_version="1.0" appid="8"><engine version="3.1.5"><![CDATA[Xdebug]]></engine><author><![CDATA[Derick Rethans]]></author><url><![CDATA[https://xdebug.org]]></url><copyright><![CDATA[Copyright (c) 2002-2022 by Derick Rethans]]></copyright></init>

[8] [Step Debug] <- feature_set -i 1 -n resolved_breakpoints -v 1
[8] [Step Debug] -> <response xmlns="urn:debugger_protocol_v1" xmlns:xdebug="https://xdebug.org/dbgp/xdebug" command="feature_set" transaction_id="1" feature="resolved_breakpoints" success="1"></response>

[8] [Step Debug] <- feature_set -i 2 -n notify_ok -v 1
[8] [Step Debug] -> <response xmlns="urn:debugger_protocol_v1" xmlns:xdebug="https://xdebug.org/dbgp/xdebug" command="feature_set" transaction_id="2" feature="notify_ok" success="1"></response>

[8] [Step Debug] <- feature_set -i 3 -n extended_properties -v 1
[8] [Step Debug] -> <response xmlns="urn:debugger_protocol_v1" xmlns:xdebug="https://xdebug.org/dbgp/xdebug" command="feature_set" transaction_id="3" feature="extended_properties" success="1"></response>

[8] [Step Debug] <- feature_get -i 4 -n breakpoint_include_return_value
[8] [Step Debug] -> <response xmlns="urn:debugger_protocol_v1" xmlns:xdebug="https://xdebug.org/dbgp/xdebug" command="feature_get" transaction_id="4" feature_name="breakpoint_include_return_value" supported="0"><![CDATA[0]]></response>

[8] [Step Debug] <- feature_set -i 5 -n max_children -v 100
[8] [Step Debug] -> <response xmlns="urn:debugger_protocol_v1" xmlns:xdebug="https://xdebug.org/dbgp/xdebug" command="feature_set" transaction_id="5" feature="max_children" success="1"></response>

[8] [Step Debug] <- breakpoint_set -i 6 -t line -f file:///app/application/modules/wildcard/controllers/AdminController.php -n 1666
[8] [Step Debug] -> <response xmlns="urn:debugger_protocol_v1" xmlns:xdebug="https://xdebug.org/dbgp/xdebug" command="breakpoint_set" transaction_id="6" id="80001" resolved="unresolved"></response>

[8] [Step Debug] <- run -i 7
[8] [Step Debug] -> <notify xmlns="urn:debugger_protocol_v1" xmlns:xdebug="https://xdebug.org/dbgp/xdebug" name="breakpoint_resolved"><breakpoint type="line" resolved="resolved" filename="file:///app/application/modules/wildcard/controllers/AdminController.php" lineno="1666" state="enabled" hit_count="0" hit_value="0" id="80001"></breakpoint></notify>

[8] [Step Debug] -> <response xmlns="urn:debugger_protocol_v1" xmlns:xdebug="https://xdebug.org/dbgp/xdebug" command="run" transaction_id="7" status="break" reason="ok"><xdebug:message filename="file:///app/application/modules/wildcard/controllers/AdminController.php" lineno="1666"></xdebug:message></response>

[8] [Step Debug] <- stack_get -i 8

Extension Logs

new connection 1 from ::ffff:172.19.0.8
xd(1) -> <?xml version="1.0" encoding="iso-8859-1"?><init xmlns="urn:debugger_protocol_v1" xmlns:xdebug="https://xdebug.org/dbgp/xdebug" fileuri="file:///app/public/index.php" language="PHP" xdebug:language_version="7.4.16" protocol_version="1.0" appid="8"><engine version="3.1.5"><![CDATA[Xdebug]]></engine><author><![CDATA[Derick Rethans]]></author><url><![CDATA[https://xdebug.org]]></url><copyright><![CDATA[Copyright (c) 2002-2022 by Derick Rethans]]></copyright></init>
xd(1) <- feature_set -i 1 -n resolved_breakpoints -v 1
xd(1) -> <?xml version="1.0" encoding="iso-8859-1"?><response xmlns="urn:debugger_protocol_v1" xmlns:xdebug="https://xdebug.org/dbgp/xdebug" command="feature_set" transaction_id="1" feature="resolved_breakpoints" success="1"></response>
xd(1) <- feature_set -i 2 -n notify_ok -v 1
xd(1) -> <?xml version="1.0" encoding="iso-8859-1"?><response xmlns="urn:debugger_protocol_v1" xmlns:xdebug="https://xdebug.org/dbgp/xdebug" command="feature_set" transaction_id="2" feature="notify_ok" success="1"></response>
xd(1) <- feature_set -i 3 -n extended_properties -v 1
xd(1) -> <?xml version="1.0" encoding="iso-8859-1"?><response xmlns="urn:debugger_protocol_v1" xmlns:xdebug="https://xdebug.org/dbgp/xdebug" command="feature_set" transaction_id="3" feature="extended_properties" success="1"></response>
xd(1) <- feature_get -i 4 -n breakpoint_include_return_value
xd(1) -> <?xml version="1.0" encoding="iso-8859-1"?><response xmlns="urn:debugger_protocol_v1" xmlns:xdebug="https://xdebug.org/dbgp/xdebug" command="feature_get" transaction_id="4" feature_name="breakpoint_include_return_value" supported="0"><![CDATA[0]]></response>
xd(1) <- feature_set -i 5 -n max_children -v 100
xd(1) -> <?xml version="1.0" encoding="iso-8859-1"?><response xmlns="urn:debugger_protocol_v1" xmlns:xdebug="https://xdebug.org/dbgp/xdebug" command="feature_set" transaction_id="5" feature="max_children" success="1"></response>
<- threadEvent
ThreadEvent { seq: 0, type: 'event', event: 'thread', body: { reason: 'started', threadId: 1 } }

xd(1) <- breakpoint_set -i 6 -t line -f file:///app/application/modules/wildcard/controllers/AdminController.php -n 1666
xd(1) -> <?xml version="1.0" encoding="iso-8859-1"?><response xmlns="urn:debugger_protocol_v1" xmlns:xdebug="https://xdebug.org/dbgp/xdebug" command="breakpoint_set" transaction_id="6" id="80001" resolved="unresolved"></response>
<- breakpointEvent
BreakpointEvent {
  seq: 0,
  type: 'event',
  event: 'breakpoint',
  body: { reason: 'changed', breakpoint: { id: 1, verified: false } } }

xd(1) <- run -i 7
xd(1) -> <?xml version="1.0" encoding="iso-8859-1"?><notify xmlns="urn:debugger_protocol_v1" xmlns:xdebug="https://xdebug.org/dbgp/xdebug" name="breakpoint_resolved"><breakpoint type="line" resolved="resolved" filename="file:///app/application/modules/wildcard/controllers/AdminController.php" lineno="1666" state="enabled" hit_count="0" hit_value="0" id="80001"></breakpoint></notify>
<- breakpointEvent
BreakpointEvent {
  seq: 0,
  type: 'event',
  event: 'breakpoint',
  body: { reason: 'changed', breakpoint: { id: 1, verified: true, line: 1666 } } }

-> threadsRequest
{ command: 'threads', type: 'request', seq: 8 }

<- threadsResponse
Response {
  seq: 0,
  type: 'response',
  request_seq: 8,
  command: 'threads',
  success: true,
  body: { threads: [ Thread { id: 1, name: 'Request 1 (11:36:34 PM)' } ] } }

xd(1) -> <?xml version="1.0" encoding="iso-8859-1"?><response xmlns="urn:debugger_protocol_v1" xmlns:xdebug="https://xdebug.org/dbgp/xdebug" command="run" transaction_id="7" status="break" reason="ok"><xdebug:message filename="file:///app/application/modules/wildcard/controllers/AdminController.php" lineno="1666"></xdebug:message></response>
<- stoppedEvent
StoppedEvent {
  seq: 0,
  type: 'event',
  event: 'stopped',
  body: { reason: 'breakpoint', threadId: 1, allThreadsStopped: false } }

-> threadsRequest
{ command: 'threads', type: 'request', seq: 9 }

<- threadsResponse
Response {
  seq: 0,
  type: 'response',
  request_seq: 9,
  command: 'threads',
  success: true,
  body: { threads: [ Thread { id: 1, name: 'Request 1 (11:36:34 PM)' } ] } }

-> stackTraceRequest
{ command: 'stackTrace',
  arguments: { threadId: 1, startFrame: 0, levels: 20 },
  type: 'request',
  seq: 10 }

xd(1) <- stack_get -i 8
<- outputEvent
OutputEvent {
  seq: 0,
  type: 'event',
  event: 'output',
  body: { category: 'console', output: 'connection 1 closed\n' } }

connection 1 closed
<- continuedEvent
ContinuedEvent {
  seq: 0,
  type: 'event',
  event: 'continued',
  body: { threadId: 1, allThreadsContinued: false } }

<- threadEvent
ThreadEvent { seq: 0, type: 'event', event: 'thread', body: { reason: 'exited', threadId: 1 } }

-> stackTraceRequest
{ command: 'stackTrace',
  arguments: { threadId: 1, startFrame: 0, levels: 20 },
  type: 'request',
  seq: 11 }

<- stackTraceResponse
Response {
  seq: 0,
  type: 'response',
  request_seq: 11,
  command: 'stackTrace',
  success: false,
  message: 'Unknown thread ID',
  body: { error: { id: 0, format: 'Unknown thread ID', showUser: true } } }

-> disconnectRequest
{ command: 'disconnect',
  arguments: { restart: false, terminateDebuggee: true },
  type: 'request',
  seq: 12 }

<- disconnectResponse
Response { seq: 0, type: 'response', request_seq: 12, command: 'disconnect', success: true }

PHP Logs

docker-nginx           | 172.19.0.1 - - [06/Nov/2023:06:36:18 +0000] "GET http://dev.app.com/admin/index HTTP/1.1" 200 119197 "https://dev.app.com/login" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/118.0.0.0 Safari/537.36" 0.286
docker-app             | 172.19.0.9 -  06/Nov/2023:06:36:17 +0000 "GET /index.php" 200
docker-nginx           | 172.19.0.1 - - [06/Nov/2023:06:36:18 +0000] "GET http://dev.app.com/lib1.js?v=1699252577 HTTP/1.1" 200 136703 "https://dev.app.com/admin/index" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/118.0.0.0 Safari/537.36" 0.000
docker-nginx           | 172.19.0.1 - - [06/Nov/2023:06:36:18 +0000] "GET http://dev.app.com/lib2.js?v=1699252577 HTTP/1.1" 200 2780 "https://dev.app.com/admin/index" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/118.0.0.0 Safari/537.36" 0.000
docker-nginx           | 172.19.0.1 - - [06/Nov/2023:06:36:18 +0000] "GET http://dev.app.com/lib3.js?v=1699252577 HTTP/1.1" 200 6774 "https://dev.app.com/admin/index" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/118.0.0.0 Safari/537.36" 0.000
docker-nginx           | 172.19.0.1 - - [06/Nov/2023:06:36:18 +0000] "GET http://dev.app.com/lib4.js?v=1699252577 HTTP/1.1" 200 6004 "https://dev.app.com/admin/index" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/118.0.0.0 Safari/537.36" 0.000
docker-nginx           | 172.19.0.1 - - [06/Nov/2023:06:36:18 +0000] "GET http://dev.app.com/lib5.js?v=1699252577 HTTP/1.1" 200 2142784 "https://dev.app.com/admin/index" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/118.0.0.0 Safari/537.36" 0.002
docker-nginx           | 172.19.0.1 - - [06/Nov/2023:06:36:18 +0000] "GET http://dev.app.com/lib6.css?v=1699252577 HTTP/1.1" 200 5453 "https://dev.app.com/admin/index" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/118.0.0.0 Safari/537.36" 0.000
docker-nginx           | 172.19.0.1 - - [06/Nov/2023:06:36:18 +0000] "GET http://dev.app.com/lib7.css?v=1699252577 HTTP/1.1" 200 8406 "https://dev.app.com/admin/index" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/118.0.0.0 Safari/537.36" 0.000
docker-nginx           | 172.19.0.1 - - [06/Nov/2023:06:36:18 +0000] "GET http://dev.app.com/lib8.js.gz?v=1699252577 HTTP/1.1" 200 2680534 "https://dev.app.com/admin/index" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/118.0.0.0 Safari/537.36" 0.001
docker-nginx           | 172.19.0.1 - - [06/Nov/2023:06:36:18 +0000] "GET http://dev.app.com/lib9.css?v=1699252577 HTTP/1.1" 200 120825 "https://dev.app.com/admin/index" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/118.0.0.0 Safari/537.36" 0.000
docker-mysql           | 2023-11-06T06:36:34.813613Z 17 [Note] Aborted connection 17 to db: 'app' user: 'app_user' host: '172.19.0.8' (Got an error reading communication packets)
docker-mysql           | 2023-11-06T06:36:34.813628Z 16 [Note] Aborted connection 16 to db: 'app' user: 'app_user' host: '172.19.0.8' (Got an error reading communication packets)
docker-mysql           | 2023-11-06T06:36:34.813662Z 14 [Note] Aborted connection 14 to db: 'app' user: 'app_user' host: '172.19.0.8' (Got an error reading communication packets)
docker-mysql           | 2023-11-06T06:36:34.813676Z 13 [Note] Aborted connection 13 to db: 'app' user: 'app_user' host: '172.19.0.8' (Got an error reading communication packets)
docker-nginx           | 2023/11/06 06:36:34 [error] 32#32: *1 recv() failed (104: Connection reset by peer) while reading response header from upstream, client: 172.19.0.3, server: *.dev.app.com, request: "GET /admin/index HTTP/1.1", upstream: "fastcgi://172.19.0.8:9000", host: "dev.app.com", referrer: "https://dev.app.com/login"
docker-mysql           | 2023-11-06T06:36:34.813647Z 15 [Note] Aborted connection 15 to db: 'app' user: 'app_user' host: '172.19.0.8' (Got an error reading communication packets)
docker-mysql           | 2023-11-06T06:36:34.813752Z 12 [Note] Aborted connection 12 to db: 'app' user: 'app_user' host: '172.19.0.8' (Got an error reading communication packets)
docker-mysql           | 2023-11-06T06:36:34.813768Z 11 [Note] Aborted connection 11 to db: 'app' user: 'app_user' host: '172.19.0.8' (Got an error reading communication packets)
docker-nginx           | 172.19.0.1 - - [06/Nov/2023:06:36:34 +0000] "GET http://dev.app.com/admin/index HTTP/1.1" 502 559 "https://dev.app.com/login" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/118.0.0.0 Safari/537.36" 0.215
docker-app             | [06-Nov-2023 06:36:34] WARNING: [pool www] child 8 exited on signal 11 (SIGSEGV) after 29.531151 seconds from start
docker-app             | [06-Nov-2023 06:36:34] NOTICE: [pool www] child 9 started
zobo commented 8 months ago

Good question why it segfaults. I suggest you make a small script that doesn't have any complex objects on the stack. This could be some infinite recursion problem in Xdebug, but since PHP 7.4 and Xdebug 3.1 are out of support I doubt much can be done here. I did a quick search in Xdebug bug database and found this. https://bugs.xdebug.org/view.php?id=2038

Although not exactly the same, you could try to add mode=debug,develop and log_level to something higher to see if you get any extra info about why it segfaults.

MitchTalmadge commented 8 months ago

This could be some infinite recursion problem in Xdebug

Thank you for saying this. I put a breakpoint much earlier in my application's lifecycle and it works great, I can step through as usual. Then I put a breakpoint later in the lifecycle, and it segfaults. It does sound like a recursion problem. I'll have to keep narrowing down to find out where it happens, but I am thankful for your help with debugging this! I see you made a PR that will close this, so I am going to leave it open, but I am pretty confident now that my particular problem is due to our old codebase. If I ever find the root cause I'll be sure to post an update. :)

since PHP 7.4 and Xdebug 3.1 are out of support

Yeah.. like I said, old codebase. I am starting to encourage my team to spend time doing an upgrade. We could really use it.

Thank you again!!

MitchTalmadge commented 8 months ago

Found it! We had a large closure that was added recently to one of our routers, and Laravel was serializing it, then unserializing it later. I don't know the specifics, but I suspect this was overflowing the stack trace because instead of a file path and a line number being added to the stack trace, it would add "laravel-serializable-closure" followed by the entire contents of the closure's source code, which was around 120 lines long. Adding it to a proper middleware fixed the issue.

zobo commented 8 months ago

Cool! Thanks a lot. Do you have any idea if this happens with the latest version of Xdebug? I'll try to reproduce it when I have time and open a bug for Xdebug if that is still the case. I'll close this issue when I merge the PR - but I need to be sure the changed behavior doesn't cause some side effects.

MitchTalmadge commented 8 months ago

I don't know if it happens with the latest xdebug, but when we finally update to PHP 8.2 I'll revisit this and check if it still happens. Right now I'm held back on xdebug because of the old PHP

zobo commented 8 months ago

I played a but with this and found some other issues in Xdebug and opened an issue there. I have not yet reproduced a crash so I'm guessing it does not happen with PHP 8.1.23 + Xdebug 3.1.2 and newer...