Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

recent changes seem to break winbot #60

Closed
agroszer opened this issue May 17, 2016 · 21 comments · Fixed by #65
Closed

recent changes seem to break winbot #60

agroszer opened this issue May 17, 2016 · 21 comments · Fixed by #65

Comments

@agroszer
Copy link
Contributor

http://winbot.zope.org/builders/ZODB_dev%20py_270_win32/builds/2116/steps/test/logs/stdio

(I plan to update builders to the currently supported platforms)

(also, @jimfulton you need failure emails from winbot?)

@jmuchemb jmuchemb self-assigned this May 17, 2016
@tseaver
Copy link
Member

tseaver commented May 17, 2016

These failures start with the merge of #58. @jmuchemb, can you figure out what might be different on Windows about that patch?

@jmuchemb
Copy link
Member

In fact, there are 2 issues:

AssertionError: 1463440525.921 not less than 1463440525.921

This one is indeed related to #58, but it's not a regression. If possible, I'd like to increase timestamp precision on Windows platform.

AssertionError: 'bar' != 'foo'

It concerns #52, and it was not fixed by #57.
The behaviour of Windows is the "opposite" of Mac OS X:

IOW, on Windows:

  • FilePool.empty can be optimized (to do nothing)
  • checkFlushNeededAfterTruncate should be disabled

@jmuchemb
Copy link
Member

jmuchemb commented Jun 8, 2016

AssertionError: 1463440525.921 not less than 1463440525.921

This one is indeed related to #58, but it's not a regression. If possible, I'd like to increase timestamp precision on Windows platform.

I have no Windows box but I made some searches and found that time.time() has a precision of 1ms. According to https://msdn.microsoft.com/en-us/library/ms724228.aspx (more exactly, the inverse function, in conjunction with GetSystemTimeAsFileTime), precision could be increased.
If anyone is interested in such improvement, a Python issue should rather be open.

Meanwhile for ZODB, I'll just add a sleep(.001).

@agroszer
Copy link
Contributor Author

agroszer commented Jun 9, 2016

Please fix winbot, you know what a long standing red CI means...

@mgedmin
Copy link
Member

mgedmin commented Jun 9, 2016

http://winbot.zope.org/builders/ZODB_dev%20py_270_win32/builds/2116/steps/test/logs/stdio

This is a 404 page. In the future can you please copy the traceback itself into the GitHub issue?

@agroszer
Copy link
Contributor Author

agroszer commented Jun 9, 2016

my bad

Running zope.testrunner.layer.UnitTests tests:
  Set up zope.testrunner.layer.UnitTests in 0.000 seconds.


Failure in test checkBaseHistory (ZODB.tests.testDemoStorage.DemoStorageTests)
Traceback (most recent call last):
  File "c:\Python33_32\lib\unittest\case.py", line 384, in _executeTestPart
    function()
  File "c:\buildslave\zodb_dev_py_330_win32\build\src\ZODB\tests\testDemoStorage.py", line 96, in checkBaseHistory
    self._checkHistory(base_only())
  File "c:\buildslave\zodb_dev_py_330_win32\build\src\ZODB\tests\HistoryStorage.py", line 46, in _checkHistory
    self.assertLess(a, b)
  File "c:\Python33_32\lib\unittest\case.py", line 1026, in assertLess
    self.fail(self._formatMessage(msg, standardMsg))
  File "c:\Python33_32\lib\unittest\case.py", line 508, in fail
    raise self.failureException(msg)
AssertionError: 1465433823.260304 not less than 1465433823.260304



Failure in test checkSimpleHistory (ZODB.tests.testDemoStorage.DemoStorageTests)
Traceback (most recent call last):
  File "c:\Python33_32\lib\unittest\case.py", line 384, in _executeTestPart
    function()
  File "c:\buildslave\zodb_dev_py_330_win32\build\src\ZODB\tests\HistoryStorage.py", line 25, in checkSimpleHistory
    self._checkHistory((11, 12, 13))
  File "c:\buildslave\zodb_dev_py_330_win32\build\src\ZODB\tests\HistoryStorage.py", line 46, in _checkHistory
    self.assertLess(a, b)
  File "c:\Python33_32\lib\unittest\case.py", line 1026, in assertLess
    self.fail(self._formatMessage(msg, standardMsg))
  File "c:\Python33_32\lib\unittest\case.py", line 508, in fail
    raise self.failureException(msg)
AssertionError: 1465433826.4163122 not less than 1465433826.416312



