Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Error on registering local node on cluster #7059

Closed
1 task
Rucchao opened this issue Jan 5, 2017 · 16 comments
Closed
1 task

Error on registering local node on cluster #7059

Rucchao opened this issue Jan 5, 2017 · 16 comments
Assignees
Labels
Milestone

Comments

@Rucchao
Copy link

Rucchao commented Jan 5, 2017

OrientDB Version, operating system, or hardware.

  • v2.2.14

Operating System

  • Linux

Expected behavior and actual behavior

Starting node in cluster for the first time
./dserver.sh (default configuration)

Steps to reproduce the problem

Error on publishing local server configuration [OHazelcastPlugin]

2017-01-05 12:35:36:350 SEVER [node1483612532316] Error on publishing local server configuration [OHazelcastPlugin]
2017-01-05 12:35:36:350 SEVER [node1483612532316] Error on registering local node on cluster [OHazelcastPlugin][node1483612532316] Error on starting distributed plugin
com.orientechnologies.orient.server.distributed.ODistributedStartupException: Error on registering local node on cluster
        at com.orientechnologies.orient.server.hazelcast.OHazelcastPlugin.startup(OHazelcastPlugin.java:213)
        at com.orientechnologies.orient.server.OServer.registerPlugins(OServer.java:1242)
        at com.orientechnologies.orient.server.OServer.activate(OServer.java:397)
        at com.orientechnologies.orient.server.OServerMain$1.run(OServerMain.java:46)
com.orientechnologies.orient.server.distributed.ODistributedStartupException: Error on starting distributed plugin
        at com.orientechnologies.orient.server.hazelcast.OHazelcastPlugin.startup(OHazelcastPlugin.java:262)
        at com.orientechnologies.orient.server.OServer.registerPlugins(OServer.java:1242)
        at com.orientechnologies.orient.server.OServer.activate(OServer.java:397)
        at com.orientechnologies.orient.server.OServerMain$1.run(OServerMain.java:46)
Caused by: com.orientechnologies.orient.server.distributed.ODistributedStartupException: Error on registering local node on cluster
        at com.orientechnologies.orient.server.hazelcast.OHazelcastPlugin.startup(OHazelcastPlugin.java:213)
        ... 3 more
 Error on publishing local server configuration [OHazelcastPlugin]

Any help would be appreciate ! Thanks !

@lvca
Copy link
Member

lvca commented Jan 5, 2017

We'd need the entire log, please.

@lvca lvca self-assigned this Jan 5, 2017
@Rucchao
Copy link
Author

Rucchao commented Jan 5, 2017

