pusher / chatkit-client-js

JavaScript client SDK for Pusher Chatkit
https://pusher.com/chatkit
MIT License
90 stars 15 forks source link

Logger.ERROR: error establishing presence subscription: Logger.ERROR: Error: presence subscription timed out #95

Closed hbole closed 6 years ago

hbole commented 6 years ago

componentDidUpdate(){ if(this.state.userId){ const chatManager = new Chatkit.ChatManager({ instanceLocator: 'API KEY', userId: this.state.userId, tokenProvider: new Chatkit.TokenProvider({ url: 'Test Url Token' }) }) chatManager.connect() .then(currentUser => { this.currentUser=currentUser this.getRooms()
}) .catch(err => { console.log('Error on connection', err) }) } } getRooms=()=>{ this.currentUser.getJoinableRooms() .then(joinableRooms => { this.setState({ joinableRooms, joinedRooms: this.currentUser.rooms }) }) .catch(err => console.log('error on joinableRooms: ', err)) } subscribeToRoom=(roomId)=>{ this.setState({ messages: [] }) this.currentUser.subscribeToRoom({ roomId: roomId, hooks: { onNewMessage: message => { this.setState({ messages: [...this.state.messages, message] }) } } }) .then(room => { this.setState({ roomId: room.id, roomName:room.name }) this.getRooms() }) .catch(err => console.log('error on subscribing to room: ', err)) } sendMessage=(text)=>{ this.currentUser.sendMessage({ text:text, roomId:this.state.roomId }) } createRoom(name) { this.currentUser.createRoom({ name }) .then(room => this.subscribeToRoom(room.id)) .catch(err => console.log('error with createRoom: ', err)) }

hbole commented 6 years ago

This is my above code. All of the things work fine. I am able to register a user, login and create a user. The problem comes when i subscribe to a room It gets subscribed even the message is sent successfully in my chatkit instance. But along with all the process an error logs out in the console even when everyhting is happening corretly. "Logger.ERROR: error establishing presence subscription: Logger.ERROR: Error: presence subscription timed out "

vivangkumar commented 6 years ago

@hbole 👋

How long have you been experiencing this issue? Looks like the presence subscription is timing out causing the library to not move into a connected state.

hbole commented 6 years ago

Yup @vivangkumar Subscription is timing out. Everything was alright till today morning untill i did not have sign in and register page. I created sign in and register page and connected them to backend and also created create user backend endpoint to create a user in my chat kit instance. From then i am getting this error although everything is working fine.

vivangkumar commented 6 years ago

@hbole I think we have a lead on the issue.

It seems to happen when the authentication endpoint takes too long to return a token making the library think the subscription has failed, but in reality the subscription has actually been established successfully. This will throw errors. We're working on a fix.

In the mean time, if you face this issue again, could you see if it your auth endpoint that is taking too long to respond?

kwamesarpong commented 6 years ago

I'm getting the same error myself so I don't think its the auth endpoint.

hbole commented 6 years ago

@vivangkumar I don't think it's any endpoint issue. As when i hit ebter the room is instantly created and message is also sent within a second as soon as i hit enter. I check it in my chatkit instance that message is instantly received but the browser console is still continuing to establish the connection and showing everytime for few secs after the message has been received.

italoj commented 6 years ago

I'm getting the same error... any solution?

hamchapman commented 6 years ago

For anyone experiencing this, are you able to confirm that the client gets a response from your token provider endpoint within 15 seconds?

italoj commented 6 years ago

@hamchapman Yes...

image

Everythings woks very well until few days ago...

componentDidMount() {
    Config.log('chatkitUserId', this.props.chatkitUserId)
    Config.log('chatkitRoomId', parseInt(this.props.chatkitRoomId))
    Config.log('url', Config.CHATKIT_TOKEN_PROVIDER_ENDPOINT)
    Config.log('instanceLocator', Config.CHATKIT_INSTANCE_LOCATOR)

    const tokenProvider = new Chatkit.TokenProvider({ url: Config.CHATKIT_TOKEN_PROVIDER_ENDPOINT })

    Config.log('Chatkit tokenProvider: ', tokenProvider)

    const chatManager = new Chatkit.ChatManager({
      instanceLocator: Config.CHATKIT_INSTANCE_LOCATOR,
      userId: this.props.chatkitUserId,
      connectionTimeout: 20000,
      tokenProvider
    })

    chatManager.connect()
    .then(currentUser => {
      console.log('Successful connection', currentUser)
    })
    .catch(err => {
      console.log('Error on connection', err)
    })
  }
