Expired credentials

[glebteterin]

We're having issues with receiving messages from the queue. First two hours it runs, it works fine. 2 hour later we consistently get the error: link detached, reason: *Error{Condition: amqp:link:detach-forced, Description: Unauthorized access. 'Listen' claim(s) are required to perform this operation. Resource: 'sb://x.servicebus.windows.net/test-timeout'., Info: map[]}

Environment

• OS: Docker alpine, macos high sierra 10.13.6
• Go version: 1.10.3
• Version of Library: v0.4.0 (ca4ff1d)
• Dependency management: dep

func main() {
	q, err := NewQueueClient()
	if err != nil {
		panic(err)
	}

	handler := &Handler{}

	for {
		ctx, _ := context.WithDeadline(context.Background(), time.Now().Add(10*time.Minute))
		err := q.ReceiveOne(ctx, handler)
		if err != nil {
			log.Println(err)
		}
	}
}

type Handler struct {
}

func (h *Handler) Handle(ctx context.Context, msg *servicebus.Message) error {
	log.Println("MESSAGE RECEIVED", msg.ID)
	err := msg.Complete(context.Background())
	if err != nil {
		log.Println(err)
	}
	return nil
}

[devigned]

First off, this shouldn't happen. Upon an error in a link, the link, session and connection will be rebuilt. During the rebuild a new token should be generated, either through via SAS (signed request via access policy key) or Azure Active Directory.

Since you are not using go modules, can you tell me what the versions of vcabbage/amqp and azure-amqp-common-go are being used? I'm hoping that dep would pull all the correct versions, but it's been a while since I've used it.

Any chance you could turn on tracing with OpenTracing? The library is instrumented, and should provide a view of operations that are leading to the error. Also, you can run your app with DEBUG_LEVEL=3 with -tags debug enabled to see low-level AMQP logging to STDOUT.

With the above information, we should be able to narrow down what's going on.

[glebteterin]

Hoping for a quick fix, I created a new test project with go 1.12 and modules and the same code, unfortunately the issue persists.

module github.com/g-rad/mod-queue

go 1.12

require (
	github.com/Azure/azure-service-bus-go v0.4.0
	github.com/pkg/errors v0.8.1
)

will provide OpenTracing and logs tomorrow.

[glebteterin]

Hi @devigned

First call of ReceiveOne:

then since I have 10 minutes timeout there were 13 identical spans, the 14th (last) looks like this:

sb.namespace.negotiateClaim was called only once during the first call of ReceiveOne

The first call of ReceiveOne was at 18:51:52
The last call of ReceiveOne was at 21:01:52 and was blocked for only 4.25 seconds before returned the error:
link detached, reason: *Error{Condition: amqp:link:detach-forced, Description: Unauthorized access. 'Listen' claim(s) are required to perform this operation. Resource: 'sb://x.servicebus.windows.net/test-timeout'., Info: map[]}

Is there anything else I can provide?

[glebteterin]

All right, so queue.ReceiveOne() does not recover connection as queue.Receive() does.

The reason I was using queue.ReceiveOne() instead of queue.Receive() is I'm having different type of issues with queue.Receive()

[devigned]

ReceiveOne should also recover. Marking as the bug it is.

[jakebjorkekato]

We have started to see this bug on service bus topic subscriptions as well.

[devigned]

I'll give this some attention this week.

[joseph-norman]

Any updates on this? Just found this after having received this for some time with service bus topic/subscription setup also. Can provide context if needed.

[devigned]

Sorry... just getting back from vacation.

I wanted to get a fix out before I left, but ran out of time. I'm working on it now.

[devigned]

Anyone watching this thread want to give the expired-creds branch a test. I believe this should renegotiate credentials on live clients so that they never expire.

I'll be running some endurance tests to verify, but would appreciate others' experiences. Thank you!

[devigned]

I'm going to close this issue since the cred refresh has been merged. If you still find this is an issue, please reopen.

[jakebjorkekato]

We were able to get around to testing this fix this week.

That seemed to resolve the issue and is working well. Thanks.

[devigned]

Thank you, @jakebjorkekato.

@gavinfish is doing some endurance / performance testing to stabilize the library before committing to a 1.0 release. This work should expose and correct issues like this.

If you run into any other odd issues related to long running processes / connections, please don't hesitate in opening an issue.