sentry-cocoa icon indicating copy to clipboard operation
sentry-cocoa copied to clipboard

Capture Logs from NSLog as Breadcrumbs

Open fzyzcjy opened this issue 4 years ago • 19 comments

Environment

How do you use Sentry? Sentry SaaS (sentry.io) or self-hosted/on-premise (which version?) saas

Which SDK and version? e.g: JavaScript 5.11.1, .NET 1.2.0 ios

Steps to Reproduce

use sample

Expected Result

want to automatically capture logs to sentry breadcrumb

Actual Result

Cannot automatically capture logs to sentry breadcrumb

thanks!

fzyzcjy avatar Jul 24 '21 09:07 fzyzcjy

Hey @fzyzcjy, which types of logs are you referring to? Would you please post some code snippets? Why do you want your logs as breadcrumbs anyway?

philipphofmann avatar Jul 26 '21 10:07 philipphofmann

@philipphofmann you know, swift's log, objc's log. e.g. these https://stackoverflow.com/questions/25951195/swift-print-vs-println-vs-nslog

because logs provide precious clues when bugs comes!

fzyzcjy avatar Jul 26 '21 12:07 fzyzcjy

We currently don't support redirecting the output of NSLog, Swift's Logger, or println. They use stderr and/or log messages to the Apple System Logging (asl) facility. You could maybe redirect stderr to SentryBreadcrumbs, but I guess that's doesn't make much sense. Furthermore, you shouldn't use NSLog in release builds, because its performance is not the best. Maybe you can use a logging framework like CocoaLumberjack, that allows you to redirect the log messages. You could also write your own logger, that uses NSLog in debug and SentryBreadcrumbs in release.

philipphofmann avatar Jul 27 '21 15:07 philipphofmann

@philipphofmann Thanks for the reply! However, I see some third party libs use NSLog to print out things. Then how can I capture them?

fzyzcjy avatar Jul 28 '21 00:07 fzyzcjy

Sorry for the late reply. Why do you want to capture third-party logs, @fzyzcjy? Just to understand your use case.

philipphofmann avatar Oct 28 '21 13:10 philipphofmann

@philipphofmann b/c I use some third-party libs. Some of them only output logs to NSLog or something like that. And you know, in production environment, it is critical to capture logs, such that we can have more information when bug happens

fzyzcjy avatar Oct 28 '21 22:10 fzyzcjy

Java, .NET, Python already have a similar feature. We need to investigate how we can hook into NSLog so we achieve this. One idea would be to redirect the stderr to a memory stream or something. Do you @fzyzcjy maybe have any input on how we could achieve this?

Worth pointing out that os_log is the latest API. See https://github.com/getsentry/sentry-cocoa/issues/1461

philipphofmann avatar Nov 17 '21 14:11 philipphofmann

I am not pretty sure how to achieve this, since I am not an expert in ios (but mostly doing flutter things). Your suggestions seem promising!

fzyzcjy avatar Nov 17 '21 14:11 fzyzcjy

I'm very interested in this feature for the extra clues that might be in logs.

As of iOS 15, an app can get its own logs:

if let logStore = try? OSLogStore(scope: .currentProcessIdentifier) {
    let oneHourAgo = logStore.position(date: Date().addingTimeInterval(-3600))
    if let allEntries = try? logStore.getEntries(at: oneHourAgo) {
        for entry in allEntries.compactMap({ $0 as? OSLogEntryLog }) {
            print("entry: \(entry.date) subsystem \(entry.subsystem) message \(entry.composedMessage)")
        }
    }
}

It seems to be a common convention to specify bundleIdentifier as the subsystem when creating the Logger; some also use the class name for category but either of these can be any string. So the logs could be filtered thusly:

if let logStore = try? OSLogStore(scope: .currentProcessIdentifier) {
    let oneHourAgo = logStore.position(date: Date().addingTimeInterval(-3600))
    if let allEntries = try? logStore.getEntries(at: oneHourAgo,
                                                 matching: NSPredicate(format: "subsystem == %@", Bundle.main.bundleIdentifier!)) {
        for entry in allEntries.compactMap({ $0 as? OSLogEntryLog }) {
            print("entry: \(entry.date) subsystem \(entry.subsystem) message \(entry.composedMessage)")
        }
    }
}

