You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@doris.apache.org by GitBox <gi...@apache.org> on 2020/10/19 12:11:10 UTC
[GitHub] [incubator-doris] caiconghui opened a new pull request #4766: Make some debug log settings configurable and change some log level from info to debug to escape performance bottlenecks
caiconghui opened a new pull request #4766:
URL: https://github.com/apache/incubator-doris/pull/4766
## Proposed changes
1. Make some debug log settings configurable.
2. Change some log level from info to debug to escape performance bottlenecks
3. The output log remains compatible with the previous one, but user can close it by verbose log settings
## Types of changes
What types of changes does your code introduce to Doris?
_Put an `x` in the boxes that apply_
- [] Bugfix (non-breaking change which fixes an issue)
- [] New feature (non-breaking change which adds functionality)
- [] Breaking change (fix or feature that would cause existing functionality to not work as expected)
- [] Documentation Update (if none of the other choices apply)
- [] Code refactor (Modify the code structure, format the code, etc...)
## Checklist
_Put an `x` in the boxes that apply. You can also fill these out after creating the PR. If you're unsure about any of them, don't hesitate to ask. We're here to help! This is simply a reminder of what we are going to look for before merging your code._
- [x] I have create an issue on (Fix #4765 ), and have described the bug/feature there in detail
- [] Compiling and unit tests pass locally with my changes
- [] I have added tests that prove my fix is effective or that my feature works
- [] If this change need a document change, I have updated the document
- [] Any dependent changes have been merged
## Further comments
If this is a relatively large or complex change, kick off the discussion at dev@doris.apache.org by explaining why you chose the solution you did and what alternatives you considered, etc...
----------------------------------------------------------------
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
---------------------------------------------------------------------
To unsubscribe, e-mail: commits-unsubscribe@doris.apache.org
For additional commands, e-mail: commits-help@doris.apache.org
[GitHub] [incubator-doris] kangkaisen commented on a change in pull request #4766: Make some debug log settings configurable and change some log level from info to debug to avoid performance bottlenecks
Posted by GitBox <gi...@apache.org>.
kangkaisen commented on a change in pull request #4766:
URL: https://github.com/apache/incubator-doris/pull/4766#discussion_r510575761
##########
File path: fe/fe-core/src/main/java/org/apache/doris/service/FrontendServiceImpl.java
##########
@@ -634,9 +634,7 @@ public TFeResult loadCheck(TLoadCheckRequest request) throws TException {
@Override
public TLoadTxnBeginResult loadTxnBegin(TLoadTxnBeginRequest request) throws TException {
Review comment:
I think all txn related logs should be info level, not debug.
----------------------------------------------------------------
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
---------------------------------------------------------------------
To unsubscribe, e-mail: commits-unsubscribe@doris.apache.org
For additional commands, e-mail: commits-help@doris.apache.org
[GitHub] [incubator-doris] caiconghui commented on a change in pull request #4766: Make some debug log settings configurable and change some log level from info to debug to escape performance bottlenecks
Posted by GitBox <gi...@apache.org>.
caiconghui commented on a change in pull request #4766:
URL: https://github.com/apache/incubator-doris/pull/4766#discussion_r509026070
##########
File path: fe/fe-core/src/main/java/org/apache/doris/service/FrontendServiceImpl.java
##########
@@ -712,7 +712,7 @@ private long loadTxnBeginImpl(TLoadTxnBeginRequest request, String clientIp) thr
@Override
public TLoadTxnCommitResult loadTxnCommit(TLoadTxnCommitRequest request) throws TException {
String clientAddr = getClientAddrAsString();
- LOG.info("receive txn commit request. db: {}, tbl: {}, txn id: {}, backend: {}",
+ LOG.debug("receive txn commit request. db: {}, tbl: {}, txn id: {}, backend: {}",
Review comment:
done
----------------------------------------------------------------
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
---------------------------------------------------------------------
To unsubscribe, e-mail: commits-unsubscribe@doris.apache.org
For additional commands, e-mail: commits-help@doris.apache.org
[GitHub] [incubator-doris] caiconghui edited a comment on pull request #4766: Make some debug log settings configurable and change some log level from info to debug to avoid performance bottlenecks
Posted by GitBox <gi...@apache.org>.
caiconghui edited a comment on pull request #4766:
URL: https://github.com/apache/incubator-doris/pull/4766#issuecomment-714980396
> > Change some log level from info to debug to escape performance bottlenecks
>
> Are you sure the log is the FE performance bottlenecks? did you do any test or benchmark?
the heavy work is still stream load and tablet schedule in fe, but log in FrontendServiceImpl make thing worse when cpu load is higher, we found that all stream load request failed when qps is higher because all threads(the limit is 4096) in fe blocked in db lock or log lock, and cannot process any request. just like the issue(#4765) mentioned.
and I test the log performance in local machine with 8 logic core.
```
LOG.info("start to test bench mark for log info");
int totalThread = 4000;
TStreamLoadPutRequest request = new TStreamLoadPutRequest("test", "test", "test", "test", null, 1111L, null, null);
CountDownLatch cdl = new CountDownLatch(totalThread);
long startTime = System.currentTimeMillis();
for (int i = 0; i < totalThread; i++) {
new Thread(new Runnable() {
@Override
public void run() {
for (int j = 0; j < 5000; j++) {
LOG.info("receive stream load put request. db:{}, tbl: {}, txn id: {}, load id: {}, backend: {}",
request.getDb(), request.getTbl(), request.getTxnId(), DebugUtil.printId(request.getLoadId()),
"localhost");
}
cdl.countDown();
}
}).start();
}
cdl.await();
long endTime = System.currentTimeMillis();
LOG.info("finish to test bench mark log info cost {} ms", endTime - startTime);
System.exit(-1);
```
it cost about 149388ms, every log cost about 0.06ms.
by the way, our fe log is heavy because of frequent stream load request which may have many rpc request, so we set the log in
FrontendServiceImpl from info level to debug level, but still keep it open, so that other user can still see the log, but we can close the log switch in FrontendServiceImpl which is useless for use at most of time.
Maybe the title is not accurate description for this PR.
----------------------------------------------------------------
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
---------------------------------------------------------------------
To unsubscribe, e-mail: commits-unsubscribe@doris.apache.org
For additional commands, e-mail: commits-help@doris.apache.org
[GitHub] [incubator-doris] kangkaisen commented on pull request #4766: Make some debug log settings configurable and change some log level from info to debug to avoid performance bottlenecks
Posted by GitBox <gi...@apache.org>.
kangkaisen commented on pull request #4766:
URL: https://github.com/apache/incubator-doris/pull/4766#issuecomment-715175538
@caiconghui I see. Thank you.
----------------------------------------------------------------
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
---------------------------------------------------------------------
To unsubscribe, e-mail: commits-unsubscribe@doris.apache.org
For additional commands, e-mail: commits-help@doris.apache.org
[GitHub] [incubator-doris] caiconghui commented on a change in pull request #4766: Make some debug log settings configurable and change some log level from info to debug to escape performance bottlenecks
Posted by GitBox <gi...@apache.org>.
caiconghui commented on a change in pull request #4766:
URL: https://github.com/apache/incubator-doris/pull/4766#discussion_r509853058
##########
File path: fe/fe-core/src/main/java/org/apache/doris/service/FrontendServiceImpl.java
##########
@@ -827,7 +823,7 @@ private void loadTxnRollbackImpl(TLoadTxnRollbackRequest request) throws UserExc
@Override
public TStreamLoadPutResult streamLoadPut(TStreamLoadPutRequest request) {
String clientAddr = getClientAddrAsString();
- LOG.info("receive stream load put request. db:{}, tbl: {}, txn id: {}, load id: {}, backend: {}",
+ LOG.debug("receive stream load put request. db:{}, tbl: {}, txn id: {}, load id: {}, backend: {}",
Review comment:
done
##########
File path: fe/fe-core/src/main/java/org/apache/doris/service/FrontendServiceImpl.java
##########
@@ -778,7 +774,7 @@ private boolean loadTxnCommitImpl(TLoadTxnCommitRequest request) throws UserExce
@Override
public TLoadTxnRollbackResult loadTxnRollback(TLoadTxnRollbackRequest request) throws TException {
String clientAddr = getClientAddrAsString();
- LOG.info("receive txn rollback request. db: {}, tbl: {}, txn id: {}, reason: {}, backend: {}",
+ LOG.debug("receive txn rollback request. db: {}, tbl: {}, txn id: {}, reason: {}, backend: {}",
Review comment:
done
----------------------------------------------------------------
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
---------------------------------------------------------------------
To unsubscribe, e-mail: commits-unsubscribe@doris.apache.org
For additional commands, e-mail: commits-help@doris.apache.org
[GitHub] [incubator-doris] kangkaisen commented on pull request #4766: Make some debug log settings configurable and change some log level from info to debug to avoid performance bottlenecks
Posted by GitBox <gi...@apache.org>.
kangkaisen commented on pull request #4766:
URL: https://github.com/apache/incubator-doris/pull/4766#issuecomment-714889069
>Change some log level from info to debug to escape performance bottlenecks
Are you sure the log is the FE performance bottlenecks? did you do any test or benchmark?
----------------------------------------------------------------
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
---------------------------------------------------------------------
To unsubscribe, e-mail: commits-unsubscribe@doris.apache.org
For additional commands, e-mail: commits-help@doris.apache.org
[GitHub] [incubator-doris] caiconghui commented on a change in pull request #4766: Make some debug log settings configurable and change some log level from info to debug to escape performance bottlenecks
Posted by GitBox <gi...@apache.org>.
caiconghui commented on a change in pull request #4766:
URL: https://github.com/apache/incubator-doris/pull/4766#discussion_r509026014
##########
File path: fe/fe-core/src/main/java/org/apache/doris/service/FrontendServiceImpl.java
##########
@@ -634,7 +634,7 @@ public TFeResult loadCheck(TLoadCheckRequest request) throws TException {
@Override
public TLoadTxnBeginResult loadTxnBegin(TLoadTxnBeginRequest request) throws TException {
String clientAddr = getClientAddrAsString();
- LOG.info("receive txn begin request, db: {}, tbl: {}, label: {}, backend: {}",
+ LOG.debug("receive txn begin request, db: {}, tbl: {}, label: {}, backend: {}",
Review comment:
done
----------------------------------------------------------------
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
---------------------------------------------------------------------
To unsubscribe, e-mail: commits-unsubscribe@doris.apache.org
For additional commands, e-mail: commits-help@doris.apache.org
[GitHub] [incubator-doris] caiconghui edited a comment on pull request #4766: Make some debug log settings configurable and change some log level from info to debug to avoid performance bottlenecks
Posted by GitBox <gi...@apache.org>.
caiconghui edited a comment on pull request #4766:
URL: https://github.com/apache/incubator-doris/pull/4766#issuecomment-714980396
> > Change some log level from info to debug to escape performance bottlenecks
>
> Are you sure the log is the FE performance bottlenecks? did you do any test or benchmark?
the heavy work is still stream load and tablet schedule in fe, but log in FrontendServiceImpl make thing worse when cpu load is higher, we found that all stream load request failed when qps is higher because all threads(the limit is 4096) in fe blocked in db lock or log lock, and cannot process any request. just like the issue(#4765) mentioned.
and I test the log performance in local machine with 8 logic core.
```
LOG.info("start to test bench mark for log info");
int totalThread = 4000;
TStreamLoadPutRequest request = new TStreamLoadPutRequest("test", "test", "test", "test", null, 1111L, null, null);
CountDownLatch cdl = new CountDownLatch(totalThread);
long startTime = System.currentTimeMillis();
for (int i = 0; i < totalThread; i++) {
new Thread(new Runnable() {
@Override
public void run() {
for (int j = 0; j < 5000; j++) {
LOG.info("receive stream load put request. db:{}, tbl: {}, txn id: {}, load id: {}, backend: {}",
request.getDb(), request.getTbl(), request.getTxnId(), DebugUtil.printId(request.getLoadId()),
"localhost");
}
cdl.countDown();
}
}).start();
}
cdl.await();
long endTime = System.currentTimeMillis();
LOG.info("finish to test bench mark log info cost {} ms", endTime - startTime);
System.exit(-1);
```
it cost about 149388ms, every log cost about 0.06ms.
by the way, our fe log is heavy because of frequent stream load request which may have many rpc request, so we set the log in
FrontendServiceImpl from info level to debug level, but still keep it open, so that other user can still see the log, but we can close Close the log switch in FrontendServiceImpl which is useless for use at most of time.
----------------------------------------------------------------
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
---------------------------------------------------------------------
To unsubscribe, e-mail: commits-unsubscribe@doris.apache.org
For additional commands, e-mail: commits-help@doris.apache.org
[GitHub] [incubator-doris] caiconghui edited a comment on pull request #4766: Make some debug log settings configurable and change some log level from info to debug to avoid performance bottlenecks
Posted by GitBox <gi...@apache.org>.
caiconghui edited a comment on pull request #4766:
URL: https://github.com/apache/incubator-doris/pull/4766#issuecomment-714980396
> > Change some log level from info to debug to escape performance bottlenecks
>
> Are you sure the log is the FE performance bottlenecks? did you do any test or benchmark?
the heavy work is still stream load and tablet schedule in fe, but log in FrontendServiceImpl make thing worse when cpu load is higher, we found that all stream load request failed when qps is higher because all threads(the limit is 4096) in fe blocked in db lock or log lock, and cannot process any request. just like the issue(#4765) mentioned.
and I test the log performance in local machine with 8 logic core.
```
LOG.info("start to test bench mark for log info");
int totalThread = 4000;
TStreamLoadPutRequest request = new TStreamLoadPutRequest("test", "test", "test", "test", null, 1111L, null, null);
CountDownLatch cdl = new CountDownLatch(totalThread);
long startTime = System.currentTimeMillis();
for (int i = 0; i < totalThread; i++) {
new Thread(new Runnable() {
@Override
public void run() {
for (int j = 0; j < 5000; j++) {
LOG.info("receive stream load put request. db:{}, tbl: {}, txn id: {}, load id: {}, backend: {}",
request.getDb(), request.getTbl(), request.getTxnId(), DebugUtil.printId(request.getLoadId()),
"localhost");
}
cdl.countDown();
}
}).start();
}
cdl.await();
long endTime = System.currentTimeMillis();
LOG.info("finish to test bench mark log info cost {} ms", endTime - startTime);
System.exit(-1);
```
it cost about 149388ms, every log cost about 0.075ms.
by the way, our fe log is heavy because of frequent stream load request which may have many rpc request, so we set the log in
FrontendServiceImpl from info level to debug level, but still keep it open, so that other user can still see the log, but we can close the log switch in FrontendServiceImpl which is useless for use at most of time.
Maybe the title is not accurate description for this PR.
----------------------------------------------------------------
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
---------------------------------------------------------------------
To unsubscribe, e-mail: commits-unsubscribe@doris.apache.org
For additional commands, e-mail: commits-help@doris.apache.org
[GitHub] [incubator-doris] caiconghui commented on pull request #4766: Make some debug log settings configurable and change some log level from info to debug to avoid performance bottlenecks
Posted by GitBox <gi...@apache.org>.
caiconghui commented on pull request #4766:
URL: https://github.com/apache/incubator-doris/pull/4766#issuecomment-714980396
> > Change some log level from info to debug to escape performance bottlenecks
>
> Are you sure the log is the FE performance bottlenecks? did you do any test or benchmark?
the heavy work is still stream load and tablet schedule in fe, but log in FrontendServiceImpl make thing worse when cpu load is higher, we found that all stream load request failed when qps is higher because all threads(the limit is 4096) in fe blocked in db lock or log lock, and cannot processed any request. just like the issue(#4765) mentioned.
and I test the log performance in local machine with 8 logic core.
```
LOG.info("start to test bench mark for log info");
int totalThread = 4000;
TStreamLoadPutRequest request = new TStreamLoadPutRequest("test", "test", "test", "test", null, 1111L, null, null);
CountDownLatch cdl = new CountDownLatch(totalThread);
long startTime = System.currentTimeMillis();
for (int i = 0; i < totalThread; i++) {
new Thread(new Runnable() {
@Override
public void run() {
for (int j = 0; j < 5000; j++) {
LOG.info("receive stream load put request. db:{}, tbl: {}, txn id: {}, load id: {}, backend: {}",
request.getDb(), request.getTbl(), request.getTxnId(), DebugUtil.printId(request.getLoadId()),
"localhost");
}
cdl.countDown();
}
}).start();
}
cdl.await();
long endTime = System.currentTimeMillis();
LOG.info("finish to test bench mark log info cost {} ms", endTime - startTime);
System.exit(-1);
```
it cost about 149388ms, every log cost about 0.06ms.
by the way, our fe log is heavy because of frequent stream load request which may have many rpc request, so we set the log in
FrontendServiceImpl from info level to debug level, but still keep it open, so that other user can still see the log, but we can close Close the log switch in FrontendServiceImpl which is useless for use at most of time.
----------------------------------------------------------------
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
---------------------------------------------------------------------
To unsubscribe, e-mail: commits-unsubscribe@doris.apache.org
For additional commands, e-mail: commits-help@doris.apache.org
[GitHub] [incubator-doris] chaoyli commented on a change in pull request #4766: Make some debug log settings configurable and change some log level from info to debug to escape performance bottlenecks
Posted by GitBox <gi...@apache.org>.
chaoyli commented on a change in pull request #4766:
URL: https://github.com/apache/incubator-doris/pull/4766#discussion_r509833385
##########
File path: fe/fe-core/src/main/java/org/apache/doris/service/FrontendServiceImpl.java
##########
@@ -827,7 +823,7 @@ private void loadTxnRollbackImpl(TLoadTxnRollbackRequest request) throws UserExc
@Override
public TStreamLoadPutResult streamLoadPut(TStreamLoadPutRequest request) {
String clientAddr = getClientAddrAsString();
- LOG.info("receive stream load put request. db:{}, tbl: {}, txn id: {}, load id: {}, backend: {}",
+ LOG.debug("receive stream load put request. db:{}, tbl: {}, txn id: {}, load id: {}, backend: {}",
Review comment:
The same as the above.
##########
File path: fe/fe-core/src/main/java/org/apache/doris/service/FrontendServiceImpl.java
##########
@@ -778,7 +774,7 @@ private boolean loadTxnCommitImpl(TLoadTxnCommitRequest request) throws UserExce
@Override
public TLoadTxnRollbackResult loadTxnRollback(TLoadTxnRollbackRequest request) throws TException {
String clientAddr = getClientAddrAsString();
- LOG.info("receive txn rollback request. db: {}, tbl: {}, txn id: {}, reason: {}, backend: {}",
+ LOG.debug("receive txn rollback request. db: {}, tbl: {}, txn id: {}, reason: {}, backend: {}",
Review comment:
I am sorry to point here to merge the two logs.
----------------------------------------------------------------
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
---------------------------------------------------------------------
To unsubscribe, e-mail: commits-unsubscribe@doris.apache.org
For additional commands, e-mail: commits-help@doris.apache.org
[GitHub] [incubator-doris] kangkaisen merged pull request #4766: Make some debug log settings configurable and change some log level from info to debug to avoid performance bottlenecks
Posted by GitBox <gi...@apache.org>.
kangkaisen merged pull request #4766:
URL: https://github.com/apache/incubator-doris/pull/4766
----------------------------------------------------------------
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
---------------------------------------------------------------------
To unsubscribe, e-mail: commits-unsubscribe@doris.apache.org
For additional commands, e-mail: commits-help@doris.apache.org
[GitHub] [incubator-doris] chaoyli commented on a change in pull request #4766: Make some debug log settings configurable and change some log level from info to debug to escape performance bottlenecks
Posted by GitBox <gi...@apache.org>.
chaoyli commented on a change in pull request #4766:
URL: https://github.com/apache/incubator-doris/pull/4766#discussion_r509018599
##########
File path: fe/fe-core/src/main/java/org/apache/doris/service/FrontendServiceImpl.java
##########
@@ -634,7 +634,7 @@ public TFeResult loadCheck(TLoadCheckRequest request) throws TException {
@Override
public TLoadTxnBeginResult loadTxnBegin(TLoadTxnBeginRequest request) throws TException {
String clientAddr = getClientAddrAsString();
- LOG.info("receive txn begin request, db: {}, tbl: {}, label: {}, backend: {}",
+ LOG.debug("receive txn begin request, db: {}, tbl: {}, label: {}, backend: {}",
Review comment:
line 637, 638 LOG.debug can merged.
##########
File path: fe/fe-core/src/main/java/org/apache/doris/service/FrontendServiceImpl.java
##########
@@ -712,7 +712,7 @@ private long loadTxnBeginImpl(TLoadTxnBeginRequest request, String clientIp) thr
@Override
public TLoadTxnCommitResult loadTxnCommit(TLoadTxnCommitRequest request) throws TException {
String clientAddr = getClientAddrAsString();
- LOG.info("receive txn commit request. db: {}, tbl: {}, txn id: {}, backend: {}",
+ LOG.debug("receive txn commit request. db: {}, tbl: {}, txn id: {}, backend: {}",
Review comment:
line 715, 716 can be merged.
----------------------------------------------------------------
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
---------------------------------------------------------------------
To unsubscribe, e-mail: commits-unsubscribe@doris.apache.org
For additional commands, e-mail: commits-help@doris.apache.org