Re: [tor-bugs] #20335 [Metrics/CollecTor]: ReferenceChecker causes OOM

[Tor Bug Tracker & Wiki]

#20335: ReferenceChecker causes OOM
---+---
 Reporter:  iwakeh |  Owner:
 Type:  defect | Status:  closed
 Priority:  High   |  Milestone:
Component:  Metrics/CollecTor  |Version:
 Severity:  Normal | Resolution:  not a bug
 Keywords: |  Actual Points:
Parent ID:  #20519 | Points:
 Reviewer: |Sponsor:
---+---
Changes (by karsten):

 * status:  new => closed
 * resolution:   => not a bug


Comment:

 Replying to [comment:13 iwakeh]:
 > Good to know the true reason now!
 >
 > I'll add a metrics-lib ticket for further work on that. (see #20395)

 Okay, I think this means we can resolve this issue, because the real issue
 is #20395, and the fix to that will magically lead to the ReferenceChecker
 not OOMing anymore.  Please re-open if this was wrong.  Closing.  Thanks!

--
Ticket URL: 
Tor Bug Tracker & Wiki 
The Tor Project: anonymity online
___
tor-bugs mailing list
tor-bugs@lists.torproject.org
https://lists.torproject.org/cgi-bin/mailman/listinfo/tor-bugs

Re: [tor-bugs] #20335 [Metrics/CollecTor]: ReferenceChecker causes OOM

[Tor Bug Tracker & Wiki]

#20335: ReferenceChecker causes OOM
---+-
 Reporter:  iwakeh |  Owner:
 Type:  defect | Status:  new
 Priority:  High   |  Milestone:
Component:  Metrics/CollecTor  |Version:
 Severity:  Normal | Resolution:
 Keywords: |  Actual Points:
Parent ID:  #20519 | Points:
 Reviewer: |Sponsor:
---+-
Changes (by iwakeh):

 * parent:   => #20519


--
Ticket URL: 
Tor Bug Tracker & Wiki 
The Tor Project: anonymity online
___
tor-bugs mailing list
tor-bugs@lists.torproject.org
https://lists.torproject.org/cgi-bin/mailman/listinfo/tor-bugs

Re: [tor-bugs] #20335 [Metrics/CollecTor]: ReferenceChecker causes OOM

[Tor Bug Tracker & Wiki]

#20335: ReferenceChecker causes OOM
---+-
 Reporter:  iwakeh |  Owner:
 Type:  defect | Status:  new
 Priority:  High   |  Milestone:
Component:  Metrics/CollecTor  |Version:
 Severity:  Normal | Resolution:
 Keywords: |  Actual Points:
Parent ID: | Points:
 Reviewer: |Sponsor:
---+-

Comment (by iwakeh):

 Good to know the true reason now!

 I'll add a metrics-lib ticket for further work on that.

 Regarding Collector it would also cause troubles if a Collector instance
 sync from another Collector that has such files.  So the grouping be
 acquisition date needs to be postponed until there is a fix in metrics-
 lib.

--
Ticket URL: 
Tor Bug Tracker & Wiki 
The Tor Project: anonymity online
___
tor-bugs mailing list
tor-bugs@lists.torproject.org
https://lists.torproject.org/cgi-bin/mailman/listinfo/tor-bugs

Re: [tor-bugs] #20335 [Metrics/CollecTor]: ReferenceChecker causes OOM

[Tor Bug Tracker & Wiki]

#20335: ReferenceChecker causes OOM
---+-
 Reporter:  iwakeh |  Owner:
 Type:  defect | Status:  new
 Priority:  High   |  Milestone:
Component:  Metrics/CollecTor  |Version:
 Severity:  Normal | Resolution:
 Keywords: |  Actual Points:
Parent ID: | Points:
 Reviewer: |Sponsor:
---+-

