Understanding the AutoGrader (part 2)

AutoGrader

So I'm hitting the grader on azure in the new branch ..., and correctly grading the ruby-intro assignment with the cleaned up grader. In the meantime I've removed the puts statements from the 8_expose_feature_grader_exceptions branch so that that can be merged into master. I've left the other log statements in as I suspect they might actually be needed to give student effective feedback on their errors.

One thing I do note is that the consolidation of the multiple parts of the assignment into a single grader means that the students have to wade through much larger sets of output. SPOC instructors have mentioned this, and I guess the reason this happened is that the assignment is in a single repo and the developers wanted to avoid having to specify a separate repo for each individual part

"assignment_spec_uri": "git@github.com:saasbook/hw-ruby-intro-ci.git"

presumably the grader could be as precise as specifying an individual spec file, if we added the level of configuration ...

• I also notice that we area outputting the json representation of the rspec results - is that from the rspec 3.6 upgrade or ... hmm, looks like that's something added ... rag specifies a json output formatter and it seems like in 3.6 we're now having all that data come out in the StringIO output, along with the general output. I've tested 3.3, 3.4 and 3.5 and the StringIO only behaves as expected in 3.6.

What I can't understand is how we get any output displayed by the grader at all with rspec 3.3 since that all gets dumped to STDOUT - I guess that's then picked up by the run_in_subprocess method which is monitoring everything the subprocess writes to STDOUT.

So anyway, I've merged the 8_expose_feature_grader_exceptions branch into master.

I guess I'm now spinning my wheels trying to work out how to remove the excess json from the rspec 3.6 output, which it seems I can do by overwriting the close method in our custom formatter:

        def close(_notification)
        end

For broken code we get the error notification three times over (because we are running the three specs?) in the older grader we also get the failure message three times, AND no stack trace, so I think we're ahead somewhat. It would be nice to have some more output from the live grading telling us what assignment it was grading. At the moment after every grading it outputs:

run_autograder.rb:10: warning: class variable access from toplevel
run_autograder exited. 

That made me wonder if the grader is actually polling or if our bash loop is doing all the work. We usually run the grader like so:

while true; do bundle exec ruby run_autograder.rb config/config.yml; done

so I tried instead

bundle exec ruby run_autograder.rb config/config.yml

which just does the same, so I guess it is polling, but then I am unclear what this stuff about "exiting" means. I also see warnings related to running the code I submitted that get dumped to STDOUT, but we don't see them in the grader output:

/tmp/spec_file20170729-21723-1rbr9iw:25: warning: already initialized constant CONSONANTS
/tmp/spec_file20170729-21723-sx6f0j:25: warning: previous definition of CONSONANTS was here
/tmp/spec_file20170729-21723-ax05ms:25: warning: already initialized constant CONSONANTS
/tmp/spec_file20170729-21723-1rbr9iw:25: warning: previous definition of CONSONANTS was here
run_autograder.rb:10: warning: class variable access from toplevel
run_autograder exited. 

run_autograder.rb has the following code:

at_exit do
  FileUtils.rm_rf('temp_repo') # make sure we always do this even if we exit abnormally
  @@logger.close # flush the log file by closing the log.
  puts 'run_autograder exited. '
end

so that's clean up for whenever that file ends - but how does it get re-hit every time we submit an assignment to edx? If the autograder keeps running, as the code at the end of run_autograder suggests then why is it exiting?

require_relative 'lib/adapter'
autograder = Submission.load(ARGV[0])
autograder.run

That "run_autograder exited." only occurs in that file ... from what I can tell that call to a run method is ultimately on the Submission::Polling class which includes a loop that doesn't terminate:

    def run
      loop do
        submission = next_submission_with_assignment
        submission.nil? ? sleep(@sleep_duration) : handle_submission(submission)
      end
    end

so why is at_exit triggered? I guess I shouldn't be getting distracted by that - really the higher priority things are checking to see if we can have the hw-ruby-intro-ci cukes pass (also low priority?) or moving on to checking the ruby-intro zip fail that my latest updates are getting, or moving on to the next assignment (sinatra?).

I guess what I really should do is split up the cukes file to get the different assignments in their own feature files ...