use utils.Logger not log

[imsodin]

I've been doing some quic-unrelated debugging with Syncthing and noticed log output in a format that Syncthing doesn't use (syncthing/syncthing#7146):

2020/11/24 10:52:01 Failed to sufficiently increase receive buffer size. Was: 208 kiB, wanted: 2048 kiB, got: 416 kiB.

Turns out it is quic logging directly to stdout instead of using it's own logger.

Please let me know if the error itself is problematic, then I can enable quic logging locally and see if it comes up consistently.

[googlebot]

Thanks for your pull request. It looks like this may be your first contribution to a Google open source project (if not, look below for help). Before we can look at your pull request, you'll need to sign a Contributor License Agreement (CLA).

📝 Please visit https://cla.developers.google.com/ to sign.

Once you've signed (or fixed any issues), please reply here with @googlebot I signed it! and we'll verify it.

---

What to do if you already signed the CLA

Individual signers

• It's possible we don't have your GitHub username or you're using a different email address on your commit. Check your existing CLA data and verify that your email is set on your git commits.

Corporate signers

• Your company has a Point of Contact who decides which employees are authorized to participate. Ask your POC to be added to the group of authorized contributors. If you don't know who your Point of Contact is, direct the Google project maintainer to go/cla#troubleshoot (Public version).
• The email used to register you as an authorized contributor must be the email used for the Git commit. Check your existing CLA data and verify that your email is set on your git commits.
• The email used to register you as an authorized contributor must also be attached to your GitHub account.

ℹ️ Googlers: Go here for more info.

[imsodin]

Could you please update your contributing section in the readme. Nothing in this private repo suggested to me that this is a google project. I know signed it as I already PRed and will probably guess I'll come accross a google project again anyway in the future, but if I'd new I wouldn't have done it for such a trivial change.

@googlebot I signed it!

[googlebot]

CLAs look good, thanks!

ℹ️ Googlers: Go here for more info.

[codecov]

Codecov Report

Merging #2904 (5694481) into master (a76879c) will not change coverage.
The diff coverage is 40.00%.

@@           Coverage Diff           @@
##           master    #2904   +/-   ##
=======================================
  Coverage   85.77%   85.77%           
=======================================
  Files         133      133           
  Lines        9180     9180           
=======================================
  Hits         7874     7874           
  Misses        958      958           
  Partials      348      348           

Impacted Files	Coverage Δ
packet_handler_map.go	73.02% <40.00%> (ø)

---

Continue to review full report at Codecov.

Legend - Click here to learn more
Δ = absolute <relative> (impact), ø = not affected, ? = missing data
Powered by Codecov. Last update a76879c...5694481. Read the comment docs.

[marten-seemann]

We're not logging to stdout, we're just using the log package. And we're deliberately doing that. If you use the default Linux UDP receive buffer size, you're guaranteed to have bad performance on high-bandwidth links.

[imsodin]

Ok, apparently I've jumped to wrong conclusions, thanks for clarifying.. Getting these lines printed to stdout and the presence of

		logger.Debugf("Connection doesn't allow setting of receive buffer size")

just a few lines above the usage of log, I assumed that was the reason. Should I open an issue to track that and find out what actually causes this?

If you use the default Linux UDP receive buffer size, you're guaranteed to have bad performance on high-bandwidth links.

Good to know, thanks for the hint. The use-case is indeed high-bandwidth and on linux and almost any other OS@ data transfer between the same application using quic-go. And we don't (recommend to) modify any UDP settings as far as I am aware, so this definitely affects us. Definitely good to know if that pops up in support, unfortunately nothing we can do pro-actively given it requires privileges to change.

[imsodin]

Having looked at your logging implementation this is how I understand it works:

You have an internal Logger interface and use a DefaultLogger instance of that for logging on different severity levels. The output of that default logger goes to the default logger of Go's log package. DefaultLogger is controlled by the env var QUIC_GO_LOG_LEVEL, which disables all logging by default, as described in https://github.com/lucas-clemente/quic-go/wiki/Logging. However in addition to this, you also use the log package directly in places, thus circumventing the logging control by QUIC_GO_LOG_LEVEL. Did I get this right?

As you log to the default logger of log, there's no way for an application using quic-go to control specifically quic-go's logging. If these errors are so bad, that they must reach the user of QUIC, then make them errors. Or expose a logging interface in the public API and log at error level by default instead of disabling, so that the user of your library can hook into that and integrate quic-go's logging into their own logging. It's not like I don't want to know when errors happen in QUIC, I just don't want any library to directly print things to stdout and thus confuse my users with weird looking log lines coming from Syncthing, but not really.

[apmattil]

how about just returning error to user and let it decide what to do ?

[marten-seemann]

Thank you for the discussion. This issue should have been alleviated by #2923 (which is included in the v0.19.3 release).