hamchapman commented 6 years ago

Okay, what version of the SDK are you using?

italoj commented 6 years ago
"react-native": "0.55.3",
"@pusher/chatkit": "^0.7.17"

My ChatComponent.js

import React from 'react'
import {
  Text,
  View,
  StyleSheet
} from 'react-native'
import { GiftedChat } from "react-native-gifted-chat"
import Chatkit from "@pusher/chatkit/react-native"

import Container from './UI/Container'
import Loading from './UI/Loading'

import Config from '../Config/Config'

import {
  Typo,
  Colors
} from './UI/Utils/Constants'

export default class ChatComponent extends React.Component {
  constructor(props) {
    super(props)
    this.state = {
      messages: []
    }
  }

  componentDidMount() {
    Config.log('chatkitUserId', this.props.chatkitUserId)
    Config.log('chatkitRoomId', parseInt(this.props.chatkitRoomId))
    Config.log('url', Config.CHATKIT_TOKEN_PROVIDER_ENDPOINT)
    Config.log('instanceLocator', Config.CHATKIT_INSTANCE_LOCATOR)

    const tokenProvider = new Chatkit.TokenProvider({ url: Config.CHATKIT_TOKEN_PROVIDER_ENDPOINT })

    Config.log('Chatkit tokenProvider: ', tokenProvider)

    const chatManager = new Chatkit.ChatManager({
      instanceLocator: Config.CHATKIT_INSTANCE_LOCATOR,
      userId: this.props.chatkitUserId,
      connectionTimeout: 20000,
      tokenProvider
    })

    chatManager.connect()
    .then(currentUser => {
      console.log('Successful connection', currentUser)
    })
    .catch(err => {
      console.log('Error on connection', err)
    })
  }

  onReceive(data) {
    const { id, senderId, text, createdAt } = data;
    const incomingMessage = {
      _id: id,
      text: text,
      createdAt: new Date(createdAt),
      user: {
        _id: senderId,
        name: senderId,
        avatar: this.props.avatar
      }
    };

    this.setState(previousState => ({
      messages: GiftedChat.append(previousState.messages, incomingMessage)
    }))
  }

  onSend([message]) {
    this.currentUser.sendMessage({
      text: message.text,
      roomId: parseInt(this.props.chatkitRoomId)
    })
  }

  render() {
    return <GiftedChat
      messages={this.state.messages}
      onSend={messages => this.onSend(messages)}
      user={{
       _id: this.props.chatkitUserId
      }}
    />
  }
}

const Styles = StyleSheet.create({
  textFeatured: {
    fontFamily: Typo.fontFamily,
    color: Colors.angel,
    fontSize: Typo.fontSize + 2,
    textAlign: 'center',
    fontStyle: 'italic',
    padding: 30
  },

  textContainer: {
    display: 'flex',
    flexDirection: 'row',
    flexWrap: 'wrap',
    paddingTop: 10
  },

  text: {
    fontFamily: Typo.fontFamily,
    color: '#000',
    fontSize: Typo.fontSize,
  },

  strong: {
    fontWeight: 'bold'
  }
})
hamchapman commented 6 years ago

What does the network tab look like when you're trying to connect? If you run your app and try to connect to Chatkit and wait 25 seconds (20 seconds for your provided connectionTimeout value plus 5 seconds as some leeway) and then look at the network tab, what's going on?

Specifically if you look at the websocket connection that is made to pusherplatform.io (the host for Chatkit) and then look at the frames for the websocket, what do you see there?

Similarly, if you provide a logger to your ChatManager like this:

