Last Comment Bug 760199 - test_incoming.js: TEST-UNEXPECTED-FAIL | got false, expected true
: test_incoming.js: TEST-UNEXPECTED-FAIL | got false, expected true
Status: RESOLVED FIXED
: intermittent-failure
Product: Core
Classification: Components
Component: DOM: Device Interfaces (show other bugs)
: Trunk
: All All
: -- normal (vote)
: mozilla17
Assigned To: Vicamo Yang [:vicamo][:vyang]
:
Mentors:
Depends on:
Blocks: 438871 707659
  Show dependency treegraph
 
Reported: 2012-05-31 10:55 PDT by Jonathan Griffin (:jgriffin)
Modified: 2012-11-25 19:31 PST (History)
5 users (show)
See Also:
Crash Signature:
(edit)
QA Whiteboard:
Iteration: ---
Points: ---
Has Regression Range: ---
Has STR: ---


Attachments
fix test failure due to SMSC timestamp truncation (947 bytes, patch)
2012-08-15 21:21 PDT, Vicamo Yang [:vicamo][:vyang]
philipp: review+
Details | Diff | Splinter Review

Description Jonathan Griffin (:jgriffin) 2012-05-31 10:55:00 PDT
This is one of the Marionette sms WebAPI tests for B2G.  On the last 10 runs of this test, 9 have failed with:

test_incoming.js
TEST-UNEXPECTED-FAIL | Traceback (most recent call last):
File "/data/jenkins/jobs/webapi-marionette-test/workspace/testing/marionette/client/marionette/marionette_test.py", line 194, in runTest
'%d tests failed:\n%s' % (results['failed'], '\n'.join(fails)))
AssertionError: 1 tests failed:
TEST-UNEXPECTED-FAIL | got false, expected true

This is the only failure on the WebAPI CI at present.

The logcat for this test is:

I/Gecko   (   41): MARIONETTE LOG: INFO: Sent fake SMS: OK
I/Gecko   (   41): MARIONETTE TEST RESULT:TEST-PASS | undefined - OK should equal OK
I/Gecko   (   41): MARIONETTE LOG: INFO: Received an SMS!
I/Gecko   (   41): MARIONETTE TEST RESULT:TEST-PASS | undefined
I/Gecko   (   41): MARIONETTE TEST RESULT:TEST-PASS | undefined - received should equal received
I/Gecko   (   41): MARIONETTE TEST RESULT:TEST-PASS | undefined - 5555552368 should equal 5555552368
I/Gecko   (   41): MARIONETTE TEST RESULT:TEST-PASS | undefined - null should equal null
I/Gecko   (   41): MARIONETTE TEST RESULT:TEST-PASS | undefined - Hello SMS world! should equal Hello SMS world!
I/Gecko   (   41): MARIONETTE TEST RESULT:TEST-PASS | undefined
I/Gecko   (   41): MARIONETTE TEST RESULT:TEST-UNEXPECTED-FAIL | undefined
Comment 1 Jonathan Griffin (:jgriffin) 2012-06-14 12:18:23 PDT
The specific test assertion which is apparently failing, given the log above, is:

  ok(message.timestamp.getTime() > now);
Comment 2 Philipp von Weitershausen [:philikon] 2012-06-14 17:42:02 PDT
(In reply to Jonathan Griffin (:jgriffin) from comment #1)
> The specific test assertion which is apparently failing, given the log
> above, is:
> 
>   ok(message.timestamp.getTime() > now);

Interesting. I'll get a patch ready to print the discrepancy of the timestamps. Maybe that'll tell us something. My initial idea was timezones, but both Date.now() and Date.prototype.getTime() should return the timestamp in UTC... mysterious, mysterious.
Comment 3 Andrew Overholt [:overholt] 2012-06-15 07:41:56 PDT
Mounir, can you please take a look at this failure?  If you don't have enough time, just let me know.  Thanks!
Comment 4 Mounir Lamouri (:mounir) 2012-06-19 06:55:15 PDT
(In reply to Andrew Overholt [:overholt] from comment #3)
> Mounir, can you please take a look at this failure?  If you don't have
> enough time, just let me know.  Thanks!

As said during the WebAPI meeting this is unlikely relevant to the WebSMS DOM code but likely to the WebSMS Gonk backend: message timestamps is provided by the backend, not the DOM code.
I assigned this to Philipp given that he said in comment 2 that he will have a look.
Comment 5 Vicamo Yang [:vicamo][:vyang] 2012-08-15 20:23:32 PDT
A SMS-DELIVER message comes with a timestamp embedded by SMSC and it's the one that we pass to DOM. However, its max accuracy is `seconds`, so here is an example of failure:

> INFO Received an SMS! Thu Aug 16 2012 03:17:05 GMT+0000 (GMT)
> INFO Now : 1345087025303 Thu Aug 16 2012 03:17:05 GMT+0000 (GMT)
> INFO Recv: 1345087025000 Thu Aug 16 2012 03:17:05 GMT+0000 (GMT)
> INFO Sent fake SMS: OK Thu Aug 16 2012 03:17:05 GMT+0000 (GMT)

As you may see, the SMSC timestamp was truncated to 1345087025"000". Thanks to modern CPU power, it is possible that the emulator finishes all the work in a second and therefore results in the test failure in this case.

I'll upload a patch later for this.
Comment 6 Vicamo Yang [:vicamo][:vyang] 2012-08-15 21:21:03 PDT
Created attachment 652318 [details] [diff] [review]
fix test failure due to SMSC timestamp truncation
Comment 7 Philipp von Weitershausen [:philikon] 2012-08-16 15:17:18 PDT
Comment on attachment 652318 [details] [diff] [review]
fix test failure due to SMSC timestamp truncation

Review of attachment 652318 [details] [diff] [review]:
-----------------------------------------------------------------

Nice catch.
Comment 8 Vicamo Yang [:vicamo][:vyang] 2012-08-16 19:03:05 PDT
https://hg.mozilla.org/integration/mozilla-inbound/rev/90a5d5cca5fc
Comment 9 Ed Morley [:emorley] 2012-08-17 05:27:58 PDT
https://hg.mozilla.org/mozilla-central/rev/90a5d5cca5fc

Note You need to log in before you can comment on or make changes to this bug.