def test_outcome_consumer_ignores_outcomes_already_handled(
kafka_producer, task_runner, kafka_admin, requires_kafka):
producer, project_id, topic_name = _setup_outcome_test(
kafka_producer, kafka_admin)
group_id = "test-outcome-consumer-1"
last_event_id = None
# put a few outcome messages on the kafka topic and also mark them in the cache
for i in range(4):
msg = _get_outcome(
event_id=i,
project_id=project_id,
outcome=Outcome.FILTERED,
reason="some_reason",
remote_addr="127.33.44.{}".format(i),
)
if i in (0, 1):
# pretend that we have already processed this outcome before
mark_signal_sent(project_id=project_id, event_id=_get_event_id(i))
else:
# Last event is used to check when the outcome producer is done
last_event_id = _get_event_id(i)
# put the outcome on the kafka topic
producer.produce(topic_name, msg)
# setup django signals for event_filtered and event_dropped
event_filtered_sink = []
event_dropped_sink = []
def event_filtered_receiver(**kwargs):
event_filtered_sink.append(kwargs.get("ip"))
def event_dropped_receiver(**kwargs):
event_dropped_sink.append("something")
event_filtered.connect(event_filtered_receiver)
event_dropped.connect(event_dropped_receiver)
consumer = get_outcomes_consumer(max_batch_size=1,
max_batch_time=100,
group_id=group_id,
auto_offset_reset="earliest")
# run the outcome consumer
with task_runner():
i = 0
while (not is_signal_sent(project_id=project_id,
event_id=last_event_id)
and i < MAX_POLL_ITERATIONS):
consumer._run_once()
i += 1
assert is_signal_sent(project_id=project_id, event_id=last_event_id)
# verify that no signal was called (since the events have been previously processed)
assert event_filtered_sink == ["127.33.44.2", "127.33.44.3"]
assert len(event_dropped_sink) == 0
def test_outcome_consumer_ignores_outcomes_already_handled(
kafka_producer, task_runner, kafka_admin
):
producer, project_id, topic_name = _setup_outcome_test(kafka_producer, kafka_admin)
consumer_group = "test-outcome-consumer-1"
# put a few outcome messages on the kafka topic and also mark them in the cache
for i in six.moves.range(1, 3):
msg = _get_outcome(
event_id=i,
project_id=project_id,
outcome=Outcome.FILTERED,
reason="some_reason",
remote_addr="127.33.44.{}".format(i),
)
# pretend that we have already processed this outcome before
mark_signal_sent(project_id=project_id, event_id=_get_event_id(i))
# put the outcome on the kafka topic
producer.produce(topic_name, msg)
# setup django signals for event_filtered and event_dropped
event_filtered_sink = []
event_dropped_sink = []
def event_filtered_receiver(**kwargs):
event_filtered_sink.append(kwargs.get("ip"))
def event_dropped_receiver(**kwargs):
event_dropped_sink.append("something")
event_filtered.connect(event_filtered_receiver)
event_dropped.connect(event_dropped_receiver)
# run the outcome consumer
with task_runner():
run_outcomes_consumer(
commit_batch_size=2,
consumer_group=consumer_group,
max_fetch_time_seconds=0.1,
initial_offset_reset="earliest",
is_shutdown_requested=_shutdown_requested(
max_secs=10, num_outcomes=1, signal_sink=event_filtered_sink
),
)
# verify that no signal was called (since the events have been previously processed)
assert len(event_filtered_sink) == 0
assert len(event_dropped_sink) == 0
def process_event(event_manager, project, key, remote_addr, helper, attachments, project_config):
event_received.send_robust(ip=remote_addr, project=project, sender=process_event)
start_time = time()
data = event_manager.get_data()
should_filter, filter_reason = event_manager.should_filter()
del event_manager
event_id = data["event_id"]
if should_filter:
signals_in_consumer = decide_signals_in_consumer()
if not signals_in_consumer:
# Mark that the event_filtered signal is sent. Do this before emitting
# the outcome to avoid a potential race between OutcomesConsumer and
# `event_filtered.send_robust` below.
mark_signal_sent(project_config.project_id, event_id)
track_outcome(
project_config.organization_id,
project_config.project_id,
key.id,
Outcome.FILTERED,
filter_reason,
event_id=event_id,
)
metrics.incr("events.blacklisted", tags={"reason": filter_reason}, skip_internal=False)
if not signals_in_consumer:
event_filtered.send_robust(ip=remote_addr, project=project, sender=process_event)
# relay will no longer be able to provide information about filter
# status so to see the impact we're adding a way to turn on relay
# like behavior here.
if options.get("store.lie-about-filter-status"):
return event_id
raise APIForbidden("Event dropped due to filter: %s" % (filter_reason,))
# TODO: improve this API (e.g. make RateLimit act on __ne__)
rate_limit = safe_execute(
quotas.is_rate_limited, project=project, key=key, _with_transaction=False
)
if isinstance(rate_limit, bool):
rate_limit = RateLimit(is_limited=rate_limit, retry_after=None)
# XXX(dcramer): when the rate limiter fails we drop events to ensure
# it cannot cascade
if rate_limit is None or rate_limit.is_limited:
if rate_limit is None:
api_logger.debug("Dropped event due to error with rate limiter")
signals_in_consumer = decide_signals_in_consumer()
if not signals_in_consumer:
# Mark that the event_dropped signal is sent. Do this before emitting
# the outcome to avoid a potential race between OutcomesConsumer and
# `event_dropped.send_robust` below.
mark_signal_sent(project_config.project_id, event_id)
reason = rate_limit.reason_code if rate_limit else None
track_outcome(
project_config.organization_id,
project_config.project_id,
key.id,
Outcome.RATE_LIMITED,
reason,
event_id=event_id,
)
metrics.incr("events.dropped", tags={"reason": reason or "unknown"}, skip_internal=False)
if not signals_in_consumer:
event_dropped.send_robust(
ip=remote_addr, project=project, reason_code=reason, sender=process_event
)
if rate_limit is not None:
raise APIRateLimited(rate_limit.retry_after)
# TODO(dcramer): ideally we'd only validate this if the event_id was
# supplied by the user
cache_key = "ev:%s:%s" % (project_config.project_id, event_id)
if cache.get(cache_key) is not None:
track_outcome(
project_config.organization_id,
project_config.project_id,
key.id,
Outcome.INVALID,
"duplicate",
event_id=event_id,
)
raise APIForbidden("An event with the same ID already exists (%s)" % (event_id,))
config = project_config.config
datascrubbing_settings = config.get("datascrubbingSettings") or {}
data = _scrub_event_data(data, datascrubbing_settings)
# mutates data (strips a lot of context if not queued)
helper.insert_data_to_database(data, start_time=start_time, attachments=attachments)
cache.set(cache_key, "", 60 * 60) # Cache for 1 hour
api_logger.debug("New event received (%s)", event_id)
event_accepted.send_robust(ip=remote_addr, data=data, project=project, sender=process_event)
return event_id
def _do_save_event(cache_key=None,
data=None,
start_time=None,
event_id=None,
project_id=None,
**kwargs):
"""
Saves an event to the database.
"""
from sentry.event_manager import HashDiscarded, EventManager
from sentry import quotas
from sentry.models import ProjectKey
from sentry.utils.outcomes import Outcome, track_outcome
from sentry.ingest.outcomes_consumer import mark_signal_sent
event_type = "none"
if cache_key and data is None:
with metrics.timer(
"tasks.store.do_save_event.get_cache") as metric_tags:
data = default_cache.get(cache_key)
if data is not None:
metric_tags["event_type"] = event_type = data.get(
"type") or "none"
with metrics.global_tags(event_type=event_type):
if data is not None:
data = CanonicalKeyDict(data)
if event_id is None and data is not None:
event_id = data["event_id"]
# only when we come from reprocessing we get a project_id sent into
# the task.
if project_id is None:
project_id = data.pop("project")
key_id = None if data is None else data.get("key_id")
if key_id is not None:
key_id = int(key_id)
timestamp = to_datetime(start_time) if start_time is not None else None
# We only need to delete raw events for events that support
# reprocessing. If the data cannot be found we want to assume
# that we need to delete the raw event.
if not data or reprocessing.event_supports_reprocessing(data):
with metrics.timer("tasks.store.do_save_event.delete_raw_event"):
delete_raw_event(project_id, event_id, allow_hint_clear=True)
# This covers two cases: where data is None because we did not manage
# to fetch it from the default cache or the empty dictionary was
# stored in the default cache. The former happens if the event
# expired while being on the queue, the second happens on reprocessing
# if the raw event was deleted concurrently while we held on to
# it. This causes the node store to delete the data and we end up
# fetching an empty dict. We could in theory not invoke `save_event`
# in those cases but it's important that we always clean up the
# reprocessing reports correctly or they will screw up the UI. So
# to future proof this correctly we just handle this case here.
if not data:
metrics.incr("events.failed",
tags={
"reason": "cache",
"stage": "post"
},
skip_internal=False)
return
with configure_scope() as scope:
scope.set_tag("project", project_id)
event = None
try:
with metrics.timer("tasks.store.do_save_event.event_manager.save"):
manager = EventManager(data)
# event.project.organization is populated after this statement.
event = manager.save(project_id,
assume_normalized=True,
cache_key=cache_key)
with metrics.timer("tasks.store.do_save_event.track_outcome"):
# This is where we can finally say that we have accepted the event.
track_outcome(
event.project.organization_id,
event.project.id,
key_id,
Outcome.ACCEPTED,
None,
timestamp,
event_id,
)
except HashDiscarded:
project = Project.objects.get_from_cache(id=project_id)
reason = FilterStatKeys.DISCARDED_HASH
project_key = None
try:
if key_id is not None:
project_key = ProjectKey.objects.get_from_cache(id=key_id)
except ProjectKey.DoesNotExist:
pass
quotas.refund(project, key=project_key, timestamp=start_time)
# There is no signal supposed to be sent for this particular
# outcome-reason combination. Prevent the outcome consumer from
# emitting it for now.
#
# XXX(markus): Revisit decision about signals once outcomes consumer is stable.
mark_signal_sent(project_id, event_id)
track_outcome(
project.organization_id,
project_id,
key_id,
Outcome.FILTERED,
reason,
timestamp,
event_id,
)
finally:
if cache_key:
with metrics.timer("tasks.store.do_save_event.delete_cache"):
default_cache.delete(cache_key)
with metrics.timer(
"tasks.store.do_save_event.delete_attachment_cache"):
# For the unlikely case that we did not manage to persist the
# event we also delete the key always.
if event is None or features.has(
"organizations:event-attachments",
event.project.organization,
actor=None):
attachment_cache.delete(cache_key)
if start_time:
metrics.timing("events.time-to-process",
time() - start_time,
instance=data["platform"])
def process_event(event_manager, project, key, remote_addr, helper,
attachments, project_config):
event_received.send_robust(ip=remote_addr,
project=project,
sender=process_event)
start_time = time()
data = event_manager.get_data()
should_filter, filter_reason = event_manager.should_filter()
del event_manager
event_id = data["event_id"]
if should_filter:
# Mark that the event_filtered signal is sent. Do this before emitting
# the outcome to avoid a potential race between OutcomesConsumer and
# `event_filtered.send_robust` below.
mark_signal_sent(project_config.project_id, event_id)
track_outcome(
project_config.organization_id,
project_config.project_id,
key.id,
Outcome.FILTERED,
filter_reason,
event_id=event_id,
)
metrics.incr("events.blacklisted",
tags={"reason": filter_reason},
skip_internal=False)
event_filtered.send_robust(ip=remote_addr,
project=project,
sender=process_event)
raise APIForbidden("Event dropped due to filter: %s" %
(filter_reason, ))
# TODO: improve this API (e.g. make RateLimit act on __ne__)
rate_limit = safe_execute(quotas.is_rate_limited,
project=project,
key=key,
_with_transaction=False)
if isinstance(rate_limit, bool):
rate_limit = RateLimit(is_limited=rate_limit, retry_after=None)
# XXX(dcramer): when the rate limiter fails we drop events to ensure
# it cannot cascade
if rate_limit is None or rate_limit.is_limited:
if rate_limit is None:
api_logger.debug("Dropped event due to error with rate limiter")
# Mark that the event_dropped signal is sent. Do this before emitting
# the outcome to avoid a potential race between OutcomesConsumer and
# `event_dropped.send_robust` below.
mark_signal_sent(project_config.project_id, event_id)
reason = rate_limit.reason_code if rate_limit else None
track_outcome(
project_config.organization_id,
project_config.project_id,
key.id,
Outcome.RATE_LIMITED,
reason,
event_id=event_id,
)
metrics.incr("events.dropped",
tags={"reason": reason or "unknown"},
skip_internal=False)
event_dropped.send_robust(ip=remote_addr,
project=project,
reason_code=reason,
sender=process_event)
if rate_limit is not None:
raise APIRateLimited(rate_limit.retry_after)
# TODO(dcramer): ideally we'd only validate this if the event_id was
# supplied by the user
cache_key = "ev:%s:%s" % (project_config.project_id, event_id)
if cache.get(cache_key) is not None:
track_outcome(
project_config.organization_id,
project_config.project_id,
key.id,
Outcome.INVALID,
"duplicate",
event_id=event_id,
)
raise APIForbidden("An event with the same ID already exists (%s)" %
(event_id, ))
config = project_config.config
datascrubbing_settings = config.get("datascrubbingSettings") or {}
scrub_ip_address = datascrubbing_settings.get("scrubIpAddresses")
scrub_data = datascrubbing_settings.get("scrubData")
if scrub_data:
# We filter data immediately before it ever gets into the queue
sensitive_fields = datascrubbing_settings.get("sensitiveFields")
exclude_fields = datascrubbing_settings.get("excludeFields")
scrub_defaults = datascrubbing_settings.get("scrubDefaults")
SensitiveDataFilter(fields=sensitive_fields,
include_defaults=scrub_defaults,
exclude_fields=exclude_fields).apply(data)
if scrub_ip_address:
# We filter data immediately before it ever gets into the queue
helper.ensure_does_not_have_ip(data)
# mutates data (strips a lot of context if not queued)
helper.insert_data_to_database(data,
start_time=start_time,
attachments=attachments)
cache.set(cache_key, "", 60 * 60) # Cache for 1 hour
api_logger.debug("New event received (%s)", event_id)
event_accepted.send_robust(ip=remote_addr,
data=data,
project=project,
sender=process_event)
return event_id
