1153358 - Investigate: why do records have no stored_on?

Status: RESOLVED FIXED

(Android Background Services Graveyard :: Reading List Sync, defect)

Description

[Richard Newman [:rnewman]]

None of Margaret's record had stored_on set.

Perhaps the server isn't sending it, or we're not correctly applying the response we get from the server? That doesn't really make sense, because we have the downloaded GUIDs correctly...

Comment 1

[Richard Newman [:rnewman]]

The code looks kosher, so I'm puzzled. Will have to repro.

Comment 2

[Richard Newman [:rnewman]]

Indeed, testing locally I also don't see STATUS_SYNCED being set -- it's almost as if none of the post-upload changes are applied apart from the GUID.

The Radical Vision of Toni Morrison                                   0a477ea8-52e6-4929-bcf7-be976786b9ff  0                           Fennec rnewman on Nexus 9   0

Comment 3

[Richard Newman [:rnewman]]

I've written a failing test.

Comment 4

[Richard Newman [:rnewman]]

Here's the literal string response from the server for the test upload POST.


{"marked_read_on": null, "is_article": false, "stored_on": null, "excerpt": "", "word_count": 0, "read_position": 0, "last_modified": 1428796540880, "resolved_url": "http://example.org/reading", "resolved_title": "Example Reading", "archived": false, "preview": null, "title": "Example Reading", "url": "http://example.org/reading", "favorite": false, "id": "f4e38c8e06c04969a1cd8f84b0d47392", "marked_read_by": null, "added_on": 1428796195636, "unread": true, "added_by": "$local"}



Why is stored_on not being set by the server? Tarek, do you know?

Comment 5

[Tarek Ziadé (:tarek)]

stored_on should get the server date by default

http://readinglist.readthedocs.org/en/latest/model.html#articles

this looks like a server bug - we're going to investigate.

Comment 6

[Mathieu Leplatre [:leplatrem]]

I may have misunderstood but I can't reproduce locally so far :( 

Could you please post the original request that produced this response from the server ?


Locally, stored_on is always set by the server:


    POST /v1/articles HTTP/1.1
    Accept: application/json
    Accept-Encoding: gzip, deflate
    Authorization: Basic bWF0Og==
    Content-Length: 66
    Content-Type: application/json; charset=utf-8
    Host: localhost:8000
    User-Agent: HTTPie/0.8.0

    {
        "added_by": "toto", 
        "title": "toto", 
        "url": "http://mozilla.com"
    }

    HTTP/1.1 200 OK
    Access-Control-Expose-Headers: Backoff, Retry-After, Alert
    Backoff: None
    Content-Length: 424
    Content-Type: application/json; charset=UTF-8
    Date: Mon, 13 Apr 2015 11:28:41 GMT
    Server: waitress

    {
        "added_by": "toto", 
        "added_on": 1428922769193, 
        "archived": false, 
        "excerpt": "", 
        "favorite": false, 
        "id": "2f09cc82-c317-4023-8372-257df02f33bc", 
        "is_article": true, 
        "last_modified": 1428922769195, 
        "marked_read_by": null, 
        "marked_read_on": null, 
        "preview": null, 
        "read_position": 0, 
        "resolved_title": "toto", 
        "resolved_url": "http://mozilla.com", 
        "stored_on": 1428922769193, 
        "title": "toto", 
        "unread": true, 
        "url": "http://mozilla.com", 
        "word_count": null
    }
        

If I specify stored_on, it is overwritten, even if I submit it as empty string or null:


    POST /v1/articles HTTP/1.1
    Accept: application/json
    Accept-Encoding: gzip, deflate
    Authorization: Basic bWF0Og==
    Content-Length: 107
    Content-Type: application/json
    Host: localhost:8000
    User-Agent: HTTPie/0.8.0

    {
        "added_by": "toto", 
        "stored_on": null, 
        "title": "toto", 
        "url": "http://mozilla.com"
    }

    HTTP/1.1 200 OK
    Access-Control-Expose-Headers: Backoff, Retry-After, Alert
    Backoff: None
    Content-Length: 424
    Content-Type: application/json; charset=UTF-8
    Date: Mon, 13 Apr 2015 11:26:51 GMT
    Server: waitress

    {
        "added_by": "toto", 
        "added_on": 1428922769193, 
        "archived": false, 
        "excerpt": "", 
        "favorite": false, 
        "id": "2f09cc82-c317-4023-8372-257df02f33bc", 
        "is_article": true, 
        "last_modified": 1428922769195, 
        "marked_read_by": null, 
        "marked_read_on": null, 
        "preview": null, 
        "read_position": 0, 
        "resolved_title": "toto", 
        "resolved_url": "http://mozilla.com", 
        "stored_on": 1428922769193, 
        "title": "toto", 
        "unread": true, 
        "url": "http://mozilla.com", 
        "word_count": null
    }

