STORM-3133: Extend metrics on Nimbus and LogViewer #2754

zd-project · 2018-07-05T21:31:32Z

This PR is based on #2743, #2771 , #2787 , and #2788 and implements the following metrics:

LogViewer:

Nimbus:

File upload time.
Nimbus launch/relaunch count
Nimbus loss of leadership
- meter marking when a nimbus node gains or loses leadership
Scheduling latency (both distribution (as histogram) and maximum (as gauge, including current scheduling iteration))
Scheduling throughput

zd-project · 2018-07-05T21:59:07Z

One thing that is worthy of noticing: Storm UI currently interweaves different search API regarding searching functionalities and it's kind of confusing.

Specifically:

For the search button at homepage, it uses a single deep search API to search all ports (server side process), both archived and non-archived.
For non-archived search at a specific topology page, it invokes search API on each port inside a loop (client side process).
For archived search at a specific topology page, it invokes deep search API (search-archived=on) on each port inside a loop (client side process)

As a result, metrics for these APIs may not accurately reflect how many searches are invoked from client's perspective.

zd-project · 2018-08-03T21:23:30Z

The metrics of IO exceptions on logviewer is kind of fuzzy as I go through the call stack manually and eyeballed all thrown exceptions. I'm not sure if it's complete or if it will over-count. It'd be great if you can help review it especially.

Ethanlm

The code changes look very good. Left some comments. Mostly nits

Ethanlm · 2018-08-07T20:39:33Z

storm-server/src/main/java/org/apache/storm/daemon/supervisor/timer/ReportWorkerHeartbeats.java

