blob: 77d7a7545e3f09deed1b521fe374eed664ea9825 [file] [log] [blame]
koder aka kdanilovbc2c8982015-06-13 02:50:43 +03001import os.path
2import logging
koder aka kdanilova732a602017-02-01 20:29:56 +02003from typing import cast, Any, List, Union
4
5import numpy
koder aka kdanilovbc2c8982015-06-13 02:50:43 +03006
koder aka kdanilov6ab4d432015-06-22 00:26:28 +03007import wally
koder aka kdanilov108ac362017-01-19 20:17:16 +02008from ...utils import StopTestError, ssize2b, b2ssize
koder aka kdanilov70227062016-11-26 23:23:21 +02009from ...node_interfaces import IRPCNode
koder aka kdanilov108ac362017-01-19 20:17:16 +020010from ...node_utils import get_os
koder aka kdanilovf2865172016-12-30 03:35:11 +020011from ..itest import ThreadedTest
koder aka kdanilovf90de852017-01-20 18:12:27 +020012from ...result_classes import TimeSeries, DataSource
13from ..job import JobConfig
koder aka kdanilovf2865172016-12-30 03:35:11 +020014from .fio_task_parser import execution_time, fio_cfg_compile, FioJobConfig, FioParams, get_log_files
koder aka kdanilovbbbe1dc2016-12-20 01:19:56 +020015from . import rpc_plugin
koder aka kdanilov23e6bdf2016-12-24 02:18:54 +020016from .fio_hist import expected_lat_bins
koder aka kdanilov7f59d562016-12-26 01:34:23 +020017
koder aka kdanilovbc2c8982015-06-13 02:50:43 +030018
19logger = logging.getLogger("wally")
20
21
koder aka kdanilov108ac362017-01-19 20:17:16 +020022class FioTest(ThreadedTest):
koder aka kdanilovbc2c8982015-06-13 02:50:43 +030023 soft_runcycle = 5 * 60
Michael Semenov8ba6e232015-08-28 10:57:18 +000024 retry_time = 30
koder aka kdanilov70227062016-11-26 23:23:21 +020025 configs_dir = os.path.dirname(__file__) # type: str
koder aka kdanilov7f59d562016-12-26 01:34:23 +020026 name = 'fio'
koder aka kdanilovf2865172016-12-30 03:35:11 +020027 job_config_cls = FioJobConfig
koder aka kdanilovbc2c8982015-06-13 02:50:43 +030028
koder aka kdanilov70227062016-11-26 23:23:21 +020029 def __init__(self, *args, **kwargs) -> None:
30 super().__init__(*args, **kwargs)
koder aka kdanilovbc2c8982015-06-13 02:50:43 +030031
koder aka kdanilov108ac362017-01-19 20:17:16 +020032 get = self.suite.params.get
koder aka kdanilovbc2c8982015-06-13 02:50:43 +030033
koder aka kdanilovbbbe1dc2016-12-20 01:19:56 +020034 self.remote_task_file = self.join_remote("task.fio")
35 self.remote_output_file = self.join_remote("fio_result.json")
36 self.use_system_fio = get('use_system_fio', False) # type: bool
37 self.use_sudo = get("use_sudo", True) # type: bool
38 self.force_prefill = get('force_prefill', False) # type: bool
koder aka kdanilova732a602017-02-01 20:29:56 +020039 self.skip_prefill = get('skip_prefill', False) # type: bool
koder aka kdanilov108ac362017-01-19 20:17:16 +020040 self.load_profile_name = self.suite.params['load'] # type: str
koder aka kdanilovbc2c8982015-06-13 02:50:43 +030041
koder aka kdanilov70227062016-11-26 23:23:21 +020042 if os.path.isfile(self.load_profile_name):
koder aka kdanilovbbbe1dc2016-12-20 01:19:56 +020043 self.load_profile_path = self.load_profile_name # type: str
koder aka kdanilov6ab4d432015-06-22 00:26:28 +030044 else:
koder aka kdanilovbbbe1dc2016-12-20 01:19:56 +020045 self.load_profile_path = os.path.join(self.configs_dir, self.load_profile_name+ '.cfg')
koder aka kdanilovbc2c8982015-06-13 02:50:43 +030046
koder aka kdanilov70227062016-11-26 23:23:21 +020047 self.load_profile = open(self.load_profile_path, 'rt').read() # type: str
koder aka kdanilovbc2c8982015-06-13 02:50:43 +030048
koder aka kdanilovbc2c8982015-06-13 02:50:43 +030049 if self.use_system_fio:
koder aka kdanilov70227062016-11-26 23:23:21 +020050 self.fio_path = "fio" # type: str
koder aka kdanilovbc2c8982015-06-13 02:50:43 +030051 else:
koder aka kdanilov108ac362017-01-19 20:17:16 +020052 self.fio_path = os.path.join(self.suite.remote_dir, "fio")
koder aka kdanilovbc2c8982015-06-13 02:50:43 +030053
koder aka kdanilov108ac362017-01-19 20:17:16 +020054 self.load_params = self.suite.params['params']
koder aka kdanilovbbbe1dc2016-12-20 01:19:56 +020055 self.file_name = self.load_params['FILENAME']
koder aka kdanilovbc2c8982015-06-13 02:50:43 +030056
koder aka kdanilovbbbe1dc2016-12-20 01:19:56 +020057 if 'FILESIZE' not in self.load_params:
58 logger.debug("Getting test file sizes on all nodes")
59 try:
koder aka kdanilov108ac362017-01-19 20:17:16 +020060 sizes = {node.conn.fs.file_stat(self.file_name)[b'size']
61 for node in self.suite.nodes}
koder aka kdanilovbbbe1dc2016-12-20 01:19:56 +020062 except Exception:
63 logger.exception("FILESIZE is not set in config file and fail to detect it." +
64 "Set FILESIZE or fix error and rerun test")
65 raise StopTestError()
koder aka kdanilova94dfe12015-08-19 13:04:51 +030066
koder aka kdanilovbbbe1dc2016-12-20 01:19:56 +020067 if len(sizes) != 1:
68 logger.error("IO target file %r has different sizes on test nodes - %r",
69 self.file_name, sizes)
70 raise StopTestError()
koder aka kdanilova94dfe12015-08-19 13:04:51 +030071
koder aka kdanilovbbbe1dc2016-12-20 01:19:56 +020072 self.file_size = list(sizes)[0]
koder aka kdanilov108ac362017-01-19 20:17:16 +020073 logger.info("Detected test file size is %sB", b2ssize(self.file_size))
koder aka kdanilova732a602017-02-01 20:29:56 +020074 if self.file_size % (4 * 1024 ** 2) != 0:
75 tail = self.file_size % (4 * 1024 ** 2)
76 logger.warning("File size is not proportional to 4M, %sb at the end will not be used for test",
77 str(tail // 1024) + "Kb" if tail > 1024 else str(tail) + "b")
78 self.file_size -= self.file_size % (4 * 1024 ** 2)
koder aka kdanilovbbbe1dc2016-12-20 01:19:56 +020079 self.load_params['FILESIZE'] = self.file_size
80 else:
81 self.file_size = ssize2b(self.load_params['FILESIZE'])
koder aka kdanilov70227062016-11-26 23:23:21 +020082
koder aka kdanilovf2865172016-12-30 03:35:11 +020083 self.job_configs = list(fio_cfg_compile(self.load_profile, self.load_profile_path,
koder aka kdanilovbbbe1dc2016-12-20 01:19:56 +020084 cast(FioParams, self.load_params)))
koder aka kdanilov70227062016-11-26 23:23:21 +020085
koder aka kdanilovf2865172016-12-30 03:35:11 +020086 if len(self.job_configs) == 0:
koder aka kdanilovbbbe1dc2016-12-20 01:19:56 +020087 logger.error("Empty fio config provided")
88 raise StopTestError()
koder aka kdanilov70227062016-11-26 23:23:21 +020089
koder aka kdanilov108ac362017-01-19 20:17:16 +020090 self.exec_folder = self.suite.remote_dir
koder aka kdanilovbc2c8982015-06-13 02:50:43 +030091
koder aka kdanilov70227062016-11-26 23:23:21 +020092 def config_node(self, node: IRPCNode) -> None:
koder aka kdanilov23e6bdf2016-12-24 02:18:54 +020093 plugin_code = open(rpc_plugin.__file__.rsplit(".", 1)[0] + ".py", "rb").read() # type: bytes
94 node.upload_plugin("fio", plugin_code)
koder aka kdanilovbbbe1dc2016-12-20 01:19:56 +020095
koder aka kdanilovbc2c8982015-06-13 02:50:43 +030096 try:
koder aka kdanilov108ac362017-01-19 20:17:16 +020097 node.conn.fs.rmtree(self.suite.remote_dir)
koder aka kdanilovbbbe1dc2016-12-20 01:19:56 +020098 except Exception:
99 pass
100
101 try:
koder aka kdanilov108ac362017-01-19 20:17:16 +0200102 node.conn.fs.makedirs(self.suite.remote_dir)
koder aka kdanilovbbbe1dc2016-12-20 01:19:56 +0200103 except Exception:
koder aka kdanilov108ac362017-01-19 20:17:16 +0200104 msg = "Failed to recreate folder {} on remote {}.".format(self.suite.remote_dir, node)
koder aka kdanilov3b4da8b2016-10-17 00:17:53 +0300105 logger.exception(msg)
koder aka kdanilovbbbe1dc2016-12-20 01:19:56 +0200106 raise StopTestError()
koder aka kdanilovbc2c8982015-06-13 02:50:43 +0300107
koder aka kdanilov108ac362017-01-19 20:17:16 +0200108 # TODO: check this during config validation
109 if self.file_size % (4 * (1024 ** 2)) != 0:
110 logger.error("Test file size must be proportional to 4MiB")
111 raise StopTestError()
112
koder aka kdanilov3b4da8b2016-10-17 00:17:53 +0300113 self.install_utils(node)
koder aka kdanilovbbbe1dc2016-12-20 01:19:56 +0200114
koder aka kdanilova732a602017-02-01 20:29:56 +0200115 if self.skip_prefill:
116 logger.info("Prefill is skipped due to 'skip_prefill' set to true")
117 else:
118 mb = int(self.file_size / 1024 ** 2)
119 logger.info("Filling test file %s on node %s with %sMiB of random data", self.file_name, node.info, mb)
120 is_prefilled, fill_bw = node.conn.fio.fill_file(self.file_name, mb,
121 force=self.force_prefill,
122 fio_path=self.fio_path)
123 if not is_prefilled:
124 logger.info("Test file on node %s is already prefilled", node.info)
125 elif fill_bw is not None:
126 logger.info("Initial fio fill bw is %s MiBps for %s", fill_bw, node.info)
koder aka kdanilovbbbe1dc2016-12-20 01:19:56 +0200127
koder aka kdanilov70227062016-11-26 23:23:21 +0200128 def install_utils(self, node: IRPCNode) -> None:
koder aka kdanilovbbbe1dc2016-12-20 01:19:56 +0200129 os_info = get_os(node)
koder aka kdanilov6ab4d432015-06-22 00:26:28 +0300130 if self.use_system_fio:
koder aka kdanilovbbbe1dc2016-12-20 01:19:56 +0200131 if os_info.distro != 'ubuntu':
132 logger.error("Only ubuntu supported on test VM")
133 raise StopTestError()
134 node.conn.fio.install('fio', binary='fio')
135 else:
136 node.conn.fio.install('bzip2', binary='bzip2')
koder aka kdanilov70227062016-11-26 23:23:21 +0200137 fio_dir = os.path.dirname(os.path.dirname(wally.__file__)) # type: str
138 fio_dir = os.path.join(os.getcwd(), fio_dir)
139 fio_dir = os.path.join(fio_dir, 'fio_binaries')
140 fname = 'fio_{0.release}_{0.arch}.bz2'.format(os_info)
141 fio_path = os.path.join(fio_dir, fname) # type: str
142
143 if not os.path.exists(fio_path):
koder aka kdanilovbbbe1dc2016-12-20 01:19:56 +0200144 logger.error("No prebuild fio binary available for {0}".format(os_info))
145 raise StopTestError()
koder aka kdanilov70227062016-11-26 23:23:21 +0200146
147 bz_dest = self.join_remote('fio.bz2') # type: str
koder aka kdanilov108ac362017-01-19 20:17:16 +0200148 node.copy_file(fio_path, bz_dest, compress=False)
koder aka kdanilovbbbe1dc2016-12-20 01:19:56 +0200149 node.run("bzip2 --decompress {} ; chmod a+x {}".format(bz_dest, self.join_remote("fio")))
koder aka kdanilov70227062016-11-26 23:23:21 +0200150
koder aka kdanilovf90de852017-01-20 18:12:27 +0200151 def get_expected_runtime(self, job_config: JobConfig) -> int:
koder aka kdanilovf2865172016-12-30 03:35:11 +0200152 return execution_time(cast(FioJobConfig, job_config))
koder aka kdanilov70227062016-11-26 23:23:21 +0200153
koder aka kdanilovf90de852017-01-20 18:12:27 +0200154 def prepare_iteration(self, node: IRPCNode, job: JobConfig) -> None:
koder aka kdanilov108ac362017-01-19 20:17:16 +0200155 node.put_to_file(self.remote_task_file, str(job).encode("utf8"))
koder aka kdanilov23e6bdf2016-12-24 02:18:54 +0200156
157 # TODO: get a link to substorage as a parameter
koder aka kdanilovf90de852017-01-20 18:12:27 +0200158 def run_iteration(self, node: IRPCNode, job: JobConfig) -> List[TimeSeries]:
koder aka kdanilov108ac362017-01-19 20:17:16 +0200159 exec_time = execution_time(cast(FioJobConfig, job))
160
koder aka kdanilov23e6bdf2016-12-24 02:18:54 +0200161
koder aka kdanilovbbbe1dc2016-12-20 01:19:56 +0200162 fio_cmd_templ = "cd {exec_folder}; " + \
163 "{fio_path} --output-format=json --output={out_file} --alloc-size=262144 {job_file}"
164
koder aka kdanilovbbbe1dc2016-12-20 01:19:56 +0200165 cmd = fio_cmd_templ.format(exec_folder=self.exec_folder,
166 fio_path=self.fio_path,
167 out_file=self.remote_output_file,
168 job_file=self.remote_task_file)
koder aka kdanilov23e6bdf2016-12-24 02:18:54 +0200169 must_be_empty = node.run(cmd, timeout=exec_time + max(300, exec_time), check_timeout=1).strip()
koder aka kdanilovbbbe1dc2016-12-20 01:19:56 +0200170
koder aka kdanilov23e6bdf2016-12-24 02:18:54 +0200171 if must_be_empty:
172 logger.error("Unexpected fio output: %r", must_be_empty)
koder aka kdanilovbc2c8982015-06-13 02:50:43 +0300173
koder aka kdanilovf2865172016-12-30 03:35:11 +0200174 # put fio output into storage
175 fio_out = node.get_file_content(self.remote_output_file)
koder aka kdanilov108ac362017-01-19 20:17:16 +0200176
177 path = DataSource(suite_id=self.suite.storage_id,
178 job_id=job.storage_id,
179 node_id=node.node_id,
koder aka kdanilova732a602017-02-01 20:29:56 +0200180 sensor='fio',
181 dev=None,
182 metric='stdout',
koder aka kdanilov108ac362017-01-19 20:17:16 +0200183 tag='json')
koder aka kdanilov108ac362017-01-19 20:17:16 +0200184 self.storage.put_extra(fio_out, path)
koder aka kdanilov23e6bdf2016-12-24 02:18:54 +0200185 node.conn.fs.unlink(self.remote_output_file)
186
187 files = [name for name in node.conn.fs.listdir(self.exec_folder)]
koder aka kdanilov108ac362017-01-19 20:17:16 +0200188 result = []
koder aka kdanilova732a602017-02-01 20:29:56 +0200189 for name, file_path, units in get_log_files(cast(FioJobConfig, job)):
koder aka kdanilov108ac362017-01-19 20:17:16 +0200190 log_files = [fname for fname in files if fname.startswith(file_path)]
koder aka kdanilov23e6bdf2016-12-24 02:18:54 +0200191 if len(log_files) != 1:
192 logger.error("Found %s files, match log pattern %s(%s) - %s",
koder aka kdanilov108ac362017-01-19 20:17:16 +0200193 len(log_files), file_path, name, ",".join(log_files[10:]))
koder aka kdanilov23e6bdf2016-12-24 02:18:54 +0200194 raise StopTestError()
195
196 fname = os.path.join(self.exec_folder, log_files[0])
197 raw_result = node.get_file_content(fname) # type: bytes
koder aka kdanilov23e6bdf2016-12-24 02:18:54 +0200198 node.conn.fs.unlink(fname)
199
200 try:
201 log_data = raw_result.decode("utf8").split("\n")
202 except UnicodeEncodeError:
203 logger.exception("Error during parse %s fio log file - can't decode usint UTF8", name)
204 raise StopTestError()
205
koder aka kdanilova732a602017-02-01 20:29:56 +0200206 # TODO: fix units, need to get array type from stream
207
208 parsed = [] # type: List[Union[List[int], int]]
209 times = []
koder aka kdanilov23e6bdf2016-12-24 02:18:54 +0200210
koder aka kdanilov23e6bdf2016-12-24 02:18:54 +0200211 for idx, line in enumerate(log_data):
212 line = line.strip()
213 if line:
214 try:
215 time_ms_s, val_s, _, *rest = line.split(",")
koder aka kdanilovf2865172016-12-30 03:35:11 +0200216 times.append(int(time_ms_s.strip()))
koder aka kdanilovffaf48d2016-12-27 02:25:29 +0200217
koder aka kdanilov23e6bdf2016-12-24 02:18:54 +0200218 if name == 'lat':
219 vals = [int(i.strip()) for i in rest]
220
221 if len(vals) != expected_lat_bins:
222 logger.error("Expect {} bins in latency histogram, but found {} at time {}"
223 .format(expected_lat_bins, len(vals), time_ms_s))
224 raise StopTestError()
225
koder aka kdanilova732a602017-02-01 20:29:56 +0200226 parsed.append(vals)
koder aka kdanilov23e6bdf2016-12-24 02:18:54 +0200227 else:
228 parsed.append(int(val_s.strip()))
229 except ValueError:
230 logger.exception("Error during parse %s fio log file in line %s: %r", name, idx, line)
231 raise StopTestError()
koder aka kdanilovffaf48d2016-12-27 02:25:29 +0200232
koder aka kdanilova732a602017-02-01 20:29:56 +0200233 if not self.suite.keep_raw_files:
234 raw_result = None
235
koder aka kdanilov108ac362017-01-19 20:17:16 +0200236 result.append(TimeSeries(name=name,
237 raw=raw_result,
koder aka kdanilova732a602017-02-01 20:29:56 +0200238 data=numpy.array(parsed, dtype='uint64'),
239 units=units,
240 times=numpy.array(times, dtype='uint64'),
241 time_units='ms',
242 source=path(metric=name, tag='csv')))
koder aka kdanilov108ac362017-01-19 20:17:16 +0200243 return result
koder aka kdanilov7f59d562016-12-26 01:34:23 +0200244
245 def format_for_console(self, data: Any) -> str:
246 raise NotImplementedError()