Release Trac 0.11.7

[Remy Blank]

This task ticket is used to coordinate the finalization and testing of the next stable version of Trac, 0.11.7.

We're entering a one week period of testing for the rc1, tagged in [9259]. Packages can be downloaded from TracDownload#LatestReleaseCandidate.

If everything goes well, release of 0.11.7 proper will happen right after that.

Testing

People having volunteered to contribute to release testing on TracDev/ReleaseTesting were added to the CC: list.

If you'd like to contribute, please fill an entry in the table you'll find there, detailing the configuration(s) you will test, and report the status of your testing in this ticket.

Status

• update ChangeLog (started)

[Christian Boos]

The Trac 0.11 instances of edgewall.org (Babel, Bitten, Genshi) are now running the 0.11.7rc1.

[Christian Boos]

Ah yes, forgot to mention that this will very likely be the last 0.11.x release, so please really consider contributing to the testing period! Thanks.

[Remy Blank]

All tests pass, creating a new environment works, playing with the new environment works, for both of my configurations.

I don't think the few post-rc1 changesets warrant an rc2, so if no other issues are reported, we should be good to go for 0.11.7.

(OT: I've been spoiled by trunk: 0.11 now feels so… archaic!)

[Christian Boos]

I've also not seen anything wrong in the Trac logs for Genshi, Babel and Bitten.

But in the trac.log of t.e.o's demo-0.11, there were a couple of issues for 0.11.7stable of the past months:

1. lots of Broken pipe and Connection reset by peer errors ("trac/web/api.py", line 463​, in write)
2. a few Cannot operate on a closed cursor. when saving a session ("trac/web/session.py", line 100​, in save)
3. one AssertionError: Session ID not set ("trac/web/session.py", line 163​, in bake_cookie - coming from get_session)
4. several backtraces for a ResourceNotFound: Attachment 'wiki:TracRss: [[Image(XXX)]] when XXX is some non existing attachment; I don't think we need to log an internal error in that case.
5. a strange Genshi error: TypeError: 'StripDirective' object is not iterable, no clue where this comes from, will file separately on Genshi
6. a few UnicodeDecodeError triggered by non-UTF-8 PATH_INFO (in "trac/web/api.py", line 208​)
7. a few TimeoutError: Unable to get database connection within 20 seconds yesterday (about 20 of them, between 8:20 and 8:22 AM).

I don't think there's any regression from 0.11.6 though. The question is, are those last errors worth fixing to have a really clean last 0.11-stable release?

Plus a few SpamFilter errors, which I'll file as separate errors.

[Remy Blank]

Here are a few thoughts:

1. I think this is normal if the client disconnects before reading all the data.
2. This sounds like a genuine (albeit infrequent) bug. But I fail to see how the cursor can be closed at that location. I wouldn't know how to analyze that.
3. This sounds like a race condition between database accesses from the session code. These are more or less inevitable.
4. True, but not essential for 0.11.7. I would fix that in trunk.
5. Ok.
6. Garbage in, garbage out. We could use to_unicode() instead, but isn't PATH_INFO specified as UTF-8?

So if you know how to fix 2., I'd include it in 0.11.7. The others I would leave for trunk. 0.11.7 won't be the perfect release, same as all the previous ones, and trunk is much closer to perfection anyway :)

[Christian Boos]

Replying to rblank:

Here are a few thoughts:

1. I think this is normal if the client disconnects before reading all the data.

True, but then this should just be ignored and not pollute the trac.log, as this makes it harder to see the actual errors (same as #3957).

2. This sounds like a genuine (albeit infrequent) bug. But I fail to see how the cursor can be closed at that location. I wouldn't know how to analyze that.

It's easy, the following sequence reproduces it (for PySqlite at least):

>>> from trac.environment import Environment
>>> env = Environment('...')
>>> db = env.get_db_cnx()
>>> cursor = db.cursor()
>>> db.rollback()
>>> cursor.execute("SELECT * FROM system")
ProgrammingError('Cannot operate on a closed cursor.',)
Traceback (most recent call last):
  File "<stdin>", line 1, in <module>
  File "C:\Workspace\src\trac\repos\trunk\trac\db\util.py", line 92, in execute
    r = self.cursor.execute(sql)
  File "C:\Workspace\src\trac\repos\trunk\trac\db\sqlite_backend.py", line 77, in execute
    result = PyFormatCursor.execute(self, *args)
  File "C:\Workspace\src\trac\repos\trunk\trac\db\sqlite_backend.py", line 56, in execute
    args or [])
  File "C:\Workspace\src\trac\repos\trunk\trac\db\sqlite_backend.py", line 48, in _rollback_on_error
    return function(self, *args, **kwargs)
pysqlite2.dbapi2.ProgrammingError: Cannot operate on a closed cursor.

3. This sounds like a race condition between database accesses from the session code. These are more or less inevitable.

Then we shouldn't have an assert… but I agree the problem has "always" been there and as the fix is not obvious I have no problem to address that in 0.12.x.

4. True, but not essential for 0.11.7. I would fix that in trunk.

Ok.

5. Ok.

This is now ​#G372.

6. Garbage in, garbage out. We could use to_unicode() instead, but isn't PATH_INFO specified as UTF-8?

No, though that's the most common situation, there's no standard for that AFAICT. See for example #3663 and various discussions in the Web-SIG mailing list hinting that some kind of utf-8 conversion with latin1 fallback should be used.

So if you know how to fix 2., I'd include it in 0.11.7. The others I would leave for trunk. 0.11.7 won't be the perfect release, same as all the previous ones, and trunk is much closer to perfection anyway :)

