Add tracing capabilities to Express #2437
Conversation
| var start = Date.now() | ||
| res.id = random(); | ||
| res.trace('start', new Date()); | ||
| next(); |
There was a problem hiding this comment.
This is not Koa; as soon as you introduce something async in the line below, res.trace('finish') not not be the finish. I know it works because everything you have in here is sync, but being an example file, this will confuse people to no end.
There was a problem hiding this comment.
Yep, sorry. I copy/pasted the example. I didn't even think about asynchronism since trace is synchronous.
|
Thank you for your feedback. I updated the example. Do you think it's ok now? About the name for the dispatch function. What do you think about |
I would probably call it |
|
Yes that sounds good. I will commit changes soon. |
|
|
|
If there is no underscore, we need to document it as if it was a public API that users shoulld be caling themselves. That's the test to know which it should be. |
frankrousseau
force-pushed
the
trace
branch
2 times, most recently
from
8d5f09c
to
1be3620
Compare
|
Ok, I changed the name from |
|
@dougwilson are the fixes good? |
|
I want to merge this. Does anyone here have any further comments on this? |
| app._callTracers = function(res, event, args){ | ||
| var date = new Date(); | ||
| var app = this; | ||
| this.tracers.forEach(function(tracer){ |
There was a problem hiding this comment.
I suggest that we use for loop to avoid the performance penalty of closures. See http://jsperf.com/array-foreach-vs-for-loop.
There was a problem hiding this comment.
Good idea :) This will get called a lot, so performance is pretty important for this function.
|
In general, this is pretty much |
|
https://github.com/strongloop/express/pull/2437/files#diff-65b72b264c47d33fec6edef30f143501R40 way too many arguments here. at this point, might be easier to pass everything through an object. playing with other than that, it's pretty straight forward and siumple |
|
Cool. Great feedback :)! |
|
Thank your @jonathanong and @raymondfeng for the feedback. So, if I understand well, what need to be changed is:
Could you me tell if I'm right? Then, if it's ok, I will commit the changes. |
|
Sounds good, yes. |
|
I made all changes you asked. @dougwilson @jonathanong @raymondfeng it's ready for another review. |
|
i added some comments, but those are usually my personal code styles so i don't think they're a big of a deal. if anything, @dougwilson likes to touch up PRs before he merges them. but overall, i think it's simple and good. i haven't touched express in a while so my opinions matter less ;) |
|
What is the next step for this PR? @ilanbiala @dougwilson @expressjs |
|
@hacksparrow @dougwilson Can we merge this please? |
|
Sorry, didn't notice all these changes to all the feedback. I'm not sure if anyone has actually take a look at all the changes yet (at least, I haven't). |
| parentTraces1[0].should.be.equal('one:event:parent1'); | ||
| parentTraces2[0].should.be.equal('one:event:parent2'); | ||
| parentTraces1[1].should.be.equal('one:event:parent1'); | ||
| parentTraces2[1].should.be.equal('one:event:parent2'); |
There was a problem hiding this comment.
At some point prior to merging, we'll want to change all these should.js usages to assert.
|
|
||
| request(appParent2) | ||
| .get('/childof2') | ||
| .expect(200, function(){ |
There was a problem hiding this comment.
This .expect(200 doesn't do anything if you're just ignoring the first argument to the function, which is err from the expect.
|
|
||
| request(appParent1) | ||
| .get('/childof1') | ||
| .expect(200, function(){ |
There was a problem hiding this comment.
This .expect(200 doesn't do anything if you're just ignoring the first argument to the function, which is err from the expect.
| }; | ||
|
|
||
| for (var i = 0; i < length; i++) { | ||
| tracers[i](options); |
There was a problem hiding this comment.
Do we want to do any kind of special handling if one of these tracers throws an error, even if that is just to continue to execute all the tracers?
There was a problem hiding this comment.
Good point but I don't know what is best. Do you know what is the best practice in this case?
There was a problem hiding this comment.
Do you know what is the best practice in this case?
I'm not sure, because that is a question that has to do with what exactly the usage of app.instrument is supposed to be. Something needs to be done, and I was hoping you would know, since you made the PR :) I can help decide, but need to understand a lot better how this PR would be used in practice, etc. You know, the code here is being built for someone to use, and those users' needs are what this needs to cater towards. I don't really have the need, so it's hard for me to answer this question unless you can help educate me on the needs :)
There was a problem hiding this comment.
I made that PR two years ago based on a open issue. At that time, everyone looked to be fine with the current implementation. So I propose we don't change anything for the moment.
There was a problem hiding this comment.
There was a problem hiding this comment.
If Koa is doing this using a module, why not do that with Express? For example, make a module that works just like the Koa one:
var app = express()
require('express-trace')(app)| var express = require('../'); | ||
|
|
||
| describe('app', function(){ | ||
| describe('._callTracers(options)', function(){ |
There was a problem hiding this comment.
I wouldn't bother adding a test for an underscore-prefixed method, unless we're intending it to be a public interface.
| default: | ||
| args = [].slice.call(arguments, 1); | ||
| } | ||
| this.app._callTracers(this, event, args); |
There was a problem hiding this comment.
Would there be any benefit to scheduling the tracers run to a new call stack, rather than in the middle of the request trying to be measured?
There was a problem hiding this comment.
Sorry, I don't get it. Can you provide more details (and examples eventually)?
There was a problem hiding this comment.
Hm, I'm not sure how to elaborate since I don't fully understand the purpose of the tracers. Can you help me understand what kinds of things people will be putting the tracers? The example provided in this PR shows only a single tracer simply doing debug(options.res.id, options.event, options.args.join(' '));. Is that the only thing people will do, or are they expected to add more complex tasks there?
There was a problem hiding this comment.
FWIW The main use case for me is tracing request times as given in the example https://github.com/expressjs/express/pull/2437/files#diff-65b72b264c47d33fec6edef30f143501R8
So it's quite important that the times measured reflect the actual time taken.
There was a problem hiding this comment.
Hi @No9 if that is the use-case, why do we need to have multiple tracers? Can you elaborate on the measurement aspect? I see you pointed to the line res.start = Date.now(), but that is in the middleware, so I'm not sure how that would be affected?
There was a problem hiding this comment.
Hi @No9 wouldn't the use-case outlined at the top of #2191 be better handled with the router events being worked on in PR pillarjs/router#49 ?
There was a problem hiding this comment.
@No9 Could you try using my branch to see if the current state answers to your needs?
There was a problem hiding this comment.
@dougwilson Oh that is interesting and it looks exactly like what I am looking for thanks - I will have a look during the week.
I also see overall tracing in node is being discussed at the moment nodejs/node#9304
There was a problem hiding this comment.
There are several discussions in this thread, let's put numbers on it to make things easier to follow:
1) Multiple tracers
I think we should keep it that way. People may need different levels of tracing and it doesn't make the code much more complex.
2) processNextTick
Not sure to understand the need of processNextTick here. I suppose that people expect an immediate execution of the tracing and processNextTick could confuse them. Can you give me an example?
3) Tracing middlewares
Tracing is very specific to developed application. In which case 3rd party middlewares trace something?
5) Documentation
I will care of it. I will see what could be done for the following use cases:
- Basic debug calls
- Response time measurement
- Generate Chrome Trace outputs
If I can't find time to do it, I will notify you.
There was a problem hiding this comment.
Re docs @frankrousseau I created a tracking issue a while back: expressjs/expressjs.com#729. If there questions or issues specific to how/what needs docs, please put them there. Thanks!
| */ | ||
|
|
||
| res.trace = function(event) { | ||
| var args = []; |
There was a problem hiding this comment.
args seems to always be reassigned below; probably a useless empty array creation here.
| }); | ||
|
|
||
| app.get('/', function(req, res){ | ||
| res.trace('one:event', 'info'); |
There was a problem hiding this comment.
In this test, isn't info also emitted? I don't see anything verifying that, so we should either verify or just remove the argument here.
There was a problem hiding this comment.
Info parameter is tested here: https://github.com/frankrousseau/express/blob/786785b77061bffff90c7b710475af24a35e7ff5/test/res.trace.js#L15
There was a problem hiding this comment.
That link is going to a different test than the one I'm commenting on here.
|
Ok @dougwilson, I will have a look at your comments this weekend. |
Supertest lib provides a method called expect to test the result of a request. This method requires a callback that takes an error object as first parametr. If this error object is not inspected, the validation performed by expect are not checked. Tracing tests didn't do that checking. This commit add checking to trace tests to ensure that no error is returned when expect method is called.
Private methods do not need to be tested
|
I opened a PR for the documentation. It may help to discuss about the use cases. I would be glad to know what you think about it. |
|
In case you missed my comment above to one your your responses, I asked why this couldn't be a module like how Koa does it and needs to be built into the core instead. A module could be used against old Express versions, while core cannot do that, for example. |
|
I am also in favor of making it a "requireable" module, which not only works with Express but also anything that has a similar signature as Express'. That is unless there is an absolute necessity to bake it into the core. |
|
Sorry, I missed your question. So, why did I chose to add it to internals? Simply because you, @dougwilson, asked me to do it: #2191 (comment) . It's now two years we are working on this. So, as a contributor, I would like to have a clear and strong decision from the maintainers: closing this PR or merging it quickly. Our back and forth won't be productive if we keep hesitating on what to do. |
Hi @frankrousseau the comment you linked to has nothing to do with this PR. This PR is something that can be done in user-space. My comment is about the actual contents of that issue, as explained at the top in #2191 (comment) I don't see anything like that in here, and to add those events, it would have to be done in core, but this PR has nothing to do with adding any events at all. I'm sorry if there was miscommunication around that, which is probably what is causing this PR to take so long. What can we do to get some clear communication going between us? Would it be effective to have a voice / video meeting between us over the weekend to hash this out or something? |
|
This comment is definetely related with this PR. If you read the following comments, you agreed with the current implementation. Moreover, this comment match with my explicit question (which is right above):
I can understand you changed your mind in 2 years, but now we need to find a consensus about what what is expected and if that feature is still wanted or not. Having a chat this weekend sounds a good solution. It will be also the opportunity for you to explain me the contribution lifecycle for the ExpressJs project. When are you available? What is your timezone mine is Europe/Paris, UTC+01:00)? |
|
I think the resolution to this PR is pretty much settled: make a module on npm. |
|
Thank you for making things clearer. |
|
Hi @frankrousseau I still do want to have the discussion, if you're up to it. You never know what will come from it (even a re-open). I am in US Eastern time (UTC-5 right now) and so something like 10am or later is workable. If you ping me an email, we can work out the contact details and time. We could even make it a Google Hangout on our YouTube channel if you're up to that, so everyone can listen it / have a record :D ! |
|
I know there has been a lot of miscommunication all around, and I am sorry. I feel bad for leading around just as much for you feeling bad for hanging around, I'm sure. FWIW, now with a much better understanding of what this PR actually does, and how it is implemented, I think that since it is capable to be implemented in user-land, actually implementing is user land would have a better positive impact than constraining it to core as @hacksparrow noted above. There is also no reason why a future core can't, for example, just automatically include the user-land mode as the method to add to core by default, similar to how much of core currently works. |
|
Now I know better Express I understand your point. But what frustrates me is that I was explicit about what I was going to do, I integrated many feedbacks from numerous reviews. To finally read, 2 years later, that it should be done outside of Express. While the module separation was one of my first question. To avoid this kind of situation, I think that something could be changed in the way contributions are handled. I will send you an email to set an Hangout meeting or equivalent. |
|
Hi @frankrousseau I understand the frustration. Also keep in mind that over those two years, the express repo has been moved between organization, has changed ownership, and more. The project was not in a good position to make large contributions successful and finally, after all this time, we are getting a Technical Committee to oversee Express, getting documentation around the principals of Express, and more. The only good thing I can say about your situation is that the contribution was over the duration of a very turbulent time in Express's history and you have been caught in that situation. |
|
Ok, so if things are better structurated, that's a good news. I hope things will keep improving. Making a clear choice about this PR is already a sign of progress. |
|
I have some minor comments on the README... @dougwilson Should we fork (or copy?) this in the expressjs org before we start working on it? Or, what's the proper workflow....? |
|
@frankrousseau thanks |
Hi Express team,
To follow the discussion posted in the #2191 issue, I send you a proposal to implement tracing support in Express. Let me know if it matches your requirements. It is inspired by Koa Trace.
Goal
We want to allow to trace the response life-cycle. The tracing should support any tracing technology.
Implementation
tracersarray at the application level.instrumentfunction on the application prototype to add a tracer to the tracer list.dispatchfunction on the application prototype to activate all set tracers.traceon the response prototype to run tracers with current context and given event as arguments.