Error log truncates important infos

We have error logs like this:

2016/06/14 12:47:45 [error] 21036#21036: *378143 FastCGI sent in stderr:
“PHP message: PHP Notice: Undefined index: model_name in
/data/example.com/module/SalesFloor/view/partial/flyout/product.phtml on
line 20
PHP message: PHP Notice: Undefined index: model_name in
/data/example.com/module/SalesFloor/view/partial/flyout/product.phtml on
line 21
PHP message: PHP Notice: Undefined index: model_name in
/data/example.com/module/SalesFloor/view/partial/flyout/product.phtml on
line 23
PHP message: PHP Notice: Undefined index: reducedprice in
/data/example.com/module/SalesFloor/view/partial/flyout/product.phtml on
line 24
PHP message: PHP Notice: Undefined index: currentprice in
/data/example.com/module/SalesFloor/view/partial/flyout/product.phtml on
line 24” while reading response header from upstream, client: 127.0.0.1,
server: example.com, request: “GET / HTTP/1.1”, upstream:
“fastcgi://unix:/var/run/php-fpm-example.com.sock:”, host: “127.0.0.1”

For us the most important parts are the values in the last line like
client,
server and so on.

Sometimes we see erros like this:

2016/06/14 12:47:23 [error] 31450#31450: *177931 FastCGI sent in stderr:
"PHP message: PHP Notice: pg_execute(): Cannot set connection to
blocking
mode in
/data/example.com/vendor/zendframework/zend-db/src/Adapter/Driver/Pgsql/Statement.php
on line 228
PHP message: PHP Fatal error: Uncaught exception
‘Zend\Db\Adapter\Exception\InvalidQueryException’ with message ‘FATAL:
terminating connection due to administrator command
SSL connection has been closed unexpectedly’ in
/data/example.com/vendor/zendframework/zend-db/src/Adapter/Driver/Pgsql/Statement.php:235
Stack trace:
#0
/data/example.com/vendor/zendframework/zend-db/src/TableGateway/AbstractTableGateway.php(238):
Zend\Db\Adapter\Driver\Pgsql\Statement->execute()
#1
/data/example.com/vendor/zendframework/zend-db/src/TableGateway/AbstractTableGateway.php(208):
Zend\Db\TableGateway\AbstractTableGateway->executeSelect(Object(Zend\Db\Sql\Select))
#2 /data/example.com/corporate/XYZ/src/XYZ/Table/Table.php(758):
Zend\Db\TableGateway\AbstractTableGateway->selectWith(Object(Zend\Db\Sql\Select))
#3 /data/example.com/module/Product/src/Product/Table/Product.php(835):
XYZ\Table\Table->selectWith(Object(Zend\Db\Sql\Select))
#4
/data/example.com/module/Product/src/Product/DataService/ProductDataService.php(232):
Product\Table\P…
PHP message: PHP Notice: pg_prepare(): Cannot set connection to
blocking
mode in
/data/example.com/vendor/zendframework/zend-db/src/Adapter/Driver/Pgsql/Statement.php
on line 179
PHP message: PHP Notice: pg_execute(): Cannot set connection to
blocking
mode in
/data/example.com/vendor/zendframework/zend-db/src/Adapter/Driver/Pgsql/Statement.php
on line 228
PHP message: PHP Fatal error: Uncaught exception
‘Zend\Db\Adapter\Exception\InvalidQueryException’ with message ‘FATAL:
terminating connection due to administrator command
SSL connection has been closed unexpectedly’ in
/data/example.com/vendor/zendframework/zend-db/src/Adapter/Driver/Pgsql/Statement.php:235
Stack trace:
#0
/data/example.com/vendor/zendframework/zend-db/src/TableGateway/AbstractTableGateway.php(238):
Z

It looks like they are truncated. We miss a lot of important information
like client ip and so on. Is this a known limitation or bug in nginx?

Posted at Nginx Forum:

Error logs have a hard coded length limit of 2048 bytes iirc, to prevent
runaway log entries. You might be better off configuring your app to
dump stack traces instead of relying on a proxy.

Hello!

On Tue, Jun 14, 2016 at 10:44:32AM -0400, philipp wrote:

[…]

Sometimes we see erros like this:

[…]

It looks like they are truncated. We miss a lot of important information
like client ip and so on. Is this a known limitation or bug in nginx?

This is a known limitation. To allow error logging without any
memory allocations, a 2048-bytes buffer is used. This limits
maximum length of error log lines accordingly.


Maxim D.
http://nginx.org/

Hmm I understand that limitation. But an attacker or a bad application
can
hide the important information which we need to identify the source of
the
problem.

What about limiting the fastcgi output to 1024 bytes and appending this
info
with max 1024 bytes.
client: 127.0.0.1, server: example.com, upstream:
“fastcgi://unix:/var/run/php-fpm-example.com.sock:”, host: “127.0.0.1” ,
request: “GET / HTTP/1.1”

[fastcgi - output max 1024][request info: client, server, upstream,
host,
request - max 1024]

This would ensure that client, server and upstream are always provided.
Host
and Request can be filled with “user generated” content, so you should
put
it to the end. This would ensure that an attacker cannot hide the
important
fields.

Posted at Nginx Forum:

PHP-FPM allows generating its own log files.
The default behavior of having errors sent back the FastCGI tube can be
overridden with proper error logging on PHP-FPM side.
2048 bytes for each line of log is more than enough on the web server
side.

Do your homework: read the PHP docs. If you are still struggling, ask
some
PHP community to help you through.

B. R.

On Wed, Jun 15, 2016 at 5:53 PM, Robert P. <

If you’re allowing user-generated output to be written directly to your
logs without any sort of sanitation, you’ve got bigger problems to worry
about :stuck_out_tongue: Again, it doesn’t really make sense to have your fcgi error
sent
here- why can’t your fcgi process log elsewhere, and leaving the nginx
error log for nginx issues?

On Wed, Jun 15, 2016 at 6:51 AM, philipp [email protected]