framework_test.py 38 KB

123456789101112131415161718192021222324252627282930313233343536373839404142434445464748495051525354555657585960616263646566676869707172737475767778798081828384858687888990919293949596979899100101102103104105106107108109110111112113114115116117118119120121122123124125126127128129130131132133134135136137138139140141142143144145146147148149150151152153154155156157158159160161162163164165166167168169170171172173174175176177178179180181182183184185186187188189190191192193194195196197198199200201202203204205206207208209210211212213214215216217218219220221222223224225226227228229230231232233234235236237238239240241242243244245246247248249250251252253254255256257258259260261262263264265266267268269270271272273274275276277278279280281282283284285286287288289290291292293294295296297298299300301302303304305306307308309310311312313314315316317318319320321322323324325326327328329330331332333334335336337338339340341342343344345346347348349350351352353354355356357358359360361362363364365366367368369370371372373374375376377378379380381382383384385386387388389390391392393394395396397398399400401402403404405406407408409410411412413414415416417418419420421422423424425426427428429430431432433434435436437438439440441442443444445446447448449450451452453454455456457458459460461462463464465466467468469470471472473474475476477478479480481482483484485486487488489490491492493494495496497498499500501502503504505506507508509510511512513514515516517518519520521522523524525526527528529530531532533534535536537538539540541542543544545546547548549550551552553554555556557558559560561562563564565566567568569570571572573574575576577578579580581582583584585586587588589590591592593594595596597598599600601602603604605606607608609610611612613614615616617618619620621622623624625626627628629630631632633634635636637638639640641642643644645646647648649650651652653654655656657658659660661662663664665666667668669670671672673674675676677678679680681682683684685686687688689690691692693694695696697698699700701702703704705706707708709710711712713714715716717718719720721722723724725726727728729730731732733734735736737738739740741742743744745746747748749750751752753754755756757758759760761762763764765766767768769770771772773774775776777778779780781782783784785786787788789790791792793794795796797798799800801802803804805806807808809810811812813814815816817818819820821822823824825826827828829830831832833834835836837838839840841842843844845846847848849850851852853854855856857858859860861862863864865866867868869870871872873874875876877878879880881882883884885886887888889890891892893894895896897898899
  1. from benchmark.fortune_html_parser import FortuneHTMLParser
  2. from setup.linux import setup_util
  3. from benchmark.test_types import *
  4. import importlib
  5. import os
  6. import subprocess
  7. import time
  8. import re
  9. from pprint import pprint
  10. import sys
  11. import traceback
  12. import json
  13. import logging
  14. import csv
  15. import shlex
  16. import math
  17. from collections import OrderedDict
  18. from threading import Thread
  19. from threading import Event
  20. from utils import header
  21. from datetime import datetime
  22. from datetime import timedelta
  23. class FrameworkTest:
  24. headers_template = "-H 'Host: localhost' -H '{accept}' -H 'Connection: keep-alive'"
  25. # Used for test types that require no pipelining or query string params.
  26. concurrency_template = """
  27. echo ""
  28. echo "---------------------------------------------------------"
  29. echo " Running Primer {name}"
  30. echo " {wrk} {headers} --latency -d 5 -c 8 --timeout 8 -t 8 \"http://{server_host}:{port}{url}\""
  31. echo "---------------------------------------------------------"
  32. echo ""
  33. {wrk} {headers} --latency -d 5 -c 8 --timeout 8 -t 8 "http://{server_host}:{port}{url}"
  34. sleep 5
  35. echo ""
  36. echo "---------------------------------------------------------"
  37. echo " Running Warmup {name}"
  38. echo " {wrk} {headers} --latency -d {duration} -c {max_concurrency} --timeout {max_concurrency} -t {max_threads} \"http://{server_host}:{port}{url}\""
  39. echo "---------------------------------------------------------"
  40. echo ""
  41. {wrk} {headers} --latency -d {duration} -c {max_concurrency} --timeout {max_concurrency} -t {max_threads} "http://{server_host}:{port}{url}"
  42. sleep 5
  43. echo ""
  44. echo "---------------------------------------------------------"
  45. echo " Synchronizing time"
  46. echo "---------------------------------------------------------"
  47. echo ""
  48. ntpdate -s pool.ntp.org
  49. for c in {levels}
  50. do
  51. echo ""
  52. echo "---------------------------------------------------------"
  53. echo " Concurrency: $c for {name}"
  54. echo " {wrk} {headers} --latency -d {duration} -c $c --timeout $c -t $(($c>{max_threads}?{max_threads}:$c)) \"http://{server_host}:{port}{url}\""
  55. echo "---------------------------------------------------------"
  56. echo ""
  57. STARTTIME=$(date +"%s")
  58. {wrk} {headers} --latency -d {duration} -c $c --timeout $c -t "$(($c>{max_threads}?{max_threads}:$c))" http://{server_host}:{port}{url}
  59. echo "STARTTIME $STARTTIME"
  60. echo "ENDTIME $(date +"%s")"
  61. sleep 2
  62. done
  63. """
  64. # Used for test types that require pipelining.
  65. pipeline_template = """
  66. echo ""
  67. echo "---------------------------------------------------------"
  68. echo " Running Primer {name}"
  69. echo " {wrk} {headers} --latency -d 5 -c 8 --timeout 8 -t 8 \"http://{server_host}:{port}{url}\""
  70. echo "---------------------------------------------------------"
  71. echo ""
  72. {wrk} {headers} --latency -d 5 -c 8 --timeout 8 -t 8 "http://{server_host}:{port}{url}"
  73. sleep 5
  74. echo ""
  75. echo "---------------------------------------------------------"
  76. echo " Running Warmup {name}"
  77. echo " {wrk} {headers} --latency -d {duration} -c {max_concurrency} --timeout {max_concurrency} -t {max_threads} \"http://{server_host}:{port}{url}\""
  78. echo "---------------------------------------------------------"
  79. echo ""
  80. {wrk} {headers} --latency -d {duration} -c {max_concurrency} --timeout {max_concurrency} -t {max_threads} "http://{server_host}:{port}{url}"
  81. sleep 5
  82. echo ""
  83. echo "---------------------------------------------------------"
  84. echo " Synchronizing time"
  85. echo "---------------------------------------------------------"
  86. echo ""
  87. ntpdate -s pool.ntp.org
  88. for c in {levels}
  89. do
  90. echo ""
  91. echo "---------------------------------------------------------"
  92. echo " Concurrency: $c for {name}"
  93. echo " {wrk} {headers} --latency -d {duration} -c $c --timeout $c -t $(($c>{max_threads}?{max_threads}:$c)) \"http://{server_host}:{port}{url}\" -s ~/pipeline.lua -- {pipeline}"
  94. echo "---------------------------------------------------------"
  95. echo ""
  96. STARTTIME=$(date +"%s")
  97. {wrk} {headers} --latency -d {duration} -c $c --timeout $c -t "$(($c>{max_threads}?{max_threads}:$c))" http://{server_host}:{port}{url} -s ~/pipeline.lua -- {pipeline}
  98. echo "STARTTIME $STARTTIME"
  99. echo "ENDTIME $(date +"%s")"
  100. sleep 2
  101. done
  102. """
  103. # Used for test types that require a database -
  104. # These tests run at a static concurrency level and vary the size of
  105. # the query sent with each request
  106. query_template = """
  107. echo ""
  108. echo "---------------------------------------------------------"
  109. echo " Running Primer {name}"
  110. echo " wrk {headers} --latency -d 5 -c 8 --timeout 8 -t 8 \"http://{server_host}:{port}{url}2\""
  111. echo "---------------------------------------------------------"
  112. echo ""
  113. wrk {headers} --latency -d 5 -c 8 --timeout 8 -t 8 "http://{server_host}:{port}{url}2"
  114. sleep 5
  115. echo ""
  116. echo "---------------------------------------------------------"
  117. echo " Running Warmup {name}"
  118. echo " wrk {headers} --latency -d {duration} -c {max_concurrency} --timeout {max_concurrency} -t {max_threads} \"http://{server_host}:{port}{url}2\""
  119. echo "---------------------------------------------------------"
  120. echo ""
  121. wrk {headers} --latency -d {duration} -c {max_concurrency} --timeout {max_concurrency} -t {max_threads} "http://{server_host}:{port}{url}2"
  122. sleep 5
  123. echo ""
  124. echo "---------------------------------------------------------"
  125. echo " Synchronizing time"
  126. echo "---------------------------------------------------------"
  127. echo ""
  128. ntpdate -s pool.ntp.org
  129. for c in {levels}
  130. do
  131. echo ""
  132. echo "---------------------------------------------------------"
  133. echo " Queries: $c for {name}"
  134. echo " wrk {headers} --latency -d {duration} -c {max_concurrency} --timeout {max_concurrency} -t {max_threads} \"http://{server_host}:{port}{url}$c\""
  135. echo "---------------------------------------------------------"
  136. echo ""
  137. STARTTIME=$(date +"%s")
  138. wrk {headers} --latency -d {duration} -c {max_concurrency} --timeout {max_concurrency} -t {max_threads} "http://{server_host}:{port}{url}$c"
  139. echo "STARTTIME $STARTTIME"
  140. echo "ENDTIME $(date +"%s")"
  141. sleep 2
  142. done
  143. """
  144. ############################################################
  145. # start(benchmarker)
  146. # Start the test using it's setup file
  147. ############################################################
  148. def start(self, out, err):
  149. # Setup environment variables
  150. logDir = os.path.join(self.fwroot, self.benchmarker.latest_results_directory, 'logs', self.name.lower())
  151. bash_functions_path= os.path.join(self.fwroot 'toolset/setup/linux/bash_functions.sh')
  152. setup_util.replace_environ(config='$FWROOT/config/benchmark_profile',
  153. command='''\
  154. export TROOT=%s && \
  155. export IROOT=%s && \
  156. export DBHOST=%s && \
  157. export LOGDIR=%s && \
  158. export MAX_THREADS=%s \
  159. ''' % (
  160. self.directory,
  161. self.iroot,
  162. self.database_host,
  163. logDir,
  164. self.benchmarker.threads))
  165. # Run the module start inside parent of TROOT
  166. # - we use the parent as a historical accident, a number of tests
  167. # refer to their TROOT maually still
  168. previousDir = os.getcwd()
  169. os.chdir(os.path.dirname(self.troot))
  170. logging.info("Running setup module start (cwd=%s)", self.directory)
  171. # Run the start script for the test as the "testrunner" user
  172. #
  173. # `sudo` - Switching user requires superuser privs
  174. # -u [username] The username
  175. # -E Preserves the current environment variables
  176. # -H Forces the home var (~) to be reset to the user specified
  177. # `stdbuf` - Disable buffering, send output to python ASAP
  178. # -o0 zero-sized buffer for stdout
  179. # -e0 zero-sized buffer for stderr
  180. # `bash` - Run the setup.sh script using bash
  181. # -e Force bash to exit on first error
  182. # -x Turn on bash tracing e.g. print commands before running
  183. #
  184. # Most servers do not output to stdout/stderr while serving
  185. # requests so there is no performance hit from disabling
  186. # output buffering. This disabling is necessary to
  187. # a) allow TFB to show output in real time and b) avoid loosing
  188. # output in the buffer when the testrunner processes are forcibly
  189. # killed
  190. #
  191. # See http://www.pixelbeat.org/programming/stdio_buffering/
  192. # See https://blogs.gnome.org/markmc/2013/06/04/async-io-and-python/
  193. # See http://eyalarubas.com/python-subproc-nonblock.html
  194. command = 'cat %s %s.sh > /tmp/command.sh && sudo -u %s -E -H stdbuf -o0 -e0 bash -ex /tmp/command.sh' % (bash_functions_path, os.path.join(self.troot, self.setup_file), self.benchmarker.runner_user)
  195. debug_command = '''\
  196. export FWROOT=%s && \\
  197. export TROOT=%s && \\
  198. export IROOT=%s && \\
  199. export DBHOST=%s && \\
  200. export LOGDIR=%s && \\
  201. export MAX_THREADS=%s && \\
  202. cd %s && \\
  203. %s''' % (self.fwroot,
  204. self.directory,
  205. self.install_root,
  206. self.database_host,
  207. logDir,
  208. self.benchmarker.threads,
  209. self.directory,
  210. command)
  211. logging.info("To run %s manually, copy/paste this:\n%s", self.name, debug_command)
  212. def tee_output(prefix, line):
  213. # Needs to be one atomic write
  214. # Explicitly use UTF-8 as it's the most common framework output
  215. # TODO improve encoding handling
  216. line = prefix.encode('utf-8') + line
  217. # Log to current terminal
  218. sys.stdout.write(line)
  219. sys.stdout.flush()
  220. # logging.error("".join([prefix, line]))
  221. out.write(line)
  222. out.flush()
  223. # Start the setup.sh command
  224. p = subprocess.Popen(command, cwd=self.directory,
  225. shell=True, stdout=subprocess.PIPE,
  226. stderr=subprocess.STDOUT,
  227. executable='/bin/bash')
  228. nbsr = setup_util.NonBlockingStreamReader(p.stdout,
  229. "%s: %s.sh and framework processes have terminated" % (self.name, self.setup_file))
  230. # Set a limit on total execution time of setup.sh
  231. timeout = datetime.now() + timedelta(minutes = 20)
  232. time_remaining = timeout - datetime.now()
  233. # Need to print to stdout once every 10 minutes or Travis-CI will abort
  234. travis_timeout = datetime.now() + timedelta(minutes = 5)
  235. # Flush output until setup.sh work is finished. This is
  236. # either a) when setup.sh exits b) when the port is bound
  237. # c) when we run out of time. Note that 'finished' doesn't
  238. # guarantee setup.sh process is dead - the OS may choose to make
  239. # setup.sh a zombie process if it still has living children
  240. #
  241. # Note: child processes forked (using &) will remain alive
  242. # after setup.sh has exited. The will have inherited the
  243. # stdout/stderr descriptors and will be directing their
  244. # output to the pipes.
  245. #
  246. prefix = "Setup %s: " % self.name
  247. while not (p.poll()
  248. or self.benchmarker.is_port_bound(self.port)
  249. or time_remaining.total_seconds() < 0):
  250. # The conditions above are slow to check, so
  251. # we will delay output substantially if we only
  252. # print one line per condition check.
  253. # Adding a tight loop here mitigates the effect,
  254. # ensuring that most of the output directly from
  255. # setup.sh is sent to tee_output before the outer
  256. # loop exits and prints things like "setup.sh exited"
  257. #
  258. for i in xrange(10):
  259. try:
  260. line = nbsr.readline(0.05)
  261. if line:
  262. tee_output(prefix, line)
  263. # Reset Travis-CI timer
  264. travis_timeout = datetime.now() + timedelta(minutes = 5)
  265. except setup_util.EndOfStream:
  266. tee_output(prefix, "Setup has terminated\n")
  267. break
  268. time_remaining = timeout - datetime.now()
  269. if (travis_timeout - datetime.now()).total_seconds() < 0:
  270. sys.stdout.write(prefix + 'Printing so Travis-CI does not time out\n')
  271. sys.stdout.flush()
  272. travis_timeout = datetime.now() + timedelta(minutes = 5)
  273. # Did we time out?
  274. if time_remaining.total_seconds() < 0:
  275. tee_output(prefix, "%s.sh timed out!! Aborting...\n" % self.setup_file)
  276. p.kill()
  277. return 1
  278. # What's our return code?
  279. # If setup.sh has terminated, use that code
  280. # Otherwise, detect if the port was bound
  281. retcode = (p.poll() or 0 if self.benchmarker.is_port_bound(self.port) else 1)
  282. if p.poll():
  283. tee_output(prefix, "%s.sh process exited naturally with %s\n" % (self.setup_file, p.poll()))
  284. elif self.benchmarker.is_port_bound(self.port):
  285. tee_output(prefix, "Bound port detected on %s\n" % self.port)
  286. # Before we return control to the benchmarker, spin up a
  287. # thread to keep an eye on the pipes in case the running
  288. # framework uses stdout/stderr. Once all processes accessing
  289. # the subprocess.PIPEs are dead, this thread will terminate.
  290. # Use a different prefix to indicate this is the framework
  291. # speaking
  292. prefix = "Server %s: " % self.name
  293. def watch_child_pipes(nbsr, prefix):
  294. while True:
  295. try:
  296. line = nbsr.readline(60)
  297. if line:
  298. tee_output(prefix, line)
  299. except setup_util.EndOfStream:
  300. tee_output(prefix, "Framework processes have terminated\n")
  301. return
  302. watch_thread = Thread(target = watch_child_pipes,
  303. args = (nbsr, prefix))
  304. watch_thread.daemon = True
  305. watch_thread.start()
  306. logging.info("Executed %s.sh, returning %s", self.setup_file, retcode)
  307. os.chdir(previousDir)
  308. return retcode
  309. ############################################################
  310. # End start
  311. ############################################################
  312. ############################################################
  313. # verify_urls
  314. # Verifys each of the URLs for this test. THis will sinply
  315. # curl the URL and check for it's return status.
  316. # For each url, a flag will be set on this object for whether
  317. # or not it passed
  318. # Returns True if all verifications succeeded
  319. ############################################################
  320. def verify_urls(self, out, err):
  321. result = True
  322. def verify_type(test_type):
  323. test = self.runTests[test_type]
  324. test.setup_out_err(out, err)
  325. out.write(header("VERIFYING %s" % test_type.upper()))
  326. base_url = "http://%s:%s" % (self.benchmarker.server_host, self.port)
  327. try:
  328. results = test.verify(base_url)
  329. except Exception as e:
  330. results = [('fail',"""Caused Exception in TFB
  331. This almost certainly means your return value is incorrect,
  332. but also that you have found a bug. Please submit an issue
  333. including this message: %s\n%s""" % (e, traceback.format_exc()),
  334. base_url)]
  335. logging.warning("Verifying test %s for %s caused an exception: %s", test_type, self.name, e)
  336. traceback.format_exc()
  337. test.failed = any(result is 'fail' for (result, reason, url) in results)
  338. test.warned = any(result is 'warn' for (result, reason, url) in results)
  339. test.passed = all(result is 'pass' for (result, reason, url) in results)
  340. def output_result(result, reason, url):
  341. out.write(" %s for %s\n" % (result.upper(), url))
  342. print " %s for %s" % (result.upper(), url)
  343. if reason is not None and len(reason) != 0:
  344. for line in reason.splitlines():
  345. out.write(" " + line + '\n')
  346. print " " + line
  347. [output_result(r1,r2,url) for (r1, r2, url) in results]
  348. if test.failed:
  349. self.benchmarker.report_verify_results(self, test_type, 'fail')
  350. elif test.warned:
  351. self.benchmarker.report_verify_results(self, test_type, 'warn')
  352. elif test.passed:
  353. self.benchmarker.report_verify_results(self, test_type, 'pass')
  354. else:
  355. raise Exception("Unknown error - test did not pass,warn,or fail")
  356. result = True
  357. for test_type in self.runTests:
  358. verify_type(test_type)
  359. if self.runTests[test_type].failed:
  360. result = False
  361. return result
  362. ############################################################
  363. # End verify_urls
  364. ############################################################
  365. ############################################################
  366. # benchmark
  367. # Runs the benchmark for each type of test that it implements
  368. # JSON/DB/Query.
  369. ############################################################
  370. def benchmark(self, out, err):
  371. def benchmark_type(test_type):
  372. out.write("BENCHMARKING %s ... " % test_type.upper())
  373. test = self.runTests[test_type]
  374. test.setup_out_err(out, err)
  375. output_file = self.benchmarker.output_file(self.name, test_type)
  376. if not os.path.exists(output_file):
  377. # Open to create the empty file
  378. with open(output_file, 'w'):
  379. pass
  380. if not test.failed:
  381. if test_type == 'plaintext': # One special case
  382. remote_script = self.__generate_pipeline_script(test.get_url(), self.port, test.accept_header)
  383. elif test_type == 'query' or test_type == 'update':
  384. remote_script = self.__generate_query_script(test.get_url(), self.port, test.accept_header)
  385. else:
  386. remote_script = self.__generate_concurrency_script(test.get_url(), self.port, test.accept_header)
  387. # Begin resource usage metrics collection
  388. self.__begin_logging(test_type)
  389. # Run the benchmark
  390. with open(output_file, 'w') as raw_file:
  391. p = subprocess.Popen(self.benchmarker.client_ssh_string.split(" "), stdin=subprocess.PIPE, stdout=raw_file, stderr=err)
  392. p.communicate(remote_script)
  393. err.flush()
  394. # End resource usage metrics collection
  395. self.__end_logging()
  396. results = self.__parse_test(test_type)
  397. print "Benchmark results:"
  398. pprint(results)
  399. self.benchmarker.report_benchmark_results(framework=self, test=test_type, results=results['results'])
  400. out.write( "Complete\n" )
  401. out.flush()
  402. for test_type in self.runTests:
  403. benchmark_type(test_type)
  404. ############################################################
  405. # End benchmark
  406. ############################################################
  407. ############################################################
  408. # parse_all
  409. # Method meant to be run for a given timestamp
  410. ############################################################
  411. def parse_all(self):
  412. for test_type in self.runTests:
  413. if os.path.exists(self.benchmarker.get_output_file(self.name, test_type)):
  414. results = self.__parse_test(test_type)
  415. self.benchmarker.report_benchmark_results(framework=self, test=test_type, results=results['results'])
  416. ##########################################################################################
  417. # Private Methods
  418. ##########################################################################################
  419. ############################################################
  420. # __parse_test(test_type)
  421. ############################################################
  422. def __parse_test(self, test_type):
  423. try:
  424. results = dict()
  425. results['results'] = []
  426. stats = []
  427. if os.path.exists(self.benchmarker.get_output_file(self.name, test_type)):
  428. with open(self.benchmarker.output_file(self.name, test_type)) as raw_data:
  429. is_warmup = True
  430. rawData = None
  431. for line in raw_data:
  432. if "Queries:" in line or "Concurrency:" in line:
  433. is_warmup = False
  434. rawData = None
  435. continue
  436. if "Warmup" in line or "Primer" in line:
  437. is_warmup = True
  438. continue
  439. if not is_warmup:
  440. if rawData == None:
  441. rawData = dict()
  442. results['results'].append(rawData)
  443. #if "Requests/sec:" in line:
  444. # m = re.search("Requests/sec:\s+([0-9]+)", line)
  445. # rawData['reportedResults'] = m.group(1)
  446. # search for weighttp data such as succeeded and failed.
  447. if "Latency" in line:
  448. m = re.findall("([0-9]+\.*[0-9]*[us|ms|s|m|%]+)", line)
  449. if len(m) == 4:
  450. rawData['latencyAvg'] = m[0]
  451. rawData['latencyStdev'] = m[1]
  452. rawData['latencyMax'] = m[2]
  453. # rawData['latencyStdevPercent'] = m[3]
  454. #if "Req/Sec" in line:
  455. # m = re.findall("([0-9]+\.*[0-9]*[k|%]*)", line)
  456. # if len(m) == 4:
  457. # rawData['requestsAvg'] = m[0]
  458. # rawData['requestsStdev'] = m[1]
  459. # rawData['requestsMax'] = m[2]
  460. # rawData['requestsStdevPercent'] = m[3]
  461. #if "requests in" in line:
  462. # m = re.search("requests in ([0-9]+\.*[0-9]*[ms|s|m|h]+)", line)
  463. # if m != None:
  464. # # parse out the raw time, which may be in minutes or seconds
  465. # raw_time = m.group(1)
  466. # if "ms" in raw_time:
  467. # rawData['total_time'] = float(raw_time[:len(raw_time)-2]) / 1000.0
  468. # elif "s" in raw_time:
  469. # rawData['total_time'] = float(raw_time[:len(raw_time)-1])
  470. # elif "m" in raw_time:
  471. # rawData['total_time'] = float(raw_time[:len(raw_time)-1]) * 60.0
  472. # elif "h" in raw_time:
  473. # rawData['total_time'] = float(raw_time[:len(raw_time)-1]) * 3600.0
  474. if "requests in" in line:
  475. m = re.search("([0-9]+) requests in", line)
  476. if m != None:
  477. rawData['totalRequests'] = int(m.group(1))
  478. if "Socket errors" in line:
  479. if "connect" in line:
  480. m = re.search("connect ([0-9]+)", line)
  481. rawData['connect'] = int(m.group(1))
  482. if "read" in line:
  483. m = re.search("read ([0-9]+)", line)
  484. rawData['read'] = int(m.group(1))
  485. if "write" in line:
  486. m = re.search("write ([0-9]+)", line)
  487. rawData['write'] = int(m.group(1))
  488. if "timeout" in line:
  489. m = re.search("timeout ([0-9]+)", line)
  490. rawData['timeout'] = int(m.group(1))
  491. if "Non-2xx" in line:
  492. m = re.search("Non-2xx or 3xx responses: ([0-9]+)", line)
  493. if m != None:
  494. rawData['5xx'] = int(m.group(1))
  495. if "STARTTIME" in line:
  496. m = re.search("[0-9]+", line)
  497. rawData["startTime"] = int(m.group(0))
  498. if "ENDTIME" in line:
  499. m = re.search("[0-9]+", line)
  500. rawData["endTime"] = int(m.group(0))
  501. test_stats = self.__parse_stats(test_type, rawData["startTime"], rawData["endTime"], 1)
  502. # rawData["averageStats"] = self.__calculate_average_stats(test_stats)
  503. stats.append(test_stats)
  504. with open(self.benchmarker.stats_file(self.name, test_type) + ".json", "w") as stats_file:
  505. json.dump(stats, stats_file, indent=2)
  506. return results
  507. except IOError:
  508. return None
  509. ############################################################
  510. # End benchmark
  511. ############################################################
  512. ############################################################
  513. # __generate_concurrency_script(url, port)
  514. # Generates the string containing the bash script that will
  515. # be run on the client to benchmark a single test. This
  516. # specifically works for the variable concurrency tests (JSON
  517. # and DB)
  518. ############################################################
  519. def __generate_concurrency_script(self, url, port, accept_header, wrk_command="wrk"):
  520. headers = self.headers_template.format(accept=accept_header)
  521. return self.concurrency_template.format(max_concurrency=max(self.benchmarker.concurrency_levels),
  522. max_threads=self.benchmarker.threads, name=self.name, duration=self.benchmarker.duration,
  523. levels=" ".join("{}".format(item) for item in self.benchmarker.concurrency_levels),
  524. server_host=self.benchmarker.server_host, port=port, url=url, headers=headers, wrk=wrk_command)
  525. ############################################################
  526. # __generate_pipeline_script(url, port)
  527. # Generates the string containing the bash script that will
  528. # be run on the client to benchmark a single pipeline test.
  529. ############################################################
  530. def __generate_pipeline_script(self, url, port, accept_header, wrk_command="wrk"):
  531. headers = self.headers_template.format(accept=accept_header)
  532. return self.pipeline_template.format(max_concurrency=16384,
  533. max_threads=self.benchmarker.threads, name=self.name, duration=self.benchmarker.duration,
  534. levels=" ".join("{}".format(item) for item in [256,1024,4096,16384]),
  535. server_host=self.benchmarker.server_host, port=port, url=url, headers=headers, wrk=wrk_command,
  536. pipeline=16)
  537. ############################################################
  538. # __generate_query_script(url, port)
  539. # Generates the string containing the bash script that will
  540. # be run on the client to benchmark a single test. This
  541. # specifically works for the variable query tests (Query)
  542. ############################################################
  543. def __generate_query_script(self, url, port, accept_header):
  544. headers = self.headers_template.format(accept=accept_header)
  545. return self.query_template.format(max_concurrency=max(self.benchmarker.concurrency_levels),
  546. max_threads=self.benchmarker.threads, name=self.name, duration=self.benchmarker.duration,
  547. levels=" ".join("{}".format(item) for item in self.benchmarker.query_levels),
  548. server_host=self.benchmarker.server_host, port=port, url=url, headers=headers)
  549. ############################################################
  550. # Returns True if any test type this this framework test will use a DB
  551. ############################################################
  552. def requires_database(self):
  553. '''Returns True/False if this test requires a database'''
  554. return any(tobj.requires_db for (ttype,tobj) in self.runTests.iteritems())
  555. ############################################################
  556. # __begin_logging
  557. # Starts a thread to monitor the resource usage, to be synced with the client's time
  558. # TODO: MySQL and InnoDB are possible. Figure out how to implement them.
  559. ############################################################
  560. def __begin_logging(self, test_type):
  561. output_file = "{file_name}".format(file_name=self.benchmarker.get_stats_file(self.name, test_type))
  562. dstat_string = "dstat -afilmprsT --aio --fs --ipc --lock --raw --socket --tcp \
  563. --raw --socket --tcp --udp --unix --vm --disk-util \
  564. --rpc --rpcd --output {output_file}".format(output_file=output_file)
  565. cmd = shlex.split(dstat_string)
  566. dev_null = open(os.devnull, "w")
  567. self.subprocess_handle = subprocess.Popen(cmd, stdout=dev_null)
  568. ##############################################################
  569. # Begin __end_logging
  570. # Stops the logger thread and blocks until shutdown is complete.
  571. ##############################################################
  572. def __end_logging(self):
  573. self.subprocess_handle.terminate()
  574. self.subprocess_handle.communicate()
  575. ##############################################################
  576. # Begin __parse_stats
  577. # For each test type, process all the statistics, and return a multi-layered dictionary
  578. # that has a structure as follows:
  579. # (timestamp)
  580. # | (main header) - group that the stat is in
  581. # | | (sub header) - title of the stat
  582. # | | | (stat) - the stat itself, usually a floating point number
  583. ##############################################################
  584. def __parse_stats(self, test_type, start_time, end_time, interval):
  585. stats_dict = dict()
  586. stats_file = self.benchmarker.stats_file(self.name, test_type)
  587. with open(stats_file) as stats:
  588. while(stats.next() != "\n"): # dstat doesn't output a completely compliant CSV file - we need to strip the header
  589. pass
  590. stats_reader = csv.reader(stats)
  591. main_header = stats_reader.next()
  592. sub_header = stats_reader.next()
  593. time_row = sub_header.index("epoch")
  594. int_counter = 0
  595. for row in stats_reader:
  596. time = float(row[time_row])
  597. int_counter+=1
  598. if time < start_time:
  599. continue
  600. elif time > end_time:
  601. return stats_dict
  602. if int_counter % interval != 0:
  603. continue
  604. row_dict = dict()
  605. for nextheader in main_header:
  606. if nextheader != "":
  607. row_dict[nextheader] = dict()
  608. header = ""
  609. for item_num, column in enumerate(row):
  610. if(len(main_header[item_num]) != 0):
  611. header = main_header[item_num]
  612. row_dict[header][sub_header[item_num]] = float(column) # all the stats are numbers, so we want to make sure that they stay that way in json
  613. stats_dict[time] = row_dict
  614. return stats_dict
  615. ##############################################################
  616. # End __parse_stats
  617. ##############################################################
  618. def __getattr__(self, name):
  619. """For backwards compatibility, we used to pass benchmarker
  620. as the argument to the setup.sh files"""
  621. try:
  622. x = getattr(self.benchmarker, name)
  623. except AttributeError:
  624. print "AttributeError: %s not a member of FrameworkTest or Benchmarker" % name
  625. print "This is probably a bug"
  626. raise
  627. return x
  628. ##############################################################
  629. # Begin __calculate_average_stats
  630. # We have a large amount of raw data for the statistics that
  631. # may be useful for the stats nerds, but most people care about
  632. # a couple of numbers. For now, we're only going to supply:
  633. # * Average CPU
  634. # * Average Memory
  635. # * Total network use
  636. # * Total disk use
  637. # More may be added in the future. If they are, please update
  638. # the above list.
  639. # Note: raw_stats is directly from the __parse_stats method.
  640. # Recall that this consists of a dictionary of timestamps,
  641. # each of which contain a dictionary of stat categories which
  642. # contain a dictionary of stats
  643. ##############################################################
  644. def __calculate_average_stats(self, raw_stats):
  645. raw_stat_collection = dict()
  646. for timestamp, time_dict in raw_stats.items():
  647. for main_header, sub_headers in time_dict.items():
  648. item_to_append = None
  649. if 'cpu' in main_header:
  650. # We want to take the idl stat and subtract it from 100
  651. # to get the time that the CPU is NOT idle.
  652. item_to_append = sub_headers['idl'] - 100.0
  653. elif main_header == 'memory usage':
  654. item_to_append = sub_headers['used']
  655. elif 'net' in main_header:
  656. # Network stats have two parts - recieve and send. We'll use a tuple of
  657. # style (recieve, send)
  658. item_to_append = (sub_headers['recv'], sub_headers['send'])
  659. elif 'dsk' or 'io' in main_header:
  660. # Similar for network, except our tuple looks like (read, write)
  661. item_to_append = (sub_headers['read'], sub_headers['writ'])
  662. if item_to_append is not None:
  663. if main_header not in raw_stat_collection:
  664. raw_stat_collection[main_header] = list()
  665. raw_stat_collection[main_header].append(item_to_append)
  666. # Simple function to determine human readable size
  667. # http://stackoverflow.com/questions/1094841/reusable-library-to-get-human-readable-version-of-file-size
  668. def sizeof_fmt(num):
  669. # We'll assume that any number we get is convertable to a float, just in case
  670. num = float(num)
  671. for x in ['bytes','KB','MB','GB']:
  672. if num < 1024.0 and num > -1024.0:
  673. return "%3.1f%s" % (num, x)
  674. num /= 1024.0
  675. return "%3.1f%s" % (num, 'TB')
  676. # Now we have our raw stats in a readable format - we need to format it for display
  677. # We need a floating point sum, so the built in sum doesn't cut it
  678. display_stat_collection = dict()
  679. for header, values in raw_stat_collection.items():
  680. display_stat = None
  681. if 'cpu' in header:
  682. display_stat = sizeof_fmt(math.fsum(values) / len(values))
  683. elif main_header == 'memory usage':
  684. display_stat = sizeof_fmt(math.fsum(values) / len(values))
  685. elif 'net' in main_header:
  686. receive, send = zip(*values) # unzip
  687. display_stat = {'receive': sizeof_fmt(math.fsum(receive)), 'send': sizeof_fmt(math.fsum(send))}
  688. else: # if 'dsk' or 'io' in header:
  689. read, write = zip(*values) # unzip
  690. display_stat = {'read': sizeof_fmt(math.fsum(read)), 'write': sizeof_fmt(math.fsum(write))}
  691. display_stat_collection[header] = display_stat
  692. return display_stat
  693. ###########################################################################################
  694. # End __calculate_average_stats
  695. #########################################################################################
  696. ##########################################################################################
  697. # Constructor
  698. ##########################################################################################
  699. def __init__(self, name, directory, benchmarker, runTests, args):
  700. self.name = name
  701. self.directory = directory
  702. self.benchmarker = benchmarker
  703. self.runTests = runTests
  704. self.fwroot = benchmarker.fwroot
  705. self.approach = ""
  706. self.classification = ""
  707. self.database = ""
  708. self.framework = ""
  709. self.language = ""
  710. self.orm = ""
  711. self.platform = ""
  712. self.webserver = ""
  713. self.os = ""
  714. self.database_os = ""
  715. self.display_name = ""
  716. self.notes = ""
  717. self.versus = ""
  718. # setup logging
  719. logging.basicConfig(stream=sys.stderr, level=logging.INFO)
  720. self.install_root="%s/%s" % (self.fwroot, "installs")
  721. if benchmarker.install_strategy is 'pertest':
  722. self.install_root="%s/pertest/%s" % (self.install_root, name)
  723. # Used in setup.sh scripts for consistency with
  724. # the bash environment variables
  725. self.troot = self.directory
  726. self.iroot = self.install_root
  727. self.__dict__.update(args)
  728. ############################################################
  729. # End __init__
  730. ############################################################
  731. ############################################################
  732. # End FrameworkTest
  733. ############################################################
  734. ##########################################################################################
  735. # Static methods
  736. ##########################################################################################
  737. ##############################################################
  738. # parse_config(config, directory, benchmarker)
  739. # parses a config file and returns a list of FrameworkTest
  740. # objects based on that config file.
  741. ##############################################################
  742. def parse_config(config, directory, benchmarker):
  743. tests = []
  744. # This sort ordering is set up specifically to return the length
  745. # of the test name. There were SO many problems involved with
  746. # 'plaintext' being run first (rather, just not last) that we
  747. # needed to ensure that it was run last for every framework.
  748. def testOrder(type_name):
  749. return len(type_name)
  750. # The config object can specify multiple tests
  751. # Loop over them and parse each into a FrameworkTest
  752. for test in config['tests']:
  753. names = [name for (name,keys) in test.iteritems()]
  754. if "default" not in names:
  755. logging.warn("Framework %s does not define a default test in benchmark_config.json", config['framework'])
  756. for test_name, test_keys in test.iteritems():
  757. # Prefix all test names with framework except 'default' test
  758. if test_name == 'default':
  759. test_name = config['framework']
  760. else:
  761. test_name = "%s-%s" % (config['framework'], test_name)
  762. # Ensure FrameworkTest.framework is available
  763. if not test_keys['framework']:
  764. test_keys['framework'] = config['framework']
  765. #if test_keys['framework'].lower() != config['framework'].lower():
  766. # print Exception("benchmark_config.json for test %s is invalid - test framework '%s' must match benchmark_config.json framework '%s'" %
  767. # (test_name, test_keys['framework'], config['framework']))
  768. # Confirm required keys are present
  769. # TODO have a TechEmpower person confirm this list - I don't know what the website requires....
  770. required = ['language','webserver','classification','database','approach','orm','framework','os','database_os']
  771. if not all (key in test_keys for key in required):
  772. raise Exception("benchmark_config.json for test %s is invalid - missing required keys" % test_name)
  773. # Map test type to a parsed FrameworkTestType object
  774. runTests = dict()
  775. for type_name, type_obj in benchmarker.types.iteritems():
  776. try:
  777. runTests[type_name] = type_obj.copy().parse(test_keys)
  778. except AttributeError as ae:
  779. # This is quite common - most tests don't support all types
  780. # Quitely log it and move on (debug logging is on in travis and this causes
  781. # ~1500 lines of debug, so I'm totally ignoring it for now
  782. # logging.debug("Missing arguments for test type %s for framework test %s", type_name, test_name)
  783. pass
  784. # We need to sort by test_type to run
  785. sortedTestKeys = sorted(runTests.keys(), key=testOrder)
  786. sortedRunTests = OrderedDict()
  787. for sortedTestKey in sortedTestKeys:
  788. sortedRunTests[sortedTestKey] = runTests[sortedTestKey]
  789. # By passing the entire set of keys, each FrameworkTest will have a member for each key
  790. tests.append(FrameworkTest(test_name, directory, benchmarker, sortedRunTests, test_keys))
  791. return tests
  792. ##############################################################
  793. # End parse_config
  794. ##############################################################