記一次 Laravel MethodNotAllowedHttpException 問題排查

Yusure發表於2019-05-17
LaravelHTTPException

問題描述

線上一個 laravel 4.2 的專案有 Exception 產生，通過檢視 log 發現每天會有 2 條左右出現，量也不大，通過日誌能看出是 MethodNotAllowedHttpException 異常，下面記錄一下解決過程。

[2019-05-17 06:04:38] Oregon.ERROR: Symfony\Component\HttpKernel\Exception\MethodNotAllowedHttpException in /******/endpoint/bootstrap/compiled.php:5753
Stack trace:
#0 /******/endpoint/bootstrap/compiled.php(5749): Illuminate\Routing\RouteCollection->methodNotAllowed(Array)
#1 /******/endpoint/bootstrap/compiled.php(5727): Illuminate\Routing\RouteCollection->getOtherMethodsRoute(Object(Illuminate\Http\Request), Array)
#2 /******/endpoint/bootstrap/compiled.php(5051): Illuminate\Routing\RouteCollection->match(Object(Illuminate\Http\Request))
#3 /******/endpoint/bootstrap/compiled.php(5039): Illuminate\Routing\Router->findRoute(Object(Illuminate\Http\Request))
#4 /******/endpoint/bootstrap/compiled.php(5031): Illuminate\Routing\Router->dispatchToRoute(Object(Illuminate\Http\Request))
#5 /******/endpoint/bootstrap/compiled.php(720): Illuminate\Routing\Router->dispatch(Object(Illuminate\Http\Request))
#6 /******/endpoint/bootstrap/compiled.php(696): Illuminate\Foundation\Application->dispatch(Object(Illuminate\Http\Request))
#7 /******/endpoint/bootstrap/compiled.php(7803): Illuminate\Foundation\Application->handle(Object(Illuminate\Http\Request), 1, true)
#8 /******/endpoint/bootstrap/compiled.php(8410): Illuminate\Session\Middleware->handle(Object(Illuminate\Http\Request), 1, true)
#9 /******/endpoint/bootstrap/compiled.php(8357): Illuminate\Cookie\Queue->handle(Object(Illuminate\Http\Request), 1, true)
#10 /******/endpoint/bootstrap/compiled.php(11154): Illuminate\Cookie\Guard->handle(Object(Illuminate\Http\Request), 1, true)
#11 /******/endpoint/bootstrap/compiled.php(657): Stack\StackedHttpKernel->handle(Object(Illuminate\Http\Request))
#12 /******/endpoint/public/index.php(48): Illuminate\Foundation\Application->run()
#13 {main} [] []

排查過程

　　通過查詢 nginx access log 找到對應的資訊，是 post 請求 index.php，我用 postMan 來進行模擬並沒有復現這個 exception，我拿到的只是一個 200 的 Response，並不是 500，這應該是掃描器批量掃描的，或者是 spider 爬的，並沒有走域名，而是從 ip 直接訪問。

**.93.2.** **.71.95.** 182.61.178.228 - "17/May/2019:06:04:39 +0800" "POST /index.php HTTP/1.1" 453 4534 0.680 500 unix:/tmp/php-cgi-72.sock - 0.004 "Mozilla/5.0 (Windows NT 6.1; Win64; x64; rv:28.0) Gecko/20100101 Firefox/28.0"

查詢 nginx error log 沒有對應的 log，問題到這裡就僵住了，返回去看 exception log 找到丟擲異常之前最後一個執行的方法 

Illuminate\Routing\RouteCollection->getOtherMethodsRoute

/* 程式碼路徑 */
/vendor/laravel/framework/src/Illuminate/Routing/RouteCollection.php  :186
    /**
     * Get a route (if necessary) that responds when other available methods are present.
     *
     * @param  \Illuminate\Http\Request  $request
     * @param  array  $others
     * @return \Illuminate\Routing\Route
     *
     * @throws \Symfony\Component\Routing\Exception\MethodNotAllowedHttpException
     */
    protected function getOtherMethodsRoute($request, array $others)
    {
        if ($request->method() == 'OPTIONS')
        {
            return (new Route('OPTIONS', $request->path(), function() use ($others)
            {
                return new Response('', 200, array('Allow' => implode(',', $others)));

            }))->bind($request);
        }

        $this->methodNotAllowed($others);
    }

　　看到這就大體明白了，如果 method 是 OPTIONS 會有 200 的正常 Response，否則就丟擲錯誤，猜測 Http method 肯定是一個比較冷門的，導致框架報錯，從 postMan 找一個比較冷門的 method UNLOCK 試了一下，果然狀態 500，成功復現。

　　這裡有一段小插曲：為什麼狀態是 500 呢，應該是 405 才對，檢視程式碼發現處理 error 的邏輯裡面呼叫了一個已經優化掉的日誌類，去掉那一行呼叫，一切正常。

正常的 405 報錯：

解決方案

/app/start/global.php 增加異常處理程式碼

App::error( function( Symfony\Component\HttpKernel\Exception\MethodNotAllowedHttpException $exception, $code)
{
    Log::debug( 'MethodNotAllowedHttpException: ' . Request::method() );
    return ['code' => $code, 'message' => 'MethodNotAllowedHttpException'];
});

加上這段程式碼之後就會捕獲這個異常，直接 return 即可，這樣就不會有 exception 產生了。到這裡框架層面的問題已經解決了，但是 Nginx 為什麼是 POST 請求，到底是個什麼請求導致了報錯，這個有必要去研究一下，於是在 Closure 裡面加一行 Log 程式碼記錄一下 method 到底是什麼東西。

提交程式碼，上線觀察，未完待續……
2019年5月17日17:36:20

相關文章