apps/workbench/test/integration/websockets_test.rb

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