Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Error: Doc not found in list: reywood_publish-composite.js line 210 #38

Open
martinhbramwell opened this issue Apr 16, 2015 · 22 comments
Open
Labels

Comments

@martinhbramwell
Copy link

This error only appears in my Cucumber log, seems not to affect my app in any way and does not reference any code in my app. Meteor-publish-composite seems to be a dependency of some other package; I did not add it explicitly myself. Perhaps it is a accident waiting to happen :

Exception in queued task: Error: Doc not found in list: 7bJXeKfHTwos7Ekc8
  at [object Object].addChildPub (/tmp/meteor-test-run49uzxg/.meteor/local/build/programs/server/packages/reywood_publish-composite.js:210:15)
  at Publication.createChildPublication (/tmp/meteor-test-run49uzxg/.meteor/local/build/programs/server/packages/reywood_publish-composite.js:136:28)
  at Array.forEach (native)
  at Function._.each._.forEach (/tmp/meteor-test-run49uzxg/.meteor/local/build/programs/server/packages/underscore.js:139:11)
  at Publication._publishChildrenOf (/tmp/meteor-test-run49uzxg/.meteor/local/build/programs/server/packages/reywood_publish-composite.js:134:7)
  at Object.added (/tmp/meteor-test-run49uzxg/.meteor/local/build/programs/server/packages/reywood_publish-composite.js:86:22)
  at [object Object].observeChangesCallbacks.added (/tmp/meteor-test-run49uzxg/.meteor/local/build/programs/server/packages/minimongo.js:3901:28)
  at self.applyChange.added (/tmp/meteor-test-run49uzxg/.meteor/local/build/programs/server/packages/minimongo.js:3801:44)
  at /tmp/meteor-test-run49uzxg/.meteor/local/build/programs/server/packages/mongo.js:1852:30
  at Array.forEach (native)

I'd like to know if I am the only one seeing this. If you need further details, I'll be happy to oblige.

I'm running it in a Xubuntu 14.04 client guest of a KVM virtual machine.
It appears exactly four times, one immediately after the other, and only during startup of my Cucumber/Velocity testing.

@reywood
Copy link
Collaborator

reywood commented Apr 16, 2015

Hmmm, that is a brain buster. After reviewing the code, I can't figure out how that's possible unless there is some test code that produces a document with a mutating _id field. If you can figure out what package depends on this one, that might help.

@reywood
Copy link
Collaborator

reywood commented Jul 7, 2015

Closing for now. Feel free to re-open if a reproduction for this issue is found.

@reywood reywood closed this as completed Jul 7, 2015
@serkandurusoy
Copy link

FWIW I seem to get this a lot and can't actually pin it down somewhere. Feels as if it is related to publications getting teared down as logged in user changes, since all my publications require this.userId

I20151210-00:20:01.881(2)? Exception in queued task: Error: Doc not found in list: v4jSeZJXqntEAZy8f
I20151210-00:20:01.882(2)?     at [object Object].addChildPub (packages/reywood_publish-composite/packages/reywood_publish-composite.js:201:1)
I20151210-00:20:01.882(2)?     at Publication.createChildPublication (packages/reywood_publish-composite/packages/reywood_publish-composite.js:127:1)
I20151210-00:20:01.882(2)?     at Array.forEach (native)
I20151210-00:20:01.882(2)?     at Function._.each._.forEach (packages/underscore/underscore.js:105:1)
I20151210-00:20:01.883(2)?     at Publication._publishChildrenOf (packages/reywood_publish-composite/packages/reywood_publish-composite.js:125:1)
I20151210-00:20:01.883(2)?     at Object.added (packages/reywood_publish-composite/packages/reywood_publish-composite.js:77:1)
I20151210-00:20:01.884(2)?     at [object Object].observeChangesCallbacks.added (packages/minimongo/observe.js:153:1)
I20151210-00:20:01.885(2)?     at self.applyChange.added (packages/minimongo/observe.js:53:1)
I20151210-00:20:01.885(2)?     at packages/mongo/observe_multiplex.js:183:1
I20151210-00:20:01.885(2)?     at Array.forEach (native)

