2020-02-18 19:03:48 +03:00
|
|
|
#!/usr/bin/env python3
|
|
|
|
# Copyright (c) Facebook, Inc. and its affiliates.
|
|
|
|
#
|
|
|
|
# This software may be used and distributed according to the terms of the
|
|
|
|
# GNU General Public License version 2.
|
|
|
|
|
2020-02-26 05:56:44 +03:00
|
|
|
# pyre-strict
|
|
|
|
|
2020-02-27 08:15:16 +03:00
|
|
|
import abc
|
2020-02-18 19:03:48 +03:00
|
|
|
import getpass
|
|
|
|
import json
|
|
|
|
import logging
|
|
|
|
import platform
|
|
|
|
import random
|
|
|
|
import socket
|
2020-02-27 08:15:16 +03:00
|
|
|
import subprocess
|
|
|
|
import time
|
2020-02-27 08:15:16 +03:00
|
|
|
import types
|
2020-02-27 08:15:16 +03:00
|
|
|
from pathlib import Path
|
2020-03-03 19:01:07 +03:00
|
|
|
from typing import Dict, List, Optional, Set, Tuple, Type, Union
|
2020-02-18 19:03:48 +03:00
|
|
|
|
|
|
|
from . import version
|
|
|
|
|
|
|
|
|
2020-02-26 05:56:44 +03:00
|
|
|
log: logging.Logger = logging.getLogger(__name__)
|
2020-02-18 19:03:48 +03:00
|
|
|
|
|
|
|
_session_id: Optional[int] = None
|
|
|
|
|
2020-03-03 19:01:07 +03:00
|
|
|
_TelemetryTypes = Union[bool, int, str, float, Set[str]]
|
|
|
|
|
2020-02-27 08:15:16 +03:00
|
|
|
|
|
|
|
class TelemetrySample(abc.ABC):
|
2020-02-27 08:15:16 +03:00
|
|
|
_start_time: float = 0.0
|
2020-02-28 06:19:48 +03:00
|
|
|
_success_recorded: bool = False
|
2020-02-27 08:15:16 +03:00
|
|
|
|
|
|
|
def __enter__(self) -> "TelemetrySample":
|
|
|
|
self._start_time = time.time()
|
|
|
|
return self
|
|
|
|
|
|
|
|
def __exit__(
|
|
|
|
self,
|
|
|
|
exc_type: Optional[Type[BaseException]],
|
|
|
|
exc_value: Optional[BaseException],
|
|
|
|
exc_tracebac: Optional[types.TracebackType],
|
|
|
|
) -> bool:
|
|
|
|
duration = time.time() - self._start_time
|
|
|
|
self.add_double("duration", duration)
|
2020-02-28 06:19:48 +03:00
|
|
|
if not self._success_recorded:
|
|
|
|
if exc_type is None:
|
|
|
|
self.add_bool("success", True)
|
|
|
|
else:
|
|
|
|
self.add_bool("success", False)
|
|
|
|
self.add_string("error", str(exc_value))
|
2020-02-27 08:15:16 +03:00
|
|
|
self.log()
|
|
|
|
return False
|
|
|
|
|
2020-02-27 08:15:16 +03:00
|
|
|
@abc.abstractmethod
|
|
|
|
def add_int(self, name: str, value: int) -> "TelemetrySample":
|
|
|
|
raise NotImplementedError()
|
|
|
|
|
|
|
|
@abc.abstractmethod
|
|
|
|
def add_string(self, name: str, value: str) -> "TelemetrySample":
|
|
|
|
raise NotImplementedError()
|
|
|
|
|
|
|
|
@abc.abstractmethod
|
|
|
|
def add_double(self, name: str, value: float) -> "TelemetrySample":
|
|
|
|
raise NotImplementedError()
|
|
|
|
|
2020-03-03 19:01:07 +03:00
|
|
|
@abc.abstractmethod
|
|
|
|
def add_tags(self, name: str, value: Set[str]) -> "TelemetrySample":
|
|
|
|
raise NotImplementedError()
|
|
|
|
|
2020-02-27 08:15:16 +03:00
|
|
|
def add_bool(self, name: str, value: bool) -> "TelemetrySample":
|
|
|
|
return self.add_int(name, int(value))
|
|
|
|
|
2020-03-03 19:01:07 +03:00
|
|
|
def add_fields(self, **kwargs: _TelemetryTypes) -> "TelemetrySample":
|
2020-02-27 08:15:16 +03:00
|
|
|
for name, value in kwargs.items():
|
|
|
|
if isinstance(value, bool):
|
|
|
|
self.add_bool(name, value)
|
|
|
|
elif isinstance(value, str):
|
|
|
|
self.add_string(name, value)
|
|
|
|
elif isinstance(value, int):
|
|
|
|
self.add_int(name, value)
|
|
|
|
elif isinstance(value, float):
|
|
|
|
self.add_double(name, value)
|
2020-03-03 19:01:07 +03:00
|
|
|
elif isinstance(value, set):
|
|
|
|
self.add_tags(name, value)
|
2020-02-27 08:15:16 +03:00
|
|
|
else: # unsupported type
|
|
|
|
log.error(
|
|
|
|
f"unsupported value type {type(value)} passed to add_fields()"
|
|
|
|
)
|
|
|
|
return self
|
|
|
|
|
2020-02-28 06:19:48 +03:00
|
|
|
def fail(self, error_msg: str) -> None:
|
|
|
|
"""Mark the sample as a failure.
|
|
|
|
|
|
|
|
This sets the success field to 0 and sets an error message.
|
|
|
|
|
|
|
|
Prefer using this method over manually setting the "success" field. Otherwise
|
|
|
|
if you log this sample by using it in a `with` context the success field will be
|
|
|
|
overwritten with a successful value if the `with` context returns successfully.
|
|
|
|
"""
|
|
|
|
self.add_bool("success", False)
|
|
|
|
self.add_string("error", error_msg)
|
|
|
|
self._success_recorded = True
|
|
|
|
|
2020-02-27 08:15:16 +03:00
|
|
|
def log(self) -> None:
|
|
|
|
"""Log the sample to the telemetry data store."""
|
|
|
|
self.add_int("time", int(time.time()))
|
|
|
|
try:
|
|
|
|
self._log_impl()
|
|
|
|
except Exception as ex:
|
|
|
|
log.warning(f"error logging telemetry sample: {ex}")
|
|
|
|
|
|
|
|
@abc.abstractmethod
|
|
|
|
def _log_impl(self) -> None:
|
|
|
|
raise NotImplementedError()
|
2020-02-18 19:03:48 +03:00
|
|
|
|
|
|
|
|
2020-02-27 08:15:16 +03:00
|
|
|
class TelemetryLogger(abc.ABC):
|
2020-10-15 06:19:13 +03:00
|
|
|
"""TelemetryLogger provides an interface for logging structured log events."""
|
2020-02-27 08:15:16 +03:00
|
|
|
|
|
|
|
session_id: int
|
|
|
|
user: str
|
|
|
|
hostname: str
|
|
|
|
os: str
|
|
|
|
os_version: str
|
|
|
|
eden_version: str
|
|
|
|
|
2020-02-26 05:56:44 +03:00
|
|
|
def __init__(self) -> None:
|
2020-02-27 08:15:16 +03:00
|
|
|
self.session_id = get_session_id()
|
|
|
|
try:
|
|
|
|
self.user = getpass.getuser()
|
|
|
|
except Exception as ex:
|
|
|
|
log.warning(f"error determining username for telemetry logging: {ex}")
|
|
|
|
self.user = ""
|
|
|
|
try:
|
|
|
|
self.hostname = socket.gethostname()
|
|
|
|
except Exception as ex:
|
|
|
|
log.warning(f"error determining hostname for telemetry logging: {ex}")
|
|
|
|
self.hostname = ""
|
|
|
|
try:
|
|
|
|
self.os, self.os_version = get_os_and_ver()
|
|
|
|
except Exception as ex:
|
|
|
|
log.warning(f"error determining OS information for telemetry logging: {ex}")
|
|
|
|
self.os = ""
|
|
|
|
self.os_version = ""
|
|
|
|
try:
|
|
|
|
self.eden_version = version.get_current_version()
|
|
|
|
except Exception as ex:
|
|
|
|
log.warning(f"error determining EdenFS version for telemetry logging: {ex}")
|
|
|
|
self.eden_version = ""
|
|
|
|
|
2020-03-03 19:01:07 +03:00
|
|
|
def new_sample(self, event_type: str, **kwargs: _TelemetryTypes) -> TelemetrySample:
|
2020-02-27 08:15:16 +03:00
|
|
|
sample = self._create_sample()
|
|
|
|
sample.add_string("type", event_type)
|
|
|
|
sample.add_int("session_id", self.session_id)
|
|
|
|
sample.add_string("user", self.user)
|
|
|
|
sample.add_string("host", self.hostname)
|
|
|
|
sample.add_string("os", self.os)
|
|
|
|
sample.add_string("osver", self.os_version)
|
|
|
|
sample.add_string("edenver", self.eden_version)
|
|
|
|
sample.add_fields(**kwargs)
|
|
|
|
return sample
|
|
|
|
|
2020-03-03 19:01:07 +03:00
|
|
|
def log(self, event_type: str, **kwargs: _TelemetryTypes) -> None:
|
2020-02-27 08:15:16 +03:00
|
|
|
self.new_sample(event_type, **kwargs).log()
|
|
|
|
|
|
|
|
@abc.abstractmethod
|
|
|
|
def _create_sample(self) -> TelemetrySample:
|
|
|
|
raise NotImplementedError()
|
|
|
|
|
|
|
|
|
|
|
|
class JsonTelemetrySample(TelemetrySample):
|
|
|
|
def __init__(self, logger: "BaseJsonTelemetryLogger") -> None:
|
|
|
|
super().__init__()
|
2020-02-26 05:56:44 +03:00
|
|
|
self.ints: Dict[str, int] = {}
|
|
|
|
self.strings: Dict[str, str] = {}
|
|
|
|
self.doubles: Dict[str, float] = {}
|
2020-03-10 19:53:16 +03:00
|
|
|
self.tags: Dict[str, List[str]] = {}
|
2020-02-27 08:15:16 +03:00
|
|
|
self.logger: "BaseJsonTelemetryLogger" = logger
|
2020-02-18 19:03:48 +03:00
|
|
|
|
2020-02-27 08:15:16 +03:00
|
|
|
def add_int(self, name: str, value: int) -> "JsonTelemetrySample":
|
2020-02-18 19:03:48 +03:00
|
|
|
self.ints[name] = value
|
|
|
|
return self
|
|
|
|
|
2020-02-27 08:15:16 +03:00
|
|
|
def add_string(self, name: str, value: str) -> "JsonTelemetrySample":
|
2020-02-18 19:03:48 +03:00
|
|
|
self.strings[name] = value
|
|
|
|
return self
|
|
|
|
|
2020-02-27 08:15:16 +03:00
|
|
|
def add_double(self, name: str, value: float) -> "JsonTelemetrySample":
|
2020-02-18 19:03:48 +03:00
|
|
|
self.doubles[name] = value
|
|
|
|
return self
|
|
|
|
|
2020-03-03 19:01:07 +03:00
|
|
|
def add_tags(self, name: str, value: Set[str]) -> "JsonTelemetrySample":
|
2020-03-10 19:53:16 +03:00
|
|
|
self.tags[name] = list(value)
|
2020-03-03 19:01:07 +03:00
|
|
|
return self
|
|
|
|
|
2020-02-27 08:15:16 +03:00
|
|
|
def get_json(self) -> str:
|
2020-03-03 19:01:07 +03:00
|
|
|
data: Dict[
|
|
|
|
str,
|
|
|
|
Union[
|
2020-03-10 19:53:16 +03:00
|
|
|
Dict[str, str], Dict[str, int], Dict[str, float], Dict[str, List[str]]
|
2020-03-03 19:01:07 +03:00
|
|
|
],
|
|
|
|
] = {}
|
2020-02-18 19:03:48 +03:00
|
|
|
data["int"] = self.ints
|
|
|
|
data["normal"] = self.strings
|
|
|
|
if self.doubles:
|
|
|
|
data["double"] = self.doubles
|
2020-03-03 19:01:07 +03:00
|
|
|
if self.tags:
|
|
|
|
data["tags"] = self.tags
|
2020-02-18 19:03:48 +03:00
|
|
|
return json.dumps(data)
|
|
|
|
|
2020-02-27 08:15:16 +03:00
|
|
|
def _log_impl(self) -> None:
|
2020-02-28 06:19:48 +03:00
|
|
|
self.logger.log_sample(self)
|
2020-02-27 08:15:16 +03:00
|
|
|
|
|
|
|
|
|
|
|
class BaseJsonTelemetryLogger(TelemetryLogger):
|
|
|
|
def _create_sample(self) -> TelemetrySample:
|
|
|
|
return JsonTelemetrySample(self)
|
|
|
|
|
|
|
|
@abc.abstractmethod
|
2020-02-28 06:19:48 +03:00
|
|
|
def log_sample(self, sample: JsonTelemetrySample) -> None:
|
2020-02-27 08:15:16 +03:00
|
|
|
raise NotImplementedError()
|
|
|
|
|
|
|
|
|
|
|
|
class ExternalTelemetryLogger(BaseJsonTelemetryLogger):
|
2020-10-15 06:19:13 +03:00
|
|
|
"""A TelemetryLogger that uses an external process to log samples."""
|
2020-02-27 08:15:16 +03:00
|
|
|
|
|
|
|
cmd: List[str]
|
|
|
|
|
|
|
|
def __init__(self, cmd: List[str]) -> None:
|
|
|
|
super().__init__()
|
|
|
|
self.cmd = cmd[:]
|
|
|
|
|
2020-02-28 06:19:48 +03:00
|
|
|
def log_sample(self, sample: JsonTelemetrySample) -> None:
|
|
|
|
cmd = self.cmd + [sample.get_json()]
|
2020-02-27 08:15:16 +03:00
|
|
|
try:
|
|
|
|
rc = subprocess.call(cmd)
|
|
|
|
if rc != 0:
|
|
|
|
log.warning(f"telemetry log command returned non-zero exit code {rc}")
|
|
|
|
except Exception as ex:
|
|
|
|
log.warning(f"error calling telemetry log command: {ex}")
|
|
|
|
|
|
|
|
|
|
|
|
class LocalTelemetryLogger(BaseJsonTelemetryLogger):
|
|
|
|
"""A TelemetryLogger that logs samples to a local file.
|
|
|
|
This is primarily useful just for debugging during development.
|
|
|
|
"""
|
|
|
|
|
|
|
|
path: Path
|
|
|
|
|
|
|
|
def __init__(self, path: Union[str, Path]) -> None:
|
|
|
|
super().__init__()
|
|
|
|
self.path = Path(path)
|
|
|
|
|
2020-02-28 06:19:48 +03:00
|
|
|
def log_sample(self, sample: JsonTelemetrySample) -> None:
|
2020-02-27 08:15:16 +03:00
|
|
|
with self.path.open("a") as f:
|
2020-02-28 06:19:48 +03:00
|
|
|
f.write(sample.get_json() + "\n")
|
|
|
|
|
|
|
|
|
|
|
|
class TestTelemetryLogger(BaseJsonTelemetryLogger):
|
|
|
|
"""A TelemetryLogger that records all samples in a local list.
|
|
|
|
This is primarily useful for use in unit tests, so you can examine the samples
|
|
|
|
that were recorded.
|
|
|
|
"""
|
|
|
|
|
|
|
|
samples: List[JsonTelemetrySample] = []
|
|
|
|
|
|
|
|
def log_sample(self, sample: JsonTelemetrySample) -> None:
|
|
|
|
self.samples.append(sample)
|
2020-02-27 08:15:16 +03:00
|
|
|
|
|
|
|
|
|
|
|
class NullTelemetrySample(TelemetrySample):
|
|
|
|
def add_int(self, name: str, value: int) -> "NullTelemetrySample":
|
2020-07-20 23:26:26 +03:00
|
|
|
# pyre-fixme[7]: Expected `NullTelemetrySample` but got implicit return
|
|
|
|
# value of `None`.
|
2020-02-27 08:15:16 +03:00
|
|
|
pass
|
|
|
|
|
|
|
|
def add_string(self, name: str, value: str) -> "NullTelemetrySample":
|
2020-07-20 23:26:26 +03:00
|
|
|
# pyre-fixme[7]: Expected `NullTelemetrySample` but got implicit return
|
|
|
|
# value of `None`.
|
2020-02-27 08:15:16 +03:00
|
|
|
pass
|
|
|
|
|
|
|
|
def add_double(self, name: str, value: float) -> "NullTelemetrySample":
|
2020-07-20 23:26:26 +03:00
|
|
|
# pyre-fixme[7]: Expected `NullTelemetrySample` but got implicit return
|
|
|
|
# value of `None`.
|
2020-02-27 08:15:16 +03:00
|
|
|
pass
|
|
|
|
|
2020-03-03 19:01:07 +03:00
|
|
|
def add_tags(self, name: str, value: Set[str]) -> "NullTelemetrySample":
|
2020-07-20 23:26:26 +03:00
|
|
|
# pyre-fixme[7]: Expected `NullTelemetrySample` but got implicit return
|
|
|
|
# value of `None`.
|
2020-03-03 19:01:07 +03:00
|
|
|
pass
|
|
|
|
|
2020-02-27 08:15:16 +03:00
|
|
|
def add_bool(self, name: str, value: bool) -> "NullTelemetrySample":
|
2020-07-20 23:26:26 +03:00
|
|
|
# pyre-fixme[7]: Expected `NullTelemetrySample` but got implicit return
|
|
|
|
# value of `None`.
|
2020-02-27 08:15:16 +03:00
|
|
|
pass
|
|
|
|
|
2020-03-03 19:01:07 +03:00
|
|
|
def add_fields(self, **kwargs: _TelemetryTypes) -> "NullTelemetrySample":
|
2020-07-20 23:26:26 +03:00
|
|
|
# pyre-fixme[7]: Expected `NullTelemetrySample` but got implicit return
|
|
|
|
# value of `None`.
|
2020-02-27 08:15:16 +03:00
|
|
|
pass
|
|
|
|
|
|
|
|
def _log_impl(self) -> None:
|
|
|
|
pass
|
|
|
|
|
|
|
|
|
|
|
|
class NullTelemetryLogger(TelemetryLogger):
|
2020-10-15 06:19:13 +03:00
|
|
|
"""A TelemetryLogger that discards all samples."""
|
2020-02-27 08:15:16 +03:00
|
|
|
|
|
|
|
def _create_sample(self) -> TelemetrySample:
|
|
|
|
return NullTelemetrySample()
|
|
|
|
|
2020-02-18 19:03:48 +03:00
|
|
|
|
|
|
|
def get_session_id() -> int:
|
|
|
|
global _session_id
|
|
|
|
sid = _session_id
|
|
|
|
if sid is None:
|
|
|
|
sid = random.randrange(2 ** 32)
|
|
|
|
_session_id = sid
|
|
|
|
return sid
|
|
|
|
|
|
|
|
|
|
|
|
def get_os_and_ver() -> Tuple[str, str]:
|
|
|
|
os = platform.system()
|
|
|
|
if os == "Darwin":
|
|
|
|
os = "macOS"
|
|
|
|
if os == "":
|
|
|
|
os = "unknown"
|
|
|
|
|
|
|
|
ver = platform.release()
|
|
|
|
if ver == "":
|
|
|
|
ver = "unknown"
|
|
|
|
|
|
|
|
return os, ver
|