New install impossible on Trac 0.13dev/1.0

[Steffen Hoffmann]

I've conducted Trac trunk testing lately and installed TagsPlugin into a fresh environment created and used with Trac ​t:r10850.

The plugin constantly failed to create the required db table tags:

Traceback (most recent call last):
  File "<shortened>/Trac-0.13dev_r10849-py2.6.egg/trac/env.py", line 810, in open_environment
    needs_upgrade = env.needs_upgrade()
  File "<shortened>/Trac-0.13dev_r10849-py2.6.egg/trac/env.py", line 646, in needs_upgrade
    if participant.environment_needs_upgrade(db):
  File "build/bdist.linux-i586/egg/tractags/model.py", line 23, in environment_needs_upgrade
    if self._need_migration(db):
  File "build/bdist.linux-i586/egg/tractags/model.py", line 47, in _need_migration
    db.rollback()
  File "<shortened>/Trac-0.13dev_r10849-py2.6.egg/trac/db/util.py", line 107, in __getattr__
    raise AttributeError
AttributeError:

Note: <shortened> has been edited by myself for traceback readability. The code resides in a virtualenv, but that seems to be unrelated here.

Never seen that before, and especially the empty error looks suspicious.

Not only it renders the whole plugin unusable but consequently leaves ugly traces in Trac itself like 'OperationalError: no such table: tags' everywhere tags are expected, like every wiki page.

Hint: Trac version reference below should be read as 0.13dev.

[Steffen Hoffmann]

I've managed to fix it by removing two similarly placed 'db.rollback()' statements in tractags/model.py.

After reading through ​recent changes reduced to the db handling part of Trac I suspect ​t:r10737 as the root cause for this changed behavior. Interestingly I've seen other places in Trac core, where similar 'db.rollback()' statements got removed for being buggy or obsolete before, i.e. in ​t:r10189.

[Remy Blank]

On trunk, we now have two types of database references:

• Normal (read-write) references (identical to what we had before).
• Read-only references that only allow non-mutating operations.

The latter don't have .commit() or .rollback() methods.

The reference you get in environment_needs_upgrade() is a read-only reference. So the db.rollback() call fails with an AttributeError.

I understand why the rollback() call is there. If the SELECT statement fails, you must roll back (at least on some backends) otherwise all following statements will fail as well.

I would say this is a bug in Trac itself. We remove both .commit() and .rollback() from read-only connections, but only the former can actually mutate the database. So we should really keep .rollback() around for exactly this case.

Would you mind opening a ticket on t.e.o about this? You can assign it to me.

[Steffen Hoffmann]

Replying to rblank:

On trunk, we now have two types of database references:

• Normal (read-write) references (identical to what we had before).
• Read-only references that only allow non-mutating operations.

The latter don't have .commit() or .rollback() methods.

The reference you get in environment_needs_upgrade() is a read-only reference. So the db.rollback() call fails with an AttributeError.

Seen the two different connection typs, but not noticed following implications or checked for the IEnvironmentSetupParticipant method in question. Thanks for the quick, comprehensive explanation.

![...] Would you mind opening a ticket on t.e.o about this? You can assign it to me.

Don't mind at all. Done so in ​t:#10451. Thank you for taking care.

So I'll not try to fix it for the intermediate Trac revisions then, right?

[Remy Blank]

Replying to hasienda:

So I'll not try to fix it for the intermediate Trac revisions then, right?

The issue is only present on current trunk. If you want to be compatible with older versions of trunk, you would have to hack in something. Our policy for trunk (in Trac) is that if you run on trunk, you are able to update to a later trunk, so we don't insert such backward compatibility fixes (unless the issue was present in a stable release as well).

[Steffen Hoffmann]

Replying to rblank:

The issue is only present on current trunk. If you want to be compatible with older versions of trunk, you would have to hack in something.

So may it be.

Our policy for trunk (in Trac) is that ... we don't insert such backward compatibility fixes (unless the issue was present in a stable release as well).

I understand, but I can afford some extra lines in appreciation of Trac trunk even in the current state, using Trac ​r10883 here.

[Steffen Hoffmann]

(In [11041]) TagsPlugin: Prevent AttributeError on environment startup for Trac 0.13dev, refs #9521.

Additionally this broke all environment upgrades for plugins and for Trac core itself, at least as long as the plugin was installed and enabled.

