* merging in master with heartbeat fixes into develop after release

.gitignore

@@ -6,4 +6,3 @@
 HTML
 .DS_Store
 coverage
-

admin/Gemfile

@@ -72,6 +72,9 @@ gem 'postgres_ext', '1.0.0'
 gem 'resque_mailer'
 gem 'rest-client'
 
+gem 'geokit-rails'
+gem 'postgres_ext', '1.0.0'
+
 group :libv8 do
   gem 'libv8', "~> 3.11.8"
 end

db/manifest

@@ -150,4 +150,4 @@ diagnostics.sql
 user_mods.sql
 connection_stale_expire.sql
 rename_chat_messages.sql
-fix_connection_fields.sql
+fix_connection_fields.sql

pb/src/client_container.proto

@@ -186,6 +186,7 @@ message LoginAck {
     optional string music_session_id = 5; // the music session that the user was in very recently (likely due to dropped connection)
     optional bool   reconnected = 6; // if reconnect_music_session_id is specified, and the server could log the user into that session, then true is returned. 
     optional string user_id = 7; // the database user id
+    optional int32  connection_expire_time = 8; // this is how long the server gives you before killing your connection entirely after missing heartbeats
 }
 
 // route_to: server

ruby/lib/jam_ruby.rb

@@ -31,6 +31,7 @@ require "jam_ruby/lib/module_overrides"
 require "jam_ruby/lib/s3_util"
 require "jam_ruby/lib/s3_manager"
 require "jam_ruby/lib/profanity"
+require "jam_ruby/lib/json_validator"
 require "jam_ruby/lib/em_helper.rb"
 require "jam_ruby/lib/nav.rb"
 require "jam_ruby/resque/audiomixer"
@@ -75,6 +76,7 @@ require "jam_ruby/models/artifact_update"
 require "jam_ruby/models/band_invitation"
 require "jam_ruby/models/band_musician"
 require "jam_ruby/models/connection"
+require "jam_ruby/models/diagnostic"
 require "jam_ruby/models/friendship"
 require "jam_ruby/models/music_session"
 require "jam_ruby/models/music_session_comment"

ruby/lib/jam_ruby/connection_manager.rb

@@ -44,7 +44,7 @@ module JamRuby
     end
   
     # reclaim the existing connection, if ip_address is not nil then perhaps a new address as well
-    def reconnect(conn, reconnect_music_session_id, ip_address)
+    def reconnect(conn, reconnect_music_session_id, ip_address, connection_stale_time, connection_expire_time)
       music_session_id = nil
       reconnected = false
 
@@ -86,7 +86,7 @@ module JamRuby
       end
 
       sql =<<SQL
