Closed Bug 1172460 Opened 7 years ago Closed 7 years ago

Intermittent failure in test_sms_notification_removed_when_sms_deleted.py in wait_for_notification_toaster_displayed

Categories

(Firefox OS Graveyard :: Gaia::UI Tests, defect)

ARM
Gonk (Firefox OS)
defect
Not set
normal

Tracking

(Not tracked)

RESOLVED FIXED

People

(Reporter: martijn.martijn, Assigned: martijn.martijn)

References

()

Details

Attachments

(3 files)

I saw this here:
http://jenkins1.qa.scl3.mozilla.com/job/flame-kk-319.mozilla-central.nightly.ui.functional.non-smoke.2/277/HTML_Report/
UNEXPECTED_ERROR 	test_sms_notification_removed_when_sms_deleted.py TestSmsNotificationRemovedWhenSMSDeleted.test_sms_notification_removed_when_sms_deleted 	374.25 	Source Screenshot Settings
Traceback (most recent call last):
  File "/var/jenkins/2/workspace/flame-kk-319.mozilla-central.nightly.ui.functional.non-smoke.2/.env/local/lib/python2.7/site-packages/marionette_client-0.13-py2.7.egg/marionette/marionette_test.py", line 296, in run
    testMethod()
  File "/var/jenkins/2/workspace/flame-kk-319.mozilla-central.nightly.ui.functional.non-smoke.2/tests/python/gaia-ui-tests/gaiatest/tests/functional/messages/test_sms_notification_removed_when_sms_deleted.py", line 34, in test_sms_notification_removed_when_sms_deleted
    message="Notification did not appear. SMS database dump: %s " % self.data_layer.get_all_sms())
  File "/var/jenkins/2/workspace/flame-kk-319.mozilla-central.nightly.ui.functional.non-smoke.2/tests/python/gaia-ui-tests/gaiatest/apps/system/app.py", line 41, in wait_for_notification_toaster_displayed
    Wait(self.marionette, timeout).until(expected.element_displayed(el), message=message)
  File "/var/jenkins/2/workspace/flame-kk-319.mozilla-central.nightly.ui.functional.non-smoke.2/.env/local/lib/python2.7/site-packages/marionette_driver-0.7-py2.7.egg/marionette_driver/wait.py", line 143, in until
    cause=last_exc)
TimeoutException: TimeoutException: Timed out after 300.1 seconds with message: Notification did not appear. SMS database dump: [{u'body': u'Automated Test 1433676047.86', u'deliveryStatus': u'not-applicable', u'sender': u'16509655943', u'read': True, u'timestamp': 1433675967931, u'threadId': 1, u'sentTimestamp': 1433675969599, u'delivery': u'sent', u'receiver': u'+16509655943', u'iccId': u'89014105276963970855', u'type': u'sms', u'id': 1, u'deliveryTimestamp': 0, u'messageClass': u'normal'}, {u'body': u'Automated Test 1433676047.86', u'deliveryStatus': u'success', u'sender': u'+16509655943', u'read': False, u'timestamp': 1433675971253, u'threadId': 1, u'sentTimestamp': 1433675970000, u'delivery': u'received', u'receiver': u'16509655943', u'iccId': u'89014105276963970855', u'type': u'sms', u'id': 2, u'deliveryTimestamp': 0, u'messageClass': u'normal'}] 


