# Help with sending PHP-FPM logs with custom pipeline

**URL:** <https://discuss.elastic.co/t/help-with-sending-php-fpm-logs-with-custom-pipeline/207588>\
**Category:** Beats\
**Tags:** filebeat\
**Created:** [November 12, 2019, 9:08pm UTC](https://discuss.elastic.co/t/help-with-sending-php-fpm-logs-with-custom-pipeline/207588 "2019-11-12T21:08:03Z")\
**Posts on this page:** 6\
**Page:** 1

<div class="post-metadata">

**Author:** ![Slavik\_Fursov](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/slavik_fursov/32/48975_2.png) [@Slavik\_Fursov](https://discuss.elastic.co/u/Slavik_Fursov)\
**Post date:** [November 12, 2019, 9:08pm UTC](https://discuss.elastic.co/t/help-with-sending-php-fpm-logs-with-custom-pipeline/207588/1 "2019-11-12T21:08:03Z")

</div>

I have Debian 9 server with Nginx+PHP.  
Installed Filebeat 7.4.2.  
I have PHP-FPM log, which has entries like this:

```
slavik@deb96:/var/log/php$ sudo cat php7.0-fpm.log
[11-Nov-2019 23:02:37] WARNING: [pool www] child 133043, script '/var/www/RussianChurchVancouver.ca/web/index.php' (request: "GET /index.php") executing too slow (2.092933 sec), logging
[11-Nov-2019 23:16:36] WARNING: [pool www] child 133053, script '/var/www/antipa.site/web/wp-admin/admin-ajax.php' (request: "POST /wp-admin/admin-ajax.php") executing too slow (2.359414 sec), logging
[11-Nov-2019 23:21:03] WARNING: [pool www] child 133051, script '/var/www/hava.propovednik.com/web/index.php' (request: "GET /index.php") executing too slow (2.079449 sec), logging
[11-Nov-2019 23:39:29] WARNING: [pool www] child 133043, script '/var/www/pittsburgh-church.com/web/index.php' (request: "GET /index.php") executing too slow (2.290184 sec), logging

```

so, added this to my `filebeat.yml` config:

```
filebeat.inputs:
# Each - is an input. Most options can be set at the input level, so
# you can use different inputs for various configurations.
# Below are the input specific configurations.

- type: log

  # Change to true to enable this input configuration.
  enabled: true

  # Paths that should be crawled and fetched. Glob based paths.
  paths:
  - /var/log/php/*fpm.log
  close_inactive: 24h

  # Optional additional fields. These fields can be freely picked
  # to add additional information to the crawled log files for filtering
  fields:
    event.dataset: "php.error"
  # The Ingest Node pipeline ID associated with this input. If this is set, it
  # overwrites the pipeline option from the Elasticsearch output.
  pipeline: filebeat-php-slow

```

I also created pipeline "filebeat-php-slow", which exists. Here is [source](https://gitlab.com/SlavikCA/share/snippets/1912561)  
I restarted Filebeat.

And I don't see any events from that log.

I also have NGINX module enabled on same host. And it works fine.

What am I missing here? Is there another step I need to do?

I checked syslog, and here is what I see:

```
slavik@deb96:/var/log$ sudo cat syslog | grep filebeat | grep php
INFO#011log/input.go:152#011Configured paths: [/var/log/php/*fpm.log]
INFO#011log/harvester.go:251#011Harvester started for file: /var/log/php/php7.0-fpm.log

```

Can you suggest any troubleshooting steps I can do?

---

<div class="post-metadata">

**Author:** ![Slavik\_Fursov](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/slavik_fursov/32/48975_2.png) [@Slavik\_Fursov](https://discuss.elastic.co/u/Slavik_Fursov)\
**Post date:** [November 13, 2019, 7:03am UTC](https://discuss.elastic.co/t/help-with-sending-php-fpm-logs-with-custom-pipeline/207588/2 "2019-11-13T07:03:22Z")

</div>

Issue was in pipeline definition: it's grok processor resulted in errors.

I was only able to troubleshoot it by sending events to "\_simulate" endpoint.

---

<div class="post-metadata">

**Author:** ![exekias](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/exekias/32/28718_2.png) [@exekias](https://discuss.elastic.co/u/exekias)\
**Post date:** [November 13, 2019, 3:27pm UTC](https://discuss.elastic.co/t/help-with-sending-php-fpm-logs-with-custom-pipeline/207588/3 "2019-11-13T15:27:29Z")

</div>

Hi @Slavik_Fursov,

I wonder if you got this working then?

It would be quite interesting to convert this into a Filebeat module, what do you think?

Best regards

---

<div class="post-metadata">

**Author:** ![Slavik\_Fursov](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/slavik_fursov/32/48975_2.png) [@Slavik\_Fursov](https://discuss.elastic.co/u/Slavik_Fursov)\
**Post date:** [November 14, 2019, 10:37pm UTC](https://discuss.elastic.co/t/help-with-sending-php-fpm-logs-with-custom-pipeline/207588/4 "2019-11-14T22:37:10Z")

</div>

@exekias  
That would be great.

Here is my pipeline and logs example:

> **[php-fpm.pipeline.json ($1913354) · Snippets · Slavik Fursov / share](https://gitlab.com/SlavikCA/share/snippets/1913354)**
>
> GitLab.com

  
I'm sure you can make it more efficient.

Description:  
Lines 5-15: grok pattern, which is valid for ALL entries of PHP-FPM. Getting TIMESTAMP, LOG\_LEVEL and MESSAGE  
I'm using `php.time` for timestamp - not sure, if there is more appropriate name exists.

Lines 16-45: parsing TIMESTAMP

Lines 46-59: grok processor to get `url.domain`, `http.request.method` and `url.original`

- these fields only present for some messages in the log (usually only for slow scripts, if enabled in PHP config). That's why this processor has `"ignore_missing": true, "ignore_failure": true`
- `url.domain` parsed based on assumption, that it's part of the PHP script path, which goes after `/var/www/`. That's obviously in not universally true. It works for my setup, not sure about default pipeline.

Lines 60-72: grok processor to get duration of slow PHP scripts.

- this field only present for some messages in the log (usually only for slow scripts, if enabled in PHP config). That's why this processor has `"ignore_missing": true, "ignore_failure": true`
- I used `php.duration` for it. Not sure, if there is a better field.

Lines 73-79: `ulrdecode` processor is there in case I have non-english characters in the script path.

---

<div class="post-metadata">

**Author:** ![Slavik\_Fursov](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/slavik_fursov/32/48975_2.png) [@Slavik\_Fursov](https://discuss.elastic.co/u/Slavik_Fursov)\
**Post date:** [November 14, 2019, 10:46pm UTC](https://discuss.elastic.co/t/help-with-sending-php-fpm-logs-with-custom-pipeline/207588/5 "2019-11-14T22:46:24Z")

</div>

I think there are 3 types of logs generated by PHP:

1. FPM-PHP error log. Enabled by default for FPM configurations.  
Example is in previous message.  
Configuration here:  
[https://github.com/php/php-src/blob/PHP-7.3.12/sapi/fpm/php-fpm.conf.in#L19-L60](https://github.com/php/php-src/blob/PHP-7.3.12/sapi/fpm/php-fpm.conf.in#L19-L60)  
CGI would be different, I'm not familiar with CGI.

2. Slow requests log. Disabled by default.  
See example here:  
[https://gitlab.com/SlavikCA/share/snippets/1913365](https://gitlab.com/SlavikCA/share/snippets/1913365)  
Configuration and format defined here:  
[https://github.com/php/php-src/blob/PHP-7.3.12/sapi/fpm/www.conf.in#L320-L333](https://github.com/php/php-src/blob/PHP-7.3.12/sapi/fpm/www.conf.in#L320-L333)

3. PHP access log. Disabled by default.  
Configuration and format defined here:  
[https://github.com/php/php-src/blob/PHP-7.3.12/sapi/fpm/www.conf.in#L257-L318](https://github.com/php/php-src/blob/PHP-7.3.12/sapi/fpm/www.conf.in#L257-L318)

---

<div class="post-metadata">

**Author:** ![system](https://us1.discourse-cdn.com/elastic/original/3X/1/a/1ac57faf039f6b580b3f104ef42a2a89e41014de.png) [@system](https://discuss.elastic.co/u/system)\
**Post date:** [December 12, 2019, 10:46pm UTC](https://discuss.elastic.co/t/help-with-sending-php-fpm-logs-with-custom-pipeline/207588/6 "2019-12-12T22:46:27Z")

</div>

This topic was automatically closed 28 days after the last reply. New replies are no longer allowed.