-UPDATE connections SET (aasm_state, updated_at, music_session_id, joined_session_at) = ('#{Connection::CONNECT_STATE.to_s}', NOW(), #{music_session_id_expression}, #{joined_session_at_expression})
+UPDATE connections SET (aasm_state, updated_at, music_session_id, joined_session_at, stale_time, expire_time) = ('#{Connection::CONNECT_STATE.to_s}', NOW(), #{music_session_id_expression}, #{joined_session_at_expression}, #{connection_stale_time}, #{connection_expire_time})
 WHERE 
   client_id = '#{conn.client_id}'
 RETURNING music_session_id
@@ -114,7 +114,6 @@ WHERE
   aasm_state = '#{Connection::CONNECT_STATE.to_s}'
 RETURNING music_session_id
 SQL
-      # @log.info("*** flag_connection_stale_with_client_id: client_id = #{client_id}; sql = #{sql}")
       self.pg_conn.exec(sql) do |result|
 
         # if we did update a client to stale, retriee music_session_id
@@ -127,24 +126,22 @@ SQL
     end
 
     # flag  connections as stale
-    def flag_stale_connections(max_seconds)
+    def flag_stale_connections()
       ConnectionManager.active_record_transaction do |connection_manager|
         conn = connection_manager.pg_conn
         sql =<<SQL
 SELECT count(user_id) FROM connections 
 WHERE 
-  updated_at < (NOW() - interval '#{max_seconds} second') AND 
+  updated_at < (NOW() - (interval '1 second' * stale_time))AND
   aasm_state = '#{Connection::CONNECT_STATE.to_s}'
 SQL
         conn.exec(sql) do |result|
           count = result.getvalue(0, 0)
-          # @log.info("flag_stale_connections: flagging #{count} stale connections")
           if 0 < count.to_i
-            # @log.info("flag_stale_connections: flagging #{count} stale connections")
             sql =<<SQL
 UPDATE connections SET aasm_state = '#{Connection::STALE_STATE.to_s}' 
 WHERE 
-  updated_at < (NOW() - interval '#{max_seconds} second') AND
+  updated_at < (NOW() - (interval '1 second' * stale_time)) AND
   aasm_state = '#{Connection::CONNECT_STATE.to_s}'
 SQL
             conn.exec(sql) 
@@ -155,33 +152,31 @@ SQL
 
     # NOTE this is only used for testing purposes;
     # actual deletes will be processed in the websocket context which cleans up dependencies
-    def expire_stale_connections(max_seconds)
-      self.stale_connection_client_ids(max_seconds).each { |cid| self.delete_connection(cid) }
+    def expire_stale_connections()
+      self.stale_connection_client_ids().each { |client| self.delete_connection(client[:client_id]) }
     end
 
     # expiring connections in stale state, which deletes them
-    def stale_connection_client_ids(max_seconds)
-      client_ids = []
+    def stale_connection_client_ids()
+      clients = []
       ConnectionManager.active_record_transaction do |connection_manager|
         conn = connection_manager.pg_conn
 sql =<<SQL
-SELECT client_id, music_session_id, user_id FROM connections
+SELECT client_id, music_session_id, user_id, client_type FROM connections
 WHERE 
-  updated_at < (NOW() - interval '#{max_seconds} second') AND 
-  aasm_state = '#{Connection::STALE_STATE.to_s}'
+  updated_at < (NOW() - (interval '1 second' * expire_time))
 SQL
         conn.exec(sql) do |result|
           result.each { |row|
             client_id = row['client_id']
             music_session_id = row['music_session_id']
             user_id = row['user_id']
-
-            client_ids << client_id
-
+            client_type = row['client_type']
+            clients << {client_id: client_id, music_session_id: music_session_id, client_type: client_type, user_id: user_id}
           }
         end
       end
-      client_ids
+      clients
     end
 
 
@@ -189,7 +184,7 @@ SQL
     # this number is used by notification logic elsewhere to know
     # 'oh the user joined for the 1st time, so send a friend update', or
     # 'don't bother because the user has connected somewhere else already'
-    def create_connection(user_id, client_id, ip_address, client_type, &blk)
+    def create_connection(user_id, client_id, ip_address, client_type, connection_stale_time, connection_expire_time, &blk)
 
       # validate client_type
       raise "invalid client_type: #{client_type}" if client_type != 'client' && client_type != 'browser'
@@ -221,8 +216,8 @@ SQL
 
         lock_connections(conn)
 
-        conn.exec("INSERT INTO connections (user_id, client_id, ip_address, client_type, addr, locidispid, aasm_state) VALUES ($1, $2, $3, $4, $5, $6, $7)",
-                                           [user_id, client_id, ip_address, client_type, addr, locidispid, Connection::CONNECT_STATE.to_s]).clear
+        conn.exec("INSERT INTO connections (user_id, client_id, ip_address, client_type, addr, locidispid, aasm_state, stale_time, expire_time) VALUES ($1, $2, $3, $4, $5, $6, $7, $8, $9)",
+                                           [user_id, client_id, ip_address, client_type, addr, locidispid, Connection::CONNECT_STATE.to_s, connection_stale_time, connection_expire_time]).clear
 
         # we just created a new connection-if this is the first time the user has shown up, we need to send out a message to his friends
         conn.exec("SELECT count(user_id) FROM connections WHERE user_id = $1", [user_id]) do |result|

ruby/lib/jam_ruby/lib/json_validator.rb

@@ -0,0 +1,15 @@
+
+# This needs to be outside the module to work.
+class JsonValidator < ActiveModel::EachValidator
+  # implement the method called during validation
+  def is_json?(value)
+    begin
+      !!JSON.parse(value)
+    rescue
+      false
+    end
+  end
+  def validate_each(record, attribute, value)
+    record.errors[attribute] << 'must be JSON' unless value.nil? || is_json?(value)
+  end
+end

ruby/lib/jam_ruby/message_factory.rb

@@ -53,7 +53,7 @@ module JamRuby
     end
 
     # create a login ack (login was successful)
-    def login_ack(public_ip, client_id, token, heartbeat_interval, music_session_id, reconnected, user_id)
+    def login_ack(public_ip, client_id, token, heartbeat_interval, music_session_id, reconnected, user_id, connection_expire_time)
       login_ack = Jampb::LoginAck.new(
         :public_ip => public_ip,
         :client_id => client_id,
@@ -61,7 +61,8 @@ module JamRuby
         :heartbeat_interval => heartbeat_interval,
         :music_session_id => music_session_id,
         :reconnected => reconnected,
-        :user_id => user_id
+        :user_id => user_id,
+        :connection_expire_time =>  connection_expire_time
       )
 
       Jampb::ClientMessage.new(

ruby/lib/jam_ruby/models/connection.rb

@@ -3,6 +3,9 @@ require 'aasm'
 module JamRuby
   class Connection < ActiveRecord::Base
 
+    # client_types
+    TYPE_CLIENT = 'client'
+    TYPE_BROWSER = 'browser'
 
     attr_accessor :joining_session
 
@@ -12,9 +15,8 @@ module JamRuby
     belongs_to :music_session, :class_name => "JamRuby::MusicSession"
     has_many :tracks, :class_name => "JamRuby::Track", :inverse_of => :connection, :foreign_key => 'connection_id', :dependent => :delete_all
 
-
     validates :as_musician, :inclusion => {:in => [true, false]}
-    validates :client_type, :inclusion => {:in => ['client', 'browser']}
+    validates :client_type, :inclusion => {:in => [TYPE_CLIENT, TYPE_BROWSER]}
     validate :can_join_music_session, :if => :joining_session?
     after_save :require_at_least_one_track_when_in_session, :if => :joining_session?
     after_create :did_create

ruby/lib/jam_ruby/models/diagnostic.rb

@@ -0,0 +1,89 @@
+module JamRuby
+  class Diagnostic < ActiveRecord::Base
+
+    # occurs when the client does not see a heartbeat from the server in a while
+    NO_HEARTBEAT_ACK = 'NO_HEARTBEAT_ACK'
+
+    # occurs when the client sees the socket go down
+    WEBSOCKET_CLOSED_REMOTELY = 'WEBSOCKET_CLOSED_REMOTELY'
+
+    # occurs when the client makes the socket go down
+    WEBSOCKET_CLOSED_LOCALLY = 'WEBSOCKET_CLOSED_LOCALLY'
+
+    # occurs when the websocket-gateway has finally given up entirely on a connection with no heartbeats seen in a while
+    EXPIRED_STALE_CONNECTION = 'EXPIRED_STALE_CONNECTION'
+
+    # occurs when the websocket-gateway is trying to handle a heartbeat, but can't find any state for the user.
+    # this implies a coding error
+    MISSING_CLIENT_STATE = 'MISSING_CLIENT_STATE'
+
+    # websocket gateway did not recognize message. indicates out-of-date websocket-gateway
+    UNKNOWN_MESSAGE_TYPE = 'UNKNOWN_MESSAGE_TYPE'
+
+    # empty route_to in message; which is invalid.  indicates programming error
+    MISSING_ROUTE_TO = 'MISSING_ROUTE_TO'
+
+    # websocket gateway got a client with the same client_id as an already-connected client
+    DUPLICATE_CLIENT = 'DUPLICATE_CLIENT'
+
+    DIAGNOSTIC_TYPES = [NO_HEARTBEAT_ACK, WEBSOCKET_CLOSED_REMOTELY, EXPIRED_STALE_CONNECTION,
+                        MISSING_CLIENT_STATE, UNKNOWN_MESSAGE_TYPE, MISSING_ROUTE_TO,
+                        DUPLICATE_CLIENT, WEBSOCKET_CLOSED_LOCALLY]
+
+    # creator types #
+    CLIENT = 'client'
+    WEBSOCKET_GATEWAY = 'websocket-gateway'
+    CREATORS = [CLIENT, WEBSOCKET_GATEWAY]
+
+    self.primary_key = 'id'
+    self.inheritance_column = 'nothing'
+
+    belongs_to :user, :inverse_of => :diagnostics, :class_name => "JamRuby::User", :foreign_key => "user_id"
+
+    validates :user, :presence => true
+    validates :type, :inclusion => {:in => DIAGNOSTIC_TYPES}
+    validates :creator, :inclusion => {:in => CREATORS}
+    validates :data, length: {maximum: 100000}
+
+
+    def self.expired_stale_connection(user, context)
+      Diagnostic.save(EXPIRED_STALE_CONNECTION, user, WEBSOCKET_GATEWAY, context.to_json) if user
+    end
+
+    def self.missing_client_state(user, context)
+      Diagnostic.save(MISSING_CLIENT_STATE, user, WEBSOCKET_GATEWAY, context.to_json) if user
+    end
+
+    def self.missing_connection(user, context)
+      Diagnostic.save(MISSING_CONNECTION, user, WEBSOCKET_GATEWAY, context.to_json) if user
+    end
+
+    def self.duplicate_client(user, context)
+      Diagnostic.save(DUPLICATE_CLIENT, user, WEBSOCKET_GATEWAY, context.to_json) if user
+    end
+
+    def self.unknown_message_type(user, client_msg)
+      Diagnostic.save(UNKNOWN_MESSAGE_TYPE, user, WEBSOCKET_GATEWAY, client_msg.to_json) if user
+    end
+
+    def self.missing_route_to(user, client_msg)
+      Diagnostic.save(MISSING_ROUTE_TO, user, WEBSOCKET_GATEWAY, client_msg.to_json) if user
+    end
+
+
+    def self.save(type, user, creator, data)
+      diagnostic = Diagnostic.new
+      if user.class == String
+        diagnostic.user_id = user
+      else
+        diagnostic.user = user
+      end
+
+      diagnostic.data = data
+      diagnostic.type = type
+      diagnostic.creator = creator
+      diagnostic.save
+    end
+  end
+
+end

ruby/lib/jam_ruby/models/friend_request.rb

@@ -34,7 +34,7 @@ module JamRuby
         ActiveRecord::Base.transaction do
           friend_request = FriendRequest.find(id)
           friend_request.status = status
-          friend_request.updated_at = Time.now.getutc
+          friend_request.updated_at = Time.now
           friend_request.save
 
           # create both records for this friendship

ruby/lib/jam_ruby/models/track.rb

@@ -151,7 +151,7 @@ module JamRuby
         track.client_track_id = client_track_id
       end
 
-      track.updated_at = Time.now.getutc
+      track.updated_at = Time.now
       track.save
       return track
     end

ruby/lib/jam_ruby/models/user.rb

@@ -17,7 +17,7 @@ module JamRuby
     attr_accessible :first_name, :last_name, :email, :city, :password, :password_confirmation, :state, :country, :birth_date, :subscribe_email, :terms_of_service, :original_fpfile, :cropped_fpfile, :cropped_large_fpfile, :cropped_s3_path, :cropped_large_s3_path, :photo_url, :large_photo_url, :crop_selection, :lat, :lng
 
     # updating_password corresponds to a lost_password
-    attr_accessor :updating_password, :updating_email, :updated_email, :update_email_confirmation_url, :administratively_created, :current_password, :setting_password, :confirm_current_password, :updating_avatar, :updating_progression_field
+    attr_accessor :updating_password, :updating_email, :updated_email, :update_email_confirmation_url, :administratively_created, :current_password, :setting_password, :confirm_current_password, :updating_avatar, :updating_progression_field, :mods_json
 
     belongs_to :icecast_server_group, class_name: "JamRuby::IcecastServerGroup", inverse_of: :users, foreign_key: 'icecast_server_group_id'
 
@@ -105,6 +105,8 @@ module JamRuby
     # affiliate_partner
     has_one :affiliate_partner, :class_name => "JamRuby::AffiliatePartner", :foreign_key => :partner_user_id
     belongs_to :affiliate_referral, :class_name => "JamRuby::AffiliatePartner", :foreign_key => :affiliate_referral_id, :counter_cache => :referral_user_count
+    # diagnostics
+    has_many :diagnostics, :class_name => "JamRuby::Diagnostic"
 
     # This causes the authenticate method to be generated (among other stuff)
     #has_secure_password
@@ -126,6 +128,7 @@ module JamRuby
     validates :subscribe_email, :inclusion => {:in => [nil, true, false]}
     validates :musician, :inclusion => {:in => [true, false]}
     validates :show_whats_next, :inclusion => {:in => [nil, true, false]}
+    validates :mods, json: true
 
     # custom validators
     validate :validate_musician_instruments
@@ -287,6 +290,19 @@ module JamRuby
       self.music_sessions.size
     end
 
+    # mods comes back as text; so give ourselves a parsed version
+    def mods_json
+      @mods_json ||= mods ? JSON.parse(mods, symbolize_names: true) : {}
+    end
+
+    def heartbeat_interval_client
+      mods_json[:heartbeat_interval_client]
+    end
+
+    def connection_expire_time_client
+      mods_json[:connection_expire_time_client]
+    end
+
     def recent_history
       recordings = Recording.where(:owner_id => self.id)
         .order('created_at DESC')
@@ -363,7 +379,7 @@ module JamRuby
         return first_name + ' ' + last_name
       end
 
-      return id
+      id
     end
 
     def set_password(old_password, new_password, new_password_confirmation)
@@ -551,7 +567,7 @@ module JamRuby
         self.biography = biography
       end
 
-      self.updated_at = Time.now.getutc
+      self.updated_at = Time.now
       self.save
     end
 

ruby/spec/factories.rb

@@ -438,4 +438,10 @@ FactoryGirl.define do
       message Faker::Lorem.characters(10)
     end
   end
+
+  factory :diagnostic, :class => JamRuby::Diagnostic do
+    type JamRuby::Diagnostic::NO_HEARTBEAT_ACK
+    creator JamRuby::Diagnostic::CLIENT
+    data Faker::Lorem.sentence
+  end
 end

ruby/spec/jam_ruby/connection_manager_spec.rb

@@ -4,6 +4,10 @@ require 'spec_helper'
 describe ConnectionManager do
 
   TRACKS = [{"instrument_id" => "electric guitar", "sound" => "mono", "client_track_id" => "some_client_track_id"}]
+  STALE_TIME = 40
+  EXPIRE_TIME = 60
+  STALE_BUT_NOT_EXPIRED = 50
+  DEFINITELY_EXPIRED = 70
 
   before do
     @conn = PG::Connection.new(:dbname => SpecDb::TEST_DB_NAME, :user => "postgres", :password => "postgres", :host => "localhost")
@@ -53,8 +57,8 @@ describe ConnectionManager do
     user.save!
     user = nil
 
-    @connman.create_connection(user_id, client_id, "1.1.1.1", 'client')
-    expect { @connman.create_connection(user_id, client_id, "1.1.1.1", 'client') }.to raise_error(PG::Error)
+    @connman.create_connection(user_id, client_id, "1.1.1.1", 'client', STALE_TIME, EXPIRE_TIME)
+    expect { @connman.create_connection(user_id, client_id, "1.1.1.1", 'client', STALE_TIME, EXPIRE_TIME) }.to raise_error(PG::Error)
   end
 
   it "create connection then delete it" do
@@ -63,7 +67,7 @@ describe ConnectionManager do
     #user_id = create_user("test", "user2", "user2@jamkazam.com")
     user = FactoryGirl.create(:user)
 
-    count = @connman.create_connection(user.id, client_id, "1.1.1.1", 'client')
+    count = @connman.create_connection(user.id, client_id, "1.1.1.1", 'client', STALE_TIME, EXPIRE_TIME)
 
     count.should == 1
 
@@ -93,7 +97,7 @@ describe ConnectionManager do
     #user_id = create_user("test", "user2", "user2@jamkazam.com")
     user = FactoryGirl.create(:user)
 
-    count = @connman.create_connection(user.id, client_id, "1.1.1.1", 'client')
+    count = @connman.create_connection(user.id, client_id, "1.1.1.1", 'client', STALE_TIME, EXPIRE_TIME)
 
     count.should == 1
 
@@ -109,7 +113,7 @@ describe ConnectionManager do
     cc.addr.should == 0x01010101
     cc.locidispid.should == 17192000002
 
-    @connman.reconnect(cc, nil, "33.1.2.3")
+    @connman.reconnect(cc, nil, "33.1.2.3", STALE_TIME, EXPIRE_TIME)
 
     cc = Connection.find_by_client_id!(client_id)
     cc.connected?.should be_true
@@ -222,20 +226,21 @@ describe ConnectionManager do
   it "flag stale connection" do
     client_id = "client_id8"
     user_id = create_user("test", "user8", "user8@jamkazam.com")
-    @connman.create_connection(user_id, client_id, "1.1.1.1", 'client')
+    @connman.create_connection(user_id, client_id, "1.1.1.1", 'client', STALE_TIME, EXPIRE_TIME)
 
     num = JamRuby::Connection.count(:conditions => ['aasm_state = ?','connected'])
     num.should == 1
     assert_num_connections(client_id, num)
-    @connman.flag_stale_connections(60)
+    @connman.flag_stale_connections()
     assert_num_connections(client_id, num)
 
-    sleep(1)
+    conn = Connection.find_by_client_id(client_id)
+    set_updated_at(conn, Time.now - STALE_BUT_NOT_EXPIRED)
 
     num = JamRuby::Connection.count(:conditions => ["updated_at < (NOW() - interval '#{1} second') AND aasm_state = 'connected'"])
     num.should == 1
     # this should change the aasm_state to stale
-    @connman.flag_stale_connections(1)
+    @connman.flag_stale_connections()
 
     num = JamRuby::Connection.count(:conditions => ["updated_at < (NOW() - interval '#{1} second') AND aasm_state = 'connected'"])
     num.should == 0
@@ -244,31 +249,39 @@ describe ConnectionManager do
     num.should == 1
     assert_num_connections(client_id, 1)
 
-    cids = @connman.stale_connection_client_ids(1)
-    cids.size.should == 1
-    cids[0].should == client_id
-    cids.each { |cid| @connman.delete_connection(cid) }
+    conn = Connection.find_by_client_id(client_id)
+    set_updated_at(conn, Time.now - DEFINITELY_EXPIRED)
+
+    cids = @connman.stale_connection_client_ids()
+    cids.size.should == 1
+    cids[0][:client_id].should == client_id
+    cids[0][:client_type].should == Connection::TYPE_CLIENT
+    cids[0][:music_session_id].should be_nil
+    cids[0][:user_id].should == user_id
+
+    cids.each { |cid| @connman.delete_connection(cid[:client_id]) }
 
-    sleep(1)
     assert_num_connections(client_id, 0)
   end
 
   it "expires stale connection" do
     client_id = "client_id8"
     user_id = create_user("test", "user8", "user8@jamkazam.com")
-    @connman.create_connection(user_id, client_id, "1.1.1.1", 'client')
+    @connman.create_connection(user_id, client_id, "1.1.1.1", 'client', STALE_TIME, EXPIRE_TIME)
 
-    sleep(1)
-    @connman.flag_stale_connections(1)
+    conn = Connection.find_by_client_id(client_id)
+    set_updated_at(conn, Time.now - STALE_BUT_NOT_EXPIRED)
+
+    @connman.flag_stale_connections
     assert_num_connections(client_id, 1)
     # assert_num_connections(client_id, JamRuby::Connection.count(:conditions => ['aasm_state = ?','stale']))
 
-    @connman.expire_stale_connections(60)
+    @connman.expire_stale_connections
     assert_num_connections(client_id, 1)
 
-    sleep(1)
+    set_updated_at(conn, Time.now - DEFINITELY_EXPIRED)
     # this should delete the stale connection
-    @connman.expire_stale_connections(1)
+    @connman.expire_stale_connections
     assert_num_connections(client_id, 0)
   end
 
@@ -281,7 +294,7 @@ describe ConnectionManager do
     user = User.find(user_id)
     music_session = MusicSession.find(music_session_id)
 
-    @connman.create_connection(user_id, client_id, "1.1.1.1", 'client')
+    @connman.create_connection(user_id, client_id, "1.1.1.1", 'client', STALE_TIME, EXPIRE_TIME)
     connection = @connman.join_music_session(user, client_id, music_session, true, TRACKS)
 
     connection.errors.any?.should be_false
@@ -317,8 +330,8 @@ describe ConnectionManager do
     client_id2 = "client_id10.12"
     user_id = create_user("test", "user10.11", "user10.11@jamkazam.com", :musician => true)
     user_id2 = create_user("test", "user10.12", "user10.12@jamkazam.com", :musician => false)
-    @connman.create_connection(user_id, client_id, "1.1.1.1", 'client')
-    @connman.create_connection(user_id2, client_id2, "1.1.1.1", 'client')
+    @connman.create_connection(user_id, client_id, "1.1.1.1", 'client', STALE_TIME, EXPIRE_TIME)
+    @connman.create_connection(user_id2, client_id2, "1.1.1.1", 'client', STALE_TIME, EXPIRE_TIME)
 
     music_session_id = create_music_session(user_id)
 
@@ -337,7 +350,7 @@ describe ConnectionManager do
   it "as_musician is coerced to boolean" do
     client_id = "client_id10.2"
     user_id = create_user("test", "user10.2", "user10.2@jamkazam.com", :musician => false)
-    @connman.create_connection(user_id, client_id, "1.1.1.1", 'client')
+    @connman.create_connection(user_id, client_id, "1.1.1.1", 'client', STALE_TIME, EXPIRE_TIME)
 
     music_session_id = create_music_session(user_id)
 
@@ -355,8 +368,8 @@ describe ConnectionManager do
     fan_client_id = "client_id10.4"
     musician_id = create_user("test", "user10.3", "user10.3@jamkazam.com")
     fan_id = create_user("test", "user10.4", "user10.4@jamkazam.com", :musician => false)
-    @connman.create_connection(musician_id, musician_client_id, "1.1.1.1", 'client')
-    @connman.create_connection(fan_id, fan_client_id, "1.1.1.1", 'client')
+    @connman.create_connection(musician_id, musician_client_id, "1.1.1.1", 'client', STALE_TIME, EXPIRE_TIME)
+    @connman.create_connection(fan_id, fan_client_id, "1.1.1.1", 'client', STALE_TIME, EXPIRE_TIME)
 
     music_session_id = create_music_session(musician_id, :fan_access => false)
 
@@ -381,7 +394,7 @@ describe ConnectionManager do
     user = User.find(user_id2)
     music_session = MusicSession.find(music_session_id)
 
-    @connman.create_connection(user_id, client_id, "1.1.1.1", 'client')
+    @connman.create_connection(user_id, client_id, "1.1.1.1", 'client', STALE_TIME, EXPIRE_TIME)
     # specify real user id, but not associated with this session
     expect { @connman.join_music_session(user, client_id, music_session, true, TRACKS) } .to raise_error(ActiveRecord::RecordNotFound)
   end
@@ -393,7 +406,7 @@ describe ConnectionManager do
     user = User.find(user_id)
     music_session = MusicSession.new
 
-    @connman.create_connection(user_id, client_id, "1.1.1.1", 'client')
+    @connman.create_connection(user_id, client_id, "1.1.1.1", 'client', STALE_TIME, EXPIRE_TIME)
     connection = @connman.join_music_session(user, client_id, music_session, true, TRACKS)
     connection.errors.size.should == 1
     connection.errors.get(:music_session).should == [ValidationMessages::MUSIC_SESSION_MUST_BE_SPECIFIED]
@@ -408,7 +421,7 @@ describe ConnectionManager do
     user = User.find(user_id2)
     music_session = MusicSession.find(music_session_id)
 
-    @connman.create_connection(user_id, client_id, "1.1.1.1", 'client')
+    @connman.create_connection(user_id, client_id, "1.1.1.1", 'client', STALE_TIME, EXPIRE_TIME)
     # specify real user id, but not associated with this session
     expect { @connman.join_music_session(user, client_id, music_session, true, TRACKS) } .to raise_error(ActiveRecord::RecordNotFound)
   end
@@ -422,7 +435,7 @@ describe ConnectionManager do
     user = User.find(user_id)
     dummy_music_session = MusicSession.new
 
-    @connman.create_connection(user_id, client_id, "1.1.1.1", 'client')
+    @connman.create_connection(user_id, client_id, "1.1.1.1", 'client', STALE_TIME, EXPIRE_TIME)
 
     expect { @connman.leave_music_session(user, Connection.find_by_client_id(client_id), dummy_music_session) }.to raise_error(JamRuby::StateError)
   end
@@ -438,7 +451,7 @@ describe ConnectionManager do
 
     dummy_music_session = MusicSession.new
 
-    @connman.create_connection(user_id, client_id, "1.1.1.1", 'client')
+    @connman.create_connection(user_id, client_id, "1.1.1.1", 'client', STALE_TIME, EXPIRE_TIME)
     @connman.join_music_session(user, client_id, music_session, true, TRACKS)
     expect { @connman.leave_music_session(user, Connection.find_by_client_id(client_id), dummy_music_session) }.to raise_error(JamRuby::StateError)
   end
@@ -452,7 +465,7 @@ describe ConnectionManager do
     user = User.find(user_id)
     music_session = MusicSession.find(music_session_id)
 
-    @connman.create_connection(user_id, client_id, "1.1.1.1", 'client')
+    @connman.create_connection(user_id, client_id, "1.1.1.1", 'client', STALE_TIME, EXPIRE_TIME)
     @connman.join_music_session(user, client_id, music_session, true, TRACKS)
 
     assert_session_exists(music_session_id, true)
@@ -490,13 +503,12 @@ describe ConnectionManager do
     # and a connection can only point to one active music_session at a time. this is a test of
     # the latter but we need a test of the former, too.
 
-
     user_id = create_user("test", "user11", "user11@jamkazam.com")
 
     user = User.find(user_id)
 
     client_id1 = Faker::Number.number(20)
-    @connman.create_connection(user_id, client_id1, "1.1.1.1", 'client')
+    @connman.create_connection(user_id, client_id1, "1.1.1.1", 'client', STALE_TIME, EXPIRE_TIME)
     music_session1 = MusicSession.find(create_music_session(user_id))
     connection1 = @connman.join_music_session(user, client_id1, music_session1, true, TRACKS)
 

ruby/spec/jam_ruby/models/diagnostic_spec.rb

@@ -0,0 +1,18 @@
+require 'spec_helper'
+
+describe Diagnostic do
+  let (:user) { FactoryGirl.create(:user) }
+  let (:diagnostic) { FactoryGirl.create(:diagnostic, user: user) }
+
+  it 'can be made' do
+    diagnostic.save!
+  end
+
+  it "validates type" do
+    diagnostic = FactoryGirl.build(:diagnostic, user: user, type: 'bleh')
+
+    diagnostic.errors[:type].should == []
+
+  end
+
+end

ruby/spec/jam_ruby/models/track_spec.rb

@@ -74,14 +74,7 @@ describe Track do
     it "updates a single track using .id to correlate" do
       track.id.should_not be_nil
       connection.tracks.length.should == 1
-      begin
-        ActiveRecord::Base.record_timestamps = false
-        track.updated_at = 1.days.ago
-        track.save!
-      ensure
-        # very important to turn it back; it'll break all tests otherwise
-        ActiveRecord::Base.record_timestamps = true
-      end
+      set_updated_at(track, 1.days.ago)
       tracks = Track.sync(connection.client_id, [{:id => track.id, :client_track_id => 'client_guid_new', :sound => 'mono', :instrument_id => 'drums'}])
       tracks.length.should == 1
       found = tracks[0]
@@ -105,14 +98,7 @@ describe Track do
     it "does not touch updated_at when nothing changes" do
       track.id.should_not be_nil
       connection.tracks.length.should == 1
-      begin
-        ActiveRecord::Base.record_timestamps = false
-        track.updated_at = 1.days.ago
-        track.save!
-      ensure
-        # very important to turn it back; it'll break all tests otherwise
-        ActiveRecord::Base.record_timestamps = true
-      end
+      set_updated_at(track, 1.days.ago)
       tracks = Track.sync(connection.client_id, [{:id => track.id, :client_track_id => track.client_track_id, :sound => track.sound, :instrument_id => track.instrument_id}])
       tracks.length.should == 1
       found = tracks[0]

ruby/spec/jam_ruby/models/user_spec.rb

@@ -21,6 +21,7 @@ describe User do
   it { should respond_to(:admin) }
   it { should respond_to(:valid_password?) }
   it { should respond_to(:can_invite) }
+  it { should respond_to(:mods) }
 
   it { should be_valid }
   it { should_not be_admin }
@@ -69,6 +70,24 @@ describe User do
     it { should_not be_valid }
   end
 
+  describe "when mods is null" do
+    before { @user.mods = nil }
+    it { should be_valid }
+  end
+
+  describe "when mods is empty" do
+    before { @user.mods = 'nil' }
+    it { should_not be_valid }
+  end
+
+
+  describe "when mods is json object" do
+    before { @user.mods = '{"key":"value"}' }
+    it { should be_valid }
+  end
+
+
+
   describe "first or last name cant have profanity" do
     it "should not let the first name have profanity" do
       @user.first_name = "fuck you"
@@ -118,6 +137,7 @@ describe User do
 
 
     it "should be saved as all lower-case" do
+      pending
       @user.email = mixed_case_email
       @user.save!
       @user.reload.email.should == mixed_case_email.downcase
@@ -428,6 +448,29 @@ describe User do
 
 
   end
+
+  describe "mods" do
+    it "should allow update of JSON" do
+      @user.mods = {some_field: 5}.to_json
+      @user.save!
+    end
+
+    it "should return heartbeart interval" do
+      @user.heartbeat_interval_client.should be_nil
+      @user.mods = {heartbeat_interval_client: 5}.to_json
+      @user.save!
+      @user = User.find(@user.id) # necessary because mods_json is cached in the model
+      @user.heartbeat_interval_client.should == 5
+    end
+
+    it "should return connection_expire_time" do
+      @user.connection_expire_time_client.should be_nil
+      @user.mods = {connection_expire_time_client:  5}.to_json
+      @user.save!
+      @user = User.find(@user.id) # necessary because mods_json is cached in the model
+      @user.connection_expire_time_client.should == 5
+    end
+  end
 =begin
   describe "update avatar" do
 

ruby/spec/jam_ruby/resque/icecast_config_worker_spec.rb

@@ -136,14 +136,7 @@ describe IcecastConfigWriter do
             pending "failing on build server"
 
             server.touch
-            begin
-              ActiveRecord::Base.record_timestamps = false
-              server.updated_at = Time.now.ago(APP_CONFIG.icecast_max_missing_check + 1)
-              server.save!
-            ensure
-              # very important to turn it back; it'll break all tests otherwise
-              ActiveRecord::Base.record_timestamps = true
-            end
+            set_updated_at(server, Time.now.ago(APP_CONFIG.icecast_max_missing_check + 1))
 
             # should enqueue 1 job
             IcecastConfigWriter.queue_jobs_needing_retry

ruby/spec/support/utilities.rb

@@ -122,6 +122,18 @@ def run_tests? type
   ENV["RUN_#{type}_TESTS"] == "1" || ENV[type] == "1" || ENV['ALL_TESTS'] == "1"
 end
 
+# you have go out of your way to update 'updated_at '
+def set_updated_at(resource, time)
+  begin
+    ActiveRecord::Base.record_timestamps = false
+    resource.updated_at = time
+    resource.save!(validate: false)
+  ensure
+    # very important to turn it back; it'll break all tests otherwise
+    ActiveRecord::Base.record_timestamps = true
+  end
+end
+
 def wipe_s3_test_bucket
   # don't bother if the user isn't doing AWS tests
   if run_tests? :aws

web/app/assets/javascripts/AAA_Log.js

@@ -15,6 +15,12 @@
         'exception', 'table'
     ];
 
+    var log_methods = {
+      'log':null, 'debug':null, 'info':null, 'warn':null, 'error':null,  'assert':null, 'trace':null, 'exception':null
+    }
+
+    var logCache = [];
+
     if ('undefined' === typeof(context.console)) {
         context.console = {};
         $.each(console_methods, function(index, value) {
@@ -27,23 +33,39 @@
         context.console.debug = function() { console.log(arguments); }
     }
 
-    context.JK.logger = context.console;
+  // http://tobyho.com/2012/07/27/taking-over-console-log/
+  function takeOverConsole(){
+    var console = window.console
+    if (!console) return
+    function intercept(method){
+      var original = console[method]
+      console[method] = function(){
 
-    // JW - some code to tone down logging. Uncomment the following, and
-    // then do your logging to logger.dbg - and it will be the only thing output.
-    // TODO - find a way to wrap this up so that debug logs can stay in, but this
-    // class can provide a way to enable/disable certain namespaces of logs.
-    /*
-    var fakeLogger = {};
-    $.each(console_methods, function(index, value) {
-        fakeLogger[value] = $.noop;
-    });
-    fakeLogger.dbg = function(m) {
-        context.console.debug(m);
-    };
-    context.JK.logger = fakeLogger;
-    */
+        logCache.push([method].concat(arguments));
+        if(logCache.length > 50) {
+          // keep the cache size 50 or lower
+          logCache.pop();
+        }
 
+        if (original.apply){
+          // Do this for normal browsers
+          original.apply(console, arguments)
+        }else{
+          // Do this for IE
+          var message = Array.prototype.slice.apply(arguments).join(' ')
+          original(message)
+        }
+      }
+    }
+    var methods = ['log', 'warn', 'error']
+    for (var i = 0; i < methods.length; i++)
+      intercept(methods[i])
+  }
+
+  takeOverConsole();
+
+  context.JK.logger = context.console;
+  context.JK.logger.logCache = logCache;
 
 
 })(window, jQuery);

web/app/assets/javascripts/JamServer.js

@@ -14,15 +14,22 @@
 
   context.JK.JamServer = function (app) {
 
+    // uniquely identify the websocket connection
+    var channelId = null;
+    var clientType = null;
+
     // heartbeat
     var heartbeatInterval = null;
     var heartbeatMS = null;
-    var heartbeatMissedMS = 10000; // if 5 seconds go by and we haven't seen a heartbeat ack, get upset
+    var connection_expire_time = null;
+    var lastHeartbeatSentTime = null;
     var lastHeartbeatAckTime = null;
     var lastHeartbeatFound = false;
+    var lastDisconnectedReason = null;
     var heartbeatAckCheckInterval = null;
     var notificationLastSeenAt = undefined;
     var notificationLastSeen = undefined;
+    var clientClosedConnection = false;
 
     // reconnection logic
     var connectDeferred = null;
@@ -53,17 +60,23 @@
     server.connected = false;
 
 
+    function heartbeatStateReset() {
+      lastHeartbeatSentTime = null;
+      lastHeartbeatAckTime = null;
+      lastHeartbeatFound = false;
+    }
+
     // if activeElementVotes is null, then we are assuming this is the initial connect sequence
     function initiateReconnect(activeElementVotes, in_error) {
       var initialConnect = !!activeElementVotes;
 
       freezeInteraction = activeElementVotes && ((activeElementVotes.dialog && activeElementVotes.dialog.freezeInteraction === true) || (activeElementVotes.screen && activeElementVotes.screen.freezeInteraction === true));
 
-      if(!initialConnect) {
+      if (!initialConnect) {
         context.JK.CurrentSessionModel.onWebsocketDisconnected(in_error);
       }
 
-      if(in_error) {
+      if (in_error) {
         reconnectAttempt = 0;
         $currentDisplay = renderDisconnected();
         beginReconnectPeriod();
@@ -87,7 +100,7 @@
 
       if (server.connected) {
         server.connected = false;
-        if(app.clientUpdating) {
+        if (app.clientUpdating) {
           // we don't want to do a 'cover the whole screen' dialog
           // because the client update is already showing.
           return;
@@ -126,8 +139,9 @@
 
       // check if the server is still sending heartbeat acks back down
       // this logic equates to 'if we have not received a heartbeat within heartbeatMissedMS, then get upset
-      if (new Date().getTime() - lastHeartbeatAckTime.getTime() > heartbeatMissedMS) {
-        logger.error("no heartbeat ack received from server after ", heartbeatMissedMS, " seconds . giving up on socket connection");
+      if (new Date().getTime() - lastHeartbeatAckTime.getTime() > connection_expire_time) {
+        logger.error("no heartbeat ack received from server after ", connection_expire_time, " seconds . giving up on socket connection");
+        lastDisconnectedReason = 'NO_HEARTBEAT_ACK';
         context.JK.JamServer.close(true);
       }
       else {
@@ -140,6 +154,16 @@
         var message = context.JK.MessageFactory.heartbeat(notificationLastSeen, notificationLastSeenAt);
         notificationLastSeenAt = undefined;
         notificationLastSeen = undefined;
+        // for debugging purposes, see if the last time we've sent a heartbeat is way off (500ms) of the target interval
+        var now = new Date();
+
+        if (lastHeartbeatSentTime) {
+          var drift = new Date().getTime() - lastHeartbeatSentTime.getTime() - heartbeatMS;
+          if (drift > 500) {
+            logger.error("significant drift between heartbeats: " + drift + 'ms beyond target interval')
+          }
+        }
+        lastHeartbeatSentTime = now;
         context.JK.JamServer.send(message);
         lastHeartbeatFound = false;
       }
@@ -147,11 +171,13 @@
 
     function loggedIn(header, payload) {
 
-      if(!connectTimeout) {
+      if (!connectTimeout) {
         clearTimeout(connectTimeout);
         connectTimeout = null;
       }
 
+      heartbeatStateReset();
+
       app.clientId = payload.client_id;
 
       // tell the backend that we have logged in
@@ -159,12 +185,13 @@
 
       $.cookie('client_id', payload.client_id);
 
+
       heartbeatMS = payload.heartbeat_interval * 1000;
-      logger.debug("jamkazam.js.loggedIn(): clientId now " + app.clientId + "; Setting up heartbeat every " + heartbeatMS + " MS");
+      connection_expire_time = payload.connection_expire_time * 1000;
+      logger.debug("jamkazam.js.loggedIn(): clientId=" + app.clientId + ", heartbeat=" + payload.heartbeat_interval + "s, expire_time=" + payload.connection_expire_time + 's');
       heartbeatInterval = context.setInterval(_heartbeat, heartbeatMS);
       heartbeatAckCheckInterval = context.setInterval(_heartbeatAckCheck, 1000);
       lastHeartbeatAckTime = new Date(new Date().getTime() + heartbeatMS); // add a little forgiveness to server for initial heartbeat
-
       connectDeferred.resolve();
       app.activeElementEvent('afterConnect', payload);
 
@@ -209,10 +236,10 @@
     function internetUp() {
       var start = new Date().getTime();
       server.connect()
-        .done(function() {
+        .done(function () {
           guardAgainstRapidTransition(start, performReconnect);
         })
-        .fail(function() {
+        .fail(function () {
           guardAgainstRapidTransition(start, closedOnReconnectAttempt);
         });
     }
@@ -224,18 +251,37 @@
 
     function performReconnect() {
 
-      if($currentDisplay.is('.no-websocket-connection')) {
-        $currentDisplay.hide();
+      if(!clientClosedConnection) {
+        lastDisconnectedReason = 'WEBSOCKET_CLOSED_REMOTELY'
+        clientClosedConnection = false;
+      }
+      else if(!lastDisconnectedReason) {
+        // let's have at least some sort of type, however generci
+        lastDisconnectedReason = 'WEBSOCKET_CLOSED_LOCALLY'
+      }
+
+      rest.createDiagnostic({
+        type: lastDisconnectedReason,
+        data: {logs: logger.logCache, client_type: clientType, client_id: server.clientID, channel_id: channelId}
+      })
+      .always(function() {
+        if ($currentDisplay.is('.no-websocket-connection')) {
+          // this path is the 'not in session path'; so there is nothing else to do
+          $currentDisplay.hide();
+
+          // TODO: tell certain elements that we've reconnected
+        }
+        else {
+          // this path is the 'in session' path, where we actually reload the page
+          context.JK.CurrentSessionModel.leaveCurrentSession()
+            .always(function () {
+              window.location.reload();
+            });
+        }
+        server.reconnecting = false;
+      });
+
 
-        // TODO: tell certain elements that we've reconnected
-      }
-      else {
-        context.JK.CurrentSessionModel.leaveCurrentSession()
-          .always(function() {
-            window.location.reload();
-          });
-      }
-      server.reconnecting = false;
     }
 
     function buildOptions() {
@@ -245,14 +291,14 @@
     function renderDisconnected() {
 
       var content = null;
-      if(freezeInteraction) {
+      if (freezeInteraction) {
         var template = $templateDisconnected.html();
         var templateHtml = $(context.JK.fillTemplate(template, buildOptions()));
         templateHtml.find('.reconnect-countdown').html(formatDelaySecs(reconnectDelaySecs()));
         content = context.JK.Banner.show({
-          html : templateHtml,
+          html: templateHtml,
           type: 'reconnect'
-        }) ;
+        });
       }
       else {
         var $inSituContent = $(context._.template($templateServerConnection.html(), buildOptions(), { variable: 'data' }));
@@ -267,7 +313,7 @@
     }
 
     function formatDelaySecs(secs) {
-      return $('<span class="countdown-seconds"><span class="countdown">' + secs + '</span> ' + (secs == 1 ?  ' second.<span style="visibility:hidden">s</span>' : 'seconds.') + '</span>');
+      return $('<span class="countdown-seconds"><span class="countdown">' + secs + '</span> ' + (secs == 1 ? ' second.<span style="visibility:hidden">s</span>' : 'seconds.') + '</span>');
     }
 
     function setCountdown($parent) {
@@ -281,7 +327,7 @@
     function renderReconnecting() {
       $currentDisplay.find('.reconnect-progress-msg').text('Attempting to reconnect...')
 
-      if($currentDisplay.is('.no-websocket-connection')) {
+      if ($currentDisplay.is('.no-websocket-connection')) {
         $currentDisplay.find('.disconnected-reconnect').removeClass('reconnect-enabled').addClass('reconnect-disabled');
       }
       else {
@@ -299,7 +345,7 @@
       var now = new Date().getTime();
 
       if ((now - start) < 1500) {
-        setTimeout(function() {
+        setTimeout(function () {
           nextStep();
         }, 1500 - (now - start))
       }
@@ -315,12 +361,12 @@
       renderReconnecting();
 
       rest.serverHealthCheck()
-        .done(function() {
+        .done(function () {
           guardAgainstRapidTransition(start, internetUp);
         })
-        .fail(function(xhr, textStatus, errorThrown) {
+        .fail(function (xhr, textStatus, errorThrown) {
 
-          if(xhr && xhr.status >= 100) {
+          if (xhr && xhr.status >= 100) {
             // we could connect to the server, and it's alive
             guardAgainstRapidTransition(start, internetUp);
           }
@@ -333,7 +379,7 @@
     }
 
     function clearReconnectTimers() {
-      if(countdownInterval) {
+      if (countdownInterval) {
         clearInterval(countdownInterval);
         countdownInterval = null;
       }
@@ -341,8 +387,8 @@
 
     function beginReconnectPeriod() {
       // allow user to force reconnect
-      $currentDisplay.find('a.disconnected-reconnect').unbind('click').click(function() {
-        if($(this).is('.button-orange') || $(this).is('.reconnect-enabled')) {
+      $currentDisplay.find('a.disconnected-reconnect').unbind('click').click(function () {
+        if ($(this).is('.button-orange') || $(this).is('.reconnect-enabled')) {
           clearReconnectTimers();
           attemptReconnect();
         }
@@ -353,9 +399,9 @@
       reconnectDueTime = reconnectingWaitPeriodStart + reconnectDelaySecs() * 1000;
 
       // update count down timer periodically
-      countdownInterval = setInterval(function() {
+      countdownInterval = setInterval(function () {
         var now = new Date().getTime();
-        if(now > reconnectDueTime) {
+        if (now > reconnectDueTime) {
           clearReconnectTimers();
           attemptReconnect();
         }
@@ -404,9 +450,14 @@
     };
 
     server.connect = function () {
+      if(!clientType) {
+        clientType = context.JK.clientType();
+      }
       connectDeferred = new $.Deferred();
-      logger.log("server.connect");
-      var uri = context.JK.websocket_gateway_uri;  // Set in index.html.erb.
+      channelId = context.JK.generateUUID(); // create a new channel ID for every websocket connection
+      logger.log("connecting websocket, channel_id: " + channelId);
+
+      var uri = context.JK.websocket_gateway_uri + '?channel_id=' + channelId;  // Set in index.html.erb.
       //var uri = context.gon.websocket_gateway_uri; // Leaving here for now, as we're looking for a better solution.
 
       server.socket = new context.WebSocket(uri);
@@ -414,9 +465,10 @@
       server.socket.onmessage = server.onMessage;
       server.socket.onclose = server.onClose;
 
-      connectTimeout = setTimeout(function() {
+      connectTimeout = setTimeout(function () {
         connectTimeout = null;
-        if(connectDeferred.state() === 'pending') {
+        if (connectDeferred.state() === 'pending') {
+          server.close(true);
           connectDeferred.reject();
         }
       }, 4000);
@@ -427,6 +479,7 @@
     server.close = function (in_error) {
       logger.log("closing websocket");
 
+      clientClosedConnection = true;
       server.socket.close();
 
       closedCleanup(in_error);
@@ -435,7 +488,7 @@
     server.rememberLogin = function () {
       var token, loginMessage;
       token = $.cookie("remember_token");
-      var clientType = context.jamClient.IsNativeClient() ? 'client' : 'browser';
+
       loginMessage = msg_factory.login_with_token(token, null, clientType);
       server.send(loginMessage);
     };
@@ -471,10 +524,11 @@
       }
     };
 
+    // onClose is called if either client or server closes connection
     server.onClose = function () {
       logger.log("Socket to server closed.");
 
-      if(connectDeferred.state() === "pending") {
+      if (connectDeferred.state() === "pending") {
         connectDeferred.reject();
       }
 
@@ -521,19 +575,19 @@
       //console.timeEnd('sendP2PMessage');
     };
 
-    server.updateNotificationSeen = function(notificationId, notificationCreatedAt) {
+    server.updateNotificationSeen = function (notificationId, notificationCreatedAt) {
       var time = new Date(notificationCreatedAt);
 
-      if(!notificationCreatedAt) {
+      if (!notificationCreatedAt) {
         throw 'invalid value passed to updateNotificationSeen'
       }
 
-      if(!notificationLastSeenAt) {
+      if (!notificationLastSeenAt) {
         notificationLastSeenAt = notificationCreatedAt;
         notificationLastSeen = notificationId;
         logger.debug("updated notificationLastSeenAt with: " + notificationCreatedAt);
       }
-      else if(time.getTime() > new Date(notificationLastSeenAt).getTime()) {
+      else if (time.getTime() > new Date(notificationLastSeenAt).getTime()) {
         notificationLastSeenAt = notificationCreatedAt;
         notificationLastSeen = notificationId;
         logger.debug("updated notificationLastSeenAt with: " + notificationCreatedAt);
@@ -573,6 +627,7 @@
     }
 
     function initialize() {
+
       registerLoginAck();
       registerHeartbeatAck();
       registerSocketClosed();
@@ -584,12 +639,24 @@
       $templateServerConnection = $('#template-server-connection');
       $templateDisconnected = $('#template-disconnected');
 
-      if($inSituBanner.length != 1) { throw "found wrong number of .server-connection: " + $inSituBanner.length; }
-      if($inSituBannerHolder.length != 1) { throw "found wrong number of .no-websocket-connection: " + $inSituBannerHolder.length; }
-      if($messageContents.length != 1) { throw "found wrong number of .message-contents: " + $messageContents.length; }
-      if($dialog.length != 1) { throw "found wrong number of #banner: " + $dialog.length; }
-      if($templateServerConnection.length != 1) { throw "found wrong number of #template-server-connection: " + $templateServerConnection.length; }
-      if($templateDisconnected.length != 1) { throw "found wrong number of #template-disconnected: " + $templateDisconnected.length; }
+      if ($inSituBanner.length != 1) {
+        throw "found wrong number of .server-connection: " + $inSituBanner.length;
+      }
+      if ($inSituBannerHolder.length != 1) {
+        throw "found wrong number of .no-websocket-connection: " + $inSituBannerHolder.length;
+      }
+      if ($messageContents.length != 1) {
+        throw "found wrong number of .message-contents: " + $messageContents.length;
+      }
+      if ($dialog.length != 1) {
+        throw "found wrong number of #banner: " + $dialog.length;
+      }
+      if ($templateServerConnection.length != 1) {
+        throw "found wrong number of #template-server-connection: " + $templateServerConnection.length;
+      }
+      if ($templateDisconnected.length != 1) {
+        throw "found wrong number of #template-disconnected: " + $templateDisconnected.length;
+      }
     }
 
     this.initialize = initialize;

web/app/assets/javascripts/configureTrack.js

@@ -7,18 +7,8 @@
     var logger = context.JK.logger;
     var myTrackCount;
 
-    var ASSIGNMENT = {
-      CHAT: -2,
-      OUTPUT: -1,
-      UNASSIGNED: 0,
-      TRACK1: 1,
-      TRACK2: 2
-    };
-
-    var VOICE_CHAT = {
-      NO_CHAT: "0",
-      CHAT: "1"
-    };
+    var ASSIGNMENT = context.JK.ASSIGNMENT;
+    var VOICE_CHAT = context.JK.VOICE_CHAT;
 
     var instrument_array = [];
 

web/app/assets/javascripts/gear_wizard.js

@@ -6,6 +6,8 @@
   context.JK = context.JK || {};
   context.JK.GearWizard = function (app) {
 
+    var ASSIGNMENT = context.JK.ASSIGNMENT;
+    var VOICE_CHAT = context.JK.VOICE_CHAT;
 
     var $dialog = null;
     var $wizardSteps = null;
@@ -20,11 +22,11 @@
 
     // populated by loadDevices
     var deviceInformation = null;
-    var musicInputPorts = null;
-    var musicOutputPorts = null;
+    var musicPorts = null;
 
-    // SELECT DEVICE STATE
-    var validScore = false;
+
+    var validLatencyScore = false;
+    var validIOScore = false;
 
     // SELECT TRACKS STATE
 
@@ -46,7 +48,7 @@
         display: 'MacOSX Built-In',
         videoURL: undefined
       },
-      MACOSX_interface: {
+      MacOSX_interface: {
         display: 'MacOSX external interface',
         videoURL: undefined
       },
@@ -86,13 +88,19 @@
       var $bufferIn = $currentWizardStep.find('.select-buffer-in');
       var $bufferOut = $currentWizardStep.find('.select-buffer-out');
       var $frameSize = $currentWizardStep.find('.select-frame-size');
-      var $inputPorts = $currentWizardStep.find('.input-ports');
-      var $outputPorts = $currentWizardStep.find('.output-ports');
+      var $inputChannels = $currentWizardStep.find('.input-ports');
+      var $outputChannels = $currentWizardStep.find('.output-ports');
       var $scoreReport = $currentWizardStep.find('.results');
+      var $latencyScoreSection = $scoreReport.find('.latency-score-section');
       var $latencyScore = $scoreReport.find('.latency-score');
+      var $ioScoreSection = $scoreReport.find('.io-score-section');
       var $ioRateScore = $scoreReport.find('.io-rate-score');
       var $ioVarScore = $scoreReport.find('.io-var-score');
+      var $ioCountdown = $scoreReport.find('.io-countdown');
+      var $ioCountdownSecs = $scoreReport.find('.io-countdown .secs');
       var $nextButton = $ftueButtons.find('.btn-next');
+      var $asioControlPanelBtn = $currentWizardStep.find('.asio-settings-btn');
+      var $resyncBtn = $currentWizardStep.find('resync-btn')
 
       // should return one of:
       // * MacOSX_builtin
@@ -126,22 +134,31 @@
         }
       }
 
-
       function loadDevices() {
-        var devices = context.jamClient.FTUEGetDevices(false);
+
+        var oldDevices = context.jamClient.FTUEGetDevices(false);
+        var devices = context.jamClient.FTUEGetAudioDevices();
+        console.log("oldDevices: " + JSON.stringify(oldDevices));
+        console.log("devices: " + JSON.stringify(devices));
 
         var loadedDevices = {};
 
         // augment these devices by determining their type
-        context._.each(devices, function (displayName, deviceId) {
+        context._.each(devices.devices, function (device) {
+
+          if(device.name == "JamKazam Virtual Monitor") {
+            return;
+          }
+
           var deviceInfo = {};
 
-          deviceInfo.id = deviceId;
-          deviceInfo.type = determineDeviceType(deviceId, displayName);
+          deviceInfo.id = device.guid;
+          deviceInfo.type = determineDeviceType(device.guid, device.display_name);
+          console.log("deviceInfo.type: " + deviceInfo.type)
           deviceInfo.displayType = audioDeviceBehavior[deviceInfo.type].display;
-          deviceInfo.displayName = displayName;
+          deviceInfo.displayName = device.display_name;
 
-          loadedDevices[deviceId] = deviceInfo;
+          loadedDevices[device.guid] = deviceInfo;
 
           logger.debug("loaded device: ", deviceInfo);
         })
@@ -179,7 +196,7 @@
       function initializeNextButtonState() {
         $nextButton.removeClass('button-orange button-grey');
 
-        if (validScore)  $nextButton.addClass('button-orange');
+        if (validLatencyScore)  $nextButton.addClass('button-orange');
         else            $nextButton.addClass('button-grey');
       }
 
@@ -218,71 +235,66 @@
         context.JK.dropdown($bufferOut);
       }
 
-      // finds out if the $port argument is from a different port pair than what's currently selected
-      function isNewlySelectedPair($port) {
-        var portId = $port.attr('data-id');
-        // get all inputs currently selected except this one
-        var $selectedInputs = $inputPorts.find('input[type="checkbox"]:checked').filter('[data-id="' + portId + '"]');
 
-        console.log("$selectedInputs", $selectedInputs);
-        var isNewlySelected = true;
-        context._.each($selectedInputs, function($current) {
-          var testPairInfo = $($current).data('pair');
+      // reloads the backend's channel state for the currently selected audio devices,
+      // and update's the UI accordingly
+      function initializeChannels() {
+        musicPorts = jamClient.FTUEGetChannels();
+        console.log("musicPorts: %o", JSON.stringify(musicPorts));
 
-          context._.each(testPairInfo.ports, function(port) {
-            // if we can find the newly selected item in this pair, then it's not a different pair...
-            if(port.id == portId) {
-              isNewlySelected = false;
-              return false; // break loop
-            }
-          });
+        initializeInputPorts(musicPorts);
+        initializeOutputPorts(musicPorts);
+      }
 
-          if(isNewlySelected) return false; // break loop
+      // during this phase of the FTUE, we have to assign selected input channels
+      // to tracks. The user, however, does not have a way to indicate which channel
+      // goes to which track (that's not until the next step of the wizard).
+      // so, we just auto-generate a valid assignment
+      function newInputAssignment() {
+        var assigned = 0;
+        context._.each(musicPorts.inputs, function(inputChannel) {
+          if(isChannelAssigned(inputChannel)) {
+            assigned += 1;
+          }
         });
 
-        return isNewlySelected;
+        var newAssignment = Math.floor(assigned / 2) + 1;
+        return newAssignment;
       }
 
-      // set checkbox state for all items in the pair
-      function setCheckedForAllInPair($portBox, pairInfo, checked, signalBackend) {
-        context._.each(pairInfo.ports, function(port) {
-          var portId = port.id;
-          var $input = $portBox.find('input[type="checkbox"][data-id="' + portId + '"]');
-          if($input.is(':checked') != checked) {
-            if(checked) {
-              $input.iCheck('check').attr('checked', 'checked');
-              //context.jamClient.FTUESetMusicInput2($input.id);
-            }
-            else  {
-              $input.iCheck('uncheck').removeAttr('checked');
-              //context.jamClient.FTUEUnsetMusicInput2($input.id);
-            }
-          }
-        })
-      }
-
-      function inputPortChanged() {
+      function inputChannelChanged() {
         if(iCheckIgnore) return;
 
         var $checkbox = $(this);
-        var portId = $checkbox.data('data-id');
-        var inputPortChecked = $checkbox.is(':checked');
-        console.log('inputPortChecked: ' + inputPortChecked);
+        var channelId = $checkbox.attr('data-id');
+        var isChecked = $checkbox.is(':checked');
 
-        if(inputPortChecked) {
-          if(isNewlySelectedPair($checkbox)) {
-            setCheckedForAllInPair($inputPorts, $checkbox.data('pair'), true, true);
-          }
-          else {
-            //context.jamClient.FTUESetMusicInput2($input.id);
-          }
+        if(isChecked) {
+          var newAssignment = newInputAssignment();
+          logger.debug("assigning input channel %o to track: %o", channelId, newAssignment);
+          context.jamClient.TrackSetAssignment(channelId, true, newAssignment);
         }
         else {
-          // context.jamClient.FTUEUnsetMusicInput2($input.id);;
+          logger.debug("unassigning input channel %o", channelId);
+          context.jamClient.TrackSetAssignment(channelId, true, ASSIGNMENT.UNASSIGNED);
+          // unassigning creates a hole in our auto-assigned tracks.  reassign them all to keep it consistent
+          var $assignedInputs = $inputChannels.find('input[type="checkbox"]:checked');
+          var assigned = 0;
+          context._.each($assignedInputs, function(assignedInput) {
+            var $assignedInput = $(assignedInput);
+            var assignedChannelId = $assignedInput.attr('data-id');
+            var newAssignment = Math.floor(assigned / 2) + 1;
+            logger.debug("re-assigning input channel %o to track: %o", assignedChannelId, newAssignment);
+            context.jamClient.TrackSetAssignment(assignedChannelId, true, newAssignment);
+            assigned += 1;
+          });
         }
+
+        initializeChannels();
       }
 
-      // should be called in a ifChanged callback if you want to cancel. bleh.
+      // should be called in a ifChanged callback if you want to cancel.
+      // you have to use this instead of 'return false' like a typical input 'change' event.
       function cancelICheckChange($checkbox) {
         iCheckIgnore = true;
         var checked = $checkbox.is(':checked');
@@ -293,58 +305,64 @@
         }, 1);
       }
 
-      function outputPortChanged() {
+      function outputChannelChanged() {
         if(iCheckIgnore) return;
-
         var $checkbox = $(this);
-        var portId = $checkbox.data('data-id');
-        var outputPortChecked = $checkbox.is(':checked');
-        console.log('outputPortChecked: ' + outputPortChecked);
+        var channelId = $checkbox.attr('data-id');
+        var isChecked = $checkbox.is(':checked');
 
-        if(outputPortChecked) {
-          var $selectedInputs = $outputPorts.find('input[type="checkbox"]:checked').filter('[data-id="' + portId + '"]');
-          $selectedInputs.iCheck('uncheck').removeAttr('checked');
-          var pairInfo = $checkbox.data('pair');
-          setCheckedForAllInPair($outputPorts, pairInfo, true, false);
-          console.log("Setting music output");
-          context.jamClient.FTUESetMusicOutput(pairInfo.ports.map(function(i) {return i.id}).join(PROFILE_DEV_SEP_TOKEN));
-        }
-        else {
-          context.JK.Banner.showAlert('You must have at least one output pair selected.');
+        // don't allow more than 2 output channels selected at once
+        if($outputChannels.find('input[type="checkbox"]:checked').length > 2) {
+          context.JK.Banner.showAlert('You can only have a maximum of 2 output ports selected.');
           // can't allow uncheck of last output
           cancelICheckChange($checkbox);
+          return;
         }
+
+        if(isChecked) {
+          logger.debug("assigning output channel %o", channelId);
+          context.jamClient.TrackSetAssignment(channelId, true, ASSIGNMENT.OUTPUT);
+        }
+        else {
+          logger.debug("unassigning output channel %o", channelId);
+          context.jamClient.TrackSetAssignment(channelId, true, ASSIGNMENT.UNASSIGNED);
+        }
+
+        initializeChannels();
       }
 
-      function initializeInputPorts(inputPorts) {
-        context._.each(inputPorts, function(inputPairs) {
-          // there is no guarantee that a pair has two items.
-          context._.each(inputPairs.ports, function(inputInPair) {
-            var inputPort = $(context._.template($templateAudioPort.html(), inputInPair, { variable: 'data' }));
-            var $checkbox = inputPort.find('input');
-            $checkbox.data('pair', inputPairs); // so when it's selected, we can see what other ports, if any, are in the same pair
-            context.JK.checkbox($checkbox);
-            $checkbox.on('ifChanged', inputPortChanged);
-            $inputPorts.append(inputPort);
-          });
+      // checks if it's an assigned OUTPUT or ASSIGNED CHAT
+      function isChannelAssigned(channel) {
+        return channel.assignment == ASSIGNMENT.CHAT || channel.assignment == ASSIGNMENT.OUTPUT || channel.assignment > 0;
+      }
+
+      function initializeInputPorts(musicPorts) {
+        $inputChannels.empty();
+        var inputPorts = musicPorts.inputs;
+        context._.each(inputPorts, function(inputChannel) {
+          var $inputChannel = $(context._.template($templateAudioPort.html(), inputChannel, { variable: 'data' }));
+          var $checkbox = $inputChannel.find('input');
+          if(isChannelAssigned(inputChannel)) {
+            $checkbox.attr('checked', 'checked');
+          }
+          context.JK.checkbox($checkbox);
+          $checkbox.on('ifChanged', inputChannelChanged);
+          $inputChannels.append($inputChannel);
         });
       }
 
-      function initializeOutputPorts(outputPorts) {
-        var first = true;
-        context._.each(outputPorts, function(outputPairs) {
-          context._.each(outputPairs.ports, function(outputInPair) {
-            var outputPort = $(context._.template($templateAudioPort.html(), outputInPair, { variable: 'data' }));
-            var $checkbox = outputPort.find('input');
-            $checkbox.data('pair', outputPairs); // so when it's selected, we can see what other ports, if any, are in the same pair
-            context.JK.checkbox($checkbox);
-            $checkbox.on('ifChanged', outputPortChanged);
-            $outputPorts.append(outputPort);
-          });
-          if(first) {
-            first = false;
-            setCheckedForAllInPair($outputPorts, outputPairs, true, false);
+      function initializeOutputPorts(musicPorts) {
+        $outputChannels.empty();
+        var outputChannels = musicPorts.outputs;
+        context._.each(outputChannels, function(outputChannel) {
+          var $outputPort = $(context._.template($templateAudioPort.html(), outputChannel, { variable: 'data' }));
+          var $checkbox = $outputPort.find('input');
+          if(isChannelAssigned(outputChannel)) {
+            $checkbox.attr('checked', 'checked');
           }
+          context.JK.checkbox($checkbox);
+          $checkbox.on('ifChanged', outputChannelChanged);
+          $outputChannels.append($outputPort);
         });
       }
 
@@ -364,11 +382,11 @@
       }
 
       function clearInputPorts() {
-        $inputPorts.empty();
+        $inputChannels.empty();
       }
 
       function clearOutputPorts() {
-        $outputPorts.empty();
+        $outputChannels.empty();
       }
 
       function resetScoreReport() {
@@ -377,6 +395,27 @@
         $latencyScore.empty();
       }
 
+      function renderLatencyScore(latencyValue, latencyClass) {
+        if(latencyValue) {
+          $latencyScore.text(latencyValue + ' ms');
+        }
+        else {
+          $latencyScore.text('');
+        }
+        $latencyScoreSection.removeClass('good acceptable bad unknown starting').addClass(latencyClass);
+      }
+
+      // std deviation is the worst value between in/out
+      // media is the worst value between in/out
+      // io is the value returned by the backend, which has more info
+      // ioClass is the pre-computed rollup class describing the result in simple terms of 'good', 'acceptable', bad'
+      function renderIOScore(std, median, ioData, ioClass) {
+        $ioRateScore.text(median ? median : '');
+        $ioVarScore.text(std ? std : '');
+        $ioScoreSection.removeClass('good acceptable bad unknown starting skip').addClass(ioClass);
+        // TODO: show help bubble of all data in IO data
+      }
+
       function updateScoreReport(latencyResult) {
         var latencyClass = "neutral";
         var latencyValue = 'N/A';
@@ -387,37 +426,69 @@
           if (latencyValue <= 10) {
             latencyClass = "good";
             validLatency = true;
-          } else if (latency.latency <= 20) {
+          } else if (latencyValue <= 20) {
             latencyClass = "acceptable";
             validLatency = true;
           } else {
             latencyClass = "bad";
           }
         }
+        else {
+          latencyClass = 'unknown';
+        }
 
-        validScore = validLatency; // validScore may become based on IO variance too
+        validLatencyScore = validLatency;
 
-        $latencyScore.html(latencyValue + ' ms');
+        renderLatencyScore(latencyValue, latencyClass);
       }
 
       function audioInputDeviceUnselected() {
-        validScore = false;
+        validLatencyScore = false;
         initializeNextButtonState();
         resetFrameBuffers();
         clearInputPorts();
       }
 
       function renderScoringStarted() {
-        validScore = false;
+        validLatencyScore = false;
         initializeNextButtonState();
         resetScoreReport();
+        freezeAudioInteraction();
+        renderLatencyScore(null, 'starting');
       }
 
       function renderScoringStopped() {
         initializeNextButtonState();
+        unfreezeAudioInteraction();
       }
 
 
+      function freezeAudioInteraction() {
+        $audioInput.attr("disabled", "disabled").easyDropDown('disable');
+        $audioOutput.attr("disabled", "disabled").easyDropDown('disable');
+        $frameSize.attr("disabled", "disabled").easyDropDown('disable');
+        $bufferIn.attr("disabled", "disabled").easyDropDown('disable');
+        $bufferOut.attr("disabled", "disabled").easyDropDown('disable');
+        $asioControlPanelBtn.on("click", false);
+        $resyncBtn.on('click', false);
+        iCheckIgnore = true;
+        $inputChannels.find('input[type="checkbox"]').iCheck('disable');
+        $outputChannels.find('input[type="checkbox"]').iCheck('disable');
+      }
+
+      function unfreezeAudioInteraction() {
+        $audioInput.removeAttr("disabled").easyDropDown('enable');
+        $audioOutput.removeAttr("disabled").easyDropDown('enable');
+        $frameSize.removeAttr("disabled").easyDropDown('enable');
+        $bufferIn.removeAttr("disabled").easyDropDown('enable');
+        $bufferOut.removeAttr("disabled").easyDropDown('enable');
+        $asioControlPanelBtn.off("click", false);
+        $resyncBtn.off('click', false);
+        $inputChannels.find('input[type="checkbox"]').iCheck('enable');
+        $outputChannels.find('input[type="checkbox"]').iCheck('enable');
+        iCheckIgnore = false;
+      }
+
       // Given a latency structure, update the view.
       function newFtueUpdateLatencyView(latency) {
         var $report = $('.ftue-new .latency .report');
@@ -506,44 +577,52 @@
         });
       }
 
-      function initializeAudioInputChanged() {
-        $audioInput.unbind('change').change(function (evt) {
+      function renderIOScoringStarted(secondsLeft) {
+        $ioCountdownSecs.text(secondsLeft);
+        $ioCountdown.show();
+      }
 
-          var audioDeviceId = selectedAudioInput();
-          if (!audioDeviceId) {
+      function renderIOScoringStopped() {
+        $ioCountdown.hide();
+      }
+
+      function renderIOCountdown(secondsLeft) {
+        $ioCountdownSecs.text(secondsLeft);
+      }
+
+      function attemptScore() {
+          var audioInputDeviceId = selectedAudioInput();
+          var audioOutputDeviceId = selectedAudioOutput();
+          if (!audioInputDeviceId) {
             audioInputDeviceUnselected();
             return false;
           }
 
-          var audioDevice = findDevice(selectedAudioInput());
-          if (!audioDevice) {
-            context.JK.alertSupportedNeeded('Unable to find device information for: ' + audioDeviceId);
+          var audioInputDevice = findDevice(audioInputDeviceId);
+          if (!audioInputDevice) {
+            context.JK.alertSupportedNeeded('Unable to find information for input device: ' + audioInputDeviceId);
             return false;
           }
 
+          if(!audioOutputDeviceId) {
+            audioOutputDeviceId = audioInputDeviceId;
+          }
+          var audioOutputDevice = findDevice(audioOutputDeviceId);
+          if (!audioInputDevice) {
+            context.JK.alertSupportedNeeded('Unable to find information for output device: ' + audioOutputDeviceId);
+            return false;
+          }
 
+          jamClient.FTUESetInputMusicDevice(audioInputDeviceId);
+          jamClient.FTUESetOutputMusicDevice(audioOutputDeviceId);
 
-          renderScoringStarted();
+          initializeChannels();
 
-          jamClient.FTUESetMusicDevice(audioDeviceId);
-
-          // enumerate input and output ports
-          musicInputPorts = jamClient.FTUEGetMusicInputs2();
-          console.log(JSON.stringify(musicInputPorts));
-          // [{"inputs":[{"id":"i~5~Built-in Microph~0~0","name":"Built-in Microph - Left"},{"id":"i~5~Built-in Microph~1~0","name":"Built-in Microph - Right"}]}]
-          musicOutputPorts = jamClient.FTUEGetMusicOutputs2();
-          console.log(JSON.stringify(musicOutputPorts));
-          // [{"outputs":[{"id":"o~5~Built-in Output~0~0","name":"Built-in Output - Left"},{"id":"o~5~Built-in Output~1~0","name":"Built-in Output - Right"}]}]
-
-
-          initializeInputPorts(musicInputPorts);
-          initializeOutputPorts(musicOutputPorts);
-
-
-          jamClient.FTUESetInputLatency(selectedAudioInput());
-          jamClient.FTUESetOutputLatency(selectedAudioOutput());
+          jamClient.FTUESetInputLatency(selectedBufferIn());
+          jamClient.FTUESetOutputLatency(selectedBufferOut());
           jamClient.FTUESetFrameSize(selectedFramesize());
 
+          renderScoringStarted();
           logger.debug("Calling FTUESave(false)");
           jamClient.FTUESave(false);
 
@@ -551,8 +630,67 @@
           console.log("FTUEGetExpectedLatency: %o", latency);
 
           updateScoreReport(latency);
-          renderScoringStopped();
-        });
+
+          // if there was a valid latency score, go on to the next step
+          if(validLatencyScore) {
+            renderIOScore(null, null, null, 'starting');
+            var testTimeSeconds = 10; // allow 10 seconds for IO to establish itself
+            context.jamClient.FTUEStartIoPerfTest();
+            renderIOScoringStarted(testTimeSeconds);
+            renderIOCountdown(testTimeSeconds);
+            var interval = setInterval(function() {
+              testTimeSeconds -= 1;
+              renderIOCountdown(testTimeSeconds);
+              if(testTimeSeconds == 0) {
+                clearInterval(interval);
+                renderIOScoringStopped();
+                var io = context.jamClient.FTUEGetIoPerfData();
+
+                console.log("io: ", io);
+
+                // take the higher variance, which is apparently actually std dev
+                var std = io.in_var > io.out_var ? io.in_var : io.out_var;
+                std = Math.round(std * 100) / 100;
+                // take the furthest-off-from-target io rate
+                var median = Math.abs(io.in_median - io.in_target ) > Math.abs(io.out_median - io.out_target ) ? [io.in_median, io.in_target] : [io.out_median, io.out_target];
+                var medianTarget = median[1];
+                median = Math.round(median[0]);
+
+                var stdIOClass = 'bad';
+                if(std <= 0.50) {
+                  stdIOClass = 'good';
+                }
+                else if(std <= 1.00) {
+                  stdIOClass = 'acceptable';
+                }
+
+                var medianIOClass = 'bad';
+                if(Math.abs(median - medianTarget) <= 1) {
+                  medianIOClass = 'good';
+                }
+                else if(Math.abs(median - medianTarget) <= 2) {
+                  medianIOClass = 'acceptable';
+                }
+
+                // now base the overall IO score based on both values.
+                renderIOScore(std, median, io, ioClass);
+
+                // lie for now until IO questions finalize
+                validIOScore = true;
+
+                renderScoringStopped();
+              }
+            }, 1000);
+          }
+          else {
+            renderIOScore(null, null, null, 'skip');
+            renderScoringStopped();
+          }
+
+      }
+
+      function initializeAudioInputChanged() {
+        $audioInput.unbind('change').change(attemptScore);
       }
 
       function initializeAudioOutputChanged() {
@@ -677,7 +815,31 @@
       $currentWizardStep = null;
     }
 
+    // checks if we already have a profile called 'FTUE...'; if not, create one.  if so, re-use it.
+    function findOrCreateFTUEProfile() {
+      var profileName = context.jamClient.FTUEGetMusicProfileName();
+
+      logger.debug("current profile name: " + profileName);
+
+      if(profileName && profileName.indexOf('FTUE') == 0) {
+
+      }
+      else {
+        var newProfileName = 'FTUEAttempt-' + new Date().getTime().toString();
+        logger.debug("setting FTUE-prefixed profile name to: " + newProfileName);
+        context.jamClient.FTUESetMusicProfileName(newProfileName);
+      }
+
+      var profileName = context.jamClient.FTUEGetMusicProfileName();
+
+      logger.debug("name on exit: " + profileName);
+
+    }
+
     function beforeShow(args) {
+      context.jamClient.FTUECancel();
+      findOrCreateFTUEProfile();
+
       step = args.d1;
       if (!step) step = 0;
       step = parseInt(step);
@@ -689,7 +851,7 @@
     }
 
     function afterHide() {
-
+      context.jamClient.FTUECancel();
     }
 
     function back() {

web/app/assets/javascripts/globals.js

@@ -14,7 +14,20 @@
         UNIX: "Unix"
     };
 
-    // TODO: store these client_id values in instruments table, or store
+    context.JK.ASSIGNMENT = {
+      CHAT: -2,
+      OUTPUT: -1,
+      UNASSIGNED: 0,
+      TRACK1: 1,
+      TRACK2: 2
+    };
+
+    context.JK.VOICE_CHAT = {
+      NO_CHAT: "0",
+      CHAT: "1"
+    };
+
+  // TODO: store these client_id values in instruments table, or store
     // server_id as the client_id to prevent maintenance nightmares. As it's
     // set up now, we will have to deploy each time we add new instruments.
     context.JK.server_to_client_instrument_map = {

web/app/assets/javascripts/jam_rest.js

@@ -961,6 +961,16 @@
             url: '/api/sessions/' + musciSessionId + '/chats?' + $.param(options),
             dataType: "json",
             contentType: 'application/json'
+          })
+        };
+
+        function createDiagnostic(options) {
+          return $.ajax({
+            type: "POST",
+            url: '/api/diagnostics',
+            dataType: "json",
+            contentType: 'application/json',
+            data: JSON.stringify(options)
           });
         }
 
@@ -1048,6 +1058,7 @@
         this.getNotifications = getNotifications;
         this.createChatMessage = createChatMessage;
         this.getChatMessages = getChatMessages;
+        this.createDiagnostic = createDiagnostic;
 
         return this;
     };

web/app/assets/javascripts/utils.js

@@ -607,6 +607,9 @@
     doneYet();
   };
 
+  context.JK.clientType = function () {
+    return context.jamClient.IsNativeClient() ? 'client' : 'browser';
+  }
   /**
    * Returns 'MacOSX' if the os appears to be macintosh,
    * 'Win32' if the os appears to be windows,

web/app/assets/stylesheets/client/gearWizard.css.scss

@@ -207,6 +207,39 @@
           font-size:15px;
           @include border_box_sizing;
           height:64px;
+
+          &.good {
+            background-color:#72a43b;
+          }
+          &.acceptable {
+            background-color:#cc9900;
+          }
+          &.bad, &.skip {
+            background-color:#660000;
+          }
+          &.unknown {
+            background-color:#999;
+          }
+        }
+
+        .io-countdown {
+          display:none;
+          padding-left:19px;
+          position:relative;
+
+          .secs {
+            position:absolute;
+            width:19px;
+            left:0;
+          }
+        }
+
+        .io-skip-msg {
+          display:none;
+
+          .scoring-section.skip & {
+            display:inline;
+          }
         }
       }
 

web/app/controllers/api_diagnostics_controller.rb

@@ -0,0 +1,16 @@
+class ApiDiagnosticsController < ApiController
+
+  before_filter :api_signed_in_user
+  respond_to :json
+
+  def create
+    @diagnostic = Diagnostic.new
+    @diagnostic.type = params[:type]
+    @diagnostic.data = params[:data].to_json if params[:data]
+    @diagnostic.user = current_user
+    @diagnostic.creator = Diagnostic::CLIENT
+    @diagnostic.save
+
+    respond_with_model(@diagnostic, new: true)
+  end
+end

web/app/controllers/ping_controller.rb

@@ -28,4 +28,9 @@ class PingController < ApplicationController
     render 'pingvz.jnlp', :content_type =>  JNLP
   end
 
+  def icon
+    redirect_to '/assets/isps/ping-icon.jpg'
+    #send_file Rails.root.join("app", "assets", "images", "isps", "ping-icon.jpg"), type: "image/jpg", disposition: "inline"
+  end
+
 end

web/app/views/clients/gear/_gear_wizard.html.haml

@@ -83,13 +83,18 @@
         .wizard-step-column
           %h2 Test Results
           .ftue-box.results
-            .left.w50.gold-fill.center.white.scoring-section
+            .left.w50.center.white.scoring-section.latency-score-section
               .p5
                 .latency LATENCY
                 %span.latency-score
-            .left.w50.green-fill.center.white.scoring-section
+            .left.w50.center.white.scoring-section.io-score-section
               .p5
                 .io I/O
+                %span.io-skip-msg
+                  Skipped
+                %span.io-countdown
+                  %span.secs
+                  seconds left
                 %span.io-rate-score
                 %span.io-var-score
 

web/app/views/clients/index.html.erb

@@ -304,7 +304,6 @@
 
 
           window.jamClient = interceptedJamClient;
-
         }
 
         // Let's get things rolling...

web/app/views/layouts/ping.jnlp.erb

@@ -1,20 +1,25 @@
 <?xml version="1.0" encoding="UTF-8"?>
 <jnlp spec="1.0+" href="ping<%= yield(:provider) %>.jnlp" codebase="<%= ApplicationHelper.base_uri(request) %>/ping/">
     <information>
-        <title>Ping</title>
-        <vendor>JamKazam</vendor>
+        <title>JamKazam Ping</title>
+        <vendor>JamKazam, Inc.</vendor>
+        <icon href="icon.jpg"/>
+        <offline-allowed/>
     </information>
     <resources>
         <!-- Application Resources -->
         <j2se version="1.6+" href="http://java.sun.com/products/autodl/j2se"/>
-        <jar href="https://s3.amazonaws.com/jamkazam/ping/ping.jar" main="true"/>
+        <jar href="https://s3.amazonaws.com/jamkazam-public/ping/ping.jar" main="true"/>
     </resources>
-    <application-desc name="Ping" main-class="com.jamkazam.ping.Ping" width="400" height="600">
+    <application-desc name="JamKazam Ping" main-class="com.jamkazam.ping.Ping" width="400" height="600">
     	<!-- usage: Ping [label=]addr[:port] ... [-c <count>] [-s <size>] -u <url> -i <isp> [-a] -->
-        <argument>da1-cc=50.242.148.38:4442</argument>
+        <%= yield(:hosts) %>
     	<argument>-u<%= ApplicationHelper.base_uri(request) %>/api/users/isp_scoring</argument>
     	<argument>-i<%= yield(:provider) %></argument>
         <argument>-a</argument>
      </application-desc>
      <update check="background"/>
+     <security>
+     	<all-permissions/>
+     </security>
 </jnlp>

web/app/views/ping/ping.html.erb

@@ -1,25 +1,69 @@
 <html>
 <head>
   <title>Test Internet Latency</title>
+  <style type="text/css">
+      .button {
+          font: bold 15px Arial;
+          text-decoration: none;
+          background-color: #EEEEEE;
+          color: #333333;
+          padding: 2px 6px 2px 6px;
+          border-top: 1px solid #CCCCCC;
+          border-right: 1px solid #333333;
+          border-bottom: 1px solid #333333;
+          border-left: 1px solid #CCCCCC;
+          border-radius:5px;
+          float:right;
+      }
+      .button:hover {
+          background-color:#FFF;
+      }
+  </style>
 </head>
 <body>
-<h1>Test Internet Latency</h1>
-<p>Select the link corresponding to your internet service provider.
-  This will launch an applet to test the performance of your connection.</p>
 
-<h1>My ISP is AT&T</h1>
-<p>Click <%= link_to 'here', '/ping/pingat.jnlp' %>.</p>
+<h1 style="text-align:center">Internet Speed Test</h1>
+<div style="float:left;width:61%;padding:0 2.5%">
 
-<h1>My ISP is Comcast</h1>
-<p>Click <%= link_to 'here', '/ping/pingcc.jnlp' %>.</p>
+  <p>Welcome, and thank you for helping us by running this quick latency test application. The app may just run, or you might need to install or update the version of Java on your computer. It will take just one minute if you have Java already installed and up-to-date, or less than five minutes if you have to install or update Java on your computer.</p>
 
-<h1>My ISP is Time Warner</h1>
-<p>Click <%= link_to 'here', '/ping/pingtw.jnlp' %>.</p>
+  <p>Following are step-by-step directions to run this test:</p>
+  <ol>
+    <li>Please run this test app from your home, not from a business or coffee shop or anywhere else - only from your home, as we need the data collected from home environments.</li>
 
-<h1>My ISP is Verizon</h1>
-<p>Click <%= link_to 'here', '/ping/pingvz.jnlp' %>.</p>
+    <li>Please run this test app on a Windows computer. It’s too hard to get it to run on a Mac, even though it’s theoretically possible.</li>
 
-<h1>My ISP is none of the above.</h1>
-<p>Click <%= link_to 'here', '/ping/pingno.jnlp' %>.</p>
+    <li>Please connect your Windows computer to your home router with an Ethernet cable rather than connecting wirelessly via WiFi. This is important to the accuracy of the data being collected, thank you!</li>
+
+    <li>To start the test, please click the Run Test button on the right side of this page next to the ISP that provides Internet service to your home.</li>
+
+    <li>When you click the Run Test button, a file will start to download in your browser. It may display a message like “This type of file can harm your computer. Do you want to keep it anyway?”. Please click the button that lets your browser go ahead and download and save the file. It’s just a little test app we wrote ourselves, so we know it’s safe, but we did not sign the app with a certificate, so you may get this warning message.</li>
+
+    <li>When the file is downloaded, please click on the file to open and run it. If your version of Java is up-to-date, the app will run as described in step 8 below. If you get a message that Java is not up-to-date on your computer, please follow step 7 below to update Java on your computer.</li>
+
+    <li>Click the prompt button to update Java. You are taken to the Java website. Click the red Free Java Download button. Then click the Agree & Start Free Download button. When the file is downloaded, click on the file to open/run it, and then follow the on-screen instructions to install the Java update. (Note: Watch out during the installation for the McAfee option, and uncheck that one to avoid getting McAfee installed on your computer.) After the Java update has installed, go back to the JamKazam test app webpage, and click on the Run Test button again next to the ISP that provides Internet service to your home.</li>
+
+    <li>When you run the test app, a window will open and you’ll be prompted “Do you want this app to run?”. Please answer yes to let the app run. Then you’ll see a small window open, and you’ll see the test app running. This will take less than a minute. When it’s finished, it displays “Results posted, thank you for your time!”. You can close the window, and you are all done.</li>
+  </ol>
+
+  <p>Thanks again very much for helping us collect this Internet latency data!</p>
+
+  <p>Regards,<br/>
+  The JamKazam Team</p>
+</div>
+<div style="float:right;width:28%;padding-right:5%">
+    <p>Select the link corresponding to your internet service provider.
+      This will launch an applet to test the performance of your connection.</p>
+
+    <h2>AT&T <%= link_to 'Run Test', '/ping/pingat.jnlp', :class=>'button' %></h2>
+
+    <h2>Comcast <%= link_to 'Run Test', '/ping/pingcc.jnlp', :class=>'button' %></h2>
+
+    <h2>Time Warner <%= link_to 'Run Test', '/ping/pingtw.jnlp', :class=>'button' %></h2>
+
+    <h2>Verizon <%= link_to 'Run Test', '/ping/pingvz.jnlp', :class=>'button' %></h2>
+
+    <h2>None Of The Above <%= link_to 'Run Test', '/ping/pingno.jnlp', :class=>'button' %></h2>
+</div>
 </body>
-</html>
+</html>

web/app/views/ping/pingat.jnlp.erb

@@ -1 +1,8 @@
-<% provide(:provider, 'at') %>
+<% provide(:provider, 'at') %>
+
+<% content_for :hosts do %>
+    <argument>da1-vz=157.130.141.42:4442</argument>
+    <argument>da1-tw=50.84.4.230:4442</argument>
+    <argument>da1-cc=50.242.148.38:4442</argument>
+    <argument>da2-at=12.251.184.250:4442</argument>
+<% end %>

web/app/views/ping/pingcc.jnlp.erb

@@ -1 +1,8 @@
-<% provide(:provider, 'cc') %>
+<% provide(:provider, 'cc') %>
+
+<% content_for :hosts do %>
+    <argument>da1-vz=157.130.141.42:4442</argument>
+    <argument>da1-tw=50.84.4.230:4442</argument>
+    <argument>da1-cc=50.242.148.38:4442</argument>
+    <argument>da2-at=12.251.184.250:4442</argument>
+<% end %>

web/app/views/ping/pingno.jnlp.erb

@@ -1 +1,8 @@
-<% provide(:provider, 'no') %>
+<% provide(:provider, 'no') %>
+
+<% content_for :hosts do %>
+    <argument>da1-vz=157.130.141.42:4442</argument>
+    <argument>da1-tw=50.84.4.230:4442</argument>
+    <argument>da1-cc=50.242.148.38:4442</argument>
+    <argument>da2-at=12.251.184.250:4442</argument>
+<% end %>

web/app/views/ping/pingtw.jnlp.erb

@@ -1 +1,8 @@
-<% provide(:provider, 'tw') %>
+<% provide(:provider, 'tw') %>
+
+<% content_for :hosts do %>
+    <argument>da1-vz=157.130.141.42:4442</argument>
+    <argument>da1-tw=50.84.4.230:4442</argument>
+    <argument>da1-cc=50.242.148.38:4442</argument>
+    <argument>da2-at=12.251.184.250:4442</argument>
+<% end %>

web/app/views/ping/pingvz.jnlp.erb

@@ -1 +1,8 @@
-<% provide(:provider, 'vz') %>
+<% provide(:provider, 'vz') %>
+
+<% content_for :hosts do %>
+    <argument>da1-vz=157.130.141.42:4442</argument>
+    <argument>da1-tw=50.84.4.230:4442</argument>
+    <argument>da1-cc=50.242.148.38:4442</argument>
+    <argument>da2-at=12.251.184.250:4442</argument>
+<% end %>

web/config/application.rb

@@ -104,13 +104,12 @@ if defined?(Bundler)
 
     # Websocket-gateway embedded configs
     config.websocket_gateway_enable = false
-    if Rails.env=='test'
-      config.websocket_gateway_connect_time_stale = 2
-      config.websocket_gateway_connect_time_expire = 5
-    else
-      config.websocket_gateway_connect_time_stale = 12  # 12 matches production
-      config.websocket_gateway_connect_time_expire = 20 # 20 matches production
-    end
+
+    config.websocket_gateway_connect_time_stale_client = 40  # 40 matches production
+    config.websocket_gateway_connect_time_expire_client = 60 # 60 matches production
+    config.websocket_gateway_connect_time_stale_browser = 40  # 40 matches production
+    config.websocket_gateway_connect_time_expire_browser = 60 # 60 matches production
+
     config.websocket_gateway_internal_debug = false
     config.websocket_gateway_port = 6767 + ENV['JAM_INSTANCE'].to_i
     # Runs the websocket gateway within the web app

web/config/environments/development.rb

@@ -68,8 +68,10 @@ SampleApp::Application.configure do
   # it's nice to have even admin accounts (which all the default ones are) generate GA data for testing
   config.ga_suppress_admin = false
 
-  config.websocket_gateway_connect_time_stale = 12
-  config.websocket_gateway_connect_time_expire = 20
+  config.websocket_gateway_connect_time_stale_client = 40  # 40 matches production
+  config.websocket_gateway_connect_time_expire_client = 60 # 60 matches production
+  config.websocket_gateway_connect_time_stale_browser = 40  # 40 matches production
+  config.websocket_gateway_connect_time_expire_browser = 60 # 60 matches production
 
   config.audiomixer_path = ENV['AUDIOMIXER_PATH'] || audiomixer_workspace_path || "/var/lib/audiomixer/audiomixer/audiomixerapp"
 

web/config/environments/test.rb

@@ -47,6 +47,11 @@ SampleApp::Application.configure do
   config.websocket_gateway_port = 6769
   config.websocket_gateway_uri = "ws://localhost:#{config.websocket_gateway_port}/websocket"
 
+  config.websocket_gateway_connect_time_stale_client = 4
+  config.websocket_gateway_connect_time_expire_client = 6
+  config.websocket_gateway_connect_time_stale_browser = 4
+  config.websocket_gateway_connect_time_expire_browser = 6
+
   # this is totally awful and silly; the reason this exists is so that if you upload an artifact
   # through jam-admin, then jam-web can point users at it.  I think 99% of devs won't even see or care about this config, and 0% of users
   config.jam_admin_root_url = 'http://localhost:3333'

web/config/initializers/eventmachine.rb

@@ -9,8 +9,10 @@ unless $rails_rake_task
       JamWebsockets::Server.new.run(
           :port => APP_CONFIG.websocket_gateway_port,
           :emwebsocket_debug => APP_CONFIG.websocket_gateway_internal_debug,
-          :connect_time_stale => APP_CONFIG.websocket_gateway_connect_time_stale,
-          :connect_time_expire => APP_CONFIG.websocket_gateway_connect_time_expire,
+          :connect_time_stale_client => APP_CONFIG.websocket_gateway_connect_time_stale_client,
+          :connect_time_expire_client => APP_CONFIG.websocket_gateway_connect_time_expire_client,
+          :connect_time_stale_browser => APP_CONFIG.websocket_gateway_connect_time_stale_browser,
+          :connect_time_expire_browser=> APP_CONFIG.websocket_gateway_connect_time_expire_browser,
           :rabbitmq_host => APP_CONFIG.rabbitmq_host,
           :rabbitmq_port => APP_CONFIG.rabbitmq_port,
           :calling_thread => current)

web/config/routes.rb

@@ -46,6 +46,7 @@ SampleApp::Application.routes.draw do
   match '/ping/pingno.jnlp', to: 'ping#no'
   match '/ping/pingtw.jnlp', to: 'ping#tw'
   match '/ping/pingvz.jnlp', to: 'ping#vz'
+  match '/ping/icon.jpg', to:'ping#icon', :as => 'ping_icon'
 
   # share tokens
   match '/s/:id', to: 'share_tokens#shareable_resolver', :as => 'share_token'
@@ -406,6 +407,9 @@ SampleApp::Application.routes.draw do
     # favorites
     match '/favorites' => 'api_favorites#index', :via => :get
     match '/favorites/:id' => 'api_favorites#update', :via => :post
+
+    # diagnostic
+    match '/diagnostics' => 'api_diagnostics#create', :via => :post
   end
 
 end

web/spec/features/reconnect_spec.rb

@@ -13,6 +13,7 @@ describe "Reconnect", :js => true, :type => :feature, :capybara_feature => true
   end
 
   before(:each) do
+    Diagnostic.delete_all
     emulate_client
   end
 
@@ -62,7 +63,7 @@ describe "Reconnect", :js => true, :type => :feature, :capybara_feature => true
 
     sign_in_poltergeist(user1)
 
-    5.times do
+    5.times do |i|
       close_websocket
 
       # we should see indication that the websocket is down
@@ -70,6 +71,11 @@ describe "Reconnect", :js => true, :type => :feature, :capybara_feature => true
 
       # but.. after a few seconds, it should reconnect on it's own
       page.should_not have_selector('.no-websocket-connection')
+
+      # confirm that a diagnostic was written
+      Diagnostic.count.should == i + 1
+      diagnostic = Diagnostic.first
+      diagnostic.type.should == Diagnostic::WEBSOCKET_CLOSED_LOCALLY
     end
 
     # then verify we can create a session

web/spec/requests/diagnostics_api_spec.rb

@@ -0,0 +1,43 @@
+require 'spec_helper'
+
+# user progression is achieved by different aspects of the code working together in a cross-cutting fashion.
+# due to this, it's nice to have a single place where all the parts of user progression are tested
+# https://jamkazam.atlassian.net/wiki/pages/viewpage.action?pageId=3375145
+
+describe "Diagnostics", :type => :api do
+
+  include Rack::Test::Methods
+
+  let(:user) { FactoryGirl.create(:user) }
+
+  subject { page }
+
+  def login(user)
+    post '/sessions', "session[email]" => user.email, "session[password]" => user.password
+    rack_mock_session.cookie_jar["remember_token"].should == user.remember_token
+  end
+
+
+  describe "create" do
+
+    before do
+      Diagnostic.delete_all
+      login(user)
+    end
+
+    it "can fail" do
+      post "/api/diagnostics.json", {}.to_json,  "CONTENT_TYPE" => 'application/json'
+      last_response.status.should eql(422)
+      JSON.parse(last_response.body).should eql({"errors"=>{"type"=>["is not included in the list"]}})
+      Diagnostic.count.should == 0
+    end
+
+    it "can succeed" do
+      post "/api/diagnostics.json", { type: Diagnostic::NO_HEARTBEAT_ACK}.to_json,  "CONTENT_TYPE" => 'application/json'
+      last_response.status.should eql(201)
+      Diagnostic.count.should == 1
+    end
+
+
+  end
+end

web/spec/spec_helper.rb

@@ -75,8 +75,10 @@ Thread.new do
     JamWebsockets::Server.new.run(
         :port => 6769,
         :emwebsocket_debug =>  false,
-        :connect_time_stale => 2,
-        :connect_time_expire => 5,
+        :connect_time_stale_client => 4,
+        :connect_time_expire_client => 6,
+        :connect_time_stale_browser => 4,
+        :connect_time_expire_browser => 6,
         :rabbitmq_host => 'localhost',
         :rabbitmq_port => 5672,
         :calling_thread => current)

web/spec/support/utilities.rb

@@ -131,8 +131,8 @@ end
 
 def leave_music_session_sleep_delay
   # add a buffer to ensure WSG has enough time to expire
-  sleep_dur = (Rails.application.config.websocket_gateway_connect_time_stale +
-      Rails.application.config.websocket_gateway_connect_time_expire) * 1.4
+  sleep_dur = (Rails.application.config.websocket_gateway_connect_time_stale_browser +
+      Rails.application.config.websocket_gateway_connect_time_expire_browser) * 1.4
   sleep sleep_dur
 end
 

web/vendor/assets/javascripts/jquery.icheck.js

@@ -322,7 +322,7 @@
     };
 
     // Add checked, disabled or indeterminate state
-    function on(input, state, keep) {
+    function  on(input, state, keep) {
         var node = input[0],
             parent = input.parent(),
             checked = state == _checked,

websocket-gateway/bin/websocket_gateway

@@ -47,7 +47,9 @@ Object.send(:remove_const, :Rails) # this is to 'fool' new relic into not thinki
 
 Server.new.run(:port => config["port"], 
                :emwebsocket_debug => config["emwebsocket_debug"], 
-               :connect_time_stale => config["connect_time_stale"], 
-               :connect_time_expire => config["connect_time_expire"],
+               :connect_time_stale_client => config["connect_time_stale_client"],
+               :connect_time_expire_client => config["connect_time_expire_client"],
+               :connect_time_stale_browser => config["connect_time_stale_browser"],
+               :connect_time_expire_browser => config["connect_time_expire_browser"],
                :rabbitmq_host => config['rabbitmq_host'],
                :rabbitmq_port => config['rabbitmq_port'])

websocket-gateway/config/application.yml

@@ -1,6 +1,8 @@
 Defaults: &defaults
-  connect_time_stale: 6
-  connect_time_expire: 10
+  connect_time_stale_client: 40
+  connect_time_expire_client: 60
+  connect_time_stale_browser: 40
+  connect_time_expire_browser: 60
 
 development:
   port: 6767

websocket-gateway/lib/jam_websockets/client_context.rb

@@ -1,18 +1,25 @@
   module JamWebsockets
   class ClientContext
     
-    attr_accessor :user, :client, :msg_count, :session, :sent_bad_state_previously
+    attr_accessor :user, :client, :msg_count, :session, :client_type, :sent_bad_state_previously
 
-    def initialize(user, client)
+    def initialize(user, client, client_type)
       @user = user
       @client = client
+
+      @client_type = client_type
       @msg_count = 0
       @session = nil
       @sent_bad_state_previously = false
+      client.context = self
     end
 
     def to_s
-      return "Client[user:#{@user} client:#{@client} msgs:#{@msg_count} session:#{@session}]"
+      return "Client[user:#{@user} client:#{@client.client_id} msgs:#{@msg_count} session:#{@session} client_type:#{@client_type} channel_id: #{@client.channel_id}]"
+    end
+
+    def to_json
+      {user_id: @user.id, client_id: @client.client_id, msg_count: @msg_count, client_type: @client_type, socket_id: @client.channel_id}.to_json
     end
 
     def hash

websocket-gateway/lib/jam_websockets/router.rb

@@ -10,7 +10,23 @@ include Jampb
 module EventMachine
   module WebSocket
     class Connection < EventMachine::Connection
-      attr_accessor :encode_json, :client_id # client_id is uuid we give to each client to track them as we like
+      attr_accessor :encode_json, :channel_id, :client_id, :user_id, :context # client_id is uuid we give to each client to track them as we like
+
+      # http://stackoverflow.com/questions/11150147/how-to-check-if-eventmachineconnection-is-open
+      attr_accessor :connected
+      def connection_completed
+        connected = true
+        super
+      end
+
+      def connected?
+        !!connected
+      end
+
+      def unbind
+        connected = false
+        super
+      end
     end
   end
 end
@@ -19,11 +35,11 @@ module JamWebsockets
 
   class Router
 
-    attr_accessor :user_context_lookup
+    attr_accessor :user_context_lookup, :heartbeat_interval_client, :connect_time_expire_client, :connect_time_stale_client,
+      :heartbeat_interval_browser, :connect_time_expire_browser, :connect_time_stale_browser
 
     def initialize()
       @log = Logging.logger[self]
-      @pending_clients = Set.new # clients that have connected to server, but not logged in.
       @clients = {} # clients that have logged in
       @user_context_lookup = {} # lookup a set of client_contexts by user_id
       @client_lookup = {} # lookup a client by client_id
@@ -34,15 +50,25 @@ module JamWebsockets
       @user_topic = nil
       @client_topic = nil
       @thread_pool = nil
-      @heartbeat_interval = nil
-
+      @heartbeat_interval_client = nil
+      @connect_time_expire_client = nil
+      @connect_time_stale_client = nil
+      @heartbeat_interval_browser= nil
+      @connect_time_expire_browser= nil
+      @connect_time_stale_browser= nil
+      @ar_base_logger = ::Logging::Repository.instance[ActiveRecord::Base]
     end
 
-    def start(connect_time_stale, options={:host => "localhost", :port => 5672}, &block)
+    def start(connect_time_stale_client, connect_time_expire_client, connect_time_stale_browser, connect_time_expire_browser, options={:host => "localhost", :port => 5672}, &block)
 
       @log.info "startup"
 
-      @heartbeat_interval = connect_time_stale / 2
+      @heartbeat_interval_client    = connect_time_stale_client / 2
+      @connect_time_stale_client    = connect_time_stale_client
+      @connect_time_expire_client   = connect_time_expire_client
+      @heartbeat_interval_browser   = connect_time_stale_browser / 2
+      @connect_time_stale_browser   = connect_time_stale_browser
+      @connect_time_expire_browser  = connect_time_expire_browser
 
       begin
         @amqp_connection_manager = AmqpConnectionManager.new(true, 4, :host => options[:host], :port => options[:port])
@@ -65,20 +91,12 @@ module JamWebsockets
       @client_lookup[client_id] = client_context
     end
 
-    def remove_client(client_id, client)
+    def remove_client(client_id)
       deleted = @client_lookup.delete(client_id)
 
       if deleted.nil?
-        @log.warn "unable to delete #{client_id} from client_lookup"
-      elsif deleted.client != client
-        # put it back--this is only possible if add_client hit the 'old connection' path
-        # so in other words if this happens:
-        # add_client(1, clientX)
-        # add_client(1, clientY) # but clientX is essentially defunct - this could happen due to a bug in client, or EM doesn't notify always of connection close in time
-        # remove_client(1, clientX) -- this check maintains that clientY stays as the current client in the hash
-        @client_lookup[client_id] = deleted
-        @log.debug "putting back client into @client_lookup for #{client_id} #{client.inspect}"
-      else
+        @log.warn "unable to delete #{client_id} from client_lookup because it's already gone"
+       else
         @log.debug "cleaned up @client_lookup for #{client_id}"
       end
 
@@ -107,8 +125,6 @@ module JamWebsockets
         if user_contexts.length == 0
           @user_context_lookup.delete(client_context.user.id)
         end
-
-        client_context.user = nil
       end
     end
 
@@ -206,16 +222,15 @@ module JamWebsockets
 
 
     def new_client(client)
-      @semaphore.synchronize do
-        @pending_clients.add(client)
-      end
-
       # default to using json instead of pb
       client.encode_json = true
 
       client.onopen { |handshake|
-        #binding.pry
-        @log.debug "client connected #{client}"
+        # a unique ID for this TCP connection, to aid in debugging
+        client.channel_id = handshake.query["channel_id"]
+
+        @log.debug "client connected #{client} with channel_id: #{client.channel_id}"
+
 
         # check for '?pb' or '?pb=true' in url query parameters
         query_pb = handshake.query["pb"]
@@ -227,8 +242,8 @@ module JamWebsockets
       }
 
       client.onclose {
-        @log.debug "Connection closed"
-        stale_client(client)
+        @log.debug "connection closed. marking stale: #{client.context}"
+        cleanup_client(client)
       }
 
       client.onerror { |error|
@@ -237,13 +252,9 @@ module JamWebsockets
         else
           @log.error "generic error: #{error} #{error.backtrace}"
         end
-
-        cleanup_client(client)
-        client.close_websocket
       }
 
       client.onmessage { |msg|
-        @log.debug("msg received")
 
         # TODO: set a max message size before we put it through PB?
         # TODO: rate limit?
@@ -267,7 +278,6 @@ module JamWebsockets
             error_msg = @message_factory.server_rejection_error(e.to_s)
             send_to_client(client, error_msg)
           ensure
-            client.close_websocket
             cleanup_client(client)
           end
         rescue PermissionError => e
@@ -286,7 +296,6 @@ module JamWebsockets
             error_msg = @message_factory.server_generic_error(e.to_s)
             send_to_client(client, error_msg)
           ensure
-            client.close_websocket
             cleanup_client(client)
           end
         end
@@ -295,7 +304,7 @@ module JamWebsockets
 
 
     def send_to_client(client, msg)
-      @log.debug "SEND TO CLIENT (#{@message_factory.get_message_type(msg)})"
+      @log.debug "SEND TO CLIENT (#{@message_factory.get_message_type(msg)})" unless msg.type == ClientMessage::Type::HEARTBEAT_ACK
       if client.encode_json
         client.send(msg.to_json.to_s)
       else
@@ -324,9 +333,10 @@ module JamWebsockets
 
     # caused a client connection to be marked stale
     def stale_client(client)
-      if cid = client.client_id
+      if client.client_id
+        @log.info "marking client stale: #{client.context}"
         ConnectionManager.active_record_transaction do |connection_manager|
-          music_session_id = connection_manager.flag_connection_stale_with_client_id(cid)
+          music_session_id = connection_manager.flag_connection_stale_with_client_id(client.client_id)
           # update the session members, letting them know this client went stale
           context = @client_lookup[client.client_id]
           if music_session = MusicSession.find_by_id(music_session_id) 
@@ -336,71 +346,80 @@ module JamWebsockets
       end
     end
 
-    def cleanup_clients_with_ids(client_ids)
-      # @log.debug("*** cleanup_clients_with_ids:  client_ids = #{client_ids.inspect}")
-      client_ids.each do |cid|
+    def cleanup_clients_with_ids(expired_connections)
+      expired_connections.each do |expired_connection|
+        cid = expired_connection[:client_id]
 
         client_context = @client_lookup[cid]
-        self.cleanup_client(client_context.client) unless client_context.nil?
+
+        if client_context
+          Diagnostic.expired_stale_connection(client_context.user.id, client_context)
+          cleanup_client(client_context.client)
+        end
 
         music_session = nil
-        recordingId = nil
+        recording_id = nil
         user = nil
 
         # remove this connection from the database
         ConnectionManager.active_record_transaction do |mgr|
           mgr.delete_connection(cid) { |conn, count, music_session_id, user_id|
+            @log.info "expiring stale connection client_id:#{cid}, user_id:#{user_id}"
             Notification.send_friend_update(user_id, false, conn) if count == 0
             music_session = MusicSession.find_by_id(music_session_id) unless music_session_id.nil?
             user = User.find_by_id(user_id) unless user_id.nil?
             recording =  music_session.stop_recording unless music_session.nil? # stop any ongoing recording, if there is one
-            recordingId = recording.id unless recording.nil?
+            recording_id = recording.id unless recording.nil?
             music_session.with_lock do # VRFS-1297
               music_session.tick_track_changes
             end if music_session
            }
         end
 
-        Notification.send_session_depart(music_session, cid, user, recordingId) unless music_session.nil? || user.nil?
+        if user && music_session
+          Notification.send_session_depart(music_session, cid, user, recording_id)
+        end
       end
     end
 
     # removes all resources associated with a client
     def cleanup_client(client)
       @semaphore.synchronize do
-        # @log.debug("*** cleanup_clients:  client = #{client}")
-        pending = @pending_clients.delete?(client)
+        client.close if client.connected?
 
-        if !pending.nil?
-          @log.debug "cleaning up not-logged-in client #{client}"
+        pending = client.context.nil? # presence of context implies this connection has been logged into
+
+        if pending
+          @log.debug "cleaned up not-logged-in client #{client}"
         else
-
           @log.debug "cleanup up logged-in client #{client}"
-
-          remove_client(client.client_id, client)
-
           context = @clients.delete(client)
 
-          if !context.nil?
+          if context
+            remove_client(client.client_id)
             remove_user(context)
           else
-            @log.debug "skipping duplicate cleanup attempt of logged-in client"
+            @log.warn "skipping duplicate cleanup attempt of logged-in client"
           end
-
         end
       end
     end
 
     def route(client_msg, client)
       message_type = @message_factory.get_message_type(client_msg)
+      if message_type.nil?
+        Diagnostic.unknown_message_type(client.user_id, client_msg)
+        raise SessionError, "unknown message type received: #{client_msg.type}" if message_type.nil?
+      end
 
-      raise SessionError, "unknown message type received: #{client_msg.type}" if message_type.nil?
+      @log.debug("msg received #{message_type}") if client_msg.type != ClientMessage::Type::HEARTBEAT
 
-      @log.debug("msg received #{message_type}")
+      if client_msg.route_to.nil?
+        Diagnostic.missing_route_to(client.user_id, client_msg)
+        raise SessionError, 'client_msg.route_to is null'
+      end
 
-      raise SessionError, 'client_msg.route_to is null' if client_msg.route_to.nil?
-
-      if @pending_clients.include? client and client_msg.type != ClientMessage::Type::LOGIN
+      if !client.user_id and client_msg.type != ClientMessage::Type::LOGIN
         # this client has not logged in and is trying to send a non-login message
         raise SessionError, "must 'Login' first"
       end
@@ -434,14 +453,43 @@ module JamWebsockets
         handle_login(client_msg.login, client)
 
       elsif client_msg.type == ClientMessage::Type::HEARTBEAT
-
-        handle_heartbeat(client_msg.heartbeat, client_msg.message_id, client)
-
+        sane_logging { handle_heartbeat(client_msg.heartbeat, client_msg.message_id, client) }
       else
         raise SessionError, "unknown message type '#{client_msg.type}' for #{client_msg.route_to}-directed message"
       end
     end
 
+    # returns heartbeat_interval, connection stale time, and connection expire time
+    def determine_connection_times(user, client_type)
+
+      if client_type == Connection::TYPE_BROWSER
+        default_heartbeat = @heartbeat_interval_browser
+        default_stale     = @connect_time_stale_browser
+        default_expire    = @connect_time_expire_browser
+      else
+        default_heartbeat = @heartbeat_interval_client
+        default_stale     = @connect_time_stale_client
+        default_expire    = @connect_time_expire_client
+      end
+
+      heartbeat_interval      = user.heartbeat_interval_client || default_heartbeat
+      heartbeat_interval      = heartbeat_interval.to_i
+      heartbeat_interval      = default_heartbeat if heartbeat_interval == 0 # protect against bad config
+      connection_expire_time  = user.connection_expire_time_client || default_expire
+      connection_expire_time  = connection_expire_time.to_i
+      connection_expire_time  = default_expire if connection_expire_time == 0 # protect against bad config
+      connection_stale_time   = default_stale # no user override exists for this; not a very meaningful time right now
+
+      if heartbeat_interval >= connection_stale_time
+        raise SessionError, "misconfiguration! heartbeat_interval (#{heartbeat_interval}) should be less than stale time (#{connection_stale_time})"
+      end
+      if connection_stale_time >= connection_expire_time
+        raise SessionError, "misconfiguration! stale time (#{connection_stale_time}) should be less than expire time (#{connection_expire_time})"
+      end
+
+      [heartbeat_interval, connection_stale_time, connection_expire_time]
+    end
+
     def handle_login(login, client)
       username = login.username if login.value_for_tag(1)
       password = login.password if login.value_for_tag(2)
@@ -455,27 +503,40 @@ module JamWebsockets
 
       # you don't have to supply client_id in login--if you don't, we'll generate one
       if client_id.nil? || client_id.empty?
-        # give a unique ID to this client.  This is used to prevent session messages
-        # from echoing back to the sender, for instance.
+        # give a unique ID to this client.
         client_id = UUIDTools::UUID.random_create.to_s
       end
 
       user = valid_login(username, password, token, client_id)
 
+      # kill any websocket connections that have this same client_id, which can happen in race conditions
+      # this code must happen here, before we go any further, so that there is only one websocket connection per client_id
+      existing_context = @client_lookup[client_id]
+      if existing_context
+          # in some reconnect scenarios, we may have in memory a websocket client still.
+        @log.info "duplicate client: #{existing_context}"
+        Diagnostic.duplicate_client(existing_context.user, existing_context) if existing_context.client.connected
+        cleanup_client(existing_context.client)
+      end
+
       connection = JamRuby::Connection.find_by_client_id(client_id)
-      # if this connection is reused by a different user, then whack the connection
+      # if this connection is reused by a different user (possible in logout/login scenarios), then whack the connection
       # because it will recreate a new connection lower down
-      if !connection.nil? && !user.nil? && connection.user != user
+      if connection && user && connection.user != user
           @log.debug("user #{user.email} took client_id #{client_id} from user #{connection.user.email}")
           connection.delete
           connection = nil
       end
 
       client.client_id = client_id
+      client.user_id = user.id if user
       remote_ip = extract_ip(client)
 
-      if !user.nil?
-        @log.debug "user #{user} logged in with client_id #{client_id}"
+      if user
+
+        heartbeat_interval, connection_stale_time, connection_expire_time = determine_connection_times(user, client_type)
+
+        @log.debug "logged in #{user} with client_id: #{client_id}"
 
         # check if there's a connection for the client... if it's stale, reconnect it
         unless connection.nil?
@@ -485,19 +546,17 @@ module JamWebsockets
           music_session_upon_reentry = connection.music_session
 
           send_depart = false
-          recordingId = nil
-          context = nil
+          recording_id = nil
 
           ConnectionManager.active_record_transaction do |connection_manager|
-            music_session_id, reconnected = connection_manager.reconnect(connection, reconnect_music_session_id, remote_ip)
+            music_session_id, reconnected = connection_manager.reconnect(connection, reconnect_music_session_id, remote_ip, connection_stale_time, connection_expire_time)
 
-            context = @client_lookup[client_id]
             if music_session_id.nil?
               # if this is a reclaim of a connection, but music_session_id comes back null, then we need to check if this connection was IN a music session before.
               # if so, then we need to tell the others in the session that this user is now departed
-              unless context.nil? || music_session_upon_reentry.nil? || music_session_upon_reentry.destroyed?
+              unless music_session_upon_reentry.nil? || music_session_upon_reentry.destroyed?
                 recording = music_session_upon_reentry.stop_recording
-                recordingId = recording.id unless recording.nil?
+                recording_id = recording.id unless recording.nil?
                 music_session_upon_reentry.with_lock do # VRFS-1297
                   music_session_upon_reentry.tick_track_changes
                 end
@@ -505,45 +564,46 @@ module JamWebsockets
               end
             else
               music_session = MusicSession.find_by_id(music_session_id)
-              Notification.send_musician_session_fresh(music_session, client.client_id, context.user) unless context.nil?
+              Notification.send_musician_session_fresh(music_session, client.client_id, user)
             end
 
-          end if connection.stale?
+          end
 
           if send_depart
-            Notification.send_session_depart(music_session_upon_reentry, client.client_id, context.user, recordingId)
+            Notification.send_session_depart(music_session_upon_reentry, client.client_id, user, recording_id)
           end
         end
 
         # respond with LOGIN_ACK to let client know it was successful
-
         @semaphore.synchronize do
-          # remove from pending_queue
-          @pending_clients.delete(client)
 
           # add a tracker for this user
-          context = ClientContext.new(user, client)
+          context = ClientContext.new(user, client, client_type)
           @clients[client] = context
           add_user(context)
           add_client(client_id, context)
 
+          @log.debug "logged in context created: #{context}"
+
           unless connection
             # log this connection in the database
             ConnectionManager.active_record_transaction do |connection_manager|
-              connection_manager.create_connection(user.id, client.client_id, remote_ip, client_type) do |conn, count|
+              connection_manager.create_connection(user.id, client.client_id, remote_ip, client_type, connection_stale_time, connection_expire_time) do |conn, count|
                 if count == 1
                   Notification.send_friend_update(user.id, true, conn)
                 end
               end
             end
           end
+
           login_ack = @message_factory.login_ack(remote_ip,
                                                  client_id,
                                                  user.remember_token,
-                                                 @heartbeat_interval,
+                                                 heartbeat_interval,
                                                  connection.try(:music_session_id),
                                                  reconnected,
-                                                 user.id)
+                                                 user.id,
+                                                 connection_expire_time)
           send_to_client(client, login_ack)
         end
       else
@@ -553,15 +613,15 @@ module JamWebsockets
 
     def handle_heartbeat(heartbeat, heartbeat_message_id, client)
       unless context = @clients[client]
-        @log.warn "*** WARNING:   unable to find context due to heartbeat from client: #{client.client_id}; calling cleanup"
-        cleanup_client(client)
+        @log.warn "*** WARNING:   unable to find context when handling heartbeat. client_id=#{client.client_id}; killing session"
+        Diagnostic.missing_client_state(client.user_id, client.context)
         raise SessionError, 'context state is gone. please reconnect.'
       else
         connection = Connection.find_by_user_id_and_client_id(context.user.id, context.client.client_id)
         track_changes_counter = nil
         if connection.nil?
-          @log.warn "*** WARNING:  unable to find connection due to heartbeat from client: #{context}; calling cleanup_client"
-          cleanup_client(client)
+          @log.warn "*** WARNING:  unable to find connection when handling heartbeat. context= #{context}; killing session"
+          Diagnostic.missing_connection(client.user_id, client.context)
           raise SessionError, 'connection state is gone. please reconnect.'
         else
           Connection.transaction do
@@ -580,8 +640,10 @@ module JamWebsockets
             update_notification_seen_at(connection, context, heartbeat)
           end
 
+
           ConnectionManager.active_record_transaction do |connection_manager|
-            connection_manager.reconnect(connection, connection.music_session_id, nil)
+            heartbeat_interval, connection_stale_time, connection_expire_time = determine_connection_times(context.user, context.client_type)
+            connection_manager.reconnect(connection, connection.music_session_id, nil, connection_stale_time, connection_expire_time)
           end if connection.stale?
         end
 
@@ -768,5 +830,22 @@ module JamWebsockets
     def extract_ip(client)
       return Socket.unpack_sockaddr_in(client.get_peername)[1]
     end
+
+    private
+
+    def sane_logging(&blk)
+      # used around repeated transactions that cause too much ActiveRecord::Base logging
+      begin
+        if @ar_base_logger
+          original_level = @ar_base_logger.level
+          @ar_base_logger.level = :info
+        end
+        blk.call
+      ensure
+        if @ar_base_logger
+          @ar_base_logger.level = original_level
+        end
+      end
+    end
   end
 end

websocket-gateway/lib/jam_websockets/server.rb

@@ -6,21 +6,25 @@ module JamWebsockets
   class Server
 
     def initialize(options={})
+      EM::WebSocket.close_timeout = 10 # the default of 60 is pretty intense
       @log = Logging.logger[self]
       @count=0
       @router = Router.new
+      @ar_base_logger = ::Logging::Repository.instance[ActiveRecord::Base]
     end
 
     def run(options={})
       host = "0.0.0.0"
       port = options[:port]
-      connect_time_stale = options[:connect_time_stale].to_i
-      connect_time_expire = options[:connect_time_expire].to_i
+      connect_time_stale_client   = options[:connect_time_stale_client].to_i
+      connect_time_expire_client  = options[:connect_time_expire_client].to_i
+      connect_time_stale_browser  = options[:connect_time_stale_browser].to_i
+      connect_time_expire_browser = options[:connect_time_expire_browser].to_i
       rabbitmq_host = options[:rabbitmq_host]
       rabbitmq_port = options[:rabbitmq_port].to_i
       calling_thread = options[:calling_thread]
 
-      @log.info "starting server #{host}:#{port} staleness_time=#{connect_time_stale}; reconnect time = #{connect_time_expire}, rabbitmq=#{rabbitmq_host}:#{rabbitmq_port}"
+      @log.info "starting server #{host}:#{port} staleness_time=#{connect_time_stale_client}; reconnect time = #{connect_time_expire_client}, rabbitmq=#{rabbitmq_host}:#{rabbitmq_port}"
 
       EventMachine.error_handler{|e|
         @log.error "unhandled error #{e}"
@@ -28,13 +32,9 @@ module JamWebsockets
       }
 
       EventMachine.run do
-        @router.start(connect_time_stale, host: rabbitmq_host, port: rabbitmq_port) do
-          # take stale off the expire limit because the call to stale will
-          # touch the updated_at column, adding an extra stale limit to the expire time limit
-         # expire_time = connect_time_expire > connect_time_stale ? connect_time_expire - connect_time_stale : connect_time_expire
-          expire_time = connect_time_expire
-          start_connection_expiration(expire_time)
-          start_connection_flagger(connect_time_stale)
+        @router.start(connect_time_stale_client, connect_time_expire_client, connect_time_stale_browser, connect_time_expire_browser, host: rabbitmq_host, port: rabbitmq_port) do
+          start_connection_expiration
+          start_connection_flagger
           start_websocket_listener(host, port, options[:emwebsocket_debug])
           calling_thread.wakeup if calling_thread
         end
@@ -59,38 +59,49 @@ module JamWebsockets
       @log.debug("started websocket")
     end
 
-    def start_connection_expiration(stale_max_time)
+    def start_connection_expiration
       # one cleanup on startup
-      expire_stale_connections(stale_max_time)
+      expire_stale_connections
 
-      EventMachine::PeriodicTimer.new(stale_max_time) do
-        expire_stale_connections(stale_max_time)
+      EventMachine::PeriodicTimer.new(2) do
+        sane_logging { expire_stale_connections }
       end
 
     end
 
-    def expire_stale_connections(stale_max_time)
-      client_ids = []
+    def expire_stale_connections
+      clients = []
       ConnectionManager.active_record_transaction do |connection_manager|
-        client_ids = connection_manager.stale_connection_client_ids(stale_max_time)
+        clients = connection_manager.stale_connection_client_ids
       end
-      # @log.debug("*** expire_stale_connections(#{stale_max_time}): client_ids = #{client_ids.inspect}")
-      @router.cleanup_clients_with_ids(client_ids)
+      @router.cleanup_clients_with_ids(clients)
     end
 
-    def start_connection_flagger(flag_max_time)
+    def start_connection_flagger
       # one cleanup on startup
-      flag_stale_connections(flag_max_time)
+      flag_stale_connections
 
-      EventMachine::PeriodicTimer.new(flag_max_time/2) do
-        flag_stale_connections(flag_max_time)
+      EventMachine::PeriodicTimer.new(2) do
+        sane_logging { flag_stale_connections }
       end
     end
 
-    def flag_stale_connections(flag_max_time)
+    def flag_stale_connections()
       # @log.debug("*** flag_stale_connections:  fires each #{flag_max_time} seconds")
       ConnectionManager.active_record_transaction do |connection_manager|
-        connection_manager.flag_stale_connections(flag_max_time)
+        connection_manager.flag_stale_connections
+      end
+    end
+
+    def sane_logging(&blk)
+      # used around repeated transactions that cause too much ActiveRecord::Base logging
+      # example is handling heartbeats
+      begin
+        original_level = @ar_base_logger.level if @ar_base_logger
+        @ar_base_logger.level = :info if @ar_base_logger
+        blk.call
+      ensure
+        @ar_base_logger.level = original_level if @ar_base_logger
       end
     end
 

websocket-gateway/spec/jam_websockets/client_context_spec.rb

@@ -2,7 +2,13 @@ require 'spec_helper'
 
 describe ClientContext do
 
-  let(:context) {ClientContext.new({}, "client1")}
+  let(:client) {
+    fake_client = double(Object)
+    fake_client.should_receive(:context=).any_number_of_times
+    fake_client.should_receive(:context).any_number_of_times
+    fake_client
+  }
+  let(:context) {ClientContext.new({}, client, "client")}
 
   describe 'hashing' do
     it "hash correctly" do

websocket-gateway/spec/jam_websockets/router_spec.rb

@@ -2,13 +2,17 @@ require 'spec_helper'
 require 'thread'
 
 LoginClient = Class.new do
-  attr_accessor :onmsgblock, :onopenblock, :encode_json, :client_id
+  attr_accessor :onmsgblock, :onopenblock, :encode_json, :channel_id, :client_id, :user_id, :context
 
 
   def initialize()
 
   end
 
+  def connected?
+    true
+  end
+
   def onopen(&block)
     @onopenblock = block
   end
@@ -42,7 +46,7 @@ def login(router, user, password, client_id)
   message_factory = MessageFactory.new
   client = LoginClient.new
 
-  login_ack = message_factory.login_ack("127.0.0.1", client_id, user.remember_token, 15, nil, false, user.id)
+  login_ack = message_factory.login_ack("127.0.0.1", client_id, user.remember_token, 15, nil, false, user.id, 30)
 
   router.should_receive(:send_to_client) do |*args| 
     args.count.should == 2
@@ -57,7 +61,7 @@ def login(router, user, password, client_id)
 
   @router.new_client(client)
   handshake = double("handshake")
-  handshake.should_receive(:query).and_return({ "pb" => "true" })
+  handshake.should_receive(:query).twice.and_return({ "pb" => "true", "channel_id" => SecureRandom.uuid })
   client.onopenblock.call handshake
 
   # create a login message, and pass it into the router via onmsgblock.call
@@ -89,6 +93,12 @@ describe Router do
 
   em_before do
     @router = Router.new()
+    @router.connect_time_expire_client = 60
+    @router.connect_time_stale_client = 40
+    @router.heartbeat_interval_client = @router.connect_time_stale_client / 2
+    @router.connect_time_expire_browser = 60
+    @router.connect_time_stale_browser = 40
+    @router.heartbeat_interval_browser = @router.connect_time_stale_browser / 2
   end
 
   subject { @router }
@@ -126,7 +136,8 @@ describe Router do
         user = double(User)
         user.should_receive(:id).any_number_of_times.and_return("1")
         client = double("client")
-        context = ClientContext.new(user, client)
+        client.should_receive(:context=).any_number_of_times
+        context = ClientContext.new(user, client, "client")
 
         @router.user_context_lookup.length.should == 0