@javascriptlove
Copy link

javascriptlove commented Jul 23, 2019

@reywood I just updated to publish-composite:1.7.1 (on Meteor 1.8.1) and started seeing this error. I saw that there is a check for this.documents[key] in the code, is it something that you've been aware of previously? Any idea how to debug this issue?

I20190723-14:10:28.263(2)? Exception in callback of async function: Error: Doc not found in list: Prf_test
I20190723-14:10:28.263(2)?     at PublishedDocumentList.addChildPub (packages/reywood:publish-composite/lib/published_document_list.js:26:19)
I20190723-14:10:28.264(2)?     at Publication.createChildPublication (packages/reywood:publish-composite/lib/publication.js:117:32)
I20190723-14:10:28.265(2)?     at Array.forEach (<anonymous>)
I20190723-14:10:28.265(2)?     at Function._.each._.forEach (packages/underscore.js:139:11)
I20190723-14:10:28.265(2)?     at Publication._publishChildrenOf (packages/reywood:publish-composite/lib/publication.js:115:11)
I20190723-14:10:28.265(2)?     at observeHandle.cursor.observe.added.Meteor.bindEnvironment.doc (packages/reywood:publish-composite/lib/publication.js:54:26)
I20190723-14:10:28.265(2)?     at runWithEnvironment (packages/meteor.js:1286:24)
I20190723-14:10:28.266(2)?     at Object.added (packages/meteor.js:1299:14)
I20190723-14:10:28.266(2)?     at _CachingChangeObserver.added (packages/minimongo/local_collection.js:1305:28)
I20190723-14:10:28.266(2)?     at added (packages/minimongo/local_collection.js:707:29)
I20190723-14:10:28.266(2)?     at runWithEnvironment (packages/meteor.js:1286:24)
I20190723-14:10:28.266(2)?     at packages/meteor.js:1299:14
I20190723-14:10:28.266(2)?     at packages/mongo/observe_multiplex.js:207:9
I20190723-14:10:28.266(2)?     at _IdMap.forEach (packages/id-map/id-map.js:51:35)
I20190723-14:10:28.266(2)?     at ObserveMultiplexer._sendAdds (packages/mongo/observe_multiplex.js:199:22)
I20190723-14:10:28.267(2)?     at ObserveMultiplexer.kadira_Multiplexer_sendAdds [as _sendAdds] (packages/meteorhacks_kadira.js:3690:29)
I20190723-14:10:28.267(2)?     at packages/mongo/observe_multiplex.js:50:12
I20190723-14:10:28.267(2)?     at runWithEnvironment (packages/meteor.js:1286:24)
I20190723-14:10:28.269(2)?     at Object.task (packages/meteor.js:1299:14)
I20190723-14:10:28.270(2)?     at Meteor._SynchronousQueue.SQp._run (packages/meteor.js:917:16)
I20190723-14:10:28.270(2)?     at packages/meteor.js:894:12

@tcastelli
Copy link

tcastelli commented Aug 7, 2019

Having the same problem since last update and was also having trouble debugging this. Any ideas why would it start complaining with the last version? @reywood
In our case this error appears to happen only asfter hot code pushes

