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

[Feature] Support Tracing for GlobalFilter and GatewayFilter in Gateway #736

Merged

Conversation

yqw570994511
Copy link
Contributor

…g-cloud-gateway-plugin #12839

  • If this pull request closes/resolves/fixes an existing issue, replace the issue number. Closes #.
  • Update the CHANGES log.

@wu-sheng
Copy link
Member

Please update the Spring Gateway cases, UT is not enough to verify plugins codes. There are many test scenarios here, such as this is for 3.x GW.

If you don't know how to run this, please follow Plugin automatic test framework docs. You could change codes of those cases, and verify them locally with new expectation files.

@wu-sheng wu-sheng added enhancement New feature or request plugin labels Dec 10, 2024
@wu-sheng wu-sheng added this to the 9.4.0 milestone Dec 10, 2024
@wu-sheng
Copy link
Member

You can see, your new codes break gateway-3.x-filter-context-scenario. That is another thing you should fix about the test scenarios.

@yqw570994511
Copy link
Contributor Author

Please update the Spring Gateway cases, UT is not enough to verify plugins codes. There are many test scenarios here, such as this is for 3.x GW.

If you don't know how to run this, please follow Plugin automatic test framework docs. You could change codes of those cases, and verify them locally with new expectation files.

Sure, I'll take a look at the documentation you provided first.

@wu-sheng
Copy link
Member

@wuwen5 Could you take a look at this?

@wuwen5
Copy link
Contributor

wuwen5 commented Dec 10, 2024

I think the issue seems to be repetitive with this #539 , and we can support it in this way.

https://github.com/apache/skywalking-java/blob/main/docs/en/setup/service-agent/java-agent/Application-toolkit-webflux.md#fetch-trace-context-relative-ids

@Override
    public Mono<Void> filter(ServerWebExchange exchange, GatewayFilterChain chain){
        // fetch trace ID
        String traceId = WebFluxSkyWalkingTraceContext.traceId(exchange);
        
        // fetch segment ID
        String segmentId = WebFluxSkyWalkingTraceContext.segmentId(exchange);
        
        // fetch span ID
        int spanId = WebFluxSkyWalkingTraceContext.spanId(exchange);
        
        return chain.filter(exchange);
    }

@wu-sheng
Copy link
Member

@yqw570994511 Could you verify this new way? If it works, we don't need extra filter interceptor.

@yqw570994511
Copy link
Contributor Author

@yqw570994511 Could you verify this new way? If it works, we don't need extra filter interceptor.

Thank you, I'll try this way

@yqw570994511
Copy link
Contributor Author

I think the issue seems to be repetitive with this #539 , and we can support it in this way.

https://github.com/apache/skywalking-java/blob/main/docs/en/setup/service-agent/java-agent/Application-toolkit-webflux.md#fetch-trace-context-relative-ids

@Override
    public Mono<Void> filter(ServerWebExchange exchange, GatewayFilterChain chain){
        // fetch trace ID
        String traceId = WebFluxSkyWalkingTraceContext.traceId(exchange);
        
        // fetch segment ID
        String segmentId = WebFluxSkyWalkingTraceContext.segmentId(exchange);
        
        // fetch span ID
        int spanId = WebFluxSkyWalkingTraceContext.spanId(exchange);
        
        return chain.filter(exchange);
    }

Thank you, I'll try this way

@yqw570994511
Copy link
Contributor Author

I think the issue seems to be repetitive with this #539 , and we can support it in this way.

https://github.com/apache/skywalking-java/blob/main/docs/en/setup/service-agent/java-agent/Application-toolkit-webflux.md#fetch-trace-context-relative-ids

@Override
    public Mono<Void> filter(ServerWebExchange exchange, GatewayFilterChain chain){
        // fetch trace ID
        String traceId = WebFluxSkyWalkingTraceContext.traceId(exchange);
        
        // fetch segment ID
        String segmentId = WebFluxSkyWalkingTraceContext.segmentId(exchange);
        
        // fetch span ID
        int spanId = WebFluxSkyWalkingTraceContext.spanId(exchange);
        
        return chain.filter(exchange);
    }

I tried it according to the method you gave, and it achieved the same effect as my previous code:

image

I got the following result:

image

But when I am in another situation, it can't meet my needs.
My project is configured with logback to output skywalking's traceId to help me track problems, but using the above method, I can see that skywalking's traceId is not output.
In the production environment, I really need my log to print out the traceId, and I also hope that I can achieve this goal by writing business code as much as possible. For example, I hope my filter code can output the traceId in the log like this:

image

The result of using the new solution is as follows:

image

I think the new scheme can support more scenarios and should help many people like me who have similar needs.

@wu-sheng
Copy link
Member

If this targets to support custom filters, I think it makes sense.

@huicunjun
Copy link

huicunjun commented Dec 12, 2024

My situation is similar to yours, the issue of logback not outputting tid can be resolved through

WebFluxSkyWalkingOperators.continueTracing(serverWebExchange, callable);
Solution to the interceptor code for the package gateway

image
In this way, the output log will be automatically filled with tid

@huicunjun
Copy link

huicunjun commented Dec 12, 2024

The problem I found is that when the gateway forwards to downstream web services, the traceId changes and the entire process is not linked together

@wu-sheng

@wu-sheng
Copy link
Member

Why ping me?

@huicunjun
Copy link

Why ping me?

The tid of the log printed in the spring gateway interceptor is inconsistent with the tid of the log printed in the downstream service interceptor after forwarding. Is there any way to troubleshoot?

@wu-sheng
Copy link
Member

I am not following. How to debug Agent and plugins are common knowledge.
There is nothing special at my side.

@wu-sheng
Copy link
Member

Here is a pull request discussion. Please don't mix things here.

@wu-sheng
Copy link
Member

It is good to see tests are passed. Thanks.

One question about this doc, with your new plugin gets merged, does user still need to add manual codes? Which scenarios are automatically working, which are still not?