Comment (by karsten):

 Yes, metrics-lib is to blame.  Here's a small class I wrote to show that:

 {{{
 package oom;

 import org.torproject.descriptor.DescriptorReader;
 import org.torproject.descriptor.DescriptorSourceFactory;

 import java.io.File;

 public class Main {
   public static void main(String[] args) {
 DescriptorReader descriptorReader =
 DescriptorSourceFactory.createDescriptorReader();
 descriptorReader.addDirectory(new File("in"));
 descriptorReader.readDescriptors();
   }
 }
 }}}

 And here's the output, once with the default heap size and once with 8G:

 {{{
 $ javac -d bin/ -cp lib/descriptor-1.4.0.jar src/oom/Main.java && java -cp
 bin/:lib/descriptor-1.4.0.jar:lib/slf4j-api-1.7.7.jar:lib/logback-
 classic-1.1.2.jar:lib/logback-core-1.1.2.jar:lib/commons-compress-1.9.jar
 oom.Main
 19:53:31.906 [Thread-0] ERROR o.t.d.impl.DescriptorReaderImpl - Bug:
 uncaught exception or error while reading descriptors: Java heap space
 java.lang.OutOfMemoryError: Java heap space
 at java.util.Arrays.copyOf(Arrays.java:3236) ~[na:1.8.0_102]
 at
 java.io.ByteArrayOutputStream.grow(ByteArrayOutputStream.java:118)
 ~[na:1.8.0_102]
 at
 java.io.ByteArrayOutputStream.ensureCapacity(ByteArrayOutputStream.java:93)
 ~[na:1.8.0_102]
 at
 java.io.ByteArrayOutputStream.write(ByteArrayOutputStream.java:153)
 ~[na:1.8.0_102]
 at
 
org.torproject.descriptor.impl.DescriptorReaderImpl$DescriptorReaderRunnable.readFile(DescriptorReaderImpl.java:378)
 ~[descriptor-1.4.0.jar:1.4.0-adf4a67]
 at
 
org.torproject.descriptor.impl.DescriptorReaderImpl$DescriptorReaderRunnable.readDescriptors(DescriptorReaderImpl.java:284)
 ~[descriptor-1.4.0.jar:1.4.0-adf4a67]
 at
 
org.torproject.descriptor.impl.DescriptorReaderImpl$DescriptorReaderRunnable.run(DescriptorReaderImpl.java:188)
 ~[descriptor-1.4.0.jar:1.4.0-adf4a67]
 at java.lang.Thread.run(Thread.java:745) [na:1.8.0_102]
 $ javac -d bin/ -cp lib/descriptor-1.4.0.jar src/oom/Main.java && java
 -Xmx8g -cp bin/:lib/descriptor-1.4.0.jar:lib/slf4j-api-1.7.7.jar:lib
 /logback-classic-1.1.2.jar:lib/logback-core-1.1.2.jar:lib/commons-
 compress-1.9.jar oom.Main
 19:54:02.620 [Thread-0] ERROR o.t.d.impl.DescriptorReaderImpl - Bug:
 uncaught exception or error while reading descriptors: null
 java.lang.OutOfMemoryError: null
 at
 java.io.ByteArrayOutputStream.hugeCapacity(ByteArrayOutputStream.java:123)
 ~[na:1.8.0_102]
 at
 java.io.ByteArrayOutputStream.grow(ByteArrayOutputStream.java:117)
 ~[na:1.8.0_102]
 at
 java.io.ByteArrayOutputStream.ensureCapacity(ByteArrayOutputStream.java:93)
 ~[na:1.8.0_102]
 at
 java.io.ByteArrayOutputStream.write(ByteArrayOutputStream.java:153)
 ~[na:1.8.0_102]
 at
 
org.torproject.descriptor.impl.DescriptorReaderImpl$DescriptorReaderRunnable.readFile(DescriptorReaderImpl.java:378)
 ~[descriptor-1.4.0.jar:1.4.0-adf4a67]
 at
 
org.torproject.descriptor.impl.DescriptorReaderImpl$DescriptorReaderRunnable.readDescriptors(DescriptorReaderImpl.java:284)
 ~[descriptor-1.4.0.jar:1.4.0-adf4a67]
 at
 
org.torproject.descriptor.impl.DescriptorReaderImpl$DescriptorReaderRunnable.run(DescriptorReaderImpl.java:188)
 ~[descriptor-1.4.0.jar:1.4.0-adf4a67]
 at java.lang.Thread.run(Thread.java:745) [na:1.8.0_102]
 }}}

 I can't think of a clean way to avoid this problem other than keeping
 votes in the `recent/` folder in separate files.  Seriously, I didn't
 think of this error case at all.  Wow.

