#113 use std.experimental.logger #187

SingingBush · 2018-05-13T20:52:17Z

not a lot to it but should be helpful

Abscissa · 2018-05-14T02:07:20Z

.gitignore

@@ -24,3 +24,10 @@ ddoc/packageVersion.ddoc
 source/mysql/packageVersion.d

 /unit-threaded-*
+
+# Ignore Intellij IDE files:


These changes aren't related to to the rest of the pull request and shouldn't be part of the same PR.

Also, these files being ignored aren't related to mysql-native or any of its dependencies. Instead, they are editor-specific and thus user-specific, so they belong in the user's own local ignore file (.git/info/exclude) not in the project's public .gitignore. (I do wish git and common git tutorials were more clear about this, though.)

that's fair enough, I'll remove them. I prefer keeping IDE related ignores in my projects gitignore. The more people that contribute the more chance there is that someone won't have a user specific ignore and such files may get pushed.

Abscissa · 2018-05-14T02:51:10Z

A few things with this:

mysql-native shouldn't output anything to stdout/stderr by default. This needs to be opt-in.
The logger should be configurable, not hard-wired to phobos's default of FileLogger(stderr).
Since the phobos logger is experimental, it's probably best to have it all behind a -version= identifier.

I'd stick all logging-calls and logging-related everything behind a version(MySQLNLog). So it's only compiled-in and used when its requested (and to prevent any future changes in the experimental API from breaking mysql-native).

