|
| 1 | +# Logging Audit: lib/backup.sh |
| 2 | + |
| 3 | +## Summary |
| 4 | +- Total issues found: 10 |
| 5 | +- HIGH priority: 3 |
| 6 | +- MEDIUM priority: 3 |
| 7 | +- LOW priority: 4 |
| 8 | + |
| 9 | +## Architecture Note |
| 10 | + |
| 11 | +The codebase uses a dual-output system: |
| 12 | +- `print_*` functions (from `lib/core.sh`): User-facing colored console output |
| 13 | +- `log_*` functions (from `lib/logging.sh`): Structured file logging with stack traces |
| 14 | + |
| 15 | +**Finding**: `lib/backup.sh` uses `print_error`, `print_warning`, `print_info`, `print_success` for user-facing output, but these do NOT call `log_*` functions. This means errors are displayed to users but NOT recorded in the log file. |
| 16 | + |
| 17 | +--- |
| 18 | + |
| 19 | +## Issues |
| 20 | + |
| 21 | +### Issue 1: print_error does not log to file |
| 22 | +- **Line:** 18, 40, 52, 64, 72, 128, 153, 177 |
| 23 | +- **Priority:** HIGH |
| 24 | +- **Description:** `print_error` only outputs to stderr with color formatting. Errors are not recorded in the log file for debugging. |
| 25 | +- **Current:** |
| 26 | +```bash |
| 27 | +print_error "System not configured. Please run setup first." |
| 28 | +``` |
| 29 | +- **Fix:** |
| 30 | +```bash |
| 31 | +log_error "System not configured. Please run setup first." |
| 32 | +print_error "System not configured. Please run setup first." |
| 33 | +``` |
| 34 | + |
| 35 | +--- |
| 36 | + |
| 37 | +### Issue 2: print_warning does not log to file |
| 38 | +- **Line:** 100, 187 |
| 39 | +- **Priority:** MEDIUM |
| 40 | +- **Description:** `print_warning` only outputs to console. Warnings are not recorded in the log file. |
| 41 | +- **Current:** |
| 42 | +```bash |
| 43 | +print_warning "No retention policy configured (automatic cleanup disabled)" |
| 44 | +``` |
| 45 | +- **Fix:** |
| 46 | +```bash |
| 47 | +log_warn "No retention policy configured (automatic cleanup disabled)" |
| 48 | +print_warning "No retention policy configured (automatic cleanup disabled)" |
| 49 | +``` |
| 50 | + |
| 51 | +--- |
| 52 | + |
| 53 | +### Issue 3: print_info does not log to file |
| 54 | +- **Line:** 35, 47, 59, 68 |
| 55 | +- **Priority:** LOW |
| 56 | +- **Description:** `print_info` only outputs to console. Info messages are not recorded in the log file. |
| 57 | +- **Current:** |
| 58 | +```bash |
| 59 | +print_info "Starting database backup..." |
| 60 | +``` |
| 61 | +- **Fix:** |
| 62 | +```bash |
| 63 | +log_info "Starting database backup..." |
| 64 | +print_info "Starting database backup..." |
| 65 | +``` |
| 66 | + |
| 67 | +--- |
| 68 | + |
| 69 | +### Issue 4: print_success does not log to file |
| 70 | +- **Line:** 189 |
| 71 | +- **Priority:** LOW |
| 72 | +- **Description:** `print_success` only outputs to console. Success messages are not recorded in the log file. |
| 73 | +- **Current:** |
| 74 | +```bash |
| 75 | +print_success "Cleanup complete. Removed $cleanup_count old backup(s)." |
| 76 | +``` |
| 77 | +- **Fix:** |
| 78 | +```bash |
| 79 | +log_info "Cleanup complete. Removed $cleanup_count old backup(s)." |
| 80 | +print_success "Cleanup complete. Removed $cleanup_count old backup(s)." |
| 81 | +``` |
| 82 | + |
| 83 | +--- |
| 84 | + |
| 85 | +### Issue 5: Plain echo for status messages |
| 86 | +- **Lines:** 13-14, 23-27, 34, 57, 60, 62, 91-92, 101-102, 107-109, 114, 133-134, 139, 146, 163, 170, 185 |
| 87 | +- **Priority:** LOW |
| 88 | +- **Description:** Many plain `echo` statements are used for UI display. While appropriate for interactive menus, critical status messages (like "Cancelled" on line 114) should be logged. |
| 89 | +- **Current:** |
| 90 | +```bash |
| 91 | +echo "Cancelled." |
| 92 | +``` |
| 93 | +- **Fix:** |
| 94 | +```bash |
| 95 | +log_debug "Cleanup cancelled by user" |
| 96 | +echo "Cancelled." |
| 97 | +``` |
| 98 | + |
| 99 | +--- |
| 100 | + |
| 101 | +### Issue 6: Cleanup deletion errors not fully logged |
| 102 | +- **Line:** 153, 177 |
| 103 | +- **Priority:** HIGH |
| 104 | +- **Description:** When `rclone delete` fails, the error is only shown via `print_error` and not logged. This makes debugging remote storage issues difficult. |
| 105 | +- **Current:** |
| 106 | +```bash |
| 107 | +print_error " Failed to delete $remote_file: $delete_output" |
| 108 | +((cleanup_errors++)) || true |
| 109 | +``` |
| 110 | +- **Fix:** |
| 111 | +```bash |
| 112 | +log_error "Failed to delete remote file: $remote_file - Output: $delete_output" |
| 113 | +print_error " Failed to delete $remote_file: $delete_output" |
| 114 | +((cleanup_errors++)) || true |
| 115 | +``` |
| 116 | + |
| 117 | +--- |
| 118 | + |
| 119 | +### Issue 7: Cutoff time calculation failure not logged |
| 120 | +- **Line:** 127-131 |
| 121 | +- **Priority:** HIGH |
| 122 | +- **Description:** If cutoff time calculation fails, the error is only shown to user via `print_error`, not logged for debugging. |
| 123 | +- **Current:** |
| 124 | +```bash |
| 125 | +if [[ "$cutoff_time" -eq 0 ]]; then |
| 126 | + print_error "Could not calculate cutoff time" |
| 127 | + press_enter_to_continue |
| 128 | + return |
| 129 | +fi |
| 130 | +``` |
| 131 | +- **Fix:** |
| 132 | +```bash |
| 133 | +if [[ "$cutoff_time" -eq 0 ]]; then |
| 134 | + log_error "Could not calculate cutoff time for retention_minutes=$retention_minutes" |
| 135 | + print_error "Could not calculate cutoff time" |
| 136 | + press_enter_to_continue |
| 137 | + return |
| 138 | +fi |
| 139 | +``` |
| 140 | + |
| 141 | +--- |
| 142 | + |
| 143 | +### Issue 8: Missing log_func_exit calls |
| 144 | +- **Lines:** 9 (run_backup), 87 (run_cleanup_now) |
| 145 | +- **Priority:** MEDIUM |
| 146 | +- **Description:** Functions call `log_func_enter` but do not call `log_func_exit` at return points. This breaks function timing and stack trace accuracy in TRACE mode. |
| 147 | +- **Current:** |
| 148 | +```bash |
| 149 | +run_backup() { |
| 150 | + log_func_enter |
| 151 | + debug_enter "run_backup" |
| 152 | + # ... function body with multiple return statements |
| 153 | +} |
| 154 | +``` |
| 155 | +- **Fix:** |
| 156 | +```bash |
| 157 | +run_backup() { |
| 158 | + log_func_enter |
| 159 | + debug_enter "run_backup" |
| 160 | + # Use log_func_trap instead of log_func_enter for auto-exit logging |
| 161 | + # OR add log_func_exit before each return statement |
| 162 | +} |
| 163 | +``` |
| 164 | + |
| 165 | +--- |
| 166 | + |
| 167 | +### Issue 9: Backup script execution not logged |
| 168 | +- **Lines:** 37, 49, 61, 70 |
| 169 | +- **Priority:** MEDIUM |
| 170 | +- **Description:** When backup scripts are executed via `bash "$SCRIPTS_DIR/db_backup.sh"`, there is no log entry indicating which script was run or its outcome. |
| 171 | +- **Current:** |
| 172 | +```bash |
| 173 | +bash "$SCRIPTS_DIR/db_backup.sh" |
| 174 | +``` |
| 175 | +- **Fix:** |
| 176 | +```bash |
| 177 | +log_info "Executing database backup script: $SCRIPTS_DIR/db_backup.sh" |
| 178 | +bash "$SCRIPTS_DIR/db_backup.sh" |
| 179 | +local exit_code=$? |
| 180 | +log_info "Database backup script completed with exit code: $exit_code" |
| 181 | +``` |
| 182 | + |
| 183 | +--- |
| 184 | + |
| 185 | +### Issue 10: Cleanup operations not logged |
| 186 | +- **Lines:** 146, 170 |
| 187 | +- **Priority:** LOW |
| 188 | +- **Description:** Successful file deletions during cleanup are echoed to console but not logged. |
| 189 | +- **Current:** |
| 190 | +```bash |
| 191 | +echo " Deleting: $remote_file ($(date -d "@$file_epoch" +"%Y-%m-%d %H:%M" 2>/dev/null))" |
| 192 | +``` |
| 193 | +- **Fix:** |
| 194 | +```bash |
| 195 | +log_debug "Deleting old backup: $remote_file (file_epoch=$file_epoch, cutoff=$cutoff_time)" |
| 196 | +echo " Deleting: $remote_file ($(date -d "@$file_epoch" +"%Y-%m-%d %H:%M" 2>/dev/null))" |
| 197 | +``` |
| 198 | + |
| 199 | +--- |
| 200 | + |
| 201 | +## Recommendation |
| 202 | + |
| 203 | +Consider creating wrapper functions that handle both console output and logging: |
| 204 | + |
| 205 | +```bash |
| 206 | +# Example helper function |
| 207 | +print_and_log_error() { |
| 208 | + local msg="$1" |
| 209 | + log_error "$msg" |
| 210 | + print_error "$msg" |
| 211 | +} |
| 212 | + |
| 213 | +print_and_log_warn() { |
| 214 | + local msg="$1" |
| 215 | + log_warn "$msg" |
| 216 | + print_warning "$msg" |
| 217 | +} |
| 218 | + |
| 219 | +print_and_log_info() { |
| 220 | + local msg="$1" |
| 221 | + log_info "$msg" |
| 222 | + print_info "$msg" |
| 223 | +} |
| 224 | +``` |
| 225 | + |
| 226 | +This would reduce code duplication and ensure all user-visible messages are also logged for debugging purposes. |
| 227 | + |
| 228 | +--- |
| 229 | + |
| 230 | +## Detailed Line Reference |
| 231 | + |
| 232 | +| Line | Current Function | Issue | Priority | |
| 233 | +|------|-----------------|-------|----------| |
| 234 | +| 18 | print_error | Not logged | HIGH | |
| 235 | +| 35 | print_info | Not logged | LOW | |
| 236 | +| 40 | print_error | Not logged | HIGH | |
| 237 | +| 47 | print_info | Not logged | LOW | |
| 238 | +| 52 | print_error | Not logged | HIGH | |
| 239 | +| 59 | print_info | Not logged | LOW | |
| 240 | +| 64 | print_error | Not logged | HIGH | |
| 241 | +| 68 | print_info | Not logged | LOW | |
| 242 | +| 72 | print_error | Not logged | HIGH | |
| 243 | +| 100 | print_warning | Not logged | MEDIUM | |
| 244 | +| 128 | print_error | Not logged | HIGH | |
| 245 | +| 153 | print_error | Not logged | HIGH | |
| 246 | +| 177 | print_error | Not logged | HIGH | |
| 247 | +| 187 | print_warning | Not logged | MEDIUM | |
| 248 | +| 189 | print_success | Not logged | LOW | |
| 249 | + |
| 250 | +--- |
| 251 | + |
| 252 | +*Audit completed: 2026-01-05* |
0 commit comments