Corroborate early unic-datetime measurement results

[filmil]

Continuing from unicode-org/rust-discuss#13, so that we keep rust-discuss a high-level discussion.

[zbraniecki]

To perform the measurements on this crate:

cd ~/projects/unic-datetime
git co f2169e6
cargo run --example test --features binary --release // us: 24
git co master
mkdir data
cd data
git clone https://github.com/unicode-cldr/cldr-dates-modern
cd ../
cargo run --example dynamic --features binary --release // us: 150
cargo run --example binary --features binary --release // us: 73

[filmil]

@zbraniecki

OK, worked after the setup with the data/ dir.

I got:

cargo run --example dynamic --features binary --release // us: 227
cargo run --example binary --features binary --release // us: 160

Does this help you any?

[zbraniecki]

Can you try with intl-measurements to compare to your results for ICU?

cd ~/projects/test/intl-measurements
cd icu
make date
./date // time: 843 us
cd ../unic/datetime
cargo run --release // us: 154
nvim ./src/main.rs // switch to json = false
cargo run --release // us: 69

[filmil]

ICU bit, working on the rest. Looks like there is quite a bit of startup overhead on my machine, so you may want to account for that . Also, it remains quite a bit slower for this workload than what you have.

┬─[fmil@fmil1:~/code/intl-measurements/icu]─[03:39:48 PM]
│ (g/b:master)
╰─>$ make date
c++ -O3 -o date date.cpp `pkg-config --libs --cflags icu-uc icu-io icu-i18n`
┬─[fmil@fmil1:~/code/intl-measurements/icu]─[03:39:59 PM]
│ (g/b:master)
╰─>$ ./date
time: 84056 us
┬─[fmil@fmil1:~/code/intl-measurements/icu]─[03:40:02 PM]
│ (g/b:master)
╰─>$ ./date
time: 3438 us
┬─[fmil@fmil1:~/code/intl-measurements/icu]─[03:40:11 PM]
│ (g/b:master)
╰─>$ ./date
time: 3340 us
┬─[fmil@fmil1:~/code/intl-measurements/icu]─[03:40:12 PM]
│ (g/b:master)
╰─>$ ./date
time: 3285 us
┬─[fmil@fmil1:~/code/intl-measurements/icu]─[03:40:13 PM]
│ (g/b:master)
╰─>$ ./date
time: 3413 us
┬─[fmil@fmil1:~/code/intl-measurements/icu]─[03:40:14 PM]
│ (g/b:master)
╰─>$ ./date
time: 3400 us
┬─[fmil@fmil1:~/code/intl-measurements/icu]─[03:40:22 PM]
│ (g/b:master)
╰─>$ 

[filmil]

Next.

