Edgewall Software
Modify

Opened 8 years ago

Closed 4 years ago

Last modified 2 years ago

#3503 closed defect (fixed)

OperationalError: database is locked

Reported by: anonymous Owned by: cboos
Priority: highest Milestone: 0.10.1
Component: general Version: devel
Severity: normal Keywords: session pysqlite database lock
Cc: exarkun@…
Release Notes:
API Changes:

Description

recent trunk, trac/web/session.py, line 210, in save, attempts to commit a transaction without performing properly error handling. If an OperationalError? is raised here, it will propagate all the way up to the top of the application without being handled.

A stacktrace recently logged on my server:

          File "/home/trac/Projects/Twisted/trunk/twisted/web2/wsgi.py", line 138, in run
            result = self.application(self.environment, self.startWSGIResponse)
          File "/home/trac/Run/trac/external.py", line 74, in __call__
            return self.application(environ, start_response)
          File "/home/trac/Run/trac/external.py", line 115, in tracApplication
            return trac.web.main.dispatch_request(environ, start_response)
          File "/home/trac/Projects/trac/trunk/trac/web/main.py", line 367, in dispatch_request
            req.send_error(sys.exc_info(), status=500)
          File "/home/trac/Projects/trac/trunk/trac/web/api.py", line 365, in send_error
            exc_info)
          File "/home/trac/Projects/trac/trunk/trac/web/main.py", line 335, in dispatch_request
            dispatcher.dispatch(req)
          File "/home/trac/Projects/trac/trunk/trac/web/main.py", line 236, in dispatch
            req.session.save()
          File "/home/trac/Projects/trac/trunk/trac/web/session.py", line 210, in save
            db.commit()
        pysqlite2.dbapi2.OperationalError: database is locked

Attachments (0)

Change History (45)

comment:1 Changed 8 years ago by anonymous

  • Cc exarkun@… added

comment:2 Changed 8 years ago by anonymous

tsete

comment:3 Changed 8 years ago by anonymous

Hiya Mark!

comment:4 Changed 8 years ago by anonymous

hiya Andy!

comment:5 Changed 8 years ago by cboos

  • Milestone set to 0.10
  • Owner changed from jonas to cboos

We should probably transform this into a TracError …

comment:6 Changed 8 years ago by anonymous

Since two weeks (still with 0.9.6) we are experiencing "database locked" errors quite often, maybe 3 or 4 times per week. What can I do to help debugging this ? Until now I only have the error message which appears in Trac. Somebody does something, then something goes wrong, and maybe the first user after that event gets a "database locked". How can I find out more ?

Alex

comment:7 follow-up: Changed 8 years ago by cboos

