1#!/usr/bin/env python3

2

3 import decimal

4 import os

5 import re

6 import sys

7 import time

8 import argparse

9 import logging

10

11 from subprocess import check_output, check_call, CalledProcessError

12

13

14 class CPUScalingTest(object):

15

16 def __init__(self):

17 self.speedUpTolerance = 10.0 # percent

18 self.retryLimit = 5

19 self.retryTolerance = 5.0 # percent

20 self.sysCPUDirectory = "/sys/devices/system/cpu"

21 self.cpufreqDirectory = os.path.join(

22 self.sysCPUDirectory, "cpu0", "cpufreq"

23 )

24 self.idaFlag = "ida"

25 self.idaSpeedupFactor = 8.0 # percent

26 self.selectorExe = "cpufreq-selector"

27 self.ifSelectorExe = None

28 self.minFreq = None

29 self.maxFreq = None

30

31 def getCPUFreqDirectories(self):

32 logging.debug("Getting CPU Frequency Directories")

33 if not os.path.exists(self.sysCPUDirectory):

34 logging.error("No file %s" % self.sysCPUDirectory)

35 return None

36 # look for cpu subdirectories

37 pattern = re.compile(r"cpu(?P<cpuNumber>[0-9]+)")

38 self.cpufreqDirectories = list()

39 for subdirectory in os.listdir(self.sysCPUDirectory):

40 match = pattern.search(subdirectory)

41 if match and match.group("cpuNumber"):

42 cpufreqDirectory = os.path.join(

43 self.sysCPUDirectory, subdirectory, "cpufreq"

44 )

45 if not os.path.exists(cpufreqDirectory):

46 logging.error(

47 "CPU %s has no cpufreq directory %s"

48 % (match.group("cpuNumber"), cpufreqDirectory)

49 )

50 return None

51 # otherwise

52 self.cpufreqDirectories.append(cpufreqDirectory)

53 if len(self.cpufreqDirectories) == 0:

54 return None

55 # otherwise

56 logging.debug("Located the following CPU Freq Directories:")

57 for line in self.cpufreqDirectories:

58 logging.debug(" %s" % line)

59 return self.cpufreqDirectories

60

61 def checkParameters(self, file):

62 logging.debug("Checking Parameters for %s" % file)

63 current = None

64 for cpufreqDirectory in self.cpufreqDirectories:

65 parameters = self.getParameters(cpufreqDirectory, file)

66 if not parameters:

67 logging.error(

68 "Error: could not determine cpu parameters from %s"

69 % os.path.join(cpufreqDirectory, file)

70 )

71 return None

72 if not current:

73 current = parameters

74 elif not current == parameters:

75 return None

76 return current

77

78 def getParameters(self, cpufreqDirectory, file):

79 logging.debug("Getting Parameters for %s" % file)

80 path = os.path.join(cpufreqDirectory, file)

81 file = open(path)

82 while 1:

83 line = file.readline()

84 if not line:

85 break

86 if len(line.strip()) > 0:

87 return line.strip().split()

88 return None

89

90 def setParameter(

91 self, setFile, readFile, value, skip=False, automatch=False

92 ):

93 def findParameter(targetFile):

94 logging.debug("Finding parameters for %s" % targetFile)

95 for root, _, files in os.walk(self.sysCPUDirectory):

96 for f in files:

97 rf = os.path.join(root, f)

98 if targetFile in rf:

99 return rf

100 return None

101

102 logging.debug("Setting %s to %s" % (setFile, value))

103 path = None

104 if not skip:

105 if automatch:

106 path = findParameter(setFile)

107 else:

108 path = os.path.join(self.cpufreqDirectory, setFile)

109

110 try:

111 check_call('echo "%s" > %s' % (value, path), shell=True)

112 except CalledProcessError as exception:

113 logging.exception("Command failed:")

114 logging.exception(exception)

115 return False

116

117 # verify it has changed

118 if automatch:

119 path = findParameter(readFile)

120 else:

121 path = os.path.join(self.cpufreqDirectory, readFile)

122

123 parameterFile = open(path)

124 line = parameterFile.readline()

125 if not line or line.strip() != str(value):

126 logging.error(

127 "Error: could not verify that %s was set to %s" % (path, value)

128 )

129 if line:

