記一次 Laravel MethodNotAllowedHttpException 問題排查

Yusure發表於2019-05-17

問題描述

線上一個 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

相關文章