Bug #2857

fix flaky CollectionsControllerTest

Added by Tim Pierce over 6 years ago. Updated over 6 years ago.

Status:
Resolved
Priority:
Normal
Assigned To:
Tim Pierce
Category:
-
Start date:
05/23/2014
Due date:
% Done:

100%

Estimated time:
(Total: 9.00 h)
Story points:
1.0

Description

CollectionsControllerTest is flaky due to generating signatures with timestamp drift, e.g. from a recent run:

  1) Failure:
Arvados::V1::CollectionsControllerTest#test_should_create [/var/lib/jenkins/workspace/arvados-api-server/services/api/test/functional/arvados/v1/collections_controller_test.rb:72]:
<". d41d8cd98f00b204e9800998ecf8427e+0+Ade9f03c9fa4c516a5f17a92452797f7b085b95b8@5391ff4b 0:0:foo.txt\n. acbd18db4cc2f85cedef654fccc4a4d8+3+A4af0dd24ad478246555c47c1b6aa7ae6a076e038@5391ff4b 0:3:bar.txt\n. acbd18db4cc2f85cedef654fccc4a4d8+3+A4af0dd24ad478246555c47c1b6aa7ae6a076e038@5391ff4b 0:3:bar.txt\n./baz acbd18db4cc2f85cedef654fccc4a4d8+3+A4af0dd24ad478246555c47c1b6aa7ae6a076e038@5391ff4b 0:3:bar.txt\n"> expected but was
<". d41d8cd98f00b204e9800998ecf8427e+0+A3779de52ecfbd8ad78722b20aa32ebbfcf89c86b@5391ff4c 0:0:foo.txt\n. acbd18db4cc2f85cedef654fccc4a4d8+3+A3ceafcbc2755d617a5adfe2d1a0efb67e8c0edc6@5391ff4c 0:3:bar.txt\n. acbd18db4cc2f85cedef654fccc4a4d8+3+A3ceafcbc2755d617a5adfe2d1a0efb67e8c0edc6@5391ff4c 0:3:bar.txt\n./baz acbd18db4cc2f85cedef654fccc4a4d8+3+A3ceafcbc2755d617a5adfe2d1a0efb67e8c0edc6@5391ff4c 0:3:bar.txt\n">.

192 tests, 872 assertions, 1 failures, 0 errors, 0 skips


Subtasks

Task #2964: Guarantee consistent timestamps for permission hints in testing.ResolvedTim Pierce

Task #2978: Review 2857-permission-testsResolvedTim Pierce

Associated revisions

Revision cea92754 (diff)
Added by Tim Pierce over 6 years ago

2857: fix flaky time-sensitive tests

Allow tests to inject a mock Time object into Blob, in order to generate
consistent behavior for tests that rely on permission signatures.

Closes #2857.

Revision 488a8113 (diff)
Added by Tim Pierce over 6 years ago

2857: strip signatures from manifests before testing equality.

As Brett observed, the "post" method in these tests mutates its
argument. For a valid test, we must ensure that the source data has not
been transformed into the result data.

For tests which do not care about validating the signatures, we just
strip out the signatures from the result manifest before comparing it to
the source.

Refs #2857.

Revision f0d8ab52
Added by Tim Pierce over 6 years ago

Merge branch '2857-collection-tests'

Closes #2857.

History

#1 Updated by Tom Clegg over 6 years ago

  • Story points set to 1.0

#2 Updated by Tom Clegg over 6 years ago

  • Target version changed from 2014-05-28 Pipeline Factory to 2014-06-17 Curating and Crunch

#3 Updated by Tim Pierce over 6 years ago

  • Status changed from New to Resolved
  • % Done changed from 0 to 100

Applied in changeset arvados|commit:cea92754dfacf2b409d1f5b45dd0775fc44c842d.

#4 Updated by Tim Pierce over 6 years ago

  • Status changed from Resolved to In Progress

#5 Updated by Brett Smith over 6 years ago

I'm having trouble following the original failing test. It starts out by assigning a static test_collection[:manifest_text]. It creates test_collection, then re-shows it, and compares test_collection against that response. Yet somehow permission signatures appear in test_collection, based on the output in this ticket. As best I can tell, the only way this can happen is if the create method modifies test_collection in place.

Am I missing something? If not, I'm concerned that the bigger issue here is not the clock, but instead the test's reliance on these side effects in the create method. Aside from bad timing, the test could also fail if somone changes this implementation detail. I think a better improvement would be to modify the test itself so that it only checks or relies on behavior that we actually care about—that would both fix the immediate problem and prevent future trouble.

But if I've overlooked something and misunderstood, do let me know.

#6 Updated by Tim Pierce over 6 years ago

Changes @ 488a811:

You are correct that the controller is mutating the collection that we pass to it. Ew!

I've rewritten the "should create" test (and the "multiple locators per line" test which appears to have been a victim of the same bug) to guarantee via marshalling and unmarshalling that the arguments to post :create are distinct from the source test data. Please feel free to double check these assumptions.

Injecting a fake clock is no longer necessary, so I've taken out that code. It would be good to be able to mock stuff like this in the future, but there are surely better ways of doing it.

Review from master: master...origin/2857-collection-tests

#7 Updated by Brett Smith over 6 years ago

Tim Pierce wrote:

I've rewritten the "should create" test (and the "multiple locators per line" test which appears to have been a victim of the same bug) to guarantee via marshalling and unmarshalling that the arguments to post :create are distinct from the source test data. Please feel free to double check these assumptions.

Injecting a fake clock is no longer necessary, so I've taken out that code. It would be good to be able to mock stuff like this in the future, but there are surely better ways of doing it.

On the whole, this approach seems a lot more sensible to me. Thanks for taking the time to dig in and rework it. My comments now are much smaller:

  • I know this might not be your code, but while we're cleaning up in here, I doubt that assert_nil assigns(:objects) is doing much interesting. Only index methods would normally assign this, and I expect the rest of the stack would ignore it if create did assign it. If you understand its intent better, maybe there's a better assertion that could go here? Otherwise, I think it should come out.
  • Why are _ and - in the signature-stripping regexp? This question is mostly for my own edification—I'm concerned that I need to go back and fix my own signature-parsing code. :)

Once you deal with the odd assertion I think you're good to merge. Thanks again.

#8 Updated by Tim Pierce over 6 years ago

Brett Smith wrote:

  • I know this might not be your code, but while we're cleaning up in here, I doubt that assert_nil assigns(:objects) is doing much interesting. Only index methods would normally assign this, and I expect the rest of the stack would ignore it if create did assign it. If you understand its intent better, maybe there's a better assertion that could go here? Otherwise, I think it should come out.

Well, it's not my code and I'm not sure I do understand its intent better. However! :-) My understanding here is that this confirms that Collections.find_object_by_uuid was not called successfully, i.e. that the system did not find any existing collection in the database by that UUID when we attempted to create one, and that the subsequent assert_not_nil assigns(:objects) after performing GET confirms that it did find one. That makes sense to me -- does it look different to you?

I'm going to go ahead and merge and close this ticket, since this particular code isn't affected by this issue, but let's make sure to close the loop and confirm whether this assertion actually expresses what we think it does.

  • Why are _ and - in the signature-stripping regexp? This question is mostly for my own edification—I'm concerned that I need to go back and fix my own signature-parsing code. :)

Tom and I (mostly me) decided in #2755 that a blob locator hint may contain alphanumerics, "@", "_" and "-". We do not currently have any hints that use _ or - that I know of, but I threw those in on the basis that they're very often considered valid identifier or word characters, and I would personally be surprised to generate a locator with those characters and find that it wasn't parsed correctly.

#9 Updated by Tim Pierce over 6 years ago

  • Status changed from In Progress to Resolved
  • % Done changed from 0 to 100

Applied in changeset arvados|commit:f0d8ab52b77f74e9294fe634207ce6e1ff9748a1.

Also available in: Atom PDF