MINIFICPP-365 Adjusting log levels. by apiri · Pull Request #244 · apache/nifi-minifi-cpp

apiri · 2018-01-17T22:04:46Z

current status of working to remove extraneous log statements.

for some of the typical flows I use for testing this amounts to almost no information being provided. going to look through the various components a bit more to see if statements should be added

phrocker · 2018-01-17T22:08:42Z

libminifi/src/sitetosite/SiteToSiteClient.cpp

  }

  if (transaction->getState() != TRANSACTION_STARTED && transaction->getState() != DATA_EXCHANGED) {
-    logger_->log_debug("Site2Site transaction %s is not at started or exchanged state", transactionID.c_str());


we should also make it a point to change these from transactionID.c_str() to tranactionID

phrocker · 2018-01-17T22:09:09Z

main/MiNiFiMain.cpp


  if (signal(SIGINT, sigHandler) == SIG_ERR || signal(SIGTERM, sigHandler) == SIG_ERR || signal(SIGPIPE, SIG_IGN) == SIG_ERR) {
-    logger->log_error("Can not install signal handler");
+    logger->log_error("Cannot install signal handler");


We shouldn't be using the logger here. Can we change this to stderr?

phrocker · 2018-01-17T22:10:51Z

libminifi/src/sitetosite/RawSocketProtocol.cpp


  if (establish() && handShake() && negotiateCodec()) {
-    logger_->log_info("Site2Site Ready For data transaction");
+    logger_->log_trace("Site2Site Ready For data transaction");


If you were to set the log level to debug one might expect there to be something here, as you would need to select trace and inevitably trace the entire flow of execution vice getting debug information.

phrocker · 2018-01-17T22:12:43Z

libminifi/src/sitetosite/RawSocketProtocol.cpp

  int ret = peer_->writeUTF(getResourceName());

-  logger_->log_info("result of writing resource name is %i", ret);
+  logger_->log_debug("result of writing resource name is %i", ret);


^ this honestly seems like it would be a trace level to help trace the level of execution through the stream writes.

phrocker · 2018-01-17T22:14:43Z

libminifi/src/core/ProcessSessionReadCallback.cpp

 bool ProcessSessionReadCallback::commit() {
  bool success = false;

-  logger_->log_info("committing export operation to %s", _destFile.c_str());


ditto on the c_str(). It adds overhead and is vestigial.

phrocker · 2018-01-17T22:16:46Z

libminifi/src/core/ProcessSession.cpp


  if (commit_ok) {
-    logger_->log_info("Commit OK.");
+    logger_->log_debug("Commit OK.");


I'm on the fence about this one. I usually use the mantra as INFO provides informational statements for support staff, debug and trace used by developers for varying levels. In this case I could see a support staff asking, "Commit OK." Is there an analog to this statement to provide this information? A totally quiet client at info makes it unusable and more importantly unsupportable by multiple levels of support.

phrocker · 2018-01-17T22:18:21Z

libminifi/src/controllers/SSLContextService.cpp

        logger_->log_debug("%s now good", certificate);
      } else {
-        logger_->log_debug("%s still not good", test_cert);
+        logger_->log_warn("%s still not good", test_cert);


good catch!

phrocker · 2018-01-17T22:18:42Z

libminifi/src/capi/Plan.cpp

 bool ExecutionPlan::setProperty(const std::shared_ptr<core::Processor> proc, const std::string &prop, const std::string &value) {
  uint32_t i = 0;
-  logger_->log_info("Attempting to set property %s %s for %s", prop, value, proc->getName());
+  logger_->log_debug("Attempting to set property %s %s for %s", prop, value, proc->getName());


oh man this is definitely me! I copied and pasted a lot of these. Thanks for catching this!

phrocker · 2018-01-17T22:18:52Z

libminifi/src/ThreadedSchedulingAgent.cpp

+  logger_->log_debug("Shutting down threads for processor %s/%s", processor->getName().c_str(), processor->getUUIDStr().c_str());

  if (processor->getScheduledState() != core::RUNNING) {
-    logger_->log_info("Cannot unschedule threads for processor %s because it is not running", processor->getName().c_str());


Much prefer this!

phrocker · 2018-01-17T22:19:48Z

libminifi/src/SchedulingAgent.cpp

 }

 std::future<bool> SchedulingAgent::enableControllerService(std::shared_ptr<core::controller::ControllerServiceNode> &serviceNode) {
-  logger_->log_info("Enabling CSN in SchedulingAgent %s", serviceNode->getName());


As per my comment below I think these are candidates for INFO based on the belief that support any type of teir 1 support might need this information.

phrocker · 2018-01-17T22:20:59Z

libminifi/src/RemoteProcessorGroupPort.cpp

    protocol_ = getNextProtocol();

    if (!protocol_) {
-      logger_->log_info("no protocol, yielding");


This one should likely be debug otherwise we'd need to get to trace to support this. The one above is definitely a trace.

phrocker · 2018-01-17T22:21:46Z

libminifi/src/FlowControlProtocol.cpp

    return;
  running_ = false;
-  logger_->log_info("FlowControl Protocol Stop");
+  logger_->log_trace("FlowControl Protocol Stop");


I believe these messages provide critical information to tier1 support.

phrocker · 2018-01-17T22:22:14Z

libminifi/include/core/controller/StandardControllerServiceProvider.h

    for (auto service : controller_map_->getAllControllerServices()) {

      if (service->canEnable()) {
-        logger_->log_info("Enabling %s", service->getName());


Ditto on the comments about enabling/starting something be critical for tier 1 to support.

phrocker · 2018-01-17T22:22:59Z

extensions/http-curl/sitetosite/HTTPProtocol.cpp

  }

  std::string append_str;
-  logger_->log_info("Site2Site close transaction %s", transaction->getUUIDStr().c_str());


I think this is truly informative for teir 1 support.

phrocker

oops won't let me remove the prior review state...

phrocker

I think in general INFO should be a log statement that's truly helpful for a tier 1 support staff to either triage OR give as a clue to higher levels of support that can direct the need for debug/trace. I like this PR; however, I'm worried that we're losing some information while definitely cleaning up other portions. I'm a +1 just on the idea of cleaning up, but when running this I get very little information. The argument that we can 'then turn up the logging' begs the question why use INFO at all vice just turning it off?

Approving because I think the net benefit of this > the potential negatives at this time. sorry for the confusion!

apiri · 2018-01-18T21:08:56Z

@phrocker I agree. I'm going to take a second pass over this and with your feedback try to get a bit more info ready. will push out another commit

apiri · 2018-01-19T20:33:47Z

@phrocker I incorporated your feedback, added logs to session transfers/penalization and adjusted the logs for RPG send/receive. I think it strikes a decent balance of showing that work is going on with pertinent details. Let me know your thoughts.

phrocker

LGTM. Definitely clears up some tech debt. this is good!

Cleaning up c_str calls, adding logging for session events and adjusting Site to Site logs.

phrocker reviewed Jan 17, 2018

View reviewed changes

phrocker requested changes Jan 17, 2018

View reviewed changes

phrocker approved these changes Jan 17, 2018

View reviewed changes

apiri force-pushed the minificpp-365 branch 2 times, most recently from be7068f to 86c5244 Compare January 19, 2018 20:32

phrocker approved these changes Jan 19, 2018

View reviewed changes

MINIFICPP-365 Adjusting log levels.

233d1d4

Cleaning up c_str calls, adding logging for session events and adjusting Site to Site logs.

apiri force-pushed the minificpp-365 branch from 86c5244 to 233d1d4 Compare January 20, 2018 04:39

asfgit merged commit 233d1d4 into apache:master Jan 20, 2018

Conversation

apiri commented Jan 17, 2018

Uh oh!

Choose a reason for hiding this comment

Uh oh!

phrocker Jan 17, 2018 • 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!

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!

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!

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!

Choose a reason for hiding this comment

Uh oh!

phrocker left a comment • 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!

phrocker left a comment • 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!

apiri commented Jan 18, 2018

Uh oh!

apiri commented Jan 19, 2018

Uh oh!

phrocker left a comment

Choose a reason for hiding this comment

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

3 participants

phrocker Jan 17, 2018 •

edited

Loading

phrocker left a comment •

edited

Loading

phrocker left a comment •

edited

Loading