Middleware not activated


#1

I’m trying to get some middleware running on an API but can’t get it activated. This is somewhat a follow up of this question but since the original one is resolved I open a new one.

This is my API definition if I query it from the Dashboard API:

{
  "api_model": {},
  "api_definition": {
    "id": "584e6a1f58126c00010bb26b",
    "name": "Some Name",
    "slug": "0",
    "api_id": "c1159682aaae4c1f54a218a46de3ed82",
    "org_id": "584e69d658126c00010bb265",
    "use_keyless": false,
    "use_oauth2": false,
    "use_openid": false,
    "openid_options": {
      "providers": [],
      "segregate_by_client": false
    },
    "oauth_meta": {
      "allowed_access_types": [],
      "allowed_authorize_types": [],
      "auth_login_redirect": ""
    },
    "auth": {
      "use_param": false,
      "param_name": "",
      "use_cookie": false,
      "cookie_name": "",
      "auth_header_name": "Authorization"
    },
    "use_basic_auth": false,
    "enable_jwt": true,
    "use_standard_auth": false,
    "enable_coprocess_auth": false,
    "jwt_signing_method": "hmac",
    "jwt_source": "a2V5MTIza2V5",
    "jwt_identity_base_field": "sub",
    "jwt_client_base_field": "",
    "jwt_policy_field_name": "policy",
    "notifications": {
      "shared_secret": "",
      "oauth_on_keychange_url": ""
    },
    "enable_signature_checking": false,
    "hmac_allowed_clock_skew": -1,
    "base_identity_provided_by": "",
    "definition": {
      "location": "header",
      "key": "version"
    },
    "version_data": {
      "not_versioned": false,
      "versions": {
        "v1": {
          "name": "v1",
          "expires": "",
          "paths": {
            "ignored": [],
            "white_list": [],
            "black_list": []
          },
          "use_extended_paths": true,
          "extended_paths": {
            "white_list": [
              {
                "path": "/fqdn/{fqdnId}/node/{nodeId}",
                "method_actions": {
                  "GET": {
                    "action": "no_action",
                    "code": 200,
                    "data": "",
                    "headers": {}
                  },
                  "PATCH": {
                    "action": "no_action",
                    "code": 200,
                    "data": "",
                    "headers": {}
                  }
                }
              },
              {
                "path": "/fqdn/{id}/nodes",
                "method_actions": {
                  "GET": {
                    "action": "no_action",
                    "code": 200,
                    "data": "",
                    "headers": {}
                  }
                }
              },
              {
                "path": "/helloworld",
                "method_actions": {
                  "GET": {
                    "action": "no_action",
                    "code": 200,
                    "data": "",
                    "headers": {}
                  }
                }
              },
              {
                "path": "/fqdn/{id}",
                "method_actions": {
                  "GET": {
                    "action": "no_action",
                    "code": 200,
                    "data": "",
                    "headers": {}
                  },
                  "PATCH": {
                    "action": "no_action",
                    "code": 200,
                    "data": "",
                    "headers": {}
                  }
                }
              },
              {
                "path": "/error",
                "method_actions": {
                  "DELETE": {
                    "action": "no_action",
                    "code": 200,
                    "data": "",
                    "headers": {}
                  },
                  "GET": {
                    "action": "no_action",
                    "code": 200,
                    "data": "",
                    "headers": {}
                  },
                  "HEAD": {
                    "action": "no_action",
                    "code": 200,
                    "data": "",
                    "headers": {}
                  },
                  "OPTIONS": {
                    "action": "no_action",
                    "code": 200,
                    "data": "",
                    "headers": {}
                  },
                  "PATCH": {
                    "action": "no_action",
                    "code": 200,
                    "data": "",
                    "headers": {}
                  },
                  "POST": {
                    "action": "no_action",
                    "code": 200,
                    "data": "",
                    "headers": {}
                  },
                  "PUT": {
                    "action": "no_action",
                    "code": 200,
                    "data": "",
                    "headers": {}
                  }
                }
              }
            ]
          },
          "global_headers": {},
          "global_headers_remove": [],
          "global_size_limit": 0,
          "override_target": ""
        }
      }
    },
    "uptime_tests": {
      "check_list": [],
      "config": {
        "expire_utime_after": 0,
        "service_discovery": {
          "use_discovery_service": false,
          "query_endpoint": "",
          "use_nested_query": false,
          "parent_data_path": "",
          "data_path": "",
          "port_data_path": "",
          "target_path": "",
          "use_target_list": false,
          "cache_timeout": 0,
          "endpoint_returns_list": false
        },
        "recheck_wait": 0
      }
    },
    "proxy": {
      "preserve_host_header": false,
      "listen_path": "/drowsy/",
      "target_url": "http://10.2.77.55:8080",
      "strip_listen_path": true,
      "enable_load_balancing": false,
      "target_list": [],
      "check_host_against_uptime_tests": false,
      "service_discovery": {
        "use_discovery_service": false,
        "query_endpoint": "",
        "use_nested_query": false,
        "parent_data_path": "",
        "data_path": "",
        "port_data_path": "",
        "target_path": "",
        "use_target_list": false,
        "cache_timeout": 0,
        "endpoint_returns_list": false
      }
    },
    "disable_rate_limit": false,
    "disable_quota": false,
    "custom_middleware": {
      "pre": [
        {
          "name": "sampleMiddleware",
          "path": "middleware/sampleMiddleware.js",
          "require_session": false
        },
        {
          "name": "tokenInjection",
          "path": "middleware/tokenInjection.js",
          "require_session": false
        }
      ],
      "post": [],
      "post_key_auth": [],
      "auth_check": {
        "name": "",
        "path": "",
        "require_session": false
      },
      "response": [],
      "driver": "",
      "id_extractor": {
        "extract_from": "",
        "extract_with": "",
        "extractor_config": {}
      }
    },
    "custom_middleware_bundle": "",
    "cache_options": {
      "cache_timeout": 0,
      "enable_cache": false,
      "cache_all_safe_requests": false,
      "cache_response_codes": [],
      "enable_upstream_cache_control": false
    },
    "session_lifetime": 0,
    "active": true,
    "auth_provider": {
      "name": "",
      "storage_engine": "",
      "meta": {}
    },
    "session_provider": {
      "name": "",
      "storage_engine": "",
      "meta": null
    },
    "event_handlers": {
      "events": {}
    },
    "enable_batch_request_support": false,
    "enable_ip_whitelisting": false,
    "allowed_ips": [],
    "dont_set_quota_on_create": false,
    "expire_analytics_after": 0,
    "response_processors": [],
    "CORS": {
      "enable": false,
      "allowed_origins": [],
      "allowed_methods": [],
      "allowed_headers": [],
      "exposed_headers": [],
      "allow_credentials": false,
      "max_age": 0,
      "options_passthrough": false,
      "debug": false
    },
    "domain": "",
    "do_not_track": false,
    "tags": [],
    "enable_context_vars": false
  },
  "hook_references": [],
  "is_site": false,
  "sort_by": 0
}

This is my middleware, located at /opt/tyk-gateway/middleware:

var tokenInjection = new TykJS.TykMiddleware.NewMiddleware({});

tokenInjection.NewProcessRequest(function(request, session) {

    console.log("This middleware does nothing, but will print this to your terminal.");

    request.SetHeaders["x-custom-header"] = "foo";

    return tokenInjection.ReturnData(request, session.meta_data);
});    

At first I thought it might only be the log statement that does not work. But if I intercept the request on the upstream API the x-custom-header is not available.

This is everything I get from the logs from the time I PUT the API definition to my request that went through:

tyk_gateway_1    | time="Dec 12 15:24:53" level=info msg="Reloading endpoints"
tyk_gateway_1    | time="Dec 12 15:24:53" level=info msg="Initiating reload"
tyk_gateway_1    | time="Dec 12 15:24:53" level=info msg="Initiating coprocess reload"
tyk_gateway_1    | time="Dec 12 15:24:53" level=info msg="Starting reload monitor..."
tyk_gateway_1    | time="Dec 12 15:25:03" level=info msg="Loading policies"
tyk_gateway_1    | time="Dec 12 15:25:03" level=info msg="Using Policies from Dashboard Service"
tyk_gateway_1    | time="Dec 12 15:25:03" level=info msg="Mutex lock acquired... calling"
tyk_gateway_1    | time="Dec 12 15:25:03" level=info msg="Calling dashboard service for policy list"
tyk_gateway_1    | time="Dec 12 15:25:03" level=warning msg="Reloader timed out! Removing sentinel"
tyk_gateway_1    | time="Dec 12 15:25:03" level=info msg="Processing policy list"
tyk_gateway_1    | time="Dec 12 15:25:03" level=info msg="--> Processing policy ID: 584e6b4b58126c00013b1a12"
tyk_gateway_1    | time="Dec 12 15:25:03" level=info msg="Detected 4 APIs"
tyk_gateway_1    | time="Dec 12 15:25:03" level=info msg="Preparing new router"
tyk_gateway_1    | time="Dec 12 15:25:03" level=info msg="Initialising Tyk REST API Endpoints"
tyk_gateway_1    | time="Dec 12 15:25:03" level=info msg="Loading API configurations."
tyk_gateway_1    | time="Dec 12 15:25:03" level=info msg="Tracking hostname" api_name="Portal Assets" domain=www.tyk-portal-test.com
tyk_gateway_1    | time="Dec 12 15:25:03" level=info msg="Tracking hostname" api_name="Portal API" domain=www.tyk-portal-test.com
tyk_gateway_1    | time="Dec 12 15:25:03" level=info msg="Tracking hostname" api_name=Portal domain=www.tyk-portal-test.com
tyk_gateway_1    | time="Dec 12 15:25:03" level=info msg="Tracking hostname" api_name="Some Name" domain="(no host)"
tyk_gateway_1    | time="Dec 12 15:25:03" level=info msg="Loading API" api_name=Portal
tyk_gateway_1    | time="Dec 12 15:25:03" level=info msg="Checking security policy: Open" api_name=Portal
tyk_gateway_1    | time="Dec 12 15:25:03" level=info msg="Loading API" api_name="Portal API"
tyk_gateway_1    | time="Dec 12 15:25:03" level=info msg="Checking security policy: Open" api_name="Portal API"
tyk_gateway_1    | time="Dec 12 15:25:03" level=info msg="Loading API" api_name="Some Name"
tyk_gateway_1    | time="Dec 12 15:25:03" level=info msg="Checking security policy: JWT" api_name="Some Name"
tyk_gateway_1    | time="Dec 12 15:25:03" level=info msg="Loading API" api_name="Portal Assets"
tyk_gateway_1    | time="Dec 12 15:25:03" level=info msg="Checking security policy: Open" api_name="Portal Assets"
tyk_gateway_1    | time="Dec 12 15:25:04" level=info msg="Processed and listening on: /portal-assets/{rest:.*}"
tyk_gateway_1    | time="Dec 12 15:25:04" level=info msg="Processed and listening on: /portal-api/{rest:.*}"
tyk_gateway_1    | time="Dec 12 15:25:04" level=info msg="Processed and listening on: /portal/{rest:.*}"
tyk_gateway_1    | time="Dec 12 15:25:04" level=info msg="Processed and listening on: /drowsy/{rest:.*}"
tyk_gateway_1    | time="Dec 12 15:25:04" level=info msg="Loading uptime tests..."
tyk_gateway_1    | time="Dec 12 15:25:04" level=info msg="Initialised API Definitions"
tyk_gateway_1    | time="Dec 12 15:25:04" level=info msg="API reload complete"
tyk_pump_1       | time="Dec 12 15:25:26" level=info msg="Purging 1 records"
tyk_pump_1       | time="Dec 12 15:27:58" level=info msg="Purging 1 records"

#2

I[;d suggest to check your tyk.conf file to see if the JSVM is enabled, the field is called enable_jsvm and it’s a bool so just set it to true.

It looks like you are suing the quickstart, which AFAICS does not have this value set in the default tyk.conf that ships with it.


#3

Thank you, that solved the issue. Would it make sense to include it in the default configuration with the value set to false so people see that it can be enabled?