TykTechnologies/tyk-operator

[TT-10958] Reconciliation of security policy fails while doing any changes in policy

utkarsh079 opened this issue · 27 comments

utkarsh079 commented

Expected Behavior

When making any changes to security policy resource, the security policy should be updates in gateway

Current Behavior

Security policy gets created alright but any kind of changes to the policy fails

Steps to Reproduce

  1. Create a security policy
  2. Try changing the numbers in rate limiting
  3. Get policy from gateway with the REST API

Logs/Errors

Logs from tyk-operator:

{"level":"error","ts":1704856888.0658429,"logger":"controllers.SecurityPolicy","msg":"Failed to re-create Policy on Tyk","SecurityPolicy":{"namespace":"adt","name":"sp-apikey-default-test-key"},"error":"Request malformed Status: error HTTP 400: Failed api call","errorVerbose":"Failed api call\nRequest malformed Status: error HTTP 400\ngithub.com/TykTechnologies/tyk-operator/pkg/client.Call\n\t/workspace/pkg/client/client.go:222\ngithub.com/TykTechnologies/tyk-operator/pkg/client.CallJSON\n\t/workspace/pkg/client/client.go:134\ngithub.com/TykTechnologies/tyk-operator/pkg/client.PostJSON\n\t/workspace/pkg/client/client.go:146\ngithub.com/TykTechnologies/tyk-operator/pkg/client/gateway.SecurityPolicy.Create\n\t/workspace/pkg/client/gateway/security_policy.go:53\ngithub.com/TykTechnologies/tyk-operator/pkg/client/klient.Policy.Create\n\t/workspace/pkg/client/klient/universal_client.go:97\ngithub.com/TykTechnologies/tyk-operator/controllers.(*SecurityPolicyReconciler).update\n\t/workspace/controllers/securitypolicy_controller.go:282\ngithub.com/TykTechnologies/tyk-operator/controllers.(*SecurityPolicyReconciler).Reconcile.func1\n\t/workspace/controllers/securitypolicy_controller.go:107\nsigs.k8s.io/controller-runtime/pkg/controller/controllerutil.mutate\n\t/go/pkg/mod/sigs.k8s.io/controller-runtime@v0.9.0/pkg/controller/controllerutil/controllerutil.go:341\nsigs.k8s.io/controller-runtime/pkg/controller/controllerutil.CreateOrUpdate\n\t/go/pkg/mod/sigs.k8s.io/controller-runtime@v0.9.0/pkg/controller/controllerutil/controllerutil.go:213\ngithub.com/TykTechnologies/tyk-operator/controllers.(*SecurityPolicyReconciler).Reconcile\n\t/workspace/controllers/securitypolicy_controller.go:75\nsigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).reconcileHandler\n\t/go/pkg/mod/sigs.k8s.io/controller-runtime@v0.9.0/pkg/internal/controller/controller.go:298\nsigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).processNextWorkItem\n\t/go/pkg/mod/sigs.k8s.io/controller-runtime@v0.9.0/pkg/internal/controller/controller.go:253\nsigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).Start.func2.2\n\t/go/pkg/mod/sigs.k8s.io/controller-runtime@v0.9.0/pkg/internal/controller/controller.go:214\nruntime.goexit\n\t/usr/local/go/src/runtime/asm_amd64.s:1594","stacktrace":"github.com/TykTechnologies/tyk-operator/controllers.(*SecurityPolicyReconciler).Reconcile.func1\n\t/workspace/controllers/securitypolicy_controller.go:107\nsigs.k8s.io/controller-runtime/pkg/controller/controllerutil.mutate\n\t/go/pkg/mod/sigs.k8s.io/controller-runtime@v0.9.0/pkg/controller/controllerutil/controllerutil.go:341\nsigs.k8s.io/controller-runtime/pkg/controller/controllerutil.CreateOrUpdate\n\t/go/pkg/mod/sigs.k8s.io/controller-runtime@v0.9.0/pkg/controller/controllerutil/controllerutil.go:213\ngithub.com/TykTechnologies/tyk-operator/controllers.(*SecurityPolicyReconciler).Reconcile\n\t/workspace/controllers/securitypolicy_controller.go:75\nsigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).reconcileHandler\n\t/go/pkg/mod/sigs.k8s.io/controller-runtime@v0.9.0/pkg/internal/controller/controller.go:298\nsigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).processNextWorkItem\n\t/go/pkg/mod/sigs.k8s.io/controller-runtime@v0.9.0/pkg/internal/controller/controller.go:253\nsigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).Start.func2.2\n\t/go/pkg/mod/sigs.k8s.io/controller-runtime@v0.9.0/pkg/internal/controller/controller.go:214"}
{"level":"error","ts":1704856888.0659,"logger":"controller-runtime.manager.controller.securitypolicy","msg":"Reconciler error","reconciler group":"tyk.tyk.io","reconciler kind":"SecurityPolicy","name":"sp-apikey-default-test-key","namespace":"adt","error":"Request malformed Status: error HTTP 400: Failed api call","errorVerbose":"Failed api call\nRequest malformed Status: error HTTP 400\ngithub.com/TykTechnologies/tyk-operator/pkg/client.Call\n\t/workspace/pkg/client/client.go:222\ngithub.com/TykTechnologies/tyk-operator/pkg/client.CallJSON\n\t/workspace/pkg/client/client.go:134\ngithub.com/TykTechnologies/tyk-operator/pkg/client.PostJSON\n\t/workspace/pkg/client/client.go:146\ngithub.com/TykTechnologies/tyk-operator/pkg/client/gateway.SecurityPolicy.Create\n\t/workspace/pkg/client/gateway/security_policy.go:53\ngithub.com/TykTechnologies/tyk-operator/pkg/client/klient.Policy.Create\n\t/workspace/pkg/client/klient/universal_client.go:97\ngithub.com/TykTechnologies/tyk-operator/controllers.(*SecurityPolicyReconciler).update\n\t/workspace/controllers/securitypolicy_controller.go:282\ngithub.com/TykTechnologies/tyk-operator/controllers.(*SecurityPolicyReconciler).Reconcile.func1\n\t/workspace/controllers/securitypolicy_controller.go:107\nsigs.k8s.io/controller-runtime/pkg/controller/controllerutil.mutate\n\t/go/pkg/mod/sigs.k8s.io/controller-runtime@v0.9.0/pkg/controller/controllerutil/controllerutil.go:341\nsigs.k8s.io/controller-runtime/pkg/controller/controllerutil.CreateOrUpdate\n\t/go/pkg/mod/sigs.k8s.io/controller-runtime@v0.9.0/pkg/controller/controllerutil/controllerutil.go:213\ngithub.com/TykTechnologies/tyk-operator/controllers.(*SecurityPolicyReconciler).Reconcile\n\t/workspace/controllers/securitypolicy_controller.go:75\nsigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).reconcileHandler\n\t/go/pkg/mod/sigs.k8s.io/controller-runtime@v0.9.0/pkg/internal/controller/controller.go:298\nsigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).processNextWorkItem\n\t/go/pkg/mod/sigs.k8s.io/controller-runtime@v0.9.0/pkg/internal/controller/controller.go:253\nsigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).Start.func2.2\n\t/go/pkg/mod/sigs.k8s.io/controller-runtime@v0.9.0/pkg/internal/controller/controller.go:214\nruntime.goexit\n\t/usr/local/go/src/runtime/asm_amd64.s:1594","stacktrace":"sigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).processNextWorkItem\n\t/go/pkg/mod/sigs.k8s.io/controller-runtime@v0.9.0/pkg/internal/controller/controller.go:253\nsigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).Start.func2.2\n\t/go/pkg/mod/sigs.k8s.io/controller-runtime@v0.9.0/pkg/internal/controller/controller.go:214"}
{"level":"info","ts":1704856888.0659378,"logger":"controllers.SecurityPolicy","msg":"Reconciling SecurityPolicy instance","SecurityPolicy":"adt/api-rate-limit-ip-w-sc-apikey-default"}
{"level":"info","ts":1704856888.0746932,"logger":"controllers.SecurityPolicy","msg":"Updating SecurityPolicy","Policy ID":"YWR0L2FwaS1yYXRlLWxpbWl0LWlwLXctc2MtYXBpa2V5LWRlZmF1bHQ"}
{"level":"info","ts":1704856888.0751746,"logger":"controllers.SecurityPolicy","msg":"Call","SecurityPolicy":"adt/api-rate-limit-ip-w-sc-apikey-default","Method":"GET","URL":"http://gateway-control-svc-tyk-gateway-tyk-headless.dst.svc.cluster.local:9696/tyk/policies/YWR0L2FwaS1yYXRlLWxpbWl0LWlwLXctc2MtYXBpa2V5LWRlZmF1bHQ","Status":200}
{"level":"info","ts":1704856888.0757208,"logger":"controllers.SecurityPolicy","msg":"Call","SecurityPolicy":"adt/api-rate-limit-ip-w-sc-apikey-default","Method":"PUT","URL":"http://gateway-control-svc-tyk-gateway-tyk-headless.dst.svc.cluster.local:9696/tyk/policies/YWR0L2FwaS1yYXRlLWxpbWl0LWlwLXctc2MtYXBpa2V5LWRlZmF1bHQ","Status":400}
{"level":"info","ts":1704856888.0757434,"logger":"controllers.SecurityPolicy","msg":"Bad Request","SecurityPolicy":"adt/api-rate-limit-ip-w-sc-apikey-default","body":"{\"status\":\"error\",\"message\":\"Request malformed\"}\n"}
{"level":"error","ts":1704856888.0757673,"logger":"controllers.SecurityPolicy","msg":"Failed to update policy on Tyk","error":"Request malformed Status: error HTTP 400: Failed api call","errorVerbose":"Failed api call\nRequest malformed Status: error HTTP 400\ngithub.com/TykTechnologies/tyk-operator/pkg/client.Call\n\t/workspace/pkg/client/client.go:222\ngithub.com/TykTechnologies/tyk-operator/pkg/client.CallJSON\n\t/workspace/pkg/client/client.go:134\ngithub.com/TykTechnologies/tyk-operator/pkg/client.PutJSON\n\t/workspace/pkg/client/client.go:150\ngithub.com/TykTechnologies/tyk-operator/pkg/client/gateway.SecurityPolicy.Update\n\t/workspace/pkg/client/gateway/security_policy.go:88\ngithub.com/TykTechnologies/tyk-operator/pkg/client/klient.Policy.Update\n\t/workspace/pkg/client/klient/universal_client.go:101\ngithub.com/TykTechnologies/tyk-operator/controllers.(*SecurityPolicyReconciler).update\n\t/workspace/controllers/securitypolicy_controller.go:275\ngithub.com/TykTechnologies/tyk-operator/controllers.(*SecurityPolicyReconciler).Reconcile.func1\n\t/workspace/controllers/securitypolicy_controller.go:107\nsigs.k8s.io/controller-runtime/pkg/controller/controllerutil.mutate\n\t/go/pkg/mod/sigs.k8s.io/controller-runtime@v0.9.0/pkg/controller/controllerutil/controllerutil.go:341\nsigs.k8s.io/controller-runtime/pkg/controller/controllerutil.CreateOrUpdate\n\t/go/pkg/mod/sigs.k8s.io/controller-runtime@v0.9.0/pkg/controller/controllerutil/controllerutil.go:213\ngithub.com/TykTechnologies/tyk-operator/controllers.(*SecurityPolicyReconciler).Reconcile\n\t/workspace/controllers/securitypolicy_controller.go:75\nsigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).reconcileHandler\n\t/go/pkg/mod/sigs.k8s.io/controller-runtime@v0.9.0/pkg/internal/controller/controller.go:298\nsigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).processNextWorkItem\n\t/go/pkg/mod/sigs.k8s.io/controller-runtime@v0.9.0/pkg/internal/controller/controller.go:253\nsigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).Start.func2.2\n\t/go/pkg/mod/sigs.k8s.io/controller-runtime@v0.9.0/pkg/internal/controller/controller.go:214\nruntime.goexit\n\t/usr/local/go/src/runtime/asm_amd64.s:1594","stacktrace":"github.com/TykTechnologies/tyk-operator/controllers.(*SecurityPolicyReconciler).Reconcile.func1\n\t/workspace/controllers/securitypolicy_controller.go:107\nsigs.k8s.io/controller-runtime/pkg/controller/controllerutil.mutate\n\t/go/pkg/mod/sigs.k8s.io/controller-runtime@v0.9.0/pkg/controller/controllerutil/controllerutil.go:341\nsigs.k8s.io/controller-runtime/pkg/controller/controllerutil.CreateOrUpdate\n\t/go/pkg/mod/sigs.k8s.io/controller-runtime@v0.9.0/pkg/controller/controllerutil/controllerutil.go:213\ngithub.com/TykTechnologies/tyk-operator/controllers.(*SecurityPolicyReconciler).Reconcile\n\t/workspace/controllers/securitypolicy_controller.go:75\nsigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).reconcileHandler\n\t/go/pkg/mod/sigs.k8s.io/controller-runtime@v0.9.0/pkg/internal/controller/controller.go:298\nsigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).processNextWorkItem\n\t/go/pkg/mod/sigs.k8s.io/controller-runtime@v0.9.0/pkg/internal/controller/controller.go:253\nsigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).Start.func2.2\n\t/go/pkg/mod/sigs.k8s.io/controller-runtime@v0.9.0/pkg/internal/controller/controller.go:214"}