Failure in test checkBaseHistory (ZODB.tests.testDemoStorage.DemoStorageHexTests)
Traceback (most recent call last):
  File "c:\Python33_32\lib\unittest\case.py", line 384, in _executeTestPart
    function()
  File "c:\buildslave\zodb_dev_py_330_win32\build\src\ZODB\tests\testDemoStorage.py", line 96, in checkBaseHistory
    self._checkHistory(base_only())
  File "c:\buildslave\zodb_dev_py_330_win32\build\src\ZODB\tests\HistoryStorage.py", line 46, in _checkHistory
    self.assertLess(a, b)
  File "c:\Python33_32\lib\unittest\case.py", line 1026, in assertLess
    self.fail(self._formatMessage(msg, standardMsg))
  File "c:\Python33_32\lib\unittest\case.py", line 508, in fail
    raise self.failureException(msg)
AssertionError: 1465433833.4938931 not less than 1465433833.493893



Failure in test checkSimpleHistory (ZODB.tests.testDemoStorage.DemoStorageHexTests)
Traceback (most recent call last):
  File "c:\Python33_32\lib\unittest\case.py", line 384, in _executeTestPart
    function()
  File "c:\buildslave\zodb_dev_py_330_win32\build\src\ZODB\tests\HistoryStorage.py", line 25, in checkSimpleHistory
    self._checkHistory((11, 12, 13))
  File "c:\buildslave\zodb_dev_py_330_win32\build\src\ZODB\tests\HistoryStorage.py", line 46, in _checkHistory
    self.assertLess(a, b)
  File "c:\Python33_32\lib\unittest\case.py", line 1026, in assertLess
    self.fail(self._formatMessage(msg, standardMsg))
  File "c:\Python33_32\lib\unittest\case.py", line 508, in fail
    raise self.failureException(msg)
AssertionError: 1465433836.571782 not less than 1465433836.571782



Failure in test checkBaseHistory (ZODB.tests.testDemoStorage.DemoStorageWrappedAroundFileStorage)
Traceback (most recent call last):
  File "c:\Python33_32\lib\unittest\case.py", line 384, in _executeTestPart
    function()
  File "c:\buildslave\zodb_dev_py_330_win32\build\src\ZODB\tests\testDemoStorage.py", line 96, in checkBaseHistory
    self._checkHistory(base_only())
  File "c:\buildslave\zodb_dev_py_330_win32\build\src\ZODB\tests\HistoryStorage.py", line 46, in _checkHistory
    self.assertLess(a, b)
  File "c:\Python33_32\lib\unittest\case.py", line 1026, in assertLess
    self.fail(self._formatMessage(msg, standardMsg))
  File "c:\Python33_32\lib\unittest\case.py", line 508, in fail
    raise self.failureException(msg)
AssertionError: 1465433843.9618392 not less than 1465433843.961839



Failure in test checkSimpleHistory (ZODB.tests.testDemoStorage.DemoStorageWrappedAroundFileStorage)
Traceback (most recent call last):
  File "c:\Python33_32\lib\unittest\case.py", line 384, in _executeTestPart
    function()
  File "c:\buildslave\zodb_dev_py_330_win32\build\src\ZODB\tests\HistoryStorage.py", line 25, in checkSimpleHistory
    self._checkHistory((11, 12, 13))
  File "c:\buildslave\zodb_dev_py_330_win32\build\src\ZODB\tests\HistoryStorage.py", line 46, in _checkHistory
    self.assertLess(a, b)
  File "c:\Python33_32\lib\unittest\case.py", line 1026, in assertLess
    self.fail(self._formatMessage(msg, standardMsg))
  File "c:\Python33_32\lib\unittest\case.py", line 508, in fail
    raise self.failureException(msg)
AssertionError: 1465433848.6802273 not less than 1465433848.680227



Failure in test checkBaseHistory (ZODB.tests.testDemoStorage.DemoStorageWrappedAroundMappingStorage)
Traceback (most recent call last):
  File "c:\Python33_32\lib\unittest\case.py", line 384, in _executeTestPart
    function()
  File "c:\buildslave\zodb_dev_py_330_win32\build\src\ZODB\tests\testDemoStorage.py", line 96, in checkBaseHistory
    self._checkHistory(base_only())
  File "c:\buildslave\zodb_dev_py_330_win32\build\src\ZODB\tests\HistoryStorage.py", line 46, in _checkHistory
    self.assertLess(a, b)
  File "c:\Python33_32\lib\unittest\case.py", line 1026, in assertLess
    self.fail(self._formatMessage(msg, standardMsg))
  File "c:\Python33_32\lib\unittest\case.py", line 508, in fail
    raise self.failureException(msg)
AssertionError: 1465433856.2890182 not less than 1465433856.289018



