These are chat archives for atomix/atomix

24th
Aug 2018
suimi
@suimi
Aug 24 2018 02:16 UTC
@kuujo i'm using the latest version 3.0.1。 after that issue i restart the other node more times, but it doesn't repetition
suimi
@suimi
Aug 24 2018 02:26 UTC
i checked the log, the last index at first segment is 413, first index at second segment is 508, about 95 entries missing
Jordan Halterman
@kuujo
Aug 24 2018 02:29 UTC
@johnou no but FileBytes#flush() does
But sync on the FD writes it to physical storage
RandomAccessFile writes to the OS cache via system calls
@suimi so the second restart it’s able to load both segments?
what OS are you on?
suimi
@suimi
Aug 24 2018 02:31 UTC
In addition, i config the segmentSize = 1024*1024*10, maxEntrySize=1024*1024`, ant checked the first segment file, the size is 16384 kb
Jordan Halterman
@kuujo
Aug 24 2018 02:31 UTC
okay that makes sense
suimi
@suimi
Aug 24 2018 02:33 UTC
restart will failed, can't load both segment, will throw the exception throw new StorageException("Cannot load segments due to corrupt journal")
Jordan Halterman
@kuujo
Aug 24 2018 02:33 UTC
after that issue i restart the other node more times, but it doesn't repetition
Did you mean you tried a second time and it worked?
or it’s just not easy to reproduce?
suimi
@suimi
Aug 24 2018 02:34 UTC
yes, it's not easy to reproduce
Jordan Halterman
@kuujo
Aug 24 2018 02:35 UTC
what OS?
suimi
@suimi
Aug 24 2018 02:36 UTC
centos
Linux version 3.10.0-693.2.2.el7.x86_64 (builder@kbuilder.dev.centos.org) (gcc version 4.8.5 20150623 (Red Hat 4.8.5-16) (GCC) )
Jordan Halterman
@kuujo
Aug 24 2018 02:37 UTC
okay
hmmm
it’s strange that the file descriptor sync() doesn’t seem to be working
that should certainly not be happening
@suimi did enabling flushOnCommit fix it?
suimi
@suimi
Aug 24 2018 02:40 UTC
the flushOnCommit can reduce the probability of that problem
Jordan Halterman
@kuujo
Aug 24 2018 02:41 UTC
but it still happens then?
suimi
@suimi
Aug 24 2018 02:41 UTC
no
Jordan Halterman
@kuujo
Aug 24 2018 02:42 UTC
actually, that wouldn’t really solve the problem even if it did reduce the probability of it occurring
because the log can still roll over to a new segment with uncommitted entries at the tail of the segment
need to figure out why this is not sufficient
suimi
@suimi
Aug 24 2018 02:44 UTC
yes, you are right, we should get the real reson
Jordan Halterman
@kuujo
Aug 24 2018 02:45 UTC
some code path must be allowing writes without syncing the FD when the log rolls over to a new segment
hmm
those two append methods are the only place getNextSegment is called, and both of them flush() the previous segment
which StorageLevel are you using? The default DISK?
suimi
@suimi
Aug 24 2018 02:47 UTC
yes, with the DISK level
Jordan Halterman
@kuujo
Aug 24 2018 02:48 UTC
the only other way a new segment is created is if the old segments are deleted, e.g. after a leader replicates a snapshot to a follower
🤔
suimi
@suimi
Aug 24 2018 02:52 UTC
your mean is if there appear two segment, only the method getNextSegment be called ?
Jordan Halterman
@kuujo
Aug 24 2018 02:53 UTC
I mean getNextSegment is where new segments are created, and that method is only called in append which always flush()es the prior segment first, so the prior segment should always have been written to physical storage before a new segment is created
obviously that’s not the case but it seems like it should be
before every journal.getNextSegment() call is currentWriter.flush()
strange
currentWriter.flush() calls randomAccessFile.getFD().sync() when DISK storage is used
@suimi can you try to produce this error with MAPPED storage?
maybe we can prove it’s a problem with getFD().sync()
suimi
@suimi
Aug 24 2018 02:57 UTC
ok, let me try
i'm not sure it can be appear
maybe need try more times
suimi
@suimi
Aug 24 2018 03:20 UTC
@kuujo got some error when restart node
2018-08-24 11:14:34,119 [raft-server-raft-group-partition-1-state] TRACE i.a.p.r.i.RaftServiceManager - RaftServer{raft-group-partition-1} - Applying Indexed{index=665, entry=CommandEntry{term=2, timestamp=2018-08-24 11:13:34,546, session=2, sequence=637, operation=PrimitiveOperation{id=DefaultOperationId{id=submit, type=COMMAND}, value=byte[]{length=16, hash=1245495222}}}} 
# A fatal error has been detected by the Java Runtime Environment:
#
#  EXCEPTION_ACCESS_VIOLATION (0xc0000005) at pc=0x0000000003db875d, pid=22080, tid=0x00000000000066b8
#
# JRE version: Java(TM) SE Runtime Environment (8.0_161-b12) (build 1.8.0_161-b12)
# Java VM: Java HotSpot(TM) 64-Bit Server VM (25.161-b12 mixed mode windows-amd64 compressed oops)
# Problematic frame:
# J 6394 C1 java.nio.DirectByteBuffer.get(I)B (16 bytes) @ 0x0000000003db875d [0x0000000003db8720+0x3d]
#
# 2018-08-24 11:14:34,119 [raft-server-raft-group-partition-1-state] TRACE i.a.p.r.i.RaftServiceManager - RaftServer{raft-group-partition-1} - Applying Indexed{index=666, entry=CommandEntry{term=2, timestamp=2018-08-24 11:13:35,559, session=2, sequence=638, operation=PrimitiveOperation{id=DefaultOperationId{id=submit, type=COMMAND}, value=byte[]{length=16, hash=1946560761}}}} 
Failed to write core dump. Minidumps are not enabled by default on client versions of Windows
# An error report file with more information is saved as:
# E:\workspace\hs_err_pid22080.log
Compiled method (c1)   41339 6393       1       io.atomix.storage.buffer.ByteBufferBytes::readByte (13 bytes)
 total in heap  [0x0000000003db9410,0x0000000003db9708] = 760
 relocation     [0x0000000003db9530,0x0000000003db9560] = 48
 main code      [0x0000000003db9560,0x0000000003db9600] = 160
 stub code      [0x0000000003db9600,0x0000000003db96a8] = 168
 oops           [0x0000000003db96a8,0x0000000003db96b0] = 8
 metadata       [0x0000000003db96b0,0x0000000003db96c0] = 16
 scopes data    [0x0000000003db96c0,0x0000000003db96d0] = 16
 scopes pcs     [0x0000000003db96d0,0x0000000003db9700] = 48
 dependencies   [0x0000000003db9700,0x0000000003db9708] = 8
#
# If you would like to submit a bug report, please visit:
#   http://bugreport.java.com/bugreport/crash.jsp
Johno Crawford
@johnou
Aug 24 2018 06:59 UTC
Tried to read on buffer that was cleaned?
suimi
@suimi
Aug 24 2018 07:02 UTC
i don't know, it's on windows, restart again will be normal
suimi
@suimi
Aug 24 2018 11:19 UTC
@kuujo i take some test with MAPPED storage, that error not appear again
but changed to DISK storage, it will appear
2018-08-24 19:19:09,215 [raft-client-system-partition-1-4] TRACE RaftSessionConnection - RaftClient{system-partition-1} - Received KeepAliveResponse{status=OK, leader=1, members=[4, 3, 2, 1, 0], sessionIds=long[]{length=2, hash=4227}} from 3 [,,]
2018-08-24 19:19:09,242 [raft-client-system-partition-1-2] DEBUG SegmentedJournal - Loaded disk segment: 1 (raft-group-partition-1-1.log) [,,]
2018-08-24 19:19:09,242 [raft-client-system-partition-1-2] DEBUG SegmentedJournal - Found segment: 1 (raft-group-partition-1-1.log) [,,]
2018-08-24 19:19:09,243 [raft-client-system-partition-1-2] DEBUG SegmentedJournal - Loaded disk segment: 2 (raft-group-partition-1-2.log) [,,]
2018-08-24 19:19:09,243 [raft-client-system-partition-1-2] DEBUG SegmentedJournal - Found segment: 2 (raft-group-partition-1-2.log) [,,]
2018-08-24 19:19:09,243 [raft-client-system-partition-1-2] ERROR SegmentedJournal - Journal appears to be corrupted! /data/home/admin/trust/data/atomix/raft-group/3/partitions/1/raft-group-partition-1-2.log is not aligned with the prior segment /data/home/
admin/trust/data/atomix/raft-group/3/partitions/1/raft-group-partition-1-1.log [,,]
suimi
@suimi
Aug 24 2018 11:33 UTC
image.png
suimi
@suimi
Aug 24 2018 12:24 UTC
it's not appear on windows, maybe the error related to OS