While this might be just a temporary Trac behavior (see Remy Blank's ​comment in ticket #10451), it prevails in trunk for more than a month now - a major headache for early adopters. So I feel like acting now, facing the risk of not fixing it properly.

The logical next step is switching to the recommended procedure of storing explicite db schema versions inside the Trac db like other plugins already do.

[Ryan J Ollos]

netjunki: I saw your comments on IRC, but you logged off before I could reply. I think you need the latest TagsPlugin, at least up to r11041, to address your issue.

(5:09:34 PM) netjunki: I'm getting this error when I try and run an upgrade on my environment: http://pastebin.com/rwaqeKVy
(5:10:21 PM) netjunki: This was happening after restarting trac and doing an upgrade. any help would be much appreciated.
(5:20:56 PM) netjunki: ah I'm just blind… looks like the version of the TagsPlugin I have doesn't like my version of trac...
(5:21:01 PM) netjunki: will have to fix that.

[Benjamin Lau]

Yeah that was definitely the problem. As you saw I actually realized the problem. Just so you know upgrading to the latest trunk version of TagsPlugin did resolve the issue.

Ben

[Ryan J Ollos]

Replying to netjunki:

Yeah that was definitely the problem. As you saw I actually realized the problem. Just so you know upgrading to the latest trunk version of TagsPlugin did resolve the issue.

Ah, good. I wasn't certain from your comment that you knew the issue was fixed in the latest version of TagsPlugin, so just wanted to be sure ;)

[Ryan J Ollos]

Relevant ​post on mailing list.

[Steffen Hoffmann]

(In [11984]) TagsPlugin: Prevent false-positive environment needs upgrade, refs #9521.

Eduard-Cristian Stefan reported issues even after [11041] when using a PostgreSQL backend, but kindly provided a patch too. Thanks for taking care.

[Ryan J Ollos]

The movement of cursor = db.cursor to outside the try/except block stood out while reviewing [11984], because of the cannot operator on closed cursor error that we've experienced in many places, such as #6765. I think your patch is okay, but the following discussion is hopefully relevant and useful in confirming the patch is okay.

Coincidentally, I just experienced this issue yet again while working on #10326. I was seeing the cannot operate on closed cursor error in _create_ordering_table of backlogplugin/0.11/backlog/web_ui.py. I implemented a fix in [11996].

Thus far, I've been led me to the following conclusions. The db object will not be destroyed before the cursor is used if the db object is passed as a parameter. I'm not sure why that is, but that's what I've been observing:

def some_function(db):
   cursor = db.cursor
   try:
       cursor.execute(...
   except:
       cursor.execute(...

However, in this case, the db object may be destroyed before the cursor is used:

def some_member_function(self):
   db = self.env.get_db_cnx()
   cursor = db.cursor
   try:
       cursor.execute(...
   except:
       cursor.execute(...

One way to fix this, which I implemented early on, but I now think is not the best way, is:

def some_member_function(self):
   db = self.env.get_db_cnx()
   try:
       cursor = db.cursor
       cursor.execute(...
   except:
       cursor = db.cursor
       cursor.execute(...

This change fixes the issue because the db object is now utilized within the try/except. You'll see that I took a different route to fixing this in [11996].

Do you agree with my assessment, or do you think it is possible that the db object may be destroyed before the cursor object is used when the db object is passed as a parameter? The possibility of that is my concern, and the reason why I comment on the patch.

[Steffen Hoffmann]

If you use the cursor in try and this causes an exception inside the db backend code, the cursor or at least it's ability to execute further statements could be lost. Consequently the third example is ugly but valid, if not even getting a new connection is required. But I don't think so.

I remember, that especially PostgreSQL has been told to lock connections hard by doing a rollback on error and require to start a new transaction. In fact this has been motivation to handle calls to each environment setup participant in separate transactions these days (see ​T:r11072) in response the the report of this issue in ​T:10451.

#6765 seems like a totally different case, because of the method definition there. The cursor here would have to pass over to the function f, what - as we know by now - doesn't happen.

Regarding [11984]: If the SELECT causes an exception, the following code will not execute. Otherwise we should always have a working cursor in the following try part. And we don't rely on the cursor, just on the connection to be available in corresponding exception handler block.

[Steffen Hoffmann]

Replying to rjollos: ...

This change fixes the issue because the db object is now utilized within the try/except. You'll see that I took a different route to fixing this in [11996].

Yes, but the dangers of using the same cursor at both sides of an unrestricted error handler apply here too.

Do you agree with my assessment, or do you think it is possible that the db object may be destroyed before the cursor object is used when the db object is passed as a parameter? The possibility of that is my concern, and the reason why I comment on the patch.

I have no reason to believe that the db object is damaged or ceases to exist. It could merely be a last resort to re-get a fresh db connection, if you ever encounter issues, that could be traced back to that part of the code.

[Ryan J Ollos]

Replying to hasienda:

Yes, but the dangers of using the same cursor at both sides of an unrestricted error handler apply here too.

This is more complex than I had understood. I'd like to continue the discussion, but I think it would be off-topic for this ticket. Perhaps I can CC you on another ticket where this issue is directly relevant and we can continue the discussion over there (#5552)?

[Steffen Hoffmann]

(In [12069]) TagsPlugin: Re-write db schema setup procedures, refs #9521.

Since early schema change before tags-0.2 in 2006 (see [1750]) this plugins schema check relied on a SELECT raising an exeption for non-existing db table. This has been discussed lately and found to be a flawed approach, that even breaks installations for Trac 0.13dev and ultimately 1.0 too.

Now we introduce the common, recommended approach of tracking plugin db schema versions in Trac db table system, so the table existence test is called one last time, current schema version set, and only this gets checked further on.

This changeset requires a database upgrade.

Old checks could even be finally dropped after the next stable release, because there's likely no pre-tags-0.2 installation left out there, isn't it?

[Steffen Hoffmann]

Finally. Upgrades are backed by unit test as well, so please run them, especially when encountering issues.

As this has been the major show-stopper for TracTags in Trac-1.0 I hope to push the release of tags-0.7 soon. Meanwhile test feedback is highly appreciated.

[Jun Omae]

I think we must not call rollback() from environment_needs_upgrade(). We could use system catalog (e.g. sqlite_master, SHOW TABLES) to check table-existing for all database backends with no transaction.

The patch, t9521-use-system-catalog.diff​, get to remove TagSetup.__init__ and workaround in unit tests for Trac 0.12.x. _get_tables() is from tracmigrateplugin/0.12/tracmigrate/admin.py#L81​.

Unit tests pass on Trac 0.11-stable, 0.12-stable and 1.0 with SQLite. However, the tests fail with PostgreSQL and MySQL caused by some other problems.

[Steffen Hoffmann]

Replying to jun66j5:

I think we must not call rollback() from environment_needs_upgrade(). We could use system catalog (e.g. sqlite_master, SHOW TABLES) to check table-existing for all database backends with no transaction.

Just what I envisioned myself, but I know that personally I lack some SQL foo as well as testbeds for MySQL and PostgreSQL here, so I was reluctant to tackle this on my own. Thus your contribution is very welcomed.

I feel, that we're close to a satisfying solution. So I've started a call for help on the issue, to finish work on this issue: ​https://groups.google.com/d/topic/trac-dev/jL0LbLvEl-M/discussion

[Steffen Hoffmann]

OT: @Jun: Thanks for the hint on TracMigratePlugin. This may come in handy for me later on, sticking to SQLite ATM, but may need to migrate to a more potent db backend with PostgreSQL being the natural choice. Value your contributions a lot, hope, you don't mind me calling for others to review and contribute as well.

[Steffen Hoffmann]

(In [12115]) TagsPlugin: Correct SQL statement and test logic for PostgreSQL, refs #9521.

First own tests with PostgreSQL backend revealed these silly little mistakes, that slipped in when rewriting the code from [11984] for [12069].

[Steffen Hoffmann]

Replying to jun66j5: ...

Unit tests pass on Trac 0.11-stable, 0.12-stable and 1.0 with SQLite. However, the tests fail with PostgreSQL and MySQL caused by some other problems.

Could you provide some instructions how do these tests, please?

[Jun Omae]

Replying to hasienda:

Could you provide some instructions how do these tests, please?

1. Setup PostgreSQL and MySQL database for test. See ​trac:browser:trunk/doc/dev/testing-database.rst
2. Run test with each Trac version and each database backend. Examples:

   $ TRAC_TEST_DB_URI=postgres://tracuser:password@localhost:5432/trac?schema=tractest python setup.py test
   $ TRAC_TEST_DB_URI=mysql://tracuser:password@localhost/tractest python setup.py test
   $ TRAC_TEST_DB_URI= python setup.py test
   

	SQLite	PostgreSQL	MySQL
0.11	passed	passed	passed
0.11.7	passed	failed	failed
0.12	passed	failed	failed
0.12.1	failed	failed	failed
0.12.2	failed	failed	failed
0.12.3	failed	failed	failed
0.12.4	failed	failed	failed
1.0	passed	failed	failed

Test logs: tagsplugin-r12115-tests.zip​

[Steffen Hoffmann]

Ok, getting a clearer vision now.

Test results on 0.11 are understandable, because it uses SQLiteConnection (SQLite) regardless of environment values. Seems like TRAC_TEST_DB_URI was introduced with backporting ​t:r8194 from rework-testing branch and merging in ​t:r8210 for Trac-0.11.5 .

Testing non-SQLite backends would require further hacking for earlier versions, so I conclude, that using Trac-0.11.5 as minimal version for MySQL + PostgreSQL is the best we can do, and assume that results for 0.11 should match to 0.11.5 - 0.11.7 . Furthermore, with your hint on testing (Thanks a lot!) I met some familiar looking issues in PostgreSQL, that caused some of these 'other problems'.

Not finally done, but I'll commit my preliminary results anyway to show progress. Maybe someone will be able to help again regarding the remaining test issues.

[Steffen Hoffmann]

(In [12124]) TagsPlugin: Don't call rollback() from environment_needs_upgrade(), refs #9521.

Table existence is tested using backend-specific db system catalogs like Jun Omae pointed out by contributing code from his TracMigratePlugin.

With default SQLite db backend all unit tests pass now, so workaround in tests was obviously needed only due to TagSetup.__init__ and _db_table_exists.

[Steffen Hoffmann]

Just noticed by printing the value of dburi in latest TagSetup.get_schema_version, that even Trac-0.12.4 still doesn't overwrite default db configuration with TRAC_TEST_DB_URI and uses SQLite (inconsistently?) instead. Only Trac-1.0 looks good in this respect, so I'll aim at fixing errors reported in this test run first.

[Steffen Hoffmann]

(In [12125]) TagsPlugin: PostgreSQL cursor dislikes early access to results, refs #9521.

I've seen this before, so `AttributeError: 'NoneType' object has no attribute 'fetchall'` was an instant reminder - done better now, squeezing 5 out of 7 issues with PostgreSQL unit tests in Trac-1.0 .

[Steffen Hoffmann]

(In [12128]) TagsPlugin: In unit tests always revert db changes done on TagSetup init, refs #9521.

Found out, that with PostgreSQL db backend neither schema version nor default permission actions have been inserted after component initialization. There might be a hidden issue with the test environment setup here, that once again requires a suspiciously looking workaround, but I'm unable to find it yet, even more since db code and SQL statements have been straightened a lot by now, therefor I'm gradually running out of ideas.

Anyway, all unit tests pass with PostgreSQL on Trac-1.0 now, while issues with older Trac versions remain, as outlined in #9521 before.

[Ryan J Ollos]

Replying to hasienda:

(In [12125]) TagsPlugin: PostgreSQL cursor dislikes early access to results, refs #9521.

I've seen this before, so `AttributeError: 'NoneType' object has no attribute 'fetchall'` was an instant reminder - done better now, squeezing 5 out of 7 issues with PostgreSQL unit tests in Trac-1.0.

I've been following this work closely since your post on the mailing list, and if I may offer a brief bit of code review, I have previously wondered on the difference between these two statements:

rows = cursor.fetchall()
for row in rows:

for row in cursor:

As far as I can tell, it is not strictly necessary to call fetchall, and I see almost no instances of this in the Trac source. The cursor is iterable, so I wonder, is there a particular reason to call fetchall? Performance reasons, or something to that effect?

It is less clear to me going back to Trac 0.11. However, in Trac 1.0, a read-only database connection results in a call to ConnectionWrapper.execute, which calls fetchall to return the list of tuples, so in that particular case it is completely unnecessary to call fetchall. I made some comments about this in ​t:#10893.

Anyway, the tests still pass if I make this change, and I know it doesn't matter at all, but I was curious about understanding the database access issues more than anything else, so I mention in hopes of learning more ;)

tractags/tests/model.py

@@ -64 +64 @@
         tags = {}
         cursor = self.db.cursor()
         cursor.execute("SELECT name,tag FROM tags")
-        for name, tag in cursor.fetchall():
+        for name, tag in cursor:
             if name in tags:
                 tags[name].add(tag)
             else:

[Ryan J Ollos]

​t:#10893 has an explanation of why you might not want to iterate over the cursor.

[Steffen Hoffmann]

Your questions have been interesting and answers given cast more light at the insights and design decisions of the Trac db API. So I've learned again as well.

For TagsPlugin the conclusion is not to change the code yet. Any place, where we use cursor.fetchone() now, does not iterate further on, but the cursor get's re-used afterwards. Especially dropping the cursor ASAP is not an issue there, quite the contrary so not draining the cursor explicitly is the right ("keep it") sign. And while on the legacy side of old 0.11-compat db API, cursor.fetchall() even seems to be the preferred way to drain the cursor, as Christian Boos explained in ​t:#10893.

Sure, the port to the new Trac 1.0 db API must happen, where I'll have to watch out to drop pulling out the cursor from the context manager. But this will break backwards compatibility with every version before.

So tags-0.7 might be the last version with full support for Trac-0.11, and Trac-0.12 too. I'll certainly maintain it for as long as there seems to be interest in that 0.11 branch, but will not port much of upstream development back to it.

[Ryan J Ollos]

Replying to hasienda:

So tags-0.7 might be the last version with full support for Trac-0.11, and Trac-0.12 too. I'll certainly maintain it for as long as there seems to be interest in that 0.11 branch, but will not port much of upstream development back to it.

I'm interested to hear that this will be your development approach moving forward, and becoming more convinced that it is the right approach, and the one that I will also adopt. Supporting 3 major Trac versions is becoming more challenging, particularly on the jQuery side as just one example, where we've progressed from jQuery 1.2.3 through in 1.7.2 in Trac 0.11 to Trac 1.0. That amounts to major changes in jQuery, and jQuery UI versions compatible back (1.5.x?) to jQuery 1.2.4 lack many features available in jQuery UI 1.7 and 1.8.

That is a bit off-topic, but the reasons for dropping 0.11 support are becoming more strong on many fronts. Overall, I think it is a good approach.

[Steffen Hoffmann]

OT? So may it be. The db API has undergone major changes, including fixes for db locks like experienced with trac-hacks.org too. IMHO it's reasonable to skip the 0.12 API as intermediate state and go just for 1.0 as the upstream, that might stay for longer now.

While plugins without Trac db storage interaction - wiki macros coming to mind here - won't be affected, those accessing the db will be forced to change for Trac-1.2 anyway. I'll remain a strong supporter of broad version compatibility, but this is the time to fork and roll over, and Trac-1.0 definitely deserves a similar adoption that 0.11 had reached before.

I doubted that the restart of version numbering would be smart, but gaining confidence each day. Users deserve i18n support and more elaborated db storage support, more contemporary web-UI and other goodies known from current stable. Even if a good number of these features has been inherited from old-stable, who cares? We are here now, so only look at 1.0 and beyond serves best, our users as well as ourselves.

[Ryan J Ollos]

It looks like there was a tab introduced to tests\model.py in [12078]:

tagsplugin/trunk/tractags/tests/model.py

@@ -48 +48 @@
     def tearDown(self):
         self.db.close()
         # Really close db connections.
-    self.env.shutdown()
+        self.env.shutdown()
         shutil.rmtree(self.env.path)
 
     # Helpers

[Steffen Hoffmann]

(In [12388]) TagsPlugin: Replace a tab white-space, that slipped in unintentionally, refs #9521.

Thanks to Ryan for change review and notification on the issue.

[Steffen Hoffmann]

#10652 has been close as a duplicate of this ticket.

However, with Trac-1.0 out for 2 months now, availability of the fix exclusively in trunk is not enough anymore, because adoption of the new Trac version may get seriously hindered by lacking Trac plugin support. I've stepped-up ticket ratings accordingly.

[Steffen Hoffmann]

(In [12773]) TracVote: Don't call rollback() from environment_needs_upgrade(), closes #10706.

This is patterned after [12124] for TagsPlugin. See #9521 for details on implications of probing the Trac db for table existence like done before.

[Steffen Hoffmann]

In 13815:

TagsPlugin: Completing preparation for v0.7 release.

Availability of that code as stable, tagged release
closes #2429, #3359, #3610, #3624, #3677, #3754, #3864, #3947, #3983, #4078, #4277, #4503, #4799, #5523, #7787, #7857, #8638, #9057, #9058, #9059, #9060, #9061, #9062, #9063, #9149, #9210, #9521, #9630, #9636, #10032, #10416, #10636, #11096, #11147, #11152, #11274, #11302, #11658 and #11659.

Additionally there are some issues and enhancement requests showing progress,
but known to require more work to resolve them satisfactorily, specifically
refs #2804, #4200, #8747 and #9064.

Thanks to all contributors and followers, that enabled and encouraged a good
portion of this development work.