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

PHP agent can't write to log when invoking php from command line


#1

I am running php-fpm on my servers(All running centos 7) and the daemon can write to the log fine. But on one of my servers(not the others) whenever I run php from the command line I get a warning:

open /var/log/newrelic/newrelic-daemon.log: permission denied

The log files are owned by root and the daemon is running as root.


#2

First thing to check with Red Hat based distros when you get unexpected permissions errors is if selinux is enforcing.

Try this:
getenforce

If it’s the result is enforcing
Then check your audit log for selinux related messages here:
/var/log/audit/audit.log

Or you could use sealert to get detailed information about any message in the audit log.

You can also just turn off selinux temporarily to rule it out with
setenforce 0


Two-a-Days for Team Community
#3

selinux doesn’t seem to be the issue. Tried all those things.


#4

Hey @tkane

That’s an interesting issue. SELinux was a good potential shout by . @jsprague - I would also maybe check if you are using suexec to change the running user of PHP. Are you logged into your machine as root or another user. If another user, then PHP process may be running as a completely different user to the owned files.

Just for reference my system has root owners php_agent and newrelic-daemon log files. I do have the user for FPM defined myself in
/etc/php-fpm.d/www.conf

under the user setting.


#5

We seem to have the same problem - running php on the CLI outputs “open /var/log/newrelic/newrelic-daemon.log: permission denied” to stderr when a non-root user. Running a CLI PHP command as root is fine, and the log does get appended to.

SELinux is disabled, and we’re not using suexec.

The /var/log/newrelic/newrelic-daemon.log file is owned by root:root, its permissions are -rw-------. The newrelic-daemon processes are owned by root.

PHP activity triggered by PHP-FPM (multiple pools, running as separate non-root users) is logging to the file.


#6

One possible explanation is that the daemon may not be running on the hosts where you’re getting the /var/log/newrelic/newrelic-daemon.log: permission denied errors. If it’s not running and you run the CLI version of PHP as a non-root user, the process will fork to spawn the daemon, resulting in a non-root daemon.

In the typical use case, the daemon is spawned by PHP-FPM or Apache, both of which start the daemon before they setuid() down to whatever user they’re running as, so the daemon effectively runs as root.

Also worth considering is… why is the daemon going away in the first place? The most likely answer is that the daemon times out after 10 minutes of inactivity, so you might want to run a small cron job (php -i or something else innocuous) every five minutes to keep it alive.


#7

The daemon does appear to be running:

    [root@stone ~]# ps auxw | grep -i newrelic-daemon
    root     51534  0.0  0.1 190360  5000 ?        Ssl  16:30   0:00 /usr/bin/newrelic-daemon --agent --pidfile /var/run/newrelic-daemon.pid --logfile /var/log/newrelic/newrelic-daemon.log --port /tmp/.newrelic.sock --tls --define utilization.detect_aws=true --define utilization.detect_azure=true --define utilization.detect_gcp=true --define utilization.detect_pcf=true --define utilization.detect_docker=true
    root     51538  0.0  0.2 198812  8436 ?        Sl   16:30   0:00 /usr/bin/newrelic-daemon --agent --pidfile /var/run/newrelic-daemon.pid --logfile /var/log/newrelic/newrelic-daemon.log --port /tmp/.newrelic.sock --tls --define utilization.detect_aws=true --define utilization.detect_azure=true --define utilization.detect_gcp=true --define utilization.detect_pcf=true --define utilization.detect_docker=true -no-pidfile

but I still get the message to stderr.

If I stop PHP-FPM, the daemon processes go away, and if I then start PHP-FPM they come back, and I get the same problem immediately, so I suspect the ten minute timeout isn’t involved.

I’ve performed a few experiments and have found that if I have no daemon processes running, then run a PHP CLI command as root, the daemon is started and thereafter, any PHP CLI commands as non-privileged users run without exhibiting the problem. If, however, the daemon was started by PHP-FPM then non-privileged CLI users can’t access it.

