bf820c553a1d8be380dbd32ecf8dad439a05b673
[barrelfish] / tools / harness / tests / webserver.py
1 ##########################################################################
2 # Copyright (c) 2009, ETH Zurich.
3 # All rights reserved.
4 #
5 # This file is distributed under the terms in the attached LICENSE file.
6 # If you do not find this file, copies can be found by writing to:
7 # ETH Zurich D-INFK, Haldeneggsteig 4, CH-8092 Zurich. Attn: Systems Group.
8 ##########################################################################
9
10 import re, socket, httplib, traceback, os, subprocess, datetime, glob, time
11 import tests, debug, siteconfig
12 from common import TestCommon, TimeoutError, select_timeout
13 from results import ResultsBase, PassFailResult, RowResults
14
15
16 WEBSERVER_TEST_FILES=['index.html', 'barrelfish.gif', 'barrelfish_sosp09.pdf', 'nevill-master-capabilities.pdf', 'razavi-master-performanceisolation.pdf']
17
18 WEBSERVER_TIMEOUT=5 # seconds
19 TEST_LOG_NAME = 'testlog.txt'
20
21 HTTPERF_BASE_ARGS='--hog --close-with-reset --timeout 2 '
22 HTTPERF_URI = '/index.html'
23
24 # Webserver stress test, It will download index page repeatedly for following
25 #       number of times
26 WEBSERVER_STRESS_COUNTER = 3000
27
28 # desired duration of an httperf test run (seconds)
29 HTTPERF_DURATION = 20
30
31 # sleep time between runs (seconds)
32 HTTPERF_SLEEPTIME = 20
33
34 # timeout for a complete run, including setup etc.
35 HTTPERF_TIMEOUT = datetime.timedelta(seconds=(HTTPERF_DURATION + 30))
36
37 # connection rates across all client machines
38 HTTPERF_STARTRATE = 1000  # initial rate
39 HTTPERF_RATEINCREMENT = 1000  # amount to increment by for each new run
40
41
42 class WebCommon(TestCommon):
43
44     def __init__(self, options):
45         super(WebCommon, self).__init__(options)
46         self.test_timeout_delta = datetime.timedelta(seconds=600)
47         self.read_after_finished = True
48         self.server_failures = []
49
50     def setup(self, build, machine, testdir):
51         super(WebCommon, self).setup(build, machine, testdir)
52         self.testdir = testdir
53         self.finished = False
54         self.ip = None
55
56     def get_modules(self, build, machine):
57         cardName = "e1000"
58         modules = super(WebCommon, self).get_modules(build, machine)
59         modules.add_module("e1000_net_sockets_server", ["auto"])
60         nfsip = socket.gethostbyname(siteconfig.get('WEBSERVER_NFS_HOST'))
61         modules.add_module("webserver", ["core=%d" % machine.get_coreids()[0], #2
62                                 nfsip, siteconfig.get('WEBSERVER_NFS_PATH')])
63 #                                         siteconfig.get('WEBSERVER_NFS_TEST_PATH')])
64         return modules
65
66     def process_line(self, line):
67         m = re.match(r'# IP Addr (\d+\.\d+\.\d+\.\d+)', line)
68         if m:
69             self.ip = m.group(1)
70         elif self.ip and 'Starting webserver' in line:
71             debug.verbose("Running the tests")
72             self.runtests(self.ip)
73             self.finished = True
74         elif line.startswith("kernel PANIC!") or \
75              line.startswith("Assertion failed on core") or \
76              re.match("Assertion .* failed at line", line) or \
77              line.startswith("Aborted"):
78             # Severe error in webserver, failing test
79             if line.startswith("Aborted") and \
80                self.previous_line not in self.server_failures:
81                 line = self.previous_line
82             self.server_failures.append(line.strip())
83             self.finished = True
84
85         self.previous_line = line.strip()
86
87     def passed(self):
88         return len(self.server_failures) == 0
89
90     def is_finished(self, line):
91         return self.finished or super(WebCommon, self).is_finished(line)
92
93
94 @tests.add_test
95 class WebserverTest(WebCommon):
96     '''tests webserver functionality'''
97     name = "webserver"
98
99     def setup(self, *args):
100         super(WebserverTest, self).setup(*args)
101         self.testlog = None
102
103     def getpage_stress(self, server, page, count):
104         debug.verbose('requesting http://%s/%s' % (server, page))
105         failure_count = 0;
106         #c = httplib.HTTPConnection(server, timeout=WEBSERVER_TIMEOUT)
107         for i in range(count):
108             try:
109                 c = httplib.HTTPConnection(server, timeout=WEBSERVER_TIMEOUT)
110                 c.request('GET', '/' + page)
111                 r = c.getresponse()
112                 if (r.status / 100) != 2 :
113                     print "HTTP request failed for %d" % (i)
114                 assert((r.status / 100) == 2) # check for success response
115                 data = r.read()
116                 # Reset failure count after sucessful retrival
117                 failure_count = 0
118                 c.close()
119             except Exception as e:
120                 print "HTTP request failed for %d, (failure count %d)" % (i,
121                         failure_count)
122                 print "Exception: ", e
123                 failure_count = failure_count + 1
124                 if failure_count >= 3:
125                     print "HTTP request failed for 3 successive times."
126                     print "Giving up for %d, (failure count %d)" % (i,
127                         failure_count)
128                     raise
129
130             #c.close()
131         debug.verbose('server replied %s %s for %d times' % (r.status, r.reason, count))
132
133
134     def getpage(self, server, page):
135         debug.verbose('requesting http://%s/%s' % (server, page))
136         c = httplib.HTTPConnection(server, timeout=WEBSERVER_TIMEOUT)
137         c.request('GET', '/' + page)
138         r = c.getresponse()
139
140         debug.verbose('server replied %s %s' % (r.status, r.reason))
141         assert((r.status / 100) == 2) # check for success response
142
143         try:
144             local_path = siteconfig.get('WEBSERVER_LOCAL_PATH')
145         except AttributeError:
146             local_path = None
147         local = os.path.join(local_path, page) if local_path else None
148         if local and os.path.isfile(local) and os.access(local, os.R_OK):
149             debug.verbose('comparing content to %s' % local)
150             l = open(local, 'r')
151             # read from both files and compare
152             CHUNKSIZE = 4096
153             while True:
154                 remote_data = r.read(CHUNKSIZE)
155                 local_data = l.read(CHUNKSIZE)
156                 if remote_data != local_data:
157                     print "Remote and local data did not match:"
158                     print "Remote data\n"
159                     print remote_data
160                     print "Local data\n"
161                     print local_data
162                 assert(remote_data == local_data)
163                 if len(local_data) < CHUNKSIZE:
164                     break
165
166             debug.verbose('contents matched for %s' % local)
167         c.close()
168
169     def dotest(self, func, args):
170         exception = None
171         r = None
172         try:
173             r = func(*args)
174         except Exception as e:
175             exception = e
176
177         s = 'Test: %s%s\t%s\n' % (func.__name__, str(args),
178                                  'FAIL' if exception else 'PASS')
179         if exception:
180             debug.verbose('Exception while running test: %s\n'
181                           % traceback.format_exc())
182             s += 'Error was: %s\n' % traceback.format_exc()
183         self.testlog.write(s)
184
185         return r
186
187     def runtests(self, server):
188         stress_counter = WEBSERVER_STRESS_COUNTER
189         self.testlog = open(os.path.join(self.testdir, TEST_LOG_NAME), 'w')
190         for f in WEBSERVER_TEST_FILES:
191             self.dotest(self.getpage, (server, f))
192             debug.verbose("Running stresstest: (%d GET %s)" %
193                     (stress_counter, str(f)))
194             self.dotest(self.getpage_stress, (server, f, stress_counter))
195         self.testlog.close()
196
197     def process_data(self, testdir, rawiter):
198         # the test passed iff we see at least one PASS and no FAILs in the log
199         passed = None
200         try:
201             testlog = open(os.path.join(testdir, TEST_LOG_NAME), 'r')
202         except IOError as e:
203             debug.verbose("Cannot find test log, failing test")
204             return PassFailResult(False, reason="Cannot find test log")
205
206         for line in testlog:
207             if re.match('Test:.*FAIL$', line):
208                 passed = False
209             elif passed != False and re.match('Test:.*PASS$', line):
210                 passed = True
211         testlog.close()
212         server_ok = super(WebserverTest, self).passed()
213         return PassFailResult(passed and server_ok)
214
215
216 @tests.add_test
217 class HTTPerfTest(WebCommon):
218     '''httperf webserver performance benchmark'''
219     name = "httperf"
220
221     def setup(self, *args):
222         super(HTTPerfTest, self).setup(*args)
223         self.nruns = 0
224
225     def _runtest(self, target, nclients, nconns, rate):
226         self.nruns += 1
227         nrun = self.nruns
228         httperfs = []
229         try:
230             for nclient in range(nclients):
231                 user, host = siteconfig.site.get_load_generator()
232                 assert(nrun < 100 and nclient < 100)
233                 filename = 'httperf_run%02d_%02d.txt' % (nrun, nclient)
234                 logfile = open(os.path.join(self.testdir, filename), 'w')
235                 debug.verbose('spawning httperf on %s' % host)
236                 hp = HTTPerfClient(logfile, user, host, target, nconns, rate)
237                 httperfs.append(hp)
238
239             # loop collecting output from all of them
240             busy_httperfs = list(httperfs) # copy list
241             timeout = datetime.datetime.now() + HTTPERF_TIMEOUT
242             while busy_httperfs:
243                 (ready, _, _) = select_timeout(timeout, busy_httperfs)
244                 if not ready:
245                     raise TimeoutError('waiting for httperfs')
246                 for hp in ready:
247                     try:
248                         hp.read()
249                     except EOFError:
250                         busy_httperfs.remove(hp)
251         finally:
252             debug.log('cleaning up httperf test...')
253             for hp in httperfs:
254                 hp.cleanup()
255
256     def runtests(self, target):
257         nclients = siteconfig.get('HTTPERF_MAXCLIENTS')
258         firstrun = True
259         totalrate = HTTPERF_STARTRATE
260         while True:
261             if firstrun:
262                 firstrun = False
263             else:
264                 # sleep a moment to let things settle down between runs
265                 debug.verbose('sleeping between httperf runs')
266                 time.sleep(HTTPERF_SLEEPTIME)
267
268             # compute rate and total number of connections for each client
269             rate = totalrate / nclients
270             nconns = HTTPERF_DURATION * rate
271
272             debug.log('starting httperf: %d clients, %d conns, rate %d (%d per client)' %
273                       (nclients, nconns, totalrate, rate))
274             self._runtest(target, nclients, nconns, rate)
275
276             # decide whether to keep going...
277             results = self._process_run(self.nruns)
278             if not results.passed():
279                 debug.log('previous test failed, stopping')
280                 break
281             elif results.request_rate < (0.9 * results.connect_rate):
282                 debug.log('request rate below 90% of connect rate, stopping')
283                 break
284             elif results.reply_rate < (0.9 * results.request_rate):
285                 debug.log('reply rate below 90% of request rate, stopping')
286                 break
287             else:
288                 totalrate += HTTPERF_RATEINCREMENT
289                 continue
290
291     def _process_one(self, logfile):
292         ret = HTTPerfResults()
293         matches = 0
294
295         for line in logfile:
296             # Connection rate
297             m = re.match('Connection rate: (\d+\.\d+) conn/s', line)
298             if m:
299                 matches += 1
300                 ret.connect_rate = float(m.group(1))
301
302             # Request rate
303             m = re.match('Request rate: (\d+\.\d+) req/s', line)
304             if m:
305                 matches += 1
306                 ret.request_rate = float(m.group(1))
307
308             # Reply rate
309             m = re.search('Reply rate \[replies/s\]: min .* avg (\d+\.\d+)'
310                           ' max .* stddev .*', line)
311             if m:
312                 matches += 1
313                 ret.reply_rate = float(m.group(1))
314
315             # Bandwidth
316             m = re.match('Net I/O: .* KB/s \((\d+\.\d+)\*10\^6 bps\)', line)
317             if m:
318                 matches += 1
319                 ret.bandwidth = float(m.group(1))
320
321             # client-side errors
322             m = re.match('Errors: fd-unavail (\d+) addrunavail (\d+)'
323                          ' ftab-full (\d+) other (\d+)', line)
324             if m:
325                 matches += 1
326                 ret.fd_unavail = int(m.group(1))
327                 ret.addrunavail = int(m.group(2))
328                 ret.ftab_full = int(m.group(3))
329                 ret.other_err = int(m.group(4))
330
331             # server-side errors
332             m = re.match('Errors: total \d+ client-timo (\d+) socket-timo (\d+)'
333                          ' connrefused (\d+) connreset (\d+)', line)
334             if m:
335                 matches += 1
336                 ret.client_timo = int(m.group(1))
337                 ret.socket_timo = int(m.group(2))
338                 ret.connrefused = int(m.group(3))
339                 ret.connreset = int(m.group(4))
340
341         if matches != 6 : # otherwise we have an invalid log
342             print "Instead of 6, only %d matches found\n" % (matches)
343
344         return ret
345
346
347     def _process_run(self, nrun):
348         nameglob = 'httperf_run%02d_*.txt' % nrun
349         results = []
350         for filename in glob.iglob(os.path.join(self.testdir, nameglob)):
351             with open(filename, 'r') as logfile:
352                 results.append(self._process_one(logfile))
353         return sum(results, HTTPerfResults())
354
355     def process_data(self, testdir, raw_iter):
356         self.testdir = testdir
357         totals = {}
358         for filename in glob.iglob(os.path.join(testdir, 'httperf_run*.txt')):
359             nrun = int(re.match('.*/httperf_run(\d+)_', filename).group(1))
360             result = self._process_run(nrun)
361             totals[nrun] = result
362
363         fields = 'run connect_rate request_rate reply_rate bandwidth errors'.split()
364         final = RowResults(fields)
365
366         for run in sorted(totals.keys()):
367             total = totals[run]
368             errsum = sum([getattr(total, f) for f in total._err_fields])
369             final.add_row([run, total.connect_rate, total.request_rate,
370                            total.reply_rate, total.bandwidth, errsum])
371             # XXX: often the last run will have errors in it, due to the control algorithm
372             #if errsum:
373             #    final.mark_failed()
374
375         # If we saw a severe failure (assertion failure, kernel panic, or user
376         # level panic) in the webserver, fail the test
377         if not super(HTTPerfTest, self).passed():
378             final.mark_failed('\n'.join(self.server_failures))
379
380         return final
381
382
383 class HTTPerfResults(ResultsBase):
384     _err_fields = 'fd_unavail addrunavail ftab_full other_err'.split()
385     _result_fields = ('client_timo socket_timo connrefused connreset'
386                       ' connect_rate request_rate bandwidth reply_rate').split()
387     _fields = _err_fields + _result_fields
388
389     def __init__(self):
390         super(HTTPerfResults, self).__init__()
391         for f in self._fields:
392             setattr(self, f, 0)
393
394     def __add__(self, other):
395         ret = HTTPerfResults()
396         for f in self._fields:
397             setattr(ret, f, getattr(self, f) + getattr(other, f))
398         return ret
399
400     def passed(self):
401         return all([getattr(self, field) == 0 for field in self._err_fields])
402
403     def to_file(self, fh):
404         errs = [(f, getattr(self,f)) for f in self._err_fields if getattr(self,f)]
405         if errs:
406             fh.write('Failed run: ' + ' '.join(['%s %d' % e for e in errs]))
407
408         fh.write('Request rate:\t%f\n' % self.request_rate)
409         fh.write('Bandwidth:\t%f\n' % self.bandwidth)
410         fh.write('Reply rate:\t%f\n' % self.reply_rate)
411
412
413 class HTTPerfClient(object):
414     def __init__(self, logfile, user, host, target, nconns, rate):
415         self.user = user
416         self.host = host
417         self.httperf_path = siteconfig.get('HTTPERF_PATH')
418         cmd = '%s %s' % (self.httperf_path, HTTPERF_BASE_ARGS)
419         cmd += ' --num-conns %d --rate %d --server %s --uri %s' % (
420                         nconns, rate, target, HTTPERF_URI)
421         self.proc = self._launchssh(cmd, stdout=subprocess.PIPE, bufsize=0)
422         self.logfile = logfile
423
424     def _launchssh(self, remotecmd, **kwargs):
425         ssh_dest = '%s@%s' % (self.user, self.host)
426         cmd = ['ssh'] + siteconfig.get('SSH_ARGS').split() + [ssh_dest, remotecmd]
427         return subprocess.Popen(cmd, **kwargs)
428
429     # mirror builtin file method so that we can pass this to select()
430     def fileno(self):
431         return self.proc.stdout.fileno()
432
433     def read(self):
434         # read only a single character to avoid blocking!
435         s = self.proc.stdout.read(1)
436         if s == '':
437             raise EOFError
438         self.logfile.write(s)
439
440     def cleanup(self):
441         """perform cleanup if necessary"""
442         self.logfile.close()
443         if self.proc is None or self.proc.poll() == 0:
444             return # clean exit
445
446         if self.proc.returncode:
447             debug.warning('httperf: SSH to %s exited with error %d'
448                           % (self.host, self.proc.returncode))
449         else: # kill SSH if still up
450             debug.warning('httperf: killing SSH child for %s' % self.host)
451             self.proc.terminate()
452             self.proc.wait()
453
454         # run a remote killall to get rid of any errant httperfs
455         debug.verbose('killing any errant httperfs on %s' % self.host)
456         p = self._launchssh('killall -q %s' % self.httperf_path)
457         retcode = p.wait()
458         if retcode != 0:
459             debug.warning('failed to killall httperf on %s!' % self.host)