const chatManager = new Chatkit.ChatManager({
  instanceLocator: Config.CHATKIT_INSTANCE_LOCATOR,
  userId: this.props.chatkitUserId,
  connectionTimeout: 20000,
  tokenProvider,
  logger: {
    verbose: console.log,
    debug: console.log,
    info: console.log,
    warn: console.log,
    error: console.log,
  }
})

what do the logs suggest is happening?

Do you get the timeout error every time you try to connect or is it sporadic?

What's the network connection like for the device that you're trying to connect with? Is it slow, fast, etc?

Sorry for the all the questions! It's just much easier for us to help debug things if we have as much information as possible 👍

italoj commented 6 years ago

@hamchapman Let's go \o/

what do the logs suggest is happening? image

image

Do you get the timeout error every time you try to connect or is it sporadic? Every time that method componentWillMount() invoked

What's the network connection like for the device that you're trying to connect with? Is it slow, fast, etc?

I'm using react-native with firebase number authentication, so i'm just can test in device (Android). The network tab dont show any requests for me...

hamchapman commented 6 years ago

Awesome - thanks a lot for the info! Very interesting logs as well.

If you're willing to, please could you open up ./node_modules/pusher-platform/dist/react-native/pusher-platform.js and find the line:

this.close(new network_1.NetworkError("Didn't received pong with proper ID"));

Above that line please could you add this line:

global.console.log("Received Pong ID: ", receviedPongID, ", lastSentPingID: ", this.lastSentPingID);

Then try running the app again and (again, please!) send over the logs.