130 logging.error("Actual Value: %s" % line)

131 else:

132 logging.error("parameter file was empty")

133 return False

134

135 return True

136

137 def checkSelectorExecutable(self):

138 logging.debug("Determining if %s is executable" % self.selectorExe)

139

140 def is_exe(fpath):

141 return os.path.exists(fpath) and os.access(fpath, os.X_OK)

142

143 if self.ifSelectorExe is None:

144 # cpufreq-selector default path

145 exe = os.path.join("/usr/bin/", self.selectorExe)

146 if is_exe(exe):

147 self.ifSelectorExe = True

148 return True

149 for path in os.environ["PATH"].split(os.pathsep):

150 exe = os.path.join(path, self.selectorExe)

151 if is_exe(exe):

152 self.ifSelectorExe = True

153 return True

154

155 self.ifSelectorExe = False

156 return False

157

158 def setParameterWithSelector(self, switch, setFile, readFile, value):

159 logging.debug("Setting %s with %s to %s" % (setFile, switch, value))

160 # Try the command for all CPUs

161 skip = True

162 if self.checkSelectorExecutable():

163 try:

164 check_call(

165 "cpufreq-selector -%s %s" % (switch, value), shell=True

166 )

167 except CalledProcessError as exception:

168 logging.exception("Note: command failed: %s" % exception.cmd)

169 skip = False

170 else:

171 skip = False

172

173 return self.setParameter(setFile, readFile, value, skip)

174

175 def setFrequency(self, frequency):

176 logging.debug("Setting Frequency to %s" % frequency)

177 return self.setParameterWithSelector(

178 "f", "scaling_setspeed", "scaling_cur_freq", frequency

179 )

180

181 def setGovernor(self, governor):

182 logging.debug("Setting Governor to %s" % governor)

183 return self.setParameterWithSelector(

184 "g", "scaling_governor", "scaling_governor", governor

185 )

186

187 def getParameter(self, parameter):

188 value = None

189 logging.debug("Getting %s" % parameter)

190 parameterFilePath = os.path.join(self.cpufreqDirectory, parameter)

191 try:

192 parameterFile = open(parameterFilePath)

193 line = parameterFile.readline()

194 if not line:

195 logging.error(

196 "Error: failed to get %s for %s"

197 % (parameter, self.cpufreqDirectory)

198 )

199 return None

200 value = line.strip()

201 return value

202 except IOError as exception:

203 logging.exception("Error: could not open %s" % parameterFilePath)

204 logging.exception(exception)

205

206 return None

207

208 def getParameterList(self, parameter):

209 logging.debug("Getting parameter list")

210 values = list()

211 for cpufreqDirectory in self.cpufreqDirectories:

212 path = os.path.join(cpufreqDirectory, parameter)

213 parameterFile = open(path)

214 line = parameterFile.readline()

215 if not line:

216 logging.error(

217 "Error: failed to get %s for %s"

218 % (parameter, cpufreqDirectory)

219 )

220 return None

221 values.append(line.strip())

222 logging.debug("Found parameters:")

223 for line in values:

224 logging.debug(" %s" % line)

225 return values

226

227 def runLoadTest(self):

228 logging.info("Running CPU load test...")

229 try:

230 output = check_output("taskset -pc 0 %s" % os.getpid(), shell=True)

231 for line in output.decode().splitlines():

232 logging.info(line)

233 except CalledProcessError as exception:

234 logging.exception("Could not set task affinity")

235 logging.exception(exception)

236 return None

237

238 runTime = None

239 tries = 0

240 while tries < self.retryLimit:

241 sys.stdout.flush()

242 (

243 start_utime,

244 start_stime,

245 start_cutime,

246 start_cstime,

247 start_elapsed_time,

248 ) = os.times()

249 self.pi()

250 (

251 stop_utime,

252 stop_stime,

253 stop_cutime,

254 stop_cstime,

255 stop_elapsed_time,

256 ) = os.times()

257 if not runTime:

258 runTime = stop_elapsed_time - start_elapsed_time

259 else:

260 thisTime = stop_elapsed_time - start_elapsed_time

261 if (

262 abs(thisTime - runTime) / runTime

263 ) * 100 < self.retryTolerance:

264 return runTime

265 else:

266 runTime = thisTime

