How to prevent sending request after an error occurred?

[kosukeohmura]

Question Checklist

• [x] Updated grpc-swift to the latest version
• [x] I read the Contribution Guidelines
• [x] I read README
• [x] I searched for existing GitHub issues (especially, there are many resolved issues related to SSL)

Question Subject

version: 1.0.0-alpha.9

I use gRPC Swift for developing an iOS app. When I call unary RPC under flight mode, I get a deadlineExceeded error but server receives the Unary request that should not be sent.

Would anyone tell me how to prevent sending request after I've got a call error, please?

Question Description

Process to reproduce:

• make connection and client:

let eventLoopGroup = MultiThreadedEventLoopGroup(numberOfThreads: 1)
let connectionConfig = ClientConnection.Configuration(target: .hostAndPort("example.com", 443), eventLoopGroup: eventLoopGroup)
let connection = ClientConnection(configuration: connectionConfig)
let service = MyServiceClient(connection: connection)

• turn on flight mode
• request Unary gRPC call and wait for the result:

let call = service.postSomething(MyRequest("✈️")) // UnaryCall
let callResultEventLoop = call.status.and(call.trailingMetadata).and(call.response)
callResultEventLoop.whenSuccess { _ in
    print("Got a response.")
}
callResultEventLoop.whenFailure { error in
    print("Got an error: \(error)")
}

• get an error log like below because it is under flight mode:

Got an error: deadlineExceeded (4): RPC timed out (timeout=10S) before completing

• turn off flight mode
• Unfortunately but server receives "✈️"

[kosukeohmura]

I passed nil to connectionBackoff of ClientConnection.Configuration initializer but there were no effects.

[glbrntt]

I use gRPC Swift for developing an iOS app. When I call unary RPC under flight mode, I get a deadlineExceeded error but server receives the Unary request that should not be sent.

Would anyone tell me how to prevent sending request after I've got a call error, please?

When does the server receive "✈️"? Do you have timestamps from when Airplane mode was enabled, disabled, when the request was sent and when the server received it?

Incidentally, if you're using gRPC on iOS you should prefer using NIOTSEventLoopGroup over MultiThreadedEventLoopGroup since gRPC will then use the Network.framework stack which should better handle network connectivity changes (see: https://github.com/grpc/grpc-swift/blob/nio/docs/apple-platforms.md).

[kosukeohmura]

Hi @glbrntt, thank you for your reply. I've printed event logs with timestamp.

The code I used for subscribe network changes:

let monitor = NWPathMonitor()
monitor.start(queue: .global(qos: .utility))
monitor.pathUpdateHandler = { path in Log.debug(message: "path changed: \(path.debugDescription)") } // Log.debug is just a wrapper for os.os_log

Client log with timestamp:

# Airplane mode was enabled
2020-01-30 12:40:48.632856+0900 example[4366:994863] ⚒ path changed: unsatisfied (No network route)
# Attempted to send a request under Airplane mode
2020-01-30 12:40:52.516149+0900 example[4366:994731] ⚒ Attempting to call unary gRPC. request type: CreateResourcesRequest
# Got an gRPC error
2020-01-30T12:41:02+0900 error: request_id=7083EE20-81B1-4A24-A1CD-7714456AAD20 error=RPC timed out (timeout=10S) before completing grpc client error
2020-01-30 12:41:02.528570+0900 example[4366:994921] ❗️ Got an unary gRPC error. request type: CreateResourcesRequest, error: deadlineExceeded (4): RPC timed out (timeout=10S) before completing
# Airplane mode was disabled
2020-01-30 12:41:09.714243+0900 example[4366:994863] ⚒ path changed: satisfied (Path is satisfied), interface: en0, ipv4, dns
2020-01-30 12:41:15.081116+0900 example[4366:994920] ⚒ path changed: satisfied (Path is satisfied), interface: en0, ipv4, dns

Our server received the request at the almost same time as Airplane mode was disabled. A part of the server log:

{
  grpc.code: "OK"   
  grpc.method: "CreateResources"   
  grpc.request.deadline: "2020-01-30T03:41:19Z"   
  grpc.service: "ResourceApi"   
  grpc.start_time: "2020-01-30T03:41:09Z"   
  grpc.time_ms: 574.5800170898438 
}

[kosukeohmura]

Also I've update my code to use NIOTSEventLoopGroup. Thank you for your information.

[glbrntt]

Thanks for the info @KosukeOhmura, I need to look into this more to work out how to fix it. We definitely shouldn't be sending a request after we've timed out in this case!

As a workaround you can close the connection when airplane mode is enabled.

[kosukeohmura]

@glbrntt The workaround worked for me. Thank you!

[622michael]

Has there been any progress on this issue? Receiving the same issue. Limiting to airplane mode may help, but it seems to also happen in cases where connection is faulty as well.