apps/workbench/test/integration/websockets_test.rb

   1 require 'integration_helper'
   2
   3 class WebsocketTest < ActionDispatch::IntegrationTest
   4   setup do
   5     need_selenium "to make websockets work"
   6     @dispatch_client = ArvadosApiClient.new
   7   end
   8
   9   def dispatch_log(body)
  10     use_token :dispatch1 do
  11       @dispatch_client.api('logs', '', log: body)
  12     end
  13   end
  14
  15   test "test page" do
  16     visit(page_with_token("active", "/websockets"))
  17     fill_in("websocket-message-content", :with => "Stuff")
  18     click_button("Send")
  19     assert_text '"status":400'
  20   end
  21
  22   [
  23    ['pipeline_instances', 'pipeline_in_running_state', api_fixture('jobs')['running']],
  24    ['jobs', 'running'],
  25    ['containers', 'running'],
  26    ['container_requests', 'running', api_fixture('containers')['running']],
  27   ].each do |controller, view_fixture_name, log_target_fixture|
  28     view_fixture = api_fixture(controller)[view_fixture_name]
  29     log_target_fixture ||= view_fixture
  30
  31     test "test live logging and scrolling for #{controller}" do
  32
  33       visit(page_with_token("active", "/#{controller}/#{view_fixture['uuid']}\#Log"))
  34       assert_no_text '123 hello'
  35
  36       text = ""
  37       (1..1000).each do |i|
  38         text << "#{i} hello\n"
  39       end
  40
  41       dispatch_log(owner_uuid: log_target_fixture['owner_uuid'],
  42                    object_uuid: log_target_fixture['uuid'],
  43                    event_type: "stderr",
  44                    properties: {"text" => text})
  45       assert_text '1000 hello'
  46
  47       # First test that when we're already at the bottom of the page, it scrolls down
  48       # when a new line is added.
  49       old_top = page.evaluate_script("$('#event_log_div').scrollTop()")
  50
  51       dispatch_log(owner_uuid: log_target_fixture['owner_uuid'],
  52                    object_uuid: log_target_fixture['uuid'],
  53                    event_type: "dispatch",
  54                    properties: {"text" => "1001 hello\n"})
  55       assert_text '1001 hello'
  56
  57       # Check that new value of scrollTop is greater than the old one
  58       new_top = page.evaluate_script("$('#event_log_div').scrollTop()")
  59       assert_operator new_top, :>, old_top
  60
  61       # Now scroll to 30 pixels from the top
  62       page.execute_script "$('#event_log_div').scrollTop(30)"
  63       assert_equal 30, page.evaluate_script("$('#event_log_div').scrollTop()")
  64
  65       dispatch_log(owner_uuid: log_target_fixture['owner_uuid'],
  66                    object_uuid: log_target_fixture['uuid'],
  67                    event_type: "stdout",
  68                    properties: {"text" => "1002 hello\n"})
  69       assert_text '1002 hello'
  70
  71       # Check that we haven't changed scroll position
  72       assert_equal 30, page.evaluate_script("$('#event_log_div').scrollTop()")
  73     end
  74   end
  75
  76   test "pipeline instance arv-refresh-on-log-event" do
  77     # Do something and check that the pane reloads.
  78     p = use_token :active do
  79       PipelineInstance.create(state: "RunningOnServer",
  80                               components: {
  81                                 c1: {
  82                                   script: "test_hash.py",
  83                                   script_version: "1de84a854e2b440dc53bf42f8548afa4c17da332"
  84                                 }
  85                               })
  86     end
  87     visit(page_with_token("active", "/pipeline_instances/#{p.uuid}"))
  88
  89     assert_text 'Active'
  90     assert page.has_link? 'Pause'
  91     assert_no_text 'Complete'
  92     assert page.has_no_link? 'Re-run with latest'
  93
  94     use_token :dispatch1 do
  95       p.update_attributes!(state: 'Complete')
  96     end
  97
  98     assert_no_text 'Active'
  99     assert page.has_no_link? 'Pause'
 100     assert_text 'Complete'
 101     assert page.has_link? 'Re-run with latest'
 102   end
 103
 104   test "job arv-refresh-on-log-event" do
 105     # Do something and check that the pane reloads.
 106     uuid = api_fixture('jobs')['running_will_be_completed']['uuid']
 107     visit(page_with_token("active", "/jobs/#{uuid}"))
 108
 109     assert_no_text 'complete'
 110     assert_no_text 'Re-run job'
 111
 112     use_token :dispatch1 do
 113       Job.find(uuid).update_attributes!(state: 'Complete')
 114     end
 115
 116     assert_text 'complete'
 117     assert_text 'Re-run job'
 118   end
 119
 120   test "dashboard arv-refresh-on-log-event" do
 121     visit(page_with_token("active", "/"))
 122
 123     assert_no_text 'test dashboard arv-refresh-on-log-event'
 124
 125     # Do something and check that the pane reloads.
 126     use_token :active do
 127       p = PipelineInstance.create({state: "RunningOnServer",
 128                                     name: "test dashboard arv-refresh-on-log-event",
 129                                     components: {
 130                                     }
 131                                   })
 132     end
 133
 134     assert_text 'test dashboard arv-refresh-on-log-event'
 135   end
 136
 137   test 'job graph appears when first data point is already in logs table' do
 138     job_graph_first_datapoint_test
 139   end
 140
 141   test 'job graph appears when first data point arrives by websocket' do
 142     use_token :admin do
 143       Log.find(api_fixture('logs')['crunchstat_for_running_job']['uuid']).destroy
 144     end
 145     job_graph_first_datapoint_test expect_existing_datapoints: false
 146   end
 147
 148   def job_graph_first_datapoint_test expect_existing_datapoints: true
 149     uuid = api_fixture('jobs')['running']['uuid']
 150
 151     visit page_with_token "active", "/jobs/#{uuid}"
 152     click_link "Log"
 153
 154     assert_selector '#event_log_div', visible: true
 155
 156     if expect_existing_datapoints
 157       assert_selector '#log_graph_div', visible: true
 158       # Magic numbers 12.99 etc come from the job log fixture:
 159       assert_last_datapoint 'T1-cpu', (((12.99+0.99)/10.0002)/8)
 160     else
 161       # Until graphable data arrives, we should see the text log but not the graph.
 162       assert_no_selector '#log_graph_div', visible: true
 163     end
 164
 165     text = "2014-11-07_23:33:51 #{uuid} 31708 1 stderr crunchstat: cpu 1970.8200 user 60.2700 sys 8 cpus -- interval 10.0002 seconds 35.3900 user 0.8600 sys"
 166
 167     assert_triggers_dom_event 'arv-log-event' do
 168       dispatch_log(owner_uuid: api_fixture('jobs')['running']['owner_uuid'],
 169                    object_uuid: uuid,
 170                    event_type: "stderr",
 171                    properties: {"text" => text})
 172     end
 173
 174     # Graph should have appeared (even if it hadn't above). It's
 175     # important not to wait like matchers usually do: we are
 176     # confirming the graph is visible _immediately_ after the first
 177     # data point arrives.
 178     using_wait_time 0 do
 179       assert_selector '#log_graph_div', visible: true
 180     end
 181     assert_last_datapoint 'T1-cpu', (((35.39+0.86)/10.0002)/8)
 182   end
 183
 184   test "live log charting from replayed log" do
 185     uuid = api_fixture("jobs")['running']['uuid']
 186
 187     visit page_with_token "active", "/jobs/#{uuid}"
 188     click_link "Log"
 189
 190     assert_triggers_dom_event 'arv-log-event' do
 191       ApiServerForTests.new.run_rake_task("replay_job_log", "test/job_logs/crunchstatshort.log,1.0,#{uuid}")
 192     end
 193
 194     assert_last_datapoint 'T1-cpu', (((35.39+0.86)/10.0002)/8)
 195   end
 196
 197   def assert_last_datapoint series, value
 198     datum = page.evaluate_script("jobGraphData[jobGraphData.length-1]['#{series}']")
 199     assert_in_epsilon value, datum.to_f
 200   end
 201
 202   test "test running job with just a few previous log records" do
 203     job = api_fixture("jobs")['running']
 204
 205     # Create just one old log record
 206     dispatch_log(owner_uuid: job['owner_uuid'],
 207                  object_uuid: job['uuid'],
 208                  event_type: "stderr",
 209                  properties: {"text" => "Historic log message"})
 210
 211     visit page_with_token("active", "/jobs/#{job['uuid']}\#Log")
 212
 213     # Expect "all" historic log records because we have less than
 214     # default Rails.configuration.running_job_log_records_to_fetch count
 215     assert_text 'Historic log message'
 216
 217     # Create new log record and expect it to show up in log tab
 218     dispatch_log(owner_uuid: job['owner_uuid'],
 219                  object_uuid: job['uuid'],
 220                  event_type: "stderr",
 221                  properties: {"text" => "Log message after subscription"})
 222     assert_text 'Log message after subscription'
 223   end
 224
 225   test "test running job with too many previous log records" do
 226     max = 5
 227     Rails.configuration.running_job_log_records_to_fetch = max
 228     job = api_fixture("jobs")['running']
 229
 230     # Create max+1 log records
 231     (0..max).each do |count|
 232       dispatch_log(owner_uuid: job['owner_uuid'],
 233                    object_uuid: job['uuid'],
 234                    event_type: "stderr",
 235                    properties: {"text" => "Old log message #{count}"})
 236     end
 237
 238     visit page_with_token("active", "/jobs/#{job['uuid']}\#Log")
 239
 240     # Expect all but the first historic log records,
 241     # because that was one too many than fetch count.
 242     (1..max).each do |count|
 243       assert_text "Old log message #{count}"
 244     end
 245     assert_no_text 'Old log message 0'
 246
 247     # Create one more log record after subscription
 248     dispatch_log(owner_uuid: job['owner_uuid'],
 249                  object_uuid: job['uuid'],
 250                  event_type: "stderr",
 251                  properties: {"text" => "Life goes on!"})
 252
 253     # Expect it to show up in log tab
 254     assert_text 'Life goes on!'
 255   end
 256 end