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

Add more logs for queue operations #122

Merged
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Jump to
Jump to file
Failed to load files.
Diff view
Diff view
Expand Up @@ -218,6 +218,7 @@ func (c *ClusterQuotaReconcilationController) Sync(discoveryFunc resourcequota.N
if c.quotaMonitor != nil && !cache.WaitForCacheSync(ctx.Done(), func() bool { return c.quotaMonitor.IsSynced(context.TODO()) }) {
utilruntime.HandleError(fmt.Errorf("timed out waiting for quota monitor sync"))
}
klog.V(2).Infof("synced cluster resource quota controller")
}, period, ctx.Done())
}

Expand Down
7 changes: 7 additions & 0 deletions pkg/quota/clusterquotareconciliation/workqueuebucket.go
Expand Up @@ -4,6 +4,7 @@ import (
"sync"

"k8s.io/client-go/util/workqueue"
"k8s.io/klog/v2"
)

// BucketingWorkQueue gives a way to add items related to a single entry in a work queue
Expand Down Expand Up @@ -46,6 +47,7 @@ func (e *workQueueBucket) AddWithData(key interface{}, data ...interface{}) {
// this Add can trigger a Get BEFORE the work is added to a list, but this is ok because the getWork routine
// waits the worklock before retrieving the work to do, so the writes in this method will be observed
e.queue.Add(key)
klog.V(2).Infof("key %s is added with data into queue", key)

if e.inProgress[key] {
e.dirtyWork[key] = append(e.dirtyWork[key], data...)
Expand All @@ -62,6 +64,7 @@ func (e *workQueueBucket) AddWithDataRateLimited(key interface{}, data ...interf
// this Add can trigger a Get BEFORE the work is added to a list, but this is ok because the getWork routine
// waits the worklock before retrieving the work to do, so the writes in this method will be observed
e.queue.AddRateLimited(key)
klog.V(2).Infof("key %s is added rate limited with data into queue", key)

if e.inProgress[key] {
e.dirtyWork[key] = append(e.dirtyWork[key], data...)
Expand All @@ -76,6 +79,8 @@ func (e *workQueueBucket) Done(key interface{}) {
defer e.workLock.Unlock()

e.queue.Done(key)
klog.V(2).Infof("key %s in the queue is marked as done", key)

e.work[key] = e.dirtyWork[key]
delete(e.dirtyWork, key)
delete(e.inProgress, key)
Expand All @@ -91,12 +96,14 @@ func (e *workQueueBucket) GetWithData() (interface{}, []interface{}, bool) {
return nil, []interface{}{}, shutdown
}

klog.V(2).Infof("key %s is gotten from queue", key)
Copy link
Member

Choose a reason for hiding this comment

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

please add the print after the lock to preserve a raciness, if there is one

Copy link
Member Author

Choose a reason for hiding this comment

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

I'll use this one to prove that item is obtained from queue and to ensure that the raciness, I've added klog.V(2).Infof("lock acquired and key % is added in progress list", key)

Copy link
Member

Choose a reason for hiding this comment

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

ack, let's see what we get with this

e.workLock.Lock()
defer e.workLock.Unlock()
// at this point, we know we have a coherent view of e.work. It is entirely possible
// that our workqueue has another item requeued to it, but we'll pick it up early. This ok
// because the next time will go into our dirty list

klog.V(2).Infof("lock acquired and key %s is added in progress list", key)
work := e.work[key]
delete(e.work, key)
delete(e.dirtyWork, key)
Expand Down