Bug testing, literally: a spider in the smart fan
My homemade bathroom fan stalled twice one morning. When I unplugged it, a spider crawled out. The fan has run slower ever since. This is what its own telemetry recorded.
It's an autonomous duct fan that learns temperature, humidity and light, and adjusts itself automatically against its baseline readings. If the humidity is too high, it leaves the fan on until it draws it out.
What the fan reports
The controller is a Pico 2 W. It switches the fan on and off (there is no speed control) and reads the fan's tachometer, so it knows how fast the fan is actually turning. Every 30 seconds, and immediately when something changes, it publishes a status message to my MQTT broker with the speed, humidity, temperature, light level, controller state and any fault. Home Assistant picks those up.
If the fan is switched on but the tachometer reads under 800 rpm, the controller turns it back off and reports fan stalled, with a counter. In my data, a healthy run sits around 4,100 rpm.
I was also recording that traffic with a packet capture, which is where most of the numbers below come from.
The morning it stopped
At 8:07:58 the light came on and the controller switched the fan on. Four seconds later the tachometer still read zero, so it raised fan stalled (0 rpm), stall 1/3 and cut power. At 8:18 the same thing happened again: stall 2/3.
At 8:20 I was troubleshooting with the agent, and we couldn't find anything technically wrong with it. So I went to troubleshoot the fan and the device itself. I unplugged it and plugged it back in, and a spider came crawling out of the fan.
I found a white spider on the breadboard, on the pins of the Pico and on the fan of the project. Two seconds after I took it apart, the spider was down the toilet, so there's no photo of the culprit.
The data shows that power cut at 8:20:58. The controller's uptime counter had reached 14,073 minutes, so it had been running without a restart since Sep 28. Once it was back, the next light-triggered start at 8:22 worked: the fan spun up within four seconds.
Running slow
With the spider gone, the fan spun again, but it has not returned to its old speed. Before Oct 8 every run held between about 4,000 and 4,180 rpm. After the spider was removed it held about 3,500 for the rest of that day, and about 3,190 the next morning. That is still well above the 800 rpm stall threshold, so the controller raised no fault. Only the speed history shows it. As of the last run (Oct 9, 7:58 AM), it hasn't recovered yet.
| Period | Runs | Median rpm | Range (10th to 90th pct) | Max |
|---|---|---|---|---|
| Before the stall (Sep 29 to Oct 8, 4 AM) | 20 | 4,086 | 4,014 to 4,178 | 4,396 |
| After the spider was removed, Oct 8 | 3 | 3,499 | 3,323 to 3,531 | 3,554 |
| After the spider was removed, Oct 9 | 1 | 3,187 | 3,115 to 3,275 | 3,293 |
The night before: a shower in the dark
Five hours before the stall, the fan was still running at full speed. At 2:58 AM humidity started climbing with the light essentially off, which looks like a shower in the dark. The controller started the fan on humidity alone, at full speed: median 4,086 rpm, peak 4,236. Humidity peaked at 97.3% at 3:02 AM. The run stopped at the controller's 60-minute maximum at 3:58, with humidity still at 68.4%. That was the last full-speed run in the data.
Key events
The whole sequence, in Eastern time:
| When (ET) | What happened |
|---|---|
| Sep 28, ~1:47 PM | Controller boots; it runs without a restart until Oct 8 |
| Oct 8, 2:58 AM | Humidity-only run, light off; humidity 61.4% to 97.3% |
| Oct 8, 3:58 AM | Run stops at the 60-minute maximum; last full-speed run |
| Oct 8, 8:07:58 AM | Light on, fan switched on, tachometer reads 14 rpm |
| Oct 8, 8:08:02 AM | Fault: fan stalled (0 rpm), stall 1/3 |
| Oct 8, 8:18:13 AM | Fault: stall 2/3 |
| Oct 8, 8:20:58 AM | I unplug it and plug it back in (boot reason power-on); a spider crawls out of the fan |
| Oct 8, 8:22:12 AM | Fan spins again, now slower; 3,293 rpm steady |
| Oct 8, 10:48 AM, 3:05 PM | Two 3-minute light runs, about 3,500 rpm |
| Oct 9, 7:58 AM | 39-minute shower run, humidity peak 95.9%; 3,187 rpm steady |
| Oct 9, 3:04 to 3:21 PM | Server hosting the broker reboots for an update; 16.6 minutes with no fan messages. Controller resets at 3:20:43 |
About the data
- Source: a packet capture of the fan's MQTT status messages (about one every 30 seconds), Sep 28 evening to Oct 9, 6:43 PM. 28,613 messages. The last fan run in that window was Oct 9 at 7:58 AM.
- Gap filled from Home Assistant: the capture for Oct 5, 6:04 PM to Oct 6, 6:10 PM was lost before it was copied off. That day's single run (48 minutes, 4,043 rpm) comes from Home Assistant's history instead.
- Outage: no data on Oct 9 from 3:04 to 3:21 PM while the broker's host rebooted.
- “Steady” speed means readings at least 60 seconds into a run, so spin-up does not pull the numbers down. The tachometer value is what the controller reports. I did not measure it separately.
Bug testing, literally
I learned that bug testing sometimes actually includes testing for literal bugs. This, for me, was a first.
Comments