You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@lucene.apache.org by mi...@apache.org on 2013/01/04 17:07:54 UTC
svn commit: r1428947 - in
/lucene/dev/trunk/lucene/core/src/java/org/apache/lucene/index:
IndexFileDeleter.java SegmentMerger.java
Author: mikemccand
Date: Fri Jan 4 16:07:54 2013
New Revision: 1428947
URL: http://svn.apache.org/viewvc?rev=1428947&view=rev
Log:
add infoStream verbosity
Modified:
lucene/dev/trunk/lucene/core/src/java/org/apache/lucene/index/IndexFileDeleter.java
lucene/dev/trunk/lucene/core/src/java/org/apache/lucene/index/SegmentMerger.java
Modified: lucene/dev/trunk/lucene/core/src/java/org/apache/lucene/index/IndexFileDeleter.java
URL: http://svn.apache.org/viewvc/lucene/dev/trunk/lucene/core/src/java/org/apache/lucene/index/IndexFileDeleter.java?rev=1428947&r1=1428946&r2=1428947&view=diff
==============================================================================
--- lucene/dev/trunk/lucene/core/src/java/org/apache/lucene/index/IndexFileDeleter.java (original)
+++ lucene/dev/trunk/lucene/core/src/java/org/apache/lucene/index/IndexFileDeleter.java Fri Jan 4 16:07:54 2013
@@ -436,7 +436,7 @@ final class IndexFileDeleter implements
assert locked();
assert Thread.holdsLock(writer);
-
+ long t0 = System.nanoTime();
if (infoStream.isEnabled("IFD")) {
infoStream.message("IFD", "now checkpoint \"" + writer.segString(writer.toLiveInfos(segmentInfos)) + "\" [" + segmentInfos.size() + " segments " + "; isCommit = " + isCommit + "]");
}
@@ -467,6 +467,10 @@ final class IndexFileDeleter implements
// Save files so we can decr on next checkpoint/commit:
lastFiles.add(segmentInfos.files(directory, false));
}
+ if (infoStream.isEnabled("IFD")) {
+ long t1 = System.nanoTime();
+ infoStream.message("IFD", ((t1-t0)/1000000) + " msec to checkpoint");
+ }
}
void incRef(SegmentInfos segmentInfos, boolean isCommit) throws IOException {
Modified: lucene/dev/trunk/lucene/core/src/java/org/apache/lucene/index/SegmentMerger.java
URL: http://svn.apache.org/viewvc/lucene/dev/trunk/lucene/core/src/java/org/apache/lucene/index/SegmentMerger.java?rev=1428947&r1=1428946&r2=1428947&view=diff
==============================================================================
--- lucene/dev/trunk/lucene/core/src/java/org/apache/lucene/index/SegmentMerger.java (original)
+++ lucene/dev/trunk/lucene/core/src/java/org/apache/lucene/index/SegmentMerger.java Fri Jan 4 16:07:54 2013
@@ -31,7 +31,6 @@ import org.apache.lucene.codecs.StoredFi
import org.apache.lucene.codecs.TermVectorsWriter;
import org.apache.lucene.store.Directory;
import org.apache.lucene.store.IOContext;
-import org.apache.lucene.util.Bits;
import org.apache.lucene.util.IOUtils;
import org.apache.lucene.util.InfoStream;
@@ -99,20 +98,46 @@ final class SegmentMerger {
mergeState.segmentInfo.setDocCount(setDocMaps());
mergeDocValuesAndNormsFieldInfos();
setMatchingSegmentReaders();
+ long t0 = System.nanoTime();
int numMerged = mergeFields();
+ if (mergeState.infoStream.isEnabled("SM")) {
+ long t1 = System.nanoTime();
+ mergeState.infoStream.message("SM", ((t1-t0)/1000000) + " msec to merge stored fields [" + numMerged + " docs]");
+ }
assert numMerged == mergeState.segmentInfo.getDocCount();
final SegmentWriteState segmentWriteState = new SegmentWriteState(mergeState.infoStream, directory, mergeState.segmentInfo,
mergeState.fieldInfos, termIndexInterval, null, context);
+ t0 = System.nanoTime();
mergeTerms(segmentWriteState);
+ if (mergeState.infoStream.isEnabled("SM")) {
+ long t1 = System.nanoTime();
+ mergeState.infoStream.message("SM", ((t1-t0)/1000000) + " msec to merge postings [" + numMerged + " docs]");
+ }
+
+ t0 = System.nanoTime();
mergePerDoc(segmentWriteState);
+ if (mergeState.infoStream.isEnabled("SM")) {
+ long t1 = System.nanoTime();
+ mergeState.infoStream.message("SM", ((t1-t0)/1000000) + " msec to merge doc values [" + numMerged + " docs]");
+ }
if (mergeState.fieldInfos.hasNorms()) {
+ t0 = System.nanoTime();
mergeNorms(segmentWriteState);
+ if (mergeState.infoStream.isEnabled("SM")) {
+ long t1 = System.nanoTime();
+ mergeState.infoStream.message("SM", ((t1-t0)/1000000) + " msec to merge norms [" + numMerged + " docs]");
+ }
}
if (mergeState.fieldInfos.hasVectors()) {
+ t0 = System.nanoTime();
numMerged = mergeVectors();
+ if (mergeState.infoStream.isEnabled("SM")) {
+ long t1 = System.nanoTime();
+ mergeState.infoStream.message("SM", ((t1-t0)/1000000) + " msec to merge vectors [" + numMerged + " docs]");
+ }
assert numMerged == mergeState.segmentInfo.getDocCount();
}
Re: svn commit: r1428947 - in /lucene/dev/trunk/lucene/core/src/java/org/apache/lucene/index:
IndexFileDeleter.java SegmentMerger.java
Posted by Dawid Weiss <da...@cs.put.poznan.pl>.
Seems like if you have a Mac you may never know if your hour has come ;)
Dawid
On Fri, Jan 4, 2013 at 5:52 PM, Uwe Schindler <uw...@thetaphi.de> wrote:
>> I have to mention: MacOSX JDK 1.7.0_10 crashed when nanotime went
>> backwards... :-) See my mail and fix for this a few days ago.
>> Happy JVM crashing!
>
> Could also have been System.getCurrentTimeMillis or new Date() - but getting time is crazy LOL:
>
> [junit4:junit4] >>> JVM J0: stdout (verbatim) ----
> [junit4:junit4] #
> [junit4:junit4] # A fatal error has been detected by the Java Runtime Environment:
> [junit4:junit4] #
> [junit4:junit4] # SIGFPE (0x8) at pc=0x00007fff88169b43, pid=504, tid=21507
> [junit4:junit4] #
> [junit4:junit4] # JRE version: 7.0_10-b18
> [junit4:junit4] # Java VM: Java HotSpot(TM) 64-Bit Server VM (23.6-b04 mixed mode bsd-amd64 compressed oops)
> [junit4:junit4] # Problematic frame:
> [junit4:junit4] # C [libsystem_c.dylib+0x2b43] __commpage_gettimeofday+0x43
> [junit4:junit4] #
> [junit4:junit4] # Failed to write core dump. Core dumps have been disabled. To enable core dumping, try "ulimit -c unlimited" before starting Java again
> [junit4:junit4] #
> [junit4:junit4] # An error report file with more information is saved as:
> [junit4:junit4] # /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/lucene/build/core/test/J0/hs_err_pid504.log
> [junit4:junit4] #
> [junit4:junit4] # If you would like to submit a bug report, please visit:
> [junit4:junit4] # http://bugreport.sun.com/bugreport/crash.jsp
> [junit4:junit4] #
> [junit4:junit4] <<< JVM J0: EOF ----
>
> Uwe
>
>> -----
>> Uwe Schindler
>> H.-H.-Meier-Allee 63, D-28213 Bremen
>> http://www.thetaphi.de
>> eMail: uwe@thetaphi.de
>>
>>
>> > -----Original Message-----
>> > From: Michael McCandless [mailto:lucene@mikemccandless.com]
>> > Sent: Friday, January 04, 2013 5:37 PM
>> > To: dev@lucene.apache.org
>> > Subject: Re: svn commit: r1428947 - in
>> > /lucene/dev/trunk/lucene/core/src/java/org/apache/lucene/index:
>> > IndexFileDeleter.java SegmentMerger.java
>> >
>> > On Fri, Jan 4, 2013 at 11:34 AM, Uwe Schindler <uw...@thetaphi.de> wrote:
>> >
>> > > System.nanoTime is a syscall and heavy on some O/S. The times are
>> > > only
>> > used when inforstream is enabled, so the calls to nanotime should only
>> > be inside "if (infostream)" blocks. Some of them are outside this check.
>> >
>> > How heavy? As heavy as a Lucene merge? ;)
>> >
>> > OK ok, I'll move them under the if ...
>> >
>> > Mike McCandless
>> >
>> > http://blog.mikemccandless.com
>> >
>> > ---------------------------------------------------------------------
>> > To unsubscribe, e-mail: dev-unsubscribe@lucene.apache.org For
>> > additional commands, e-mail: dev-help@lucene.apache.org
>>
>>
>> ---------------------------------------------------------------------
>> To unsubscribe, e-mail: dev-unsubscribe@lucene.apache.org For additional
>> commands, e-mail: dev-help@lucene.apache.org
>
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: dev-unsubscribe@lucene.apache.org
> For additional commands, e-mail: dev-help@lucene.apache.org
>
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@lucene.apache.org
For additional commands, e-mail: dev-help@lucene.apache.org
RE: svn commit: r1428947 - in /lucene/dev/trunk/lucene/core/src/java/org/apache/lucene/index: IndexFileDeleter.java SegmentMerger.java
Posted by Uwe Schindler <uw...@thetaphi.de>.
> I have to mention: MacOSX JDK 1.7.0_10 crashed when nanotime went
> backwards... :-) See my mail and fix for this a few days ago.
> Happy JVM crashing!
Could also have been System.getCurrentTimeMillis or new Date() - but getting time is crazy LOL:
[junit4:junit4] >>> JVM J0: stdout (verbatim) ----
[junit4:junit4] #
[junit4:junit4] # A fatal error has been detected by the Java Runtime Environment:
[junit4:junit4] #
[junit4:junit4] # SIGFPE (0x8) at pc=0x00007fff88169b43, pid=504, tid=21507
[junit4:junit4] #
[junit4:junit4] # JRE version: 7.0_10-b18
[junit4:junit4] # Java VM: Java HotSpot(TM) 64-Bit Server VM (23.6-b04 mixed mode bsd-amd64 compressed oops)
[junit4:junit4] # Problematic frame:
[junit4:junit4] # C [libsystem_c.dylib+0x2b43] __commpage_gettimeofday+0x43
[junit4:junit4] #
[junit4:junit4] # Failed to write core dump. Core dumps have been disabled. To enable core dumping, try "ulimit -c unlimited" before starting Java again
[junit4:junit4] #
[junit4:junit4] # An error report file with more information is saved as:
[junit4:junit4] # /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/lucene/build/core/test/J0/hs_err_pid504.log
[junit4:junit4] #
[junit4:junit4] # If you would like to submit a bug report, please visit:
[junit4:junit4] # http://bugreport.sun.com/bugreport/crash.jsp
[junit4:junit4] #
[junit4:junit4] <<< JVM J0: EOF ----
Uwe
> -----
> Uwe Schindler
> H.-H.-Meier-Allee 63, D-28213 Bremen
> http://www.thetaphi.de
> eMail: uwe@thetaphi.de
>
>
> > -----Original Message-----
> > From: Michael McCandless [mailto:lucene@mikemccandless.com]
> > Sent: Friday, January 04, 2013 5:37 PM
> > To: dev@lucene.apache.org
> > Subject: Re: svn commit: r1428947 - in
> > /lucene/dev/trunk/lucene/core/src/java/org/apache/lucene/index:
> > IndexFileDeleter.java SegmentMerger.java
> >
> > On Fri, Jan 4, 2013 at 11:34 AM, Uwe Schindler <uw...@thetaphi.de> wrote:
> >
> > > System.nanoTime is a syscall and heavy on some O/S. The times are
> > > only
> > used when inforstream is enabled, so the calls to nanotime should only
> > be inside "if (infostream)" blocks. Some of them are outside this check.
> >
> > How heavy? As heavy as a Lucene merge? ;)
> >
> > OK ok, I'll move them under the if ...
> >
> > Mike McCandless
> >
> > http://blog.mikemccandless.com
> >
> > ---------------------------------------------------------------------
> > To unsubscribe, e-mail: dev-unsubscribe@lucene.apache.org For
> > additional commands, e-mail: dev-help@lucene.apache.org
>
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: dev-unsubscribe@lucene.apache.org For additional
> commands, e-mail: dev-help@lucene.apache.org
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@lucene.apache.org
For additional commands, e-mail: dev-help@lucene.apache.org
RE: svn commit: r1428947 - in /lucene/dev/trunk/lucene/core/src/java/org/apache/lucene/index: IndexFileDeleter.java SegmentMerger.java
Posted by Uwe Schindler <uw...@thetaphi.de>.
My problem was not how heavy it is, but if ist only used inside conditionals we should not mix it.
I have to mention: MacOSX JDK 1.7.0_10 crashed when nanotime went backwards... :-) See my mail and fix for this a few days ago.
Happy JVM crashing!
Uwe
-----
Uwe Schindler
H.-H.-Meier-Allee 63, D-28213 Bremen
http://www.thetaphi.de
eMail: uwe@thetaphi.de
> -----Original Message-----
> From: Michael McCandless [mailto:lucene@mikemccandless.com]
> Sent: Friday, January 04, 2013 5:37 PM
> To: dev@lucene.apache.org
> Subject: Re: svn commit: r1428947 - in
> /lucene/dev/trunk/lucene/core/src/java/org/apache/lucene/index:
> IndexFileDeleter.java SegmentMerger.java
>
> On Fri, Jan 4, 2013 at 11:34 AM, Uwe Schindler <uw...@thetaphi.de> wrote:
>
> > System.nanoTime is a syscall and heavy on some O/S. The times are only
> used when inforstream is enabled, so the calls to nanotime should only be
> inside "if (infostream)" blocks. Some of them are outside this check.
>
> How heavy? As heavy as a Lucene merge? ;)
>
> OK ok, I'll move them under the if ...
>
> Mike McCandless
>
> http://blog.mikemccandless.com
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: dev-unsubscribe@lucene.apache.org For additional
> commands, e-mail: dev-help@lucene.apache.org
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@lucene.apache.org
For additional commands, e-mail: dev-help@lucene.apache.org
Re: svn commit: r1428947 - in /lucene/dev/trunk/lucene/core/src/java/org/apache/lucene/index:
IndexFileDeleter.java SegmentMerger.java
Posted by Michael McCandless <lu...@mikemccandless.com>.
On Fri, Jan 4, 2013 at 11:34 AM, Uwe Schindler <uw...@thetaphi.de> wrote:
> System.nanoTime is a syscall and heavy on some O/S. The times are only used when inforstream is enabled, so the calls to nanotime should only be inside "if (infostream)" blocks. Some of them are outside this check.
How heavy? As heavy as a Lucene merge? ;)
OK ok, I'll move them under the if ...
Mike McCandless
http://blog.mikemccandless.com
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@lucene.apache.org
For additional commands, e-mail: dev-help@lucene.apache.org
RE: svn commit: r1428947 - in /lucene/dev/trunk/lucene/core/src/java/org/apache/lucene/index: IndexFileDeleter.java SegmentMerger.java
Posted by Uwe Schindler <uw...@thetaphi.de>.
Hi Mike,
System.nanoTime is a syscall and heavy on some O/S. The times are only used when inforstream is enabled, so the calls to nanotime should only be inside "if (infostream)" blocks. Some of them are outside this check.
Uwe
-----
Uwe Schindler
H.-H.-Meier-Allee 63, D-28213 Bremen
http://www.thetaphi.de
eMail: uwe@thetaphi.de
> -----Original Message-----
> From: mikemccand@apache.org [mailto:mikemccand@apache.org]
> Sent: Friday, January 04, 2013 5:08 PM
> To: commits@lucene.apache.org
> Subject: svn commit: r1428947 - in
> /lucene/dev/trunk/lucene/core/src/java/org/apache/lucene/index:
> IndexFileDeleter.java SegmentMerger.java
>
> Author: mikemccand
> Date: Fri Jan 4 16:07:54 2013
> New Revision: 1428947
>
> URL: http://svn.apache.org/viewvc?rev=1428947&view=rev
> Log:
> add infoStream verbosity
>
> Modified:
>
> lucene/dev/trunk/lucene/core/src/java/org/apache/lucene/index/IndexFile
> Deleter.java
>
> lucene/dev/trunk/lucene/core/src/java/org/apache/lucene/index/Segment
> Merger.java
>
> Modified:
> lucene/dev/trunk/lucene/core/src/java/org/apache/lucene/index/IndexFile
> Deleter.java
> URL:
> http://svn.apache.org/viewvc/lucene/dev/trunk/lucene/core/src/java/org/
> apache/lucene/index/IndexFileDeleter.java?rev=1428947&r1=1428946&r2=1
> 428947&view=diff
> ==========================================================
> ====================
> ---
> lucene/dev/trunk/lucene/core/src/java/org/apache/lucene/index/IndexFile
> Deleter.java (original)
> +++
> lucene/dev/trunk/lucene/core/src/java/org/apache/lucene/index/IndexF
> +++ ileDeleter.java Fri Jan 4 16:07:54 2013
> @@ -436,7 +436,7 @@ final class IndexFileDeleter implements
> assert locked();
>
> assert Thread.holdsLock(writer);
> -
> + long t0 = System.nanoTime();
> if (infoStream.isEnabled("IFD")) {
> infoStream.message("IFD", "now checkpoint \"" +
> writer.segString(writer.toLiveInfos(segmentInfos)) + "\" [" +
> segmentInfos.size() + " segments " + "; isCommit = " + isCommit + "]");
> }
> @@ -467,6 +467,10 @@ final class IndexFileDeleter implements
> // Save files so we can decr on next checkpoint/commit:
> lastFiles.add(segmentInfos.files(directory, false));
> }
> + if (infoStream.isEnabled("IFD")) {
> + long t1 = System.nanoTime();
> + infoStream.message("IFD", ((t1-t0)/1000000) + " msec to checkpoint");
> + }
> }
>
> void incRef(SegmentInfos segmentInfos, boolean isCommit) throws
> IOException {
>
> Modified:
> lucene/dev/trunk/lucene/core/src/java/org/apache/lucene/index/Segment
> Merger.java
> URL:
> http://svn.apache.org/viewvc/lucene/dev/trunk/lucene/core/src/java/org/
> apache/lucene/index/SegmentMerger.java?rev=1428947&r1=1428946&r2=1
> 428947&view=diff
> ==========================================================
> ====================
> ---
> lucene/dev/trunk/lucene/core/src/java/org/apache/lucene/index/Segment
> Merger.java (original)
> +++
> lucene/dev/trunk/lucene/core/src/java/org/apache/lucene/index/Segmen
> +++ tMerger.java Fri Jan 4 16:07:54 2013
> @@ -31,7 +31,6 @@ import org.apache.lucene.codecs.StoredFi import
> org.apache.lucene.codecs.TermVectorsWriter;
> import org.apache.lucene.store.Directory;
> import org.apache.lucene.store.IOContext;
> -import org.apache.lucene.util.Bits;
> import org.apache.lucene.util.IOUtils;
> import org.apache.lucene.util.InfoStream;
>
> @@ -99,20 +98,46 @@ final class SegmentMerger {
> mergeState.segmentInfo.setDocCount(setDocMaps());
> mergeDocValuesAndNormsFieldInfos();
> setMatchingSegmentReaders();
> + long t0 = System.nanoTime();
> int numMerged = mergeFields();
> + if (mergeState.infoStream.isEnabled("SM")) {
> + long t1 = System.nanoTime();
> + mergeState.infoStream.message("SM", ((t1-t0)/1000000) + " msec to
> merge stored fields [" + numMerged + " docs]");
> + }
> assert numMerged == mergeState.segmentInfo.getDocCount();
>
> final SegmentWriteState segmentWriteState = new
> SegmentWriteState(mergeState.infoStream, directory,
> mergeState.segmentInfo,
> mergeState.fieldInfos, termIndexInterval,
> null, context);
> + t0 = System.nanoTime();
> mergeTerms(segmentWriteState);
> + if (mergeState.infoStream.isEnabled("SM")) {
> + long t1 = System.nanoTime();
> + mergeState.infoStream.message("SM", ((t1-t0)/1000000) + " msec to
> merge postings [" + numMerged + " docs]");
> + }
> +
> + t0 = System.nanoTime();
> mergePerDoc(segmentWriteState);
> + if (mergeState.infoStream.isEnabled("SM")) {
> + long t1 = System.nanoTime();
> + mergeState.infoStream.message("SM", ((t1-t0)/1000000) + " msec to
> merge doc values [" + numMerged + " docs]");
> + }
>
> if (mergeState.fieldInfos.hasNorms()) {
> + t0 = System.nanoTime();
> mergeNorms(segmentWriteState);
> + if (mergeState.infoStream.isEnabled("SM")) {
> + long t1 = System.nanoTime();
> + mergeState.infoStream.message("SM", ((t1-t0)/1000000) + " msec to
> merge norms [" + numMerged + " docs]");
> + }
> }
>
> if (mergeState.fieldInfos.hasVectors()) {
> + t0 = System.nanoTime();
> numMerged = mergeVectors();
> + if (mergeState.infoStream.isEnabled("SM")) {
> + long t1 = System.nanoTime();
> + mergeState.infoStream.message("SM", ((t1-t0)/1000000) + " msec to
> merge vectors [" + numMerged + " docs]");
> + }
> assert numMerged == mergeState.segmentInfo.getDocCount();
> }
>
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@lucene.apache.org
For additional commands, e-mail: dev-help@lucene.apache.org