swiftlang / swift

The Swift Programming Language
https://swift.org
Apache License 2.0
67.5k stars 10.35k forks source link

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

Open ktoso opened 5 years ago

ktoso commented 5 years ago
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 ff641d3965)

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 commented 5 years ago

Comment by Jens Jakob Jensen (JIRA)

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

belkadan commented 5 years ago

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 commented 5 years ago

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 commented 5 years ago

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

(cc @airspeedswift and @jckarter)

ktoso commented 5 years ago

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

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:


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 commented 4 years ago

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:

where

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 commented 4 years ago

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 commented 4 years ago

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 commented 4 years ago

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 commented 4 years ago

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 commented 4 years ago

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 commented 4 years ago

@swift-ci create