Failure in test checkSimpleHistory (ZODB.tests.testDemoStorage.DemoStorageWrappedAroundMappingStorage)
Traceback (most recent call last):
  File "c:\Python33_32\lib\unittest\case.py", line 384, in _executeTestPart
    function()
  File "c:\buildslave\zodb_dev_py_330_win32\build\src\ZODB\tests\HistoryStorage.py", line 25, in checkSimpleHistory
    self._checkHistory((11, 12, 13))
  File "c:\buildslave\zodb_dev_py_330_win32\build\src\ZODB\tests\HistoryStorage.py", line 46, in _checkHistory
    self.assertLess(a, b)
  File "c:\Python33_32\lib\unittest\case.py", line 1026, in assertLess
    self.fail(self._formatMessage(msg, standardMsg))
  File "c:\Python33_32\lib\unittest\case.py", line 508, in fail
    raise self.failureException(msg)
AssertionError: 1465433859.3825302 not less than 1465433859.38253



Failure in test checkBaseHistory (ZODB.tests.testDemoStorage.DemoStorageWrappedAroundHexMappingStorage)
Traceback (most recent call last):
  File "c:\Python33_32\lib\unittest\case.py", line 384, in _executeTestPart
    function()
  File "c:\buildslave\zodb_dev_py_330_win32\build\src\ZODB\tests\testDemoStorage.py", line 96, in checkBaseHistory
    self._checkHistory(base_only())
  File "c:\buildslave\zodb_dev_py_330_win32\build\src\ZODB\tests\HistoryStorage.py", line 46, in _checkHistory
    self.assertLess(a, b)
  File "c:\Python33_32\lib\unittest\case.py", line 1026, in assertLess
    self.fail(self._formatMessage(msg, standardMsg))
  File "c:\Python33_32\lib\unittest\case.py", line 508, in fail
    raise self.failureException(msg)
AssertionError: 1465433866.4757352 not less than 1465433866.475735



Failure in test checkSimpleHistory (ZODB.tests.testDemoStorage.DemoStorageWrappedAroundHexMappingStorage)
Traceback (most recent call last):
  File "c:\Python33_32\lib\unittest\case.py", line 384, in _executeTestPart
    function()
  File "c:\buildslave\zodb_dev_py_330_win32\build\src\ZODB\tests\HistoryStorage.py", line 25, in checkSimpleHistory
    self._checkHistory((11, 12, 13))
  File "c:\buildslave\zodb_dev_py_330_win32\build\src\ZODB\tests\HistoryStorage.py", line 46, in _checkHistory
    self.assertLess(a, b)
  File "c:\Python33_32\lib\unittest\case.py", line 1026, in assertLess
    self.fail(self._formatMessage(msg, standardMsg))
  File "c:\Python33_32\lib\unittest\case.py", line 508, in fail
    raise self.failureException(msg)
AssertionError: 1465433869.616119 not less than 1465433869.616119



Failure in test checkSimpleHistory (ZODB.tests.testMVCCMappingStorage.MVCCMappingStorageTests)
Traceback (most recent call last):
  File "c:\Python33_32\lib\unittest\case.py", line 384, in _executeTestPart
    function()
  File "c:\buildslave\zodb_dev_py_330_win32\build\src\ZODB\tests\HistoryStorage.py", line 25, in checkSimpleHistory
    self._checkHistory((11, 12, 13))
  File "c:\buildslave\zodb_dev_py_330_win32\build\src\ZODB\tests\HistoryStorage.py", line 46, in _checkHistory
    self.assertLess(a, b)
  File "c:\Python33_32\lib\unittest\case.py", line 1026, in assertLess
    self.fail(self._formatMessage(msg, standardMsg))
  File "c:\Python33_32\lib\unittest\case.py", line 508, in fail
    raise self.failureException(msg)
AssertionError: 1465433879.81846 not less than 1465433879.81846



Failure in test checkSimpleHistory (ZODB.tests.testMappingStorage.MappingStorageHexTests)
Traceback (most recent call last):
  File "c:\Python33_32\lib\unittest\case.py", line 384, in _executeTestPart
    function()
  File "c:\buildslave\zodb_dev_py_330_win32\build\src\ZODB\tests\HistoryStorage.py", line 25, in checkSimpleHistory
    self._checkHistory((11, 12, 13))
  File "c:\buildslave\zodb_dev_py_330_win32\build\src\ZODB\tests\HistoryStorage.py", line 46, in _checkHistory
    self.assertLess(a, b)
  File "c:\Python33_32\lib\unittest\case.py", line 1026, in assertLess
    self.fail(self._formatMessage(msg, standardMsg))
  File "c:\Python33_32\lib\unittest\case.py", line 508, in fail
    raise self.failureException(msg)
