Skip to content

Conversation

aguilEA
Copy link
Contributor

@aguilEA aguilEA commented Nov 9, 2018

Resolves #222

@coveralls
Copy link

coveralls commented Nov 9, 2018

Pull Request Test Coverage Report for Build 1143

  • 26 of 59 (44.07%) changed or added relevant lines in 2 files are covered.
  • No unchanged relevant lines lost coverage.
  • Overall coverage increased (+0.2%) to 25.484%

Changes Missing Coverage Covered Lines Changed/Added Lines %
rtcpeerconnection.go 4 10 40.0%
pkg/logging/logging.go 22 49 44.9%
Totals Coverage Status
Change from base Build 1140: 0.2%
Covered Lines: 1750
Relevant Lines: 6867

💛 - Coveralls

@aguilEA aguilEA force-pushed the rtcpeerconnectionLogging branch from 9beba43 to 706ff2a Compare November 10, 2018 22:39
Copy link
Member

@Sean-Der Sean-Der left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Fantastic work! This is such an exciting change, if you can land the changes suggested I would be happy to merge right away :)

this is going to make a lot of people happy (including myself)

// comparisons when no value was defined.
const Unknown = iota

// RTCPeerLogger is the default logging struct for rtcpeerconnection.
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I would move RTCPeerLogger + webrtcLogger to a dedicated package

This way other packages can import/use the logger (like github.com/pions/internal/sctp) right now we can't pass our logger instance down to other packages.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Placed them in their own package pkg/logging/. The interface and struct names seem slightly unintuitive. Let me know if you have a better naming convention.

@aguilEA aguilEA force-pushed the rtcpeerconnectionLogging branch from 6ed043d to 3bbe277 Compare November 19, 2018 22:50
@mjmac
Copy link
Contributor

mjmac commented Nov 20, 2018

@aguilEA: If you rebase your changes on master and then force-push, it will make it easier to review this patch. As it is now, your patch changes are mixed in with all of the updates that have happened since you first submitted this.

Copy link
Contributor

@mjmac mjmac left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Hi @aguilEA -- there are some good ideas in here, but I think we need to generalize things a bit and also address the requirement for enabling/disabling logging per component or subsystem. For example a developer or power user may want to enable copious logging in the ICE agent while trying to figure out why connections aren't working, but doesn't want to see tons of log spam from other systems.

I took a stab at addressing that in my own proposal, but I didn't add any provision for logging at different levels. Do you want to see where we can meet in the middle on these ideas?

)