Logs from gateway:

time="Jan 10 04:28:08" level=debug msg="Requesting policy forYWR0L2FwaS1yYXRlLWxpbWl0LWlwLXctc2MtYXBpa2V5LWRlZmF1bHQ"
time="Jan 10 04:28:08" level=debug msg="Updating existing Policy: YWR0L2FwaS1yYXRlLWxpbWl0LWlwLXctc2MtYXBpa2V5LWRlZmF1bHQ"
time="Jan 10 04:28:08" level=error msg="Couldn't decode new policy object: invalid ObjectId in JSON: \"YWR0L2FwaS1yYXRlLWxpbWl0LWlwLXctc2MtYXBpa2V5LWRlZmF1bHQ\""

Security policy object:

apiVersion: tyk.tyk.io/v1alpha1
kind: SecurityPolicy
metadata:
  name: api-rate-limit-ip-w-sc-apikey-default
  namespace: adt
spec:
  _id: YWR0L2FwaS1yYXRlLWxpbWl0LWlwLXctc2MtYXBpa2V5LWRlZmF1bHQ
  active: true
  id: YWR0L2FwaS1yYXRlLWxpbWl0LWlwLXctc2MtYXBpa2V5LWRlZmF1bHQ
  is_inactive: false
  name: apikey-default
  org_id: ''
  partitions:
    acl: false
    complexity: false
    per_api: false
    quota: true
    rate_limit: true
  per: 60
  quota_renewal_rate: 60
  rate: 100
  state: active
  throttle_interval: 10
  throttle_retry_limit: 3

