/zookeeper

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

ZOOKEEPER-2824: `FileChannel#size` info should be added to `FileTxnLog#commit` to solve the confuse that reason is too large log or too busy disk I/O #296

Closed
wants to merge 2 commits into
base: master
from

Conversation

Reviewers

@phunt phunt

@afine afine

@anmolnar anmolnar

Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
4 participants
@asdf2014 @anmolnar @afine @phunt
@asdf2014
Member

asdf2014 commented Jun 28, 2017 •
edited

FileChannel#size info should be added to FileTxnLog#commit to solve the confuse that reason is too large log or too busy disk I/O

Example from jenkins log:

2017-06-28 10:25:16,645 [myid:] - WARN  [SyncThread:0:FileTxnLog@341] - fsync-ing the write ahead log (1945616 bytes) in SyncThread:0 took 2240ms which will adversely effect operation latency. See the ZooKeeper troubleshooting guide

@asdf2014 asdf2014 force-pushed the asdf2014:ZOOKEEPER-2824 branch from 9006b8f to 34fcc36 Jun 28, 2017

@asdf2014
ZOOKEEPER-2824: `FileChannel#size` info should be added to `FileTxnLo… 
…g#commit` to solve the confuse that reason is too large log or too busy disk I/O
Loading status checks…
dd2268f

@asdf2014 asdf2014 force-pushed the asdf2014:ZOOKEEPER-2824 branch from 34fcc36 to dd2268f Jun 28, 2017

@afine

afine reviewed Jun 29, 2017
View changes

