Happening on new repository after initial subversion activity

[airbaggins@…]

I have just installed a new trac and configured it. But I keep getting the following error:

Oops...

Trac detected an internal error:

database is locked
Traceback (most recent call last):
  File "/usr/lib/python2.3/site-packages/trac/core.py", line 531, in cgi_start
    real_cgi_start()
  File "/usr/lib/python2.3/site-packages/trac/core.py", line 526, in real_cgi_start
    dispatch_request(path_info, args, req, env)
  File "/usr/lib/python2.3/site-packages/trac/core.py", line 433, in dispatch_request
    req.session = Session.Session(env, req, newsession)
  File "/usr/lib/python2.3/site-packages/trac/Session.py", line 51, in __init__
    self.get_session(sid)
  File "/usr/lib/python2.3/site-packages/trac/Session.py", line 107, in get_session
    " WHERE sid=%s", self.sid)
  File "/usr/lib/python2.3/site-packages/sqlite/main.py", line 237, in execute
    self.con._begin()
  File "/usr/lib/python2.3/site-packages/sqlite/main.py", line 508, in _begin
    self.db.execute("BEGIN")
OperationalError: database is locked

I know that my fsfs subversion repository is verified, good and not locked. While the page is loading, the trac.db-journal file appears. I cannot work out why it would compain about being locked.

​http://www.hobbiton.cjb.net/cgi-bin/trac.cgi

[metadev at gmail dot com]

I have the same problem when running under a custom user. The error doesn't appear when trac.cgi is running as root.

(The trac repository is properly owned.)

I am increasing the severity and the priority of this ticket because it prevents usage on production environments.

[Matthew Good]

If the problem occurs as one user, but not as root it's certainly a problem with your directory permissions. Please ask on the MailingList or IrcChannel for help resolving this.

[NumaanHuq@…]

I've the same problem as described above. Since Friday (Oct 14, 2005)I've been running TRAC as www-data.staff and it worked fine and correctly. We continued to checkin/checkout our data into subversion and made NO changes to TRAC whatsoever. We got the database is locked error totally out of the blues. It was working one minute and the next minute the entire system just froze up. We can use the Wiki and the ticket system but as soon as we try to access the Browse Source the trac.cgi script (seen from top) gets hold of 99.9% CPU time and keeps on processing infinitely. We've determined that trac is opening the svn repository, reading it, closing it, opening the svn repository, reading it, closing it… infinitely. Thank you.

Numaan

Traceback (most recent call last):

File "/usr/lib/python2.3/site-packages/trac/core.py", line 531, in cgi_start

real_cgi_start()

File "/usr/lib/python2.3/site-packages/trac/core.py", line 513, in real_cgi_start

env = open_environment()

File "/usr/lib/python2.3/site-packages/trac/core.py", line 190, in open_environment

version = env.get_version()

File "/usr/lib/python2.3/site-packages/trac/Environment.py", line 162, in get_version

cursor.execute("SELECT value FROM system WHERE name='database_version'")

File "/usr/lib/python2.3/site-packages/sqlite/main.py", line 244, in execute

self.rs = self.con.db.execute(SQL)

OperationalError: database is locked

[NumaanHuq@…]

Further information to help in figuring out this process. I took snippet of the strace dump for the trac.cgi process:

open("/home/numaanh/repo/db/revs/1", O_RDONLY) = 9 lseek(9, 202638419, SEEK_SET) = 202638419 read(9, "id: 6xa.0.r1/202638419\ntype: fil"…, 4096) = 4096 close(9) = 0 _llseek(3, 371162112, [371162112], SEEK_SET) = 0 write(3, "\363\207\5\0\10\0\264\3\337\207\5\0\4\0\240\0\0\0\205\0"…, 1024) = 1024 open("/home/numaanh/repo/db/revs/75", O_RDONLY) = 9 lseek(9, 160327295, SEEK_SET) = 160327295 read(9, "id: 6tx.u.r75/160327295\ntype: di"…, 4096) = 4096 close(9) = 0 open("/home/numaanh/repo/db/revs/1", O_RDONLY) = 9 lseek(9, 202638745, SEEK_SET) = 202638745 read(9, "id: 6xb.0.r1/202638745\ntype: fil"…, 4096) = 4096 close(9) = 0 open("/home/numaanh/repo/db/revs/1", O_RDONLY) = 9 lseek(9, 202638703, SEEK_SET) = 202638703 read(9, "PLAIN\nK 14\nsvn:executable\nV 0\n\nE"…, 4096) = 4096 close(9) = 0 open("/home/numaanh/repo/db/revs/1", O_RDONLY) = 9 lseek(9, 202638745, SEEK_SET) = 202638745 read(9, "id: 6xb.0.r1/202638745\ntype: fil"…, 4096) = 4096 close(9) = 0 open("/home/numaanh/repo/db/revs/75", O_RDONLY) = 9 lseek(9, 160327295, SEEK_SET) = 160327295 read(9, "id: 6tx.u.r75/160327295\ntype: di"…, 4096) = 4096 close(9) = 0 open("/home/numaanh/repo/db/revs/1", O_RDONLY) = 9 lseek(9, 202639067, SEEK_SET) = 202639067 read(9, "id: 6xc.0.r1/202639067\ntype: fil"…, 4096) = 4096 close(9) = 0 open("/home/numaanh/repo/db/revs/1", O_RDONLY) = 9 lseek(9, 202639025, SEEK_SET) = 202639025 read(9, "PLAIN\nK 14\nsvn:executable\nV 0\n\nE"…, 4096) = 4096 close(9) = 0 open("/home/numaanh/repo/db/revs/1", O_RDONLY) = 9 lseek(9, 202639067, SEEK_SET) = 202639067 read(9, "id: 6xc.0.r1/202639067\ntype: fil"…, 4096) = 4096 close(9) = 0 open("/home/numaanh/repo/db/revs/75", O_RDONLY) = 9 lseek(9, 160327295, SEEK_SET) = 160327295 read(9, "id: 6tx.u.r75/160327295\ntype: di"…, 4096) = 4096 close(9) = 0 open("/home/numaanh/repo/db/revs/1", O_RDONLY) = 9 lseek(9, 202639390, SEEK_SET) = 202639390 read(9, "id: 6xd.0.r1/202639390\ntype: fil"…, 4096) = 4096 close(9) = 0 open("/home/numaanh/repo/db/revs/1", O_RDONLY) = 9 lseek(9, 202639348, SEEK_SET) = 202639348 read(9, "PLAIN\nK 14\nsvn:executable\nV 0\n\nE"…, 4096) = 4096 close(9) = 0 open("/home/numaanh/repo/db/revs/1", O_RDONLY) = 9 lseek(9, 202639390, SEEK_SET) = 202639390 read(9, "id: 6xd.0.r1/202639390\ntype: fil"…, 4096) = 4096 close(9) = 0 open("/home/numaanh/repo/db/revs/75", O_RDONLY) = 9 lseek(9, 160327295, SEEK_SET) = 160327295 read(9, "id: 6tx.u.r75/160327295\ntype: di"…, 4096) = 4096 close(9) = 0 open("/home/numaanh/repo/db/revs/1", O_RDONLY) = 9 lseek(9, 202639709, SEEK_SET) = 202639709 read(9, "id: 6xe.0.r1/202639709\ntype: fil"…, 4096) = 4096 close(9) = 0 open("/home/numaanh/repo/db/revs/1", O_RDONLY) = 9 lseek(9, 202639667, SEEK_SET) = 202639667 read(9, "PLAIN\nK 14\nsvn:executable\nV 0\n\nE"…, 4096) = 4096 close(9) = 0 open("/home/numaanh/repo/db/revs/1", O_RDONLY) = 9 lseek(9, 202639709, SEEK_SET) = 202639709 read(9, "id: 6xe.0.r1/202639709\ntype: fil"…, 4096) = 4096 close(9) = 0 open("/home/numaanh/repo/db/revs/75", O_RDONLY) = 9 lseek(9, 160327295, SEEK_SET) = 160327295 read(9, "id: 6tx.u.r75/160327295\ntype: di"…, 4096) = 4096 close(9) = 0 open("/home/numaanh/repo/db/revs/1", O_RDONLY) = 9 lseek(9, 202640031, SEEK_SET) = 202640031 read(9, "id: 6xf.0.r1/202640031\ntype: fil"…, 4096) = 4096 close(9) = 0 open("/home/numaanh/repo/db/revs/1", O_RDONLY) = 9 lseek(9, 202639989, SEEK_SET) = 202639989 read(9, "PLAIN\nK 14\nsvn:executable\nV 0\n\nE"…, 4096) = 4096 close(9) = 0 open("/home/numaanh/repo/db/revs/1", O_RDONLY) = 9 lseek(9, 202640031, SEEK_SET) = 202640031 read(9, "id: 6xf.0.r1/202640031\ntype: fil"…, 4096) = 4096 close(9) = 0 open("/home/numaanh/repo/db/revs/75", O_RDONLY) = 9 lseek(9, 160327295, SEEK_SET) = 160327295 read(9, "id: 6tx.u.r75/160327295\ntype: di"…, 4096) = 4096 close(9) = 0 open("/home/numaanh/repo/db/revs/1", O_RDONLY) = 9 lseek(9, 202640353, SEEK_SET) = 202640353 read(9, "id: 6xg.0.r1/202640353\ntype: fil"…, 4096) = 4096 close(9) = 0 open("/home/numaanh/repo/db/revs/1", O_RDONLY) = 9 lseek(9, 202640311, SEEK_SET) = 202640311 read(9, "PLAIN\nK 14\nsvn:executable\nV 0\n\nE"…, 4096) = 4096 close(9) = 0 open("/home/numaanh/repo/db/revs/1", O_RDONLY) = 9 lseek(9, 202640353, SEEK_SET) = 202640353 read(9, "id: 6xg.0.r1/202640353\ntype: fil"…, 4096) = 4096 close(9) = 0 _llseek(3, 371184640, [371184640], SEEK_SET) = 0 write(3, "\t\210\5\0\10\0\304\3\365\207\5\0\4\0\214\0\0\0r\0\200"…, 1024) = 1024 open("/home/numaanh/repo/db/revs/75", O_RDONLY) = 9 lseek(9, 160327295, SEEK_SET) = 160327295 read(9, "id: 6tx.u.r75/160327295\ntype: di"…, 4096) = 4096 close(9) = 0 open("/home/numaanh/repo/db/revs/1", O_RDONLY) = 9 lseek(9, 202640674, SEEK_SET) = 202640674 read(9, "id: 6xh.0.r1/202640674\ntype: fil"…, 4096) = 4096 close(9) = 0 open("/home/numaanh/repo/db/revs/1", O_RDONLY) = 9 lseek(9, 202640632, SEEK_SET) = 202640632 read(9, "PLAIN\nK 14\nsvn:executable\nV 0\n\nE"…, 4096) = 4096 close(9) = 0 open("/home/numaanh/repo/db/revs/1", O_RDONLY) = 9 lseek(9, 202640674, SEEK_SET) = 202640674 read(9, "id: 6xh.0.r1/202640674\ntype: fil"…, 4096) = 4096 close(9) = 0 open("/home/numaanh/repo/db/revs/75", O_RDONLY) = 9 lseek(9, 160327295, SEEK_SET) = 160327295 read(9, "id: 6tx.u.r75/160327295\ntype: di"…, 4096) = 4096Process 5418 detached