2017-01-05 12:41:55:794 INFO  Loading configuration from: /chzhang/orientdb/orientdb-community-2.2.14/config/orientdb-server-config.xml... [OServerConfigurationLoaderXml]
2017-01-05 12:41:56:133 INFO  OrientDB Server v2.2.14 (build 2.2.x@r483093384e4fdbe825e2de0950f007776ee27a84; 2016-12-22 14:57:07+0000) is starting up... [OServer]
2017-01-05 12:41:56:140 INFO  Databases directory: /chzhang/orientdb/orientdb-community-2.2.14/databases [OServer]
2017-01-05 12:41:56:193 INFO  OrientDB auto-config DISKCACHE=26����188MB (heap=3����926MB direct=524����288MB os=32����162MB) [orientechnologies]
2017-01-05 12:41:56:372 INFO  Listening binary connections on 0.0.0.0:2424 (protocol v.36, socket=default) [OServerNetworkListener]
2017-01-05 12:41:56:376 INFO  Listening http connections on 0.0.0.0:2480 (protocol v.10, socket=default) [OServerNetworkListener]
2017-01-05 12:41:56:386 INFO  Installing dynamic plugin 'studio-2.2.zip'... [OServerPluginManager]
2017-01-05 12:41:56:390 INFO  ODefaultPasswordAuthenticator is active [ODefaultPasswordAuthenticator]
2017-01-05 12:41:56:391 INFO  OServerConfigAuthenticator is active [OServerConfigAuthenticator]
2017-01-05 12:41:56:392 INFO  OSystemUserAuthenticator is active [OSystemUserAuthenticator]
2017-01-05 12:41:56:416 INFO  Installed GREMLIN language v.2.6.0 - graph.pool.max=50 [OGraphServerHandler]
2017-01-05 12:41:56:531 WARNI {db=OSystem} Storage 'OSystem' was not closed properly. Will try to recover from write ahead log [OLocalPaginatedStorage]
2017-01-05 12:41:56:531 INFO  {db=OSystem} Looking for last checkpoint... [OLocalPaginatedStorage]
2017-01-05 12:41:57:010 INFO  {db=OSystem} FULL checkpoint found. [OLocalPaginatedStorage]
2017-01-05 12:41:57:011 INFO  {db=OSystem} Data restore procedure from full checkpoint is started. Restore is performed from LSN LSN{segment=0, position=129759} [OLocalPaginatedStorage]
2017-01-05 12:41:57:014 WARNI {db=OSystem} Record com.orientechnologies.orient.core.storage.impl.local.paginated.wal.OCheckpointEndRecord{lsn=LSN{segment=0, position=129783}} will be skipped during data restore [OLocalPaginatedStorage]
2017-01-05 12:41:57:015 INFO  {db=OSystem} 1 operations were processed, current LSN is LSN{segment=0, position=129783} last LSN is LSN{segment=0, position=367251} [OLocalPaginatedStorage]
2017-01-05 12:41:57:017 WARNI {db=OSystem} Non tx operation was used during data modification we will need index rebuild. [OLocalPaginatedStorage]
2017-01-05 12:41:57:066 INFO  {db=OSystem} Storage data recover was completed [OLocalPaginatedStorage]
2017-01-05 12:41:57:601 INFO  {db=OSystem} Wait till indexes restore after crash was finished. [OIndexManagerShared]
2017-01-05 12:41:57:727 INFO  {db=OSystem} Start creation of index 'ORole.name' [OIndexManagerShared$RecreateIndexesTask]
2017-01-05 12:41:57:945 INFO  {db=OSystem} Index 'ORole.name' was successfully created and rebuild is going to be started [OIndexManagerShared$RecreateIndexesTask]
2017-01-05 12:41:58:294 INFO  {db=OSystem} - Rebuilding index OSystem.ORole.name (estimated 3 items)... [OIndexRebuildOutputListener]
2017-01-05 12:41:58:303 INFO  {db=OSystem} --> OK, indexed 3 items in 9 ms [OIndexRebuildOutputListener]
2017-01-05 12:41:58:311 INFO  {db=OSystem} Rebuild of 'ORole.name index was successfully finished [OIndexManagerShared$RecreateIndexesTask]
2017-01-05 12:41:58:402 INFO  {db=OSystem} Start creation of index 'OUser.name' [OIndexManagerShared$RecreateIndexesTask]
2017-01-05 12:41:58:594 INFO  {db=OSystem} Index 'OUser.name' was successfully created and rebuild is going to be started [OIndexManagerShared$RecreateIndexesTask]
2017-01-05 12:41:58:886 INFO  {db=OSystem} Rebuild of 'OUser.name index was successfully finished [OIndexManagerShared$RecreateIndexesTask]
2017-01-05 12:41:58:889 INFO  {db=OSystem} Index 'dictionary' is not automatic index and will be added as is [OIndexManagerShared$RecreateIndexesTask]
2017-01-05 12:41:58:889 INFO  {db=OSystem} Index 'dictionary' was added in DB index list [OIndexManagerShared$RecreateIndexesTask]
2017-01-05 12:41:59:077 INFO  {db=OSystem} Start creation of index 'OFunction.name' [OIndexManagerShared$RecreateIndexesTask]
2017-01-05 12:41:59:512 INFO  {db=OSystem} Index 'OFunction.name' was successfully created and rebuild is going to be started [OIndexManagerShared$RecreateIndexesTask]
2017-01-05 12:42:00:137 INFO  {db=OSystem} Rebuild of 'OFunction.name index was successfully finished [OIndexManagerShared$RecreateIndexesTask]
2017-01-05 12:42:00:147 INFO  {db=OSystem} 4 indexes were restored successfully, 0 errors [OIndexManagerShared$RecreateIndexesTask]
2017-01-05 12:42:00:911 INFO  {db=OSystem} Indexes restore after crash was finished. [OIndexManagerShared]
2017-01-05 12:42:01:062 INFO  Configuring Hazelcast from '/chzhang/orientdb/orientdb-community-2.2.14/config/hazelcast.xml'. [FileSystemXmlConfig]
2017-01-05 12:42:01:123 WARNI Name of the hazelcast schema location incorrect using default [AbstractXmlConfigHelper]
2017-01-05 12:42:01:397 INFO  [LOCAL] [orientdb] [3.6.5] Prefer IPv4 stack is true. [DefaultAddressPicker]
2017-01-05 12:42:01:407 INFO  [LOCAL] [orientdb] [3.6.5] Picked Address[x]:2434, using socket ServerSocket[addr=/0:0:0:0:0:0:0:0,localport=2434], bind any local is true [DefaultAddressPicker]
2017-01-05 12:42:01:421 INFO  [x]:2434 [orientdb] [3.6.5] Hazelcast 3.6.5 (20160823 - e4af3d9) starting at Address[x]:2434 [system]
2017-01-05 12:42:01:421 INFO  [x]:2434 [orientdb] [3.6.5] Copyright (c) 2008-2016, Hazelcast, Inc. All Rights Reserved. [system]
2017-01-05 12:42:01:421 INFO  [x]:2434 [orientdb] [3.6.5] Configured Hazelcast Serialization version : 1 [system]
2017-01-05 12:42:01:629 INFO  [x]:2434 [orientdb] [3.6.5] Backpressure is disabled [OperationService]
2017-01-05 12:42:01:656 INFO  [x]:2434 [orientdb] [3.6.5] Starting with 1 generic operation threads and 1 partition operation threads. [ClassicOperationExecutor]
2017-01-05 12:42:02:061 INFO  [x]:2434 [orientdb] [3.6.5] Creating MulticastJoiner [Node]
2017-01-05 12:42:02:065 INFO  [x]:2434 [orientdb] [3.6.5] Address[x]:2434 is STARTING [LifecycleService]
2017-01-05 12:42:02:158 INFO  [x]:2434 [orientdb] [3.6.5] TcpIpConnectionManager configured with Non Blocking IO-threading model: 3 input threads and 3 output threads [NonBlockingIOThreadingModel]
2017-01-05 12:42:04:309 INFO  [x]:2434 [orientdb] [3.6.5] 