267 tries += 1

268

269 logging.error(

270 "Could not repeat load test times within %.1f%%"

271 % self.retryTolerance

272 )

273 return None

274

275 def pi(self):

276 decimal.getcontext().prec = 500

277 s = decimal.Decimal(1)

278 h = decimal.Decimal(3).sqrt() / 2

279 n = 6

280 for i in range(170):

281 s2 = (1 - h) ** 2 + s**2 / 4

282 s = s2.sqrt()

283 h = (1 - s2 / 4).sqrt()

284 n = 2 * n

285

286 return True

287

288 def verifyMinimumFrequency(self, waitTime=5):

289 logging.debug("Verifying minimum frequency")

290 logging.info("Waiting %d seconds..." % waitTime)

291 time.sleep(waitTime)

292 logging.info("Done.")

293 minimumFrequency = self.getParameter("scaling_min_freq")

294 currentFrequency = self.getParameter("scaling_cur_freq")

295 if (

296 not minimumFrequency

297 or not currentFrequency

298 or (minimumFrequency != currentFrequency)

299 ):

300 return False

301

302 # otherwise

303 return True

304

305 def getSystemCapabilities(self):

306 logging.info("System Capabilites:")

307 logging.info("-------------------------------------------------")

308

309 # Do the CPUs support scaling?

310 if not self.getCPUFreqDirectories():

311 return False

312 if len(self.cpufreqDirectories) > 1:

313 logging.info("System has %u cpus" % len(self.cpufreqDirectories))

314

315 # Ensure all CPUs support the same frequencies

316 freqFileName = "scaling_min_freq"

317 self.minFreq = int(self.checkParameters(freqFileName)[0])

318 if not self.minFreq:

319 return False

320 freqFileName = "scaling_max_freq"

321 self.maxFreq = int(self.checkParameters(freqFileName)[0])

322 if not self.maxFreq:

323 return False

324 logging.info(

325 "Supported CPU Frequencies: %s - %s MHz",

326 self.minFreq / 1000,

327 self.maxFreq / 1000,

328 )

329 # Check governors to verify all CPUs support the same control methods

330 governorFileName = "scaling_available_governors"

331 self.governors = self.checkParameters(governorFileName)

332 if not self.governors:

333 return False

334

335 logging.info("Supported Governors: ")

336 for governor in self.governors:

337 logging.info(" %s" % governor)

338

339 self.originalGovernors = self.getParameterList("scaling_governor")

340 if self.originalGovernors:

341 logging.info("Current governors:")

342 i = 0

343 for g in self.originalGovernors:

344 logging.info(" cpu%u: %s" % (i, g))

345 i += 1

346 else:

347 logging.error(

348 "Error: could not determine current governor settings"

349 )

350 return False

351

352 self.getCPUFlags()

353

354 return True

355

356 def getCPUFlags(self):

357 logging.debug("Getting CPU flags")

358 self.cpuFlags = None

359 try:

360 cpuinfo_file = open("/proc/cpuinfo", "r")

361 cpuinfo = cpuinfo_file.read().split("\n")

362 cpuinfo_file.close()

363

364 for line in cpuinfo:

365 if line.startswith("flags"):

366 pre, post = line.split(":")

367 self.cpuFlags = post.strip().split()

368 break

369 logging.debug("Found the following CPU Flags:")

370 for line in self.cpuFlags:

371 logging.debug(" %s" % line)

372 except OSError:

373 logging.warning("Could not read CPU flags")

374

375 def runUserSpaceTests(self):

376 logging.info("Userspace Governor Test:")

377 logging.info("-------------------------------------------------")

378 self.minimumFrequencyTestTime = None

379 self.maximumFrequencyTestTime = None

380

381 success = True

382 differenceSpeedUp = None

383 governor = "userspace"

384 if governor not in self.governors:

385 logging.warning("Note: %s governor not supported" % governor)

386 else:

387

388 # Set the governor to "userspace" and verify

389 logging.info("Setting governor to %s" % governor)

390 if not self.setGovernor(governor):

391 success = False

392

393 # Set the CPU speed to its lowest value

394 frequency = self.minFreq

395 logging.info(

396 "Setting CPU frequency to %u MHz" % (int(frequency) / 1000)

397 )

