Adds more logging in scrub and sync.

This commit is contained in:
Andrea Mazzoleni 2013-10-21 21:56:53 +02:00
parent 6c3d84d775
commit c95917ecfe
4 changed files with 43 additions and 24 deletions

20
check.c
View file

@ -233,7 +233,7 @@ static int repair_step(struct snapraid_state* state, int rehash, unsigned pos, u
if (is_hash_matching(state, rehash, diskmax, failed, failed_map, failed_count, buffer, buffer_zero))
return 0;
fprintf(stdlog, "error:%u:%s: Data error\n", pos, lev_config_name(COMBO1[i].a));
fprintf(stdlog, "parity_error:%u:%s: Data error\n", pos, lev_config_name(COMBO1[i].a));
++error;
}
}
@ -254,7 +254,7 @@ static int repair_step(struct snapraid_state* state, int rehash, unsigned pos, u
if (is_parity_matching(state, diskmax, COMBO2[i].b, buffer, buffer_recov))
return 0;
fprintf(stdlog, "error:%u:%s/%s: Data error\n", pos, lev_config_name(COMBO2[i].a), lev_config_name(COMBO2[i].b));
fprintf(stdlog, "parity_error:%u:%s/%s: Data error\n", pos, lev_config_name(COMBO2[i].a), lev_config_name(COMBO2[i].b));
++error;
}
}
@ -276,7 +276,7 @@ static int repair_step(struct snapraid_state* state, int rehash, unsigned pos, u
if (is_hash_matching(state, rehash, diskmax, failed, failed_map, failed_count, buffer, buffer_zero))
return 0;
fprintf(stdlog, "error:%u:%s/%s: Data error\n", pos, lev_config_name(COMBO2[i].a), lev_config_name(COMBO2[i].b));
fprintf(stdlog, "parity_error:%u:%s/%s: Data error\n", pos, lev_config_name(COMBO2[i].a), lev_config_name(COMBO2[i].b));
++error;
}
}
@ -298,7 +298,7 @@ static int repair_step(struct snapraid_state* state, int rehash, unsigned pos, u
if (is_parity_matching(state, diskmax, COMBO3[i].c, buffer, buffer_recov))
return 0;
fprintf(stdlog, "error:%u:%s/%s/%s: Data error\n", pos, lev_config_name(COMBO3[i].a), lev_config_name(COMBO3[i].b), lev_config_name(COMBO3[i].c));
fprintf(stdlog, "parity_error:%u:%s/%s/%s: Data error\n", pos, lev_config_name(COMBO3[i].a), lev_config_name(COMBO3[i].b), lev_config_name(COMBO3[i].c));
++error;
}
}
@ -321,7 +321,7 @@ static int repair_step(struct snapraid_state* state, int rehash, unsigned pos, u
if (is_hash_matching(state, rehash, diskmax, failed, failed_map, failed_count, buffer, buffer_zero))
return 0;
fprintf(stdlog, "error:%u:%s/%s/%s: Data error\n", pos, lev_config_name(COMBO3[i].a), lev_config_name(COMBO3[i].b), lev_config_name(COMBO3[i].c));
fprintf(stdlog, "parity_error:%u:%s/%s/%s: Data error\n", pos, lev_config_name(COMBO3[i].a), lev_config_name(COMBO3[i].b), lev_config_name(COMBO3[i].c));
++error;
}
}
@ -344,7 +344,7 @@ static int repair_step(struct snapraid_state* state, int rehash, unsigned pos, u
if (is_parity_matching(state, diskmax, COMBO4[i].d, buffer, buffer_recov))
return 0;
fprintf(stdlog, "error:%u:%s/%s/%s/%s: Data error\n", pos, lev_config_name(COMBO4[i].a), lev_config_name(COMBO4[i].b), lev_config_name(COMBO4[i].c), lev_config_name(COMBO4[i].d));
fprintf(stdlog, "parity_error:%u:%s/%s/%s/%s: Data error\n", pos, lev_config_name(COMBO4[i].a), lev_config_name(COMBO4[i].b), lev_config_name(COMBO4[i].c), lev_config_name(COMBO4[i].d));
++error;
}
}
@ -368,7 +368,7 @@ static int repair_step(struct snapraid_state* state, int rehash, unsigned pos, u
if (is_hash_matching(state, rehash, diskmax, failed, failed_map, failed_count, buffer, buffer_zero))
return 0;
fprintf(stdlog, "error:%u:%s/%s/%s/%s: Data error\n", pos, lev_config_name(COMBO4[i].a), lev_config_name(COMBO4[i].b), lev_config_name(COMBO4[i].c), lev_config_name(COMBO4[i].d));
fprintf(stdlog, "parity_error:%u:%s/%s/%s/%s: Data error\n", pos, lev_config_name(COMBO4[i].a), lev_config_name(COMBO4[i].b), lev_config_name(COMBO4[i].c), lev_config_name(COMBO4[i].d));
++error;
}
}
@ -899,7 +899,7 @@ static int state_check_process(struct snapraid_state* state, int check, int fix,
if (ret == -1) {
buffer_recov[l] = 0; /* no parity to use */
fprintf(stdlog, "error:%u:%s: Read error\n", i, lev_config_name(l));
fprintf(stdlog, "parity_error:%u:%s: Read error\n", i, lev_config_name(l));
++error;
}
} else {
@ -953,7 +953,7 @@ static int state_check_process(struct snapraid_state* state, int check, int fix,
if (buffer_recov[l] != 0 && memcmp(buffer_recov[l], buffer[diskmax + l], state->block_size) != 0) {
buffer_recov[l] = 0;
fprintf(stdlog, "error:%u:%s: Data error\n", i, lev_config_name(l));
fprintf(stdlog, "parity_error:%u:%s: Data error\n", i, lev_config_name(l));
++error;
}
}
@ -1017,7 +1017,7 @@ static int state_check_process(struct snapraid_state* state, int check, int fix,
goto bail;
}
fprintf(stdlog, "fixed:%u:%s: Fixed data error\n", i, lev_config_name(l));
fprintf(stdlog, "parity_fixed:%u:%s: Fixed data error\n", i, lev_config_name(l));
++recovered_error;
}
}

