fmt: %x verb interacts badly with types having a String method

[bjames2011]

Environment

What version of Go are you using?

> go version
go version go1.6.2 linux/amd64

Does this issue reproduce with the latest release?

Unknown - the Go playground code example, doesn't reproduce the behaviour I see locally (on Linux AMD64) - probably because the underlying OS/arch on the Go playground is not the same as my machine and hence my hard-coded example value (0x137f) is completely meaningless.

What operating system and processor architecture are you using?

> go version
go version go1.6.2 linux/amd64
bjames@yoga:~/Dropbox/go/src/bcj/process_trace$ go env
GOARCH="amd64"
GOBIN=""
GOEXE=""
GOHOSTARCH="amd64"
GOHOSTOS="linux"
GOOS="linux"
GOPATH="/home/bjames/Dropbox/go"
GORACE=""
GOROOT="/usr/lib/go-1.6"
GOTOOLDIR="/usr/lib/go-1.6/pkg/tool/linux_amd64"
GO15VENDOREXPERIMENT="1"
CC="gcc"
GOGCCFLAGS="-fPIC -m64 -pthread -fmessage-length=0"
CXX="g++"
CGO_ENABLED="1"

What did you do?

Here's the code I'm using to print a stop signal in various formats:

var ws syscall.WaitStatus  = 0x137f
fmt.Printf( "   var ws syscall.WaitStatus = 0x%0x\n",  ws )
fmt.Printf( "   ws.Stopped                 %%t      %t\n",     ws.Stopped() )
fmt.Printf( "   ws.StopSignal()            %%0d     %0d\n",    ws.StopSignal() )
fmt.Printf( "   ws.StopSignal()            0x%%0x   0x%0x\n",  ws.StopSignal() )
fmt.Printf( "   uint32(ws.StopSignal())    0x%%0x   0x%0x\n",  uint32(ws.StopSignal()) )
fmt.Printf( "   ws.StopSignal()            0b%%0b   0b%0b\n",  ws.StopSignal() )
fmt.Printf( "   ws.StopSignal().String()   %%s      %s\n",     ws.StopSignal().String() )

This produces the following output (see syscall_linux.go):

var ws syscall.WaitStatus = 0x137f
ws.Stopped                 %t      true                                  << Correct
ws.StopSignal()            %0d     19                                    << Correct
ws.StopSignal()            0x%0x   0x73746f7070656420287369676e616c29    << Pure madness!
uint32(ws.StopSignal())    0x%0x   0x13                                  << Correct, but the cast shouldn't be necessary
ws.StopSignal()            0b%0b   0b10011                               << Correct
ws.StopSignal().String()   %s      stopped (signal)                      << Correct

What did you expect to see?

Given that the underlying type of syscall.WaitStatus is uint32, I expect that ws.StopSignal() and uint32(ws.StopSignal()) should both print identically.

Expected:

ws.StopSignal()            0x%0x   0x13

What did you see instead?

ws.StopSignal()            0x%0x   0x73746f7070656420287369676e616c29

[bjames2011]

I've narrowed the issue down to the following:

package main

import (
	"fmt"
	"syscall"
)

func main() {
	fmt.Printf("syscall.Signal(19)         %%0d     %0d\n", syscall.Signal(19))
	fmt.Printf("syscall.Signal(19)         0x%%0x   0x%0x\n", syscall.Signal(19))
}

...which gives the following ouput:

syscall.Signal(19)         %0d     19
syscall.Signal(19)         0x%0x   0x73746f7070656420287369676e616c29

[ALTree]

Fun fact: the strange 0x73746f7070656420287369676e616c29 number you are seeing is the output of

b := "stopped (signal)"
fmt.Printf("%x\n", b)

The "stopped (signal)" string is generated by the String method of Signal.

Here's a small reproducer:

package main

import (
	"fmt"
)

type S int

func (s S) String() string {
	return "I'm a string!"
}

func main() {
	var s S = 42
	fmt.Printf("%d\n", s)
	fmt.Printf("0x%x\n", s)
}

output:

42
0x49276d206120737472696e6721

[bjames2011]

So it would appear that fmt.Printf() is somehow ignoring the field specifier ("%x") and calling arg.String() instead?

[ALTree]

is somehow ignoring the field specifier ("%x")

I'd say that it's not ignoring it. It's applying it, not on the variable itself, but on the output of the variable's String method.

Is it supposed to behave like this? I think it is. The doc says:

If the format [..] is valid for a string (%s %q %v %x %X), the following two rules apply:

4. [..]

5. If an operand implements method String() string, that method will be invoked to convert the object to a string, which will then be formatted as required by the verb (if any)

Since the format you are using (%x) is valid for a string, the fmt package is calling the String method and then applying the %x verb to it. This does not happen when you use a cast because after the cast the variable's type is no longer Signal, it's uint32, which does not have a string method.

[bjames2011]

I see.

Seems like an Interesting combination of factors that leads to a break in POLA as far as the user is concerned.

Thanks for explanation.

[ALTree]

I think the main point here is: should %x be in the list of the formats that trigger a call to the type's String method?

It's obvious that the current rules play nicely with fmt.Printf("%s\n", s), because you're asking for string formatting. It's much less obvious to me that this is worth it for the %x / %X verbs. Yes, you can use them to print a string, but I feel that most Go users would only use %x to hex-format integer numbers. And they'll be bitten by the current behaviour when using an int-like type that implements String.

It could make sense to remove %x / %X from the list of verbs that trigger a String call.

Not for go1, obviously, but maybe something to keep in mind for go2.

