[egenix-users] Invalid cursor state

[Dan Fairs]

Hi,

We're experiencing intermittent problems using the mxODBCZopeDA  
connecting to a SQL Server database. Every so often (in our  
development environments), we'll see tracebacks that look like this:

Site Error
An error was encountered while publishing this resource.

mx.ODBC.Error.InternalError

Sorry, a site error occurred.

Traceback (innermost last):

	• Module ZPublisher.Publish, line 202, in publish_module_standard
	• Module ZPublisher.Publish, line 150, in publish
	• Module ZPublisher.Publish, line 119, in publish
	• Module ZPublisher.mapply, line 88, in mapply
	• Module ZPublisher.Publish, line 42, in call_object
	• Module webui.browser.repositoriesui.base, line 28, in __call__
	• Module webui.browser.repositoriesui.repositories, line 43, in update
	• Module webui.browser.repositoriesui.base, line 251, in getAssessments
	• Module app.directdb.loaders, line 124, in repositories
	• Module app.db._db, line 86, in execute
	• Module app.db._db, line 119, in _execute
	• Module Shared.DC.ZRDB.DA, line 500, in __call__
<FSZSQLMethod at /root/zsql/direct/s_Repositories>
	• Module Products.mxODBCZopeDA.ZopeDA, line 1503, in query
	• Module Products.mxODBCZopeDA.ZopeDA, line 1400, in  
run_cursor_callback
	• Module Products.mxODBCZopeDA.ZopeDA, line 999, in errorhandler
InternalError: ('24000', 0, '[unixODBC][FreeTDS][SQL Server]Invalid  
cursor state', 4543)

Once this has happened, refreshing the page consistently returns the  
same error. Other pages in the site (which use other FSZSQLMethods  
using the same ZopeDA instance in the ZODB) continue to work fine - so  
the problem appears to be bound to a particular FSZSQLMethod.  
Restarting Zope makes the problem go away temporarily. The problem may  
recur quickly, or it may take days to appear again.

When we load a page that provokes the error, while running SQL  
Profiler on the database server, we can see the SQL generated by the  
ZSQL method arrive and appear to be served correctly. I've turned on  
tracing in /etc/odbcinst.ini (though of course, since I've done that I  
can't provoke the error! I'll attach a trace log when I get one.)

We know that the SQL that is being run is valid - we can copy it out  
of Profiler and run it in Management Studio; and besides, the page  
usually works flawlessly. The ZSQL method itself has no caching  
specified. All FSZSQLMethods live in FileSystemDirectoryViews, and are  
invoked directly from trusted Python code (ie. not a skin script).

We're using the following software versions (from Ubuntu's package  
manager):

unixODBC 2.2.11-16build2
tdsodbc 0.82-3ubuntu1
Zope 2.10.4 (built using buildout and sources, not Ubuntu packages)
mxODBCZopeDA-1.0.10
SQL Server 2005 Developer (also happens on SQL Server 2008 Express)
Zope server is Ubuntu 8.10, though this also happens with 9.04.
Python 2.4.5 (built from source)

The DA is configured with the following parameters:

ODBC Driver Manager: unixODBC
Connection pool size: 25
All connection options set to 'off'
Connection state - 'Open Connection' is checked.

We don't see anything in the logs on the SQL Server side.

I'm not sure where to look next, or what further tests to carry out in  
order to debug this further. The query does appear to be running  
correctly (with both BatchStarting and BatchCompleted entries in SQL  
Profiler).

Has anyone seen something like this before, or have any idea what to  
look at when it starts happening again?

Many thanks,
Dan
--
Dan Fairs <dan.fairs at gmail.com> | http://www.fezconsulting.com/