398 if not self.setFrequency(frequency):

399 success = False

400

401 # Verify the speed is set to the lowest value

402 minimumFrequency = self.getParameter("scaling_min_freq")

403 currentFrequency = self.getParameter("scaling_cur_freq")

404 if (

405 not minimumFrequency

406 or not currentFrequency

407 or (minimumFrequency != currentFrequency)

408 ):

409 logging.error(

410 "Could not verify that cpu frequency is set to the minimum"

411 " value of %s" % minimumFrequency

412 )

413 success = False

414

415 # Run Load Test

416 self.minimumFrequencyTestTime = self.runLoadTest()

417 if not self.minimumFrequencyTestTime:

418 logging.error(

419 "Could not retrieve the minimum frequency test's"

420 " execution time."

421 )

422 success = False

423 else:

424 logging.info(

425 "Minimum frequency load test time: %.2f"

426 % self.minimumFrequencyTestTime

427 )

428

429 # Set the CPU speed to it's highest value as above.

430 frequency = self.maxFreq

431 logging.info(

432 "Setting CPU frequency to %u MHz" % (int(frequency) / 1000)

433 )

434 if not self.setFrequency(frequency):

435 success = False

436

437 maximumFrequency = self.getParameter("scaling_max_freq")

438 currentFrequency = self.getParameter("scaling_cur_freq")

439 if (

440 not maximumFrequency

441 or not currentFrequency

442 or (maximumFrequency != currentFrequency)

443 ):

444 logging.error(

445 "Could not verify that cpu frequency is set to the"

446 " maximum value of %s" % maximumFrequency

447 )

448 success = False

449

450 # Repeat workload test

451 self.maximumFrequencyTestTime = self.runLoadTest()

452 if not self.maximumFrequencyTestTime:

453 logging.error(

454 "Could not retrieve the maximum frequency test's "

455 "execution time."

456 )

457 success = False

458 else:

459 logging.info(

460 "Maximum frequency load test time: %.2f"

461 % self.maximumFrequencyTestTime

462 )

463

464 # Verify MHz increase is comparable to time % decrease

465 predictedSpeedup = float(maximumFrequency) / float(

466 minimumFrequency

467 )

468

469 # If "ida" turbo thing, increase the expectation by 8%

470 if self.cpuFlags and self.idaFlag in self.cpuFlags:

471 logging.info(

472 "Found %s flag, increasing expected speedup by %.1f%%"

473 % (self.idaFlag, self.idaSpeedupFactor)

474 )

475 predictedSpeedup = predictedSpeedup * (

476 1.0 / (1.0 - (self.idaSpeedupFactor / 100.0))

477 )

478

479 if self.minimumFrequencyTestTime and self.maximumFrequencyTestTime:

480 measuredSpeedup = (

481 self.minimumFrequencyTestTime

482 / self.maximumFrequencyTestTime

483 )

484 logging.info("CPU Frequency Speed Up: %.2f" % predictedSpeedup)

485 logging.info("Measured Speed Up: %.2f" % measuredSpeedup)

486 differenceSpeedUp = (

487 (measuredSpeedup - predictedSpeedup) / predictedSpeedup

488 ) * 100

489 logging.info(

490 "Percentage Difference %.1f%%" % differenceSpeedUp

491 )

492 if differenceSpeedUp > self.speedUpTolerance:

493 logging.error(

494 "Measured speedup vs expected speedup is %.1f%% "

495 "and is not within %.1f%% margin."

496 % (differenceSpeedUp, self.speedUpTolerance)

497 )

498 success = False

499 elif differenceSpeedUp < 0:

500 logging.info(

501 "Measured speed up %.2f exceeded expected speedup %.2f"

502 % (measuredSpeedup, predictedSpeedup)

503 )

504 else:

505 logging.error(

506 "Not enough timing data to calculate speed differences."

507 )

508

509 return success

510

511 def runOnDemandTests(self):

512 logging.info("On Demand Governor Test:")

513 logging.info("-------------------------------------------------")

514 differenceOnDemandVsMaximum = None

515 onDemandTestTime = None

516 governor = "ondemand"

517 success = True

518 if governor not in self.governors:

519 logging.warning("%s governor not supported" % governor)

520 else:

521 # Set the governor to "ondemand"

