gecko-dev/toolkit/components/telemetry/TelemetryEvent.cpp

/* -*- Mode: C++; tab-width: 8; indent-tabs-mode: nil; c-basic-offset: 2 -*- */
/* vim: set ts=8 sts=2 et sw=2 tw=80: */
/* This Source Code Form is subject to the terms of the Mozilla Public
 * License, v. 2.0. If a copy of the MPL was not distributed with this
 * file, You can obtain one at http://mozilla.org/MPL/2.0/. */

#include <prtime.h>
#include "nsITelemetry.h"
#include "nsHashKeys.h"
#include "nsDataHashtable.h"
#include "nsClassHashtable.h"
#include "nsTArray.h"
#include "mozilla/StaticMutex.h"
#include "mozilla/Unused.h"
#include "mozilla/Maybe.h"
#include "mozilla/StaticPtr.h"
#include "jsapi.h"
#include "nsJSUtils.h"
#include "nsXULAppAPI.h"
#include "nsUTF8Utils.h"

#include "TelemetryCommon.h"
#include "TelemetryEvent.h"
#include "TelemetryEventData.h"

using mozilla::StaticMutex;
using mozilla::StaticMutexAutoLock;
using mozilla::ArrayLength;
using mozilla::Maybe;
using mozilla::Nothing;
using mozilla::Pair;
using mozilla::StaticAutoPtr;
using mozilla::Telemetry::Common::AutoHashtable;
using mozilla::Telemetry::Common::IsExpiredVersion;
using mozilla::Telemetry::Common::CanRecordDataset;
using mozilla::Telemetry::Common::IsInDataset;
using mozilla::Telemetry::Common::MsSinceProcessStart;
using mozilla::Telemetry::Common::LogToBrowserConsole;

////////////////////////////////////////////////////////////////////////
////////////////////////////////////////////////////////////////////////
//
// Naming: there are two kinds of functions in this file:
//
// * Functions taking a StaticMutexAutoLock: these can only be reached via
//   an interface function (TelemetryEvent::*). They expect the interface
//   function to have acquired |gTelemetryEventsMutex|, so they do not
//   have to be thread-safe.
//
// * Functions named TelemetryEvent::*. This is the external interface.
//   Entries and exits to these functions are serialised using
//   |gTelemetryEventsMutex|.
//
// Avoiding races and deadlocks:
//
// All functions in the external interface (TelemetryEvent::*) are
// serialised using the mutex |gTelemetryEventsMutex|. This means
// that the external interface is thread-safe, and the internal
// functions can ignore thread safety. But it also brings a danger
// of deadlock if any function in the external interface can get back
// to that interface. That is, we will deadlock on any call chain like
// this:
//
// TelemetryEvent::* -> .. any functions .. -> TelemetryEvent::*
//
// To reduce the danger of that happening, observe the following rules:
//
// * No function in TelemetryEvent::* may directly call, nor take the
//   address of, any other function in TelemetryEvent::*.
//
// * No internal function may call, nor take the address
//   of, any function in TelemetryEvent::*.

////////////////////////////////////////////////////////////////////////
////////////////////////////////////////////////////////////////////////
//
// PRIVATE TYPES

namespace {

const uint32_t kEventCount = mozilla::Telemetry::EventID::EventCount;
// This is a special event id used to mark expired events, to make expiry checks
// faster at runtime.
const uint32_t kExpiredEventId = kEventCount + 1;
static_assert(kEventCount < kExpiredEventId, "Should not overflow.");

// This is the hard upper limit on the number of event records we keep in storage.
// If we cross this limit, we will drop any further event recording until elements
// are removed from storage.
const uint32_t kMaxEventRecords = 1000;
// Maximum length of any passed value string, in UTF8 byte sequence length.
const uint32_t kMaxValueByteLength = 80;
// Maximum length of any string value in the extra dictionary, in UTF8 byte sequence length.
const uint32_t kMaxExtraValueByteLength = 80;

typedef nsDataHashtable<nsCStringHashKey, uint32_t> StringUintMap;
typedef nsClassHashtable<nsCStringHashKey, nsCString> StringMap;

enum class RecordEventResult {
  Ok,
  UnknownEvent,
  InvalidExtraKey,
  StorageLimitReached,
};

struct ExtraEntry {
  const nsCString key;
  const nsCString value;
};

typedef nsTArray<ExtraEntry> ExtraArray;

class EventRecord {
public:
  EventRecord(double timestamp, uint32_t eventId, const Maybe<nsCString>& value,
              const ExtraArray& extra)
    : mTimestamp(timestamp)
    , mEventId(eventId)
    , mValue(value)
    , mExtra(extra)
  {}

