monti-apm / monti-apm-agent

Monitor Meteor apps with Monti APM
https://montiapm.com
MIT License
45 stars 22 forks source link

Error after updating to latest version (publications using publish-counts) #14

Closed tcastelli closed 3 years ago

tcastelli commented 5 years ago

I'm getting this error wehenever i start an app with the latest version


I20190606-13:14:04.786(2)?     at Tracer.event (packages/montiapm:agent/lib/tracer/tracer.js:91:56)
I20190606-13:14:04.786(2)?     at Cursor.cursorProto.(anonymous function) (packages/montiapm:agent/lib/hijack/db.js:135:37)
I20190606-13:14:04.786(2)?     at Cursor.kadira_Cursor_observe [as observe] (packages/montiapm:agent/lib/hijack/set_labels.js:83:34)
I20190606-13:14:04.786(2)?     at Object.Counts.publish (packages/tmeasday_publish-counts.js:104:21)
I20190606-13:14:04.786(2)?     at Subscription.<anonymous> (imports/api/activities/server/publications.js:28:12)
I20190606-13:14:04.786(2)?     at packages/matb33_collection-hooks.js:307:21
I20190606-13:14:04.786(2)?     at Meteor.EnvironmentVariable.EVp.withValue (packages/meteor.js:1234:12)
I20190606-13:14:04.786(2)?     at Subscription._handler (packages/matb33_collection-hooks.js:306:28)
I20190606-13:14:04.786(2)?     at maybeAuditArgumentChecks (packages/ddp-server/livedata_server.js:1771:12)
I20190606-13:14:04.786(2)?     at DDP._CurrentPublicationInvocation.withValue (packages/ddp-server/livedata_server.js:1046:15)
I20190606-13:14:04.786(2)?     at Meteor.EnvironmentVariable.EVp.withValue (packages/meteor.js:1234:12)
I20190606-13:14:04.786(2)?     at Subscription._runHandler (packages/ddp-server/livedata_server.js:1044:51)
I20190606-13:14:04.787(2)?     at Subscription.subscriptionProto._runHandler (packages/montiapm:agent/lib/hijack/wrap_subscription.js:12:24)
I20190606-13:14:04.787(2)?     at Session._startSubscription (packages/ddp-server/livedata_server.js:860:9)
I20190606-13:14:04.787(2)?     at Session.sub (packages/ddp-server/livedata_server.js:625:12)
I20190606-13:14:04.787(2)?     at packages/montiapm:agent/lib/hijack/wrap_session.js:77:34
I20190606-13:14:04.787(2)?     at Meteor.EnvironmentVariable.EVp.withValue (packages/meteor.js:1234:12)
I20190606-13:14:04.787(2)?     at Session.sessionProto.protocol_handlers.sub (packages/montiapm:agent/lib/hijack/wrap_session.js:76:44)
I20190606-13:14:04.787(2)?     at packages/ddp-server/livedata_server.js:559:43````
zodern commented 5 years ago

Is there an error message shown above the stack trace?

tcastelli commented 5 years ago

Yes sorry @zodern forgot to copy the error at the top. Here it is directly from webstorm debugging console

Exception from sub unreadMessages id gXL2akGPZKN5zLPen TypeError: Cannot read property 'length' of undefined
    at Tracer.event (packages/montiapm:agent/lib/tracer/tracer.js:91:56)
    at Cursor.cursorProto.(anonymous function) (packages/montiapm:agent/lib/hijack/db.js:135:37)
    at Cursor.kadira_Cursor_observe [as observe] (packages/montiapm:agent/lib/hijack/set_labels.js:83:34)
    at Object.Counts.publish (packages/tmeasday_publish-counts.js:104:21)
    at Subscription.<anonymous> (imports/api/messages/server/publications.js:63:12)
    at packages/matb33_collection-hooks.js:307:21
    at Meteor.EnvironmentVariable.EVp.withValue (packages/meteor.js:1234:12)
    at Subscription._handler (packages/matb33_collection-hooks.js:306:28)
    at maybeAuditArgumentChecks (packages/ddp-server/livedata_server.js:1771:12)
    at DDP._CurrentPublicationInvocation.withValue (packages/ddp-server/livedata_server.js:1046:15)
    at Meteor.EnvironmentVariable.EVp.withValue (packages/meteor.js:1234:12)
    at Subscription._runHandler (packages/ddp-server/livedata_server.js:1044:51)
    at Subscription.subscriptionProto._runHandler (packages/montiapm:agent/lib/hijack/wrap_subscription.js:12:24)
    at Session._startSubscription (packages/ddp-server/livedata_server.js:860:9)
    at Session.sub (packages/ddp-server/livedata_server.js:625:12)
    at packages/montiapm:agent/lib/hijack/wrap_session.js:77:34
    at Meteor.EnvironmentVariable.EVp.withValue (packages/meteor.js:1234:12)
    at Session.sessionProto.protocol_handlers.sub (packages/montiapm:agent/lib/hijack/wrap_session.js:76:44)
    at packages/ddp-server/livedata_server.js:559:43