Thanks a lot (if you're able to!)

italoj commented 6 years ago

@hamchapman

In ./node_modules/pusher-platform/dist/react-native/pusher-platform.js

WebSocketTransport.prototype.onPongMessage = function (message) {
        var receviedPongID = message[0];
        if (this.lastSentPingID !== receviedPongID) {
            this.close(new network_1.NetworkError("Didn't received pong with proper ID"));
            global.console.log("Received Pong ID: ", receviedPongID, ", lastSentPingID: ", this.lastSentPingID);
        }
        global.clearTimeout(this.pongTimeout);
        delete this.pongTimeout;
        this.lastSentPingID = null;
    };

After a long time, the log is in loop with this result:

image

Thanks for help me... its very important to works for me!

hamchapman commented 6 years ago

Ah, could you try with this line:

global.console.log("Received Pong ID: ", receviedPongID, ", lastSentPingID: ", this.lastSentPingID);

before the other line in that if block?

italoj commented 6 years ago

@hamchapman I made this changes and re-build app and the line that i added, not showing...

WebSocketTransport.prototype.onPongMessage = function (message) {
        var receviedPongID = message[0];
        if (this.lastSentPingID !== receviedPongID) {
            global.console.log("Received Pong ID: ", receviedPongID, ", lastSentPingID: ", this.lastSentPingID);
            this.close(new network_1.NetworkError("Didn't received pong with proper ID"));
        }
        global.clearTimeout(this.pongTimeout);
        delete this.pongTimeout;
        this.lastSentPingID = null;
 };

In Console...

image

hamchapman commented 6 years ago

Ah so it looks like it's not getting used as part of your build. If you have some sort of build artefact like an app.js or similar, and it's not minified / uglified for your dev environment, are you able to try inserting the line I pasted into that file to see if you can get that logging?

italoj commented 6 years ago

@hamchapman I've tried in many ways to display this log, but to no avail. Do you suggest any other way?

Is it being added to the correct file itself?

hamchapman commented 6 years ago

I've pushed a branch called pong-logging and so you should be able to use this version in your app by changing your reference to the Chatkit JS SDK from @pusher/chatkit to pusher/chatkit-client-js#pong-logging

italoj commented 6 years ago

@hamchapman now works!

Received Pong ID:  1537378954172 , lastSentPingID:  null
chatkit.js:1 TokenProvidingSubscription: subscription errored: {error: "Didn't received pong with proper ID"}
chatkit.js:1 TokenProvidingSubscription: transitioning to InactiveState
chatkit.js:1 RetryingSubscription: transitioning to RetryingSubscriptionState
chatkit.js:1 e: Error received {error: "Didn't received pong with proper ID"}
chatkit.js:1 e: It's a Network Error, will retry {error: "Didn't received pong with proper ID"}
chatkit.js:1 e: Retrying in 2000ms
chatkit.js:1 TokenProvidingSubscription: subscription errored: {error: "Didn't received pong with proper ID"}
chatkit.js:1 TokenProvidingSubscription: transitioning to InactiveState
chatkit.js:1 RetryingSubscription: transitioning to RetryingSubscriptionState
chatkit.js:1 e: Error received {error: "Didn't received pong with proper ID"}
chatkit.js:1 e: It's a Network Error, will retry {error: "Didn't received pong with proper ID"}
chatkit.js:1 e: Retrying in 2000ms
chatkit.js:1 TokenProvidingSubscription: subscription errored: {error: "Didn't received pong with proper ID"}
chatkit.js:1 TokenProvidingSubscription: transitioning to InactiveState
chatkit.js:1 RetryingSubscription: transitioning to RetryingSubscriptionState
chatkit.js:1 e: Error received {error: "Didn't received pong with proper ID"}
chatkit.js:1 e: It's a Network Error, will retry {error: "Didn't received pong with proper ID"}
chatkit.js:1 e: Retrying in 2000ms
chatkit.js:1 RetryingSubscription: trying to re-establish the subscription
chatkit.js:1 TokenProvidingSubscription: transitioning to ActiveState
chatkit.js:1 RetryingSubscription: trying to re-establish the subscription
chatkit.js:1 TokenProvidingSubscription: transitioning to ActiveState
chatkit.js:1 RetryingSubscription: trying to re-establish the subscription
chatkit.js:1 TokenProvidingSubscription: transitioning to ActiveState
3chatkit.js:1 TokenProvidingSubscription: token fetched: eyJhbGciOiJIUzI1NiIsInR5cCI6IkpXVCJ9.eyJleHAiOjE1Mzc0NjUzNTMsImlhdCI6MTUzNzM3ODk1MywiaW5zdGFuY2UiOiI2Zjk3YmRiYi02ZjJiLTRkOTMtYTM0My04YjBhM2M2ZGE3ZGIiLCJpc3MiOiJhcGlfa2V5cy82MjExMjljMS1jMzNlLTRlMDMtYTY1OC03M2U3ZmY3MmMxYmQiLCJzdWIiOiJvcWZaQUNVcWQ2QXp4d0hIIn0.nhJ985Q8EgkD-4v_wC1RmlCxs7vEHZrnqFgCIHmnfTg
chatkit.js:1 TokenProvidingSubscription: subscription opened
chatkit.js:1 RetryingSubscription: transitioning to OpenSubscriptionState
chatkit.js:1 TokenProvidingSubscription: subscription opened
chatkit.js:1 RetryingSubscription: transitioning to OpenSubscriptionState
chatkit.js:1 TokenProvidingSubscription: subscription opened
chatkit.js:1 RetryingSubscription: transitioning to OpenSubscriptionState
chatkit.js:1 Received Pong ID:  1537378985862 , lastSentPingID:  null
chatkit.js:1 TokenProvidingSubscription: subscription errored: {error: "Didn't received pong with proper ID"}
chatkit.js:1 TokenProvidingSubscription: transitioning to InactiveState
hbole commented 6 years ago

Hello @hamchapman you mean that we have to change the dependency from @pusher/chatkit to pusher/chatkit-client-js#pong-logging.....??

hamchapman commented 6 years ago

@hbole nope that won't fix it but it's useful to get some logging to show what's going on.

@italoj your logs are interesting!

It looks like maybe you have a slow to complete token fetch going on? At least judging by this line: 3chatkit.js:1 TokenProvidingSubscription: token fetched ...

Does that show up as happening on your side?

Also, I've updated the branch to have some more logging so if you get a chance to run your app again and could share the logs again, that'd be massively appreciated!

I was unable to recreate the logs you're seeing so I'm interested to see what might be going on 👍

italoj commented 6 years ago

@hamchapman Awesome...

image

hamchapman commented 6 years ago

Thanks! Interesting things there already.

One question: are those all of the logs, right from the start? It might be easier to copy them as text into a gist, just to make sure no context is missing

italoj commented 6 years ago

@hamchapman

instanceLocator v1:us1:6f97bdbb-6f2b-4d93-a343-8b0a3c6da7db
Config.js:14 Chatkit tokenProvider:  e {fetchToken: ƒ, fetchFreshToken: ƒ, cacheIsStale: ƒ, cache: ƒ, clearCache: ƒ, …}
chatkit.js:1 RetryingSubscription: transitioning to OpeningSubscriptionState
chatkit.js:1 TokenProvidingSubscription: transitioning to ActiveState
chatkit.js:1 RetryingSubscription: transitioning to OpeningSubscriptionState
chatkit.js:1 TokenProvidingSubscription: transitioning to ActiveState
chatkit.js:1 RetryingSubscription: transitioning to OpeningSubscriptionState
chatkit.js:1 TokenProvidingSubscription: transitioning to ActiveState
chatkit.js:1 error establishing presence subscription: Error: presence subscription timed out
    at chatkit.js:1
    at JSTimers.js:256
    at _callTimer (JSTimers.js:152)
    at Object.callTimers (JSTimers.js:405)
    at MessageQueue.__callFunction (MessageQueue.js:351)
    at MessageQueue.js:116
    at MessageQueue.__guardSafe (MessageQueue.js:314)
    at MessageQueue.callFunctionReturnFlushedQueue (MessageQueue.js:115)
    at debuggerWorker.js:70
chatkit.js:1 error establishing cursor subscription: Error: cursor subscription timed out
    at chatkit.js:1
    at JSTimers.js:256
    at _callTimer (JSTimers.js:152)
    at Object.callTimers (JSTimers.js:405)
    at MessageQueue.__callFunction (MessageQueue.js:351)
    at MessageQueue.js:116
    at MessageQueue.__guardSafe (MessageQueue.js:314)
    at MessageQueue.callFunctionReturnFlushedQueue (MessageQueue.js:115)
    at debuggerWorker.js:70
chatkit.js:1 error establishing user subscription: Error: user subscription timed out
    at chatkit.js:1
    at JSTimers.js:256
    at _callTimer (JSTimers.js:152)
    at Object.callTimers (JSTimers.js:405)
    at MessageQueue.__callFunction (MessageQueue.js:351)
    at MessageQueue.js:116
    at MessageQueue.__guardSafe (MessageQueue.js:314)
    at MessageQueue.callFunctionReturnFlushedQueue (MessageQueue.js:115)
    at debuggerWorker.js:70
ChatComponent.js:57 Error on connection Error: presence subscription timed out
    at chatkit.js:1
    at JSTimers.js:256
    at _callTimer (JSTimers.js:152)
    at Object.callTimers (JSTimers.js:405)
    at MessageQueue.__callFunction (MessageQueue.js:351)
    at MessageQueue.js:116
    at MessageQueue.__guardSafe (MessageQueue.js:314)
    at MessageQueue.callFunctionReturnFlushedQueue (MessageQueue.js:115)
    at debuggerWorker.js:70
3chatkit.js:1 TokenProvidingSubscription: token fetched: eyJhbGciOiJIUzI1NiIsInR5cCI6IkpXVCJ9.eyJleHAiOjE1Mzc1MzY5NjcsImlhdCI6MTUzNzQ1MDU2NywiaW5zdGFuY2UiOiI2Zjk3YmRiYi02ZjJiLTRkOTMtYTM0My04YjBhM2M2ZGE3ZGIiLCJpc3MiOiJhcGlfa2V5cy82MjExMjljMS1jMzNlLTRlMDMtYTY1OC03M2U3ZmY3MmMxYmQiLCJzdWIiOiJvcWZaQUNVcWQ2QXp4d0hIIn0.A_Mt3bc8D6cy3lKm-Zv80LBwMw8sfTL7PrL-zYBqliw
chatkit.js:1 Sending ping:  1537450567167
chatkit.js:1 TokenProvidingSubscription: subscription opened
chatkit.js:1 RetryingSubscription: transitioning to OpenSubscriptionState
chatkit.js:1 Received invalid Pong ID:  1537450567167 , lastSentPingID:  null
chatkit.js:1 Received Pong ID:  1537450567167 , lastSentPingID:  null
chatkit.js:1 Resetting lastSentPingID
chatkit.js:1 TokenProvidingSubscription: subscription errored: {error: "Didn't received pong with proper ID"}
chatkit.js:1 TokenProvidingSubscription: transitioning to InactiveState
chatkit.js:1 RetryingSubscription: transitioning to RetryingSubscriptionState
chatkit.js:1 e: Error received {error: "Didn't received pong with proper ID"}
chatkit.js:1 e: It's a Network Error, will retry {error: "Didn't received pong with proper ID"}
chatkit.js:1 e: Retrying in 2000ms
chatkit.js:1 TokenProvidingSubscription: subscription errored: {error: "Didn't received pong with proper ID"}
chatkit.js:1 TokenProvidingSubscription: transitioning to InactiveState
chatkit.js:1 RetryingSubscription: transitioning to RetryingSubscriptionState
chatkit.js:1 e: Error received {error: "Didn't received pong with proper ID"}
chatkit.js:1 e: It's a Network Error, will retry {error: "Didn't received pong with proper ID"}
chatkit.js:1 e: Retrying in 2000ms
chatkit.js:1 TokenProvidingSubscription: subscription errored: {error: "Didn't received pong with proper ID"}
chatkit.js:1 TokenProvidingSubscription: transitioning to InactiveState
chatkit.js:1 RetryingSubscription: transitioning to RetryingSubscriptionState
chatkit.js:1 e: Error received {error: "Didn't received pong with proper ID"}
chatkit.js:1 e: It's a Network Error, will retry {error: "Didn't received pong with proper ID"}
chatkit.js:1 e: Retrying in 2000ms
chatkit.js:1 RetryingSubscription: trying to re-establish the subscription
chatkit.js:1 TokenProvidingSubscription: transitioning to ActiveState
chatkit.js:1 RetryingSubscription: trying to re-establish the subscription
chatkit.js:1 TokenProvidingSubscription: transitioning to ActiveState
chatkit.js:1 RetryingSubscription: trying to re-establish the subscription
chatkit.js:1 TokenProvidingSubscription: transitioning to ActiveState
3chatkit.js:1 TokenProvidingSubscription: token fetched: eyJhbGciOiJIUzI1NiIsInR5cCI6IkpXVCJ9.eyJleHAiOjE1Mzc1MzY5NjcsImlhdCI6MTUzNzQ1MDU2NywiaW5zdGFuY2UiOiI2Zjk3YmRiYi02ZjJiLTRkOTMtYTM0My04YjBhM2M2ZGE3ZGIiLCJpc3MiOiJhcGlfa2V5cy82MjExMjljMS1jMzNlLTRlMDMtYTY1OC03M2U3ZmY3MmMxYmQiLCJzdWIiOiJvcWZaQUNVcWQ2QXp4d0hIIn0.A_Mt3bc8D6cy3lKm-Zv80LBwMw8sfTL7PrL-zYBqliw
chatkit.js:1 TokenProvidingSubscription: subscription opened
chatkit.js:1 RetryingSubscription: transitioning to OpenSubscriptionState
chatkit.js:1 TokenProvidingSubscription: subscription opened
chatkit.js:1 RetryingSubscription: transitioning to OpenSubscriptionState
chatkit.js:1 TokenProvidingSubscription: subscription opened
chatkit.js:1 RetryingSubscription: transitioning to OpenSubscriptionState
chatkit.js:1 Sending ping:  1537450598293
chatkit.js:1 Received invalid Pong ID:  1537450598293 , lastSentPingID:  null
chatkit.js:1 Received Pong ID:  1537450598293 , lastSentPingID:  null
chatkit.js:1 Resetting lastSentPingID
chatkit.js:1 TokenProvidingSubscription: subscription errored: {error: "Didn't received pong with proper ID"}
chatkit.js:1 TokenProvidingSubscription: transitioning to InactiveState
chatkit.js:1 e: Error received {error: "Didn't received pong with proper ID"}
chatkit.js:1 e: It's a Network Error, will retry {error: "Didn't received pong with proper ID"}
chatkit.js:1 e: Retrying in 4000ms
chatkit.js:1 TokenProvidingSubscription: subscription errored: {error: "Didn't received pong with proper ID"}
chatkit.js:1 TokenProvidingSubscription: transitioning to InactiveState
chatkit.js:1 e: Error received {error: "Didn't received pong with proper ID"}
chatkit.js:1 e: It's a Network Error, will retry {error: "Didn't received pong with proper ID"}
chatkit.js:1 e: Retrying in 4000ms
chatkit.js:1 TokenProvidingSubscription: subscription errored: {error: "Didn't received pong with proper ID"}
chatkit.js:1 TokenProvidingSubscription: transitioning to InactiveState
chatkit.js:1 e: Error received {error: "Didn't received pong with proper ID"}
chatkit.js:1 e: It's a Network Error, will retry {error: "Didn't received pong with proper ID"}
chatkit.js:1 e: Retrying in 4000ms
chatkit.js:1 RetryingSubscription: trying to re-establish the subscription
chatkit.js:1 TokenProvidingSubscription: transitioning to ActiveState
chatkit.js:1 RetryingSubscription: trying to re-establish the subscription
chatkit.js:1 TokenProvidingSubscription: transitioning to ActiveState
chatkit.js:1 RetryingSubscription: trying to re-establish the subscription
chatkit.js:1 TokenProvidingSubscription: transitioning to ActiveState
hamchapman commented 6 years ago

@italoj thanks for the logs again.

It really does look like your client is waiting a long time to get a token back, and that's causing the timeout.

Please could you share a screenshot of your network tab when running your app? Specifically, if you could also share a screenshot of just the token-fetching request information, that would help a lot!

italoj commented 6 years ago

@hamchapman I can't generate this type of log. I am debugging in an app in debug version on Android because the system authentication is via Firebase Number Auth. I don't have the information generated by the Network tab.

italoj commented 6 years ago

@hamchapman Give me good news! kkkkkk

hamchapman commented 6 years ago

Without more information all I can really do is guess. It looks like the token fetch requests are taking a long time and that's leading to the error. We're aware of this bug but there's an easy fix for now which is to increase the connection timeout to something larger.

italoj commented 6 years ago

@hamchapman This is a link for Pusher codepen exemple, in yours documentation! I believe that same error is occurred.

https://codepen.io/pusher/pen/XEVYmj

image

This is a Pusher issue!

Is there no other way to solve?

luiztiago commented 6 years ago

@italoj same error is happening here. it's weird

codinger41 commented 6 years ago

Same here!

jlcarruda commented 6 years ago

I'm also having this problem!

hamchapman commented 6 years ago

The error on the codepen demo was because the test token provider had been disabled for that Chatkit instance.

I've just reenabled it and it's now working.

It would appear that every time this error has been reported it's been as a result of a slow token provider response. Some of the logs @italoj shared previously also seemed to show that.

@italoj @jlcarruda @leksyib @luiztiago what are you all using for your token provider endpoint?

Are any of you using the test token provider that Chatkit provides?

Are you able to look in the Network tab of your JS console (or equivalent) to see how long your token provider endpoint is taking to return a valid token?

codinger41 commented 6 years ago

@hamchapman I'm using the token provider that Chatkit provides (of course it's enabled). But what I just realized is that it's not stable. Sometimes it establishes connections successfully and sometimes it doesn't.

