custom request execute twice if all the rules success passed, with laravel v5.8.26 + dingo v2.2.4 or v2.3.0

[plhwin]

• Laravel Version: v5.8.26
• PHP Version: 7.1.21
• Database Driver & Version: MySQL & 5.7.23

Description:

A custom request class in Laravel will validate before entering a controller action, but all methods in the custom request will be executed twice if all the verification rules are passed.

if some rules got error, executed only once.

this is a bug caused by dingo/api, v2.2.3 is work. v2.2.4 and v2.3.0 are all meet this bug.

refer link:
laravel/framework#28972

Steps To Reproduce:

Example Controller

<?php

namespace App\Http\Controllers\Api\V1;

use App\Http\Requests\Api\V1\TestRequest;
use Illuminate\Support\Facades\Log;


class AdminOrdersController extends \App\Http\Controllers\Controller
{

    public function cancel(TestRequest $request)
    {
        Log::info("test3:".time());
    }

}

Example Custom Request:

<?php

namespace App\Http\Requests\Api\V1;

use Illuminate\Foundation\Http\FormRequest;
use Illuminate\Support\Facades\Log;

class TestRequest extends FormRequest
{
    /**
     * Determine if the user is authorized to make this request.
     *
     * @return bool
     */
    public function authorize()
    {
        Log::info("test1:".time());
        return true;
    }

    /**
     * Get the validation rules that apply to the request.
     *
     * @return array
     */
    public function rules()
    {
        return [
            'orderNo' => [
                'required', 'integer',
                'exists:orders,order_no',
                function ($attr, $value, $fail) {
                    Log::info("test2:".time());
                }
            ],
        ];
    }
}

for the example code above, if all the verification rules passed, logs like below:

[2019-06-27 13:01:58] local.INFO: test1:1561611718  
[2019-06-27 13:01:58] local.INFO: [SQL] select count(*) as aggregate from `orders` where `order_no` = ? ["5614450133994844"] 
[2019-06-27 13:01:58] local.INFO: test2:1561611718  
[2019-06-27 13:01:58] local.INFO: test1:1561611718  
[2019-06-27 13:01:58] local.INFO: [SQL] select count(*) as aggregate from `orders` where `order_no` = ? ["5614450133994844"] 
[2019-06-27 13:01:58] local.INFO: test2:1561611718  
[2019-06-27 13:01:58] local.INFO: test3:1561611718 

if some verification rules fails, logs like below:

[2019-06-27 13:04:10] local.INFO: test1:1561611850  
[2019-06-27 13:04:10] local.INFO: [SQL] select count(*) as aggregate from `orders` where `order_no` = ? ["5614450133994845"] 
[2019-06-27 13:04:10] local.INFO: test2:1561611850  

[specialtactics]

This may be related to a known issue whereby a controller actually gets instantiated twice.

Can you do a test and instead of typehinting the request class in the method args, use a normal request, and instead do this inside the body:

app(TestRequest);

And let me know if the result is the same or not.

[ceejayoz]

Wanted to chime in that we're affected by this, as well.

Our prepareForValidation function massages the request data, and the running twice causes it to double up on these changes, breaking things. Rolling back to Dingo 2.2.3 worked for us as well. (Thanks for the version number, @plhwin!)

I suspect it might be related to laravel/framework#26419.

[specialtactics]

Would you guys be able to post some code snippets of your controllers ? I myself am using the FormRequests in a couple of different ways, but the issue doesn't seem to happen for me, so I want more sample data to work with.

Also would you mind trying the above suggestion?

[bruno-rodrigues]

@specialtactics Downgrading to 2.2.3 solved it for me, no other code changes were required.

🐛 🐛 🐛

[ceejayoz]

@specialtactics I'll see what I can do. Ours is a bit complex; I'll see if I can narrow it down to a minimal reproducible example. OP posted some code, as well.

[luisdc05]

