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

Simple date format each time new object creation removed #3027

Closed

Conversation

khanimteyaz
Copy link
Contributor

What is the purpose of the change

AcceLogFilter message creation and last and current check was performing by each time simple date formate object creation. In this version of code I have use the ThreadLocal for each thread wise to create simple date format object instead of each call

#3026

Brief changelog

XXXXX

Verifying this change

Runnig UT and verifying generated access log.

Follow this checklist to help us incorporate your contribution quickly and easily:

  • Make sure there is a [GITHUB_issue] (AccessLogFilter simple date format reduce instance creation #3026) field for the change (usually before you start working on it). Trivial changes like typos do not require a GITHUB issue. Your pull request should address just this issue, without pulling in other changes - one PR resolves one issue.
  • Format the pull request title like [Dubbo-XXX] Fix UnknownException when host config not exist #XXX. Each commit in the pull request should have a meaningful subject line and body.
  • Write a pull request description that is detailed enough to understand what the pull request does, how, and why.
  • Write necessary unit-test to verify your logic correction, more mock a little better when cross module dependency exist. If the new feature or significant change is committed, please remember to add integration-test in test module.
  • Run mvn clean install -DskipTests=false & mvn clean test-compile failsafe:integration-test to make sure unit-test and integration-test pass.
  • If this contribution is large, please follow the Software Donation Guide.

@codecov-io
Copy link

codecov-io commented Dec 20, 2018

Codecov Report

Merging #3027 into master will decrease coverage by 0.03%.
The diff coverage is 60%.

Impacted file tree graph

@@            Coverage Diff             @@
##           master    #3027      +/-   ##
==========================================
- Coverage   64.24%   64.21%   -0.04%     
==========================================
  Files         584      584              
  Lines       26056    26059       +3     
  Branches     4562     4562              
==========================================
- Hits        16740    16734       -6     
- Misses       7132     7139       +7     
- Partials     2184     2186       +2
Impacted Files Coverage Δ
...annotation/ServiceAnnotationBeanPostProcessor.java 86.89% <ø> (ø) ⬆️
...ing/transport/netty4/NettyBackedChannelBuffer.java 19.04% <ø> (ø) ⬆️
...ava/org/apache/dubbo/common/utils/ConfigUtils.java 77.93% <ø> (ø) ⬆️
...apache/dubbo/rpc/filter/tps/DefaultTPSLimiter.java 66.66% <ø> (ø) ⬆️
...notation/ReferenceAnnotationBeanPostProcessor.java 76.38% <ø> (ø) ⬆️
...ting/transport/netty/NettyBackedChannelBuffer.java 0% <ø> (ø) ⬆️
...he/dubbo/common/io/UnsafeByteArrayInputStream.java 82.92% <ø> (ø) ⬆️
.../CompatibleServiceAnnotationBeanPostProcessor.java 0% <ø> (ø) ⬆️
...pc/cluster/support/wrapper/MockClusterInvoker.java 71.42% <ø> (ø) ⬆️
...a/org/apache/dubbo/remoting/exchange/Response.java 94.73% <ø> (ø) ⬆️
... and 27 more

Continue to review full report at Codecov.

Legend - Click here to learn more
Δ = absolute <relative> (impact), ø = not affected, ? = missing data
Powered by Codecov. Last update 1a06874...89e5485. Read the comment docs.

Copy link

@manzhizhen manzhizhen left a comment

Choose a reason for hiding this comment

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

Please format the code,haha

}
};

