strugee.net

This is week 10 of being at the Recurse Center.

Day 35

Arrived ~13:00, departed ~21:30, total time at RC 8h30m.

Decided (in the morning) to sleep in because honestly, I was just really behind on sleep.

Didn't do a whole lot today. Took care of the monthly pump.io release, but spent most of the day writing Driftless at 1,000 mph. In the evening (i.e. after the Iron Blogger meeting) I spent some time fixing ejabberd's configuration to use the new access control syntax (I'd rewritten the config a while back, but hadn't deployed it yet because it broke logins).

Day 36

Arrived ~10:40, departed ~23:40, total time at RC 13h0m.

Spent basically all day working on realtime.recurse.com. I (mostly) finished up the bits that watch the filesystem and dispatch events (including the "periodic" submission logic), then started in on an automatic update mechanism. I'm pretty pleased with how it's turning out - I think it's pretty elegant. And, it's secure - updates are required to be cryptographically signed by yours truly. Went out to Black Burger with a bunch of people before going to Fat Cat in the evening. Then came back, worked on the updater a little more, and went home.

Day 37

Arrived ~14:40, departed ~23:20, total time at RC 8h40m.

Overslept by accident this morning. Spent a bit of time in the afternoon dealing with email, then focused on realtime.recurse.com - basically I was just working on the autoupater I started yesterday. My Python is definitely improving!

I'm actually really pleased with the updater. It's pretty elegant, I think. Basically whenever the server sees a request coming from the client, it checks the User-Agent header to see if the client's out of date and, if so, sends back an X-Requires-Upgrade header. Upon receiving this header the client will go fetch version information, which it'll use to download and verify an update bundle cryptographically signed by me. Yay for secure updates, and yay for simplicity! (Note that this design basically just reuses the connections the client is already making to the server, so it doesn't have to poll for updates all the time.)

I also spent a couple hours talking with Mikhail, discussing a lot of things - ranging from how Node.js's event loop works to the is keyword in Python to static site generator architecture compared to dynamic site architecture.

Day 38

Arrived ~9:50, departed ~23:00, total time at RC 13h10m.

Woke up, completely naturally, around 7 AM despite going to sleep at 3 AM. This was so surprising - and this is a true story - that I thought I had woken up at 7 PM and missed the entire day, including Security Club, Abstract Salad Factory, and Thursday night presentations. I was really mad, honestly. But then I looked at my watch and realized that I was on 24-hour time but it didn't say "19:00" and also my alarms were in the future and my phone was in 24-hour time too and also Anja on Zulip said "?" when I said I'd slept through Security Club. Despite the overwhelming evidence in the end, though, I still had a weird feeling that it was 7 PM. So that's the story of how, for a good 5 or 10 minutes, I genuinely believed I'd slept through the entire day.

Once I got to RC, I spent the morning finally(!) merging in a bunch of upstream ejabberd.yml config changes to steevie's ejabberd configuration, which got me closer to fixing the awful spam problem I have. Then I went to Abstract Salad Factory, followed by Security Club. Then in the afternoon (and after presentations) I started reading FreeBSD documentation since that's what I'm running my new Tor relay on - as I discovered a couple days ago, my old one apparently got hung during boot and was consuming 100% CPU due to the kernel image being corrupted or something. I chose FreeBSD because a) it's a rock-solid system, b) it's a good opportunity to gain experience with administrating a BSD, and c) it increases the diversity of the Tor network. Also, had a conference call in the afternoon with the EFF and Paul from TA3M Seattle about TA3M Seattle joining the EFF's Electronic Frontier Alliance, which was exciting for everyone.

Friday

Arrived ~13:00, departed ~22:30, total time at RC 9h30m. As always, Friday doesn't count as a day because RC is technically not in session.

Didn't do a whole lot of coding. Spent a while helping Jason debug Datamost's 3.0.0 upgrade (which apparently broke uploads). Attended presentations for the RC Game Jam, then fixed the documentation that caused Jason's problems. Spent a little bit of time polishing the website and README, too.

In the evening, fixed people being banned from ejabberd MUCs, then proceeded to fix my spam problem. Whoooooo! Then I kept working on my Tor relay.

Executive summary

Like any week, this had moments where I wasn't very productive. But overall I think it was pretty good - I made a lot of progress on realtime.recurse.com (and improved my Python in the process), and I made a lot of progress on setting up my Tor relay again (and learned a bunch about FreeBSD in the process). Also, I fixed my ejabberd spam problem. I learned nothing from that, but thank god I did it because the spam problem was honestly awful. The one issue was that I just didn't do a very good job getting up and making it to checkins.

Total time at RC 52 hours 50 minutes; cumulative time 464 hours 50 minutes.

(Okay, so I miserably failed my blog-every-day thing. Shut up. Maybe next time I'll try every week or something... anyway.)

A couple of days ago I logged into the Tor relay I run to show someone the ARM graphs. I had a fair amount of traffic, so the graphs were fairly impressive, but I'm also in the habit of running apt-get update; apt-get upgrade every time I log into a server, so I did that too. To my surprise, I got a message telling me that there was a dependency problem with my kernel! So like the great sysadmin I am, I looked at such a fundamental system problem, shrugged my shoulders, and said, "oh, I should probably fix that". And then logged out.

Well, I did end up fixing it today. And boy, was it an adventure. My first step was to ignore the APT problems and edit my torrc, to reflect a) the fact that I'm not eligible for the AWS Free Tier anymore (so I needed to throttle bandwidth), b) my new email, and c) my new GPG key. With that being done, I knew that I could easily have the system fix dependency problems by doing a simple apt-get install -f. Easy!

