Ensure to save Testrun even when an error occurs

app/controllers/submissions_controller.rb

@@ -134,18 +134,17 @@ class SubmissionsController < ApplicationController
 
   def handle_websockets(tubesock, socket)
     tubesock.send_data JSON.dump({cmd: :status, status: :container_running})
-    @output = +''
-
-    socket.on :output do |data|
-      @output << data if @output.size + data.size <= max_output_buffer_size
-    end
 
     socket.on :stdout do |data|
-      tubesock.send_data(JSON.dump({cmd: :write, stream: :stdout, data: data}))
+      json_data = JSON.dump({cmd: :write, stream: :stdout, data: data})
+      @output << json_data[0, max_output_buffer_size - @output.size]
+      tubesock.send_data(json_data)
     end
 
     socket.on :stderr do |data|
-      tubesock.send_data(JSON.dump({cmd: :write, stream: :stderr, data: data}))
+      json_data = JSON.dump({cmd: :write, stream: :stderr, data: data})
+      @output << json_data[0, max_output_buffer_size - @output.size]
+      tubesock.send_data(json_data)
     end
 
     socket.on :exit do |exit_code|
@@ -180,6 +179,7 @@ class SubmissionsController < ApplicationController
   end
 
   def run
+    @output = +''
     hijack do |tubesock|
       return kill_socket(tubesock) if @embed_options[:disable_run]
 
@@ -188,20 +188,22 @@ class SubmissionsController < ApplicationController
       end
       @container_execution_time = durations[:execution_duration]
       @waiting_for_container_time = durations[:waiting_duration]
-      save_run_output
     rescue Runner::Error::ExecutionTimeout => e
       tubesock.send_data JSON.dump({cmd: :status, status: :timeout})
       kill_socket(tubesock)
       Rails.logger.debug { "Running a submission timed out: #{e.message}" }
+      @output = "timeout: #{@output}"
     rescue Runner::Error => e
       tubesock.send_data JSON.dump({cmd: :status, status: :container_depleted})
       kill_socket(tubesock)
       Rails.logger.debug { "Runner error while running a submission: #{e.message}" }
+    ensure
+      save_run_output
     end
   end
 
   def kill_socket(tubesock)
-    # search for errors and save them as StructuredError (for scoring runs see submission_scoring.rb)
+    # search for errors and save them as StructuredError (for scoring runs see submission.rb)
     errors = extract_errors
     send_hints(tubesock, errors)
 
@@ -210,11 +212,8 @@ class SubmissionsController < ApplicationController
     tubesock.close
   end
 
-  # save the output of this "run" as a "testrun" (scoring runs are saved in submission_scoring.rb)
+  # save the output of this "run" as a "testrun" (scoring runs are saved in submission.rb)
   def save_run_output
-    return if @output.blank?
-
-    @output = @output[0, max_output_buffer_size] # trim the string to max_output_buffer_size chars
     Testrun.create(
       file: @file,
       cause: 'run',
@@ -243,12 +242,9 @@ class SubmissionsController < ApplicationController
       tubesock.send_data(JSON.dump(format_scoring_results(@submission.calculate_score)))
       # To enable hints when scoring a submission, uncomment the next line:
       # send_hints(tubesock, StructuredError.where(submission: @submission))
-    rescue Runner::Error::ExecutionTimeout => e
-      tubesock.send_data JSON.dump({cmd: :status, status: :timeout})
-      Rails.logger.debug { "Scoring a submission timed out: #{e.message}" }
     rescue Runner::Error => e
       tubesock.send_data JSON.dump({cmd: :status, status: :container_depleted})
-      Rails.logger.debug { "Runner error while scoring a submission: #{e.message}" }
+      Rails.logger.debug { "Runner error while scoring submission #{@submission.id}: #{e.message}" }
     ensure
       tubesock.send_data JSON.dump({cmd: :exit})
       tubesock.close

app/models/submission.rb

@@ -143,29 +143,33 @@ class Submission < ApplicationRecord
     prepared_runner do |runner, waiting_duration|
       file_scores = collect_files.select(&:teacher_defined_assessment?).map do |file|
         score_command = command_for execution_environment.test_command, file.name_with_extension
+        output = {file_role: file.role, waiting_for_container_time: waiting_duration}
         stdout = +''
         stderr = +''
-        exit_code = 1 # default to error
-        execution_time = runner.attach_to_execution(score_command) do |socket|
-          socket.on :stderr do |data|
-            stderr << data
-          end
-          socket.on :stdout do |data|
-            stdout << data
-          end
-          socket.on :exit do |received_exit_code|
-            exit_code = received_exit_code
-            EventMachine.stop_event_loop
+        begin
+          exit_code = 1 # default to error
+          execution_time = runner.attach_to_execution(score_command) do |socket|
+            socket.on :stderr do |data|
+              stderr << data
+            end
+            socket.on :stdout do |data|
+              stdout << data
+            end
+            socket.on :exit do |received_exit_code|
+              exit_code = received_exit_code
+              EventMachine.stop_event_loop
+            end
           end
+          output.merge!(container_execution_time: execution_time, status: exit_code.zero? ? :ok : :failed)
+        rescue Runner::Error::ExecutionTimeout => e
+          Rails.logger.debug("Running tests in #{file.name_with_extension} for submission #{id} timed out: #{e.message}")
+          output.merge!(status: :timeout)
+        rescue Runner::Error => e
+          Rails.logger.debug("Running tests in #{file.name_with_extension} for submission #{id} failed: #{e.message}")
+          output.merge!(status: :failed)
+        ensure
+          output.merge!(stdout: stdout, stderr: stderr)
         end
-        output = {
-          file_role: file.role,
-          waiting_for_container_time: waiting_duration,
-          container_execution_time: execution_time,
-          status: exit_code.zero? ? :ok : :failed,
-          stdout: stdout,
-          stderr: stderr,
-        }
         score_file(output, file)
       end
     end

lib/runner/connection.rb

@@ -57,7 +57,7 @@ class Runner::Connection
     return unless BACKEND_OUTPUT_SCHEMA.valid?(event)
 
     event = event.deep_symbolize_keys
-    message_type = event[:type]
+    message_type = event[:type].to_sym
     if WEBSOCKET_MESSAGE_TYPES.include?(message_type)
       __send__("handle_#{message_type}", event)
     else