  EventRecord(const EventRecord& other)
    : mTimestamp(other.mTimestamp)
    , mEventId(other.mEventId)
    , mValue(other.mValue)
    , mExtra(other.mExtra)
  {}

  EventRecord& operator=(const EventRecord& other) = delete;

  double Timestamp() const { return mTimestamp; }
  uint32_t EventId() const { return mEventId; }
  const Maybe<nsCString>& Value() const { return mValue; }
  const ExtraArray& Extra() const { return mExtra; }

  size_t SizeOfExcludingThis(mozilla::MallocSizeOf aMallocSizeOf) const;

private:
  const double mTimestamp;
  const uint32_t mEventId;
  const Maybe<nsCString> mValue;
  const ExtraArray mExtra;
};

// Implements the methods for EventInfo.
const char*
EventInfo::method() const
{
  return &gEventsStringTable[this->method_offset];
}

const char*
EventInfo::object() const
{
  return &gEventsStringTable[this->object_offset];
}

// Implements the methods for CommonEventInfo.
const char*
CommonEventInfo::category() const
{
  return &gEventsStringTable[this->category_offset];
}

const char*
CommonEventInfo::expiration_version() const
{
  return &gEventsStringTable[this->expiration_version_offset];
}

const char*
CommonEventInfo::extra_key(uint32_t index) const
{
  MOZ_ASSERT(index < this->extra_count);
  uint32_t key_index = gExtraKeysTable[this->extra_index + index];
  return &gEventsStringTable[key_index];
}

// Implementation for the EventRecord class.
size_t
EventRecord::SizeOfExcludingThis(mozilla::MallocSizeOf aMallocSizeOf) const
{
  size_t n = 0;

  if (mValue) {
    n += mValue.value().SizeOfExcludingThisIfUnshared(aMallocSizeOf);
  }

  n += mExtra.ShallowSizeOfExcludingThis(aMallocSizeOf);
  for (uint32_t i = 0; i < mExtra.Length(); ++i) {
    n += mExtra[i].key.SizeOfExcludingThisIfUnshared(aMallocSizeOf);
    n += mExtra[i].value.SizeOfExcludingThisIfUnshared(aMallocSizeOf);
  }

  return n;
}

nsCString
UniqueEventName(const nsACString& category, const nsACString& method, const nsACString& object)
{
  nsCString name;
  name.Append(category);
  name.AppendLiteral("#");
  name.Append(method);
  name.AppendLiteral("#");
  name.Append(object);
  return name;
}

nsCString
UniqueEventName(const EventInfo& info)
{
  return UniqueEventName(nsDependentCString(info.common_info.category()),
                         nsDependentCString(info.method()),
                         nsDependentCString(info.object()));
}

bool
IsExpiredDate(uint32_t expires_days_since_epoch) {
  if (expires_days_since_epoch == 0) {
    return false;
  }

  const uint32_t days_since_epoch = PR_Now() / (PRTime(PR_USEC_PER_SEC) * 24 * 60 * 60);
  return expires_days_since_epoch <= days_since_epoch;
}

void
TruncateToByteLength(nsCString& str, uint32_t length)
{
  // last will be the index of the first byte of the current multi-byte sequence.
  uint32_t last = RewindToPriorUTF8Codepoint(str.get(), length);
  str.Truncate(last);
}

} // anonymous namespace

////////////////////////////////////////////////////////////////////////
////////////////////////////////////////////////////////////////////////
//
// PRIVATE STATE, SHARED BY ALL THREADS

namespace {

// Set to true once this global state has been initialized.
bool gInitDone = false;

bool gCanRecordBase;
bool gCanRecordExtended;

// The EventName -> EventID cache map.
StringUintMap gEventNameIDMap(kEventCount);

// The CategoryName -> CategoryID cache map.
StringUintMap gCategoryNameIDMap;

// This tracks the IDs of the categories for which recording is enabled.
nsTHashtable<nsUint32HashKey> gEnabledCategories;

// The main event storage. Events are inserted here in recording order.
StaticAutoPtr<nsTArray<EventRecord>> gEventRecords;

} // namespace