hamchapman commented 6 years ago

Can you be more specific? What errors / issues do you see?

codinger41 commented 6 years ago

@hamchapman Logger.ERROR: error establishing presence subscription: Logger.ERROR: Error: presence subscription timed out

hamchapman commented 6 years ago

That's not (necessarily) an error with the token provider though. Are you seeing errors communicating with the token provider? If you look in the network tab of your JS console of your browser then do you see errors with the token provider?

neuropass commented 6 years ago

Logger.ERROR: error establishing presence subscription Logger.ERROR: Error: "presence subscription timed out"

Same thing here as of tonight! Why tonight? yesterday was all working.

What's happening? this is quite discouraging! Anything changed in the chatkit API?

please advice @vivangkumar @callum-oakley @hamchapman

EDIT: this is happeing right now on the demo from pusher docs:

https://gyazo.com/04a7fb467fd42c1ab332e865c9f4b773

which is this one: https://pusher.github.io/react-slack-clone/

Regards

hamchapman commented 6 years ago

Sometimes that can happen with the React Slack clone app because the token provider (auth) endpoint is running on a server that sometimes has a slow cold boot time. So sometimes if you're the first user to use the app for a while then you'll run into the slow boot time issue which will mean it takes you a long time to get a Chatkit token back. This can then lead to the errors about subscriptions timing out.

