Example from README wrong about time-precision? #219

kaspergrubbe · 2018-07-08T19:11:14Z

On my system, the two examples provides different output, is that on purpose?

time = (Time.now.to_r * 1000).to_i
# A faster, albeit less readable alternative:
# time = Process.clock_gettime(Process::CLOCK_MONOTONIC, :millisecond)

And running it:

(Time.now.to_r * 1000).to_i
#=> 1531077037130

Process.clock_gettime(Process::CLOCK_MONOTONIC, :millisecond)
#=> 977363055

kaspergrubbe · 2018-07-09T01:43:25Z

Also, the only way I can get InfluxDB to accept nanoseconds are by using Time#nsec.

Here is my test:

require 'influxdb'

client = InfluxDB::Client.new(influxdb_config['database'],
  url: influxdb_config['url'],
  username: influxdb_config['username'],
  password: influxdb_config['password'],
  async: false,
  time_precision: 'ns',
)

database_name = "rails_test_#{Time.now.to_i}"
client.write_point(database_name, {
  values:    {value: 1},
  tags:      {type: 'time_now_utc'},
  timestamp: (Time.now.utc.to_r * 10**6).to_i,
})
# => #<Net::HTTPNoContent 204 No Content readbody=true>

client.write_point(database_name, {
  values:    {value: 1},
  tags:      {type: 'time_now'},
  timestamp: (Time.now.to_r * 10**6).to_i,
})
# => #<Net::HTTPNoContent 204 No Content readbody=true>

client.write_point(database_name, {
  values:    {value: 1},
  tags:      {type: 'process'},
  timestamp: Process.clock_gettime(Process::CLOCK_MONOTONIC, :nanosecond),
})
# => #<Net::HTTPNoContent 204 No Content readbody=true>

time = Time.now
client.write_point(database_name, {
  values:    {value: 1},
  tags:      {type: 'time_nsec'},
  timestamp: "#{time.to_i}#{time.nsec}".to_i,
})
# => #<Net::HTTPNoContent 204 No Content readbody=true>

pp client.query "SELECT * FROM #{database_name}"
# => [{"name"=>"rails_test_1531100259",
#  "tags"=>nil,
#  "values"=>
#   [{"time"=>"1970-01-12T13:57:09.938726Z", "type"=>"process", "value"=>1},
#    {"time"=>"1970-01-18T17:18:20.299806123Z", "type"=>"time_now_utc", "value"=>1},
#    {"time"=>"1970-01-18T17:18:20.304718964Z", "type"=>"time_now", "value"=>1},
#    {"time"=>"2018-07-09T01:38:36.56181Z", "type"=>"time_nsec", "value"=>1}]}]

vassilevsky · 2018-07-09T08:03:59Z

Interesting. Could you post details about your OS and Ruby build?

kaspergrubbe · 2018-07-09T08:18:53Z

Sure, I am on OSX Sierra 10.12 using Ruby 2.4.1 installed through rbenv, and with the following configure_args:

" '--prefix=/Users/kaspergrubbe/.rbenv/versions/2.4.1' '--with-openssl-dir=/usr/local/opt/openssl' '--with-readline-dir=/usr/local/opt/readline' 'CC=clang' 'CFLAGS=-march=native -O3 -pipe -fomit-frame-pointer -O3 -Wno-error=shorten-64-to-32 -march=native -O3 -pipe -fomit-frame-pointer' 'LDFLAGS=-L/Users/kaspergrubbe/.rbenv/versions/2.4.1/lib ' 'CPPFLAGS=-I/Users/kaspergrubbe/.rbenv/versions/2.4.1/include '"

Please tell me if anything else is relevant.

kaspergrubbe · 2018-07-09T08:24:44Z

From a Linux machine running Gentoo, with Ruby 2.3.3 compiled the following way:

" '--prefix=/usr' '--build=x86_64-pc-linux-gnu' '--host=x86_64-pc-linux-gnu' '--mandir=/usr/share/man' '--infodir=/usr/share/info' '--datadir=/usr/share' '--sysconfdir=/etc' '--localstatedir=/var/lib' '--libdir=/usr/lib64' '--program-suffix=23' '--with-soname=ruby23' '--docdir=/usr/share/doc/ruby-2.3.3' '--enable-shared' '--enable-pthread' '--disable-rpath' '--without-ext=,tk' '--disable-jemalloc' '--disable-socks' '--disable-install-doc' '--enable-ipv6' '--disable-debug' '--enable-option-checking=no' 'build_alias=x86_64-pc-linux-gnu' 'host_alias=x86_64-pc-linux-gnu' 'CFLAGS=-march=core2 -O2 -pipe -fno-strict-aliasing' 'LDFLAGS=-Wl,-O1 -Wl,--as-needed -Wl,--hash-style=gnu' 'CPPFLAGS=' 'CXXFLAGS=-march=core2 -O2 -pipe -fno-strict-aliasing'"

I see the same:

[{"name"=>"rails_test_1531124585",
  "tags"=>nil,
  "values"=>
   [{"time"=>"1970-01-18T17:18:44.590248149Z", "type"=>"time_now_utc", "value"=>1},
    {"time"=>"1970-01-18T17:18:44.594110677Z", "type"=>"time_now", "value"=>1},
    {"time"=>"1970-07-23T01:25:09.073080319Z", "type"=>"process", "value"=>1},
    {"time"=>"2018-07-09T08:23:26.299737598Z", "type"=>"time_nsec", "value"=>1}]}]

kaspergrubbe · 2018-07-09T08:29:03Z

They are both connected to the same InfluxDB server and they are connecting through http, and they are both using the gem version 0.5.3.

The InfluxDB is running version 1.5.4 with the docker-image influxdb:1.5.4-alpine with the docker-compose-file:

version: "3"

services:
  influxdb:
    image: influxdb:1.5.4-alpine
    volumes:
      - /root/influxdb-data:/var/lib/influxdb
    environment:
      - INFLUXDB_DB=rails-production

dmke · 2018-07-09T08:48:12Z

Sorry for the delayed response, I can reproduce this on my machine as well:

irb(main):001:0> puts Process.clock_gettime(Process::CLOCK_MONOTONIC, :millisecond), (Time.now.to_r*1000).to_i
1597049
1531125710121
=> nil

Looking at clock_gettime(2), it lists CLOCK_MONOTONIC as

monotonic time since some unspecified starting point

The FreeBSD version of clock_gettime(2) doesn't specify this, but my guess it, the follow POSIX as well :-)

So, the sample in the readme is clearly wrong.

Thanks for reporting this. I will clean it up later when I'm back home.

kaspergrubbe · 2018-07-09T09:15:01Z

@dmke No worries about the "delay", I went to bed and had a response when I woke up, so thanks! 👍 Any input is very appreciated.

I see different results based on whether or not #write_point is supplied with precision or not.

This is my current script:

require 'rbconfig'
puts [RbConfig::CONFIG['MAJOR'], RbConfig::CONFIG['MINOR'], RbConfig::CONFIG['TEENY']].join('.')
puts RbConfig::CONFIG['configure_args']

influxdb_config = Rails.application.config_for(Rails.env.development? || Rails.env.test? ? :influxdb_local : :influxdb)

InfluxDB::Client.new(influxdb_config['database'],
  url: influxdb_config['url'],
  username: influxdb_config['username'],
  password: influxdb_config['password'],
  async: true,
  time_precision: 'ms',
)

database_name = "rails_test_#{Time.now.to_i}"
Rails.configuration.influxdb_client.write_point(database_name, {
  values:    {value: 1},
  tags:      {type: 'time_now_to_r_utc'},
  timestamp: (Time.now.utc.to_r * 1000).to_i,
})

Rails.configuration.influxdb_client.write_point(database_name, {
  values:    {value: 1},
  tags:      {type: 'time_to_r_now'},
  timestamp: (Time.now.to_r * 1000).to_i,
})

Rails.configuration.influxdb_client.write_point(database_name, {
  values:    {value: 1},
  tags:      {type: 'time_to_r_now_with_precision'},
  timestamp: (Time.now.to_r * 1000).to_i,
}, 'ms')

Rails.configuration.influxdb_client.write_point(database_name, {
  values:    {value: 1},
  tags:      {type: 'time_to_f_now'},
  timestamp: (Time.now.to_f * 1000).to_i,
})