And then there should be a small mysql.log module containing a public version(MySQLNLog) Logger logger; which the user can configure as they wish (it should also be compiled in when version(MySQLDocs) is defined so it's included in the generated documentation). Either default it to FileLogger(stderr) or better yet, leave it null by default (so it doesn't need a module constructor - those can be problematic...I kinda wish that module wasn't OO-based) and force the user to set it to what they want before using mysql-native.

FYI, the current travis-ci test failures appear to be unrelated to this, and no cause for concern. There's some kind of hiccup currently causing travis-ci issues with certain compiler versions.

SingingBush · 2018-05-14T09:43:15Z

I agree that the default should be not to log anything. This seems like a defect of std.experimental.logger (created issue for it), it has a nulllogger but for some reason the default is the filelogger. It should be down to users to chose which is used though. This is done via sharedLog, it should be configured by users of mysql-native.
It is configurable, users should make an implementation of Logger and assign it to sharedLog. Then any dependency that's using std.experimental.logger will output to the same Logger.
How about using a static if with a __VERSION__?

or:

static if(__traits(compiles, (){ import std.experimental.logger; })) {
	import std.experimental.logger;
}

Abscissa · 2018-05-16T03:46:36Z

I agree that the default should be not to log anything. This seems like a defect of std.experimental.logger (created issue for it), it has a nulllogger but for some reason the default is the filelogger. It should be down to users to chose which is used though. This is done via sharedLog, it should be configured by users of mysql-native.

It is configurable, users should make an implementation of Logger and assign it to sharedLog. Then any dependency that's using std.experimental.logger will output to the same Logger.

Oh, I see. This confused me until I realized sharedLog was something already-existing in std.experimental.logger.core. I didn't notice it there before. I understand now.

How about using a static if with a __VERSION__?
or: __traits(compiles,

I was thinking more of a user's-choice opt-in, regardless of version. Most importantly, so that anyone not already using std.experimental.logger doesn't get stdout/err output from mysqln without asking for it. But also just as an escape hatch in case, for example, if any API changes occur in a future logger release, or for any other unforeseeable reason.

SingingBush · 2019-10-28T07:36:14Z

Now that this has been revised and shown to pass CI can it be merged or are further changes required?

schveiguy · 2019-10-28T23:42:11Z

Does this jive with vibed's logging system?

Edit: Oh nevermind. I see you are using vibe-d to log when in vibe-d mode and std.experimental.logger in phobos mode. Nice.

schveiguy · 2019-10-28T23:45:16Z

Hm.. wait, it's not logging to vibe-d's log system in the other parts, only in socket creation. Is there a way to make this seamless?

schveiguy · 2019-10-28T23:47:15Z

source/mysql/protocol/comms.d

+static if(__traits(compiles, (){ import std.experimental.logger; } )) {
+	import std.experimental.logger;
+}
+


Something that might be useful is to make an abstracted logging facility (to define either vibe-d or std.experimental logging). Just create functions or alias the appropriate logging facility, and then your code doesn't have to have any static ifs.

Abscissa · 2019-10-31T20:15:47Z

This will definitely be a nice feature to have.

Here are the things still needed:

A. All the instances of static if(__traits(compiles, (){ import std.experimental.logger; } )) should be changed to version(MYSQLN_LOG). Since Phobos’s sharedLog defaults to a non-null logger, we need to be opt-in, not opt-out.

B. Everything should be logged to the same logger, not some things to the phobos logger and other things to vibe logger. Probably the easiest thing would be to just change that one place where it’s using the vibe logger and just change that to the phobos logger instead.

If you do want to support the vibe logger as well, then like @schveiguy suggested, there should be a single abstracted logging facility which can then be directed to either phobos logging, vibe logging or whatever else there might be. But, doing that would be a more involved change...which will involve more code review...so if you did want to do that, I’d recommend leaving it as a separate follow-up PR after this one, so we can at least get this phobos logging support up-and-running in the meantime.

C. To make sure this gets compiled-checked by CI, dub.sdl should be updated to add versions “MYSQLN_LOG” to the configurations unittest-vibe and unittest-vibe-ut (this is for the vibe socket tests). Similary, for the phobos socket tests, add -version=MYSQLN_LOG to this line. And finally, because I don’t want it to clutter the test output (just have it compile-checked), add this to source/mysql/test/common.d somewhere inside the big version(DoCoreTests) {...} section:

version(MYSQLN_LOG)
static this()
{
	import std.experimental.logger;
	// Or whatever is the correct syntax for this:
	sharedLog = nullLogger;
}

With these changes, we should be good-to-go.

Abscissa · 2019-10-31T20:22:55Z

Oh, also: Should we be prefixing something like "mysql-native: " to each of our log outputs, or does std.experimental.logger automatically prepend the module name?

schveiguy · 2019-11-01T13:19:50Z

If you do want to support the vibe logger as well

Please support vibe-d logger. I want one logging system in my vibe-d app. If this doesn't happen, I'll fix it myself ;)

Question: is it possible for std.experimental.logger to support vibe-d logging seamlessly? Might be the best option.

And I really do want to see some logging in mysql, would be super-useful.

SingingBush · 2019-11-01T22:39:06Z

You can get vibe log and std logger working together, I have both types working for me. There's no need to prefix, the output shows where the log messages come from. The reason I put a vibe log in one section was because it was vibed specific code so made sense to do so.

I'm happy to make the changes. Just not sure how soon it will be.

schveiguy · 2021-01-23T15:55:07Z

Related: #113

SingingBush · 2021-05-24T20:47:21Z

This is rebased and thanks to CI proved to not cause any issues. I appreciate there were some comments about alternative approaches but seeing as no alternatives have implemented in the last 3 years can this be merged in the meantime.

In the current form, I don't believe it will cause anyone issues and even if it did it's a small piece to revert. Having those prepared statements output in my application would have certainly helped me in the last few years. Users are already 'opting in' when they decide to configure a logger.

schveiguy · 2021-05-28T16:08:31Z

Thanks for doing the rebase. I'll wait until CI is done and then merge #220 to see if it triggers the CI automatically.

schveiguy · 2021-05-28T16:15:05Z

Ugh, I thought adding "edited" to the trigger for PRs would rerun the actions when master is merged. Is there a way to get this to rerun automatically?

schveiguy · 2021-05-28T16:23:08Z

Looks like it's not possible. That's unfortunate. So basically, GH actions are stale as soon as another PR is merged. https://github.community/t/re-build-pr-if-target-branch-is-changed/17588

schveiguy

Add vibe logging alongside std.experimental.logger. My thoughts for first release is to use vibe logging facilities by default if Have_vibe_core, and otherwise use std.experimental.logger. Configuration of which logging facility to use via a version/config in the dub.sdl is acceptable, but not necessary for this. But absolutely, if you are on vibe, you should not have to forego logging.

Open to other ideas, but if we are going to start adding logging, let's support the mechanism the user has already selected.

schveiguy · 2021-05-28T16:29:35Z

source/mysql/connection.d

+static if(__traits(compiles, (){ import std.experimental.logger; } )) {
+	import std.experimental.logger;
+}


Let's make this either a version or an enum that can be used with static if. Using __traits(compiles throughout the code shouldn't be necessary.

schveiguy · 2021-05-28T16:52:41Z

source/mysql/protocol/comms.d

@@ -525,6 +539,11 @@ package(mysql) bool execQueryImpl(Connection conn, ExecQueryImplInfo info, out u
 	{
 		conn.resetPacket();
 		auto okp = OKErrorPacket(packet);
+
+		static if(__traits(compiles, (){ import std.experimental.logger; } )) {
+			sharedLog.errorf("packet error: %s %s", okp.error, okp.message);


Shouldn't this be behind a check to make sure it's actually an error? or am I missing something.

ok will make some changes. Should have another commit soon

schveiguy · 2021-05-28T16:59:45Z

FYI, I'm seeing the trace messages in the CI logs. Why are those being triggered? I don't want people who have standard debug flags to see all the trace data.

schveiguy · 2021-05-28T17:09:22Z

By default, the logger will log ALL messages. This is unacceptable for mysql-native to use. Everyone who uses mysql-native will all of a sudden see mountains of trace messages appear.

This is unfortunately a design issue IMO of std.experimental.logger and not anything you can do here, but nevertheless, we can't accept this without a version switch.

SingingBush · 2021-05-28T17:36:41Z

By default, the logger will log ALL messages. This is unacceptable for mysql-native to use. Everyone who uses mysql-native will all of a sudden see mountains of trace messages appear.

This is unfortunately a design issue IMO of std.experimental.logger and not anything you can do here, but nevertheless, we can't accept this without a version switch.

Are you seeing that because running tests will set it into trace level? I use std.experimental.logger and certainly don't get all levels of logging being output.

schveiguy · 2021-05-28T17:38:24Z

No, I'm saying that if you NEVER do anything to use std.experimental.logger, but used mysql-native with this PR, you will get tracing data on stderr.

See my latest post to the NG: https://forum.dlang.org/post/s8r9ac$hlt$1@digitalmars.com

schveiguy · 2021-05-28T17:42:29Z

Another option is not to use sharedLog, but use a library-specific logger instance (which of course, could be set to the same as sharedLog).

schveiguy · 2021-05-29T01:45:36Z

I'll do a release now, without this PR yet, just to get people up and running.

If the phobos logger library doesn't get fixed, maybe you can set up an alternate configuration with a veresioned-in logging facility.

SingingBush · 2021-05-29T12:16:48Z

I've made changes which I'm pretty happy with and in the end, was actually pretty simple. Not only does this work with both types of loggers but it also retains the module/file/line number that the message came from (which was the main challenge). Basically with this PR, if you want to log something import mysql.logger and use one of:

logTrace
logDebug
logInfo
logWarn
logError
logCritical

which are aliases for the underlying logger. There is of course the issue that std.experimental.logger is by default set to LogLevel.all (https://forum.dlang.org/post/s8r9ac$hlt$1@digitalmars.com) but I think that should be solved in phobos and it's also easy for users to set sharedLog = new NullLogger() if really needed. Also at the minute we're not logging much and I suspect most people are using vibe-core, so will not even be affected.

schveiguy · 2021-05-31T18:06:02Z

I like the way this has changed, this looks much better!

For sure, we can't merge this unless either Phobos is changed or we have this hidden behind a version, or possibly we don't use the shared logger, and allow one to set the logger away from a default Null logger.

One thing I noticed is that you have a third case where neither Have_vibe_core, nor std.experimental.logger is available, in which case no aliases are defined. I don't think we even need to support this case since we cut off the compiler support to last 10 releases, so most likely you can just say:

version(Have_vibe_core) {
    /* vibe stuff */
}  else {
    /* std.experimental.logger stuff */
}

SingingBush · 2021-06-01T09:23:00Z

I like the way this has changed, this looks much better!

For sure, we can't merge this unless either Phobos is changed or we have this hidden behind a version, or possibly we don't use the shared logger, and allow one to set the logger away from a default Null logger.

One thing I noticed is that you have a third case where neither Have_vibe_core, nor std.experimental.logger is available, in which case no aliases are defined. I don't think we even need to support this case since we cut off the compiler support to last 10 releases, so most likely you can just say:
version(Have_vibe_core) {
    /* vibe stuff */
}  else {
    /* std.experimental.logger stuff */
}

I thought about that but sooner or later std.expirmental.logger will move. When it does it's be nice for it not to break. Hopefully some changes get made before it becomes std.logger

schveiguy · 2021-06-01T14:59:19Z

When it does it's be nice for it not to break.

You misunderstand.

If they are not using vibe, and std.experimental.logger doesn't exist, then no aliases are defined for the functions. And therefore, when you call the aliases, it will not compile.

But in any case, I'm OK with it breaking, I'd rather know about it loudly! And given that I want to have the library built using the dlang projects buildkite tester, any changes to std.experimental.logger should cause build errors to happen.

schveiguy · 2022-01-07T16:39:04Z

The issue with std.experimental.logger has been resolved, but not released yet. When that happens, I would like to incorporate this. See dlang/phobos#8336

I want to start working again on getting my safe patch in. If you want this to go in first, let me know.

SingingBush · 2022-01-12T21:15:06Z

I'd like to get it merged. Not sure how soon I can pick it up though. Perhaps over the weekend. Give me a few days but if I don't get changes in by next week feel free to go first.

update: couldn't sleep so rebased and took a look at changes. looks like all required changes were already made so please go ahead and merge

schveiguy

You can leave the vibe logging alone, I'll have to look into how the equivalent test harness can be done, but just add that static assert, and I'm good to merge.

schveiguy · 2022-01-13T14:09:30Z

source/mysql/logger.d

+		logWarn("Test that a call to mysql.logger.logWarn maps to vibe.core.log.logWarn");
+		logError("Test that a call to mysql.logger.logError maps to vibe.core.log.logError");
+		logCritical("Test that a call to mysql.logger.logCritical maps to vibe.core.log.logCritical");
+		//logFatal("Test that a call to mysql.logger.logFatal maps to vibe.core.log.logFatal");


I can imagine that vibe logger also has customizable logging?

source/mysql/logger.d

source/mysql/protocol/comms.d

schveiguy · 2022-01-13T14:42:28Z

source/mysql/connection.d

@@ -387,6 +388,7 @@ package:

 	static PlainPhobosSocket defaultOpenSocketPhobos(string host, ushort port)
 	{
+		logDebug("opening phobos socket %s:%d", host, port);


For some reason this is using std.experimental.logger even when vibe is used: https://github.com/mysql-d/mysql-native/runs/4796611671?check_suite_focus=true#step:6:991

I'm trying to think of a reason, is the build for one unittest file being done without vibe?

it probably is that. It's within the function for opening a socket with phobos which should only be done when vibe-d is not present. the route to opening a socket using the alternative vibe based function requires having gone through a version(Have_vibe_core) check on the constructor.

But isn't the vibe test compiled with vibe? How is it that part of the code is built with the vibe version, but part is not? Indeed, most of the logging is vibe, just a few parts aren't, and I'm not sure why.

Phobos sockets can still be used even if you are linking in vibe-core. It's a parameter to the constructor. I would still expect vibe logging if I am using vibe.

Now, technically, I'd like to see the log type be configurable. And really, as said above, it would be best if we used one logging facility and it wrapped the other. But at this point, I just want it to be consistent.

If the solution isn't immediately obvious, then we can just merge this, and I can take a deeper look later. This is after all an issue with unittests, run in the integration subproject, which may not affect the main library.

FYI, I found out why this is happening. One of the integration tests builds the example project, which doesn't use vibe. All the output from running dub is suppressed, which is why it just inexplicably shows up.

See the test here despite what the comment says, it's not using vibe. I'm unsure why we run it this way, I might switch to using github actions to run it.

schveiguy · 2022-01-14T03:18:39Z

tag will have to wait until Phobos fix is released.

Abscissa reviewed May 14, 2018

View reviewed changes

SingingBush force-pushed the feature/logging branch from 8ee94fd to 9184e6d Compare October 5, 2019 08:08

SingingBush force-pushed the feature/logging branch from 9184e6d to c533379 Compare October 28, 2019 01:19

schveiguy reviewed Oct 28, 2019

View reviewed changes

SingingBush force-pushed the feature/logging branch from c533379 to 103576e Compare May 24, 2021 20:30

SingingBush mentioned this pull request May 28, 2021

Split testing into its own project #235

Merged

SingingBush force-pushed the feature/logging branch from 103576e to 8cc782d Compare May 28, 2021 15:59

schveiguy closed this May 28, 2021

schveiguy reopened this May 28, 2021

schveiguy requested changes May 28, 2021

View reviewed changes

schveiguy reviewed May 28, 2021

View reviewed changes

SingingBush force-pushed the feature/logging branch from 8cc782d to 00bb588 Compare May 29, 2021 12:08

SingingBush requested a review from schveiguy May 29, 2021 12:17

\mysql-d#113 Allow logging via vibe-core or std.experimental.logger

def835e

SingingBush force-pushed the feature/logging branch from 00bb588 to def835e Compare January 12, 2022 23:17

schveiguy requested changes Jan 13, 2022

View reviewed changes

schveiguy reviewed Jan 13, 2022

View reviewed changes

source/mysql/protocol/comms.d Outdated Show resolved Hide resolved

schveiguy reviewed Jan 13, 2022

View reviewed changes

mysql-d#113 making requested changes

111770e

schveiguy approved these changes Jan 14, 2022

View reviewed changes

schveiguy merged commit 5ceed3c into mysql-d:master Jan 14, 2022

schveiguy mentioned this pull request Jan 14, 2022

use vibe.core.log when Have_vibe_d_core #113

Closed

SingingBush deleted the feature/logging branch April 21, 2022 14:47

#113 use std.experimental.logger #187

#113 use std.experimental.logger #187

Uh oh!

Conversation

SingingBush commented May 13, 2018

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Abscissa commented May 14, 2018

Uh oh!

SingingBush commented May 14, 2018 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

Abscissa commented May 16, 2018

Uh oh!

SingingBush commented Oct 28, 2019

Uh oh!

schveiguy commented Oct 28, 2019 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

schveiguy commented Oct 28, 2019

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Abscissa commented Oct 31, 2019

Uh oh!

Abscissa commented Oct 31, 2019

Uh oh!

schveiguy commented Nov 1, 2019

Uh oh!

SingingBush commented Nov 1, 2019

Uh oh!

schveiguy commented Jan 23, 2021

Uh oh!

SingingBush commented May 24, 2021

Uh oh!

schveiguy commented May 28, 2021

Uh oh!

schveiguy commented May 28, 2021

Uh oh!

schveiguy commented May 28, 2021

Uh oh!

schveiguy left a comment

Choose a reason for hiding this comment

Uh oh!

schveiguy May 28, 2021 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

schveiguy commented May 28, 2021

Uh oh!

schveiguy commented May 28, 2021

Uh oh!

SingingBush commented May 28, 2021

Uh oh!

schveiguy commented May 28, 2021

Uh oh!

schveiguy commented May 28, 2021

Uh oh!

schveiguy commented May 29, 2021

Uh oh!

SingingBush commented May 29, 2021

Uh oh!

schveiguy commented May 31, 2021

Uh oh!

SingingBush commented Jun 1, 2021

Uh oh!

schveiguy commented Jun 1, 2021

Uh oh!

schveiguy commented Jan 7, 2022

Uh oh!

SingingBush commented Jan 12, 2022 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

SingingBush commented May 14, 2018 •

edited

Loading

schveiguy commented Oct 28, 2019 •

edited

Loading

schveiguy May 28, 2021 •

edited

Loading

SingingBush commented Jan 12, 2022 •

edited

Loading

schveiguy commented Jan 14, 2022 •

edited

Loading