// RTCPeerLogger is the default logging struct for rtcpeerconnection.
type RTCPeerLogger struct{
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I think the overall goal should be to provide a generalized logging solution for various subsystems in pions-WebRTC, right? Rather than naming this RTCPeerLogger I'd suggest something like LeveledLogger? That's a little awkward to import as logging.LeveledLogger, but not the worst imo.


// webrtcLogger is the interface that must be implemented if a custom
// logger is used.
type webrtcLogger interface{
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I'm confused about what this interface is used for -- it's not exported, so it can only be used internally to the logging package. But I don't see any use of it in logging.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I was setting it a loging interface in order to have method in RTCPeerConnection which accepts the interface, and the user can pass a struct that allows them to do logging however they want. Ultimately a user would call a function pc.setLogger(myCustomLogger).

}

func (pclog *RTCPeerLogger) Debug(debug string){
pclog.debug.Println(debug)
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This is clear and simple, and the use of ioutil.Discard as the default writer makes sense from a functionality perspective. I have concerns about this approach from a performance perspective, however. For occasional logging e.g. at the Info/Warning level, I think overhead would be negligible. For copious logging at the Trace/Debug levels, I'm sure that we would start to see a lot of wasted resources spent formatting things in Println() just to throw them away.

Have a look at the source of printArg() to see how much work is happening behind the scenes -- it's pretty interesting.

I would propose instead using SetLoglevel() to set a level in the logger and then only calling Println() for the appropriate levels.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Yeah I read "Discard is an io.Writer on which all Write calls succeed without doing anything." and thought that it was not affecting performace. However if this is not the case then yeah we don't want to impact performance. This is my first time messing with the go logger, but if we can set a level in the logger and use that to determine what to print then that sounds good.

pclog.trace.Println(trace)
}

func (pclog *RTCPeerLogger) SetLogLevel(l logLevel) {
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This is a good first pass, but unfortunately it would reconfigure the logging destinations every time SetLogLevel() is called. If we're going to go down the road of setting separate loggers for each log level, then I think it would make more sense to do this setup in a NewLogger() function and keep SetLogLevel() focused on simply changing the active logging level.

One way to make this nicely configurable might be to add With...() methods on your logger. So for example your NewLogger() would return a logger configured for opinionated and sane defaults, but that logger would have methods for doing things like setting the loglevel (e.g. .WithLogLevel(logging.Debug)), and logging destinations/configuration for various levels. For example, one might define a logger like so:

log := logging.NewLeveledLogger().
      WithLogLevel(logging.LogLevelDebug).
      WithDebugLogger(log.New(os.Stderr, "custom ", log.Lmicroseconds|log.Llongfile|log.LUTC))

log.Debug("o hai")

Copy link
Contributor Author

@aguilEA aguilEA Nov 21, 2018

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

In the case that we do use levels for loging are you suggesting that we create logers like this?

Tracelog := logging.NewLeveledLogger().
WithLogLevel(logging.LogLevelTrace).
WithDebugLogger(log.New(os.Stderr, "trace ", log.Lmicroseconds|log.Llongfile|log.LUTC))

Debuglog := logging.NewLeveledLogger().
WithLogLevel(logging.LogLevelDebug).
WithDebugLogger(log.New(os.Stderr, "debug ", log.Lmicroseconds|log.Llongfile|log.LUTC))

@aguilEA
Copy link
Contributor Author

aguilEA commented Nov 21, 2018

Hey @mjmac
Thanks alot! I think you are right about implementing logging per subsystem. I was implementing a simple and common functionality logger, but ultimately subsystem logging will create a more understandable debugging.

I read you suggestions on LoggingAPI wiki and I agree that an error should be returned to the user code. I am also not sure who will be defining what info, warning, etc levels are and we can add those if someone can define what type of messages are categorized under those levels.

@aguilEA aguilEA force-pushed the rtcpeerconnectionLogging branch from 3bbe277 to 0c74339 Compare November 25, 2018 22:51
@Sean-Der
Copy link
Member

@aguilEA are you still interested in working on this? No rush (would much rather have outside contributors) but would love to see this implemented!

I think this features lends to some bikeshedding, I think we could figure out a minimal version and really should shoot to get it written/merged in under 3 days :) I hate to see peoples work ignored

@aguilEA
Copy link
Contributor Author

aguilEA commented Dec 22, 2018 via email

@Sean-Der
Copy link
Member

Hey @aguilEA

No rush at all! But I would love to see this change, it is very high on my personal wish list. Feel free to chat in the #pion slack with @mjmac if that makes it easier.

It is always better when other people work on features (they point out features and add things you never thought of) and just a great way for me to learn :)

thanks

@backkem backkem changed the title RTCPeerConnection Logging [WIP] RTCPeerConnection Logging Dec 24, 2018
@Sean-Der
Copy link
Member

This landed with b98909a

This is a great start, but would love to continue to see improvements to the logging if you are interested @aguilEA

We should right a lint that doesn't allow fmt.Println or fmt.Printf and covert them all to the logging stuff (and other things like that)

@Sean-Der Sean-Der closed this Dec 31, 2018
@aguilEA
Copy link
Contributor Author

aguilEA commented Jan 3, 2019 via email

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Development

Successfully merging this pull request may close these issues.

4 participants