[SR-11001] Collections description ends up invoking debugDescription of elements

[ktoso]

Previous ID	SR-11001
Radar	rdar://problem/63898476
Original Reporter	@ktoso
Type	Bug

Additional Detail from JIRA

Votes	3
Component/s	Standard Library
Labels	Bug
Assignee	None
Priority	Medium

md5: 1d0d6cf976a9b368d4533a89dca6f9ab

Issue Description:

Swift version Apple Swift version 5.0-dev (LLVM f961e3dd74, Swift ff641d3)

Let's say I have a carefully designed type with information which is definitely enough for users to identify and observe a value, as well as some "very internal, noone should care, unless debugging" state:

  1> struct Thing: CustomStringConvertible, CustomDebugStringConvertible {
  2.     let name: String
  3.     let _hidden: String
  4.     let _dontTellAnyone: String
  5.     public var description: String {
  6.         return "DESC: \(name)"
  7.     }
  8.     public var debugDescription: String {
  9.         return "DEBUG: \(name) \(_hidden) \(_dontTellAnyone)"
 10.     }
 11. }
 12> let thing = Thing(name: "Bob", _hidden: "hello long text", _dontTellAnyone: "so many words!!!")
thing: Thing = {
  name = "Bob"
  _hidden = "hello long text"
  _dontTellAnyone = "so many words!!!"
}

Printing the type works as expected:

 13> "\(thing)"
$R0: String = "DESC: Bob"
 14> ["\(thing)"]
$R1: [String] = 1 value {
  [0] = "DESC: Bob"
}

Yet printing it as part of a collection now, which users of my library may happen to do:

 15> "\([thing])"
$R2: String = "[DEBUG: Bob hello long text so many words!!!]"

Now all that carefully hidden state is being printed while invoking the collection's `.description` ⚠️

---

This seems like an omission / confusion;

Current behavior

 16> String(describing: [thing])
$R3: String = "[DEBUGL Bob hello long text so many words!!!]"
 17> String(reflecting: [thing])
$R4: String = "[DEBUGL Bob hello long text so many words!!!]"

Expected behavior

 16> String(describing: [thing])
$R3: String = "[DESC: Bob]"
 17> String(reflecting: [thing])
$R4: String = "[DEBUGL Bob hello long text so many words!!!]"

