Edgewall Software
Modify

Opened 6 years ago

Closed 6 years ago

Last modified 6 years ago

#12019 closed defect (fixed)

Failures of trac.tests.config on Windows since Trac 1.1.3

Reported by: Jun Omae Owned by: Jun Omae
Priority: normal Milestone: 1.0.6
Component: general Version:
Severity: normal Keywords: windows
Cc: Branch:
Release Notes:

Fix low resolution of wait_for_file_mtime_change() on Windows.

API Changes:

trac.util: Added touch_file() (r13969)

Internal Changes:

Description

trunk

C:> git checkout mirror/trunk
Previous HEAD position was ebbd95d... 1.1.4: Tagging trac-1.1.4.
HEAD is now at e51a24c... Merge from 1.0-stable.

C:> python -m trac.tests.config
SKIP: trac.tests.config.ConfigurationSetDefaultsTestCase (__name__ is not trac.tests.config)
...........................F..........
======================================================================
FAIL: test_reparse (__main__.ConfigurationTestCase)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "C:\usr\src\trac\trac.git\trac\tests\config.py", line 543, in test_reparse
    self.assertEqual('y', config.get('a', 'option'))
AssertionError: 'y' != u'x'

----------------------------------------------------------------------
Ran 38 tests in 2.142s

FAILED (failures=1)

Trac 1.1.4

C:> git checkout trac-1.1.4
Previous HEAD position was f4bc66e... 1.1.3: Tagging trac-1.1.3.
HEAD is now at ebbd95d... 1.1.4: Tagging trac-1.1.4.

C:> python -m trac.tests.config
SKIP: trac.tests.config.ConfigurationSetDefaultsTestCase (__name__ is not trac.tests.config)
..........F................F..........
======================================================================
FAIL: test_inherit_reparse (__main__.ConfigurationTestCase)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "C:\usr\src\trac\trac.git\trac\tests\config.py", line 554, in test_inherit_reparse
    self._test_with_inherit(testcb)
  File "C:\usr\src\trac\trac.git\trac\tests\config.py", line 697, in _test_with_inherit
    testcb()
  File "C:\usr\src\trac\trac.git\trac\tests\config.py", line 553, in testcb
    self.assertEqual('y', config.get('a', 'option'))
AssertionError: 'y' != u'x'

======================================================================
FAIL: test_reparse (__main__.ConfigurationTestCase)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "C:\usr\src\trac\trac.git\trac\tests\config.py", line 543, in test_reparse
    self.assertEqual('y', config.get('a', 'option'))
AssertionError: 'y' != u'x'

----------------------------------------------------------------------
Ran 38 tests in 2.219s

FAILED (failures=2)

Trac 1.1.3

C:> git checkout trac-1.1.3
Previous HEAD position was 58602e8... 1.1.2: Tagging trac-1.1.2.
HEAD is now at f4bc66e... 1.1.3: Tagging trac-1.1.3.

C:> python -m trac.tests.config
...........................F..........
======================================================================
FAIL: test_reparse (__main__.ConfigurationTestCase)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "C:\usr\src\trac\trac.git\trac\tests\config.py", line 516, in test_reparse
    self.assertEqual('y', config.get('a', 'option'))
AssertionError: 'y' != u'x'

----------------------------------------------------------------------
Ran 38 tests in 1.719s

FAILED (failures=1)

Trac 1.1.2

C:> git checkout trac-1.1.2
Previous HEAD position was f4bc66e... 1.1.3: Tagging trac-1.1.3.
HEAD is now at 58602e8... 1.1.2: Tagging trac-1.1.2.

C:> python -m trac.tests.config
....................................
----------------------------------------------------------------------
Ran 36 tests in 4.659s

OK

Attachments (1)

t12019-touch_file.diff (5.3 KB ) - added by Jun Omae 6 years ago.

Download all attachments as: .zip

Change History (9)

comment:1 by Ryan J Ollos, 6 years ago

The failing test was implemented in #11902 ([13628]).

Version 0, edited 6 years ago by Ryan J Ollos (next)

comment:2 by Peter Suter, 6 years ago

Weird. It's a timing / mtime issue, right? Here it only happens once in a while.

Maybe same issue as in #11904? This seems to fix it for me:

  • trac/util/compat.py

    diff -r e3f64f376184 trac/util/compat.py
    a b  
    7373    try:
    7474        mtime = os.stat(filename).st_mtime
    7575        os.utime(filename, None)
    76         while mtime == os.stat(filename).st_mtime:
     76        while mtime >= os.stat(filename).st_mtime:
    7777            time.sleep(1e-3)
    7878            os.utime(filename, None)
    7979    except OSError:
Last edited 6 years ago by Peter Suter (previous) (diff)

comment:3 by Jun Omae, 6 years ago

The cause is that os.utime() is implemented using GetSystemTime() on Windows and the system clock has low resolution (15ms-16ms).

>>> import os
>>> from trac.util import create_file
>>> create_file('test.txt')
>>> '%.9f' % os.stat('test.txt').st_mtime
'1428046347.664300900'
>>> os.utimes('test.txt', None)
>>> os.utime('test.txt', None)
>>> '%.9f' % os.stat('test.txt').st_mtime
'1428046389.869000000'   # <== low resolution of mtime

Instead, we could use f.truncate(os.fstat(f.fileno()).st_size) to update modified time. See t12019-touch_file.diff.

>>> create_file('test.txt')
>>> '%.9f' % os.stat('test.txt').st_mtime
'1428052266.600536600'
>>> with open('test.txt', 'ab') as f:
...     f.truncate(os.fstat(f.fileno()).st_size)
...
>>> '%.9f' % os.stat('test.txt').st_mtime
'1428052293.487920500'

by Jun Omae, 6 years ago

Attachment: t12019-touch_file.diff added

comment:4 by Ryan J Ollos, 6 years ago

All proposed changes look good to me. I haven't checked, but seems like the issue would be found on 1.0-stable as well.

Additionally, even prior to these changes it looks like the os.utime call in Configuration.touch is redundant: tags/trac-1.0.5/trac/config.py@:300#L296. It looks like it could have been removed when wait_for_file_mtime_change was added in [12258#file1].

Last edited 6 years ago by Ryan J Ollos (previous) (diff)

comment:5 by Jun Omae, 6 years ago

Milestone: 1.1.51.0.6
Owner: set to Jun Omae
Status: newassigned

Thanks for the reviewing. I get the same issue on 1.0-stable with Windows.

Proposed changes in jomae.git@t12019.

comment:6 by Jun Omae, 6 years ago

See also Issue 19727: os.utime(..., None) has poor resolution on Windows - Python tracker. The os.utime() has been improved on Windows since Python 3.4.

comment:7 by Jun Omae, 6 years ago

Release Notes: modified (diff)
Resolution: fixed
Status: assignedclosed

Committed in [13969] and merged to trunk in [13970].

comment:8 by Jun Omae, 6 years ago

API Changes: modified (diff)

Modify Ticket

Change Properties
Set your email in Preferences
Action
as closed The owner will remain Jun Omae.
The resolution will be deleted. Next status will be 'reopened'.
to The owner will be changed from Jun Omae to the specified user.

Add Comment


E-mail address and name can be saved in the Preferences .
 
Note: See TracTickets for help on using tickets.