980239 - Failure syncing 3rd-party engines: POST to non-existent collection returns 404

Status: RESOLVED FIXED

(Cloud Services Graveyard :: Server: Sync, defect, P1)

Description

[Mark Hammond [:markh] [:mhammond]]

Via irc, a log which includes:

1394094421371 Sync.Tracker.Addons DEBUG Saving changed IDs to addons
1394094421373 Sync.Tracker.AdblockPlus.private DEBUG Saving changed IDs to adblockplus.private
1394094421506 Sync.Tracker.AdblockPlus DEBUG Saving changed IDs to adblockplus
1394094510505 Sync.Service DEBUG User-Agent: Firefox/30.0a1 FxSync/1.32.0.20140305030201. 1
...
1394094510905 Sync.Engine.AdblockPlus DEBUG First sync, uploading all items
1394094510905 Sync.Engine.AdblockPlus INFO 1 outgoing items pre-reconciliation
1394094510906 Sync.Engine.AdblockPlus INFO Records: 0 applied, 0 successfully, 0 failed to apply, 0 newly failed to apply, 0 reconciled.
1394094510908 Sync.Engine.AdblockPlus INFO Uploading all of 1 records
1394094510912 Sync.Collection DEBUG POST Length: 475
1394094511054 Sync.Collection DEBUG mesg: POST fail 404 https://sync-1-us-east-1.sync.services.mozilla.com/1.5/69814/storage/adblockplus
1394094511054 Sync.Collection DEBUG POST fail 404 https://sync-1-us-east-1.sync.services.mozilla.com/1.5/69814/storage/adblockplus
1394094511055 Sync.Engine.AdblockPlus DEBUG Uploading records failed: 0
1394094511055 Sync.Status DEBUG Status for engine adblockplus: error.engine.reason.record_upload_fail
1394094511055 Sync.Status DEBUG Status.service: success.status_ok => error.sync.failed_partial
1394094511055 Sync.ErrorHandler DEBUG adblockplus failed: 0 No traceback available
1394094511056 Sync.Synchronizer INFO Sync completed at 2014-03-06 09:28:31 after 0.55 secs.
1394094511057 Sync.SyncScheduler DEBUG Next sync in 600000 ms.
1394094511057 Sync.ErrorHandler DEBUG Some engines did not sync correctly.

Disabling that engine via prefs was a work-around.  Probably worth trying to fix in 29 if there are a few such broken engines.

Comment 1

[Richard Newman [:rnewman]]

Related to Bug 963332?

Upstream issues:

https://code.google.com/p/reqpolsync/issues/detail?id=3

Comment 2

[Ryan Kelly [:rfkelly]]

That...that should not be possible.  I suspect this will be a fun one...

Comment 3

[:Gavin Sharp [email: [e-mail]]]

I don't fully understand this bug but I'm going to assume this dependency change is correct!

Comment 4

[Ryan Kelly [:rfkelly]]

Yes, it appears to be a server-side issue of some sort, a 404 on POST to a collection is wildly out of spec.

Comment 5

[Ryan Kelly [:rfkelly]]

Attachment: rfkelly initial reproduction of this issue

Well at least I managed to reproduce it on my own account; attaching sync log for my reference

Comment 6

[Ryan Kelly [:rfkelly]]

STR: instal Stylish and StylishSync addons, attempt to sync, see errors due to "stylishsync" collection giving a 404.

Comment 7

[Ryan Kelly [:rfkelly]]

Reproduced on stage, and I can see we're getting an IntegrityError when trying to create the new collection:

IntegrityError: (IntegrityError) (1048, u"Column 'collectionid' cannot be null") '/* [queryName=INSERT_COLLECTION] */ INSERT INTO collections (collectionid, name) VALUES (%s, %s)' (None, u'stylishsync')


(This results in a 404 because the code assumes "oh, I couldn't insert the collection, someone must have created it at the same time as me" and then it goes to re-read the collectionid).

Comment 8

[Ryan Kelly [:rfkelly]]

Looks like the stage (and I assume prod) dbs appear to be using an old schema, which makes insertion of custom collection names fail: Bug 980776.

Comment 9

[Ryan Kelly [:rfkelly]]

Database schema updated, stylishsync now works for me with custom collection names.

Comment 10

[Johannes Pfrang [:johnp]]

Well, after the db schema update it seems StylishSync and RequestPolicySync are now working as they should but the latest AdBlock Pus development build now gives another error instead of the 404:

Sync.Collection	DEBUG	mesg: POST fail 500 https://sync-2-us-east-1.sync.services.mozilla.com/1.5/10085/storage/adblockplus
Sync.Collection	DEBUG	POST fail 500 https://sync-2-us-east-1.sync.services.mozilla.com/1.5/10085/storage/adblockplus
Sync.Engine.AdblockPlus	DEBUG	Uploading records failed: <html>
  <head>
    <title>Internal Server Error</title>
  </head>
  <body>
    <h1>Internal Server Error</h1>
    
  </body>
</html>

Sync.Status	DEBUG	Status for engine adblockplus: error.engine.reason.record_upload_fail
Sync.Status	DEBUG	Status.service: success.status_ok => error.sync.failed_partial
Sync.ErrorHandler	DEBUG	adblockplus failed: <html>
  <head>
    <title>Internal Server Error</title>
  </head>
  <body>
    <h1>Internal Server Error</h1>
    
  </body>
</html>
 No traceback available
Sync.Synchronizer	INFO	Aborting sync for failure in adblockplus
Sync.Synchronizer	INFO	Sync completed at 2014-03-07 14:34:09 after 1.04 secs.
Sync.SyncScheduler	DEBUG	Starting client-initiated backoff. Next sync in 14834050 ms.
Sync.SyncScheduler	DEBUG	Next sync in 14834050 ms.
Sync.ErrorHandler	DEBUG	Some engines did not sync correctly.

Could someone please look into it? Seems something else is wrong here...

Comment 11

[Johannes Pfrang [:johnp]]

Attachment: AdBlock Plus error

Complete log attached.  The warnings at the beginning don't occur in other logs. Most likely happened because I updated some add-ons in between. Don't know if this is intended to throw an Exception.

Comment 12

[Johannes Pfrang [:johnp]]

Moved the internal server error bug into bug 981294.