Warning: Can't synchronize with repository "(default)" (Unsupported version control system "svn": No module named svn). Look in the Trac log for more information.

Ticket #249 (closed defect: fixed)

Opened 12 years ago

Last modified 10 years ago

Catwalk permanently locks the database when attached.

Reported by: matt.bevan@… Owned by: anonymous
Priority: normal Milestone: 0.9
Component: Toolbox Version:
Severity: blocker Keywords: develix
Cc: mail@…

Description

CatWalk seems to have an unbalanced hub.begin()/hub.commit() pair which is causing my database to become permanantly locked. For example, if I define a DB called sqlite:///home/mbevan/database.db, define a simple model, and attach CatWalk to my application in the following way, running ./myapp-start.py creates a database.db.journal file and leaves it there.

class Root(controllers.Root):
	import model
	from turbogears.catwalk import CatWalk
	catwalk = CatWalk(model, allowedHosts=['127.0.0.1'])
	... 

Resulting in the following traceback:

                     CatWalk fail to load your model file,
                     If you are mounting CatWalk to your controller remember
                     to import your model and pass a reference to it

2005/12/21 13:06:31 CONFIG INFO Server parameters:
2005/12/21 13:06:31 CONFIG INFO   server.environment: development
2005/12/21 13:06:31 CONFIG INFO   server.logToScreen: True
2005/12/21 13:06:31 CONFIG INFO   server.logFile:
2005/12/21 13:06:31 CONFIG INFO   server.protocolVersion: HTTP/1.0
2005/12/21 13:06:31 CONFIG INFO   server.socketHost:
2005/12/21 13:06:31 CONFIG INFO   server.socketPort: 8080
2005/12/21 13:06:31 CONFIG INFO   server.socketFile:
2005/12/21 13:06:31 CONFIG INFO   server.reverseDNS: False
2005/12/21 13:06:31 CONFIG INFO   server.socketQueueSize: 5
2005/12/21 13:06:31 CONFIG INFO   server.threadPool: 0
2005/12/21 13:06:31 HTTP INFO Serving HTTP on http://localhost:8080/
2005/12/21 13:06:39 HTTP INFO 127.0.0.1 - GET / HTTP/1.1
2005/12/21 13:06:39  INFO Traceback (most recent call last):
  File "/usr/lib64/python2.4/site-packages/CherryPy-2.1.0-py2.4.egg/cherrypy/_cphttptools.py", line 271, in run
    main()
  File "/usr/lib64/python2.4/site-packages/CherryPy-2.1.0-py2.4.egg/cherrypy/_cphttptools.py", line 502, in main
    body = page_handler(*args, **cherrypy.request.paramMap)
  File "/usr/lib64/python2.4/site-packages/TurboGears-0.9a0dev_r352-py2.4.egg/turbogears/controllers.py", line 196, in newfunc
    html, *args, **kw)
  File "/usr/lib64/python2.4/site-packages/TurboGears-0.9a0dev_r352-py2.4.egg/turbogears/database.py", line 174, in run_with_transaction
    retval = func(*args, **kw)
  File "/usr/lib64/python2.4/site-packages/TurboGears-0.9a0dev_r352-py2.4.egg/turbogears/controllers.py", line 222, in _execute_func
    output = func(self, *args, **kw)
  File "/home/mbevan/Projects/Top-Floor-Website/topfloor/controllers.py", line 40, in index
  File "/usr/lib64/python2.4/site-packages/TurboGears-0.9a0dev_r352-py2.4.egg/turbogears/controllers.py", line 199, in newfunc
    tg_format, html, *args, **kw)
  File "/usr/lib64/python2.4/site-packages/TurboGears-0.9a0dev_r352-py2.4.egg/turbogears/controllers.py", line 222, in _execute_func
    output = func(self, *args, **kw)
  File "/home/mbevan/Projects/Top-Floor-Website/topfloor/controllers.py", line 16, in index
  File "/usr/lib64/python2.4/site-packages/TurboGears-0.9a0dev_r352-py2.4.egg/turbogears/controllers.py", line 199, in newfunc
    tg_format, html, *args, **kw)
  File "/usr/lib64/python2.4/site-packages/TurboGears-0.9a0dev_r352-py2.4.egg/turbogears/controllers.py", line 222, in _execute_func
    output = func(self, *args, **kw)
  File "/home/mbevan/Projects/Top-Floor-Website/topfloor/controllers.py", line 20, in view
    turbogears.flash("This is a test flash message.  Real errors would be more worrying.")
  File "/usr/lib64/python2.4/site-packages/SQLObject-0.7.0-py2.4.egg/sqlobject/inheritance/__init__.py", line 161, in get
    val = super(InheritableSQLObject, cls).get(id, connection, selectResults)
  File "/usr/lib64/python2.4/site-packages/SQLObject-0.7.0-py2.4.egg/sqlobject/main.py", line 908, in get
    val._init(id, connection, selectResults)
  File "/usr/lib64/python2.4/site-packages/SQLObject-0.7.0-py2.4.egg/sqlobject/main.py", line 944, in _init
    selectResults = self._connection._SO_selectOne(self, dbNames)
  File "/usr/lib64/python2.4/site-packages/SQLObject-0.7.0-py2.4.egg/sqlobject/dbconnection.py", line 565, in _SO_selectOne
    return self.queryOne(
  File "/usr/lib64/python2.4/site-packages/SQLObject-0.7.0-py2.4.egg/sqlobject/dbconnection.py", line 740, in queryOne
    return self._dbConnection._queryOne(self._connection, s)
  File "/usr/lib64/python2.4/site-packages/SQLObject-0.7.0-py2.4.egg/sqlobject/dbconnection.py", line 339, in _queryOne
    self._executeRetry(conn, c, s)
  File "/usr/lib64/python2.4/site-packages/SQLObject-0.7.0-py2.4.egg/sqlobject/dbconnection.py", line 295, in _executeRetry
    return cursor.execute(query)
  File "/usr/lib64/python2.4/site-packages/sqlite/main.py", line 244, in execute
    self.rs = self.con.db.execute(SQL)
OperationalError: database is locked

127.0.0.1 - - [2005/12/21 13:06:39] "GET / HTTP/1.1" 500 3878

I am using the latest SVN checkout - revision 352? - the version from this morning at 9:00am, that is.

Change History

comment:1 Changed 12 years ago by florian

I've got the same problem using r385

comment:2 Changed 12 years ago by bbockelm@…

  • Cc matt.bevan@… added
  • Summary changed from CatWalk permanantly locks the database when attached. to Catwalk permanently locks the database when attached.

The warning on the top of the traceback means that catwalk hasn't been able to find your model. This is probably the root of your problem - is Turbogears configured to look at the correct database? I've had that happen to me before.

I haven't been able to recreate this problem. Could you archive your setup, and attach it to the ticket? I'll give it a whirl.

comment:3 Changed 12 years ago by slate

I have the same with r428. Ubuntu linux 5.10, sqlite2. -- I have set up a fresh install and a new quickstart project. -- I copy-pasted the survey model from modeldesigner into model.py (imported DateTime? from mx) -- tg-admin shell works ok, s=Survey(name="asd",description="sdfdsf") works. -- If I try to access Answer entity, I get the following traceback

Running server on port 7654. 2005/12/30 13:28:55 CONFIG INFO Server parameters: 2005/12/30 13:28:55 CONFIG INFO server.environment: development 2005/12/30 13:28:55 CONFIG INFO server.logToScreen: True 2005/12/30 13:28:55 CONFIG INFO server.logFile: 2005/12/30 13:28:55 CONFIG INFO server.protocolVersion: HTTP/1.0 2005/12/30 13:28:55 CONFIG INFO server.socketHost: 2005/12/30 13:28:55 CONFIG INFO server.socketPort: 7654 2005/12/30 13:28:55 CONFIG INFO server.socketFile: 2005/12/30 13:28:55 CONFIG INFO server.reverseDNS: False 2005/12/30 13:28:55 CONFIG INFO server.socketQueueSize: 5 2005/12/30 13:28:55 CONFIG INFO server.threadPool: 0 2005/12/30 13:28:55 HTTP INFO Serving HTTP on  http://localhost:7654/ 2005/12/30 13:28:58 HTTP INFO 127.0.0.1 - GET /catwalk/columns?objectName=Answer HTTP/1.1 2005/12/30 13:28:58 INFO Traceback (most recent call last):

File "/usr/lib/python2.4/site-packages/CherryPy-2.1.0-py2.4.egg/cherrypy/_cphttptools.py", line 271, in run

main()

File "/usr/lib/python2.4/site-packages/CherryPy-2.1.0-py2.4.egg/cherrypy/_cphttptools.py", line 502, in main

body = page_handler(*args, cherrypy.request.paramMap)

File "/usr/lib/python2.4/site-packages/TurboGears-0.9a0dev_r428-py2.4.egg/turbogears/controllers.py", line 242, in newfunc

html, *args, kw)

