Can't connect

[MarkPare]

Thanks for the library.

I'm having issues connecting and I haven't been able to track down the cause.

• Server is running correctly.
• INTERNET and ACCESS_NETWORK_STATE permissions have been added to AndroidManifest.xml.

Here's my activity:

package com.mydomain.myapp

import android.support.v7.app.AppCompatActivity
import android.os.Bundle
import android.util.Log
import org.phoenixframework.PhxSocket

class MainActivity : AppCompatActivity() {
  private val TAG = "MainActivity";

  override fun onCreate(savedInstanceState: Bundle?) {
    super.onCreate(savedInstanceState)
    setContentView(R.layout.activity_main)
    this.connectToChatRoom()
  }

  fun connectToChatRoom() {

    // Create the Socket
    val params = hashMapOf("token" to "abc123")
    val url = "http://localhost:4000/socket/websocket"
    val socket = PhxSocket(url, params)

    // Listen to events on the Socket
    socket.logger = { Log.d("TAG", it) }
    socket.onOpen { Log.d("TAG", "Socket Opened") }
    socket.onClose { Log.d("TAG", "Socket Closed") }
    socket.onError { throwable, response ->
      throwable?.printStackTrace()
      Log.d("Message", throwable?.message)
      Log.d("Response:", "${response?.toString()}")
      Log.d(throwable.toString(), "\"Socket Error\"")
    }

    socket.connect()

    // Join channels and listen to events
    val chatroom = socket.channel("user:1")
    chatroom.on("new_message") {
      // `it` is a PhxMessage object
      val payload = it.payload
      Log.d("TAG", "payload received")
    }

    chatroom.join()
      .receive("ok") { /* Joined the chatroom */ }
      .receive("error") { /* failed to join the chatroom */ }
  }
}

And here's my log:

