porch: background refresh of unregistered repo

Original issue URL: https://github.com/kptdev/kpt/issues/3883 Original issue user: https://github.com/johnbelamaric Original issue created at: 2023-03-14T18:15:00Z Original issue last updated at: 2023-03-16T20:47:03Z Original issue body: ### Expected behavior Unregistered repos should no longer be background refreshed.

Actual behavior

I noticed this in the log just now:

I0314 18:08:47.281345       1 repository.go:354] background-refreshing repo "git://https://github.com/johnbelamaric/nephio-testorg-deploy.git"
I0314 18:08:50.772099       1 background.go:113] Background task 2023-03-14 18:08:50.772047627 +0000 UTC m=+88984.305949069
I0314 18:08:50.772167       1 background.go:147] background-refreshing repositories
I0314 18:08:51.468568       1 repository.go:354] background-refreshing repo "git://https://github.com/nephio-test/jbelamaric-us-central1-edge-02.git"
I0314 18:08:52.174401       1 repository.go:354] background-refreshing repo "git://https://github.com/nephio-test/jbelamaric-us-central1-edge-03.git"
I0314 18:08:52.376724       1 package_tree.go:182] found package "cachingdns-edge/Kptfile" with Kptfile hash "e1fdebda2b0cb5238ca3f78034c87d9cd31e14b4"
W0314 18:08:52.377180       1 repository.go:486] over-notifying of package updates (even on unchanged packages)
I0314 18:08:52.379704       1 watch.go:238] sending watch event {MODIFIED 0xc001cb7a40}

However, that repo (nephio-testorg-deploy) was unregistered yesterday:

jbelamaric@jbelamaric:~/proj/tmp/cachingdns-topology$ k get repositories
NAME                      TYPE   CONTENT   DEPLOYMENT   READY   ADDRESS
nephio-packages           git    Package                True    https://github.com/nephio-project/nephio-packages.git
nephio-testorg-packages   git    Package                True    https://github.com/johnbelamaric/nephio-testorg-packages.git
us-central1-edge-01       git    Package   true         True    https://github.com/nephio-test/jbelamaric-us-central1-edge-01.git
us-central1-edge-02       git    Package   true         True    https://github.com/nephio-test/jbelamaric-us-central1-edge-02.git
us-central1-edge-03       git    Package   true         True    https://github.com/nephio-test/jbelamaric-us-central1-edge-03.git
us-central1-edge-04       git    Package   true         True    https://github.com/nephio-test/jbelamaric-us-central1-edge-04.git
us-central1-regional      git    Package   true         True    https://github.com/nephio-test/jbelamaric-us-central1-regional.git
us-central2-regional      git    Package   true         True    https://github.com/nephio-test/jbelamaric-us-central2-regional.git
us-east1-edge-01          git    Package   true         True    https://github.com/nephio-test/jbelamaric-us-east1-edge-01.git
us-east1-edge-02          git    Package   true         True    https://github.com/nephio-test/jbelamaric-us-east1-edge-02.git
us-east1-regional-01      git    Package   true         True    https://github.com/nephio-test/jbelamaric-us-east1-regional-01.git
us-east1-regional-02      git    Package   true         True    https://github.com/nephio-test/jbelamaric-us-east1-regional-02.git
us-east2-regional         git    Package   true         True    https://github.com/nephio-test/jbelamaric-us-east2-regional.git

Information

Porch v0.0.15 porch-server.log

Steps to reproduce the behavior

I suspect just register then unregister a repo, not sure though.

Original issue comments: Comment user: https://github.com/natasha41575 Comment created at: 2023-03-16T16:23:21Z Comment last updated at: 2023-03-16T16:29:24Z Comment body: > I suspect just register then unregister a repo, not sure though.

🤔 I'm not able to reproduce the issue with just registration and unregistration (running porch locally). I see the repository get removed from both the cluster and the internal cache, and the following background refresh no longer includes the unregistered repo.

There isn't anything that stands out to me in your log file, do you know if you did anything else with this repo? Maybe register and unregister it multiple times? Are you running the controller locally or in a cluster?

Comment user: https://github.com/johnbelamaric Comment created at: 2023-03-16T18:16:43Z Comment last updated at: 2023-03-16T18:16:43Z Comment body: Running in a cluster. This is the repo that had errors creating packages with #3870. Other than that it's normal.

Comment user: https://github.com/natasha41575 Comment created at: 2023-03-16T20:47:03Z Comment last updated at: 2023-03-16T20:47:03Z Comment body: Thanks. I'll try reproducing your setup with https://github.com/johnbelamaric/nephio-testorg-deploy/blob/main/repos.sh and see if I can find anything.