AssertionError: 1465433890.3176541 not less than 1465433890.317654

  Ran 975 tests with 12 failures, 0 errors and 0 skipped in 2 minutes 10.349 seconds.
Running .BlobAdaptedFileStorageBlobTests tests:
  Tear down zope.testrunner.layer.UnitTests in 0.000 seconds.
  Set up .BlobAdaptedFileStorageBlobTests in 0.016 seconds.
  Ran 21 tests with 12 failures, 0 errors and 0 skipped in 11.624 seconds.
Running .BlobFileHexStorageBlobTests tests:
  Tear down .BlobAdaptedFileStorageBlobTests in 0.000 seconds.
  Set up .BlobFileHexStorageBlobTests in 0.000 seconds.
  Ran 21 tests with 12 failures, 0 errors and 0 skipped in 12.343 seconds.
Running .BlobFileStorageBlobTests tests:
  Tear down .BlobFileHexStorageBlobTests in 0.000 seconds.
  Set up .BlobFileStorageBlobTests in 0.000 seconds.
  Ran 21 tests with 12 failures, 0 errors and 0 skipped in 11.765 seconds.
Running .MVCCMappingBlobTests tests:
  Tear down .BlobFileStorageBlobTests in 0.000 seconds.
  Set up .MVCCMappingBlobTests in 0.000 seconds.
  Ran 14 tests with 12 failures, 0 errors and 0 skipped in 2.703 seconds.
Running .repozo tests:
  Tear down .MVCCMappingBlobTests in 0.000 seconds.
  Set up .repozo in 0.000 seconds.
  Ran 1 tests with 12 failures, 0 errors and 0 skipped in 2 minutes 10.053 seconds.
Running .testFileStorage tests:
  Tear down .repozo in 0.000 seconds.
  Set up .testFileStorage in 0.000 seconds.


Failure in test checkSimpleHistory (ZODB.tests.testFileStorage.FileStorageTests)
Traceback (most recent call last):
  File "c:\Python33_32\lib\unittest\case.py", line 384, in _executeTestPart
    function()
  File "c:\buildslave\zodb_dev_py_330_win32\build\src\ZODB\tests\HistoryStorage.py", line 25, in checkSimpleHistory
    self._checkHistory((11, 12, 13))
  File "c:\buildslave\zodb_dev_py_330_win32\build\src\ZODB\tests\HistoryStorage.py", line 47, in _checkHistory
    self.assertLess(start, a)
  File "c:\Python33_32\lib\unittest\case.py", line 1026, in assertLess
    self.fail(self._formatMessage(msg, standardMsg))
  File "c:\Python33_32\lib\unittest\case.py", line 508, in fail
    raise self.failureException(msg)
AssertionError: 1465434163.92164 not less than 1465434163.92164



Failure in test checkSimpleHistory (ZODB.tests.testFileStorage.FileStorageHexTests)
Traceback (most recent call last):
  File "c:\Python33_32\lib\unittest\case.py", line 384, in _executeTestPart
    function()
  File "c:\buildslave\zodb_dev_py_330_win32\build\src\ZODB\tests\HistoryStorage.py", line 25, in checkSimpleHistory
    self._checkHistory((11, 12, 13))
  File "c:\buildslave\zodb_dev_py_330_win32\build\src\ZODB\tests\HistoryStorage.py", line 47, in _checkHistory
    self.assertLess(start, a)
  File "c:\Python33_32\lib\unittest\case.py", line 1026, in assertLess
    self.fail(self._formatMessage(msg, standardMsg))
  File "c:\Python33_32\lib\unittest\case.py", line 508, in fail
    raise self.failureException(msg)
AssertionError: 1465434203.949815 not less than 1465434203.9498148



Failure in test checkSimpleHistory (ZODB.tests.testFileStorage.FileStorageTestsWithBlobsEnabled)
Traceback (most recent call last):
  File "c:\Python33_32\lib\unittest\case.py", line 384, in _executeTestPart
    function()
  File "c:\buildslave\zodb_dev_py_330_win32\build\src\ZODB\tests\HistoryStorage.py", line 25, in checkSimpleHistory
    self._checkHistory((11, 12, 13))
  File "c:\buildslave\zodb_dev_py_330_win32\build\src\ZODB\tests\HistoryStorage.py", line 46, in _checkHistory
    self.assertLess(a, b)
  File "c:\Python33_32\lib\unittest\case.py", line 1026, in assertLess
    self.fail(self._formatMessage(msg, standardMsg))
  File "c:\Python33_32\lib\unittest\case.py", line 508, in fail
    raise self.failureException(msg)
AssertionError: 1465434239.290851 not less than 1465434239.290851



Failure in test checkSimpleHistory (ZODB.tests.testFileStorage.FileStorageHexTestsWithBlobsEnabled)
Traceback (most recent call last):
  File "c:\Python33_32\lib\unittest\case.py", line 384, in _executeTestPart
    function()
  File "c:\buildslave\zodb_dev_py_330_win32\build\src\ZODB\tests\HistoryStorage.py", line 25, in checkSimpleHistory
    self._checkHistory((11, 12, 13))
  File "c:\buildslave\zodb_dev_py_330_win32\build\src\ZODB\tests\HistoryStorage.py", line 47, in _checkHistory
    self.assertLess(start, a)
  File "c:\Python33_32\lib\unittest\case.py", line 1026, in assertLess
    self.fail(self._formatMessage(msg, standardMsg))
  File "c:\Python33_32\lib\unittest\case.py", line 508, in fail
    raise self.failureException(msg)
AssertionError: 1465434272.944516 not less than 1465434272.9445157

  Ran 408 tests with 16 failures, 0 errors and 0 skipped in 3 minutes 0.627 seconds.
Tearing down left over layers:
  Tear down .testFileStorage in 0.000 seconds.
Total: 1461 tests, 16 failures, 0 errors and 0 skipped in 7 minutes 59.838 seconds.

@mgedmin
Copy link
Member

mgedmin commented Jun 14, 2016

