Add client-side console logging to help debug reconnect issues

2 files changed, 15 insertions, 1 deletions

diff --git a/actioncable/app/assets/javascripts/action_cable/connection.coffee b/actioncable/app/assets/javascripts/action_cable/connection.coffee
index fbd7dbd35b..866bb20870 100644
--- a/actioncable/app/assets/javascripts/action_cable/connection.coffee
+++ b/actioncable/app/assets/javascripts/action_cable/connection.coffee
@@ -17,8 +17,10 @@ class ActionCable.Connection
 
   open: =>
     if @webSocket and not @isState("closed")
+      console.log("[cable] Attemped to open WebSocket, but existing socket is #{@getState()}", Date.now())
       throw new Error("Existing connection must be closed before opening")
     else
+      console.log("[cable] Opening WebSocket", Date.now())
       @webSocket = new WebSocket(@consumer.url)
       @installEventHandlers()
       true
@@ -27,12 +29,14 @@ class ActionCable.Connection
     @webSocket?.close()
 
   reopen: ->
+    console.log("[cable] Reopening WebSocket, current state is #{@getState()}", Date.now())
     if @isState("closed")
       @open()
     else
       try
         @close()
       finally
+        console.log("[cable] Failed to reopen WebSocket, retrying in #{@constructor.reopenDelay}ms", Date.now())
         setTimeout(@open, @constructor.reopenDelay)
 
   isOpen: ->
@@ -66,13 +70,16 @@ class ActionCable.Connection
           @consumer.subscriptions.notify(identifier, "received", message)
 
     open: ->
+      console.log("[cable] WebSocket onopen event", Date.now())
       @disconnected = false
       @consumer.subscriptions.reload()
 
     close: ->
+      console.log("[cable] WebSocket onclose event", Date.now())
       @disconnect()
 
     error: ->
+      console.log("[cable] WebSocket onerror event", Date.now())
       @disconnect()
 
   disconnect: ->
diff --git a/actioncable/app/assets/javascripts/action_cable/connection_monitor.coffee b/actioncable/app/assets/javascripts/action_cable/connection_monitor.coffee
index 99b9a1c6d5..e92a43688a 100644
--- a/actioncable/app/assets/javascripts/action_cable/connection_monitor.coffee
+++ b/actioncable/app/assets/javascripts/action_cable/connection_monitor.coffee
@@ -33,10 +33,12 @@ class ActionCable.ConnectionMonitor
     @startedAt = now()
     @poll()
     document.addEventListener("visibilitychange", @visibilityDidChange)
+    console.log("[cable] ConnectionMonitor started, pollInterval is #{@getInterval()}ms", Date.now())
 
   stop: ->
     @stoppedAt = now()
     document.removeEventListener("visibilitychange", @visibilityDidChange)
+    console.log("[cable] ConnectionMonitor stopped", Date.now())
 
   poll: ->
     setTimeout =>
@@ -52,8 +54,12 @@ class ActionCable.ConnectionMonitor
 
   reconnectIfStale: ->
     if @connectionIsStale()
+      console.log("[cable] ConnectionMonitor detected stale connection, reconnectAttempts = #{@reconnectAttempts}", Date.now())
       @reconnectAttempts++
-      unless @disconnectedRecently()
+      if @disconnectedRecently()
+        console.log("[cable] ConnectionMonitor skipping repopen because recently disconnected at #{@disconnectedAt}", Date.now())
+      else
+        console.log("[cable] ConnectionMonitor reopening", Date.now())
         @consumer.connection.reopen()
 
   connectionIsStale: ->
@@ -66,6 +72,7 @@ class ActionCable.ConnectionMonitor
     if document.visibilityState is "visible"
       setTimeout =>
         if @connectionIsStale() or not @consumer.connection.isOpen()
+          console.log("[cable] ConnectionMonitor reopening stale connection after visibilitychange", Date.now())
           @consumer.connection.reopen()
       , 200