////////////////////////////////////////////////////////////////////////
////////////////////////////////////////////////////////////////////////
//
// PRIVATE: thread-unsafe helpers for event recording.

namespace {

bool
CanRecordEvent(const StaticMutexAutoLock& lock, const CommonEventInfo& info)
{
  if (!gCanRecordBase) {
    return false;
  }

  if (!CanRecordDataset(info.dataset, gCanRecordBase, gCanRecordExtended)) {
    return false;
  }

  return gEnabledCategories.GetEntry(info.category_offset);
}

RecordEventResult
RecordEvent(const StaticMutexAutoLock& lock, double timestamp,
            const nsACString& category, const nsACString& method,
            const nsACString& object, const Maybe<nsCString>& value,
            const ExtraArray& extra)
{
  // Apply hard limit on event count in storage.
  if (gEventRecords->Length() >= kMaxEventRecords) {
    return RecordEventResult::StorageLimitReached;
  }

  // Look up the event id.
  const nsCString& name = UniqueEventName(category, method, object);
  uint32_t eventId;
  if (!gEventNameIDMap.Get(name, &eventId)) {
    return RecordEventResult::UnknownEvent;
  }

  // If the event is expired, silently drop this call.
  // We don't want recording for expired probes to be an error so code doesn't
  // have to be removed at a specific time or version.
  // Even logging warnings would become very noisy.
  if (eventId == kExpiredEventId) {
    return RecordEventResult::Ok;
  }

  // Check whether we can record this event.
  const CommonEventInfo& common = gEventInfo[eventId].common_info;
  if (!CanRecordEvent(lock, common)) {
    return RecordEventResult::Ok;
  }

  // Check whether the extra keys passed are valid.
  nsTHashtable<nsCStringHashKey> validExtraKeys;
  for (uint32_t i = 0; i < common.extra_count; ++i) {
    validExtraKeys.PutEntry(nsDependentCString(common.extra_key(i)));
  }

  for (uint32_t i = 0; i < extra.Length(); ++i) {
    if (!validExtraKeys.GetEntry(extra[i].key)) {
      return RecordEventResult::InvalidExtraKey;
    }
  }

  // Add event record.
  gEventRecords->AppendElement(EventRecord(timestamp, eventId, value, extra));
  return RecordEventResult::Ok;
}

} // anonymous namespace

////////////////////////////////////////////////////////////////////////
////////////////////////////////////////////////////////////////////////
//
// EXTERNALLY VISIBLE FUNCTIONS in namespace TelemetryEvents::

// This is a StaticMutex rather than a plain Mutex (1) so that
// it gets initialised in a thread-safe manner the first time
// it is used, and (2) because it is never de-initialised, and
// a normal Mutex would show up as a leak in BloatView.  StaticMutex
// also has the "OffTheBooks" property, so it won't show as a leak
// in BloatView.
// Another reason to use a StaticMutex instead of a plain Mutex is
// that, due to the nature of Telemetry, we cannot rely on having a
// mutex initialized in InitializeGlobalState. Unfortunately, we
// cannot make sure that no other function is called before this point.
static StaticMutex gTelemetryEventsMutex;

void
TelemetryEvent::InitializeGlobalState(bool aCanRecordBase, bool aCanRecordExtended)
{
  StaticMutexAutoLock locker(gTelemetryEventsMutex);
  MOZ_ASSERT(!gInitDone, "TelemetryEvent::InitializeGlobalState "
             "may only be called once");

  gCanRecordBase = aCanRecordBase;
  gCanRecordExtended = aCanRecordExtended;

  gEventRecords = new nsTArray<EventRecord>();

  // Populate the static event name->id cache. Note that the event names are
  // statically allocated and come from the automatically generated TelemetryEventData.h.
  const uint32_t eventCount = static_cast<uint32_t>(mozilla::Telemetry::EventID::EventCount);
  for (uint32_t i = 0; i < eventCount; ++i) {
    const EventInfo& info = gEventInfo[i];
    uint32_t eventId = i;

    // If this event is expired, mark it with a special event id.
    // This avoids doing expensive expiry checks at runtime.
    if (IsExpiredVersion(info.common_info.expiration_version()) ||
        IsExpiredDate(info.common_info.expiration_day)) {
      eventId = kExpiredEventId;
    }

    gEventNameIDMap.Put(UniqueEventName(info), eventId);
    if (!gCategoryNameIDMap.Contains(nsDependentCString(info.common_info.category()))) {
      gCategoryNameIDMap.Put(nsDependentCString(info.common_info.category()),
                             info.common_info.category_offset);
    }
  }

#ifdef DEBUG
  gEventNameIDMap.MarkImmutable();
  gCategoryNameIDMap.MarkImmutable();
#endif
  gInitDone = true;
}