Comment 7

[Rémy Hubscher (:natim)]

I was going to say the exact same thing :)

rhubscher@Crapouille:~$ http POST https://readinglist.stage.mozaws.net/v1/articles \
    title=Trunat \
    url=http://www.trunat.fr/ \
    added_by=Natim \
    --auth "Natim:"

HTTP/1.1 201 Created
Access-Control-Expose-Headers: Backoff, Retry-After, Alert
Backoff: None
Connection: keep-alive
Content-Length: 437
Content-Type: application/json; charset=UTF-8
Date: Mon, 13 Apr 2015 12:21:06 GMT

{
    "added_by": "Natim", 
    "added_on": 1428927666493, 
    "archived": false, 
    "excerpt": "", 
    "favorite": false, 
    "id": "4cd58551-57ea-413c-873f-4e9a721c6054", 
    "is_article": true, 
    "last_modified": 1428927666495, 
    "marked_read_by": null, 
    "marked_read_on": null, 
    "preview": null, 
    "read_position": 0, 
    "resolved_title": "Trunat", 
    "resolved_url": "http://www.trunat.fr/", 
    "stored_on": 1428927666493, 
    "title": "Trunat", 
    "unread": true, 
    "url": "http://www.trunat.fr/", 
    "word_count": null
}

Comment 8

[Rémy Hubscher (:natim)]

Actually Mathieu I see why it doesn't show in your example, because you don't delete the record and get a 200 instead of a 201.

I could eventually reproduce buggy behaviors:

http POST https://readinglist.stage.mozaws.net/v1/articles title=Trunat url=http://www.trunat.fr/2 added_by=Natim stored_on=""  --auth "random_value:"

http POST https://readinglist.stage.mozaws.net/v1/articles title=Trunat url=http://www.trunat.fr/1 added_by=Natim stored_on=1234  --auth "random_value:"

Comment 9

[Richard Newman [:rnewman]]

Does that mean you've found the bug? :D

Comment 10

[Richard Newman [:rnewman]]

Every record I see in our DBs that was uploaded by Android is missing the stored_on property.

Comment 11

[Mathieu Leplatre [:leplatrem]]

Indeed, the fault is spotted!

The stored_on property is not forced at creation. In other words, when stored_on is specified in request body, the server does not overwrite the field with its current timestamp.

I'll write a fix.

Meanwhile, a workaround is to remove the field (here with an empty value) from the posted request body.

Comment 12

[Richard Newman [:rnewman]]

Attachment: Client mitigation.

Comment 13

[Nick Alexander :nalexander [he/him]]

Comment on attachment 8591854 [details] [review]
Client mitigation.

lgtm.

Comment 14

[Richard Newman [:rnewman]]

https://hg.mozilla.org/integration/fx-team/rev/e5ce8c76d823

Comment 15

[Richard Newman [:rnewman]]

Comment on attachment 8591854 [details] [review]
Client mitigation.

Approval Request Comment
[Feature/regressing bug #]:
  Server issue; client mitigation suggested by server devs.

[User impact if declined]:
  Items created on Android won't have a stored_on date. Bad data in DBs is a bad thing.

[Describe test coverage new/current, TreeHerder]:
  Waiting to see manual testing results on Nightly.

[Risks and why]: 
  Absurdly low risk.

[String/UUID change made/needed]:
  None.

Comment 16

[Rémy Hubscher (:natim)]

Fixed on server side as well: https://github.com/mozilla-services/readinglist/commit/f249efbee5642f5e90117d99513f663fec73a2ca

It will be in readinglist-1.7.0 release.

Comment 17

[Rémy Hubscher (:natim)]

I thought it was a Server:Readinglist bug but actually it is not.

Comment 18

[Carsten Book [:Tomcat]]

https://hg.mozilla.org/mozilla-central/rev/e5ce8c76d823

Comment 19

[Ryan VanderMeulen [:RyanVM]]

https://hg.mozilla.org/releases/mozilla-aurora/rev/e71fcee4fabb

Comment 20

[Ryan VanderMeulen [:RyanVM]]

https://hg.mozilla.org/releases/mozilla-beta/rev/1412c445ff0d