PreSync hooks failing due to missing namespace even though CreateNamespace=true is set

[elemental-lf]

Checklist:

• I've searched in the docs and FAQ for my answer: https://bit.ly/argocd-faq.
• I've included steps to reproduce the bug.
• I've pasted the output of argocd version.

Describe the bug

I've observed that PreSync hooks are failing if the namespace doesn't exist even though CreateNamespace=true is set. In the case described below synchronization of the application fails in a PreSync hook with an error message of namespaces "beta" not found.

If I create the namespace in question the execution of the hooks proceeds.

This bug is actually in https://github.com/argoproj/gitops-engine/ but I wasn't sure if I should open the issue here or there.

To Reproduce

I'm trying to install a Helm chart which includes some resources with the helm.sh/hook: pre-install,pre-upgrade annotation set:

---
apiVersion: v1
kind: Secret
metadata:
  name: beta-api
  labels:
    {{ include "beta.labels" . | nindent 4 }}
    tier: backend
  annotations:
    "helm.sh/hook": pre-install,pre-upgrade
    "helm.sh/hook-weight": "-10"
    "helm.sh/hook-delete-policy": before-hook-creation
type: Opaque
data:
[...]

The namespace doesn't exist but the application has CreateNamespace=true set and some other synchronization options set:

  destination:
    namespace: beta
    name: <redacted>
  syncPolicy:
    automated:
      selfHeal: true
      prune: true
    retry:
      backoff:
        duration: 5s
        factor: 2
        maxDuration: 60s
        limit: 1000000
    syncOptions:
      - "CreateNamespace=true"

Expected behavior

ArgoCD should create the namespace before running PreSync hooks.

Version

argocd: v1.7.7+33c93ae
  BuildDate: 2020-09-29T04:54:55Z
  GitCommit: 33c93aea0b9ee3d02fb9703cd82cecce3540e954
  GitTreeState: clean
  GoVersion: go1.14.1
  Compiler: gc
  Platform: linux/amd64
argocd-server: v1.7.7+33c93ae
  BuildDate: 2020-09-29T04:56:23Z
  GitCommit: 33c93aea0b9ee3d02fb9703cd82cecce3540e954
  GitTreeState: clean
  GoVersion: go1.14.1
  Compiler: gc
  Platform: linux/amd64
  Ksonnet Version: v0.13.1
  Kustomize Version: {Version:kustomize/v3.6.1 GitCommit:c97fa946d576eb6ed559f17f2ac43b3b5a8d5dbd BuildDate:2020-05-27T20:47:35Z GoOs:linux GoArch:amd64}
  Helm Version: version.BuildInfo{Version:"v3.2.0", GitCommit:"e11b7ce3b12db2941e90399e874513fbd24bcb71", GitTreeState:"clean", GoVersion:"go1.13.10"}
  Kubectl Version: v1.17.8

Logs

time="2020-11-04T16:38:21Z" level=info msg="apply failed" application=<redacted> dryRun=false message="namespaces \"beta\" not found" syncId=00075-abUEC task="PreSync/-10 hook /Secret:beta/beta-api nil->obj (,,)"
time="2020-11-04T16:38:21Z" level=info msg="adding resource result, status: 'SyncFailed', phase: 'Failed', message: 'namespaces \"beta\" not found'" application=<redacted> kind=Secret name=beta-api namespace=beta phase=PreSync syncId=00075-abUEC

[mayzhang2000]

I tried the following steps and could not reproduce it.

1. Create an app

apiVersion: argoproj.io/v1alpha1
kind: Application
metadata:
  name: mayhook
  namespace: argocd-e2e
spec:
  destination:
    namespace: bug1104
    server: https://kubernetes.default.svc
  project: default
  source:
    path: bug
    repoURL: https://github.com/mayzhang2000/argocd-example-apps.git
    targetRevision: HEAD
  syncPolicy:
    syncOptions:
    - CreateNamespace=true

2. Source contains PreSync hook: https://github.com/mayzhang2000/argocd-example-apps/blob/master/bug/presynchook.yaml
3. Sync and verified namespace bug1104 is created.

[elemental-lf]

@mayzhang2000 thank you for looking into this. I tried your code with our local installation and I still see the problem. If I'm reading the log correctly ArgoCD's order of execution is Secret -> Namespace -> Pod and this fails in the first step because the namespace doesn't exist yet. If I create the namespace beforehand it says time="2020-11-05T10:57:03Z" level=info msg="Namespace bug1104 is already existed." application=argo-cd-issue-4753 syncId=00078-pqeJH in the log and the sync runs successfully.

So what is the difference between your installation and mine? I'll upgrade to 1.7.8 first and try to reproduce again.

Full logs showing the problem (creating the app with kubectl apply and then starting a sync via the web UI):

time="2020-11-05T10:47:33Z" level=info msg="Refreshing app status (comparison expired. reconciledAt: never, expiry: 3m0s), level (2)" application=argo-cd-issue-4753
time="2020-11-05T10:47:33Z" level=info msg="Ignore status for CustomResourceDefinitions"
time="2020-11-05T10:47:33Z" level=info msg="Comparing app state (cluster: https://kubernetes.default.svc, namespace: bug1104)" application=argo-cd-issue-4753
time="2020-11-05T10:47:33Z" level=info msg="getRepoObjs stats" application=argo-cd-issue-4753 build_options_ms=0 helm_ms=0 plugins_ms=0 repo_ms=0 time_ms=481 unmarshal_ms=481 version_ms=0
time="2020-11-05T10:47:33Z" level=info msg="Updated sync status:  -> OutOfSync" application=argo-cd-issue-4753 dest-namespace=bug1104 dest-server="https://kubernetes.default.svc" reason=ResourceUpdated type=Normal
time="2020-11-05T10:47:33Z" level=info msg="Updated health status:  -> Missing" application=argo-cd-issue-4753 dest-namespace=bug1104 dest-server="https://kubernetes.default.svc" reason=ResourceUpdated type=Normal
time="2020-11-05T10:47:33Z" level=info msg="Update successful" application=argo-cd-issue-4753
time="2020-11-05T10:47:33Z" level=info msg="Reconciliation completed" application=argo-cd-issue-4753 dedup_ms=0 dest-name= dest-namespace=bug1104 dest-server="https://kubernetes.default.svc" diff_ms=0 fields.level=2 git_ms=481 health_ms=0 live_ms=3 settings_ms=0 sync_ms=0 time_ms=515
time="2020-11-05T10:48:39Z" level=info msg="updated 'argo-cd-issue-4753' operation (phase: Running)"
time="2020-11-05T10:48:39Z" level=info msg="Initialized new operation: {&SyncOperation{Revision:e56877c8dc954f41ed8357eb87c4024bffe8920b,Prune:false,DryRun:false,SyncStrategy:&SyncStrategy{Apply:nil,Hook:&SyncStrategyHook{SyncStrategyApply:SyncStrategyApply{Force:false,},},},Resources:[]SyncOperationResource{},Source:nil,Manifests:[],SyncOptions:[CreateNamespace=true],} {admin false} [] {0 nil}}" application=argo-cd-issue-4753
time="2020-11-05T10:48:39Z" level=info msg="Ignore status for CustomResourceDefinitions"
time="2020-11-05T10:48:39Z" level=info msg="Comparing app state (cluster: https://kubernetes.default.svc, namespace: bug1104)" application=argo-cd-issue-4753
time="2020-11-05T10:48:39Z" level=info msg="getRepoObjs stats" application=argo-cd-issue-4753 build_options_ms=0 helm_ms=0 plugins_ms=0 repo_ms=0 time_ms=6 unmarshal_ms=5 version_ms=0
time="2020-11-05T10:48:39Z" level=info msg="Ignore status for CustomResourceDefinitions"
time="2020-11-05T10:48:39Z" level=info msg=syncing application=argo-cd-issue-4753 skipHooks=false started=false syncId=00077-uRrRC
time="2020-11-05T10:48:39Z" level=info msg=tasks application=argo-cd-issue-4753 syncId=00077-uRrRC tasks="[PreSync/-10 hook /Secret:bug1104/beta-api nil->obj (,,), PreSync/0 resource /Namespace:/bug1104 nil->obj (,,), Sync/0 resource /Pod:bug1104/hello nil->obj (,,)]"
time="2020-11-05T10:48:39Z" level=info msg="Applying resource Secret/beta-api in cluster: https://172.31.0.1:443, namespace: bug1104"
time="2020-11-05T10:48:40Z" level=info msg="Applying resource Namespace/bug1104 in cluster: https://172.31.0.1:443, namespace: "
time="2020-11-05T10:48:40Z" level=info msg="Applying resource Pod/hello in cluster: https://172.31.0.1:443, namespace: bug1104"
time="2020-11-05T10:48:40Z" level=info msg="Updating operation state. phase: Running -> Running, message: '' -> 'one or more tasks are running'" application=argo-cd-issue-4753 syncId=00077-uRrRC
time="2020-11-05T10:48:40Z" level=info msg="Applying resource Secret/beta-api in cluster: https://172.31.0.1:443, namespace: bug1104"
time="2020-11-05T10:48:40Z" level=info msg="apply failed" application=argo-cd-issue-4753 dryRun=false message="namespaces \"bug1104\" not found" syncId=00077-uRrRC task="PreSync/-10 hook /Secret:bug1104/beta-api nil->obj (,,)"
time="2020-11-05T10:48:40Z" level=info msg="adding resource result, status: 'SyncFailed', phase: 'Failed', message: 'namespaces \"bug1104\" not found'" application=argo-cd-issue-4753 kind=Secret name=beta-api namespace=bug1104 phase=PreSync syncId=00077-uRrRC
time="2020-11-05T10:48:40Z" level=info msg="Updating operation state. phase: Running -> Failed, message: 'one or more tasks are running' -> 'one or more objects failed to apply'" application=argo-cd-issue-4753 syncId=00077-uRrRC
time="2020-11-05T10:48:40Z" level=info msg="sync/terminate complete" application=argo-cd-issue-4753 duration=490.556525ms syncId=00077-uRrRC
time="2020-11-05T10:48:40Z" level=info msg="updated 'argo-cd-issue-4753' operation (phase: Failed)"
time="2020-11-05T10:48:40Z" level=info msg="Sync operation to e56877c8dc954f41ed8357eb87c4024bffe8920b failed: one or more objects failed to apply" application=argo-cd-issue-4753 dest-namespace=bug1104 dest-server="https://kubernetes.default.svc" reason=OperationCompleted type=Warning
time="2020-11-05T10:48:40Z" level=info msg="Refreshing app status (controller refresh requested), level (2)" application=argo-cd-issue-4753
time="2020-11-05T10:48:40Z" level=info msg="Ignore status for CustomResourceDefinitions"
time="2020-11-05T10:48:40Z" level=info msg="Comparing app state (cluster: https://kubernetes.default.svc, namespace: bug1104)" application=argo-cd-issue-4753
time="2020-11-05T10:48:40Z" level=info msg="getRepoObjs stats" application=argo-cd-issue-4753 build_options_ms=0 helm_ms=0 plugins_ms=0 repo_ms=0 time_ms=375 unmarshal_ms=375 version_ms=0
time="2020-11-05T10:48:40Z" level=info msg="Update successful" application=argo-cd-issue-4753
time="2020-11-05T10:48:40Z" level=info msg="Reconciliation completed" application=argo-cd-issue-4753 dedup_ms=0 dest-name= dest-namespace=bug1104 dest-server="https://kubernetes.default.svc" diff_ms=0 fields.level=2 git_ms=375 health_ms=0 live_ms=2 settings_ms=0 sync_ms=0 time_ms=396