@neuropass If you go to the app and encounter the problem and then refresh, do you then encounter the problem again?

neuropass commented 6 years ago

@hamchapman thanks for your reply! I see but my app is not built on react. Im using VUE. I just happened to check the demo and I noticed the same issue at the same time as mine. (I did hard refresh the browser and tested on other browsers just to make sure wasn't cache related.) This is why I was pointing at pusher's server issue. This morning the app works again.

frkntony commented 6 years ago

My app is down too. I have the same error.

I've tried to re-enable my endpoint but that didn't seem to work.

neuropass commented 6 years ago

@hamchapman its happening again right now.

https://gyazo.com/340be819218273e7685a668238bf07b9

This cannot be a coincidence. Both my app the demo link above error out. Surely something is happening on pusher side. I just don't understand why you guys are not investigating the issue. If this chatkit service is not reliable then I don't know what to say. Now we are facing this connection issue, never mind a paid premium subscription at this point. Quite frustrating. To me this is an issue a top priority issue that should not be ignored. Not sure why its treated with so little importance especially after many people here coming across this situation.

Is the token auth method the issue? can there be another method to auth with pusher if this is the case? Why can this not be resolved on the pusher side?

SiteSplat commented 6 years ago

Same thing here... its been happening at least once a day for the past week or so. This is as far I can see.

neuropass commented 6 years ago

Its out again. Was working for about an hour then again here we are right now: Logger.ERROR: error establishing presence subscription Logger.ERROR: Error: "presence subscription timed out"

I don't know guys, check the sever log @pusher-ci ??? lol Can we do something about this? Are you going to tell me you are moving out of Beta like this?

RobinJayaswal commented 6 years ago

@hamchapman

I can see from the logs in my own API that it is returning this in less than 1 second when the token endpoint is hit:

AuthenticationResponse {
 status: 200,
 headers: {},
 body:
  { access_token:
     'eyJ....',
    expires_in: 86400,
    token_type: 'bearer' } }

And yet I see Logger.ERROR: Error: "presence subscription timed out" after about 10 seconds on my app. Throughout the day it sometimes works and sometimes does not (with the api always returning a response immediately) just like others here are reporting.

Above you are trying to blame it on slow networks, but I have ruled this out because my api is always able to connect with chatkit and create a token in less than one second, and my app is running on the same network (local api and iOS simulator).

Code from my api that executes in less than one second and produces above AuthenticationResponse:

const chatkit = new Chatkit.default({
  instanceLocator: INSTANCE_LOCATOR,
  key:
    process.env.CHATKIT_SECRET
})

const authData = chatkit.authenticate({
  userId: userId
})

The fact that this works on and off throughout the day and cannot be a network issue suggests to me that on Pusher's side there are some serious problems. I recognize it was a risk I took to build a feature using a beta product, but the fact that it does not seem like this is being investigated while I have a chat feature in production that sporadically works and then does not is very frustrating.

irajwani commented 6 years ago

Hi, are there any resolutions to this issue? I can't upload my app to ItunesConnect because of this error: "error establishing presence subscription". Any help would be greatly appreciated.

irajwani commented 6 years ago

Also, I'd like to second the points made by @RobinJayaswal as I had the exact same experience. Everything was working like a charm until very recently.

vivangkumar commented 6 years ago

Hey guys!

We're investigating this currently. We might have a lead, but we're not sure yet. Apologies for the inconvenience. We'll keep this updated as we know more!