/*
 * Copyright (C) 2022 The Android Open Source Project
 *
 * Licensed under the Apache License, Version 2.0 (the "License");
 * you may not use this file except in compliance with the License.
 * You may obtain a copy of the License at
 *
 *      http://www.apache.org/licenses/LICENSE-2.0
 *
 * Unless required by applicable law or agreed to in writing, software
 * distributed under the License is distributed on an "AS IS" BASIS,
 * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
 * See the License for the specific language governing permissions and
 * limitations under the License.
 */

#include "src/trace_processor/importers/android_bugreport/android_log_parser.h"

#include "perfetto/base/time.h"
#include "perfetto/ext/base/string_utils.h"
#include "src/trace_processor/storage/trace_storage.h"
#include "test/gtest_and_gmock.h"

#include "protos/perfetto/common/android_log_constants.pbzero.h"

namespace perfetto {
namespace trace_processor {

const int64_t kStoNs = 1000000000LL;

inline std::ostream& operator<<(std::ostream& stream,
                                const AndroidLogEvent& e) {
  char tms[32];
  time_t secs = static_cast<time_t>(e.ts / kStoNs);
  int ns = static_cast<int>(e.ts - secs * kStoNs);
  strftime(tms, sizeof(tms), "%Y-%m-%d %H:%M:%S", gmtime(&secs));
  base::StackString<64> tss("%s.%d", tms, ns);

  stream << "{ts=" << tss.c_str() << ", pid=" << e.pid << ", tid=" << e.tid
         << ", prio=" << e.prio << ", tag=" << e.tag.raw_id()
         << ", msg=" << e.msg.raw_id() << "}";
  return stream;
}

namespace {

using ::testing::ElementsAreArray;

TEST(AndroidLogParserTest, PersistentLogFormat) {
  TraceStorage storage;
  AndroidLogParser alp(2020, &storage);
  auto S = [&](const char* str) { return storage.InternString(str); };
  using P = ::perfetto::protos::pbzero::AndroidLogPriority;

  std::vector<AndroidLogEvent> events;
  alp.ParseLogLines(
      {
          "01-02 03:04:05.678901 1000 2000 D Tag: message",
          "01-02 03:04:05.678901 1000 2000 V Tag: message",
          "12-31 23:59:00.123456 1 2 I [tag:with:colon]: moar long message",
          "12-31 23:59:00.123 1 2 W [tag:with:colon]: moar long message",
          "12-31 23:59:00.1 1 2 E [tag:with:colon]: moar long message",
          "12-31 23:59:00.01 1 2 F [tag:with:colon]: moar long message",
      },
      &events);

  EXPECT_EQ(storage.stats()[stats::android_log_num_failed].value, 0);
  ASSERT_THAT(
      events,
      ElementsAreArray({
          AndroidLogEvent{
              base::MkTime(2020, 1, 2, 3, 4, 5) * kStoNs + 678901000, 1000,
              2000, P::PRIO_DEBUG, S("Tag"), S("message")},
          AndroidLogEvent{
              base::MkTime(2020, 1, 2, 3, 4, 5) * kStoNs + 678901000, 1000,
              2000, P::PRIO_VERBOSE, S("Tag"), S("message")},
          AndroidLogEvent{
              base::MkTime(2020, 12, 31, 23, 59, 0) * kStoNs + 123456000, 1, 2,
              P::PRIO_INFO, S("[tag:with:colon]"), S("moar long message")},
          AndroidLogEvent{
              base::MkTime(2020, 12, 31, 23, 59, 0) * kStoNs + 123000000, 1, 2,
              P::PRIO_WARN, S("[tag:with:colon]"), S("moar long message")},
          AndroidLogEvent{
              base::MkTime(2020, 12, 31, 23, 59, 0) * kStoNs + 100000000, 1, 2,
              P::PRIO_ERROR, S("[tag:with:colon]"), S("moar long message")},
          AndroidLogEvent{
              base::MkTime(2020, 12, 31, 23, 59, 0) * kStoNs + 10000000, 1, 2,
              P::PRIO_FATAL, S("[tag:with:colon]"), S("moar long message")},
      }));
}

TEST(AndroidLogParserTest, BugreportFormat) {
  TraceStorage storage;
  AndroidLogParser alp(2020, &storage);
  auto S = [&](const char* str) { return storage.InternString(str); };
  using P = ::perfetto::protos::pbzero::AndroidLogPriority;

  std::vector<AndroidLogEvent> events;
  alp.ParseLogLines(
      {
          "07-28 14:25:20.355  0     1     2 I init   : Loaded kernel module",
          "07-28 14:25:54.876  1000   643   644 D PackageManager: No files",
          "08-24 23:39:12.272  root     0     1 I        : c0  11835 binder: 1",
          "08-24 23:39:12.421 radio  2532  2533 D TelephonyProvider: Using old",
      },
      &events);

  EXPECT_EQ(storage.stats()[stats::android_log_num_failed].value, 0);
  ASSERT_THAT(
      events,
      ElementsAreArray({
          AndroidLogEvent{
              base::MkTime(2020, 7, 28, 14, 25, 20) * kStoNs + 355000000, 1, 2,
              P::PRIO_INFO, S("init"), S("Loaded kernel module")},
          AndroidLogEvent{
              base::MkTime(2020, 7, 28, 14, 25, 54) * kStoNs + 876000000, 643,
              644, P::PRIO_DEBUG, S("PackageManager"), S("No files")},
          AndroidLogEvent{
              base::MkTime(2020, 8, 24, 23, 39, 12) * kStoNs + 272000000, 0, 1,
              P::PRIO_INFO, S(""), S("c0  11835 binder: 1")},
          AndroidLogEvent{
              base::MkTime(2020, 8, 24, 23, 39, 12) * kStoNs + 421000000, 2532,
              2533, P::PRIO_DEBUG, S("TelephonyProvider"), S("Using old")},
      }));
}

// Tests the deduping logic. This is used when parsing events first from the
// persistent logcat (which has us resolution) and then from dumpstate (which
// has ms resolution and sometimes contains dupes of the persistent entries).
TEST(AndroidLogParserTest, Dedupe) {
  TraceStorage storage;
  AndroidLogParser alp(2020, &storage);
  auto S = [&](const char* str) { return storage.InternString(str); };
  using P = ::perfetto::protos::pbzero::AndroidLogPriority;
  std::vector<AndroidLogEvent> events;

  // Parse some initial events without any deduping.
  alp.ParseLogLines(
      {
          "01-01 00:00:01.100000  0 1 1 I tag : M1",
          "01-01 00:00:01.100111  0 1 1 I tag : M2",
          "01-01 00:00:01.100111  0 1 1 I tag : M3",
          "01-01 00:00:01.100222  0 1 1 I tag : M4",
          "01-01 00:00:01.101000  0 1 1 I tag : M5",
      },
      &events);

  ASSERT_EQ(events.size(), 5u);

  // Add a batch of events with truncated timestamps, some of which are dupes.
  alp.ParseLogLines(
      {
          "01-01 00:00:01.100  0 1 1 I tag : M1",  // Dupe
          "01-01 00:00:01.100  0 1 1 I tag : M1.5",
          "01-01 00:00:01.100  0 1 1 I tag : M3",  // Dupe
          "01-01 00:00:01.100  0 1 1 I tag : M4",  // Dupe
          "01-01 00:00:01.101  0 1 1 I tag : M5",  // Dupe
          "01-01 00:00:01.101  0 1 1 I tag : M6",
      },
      &events, /*dedupe_idx=*/5);
  EXPECT_EQ(storage.stats()[stats::android_log_num_failed].value, 0);

  std::stable_sort(events.begin(), events.end());
  ASSERT_THAT(events,
              ElementsAreArray({
                  AndroidLogEvent{
                      base::MkTime(2020, 1, 1, 0, 0, 1) * kStoNs + 100000000, 1,
                      1, P::PRIO_INFO, S("tag"), S("M1")},
                  AndroidLogEvent{
                      base::MkTime(2020, 1, 1, 0, 0, 1) * kStoNs + 100000000, 1,
                      1, P::PRIO_INFO, S("tag"), S("M1.5")},
                  AndroidLogEvent{
                      base::MkTime(2020, 1, 1, 0, 0, 1) * kStoNs + 100111000, 1,
                      1, P::PRIO_INFO, S("tag"), S("M2")},
                  AndroidLogEvent{
                      base::MkTime(2020, 1, 1, 0, 0, 1) * kStoNs + 100111000, 1,
                      1, P::PRIO_INFO, S("tag"), S("M3")},
                  AndroidLogEvent{
                      base::MkTime(2020, 1, 1, 0, 0, 1) * kStoNs + 100222000, 1,
                      1, P::PRIO_INFO, S("tag"), S("M4")},
                  AndroidLogEvent{
                      base::MkTime(2020, 1, 1, 0, 0, 1) * kStoNs + 101000000, 1,
                      1, P::PRIO_INFO, S("tag"), S("M5")},
                  AndroidLogEvent{
                      base::MkTime(2020, 1, 1, 0, 0, 1) * kStoNs + 101000000, 1,
                      1, P::PRIO_INFO, S("tag"), S("M6")},
              }));
}

}  // namespace
}  // namespace trace_processor
}  // namespace perfetto