Truffleruby: Wrong Process time constants on macOS

[felixbuenemann]

It looks like the macOS release of truffleruby 1.1.0-rc16 uses time.h / clock_gettime constant values from Linux:

truffleruby-1.0.0-rc16 :001 > Process::CLOCK_MONOTONIC
 => 1
truffleruby-1.0.0-rc16 :002 > Process.clock_gettime Process::CLOCK_MONOTONIC
 => 101079.534420271
truffleruby-1.0.0-rc16 :003 > Process.clock_gettime 6
 => 181875.392374
truffleruby-1.0.0-rc16 :004 >

Compared to ruby-2.6.2:

2.6.1 :001 > Process::CLOCK_MONOTONIC
 => 6
2.6.1 :002 > Process.clock_gettime Process::CLOCK_MONOTONIC
 => 181922.081266
2.6.1 :003 > Process.clock_gettime 6
 => 181928.064831
2.6.1 :004 >

Tested in macOS 10.14.4 x86-64 / Xcode 10.2.1 with truffleruby-1.0.0-rc16 installed by rvm 1.29.7.

[felixbuenemann]

For reference, here's a comparison of the constant values on MRI 2.6.1:

Script:

ruby -e 'pp Process.constants.select{|i| i.match? /^CLOCK_/}.map{|i| [Process.const_get(i), i] }.sort.to_h.invert'

Linux 4.4.0 (Ubuntu 16.04.6):

{:CLOCK_REALTIME=>0,
 :CLOCK_MONOTONIC=>1,
 :CLOCK_PROCESS_CPUTIME_ID=>2,
 :CLOCK_THREAD_CPUTIME_ID=>3,
 :CLOCK_MONOTONIC_RAW=>4,
 :CLOCK_REALTIME_COARSE=>5,
 :CLOCK_MONOTONIC_COARSE=>6,
 :CLOCK_BOOTTIME=>7,
 :CLOCK_REALTIME_ALARM=>8,
 :CLOCK_BOOTTIME_ALARM=>9}

Darwin 18.5.0 (macOS 10.14.4):

{:CLOCK_REALTIME=>0,
 :CLOCK_MONOTONIC_RAW=>4,
 :CLOCK_MONOTONIC_RAW_APPROX=>5,
 :CLOCK_MONOTONIC=>6,
 :CLOCK_UPTIME_RAW=>8,
 :CLOCK_UPTIME_RAW_APPROX=>9,
 :CLOCK_PROCESS_CPUTIME_ID=>12,
 :CLOCK_THREAD_CPUTIME_ID=>16}

[felixbuenemann]

It looks like CLOCK_MONOTONIC is returning CLOCK_UPTIME_RAW or _APPROX:

truffleruby-1.0.0-rc16 :001 > Process.clock_gettime Process::CLOCK_MONOTONIC
 => 103165.538619266
truffleruby-1.0.0-rc16 :002 > Process.clock_gettime 6
 => 183966.323637
truffleruby-1.0.0-rc16 :003 > Process.clock_gettime 8
 => 103183.579113542
truffleruby-1.0.0-rc16 :004 >

2.6.1 :001 > Process.clock_gettime Process::CLOCK_MONOTONIC
 => 184179.524059
2.6.1 :002 > Process.clock_gettime 6
 => 184186.647761
2.6.1 :003 > Process.clock_gettime 8
 => 103400.46151786
2.6.1 :004 > Process.clock_gettime Process::CLOCK_UPTIME_RAW
 => 103406.63288545
2.6.1 :005 > Process.clock_gettime Process::CLOCK_UPTIME_RAW_APPROX
 => 103412.581097134
2.6.1 :006 >

[eregon]

Thank you for the report.

We currently treat CLOCK_MONOTONIC and CLOCK_REALTIME specially and use Java's System.nanoTime() and System.currentTimeMillis() for those, instead of clock_gettime():
https://github.com/oracle/truffleruby/blob/04afba28d4ab1bdbfd8d92027f1ccc48b9a50bcb/src/main/ruby/core/process.rb#L170-L178
So maybe Java's System.nanoTime() doesn't correspond to CLOCK_MONOTONIC?

The fact you get 1 instead of 6 for Process::CLOCK_MONOTONIC on macOS definitely seems like a bug though, because as far I can see, we set Process::CLOCK_MONOTONIC to 6 on macOS:
https://github.com/oracle/truffleruby/blob/04afba28d4ab1bdbfd8d92027f1ccc48b9a50bcb/src/main/java/org/truffleruby/platform/darwin/DarwinNativeConfiguration.java#L601

@felixbuenemann Do you know if this worked better in a previous release, e.g., 1.0.0-rc15?
Could you run the command you posted above on TruffleRuby on macOS?

rvm use truffleruby
ruby -e 'pp Process.constants.select{|i| i.match? /^CLOCK_/}.map{|i| [Process.const_get(i), i] }.sort.to_h.invert'

At least on Linux, I get consistent results with MRI, but I don't have a macOS machine available to test.

[felixbuenemann]

@felixbuenemann Do you know if this worked better in a previous release, e.g., 1.0.0-rc15?

No, I didn't test this on previous releases. But if you have a specific version I should check I can install it through rvm.

Could you run the command you posted above on TruffleRuby on macOS?

