diff --git a/cmdline/check.c b/cmdline/check.c index 607ec2d8..9795a2d7 100644 --- a/cmdline/check.c +++ b/cmdline/check.c @@ -1516,7 +1516,7 @@ static int file_post(struct snapraid_state* state, int fix, int partial, block_o ret = handle_close(&handle[j]); if (ret != 0) { /* LCOV_EXCL_START */ - log_tag("%s:%" PRIu64 ":%s:%s: Close error. %s.\n", es(errno), i, disk->name, esc_tag(report->sub), strerror(errno)); + log_tag("%s::%s:%s: Close error. %s.\n", es(errno), disk->name, esc_tag(report->sub), strerror(errno)); log_fatal_errno(errno, disk->name); return -1; /* LCOV_EXCL_STOP */ @@ -1580,7 +1580,7 @@ static int file_post(struct snapraid_state* state, int fix, int partial, block_o ret = handle_close(&handle[j]); if (ret != 0) { /* LCOV_EXCL_START */ - log_tag("%s:%" PRIu64 ":%s:%s: Close error. %s.\n", es(errno), i, disk->name, esc_tag(file->sub), strerror(errno)); + log_tag("%s::%s:%s: Close error. %s.\n", es(errno), disk->name, esc_tag(file->sub), strerror(errno)); log_fatal_errno(errno, disk->name); return -1; /* LCOV_EXCL_STOP */ @@ -1635,7 +1635,7 @@ close_and_continue: ret = handle_close(&handle[j]); if (ret != 0) { /* LCOV_EXCL_START */ - log_tag("%s:%" PRIu64 ":%s:%s: Close error. %s.\n", es(errno), i, disk->name, esc_tag(file->sub), strerror(errno)); + log_tag("%s::%s:%s: Close error. %s.\n", es(errno), disk->name, esc_tag(file->sub), strerror(errno)); log_fatal_errno(errno, disk->name); return -1; /* LCOV_EXCL_STOP */ @@ -2041,7 +2041,7 @@ static int state_check_process(struct snapraid_state* state, int fix, struct sna ret = handle_close(&handle[j]); if (ret == -1) { /* LCOV_EXCL_START */ - log_tag("%s:%" PRIu64 ":%s:%s: Close error. %s.\n", es(errno), i, disk->name, esc_tag(report->sub), strerror(errno)); + log_tag("%s::%s:%s: Close error. %s.\n", es(errno), disk->name, esc_tag(report->sub), strerror(errno)); log_fatal_errno(errno, disk->name); log_fatal(errno, "Stopping at block %" PRIu64 "\n", i); @@ -2941,7 +2941,7 @@ bail: * If handle_close fails, the handle was open (f != -1), which * guarantees that both file and disk pointers are valid. */ - log_tag("%s:%" PRIu64 ":%s:%s: Close error. %s.\n", es(errno), blockmax, disk->name, esc_tag(file->sub), strerror(errno)); + log_tag("%s::%s:%s: Close error. %s.\n", es(errno), disk->name, esc_tag(file->sub), strerror(errno)); log_fatal_errno(errno, disk->name); ++unrecoverable_error; @@ -3126,7 +3126,7 @@ int state_check(struct snapraid_state* state, int fix, block_off_t blockstart, b */ ret = parity_open(parity_ptr[l], &state->parity[l], l, state->file_mode, state->block_size, state->opt.parity_limit_size); if (ret == -1) { - log_tag("parity_%s:%" PRIu64 ":%s: Open error. %s.\n", es(errno), blockmax, lev_config_name(l), strerror(errno)); + log_tag("parity_%s:%u:%s: Open error. %s.\n", es(errno), 0, lev_config_name(l), strerror(errno)); if (is_hw(errno)) { log_fatal_errno(errno, lev_config_name(l)); exit(EXIT_FAILURE); @@ -3180,7 +3180,7 @@ int state_check(struct snapraid_state* state, int fix, block_off_t blockstart, b parity_ptr[l] = &parity[l]; ret = parity_open(parity_ptr[l], &state->parity[l], l, state->file_mode, state->block_size, state->opt.parity_limit_size); if (ret == -1) { - log_tag("parity_%s:%" PRIu64 ":%s: Open error. %s.\n", es(errno), blockmax, lev_config_name(l), strerror(errno)); + log_tag("parity_%s:%u:%s: Open error. %s.\n", es(errno), 0, lev_config_name(l), strerror(errno)); if (is_hw(errno)) { log_fatal_errno(errno, lev_config_name(l)); exit(EXIT_FAILURE); @@ -3217,7 +3217,7 @@ int state_check(struct snapraid_state* state, int fix, block_off_t blockstart, b ret = parity_close(parity_ptr[l]); if (ret == -1) { /* LCOV_EXCL_START */ - log_tag("parity_%s:%" PRIu64 ":%s: Close error. %s.\n", es(errno), blockmax, lev_config_name(l), strerror(errno)); + log_tag("parity_%s::%s: Close error. %s.\n", es(errno), lev_config_name(l), strerror(errno)); log_fatal_errno(errno, lev_config_name(l)); ++process_error; diff --git a/cmdline/dry.c b/cmdline/dry.c index 03066564..52a002de 100644 --- a/cmdline/dry.c +++ b/cmdline/dry.c @@ -65,7 +65,7 @@ static void dry_data_reader(struct snapraid_worker* worker, struct snapraid_task * This one is really an unexpected error, because we are only reading * and closing a descriptor should never fail */ - log_tag("%s:%" PRIu64 ":%s:%s: Close error. %s.\n", es(errno), blockcur, disk->name, esc_tag(report->sub), strerror(errno)); + log_tag("%s::%s:%s: Close error. %s.\n", es(errno), disk->name, esc_tag(report->sub), strerror(errno)); log_fatal_errno(errno, disk->name); log_fatal(errno, "Stopping at block %" PRIu64 "\n", blockcur); @@ -377,7 +377,7 @@ bail: * If handle_close fails, the handle was open (f != -1), which * guarantees that both file and disk pointers are valid. */ - log_tag("%s:%" PRIu64 ":%s:%s: Close error. %s.\n", es(errno), blockcur, disk->name, esc_tag(file->sub), strerror(errno)); + log_tag("%s::%s:%s: Close error. %s.\n", es(errno), disk->name, esc_tag(file->sub), strerror(errno)); log_fatal_errno(errno, disk->name); if (is_hw(errno)) { @@ -454,7 +454,7 @@ int state_dry(struct snapraid_state* state, block_off_t blockstart, block_off_t ret = parity_open(&parity_handle[l], &state->parity[l], l, state->file_mode, state->block_size, state->opt.parity_limit_size); if (ret == -1) { /* LCOV_EXCL_START */ - log_tag("parity_%s:%" PRIu64 ":%s: Open error. %s.\n", es(errno), blockmax, lev_config_name(l), strerror(errno)); + log_tag("parity_%s:%u:%s: Open error. %s.\n", es(errno), 0, lev_config_name(l), strerror(errno)); log_fatal_errno(errno, lev_config_name(l)); exit(EXIT_FAILURE); /* LCOV_EXCL_STOP */ @@ -479,7 +479,7 @@ int state_dry(struct snapraid_state* state, block_off_t blockstart, block_off_t ret = parity_close(&parity_handle[l]); if (ret == -1) { /* LCOV_EXCL_START */ - log_tag("parity_%s:%" PRIu64 ":%s: Close error. %s.\n", es(errno), blockmax, lev_config_name(l), strerror(errno)); + log_tag("parity_%s::%s: Close error. %s.\n", es(errno), lev_config_name(l), strerror(errno)); log_fatal_errno(errno, lev_config_name(l)); ++process_error; diff --git a/cmdline/scrub.c b/cmdline/scrub.c index 094210c0..2344a442 100644 --- a/cmdline/scrub.c +++ b/cmdline/scrub.c @@ -370,7 +370,7 @@ static void scrub_data_reader(struct snapraid_worker* worker, struct snapraid_ta * This one is really an unexpected error, because we are only reading * and closing a descriptor should never fail */ - log_tag("%s:%" PRIu64 ":%s:%s: Close error. %s.\n", es(errno), blockcur, disk->name, esc_tag(report->sub), strerror(errno)); + log_tag("%s::%s:%s: Close error. %s.\n", es(errno), disk->name, esc_tag(report->sub), strerror(errno)); log_fatal_errno(errno, disk->name); log_fatal(errno, "Stopping at block %" PRIu64 "\n", blockcur); @@ -1034,7 +1034,7 @@ bail: * If handle_close fails, the handle was open (f != -1), which * guarantees that both file and disk pointers are valid. */ - log_tag("%s:%" PRIu64 ":%s:%s: Close error. %s.\n", es(errno), blockcur, disk->name, esc_tag(file->sub), strerror(errno)); + log_tag("%s::%s:%s: Close error. %s.\n", es(errno), disk->name, esc_tag(file->sub), strerror(errno)); log_fatal_errno(errno, disk->name); if (is_hw(errno)) { @@ -1239,7 +1239,7 @@ int state_scrub(struct snapraid_state* state, int plan100, int olderthan) ret = parity_open(&parity_handle[l], &state->parity[l], l, state->file_mode, state->block_size, state->opt.parity_limit_size); if (ret == -1) { /* LCOV_EXCL_START */ - log_tag("parity_%s:%" PRIu64 ":%s: Open error. %s.\n", es(errno), blockmax, lev_config_name(l), strerror(errno)); + log_tag("parity_%s:%u:%s: Open error. %s.\n", es(errno), 0, lev_config_name(l), strerror(errno)); log_fatal_errno(errno, lev_config_name(l)); exit(EXIT_FAILURE); /* LCOV_EXCL_STOP */ @@ -1258,7 +1258,7 @@ int state_scrub(struct snapraid_state* state, int plan100, int olderthan) ret = parity_close(&parity_handle[l]); if (ret == -1) { /* LCOV_EXCL_START */ - log_tag("parity_%s:%" PRIu64 ":%s: Close error. %s.\n", es(errno), blockmax, lev_config_name(l), strerror(errno)); + log_tag("parity_%s::%s: Close error. %s.\n", es(errno), lev_config_name(l), strerror(errno)); log_fatal_errno(errno, lev_config_name(l)); ++process_error; diff --git a/cmdline/sync.c b/cmdline/sync.c index c85ccaab..50ac681b 100644 --- a/cmdline/sync.c +++ b/cmdline/sync.c @@ -272,6 +272,47 @@ * both file size and modification time, may not be detected by a later scan. * This is a general limitation of metadata-based change detection, not a * special property of modifications occurring during sync. + * + * Structured error log model + * -------------------------- + * + * Errors affecting data files are reported as: + * + * error:::: + * error_io:::: + * error_data:::: + * + * Errors affecting parity are reported as: + * + * parity_error::: + * parity_error_io::: + * parity_error_data::: + * + * "error" reports a soft or logical error that is not classified as a hardware + * I/O failure. "error_io" reports an I/O failure classified by is_hw(). + * "error_data" reports data that was successfully read but did not match the + * expected hash or parity. + * + * The block field identifies the SnapRAID parity position associated with the + * error. It identifies the logical position affected by the failed operation, + * not necessarily the physical sector that caused the failure. + * + * Data file open/create errors occurring while processing a position report + * the current block, because that position could not be processed and may be + * marked bad for a later retry. Read/write and data errors report the position + * directly involved in the operation. + * + * Parity open/create errors report block 0. This is a retry marker rather than + * an indication that parity block 0 is bad: parity will be opened or created + * again by a subsequent command. + * + * The block field is empty when the error cannot be associated with a specific + * position. In particular, close errors use an empty block because an error + * reported by close() may originate from an earlier operation and cannot be + * reliably attributed to any previously processed block. + * + * Error classification and block localization are independent: for example, + * both error and error_io may have an empty block when reporting a close error. */ /****************************************************************************/ @@ -400,7 +441,7 @@ static int state_hash_process(struct snapraid_state* state, block_off_t blocksta * This one is really an unexpected error, because we are only reading * and closing a descriptor should never fail */ - log_tag("%s:%" PRIu64 ":%s:%s: Close error. %s.\n", es(errno), blockcur, disk->name, esc_tag(report->sub), strerror(errno)); + log_tag("%s::%s:%s: Close error. %s.\n", es(errno), disk->name, esc_tag(report->sub), strerror(errno)); log_fatal_errno(errno, disk->name); log_fatal(errno, "Stopping at block %" PRIu64 "\n", blockcur); @@ -580,7 +621,7 @@ static int state_hash_process(struct snapraid_state* state, block_off_t blocksta * This one is really an unexpected error, because we are only reading * and closing a descriptor should never fail */ - log_tag("%s:%" PRIu64 ":%s:%s: Close error. %s.\n", es(errno), blockmax, disk->name, esc_tag(report->sub), strerror(errno)); + log_tag("%s::%s:%s: Close error. %s.\n", es(errno), disk->name, esc_tag(report->sub), strerror(errno)); log_fatal_errno(errno, disk->name); log_fatal(errno, "Stopping at block %" PRIu64 "\n", blockmax); @@ -634,7 +675,7 @@ bail: * If handle_close fails, the handle was open (f != -1), which * guarantees that both file and disk pointers are valid. */ - log_tag("%s:%" PRIu64 ":%s:%s: Close error. %s.\n", es(errno), blockcur, disk->name, esc_tag(file->sub), strerror(errno)); + log_tag("%s::%s:%s: Close error. %s.\n", es(errno), disk->name, esc_tag(file->sub), strerror(errno)); log_fatal_errno(errno, disk->name); if (is_hw(errno)) { @@ -802,7 +843,7 @@ static void sync_data_reader(struct snapraid_worker* worker, struct snapraid_tas * This one is really an unexpected error, because we are only reading * and closing a descriptor should never fail */ - log_tag("%s:%" PRIu64 ":%s:%s: Close error. %s.\n", es(errno), blockcur, disk->name, esc_tag(report->sub), strerror(errno)); + log_tag("%s::%s:%s: Close error. %s.\n", es(errno), disk->name, esc_tag(report->sub), strerror(errno)); log_fatal_errno(errno, disk->name); log_fatal(errno, "Stopping at block %" PRIu64 "\n", blockcur); @@ -1843,7 +1884,7 @@ bail_abort: * If handle_close fails, the handle was open (f != -1), which * guarantees that both file and disk pointers are valid. */ - log_tag("%s:%" PRIu64 ":%s:%s: Close error. %s.\n", es(errno), blockcur, disk->name, esc_tag(file->sub), strerror(errno)); + log_tag("%s::%s:%s: Close error. %s.\n", es(errno), disk->name, esc_tag(file->sub), strerror(errno)); log_fatal_errno(errno, disk->name); if (is_hw(errno)) { @@ -2234,7 +2275,7 @@ int state_sync(struct snapraid_state* state, block_off_t blockstart, block_off_t ret = parity_close(&parity_handle[l]); if (ret == -1) { /* LCOV_EXCL_START */ - log_tag("parity_%s:%" PRIu64 ":%s: Close error. %s.\n", es(errno), blockmax, lev_config_name(l), strerror(errno)); + log_tag("parity_%s::%s: Close error. %s.\n", es(errno), lev_config_name(l), strerror(errno)); log_fatal_errno(errno, lev_config_name(l)); ++process_error; diff --git a/doc/snapraid_log.1 b/doc/snapraid_log.1 index 928e7a01..fb3d2b5d 100644 --- a/doc/snapraid_log.1 +++ b/doc/snapraid_log.1 @@ -1952,23 +1952,32 @@ These tags report specific errors that occur on data disks during the commands that access files and parities. .TP .B error[_io|_data]:::: -Logs file access errors (open, read, file changed) during the -data disk read operation for parity calculation or verification. +Logs errors affecting data files. +.PP +.RS 4 +With no suffix, \`error\` indicates a soft or logical error not +classified as a hardware I/O or silent data error. +.RE .RS 4 .PD 0 .HP 4 .I _io -Indicates a physical Input/Output error. -The disk was unable to read or write a specific block, -typically signaling a failing sector or cable issue. +Indicates a physical Input/Output error, typically +signaling a failing sector, device, or cable issue. .HP 4 .I _data -Indicates the data was read successfully but failed -the checksum/hash verification. This signals \`silent\` +Indicates data that was read successfully but failed +the checksum/hash verification, signaling \`silent\` corruption or an unsuccessful parity match. .HP 4 .I -The zero\-based index of the block where the error occurred (uint). +The zero\-based SnapRAID parity position associated with +the error (uint). It identifies the logical position affected +by the failed operation, not necessarily the physical sector +that caused the failure. Data file open/create errors occurring +while processing a position report the current block. The field +is empty when the error cannot be associated with a specific +position, such as for close errors. .HP 4 .I The name of the data disk. @@ -1985,22 +1994,30 @@ error (e.g., \`Open/Read/Write error\`, .RE .TP .B parity_error[_io|_data]::: -Logs errors during parity disk read or write operations. +Logs errors affecting parity. +.PP +.RS 4 +With no suffix, \`parity_error\` indicates a soft or logical error +not classified as a hardware I/O or silent data error. +.RE .RS 4 .PD 0 .HP 4 .I _io -Indicates a physical Input/Output error. -The disk was unable to read or write a specific block, -typically signaling a failing sector or cable issue. +Indicates a physical Input/Output error, typically +signaling a failing sector, device, or cable issue. .HP 4 .I _data -Indicates the data was read successfully but failed -the checksum/hash verification. This signals \`silent\` -corruption or an unsuccessful parity match. +Indicates data that was read successfully but failed +the parity verification, signaling \`silent\` corruption. .HP 4 .I -The zero\-based index of the block where the error occurred (uint). +The zero\-based SnapRAID parity position associated with +the error (uint). Parity open/create errors report block 0 as +a retry marker; this does not mean that parity block 0 is bad. +Parity access is attempted again by subsequent commands. The +field is empty when the error cannot be associated with a +specific position, such as for close errors. .HP 4 .I The configuration name of the parity level (e.g., @@ -2008,7 +2025,7 @@ The configuration name of the parity level (e.g., .HP 4 .I A descriptive message indicating the nature of the -error (e.g., \`Read/Write error\`, +error (e.g., \`Open/Read/Write error\`, \`Data error, diff bits /\`). .PD .RE diff --git a/doc/snapraid_log.d b/doc/snapraid_log.d index 03bebdb8..bcdc2546 100644 --- a/doc/snapraid_log.d +++ b/doc/snapraid_log.d @@ -1230,16 +1230,23 @@ Error Tags commands that access files and parities. =error[_io|_data]:::: - Logs file access errors (open, read, file changed) during the - data disk read operation for parity calculation or verification. + Logs errors affecting data files. - _io - Indicates a physical Input/Output error. - The disk was unable to read or write a specific block, - typically signaling a failing sector or cable issue. - _data - Indicates the data was read successfully but failed - the checksum/hash verification. This signals `silent` + With no suffix, `error` indicates a soft or logical error not + classified as a hardware I/O or silent data error. + + _io - Indicates a physical Input/Output error, typically + signaling a failing sector, device, or cable issue. + _data - Indicates data that was read successfully but failed + the checksum/hash verification, signaling `silent` corruption or an unsuccessful parity match. - - The zero-based index of the block where the error occurred (uint). + - The zero-based SnapRAID parity position associated with + the error (uint). It identifies the logical position affected + by the failed operation, not necessarily the physical sector + that caused the failure. Data file open/create errors occurring + while processing a position report the current block. The field + is empty when the error cannot be associated with a specific + position, such as for close errors. - The name of the data disk. - The path (relative to the disk mount point) of the file containing the block (escaped). @@ -1248,19 +1255,25 @@ Error Tags `Data error at position , diff bits /`). =parity_error[_io|_data]::: - Logs errors during parity disk read or write operations. + Logs errors affecting parity. - _io - Indicates a physical Input/Output error. - The disk was unable to read or write a specific block, - typically signaling a failing sector or cable issue. - _data - Indicates the data was read successfully but failed - the checksum/hash verification. This signals `silent` - corruption or an unsuccessful parity match. - - The zero-based index of the block where the error occurred (uint). + With no suffix, `parity_error` indicates a soft or logical error + not classified as a hardware I/O or silent data error. + + _io - Indicates a physical Input/Output error, typically + signaling a failing sector, device, or cable issue. + _data - Indicates data that was read successfully but failed + the parity verification, signaling `silent` corruption. + - The zero-based SnapRAID parity position associated with + the error (uint). Parity open/create errors report block 0 as + a retry marker; this does not mean that parity block 0 is bad. + Parity access is attempted again by subsequent commands. The + field is empty when the error cannot be associated with a + specific position, such as for close errors. - The configuration name of the parity level (e.g., `parity`, `2-parity`). - A descriptive message indicating the nature of the - error (e.g., `Read/Write error`, + error (e.g., `Open/Read/Write error`, `Data error, diff bits /`). =hardlink_error[_io]:::: diff --git a/doc/snapraid_log.txt b/doc/snapraid_log.txt index d2af6444..39cf518a 100644 --- a/doc/snapraid_log.txt +++ b/doc/snapraid_log.txt @@ -1282,16 +1282,23 @@ These tags report specific errors that occur on data disks during the commands that access files and parities. error[_io|_data]:::: - Logs file access errors (open, read, file changed) during the - data disk read operation for parity calculation or verification. + Logs errors affecting data files. - _io - Indicates a physical Input/Output error. - The disk was unable to read or write a specific block, - typically signaling a failing sector or cable issue. - _data - Indicates the data was read successfully but failed - the checksum/hash verification. This signals `silent` + With no suffix, `error` indicates a soft or logical error not + classified as a hardware I/O or silent data error. + + _io - Indicates a physical Input/Output error, typically + signaling a failing sector, device, or cable issue. + _data - Indicates data that was read successfully but failed + the checksum/hash verification, signaling `silent` corruption or an unsuccessful parity match. - - The zero-based index of the block where the error occurred (uint). + - The zero-based SnapRAID parity position associated with + the error (uint). It identifies the logical position affected + by the failed operation, not necessarily the physical sector + that caused the failure. Data file open/create errors occurring + while processing a position report the current block. The field + is empty when the error cannot be associated with a specific + position, such as for close errors. - The name of the data disk. - The path (relative to the disk mount point) of the file containing the block (escaped). @@ -1300,19 +1307,25 @@ commands that access files and parities. `Data error at position , diff bits /`). parity_error[_io|_data]::: - Logs errors during parity disk read or write operations. + Logs errors affecting parity. - _io - Indicates a physical Input/Output error. - The disk was unable to read or write a specific block, - typically signaling a failing sector or cable issue. - _data - Indicates the data was read successfully but failed - the checksum/hash verification. This signals `silent` - corruption or an unsuccessful parity match. - - The zero-based index of the block where the error occurred (uint). + With no suffix, `parity_error` indicates a soft or logical error + not classified as a hardware I/O or silent data error. + + _io - Indicates a physical Input/Output error, typically + signaling a failing sector, device, or cable issue. + _data - Indicates data that was read successfully but failed + the parity verification, signaling `silent` corruption. + - The zero-based SnapRAID parity position associated with + the error (uint). Parity open/create errors report block 0 as + a retry marker; this does not mean that parity block 0 is bad. + Parity access is attempted again by subsequent commands. The + field is empty when the error cannot be associated with a + specific position, such as for close errors. - The configuration name of the parity level (e.g., `parity`, `2-parity`). - A descriptive message indicating the nature of the - error (e.g., `Read/Write error`, + error (e.g., `Open/Read/Write error`, `Data error, diff bits /`). hardlink_error[_io]::::