Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Simple program goes into infinite loop #796

Closed
bingatgoogle opened this issue Feb 21, 2022 · 8 comments
Closed

Simple program goes into infinite loop #796

bingatgoogle opened this issue Feb 21, 2022 · 8 comments

Comments

@bingatgoogle
Copy link

The following program prints the message infinitely times, under the opt mode.

#include <glog/logging.h>

// * bazel run -c opt visionai/issues:overflow_plus_logging will invoke an
//     infinite loop.
// * -c dbg works fine.

int main (int argc, char* argv[]) {
  ::google::InitGoogleLogging(argv[0]);
  for (int i = 1; i <= 2; i++) {
    LOG(ERROR) << "should only output just twice";
    uint64_t a = i * 2147483647;
  }
  return 0;
}

Sample output:

......
E20220220 22:38:17.697548 1707658 overflow_plus_logging.cc:10] should only output just twice
E20220220 22:38:17.697566 1707658 overflow_plus_logging.cc:10] should only output just twice
E20220220 22:38:17.697582 1707658 overflow_plus_logging.cc:10] should only output just twice
E20220220 22:38:17.697598 1707658 overflow_plus_logging.cc:10] should only output just twice
E20220220 22:38:17.697614 1707658 overflow_plus_logging.cc:10] should only output just twice
E20220220 22:38:17.697630 1707658 overflow_plus_logging.cc:10] should only output just twice
E20220220 22:38:17.697647 1707658 overflow_plus_logging.cc:10] should only output just twice
E20220220 22:38:17.697664 1707658 overflow_plus_logging.cc:10] should only output just twice
......

BUILD file:

cc_binary(
    name = "overflow_plus_logging",
    srcs = [
        "overflow_plus_logging.cc",
    ],
    deps = [
        "@com_github_google_glog//:glog",
    ],
)

uname -a: Linux 276db1447620 5.14.16-1rodete1-amd64 #1 SMP Debian 5.14.16-1rodete1 (2021-11-17) x86_64 GNU/Linux
Bazel version: 5.0.0
gcc version: gcc version 8.3.0 (Debian 8.3.0-6)
Bazel workspace:

load("@bazel_tools//tools/build_defs/repo:http.bzl", "http_archive")

http_archive(
    name = "com_github_gflags_gflags",
    sha256 = "34af2f15cf7367513b352bdcd2493ab14ce43692d2dcd9dfc499492966c64dcf",
    strip_prefix = "gflags-2.2.2",
    urls = ["https://github.com/gflags/gflags/archive/v2.2.2.tar.gz"],
)

http_archive(
    name = "com_github_google_glog",
    sha256 = "21bc744fb7f2fa701ee8db339ded7dce4f975d0d55837a97be7d46e8382dea5a",
    strip_prefix = "glog-0.5.0",
    urls = ["https://github.com/google/glog/archive/v0.5.0.zip"],
)

Docker file if helpful:

FROM debian

ENV ROOTPATH=/
WORKDIR $ROOTPATH