Members [1] {
	Member [x]:2434 this
}
 [MulticastJoiner]
2017-01-05 12:42:04:340 INFO  [x]:2434 [orientdb] [3.6.5] Address[x]:2434 is STARTED [LifecycleService]
2017-01-05 12:42:04:340 INFO  Starting distributed server 'node1483612532316' (hzID=c3840337-7990-4f49-bbf7-54d5a2e351c0)... [OHazelcastPlugin]
2017-01-05 12:42:04:344 INFO  Distributed cluster time=Thu Jan 05 12:42:04 EET 2017 (delta from local node=0)... [OHazelcastPlugin]
2017-01-05 12:42:04:384 INFO  [x]:2434 [orientdb] [3.6.5] Initializing cluster partition table arrangement... [InternalPartitionService]
2017-01-05 12:42:04:438 INFO  [x]:2434 [orientdb] [3.6.5] Partition assignments changed while executing query: TruePredicate{} [MapQueryEngineImpl]
2017-01-05 12:42:04:475 INFO  [node1483612532316] Loaded configuration for database 'OSystem' from disk: /chzhang/orientdb/orientdb-community-2.2.14/config/default-distributed-db-config.json [ODistributedStorage]
2017-01-05 12:42:04:485 WARNI [node1483612532316] Servers in cluster: [node1483612532316] [OHazelcastPlugin]
2017-01-05 12:42:04:492 SEVER [node1483612532316] Error on publishing local server configuration [OHazelcastPlugin]
2017-01-05 12:42:04:493 SEVER [node1483612532316] Error on registering local node on cluster [OHazelcastPlugin][node1483612532316] Error on starting distributed plugin
com.orientechnologies.orient.server.distributed.ODistributedStartupException: Error on registering local node on cluster
	at com.orientechnologies.orient.server.hazelcast.OHazelcastPlugin.startup(OHazelcastPlugin.java:213)
	at com.orientechnologies.orient.server.OServer.registerPlugins(OServer.java:1242)
	at com.orientechnologies.orient.server.OServer.activate(OServer.java:397)
	at com.orientechnologies.orient.server.OServerMain$1.run(OServerMain.java:46)

