Skip to content

error: partially re-inline error constructors#385

Merged
BurntSushi merged 1 commit intomasterfrom
ag/fix-parse-perf-regression
Jun 13, 2025
Merged

error: partially re-inline error constructors#385
BurntSushi merged 1 commit intomasterfrom
ag/fix-parse-perf-regression

Conversation

@BurntSushi
Copy link
Owner

@BurntSushi BurntSushi commented Jun 13, 2025

It turns out that #379 ended up pretty badly regressing datetime parsing
performance. In particular, the with_context routine on Result<T, E>
was eagerly calling the caller-provided closure even in the success
case. Which means error values (which are generally much more expensive
to build than to parse a datetime) were being constructed on every
parse. Owch.

I'm not sure how I missed this. I ran the benchmarks in #379 and they
didn't report anything egregious. I should double-back and improve
benchmark coverage.

Thankfully, this doesn't seem to regress the number of LLVM lines we're
emitting:

  Lines                 Copies              Function name
  -----                 ------              -------------
  192746                2456                (TOTAL)
    3978 (2.1%,  2.1%)     1 (0.0%,  0.0%)  jiff::fmt::strtime::format::Formatter<W,L>::format_one
    3785 (2.0%,  4.0%)     1 (0.0%,  0.1%)  jiff::fmt::strtime::parse::Parser::parse
    3600 (1.9%,  5.9%)     2 (0.1%,  0.2%)  jiff::fmt::temporal::printer::SpanPrinter::print_span
    3340 (1.7%,  7.6%)     2 (0.1%,  0.2%)  jiff::fmt::friendly::printer::SpanPrinter::print_duration_designators
    3250 (1.7%,  9.3%)    86 (3.5%,  3.7%)  <core::result::Result<T,jiff::error::Error> as jiff::error::ErrorContext>::with_context::{{closure}}
    2910 (1.5%, 10.8%)     6 (0.2%,  4.0%)  jiff::fmt::temporal::printer::DateTimePrinter::print_time
    2190 (1.1%, 12.0%)     1 (0.0%,  4.0%)  jiff::span::Span::from_invariant_nanoseconds
    2166 (1.1%, 13.1%)     6 (0.2%,  4.3%)  jiff::fmt::temporal::printer::DateTimePrinter::print_date
    1760 (0.9%, 14.0%)     2 (0.1%,  4.4%)  jiff::fmt::temporal::printer::SpanPrinter::print_duration
    1588 (0.8%, 14.8%)     2 (0.1%,  4.4%)  jiff::fmt::friendly::printer::SpanPrinter::print_span_hms
    1450 (0.8%, 15.6%)     2 (0.1%,  4.5%)  jiff::fmt::friendly::printer::SpanPrinter::print_span_designators_non_fraction
    1432 (0.7%, 16.3%)     4 (0.2%,  4.7%)  jiff::fmt::temporal::printer::DateTimePrinter::print_offset_rounded
    1398 (0.7%, 17.0%)     2 (0.1%,  4.8%)  jiff::fmt::temporal::printer::DateTimePrinter::print_pieces
    1368 (0.7%, 17.8%)     6 (0.2%,  5.0%)  jiff::fmt::friendly::printer::DesignatorWriter<W>::write
    1364 (0.7%, 18.5%)     2 (0.1%,  5.1%)  jiff::fmt::friendly::printer::SpanPrinter::print_duration_hms
    1248 (0.6%, 19.1%)    16 (0.7%,  5.7%)  <jiff::util::rangeint::RangedDebug<_,_> as core::fmt::Debug>::fmt
    1243 (0.6%, 19.8%)     1 (0.0%,  5.8%)  jiff::fmt::rfc2822::DateTimePrinter::print_civil_with_offset
    1222 (0.6%, 20.4%)    13 (0.5%,  6.3%)  jiff::util::rangeint::ri8<_,_>::new
    1108 (0.6%, 21.0%)    28 (1.1%,  7.5%)  core::result::Result<T,E>::unwrap
    1097 (0.6%, 21.5%)     1 (0.0%,  7.5%)  jiff::shared::tzif::Header::parse
    1086 (0.6%, 22.1%)    22 (0.9%,  8.4%)  core::option::Option<T>::map_or

Kudos to @charliermarsh for finding this while profiling uv.

It turns out that #379 ended up pretty badly regressing datetime parsing
performance. In particular, the `with_context` routine on `Result<T, E>`
was _eagerly_ calling the caller-provided closure even in the success
case. Which means error values (which are generally much more expensive
to build than to parse a datetime) were being constructed on every
parse. Owch.

