Hard crash on test failures with UTF-8 characters in test names

[mrsimo]

I believe this gist should help reproduce this error: https://gist.github.com/mrsimo/9cfc750719a7230c2a96803a4c861042

I added a puts inside the redis gem just before executes a command, hence the redis output we see:

$ be minitest-queue retry --build wadus-1 --queue $queue test.rb
["*2", "$4", "auth", "$32", <zip>"]
["*4", "$6", "lrange", "$27", "build:wadus-1:worker::queue", "$1", "0", "$2", "-1"]
["*4", "$4", "hset", "$27", "build:wadus-1:error-reports", "$57", "BugTest#test_doesn’t_allow_requests_from_inactive_users", "$333", "\x04\b{\b:\x19test_and_module_nameI\">BugTest#test_doesn\xE2\x80\x99t_allow_requests_from_inactive_users\x06:\x06ET:\x0Etest_nameI\"6test_doesn\xE2\x80\x99t_allow_requests_from_inactive_users\x06;\x06T:\voutputI\"\x01\x9F\e[31mFAIL\e[0m BugTest#test_doesn\xE2\x80\x99t_allow_requests_from_inactive_users\n\e[33mExpected true to not be truthy.\e[0m\n    test.rb:10:in `block in <class:BugTest>'\n\n\x06;\x06T"]
Traceback (most recent call last):
	35: from /home/albert/.rbenv/versions/2.5.1/lib/ruby/gems/2.5.0/gems/minitest-5.11.3/lib/minitest.rb:63:in `block in autorun'
	34: from /home/albert/.rbenv/versions/2.5.1/lib/ruby/gems/2.5.0/gems/minitest-5.11.3/lib/minitest.rb:136:in `run'
	33: from /home/albert/.rbenv/versions/2.5.1/lib/ruby/gems/2.5.0/gems/ci-queue-0.13.4/lib/minitest/queue.rb:145:in `__run'
	32: from /home/albert/.rbenv/versions/2.5.1/lib/ruby/gems/2.5.0/gems/ci-queue-0.13.4/lib/minitest/queue.rb:156:in `run_from_queue'
	31: from /home/albert/.rbenv/versions/2.5.1/lib/ruby/gems/2.5.0/gems/ci-queue-0.13.4/lib/ci/queue/static.rb:52:in `poll'
	30: from /home/albert/.rbenv/versions/2.5.1/lib/ruby/gems/2.5.0/gems/ci-queue-0.13.4/lib/minitest/queue.rb:177:in `block in run_from_queue'
	29: from /home/albert/.rbenv/versions/2.5.1/lib/ruby/gems/2.5.0/gems/minitest-5.11.3/lib/minitest.rb:802:in `record'
	28: from /home/albert/.rbenv/versions/2.5.1/lib/ruby/gems/2.5.0/gems/minitest-5.11.3/lib/minitest.rb:802:in `each'
	27: from /home/albert/.rbenv/versions/2.5.1/lib/ruby/gems/2.5.0/gems/minitest-5.11.3/lib/minitest.rb:803:in `block in record'
	26: from /home/albert/.rbenv/versions/2.5.1/lib/ruby/gems/2.5.0/gems/minitest-reporters-1.3.0/lib/minitest/minitest_reporter_plugin.rb:20:in `record'
	25: from /home/albert/.rbenv/versions/2.5.1/lib/ruby/gems/2.5.0/gems/minitest-reporters-1.3.0/lib/minitest/minitest_reporter_plugin.rb:20:in `each'
	24: from /home/albert/.rbenv/versions/2.5.1/lib/ruby/gems/2.5.0/gems/minitest-reporters-1.3.0/lib/minitest/minitest_reporter_plugin.rb:21:in `block in record'
	23: from /home/albert/.rbenv/versions/2.5.1/lib/ruby/gems/2.5.0/gems/ci-queue-0.13.4/lib/minitest/queue/build_status_recorder.rb:52:in `record'
	22: from /home/albert/.rbenv/versions/2.5.1/lib/ruby/gems/2.5.0/gems/ci-queue-0.13.4/lib/ci/queue/redis/build_record.rb:20:in `record_error'
	21: from /home/albert/.rbenv/versions/2.5.1/lib/ruby/gems/2.5.0/gems/redis-4.0.1/lib/redis.rb:2303:in `pipelined'
	20: from /home/albert/.rbenv/versions/2.5.1/lib/ruby/gems/2.5.0/gems/redis-4.0.1/lib/redis.rb:45:in `synchronize'
	19: from /home/albert/.rbenv/versions/2.5.1/lib/ruby/2.5.0/monitor.rb:226:in `mon_synchronize'
	18: from /home/albert/.rbenv/versions/2.5.1/lib/ruby/gems/2.5.0/gems/redis-4.0.1/lib/redis.rb:45:in `block in synchronize'
	17: from /home/albert/.rbenv/versions/2.5.1/lib/ruby/gems/2.5.0/gems/redis-4.0.1/lib/redis.rb:2307:in `block in pipelined'
	16: from /home/albert/.rbenv/versions/2.5.1/lib/ruby/gems/2.5.0/gems/redis-4.0.1/lib/redis/client.rb:153:in `call_pipeline'
	15: from /home/albert/.rbenv/versions/2.5.1/lib/ruby/gems/2.5.0/gems/redis-4.0.1/lib/redis/client.rb:291:in `with_reconnect'
	14: from /home/albert/.rbenv/versions/2.5.1/lib/ruby/gems/2.5.0/gems/redis-4.0.1/lib/redis/client.rb:155:in `block in call_pipeline'
	13: from /home/albert/.rbenv/versions/2.5.1/lib/ruby/gems/2.5.0/gems/redis-4.0.1/lib/redis/client.rb:185:in `call_pipelined'
	12: from /home/albert/.rbenv/versions/2.5.1/lib/ruby/gems/2.5.0/gems/redis-4.0.1/lib/redis/client.rb:218:in `process'
	11: from /home/albert/.rbenv/versions/2.5.1/lib/ruby/gems/2.5.0/gems/redis-4.0.1/lib/redis/client.rb:304:in `logging'
	10: from /home/albert/.rbenv/versions/2.5.1/lib/ruby/gems/2.5.0/gems/redis-4.0.1/lib/redis/client.rb:219:in `block in process'
	 9: from /home/albert/.rbenv/versions/2.5.1/lib/ruby/gems/2.5.0/gems/redis-4.0.1/lib/redis/client.rb:366:in `ensure_connected'
	 8: from /home/albert/.rbenv/versions/2.5.1/lib/ruby/gems/2.5.0/gems/redis-4.0.1/lib/redis/client.rb:220:in `block (2 levels) in process'
	 7: from /home/albert/.rbenv/versions/2.5.1/lib/ruby/gems/2.5.0/gems/redis-4.0.1/lib/redis/client.rb:220:in `each'
	 6: from /home/albert/.rbenv/versions/2.5.1/lib/ruby/gems/2.5.0/gems/redis-4.0.1/lib/redis/client.rb:226:in `block (3 levels) in process'
	 5: from /home/albert/.rbenv/versions/2.5.1/lib/ruby/gems/2.5.0/gems/redis-4.0.1/lib/redis/client.rb:267:in `write'
	 4: from /home/albert/.rbenv/versions/2.5.1/lib/ruby/gems/2.5.0/gems/redis-4.0.1/lib/redis/client.rb:248:in `io'
	 3: from /home/albert/.rbenv/versions/2.5.1/lib/ruby/gems/2.5.0/gems/redis-4.0.1/lib/redis/client.rb:269:in `block in write'
	 2: from /home/albert/.rbenv/versions/2.5.1/lib/ruby/gems/2.5.0/gems/redis-4.0.1/lib/redis/connection/ruby.rb:356:in `write'
	 1: from /home/albert/.rbenv/versions/2.5.1/lib/ruby/gems/2.5.0/gems/redis-4.0.1/lib/redis/connection/command_helper.rb:30:in `build_command'
/home/albert/.rbenv/versions/2.5.1/lib/ruby/gems/2.5.0/gems/redis-4.0.1/lib/redis/connection/command_helper.rb:30:in `join': incompatible character encodings: UTF-8 and ASCII-8BIT (Encoding::CompatibilityError)

If I change the ’ from doesn’t things go well.

I can hopefully just change all these in my test suite, but it seems we have very enthusiastic developers when comes to proper apostrophes in our team 😆 and we'll just be one ’ away from test catastrophe.

[mrsimo]

Seems like in this line, "#{test.klass}##{test.name}" ends up with UTF-8 encoding because of that apostrophe, and dump(test) is US-ASCII.

With Snappy it doesn't happen, I guess because of this.

Would it be enough to just force_encoding(Encoding::UTF_8) when using Marshal?

[casperisfine]

Would it be enough to just force_encoding(Encoding::UTF_8) when using Marshal?

I think so yes. Even that's assuming the test name was UTF-8 in the first place, but that more than likely.

[casperisfine]

I wonder how you test is defined. As Marshal should preserve the original encoding.

[mrsimo]

The gist should reproduce the issue I see. I could fix things in my app with this monkey patch:

if Rails.env.test?
  module FixCiQueueUtf8
    def record_error(id, payload, stats: nil)
      super(id, payload.to_s.force_encoding('UTF-8'), stats: stats)
    end
  end

  module CI
    module Queue
      module Redis
        class BuildRecord
          prepend FixCiQueueUtf8
        end
      end
    end
  end
end

[casperisfine]

Woops, I totally overlooked your gist

[casperisfine]

Ok, I see what's going on. The problem is that the Marshal payload doesn't have an encoding, which is expected, and we shouldn't give it one (it isn't valid UTF8 or anything, just binary).

However in the HSET, the hash key is the test name, which is UTF8, so Redis fail to concatenate theses.

I think the fix would be to hash the test name.