2018-12-14 13:24:30.806 17467-17467/com.mydomain.myapp D/NetworkSecurityConfig: No Network Security Config specified, using platform default
2018-12-14 13:24:30.857 17467-17484/com.mydomain.myapp D/TAG: Transport: error
2018-12-14 13:24:30.859 17467-17484/com.mydomain.myapp W/System.err: java.net.ConnectException: Failed to connect to localhost/127.0.0.1:4000
2018-12-14 13:24:30.859 17467-17484/com.mydomain.myapp W/System.err:     at okhttp3.internal.connection.RealConnection.connectSocket(RealConnection.java:242)
2018-12-14 13:24:30.859 17467-17484/com.mydomain.myapp W/System.err:     at okhttp3.internal.connection.RealConnection.connect(RealConnection.java:160)
2018-12-14 13:24:30.859 17467-17484/com.mydomain.myapp W/System.err:     at okhttp3.internal.connection.StreamAllocation.findConnection(StreamAllocation.java:257)
2018-12-14 13:24:30.859 17467-17484/com.mydomain.myapp W/System.err:     at okhttp3.internal.connection.StreamAllocation.findHealthyConnection(StreamAllocation.java:135)
2018-12-14 13:24:30.859 17467-17484/com.mydomain.myapp W/System.err:     at okhttp3.internal.connection.StreamAllocation.newStream(StreamAllocation.java:114)
2018-12-14 13:24:30.859 17467-17484/com.mydomain.myapp W/System.err:     at okhttp3.internal.connection.ConnectInterceptor.intercept(ConnectInterceptor.java:42)
2018-12-14 13:24:30.860 17467-17484/com.mydomain.myapp W/System.err:     at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:147)
2018-12-14 13:24:30.860 17467-17484/com.mydomain.myapp W/System.err:     at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:121)
2018-12-14 13:24:30.860 17467-17484/com.mydomain.myapp W/System.err:     at okhttp3.internal.cache.CacheInterceptor.intercept(CacheInterceptor.java:93)
2018-12-14 13:24:30.860 17467-17484/com.mydomain.myapp W/System.err:     at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:147)
2018-12-14 13:24:30.860 17467-17484/com.mydomain.myapp W/System.err:     at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:121)
2018-12-14 13:24:30.860 17467-17484/com.mydomain.myapp W/System.err:     at okhttp3.internal.http.BridgeInterceptor.intercept(BridgeInterceptor.java:93)
2018-12-14 13:24:30.860 17467-17484/com.mydomain.myapp W/System.err:     at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:147)
2018-12-14 13:24:30.860 17467-17484/com.mydomain.myapp W/System.err:     at okhttp3.internal.http.RetryAndFollowUpInterceptor.intercept(RetryAndFollowUpInterceptor.java:126)
2018-12-14 13:24:30.860 17467-17484/com.mydomain.myapp W/System.err:     at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:147)
2018-12-14 13:24:30.860 17467-17484/com.mydomain.myapp W/System.err:     at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:121)
2018-12-14 13:24:30.860 17467-17484/com.mydomain.myapp W/System.err:     at okhttp3.RealCall.getResponseWithInterceptorChain(RealCall.java:200)
2018-12-14 13:24:30.860 17467-17484/com.mydomain.myapp W/System.err:     at okhttp3.RealCall$AsyncCall.execute(RealCall.java:147)
2018-12-14 13:24:30.860 17467-17484/com.mydomain.myapp W/System.err:     at okhttp3.internal.NamedRunnable.run(NamedRunnable.java:32)
2018-12-14 13:24:30.860 17467-17484/com.mydomain.myapp W/System.err:     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1133)
2018-12-14 13:24:30.860 17467-17484/com.mydomain.myapp W/System.err:     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:607)
2018-12-14 13:24:30.860 17467-17484/com.mydomain.myapp W/System.err:     at java.lang.Thread.run(Thread.java:761)
2018-12-14 13:24:30.861 17467-17484/com.mydomain.myapp W/System.err: Caused by: java.net.ConnectException: Connection refused
2018-12-14 13:24:30.861 17467-17484/com.mydomain.myapp W/System.err:     at java.net.PlainSocketImpl.socketConnect(Native Method)
2018-12-14 13:24:30.861 17467-17484/com.mydomain.myapp W/System.err:     at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:334)
2018-12-14 13:24:30.861 17467-17484/com.mydomain.myapp W/System.err:     at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:196)
2018-12-14 13:24:30.861 17467-17484/com.mydomain.myapp W/System.err:     at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:178)
2018-12-14 13:24:30.861 17467-17484/com.mydomain.myapp W/System.err:     at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:356)
2018-12-14 13:24:30.861 17467-17484/com.mydomain.myapp W/System.err:     at java.net.Socket.connect(Socket.java:605)
2018-12-14 13:24:30.861 17467-17484/com.mydomain.myapp W/System.err:     at okhttp3.internal.platform.AndroidPlatform.connectSocket(AndroidPlatform.java:71)
2018-12-14 13:24:30.861 17467-17484/com.mydomain.myapp W/System.err:     at okhttp3.internal.connection.RealConnection.connectSocket(RealConnection.java:240)
2018-12-14 13:24:30.861 17467-17484/com.mydomain.myapp W/System.err:  ... 21 more
2018-12-14 13:24:30.861 17467-17484/com.mydomain.myapp D/message: Failed to connect to localhost/127.0.0.1:4000
2018-12-14 13:24:30.861 17467-17484/com.mydomain.myapp D/java.net.ConnectException: Failed to connect to localhost/127.0.0.1:4000: "Socket Error"
2018-12-14 13:24:30.861 17467-17484/com.mydomain.myapp D/Response:: null

Any suggestions are appreciated!

[dustinconrad]

You are trying to connect to a non-ssl endpoint and your application isn't configured to do that. This has nothing to do with this client or even websockets. If you tried to hit a regular REST endpoint on non-ssl localhost the same thing would happen. You should read this.

Heres some excerpts that should help

in AndroidManifest.xml
android:networkSecurityConfig="@xml/network_security_config"

in /res/xml/network_security_config

<network-security-config>
    <domain-config cleartextTrafficPermitted="true">
        <domain includeSubdomains="true">localhost</domain>
    </domain-config>
</network-security-config>

[MarkPare]

Thanks for your response.

Not only that, but I was using an Android emulator which requires using specially-designated port 10.0.2.2 to connect to localhost on dev machine. It's been a while since I did some Android dev - apologies.

