<commit_before>require 'rails_helper'
require 'capybara/rspec'

describe 'login timing', type: :feature do
  let!(:pals) { TestPals.create! }
  before(:each) { LoginTests.reset_rack_attack! }

  def sample_educator(seed)
    Educator.all.sample(random: Random.new(seed))
  end

  def attempt_variants(seed)
    [
      [sample_educator(seed).email, 'demo-password'],
      [sample_educator(seed).email, 'wrong-password'],
      [sample_educator(seed).email, ''],
      ['invalid-login', 'wrong-password'],
      ['invalid-login', '']
    ]
  end

  def create_multiple_attempts(n, seed)
    attempts = []
    n.times { attempts += attempt_variants(seed) }
    attempts.shuffle(random: Random.new(seed))
  end

  def reset_login_attempt!
    Rack::Attack.cache.store.clear
    sign_out if page.has_content?('Sign Out')
  end

  # simulate a really slow response from an LDAP #bind
  def mock_slow_ldap_bind!(username, password, delay_milliseconds)
    slow_mock_ldap = MockLDAP.new({
      auth: {
        username: username,
        password: password
      }
    })
    allow(slow_mock_ldap).to receive(:bind) do
      sleep(delay_milliseconds/1000.0)
      false
    end
    allow(MockLDAP).to receive(:new).and_return(slow_mock_ldap)
    nil
  end

  def puts_debug(login, password, elapsed_milliseconds)
    # puts '---------'
    # puts "login: #{login}"
    # puts "password: #{password}"
    # puts "elapsed_milliseconds: #{elapsed_milliseconds}"
    # puts
    # puts
  end

  it 'does not have consistent timing for empty login, since Devise short-circuits' do
    _, elapsed_milliseconds = ConsistentTiming.new.measure_timing_only do
      sign_in_attempt('', 'foo')
    end
    reset_login_attempt!
    expect(elapsed_milliseconds).to be < 1000
  end

  context 'when longer than expected' do
    before(:each) { LoginTests.before_set_login_timing!(500) }
    after(:each) { LoginTests.after_reset_loging_timing! }

    it 'tolerates and warns' do
      allow(Rollbar).to receive(:warn)
      expect(Rollbar).to receive(:warn).once.with('ConsistentTiming#wait_for_milliseconds_or_alert was negative', {
        milliseconds_to_wait: anything
      })

      login, password = [pals.uri.email, '<PASSWORD>']
      _, elapsed_milliseconds = ConsistentTiming.new.measure_timing_only do
        mock_slow_ldap_bind!(login, password, 1000)
        sign_in_attempt(login, password)
      end
      reset_login_attempt!

      puts_debug(login, password, elapsed_milliseconds)
      expect(elapsed_milliseconds).to be > 1000
    end
  end

  context 'across all execution paths' do
    let!(:expected_timing_in_milliseconds) { 500 }
    before(:each) { LoginTests.before_set_login_timing!(expected_timing_in_milliseconds) }
    after(:each) { LoginTests.after_reset_loging_timing! }

    it 'has consistent timing within range' do
      # allow untimed sign-in as a warm-up (eg, seed 6996)
      sign_in_attempt(pals.uri.email, '<PASSWORD>')
      reset_login_attempt!

      # test a sampling of attempts in random order; none should leak what's
      # happening on the server-side through response timing
      create_multiple_attempts(2, RSpec.configuration.seed).each do |attempt|
        login, password = attempt
        _, elapsed_milliseconds = ConsistentTiming.new.measure_timing_only do
          print('✓') # a nice progress indicator since these are slower tests
          sign_in_attempt(login, password)
        end
        reset_login_attempt! # not measured

        tolerance_ms = 100
        puts_debug(login, password, elapsed_milliseconds)
        expect(elapsed_milliseconds).to be_within(tolerance_ms).of(expected_timing_in_milliseconds), "unexpected timing for login='#{login}' and password='#{password}'  timing: #{elapsed_milliseconds}"
      end
    end
  end
end
<commit_msg>Trying to make a timing spec more explicit<commit_after>require 'rails_helper'
require 'capybara/rspec'

