FormatTime() has regressed in release LTS 20210324.2, for cross compiler (works fine in LTS 20190808)

[pkbehera]

Describe the bug We are using this library with a purpose built GCC v7.5-2019.12 cross-compiler targeting ARM Cortex-A15 or Cortex-A9 based upon this software release from Linaro http://releases.linaro.org/components/toolchain/gcc-linaro/7.5-2019.12.

With this cross-compiler the FormatTime() API works fine as expected in abseil release LTS 20190808, but it is broken in latest release LTS 20210324.2.

Steps to reproduce the bug

Build and run this google-test with the above cross-compiler

#include <unordered_map>

#include <gmock/gmock.h>
#include <gtest/gtest.h>

#include "absl/time/clock.h"
#include "absl/time/time.h"  

TEST(TimeUtilTests, FormatTime) {
  for (const auto& [epoch_ns, ts_str] : std::unordered_map<uint64_t, std::string>({
           {1634058342371043590, "2021-10-12T17:05:42"},
           {1634058340564981005, "2021-10-12T17:05:40"},
       })) {
    EXPECT_EQ(absl::FormatTime("%Y-%m-%dT%H:%M:%S", absl::FromUnixNanos(epoch_ns), absl::UTCTimeZone()),
              ts_str);
  }
}

With latest release LTS 20210324.2 this test fails:

CFS:default@S001T1190406421(B10:bn) [/tmp]$ ./time_util_test
Running main() from /home/yatish/work/clients/releasedevel/tarana3/cpu/filesystem/grpc/third_party/googletest/googletest/src/gtest_main.cc
[==========] Running 1 test from 1 test suite.
[----------] Global test environment set-up.
[----------] 1 test from TimeUtilTests
[ RUN      ] TimeUtilTests.FormatTime
util/time_util_test.cpp:14: Failure
Expected equality of these values:
  absl::FormatTime("%Y-%m-%dT%H:%M:%S", absl::FromUnixNanos(epoch_ns), absl::UTCTimeZone())
    Which is: "2021-10-12T1\0:14:56"
  ts_str
    Which is: "2021-10-12T17:14:56"
util/time_util_test.cpp:14: Failure
Expected equality of these values:
  absl::FormatTime("%Y-%m-%dT%H:%M:%S", absl::FromUnixNanos(epoch_ns), absl::UTCTimeZone())
    Which is: "2021-10-12T1\0:05:57"
  ts_str
    Which is: "2021-10-12T17:05:57"
[  FAILED  ] TimeUtilTests.FormatTime (11 ms)
[----------] 1 test from TimeUtilTests (11 ms total)

[----------] Global test environment tear-down
[==========] 1 test from 1 test suite ran. (15 ms total)
[  PASSED  ] 0 tests.
[  FAILED  ] 1 test, listed below:
[  FAILED  ] TimeUtilTests.FormatTime

Note the \0s in the output, which is why the output string of FormatTime() does not match with what is expected.

This test works fine with abseil release LTS 20190808, from which we're trying to upgrade.

Also, this is not a regression with gcc/clang on x86, both these releases work fine on it.

What version of Abseil are you using? LTS 20210324.2

What operating system and version are you using Linux on ARM Cortex-A15 or Cortex-A9

What compiler and version are you using? purpose built GCC v7.5-2019.12 targeting ARM Cortex-A15 or Cortex-A9 based upon this software release from Linaro http://releases.linaro.org/components/toolchain/gcc-linaro/7.5-2019.12.

What build system are you using?

$ bazel --version
bazel 4.2.1

Additional context None

[derekmauro]

I copied your test here: https://godbolt.org/z/rEx5j8YPq

The test passes for me, but I don't have an easy way of running the test with the compiler you are using.

I wonder if @devbww has any guess what might be going on here.

[devbww]

The first thing I'll note is that the test code given does not match the test output. For example, the test code is looking for 2021-10-12T17:05:42 and 2021-10-12T17:05:40, while the test output says it was trying to match 2021-10-12T17:14:56 (1634058896) and 2021-10-12T17:05:57 (1634058357).

Whatever values you are actually using, the mismatch seems to appear in the %H field, which is formatted at https://github.com/abseil/abseil-cpp/blob/master/absl/time/internal/cctz/src/time_zone_format.cc#L422-L425

        case 'H':
          bp = Format02d(ep, al.cs.hour());
          result.append(bp, static_cast<std::size_t>(ep - bp));
          break;

which calls https://github.com/abseil/abseil-cpp/blob/master/absl/time/internal/cctz/src/time_zone_format.cc#L174-L179

const char kDigits[] = "0123456789";

// Formats [0 .. 99] as %02d.
char* Format02d(char* ep, int v) {
  *--ep = kDigits[v % 10];
  *--ep = kDigits[(v / 10) % 10];
  return ep;
}

so it doesn't look like there is any possibility of injecting a NUL into the buffer. (Indeed, %m, %d, %M, and %S all use the same code path.)

Also, it also doesn't look like any of that code has changed between 20190808 and 20210324.2.

So, something subtle must be going on. And given that we can't reproduce it, we'll undoubtedly need your help in chasing down whatever the issue is. Thanks.

My first questions would be:

• Can you reproduce it just using %H?
• Are you able to insert any tracing code into the test run, or run the test within a debugger?

[devbww]

Can you reproduce it just using %H?

You might also try adding additional %H specifiers, and moving them to alternate places in the format string to see (1) if they each result in a NUL, or (2) whether the NUL changes position too.

[pkbehera]

I changed the test to the following, to try just %H

#include <unordered_map>

#include <gmock/gmock.h>
#include <gtest/gtest.h>

#include "absl/time/clock.h"
#include "absl/time/time.h"

TEST(TimeUtilTests, FormatTime) {
  for (const auto& [epoch_ns, ts_str] : std::unordered_map<uint64_t, std::string>({
           {1634058342371043590, "17:17:17:17:17"},
           {1634058340564981005, "17:17:17:17:17"},
       })) {
    EXPECT_EQ(absl::FormatTime("%H:%H:%H:%H:%H", absl::FromUnixNanos(epoch_ns), absl::UTCTimeZone()), ts_str);
  }
}

Now I see multiple NULL in the output, same as the number of %Hs in the format string:

I will try and run the test from a debugger and post my findings.

[devbww]

I changed the test to the following, to try just %H ... Now I see multiple NULL in the output, same as the number of %Hs in the format string

That's interesting. I'd be curious to see the value of al.cs.hour() within the case 'H' code above then.

I will try and run the test from a debugger and post my findings.

Thanks. Another possibility might be that kDigits[7] had been overwritten with a NUL, but I see from your original test output that %S was able to produce a "7". Take a look at kDigits[] in any case.

[pkbehera]

I tried to run the test from gdb but seeing something strange here:

• The problem is not reproducible if the test is built in debug mode!
• In fact the problem is not reproducible if the test is statically linked (linkstatic = 1 in bazel BUILD)!
• It is reproducible only if I link the test dynamically! (linkstatic = 0), which is what we do.

Not sure where should I look now, the cctz format doesn't seem to have any problem.

[devbww]

Thanks for looking deeply into that @pkbehera. I certainly agree that this looks more like a tool-chain issue than anything to do with the source code.

So, I'm going to hand this back to @derekmauro, who may have some more information about using Abseil with dynamic linking.