debugging run loop stacktraces is not dev friendly, is it possible to add function arguments?

[Leooo]

Hello,

Debugging in Ember is very cumbersome due to the run loop.

We have the stack trace but it is not always useful to understand from which part of the application code the exceptions come from - we have the line number but not the data used.

For example, for this regular exception:

  Error: Assertion Failed: calling set on destroyed object
    at new Error (native)
    at Error.EmberError (http://localhost:3000/assets/frontend/vendor.js:22060:21)
    at Object.Ember.default.assert (http://localhost:3000/assets/frontend/vendor.js:15395:13)
    at Object.set (http://localhost:3000/assets/frontend/vendor.js:25870:24)
    at exports.default.mixin.Mixin.create.set (http://localhost:3000/assets/frontend/vendor.js:39863:20)
    at Ember.Object.extend.flushCanonical (http://localhost:3000/assets/frontend/vendor.js:86749:14)
    at ember$data$lib$system$relationships$state$has$many$$ManyRelationship.flushCanonical (http://localhost:3000/assets/frontend/vendor.js:87069:22)
    at Queue.invoke (http://localhost:3000/assets/frontend/vendor.js:11433:18)
    at Object.Queue.flush (http://localhost:3000/assets/frontend/vendor.js:11498:13)
    at Object.DeferredActionQueues.flush (http://localhost:3000/assets/frontend/vendor.js:11303:19)"

For every new release of Ember, I overwrite ember-debug with the following lines:

  function set(obj, keyName, value, tolerant) {
    (...)
    if (obj.isDestroyed) {
      log("LV ember set "+keyName+" on destroyed object, returning false:","red");
      log(obj);
      return false;
      //Ember['default'].assert("calling set on destroyed object", !obj.isDestroyed);
    }

which tells me which object created the exception and the property who is getting set.

Is it naive to ask if such objects could be added in the EmberError stacks, if this is possible technically (not sure in javascript strict mode) with a routine which would systematically add the arguments of the function being called and the context - this would cover most of the cases. If not, maybe try to add more information on the most frequent errors in the run loop?

Thanks.

https://github.com/emberjs/ember.js/issues/2817

[Leooo]

Just to give another example:

  invokeWithOnError: function(target, method, args, onError, errorRecordedForStack) {
    try {
      if (args && args.length > 0) {
        method.apply(target, args);
      } else {
        method.call(target);
      }
    } catch(error) {
      //LV
      log("LV invokeWithOnError error:","red");
      log(target);
      log(method);
      log(args);
      onError(error, errorRecordedForStack);
    }
  },

[stefanpenner]

Just to give another example:

this is already pluggable. Ember.onerror

[Leooo]

?
Ember.onerror gives us access to the error message and stack, which of course is great. But here is the result for the example above:

TypeError: Cannot read property 'reopen' of undefined
    at EmberObject.extend.dropObject (<anonymous>:2198:17)
    at EmberObject.extend.retainObject.object.reopen.willDestroy (<anonymous>:2170:18)
    at Queue.invokeWithOnError (http://localhost:3000/assets/frontend/vendor.js:11442:20)
    at Object.Queue.flush (http://localhost:3000/assets/frontend/vendor.js:11503:13)
    at Object.DeferredActionQueues.flush (http://localhost:3000/assets/frontend/vendor.js:11303:19)
    at Object.Backburner.end (http://localhost:3000/assets/frontend/vendor.js:10728:27)
    at http://localhost:3000/assets/frontend/vendor.js:11131:20

How am I supposed to know where the error comes from with this?

By logging the objects, I was able to see that a view was being destroyed in a weird way, which view it was, its constructor, parentController etc.: immediate to debug, except I had to monkey patch ember-debug to log the objects..

Basically if you could pass objects in addition to the error message in Ember.assert, and make them accessible in Ember.onerror that would be it.

[stefanpenner]

How am I supposed to know where the error comes from with this?

at EmberObject.extend.dropObject (:2198:17) at EmberObject.extend.retainObject.object.reopen.willDestroy (:2170:18)

It tells you where it came from, but doesn't provide context as to why that code path was taken.

A solution exists, but without platform support it will make apps in dev mode hundreds of times slower. In theory we could make that mode opt-in.

––––

note: this is a duplicate, as it arises every few months. We have commitment from the chrome team to provide us platform support: See https://code.google.com/p/chromium/issues/detail?id=332624 for more details.

As it still hasn't landed there, we may need to add longStacks, but again they will have to be opt in as they are going to be quite costly.

[Leooo]

ok, what I meant was: From the stack, I understand that an undefined object is being destroyed. From my additional logs, I understand which object it is (a view on my right col panel). Without this additional log I can not debug.

I'm fine with adding my logs to ember-debug, I was just thinking such an improvement would save lots of time for developers getting into Ember.

[stefanpenner]

I'm fine with adding my logs to ember-debug, I was just thinking such an improvement would save lots of time for developers getting into Ember.

I think if anything, opt-in longStack traces would be accepted. I should likely just implement those tonight/soon, i've been hoping our friends on the chrome team would land there (much faster and better work) sooner. As that approach would provide a useful stacktrace explorer

[Leooo]

Not sure I'm following, but thanks.

In my case the line causing the exception was:

 Ember.run.once(this,'destroy')

Given the destroy method is inside the run loop, would you be able to trace back to the function calling the Ember.run.once? If yes I don't know how you do that but it's great.

[stefanpenner]

If yes I don't know how you do that but it's great.

yes

[Leooo]

It's great.

[pixelhandler]

Just curious, @Leooo @stefanpenner is this the type of request that should be moved into an RFC? http://github.com/emberjs/rfcs

[stefanpenner]

Just curious, @Leooo @stefanpenner is this the type of request that should be moved into an RFC? http://github.com/emberjs/rfcs

In general yes, although maybe we can fast track this.

My thought process (please feel free to share your thoughts)

1. There isn't any controversy/objection, I have personally just put this off for ages...
2. no public API will be needed
3. I intend to implement something already understood (it exists in promise libs all over the place, just not in BB + RSVP)
4. Time trade-off: I can likely implement it the time it would take me to write the RFC.
5. RFC typically is used to flesh out the unknowns, I am fairly confident in the solution.

I can accept that that fact that this is embodied in my brain is a risk, i suspect once i show the code it wont be a risk?

That being said, I can likely accept that a detailed explanation will be of value. But maybe its worth more being left as inline docs?

[rwjblue]

@stefanpenner - I do not think an RFC is needed if we do not expose additional public API.

[Leooo]

btw, just a small note: the "Promises" tab in Ember Inspector seems in most cases to have all the information which would be needed to debug an exception: model, id etc. (Label column). Wouldn't it be easy to add the label / promise Id to the error message when occuring inside a promise (like in most cases)?

For example, right now I have a "Cannot read property '_internalModel' of undefined" exception in my staging environment (only, not in development) that I can't explain (I'm trying to check my find/findRecords methods but I can't see anything wrong). Checking the promises tab I see lots of promises rejected with the label "Fetching frontend@model:relationship-element with id: 1289", this may be a lead to understand the exception but then there are thousands of promises in the inspector tab so not easy to understand - except if I had the exact id of the promise who failed.

EDIT:

Got it! One of the promises in the inspector tab had the fulfillment / rejection value "TypeError: Cannot read property '_internalModel' of undefined", so that's the one. The label is "Fetching frontend@model:cur-user2:with id: 13" so now i know where it's coming from. It doesn't seem possible to search by fullfilment value in the Ember Inspector tab but I can at least look only at the rejected promises to isolate the one which caused the exception. It should be very useful for me in the future, but I think the whole process should at the very least be explained in the debugging docs for Ember.

[stefanpenner]

Hey that sounds like a great little improvement for the inspector can you open an issue there also so we don't forget?

[Leooo]

done thanks Stefan.

[Leooo]

Adding here the feature request which would not be for the Ember Inspector team: add promise labels as a second argument to the on('error') event.

[stefanpenner]

@Leooo https://github.com/emberjs/ember-inspector might be the best place to report that

[Leooo]

Hmm no that's the point: the Ember Inspector team isn't managing the on('error') event right? I mean I don't know how you guys split the work, still posting in both threads but I suppose this part of the request (adding promise labels to the error event) wouldn't be for them.

[stefanpenner]

(we are the same team, no need to cross post) Its easier to track issues at the level at which they are used.

[teddyzeenny]

@stefanpenner I think @Leooo is proposing:

RSVP.on('error', (error, label) => {
  // The unhandled failed promise's label is passed here so we know which promise failed.
  console.log('failed promise: ', label);
});

So that users can access promise labels of failed promises without having to look for them in the inspector.

[Leooo]

Exactly, sorry if I was not more clear.

[stefanpenner]

ah, i get it. Easy...adding that now.

[stefanpenner]

@teddyzeenny / @Leooo https://github.com/tildeio/rsvp.js/pull/404

[Leooo]

Thanks!

[stefanpenner]

So, i basically stopped working on the long stack stitching stuff when i realize there was no way to make chrome print it by default... We have been working with the chrome folks on making custom printers, so things like ember inspector could provide higher fidelity output. This may be an avenue to fix this issue, if/when it lands I will be more motivated to work on this.

In addition the chrome folks are apparently going to be working on an ability for user land libs, to annotate/inform the runtime of source stacks, which in theory would allow both errors and the stack explorer to work as expected. They are interested in pursuing this I hope it lands.

We should revisit if either of the above two become available. (or if a different solution is presented)

[shellandbull]

@stefanpenner hello - was wondering if any of the 2 have happened? or where to follow up on this sort of news? 😄