Faas: Question about stdout and stderr within function output

[derailed]

I've build some Go based handlers and trying to build a pipeline of functions and I am seeing some surprising and totally unexpected results. I hope I am missing something here...

Say I have a function f1 that needs to call another function f2.
For instance I am building a pipeline as such: echo -n "blee" | f1() | f2() -> "blee doh"
where function f2 appends the string its given with another.

My function handlers looks something like this:

// F1
func Handle(req []byte) string {
    log.Printf("F1 called with `%s`\n", string(req))
    fmt.Println("F1 is happy as a hippo!")
       return callF2(req)
}

// F2
func Handle(req []byte) string {
    log.Printf("F2 called with `%s`\n", string(req))
    fmt.Println("F2 is happy as a hippo!")
       return string(req + " doh")
}

Expected Behaviour

echo -n 'blee' | faas invoke f1 

Yields...

blee doh

Current Behaviour

echo -n 'blee' | faas invoke f1 

Yields...

[2018/02/20 13:03:07] F1 called with blee
F1 is happy as a hippo!
[2018/02/20 13:03:07] F2 called with blee
F2 is happy as a hippo!
blee doh

NOTE: As you can see, tho I've specified I want my function to return the appended string
I am getting my logs and debug message as part of the response too?? I hope I am missing
something here as this makes it really rough to chain function especially in light of
marshalling/unmarshalling JSON in between calls! This totally hoarks my use case.

Possible Solution

Return what the user specifies no other io operations to stdout should be surfaced in the response!

Steps to Reproduce (for bugs)

1. Deploy f1 go function
2. Call f1 returns output from log.Println, fmt.Println + the returned string tho I specified return x in the call??

Context

I can't build a simple pipeline and try to mashall json responses in between function calls. Can't add
any debug stmt as this kill my json parse. This was highly surprising and unexpected. Trying to debug
my calls kills my whole pipeline!

A bigger note here is I am not really sure about the handler signature handle(string) string. At first I like
the simplicity of it, but now I am really not sure this is what's best especially in light of go function. Go provides nice constructs to formulate request/response via header, cookies, query params, etc and yet all these are gone with OpenFAAS. Resulting in having to parse out env vars and such to get the just of a function call. I think this limit this framework greatly for the use cases where one wants to configure the essence of a request ie I want to call f1 with a cookie that will affect how f1 behaves based on user input. I believe lang familiarity should be fully enable to function writers. In this case fully taking advantage of go http package make most sense as now one can leverage the full power of the language mechanics vs having to handle common http idioms via env vars. I do understand the lowest common denominator to span across langs but in the case I feel this negates the beauty and simplicity of this framework since as a function writer I really don't feel that empowered with string semantics. To boot tho I specify a return string signature this is not really my function output??

Your Environment

• Docker: 17.09
• OpenFAAS: 0.6.2
• K8s: 1.9

• Go: 1.10

• Are you using Docker Swarm or Kubernetes (FaaS-netes)?

Faasnetes

• Operating System and version (e.g. Linux, Windows, MacOS):

OSX

• Link to your project or a code example to reproduce issue:

• Please also follow the troubleshooting guide and paste in any other diagnostic information you have:

[alexellis]

The Go logging library writes to stderr.

Right now the watchdog version you are using captures both stderr and stdout for the function response. This is by design.

The of-watchdog incubator project I'm working on does not return anything printed to stderr. You are welcome to try that. It exists under the openfaas-incubator organisation and is a drop in replacement. To make use of it just edit your local templates.

[alexellis]

Derek set title: Question about stdout and stderr within function output

[alexellis]

Derek add label: question

[derailed]

Thank you @alexellis for the reference!! I'll take a look. I don't mean to sound arch here but this does not sit well with me. It feels very strange to me to aggregate the streams automatically though my function specifically return "fred". As a function writer concerns me to have any debug/log contribute to the return value of my function. To boot one could define a custom logger and log to stdout too... Right now I can't add debugs/logs and still parse the json produce by my functions. Ultimately I think the string metaphor is very limiting. Are there design decisions that were make to shy away from http.Request/Response fn signatures in Goland? It seems these would be superior constructs especially in terms of dealing with headers, authN/Z, cookies, etc... and would open this framework and fn devs to a much better place imho, as all these concerns will be next in line in faasland....

[burtonr]

@derailed, you mention Go and the HTTP framework in that language, but that is also limiting. The benefit of using the stdout is that there is no limitation to what language is used in the function. For example, I have several CLI tools that I have ported to be functions. That would be impossible if OpenFaaS only supported languages with an HTTP framework...

There is work in progress to make HTTP versions of the language templates that support it (Python, Node, C#, etc) as Alex mentioned above. You can find the repo here: https://github.com/openfaas-incubator/of-watchdog

This updated watchdog adds support for an "http mode" which I think is what you are looking for. Be sure to make note of the watchdog modes in the readme.

Also, for debugging, there are some examples of how to debug your function that may prove useful for you here: https://github.com/openfaas/faas/blob/master/guide/troubleshooting.md#watchdog

[derailed]

@BurtonR Thank you kindly for your feedback and additional info! I'll take a peek...

[alexellis]

The blog post you've written does not mention the of-watchdog instructions that I provided for you. It seems unfair that you'd omit this detail and then write negative and unrepresentative things about the project such as:

This is where the initial buzz and dev happiness started to fade a bit for me.

This was my OpenFAAS kiss of death moment right there

The of-watchdog resolves your reported issue, but you didn't try it. For full disclosure you really should say that you're writing a comparative / critical piece on a project.

The reason stderr is combined by default with stdout is that this is where error messages are supposed to be written. Our users found "exit code 1" to be ambiguous and unhelpful so requested for stderr to be combined in output by default.

The of-watchdog which you don't appear to have mentioned in the blog allows stderr to be omitted.

Replace ./template/go/Dockerfile with this Gist: https://gist.github.com/alexellis/8792b38ecd5ea60c357b6c75eaddebc2

[alex@nuc tmp]$ faas deploy -f blog1.yml  -g 127.0.0.1:8081
Deploying: blog1.

Deployed. 200 OK.
URL: http://127.0.0.1:8081/function/blog1

[alex@nuc tmp]$ curl  http://127.0.0.1:8081/function/blog1 -d test
Hello, Go. You said: test

[alex@nuc tmp]$ docker service logs blog1
blog1.1.jbgee9h5o70t@nuc    | 2018/02/24 18:38:54 OperationalMode: streaming
blog1.1.jbgee9h5o70t@nuc    | 2018/02/24 18:38:54 Writing lock file at: /tmp/.lock
blog1.1.jbgee9h5o70t@nuc    | 2018/02/24 18:38:59 Running ./handler
blog1.1.jbgee9h5o70t@nuc    | 2018/02/24 18:38:59 Started logging stderr from function.
blog1.1.jbgee9h5o70t@nuc    | 2018/02/24 18:38:59 stderr: 2018/02/24 18:38:59 Misc logging statement
blog1.1.jbgee9h5o70t@nuc    | 
blog1.1.jbgee9h5o70t@nuc    | 2018/02/24 18:38:59 Took 0.001413 secs

You're entitled to your opinions but I think it is unreasonable to push false information.

[derailed]

Hi @alexellis Thanks for the feedback! You are totally correct my bad! I've meant to mention it in the post and spaced it. I will definitely try the new watchdog just ran out of time. I did not add it as this was not my out of the box experience. Thanks for calling me on this! I will correct the post and add the reference right away. Thanks Alex!!

[alexellis]

Derek close: inactive