I'm not sure how I missed this. I ran the benchmarks in #379 and they
didn't report anything egregious. I should double-back and improve
benchmark coverage.

Thankfully, this doesn't seem to regress the number of LLVM lines we're
emitting:

  Lines                 Copies              Function name
  -----                 ------              -------------
  192746                2456                (TOTAL)
    3978 (2.1%,  2.1%)     1 (0.0%,  0.0%)  jiff::fmt::strtime::format::Formatter<W,L>::format_one
    3785 (2.0%,  4.0%)     1 (0.0%,  0.1%)  jiff::fmt::strtime::parse::Parser::parse
    3600 (1.9%,  5.9%)     2 (0.1%,  0.2%)  jiff::fmt::temporal::printer::SpanPrinter::print_span
    3340 (1.7%,  7.6%)     2 (0.1%,  0.2%)  jiff::fmt::friendly::printer::SpanPrinter::print_duration_designators
    3250 (1.7%,  9.3%)    86 (3.5%,  3.7%)  <core::result::Result<T,jiff::error::Error> as jiff::error::ErrorContext>::with_context::{{closure}}
    2910 (1.5%, 10.8%)     6 (0.2%,  4.0%)  jiff::fmt::temporal::printer::DateTimePrinter::print_time
    2190 (1.1%, 12.0%)     1 (0.0%,  4.0%)  jiff::span::Span::from_invariant_nanoseconds
    2166 (1.1%, 13.1%)     6 (0.2%,  4.3%)  jiff::fmt::temporal::printer::DateTimePrinter::print_date
    1760 (0.9%, 14.0%)     2 (0.1%,  4.4%)  jiff::fmt::temporal::printer::SpanPrinter::print_duration
    1588 (0.8%, 14.8%)     2 (0.1%,  4.4%)  jiff::fmt::friendly::printer::SpanPrinter::print_span_hms
    1450 (0.8%, 15.6%)     2 (0.1%,  4.5%)  jiff::fmt::friendly::printer::SpanPrinter::print_span_designators_non_fraction
    1432 (0.7%, 16.3%)     4 (0.2%,  4.7%)  jiff::fmt::temporal::printer::DateTimePrinter::print_offset_rounded
    1398 (0.7%, 17.0%)     2 (0.1%,  4.8%)  jiff::fmt::temporal::printer::DateTimePrinter::print_pieces
    1368 (0.7%, 17.8%)     6 (0.2%,  5.0%)  jiff::fmt::friendly::printer::DesignatorWriter<W>::write
    1364 (0.7%, 18.5%)     2 (0.1%,  5.1%)  jiff::fmt::friendly::printer::SpanPrinter::print_duration_hms
    1248 (0.6%, 19.1%)    16 (0.7%,  5.7%)  <jiff::util::rangeint::RangedDebug<_,_> as core::fmt::Debug>::fmt
    1243 (0.6%, 19.8%)     1 (0.0%,  5.8%)  jiff::fmt::rfc2822::DateTimePrinter::print_civil_with_offset
    1222 (0.6%, 20.4%)    13 (0.5%,  6.3%)  jiff::util::rangeint::ri8<_,_>::new
    1108 (0.6%, 21.0%)    28 (1.1%,  7.5%)  core::result::Result<T,E>::unwrap
    1097 (0.6%, 21.5%)     1 (0.0%,  7.5%)  jiff::shared::tzif::Header::parse
    1086 (0.6%, 22.1%)    22 (0.9%,  8.4%)  core::option::Option<T>::map_or

Kudos to @charliermarsh for finding this while profiling uv.
@BurntSushi BurntSushi merged commit e355d48 into master Jun 13, 2025
38 checks passed
@BurntSushi BurntSushi deleted the ag/fix-parse-perf-regression branch June 13, 2025 18:17
@BurntSushi
Copy link
Owner Author

This PR is on crates.io in jiff 0.2.15.

BurntSushi added a commit to astral-sh/uv that referenced this pull request Jun 13, 2025
This brings in BurntSushi/jiff#385, which makes
cold resolves about 10% faster. Or, stated differently, as fast as they
were a few weeks ago before the perf regression introduced by
`jiff 0.2.14`.
charliermarsh pushed a commit to astral-sh/uv that referenced this pull request Jun 13, 2025
This brings in BurntSushi/jiff#385, which makes
cold resolves about 10% faster. Or, stated differently, as fast as they
were a few weeks ago before the perf regression introduced by
`jiff 0.2.14`.
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant