-
Notifications
You must be signed in to change notification settings - Fork 0
Add simple logging with timestamps to identify high-traffic scheduled tasks #109
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.
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
Conversation
Co-authored-by: HNygard <168380+HNygard@users.noreply.github.com>
Co-authored-by: HNygard <168380+HNygard@users.noreply.github.com>
Co-authored-by: HNygard <168380+HNygard@users.noreply.github.com>
Co-authored-by: HNygard <168380+HNygard@users.noreply.github.com>
… method Co-authored-by: HNygard <168380+HNygard@users.noreply.github.com>
|
@copilot This is way overkill. Just log response time and number of different imap actions on scheduled tasks. Log to PHP error log (outputs to docker strerr) |
Co-authored-by: HNygard <168380+HNygard@users.noreply.github.com>
Simplified the implementation in commit d0b6784. Now using error_log() to log response times and action counts for each scheduled task. The IMAP handling task also logs individual action durations (createFolders, processSentFolder, processInbox). All database infrastructure, UI, and tests removed. |
|
|
||
| $startTime = microtime(true); | ||
| $taskName = 'scheduled-email-extraction-' . $extractionType; | ||
| error_log("[$taskName] Starting task"); |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
@copilot : Timestamp the error_log() calls.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Added timestamps in commit 61d5fab. All error_log() calls now include date('Y-m-d H:i:s') prefix.
Co-authored-by: HNygard <168380+HNygard@users.noreply.github.com>
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
This is the final PR Bugbot will review for you during this billing cycle
Your free Bugbot reviews will reset on January 27
Details
You are on the Bugbot Free tier. On this plan, Bugbot will review limited PRs each billing cycle.
To receive Bugbot reviews on all of your PRs, visit the Cursor dashboard to activate Pro and start your 14-day free trial.
| $result = $emailReceiver->processNextFolder(); | ||
| $results[] = $result; | ||
| if ($result['success']) { | ||
| $foldersProcessed++; |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Folder count underreports by one due to uncounted call
The $foldersProcessed counter is initialized to 0 and only incremented inside the loop (lines 28-45), but processNextFolder() is also called at line 24 before the loop starts. This means the logged folder count will always be off by one — the timing includes all processed folders but the count misses the first one. Since the PR's goal is to identify high-bandwidth tasks, this inaccurate count could mislead debugging efforts.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
@copilot : Fix comment
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Pull request overview
This PR adds simple timestamp-based logging to all scheduled tasks in the organizer system to identify which task is consuming excessive bandwidth. The logging outputs to PHP's error_log (Docker stderr) and tracks task duration and action counts for each scheduled task.
Key Changes:
- Added start/end logging with timestamps in
Y-m-d H:i:sformat to all 5 scheduled tasks - Implemented duration tracking using
microtime(true)for precise timing measurements - Added detailed IMAP operation timing for the
scheduled-imap-handlingtask to identify which specific operation (createFolders, processSentFolder, or processInbox) consumes the most time
Reviewed changes
Copilot reviewed 5 out of 5 changed files in this pull request and generated 2 comments.
Show a summary per file
| File | Description |
|---|---|
| scheduled-thread-follow-up.php | Added start/end logging with task duration and success/failure status tracking |
| scheduled-imap-handling.php | Added task-level logging plus individual timing for three IMAP operations (createFolders, processSentFolder, processInbox) |
| scheduled-email-sending.php | Added start/end logging with task duration and success/failure status tracking |
| scheduled-email-receiver.php | Added start/end logging with folder processing counter to track how many folders were successfully processed |
| scheduled-email-extraction.php | Added start/end logging with extraction counter and invalid extraction type error logging |
💡 Add Copilot custom instructions for smarter, more guided reviews. Learn how to get started.
Co-authored-by: Copilot <175728472+Copilot@users.noreply.github.com>
|
|
||
| $duration = round(microtime(true) - $startTime, 3); | ||
| $status = $result['success'] ? 'completed' : 'failed'; | ||
| error_log(date('Y-m-d H:i:s') . " [$taskName] Task $status in {$duration}s - " . ($result['message'] ?? 'no message')); |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Normal idle state incorrectly logged as task failure
The $status variable is set to 'failed' whenever $result['success'] is false, but the underlying classes return success => false with "No threads ready for sending/follow-up" when there's simply nothing to process—a normal idle condition, not an error. The existing code correctly treats this as non-error (skipping admin notification), but the new logging will generate "Task failed" entries during routine operation. This will pollute logs with false failure messages, making it harder to identify actual problems when debugging bandwidth issues.
One of the scheduled tasks is consuming excessive bandwidth, likely downloading gigabytes of email data. Need instrumentation to identify which task.
Changes
Simplified Logging Approach
Y-m-d H:i:sformatTask Integration
All 5 scheduled tasks now log timing and action counts with timestamps:
IMAP Action Details
For
scheduled-imap-handling, individual IMAP action durations are logged with timestamps:createFoldersexecution timeprocessSentFolderexecution timeprocessInboxexecution timeThis helps identify which specific IMAP operation is consuming the most time/bandwidth.
Usage
View Docker logs to identify which task takes the longest time, indicating high bandwidth usage:
Example output:
Original prompt
✨ Let Copilot coding agent set things up for you — coding agent works faster and does higher quality work when set up for your repo.
Note
Adds lightweight instrumentation to scheduled tasks to identify high-bandwidth operations.
error_logstart/complete/fail messages with execution duration acrossscheduled-email-receiver,scheduled-email-sending,scheduled-thread-follow-up,scheduled-email-extraction, andscheduled-imap-handlingscheduled-imap-handlingforcreateFolders,processSentFolder, andprocessInboxWritten by Cursor Bugbot for commit cb5a93c. This will update automatically on new commits. Configure here.