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.

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(upgrade): add sleep to allow event to flush before panic #3234

Merged
merged 1 commit into from
Oct 30, 2024

Conversation

james-munson
Copy link
Contributor

Which issue(s) this PR fixes:

Issue longhorn/longhorn#9569

What this PR does / why we need it:

Add a sleep after Run() before panicking to let the queued event get flushed. We thought that eventBroadcaster.Shutdown() would take care of that, and it did in some testing, but there is still a race and it does not work reliably. QA found that while testing the feature and I did reproduce it - see the note in longhorn/longhorn#9569 (comment)

Special notes for your reviewer:

This is the simplest fix. We could do something more complicated, like calling Watch() on the events and waiting for it to appear, but there is no need to speed up the exit as soon as possible. The upgrade will not go forward anyway. The important thing is to guarantee the event can be found so the problem can be corrected.

Additional documentation or context

Copy link

coderabbitai bot commented Oct 24, 2024

Walkthrough

The changes in this pull request involve modifications to the postUpgrade and preUpgrade functions within the app/post_upgrade.go and app/pre_upgrade.go files, respectively. In both functions, a five-second delay (time.Sleep(5 * time.Second)) has been introduced in the shutdown logic of the eventBroadcaster. This adjustment alters the timing of the shutdown process, ensuring a pause before the functions exit, while the overall structure and logic of the functions remain unchanged.

Changes

File Change Summary
app/post_upgrade.go Modified postUpgrade to include a 5-second delay after eventBroadcaster.Shutdown().
app/pre_upgrade.go Modified preUpgrade to include a 5-second delay after eventBroadcaster.Shutdown().

Assessment against linked issues

Objective Addressed Explanation
Pre-upgrade pod should event the reason for any failures. (#9569) The changes do not address event recording for failures.

Possibly related PRs

Suggested reviewers

  • c3y1huang
  • shuo-wu
  • PhanLe1010

📜 Recent review details

Configuration used: .coderabbit.yaml
Review profile: CHILL

📥 Commits

Files that changed from the base of the PR and between 6675802 and 0c21cf5.

📒 Files selected for processing (2)
  • app/post_upgrade.go (1 hunks)
  • app/pre_upgrade.go (2 hunks)
🚧 Files skipped from review as they are similar to previous changes (2)
  • app/post_upgrade.go
  • app/pre_upgrade.go

Thank you for using CodeRabbit. We offer it for free to the OSS community and would appreciate your support in helping us grow. If you find it useful, would you consider giving us a shout-out on your favorite social media?

❤️ Share
🪧 Tips

Chat

There are 3 ways to chat with CodeRabbit:

  • Review comments: Directly reply to a review comment made by CodeRabbit. Example:
    • I pushed a fix in commit <commit_id>, please review it.
    • Generate unit testing code for this file.
    • Open a follow-up GitHub issue for this discussion.
  • Files and specific lines of code (under the "Files changed" tab): Tag @coderabbitai in a new review comment at the desired location with your query. Examples:
    • @coderabbitai generate unit testing code for this file.
    • @coderabbitai modularize this function.
  • PR comments: Tag @coderabbitai in a new PR comment to ask questions about the PR branch. For the best results, please provide a very specific query, as very limited context is provided in this mode. Examples:
    • @coderabbitai gather interesting stats about this repository and render them as a table. Additionally, render a pie chart showing the language distribution in the codebase.
    • @coderabbitai read src/utils.ts and generate unit testing code.
    • @coderabbitai read the files in the src/scheduler package and generate a class diagram using mermaid and a README in the markdown format.
    • @coderabbitai help me debug CodeRabbit configuration file.

Note: Be mindful of the bot's finite context window. It's strongly recommended to break down tasks such as reading entire modules into smaller chunks. For a focused discussion, use review comments to chat about specific files and their changes, instead of using the PR comments.

CodeRabbit Commands (Invoked using PR comments)

  • @coderabbitai pause to pause the reviews on a PR.
  • @coderabbitai resume to resume the paused reviews.
  • @coderabbitai review to trigger an incremental review. This is useful when automatic reviews are disabled for the repository.
  • @coderabbitai full review to do a full review from scratch and review all the files again.
  • @coderabbitai summary to regenerate the summary of the PR.
  • @coderabbitai resolve resolve all the CodeRabbit review comments.
  • @coderabbitai configuration to show the current CodeRabbit configuration for the repository.
  • @coderabbitai help to get help.

Other keywords and placeholders

  • Add @coderabbitai ignore anywhere in the PR description to prevent this PR from being reviewed.
  • Add @coderabbitai summary to generate the high-level summary at a specific location in the PR description.
  • Add @coderabbitai anywhere in the PR title to generate the title automatically.

Documentation and Community

  • Visit our Documentation for detailed information on how to use CodeRabbit.
  • Join our Discord Community to get help, request features, and share feedback.
  • Follow us on X/Twitter for updates and announcements.

@james-munson james-munson requested review from derekbit, PhanLe1010 and a team October 24, 2024 03:42
Copy link

@coderabbitai coderabbitai bot left a comment

Choose a reason for hiding this comment

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

Actionable comments posted: 2

🧹 Outside diff range and nitpick comments (3)
app/pre_upgrade.go (1)

82-85: Consider restructuring event handling for better reliability.

The current implementation might still miss events due to the order of operations. The sleep occurs after Run()'s deferred event recording but before the broadcaster shutdown.

Consider this more robust approach:

 func preUpgrade(c *cli.Context) error {
     // ... existing code ...
-    defer eventBroadcaster.Shutdown()
     
     err = newPreUpgrader(namespace, lhClient, eventRecorder).Run()
     if err != nil {
         logrus.Warnf("Done with Run() ... err is %v", err)
-        time.Sleep(5 * time.Minute)
+        // Ensure event is recorded and flushed
+        time.Sleep(preUpgradeEventFlushDelay)
     }
+    
+    // Gracefully shutdown the broadcaster after all events are flushed
+    eventBroadcaster.Shutdown()
     
     return err
 }

Additionally, consider implementing a more deterministic approach:

  1. Add an event queue depth check
  2. Implement a proper wait mechanism with timeout
  3. Add metrics for event broadcasting failures

Would you like me to provide a more detailed implementation of these suggestions?

app/post_upgrade.go (2)

89-92: Log the specific error details before sleep.

The current implementation only logs that Run() is done with an error. For better debugging, consider adding more context about the failure.

-logrus.Warnf("Done with Run() ... err is %v", err)
+logrus.Errorf("Post-upgrade checks failed: %v. Waiting for events to be flushed...", err)
 time.Sleep(5 * time.Minute)

Line range hint 41-67: Consider improving error handling in the CLI command.

The current implementation logs the error and exits, but we could provide more user-friendly error messages and potentially different exit codes for different failure scenarios.

 Action: func(c *cli.Context) {
     logrus.Info("Running post-upgrade...")
-    defer logrus.Info("Completed post-upgrade.")
+    defer func() {
+        if r := recover(); r != nil {
+            logrus.Errorf("Post-upgrade panic: %v", r)
+            // Ensure we exit with error code
+            cli.Exit("Post-upgrade failed with panic", 2)
+        }
+    }()
+    
     if err := postUpgrade(c); err != nil {
-        logrus.Fatalf("Error during post-upgrade: %v", err)
+        // Use structured error message
+        logrus.WithError(err).Error("Post-upgrade failed")
+        cli.Exit("Post-upgrade failed. Check logs for details.", 1)
     }
+    logrus.Info("Completed post-upgrade successfully")
 },
📜 Review details

Configuration used: .coderabbit.yaml
Review profile: CHILL

📥 Commits

Files that changed from the base of the PR and between e7db6e7 and 26e7138.

📒 Files selected for processing (2)
  • app/post_upgrade.go (1 hunks)
  • app/pre_upgrade.go (2 hunks)
🔇 Additional comments (3)
app/pre_upgrade.go (2)

4-5: LGTM: Import addition is appropriate.

The time import is correctly placed and necessary for the new sleep functionality.


82-85: Verify consistent error handling across upgrade components.

Let's ensure this pattern is consistently applied across all upgrade-related components.

✅ Verification successful

Based on the results, I can now generate the final response as we have sufficient information about the error handling patterns across upgrade components.

Error handling is consistent across upgrade components

The verification shows that:

  • Both preUpgrader and postUpgrader implement consistent error handling patterns in their Run() methods
  • Event broadcasting and shutdown are handled similarly in both components
  • Event recording for upgrade checks follows a consistent pattern with proper event reasons defined in constants
🏁 Scripts executed

The following scripts were executed for the analysis:

Script:

#!/bin/bash
# Search for similar error handling patterns in upgrade-related files
echo "Checking error handling patterns in upgrade-related files..."
rg -A 5 "func.*[Uu]pgrade.*Run\(\)" 

echo "Checking event broadcasting patterns..."
rg -A 5 "eventBroadcaster.Shutdown\(\)"

echo "Checking related event recording..."
rg "EventReasonFailedUpgradePreCheck|EventReasonPassedUpgradeCheck"

Length of output: 2340

app/post_upgrade.go (1)

Line range hint 52-58: Ensure proper cleanup of resources.

The eventBroadcaster shutdown is deferred, but we should ensure it has enough time to process events before the program exits.

Let's verify the event broadcaster implementation:

app/pre_upgrade.go Outdated Show resolved Hide resolved
app/post_upgrade.go Outdated Show resolved Hide resolved
@james-munson james-munson force-pushed the 9569-add-sleep branch 2 times, most recently from d1b2d32 to a1ade09 Compare October 25, 2024 00:55
PhanLe1010
PhanLe1010 previously approved these changes Oct 25, 2024
Copy link
Contributor

@PhanLe1010 PhanLe1010 left a comment

Choose a reason for hiding this comment

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

LGTM

It seems that we need both eventBroadcaster.Shutdown() and sleep:

  • eventBroadcaster.Shutdown() will trigger event flushing
  • Sleep will wait for the event to hit API server

Other considered alternative is creating the event directly using kubeclient. But looks like using eventBroadcaster will be more consistent with other part of the code

@derekbit
Copy link
Member

derekbit commented Oct 25, 2024

I'm fine with the sleep method.

Another idea for reference is combining EventSinkImpl with WaitGroup and make the flush period not fixed. Not sure if this can work :p

func createEventBroadcasterWithConfirmation(config *rest.Config) (record.EventBroadcaster, *ConfirmingEventSink, error) {
    kubeClient, err := kubernetes.NewForConfig(config)
    if err != nil {
        return nil, nil, err
    }

    eventBroadcaster := record.NewBroadcaster()

    standardSink := &typedv1core.EventSinkImpl{
        Interface: kubeClient.CoreV1().Events(""),
    }
    confirmingSink := NewConfirmingEventSink(standardSink)
    
    eventBroadcaster.StartRecordingToSink(confirmingSink)
    
    return eventBroadcaster, confirmingSink, nil
}

type ConfirmingEventSink struct {
    sink EventSink
    wg   sync.WaitGroup
}

func NewConfirmingEventSink(sink EventSink) *ConfirmingEventSink {
    return &ConfirmingEventSink{
        sink: sink,
    }
}

func (s *ConfirmingEventSink) Create(event *v1.Event) (*v1.Event, error) {
    s.wg.Add(1)
    defer s.wg.Done()
    return s.sink.Create(event)
}

func (s *ConfirmingEventSink) Update(event *v1.Event) (*v1.Event, error) {
...
}

func (s *ConfirmingEventSink) Patch(oldEvent *v1.Event, data []byte) (*v1.Event, error) {
...
}

func (s *ConfirmingEventSink) WaitForComplete(timeout time.Duration) bool {
    c := make(chan struct{})
    go func() {
        defer close(c)
        s.wg.Wait()
    }()
    
    select {
    case <-c:
        return true
    case <-time.After(timeout):
        return false
    }
}

Then, after eventBroadcaster.Shudown()

    defer func() {
        eventBroadcaster.Shutdown()
        if !confirmingSink.WaitForComplete(10 * time.Second) {
            logrus.Warn("Timeout waiting for events to be processed")
        }
    }()

@james-munson
Copy link
Contributor Author

james-munson commented Oct 25, 2024

Ok, let's go with the simple sleep, then, and keep this in our back pocket in case problems still show up in testing. Thanks!
If approved, I'll backport to 1.6 and 1.7.

defer eventBroadcaster.Shutdown()
defer func() {
eventBroadcaster.Shutdown()
time.Sleep(5 * time.Second)
Copy link
Member

Choose a reason for hiding this comment

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

I remember you used a big number before. How do you determine the sleep period?

Copy link
Contributor Author

Choose a reason for hiding this comment

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

The long period was to allow a shot at gathering logs before the pod exited. But as @PhanLe1010 points out, that could get in the way of another run, and if the event is in place, the logs are not as important. This is a reasonable guess at a time that should allow the event to be flushed, but get the result back to the job quickly.

Copy link
Member

@derekbit derekbit Oct 26, 2024

Choose a reason for hiding this comment

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

@james-munson Isee.
Ah, no, I mean leave a comment above time.Sleep(5 * time.Second). Thank you.

…fore panic

Signed-off-by: James Munson <james.munson@suse.com>
@derekbit derekbit merged commit 235b1ae into longhorn:master Oct 30, 2024
9 checks passed
@derekbit
Copy link
Member

@mergify backport v1.7.x v1.6.x

Copy link

mergify bot commented Oct 30, 2024

backport v1.7.x v1.6.x

✅ Backports have been created

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

3 participants