Tracking down headers already sent error

Bonesnap

When I updated my company's quote form I was also instructed to setup a cron job with our host to query the database and gather any data for the people that didn't complete the quote process. It's a three step process and people usually bail when they are asked for an approximate budget (final step). Always kinda made me chuckle.

Anyway, I have a PHP file that is run by the cron job. It simply queries the database, pulls any quotes that match the criteria (a couple flags are set during the process) and then packages up everything and emails it to my manager. It's been in place since early July and works - he receives the emails and is quite pleased with the whole process.

Yesterday we noticed the Instagram feed on our site stopped working abruptly, so I was tasked with looking into fixing it. When I logged into the FTP I noticed our PHP error log had quite a few entries. In fact it was huge, at over 100MB. I pulled it down and noticed many of the errors were due to the Instagram feed, but also over half of them were being caused by 'headers already sent' regarding when a session starts. At first I thought it was related to our small admin area since the person who developed it put the require() to the config.php file under the doctype...

Upon further inspection though I noticed that the timestamps of the errors matched up exactly with our cron job's schedule, so I took a look at that. But I am unable to figure out what is causing the warning. The very first line in the config.php file is the opening <?php tag, and the immediate next line is the session_start() call. This file does include a bunch of other files that do in fact create output, but that's much further down the file.

The file that is being run by the cron job has the opening <?php tag, a bunch of multiline comments explaining what it does, and then a require_once() to the config.php file. The rest is just querying the database, packaging it all up into an email, and sending it off. This of course all happens after the session starts.

I looked into BOM. According to some random answers on the PhpStorm forums, PhpStorm does not add a BOM to files, but also does not remove them if they were already there. I found a keybinding to remove a BOM, so I used it on the files and reuploaded them, but still have the issue. The files are encoded in UTF-8.

Below is what is being logged:

[18-Aug-2015 09:30:00 America/Toronto] PHP Warning:  session_start(): Cannot send session cookie - headers already sent in [WEBSITE]/config.php on line 2
[18-Aug-2015 09:30:00 America/Toronto] PHP Warning:  session_start(): Cannot send session cache limiter - headers already sent in [WEBSITE]/config.php on line 2

It should be noted that this warning does not appear during normal operation of the website (clicking around, accessing pages, etc.), and no other entries are in the error log.

Any ideas? Anything obscure that may be causing this or something I have overlooked?

Thanks!

NogDog

Ultimately, I think the issue here is that sessions make no real sense in a CLI use of PHP (which is what cron is doing). If this code needs to support use via cron as well as via the web, you might need to test whether it's CLI or not before calling session_start(): http://php.net/php_sapi_name (and test for "cli", most likely, but see the discussion there).

cretaceous

Yes - that's what I was thinking - why would you need session in cron?
Nothing can persist.
(as the Buddah observed)

dalecosp

I'd concur that this looks like the source of the problem, at least on the surface.

Not sure of your setup, but you might be able to do something like this in config.php:

if ( php_sapi_name() !="cli" ) { 
   session_start();       //only use sessions with web clients
}

sneakyimp

You could start by giving us the actual cron job command.

My guess is that you are invoking the PHP script via cron/cli and you get some kind of E_WARNING or E_NOTICE and this is what causes the output to be sent before you call session start. You could try running the exact cron command via cli yourself and see if you get any errors. Or you could change the cron job to route its output into some output file:

0 0 * * *  /path/to/some/php/script.php > /path/to/some/output/file.txt

Then look in the output file and see if you have any error messages.

You could also try directing both stdout and stderr to the output file with something like this I think:

0 0 * * *  /path/to/some/php/script.php > /path/to/some/output/file.txt 2>&1

Bonesnap

Thanks for the replies, guys! For now my manager has told me to put it on the backburner because of too many deadlines. Sigh...

cretaceous;11050193 wrote:
Yes - that's what I was thinking - why would you need session in cron?
Nothing can persist.
(as the Buddah observed)

I don't, I was including it because it contains the database credentials. I wasn't really involved in the beginning of the site (at least in that area) so I didn't really come up with the "architecture" of how the config files were put together. I would have done it differently, that's for sure. But honestly I didn't think anything of it. I wasn't aware it mattered.