2
dry.c
View file

@ -103,7 +103,7 @@ static int state_dry_process(struct snapraid_state* state, struct snapraid_parit
if (parity[l]) {
ret = parity_read(parity[l], i, buffer_aligned, state->block_size, stdlog);
if (ret == -1) {
fprintf(stdlog, "error:%u:%s: Read error\n", i, lev_config_name(l));
fprintf(stdlog, "parity_error:%u:%s: Read error\n", i, lev_config_name(l));
++error;
}
}

10
scrub.c
View file

@ -219,6 +219,7 @@ static int state_scrub_process(struct snapraid_state* state, struct snapraid_par
if (ret == -1) {
/* This one is really an unexpected error, because we are only reading */
/* and closing a descriptor should never fail */
fprintf(stdlog, "error:%u:%s:%s: Close error. %s\n", i, handle[j].disk->name, handle[j].file->sub, strerror(errno));
fprintf(stderr, "DANGER! Unexpected close error in a data disk, it isn't possible to scrub.\n");
printf("Stopping at block %u\n", i);
++error;
@ -228,7 +229,7 @@ static int state_scrub_process(struct snapraid_state* state, struct snapraid_par
ret = handle_open(&handle[j], block_file_get(block), state->opt.skip_sequential, stderr);
if (ret == -1) {
fprintf(stdlog, "error:%u:%s:%s: Open error at position %u\n", i, handle[j].disk->name, block_file_get(block)->sub, block_file_pos(block));
fprintf(stdlog, "error:%u:%s:%s: Open error. %s\n", i, handle[j].disk->name, handle[j].file->sub, strerror(errno));
++error;
error_on_this_block = 1;
continue;
@ -251,7 +252,7 @@ static int state_scrub_process(struct snapraid_state* state, struct snapraid_par
read_size = handle_read(&handle[j], block, buffer[j], state->block_size, stderr);
if (read_size == -1) {
fprintf(stdlog, "error:%u:%s:%s: Read error at position %u\n", i, handle[j].disk->name, block_file_get(block)->sub, block_file_pos(block));
fprintf(stdlog, "error:%u:%s:%s: Read error at position %u\n", i, handle[j].disk->name, handle[j].file->sub, block_file_pos(block));
++error;
error_on_this_block = 1;
continue;
@ -273,7 +274,7 @@ static int state_scrub_process(struct snapraid_state* state, struct snapraid_par
if (block_has_updated_hash(block)) {
/* compare the hash */
if (memcmp(hash, block->hash, HASH_SIZE) != 0) {
fprintf(stdlog, "error:%u:%s:%s: Data error at position %u\n", i, handle[j].disk->name, block_file_get(block)->sub, block_file_pos(block));
fprintf(stdlog, "error:%u:%s:%s: Data error at position %u\n", i, handle[j].disk->name, handle[j].file->sub, block_file_pos(block));
/* it's a silent error only if we are dealing with synched files */
if (file_is_unsynched) {
@ -281,7 +282,7 @@ static int state_scrub_process(struct snapraid_state* state, struct snapraid_par
error_on_this_block = 1;
} else {
fprintf(stderr, "Data error in file '%s' at position '%u'\n", handle[j].path, block_file_pos(block));
fprintf(stderr, "DANGER! Unexpected data error in a data disk! The block is now marked as bad!\n");
fprintf(stderr, "WARNING! Unexpected data error in a data disk! The block is now marked as bad!\n");
fprintf(stderr, "Try with 'snapraid -e fix' to recover!\n");
++silent_error;
@ -318,7 +319,6 @@ static int state_scrub_process(struct snapraid_state* state, struct snapraid_par
/* compare the parity */
for(l=0;l<state->level;++l) {
if (buffer_recov[l] && memcmp(buffer[diskmax + l], buffer_recov[l], state->block_size) != 0) {
fprintf(stdlog, "parity_error:%u:%s: Data error\n", i, lev_config_name(l));

35
sync.c
View file

@ -230,7 +230,9 @@ static int state_sync_process(struct snapraid_state* state, struct snapraid_pari
if (ret == -1) {
/* This one is really an unexpected error, because we are only reading */
/* and closing a descriptor should never fail */
fprintf(stdlog, "error:%u:%s:%s: Close error. %s\n", i, handle[j].disk->name, handle[j].file->sub, strerror(errno));
fprintf(stderr, "DANGER! Unexpected close error in a data disk, it isn't possible to sync.\n");
fprintf(stderr, "Ensure that disk '%s' is sane and that file '%s' can be accessed.\n", handle[j].disk->dir, handle[j].path);
printf("Stopping at block %u\n", i);
++error;
goto bail;
@ -240,8 +242,10 @@ static int state_sync_process(struct snapraid_state* state, struct snapraid_pari
ret = handle_open(&handle[j], block_file_get(block), state->opt.skip_sequential, stderr);
if (ret == -1) {
if (errno == ENOENT) {
fprintf(stdlog, "error:%u:%s:%s: Open missing error\n", i, handle[j].disk->name, handle[j].file->sub);
fprintf(stderr, "Missing file '%s'.\n", handle[j].path);
fprintf(stderr, "WARNING! You cannot modify data disk during a sync. Rerun the sync command when finished.\n");
fprintf(stderr, "WARNING! You cannot modify data disk during a sync.\n");
fprintf(stderr, "Rerun the sync command when finished.\n");
++error;
@ -250,12 +254,21 @@ static int state_sync_process(struct snapraid_state* state, struct snapraid_pari
error_on_this_block = 1;
continue;
} else if (errno == EACCES) {
fprintf(stdlog, "error:%u:%s:%s: Open access error\n", i, handle[j].disk->name, handle[j].file->sub);
fprintf(stderr, "No access at file '%s'.\n", handle[j].path);
fprintf(stderr, "WARNING! Please fix the access permission in the data disk.\n");
printf("Stopping at block %u\n", i);
fprintf(stderr, "Rerun the sync command when finished.\n");
++error;
/* this isn't a serious error, so we skip this block, and continue with others */
error_on_this_block = 1;
continue;
} else {
fprintf(stdlog, "error:%u:%s:%s: Open error. %s\n", i, handle[j].disk->name, handle[j].file->sub, strerror(errno));
fprintf(stderr, "DANGER! Unexpected open error in a data disk, it isn't possible to sync.\n");
printf("Stopping to allow recovery. Try with 'snapraid check'\n");
fprintf(stderr, "Ensure that disk '%s' is sane and that file '%s' can be accessed.\n", handle[j].disk->dir, handle[j].path);
printf("Stopping to allow recovery. Try with 'snapraid check -f %s'\n", handle[j].file->sub);
}
++error;
@ -268,6 +281,7 @@ static int state_sync_process(struct snapraid_state* state, struct snapraid_pari
|| STAT_NSEC(&handle[j].st) != block_file_get(block)->mtime_nsec
|| handle[j].st.st_ino != block_file_get(block)->inode
) {
fprintf(stdlog, "error:%u:%s:%s: Unexpected change\n", i, handle[j].disk->name, handle[j].file->sub);
if (handle[j].st.st_size != block_file_get(block)->size)
fprintf(stderr, "Unexpected size change at file '%s'.\n", handle[j].path);
else if (handle[j].st.st_mtime != block_file_get(block)->mtime_sec
@ -275,7 +289,8 @@ static int state_sync_process(struct snapraid_state* state, struct snapraid_pari
fprintf(stderr, "Unexpected time change at file '%s'.\n", handle[j].path);
else
fprintf(stderr, "Unexpected inode change from %"PRIu64" to %"PRIu64" at file '%s'.\n", block_file_get(block)->inode, (uint64_t)handle[j].st.st_ino, handle[j].path);
fprintf(stderr, "WARNING! You cannot modify files during a sync. Rerun the sync command when finished.\n");
fprintf(stderr, "WARNING! You cannot modify files during a sync.\n");
fprintf(stderr, "Rerun the sync command when finished.\n");
++error;
@ -287,8 +302,10 @@ static int state_sync_process(struct snapraid_state* state, struct snapraid_pari
read_size = handle_read(&handle[j], block, buffer[j], state->block_size, stderr);
if (read_size == -1) {
fprintf(stdlog, "error:%u:%s:%s: Read error at position %u\n", i, handle[j].disk->name, handle[j].file->sub, block_file_pos(block));
fprintf(stderr, "DANGER! Unexpected read error in a data disk, it isn't possible to sync.\n");
printf("Stopping to allow recovery. Try with 'snapraid check'\n");
fprintf(stderr, "Ensure that disk '%s' is sane and that file '%s' can be read.\n", handle[j].disk->dir, handle[j].path);
printf("Stopping to allow recovery. Try with 'snapraid check -f %s'\n", handle[j].file->sub);
++error;
goto bail;
}
@ -309,9 +326,9 @@ static int state_sync_process(struct snapraid_state* state, struct snapraid_pari
if (block_has_updated_hash(block)) {
/* compare the hash */
if (memcmp(hash, block->hash, HASH_SIZE) != 0) {
fprintf(stdlog, "error:%u:%s:%s: Data error at position %u\n", i, handle[j].disk->name, block_file_get(block)->sub, block_file_pos(block));
fprintf(stderr, "Data error in file '%s' at position '%u'\n", handle[j].path, block_file_pos(block));
fprintf(stderr, "DANGER! Unexpected data error in a data disk! The block is now marked as bad!\n");
fprintf(stdlog, "error:%u:%s:%s: Data error at position %u\n", i, handle[j].disk->name, handle[j].file->sub, block_file_pos(block));
fprintf(stderr, "Data error at file '%s' at position '%u'\n", handle[j].path, block_file_pos(block));
fprintf(stderr, "WARNING! Unexpected data error in a data disk! The block is now marked as bad!\n");
fprintf(stderr, "Try with 'snapraid -e fix' to recover!\n");
/* silent errors are very rare, and are not a signal that a disk */
@ -363,7 +380,9 @@ static int state_sync_process(struct snapraid_state* state, struct snapraid_pari
for(l=0;l<state->level;++l) {
ret = parity_write(parity[l], i, buffer[diskmax+l], state->block_size);
if (ret == -1) {
fprintf(stdlog, "parity_error:%u:%s: Write error\n", i, lev_config_name(l));
fprintf(stderr, "DANGER! Write error in the %s disk, it isn't possible to sync.\n", lev_name(l));
fprintf(stderr, "Ensure that disk '%s' is sane.\n", lev_config_name(l));
printf("Stopping at block %u\n", i);
++error;
goto bail;