Subscription finalizer is blocking namespace deletion

[dsimansk]

Describe the bug The issue started to manifest itself in knative/client E2E tests running against nightly releases. The tests prepare namespace with labe to inject broker, create, update, delete triggers and finally teardown method deletes the testing namespace. However, the namespace is stuck in terminating state with subscription resources left there.

E2E tests log dump, look for kne2etests8.

Eventing controller log:

{"level":"error","ts":"2020-02-27T15:24:31.809Z","logger":"controller","caller":"controller/controller.go:409","msg":"Reconcile error","commit":"598d52a","error":"inmemorychannels.messaging.knative.dev \"default-kne-trigger\" not found","stacktrace":"knative.dev/eventing/vendor/knative.dev/pkg/controller.(*Impl).handleErr\n\tknative.dev/eventing/vendor/knative.dev/pkg/controller/controller.go:409\nknative.dev/eventing/vendor/knative.dev/pkg/controller.(*Impl).processNextWorkItem\n\tknative.dev/eventing/vendor/knative.dev/pkg/controller/controller.go:395\nknative.dev/eventing/vendor/knative.dev/pkg/controller.(*Impl).Run.func2\n\tknative.dev/eventing/vendor/knative.dev/pkg/controller/controller.go:343"}
{"level":"info","ts":"2020-02-27T15:24:31.809Z","logger":"controller","caller":"controller/controller.go:396","msg":"Reconcile failed. Time taken: 1.458989ms.","commit":"598d52a","knative.dev/traceid":"3ab0525c-3eac-43b8-a189-35d09d997ff6","knative.dev/key":"kne2etests0/default-trigger2-036a9c39-d106-42d3-8933-6dc824964bdd"}
{"level":"info","ts":"2020-02-27T15:24:31.810Z","logger":"controller.event-broadcaster","caller":"record/event.go:274","msg":"Event(v1.ObjectReference{Kind:\"Subscription\", Namespace:\"kne2etests0\", Name:\"default-trigger2-036a9c39-d106-42d3-8933-6dc824964bdd\", UID:\"a35c7ee0-916d-4a5d-8aa8-2a67d49448e6\", APIVersion:\"messaging.knative.dev/v1alpha1\", ResourceVersion:\"2316\", FieldPath:\"\"}): type: 'Warning' reason: 'InternalError' inmemorychannels.messaging.knative.dev \"default-kne-trigger\" not found","commit":"598d52a"}
{"level":"warn","ts":"2020-02-27T15:24:32.188Z","logger":"controller","caller":"subscription/subscription.go:329","msg":"GETTING channel","commit":"598d52a","knative.dev/traceid":"57e3c1df-f2b8-4f6c-908c-82f3c75e2756","knative.dev/key":"kne2etests0/default-updtrigger-47d25e74-3c12-4db9-8051-aa58b1e25c77","channel":{"kind":"InMemoryChannel","name":"default-kne-trigger","apiVersion":"messaging.knative.dev/v1alpha1"}}
{"level":"error","ts":"2020-02-27T15:24:32.188Z","logger":"controller","caller":"subscription/subscription.go:318","msg":"Error getting channel from lister","commit":"598d52a","knative.dev/traceid":"57e3c1df-f2b8-4f6c-908c-82f3c75e2756","knative.dev/key":"kne2etests0/default-updtrigger-47d25e74-3c12-4db9-8051-aa58b1e25c77","channel":{"kind":"InMemoryChannel","name":"default-kne-trigger","apiVersion":"messaging.knative.dev/v1alpha1"},"error":"inmemorychannels.messaging.knative.dev \"default-kne-trigger\" not found","stacktrace":"knative.dev/eventing/pkg/reconciler/subscription.(*Reconciler).trackAndFetchChannel\n\tknative.dev/eventing/pkg/reconciler/subscription/subscription.go:318\nknative.dev/eventing/pkg/reconciler/subscription.(*Reconciler).getChannel\n\tknative.dev/eventing/pkg/reconciler/subscription/subscription.go:332\nknative.dev/eventing/pkg/reconciler/subscription.(*Reconciler).FinalizeKind\n\tknative.dev/eventing/pkg/reconciler/subscription/subscription.go:124\nknative.dev/eventing/pkg/client/injection/reconciler/messaging/v1alpha1/subscription.(*reconcilerImpl).Reconcile\n\tknative.dev/eventing/pkg/client/injection/reconciler/messaging/v1alpha1/subscription/reconciler.go:163\nknative.dev/eventing/vendor/knative.dev/pkg/controller.(*Impl).processNextWorkItem\n\tknative.dev/eventing/vendor/knative.dev/pkg/controller/controller.go:394\nknative.dev/eventing/vendor/knative.dev/pkg/controller.(*Impl).Run.func2\n\tknative.dev/eventing/vendor/knative.dev/pkg/controller/controller.go:343"}
{"level":"error","ts":"2020-02-27T15:24:32.189Z","logger":"controller","caller":"subscription/reconciler.go:190","msg":"returned an error","commit":"598d52a","knative.dev/traceid":"57e3c1df-f2b8-4f6c-908c-82f3c75e2756","knative.dev/key":"kne2etests0/default-updtrigger-47d25e74-3c12-4db9-8051-aa58b1e25c77","targetMethod":"FinalizeKind","error":"inmemorychannels.messaging.knative.dev \"default-kne-trigger\" not found","stacktrace":"knative.dev/eventing/pkg/client/injection/reconciler/messaging/v1alpha1/subscription.(*reconcilerImpl).Reconcile\n\tknative.dev/eventing/pkg/client/injection/reconciler/messaging/v1alpha1/subscription/reconciler.go:190\nknative.dev/eventing/vendor/knative.dev/pkg/controller.(*Impl).processNextWorkItem\n\tknative.dev/eventing/vendor/knative.dev/pkg/controller/controller.go:394\nknative.dev/eventing/vendor/knative.dev/pkg/controller.(*Impl).Run.func2\n\tknative.dev/eventing/vendor/knative.dev/pkg/controller/controller.go:343"}
{"level":"error","ts":"2020-02-27T15:24:32.189Z","logger":"controller","caller":"controller/controller.go:409","msg":"Reconcile error","commit":"598d52a","error":"inmemorychannels.messaging.knative.dev \"default-kne-trigger\" not found","stacktrace":"knative.dev/eventing/vendor/knative.dev/pkg/controller.(*Impl).handleErr\n\tknative.dev/eventing/vendor/knative.dev/pkg/controller/controller.go:409\nknative.dev/eventing/vendor/knative.dev/pkg/controller.(*Impl).processNextWorkItem\n\tknative.dev/eventing/vendor/knative.dev/pkg/controller/controller.go:395\nknative.dev/eventing/vendor/knative.dev/pkg/controller.(*Impl).Run.func2\n\tknative.dev/eventing/vendor/knative.dev/pkg/controller/controller.go:343"}
{"level":"info","ts":"2020-02-27T15:24:32.189Z","logger":"controller","caller":"controller/controller.go:396","msg":"Reconcile failed. Time taken: 1.325887ms.","commit":"598d52a","knative.dev/traceid":"57e3c1df-f2b8-4f6c-908c-82f3c75e2756","knative.dev/key":"kne2etests0/default-updtrigger-47d25e74-3c12-4db9-8051-aa58b1e25c77"}
{"level":"info","ts":"2020-02-27T15:24:32.189Z","logger":"controller.event-broadcaster","caller":"record/event.go:274","msg":"Event(v1.ObjectReference{Kind:\"Subscription\", Namespace:\"kne2etests0\", Name:\"default-updtrigger-47d25e74-3c12-4db9-8051-aa58b1e25c77\", UID:\"d1b5385d-d35b-4710-aea6-01a945913e26\", APIVersion:\"messaging.knative.dev/v1alpha1\", ResourceVersion:\"2318\", FieldPath:\"\"}): type: 'Warning' reason: 'InternalError' inmemorychannels.messaging.knative.dev \"default-kne-trigger\" not found","commit":"598d52a"}
E0227 15:24:32.202346       1 event.go:256] Server rejected event '&v1.Event{TypeMeta:v1.TypeMeta{Kind:"", APIVersion:""}, ObjectMeta:v1.ObjectMeta{Name:"default-updtrigger-47d25e74-3c12-4db9-8051-aa58b1e25c77.15f74baaa586e853", GenerateName:"", Namespace:"kne2etests0", SelfLink:"", UID:"", ResourceVersion:"", Generation:0, CreationTimestamp:v1.Time{Time:time.Time{wall:0x0, ext:0, loc:(*time.Location)(nil)}}, DeletionTimestamp:(*v1.Time)(nil), DeletionGracePeriodSeconds:(*int64)(nil), Labels:map[string]string(nil), Annotations:map[string]string(nil), OwnerReferences:[]v1.OwnerReference(nil), Finalizers:[]string(nil), ClusterName:"", ManagedFields:[]v1.ManagedFieldsEntry(nil)}, InvolvedObject:v1.ObjectReference{Kind:"Subscription", Namespace:"kne2etests0", Name:"default-updtrigger-47d25e74-3c12-4db9-8051-aa58b1e25c77", UID:"d1b5385d-d35b-4710-aea6-01a945913e26", APIVersion:"messaging.knative.dev/v1alpha1", ResourceVersion:"2318", FieldPath:""}, Reason:"InternalError", Message:"inmemorychannels.messaging.knative.dev \"default-kne-trigger\" not found", Source:v1.EventSource{Component:"subscription-controller", Host:""}, FirstTimestamp:v1.Time{Time:time.Time{wall:0xbf8e1597941fbc53, ext:315505918496, loc:(*time.Location)(0x2d6dbc0)}}, LastTimestamp:v1.Time{Time:time.Time{wall:0xbf8e15ac0b46cc6f, ext:397357483743, loc:(*time.Location)(0x2d6dbc0)}}, Count:15, Type:"Warning", EventTime:v1.MicroTime{Time:time.Time{wall:0x0, ext:0, loc:(*time.Location)(nil)}}, Series:(*v1.EventSeries)(nil), Action:"", Related:(*v1.ObjectReference)(nil), ReportingController:"", ReportingInstance:""}': 'events "default-updtrigger-47d25e74-3c12-4db9-8051-aa58b1e25c77.15f74baaa586e853" is forbidden: unable to create new content in namespace kne2etests0 because it is being terminated' (will not retry!)