┬─[fmil@fmil1:~/code/intl-measurements/unic/datetime]─[03:42:05 PM]
│ (g/b:master)
╰─>$ cargo run --release
    Updating git repository `https://github.com/zbraniecki/unic-datetime`
    Updating crates.io index
   Compiling proc-macro2 v1.0.7
   Compiling unicode-xid v0.2.0
   Compiling syn v1.0.13
   Compiling serde v1.0.104
   Compiling byteorder v1.3.2
   Compiling ryu v1.0.2
   Compiling itoa v0.4.4
   Compiling quote v1.0.2
   Compiling serde_derive v1.0.104
   Compiling bincode v1.2.1
   Compiling serde_json v1.0.44
   Compiling unic-datetime v0.1.0 (https://github.com/zbraniecki/unic-datetime#cd08dff9)
   Compiling datetime-test v0.1.0 (/usr/local/google/home/fmil/code/intl-measurements/unic/datetime)
    Finished release [optimized] target(s) in 29.43s
     Running `target/release/datetime-test`
us: 255

[filmil]

Last bit:

╰─>$ cargo run --release
   Compiling datetime-test v0.1.0 (/usr/local/google/home/fmil/code/intl-measurements/unic/datetime)
    Finished release [optimized] target(s) in 0.72s
     Running `target/release/datetime-test`
us: 136
┬─[fmil@fmil1:~/code/intl-measurements/unic/datetime]─[03:43:47 PM]
│ (g/b:master)
╰─>$ cargo run --release
    Finished release [optimized] target(s) in 0.02s
     Running `target/release/datetime-test`
us: 112
┬─[fmil@fmil1:~/code/intl-measurements/unic/datetime]─[03:43:54 PM]
│ (g/b:master)
╰─>$ cargo run --release
    Finished release [optimized] target(s) in 0.04s
     Running `target/release/datetime-test`
us: 177
┬─[fmil@fmil1:~/code/intl-measurements/unic/datetime]─[03:43:55 PM]
│ (g/b:master)
╰─>$ 

[filmil]

HTH

[zbraniecki]

Yep, so your results seem to be:

1. ICU: ~3400 us
2. UNIC with JSON: ~255 us
3. UNIC with bin res: ~150 us

That seems to reproduce my performance differences.

Next it would be good to investigate why is Rust version so much faster.

[zbraniecki]

@sffc ? @srl295? @FrankYFTang? thoughts?

[filmil]

quick gprof report --- don't read too much into it, I had to change the initial code and compilation results.

		     Call graph (explanation follows)


granularity: each sample hit covers 2 byte(s) for 99.98% of 0.01 seconds

index % time    self  children    called     name
                                                 <spontaneous>
[1]    100.0    0.00    0.01                 main [1]
                0.00    0.01       1/1           show() [4]
-----------------------------------------------
                0.01    0.00 1000000/1000000     icu_64::UnicodeString::UnicodeString() [3]
[2]    100.0    0.01    0.00 1000000         icu_64::Replaceable::Replaceable() [2]
                0.00    0.00 1000000/1000000     icu_64::UObject::UObject() [35]
-----------------------------------------------
                0.00    0.01 1000000/1000000     show() [4]
[3]    100.0    0.00    0.01 1000000         icu_64::UnicodeString::UnicodeString() [3]
                0.01    0.00 1000000/1000000     icu_64::Replaceable::Replaceable() [2]
-----------------------------------------------
                0.00    0.01       1/1           main [1]
[4]    100.0    0.00    0.01       1         show() [4]
                0.00    0.01 1000000/1000000     icu_64::UnicodeString::UnicodeString() [3]
                0.00    0.00       1/1           std::common_type<std::chrono::duration<long, std::ratio<1l, 1000000000l> >, std::chrono::duration<long, std::ratio<1l, 1000000000l> > >::type std::chrono::operator-<std::chrono::_V2::steady_clock, std::chrono::duration<long, std::ratio<1l, 1000000000l> >, std::chrono::duration<long, std::ratio<1l, 1000000000l> > >(std::chrono::time_point<std::chrono::_V2::steady_clock, std::chrono::duration<long, std::ratio<1l, 1000000000l> > > const&, std::chrono::time_point<std::chrono::_V2::steady_clock, std::chrono::duration<long, std::ratio<1l, 1000000000l> > > const&) [43]
                0.00    0.00       1/1           std::enable_if<std::chrono::__is_duration<std::chrono::duration<long, std::ratio<1l, 1000000l> > >::value, std::chrono::duration<long, std::ratio<1l, 1000000l> > >::type std::chrono::duration_cast<std::chrono::duration<long, std::ratio<1l, 1000000l> >, long, std::ratio<1l, 1000000000l> >(std::chrono::duration<long, std::ratio<1l, 1000000000l> > const&) [39]
                0.00    0.00       1/1           std::chrono::duration<long, std::ratio<1l, 1000000l> >::count() const [38]
-----------------------------------------------
                0.00    0.00 1000000/1000000     icu_64::Replaceable::Replaceable() [2]
[35]     0.0    0.00    0.00 1000000         icu_64::UObject::UObject() [35]
-----------------------------------------------
                0.00    0.00       1/3           std::chrono::duration<long, std::ratio<1l, 1000000l> > std::chrono::__duration_cast_impl<std::chrono::duration<long, std::ratio<1l, 1000000l> >, std::ratio<1l, 1000l>, long, true, false>::__cast<long, std::ratio<1l, 1000000000l> >(std::chrono::duration<long, std::ratio<1l, 1000000000l> > const&) [40]
                0.00    0.00       2/3           std::common_type<std::chrono::duration<long, std::ratio<1l, 1000000000l> >, std::chrono::duration<long, std::ratio<1l, 1000000000l> > >::type std::chrono::operator-<long, std::ratio<1l, 1000000000l>, long, std::ratio<1l, 1000000000l> >(std::chrono::duration<long, std::ratio<1l, 1000000000l> > const&, std::chrono::duration<long, std::ratio<1l, 1000000000l> > const&) [44]
[36]     0.0    0.00    0.00       3         std::chrono::duration<long, std::ratio<1l, 1000000000l> >::count() const [36]
-----------------------------------------------
                0.00    0.00       2/2           std::common_type<std::chrono::duration<long, std::ratio<1l, 1000000000l> >, std::chrono::duration<long, std::ratio<1l, 1000000000l> > >::type std::chrono::operator-<std::chrono::_V2::steady_clock, std::chrono::duration<long, std::ratio<1l, 1000000000l> >, std::chrono::duration<long, std::ratio<1l, 1000000000l> > >(std::chrono::time_point<std::chrono::_V2::steady_clock, std::chrono::duration<long, std::ratio<1l, 1000000000l> > > const&, std::chrono::time_point<std::chrono::_V2::steady_clock, std::chrono::duration<long, std::ratio<1l, 1000000000l> > > const&) [43]
[37]     0.0    0.00    0.00       2         std::chrono::time_point<std::chrono::_V2::steady_clock, std::chrono::duration<long, std::ratio<1l, 1000000000l> > >::time_since_epoch() const [37]
-----------------------------------------------
                0.00    0.00       1/1           show() [4]
[38]     0.0    0.00    0.00       1         std::chrono::duration<long, std::ratio<1l, 1000000l> >::count() const [38]
-----------------------------------------------
                0.00    0.00       1/1           show() [4]
[39]     0.0    0.00    0.00       1         std::enable_if<std::chrono::__is_duration<std::chrono::duration<long, std::ratio<1l, 1000000l> > >::value, std::chrono::duration<long, std::ratio<1l, 1000000l> > >::type std::chrono::duration_cast<std::chrono::duration<long, std::ratio<1l, 1000000l> >, long, std::ratio<1l, 1000000000l> >(std::chrono::duration<long, std::ratio<1l, 1000000000l> > const&) [39]
                0.00    0.00       1/1           std::chrono::duration<long, std::ratio<1l, 1000000l> > std::chrono::__duration_cast_impl<std::chrono::duration<long, std::ratio<1l, 1000000l> >, std::ratio<1l, 1000l>, long, true, false>::__cast<long, std::ratio<1l, 1000000000l> >(std::chrono::duration<long, std::ratio<1l, 1000000000l> > const&) [40]
-----------------------------------------------
                0.00    0.00       1/1           std::enable_if<std::chrono::__is_duration<std::chrono::duration<long, std::ratio<1l, 1000000l> > >::value, std::chrono::duration<long, std::ratio<1l, 1000000l> > >::type std::chrono::duration_cast<std::chrono::duration<long, std::ratio<1l, 1000000l> >, long, std::ratio<1l, 1000000000l> >(std::chrono::duration<long, std::ratio<1l, 1000000000l> > const&) [39]
[40]     0.0    0.00    0.00       1         std::chrono::duration<long, std::ratio<1l, 1000000l> > std::chrono::__duration_cast_impl<std::chrono::duration<long, std::ratio<1l, 1000000l> >, std::ratio<1l, 1000l>, long, true, false>::__cast<long, std::ratio<1l, 1000000000l> >(std::chrono::duration<long, std::ratio<1l, 1000000000l> > const&) [40]
                0.00    0.00       1/3           std::chrono::duration<long, std::ratio<1l, 1000000000l> >::count() const [36]
                0.00    0.00       1/1           std::chrono::duration<long, std::ratio<1l, 1000000l> >::duration<long, void>(long const&) [42]
-----------------------------------------------
                0.00    0.00       1/1           std::common_type<std::chrono::duration<long, std::ratio<1l, 1000000000l> >, std::chrono::duration<long, std::ratio<1l, 1000000000l> > >::type std::chrono::operator-<long, std::ratio<1l, 1000000000l>, long, std::ratio<1l, 1000000000l> >(std::chrono::duration<long, std::ratio<1l, 1000000000l> > const&, std::chrono::duration<long, std::ratio<1l, 1000000000l> > const&) [44]
[41]     0.0    0.00    0.00       1         std::chrono::duration<long, std::ratio<1l, 1000000000l> >::duration<long, void>(long const&) [41]
-----------------------------------------------
                0.00    0.00       1/1           std::chrono::duration<long, std::ratio<1l, 1000000l> > std::chrono::__duration_cast_impl<std::chrono::duration<long, std::ratio<1l, 1000000l> >, std::ratio<1l, 1000l>, long, true, false>::__cast<long, std::ratio<1l, 1000000000l> >(std::chrono::duration<long, std::ratio<1l, 1000000000l> > const&) [40]
[42]     0.0    0.00    0.00       1         std::chrono::duration<long, std::ratio<1l, 1000000l> >::duration<long, void>(long const&) [42]
-----------------------------------------------
                0.00    0.00       1/1           show() [4]
[43]     0.0    0.00    0.00       1         std::common_type<std::chrono::duration<long, std::ratio<1l, 1000000000l> >, std::chrono::duration<long, std::ratio<1l, 1000000000l> > >::type std::chrono::operator-<std::chrono::_V2::steady_clock, std::chrono::duration<long, std::ratio<1l, 1000000000l> >, std::chrono::duration<long, std::ratio<1l, 1000000000l> > >(std::chrono::time_point<std::chrono::_V2::steady_clock, std::chrono::duration<long, std::ratio<1l, 1000000000l> > > const&, std::chrono::time_point<std::chrono::_V2::steady_clock, std::chrono::duration<long, std::ratio<1l, 1000000000l> > > const&) [43]
                0.00    0.00       2/2           std::chrono::time_point<std::chrono::_V2::steady_clock, std::chrono::duration<long, std::ratio<1l, 1000000000l> > >::time_since_epoch() const [37]
                0.00    0.00       1/1           std::common_type<std::chrono::duration<long, std::ratio<1l, 1000000000l> >, std::chrono::duration<long, std::ratio<1l, 1000000000l> > >::type std::chrono::operator-<long, std::ratio<1l, 1000000000l>, long, std::ratio<1l, 1000000000l> >(std::chrono::duration<long, std::ratio<1l, 1000000000l> > const&, std::chrono::duration<long, std::ratio<1l, 1000000000l> > const&) [44]
-----------------------------------------------
                0.00    0.00       1/1           std::common_type<std::chrono::duration<long, std::ratio<1l, 1000000000l> >, std::chrono::duration<long, std::ratio<1l, 1000000000l> > >::type std::chrono::operator-<std::chrono::_V2::steady_clock, std::chrono::duration<long, std::ratio<1l, 1000000000l> >, std::chrono::duration<long, std::ratio<1l, 1000000000l> > >(std::chrono::time_point<std::chrono::_V2::steady_clock, std::chrono::duration<long, std::ratio<1l, 1000000000l> > > const&, std::chrono::time_point<std::chrono::_V2::steady_clock, std::chrono::duration<long, std::ratio<1l, 1000000000l> > > const&) [43]
[44]     0.0    0.00    0.00       1         std::common_type<std::chrono::duration<long, std::ratio<1l, 1000000000l> >, std::chrono::duration<long, std::ratio<1l, 1000000000l> > >::type std::chrono::operator-<long, std::ratio<1l, 1000000000l>, long, std::ratio<1l, 1000000000l> >(std::chrono::duration<long, std::ratio<1l, 1000000000l> > const&, std::chrono::duration<long, std::ratio<1l, 1000000000l> > const&) [44]
                0.00    0.00       2/3           std::chrono::duration<long, std::ratio<1l, 1000000000l> >::count() const [36]
                0.00    0.00       1/1           std::chrono::duration<long, std::ratio<1l, 1000000000l> >::duration<long, void>(long const&) [41]
-----------------------------------------------

 This table describes the call tree of the program, and was sorted by

[zbraniecki]

On Friday I left one bit of code commented out that impacts performance. I now removed obsolete attempts to layout data and re-added ability to test inline.

It's still not the final data model (we need Options to handle missing data), but the current results I see are:

ICU: 849 us
UNIC(JSON): 110 us
UNIC(Bin): 79 us
UNIC(Inline): 34 us

[zbraniecki]

I think the code should be very comparable for profiling.