I'm still having an issue connecting. The request is now going through, but I'm getting a 404 and this error in my Android log:

2018-12-15 18:39:58.015 21153-21169/com.mydomain.myapp D/TAG: Transport: error
2018-12-15 18:39:58.018 21153-21169/com.mydomain.myapp W/System.err: java.net.ProtocolException: Expected HTTP 101 response but was '404 Not Found'
2018-12-15 18:39:58.025 21153-21169/com.mydomain.myapp W/System.err:     at okhttp3.internal.ws.RealWebSocket.checkResponse(RealWebSocket.java:228)
2018-12-15 18:39:58.026 21153-21169/com.mydomain.myapp W/System.err:     at okhttp3.internal.ws.RealWebSocket$2.onResponse(RealWebSocket.java:195)
2018-12-15 18:39:58.038 21153-21169/com.mydomain.myapp W/System.err:     at okhttp3.RealCall$AsyncCall.execute(RealCall.java:153)
2018-12-15 18:39:58.038 21153-21169/com.mydomain.myapp W/System.err:     at okhttp3.internal.NamedRunnable.run(NamedRunnable.java:32)
2018-12-15 18:39:58.038 21153-21169/com.mydomain.myapp W/System.err:     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1133)
2018-12-15 18:39:58.038 21153-21169/com.mydomain.myapp W/System.err:     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:607)
2018-12-15 18:39:58.038 21153-21169/com.mydomain.myapp W/System.err:     at java.lang.Thread.run(Thread.java:761)
2018-12-15 18:39:58.038 21153-21169/com.mydomain.myapp D/Message: Expected HTTP 101 response but was '404 Not Found'
2018-12-15 18:39:58.038 21153-21169/com.mydomain.myapp D/Response:: Response{protocol=http/1.1, code=404, message=Not Found, url=http://10.0.2.2:4000/socket}
2018-12-15 18:39:58.038 21153-21169/com.mydomain.myapp D/java.net.ProtocolException: Expected HTTP 101 response but was '404 Not Found': "Socket Error"

I can see that the source code for PhxSocket changes the protocol from ws to http, so it makes sense that my phoenix app is returning 404 because there is no http route for /socket.

Code from PhxSocket:

        // Silently replace web socket URLs with HTTP URLs.
        var mutableUrl = url
        if (url.regionMatches(0, "ws:", 0, 3, ignoreCase = true)) {
            mutableUrl = "http:" + url.substring(3)
        } else if (url.regionMatches(0, "wss:", 0, 4, ignoreCase = true)) {
            mutableUrl = "https:" + url.substring(4)
        }

My javascript phoenix socket client works fine and I don't believe it does anything under the hood to change the protocol - it's always ws or wss.

Is there a reason for doing this? Any suggestions are appreciated!

[dustinconrad]

The biggest help for debugging would be to create your own okhttp client and log all requests/responses.

in your build.gradle
implementation "com.squareup.okhttp3:logging-interceptor:3.11.0"

create your client

val loggingInterceptor = HttpLoggingInterceptor()
loggingInterceptor.level =  HttpLoggingInterceptor.Level.BODY

httpClient = OkHttpClient.Builder()
            .addInterceptor(loggingInterceptor)
            .build()

create your phoenix client

val socket = PhxSocket(baseWsUrl, client = httpClient)

Maybe this will help shed some light on your issue. I can say that this library is working for me, although I did not set up the phoenix backend.

[MarkPare]

Thanks. The error I'm getting makes perfect sense to me. I'm wondering how this could work as my Phoenix backend is expecting a ws or wss uri.

For example, my endpoint file is:

defmodule MyAppWeb.Endpoint do
  use Phoenix.Endpoint, otp_app: :my_app

  plug CORSPlug, origin: ["*"]
  
  socket "/socket", MyAppWeb.UserSocket
...

so the /socket uri will only go to MyAppWeb.UserSocket if it's schema is ws or wss; http or https will go to my router.ex.

I don't see anything in the Phoenix app that would automatically give the Expected HTTP 101 response that is expected by this library.

As a side note, I came across this issue in the OkHttp library that is used by this library. I assume this is part of the reason why this library does the silent replacement of ws schema with http. However, I still don't understand how this would be expected to work.

Thanks again for your input.

[MarkPare]

Update:

I'm able to open the connection by defining an http route in my router.ex that matches /socket uri, then implementing a custom controller function in my Phoenix app that sends the expected response. Something like:

# controller function

def upgrade(conn, _params) do
    magic_string = "258EAFA5-E914-47DA-95CA-C5AB0DC85B11"
    client_key = get_req_header(conn, "sec-websocket-key")

    r = "#{client_key}#{magic_string}"
    r = :crypto.hash(:sha, r)
    r = Base.encode64(r)

    conn
    |> put_resp_header("connection", "Upgrade")
    |> put_resp_header("upgrade", "websocket")
    |> put_resp_header("Sec-WebSocket-Accept", r)
    |> send_resp(101, "")
  end

The logic for deriving the Sec-WebSocket-Accept value is from here.

So now the socket connection is open, but I receive this error almost immediately:

2018-12-16 01:16:49.914 25061-25085/com.mydomain.myapp W/System.err: java.io.EOFException
2018-12-16 01:16:49.914 25061-25085/com.mydomain.myapp W/System.err:     at okio.RealBufferedSource.require(RealBufferedSource.java:61)
2018-12-16 01:16:49.915 25061-25085/com.mydomain.myapp W/System.err:     at okio.RealBufferedSource.readByte(RealBufferedSource.java:74)
2018-12-16 01:16:49.915 25061-25085/com.mydomain.myapp W/System.err:     at okhttp3.internal.ws.WebSocketReader.readHeader(WebSocketReader.java:117)
2018-12-16 01:16:49.915 25061-25085/com.mydomain.myapp W/System.err:     at okhttp3.internal.ws.WebSocketReader.processNextFrame(WebSocketReader.java:101)
2018-12-16 01:16:49.915 25061-25085/com.mydomain.myapp W/System.err:     at okhttp3.internal.ws.RealWebSocket.loopReader(RealWebSocket.java:274)
2018-12-16 01:16:49.915 25061-25085/com.mydomain.myapp W/System.err:     at okhttp3.internal.ws.RealWebSocket$2.onResponse(RealWebSocket.java:214)
2018-12-16 01:16:49.915 25061-25085/com.mydomain.myapp W/System.err:     at okhttp3.RealCall$AsyncCall.execute(RealCall.java:206)
2018-12-16 01:16:49.915 25061-25085/com.mydomain.myapp W/System.err:     at okhttp3.internal.NamedRunnable.run(NamedRunnable.java:32)
2018-12-16 01:16:49.915 25061-25085/com.mydomain.myapp W/System.err:     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1133)
2018-12-16 01:16:49.915 25061-25085/com.mydomain.myapp W/System.err:     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:607)
2018-12-16 01:16:49.915 25061-25085/com.mydomain.myapp W/System.err:     at java.lang.Thread.run(Thread.java:761)