Monti APM: trace has not started yet
  Tracer.buildTrace 
  subscriptionProto.error   
  _runHandler   
  subscriptionProto._runHandler 
  _startSubscription    
  sub   
  (anonymous function)  
  EVp.withValue 
  sessionProto.protocol_handlers.sub    
  (anonymous function)  
Async call from TickObject
  init  
  emitInitNative    
  emitInitScript    
  nextTick  
  handleOperationCallback   
  (anonymous function)  
  authenticateStragglers    
  (anonymous function)  
  emitMessageHandler    
  (anonymous function)  
  emitOne   
  emit  
  addChunk  
  readableAddChunk  
  Readable.push 
  onread    
Async call from TCPWRAP
  init  
  emitInitNative    
  Socket.connect    
  connect   
  makeUnsecureConnection    
  doConnect 
  Connection.connect    
  Pool.connect  
  Server.connect    
  connect   
  createServer  
  parseFn   
  parseConnectionString 
  connect   
  connectOp 
  executeOperation  
  MongoClient.connect   
  MongoClient.connect   
  MongoConnection   
  MongoInternals.RemoteCollectionDriver 
  (anonymous function)  
  (anonymous function)  
  Collection    
  AccountsCommon    
  AccountsServer    
  server_main.js    
  fileEvaluate  
  require   
  require   
  (anonymous function)  
  (anonymous function)  
  (anonymous function)  
  (anonymous function)  
  (anonymous function)  
  run   
  (anonymous function)  
Async call from Immediate
  init  
  emitInitNative    
  emitInitScript    
  Immediate 
  createImmediate   
  setImmediate  
  SQp._scheduleRun  
  SQp.runTask   
  WebAppInternals.reloadClientPrograms  
  runWebAppServer   
  webapp_server.js  
  fileEvaluate  
  require   
  require   
  (anonymous function)  
  (anonymous function)  
  (anonymous function)  
  (anonymous function)  
  (anonymous function)  
  run   
  (anonymous function)  

Exception from sub unverifiedActivities id uyc8TCARLPtsRvTHu TypeError: Cannot read property 'length' of undefined
    at Tracer.event (packages/montiapm:agent/lib/tracer/tracer.js:91:56)
    at Cursor.cursorProto.(anonymous function) (packages/montiapm:agent/lib/hijack/db.js:135:37)
    at Cursor.kadira_Cursor_observe [as observe] (packages/montiapm:agent/lib/hijack/set_labels.js:83:34)
    at Object.Counts.publish (packages/tmeasday_publish-counts.js:104:21)
    at Subscription.<anonymous> (imports/api/activities/server/publications.js:28:12)
    at packages/matb33_collection-hooks.js:307:21
    at Meteor.EnvironmentVariable.EVp.withValue (packages/meteor.js:1234:12)
    at Subscription._handler (packages/matb33_collection-hooks.js:306:28)
    at maybeAuditArgumentChecks (packages/ddp-server/livedata_server.js:1771:12)
    at DDP._CurrentPublicationInvocation.withValue (packages/ddp-server/livedata_server.js:1046:15)
    at Meteor.EnvironmentVariable.EVp.withValue (packages/meteor.js:1234:12)
    at Subscription._runHandler (packages/ddp-server/livedata_server.js:1044:51)
    at Subscription.subscriptionProto._runHandler (packages/montiapm:agent/lib/hijack/wrap_subscription.js:12:24)
    at Session._startSubscription (packages/ddp-server/livedata_server.js:860:9)
    at Session.sub (packages/ddp-server/livedata_server.js:625:12)
    at packages/montiapm:agent/lib/hijack/wrap_session.js:77:34
    at Meteor.EnvironmentVariable.EVp.withValue (packages/meteor.js:1234:12)
    at Session.sessionProto.protocol_handlers.sub (packages/montiapm:agent/lib/hijack/wrap_session.js:76:44)
    at packages/ddp-server/livedata_server.js:559:43
maxfi commented 5 years ago

