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?)