trac.ticket.tests.notification.NotificationTestCase fails with sqlite on Windows

[Christian Boos]

======================================================================
ERROR: test_from_author (trac.ticket.tests.notification.NotificationTestCase)
Using the reporter or change author as the notification sender
----------------------------------------------------------------------
Traceback (most recent call last):
  File "C:\projects\trac\trac\ticket\tests\notification.py", line 480, in test_from_author
    ticket.save_changes('noname', 'Final changes')
  File "C:\projects\trac\trac\ticket\model.py", line 355, in save_changes
    old_db_values.get(name), db_values.get(name)))
  File "C:\projects\trac\trac\db\util.py", line 128, in execute
    cursor.execute(query, params if params is not None else [])
  File "C:\projects\trac\trac\db\util.py", line 61, in execute
    r = self.cursor.execute(sql_escape_percent(sql), args)
  File "C:\projects\trac\trac\db\sqlite_backend.py", line 82, in execute
    result = PyFormatCursor.execute(self, *args)
  File "C:\projects\trac\trac\db\sqlite_backend.py", line 60, in execute
    args or [])
  File "C:\projects\trac\trac\db\sqlite_backend.py", line 52, in _rollback_on_error
    return function(self, *args, **kwargs)
IntegrityError: columns ticket, time, field are not unique

The reproducibility is not 100%. On 1.0-stable Python 2.6.6 and 2.7.11 both x86 and x64) were affected, but on trunk, it happened reliably with x64 builds of Python only. So it happened with both in-memory and file based SQLite databases.

I couldn't reproduce the problem locally.

[Christian Boos]

So this is nothing new, I already noticed that a while ago, but it was happening a lot less frequently on my system, see #11301.

However, as that ticket evolved into a "replay-transactions", let's keep the present ticket dedicated to a short term solution that would get our builds green on AppVeyor.

[Jun Omae]

We could use ​GetSystemTimePreciseAsFileTime to retrieve high-resolution system time on Windows 8+ and Windows Server 2012+.

>>> from trac.util.datefmt import datetime_now, utc, localtz
>>> print('\n'.join(datetime_now(localtz).isoformat() for i in xrange(10)))
2016-01-12T01:27:44.808912+09:00
2016-01-12T01:27:44.809091+09:00
2016-01-12T01:27:44.809136+09:00
2016-01-12T01:27:44.809171+09:00
2016-01-12T01:27:44.809203+09:00
2016-01-12T01:27:44.809235+09:00
2016-01-12T01:27:44.809266+09:00
2016-01-12T01:27:44.809298+09:00
2016-01-12T01:27:44.809329+09:00
2016-01-12T01:27:44.809377+09:00

Proof of concept in log:jomae.git@t12311.

[Jun Omae]

See also ​Issue 19007: precise time.time() under Windows 8: use GetSystemTimePreciseAsFileTime - Python tracker.

[Christian Boos]

I tested your branch on AppVeyor (rebased so that it contains the .appveyor.yml file, + one more datetime_now, see log:cboos.git@t12311.appveyor) and it seems like it fixes the issue!

See ​https://ci.appveyor.com/project/cboos/trac/build/t12311.appveyor.5, the only failure is the test_sync_too_many_merges one (#12312).

Note that I had to re-init the project on AppVeyor, so all the previous experimental builds are gone. I'll soon commit the .appveyor.yml file and explain how one can setup an AppVeyor project (well, at this point it's trivial ;-) ).

Back to your changes: for me they look great, so feel free to grab the ticket and commit the fix!

[Jun Omae]

Thanks for the reviewing and testing! Committed in [14480] and merged to trunk in [14481].