Interestingly, the debug message and the screenshot shows there was an sms notification sent, but for some reason, it wasn't picked up.
(In reply to Martijn Wargers [:mwargers] (QA) from comment #1)
> Created attachment 8616627 [details] [review]
> Add stable = false to this test

Merged this: https://github.com/mozilla-b2g/gaia/commit/f9e95e296c5439165ad45fd341120505ffcb64da
See Also: → 1172618
In normal times from the database dump:
sender: 'sentTimestamp': 1433675969.599 - Sun, 07 Jun 2015 11:19:29 GMT
receiver:'timestamp': 1433675971.253 - Sun, 07 Jun 2015 11:19:31 GMT
receiver:'sentTimestamp': 1433675970.000 - Sun, 07 Jun 2015 11:19:30 GMT

So it looks like the sms was received already 2 seconds after it was sent.

My guess is that the data_layer can be slow to respond before it sees that the sms has been sent:
http://mxr.mozilla.org/gaia/source/tests/atoms/gaia_data_layer.js#498

It makes me wonder if we should move the wait_for_notification_toaster_displayed before the self.data_layer.send_sms call.
I don't think it can hurt and it could potentially resolve this failure.
(In reply to Martijn Wargers [:mwargers] (QA) from comment #3)
> It makes me wonder if we should move the
> wait_for_notification_toaster_displayed before the self.data_layer.send_sms
> call.
> I don't think it can hurt and it could potentially resolve this failure.

Ah wait, that's of course not possible.
Is something like this reasonable? (I think it is)
Attachment #8617922 - Flags: review?(npark)
Attachment #8617922 - Flags: review?(jlorenzo)
Comment on attachment 8617922 [details] [review]
https://github.com/mozilla-b2g/gaia/pull/30520

If I understand correctly, if we put these ifs, we won't test the notification anymore, which was the purpose of both tests. Also having these assertions at the beginning of the tests can give us another set of intermittent failures. 

I proposed some solutions in GitHub.
Attachment #8617922 - Flags: review?(jlorenzo) → review-
(In reply to Johan Lorenzo [:jlorenzo] (QA) from comment #7)
> Comment on attachment 8617922 [details] [review]
> https://github.com/mozilla-b2g/gaia/pull/30520
> 
> If I understand correctly, if we put these ifs, we won't test the
> notification anymore, which was the purpose of both tests. Also having these
> assertions at the beginning of the tests can give us another set of
> intermittent failures. 
> 
> I proposed some solutions in GitHub.

Ok, thanks, it turns out that this is indeed a problem in this case apparently:
http://jenkins1.qa.scl3.mozilla.com/view/Bitbar/job/flame-kk-319.mozilla-central.nightly.ui.functional.non-smoke.1.bitbar/96/HTML_Report/
In that case, there are 2 sms messages in the sms database, but there is no blue notification line, which indicated that there was a notification toaster.

I think it would be better to use the UI for sending an sms message here. self.data_layer.sendSMS might just be too slow sometimes. (SMS already sent and received, while that function is still running).
Comment on attachment 8617922 [details] [review]
https://github.com/mozilla-b2g/gaia/pull/30520

How about something like this?
This makes self.data_layer.send_sms finish instantly, so that the check for the notification is on time.
I think it makes sense. It means that in those cases, the sending of the sms check is not done in gaia_test.py and gaia_data_layer.js, but since we're checking for the sms notification anyway, that shouldn't matter.
Attachment #8617922 - Flags: review- → review?(jlorenzo)
Comment on attachment 8617922 [details] [review]
https://github.com/mozilla-b2g/gaia/pull/30520

That may work. However we need to change the variable name to something else. "synchronous" will lie to people using send_sms(), because if you set it to true, you don't execute exactly the same function but in a synchronous way; you by pass the verification on the send status. Let's rename it to something like "byPassSendVerification".

Re-asking No-Jun for review as that's not the same pull request anymore.
Attachment #8617922 - Flags: review?(npark)
Attachment #8617922 - Flags: review?(jlorenzo)
Attachment #8617922 - Flags: review+
(In reply to Johan Lorenzo [:jlorenzo] (QA) from comment #10)
> That may work. However we need to change the variable name to something
> else. "synchronous" will lie to people using send_sms(), because if you set
> it to true, you don't execute exactly the same function but in a synchronous
> way; you by pass the verification on the send status. Let's rename it to
> something like "byPassSendVerification".

Yeah, thanks, I struggled to find a good word for it. But what you propose makes perfect sense.
Comment on attachment 8617922 [details] [review]
https://github.com/mozilla-b2g/gaia/pull/30520

echoing Johan's comment.  something like 'skip_verification' would make it easier to read, but other that that, this is a simpler fix to the problem than the one that we were discussing last time.
Attachment #8617922 - Flags: review?(npark) → review+
Comment on attachment 8617922 [details] [review]
https://github.com/mozilla-b2g/gaia/pull/30520

Ok, just a quick recheck, ok?
I've used skip_verification now. Also, added a return, after the marionetteScriptFinished call.

I'll squash the commits when I merge this pull request.
Attachment #8617922 - Flags: review+ → review?(npark)
Attachment #8617922 - Flags: review?(npark) → review+
Merged: https://github.com/mozilla-b2g/gaia/commit/a20a86755274d942b62e92b34452fa6d58d30819
Status: NEW → RESOLVED
Closed: 7 years ago
Resolution: --- → FIXED
This issue is still failing: it has about a 60% repro rate so it has dodged some reports. It looks like the cause was also hypothesized by Dave Hunt in bug 1172618:

"Hmm.. I distinctly recall responding to this - maybe I forgot to click save! Does that affect more than one device? If so, it's likely an environment issue. If not, it may be that the phone number label is incorrect on Bitbar's side. You can find the phone number associated with the selected in the device.json artifact in Jenkins. We should e-mail Bitbar if we think the wrong phone number is associated with a device."

I'll take a look into his second claim with some local adhoc testing. Since these issues are identical, I think we should dupe bug 1172618 to this issue and reopen as the fix did not resolve the issue. ni? Martijn for further action suggested.
Flags: needinfo?(martijn.martijn)
Yeah, I planned to take action on the issue mentioned in bug 1172618, comment 2 to do some logging of the phone numbers in the sim and the testvars that are mentioned in the Jenkins output, but I haven't got around to do that yet.

This is a different bug than the one in bug 1172618, because in this case, the sms was actually received, so I don't think it's a good idea to dupe this bug to that bug.
See comment 16.
Flags: needinfo?(martijn.martijn)
You need to log in before you can comment on or make changes to this bug.