This is on a CentOS7 server, and I can replicate this behaviour on a CentOS7 box under vagrant as well. We have NR on several CentOS6 servers and haven’t encountered this problem on those.

It seems that there’s something different when the daemon is invoked by PHP-FPM (compared to when it’s invoked by PHP-CLI as root) that triggers the problem.


#8

Heya @jon-tls, I was just checking in to see if you’d made any progress? This is a tricky issue, and I was unable to make any headway myself. I’ve forwarded this to the PHP Agent Engineering team and I’ll let you know if they have any questions or suggestions for moving forward as soon as I hear back.

Thanks!


#9

Hi Jay,

I’ve not looked any further into it - it seems to be a problem with an out-of-the-box installation of NR, and I’ve reached the end of my skills!

I look forward to hearing back from the Agent team.

Thanks for your help,
Jon


#10

Still working with the Product Team on this one, @jon-tjs! Just wanted to give you a quick update. :blush: In the meantime, please feel free to update us with any progress you make here in this thread!

Thanks! Talk soon.


#11

Hi Jon,

Are you using SELinux by chance? The extra permissions security of SELinux has been known to cause issues with logging.


#12

Have the product team made any further progress with this?

As I said in my original post, we’re not using SELinux.

I’ve since seen the same thing (once) on a CentOS 6 box. the CentOS box we were encountering it in hasn’t had the problem lately as we’ve now launched a website on it, so PHP-FPM seems to keep the daemon that it started alive once there’s activity.


#13

Hi Jon,
Would you mind sending us your Vagrant reproduction of this issue so that our engineers can take a look at it?


#15

Resurrecting a zombie here, my apologies.

For some reason, this problem goes away for me after I restart the newrelic daemon once by killing it and then restarting apache.

I’m having this problem on CentOS 7 after switching to a full attribute-based configuration with the NewRelic chef recipe. I think that the problem is that I’m installing and configuring the newrelic daemon before Apache is properly configured, and then subsequent restarts of apache during the chef run don’t restart the daemon, leading to the observation of this problem.

Some console logs to illustrate the problem:

[andrew.bobulsky@ip-172-17-6-204 ~] :) php file.php 
open /var/log/newrelic/newrelic-daemon.log: permission denied
hello there
[andrew.bobulsky@ip-172-17-6-204 ~] :) ps aux | grep relic
root     10355  0.0  0.0  48732  2672 ?        Ssl  Nov06   0:00 /usr/bin/newrelic-daemon --agent --pidfile /var/run/newrelic-daemon.pid --logfile /var/log/newrelic/newrelic-daemon.log --port /tmp/.newrelic.sock --tls --define utilization.detect_aws=true --define utilization.detect_azure=true --define utilization.detect_gcp=true --define utilization.detect_pcf=true --define utilization.detect_docker=true
root     10360  0.0  0.0 211468  3176 ?        Sl   Nov06   0:00 /usr/bin/newrelic-daemon --agent --pidfile /var/run/newrelic-daemon.pid --logfile /var/log/newrelic/newrelic-daemon.log --port /tmp/.newrelic.sock --tls --define utilization.detect_aws=true --define utilization.detect_azure=true --define utilization.detect_gcp=true --define utilization.detect_pcf=true --define utilization.detect_docker=true -no-pidfile
newrelic 11990  0.0  0.0  16948   524 ?        Ss   Nov06   0:00 /usr/sbin/nrsysmond -c /etc/newrelic/nrsysmond.cfg -p /var/run/newrelic/nrsysmond.pid
newrelic 11991  0.0  0.1 262284  5836 ?        Sl   Nov06   0:59 /usr/sbin/nrsysmond -c /etc/newrelic/nrsysmond.cfg -p /var/run/newrelic/nrsysmond.pid
andrew.+ 28463  0.0  0.0 112708   972 pts/1    S+   14:55   0:00 grep --color=auto relic
[andrew.bobulsky@ip-172-17-6-204 ~] :) sudo killall newrelic-daemon
[andrew.bobulsky@ip-172-17-6-204 ~] :) php file.php 
open /var/log/newrelic/newrelic-daemon.log: permission denied
hello there
[andrew.bobulsky@ip-172-17-6-204 ~] :) ps aux | grep relic
newrelic 11990  0.0  0.0  16948   524 ?        Ss   Nov06   0:00 /usr/sbin/nrsysmond -c /etc/newrelic/nrsysmond.cfg -p /var/run/newrelic/nrsysmond.pid
newrelic 11991  0.0  0.1 262284  5836 ?        Sl   Nov06   0:59 /usr/sbin/nrsysmond -c /etc/newrelic/nrsysmond.cfg -p /var/run/newrelic/nrsysmond.pid
andrew.+ 28480  0.0  0.0 112708   968 pts/1    S+   14:55   0:00 grep --color=auto relic
[andrew.bobulsky@ip-172-17-6-204 ~] :) sudo service httpd restart
Redirecting to /bin/systemctl restart httpd.service
[andrew.bobulsky@ip-172-17-6-204 ~] :) ps aux | grep relic
newrelic 11990  0.0  0.0  16948   524 ?        Ss   Nov06   0:00 /usr/sbin/nrsysmond -c /etc/newrelic/nrsysmond.cfg -p /var/run/newrelic/nrsysmond.pid
newrelic 11991  0.0  0.1 262284  5836 ?        Sl   Nov06   0:59 /usr/sbin/nrsysmond -c /etc/newrelic/nrsysmond.cfg -p /var/run/newrelic/nrsysmond.pid
root     28512  0.0  0.1 114268  5000 ?        Ssl  14:55   0:00 /usr/bin/newrelic-daemon --agent --pidfile /var/run/newrelic-daemon.pid --logfile /var/log/newrelic/newrelic-daemon.log --port @newrelic-daemon --tls --define utilization.detect_aws=true --define utilization.detect_azure=true --define utilization.detect_gcp=true --define utilization.detect_pcf=true --define utilization.detect_docker=true
root     28528  0.0  0.1 198916  5644 ?        Sl   14:55   0:00 /usr/bin/newrelic-daemon --agent --pidfile /var/run/newrelic-daemon.pid --logfile /var/log/newrelic/newrelic-daemon.log --port @newrelic-daemon --tls --define utilization.detect_aws=true --define utilization.detect_azure=true --define utilization.detect_gcp=true --define utilization.detect_pcf=true --define utilization.detect_docker=true -no-pidfile
andrew.+ 28549  0.0  0.0 112708   972 pts/1    S+   14:55   0:00 grep --color=auto relic
[andrew.bobulsky@ip-172-17-6-204 ~] :) php file.php 
hello there

I’ll post again once I resolve this problem


#16

I really hate to say this, but I fixed it and I don’t have a satisfactory explanation as to why it’s working now.

I use the newrelic chef recipe to install and configure the agent. I configure the agent through attributes, install it by including the chef recipe, and then open up the permissions on the log file slightly (which shouldn’t be making a difference).

# Install newrelic daemon
include_recipe 'newrelic::server_monitor_agent'
include_recipe 'newrelic::php_agent'

file '/var/log/newrelic/newrelic-daemon.log' do
  owner 'root'
  group 'newrelic'
  mode '0664'
end

It could be the result of setting this attribute:

default['newrelic']['application_monitoring']['daemon']['port'] = "@newrelic-daemon"

…but I’m not 100% sure. The behavior is really strange and I don’t have time to troubleshoot further. I hope this was helpful.


#17

Hi @andrew.bobulsky,

Thanks for sharing with us what you’ve found! For sure puzzling that you ran into this issue, but uncertain what exactly resolved the behavior.

I did some digging around, it doesn’t look like we’ve seen this exact issue come up since then, so I’m unable give more insight as to what might have caused this. If we notice anything that points to the root cause of this, I will be sure to update this thread.

Thanks again for sharing your findings with this!