Bad news: winbot is still unhappy :(

http://winbot.zope.org/builders/ZODB_dev%20py_270_win32/builds/17/steps/test/logs/stdio:

Failure in test checkBaseHistory (ZODB.tests.testDemoStorage.DemoStorageTests)
Traceback (most recent call last):
  File "c:\Python27_32\lib\unittest\case.py", line 329, in run
    testMethod()
  File "c:\buildslave\zodb_dev_py_270_win32\build\src\ZODB\tests\testDemoStorage.py", line 96, in checkBaseHistory
    self._checkHistory(base_only())
  File "c:\buildslave\zodb_dev_py_270_win32\build\src\ZODB\tests\HistoryStorage.py", line 50, in _checkHistory
    self.assertLess(a, b)
  File "c:\Python27_32\lib\unittest\case.py", line 930, in assertLess
    self.fail(self._formatMessage(msg, standardMsg))
  File "c:\Python27_32\lib\unittest\case.py", line 410, in fail
    raise self.failureException(msg)
AssertionError: 1465862032.751 not less than 1465862032.751



Failure in test checkBaseHistory (ZODB.tests.testDemoStorage.DemoStorageHexTests)
Traceback (most recent call last):
  File "c:\Python27_32\lib\unittest\case.py", line 329, in run
    testMethod()
  File "c:\buildslave\zodb_dev_py_270_win32\build\src\ZODB\tests\testDemoStorage.py", line 104, in checkBaseHistory
    self._checkHistory(base_and_changes())
  File "c:\buildslave\zodb_dev_py_270_win32\build\src\ZODB\tests\HistoryStorage.py", line 50, in _checkHistory
    self.assertLess(a, b)
  File "c:\Python27_32\lib\unittest\case.py", line 930, in assertLess
    self.fail(self._formatMessage(msg, standardMsg))
  File "c:\Python27_32\lib\unittest\case.py", line 410, in fail
    raise self.failureException(msg)
AssertionError: 1465862043.204 not less than 1465862043.204



Failure in test checkBaseHistory (ZODB.tests.testDemoStorage.DemoStorageWrappedAroundFileStorage)
Traceback (most recent call last):
  File "c:\Python27_32\lib\unittest\case.py", line 329, in run
    testMethod()
  File "c:\buildslave\zodb_dev_py_270_win32\build\src\ZODB\tests\testDemoStorage.py", line 104, in checkBaseHistory
    self._checkHistory(base_and_changes())
  File "c:\buildslave\zodb_dev_py_270_win32\build\src\ZODB\tests\HistoryStorage.py", line 50, in _checkHistory
    self.assertLess(a, b)
  File "c:\Python27_32\lib\unittest\case.py", line 930, in assertLess
    self.fail(self._formatMessage(msg, standardMsg))
  File "c:\Python27_32\lib\unittest\case.py", line 410, in fail
    raise self.failureException(msg)
AssertionError: 1465862053.907 not less than 1465862053.907



Failure in test checkSimpleHistory (ZODB.tests.testDemoStorage.DemoStorageWrappedAroundMappingStorage)
Traceback (most recent call last):
  File "c:\Python27_32\lib\unittest\case.py", line 329, in run
    testMethod()
  File "c:\buildslave\zodb_dev_py_270_win32\build\src\ZODB\tests\HistoryStorage.py", line 26, in checkSimpleHistory
    self._checkHistory((11, 12, 13))
  File "c:\buildslave\zodb_dev_py_270_win32\build\src\ZODB\tests\HistoryStorage.py", line 50, in _checkHistory
    self.assertLess(a, b)
  File "c:\Python27_32\lib\unittest\case.py", line 930, in assertLess
    self.fail(self._formatMessage(msg, standardMsg))
  File "c:\Python27_32\lib\unittest\case.py", line 410, in fail
    raise self.failureException(msg)
AssertionError: 1465862069.032 not less than 1465862069.032



Failure in test checkBaseHistory (ZODB.tests.testDemoStorage.DemoStorageWrappedAroundHexMappingStorage)
Traceback (most recent call last):
  File "c:\Python27_32\lib\unittest\case.py", line 329, in run
    testMethod()
  File "c:\buildslave\zodb_dev_py_270_win32\build\src\ZODB\tests\testDemoStorage.py", line 104, in checkBaseHistory
    self._checkHistory(base_and_changes())
  File "c:\buildslave\zodb_dev_py_270_win32\build\src\ZODB\tests\HistoryStorage.py", line 50, in _checkHistory
    self.assertLess(a, b)
  File "c:\Python27_32\lib\unittest\case.py", line 930, in assertLess
    self.fail(self._formatMessage(msg, standardMsg))
  File "c:\Python27_32\lib\unittest\case.py", line 410, in fail
    raise self.failureException(msg)
AssertionError: 1465862076.329 not less than 1465862076.329



Failure in test checkSimpleHistory (ZODB.tests.testMappingStorage.MappingStorageHexTests)
Traceback (most recent call last):
  File "c:\Python27_32\lib\unittest\case.py", line 329, in run
    testMethod()
  File "c:\buildslave\zodb_dev_py_270_win32\build\src\ZODB\tests\HistoryStorage.py", line 26, in checkSimpleHistory
    self._checkHistory((11, 12, 13))
  File "c:\buildslave\zodb_dev_py_270_win32\build\src\ZODB\tests\HistoryStorage.py", line 50, in _checkHistory
    self.assertLess(a, b)
  File "c:\Python27_32\lib\unittest\case.py", line 930, in assertLess
    self.fail(self._formatMessage(msg, standardMsg))
  File "c:\Python27_32\lib\unittest\case.py", line 410, in fail
    raise self.failureException(msg)
AssertionError: 1465862100.579 not less than 1465862100.579


Failure in test checkSimpleHistory (ZODB.tests.testFileStorage.FileStorageHexTestsWithBlobsEnabled)
Traceback (most recent call last):
  File "c:\Python27_32\lib\unittest\case.py", line 329, in run
    testMethod()
  File "c:\buildslave\zodb_dev_py_270_win32\build\src\ZODB\tests\HistoryStorage.py", line 26, in checkSimpleHistory
    self._checkHistory((11, 12, 13))
  File "c:\buildslave\zodb_dev_py_270_win32\build\src\ZODB\tests\HistoryStorage.py", line 50, in _checkHistory
    self.assertLess(a, b)
  File "c:\Python27_32\lib\unittest\case.py", line 930, in assertLess
    self.fail(self._formatMessage(msg, standardMsg))
  File "c:\Python27_32\lib\unittest\case.py", line 410, in fail
    raise self.failureException(msg)
AssertionError: 1465862401.079 not less than 1465862401.079

(This was building commit ee94233)

@mgedmin mgedmin reopened this Jun 14, 2016
@mgedmin
Copy link
Member

mgedmin commented Jun 14, 2016

The failures seem more rare, e.g. only 3 tests failed on Python 3.3 (32-bit), and none at all on Python 3.3 (64-bit).

The failures on Python 2.7 are all about X being not less than X with the exact same timestamp on both sides.

The failures on Python 3.x look like X not less than Y where Y looks like X truncated to 6 decimal digits, e.g.

Failure in test checkBaseHistory (ZODB.tests.testDemoStorage.DemoStorageTests)
Traceback (most recent call last):
  File "c:\Python33_32\lib\unittest\case.py", line 384, in _executeTestPart
    function()
  File "c:\buildslave\zodb_dev_py_330_win32\build\src\ZODB\tests\testDemoStorage.py", line 104, in checkBaseHistory
    self._checkHistory(base_and_changes())
  File "c:\buildslave\zodb_dev_py_330_win32\build\src\ZODB\tests\HistoryStorage.py", line 50, in _checkHistory
    self.assertLess(a, b)
  File "c:\Python33_32\lib\unittest\case.py", line 1026, in assertLess
    self.fail(self._formatMessage(msg, standardMsg))
  File "c:\Python33_32\lib\unittest\case.py", line 508, in fail
    raise self.failureException(msg)
AssertionError: 1465862988.8763752 not less than 1465862988.876375

Looks like the precision of time.time() was increased on Python 3. Meanwhile the truncation of tids to 6 decimal digits makes me suspect https://github.com/zopefoundation/persistent/blob/master/persistent/timestamp.py#L65 again.

@jmuchemb
Copy link
Member

I don't think there's any missing sleep. It's like sleep(0.001) does nothing.
So what to do, increasing until winbot is happy ?
Is there any special branch on which I could force-push draft commits until it works, so that I don't pollute master ? Or maybe someone can easily test on a Windows box.
I remembered I had an old XP image that runs in VirtualBox but I can't reproduce the issue (sleep(0.001) always sleeps more than 1ms). I should be able to try on bare metal next saturday.

@jimfulton
Copy link
Member

On Thu, Jun 16, 2016 at 7:38 AM, Julien Muchembled <notifications@github.com

wrote:

I don't think there's any missing sleep. It's like sleep(0.001) does
nothing.

The failures suggest that .002 will work.

So what to do, increasing until winbot is happy ?

Yes. I predict .002 will be enough.

Is there any special branch on which I could force-push draft commits
until it works, so that I don't pollute master ?

Adam, does winbot run tests against PRs?

If not, I'm not opposed to trying this on master. In fact, I'll bump it to
.002 on master shortly.

Or maybe someone can easily test on a Windows box.
I remembered I had an old XP image that runs in VirtualBox but I can't
reproduce the issue (sleep(0.001) always sleeps more than 1ms). I should be
able to try on bare metal next saturday.

Or that. :)

