Functions in OpenFaaS are not READY, even when they report so

[kars7e]

• [x] Bug
• [ ] Feature
• [ ] Enhancement

Detailed Description

With recent version (7040a82d1e) and when using OpenFaaS driver, Trying to invoke function instantly after it becomes READY returns weird errors:

• Function run gets stuck in CREATING, then it times out after 60 seconds and goes into ERROR
• dispatch get run returns:

  {
      "event": {
          "cloud-events-version": "0.1",
          "content-type": "application/json",
          "event-id": "c90b1cfb-2613-4e95-ba25-aa267569535b",
          "event-time": "2018-04-10T03:04:51.000Z",
          "event-type": "test.event.21733",
          "namespace": "dispatchframework.io",
          "source-id": "dispatch",
          "source-type": "dispatch"
      },
      "executedTime": -62167208109,
      "finishedTime": -62135596800,
      "functionId": "04ea4d64-0f6a-457f-83d0-2a4ca6c0c93c",
      "functionName": "node-echo-back-5682",
      "input": "{\"name\": \"Jon\", \"place\": \"Winterfell\"}",
      "logs": null,
      "name": "45831e8d-9f00-4ce8-9a65-f3e3fe829759",
      "reason": [
          "error running function: node-echo-back-5682: request to OpenFaaS on http://gateway.openfaas:8080 failed: Post http://gateway.openfaas:8080/function/of-04ea4d64-0f6a-457f-83d0-2a4ca6c0c93c: EOF"
      ],
      "secrets": null,
      "status": "ERROR",
      "tags": []
  }

• openfaas gateway service logs include:

  2018/04/10 03:04:51 > Forwarding [POST] to /function/of-04ea4d64-0f6a-457f-83d0-2a4ca6c0c93c
  GetHeaderCode before 502
  2018/04/10 03:05:51 http: proxy error: EOF
  2018/04/10 03:05:51 < [http://faas-netesd.openfaas:8080/function/of-04ea4d64-0f6a-457f-83d0-2a4ca6c0c93c] - 502 took 60.001491 seconds
  2018/04/10 03:05:51 function=of-04ea4d64-0f6a-457f-83d0-2a4ca6c0c93c

• openfaas faas-netesd service logs include:

  2018/04/10 03:04:45 Created deployment - of-04ea4d64-0f6a-457f-83d0-2a4ca6c0c93c
  2018/04/10 03:04:45 Created service - of-04ea4d64-0f6a-457f-83d0-2a4ca6c0c93c
  2018/04/10 03:04:45 {"service":"of-04ea4d64-0f6a-457f-83d0-2a4ca6c0c93c","image":"10.35.243.233:5000/func-openfaas-04ea4d64-0f6a-457f-83d0-2a4ca6c0c93c:latest","network":"func_functions","envProcess":"","envVars":{},"constraints":[],"secrets":null,"labels":null,"limits":null,"requests":null}
  2018/04/10 03:05:51 Post http://of-04ea4d64-0f6a-457f-83d0-2a4ca6c0c93c.openfaas:8080/function/of-04ea4d64-0f6a-457f-83d0-2a4ca6c0c93c: dial tcp 10.35.249.182:8080: i/o timeout
  2018/04/10 03:05:51 [1523329491] took 60.000320 seconds

Context

This has been discovered when I removed sleep 5 from here. I'm able to consistenly reproduce it by running events tests with sleep removed.

Impact

• [ ] Low - Annoyance, but does not impact business or functionality
• [x] Medium - Issue can be worked around, but is causing pain
• [ ] High - Blocker

[kars7e]

CC @imikushin

[alexellis]

(I believe this is resolved now via the changes in the OpenFaaS codebase? We added readiness in the API. Can this be closed?)