void
TelemetryEvent::DeInitializeGlobalState()
{
  StaticMutexAutoLock locker(gTelemetryEventsMutex);
  MOZ_ASSERT(gInitDone);

  gCanRecordBase = false;
  gCanRecordExtended = false;

  gEventNameIDMap.Clear();
  gCategoryNameIDMap.Clear();
  gEnabledCategories.Clear();
  gEventRecords->Clear();
  gEventRecords = nullptr;

  gInitDone = false;
}

void
TelemetryEvent::SetCanRecordBase(bool b)
{
  StaticMutexAutoLock locker(gTelemetryEventsMutex);
  gCanRecordBase = b;
}

void
TelemetryEvent::SetCanRecordExtended(bool b) {
  StaticMutexAutoLock locker(gTelemetryEventsMutex);
  gCanRecordExtended = b;
}

nsresult
TelemetryEvent::RecordEvent(const nsACString& aCategory, const nsACString& aMethod,
                            const nsACString& aObject, JS::HandleValue aValue,
                            JS::HandleValue aExtra, JSContext* cx,
                            uint8_t optional_argc)
{
  // Currently only recording in the parent process is supported.
  if (!XRE_IsParentProcess()) {
    return NS_OK;
  }

  // Get the current time.
  double timestamp = -1;
  nsresult rv = MsSinceProcessStart(&timestamp);
  if (NS_FAILED(rv)) {
    LogToBrowserConsole(nsIScriptError::warningFlag,
                        NS_LITERAL_STRING("Failed to get time since process start."));
    return NS_OK;
  }

  // Check value argument.
  if ((optional_argc > 0) && !aValue.isNull() && !aValue.isString()) {
    LogToBrowserConsole(nsIScriptError::warningFlag,
                        NS_LITERAL_STRING("Invalid type for value parameter."));
    return NS_OK;
  }

  // Extract value parameter.
  Maybe<nsCString> value;
  if (aValue.isString()) {
    nsAutoJSString jsStr;
    if (!jsStr.init(cx, aValue)) {
      LogToBrowserConsole(nsIScriptError::warningFlag,
                          NS_LITERAL_STRING("Invalid string value for value parameter."));
      return NS_OK;
    }

    nsCString str = NS_ConvertUTF16toUTF8(jsStr);
    if (str.Length() > kMaxValueByteLength) {
      LogToBrowserConsole(nsIScriptError::warningFlag,
                          NS_LITERAL_STRING("Value parameter exceeds maximum string length, truncating."));
      TruncateToByteLength(str, kMaxValueByteLength);
    }
    value = mozilla::Some(str);
  }

  // Check extra argument.
  if ((optional_argc > 1) && !aExtra.isNull() && !aExtra.isObject()) {
    LogToBrowserConsole(nsIScriptError::warningFlag,
                        NS_LITERAL_STRING("Invalid type for extra parameter."));
    return NS_OK;
  }

  // Extract extra dictionary.
  ExtraArray extra;
  if (aExtra.isObject()) {
    JS::RootedObject obj(cx, &aExtra.toObject());
    JS::Rooted<JS::IdVector> ids(cx, JS::IdVector(cx));
    if (!JS_Enumerate(cx, obj, &ids)) {
      LogToBrowserConsole(nsIScriptError::warningFlag,
                          NS_LITERAL_STRING("Failed to enumerate object."));
      return NS_OK;
    }

    for (size_t i = 0, n = ids.length(); i < n; i++) {
      nsAutoJSString key;
      if (!key.init(cx, ids[i])) {
        LogToBrowserConsole(nsIScriptError::warningFlag,
                            NS_LITERAL_STRING("Extra dictionary should only contain string keys."));
        return NS_OK;
      }

      JS::Rooted<JS::Value> value(cx);
      if (!JS_GetPropertyById(cx, obj, ids[i], &value)) {
        LogToBrowserConsole(nsIScriptError::warningFlag,
                            NS_LITERAL_STRING("Failed to get extra property."));
        return NS_OK;
      }

      nsAutoJSString jsStr;
      if (!value.isString() || !jsStr.init(cx, value)) {
        LogToBrowserConsole(nsIScriptError::warningFlag,
                            NS_LITERAL_STRING("Extra properties should have string values."));
        return NS_OK;
      }

      nsCString str = NS_ConvertUTF16toUTF8(jsStr);
      if (str.Length() > kMaxExtraValueByteLength) {
        LogToBrowserConsole(nsIScriptError::warningFlag,
                            NS_LITERAL_STRING("Extra value exceeds maximum string length, truncating."));
        TruncateToByteLength(str, kMaxExtraValueByteLength);
      }

      extra.AppendElement(ExtraEntry{NS_ConvertUTF16toUTF8(key), str});
    }
  }

  // Lock for accessing internal data.
  // While the lock is being held, no complex calls like JS calls can be made,
  // as all of these could record Telemetry, which would result in deadlock.
  RecordEventResult res;
  {
    StaticMutexAutoLock lock(gTelemetryEventsMutex);

    if (!gInitDone) {
      return NS_ERROR_FAILURE;
    }

    res = ::RecordEvent(lock, timestamp, aCategory, aMethod, aObject, value, extra);
  }

  // Trigger warnings or errors where needed.
  switch (res) {
    case RecordEventResult::UnknownEvent: {
      JS_ReportErrorASCII(cx, R"(Unknown event: ["%s", "%s", "%s"])",
                          PromiseFlatCString(aCategory).get(),
                          PromiseFlatCString(aMethod).get(),
                          PromiseFlatCString(aObject).get());
      return NS_ERROR_INVALID_ARG;
    }
    case RecordEventResult::InvalidExtraKey:
      LogToBrowserConsole(nsIScriptError::warningFlag,
                          NS_LITERAL_STRING("Invalid extra key for event."));
      return NS_OK;
    case RecordEventResult::StorageLimitReached:
      LogToBrowserConsole(nsIScriptError::warningFlag,
                          NS_LITERAL_STRING("Event storage limit reached."));
      return NS_OK;
    default:
      return NS_OK;
  }
}

