Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

improve logging configuration and usage #4

Merged
merged 12 commits into from
Apr 24, 2018
Merged

improve logging configuration and usage #4

merged 12 commits into from
Apr 24, 2018

Conversation

bpintea
Copy link
Collaborator

@bpintea bpintea commented Apr 20, 2018

The logging of functions call and their actions is used mostly for troubleshooting the driver, but can be useful for a potential application developer as well.
Logging configuration would ideally go into the connection string, but this has some drawbacks:

  • the DM can invoke a set of driver functions prior to the one that passes to the driver the connection string; so all these calls would be either lost (i.e. not 'loggable') or logged incorrectly into some defaults.
  • each connection having its own logging file would make some sense, but managing all the logging files and tracing these from a given descriptor all the way up the connection, to get the log handle, would complicate a bit the logic and make the logging action a bit more expensive.

Taking into account these considerations, I've decided to have a log handle per process only, used by all the threads within it. To help with potential verbosity, I've added "handle logging" macros, that are to be used wherever an API handle is available in the scope. This way one can track easier in the log files the tree (environment -> connection[s] -> statement[s] -> descriptor[s] -> record[s]), where necessary.

Logging is disabled by default. To enable it, one needs to set an environment variable; a logging level can also be specified (ESODBC_LOG_DIR=C:\Users\myuser\mydirectory?warning). The alternative could be a registry entry, though this wouldn't be very portable.

bpintea added 9 commits April 18, 2018 18:17
Consider current position in current buffer when calculating the size
for a new buffer to realloc, to copy the received reply in.
- removing ' $'
- aligning to 80 columns
Change the struct's name to keep consistent with the rest of
structures naming, for those structures visible through the API.
- The config file is now created if an environment variable,
ESODBC_LOG_DIR is present and pointing to a valid path. The driver will
then create one log file per process that attaches to it.
- Logging withing a process is serialized now.

Above changes are needed since connections strings (the other
configuration place alternative) are fed "late" to the driver - the DM
will typically call a few of driver's functions before actually forwarding
the connection call - and these functions would either not be logged, or
logged in a non-configurable way (directory / level).

- Added primitives for handle logging. i.e. ERRH(my_dbc_handle, ...) will log
a message like "[ERROR] [DBC@0xdeadbeef] some message".
- Use the *H(handle, ...) logging macros wherever a handle is available
  in the scope. This will give more context and easier tracking for the
  API objects throught the driver.
- replace `RET_STATE(SQL_STATE_00000)` with simple `return SQL_SUCCESS`,
  this was an unnecessary complication (and extra useless logging msg).
- a temporary directory is now set from existing environment variables,
  to usual defaults, if no env vars are set.
- logging dir is also now read from ESODBC_LOG_DIR env var, if this is
  set; no default for this is assumed anymore.
removed final string quote instead of space after it.
in case original string wasn't 0-terminated, the position of the 0-term
in the converted string was wrong (one charater too short)
@bpintea bpintea requested review from droberts195 and edsavage April 20, 2018 15:57
@bpintea bpintea mentioned this pull request Apr 20, 2018
Closed
Copy link
Collaborator

@edsavage edsavage left a comment

Choose a reason for hiding this comment

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

LGTM

format, iter->kw, LWSTR(iter->val));
if (n < 0) {
ERRN("failed to outprint connection string (space left:"
" %d; needed: %d).", cchConnStrOutMax - pos,
ERRN("failed to outprint connection string (space "
Copy link
Collaborator

Choose a reason for hiding this comment

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

Should this one be ERRNH?

Copy link
Collaborator Author

Choose a reason for hiding this comment

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

I don't have any handler in this function. I could pass one (a DB connection handler is available in calling function), but it'd be just for logging this one error message.
OTOH, if the function fails, the calling function will use a ERRH to log the failure.

@@ -130,11 +130,12 @@ static SQLSMALLINT type_elastic2csql(const SQLWCHAR *type_name, size_t len)
return SQL_C_SSHORT;
break;
}
ERR("unrecognized Elastic type `" LWPDL "` (%zd).", len, type_name, len);
ERR("unrecognized Elastic type `" LWPDL "` (%zd).", len, type_name,
Copy link
Collaborator

Choose a reason for hiding this comment

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

ERRH?

Copy link
Collaborator Author

Choose a reason for hiding this comment

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

Same as above, not having a handler available within the scope of this function, could add it, but as a small utility function, its failure would be logged by calling function with an ERRH.

driver/log.c Outdated
/* log file path -- process variable */
static TCHAR *log_path = NULL;
/* log file mutex -- process variable */
static HANDLE log_mux = NULL;
Copy link
Contributor

Choose a reason for hiding this comment

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

If you want the simplest, most lightweight, non-recursive mutex then for Windows the best choice is SRWLOCK, always locked for writing. For an example of how to use a slim read/write lock in this way, see https://github.com/elastic/ml-cpp/blob/master/include/core/CFastMutex.h and https://github.com/elastic/ml-cpp/blob/master/lib/core/CFastMutex_Windows.cc

Another advantage of SRWLOCK is that you don't need to make a call to destroy it when you're finished with it, so there's no danger of leaking any resource if the driver is repeatedly loaded and unloaded within an application for some reason.

If you need a recursive mutex but with scope of a single process then use a CRITICAL_SECTION. But if you don't need it to be recursive it definitely is quite a bit slower than SRWLOCK - see here for some timings: https://web.archive.org/web/20160326022611/http://info.prelert.com:80/blog/locking

It's best to only use the thing Windows calls a "mutex" if you need to share it between processes. Because these objects are linked to kernel handles and can be used across processes there's a huge overhead to using them. (I didn't even bother including those in the blog post because the performance is so awful.)

Copy link
Collaborator Author

Choose a reason for hiding this comment

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

Great stuff, thanks for the links!
I've pushed the change to SRWLOCK.

bpintea added 2 commits April 24, 2018 01:03
- removed logging calls that could happen after log cleanup;
- make sure log closing is the last thing done on process detach.
Copy link
Contributor

@droberts195 droberts195 left a comment

Choose a reason for hiding this comment

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

LGTM

@bpintea bpintea merged commit 881f900 into elastic:master Apr 24, 2018
@bpintea bpintea deleted the feature/handle_logging branch April 24, 2018 14:27
bpintea added a commit that referenced this pull request Jun 4, 2018
improve logging configuration and usage
@bpintea bpintea added >feature Applicable to PRs adding new functionality v6.5.0 labels May 3, 2019
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
>feature Applicable to PRs adding new functionality v6.5.0
Projects
None yet
Development

Successfully merging this pull request may close these issues.

3 participants