# Error log truncates important infos

**URL:** <https://www.ruby-forum.com/t/error-log-truncates-important-infos/244786>\
**Category:** NGINX\
**Created:** [June 14, 2016, 4:44pm UTC](https://www.ruby-forum.com/t/error-log-truncates-important-infos/244786 "2016-06-14T16:44:52Z")\
**Posts on this page:** 6\
**Page:** 1

<div class="post-metadata">

**Author:** ![Rafa\_F](https://www.ruby-forum.com/letter_avatar_proxy/v4/letter/r/958977/32.png) [@Rafa\_F](https://www.ruby-forum.com/u/Rafa_F)\
**Post date:** [June 14, 2016, 4:44pm UTC](https://www.ruby-forum.com/t/error-log-truncates-important-infos/244786/1 "2016-06-14T16:44:52Z")

</div>

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](http://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 log truncates important infos](https://forum.nginx.org/read.php?2,267568,267568#msg-267568)**
>
> 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...

---

<div class="post-metadata">

**Author:** ![casper\_the\_ghost](https://www.ruby-forum.com/letter_avatar_proxy/v4/letter/c/58956e/32.png) [@casper\_the\_ghost](https://www.ruby-forum.com/u/casper_the_ghost)\
**Post date:** [June 14, 2016, 4:53pm UTC](https://www.ruby-forum.com/t/error-log-truncates-important-infos/244786/2 "2016-06-14T16:53:03Z")

</div>

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.

---

<div class="post-metadata">

**Author:** ![casper\_the\_ghost](https://www.ruby-forum.com/letter_avatar_proxy/v4/letter/c/58956e/32.png) [@casper\_the\_ghost](https://www.ruby-forum.com/u/casper_the_ghost)\
**Post date:** [June 14, 2016, 5:00pm UTC](https://www.ruby-forum.com/t/error-log-truncates-important-infos/244786/3 "2016-06-14T17:00:03Z")

</div>

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.

> **[nginx](http://nginx.org/)**

---

<div class="post-metadata">

**Author:** ![casper\_the\_ghost](https://www.ruby-forum.com/letter_avatar_proxy/v4/letter/c/58956e/32.png) [@casper\_the\_ghost](https://www.ruby-forum.com/u/casper_the_ghost)\
**Post date:** [June 15, 2016, 3:52pm UTC](https://www.ruby-forum.com/t/error-log-truncates-important-infos/244786/4 "2016-06-15T15:52:15Z")

</div>

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](http://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:

> **[Re: error log truncates important infos](https://forum.nginx.org/read.php?2,267568,267592#msg-267592)**
>
> 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...

---

<div class="post-metadata">

**Author:** ![casper\_the\_ghost](https://www.ruby-forum.com/letter_avatar_proxy/v4/letter/c/58956e/32.png) [@casper\_the\_ghost](https://www.ruby-forum.com/u/casper_the_ghost)\
**Post date:** [June 15, 2016, 7:22pm UTC](https://www.ruby-forum.com/t/error-log-truncates-important-infos/244786/5 "2016-06-15T19:22:33Z")

</div>

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. \<

---

<div class="post-metadata">

**Author:** ![casper\_the\_ghost](https://www.ruby-forum.com/letter_avatar_proxy/v4/letter/c/58956e/32.png) [@casper\_the\_ghost](https://www.ruby-forum.com/u/casper_the_ghost)\
**Post date:** [June 15, 2016, 5:54pm UTC](https://www.ruby-forum.com/t/error-log-truncates-important-infos/244786/6 "2016-06-15T17:54:20Z")

</div>

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 😛 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 [removed\_email\_address@domain.invalid](mailto:removed_email_address@domain.invalid)
