gopherdata / gophernotes

The Go kernel for Jupyter notebooks and nteract.
MIT License
3.8k stars 264 forks source link

Potential bug with golang 1.13, fmt.Println returns printed text plus <nil> #179

Closed Mathis001 closed 4 years ago

Mathis001 commented 4 years ago

I'm running into an interesting bug that may be related to the newest version of golang (version 1.13 released 9/3). I can get gophernotes installed, and it works as a kernel, but doing a hello world test returns some extraneous results.

[1]:    import "fmt"
[2]:    fmt.Println("hello world")
        hello world
[2]:    12 <nil>

What's interesting is the number appears to be the number of characters + 1. Here is another result showing the number changing:

[1]:    import "fmt"
[2]:    fmt.Println("test")
        test
[2]:    5 <nil>

This happens both in a notebook, and in the console view in Jupyter Lab. I can supply screenshots of this or any other logs as necessary. I ran a similar go file from the command line to confirm this isn't an issue with my golang install:

// helloworld.go
package main
import "fmt"

func main() {
    fmt.Println("hello world")
}
$ go run helloworld.go
hello world

Here is the relevant information to help duplicate this issue:

OS Info:

Ubuntu 18.04
4.15.0-60-generic

ZeroMQ 4.X.X Info:

libzmq3-dev is already the newest version (4.2.5-1ubuntu0.2)

golang 1.13 info:

$ go version
go version go1.13 linux/amd64
$ go env
GO111MODULE=""
GOARCH="amd64"
GOBIN=""
GOCACHE="/home/jupyter/.cache/go-build"
GOENV="/home/jupyter/.config/go/env"
GOEXE=""
GOFLAGS=""
GOHOSTARCH="amd64"
GOHOSTOS="linux"
GONOPROXY=""
GONOSUMDB=""
GOOS="linux"
GOPATH="/home/jupyter/go"
GOPRIVATE=""
GOPROXY="https://proxy.golang.org,direct"
GOROOT="/usr/local/go"
GOSUMDB="sum.golang.org"
GOTMPDIR=""
GOTOOLDIR="/usr/local/go/pkg/tool/linux_amd64"
GCCGO="gccgo"
AR="ar"
CC="gcc"
CXX="g++"
CGO_ENABLED="1"
GOMOD=""
CGO_CFLAGS="-g -O2"
CGO_CPPFLAGS=""
CGO_CXXFLAGS="-g -O2"
CGO_FFLAGS="-g -O2"
CGO_LDFLAGS="-g -O2"
PKG_CONFIG="pkg-config"
GOGCCFLAGS="-fPIC -m64 -pthread -fmessage-length=0 -fdebug-prefix-map=/tmp/go-build422422188=/tmp/go-build -gno-record-gcc-switches"

Jupyter info:

$ jupyter --version
jupyter core     : 4.5.0
jupyter-notebook : not installed
qtconsole        : not installed
ipython          : 5.8.0
ipykernel        : 4.10.1
jupyter client   : 5.3.1
jupyter lab      : not installed
nbconvert        : 5.3.1
ipywidgets       : not installed
nbformat         : 4.4.0
traitlets        : 4.3.2

I'd appreciate any help with this, thanks!

SpencerPark commented 4 years ago

Thanks for the extensive info related to this report!

This behavior is expected even if not necessarily desired in this particular case. fmt.Println returns the number of bytes printed and a error. In the cases you are observing, it is one byte per character and an extra for the newline. No write errors occurred so the returned error is nil.

When an expression is written on the last line, the Out of the cell is the value of that expression. In this case the expression is the function call with the side effect of printing the argument. This behavior is consistent with how interaction with the console is expected to behave. Writing an expression should return the result.

Simply leaving "test" on the last line, adding a double semicolon fmt.Println("test");; such that the last statement is actually empty, or using println should work as expected.

Mathis001 commented 4 years ago

Hey Spencer,

Thanks so much for the explanation, doing the double semicolon at the end works as you describe. I'm new to the golang, and I've tried looking into this a bit more, and apparently the lexer inserts them as necessary:

https://golang.org/doc/effective_go.html#semicolons

It looks like omitting these semicolons is good practice when writing in the golang, with the understanding that the lexer will take care of them. Is there a reason that in my case, it doesn't appear that the lexer is inputting the required semicolons? I ran a similar test which is in this repo's readme that shows not needing to add the semicolons:

https://raw.githubusercontent.com/gopherdata/gophernotes/master/files/jupyter.gif

Running the same commands as shown here I still get the number of bytes and , despite this gif showing just the variable being printed. Is there a way to get the behavior seen in this gif, as it seems to be closer to what the corresponding golang code would look like?

In any rate, thanks for your quick reply!

SpencerPark commented 4 years ago

No problem :) Unfortunately it looks like the README is a bit out of date with respect to that demo... the internals of gophernotes code evaluation has changed quite a bit since the recording.

In gophernotes we are using gomacro for interpreting the Go code. It does a fantastic job of running Go in a REPL as is the case in Jupyter. The semicolons I suggested are more of a hack than a solution and are certainly not necessary in general.

The important thing to remember is how the last expression is evaluated. Consider the case where you are using gophernotes with the Jupyter console. The expected behavior when writing an expression is that the result is returned:

In[1]:  1 + 2
Out[1]: 3

Similar is the case when making it a bit more indirect such as calling a function:

In[1]:  func Add(x, y int) int {
            return x + y
        }
In[2]:  Add(1, 2)
Out[2]: 3

When in a notebook, cells get a bit longer and the previous example could merge those 2 inputs into one, but still the last expression should be evaluated and the result is the Out.

In[1]:  func Add(x, y int) int {
            return x + y
        }
        Add(1, 2)
Out[1]: 3

If the last line was instead fmt.Println("test"), it is not clear why the result of calling this function in particular would have any different behavior. It returns a value (2 actually) and therefore that value is the result of executing the cell so it goes in the Out.

Adding the extra semi colon just tricks the interpreter into reading the code as:

fmt.Println("test");
/*empty*/;

in which case the last expression is instead an empty statement which has no result. The regular Go semantics apply to the previous statement which just ignores the return values.

Some other options for completeness to help get a feel for how these last expression semantics are working.

In[1]:  fmt.Sprintln("test")
Out[1]: test
In[1]:  _, _ := fmt.Println("test")
test

Some what of a long winded answer but I hope it helps clear some things up, feel free to ask again for some clarification if necessary!