Writing to Sqlite database causes process to hang while using TypeORM

[davidstevens37]

What version of Bun is running?

1.1.17+bb66bba1b

What platform is your computer?

Darwin 23.2.0 arm64 arm

What steps can reproduce the bug?

While using TypeORM, the operations seem to "work" however after a certain point the process hangs and does not finish. This is quickly visible iterating and bulk inserting records into the sqlite database using TypeORM.

typeorm-example.ts:

import 'reflect-metadata';
import { DataSource, BaseEntity, Entity, PrimaryGeneratedColumn, Column } from "typeorm";

@Entity({ name: 'test' })
class Item extends BaseEntity {
    @PrimaryGeneratedColumn()
    id!: number;

    @Column()
    name!: string;
}

const AppDataSource = new DataSource({
    type: 'sqlite',
    database: 'db.sqlite',
    synchronize: true,
    enableWAL: true,
    entities: [Item],
    migrations: [],
    subscribers: [],
});
await AppDataSource.initialize();
await Item.delete({});
const start = Date.now();
let count = 0;

while (count < 50000) {
    const items = Array.from({ length: 1000 }, (_, i) => Item.create({ name: 'test' }));
    await Item.save(items);
    count = await Item.count();
    console.log(count);
}
console.log('Time:', Date.now() - start);
await AppDataSource.close();

tsconfig:

{
  "compilerOptions": {
    "target": "ES2017",
    "module": "NodeNext",
    "outDir": "./dist",
    "strict": true,
    "esModuleInterop": true,
    "emitDecoratorMetadata": true,
    "experimentalDecorators": true
  }
}

What is the expected behavior?

the output of the script above should be 50 console.logs incrementing by 1000 each time (the number of records), followed by a Time taken.

while either using ts-node or transpiring to to a javascript file and running node dist/typeorm-example.js the output results in the expected.

> node --loader ts-node/esm typeorm-example.ts
1000
2000
3000
...
...
...
48000
49000
50000
Time: 2686

What do you see instead?

while executing the typescript file with bun bun run typeorm-example.ts or the transpiled javascript (using tsc or bun) with bun bun run dist/typeorm-example.js, the output begins as expected, but the freezes and does not print more than X iterations. Seems it gets farther when running the transpiled version instead of the TS directly.

With the transpiled JS, it gets 9, 11, or 16 iterations before freezing. With the TS directly, it usually chokes around 3 or 4 iterations. Once it stops, it makes no further progress, even if left for minutes.

> bun run typeorm-example.ts
1000
2000
3000

Additional information

No response

[Jarred-Sumner]

I'm able to reproduce a crash when sqlite3 is not installed. The crash becomes an error in #12246 (likely due to https://github.com/WebKit/WebKit/pull/30298), but I'm not yet able to reproduce the hanging.

[davidstevens37]

@Jarred-Sumner it seems to be an issue only impacting Apple Silicon. I executed the example in the following environments:

• My MB Pro M1 (Apple M1 Pro, 32 GB, 14.2 Beta) -- Hung
• Another MB Air M2 (Apple M2 Air, 24 GB, 14.5) -- Hung
• An ec2 instance running amazon linux 2023 -- Did Not Hang
• A docker container, hosted on the above MB Pro M1, built from arm64v8/ubuntu:20.04 -- Did Not Hang

Please, let me know if there's any other information that I can collect to provide more context.

[billywhizz]

@davidstevens37 i am also unable to reproduce this issue on Mac Pro M3 Max running Darwin 23.5.0. I see the initial crash as you and jarred do when sqlite module is not installed but after everything is installed, it works every time.

I have put a gist up here so you can see exactly what i am running. https://gist.github.com/billywhizz/7d0b1149aec4dcd4ef3a061834b77c2d

[billywhizz]

ok, so i just tried the exact same gist on a scaleway m1 mini and i see the issue you are describing with it hanging. i will see if i can find out more.

the m1 i am testing on is running darwin 22.6.0.