@zodern I'm seeing the same issue with versions 2.36.0 and 2.36.1. Version 2.35.0 is ok.

elie222 commented 5 years ago

I'm seeing similar issues. I am on:

montiapm:agent@2.36.1

Unclear what is causing this to happen.

This is the line causing the issues:

const Subscriptions = new Mongo.Collection('subscriptions');
// this line throws an error for some reason:
return Subscriptions.findOne(selector, options);
zodern commented 5 years ago

Thanks @elie222. When is this code run (server startup, method, publication, etc.)?

elie222 commented 5 years ago

Method

On Fri, 5 Jul 2019 at 0:15 zodern notifications@github.com wrote:

Thanks @elie222 https://github.com/elie222. When is this code run (server startup, method, publication, etc.)?

— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub https://github.com/monti-apm/monti-apm-agent/issues/14?email_source=notifications&email_token=AAXSQXYQBP32FWRUQJN4WE3P5ZR67A5CNFSM4HVA2V32YY3PNVWWK3TUL52HS4DFVREXG43VMVBW63LNMVXHJKTDN5WW2ZLOORPWSZGODZIERKI#issuecomment-508577961, or mute the thread https://github.com/notifications/unsubscribe-auth/AAXSQXY4UWZBRJPO2F3RMXTP5ZR67ANCNFSM4HVA2V3Q .

elie222 commented 5 years ago

I will check later what the exact circumstances are and what’s different here. Didn’t get to spend enough time looking at it yet.

elie222 commented 5 years ago

So it's a Meteor method that calls an ES6 async function. It turns out that this function doesn't use await at all so I just made it non async and all works.

I'm worried this is still an issue in other places however. I don't remember how this all works with Meteor, but did this issue arise because I had to wrap the async function in Meteor.wrapAsync, or is it in fact a bug with this package?

This is a full stack trace:

W20190705-01:02:49.804(3)? (STDERR) TypeError: Cannot read property 'length' of undefined
W20190705-01:02:49.804(3)? (STDERR)     at Tracer.event (packages/montiapm:agent/lib/tracer/tracer.js:91:56)
W20190705-01:02:49.805(3)? (STDERR)     at Function.Fibers.yield (packages/montiapm:agent/lib/hijack/async.js:8:33)
W20190705-01:02:49.805(3)? (STDERR)     at stackSafeYield (~/.meteor/packages/promise/.0.11.2.20ax7l.y5vky++os+web.browser+web.browser.legacy+web.cordova/npm/node_modules/meteor-promise/promise_server.js:101:25)
W20190705-01:02:49.805(3)? (STDERR)     at awaitPromise (~/.meteor/packages/promise/.0.11.2.20ax7l.y5vky++os+web.browser+web.browser.legacy+web.cordova/npm/node_modules/meteor-promise/promise_server.js:96:12)
W20190705-01:02:49.805(3)? (STDERR)     at Promise.await (~/.meteor/packages/promise/.0.11.2.20ax7l.y5vky++os+web.browser+web.browser.legacy+web.cordova/npm/node_modules/meteor-promise/promise_server.js:60:12)
W20190705-01:02:49.805(3)? (STDERR)     at SynchronousCursor._nextObject (packages/mongo/mongo_driver.js:1091:12)
W20190705-01:02:49.805(3)? (STDERR)     at SynchronousCursor.SyncronousCursor._nextObject (packages/montiapm:agent/lib/hijack/db.js:235:33)
W20190705-01:02:49.805(3)? (STDERR)     at SynchronousCursor.forEach (packages/mongo/mongo_driver.js:1105:22)
W20190705-01:02:49.806(3)? (STDERR)     at SynchronousCursor.map (packages/mongo/mongo_driver.js:1115:10)
W20190705-01:02:49.806(3)? (STDERR)     at SynchronousCursor.fetch (packages/mongo/mongo_driver.js:1139:17)
W20190705-01:02:49.806(3)? (STDERR)     at Cursor.(anonymous function) (packages/mongo/mongo_driver.js:887:44)
W20190705-01:02:49.806(3)? (STDERR)     at Cursor.cursorProto.(anonymous function) (packages/montiapm:agent/lib/hijack/db.js:144:32)
W20190705-01:02:49.806(3)? (STDERR)     at Cursor.kadira_Cursor_fetch [as fetch] (packages/montiapm:agent/lib/hijack/set_labels.js:65:32)
W20190705-01:02:49.806(3)? (STDERR)     at MongoConnection.findOne (packages/mongo/mongo_driver.js:794:56)
W20190705-01:02:49.806(3)? (STDERR)     at OptimizedApply (packages/montiapm:agent/lib/utils.js:31:17)
W20190705-01:02:49.806(3)? (STDERR)     at Object.ret.(anonymous function) (packages/montiapm:agent/lib/hijack/db.js:20:16)
W20190705-01:02:49.807(3)? (STDERR)     at Object.<anonymous> (packages/matb33_collection-hooks.js:819:16)
W20190705-01:02:49.807(3)? (STDERR)     at Object.collection.(anonymous function) [as findOne] (packages/matb33_collection-hooks.js:146:21)
W20190705-01:02:49.818(3)? (STDERR)     at ns.Collection.findOne (packages/mongo/collection.js:356:29)
W20190705-01:02:49.818(3)? (STDERR)     at findSubscription (imports/api/stripe/subscriptions/controller.js:40:27)
W20190705-01:02:49.818(3)? (STDERR)     at Promise.asyncApply (server/payments/stripePayments.js:433:20)
W20190705-01:02:49.819(3)? (STDERR)     at ~/.meteor/packages/promise/.0.11.2.20ax7l.y5vky++os+web.browser+web.browser.legacy+web.cordova/npm/node_modules/meteor-promise/fiber_pool.js:43:40
W20190705-01:02:49.819(3)? (STDERR)  => awaited here:
W20190705-01:02:49.819(3)? (STDERR)     at Promise.await (~/.meteor/packages/promise/.0.11.2.20ax7l.y5vky++os+web.browser+web.browser.legacy+web.cordova/npm/node_modules/meteor-promise/promise_server.js:60:12)
W20190705-01:02:49.820(3)? (STDERR)     at SynchronousCursor._nextObject (packages/mongo/mongo_driver.js:1091:12)
W20190705-01:02:49.820(3)? (STDERR)     at SynchronousCursor.SyncronousCursor._nextObject (packages/montiapm:agent/lib/hijack/db.js:235:33)
W20190705-01:02:49.820(3)? (STDERR)     at SynchronousCursor.forEach (packages/mongo/mongo_driver.js:1105:22)
W20190705-01:02:49.820(3)? (STDERR)     at SynchronousCursor.map (packages/mongo/mongo_driver.js:1115:10)
W20190705-01:02:49.820(3)? (STDERR)     at SynchronousCursor.fetch (packages/mongo/mongo_driver.js:1139:17)
W20190705-01:02:49.821(3)? (STDERR)     at Cursor.(anonymous function) (packages/mongo/mongo_driver.js:887:44)
W20190705-01:02:49.821(3)? (STDERR)     at Cursor.cursorProto.(anonymous function) (packages/montiapm:agent/lib/hijack/db.js:144:32)
W20190705-01:02:49.821(3)? (STDERR)     at Cursor.kadira_Cursor_fetch [as fetch] (packages/montiapm:agent/lib/hijack/set_labels.js:65:32)
W20190705-01:02:49.822(3)? (STDERR)     at MongoConnection.findOne (packages/mongo/mongo_driver.js:794:56)
W20190705-01:02:49.822(3)? (STDERR)     at OptimizedApply (packages/montiapm:agent/lib/utils.js:31:17)
W20190705-01:02:49.822(3)? (STDERR)     at Object.ret.(anonymous function) (packages/montiapm:agent/lib/hijack/db.js:20:16)
W20190705-01:02:49.822(3)? (STDERR)     at Object.<anonymous> (packages/matb33_collection-hooks.js:819:16)
W20190705-01:02:49.835(3)? (STDERR)     at Object.collection.(anonymous function) [as findOne] (packages/matb33_collection-hooks.js:146:21)
W20190705-01:02:49.836(3)? (STDERR)     at ns.Collection.findOne (packages/mongo/collection.js:356:29)
W20190705-01:02:49.836(3)? (STDERR)     at findSubscription (imports/api/stripe/subscriptions/controller.js:40:27)
W20190705-01:02:49.837(3)? (STDERR)     at Promise.asyncApply (server/payments/stripePayments.js:433:20)
W20190705-01:02:49.838(3)? (STDERR)     at ~/.meteor/packages/promise/.0.11.2.20ax7l.y5vky++os+web.browser+web.browser.legacy+web.cordova/npm/node_modules/meteor-promise/fiber_pool.js:43:40
W20190705-01:02:49.838(3)? (STDERR) ~/.../app/node_modules/apollo-engine/lib/launcher.js:246
W20190705-01:02:49.839(3)? (STDERR)                 throw maybeError;
elie222 commented 5 years ago

I can confirm the issue does not exist on montiapm:agent@2.35.0.

bavuongco10 commented 5 years ago

it's a real problem, our publications just crash without knowing the cause @@

tcastelli commented 5 years ago

Any updates on this @zodern ? For us, it happens just after starting the app when subscribing to any publication that uses publish-counts

zodern commented 5 years ago

It is fixed in version 2.37.0

radovansurlak commented 4 years ago

This is still a problem for me with version 2.37.2 - had to downgrade to 2.35.0

Exception while invoking method 'login' TypeError: Cannot read property 'length' of undefined I20200519-12:17:47.926(2)? at Tracer.event (packages/montiapm:agent/lib/tracer/tracer.js:98:56) I20200519-12:17:47.927(2)? at MongoConnection.mongoConnectionProto.(anonymous function) [as find] (packages/montiapm:agent/lib/hijack/db.js:67:37) I20200519-12:17:47.927(2)? at MongoConnection.findOne (packages/mongo/mongo_driver.js:794:15) I20200519-12:17:47.928(2)? at _0xb3b0x8.(anonymous function).findOne (packages/mongo/collection.js:356:29) I20200519-12:17:47.928(2)? at MethodInvocation.defaultResumeLoginHandler (packages/accounts-base/accounts_server.js:1324:29) I20200519-12:17:47.929(2)? at MethodInvocation.<anonymous> (packages/accounts-base/accounts_server.js:1308:38) I20200519-12:17:47.929(2)? at tryLoginMethod (packages/accounts-base/accounts_server.js:460:31) I20200519-12:17:47.931(2)? at tryLoginMethod (packages/accounts-base/accounts_server.js:1294:14) I20200519-12:17:47.931(2)? at AccountsServer._runLoginHandlers (packages/accounts-base/accounts_server.js:458:22) I20200519-12:17:47.932(2)? at MethodInvocation.methods.login (packages/accounts-base/accounts_server.js:518:31) I20200519-12:17:47.932(2)? at MethodInvocation.methodMap.(anonymous function) (packages/mdg:meteor-apm-agent/lib/hijack/wrap_session.js:161:30) I20200519-12:17:47.939(2)? at MethodInvocation.methodMap.(anonymous function) (packages/montiapm:agent/lib/hijack/wrap_session.js:161:30) I20200519-12:17:47.939(2)? at maybeAuditArgumentChecks (packages/ddp-server/livedata_server.js:1771:12) I20200519-12:17:47.940(2)? at DDP._CurrentMethodInvocation.withValue (packages/ddp-server/livedata_server.js:719:19) I20200519-12:17:47.942(2)? at Meteor.EnvironmentVariable.EVp.withValue (packages/meteor.js:1234:12) I20200519-12:17:47.942(2)? at DDPServer._CurrentWriteFence.withValue (packages/ddp-server/livedata_server.js:717:46) I20200519-12:17:47.943(2)? at Meteor.EnvironmentVariable.EVp.withValue (packages/meteor.js:1234:12) I20200519-12:17:47.943(2)? at Promise (packages/ddp-server/livedata_server.js:715:46) I20200519-12:17:47.944(2)? at new Promise (<anonymous>) I20200519-12:17:47.995(2)? at Session.method (packages/ddp-server/livedata_server.js:689:23) I20200519-12:17:47.996(2)? at packages/mdg:meteor-apm-agent/lib/hijack/wrap_session.js:52:38 I20200519-12:17:47.997(2)? at Meteor.EnvironmentVariable.EVp.withValue (packages/meteor.js:1234:12) I20200519-12:17:48.000(2)? Exception from sub meteor.loginServiceConfiguration id hFydNAPcM6AWcjsJp TypeError: Cannot read property 'length' of undefined I20200519-12:17:48.002(2)? at Tracer.event (packages/montiapm:agent/lib/tracer/tracer.js:98:56) I20200519-12:17:48.004(2)? at Cursor.cursorProto.(anonymous function) (packages/montiapm:agent/lib/hijack/db.js:135:37) I20200519-12:17:48.005(2)? at Cursor.kadira_Cursor_observeChanges [as observeChanges] (packages/montiapm:agent/lib/hijack/set_labels.js:77:41) I20200519-12:17:48.007(2)? at Function._publishCursor (packages/mongo/collection.js:365:32) I20200519-12:17:48.036(2)? at Cursor._publishCursor (packages/mongo/mongo_driver.js:910:27) I20200519-12:17:48.037(2)? at Subscription._publishHandlerResult (packages/ddp-server/livedata_server.js:1090:13) I20200519-12:17:48.037(2)? at Subscription._runHandler (packages/ddp-server/livedata_server.js:1063:10) I20200519-12:17:48.040(2)? at Subscription.MeteorX.Subscription._runHandler (packages/lamhieu_unblock.js:68:22) I20200519-12:17:48.043(2)? at Subscription.subscriptionProto._runHandler (packages/mdg:meteor-apm-agent/lib/hijack/wrap_subscription.js:12:24) I20200519-12:17:48.046(2)? at Subscription.subscriptionProto._runHandler (packages/montiapm:agent/lib/hijack/wrap_subscription.js:12:24) I20200519-12:17:48.046(2)? at Session.MeteorX.Session._startSubscription (packages/lamhieu_unblock.js:56:7) I20200519-12:17:48.048(2)? at Session.sub (packages/ddp-server/livedata_server.js:625:12) I20200519-12:17:48.179(2)? at Session.MeteorX.Session.protocol_handlers.sub (packages/lamhieu_unblock.js:27:15) I20200519-12:17:48.180(2)? at packages/mdg:meteor-apm-agent/lib/hijack/wrap_session.js:77:34 I20200519-12:17:48.182(2)? at Meteor.EnvironmentVariable.EVp.withValue (packages/meteor.js:1234:12) I20200519-12:17:48.183(2)? at Session.sessionProto.protocol_handlers.sub (packages/mdg:meteor-apm-agent/lib/hijack/wrap_session.js:76:44) I20200519-12:17:48.184(2)? at packages/montiapm:agent/lib/hijack/wrap_session.js:77:34 I20200519-12:17:48.184(2)? at Meteor.EnvironmentVariable.EVp.withValue (packages/meteor.js:1234:12) I20200519-12:17:48.185(2)? at Session.sessionProto.protocol_handlers.sub (packages/montiapm:agent/lib/hijack/wrap_session.js:76:44) I20200519-12:17:48.186(2)? at packages/ddp-server/livedata_server.js:559:43 W20200519-12:17:48.187(2)? (STDERR) Monti APM: no end event for type: wait W20200519-12:17:48.212(2)? (STDERR) This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). The promise rejected with the reason: W20200519-12:17:48.215(2)? (STDERR) TypeError: Cannot read property 'at' of null W20200519-12:17:48.216(2)? (STDERR) at MethodsModel.processMethod (packages/montiapm:agent/lib/models/methods.js:66:44) W20200519-12:17:48.217(2)? (STDERR) at Session.sessionProto.send (packages/montiapm:agent/lib/hijack/wrap_session.js:126:31) W20200519-12:17:48.218(2)? (STDERR) at Session.kadira_Session_send [as send] (packages/montiapm:agent/lib/hijack/set_labels.js:5:25) W20200519-12:17:48.219(2)? (STDERR) at promise.then.exception (packages/ddp-server/livedata_server.js:749:14) W20200519-12:17:48.220(2)? (STDERR) at /Users/radovan/.meteor/packages/promise/.0.11.2.7j140w.ob2tj++os+web.browser+web.browser.legacy+web.cordova/npm/node_modules/meteor-promise/fiber_pool.js:43:40 W20200519-12:17:48.348(2)? (STDERR) Monti APM: no end event for type: wait

