Skip to content

Commit 5d6440d

Browse files
authored
Merge pull request #410 from pingiun/add-livestack
Add information on livestack.py
2 parents 107fab3 + 166beb3 commit 5d6440d

File tree

1 file changed

+146
-0
lines changed

1 file changed

+146
-0
lines changed
Lines changed: 146 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,146 @@
1+
---
2+
myst:
3+
html_meta:
4+
description: If you have a PHP process that has been running for a long while,
5+
it can be difficult to find out what it’s currently doing. With livestack.py
6+
you can see a point-in-time stack trace of a running process, and have a place
7+
to start debugging further.
8+
title: How to debug long running PHP processes with livestack on Hypernode?
9+
---
10+
11+
# How to debug long running PHP processes with livestack.py
12+
13+
[livestack.py](https://github.com/bigbridge-nl/livestack) is a debugging tool built by [Bigbridge](https://bigbridge.nl).
14+
It can be used on Hypernode to inspect the current stack frame of a running PHP process.
15+
It requires some setup to get running, but it is very powerful when investigating long running cron commands, or hanging web requests.
16+
17+
Note that livestack.py is not a Hypernode project, and as such Hypernode does not give support for the usage or with any issues of livestack.py.
18+
You can [create a GitHub issue](https://github.com/bigbridge-nl/livestack/issues) on the livestack GitHub page when you encounter problems.
19+
20+
## Setup
21+
22+
First, contact [hypernode support](mailto:[email protected]?subject=PHP%20debug%20symbols) to ask them to enable the php-dbg (PHP debug symbols) package for your Hypernode.
23+
For now this is a manual step that needs to be done by support on any Hypernode you want to use livestack.py on.
24+
25+
Then, you can copy the script to your hypernode:
26+
27+
```bash
28+
# On your hypernode:
29+
git clone https://github.com/bigbridge-nl/livestack.git
30+
```
31+
32+
## General usage
33+
34+
Let's say you're investigating an index process that is taking a lot of time to complete:
35+
36+
```shell
37+
app@webshop-magweb-aws:~$ ps aux | grep cron:run
38+
app 1614969 0.0 0.0 2584 932 ? S 10:39 23:51 /usr/bin/php /data/web/webshop.nl/deployments/releases/current/bin/magento cron:run --group index
39+
```
40+
41+
The ps output shows this process has been running for a long time.
42+
It may be in a loop, or waiting on something, or just processing way too many things---but you don't know yet.
43+
44+
If you knew where to look you could use XDebug locally or on your [staging server](/hypernode-platform/php/remote-debugging.md), but the first step is knowing where to look.
45+
Using livestack.py you can pause the program momentarily and print out a stacktrace.
46+
Now you have an idea what the program is currently running.
47+
By running livestack.py a few times, you can see in which area of the code PHP is spending the most time.
48+
49+
Let's see how it works with an example:
50+
51+
```shell
52+
app@webshop-magweb-aws:~$ ~/livestack/livestack.py 'cron:run --group index'
53+
Printing stack for '/usr/bin/php /data/web/webshop.nl/deployments/releases/current/bin/magento cron:run --group index' (PID: 1614969)
54+
55+
#0 (internal) - curl_exec
56+
#1 vendor/ezimuel/ringphp/src/Client/CurlHandler.php:89 - GuzzleHttp\Ring\Client\CurlHandler::_invokeAsArray
57+
#2 vendor/ezimuel/ringphp/src/Client/CurlHandler.php:68 - GuzzleHttp\Ring\Client\CurlHandler::__invoke
58+
#3 vendor/ezimuel/ringphp/src/Client/Middleware.php:30 - GuzzleHttp\Ring\Client\Middleware::GuzzleHttp\Ring\Client\{closure}
59+
#4 vendor/elasticsearch/elasticsearch/src/Elasticsearch/Connections/Connection.php:265 - Elasticsearch\Connections\Connection::Elasticsearch\Connections\{closure}
60+
#5 vendor/elasticsearch/elasticsearch/src/Elasticsearch/Connections/Connection.php:241 - Elasticsearch\Connections\Connection::performRequest
61+
#6 vendor/elasticsearch/elasticsearch/src/Elasticsearch/Transport.php:110 - Elasticsearch\Transport::performRequest
62+
#7 vendor/elasticsearch/elasticsearch/src/Elasticsearch/Client.php:1929 - Elasticsearch\Client::performRequest
63+
#8 vendor/elasticsearch/elasticsearch/src/Elasticsearch/Client.php:347 - Elasticsearch\Client::bulk
64+
#9 vendor/magento/module-elasticsearch-7/Model/Client/Elasticsearch.php:173 - Magento\Elasticsearch7\Model\Client\Elasticsearch::bulkQuery
65+
#10 vendor/magento/module-elasticsearch/Model/Adapter/Elasticsearch.php:237 - Magento\Elasticsearch\Model\Adapter\Elasticsearch::addDocs
66+
#11 vendor/magento/module-elasticsearch/Model/Indexer/IndexerHandler.php:140 - Magento\Elasticsearch\Model\Indexer\IndexerHandler::saveIndex
67+
#12 vendor/magento/module-catalog-search/Model/Indexer/Fulltext.php:176 - Magento\CatalogSearch\Model\Indexer\Fulltext::executeByDimensions
68+
#13 vendor/magento/module-catalog-search/Model/Indexer/Fulltext.php:236 - Magento\CatalogSearch\Model\Indexer\Fulltext::Magento\CatalogSearch\Model\Indexer\{closure}
69+
...
70+
#52 vendor/symfony/console/Application.php:1040 - Symfony\Component\Console\Application::doRunCommand
71+
#53 vendor/symfony/console/Application.php:301 - Symfony\Component\Console\Application::doRun
72+
#54 vendor/magento/framework/Console/Cli.php:116 - Magento\Framework\Console\Cli::doRun
73+
#55 vendor/symfony/console/Application.php:171 - Symfony\Component\Console\Application::run
74+
#56 bin/magento:23 - (unknown function)
75+
```
76+
77+
In this example the grep mode is used.
78+
The first argument is a regex which searches through the running PHP processes.
79+
The equivalent shell command would be (roughly) `ps aux | grep php | grep 'cron:run --group index'`, as livestack.py only filters through php processes.
80+
81+
Another way to use livestack.py is to supply the process ID (PID) directly.
82+
For this, use the `--pid` option.
83+
The two modes work equivalently.
84+
85+
```shell
86+
app@webshop-magweb-aws:~$ ~/livestack/livestack.py --pid=1614969
87+
```
88+
89+
So in this example you can see something happening in the fulltext indexer that's causing problems!
90+
If you run livestack.py a couple of times in short succession, and every time you see the same curl_exec call by this indexer you know where the problem is.
91+
You may not yet know what exactly is causing the problem, but you can start your debugging session somewhere.
92+
93+
## Examining long running web requests
94+
95+
You may already know how to use livefpm and hypernode-fpm-status to see [what kinds of requests your Hypernode is currently serving](/hypernode-platform/tools/what-kind-of-request-is-my-hypernode-serving.md).
96+
You can investigate any long running requests further using livestack.py.
97+
98+
As `hypernode-fpm-status | grep '/some/url'` would give you current PHP process generating some url, you can also run `livestack.py --fpm '/some/url'` to find the current stack trace of that PHP process.
99+
100+
When using the `--fpm` flag, you are basically grepping through the output of `hypernode-fpm-status`, so you can search for a url, ip or user-agent.
101+
102+
An example (this only works if you have a single BUSY request):
103+
104+
```shell
105+
app@webshop-magweb-aws:~$ ./livestack.py --fpm BUSY
106+
Printing stack for 'BUSY 498.7s NL phpfpm 95.97.37.190 GET webshop.hypernode.io/men/tops-men.html?color=58&x=8123111111 (Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/139.0.0.0 Safari/537.36)' (PID: 825564)
107+
108+
#0 (internal) - sleep
109+
#1 /data/web/deployments/releases/3/pub/index.php:11 - (unknown function)
110+
```
111+
112+
Once again, you can also use the `--pid` option instead of grepping using livestack.py.
113+
You don't need to use the `--fpm` option when you have the PID directly.
114+
115+
## Considerations with production usage
116+
117+
Livestack.py works in production, where you normally would not have XDebug enabled.
118+
However, do note that livestack.py does pause your PHP script or request for one to two seconds.
119+
In cases where the script or request seems to be hanging anyway this may not matter but it's an important consideration.
120+
121+
Also, although livestack.py has not managed to crash the PHP process with simple stack trace dumping during testing at Bigbridge, it is certainly possible (and not hard) to crash the PHP process in interactive usage.
122+
Care should be taken to not prod at the PHP internals too much when using GDB or livestack.py in interactive mode.
123+
124+
## Advanced (interactive) usage
125+
126+
Internally, livestack.py uses GDB to attach to the running process and inspect it's memory.
127+
After commanding GDB, it unattaches and the PHP process is free to continue running.
128+
However, in interactive mode you can stay in GDB and issue more commands.
129+
This keeps the PHP process paused while you are interacting with GDB.
130+
Of course, this hangs the PHP script or request for as long as you stay attached.
131+
132+
Interactive mode allows you to jump into GDB giving you full power to see every byte of process memory and execution flow.
133+
Besides the regular GDB commands, two extra PHP specific commands are added by livestack.py:
134+
135+
- `php-print-stack` This is the same as a regular incantation of livestack.py, and prints the stack trace PHP was currently executing.
136+
137+
- `php-frame-info <frame-number>` Using the frame number from `php-print-stack`, get some more information about this function call.
138+
Currently this only shows the contents of "simple" function arguments.
139+
As internally this uses json_encode, object arguments are not supported.
140+
However, you can see the sql insert command or the bindings of the `Magento\Framework\DB\Adapter\Pdo\Mysql::query` function for example.
141+
142+
Using interactive mode requires a bit more GDB knowledge, and ideally knowledge of the PHP/Zend C code internals.
143+
One interesting command to get started may be the `bt full` command, which shows you a stack trace of the PHP internals.
144+
145+
When you want to exit the interactive mode, you can type `Ctrl+D` or use the `quit` command.
146+
After detaching, the process continues on like normal.

0 commit comments

Comments
 (0)