Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

File IO integration not working for iOS 18 #4546

Open
brustolin opened this issue Nov 18, 2024 · 12 comments
Open

File IO integration not working for iOS 18 #4546

brustolin opened this issue Nov 18, 2024 · 12 comments
Assignees

Comments

@brustolin
Copy link
Contributor

Description

Some file IO operations not being tracked for iOS 18.

See https://github.com/getsentry/sentry-cocoa/actions/runs/11858258351/job/33048500905?pr=4542

@philipphofmann
Copy link
Member

If we can't swizzle certain file IO operations, we can create an Extension or a SentryFileManager class wrapping file IO operations and adding spans.

@philipphofmann philipphofmann moved this from Needs Discussion to Backlog in Mobile & Cross Platform SDK Nov 27, 2024
@philipphofmann philipphofmann changed the title FIle IO integration not working for iOS 18 File IO integration not working for iOS 18 Dec 3, 2024
@philprime
Copy link
Contributor

philprime commented Dec 5, 2024

To figure out when the changes were introduced, I went ahead and ran the failing unit tests in SentryFileIOTrackingIntegrationObjCTests with different Simulator iOS and Xcode versions, to figure out when the change causing the issue was introduced by Apple:

Xcode \ iOS macOS 15.1.1 Simulator iOS 18.2-beta4 Simulator iOS 18.1 Simulator iOS 18.0 Simulator iOS 17.5 Simulator iOS 17.4 Simulator iOS 17.2
16.2 Beta 3
16.1
16.0