philipmjohnson commented 4 years ago

I am getting a similar error as above. But I can't downgrade to 2.35.0 because my other packages require email@2.0.0. So, I'm not able to use Monti APM until this is resolved. Which is a drag, because I really want to pay you $5/month use it!

=> App running at: http://localhost:3200/
W20200930-14:17:25.586(-10)? (STDERR) (node:49481) UnhandledPromiseRejectionWarning: TypeError: Cannot read property 'length' of undefined
W20200930-14:17:25.587(-10)? (STDERR)     at Tracer.event (packages/montiapm:agent/lib/tracer/tracer.js:99:56)
W20200930-14:17:25.587(-10)? (STDERR)     at Function.Fibers.yield (packages/montiapm:agent/lib/hijack/async.js:8:33)
W20200930-14:17:25.587(-10)? (STDERR)     at stackSafeYield (/Users/philipjohnson/.meteor/packages/promise/.0.11.2.1e1wn8z.joczg++os+web.browser+web.browser.legacy+web.cordova/npm/node_modules/meteor-promise/promise_server.js:101:20)
W20200930-14:17:25.587(-10)? (STDERR)     at awaitPromise (/Users/philipjohnson/.meteor/packages/promise/.0.11.2.1e1wn8z.joczg++os+web.browser+web.browser.legacy+web.cordova/npm/node_modules/meteor-promise/promise_server.js:96:12)
W20200930-14:17:25.588(-10)? (STDERR)     at Function.Promise.await (/Users/philipjohnson/.meteor/packages/promise/.0.11.2.1e1wn8z.joczg++os+web.browser+web.browser.legacy+web.cordova/npm/node_modules/meteor-promise/promise_server.js:56:12)
W20200930-14:17:25.588(-10)? (STDERR)     at packages/webapp/webapp_server.js:466:3
W20200930-14:17:25.588(-10)? (STDERR)     at /Users/philipjohnson/.meteor/packages/promise/.0.11.2.1e1wn8z.joczg++os+web.browser+web.browser.legacy+web.cordova/npm/node_modules/meteor-promise/fiber_pool.js:43:40
W20200930-14:17:25.588(-10)? (STDERR)  => awaited here:
W20200930-14:17:25.588(-10)? (STDERR)     at Function.Promise.await (/Users/philipjohnson/.meteor/packages/promise/.0.11.2.1e1wn8z.joczg++os+web.browser+web.browser.legacy+web.cordova/npm/node_modules/meteor-promise/promise_server.js:56:12)
W20200930-14:17:25.588(-10)? (STDERR)     at packages/webapp/webapp_server.js:466:3
W20200930-14:17:25.588(-10)? (STDERR)     at /Users/philipjohnson/.meteor/packages/promise/.0.11.2.1e1wn8z.joczg++os+web.browser+web.browser.legacy+web.cordova/npm/node_modules/meteor-promise/fiber_pool.js:43:40
W20200930-14:17:25.589(-10)? (STDERR) (node:49481) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag `--unhandled-rejections=strict` (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 2)
W20200930-14:17:25.589(-10)? (STDERR) (node:49481) [DEP0018] DeprecationWarning: Unhandled promise rejections are deprecated. In the future, promise rejections that are not handled will terminate the Node.js process with a non-zero exit code.