sneakyimp;11050205 wrote:
You could start by giving us the actual cron job command.

I don't have that otherwise I would have. The cron job is created via a support ticket that's submitted to the host.

sneakyimp;11050205 wrote:
My guess is that you are invoking the PHP script via cron/cli and you get some kind of E_WARNING or E_NOTICE and this is what causes the output to be sent before you call session start. You could try running the exact cron command via cli yourself and see if you get any errors. Or you could change the cron job to route its output into some output file:
0 0 * * *  /path/to/some/php/script.php > /path/to/some/output/file.txt
Then look in the output file and see if you have any error messages.

You could also try directing both stdout and stderr to the output file with something like this I think:
0 0 * * *  /path/to/some/php/script.php > /path/to/some/output/file.txt 2>&1

I was told by the support tech at the host that the cron job is using the same error log as the site so if there were any warnings or notices it should have recorded them, no? I didn't see any. Also I do not have access to anything like a command line in the control panel, unless you mean something else (but also I don't have the actual command).

sneakyimp

the support tech at the host sounds a little suspect to me. Ask him/her for the actual cron command and try running it yourself. Or ask the tech for the script's stdout and stderr. This sort of bureaucracy and the inability to go and just look yourself is a really good argument in favor of using digital ocean or something like that. If you have root access to the server, you can do all this yourself without relying on some tech support burnout to get your important work done.

EDIT: I apologize for this rantish statement. Some tech support guys are really good. Others, not so much. I was, perhaps wrongly, imagining the guy to be using CPanel or WHM and just pasting commands into a browser.

Some things to note about cli/cron:
cli/cron jobs may run as some entirely different user than your-user or www-data and may not have necessary permissions
cli/cron jobs do not inherit the same working directory as scripts run via apache. A simple include command may trigger an E_WARNING unless you specify the entire absolute path from the root to the file. E.g.:

include "config.php"; // this may run fine via apache but throw E_WARNING via cron job. maybe try require instead and see if that changes anything?

cli/cron jobs, because they run as a different user, may not have permissions to write certain log files
cli/cron jobs may run with an entirely different PHP.ini, may write to a different error log, might even have certain php modules disabled

But anyway, it's on hold now.

sneakyimp

Also, a quick search yielded this helpful info:

If you want to obtain the filename and line-number where the output started, you can call the headers_sent() function with two optional parameters:
$sent = headers_sent($file, $line);
Those two variables $file and $line will contain the information you're looking for after the function has been invoked. You don't need to wait for the error message (but you might need to flush output (at many places) if you don't see any error message and you want to pinpoint the origin). So ensure that output buffering is disabled.

You might try slipping that into your cron script right before the session_start call and writing/emailing some kind of message so you can go check it out. If you insist on using error_log, then it would also be a good test of the tech support's assertion that both apache and this cron job write to the same error log.

You could also try using file_put_contents instead of error_log, but you would need to make sure that the target file is writable by your cron user, whoever that is.

Bonesnap

sneakyimp;11050215 wrote:
the support tech at the host sounds a little suspect to me. Ask him/her for the actual cron command and try running it yourself. Or ask the tech for the script's stdout and stderr. This sort of bureaucracy and the inability to go and just look yourself is a really good argument in favor of using digital ocean or something like that. If you have root access to the server, you can do all this yourself without relying on some tech support burnout to get your important work done.

EDIT: I apologize for this rantish statement. Some tech support guys are really good. Others, not so much. I was, perhaps wrongly, imagining the guy to be using CPanel or WHM and just pasting commands into a browser.

No need to apologize, I hear ya :p

We have dealt with the tech support guy quite a bit in the past and he's really helped us (even broke a company policy or two for us). I can't speak for his technical knowledge, but I don't think he would (intentionally, anyway) tell me incorrectly about the cron job. We know it runs since we are receiving the emails and it's updating the database, etc. Also this is the company's website. I have zero control or influence on where/how it is hosted (on a side note I am probably going to sign up with Digital Ocean this weekend to play around with). My manager hands me the credentials on a folded piece of paper to log in, once I am done whatever I am doing, he expects me to hand it back. If he is in the vicinity and what I am working on is a quick change, he'll hover while it's being done, and make sure everything is cleared before leaving (and taking the paper).

sneakyimp;11050215 wrote:
Some things to note about cli/cron:
cli/cron jobs may run as some entirely different user than your-user or www-data and may not have necessary permissions
cli/cron jobs do not inherit the same working directory as scripts run via apache. A simple include command may trigger an E_WARNING unless you specify the entire absolute path from the root to the file. E.g.:
include "config.php"; // this may run fine via apache but throw E_WARNING via cron job. maybe try require instead and see if that changes anything?
cli/cron jobs, because they run as a different user, may not have permissions to write certain log files
cli/cron jobs may run with an entirely different PHP.ini, may write to a different error log, might even have certain php modules disabled

But anyway, it's on hold now.

I can verify that the path to the file is using the absolute file path and not a simple require (I am using require). I will admit I made this mistake very early on when I was developing it, so I can confirm that is not the case. I can't say much about the user, permissions, or .ini file, but the cron job is running and we are receiving the emails and the database is being updated. I have to assume for now that is all set up and working correctly.

sneakyimp;11050217 wrote:
Also, a quick search yielded this helpful info:

You might try slipping that into your cron script right before the session_start call and writing/emailing some kind of message so you can go check it out. If you insist on using error_log, then it would also be a good test of the tech support's assertion that both apache and this cron job write to the same error log.

You could also try using file_put_contents instead of error_log, but you would need to make sure that the target file is writable by your cron user, whoever that is.

Thanks for taking a look into this. I didn't know about headers_sent(). Whenever my workload is not quite so much (ha!) I'll inquire to my manager again about getting in there to fix it. Knowing the error log is filling up every day needlessly irritates me.

Also wouldn't the fact that the error log is being written to at the exact schedule of the cron job indicate that it's using the same log as Apache?

sneakyimp

If your script is running and doing it's job, I suppose that is a good indication.

You should not be calling session_start in a cron job script. As dalecosp suggested, you probably want to check if the file is being run via CLI before doing that. Or separate out your db credentials from your environment configuration stuff.

You could always try to write a log message or send yourself an email. Maybe change that session_start call to something like this:

$file = NULL;
$line = NULL;
if (headers_sent($file, $line)) {
  $msg = "DAMMIT cannot session_start because output already started in $file on line $line";
  // email this message to yourself or write it to the log file
} else {
  session_start();
}

You might get a flood of info but it would probably tell you where the problem is.

Bonesnap wrote:
Also wouldn't the fact that the error log is being written to at the exact schedule of the cron job indicate that it's using the same log as Apache?

Possibly. Or perhaps some magic visitor is showing up at exactly the time your cron goes off to request some page that writes a message to the log file that is confusing you? It should be clear that determining if cron jobs and apache are writing the same log file would require you to verify this yourself with some clever test. I hope you have the imagination to figure it out as I'm not especially useful this morning.

The reason I asked about how the cron job was set up is because a lot of hackish tech support guys tend to set up cron jobs to run a php script by simply getting cron to request the cron script from the web server. E.g.:

// this creates an http request and contacts your web server.
curl http://example.com/paith/to/cron-script.php
// so does this 
wget  http://example.com/paith/to/cron-script.php

I would say that you shouldn't be running any cron jobs this way. It's...untidy and consumes unnecessary resources. That said, I've done it myself to resolve difficulties with path and environment issues.

If that is how your cron job is set up, then having your doctype declaration before your session_start call is going to cause this error to happen at almost the exact moment that your cron job runs every time. This might just be that magic visitor.

At any rate, if you are getting 'headers already sent' when trying to call session_start it is usually because you have text output already sent which could be caused by:
outputting doctype declaration somewhere before session_start call
BOM at the beginning of the file. You might be able to examine your files using a command line utility like xxd to check for this
white space before opening PHP tag or after closing PHP tag in your script or more likely some included script (use headers_sent($file, $line) to find out where this might have happened).
poor code organization where you echo, var_dump, print, write to stdout in any way or fashion before you call session_start.

EDIT: and I hope it's painfully obvious that session_start is never, ever going to work if you have already sent output (such as your doctype) first. You should fix this problem or forget about calling session_start.