Your data. Anywhere you go.

New Relic for iOS or Android


Download on the App Store    Android App on Google play


New Relic Insights App for iOS


Download on the App Store


Learn more

Close icon

Relic Solution: PHP Agent Startup Process

level-up
relic-solutions

#1

This aims to detail the startup process of the PHP Agent. This can be useful in troubleshooting why an application is not reporting especially in containerized apps which might start, run a php script, and then exit.

Startup Process

  1. Starting your PHP handler causes a PHP MINIT, or module initialize. This is where the agent attempts to start the newrelic-daemon if it is not already running. This occurs before any PHP code is run and can be seen in the php_agent.log:

2018-10-02 15:59:32.055 -0700 (117565 117565) info: New Relic 8.2.0.221 (“bisque” - “6322967e9a43”) [daemon=’/tmp/.newrelic.sock’ php=‘7.1.22-1+ubuntu16.04.1+deb.sury.org+1’ zts=no sapi=‘apache2handler’ apache=‘2.4.18’ mpm=prefork pid=117565 ppid=1 uid=0 euid=0 gid=0 egid=0 backtrace=yes startup=agent os=‘Linux’ rel=‘4.4.0-87-generic’ mach=‘x86_64’ ver=’#110-Ubuntu SMP Tue Jul 18 12’ node=‘earl’]
2018-10-02 15:59:32.055 -0700 (117565 117565) verbosedebug: daemon connect(fd=11 uds=/tmp/.newrelic.sock) returned -1 errno=ECONNREFUSED
2018-10-02 15:59:32.056 -0700 (117565 117565) info: spawned daemon child pid=117568
2018-10-02 15:59:32.087 -0700 (117565 117565) debug: MINIT processing done

Here we see an initial connect failing due to no process existing and the agent then starts a new daemon process. This step can be skipped if you are running the daemon in external startup mode (init).

  1. The first PHP RINIT, or request initialize, attempts to make a connection. When this occurs, the daemon connects to New Relic to check for any settings you have applied through the UI for that app. While this occurs, transactions will be lost. If you have only one PHP script that runs this will be lost connecting the agent and you will see no data collected. A workaround is to make a dummy PHP request to connect the app before starting your script. This can be seen in the agent log as well:

2018-10-02 16:00:31.140 -0700 (117584 117584) debug: late_init called from pid=117584
2018-10-02 16:00:31.141 -0700 (117584 117584) verbosedebug: RINIT processing started
2018-10-02 16:00:31.141 -0700 (117584 117584) verbosedebug: daemon connect(fd=14 uds=/tmp/.newrelic.sock) succeeded
2018-10-02 16:00:31.141 -0700 (117584 117584) debug: added app=‘Earl (Ubuntu)’ license=‘ea…9b’
2018-10-02 16:00:31.141 -0700 (117584 117584) verbosedebug: querying app=‘Earl (Ubuntu)’ from parent=14
2018-10-02 16:00:31.141 -0700 (117584 117584) verbosedebug: sending appinfo message, len=6652
2018-10-02 16:00:31.143 -0700 (117584 117584) debug: APPINFO reply unknown app=‘Earl (Ubuntu)’
2018-10-02 16:00:31.144 -0700 (117584 117584) debug: unable to begin transaction: app ‘Earl (Ubuntu)’ is unknown
2018-10-02 16:00:34.146 -0700 (117584 117584) verbosedebug: post-deactivate processing started
2018-10-02 16:00:34.146 -0700 (117584 117584) verbosedebug: post-deactivate processing done

Note that while generally each RINIT matches to a transaction, a single RINIT can be broken up into multiple transactions such as in the case of Laravel queue:work or using the newrelic_end_transaction()/newrelic_start_transaction() API calls.

  1. Finally, once connected further RINITs will report to New Relic:

2018-10-02 16:00:51.695 -0700 (117583 117583) debug: late_init called from pid=117583
2018-10-02 16:00:51.696 -0700 (117583 117583) verbosedebug: RINIT processing started
2018-10-02 16:00:51.696 -0700 (117583 117583) verbosedebug: daemon connect(fd=14 uds=/tmp/.newrelic.sock) succeeded
2018-10-02 16:00:51.697 -0700 (117583 117583) debug: added app=‘Earl (Ubuntu)’ license=‘ea…9b’
2018-10-02 16:00:51.697 -0700 (117583 117583) verbosedebug: querying app=‘Earl (Ubuntu)’ from parent=14
2018-10-02 16:00:51.697 -0700 (117583 117583) verbosedebug: sending appinfo message, len=6652
2018-10-02 16:00:51.697 -0700 (117583 117583) debug: APPINFO reply connected
2018-10-02 16:00:51.697 -0700 (117583 117583) debug: APPINFO reply full app=‘Earl (Ubuntu)’ agent_run_id=WzIse2E6MTc3NDE0MzA1NixiOjE5Nzk5NzM2MyxjOjE3MzE3NTEsZDoiOC4yLjAuMjIxIixlOiJwaHAiLGY6ImVhcmwiLGc6W3thOjEwMTYwNDMyMSxiOiJFYXJsIChVYnVudHUpIn1dfSw3NjQzMTI3MzFd
2018-10-02 16:00:51.697 -0700 (117583 117583) debug: ‘WT_IS_FILENAME & SCRIPT_FILENAME’ naming is ‘/beastmanisbest.php’
2018-10-02 16:00:51.697 -0700 (117583 117583) verbosedebug: RINIT processing done
2018-10-02 16:00:54.698 -0700 (117583 117583) verbosedebug: RSHUTDOWN processing started
2018-10-02 16:00:54.699 -0700 (117583 117583) verbosedebug: request_uri=’/beastmanisbest.php’
2018-10-02 16:00:54.699 -0700 (117583 117583) verbosedebug: RSHUTDOWN processing done

A command line PHP script is often a single MINIT/RINIT combo. This means that it alone will only do one of the above steps while something like PHP-FPM will have an MINIT when the service is started and each request will be an RINIT.