Jim

Jim Fulton
http://jimfulton.info

@jimfulton
Copy link
Member

On Thu, Jun 16, 2016 at 8:50 AM, Jim Fulton jim@jimfulton.info wrote:
...

Is there any special branch on which I could force-push draft commits
until it works, so that I don't pollute master ?

Adam, does winbot run tests against PRs?

If not, I'm not opposed to trying this on master. In fact, I'll bump it to
.002 on master shortly.

Done, Travis is green. Does anyone know how to force winbot to run?

Jim

Jim Fulton
http://jimfulton.info

@agroszer
Copy link
Contributor Author

Adam, does winbot run tests against PRs?

Sadly not, it's a buildbot, not a fancy-funky CI.

@agroszer
Copy link
Contributor Author

Done, Travis is green. Does anyone know how to force winbot to run?

I'll kick winbot

@jmuchemb
Copy link
Member

I could test on Windows and found that there was a missing sleep. Only committed in branch '4' for the moment.
Could we have a builder for the ZODB 4.x branch?

tseaver added a commit that referenced this issue Jun 23, 2016
@jmuchemb
Copy link
Member

2ms are useless. The issue was already fixed by f46359e (you can see also see the difference between builds #26 and #27).

Winbot still fails for another reason, apparently due to #56:

Error in test check2StorageThreads (ZODB.tests.testFileStorage.FileStorageTests)
Traceback (most recent call last):
  File "c:\Python27_64\lib\unittest\case.py", line 358, in run
    self.tearDown()
  File "c:\buildslave\zodb_dev_py_270_win64\build\src\ZODB\tests\StorageTestBase.py", line 156, in tearDown
    ZODB.tests.util.TestCase.tearDown(self)
  File "c:\buildslave\zodb_dev_py_270_win64\build\src\ZODB\tests\util.py", line 77, in tearDown
    zope.testing.setupstack.tearDown(test)
  File "d:\eggs\zope.testing-4.5.0-py2.7.egg\zope\testing\setupstack.py", line 44, in tearDown
    f(*p, **k)
  File "d:\eggs\zope.testing-4.5.0-py2.7.egg\zope\testing\setupstack.py", line 59, in rmtree
    os.remove(fname)
WindowsError: [Error 32] The process cannot access the file because it is being used by another process: 'c:\\buildslave\\ZODB_dev_py_270_win64\\build\\parts\\test\\tmp\\SetstateErrorLoggingTestso8d87k\\FileStorageTests1igsih\\FileStorageTests.fs'

@tseaver
Copy link
Member

tseaver commented Jun 30, 2016

@jmuchemb the 2ms change is what fixed the winbot timestamp failures. Those tests kept failing after f46359e (which you committed 2016-06-19 23:01 UTC), and went away after I pushed f886a01 (2016-06-23 12:08 UTC).

@jmuchemb
Copy link
Member

f46359e was committed in branch 4. It was merged in master with f9f3dda, which was tested after the build you mention.

jmuchemb referenced this issue Aug 2, 2016
…tion.

This implements: #50

Rather than watching invalidations, simply use 1 + the storages
lastTransaction, which is equivalent to but much simpler than waiting
for the first invalidation after a transaction starts.

More importantly, it means we can always use loadBefore and get away
from load.  We no longer have to worry about ordering of invalidations
and load() results.

Much thanks to NEO for pointing the way toward this simplification!

Implementing this initially caused a deadlock, because DB.open()
called Connection.open() while holding a database lock and
Connection.open() now calls IStotage.lastTransaction(), which acquires a
storage lock. (It's not clear that lastTransaction() really needs a
storage lock.)  Meanwhile, IStotage.tpc_finish() calls a DB function
that requires the DB lock while holding the storage lock.  Fixing this
required moving the call to Connection.open() outside the region where
the DB lock was held.

To debug the problem above, I greatly improved lock-debugging
support. Now all of the ZODB code imports Lock, RLock and Condition
from ZODB.utils. If the DEBUG_LOCKING is set to a non-empty value,
then these are wrapped in such a way that debugging information is
printed as they are used. This made spotting the nature of the
deadlock easier.

Of course, a change this basic broke lots of tests. Most of the
breakage arises from the fact that connections now call
lastTransaction on storages at transaction boundaries.  Lots of tests
didn't clean up databases and connections properly.  I fixed many
tests, but ultimately gave up and added some extra cleanup code that
violated transaction-manager underware (and the underware's privates)
to clear transaction synchonizers in test setup and tear-down.  I plan
to add a transaction manager API for this and to use it in a
subsequent PR.

This tests makes database and connection hygiene a bit more important,
especially for tests, because a connection will continue to interact
with storages if it isn't properly closed, which can lead to errors if
the storage is closed.  I chose not to swallow these errors in
Connection, choosing rather to clean up tests.

The thread debugging and test changes make this PR larger than I would
have liked. Apologies in advance to the reviewers.
@jmuchemb
Copy link
Member

jmuchemb commented Aug 7, 2016

The above issue is fixed by 8b00038, but I didn't notice there was yet another issue on win32:

Error in test test_configuration (ZODB.tests.testConnection.EstimatedSizeTests)
Traceback (most recent call last):
  File "c:\Python27_32\lib\unittest\case.py", line 329, in run
    testMethod()
  File "c:\buildslave\zodb_dev_py_270_win32\build\src\ZODB\tests\testConnection.py", line 1144, in test_configuration
    db = databaseFromString("<zodb>\n"
  File "c:\buildslave\zodb_dev_py_270_win32\build\src\ZODB\config.py", line 45, in databaseFromString
    return databaseFromFile(StringIO(s))
  File "c:\buildslave\zodb_dev_py_270_win32\build\src\ZODB\config.py", line 49, in databaseFromFile
    return databaseFromConfig(config.database)
  File "c:\buildslave\zodb_dev_py_270_win32\build\src\ZODB\config.py", line 59, in databaseFromConfig
    db = factory.open(databases)
  File "c:\buildslave\zodb_dev_py_270_win32\build\src\ZODB\config.py", line 130, in open
    **options)
  File "c:\buildslave\zodb_dev_py_270_win32\build\src\ZODB\DB.py", line 461, in __init__
    with self.transaction('initial database creation') as conn:
  File "c:\buildslave\zodb_dev_py_270_win32\build\src\ZODB\DB.py", line 922, in __enter__
    self.conn = self.db.open(self.tm)
  File "c:\buildslave\zodb_dev_py_270_win32\build\src\ZODB\DB.py", line 716, in open
    self._cache_size_bytes,
  File "c:\buildslave\zodb_dev_py_270_win32\build\src\ZODB\Connection.py", line 133, in __init__
    self._cache = PickleCache(self, cache_size, cache_size_bytes)
OverflowError: Python int too large to convert to C long

@jmuchemb
Copy link
Member

jmuchemb commented Aug 7, 2016

... Maybe this can be reproduced on linux 32 ?

@jmuchemb jmuchemb removed their assignment Aug 20, 2016
@jamadden
Copy link
Member

In #157 CI services on Windows (AppVeyor) were added in April of this year. Those are green, so maybe this issue can be closed?

It appears that winbot is still failing, but for a completely unrelated issue with buildout.

@jimfulton
Copy link
Member

Winbot's days are numbered anyway.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging a pull request may close this issue.

6 participants