Amplify.API.subscribe can not be connected to server in the first time launch app

[santoso8118]

Describe the bug

When user login to our app
We config Amplify with below configurations:

 if let url = url {
       do {
            try Amplify.add(plugin: AWSCognitoAuthPlugin())
            try Amplify.add(plugin: AWSAPIPlugin())
            try Amplify.add(plugin: AWSPinpointAnalyticsPlugin())
            
            let configuration = try AmplifyConfiguration(configurationFile: url)
            try Amplify.configure(configuration)
            
        } catch {
            // Need to handle error if Amplify init fails
            print("Failed to initialize Amplify with \(error.localizedDescription)")
        }
}

In the first time install app and open app then login successfully then we call Amplify.API.subscribe to our subscription but I only got failed connection and we can not receive any datas from server, the states as below:

1. connecting
2. disconnected (when we call cancel)

As normal connection states should be as below:

1. connecting
2. connected
3. disconnected (when we call cancel)

The issue only happen for the first time subcribe. In the second time we successfully connect and get data
After relaunch the app and we try Amplify.API.subscribe again, all subscriptions are working fine.

Steps To Reproduce

1. Refresh Install Application
2. Login to app
3. Then call **Amplify.API.subscribe** realtime data
4. For the fist time subscribe the connection does not successfully
5. In the second time we call **Amplify.API.subscribe** for the same realtime event it can connect successfully and return the data correcly

Expected behavior

Amplify.API.subscribe should always connect successfully even the very first time

Amplify Framework Version

2.33.3

Amplify Categories

API

Dependency manager

Swift PM

Swift version

5.10

CLI version

12.12.4

Xcode version

15.2

Relevant log output

<details>
<summary>Log Messages</summary>


INSERT LOG MESSAGES HERE