Rails.configuration.influxdb_client.write_point(database_name, {
  values:    {value: 1},
  tags:      {type: 'time_to_f_now_with_precision'},
  timestamp: (Time.now.to_f * 1000).to_i,
}, 'ms')

Rails.configuration.influxdb_client.write_point(database_name, {
  values:    {value: 1},
  tags:      {type: 'process'},
  timestamp: Process.clock_gettime(Process::CLOCK_MONOTONIC, :millisecond),
})

Rails.configuration.influxdb_client.write_point(database_name, {
  values:    {value: 1},
  tags:      {type: 'process_with_precision'},
  timestamp: Process.clock_gettime(Process::CLOCK_MONOTONIC, :millisecond),
}, 'ms')

time = Time.now
Rails.configuration.influxdb_client.write_point(database_name, {
  values:    {value: 1},
  tags:      {type: 'time_nsec'},
  timestamp: "#{time.to_i}#{time.nsec}".to_i,
})

sleep(10)
pp Rails.configuration.influxdb_client.query "SELECT * FROM #{database_name}"

And the output is this:

[{"name"=>"rails_test_1531127564",
  "tags"=>nil,
  "values"=>
   [{"time"=>"1970-01-01T00:00:01.027883903Z", "type"=>"process", "value"=>1},
    {"time"=>"1970-01-01T00:25:31.127564704Z", "type"=>"time_now_to_r_utc", "value"=>1},
    {"time"=>"1970-01-01T00:25:31.127564704Z", "type"=>"time_to_r_now", "value"=>1},
    {"time"=>"1970-01-01T00:25:31.127564705Z", "type"=>"time_to_f_now", "value"=>1},
    {"time"=>"1970-01-12T21:31:23.903Z", "type"=>"process_with_precision", "value"=>1},
    {"time"=>"2018-07-09T09:12:44.705Z", "type"=>"time_to_f_now_with_precision", "value"=>1},
    {"time"=>"2018-07-09T09:12:44.705Z", "type"=>"time_to_r_now_with_precision", "value"=>1},
    {"time"=>"2018-07-09T09:12:44.705818Z", "type"=>"time_nsec", "value"=>1}]}]

Sorry if I have misunderstood the documentation.

dmke · 2018-07-10T18:24:56Z

It is actually Process::CLOCK_REALTIME, which gets the current time without the overhead of constructing a Time instance. I've corrected that in the readme.

Regarding

I see different results based on whether or not #write_point is supplied with precision or not.

That's because you're using async: true. The async writer currently ignores its precision argument. There's an open issue (#211, you already discovered it), which I hope to revisit in the next days (I'm currently abnormally busy, though).

kaspergrubbe mentioned this issue Jul 9, 2018

RFC: Timestamp points before queuing to preserve original time #211

Closed

dmke closed this as completed in d616325 Jul 10, 2018

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Example from README wrong about time-precision? #219

Example from README wrong about time-precision? #219

kaspergrubbe commented Jul 8, 2018

kaspergrubbe commented Jul 9, 2018 •

edited

Loading

vassilevsky commented Jul 9, 2018

kaspergrubbe commented Jul 9, 2018 •

edited

Loading

kaspergrubbe commented Jul 9, 2018 •

edited

Loading

kaspergrubbe commented Jul 9, 2018 •

edited

Loading

dmke commented Jul 9, 2018

kaspergrubbe commented Jul 9, 2018

dmke commented Jul 10, 2018

Example from README wrong about time-precision? #219

Example from README wrong about time-precision? #219

Comments

kaspergrubbe commented Jul 8, 2018

kaspergrubbe commented Jul 9, 2018 • edited Loading

vassilevsky commented Jul 9, 2018

kaspergrubbe commented Jul 9, 2018 • edited Loading

kaspergrubbe commented Jul 9, 2018 • edited Loading

kaspergrubbe commented Jul 9, 2018 • edited Loading

dmke commented Jul 9, 2018

kaspergrubbe commented Jul 9, 2018

dmke commented Jul 10, 2018

kaspergrubbe commented Jul 9, 2018 •

edited

Loading

kaspergrubbe commented Jul 9, 2018 •

edited

Loading

kaspergrubbe commented Jul 9, 2018 •

edited

Loading

kaspergrubbe commented Jul 9, 2018 •

edited

Loading