results.py 24 KB

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