In dingo 2.2.4 this code was added in the LaravelServiceProvider class:

        // Validate FormRequest after resolving
        $this->app->afterResolving(ValidatesWhenResolved::class, function ($resolved) {
            $resolved->validateResolved();
        });

This code is also in laravel's framework FormRequestServiceProvider class (which is loaded by the FoundationServiceProvider).

So if you have Illuminate\Foundation\Providers\FoundationServiceProvider::class and Dingo\Api\Provider\LaravelServiceProvider::class in your app.php providers, thevalidateResolved method in your request class will be called twice.

To fix this you will need to remain on 2.2.3 version or if you really want to update to a newer version you can override the Illuminate\Foundation\Providers\FoundationServiceProvider class and set the $providers property as an empty array then replace Illuminate\Foundation\Providers\FoundationServiceProvider::class in your app.php with the new one you created.

[antennaio]

@luisdc05 is spot on, I can confirm that's precisely what's going on...

[specialtactics]

Would really appreciate if you guys gave me your version of Laravel and a code sample, for my applications the behaviour is much different to what you describe.

I am not saying you're wrong, but it's just very difficult to investigate this without further to go on.

[luisdc05]

Hello!

Does this repo help?

Laravel: 5.8.38
Dingo: 2.3.0

Just hit the {{url}}/api/request route and you will see two var dumps from the App\Http\Requests\DingoRequest class.

[specialtactics]

Thank you so much @luisdc05 I will investigate this over the weekend, and post an update.

[zxj95121]

when I change my FoundationServiceProvider and it not work too.

[JamesKid]

I get this problem too, is there any solution , i don't want to downgrading my laravel 6.5

[Broutard]

@specialtactics any news about this ?

[JamesKid]

I fork dingo/api project from 2.4.0 to my github repository , and i comment the twice call code , and i submit it in the composer "jameskid/dingo-api-fix-twice": "v1.0.0" , then , it's ok.

[specialtactics]

Hey everyone

Sorry, I've been away due to the holidays. I'm very keen to fix this bug ASAP, so I devoted some time today to testing. I've commented out that code that's been pointed out, and I do believe it should return things to normal.

PR Merged here: #1698
Tagged as v2.4.4, so if you update your dingo package, it should be good now.

To elaborate, I set up a custom request just to test one attribute "called test", these are the results;

 + Default Laravel Behaviour

[2020-01-05 05:09:21] local.INFO: prepareForValidation  
[2020-01-05 05:09:21] local.INFO: rules()  
[2020-01-05 05:09:21] local.INFO: withValidator  
[2020-01-05 05:09:21] local.INFO: controller line one  
[2020-01-05 05:09:21] local.INFO: validated()  
[2020-01-05 05:09:21] local.INFO: controller after validated()  
[2020-01-05 05:24:08] local.INFO: array (
  'test' => true,
)  

 + Dingo Befaviour

[2020-01-05 05:24:08] local.INFO: prepareForValidation  
[2020-01-05 05:24:08] local.INFO: rules()  
[2020-01-05 05:24:08] local.INFO: withValidator  
[2020-01-05 05:24:08] local.INFO: prepareForValidation  <--------- Shouldn't be here
[2020-01-05 05:24:08] local.INFO: controller line one  
[2020-01-05 05:24:08] local.INFO: validated()  
[2020-01-05 05:24:08] local.INFO: controller after validated()  
[2020-01-05 05:24:08] local.INFO: array (
  'test' => true,
)  

 + Fixed Dingo Befaviour (Same as vanilla Laravel)

[2020-01-05 05:34:33] local.INFO: prepareForValidation  
[2020-01-05 05:34:33] local.INFO: rules()  
[2020-01-05 05:34:33] local.INFO: withValidator  
[2020-01-05 05:34:33] local.INFO: controller line one  
[2020-01-05 05:34:33] local.INFO: validated()  
[2020-01-05 05:34:33] local.INFO: controller after validated()  
[2020-01-05 05:34:33] local.INFO: array (
  'test' => true,
) 

This is a vert tricky regression, if anyone could try and write unit tests to prevent this form happening, that would be great !