FabricLabs / soundtrack

Self-hosted collaborative music playing application.
https://soundtrack.io
126 stars 52 forks source link

Mongo duplicate key error causing null artists crash #196

Open diginc opened 8 years ago

diginc commented 8 years ago

I had a crash sunday (when no one was on AFAIK) and then again today (with active people) on my instance. My impression of root cause is the artist already exists but didn't get matched / re-used and then the index prevent a duplicate artist from being created, not sure though. Here are some more details on what I see in logs/mongo:

This is shown in the node log after someone queued this song according to them the song actually played succesfully too. then the instance seems to crash.

{ [MongoError: E11000 duplicate key error index: soundtrack.artists.$name_1  dup key: { : "Degradead" }]
  name: 'MongoError',
  err: 'E11000 duplicate key error index: soundtrack.artists.$name_1  dup key: { : "Degradead" }',
  code: 11000,
  n: 0,
  connectionId: 1768,
  ok: 1 }

When starting the node process got this error:

TypeError: Cannot read property '_id' of null
    at Promise.<anonymous> (/home/soundtrack/soundtrack.io/models/Room.js:293:41)
    at Promise.<anonymous> (/home/soundtrack/soundtrack.io/node_modules/mongoose/node_modules/mpromise/lib/promise.js:162:8)
    at Promise.EventEmitter.emit (events.js:95:17)
    at Promise.emit (/home/soundtrack/soundtrack.io/node_modules/mongoose/node_modules/mpromise/lib/promise.js:79:38)
    at Promise.fulfill (/home/soundtrack/soundtrack.io/node_modules/mongoose/node_modules/mpromise/lib/promise.js:92:20)
    at Promise.resolve (/home/soundtrack/soundtrack.io/node_modules/mongoose/lib/promise.js:108:15)
    at Promise.<anonymous> (/home/soundtrack/soundtrack.io/node_modules/mongoose/node_modules/mpromise/lib/promise.js:162:8)
    at Promise.EventEmitter.emit (events.js:95:17)
    at Promise.emit (/home/soundtrack/soundtrack.io/node_modules/mongoose/node_modules/mpromise/lib/promise.js:79:38)
    at Promise.fulfill (/home/soundtrack/soundtrack.io/node_modules/mongoose/node_modules/mpromise/lib/promise.js:92:20)

I threw in a console.log(track) right above line 292 and found the track ID just to confirm it was was the same one as the duplicate key error:

{ __v: 0,
  _artist: null,
  _credits: [ 56df127bce7a3a9a4a000a6c ],
  _id: 56df10f1ce7a3a9a4a000a55,
  _remixes: [],
  _sources: [],
  duration: 231,
  flags: { live: false, nsfw: false },
  images: { thumbnail: { url: 'https://i.ytimg.com/vi/E04aXOgqjek/default.jpg' } },
  slug: 'degradead-genetic-waste',
  slugs: [ 'degradead-genetic-waste' ],
  sources: 
   { vimeo: [],
     bandcamp: [],
     soundcloud: [],
     youtube: [ [Object] ],
     lastfm: [],
     direct: [] },
  title: 'Genetic Waste',
  titles: [],
  updated: Wed Dec 31 1969 19:00:00 GMT-0500 (EST) }

Now knowing about the duplicate key error I looked back threw my log and found how it has actually been happening a lot however I've only had the 2 crashes followed by inability to start node back up:

root@magus /home/soundtrack $ grep -c 'duplicate key' log/soundtrack_node.log 
92

Seems my database has gotten a little dirty...these tracks get plays/tracks created but no corresponding artist object (due to an index constraint it seems?).

I've been cleaning up like this for now, but two crashes in two days is not a good sign.

db.plays.remove( { _track: ObjectId("56df10f1ce7a3a9a4a000a55") } )
db.tracks.remove( { _id: ObjectId("56df10f1ce7a3a9a4a000a55") })
martindale commented 8 years ago

If you aren't trying to keep track of which artists are being played most, you can disable this index in models/Artist.js: https://github.com/martindale/soundtrack.io/blob/soundtrack.io/models/Artist.js#L11 (just remove unique: true, run db.artists.dropIndexes(), then restart your app). However, I don't recommend this.

I'm adding an action item to overhaul the stat tracking for 1.0, as what we have in place is a very rough cut. If you're able to track down any particular way of reproducing this, please let me know – it'll be helpful for producing a patch before we get to 1.0.