diff --git a/bdb/file.c b/bdb/file.c index 0b576d6f2c..77b7c8b903 100644 --- a/bdb/file.c +++ b/bdb/file.c @@ -3592,7 +3592,7 @@ static void delete_log_files_int(bdb_state_type *bdb_state) log files greater than that filenum */ lowfilenum = get_lowfilenum_sanclist(bdb_state); if (bdb_state->attr->debug_log_deletion) - logmsg(LOGMSG_USER, "lowfilenum %d\n", lowfilenum); + logmsg(LOGMSG_USER, "%s: cluster-wide lowfilenum is %d\n", __func__, lowfilenum); { struct interned_string *hosts[REPMAX]; @@ -3617,7 +3617,7 @@ static void delete_log_files_int(bdb_state_type *bdb_state) if (sc_logical_lwm < lowfilenum) { lowfilenum = sc_logical_lwm; if (bdb_state->attr->debug_log_deletion) { - logmsg(LOGMSG_USER, "Setting lowfilenum to %d for schema change logical redo\n", lowfilenum); + logmsg(LOGMSG_USER, "%s: Setting lowfilenum to %d for schema change logical redo\n", __func__, lowfilenum); } } } @@ -3642,7 +3642,7 @@ static void delete_log_files_int(bdb_state_type *bdb_state) if (gbl_rowlocks) { rc = bdb_get_file_lwm(bdb_state, NULL, &lwmlsn, &bdberr); if (rc) { - logmsg(LOGMSG_ERROR, "can't get perm lsn lwm rc %d bdberr %d\n", rc, + logmsg(LOGMSG_ERROR, "%s: can't get perm lsn lwm rc %d bdberr %d\n", __func__, rc, bdberr); return; } @@ -3667,8 +3667,8 @@ static void delete_log_files_int(bdb_state_type *bdb_state) if (snapylsn.file <= lowfilenum) { if (bdb_state->attr->debug_log_deletion) { logmsg(LOGMSG_USER, - "Setting lowfilenum to %d from %d because snapylsn is " - "%d:%d\n", + "%s: Setting lowfilenum to %d from %d because snapylsn is " + "%d:%d\n", __func__, snapylsn.file - 1, lowfilenum, snapylsn.file, snapylsn.offset); } @@ -3676,8 +3676,8 @@ static void delete_log_files_int(bdb_state_type *bdb_state) } else { if (bdb_state->attr->debug_log_deletion) { logmsg(LOGMSG_USER, - "Ignoring snapylsn because %d is already <= %d:%d\n", - lowfilenum, snapylsn.file, snapylsn.offset); + "%s: Ignoring snapylsn because %d is already <= %d:%d\n", + __func__, lowfilenum, snapylsn.file, snapylsn.offset); } } } @@ -3696,9 +3696,9 @@ static void delete_log_files_int(bdb_state_type *bdb_state) if (asoflsn.file <= lowfilenum) { if (bdb_state->attr->debug_log_deletion) { logmsg(LOGMSG_USER, - "Setting lowfilenum to %d from %d because asoflsn is " + "%s: Setting lowfilenum to %d from %d because asoflsn is " "%d:%d\n", - asoflsn.file - 1, lowfilenum, asoflsn.file, + __func__, asoflsn.file - 1, lowfilenum, asoflsn.file, asoflsn.offset); } lowfilenum = asoflsn.file - 1; @@ -3709,8 +3709,8 @@ static void delete_log_files_int(bdb_state_type *bdb_state) if (bdb_state->attr->log_delete_low_headroom_breaktime && low_headroom_count > bdb_state->attr->log_delete_low_headroom_breaktime) { - logmsg(LOGMSG_WARN, "low_headroom, but tried %d times and giving up\n", - bdb_state->attr->log_delete_low_headroom_breaktime); + logmsg(LOGMSG_WARN, "%s: low_headroom, but tried %d times and giving up\n", + __func__, bdb_state->attr->log_delete_low_headroom_breaktime); return; } @@ -3718,7 +3718,7 @@ static void delete_log_files_int(bdb_state_type *bdb_state) /* ask berk for a list of files that it thinks we can delete */ rc = bdb_state->dbenv->log_archive(bdb_state->dbenv, &list, 0); if (rc != 0) { - logmsg(LOGMSG_ERROR, "delete_log_files: log_archive failed\n"); + logmsg(LOGMSG_ERROR, "%s: log_archive rc(%d)\n", __func__, rc); return; } @@ -3728,7 +3728,7 @@ static void delete_log_files_int(bdb_state_type *bdb_state) print(bdb_state, "flushing log file\n"); rc = bdb_state->dbenv->log_flush(bdb_state->dbenv, NULL); if (rc != 0) { - logmsg(LOGMSG_ERROR, "delete_log_files: log_flush err %d\n", rc); + logmsg(LOGMSG_ERROR, "%s: log_flush rc(%d)\n", __func__, rc); return; } @@ -3736,14 +3736,14 @@ static void delete_log_files_int(bdb_state_type *bdb_state) if ((rc = __db_find_recovery_start_if_enabled(bdb_state->dbenv, &recovery_lsn)) != 0) { - logmsg(LOGMSG_ERROR, "__db_find_recovery_start ret %d\n", rc); + logmsg(LOGMSG_ERROR, "%s: __db_find_recovery_start rc(%d)\n", __func__, rc); return; } if (bdb_state->attr->debug_log_deletion) { - logmsg(LOGMSG_USER, "recovery lsn %u:%u\n", recovery_lsn.file, + logmsg(LOGMSG_USER, "%s: recovery lsn %u:%u\n", __func__, recovery_lsn.file, recovery_lsn.offset); - logmsg(LOGMSG_USER, "lowfilenum %d\n", lowfilenum); + logmsg(LOGMSG_USER, "%s: lowfilenum %d\n", __func__, lowfilenum); } } @@ -3781,12 +3781,12 @@ static void delete_log_files_int(bdb_state_type *bdb_state) filenum = get_filenum_from_logfile(logname); if (bdb_state->attr->debug_log_deletion) { - logmsg(LOGMSG_USER, "considering %s filenum %d\n", *file, filenum); + logmsg(LOGMSG_USER, "%s: considering %s filenum %d\n", __func__, *file, filenum); } rc = stat(logname, &logfile_stats); if (rc != 0) - logmsg(LOGMSG_ERROR, "delete_log_files: stat returned %d\n", rc); + logmsg(LOGMSG_ERROR, "%s: delete_log_files: stat returned %d\n", __func__, rc); time_t log_age = time(NULL) - logfile_stats.st_mtime; @@ -3794,12 +3794,13 @@ static void delete_log_files_int(bdb_state_type *bdb_state) if (delete_hwm_logs == 0) { if (bdb_state->attr->debug_log_deletion) logmsg(LOGMSG_ERROR, - "Can't delete log, age %ld not older " + "%s: Can't delete %s, age %ld not older " "than log delete age %d.\n", - log_age, bdb_state->attr->min_keep_logs_age); + __func__, *file, log_age, bdb_state->attr->min_keep_logs_age); if (ctrace_info) - ctrace("Can't delete log, age %lld not older than log " + ctrace("Can't delete %s, age %lld not older than log " "delete age %lld.\n", + *file, (long long int)log_age, (long long int)bdb_state->attr->min_keep_logs_age); break; @@ -3808,16 +3809,16 @@ static void delete_log_files_int(bdb_state_type *bdb_state) else { if (bdb_state->attr->debug_log_deletion) logmsg(LOGMSG_USER, - "Log age %ld is younger than min_age " + "%s: %s age %ld is younger than min_age " "but fall-through: numlogs" " is %d and high water mark is %d\n", - log_age, numlogs, + __func__, *file, log_age, numlogs, bdb_state->attr->min_keep_logs_age_hwm); if (ctrace_info) - ctrace("Log age %ld is younger than min_age but " + ctrace("%s: %s age %ld is younger than min_age but " "fall-through: numlogs" " is %d and high water mark is %d\n", - log_age, numlogs, + __func__, *file, log_age, numlogs, bdb_state->attr->min_keep_logs_age_hwm); delete_hwm_logs--; } @@ -3825,7 +3826,7 @@ static void delete_log_files_int(bdb_state_type *bdb_state) if (!__checkpoint_ok_to_delete_log(bdb_state->dbenv, filenum)) { if (bdb_state->attr->debug_log_deletion) - logmsg(LOGMSG_USER, "not ok to delete log, newer than checkpoint\n"); + logmsg(LOGMSG_USER, "%s: not ok to delete log %s, newer than checkpoint\n", __func__, *file); if (ctrace_info) ctrace("not ok to delete log, newer than checkpoint\n"); break; @@ -3834,7 +3835,7 @@ static void delete_log_files_int(bdb_state_type *bdb_state) if (recovery_lsn.file != 0 && filenum >= recovery_lsn.file) { if (bdb_state->attr->debug_log_deletion) logmsg(LOGMSG_DEBUG, - "not ok to delete log, newer than recovery point\n"); + "%s: not ok to delete log %s, newer than recovery point\n", __func__, *file); if (ctrace_info) ctrace("not ok to delete log, newer than recovery point\n"); break; @@ -3845,35 +3846,35 @@ static void delete_log_files_int(bdb_state_type *bdb_state) if (!gbl_is_physical_replicant && bdb_state->attr->private_blkseq_enabled && !bdb_blkseq_can_delete_log(bdb_state, filenum)) { if (bdb_state->attr->debug_log_deletion) { - logmsg(LOGMSG_USER, "skipping log %s filenm %d because it has recent blkseqs\n", - *file, filenum); + logmsg(LOGMSG_USER, "%s: skipping log %s because it has recent blkseqs\n", + __func__, *file); bdb_blkseq_dumplogs(bdb_state); } if (ctrace_info) - ctrace("skipping log %s filenm %d because it has recent blkseqs\n", - *file, filenum); + ctrace("skipping log %s because it has recent blkseqs\n", + *file); break; } if (lwm_lowfilenum != -1 && filenum > lwm_lowfilenum) { if (bdb_state->attr->debug_log_deletion) - logmsg(LOGMSG_USER, "not ok to delete log %d, newer than the " + logmsg(LOGMSG_USER, "%s: not ok to delete log %s, newer than the " "lwm_lowfilenum %d\n", - filenum, lwm_lowfilenum); + __func__, *file, lwm_lowfilenum); if (ctrace_info) - ctrace("not ok to delete log %d, newer than the " + ctrace("not ok to delete log %s, newer than the " "lwm_lowfilenum %d\n", - filenum, lwm_lowfilenum); + *file, lwm_lowfilenum); break; } int lowest_in_use_modsnap_file = bdb_get_lowest_modsnap_file(bdb_state); if (lowest_in_use_modsnap_file != -1 && filenum >= lowest_in_use_modsnap_file) { if (bdb_state->attr->debug_log_deletion) { - logmsg(LOGMSG_USER, "not ok to delete log %d, log file " + logmsg(LOGMSG_USER, "%s: not ok to delete log %s, log file " "needed to maintain current modsnap " "transactions\n", - filenum); + __func__, *file); } break; } @@ -3885,14 +3886,14 @@ static void delete_log_files_int(bdb_state_type *bdb_state) if (!bdb_osql_trn_asof_ok_to_delete_log(filenum)) { Pthread_mutex_unlock(&bdb_gbl_recoverable_lsn_mutex); if (bdb_state->attr->debug_log_deletion) - logmsg(LOGMSG_USER, "not ok to delete log %d, log file " + logmsg(LOGMSG_USER, "%s: not ok to delete log %s, log file " "needed to maintain begin-as-of " "transactions\n", - filenum); + __func__, *file); if (ctrace_info) - ctrace("not ok to delete log %d, log file needed to " + ctrace("not ok to delete log %s, log file needed to " "maintain begin-as-of transactions\n", - filenum); + *file); break; } } @@ -3904,12 +3905,12 @@ static void delete_log_files_int(bdb_state_type *bdb_state) bdb_state->attr->min_keep_logs_age, filenum)) { Pthread_mutex_unlock(&bdb_gbl_recoverable_lsn_mutex); if (bdb_state->attr->debug_log_deletion) - logmsg(LOGMSG_USER, "not ok to delete log, log file needed " + logmsg(LOGMSG_USER, "%s: not ok to delete log %s, log file needed " "to recover to at least %ds ago\n", - bdb_state->attr->min_keep_logs_age); + __func__, *file, bdb_state->attr->min_keep_logs_age); if (ctrace_info) - ctrace("not ok to delete log, log file needed to " - "recover to at least %ds ago\n", + ctrace("not ok to delete log %s, log file needed to " + "recover to at least %ds ago\n", *file, bdb_state->attr->min_keep_logs_age); break; } @@ -3941,15 +3942,15 @@ static void delete_log_files_int(bdb_state_type *bdb_state) /* delete this file if we got this far AND it's <= the * replicated low number */ if (is_low_headroom) { - logmsg(LOGMSG_WARN, "LOW HEADROOM : delete_log_files: deleting " + logmsg(LOGMSG_WARN, "%s: LOW HEADROOM : delete_log_files: deleting " "logfile: %s\n", - logname); + __func__, *file); } - print(bdb_state, "%sdelete_log_files: deleting logfile: %s " - "filenum %d lowfilenum was %d\n", - (is_low_headroom) ? "LOW HEADROOM : " : "", logname, - filenum, lowfilenum); + print(bdb_state, "%s: %sdelete_log_files: deleting logfile: %s " + "lowfilenum was %d\n", + __func__, (is_low_headroom) ? "LOW HEADROOM : " : "", *file, + lowfilenum); print(bdb_state, "filenums: %s\n", filenums_str); if (gbl_rowlocks) print(bdb_state, "lwm at log delete time: %u:%u\n", @@ -3963,11 +3964,11 @@ static void delete_log_files_int(bdb_state_type *bdb_state) char *newname = comdb2_location("backup_logfiles_dir", "%s", base); if (bdb_state->attr->debug_log_deletion) { - logmsg(LOGMSG_DEBUG, "backingup log %s to %s\n", logname, newname); + logmsg(LOGMSG_DEBUG, "%s: backing up log %s to %s\n", __func__, logname, newname); } if (ctrace_info) { - ctrace("backingup log %s to %s\n", logname, newname); + ctrace("backing up log %s to %s\n", logname, newname); } char cmd[4048]; @@ -3983,19 +3984,19 @@ static void delete_log_files_int(bdb_state_type *bdb_state) } if (!deleted) { if (bdb_state->attr->debug_log_deletion) { - logmsg(LOGMSG_DEBUG, "deleting log %s %d\n", logname, filenum); + logmsg(LOGMSG_DEBUG, "%s: deleting log %s\n", __func__, logname); } if (ctrace_info) { - ctrace("deleting log %s %d\n", logname, filenum); + ctrace("deleting log %s\n", logname); } __log_invalidate(filenum); rc = unlink(logname); if (rc) { logmsg(LOGMSG_ERROR, - "delete_log_files: unlink for <%s> returned %d %d\n", - logname, rc, errno); + "%s: unlink for <%s> returned %d %d\n", + __func__, logname, rc, errno); } } } else { @@ -4006,13 +4007,13 @@ static void delete_log_files_int(bdb_state_type *bdb_state) * loop, so don't actually delete so we don't create log holes. */ if (bdb_state->attr->debug_log_deletion) { - logmsg(LOGMSG_DEBUG, "not deleting %d, lowfilenum %d adj %d low %d\n", - filenum, lowfilenum, delete_adjacent, + logmsg(LOGMSG_DEBUG, "%s: Not deleting %s, lowfilenum %d adj %d low %d\n", + __func__, *file, lowfilenum, delete_adjacent, is_low_headroom); } if (ctrace_info) - ctrace("not deleting %d, lowfilenum %d adj %d low %d\n", - filenum, lowfilenum, delete_adjacent, + ctrace("not deleting %s, lowfilenum %d adj %d low %d\n", + *file, lowfilenum, delete_adjacent, is_low_headroom); delete_adjacent = 0; } @@ -4070,7 +4071,7 @@ static void delete_log_files_int(bdb_state_type *bdb_state) send_filenum = filenum; if (bdb_state->attr->debug_log_deletion) - logmsg(LOGMSG_DEBUG, "nothing to delete, at file %d\n", first_log_lsn.file); + logmsg(LOGMSG_DEBUG, "%s: nothing to delete, at file %d\n", __func__, first_log_lsn.file); if (ctrace_info) ctrace("nothing to delete, at file %d\n", first_log_lsn.file); @@ -4081,9 +4082,9 @@ static void delete_log_files_int(bdb_state_type *bdb_state) struct hostinfo *h = retrieve_hostinfo(bdb_state->repinfo->myhost_interned); h->filenum = send_filenum; if (bdb_state->attr->debug_log_deletion) - logmsg(LOGMSG_WARN, "sending filenum %d\n", send_filenum); + logmsg(LOGMSG_WARN, "%s: sending local lowfilenum (%d) to cluster\n", __func__, send_filenum); if (ctrace_info) - ctrace("sending filenum %d\n", send_filenum); + ctrace("%s: sending local lowfilenum (%d) to cluster\n", __func__, send_filenum); } int bdb_get_low_headroom_count(bdb_state_type *bdb_state) diff --git a/tests/logdelete.test/lrl.options b/tests/logdelete.test/lrl.options index b769335deb..1da841c074 100644 --- a/tests/logdelete.test/lrl.options +++ b/tests/logdelete.test/lrl.options @@ -1,5 +1,6 @@ setattr LOGFILESIZE 10000000 LOGMEMSIZE 1048576 +setattr DEBUG_LOG_DELETION 1 setattr LOGDELETELOWFILENUM -1 setattr MIN_KEEP_LOGS_AGE 60 setattr PRIVATE_BLKSEQ_MAXAGE 60