static ThreadLocal<SimpleDateFormat> MESSAGE_DATE_FORMATTER= new ThreadLocal<SimpleDateFormat>() {
Copy link
Member

Choose a reason for hiding this comment

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

Hi, khan
We have integrated Netty's FastThreadLocal in dubbo. I think we can use it instead of ThreadLocal. I suggest you refer to RpcContext.LOCAL.

Copy link
Contributor Author

@khanimteyaz khanimteyaz Dec 21, 2018

Choose a reason for hiding this comment

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

Thanks for suggesting this. I was looking into RpcContext code for LOCAL and SERVER_LOCAL implementation, I would like to go this approach.
I am very curious to know, the difference between LOCAL and SERVER_LOCAL here. Is LOCAL is used for when the call is from consumer and SERVER_LOCAL is used for,when call is served by SERVER? Is this understanding of mine is correct?

@@ -113,7 +127,7 @@ public Result invoke(Invoker<?> invoker, Invocation inv) throws RpcException {
String version = invoker.getUrl().getParameter(Constants.VERSION_KEY);
String group = invoker.getUrl().getParameter(Constants.GROUP_KEY);
StringBuilder sn = new StringBuilder();
sn.append("[").append(new SimpleDateFormat(MESSAGE_DATE_FORMAT).format(new Date())).append("] ").append(context.getRemoteHost()).append(":").append(context.getRemotePort())
sn.append("[").append(MESSAGE_DATE_FORMATTER.get().format(new Date())).append("] ").append(context.getRemoteHost()).append(":").append(context.getRemotePort())
Copy link
Member

Choose a reason for hiding this comment

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

Another thing we should consider is that when we clear the threadlocal's value.
Should we keep them in memory all the time?

Copy link
Contributor Author

Choose a reason for hiding this comment

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

@carryxyh
If the current thread which execute this invoke is from a thread pool then I think we should keep it because then it will be reusable and will avoid the time creating new date formatter object, otherwise we should remove it.
What would you suggest to me?

Copy link
Contributor Author

Choose a reason for hiding this comment

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

@carryxyh would you suggest is there any things I needs to change here?

Fixing some typos.
@beiwei30
Copy link
Member

If we can move all date time format into org.apache.dubbo.rpc.filter.AccessLogFilter.LogTask, then we can safely make the formatter static, since it is now running on a single thread.

@khanimteyaz
Copy link
Contributor Author

khanimteyaz commented Dec 21, 2018

If we can move all date time format into org.apache.dubbo.rpc.filter.AccessLogFilter.LogTask, then we can safely make the formatter static, since it is now running on a single thread.

@beiwei30

I am planning for move FILE_DATE_FORMATTER to LogTask level (as you are suggesting, i also beleive it will make sense) as this is created once for each log thread(which is currently single threaded). as of now to simply intiale SimpleDateFormat once per LogTask thread instance as it is created (as of now it is not served from thread pool, when we have thread pool can change it accordingly) and MESSAGE_DATE_FORMATTER to RpcContext level. Would you correct me if this approach has problem. Any guidance will be appreciated.

@khanimteyaz
Copy link
Contributor Author

Hi all, would you care to review it.

@khanimteyaz
Copy link
Contributor Author

@beiwei30, would you suggest here me any thing ?

@carryxyh
Copy link
Member

@khanimteyaz
Hi,
I have not found a LogTask in AccessLogFilter before. After I looked at the code, I personally thought that it would be fine to put all the log output into the LogTask.

I think we can use the newSingleThreadScheduledExecutor to create a timed task. This way we can just create a SimpleDateFormat once (bind to a LogTask).
How do u think?

@khanimteyaz
Copy link
Contributor Author

khanimteyaz commented Dec 26, 2018

@khanimteyaz
Hi,
I have not found a LogTask in AccessLogFilter before. After I looked at the code, I personally thought that it would be fine to put all the log output into the LogTask.

I think we can use the newSingleThreadScheduledExecutor to create a timed task. This way we can just create a SimpleDateFormat once (bind to a LogTask).
How do u think?

It make sense writing to log through this thread, but just to confirm you mean writing to log only, not the log message creation part?

Performing all write through single instance by **newSingleThreadScheduledExecutor ** is good approach and I am with you on this, only thing which is stoping me how in the case of writing pending log message in case of jvm shutdown. I think jdk provide a way for this and using the scheduleWithFixedDelay of ScheduledExecutorService.

@carryxyh
Do you feel, the approach I am taking is right or would you suggest me something else here on the implementation?

@carryxyh
Copy link
Member

@khanimteyaz
IMO, the log message will create and log in schedule thread.

how in the case of writing pending log message in case of jvm shutdown

What I may understand about this sentence is not very accurate. What you mean is, how do you write the pending information to a file at the end of the JVM? I think we can let the scheduled thread daemon.

Do you feel, the approach I am taking is right or would you suggest me something else here on the implementation?

I think we should change the logQueue to let us create log message in another thread.
Maybe like this: ConcurrentMap<String, Set<LogData>> logQueue. And then, our scheduled thread just check the queue regularly. This is my thought. After that, we can promise our log is print in only one thread and make the SimpleDateFormat single instance.

@khanimteyaz
Copy link
Contributor Author

@carryxyh

What I may understand about this sentence is not very accurate. What you mean is, how do you write the pending information to a file at the end of the JVM? I think we can let the scheduled thread daemon.

I am think I was wrong on the pending log message, thanks for correcting me and helping out here. Let the schedule thread to finish the pending task 😄

Regarding

I think we should change the logQueue to let us create log message in another thread.
Maybe like this: ConcurrentMap<String, Set> logQueue. And then, our scheduled thread just check the queue regularly. This is my thought. After that, we can promise our log is print in only one thread and make the SimpleDateFormat single instance.

I will make the changes accordingly.

@khanimteyaz
Copy link
Contributor Author

@carryxyh I have made the changes but builds failing due to travis log limit.

@carryxyh
Copy link
Member

Hi, seems like your pr has many commits of other persons.
Would u pls clear your pr first? I saw that this pr has changed about 600 lines code.

About the ci, I will have a look.

@khanimteyaz
Copy link
Contributor Author

Hi, seems like your pr has many commits of other persons.
Would u pls clear your pr first? I saw that this pr has changed about 600 lines code.

About the ci, I will have a look.

Sure. on it.

@khanimteyaz khanimteyaz deleted the acesslog-dateformat-enhancemnet branch December 27, 2018 08:55
@khanimteyaz
Copy link
Contributor Author

I will create a new branch where, would raised all the changes with all recommendation

khanimteyaz added a commit to khanimteyaz/incubator-dubbo that referenced this pull request Dec 27, 2018
@khanimteyaz
Copy link
Contributor Author

@carryxyh created another PR for the same #3080

As I am not sure how to reduce number of commit from existing PR, so created a new one. Sorry for the inconvenience.
Would request you to guide on this, how to reduce or clear other's commit from existing one, so that next time I can avoid creating separate PR.

khanimteyaz added a commit to khanimteyaz/incubator-dubbo that referenced this pull request Dec 28, 2018
@khanimteyaz khanimteyaz mentioned this pull request Dec 28, 2018
6 tasks
@khanimteyaz khanimteyaz mentioned this pull request Jan 18, 2019
6 tasks
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

Successfully merging this pull request may close these issues.

6 participants