debug logging

[max-mapper]

I've had this in the back of my mind forever and finally decided to give it a go today. I often want to do e.g. DEBUG=through2 to see the start, transform and end state of through2 streams when debugging. This is a first pass at doing so. It's just a proposal right now -- I'm open to feedback.

Example output:

I tried to do it in a way that wouldn't add a dependency and also wouldn't impact perf. I think having this logic in through2 makes sense because it is used so widely. I thought about putting the debug module in another module called e.g. through2-debug but I personally don't think that would be as widely useful for debugging.

I also am open to suggestions on how to test this.

[juliangruber]

maybe (debug === '*') || (/through2/.test(debug)) so you can do DEBUG=through2,another-module

[max-mapper]

cool, updated in max-mapper@7445786

[juliangruber]

i find assigning random ids to streams very helpful for debugging, so in your output you can tell which stream an event belongs to...like

function Stream(){
  this.id = rand();
  if (!debugMode) this.debug = function(){}
}
Stream.prototype.debug = function(){
  console.error([this.id].concat(arguments))
}

[mafintosh]

for perf reasons you probably want to put the content of this if inside a function to avoid these functions being hoisted

[max-mapper]

it would only happen once though at the time of stream construction, do you think that would make a noticeable perf impact?

[mafintosh]

true, probably not

[mafintosh]

LGTM from me. @juliangruber @rvagg ? (the tests seem to fail on 0.11 for some weird unrelated reason)

[juliangruber]

lgtm

[timoxley]

I usually add something very similar to this to my streams when I'm trying to figure out what's going on, overall +1.

i find assigning random ids to streams very helpful for debugging

Agree.

[max-mapper]

OK with some pair programming w/ @timoxley I added ids to streams and did some refactoring. I think i've addressed all the comments so far

[juliangruber]

looks 🥚cellent to me!

[max-mapper]

@rvagg ping, any feedback?

[rvagg]

eeek, sorry @maxogden, I'm slowly catching up on a big backlog. I don't see any negativity about this change from contributors so far so I'm not inclined to give a -1 here even though I have some reservations.

@Delapouite & @brycebaril do either of you have thoughts to add here?

[stevemao]

👍

[okdistribute]

As a beginner in the node streams space, I've found myself doing this manually a lot while learning. Would be great to have!

[rvagg]

@brycebaril and @thlorenz would you mind giving me another opinion here? I'm not a fan of this change because it's so invasive but perhaps the argument of being able to see inside makes it warranted?

[thlorenz]

I'm not sure this belongs into through2, even though it's a nice feature to have.
A better way may be to hook into streams creation and attach handlers then.

I haven't done this myself, but if the Stream base constructor was patched to emit an event with the stream (this) as argument when it is created then the listeners could be attached there.

It's as dirty as it gets, but would only be used in DEBUG mode. As an added benefit it'd give info about all streams, not just the ones created with through2.

[max-mapper]

@thlorenz ah thats not a bad idea. I'll give that a shot and see if I can get my precious DEBUG data that way :)

[thlorenz]

@maxogden looking forward to seeing that code as until recently I wasn't even aware that you could patch constructors. I'd like to learn how that's done :)

[mafintosh]

@maxogden you probably need to walk require.cache and do this for all
instances of readable-stream required
On Tue 12 May 2015 at 03:30 Thorsten Lorenz notifications@github.com
wrote:

@maxogden https://github.com/maxogden looking forward to seeing that
code as until recently I wasn't even aware that you could patch
constructors. I'd like to learn how that's done :)

—
Reply to this email directly or view it on GitHub
#33 (comment).

[stevemao]

any news @maxogden ?

[rvagg]

stale, sorry