RUN apt-get update && apt-get install -y --no-install-recommends \
      build-essential \
      ca-certificates \
      curl \
      vim \
      && \
    apt-get clean && \
    rm -rf /var/lib/apt/lists/*

RUN apt-get update && \
    DEBIAN_FRONTEND=noninteractive apt-get install -y --no-install-recommends \
      git \
      gnupg \
      && \
    apt-get clean && \
    rm -rf /var/lib/apt/lists/*

# Install bazel
RUN curl -fsSL https://bazel.build/bazel-release.pub.gpg | gpg \
      --dearmor > bazel.gpg && \
    mv bazel.gpg /etc/apt/trusted.gpg.d/ && \
    echo "deb [arch=amd64] https://storage.googleapis.com/bazel-apt stable jdk1.8" | \
      tee /etc/apt/sources.list.d/bazel.list && \
    apt-get update && \
    DEBIAN_FRONTEND=noninteractive apt-get install -y --no-install-recommends \
      bazel \
      && \
    apt-get clean && \
    rm -rf /var/lib/apt/lists/*

CMD ["bash"]
@drigz
Copy link
Member

drigz commented Feb 21, 2022

What makes you think this is a glog issue? The loop contains undefined behavior so it could be the compiler could be doing something weird with the loop as a result, perhaps assuming that i==0.

bazel/example/main.cc:7:20: warning: iteration 1 invokes undefined behavior [-Waggressive-loop-optimizations]
    7 |     uint64_t a = i * 2147483647;
      |                  ~~^~~~~~~~~~~~
bazel/example/main.cc:5:21: note: within this loop
    5 |   for (int i = 1; i <= 2; i++) {
      |                   ~~^~~~

I can reproduce the issue with the undefined behavior, but if I avoid it by using i * 2147483647ll then the loop terminates as expected.

@sergiud
Copy link
Collaborator

sergiud commented Feb 21, 2022

The signed integer overflow also caught my eye. Ignoring warnings is generally a bad idea.

@bingatgoogle
Copy link
Author

What makes you think this is a glog issue?

Remove the LOG(ERROR) statement, the loop ends. I don't know whether it's a glog issue and I lean toward gcc issue. But so far the LOG(ERROR) is the only way I find to invoke the issue.

The loop contains undefined behavior so it could be the compiler could be doing something weird with the loop as a result, perhaps assuming that i==0.

bazel/example/main.cc:7:20: warning: iteration 1 invokes undefined behavior [-Waggressive-loop-optimizations]

How did you get this? My bazel build only gave one warning of unused variable (bazel version and gcc version pasted in the first comment).

INFO: From Compiling overflow_plus_logging.cc:
overflow_plus_logging.cc: In function 'int main(int, char**)':
overflow_plus_logging.cc:11:14: warning: unused variable 'a' [-Wunused-variable]
     uint64_t a = i * 2147483647;
              ^
Target //:overflow_plus_logging up-to-date:
  bazel-bin/overflow_plus_logging

I can reproduce the issue with the undefined behavior, but if I avoid it by using i * 2147483647ll then the loop terminates as expected.

This is just an oversimplified example to demonstrate the unexpected behavior. The issue originated from a much complicated logic where no easy target as this dumb statement.

Anyway, I changed the program a bit to get rid of the unused variable. Now there are just two LOG statements in the body.

#include <glog/logging.h>

// * bazel run -c opt visionai/issues:overflow_plus_logging will invoke an
//     infinite loop.
// * -c dbg works fine.

int main (int argc, char* argv[]) {
  ::google::InitGoogleLogging(argv[0]);
  for (int i = 1; i <= 2; i++) {
    LOG(ERROR) << "should only output just twice.";
    LOG(ERROR) << i * 1147483641;
  }
  return 0;
}

@bingatgoogle
Copy link
Author

The signed integer overflow also caught my eye. Ignoring warnings is generally a bad idea.

The posted program didn't actually produce the warning. Please give it a try.

@drigz
Copy link
Member

drigz commented Feb 21, 2022

2*1147483641 is still undefined behavior, as the result doesn't fit in a 32-bit signed integer. I suspect something else in the original complicated logic caused a similar overflow and made the compiler assume the index never gets that high. In general, when there are two things in a loop and removing either of them prevents the bug, I don't think we can conclude that both of those things are equally to blame. The fact that your compiler doesn't warn about it probably just means that your compiler is older and doesn't provide helpful warnings about undefined behavior.

You can see a similar case here where undefined behavior leads to an infinite loop, whether or not the compiler is clever enough to print a warning: https://community.st.com/s/question/0D50X0000C6bXXMSQ2/solved-infinite-loop-without-warning-iteration-n-invokes-undefined-behavior-using-pointers-to-get-data-from-a-function

@bingatgoogle
Copy link
Author

Thanks Rodrigo.
I tried with the std iostream library for output and this time there is no infinite loop but the complier did warn against undefined behavior. So in summary, with LOG(ERROR) the compiler didn't warn but there was infinite loop; with std::cout there was warning and there was no infinite loop (in fact, the loop was not even started).

Suppose c = a + 1 overflow and there is undefined behavior. My expectation will be that c in undefined state so anything depends on c will be undefined. But I have never expect that a will also be changed.

As said I lean toward this is more of a compiler issue and I'll ask on gcc community. It will be more convincible If I could get a more language native way to demonstrate the issue without touching glog.

@drigz
Copy link
Member

drigz commented Feb 21, 2022

Suppose c = a + 1 overflow and there is undefined behavior. My expectation will be that c in undefined state so anything depends on c will be undefined. But I have never expect that a will also be changed.

This is a reasonable expectation but unfortunately wrong. Since the behavior of a + 1 is undefined, the compiler can choose whatever behavior it likes, including changing a, or, as a Usenet poster once explained, "to make demons fly out of your nose": https://en.wikipedia.org/wiki/Undefined_behavior

In this case, I would guess the compiler sees that a * 1147483641 would overflow unless a is 0 or 1. It therefore assumes a is 0 or 1, as in the other cases the behavior is undefined. That causes the optimizer to remove the a <= 2 comparison, as a could never reach 3. That said, I'm not an expert on this sort of thing.

If you're not sure what caused this in your original code, you could look into using ubsan to try to catch it.

I'll close this as I doubt it's specific to glog, although if you're able to reproduce the issue without undefined behavior in the loop please let us know.

@drigz drigz closed this as completed Feb 21, 2022
@bingatgoogle
Copy link
Author

Thanks Rodrigo. Your explanation makes total sense. Special thanks for correcting my understanding on undefined behavior!

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

No branches or pull requests

3 participants