I'll add the system log and see what else could be discovered.
Post
Replies
Boosts
Views
Activity
Though I didn't change over to system logs, I've did add the inclusion of the PID.
I think with this new bit of info we can say that there are multiple instances of the PushProvider being made on the same PID.
Could you provide me with more info as to why the system is doing this?
Here's a log that comes after the crash. Note the new PID.
2025-02-10 07:02:11.657 [Debug] [ExtensionConnectionInteractor.swift:150] start(providerConfiguration:) > PID: 71304 | ποΈβ
Connection success 9FE76
2025-02-10 07:02:11.658 [Debug] [AuthenticationViewModel.swift:89] updateAuthenticationStatus(_:) > PID: 71304 | success...
2025-02-10 07:02:11.659 [Debug] [Authenticatable.swift:145] setupAuthenticationFlow(lifetime:) > PID: 71304 | π didLogIn --> Completed
And then in an hour before it crashes we see this. It seems that more push providers are being created still.
** many redundant lines were removed due to character limit **
start(providerConfiguration:) > PID: 71304 | ποΈβ
Connection success B9979
2025-02-10 08:34:49.671 [Debug] [AuthenticationViewModel.swift:89] updateAuthenticationStatus(_:) > PID: 71304 | success...
2025-02-10 08:34:49.671 [Debug] [Authenticatable.swift:145] setupAuthenticationFlow(lifetime:) > PID: 71304 | π didLogIn --> Completed
2025-02-10 08:34:49.672 [Debug] [ExtensionConnectionInteractor.swift:150] start(providerConfiguration:) > PID: 71304 | ποΈβ
Connection success A6665
2025-02-10 08:34:49.672 [Debug] [AuthenticationViewModel.swift:89] updateAuthenticationStatus(_:) > PID: 71304 | success...
2025-02-10 08:34:49.672 [Debug] [Authenticatable.swift:145] setupAuthenticationFlow(lifetime:) > PID: 71304 | π didLogIn --> Completed
2025-02-10 08:34:49.672 [Debug] [ExtensionConnectionInteractor.swift:150] start(providerConfiguration:) > PID: 71304 | ποΈβ
Connection success 2BD1F
2025-02-10 08:34:49.672 [Debug] [AuthenticationViewModel.swift:89] updateAuthenticationStatus(_:) > PID: 71304 | success...
2025-02-10 08:34:49.672 [Debug] [Authenticatable.swift:145] setupAuthenticationFlow(lifetime:) > PID: 71304 | π didLogIn --> Completed
2025-02-10 08:34:49.673 [Debug] [ExtensionConnectionInteractor.swift:150] start(providerConfiguration:) > PID: 71304 | ποΈβ
Connection success 3F205
2025-02-10 08:34:49.673 [Debug] [AuthenticationViewModel.swift:89] updateAuthenticationStatus(_:) > PID: 71304 | success...
2025-02-10 08:34:49.673 [Debug] [Authenticatable.swift:145] setupAuthenticationFlow(lifetime:) > PID: 71304 | π didLogIn --> Completed
2025-02-10 08:34:49.673 [Debug] [ExtensionConnectionInteractor.swift:150] start(providerConfiguration:) > PID: 71304 | ποΈβ
Connection success 6BA62
2025-02-10 08:34:49.674 [Debug] [AuthenticationViewModel.swift:89] updateAuthenticationStatus(_:) > PID: 71304 | success...
2025-02-10 08:34:49.674 [Debug] [Authenticatable.swift:145] setupAuthenticationFlow(lifetime:) > PID: 71304 | π didLogIn --> Completed
2025-02-10 08:34:49.675 [Debug] [ExtensionConnectionInteractor.swift:150] start(providerConfiguration:) > PID: 71304 | ποΈβ
Connection success 3D807
2025-02-10 08:34:49.675 [Debug] [AuthenticationViewModel.swift:89] updateAuthenticationStatus(_:) > PID: 71304 | success...
2025-02-10 08:34:49.675 [Debug] [Authenticatable.swift:145] setupAuthenticationFlow(lifetime:) > PID: 71304 | π didLogIn --> Completed
2025-02-10 08:34:49.676 [Debug] [ExtensionConnectionInteractor.swift:150] start(providerConfiguration:) > PID: 71304 | ποΈβ
Connection success 7C9B0
2025-02-10 08:34:49.676 [Debug] [AuthenticationViewModel.swift:89] updateAuthenticationStatus(_:) > PID: 71304 | success...
2025-02-10 08:34:49.676 [Debug] [Authenticatable.swift:145] setupAuthenticationFlow(lifetime:) > PID: 71304 | π didLogIn --> Completed
2025-02-10 08:34:49.676 [Debug] [ExtensionConnectionInteractor.swift:150] start(providerConfiguration:) > PID: 71304 | ποΈβ
Connection success E408B
2025-02-10 08:34:49.676 [Debug] [AuthenticationViewModel.swift:89] updateAuthenticationStatus(_:) > PID: 71304 | success...
2025-02-10 08:34:49.676 [Debug] [Authenticatable.swift:145] setupAuthenticationFlow(lifetime:) > PID: 71304 | π didLogIn --> Completed
2025-02-10 08:34:49.677 [Debug] [ExtensionConnectionInteractor.swift:150] start(providerConfiguration:) > PID: 71304 | ποΈβ
Connection success C21C1
2025-02-10 08:34:49.677 [Debug] [AuthenticationViewModel.swift:89] updateAuthenticationStatus(_:) > PID: 71304 | success...
2025-02-10 08:34:49.677 [Debug] [Authenticatable.swift:145] setupAuthenticationFlow(lifetime:) > PID: 71304 | π didLogIn --> Completed
2025-02-10 08:34:49.678 [Debug] [ExtensionConnectionInteractor.swift:150] start(providerConfiguration:) > PID: 71304 | ποΈβ
Connection success 57EFC
2025-02-10 08:34:49.678 [Debug] [AuthenticationViewModel.swift:89] updateAuthenticationStatus(_:) > PID: 71304 | success...
2025-02-10 08:34:49.678 [Debug] [Authenticatable.swift:145] setupAuthenticationFlow(lifetime:) > PID: 71304 | π didLogIn --> Completed
2025-02-10 08:34:49.679 [Debug] [ExtensionConnectionInteractor.swift:150] start(providerConfiguration:) > PID: 71304 | ποΈβ
Connection success CF0A5
2025-02-10 08:34:49.679 [Debug] [AuthenticationViewModel.swift:89] updateAuthenticationStatus(_:) > PID: 71304 | success...
2025-02-10 08:34:49.679 [Debug] [Authenticatable.swift:145] setupAuthenticationFlow(lifetime:) > PID: 71304 | π didLogIn --> Completed
2025-02-10 08:34:49.679 [Debug] [ExtensionConnectionInteractor.swift:150] start(providerConfiguration:) > PID: 71304 | ποΈβ
Connection success 85337
2025-02-10 08:34:49.679 [Debug] [AuthenticationViewModel.swift:89] updateAuthenticationStatus(_:) > PID: 71304 | success...
2025-02-10 08:34:49.680 [Debug] [Authenticatable.swift:145] setupAuthenticationFlow(lifetime:) > PID: 71304 | π didLogIn --> Completed
2025-02-10 08:34:49.680 [Debug] [ExtensionConnectionInteractor.swift:150] start(providerConfiguration:) > PID: 71304 | ποΈβ
Connection success 5D0E3
2025-02-10 08:34:49.680 [Debug] [AuthenticationViewModel.swift:89] updateAuthenticationStatus(_:) > PID: 71304 | success...
2025-02-10 08:34:49.680 [Debug] [Authenticatable.swift:145] setupAuthenticationFlow(lifetime:) > PID: 71304 | π didLogIn --> Completed
I'm back with new logs. Just as a reminder, there's a 1-1 correspondence with the PushProvider subclass instantiated and the ExtensionConnectionInteractor. The interactor is only instantiated in the init of the PushProvider subclass.
Below is how the log starts out. The last 5 characters, after connection success, are from a UUID to identify the instance of the interactor. As requested the PID was added to the log.
2025-02-06 15:17:11.241 [Debug] [ExtensionClient.swift:453] setAndBroadcastAuthenticationState(_:error:) > ποΈποΈποΈ state: authenticated
2025-02-06 15:17:11.241 [Debug] [ExtensionConnectionInteractor.swift:150] start(providerConfiguration:) > PID: 65933 | ποΈβ
Connection success 0D170
2025-02-06 15:17:11.242 [Debug] [AuthenticationViewModel.swift:89] updateAuthenticationStatus(_:) > PID: 65933 | success...
Here's the system in the process of reconnection before it crashes. Note the date, it took about 3 days to get here. Note the same PID but separate instances of the interactor. This seems to imply multiple calls to instantiate the PushProvider subclass.
** many lines were removed due to character limit. But the lines are all calls from additional interactors trying to reconnect **
2025-02-10 07:02:01.751 [Debug] [ExtensionConnectionInteractor.swift:153] start(providerConfiguration:) > PID: 65933 | ποΈ Connection status: Optional(ReplicaShared.AuthenticationStatus.authenticating) 9C171
2025-02-10 07:02:01.751 [Debug] [AuthenticationViewModel.swift:93] updateAuthenticationStatus(_:) > PID: 65933 | authenticating
2025-02-10 07:02:01.751 [Debug] [Authenticatable.swift:101] setupAuthenticationFlow(lifetime:) > PID: 65933 | π didConnect --> Registering Device
2025-02-10 07:02:01.752 [Debug] [ExtensionConnectionInteractor.swift:153] start(providerConfiguration:) > PID: 65933 | ποΈ Connection status: Optional(ReplicaShared.AuthenticationStatus.authenticating) FD88C
2025-02-10 07:02:01.752 [Debug] [AuthenticationViewModel.swift:93] updateAuthenticationStatus(_:) > PID: 65933 | authenticating
2025-02-10 07:02:01.752 [Debug] [Authenticatable.swift:101] setupAuthenticationFlow(lifetime:) > PID: 65933 | π didConnect --> Registering Device
2025-02-10 07:02:01.752 [Debug] [ExtensionConnectionInteractor.swift:153] start(providerConfiguration:) > PID: 65933 | ποΈ Connection status: Optional(ReplicaShared.AuthenticationStatus.authenticating) B5416
2025-02-10 07:02:01.753 [Debug] [AuthenticationViewModel.swift:93] updateAuthenticationStatus(_:) > PID: 65933 | authenticating
2025-02-10 07:02:01.753 [Debug] [Authenticatable.swift:101] setupAuthenticationFlow(lifetime:) > PID: 65933 | π didConnect --> Registering Device
2025-02-10 07:02:01.754 [Debug] [ExtensionConnectionInteractor.swift:153] start(providerConfiguration:) > PID: 65933 | ποΈ Connection status: Optional(ReplicaShared.AuthenticationStatus.authenticating) 6C848
2025-02-10 07:02:01.754 [Debug] [AuthenticationViewModel.swift:93] updateAuthenticationStatus(_:) > PID: 65933 | authenticating
2025-02-10 07:02:01.754 [Debug] [Authenticatable.swift:101] setupAuthenticationFlow(lifetime:) > PID: 65933 | π didConnect --> Registering Device
2025-02-10 07:02:01.754 [Debug] [ExtensionConnectionInteractor.swift:153] start(providerConfiguration:) > PID: 65933 | ποΈ Connection status: Optional(ReplicaShared.AuthenticationStatus.authenticating) 31276
2025-02-10 07:02:01.755 [Debug] [AuthenticationViewModel.swift:93] updateAuthenticationStatus(_:) > PID: 65933 | authenticating
2025-02-10 07:02:01.755 [Debug] [Authenticatable.swift:101] setupAuthenticationFlow(lifetime:) > PID: 65933 | π didConnect --> Registering Device
2025-02-10 07:02:01.755 [Debug] [ExtensionConnectionInteractor.swift:153] start(providerConfiguration:) > PID: 65933 | ποΈ Connection status: Optional(ReplicaShared.AuthenticationStatus.authenticating) 51463
2025-02-10 07:02:01.755 [Debug] [AuthenticationViewModel.swift:93] updateAuthenticationStatus(_:) > PID: 65933 | authenticating
2025-02-10 07:02:01.756 [Debug] [Authenticatable.swift:101] setupAuthenticationFlow(lifetime:) > PID: 65933 | π didConnect --> Registering Device
2025-02-10 07:02:01.756 [Debug] [ExtensionConnectionInteractor.swift:153] start(providerConfiguration:) > PID: 65933 | ποΈ Connection status: Optional(ReplicaShared.AuthenticationStatus.authenticating) CD715
2025-02-10 07:02:01.756 [Debug] [AuthenticationViewModel.swift:93] updateAuthenticationStatus(_:) > PID: 65933 | authenticating
2025-02-10 07:02:01.757 [Debug] [Authenticatable.swift:101] setupAuthenticationFlow(lifetime:) > PID: 65933 | π didConnect --> Registering Device
2025-02-10 07:02:01.757 [Debug] [ExtensionConnectionInteractor.swift:153] start(providerConfiguration:) > PID: 65933 | ποΈ Connection status: Optional(ReplicaShared.AuthenticationStatus.authenticating) 21B76
2025-02-10 07:02:01.757 [Debug] [AuthenticationViewModel.swift:93] updateAuthenticationStatus(_:) > PID: 65933 | authenticating
2025-02-10 07:02:01.758 [Debug] [Authenticatable.swift:101] setupAuthenticationFlow(lifetime:) > PID: 65933 | π didConnect --> Registering Device
2025-02-10 07:02:01.758 [Debug] [ExtensionConnectionInteractor.swift:153] start(providerConfiguration:) > PID: 65933 | ποΈ Connection status: Optional(ReplicaShared.AuthenticationStatus.authenticating) B46CF
2025-02-10 07:02:01.758 [Debug] [AuthenticationViewModel.swift:93] updateAuthenticationStatus(_:) > PID: 65933 | authenticating
2025-02-10 07:02:01.758 [Debug] [Authenticatable.swift:101] setupAuthenticationFlow(lifetime:) > PID: 65933 | π didConnect --> Registering Device
2025-02-10 07:02:01.759 [Debug] [ExtensionConnectionInteractor.swift:153] start(providerConfiguration:) > PID: 65933 | ποΈ Connection status: Optional(ReplicaShared.AuthenticationStatus.authenticating) 4F224
2025-02-10 07:02:01.759 [Debug] [AuthenticationViewModel.swift:93] updateAuthenticationStatus(_:) > PID: 65933 | authenticating
2025-02-10 07:02:01.759 [Debug] [Authenticatable.swift:101] setupAuthenticationFlow(lifetime:) > PID: 65933 | π didConnect --> Registering Device
2025-02-10 07:02:01.759 [Debug] [ExtensionConnectionInteractor.swift:153] start(providerConfiguration:) > PID: 65933 | ποΈ Connection status: Optional(ReplicaShared.AuthenticationStatus.authenticating) EDC79
2025-02-10 07:02:01.760 [Debug] [AuthenticationViewModel.swift:93] updateAuthenticationStatus(_:) > PID: 65933 | authenticating
2025-02-10 07:02:01.760 [Debug] [Authenticatable.swift:101] setupAuthenticationFlow(lifetime:) > PID: 65933 | π didConnect --> Registering Device
2025-02-10 07:02:01.760 [Debug] [ExtensionConnectionInteractor.swift:153] start(providerConfiguration:) > PID: 65933 | ποΈ Connection status: Optional(ReplicaShared.AuthenticationStatus.authenticating) D2257
2025-02-10 07:02:01.760 [Debug] [AuthenticationViewModel.swift:93] updateAuthenticationStatus(_:) > PID: 65933 | authenticating
As a general note on this, if you're doing your own logging I recommend including the pid in every log message. It takes up minimal space and I've seen way to many cases where it was the one detail that suddenly made everything clear.
Will do, need to check my assumptions and include the PID.
The exact behavior depend on the device state, but if the device has plenty of empty space and hasn't been rebooted, then the sysdiagnose will often to back 24+ hours. The one thing to be aware of is that the system does start purging data (particularly when space is constrained) and this purging is by system/subsystem, not just time. In concrete terms, many logs often go back a very long time but on closer inspection you'll find that there are significant process (like, "the kernel") missing from those older log messages. Regardless, the next step here is to pull the log data and see what you find.
I read your posts on using the system log and I'm going to include them next since they'll be good to have in our release build. Right now in our debug builds we log to file in the documents directory. As a fast fix I added the PID to existing logs.
Gotcha I'll be sure to get the critical information, PIDs and timestamps. They'll be in the next long term test in QA. I'll report back when I get something. Thank you.
I'll keep that in mind, but for my situation it takes approximately 4-8 hours for the issue to occur and I'm not sure if system log will go back that far.
But let me give you an example of what I'm seeing. When I first init you'll see this
> ποΈ Connection status: Optional(AuthenticationStatus.connecting)
> ποΈ Connection status: Optional(AuthenticationStatus.authenticating)
> ποΈβ‘οΈ didLogIn
Later I see it init
ποΈπͺ¬πͺ¬ποΈ MyPushProvider Init D6E50D82-3671-4ED9-BBA4-411F8FB854C4
Then I see the following
> ποΈ Connection status: Optional(ReplicaShared.AuthenticationStatus.connecting)
> ποΈ Connection status: Optional(ReplicaShared.AuthenticationStatus.connecting)
> ποΈ Connection status: Optional(ReplicaShared.AuthenticationStatus.authenticating)
> ποΈ Connection status: Optional(ReplicaShared.AuthenticationStatus.authenticating)
> ποΈβ‘οΈ didLogIn
With ever init log, I'll see an additional print for the connection status.
So after the 3rd MyPushProvider Init I'll see a third log, and so on. So it seems likely, at least from what I see, that there are multiple Push Providers in existence at once. I'm adding additional logs to keep track of which instances are giving out their status as well as what their provider info, such as provider configuration info.
From the app, I only saved one configuration and it tracks to a minute or less before the first log where this push provider is initialized. Other than that there are no other saves to the push configuration manager. I feel pretty stuck because it doesn't seem like I control what calls MyPushProvider()
You say you don't have specific experience with the NEAppPushProvider, is there a way to get into someone else who does?
I'm pretty stuck, and if you can unstuck me then I'll be super grateful. Thanks.
This was the response I received from the Swift forum
https://forums.swift.org/t/asyncstream-stops-yielding-values/75514
mbrandonw
Brandon Williams
4m
Hi @Biclops, if I'm reading your code correctly it seems that you are subscribing to an AsyncStream twice: once in setupAsyncWrites and once in waitForHandshakedone. Unfortunately AsyncStream does not support multiple subscribers. You can look into using AsyncChannel from the swift-async-algorithms package, but it's also subtly different. In particular, the channel.send method will suspend until someone consumes the value being emitted.