Bug: sqlite3.OperationalError, database is locked

[mastersuv]

How to reproduce:

• /start as an Administrator
• Go to "📦 Orders"
• Click "🛑 Stop" to stop live orders.
• Click "👤 Switch to customer mode"
• Click "🛒 Order products"
• Click "🔙 Cancel"
• Send /start command to go back to Administrator menu

CRASH.
Sqlite exception. Database is locked.

Exception in <Worker 763512861>: (sqlite3.OperationalError) database is locked [SQL: UPDATE admins SET live_mode=? WHERE admins.user_id = ?] [parameters: (0, 763512861)] (Background on this error at: http://sqlalche.me/e/13/e3q8)

[mastersuv]

At first sight, it seems like live_mode and user_id values go missing after switching between admin and customer mode. But Python code is hard to me to debug :(

[mastersuv]

I added an extra line at the end of worker.py to close database session and it seems to fix the problem.

Line added: self.session.close()

After this comment here:

greed/worker.py

Line 1533 in a20889d

# Close the database session

[Shocking-Sys]

Hello, First of all - understand what SQLite Database work! - You or already in use this database i.e. watch it trough SQLite Viewer or you run same Bot twice (didn't close them properly)
Also it can occur if your I\O system is slow (old HDD, SD card, etc.)

[mastersuv]

I understand how SQLite works, but Python+sqlalchemy are new to me.
Adding that line fixed the problem for me though. Try to reproduce the problem on your side to see if it was only me.

[Shocking-Sys]

From my side Greed Bot work like a charm (Right now i don't use it, but it's not too much addition in Master Branch since September-October)
But I run them on VPS with SSD and NVMe so never catch (Database Locked) error.

Also it was under:

• Python 3.7 (in pyenv \ pipenv)
• python-telegram-bot 12
• sqlalchemy 1.3

• And just for your info - by using SQLAlchemy you can use PostgreSQL, MySQL, etc. without rewrite code.

[mastersuv]

Thanks for the feedback. That's weird then, I'm also running a VPS with SSD (CentOS 8).
The only difference I see is I'm using python-telegram-bot 13, which I guess it has nothing to do with the error.

I'll test on another machine to see how it goes.

[Shocking-Sys]

@mastersuv Check that you don't run ./database.py or ./core.py twice. SQLite can handle only one connection at a time. And it handled exactly by database.py which invoked by a worker.py which invoked by a core.py.
Changes in python-telegram-bot 12 and python-telegram-bot 13 - major but it's compaitable, because Greed use small small part of this library:

• Send Message Markadown'ed
• Send Message HTML'ed
• Get Context - ( Text from message by user )
• Get User Info - ( Telegram ID, username, name, etc. )

So no big changes in library in behaviour on this functions - so it's compaitable with 13. But yes this error even not by a SQLAlchemy it's a SQLite behaviour (Only 1 connection to DB allowed)

Have a nice day.

[mastersuv]

Thanks, I'll check that out!

[Shocking-Sys]

But better if @Steffo99 look at this error - may be when you was in Live mod previously it's not close DB Connection. And it locked down database.

[mastersuv]

Yeah, I think I've identified part of the problem.

The error always happens when the /start command is sent to the bot and live_mode is set to 1 in the database.
So, I concluded, live_mode must be 0 when the /start command is received by the bot.
By entering Live Orders mode, the database field live_mode is set to 1. And for some reason, never being set to 0 again.

[Shocking-Sys]

Because when live_mode is on - it's expected behaviour because it's ask DB for new Orders. But iirc it's check db for new orders not always connected to DB but with expected period of time. You chek the same admin user who is in Live_mode on if i understand correctly. Or you have try it by another user who is not in Live_mode but there is exist user with live_mode enabled ?

[mastersuv]

Yeah, there are no other admins or users, just me.

[mastersuv]

I tried on another computer and is working perfectly fine. No more database locked errors... I was running core.py twice... Duplicated processes.

[mastersuv]

Sorry 🤦‍♂️

[Steffo99]

I was able to reproduce the error!

Now let's see what causes it...

[Steffo99]

I added an extra line at the end of worker.py to close database session and it seems to fix the problem.

Line added: self.session.close()

After this comment here:

greed/worker.py

Line 1533 in a20889d

# Close the database session

This fix worked!

The bot wasn't closing sessions properly on a conversation exit, and it seems it was because of a line that was missing since the first commits of the bot ( 5f04a1f )!

I'm committing that in your name, so to give proper credit. Thank you!

[Steffo99]

Fixed with 3915bb7 .

[Steffo99]

@laskriabdellah has reported that the issue has somehow resurfaced in: #201 (comment)

[Steffo99]

@laskriabdellah, can you provide some debug logs?

In config.toml, set the logging parameters as follows:

# Logging settings
[Logging]
# The output format for the messages printed to the console
# See https://docs.python.org/3/library/logging.html#logrecord-attributes for information about the {}-attributes
format = "{asctime} | {threadName} | {name} | {message}"
# Logging level: ignore all log entries with a level lower than the specified one
# Valid options are FATAL, ERROR, WARNING, INFO, and DEBUG
level = "DEBUG"

Please post the results here!