539908 - Random orange: TEST-UNEXPECTED-FAIL | test_videoAllowedInMail

Status: RESOLVED FIXED

(Thunderbird :: General, defect)

Description

[Mark Banner (:standard8)]

TEST-UNEXPECTED-FAIL |  test_videoAllowedInMail
  EXCEPTION: Video has not been blocked in message content as expected.
    at: test-video-content-policy.js line 205
       Error("Video has not been blocked in message content as expected.")  0
       test_videoAllowedInMail() test-video-content-policy.js 205
            frame.js 460
            frame.js 512
            frame.js 554
            frame.js 403
            frame.js 559
            server.js 164
            server.js 168

http://tinderbox.mozilla.org/showlog.cgi?log=ThunderbirdTest/1263533744.1263536301.8530.gz

Comment 1

[Mark Banner (:standard8)]

Attachment: [checked in] Fix comments, add debug.

Looking at the test, I obviously did some incorrect copy and paste on the failure statements. This patch corrects those.

For the failure case, this bug adds a delay and then some extra debugging. It does not make the test pass. My suspicion is that wait_for_message_display_completion isn't doing what it should be, but I want to catch it in the act.

Comment 2

[Andrew Sutherland [:asuth] (he/him)]

You might want to try passing 'true' for wait_for_message_display_completion's aLoadDemanded argument.  By default, the method only does something if a load is in progress.  If the load is not reliably initiated, the method will end up not actually doing any waiting...

Code with the doc block:
http://mxr.mozilla.org/comm-central/source/mail/test/mozmill/shared-modules/test-folder-display-helpers.js#1060

Comment 3

[Mark Banner (:standard8)]

(In reply to comment #2)
> You might want to try passing 'true' for wait_for_message_display_completion's
> aLoadDemanded argument.  By default, the method only does something if a load
> is in progress.  If the load is not reliably initiated, the method will end up
> not actually doing any waiting...

Whilst I believe the load should always be initiated (we end up calling reloadMessage on the dbView) there could be something I'm not aware of.

This failure is occurring a couple of times a day, so I've checked in the patch as-is to confirm that the allowing of remote content is happening, and there isn't some weirder kind of error. Once we get the debug, then I'll probably try adding the true parameter.

Comment 4

[Mark Banner (:standard8)]

Comment on attachment 421806 [details] [diff] [review]
[checked in] Fix comments, add debug.

http://hg.mozilla.org/comm-central/rev/180c22a0e1b1

Comment 5

[Mark Banner (:standard8)]

The error occurred again very quickly and we got:

Video was unexpectedly blocked. Network State was: 4After a 3 second sleep, the network state is now: 1

Which means after a bit longer it did work fine.

Comment 6

[Mark Banner (:standard8)]

Attachment: Proposed fix

Based on asuth's comments - pass true to wait_for_message_display_completion and remove the debug code. Sid tells me that onclick isn't guaranteed to be synchronous and this follows what is happening in the test.

Comment 7

[Rain [:rain1] (inactive)]

Comment on attachment 422094 [details] [diff] [review]
Proposed fix

Nit: You could get rid of the braces around the now single-statement if.

Let's see if this fixes things.

Comment 8

[Rain [:rain1] (inactive)]

Bah, it didn't help: <http://tinderbox.mozilla.org/showlog.cgi?log=ThunderbirdTest/1263748464.1263750599.15074.gz>

Comment 9

[Rain [:rain1] (inactive)]

I'm wondering if we're missing the case where we've returned without yet firing the oncommand handler at <http://mxr.mozilla.org/comm-central/source/mail/base/content/mailWindowOverlay.xul#1872>, and so messageLoaded hasn't yet become false. This would mean that we pass the isLoadedChecker check without waiting for messageLoaded to become false, then true. asuth, could something like this happen?

One solution to this might be to call LoadMsgWithRemoteContent() directly.

Comment 10

[Rain [:rain1] (inactive)]

s/to become false, then true/to become true/

Comment 11

[Andrew Sutherland [:asuth] (he/him)]

Attachment: add plan_for_message_display, debug helper, and improve docs v1

(In reply to comment #9)
> I'm wondering if we're missing the case where we've returned without yet firing
> the oncommand handler at

This sounds very possible.  When I read all of the docs for wait_for_message_display_completion, I notice that it requires messageLoaded to be false at that point when requiring a load.  I think it's slightly incorrect about that; what we want to require is that messageLoaded was forced or verified to be false prior to triggering the action that would initiate a load.  (Otherwise wait_for_message_display_completion could be a more friendly API and just clobber the variable itself.)

It's probably best to abstract this issue by introducing a new helper "plan_for_message_display" that clobbers messageLoaded but could do something more elegant in the future.

> One solution to this might be to call LoadMsgWithRemoteContent() directly.

This seems less desirable than the above.

I've implemented the former fix and verified this solves the problem locally.  To enable the verification I've added a simple augmented helper function to the controller called defer_click which allows us to synthesize the presumed failure in this case.  Without the call to 'plan_for_message_display' and using defer_click the test appears to fail per this bug's description.

Comment 12

[Rain [:rain1] (inactive)]

The patch looks good.

I think having them both set to false instead of null initially would make more sense -- also, we should probably do this with other wait_for_message_display_completion(_, true) calls too.

Comment 13

[Andrew Sutherland [:asuth] (he/him)]

Comment on attachment 422157 [details] [diff] [review]
add plan_for_message_display, debug helper, and improve docs v1

treating previous comment as r=sid0.  I'll make the null/false change and push.  (At some point I adopted null as a marker that an attribute exists on the prototype but should be initialized in the constructor; but since we aren't initializing in the constructor here, that makes no sense.)

Leaving the other wait_for_message_display_completion stuff for another patch for now, noting that I change all of the cases in folder-display already.  (The cases not changed were for new windows where it's not required, as per my docs.)

Comment 14

[Andrew Sutherland [:asuth] (he/him)]

pushed attachment 422157 [details] [diff] [review]:
http://hg.mozilla.org/comm-central/rev/3224404d8ed9

Comment 15

[Rain [:rain1] (inactive)]

We've had around 50 test runs since, and the test hasn't failed even once. Looks like it's fixed.

Comment 16

[Rain [:rain1] (inactive)]

Comment on attachment 422157 [details] [diff] [review]
add plan_for_message_display, debug helper, and improve docs v1

NPOTB, test-only correctness fix.

Comment 17

[Mark Banner (:standard8)]

Comment on attachment 422157 [details] [diff] [review]
add plan_for_message_display, debug helper, and improve docs v1

a=Standard8 but you should land the other two patches as well (especially the first to get the test failure text right).

Comment 18

[Rain [:rain1] (inactive)]

in order:

http://hg.mozilla.org/releases/comm-1.9.1/rev/d9b40f7b2763
http://hg.mozilla.org/releases/comm-1.9.1/rev/dc191b1d559d
http://hg.mozilla.org/releases/comm-1.9.1/rev/b46353fdc58f

Comment 19

[Mark Banner (:standard8)]

Verifying as fixed for 3.0.2 based on the fact that these are test-only patches and the last 5 runs from MozMill/unit tests have been green with no failures relating to these patches.