Ever since I started using a PHP library that produces a long call chain it's been increasingly difficult to debug issues caused by it because my error logs end up containing output like this: (some values have been blanked out using *
)
2017/08/23 10:47:26 [error] 13057#13057: *206119 FastCGI sent in stderr: "PHP message: PHP Fatal error: Uncaught ActiveRecord\DatabaseException: PDOException: SQLSTATE[22P02]: Invalid text representation: 7 ERROR: invalid input syntax for integer: "" in /var/www/********/vendor/php-activerecord/php-activerecord/lib/Connection.php:337
Stack trace:
#0 /var/www/********/vendor/php-activerecord/php-activerecord/lib/Connection.php(337): PDOStatement->execute(Array)
#1 /var/www/********/vendor/php-activerecord/php-activerecord/lib/Table.php(237): ActiveRecord\Connection->query('SELECT * FROM "...', Array)
#2 /var/www/********/vendor/php-activerecord/php-activerecord/lib/Table.php(219): ActiveRecord\Table->find_by_sql('SELECT * FROM "...', Array, false, NULL)
#3 /var/www/********/vendor/php-activerecord/php-activerecord/lib/Model.php(1666): ActiveRecord\Table->find(Array)
#4 /var/www/********/vendor/php-activerecord/php-activerecord/lib/Model.php(1605): ActiveRecord\Model::find_by_pk('', Array)
#5 /var/www/********/includes/classes/Models/NSModel.php(11): ActiveRecord\Model::find(''" while reading response header from upstream, client: **.***.***.***, server: ***********, request: "POST /************************************ HTTP/1.1", upstream: "fastcgi://unix:/run/php/php7.1-fpm.sock:", host: "***********", referrer: "************************************************************"
Notice how on the last line the FastCGI stderr output abruptly ends after ActiveRecord\Model::find(''"
. Another example:
2017/08/22 17:20:53 [error] 13057#13057: *193907 FastCGI sent in stderr: "PHP message: PHP Fatal error: Uncaught TypeError: Argument 1 passed to App\DeviantArt::isImageAvailable() must be of the type string, null given, called in /var/www/********/includes/classes/ImageProvider.php on line 138 and defined in /var/www/********/includes/classes/DeviantArt.php:357
Stack trace:
#0 /var/www/********/includes/classes/ImageProvider.php(138): App\DeviantArt::isImageAvailable(NULL)
#1 /var/www/********/includes/classes/ImageProvider.php(21): App\ImageProvider->setUrls('*******')
#2 /var/www/********/includes/classes/Posts.php(207): App\ImageProvider->__construct('******************', Array)
#3 /var/www/********/includes/classes/Controllers/PostController.php(334): App\Posts::checkRequestFinishingImage('***************...')
#4 /var/www/********/includes/classes/RouteHelper.php(11): App\Controllers\PostController->action(Array)
#5 /var/www/********/includes/do.php(27): App\RouteHelper::App\{closure}(Array)
#6 /var/www/********/www/index.php(1): require('/var/www/******...')
#7 {main}
t" while reading response header from upstream, client: **.***.***.***, server: ***********, request: "POST /*************************** HTTP/1.1", upstream: "fastcgi://unix:/run/php/php7.1-fpm.sock:", host: "***********"
Here the stderr output is cut off after the t
, which leaves enough info to find the issue, but it's still not the full message. I cannot find any pattern between the length of the output and when it gets cut off.
I'm using nginx version 1.10.3 and PHP version 7.1.8 on Debian Stretch. I also tried setting the following values in nginx.conf
(because I've looked up solutions to this issue in the past), but the examples above were produced with these settings already in effect.
fastcgi_buffers 256 4k;
client_max_body_size 20M;