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.

Sign up for GitHub

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

Jump to bottom

Use a metric instead of logging excessive filter execution time #1096

Merged
merged 2 commits into from Aug 20, 2021
+26 −11
Merged

Use a metric instead of logging excessive filter execution time #1096

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
2 commits
Select commit Hold shift + click to select a range
43e878f
Use a metric instead of logging excessive filter execution time
jfernandez Aug 17, 2021
b944330
Add metrics registry to constructors
jfernandez Aug 18, 2021
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Jump to
Jump to file
Failed to load files.
Diff view
Diff view
16 changes: 14 additions & 2 deletions zuul-core/src/main/java/com/netflix/zuul/netty/filter/BaseZuulFilterRunner.java
View file
Open in desktop
Expand Up @@ -17,6 +17,8 @@
package com.netflix.zuul.netty.filter;

import com.netflix.config.CachedDynamicIntProperty;
import com.netflix.spectator.api.Id;
import com.netflix.spectator.api.Registry;
import com.netflix.spectator.impl.Preconditions;
import com.netflix.zuul.ExecutionStatus;
import com.netflix.zuul.FilterUsageNotifier;
Expand All @@ -37,6 +39,8 @@
import io.netty.handler.codec.http.HttpContent;
import io.perfmark.Link;
import io.perfmark.TaskCloseable;

import java.util.concurrent.TimeUnit;
import java.util.concurrent.atomic.AtomicReference;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
Expand Down Expand Up @@ -78,12 +82,17 @@ public abstract class BaseZuulFilterRunner<I extends ZuulMessage, O extends Zuul

private static final CachedDynamicIntProperty FILTER_EXCESSIVE_EXEC_TIME = new CachedDynamicIntProperty("zuul.filters.excessive.execTime", 500);

private final Registry registry;
private final Id filterExcessiveTimerId;