[davidstevens37]

thanks @billywhizz! Also, here's a much more focused example that removes typeorm and distills it down to direct interactions with sqlite3. Additionally, I've noticed a difference in behavior when a callback is passed to the sqlite database instance's run method.

It seems the hanging event is due to awaiting a promise that never resolves. The promise never resolves because the resolve function is called from the callback that's passed to sqlite's db.run() method and that callback passed to the sqlite db.run() is never called.

---

With callback passed to db.run():

• This often produces the hanging behavior.
• When it happens, the execute func is called along with the sqlite db.run(). However, that iteration does not make it to the table and the callback is never called, causing the promise to never resolve.

import sqlite from 'sqlite3'
const db = new sqlite.Database('db.sqlite');

db.exec('CREATE TABLE IF NOT EXISTS test (name TEXT)');
db.exec('DELETE FROM test');

const execute = (query, params) => new Promise((ok, fail) => {
    console.log('\nbegin -- ', params[0])
    db.run(query, params, (err, row) => {
        console.log('callback -- ', params[0])
        if (err) return fail(err);
        ok(row);
    });
});

for (let i = 0; i < 100; i++) {
    db.exec('BEGIN TRANSACTION');
    for (let j = 0; j < 10_000; j++) {
        await execute('INSERT INTO test (name) VALUES (?)', [`i-${i}__j-${j}`]);
    }
    db.exec('COMMIT');
    console.log(i)
}

• 
• 

---

Without callback passed to db.run():

• When a callback is not passed, i've not seen a hanging event.
• What does happen, is it will finish the i loop and the database table will continue to receive new records until it catches up. it takes a handful of seconds for the table to finish receiving all the records and it happens incrementally.

import sqlite from 'sqlite3'
const db = new sqlite.Database('db.sqlite');

db.exec('CREATE TABLE IF NOT EXISTS test (name TEXT)');
db.exec('DELETE FROM test');

for (let i = 0; i < 100; i++) {
    db.exec('BEGIN TRANSACTION');
    for (let j = 0; j < 10_000; j++) {
        db.run('INSERT INTO test (name) VALUES (?)', [`i-${i}__j-${j}`]);
    }
    db.exec('COMMIT');
    console.log(i)
}

---

i can try to dig a little deeper later this evening.

[davidstevens37]

@billywhizz

TL;DR:

• i think it all boils down to uninvoked callbacks.
• the statement is still written in the event of an uninvoked callback.

• seems to happen with .run, but not with .exec

it appears the sqlite library is in fact writing to the table, but in the example above, the transaction was never commited, which explains why all the records do reach the table in the example without a callback. Without a callback, there's not an opportunity for the script have a promise unresolved, preventing getting to the COMMIT command.

Here, we're forcing the promise to resolve after an arbitrary timeout and in every execution of this script ends up with the correct, expected dataset, despite the callback never being invoked (which if unforced, would leave the promise unresolved exhibiting the hanging behavior).

Additionally, I noted this behavior exists with the .run command, but not with the .exec command.

• running with db.run with fn signature (SqlString, ParamArray, Callback) -- Exhibits failed callbacks.
• running with db.run with fn signature (SqlString, Callback) -- Exhibits failed callbacks.
• running with db.run with fn signature (SqlString, ParamArray) -- Does not fail to call callbacks as they're non-existant. and this prevents async control flow.
• running with db.exec with fn signature (SqlString, Callback) -- Have yet to see this instance fail

Executed with .run

import sqlite from 'sqlite3'
const db = new sqlite.Database('db.sqlite');

const failedQueries = [];

const execute = (query) => new Promise((ok, fail) => {
    const promiseTimeoutResolver = setTimeout(()=> {
        failedQueries.push(query);
        ok();
    }, 1000);
    db.run(query, (err, row) => {
        clearTimeout(promiseTimeoutResolver);
        if (err) return fail(err);
        ok(row);
    });
});

await execute('CREATE TABLE IF NOT EXISTS test (name TEXT)');
await execute('DELETE FROM test');

for (let i = 0; i < 100; i++) {
    await execute('BEGIN TRANSACTION');
    for (let j = 0; j < 10_000; j++) {
        const name = `i-${i}__j-${j}`;
        await execute(`INSERT INTO test (name) VALUES ('${name}')`);
    }
    await execute('COMMIT');
}

const count = await new Promise((ok, fail) => 
    db.get('SELECT COUNT(*) as count FROM test', (err, row) => err ? fail(err) : ok(row.count)));

console.log(
    `\ntotal rows: ${count}`,
    `\nnon-invoked callback count: ${failedQueries.length}`,
    failedQueries.map(q=> '\n\t-- ' + q).join(''),
);

λ bun run index.js
total rows: 1000000
non-invoked callback count: 9 
        -- INSERT INTO test (name) VALUES ('i-11__j-2712')
        -- INSERT INTO test (name) VALUES ('i-26__j-822')
        -- INSERT INTO test (name) VALUES ('i-27__j-196')
        -- INSERT INTO test (name) VALUES ('i-59__j-248')
        -- INSERT INTO test (name) VALUES ('i-61__j-264')
        -- INSERT INTO test (name) VALUES ('i-69__j-294')
        -- INSERT INTO test (name) VALUES ('i-71__j-29')
        -- INSERT INTO test (name) VALUES ('i-73__j-333')
        -- INSERT INTO test (name) VALUES ('i-81__j-4065') 

λ bun run index.js
total rows: 1000000
non-invoked callback count: 11 
        -- INSERT INTO test (name) VALUES ('i-12__j-489')
        -- INSERT INTO test (name) VALUES ('i-25__j-130')
        -- INSERT INTO test (name) VALUES ('i-26__j-145')
        -- INSERT INTO test (name) VALUES ('i-34__j-82')
        -- INSERT INTO test (name) VALUES ('i-40__j-68')
        -- INSERT INTO test (name) VALUES ('i-50__j-193')
        -- INSERT INTO test (name) VALUES ('i-51__j-208')
        -- INSERT INTO test (name) VALUES ('i-58__j-943')
        -- INSERT INTO test (name) VALUES ('i-61__j-260')
        -- INSERT INTO test (name) VALUES ('i-65__j-315')
        -- INSERT INTO test (name) VALUES ('i-87__j-5912') 

λ bun run index.js
total rows: 1000000 
non-invoked callback count: 7 
        -- INSERT INTO test (name) VALUES ('i-13__j-6538')
        -- INSERT INTO test (name) VALUES ('i-15__j-157')
        -- INSERT INTO test (name) VALUES ('i-46__j-412')
        -- INSERT INTO test (name) VALUES ('i-51__j-4529')
        -- INSERT INTO test (name) VALUES ('i-60__j-1189')
        -- INSERT INTO test (name) VALUES ('i-61__j-211')
        -- INSERT INTO test (name) VALUES ('i-84__j-152')

With db.exec:

• by changing line 11 to use db.exec insteead of db.run, i have yet to see an uninvoked callback.

λ bun run index.js
total rows: 1000000 
non-invoked callback count: 0 

λ bun run index.js
total rows: 1000000 
non-invoked callback count: 0 

λ bun run index.js
total rows: 1000000 
non-invoked callback count: 0 

λ bun run index.js
total rows: 1000000 
non-invoked callback count: 0 

λ bun run index.js
total rows: 1000000 
non-invoked callback count: 0 

λ bun run index.js
total rows: 1000000 
non-invoked callback count: 0 

λ bun run index.js
total rows: 1000000 
non-invoked callback count: 0 

λ bun run index.js
total rows: 1000000 
non-invoked callback count: 0 

---

I hope this information is at least somewhat helpful. Thanks for your help on this issue!

[billywhizz]

thanks for all the detail @davidstevens37! i will try to take a look in more detail over next couple days and will get back to you. :pray: