Go - Inconsistent Evaluation of Deferred Functions

Question

I am experimenting with Go and am seeing some unexpected behaviour with deferred functions. Consider the following program that increments a global variable by a given amount.

package main

import "fmt"

var z = 1

func main() {

    defer increaseZ(10)
    defer fmt.Println("z =", increaseZ(20), "Deferred Value 1")
    defer fmt.Println("z =", increaseZ(30), "Deferred Value 2")

    fmt.Println("z =", z, "Main Value")
}

func increaseZ(y int) int {
    z += y
    println("z =", z, "Inside Increase Function")
    return z
}

When run in the go playground, this outputs:

z = 21 Inside Increase Function
z = 51 Inside Increase Function
z = 61 Inside Increase Function
z = 51 Main Value
z = 51 Deferred Value 2
z = 21 Deferred Value 1

If I switch the order of the deferred functions, it has another effect:

defer fmt.Println("z =", increaseZ(20), "Deferred Value 1")
defer fmt.Println("z =", increaseZ(30), "Deferred Value 2")
defer increaseZ(10)

Outputs:

z = 21 Inside Increase Function
z = 51 Inside Increase Function
z = 51 Main Value
z = 61 Inside Increase Function
z = 51 Deferred Value 2
z = 21 Deferred Value 1

The Go documentation states:

The deferred call's arguments are evaluated immediately, but the function call is not executed until the surrounding function returns.

So arguments being evaluated, may explain why the Main Value returned is 51 and not 61, since the fmt.Println statements are taking increaseZ as an argument, but defer increaseZ(10) would not be called until after the main function returns.

However, this does not explain why in the first example the increaseZ(10) is outputting before main has completed, and after main has completed in the second example.

I would be grateful if anyone could help me understand what is happening here, since this looks like fertile ground for difficult to diagnose bugs further down the line.

Answer 1

You are being inconsistent in your print destination.

stdout: fmt.Println

stderr: println

Write to the same print destination.

package main

import "fmt"

var z = 1

func main() {

    defer increaseZ(10)
    defer fmt.Println("z =", increaseZ(20), "Deferred Value 1")
    defer fmt.Println("z =", increaseZ(30), "Deferred Value 2")

    fmt.Println("z =", z, "Main Value")
}

func increaseZ(y int) int {
    z += y
    fmt.Println("z =", z, "Inside Increase Function")
    return z
}

Output:

z = 21 Inside Increase Function
z = 51 Inside Increase Function
z = 51 Main Value
z = 51 Deferred Value 2
z = 21 Deferred Value 1
z = 61 Inside Increase Function

or,

package main

import (
    "fmt"
    "os"
)

var z = 1

func main() {

    defer increaseZ(10)
    defer fmt.Fprintln(os.Stderr, "z =", increaseZ(20), "Deferred Value 1")
    defer fmt.Fprintln(os.Stderr, "z =", increaseZ(30), "Deferred Value 2")

    fmt.Fprintln(os.Stderr, "z =", z, "Main Value")
}

func increaseZ(y int) int {
    z += y
    println("z =", z, "Inside Increase Function")
    return z
}

Output:

z = 21 Inside Increase Function
z = 51 Inside Increase Function
z = 51 Main Value
z = 51 Deferred Value 2
z = 21 Deferred Value 1
z = 61 Inside Increase Function

Answer 2

It's not about deferred evaluations. It's about printing. println function documented for completeness but are not guaranteed to stay in the language at all. Also Stdout and Stderr merged in one stream on Playground by design. If you use fmt.Println(...) everywhere http://play.golang.org/p/PU3hxHCazA or explicitly define fmt.Fprintln(os.Stdout, ... http://play.golang.org/p/OQpOQR2vm0 things would work as expected.

Answer 3

I suspect this is a bug with the Go playground. When I compile and run this program on my machine, it yields the expected output. A bug report pertaining this issue has been filed.