nsresult
TelemetryEvent::CreateSnapshots(uint32_t aDataset, bool aClear, JSContext* cx,
                                uint8_t optional_argc, JS::MutableHandleValue aResult)
{
  // Extract the events from storage.
  nsTArray<EventRecord> events;
  {
    StaticMutexAutoLock locker(gTelemetryEventsMutex);

    if (!gInitDone) {
      return NS_ERROR_FAILURE;
    }

    uint32_t len = gEventRecords->Length();
    for (uint32_t i = 0; i < len; ++i) {
      const EventRecord& record = (*gEventRecords)[i];
      const EventInfo& info = gEventInfo[record.EventId()];

      if (IsInDataset(info.common_info.dataset, aDataset)) {
        events.AppendElement(record);
      }
    }

    if (aClear) {
      gEventRecords->Clear();
    }
  }

  // We serialize the events to a JS array.
  JS::RootedObject eventsArray(cx, JS_NewArrayObject(cx, events.Length()));
  if (!eventsArray) {
    return NS_ERROR_FAILURE;
  }

  for (uint32_t i = 0; i < events.Length(); ++i) {
    const EventRecord& record = events[i];
    const EventInfo& info = gEventInfo[record.EventId()];

    // Each entry is an array of one of the forms:
    // [timestamp, category, method, object, value]
    // [timestamp, category, method, object, null, extra]
    // [timestamp, category, method, object, value, extra]
    JS::AutoValueVector items(cx);

    // Add timestamp.
    JS::Rooted<JS::Value> val(cx);
    if (!items.append(JS::NumberValue(floor(record.Timestamp())))) {
      return NS_ERROR_FAILURE;
    }

    // Add category, method, object.
    const char* strings[] = {
      info.common_info.category(),
      info.method(),
      info.object(),
    };
    for (const char* s : strings) {
      const NS_ConvertUTF8toUTF16 wide(s);
      if (!items.append(JS::StringValue(JS_NewUCStringCopyN(cx, wide.Data(), wide.Length())))) {
        return NS_ERROR_FAILURE;
      }
    }

    // Add the optional string value only when needed.
    // When extra is empty and this has no value, we can save a little space.
    if (record.Value()) {
      const NS_ConvertUTF8toUTF16 wide(record.Value().value());
      if (!items.append(JS::StringValue(JS_NewUCStringCopyN(cx, wide.Data(), wide.Length())))) {
        return NS_ERROR_FAILURE;
      }
    } else if (!record.Extra().IsEmpty()) {
      if (!items.append(JS::NullValue())) {
        return NS_ERROR_FAILURE;
      }
    }

    // Add the optional extra dictionary.
    // To save a little space, only add it when it is not empty.
    if (!record.Extra().IsEmpty()) {
      JS::RootedObject obj(cx, JS_NewPlainObject(cx));
      if (!obj) {
        return NS_ERROR_FAILURE;
      }

      // Add extra key & value entries.
      const ExtraArray& extra = record.Extra();
      for (uint32_t i = 0; i < extra.Length(); ++i) {
        const NS_ConvertUTF8toUTF16 wide(extra[i].value);
        JS::Rooted<JS::Value> value(cx);
        value.setString(JS_NewUCStringCopyN(cx, wide.Data(), wide.Length()));

        if (!JS_DefineProperty(cx, obj, extra[i].key.get(), value, JSPROP_ENUMERATE)) {
          return NS_ERROR_FAILURE;
        }
      }
      val.setObject(*obj);

      if (!items.append(val)) {
        return NS_ERROR_FAILURE;
      }
    }

    // Add the record to the events array.
    JS::RootedObject itemsArray(cx, JS_NewArrayObject(cx, items));
    if (!JS_DefineElement(cx, eventsArray, i, itemsArray, JSPROP_ENUMERATE)) {
      return NS_ERROR_FAILURE;
    }
  }

  aResult.setObject(*eventsArray);
  return NS_OK;
}

