diff --git a/app/controllers/concerns/submission_scoring.rb b/app/controllers/concerns/submission_scoring.rb index a8b76748..2e932631 100644 --- a/app/controllers/concerns/submission_scoring.rb +++ b/app/controllers/concerns/submission_scoring.rb @@ -19,7 +19,15 @@ module SubmissionScoring end end end - Testrun.new(submission: submission, cause: 'assess', file: file, passed: passed, output: testrun_output).save + Testrun.new( + submission: submission, + cause: 'assess', + file: file, + passed: passed, + output: testrun_output, + container_execution_time: output[:container_execution_time], + waiting_for_container_time: output[:waiting_for_container_time] + ).save output.merge!(assessment) output.merge!(filename: file.name_with_extension, message: feedback_message(file, output[:score]), weight: file.weight) end diff --git a/app/controllers/submissions_controller.rb b/app/controllers/submissions_controller.rb index 3a72e136..7554a91f 100644 --- a/app/controllers/submissions_controller.rb +++ b/app/controllers/submissions_controller.rb @@ -161,8 +161,10 @@ class SubmissionsController < ApplicationController # give the docker_client the tubesock object, so that it can send messages (timeout) @docker_client.tubesock = tubesock + container_request_time = Time.now result = @docker_client.execute_run_command(@submission, sanitize_filename) tubesock.send_data JSON.dump({'cmd' => 'status', 'status' => result[:status]}) + @waiting_for_container_time = Time.now - container_request_time if result[:status] == :container_running socket = result[:socket] @@ -199,6 +201,7 @@ class SubmissionsController < ApplicationController # Send command after all listeners are attached. # Newline required to flush + @execution_request_time = Time.now socket.send command + "\n" Rails.logger.info('Sent command: ' + command.to_s) else @@ -208,6 +211,7 @@ class SubmissionsController < ApplicationController end def kill_socket(tubesock) + @container_execution_time = Time.now - @execution_request_time unless @execution_request_time.blank? # search for errors and save them as StructuredError (for scoring runs see submission_scoring.rb) errors = extract_errors send_hints(tubesock, errors) @@ -302,7 +306,14 @@ class SubmissionsController < ApplicationController def save_run_output unless @run_output.blank? @run_output = @run_output[(0..max_run_output_buffer_size-1)] # trim the string to max_message_buffer_size chars - Testrun.create(file: @file, cause: 'run', submission: @submission, output: @run_output) + Testrun.create( + file: @file, + cause: 'run', + submission: @submission, + output: @run_output, + container_execution_time: @container_execution_time, + waiting_for_container_time: @waiting_for_container_time + ) end end diff --git a/db/migrate/20200326115249_add_container_execution_time_to_testruns.rb b/db/migrate/20200326115249_add_container_execution_time_to_testruns.rb new file mode 100644 index 00000000..d04b041d --- /dev/null +++ b/db/migrate/20200326115249_add_container_execution_time_to_testruns.rb @@ -0,0 +1,6 @@ +class AddContainerExecutionTimeToTestruns < ActiveRecord::Migration[5.2] + def change + add_column :testruns, :container_execution_time, :interval + add_column :testruns, :waiting_for_container_time, :interval + end +end diff --git a/lib/docker_client.rb b/lib/docker_client.rb index 769f4a82..d3bd87a6 100644 --- a/lib/docker_client.rb +++ b/lib/docker_client.rb @@ -256,13 +256,21 @@ class DockerClient #only used by score def execute_command(command, before_execution_block, output_consuming_block) #tries ||= 0 + container_request_time = Time.now @container = DockerContainerPool.get_container(@execution_environment) + waiting_for_container_time = Time.now - container_request_time if @container @container.status = :executing before_execution_block.try(:call) - send_command(command, @container, &output_consuming_block) + execution_request_time = Time.now + command_result = send_command(command, @container, &output_consuming_block) + container_execution_time = Time.now - execution_request_time + + command_result.merge!(waiting_for_container_time: waiting_for_container_time) + command_result.merge!(container_execution_time: container_execution_time) + command_result else - {status: :container_depleted} + {status: :container_depleted, waiting_for_container_time: waiting_for_container_time, container_execution_time: nil} end rescue Excon::Errors::SocketError => error # socket errors seems to be normal when using exec