Unverified Commit f28e2ce7 authored by chenyang8094's avatar chenyang8094 Committed by GitHub
Browse files

improve logging around AOF file creation and loading (#10763)

instead of printing a log when a folder or a manifest is missing (level reduced), we print:

total time it took to load all the aof files
when creating a new base or incr file
starting to write to an existing incr file on startup
parent ad25716a
...@@ -231,14 +231,14 @@ sds getAofManifestAsString(aofManifest *am) { ...@@ -231,14 +231,14 @@ sds getAofManifestAsString(aofManifest *am) {
void aofLoadManifestFromDisk(void) { void aofLoadManifestFromDisk(void) {
server.aof_manifest = aofManifestCreate(); server.aof_manifest = aofManifestCreate();
if (!dirExists(server.aof_dirname)) { if (!dirExists(server.aof_dirname)) {
serverLog(LL_NOTICE, "The AOF directory %s doesn't exist", server.aof_dirname); serverLog(LL_DEBUG, "The AOF directory %s doesn't exist", server.aof_dirname);
return; return;
} }
sds am_name = getAofManifestFileName(); sds am_name = getAofManifestFileName();
sds am_filepath = makePath(server.aof_dirname, am_name); sds am_filepath = makePath(server.aof_dirname, am_name);
if (!fileExist(am_filepath)) { if (!fileExist(am_filepath)) {
serverLog(LL_NOTICE, "The AOF manifest file %s doesn't exist", am_name); serverLog(LL_DEBUG, "The AOF manifest file %s doesn't exist", am_name);
sdsfree(am_name); sdsfree(am_name);
sdsfree(am_filepath); sdsfree(am_filepath);
return; return;
...@@ -714,15 +714,16 @@ void aofOpenIfNeededOnServerStart(void) { ...@@ -714,15 +714,16 @@ void aofOpenIfNeededOnServerStart(void) {
} }
/* If we start with an empty dataset, we will force create a BASE file. */ /* If we start with an empty dataset, we will force create a BASE file. */
if (!server.aof_manifest->base_aof_info && size_t incr_aof_len = listLength(server.aof_manifest->incr_aof_list);
!listLength(server.aof_manifest->incr_aof_list)) if (!server.aof_manifest->base_aof_info && !incr_aof_len) {
{
sds base_name = getNewBaseFileNameAndMarkPreAsHistory(server.aof_manifest); sds base_name = getNewBaseFileNameAndMarkPreAsHistory(server.aof_manifest);
sds base_filepath = makePath(server.aof_dirname, base_name); sds base_filepath = makePath(server.aof_dirname, base_name);
if (rewriteAppendOnlyFile(base_filepath) != C_OK) { if (rewriteAppendOnlyFile(base_filepath) != C_OK) {
exit(1); exit(1);
} }
sdsfree(base_filepath); sdsfree(base_filepath);
serverLog(LL_NOTICE, "Creating AOF base file %s on server start",
base_name);
} }
/* Because we will 'exit(1)' if open AOF or persistent manifest fails, so /* Because we will 'exit(1)' if open AOF or persistent manifest fails, so
...@@ -746,6 +747,12 @@ void aofOpenIfNeededOnServerStart(void) { ...@@ -746,6 +747,12 @@ void aofOpenIfNeededOnServerStart(void) {
} }
server.aof_last_incr_size = getAppendOnlyFileSize(aof_name, NULL); server.aof_last_incr_size = getAppendOnlyFileSize(aof_name, NULL);
if (incr_aof_len) {
serverLog(LL_NOTICE, "Opening AOF incr file %s on server start", aof_name);
} else {
serverLog(LL_NOTICE, "Creating AOF incr file %s on server start", aof_name);
}
} }
int aofFileExist(char *filename) { int aofFileExist(char *filename) {
...@@ -801,6 +808,9 @@ int openNewIncrAofForAppend(void) { ...@@ -801,6 +808,9 @@ int openNewIncrAofForAppend(void) {
goto cleanup; goto cleanup;
} }
} }
serverLog(LL_NOTICE, "Creating AOF incr file %s on background rewrite",
new_aof_name);
sdsfree(new_aof_name); sdsfree(new_aof_name);
/* If reaches here, we can safely modify the `server.aof_manifest` /* If reaches here, we can safely modify the `server.aof_manifest`
...@@ -2348,7 +2358,6 @@ int rewriteAppendOnlyFile(char *filename) { ...@@ -2348,7 +2358,6 @@ int rewriteAppendOnlyFile(char *filename) {
stopSaving(0); stopSaving(0);
return C_ERR; return C_ERR;
} }
serverLog(LL_NOTICE,"SYNC append only file rewrite performed");
stopSaving(1); stopSaving(1);
return C_OK; return C_OK;
...@@ -2403,6 +2412,8 @@ int rewriteAppendOnlyFileBackground(void) { ...@@ -2403,6 +2412,8 @@ int rewriteAppendOnlyFileBackground(void) {
redisSetCpuAffinity(server.aof_rewrite_cpulist); redisSetCpuAffinity(server.aof_rewrite_cpulist);
snprintf(tmpfile,256,"temp-rewriteaof-bg-%d.aof", (int) getpid()); snprintf(tmpfile,256,"temp-rewriteaof-bg-%d.aof", (int) getpid());
if (rewriteAppendOnlyFile(tmpfile) == C_OK) { if (rewriteAppendOnlyFile(tmpfile) == C_OK) {
serverLog(LL_NOTICE,
"Successfully created the temporary AOF base file %s", tmpfile);
sendChildCowInfo(CHILD_INFO_TYPE_AOF_COW_SIZE, "AOF rewrite"); sendChildCowInfo(CHILD_INFO_TYPE_AOF_COW_SIZE, "AOF rewrite");
exitFromChild(0); exitFromChild(0);
} else { } else {
...@@ -2543,7 +2554,7 @@ void backgroundRewriteDoneHandler(int exitcode, int bysignal) { ...@@ -2543,7 +2554,7 @@ void backgroundRewriteDoneHandler(int exitcode, int bysignal) {
latencyStartMonitor(latency); latencyStartMonitor(latency);
if (rename(tmpfile, new_base_filepath) == -1) { if (rename(tmpfile, new_base_filepath) == -1) {
serverLog(LL_WARNING, serverLog(LL_WARNING,
"Error trying to rename the temporary AOF file %s into %s: %s", "Error trying to rename the temporary AOF base file %s into %s: %s",
tmpfile, tmpfile,
new_base_filepath, new_base_filepath,
strerror(errno)); strerror(errno));
...@@ -2553,20 +2564,21 @@ void backgroundRewriteDoneHandler(int exitcode, int bysignal) { ...@@ -2553,20 +2564,21 @@ void backgroundRewriteDoneHandler(int exitcode, int bysignal) {
} }
latencyEndMonitor(latency); latencyEndMonitor(latency);
latencyAddSampleIfNeeded("aof-rename", latency); latencyAddSampleIfNeeded("aof-rename", latency);
serverLog(LL_NOTICE,
"Successfully renamed the temporary AOF base file %s into %s", tmpfile, new_base_filename);
/* Rename the temporary incr aof file to 'new_incr_filename'. */ /* Rename the temporary incr aof file to 'new_incr_filename'. */
if (server.aof_state == AOF_WAIT_REWRITE) { if (server.aof_state == AOF_WAIT_REWRITE) {
/* Get temporary incr aof name. */ /* Get temporary incr aof name. */
sds temp_incr_aof_name = getTempIncrAofName(); sds temp_incr_aof_name = getTempIncrAofName();
sds temp_incr_filepath = makePath(server.aof_dirname, temp_incr_aof_name); sds temp_incr_filepath = makePath(server.aof_dirname, temp_incr_aof_name);
sdsfree(temp_incr_aof_name);
/* Get next new incr aof name. */ /* Get next new incr aof name. */
sds new_incr_filename = getNewIncrAofName(temp_am); sds new_incr_filename = getNewIncrAofName(temp_am);
new_incr_filepath = makePath(server.aof_dirname, new_incr_filename); new_incr_filepath = makePath(server.aof_dirname, new_incr_filename);
latencyStartMonitor(latency); latencyStartMonitor(latency);
if (rename(temp_incr_filepath, new_incr_filepath) == -1) { if (rename(temp_incr_filepath, new_incr_filepath) == -1) {
serverLog(LL_WARNING, serverLog(LL_WARNING,
"Error trying to rename the temporary incr AOF file %s into %s: %s", "Error trying to rename the temporary AOF incr file %s into %s: %s",
temp_incr_filepath, temp_incr_filepath,
new_incr_filepath, new_incr_filepath,
strerror(errno)); strerror(errno));
...@@ -2575,11 +2587,15 @@ void backgroundRewriteDoneHandler(int exitcode, int bysignal) { ...@@ -2575,11 +2587,15 @@ void backgroundRewriteDoneHandler(int exitcode, int bysignal) {
aofManifestFree(temp_am); aofManifestFree(temp_am);
sdsfree(temp_incr_filepath); sdsfree(temp_incr_filepath);
sdsfree(new_incr_filepath); sdsfree(new_incr_filepath);
sdsfree(temp_incr_aof_name);
goto cleanup; goto cleanup;
} }
latencyEndMonitor(latency); latencyEndMonitor(latency);
latencyAddSampleIfNeeded("aof-rename", latency); latencyAddSampleIfNeeded("aof-rename", latency);
serverLog(LL_NOTICE,
"Successfully renamed the temporary AOF incr file %s into %s", temp_incr_aof_name, new_incr_filename);
sdsfree(temp_incr_filepath); sdsfree(temp_incr_filepath);
sdsfree(temp_incr_aof_name);
} }
/* Change the AOF file type in 'incr_aof_list' from AOF_FILE_TYPE_INCR /* Change the AOF file type in 'incr_aof_list' from AOF_FILE_TYPE_INCR
......
...@@ -6438,6 +6438,7 @@ void loadDataFromDisk(void) { ...@@ -6438,6 +6438,7 @@ void loadDataFromDisk(void) {
int ret = loadAppendOnlyFiles(server.aof_manifest); int ret = loadAppendOnlyFiles(server.aof_manifest);
if (ret == AOF_FAILED || ret == AOF_OPEN_ERR) if (ret == AOF_FAILED || ret == AOF_OPEN_ERR)
exit(1); exit(1);
serverLog(LL_NOTICE, "DB loaded from append only file: %.3f seconds", (float)(ustime()-start)/1000000);
} else { } else {
rdbSaveInfo rsi = RDB_SAVE_INFO_INIT; rdbSaveInfo rsi = RDB_SAVE_INFO_INIT;
errno = 0; /* Prevent a stale value from affecting error checking */ errno = 0; /* Prevent a stale value from affecting error checking */
......
Markdown is supported
0% or .
You are about to add 0 people to the discussion. Proceed with caution.
Finish editing this message first!
Please register or to comment