results.py 23 KB

123456789101112131415161718192021222324252627282930313233343536373839404142434445464748495051525354555657585960616263646566676869707172737475767778798081828384858687888990919293949596979899100101102103104105106107108109110111112113114115116117118119120121122123124125126127128129130131132133134135136137138139140141142143144145146147148149150151152153154155156157158159160161162163164165166167168169170171172173174175176177178179180181182183184185186187188189190191192193194195196197198199200201202203204205206207208209210211212213214215216217218219220221222223224225226227228229230231232233234235236237238239240241242243244245246247248249250251252253254255256257258259260261262263264265266267268269270271272273274275276277278279280281282283284285286287288289290291292293294295296297298299300301302303304305306307308309310311312313314315316317318319320321322323324325326327328329330331332333334335336337338339340341342343344345346347348349350351352353354355356357358359360361362363364365366367368369370371372373374375376377378379380381382383384385386387388389390391392393394395396397398399400401402403404405406407408409410411412413414415416417418419420421422423424425426427428429430431432433434435436437438439440441442443444445446447448449450451452453454455456457458459460461462463464465466467468469470471472473474475476477478479480481482483484485486487488489490491492493494495496497498499500501502503504505506507508509510511512513514515516517518519520521522523524525526527528529530531532533534535536537538539540541542543544545546547548549550551552553554555556557558559560561562563564565566
  1. from toolset.utils.output_helper import log
  2. import os
  3. import subprocess
  4. import uuid
  5. import time
  6. import json
  7. import requests
  8. import threading
  9. import re
  10. import math
  11. import csv
  12. import traceback
  13. from datetime import datetime
  14. # Cross-platform colored text
  15. from colorama import Fore, Style
  16. class Results:
  17. def __init__(self, benchmarker):
  18. '''
  19. Constructor
  20. '''
  21. self.benchmarker = benchmarker
  22. self.config = benchmarker.config
  23. self.directory = os.path.join(self.config.results_root,
  24. self.config.timestamp)
  25. try:
  26. os.makedirs(self.directory)
  27. except OSError:
  28. pass
  29. self.file = os.path.join(self.directory, "results.json")
  30. self.uuid = str(uuid.uuid4())
  31. self.name = datetime.now().strftime(self.config.results_name)
  32. self.environmentDescription = self.config.results_environment
  33. try:
  34. self.git = dict()
  35. self.git['commitId'] = self.__get_git_commit_id()
  36. self.git['repositoryUrl'] = self.__get_git_repository_url()
  37. self.git['branchName'] = self.__get_git_branch_name()
  38. except Exception:
  39. #Could not read local git repository, which is fine.
  40. self.git = None
  41. self.startTime = int(round(time.time() * 1000))
  42. self.completionTime = None
  43. self.concurrencyLevels = self.config.concurrency_levels
  44. self.pipelineConcurrencyLevels = self.config.pipeline_concurrency_levels
  45. self.queryIntervals = self.config.query_levels
  46. self.cachedQueryIntervals = self.config.cached_query_levels
  47. self.frameworks = [t.name for t in benchmarker.tests]
  48. self.duration = self.config.duration
  49. self.rawData = dict()
  50. self.rawData['json'] = dict()
  51. self.rawData['db'] = dict()
  52. self.rawData['query'] = dict()
  53. self.rawData['fortune'] = dict()
  54. self.rawData['update'] = dict()
  55. self.rawData['plaintext'] = dict()
  56. self.rawData['cached_query'] = dict()
  57. self.completed = dict()
  58. self.succeeded = dict()
  59. self.succeeded['json'] = []
  60. self.succeeded['db'] = []
  61. self.succeeded['query'] = []
  62. self.succeeded['fortune'] = []
  63. self.succeeded['update'] = []
  64. self.succeeded['plaintext'] = []
  65. self.succeeded['cached_query'] = []
  66. self.failed = dict()
  67. self.failed['json'] = []
  68. self.failed['db'] = []
  69. self.failed['query'] = []
  70. self.failed['fortune'] = []
  71. self.failed['update'] = []
  72. self.failed['plaintext'] = []
  73. self.failed['cached_query'] = []
  74. self.verify = dict()
  75. #############################################################################
  76. # PUBLIC FUNCTIONS
  77. #############################################################################
  78. def parse(self, tests):
  79. '''
  80. Ensures that the system has all necessary software to run
  81. the tests. This does not include that software for the individual
  82. test, but covers software such as curl and weighttp that
  83. are needed.
  84. '''
  85. # Run the method to get the commmit count of each framework.
  86. self.__count_commits()
  87. # Call the method which counts the sloc for each framework
  88. self.__count_sloc()
  89. # Time to create parsed files
  90. # Aggregate JSON file
  91. with open(self.file, "w") as f:
  92. f.write(json.dumps(self.__to_jsonable(), indent=2))
  93. def parse_test(self, framework_test, test_type):
  94. '''
  95. Parses the given test and test_type from the raw_file.
  96. '''
  97. results = dict()
  98. results['results'] = []
  99. stats = []
  100. if os.path.exists(self.get_raw_file(framework_test.name, test_type)):
  101. with open(self.get_raw_file(framework_test.name,
  102. test_type)) as raw_data:
  103. is_warmup = True
  104. rawData = None
  105. for line in raw_data:
  106. if "Queries:" in line or "Concurrency:" in line:
  107. is_warmup = False
  108. rawData = None
  109. continue
  110. if "Warmup" in line or "Primer" in line:
  111. is_warmup = True
  112. continue
  113. if not is_warmup:
  114. if rawData is None:
  115. rawData = dict()
  116. results['results'].append(rawData)
  117. if "Latency" in line:
  118. m = re.findall(r"([0-9]+\.*[0-9]*[us|ms|s|m|%]+)",
  119. line)
  120. if len(m) == 4:
  121. rawData['latencyAvg'] = m[0]
  122. rawData['latencyStdev'] = m[1]
  123. rawData['latencyMax'] = m[2]
  124. if "requests in" in line:
  125. m = re.search("([0-9]+) requests in", line)
  126. if m is not None:
  127. rawData['totalRequests'] = int(m.group(1))
  128. if "Socket errors" in line:
  129. if "connect" in line:
  130. m = re.search("connect ([0-9]+)", line)
  131. rawData['connect'] = int(m.group(1))
  132. if "read" in line:
  133. m = re.search("read ([0-9]+)", line)
  134. rawData['read'] = int(m.group(1))
  135. if "write" in line:
  136. m = re.search("write ([0-9]+)", line)
  137. rawData['write'] = int(m.group(1))
  138. if "timeout" in line:
  139. m = re.search("timeout ([0-9]+)", line)
  140. rawData['timeout'] = int(m.group(1))
  141. if "Non-2xx" in line:
  142. m = re.search("Non-2xx or 3xx responses: ([0-9]+)",
  143. line)
  144. if m != None:
  145. rawData['5xx'] = int(m.group(1))
  146. if "STARTTIME" in line:
  147. m = re.search("[0-9]+", line)
  148. rawData["startTime"] = int(m.group(0))
  149. if "ENDTIME" in line:
  150. m = re.search("[0-9]+", line)
  151. rawData["endTime"] = int(m.group(0))
  152. test_stats = self.__parse_stats(
  153. framework_test, test_type,
  154. rawData["startTime"], rawData["endTime"], 1)
  155. stats.append(test_stats)
  156. with open(
  157. self.get_stats_file(framework_test.name, test_type) + ".json",
  158. "w") as stats_file:
  159. json.dump(stats, stats_file, indent=2)
  160. return results
  161. def parse_all(self, framework_test):
  162. '''
  163. Method meant to be run for a given timestamp
  164. '''
  165. for test_type in framework_test.runTests:
  166. if os.path.exists(
  167. self.get_raw_file(framework_test.name, test_type)):
  168. results = self.parse_test(framework_test, test_type)
  169. self.report_benchmark_results(framework_test, test_type,
  170. results['results'])
  171. def write_intermediate(self, test_name, status_message):
  172. '''
  173. Writes the intermediate results for the given test_name and status_message
  174. '''
  175. self.completed[test_name] = status_message
  176. self.__write_results()
  177. def set_completion_time(self):
  178. '''
  179. Sets the completionTime for these results and writes the results
  180. '''
  181. self.completionTime = int(round(time.time() * 1000))
  182. self.__write_results()
  183. def upload(self):
  184. '''
  185. Attempts to upload the results.json to the configured results_upload_uri
  186. '''
  187. if self.config.results_upload_uri is not None:
  188. try:
  189. requests.post(
  190. self.config.results_upload_uri,
  191. headers={'Content-Type': 'application/json'},
  192. data=json.dumps(self.__to_jsonable(), indent=2),
  193. timeout=300)
  194. except Exception:
  195. log("Error uploading results.json")
  196. def load(self):
  197. '''
  198. Load the results.json file
  199. '''
  200. try:
  201. with open(self.file) as f:
  202. self.__dict__.update(json.load(f))
  203. except (ValueError, IOError):
  204. pass
  205. def get_raw_file(self, test_name, test_type):
  206. '''
  207. Returns the output file for this test_name and test_type
  208. Example: fw_root/results/timestamp/test_type/test_name/raw.txt
  209. '''
  210. path = os.path.join(self.directory, test_name, test_type, "raw.txt")
  211. try:
  212. os.makedirs(os.path.dirname(path))
  213. except OSError:
  214. pass
  215. return path
  216. def get_stats_file(self, test_name, test_type):
  217. '''
  218. Returns the stats file name for this test_name and
  219. Example: fw_root/results/timestamp/test_type/test_name/stats.txt
  220. '''
  221. path = os.path.join(self.directory, test_name, test_type, "stats.txt")
  222. try:
  223. os.makedirs(os.path.dirname(path))
  224. except OSError:
  225. pass
  226. return path
  227. def report_verify_results(self, framework_test, test_type, result):
  228. '''
  229. Used by FrameworkTest to add verification details to our results
  230. TODO: Technically this is an IPC violation - we are accessing
  231. the parent process' memory from the child process
  232. '''
  233. if framework_test.name not in self.verify.keys():
  234. self.verify[framework_test.name] = dict()
  235. self.verify[framework_test.name][test_type] = result
  236. def report_benchmark_results(self, framework_test, test_type, results):
  237. '''
  238. Used by FrameworkTest to add benchmark data to this
  239. TODO: Technically this is an IPC violation - we are accessing
  240. the parent process' memory from the child process
  241. '''
  242. if test_type not in self.rawData.keys():
  243. self.rawData[test_type] = dict()
  244. # If results has a size from the parse, then it succeeded.
  245. if results:
  246. self.rawData[test_type][framework_test.name] = results
  247. # This may already be set for single-tests
  248. if framework_test.name not in self.succeeded[test_type]:
  249. self.succeeded[test_type].append(framework_test.name)
  250. else:
  251. # This may already be set for single-tests
  252. if framework_test.name not in self.failed[test_type]:
  253. self.failed[test_type].append(framework_test.name)
  254. def finish(self):
  255. '''
  256. Finishes these results.
  257. '''
  258. if not self.config.parse:
  259. # Normally you don't have to use Fore.BLUE before each line, but
  260. # Travis-CI seems to reset color codes on newline (see travis-ci/travis-ci#2692)
  261. # or stream flush, so we have to ensure that the color code is printed repeatedly
  262. log("Verification Summary",
  263. border='=',
  264. border_bottom='-',
  265. color=Fore.CYAN)
  266. for test in self.benchmarker.tests:
  267. log(Fore.CYAN + "| {!s}".format(test.name))
  268. if test.name in self.verify.keys():
  269. for test_type, result in self.verify[
  270. test.name].iteritems():
  271. if result.upper() == "PASS":
  272. color = Fore.GREEN
  273. elif result.upper() == "WARN":
  274. color = Fore.YELLOW
  275. else:
  276. color = Fore.RED
  277. log(Fore.CYAN + "| " + test_type.ljust(13) +
  278. ' : ' + color + result.upper())
  279. else:
  280. log(Fore.CYAN + "| " + Fore.RED +
  281. "NO RESULTS (Did framework launch?)")
  282. log('', border='=', border_bottom='', color=Fore.CYAN)
  283. log("Results are saved in " + self.directory)
  284. #############################################################################
  285. # PRIVATE FUNCTIONS
  286. #############################################################################
  287. def __to_jsonable(self):
  288. '''
  289. Returns a dict suitable for jsonification
  290. '''
  291. toRet = dict()
  292. toRet['uuid'] = self.uuid
  293. toRet['name'] = self.name
  294. toRet['environmentDescription'] = self.environmentDescription
  295. toRet['git'] = self.git
  296. toRet['startTime'] = self.startTime
  297. toRet['completionTime'] = self.completionTime
  298. toRet['concurrencyLevels'] = self.concurrencyLevels
  299. toRet['pipelineConcurrencyLevels'] = self.pipelineConcurrencyLevels
  300. toRet['queryIntervals'] = self.queryIntervals
  301. toRet['cachedQueryIntervals'] = self.cachedQueryIntervals
  302. toRet['frameworks'] = self.frameworks
  303. toRet['duration'] = self.duration
  304. toRet['rawData'] = self.rawData
  305. toRet['completed'] = self.completed
  306. toRet['succeeded'] = self.succeeded
  307. toRet['failed'] = self.failed
  308. toRet['verify'] = self.verify
  309. toRet['testMetadata'] = self.benchmarker.metadata.to_jsonable()
  310. return toRet
  311. def __write_results(self):
  312. try:
  313. with open(self.file, 'w') as f:
  314. f.write(json.dumps(self.__to_jsonable(), indent=2))
  315. except IOError:
  316. log("Error writing results.json")
  317. def __count_sloc(self):
  318. '''
  319. Counts the significant lines of code for all tests and stores in results.
  320. '''
  321. frameworks = self.benchmarker.metadata.gather_frameworks(
  322. self.config.test, self.config.exclude)
  323. framework_to_count = {}
  324. for framework, testlist in frameworks.items():
  325. wd = testlist[0].directory
  326. # Find the last instance of the word 'code' in the yaml output. This
  327. # should be the line count for the sum of all listed files or just
  328. # the line count for the last file in the case where there's only
  329. # one file listed.
  330. command = "cloc --yaml --follow-links . | grep code | tail -1 | cut -d: -f 2"
  331. log("Running \"%s\" (cwd=%s)" % (command, wd))
  332. try:
  333. line_count = int(subprocess.check_output(command, cwd=wd, shell=True))
  334. except (subprocess.CalledProcessError, ValueError) as e:
  335. log("Unable to count lines of code for %s due to error '%s'" %
  336. (framework, e))
  337. continue
  338. log("Counted %s lines of code" % line_count)
  339. framework_to_count[framework] = line_count
  340. self.rawData['slocCounts'] = framework_to_count
  341. def __count_commits(self):
  342. '''
  343. Count the git commits for all the framework tests
  344. '''
  345. frameworks = self.benchmarker.metadata.gather_frameworks(
  346. self.config.test, self.config.exclude)
  347. def count_commit(directory, jsonResult):
  348. command = "git rev-list HEAD -- " + directory + " | sort -u | wc -l"
  349. try:
  350. commitCount = subprocess.check_output(command, shell=True)
  351. jsonResult[framework] = int(commitCount)
  352. except subprocess.CalledProcessError:
  353. pass
  354. # Because git can be slow when run in large batches, this
  355. # calls git up to 4 times in parallel. Normal improvement is ~3-4x
  356. # in my trials, or ~100 seconds down to ~25
  357. # This is safe to parallelize as long as each thread only
  358. # accesses one key in the dictionary
  359. threads = []
  360. jsonResult = {}
  361. # t1 = datetime.now()
  362. for framework, testlist in frameworks.items():
  363. directory = testlist[0].directory
  364. t = threading.Thread(
  365. target=count_commit, args=(directory, jsonResult))
  366. t.start()
  367. threads.append(t)
  368. # Git has internal locks, full parallel will just cause contention
  369. # and slowness, so we rate-limit a bit
  370. if len(threads) >= 4:
  371. threads[0].join()
  372. threads.remove(threads[0])
  373. # Wait for remaining threads
  374. for t in threads:
  375. t.join()
  376. # t2 = datetime.now()
  377. # print "Took %s seconds " % (t2 - t1).seconds
  378. self.rawData['commitCounts'] = jsonResult
  379. self.config.commits = jsonResult
  380. def __get_git_commit_id(self):
  381. '''
  382. Get the git commit id for this benchmark
  383. '''
  384. return subprocess.check_output(
  385. ["git", "rev-parse", "HEAD"], cwd=self.config.fw_root).strip()
  386. def __get_git_repository_url(self):
  387. '''
  388. Gets the git repository url for this benchmark
  389. '''
  390. return subprocess.check_output(
  391. ["git", "config", "--get", "remote.origin.url"],
  392. cwd=self.config.fw_root).strip()
  393. def __get_git_branch_name(self):
  394. '''
  395. Gets the git branch name for this benchmark
  396. '''
  397. return subprocess.check_output(
  398. 'git rev-parse --abbrev-ref HEAD',
  399. shell=True,
  400. cwd=self.config.fw_root).strip()
  401. def __parse_stats(self, framework_test, test_type, start_time, end_time,
  402. interval):
  403. '''
  404. For each test type, process all the statistics, and return a multi-layered
  405. dictionary that has a structure as follows:
  406. (timestamp)
  407. | (main header) - group that the stat is in
  408. | | (sub header) - title of the stat
  409. | | | (stat) - the stat itself, usually a floating point number
  410. '''
  411. stats_dict = dict()
  412. stats_file = self.get_stats_file(framework_test.name, test_type)
  413. with open(stats_file) as stats:
  414. # dstat doesn't output a completely compliant CSV file - we need to strip the header
  415. for _ in range(4):
  416. stats.next()
  417. stats_reader = csv.reader(stats)
  418. main_header = stats_reader.next()
  419. sub_header = stats_reader.next()
  420. time_row = sub_header.index("epoch")
  421. int_counter = 0
  422. for row in stats_reader:
  423. time = float(row[time_row])
  424. int_counter += 1
  425. if time < start_time:
  426. continue
  427. elif time > end_time:
  428. return stats_dict
  429. if int_counter % interval != 0:
  430. continue
  431. row_dict = dict()
  432. for nextheader in main_header:
  433. if nextheader != "":
  434. row_dict[nextheader] = dict()
  435. header = ""
  436. for item_num, column in enumerate(row):
  437. if len(main_header[item_num]) != 0:
  438. header = main_header[item_num]
  439. # all the stats are numbers, so we want to make sure that they stay that way in json
  440. row_dict[header][sub_header[item_num]] = float(column)
  441. stats_dict[time] = row_dict
  442. return stats_dict
  443. def __calculate_average_stats(self, raw_stats):
  444. '''
  445. We have a large amount of raw data for the statistics that may be useful
  446. for the stats nerds, but most people care about a couple of numbers. For
  447. now, we're only going to supply:
  448. * Average CPU
  449. * Average Memory
  450. * Total network use
  451. * Total disk use
  452. More may be added in the future. If they are, please update the above list.
  453. Note: raw_stats is directly from the __parse_stats method.
  454. Recall that this consists of a dictionary of timestamps, each of which
  455. contain a dictionary of stat categories which contain a dictionary of stats
  456. '''
  457. raw_stat_collection = dict()
  458. for time_dict in raw_stats.items()[1]:
  459. for main_header, sub_headers in time_dict.items():
  460. item_to_append = None
  461. if 'cpu' in main_header:
  462. # We want to take the idl stat and subtract it from 100
  463. # to get the time that the CPU is NOT idle.
  464. item_to_append = sub_headers['idl'] - 100.0
  465. elif main_header == 'memory usage':
  466. item_to_append = sub_headers['used']
  467. elif 'net' in main_header:
  468. # Network stats have two parts - recieve and send. We'll use a tuple of
  469. # style (recieve, send)
  470. item_to_append = (sub_headers['recv'], sub_headers['send'])
  471. elif 'dsk' or 'io' in main_header:
  472. # Similar for network, except our tuple looks like (read, write)
  473. item_to_append = (sub_headers['read'], sub_headers['writ'])
  474. if item_to_append is not None:
  475. if main_header not in raw_stat_collection:
  476. raw_stat_collection[main_header] = list()
  477. raw_stat_collection[main_header].append(item_to_append)
  478. # Simple function to determine human readable size
  479. # http://stackoverflow.com/questions/1094841/reusable-library-to-get-human-readable-version-of-file-size
  480. def sizeof_fmt(num):
  481. # We'll assume that any number we get is convertable to a float, just in case
  482. num = float(num)
  483. for x in ['bytes', 'KB', 'MB', 'GB']:
  484. if 1024.0 > num > -1024.0:
  485. return "%3.1f%s" % (num, x)
  486. num /= 1024.0
  487. return "%3.1f%s" % (num, 'TB')
  488. # Now we have our raw stats in a readable format - we need to format it for display
  489. # We need a floating point sum, so the built in sum doesn't cut it
  490. display_stat_collection = dict()
  491. for header, values in raw_stat_collection.items():
  492. display_stat = None
  493. if 'cpu' in header:
  494. display_stat = sizeof_fmt(math.fsum(values) / len(values))
  495. elif main_header == 'memory usage':
  496. display_stat = sizeof_fmt(math.fsum(values) / len(values))
  497. elif 'net' in main_header:
  498. receive, send = zip(*values) # unzip
  499. display_stat = {
  500. 'receive': sizeof_fmt(math.fsum(receive)),
  501. 'send': sizeof_fmt(math.fsum(send))
  502. }
  503. else: # if 'dsk' or 'io' in header:
  504. read, write = zip(*values) # unzip
  505. display_stat = {
  506. 'read': sizeof_fmt(math.fsum(read)),
  507. 'write': sizeof_fmt(math.fsum(write))
  508. }
  509. display_stat_collection[header] = display_stat
  510. return display_stat