I20190807-17:57:39.635(2)? Exception in callback of async function: Error: Doc not found in list: XCZLHjoC8rQ9YviZq
I20190807-17:57:39.635(2)?     at PublishedDocumentList.addChildPub (packages/reywood:publish-composite/lib/published_document_list.js:26:19)
I20190807-17:57:39.635(2)?     at Publication.createChildPublication (packages/reywood:publish-composite/lib/publication.js:117:32)
I20190807-17:57:39.636(2)?     at Array.forEach (<anonymous>)
I20190807-17:57:39.636(2)?     at Function._.each._.forEach (packages/underscore.js:139:11)
I20190807-17:57:39.636(2)?     at Publication._publishChildrenOf (packages/reywood:publish-composite/lib/publication.js:115:11)
I20190807-17:57:39.636(2)?     at observeHandle.cursor.observe.added.Meteor.bindEnvironment.doc (packages/reywood:publish-composite/lib/publication.js:54:26)
I20190807-17:57:39.636(2)?     at runWithEnvironment (packages/meteor.js:1286:24)
I20190807-17:57:39.636(2)?     at Object.added (packages/meteor.js:1299:14)
I20190807-17:57:39.636(2)?     at _CachingChangeObserver.added (packages/minimongo/local_collection.js:1305:28)
I20190807-17:57:39.636(2)?     at added (packages/minimongo/local_collection.js:707:29)
I20190807-17:57:39.636(2)?     at runWithEnvironment (packages/meteor.js:1286:24)
I20190807-17:57:39.636(2)?     at packages/meteor.js:1299:14
I20190807-17:57:39.636(2)?     at packages/mongo/observe_multiplex.js:182:30
I20190807-17:57:39.636(2)?     at Array.forEach (<anonymous>)
I20190807-17:57:39.637(2)?     at Function._.each._.forEach (packages/underscore.js:139:11)
I20190807-17:57:39.637(2)?     at Object.task (packages/mongo/observe_multiplex.js:176:9)
I20190807-17:57:39.637(2)?     at Meteor._SynchronousQueue.SQp._run (packages/meteor.js:917:16)
I20190807-17:57:39.637(2)?     at packages/meteor.js:894:12

@javascriptlove
Copy link

@reywood @martinhbramwell Guys, someone has to reopen this, the issue persists with latest available version

@jorisroling
Copy link

+1

@kswilliames
Copy link

+1

@jorisroling
Copy link

I've found that using the selector function reactive, it is runs (because of Tracker.autorun) too often and prevents going to the next page. By being careful with assigning to those ReactiveVars only when actually changed (see below) this is prevented.

I use this code (both server & client):

import { ReactiveVar } from 'meteor/reactive-var'
import equal from 'fast-deep-equal'

ReactiveVar.prototype.setIfChanged = function(val) {
  if (!equal(val,this.get())) {
    return this.set(val)
  }
}

and then use .setIfChanged(value) to make the selector only be called (autoran) when actual new values arrive.

Hope it helps!

@kswilliames
Copy link

Thanks @jorisroling I'll look into the rate the subscription is being called, it seems like it's refreshing as new data comes from higher containers. It didn't seem to have this problem before the latest update to meteor-publish-composite

@SimonSimCity
Copy link
Member

I can confirm that this bug is also present using Meteor 1.8.1 and this package in version 1.7.0.

My stack-trace just looks a little different because I'm using cultofcoders:redis-oplog - which is why you find this here in the stack trace.

Exception in callback of async function: Error: Doc not found in list: A6L9wjekBBYv4vmTC
    at PublishedDocumentList.addChildPub (packages/reywood:publish-composite/lib/published_document_list.js:26:19)
    at Publication.createChildPublication (packages/reywood:publish-composite/lib/publication.js:98:32)
    at Array.forEach (<anonymous>)
    at Function._.each._.forEach (packages/underscore.js:139:11)
    at Publication._publishChildrenOf (packages/reywood:publish-composite/lib/publication.js:96:11)
    at observeHandle.cursor.observe.added.Meteor.bindEnvironment.doc (packages/reywood:publish-composite/lib/publication.js:45:26)
    at runWithEnvironment (packages/meteor.js:1286:24)
    at Object.added (packages/meteor.js:1299:14)
    at _CachingChangeObserver.added (packages/minimongo/local_collection.js:1305:28)
    at added (packages/minimongo/local_collection.js:707:29)
    at runWithEnvironment (packages/meteor.js:1286:24)
    at packages/meteor.js:1299:14
    at packages/cultofcoders:redis-oplog/lib/mongo/ObserveMultiplex.js:232:42
    at Array.forEach (<anonymous>)
    at Function._.each._.forEach (packages/underscore.js:139:11)
    at Object.task (packages/cultofcoders:redis-oplog/lib/mongo/ObserveMultiplex.js:215:15)
    at Meteor._SynchronousQueue.SQp._run (packages/meteor.js:917:16)
    at packages/meteor.js:894:12

