One might think, this blog is exclusively about
weird language behavior and yelling at computers Well, welcome to another episode of Jackass!
Today's opponent is
Ruby, or maybe
minitest , or maybe
Mocha. I'm not exactly sure, but it was a rather amusing exercise and I like to share my nightmares ;)
It all started with the classical
"you're using old and unmaintained software, please switch to something new".
The
first attempt was to switch from the
ci_reporter_minitest plugin to the
minitest-ci plugin. While the change worked great for Foreman itself, it broke the reporting in
Katello - the tests would run but no
junit.xml was generated and Jenkins rightfully complained that it got no test results.
While investigating what the hell was wrong, we realized that Katello was already using a minitest reporting plugin:
minitest-reporters. Loading two different reporting plugins seemed like a good source for problems, so I tried
using the same plugin for Foreman too.
Guess what? After a bit of massaging (mostly to disable the second
minitest-reporters initialization in Katello) reporting of test results from Katello started to work like a charm. But now the Foreman tests started to fail. Not fail to report, fail to actually run. WTH
The failure was quite interesting too:
test/unit/parameter_filter_test.rb:5:in block in <class:ParameterFilterTest>':
Mocha methods cannot be used outside the context of a test (Mocha::NotInitializedError)
Yes, this is a single test file failing, all others were fine.
The failing code doesn't look problematic on first glance:
require 'test_helper'
class ParameterFilterTest < ActiveSupport::TestCase
let(:klass) do
mock('Example').tap do k
k.stubs(:name).returns('Example')
end
end
test 'something' do
something
end
end
The failing line (5) is
mock('Example').tap and for some reason Mocha thinks it's not initialized here.
This
certainly has something to do with
how the various reporting plugins inject themselves, but I really didn't want to debug how to run two reporting plugins in parallel (which, as you remember, didn't expose this behavior). So the only real path forward was to debug what's happening here.
Calling the test on its own, with one of the working reporter was the first step:
$ bundle exec rake test TEST=test/unit/parameter_filter_test.rb TESTOPTS=-v
#<Mocha::Mock:0x0000557bf1f22e30>#test_0001_permits plugin-added attribute = 0.04 s = .
#<Mocha::Mock:0x0000557bf12cf750>#test_0002_permits plugin-added attributes from blocks = 0.49 s = .
Wait, what?
#<Mocha::Mock: >? Shouldn't this read more like
ParameterFilterTest:: as it happens for every single other test in our test suite? It definitely should! That's actually great, as it tells us that there is really something wrong with the
test and the change of the reporting plugin just makes it worse.
What comes next is sheer luck. Well, that, and years of experience in yelling at computers.
We use
let(:klass) to define an object called
klass and this object is a
Mocha::Mock that we'll use in our tests later. Now
klass is a very common term in Ruby when talking about classes and needing to store them mostly because one can't use
class which is a keyword. Is something else in the stack using
klass and our
let is overriding that, making this whole thing explode?
It was! The moment we
replaced klass with klass1 (silly, I know, but there also was a
klass2 in that code, so it did fit), things started to work nicely.
I really liked
Tomer's comment in the PR:
"no idea why, but I am not going to dig into mocha to figure that out."
Turns out, I couldn't let (HAH!) the code rest and really wanted to understand what happened there.
What I didn't want to do is to debug the whole Foreman test stack, because it is massive.
So I started to write a minimal reproducer for the issue.
All starts with a
Gemfile, as we need a few dependencies:
gem 'rake'
gem 'mocha'
gem 'minitest', '~> 5.1', '< 5.11'
Then a
Rakefile:
require 'rake/testtask'
Rake::TestTask.new(:test) do t
t.libs << 'test'
t.test_files = FileList["test/**/*_test.rb"]
end
task :default => :test
And a test! I took the liberty to replace
ActiveSupport::TestCase with
Minitest::Test, as the test won't be using any Rails features and I wanted to keep my environment minimal.
require 'minitest/autorun'
require 'minitest/spec'
require 'mocha/minitest'
class ParameterFilterTest < Minitest::Test
extend Minitest::Spec::DSL
let(:klass) do
mock('Example').tap do k
k.stubs(:name).returns('Example')
end
end
def test_lol
assert klass
end
end
Well, damn, this passed! Is it Rails after all that breaks stuff? Let's add it to the
Gemfile!
$ vim Gemfile
$ bundle install
$ bundle exec rake test TESTOPTS=-v
#<Mocha::Mock:0x0000564bbfe17e98>#test_lol = 0.00 s = .
Wait, I didn't change anything and it's already failing?! Fuck! I mean, cool!
But the test isn't
minimal yet. What can we reduce?
let is just a fancy, lazy
def, right? So instead of
let(:klass) we should be able to write
def class and achieve a similar outcome
and drop that
Minitest::Spec.
require 'minitest/autorun'
require 'mocha/minitest'
class ParameterFilterTest < Minitest::Test
def klass
mock
end
def test_lol
assert klass
end
end
$ bundle exec rake test TESTOPTS=-v
/home/evgeni/Devel/minitest-wtf/test/parameter_filter_test.rb:5:in klass': Mocha methods cannot be used outside the context of a test (Mocha::NotInitializedError)
from /home/evgeni/Devel/minitest-wtf/vendor/bundle/ruby/3.0.0/gems/railties-6.1.4.1/lib/rails/test_unit/reporter.rb:68:in format_line'
from /home/evgeni/Devel/minitest-wtf/vendor/bundle/ruby/3.0.0/gems/railties-6.1.4.1/lib/rails/test_unit/reporter.rb:15:in record'
from /home/evgeni/Devel/minitest-wtf/vendor/bundle/ruby/3.0.0/gems/minitest-5.10.3/lib/minitest.rb:682:in block in record'
from /home/evgeni/Devel/minitest-wtf/vendor/bundle/ruby/3.0.0/gems/minitest-5.10.3/lib/minitest.rb:681:in each'
from /home/evgeni/Devel/minitest-wtf/vendor/bundle/ruby/3.0.0/gems/minitest-5.10.3/lib/minitest.rb:681:in record'
from /home/evgeni/Devel/minitest-wtf/vendor/bundle/ruby/3.0.0/gems/minitest-5.10.3/lib/minitest.rb:324:in run_one_method'
from /home/evgeni/Devel/minitest-wtf/vendor/bundle/ruby/3.0.0/gems/minitest-5.10.3/lib/minitest.rb:311:in block (2 levels) in run'
from /home/evgeni/Devel/minitest-wtf/vendor/bundle/ruby/3.0.0/gems/minitest-5.10.3/lib/minitest.rb:310:in each'
from /home/evgeni/Devel/minitest-wtf/vendor/bundle/ruby/3.0.0/gems/minitest-5.10.3/lib/minitest.rb:310:in block in run'
from /home/evgeni/Devel/minitest-wtf/vendor/bundle/ruby/3.0.0/gems/minitest-5.10.3/lib/minitest.rb:350:in on_signal'
from /home/evgeni/Devel/minitest-wtf/vendor/bundle/ruby/3.0.0/gems/minitest-5.10.3/lib/minitest.rb:337:in with_info_handler'
from /home/evgeni/Devel/minitest-wtf/vendor/bundle/ruby/3.0.0/gems/minitest-5.10.3/lib/minitest.rb:309:in run'
from /home/evgeni/Devel/minitest-wtf/vendor/bundle/ruby/3.0.0/gems/minitest-5.10.3/lib/minitest.rb:159:in block in __run'
from /home/evgeni/Devel/minitest-wtf/vendor/bundle/ruby/3.0.0/gems/minitest-5.10.3/lib/minitest.rb:159:in map'
from /home/evgeni/Devel/minitest-wtf/vendor/bundle/ruby/3.0.0/gems/minitest-5.10.3/lib/minitest.rb:159:in __run'
from /home/evgeni/Devel/minitest-wtf/vendor/bundle/ruby/3.0.0/gems/minitest-5.10.3/lib/minitest.rb:136:in run'
from /home/evgeni/Devel/minitest-wtf/vendor/bundle/ruby/3.0.0/gems/minitest-5.10.3/lib/minitest.rb:63:in block in autorun'
rake aborted!
Oh nice, this is even better! Instead of the mangled class name, we now get the very same error the Foreman tests aborted with,
plus a nice stack trace! But wait, why is it pointing at
railties? We're not loading that! Anyways, lets look at
railties-6.1.4.1/lib/rails/test_unit/reporter.rb, line 68
def format_line(result)
klass = result.respond_to?(:klass) ? result.klass : result.class
"%s#%s = %.2f s = %s" % [klass, result.name, result.time, result.result_code]
end
Heh, this is touching
result.klass, which we just messed up. Nice!
But quickly back to
railties What if we only add that to the
Gemfile, not full blown Rails?
gem 'railties'
gem 'rake'
gem 'mocha'
gem 'minitest', '~> 5.1', '< 5.11'
Yepp, same failure. Also happens with
require => false added to the line, so it seems
railties somehow injects itself into
rake even if nothing is using it?! "Cool"!
By the way, why are we still pinning
minitest to
< 5.11? Oh right, this was the
original reason to look into that whole topic. And, uh, it's pointing at
klass there already! 4 years ago!
So
lets remove that boundary and funny enough,
now tests are passing again, even if we use
klass!
Minitest 5.11 changed how
Minitest::Test is structured, and seems not to rely on
klass at that point anymore. And I guess Rails also changed a bit since the original pin was put in place four years ago.
I didn't want to go another rabbit hole, finding out what changed in Rails, but I did try with 5.0 (well, 5.0.7.2) to be precise, and the output with newer (>= 5.11) Minitest was interesting:
$ bundle exec rake test TESTOPTS=-v
Minitest::Result#test_lol = 0.00 s = .
It's leaking
Minitest::Result as
klass now, instead of
Mocha::Mock. So probably something along these lines was broken 4 years ago and triggered this pin.
What do we learn from that?
klass is cursed and shouldn't be used in places where inheritance and tooling might decide to use it for some reason- inheritance is cursed - why the heck are implementation details of Minitest leaking inside my tests?!
- tooling is cursed - why is
railties injecting stuff when I didn't ask it to?!
- dependency pinning is cursed - at least if you pin to avoid an issue and then forget about said issue for four years
- I like cursed things!
I've a set of Alesis M1Active 330 USB on my desk to listen to music.
They were relatively inexpensive (~100 ), have USB and sound pretty good for their size/price.
They were also sitting on my desk unused for a while, because the left speaker didn't produce any sound.
Well, almost any.
If you'd move the volume knob long enough you might have found a position where the left speaker would work a bit,
but it'd be quieter than the right one and stop working again after some time.
Pretty unacceptable when you want to listen to music.
Given the right speaker was working just fine and the left would work a bit when the volume knob is moved,
I was quite certain which part was to blame: the potentiometer.
So just open the right speaker (it contains all the logic boards, power supply, etc),
take out the broken potentiometer, buy a new one, replace, done.
Sounds easy?
Well, to open the speaker you gotta loosen 8 (!) screws on the back.
At least it's not glued, right?
Once the screws are removed you can pull out the back plate, which will bring the power supply,
USB controller, sound amplifier and cables, lots of cables: two pairs of thick cables, one to each driver,
one thin pair for the power switch and two sets of "WTF is this, I am not going to trace pinouts today",
one with a 6 pin plug, one with a 5 pin one.
Unplug all of these!
Yes, they are plugged, nice.
Nope, still no friggin' idea how to get to the potentiometer.
If you trace the "thin pair" and "WTF1" cables, you see they go inside a small wooden box structure.
So we have to pull the thing from the front?
Okay, let's remove the plastic part of the knob
Right, this looks like a potentiometer.
Unscrew it.
No, no need for a Makita wrench, I just didn't have anything else in the right size (10mm).
Still, no movement.
Let's look again from the inside!
Oh ffs, there are six more screws inside, holding the front.
Away with them!
Just need a very long PH1 screwdriver.
Now you can slowly remove the part of the front where the potentiometer is.
Be careful, the top tweeter is mounted to the front, not the main case and so is the headphone jack, without an obvious way to detach it.
But you can move away the front far enough to remove the small PCB with the potentiometer and the LED.
Great, this was the easy part!
The only thing printed on the potentiometer is "A10K".
10K is easy -- 10kOhm.
A?!
Wikipedia says "A" means "logarithmic", but only if made in the US or Asia.
In Europe that'd be "linear".
"B" in US/Asia means "linear", in Europe "logarithmic".
Do I need to tap the sign again?
(The sign is a print of XKCD#927.)
My multimeter says in this case it's something like logarithmic.
On the right channel anyway, the left one is more like a chopping board.
And what's this green box at the end?
Oh right, this thing also turns the power on and off.
So it's a power switch.
Where the fuck do I get a logarithmic 10kOhm stereo potentiometer with a power switch?
And then in the exact right size too?!
Of course not at any of the big German electronics pharmacies.
But AliExpress saves the day, again.
It's even the same color!
Soldering without pulling out the cable out of the case was a bit challenging,
but I've managed it and now have stereo sound again.
Yay!
PS: Don't operate this thing open to try it out. 230V are dangerous!
It s been over 20 months since the first COVID lockdown kicked in here in Northern Ireland and I started working from home. Even when the strict lockdown was lifted the advice here has continued to be If you can work from home you should work from home . I ve been into the office here and there (for new starts given you need to hand over a laptop and sort out some login details it s generally easier to do so in person, and I ve had a couple of whiteboard sessions that needed the high bandwidth face to face communication), but day to day is all from home.