The exact steps test is going through: https://github.com/knative/client/blob/master/test/e2e/trigger_test.go#L30

Expected behavior When namespace is deleted, all belonging resources are successfully deleted.

To Reproduce

1. Minikube with latest nightly preinstalled
2. Clone https://github.com/knative/client
3. Execute ./test/e2e-tests-local.sh -run ^TestBrokerTrigger$

4. Look for namespace kne2etests0 in terminating state

   Knative release version Eventing nightly - v20200227-598d52ae

[dsimansk]

I managed to reproduce the behaviour with plain yamls also:

1. Minikube with latest nightly preinstalled
2. Apply following cmds

   
   kubectl create ns test
   kubectl label namespace test knative-eventing-injection=enabled
   kubens test

--> wait a bit for broker pods to start

kubectl apply -f https://raw.githubusercontent.com/matzew/knative-eventing-samples/master/03-source_broker/000-ksvc2.yaml kubectl apply -f https://raw.githubusercontent.com/matzew/knative-eventing-samples/master/03-source_broker/030-trigger2.yaml

kubectl delete ns test --> delete op won't finish

3. Check `kubectl get all` that there's only `sub` resource left ([whole yaml](https://gist.github.com/dsimansk/cdab1faac0a580886b9da4e7061b7b1e))

