Martijn Wargers (dead) Assignee
	Description • 9 years ago

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.

	Martijn Wargers (dead) Assignee
	Comment 2 • 9 years ago

(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

	Martijn Wargers (dead) Assignee
	Comment 3 • 9 years ago

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.

	Martijn Wargers (dead) Assignee
	Comment 4 • 9 years ago

(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.

	Martijn Wargers (dead) Assignee
	Comment 5 • 9 years ago

Is something like this reasonable? (I think it is)

	No-Jun Park [:njpark]
	Comment 6 • 9 years ago

Comment on attachment 8617922 [details] [review]
https://github.com/mozilla-b2g/gaia/pull/30520

LGTM.

	Johan Lorenzo [:jlorenzo]
	Comment 7 • 9 years ago

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.

	Martijn Wargers (dead) Assignee
	Comment 8 • 9 years ago

(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).

	Martijn Wargers (dead) Assignee
	Comment 9 • 9 years ago

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.

	Johan Lorenzo [:jlorenzo]
	Comment 10 • 9 years ago

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.

	Martijn Wargers (dead) Assignee
	Comment 11 • 9 years ago

(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.

	No-Jun Park [:njpark]
	Comment 12 • 9 years ago

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.

	Martijn Wargers (dead) Assignee
	Comment 13 • 9 years ago

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.

	Martijn Wargers (dead) Assignee
	Comment 14 • 9 years ago

Merged: https://github.com/mozilla-b2g/gaia/commit/a20a86755274d942b62e92b34452fa6d58d30819

	Oliver Nelson [:oliverthor]
	Comment 15 • 9 years ago

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.

	Martijn Wargers (dead) Assignee
	Comment 16 • 9 years ago

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.

	Martijn Wargers (dead) Assignee
	Comment 17 • 9 years ago

See comment 16.