GitLab

I had to re-import all of May on the Onionoo mirror because it was offline for more than three days. Now it's running out of memory in the shut-down process. Logs and exception below:

2016-06-01 09:30:33,944 INFO o.t.o.cron.Main:92 Going to run one-time updater ... 
2016-06-01 09:30:34,002 INFO o.t.o.cron.Main:130 Initializing.
2016-06-01 09:30:34,005 INFO o.t.o.cron.Main:133 Acquired lock
2016-06-01 09:30:34,005 DEBUG o.t.o.cron.Main:152 Started update ...
2016-06-01 09:30:34,007 INFO o.t.o.cron.Main:155 Initialized descriptor source
2016-06-01 09:30:34,012 INFO o.t.o.cron.Main:159 Initialized document store
2016-06-01 09:30:34,029 INFO o.t.o.cron.Main:163 Initialized status update runner
2016-06-01 09:30:34,040 INFO o.t.o.cron.Main:168 Initialized document writer runner
2016-06-01 09:30:34,041 INFO o.t.o.cron.Main:176 Downloading descriptors.
2016-06-01 09:30:34,041 INFO o.t.o.u.DescriptorSource:64 Loading: RELAY_CONSENSUSES
2016-06-01 09:33:02,861 INFO o.t.o.u.DescriptorSource:64 Loading: RELAY_SERVER_DESCRIPTORS
2016-06-01 09:35:39,639 INFO o.t.o.u.DescriptorSource:64 Loading: RELAY_EXTRA_INFOS
2016-06-01 09:38:10,562 INFO o.t.o.u.DescriptorSource:64 Loading: EXIT_LISTS
2016-06-01 09:38:51,159 INFO o.t.o.u.DescriptorSource:64 Loading: BRIDGE_STATUSES
2016-06-01 09:40:29,716 INFO o.t.o.u.DescriptorSource:64 Loading: BRIDGE_SERVER_DESCRIPTORS
2016-06-01 09:41:58,737 INFO o.t.o.u.DescriptorSource:64 Loading: BRIDGE_EXTRA_INFOS
2016-06-01 09:43:44,958 INFO o.t.o.cron.Main:184 Reading descriptors.
2016-06-01 09:43:44,959 INFO o.t.o.u.DescriptorSource:153 Reading archived descriptors...
2016-06-02 02:51:09,249 INFO o.t.o.u.DescriptorSource:200 Read archived descriptors
2016-06-02 02:51:09,249 DEBUG o.t.o.u.DescriptorSource:84 Reading recent RELAY_SERVER_DESCRIPTORS ...
2016-06-02 02:53:01,224 INFO o.t.o.u.DescriptorSource:129 Read recent relay server descriptors
2016-06-02 02:53:01,224 DEBUG o.t.o.u.DescriptorSource:88 Reading recent RELAY_EXTRA_INFOS ...
2016-06-02 03:31:50,889 INFO o.t.o.u.DescriptorSource:132 Read recent relay extra-info descriptors
2016-06-02 03:31:50,890 DEBUG o.t.o.u.DescriptorSource:91 Reading recent EXIT_LISTS ...
2016-06-02 03:32:13,478 INFO o.t.o.u.DescriptorSource:135 Read recent exit lists
2016-06-02 03:32:13,479 DEBUG o.t.o.u.DescriptorSource:94 Reading recent RELAY_CONSENSUSES ...
2016-06-02 08:29:52,761 INFO o.t.o.u.DescriptorSource:126 Read recent relay network consensuses
2016-06-02 08:29:52,765 DEBUG o.t.o.u.DescriptorSource:97 Reading recent BRIDGE_SERVER_DESCRIPTORS ...
2016-06-02 08:31:32,294 INFO o.t.o.u.DescriptorSource:141 Read recent bridge server descriptors
2016-06-02 08:31:32,295 DEBUG o.t.o.u.DescriptorSource:101 Reading recent BRIDGE_EXTRA_INFOS ...
2016-06-02 09:22:29,247 INFO o.t.o.u.DescriptorSource:144 Read recent bridge extra-info descriptors
2016-06-02 09:22:29,247 DEBUG o.t.o.u.DescriptorSource:104 Reading recent BRIDGE_STATUSES ...
2016-06-02 09:23:44,681 INFO o.t.o.u.DescriptorSource:138 Read recent bridge network statuses
2016-06-02 09:23:44,682 INFO o.t.o.cron.Main:186 Updating internal status files.
2016-06-02 09:23:44,682 DEBUG o.t.o.u.StatusUpdateRunner:36 Begin update of NodeDetailsStatusUpdater
2016-06-02 09:25:02,021 INFO o.t.o.u.NodeDetailsStatusUpdater:379 Read node statuses
2016-06-02 09:25:12,500 INFO o.t.o.u.NodeDetailsStatusUpdater:381 Started reverse domain name lookups
2016-06-02 09:31:29,006 INFO o.t.o.u.NodeDetailsStatusUpdater:383 Looked up cities and ASes
2016-06-02 09:31:29,112 INFO o.t.o.u.NodeDetailsStatusUpdater:385 Calculated path selection probabilities
2016-06-02 09:31:29,224 INFO o.t.o.u.NodeDetailsStatusUpdater:387 Computed effective and extended families
2016-06-02 09:31:29,252 INFO o.t.o.u.NodeDetailsStatusUpdater:389 Finished reverse domain name lookups
2016-06-02 09:34:37,918 INFO o.t.o.u.NodeDetailsStatusUpdater:391 Updated node and details statuses
2016-06-02 09:34:37,918 INFO o.t.o.u.StatusUpdateRunner:38 NodeDetailsStatusUpdater updated status files
2016-06-02 09:34:37,918 DEBUG o.t.o.u.StatusUpdateRunner:36 Begin update of BandwidthStatusUpdater
2016-06-02 09:34:37,918 INFO o.t.o.u.StatusUpdateRunner:38 BandwidthStatusUpdater updated status files
2016-06-02 09:34:37,918 DEBUG o.t.o.u.StatusUpdateRunner:36 Begin update of WeightsStatusUpdater
2016-06-02 09:34:37,918 INFO o.t.o.u.StatusUpdateRunner:38 WeightsStatusUpdater updated status files
2016-06-02 09:34:37,919 DEBUG o.t.o.u.StatusUpdateRunner:36 Begin update of ClientsStatusUpdater
2016-06-02 09:47:57,798 INFO o.t.o.u.StatusUpdateRunner:38 ClientsStatusUpdater updated status files
2016-06-02 09:47:57,799 DEBUG o.t.o.u.StatusUpdateRunner:36 Begin update of UptimeStatusUpdater
2016-06-02 10:28:41,049 INFO o.t.o.u.StatusUpdateRunner:38 UptimeStatusUpdater updated status files
2016-06-02 10:28:41,049 INFO o.t.o.cron.Main:194 Updating document files.
2016-06-02 10:28:41,049 DEBUG o.t.o.w.DocumentWriterRunner:28 Writing SummaryDocumentWriter
2016-06-02 10:29:03,109 INFO o.t.o.w.SummaryDocumentWriter:97 Wrote summary document files
2016-06-02 10:29:03,110 DEBUG o.t.o.w.DocumentWriterRunner:28 Writing DetailsDocumentWriter
2016-06-02 10:33:58,870 INFO o.t.o.w.DetailsDocumentWriter:46 Wrote details document files
2016-06-02 10:33:58,870 DEBUG o.t.o.w.DocumentWriterRunner:28 Writing BandwidthDocumentWriter
2016-06-02 11:45:04,633 INFO o.t.o.w.BandwidthDocumentWriter:54 Wrote bandwidth document files
2016-06-02 11:45:04,634 DEBUG o.t.o.w.DocumentWriterRunner:28 Writing WeightsDocumentWriter
2016-06-02 12:19:42,480 INFO o.t.o.w.WeightsDocumentWriter:55 Wrote weights document files
2016-06-02 12:19:42,481 DEBUG o.t.o.w.DocumentWriterRunner:28 Writing ClientsDocumentWriter
2016-06-02 12:23:22,577 INFO o.t.o.w.ClientsDocumentWriter:84 Wrote clients document files
2016-06-02 12:23:22,577 DEBUG o.t.o.w.DocumentWriterRunner:28 Writing UptimeDocumentWriter
2016-06-02 12:39:58,477 INFO o.t.o.w.UptimeDocumentWriter:57 Wrote uptime document files
2016-06-02 12:39:58,477 INFO o.t.o.cron.Main:199 Shutting down.
2016-06-02 12:39:58,477 DEBUG o.t.o.u.DescriptorSource:204 Writing parse histories for recent descriptors...
2016-06-02 12:39:58,492 INFO o.t.o.cron.Main:202 Wrote parse histories