File "/usr/lib/python2.4/site-packages/TurboGears-0.9a0dev_r428-py2.4.egg/turbogears/database.py", line 189, in run_with_transaction

retval = func(*args, kw)

File "/usr/lib/python2.4/site-packages/TurboGears-0.9a0dev_r428-py2.4.egg/turbogears/controllers.py", line 259, in _execute_func

output = func(self, *args, kw)

File "/usr/lib/python2.4/site-packages/TurboGears-0.9a0dev_r428-py2.4.egg/turbogears/toolbox/catwalk/init.py", line 988, in columns

columns=self.object_columns(objectName),

File "/usr/lib/python2.4/site-packages/TurboGears-0.9a0dev_r428-py2.4.egg/turbogears/toolbox/catwalk/init.py", line 497, in object_columns

cols = self.get_columns_for_object(object)

File "/usr/lib/python2.4/site-packages/TurboGears-0.9a0dev_r428-py2.4.egg/turbogears/toolbox/catwalk/init.py", line 509, in get_columns_for_object

cols.append(self.get_column_properties(column_name,column))

File "/usr/lib/python2.4/site-packages/TurboGears-0.9a0dev_r428-py2.4.egg/turbogears/toolbox/catwalk/init.py", line 471, in get_column_properties

props = self.get_foreign_key_properties(column,props)

