How to trace call to output buffer

Question

So the scenario is that I have an application that uses output buffering, and the application is returning some extra data in addition to the expected results. I can manipulate the point where the expected results are being added to the output buffer to confirm that at this point in the application, the data being sent to the output buffer is correct, thus the unexpected extra data must be coming from another source.

I suspect that the issue is a stray character that is not inside the PHP script tags, but I'm having no luck figuring out which (if any) files is the culprit. For all I know, there could be some file that is being included that is actually doing an explicit echo of the extra data.

So I was hoping to capture the filename and line number of any file that writes to the output buffer, but this is proving much more difficult than I expected. I know where the initial ob_start is, so I've been trying to use a custom output_callback. Here are a few things I've tried already:

ob_start(function($string) { 
    return __FILE__ . ":" . __LINE__ . " : " $string; 
});

This returns the filename and line number where the function is defined, not where it was called from (as expected, I guess, but off to a bad start).

ob_start(function($string) { 
    return print_r(debug_print_backtrace(), true) . " : " $string; 
});

This throws an error about destroying a lambda function.

ob_start(function($string) { 
    return var_dump(debug_backtrace()) . " : " $string; 
});

This had mixed results. I will admit I'm not totally sure why. But in most cases the var_dump resolved to an empty string (nothing), but in one case, it seemed to generate some trace array, but didn't have anything reflecting the origin of the ob_start call (in other words, whatever it output, the source file that actually called the echo wasn't part of the trace).

Keep in mind that with the above, I have been doing some pretty basic testing just to figure out what the custom output_callback function would look like for when I'm ready to drop it into a troubleshooting context. So the issue isn't application-specific, I'm just trying to find a generic way to intercept output functions (echo, print, etc) and get information on where that output call originated.

There seems to be missing a `.` in your code examples, in this piece: `" : " $string;` — Luuk, May 06 '23 at 07:10

Kamal Soni · Answer 1 · 2017-12-19T04:14:29.443

2

Possible Solutions

1

If you your code is using output buffering to spit out that stray character, the below solution can help. You are also right, that it will only work when the output buffering is flushed/retrieved, not at every print/echo statement. Also, all the native functions do not work in the call back function and print_r is one of them, but we can throw Exception. Please try the below code and see if it helps you in resolving your issue.

ob_start(function($buffer) {
    try {
        $stackTrace = debug_print_backtrace();
        throw new \Exception($stackTrace, 1);
    } catch (\Exception $ex) {
        //This line can be logged to a file instead of appending to the buffer
        $buffer .= PHP_EOL.$ex->getTraceAsString().PHP_EOL.PHP_EOL;
    }
    return $buffer;
});

2

If the first solution does not help resolve your issue, you might want to use advanced debugging and profiling tools like Xdebug

3

If you really don't care about the content that is already being echoed out before the current line or if you want to future proof that the similar issue does not happen in future you can just flush out the buffer using ob_end_clean before your ob_start.

ob_end_clean();
ob_start();

4

Finding all PHP white space after closing tag:

pcregrep -rMl '\?>[\s\n]+\z' *

OR

pcregrep -rM '\?>[\s]+[^\S]*$' *.php

edited Dec 19 '17 at 04:14

answered Dec 14 '17 at 03:35

Kamal Soni

1,522
13
15

I don't think this will work as a troubleshooting tool, for 1) it won't point to which files are contributing to the output (thus not allowing us to have better clarity on where that output is coming from), and 2) in your example, it assumes that the fudgey output occurs before `ob_start`, which is not necessarily the case. A custom extension may contribute to the output within the scope of the proper `ob_start` content, but simply have an error or be outputting at times when it shouldn't. The goal is to determine where any potential output is originating. – Anthony Dec 14 '17 at 07:48
Doing more testing, I now get that the custom `ob_callback` function is called when the output buffer is flushed/retrieved, not every time it is written to, which is how I understood it. Is there any way to trigger a callback whenever the output buffer is updated? – Anthony Dec 14 '17 at 21:23
Would it be possible (or advisable) to override the `php://output` stream so that it functions as usual but also sends a timestamp or some other identifier to the error log that can then be reconciled against a trace file? – Anthony Dec 14 '17 at 21:31
1

Hi @Anthony I have updated my answer based on your comments. – Kamal Soni Dec 15 '17 at 00:13
Hi @Anthony Did the first option helped you in any ways? – Kamal Soni Dec 17 '17 at 23:37
Thanks for checking in. No! I'm not having any luck. And now I am trying to troubleshoot the problem directly. Even with XDebug doing a trace on every request, I can't narrow down where the stray newline is coming from. Clearing the buffer and restarting `ob_start` works, but unfortunately isn't an option for a production instance, so I'm kind of stuck. – Anthony Dec 18 '17 at 16:26
@Anthony good to know. I had similar problem like having a space or newline after php end tag ?> for a random php file which does not get interpreted by the PHP file and it gets echoed out. It looks like you might have similar problem. Try looking for that file using option four in my updated answer. – Kamal Soni Dec 19 '17 at 04:14
I actually found it soon after I posted that comment, but pretty much from luck, not from any tool or callback function. It was a file that has *two* extra newlines after the closing tag, whereas others I'd spotted had either no closing tag or at most one stray newline. I'm baffled but relived I stumbled on it and decided to see if changing it made a difference. But it would be great if there was a reliable way to determine where any given bit of output (to the browser or buffer) originated. This was maddening before I got lucky. – Anthony Dec 19 '17 at 04:20
@Anthony Yes, it took if some time myself when it happened to me. No closing is not an issue because then PHP disregards the white space. It looks like I won't be of much help to you, but I hope my answer might be helpful to others who might have not gone as further as yourself. All the best. – Kamal Soni Dec 19 '17 at 04:38

score 1 · Answer 2 · answered May 06 '23 at 06:40

Use step-through debugging in PhpStorm and enter ob_get_contents() in the PhpStorm console to see if anything is in the output. Use a "binary search" pattern, testing around the halfway point of your "main" function, etc. Then repeat the process inside any function called from "main" that produces that output, until you find it.

Only took me 10-15 minutes to find the offending line this way, after wasting much more time before.

How to trace call to output buffer

2 Answers2