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.

Sign up for GitHub

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

Jump to bottom

Always Lost one record when shutdown remote server in distributed mode #1304

Closed
henryzhao81 opened this issue Jan 24, 2013 · 0 comments
Closed

Always Lost one record when shutdown remote server in distributed mode #1304

henryzhao81 opened this issue Jan 24, 2013 · 0 comments
Assignees
@lvca
Milestone
1.4.0

Comments

@henryzhao81
Copy link
Contributor

Set 2 server cluster (server1, server2).
Sending requests to server1, server2 got synchronized. Shutdown server2, and restarted, server2 start to synchronize data to server1.
After finishing sync, check records on server2, one record was lost and miss to sync with server1.

Try couple time, follow the same steps. Everytime got one record missing.
Following is the server log :

Server2
2013-01-23 12:14:58:467 WARN Journaled operation RECORD_CREATE #13:30 as #1358972066868.45 [ODatabaseJournal]
2013-01-23 12:14:58:468 WARN DISTRIBUTED <-[10.7.2.112:2434/pharos] CREATE RECORD #13:30 v.0 [OCreateRecordDistributedTask]
2013-01-23 12:14:58:469 WARN Updating status operation #1358972066868.45 rid #13:30 [ODatabaseJournal]
2013-01-23 12:14:58:517 INFO [DEBUG] rid : #13:31 status : REMOTE_EXEC localNodeid : 10.7.32.70:2434 status : online [OCreateRecordDistributedTask]
2013-01-23 12:14:58:517 WARN Journaled operation RECORD_CREATE #13:31 as #1358972066868.46 [ODatabaseJournal]
2013-01-23 12:14:58:518 WARN DISTRIBUTED <-[10.7.2.112:2434/pharos] CREATE RECORD #13:31 v.0 [OCreateRecordDistributedTask]
2013-01-23 12:14:58:519 WARN Updating status operation #1358972066868.46 rid #13:31 [ODatabaseJournal]
2013-01-23 12:14:58:565 INFO [DEBUG] rid : #13:32 status : REMOTE_EXEC localNodeid : 10.7.32.70:2434 status : online [OCreateRecordDistributedTask]
2013-01-23 12:14:58:565 WARN Journaled operation RECORD_CREATE #13:32 as #1358972066868.47 [ODatabaseJournal]
2013-01-23 12:14:58:566 WARN DISTRIBUTED <-[10.7.2.112:2434/pharos] CREATE RECORD #13:32 v.0 [OCreateRecordDistributedTask]
2013-01-23 12:14:58:571 WARN Updating status operation #1358972066868.47 rid #13:32 [ODatabaseJournal]
2013-01-23 12:14:58:573 INFO OrientDB Server is shutting down... [OServer]

As we can see, before server shutdown, last record got synchronize is #13:32, which JournalID is #1358972066868.47

Restart server2, check log on server1

server1