I0620 12:51:50.154458       1 background.go:134] Repository added: porch-demo:test2
I0620 12:51:50.505661       1 repository.go:363] repo git://http://172.18.255.200:3000/nephio/test2.git//@porch-demo/test2: poll started
I0620 12:51:50.650421       1 background.go:137] Repository modified: porch-demo:test2
I0620 12:51:51.085419       1 git.go:1718] discovered 0 packages @29dff563ccdb530c635d6653ab45b08138129f26
I0620 12:51:51.085491       1 repository.go:527] repo git://http://172.18.255.200:3000/nephio/test2.git//@porch-demo/test2: addSent 0, modSent 0, delSent for 0 old and 0 new repo packages
I0620 12:51:51.085508       1 repository.go:396] repo git://http://172.18.255.200:3000/nephio/test2.git//@porch-demo/test2: refresh finished in 0.411299 secs
I0620 12:51:51.085531       1 repository.go:364] repo git://http://172.18.255.200:3000/nephio/test2.git//@porch-demo/test2: poll finished in 0.579910 secs
I0620 12:51:51.085545       1 repository.go:363] repo git://http://172.18.255.200:3000/nephio/test2.git//@porch-demo/test2: poll started
I0620 12:51:51.338966       1 repository.go:396] repo git://http://172.18.255.200:3000/nephio/test2.git//@porch-demo/test2: refresh finished in 0.091690 secs
I0620 12:52:03.988582       1 background.go:104] Bookmark: "111817"172.18.255.200:3000/nephio/test2.git//@porch-demo/test2: poll finished in 0.253479 secs
I0620 12:52:05.007959       1 background.go:104] Bookmark: "111817"
E0620 12:52:06.679362       1 background.go:94] Watch event stream closed. Will restart watch from bookmark "111817"
I0620 12:52:07.680279       1 background.go:76] Starting watch ...
I0620 12:52:07.683424       1 background.go:88] Watch successfully started.
I0620 12:52:17.791011       1 background.go:115] Background task 2024-06-20 12:52:17.790911454 +0000 UTC m=+82683.303838516
I0620 12:52:17.791099       1 background.go:153] background-refreshing repositories
I0620 12:52:21.426084       1 repository.go:363] repo git://http://172.18.255.200:3000/nephio/test1.git//@porch-demo/test1: poll started
I0620 12:52:21.754015       1 repository.go:396] repo git://http://172.18.255.200:3000/nephio/test1.git//@porch-demo/test1: refresh finished in 0.157613 secs
I0620 12:52:21.754066       1 repository.go:364] repo git://http://172.18.255.200:3000/nephio/test1.git//@porch-demo/test1: poll finished in 0.328016 secs
I0620 12:52:32.459053       1 repository.go:363] repo git://http://172.18.255.200:3000/nephio/test.git//@porch-demo/test: poll started
I0620 12:52:32.789957       1 repository.go:396] repo git://http://172.18.255.200:3000/nephio/test.git//@porch-demo/test: refresh finished in 0.167842 secs
I0620 12:52:32.790023       1 repository.go:364] repo git://http://172.18.255.200:3000/nephio/test.git//@porch-demo/test: poll finished in 0.331003 secs
I0620 12:52:51.339484       1 repository.go:363] repo git://http://172.18.255.200:3000/nephio/test2.git//@porch-demo/test2: poll started
I0620 12:52:51.670905       1 repository.go:396] repo git://http://172.18.255.200:3000/nephio/test2.git//@porch-demo/test2: refresh finished in 0.172232 secs
I0620 12:52:51.670967       1 repository.go:364] repo git://http://172.18.255.200:3000/nephio/test2.git//@porch-demo/test2: poll finished in 0.331509 secs
I0620 12:53:02.820773       1 background.go:140] Repository deleted: porch-demo:test2
I0620 12:53:02.827455       1 repository.go:342] repo git://http://172.18.255.200:3000/nephio/test2.git//@porch-demo/test2: sent 0 notifications for 0 package revisions during close
I0620 12:53:07.781327       1 background.go:104] Bookmark: "111895"
I0620 12:53:17.790123       1 background.go:115] Background task 2024-06-20 12:53:17.790055403 +0000 UTC m=+82743.302982489
I0620 12:53:17.790202       1 background.go:153] background-refreshing repositories
I0620 12:53:21.754924       1 repository.go:363] repo git://http://172.18.255.200:3000/nephio/test1.git//@porch-demo/test1: poll started
I0620 12:53:22.094236       1 repository.go:396] repo git://http://172.18.255.200:3000/nephio/test1.git//@porch-demo/test1: refresh finished in 0.168653 secs
I0620 12:53:22.094300       1 repository.go:364] repo git://http://172.18.255.200:3000/nephio/test1.git//@porch-demo/test1: poll finished in 0.339410 secs
I0620 12:53:32.791137       1 repository.go:363] repo git://http://172.18.255.200:3000/nephio/test.git//@porch-demo/test: poll started
I0620 12:53:33.124922       1 repository.go:396] repo git://http://172.18.255.200:3000/nephio/test.git//@porch-demo/test: refresh finished in 0.162516 secs
I0620 12:53:33.124987       1 repository.go:364] repo git://http://172.18.255.200:3000/nephio/test.git//@porch-demo/test: poll finished in 0.333889 secs
I0620 12:54:07.285474       1 background.go:104] Bookmark: "111974"
I0620 12:54:17.790349       1 background.go:115] Background task 2024-06-20 12:54:17.79027756 +0000 UTC m=+82803.303204632
I0620 12:54:17.790598       1 background.go:153] background-refreshing repositories
I0620 12:54:22.095384       1 repository.go:363] repo git://http://172.18.255.200:3000/nephio/test1.git//@porch-demo/test1: poll started
I0620 12:54:22.396855       1 repository.go:396] repo git://http://172.18.255.200:3000/nephio/test1.git//@porch-demo/test1: refresh finished in 0.142898 secs
I0620 12:54:22.396939       1 repository.go:364] repo git://http://172.18.255.200:3000/nephio/test1.git//@porch-demo/test1: poll finished in 0.301592 secs
I0620 12:54:33.125571       1 repository.go:363] repo git://http://172.18.255.200:3000/nephio/test.git//@porch-demo/test: poll started
I0620 12:54:33.466116       1 repository.go:396] repo git://http://172.18.255.200:3000/nephio/test.git//@porch-demo/test: refresh finished in 0.169932 secs
I0620 12:54:33.466180       1 repository.go:364] repo git://http://172.18.255.200:3000/nephio/test.git//@porch-demo/test: poll finished in 0.340638 secs
I0620 12:55:07.709620       1 background.go:104] Bookmark: "112051"

I cannot reproduce the issue anymore. A repo named test2 was created, the background refresh started for it but as soon as test2 repo was deleted, the server noticed it and background refresh for it stopped.

nephio-project / nephio