File "/usr/lib/python2.4/site-packages/TurboGears-0.9a0dev_r428-py2.4.egg/turbogears/toolbox/catwalk/init.py", line 486, in get_foreign_key_properties

propertieslabelColumn?)

File "/usr/lib/python2.4/site-packages/TurboGears-0.9a0dev_r428-py2.4.egg/turbogears/toolbox/catwalk/init.py", line 345, in foreign_key_alternatives

alt = list(obj.select())

File "/usr/lib/python2.4/site-packages/SQLObject-0.7.0-py2.4.egg/sqlobject/sresults.py", line 149, in iter

return iter(list(self.lazyIter()))

File "/usr/lib/python2.4/site-packages/SQLObject-0.7.0-py2.4.egg/sqlobject/sresults.py", line 157, in lazyIter

return conn.iterSelect(self)

File "/usr/lib/python2.4/site-packages/SQLObject-0.7.0-py2.4.egg/sqlobject/dbconnection.py", line 755, in iterSelect

select, keepConnection=True)))

File "/usr/lib/python2.4/site-packages/SQLObject-0.7.0-py2.4.egg/sqlobject/dbconnection.py", line 687, in init

self.dbconn._executeRetry(self.rawconn, self.cursor, self.query)

File "/usr/lib/python2.4/site-packages/SQLObject-0.7.0-py2.4.egg/sqlobject/dbconnection.py", line 295, in _executeRetry

return cursor.execute(query)

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

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

OperationalError?: database is locked

127.0.0.1 - - [2005/12/30 13:28:58] "GET /catwalk/columns?objectName=Answer HTTP/1.1" 500 3638

comment:4 Changed 12 years ago by slate

Sorry for the malformed entry.

I have the same with r428. Ubuntu linux 5.10, sqlite2.

  • I have set up a fresh install and a new quickstart project.
  • I copy-pasted the survey model from modeldesigner into model.py (imported DateTime?? from mx)
  • tg-admin shell works ok, s=Survey(name="asd",description="sdfdsf") works.
  • If I try to click on Answer entity, I get the following traceback
