mozilla-vpn-client icon indicating copy to clipboard operation
mozilla-vpn-client copied to clipboard

iOS: Swift logging doesn't save to VPN log stream

Open data-sync-user opened this issue 1 year ago • 4 comments

Swift logs aren’t in the logs that are produced by the app.

Similar to https://mozilla-hub.atlassian.net/browse/VPN-5184, but for iOS.

┆Issue is synchronized with this Jira Task ┆Reporter: Matt Cleinman

data-sync-user avatar Dec 19 '23 21:12 data-sync-user

➤ Beatriz Rizental Machado commented:

Changing this to a bug and changing priority to high.

The outcome here is that logs from the Swift side of the code, including the daemon are not part of the VPN logs. This is useful context during development and general debugging that we are currently lacking.

data-sync-user avatar Jan 19 '24 17:01 data-sync-user

➤ Matt Cleinman commented:

It’s because of this line:

if (Bundle.main.bundlePath.hasSuffix(".appex"))

Some of the swift logging is in the main app, which has the main bundle name - so this is false. And thus we’re not logging it.

However, when removing this line we get unexpected linebreaks and some things logging to the backend that we’d expect logged to the front end. Not digging into this right now, but shouldn’t be too hard to fix once we look into it more.

data-sync-user avatar Jan 19 '24 18:01 data-sync-user

➤ Gela Malek Pour commented:

Some notes on this bug:

  1. Not all Swift logs are missing. In fact network extension code in Swift is being recorded. For example we are gathering logs from iostunnelmanager.swift (Search the logs for "Attempting to initialize VPN tunnel" which comes from iostunnelmanager.swift
  2. We are not missing backend or network extension logs.
  3. We are specifically only missing client side swift code that is not in network extension. This means the logs coming from ioscontroller.swift are not being recorded. This is important because it collects the VPN state (on, off, connecting, etc..) which is frequently used to debug and assess logs coming from customers.
  4. As Matt mentioned earlier, removing if (Bundle.main.bundlePath.hasSuffix(".appex")) or expanding it to if (Bundle.main.bundlePath.hasSuffix(".appex")) || (Bundle.main.bundlePath.hasSuffix(".app")) resolves the issue of missing logs, but it ends duplicating some other log statements from elsewhere.
  5. The biggest challenge for me with this ticket is that I only have access to an iOS emulator (and not a physical device). While using the emulator, we never actually go into the code is ioscontroller.swift which is where the issue surfaces; therefore I am not able to reproduce or debug this issue on my end. We cannot actually activate the VPN in the emulator. I was able to get into the ioscontroller.swift code by changing the logic in ioscontroller.mm ( https://github.com/mozilla-mobile/mozilla-vpn-client/blob/main/src/platforms/ios/ioscontroller.mm#L73 ) to forcefully initialize the iOS controller. However, this did not work given that we do not have the logic to activate the iOS controller and so none of the relevant code was reached/logged.

Open questions:

  1. Is it possible to get access to an iPhone for testing purposes?
  2. I would like to figure out how the logging in the client works. Where is the code that writes to mozillavpn.log? Is it being done in Swift, Objective-C or C++?
  3. Rather than trying to chronologically intertwine C++ and Swift code, should we consider having a separate section for swift logging the same way we do for frontend vs backend log statements?

data-sync-user avatar Feb 10 '24 00:02 data-sync-user

➤ Gela Malek Pour commented:

A potential fix?

We are dropping all swift client side logs messages that are not in the network extension. This is problematic because we use the iOS logs to determine issues for the clients, and not seeing vital information such as VPN connection state for example could make it harder/impossible to effectively draw conclusions from the iOS logs.

Because in iOSLogger we are filtering the messages by only logging what's coming from .appex, we are missing this data. Simply removing the if statement if (Bundle.main.bundlePath.hasSuffix(".appex") doesn't resolve this because now we end up with some duplicate logs coming from the main app.

The simplest fix I could think of which doesn't involves rewriting the logging code is to append the class name to the log messages coming from the swift controller, and expanding the if statement check to allow messages coming from IOSSwiftController. I would argue that this is a good practice in general because otherwise with the log statement we can't even tell where they're coming from. For example just seeing "Connecting" in logs gives no context as to where it's coming from.

data-sync-user avatar Feb 10 '24 02:02 data-sync-user

➤ Matt Cleinman commented:

I looked into adding a objc bridging header and writing directly to the main logger. Unfortunately, the main logger class uses a lot of Qt imports, and the build fails due to these deeper dependencies. Given that untangling this would be non-trivial and the current status of the app, I’m going to do a simpler solution. We’ll add a third section of logs to the log output - Swift logs from the main app will exist, but be in their own section.

data-sync-user avatar Feb 29 '24 22:02 data-sync-user

➤ Valentina Virlics commented:

Matt Cleinman Is there something that QA can verify here? If, yes, could you please provide some details? Thanks!

data-sync-user avatar Mar 20 '24 07:03 data-sync-user

➤ Matt Cleinman commented:

Valentina Virlics apologies. What you should check here is that there is a third section of the logs that says “Swift” in the header, and has some data. (Note that this section will likely be empty unless the VPN was activated from the app at least once.)

data-sync-user avatar Mar 20 '24 15:03 data-sync-user

➤ Valentina Virlics commented:

Verified this while using Mozilla VPN 2.21(2.202403202206) on iOS 16.

The new section is displayed inside logs. (see ss below)

!image-20240321-071725.png|width=208,height=106!

In regards of section content, after app reset, the section is not empty. Matt Cleinman I suppose, it is ok? Attaching ss with the content.

!image-20240321-072429.png|width=799,height=563!

Thanks!

data-sync-user avatar Mar 21 '24 07:03 data-sync-user

➤ Matt Cleinman commented:

Are the backend logs reset after an app reset? I’d expect these Swift logs to match the behavior of our existing logs. Please let me know if that’s not true.

data-sync-user avatar Mar 21 '24 17:03 data-sync-user

➤ Valentina Virlics commented:

Verified this on the latest 2.21 build, on iOS 16, and noticed the following:

  • fresh install / no VPN turn ON

    • swift logs displayed;
    • backend logs displayed;
  • reset the app/ no VPN turn ON

    • swift logs displayed;
    • backend logs displayed;

So, it seems like the matching between old and new logs is there.

[^fresh install - mozillavpn.log]

Matt Cleinman Please let us know if other checks are required. Thanks!

data-sync-user avatar Mar 22 '24 09:03 data-sync-user

➤ Matt Cleinman commented:

Sounds great, thank you! Nothing else I can think of.

data-sync-user avatar Mar 22 '24 16:03 data-sync-user