describe 'login timing', type: :feature do
  let!(:pals) { TestPals.create! }
  before(:each) { LoginTests.reset_rack_attack! }

  def sample_educator(seed)
    Educator.all.sample(random: Random.new(seed))
  end

  def attempt_variants(seed)
    [
      [sample_educator(seed).email, 'demo-password'],
      [sample_educator(seed).email, 'wrong-password'],
      [sample_educator(seed).email, ''],
      ['invalid-login', 'wrong-password'],
      ['invalid-login', '']
    ]
  end

  def create_multiple_attempts(n, seed)
    attempts = []
    n.times { attempts += attempt_variants(seed) }
    attempts.shuffle(random: Random.new(seed))
  end

  def reset_login_attempt!
    Rack::Attack.cache.store.clear
    sign_out if page.has_content?('Sign Out')
  end

  # simulate a really slow response from an LDAP #bind
  def mock_slow_ldap_bind!(username, password, delay_milliseconds)
    slow_mock_ldap = MockLDAP.new({
      auth: {
        username: username,
        password: password
      }
    })
    allow(slow_mock_ldap).to receive(:bind) do
      sleep(delay_milliseconds/1000.0)
      false
    end
    allow(MockLDAP).to receive(:new).and_return(slow_mock_ldap)
    nil
  end

  def puts_debug(login, password, elapsed_milliseconds)
    # puts '---------'
    # puts "login: #{login}"
    # puts "password: #{password}"
    # puts "elapsed_milliseconds: #{elapsed_milliseconds}"
    # puts
    # puts
  end

  context 'when login is empty' do
    before(:each) { LoginTests.before_set_login_timing!(10000) }
    after(:each) { LoginTests.after_reset_loging_timing! }

    it 'does not have consistent timing since Devise short-circuits' do
      _, elapsed_milliseconds = ConsistentTiming.new.measure_timing_only do
        sign_in_attempt('', 'foo')
      end
      expect(elapsed_milliseconds).to be < 1000
    end
  end

  context 'when longer than expected' do
    before(:each) { LoginTests.before_set_login_timing!(500) }
    after(:each) { LoginTests.after_reset_loging_timing! }

    it 'tolerates and warns' do
      allow(Rollbar).to receive(:warn)
      expect(Rollbar).to receive(:warn).once.with('ConsistentTiming#wait_for_milliseconds_or_alert was negative', {
        milliseconds_to_wait: anything
      })

      login, password = [pals.uri.email, '<PASSWORD>']
      _, elapsed_milliseconds = ConsistentTiming.new.measure_timing_only do
        mock_slow_ldap_bind!(login, password, 1000)
        sign_in_attempt(login, password)
      end
      reset_login_attempt!

      puts_debug(login, password, elapsed_milliseconds)
      expect(elapsed_milliseconds).to be > 1000
    end
  end

  context 'across all execution paths' do
    let!(:expected_timing_in_milliseconds) { 500 }
    before(:each) { LoginTests.before_set_login_timing!(expected_timing_in_milliseconds) }
    after(:each) { LoginTests.after_reset_loging_timing! }

    it 'has consistent timing within range' do
      # allow untimed sign-in as a warm-up (eg, seed 6996)
      sign_in_attempt(pals.uri.email, '<PASSWORD>')
      reset_login_attempt!

      # test a sampling of attempts in random order; none should leak what's
      # happening on the server-side through response timing
      create_multiple_attempts(2, RSpec.configuration.seed).each do |attempt|
        login, password = attempt
        _, elapsed_milliseconds = ConsistentTiming.new.measure_timing_only do
          print('✓') # a nice progress indicator since these are slower tests
          sign_in_attempt(login, password)
        end
        reset_login_attempt! # not measured

        tolerance_ms = 100
        puts_debug(login, password, elapsed_milliseconds)
        expect(elapsed_milliseconds).to be_within(tolerance_ms).of(expected_timing_in_milliseconds), "unexpected timing for login='#{login}' and password='#{password}'  timing: #{elapsed_milliseconds}"
      end
    end
  end
end

{'fraction_non_alphanumeric': 0.1041264944080216, 'fraction_numerical': 0.008612932253503021, 'mean_word_length': 3.518002322880372, 'pattern_counts': {'":': 0, '<': 9, '<?xml version=': 0, '>': 9, 'https://': 0, 'lorem ipsum': 0, 'www.': 0, 'xml': 0}, 'pii_count': 0, 'substrings_counts': 0, 'word_list_counts': {'cursed_substrings.json': 0, 'profanity_word_list.json': 0, 'sexual_word_list.json': 0, 'zh_pornsignals.json': 0}}
{'dir': 'git-commits-cleaned', 'id': '3610078', 'n_tokens_mistral': 2549, 'n_tokens_neox': 2404, 'n_words': 532}