Running server on port 7654.
2005/12/30 13:28:55 CONFIG INFO Server parameters:
2005/12/30 13:28:55 CONFIG INFO   server.environment: development
2005/12/30 13:28:55 CONFIG INFO   server.logToScreen: True
2005/12/30 13:28:55 CONFIG INFO   server.logFile:
2005/12/30 13:28:55 CONFIG INFO   server.protocolVersion: HTTP/1.0
2005/12/30 13:28:55 CONFIG INFO   server.socketHost:
2005/12/30 13:28:55 CONFIG INFO   server.socketPort: 7654
2005/12/30 13:28:55 CONFIG INFO   server.socketFile:
2005/12/30 13:28:55 CONFIG INFO   server.reverseDNS: False
2005/12/30 13:28:55 CONFIG INFO   server.socketQueueSize: 5
2005/12/30 13:28:55 CONFIG INFO   server.threadPool: 0
2005/12/30 13:28:55 HTTP INFO Serving HTTP on http://localhost:7654/
2005/12/30 13:28:58 HTTP INFO 127.0.0.1 - GET /catwalk/columns?objectName=Answer HTTP/1.1
2005/12/30 13:28:58  INFO Traceback (most recent call last):
  File "/usr/lib/python2.4/site-packages/CherryPy-2.1.0-py2.4.egg/cherrypy/_cphttptools.py", line 271, in run
    main()
  File "/usr/lib/python2.4/site-packages/CherryPy-2.1.0-py2.4.egg/cherrypy/_cphttptools.py", line 502, in main
    body = page_handler(*args, **cherrypy.request.paramMap)
  File "/usr/lib/python2.4/site-packages/TurboGears-0.9a0dev_r428-py2.4.egg/turbogears/controllers.py", line 242, in newfunc
    html, *args, **kw)
  File "/usr/lib/python2.4/site-packages/TurboGears-0.9a0dev_r428-py2.4.egg/turbogears/database.py", line 189, in run_with_transaction
    retval = func(*args, **kw)
  File "/usr/lib/python2.4/site-packages/TurboGears-0.9a0dev_r428-py2.4.egg/turbogears/controllers.py", line 259, in _execute_func
    output = func(self, *args, **kw)
  File "/usr/lib/python2.4/site-packages/TurboGears-0.9a0dev_r428-py2.4.egg/turbogears/toolbox/catwalk/__init__.py", line 988, in columns
    columns=self.object_columns(objectName),
  File "/usr/lib/python2.4/site-packages/TurboGears-0.9a0dev_r428-py2.4.egg/turbogears/toolbox/catwalk/__init__.py", line 497, in object_columns
    cols = self.get_columns_for_object(object)
  File "/usr/lib/python2.4/site-packages/TurboGears-0.9a0dev_r428-py2.4.egg/turbogears/toolbox/catwalk/__init__.py", line 509, in get_columns_for_object
    cols.append(self.get_column_properties(column_name,column))
  File "/usr/lib/python2.4/site-packages/TurboGears-0.9a0dev_r428-py2.4.egg/turbogears/toolbox/catwalk/__init__.py", line 471, in get_column_properties
    props = self.get_foreign_key_properties(column,props)
  File "/usr/lib/python2.4/site-packages/TurboGears-0.9a0dev_r428-py2.4.egg/turbogears/toolbox/catwalk/__init__.py", line 486, in get_foreign_key_properties
    properties['labelColumn'])
  File "/usr/lib/python2.4/site-packages/TurboGears-0.9a0dev_r428-py2.4.egg/turbogears/toolbox/catwalk/__init__.py", line 345, in foreign_key_alternatives
    alt = list(obj.select())
  File "/usr/lib/python2.4/site-packages/SQLObject-0.7.0-py2.4.egg/sqlobject/sresults.py", line 149, in __iter__
    return iter(list(self.lazyIter()))
  File "/usr/lib/python2.4/site-packages/SQLObject-0.7.0-py2.4.egg/sqlobject/sresults.py", line 157, in lazyIter
    return conn.iterSelect(self)
  File "/usr/lib/python2.4/site-packages/SQLObject-0.7.0-py2.4.egg/sqlobject/dbconnection.py", line 755, in iterSelect
    select, keepConnection=True)))
  File "/usr/lib/python2.4/site-packages/SQLObject-0.7.0-py2.4.egg/sqlobject/dbconnection.py", line 687, in __init__
    self.dbconn._executeRetry(self.rawconn, self.cursor, self.query)
  File "/usr/lib/python2.4/site-packages/SQLObject-0.7.0-py2.4.egg/sqlobject/dbconnection.py", line 295, in _executeRetry
    return cursor.execute(query)
  File "/usr/lib/python2.4/site-packages/sqlite/main.py", line 244, in execute
    self.rs = self.con.db.execute(SQL)
OperationalError: database is locked

127.0.0.1 - - [2005/12/30 13:28:58] "GET /catwalk/columns?objectName=Answer HTTP/1.1" 500 3638

comment:5 Changed 12 years ago by anonymous

  • Component changed from SQLObject to Toolbox

comment:6 Changed 12 years ago by slate

tg-admin sql create or catwalk doesn't create catwalk_state_table. appending the following to model.py solves the problem:

class catwalk_state_table(SQLObject):
        state = BLOBCol()

comment:7 Changed 12 years ago by anonymous

  • Milestone set to 0.9

comment:8 Changed 12 years ago by kevin

  • Keywords develix added

comment:9 Changed 12 years ago by joost

