SQLSTATE[25P01]: No active sql transaction: 7 ERROR: SAVEPOINT can only be used in transaction blocks error when using $afterCommit = true;

[azgooon]

Laravel Version

10.25.2 & 10.25.1

PHP Version

8.2.10

Database Driver & Version

PostgreSQL

Description

The project I am working on uses nested transactions and they used to work flawlesly however I've updated laravel framework from version 10.25.0 to 10.25.2 and now I keep getting errors:
PDOException: SQLSTATE[25P01]: No active sql transaction: 7 ERROR: SAVEPOINT can only be used in transaction blocks in /var/www/vendor/laravel/framework/src/Illuminate/Database/Concerns/ManagesTransactions.php:159

I reverted back to v10.25.0 and the problem has gone away, then changed to v10.25.1 and problem re-appeared.

I then looked into the changes in vendor/laravel/framework/src/Illuminate/Database/Concerns/ManagesTransactions.php and it turned out that if I revert logic of this trait back to https://github.com/laravel/framework/blob/4b5ef9e96e15eff8b1a8f848419feba8dc0be50f/src/Illuminate/Database/Concerns/ManagesTransactions.php then issue vanished as well.

Please see below steps to reproduce and let me know if anything is unclear.

FYI (I hope you don't mid) : @mpyw, @tonysm @crynobone

Steps To Reproduce

Step 1 - below code is executed, however ActionQueue "created" event is observerd. ActionQueue observer has got $afterCommit set to true.

        DB::transaction(function () {
            $actionQueue = new ActionQueue([
                'action_id'     => Action::TEST->actionId(),
                'delay'         => 0,
                'payload'       => ['data' => 'test'],
            ]);
            $actionQueue->save();
        });

Step2 - in ActionQueue observer I dispatch below job using dispatchSync() method.

<?php

namespace App\Jobs;

use App\Models\ActionNote;
use Illuminate\Bus\Queueable;
use Illuminate\Contracts\Queue\ShouldQueue;
use Illuminate\Foundation\Bus\Dispatchable;
use Illuminate\Queue\InteractsWithQueue;
use Illuminate\Queue\SerializesModels;
use Illuminate\Support\Facades\DB;
use Spatie\InteractsWithPayload\Concerns\InteractsWithPayload;

class Test implements ShouldQueue
{
    use Dispatchable, InteractsWithQueue, Queueable, SerializesModels, InteractsWithPayload;

    public function handle(): void
    {
        DB::transaction(function () {
            $note = new ActionNote(['note' => mt_rand(1, 10)]);
            return $note->save();
        });
    }
}

This is when I get error:

SQLSTATE[25P01]: No active sql transaction: 7 ERROR: SAVEPOINT can only be used in transaction blocks

[tonysm]

I was able to reproduce this. The issue seems to be with $afterCommit and dispatchSync... I didn't have much time to dig in, but I created a sample test. With this code in my routes/web.php file I was able to reproduce it on latest Laravel:

routes/web.php

<?php

use Illuminate\Bus\Queueable;
use Illuminate\Contracts\Queue\ShouldQueue;
use Illuminate\Database\Eloquent\Factories\HasFactory;
use Illuminate\Foundation\Auth\User as Authenticatable;
use Illuminate\Foundation\Bus\Dispatchable;
use Illuminate\Notifications\Notifiable;
use Illuminate\Queue\InteractsWithQueue;
use Illuminate\Queue\SerializesModels;
use Illuminate\Support\Facades\DB;
use Illuminate\Support\Facades\Route;
use Laravel\Sanctum\HasApiTokens;

class User extends Authenticatable
{
    use HasApiTokens, HasFactory, Notifiable;

    /**
     * The attributes that are mass assignable.
     *
     * @var array<int, string>
     */
    protected $fillable = [
        'name',
        'email',
        'password',
    ];

    /**
     * The attributes that should be hidden for serialization.
     *
     * @var array<int, string>
     */
    protected $hidden = [
        'password',
        'remember_token',
    ];

    /**
     * The attributes that should be cast.
     *
     * @var array<string, string>
     */
    protected $casts = [
        'email_verified_at' => 'datetime',
        'password' => 'hashed',
    ];
}

class UserObserver
{
    public $afterCommit = true;

    public function created(User $user)
    {
        logger('[observer] before dispatching the job');

        LogUserCreation::dispatchSync($user);

        logger('[observer] after dispatching job');
    }
}

User::observe(UserObserver::class);

class LogUserCreation implements ShouldQueue
{
    use Dispatchable, InteractsWithQueue, Queueable, SerializesModels;

    public function __construct(public User $user)
    {
    }

    public function handle(): void
    {
        DB::transaction(function () {
            logger('[job] before updating user');

            $this->user->update(['name' => 'changed']);

            logger('[job] after updating user but before transaction commits');
        });

        logger('[job] after transaction committed...');
    }
}

Route::get('/', function () {
    DB::transaction(function () {
        logger('[request] before creating the user (level 1)');

        DB::transaction(function () {
            logger('[request] before creating the user (level 2)');

            $user = User::make(User::factory()->raw());
            $user->save();

            logger('[request] after creating the user, but before transaction (level 2)');
        });

        logger('[request] after creating the user, but before transaction (level 1)');
    });

    return view('welcome');
});

It looks like when the transaction inside the job tries to begin, it "thinks" there's an open transaction running...

[tonysm]

I'll try to dig in deeper this weekend, but if anyone wants to take it over, feel free (I'm at a conference today and tomorrow, so don't have that much time available).

[mpyw]

Somehow I can't reproduct it with v10.25.1 in my environment...

Confirmed.

[2023-10-06 18:24:25] local.DEBUG: creating real transaction  
[2023-10-06 18:24:25] local.DEBUG: [request] before creating the user (level 1)  
[2023-10-06 18:24:25] local.DEBUG: creating savepoint  
[2023-10-06 18:24:25] local.DEBUG: [request] before creating the user (level 2)  
[2023-10-06 18:24:25] local.DEBUG: [request] after creating the user, but before transaction (level 2)  
[2023-10-06 18:24:25] local.DEBUG: [request] after creating the user, but before transaction (level 1)  
[2023-10-06 18:24:25] local.DEBUG: [observer] before dispatching the job  
[2023-10-06 18:24:25] local.DEBUG: creating savepoint  <--- !!!
[2023-10-06 18:24:25] local.DEBUG: [job] before updating user  
[2023-10-06 18:24:25] local.DEBUG: [job] after updating user but before transaction commits  
[2023-10-06 18:24:25] local.DEBUG: [job] after transaction committed...  
[2023-10-06 18:24:25] local.DEBUG: [observer] after dispatching job  

[mpyw]

Probably the following block causing problems.

try {
    if ($this->transactions == 1) {
        $this->fireConnectionEvent('committing');
        $this->getPdo()->commit();
    }

    if ($this->afterCommitCallbacksShouldBeExecuted()) {
        $this->transactionsManager?->commit($this->getName());
    }
} catch (Throwable $e) {
    $this->handleCommitTransactionException(
        $e, $currentAttempt, $attempts
    );

    continue;
} finally {
    $this->transactions = max(0, $this->transactions - 1);
}

It might be like:

+$decreaseLevel = function (): void {
+    static $applied = false;
+    if ($applied) {
+        return;
+    }
+    $this->transactions = max(0, $this->transactions - 1);
+    $applied = true;
+};
 
 try {
     if ($this->transactions == 1) {
         $this->fireConnectionEvent('committing');
         $this->getPdo()->commit();
     }
+
+    $decreaseLevel();
 
     if ($this->afterCommitCallbacksShouldBeExecuted()) {
         $this->transactionsManager?->commit($this->getName());
     }
 } catch (Throwable $e) {
     $this->handleCommitTransactionException(
         $e, $currentAttempt, $attempts
     );
 
     continue;
 } finally {
-    $this->transactions = max(0, $this->transactions - 1);
+    $decreaseLevel();
 }

[mpyw]

@crynobone I think the three methods trasaction() commit() rollback() should be reviewed at the same time, since the order of level decreasing and callback executions must be consistent.

[mpyw]

Also this seems to be PostgreSQL specific, not reproducible on SQLite. SQLite probably ignores SAVEPOINT calls outside of transactions.

[azgooon]

Thank you for getting involved and I am really pleased that you were able to reproduce the issue.

[tonysm]

Hey @crynobone we may need to revert that change to transactions, this looks a bit serious for apps using transactions. I won't have time to dig into it until Sunday 😔

[crynobone]

We already tested the code using DatabaseMigration trait which uses the default Laravel Transaction Manager without any issue (and tested with Postgres), should add failing tests example https://github.com/laravel/framework/blob/10.x/tests/Integration/Database/EloquentTransactionWithAfterCommitTests.php