522 logging.info("Setting governor to %s" % governor)

523 if not self.setGovernor(governor):

524 success = False

525

526 # Wait a fixed period of time, then verify current speed

527 # is the slowest in as before

528 if not self.verifyMinimumFrequency():

529 logging.error(

530 "Could not verify that cpu frequency has settled to the "

531 "minimum value"

532 )

533 success = False

534

535 # Repeat workload test

536 onDemandTestTime = self.runLoadTest()

537 if not onDemandTestTime:

538 logging.warning("No On Demand load test time available.")

539 success = False

540 else:

541 logging.info(

542 "On Demand load test time: %.2f" % onDemandTestTime

543 )

544

545 if onDemandTestTime and self.maximumFrequencyTestTime:

546 # Compare the timing to the max results from earlier,

547 # again time should be within self.speedUpTolerance

548 differenceOnDemandVsMaximum = (

549 abs(onDemandTestTime - self.maximumFrequencyTestTime)

550 / self.maximumFrequencyTestTime

551 ) * 100

552 logging.info(

553 "Percentage Difference vs. maximum frequency: %.1f%%"

554 % differenceOnDemandVsMaximum

555 )

556 if differenceOnDemandVsMaximum > self.speedUpTolerance:

557 logging.error(

558 "On demand performance vs maximum of %.1f%% is not "

559 "within %.1f%% margin"

560 % (differenceOnDemandVsMaximum, self.speedUpTolerance)

561 )

562 success = False

563 else:

564 logging.error(

565 "Not enough timing data to calculate speed differences."

566 )

567

568 # Verify the current speed has returned to the lowest speed again

569 if not self.verifyMinimumFrequency():

570 logging.error(

571 "Could not verify that cpu frequency has settled to the "

572 "minimum value"

573 )

574 success = False

575

576 return success

577

578 def runPerformanceTests(self):

579 logging.info("Performance Governor Test:")

580 logging.info("-------------------------------------------------")

581 differencePerformanceVsMaximum = None

582 governor = "performance"

583 success = True

584 if governor not in self.governors:

585 logging.warning("%s governor not supported" % governor)

586 else:

587 # Set the governor to "performance"

588 logging.info("Setting governor to %s" % governor)

589 if not self.setGovernor(governor):

590 success = False

591

592 # let's run a warm-up task so the CPU can raise its freq

593 performanceTestTime = self.runLoadTest()

594 # Verify the current speed is close to scaling_max_freq

595 maximumFrequency = self.getParameter("scaling_max_freq")

596 currentFrequency = self.getParameter("scaling_cur_freq")

597 if (

598 not maximumFrequency

599 or not currentFrequency

600 or (float(currentFrequency) < 0.99 * float(maximumFrequency))

601 ):

602 logging.error(

603 "Current cpu frequency of %s is not close enough to the "

604 "maximum value of %s"

605 % (currentFrequency, maximumFrequency)

606 )

607 success = False

608

609 # Repeat work load test

610 performanceTestTime = self.runLoadTest()

611 if not performanceTestTime:

612 logging.error("No Performance load test time available.")

613 success = False

614 else:

615 logging.info(

616 "Performance load test time: %.2f" % performanceTestTime

617 )

618

619 if performanceTestTime and self.maximumFrequencyTestTime:

620 # Compare the timing to the max results

621 differencePerformanceVsMaximum = (

622 abs(performanceTestTime - self.maximumFrequencyTestTime)

623 / self.maximumFrequencyTestTime

624 ) * 100

625 logging.info(

626 "Percentage Difference vs. maximum frequency: %.1f%%"

627 % differencePerformanceVsMaximum

628 )

629 if differencePerformanceVsMaximum > self.speedUpTolerance:

630 logging.error(

631 "Performance setting vs maximum of %.1f%% is not "

632 "within %.1f%% margin"

633 % (

634 differencePerformanceVsMaximum,

635 self.speedUpTolerance,

636 )

637 )

638 success = False

639 else:

640 logging.error(

641 "Not enough timing data to calculate speed differences."

642 )

643

644 return success

645

646 def runConservativeTests(self):

647 logging.info("Conservative Governor Test:")

648 logging.info("-------------------------------------------------")

649 differenceConservativeVsMinimum = None

650 governor = "conservative"