@Rucchao
Copy link
Author

Rucchao commented Jan 5, 2017

I am wondering if it is caused by any files which need read or wirte rights ?

@lvca
Copy link
Member

lvca commented Jan 5, 2017

It looks like the starting node is unable to register on Hazelcast cluster. Could you try to replace x with your actual ip address? Try with 127.0.0.1 first.

@Rucchao
Copy link
Author

Rucchao commented Jan 5, 2017

Could you please tell me in which file should i configure this ip ? Thanks.

@Rucchao
Copy link
Author

Rucchao commented Jan 5, 2017

Hi, lvca:
I changed the hazelcast.html to this:

<network>
	<port auto-increment="true">2434</port>
	<join>
		<multicast enabled="false">
			<multicast-group>235.1.1.1</multicast-group>
			<multicast-port>2434</multicast-port>
		</multicast>
  <tcp-ip enabled="true">
    <member>127.0.0.1:2434</member>
  </tcp-ip>
</join>
</network>
<executor-service>
	<pool-size>16</pool-size>
</executor-service>

The problem remains.

@Rucchao
Copy link
Author

Rucchao commented Jan 5, 2017

Now I have no ideas, the log is as follows:

2017-01-05 13:21:10:264 INFO  Loading configuration from: /chzhang/orientdb/orientdb-community-2.2.14/config/orientdb-server-config.xml... [OServerConfigurationLoaderXml]
2017-01-05 13:21:10:603 INFO  OrientDB Server v2.2.14 (build 2.2.x@r483093384e4fdbe825e2de0950f007776ee27a84; 2016-12-22 14:57:07+0000) is starting up... [OServer]
2017-01-05 13:21:10:610 INFO  Databases directory: /chzhang/orientdb/orientdb-community-2.2.14/databases [OServer]
2017-01-05 13:21:10:663 INFO  OrientDB auto-config DISKCACHE=26����188MB (heap=3����926MB direct=524����288MB os=32����162MB) [orientechnologies]
2017-01-05 13:21:10:842 WARNI Port 0.0.0.0:2424 busy, trying the next available... [OServerNetworkListener]
2017-01-05 13:21:10:842 WARNI Port 0.0.0.0:2425 busy, trying the next available... [OServerNetworkListener]
2017-01-05 13:21:10:843 WARNI Port 0.0.0.0:2426 busy, trying the next available... [OServerNetworkListener]
2017-01-05 13:21:10:844 INFO  Listening binary connections on 0.0.0.0:2427 (protocol v.36, socket=default) [OServerNetworkListener]
2017-01-05 13:21:10:847 WARNI Port 0.0.0.0:2480 busy, trying the next available... [OServerNetworkListener]
2017-01-05 13:21:10:848 WARNI Port 0.0.0.0:2481 busy, trying the next available... [OServerNetworkListener]
2017-01-05 13:21:10:849 WARNI Port 0.0.0.0:2482 busy, trying the next available... [OServerNetworkListener]
2017-01-05 13:21:10:849 INFO  Listening http connections on 0.0.0.0:2483 (protocol v.10, socket=default) [OServerNetworkListener]
2017-01-05 13:21:10:859 INFO  Installing dynamic plugin 'studio-2.2.zip'... [OServerPluginManager]
2017-01-05 13:21:10:863 INFO  ODefaultPasswordAuthenticator is active [ODefaultPasswordAuthenticator]
2017-01-05 13:21:10:864 INFO  OServerConfigAuthenticator is active [OServerConfigAuthenticator]
2017-01-05 13:21:10:865 INFO  OSystemUserAuthenticator is active [OSystemUserAuthenticator]
2017-01-05 13:21:10:889 INFO  Installed GREMLIN language v.2.6.0 - graph.pool.max=50 [OGraphServerHandler]
2017-01-05 13:21:10:968 SEVER {db=OSystem} File lock is null , file lock is not released [OPaginatedStorageDirtyFlag]
2017-01-05 13:21:10:968 SEVER getUser() Exception: Cannot open local storage '/chzhang/orientdb/orientdb-community-2.2.14/databases/OSystem' with mode=rw
	DB name="OSystem" [OSystemUserAuthenticator]