The reason this happens seems to be that all collections share an implementation here, which ends up calling debugPrint(item, regardless if debug printing or not: https://github.com/apple/swift/blob/e9d827ca3c809f511ebb53d169d6ce11d396eec3/stdlib/public/core/ArrayShared.swift#L83

Happy to work on a fix if this indeed was an oversight and not intended behavior (albeit quite weird one then).

[swift-ci]

Comment by Jens Jakob Jensen (JIRA)

I vote for this being a bug and not a new feature.

[belkadan]

Collections deliberately call debugPrint in their description because a number of simple model types print in ways that don't make their structure obvious. Consider a collection of two strings: "A, B" and "1, 2". If you printed these in an Array using their description, the output would be [A, B, 1, 2] and it would look like an array of four items. You can see a bit more discussion about this in SR-2062.

[swift-ci]

Comment by Jens Jakob Jensen (JIRA)

Would it be possible to fix that in another way? I.e. what if a custom debugDescription contained a comma like e.g. just, wondering -> [1, 2, just, wondering, 4]? Aren't this solution just hiding the issue a bit, making it harder to grasp? Perhaps it's the responsibility of the array description to somehow escape these?

I really think String(describing:``) should avoid using debugDescription. But I'm probably not seeing the whole picture 🙂

[belkadan]

Why does it matter, though? A collection's description already isn't suitable for anything in particular.

(cc @airspeedswift and @jckarter)

[ktoso]

I can see the intent behind trying to make ["A, B", "C"] output "nice" but it also breaks the reasonable expectation of consistency that:

• ".description invokes .description",

• ".debugDescription invokes .debugDescription"

For reference the outputs are in CLI/Playgrounds:

 16> thing
$R0: Thing = {
  name = "Bob"
  _hidden = "hello long text"
  _dontTellAnyone = "so many words!!!"
}
 17> "\(thing)"
$R1: String = "DESC"
 18> String(describing: thing)
$R2: String = "DESC"
 19> String(reflecting: thing)
$R3: String = "DEBUG"
 20> String(describing: [thing])
$R4: String = "[DEBUG]"
 21> String(reflecting: [thing])
$R5: String = "[DEBUG]"

thing // DEBUG // ok, makes sense; we are interactive and inspecting after all
"\(thing)" // "DESC" // ok, the string repr is the .description after all

String(describing: thing) // "DESC" // ok
String(reflecting: thing) // "DEBUG" // ok

String(describing: [thing]) // "[DEBUG]" // weird (!)
String(reflecting: [thing]) // "[DEBUG]" // ok, I requested "debug info"

> Why does it matter, though? A collection's description already isn't suitable for anything in particular.

From my perspective there's two or three use cases when people might see such printouts:

• testing, when I expect some array to be equal to another one -> here the debugDescription likely is helpful; e.g. error: ["Hell", "o"] does not equal expected: ["Hello"]; testing libs can and do invoke the .debugDescription

• "playing around in repl or trying to understand a thing by printing out what state things are in" aka. "println debugging" which we may laugh about but everyone's done it at some point; playgrounds already do invoke the .debugDescription for jut printing a value; for a "(value)" they do the right thing

• logging, where people might want to log what things they have (the "things" example is a bit fuzzy here, but the reason for this ticket is that I've been logging things in my library, and suddenly had the debug representations printed, where I expected the "user friendly ones", since the values were in an array); here I'd very likely want to always get the "normal" representation, regardless if accidentally somewhere somehow the value happened to be stored in a collection

---

If we are mostly worried about string outputs in collections, perhaps as Hugin777 (JIRA User) suggests, it should be the collection's `.description` implementations task to do something about it? (escape)

—

What it comes down to for libraries I think is this:

If we can't reasonably expect that .debugDescription is only called from "debug situations", since collections may call it from .description, then I can't use .debugDescription at all for the "show all the information about this value" use case.

Since it may print out all the internal complex details that my types abstract away for not-expecting users which just wanted to log "what are my things?", and the things happened to be in a collection, while printing them one by one is totally fine...

It would feel wrong to have to tell users "you can include this value in your logs, but whoa, better don't log a collection of them!", so we'd have to make sure the "not scary" output happens in those cases as well by not using CustomDebugStringConvertible at all. Which may be an answer, but it is a bit weird / inconsistent.

On the other hand, since playgrounds always invoke .debugDescription, we may need to stop printing the "all the details" in any case anywhere, since it'd look scary to users playing with such library in Playgrounds...

[dabrahams]

This part of Swift was very intentionally designed as it is, modeled on Python.

In [22]: class X(object):
    ...:     def __repr__(self): return 'repr' # analogous to debugDescription
    ...:     def __str__(self): return 'str'   # analogous to description
    ...:

In [23]: str([X(), X()])
Out[23]: '[repr, repr]'

The reason for this design is that preserves a number of properties that I consider to be essential to an understandable experience for users:

• print("foo") ⟹ foo

• debugPrint("foo") ⟹ "foo"

• print(["foo"]) ⟹ ["foo"]

where

• print(String(describing: a)) is equivalent to print(a)

• print(String(reflecting: a)) is equivalent to debugPrint(a)

If there's another design that preserves these output properties and achieves the requested consistency, I'd have no objection, but I cannot imagine most users being willing to sacrifice these properties in order to get more consistent dispatching of functionality to description/debugDescription.

[ktoso]

Thanks for more background here Dave. I can definitely see that as being desirable when explained like that.

Could we somehow improve documentation, be it here https://developer.apple.com/documentation/swift/customdebugstringconvertible or elsewhere to give these examples (explaining that this is one purpose, and for those reasons)?

It would have helped a lot when deciding if and how to conform to this protocol. In my case, it is datastructures which will definitely be printed and logged by users a lot, yet they really never should care about many fields those structures have (and thus I should not show them in neither description or debugDescription is my conclusion today then).

More in general my takeaway from this discussion is that "description"/"debugDescription" should not be used to hide/show fields which you'd not want users to see in "normal day to day programming" (which is how we understood those protocols when we started out adopting them). And rather, as the docs do suggest – but I didn't quite get the message when first reading it, without the context from this ticket – one would want also not show that "not important for normal users" field in debugDescription, but only leave it to be seen in it's mirror and debugging etc.

Would that be a fair characterization of how to best to view the print capabilities?

[natecook1000]

Perhaps the issue lies in the fact that we're using two customization points to describe three or four different concepts:

1. a standalone string representation

2. a string representation when included as part of an aggregate

3. a standalone "debugging" string representation (which is vague and ill-defined)

4. a "debugging" string representation when included as part of an aggregate

We don't seem to have consensus that #3 is usable for #2, despite that being what Swift does today.

[ktoso]

Hey Nate, yeah I think that's the root problem...

I could always work around all this by doing func prettyDescription (which i have in some spots I guess already), to avoid having the pretty formated output happen via debugDescription (because those datatypes always end up in collections in logs, and there I don't want any \n).

It feels a bit off that for actual interactive println debugging debugDescription is not what I'd use, but the "pretty" one, but that's fine... Looking forward to see if we could consider such protocol for "print me pretty" for Dave's pprint proposal.

[dabrahams]

I don't think it would be entirely unreasonable to handle aggregate elements via a special case for things conforming to StringProtocol, rather than by going through a different hook, FWIW.

Strings are just different from other things in that their printed representations are too irregular to be presented among other data without qualification by quotes and escapes.

[weissi]

I'm with @ktoso here and really like @dabrahams suggestion. I feel it's pretty strange to call debugDescription from a description method, in fact everybody seems to be surprised when that is mentioned. The [String] argument that ["foo, bar", "buz"] shouldn't print as [foo, bar, buz] of course makes sense but Dave's suggestion provides an easy workaround for this.

@natecook1000's 3/4 concepts in 2 customisation points seems to indeed be the core issue.

The current solution however means that debugDescription can't really be used to give a very verbose description for debugging because if something ever ends up in a collection, all of that gets printed 🙁.

[ktoso]

@swift-ci create