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