2017-01-05 13:21:11:042 INFO  Configuring Hazelcast from '/chzhang/orientdb/orientdb-community-2.2.14/config/hazelcast.xml'. [FileSystemXmlConfig]
2017-01-05 13:21:11:101 WARNI Name of the hazelcast schema location incorrect using default [AbstractXmlConfigHelper]
2017-01-05 13:21:11:374 INFO  [LOCAL] [orientdb] [3.6.5] Interfaces is disabled, trying to pick one address from TCP-IP config addresses: [127.0.0.1] [DefaultAddressPicker]
2017-01-05 13:21:11:380 INFO  [LOCAL] [orientdb] [3.6.5] Picked Address[127.0.0.1]:2436, using socket ServerSocket[addr=/0:0:0:0:0:0:0:0,localport=2436], bind any local is true [DefaultAddressPicker]
2017-01-05 13:21:11:394 INFO  [127.0.0.1]:2436 [orientdb] [3.6.5] Hazelcast 3.6.5 (20160823 - e4af3d9) starting at Address[127.0.0.1]:2436 [system]
2017-01-05 13:21:11:394 INFO  [127.0.0.1]:2436 [orientdb] [3.6.5] Copyright (c) 2008-2016, Hazelcast, Inc. All Rights Reserved. [system]
2017-01-05 13:21:11:394 INFO  [127.0.0.1]:2436 [orientdb] [3.6.5] Configured Hazelcast Serialization version : 1 [system]
2017-01-05 13:21:11:611 INFO  [127.0.0.1]:2436 [orientdb] [3.6.5] Backpressure is disabled [OperationService]
2017-01-05 13:21:11:640 INFO  [127.0.0.1]:2436 [orientdb] [3.6.5] Starting with 1 generic operation threads and 1 partition operation threads. [ClassicOperationExecutor]
2017-01-05 13:21:12:050 INFO  [127.0.0.1]:2436 [orientdb] [3.6.5] Creating TcpIpJoiner [Node]
2017-01-05 13:21:12:052 INFO  [127.0.0.1]:2436 [orientdb] [3.6.5] Address[127.0.0.1]:2436 is STARTING [LifecycleService]
2017-01-05 13:21:12:142 INFO  [127.0.0.1]:2436 [orientdb] [3.6.5] TcpIpConnectionManager configured with Non Blocking IO-threading model: 3 input threads and 3 output threads [NonBlockingIOThreadingModel]
2017-01-05 13:21:12:161 INFO  [127.0.0.1]:2436 [orientdb] [3.6.5] Connecting to /127.0.0.1:2434, timeout: 0, bind-any: true [InitConnectionTask]
2017-01-05 13:21:12:168 INFO  [127.0.0.1]:2436 [orientdb] [3.6.5] Established socket connection between /127.0.0.1:35170 and /127.0.0.1:2434 [TcpIpConnectionManager]
2017-01-05 13:21:17:160 INFO  [127.0.0.1]:2436 [orientdb] [3.6.5] 


Members [1] {
	Member [127.0.0.1]:2436 this
}
 [TcpIpJoiner]