It seems that the internal implementation of NSFileManager.createFileAtPath:contents:attributes: was changed starting with iOS 18.0 and maybe macOS 15 (I don't have a comparison system available right now).

Based on the current implementation it is assumed that NSFileManager uses NSData to create the new file. This was most likely changed to a different implementation without NSData, therefore not getting recognized by the NSData swizzling.

Next I'll try to figure out if we have to swizzle NSFileManager to fix this, or if it still uses some alternative class like NSData we want to track instead.

@philprime philprime moved this from Backlog to In Progress in Mobile & Cross Platform SDK Dec 6, 2024
@philprime
Copy link
Contributor

philprime commented Dec 6, 2024

I focused on the failing test -[SentryFileIOTrackingIntegrationObjCTests test_NSFileManagerCreateFile] as it seems to be the only failing.

For visualization of the differences, I added logging statements to SentryNSDataSwizzling and SentryNSDataTracker and we can see differences in the called methods:

Test Log iOS 17.5:
Test Suite 'Selected tests' started at 2024-12-06 10:56:21.317.
Test Suite 'SentryTests.xctest' started at 2024-12-06 10:56:21.318.
Test Suite 'SentryFileIOTrackingIntegrationObjCTests' started at 2024-12-06 10:56:21.318.
Test Case '-[SentryFileIOTrackingIntegrationObjCTests test_NSFileManagerCreateFile]' started.
SWIZZLE NSData.writeToFile:options:error:
--> SentryNSDataTracker.measureNSData:writeToFile:options:error
SWIZZLE NSData.initWithContentsOfFile:
--> SentryNSDataTracker.measureNSDataFromFile:path:
SWIZZLE NSData.initWithContentsOfFile:
--> SentryNSDataTracker.measureNSDataFromFile:path:
SWIZZLE NSData.writeToFile:options:error:
--> SentryNSDataTracker.measureNSData:writeToFile:options:error
Test Case '-[SentryFileIOTrackingIntegrationObjCTests test_NSFileManagerCreateFile]' passed (0.067 seconds).
Test Suite 'SentryFileIOTrackingIntegrationObjCTests' passed at 2024-12-06 10:56:21.385.
	 Executed 1 test, with 0 failures (0 unexpected) in 0.067 (0.068) seconds
Test Suite 'SentryTests.xctest' passed at 2024-12-06 10:56:21.386.
	 Executed 1 test, with 0 failures (0 unexpected) in 0.067 (0.068) seconds
Test Suite 'Selected tests' passed at 2024-12-06 10:56:21.386.
	 Executed 1 test, with 0 failures (0 unexpected) in 0.067 (0.069) seconds
Program ended with exit code: 0
Test Log iOS 18.1:
Test Suite 'Selected tests' started at 2024-12-06 10:55:39.607.
Test Suite 'SentryTests.xctest' started at 2024-12-06 10:55:39.607.
Test Suite 'SentryFileIOTrackingIntegrationObjCTests' started at 2024-12-06 10:55:39.607.
Test Case '-[SentryFileIOTrackingIntegrationObjCTests test_NSFileManagerCreateFile]' started.
SentryFileIOTrackingIntegrationObjCTests.m:212: error: -[SentryFileIOTrackingIntegrationObjCTests test_NSFileManagerCreateFile] : ((parentTransaction.children.count) equal to (1)) failed: ("0") is not equal to ("1")
SentryFileIOTrackingIntegrationObjCTests.m:213: error: -[SentryFileIOTrackingIntegrationObjCTests test_NSFileManagerCreateFile] : (([ioSpan.data[@"file.size"] unsignedIntValue]) equal to (someData.length)) failed: ("0") is not equal to ("9")
SentryFileIOTrackingIntegrationObjCTests.m:214: error: -[SentryFileIOTrackingIntegrationObjCTests test_NSFileManagerCreateFile] : ((ioSpan.data[@"file.path"]) equal to (filePath)) failed: ("(null)") is not equal to ("/Users/philip/Library/Developer/CoreSimulator/Devices/772691D9-D886-456C-8801-DFEC684B3ACF/data/Documents/TestFile")
SentryFileIOTrackingIntegrationObjCTests.m:215: error: -[SentryFileIOTrackingIntegrationObjCTests test_NSFileManagerCreateFile] : ((operation) equal to (ioSpan.operation)) failed: ("file.write") is not equal to ("(null)")
SentryFileIOTrackingIntegrationObjCTests.m:225: error: -[SentryFileIOTrackingIntegrationObjCTests test_NSFileManagerCreateFile] : ((ioSpan.spanDescription) equal to (expectedString)) failed: ("(null)") is not equal to ("TestFile (9 bytes)")
SWIZZLE NSData.initWithContentsOfFile:
--> SentryNSDataTracker.measureNSDataFromFile:path:
SWIZZLE NSData.initWithContentsOfFile:
--> SentryNSDataTracker.measureNSDataFromFile:path:
SWIZZLE NSData.writeToFile:options:error:
--> SentryNSDataTracker.measureNSData:writeToFile:options:error
Test Case '-[SentryFileIOTrackingIntegrationObjCTests test_NSFileManagerCreateFile]' failed (0.106 seconds).
Test Suite 'SentryFileIOTrackingIntegrationObjCTests' failed at 2024-12-06 10:55:39.713.
	 Executed 1 test, with 5 failures (0 unexpected) in 0.106 (0.106) seconds
Test Suite 'SentryTests.xctest' failed at 2024-12-06 10:55:39.713.
	 Executed 1 test, with 5 failures (0 unexpected) in 0.106 (0.106) seconds
Test Suite 'Selected tests' failed at 2024-12-06 10:55:39.714.
	 Executed 1 test, with 5 failures (0 unexpected) in 0.106 (0.107) seconds
Program ended with exit code: 1
Test Log macOS 15.1.1:
Test Suite 'Selected tests' started at 2024-12-06 10:55:19.464.
Test Suite 'SentryTests.xctest' started at 2024-12-06 10:55:19.470.
Test Suite 'SentryFileIOTrackingIntegrationObjCTests' started at 2024-12-06 10:55:19.474.
Test Case '-[SentryFileIOTrackingIntegrationObjCTests test_NSFileManagerCreateFile]' started.
SentryFileIOTrackingIntegrationObjCTests.m:212: error: -[SentryFileIOTrackingIntegrationObjCTests test_NSFileManagerCreateFile] : ((parentTransaction.children.count) equal to (1)) failed: ("0") is not equal to ("1")
SentryFileIOTrackingIntegrationObjCTests.m:213: error: -[SentryFileIOTrackingIntegrationObjCTests test_NSFileManagerCreateFile] : (([ioSpan.data[@"file.size"] unsignedIntValue]) equal to (someData.length)) failed: ("0") is not equal to ("9")
SentryFileIOTrackingIntegrationObjCTests.m:214: error: -[SentryFileIOTrackingIntegrationObjCTests test_NSFileManagerCreateFile] : ((ioSpan.data[@"file.path"]) equal to (filePath)) failed: ("(null)") is not equal to ("/Users/philip/Documents/TestFile")
SentryFileIOTrackingIntegrationObjCTests.m:215: error: -[SentryFileIOTrackingIntegrationObjCTests test_NSFileManagerCreateFile] : ((operation) equal to (ioSpan.operation)) failed: ("file.write") is not equal to ("(null)")
SentryFileIOTrackingIntegrationObjCTests.m:225: error: -[SentryFileIOTrackingIntegrationObjCTests test_NSFileManagerCreateFile] : ((ioSpan.spanDescription) equal to (expectedString)) failed: ("(null)") is not equal to ("TestFile (9 bytes)")
SWIZZLE NSData.initWithContentsOfFile:
--> SentryNSDataTracker.measureNSDataFromFile:path:
Test Case '-[SentryFileIOTrackingIntegrationObjCTests test_NSFileManagerCreateFile]' failed (0.597 seconds).
Test Suite 'SentryFileIOTrackingIntegrationObjCTests' failed at 2024-12-06 10:55:20.080.
	 Executed 1 test, with 5 failures (0 unexpected) in 0.597 (0.606) seconds
Test Suite 'SentryTests.xctest' failed at 2024-12-06 10:55:20.086.
	 Executed 1 test, with 5 failures (0 unexpected) in 0.597 (0.615) seconds
Test Suite 'Selected tests' failed at 2024-12-06 10:55:20.092.
	 Executed 1 test, with 5 failures (0 unexpected) in 0.597 (0.628) seconds
Program ended with exit code: 1

It seems like NSData.writeToFile is not called twice on iOS 18, and not at all on macOS.

I enabled objc message logging by setting the test run environment flag NSObjCMessageLoggingEnabled=YES (Documentation). The logging of ObjC messages appears to only be available for macOS, but as the tests are also failing there, it helped to get an initial idea.

The full message log just for the call of NSFileManager.createFileAtPath is roughly 500 lines, but there is no usage of any NSData.writeToFile in there, so I don't believe the current swizzling is sufficient.

After swizzling NSFileManager.createFileAtPath directly the tests passed, so I am going to create a PR with an implementation proposition next.

objc-message-sends.log

@brustolin
Copy link
Contributor Author

I focused on the failing test -[SentryFileIOTrackingIntegrationObjCTests test_NSFileManagerCreateFile] as it seems to be the only failing.

We also have this failing tests:

  • SentryFileIOTrackingIntegrationTests.test_ReadingURL_Tracking()
  • SentryFileIOTrackingIntegrationTests.test_ReadingURLWithOption_Tracking()
  • SentryFileIOTrackingIntegrationTests.test_Writing_Tracking()
  • SentryFileIOTrackingIntegrationTests.test_WritingWithOption_Tracking()

But we could split the solutions into different PRs.

@philprime
Copy link
Contributor

@brustolin I see tests failing now too. I believe they are related to my changes so I will look into it in this PR. I enabled testing for iOS 18 and macOS 15 due to the results of the investigation and verifying backwards compatibility

@brustolin
Copy link
Contributor Author

I believe they are related to my changes so I will look into it in this PR

This tests also fail in my draft PR, I dont think its related to your changes but other IO api changes from Apple.

@philprime
Copy link
Contributor

I created a simple Objective-C message logger to log the messages dispatched by NSFileManager.createFileAtPath with empty data on macOS 14.6.1 (23G93) with Xcode 16.1 and macOS 15.1.1 (24B2091) with Xcode 16.1 (Thank you @armcknight!):

let tempPath = URL(fileURLWithPath: NSTemporaryDirectory())
    .appending(path: UUID().uuidString)
    .appendingPathExtension("tmp")
let data = Data()
let manager = FileManager.default

// -- EXECUTE --
let logs = try collectLogs {
    // manager.createFile(atPath: tempPath.absoluteString, contents: data, attributes: nil)
    let _ = NSString("Hello World")
}

This excerpt of the diff clearly shows how the new internal implementation is not using NSData.writeToFile anymore:

macOS 14.6.1:
< - _NSZeroData NSData writeToFile:options:error:
< - __NSCFString NSString getFileSystemRepresentation:maxLength:
< - __NSCFString __NSCFString isEqual:
< - __NSCFString NSString stringByDeletingLastPathComponent
< - __NSCFString __NSCFString length
< - __NSCFString __NSCFString getCharacters:range:
< + NSPathStore2 NSPathStore2 pathStoreWithCharacters:length:

macOS 15.1.1:
> - _NSFileManagerBridge _NSFileManagerBridge createFileAtPath:contents:attributes:
> - __NSCFString __NSCFString retain
> - __NSCFString __NSCFString copyWithZone:
> - __NSCFString __NSCFString _fastCStringContents:
> - __NSCFString __NSCFString length
> - __NSCFString __NSCFString retain
> - __NSCFString __NSCFString release
> - __NSCFString __NSCFString release
> - _NSZeroData _NSZeroData retain
> - _NSZeroData _NSZeroData length
> - _NSZeroData _NSZeroData release
> - __NSCFString __NSCFString retain
> + NSURL NSURL allocWithZone:
> - __NSCFString __NSCFString retain
> - __NSCFString __NSCFString release
> - NSURL NSURL initFileURLWithPath:
> - __NSCFString __NSCFString length
> - __NSCFString NSString isAbsolutePath
> - __NSCFString __NSCFString length
> - __NSCFString __NSCFString getCharacters:range:
> - __NSCFString NSString stringByStandardizingPath
> - __NSCFString NSString _stringByStandardizingPathUsingCache:
> - __NSCFString __NSCFString length
> - __NSCFString __NSCFString length
> - __NSCFString __NSCFString getCharacters:range:
> - NSPathStore2 NSPathStore2 length
> - NSPathStore2 NSPathStore2 characterAtIndex:

macos-14.log
macos-15.log

Based on these results I am confident in my assumption that NSFileManager should be swizzled starting with macOS 15 and iOS 18 as already implemented in the draft PR.

Regarding the failing tests in SentryFileIOTrackingIntegrationTests.swift I will need further time to investigate them.

@philipphofmann
Copy link
Member

If I got it right, we need to address two different problems to fix this issue:

  1. Fixing the instrumentation for NSFileManager. createFileAtPath
  2. Fixing the instrumentation for Data(contentsOf::)

NSFileManager.createFileAtPath

Before iOS 18 NSFileManager.createFileAtPath used NSData, so it was a nice side effect of getting the file manager's instrumentation by only swizzling NSData. I think this stopped working because they ported the FileManager to swift-foundation with swiftlang/swift-foundation#410. @philprime, I'm not 100% up to date on the PR #4605. Does swizzling the NSFileManager fix this issue?

Data(contentsOf::)

It seems like Swift Data also stopped using NSData under the hood. That's the main goal of https://github.com/swiftlang/swift-foundation. So the SentryDataWrapper you proposed in #4605 (comment) seems like the only solution for us to fix this, but I still need to check the details of the wrapper.

@philprime
Copy link
Contributor

@philipphofmann you summarized it correctly.

ad 1.: Yes, swizzling NSFileManager as proposed in #4605 fixes the tracing of NSFileManager.createFileAtPath and the unit tests pass again.

ad 2.: Yes, my proposed SentryDataWrapper acts as a drop-in replacement for Swift.Data, but I need further guidance how to record the spans, hence the comment. Looking forward to your feedback.

@philipphofmann
Copy link
Member

OK, then I would split this issue up into two issues. One for the NSFileManager and another one for Swift.Data. I would first swizzle the NSFileManager behind an experimental feature to minimize the risk of breaking something. After we merge this, we can look at Swift.Data. For that, I would first start with the code you want to write. Maybe the Wrapper you proposed is the best solution, maybe we can use extensions. We still need to evaluate which approach works best.

@philprime
Copy link
Contributor

@kahest
Copy link
Member

kahest commented Dec 13, 2024

somewhat related, so FYI #4238

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
Status: In Progress
Development

No branches or pull requests

4 participants