Merge branch '16726-anon-fed' into 16726-anon-user-token
[arvados.git] / 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 'job graph appears when first data point is already in logs table' do
81     job_graph_first_datapoint_test
82   end
83
84   test 'job graph appears when first data point arrives by websocket' do
85     use_token :admin do
86       Log.find(api_fixture('logs')['crunchstat_for_running_job']['uuid']).destroy
87     end
88     job_graph_first_datapoint_test expect_existing_datapoints: false
89   end
90
91   def job_graph_first_datapoint_test expect_existing_datapoints: true
92     uuid = api_fixture('jobs')['running']['uuid']
93
94     visit page_with_token "active", "/jobs/#{uuid}"
95     click_link "Log"
96
97     assert_selector '#event_log_div', visible: true
98
99     if expect_existing_datapoints
100       assert_selector '#log_graph_div', visible: true
101       # Magic numbers 12.99 etc come from the job log fixture:
102       assert_last_datapoint 'T1-cpu', (((12.99+0.99)/10.0002)/8)
103     else
104       # Until graphable data arrives, we should see the text log but not the graph.
105       assert_no_selector '#log_graph_div', visible: true
106     end
107
108     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"
109
110     assert_triggers_dom_event 'arv-log-event' do
111       dispatch_log(owner_uuid: api_fixture('jobs')['running']['owner_uuid'],
112                    object_uuid: uuid,
113                    event_type: "stderr",
114                    properties: {"text" => text})
115     end
116
117     # Graph should have appeared (even if it hadn't above). It's
118     # important not to wait like matchers usually do: we are
119     # confirming the graph is visible _immediately_ after the first
120     # data point arrives.
121     using_wait_time 0 do
122       assert_selector '#log_graph_div', visible: true
123     end
124     assert_last_datapoint 'T1-cpu', (((35.39+0.86)/10.0002)/8)
125   end
126
127   test "live log charting from replayed log" do
128     uuid = api_fixture("jobs")['running']['uuid']
129
130     visit page_with_token "active", "/jobs/#{uuid}"
131     click_link "Log"
132
133     assert_triggers_dom_event 'arv-log-event' do
134       ApiServerForTests.new.run_rake_task("replay_job_log", "test/job_logs/crunchstatshort.log,1.0,#{uuid}")
135     end
136
137     assert_last_datapoint 'T1-cpu', (((35.39+0.86)/10.0002)/8)
138   end
139
140   def assert_last_datapoint series, value
141     datum = page.evaluate_script("jobGraphData[jobGraphData.length-1]['#{series}']")
142     assert_in_epsilon value, datum.to_f
143   end
144
145   test "test running job with just a few previous log records" do
146     job = api_fixture("jobs")['running']
147
148     # Create just one old log record
149     dispatch_log(owner_uuid: job['owner_uuid'],
150                  object_uuid: job['uuid'],
151                  event_type: "stderr",
152                  properties: {"text" => "Historic log message"})
153
154     visit page_with_token("active", "/jobs/#{job['uuid']}\#Log")
155
156     # Expect "all" historic log records because we have less than
157     # default Rails.configuration.Workbench.RunningJobLogRecordsToFetch
158     assert_text 'Historic log message'
159
160     # Create new log record and expect it to show up in log tab
161     dispatch_log(owner_uuid: job['owner_uuid'],
162                  object_uuid: job['uuid'],
163                  event_type: "stderr",
164                  properties: {"text" => "Log message after subscription"})
165     assert_text 'Log message after subscription'
166   end
167
168   test "test running job with too many previous log records" do
169     max = 5
170     Rails.configuration.Workbench.RunningJobLogRecordsToFetch = max
171     job = api_fixture("jobs")['running']
172
173     # Create max+1 log records
174     (0..max).each do |count|
175       dispatch_log(owner_uuid: job['owner_uuid'],
176                    object_uuid: job['uuid'],
177                    event_type: "stderr",
178                    properties: {"text" => "Old log message #{count}"})
179     end
180
181     visit page_with_token("active", "/jobs/#{job['uuid']}\#Log")
182
183     # Expect all but the first historic log records,
184     # because that was one too many than fetch count.
185     (1..max).each do |count|
186       assert_text "Old log message #{count}"
187     end
188     assert_no_text 'Old log message 0'
189
190     # Create one more log record after subscription
191     dispatch_log(owner_uuid: job['owner_uuid'],
192                  object_uuid: job['uuid'],
193                  event_type: "stderr",
194                  properties: {"text" => "Life goes on!"})
195
196     # Expect it to show up in log tab
197     assert_text 'Life goes on!'
198   end
199 end