{:CLOCK_MONOTONIC=>1,
 :CLOCK_REALTIME=>2,
 :CLOCK_THREAD_CPUTIME_ID=>3,
 :CLOCK_MONOTONIC_RAW_ID=>4}

Btw. looks like the PP module is not auto-required in TruffleRuby, so I had to use ruby -rpp -e ….

[eregon]

@felixbuenemann I'm starting to think this is due to a bug of RVM (for instance, https://github.com/rvm/rvm/issues/4633 seems highly related), and that you are actually running with a much older version of TruffleRuby.
Could you show your ruby -v after switching to truffleruby in RVM?

For instance, ruby -e 'pp 45' does work with 1.0.0-rc16.

Also, @chrisseaton ran 1.0.0-rc16 with rbenv on macOS and got the correct result (same as you show above for MRI):

{:CLOCK_REALTIME=>0,
 :CLOCK_MONOTONIC_RAW=>4,
 :CLOCK_MONOTONIC_RAW_APPROX=>5,
 :CLOCK_MONOTONIC=>6,
 :CLOCK_UPTIME_RAW=>8,
 :CLOCK_UPTIME_RAW_APPROX=>9,
 :CLOCK_PROCESS_CPUTIME_ID=>12,
 :CLOCK_THREAD_CPUTIME_ID=>16}

That bug is hopefully fixed in latest RVM.
Therefore could you uninstall all truffleruby versions installed with RVM, then rvm get head and rvm install truffleruby? I think that should solve it.

[felixbuenemann]

I'll check that later today. I'm not using rvm head atm because the rvm update seems broken in head and it tries to update rvm on each invocation, but that shouldn't stop me from installing rubies with rvm head.

[eregon]

RVM stable is quite old (Jan 3, 2019) and contains the fairly old TruffleRuby 1.0.0-rc10:
https://github.com/rvm/rvm/blob/stable/config/db

I'm not using rvm head atm because the rvm update seems broken in head and it tries to update rvm on each invocation

In such a case I would recommend using ruby-build or ruby-install, they are much more reliable in my experience. It would be good to report that bug to RVM, though.

It's also possible to install manually, that's just downloading, extracting and running lib/truffle/post_install_hook.sh as described in https://github.com/oracle/truffleruby/blob/master/doc/user/standalone-distribution.md#testing-truffleruby-in-ci.

[felixbuenemann]

It looks like you're right about the rvm bug, because ruby -v shows truffleruby 1.0.0-rc10, like ruby 2.4.4, GraalVM CE Native [x86_64-darwin], even though the irb prompt says truffleruby-1.0.0-rc16 :001 >.

I explicitly installed through rvm install truffleruby-1.0.0-rc16 which usually works, even if rvm doesn't know about that version yet.

I checked ~/.rvm/user/md5 and it contained the following line:

https://github.com/oracle/truffleruby/releases/download/vm-1.0.0-rc10/truffleruby-1.0.0-rc10-macos-amd64.tar.gz=bba618b4483b79eebf9f0e7af4078502

After updating to rvm head it is trying to install the right version with rvm reinstall truffleruby-1.0.0-rc16, however install runs into an endless loop in what appears to be __list_remote_all() of ~/.rvm/src/rvm/scripts/functions/utility_system, since it looks like it can call continue without ever incrementing the iterator.

I'll try to fix that bug in rvm and then come back to this issue.

[felixbuenemann]

I've been busy with other stuff, so I haven't yet been able to prepare the PR with the RVM bugfix mentioned, but the problem described here was caused by an outdated truffle ruby version.

[eregon]

I tried using a slightly older RVM and installing the latest release (19.0.0), and that works for me in Docker. So I think the fix for https://github.com/rvm/rvm/issues/4633 fixed the issue you had with the wrong version.

For the record, here is the Dockerfile I used (run in the root of the RVM repo at commit 06914eaf):

FROM ubuntu:18.04

ENV DEBIAN_FRONTEND=noninteractive

RUN apt-get update
RUN apt-get install -y locales
RUN locale-gen en_US.UTF-8
ENV LANG=en_US.UTF-8

RUN apt-get install -y curl git libssl-dev make clang llvm libc++-dev
RUN apt-get install -y tzdata zlib1g-dev

WORKDIR /test
RUN useradd -ms /bin/bash test
RUN chown test /test
USER test

ADD . rvm
RUN cd rvm && ./install

ENV RVM_SCRIPT=/home/test/.rvm/scripts/rvm
RUN bash -c 'source $RVM_SCRIPT && rvm --version'
RUN bash -c 'source $RVM_SCRIPT && rvm autolibs disable'
RUN bash -c 'source $RVM_SCRIPT && rvm list'
RUN bash -c 'source $RVM_SCRIPT && rvm install truffleruby-19.0.0'

RUN $HOME/.rvm/rubies/truffleruby-19.0.0/bin/truffleruby --version

RUN bash -c 'source $RVM_SCRIPT && rvm list'
RUN bash -c 'source $RVM_SCRIPT && ruby --version'

RUN bash -c 'source $RVM_SCRIPT && rvm use truffleruby-19.0.0 && ruby --version'

@felixbuenemann Could you file an issue on the RVM tracker with the __list_remote_all problem?

[felixbuenemann]

The bug I‘m talking about can only happen on macOS and only outside Travis CI.

I have a bugfix locally, I just haven't come around to preparing the PR yet.

[felixbuenemann]

For reference the endless loop bugfix is rvm/rvm#4703.