Skip to content

Commit dbcbd64

Browse files
committed
[MOB-46781] Parse actionId for errors
- Jira: https://perforce.atlassian.net/browse/MOB-46781
1 parent 10fae44 commit dbcbd64

File tree

4 files changed

+157
-16
lines changed

4 files changed

+157
-16
lines changed

bzt/modules/_apiritif/generator.py

Lines changed: 69 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -62,6 +62,75 @@ def create_method_name(label):
6262

6363

6464
class ApiritifScriptGenerator(object):
65+
def _gen_class_actionid_tracking(self):
66+
# Add _current_actionId to the class and update it on each action_start
67+
return [
68+
ast.Assign(
69+
targets=[ast_attr("self._current_actionId")],
70+
value=ast.Constant(value=None, kind="")
71+
)
72+
]
73+
74+
def _gen_action_start_with_tracking(self, actionId):
75+
# Assign actionId to self._current_actionId before action_start
76+
return [
77+
ast.Assign(
78+
targets=[ast_attr("self._current_actionId")],
79+
value=ast.Constant(value=actionId, kind="")
80+
)
81+
]
82+
83+
def _gen_teardown_with_actionid(self):
84+
# Print the last actionId if an error occurred
85+
return ast.FunctionDef(
86+
name="tearDown",
87+
args=[ast.Name(id='self', ctx=ast.Param())],
88+
body=[
89+
ast.If(
90+
test=ast_attr("self.driver"),
91+
body=[ast.Expr(ast_call(func=ast_attr("self.driver.quit")))],
92+
orelse=[]
93+
),
94+
ast.If(
95+
test=ast.Call(
96+
func=ast.Name(id="hasattr", ctx=ast.Load()),
97+
args=[ast.Name(id="self", ctx=ast.Load()), ast.Constant("_outcome", kind="")],
98+
keywords=[]
99+
),
100+
body=[
101+
ast.If(
102+
test=ast.Attribute(
103+
value=ast.Attribute(
104+
value=ast.Name(id="self", ctx=ast.Load()),
105+
attr="_outcome",
106+
ctx=ast.Load()
107+
),
108+
attr="errors",
109+
ctx=ast.Load()
110+
),
111+
body=[
112+
ast.Expr(ast_call(
113+
func=ast.Name(id="print", ctx=ast.Load()),
114+
args=[ast.BinOp(
115+
left=ast.Constant("[TAURUS][actionId] ", kind=""),
116+
op=ast.Add(),
117+
right=ast.Call(
118+
func=ast.Name(id="str", ctx=ast.Load()),
119+
args=[ast_attr("self._current_actionId")],
120+
keywords=[]
121+
)
122+
)],
123+
keywords=[]
124+
))
125+
],
126+
orelse=[]
127+
)
128+
],
129+
orelse=[]
130+
)
131+
],
132+
decorator_list=[]
133+
)
65134
BYS = {
66135
'xpath': "XPATH",
67136
'css': "CSS_SELECTOR",

bzt/modules/aggregator.py

Lines changed: 29 additions & 8 deletions
Original file line numberDiff line numberDiff line change
@@ -232,6 +232,7 @@ def __init__(self, perc_levels=(), hist_max_rt=1000.0, ext_aggregation=False):
232232
self[KPISet.RESP_CODES] = Counter()
233233
self[KPISet.PERCENTILES] = {}
234234
self.ext_aggregation = ext_aggregation
235+
self.log = logging.getLogger(self.__class__.__name__)
235236

236237
def __deepcopy__(self, memo):
237238
mycopy = KPISet(self.perc_levels, self[KPISet.RESP_TIMES].high)
@@ -248,10 +249,12 @@ def __deepcopy__(self, memo):
248249
@staticmethod
249250
def error_item_skel(
250251
error: str, ret_c: str, cnt: int, err_type: int,
251-
urls: Counter, tag: str, err_resp_data: Optional[ErrorResponseData] = None) -> dict:
252+
urls: Counter, tag: str, err_resp_data: Optional[ErrorResponseData] = None, action_id: str = None) -> dict:
252253
assert isinstance(urls, collections.Counter)
254+
logging.getLogger("DEV DEV").info("In error_item_skel, err_resp_data: {}".format(err_resp_data))
253255
response_bodies = KPISet._get_response_bodies(err_resp_data)
254-
return {
256+
logging.getLogger("DEV DEV").info("In error_item_skel, response_bodies: {}".format(response_bodies))
257+
item = {
255258
"cnt": cnt,
256259
"msg": error,
257260
"tag": tag, # just one more string qualifier
@@ -260,6 +263,9 @@ def error_item_skel(
260263
"urls": urls,
261264
"responseBodies": response_bodies
262265
}
266+
if action_id is not None:
267+
item["action_id"] = action_id
268+
return item
263269

264270
@staticmethod
265271
def _get_response_bodies(err_resp_data: Optional[ErrorResponseData]) -> list:
@@ -276,11 +282,15 @@ def _get_response_bodies(err_resp_data: Optional[ErrorResponseData]) -> list:
276282

277283
def add_sample(self, sample):
278284
"""
279-
Add sample, consisting of: cnc, rt, cn, lt, rc, error, trname, byte_count
285+
Add sample, consisting of: cnc, rt, cn, lt, rc, error, trname, byte_count, [action_id]
280286
281287
:type sample: tuple
282288
"""
283-
cnc, r_time, con_time, latency, r_code, error, trname, byte_count = sample
289+
if len(sample) == 9:
290+
cnc, r_time, con_time, latency, r_code, error, trname, byte_count, action_id = sample
291+
else:
292+
cnc, r_time, con_time, latency, r_code, error, trname, byte_count = sample
293+
action_id = None
284294
self[self.SAMPLE_COUNT] += 1
285295
if cnc:
286296
self.add_concurrency(cnc, trname)
@@ -297,8 +307,19 @@ def add_sample(self, sample):
297307

298308
if error is not None:
299309
self[self.FAILURES] += 1
300-
301-
item = self.error_item_skel(error, r_code, 1, KPISet.ERRTYPE_ERROR, Counter(), None)
310+
self.log.info(f"DEV DEV: error: {error}")
311+
self.log.info(f"DEV DEV: r_code: {r_code}")
312+
self.log.info(f"DEV DEV: error: {error}")
313+
self.log.info(f"DEV DEV: action_id: {action_id}")
314+
item = self.error_item_skel(
315+
error,
316+
r_code,
317+
1,
318+
KPISet.ERRTYPE_ERROR,
319+
Counter(),
320+
None,
321+
action_id=action_id)
322+
self.log.info(f"DEV DEV: item: {item}")
302323
self.inc_list(self[self.ERRORS], ("msg", error), item)
303324
else:
304325
self[self.SUCCESSES] += 1
@@ -739,7 +760,7 @@ def __aggregate_current(self, datapoint, samples):
739760

740761
if self.generalize_labels:
741762
base_label = self._generalize_label(base_label)
742-
763+
self.log.info(f"Sample: {sample}")
743764
self.__add_sample(current, base_label, sample[1:])
744765

745766
overall = KPISet(self.track_percentiles, self.__get_rtimes_max(''), ext_aggregation=self._redundant_aggregation)
@@ -767,7 +788,7 @@ def __add_sample(self, current, label, kpis):
767788
perc_levels=self.track_percentiles,
768789
hist_max_rt=self.__get_rtimes_max(label),
769790
ext_aggregation=self._redundant_aggregation)
770-
791+
self.log.info(f"kpis: {kpis}")
771792
current[label].add_sample(kpis)
772793

773794
def __get_rtimes_max(self, label):

bzt/modules/functional.py

Lines changed: 46 additions & 6 deletions
Original file line numberDiff line numberDiff line change
@@ -18,7 +18,8 @@
1818
from bzt.engine import Aggregator
1919
from bzt.modules.aggregator import ResultsReader
2020
from bzt.utils import BetterDict, iteritems, LDJSONReader
21-
21+
import pprint
22+
import logging
2223

2324
class FunctionalAggregator(Aggregator):
2425
"""
@@ -35,10 +36,12 @@ def __init__(self):
3536

3637
def add_underling(self, reader):
3738
assert isinstance(reader, FunctionalResultsReader)
39+
self.log.info("DEV DEV: adding underling: %s", pprint.pformat(vars(reader)))
3840
self.underlings.append(reader)
3941

4042
def add_listener(self, listener):
4143
assert isinstance(listener, FunctionalAggregatorListener)
44+
self.log.info("DEV DEV: adding listener: %s", pprint.pformat(vars(listener)))
4245
self.listeners.append(listener)
4346

4447
def prepare(self):
@@ -49,11 +52,13 @@ def process_readers(self, last_pass=False):
4952

5053
for reader in self.underlings:
5154
for sample in reader.read(last_pass):
55+
self.log.info("DEV DEV: sample in process: %s", pprint.pformat(sample.__dict__))
5256
new_results.add_sample(sample)
5357

5458
if new_results:
5559
self.cumulative_results.merge(new_results)
5660
for listener in self.listeners:
61+
self.log.info("DEV DEV: functional aggregated_results: %s", pprint.pformat(self.cumulative_results.__dict__))
5762
listener.aggregated_results(new_results, self.cumulative_results)
5863

5964
def check(self):
@@ -65,10 +70,20 @@ def post_process(self):
6570

6671

6772
class FunctionalSample(object):
73+
def to_error_dict(self):
74+
err = {
75+
"error_msg": self.error_msg,
76+
"error_trace": self.error_trace,
77+
"status": self.status,
78+
}
79+
if getattr(self, "actionId", None):
80+
err["actionId"] = self.actionId
81+
return err
82+
6883
def __init__(
6984
self, test_case, test_suite, status,
7085
start_time, duration, error_msg, error_trace,
71-
extras=None, subsamples=None, path=None,
86+
extras=None, subsamples=None, path=None, actionId=None
7287
):
7388
# test_case: str - name of test case (method)
7489
# test_suite: str - name of test suite (class)
@@ -90,6 +105,7 @@ def __init__(
90105
self.extras = extras or {}
91106
self.subsamples = subsamples or []
92107
self.path = path or []
108+
self.actionId = actionId
93109

94110
def get_fqn(self):
95111
if self.path:
@@ -112,18 +128,25 @@ def get_type(self):
112128
class ResultsTree(BetterDict):
113129
def __init__(self):
114130
super(ResultsTree, self).__init__()
131+
self.log = logging.getLogger(self.__class__.__name__)
115132

116133
def add_sample(self, sample):
117134
"""
118135
:type sample: FunctionalSample
119136
"""
120137
test_suite = sample.test_suite
138+
self.log.info("DEV DEV: adding sample to suite: %s", pprint.pformat(vars(sample)))
139+
self.log.info("DEV DEV: test_suite: %s", pprint.pformat(test_suite))
140+
if hasattr(sample, "error_msg") and sample.error_msg:
141+
self.log.info("DEV DEV: Adding error sample with error dict: %s", sample.to_error_dict())
121142
self.get(test_suite, [], force_set=True).append(sample)
122143

123144
def test_suites(self):
124145
return [key for key, _ in iteritems(self)]
125146

126147
def test_cases(self, suite_name):
148+
test_cases = self.get(suite_name, [])
149+
self.log.info("DEV DEV: In results tree test_cases: %s", [sample.to_error_dict() for sample in test_cases])
127150
return self.get(suite_name, [])
128151

129152

@@ -237,6 +260,8 @@ class FuncSamplesReader(FunctionalResultsReader):
237260
FIELDS_EXTRACTED_TO_ARTIFACTS = ["requestBody", "responseBody", "requestCookiesRaw"]
238261

239262
def __init__(self, filename, engine, parent_logger):
263+
import logging
264+
self.log = logging.getLogger(self.__class__.__name__)
240265
self.report_reader = TestReportReader(filename, parent_logger)
241266
self.engine = engine
242267
self.read_records = 0
@@ -257,14 +282,29 @@ def _write_sample_data_to_artifacts(self, sample_extras):
257282

258283
def _samples_from_row(self, row):
259284
result = []
285+
self.log.info("DEV DEV: In _samples_from_row, row: %s", pprint.pformat(row))
260286
subsamples = [sample for item in row.get("subsamples", []) for sample in self._samples_from_row(item)]
261287
if any(subsample.get_type() == 'transaction' for subsample in subsamples):
288+
self.log.info("DEV DEV: In _samples_from_row if")
289+
for sub in subsamples:
290+
if sub.get_type() == 'transaction':
291+
self.log.info("DEV DEV: transaction subsample actionId: %s", getattr(sub, 'actionId', None))
262292
result.extend([sub for sub in subsamples if sub.get_type() == 'transaction'])
263293
else:
264-
sample = FunctionalSample(test_case=row["test_case"], test_suite=row["test_suite"],
265-
status=row["status"], start_time=row["start_time"], duration=row["duration"],
266-
error_msg=row["error_msg"], error_trace=row["error_trace"],
267-
extras=row.get("extras", {}), subsamples=subsamples, path=row.get("path", []))
294+
self.log.info("DEV DEV: In _samples_from_row else")
295+
sample = FunctionalSample(
296+
test_case=row["test_case"],
297+
test_suite=row["test_suite"],
298+
status=row["status"],
299+
start_time=row["start_time"],
300+
duration=row["duration"],
301+
error_msg=row["error_msg"],
302+
error_trace=row["error_trace"],
303+
extras=row.get("extras", {}),
304+
subsamples=subsamples,
305+
path=row.get("path", []),
306+
actionId=row.get("actionId") or row.get("action_id")
307+
)
268308
result.append(sample)
269309
return result
270310

bzt/modules/reporting.py

Lines changed: 13 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -17,10 +17,12 @@
1717
"""
1818
import copy
1919
import csv
20+
import logging
2021
import os
2122
import time
2223
from collections import Counter, OrderedDict
2324
from datetime import datetime
25+
import pprint
2426

2527
from terminaltables3 import AsciiTable
2628

@@ -46,6 +48,7 @@ def __init__(self):
4648
self.end_time = time.time()
4749
self.first_ts = float("inf")
4850
self.last_ts = 0
51+
self.log = logging.getLogger(self.__class__.__name__)
4952

5053
def startup(self):
5154
self.start_time = time.time()
@@ -74,6 +77,7 @@ def aggregated_results(self, results, cumulative_results):
7477
:type cumulative_results: bzt.modules.functional.ResultsTree
7578
:type results: bzt.modules.functional.ResultsTree
7679
"""
80+
self.log.info("DEV DEV: Final aggregated_results: %s", pprint.pformat(vars(cumulative_results)))
7781
self.cumulative_results = cumulative_results
7882

7983
def shutdown(self):
@@ -87,11 +91,11 @@ def post_process(self):
8791

8892
if self.parameters.get("test-duration", True):
8993
self.__report_duration()
90-
94+
self.log.info("DEV DEV: Reached in postprocess of FinalStatus")
9195
if self.last_sec:
9296
if '' in self.last_sec[DataPoint.CUMULATIVE]:
9397
summary_kpi = self.last_sec[DataPoint.CUMULATIVE][""]
94-
98+
self.log.info(f"DEV DEV: summary_kpi: {summary_kpi}")
9599
if self.parameters.get("summary", True):
96100
self.__report_samples_count(summary_kpi)
97101
if self.parameters.get("percentiles", True):
@@ -136,11 +140,15 @@ def __report_all_tests(self):
136140
self.log.info("Stacktrace:\n%s", case.error_trace)
137141

138142
def __report_failed_tests(self):
143+
self.log.info("DEV DEV: __report_failed_tests:")
139144
for test_suite in self.cumulative_results.test_suites():
140145
for case in self.cumulative_results.test_cases(test_suite):
146+
self.log.info("DEV DEV: case: %s", pprint.pformat(vars(case)))
141147
if case.status in ("FAILED", "BROKEN"):
142148
full_name = case.test_suite + "." + case.test_case
143149
msg = "Test {test_case} failed: {error_msg}".format(test_case=full_name, error_msg=case.error_msg)
150+
if hasattr(case, "action_id") and case.action_id:
151+
msg += f"\nAction ID: {case.action_id}"
144152
if case.error_trace:
145153
msg += "\n" + case.error_trace
146154
self.log.warning(msg)
@@ -182,6 +190,7 @@ def __report_failed_labels(self, cumulative):
182190
"""
183191
reports failed labels
184192
"""
193+
self.log.info(f"DEV DEV: cumulative: {cumulative}")
185194
report_template = "%d failed samples: %s"
186195
sorted_labels = sorted(cumulative.keys())
187196
for sample_label in sorted_labels:
@@ -196,6 +205,7 @@ def __get_sample_element(self, sample, label_name):
196205
total_samples_count = failed_samples_count + success_samples_count
197206
assert total_samples_count > 0, "Total samples is zero for %s" % label_name
198207
success_samples_perc = (success_samples_count * 100) / total_samples_count
208+
self.log.info(f"DEV DEV: sample: {sample}, label_name: {label_name}, failed_samples_count: {failed_samples_count}, success_samples_count: {success_samples_count}, total_samples_count: {total_samples_count}, success_samples_perc: {success_samples_perc}")
199209

200210
errors = set()
201211
for err_desc in sample['errors']:
@@ -403,6 +413,7 @@ def aggregated_results(self, _, cumulative_results):
403413
"""
404414
:type cumulative_results: bzt.modules.functional.ResultsTree
405415
"""
416+
self.log.info("DEV DEV: aggregated_results: %s", pprint.pformat(vars(cumulative_results)))
406417
self.cumulative_results = cumulative_results
407418

408419
def post_process(self):

0 commit comments

Comments
 (0)