--
Ticket URL: 
Tor Bug Tracker & Wiki 
The Tor Project: anonymity online
___
tor-bugs mailing list
tor-bugs@lists.torproject.org
https://lists.torproject.org/cgi-bin/mailman/listinfo/tor-bugs

Re: [tor-bugs] #20335 [Metrics/CollecTor]: ReferenceChecker causes OOM

[Tor Bug Tracker & Wiki]

#20335: ReferenceChecker causes OOM
---+-
 Reporter:  iwakeh |  Owner:
 Type:  defect | Status:  new
 Priority:  High   |  Milestone:
Component:  Metrics/CollecTor  |Version:
 Severity:  Normal | Resolution:
 Keywords: |  Actual Points:
Parent ID: | Points:
 Reviewer: |Sponsor:
---+-

Comment (by iwakeh):

 Replying to [comment:10 karsten]:
 > I ''believe'' that's a smart thing to do.  I'm not sure if that would
 break something.

 Unfortunately, you're right and this was not the reason for the oom :-/

 >
 > But I think it doesn't solve the issue here.  Or, I ran out of memory
 with a similar patch applied.  And I think I know why:
 >
 > {{{
 > -rw-r--r--  1 karsten  staff   2.1G Oct 18 11:52
 /Users/karsten/src/collector/recent/relay-
 descriptors/votes/2016-10-18-09-22-46-votes
 > }}}
 >
 > With the recent change to append all votes to a single file, we're
 creating a 2.1G large file when doing the first synchronization run.
 However, metrics-lib wants to read that entire file to memory which
 probably doubles in size when it's parsed.  Ugh!
 >
 > Note that the CollecTor's reference checker is just one application that
 breaks when input files are too large.  Other applications using metrics-
 lib would similarly be affected.
 >
 > A longer-term fix might be to change metrics-lib to read through large
 files and pause when it has parsed enough descriptors that the application
 still has to process.

 Did you verify that metrics-lib is the culprit? Like, reading the 2G file
 for parsing?

 >
 > A short-term fix would be to stick with the current naming scheme for
 files in the `recent/` directory, as that would have avoided this issue.
 >

 The commit for the review in #18910 is easily adaptable, if necessary.

 > Fun times!

 Wouldn't it be boring without the unforeseen ;-)

--
Ticket URL: 
Tor Bug Tracker & Wiki 
The Tor Project: anonymity online
___
tor-bugs mailing list
tor-bugs@lists.torproject.org
https://lists.torproject.org/cgi-bin/mailman/listinfo/tor-bugs

Re: [tor-bugs] #20335 [Metrics/CollecTor]: ReferenceChecker causes OOM

[Tor Bug Tracker & Wiki]

#20335: ReferenceChecker causes OOM
---+-
 Reporter:  iwakeh |  Owner:
 Type:  defect | Status:  new
 Priority:  High   |  Milestone:
Component:  Metrics/CollecTor  |Version:
 Severity:  Normal | Resolution:
 Keywords: |  Actual Points:
Parent ID: | Points:
 Reviewer: |Sponsor:
---+-
Changes (by karsten):

 * priority:  Medium => High


Comment:

 I ''believe'' that's a smart thing to do.  I'm not sure if that would
 break something.

 But I think it doesn't solve the issue here.  Or, I ran out of memory with
 a similar patch applied.  And I think I know why:

 {{{
 -rw-r--r--  1 karsten  staff   2.1G Oct 18 11:52
 /Users/karsten/src/collector/recent/relay-
 descriptors/votes/2016-10-18-09-22-46-votes
 }}}

 With the recent change to append all votes to a single file, we're
 creating a 2.1G large file when doing the first synchronization run.
 However, metrics-lib wants to read that entire file to memory which
 probably doubles in size when it's parsed.  Ugh!

 Note that the CollecTor's reference checker is just one application that
 breaks when input files are too large.  Other applications using metrics-
 lib would similarly be affected.

 A longer-term fix might be to change metrics-lib to read through large
 files and pause when it has parsed enough descriptors that the application
 still has to process.

 A short-term fix would be to stick with the current naming scheme for
 files in the `recent/` directory, as that would have avoided this issue.

 Fun times!

