211: Logging
00:00:00
◼
►
Welcome to Under the Radar, a show about independent iOS app development.
00:00:04
◼
►
I'm Marco Arment.
00:00:06
◼
►
And I'm David Smith. Under the Radar is never longer than 30 minutes, so let's get started.
00:00:10
◼
►
So, we need to log an event that we have started the show, duly noted.
00:00:14
◼
►
And then when the show ends, we'll log another event that the show has ended.
00:00:18
◼
►
And we can use this to make our event log for our podcast.
00:00:22
◼
►
This is... [laughs]
00:00:24
◼
►
Logging in apps is about as exciting as this intro has been so far.
00:00:29
◼
►
But it actually... I have found it to have some significant value.
00:00:33
◼
►
And some context here for what I'm talking about is...
00:00:37
◼
►
There's been all sorts of logging frameworks that you can embed into your app
00:00:41
◼
►
to go beyond just like nslog and to actually have things like
00:00:45
◼
►
different logs for different things, to have different subsystems of your app
00:00:49
◼
►
be logging in different ways, customization of how and where they're logged,
00:00:53
◼
►
persistence of logs, maybe some display of the log on device
00:00:57
◼
►
for debugging or including in beta bug reports and stuff like that.
00:01:02
◼
►
And I recently started diving into this world, I guess re-diving into it.
00:01:07
◼
►
A long time ago I used... What was that one? Cocoa Lumberjack?
00:01:11
◼
►
I used that forever ago.
00:01:13
◼
►
That sounds right, but that feels like a very long time ago.
00:01:15
◼
►
Yeah, and I don't even know... I think it's still maintained, but I haven't used it in a while.
00:01:20
◼
►
But in the latest Overcast Beta series, part of this update to the app
00:01:25
◼
►
is that I rewrote a whole bunch of subsystems, or at least I refactored or modernized them
00:01:30
◼
►
in significant ways. Many of the subsystems of the app are now
00:01:35
◼
►
rewritten in Swift, many of them are, if not rewritten, at least now interacting
00:01:40
◼
►
with rewritten components, so there's been a lot of changes under the hood.
00:01:45
◼
►
And as part of my testing and quality control process, I wanted to have some kind of
00:01:50
◼
►
persistent logging, that I could log stuff that happened in the app,
00:01:55
◼
►
and importantly on the watch app, I could log them to a file somewhere in the app's control
00:02:00
◼
►
and then I could have that file be emailed to me if people had bug reports,
00:02:05
◼
►
or they could paste it into the slack, or I could even just look at it and see with my own app,
00:02:10
◼
►
like, what's going on with my app when I'm not connected to Xcode?
00:02:15
◼
►
Like, what happens overnight? Do I get the background refreshes and stuff like that?
00:02:20
◼
►
And so I built out, of course, because it's me, I built out my own custom logging thing.
00:02:25
◼
►
Of course. And it's very simple.
00:02:30
◼
►
Part of the reason I do these things myself so often is that I want things to be
00:02:35
◼
►
exactly what I need, but no more than that. I like things to be very simple.
00:02:40
◼
►
And so my logging quote framework is one file and I think it's, you know,
00:02:45
◼
►
maybe a hundred lines of code. There's not much to it, but it's good for me.
00:02:50
◼
►
And the main difference between it and just nslog is persistence to a file,
00:02:55
◼
►
and that's about it. Pretty much everything else about it is pretty basic.
00:03:02
◼
►
Just, you know, printing formatted strings with timestamps on them.
00:03:07
◼
►
But I have found this to be an incredibly useful tool,
00:03:12
◼
►
not only for just general app quality, but also just to see, like,
00:03:17
◼
►
the things I've rewritten. Are they working right? You know, are, like, what,
00:03:22
◼
►
how are they behaving? Are they behaving the way I intended them to behave?
00:03:27
◼
►
And is there anything about them that is either, you know, that either is broken
00:03:30
◼
►
or that needs improvement or that could be improved?
00:03:33
◼
►
And I've found a number of these throughout my Overcast Beta process so far,
00:03:38
◼
►
thanks to this log that I added. I mean, I just added it maybe a few weeks
00:03:43
◼
►
or a month ago, so it's actually been pretty recent. But I'm curious, Dave,
00:03:47
◼
►
do you do anything like this? Any kind of, like, persistent logging and, you know,
00:03:50
◼
►
bug report log attachment kind of stuff?
00:03:53
◼
►
So I use it, but only internally. Like, I've never built something like this
00:03:56
◼
►
in a way that it has ever customer-facing or even beta customer-facing.
00:03:59
◼
►
It's always been something that, and I think especially, again, on the watch,
00:04:04
◼
►
it's a situation where I found, I know when I was developing a lot of workout
00:04:08
◼
►
stuff on the watch, there was a lot, it was just the nature of doing workouts
00:04:12
◼
►
was that it was very inconvenient to be connected to Xcode while I was, like,
00:04:16
◼
►
going for an outdoor run. And so I needed to build a bunch of, you know,
00:04:21
◼
►
like, essentially persistent logging into the application just to the degree
00:04:26
◼
►
that I could, like, keep track of what was going on and, you know,
00:04:31
◼
►
identify any bugs or issues or make sure that things were writing to HealthKit correctly.
00:04:34
◼
►
And so I've done it in that sense, but it's never been something that I've sort of
00:04:39
◼
►
wrapped up to a point where it would ever be, you know, had a nice, pretty exterior to it.
00:04:42
◼
►
Mostly what I'm doing is just, like, you know, turning on iTunes file sharing
00:04:47
◼
►
and having the app just, like, dump a log file into the app's documents directory
00:04:53
◼
►
that I can pull out from Finder.
00:04:58
◼
►
But it is one of those funny things that I feel like, you know,
00:05:01
◼
►
if ultimately the best way to, like, debug a view is to put a border around all your views.
00:05:04
◼
►
And the best way to debug logic or sort of anything slightly more complicated
00:05:09
◼
►
is with, like, logging statements.
00:05:14
◼
►
Like, every year Apple comes out with these amazing cool things in Xcode
00:05:16
◼
►
where it's, like, their crazy view debugging thing or the memory architecture
00:05:19
◼
►
or all these things that they've come up with and they keep improving the logging system.
00:05:21
◼
►
I mean, that's cool, but, like, I find in day-to-day practice,
00:05:26
◼
►
like, a good, well-placed log statement is just worth its weight in gold.
00:05:29
◼
►
So it's kind of one of those funny things about being a developer,
00:05:34
◼
►
is that, like, you know, when I was in the early days of developing,
00:05:36
◼
►
maybe I thought I was like, "Oh, this is just like what noobs like me do."
00:05:40
◼
►
But now it's like I'm less of a beginner at this,
00:05:43
◼
►
but I still, you know, my apps are constantly filled with log statements
00:05:46
◼
►
and it's such a useful way to visualize kind of turning the sort of multidimensional complexity
00:05:51
◼
►
of an application into just a linear flow of events.
00:05:58
◼
►
And that, like, that simplification is so powerful at helping us diagnose problems
00:06:01
◼
►
or even just, like, verifying that things are working correctly,
00:06:06
◼
►
even if it isn't in from a purely diagnostic perspective.
00:06:12
◼
►
And, like, I have found, I mean, you mentioned the, you know, the watch workout case.
00:06:15
◼
►
This, to me, like, this is where logging is incredible,
00:06:20
◼
►
because it isn't just about workout apps, it's just any watch app.
00:06:23
◼
►
Debugging on the Apple Watch is slow and unreliable and is never a very fun process.
00:06:26
◼
►
And so sometimes you need to know, like, you know,
00:06:33
◼
►
what was going on during the other 95% of the time that my app exists on my watch.
00:06:36
◼
►
What's going on that other rest of the time?
00:06:42
◼
►
Is it getting those background updates?
00:06:41
◼
►
Is it crashing?
00:06:46
◼
►
You know, like, there's certain things that are just easier to spot
00:06:47
◼
►
or pull out of a log file than to try to figure out through, you know, direct debugging methods.
00:06:51
◼
►
And so this has been kind of, like, my slow process of, like,
00:06:57
◼
►
modernizing and improving my app, even crash logs.
00:07:01
◼
►
Like, I added my own crash reporter a few versions ago now,
00:07:06
◼
►
where it submits to my server any uncaught exception crash logs.
00:07:11
◼
►
Because Apple's crash logs, I think at the time, and I think still today,
00:07:15
◼
►
for uncaught exceptions, they don't tell you what the exception was.
00:07:19
◼
►
They just tell you it's an uncaught exception that was thrown here.
00:07:23
◼
►
And they might tell you, like, the name of it,
00:07:26
◼
►
but they won't tell you any of the, like, the parameters
00:07:28
◼
►
or, like, the description string or anything like that.
00:07:30
◼
►
So I found it hard to debug that just from Apple's own crash reports,
00:07:32
◼
►
because I didn't know, like, okay, there was an exception thrown, you know,
00:07:37
◼
►
on this dictionary line, like, well, it's probably something was nil or something,
00:07:40
◼
►
but I don't know that for sure.
00:07:43
◼
►
And it would be nice to know, like, what's the actual message being thrown here.
00:07:45
◼
►
And so I built in my own very basic, like, uncaught exception handler crash reporter a few months back,
00:07:50
◼
►
and it sends them to my server.
00:07:55
◼
►
And I have a little shell script that I can run based on the UUID of each crash that gets reported.
00:07:59
◼
►
I can automatically look up the symbolicated symbols in my archives
00:08:04
◼
►
and run this shell script, and it symbolicates the whole crash log for me most of the time.
00:08:09
◼
►
Symbolication works most of the time.
00:08:15
◼
►
That's the case with any crash reporting system I've ever worked with.
00:08:18
◼
►
It's like, most of the time it works perfect.
00:08:23
◼
►
Some of the times, not at all.
00:08:24
◼
►
And again, and this is another, you know, I'm building all this stuff myself,
00:08:29
◼
►
in part because I'm just, you know, that kind of jerk,
00:08:32
◼
►
and I only trust my own code to do most things,
00:08:35
◼
►
but also it really keeps things a lot simpler and more privacy conscious.
00:08:37
◼
►
You know, I don't want to be using some big service to do something that I can do fairly simply myself.
00:08:42
◼
►
You know, if I need a really big pain in the butt problem solved,
00:08:48
◼
►
like hosting servers, like, I don't want to physically deal with servers,
00:08:52
◼
►
so I outsource that to our friends at Linode, and this is not a sponsorship.
00:08:57
◼
►
I outsource it to Linode because running servers is a really big deal that I don't want to do myself.
00:09:01
◼
►
But stuff like having a log framework in my app, that's a really small deal.
00:09:06
◼
►
I don't have massive needs for that.
00:09:10
◼
►
I need to write statements to a file and be able to get to that file sometimes.
00:09:16
◼
►
And so doing stuff like this myself, I feel like is worth that trade-off.
00:09:18
◼
►
If you're in a bind and you don't have a lot of time, obviously,
00:09:23
◼
►
I would understand completely for people who are like, "That's fine for Marco,
00:09:27
◼
►
but I have to use whatever this free service is by Google or Twitter or Facebook or whatever."
00:09:31
◼
►
I don't have the kind of needs that would need something big like that when it's something simple like this.
00:09:37
◼
►
But I do get a lot of value out of having this kind of functionality at all.
00:09:42
◼
►
And to me, that's a perfect recipe for something that's good to write yourself.
00:09:46
◼
►
And I think what's interesting there is that sense of identifying the need.
00:09:51
◼
►
I think it's the first step, though.
00:09:56
◼
►
In terms of both of these things, what are you actually trying to do?
00:09:58
◼
►
Is this something that you're trying to ultimately expose to your mainstream users?
00:10:01
◼
►
Is it going to have a wide audience and user base?
00:10:06
◼
►
Those are the kind of things that you need to make sure you understand it too ahead of time
00:10:09
◼
►
for whether it makes sense to build it yourself or even just what this looks like from a privacy perspective
00:10:12
◼
►
and what the privacy implications are.
00:10:17
◼
►
It's something that you only expect to turn on and have active, say, during beta builds.
00:10:19
◼
►
There's a different set of privacy expectations and things that you need to communicate in those contexts
00:10:25
◼
►
than if it's something that's going to go out to your main big users.
00:10:30
◼
►
And so I think that's also the thing to keep in mind.
00:10:34
◼
►
And whether you build it yourself or use a hosted thing, it is one of those
00:10:36
◼
►
"increasingly I find myself just trying to, as much as I can, just build things myself."
00:10:39
◼
►
Because honestly, I have such anxiety about all the things going on with the privacy space right now.
00:10:44
◼
►
With Apple, where they're tracking changes and the IDFA changes and all these things.
00:10:52
◼
►
There's just so much ambiguity there that it's like, anytime you can just take away one of the,
00:10:56
◼
►
"Huh, if I include this thing, is it going to end up being a giant pain down the road?
00:11:01
◼
►
Or am I going to end up being caught up in something where, even if you're not using the parts of that framework or language,
00:11:08
◼
►
that could be creepy?"
00:11:13
◼
►
Then your app is flagged by Apple, and App Review looks at you and says,
00:11:16
◼
►
"Oh, because you linked to this thing, then you have to do it."
00:11:20
◼
►
And so in that sense, rolling it yourself I think makes sense.
00:11:23
◼
►
And especially as long as you can roll it out in a way that is reasonable in terms of time it takes to build,
00:11:26
◼
►
and time and expense in terms of hosting, which is probably fairly manageable.
00:11:32
◼
►
It's definitely something that I've found myself doing a lot more.
00:11:37
◼
►
And it's not to your degree, where I think you build everything yourself.
00:11:40
◼
►
There are a few things that I'll still outsource, but I'm definitely handing in that direction myself over time.
00:11:44
◼
►
We are sponsored this week by Pingdom.
00:11:52
◼
►
Do you have a website, and does it have things like a shopping cart or a registration form or a contact page?
00:11:55
◼
►
If you answered yes to any of those questions, you need Pingdom.
00:11:59
◼
►
Nobody wants their critical website transactions to fail.
00:12:04
◼
►
That means a bad experience for your users, and could mean lost business for you.
00:12:07
◼
►
But the good news is, you can set up transaction monitoring with Pingdom.
00:12:11
◼
►
Transaction monitoring will alert you when things like cart checkout or forms or login pages fail,
00:12:15
◼
►
before they affect your customers and your business.
00:12:20
◼
►
Pingdom can let you know the moment any of them fail, in whatever way is best for you.
00:12:23
◼
►
You fully customize how you're alerted, who is alerted, when you're alerted,
00:12:26
◼
►
depending on the outage of severity.
00:12:31
◼
►
And Pingdom cares about your users having the smoothest site experience possible.
00:12:33
◼
►
So if disaster strikes, you will be the first to know so you can get in there and fix it.
00:12:37
◼
►
It's super easy to get started.
00:12:42
◼
►
I've personally been a Pingdom customer for, oh man, maybe 10 years?
00:12:43
◼
►
It's been a long time, because it's a great service for monitoring pretty much anything.
00:12:47
◼
►
So you can see for yourself, Pingdom.com/RelayFM right now,
00:12:52
◼
►
for a 30 day free trial with no credit card required.
00:12:57
◼
►
When you sign up, use promo code RADAR at checkout to get a huge 30% off your first invoice.
00:13:02
◼
►
Once again, Pingdom.com/RelayFM, code RADAR for 30% off your first invoice.
00:13:08
◼
►
Thanks to Pingdom from SolarWinds for their support of this show and RelayFM.
00:13:13
◼
►
So I'm curious, I've been using this kind of system in Overcast,
00:13:21
◼
►
both the logging and then a different kind of logging that I'll get to in a second.
00:13:26
◼
►
And I've actually made significant quality fixes and usage fixes from this logging.
00:13:29
◼
►
Last week I found that I had actually forgotten in certain cases
00:13:36
◼
►
to schedule the next background refresh task for Overcast.
00:13:42
◼
►
And I was able to verify this by looking at my own log and saying,
00:13:46
◼
►
"Oh, this is somehow wrong. I'm not getting background refreshes all night long."
00:13:49
◼
►
And I had a couple of beta testers report the same thing, like,
00:13:54
◼
►
"Hey, I got a background refresh at midnight and then nothing until 8 in the morning.
00:13:56
◼
►
It's supposed to be more often than that."
00:14:00
◼
►
And I was able to look and find the issue, and like, "Oh, I wasn't fixing this correctly."
00:14:02
◼
►
And so I was able to do it.
00:14:07
◼
►
One other thing I saw in my main logging is I noticed that
00:14:10
◼
►
I was running new artwork fetches for podcasts much more often for certain shows than I thought.
00:14:18
◼
►
And it was necessary.
00:14:23
◼
►
And I know this because I would see ATP said it had a new artwork version.
00:14:24
◼
►
And I thought, "I didn't change the artwork for ATP. I'm pretty sure something is wrong here."
00:14:29
◼
►
You would know. You would definitely know.
00:14:35
◼
►
Right, and I noticed after every time it would sync artwork, it would say, "ATP's artwork had changed."
00:14:37
◼
►
And I was like, "That's not right."
00:14:43
◼
►
And I traced it to actually a server bug that, depending on which server it was,
00:14:45
◼
►
had checked the artwork.
00:14:50
◼
►
These two servers had a slightly different version of ImageMagick on them.
00:14:52
◼
►
And so they would encode the artwork to a different sequence of bytes, depending on which server encoded it.
00:14:56
◼
►
And so I discovered this whole image bug.
00:15:03
◼
►
I was able to fix that server side, basically comparing the bytes before compression instead of after.
00:15:07
◼
►
Which I should have been doing the whole time anyway, but oh well. No one's perfect.
00:15:13
◼
►
And so I was able to fix this server side bug because I was noticing in my own local logs in the app,
00:15:18
◼
►
"Hey, this isn't right."
00:15:24
◼
►
And then the other thing that I was working on, I've gotten some reports here or there over the years of making Overcast.
00:15:26
◼
►
People often report that it uses a lot of cell data sometimes.
00:15:33
◼
►
And it's really hard to debug that.
00:15:36
◼
►
Because especially an app that's designed to let you download large numbers of podcasts,
00:15:39
◼
►
it's kind of hard to know when someone says it uses a lot of data.
00:15:44
◼
►
Is that my fault or theirs?
00:15:48
◼
►
And so I built this whole feature into the current beta version that will be shipping soon
00:15:51
◼
►
that actually tracks data usage logging.
00:15:55
◼
►
It actually logs every single bit of data that I can find a way to track my app using.
00:16:04
◼
►
And this is largely thanks to a thing that I don't know if many people know about.
00:16:04
◼
►
On NSURL session, there's a delegate method that was added a few OS versions ago.
00:16:09
◼
►
Something something did finish collecting metrics for task.
00:16:15
◼
►
And there's this whole URL session task metrics object that will tell you for any URL task that you want to know about,
00:16:19
◼
►
it'll tell you whether it went through any redirects, what they were,
00:16:25
◼
►
and then all the byte usage for all their different requests.
00:16:29
◼
►
It'll send the bytes from the headers, bytes from the bodies.
00:16:30
◼
►
It tells you all that stuff in this URL metrics object.
00:16:35
◼
►
And so I went through my app and I audited all the network fetches I could find
00:16:39
◼
►
and added this metrics collection.
00:16:43
◼
►
And I have this whole feature now that categorizes and shows you in a similar way to,
00:16:45
◼
►
I have a storage usage screen that shows you storage by podcast.
00:16:51
◼
►
I now have a similar screen in the current beta for data usage.
00:16:55
◼
►
And it'll break down for each podcast.
00:16:55
◼
►
Like here's how much data was spent on audio, images, sync data and updates, etc.
00:17:00
◼
►
And what I found was that certain podcasts that I was subscribed to
00:17:06
◼
►
were sending huge amounts of data as feed updates.
00:17:10
◼
►
And I noticed, like, wait, why is this feed using like 20 megabytes of data in a day?
00:17:15
◼
►
That's a ton of feed updates.
00:17:21
◼
►
And I eventually traced it to the specific issue where certain feeds now,
00:17:23
◼
►
especially this is very common with user specific private feeds.
00:17:28
◼
►
So any premium content that you subscribe to that you pay for, or like Patreon feeds, things like that,
00:17:32
◼
►
where each user gets their own feed and there's like a big hash after it.
00:17:37
◼
►
ATP's feed works that way as well.
00:17:40
◼
►
Many of these feeds are now doing hashed enclosure URLs.
00:17:42
◼
►
So they'll have, at the end of each audio enclosure URL,
00:17:48
◼
►
they'll have some giant long URL hashed with a time-bombed, time-expiring link,
00:17:51
◼
►
like an S3 signed URL or something like that.
00:17:56
◼
►
And every time you fetch the feed, or maybe every 15 or 30 minutes,
00:17:59
◼
►
those URLs all change.
00:18:04
◼
►
Which means that every single time this feed is fetched by Overcast servers,
00:18:06
◼
►
the entire feed has changed because all of its download URLs have changed.
00:18:11
◼
►
This causes tons of sync data because the way Overcast works is
00:18:17
◼
►
whenever your app checks in with the servers and something has changed about the feed,
00:18:22
◼
►
it downloads whatever has changed.
00:18:26
◼
►
And so these feeds that had per user hashes that would change every hour, 15 minutes or whatever,
00:18:28
◼
►
they were just causing huge amounts of data transfer,
00:18:35
◼
►
but the only changes were the enclosure URLs.
00:18:38
◼
►
And so I was able to fix that even server-side as well,
00:18:40
◼
►
where I just redirect all downloads now through an overcast.fm/download/giant_long_hash URL.
00:18:46
◼
►
Which then that redirects to whatever the current enclosure URL is in the feed.
00:18:51
◼
►
But what that means to the app is that those URLs are no longer changing every hour for all those feeds,
00:18:56
◼
►
which means that those feeds now have way, way less data usage on the sync side of things.
00:19:01
◼
►
And I was only able to find that because of all these logging features I'm building into the app.
00:19:08
◼
►
And so it seems really boring.
00:19:11
◼
►
This seems like a grunt work boring task,
00:19:16
◼
►
but I really have gotten a lot of significant value out of just selectively adding a few bits of logging
00:19:21
◼
►
and a few metric collection things here and there.
00:19:28
◼
►
And there is also this whole other system I wanted to mention that I haven't looked fully into yet,
00:19:31
◼
►
but there's an API called MetricKit that was added in iOS 13 and a little bit expanded in iOS 14.
00:19:38
◼
►
This is a whole Apple API for things like total data usage of your app,
00:19:43
◼
►
disk writes, crash logs, CPU usage, et cetera.
00:19:48
◼
►
And it's not real-time, so it's not, you basically get an update once a day or something like that.
00:19:52
◼
►
I haven't done a lot of work against it yet, but I'm trying to add it into my logging
00:19:57
◼
►
and have this augment what I'm already logging and check my work on certain areas,
00:20:02
◼
►
like the network transfer stuff.
00:20:04
◼
►
And I think it's this great framework that it's not showing you anything new
00:20:09
◼
►
that you can't just get from the Xcode summary tabs for energy logs and stuff like that.
00:20:14
◼
►
At least I don't think it is, or at least it's not doing too much more than that.
00:20:21
◼
►
But it's nice to be able to have that locally in the app
00:20:24
◼
►
and then to be able to associate certain high-usage scenarios with,
00:20:28
◼
►
"All right, well, how many podcasts does this person subscribe to?"
00:20:31
◼
►
And so if somebody subscribes to five podcasts and they're having high data usage,
00:20:36
◼
►
it's a very different scenario than if they subscribe to 500 podcasts and they have high data usage.
00:20:41
◼
►
So it's nice to be able to have this kind of stuff in the app
00:20:45
◼
►
and be able to find other quality issues that your own logging couldn't catch.
00:20:48
◼
►
Yeah, and I think what's interesting, too, is it's the,
00:20:53
◼
►
so much of this is about logging lets you check your assumptions.
00:20:57
◼
►
There's so many of these things where you assume,
00:21:02
◼
►
you were saying, "I assume that I'm requesting all my background app refreshes.
00:21:05
◼
►
So if I'm not getting them, it's because the system is doing something wrong."
00:21:10
◼
►
You've made this assumption that, "Of course, every time I start one, I schedule the next one."
00:21:15
◼
►
And it lets you check your work on that.
00:21:20
◼
►
Or you assume, "Why would feeds be changing all the time?"
00:21:22
◼
►
It's like, "That doesn't make any sense."
00:21:22
◼
►
There's a reason for that.
00:21:27
◼
►
There are certain assumptions that I feel are really hard to catch unless you have this,
00:21:28
◼
►
because you have this data that doesn't care about what your assumption was.
00:21:33
◼
►
It's just a measurement of what happened in reality, and it lets you catch these things.
00:21:40
◼
►
Because I know I've run into things where these situations are like,
00:21:45
◼
►
"Why would there be all this cellular data usage?"
00:21:48
◼
►
And it's like, in Overcast, you do cellular...
00:21:53
◼
►
I remember years ago, you were doing battle with the downloader
00:21:57
◼
►
so that it would only ever download based on your settings of
00:22:02
◼
►
"Use Wi-Fi or Use Cellular."
00:22:07
◼
►
So it probably wasn't the syncing of the audio files themselves.
00:22:10
◼
►
It's going to be something else.
00:22:15
◼
►
And it's like, "Oh, these are just normal server sync messages
00:22:14
◼
►
that you send irrespective of Wi-Fi or Cellular."
00:22:19
◼
►
So in theory, they should be relatively straightforward and small and simple,
00:22:22
◼
►
but you found a situation where that assumption was invalidated.
00:22:25
◼
►
And so it's just one of those things that I think logging is so powerful for.
00:22:29
◼
►
But one thing that I'm just curious about with you is,
00:22:34
◼
►
when you're making a log, are you annotating that with things other than just the time?
00:22:37
◼
►
Are you using user-specific tokens?
00:22:43
◼
►
Or how are you keeping track of this in a way that you can pull back together
00:22:48
◼
►
the timeline of what happened subsequently at the end?
00:22:52
◼
►
So there's not much I can pull back because I'm not adding any user data to it.
00:22:56
◼
►
However, the log doesn't even get to me unless the user sends it to me.
00:23:02
◼
►
So for privacy reasons, obviously you have to be careful how much you're logging
00:23:08
◼
►
and what you're logging and where those logs are going.
00:23:11
◼
►
The way my logs work is they're just files locally,
00:23:16
◼
►
and the only way you can get to them is on the feedback screen.
00:23:18
◼
►
There's a button on the right that says "Debug Log."
00:23:22
◼
►
And again, this is only in the current beta.
00:23:24
◼
►
This is not in the App Store version yet, but it will be if Apple lets me leave it there.
00:23:25
◼
►
So you hit "Debug Log," and then it opens up a share sheet with two text files attached.
00:23:30
◼
►
One from the phone, one from the watch. That's it.
00:23:35
◼
►
And then you can choose what to do with that information.
00:23:38
◼
►
If you want to send it to me as part of a report, that's fine.
00:23:37
◼
►
People have largely figured that out, but that's fine.
00:23:42
◼
►
So from a privacy perspective, I could theoretically stick a user number in there or something,
00:23:45
◼
►
but I'd rather not just because I don't really need it.
00:23:52
◼
►
The main things I put in the log are things like the activity statements,
00:23:55
◼
►
of things like, "Okay, we're syncing because this feed has changed.
00:24:01
◼
►
We're syncing because this artwork has changed," etc.
00:24:04
◼
►
"This download just completed over cellular. This one didn't."
00:24:05
◼
►
But also I just have basic admin data, like, "Okay, I'm running this build number,
00:24:10
◼
►
this PID," similar to the nslog prefix where it has the date and the PID.
00:24:14
◼
►
But also I just add version history, or version number and build number to it.
00:24:20
◼
►
So that way I can tell when someone's sending a report from the beta,
00:24:23
◼
►
like, "Okay, which version were they actually running?
00:24:26
◼
►
Are they running the latest build? Do I know of a certain problem with the one they are running?"
00:24:29
◼
►
For the most part, I'm not adding more information than I think I would really need to diagnose particular problems.
00:24:34
◼
►
So I'm not adding things like their login token or their email address if I have it or anything like that,
00:24:41
◼
►
because that's just not relevant to the problems I'm trying to solve.
00:24:51
◼
►
That was one of those things that in my past when I've gone down this road is
00:24:52
◼
►
what's really awkward sometimes is there are certain categories of bugs that are very hard to reproduce generically,
00:24:58
◼
►
but some users' configuration will reproduce a bug regularly and straightforwardly.
00:25:03
◼
►
And it's one of those tricky things where sometimes it's like,
00:25:11
◼
►
I've definitely done the thing where you essentially make a fake login token and login almost as though I'm that person,
00:25:14
◼
►
but it's always kind of a tricky thing where you don't want to obviously access someone's private data
00:25:21
◼
►
and get into that in a way that starts to become privacy conscious.
00:25:25
◼
►
And so it's a really awkward thing where sometimes you want to find this balance between collecting just enough data
00:25:30
◼
►
that you'd be able to recreate it essentially with fictitious data without needing to go into this specific case of a specific person
00:25:36
◼
►
and what their specific actual data that would be privacy conscious or privacy a concern is.
00:25:44
◼
►
And so it's just always such a tricky thing.
00:25:51
◼
►
It's like, are you keeping track there?
00:25:51
◼
►
When you say a feed has changed, are you keeping track of the actual feed ID there?
00:25:56
◼
►
Or just some generic feed has changed?
00:26:01
◼
►
In that case, that's the specific feed with the feed ID.
00:26:04
◼
►
It's just a podcast entry.
00:26:09
◼
►
Overcast, by the way it works, already knows for this user ID number,
00:26:11
◼
►
they subscribe to feeds X, Y, and Z.
00:26:16
◼
►
It has to know that.
00:26:17
◼
►
That's all that is.
00:26:22
◼
►
Again, I try to minimize the personal data whenever possible.
00:26:24
◼
►
There are certain cases where I think it's warranted to associate.
00:26:28
◼
►
One example is on the ATP membership panel.
00:26:33
◼
►
There's a link to email us with any kind of question about your membership.
00:26:36
◼
►
And when you do that, it's a mail to link that includes in the subject line your membership number,
00:26:40
◼
►
like your user ID number.
00:26:42
◼
►
And on the back end, I have a crappy little admin panel that I can just paste in that number
00:26:47
◼
►
into either our dashboard or into Stripe's dashboard for payments.
00:26:52
◼
►
And that number just instantly brings up that customer's account
00:26:56
◼
►
and whatever info I might need to help them fix their problem.
00:26:59
◼
►
And that kind of thing I think is totally fine.
00:27:02
◼
►
You're already my customer.
00:27:05
◼
►
You're already emailing me about your account,
00:27:07
◼
►
so I'll make it easier for me to find your account by having this number in the subject line
00:27:09
◼
►
that you can plainly see.
00:27:14
◼
►
I feel like that kind of thing is okay.
00:27:18
◼
►
And I totally agree.
00:27:19
◼
►
I feel like there's something, in some ways,
00:27:20
◼
►
the best kind of privacy stuff like this is always the sense of,
00:27:22
◼
►
it's giving the user control about what they're sharing with you.
00:27:25
◼
►
And this is another example where it's like,
00:27:29
◼
►
if you were automatically collecting those log files
00:27:31
◼
►
and streaming them to a server
00:27:34
◼
►
and transparently in the background,
00:27:36
◼
►
which I'm sure there are systems in place in the world
00:27:35
◼
►
and there are many apps, I'm sure they'd probably even do this.
00:27:40
◼
►
That starts where you start to get into situations
00:27:42
◼
►
that become very complicated from a privacy perspective.
00:27:45
◼
►
And potentially you could find and track down
00:27:48
◼
►
a whole lot of bugs that way.
00:27:50
◼
►
As long as it's something where the user is making that choice
00:27:52
◼
►
and it's a conscious and opaque thing,
00:27:54
◼
►
whatever the opposite of transparent is.
00:27:58
◼
►
It's like making sure that it's clear to them.
00:28:00
◼
►
It's like making sure that it's completely clear to the user
00:28:02
◼
►
that what they're doing is they're going to email you
00:28:01
◼
►
and in that email it's going to have a file
00:28:06
◼
►
and the file isn't some sort of garbled, cryptic thing.
00:28:08
◼
►
It's like, nope, it's just a plain text file.
00:28:12
◼
►
They can see exactly what's going with them.
00:28:14
◼
►
Then it feels like you're in the clear for,
00:28:16
◼
►
they've made this choice to send it to you
00:28:18
◼
►
and you're not imposing on their privacy.
00:28:20
◼
►
You're just responding to something
00:28:23
◼
►
that they want decided to share to you.
00:28:25
◼
►
Yeah, exactly.
00:28:26
◼
►
All right, well, thanks for listening
00:28:26
◼
►
to this exciting episode about logging.
00:28:31
◼
►
Hey, don't talk down to logs.
00:28:34
◼
►
Logs are very important and I think it's time
00:28:37
◼
►
they finally got their due and I'm glad we got that.
00:28:40
◼
►
But now we can record that event that the podcast has ended.
00:28:42
◼
►
Thanks for listening everybody