Well, no. That tried to install some Linux kernel headers, which seemed all well and good, until I got this:

Unpacking linux-headers-3.2.0-90 (from .../linux-headers-3.2.0-90_3.2.0-90.128_all.deb) ...
dpkg: error processing /var/cache/apt/archives/linux-headers-3.2.0-90_3.2.0-90.128_all.deb (--unpack):
unable to create `/usr/src/linux-headers-3.2.0-90/arch/arm/plat-pxa/include/plat/dma.h.dpkg-new' (while processing `./usr/src/linux-headers-3.2.0-90/arch/arm/plat-pxa/include/plat/dma.h'): No space left on device
No apport report written because the error message indicates a disk full error
dpkg-deb: error: subprocess paste was killed by signal (Broken pipe)

Um, what? How am I out of free space? Okay, whatever. I knew that there were probably a lot of packages cached in /var/cache/apt/, including old, vulnerable packages that had been replaced by the unattended upgrades system. I did an ls, and found only about five .deb files - something must have been automatically cleaning that directory. I was getting a little worried now, but I nuked the files anyway and reran apt-get install -f. Same thing. Well, okay, maybe I didn't get rid of enough stuff? How much did I need?

$ df -h /
Filesystem      Size  Used Avail Use% Mounted on
/dev/xvda1      4.0G  2.2G  1.6G  59% /

At this point I'm in full-on "something-is-seriously-wrong-and-I-need-to-recover" mode. How was it possible that I had only used 59% of the filesystem, but dpkg was saying my disk was full? A little searching the internet later, I found the culprit:

$ df -i
Filesystem     Inodes  IUsed IFree IUse% Mounted on
/dev/xvda1     262144 257479  4665   99% /
udev            74758    377 74381    1% /dev
tmpfs           76179    259 75920    1% /run
none            76179      3 76176    1% /run/lock
none            76179      1 76178    1% /run/shm

I hadn't run out of disk space. But I had run out of inodes. (Isn't this supposed to happen to other people?)

I tried removing some stuff via APT, but that refused to do anything due to the dependency problems. My next thought was that there were probably a bunch of old processes running that were essentially holding a bunch of inodes hostage. I couldn't install debian-goodies, so I couldn't use checkrestart, but I improvised by looping over all running services in a for loop, and restarting them.

Still nothing.

I'm not proud of what I did next. But I was backed into a corner, so I did something only dpkg is supposed to do. I ran rm -r on a couple directories in /usr/src. And boy, it was like magic. Suddenly apt-get install -f worked like a charm. It started to upgrade a couple packages, rebuilding some GRUB configuration files... and then came to a screeching halt.

Setting up linux-headers-3.2.0-90-virtual (3.2.0-90.128) ...
dpkg: dependency problems prevent configuration of linux-headers-virtual:
linux-headers-virtual depends on linux-headers-3.2.0-68-virtual; however:
Package linux-headers-3.2.0-68-virtual is not installed.
dpkg: error processing linux-headers-virtual (--configure):
dependency problems - leaving unconfigured
No apport report written because the error message indicates its a followup error from a previous failure.
dpkg: dependency problems prevent configuration of linux-virtual:
linux-virtual depends on linux-headers-virtual (= 3.2.0.68.81); however:
Package linux-headers-virtual is not configured yet.
dpkg: error processing linux-virtual (--configure):
dependency problems - leaving unconfigured
No apport report written because the error message indicates its a followup error from a previous failure.
Errors were encountered while processing:
linux-headers-virtual
linux-virtual
E: Sub-process /usr/bin/dpkg returned an error code (1)

Are you kidding?? More errors?

Turns out that APT is essentially the only thing on this system that makes large changes to the filesystem. So the probability that APT would be the program to trigger the inode limit was pretty high. It started an upgrade run, then got interrupted in the middle by the "no space left on device" error, leaving the dependency tree in a state that we in the tech community call "100% totally screwed". (This is the technical term.)

I'll spare you the gory details, but I ended up trying to chase down packages in the Ubuntu archive, running ubuntu-support-status because I was wondering if the packages I was looking for actually weren't in the archive, because they were unsupported, using aptitude instead of apt-get (because aptitude's dependency resolver tends to be better), etc. Finally the solution turned out to be doing dpkg --install on the exact right .debs in the exact right order, which finally satisfied APT's dependency woes, allowed apt-get install -f to fix the configuration problems, and allowed the hundreds of packages which had been waiting for an upgrade to finally install. Whew!

Anyway, I need to upgrade the version of Ubuntu the system is on (currently it's 12.04.5 LTS), because Tor is out of date (among other reasons). However, since that will involve taking the system down for a reboot, I wanted to memorialize the following:

$ uptime
00:01:47 up 392 days, 17:15,  1 user,  load average: 0.05, 0.04, 0.05

Holy moly. This system is bordering on 400 days of uptime. That's over a year of continuous run time! Astonishing.

Wish me luck with this upgrade...

tl;dr: inode limits are killer.