Looks like it might be related to this issue from OkHttp library.

The solution proposes adding .pingInterval(30, TimeUnit.SECONDS) to the client so that server does not close connection.

Still, this doesn't totally explain why I'm seeing this error immediately after socket opening, especially because by default Phoenix websocket shouldn't timeout for at least a minute (at least how I'm reading that document).

[MarkPare]

@dustinconrad, did you need to configure anything in your Phoenix app to get this running? I'm still stuck here. No issues when using Javascript client for Phoenix channels, but no luck with this android client.

[dustinconrad]

Hey @MarkPare, sorry I can't be more help from the elixir side, but I did not set that portion up. It just worked when I started hitting the endpoint.

[dsrees]

Hey guys, thanks for trying to work this out together already. I'll try to take some time this weekend to dig a little into this but may be delayed by the holidays!

[MarkPare]

@dsrees , thanks for your response. I'm happy to continue debugging this myself; I'm just kind of stuck right now.

Below are my Elixir and Phoenix versions if that's helpful.

Elixir 1.7.3
Phoenix 1.3.4

[dsrees]

@MarkPare were you ever able to resolve this? I have not been able to reproduce your issue on my end

[MarkPare]

@dsrees I was never able to solve this and had to opt for a different solution. When I get a chance I'll post something that's reproducible and testable. Thanks.