3.18.6 broke before_request

[asbjornu]

Upgrading from 3.18.5 to 3.18.6 somehow broke the before_request hook. I'm not sure what, but something in 3bb8d35...75ad787 must change the behaviour such that before_request is no longer being invoked, at least in some circumstances. Ideas on what may be the cause would be good so we could both fix it and add more tests to ensure that this doesn't break again.

[gjtorikian]

Can you provide a minimum reproducible case? #622 probably broke it, but all existing tests passed, so I am curious to know what was missed.

[asbjornu]

It's not exactly minimal, but here's where HTMLProofer is in use that broke when upgrading from 3.18.5 to 3.18.6.

[gjtorikian]

Oh this is the external URL link request, not the middleware one. Hm.

I guess this is one of the broken tests? Can you talk me through what you expect to happen and what is happening? https://github.com/SwedbankPay/jekyll-plantuml-docker/tree/develop/link.md is actually a 404 so I'm not sure what the problem is.

[asbjornu]

The failing test expects a log statement coming from before_request that is logged successfully in 3.18.5, but is not logged (and thus failing the spec) in 3.18.6. The source code for the spec is:

it 'sets bearer token for github' do
  ignore_urls = [ '/', 'http://www.wikipedia.org', %r{[/.]?page1} ]
  allow(context.arguments).to receive(:ignore_urls).and_return(ignore_urls)
  logger = SpecLogger.new(:debug)
  subject.logger = logger
  subject.verify
  expect(logger.message).to include('Authorization set for')
end

[asbjornu]

The code that performs the logging is:

def before_request(request)
  uri = URI(request.base_url)

  unless uri.host.match('github\.(com|io)$')
    log(:debug, "No authorization set for <#{uri}> as it's not matching github.com or github.io.")
    return
  end

  auth = "Bearer #{@context.auth_token}"
  request.options[:headers]['Authorization'] = auth
  log(:debug, "Authorization set for <#{uri}>.")
end

[gjtorikian]

Ok I’ll take a look this week (I’m moving at the moment).

[gjtorikian]

It looks like this was fixed in your project? I see 3.18.6 in your lockfile.

[asbjornu]

I wish that was true, but that's unfortunately only the lockfile of a test project. This is the relevant lockfile which has HTMLProofer locked to 3.18.5 still.

[gjtorikian]

I'm a bit stumped. I can't recreate this locally, and nothing dealing with before_request was changed. 🤔

[gjtorikian]

Ah! I found a culprit. I cloned your project and was able to recreate an issue. One moment...

[gjtorikian]

Thanks for your patience. 3.18.7 will be released with the fix soon.

PS If this open source project is helping you, please consider sponsoring it. ✌️

[asbjornu]

Thanks @gjtorikian! The bump from Dependabot came tonight and unfortunately, it still looks to be broken. 😕

[gjtorikian]

😠

[gjtorikian]

@asbjornu Ok, here's what I think is happening: I think your test might be wrong. Your test relies on the cache, so on the first run, it passes; on the second run, it relies on the response stored in the cache file, and so never actually makes the external request.

To fix this, you can either rm tmp/.htmlproofer/cache.log to get it to a clean state; or, use something like Timecop to move outside of the cache timeframe and force html-proofer to ignore what's in the cache. The first option is probably easier.

Let me know how that goes!

[asbjornu]

Sorry for being stupid – you are entirely correct. The caching was indeed the problem. This fixed it:

after { FileUtils.rm_rf(File.expand_path(File.join(__dir__, '..', 'tmp'))) }

[gjtorikian]

No worries at all. There was a legitimate problem with caching around here, which the last patch bump fixed.