You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@zookeeper.apache.org by ca...@apache.org on 2011/11/15 19:26:32 UTC

svn commit: r1202357 - in /zookeeper/branches/branch-3.3: CHANGES.txt src/docs/src/documentation/content/xdocs/zookeeperAdmin.xml src/java/main/org/apache/zookeeper/server/persistence/FileTxnLog.java

Author: camille
Date: Tue Nov 15 18:26:32 2011
New Revision: 1202357

URL: http://svn.apache.org/viewvc?rev=1202357&view=rev
Log:
ZOOKEEPER-1239. add logging/stats to identify fsync stalls. (phunt via camille)

Modified:
    zookeeper/branches/branch-3.3/CHANGES.txt
    zookeeper/branches/branch-3.3/src/docs/src/documentation/content/xdocs/zookeeperAdmin.xml
    zookeeper/branches/branch-3.3/src/java/main/org/apache/zookeeper/server/persistence/FileTxnLog.java

Modified: zookeeper/branches/branch-3.3/CHANGES.txt
URL: http://svn.apache.org/viewvc/zookeeper/branches/branch-3.3/CHANGES.txt?rev=1202357&r1=1202356&r2=1202357&view=diff
==============================================================================
--- zookeeper/branches/branch-3.3/CHANGES.txt (original)
+++ zookeeper/branches/branch-3.3/CHANGES.txt Tue Nov 15 18:26:32 2011
@@ -47,6 +47,8 @@ BUGFIXES:
   ZOOKEEPER-1208. Ephemeral node not removed after the client session is long gone. (phunt via camille)
  
   ZOOKEEPER-1283. building 3.3 branch fails with Ant 1.8.2 (success with 1.7.1 though). (phunt via camille)
+  
+  ZOOKEEPER-1239. add logging/stats to identify fsync stalls. (phunt via camille)
 
 Release 3.3.3 - 2011-02-23
 Backward compatible changes:

Modified: zookeeper/branches/branch-3.3/src/docs/src/documentation/content/xdocs/zookeeperAdmin.xml
URL: http://svn.apache.org/viewvc/zookeeper/branches/branch-3.3/src/docs/src/documentation/content/xdocs/zookeeperAdmin.xml?rev=1202357&r1=1202356&r2=1202357&view=diff
==============================================================================
--- zookeeper/branches/branch-3.3/src/docs/src/documentation/content/xdocs/zookeeperAdmin.xml (original)
+++ zookeeper/branches/branch-3.3/src/docs/src/documentation/content/xdocs/zookeeperAdmin.xml Tue Nov 15 18:26:32 2011
@@ -774,6 +774,21 @@ server.3=zoo3:2888:3888</programlisting>
               the <emphasis role="bold">tickTime</emphasis>.</para>
             </listitem>
            </varlistentry>
+
+          <varlistentry>
+            <term>fsync.warningthresholdms</term>
+            <listitem>
+              <para>(Java system property: <emphasis
+              role="bold">fsync.warningthresholdms</emphasis>)</para>
+
+              <para><emphasis role="bold">New in 3.3.4:</emphasis> A
+              warning message will be output to the log whenever an
+              fsync in the Transactional Log (WAL) takes longer than
+              this value. The values is specified in milliseconds and
+              defaults to 1000. This value can only be set as a system
+              property.</para>
+            </listitem>
+           </varlistentry>
         </variablelist>
       </section>
 

Modified: zookeeper/branches/branch-3.3/src/java/main/org/apache/zookeeper/server/persistence/FileTxnLog.java
URL: http://svn.apache.org/viewvc/zookeeper/branches/branch-3.3/src/java/main/org/apache/zookeeper/server/persistence/FileTxnLog.java?rev=1202357&r1=1202356&r2=1202357&view=diff
==============================================================================
--- zookeeper/branches/branch-3.3/src/java/main/org/apache/zookeeper/server/persistence/FileTxnLog.java (original)
+++ zookeeper/branches/branch-3.3/src/java/main/org/apache/zookeeper/server/persistence/FileTxnLog.java Tue Nov 15 18:26:32 2011
@@ -32,6 +32,7 @@ import java.nio.ByteBuffer;
 import java.util.ArrayList;
 import java.util.LinkedList;
 import java.util.List;
+import java.util.concurrent.TimeUnit;
 import java.util.zip.Adler32;
 import java.util.zip.Checksum;
 
@@ -96,6 +97,9 @@ public class FileTxnLog implements TxnLo
 
     public final static int VERSION = 2;
 
+    /** Maximum time we allow for elapsed fsync before WARNing */
+    private final static long fsyncWarningThresholdMS;
+
     static {
         LOG = Logger.getLogger(FileTxnLog.class);
 
@@ -107,6 +111,7 @@ public class FileTxnLog implements TxnLo
                 LOG.warn(size + " is not a valid value for preAllocSize");
             }
         }
+        fsyncWarningThresholdMS = Long.getLong("fsync.warningthresholdms", 1000);
     }
 
     long lastZxidSeen;
@@ -306,7 +311,19 @@ public class FileTxnLog implements TxnLo
         for (FileOutputStream log : streamsToFlush) {
             log.flush();
             if (forceSync) {
+                long startSyncNS = System.nanoTime();
+
                 log.getChannel().force(false);
+
+                long syncElapsedMS =
+                    TimeUnit.NANOSECONDS.toMillis(System.nanoTime() - startSyncNS);
+                if (syncElapsedMS > fsyncWarningThresholdMS) {
+                    LOG.warn("fsync-ing the write ahead log in "
+                            + Thread.currentThread().getName()
+                            + " took " + syncElapsedMS
+                            + "ms which will adversely effect operation latency. "
+                            + "See the ZooKeeper troubleshooting guide");
+                }
             }
         }
         while (streamsToFlush.size() > 1) {