Policy object from the gateway:

{
  "_id": "",
  "id": "YWR0L2FwaS1yYXRlLWxpbWl0LWlwLXctc2MtYXBpa2V5LWRlZmF1bHQ",
  "name": "apikey-default",
  "org_id": "",
  "rate": 100,
  "per": 60,
  "quota_max": 0,
  "quota_renewal_rate": 60,
  "throttle_interval": -1,
  "throttle_retry_limit": -1,
  "max_query_depth": 0,
  "access_rights": null,
  "hmac_enabled": false,
  "enable_http_signature_validation": false,
  "active": true,
  "is_inactive": false,
  "tags": [
    "implements-auth"
  ],
  "key_expires_in": 0,
  "partitions": {
    "quota": true,
    "rate_limit": true,
    "complexity": false,
    "acl": false,
    "per_api": false
  },
  "last_updated": "",
  "meta_data": null,
  "graphql_access_rights": null
}

though '_id' and 'id' in securitypolicy CR is same but '_id' is an empty string in the security policy object. I am not sure if I am missing something or something is wrong

Your Environment

  • OS (e.g. Linux, macOS, Windows):
    • OS version: Kubernetes 1.25
  • tyk-operator version/commit: 0.15.0
komalsukhani commented

@utkarsh079 Have you set allow_explicit_policy_id as mentioned in the docs ?