[bjames2011]

It could make sense to remove %x / %X from the list of verbs that trigger a String call.

That would be my choice, however I don't have an appreciation for "Thinking in Go" (as Bruce Eckel might say) yet and therefore only have the assumptions brought from a background in C - i.e. thinking "hmm, storage type is a uint32, how do I tell printf how to interpret the storage type"

[bjames2011]

In general, I'd say that if the underlying type can be interpreted directly by the verb (e.g. %x), then it doesn't make sense to me to indirectly interpret the value by invoking any method (String() or otherwise) on the value.

[josharian]

@robpike

[martisch]

Making %x/%X special vs other string verbs (and adding another edge case to fmt rules) does not seem to warrant breaking existing code with go2 for.

A type can satisfy the Stringer interface to be able to effect the output of fmt, that is an option. If the types value should be printed directly the Stringer interface can be left unimplemented or the Formatter interface can be implemented for more fine grained control.

If the types String method should not be used by fmt with %x or %X verbs the type can satisfy the Formatter interface and return another value depending on the verb.

Removing calling the String method in fmt in its current form would break a large amount of go programs (probably all that use logging or custom error strings).

fmt mostly knows how to interpret the values directly and can print the underlying structure with %#v.

The default that simple string verbs and %v call the String method (if it exists) seems more useful as it usually provides human readable output by default.

Otherwise:

fmt.Printf("%v", time.Now())

would print something like {63393490800, 0, 0x177380} as the direct interpretation
instead of 2009-11-10 23:00:00 +0000 UTC.

[ALTree]

@martisch thanks for the feedback.

Considering the scarce budget for changes an hypothetical go2 would have, it makes sense to use that budget for changes that will bring a clear benefit to the Go users, and are largely uncontroversial; the change proposed above clearly does not meet those requirements.

If we're not going to keep this issue as a go2 reminder (and I'm okay with that), I guess we can close it.

[bjames2011]

@martisch

Making %x/%X special vs other string verbs...

Based on the documentation %x and %x are both string verbs and integer verbs - and in this case, I would argue that because the type is an integer, but only implements a Stringer interface (String() method), it should be considered an integer first and foremost.

A type can satisfy the Stringer interface to be able to effect the output of fmt, that is an option.

In the example I gave above, the type (WaitStatus) does implement a Stringer interface - exactly because the underlying integer type can reasonably be represented by a string, but that does not mean it should be treated as a string.

Fundamentally, in the example I gave above...

This:
type(uint32) -> representation(string) -> representation(hex)

...takes precedence over this:
type(uint32) -> representation(hex)

Which seems a little bit bonkers - the author of the WaitStatus type intended it to be human-readable when printed, but I'm fairly sure they had no intention for it to be unintentionally treated as a different type.

If I can make an analogy to Python - this feels like fmt is calling __str__() (give me a human-readable string) and interpreting the output as that of __repr__() (give me a string which unambiguously describes the actual data value).

Removing calling the String method in fmt in its current form would break a large amount of go programs (probably all that use logging or custom error strings).

I'm not necessarily suggesting removing calling of String(); given that %x/%X can be applied to both integers and strings, wouldn't it make sense for the precedence order to be type first, then representation?

fmt mostly knows how to interpret the values directly and can print the underlying structure with %#v.

OK, but isn't that a bit non-sequitur? The use-case here is "print this integer type in hex format". I don't understand how %v comes into play. Apologies if I'm missing something obvious to more seasoned Go-ers out there. :-)

Also (from the specification):

"Package fmt implements formatted I/O with functions analogous to C's printf and scanf. The format 'verbs' are derived from C's but are simpler."

This is somewhat of a misleading statement.

I appreciate this is probably a bit of a sticky one and I can understand not wanting to change something that might have many dependencies. I'm also very aware of holding a fairly ignorant and idealist "but why doesn't the logical thing work" viewpoint (where "logical" is loaded with presumptions based on having used an array of other languages that work differently).

[martisch]

The valued passed to fmt is not of type uint32 but has type WaitStatus
https://play.golang.org/p/srPPm7oyq7

The call to fmt is fmt.Printf("%X\n", ws) -> "print this WaitStatus type in hex format"
"print this integer type in hex format" is fmt.Printf("%X\n", uint32(ws)).

[martisch]

@ALTree
I think if the issue is meant as a bug report then it can be closed as %x/%X is document and consistent behavior.

If this is a proposal than i think it needs to be refined to be clearer what the problem is and what the concrete proposed change of behavior in fmt is.

[bjames2011]

The valued passed to fmt is not of type uint32 but has type WaitStatus

Yes, that is very true, however WaitStatus is "derived" (n.b. terminology here is probably way off) from a uint32 and - in my mind at least - is "more of a uint32 than a string".

It feels like the summary of this ticket is "yeah, maybe the current implementation is a bit counter-intuitive in some cases, but changing it would be a huge pain, so let's not".

[bjames2011]

If this is a proposal than i think it needs to be refined to be clearer what the problem is and what the concrete proposed change of behavior in fmt is.

I would hope that the problem is clear. I do not, however, have a complete proposal that might "fix" this.

[ALTree]

@martisch not really a proposal (not from me, at least) I was just thinking out loud about the possibility of making this less unintuitive. I agree it's probably not worth it. So as far as I'm concerned we can close this.

[bjames2011]

So as far as I'm concerned we can close this.

No problem. Thanks all for considering this ticket and for the open discussion.

[robpike]

In this case it's a little odd, but it is indeed working as intended.