magic-folder test failure on slackware buildslave (test_move_tree) #2834

Closed
opened 2016-09-27 18:53:07 +00:00 by warner · 7 comments
warner commented 2016-09-27 18:53:07 +00:00
Owner

5.g.: https://tahoe-lafs.org/buildbot-tahoe-lafs/builders/Markus%20slackware64%20stable/builds/279/steps/tox/logs/problems

This had been masked by #2807, which is now fixed. It's only happening on slackware, which is odd (travis and the other buildslaves are fine).

Traceback (most recent call last):
  File "/src/buildslave/tahoe-lafs/Markus_slackware64_stable/build/src/allmydata/test/test_magic_folder.py", line 1177, in <lambda>
    d.addCallback(lambda ign: self.failUnlessReallyEqual(self._get_count('uploader.objects_succeeded'), 3))
  File "/src/buildslave/tahoe-lafs/Markus_slackware64_stable/build/src/allmydata/test/common_util.py", line 78, in failUnlessReallyEqual
    self.failUnlessEqual(a, b, msg=msg)
  File "/src/buildslave/tahoe-lafs/Markus_slackware64_stable/build/.tox/py27/lib/python2.7/site-packages/twisted/trial/_synctest.py", line 425, in assertEqual
    super(_Assertions, self).assertEqual(first, second, msg)
  File "/usr/lib64/python2.7/unittest/case.py", line 513, in assertEqual
    assertion_func(first, second, msg=msg)
  File "/usr/lib64/python2.7/unittest/case.py", line 506, in _baseAssertEqual
    raise self.failureException(msg)
twisted.trial.unittest.FailTest: 4 != 3

allmydata.test.test_magic_folder.RealTest.test_move_tree
5.g.: <https://tahoe-lafs.org/buildbot-tahoe-lafs/builders/Markus%20slackware64%20stable/builds/279/steps/tox/logs/problems> This had been masked by #2807, which is now fixed. It's only happening on slackware, which is odd (travis and the other buildslaves are fine). ``` Traceback (most recent call last): File "/src/buildslave/tahoe-lafs/Markus_slackware64_stable/build/src/allmydata/test/test_magic_folder.py", line 1177, in <lambda> d.addCallback(lambda ign: self.failUnlessReallyEqual(self._get_count('uploader.objects_succeeded'), 3)) File "/src/buildslave/tahoe-lafs/Markus_slackware64_stable/build/src/allmydata/test/common_util.py", line 78, in failUnlessReallyEqual self.failUnlessEqual(a, b, msg=msg) File "/src/buildslave/tahoe-lafs/Markus_slackware64_stable/build/.tox/py27/lib/python2.7/site-packages/twisted/trial/_synctest.py", line 425, in assertEqual super(_Assertions, self).assertEqual(first, second, msg) File "/usr/lib64/python2.7/unittest/case.py", line 513, in assertEqual assertion_func(first, second, msg=msg) File "/usr/lib64/python2.7/unittest/case.py", line 506, in _baseAssertEqual raise self.failureException(msg) twisted.trial.unittest.FailTest: 4 != 3 allmydata.test.test_magic_folder.RealTest.test_move_tree ```
tahoe-lafs added the
code-frontend-magic-folder
normal
defect
1.11.0
labels 2016-09-27 18:53:07 +00:00
tahoe-lafs added this to the 1.12.0 milestone 2016-09-27 18:53:07 +00:00
dawuud commented 2016-10-05 12:36:57 +00:00
Author
Owner

it seems this test is failing because inotify is behaving differently. a directory is moved into the watched directory so the new directory is watched now. the directory is moved out of the watched directory and then a file is added to it... the test expects the event to be captured... although this is the behavior we expect on linux... it's OK if a given inotify implementation doesn't work that way. it's not indicative of a bug in our software.

it seems this test is failing because inotify is behaving differently. a directory is moved into the watched directory so the new directory is watched now. the directory is moved out of the watched directory and then a file is added to it... the test expects the event to be captured... although this is the behavior we expect on linux... it's OK if a given inotify implementation doesn't work that way. it's not indicative of a bug in our software.
dawuud commented 2016-10-06 13:16:55 +00:00
Author
Owner

actually i'm convinced the test should always fail as it's written now because the last thing test_move_tree is testing is weather our inotifier watcher is watching a sub-directory which was moved into the magic-folder and then move out.

created a ticket to address that bug:
https://tahoe-lafs.org/trac/tahoe-lafs/ticket/2836

actually i'm convinced the test *should* always fail as it's written now because the last thing test_move_tree is testing is weather our inotifier watcher is watching a sub-directory which was moved into the magic-folder and then move out. created a ticket to address that bug: <https://tahoe-lafs.org/trac/tahoe-lafs/ticket/2836>
daira commented 2016-10-13 16:59:05 +00:00
Author
Owner

I patched the magic folder code to print out log messages, and forced a build of that branch.

The Jessie and Xenial builders, which both succeed, have the same pattern of events: "local_dir/empty_tr\xc3\xaae moved_to, is_dir" once, as expected.

The Centos, Fedora, and Slackware builders, which fail, have a different pattern: "local_dir/empty_tree moved_to, is_dir" twice, then "local_dir/empty_tree delete_self".

It's unclear whether the filename being Unicode on the succeeding systems and ASCII on the failing systems is causative or a coincidence, given that the pattern of events is also different.

I patched the magic folder code to print out log messages, and forced a build of [that branch](https://github.com/daira/tahoe-lafs/commits/2834.enable-magic-folder-logging.0). The [Jessie](https://tahoe-lafs.org/buildbot-tahoe-lafs/builders/Debian%20Jessie/builds/11/steps/tox/logs/stdio) and [Xenial](https://tahoe-lafs.org/buildbot-tahoe-lafs/builders/Ubuntu%20xenial%2016.04/builds/6/steps/tox/logs/stdio) builders, which both succeed, have the same pattern of events: "`local_dir/empty_tr\xc3\xaae` moved_to, is_dir" once, as expected. The [Centos](https://tahoe-lafs.org/buildbot-tahoe-lafs/builders/Centos%207/builds/2/steps/tox/logs/stdio), [Fedora](https://tahoe-lafs.org/buildbot-tahoe-lafs/builders/Fedora%2024/builds/4/steps/tox/logs/stdio), and [Slackware](https://tahoe-lafs.org/buildbot-tahoe-lafs/builders/Markus%20slackware64%20stable/builds/283/steps/tox/logs/stdio) builders, which fail, have a different pattern: "`local_dir/empty_tree` moved_to, is_dir" **twice**, then "`local_dir/empty_tree` delete_self". It's unclear whether the filename being Unicode on the succeeding systems and ASCII on the failing systems is causative or a coincidence, given that the pattern of events is also different.
dawuud commented 2016-10-19 14:20:46 +00:00
Author
Owner

i modified magic-folder class and queue mixin to allow for debug logging after the magic-folder object has been created... that way in our tests we can easily turn debug logging on for a particular test as i've done here for test_move_tree:

https://github.com/david415/tahoe-lafs/tree/2834.logging_test_move_tree.0

however this change uses 'print' to log the messages instead of twisted logger. i suppose we cannot merge this until that's fixed.

i modified magic-folder class and queue mixin to allow for debug logging after the magic-folder object has been created... that way in our tests we can easily turn debug logging on for a particular test as i've done here for test_move_tree: <https://github.com/david415/tahoe-lafs/tree/2834.logging_test_move_tree.0> however this change uses 'print' to log the messages instead of twisted logger. i suppose we cannot merge this until that's fixed.
warner commented 2016-10-19 18:05:31 +00:00
Author
Owner

yeah, make it a twisted.python.log.msg() and they'll show up in test.log where the buildbot can show them to us

yeah, make it a twisted.python.log.msg() and they'll show up in test.log where the buildbot can show them to us
Brian Warner <warner@lothar.com> commented 2016-11-02 20:58:54 +00:00
Author
Owner

In 250c6f60/trunk:

test_magic_folder: mark failing test as .todo

As discussed in this week's meeting, since we don't yet know why some
flavors of linux have slightly different inotify behavior than others,
and since we believe the actual functionality is not significantly
impacted, and since the red buildbot is reducing our confidence that the
other tests are passing, and since we have a release coming up: we're
marking the one troublesome test as ".todo". We expect that the test
will be fixed soon (perhaps to accept either 3 or 4 events), but not
necessarily before the 1.12 release.

refs ticket:2834
In [250c6f60/trunk](/tahoe-lafs/trac-2024-07-25/commit/250c6f6054c05df66957412d33b022f5b423a0d4): ``` test_magic_folder: mark failing test as .todo As discussed in this week's meeting, since we don't yet know why some flavors of linux have slightly different inotify behavior than others, and since we believe the actual functionality is not significantly impacted, and since the red buildbot is reducing our confidence that the other tests are passing, and since we have a release coming up: we're marking the one troublesome test as ".todo". We expect that the test will be fixed soon (perhaps to accept either 3 or 4 events), but not necessarily before the 1.12 release. refs ticket:2834 ```
dawuud commented 2016-12-08 18:47:25 +00:00
Author
Owner

this TODO and this ticket can go away once we've landed our new inotify test suite from #1432.

it will improve reliability of tests by only making a small set of inotify tests actually test the inotify implementation. all the magic-folder tests will use a mock inotify.

this TODO and this ticket can go away once we've landed our new inotify test suite from #1432. it will improve reliability of tests by only making a small set of inotify tests actually test the inotify implementation. all the magic-folder tests will use a mock inotify.
tahoe-lafs added the
fixed
label 2016-12-09 21:44:10 +00:00
dawuud closed this issue 2016-12-09 21:44:10 +00:00
Sign in to join this conversation.
No milestone
No project
No assignees
1 participant
Notifications
Due date
The due date is invalid or out of range. Please use the format "yyyy-mm-dd".

No due date set.

Dependencies

No dependencies set.

Reference: tahoe-lafs/trac-2024-07-25#2834
No description provided.