I haven't been able replicate this on winx-pro, r518, sqlite3. Anyone else having this problem? CatWalk uses model.hub to create the state table during construction, when it fails it will print the warning message. My best guess is that your model.hub and model.connection aren't pointing to the same resource. Could you attach the whole package?

comment:10 Changed 12 years ago by mail@…

I've had the same problem with a freshly quickstarted project using r556, I had to remove the blanket try: except: around CatWalkState?.createTable but when I did I got the exact same traceback that the others have described. model.hub and model.connection are set to the same value (PackageHub?("packagename")).

comment:11 Changed 12 years ago by ronald@…

Can someone who can reproduce the problem (I can't) check with the latest revision? Revision r558 updated the way CatWalk aquired a connection for the state table, which in theory should fix this issue.

comment:12 Changed 12 years ago by mail@…

Hi Ronald, no this doesn't fix it but nor would I expect it to. The patch you talk about changes the way a connection is acquired if model.hub doesn't exist, but with this bug it does exist -that's not the problem. The problem is in the createTable method which seems to be called in the same way as it was before. It tries to acquire the database but can't because it's locked.

I wondered whether the sqlite threading issues Ian has just fixed were the cause of it:

 http://groups.google.com/group/turbogears/browse_thread/thread/3583b8469f73cb62/bfffd537c7c7320b#bfffd537c7c7320b

i'll try this out later today and post back.

comment:13 Changed 12 years ago by mail@…

the latest sqlobject doesn't fix it either. It seems like the database is already locked when catwalk tries to use it to create its model with a new project, which it does when it's mounted, what else is using the database at this time? I can't really see how it can be a catwalk problem as it has barely had the chance to do anything else before the point where it tries to create the table.

comment:14 Changed 12 years ago by kevin

Mark Ramm was reporting similar problems to me on Saturday (using sqlite2 on ubuntu, and he then upgraded to sqlite3 but was having other problems due to the combination of libraries and command line tools he had or some such).

Do you have visit code on? You could also try adding ?debug=1 to your database URI to see if there are any queries that may be causing contention.

comment:15 Changed 12 years ago by kevin

  • Severity changed from normal to blocker

comment:16 Changed 12 years ago by mail@…

Hi,

I've just tried with a postgres database and the same problem occurs (though postgres seems to wait for whatever other query is blocking the database and so it just hangs on startup - when I ctrl-c I get a trace that shows it's catwalk's createTable that's trying to execute a query). I switched off the visit code and this had no effect. Putting the catwalk model into model.py so it's created on tg-admin sql create solves the problem as with sqlite.

comment:17 Changed 12 years ago by ronald@…

  • Cc mail@… added; matt.bevan@… removed

Jamie, Can you tell me what happen with postgres if you move CatWalkState?.createTable(ifNotExists=True)

from the init method to the index method (line 120 to line 1111)?

TIA.

comment:18 Changed 12 years ago by kevin

This may also be related to #213.

comment:19 Changed 12 years ago by kevin@…

I can replicate this problem with a fresh install of 0.9a1 in Win2K Pro using sqlite3.

I was able to go in to the db using sqlite3.exe and unlock it, but CatWalk just locked it again every time I connected with it.

comment:20 Changed 12 years ago by kevin@…

hmmm...I know that the "database is locked" error in sqlite can be caused when a transaction is started but never committed, and it looks like something similar may be happening in #213, so, yeah, it may be related.

comment:21 Changed 12 years ago by matt.bevan@…

Seems to me that when ever CatWalk attempts to create its tables, it locks the database, and never unlocks. If the table creation code was wrapped in a hub.begin() hub.commit() block...

comment:22 Changed 12 years ago by kevin@…

I created the catwalk_state_table manually and all was well...except that when editing the tg_user table TG complained that I needed to turn identity.on and visit.on to True.

hmmm...

OK next test...I deleted the catwalk_state_table, leaving identity.on and visit.on set to True, and no odd locking occurred.

So is it possible that in order to fix (or at least work around) this problem, you just have to make sure that identity.on=True and visit.on=True???

That doesn't make sense to me, but that appears to be the case.

shrug

comment:23 Changed 12 years ago by anonymous

nevermind...I was apparently smoking big crack last night. Catwalk still locked the database...but because the table was already created it locked the DB when I created my first record...then blocked me when I tried to create a second record.

Looks like the mismatched hub.begin()/hub.commit() isn't just related to table creation code.

comment:24 Changed 12 years ago by ronald@…

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

Checked in a workaround in rev909

Note: See TracTickets for help on using tickets.