@reywood
Copy link
Collaborator

reywood commented Sep 9, 2019

If someone can create a small example project that reproduces this bug, I'm happy to have a look.

@SimonSimCity
Copy link
Member

SimonSimCity commented Sep 29, 2019

I haven't seen it again in the past month, but that doesn't say much. We've had a big spike that day I got the error; the past month was rather quiet. Seems like it's a very tough race-condition. I'll keep you posted as I see it again, but it's definitively there - please reopen.

@SimonSimCity
Copy link
Member

@reywood @filipenevola can someone please reopen it, because this still is a bug, and the exception still occurs at least once a week.

I'll now start forking the project by adding more logs to when what and how this could happen.

@filipenevola
Copy link

@SimonSimCity done.

@filipenevola filipenevola reopened this Nov 6, 2019
@tpmh31292
Copy link

I'm having the same problem. Using Meteor 1.8.1 / cultofcoders:redis-oplog 2.0.2 / publish-composite 1.7.1
Stack trace quite similar to @SimonSimCity. You have any updates please?

Exception in callback of async function: Error: Doc not found in list: EsXPNyv8wuxPLkXtM
at PublishedDocumentList.addChildPub (packages/reywood:publish-composite/lib/published_document_list.js:26:19)
at Publication.createChildPublication (packages/reywood:publish-composite/lib/publication.js:117:32)
at Array.forEach (<anonymous>)
at Function._.each._.forEach (packages/underscore.js:139:11)
at Publication._publishChildrenOf (packages/reywood:publish-composite/lib/publication.js:115:11)
at observeHandle.cursor.observe.added.Meteor.bindEnvironment.doc (packages/reywood:publish-composite/lib/publication.js:54:26)
at runWithEnvironment (packages/meteor.js:1286:24)
at Object.added (packages/meteor.js:1299:14)
at _CachingChangeObserver.added (packages/minimongo/local_collection.js:1305:28)
 at added (packages/minimongo/local_collection.js:707:29)
at runWithEnvironment (packages/meteor.js:1286:24)
at packages/meteor.js:1299:14
at packages/cultofcoders:redis-oplog/lib/mongo/ObserveMultiplex.js:256:18
at _IdMap.forEach (packages/id-map/id-map.js:51:35)
at ObserveMultiplexer._sendAdds (packages/cultofcoders:redis-oplog/lib/mongo/ObserveMultiplex.js:249:26)
at packages/cultofcoders:redis-oplog/lib/mongo/ObserveMultiplex.js:68:18

@SimonSimCity
Copy link
Member

@tpmh31292 you can help us - e.g. by taking my fork of this package, import it as a custom-override and share your insight 😉 I've just added a bunch of logging data in case it fails: SimonSimCity@0f37777 I'm running this in production trying to get more details ...

@adamgins
Copy link

Was anything resolved here. I am seeing this under load too

@SimonSimCity
Copy link
Member

@adamgins would you be willing to include my patch and share the details? You can just create a copy of this package into the packages folder of your project which will then be used instead of the package from atmosphere (https://guide.meteor.com/writing-atmosphere-packages.html#overriding-atmosphere-packages)

@adamgins
Copy link

@SimonSimCity will do soon and get back to you

@StorytellerCZ
Copy link
Member

@SimonSimCity @adamgins any new insight into this issue and a potential fix?

@SimonSimCity
Copy link
Member

@StorytellerCZ I have to admit that my focus for private and business projects has shifted away from Meteor. For this reason, I won't be able to provide any new insights without substantial effort.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
None yet
Development

No branches or pull requests