Probably, almost all the inhabitants of Habr know what a dichotomy is and how to catch a lion in the desert with its help. Errors in the programs can also be caught by the dichotomy, especially in the absence of imputed diagnostic information.
Once debugging my PHP / Laravel project, I saw this error in the browser:
This was at least strange, because, judging from the description in RFC 2616, the error 502 means that “The server, acting as a gateway or proxy, received an incorrect response from the upstream server”. In my case, there were no gateways, there was no proxy between the Web server and the browser, the Web server was a nginx operating under the virtualbox and issuing the Web content directly, without any intermediaries. The nginx logs had this:
2018/06/20 13:42:41 [error] 2791#2791: *2206 recv() failed (104: Connection reset by peer) while reading response header from upstream, client: 192.168.10.1, server: colg.test, request: "GET / HTTP/1.1", upstream: "fastcgi://unix:/var/run/php/php7.1-fpm.sock:", host: "colg.test"
The words “upstream server” in the description of the 502 errors (“upstream server” in the RFC original in English) suggested some additional network servers in the path of the request from the browser to nginx, but, apparently, in this case, mentioned in the message PHP-FPM module, being a server program, acts as this upstream server. The PHP logs had this:
[20-Jun-2018 13:42:41] WARNING: [pool www] child 26098 exited on signal 11 (SIGSEGV - core dumped) after 102247.908379 seconds from start
Now it was clear where the problem arises, but its cause was unclear. PHP just dropped out in the core dump, not displaying any information about the moment when the PHP program was interpreted, an error occurred. So it's time to catch a lion in the desert - use my favorite in such cases, the method of debugging dichotomy. Anticipating objections in the comments, I would note that a debugger could be used here, for example, the same XDebug, but the dichotomy was more interesting. In addition, the queue will continue to XDebug.
So, on the way to processing the Web request, I put the simplest diagnostic output, with the program terminating further, to make sure that no error occurs before its installation:
echo “I am here”; die();
Now the bad page looked like this:
Putting the above command first to the beginning and then to the end of the path of processing the Web request, I found out that the error (who would doubt!) Arises somewhere between these two points. By installing the diagnostics at about the middle of the Web request path, I learned that the error appears somewhere near the end. After a couple of such iterations, I realized that the error does not occur in the Laravel controller's MVC architecture, but already at the output from it, when rendering the view, which is the simplest here, in this spirit:
@extends('layouts.app') @section('content') <div> <div class="panel-heading">Myservice</div> <div class="panel-body"></div> </div> @endsection
As you can see, the PHP code does not contain the view template (the Laravel template engine allows using the PHP code in the view), and the problems are definitely not here. But above, we see that this view inherits the template layouts.app, so we look there. There it is already more difficult: there are navigation elements, login forms, and other things common to all pages of the service. Dropping everything that is there, I will give only a line, because of which there was a failure, it was found all the same dichotomy. Here is this line:
<script> window.bkConst = {!! (new App\Src\Helpers\UtilsHelper())->loadBackendConstantsAsJSData() !!}; </script>
This is where PHP was used in the view template code. It was my “charm” - output of backend constants, in the form of a JS code, for use on the frontend, in the name of the DRY principle. The loadBackendConstantsAsJSData method listed several classes with the necessary constants on the frontend. The error also occurred in the addClassConstants method used by it, where PHP introspection was used to obtain the list of class constants:
private function addClassConstants(string $classFullName, array &$constantsArray) { $r = new ReflectionClass($classFullName); $result = []; $className = $r->getShortName(); $classConstants = $r->getConstants(); foreach($classConstants as $name => $value) { if (is_array($value) || is_object($value)) { continue; } $result["$className::$name"] = $value; } $constantsArray = array_merge($constantsArray, $result); }
After searching among the classes with constants passed to this method, it turned out that the reason for everything is this class with constants - the paths to the REST API methods.
class APIPath { const API_BASE_PATH = '/api/v1'; const DATA_API = self::API_BASE_PATH . "/data"; ... const DATA_ADDITIONAL_API = DATA_API . "/additional"; }
There are quite a few lines in it, and the dichotomy again came in handy to find the right one. Now, I hope everyone noticed that in the definition of a constant self :: is omitted before the name of the constant DATA_API. After adding it to its rightful place, everything worked.
Having decided that the problem is in the mechanism of introspection, I began to write a minimal example for the reproduction of the bug:
class SomeConstants { const SOME_CONSTANT = SOME_NONSENSE; } $r = new \ReflectionClass(SomeConstants::class); $r->getConstants();
However, at the start of this script, PHP was not going to fall, but issued a completely sane warning.
PHP Warning: Use of undefined constant SOME_NONSENSE - assumed 'SOME_NONSENSE' (this will throw an Error in a future version of PHP) in /home/vagrant/code/colg/_tmp/1.php on line 17At this point, I was already convinced that the problem manifests itself not only when the site is loaded, but also when executing the code written above via the command line. The only difference between the runtime and the minimal script was the presence of the Laravel context: the problem code was run through its artisan utility. So, under Laravel there was some difference. To understand what it is, it's time to use the debugger. Running the code under xdebug, I saw that the crash occurs after calling the ReflectionClass :: getConstants method, in the Illuminate \ Foundation \ Bootstrap \ HandleExceptions :: handleError method, which looks very simple:
public function handleError($level, $message, $file = '', $line = 0, $context = []) { if (error_reporting() & $level) { throw new ErrorException($message, 0, $level, $file, $line); } }
The execution flow got there after throwing an exception because of the very error describing the constant that started it all, and PHP crashed when trying to throw an ErrorException exception. An exception in the exception handler ... I immediately remembered the famous
Double fault . So, to call a failure, you need to install exception handlers in the same way as Laravel's. Just above the code was the bootstrap method, which did this:
Now the final minimal example looked like this:
<?php class SomeConstants { const SOME_CONSTANT = SOME_NONSENSE; } function handleError() { throw new ErrorException(); } set_error_handler('handleError'); set_exception_handler('handleError'); $r = new \ReflectionClass(SomeConstants::class); $r->getConstants();
and its launch was stably stacked with the PHP version 7.2.4 interpreter in the core dump.
It seems that here there is an infinite recursion - when processing an exception from the initial error in handleException, the next exception is thrown, processed again in handleException, and so on to infinity. Moreover, to reproduce the failure, you need to set both error_handler and exception_handler, if only one of them is installed, then the problem does not manifest itself. It also didn’t work out just to throw an exception, instead of generating an error, it seems that there’s not an ordinary recursion, but something like a circular dependency.
After that, I checked the existence of the problem under different versions of PHP (thanks, Docker!). It turned out that the failure only appears since PHP 7.1, earlier versions of PHP work correctly - swear at the uncaught ErrorException exception.
What conclusions can be drawn from all this?
- Debugging with a dichotomy, although it is an antediluvian method of debugging, but sometimes it may be necessary, especially in the conditions of a lack of diagnostic information.
- In my opinion, a 502 error is unintelligible, both the message about it (“Bad gateway”) and its decryption in the RFC about the “wrong answer from the upstream server”. Although, if we assume that modules connected to a Web server are server programs, then the meaning of decoding an error in the RFC can be understood. However, let's say the same PHP-FPM in the documentation is called a module and not a server.
- Static analyzer - taxis, he would immediately report an error in the description of the constant. But then the bug would not have been caught.
At this let me finish, thank you all for your attention!
Bugreport -
sent .
UPD: bug
fixed . Judging by the code, it still appeared in the reflection mechanism - in error handling of the ReflectionClass :: getConstants method