--
Ticket URL: 
Tor Bug Tracker & Wiki 
The Tor Project: anonymity online
___
tor-bugs mailing list
tor-bugs@lists.torproject.org
https://lists.torproject.org/cgi-bin/mailman/listinfo/tor-bugs

Re: [tor-bugs] #20335 [Metrics/CollecTor]: ReferenceChecker causes OOM

[Tor Bug Tracker & Wiki]

#20335: ReferenceChecker causes OOM
---+-
 Reporter:  iwakeh |  Owner:
 Type:  defect | Status:  new
 Priority:  Medium |  Milestone:
Component:  Metrics/CollecTor  |Version:
 Severity:  Normal | Resolution:
 Keywords: |  Actual Points:
Parent ID: | Points:
 Reviewer: |Sponsor:
---+-

Comment (by iwakeh):

 I think I found a way to avoid the oom:

 The sync-process provides collector with many (in the constant*10E+6
 range) new descriptor references that are actually stale.  I added a check
 for the valid date to `addReference`, i.e.
 {{{

private void addReference(String referencing, String referenced,
double weight, long expiresAfterMillis) {
 -this.references.add(new Reference(referencing.toUpperCase(),
 -referenced.toUpperCase(), weight, expiresAfterMillis));
 +if (this.currentTimeMillis <= expiresAfterMillis) {
 +  this.references.add(new Reference(referencing.toUpperCase(),
 +  referenced.toUpperCase(), weight, expiresAfterMillis));
 +}
 }}}

 This seems to reduce the used memory; the sync-test is still running ...

 Is there anything problematic with this change that I missed?

--
Ticket URL: 
Tor Bug Tracker & Wiki 
The Tor Project: anonymity online
___
tor-bugs mailing list
tor-bugs@lists.torproject.org
https://lists.torproject.org/cgi-bin/mailman/listinfo/tor-bugs

Re: [tor-bugs] #20335 [Metrics/CollecTor]: ReferenceChecker causes OOM

[Tor Bug Tracker & Wiki]

#20335: ReferenceChecker causes OOM
---+-
 Reporter:  iwakeh |  Owner:
 Type:  defect | Status:  new
 Priority:  Medium |  Milestone:
Component:  Metrics/CollecTor  |Version:
 Severity:  Normal | Resolution:
 Keywords: |  Actual Points:
Parent ID: | Points:
 Reviewer: |Sponsor:
---+-

Comment (by iwakeh):

 Replying to [comment:7 karsten]:
 > ...
 >
 > I did run out of heap space while reading descriptors in a second run:

 Right, this is where the OOM occurs.  Without the reference checker out,
 there was no oom.

 But, I'll test this again with the reference checker included after
 applying the other changes from #18910.

--
Ticket URL: 
Tor Bug Tracker & Wiki 
The Tor Project: anonymity online
___
tor-bugs mailing list
tor-bugs@lists.torproject.org
https://lists.torproject.org/cgi-bin/mailman/listinfo/tor-bugs

Re: [tor-bugs] #20335 [Metrics/CollecTor]: ReferenceChecker causes OOM

[Tor Bug Tracker & Wiki]

#20335: ReferenceChecker causes OOM
---+-
 Reporter:  iwakeh |  Owner:
 Type:  defect | Status:  new
 Priority:  Medium |  Milestone:
Component:  Metrics/CollecTor  |Version:
 Severity:  Normal | Resolution:
 Keywords: |  Actual Points:
Parent ID: | Points:
 Reviewer: |Sponsor:
---+-

Comment (by karsten):

 Replying to [comment:4 iwakeh]:
 > Steps to reproduce (from #18910, the discussion should take place here):
 >
 [https://gitweb.torproject.org/user/iwakeh/collector.git/commit/?h=task-18910
 -first-sync=5eb89c10a0a720c1fa4eb806e5d5b5f2dee75b65 Collector branch]:
 Run the jar in a new location, i.e. with empty recent and out. Configure
 relaydescs and sync. RunOnce will be sufficient the OOM heap dump contains
 very many Reference objects. (Your assumption in one of the previous
 comments hinted in the right direction, I think, but I couldn't verify
 that yet.)

 Hmm, I didn't run out of memory while checking references.  And I don't
 quite understand how that would happen in an initial run, because the
 reference checker is run before the sync manager even starts to run.

 I did run out of heap space while reading descriptors in a second run:

 {{{
 $ java -DLOGBASE=log -jar collector-1.1.0-dev.jar
 2016-10-13 12:54:55,995 ERROR o.t.d.i.DescriptorReaderImpl:192 Bug:
 uncaught exception or error while reading descriptors: Java heap space
 java.lang.OutOfMemoryError: Java heap space
 at java.util.Arrays.copyOf(Arrays.java:3236) ~[na:1.8.0_102]
 at
 java.io.ByteArrayOutputStream.grow(ByteArrayOutputStream.java:118)
 ~[na:1.8.0_102]
 at
 java.io.ByteArrayOutputStream.ensureCapacity(ByteArrayOutputStream.java:93)
 ~[na:1.8.0_102]
 at
 java.io.ByteArrayOutputStream.write(ByteArrayOutputStream.java:153)
 ~[na:1.8.0_102]
 at
 
org.torproject.descriptor.impl.DescriptorReaderImpl$DescriptorReaderRunnable.readFile(DescriptorReaderImpl.java:378)
 ~[collector-1.1.0-dev.jar:1.1.0-dev-5eb89c1]
 at
 
org.torproject.descriptor.impl.DescriptorReaderImpl$DescriptorReaderRunnable.readDescriptors(DescriptorReaderImpl.java:284)
 ~[collector-1.1.0-dev.jar:1.1.0-dev-5eb89c1]
 at
 
org.torproject.descriptor.impl.DescriptorReaderImpl$DescriptorReaderRunnable.run(DescriptorReaderImpl.java:188)
 ~[collector-1.1.0-dev.jar:1.1.0-dev-5eb89c1]
 at java.lang.Thread.run(Thread.java:745) [na:1.8.0_102]
 }}}

 Can you try to put the reference checker back in and see if you still run
 out of memory somewhere?  I'm not yet convinced that it's the reference
 checker that is to blame here.

--
Ticket URL: 
Tor Bug Tracker & Wiki 
The Tor Project: anonymity online
___
tor-bugs mailing list
tor-bugs@lists.torproject.org
https://lists.torproject.org/cgi-bin/mailman/listinfo/tor-bugs

Re: [tor-bugs] #20335 [Metrics/CollecTor]: ReferenceChecker causes OOM

[Tor Bug Tracker & Wiki]

#20335: ReferenceChecker causes OOM
---+-
 Reporter:  iwakeh |  Owner:
 Type:  defect | Status:  new
 Priority:  Medium |  Milestone:
Component:  Metrics/CollecTor  |Version:
 Severity:  Normal | Resolution:
 Keywords: |  Actual Points:
Parent ID: | Points:
 Reviewer: |Sponsor:
---+-

Comment (by iwakeh):

 I forgot: such a db could solve the microdesc validAfter-date-in-out-path
 question, too.

--
Ticket URL: 
Tor Bug Tracker & Wiki 
The Tor Project: anonymity online
___
tor-bugs mailing list
tor-bugs@lists.torproject.org
https://lists.torproject.org/cgi-bin/mailman/listinfo/tor-bugs

Re: [tor-bugs] #20335 [Metrics/CollecTor]: ReferenceChecker causes OOM

[Tor Bug Tracker & Wiki]

#20335: ReferenceChecker causes OOM
---+-
 Reporter:  iwakeh |  Owner:
 Type:  defect | Status:  new
 Priority:  Medium |  Milestone:
Component:  Metrics/CollecTor  |Version:
 Severity:  Normal | Resolution:
 Keywords: |  Actual Points:
Parent ID: | Points:
 Reviewer: |Sponsor:
---+-

Comment (by iwakeh):

 Suggestion for, how to separate statistics:

 Well, mostly the code for the stats tries to implement database
 functionality, i.e. persistence between runs, queries, and cleaning data
 items that are too old.

 I think a simple hsqldb would be fine here. This needs just the hsqldb
 dependency (available in debian).  It creates the db if it is not there,
 below the stats path for example.   The data could be written from the
 newly introduced *Persistence classes.  The clean-up would be just a query
 per table (there are foreign keys and cascades available).  Schema and
 access rights are delivered with inside collector.jar hidden from the
 user. So, there is some freedom to adapt and change with time.

 An additional benefit would be that this db could be queried by command
 line for additional information. Or, the date could easily even be
 transferred to a 'real' dbms for continuous analysis, if necessary.

--
Ticket URL: 
Tor Bug Tracker & Wiki 
The Tor Project: anonymity online
___
tor-bugs mailing list
tor-bugs@lists.torproject.org
https://lists.torproject.org/cgi-bin/mailman/listinfo/tor-bugs

Re: [tor-bugs] #20335 [Metrics/CollecTor]: ReferenceChecker causes OOM

[Tor Bug Tracker & Wiki]

#20335: ReferenceChecker causes OOM
---+-
 Reporter:  iwakeh |  Owner:
 Type:  defect | Status:  new
 Priority:  Medium |  Milestone:
Component:  Metrics/CollecTor  |Version:
 Severity:  Normal | Resolution:
 Keywords: |  Actual Points:
Parent ID: | Points:
 Reviewer: |Sponsor:
---+-

Comment (by iwakeh):

 Steps to reproduce (from #18910, the discussion should take place here):
 [https://gitweb.torproject.org/user/iwakeh/collector.git/commit/?h=task-18910
 -first-sync=5eb89c10a0a720c1fa4eb806e5d5b5f2dee75b65 Collector branch]:
 Run the jar in a new location, i.e. with empty recent and out. Configure
 relaydescs and sync. RunOnce will be sufficient the OOM heap dump contains
 very many Reference objects. (Your assumption in one of the previous
 comments hinted in the right direction, I think, but I couldn't verify
 that yet.)

--
Ticket URL: 
Tor Bug Tracker & Wiki 
The Tor Project: anonymity online
___
tor-bugs mailing list
tor-bugs@lists.torproject.org
https://lists.torproject.org/cgi-bin/mailman/listinfo/tor-bugs

Re: [tor-bugs] #20335 [Metrics/CollecTor]: ReferenceChecker causes OOM

[Tor Bug Tracker & Wiki]

#20335: ReferenceChecker causes OOM
---+-
 Reporter:  iwakeh |  Owner:
 Type:  defect | Status:  new
 Priority:  Medium |  Milestone:
Component:  Metrics/CollecTor  |Version:
 Severity:  Normal | Resolution:
 Keywords: |  Actual Points:
Parent ID: | Points:
 Reviewer: |Sponsor:
---+-

Comment (by karsten):

 Replying to [comment:1 iwakeh]:
 > In addition, the reported statistics are somewhat doubtful, but I didn't
 explicitly verify.

 Can you elaborate?

--
Ticket URL: 
Tor Bug Tracker & Wiki 
The Tor Project: anonymity online
___
tor-bugs mailing list
tor-bugs@lists.torproject.org
https://lists.torproject.org/cgi-bin/mailman/listinfo/tor-bugs

Re: [tor-bugs] #20335 [Metrics/CollecTor]: ReferenceChecker causes OOM

[Tor Bug Tracker & Wiki]

#20335: ReferenceChecker causes OOM
---+-
 Reporter:  iwakeh |  Owner:
 Type:  defect | Status:  new
 Priority:  Medium |  Milestone:
Component:  Metrics/CollecTor  |Version:
 Severity:  Normal | Resolution:
 Keywords: |  Actual Points:
Parent ID: | Points:
 Reviewer: |Sponsor:
---+-

Comment (by iwakeh):

 In addition, the reported statistics are somewhat doubtful, but I didn't
 explicitly verify.

--
Ticket URL: 
Tor Bug Tracker & Wiki 
The Tor Project: anonymity online
___
tor-bugs mailing list
tor-bugs@lists.torproject.org
https://lists.torproject.org/cgi-bin/mailman/listinfo/tor-bugs