src/java/main/org/apache/zookeeper/server/persistence/FileTxnLog.java Outdated
syncElapsedMS = TimeUnit.NANOSECONDS.toMillis(System.nanoTime() - startSyncNS);
if (syncElapsedMS > fsyncWarningThresholdMS) {
LOG.warn("fsync-ing the write ahead log in "
LOG.warn("fsync-ing the write ahead log ("
+ channel.size() + " bytes) in "

This comment has been minimized.

Sign in to view
Copy link
@afine

afine Jun 29, 2017

Contributor

According to the javadoc, size() returns "Returns the current size of this channel's file." Can you explain why this is valuable?

This comment has been minimized.

Sign in to view
Copy link
@asdf2014

asdf2014 Jun 30, 2017

Member

@afine Thank you for code review. When we got the warn message, will confuse that reason is too large log or too busy disk I/O? So, need to show the size of log to eliminate the too large log possibility.

This comment has been minimized.

Sign in to view
Copy link
@phunt

phunt Jan 19, 2018

Contributor

@asdf2014 can you move the changed text after the first sentence?

... latency. File size is ### bytes. See ...

The reason being that I know a number of users who have log triggers on this log message and I'd like to minimize the impact as much as possible.

This comment has been minimized.

Sign in to view
Copy link
@afine

afine Jan 30, 2018

Contributor

@asdf2014 as soon as @phunt's comment is addressed I can merge this in.
@asdf2014

This comment has been minimized.

Sign in to view
Member

asdf2014 commented Dec 22, 2017

@afine Could you approve this PR?
@phunt @anmolnar PTAL.


Just recently, i experienced this situation again, this time due to the bad disk rather than the huge WAL file. But i still cannot get the root cause from Zookeeper log...
image
@anmolnar

This comment has been minimized.

Sign in to view
Contributor

anmolnar commented Jan 11, 2018

Hi @asdf2014

I'm happy with the change if it has any help to you for debugging.
@asdf2014

This comment has been minimized.

Sign in to view
Member

asdf2014 commented Jan 12, 2018

Hi, @anmolnar . Thanks, would you approve this PR?
@anmolnar

anmolnar approved these changes Jan 12, 2018
View changes

@afine

afine suggested changes Jan 30, 2018
View changes

src/java/main/org/apache/zookeeper/server/persistence/FileTxnLog.java Outdated
syncElapsedMS = TimeUnit.NANOSECONDS.toMillis(System.nanoTime() - startSyncNS);
if (syncElapsedMS > fsyncWarningThresholdMS) {
LOG.warn("fsync-ing the write ahead log in "
LOG.warn("fsync-ing the write ahead log ("
+ channel.size() + " bytes) in "

This comment has been minimized.

Sign in to view
Copy link
@afine

afine Jan 30, 2018

Contributor

@asdf2014 as soon as @phunt's comment is addressed I can merge this in.
@asdf2014
Improve latency log description
Loading status checks…
7cf4b68
@asdf2014

This comment has been minimized.

Sign in to view
Member

asdf2014 commented Jan 31, 2018

@phunt @afine Thank you for those suggestions. Considered very thoughtful. Already fixed.
@afine

afine approved these changes Feb 1, 2018
View changes

@asfgit asfgit closed this in 069c3e4 Feb 1, 2018

asfgit pushed a commit that referenced this pull request Feb 1, 2018

@asdf2014 @afine
ZOOKEEPER-2824: `FileChannel#size` info should be added to `FileTxnLo… 
…g#commit` to solve the confuse that reason is too large log or too busy disk I/O

`FileChannel#size` info should be added to `FileTxnLog#commit` to solve the confuse that reason is too large log or too busy disk I/O

------
Example from jenkins [log](https://builds.apache.org/job/PreCommit-ZOOKEEPER-github-pr-build/830/console):
```java
2017-06-28 10:25:16,645 [myid:] - WARN  [SyncThread:0:FileTxnLog341] - fsync-ing the write ahead log (1945616 bytes) in SyncThread:0 took 2240ms which will adversely effect operation latency. See the ZooKeeper troubleshooting guide
```

Author: asdf2014 <benedictjin2016@gmail.com>
Author: asdf2014 <1571805553@qq.com>

Reviewers: Patrick Hunt <phunt@apache.org>, Andor Molnár <andor@cloudera.com>, Abraham Fine <afine@apache.org>

Closes #296 from asdf2014/ZOOKEEPER-2824 and squashes the following commits:

7cf4b68 [asdf2014] Improve latency log description
dd2268f [asdf2014] ZOOKEEPER-2824: `FileChannel#size` info should be added to `FileTxnLog#commit` to solve the confuse that reason is too large log or too busy disk I/O

(cherry picked from commit 069c3e4)

Signed-off-by: Abraham Fine <afine@apache.org>

Signed-off-by: Abraham Fine <afine@apache.org>
0b6442a
@afine

This comment has been minimized.

Sign in to view
Contributor

afine commented Feb 1, 2018

Merged. Thanks @asdf2014!
@asdf2014

This comment has been minimized.

Sign in to view
Member

asdf2014 commented Feb 2, 2018

@afine You are welcome :-)

@asdf2014 asdf2014 deleted the asdf2014:ZOOKEEPER-2824 branch Feb 2, 2018

lvfangmin pushed a commit to lvfangmin/zookeeper that referenced this pull request Jun 17, 2018

@asdf2014 Fangmin Lyu
ZOOKEEPER-2824: `FileChannel#size` info should be added to `FileTxnLo… 
…g#commit` to solve the confuse that reason is too large log or too busy disk I/O

`FileChannel#size` info should be added to `FileTxnLog#commit` to solve the confuse that reason is too large log or too busy disk I/O

------
Example from jenkins [log](https://builds.apache.org/job/PreCommit-ZOOKEEPER-github-pr-build/830/console):
```java
2017-06-28 10:25:16,645 [myid:] - WARN  [SyncThread:0:FileTxnLog341] - fsync-ing the write ahead log (1945616 bytes) in SyncThread:0 took 2240ms which will adversely effect operation latency. See the ZooKeeper troubleshooting guide
```

Author: asdf2014 <benedictjin2016@gmail.com>
Author: asdf2014 <1571805553@qq.com>

Reviewers: Patrick Hunt <phunt@apache.org>, Andor Molnár <andor@cloudera.com>, Abraham Fine <afine@apache.org>

Closes apache#296 from asdf2014/ZOOKEEPER-2824 and squashes the following commits:

7cf4b68 [asdf2014] Improve latency log description
dd2268f [asdf2014] ZOOKEEPER-2824: `FileChannel#size` info should be added to `FileTxnLog#commit` to solve the confuse that reason is too large log or too busy disk I/O
902b9d6
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment