Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Backend plugin middleware does not execute response modifier if proxy returns an error in at least 1 backend #597

Open
danielfpferreira opened this issue Aug 9, 2022 · 3 comments

Comments

@danielfpferreira
Copy link

Environment info:

  • KrakenD version: 2.0.5
  • lura version: 2.0.5
  • System info: docker
  • Backend technology: Go

Describe the bug
plugin/req-resp-modifier in an endpoint is not called if one of the backend CEL evaluations fails

this was initially submitted in krakend/krakend-ce#542

After some debugging it looks like it's an issue in the plugin.go in the proxy pkg https://github.com/luraproject/lura/blob/master/proxy/plugin.go#L91-L96

When receiving a merged response for multiple backends, if one of the backends fails, we get a non nil err that is a mergeError.
The error contains a slice with one entry per failed backend.
Tested a simple fix, check if resp is nil, this still returns error and does not call the response modifier when all backends fail or is just one that failed, while allowing for the modifier to still be called.

Your configuration file:

{
  "$schema": "https://www.krakend.io/schema/v3.json",
  "version": 3,
  "name": "conditional test",
  "timeout": "3000s",
  "cache_ttl": "300s",
  "output_encoding": "json",
  "disable_rest": false,
  "plugin": {
    "folder": "./plugins/",
    "pattern": ".so"
  },
  "extra_config": {
    "telemetry/logging": {
      "level": "DEBUG",
      "prefix": "[KRAKEND]",
      "syslog": false,
      "stdout": true
    }
  },
  "endpoints": [
    {
      "endpoint": "/services",
      "input_headers": [
        "X-Group-Id"
      ],
      "method": "GET",
      "output_encoding": "json-collection",
      "extra_config": {
        "plugin/req-resp-modifier": {
          "name": [
            "krakend-response-aggregator"
          ]
        }
      },
      "backend": [
        {
          "group": "app1",
          "url_pattern": "/pattern1",
          "encoding": "safejson",
          "sd": "static",
          "method": "GET",
          "host": [
            "localhost:8090"
          ],
          "extra_config": {
            "validation/cel": [
              {
                "check_expr": "'group1' in req_headers['X-Group-Id']"
              }
            ]
          }
        },
        {
          "group": "app2",
          "url_pattern": "/pattern1",
          "encoding": "safejson",
          "sd": "static",
          "method": "GET",
          "host": [
            "localhost:8090"
          ],
          "extra_config": {
            "validation/cel": [
              {
                "check_expr": "'group2' in req_headers['X-Group-Id']"
              }
            ]
          }
        },
        {
          "group": "app3",
          "url_pattern": "/pattern2",
          "encoding": "safejson",
          "sd": "static",
          "method": "GET",
          "host": [
            "localhost:8090"
          ],
          "extra_config": {
            "validation/cel": [
              {
                "check_expr": "'group1' in req_headers['X-Group-Id']"
              }
            ]
          }
        }
      ]
    }
  ]
}

Configuration check output:
Result of krakend check -dtc krakend_conditional.json --lint command

Parsing configuration file: krakend_conditional.json
Global settings
        Name: conditional test
        Port: 8080
        Folder: ./plugins/
        Pattern: .so
1 global component configuration(s):
- telemetry/logging
1 API endpoint(s):
        - GET /services
        Timeout: 50m0s
        1 endpoint component configuration(s):
        - plugin/req-resp-modifier
        Connecting to 3 backend(s):
                [+] GET /pattern1
                Timeout: 50m0s
                Hosts: [http://localhost:8090]
                1 backend component configuration(s):
                - validation/cel

                [+] GET /pattern1
                Timeout: 50m0s
                Hosts: [http://localhost:8090]
                1 backend component configuration(s):
                - validation/cel

                [+] GET /pattern2
                Timeout: 50m0s
                Hosts: [http://localhost:8090]
                1 backend component configuration(s):
                - validation/cel

0 async agent(s):
Syntax OK!

Commands used:
How did you start the software?

krakend run -d  -c krakend_conditional.json

Expected behavior
The objective is to call multiple backends on a endpoint conditionally and return each backend response as a JSON collection where each element is the backend response.

Each backend is called if an HTTP header values matches a condition.

Each backend has a group defined and I have written a response modifier plugin that applied to the endpoint gets the merged response and then collapses each group response and moves the group key name to the value of "name" into the each backend response and adds the response collection to a "collection" object.

So each backend returns something in the likes of

{
  "groupId": "group1",
  "url": "/pattern1"
}

Merged response would look like

{
  "app1": {
    "groupId": "group1",
    "url": "/pattern1"
  },
  "app3": {
    "groupId": "group1",
    "url": "/pattern2"
  }
}

And modified response by the custom plugin:

{
  "collection": [
    {
      "name": "app1",
      "groupId": "group1",
      "url": "/pattern1"
    },
    {
      "name": "app3",
      "groupId": "group1",
      "url": "/pattern2"
    }
  ]
}

With output_encoding as json-collection we would get:

[
  {
    "name": "app1",
    "groupId": "group1",
    "url": "/pattern1"
  },
  {
    "name": "app3",
    "groupId": "group1",
    "url": "/pattern2"
  }
]

Call to services endpoint should return the expected collection resulting of the custom plugin response modification but instead returns an empty JSON collection

 curl http://localhost:8080/services -H 'x-group-id: group1' | jq
  % Total    % Received % Xferd  Average Speed   Time    Time     Time  Current
                                 Dload  Upload   Total   Spent    Left  Speed
100     2  100     2    0     0    163      0 --:--:-- --:--:-- --:--:--   181
[]

Setting the endpoint's output_encoding to json shows that the backend responses were merged but the response modifier was not triggered.

{
  "app1": {
    "groupId": "group1",
    "url": "/pattern1"
  },
  "app3": {
    "groupId": "group1",
    "url": "/pattern2"
  }
}

Logs:

The custom-plugin has logging and it should be visible with debug

Parsing configuration file: krakend_conditional.json
[KRAKEND] 2022/08/03 - 15:38:34.300 ▶ DEBUG [SERVICE: Plugin Loader] Starting loading process
krakend-response-aggregator loaded
[KRAKEND] 2022/08/03 - 15:38:34.348 ▶ DEBUG [SERVICE: Executor Plugin] plugin #0 (plugins/krakend-response-aggregator.so): plugin: symbol ClientRegisterer not found in plugin krakend-response-aggregator
[KRAKEND] 2022/08/03 - 15:38:34.348 ▶ DEBUG [SERVICE: Handler Plugin] plugin #0 (plugins/krakend-response-aggregator.so): plugin: symbol HandlerRegisterer not found in plugin krakend-response-aggregator
[KRAKEND] 2022/08/03 - 15:38:34.349 ▶ DEBUG [PLUGIN: krakend-response-aggregator] Logger loaded
[KRAKEND] 2022/08/03 - 15:38:34.349 ▶ INFO [SERVICE: Modifier Plugin] Total plugins loaded: 1
[KRAKEND] 2022/08/03 - 15:38:34.349 ▶ DEBUG [SERVICE: Plugin Loader] Loading process completed
[KRAKEND] 2022/08/03 - 15:38:34.349 ▶ DEBUG [SERVICE: Gin] Debug enabled
[KRAKEND] 2022/08/03 - 15:38:34.349 ▶ INFO Starting the KrakenD instance
[KRAKEND] 2022/08/03 - 15:38:34.349 ▶ DEBUG [ENDPOINT: /services] Building the proxy pipe
[KRAKEND] 2022/08/03 - 15:38:34.349 ▶ DEBUG [BACKEND: /pattern1] Building the backend pipe
[KRAKEND] 2022/08/03 - 15:38:34.349 ▶ DEBUG [BACKEND: /pattern1][CEL] Loading configuration
[KRAKEND] 2022/08/03 - 15:38:34.350 ▶ DEBUG [CEL] Parsing expression: 'group1' in req_headers['X-Group-Id']
[KRAKEND] 2022/08/03 - 15:38:34.360 ▶ DEBUG [BACKEND: /pattern1][CEL] 1 preEvaluator(s) loaded
[KRAKEND] 2022/08/03 - 15:38:34.360 ▶ DEBUG [BACKEND: /pattern1][CEL] 0 postEvaluator(s) loaded
[KRAKEND] 2022/08/03 - 15:38:34.360 ▶ DEBUG [BACKEND: /pattern1] Building the backend pipe
[KRAKEND] 2022/08/03 - 15:38:34.360 ▶ DEBUG [BACKEND: /pattern1][CEL] Loading configuration
[KRAKEND] 2022/08/03 - 15:38:34.360 ▶ DEBUG [CEL] Parsing expression: 'group2' in req_headers['X-Group-Id']
[KRAKEND] 2022/08/03 - 15:38:34.360 ▶ DEBUG [BACKEND: /pattern1][CEL] 1 preEvaluator(s) loaded
[KRAKEND] 2022/08/03 - 15:38:34.360 ▶ DEBUG [BACKEND: /pattern1][CEL] 0 postEvaluator(s) loaded
[KRAKEND] 2022/08/03 - 15:38:34.360 ▶ DEBUG [BACKEND: /pattern2] Building the backend pipe
[KRAKEND] 2022/08/03 - 15:38:34.360 ▶ DEBUG [BACKEND: /pattern2][CEL] Loading configuration
[KRAKEND] 2022/08/03 - 15:38:34.361 ▶ DEBUG [CEL] Parsing expression: 'group1' in req_headers['X-Group-Id']
[KRAKEND] 2022/08/03 - 15:38:34.361 ▶ DEBUG [BACKEND: /pattern2][CEL] 1 preEvaluator(s) loaded
[KRAKEND] 2022/08/03 - 15:38:34.361 ▶ DEBUG [BACKEND: /pattern2][CEL] 0 postEvaluator(s) loaded
[KRAKEND] 2022/08/03 - 15:38:34.361 ▶ DEBUG [ENDPOINT: /services][Merge] Backends: 3, sequential: false, combiner: default
[KRAKEND] 2022/08/03 - 15:38:34.361 ▶ DEBUG [ENDPOINT: /services][Modifier Plugins] Adding 0 request and 1 response modifiers
[KRAKEND] 2022/08/03 - 15:38:34.361 ▶ DEBUG [ENDPOINT: /services] Building the http handler
[KRAKEND] 2022/08/03 - 15:38:34.361 ▶ DEBUG [ENDPOINT: /services][JWTSigner] Signer disabled
[KRAKEND] 2022/08/03 - 15:38:34.361 ▶ INFO [ENDPOINT: /services][JWTValidator] Validator disabled for this endpoint
[KRAKEND] 2022/08/03 - 15:38:34.361 ▶ INFO [SERVICE: Gin] Listening on port: 8080
[KRAKEND] 2022/08/03 - 15:38:39.301 ▶ DEBUG [SERVICE: Telemetry] Registering usage stats for Cluster ID uSR1YoKcD2Ts8buAGDYEE9UgLU1ZN1NSKgJqm4dPzJI=
[KRAKEND] 2022/08/03 - 15:41:58.351 ▶ DEBUG [BACKEND: /pattern2][CEL][pre] Evaluator #0 result: true
[KRAKEND] 2022/08/03 - 15:41:58.351 ▶ INFO [BACKEND: /pattern1][CEL][pre] Evaluator #0 result: false
[KRAKEND] 2022/08/03 - 15:41:58.351 ▶ DEBUG [BACKEND: /pattern1][CEL][pre] Evaluator #0 result: true
[KRAKEND] 2022/08/03 - 15:41:58.358 ▶ ERROR [ENDPOINT: /services] Error #0: request aborted by evaluator #0
[GIN] 2022/08/03 - 15:41:58 | 200 |    7.348922ms |       127.0.0.1 | GET      "/services"

Additional comments:

Changing the CEL expression with group2 to group1 so that all backends pass the CEL evaluation proves that the custom plugin works when called

➜ curl http://localhost:8080/services -H 'x-group-id: group1' | jq
  % Total    % Received % Xferd  Average Speed   Time    Time     Time  Current
                                 Dload  Upload   Total   Spent    Left  Speed
100   160  100   160    0     0  16472      0 --:--:-- --:--:-- --:--:-- 17777
[
  {
    "groupId": "group1",
    "name": "app2",
    "url": "/pattern1"
  },
  {
    "groupId": "group1",
    "name": "app3",
    "url": "/pattern2"
  },
  {
    "groupId": "group1",
    "name": "app1",
    "url": "/pattern1"
  }
]

Logs

...
[KRAKEND] 2022/08/03 - 15:52:31.953 ▶ DEBUG [BACKEND: /pattern2][CEL][pre] Evaluator #0 result: true
[KRAKEND] 2022/08/03 - 15:52:31.953 ▶ DEBUG [BACKEND: /pattern1][CEL][pre] Evaluator #0 result: true
[KRAKEND] 2022/08/03 - 15:52:31.953 ▶ DEBUG [BACKEND: /pattern1][CEL][pre] Evaluator #0 result: true
[KRAKEND] 2022/08/03 - 15:52:31.961 ▶ DEBUG [PLUGIN: krakend-response-aggregator] called
[KRAKEND] 2022/08/03 - 15:52:31.962 ▶ DEBUG [PLUGIN: krakend-response-aggregator] response: {map[app1:map[groupId:group1 name:app1 url:/pattern1] app2:map[groupId:group1 name:app2 url:/pattern1] app3:map[groupId:group1 name:app3 url:/pattern2]] true {map[] 0} <nil>}
[GIN] 2022/08/03 - 15:52:31 | 200 |    8.802293ms |       127.0.0.1 | GET      "/services"
@alombarte
Copy link
Member

We didn't review this yet, but I am curious to know why you closed the PR.
The functionality you describe is expected by design.

@danielfpferreira
Copy link
Author

@alombarte sorry for the late reply, nothing to do with the code, I agree that it is a bug that needs fixing.
We are currently trying to clarify some legal constraints about contributing to the project.
Hopefully we'll be able to unblock the PR soon.

@husseljoo
Copy link

Any updates regarding this bug?

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging a pull request may close this issue.

3 participants