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

Accesslog Configuration does NOT work, while metadata-report configured. #5281

Closed
2 tasks done
jicro opened this issue Nov 5, 2019 · 3 comments
Closed
2 tasks done

Comments

@jicro
Copy link

jicro commented Nov 5, 2019

  • I have searched the issues of this repository and believe that this is not a duplicate.
  • I have checked the FAQ of this repository and believe that this is not a duplicate.

Environment

  • Dubbo version: 2.7.3(with maven groupId: org.apache.dubbo) (upgrade from 2.6.5 with groupId: com.alibaba)
  • Operating System version: CentOS Linux release 7.3.1611 (Core)
  • Java version: Oracle JDK 1.8

Steps to reproduce this issue

  1. (Dubbo 2.6.5) Provider-side program with provider.xml (Spring-Context-Configuration), which without metadata-report configuration. And accesslog enabled:
<dubbo:protocol name="dubbo" port="21881" server="netty" register="true" accesslog="logs/access.log"/>
    <!-- 接口的位置 -->
    <dubbo:service interface="xxx.xxx.xxxService"
                   ref="xxxService" timeout="10000" retries="3"
                   executes="100" loadbalance="leastactive"
                   accesslog="logs/access-xxx.log" register="true"
                   owner="jk" group="gp" version="1.0" />
  1. Launching the program, and accesslog print exactly.
  2. (Upgrade to 2.7.3) Enable metadata-report (I'm not sure whether this affects. Then I tried without metadata-report configuration, and it still not works.), with configuration:
<dubbo:metadata-report address="zookeeper://zk1.registry.gp.org:2181" cycle-report="false" sync-report="true"/>
  1. Restart the provider-side program, console got log:
2019-11-05 14:55:28  [DUBBO] You specified the config centre, but there's not even one single config item in it., dubbo version: 2.7.3, current host: 192.168.10.***
2019-11-05 14:55:28  [DUBBO] You specified the config centre, but there's not even one single config item in it., dubbo version: 2.7.3, current host: 192.168.10.***
2019-11-05 14:55:28  [DUBBO] There's no valid monitor config found, if you want to open monitor statistics for Dubbo, please make sure your monitor is configured properly., dubbo version: 2.7.3, current host: 192.168.10.***

and the accesslog file, which specified with path logs/access-xxx.log does NOT print any access log data.
5. Remove metadata-report configuration, and restart the provider-side program, the same scene appears in step 4.
6. I debugged the code, the AccessLogFilter class in dubbo-2.7.3.jar got an invoker with URL dubbo://192.168.10.xxx:20881/xxx.xxx.xxxService?accesslog=logs/access-xxx.log&anyhost=true&application=platform-xxx-provider&bean.name=xxx.xxx.xxxService&bind.ip=192.168.10.***&bind.port=20881&deprecated=false&dubbo=2.0.2&dynamic=true&executes=16&generic=false&group=gp&interface=xxx.xxx.xxxService&loadbalance=leastactive&methods=advanced,simple&owner=jk&pid=106617&qos.accept.foreign.ip=false&qos.enable=false&qos.port=33333&register=true&release=2.7.3&retries=3&revision=1.0.0&server=netty&side=provider&timeout=10000&timestamp=1572936930641&version=1.0
Here we got a parameter named accesslog in the URL, but the code retrieved dubbo.accesslog key which assigned by static final variable ACCESS_LOG_KEY in this class, and then got null value with accessLogKey variable during the invoke function below:

@Override
    public Result invoke(Invoker<?> invoker, Invocation inv) throws RpcException {
        try {
            String accessLogKey = invoker.getUrl().getParameter(ACCESS_LOG_KEY);
            if (ConfigUtils.isNotEmpty(accessLogKey)) {
                AccessLogData logData = buildAccessLogData(invoker, inv);
                log(accessLogKey, logData);
            }
        } catch (Throwable t) {
            logger.warn("Exception in AccessLogFilter of service(" + invoker + " -> " + inv + ")", t);
        }
        return invoker.invoke(inv);
    }

AND, I also tried the source code with dubbo-2.6.5 (maven groupId: com.alibaba), and got different Java implementation source bellow (Notice that, the Constants.ACCESS_LOG_KEY has value accesslog assigned, and same value in 2.7.3 with maven groupId: org.apache.dubbo):

@Override
    public Result invoke(Invoker<?> invoker, Invocation inv) throws RpcException {
        try {
            String accesslog = invoker.getUrl().getParameter(Constants.ACCESS_LOG_KEY);
            if (ConfigUtils.isNotEmpty(accesslog)) {
                RpcContext context = RpcContext.getContext();
                String serviceName = invoker.getInterface().getName();
                String version = invoker.getUrl().getParameter(Constants.VERSION_KEY);
                String group = invoker.getUrl().getParameter(Constants.GROUP_KEY);
   ...

BTW: The bugfix 4374 shows that this was fixed, but not specified the fixed version.

Expected Result

Those accesslog configurations should also work, or some other ways to meet the accesslog needs.
BTW: It seems that the AccessLogFilter.ACCESS_LOG_KEY used correctly, and value assigned correctly here. Since it works before metadata-report configured. But when metadata-report configured, it does not work. Is the URL value generated correctly?

Actual Result

I have read the documents of accesslog, but neither the Logging by logging framework part nor the Logging by specified file path part works.

If there is an exception, please attach the exception trace:

NO EXCEPTION. CONFIGURATION NOT WORK.
@jicro
Copy link
Author

jicro commented Nov 5, 2019

简单用中文描述一下踩到的坑(还在坑里没出来.....):
(1)自从2.6.5 (Maven groupId为com.alibaba)升级到2.7.3(Maven groupId为org.apache.dubbo)以后,在provider.xml配置文件中对应的accesslog的配置项不起作用了。
(2)在升级的过程中做了metadata-report的配置,一开始怀疑是由于这部分的配置导致dubbo从config centre获取配置,但是后来发现去掉这部分的配置仍然无法记录accesslog。
(3)换过两个provider端的程序(考虑到可能由于application-name重复导致的配置在ZK中存在了?),从未配置过metadata-report的程序在升级到2.7.3以后也是无法记录accesslog的。

(4)远程DEBUG了一波,发现2.7.3里面的AccessLogFilter会从invoker的URL中取参数项“dubbo.accesslog”(通过变量AccessLogFilter.ACCESS_LOG_KEY),但是URL中根本不存在这个项,对应在URL中存在的是“accesslog”配置项。
调试2.6.5版本的代码发现是通过“accesslog”(通过变量Constants.ACCESS_LOG_KEY)的配置项获取对应的值。

(5)因此分析,可能是由于升级后的版本代码变更后,对日志这部分进行了调整。通过查阅其它issue发现有说根据官网文档配置的方式。后来参考官方文档的Logging by logging framework小节配置了一波,发现能够创建配置的日志文件,但是不打印访问日志.....另外根据Logging by specified file path小节配置的就是原来的配置方法,不生效(不创建日志文件,也不打印日志)。

顺带建议一下:能否更新一下官网的文档?那文档太迷了....也不知道对应哪个版本。
github里面的wiki也存在文档不清晰的问题,有些配置区分admin.xxx 和dubbo.xxx,到底是啥效果也没说清楚....
希望Dubbo能越来越好,尽管Service Mesh被吹的挺厉害,但个人还是比较认可Dubbo,希望它能越来越完善。

@chickenlj
Copy link
Contributor

(4)远程DEBUG了一波,发现2.7.3里面的AccessLogFilter会从invoker的URL中取参数项“dubbo.accesslog”(通过变量AccessLogFilter.ACCESS_LOG_KEY),但是URL中根本不存在这个项,对应在URL中存在的是“accesslog”配置项。
调试2.6.5版本的代码发现是通过“accesslog”(通过变量Constants.ACCESS_LOG_KEY)的配置项获取对应的值。

在 2.7.3 中 AccessLogFilter 中的 ACCESS_LOG_KEY 定义和 org.apache.dubbo.rpc.Constants.ACCESS_LOG_KEY 存在重复, 导致了以上问题。我发现在 2.7.4.1 中被修复了

@jicro
Copy link
Author

jicro commented Nov 19, 2019

(4)远程DEBUG了一波,发现2.7.3里面的AccessLogFilter会从invoker的URL中取参数项“dubbo.accesslog”(通过变量AccessLogFilter.ACCESS_LOG_KEY),但是URL中根本不存在这个项,对应在URL中存在的是“accesslog”配置项。
调试2.6.5版本的代码发现是通过“accesslog”(通过变量Constants.ACCESS_LOG_KEY)的配置项获取对应的值。

在 2.7.3 中 AccessLogFilter 中的 ACCESS_LOG_KEY 定义和 org.apache.dubbo.rpc.Constants.ACCESS_LOG_KEY 存在重复, 导致了以上问题。我发现在 2.7.4.1 中被修复了

非常感谢,经测 2.7.4.1 版本已经可以正常使用了。

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

2 participants