On 9/25/19 9:36 PM, Steve Dougherty wrote:
Hm, I’m not loving the exception logging there; the stack trace of the
source of the problem does not appear to be included. The useful part of
that trace seems like
https://github.com/freenet/fred/blob/build01484/src/freenet/node/Node.java#L862
https://github.com/freenet/fred/blob/build01484/src/freenet/node/Node.java#L2900
I’d expect wrapper.log (or stderr depending on how you’ve started the
node) to contain more information after the string "Could not open store: "
Can you find such a log line?
Ah yes. It was in the wrapper.log, not in the freenet log where I was
looking.
And now that you've pointed that out, the problem was obvious: NFS
locking wasn't running!
After starting statd and lockd, switching the datastore type from ram to
salt-hash worked perfectly.
Thanks for your help!
The log:
----8<----
INFO | jvm 1 | 2019/08/18 20:36:40 | Setting datastore size to
524056200KiB
INFO | jvm 1 | 2019/08/18 20:36:40 | Initializing CHK Datastore
(7668822 keys)
INFO | jvm 1 | 2019/08/18 20:36:40 | Could not open store:
java.io.IOException: Operation not supported
INFO | jvm 1 | 2019/08/18 20:36:40 | java.io.IOException: Operation
not supported
INFO | jvm 1 | 2019/08/18 20:36:40 | at
sun.nio.ch.FileDispatcherImpl.lock0(Native Method)
INFO | jvm 1 | 2019/08/18 20:36:40 | at
sun.nio.ch.FileDispatcherImpl.lock(FileDispatcherImpl.java:94)
INFO | jvm 1 | 2019/08/18 20:36:40 | at
sun.nio.ch.FileChannelImpl.lock(FileChannelImpl.java:1072)
INFO | jvm 1 | 2019/08/18 20:36:40 | at
java.nio.channels.FileChannel.lock(FileChannel.java:1053)
INFO | jvm 1 | 2019/08/18 20:36:40 | at
freenet.store.saltedhash.SaltedHashFreenetStore.openStoreFiles(SaltedHashFreenetStore.java:838)
INFO | jvm 1 | 2019/08/18 20:36:40 | at
freenet.store.saltedhash.SaltedHashFreenetStore.<init>(SaltedHashFreenetStore.java:192)
INFO | jvm 1 | 2019/08/18 20:36:40 | at
freenet.store.saltedhash.SaltedHashFreenetStore.construct(SaltedHashFreenetStore.java:149)
INFO | jvm 1 | 2019/08/18 20:36:40 | at
freenet.node.Node.makeStore(Node.java:2980)
INFO | jvm 1 | 2019/08/18 20:36:40 | at
freenet.node.Node.makeStore(Node.java:2973)
INFO | jvm 1 | 2019/08/18 20:36:40 | at
freenet.node.Node.initSaltHashFS(Node.java:2803)
INFO | jvm 1 | 2019/08/18 20:36:40 | at
freenet.node.Node.makeStore(Node.java:862)
INFO | jvm 1 | 2019/08/18 20:36:40 | at
freenet.node.Node$StoreTypeCallback.set(Node.java:336)
INFO | jvm 1 | 2019/08/18 20:36:40 | at
freenet.node.Node$StoreTypeCallback.set(Node.java:309)
INFO | jvm 1 | 2019/08/18 20:36:40 | at
freenet.config.Option.set(Option.java:73)
INFO | jvm 1 | 2019/08/18 20:36:40 | at
freenet.config.Option.setValue(Option.java:62)
INFO | jvm 1 | 2019/08/18 20:36:40 | at
freenet.config.SubConfig.set(SubConfig.java:318)
INFO | jvm 1 | 2019/08/18 20:36:40 | at
freenet.clients.http.wizardsteps.DATASTORE_SIZE._setDatastoreSize(DATASTORE_SIZE.java:122)
INFO | jvm 1 | 2019/08/18 20:36:40 | at
freenet.clients.http.wizardsteps.DATASTORE_SIZE.postStep(DATASTORE_SIZE.java:93)
INFO | jvm 1 | 2019/08/18 20:36:40 | at
freenet.clients.http.FirstTimeWizardToadlet.handleMethodPOST(FirstTimeWizardToadlet.java:262)
INFO | jvm 1 | 2019/08/18 20:36:40 | at
sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
INFO | jvm 1 | 2019/08/18 20:36:40 | at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
INFO | jvm 1 | 2019/08/18 20:36:40 | at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
INFO | jvm 1 | 2019/08/18 20:36:40 | at
java.lang.reflect.Method.invoke(Method.java:498)
INFO | jvm 1 | 2019/08/18 20:36:40 | at
freenet.clients.http.ToadletContextImpl.callToadletMethod(ToadletContextImpl.java:747)
INFO | jvm 1 | 2019/08/18 20:36:40 | at
freenet.clients.http.ToadletContextImpl.handle(ToadletContextImpl.java:660)
INFO | jvm 1 | 2019/08/18 20:36:40 | at
freenet.clients.http.SimpleToadletServer$SocketHandler.run(SimpleToadletServer.java:1036)
INFO | jvm 1 | 2019/08/18 20:36:40 | at
freenet.support.PooledExecutor$MyThread.innerRun(PooledExecutor.java:249)
INFO | jvm 1 | 2019/08/18 20:36:40 | at
freenet.support.PooledExecutor$MyThread.realRun(PooledExecutor.java:189)
INFO | jvm 1 | 2019/08/18 20:36:40 | at
freenet.support.io.NativeThread.run(NativeThread.java:156)
----8<----
On Wed, Sep 25, 2019 at 8:07 PM, CyberLeo <cyber...@sdf.lonestar.org
<mailto:cyber...@sdf.lonestar.org>> wrote:
You know, I just realized I sent this from the wrong address and it
never made it to the list.
On 8/19/19 2:10 AM, CyberLeo wrote:
> During test-setup of a new node from Github release build01484, I get
> the following exception, both during the new startup wizard and whenever
> I instruct the node to change the datastore type from ram to salt-hash.
> The store type remains as ram.
>
> The node is a VM running FreeBSD 11.3-RELEASE amd64, NFS-mounted home
> directory from the host, and the host filesystem is backed by a
> dedicated ZFS dataset with plenty of space.
>
> Any ideas on how to start troubleshooting the source of this error?
>
> Thanks!
>
> ----8<----
> Aug 18, 2019 20:36:40:281 (freenet.node.Node, HTTP socket
> handler@1389158290(3), ERROR): Unable to create new store
> freenet.node.NodeInitException: Operation not supported (3)
> at freenet.node.Node.initSaltHashFS(Node.java:2900)
> at freenet.node.Node.makeStore(Node.java:862)
> at freenet.node.Node$StoreTypeCallback.set(Node.java:336)
> at freenet.node.Node$StoreTypeCallback.set(Node.java:309)
> at freenet.config.Option.set(Option.java:73)
> at freenet.config.Option.setValue(Option.java:62)
> at freenet.config.SubConfig.set(SubConfig.java:318)
> at
>
freenet.clients.http.wizardsteps.DATASTORE_SIZE._setDatastoreSize(DATASTORE_SIZE.java:122)
>
> at
>
freenet.clients.http.wizardsteps.DATASTORE_SIZE.postStep(DATASTORE_SIZE.java:93)
>
> at
>
freenet.clients.http.FirstTimeWizardToadlet.handleMethodPOST(FirstTimeWizardToadlet.java:262)
>
> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
> at
>
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
>
> at
>
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
>
> at java.lang.reflect.Method.invoke(Method.java:498)
> at
>
freenet.clients.http.ToadletContextImpl.callToadletMethod(ToadletContextImpl.java:747)
>
> at
>
freenet.clients.http.ToadletContextImpl.handle(ToadletContextImpl.java:660)
> at
>
freenet.clients.http.SimpleToadletServer$SocketHandler.run(SimpleToadletServer.java:1036)
>
> 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)
> Aug 18, 2019 20:36:40:305
> (freenet.clients.http.wizardsteps.DATASTORE_SIZE, HTTP socket
> handler@1389158290(3), ERROR): Should not happen, please
> report!freenet.config.InvalidConfigValueException: Unable to create new
> store: freenet.node.NodeInitException: Operation not supported (3)
> freenet.config.InvalidConfigValueException: Unable to create new store:
> freenet.node.NodeInitException: Operation not supported (3)
> at freenet.node.Node.makeStore(Node.java:868)
> at freenet.node.Node$StoreTypeCallback.set(Node.java:336)
> at freenet.node.Node$StoreTypeCallback.set(Node.java:309)
> at freenet.config.Option.set(Option.java:73)
> at freenet.config.Option.setValue(Option.java:62)
> at freenet.config.SubConfig.set(SubConfig.java:318)
> at
>
freenet.clients.http.wizardsteps.DATASTORE_SIZE._setDatastoreSize(DATASTORE_SIZE.java:122)
>
> at
>
freenet.clients.http.wizardsteps.DATASTORE_SIZE.postStep(DATASTORE_SIZE.java:93)
>
> at
>
freenet.clients.http.FirstTimeWizardToadlet.handleMethodPOST(FirstTimeWizardToadlet.java:262)
>
> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
> at
>
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
>
> at
>
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
>
> at java.lang.reflect.Method.invoke(Method.java:498)
> at
>
freenet.clients.http.ToadletContextImpl.callToadletMethod(ToadletContextImpl.java:747)
>
> at
>
freenet.clients.http.ToadletContextImpl.handle(ToadletContextImpl.java:660)
> at
>
freenet.clients.http.SimpleToadletServer$SocketHandler.run(SimpleToadletServer.java:1036)
>
> 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)
> ----8<----
>
--
Fuzzy love,
-CyberLeo
<cyber...@cyberleo.net>
Technical Administrator
CyberLeo.Net Webhosting
http://www.CyberLeo.Net
Element9 Communications
http://www.Element9.net
Furry Peace! - http://www.fur.com/peace/