[elemental-lf]

I can also reproduce the problem with 1.7.8. Log looks the same:

time="2020-11-05T11:24:21Z" level=info msg=syncing application=argo-cd-issue-4753 skipHooks=false started=false syncId=00001-TyWfL
time="2020-11-05T11:24:21Z" level=info msg=tasks application=argo-cd-issue-4753 syncId=00001-TyWfL tasks="[PreSync/-10 hook /Secret:bug1104/beta-api nil->obj (,,), PreSync/0 resource /Namespace:/bug1104 nil->obj (,,), Sync/0 resource /Pod:bug1104/hello nil->obj (,,)]"
time="2020-11-05T11:24:21Z" level=info msg="Applying resource Secret/beta-api in cluster: https://172.31.0.1:443, namespace: bug1104"
time="2020-11-05T11:24:22Z" level=info msg="Applying resource Namespace/bug1104 in cluster: https://172.31.0.1:443, namespace: "
time="2020-11-05T11:24:22Z" level=info msg="Applying resource Pod/hello in cluster: https://172.31.0.1:443, namespace: bug1104"
time="2020-11-05T11:24:22Z" level=info msg="Updating operation state. phase: Running -> Running, message: '' -> 'one or more tasks are running'" application=argo-cd-issue-4753 syncId=00001-TyWfL
time="2020-11-05T11:24:22Z" level=info msg="Applying resource Secret/beta-api in cluster: https://172.31.0.1:443, namespace: bug1104"
time="2020-11-05T11:24:22Z" level=info msg="apply failed" application=argo-cd-issue-4753 dryRun=false message="namespaces \"bug1104\" not found" syncId=00001-TyWfL task="PreSync/-10 hook /Secret:bug1104/beta-api nil->obj (,,)"
time="2020-11-05T11:24:22Z" level=info msg="adding resource result, status: 'SyncFailed', phase: 'Failed', message: 'namespaces \"bug1104\" not found'" application=argo-cd-issue-4753 kind=Secret name=beta-api namespace=bug1104 phase=PreSync syncId=00001-TyWfL
time="2020-11-05T11:24:22Z" level=info msg="Updating operation state. phase: Running -> Failed, message: 'one or more tasks are running' -> 'one or more objects failed to apply'" application=argo-cd-issue-4753 syncId=00001-TyWfL
time="2020-11-05T11:24:22Z" level=info msg="sync/terminate complete" application=argo-cd-issue-4753 duration=622.614351ms syncId=00001-TyWfL
time="2020-11-05T11:24:22Z" level=info msg="updated 'argo-cd-issue-4753' operation (phase: Failed)"
time="2020-11-05T11:24:22Z" level=info msg="Sync operation to e56877c8dc954f41ed8357eb87c4024bffe8920b failed: one or more objects failed to apply" application=argo-cd-issue-4753 dest-namespace=bug1104 dest-server="https://kubernetes.default.svc" reason=OperationCompleted type=Warning