protected BaseZuulFilterRunner(FilterType filterType, FilterUsageNotifier usageNotifier, FilterRunner<O, ?> nextStage) {
protected BaseZuulFilterRunner(FilterType filterType, FilterUsageNotifier usageNotifier,
FilterRunner<O, ?> nextStage, Registry registry) {
this.usageNotifier = Preconditions.checkNotNull(usageNotifier, "filter usage notifier");
this.nextStage = nextStage;
this.RUNNING_FILTER_IDX_SESSION_CTX_KEY = filterType + "RunningFilterIndex";
this.AWAITING_BODY_FLAG_SESSION_CTX_KEY = filterType + "IsAwaitingBody";
this.registry = registry;
this.filterExcessiveTimerId = registry.createId("zuul.request.timing.filterExcessive");
}

public static final ChannelHandlerContext getChannelHandlerContext(final ZuulMessage mesg) {
Expand Down Expand Up @@ -318,7 +327,10 @@ protected void recordFilterCompletion(final ExecutionStatus status, final ZuulFi
final long execTimeNs = System.nanoTime() - startTime;
final long execTimeMs = execTimeNs / 1_000_000L;
if (execTimeMs >= FILTER_EXCESSIVE_EXEC_TIME.get()) {
logger.warn("Filter {} took {} ms to complete! status = {}", filter.filterName(), execTimeMs, status.name());
registry.timer(filterExcessiveTimerId
.withTag("id", filter.filterName())
.withTag("status", status.name()))
.record(execTimeMs, TimeUnit.MILLISECONDS);
}

// Record the execution summary in context.
Expand Down
5 changes: 3 additions & 2 deletions zuul-core/src/main/java/com/netflix/zuul/netty/filter/ZuulEndPointRunner.java
View file
Open in desktop
Expand Up @@ -18,6 +18,7 @@

import com.google.common.base.Strings;
import com.netflix.config.DynamicStringProperty;
import com.netflix.spectator.api.Registry;
import com.netflix.spectator.impl.Preconditions;
import com.netflix.zuul.FilterLoader;
import com.netflix.zuul.FilterUsageNotifier;
Expand Down Expand Up @@ -59,8 +60,8 @@ public class ZuulEndPointRunner extends BaseZuulFilterRunner<HttpRequestMessage,


public ZuulEndPointRunner(FilterUsageNotifier usageNotifier, FilterLoader filterLoader,
FilterRunner<HttpResponseMessage, HttpResponseMessage> respFilters) {
super(FilterType.ENDPOINT, usageNotifier, respFilters);
FilterRunner<HttpResponseMessage, HttpResponseMessage> respFilters, Registry registry) {
super(FilterType.ENDPOINT, usageNotifier, respFilters, registry);
this.filterLoader = filterLoader;
}

Expand Down
10 changes: 6 additions & 4 deletions zuul-core/src/main/java/com/netflix/zuul/netty/filter/ZuulFilterChainRunner.java
View file
Open in desktop
Expand Up @@ -16,6 +16,7 @@

package com.netflix.zuul.netty.filter;

import com.netflix.spectator.api.Registry;
import com.netflix.spectator.impl.Preconditions;
import com.netflix.zuul.FilterUsageNotifier;
import com.netflix.zuul.filters.ZuulFilter;
Expand All @@ -40,13 +41,14 @@ public class ZuulFilterChainRunner<T extends ZuulMessage> extends BaseZuulFilter

private final ZuulFilter<T, T>[] filters;

public ZuulFilterChainRunner(ZuulFilter<T, T>[] zuulFilters, FilterUsageNotifier usageNotifier, FilterRunner<T, ?> nextStage) {
super(zuulFilters[0].filterType(), usageNotifier, nextStage);
public ZuulFilterChainRunner(ZuulFilter<T, T>[] zuulFilters, FilterUsageNotifier usageNotifier,
FilterRunner<T, ?> nextStage, Registry registry) {
super(zuulFilters[0].filterType(), usageNotifier, nextStage, registry);
this.filters = zuulFilters;
}

public ZuulFilterChainRunner(ZuulFilter<T, T>[] zuulFilters, FilterUsageNotifier usageNotifier) {
this(zuulFilters, usageNotifier, null);
public ZuulFilterChainRunner(ZuulFilter<T, T>[] zuulFilters, FilterUsageNotifier usageNotifier, Registry registry) {
this(zuulFilters, usageNotifier, null, registry);
}

@Override
Expand Down
6 changes: 3 additions & 3 deletions zuul-core/src/main/java/com/netflix/zuul/netty/server/BaseZuulChannelInitializer.java
View file
Open in desktop
Expand Up @@ -336,18 +336,18 @@ protected void addZuulFilterChainHandler(final ChannelPipeline pipeline) {

protected ZuulEndPointRunner getEndpointRunner(ZuulFilterChainRunner<HttpResponseMessage> responseFilterChain,
FilterUsageNotifier filterUsageNotifier, FilterLoader filterLoader) {
return new ZuulEndPointRunner(filterUsageNotifier, filterLoader, responseFilterChain);
return new ZuulEndPointRunner(filterUsageNotifier, filterLoader, responseFilterChain, registry);
}

protected <T extends ZuulMessage> ZuulFilterChainRunner<T> getFilterChainRunner(ZuulFilter<T, T>[] filters,
FilterUsageNotifier filterUsageNotifier) {
return new ZuulFilterChainRunner<>(filters, filterUsageNotifier);
return new ZuulFilterChainRunner<>(filters, filterUsageNotifier, registry);
}

protected <T extends ZuulMessage, R extends ZuulMessage> ZuulFilterChainRunner<T> getFilterChainRunner(ZuulFilter<T, T>[] filters,
FilterUsageNotifier filterUsageNotifier,
FilterRunner<T, R> filterRunner) {
return new ZuulFilterChainRunner<>(filters, filterUsageNotifier, filterRunner);
return new ZuulFilterChainRunner<>(filters, filterUsageNotifier, filterRunner, registry);
}

@SuppressWarnings("unchecked") // For the conversion from getFiltersByType. It's not safe, sorry.
Expand Down