Comment on lines 42 to 43
STACK_DEEP.get().getAndIncrement();
if (isEntry()) {
Copy link
Member

Choose a reason for hiding this comment

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

I think you have some duplicate executions here and same as isExit.

STACK_DEEP.get().getAndIncrement() will return 0 for the first time(as Entry), and STACK_DEEP.get().decrementAndGet() will return 0 too for the last time(as Exit).

Your codes call getThreadLocal and getIntValue twice. You could polish codes about this.

Copy link
Member

Choose a reason for hiding this comment

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

@yqw570994511 Could you check this and polish?

Copy link
Contributor Author

Choose a reason for hiding this comment

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

@yqw570994511 Could you check this and polish?

Thank you, I will adjust my code as follows

public class GatewayFilterInterceptor implements InstanceMethodsAroundInterceptor {

    private static final ThreadLocal<AtomicInteger> STACK_DEEP = ThreadLocal.withInitial(() -> new AtomicInteger(0));

    @Override
    public void beforeMethod(EnhancedInstance objInst, Method method, Object[] allArguments, Class<?>[] argumentsTypes,
                             MethodInterceptResult result) throws Throwable {
        if (isEntry()) {
            ServerWebExchange exchange = (ServerWebExchange) allArguments[0];

            EnhancedInstance enhancedInstance = getInstance(exchange);

            AbstractSpan span = ContextManager.createLocalSpan("SpringCloudGateway/GatewayFilter");
            if (enhancedInstance != null && enhancedInstance.getSkyWalkingDynamicField() != null) {
                ContextManager.continued((ContextSnapshot) enhancedInstance.getSkyWalkingDynamicField());
            }
            span.setComponent(SPRING_CLOUD_GATEWAY);
        }
    }

    public static EnhancedInstance getInstance(Object o) {
        EnhancedInstance instance = null;
        if (o instanceof DefaultServerWebExchange) {
            instance = (EnhancedInstance) o;
        } else if (o instanceof ServerWebExchangeDecorator) {
            ServerWebExchange delegate = ((ServerWebExchangeDecorator) o).getDelegate();
            return getInstance(delegate);
        }
        return instance;
    }

    @Override
    public Object afterMethod(EnhancedInstance objInst, Method method, Object[] allArguments, Class<?>[] argumentsTypes,
                              Object ret) throws Throwable {
        if (isExit()) {
            if (ContextManager.isActive()) {
                ContextManager.stopSpan();
            }
        }
        return ret;
    }

    @Override
    public void handleMethodException(EnhancedInstance objInst, Method method, Object[] allArguments,
                                      Class<?>[] argumentsTypes, Throwable t) {
        ContextManager.activeSpan().log(t);
    }

    private boolean isEntry() {
        return STACK_DEEP.get().getAndIncrement() == 0;
    }

    private boolean isExit() {
        boolean isExit = STACK_DEEP.get().decrementAndGet() == 0;
        if (isExit) {
            STACK_DEEP.remove();
        }
        return isExit;
    }
}

If you think it is feasible, can I submit the code accordingly?

Copy link
Member

Choose a reason for hiding this comment

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

Yes, please go ahead

@yqw570994511
Copy link
Contributor Author

yqw570994511 commented Dec 15, 2024

I tried it according to the method you gave, and it achieved the same effect as my previous code

@Component
public class Filter1 implements GlobalFilter, Ordered {
    private static final Logger log = LoggerFactory.getLogger(Filter1.class);
    @Override
    public Mono<Void> filter(ServerWebExchange exchange, GatewayFilterChain chain) {
        // fetch trace ID
        String traceId = WebFluxSkyWalkingTraceContext.traceId(exchange);
        // fetch segment ID
        String segmentId = WebFluxSkyWalkingTraceContext.segmentId(exchange);
        // fetch span ID
        int spanId = WebFluxSkyWalkingTraceContext.spanId(exchange);
        log.info("filter1 traceId: {}, segmentId: {}, spanId: {}", traceId, segmentId, spanId);
        return chain.filter(exchange);
    }
    @Override
    public int getOrder() {
        return -100;
    }
}

I got the following result

image

But when I am in another situation, it can't meet my needs. My project is configured with logback to output skywalking's traceId to help me track problems, but using the above method, I can see that skywalking's traceId is not output. In the production environment, I really need my log to print out the traceId, and I also hope that I can achieve this goal by writing business code as much as possible. For example, I hope my filter code can output the traceId in the log like this:

@Component
public class Filter1 implements GlobalFilter, Ordered {
    private static final Logger log = LoggerFactory.getLogger(Filter1.class);
    @Override
    public Mono<Void> filter(ServerWebExchange exchange, GatewayFilterChain chain) {
        log.info("filter1 running");
        return chain.filter(exchange);
    }
    @Override
    public int getOrder() {
        return -100;
    }
}

The result of using the new solution is as follows:
image

I think the new scheme can support more scenarios and should help many people like me who have similar needs

I think the issue seems to be repetitive with this #539 , and we can support it in this way.

https://github.com/apache/skywalking-java/blob/main/docs/en/setup/service-agent/java-agent/Application-toolkit-webflux.md#fetch-trace-context-relative-ids

@Override
    public Mono<Void> filter(ServerWebExchange exchange, GatewayFilterChain chain){
        // fetch trace ID
        String traceId = WebFluxSkyWalkingTraceContext.traceId(exchange);
        
        // fetch segment ID
        String segmentId = WebFluxSkyWalkingTraceContext.segmentId(exchange);
        
        // fetch span ID
        int spanId = WebFluxSkyWalkingTraceContext.spanId(exchange);
        
        return chain.filter(exchange);
    }

I think the issue seems to be repetitive with this #539 , and we can support it in this way.

https://github.com/apache/skywalking-java/blob/main/docs/en/setup/service-agent/java-agent/Application-toolkit-webflux.md#fetch-trace-context-relative-ids

@Override
    public Mono<Void> filter(ServerWebExchange exchange, GatewayFilterChain chain){
        // fetch trace ID
        String traceId = WebFluxSkyWalkingTraceContext.traceId(exchange);
        
        // fetch segment ID
        String segmentId = WebFluxSkyWalkingTraceContext.segmentId(exchange);
        
        // fetch span ID
        int spanId = WebFluxSkyWalkingTraceContext.spanId(exchange);
        
        return chain.filter(exchange);
    }

I tried it according to the method you gave, and it achieved the same effect as my previous code
@Component public class Filter1 implements GlobalFilter, Ordered { private static final Logger log = LoggerFactory.getLogger(Filter1.class); @Override public Mono<Void> filter(ServerWebExchange exchange, GatewayFilterChain chain) { // fetch trace ID String traceId = WebFluxSkyWalkingTraceContext.traceId(exchange); // fetch segment ID String segmentId = WebFluxSkyWalkingTraceContext.segmentId(exchange); // fetch span ID int spanId = WebFluxSkyWalkingTraceContext.spanId(exchange); log.info("filter1 traceId: {}, segmentId: {}, spanId: {}", traceId, segmentId, spanId); return chain.filter(exchange); } @Override public int getOrder() { return -100; } }

I got the following result

image

But when I am in another situation, it can't meet my needs. My project is configured with logback to output skywalking's traceId to help me track problems, but using the above method, I can see that skywalking's traceId is not output. In the production environment, I really need my log to print out the traceId, and I also hope that I can achieve this goal by writing business code as much as possible. For example, I hope my filter code can output the traceId in the log like this:

@Component public class Filter1 implements GlobalFilter, Ordered { private static final Logger log = LoggerFactory.getLogger(Filter1.class); @Override public Mono<Void> filter(ServerWebExchange exchange, GatewayFilterChain chain) { log.info("filter1 running"); return chain.filter(exchange); } @Override public int getOrder() { return -100; } }

The result of using the new solution is as follows:
image

I think the new scheme can support more scenarios and should help many people like me who have similar needs

It is good to see tests are passed. Thanks.

One question about this doc, with your new plugin gets merged, does user still need to add manual codes? Which scenarios are automatically working, which are still not?

Writing code similar to this is enough:
`
@component
public class Filter1 implements GlobalFilter, Ordered {

private static final Logger log = LoggerFactory.getLogger(Filter1.class);
@Override
public Mono<Void> filter(ServerWebExchange exchange, GatewayFilterChain chain) {
    log.info("filter1 running");

    // fetch trace ID
    String traceId = TraceContext.traceId();
    log.info("filter1 traceId: {}", traceId);

    // fetch segment ID
    String segmentId = TraceContext.segmentId();
    log.info("filter1 segmentId: {}", segmentId);

    // fetch span ID
    int spanId = TraceContext.spanId();
    log.info("filter1 spanId: {}", spanId);
    
    return chain.filter(exchange);
}
@Override
public int getOrder() {
    return -100;
}

}

@component
public class GatewayFilter1 implements GatewayFilter {

private static final Logger log = LoggerFactory.getLogger(GatewayFilter1.class);
@Override
public Mono<Void> filter(ServerWebExchange exchange, GatewayFilterChain chain) {
    log.info("gatewayFilter1 running");
    return chain.filter(exchange);
}

}
`
The results obtained are as follows:
image

@wu-sheng
Copy link
Member

Could you reformat your comment? It is a little chaos from reading. I tried to edit but still not clear.

@wu-sheng
Copy link
Member

The reason I am asking about, is not doubting your PR. The key is, I want to set up a good boundary for community users.
How much does this PR resolve the issues about the manual codes required? In which cases, they still need to consider adding those codes.
Could you focus on that?

@wu-sheng
Copy link
Member

Because in this doc, it mentioned about fetching trace IDs, I had known they are not able to output in the same place of the logs. We don't need to talk about that part.

The question is, are all filters logs carrying logs automatically now? Or some fliters can, others can't. If it is later, then which filters still can't have the automatic injected trace contexts in their logs.

@yqw570994511
Copy link
Contributor Author

It is good to see tests are passed. Thanks.

One question about this doc, with your new plugin gets merged, does user still need to add manual codes? Which scenarios are automatically working, which are still not?

Writing code similar to this is enough:

@Component
public class Filter1 implements GlobalFilter, Ordered {

    private static final Logger log = LoggerFactory.getLogger(Filter1.class);
    @Override
    public Mono<Void> filter(ServerWebExchange exchange, GatewayFilterChain chain) {
        log.info("filter1 running");

        // fetch trace ID
        String traceId = TraceContext.traceId();
        log.info("filter1 traceId: {}", traceId);

        // fetch segment ID
        String segmentId = TraceContext.segmentId();
        log.info("filter1 segmentId: {}", segmentId);

        // fetch span ID
        int spanId = TraceContext.spanId();
        log.info("filter1 spanId: {}", spanId);

        return chain.filter(exchange);
    }
    @Override
    public int getOrder() {
        return -100;
    }
}
@Component
public class GatewayFilter1 implements GatewayFilter {

    private static final Logger log = LoggerFactory.getLogger(GatewayFilter1.class);
    @Override
    public Mono<Void> filter(ServerWebExchange exchange, GatewayFilterChain chain) {
        log.info("gatewayFilter1 running");
        return chain.filter(exchange);
    }
}

The results obtained are as follows:
image

@wu-sheng
Copy link
Member

Is there any filter not supposed?

@yqw570994511
Copy link
Contributor Author

Because in this doc, it mentioned about fetching trace IDs, I had known they are not able to output in the same place of the logs. We don't need to talk about that part.

The question is, are all filters logs carrying logs automatically now? Or some fliters can, others can't. If it is later, then which filters still can't have the automatic injected trace contexts in their logs.

Any filter that implements the GlobalFilter and GatewayFilter interfaces can be supported. If the user only calls the code chain.filter(exchange) in each filter, the traceId will be fully recorded. However, if the user writes this code chain.filter(exchange).then(), the code in then() will not be able to obtain the traceId. In this case, you need to manually call WebFluxSkyWalkingTraceContext.traceId(exchange) in then() to obtain it. Here is an example:

@Component
public class Filter1 implements GlobalFilter, Ordered {

    private static final Logger log = LoggerFactory.getLogger(Filter1.class);
    @Override
    public Mono<Void> filter(ServerWebExchange exchange, GatewayFilterChain chain) {
        log.info("filter1 running");

        // fetch trace ID
        String traceId = TraceContext.traceId();
        log.info("filter1 traceId: {}", traceId);

        // fetch segment ID
        String segmentId = TraceContext.segmentId();
        log.info("filter1 segmentId: {}", segmentId);

        // fetch span ID
        int spanId = TraceContext.spanId();
        log.info("filter1 spanId: {}", spanId);

        return chain.filter(exchange).then(Mono.fromRunnable(() -> {
            log.info("filter1 then running");

            // fetch trace ID
            String traceId2 = TraceContext.traceId();
            log.info("filter1 then traceId: {}", traceId2);

            // fetch segment ID
            String segmentId2 = TraceContext.segmentId();
            log.info("filter1 then segmentId: {}", segmentId2);

            // fetch span ID
            int spanId2 = TraceContext.spanId();
            log.info("filter1 then spanId: {}", spanId2);
        }));
    }
    @Override
    public int getOrder() {
        return -100;
    }
}

result:
image

@Component
public class Filter2 implements GlobalFilter, Ordered {

    private static final Logger log = LoggerFactory.getLogger(Filter2.class);
    @Override
    public Mono<Void> filter(ServerWebExchange exchange, GatewayFilterChain chain) {
        log.info("filter2 running");

        // fetch trace ID
        String traceId = TraceContext.traceId();
        log.info("filter2 traceId: {}", traceId);

        // fetch segment ID
        String segmentId = TraceContext.segmentId();
        log.info("filter2 segmentId: {}", segmentId);

        // fetch span ID
        int spanId = TraceContext.spanId();
        log.info("filter2 spanId: {}", spanId);
        return chain.filter(exchange).then(Mono.fromRunnable(() -> {
            String traceId2 = WebFluxSkyWalkingTraceContext.traceId(exchange);
            log.info("filter2 then traceId: {}", traceId2);

            String segmentId2 = WebFluxSkyWalkingTraceContext.segmentId(exchange);
            log.info("filter2 then segmentId: {}", segmentId2);

            int spanId2 = WebFluxSkyWalkingTraceContext.spanId(exchange);
            log.info("filter2 then spanId: {}", spanId2);
        }));
    }

    @Override
    public int getOrder() {
        return 10;
    }
}

result:
image

@yqw570994511
Copy link
Contributor Author

Because in this doc, it mentioned about fetching trace IDs, I had known they are not able to output in the same place of the logs. We don't need to talk about that part.

The question is, are all filters logs carrying logs automatically now? Or some fliters can, others can't. If it is later, then which filters still can't have the automatic injected trace contexts in their logs.

Is there any filter not supposed?

The GlobalFilter and GatewayFilter loaded by default by the Spring Gateway will also be intercepted. Do you think this is an unnecessary filter?

@wu-sheng
Copy link
Member

I didn't have a concept which interceptor is necessary or unnecessary.
I just wanted to setup a feature boundaries.
It is good enough now.

Could you polish the codes by review? I think we are almost good.

@yqw570994511
Copy link
Contributor Author

I didn't have a concept which interceptor is necessary or unnecessary. I just wanted to setup a feature boundaries. It is good enough now.

Could you polish the codes by review? I think we are almost good.

Thank you, I will adjust my code as follows

public class GatewayFilterInterceptor implements InstanceMethodsAroundInterceptor {

    private static final ThreadLocal<AtomicInteger> STACK_DEEP = ThreadLocal.withInitial(() -> new AtomicInteger(0));

    @Override
    public void beforeMethod(EnhancedInstance objInst, Method method, Object[] allArguments, Class<?>[] argumentsTypes,
                             MethodInterceptResult result) throws Throwable {
        if (isEntry()) {
            ServerWebExchange exchange = (ServerWebExchange) allArguments[0];

            EnhancedInstance enhancedInstance = getInstance(exchange);

            AbstractSpan span = ContextManager.createLocalSpan("SpringCloudGateway/GatewayFilter");
            if (enhancedInstance != null && enhancedInstance.getSkyWalkingDynamicField() != null) {
                ContextManager.continued((ContextSnapshot) enhancedInstance.getSkyWalkingDynamicField());
            }
            span.setComponent(SPRING_CLOUD_GATEWAY);
        }
    }

    public static EnhancedInstance getInstance(Object o) {
        EnhancedInstance instance = null;
        if (o instanceof DefaultServerWebExchange) {
            instance = (EnhancedInstance) o;
        } else if (o instanceof ServerWebExchangeDecorator) {
            ServerWebExchange delegate = ((ServerWebExchangeDecorator) o).getDelegate();
            return getInstance(delegate);
        }
        return instance;
    }

    @Override
    public Object afterMethod(EnhancedInstance objInst, Method method, Object[] allArguments, Class<?>[] argumentsTypes,
                              Object ret) throws Throwable {
        if (isExit()) {
            if (ContextManager.isActive()) {
                ContextManager.stopSpan();
            }
        }
        return ret;
    }

    @Override
    public void handleMethodException(EnhancedInstance objInst, Method method, Object[] allArguments,
                                      Class<?>[] argumentsTypes, Throwable t) {
        ContextManager.activeSpan().log(t);
    }

    private boolean isEntry() {
        return STACK_DEEP.get().getAndIncrement() == 0;
    }

    private boolean isExit() {
        boolean isExit = STACK_DEEP.get().decrementAndGet() == 0;
        if (isExit) {
            STACK_DEEP.remove();
        }
        return isExit;
    }
}

@wu-sheng
Copy link
Member

I posted this discussion according to your comments, apache/skywalking#12860

@wu-sheng wu-sheng merged commit be3d092 into apache:main Dec 16, 2024
193 checks passed
@yqw570994511 yqw570994511 deleted the feature_support_gateway_filter_trace_id branch December 16, 2024 07:14
@hyhyf
Copy link
Contributor

hyhyf commented Dec 27, 2024

Why ping me?

The tid of the log printed in the spring gateway interceptor is inconsistent with the tid of the log printed in the downstream service interceptor after forwarding. Is there any way to troubleshoot?

Maybe you need to add spring-cloud-gateway plugin to your projcet. @huicunjun

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
enhancement New feature or request plugin
Projects
None yet
Development

Successfully merging this pull request may close these issues.

5 participants