quantcast / qfs

Quantcast File System
https://quantcast.atlassian.net
Apache License 2.0
643 stars 171 forks source link

Error in writing qfs files when a involved chunk server is pulled out of network #216

Closed lucoysword closed 6 years ago

lucoysword commented 7 years ago

I am playing with a QFS testing deployment. In the process, I encountered some errors. It seems the system retried 6 times, and then there is "invalidate" action. Not sure what exactly happened. Is there a big data loss there? It will be a big issue if so.

04-19-2017 14:39:05.028 ERROR - (KfsNetClient.cc:658) PW 54,1156,312,content closing connection: not connected to: 10.10.16.175 210010 due to network error pending: read: 0 write: 0 ops: 1 auth failures: 0 error: 04-19-2017 14:39:05.028 ERROR - (Writer.cc:1504) PW 54,1156,312,content operation failure, seq: 605585302507169819 status: -10110 msg: op: write-prepare: chunkid: 138224 version: 1 offset: 49283072 numBytes: 1048576 checksum: 3985657311 location: 10.10.16.175 210010 writeId: 1567693263053917382 current chunk server: 10.10.16.175 210010 chunkserver: no data sent Request: WRITE_PREPARE^M Cseq: 605585302507169819^M Version: KFS/1.0^M Client-Protocol-Version: 115^M UserId: 1002^M GroupId: 1002^M User: test^M Chunk-handle: 138224^M Chunk-version: 1^M Offset: 49283072^M Num-bytes: 1048576^M Checksum: 3985657311^M Checksum-entries: 0^M Reply: 1^M Num-servers: 1^M Servers:10.10.16.175 210010 1567693263053917382 ^M

04-19-2017 14:39:05.028 INFO - (Writer.cc:1609) PW 54,1156,312,content scheduling retry: 1 of 6 in 5 sec. op: write-prepare: chunkid: 138224 version: 1 offset: 49283072 numBytes: 1048576 checksum: 3985657311 location: 10.10.16.175 210010 writeId: 1567693263053917382 04-19-2017 14:39:05.028 ERROR - (KfsNetClient.cc:658) PW 54,1156,312,content closing connection: not connected to: 10.10.16.175 210011 due to network error pending: read: 0 write: 0 ops: 1 auth failures: 0 error: 04-19-2017 14:39:05.028 ERROR - (Writer.cc:1504) PW 54,1156,312,content operation failure, seq: 605585302507204819 status: -10110 msg: op: write-prepare: chunkid: 138231 version: 1 offset: 49283072 numBytes: 1048576 checksum: 3797051669 location: 10.10.16.175 210011 writeId: 4329310647880148800 current chunk server: 10.10.16.175 210011 chunkserver: no data sent Request: WRITE_PREPARE^M Cseq: 605585302507204819^M Version: KFS/1.0^M Client-Protocol-Version: 115^M UserId: 1002^M GroupId: 1002^M User: test^M Chunk-handle: 138231^M Chunk-version: 1^M Offset: 49283072^M Num-bytes: 1048576^M Checksum: 3797051669^M Checksum-entries: 0^M Reply: 1^M Num-servers: 1^M Servers:10.10.16.175 210011 4329310647880148800 ^M

04-19-2017 14:39:05.028 INFO - (Writer.cc:1609) PW 54,1156,312,content scheduling retry: 1 of 6 in 5 sec. op: write-prepare: chunkid: 138231 version: 1 offset: 49283072 numBytes: 1048576 checksum: 3797051669 location: 10.10.16.175 210011 writeId: 4329310647880148800 04-19-2017 14:39:05.028 ERROR - (KfsNetClient.cc:658) PW 54,1156,312,content closing connection: not connected to: 10.10.16.175 210010 due to network error pending: read: 0 write: 0 ops: 1 auth failures: 0 error: 04-19-2017 14:39:05.028 ERROR - (Writer.cc:1504) PW 54,1156,312,content operation failure, seq: 605585302507209819 status: -10110 msg: op: write-prepare: chunkid: 138232 version: 1 offset: 49283072 numBytes: 1048576 checksum: 1493938394 location: 10.10.16.175 210010 writeId: 1567693263053917384 current chunk server: 10.10.16.175 210010 chunkserver: no data sent Request: WRITE_PREPARE^M Cseq: 605585302507209819^M Version: KFS/1.0^M Client-Protocol-Version: 115^M UserId: 1002^M GroupId: 1002^M User: test^M Chunk-handle: 138232^M Chunk-version: 1^M Offset: 49283072^M Num-bytes: 1048576^M Checksum: 1493938394^M Checksum-entries: 0^M Reply: 1^M Num-servers: 1^M Servers:10.10.16.175 210010 1567693263053917384 ^M ^M

