Understanding the AutoGrader

So I just reviewed the ruby-intro homework and wrote a walkthrough. Now I want to look at how the autograder is grading it and check that everything is working okay on Azure ...

Currently we have the live graders using the 8_expose_feature_grader_exceptions branch, on which all the tests pass locally for me, and they also pass on the EC2 production grader. They don't all pass on the Azure grader, but the Azure grader does seem to grade all the assignments correctly - at least the ones that I've tried ...

We don't seem to have a PR for that into master ... I have opened one to clearly expose the changes ...

Trying to head into the grader to look at how testing works so we can start understanding all this better. The RSpec tests all involve using FakeWeb to stub the reach out via Xqueue to pull specs off a remote connection. This refactoring to the XQueue gem was where we lost the ability to run the graders from the command line - something else it would be good to have back, but priorities, priorities ...

Running the specs leaves a lot of output - my logging statements - start by removing those? Actually my logging statements in this branch only affect the feature grader - looks like there is set up here to adjust logging levels - should be turned off for test by default I think (would be huge if the logs included line numbers ...)

We have a custom logger in lib/rag_logger.rb which builds on the basic ruby logger that will either write to logs, or print to STDOUT if not set. Looks like there are some hacks to add line numbers:

https://www.google.co.jp/search?q=ruby+logger+log+line+numbers

Look into them later I guess ...

RagLogger.configure_logger(false, Logger::ERROR)

in the spec helper reduces the test logging, but does not adjust the level of logging in the separate process run by the grader ...

I can further reduce the level of logging by adding log_level: 3 to the spec/fixtures/x_queue_config.yml

However the rspec grader test appears to dump some stuff to stdout after calling the grade method, and ramping up the logging level does not allow me to see where it's coming from - I assume it's part of the other process ...

So it looks to me like the lib/graders/rspec_grader/rspec_grader.rb is outputting to STDOUT as part of running the RSpec core runner. If I add any logging there I seem to break the test as maybe I interferes with the rspec output that is processed in order to determine the result of the grading activity ...

We're using RSpec::Core::Runner with a StringIO passed in as the output - I can remove that and the output goes to stdout and gets coloured correctly (and the test passes), but what's strange is us getting the black and white only output when we have the StringIO object being passed in ...

https://stackoverflow.com/questions/43553798/how-to-programmatically-run-rspec-test-and-capture-output

Looks to me like I'd have to dive into RSpec to get to the bottom of that issue ... and really this is a side show compared to trying to do what I really want to do which is just run the cuke for the ruby intro assignment and move on to checking the variations on Azure ...

Although this issue also affects all the cuke outputs ... ... so I'm wondering if I might just poke around in RSpec for a bit to see what's going on here ... what I really need is to check if we get this behaviour outside of the graders separately running thread ...

So upgrading to rspec 3.6 causes the RSpec runner output to actually push stuff to the StringIO, but the output is still not nothing - we're still getting Run options, the title of the assignment, which I've now been able to suppress and I've managed to get our output down to this:

→ be rspec spec/graders/rspec_grader_spec.rb:18

Graders::RspecGrader
  should be able to grade a simple homework
    gives points to a hw1 solution

Finished in 0.18767 seconds (files took 0.93212 seconds to load)
1 example, 0 failures

and I note that even for the tests we are caching all the downloaded specs to the submissions/ directory, so for properly updating repeatable tests, we need to remove the directory every time we run the test suite, and even in-between running individual tests ...

So anyway, reasonably happy day, I can run the entire rspec suite with no extraneous output, but I seem to have had to upgrade ALL the gems to get rspec upgraded ...

I can also get clean output from cucumber - at least the first simple test:

→ be cucumber features/autograder_xqueue_stubbed.feature:7
Feature: Autograder configured to accept student submissions from edX and grade them
  As an instructor
  So that I can give feedback to my students on their code responses
  I want to be able to create a code submission page in edX and grade it using rag

  Scenario: simple one file submission against one spec file RSpecGrader    # features/autograder_xqueue_stubbed.feature:7
    Given an XQueue that has submission "simple_rspec_xqueue.json" in queue # features/step_definitions/adapter_x_queue_steps.rb:28
      ["http://www.fakedownload.com/hw1.rb"]
      register_uri for : http://www.fakedownload.com/hw1.rb
    And has been setup with the config file "conf.yml"                      # features/step_definitions/adapter_x_queue_steps.rb:44
    Then I should receive a grade of "30" for my assignment                 # features/step_definitions/adapter_x_queue_steps.rb:49

1 scenario (1 passed)
3 steps (3 passed)
0m0.229s

