mayhemer / logan

Log Analyzer for Mozilla logs
7 stars 4 forks source link

Add support for Http2PushedStreams #30

Closed nwgh closed 6 years ago

nwgh commented 6 years ago

This one may be a bit tricky (or may not), because due to inheritance, some (many?) log lines from Http2PushedStreams show up as Http2Stream. It would be really useful to have, though. Probably also want to add Http2PushTransactionBuffer at the same time.

mayhemer commented 6 years ago

Definitely! Does this anything more than just proper ctor/dtor and linking (to a concrete class) logging? If yes, I will need to understand the structure and linking first. If you can describe it here or somehow in person, it would greatly help.

nwgh commented 6 years ago

The push stream ctor logs at https://searchfox.org/mozilla-central/rev/6d1ab84b4b39fbfb9505d4399857239bc15202ef/netwerk/protocol/http/Http2Push.cpp#78 - it gives you the this pointer, and the stream id. I believe the regular Http2Stream ctor code will run (and therefore log) before that line is hit, so that will need to be taken into account.

Later on, once gecko generates a transaction to use whatever was pushed to us, the code at https://searchfox.org/mozilla-central/rev/6d1ab84b4b39fbfb9505d4399857239bc15202ef/netwerk/protocol/http/Http2Stream.cpp#500 will run, which has the pointer of the pushed stream logged. That line already shows up in logs as matched with an Http2Stream (I believe), so I think you already have the info to match the two there. Matching those two allows us to chain from the pushed stream to the consumer stream to the consumer transaction. (Doesn't need to be in logan explicitly, as long as I can click through like I do for session -> stream -> transaction.)

Let me know if you need anything else from me.

mayhemer commented 6 years ago

And how are the objects related in reality? I still don't follow what to link with what - a pushed stream with a regular stream? I think that is the last bit I need to update logan rules, hopefully.

mayhemer commented 6 years ago

Aha, Http2PushedStream derives from Http2Stream. Still, not sure what exactly you want me to do.

mayhemer commented 6 years ago

And if you can, please give me a log to test with or a link to a test case/web I can produce a log to test with, thanks.

nwgh commented 6 years ago

Sorry, let me try to make all these relations clearer by describing a bit what we do with pushes in our h2 stack.

So what happens is, T and S know about each other, just like they would if no pushes were involved. However, S and P also know about each other (so the stream S can get data out of the pushed stream P and pass it on to the transaction T). The session knows about both S and P, but doesn't keep any explicit mapping between the two.

I'm attaching a (gzipped) log with a push in it (though note that this is from a buggy run where the transaction that eventually gets matched to that push never gets closed). Here's a bit of relevant info:

Http2PushedStream pointer 0x149229c90 id 0x86 (this is P in my outline above) Http2Stream pointer 0x12a77b480 id 0x0 (this is S in my outline above) nsHttpTransaction pointer 0x12e530c00 (this is T in my outline above) Http2Session pointer 0x149323800

nspr.log.gz

What I'm hoping for is for logan to show the link between S and P in the same way that it shows the link between S and T (where there's an added line that shows something like nsHttpTransaction @<ptr> --> Http2Stream @<ptr>)

mayhemer commented 6 years ago

Thanks! This is an awesome description.

mayhemer commented 6 years ago

If the only stream actually used in the log was the one you refer, then this is fixed with https://github.com/mayhemer/logan/commit/57bda9007348b12219debc86b2c0c34b45a66006