utkarsh079 commented

@komalsukhani yes the allow_explicit_policy_id is set to true

echo $TYK_GW_POLICIES_ALLOWEXPLICITPOLICYID
true
buraksekili commented

@utkarsh079 can you please share the gateway configuration and logs if possible?

utkarsh079 commented

tyk.conf

{
    "listen_port": 8080,
    "template_path": "/opt/tyk-gateway/templates",
    "tyk_js_path": "/opt/tyk-gateway/js/tyk.js",
    "middleware_path": "/mnt/tyk-gateway/middleware",
    "use_db_app_configs": false,
    "db_app_conf_options": {
        "connection_string": "",
        "node_is_segmented": false,
        "tags": []
    },
    "app_path": "/mnt/tyk-gateway/apps",
    "storage": {
        "type": "redis",
        "enable_cluster": false,
        "hosts": {
            "$redis": "$rport"
        },
        "username": "",
        "password": "",
        "database": 0,
        "optimisation_max_idle": 1000
    },
    "enable_analytics": false,
    "analytics_config": {
        "type": "mongo",
        "csv_dir": "/tmp",
        "mongo_url": "",
        "mongo_db_name": "",
        "mongo_collection": "",
        "purge_delay": -1,
        "ignored_ips": []
    },
    "health_check": {
        "enable_health_checks": false,
        "health_check_value_timeouts": 60
    },
    "optimisations_use_async_session_write": true,
    "enable_non_transactional_rate_limiter": true,
    "enable_sentinel_rate_limiter": false,
    "allow_master_keys": false,
    "policies": {
        "policy_source": "file",
        "policy_record_name": "/mnt/tyk-gateway/policies/policies.json"
    },
    "hash_keys": true,
    "hash_key_function": "murmur128",
    "close_connections": false,
    "http_server_options": {
        "enable_websockets": true,
        "use_ssl": true,
        "server_name": "*",
        "min_version": 771,
        "certificates": [{
            "domain_name": "*",
            "cert_file": "/etc/certs/cert.pem",
            "key_file": "/etc/certs/key.pem"
        }]
    },
    "allow_insecure_configs": true,
    "coprocess_options": {
        "enable_coprocess": true,
        "coprocess_grpc_server": ""
    },
    "enable_bundle_downloader": false,
    "bundle_base_url": "",
    "global_session_lifetime": 100,
    "force_global_session_lifetime": false,
    "max_idle_connections_per_host": 500,
    "enable_custom_domains": true,
    "pid_file_location": "/mnt/tyk-gateway/tyk.pid"
}