2017-01-05 13:21:17:161 WARNI [127.0.0.1]:2436 [orientdb] [3.6.5] Config seed port is 2434 and cluster size is 1. Some of the ports seem occupied! [Node]
2017-01-05 13:21:17:190 INFO  [127.0.0.1]:2436 [orientdb] [3.6.5] Address[127.0.0.1]:2436 is STARTED [LifecycleService]
2017-01-05 13:21:17:191 INFO  Starting distributed server 'node1483612532316' (hzID=20eec784-5a73-4e40-ad9e-c50b4e6d4ce2)... [OHazelcastPlugin]
2017-01-05 13:21:17:195 INFO  Distributed cluster time=Thu Jan 05 13:21:17 EET 2017 (delta from local node=0)... [OHazelcastPlugin]
2017-01-05 13:21:17:232 INFO  [127.0.0.1]:2436 [orientdb] [3.6.5] Initializing cluster partition table arrangement... [InternalPartitionService]
2017-01-05 13:21:17:289 INFO  [127.0.0.1]:2436 [orientdb] [3.6.5] Partition assignments changed while executing query: TruePredicate{} [MapQueryEngineImpl]
2017-01-05 13:21:17:329 INFO  [node1483612532316] Loaded configuration for database 'OSystem' from disk: /chzhang/orientdb/orientdb-community-2.2.14/config/default-distributed-db-config.json [ODistributedStorage]
2017-01-05 13:21:17:339 WARNI [node1483612532316] Servers in cluster: [node1483612532316] [OHazelcastPlugin]
2017-01-05 13:21:17:353 SEVER [node1483612532316] Error on publishing local server configuration [OHazelcastPlugin]
2017-01-05 13:21:17:353 SEVER [node1483612532316] Error on registering local node on cluster [OHazelcastPlugin][node1483612532316] Error on starting distributed plugin
com.orientechnologies.orient.server.distributed.ODistributedStartupException: Error on registering local node on cluster
	at com.orientechnologies.orient.server.hazelcast.OHazelcastPlugin.startup(OHazelcastPlugin.java:213)
	at com.orientechnologies.orient.server.OServer.registerPlugins(OServer.java:1242)
	at com.orientechnologies.orient.server.OServer.activate(OServer.java:397)
	at com.orientechnologies.orient.server.OServerMain$1.run(OServerMain.java:46)

@Rucchao
Copy link
Author

Rucchao commented Jan 5, 2017

I also try my own ip, the issue remains.

@CrazyBeeline
Copy link

Dear friend
I have the same problems
if you save the problem
Please tell me the solution

@Rucchao
Copy link
Author

Rucchao commented Jan 10, 2017

Hi, @CrazyBeeline , I still have this problem, even the different nodes can established the socket connection, maybe @lvca can fix it and make it more steady later.

@lvca
Copy link
Member

lvca commented Jan 10, 2017

Hi guys, I'm unable to reproduce it. Could you please try with last version on 2.2.x branch?

@CrazyBeeline
Copy link

Dear friend
This problem is solved when I use a low version (2.2.13)
But my colleagues have successfully installed the 2.2.14 version
In view of the fact that we installed on different machines all should feel server environment problems
I hope my experience can help you

@lvca
Copy link
Member

lvca commented Jan 11, 2017

@CrazyBeeline In order to help other users wit a similar error, do you have any ideas what could be the cause?

@lvca lvca added the bug label Jan 14, 2017
@santo-it
Copy link

Hi,

Thanks for your patience while we continue our analysis on this issue

We feel this might be linked to the installed java version. Are you using java 1.7 in the system where the issue is happening?

Many Thanks,

@SDIPro
Copy link
Contributor

SDIPro commented Jan 25, 2017

This has just been fixed in 2.2.16-SNAPSHOT to work with Java 7.

@SDIPro SDIPro closed this as completed Jan 25, 2017
@santo-it
Copy link

Thanks @SDIPro


Link to the commit that fixes the issue: 7b44e0d

Release Notes updated

No changes needed in the documentation

@santo-it santo-it added this to the 2.2.16 milestone Jan 25, 2017
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Development

No branches or pull requests

6 participants