framework_test.py 45 KB

1234567891011121314151617181920212223242526272829303132333435363738394041424344454647484950515253545556575859606162636465666768697071727374757677787980818283848586878889909192939495969798991001011021031041051061071081091101111121131141151161171181191201211221231241251261271281291301311321331341351361371381391401411421431441451461471481491501511521531541551561571581591601611621631641651661671681691701711721731741751761771781791801811821831841851861871881891901911921931941951961971981992002012022032042052062072082092102112122132142152162172182192202212222232242252262272282292302312322332342352362372382392402412422432442452462472482492502512522532542552562572582592602612622632642652662672682692702712722732742752762772782792802812822832842852862872882892902912922932942952962972982993003013023033043053063073083093103113123133143153163173183193203213223233243253263273283293303313323333343353363373383393403413423433443453463473483493503513523533543553563573583593603613623633643653663673683693703713723733743753763773783793803813823833843853863873883893903913923933943953963973983994004014024034044054064074084094104114124134144154164174184194204214224234244254264274284294304314324334344354364374384394404414424434444454464474484494504514524534544554564574584594604614624634644654664674684694704714724734744754764774784794804814824834844854864874884894904914924934944954964974984995005015025035045055065075085095105115125135145155165175185195205215225235245255265275285295305315325335345355365375385395405415425435445455465475485495505515525535545555565575585595605615625635645655665675685695705715725735745755765775785795805815825835845855865875885895905915925935945955965975985996006016026036046056066076086096106116126136146156166176186196206216226236246256266276286296306316326336346356366376386396406416426436446456466476486496506516526536546556566576586596606616626636646656666676686696706716726736746756766776786796806816826836846856866876886896906916926936946956966976986997007017027037047057067077087097107117127137147157167177187197207217227237247257267277287297307317327337347357367377387397407417427437447457467477487497507517527537547557567577587597607617627637647657667677687697707717727737747757767777787797807817827837847857867877887897907917927937947957967977987998008018028038048058068078088098108118128138148158168178188198208218228238248258268278288298308318328338348358368378388398408418428438448458468478488498508518528538548558568578588598608618628638648658668678688698708718728738748758768778788798808818828838848858868878888898908918928938948958968978988999009019029039049059069079089099109119129139149159169179189199209219229239249259269279289299309319329339349359369379389399409419429439449459469479489499509519529539549559569579589599609619629639649659669679689699709719729739749759769779789799809819829839849859869879889899909919929939949959969979989991000100110021003100410051006100710081009101010111012101310141015101610171018101910201021102210231024102510261027102810291030103110321033103410351036103710381039104010411042104310441045104610471048104910501051105210531054105510561057105810591060106110621063106410651066106710681069
  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 socket
  8. import time
  9. import re
  10. from pprint import pprint
  11. import sys
  12. import traceback
  13. import json
  14. import logging
  15. import csv
  16. import shlex
  17. import math
  18. import multiprocessing
  19. from collections import OrderedDict
  20. from requests import ConnectionError
  21. from threading import Thread
  22. from threading import Event
  23. from utils import header
  24. from utils import gather_docker_dependencies
  25. from utils import find_docker_file
  26. # Cross-platform colored text
  27. from colorama import Fore, Back, Style
  28. from datetime import datetime
  29. from datetime import timedelta
  30. class FrameworkTest:
  31. headers_template = "-H 'Host: {server_host}' -H 'Accept: {accept}' -H 'Connection: keep-alive'"
  32. # Used for test types that require no pipelining or query string params.
  33. concurrency_template = """
  34. let max_threads=$(cat /proc/cpuinfo | grep processor | wc -l)
  35. echo ""
  36. echo "---------------------------------------------------------"
  37. echo " Running Primer {name}"
  38. echo " {wrk} {headers} --latency -d 5 -c 8 --timeout 8 -t 8 \"http://{server_host}:{port}{url}\""
  39. echo "---------------------------------------------------------"
  40. echo ""
  41. {wrk} {headers} --latency -d 5 -c 8 --timeout 8 -t 8 "http://{server_host}:{port}{url}"
  42. sleep 5
  43. echo ""
  44. echo "---------------------------------------------------------"
  45. echo " Running Warmup {name}"
  46. echo " {wrk} {headers} --latency -d {duration} -c {max_concurrency} --timeout 8 -t $max_threads \"http://{server_host}:{port}{url}\""
  47. echo "---------------------------------------------------------"
  48. echo ""
  49. {wrk} {headers} --latency -d {duration} -c {max_concurrency} --timeout 8 -t $max_threads "http://{server_host}:{port}{url}"
  50. sleep 5
  51. echo ""
  52. echo "---------------------------------------------------------"
  53. echo " Synchronizing time"
  54. echo "---------------------------------------------------------"
  55. echo ""
  56. ntpdate -s pool.ntp.org
  57. for c in {levels}
  58. do
  59. echo ""
  60. echo "---------------------------------------------------------"
  61. echo " Concurrency: $c for {name}"
  62. echo " {wrk} {headers} --latency -d {duration} -c $c --timeout 8 -t $(($c>$max_threads?$max_threads:$c)) \"http://{server_host}:{port}{url}\""
  63. echo "---------------------------------------------------------"
  64. echo ""
  65. STARTTIME=$(date +"%s")
  66. {wrk} {headers} --latency -d {duration} -c $c --timeout 8 -t "$(($c>$max_threads?$max_threads:$c))" http://{server_host}:{port}{url}
  67. echo "STARTTIME $STARTTIME"
  68. echo "ENDTIME $(date +"%s")"
  69. sleep 2
  70. done
  71. """
  72. # Used for test types that require pipelining.
  73. pipeline_template = """
  74. let max_threads=$(cat /proc/cpuinfo | grep processor | wc -l)
  75. echo ""
  76. echo "---------------------------------------------------------"
  77. echo " Running Primer {name}"
  78. echo " {wrk} {headers} --latency -d 5 -c 8 --timeout 8 -t 8 \"http://{server_host}:{port}{url}\""
  79. echo "---------------------------------------------------------"
  80. echo ""
  81. {wrk} {headers} --latency -d 5 -c 8 --timeout 8 -t 8 "http://{server_host}:{port}{url}"
  82. sleep 5
  83. echo ""
  84. echo "---------------------------------------------------------"
  85. echo " Running Warmup {name}"
  86. echo " {wrk} {headers} --latency -d {duration} -c {max_concurrency} --timeout 8 -t $max_threads \"http://{server_host}:{port}{url}\""
  87. echo "---------------------------------------------------------"
  88. echo ""
  89. {wrk} {headers} --latency -d {duration} -c {max_concurrency} --timeout 8 -t $max_threads "http://{server_host}:{port}{url}"
  90. sleep 5
  91. echo ""
  92. echo "---------------------------------------------------------"
  93. echo " Synchronizing time"
  94. echo "---------------------------------------------------------"
  95. echo ""
  96. ntpdate -s pool.ntp.org
  97. for c in {levels}
  98. do
  99. echo ""
  100. echo "---------------------------------------------------------"
  101. echo " Concurrency: $c for {name}"
  102. echo " {wrk} {headers} --latency -d {duration} -c $c --timeout 8 -t $(($c>$max_threads?$max_threads:$c)) \"http://{server_host}:{port}{url}\" -s ~/pipeline.lua -- {pipeline}"
  103. echo "---------------------------------------------------------"
  104. echo ""
  105. STARTTIME=$(date +"%s")
  106. {wrk} {headers} --latency -d {duration} -c $c --timeout 8 -t "$(($c>$max_threads?$max_threads:$c))" http://{server_host}:{port}{url} -s ~/pipeline.lua -- {pipeline}
  107. echo "STARTTIME $STARTTIME"
  108. echo "ENDTIME $(date +"%s")"
  109. sleep 2
  110. done
  111. """
  112. # Used for test types that require a database -
  113. # These tests run at a static concurrency level and vary the size of
  114. # the query sent with each request
  115. query_template = """
  116. let max_threads=$(cat /proc/cpuinfo | grep processor | wc -l)
  117. echo ""
  118. echo "---------------------------------------------------------"
  119. echo " Running Primer {name}"
  120. echo " wrk {headers} --latency -d 5 -c 8 --timeout 8 -t 8 \"http://{server_host}:{port}{url}2\""
  121. echo "---------------------------------------------------------"
  122. echo ""
  123. wrk {headers} --latency -d 5 -c 8 --timeout 8 -t 8 "http://{server_host}:{port}{url}2"
  124. sleep 5
  125. echo ""
  126. echo "---------------------------------------------------------"
  127. echo " Running Warmup {name}"
  128. echo " wrk {headers} --latency -d {duration} -c {max_concurrency} --timeout 8 -t $max_threads \"http://{server_host}:{port}{url}2\""
  129. echo "---------------------------------------------------------"
  130. echo ""
  131. wrk {headers} --latency -d {duration} -c {max_concurrency} --timeout 8 -t $max_threads "http://{server_host}:{port}{url}2"
  132. sleep 5
  133. echo ""
  134. echo "---------------------------------------------------------"
  135. echo " Synchronizing time"
  136. echo "---------------------------------------------------------"
  137. echo ""
  138. ntpdate -s pool.ntp.org
  139. for c in {levels}
  140. do
  141. echo ""
  142. echo "---------------------------------------------------------"
  143. echo " Queries: $c for {name}"
  144. echo " wrk {headers} --latency -d {duration} -c {max_concurrency} --timeout 8 -t $max_threads \"http://{server_host}:{port}{url}$c\""
  145. echo "---------------------------------------------------------"
  146. echo ""
  147. STARTTIME=$(date +"%s")
  148. wrk {headers} --latency -d {duration} -c {max_concurrency} --timeout 8 -t $max_threads "http://{server_host}:{port}{url}$c"
  149. echo "STARTTIME $STARTTIME"
  150. echo "ENDTIME $(date +"%s")"
  151. sleep 2
  152. done
  153. """
  154. ############################################################
  155. # start(benchmarker)
  156. # Start the test using its setup file
  157. ############################################################
  158. def start(self, out):
  159. # Setup environment variables
  160. logDir = os.path.join(self.fwroot, self.benchmarker.full_results_directory(), 'logs', self.name.lower())
  161. def tee_output(prefix, line):
  162. # Needs to be one atomic write
  163. # Explicitly use UTF-8 as it's the most common framework output
  164. # TODO improve encoding handling
  165. line = prefix.encode('utf-8') + line
  166. # Log to current terminal
  167. sys.stdout.write(line)
  168. sys.stdout.flush()
  169. out.write(line)
  170. out.flush()
  171. prefix = "Setup %s: " % self.name
  172. ###########################
  173. # Build the Docker images
  174. ###########################
  175. test_docker_file = os.path.join(self.directory, "%s.dockerfile" % self.name)
  176. deps = list(reversed(gather_docker_dependencies( test_docker_file )))
  177. docker_dir = os.path.join(setup_util.get_fwroot(), "toolset", "setup", "linux", "docker")
  178. for dependency in deps:
  179. docker_file = os.path.join(self.directory, dependency + ".dockerfile")
  180. if not docker_file or not os.path.exists(docker_file):
  181. docker_file = find_docker_file(docker_dir, dependency + ".dockerfile")
  182. if not docker_file:
  183. tee_output(prefix, "Docker build failed; %s could not be found; terminating\n" % (dependency + ".dockerfile"))
  184. return 1
  185. p = subprocess.Popen([
  186. "docker",
  187. "build",
  188. "--build-arg",
  189. "CPU_COUNT=%s" % str(multiprocessing.cpu_count()),
  190. "--build-arg",
  191. "MAX_CONCURRENCY=%s" % max(self.benchmarker.concurrency_levels),
  192. "-f",
  193. docker_file,
  194. "-t",
  195. "tfb/%s" % dependency,
  196. os.path.dirname(docker_file)],
  197. stdout=subprocess.PIPE,
  198. stderr=subprocess.STDOUT)
  199. nbsr = setup_util.NonBlockingStreamReader(p.stdout)
  200. while (p.poll() is None):
  201. for i in xrange(10):
  202. try:
  203. line = nbsr.readline(0.05)
  204. if line:
  205. tee_output(prefix, line)
  206. except setup_util.EndOfStream:
  207. break
  208. if p.returncode != 0:
  209. tee_output(prefix, "Docker build failed; terminating\n")
  210. return 1
  211. p = subprocess.Popen([
  212. "docker",
  213. "build",
  214. "--build-arg",
  215. "CPU_COUNT=%s" % str(multiprocessing.cpu_count()),
  216. "--build-arg",
  217. "MAX_CONCURRENCY=%s" % max(self.benchmarker.concurrency_levels),
  218. "-f",
  219. test_docker_file,
  220. "-t",
  221. "tfb/test/%s" % self.name,
  222. self.directory],
  223. stdout=subprocess.PIPE,
  224. stderr=subprocess.STDOUT)
  225. nbsr = setup_util.NonBlockingStreamReader(p.stdout)
  226. while (p.poll() is None):
  227. for i in xrange(10):
  228. try:
  229. line = nbsr.readline(0.05)
  230. if line:
  231. tee_output(prefix, line)
  232. except setup_util.EndOfStream:
  233. break
  234. if p.returncode != 0:
  235. tee_output(prefix, "Docker build failed; terminating\n")
  236. return 1
  237. ##########################
  238. # Run the Docker container
  239. ##########################
  240. p = subprocess.Popen(["docker", "run", "--rm", "-p", "%s:%s" % (self.port, self.port), "--network=host", "tfb/test/%s" % self.name],
  241. stdout=subprocess.PIPE,
  242. stderr=subprocess.STDOUT)
  243. nbsr = setup_util.NonBlockingStreamReader(p.stdout,
  244. "%s: framework processes have terminated" % self.name)
  245. # Set a limit on total execution time of setup.sh
  246. timeout = datetime.now() + timedelta(minutes = 105)
  247. time_remaining = timeout - datetime.now()
  248. # Need to print to stdout once every 10 minutes or Travis-CI will abort
  249. travis_timeout = datetime.now() + timedelta(minutes = 5)
  250. # Flush output until docker run work is finished. This is
  251. # either a) when docker run exits b) when the port is bound
  252. # c) when we run out of time.
  253. prefix = "Server %s: " % self.name
  254. while (p.poll() is None
  255. and not self.benchmarker.is_port_bound(self.port)
  256. and not time_remaining.total_seconds() < 0):
  257. # The conditions above are slow to check, so
  258. # we will delay output substantially if we only
  259. # print one line per condition check.
  260. # Adding a tight loop here mitigates the effect,
  261. # ensuring that most of the output directly from
  262. # docker is sent to tee_output before the outer
  263. # loop exits and prints things like "docker exited"
  264. for i in xrange(10):
  265. try:
  266. line = nbsr.readline(0.05)
  267. if line:
  268. tee_output(prefix, line)
  269. # Reset Travis-CI timer
  270. travis_timeout = datetime.now() + timedelta(minutes = 5)
  271. except setup_util.EndOfStream:
  272. tee_output(prefix, "Docker has terminated\n")
  273. break
  274. time_remaining = timeout - datetime.now()
  275. if (travis_timeout - datetime.now()).total_seconds() < 0:
  276. sys.stdout.write(prefix + 'Printing so Travis-CI does not time out\n')
  277. sys.stdout.write(prefix + "Status: Poll: %s, Port %s bound: %s, Time Left: %s\n" % (
  278. p.poll(), self.port, self.benchmarker.is_port_bound(self.port), time_remaining))
  279. sys.stdout.flush()
  280. travis_timeout = datetime.now() + timedelta(minutes = 5)
  281. # Did we time out?
  282. if time_remaining.total_seconds() < 0:
  283. tee_output(prefix, "Docker run has timed out!! Aborting...\n" % self.setup_file)
  284. p.kill()
  285. return 1
  286. # What's our return code?
  287. # If docker run has terminated, use that code
  288. # Otherwise, detect if the port was bound
  289. tee_output(prefix, "Status: Poll: %s, Port %s bound: %s, Time Left: %s\n" % (
  290. p.poll(), self.port, self.benchmarker.is_port_bound(self.port), time_remaining))
  291. retcode = (p.poll() if p.poll() is not None else 0 if self.benchmarker.is_port_bound(self.port) else 1)
  292. if p.poll() is not None:
  293. tee_output(prefix, "Docker run process exited naturally with %s\n" % p.poll())
  294. elif self.benchmarker.is_port_bound(self.port):
  295. tee_output(prefix, "Bound port detected on %s\n" % self.port)
  296. # Before we return control to the benchmarker, spin up a
  297. # thread to keep an eye on the pipes in case the running
  298. # framework uses stdout/stderr. Once all processes accessing
  299. # the subprocess.PIPEs are dead, this thread will terminate.
  300. # Use a different prefix to indicate this is the framework
  301. # speaking
  302. def watch_child_pipes(nbsr, prefix):
  303. while True:
  304. try:
  305. line = nbsr.readline(60)
  306. if line:
  307. tee_output(prefix, line)
  308. except setup_util.EndOfStream:
  309. tee_output(prefix, "Framework processes have terminated\n")
  310. return
  311. watch_thread = Thread(target = watch_child_pipes,
  312. args = (nbsr, prefix))
  313. watch_thread.daemon = True
  314. watch_thread.start()
  315. return retcode
  316. ############################################################
  317. # End start
  318. ############################################################
  319. ############################################################
  320. # verify_urls
  321. # Verifys each of the URLs for this test. THis will sinply
  322. # curl the URL and check for it's return status.
  323. # For each url, a flag will be set on this object for whether
  324. # or not it passed
  325. # Returns True if all verifications succeeded
  326. ############################################################
  327. def verify_urls(self, logPath):
  328. result = True
  329. def verify_type(test_type):
  330. verificationPath = os.path.join(logPath, test_type)
  331. try:
  332. os.makedirs(verificationPath)
  333. except OSError:
  334. pass
  335. with open(os.path.join(verificationPath, 'verification.txt'), 'w') as verification:
  336. test = self.runTests[test_type]
  337. test.setup_out(verification)
  338. verification.write(header("VERIFYING %s" % test_type.upper()))
  339. base_url = "http://%s:%s" % (self.benchmarker.server_host, self.port)
  340. try:
  341. # Verifies headers from the server. This check is made from the
  342. # App Server using Pythons requests module. Will do a second check from
  343. # the client to make sure the server isn't only accepting connections
  344. # from localhost on a multi-machine setup.
  345. results = test.verify(base_url)
  346. # Now verify that the url is reachable from the client machine, unless
  347. # we're already failing
  348. if not any(result == 'fail' for (result, reason, url) in results):
  349. p = subprocess.call(["ssh", "TFB-client", "curl -sSf %s" % base_url + test.get_url()], shell=False, stdout=subprocess.PIPE, stderr=subprocess.PIPE)
  350. if p is not 0:
  351. results = [('fail', "Server did not respond to request from client machine.", base_url)]
  352. logging.warning("""This error usually means your server is only accepting
  353. requests from localhost.""")
  354. except ConnectionError as e:
  355. results = [('fail',"Server did not respond to request", base_url)]
  356. logging.warning("Verifying test %s for %s caused an exception: %s", test_type, self.name, e)
  357. except Exception as e:
  358. results = [('fail',"""Caused Exception in TFB
  359. This almost certainly means your return value is incorrect,
  360. but also that you have found a bug. Please submit an issue
  361. including this message: %s\n%s""" % (e, traceback.format_exc()),
  362. base_url)]
  363. logging.warning("Verifying test %s for %s caused an exception: %s", test_type, self.name, e)
  364. traceback.format_exc()
  365. test.failed = any(result == 'fail' for (result, reason, url) in results)
  366. test.warned = any(result == 'warn' for (result, reason, url) in results)
  367. test.passed = all(result == 'pass' for (result, reason, url) in results)
  368. def output_result(result, reason, url):
  369. specific_rules_url = "http://frameworkbenchmarks.readthedocs.org/en/latest/Project-Information/Framework-Tests/#specific-test-requirements"
  370. color = Fore.GREEN
  371. if result.upper() == "WARN":
  372. color = Fore.YELLOW
  373. elif result.upper() == "FAIL":
  374. color = Fore.RED
  375. verification.write((" " + color + "%s" + Style.RESET_ALL + " for %s\n") % (result.upper(), url))
  376. print(" {!s}{!s}{!s} for {!s}\n".format(color, result.upper(), Style.RESET_ALL, url))
  377. if reason is not None and len(reason) != 0:
  378. for line in reason.splitlines():
  379. verification.write(" " + line + '\n')
  380. print(" " + line)
  381. if not test.passed:
  382. verification.write(" See %s\n" % specific_rules_url)
  383. print(" See {!s}\n".format(specific_rules_url))
  384. [output_result(r1,r2,url) for (r1, r2, url) in results]
  385. if test.failed:
  386. self.benchmarker.report_verify_results(self, test_type, 'fail')
  387. elif test.warned:
  388. self.benchmarker.report_verify_results(self, test_type, 'warn')
  389. elif test.passed:
  390. self.benchmarker.report_verify_results(self, test_type, 'pass')
  391. else:
  392. raise Exception("Unknown error - test did not pass,warn,or fail")
  393. verification.flush()
  394. result = True
  395. for test_type in self.runTests:
  396. verify_type(test_type)
  397. if self.runTests[test_type].failed:
  398. result = False
  399. return result
  400. ############################################################
  401. # End verify_urls
  402. ############################################################
  403. ############################################################
  404. # benchmark
  405. # Runs the benchmark for each type of test that it implements
  406. # JSON/DB/Query.
  407. ############################################################
  408. def benchmark(self, logPath):
  409. def benchmark_type(test_type):
  410. benchmarkPath = os.path.join(logPath, test_type)
  411. try:
  412. os.makedirs(benchmarkPath)
  413. except OSError:
  414. pass
  415. with open(os.path.join(benchmarkPath, 'benchmark.txt'), 'w') as out:
  416. out.write("BENCHMARKING %s ... " % test_type.upper())
  417. test = self.runTests[test_type]
  418. test.setup_out(out)
  419. output_file = self.benchmarker.output_file(self.name, test_type)
  420. if not os.path.exists(output_file):
  421. # Open to create the empty file
  422. with open(output_file, 'w'):
  423. pass
  424. if not test.failed:
  425. if test_type == 'plaintext': # One special case
  426. remote_script = self.__generate_pipeline_script(test.get_url(), self.port, test.accept_header)
  427. elif test_type == 'query' or test_type == 'update':
  428. remote_script = self.__generate_query_script(test.get_url(), self.port, test.accept_header, self.benchmarker.query_levels)
  429. elif test_type == 'cached_query':
  430. remote_script = self.__generate_query_script(test.get_url(), self.port, test.accept_header, self.benchmarker.cached_query_levels)
  431. else:
  432. remote_script = self.__generate_concurrency_script(test.get_url(), self.port, test.accept_header)
  433. # Begin resource usage metrics collection
  434. self.__begin_logging(test_type)
  435. # Run the benchmark
  436. with open(output_file, 'w') as raw_file:
  437. p = subprocess.Popen(self.benchmarker.client_ssh_string.split(" "), stdin=subprocess.PIPE, stdout=raw_file, stderr=raw_file)
  438. p.communicate(remote_script)
  439. out.flush()
  440. # End resource usage metrics collection
  441. self.__end_logging()
  442. results = self.__parse_test(test_type)
  443. print("Benchmark results:")
  444. pprint(results)
  445. self.benchmarker.report_benchmark_results(framework=self, test=test_type, results=results['results'])
  446. out.write( "Complete\n" )
  447. out.flush()
  448. for test_type in self.runTests:
  449. benchmark_type(test_type)
  450. ############################################################
  451. # End benchmark
  452. ############################################################
  453. ############################################################
  454. # parse_all
  455. # Method meant to be run for a given timestamp
  456. ############################################################
  457. def parse_all(self):
  458. for test_type in self.runTests:
  459. if os.path.exists(self.benchmarker.get_output_file(self.name, test_type)):
  460. results = self.__parse_test(test_type)
  461. self.benchmarker.report_benchmark_results(framework=self, test=test_type, results=results['results'])
  462. ##########################################################################################
  463. # Private Methods
  464. ##########################################################################################
  465. ############################################################
  466. # __parse_test(test_type)
  467. ############################################################
  468. def __parse_test(self, test_type):
  469. try:
  470. results = dict()
  471. results['results'] = []
  472. stats = []
  473. if os.path.exists(self.benchmarker.get_output_file(self.name, test_type)):
  474. with open(self.benchmarker.output_file(self.name, test_type)) as raw_data:
  475. is_warmup = True
  476. rawData = None
  477. for line in raw_data:
  478. if "Queries:" in line or "Concurrency:" in line:
  479. is_warmup = False
  480. rawData = None
  481. continue
  482. if "Warmup" in line or "Primer" in line:
  483. is_warmup = True
  484. continue
  485. if not is_warmup:
  486. if rawData == None:
  487. rawData = dict()
  488. results['results'].append(rawData)
  489. #if "Requests/sec:" in line:
  490. # m = re.search("Requests/sec:\s+([0-9]+)", line)
  491. # rawData['reportedResults'] = m.group(1)
  492. # search for weighttp data such as succeeded and failed.
  493. if "Latency" in line:
  494. m = re.findall("([0-9]+\.*[0-9]*[us|ms|s|m|%]+)", line)
  495. if len(m) == 4:
  496. rawData['latencyAvg'] = m[0]
  497. rawData['latencyStdev'] = m[1]
  498. rawData['latencyMax'] = m[2]
  499. # rawData['latencyStdevPercent'] = m[3]
  500. #if "Req/Sec" in line:
  501. # m = re.findall("([0-9]+\.*[0-9]*[k|%]*)", line)
  502. # if len(m) == 4:
  503. # rawData['requestsAvg'] = m[0]
  504. # rawData['requestsStdev'] = m[1]
  505. # rawData['requestsMax'] = m[2]
  506. # rawData['requestsStdevPercent'] = m[3]
  507. #if "requests in" in line:
  508. # m = re.search("requests in ([0-9]+\.*[0-9]*[ms|s|m|h]+)", line)
  509. # if m != None:
  510. # # parse out the raw time, which may be in minutes or seconds
  511. # raw_time = m.group(1)
  512. # if "ms" in raw_time:
  513. # rawData['total_time'] = float(raw_time[:len(raw_time)-2]) / 1000.0
  514. # elif "s" in raw_time:
  515. # rawData['total_time'] = float(raw_time[:len(raw_time)-1])
  516. # elif "m" in raw_time:
  517. # rawData['total_time'] = float(raw_time[:len(raw_time)-1]) * 60.0
  518. # elif "h" in raw_time:
  519. # rawData['total_time'] = float(raw_time[:len(raw_time)-1]) * 3600.0
  520. if "requests in" in line:
  521. m = re.search("([0-9]+) requests in", line)
  522. if m != None:
  523. rawData['totalRequests'] = int(m.group(1))
  524. if "Socket errors" in line:
  525. if "connect" in line:
  526. m = re.search("connect ([0-9]+)", line)
  527. rawData['connect'] = int(m.group(1))
  528. if "read" in line:
  529. m = re.search("read ([0-9]+)", line)
  530. rawData['read'] = int(m.group(1))
  531. if "write" in line:
  532. m = re.search("write ([0-9]+)", line)
  533. rawData['write'] = int(m.group(1))
  534. if "timeout" in line:
  535. m = re.search("timeout ([0-9]+)", line)
  536. rawData['timeout'] = int(m.group(1))
  537. if "Non-2xx" in line:
  538. m = re.search("Non-2xx or 3xx responses: ([0-9]+)", line)
  539. if m != None:
  540. rawData['5xx'] = int(m.group(1))
  541. if "STARTTIME" in line:
  542. m = re.search("[0-9]+", line)
  543. rawData["startTime"] = int(m.group(0))
  544. if "ENDTIME" in line:
  545. m = re.search("[0-9]+", line)
  546. rawData["endTime"] = int(m.group(0))
  547. test_stats = self.__parse_stats(test_type, rawData["startTime"], rawData["endTime"], 1)
  548. # rawData["averageStats"] = self.__calculate_average_stats(test_stats)
  549. stats.append(test_stats)
  550. with open(self.benchmarker.stats_file(self.name, test_type) + ".json", "w") as stats_file:
  551. json.dump(stats, stats_file, indent=2)
  552. return results
  553. except IOError:
  554. return None
  555. ############################################################
  556. # End benchmark
  557. ############################################################
  558. ############################################################
  559. # __generate_concurrency_script(url, port)
  560. # Generates the string containing the bash script that will
  561. # be run on the client to benchmark a single test. This
  562. # specifically works for the variable concurrency tests (JSON
  563. # and DB)
  564. ############################################################
  565. def __generate_concurrency_script(self, url, port, accept_header, wrk_command="wrk"):
  566. headers = self.headers_template.format(server_host=self.benchmarker.server_host, accept=accept_header)
  567. return self.concurrency_template.format(max_concurrency=max(self.benchmarker.concurrency_levels),
  568. name=self.name, duration=self.benchmarker.duration,
  569. levels=" ".join("{}".format(item) for item in self.benchmarker.concurrency_levels),
  570. server_host=self.benchmarker.server_host, port=port, url=url, headers=headers, wrk=wrk_command)
  571. ############################################################
  572. # __generate_pipeline_script(url, port)
  573. # Generates the string containing the bash script that will
  574. # be run on the client to benchmark a single pipeline test.
  575. ############################################################
  576. def __generate_pipeline_script(self, url, port, accept_header, wrk_command="wrk"):
  577. headers = self.headers_template.format(server_host=self.benchmarker.server_host, accept=accept_header)
  578. return self.pipeline_template.format(max_concurrency=max(self.benchmarker.pipeline_concurrency_levels),
  579. name=self.name, duration=self.benchmarker.duration,
  580. levels=" ".join("{}".format(item) for item in self.benchmarker.pipeline_concurrency_levels),
  581. server_host=self.benchmarker.server_host, port=port, url=url, headers=headers, wrk=wrk_command,
  582. pipeline=16)
  583. ############################################################
  584. # __generate_query_script(url, port)
  585. # Generates the string containing the bash script that will
  586. # be run on the client to benchmark a single test. This
  587. # specifically works for the variable query tests (Query)
  588. ############################################################
  589. def __generate_query_script(self, url, port, accept_header, query_levels):
  590. headers = self.headers_template.format(server_host=self.benchmarker.server_host, accept=accept_header)
  591. return self.query_template.format(max_concurrency=max(self.benchmarker.concurrency_levels),
  592. name=self.name, duration=self.benchmarker.duration,
  593. levels=" ".join("{}".format(item) for item in query_levels),
  594. server_host=self.benchmarker.server_host, port=port, url=url, headers=headers)
  595. ############################################################
  596. # Returns True if any test type this this framework test will use a DB
  597. ############################################################
  598. def requires_database(self):
  599. '''Returns True/False if this test requires a database'''
  600. return any(tobj.requires_db for (ttype,tobj) in self.runTests.iteritems())
  601. ############################################################
  602. # __begin_logging
  603. # Starts a thread to monitor the resource usage, to be synced with the client's time
  604. # TODO: MySQL and InnoDB are possible. Figure out how to implement them.
  605. ############################################################
  606. def __begin_logging(self, test_type):
  607. output_file = "{file_name}".format(file_name=self.benchmarker.get_stats_file(self.name, test_type))
  608. dstat_string = "dstat -Tafilmprs --aio --fs --ipc --lock --raw --socket --tcp \
  609. --raw --socket --tcp --udp --unix --vm --disk-util \
  610. --rpc --rpcd --output {output_file}".format(output_file=output_file)
  611. cmd = shlex.split(dstat_string)
  612. dev_null = open(os.devnull, "w")
  613. self.subprocess_handle = subprocess.Popen(cmd, stdout=dev_null, stderr=subprocess.STDOUT)
  614. ##############################################################
  615. # Begin __end_logging
  616. # Stops the logger thread and blocks until shutdown is complete.
  617. ##############################################################
  618. def __end_logging(self):
  619. self.subprocess_handle.terminate()
  620. self.subprocess_handle.communicate()
  621. ##############################################################
  622. # Begin __parse_stats
  623. # For each test type, process all the statistics, and return a multi-layered dictionary
  624. # that has a structure as follows:
  625. # (timestamp)
  626. # | (main header) - group that the stat is in
  627. # | | (sub header) - title of the stat
  628. # | | | (stat) - the stat itself, usually a floating point number
  629. ##############################################################
  630. def __parse_stats(self, test_type, start_time, end_time, interval):
  631. stats_dict = dict()
  632. stats_file = self.benchmarker.stats_file(self.name, test_type)
  633. with open(stats_file) as stats:
  634. while(stats.next() != "\n"): # dstat doesn't output a completely compliant CSV file - we need to strip the header
  635. pass
  636. stats_reader = csv.reader(stats)
  637. main_header = stats_reader.next()
  638. sub_header = stats_reader.next()
  639. time_row = sub_header.index("epoch")
  640. int_counter = 0
  641. for row in stats_reader:
  642. time = float(row[time_row])
  643. int_counter+=1
  644. if time < start_time:
  645. continue
  646. elif time > end_time:
  647. return stats_dict
  648. if int_counter % interval != 0:
  649. continue
  650. row_dict = dict()
  651. for nextheader in main_header:
  652. if nextheader != "":
  653. row_dict[nextheader] = dict()
  654. header = ""
  655. for item_num, column in enumerate(row):
  656. if(len(main_header[item_num]) != 0):
  657. header = main_header[item_num]
  658. 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
  659. stats_dict[time] = row_dict
  660. return stats_dict
  661. ##############################################################
  662. # End __parse_stats
  663. ##############################################################
  664. def __getattr__(self, name):
  665. """For backwards compatibility, we used to pass benchmarker
  666. as the argument to the setup.sh files"""
  667. try:
  668. x = getattr(self.benchmarker, name)
  669. except AttributeError:
  670. print("AttributeError: {!s} not a member of FrameworkTest or Benchmarker".format(name))
  671. print("This is probably a bug")
  672. raise
  673. return x
  674. ##############################################################
  675. # Begin __calculate_average_stats
  676. # We have a large amount of raw data for the statistics that
  677. # may be useful for the stats nerds, but most people care about
  678. # a couple of numbers. For now, we're only going to supply:
  679. # * Average CPU
  680. # * Average Memory
  681. # * Total network use
  682. # * Total disk use
  683. # More may be added in the future. If they are, please update
  684. # the above list.
  685. # Note: raw_stats is directly from the __parse_stats method.
  686. # Recall that this consists of a dictionary of timestamps,
  687. # each of which contain a dictionary of stat categories which
  688. # contain a dictionary of stats
  689. ##############################################################
  690. def __calculate_average_stats(self, raw_stats):
  691. raw_stat_collection = dict()
  692. for timestamp, time_dict in raw_stats.items():
  693. for main_header, sub_headers in time_dict.items():
  694. item_to_append = None
  695. if 'cpu' in main_header:
  696. # We want to take the idl stat and subtract it from 100
  697. # to get the time that the CPU is NOT idle.
  698. item_to_append = sub_headers['idl'] - 100.0
  699. elif main_header == 'memory usage':
  700. item_to_append = sub_headers['used']
  701. elif 'net' in main_header:
  702. # Network stats have two parts - recieve and send. We'll use a tuple of
  703. # style (recieve, send)
  704. item_to_append = (sub_headers['recv'], sub_headers['send'])
  705. elif 'dsk' or 'io' in main_header:
  706. # Similar for network, except our tuple looks like (read, write)
  707. item_to_append = (sub_headers['read'], sub_headers['writ'])
  708. if item_to_append is not None:
  709. if main_header not in raw_stat_collection:
  710. raw_stat_collection[main_header] = list()
  711. raw_stat_collection[main_header].append(item_to_append)
  712. # Simple function to determine human readable size
  713. # http://stackoverflow.com/questions/1094841/reusable-library-to-get-human-readable-version-of-file-size
  714. def sizeof_fmt(num):
  715. # We'll assume that any number we get is convertable to a float, just in case
  716. num = float(num)
  717. for x in ['bytes','KB','MB','GB']:
  718. if num < 1024.0 and num > -1024.0:
  719. return "%3.1f%s" % (num, x)
  720. num /= 1024.0
  721. return "%3.1f%s" % (num, 'TB')
  722. # Now we have our raw stats in a readable format - we need to format it for display
  723. # We need a floating point sum, so the built in sum doesn't cut it
  724. display_stat_collection = dict()
  725. for header, values in raw_stat_collection.items():
  726. display_stat = None
  727. if 'cpu' in header:
  728. display_stat = sizeof_fmt(math.fsum(values) / len(values))
  729. elif main_header == 'memory usage':
  730. display_stat = sizeof_fmt(math.fsum(values) / len(values))
  731. elif 'net' in main_header:
  732. receive, send = zip(*values) # unzip
  733. display_stat = {'receive': sizeof_fmt(math.fsum(receive)), 'send': sizeof_fmt(math.fsum(send))}
  734. else: # if 'dsk' or 'io' in header:
  735. read, write = zip(*values) # unzip
  736. display_stat = {'read': sizeof_fmt(math.fsum(read)), 'write': sizeof_fmt(math.fsum(write))}
  737. display_stat_collection[header] = display_stat
  738. return display_stat
  739. ###########################################################################################
  740. # End __calculate_average_stats
  741. #########################################################################################
  742. ##########################################################################################
  743. # Constructor
  744. ##########################################################################################
  745. def __init__(self, name, directory, benchmarker, runTests, args):
  746. self.name = name
  747. self.directory = directory
  748. self.benchmarker = benchmarker
  749. self.runTests = runTests
  750. self.fwroot = benchmarker.fwroot
  751. self.approach = ""
  752. self.classification = ""
  753. self.database = ""
  754. self.framework = ""
  755. self.language = ""
  756. self.orm = ""
  757. self.platform = ""
  758. self.webserver = ""
  759. self.os = ""
  760. self.database_os = ""
  761. self.display_name = ""
  762. self.notes = ""
  763. self.versus = ""
  764. # setup logging
  765. logging.basicConfig(stream=sys.stderr, level=logging.INFO)
  766. self.install_root="%s/%s" % (self.fwroot, "installs")
  767. # Used in setup.sh scripts for consistency with
  768. # the bash environment variables
  769. self.troot = self.directory
  770. self.iroot = self.install_root
  771. self.__dict__.update(args)
  772. ############################################################
  773. # End __init__
  774. ############################################################
  775. ############################################################
  776. # End FrameworkTest
  777. ############################################################
  778. # Static methods
  779. def test_order(type_name):
  780. """
  781. This sort ordering is set up specifically to return the length
  782. of the test name. There were SO many problems involved with
  783. 'plaintext' being run first (rather, just not last) that we
  784. needed to ensure that it was run last for every framework.
  785. """
  786. return len(type_name)
  787. def validate_urls(test_name, test_keys):
  788. """
  789. Separated from validate_test because urls are not required anywhere. We know a url is incorrect if it is
  790. empty or does not start with a "/" character. There is no validation done to ensure the url conforms to
  791. the suggested url specifications, although those suggestions are presented if a url fails validation here.
  792. """
  793. example_urls = {
  794. "json_url": "/json",
  795. "db_url": "/mysql/db",
  796. "query_url": "/mysql/queries?queries= or /mysql/queries/",
  797. "fortune_url": "/mysql/fortunes",
  798. "update_url": "/mysql/updates?queries= or /mysql/updates/",
  799. "plaintext_url": "/plaintext",
  800. "cached_query_url": "/mysql/cached_queries?queries= or /mysql/cached_queries"
  801. }
  802. for test_url in ["json_url","db_url","query_url","fortune_url","update_url","plaintext_url","cached_query_url"]:
  803. key_value = test_keys.get(test_url, None)
  804. if key_value != None and not key_value.startswith('/'):
  805. errmsg = """`%s` field in test \"%s\" does not appear to be a valid url: \"%s\"\n
  806. Example `%s` url: \"%s\"
  807. """ % (test_url, test_name, key_value, test_url, example_urls[test_url])
  808. raise Exception(errmsg)
  809. def validate_test(test_name, test_keys, directory):
  810. """
  811. Validate benchmark config values for this test based on a schema
  812. """
  813. # Ensure that each FrameworkTest has a framework property, inheriting from top-level if not
  814. if not test_keys['framework']:
  815. test_keys['framework'] = config['framework']
  816. recommended_lang = directory.split('/')[-2]
  817. windows_url = "https://github.com/TechEmpower/FrameworkBenchmarks/issues/1038"
  818. schema = {
  819. 'language': {
  820. 'help': ('language', 'The language of the framework used, suggestion: %s' % recommended_lang)
  821. },
  822. 'webserver': {
  823. 'help': ('webserver', 'Name of the webserver also referred to as the "front-end server"')
  824. },
  825. 'classification': {
  826. 'allowed': [
  827. ('Fullstack', '...'),
  828. ('Micro', '...'),
  829. ('Platform', '...')
  830. ]
  831. },
  832. 'database': {
  833. 'allowed': [
  834. ('MySQL', 'One of the most popular databases around the web and in TFB'),
  835. ('Postgres', 'An advanced SQL database with a larger feature set than MySQL'),
  836. ('MongoDB', 'A popular document-store database'),
  837. ('Cassandra', 'A highly performant and scalable NoSQL database'),
  838. ('Elasticsearch', 'A distributed RESTful search engine that is used as a database for TFB tests'),
  839. ('Redis', 'An open-sourced, BSD licensed, advanced key-value cache and store'),
  840. ('SQLite', 'A network-less database, still supported for backwards compatibility'),
  841. ('SQLServer', 'Microsoft\'s SQL implementation'),
  842. ('None', 'No database was used for these tests, as is the case with Json Serialization and Plaintext')
  843. ]
  844. },
  845. 'approach': {
  846. 'allowed': [
  847. ('Realistic', '...'),
  848. ('Stripped', '...')
  849. ]
  850. },
  851. 'orm': {
  852. 'allowed': [
  853. ('Full', 'Has a full suite of features like lazy loading, caching, multiple language support, sometimes pre-configured with scripts.'),
  854. ('Micro', 'Has basic database driver capabilities such as establishing a connection and sending queries.'),
  855. ('Raw', 'Tests that do not use an ORM will be classified as "raw" meaning they use the platform\'s raw database connectivity.')
  856. ]
  857. },
  858. 'platform': {
  859. 'help': ('platform', 'Name of the platform this framework runs on, e.g. Node.js, PyPy, hhvm, JRuby ...')
  860. },
  861. 'framework': {
  862. # Guranteed to be here and correct at this point
  863. # key is left here to produce the set of required keys
  864. },
  865. 'os': {
  866. 'allowed': [
  867. ('Linux', 'Our best-supported host OS, it is recommended that you build your tests for Linux hosts'),
  868. ('Windows', 'TFB is not fully-compatible on windows, contribute towards our work on compatibility: %s' % windows_url)
  869. ]
  870. },
  871. 'database_os': {
  872. 'allowed': [
  873. ('Linux', 'Our best-supported host OS, it is recommended that you build your tests for Linux hosts'),
  874. ('Windows', 'TFB is not fully-compatible on windows, contribute towards our work on compatibility: %s' % windows_url)
  875. ]
  876. }
  877. }
  878. # Confirm required keys are present
  879. required_keys = schema.keys()
  880. missing = list(set(required_keys) - set(test_keys))
  881. if len(missing) > 0:
  882. missingstr = (", ").join(map(str, missing))
  883. raise Exception("benchmark_config.json for test %s is invalid, please amend by adding the following required keys: [%s]"
  884. % (test_name, missingstr))
  885. # Check the (all optional) test urls
  886. validate_urls(test_name, test_keys)
  887. # Check values of keys against schema
  888. for key in required_keys:
  889. val = test_keys.get(key, "").lower()
  890. has_predefined_acceptables = 'allowed' in schema[key]
  891. if has_predefined_acceptables:
  892. allowed = schema[key].get('allowed', [])
  893. acceptable_values, descriptors = zip(*allowed)
  894. acceptable_values = [a.lower() for a in acceptable_values]
  895. if val not in acceptable_values:
  896. msg = ("Invalid `%s` value specified for test \"%s\" in framework \"%s\"; suggestions:\n"
  897. % (key, test_name, test_keys['framework']))
  898. helpinfo = ('\n').join([" `%s` -- %s" % (v, desc) for (v, desc) in zip(acceptable_values, descriptors)])
  899. fullerr = msg + helpinfo + "\n"
  900. raise Exception(fullerr)
  901. elif not has_predefined_acceptables and val == "":
  902. msg = ("Value for `%s` in test \"%s\" in framework \"%s\" was missing:\n"
  903. % (key, test_name, test_keys['framework']))
  904. helpinfo = " %s -- %s" % schema[key]['help']
  905. fullerr = msg + helpinfo + '\n'
  906. raise Exception(fullerr)
  907. def parse_config(config, directory, benchmarker):
  908. """
  909. Parses a config file into a list of FrameworkTest objects
  910. """
  911. tests = []
  912. # The config object can specify multiple tests
  913. # Loop over them and parse each into a FrameworkTest
  914. for test in config['tests']:
  915. tests_to_run = [name for (name,keys) in test.iteritems()]
  916. if "default" not in tests_to_run:
  917. logging.warn("Framework %s does not define a default test in benchmark_config.json", config['framework'])
  918. # Check that each test configuration is acceptable
  919. # Throw exceptions if a field is missing, or how to improve the field
  920. for test_name, test_keys in test.iteritems():
  921. # Validates the benchmark_config entry
  922. validate_test(test_name, test_keys, directory)
  923. # Map test type to a parsed FrameworkTestType object
  924. runTests = dict()
  925. for type_name, type_obj in benchmarker.types.iteritems():
  926. try:
  927. # Makes a FrameWorkTestType object using some of the keys in config
  928. # e.g. JsonTestType uses "json_url"
  929. runTests[type_name] = type_obj.copy().parse(test_keys)
  930. except AttributeError as ae:
  931. # This is quite common - most tests don't support all types
  932. # Quitely log it and move on (debug logging is on in travis and this causes
  933. # ~1500 lines of debug, so I'm totally ignoring it for now
  934. # logging.debug("Missing arguments for test type %s for framework test %s", type_name, test_name)
  935. pass
  936. # We need to sort by test_type to run
  937. sortedTestKeys = sorted(runTests.keys(), key=test_order)
  938. sortedRunTests = OrderedDict()
  939. for sortedTestKey in sortedTestKeys:
  940. sortedRunTests[sortedTestKey] = runTests[sortedTestKey]
  941. # Prefix all test names with framework except 'default' test
  942. # Done at the end so we may still refer to the primary test as `default` in benchmark config error messages
  943. if test_name == 'default':
  944. test_name = config['framework']
  945. else:
  946. test_name = "%s-%s" % (config['framework'], test_name)
  947. # By passing the entire set of keys, each FrameworkTest will have a member for each key
  948. tests.append(FrameworkTest(test_name, directory, benchmarker, sortedRunTests, test_keys))
  949. return tests