1. and 2. should be easy to fix. 3., 4. and 6. for later and 7., well, that's #8602 / #8443.

[Remy Blank]

Replying to cboos:

It's easy, the following sequence reproduces it (for PySqlite at least):

I was wondering if the db.rollback() a few lines up could be the cause, but I thought it shouldn't, by symmetry with db.commit() which doesn't seem to invalidate cursors.

But ok, then it's probably an easy fix: just add a cursor = db.cursor() right after the db.rollback()?

Then we shouldn't have an assert… but I agree the problem has "always" been there and as the fix is not obvious I have no problem to address that in 0.12.x.

Not only that, but as long as we don't use completely isolated database accesses, we will always have many locations where race conditions are possible.

No, though that's the most common situation, there's no standard for that AFAICT. See for example #3663 and various discussions in the Web-SIG mailing list hinting that some kind of utf-8 conversion with latin1 fallback should be used.

Ok, but that wouldn't fix #3663. Also, aren't there other variables coming from the web server that should be converted?

1. and 2. should be easy to fix. 3., 4. and 6. for later and 7., well, that's #8602 / #8443.

Ok for me.

[Christian Boos]

Replying to rblank:

Ok, but that wouldn't fix #3663. Also, aren't there other variables coming from the web server that should be converted?

Point 6. is in fact exactly about #3663, and the to_unicode solution works and is simple enough to be included in 0.11.7, IMO. Please review.

[osimons]

Regarding 2. (Cannot operate on a closed cursor): I've just had an interesting discussion on IRC regarding the ​HackerGotchi source from a user that get the same error after 0.11.6 upgrade - an error that did not happen before.

The interesting pattern here is that db and cursor is defined in an outer method, but used inside a closure. Cursor used inside the closure (or in other methods called from closure with cursor argument) causes the error to appear. Moving the db and cursor declaration into the closure fixes it.

I'll be honest and say I can't really remember the changes done in Trac recently, and therefore not quite how this may be impacted. However, to me I can't quite see why the db should become dereferenced and returned to the pool (with rollback() called as part of the cleanup). What changed that may now make this pattern unusable? Is it an inherit problem with closures? Is the connection code too agressive somehow?

The user submitted a ticket for it at ​th:ticket:6765

[Christian Boos]

Replying to osimons:

Regarding 2. (Cannot operate on a closed cursor): I've just had an interesting discussion on IRC regarding the ​HackerGotchi source from a user that get the same error after 0.11.6 upgrade - an error that did not happen before.

Not sure why it didn't happen before, but that code has some issues, see my reply ticket:8708#comment:9 to a similar problem reported in that ticket.

The interesting pattern here is that db and cursor is defined in an outer method, but used inside a closure. Cursor used inside the closure (or in other methods called from closure with cursor argument) causes the error to appear. Moving the db and cursor declaration into the closure fixes it.

See #9104.

I'll be honest and say I can't really remember the changes done in Trac recently, and therefore not quite how this may be impacted. However, to me I can't quite see why the db should become dereferenced and returned to the pool (with rollback() called as part of the cleanup). What changed that may now make this pattern unusable? Is it an inherit problem with closures? Is the connection code too agressive somehow?

It's due to explicit close of cursors we do in rollback() (see tags/trac-0.11/trac/db/sqlite_backend.py@:191-194#L184​), that code is from Trac 0.9 though (r2355). I think it's not needed to do this anymore with recent versions of pysqlite, it's probably best to still keep that around until we make pysqlite 2.2.1 an explicit minimum requirement (see last point in [pysqlite:wiki:2.2.1_Changelog 2.2.1 Changelog], though reading the [pysqlite:wiki:2.3.1_Changelog 2.3.1_Changelog] we might as well impose that as the minimum… Python 2.5.2 comes with 2.3.2, so this should be possible). Nothing new, still :-)

[osimons]

Replying to cboos:

Not sure why it didn't happen before, but that code has some issues, see my reply ticket:8708#comment:9 to a similar problem reported in that ticket.

"Same" - not just "similar"… Both from Noah's plugin code.

Thanks for pointers. I suppose there are some holes in my understanding of Python internals and closures, but I still can't quite comprehend why db should be reclaimed when execution is inside of the closure - why shouldn't the external scope be available and adressable? I don't quite see where the rollback() is supposed to happen.

[Christian Boos]

Replying to osimons:

… why shouldn't the external scope be available and adressable?

It is…

I don't quite see where the rollback() is supposed to happen.

Edit: now realizing that you were talking about HackerGotchi here ;-) See follow-up comment on #8708.

A few lines above, source:branches/0.11-stable/trac/web/session.py@9300:94#L73​. Now that I think about it, as we're coming there because of a concurrent request, we could as well simply return at that point, as the expiration checks have been performed by the other request… I'll post a second patch on #9104, please follow-up there.

[Christian Boos]

t.e.o is now running r9336 (demo-0.11, ​Genshi, [Babel:], ​Bitten). If all is fine there and nobody objects, this will become 0.11.7.

[osimons]

I upgraded to r9336 last night too for all my projects. All seems to work as expected.

[Remy Blank]

Sounds good to me.

[Christian Boos]

Too bad, found again something in the logs (#5932). I think it's worth fixing this long time mysterious error, now that we have a reproduction case.

The good news is that I found nothing else, everything seems to work fine besides this.

[Christian Boos]

Release tagged in r9340.

The packages for Trac 0.11.7 are now available (TracDownload@114).

I'll send the announcement mail at some point tomorrow, once I get confirmation everything is OK with the packages.

[Remy Blank]

The .tar.gz package is fine, tested here on Linux.

[Christian Boos]

Announcement mail sent to Trac Announce and Trac Users mailing lists.