Gateway is installed in k8s using helm chart, here are the extra environment variables that I have set

extraEnvs:
    - name: TYK_GW_STORAGE_SSLINSECURESKIPVERIFY
      value: "true"
    - name: TYK_GW_ENABLEHASHEDKEYSLISTING
      value: "true"
    - name: TYK_GW_LOGLEVEL
      value: "debug"
    - name: TYK_GW_ENABLEBUNDLEDOWNLOADER
      value: "true"
    - name: TYK_GW_BUNDLEBASEURL
      value: "<>"
    - name: "TYK_GW_BUNDLEINSECURESKIPVERIFY"
      value: "true"
    - name: "TYK_GW_COPROCESSOPTIONS_ENABLECOPROCESS"
      value: "true"
    - name: "TYK_GW_COPROCESSOPTIONS_PYTHONPATHPREFIX"
      value: "/opt/tyk-gateway"
    - name: "TYK_GW_CONTROLAPIHOSTNAME"
      value: "<>"
    - name: TYK_GW_ENABLEANALYTICS
      value: "true"
    - name: "VTX_ENVIRONMENT"
      value: "develop"
    - name: "TYK_PMP_DECODERAWREQUEST"
      value: "true"
    - name: "TYK_GW_ENABLEREDISROLLINGLIMITER"
      value: "false"
    - name: "TYK_GW_POLICIES_ALLOWEXPLICITPOLICYID"
      value: "true"
    - name: "TYK_GW_ENABLEKEYLOGGING"
      value: "true"
    - name: "TYK_GW_HASHKEYS"
      value: "true"
    - name: "TYK_GW_ENABLESENTINELRATELIMITER"
      value: "false"

Is there anything specific you are looking for in logs? Most relevant logs that I found in gateway are thses

time="Jan 10 04:28:08" level=debug msg="Requesting policy forYWR0L2FwaS1yYXRlLWxpbWl0LWlwLXctc2MtYXBpa2V5LWRlZmF1bHQ"
time="Jan 10 04:28:08" level=debug msg="Updating existing Policy: YWR0L2FwaS1yYXRlLWxpbWl0LWlwLXctc2MtYXBpa2V5LWRlZmF1bHQ"
time="Jan 10 04:28:08" level=error msg="Couldn't decode new policy object: invalid ObjectId in JSON: \"YWR0L2FwaS1yYXRlLWxpbWl0LWlwLXctc2MtYXBpa2V5LWRlZmF1bHQ\""
komalsukhani commented

@utkarsh079 Are you installing tyk-oss?
Can you also let us know which gateway/dashboard version have you installed?

utkarsh079 commented

yes, I am installing tyk-oss
gateway: v5.2.3

buraksekili commented

Thank you, @utkarsh079. However, Gateway v2.5.3 does not support policies. Did you mean v5.2.3?

utkarsh079 commented

ahh my bad, yes I mean v5.2.3

mguggi commented

I have a similar issue, but I see the following message in the gateway log when I create the policy.

gateway-tyk-gateway time="Jan 11 09:34:04" level=error msg="Couldn't decode new policy object: invalid ObjectId in JSON: \"ZGVmYXVsdC9qd3QtcG9saWN5\" (encoding/hex: invalid byte: U+005A 'Z')"

The filed _id is an empty string in the according file.

I use the following versions:

  • gateway: v5.2.5
  • operator: v0.15.1
buraksekili commented

thanks for reporting this issue @utkarsh079 and @mguggi. we are working on the issue and try to raise a fix for it for the upcoming release

buraksekili commented

The fix is pushed to the new release and is available from Tyk Operator v0.16.0. Thank you again @utkarsh079 and @mguggi for raising the issue. Feel free to raise a new issue if new issues emerge.