Unfortunately, "database locked" errors are somewhat inherent the to default architecture used by Trac (see also #3446 for enhancement proposals).

This ticket is about the suggestion of transforming the "database locked" error into a more "friendly" error message, if that's possible.

The only situations where the "database locked" errors are indeed problematic are the ones in which the database remains locked for all subsequent requests. Fortunately, we haven't seen that since a while, now.

comment:8 Changed 8 years ago by anonymous

Just as a note: we are running trac in fastcgi-mode. If the lock happens, it doesn't go away. We have to login to the server and kill the trac.fcgi processes with killall. At least one of them can't be killed friendly, but SIGKILL has to be used. Then we have to restart apache. We are running Trac 0.9.4 and sqlite etc. from march or april.

Alex

comment:9 Changed 8 years ago by anonymous

Similarly, I'm using WSGI and if the lock happens, I also have to SIGKILL the server process to get it to exit.

SQLite, subversion, and Python bindings for both are the versions packaged in Ubuntu Breezy.

comment:10 follow-up: Changed 8 years ago by mgood

At this point we're not in need of more feedback from 0.9.x versions, since there have been improvement in the trunk since then. So, if you're interested in providing more testing please upgrade to 0.10b1 or the trunk.

cboos: do you have a plan for addressing this in 0.10, or can we push it to 0.10.1 since there doesn't seem to be sufficient information to debug it?

comment:11 Changed 8 years ago by anonymous

I should have mentioned the version of trac I am using is a fairly recent trunk, r3585 (0.9.x had no WSGI support, did it?)

comment:12 in reply to: ↑ 10 Changed 8 years ago by cboos

  • Milestone changed from 0.10 to 0.10.1

Replying to mgood:

cboos: do you have a plan for addressing this in 0.10, or can we push it to 0.10.1 since there doesn't seem to be sufficient information to debug it?

For 0.10, I only planned to implement the suggestion that we should convert the database is locked error to a more "friendly" TracError, as the lock error seems to be inevitable at this point, but this shouldn't block 0.10 and can well be post-poned to 0.10.1.

However, the fact that there are apparently still serious persitent locks around would probably justify that we reopen #1661, which was closed due to lack of feedback and because I believed that people stopped being affected by this, which is apparently wrong…

comment:13 follow-up: Changed 8 years ago by kre

Unfortunately I have been hitting "Database is locked" from switching to current trunk. Seems something that changed in last ~20 commits that caused database to be locked rather often.

comment:14 Changed 8 years ago by cboos

#3756 marked as duplicate.

comment:15 in reply to: ↑ 13 ; follow-up: Changed 8 years ago by anonymous

Replying to kre:

Unfortunately I have been hitting "Database is locked" from switching to current trunk. Seems something that changed in last ~20 commits that caused database to be locked rather often.

Does this mean it happens more often with 0.10.0 than with previous versions ? If that's the case, we can't upgrade to 0.10.0, because this would block us even more. (I understand that reports about 0.9.x don't help you in any way anymore)

Alex

comment:16 in reply to: ↑ 15 Changed 8 years ago by cboos

Replying to anonymous:

Does this mean it happens more often with 0.10.0 than with previous versions ?

I don't think so. In addition, with r3830, the locks seem to be much harder to reproduce. At least, I couldn't get one anymore, using tracd. I think I'll backport to 0.10.1, but more user feedback is needed first, so I'll be glad to hear from you if 0.10 + r3830 helps.

If that's the case, we can't upgrade to 0.10.0, because this would block us even more. (I understand that reports about 0.9.x don't help you in any way anymore)

No, 0.9.x in general will not get any more improvements, but only security bug fixes. Your best move would be to have a test drive of 0.10 like suggested above: this will help us to make a more robust 0.10.1 that you'll also benefit from.

comment:17 in reply to: ↑ 7 ; follow-up: Changed 8 years ago by ThurnerRupert

Replying to cboos:

Unfortunately, "database locked" errors are somewhat inherent the to default architecture used by Trac (see also #3446 for enhancement proposals).

This ticket is about the suggestion of transforming the "database locked" error into a more "friendly" error message, if that's possible.

The only situations where the "database locked" errors are indeed problematic are the ones in which the database remains locked for all subsequent requests. Fortunately, we haven't seen that since a while, now.

unfortunately, we had it today. v 0.10.

comment:18 in reply to: ↑ 17 Changed 8 years ago by ThurnerRupert

Replying to ThurnerRupert:

Replying to cboos:

Unfortunately, "database locked" errors are somewhat inherent the to default architecture used by Trac (see also #3446 for enhancement proposals).

This ticket is about the suggestion of transforming the "database locked" error into a more "friendly" error message, if that's possible.

The only situations where the "database locked" errors are indeed problematic are the ones in which the database remains locked for all subsequent requests. Fortunately, we haven't seen that since a while, now.

unfortunately, we had it today. v 0.10.

read #1661 … we did not wait a couple of minutes, but 3-4 times as long as with the normal (frequent) locking errors.

comment:19 Changed 8 years ago by ThurnerRupert

  • Resolution set to duplicate
  • Status changed from new to closed

seems to be a duplicate for #3446, there is a solution. we try it and report back.

comment:20 Changed 8 years ago by cboos

  • Keywords session pysqlite database lock added
  • Priority changed from high to highest
  • Resolution duplicate deleted
  • Status changed from closed to reopened

No, it's not the same. The error reported in this ticket is specific to the req.session.save() done after the response was sent. The problem here is that we attempt to do a req.send_error() which will necessarily fail (as a response was already sent).

Also, it doesn't seem to be a good idea to persist the session changes if the request actually failed.

It would be possible to catch the session save failure and present it to the user if that is done before sending the response. However, this might increase the visible rate of database locks, which I think would be nevertheless OK given the recent progresses on this front.

comment:21 follow-up: Changed 8 years ago by cboos

Above changes implemented in r4048.

I should note that I still have a hard way to trigger database locks, even with that change, probably thanks to r3830 (see #3446). However, I was able to see the problem with the TracTimeline just after a commit (i.e. #2902).

Will backport this later.

comment:22 in reply to: ↑ 21 Changed 8 years ago by cboos

Replying to cboos:

Above changes implemented in r4048.

Oops, not really… I actually misplaced the req.session.save, and of course there's no locks as nothing gets changed :\

comment:23 Changed 8 years ago by cboos

…and with r4050, this should now be done correctly.

I still don't get database locks anymore… :)

The only database error that's still there (rarely) is: ERROR: columns sid, authenticated are not unique, which is a well known issue and not that critical (see #3563).

comment:24 Changed 8 years ago by cboos

(and now I'll take a break, some sleep etc., as I realized that r4048 was OK; r4050 only moves the session.save after the post-processing, which is of course a bit better but wasn't that critical ;) )

comment:25 follow-up: Changed 8 years ago by ThurnerRupert <rupert.thurner@…>

  • Resolution set to fixed
  • Status changed from reopened to closed

we upgraded recently and we do not experience lock errors any more. before there was one lock error every 5-10 minutes caused by the company search engine spidering the trac instance.

comment:26 Changed 8 years ago by cboos

  • Resolution fixed deleted
  • Status changed from closed to reopened

Thanks very much for the feedback, but I've left the issue opened as a reminder for me to backport it to 0.10-stable, as currently this is only fixed in trunk.

comment:27 in reply to: ↑ 25 Changed 8 years ago by cboos

  • Resolution set to fixed
  • Status changed from reopened to closed

r4048 was adapted for 0.10-stable in r4171.

Replying to ThurnerRupert <rupert.thurner@gmail.com>:

we upgraded recently and we do not experience lock errors any more. before there was one lock error every 5-10 minutes caused by the company search engine spidering the trac instance.

and this is probably due to r3830, ported in r3910.

comment:28 Changed 6 years ago by phil.taylor@…

We just experienced the problem with version 0.11.1 - it went away after a few minutes.

comment:29 follow-up: Changed 6 years ago by anonymous

  • Resolution fixed deleted
  • Status changed from closed to reopened

We have started experiencing this in 0.10.4 as of a few days ago. What gives?

comment:30 in reply to: ↑ 29 Changed 6 years ago by eblot

  • Resolution set to fixed
  • Status changed from reopened to closed

Replying to anonymous:

We have started experiencing this in 0.10.4 as of a few days ago. What gives?

Options are:

  • move to 0.11.2,
  • move to fastcgi, instead of mod_python,
  • move to PostgreSQL,

and read MostFrequentDuplicates

comment:31 Changed 5 years ago by anonymous

We just experienced the problem with version 0.11.5. Can anyone give a way to relock the database? If the lock is not release,will trac work well without any problems?

comment:32 follow-up: Changed 5 years ago by cboos

The database is locked issue is nearly always a transient issue. If so, the problem is believed to be fixed now (#3446), so you could upgrade to 0.11.6dev (see TracDownload#Tracstable).

But are you saying that you have a persistent lock, i.e. that the database stays locked, even after a restart of the server?

comment:33 in reply to: ↑ 32 Changed 5 years ago by anonymous

Replying to cboos:

The database is locked issue is nearly always a transient issue. If so, the problem is believed to be fixed now (#3446), so you could upgrade to 0.11.6dev (see TracDownload#Tracstable).

But are you saying that you have a persistent lock, i.e. that the database stays locked, even after a restart of the server?

Thank you for replying. It was a transient issue and now it work well again.but I will upgrade the trac when possible.

comment:34 follow-up: Changed 5 years ago by patrick232@…

I have got this error running Trac 0.12multirepos-r8178 on a virtual machine (Virtualbox 3.1.4) where the trac-db was mounted (cifs) from a machine running Vista.

Solved the problem by copying the db into the virtual-machine's filesystem.

comment:35 Changed 4 years ago by anonymous

Today we had this issue on TRAC 0.11.7. It wasn't permanent though.

comment:36 Changed 4 years ago by anonymous

4 years and counting. This bug is so annoying.

Why not just work around it, by quietly re-trying the request??

comment:37 follow-up: Changed 4 years ago by cboos

Well, this exception has become very … exceptional, these days. If you're seeing that frequently, then I'm pretty confident you're not running a recent version of Trac, PySqlite or SQLite.

comment:38 in reply to: ↑ 34 Changed 4 years ago by anonymous

Replying to patrick232@…:

I have got this error running Trac 0.12multirepos-r8178 on a virtual machine (Virtualbox 3.1.4) where the trac-db was mounted (cifs) from a machine running Vista.

Solved the problem by copying the db into the virtual-machine's filesystem.

it appears using nobrl option in mount.cifs solves the problem.

comment:39 in reply to: ↑ 37 Changed 4 years ago by alexander.papaspyrou@…

Replying to cboos:

Well, this exception has become very … exceptional, these days. If you're seeing that frequently, then I'm pretty confident you're not running a recent version of Trac, PySqlite or SQLite.

Hm, not sure. I am using quite recent versions (over apache2 and mod_python):

[ ~ ]
alexp@forge:0<!534,j0>$ dpkg -l | grep trac
ii  trac  0.11.7-1  Enhanced wiki and issue tracking system for 

[ ~ ]
alexp@forge:0<!535,j0>$ cat /etc/lsb-release 
DISTRIB_ID=Ubuntu
DISTRIB_RELEASE=10.04
DISTRIB_CODENAME=lucid
DISTRIB_DESCRIPTION="Ubuntu 10.04.1 LTS"

and

Python 2.6.5 (r265:79063, Apr 16 2010, 13:09:56) 
[GCC 4.4.3] on linux2
Type "help", "copyright", "credits" or "license" for more information.
>>> import trac.db.sqlite_backend as test
>>> test._ver
(3, 6, 22)
>>> test.have_pysqlite
2
>>> test.sqlite.version
'2.5.5'
>>>

Accessing the login page constantly (even over apache2 restarts)

Traceback (most recent call last):
  File "/usr/lib/python2.6/dist-packages/trac/web/api.py", line 376, in send_error
    'text/html')
  File "/usr/lib/python2.6/dist-packages/trac/web/chrome.py", line 733, in render_template
    message = req.session.pop('chrome.%s.%d' % (type_, i))
  File "/usr/lib/python2.6/dist-packages/trac/web/api.py", line 195, in __getattr__
    value = self.callbacks[name](self)
  File "/usr/lib/python2.6/dist-packages/trac/web/main.py", line 265, in _get_session
    return Session(self.env, req)
  File "/usr/lib/python2.6/dist-packages/trac/web/session.py", line 161, in __init__
    self.promote_session(sid)
  File "/usr/lib/python2.6/dist-packages/trac/web/session.py", line 248, in promote_session
    db.commit()
OperationalError: database is locked

Same in the logs. The only thing that comes up to my mind is that the trac environments live on an NFS share…

Thoughts? -Alexander

comment:40 Changed 4 years ago by anonymous

It still occur every day! even after upraded to latest version(Trac 0.13dev-r10406) :(

2011-01-06 17:35:09,572 Trac[main] ERROR: Internal Server Error: 
Traceback (most recent call last):
  File "build\bdist.win32\egg\trac\web\main.py", line 447, in _dispatch_request
    dispatcher.dispatch(req)
  File "build\bdist.win32\egg\trac\web\main.py", line 201, in dispatch
    req.session.save()
  File "build\bdist.win32\egg\trac\web\session.py", line 140, in save
    """, (mintime,))
  File "build\bdist.win32\egg\trac\db\api.py", line 140, in __exit__
    self.db.commit()
OperationalError: database is locked

why not keep session in memory? main trac use enviroment is small team, I think.

comment:41 follow-ups: Changed 4 years ago by anonymous

  • Milestone changed from 0.10.1 to 0.13
  • Resolution fixed deleted
  • Status changed from closed to reopened

It still occur every day! even after upraded to latest version(Trac 0.13dev-r10406) :(

is it a mission impossible ?

comment:42 in reply to: ↑ 41 Changed 4 years ago by cboos

Replying to anonymous:

It still occur every day! even after upraded to latest version(Trac 0.13dev-r10406) :(

is it a mission impossible ?

It all depends on you… and whether you're responsive to our requests for feedback or not. Let's see.

Please give us at least the following information:

  • version information for Python, the PySqlite bindings and SQLite itself
  • which platform, which web front-end (+ version information when relevant)
  • on what kind of filesystem is the <tracenv>/db/trac.db file located? Same question for /tmp (if you're on Unix)?
  • are you using any Trac plugins? does the problem also happen when you try without any plugin enabled?

And also:

  • how many users? what is the estimate of the number of concurrent requests when a lock happens? (you can add timing information in the Trac log, if you can't gather this information from the web server logs, see TracLogging)
  • post a typical backtrace
  • does the problem happens for any kind of request, or just some actions?
  • do you have a reproduction scenario?

comment:43 Changed 4 years ago by cboos

  • Resolution set to fixed
  • Status changed from reopened to closed

… right.

comment:44 Changed 4 years ago by kokushibyou@…

We started seeing this problem recently, once we moved TRAC from a Netapp to a Hitachi SAN. That was literally the only difference.

Hitachi deals with file locks in a very different way then Netapp, which the Trac db doesn't seem to like.

If you can properly lock the file on writes, or leave it on local disk, you should not run into these problems any further.

comment:45 in reply to: ↑ 41 Changed 2 years ago by cboos

  • Milestone changed from 1.0 to 0.10.1

restoring original milestone

Add Comment

Modify Ticket

Change Properties
<Author field>
Action
as closed The owner will remain cboos.
The resolution will be deleted. Next status will be 'reopened'.
to The owner will be changed from cboos to the specified user.
Author


E-mail address and user name can be saved in the Preferences.

 
Note: See TracTickets for help on using tickets.