Version info (I only upgraded the server components):

argocd: v1.7.7+33c93ae
  BuildDate: 2020-09-29T04:54:55Z
  GitCommit: 33c93aea0b9ee3d02fb9703cd82cecce3540e954
  GitTreeState: clean
  GoVersion: go1.14.1
  Compiler: gc
  Platform: linux/amd64
argocd-server: v1.7.8+ef5010c
  BuildDate: 2020-10-15T22:34:12Z
  GitCommit: ef5010c3a0b5e027fd642732d03c5b0391b1e574
  GitTreeState: clean
  GoVersion: go1.14.1
  Compiler: gc
  Platform: linux/amd64
  Ksonnet Version: v0.13.1
  Kustomize Version: {Version:kustomize/v3.6.1 GitCommit:c97fa946d576eb6ed559f17f2ac43b3b5a8d5dbd BuildDate:2020-05-27T20:47:35Z GoOs:linux GoArch:amd64}
  Helm Version: version.BuildInfo{Version:"v3.2.0", GitCommit:"e11b7ce3b12db2941e90399e874513fbd24bcb71", GitTreeState:"clean", GoVersion:"go1.13.10"}
  Kubectl Version: v1.17.8

[jannfis]

@elemental-lf I think this is because your resources actually contain a Namespace resource:

time="2020-11-05T11:24:22Z" level=info msg="Applying resource Namespace/bug1104 in cluster: https://172.31.0.1:443, namespace: "

I think the CreateNamespace option only works if the resources do not contain a dedicated Namespace resource: https://github.com/argoproj/gitops-engine/blob/9a6cf9d611a59473346fad521266858a9c42a7a6/pkg/sync/sync_context.go#L622

[jannfis]

@mayzhang2000 Is this behaviour intended? I think it would make sense to auto-create the name space despite there being a dedicated Namespace resource in the source manifest (i.e. for applying labels or annotations to the namespace), while the automatic creation of namespaces could benefit PreSync hooks that create intermittent resources in the target namespace.

[elemental-lf]

@jannfis I used the example by mayzhang2000 as is and there is no dedicated Namespace resource in it. There is just a Pod and a Secret resource.

[elemental-lf]

@mayzhang2000 I just tried with current master (commit hash 9ee0d2c) and the problem does not occur there. And I'd guess that this PR is the reason: argoproj/gitops-engine#159.

EDIT: Fix was introduced into ArgoCD via #4563.

[jannfis]

@elemental-lf Ah, yeah, you're right. Thanks. Behaviour has changed with the PRs you linked. They will be part of v1.8.

@mayzhang2000 Please ignore my previous comment then. :)

[jannfis]

Is it ok for you to close this issue then, @elemental-lf ?

[elemental-lf]

Yes, thak you!