Acesslog dateformat enhancemnet #3090

khanimteyaz · 2018-12-28T16:08:25Z

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

In this PR

I have moved the access log creation and writing to file into a single thread and reusing a single instance of SimpleDateFormat
Refactored code to separate our and group related task in separate method and have enhance the readability by using
- Method naming
- Reducing big methods to small.

This PR is a resurrection of old PR

3027 (Simple date format each time new object creation removed #3027) PR
3080 (Simple date format each time new object creation removed #3080)
Sorry for the inconvenience

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.

Update from upstream

master synch

Sync of master

Master sync

codecov-io · 2018-12-28T16:33:23Z

Codecov Report

Merging #3090 into master will increase coverage by 0.21%.
The diff coverage is 85.4%.

@@             Coverage Diff              @@
##             master    #3090      +/-   ##
============================================
+ Coverage      63.5%   63.72%   +0.21%     
  Complexity       75       75              
============================================
  Files           653      654       +1     
  Lines         28251    28256       +5     
  Branches       4816     4781      -35     
============================================
+ Hits          17942    18005      +63     
+ Misses         8040     7997      -43     
+ Partials       2269     2254      -15

Impacted Files	Coverage Δ	Complexity Δ
...n/java/org/apache/dubbo/common/utils/DateUtil.java	`100% <100%> (ø)`	`0 <0> (?)`
...a/org/apache/dubbo/rpc/filter/AccessLogFilter.java	`83.33% <80.95%> (+12.22%)`	`0 <0> (ø)`	⬇️
...va/org/apache/dubbo/rpc/support/AccessLogData.java	`88.73% <88.73%> (ø)`	`0 <0> (?)`
.../remoting/transport/netty4/NettyClientHandler.java	`75% <0%> (-11.12%)`	`0% <0%> (ø)`
...bo/rpc/cluster/support/FailbackClusterInvoker.java	`67.21% <0%> (-8.2%)`	`0% <0%> (ø)`
...ng/zookeeper/zkclient/ZkclientZookeeperClient.java	`55% <0%> (-7.75%)`	`0% <0%> (ø)`
...ava/org/apache/dubbo/rpc/cluster/Configurator.java	`92.3% <0%> (-7.7%)`	`0% <0%> (ø)`
...onfig/spring/extension/SpringExtensionFactory.java	`78.04% <0%> (-7.32%)`	`0% <0%> (ø)`
...apache/dubbo/remoting/transport/AbstractCodec.java	`76.92% <0%> (-3.85%)`	`0% <0%> (ø)`
...dubbo/remoting/exchange/support/DefaultFuture.java	`71.81% <0%> (-3.36%)`	`0% <0%> (ø)`
... and 99 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 09cbf8f...154b560. Read the comment docs.

khanimteyaz · 2018-12-28T16:33:34Z

@carryxyh could you please review this.

beiwei30 · 2018-12-29T03:00:21Z

I didn't look into the change closely, but it looks like we are now moving the date formatter into one single thread to avoid contention completely, which I believe it is the right direction as I pointed out in the old pull request :)

zonghaishang

not thread safe

khanimteyaz · 2018-12-30T07:19:01Z

@zonghaishang
Whole log parsing and writing is happening in a single thread environment , irrespective of invokes. Would you provide more details so that I can fix it if I can ?

khanimteyaz · 2019-01-03T06:43:54Z

@zonghaishang could you please provide the details about the thread safety so that I can work on this?

@beiwei30 Is there something to incorporate which you feel here?

carryxyh

I think we can make the log queue static.
What do u think?

carryxyh · 2019-01-04T06:32:08Z

dubbo-rpc/dubbo-rpc-api/src/main/java/org/apache/dubbo/rpc/filter/AccessLogFilter.java

-        }
-        if (logSet.size() < LOG_MAX_BUFFER) {
-            logSet.add(logmessage);
+    private static final InternalThreadLocal<SimpleDateFormat> INLINE_MESSAGE_DATE_FORMATTER = new InternalThreadLocal<SimpleDateFormat>() {


Seems like this filed is never used.

yes. I will remove it.

carryxyh · 2019-01-04T06:32:50Z

dubbo-rpc/dubbo-rpc-api/src/main/java/org/apache/dubbo/rpc/filter/AccessLogFilter.java


-    private volatile ScheduledFuture<?> logFuture = null;
+    private final ConcurrentMap<String, Set<AccessLogData>> logQueue = new ConcurrentHashMap<String, Set<AccessLogData>>();


Can this field be static?

I think it make sense now to make it static as it is now bound to single thread.

In addition to this, I was thinking (correct me If I am wrong), instead of defining the logQueue as a member of this class, we can it get through a factory (although factory will supply single queue only), so that in future even if we have change it based on our defined we don't have to touch this class. May be we can do this as part of separate PR. What do you say?

emmm...
What is this factory produce? Maybe I haven't get your point~ Can u give more details?

it provide the storage object which its consumer object,

e.g.

Store store= InMemoryQueueStorageFactory.getInstance().getStore(); store.add(accessLog);

something like above. The above example what I hvae given may not be very intuitive itself for explaination, but for high level understanding it might help. If you want I might create a sample branch to demonestrate in more detail way by having some implementation. What do you say?

Personally think that it is not necessary, because it will make the code more complicated. I think that the current structure is relatively simple, haha.

dubbo-rpc/dubbo-rpc-api/src/main/java/org/apache/dubbo/rpc/filter/AccessLogFilter.java

carryxyh · 2019-01-04T06:35:44Z

dubbo-rpc/dubbo-rpc-api/src/main/java/org/apache/dubbo/rpc/filter/AccessLogFilter.java

-                        } catch (Exception e) {
-                            logger.error(e.getMessage(), e);
+    private void log(String accessLog, AccessLogData accessLogData) {
+        Set<AccessLogData> logSet = logQueue.get(accessLog);


Can we use computeIfAbsent to optimize this?

dubbo-rpc/dubbo-rpc-api/src/main/java/org/apache/dubbo/rpc/support/AccessLogData.java

khanimteyaz · 2019-01-04T09:45:30Z

@carryxyh I have made the changes, would you plz review it.

carryxyh · 2019-01-04T09:47:39Z

@khanimteyaz
nice work!
I will take a look.

khanimteyaz · 2019-01-07T15:26:12Z

@zonghaishang would you care to provide some detail on the thread safety, so that I can incorporate them? FYI I have provided the comment in previous section about the implementation.

khanimteyaz · 2019-01-10T16:35:49Z

I have updated with comment, would you review my pr?

carryxyh · 2019-01-11T02:29:23Z

@zonghaishang
Hi, yiji, would u pls check this pr again?

@khanimteyaz
Let's wait for his feedback. Seems like yiji is very busy recently. :)

jasonjoo2010 · 2019-01-11T03:19:00Z

Why not introducing FastDateFormat?

I think it's more simple and make sense.

carryxyh · 2019-01-11T03:29:10Z

@jasonjoo2010
Is the class thread-safe?

jasonjoo2010 · 2019-01-11T04:02:42Z

@jasonjoo2010
Is the class thread-safe?

Yes, it's thread-safe by implemented no sharing data and also including instances cache.

Generally we can just call FastDataFormat.getInstance("yyyyMMdd") as same as new SimpleDateFormat("yyyyMMdd").

carryxyh · 2019-01-11T04:09:37Z

@khanimteyaz
Would pls check whether 'FastDataFormat' is better?
:)

Thx for your suggestion. @jasonjoo2010

jasonjoo2010 · 2019-01-11T05:38:17Z

@khanimteyaz
Would pls check whether 'FastDataFormat' is better?
:)

Thx for your suggestion. @jasonjoo2010

But it's in commons-lang or commons-lang3 library maybe we need introduce a new library to project. It's the only point.

lixiaojiee · 2019-01-11T06:38:54Z

SimpleDateFormat is not thread-safe, which is why we have to create new objects every time before. I did some research. Java8 currently has a thread-safe date tool called LocalDateTime. After reviewing @jasonjoo2010 's recommendation, I did some testing and found that FastDateFormat performs much better than the other two. Therefore, I also recommend FastDateFormat, but I prefer to bring it into the dubbo-commom package as a common date tool for other modules to reuse.You can refer to the data in the table below. The first column is the number of samples, and the following data is the average time corresponding to each sample in ms.

	SimpleDateFormat	FastDateFormat	LocalDateTime
10	3	1	77
100	10	4	83
1000	54	26	137
10000	170	52	168
100000	470	153	341
1000000	1827	501	1024
10000000	11591	3473	6228

Note : For environmental reasons, the above data are for reference only

carryxyh · 2019-01-11T07:05:58Z

Do we copy code into dubbo?
Seems like we can depend on common-langs package.

Release resource after use in ConfigParserTest

add javadoc for registry and optimize code

* code optimization * useless import * optimization

code optimization

Add javadoc for dubbo-serialization module(apache#3002).

* optimize log output * Separate logs for reconnect and close * remove reconnect exception log

* modify some log describe * use java8 lambda expression

* fix telnet trace times is always 1 * use StringUtils determine if the string is empty * Fix 3105 , make invoke command with Json string parameter without "class" key * Fix 3105 ，Keep the class key to support overloaded methods * optimize InvokerTelnetHandlerTest

* upgrade junit to junit5 * modify test * 批量修改upgrade_junt_to_junit5 * 删除多余的文件 * fi test case * Disabled soem test case temporarily * upgrade junit to junit5 and batch modify test case * copy some code from jupiter5.4.0.M1 for some issues * 修改rat福泽 * update rat path * revert case * add junit-platform-surefire-provider to maven-surefire-plugin * update dependency * fix coverage issue (#1) * use jupiter 5.4.0-M1 and remove junit5 source code

)

…backService method issue. (apache#3199) * Optimize the code: fix url to null, NullPointerException, change private variable to camel mode. * Optimize the code: exportOrUnexportCallbackService method camel mode. * Optimize the code: fix method:encodeInvocationArgument private callbackStatus is camel writing. * Optimize the code: fix name issue * Exporter is a noun, we should use a verb here, like Export. * The generics that can be inferred automatically are also deleted.

* refactor telnet invoke command * add select command for telnet * fix test case

* wrong event setting * modify event seeting * modify

* Code optimization, call the util method * mofidy * modify * * import package

* qos heart question fix apache#3165 * modify * judge if it's a IdleStateEvent * add UT * modify

* modify some typos * fix some other addionalParameterKeys and paramter typos

* must shutdown thread pool when no in use

khanimteyaz and others added 8 commits December 7, 2018 00:57

Merge pull request #1 from apache/master

4704218

Update from upstream

Merge pull request #3 from apache/master

3c972a1

master synch

Merge pull request #4 from apache/master

6eaf970

Sync of master

Merge pull request #6 from apache/master

61dfa3c

Master sync

Merge pull request #7 from apache/master

565aa1a

Master sync

Merge pull request #8 from apache/master

5b67c0f

Master sync

Merge pull request #9 from apache/master

a868472

Master sync

review comment incorporated

a3592ed

zonghaishang approved these changes Dec 30, 2018

View reviewed changes

zonghaishang requested changes Dec 30, 2018

View reviewed changes

carryxyh reviewed Jan 4, 2019

View reviewed changes

khanimteyaz added 2 commits January 4, 2019 13:12

incorporated PR review comment

2f60558

incorporated PR review comment

47ca7c4

CrazyHZM and others added 27 commits January 18, 2019 21:40

Remove unused code, fix apache#3070 (apache#3073)

e0f960a

Add monitor module javadoc (apache#3121)

d54cb41

Release resource after use in ConfigParserTest (apache#3127)

04abe1d

Release resource after use in ConfigParserTest

add javadoc for registry and some code (apache#3140)

ab145f3

add javadoc for registry and optimize code

Correct spelling error (apache#3146)

fdf7175

Code optimization (apache#3118)

1e31df6

* code optimization * useless import * optimization

Code rule (apache#3016)

8ce6970

code optimization (apache#3167)

d9df5e2

code optimization

Add javadoc for dubbo-serialization module(apache#3002). (apache#3004)

77dbfbe

Add javadoc for dubbo-serialization module(apache#3002).

optimize ReconnectTimerTask's log output (apache#3162)

b727493

* optimize log output * Separate logs for reconnect and close * remove reconnect exception log

add some small optimize (apache#3171)

83b7e11

* modify some log describe * use java8 lambda expression

Format change.

83c67b1

fix wrong word spelling (apache#3217)

db431e5

Fix provicer --> provider (apache#3222)

dfad45d

Optimize the code: use logger instead of printStackTrace(). (apache#3202

a2a7531

)

Optimize code: remove unnecessary judgment code. (apache#3196)

2cb3d7c

Refactor telnet invoke command (apache#3210)

fddc018

* refactor telnet invoke command * add select command for telnet * fix test case

Modified to lower camel case (apache#3003)

0458509

wrong event setting (apache#3043)

1fd071a

* wrong event setting * modify event seeting * modify

call the util method (apache#3230)

e07735b

* Code optimization, call the util method * mofidy * modify * * import package

Qos heart (apache#3170)

ad7497e

* qos heart question fix apache#3165 * modify * judge if it's a IdleStateEvent * add UT * modify

remove getContext() (apache#3235)

b463bb7

modify some typos (apache#3257)

3ba5c8c

* modify some typos * fix some other addionalParameterKeys and paramter typos

must shutdown thread pool when no in use (apache#3255)

8893944

* must shutdown thread pool when no in use

khanimteyaz closed this Jan 18, 2019

khanimteyaz deleted the acesslog-dateformat-enhancemnet branch January 18, 2019 19:01

khanimteyaz mentioned this pull request Jan 18, 2019

Acesslog dateformat enhancemnet #3274

Merged

6 tasks

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Acesslog dateformat enhancemnet #3090

Acesslog dateformat enhancemnet #3090

khanimteyaz commented Dec 28, 2018

codecov-io commented Dec 28, 2018 •

edited

Loading

khanimteyaz commented Dec 28, 2018

beiwei30 commented Dec 29, 2018

zonghaishang left a comment

khanimteyaz commented Dec 30, 2018 •

edited

Loading

khanimteyaz commented Jan 3, 2019

carryxyh left a comment

carryxyh Jan 4, 2019

khanimteyaz Jan 4, 2019

khanimteyaz Jan 4, 2019

carryxyh Jan 4, 2019

khanimteyaz Jan 4, 2019

carryxyh Jan 4, 2019

khanimteyaz Jan 4, 2019

carryxyh Jan 4, 2019

khanimteyaz Jan 4, 2019

carryxyh Jan 4, 2019

khanimteyaz Jan 4, 2019

khanimteyaz commented Jan 4, 2019

carryxyh commented Jan 4, 2019

khanimteyaz commented Jan 7, 2019

khanimteyaz commented Jan 10, 2019

carryxyh commented Jan 11, 2019

jasonjoo2010 commented Jan 11, 2019

carryxyh commented Jan 11, 2019

jasonjoo2010 commented Jan 11, 2019

carryxyh commented Jan 11, 2019

jasonjoo2010 commented Jan 11, 2019

lixiaojiee commented Jan 11, 2019 •

edited

Loading

carryxyh commented Jan 11, 2019


		private volatile ScheduledFuture<?> logFuture = null;
		private final ConcurrentMap<String, Set<AccessLogData>> logQueue = new ConcurrentHashMap<String, Set<AccessLogData>>();

Acesslog dateformat enhancemnet #3090

Acesslog dateformat enhancemnet #3090

Conversation

khanimteyaz commented Dec 28, 2018

What is the purpose of the change

Brief changelog

Verifying this change

codecov-io commented Dec 28, 2018 • edited Loading

Codecov Report

khanimteyaz commented Dec 28, 2018

beiwei30 commented Dec 29, 2018

zonghaishang left a comment

Choose a reason for hiding this comment

khanimteyaz commented Dec 30, 2018 • edited Loading

khanimteyaz commented Jan 3, 2019

carryxyh 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

khanimteyaz commented Jan 4, 2019

carryxyh commented Jan 4, 2019

khanimteyaz commented Jan 7, 2019

khanimteyaz commented Jan 10, 2019

carryxyh commented Jan 11, 2019

jasonjoo2010 commented Jan 11, 2019

carryxyh commented Jan 11, 2019

jasonjoo2010 commented Jan 11, 2019

carryxyh commented Jan 11, 2019

jasonjoo2010 commented Jan 11, 2019

lixiaojiee commented Jan 11, 2019 • edited Loading

carryxyh commented Jan 11, 2019

codecov-io commented Dec 28, 2018 •

edited

Loading

khanimteyaz commented Dec 30, 2018 •

edited

Loading

lixiaojiee commented Jan 11, 2019 •

edited

Loading