matthewreimer avatar Jun 15 '22 18:06 matthewreimer

Also I see NSLog output in these logs too, with a subsystem of message (the leading space seems to be significant).

matthewreimer avatar Jun 15 '22 18:06 matthewreimer

We might be able to stream the logs from the OSLogStore, see https://steipete.com/posts/logging-in-swift/#update-ios-15 and https://github.com/steipete/OSLogTest.

philipphofmann avatar Jun 20 '22 13:06 philipphofmann

FYI, I've been investigating this as well.

I started by experimenting with the following snippet to send OSLog entries to Sentry: https://gist.github.com/garriguv/b5462cf629d8c8474d9b8474ca6d0744

The caveat is that the OSLogStore is very slow, so we only get a batch of logs every 10-15 seconds, which means that you'll likely miss the logs leading up to a crash.

A better approach could be to attach the logs from the last hour as breadcrumbs with every Sentry event using the beforeSend hook. It would look like this: https://gist.github.com/garriguv/4d2606862ba72b01a206c4ad3e8138c0

While the latter option works well for messages, it unfortunately does not work for crashes since they are sent the next time the application starts. In that case, we only get the logs from the ~last~ latest app launch, not any of the prior launches. This is likely because the OSLogStore is instantiated with the .currentProcessIdentifier scope, and the process identifier differs across app launches. See: https://developer.apple.com/forums/thread/700321?answerId=704363022#704363022

garriguv avatar Oct 05 '22 14:10 garriguv

Thank you, @garriguv, for the update. 👏

A better approach could be to attach the logs from the last hour as breadcrumbs with every Sentry event using the beforeSend hook

Are these up to date or also 15 seconds delayed?

In that case, we only get the logs from the last app launch, not the prior launches.

Do you mean logs from the last app launch that crashed? Wouldn't that be enough?

philipphofmann avatar Oct 06 '22 07:10 philipphofmann

Do you mean logs from the last app launch that crashed? Wouldn't that be enough?

I meant the logs from the latest app launch, the one after the crash happened, which is not enough. I updated my post to clarify that point.

Are these up to date or also 15 seconds delayed?

I actually don't know. I think that building a little test bench project is the correct next step here. Maybe a good idea for your upcoming Hacktoberfest? 😉

garriguv avatar Oct 06 '22 07:10 garriguv

Hacktoberfest is actually for contributing to open source. I added the tag because I thought it might be something a contributor could have a shot at.

Thanks for the update, @garriguv.

philipphofmann avatar Oct 06 '22 13:10 philipphofmann

Reading the application logs that led up to a crash is something I also have been missing a lot with Sentry. It's a feature I'm used to from Firebase/Crashlytics and Bugsnag. Breadcrumbs intend to solve the same problem but they only capture a small fraction of the information developers typically print to the console.

We already have a custom "report a bug" feature in our app which attaches the logs. My initial thought was that I could just attach these logs to a Sentry crash. Here is how we did that with Bugsnag, there is a closure you pass in when initializing Bugsnag which allows you to attach information to a crash when it happens. Unfortunately it doesn't look like this is possible in Sentry, as the docs state "Please note that attachments don't work yet with crashes.".

mplorentz avatar Jan 09 '24 15:01 mplorentz

@mplorentz, adding info to a crash while it happens will be possible with https://github.com/getsentry/sentry-cocoa/issues/3408, but I can't give you an ETA.

You could try adding your logs, if they aren't too big, to the context which also ends up in crash events with something like

SentrySDK.configureScope { scope in
    scope.setContext(value: [
        "log 1": "login",
        "log 2" : "log out",
    ], key: "my_logs")
}

philipphofmann avatar Jan 10 '24 10:01 philipphofmann

Thanks @philipphofmann. I subscribed to #3408. Our logs are pretty big right now so I'm not going to attempt the configureScope option, but maybe it is useful for others.

mplorentz avatar Jan 10 '24 20:01 mplorentz

@mplorentz, another idea is that you could use initialScope to add attachments and then remove them sometime later after initializing the SDK.

philipphofmann avatar Jan 11 '24 12:01 philipphofmann