651 success = True

652 if governor not in self.governors:

653 logging.warning("%s governor not supported" % governor)

654 else:

655 # Set the governor to "conservative"

656 logging.info("Setting governor to %s" % governor)

657 if not self.setGovernor(governor):

658 success = False

659

660 # Set the frequency step to 20,

661 # so that it jumps to minimum frequency

662 path = os.path.join("conservative", "freq_step")

663 if not self.setParameter(path, path, 20, automatch=True):

664 success = False

665

666 # Wait a fixed period of time,

667 # then verify current speed is the slowest in as before

668 if not self.verifyMinimumFrequency(10):

669 logging.error(

670 "Could not verify that cpu frequency has settled "

671 "to the minimum value"

672 )

673 success = False

674

675 # Set the frequency step to 0,

676 # so that it doesn't gradually increase

677 if not self.setParameter(path, path, 0, automatch=True):

678 success = False

679

680 # Repeat work load test

681 conservativeTestTime = self.runLoadTest()

682 if not conservativeTestTime:

683 logging.error("No Conservative load test time available.")

684 success = False

685 else:

686 logging.info(

687 "Conservative load test time: %.2f" % conservativeTestTime

688 )

689

690 if conservativeTestTime and self.minimumFrequencyTestTime:

691 # Compare the timing to the max results

692 differenceConservativeVsMinimum = (

693 abs(conservativeTestTime - self.minimumFrequencyTestTime)

694 / self.minimumFrequencyTestTime

695 ) * 100

696 logging.info(

697 "Percentage Difference vs. minimum frequency: %.1f%%"

698 % differenceConservativeVsMinimum

699 )

700 if differenceConservativeVsMinimum > self.speedUpTolerance:

701 logging.error(

702 "Performance setting vs minimum of %.1f%% is not "

703 "within %.1f%% margin"

704 % (

705 differenceConservativeVsMinimum,

706 self.speedUpTolerance,

707 )

708 )

709 success = False

710 else:

711 logging.error(

712 "Not enough timing data to calculate speed differences."

713 )

714

715 return success

716

717 def restoreGovernors(self):

718 logging.info(

719 "Restoring original governor to %s" % (self.originalGovernors[0])

720 )

721 self.setGovernor(self.originalGovernors[0])

722

723

724 def main():

725 parser = argparse.ArgumentParser()

726 parser.add_argument(

727 "-q", "--quiet", action="store_true", help="Suppress output."

728 )

729 parser.add_argument(

730 "-c",

731 "--capabilities",

732 action="store_true",

733 help="Only output CPU capabilities.",

734 )

735 parser.add_argument(

736 "-d",

737 "--debug",

738 action="store_true",

739 help="Turn on debug level output for extra info during test run.",

740 )

741 args = parser.parse_args()

742

743 # Set up the logging system (unless we don't want ANY logging)

744 if not args.quiet or args.debug:

745 logger = logging.getLogger()

746 logger.setLevel(logging.DEBUG)

747 format = "%(asctime)s %(levelname)-8s %(message)s"

748 date_format = "%Y-%m-%d %H:%M:%S"

749

750 # If we DO want console output

751 if not args.quiet:

752 console_handler = logging.StreamHandler()

753 console_handler.setFormatter(logging.Formatter(format, date_format))

754 console_handler.setLevel(logging.INFO)

755 logger.addHandler(console_handler)

756

757 # If we ALSO want to create a file for future reference

758 if args.debug:

759 console_handler.setLevel(logging.DEBUG)

760

761 test = CPUScalingTest()

762 if not os.path.exists(test.cpufreqDirectory):

763 logging.info("CPU Frequency Scaling not supported")

764 return 0

765

766 if not test.getSystemCapabilities():

767 logging.error("Failed to get system capabilities")

768 return 1

769

770 returnValues = []

771 if not args.capabilities:

772 logging.info("Beginning Frequency Governors Testing")

773 returnValues.append(test.runUserSpaceTests())

774 returnValues.append(test.runOnDemandTests())

775 returnValues.append(test.runPerformanceTests())

776 returnValues.append(test.runConservativeTests())

777 test.restoreGovernors()

778

779 return 1 if False in returnValues else 0

780

781

782 if __name__ == "__main__":

783 sys.exit(main())