Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

fix: Reduce the stalled logging for snapshot #625

Merged
merged 2 commits into from
Jun 25, 2024
Merged

fix: Reduce the stalled logging for snapshot #625

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
2 commits
Select commit Hold shift + click to select a range
5cb5df7
refactor: Reuse the oper instead of initializing new variable
sebinsunny Jun 25, 2024
e1ac0bb
fix: Reduce the stalled logging for snapshot
sebinsunny Jun 25, 2024
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
12 changes: 1 addition & 11 deletions pghoard/basebackup/delta.py
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -49,7 +49,6 @@ class HasReadAndSeek(HasRead, HasSeek, Protocol):
FilesChunk = Set[Tuple]
SnapshotFiles = Dict[str, SnapshotFile]
PROGRESS_CHECK_INTERVAL = 10
STALLED_PROGRESS_THRESHOLD = 600

EMPTY_FILE_HASH = hashlib.blake2s().hexdigest()

Expand Down Expand Up @@ -88,25 +87,16 @@ def progress_callback(progress_step: ProgressStep, progress_data: ProgressMetric
persisted_progress = PersistedProgress.read(self.metrics)
progress_info = persisted_progress.get(key)
tags: dict = {"phase": progress_step.value}
self.last_flush_time = time.monotonic()

if progress_data["handled"] > progress_info.current_progress:
progress_info.update(progress_data["handled"])
persisted_progress.write(self.metrics)
self.last_flush_time = time.monotonic()
self.metrics.gauge("pghoard.seconds_since_backup_progress_stalled", 0, tags=tags)
self.log.info(
"Updated snapshot progress for %s to %d files; elapsed time since last check: %.2f seconds.",
Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

It confuses operators, and because it doesn't log frequently, we might think it is stuck. Because of progress_data["handled"] value

progress_step.value, progress_data["handled"], elapsed
)
else:
stalled_age = progress_info.age
self.metrics.gauge("pghoard.seconds_since_backup_progress_stalled", stalled_age, tags=tags)

if stalled_age >= STALLED_PROGRESS_THRESHOLD:
self.log.warning(
"Snapshot progress for %s has been stalled for %s seconds.", progress_step, stalled_age
)

self.last_flush_time = time.monotonic()
snapshotter.snapshot(reuse_old_snapshotfiles=False, progress_callback=progress_callback)
snapshot_result = SnapshotResult(end=None, state=None, hashes=None)
Expand Down
3 changes: 1 addition & 2 deletions pghoard/transfer.py
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -412,9 +412,8 @@ def run_safe(self):
if file_to_transfer.callback_queue:
file_to_transfer.callback_queue.put(result)

operation_type = file_to_transfer.operation
status = "FAILED" if not result.success else "successfully"
log_msg = f"{operation_type.capitalize()} of key: {key}, " \
log_msg = f"{oper.capitalize()} of key: {key}, " \
Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Reused oper and already contained the necessary info

f"size: {oper_size}, {status} in {time.monotonic() - start_time:.3f}s"
self.log.info(log_msg)

Expand Down
Loading