Rust: Why does this code take a long time to run?

Programming Rust
1

Why does this code take a long time to run? It took 10-20s on multiple attempts by the Rust test runner.

(context: Sporadic, spurious "One of the tests timed out" errors using `exercism` CLI · Issue #6697 · exercism/exercism · GitHub)

// The code below is a stub. Just enough to satisfy the compiler.
// In order to pass the tests you can add-to or change any of this code.

// Duration in earth years.
#[derive(Debug)]
pub struct Duration(f64);

// Seconds in 365.25 days.
const EARTH_YEAR_SECONDS: f64 = 31557600.0;

impl From<u64> for Duration {
    fn from(s: u64) -> Self {
        Duration(s as f64 / EARTH_YEAR_SECONDS)
    }
}

pub trait Planet {
    // Default implementation.
    fn years_during(d: &Duration) -> f64 {
        // There's no way to access tuple struct fields by index --
        // e.g. `d.0` -- unlike for plane tuples :/
        let Duration(y) = d;
        y / Self::PERIOD
    }
    // Associated constant with unusable default implementation. This
    // means that the code will compile before you implement `PERIOD`
    // for a new `Planet`, as long as you don't use that planet.
    //
    // Can't use `unimplemented!` here, but `panic!` is ok.
    const PERIOD: f64 = panic!("TODO");
}

pub struct Mercury;
pub struct Venus;
pub struct Earth;
pub struct Mars;
pub struct Jupiter;
pub struct Saturn;
pub struct Uranus;
pub struct Neptune;

impl Planet for Mercury { const PERIOD: f64 = 0.2408467; }
impl Planet for Venus { const PERIOD: f64 = 0.61519726; }
impl Planet for Earth { const PERIOD: f64 = 1.0; }
impl Planet for Mars { const PERIOD: f64 = 1.8808158; }
impl Planet for Jupiter { const PERIOD: f64 = 11.862615; }
impl Planet for Saturn { const PERIOD: f64 = 29.447498; }
impl Planet for Uranus { const PERIOD: f64 = 84.016846; }
impl Planet for Neptune { const PERIOD: f64 = 164.79132; }
2

The Rust test-runner returned the error message “One of the tests timed out” when it failed.

3

Interesting. I should have time tomorrow to investigate. Nothing jumps out at me just by reading the code.

4

No, me neither. In this case it runs sometimes fast, but sometimes it has run slowly. It could be resources on the machines or various other things, but going from 1s to 20s seems extreme!

Thanks :)

5

stdout:

slug:          space-age
solution path: /mnt/exercism-iteration/
output path:   /mnt/exercism-iteration
WARNING: student did not upload Cargo.lock. This may cause build errors.
null

results.out:

WARNING: student did not upload Cargo.lock. This may cause build errors.

timeout: sending signal TERM to command 'cargo'

results.json:

  "version": 2,
  "status": "error",
  "message": "One of the tests timed out"
}

cargo.toml

edition = "2021"
name = "space-age"
version = "1.2.0"
6

Across 500 local runs, the max time for this space-age solution is 372ms (in docker). Which leads me to believe it has something to do with infra, which I can’t debug.

@ntc2 judging from your github issue, space-age wasn’t the only exercise you had this problem, right? Other exercises were also affected? In that case we shouldn’t spend too much time analyzing the code itself.

1 Like
7

Thanks for the research.

So the issue we have is that docker is just sitting on a server running solutions. That machine isn’t doing much else other than existing. So the thing we maybe need to work out is what needs to happen to a machine to make it unable to run those iterations in a performant time. Does Rust need some minimal CPU or memory that we’re not consistently able to give it maybe?

8

I’m not aware of such an inherent limitation, beyond what would be expected generally… if the rust compiler is allocated half the amount of CPU time, I’d expect the compilation to take twice as long. The memory may have a harder limit, but the memory usage of running docker locally is imperceptible for me. (< 100 MB)

9

Is there any way to gather data about this? How much resources were allocated to the process and how long it took? (I’m way out of my area of expertise here)

10

when I did some testing on docker to see how to reduce the size of the image, the timeout script acted very oddly.

But I may add, I have the same experience on Crystal, for a few weeks ago everything was fine, now it fails with time out of no reason.

11

Potentially, but I’m not sure what to log or how to do that really. Maybe someone else can chip in? (e.g. @IsaacG)

The only real change we’ve made is to upgrade to a newer ubuntu and docker host machine. We also doubled the size of the machine.

The thing with the Rust one is that the Rust Test Runner itself is timing out its own tests, which is sort of useful info, because it means the container is running and alive, but for some reason is taking a long time to run its tests. Which makes me wonder if the docker contain has sporadic resources at hand etc.

One possibility is that newer version of Docker has some defaults that are restricting things sometimes somehow.

12

Wha…? What’s going on?

I know nothing about Rust and minimal amounts about Docker. You can wrap your process in the time bash built-in to get wall time and system time. When I use systemd-run to run commands in a cgroup, when the command exits it logs (CPU?) time of the process to the journal.

You can use Prometheus or even a shell script to grab a processes memory usage (virtual, working set) every N seconds and dump that into a logfile. You can possibly write a wrapper script that helps launch your test running and set up monitoring alongside it.

Docker itself might have some tools/extensions/thingies that help log resource usage. I would Google for that prior to building your own. A quick search shows there’s a docket stats command and a blog entry about it. That’s probably a good starting point.

I haven’t been following this thread so that’s probably all pretty vague. If there’s more specific questions or help wanted from me, I’m happy to try to figure out what’s going on with things :smile: Though not this week; I’m currently on call.

13

@remise correct, I experienced the spurious timeout on two different exercises, so I doubt the problem has anything to do with the specific code I’m submitting. I’m using the exercism submit command line to submit my exercises, which might be relevant.

I deleted the other “timed out” iteration (because I wrongly thought that would allow me to resubmit the code without changing it) but it must have been essentially this, the next iteration I submitted (for the Rust “clock” exercise):

#[derive(Debug, PartialEq)]
pub struct Clock {
    hours: i32,
    minutes: i32,
}

impl Clock {
    pub fn new(hours: i32, minutes: i32) -> Self {
        let hours = (hours + minutes.div_euclid(60)).rem_euclid(24);
        let minutes = minutes.rem_euclid(60);
        Clock { hours: hours, minutes: minutes }
    }

    pub fn add_minutes(&self, minutes: i32) -> Self {
        Clock::new(self.hours, self.minutes + minutes)
    }
}

use std::fmt;
impl std::fmt::Display for Clock {
    fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
        write!(f, "{:02}:{:02}", self.hours, self.minutes)
    }
}
14

I finally got bit by the passed then failed phenomenon. My first iteration of Phone Number passed in the browser. It was an embarrassingly bad solution. My second iteration failed in the browser with the “Failed to upload Cargo.lock”, so I submitted via CLI with Cargo.toml. It passed, then failed. Same for the third try submitted from the CLI with Cargo.toml and Cargo.lock, again with the “Failed to upload Cargo.lock”. So I unpublished my embarrassing iteration. I go cry now…

Edit: I Was able to successfully get a couple more iterations accepted by the editor. I wipe tears from face now.