04-19-2017 14:39:05.028 INFO - (Writer.cc:1609) PW 54,1156,312,content scheduling retry: 1 of 6 in 5 sec. op: write-prepare: chunkid: 138232 version: 1 offset: 49283072 numBytes: 1048576 checksum: 1493938394 location: 10.10.16.175 210010 writeId: 1567693263053917384 04-19-2017 14:39:11.731 ERROR - (Writer.cc:1504) PW 54,1156,312,content operation failure, seq: 2254749033532708099 status: -1003 msg: no replicas available op: allocate: fid: 1156 offset: 603979776 access: s: c: valid for: 0 lease duration: -1 current chunk server: 10.10.16.175 210010 chunkserver: no data sent Request: ALLOCATE^M Cseq: 2254749033532708099^M Version: KFS/1.0^M Client-Protocol-Version: 115^M UserId: 1002^M GroupId: 1002^M User: test^M Max-wait-ms: 120000^M Client-host: node18^M Pathname: /testdir/0/000051/content^M File-handle: 1156^M Chunk-offset: 603979776^M ^M

04-19-2017 14:39:11.731 INFO - (Writer.cc:1561) PW 54,1156,312,content invalidate: chunk: 0 offset: 603979776 status: -1003 => 0 pending: 1048576 w-empty: 0 04-19-2017 14:39:11.731 ERROR - (Writer.cc:1504) PW 54,1156,312,content operation failure, seq: 2254749033532708100 status: -1003 msg: no replicas available op: allocate: fid: 1156 offset: 1073741824 access: s: c: valid for: 0 lease duration: -1 current chunk server: 10.10.16.175 210011 chunkserver: no data sent Request: ALLOCATE^M Cseq: 2254749033532708100^M Version: KFS/1.0^M Client-Protocol-Version: 115^M UserId: 1002^M GroupId: 1002^M User: test^M Max-wait-ms: 120000^M Client-host: node18^M Pathname: /testdir/0/000051/content^M File-handle: 1156^M Chunk-offset: 1073741824^M

04-19-2017 14:39:11.731 INFO - (Writer.cc:1609) PW 54,1156,312,content scheduling retry: 2 of 6 in 5 sec. op: allocate: fid: 1156 offset: 1073741824 access: s: c: valid for: 0 lease duration: -1 04-19-2017 14:39:11.731 ERROR - (Writer.cc:1504) PW 54,1156,312,content operation failure, seq: 2254749033532708101 status: -1003 msg: no replicas available op: allocate: fid: 1156 offset: 1140850688 access: s: c: valid for: 0 lease duration: -1 current chunk server: 10.10.16.175 210010 chunkserver: no data sent Request: ALLOCATE^M Cseq: 2254749033532708101^M Version: KFS/1.0^M Client-Protocol-Version: 115^M UserId: 1002^M GroupId: 1002^M User: test^M Max-wait-ms: 120000^M Client-host: node18^M Pathname: /testdir/0/000051/content^M File-handle: 1156^M Chunk-offset: 1140850688^M ^M

