Am Freitag, 11. April 2008 15:19:57 schrieb Guido Winkelmann:
> Am Freitag, 11. April 2008 04:18:01 schrieb Daniel Cheng:
> > It's rebuilding the database and it would take some time for large
> > datastore. Do you have still any error message _before_ theses lines?
>
> The earliest messages in there look like this:
>
> INFO | jvm 4 | 2008/04/10 07:55:20 | Freed block 29889 (can't
> reconsturct key (freenet.store.SSKStore at 1123d4e))
> INFO | jvm 4 | 2008/04/10 07:55:20 | Bogus or unreconstructible key at
> slot 29890 : freenet.keys.SSKVerifyException: Unknown type byte 0 - lost
> block 29890
> INFO | jvm 4 | 2008/04/10 07:55:20 | Freed block 29890 (can't
> reconsturct key (freenet.store.SSKStore at 1123d4e))
> INFO | jvm 4 | 2008/04/10 07:55:20 | Bogus or unreconstructible key at
> slot 29891 : freenet.keys.SSKVerifyException: Unknown type byte 0 - lost
> block 29891
>
> The node has finished starting up just minutes ago, btw.
I spoke too early. The wrapper.log looks like this now (see attachment).
It looks like if this continues like this, the node will never ever actually
start up.
Guido
--
| _ | ASCII Ribbon Campaign Against HTML Emails.
| ( ) |
| X |
| / \ |
-------------- next part --------------
INFO | jvm 5 | 2008/04/11 15:11:01 | Freed block 330164 (duplicate)
INFO | jvm 5 | 2008/04/11 15:11:14 | Freed block 330237 (duplicate)
INFO | jvm 5 | 2008/04/11 15:11:39 | Freed block 330349 (duplicate)
INFO | jvm 5 | 2008/04/11 15:12:56 | Freed block 330547 (duplicate)
INFO | jvm 5 | 2008/04/11 15:12:56 | Freed block 330549 (duplicate)
INFO | jvm 5 | 2008/04/11 15:12:58 | Freed block 330557 (duplicate)
INFO | jvm 5 | 2008/04/11 15:13:49 | Key 330752/460332 OK (2760 dupes, 169
failures)
INFO | jvm 5 | 2008/04/11 15:13:56 | Freed block 330776 (duplicate)
INFO | jvm 5 | 2008/04/11 15:15:04 | Freed block 331018 (duplicate)
INFO | jvm 5 | 2008/04/11 15:15:14 | Freed block 331064 (duplicate)
INFO | jvm 5 | 2008/04/11 15:15:52 | Freed block 331178 (duplicate)
INFO | jvm 5 | 2008/04/11 15:15:55 | Freed block 331190 (duplicate)
INFO | jvm 5 | 2008/04/11 15:15:57 | Freed block 331197 (duplicate)
INFO | jvm 5 | 2008/04/11 15:16:14 | Freed block 331253 (duplicate)
INFO | jvm 5 | 2008/04/11 15:17:04 | Freed block 331496 (duplicate)
INFO | jvm 5 | 2008/04/11 15:17:08 | Freed block 331514 (duplicate)
INFO | jvm 5 | 2008/04/11 15:17:15 | Freed block 331548 (duplicate)
INFO | jvm 5 | 2008/04/11 15:17:16 | Freed block 331554 (duplicate)
ERROR | wrapper | 2008/04/11 15:17:22 | Startup failed: Timed out waiting for
signal from JVM.
ERROR | wrapper | 2008/04/11 15:17:23 | JVM did not exit on request,
terminated
STATUS | wrapper | 2008/04/11 15:17:27 | Reloading Wrapper configuration...
STATUS | wrapper | 2008/04/11 15:17:27 | Launching a JVM...
INFO | jvm 6 | 2008/04/11 15:17:30 | Wrapper (Version 3.2.3)
http://wrapper.tanukisoftware.org
INFO | jvm 6 | 2008/04/11 15:17:30 | Copyright 1999-2006 Tanuki
Software, Inc. All Rights Reserved.
INFO | jvm 6 | 2008/04/11 15:17:30 |
INFO | jvm 6 | 2008/04/11 15:17:30 | WARNING - The Wrapper jar file
currently in use is version "3.2.3"
INFO | jvm 6 | 2008/04/11 15:17:30 | while the version of the
Wrapper which launched this JVM is
INFO | jvm 6 | 2008/04/11 15:17:30 | "3.2.1".
INFO | jvm 6 | 2008/04/11 15:17:30 | The Wrapper may appear to
work correctly but some features may
INFO | jvm 6 | 2008/04/11 15:17:30 | not function correctly.
This configuration has not been tested
INFO | jvm 6 | 2008/04/11 15:17:30 | and is not supported.
INFO | jvm 6 | 2008/04/11 15:17:30 |
INFO | jvm 6 | 2008/04/11 15:17:30 | WARNING - The Wrapper jar file
currently in use is version "3.2.3"
INFO | jvm 6 | 2008/04/11 15:17:30 | while the version of the
native library is "3.2.1".
INFO | jvm 6 | 2008/04/11 15:17:30 | The Wrapper may appear to
work correctly but some features may
INFO | jvm 6 | 2008/04/11 15:17:30 | not function correctly.
This configuration has not been tested
INFO | jvm 6 | 2008/04/11 15:17:30 | and is not supported.
INFO | jvm 6 | 2008/04/11 15:17:30 |
INFO | jvm 6 | 2008/04/11 15:17:30 | freenet.jar built with
freenet-ext.jar Build #20 r18484
INFO | jvm 6 | 2008/04/11 15:17:31 |
INFO | jvm 6 | 2008/04/11 15:17:31 | Created log files
INFO | jvm 6 | 2008/04/11 15:17:31 | INFO: Native CPUID library
'freenet/support/CPUInformation/libjcpuid-x86-linux.so' loaded from resource
INFO | jvm 6 | 2008/04/11 15:17:31 | INFO: Optimized native BigInteger
library 'net/i2p/util/libjbigi-linux-athlon.so' loaded from resource
INFO | jvm 6 | 2008/04/11 15:17:31 | Attempting to load the NativeThread
library
[jar:file:/home/guido/freenet/freenet-ext.jar.new!/freenet/support/io/libNativeThread-i386.so]
INFO | jvm 6 | 2008/04/11 15:17:31 | Using the NativeThread implementation
(base nice level is 15)
INFO | jvm 6 | 2008/04/11 15:17:32 | Initializing Node using Freenet Build
#1135 r19099M and freenet-ext Build #20 r18484 with Sun Microsystems Inc. JVM
version 1.6.0_05 running on i386 Linux 2.6.23-gentoo-r3
INFO | jvm 6 | 2008/04/11 15:17:32 | Starting FProxy on 127.0.0.1:8888
INFO | jvm 6 | 2008/04/11 15:17:33 | FNP port created on 0.0.0.0:xxxx
INFO | jvm 6 | 2008/04/11 15:17:33 | Testnet mode DISABLED. You may have
some level of anonymity. :)
INFO | jvm 6 | 2008/04/11 15:17:33 | Note that this version of Freenet is
still a very early alpha, and may well have numerous bugs and design flaws.
INFO | jvm 6 | 2008/04/11 15:17:33 | In particular: YOU ARE WIDE OPEN TO
YOUR IMMEDIATE PEERS! They can eavesdrop on your requests with relatively
little difficulty at present (correlation attacks etc).
INFO | jvm 6 | 2008/04/11 15:17:33 | Creating PeerManager
INFO | jvm 6 | 2008/04/11 15:17:33 | Read 10 darknet peers from
./peers-xxxx
INFO | jvm 6 | 2008/04/11 15:17:33 | Starting database...
INFO | jvm 6 | 2008/04/11 15:18:03 | Initializing CHK Datastore (460332
keys)
INFO | jvm 6 | 2008/04/11 15:18:03 | Opening database using
datastore/chk-xxxx.store
INFO | jvm 6 | 2008/04/11 15:18:03 | Opened main database for chk-store-
INFO | jvm 6 | 2008/04/11 15:19:16 | Opening access times database for
chk-store-
INFO | jvm 6 | 2008/04/11 15:19:16 | Opened access times database for
chk-store-
INFO | jvm 6 | 2008/04/11 15:19:31 | Opening block db index
INFO | jvm 6 | 2008/04/11 15:19:31 | Opened block number database for
chk-store-
INFO | jvm 6 | 2008/04/11 15:19:32 | Keys in store: db 460332 file 460332
/ max 460332
INFO | jvm 6 | 2008/04/11 15:19:32 | Initializing CHK Datacache
(460333:460333 keys)
INFO | jvm 6 | 2008/04/11 15:19:32 | Opening database using
datastore/chk-xxxx.cache
INFO | jvm 6 | 2008/04/11 15:19:32 | Opened main database for chk-cache-
INFO | jvm 6 | 2008/04/11 15:20:37 | Opening access times database for
chk-cache-
INFO | jvm 6 | 2008/04/11 15:20:37 | Opened access times database for
chk-cache-
INFO | jvm 6 | 2008/04/11 15:20:39 | Opening block db index
INFO | jvm 6 | 2008/04/11 15:20:39 | Opened block number database for
chk-cache-
INFO | jvm 6 | 2008/04/11 15:20:40 | Keys in store: db 460333 file 460333
/ max 460333
INFO | jvm 6 | 2008/04/11 15:20:40 | Initializing pubKey Datastore
INFO | jvm 6 | 2008/04/11 15:20:40 | Opening database using
datastore/pubkey-xxxx.store
INFO | jvm 6 | 2008/04/11 15:20:40 | Opened main database for pubkey-store-
INFO | jvm 6 | 2008/04/11 15:20:49 | Opening access times database for
pubkey-store-
INFO | jvm 6 | 2008/04/11 15:20:49 | Opened access times database for
pubkey-store-
INFO | jvm 6 | 2008/04/11 15:20:50 | Opening block db index
INFO | jvm 6 | 2008/04/11 15:20:50 | Opened block number database for
pubkey-store-
INFO | jvm 6 | 2008/04/11 15:20:50 | Keys in store: db 104224 file 104224
/ max 460332
INFO | jvm 6 | 2008/04/11 15:20:50 | Initializing pubKey Datacache (460333
keys)
INFO | jvm 6 | 2008/04/11 15:20:50 | Opening database using
datastore/pubkey-xxxx.cache
INFO | jvm 6 | 2008/04/11 15:20:50 | Opened main database for pubkey-cache-
INFO | jvm 6 | 2008/04/11 15:21:15 | Opening access times database for
pubkey-cache-
INFO | jvm 6 | 2008/04/11 15:21:15 | Opened access times database for
pubkey-cache-
INFO | jvm 6 | 2008/04/11 15:21:15 | Opening block db index
INFO | jvm 6 | 2008/04/11 15:21:15 | Opened block number database for
pubkey-cache-
INFO | jvm 6 | 2008/04/11 15:21:15 | Keys in store: db 460333 file 460333
/ max 460333
INFO | jvm 6 | 2008/04/11 15:21:15 | Initializing SSK Datastore
INFO | jvm 6 | 2008/04/11 15:21:15 | Opening database using
datastore/ssk-xxxx.store
INFO | jvm 6 | 2008/04/11 15:21:15 | Opened main database for ssk-store-
INFO | jvm 6 | 2008/04/11 15:21:26 | Opening access times database for
ssk-store-
INFO | jvm 6 | 2008/04/11 15:21:26 | Opened access times database for
ssk-store-
INFO | jvm 6 | 2008/04/11 15:21:26 | Opening block db index
INFO | jvm 6 | 2008/04/11 15:21:26 | Opened block number database for
ssk-store-
INFO | jvm 6 | 2008/04/11 15:21:26 | Keys in store: db 110652 file 110653
/ max 460332
INFO | jvm 6 | 2008/04/11 15:21:26 | Initializing SSK Datacache (460333
keys)
INFO | jvm 6 | 2008/04/11 15:21:26 | Opening database using
datastore/ssk-xxxx.cache
INFO | jvm 6 | 2008/04/11 15:21:26 | Opened main database for ssk-cache-
INFO | jvm 6 | 2008/04/11 15:21:37 | Opening access times database for
ssk-cache-
INFO | jvm 6 | 2008/04/11 15:21:37 | Opened access times database for
ssk-cache-
INFO | jvm 6 | 2008/04/11 15:21:37 | Opening block db index
INFO | jvm 6 | 2008/04/11 15:21:37 | Opened block number database for
ssk-cache-
INFO | jvm 6 | 2008/04/11 15:21:37 | Keys in store: db 331581 file 460332
/ max 460332
INFO | jvm 6 | 2008/04/11 15:21:37 | Closed database
INFO | jvm 6 | 2008/04/11 15:21:37 | Caught exception, closing database:
com.sleepycat.je.DatabaseException: (JE 3.2.68) Keys in database: 331581 but
keys in file: 460332
INFO | jvm 6 | 2008/04/11 15:21:37 | com.sleepycat.je.DatabaseException:
(JE 3.2.68) Keys in database: 331581 but keys in file: 460332
INFO | jvm 6 | 2008/04/11 15:21:37 | at
freenet.store.BerkeleyDBFreenetStore.<init>(BerkeleyDBFreenetStore.java:463)
INFO | jvm 6 | 2008/04/11 15:21:37 | at
freenet.store.BerkeleyDBFreenetStore.openStore(BerkeleyDBFreenetStore.java:199)
INFO | jvm 6 | 2008/04/11 15:21:37 | at
freenet.store.BerkeleyDBFreenetStore.construct(BerkeleyDBFreenetStore.java:150)
INFO | jvm 6 | 2008/04/11 15:21:37 | at
freenet.node.Node.<init>(Node.java:1541)
INFO | jvm 6 | 2008/04/11 15:21:37 | at
freenet.node.NodeStarter.start(NodeStarter.java:157)
INFO | jvm 6 | 2008/04/11 15:21:37 | at
org.tanukisoftware.wrapper.WrapperManager$12.run(WrapperManager.java:2788)
INFO | jvm 6 | 2008/04/11 15:21:37 | Could not open store:
com.sleepycat.je.DatabaseException: (JE 3.2.68) Keys in database: 331581 but
keys in file: 460332
INFO | jvm 6 | 2008/04/11 15:21:37 | com.sleepycat.je.DatabaseException:
(JE 3.2.68) Keys in database: 331581 but keys in file: 460332
INFO | jvm 6 | 2008/04/11 15:21:37 | at
freenet.store.BerkeleyDBFreenetStore.<init>(BerkeleyDBFreenetStore.java:463)
INFO | jvm 6 | 2008/04/11 15:21:37 | at
freenet.store.BerkeleyDBFreenetStore.openStore(BerkeleyDBFreenetStore.java:199)
INFO | jvm 6 | 2008/04/11 15:21:37 | at
freenet.store.BerkeleyDBFreenetStore.construct(BerkeleyDBFreenetStore.java:150)
INFO | jvm 6 | 2008/04/11 15:21:37 | at
freenet.node.Node.<init>(Node.java:1541)
INFO | jvm 6 | 2008/04/11 15:21:37 | at
freenet.node.NodeStarter.start(NodeStarter.java:157)
INFO | jvm 6 | 2008/04/11 15:21:37 | at
org.tanukisoftware.wrapper.WrapperManager$12.run(WrapperManager.java:2788)
INFO | jvm 6 | 2008/04/11 15:21:37 | Attempting to reconstruct index...
INFO | jvm 6 | 2008/04/11 15:28:59 | Removed old database ssk-cache-
INFO | jvm 6 | 2008/04/11 15:28:59 | Creating block db index
INFO | jvm 6 | 2008/04/11 15:28:59 | Reconstructing store index from store
file: callback=freenet.store.SSKStore at 19c384e
INFO | jvm 6 | 2008/04/11 15:29:01 | Key 0/460332 OK (0 dupes, 0 failures)
INFO | jvm 6 | 2008/04/11 15:29:22 | Freed block 72 (duplicate)
INFO | jvm 6 | 2008/04/11 15:33:29 | Bogus or unreconstructible key at
slot 923 : freenet.keys.SSKVerifyException: No pubkey found - lost block 923
INFO | jvm 6 | 2008/04/11 15:33:29 | Freed block 923 (can't reconsturct
key (freenet.store.SSKStore at 19c384e))
INFO | jvm 6 | 2008/04/11 15:34:13 | Key 1024/460332 OK (1 dupes, 1
failures)
INFO | jvm 6 | 2008/04/11 15:38:13 | Freed block 1825 (duplicate)
INFO | jvm 6 | 2008/04/11 15:39:03 | Bogus or unreconstructible key at
slot 2017 : freenet.keys.SSKVerifyException: Unknown type byte 0 - lost block
2017
INFO | jvm 6 | 2008/04/11 15:39:03 | Freed block 2017 (can't reconsturct
key (freenet.store.SSKStore at 19c384e))
INFO | jvm 6 | 2008/04/11 15:39:11 | Key 2048/460332 OK (2 dupes, 2
failures)
INFO | jvm 6 | 2008/04/11 15:43:39 | Key 3072/460332 OK (2 dupes, 2
failures)
INFO | jvm 6 | 2008/04/11 15:44:20 | Freed block 3218 (duplicate)
INFO | jvm 6 | 2008/04/11 15:46:06 | Bogus or unreconstructible key at
slot 3714 : freenet.keys.SSKVerifyException: Unknown type byte 0 - lost block
3714
INFO | jvm 6 | 2008/04/11 15:46:06 | Freed block 3714 (can't reconsturct
key (freenet.store.SSKStore at 19c384e))
INFO | jvm 6 | 2008/04/11 15:47:14 | Bogus or unreconstructible key at
slot 4003 : freenet.keys.SSKVerifyException: Unknown type byte 0 - lost block
4003
INFO | jvm 6 | 2008/04/11 15:47:14 | Freed block 4003 (can't reconsturct
key (freenet.store.SSKStore at 19c384e))
INFO | jvm 6 | 2008/04/11 15:47:24 | Bogus or unreconstructible key at
slot 4062 : freenet.keys.SSKVerifyException: No pubkey found - lost block 4062
INFO | jvm 6 | 2008/04/11 15:47:24 | Freed block 4062 (can't reconsturct
key (freenet.store.SSKStore at 19c384e))
INFO | jvm 6 | 2008/04/11 15:47:32 | Key 4096/460332 OK (3 dupes, 5
failures)
INFO | jvm 6 | 2008/04/11 15:48:33 | Freed block 4382 (duplicate)
INFO | jvm 6 | 2008/04/11 15:48:57 | Freed block 4487 (duplicate)
INFO | jvm 6 | 2008/04/11 15:50:48 | Key 5120/460332 OK (5 dupes, 5
failures)
INFO | jvm 6 | 2008/04/11 15:51:46 | Freed block 5358 (duplicate)
INFO | jvm 6 | 2008/04/11 15:52:52 | Bogus or unreconstructible key at
slot 5639 : freenet.keys.SSKVerifyException: No pubkey found - lost block 5639
INFO | jvm 6 | 2008/04/11 15:52:52 | Freed block 5639 (can't reconsturct
key (freenet.store.SSKStore at 19c384e))
INFO | jvm 6 | 2008/04/11 15:53:32 | Freed block 5801 (duplicate)
INFO | jvm 6 | 2008/04/11 15:54:33 | Key 6144/460332 OK (7 dupes, 6
failures)
INFO | jvm 6 | 2008/04/11 15:54:36 | Freed block 6163 (duplicate)
INFO | jvm 6 | 2008/04/11 15:57:44 | Key 7168/460332 OK (8 dupes, 6
failures)
INFO | jvm 6 | 2008/04/11 15:59:25 | Freed block 7654 (duplicate)
INFO | jvm 6 | 2008/04/11 15:59:39 | Freed block 7723 (duplicate)
INFO | jvm 6 | 2008/04/11 16:00:33 | Freed block 8027 (duplicate)
INFO | jvm 6 | 2008/04/11 16:00:59 | Key 8192/460332 OK (11 dupes, 6
failures)
INFO | jvm 6 | 2008/04/11 16:01:34 | Freed block 8386 (duplicate)
INFO | jvm 6 | 2008/04/11 16:02:31 | Freed block 8765 (duplicate)
INFO | jvm 6 | 2008/04/11 16:02:52 | Freed block 8876 (duplicate)
INFO | jvm 6 | 2008/04/11 16:02:59 | Freed block 8910 (duplicate)
INFO | jvm 6 | 2008/04/11 16:03:55 | Key 9216/460332 OK (15 dupes, 6
failures)
INFO | jvm 6 | 2008/04/11 16:05:01 | Freed block 9553 (duplicate)
INFO | jvm 6 | 2008/04/11 16:05:24 | Freed block 9657 (duplicate)
INFO | jvm 6 | 2008/04/11 16:07:10 | Key 10240/460332 OK (17 dupes, 6
failures)
INFO | jvm 6 | 2008/04/11 16:07:14 | Freed block 10265 (duplicate)
INFO | jvm 6 | 2008/04/11 16:10:44 | Freed block 11249 (duplicate)
INFO | jvm 6 | 2008/04/11 16:10:47 | Key 11264/460332 OK (19 dupes, 6
failures)
INFO | jvm 6 | 2008/04/11 16:10:54 | Freed block 11301 (duplicate)
INFO | jvm 6 | 2008/04/11 16:11:00 | Freed block 11330 (duplicate)
INFO | jvm 6 | 2008/04/11 16:11:05 | Freed block 11358 (duplicate)
INFO | jvm 6 | 2008/04/11 16:11:23 | Freed block 11454 (duplicate)
INFO | jvm 6 | 2008/04/11 16:11:35 | Freed block 11517 (duplicate)
INFO | jvm 6 | 2008/04/11 16:11:40 | Freed block 11544 (duplicate)
INFO | jvm 6 | 2008/04/11 16:11:48 | Freed block 11586 (duplicate)
INFO | jvm 6 | 2008/04/11 16:12:29 | Freed block 11813 (duplicate)
INFO | jvm 6 | 2008/04/11 16:12:40 | Freed block 11877 (duplicate)
INFO | jvm 6 | 2008/04/11 16:12:49 | Freed block 11910 (duplicate)
INFO | jvm 6 | 2008/04/11 16:14:00 | Key 12288/460332 OK (29 dupes, 6
failures)
INFO | jvm 6 | 2008/04/11 16:14:07 | Freed block 12335 (duplicate)
INFO | jvm 6 | 2008/04/11 16:14:18 | Freed block 12403 (duplicate)
INFO | jvm 6 | 2008/04/11 16:14:19 | Freed block 12405 (duplicate)
INFO | jvm 6 | 2008/04/11 16:14:45 | Freed block 12567 (duplicate)
INFO | jvm 6 | 2008/04/11 16:15:26 | Freed block 12811 (duplicate)
INFO | jvm 6 | 2008/04/11 16:15:26 | Freed block 12814 (duplicate)
INFO | jvm 6 | 2008/04/11 16:15:40 | Freed block 12861 (duplicate)
INFO | jvm 6 | 2008/04/11 16:15:46 | Freed block 12896 (duplicate)
INFO | jvm 6 | 2008/04/11 16:15:56 | Freed block 12955 (duplicate)
INFO | jvm 6 | 2008/04/11 16:16:25 | Freed block 13127 (duplicate)
INFO | jvm 6 | 2008/04/11 16:16:48 | Key 13312/460332 OK (39 dupes, 6
failures)
INFO | jvm 6 | 2008/04/11 16:17:01 | Freed block 13489 (duplicate)
INFO | jvm 6 | 2008/04/11 16:17:12 | Freed block 13610 (duplicate)
INFO | jvm 6 | 2008/04/11 16:17:14 | Freed block 13643 (duplicate)
INFO | jvm 6 | 2008/04/11 16:17:15 | Freed block 13650 (duplicate)
INFO | jvm 6 | 2008/04/11 16:17:23 | Freed block 13737 (duplicate)
INFO | jvm 6 | 2008/04/11 16:17:31 | Freed block 13794 (duplicate)
INFO | jvm 6 | 2008/04/11 16:17:45 | Bogus or unreconstructible key at
slot 13880 : freenet.keys.SSKVerifyException: No pubkey found - lost block 13880
INFO | jvm 6 | 2008/04/11 16:17:45 | Freed block 13880 (can't reconsturct
key (freenet.store.SSKStore at 19c384e))
INFO | jvm 6 | 2008/04/11 16:18:08 | Freed block 14136 (duplicate)