The second cuke however gives me this error:

Encoding::UndefinedConversionError: "\xEB" from ASCII-8BIT to UTF-8

for which I find this on google:

https://github.com/roidrage/lograge/issues/210

and appears to be related to unzipping some files - my local encoding is UTF-8 - moving the ruby zip gem back does not help.

my options here are try to back out and use the original Gemfile.lock with just the rspec updated - which I do, and it works ... and all the specs are still passing with no overhead output ...

the following cuke fails:

→ be cucumber features/autograder_xqueue_stubbed.feature:25
Feature: Autograder configured to accept student submissions from edX and grade them
  As an instructor
  So that I can give feedback to my students on their code responses
  I want to be able to create a code submission page in edX and grade it using rag

  # These tests can be slow and unreliable because they rely on heroku deployments; the dynos may be down or need to spin up.
  @require_net_connect
  Scenario: student submits a HerokuGrader homework                   # features/autograder_xqueue_stubbed.feature:25
    Given I set up a test that requires internet connection           # features/step_definitions/adapter_x_queue_steps.rb:24
    Given an XQueue that has submission "heroku_xqueue.json" in queue # features/step_definitions/adapter_x_queue_steps.rb:28
      ["http://www.fakedownload.com/hw2.txt"]
      register_uri for : http://www.fakedownload.com/hw2.txt
    And has been setup with the config file "conf.yml"                # features/step_definitions/adapter_x_queue_steps.rb:44
    Then I should receive a grade of "100" for my assignment          # features/step_definitions/adapter_x_queue_steps.rb:49
      expected: == 100.0
           got:    0.0 (RSpec::Expectations::ExpectationNotMetError)
      ./features/step_definitions/adapter_x_queue_steps.rb:57:in `/^I should receive a grade of "(.*?)" for my assignment$/'
      features/autograder_xqueue_stubbed.feature:29:in `Then I should receive a grade of "100" for my assignment'

Failing Scenarios:
cucumber features/autograder_xqueue_stubbed.feature:25 # Scenario: student submits a HerokuGrader homework

but I'm offline and that one requires network access so that's not surprising. The other cukes seem to be passing. Some are slow running - I wonder if that's related to writing out files to the file system? or just building rails stuff locally ...

Now I can also see my logging statements from the branch from before ...

Sensibly I'll break all these HW4 (awful name) into a separate file

All the other cukes are passing, which is nice. The output to stdout is actually a bit of a feature when the grader is running, so it would be nice to be able to turn that on and off at will ...

just running bec to check I've cleared out extraneous logging, and I still see:

/Users/tansaku/Documents/GitHub/saasbook/rag/features/step_definitions/adapter_x_queue_steps.rb:31: warning: already initialized constant JSON_string
/Users/tansaku/Documents/GitHub/saasbook/rag/features/step_definitions/adapter_x_queue_steps.rb:31: warning: previous definition of JSON_string was here

and

["http://www.fakedownload.com/hw3.zip"]

register_uri for : http://www.fakedownload.com/hw3.zip

not sure where that's coming from ... the latter looks like a couple of puts statements in the cuke steps - trimmed those out ... and the former one looks like a redundant warning based on the JSON_string being treated as a constant, can easily sort that ...

hmm, so now we can run the tests with clearer visibility. Of course I still need to test these on Azure, and then probably on EC2 if we can't get a good read there ... I think the main slowness for the cuke is the timeout for the runaway process - perhaps we could shorten that for the test?

I managed to reduce it with:

And(/^I've hacked the grader to have a short timeout$/) do
  class Graders::AutoGrader
    def timeout; 20; end
  end
end

but I think that's a bit dangerous ..., since maybe part of this test is checking against the default time out for the feature grader - 20 is the lowest that we still get the expected error ... and that looks like I'm introducing a slew of other errors (I had to adjust how the grader reads timeouts too ...)

okay, so I back out of that, but maybe I'm ahead having a cleaner version of the tests to work against ... and a better understanding of the grader to boot ...

So next steps are to check that one heroku cuke spec passes when I'm reconnected to the network, and then I could maybe merge that branch to master, since it's been running in production long enough (remove my logging things?) and remind myself of the errors we're getting on Azure ...

might even experiment with this upgraded branch on Azure ... as well as hitting with more tests from edx part 1???

and then we probably also want a test step that deletes the submission directory - interesting - seems like "student submits RSpecGrader assignment containing multiple files with specs hosted on Github" also fails offline if we're not cached ...

Action Plan:

1. merge 8_expose_feature_grader_exceptions into master ...