If you want to reproduce this error, you can download the RadGrad2 system from:

https://github.com/radgrad/radgrad2

  1. CD into the app/ directory
  2. meteor add montiapm:agent
  3. meteor npm install
  4. meteor npm run start

Then try to retrieve http://localhost:3200 in a browser. That will trigger this error.

zodern commented 4 years ago

Thanks for the reproduction @philipmjohnson. I tried it, and did not encounter the error.

I published version 2.39.1-beta.1 which will log the full trace when this error happens. You can try it with meteor add montiapm:agent@2.39.1-beta.1. When it logs the trace, please share it here.

zodern commented 4 years ago

@philipmjohnson until this is fixed, you can modify the .meteor/packages file to force it to use email@2.0.0.

email@2.0.0!
montiapm:agent@2.35.0

Older versions of the agent are compatible with email@2

philipmjohnson commented 4 years ago

@zodern I promise you, it was busted yesterday!

Anyway, I started over with montiapm:agent@2.39.1-beta.1, and now everything appears to be working.

Thank you so much for your quick response! Already worth way more than the $5/month!

milanzigmond commented 3 years ago

Just added montiapm:agent@2.40.1 to my project and getting the same error:

I20210120-11:46:43.644(1)? Monti APM: Successfully connected W20210120-11:46:57.746(1)? (STDERR) Monti: invalid trace. Please share the trace below at W20210120-11:46:57.747(1)? (STDERR) Monti: https://github.com/monti-apm/monti-apm-agent/issues/14 I20210120-11:46:57.748(1)? { I20210120-11:46:57.749(1)? _id: 'undefined::0', I20210120-11:46:57.749(1)? type: 'http', I20210120-11:46:57.749(1)? name: 'GET-/', I20210120-11:46:57.749(1)? session: undefined, I20210120-11:46:57.749(1)? id: undefined, I20210120-11:46:57.749(1)? events: [ I20210120-11:46:57.750(1)? { I20210120-11:46:57.750(1)? type: 'start', I20210120-11:46:57.750(1)? at: 1611139617734, I20210120-11:46:57.750(1)? endAt: 1611139617734, I20210120-11:46:57.750(1)? nested: [], I20210120-11:46:57.750(1)? data: { I20210120-11:46:57.750(1)? url: '/', I20210120-11:46:57.750(1)? method: 'GET', I20210120-11:46:57.750(1)? headers: '{"x-forwarded-host":"localhost:3000","x-forwarded-proto":"http","x-forwarded-port":"3000","x-forwarded-for":"127.0.0.1","cookie":"_ga=GA1.1.428594087.1590139446; _ga_PE5DFP2BBB=GS1.1.1611138657.38.1.1611138813.0","accept-language":"en-US,en;q=0.9","accept-encoding":"gzip, deflate, br","sec-fetch-dest":"document","sec-fetch-user":"?1","sec-fetch-mode":"navigate","sec-fetch-site":"none","sec-gpc":"1","accept":"text/html,application/xhtml+xml,application/xml;q=0.9,image/avif,image/webp,image/apng,/;q=0.8,application/signed-exchange;v=b3;q=0.9","user-agent":"Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/87.0.4280.141 Safari/537.36","upgrade-insecure-requests":"1","connection":"keep-alive","host":"localhost:3000"}' I20210120-11:46:57.755(1)? } I20210120-11:46:57.756(1)? }, I20210120-11:46:57.756(1)? { I20210120-11:46:57.756(1)? type: 'async', I20210120-11:46:57.756(1)? at: 1611139617736, I20210120-11:46:57.756(1)? endAt: 1611139617736, I20210120-11:46:57.757(1)? nested: [] I20210120-11:46:57.757(1)? }, I20210120-11:46:57.757(1)? { type: 'async', at: 1611139617736 }, I20210120-11:46:57.757(1)? { type: 'asyncend', at: 1611139617736 } I20210120-11:46:57.757(1)? ], I20210120-11:46:57.757(1)? userId: undefined, I20210120-11:46:57.757(1)? _lastEventId: null I20210120-11:46:57.757(1)? } W20210120-11:46:57.846(1)? (STDERR) This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). The promise rejected with the reason: W20210120-11:46:57.847(1)? (STDERR) TypeError: Cannot read property 'length' of undefined W20210120-11:46:57.848(1)? (STDERR) at Tracer.event (packages/montiapm:agent/lib/tracer/tracer.js:104:56) W20210120-11:46:57.848(1)? (STDERR) at Function.Fibers.yield (packages/montiapm:agent/lib/hijack/async.js:8:33) W20210120-11:46:57.848(1)? (STDERR) at stackSafeYield (/Users/milanzigmond/.meteor/packages/promise/.0.11.2.1p7w05n.45ca++os+web.browser+web.browser.legacy+web.cordova/npm/node_modules/meteor-promise/promise_server.js:101:20) W20210120-11:46:57.848(1)? (STDERR) at awaitPromise (/Users/milanzigmond/.meteor/packages/promise/.0.11.2.1p7w05n.45ca++os+web.browser+web.browser.legacy+web.cordova/npm/node_modules/meteor-promise/promise_server.js:96:12) W20210120-11:46:57.848(1)? (STDERR) at Function.Promise.await (/Users/milanzigmond/.meteor/packages/promise/.0.11.2.1p7w05n.45ca++os+web.browser+web.browser.legacy+web.cordova/npm/node_modules/meteor-promise/promise_server.js:56:12) W20210120-11:46:57.849(1)? (STDERR) at packages/webapp/webapp_server.js:466:3 W20210120-11:46:57.849(1)? (STDERR) at /Users/milanzigmond/.meteor/packages/promise/.0.11.2.1p7w05n.45ca++os+web.browser+web.browser.legacy+web.cordova/npm/node_modules/meteor-promise/fiber_pool.js:43:40 W20210120-11:46:57.853(1)? (STDERR) => awaited here: W20210120-11:46:57.854(1)? (STDERR) at Function.Promise.await (/Users/milanzigmond/.meteor/packages/promise/.0.11.2.1p7w05n.45ca++os+web.browser+web.browser.legacy+web.cordova/npm/node_modules/meteor-promise/promise_server.js:56:12) W20210120-11:46:57.854(1)? (STDERR) at packages/webapp/webapp_server.js:466:3 W20210120-11:46:57.854(1)? (STDERR) at /Users/milanzigmond/.meteor/packages/promise/.0.11.2.1p7w05n.45ca++os+web.browser+web.browser.legacy+web.cordova/npm/node_modules/meteor-promise/fiber_pool.js:43:40

NOTE: mdg:meteor-apm-agent package is still in the project, not sure if that might be the problem

NOTE 2 - RESOLVED: looks like it was the problem to have the mdg package there, maybe it should be in the readme

zodern commented 3 years ago

This is fixed in version 2.41.0. It checks if your app is using any other APM agents based on Kadira, and logs a warning.