After deleting a tag in Portus "NoMethodError (undefined method `handle_delete_event'" is logged every second

[AndreasUfert]

Hi,

given a Portus system based on the opensuse/portus image from Docker Hub (contains portus-2.1.0~dev+git050d095b08875306923663c8a1f9dfd9798bd0fb-5.1.x86_64).

After deleting a tag in Portus, Portus is called once per second on URI /v2/webhooks/events but this POST fails with NoMethodError (undefined methodhandle_delete_event'` (see log excerpt):

portus-web      | App 164 stdout: Started DELETE "/tags/46" for 10.180.43.80 at 2016-07-08 12:47:08 +0000
portus-web      | App 164 stdout: Processing by TagsController#destroy as HTML
portus-web      | App 164 stdout:   Parameters: {"authenticity_token"=>"XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX==", "id"=>"46"}
portus-registry | time="2016-07-08T12:47:09Z" level=warning msg="error authorizing context: authorization token required" go.version=go1.6.2 http.request.host=registry.mydomain http.request.id=ea50165f-2cf6-441e-8423-69713869349c http.request.method=DELETE http.request.remoteaddr=172.17.0.1 http.request.uri="/v2/unix/alpine/manifests/sha256:4fa633f4feff6a8f02acfc7424efd5cb3e76686ed3218abf4ca0fa4a2a358423" http.request.useragent=Ruby instance.id=dfa163fd-9e1f-4a1a-bc33-211d46f635cc vars.name="unix/alpine" vars.reference="sha256:4fa633f4feff6a8f02acfc7424efd5cb3e76686ed3218abf4ca0fa4a2a358423" version=v2.5.0-rc.1
portus-registry | 172.17.0.4 - - [08/Jul/2016:12:47:09 +0000] "DELETE /v2/unix/alpine/manifests/sha256:4fa633f4feff6a8f02acfc7424efd5cb3e76686ed3218abf4ca0fa4a2a358423 HTTP/1.1" 401 140 "" "Ruby"
portus-web      | 172.17.0.1 - - [08/Jul/2016:12:47:08 +0000] "DELETE /v2/unix/alpine/manifests/sha256:4fa633f4feff6a8f02acfc7424efd5cb3e76686ed3218abf4ca0fa4a2a358423 HTTP/1.1" 401 140 "-" "Ruby"
portus-web      | App 171 stdout: Started GET "/v2/token?account=portus&scope=repository%3Aunix%2Falpine%3A%2A&service=registry.mydomain" for 172.17.0.4 at 2016-07-08 12:47:09 +0000
portus-web      | App 171 stdout: Processing by Api::V2::TokensController#show as JSON
portus-web      | App 171 stdout:   Parameters: {"account"=>"portus", "scope"=>"repository:unix/alpine:*", "service"=>"registry.mydomain"}
portus-web      | App 171 stdout: Completed 200 OK in 225ms (Views: 0.5ms | ActiveRecord: 20.9ms)
portus-web      | 172.17.0.4 - - [08/Jul/2016:12:47:09 +0000] "GET /v2/token?account=portus&scope=repository%3Aunix%2Falpine%3A%2A&service=registry.mydomain HTTP/1.1" 200 896 "-" "Ruby"
portus-registry | time="2016-07-08T12:47:09Z" level=info msg="response completed" go.version=go1.6.2 http.request.host=registry.mydomain http.request.id=fc331657-b1cb-4585-8194-9fa53bb18253 http.request.method=DELETE http.request.remoteaddr=172.17.0.1 http.request.uri="/v2/unix/alpine/manifests/sha256:4fa633f4feff6a8f02acfc7424efd5cb3e76686ed3218abf4ca0fa4a2a358423" http.request.useragent=Ruby http.response.duration=5.69212ms http.response.status=202 http.response.written=0 instance.id=dfa163fd-9e1f-4a1a-bc33-211d46f635cc version=v2.5.0-rc.1
portus-registry | 172.17.0.4 - - [08/Jul/2016:12:47:09 +0000] "DELETE /v2/unix/alpine/manifests/sha256:4fa633f4feff6a8f02acfc7424efd5cb3e76686ed3218abf4ca0fa4a2a358423 HTTP/1.1" 202 0 "" "Ruby"
portus-web      | 172.17.0.1 - - [08/Jul/2016:12:47:09 +0000] "DELETE /v2/unix/alpine/manifests/sha256:4fa633f4feff6a8f02acfc7424efd5cb3e76686ed3218abf4ca0fa4a2a358423 HTTP/1.1" 202 - "-" "Ruby"
portus-web      | App 164 stdout: [catalog] Removed the tag '3.3'.
portus-web      | App 171 stdout: Started POST "/v2/webhooks/events" for 172.17.0.1 at 2016-07-08 12:47:09 +0000
portus-web      | App 171 stdout: Processing by Api::V2::EventsController#create as JSON
portus-web      | App 171 stdout: Handling 'delete' event:
portus-web      | App 171 stdout: {
portus-web      | App 171 stdout:   "id": "b3a06bfa-4423-44a9-8e04-b9ee62d5fb0c",
portus-web      | App 171 stdout:   "timestamp": "2016-07-08T12:47:09.330564835Z",
portus-web      | App 171 stdout:   "action": "delete",
portus-web      | App 171 stdout:   "target": {
portus-web      | App 171 stdout:     "digest": "sha256:4fa633f4feff6a8f02acfc7424efd5cb3e76686ed3218abf4ca0fa4a2a358423",
portus-web      | App 171 stdout:     "repository": "unix/alpine"
portus-web      | App 171 stdout:   },
portus-web      | App 171 stdout:   "request": {
portus-web      | App 171 stdout:     "id": "fc331657-b1cb-4585-8194-9fa53bb18253",
portus-web      | App 171 stdout:     "addr": "172.17.0.1",
portus-web      | App 171 stdout:     "host": "registry.mydomain",
portus-web      | App 171 stdout:     "method": "DELETE",
portus-web      | App 171 stdout:     "useragent": "Ruby"
portus-web      | App 171 stdout:   },
portus-web      | App 171 stdout:   "actor": {
portus-web      | App 171 stdout:     "name": "portus"
portus-web      | App 171 stdout:   },
portus-web      | App 171 stdout:   "source": {
portus-web      | App 171 stdout:     "addr": "3e03705b06d5:5000",
portus-web      | App 171 stdout:     "instanceID": "dfa163fd-9e1f-4a1a-bc33-211d46f635cc"
portus-web      | App 171 stdout:   }
portus-web      | App 171 stdout: }
portus-web      | App 164 stdout: Redirected to https://portus.mydomain/repositories/6
portus-web      | App 164 stdout: Completed 302 Found in 453ms (ActiveRecord: 43.0ms)
portus-web      | 10.180.43.80 - - [08/Jul/2016:12:47:08 +0000] "POST /tags/46 HTTP/1.1" 302 121 "https://portus.mydomain/repositories/6" "Mozilla/5.0 (Windows NT 6.1; Win64; x64; rv:47.0) Gecko/20100101 Firefox/47.0"
portus-web      | App 171 stdout: Completed 500 Internal Server Error in 31ms (ActiveRecord: 4.9ms)
portus-web      | App 171 stdout:
portus-web      | App 171 stdout: NoMethodError (undefined method `handle_delete_event' for #<Class:0x00000003e10b10>):
portus-web      | App 171 stdout:   lib/portus/registry_notification.rb:21:in `block (2 levels) in process!'
portus-web      | App 171 stdout:   lib/portus/registry_notification.rb:21:in `each'
portus-web      | App 171 stdout:   lib/portus/registry_notification.rb:21:in `block in process!'
portus-web      | App 171 stdout:   lib/portus/registry_notification.rb:13:in `each'
portus-web      | App 171 stdout:   lib/portus/registry_notification.rb:13:in `process!'
portus-web      | App 171 stdout:   app/controllers/api/v2/events_controller.rb:6:in `create'
portus-web      | App 171 stdout:
portus-web      | App 171 stdout:
portus-web      | 172.17.0.1 - - [08/Jul/2016:12:47:09 +0000] "POST /v2/webhooks/events HTTP/1.1" 500 - "-" "Go-http-client/1.1"
portus-registry | time="2016-07-08T12:47:09Z" level=error msg="retryingsink: error writing events: httpSink{https://portus.mydomain/v2/webhooks/events}: response status 500 Internal Server Error unaccepted, retrying"
portus-web      | App 164 stdout: Started GET "/repositories/6" for 10.180.43.80 at 2016-07-08 12:47:09 +0000
portus-web      | App 164 stdout: Processing by RepositoriesController#show as HTML
portus-web      | App 164 stdout:   Parameters: {"id"=>"6"}
portus-web      | App 171 stdout: Started POST "/v2/webhooks/events" for 172.17.0.1 at 2016-07-08 12:47:09 +0000
portus-web      | App 171 stdout: Processing by Api::V2::EventsController#create as JSON
portus-web      | App 171 stdout: Handling 'delete' event:
portus-web      | App 171 stdout: {
portus-web      | App 171 stdout:   "id": "b3a06bfa-4423-44a9-8e04-b9ee62d5fb0c",
portus-web      | App 171 stdout:   "timestamp": "2016-07-08T12:47:09.330564835Z",
portus-web      | App 171 stdout:   "action": "delete",
portus-web      | App 171 stdout:   "target": {
portus-web      | App 171 stdout:     "digest": "sha256:4fa633f4feff6a8f02acfc7424efd5cb3e76686ed3218abf4ca0fa4a2a358423",
portus-web      | App 171 stdout:     "repository": "unix/alpine"
portus-web      | App 171 stdout:   },
portus-web      | App 171 stdout:   "request": {
portus-web      | App 171 stdout:     "id": "fc331657-b1cb-4585-8194-9fa53bb18253",
portus-web      | App 171 stdout:     "addr": "172.17.0.1",
portus-web      | App 171 stdout:     "host": "registry.mydomain",
portus-web      | App 171 stdout:     "method": "DELETE",
portus-web      | App 171 stdout:     "useragent": "Ruby"
portus-web      | App 171 stdout:   },
portus-web      | App 171 stdout:   "actor": {
portus-web      | App 171 stdout:     "name": "portus"
portus-web      | App 171 stdout:   },
portus-web      | App 171 stdout:   "source": {
portus-web      | App 171 stdout:     "addr": "3e03705b06d5:5000",
portus-web      | App 171 stdout:     "instanceID": "dfa163fd-9e1f-4a1a-bc33-211d46f635cc"
portus-web      | App 171 stdout:   }
portus-web      | App 171 stdout: }
portus-web      | App 171 stdout: Completed 500 Internal Server Error in 7ms (ActiveRecord: 1.4ms)
portus-web      | App 171 stdout:
portus-web      | App 171 stdout: NoMethodError (undefined method `handle_delete_event' for #<Class:0x00000003e10b10>):
portus-web      | App 171 stdout:   lib/portus/registry_notification.rb:21:in `block (2 levels) in process!'
portus-web      | App 171 stdout:   lib/portus/registry_notification.rb:21:in `each'
portus-web      | App 171 stdout:   lib/portus/registry_notification.rb:21:in `block in process!'
portus-web      | App 171 stdout:   lib/portus/registry_notification.rb:13:in `each'
portus-web      | App 171 stdout:   lib/portus/registry_notification.rb:13:in `process!'
portus-web      | App 171 stdout:   app/controllers/api/v2/events_controller.rb:6:in `create'
portus-web      | App 171 stdout:
portus-web      | App 171 stdout:

[mssola]

This has already been fixed in #959. Do you have the latest version ? (the docker image is an automatic build, so from time to time it gets updated).

[AndreasUfert]

You're right. After pulling the latest version this morning this issue doesn't appear anymore.