Invalid HTTP upgrade spams the log instead of returning an error

[sgade]

Summary

When connecting to an invalid web socket connection,, Apollo's WebSocketTransport is continuously printing (about every second) the error to stdout.

"websocket is disconnected: WSError(type: ApolloWebSocket.WebSocket.WSError.ErrorType.upgradeError, message: \"Invalid HTTP upgrade\", code: 404)"

The message is printed in this line: https://github.com/apollographql/apollo-ios/blob/1d9b9262a641bac0a1071d42574f6197254542e6/Sources/ApolloWebSocket/WebSocketTransport.swift#L531

This is happening because the previousState is .disconnected in handleDisconnection(with:)

Bug noticed first in 1.6.0 but verified with 1.8.0.

I would expect this to give up immediately because no connection is possible at all. Since this is not even sending out any requests right now, is there a way we are supposed to be able to handle this gracefully in our code?

Version

1.8.0

Steps to reproduce the behavior

1. Create a SplitNetworkTransport with a WebSocketTransport that uses an unsupported URL like ws://www.google.com. The http code is of course dependent on the remote server.
2. Run the application. Without the need to send out any subscription, the logs will start appearing.

Logs

No response

Anything else?

No response

[calvincestari]

Hi @sgade

Bug noticed first in 1.6.0 but verified with 1.8.0.

Is this implying the behaviour was different in earlier versions, i.e.: < 1.6.0?

[sgade]

Hi @calvincestari, thanks for asking. I meant that the issue was happening in 1.6.0 but I upgraded to 1.8.0 and noticed the same behavior. On further inspection, it seems the code in WebSocketTransport is the same at the mentioned place in both versions.

[calvincestari]

I don't think WebSocketTransport has changed for a while now so it should be the same prior to 1.6.0 too but I wanted to ask and confirm.

[calvincestari]

Hi @sgade, I took a look into the issue this morning and it's not a bug but rather a combination of the WebSocketTransport.Configuration values.

What you're seeing is a result of the default values for:

• connectOnInit (default: true) - start trying to connect to the websocket immediately when the transport is created.
• reconnect (default: true) - attempts to establish the connection when disconnected. Note there is no distinction here between never-had-a-connection and did-have-a-connection.
• reconnectionInterval (default: 0.5) - the frequency at which reconnect attempts to establish the connection.

I'm going to close this issue as the websocket behaviour is normal and I recommend adjusting those configuration values to better suit the network environment you're operating in.

[github-actions[bot]]

Do you have any feedback for the maintainers? Please tell us by taking a one-minute survey. Your responses will help us understand Apollo iOS usage and allow us to serve you better.

[sgade]

Thanks for the clarification, @calvincestari. Although I'm not a fan of these defaults, I can now understand what is happening.

Is there any way you could provide more control over these log messages? Instead of logging, a library should instead pass the error around. Even if the delegate gets called, the message is still printed to stdout. Since Apple is recommending to use OSLog and everybody has their own logging system, it would be great to have that unified for each specific case. That would mean dropping the debugPrint call.

[calvincestari]

Thanks for the clarification, @calvincestari. Although I'm not a fan of these defaults, I can now understand what is happening.

They are configurable through the WebSocketTransport initializer; if you supply your own config parameter you can change that behaviour.

Is there any way you could provide more control over these log messages? Instead of logging, a library should instead pass the error around. Even if the delegate gets called, the message is still printed to stdout. Since Apple is recommending to use OSLog and everybody has their own logging system, it would be great to have that unified for each specific case. That would mean dropping the debugPrint call

I'll take a look at that logging behaviour later today and get back to you.

[calvincestari]

I've got a PR up to remove those logging calls, they serve no purpose - https://github.com/apollographql/apollo-ios-dev/pull/253.

[sgade]

Looks great, thanks!

[github-actions[bot]]

Do you have any feedback for the maintainers? Please tell us by taking a one-minute survey. Your responses will help us understand Apollo iOS usage and allow us to serve you better.