NAME READY REASON AGE subscription.messaging.knative.dev/default-testevents-trigger-6a42b605-6e45-4b56-a08e-47ea08f0d55e Unknown ChannelReferenceFailed 40m

4. `kubectl get ns` will display test ns in `Terminating` state
5. After removing the finalizer the stuck subscription is removed and subsequently the namespace also

kubectl patch subscription.messaging.knative.dev/default-testevents-trigger-6a42b605-6e45-4b56-a08e-47ea08f0d55e -p '{"metadata":{"finalizers": []}}' --type=merge

I wonder if that might be related to apiVersion disprepancy from [recent change](https://github.com/knative/eventing/pull/2595), that seems similar to [the following issue](https://github.com/knative/eventing/issues/2464). Or a more generic problem related to switch to generated reconciler for subscription.

[lionelvillard]

Thanks! It seems to me it's a duplicate of https://github.com/knative/eventing/issues/2633.

[dsimansk]

Subscriptions cannot be deleted when its associated channel is deleted first. The finalizer is not removed.

Indeed this issue is just another manifestation of the above problem.

@lionelvillard thanks for pointing that out and sorry I should have used search first. :)

/close duplicate

[matzew]

/close

[knative-prow-robot]

@matzew: Closing this issue.

In response to [this](https://github.com/knative/eventing/issues/2668#issuecomment-592544289): >/close Instructions for interacting with me using PR comments are available [here](https://git.k8s.io/community/contributors/guide/pull-requests.md). If you have questions or suggestions related to my behavior, please file an issue against the [kubernetes/test-infra](https://github.com/kubernetes/test-infra/issues/new?title=Prow%20issue:) repository.

[AceHack]

How do you work around this issue?

[matzew]

no work ariund, but this is a dup

see comments above.

On Fri 28. Feb 2020 at 20:21, Aaron Stainback notifications@github.com wrote:

How do you work around this issue?

— You are receiving this because you were mentioned.

Reply to this email directly, view it on GitHub https://github.com/knative/eventing/issues/2668?email_source=notifications&email_token=AABGPTQZODYGCJ3MIK4E34LRFFP4FA5CNFSM4K45REVKYY3PNVWWK3TUL52HS4DFVREXG43VMVBW63LNMVXHJKTDN5WW2ZLOORPWSZGOENJ2SWY#issuecomment-592685403, or unsubscribe https://github.com/notifications/unsubscribe-auth/AABGPTTFLRY77M44ZG3EINDRFFP4FANCNFSM4K45REVA .

-- Sent from Gmail Mobile

[dsimansk]

@AceHack The most straightforward workaround is to remove finalizer, e.g.:

kubectl patch <stale-subscription-name> -p '{"metadata":{"finalizers": []}}' --type=merge  

[nachocano]

@AceHack The most straightforward workaround is to remove finalizer, e.g.:

kubectl patch <stale-subscription-name> -p '{"metadata":{"finalizers": []}}' --type=merge  

This was fixed last friday here: https://github.com/knative/eventing/pull/2676. Pull latest master and it should work