```

Is this a regression?

No

Regression additional context

No response

Platforms

iOS

OS Version

iOS 16.2

Device

iPhone 11

Specific to simulators

No response

Additional context

No response

[harsh62]

Thanks for opening the issue. Our team will look into the issue and provide update.

[santoso8118]

@harsh62
Could you check why Amplify.API.subscribe returns connecting state and never returns connected state ?

[lawmicha]

Hi @santoso8118, do you have any verbose logs we can investigate to see what is happening? Do you have Amplify.Logging.logLevel = .verbose set?

[santoso8118]

Thanks @lawmicha
I will set log level and update to you

[santoso8118]

Hi @lawmicha
This is the log when the issue happen its failed to subscribe and returns timeout error
Could you help to check what is the issue

[APIAppSyncRealTimeClient] [AppSyncRealTimeClient] Received subscription request id: 13BCE33A-4FAB-4488-B36A-DE17EDFDDDA9, query: {"variables":{"userId":"12fc012c-1893-4b2e-886e-9f9601bc974d"},"query":"subscription RefreshMockEvent($userId: String!) {\n  refreshMockEvent(userId: $userId) {\n    __typename\n    userId\n    eventType\n    message\n    distance\n    chargeAmount\n    detailMessage\n    data\n  }\n}"}
2024-08-27 10:38:25.598221+0800  [APIAppSyncRealTimeSubscription] [AppSyncRealTimeSubscription-13BCE33A-4FAB-4488-B36A-DE17EDFDDDA9] Start subscribing
10:38:25.598 AM 💚 DEBUG AppSync.subscribeToMockObuEvent():237 - Subscription subscribeToMockObuEvent connect state is connecting
10:38:25.598 AM 💚 DEBUG AppSync.subscribeToMockObuEvent():237 - Subscription subscribeToMockObuEvent connect state is connecting
10:38:25.599 AM 💚 DEBUG AppSync.subscribeToMockObuEvent():237 - Subscription subscribeToMockObuEvent connect state is connecting
2024-08-27 10:38:25.600461+0800  [WebSocketClient] [WebSocketClient] WebSocket write message string: {"type":"start","id":"13BCE33A-4FAB-4488-B36A-DE17EDFDDDA9","payload":{"data":"{\"variables\":{\"userId\":\"12fc012c-1893-4b2e-886e-9f9601bc974d\"},\"query\":\"subscription RefreshMockEvent($userId: String!) {\\n  refreshMockEvent(userId: $userId) {\\n    __typename\\n    userId\\n    eventType\\n    message\\n    distance\\n    chargeAmount\\n    detailMessage\\n    data\\n  }\\n}\"}","extensions":{"authorization":{"host":"hsjyntfl6vfxfcbya6rr2mi2p4.appsync-api.ap-southeast-1.amazonaws.com","Authorization":"eyJraWQiOiJYTm9rMU5PNnd5VmxWbkdcL0Vib1wveUhkY3Y4VTREcHpRYjBVWjJrWnpwWDA9IiwiYWxnIjoiUlMyNTYifQ.eyJzdWIiOiIxMmZjMDEyYy0xODkzLTRiMmUtODg2ZS05Zjk2MDFiYzk3NGQiLCJjb2duaXRvOmdyb3VwcyI6WyJhcC1zb3V0aGVhc3QtMV9LakdEWHRlUHFfU2lnbkluV2l0aEFwcGxlIl0sImlzcyI6Imh0dHBzOlwvXC9jb2duaXRvLWlkcC5hcC1zb3V0aGVhc3QtMS5hbWF6b25hd3MuY29tXC9hcC1zb3V0aGVhc3QtMV9LakdEWHRlUHEiLCJ2ZXJzaW9uIjoyLCJjbGllbnRfaWQiOiIzb2t2dTY2MGNmbWRmZ2JmYzI4M2gwMzJhbiIsInRva2VuX3VzZSI6ImFjY2VzcyIsInNjb3BlIjoiYXdzLmNvZ25pdG8uc2lnbmluLnVzZXIuYWRtaW4gb3BlbmlkIHByb2ZpbGUiLCJhdXRoX3RpbWUiOjE3MjQ3MjYxOTMsImV4cCI6MTcyNDgxMjU5MywiaWF0IjoxNzI0NzI2MTkzLCJqdGkiOiIwZjQ0YWE0My01MmZhLTRjNzktODViMS0xOGJhMTg5YjQ1ZWUiLCJ1c2VybmFtZSI6InNpZ25pbndpdGhhcHBsZV8wMDEyNTcuNTc2MzdlZmEwMDg1NDhkNzhjNjQ2NzIyMTM5N2E1OTQuMTAwMyJ9.zMhv03jBqgV_VIHjIttiNPMi3o4bbLL7Ht50YmvfGR8Tk7O4TMmDMHvY3m2O2GkldRJRSnFy6Ogotxbi-cppM_E67NeTfuYcZzlWyqFgVPiMCoWWO7oMTbHGzxmEm2h-eWlnZjGlUTrdGEclx9hB9GVjm1hj6L_4mfjGdqcpNIwJe71oEf4W5mRbNLD6V4kCNX4ajtbSLKEYyrtJXjG0Y88tFaj013qLPj2t5XNdNZwIrqDnps6a99nZ0FNUVaMnTxSh_jGLq6Tc1kuxM5FzjDBiVbIWBg4ItiS3Ir-RJ1lAPCKSkXNB26dYcBRXpKMcp-PMJFqurkH9eKeZvHrGow"}}}}
2024-08-27 10:38:25.609249+0800  [APIAppSyncRealTimeClient] [AppSyncRealTimeClient]Failed to send AppSync request start(AWSAPIPlugin.AppSyncRealTimeRequest.StartRequest(id: "13BCE33A-4FAB-4488-B36A-DE17EDFDDDA9", data: "{\"variables\":{\"userId\":\"12fc012c-1893-4b2e-886e-9f9601bc974d\"},\"query\":\"subscription RefreshMockEvent($userId: String!) {\\n  refreshMockEvent(userId: $userId) {\\n    __typename\\n    userId\\n    eventType\\n    message\\n    distance\\n    chargeAmount\\n    detailMessage\\n    data\\n  }\\n}\"}", auth: nil)), error: Error Domain=kNWErrorDomainPOSIX Code=53 "Software caused connection abort" UserInfo={NSDescription=Software caused connection abort}
2024-08-27 10:38:30.600763+0800  [APIAppSyncRealTimeSubscription] [AppSyncRealTimeSubscription-13BCE33A-4FAB-4488-B36A-DE17EDFDDDA9] Failed to subscribe, error: timeout

[AnirudhWinimy]

@lawmicha
This seems to be related to #3632
@santoso8118 and i have noticed that this happens when moving the app to background and foreground.

The app sync subscription is unable to recover after it disconnects when app is in background.

Even after upgrading to 2.37.0 we still see the error. However now we receive the following error in addition in log in 2.37.0:

Amplify.APIError error 3.

[lawmicha]

Hi @AnirudhWinimy / @santoso8118 , from my understanding, the changes made by @5d (please chime in if I'm wrong here) in #3800 for #3632 released in 2.37.0 will propagate the connection lost error back to the caller.

The APIError has an error description, recovery suggestion, and optional underlying error. In the PR, we are returning APIError.networkError with an underlying error of URLError(.networkConnectionLost) code line 411. Is this what you are getting when you reproduce the scenario of backgrounding to foregrounding? If so, you can check if the underlying error is the URLError networkConnectionLost and perform subscribe to retry connecting to websocket and establishing the subscription.

[santoso8118]

Hi @lawmicha :

When the error happens we try to perform subscription again its always got failed with the same error.
Base on the timing that SDK give log error timeout, its not a timeout actually. It seems the subscription get timeout immediately when I call subscribe again.

By the way could you tell me how long subscription get timeout if can not connect to server ?

[AnirudhWinimy]

@lawmicha

When the error happens we try to perform subscription again its always got failed with the same error. Base on the timing that SDK give log error timeout, its not a timeout actually. It seems the subscription get timeout immediately when I call subscribe again.

By the way could you tell me how long subscription get timeout if can not connect to server ?

To elaborate further, your suggestion works when we downgrade to version 2.28.0, i.e we can re-subscribe when the app is back to the foreground.

However since upgrading to 2.33.3 (and even on 2.37.0) whenever the app goes to the background and returns to the foreground, calling re-subscribe consistently fails with a network timeout error almost immediately. In reality there is no connection error and any mutations sent works.

The error lines when attempting to re-subscribe are shared in
#3831 (comment)

2024-08-27 10:38:25.609249+0800  [APIAppSyncRealTimeClient] [AppSyncRealTimeClient]Failed to send AppSync request start(AWSAPIPlugin.AppSyncRealTimeRequest.StartRequest(id: "13BCE33A-4FAB-4488-B36A-DE17EDFDDDA9", data: "{\"variables\":{\"userId\":\"12fc012c-1893-4b2e-886e-9f9601bc974d\"},\"query\":\"subscription RefreshMockEvent($userId: String!) {\\n  refreshMockEvent(userId: $userId) {\\n    __typename\\n    userId\\n    eventType\\n    message\\n    distance\\n    chargeAmount\\n    detailMessage\\n    data\\n  }\\n}\"}", auth: nil)), error: Error Domain=kNWErrorDomainPOSIX Code=53 "Software caused connection abort" UserInfo={NSDescription=Software caused connection abort}
2024-08-27 10:38:30.600763+0800  [APIAppSyncRealTimeSubscription] [AppSyncRealTimeSubscription-13BCE33A-4FAB-4488-B36A-DE17EDFDDDA9] Failed to subscribe, error: timeout

[5d]

Hi @lawmicha This is the log when the issue happen its failed to subscribe and returns timeout error Could you help to check what is the issue

[APIAppSyncRealTimeClient] [AppSyncRealTimeClient] Received subscription request id: 13BCE33A-4FAB-4488-B36A-DE17EDFDDDA9, query: {"variables":{"userId":"12fc012c-1893-4b2e-886e-9f9601bc974d"},"query":"subscription RefreshMockEvent($userId: String!) {\n  refreshMockEvent(userId: $userId) {\n    __typename\n    userId\n    eventType\n    message\n    distance\n    chargeAmount\n    detailMessage\n    data\n  }\n}"}
2024-08-27 10:38:25.598221+0800  [APIAppSyncRealTimeSubscription] [AppSyncRealTimeSubscription-13BCE33A-4FAB-4488-B36A-DE17EDFDDDA9] Start subscribing
10:38:25.598 AM 💚 DEBUG AppSync.subscribeToMockObuEvent():237 - Subscription subscribeToMockObuEvent connect state is connecting
10:38:25.598 AM 💚 DEBUG AppSync.subscribeToMockObuEvent():237 - Subscription subscribeToMockObuEvent connect state is connecting
10:38:25.599 AM 💚 DEBUG AppSync.subscribeToMockObuEvent():237 - Subscription subscribeToMockObuEvent connect state is connecting
2024-08-27 10:38:25.600461+0800  [WebSocketClient] [WebSocketClient] WebSocket write message string: {"type":"start","id":"13BCE33A-4FAB-4488-B36A-DE17EDFDDDA9","payload":{"data":"{\"variables\":{\"userId\":\"12fc012c-1893-4b2e-886e-9f9601bc974d\"},\"query\":\"subscription RefreshMockEvent($userId: String!) {\\n  refreshMockEvent(userId: $userId) {\\n    __typename\\n    userId\\n    eventType\\n    message\\n    distance\\n    chargeAmount\\n    detailMessage\\n    data\\n  }\\n}\"}","extensions":{"authorization":{"host":"hsjyntfl6vfxfcbya6rr2mi2p4.appsync-api.ap-southeast-1.amazonaws.com","Authorization":"eyJraWQiOiJYTm9rMU5PNnd5VmxWbkdcL0Vib1wveUhkY3Y4VTREcHpRYjBVWjJrWnpwWDA9IiwiYWxnIjoiUlMyNTYifQ.eyJzdWIiOiIxMmZjMDEyYy0xODkzLTRiMmUtODg2ZS05Zjk2MDFiYzk3NGQiLCJjb2duaXRvOmdyb3VwcyI6WyJhcC1zb3V0aGVhc3QtMV9LakdEWHRlUHFfU2lnbkluV2l0aEFwcGxlIl0sImlzcyI6Imh0dHBzOlwvXC9jb2duaXRvLWlkcC5hcC1zb3V0aGVhc3QtMS5hbWF6b25hd3MuY29tXC9hcC1zb3V0aGVhc3QtMV9LakdEWHRlUHEiLCJ2ZXJzaW9uIjoyLCJjbGllbnRfaWQiOiIzb2t2dTY2MGNmbWRmZ2JmYzI4M2gwMzJhbiIsInRva2VuX3VzZSI6ImFjY2VzcyIsInNjb3BlIjoiYXdzLmNvZ25pdG8uc2lnbmluLnVzZXIuYWRtaW4gb3BlbmlkIHByb2ZpbGUiLCJhdXRoX3RpbWUiOjE3MjQ3MjYxOTMsImV4cCI6MTcyNDgxMjU5MywiaWF0IjoxNzI0NzI2MTkzLCJqdGkiOiIwZjQ0YWE0My01MmZhLTRjNzktODViMS0xOGJhMTg5YjQ1ZWUiLCJ1c2VybmFtZSI6InNpZ25pbndpdGhhcHBsZV8wMDEyNTcuNTc2MzdlZmEwMDg1NDhkNzhjNjQ2NzIyMTM5N2E1OTQuMTAwMyJ9.zMhv03jBqgV_VIHjIttiNPMi3o4bbLL7Ht50YmvfGR8Tk7O4TMmDMHvY3m2O2GkldRJRSnFy6Ogotxbi-cppM_E67NeTfuYcZzlWyqFgVPiMCoWWO7oMTbHGzxmEm2h-eWlnZjGlUTrdGEclx9hB9GVjm1hj6L_4mfjGdqcpNIwJe71oEf4W5mRbNLD6V4kCNX4ajtbSLKEYyrtJXjG0Y88tFaj013qLPj2t5XNdNZwIrqDnps6a99nZ0FNUVaMnTxSh_jGLq6Tc1kuxM5FzjDBiVbIWBg4ItiS3Ir-RJ1lAPCKSkXNB26dYcBRXpKMcp-PMJFqurkH9eKeZvHrGow"}}}}
2024-08-27 10:38:25.609249+0800  [APIAppSyncRealTimeClient] [AppSyncRealTimeClient]Failed to send AppSync request start(AWSAPIPlugin.AppSyncRealTimeRequest.StartRequest(id: "13BCE33A-4FAB-4488-B36A-DE17EDFDDDA9", data: "{\"variables\":{\"userId\":\"12fc012c-1893-4b2e-886e-9f9601bc974d\"},\"query\":\"subscription RefreshMockEvent($userId: String!) {\\n  refreshMockEvent(userId: $userId) {\\n    __typename\\n    userId\\n    eventType\\n    message\\n    distance\\n    chargeAmount\\n    detailMessage\\n    data\\n  }\\n}\"}", auth: nil)), error: Error Domain=kNWErrorDomainPOSIX Code=53 "Software caused connection abort" UserInfo={NSDescription=Software caused connection abort}
2024-08-27 10:38:30.600763+0800  [APIAppSyncRealTimeSubscription] [AppSyncRealTimeSubscription-13BCE33A-4FAB-4488-B36A-DE17EDFDDDA9] Failed to subscribe, error: timeout

Hi @santoso8118

According to the log, the websocket encountered a kernel-level error: kNWErrorDomainPOSIX with code 53, indicating "Software caused connection abort." This error typically occurs when the application is moved to the background.

The subscription timeout error happens 5 seconds after the request is sent, which is expected behavior since we’ve set a default 5-second timeout for a connected websocket to receive a response from the server.

To better understand the complete testing scenario, could you provide the full log from when you reproduce this issue? This additional information would help us gain a more comprehensive view of the problem and its context.

ref:

• https://opensource.apple.com/source/xnu/xnu-792/bsd/sys/errno.h.auto.html
• https://github.com/aws-amplify/amplify-swift/blob/main/AmplifyPlugins/API/Sources/AWSAPIPlugin/AppSyncRealTimeClient/AppSyncRealTimeClient%2BHandleRequest.swift#L23

[santoso8118]

Hi @lawmicha

We already share all the logs that we have after enable the verbose log and reproduce the issue.
As you said the subscription get timeout after 5 seconds its fine.
But after app enters background the web socket got disconnected and then app comes back to foreground again we can not subscribe app sync event again successfully.

I see that there are some release versions recently that fixed issues relate to appsync and web socket connection.
Do you know any released version that fixed this issue. Please advice!

[tylerjroach]

Hi @santoso8118,

We are currently trying to replicate the behavior on our latest version and will get back to you once we have an answer. Thank you for the log provided here and the code example with support.

[harsh62]

@santoso8118

So I spend considerable time trying to reproduce the issue and was unable to see the subscription error reported. I have tried on both the latest version of Amplify and also on the affected version (2.33.3) in the ticket. Amplify behaves consistently every time.

• I have tried foregrounding and backgrounding the app multiple times.
• I have also tried regular subscription initiations and cancellations.

I have followed the Amplify documentation guide to setup a simple app to reproduce the issue in an isolated environment.

My subscription code is exactly the same mentioned in the documentation and I am using the following strategy to test backgrounding and foregrounding the app.

// Create an observable object instance.
    @StateObject var vm = TodoViewModel()
    @Environment(\.scenePhase) var scenePhase

    var body: some View {
        VStack {
            Text("Hello")
                .onChange(of: scenePhase) { oldPhase, newPhase in
                    if newPhase == .active {
                        print("App is Active, start subscription ")
                        vm.subscribe()
                    } else if newPhase == .background {
                        print("App Backgrounded, cancel subscription")
                        vm.cancel()
                    }
                }
            }
        }
   }

Just so that everybody is on the same page, following is my view models subscription and cancellation calls.

    // Subscription
    private var subscription: AmplifyAsyncThrowingSequence<GraphQLSubscriptionEvent<Todo>>? = nil

    func subscribe() {
        self.subscription = Amplify.API.subscribe(request: .subscription(of: Todo.self, type: .onCreate))
        Task {
            guard let subscription = subscription else { return }
            do {
                for try await subscriptionEvent in subscription {
                    handleSubscriptionEvent(subscriptionEvent)
                }
            } catch {
                print("Subscription has terminated with \(error)")
            }
        }
    }

    // Cancel subscription
    func cancel() {
        self.subscription?.cancel()
    }

---

App verbose Logs that I have observed during my debugging session

• Subscription

Active
[AppSyncRealTimeClient] Received subscription request id: 226D41DB-50D7-4F3A-BDEC-F729E556BAB2, query: {"query":"subscription OnCreateTodo {\n  onCreateTodo {\n    id\n    content\n    createdAt\n    updatedAt\n    __typename\n  }\n}"}
[AppSyncRealTimeClient] client start connecting
[WebSocketClient] WebSocket about to connect
[WebSocketClient] Creating new connection and starting read
[WebSocketClient] WebSocket write message string: {"type":"connection_init"}
[WebSocketClient] Websocket connected
[AppSyncRealTimeClient] Received websocket event connected
[AppSyncRealTimeClient] WebSocket connected
[WebSocketClient] WebSocket received message: string("{\"type\":\"connection_ack\",\"payload\":{\"connectionTimeoutMs\":300000}}")
[AppSyncRealTimeClient] Received websocket event string("{\"type\":\"connection_ack\",\"payload\":{\"connectionTimeoutMs\":300000}}")
[WebSocketClient] WebSocket received message: string("{\"type\":\"ka\"}")
[AppSyncRealTimeClient] AppSync connected: Optional(Amplify.JSONValue.object(["connectionTimeoutMs": Amplify.JSONValue.number(300000.0)]))
[AppSyncRealTimeClient] Resuming existing subscriptions
[AppSyncRealTimeClient] Starting heart beat monitor with interval 300000 ms
[AppSyncRealTimeClient] Received websocket event string("{\"type\":\"ka\"}")
[AppSyncRealTimeSubscription-226D41DB-50D7-4F3A-BDEC-F729E556BAB2] Start subscribing
Subscription connect state is connecting
[AppSyncRealTimeSubscription-226D41DB-50D7-4F3A-BDEC-F729E556BAB2] Subscription already in subscribing state
[WebSocketClient] WebSocket write message string: {"payload":{"data":"{\"query\":\"subscription OnCreateTodo {\\n  onCreateTodo {\\n    id\\n    content\\n    createdAt\\n    updatedAt\\n    __typename\\n  }\\n}\"}","extensions":{"authorization":{"x-api-key":"****","x-amz-date":"20241127T181527Z","host":"****"}}},"type":"start","id":"226D41DB-50D7-4F3A-BDEC-F729E556BAB2"}
[WebSocketClient] WebSocket received message: string("{\"id\":\"226D41DB-50D7-4F3A-BDEC-F729E556BAB2\",\"type\":\"start_ack\"}")
[AppSyncRealTimeClient] Received websocket event string("{\"id\":\"226D41DB-50D7-4F3A-BDEC-F729E556BAB2\",\"type\":\"start_ack\"}")
[AppSyncRealTimeClient] AppSync received response: AppSyncRealTimeResponse(id: Optional("226D41DB-50D7-4F3A-BDEC-F729E556BAB2"), payload: nil, type: AWSAPIPlugin.AppSyncRealTimeResponse.EventType.startAck)
[AppSyncRealTimeSubscription-226D41DB-50D7-4F3A-BDEC-F729E556BAB2] Subscribed
Subscription connect state is connected

• Cancellation

Inactive
Background
[AppSyncRealTimeClient] unsubscribing: 9927DAD3-7EDC-430B-976F-EB73741C7A1A
[AppSyncRealTimeSubscription-9927DAD3-7EDC-430B-976F-EB73741C7A1A] Unsubscribing
[WebSocketClient] WebSocket write message string: {"id":"9927DAD3-7EDC-430B-976F-EB73741C7A1A","type":"stop"}
[WebSocketClient] WebSocket received message: string("{\"id\":\"9927DAD3-7EDC-430B-976F-EB73741C7A1A\",\"type\":\"complete\"}")
[AppSyncRealTimeClient] Received websocket event string("{\"id\":\"9927DAD3-7EDC-430B-976F-EB73741C7A1A\",\"type\":\"complete\"}")
[AppSyncRealTimeClient] AppSync received response: AppSyncRealTimeResponse(id: Optional("9927DAD3-7EDC-430B-976F-EB73741C7A1A"), payload: nil, type: AWSAPIPlugin.AppSyncRealTimeResponse.EventType.stopAck)
[AppSyncRealTimeSubscription-9927DAD3-7EDC-430B-976F-EB73741C7A1A] Unsubscribed
[AppSyncRealTimeClient] deleted subscription with id: 9927DAD3-7EDC-430B-976F-EB73741C7A1A
[AppSyncRealTimeClient] no subscription exist, client is trying to disconnect
[AppSyncRealTimeClient] client start disconnecting
[AppSyncRealTimeSubscription-9927DAD3-7EDC-430B-976F-EB73741C7A1A] Subscription should be subscribed to be unsubscribed
[AppSyncRealTimeSubscription-9927DAD3-7EDC-430B-976F-EB73741C7A1A] Subscription should be subscribed to be unsubscribed
[AppSyncRealTimeClient] client is disconnected
[WebSocketClient] Websocket disconnected

• Resubscription

Active
[AppSyncRealTimeClient] Received subscription request id: 8D72C7F3-F21F-4B84-9C06-E0FE636739AD, query: {"query":"subscription OnCreateTodo {\n  onCreateTodo {\n    id\n    content\n    createdAt\n    updatedAt\n    __typename\n  }\n}"}
[WebSocketClient] WebSocket received message: string("{\"type\":\"ka\"}")
[WebSocketClient] WebSocket received message: string("{\"type\":\"ka\"}")
[AppSyncRealTimeSubscription-8D72C7F3-F21F-4B84-9C06-E0FE636739AD] Start subscribing
Subscription connect state is connecting
[AppSyncRealTimeClient] Received websocket event string("{\"type\":\"ka\"}")
[AppSyncRealTimeClient] Received websocket event string("{\"type\":\"ka\"}")
[WebSocketClient] WebSocket write message string: {"payload":{"extensions":{"authorization":{"host":"***","x-amz-date":"20241127T185414Z","x-api-key":"****"}},"data":"{\"query\":\"subscription OnCreateTodo {\\n  onCreateTodo {\\n    id\\n    content\\n    createdAt\\n    updatedAt\\n    __typename\\n  }\\n}\"}"},"type":"start","id":"8D72C7F3-F21F-4B84-9C06-E0FE636739AD"}
[WebSocketClient] WebSocket received message: string("{\"id\":\"8D72C7F3-F21F-4B84-9C06-E0FE636739AD\",\"type\":\"start_ack\"}")
[AppSyncRealTimeClient] Received websocket event string("{\"id\":\"8D72C7F3-F21F-4B84-9C06-E0FE636739AD\",\"type\":\"start_ack\"}")
[AppSyncRealTimeClient] AppSync received response: AppSyncRealTimeResponse(id: Optional("8D72C7F3-F21F-4B84-9C06-E0FE636739AD"), payload: nil, type: AWSAPIPlugin.AppSyncRealTimeResponse.EventType.startAck)
[AppSyncRealTimeSubscription-8D72C7F3-F21F-4B84-9C06-E0FE636739AD] Subscribed
Subscription connect state is connected

---

As of next steps, I would suggest that try to reproduce the issue in a local isolated environment and share that with the team otherwise its very difficult to further investigate the issue.

[AnirudhWinimy]

@harsh62

We recently migrated from AWS AppSync SDK for iOS to aws amplify sdk as per the deprecation notice (https://github.com/awslabs/aws-mobile-appsync-sdk-ios)

In the official aws notification for us to migrate we were provided the following link to upgrade which we are following
https://docs.amplify.aws/gen1/swift/build-a-backend/graphqlapi/upgrade-guide/

We are using a similar mechanism to subscribe shared in the link above

  let refreshDataSetMutation = RefreshDataSetSubscription(notificationType: key)
    let graphQLRequest = GraphQLRequest(document: RefreshDataSetSubscription.operationString, variables: refreshDataSetMutation.variables?.jsonObject, responseType: RefreshDataSetSubscription.Data.self)
    let subscription = Amplify.API.subscribe(request: graphQLRequest)

The above works for the first time launch and the re-subscribe from background to foreground works in 2.28.0 using the above mechanism.

However after upgrading above 2.28.0 this mechanism stops working.

[tylerjroach]

Hi @AnirudhWinimy,

Using the latest version of Amplify, can you please attempt to create a sample app demonstrating the bug that you are experiencing and we could pull that app down and test? As @harsh62 mentioned, we have been unable to reproduce the reported bug that is being described.

[AnirudhWinimy]

@tylerjroach @harsh62

We now suspect the issue was caused due to a forceful disconnection to the appsync websocket connection that was initiated by the os, when the app moved to the background. This (app connections termination in background) is something that we observed and seems to be valid scenario as per the ios documentation.

This was observed when testing on multiple devices on builds using Xcode 15.2 targeting ios 16.2 .

However after upgrading the xcode and ios version to version 18, we are unable to reproduce even the forceful connection disconnection event triggered by the os in the background. And thereby unable to reproduce this issue in the affected amplify sdk versions ( i.e versions above 2.28.0) in ios 18.

Our next step is to try to rollback our version to match the original environment and see if we can reproduce the issue.

[tylerjroach]

Thank you for the status update. If you discover anything, please let us know.