Re: Reproduced: Re: FN cannot start

2019-06-13 Thread Steve Dougherty
Oh, interesting! Is this a symptom of a malformed client.dat.crypt? If you 
restore the file, does it fail in the same way again?

- Steve

Sent from ProtonMail Mobile

On Thu, Jun 13, 2019 at 10:36 AM, Krzysztof  wrote:

> No, I don't.
>
> What I discovered so far, after deleting file 'client.dat.crypt', the
> node started normally. Of course, all downloads were gone.
>
> Maybe there is a way to test or repair this file?
>
> Pozdrawiam
> Krzysztof Jasieński
>
> On 6/13/19 12:29 PM, Arne Babenhauserheide wrote:
>> My node now also stopped starting.
>>
>>
>> Question to Krzysztof: Do you have a darknet connection?
>>
>>
>> When run via ./run.sh console, this is the last line I see before
>> startup fails:
>>
>>
>> jvm 2 | Deleted 0 of 0 temporary files (0 non-temp files in temp directory) 
>> in 0s
>>
>>
>> This is what I should see:
>>
>>
>> jvm 1 | Resumed 4 requests ...
>> jvm 1 | Initializing USK Manager
>> jvm 1 | Loading cache of request statuses...
>> jvm 1 | Initializing Node Updater
>>
>>
>> Disabling all plugins does not make a difference.
>> Starting without the wrapper does not make a difference either.
>> Moving tmp away does not make a difference, either.
>> Moving datastore to datastore.broken does not make a difference.
>> Moving persistent-temp to persistent-temp.broken only lets it show one
>> more error:
>> jvm 1 | Unable to resume request
>> freenet.clients.fcp.ClientGet@45d042f9 after loading it.
>>
>> So it looks like there is some broken state which blocks startup.
>>
>>
>> logs/freenet-latest.log says
>>
>> Jun 13, 2019 09:18:00:317 (freenet.io.AddressTracker, 
>> WrapperListener_start_runner, WARNING): Failed to load from disk for port 
>> : freenet.node.FSParseException: Unable to load address tracker table, 
>> assuming an unclean shutdown: Last ID was  but stored 
>> freenet.node.FSParseException: Unable to load address tracker table, 
>> assuming an unclean shutdown: Last ID was  but stored 
>> at freenet.io.AddressTracker.(AddressTracker.java:115)
>> at freenet.io.AddressTracker.create(AddressTracker.java:84)
>> at freenet.io.comm.UdpSocketHandler.(UdpSocketHandler.java:161)
>> at freenet.node.NodeCrypto.(NodeCrypto.java:121)
>> at freenet.node.Node.(Node.java:1489)
>> at freenet.node.NodeStarter.start(NodeStarter.java:194)
>> at org.tanukisoftware.wrapper.WrapperManager$11.run(WrapperManager.java:4048)
>>
>>
>>
>> I took an application snapshot with jvisualvm: Here’s the threaddump
>>
>>
>> Full thread dump OpenJDK 64-Bit Server VM (25.191-b12 mixed mode):
>>
>> "Pooled thread awaiting work @1 for prio 5" #42 daemon prio=5 os_prio=0 
>> tid=0x7f68005f7000 nid=0x27ae in Object.wait() [0x7f681dc9e000]
>> java.lang.Thread.State: TIMED_WAITING (on object monitor)
>> at java.lang.Object.wait(Native Method)
>> - waiting on <0x9d22ff80> (a freenet.support.PooledExecutor$MyThread)
>> at freenet.support.PooledExecutor$MyThread.innerRun(PooledExecutor.java:218)
>> - locked <0x9d22ff80> (a freenet.support.PooledExecutor$MyThread)
>> at freenet.support.PooledExecutor$MyThread.realRun(PooledExecutor.java:189)
>> at freenet.support.io.NativeThread.run(NativeThread.java:156)
>>
>> Locked ownable synchronizers:
>> - None
>>
>> "Timer-0" #36 daemon prio=5 os_prio=0 tid=0x7f680009d000 nid=0x27a1 in 
>> Object.wait() [0x7f681e19f000]
>> java.lang.Thread.State: WAITING (on object monitor)
>> at java.lang.Object.wait(Native Method)
>> - waiting on <0x9cfdf0b0> (a java.util.TaskQueue)
>> at java.lang.Object.wait(Object.java:502)
>> at java.util.TimerThread.mainLoop(Timer.java:526)
>> - locked <0x9cfdf0b0> (a java.util.TaskQueue)
>> at java.util.TimerThread.run(Timer.java:505)
>>
>> Locked ownable synchronizers:
>> - None
>>
>> "SimpleToadletServer" #29 daemon prio=5 os_prio=0 tid=0x7f6800844800 
>> nid=0x2788 waiting on condition [0x7f681e4a]
>> java.lang.Thread.State: WAITING (parking)
>> at sun.misc.Unsafe.park(Native Method)
>> - parking to wait for <0x9cfdf740> (a 
>> java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
>> at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
>> at 
>> java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitUninterruptibly(AbstractQueuedSynchronizer.java:1976)
>> at freenet.io.NetworkInterface.accept(NetworkInterface.java:249)
>> at freenet.clients.http.SimpleToadletServer.run(SimpleToadletServer.java:999)
>> at java.lang.Thread.run(Thread.java:748)
>>
>> Locked ownable synchronizers:
>> - None
>>
>> "Network Interface Acceptor for 
>> ServerSocket[addr=/127.15.9.6,localport=8988](0)" #28 daemon prio=5 
>> os_prio=0 tid=0x7f6800843000 nid=0x2787 runnable [0x7f681e5a1000]
>> java.lang.Thread.State: RUNNABLE
>> at java.net.PlainSocketImpl.socketAccept(Native Method)
>> at java.net.AbstractPlainSocketImpl.accept(AbstractPlainSocketImpl.java:409)
>> at java.net.ServerSocket.implAccept(ServerSocket.java:545)
>> at 

Re: Reproduced: Re: FN cannot start

2019-06-13 Thread Krzysztof

No, I don't.

What I discovered so far, after deleting file 'client.dat.crypt', the 
node started normally. Of course, all downloads were gone.


Maybe there is a way to test or repair this file?

Pozdrawiam
Krzysztof Jasieński

On 6/13/19 12:29 PM, Arne Babenhauserheide wrote:

My node now also stopped starting.


Question to Krzysztof: Do you have a darknet connection?


When run via ./run.sh console, this is the last line I see before
startup fails:


jvm 2| Deleted 0 of 0 temporary files (0 non-temp files in temp directory) 
in 0s


This is what I should see:


jvm 1| Resumed 4 requests ...
jvm 1| Initializing USK Manager
jvm 1| Loading cache of request statuses...
jvm 1| Initializing Node Updater


Disabling all plugins does not make a difference.
Starting without the wrapper does not make a difference either.
Moving tmp away does not make a difference, either.
Moving datastore to datastore.broken does not make a difference.
Moving persistent-temp to persistent-temp.broken only lets it show one
 more error:
 jvm 1| Unable to resume request
 freenet.clients.fcp.ClientGet@45d042f9 after loading it.

So it looks like there is some broken state which blocks startup.


logs/freenet-latest.log says

Jun 13, 2019 09:18:00:317 (freenet.io.AddressTracker, 
WrapperListener_start_runner, WARNING): Failed to load from disk for port : 
freenet.node.FSParseException: Unable to load address tracker table, assuming 
an unclean shutdown: Last ID was  but stored 
freenet.node.FSParseException: Unable to load address tracker table, assuming 
an unclean shutdown: Last ID was  but stored 
at freenet.io.AddressTracker.(AddressTracker.java:115)
at freenet.io.AddressTracker.create(AddressTracker.java:84)
at freenet.io.comm.UdpSocketHandler.(UdpSocketHandler.java:161)
at freenet.node.NodeCrypto.(NodeCrypto.java:121)
at freenet.node.Node.(Node.java:1489)
at freenet.node.NodeStarter.start(NodeStarter.java:194)
at 
org.tanukisoftware.wrapper.WrapperManager$11.run(WrapperManager.java:4048)



I took an application snapshot with jvisualvm: Here’s the threaddump


Full thread dump OpenJDK 64-Bit Server VM (25.191-b12 mixed mode):

"Pooled thread awaiting work @1 for prio 5" #42 daemon prio=5 os_prio=0 
tid=0x7f68005f7000 nid=0x27ae in Object.wait() [0x7f681dc9e000]
java.lang.Thread.State: TIMED_WAITING (on object monitor)
 at java.lang.Object.wait(Native Method)
 - waiting on <0x9d22ff80> (a 
freenet.support.PooledExecutor$MyThread)
 at 
freenet.support.PooledExecutor$MyThread.innerRun(PooledExecutor.java:218)
 - locked <0x9d22ff80> (a 
freenet.support.PooledExecutor$MyThread)
 at 
freenet.support.PooledExecutor$MyThread.realRun(PooledExecutor.java:189)
 at freenet.support.io.NativeThread.run(NativeThread.java:156)

Locked ownable synchronizers:
 - None

"Timer-0" #36 daemon prio=5 os_prio=0 tid=0x7f680009d000 nid=0x27a1 in 
Object.wait() [0x7f681e19f000]
java.lang.Thread.State: WAITING (on object monitor)
 at java.lang.Object.wait(Native Method)
 - waiting on <0x9cfdf0b0> (a java.util.TaskQueue)
 at java.lang.Object.wait(Object.java:502)
 at java.util.TimerThread.mainLoop(Timer.java:526)
 - locked <0x9cfdf0b0> (a java.util.TaskQueue)
 at java.util.TimerThread.run(Timer.java:505)

Locked ownable synchronizers:
 - None

"SimpleToadletServer" #29 daemon prio=5 os_prio=0 tid=0x7f6800844800 
nid=0x2788 waiting on condition [0x7f681e4a]
java.lang.Thread.State: WAITING (parking)
 at sun.misc.Unsafe.park(Native Method)
 - parking to wait for  <0x9cfdf740> (a 
java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
 at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
 at 
java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitUninterruptibly(AbstractQueuedSynchronizer.java:1976)
 at freenet.io.NetworkInterface.accept(NetworkInterface.java:249)
 at 
freenet.clients.http.SimpleToadletServer.run(SimpleToadletServer.java:999)
 at java.lang.Thread.run(Thread.java:748)

Locked ownable synchronizers:
 - None

"Network Interface Acceptor for 
ServerSocket[addr=/127.15.9.6,localport=8988](0)" #28 daemon prio=5 os_prio=0 
tid=0x7f6800843000 nid=0x2787 runnable [0x7f681e5a1000]
java.lang.Thread.State: RUNNABLE
 at java.net.PlainSocketImpl.socketAccept(Native Method)
 at 
java.net.AbstractPlainSocketImpl.accept(AbstractPlainSocketImpl.java:409)
 at java.net.ServerSocket.implAccept(ServerSocket.java:545)
 at java.net.ServerSocket.accept(ServerSocket.java:513)
 at freenet.io.NetworkInterface$Acceptor.run(NetworkInterface.java:389)
 at 

Reproduced: Re: FN cannot start

2019-06-13 Thread Arne Babenhauserheide
My node now also stopped starting.


Question to Krzysztof: Do you have a darknet connection?


When run via ./run.sh console, this is the last line I see before
startup fails:


jvm 2| Deleted 0 of 0 temporary files (0 non-temp files in temp directory) 
in 0s


This is what I should see:


jvm 1| Resumed 4 requests ...
jvm 1| Initializing USK Manager
jvm 1| Loading cache of request statuses...
jvm 1| Initializing Node Updater


Disabling all plugins does not make a difference.
Starting without the wrapper does not make a difference either.
Moving tmp away does not make a difference, either.
Moving datastore to datastore.broken does not make a difference.
Moving persistent-temp to persistent-temp.broken only lets it show one
more error:
jvm 1| Unable to resume request
freenet.clients.fcp.ClientGet@45d042f9 after loading it.

So it looks like there is some broken state which blocks startup.


logs/freenet-latest.log says

Jun 13, 2019 09:18:00:317 (freenet.io.AddressTracker, 
WrapperListener_start_runner, WARNING): Failed to load from disk for port : 
freenet.node.FSParseException: Unable to load address tracker table, assuming 
an unclean shutdown: Last ID was  but stored 
freenet.node.FSParseException: Unable to load address tracker table, assuming 
an unclean shutdown: Last ID was  but stored 
at freenet.io.AddressTracker.(AddressTracker.java:115)
at freenet.io.AddressTracker.create(AddressTracker.java:84)
at freenet.io.comm.UdpSocketHandler.(UdpSocketHandler.java:161)
at freenet.node.NodeCrypto.(NodeCrypto.java:121)
at freenet.node.Node.(Node.java:1489)
at freenet.node.NodeStarter.start(NodeStarter.java:194)
at 
org.tanukisoftware.wrapper.WrapperManager$11.run(WrapperManager.java:4048)



I took an application snapshot with jvisualvm: Here’s the threaddump


Full thread dump OpenJDK 64-Bit Server VM (25.191-b12 mixed mode):

"Pooled thread awaiting work @1 for prio 5" #42 daemon prio=5 os_prio=0 
tid=0x7f68005f7000 nid=0x27ae in Object.wait() [0x7f681dc9e000]
   java.lang.Thread.State: TIMED_WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
- waiting on <0x9d22ff80> (a 
freenet.support.PooledExecutor$MyThread)
at 
freenet.support.PooledExecutor$MyThread.innerRun(PooledExecutor.java:218)
- locked <0x9d22ff80> (a 
freenet.support.PooledExecutor$MyThread)
at 
freenet.support.PooledExecutor$MyThread.realRun(PooledExecutor.java:189)
at freenet.support.io.NativeThread.run(NativeThread.java:156)

   Locked ownable synchronizers:
- None

"Timer-0" #36 daemon prio=5 os_prio=0 tid=0x7f680009d000 nid=0x27a1 in 
Object.wait() [0x7f681e19f000]
   java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
- waiting on <0x9cfdf0b0> (a java.util.TaskQueue)
at java.lang.Object.wait(Object.java:502)
at java.util.TimerThread.mainLoop(Timer.java:526)
- locked <0x9cfdf0b0> (a java.util.TaskQueue)
at java.util.TimerThread.run(Timer.java:505)

   Locked ownable synchronizers:
- None

"SimpleToadletServer" #29 daemon prio=5 os_prio=0 tid=0x7f6800844800 
nid=0x2788 waiting on condition [0x7f681e4a]
   java.lang.Thread.State: WAITING (parking)
at sun.misc.Unsafe.park(Native Method)
- parking to wait for  <0x9cfdf740> (a 
java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
at 
java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitUninterruptibly(AbstractQueuedSynchronizer.java:1976)
at freenet.io.NetworkInterface.accept(NetworkInterface.java:249)
at 
freenet.clients.http.SimpleToadletServer.run(SimpleToadletServer.java:999)
at java.lang.Thread.run(Thread.java:748)

   Locked ownable synchronizers:
- None

"Network Interface Acceptor for 
ServerSocket[addr=/127.15.9.6,localport=8988](0)" #28 daemon prio=5 os_prio=0 
tid=0x7f6800843000 nid=0x2787 runnable [0x7f681e5a1000]
   java.lang.Thread.State: RUNNABLE
at java.net.PlainSocketImpl.socketAccept(Native Method)
at 
java.net.AbstractPlainSocketImpl.accept(AbstractPlainSocketImpl.java:409)
at java.net.ServerSocket.implAccept(ServerSocket.java:545)
at java.net.ServerSocket.accept(ServerSocket.java:513)
at freenet.io.NetworkInterface$Acceptor.run(NetworkInterface.java:389)
at 
freenet.support.PooledExecutor$MyThread.innerRun(PooledExecutor.java:249)
at 
freenet.support.PooledExecutor$MyThread.realRun(PooledExecutor.java:189)
at freenet.support.io.NativeThread.run(NativeThread.java:156)

   Locked ownable synchronizers:
- None

"Plug" #27 prio=10 os_prio=0 tid=0x7f6800172800 nid=0x277f waiting on