[Christian Boos]

Hard to say what's going on here… It's maybe a bug while doing the resync. The repository doesn't seem to be big, any chance you could provide us the repository dump?

Also, you could try to upgrade to 0.9 to see if the problem persist (see TracDownload), as anyway there's little chance there will be another 0.8 release (except for security fixes, I guess).

[NumaanHuq@…]

The current repository is about a 1GB+. I'm sorry but unfortunately I can't give you a repository dump because the code is proprietary. We will upgrade to 0.9 and try and replicate the problem.

[NumaanHuq@…]

We've upgraded to the latest TRAC release 0.9beta2 and the problem has disappeared. We suspected that the database might have been corrupted in some way but that doesn't seem to be the problem. Hop e you guys succeed in killing this bug. I'll lower the priority on this bug.

[Christopher Lenz]

So it seems like this is either fixed or was a user error.

[Christian Boos]

… and in general, the situation with database locks with SQLite should be much improved since the 0.9 release.

[peter.yamamoto@…]

We just finished setting up subversion+trac under Windows XP Pro+Apache. First day we could browse source, no reports of this error. After an intensive week of populating the subversion repository, now trac is reporting this error on "login", "source browser", and now even when trying to access the home page. On install, I made two users admin users, everybody else was default. Is this still a problem or is this error also symptomatic of something else?

[Christian Boos]

peter, what's the status about this, do you still have the problem? If yes, when this happens, is the database lock persistent (i.e. all subsequent requests also fail with this error), or does the problem only happen occasionally?

Plus, what PySqlite version are you using?

[Christian Boos]

See #3446 and #3503.

Possibly also related to #1661, which is the one which would have to be reopened if persistent locks (i.e. locks that require a server restart) happen again.