@@ -51,6 +51,7 @@ public void run() {
    private SupervisorWorkerHeartbeats getAndResetWorkerHeartbeats() {
        Map<String, LSWorkerHeartbeat> localHeartbeats;
        try {
+            //TODO: This call no longer throws exceptions, do we still want to wrap it in try catch block?


remove comment

Ethanlm · 2018-08-07T20:40:39Z

storm-server/src/main/java/org/apache/storm/metric/StormMetricsRegistry.java

@@ -48,6 +53,30 @@ public static Meter registerMeter(String name) {
        return REGISTRY.register(name, new Meter());
    }

+    //Change the name to avoid name conflict in future Metrics release


change the name?

Ethanlm · 2018-08-07T21:38:59Z

...-webapp/src/main/java/org/apache/storm/daemon/logviewer/handler/LogviewerLogPageHandler.java

+                //This is the same as what #pageFile(String path, Integer tail) does
+                // boolean isZipFile = path.endsWith(".gz");
+                // long fileLength = isZipFile ? ServerUtils.zipFileSize(new File(path)) : new File(path).length();
+                // return pageFile(path, Long.valueOf(fileLength - tail).intValue(), tail);


remove comments

Ethanlm · 2018-08-08T16:36:30Z

...-webapp/src/main/java/org/apache/storm/daemon/logviewer/handler/LogviewerLogPageHandler.java

-            } else {
-                logString = escapeHtml("This is a binary file and cannot display! You may download the full file.");
+            final boolean isZipFile = path.endsWith(".gz");
+            long fileLength = isZipFile ? ServerUtils.zipFileSize(file) : file.length();


why not reuse getFileLength

Ethanlm · 2018-08-08T18:33:38Z

...ebapp/src/main/java/org/apache/storm/daemon/logviewer/handler/LogviewerLogSearchHandler.java

@@ -71,6 +78,11 @@

 public class LogviewerLogSearchHandler {
    private static final Logger LOG = LoggerFactory.getLogger(LogviewerLogSearchHandler.class);
+    private static final Meter numDeepSearchNoResult = StormMetricsRegistry.registerMeter("logviewer:num-deep-search-no-result");
+    private static final Histogram numFilesOpenedDeepSearch = StormMetricsRegistry.registerHistogram(
+            "logviewer:num-files-opened-deep-search", new ExponentiallyDecayingReservoir());


opened--> scanned? more clear

Ethanlm · 2018-08-08T20:09:51Z

storm-server/src/main/java/org/apache/storm/daemon/nimbus/Nimbus.java

                }
            }
+            LOG.info("{} assignments unchanged: {}", difference.entriesInCommon().size(), difference.entriesInCommon().keySet());


better to put to LOG.debug().

Ethanlm · 2018-08-08T20:14:04Z

storm-server/src/main/java/org/apache/storm/daemon/nimbus/Nimbus.java

+        numAddedSlotPerScheduling.update(numAddedSlot);
+        numRemovedExecPerScheduling.update(numRemovedExec);
+        numRemovedSlotPerScheduling.update(numRemovedSlot);
+        numNetExecChangePerScheduling.update(numAddedExec - numRemovedExec);


better to use numNetAddedExecPerScheduling and numNetAddedSlotPerScheduling

Ethanlm · 2018-08-08T20:27:23Z

storm-server/src/main/java/org/apache/storm/daemon/nimbus/Nimbus.java

-        long scheduleTimeElapsedMs = System.currentTimeMillis() - beforeSchedule;
-        LOG.debug("Scheduling took {} ms for {} topologies", scheduleTimeElapsedMs, topologies.getTopologies().size());
-        scheduleTopologyTimeMs.update(scheduleTimeElapsedMs);
+        //Will compiler optimize the order of evalutation and cause race condition?


remove comment

See #2764 (comment)

Ethanlm · 2018-08-08T20:27:44Z

storm-server/src/main/java/org/apache/storm/daemon/nimbus/Nimbus.java

                idToResources.set(new HashMap<>());
                idToWorkerResources.set(new HashMap<>());
            }

            //tasks figure out what tasks to talk to by looking at topology at runtime
            // only log/set when there's been a change to the assignment
+            // TODO: why do we have loop fission here


remove comment

Ethanlm · 2018-08-08T20:37:00Z

...ebapp/src/main/java/org/apache/storm/daemon/logviewer/handler/LogviewerLogSearchHandler.java

+        //fileOffset is not being used and it behaves inconsistently (showing
+        // (index of files search ends on - 1) if [enough matches] else (index of files search ends on))
+        // I don't think we should expose the data to public if it's not used.
+        // can I dropped this field or change its behavior so it's used for metrics [numScannedFiles]?


You can file a separate jira for this

See https://issues.apache.org/jira/browse/STORM-3189

zd-project · 2018-08-09T20:20:00Z

Some important changes have been made to address nits you guys have, especially on metrics for scheduler. @srdo @Ethanlm

Ethanlm · 2018-08-09T20:23:45Z

storm-server/src/main/java/org/apache/storm/daemon/nimbus/Nimbus.java

-    private static final Histogram numNetExecChangePerScheduling = StormMetricsRegistry.registerHistogram("nimbus:num-net-executors-changed-per-scheduling", new ExponentiallyDecayingReservoir());
-    private static final Histogram numNetSlotChangePerScheduling = StormMetricsRegistry.registerHistogram("nimbus:num-net-slots-changed-per-scheduling", new ExponentiallyDecayingReservoir());
+    private static final Histogram numNetExecIncreasePerScheduling = StormMetricsRegistry.registerHistogram("nimbus:num-net-executors-changed-per-scheduling", new ExponentiallyDecayingReservoir());
+    private static final Histogram numNetSlotIncreasePerScheduling = StormMetricsRegistry.registerHistogram("nimbus:num-net-slots-changed-per-scheduling", new ExponentiallyDecayingReservoir());


better to change nimbus:num-net-slots-changed-per-scheduling too

Ethanlm · 2018-08-09T20:25:07Z

storm-server/src/main/java/org/apache/storm/daemon/nimbus/Nimbus.java

+                                    () -> {
+                                        try {
+                                            if (isLeader()) {
+                                                sendClusterMetricsToExecutors();


looks like a typo here?

sorry a mistake

srdo

Finished reviewing, left some comments.

srdo · 2018-08-09T19:08:58Z

storm-server/src/test/java/org/apache/storm/metric/StormMetricsRegistryTest.java

+    void registerMetricSet() {
+        Meter existingInnerMeter = StormMetricsRegistry.registerMeter(name(INNER_SET, INNER_METER));
+
+        System.out.println("register outer set");


Please use a Logger instead, I think System.out ends up in the console, whereas all the other logs go to files when we run tests.

srdo · 2018-08-09T19:14:39Z

storm-webapp/src/main/java/org/apache/storm/daemon/logviewer/LogviewerServer.java

@@ -52,7 +55,7 @@
 /**
 * The main entry of Logviewer.
 */
-public class LogviewerServer implements AutoCloseable {
+public class LogviewerServer implements AutoCloseable, MetricSet {


This seems like an odd choice. Why doesn't ExceptionMeters implement MetricSet instead, LogviewerServer is not a MetricSet?

It would be weirder since getMetrics is an instance method. So I have to do [SOME_ENUM].getMetrics()

You're right, but can't a lambda solve this? Would it work to do registerMetricSet(ExceptionMeters::getMetrics) in line 132 instead?

No it would be registerMetricSet(ExceptionMeters.[SOME_ENUM]) or

enum ExceptionMeters implements MetricSet { ENUM1; private static final Map<...> map = ...; public static MetricSet getMetricSet() { return ENUM1; @Override public Map<...> getMetrics() { return map; } }

How pretty is that.

I can think of an Alternative

enum ExceptionMeters { ENUM1; private static final Map<...> map = ...; private static final MetricSet set = () -> map; public static MetricSet getMetricSet() { return set; }

StormMetricsRegistry.registerMetricSet(ExceptionMeters::getMetrics); works fine for me?

Just to be clear, I'm talking about removing implements MetricSet from LogviewerServer and replacing it with StormMetricsRegistry.registerMetricSet(ExceptionMeters::getMetrics);. ExceptionMeters doesn't need to implement MetricSet.

Ah I see. That's brilliant. Thanks

srdo · 2018-08-09T19:17:19Z

...-webapp/src/main/java/org/apache/storm/daemon/logviewer/handler/LogviewerLogPageHandler.java

-
-                List<String> reorderedFilesStr = new ArrayList<>();
-                reorderedFilesStr.addAll(filesStrWithoutFileParam);
+                List<String> reorderedFilesStr = logFiles.stream().map(WorkerLogs::getTopologyPortWorkerLog)


Nit: Put each step of the pipeline on a new line.

srdo · 2018-08-09T20:19:33Z

...ebapp/src/main/java/org/apache/storm/daemon/logviewer/handler/LogviewerLogSearchHandler.java

@@ -71,6 +78,11 @@

 public class LogviewerLogSearchHandler {
    private static final Logger LOG = LoggerFactory.getLogger(LogviewerLogSearchHandler.class);
+    private static final Meter numDeepSearchNoResult = StormMetricsRegistry.registerMeter("logviewer:num-deep-search-no-result");
+    private static final Histogram numFilesOpenedDeepSearch = StormMetricsRegistry.registerHistogram(
+            "logviewer:num-files-opened-deep-search", new ExponentiallyDecayingReservoir());


I think you added a convenience histogram method to the registry at one point, so you don't have to specify the reservoir.

srdo · 2018-08-09T20:33:26Z

...ebapp/src/main/java/org/apache/storm/daemon/logviewer/handler/LogviewerLogSearchHandler.java

            currentFileMatch.put("fileName", fileName);
            Path firstLogAbsPath;
            try {
                firstLogAbsPath = firstLog.getCanonicalFile().toPath();
            } catch (IOException e) {
                throw new RuntimeException(e);
            }
+            //Why do we need to start from scratch to retrieve just the port here?


Please remove. Also what do you mean start from scratch?

Oh I was complaining that the implementation doesn't look too good. Both port and filename are included in the absolute path. We could just optimize the code here. It looks minor though.

srdo · 2018-08-09T21:03:38Z

storm-server/src/main/java/org/apache/storm/daemon/nimbus/Nimbus.java

+    private static final Histogram numAddedSlotPerScheduling = StormMetricsRegistry.registerHistogram("nimbus:num-added-slots-per-scheduling", new ExponentiallyDecayingReservoir());
+    private static final Histogram numRemovedExecPerScheduling = StormMetricsRegistry.registerHistogram("nimbus:num-removed-executors-per-scheduling", new ExponentiallyDecayingReservoir());
+    private static final Histogram numRemovedSlotPerScheduling = StormMetricsRegistry.registerHistogram("nimbus:num-removed-slots-per-scheduling", new ExponentiallyDecayingReservoir());
+    private static final Histogram numNetExecIncreasePerScheduling = StormMetricsRegistry.registerHistogram("nimbus:num-net-executors-changed-per-scheduling", new ExponentiallyDecayingReservoir());


The variable name says it's exec increase, but the metric name says it's the number changed.

Sorry I fixed in in another commit. Will port it here.

srdo · 2018-08-09T21:05:14Z

...-webapp/src/main/java/org/apache/storm/daemon/logviewer/handler/LogviewerLogPageHandler.java

 import org.apache.storm.utils.ConfigUtils;
 import org.apache.storm.utils.ServerUtils;
 import org.jooq.lambda.Unchecked;

 public class LogviewerLogPageHandler {
+    private static final Meter numPageRead = StormMetricsRegistry.registerMeter("logviewer:num-page-read");


What is this metric useful for?

How many pages of logs are read from handling each request.

I mean why does someone want to know this :P. Nevermind, I'm guessing this was also requested by @kishorvpatil. I just wanted to know whether someone asked for/had a use case for these metrics.

It's as part of IO performance metrics. He seems to be concerning about the IO performance of logviewer, which makes sense to me because majority of our API calls are blocking call.

srdo · 2018-08-09T21:05:47Z

...ebapp/src/main/java/org/apache/storm/daemon/logviewer/handler/LogviewerLogSearchHandler.java

@@ -71,6 +78,10 @@

 public class LogviewerLogSearchHandler {
    private static final Logger LOG = LoggerFactory.getLogger(LogviewerLogSearchHandler.class);
+    private static final Meter numDeepSearchNoResult = StormMetricsRegistry.registerMeter("logviewer:num-deep-search-no-result");


Are these metrics useful?

I think it's for analyzing invalid requests, but I'm not sure. @kishorvpatil requested it. You may ask him for his intention.

srdo · 2018-08-09T21:07:29Z

storm-webapp/src/main/java/org/apache/storm/daemon/logviewer/utils/ExceptionMeters.java

+
+public enum ExceptionMeters {
+    //Operation level IO Exceptions
+    NUM_FILE_OPEN_EXCEPTIONS("logviewer:num-file-open-exceptions"),


Why is it useful to distinguish between e.g. read and open errors in the metrics?

That's a good point though. I don't see a very compelling reason. Again this was requested by @kishorvpatil.

srdo · 2018-08-09T21:09:09Z

storm-webapp/src/main/java/org/apache/storm/daemon/logviewer/webapp/LogviewerResource.java

@@ -62,6 +64,14 @@
            "logviewer:num-download-log-daemon-file-http-requests");
    private static final Meter meterListLogsHttpRequests = StormMetricsRegistry.registerMeter("logviewer:num-list-logs-http-requests");

+    private static final Meter numSearchLogRequests = StormMetricsRegistry.registerMeter("logviewer:num-search-logs-requests");


I see why it's useful to know how long they take, but is it useful to know how many searches have happened as well?

It also reports the frequency of requests handling. I think it can reflect the server load in a way.

Ethanlm

+1 looks good to me. I think it's good to go after you address @srdo 's comments.

zd-project · 2018-08-10T16:06:25Z

All nits should have been addressed as of now.

srdo · 2018-08-10T16:13:21Z

storm-server/src/main/java/org/apache/storm/daemon/nimbus/Nimbus.java

-        long scheduleTimeElapsedMs = System.currentTimeMillis() - beforeSchedule;
-        LOG.debug("Scheduling took {} ms for {} topologies", scheduleTimeElapsedMs, topologies.getTopologies().size());
-        scheduleTopologyTimeMs.update(scheduleTimeElapsedMs);
+        long elapsed = -schedulingStartTimeNs.getAndSet(null) + Time.nanoTime();


I might have asked this over on the other PR, but is it written this way to fix the race? If so, please put a note in here about it, otherwise it's very likely this gets reordered next time someone happens across this code.

Also splitting this line in two would probably also be appropriate.

//Get and set the start time before getting current time in order to avoid potential race with the longestSchedulingTime gauge long startTimeNs = schedulingStartTimeNs.getAndSet(null); long nowNs = Time.nanoTime(); long elapsed = nowNs - startTimeNs;

It's much more obvious that the order matters this way.

srdo · 2018-08-10T16:14:03Z

storm-server/src/main/java/org/apache/storm/daemon/nimbus/Nimbus.java

-
+            StormMetricsRegistry.registerGauge("nimbus:longest-scheduling-time-ms", () -> {
+                //We want to update longest scheduling time in real time in case scheduler get stuck
+                // It's normal to see some very minor jiggling in value as race condition may happen


Is the race still there given your reordering?

srdo · 2018-08-10T16:42:30Z

+1. Please squash and we can merge.

STORM-3157: Added registration method for MetricSet STORM-3133: Refactored and added metrics to LogViewer components STORM-3133: Fixed up Unit test for LogViewer STORM-3133: Refactored and added metrics to Nimbus components. STORM-3133: Add nimbus scheduling metrics STORM-3133: Add metrics for disk usage of workers' logs and performance of LogCleaner routine STORM-3133: Refactored code and added file partial read count metric for logviewer STORM-3133: Add metrics for counting LogViewer's IOExceptions

zd-project force-pushed the STORM-3133 branch from 22457eb to 9679e07 Compare July 5, 2018 21:37

zd-project force-pushed the STORM-3133 branch 2 times, most recently from 6085270 to 07ad8a6 Compare July 12, 2018 16:16

zd-project mentioned this pull request Jul 19, 2018

STORM-3159: Fixed a potential file resource leak. #2769

Merged

zd-project changed the title ~~STORM-3133: Extend metrics on Nimbus and LogViewer~~ [WIP] STORM-3133: Extend metrics on Nimbus and LogViewer Jul 19, 2018

zd-project force-pushed the STORM-3133 branch from a1469d7 to 7bea4cf Compare July 27, 2018 18:10

zd-project mentioned this pull request Jul 27, 2018

STORM-3157: General improvement to StormMetricsRegistry #2771

Merged

zd-project force-pushed the STORM-3133 branch from 7bea4cf to 23ba886 Compare July 30, 2018 20:56

zd-project mentioned this pull request Aug 1, 2018

STORM-3170: Fixed bug to eliminate invalid file deletion #2788

Merged

zd-project force-pushed the STORM-3133 branch 7 times, most recently from b5487c3 to c9a7937 Compare August 3, 2018 20:12

zd-project changed the title ~~[WIP] STORM-3133: Extend metrics on Nimbus and LogViewer~~ STORM-3133: Extend metrics on Nimbus and LogViewer Aug 3, 2018

zd-project force-pushed the STORM-3133 branch 3 times, most recently from 63fac98 to a1b3e02 Compare August 8, 2018 15:20

Ethanlm reviewed Aug 8, 2018

View reviewed changes

zd-project mentioned this pull request Aug 8, 2018

STORM-3147: Port ClusterSummary as metrics to StormMetricsRegistry #2764

Closed

zd-project force-pushed the STORM-3133 branch 2 times, most recently from 80fbf52 to a247b86 Compare August 9, 2018 20:18

Ethanlm reviewed Aug 9, 2018

View reviewed changes

srdo reviewed Aug 9, 2018

View reviewed changes

Ethanlm approved these changes Aug 10, 2018

View reviewed changes

zd-project force-pushed the STORM-3133 branch from 6e71bee to 75c65c8 Compare August 10, 2018 15:41

srdo reviewed Aug 10, 2018

View reviewed changes

Ethanlm approved these changes Aug 10, 2018

View reviewed changes

zd-project force-pushed the STORM-3133 branch from a937149 to bf81b68 Compare August 10, 2018 17:02

asfgit merged commit bf81b68 into apache:master Aug 10, 2018

STORM-3133: Extend metrics on Nimbus and LogViewer #2754

STORM-3133: Extend metrics on Nimbus and LogViewer #2754

Conversation

zd-project commented Jul 5, 2018 • edited

zd-project commented Jul 5, 2018 • edited

zd-project commented Aug 3, 2018

Ethanlm left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

zd-project commented Aug 9, 2018

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

srdo left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

zd-project Aug 9, 2018 • edited

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Ethanlm left a comment

Choose a reason for hiding this comment

zd-project commented Aug 10, 2018

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

srdo commented Aug 10, 2018

zd-project commented Jul 5, 2018 •

edited

zd-project commented Jul 5, 2018 •

edited

zd-project Aug 9, 2018 •

edited