04-19-2017 14:39:11.731 INFO - (Writer.cc:1609) PW 54,1156,312,content scheduling retry: 2 of 6 in 5 sec. op: allocate: fid: 1156 offset: 1140850688 access: s: c: valid for: 0 lease duration: -1 04-19-2017 14:39:11.732 INFO - (Writer.cc:892) PW 54,1156,312,content invalidate done: chunk: 138224 offset: 603979776 status: 0 pending: 1048576 w-empty: 0 04-19-2017 14:39:17.738 ERROR - (Writer.cc:1504) PW 54,1156,312,content operation failure, seq: 2254749033532708103 status: -1003 msg: no replicas available op: allocate: fid: 1156 offset: 1073741824 access: s: c: valid for: 0 lease duration: -1 current chunk server: 10.10.16.175 210011 chunkserver: no data sent Request: ALLOCATE^M Cseq: 2254749033532708103^M Version: KFS/1.0^M Client-Protocol-Version: 115^M UserId: 1002^M GroupId: 1002^M User: test^M Max-wait-ms: 120000^M Client-host: node18^M Pathname: /testdir/0/000051/content^M File-handle: 1156^M Chunk-offset: 1073741824^M

...(I omitted similar retry log here.)

04-19-2017 14:39:41.768 INFO - (Writer.cc:1561) PW 54,1156,312,content invalidate: chunk: 0 offset: 1073741824 status: -1003 => 0 pending: 1048576 w-empty: 0 04-19-2017 14:39:41.768 ERROR - (Writer.cc:1504) PW 54,1156,312,content operation failure, seq: 2254749033532708112 status: -1003 msg: no replicas available op: allocate: fid: 1156 offset: 1140850688 access: s: c: valid for: 0 lease duration: -1 current chunk server: 10.10.16.175 210010 chunkserver: no data sent Request: ALLOCATE^M Cseq: 2254749033532708112^M Version: KFS/1.0^M Client-Protocol-Version: 115^M UserId: 1002^M GroupId: 1002^M User: test^M Max-wait-ms: 120000^M Client-host: node18^M Pathname: /testdir/0/000051/content^M File-handle: 1156^M Chunk-offset: 1140850688^M ^M

04-19-2017 14:39:41.768 INFO - (Writer.cc:1561) PW 54,1156,312,content invalidate: chunk: 0 offset: 1140850688 status: -1003 => 0 pending: 1048576 w-empty: 0 04-19-2017 14:39:41.768 INFO - (Writer.cc:892) PW 54,1156,312,content invalidate done: chunk: 138231 offset: 1073741824 status: 0 pending: 1048576 w-empty: 0 04-19-2017 14:39:41.768 INFO - (Writer.cc:892) PW 54,1156,312,content invalidate done: chunk: 138232 offset: 1140850688 status: 0 pending: 1048576 w-empty: 0 04-19-2017 14:40:59.179 ERROR - (Writer.cc:1504) PW 1,1000,2,index operation failure, seq: 605585302502019039 status: -22 msg: invalid write id op: write-prepare: chunkid: 135792 version: 4 offset: 13697024 numBytes: 65536 checksum: 3966163118 location: 10.10.16.175 210011 writeId: 4329310647880148768 current chunk server: 10.10.16.175 210011 chunkserver: all data sent Request: WRITE_PREPARE^M Cseq: 605585302502019039^M Version: KFS/1.0^M Client-Protocol-Version: 115^M UserId: 1002^M GroupId: 1002^M User: test^M Chunk-handle: 135792^M Chunk-version: 4^M Offset: 13697024^M Num-bytes: 65536^M Checksum: 3966163118^M Checksum-entries: 0^M Reply: 1^M

kstinsonqc commented 7 years ago

Did the client return an error for the write so that you know that there was an issue with the file?

BTW, did you intentionally configure port number > 65535? I believe that the upper bits will just get ignored.

lucoysword commented 7 years ago

The client seems ok. We always check the return value of write and no error reported. But the files does seems corrupted. A program is being run at the moment to examine the data integrity.

lucoysword commented 7 years ago

We experienced this issue again. In both cases, we had one chunk server pulled out of network in accident. There are content of 2 files buffered for that specific chunk server. In both case, it led to corrupted data of both files. ,

It seems like QFS is unable to handle such cases. Theoretically, it should be possible. Data contained in failed chunk server should be recoverable from other chunk nodes, and write should continue, probably with some delay.

mikeov commented 6 years ago

From looking at the messages the write is for file with no redundancy, i.e. replication 1 and no RS. In this case it isn't possible to recover from chunk loss, as no other replicas or recovery data exists.

Closing.