search

tursodatabase / turso-driver-laravel

Turso Driver for Laravel with Native libSQL
https://turso.tech/sdk/php/guides/laravel
MIT License
62 stars 7 forks source link

[Bug]: Insert not working #11

Closed ineersa closed 4 months ago

ineersa commented 4 months ago

What happened?

Insert currently not working. I'm trying to create new record via eloquent model using save().

It internally calls \Illuminate\Database\Query\Processors\Processor::processInsertGetId

    /**
     * Process an  "insert get ID" query.
     *
     * @param  \Illuminate\Database\Query\Builder  $query
     * @param  string  $sql
     * @param  array  $values
     * @param  string|null  $sequence
     * @return int
     */
    public function processInsertGetId(Builder $query, $sql, $values, $sequence = null)
    {
        $query->getConnection()->insert($sql, $values);

        $id = $query->getConnection()->getPdo()->lastInsertId($sequence);
        dd($id);
        return is_numeric($id) ? (int) $id : $id;
    }

And since insert method not implemented in connection it uses default one, which not adding records into database.

How to reproduce the bug

$note = new Note($data);
$note->save();

Where Note is instance of Eloquent Model

Package Version

latest

PHP Version

8.3.8

Laravel Version

11

Which operating systems does with happen with?

Linux

Notes

No response

ineersa commented 4 months ago

This on is quite hard and i can't understand why it's happening.

If i try to run code from console command:

public function createNote(array $data): Note
    {
        $connection = UserDatabasesService::CONNECTION_NAME;

        \Log::info('Environment: ' . app()->environment());
        \Log::info('Database connection: ' . $connection);

        $config = DB::connection($connection)->getConfig();
        \Log::info('Database config:', array_intersect_key($config, array_flip(['driver', 'database', 'username'])));

        DB::connection($connection)->enableQueryLog();

        try {
            \Log::info('Input data:', $data);

            $note = new Note($data);
            $note->shared = false;
            $note->public = false;
            $note->archived = false;
            $note->metadata = null;

            \Log::info('Note before save:', $note->toArray());

            $saveResult = $note->save();
            \Log::info('Save result: ' . ($saveResult ? 'true' : 'false'));

            \Log::info('Note after save:', $note->toArray());

            $retrievedNote = Note::find($note->id);
            \Log::info('Retrieved note:', $retrievedNote ? $retrievedNote->toArray() : ['status' => 'Not found']);

            \Log::info('Executed queries:', DB::connection($connection)->getQueryLog());

            $checkNote = DB::connection($connection)->table('notes')->where('id', $note->id)->first();
            \Log::info('Note check in separate connection:', $checkNote ? (array)$checkNote : ['status' => 'Not found']);

        } catch (\Throwable $e) {
            \Log::error('Error in createNote: ' . $e->getMessage());
            \Log::error('Stack trace: ' . $e->getTraceAsString());
            throw $e;
        }

        DB::connection($connection)->disconnect();
        DB::connection($connection)->reconnect();

        $finalCheck = DB::connection($connection)->table('notes')->where('id', $note->id)->first();
        \Log::info('Final note check after reconnection:', $finalCheck ? (array)$finalCheck : ['status' => 'Not found']);

        return $note;
    }

i do have correct record inserted.

