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