2013-01-23 12:16:23:640 WARN DISTRIBUTED <-[10.7.32.70:2434/pharos] align request starting from 1358972066868.48 [OAlignRequestDistributedTask]
2013-01-23 12:16:23:644 INFO [DEBUG] iNodeId : 10.7.32.70:2434 taskMode : FIRE_AND_FORGET taskClz : com.hazelcast.core.DistributedTask [OHazelcastPlugin]
2013-01-23 12:16:23:644 INFO [DEBUG] local vs remote : 1358972066868/1358972066868 64/48 [ODatabaseJournal]
2013-01-23 12:16:23:644 INFO [DEBUG] add fileOffset : 1600 [ODatabaseJournal]
2013-01-23 12:16:23:645 INFO [DEBUG] add fileOffset : 1568 [ODatabaseJournal]
2013-01-23 12:16:23:645 INFO [DEBUG] add fileOffset : 1536 [ODatabaseJournal]
2013-01-23 12:16:23:645 INFO [DEBUG] add fileOffset : 1504 [ODatabaseJournal]
2013-01-23 12:16:23:645 INFO [DEBUG] add fileOffset : 1472 [ODatabaseJournal]
2013-01-23 12:16:23:645 INFO [DEBUG] add fileOffset : 1440 [ODatabaseJournal]
2013-01-23 12:16:23:645 INFO [DEBUG] add fileOffset : 1408 [ODatabaseJournal]
2013-01-23 12:16:23:645 INFO [DEBUG] add fileOffset : 1376 [ODatabaseJournal]
2013-01-23 12:16:23:646 INFO [DEBUG] add fileOffset : 1344 [ODatabaseJournal]
2013-01-23 12:16:23:646 INFO [DEBUG] add fileOffset : 1312 [ODatabaseJournal]
2013-01-23 12:16:23:646 INFO [DEBUG] add fileOffset : 1280 [ODatabaseJournal]
2013-01-23 12:16:23:646 INFO [DEBUG] add fileOffset : 1248 [ODatabaseJournal]
2013-01-23 12:16:23:646 INFO [DEBUG] add fileOffset : 1216 [ODatabaseJournal]
2013-01-23 12:16:23:646 INFO [DEBUG] add fileOffset : 1184 [ODatabaseJournal]
2013-01-23 12:16:23:646 INFO [DEBUG] add fileOffset : 1152 [ODatabaseJournal]
2013-01-23 12:16:23:646 INFO [DEBUG] add fileOffset : 1120 [ODatabaseJournal]
2013-01-23 12:16:23:647 INFO [DEBUG] iNodeId : 1120 [OAlignRequestDistributedTask]
2013-01-23 12:16:23:647 INFO [DEBUG] getOperation [RECORD_CREATE] : #13:34 [ODatabaseJournal]
2013-01-23 12:16:23:647 WARN DISTRIBUTED ->[10.7.32.70:2434/pharos] operation record_create(#13:34 v.0) [OAlignRequestDistributedTask]
2013-01-23 12:16:23:647 INFO [DEBUG] iNodeId : 1152 [OAlignRequestDistributedTask]
2013-01-23 12:16:23:647 INFO [DEBUG] getOperation [RECORD_CREATE] : #13:35 [ODatabaseJournal]
2013-01-23 12:16:23:648 WARN DISTRIBUTED ->[10.7.32.70:2434/pharos] operation record_create(#13:35 v.0) [OAlignRequestDistributedTask]
2013-01-23 12:16:23:648 INFO [DEBUG] iNodeId : 1184 [OAlignRequestDistributedTask]
2013-01-23 12:16:23:648 INFO [DEBUG] getOperation [RECORD_CREATE] : #13:36 [ODatabaseJournal]
2013-01-23 12:16:23:648 WARN DISTRIBUTED ->[10.7.32.70:2434/pharos] operation record_create(#13:36 v.0) [OAlignRequestDistributedTask]
2013-01-23 12:16:23:648 INFO [DEBUG] iNodeId : 1216 [OAlignRequestDistributedTask]
2013-01-23 12:16:23:648 INFO [DEBUG] getOperation [RECORD_CREATE] : #13:37 [ODatabaseJournal]
2013-01-23 12:16:23:649 WARN DISTRIBUTED ->[10.7.32.70:2434/pharos] operation record_create(#13:37 v.0) [OAlignRequestDistributedTask]
2013-01-23 12:16:23:649 INFO [DEBUG] iNodeId : 1248 [OAlignRequestDistributedTask]
2013-01-23 12:16:23:649 INFO [DEBUG] getOperation [RECORD_CREATE] : #13:38 [ODatabaseJournal]
2013-01-23 12:16:23:649 WARN DISTRIBUTED ->[10.7.32.70:2434/pharos] operation record_create(#13:38 v.0) [OAlignRequestDistributedTask]
2013-01-23 12:16:23:649 INFO [DEBUG] iNodeId : 1280 [OAlignRequestDistributedTask]
2013-01-23 12:16:23:649 INFO [DEBUG] getOperation [RECORD_CREATE] : #13:39 [ODatabaseJournal]
2013-01-23 12:16:23:650 WARN DISTRIBUTED ->[10.7.32.70:2434/pharos] operation record_create(#13:39 v.0) [OAlignRequestDistributedTask]
2013-01-23 12:16:23:650 INFO [DEBUG] iNodeId : 1312 [OAlignRequestDistributedTask]
2013-01-23 12:16:23:650 INFO [DEBUG] getOperation [RECORD_CREATE] : #13:40 [ODatabaseJournal]
2013-01-23 12:16:23:650 WARN DISTRIBUTED ->[10.7.32.70:2434/pharos] operation record_create(#13:40 v.0) [OAlignRequestDistributedTask]
2013-01-23 12:16:23:650 INFO [DEBUG] iNodeId : 1344 [OAlignRequestDistributedTask]
2013-01-23 12:16:23:650 INFO [DEBUG] getOperation [RECORD_CREATE] : #13:41 [ODatabaseJournal]
2013-01-23 12:16:23:650 WARN DISTRIBUTED ->[10.7.32.70:2434/pharos] operation record_create(#13:41 v.0) [OAlignRequestDistributedTask]
2013-01-23 12:16:23:651 INFO [DEBUG] iNodeId : 1376 [OAlignRequestDistributedTask]

Align request start from 48 which is correct, but sync record actually start from record #13:34, record #13:33 was missing. And it is 100% reproducible
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@lvca lvca

Labels
None yet
Milestone
1.4.0
Development

No branches or pull requests
2 participants
@lvca @henryzhao81