feat: db connection analytics

[eschutho]

SUMMARY

adds analytics logs to the db connection success/failures

TEST PLAN

unit tests

ADDITIONAL INFORMATION

• Has associated issue:
• Changes UI
• Requires DB Migration.
• Confirm DB Migration upgrade and downgrade tested.
• Introduces new feature or API
• Removes existing feature or API

[eschutho]

engine wasn't defined if database was None, so I put it under this block.

[codecov]

Codecov Report

❗ No coverage uploaded for pull request base (db-connection-logs@d323eb1). Click here to learn what that means.
The diff coverage is n/a.

@@                  Coverage Diff                  @@
##             db-connection-logs   #13346   +/-   ##
=====================================================
  Coverage                      ?   54.61%           
=====================================================
  Files                         ?      478           
  Lines                         ?    15982           
  Branches                      ?     4123           
=====================================================
  Hits                          ?     8729           
  Misses                        ?     7253           
  Partials                      ?        0           

Flag	Coverage Δ
cypress	54.61% <0.00%> (?)

Flags with carried forward coverage won't be shown. Click here to find out more.

---

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 d323eb1...0ceb8f7. Read the comment docs.

[betodealmeida]

LGTM, my only concern is that in theory we might fail to rollback a transaction. I also left a comment on using log instead of log_context.

[betodealmeida]

This worries me a bit — if there's an error in the context manager we won't rollback the transaction.

I think it would be better to just log, instead of using a context manager:

try:
    event_logger.log(action=f"db_connection_failed.{database.db_engine_spec.__name__}")
finally:
    db.session.rollback()

To ensure that rollback is always called.

[mistercrunch]

Maybe log should be pessimistic / guaranteed to never raise(?) so that we don't have to use caution every time we call it? That would mean wrapping the content of log in a try ?

[eschutho]

@betodealmeida and I were talking about this earlier, and most statements before the yield are pretty safe, but to be sure, I moved what I could below the yield statement. I don't think there's much risk of this failing now:

 start_time = time.time()
 payload_override = {}

[eschutho]

lmk if you think this works as a solution @betodealmeida @mistercrunch

[betodealmeida]

We might want to just use log in places like this. The main difference between log and log_context is that the former, in addition to being a context manager, logs the duration automatically, together with some dashboard/chart metadata that is irrelevant here.

[eschutho]

true... it also logs the user_id and referrer, so maybe it's still useful?

[mistercrunch]

We may want to either 1) refactor log to do some of the magic in log_context maybe add a bool flag enrich_with_request_context=False, or 2) can we just call the context manager with the with block? Would that just work? or 3) refactor log_context to NOT be be context manager and create a new one say log_context_manager (or better name) that's used only when we want duration / with block

[betodealmeida]

One problem is that adding the flag enrich_with_request_context would be a breaking change (our event logger, for example, would have to be updated).

I think the best way here is:

1. Create a new method in AbstractEventLogger called log_with_context, that does all the job that log_context does but is a function, not a context manager. The method calls log at the end, with all the extracted context.
2. Change AbstractEventLogger.log_context to use log_with_context for the enrichment, removing the shared code between them.
3. In this PR, call the new log_with_context. Since it delegates the actual logging to log it will work with all existing event loggers, and is not a breaking change..

Eventually I think we should have the event logger itself be a context manager by implementing __enter__ and __exit__ methods, so we could call:

with event_logger(action="foo"):
   do_something()

Since we can do this by adding methods to AbstractEventLogger it would also not be a breaking change.

[mistercrunch]

Quick clarification that enrich_with_request_context would be false by default to protect backwards compatibity. But maybe function composition is better than a parameter here, I'm ok with with either pattern.

There's a need to really clarify/improve the method in AbstractEventLogger with good/clear names here between functions we can call, content manager(s) and decorator(s)

[eschutho]

since we're merging this branch into @hughhhh's feature branch rather than master, @betodealmeida said that he could do the log_context refactor in a separate PR.

[betodealmeida]

I'm working on the refactor right now.

@mistercrunch you're right, I forgot that log takes a **kwargs that would swallow the new argument.

[mistercrunch]

I feel like we may want to add engine as it's own dimension as opposed to overloading the action type with it.

Eventually I'd like to add the engine to all analytics events that interact with analytics databases like viewing a chart, running a SQL Lab query, .

I think you can just pass as a keyword as in event_logger.log_context('test_connection_success', engine=engine)

I made a related comment here: #13223 (comment)

[eschutho]

@mistercrunch I added in the engine here as a kwarg. Also, just as an FYI, the strings that we're passing in these two files aren't exactly 1:1. Here we have to use the engine spec name, and in the test_connection file we pass the engine+driver combo. But the information is essentially the same.. any downstream integrations can still see the engine from the string that is passed in.

[eschutho]

rerun tests

[eschutho]

@hughhhh I saw this earlier today, that we're currently logging the entire exception. Can we change this on line 71 and 72 to log just the class? I originally thought since we were already logging it, it would be fine to pass to the event logger, but I think we should actually clean this up as well.

[eschutho]

@hughhhh is taking this effort over in https://github.com/apache/superset/pull/13468/files