/**
 * Resets all the stored events. This is intended to be only used in tests.
 */
void
TelemetryEvent::ClearEvents()
{
  StaticMutexAutoLock lock(gTelemetryEventsMutex);

  if (!gInitDone) {
    return;
  }

  gEventRecords->Clear();
}

void
TelemetryEvent::SetEventRecordingEnabled(const nsACString& category, bool enabled)
{
  StaticMutexAutoLock locker(gTelemetryEventsMutex);

  uint32_t categoryId;
  if (!gCategoryNameIDMap.Get(category, &categoryId)) {
    LogToBrowserConsole(nsIScriptError::warningFlag,
                        NS_LITERAL_STRING("Unkown category for SetEventRecordingEnabled."));
    return;
  }

  if (enabled) {
    gEnabledCategories.PutEntry(categoryId);
  } else {
    gEnabledCategories.RemoveEntry(categoryId);
  }
}

size_t
TelemetryEvent::SizeOfIncludingThis(mozilla::MallocSizeOf aMallocSizeOf)
{
  StaticMutexAutoLock locker(gTelemetryEventsMutex);
  size_t n = 0;

  n += gEventRecords->ShallowSizeOfIncludingThis(aMallocSizeOf);
  for (uint32_t i = 0; i < gEventRecords->Length(); ++i) {
    n += (*gEventRecords)[i].SizeOfExcludingThis(aMallocSizeOf);
  }

  n += gEventNameIDMap.ShallowSizeOfExcludingThis(aMallocSizeOf);
  for (auto iter = gEventNameIDMap.ConstIter(); !iter.Done(); iter.Next()) {
    n += iter.Key().SizeOfExcludingThisIfUnshared(aMallocSizeOf);
  }

  n += gCategoryNameIDMap.ShallowSizeOfExcludingThis(aMallocSizeOf);
  for (auto iter = gCategoryNameIDMap.ConstIter(); !iter.Done(); iter.Next()) {
    n += iter.Key().SizeOfExcludingThisIfUnshared(aMallocSizeOf);
  }

  n += gEnabledCategories.ShallowSizeOfExcludingThis(aMallocSizeOf);

  return n;
}