[2024-07-08 19:42:43] local.INFO: Environment: local  
[2024-07-08 19:42:43] local.INFO: Database connection: user_db  
[2024-07-08 19:42:43] local.INFO: Database config: {"driver":"libsql","database":"file:/var/www/notes/database/users_databases/id_166821b38418e3.sqlite"} 
[2024-07-08 19:42:43] local.INFO: Input data: {"content":"asdasd asdad","tags":["ad"]} 
[2024-07-08 19:42:43] local.INFO: Note before save: {"content":"asdasd asdad","shared":false,"public":false,"archived":false,"metadata":null} 
[2024-07-08 19:42:43] local.INFO: Save result: true  
[2024-07-08 19:42:43] local.INFO: Note after save: {"content":"asdasd asdad","shared":false,"public":false,"archived":false,"metadata":null,"updated_at":"2024-07-09T01:42:43.000000Z","created_at":"2024-07-09T01:42:43.000000Z","id":8} 
[2024-07-08 19:42:43] local.INFO: Retrieved note: {"shared":0,"content":"asdasd asdad","updated_at":"2024-07-09T01:42:43.000000Z","metadata":null,"created_at":"2024-07-09T01:42:43.000000Z","public":0,"id":8,"archived":0} 
[2024-07-08 19:42:43] local.INFO: Executed queries: [{"query":"insert into \"notes\" (\"content\", \"shared\", \"public\", \"archived\", \"metadata\", \"updated_at\", \"created_at\") values (?, ?, ?, ?, ?, ?, ?)","bindings":["asdasd asdad",false,false,false,null,"2024-07-08 19:42:43","2024-07-08 19:42:43"],"time":8.15},{"query":"select * from \"tags\" where \"type\" is null and (json_extract(\"name\", '$.\"en\"') = ? or json_extract(\"slug\", '$.\"en\"') = ?) limit 1","bindings":["ad","ad"],"time":0.14},{"query":"select max(\"order_column\") as aggregate from \"tags\"","bindings":[],"time":0.08},{"query":"insert into \"tags\" (\"name\", \"type\", \"slug\", \"order_column\", \"updated_at\", \"created_at\") values (?, ?, ?, ?, ?, ?)","bindings":["{\"en\":\"ad\"}",null,"{\"en\":\"ad\"}",8,"2024-07-08 19:42:43","2024-07-08 19:42:43"],"time":1.45},{"query":"select * from \"taggables\" where \"taggables\".\"taggable_id\" = ? and \"taggable_type\" = ?","bindings":[8,"App\\Models\\Note"],"time":0.1},{"query":"insert into \"taggables\" (\"taggable_type\", \"tag_id\", \"taggable_id\") values (?, ?, ?)","bindings":["App\\Models\\Note",8,8],"time":1.95},{"query":"select * from \"notes\" where \"notes\".\"id\" = ? limit 1","bindings":[8],"time":0.1}] 
[2024-07-08 19:42:43] local.INFO: Note check in separate connection: {"public":0,"metadata":"null","archived":0,"content":"asdasd asdad","created_at":"2024-07-08 19:42:43","id":8,"updated_at":"2024-07-08 19:42:43","shared":0} 
[2024-07-08 19:42:43] local.INFO: Final note check after reconnection: {"public":0,"updated_at":"2024-07-08 19:42:43","id":8,"content":"asdasd asdad","archived":0,"metadata":"null","created_at":"2024-07-08 19:42:43","shared":0} 
[2024-07-08 19:44:18] local.INFO: Environment: local  
[2024-07-08 19:44:18] local.INFO: Database connection: user_db  
[2024-07-08 19:44:18] local.INFO: Database config: {"driver":"libsql","database":"file:/var/www/notes/database/users_databases/id_166821b38418e3.sqlite"} 
[2024-07-08 19:44:18] local.INFO: Input data: {"content":"asdasdas asda","tags":["add"]} 
[2024-07-08 19:44:18] local.INFO: Note before save: {"content":"asdasdas asda","shared":false,"public":false,"archived":false,"metadata":null} 
[2024-07-08 19:44:18] local.INFO: Save result: true  
[2024-07-08 19:44:18] local.INFO: Note after save: {"content":"asdasdas asda","shared":false,"public":false,"archived":false,"metadata":null,"updated_at":"2024-07-09T01:44:18.000000Z","created_at":"2024-07-09T01:44:18.000000Z","id":0}

But if i run this code from web interface, it's not working anymore, same code same data:

[2024-07-08 19:46:51] local.INFO: Environment: local  
[2024-07-08 19:46:51] local.INFO: Database connection: user_db  
[2024-07-08 19:46:51] local.INFO: Database config: {"driver":"libsql","database":"file:/var/www/notes/database/users_databases/id_166821b38418e3.sqlite"} 
[2024-07-08 19:46:51] local.INFO: Input data: {"content":"asdasdas asda","tags":["add"]} 
[2024-07-08 19:46:51] local.INFO: Note before save: {"content":"asdasdas asda","shared":false,"public":false,"archived":false,"metadata":null} 
[2024-07-08 19:46:51] local.INFO: Save result: true  
[2024-07-08 19:46:51] local.INFO: Note after save: {"content":"asdasdas asda","shared":false,"public":false,"archived":false,"metadata":null,"updated_at":"2024-07-09T01:46:51.000000Z","created_at":"2024-07-09T01:46:51.000000Z","id":0} 
[2024-07-08 19:46:51] local.INFO: Retrieved note: {"status":"Not found"} 
[2024-07-08 19:46:51] local.INFO: Executed queries: [{"query":"insert into \"notes\" (\"content\", \"shared\", \"public\", \"archived\", \"metadata\", \"updated_at\", \"created_at\") values (?, ?, ?, ?, ?, ?, ?)","bindings":["asdasdas asda",false,false,false,null,"2024-07-08 19:46:51","2024-07-08 19:46:51"],"time":0.19},{"query":"select * from \"tags\" where \"type\" is null and (json_extract(\"name\", '$.\"en\"') = ? or json_extract(\"slug\", '$.\"en\"') = ?) limit 1","bindings":["add","add"],"time":0.09},{"query":"select max(\"order_column\") as aggregate from \"tags\"","bindings":[],"time":0.07},{"query":"insert into \"tags\" (\"name\", \"type\", \"slug\", \"order_column\", \"updated_at\", \"created_at\") values (?, ?, ?, ?, ?, ?)","bindings":["{\"en\":\"add\"}",null,"{\"en\":\"add\"}",9,"2024-07-08 19:46:51","2024-07-08 19:46:51"],"time":0.06},{"query":"select * from \"taggables\" where \"taggables\".\"taggable_id\" = ? and \"taggable_type\" = ?","bindings":[0,"App\\Models\\Note"],"time":0.08},{"query":"insert into \"taggables\" (\"taggable_type\", \"tag_id\", \"taggable_id\") values (?, ?, ?)","bindings":["App\\Models\\Note",0,0],"time":0.04},{"query":"select * from \"notes\" where \"notes\".\"id\" = ? limit 1","bindings":[0],"time":0.07}] 
[2024-07-08 19:46:51] local.INFO: Note check in separate connection: {"status":"Not found"} 
[2024-07-08 19:46:51] local.INFO: Final note check after reconnection: {"status":"Not found"}

And it's quite puzzling...

As far as i can see Laravel is not processing statement execute result at all:

public function processInsertGetId(Builder $query, $sql, $values, $sequence = null)
    {
        $query->getConnection()->insert($sql, $values);

        $id = $query->getConnection()->getPdo()->lastInsertId($sequence);

        return is_numeric($id) ? (int) $id : $id;
    }

And we get false from insert here...

ineersa commented 4 months ago

I've found an issue, it was rights on database www-data had no rights on that file, that's why writes from console was working and from web not.

I think the issue is we don't see any errors, which should be thrown from extension in this case? Debugging errors having only false as statement execute result is kinda close to insanity...

I've tried to insert incorrect data, and it just works without giving any errors, it shouldn't, please look into extension and propagate errors instead of hiding them.

Also while debugging this issue I've found that lastInsertedId() is not finished and not working, which blocks further work after creation with Eloquent models, I can make separate issue for this. I've fixed for myself in dev branch fix looks like this https://github.com/tursodatabase/turso-driver-laravel/commit/fa7eb5ea1e929270e83fb1fde8ccf885944078c2 It's not thread safe, but there is no better alternative anyway I think?

ineersa commented 4 months ago

This one is really frustrating, because driver and database gives 0 errors or exceptions or any info at all, but I think I've found the reason - https://github.com/tursodatabase/turso-driver-laravel/blob/main/src/Database/LibSQLPDOStatement.php#L57

LibSQLPDOStatement class is the cause, it's not doing execute but uses query, also it shouldn't handle lastInsertId it's PDO responsibility (which is LibSQLDatabase in our case), and somehow incorrect instance is set in $this->db

ineersa commented 4 months ago

Ok, so I've fixed lastInsertID here https://github.com/ineersa/turso-driver-laravel/commit/bdc1a63e063665c371e760acdd46b13c285ceb03 and it seems like it's working ok, but still it's quite interesting approach to use query() method instead of execute() but it works atleast now.

I'll try to make some pull requests today or tomorrow with small changes

ineersa commented 4 months ago

@darkterminal In this https://github.com/tursodatabase/turso-driver-laravel/pull/15/files#diff-1845c220ace1bd4e6411e3abb2eb195ad1be46179ce58dffb8b416100ced8da6R49 I've added test to show what exactly is not working.

The problem is in lastInsertId retrieval.

In my dev branch I've changed how it's retrieved:

I moved this responsibility to PDO (LibSQLDatabase) which responsibility is to provide those methods, but my version is very different of yours so if you can provide hints to implementation i can try to build PR, otherwise please use tests and try to fix it.

This functionality is crucial for Eloquent models, and without it driver is basically unusable.

darkterminal commented 4 months ago

@ineersa you can check the latest tests that I merged. And try to checkout the main branch. I've tested and it's work!

I am override the Connection from LibSQLConnection class, to work with LibSQL driver.

darkterminal commented 4 months ago

Get lastInsertId now working.

image