src/dctv/test_event_parser.py

# Copyright (C) 2020 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.
"""Test event parser routines"""

# pylint: disable=missing-docstring

import logging
from tempfile import NamedTemporaryFile
from contextlib import contextmanager

import numpy as np
from cytoolz import valmap
import pytest

from .trace_file_util import (
  BadTraceFileError,
  ParseFailureError,
)

from .util import (
  INT64,
)

from .model import TraceAnalysisSession, FileTraceContext
from .test_query import TestQueryTable

log = logging.getLogger(__name__)

@contextmanager
def trace_in_ntf(string):
  with NamedTemporaryFile(prefix="dctv-ep-test-", suffix=".trace") as ntf:
    ntf.write(string.encode("UTF-8"))
    ntf.flush()
    yield ntf

@contextmanager
def trace_session(string, time_basis_override=None, threads=False):
  with trace_in_ntf(string) as ntf, \
       TraceAnalysisSession(threads=threads) as session:
    session.mount_trace(["trace"],
                        FileTraceContext(
                          ntf.name,
                          force_ftrace=True,
                          time_basis_override=time_basis_override),
                        temp_hack_lenient_metadata=True)
    yield session

TEST_TRACE_BASIC = """\
       trace-cmd-12196 [005] d..3 276946.285107: sched_switch:         prev_comm=trace-cmd prev_pid=12196 prev_prio=120 prev_state=S ==> next_comm=swapper/5 next_pid=0 next_prio=120
          <idle>-0     [005] d..3 276946.285115: sched_waking:         comm=trace-cmd pid=12203 prio=120 target_cpu=006
          <idle>-0     [005] d..3 276946.285121: sched_wakeup:         comm=trace-cmd pid=12203 prio=120 target_cpu=004
          <idle>-0     [004] d..3 276946.285124: cpu_idle:             state=4294967295 cpu_id=4
          <idle>-0     [004] d..3 276946.285128: sched_waking:         comm=trace-cmd pid=12202 prio=120 target_cpu=004
          <idle>-0     [005] d..3 276946.285129: cpu_idle:             state=0 cpu_id=5
          <idle>-0     [004] d..3 276946.285131: sched_wakeup:         comm=trace-cmd pid=12202 prio=120 target_cpu=004
          <idle>-0     [004] d..3 276946.285134: sched_switch:         prev_comm=swapper/4 prev_pid=0 prev_prio=120 prev_state=R ==> next_comm=trace-cmd next_pid=12202 next_prio=120
       trace-cmd-12202 [004] d..3 276946.285141: sched_switch:         prev_comm=trace-cmd prev_pid=12202 prev_prio=120 prev_state=S ==> next_comm=trace-cmd next_pid=12203 next_prio=120
"""

def _array2str(array, st):
  return [b.decode("UTF-8") for b in st.vlookup(array)]

def _sessionq(session, sql, *, as_raw_array=False):
  result = dict(session.sql_query(sql))
  if not as_raw_array:
    result = valmap(lambda x: x.tolist(), result)
  return result

@pytest.mark.parametrize("threads", ["threads", "nothreads"])
def test_parse_events_basic(threads):
  # pylint: disable=bad-whitespace
  with trace_session(TEST_TRACE_BASIC,
                     threads=(threads=="threads")) as session:
    assert _sessionq(session, """
      SELECT event_type, COUNT(*) AS count FROM trace.raw_event_index
      GROUP BY event_type""") == TestQueryTable(
        names=["event_type", "count"],
        rows=[
          ["sched_switch", 3],
          ["sched_waking", 2],
          ["sched_wakeup", 2],
          ["cpu_idle",     2],
        ]).as_dict()
    assert _sessionq(session, """
    SELECT prev_tid, cpu, comm FROM trace.raw_events.sched_switch
    """) == TestQueryTable(
      names=["prev_tid", "cpu", "comm"],
      rows=[
        [12196, 5, "trace-cmd"],
        [0, 4, "<idle>"],
        [12202, 4, "trace-cmd"],
      ]).as_dict()

def test_parse_events_ts():
  with trace_session(TEST_TRACE_BASIC, time_basis_override=0) as session:
    assert _sessionq(session, """
    SELECT _ts FROM trace.raw_events.sched_switch""") == \
    TestQueryTable(
      names=["_ts"],
      rows=[
        [276946285107000],
        [276946285134000],
        [276946285141000],
      ]).as_dict()

def test_parse_events_time_basis():
  with trace_session(TEST_TRACE_BASIC) as session:
    assert _sessionq(session, """
    SELECT _ts FROM trace.raw_events.sched_switch""") == \
    TestQueryTable(
      names=["_ts"],
      rows=[
        [0],
        [27000],
        [34000],
      ]).as_dict()

def test_fake_empty_event_list():
  with trace_session(TEST_TRACE_BASIC) as session:
    result = _sessionq(session, """
    SELECT _ts, handler_name FROM trace.raw_events.irq_handler_entry
    """, as_raw_array=True)
    assert result["_ts"].dtype == INT64
    assert result["handler_name"].dtype == np.dtype("O")

def test_last_ts():
  with trace_session(TEST_TRACE_BASIC) as session:
    assert _sessionq(session, "SELECT EVENT * FROM trace.last_ts") == \
      dict(_ts=[34000])

TEST_TRACE_BAD_PAYLOAD_SS = """\
       TRACE-cmd-12196 [005] d..3 276946.285107: sched_switch:         prev_comm=trace-cmd prev_pid=12196 prev_prio=120 prev_state=S ==> next_comm=swapper/5 next_pid=0 next_prio=120
       trace-cmd-12202 [004] d..3 276946.285141: sched_switch:         prev_comm=trace-cmd INVALID_FIELD=12202 prev_prio=120 prev_state=S ==> next_comm=trace-cmd next_pid=12203 next_prio=120
"""

def test_parse_event_error():
  with trace_session(TEST_TRACE_BAD_PAYLOAD_SS) as session:
    with pytest.raises(BadTraceFileError) as ex:
      _sessionq(session,
                "SELECT prev_tid FROM trace.raw_events.sched_switch")
    assert "INVALID_FIELD" in str(ex)
    cause = ex.value.__cause__
    assert isinstance(cause, ParseFailureError)
    assert cause.offset == 182

TEST_TRACE_BAD_INDEX = """\
       TRACE-cmd-12196 [005] d..3 276946.285107: sched_switch:         prev_comm=trace-cmd prev_pid=12196 prev_prio=120 prev_state=S ==> next_comm=swapper/5 next_pid=0 next_prio=120
       dsfaadfsfasf
"""

def test_index_error():
  with trace_session(TEST_TRACE_BAD_INDEX) as session:
    with pytest.raises(BadTraceFileError) as ex:
      _sessionq(session,
                "SELECT prev_tid FROM trace.raw_events.sched_switch")
  assert "index error" in str(ex)
  cause = ex.value.__cause__
  assert isinstance(cause, ParseFailureError)
  assert 182 <= cause.offset < len(TEST_TRACE_BAD_INDEX)