karsten@onionoo:/srv/onionoo.thecthulhu.com/onionoo$ java -DLOGBASE=/srv/onionoo.thecthulhu.com/onionoo/log-cron/ -Xmx4g -jar dist/onionoo-3.1.0.jar --single-run && java -DLOGBASE=/srv/onionoo.thecthulhu.com/onionoo/log-cron/ -Xmx4g -jar dist/onionoo-3.1.0.jar
Exception in thread "main" java.lang.OutOfMemoryError: Java heap space
        at java.util.Arrays.copyOf(Arrays.java:2367)
        at java.lang.AbstractStringBuilder.expandCapacity(AbstractStringBuilder.java:130)
        at java.lang.AbstractStringBuilder.ensureCapacityInternal(AbstractStringBuilder.java:114)
        at java.lang.AbstractStringBuilder.append(AbstractStringBuilder.java:415)
        at java.lang.StringBuilder.append(StringBuilder.java:132)
        at org.torproject.onionoo.docs.DocumentStore.writeNodeStatuses(DocumentStore.java:710)
        at org.torproject.onionoo.docs.DocumentStore.flushDocumentCache(DocumentStore.java:669)
        at org.torproject.onionoo.cron.Main.shutDown(Main.java:205)
        at org.torproject.onionoo.cron.Main.run(Main.java:121)
        at org.torproject.onionoo.cron.Main.runOrScheduleExecutions(Main.java:93)
        at org.torproject.onionoo.cron.Main.main(Main.java:32)

karsten@onionoo:/srv/onionoo.thecthulhu.com/onionoo$ ls -lh in/archive/
total 6.9G
-rw-r--r-- 1 karsten karsten 2.9G May 31 23:40 bridge-descriptors-2016-05.tar
-rw-r--r-- 1 karsten karsten 1.1G May 30 23:19 consensuses-2016-05.tar
-rw-r--r-- 1 karsten karsten 1.5G May 31 15:57 extra-infos-2016-05.tar
-rw-r--r-- 1 karsten karsten 1.5G May 31 12:41 server-descriptors-2016-05.tar

I didn't really start investigating. Note that it takes over 24 hours to do the processing, so we cannot reproduce this bug as easily.