1 | // Copyright (C) 2022 The Qt Company Ltd. |
2 | // SPDX-License-Identifier: LicenseRef-Qt-Commercial OR LGPL-3.0-only OR GPL-2.0-only OR GPL-3.0-only |
3 | |
4 | #include <QtTest/private/qtestresult_p.h> |
5 | #include <QtTest/qtestassert.h> |
6 | #include <QtTest/private/qtestlog_p.h> |
7 | #include <QtTest/private/qplaintestlogger_p.h> |
8 | #include <QtTest/private/qbenchmark_p.h> |
9 | #include <QtTest/private/qbenchmarkmetric_p.h> |
10 | |
11 | #include <QtCore/private/qlogging_p.h> |
12 | |
13 | #include <array> |
14 | |
15 | #include <stdio.h> |
16 | #include <stdlib.h> |
17 | #include <string.h> |
18 | |
19 | #include <QtCore/QByteArray> |
20 | #include <QtCore/qmath.h> |
21 | #include <QtCore/QLibraryInfo> |
22 | |
23 | #ifdef Q_OS_ANDROID |
24 | # include <android/log.h> |
25 | #endif |
26 | |
27 | #ifdef Q_OS_WIN |
28 | # include <qt_windows.h> |
29 | #endif |
30 | |
31 | QT_BEGIN_NAMESPACE |
32 | |
33 | using namespace Qt::StringLiterals; |
34 | |
35 | namespace { |
36 | static const char multiplePrefixes[] = "\0kMGTPE" ; // kilo, mega, giga, tera, peta, exa |
37 | static const char submultiplePrefixes[] = "afpnum" ; // atto, femto, pico, nano, micro, milli |
38 | |
39 | template <int N> struct FixedBufString |
40 | { |
41 | static constexpr size_t MaxSize = N; |
42 | size_t used = 0; |
43 | std::array<char, N + 2> buf; // for the newline and terminating null |
44 | FixedBufString() |
45 | { |
46 | clear(); |
47 | } |
48 | void clear() |
49 | { |
50 | used = 0; |
51 | buf[0] = '\0'; |
52 | } |
53 | |
54 | operator const char *() const |
55 | { |
56 | return buf.data(); |
57 | } |
58 | |
59 | void append(const char *text) |
60 | { |
61 | size_t len = qMin(a: strlen(s: text), b: MaxSize - used); |
62 | memcpy(buf.data() + used, text, len); |
63 | used += len; |
64 | buf[used] = '\0'; |
65 | } |
66 | |
67 | template <typename... Args> void appendf(const char *format, Args &&... args) |
68 | { |
69 | // vsnprintf includes the terminating null |
70 | used += qsnprintf(buf.data() + used, MaxSize - used + 1, format, |
71 | std::forward<Args>(args)...); |
72 | } |
73 | |
74 | template <int Power = 1000> void appendScaled(qreal value, const char *unit) |
75 | { |
76 | char prefix[2] = {}; |
77 | qreal v = qAbs(t: value); |
78 | qint64 ratio; |
79 | if (v < 1 && Power == 1000) { |
80 | const char *prefixes = submultiplePrefixes; |
81 | ratio = qreal(std::atto::num) / std::atto::den; |
82 | while (value * ratio > 1000 && *prefixes) { |
83 | ++prefixes; |
84 | ratio *= 1000; |
85 | } |
86 | prefix[0] = *prefixes; |
87 | } else { |
88 | const char *prefixes = multiplePrefixes; |
89 | ratio = 1; |
90 | while (value > 1000 * ratio) { // yes, even for binary |
91 | ++prefixes; |
92 | ratio *= Power; |
93 | } |
94 | prefix[0] = *prefixes; |
95 | } |
96 | |
97 | // adjust the value by the ratio |
98 | value /= ratio; |
99 | appendf(", %.3g %s%s" , value, prefix, unit); |
100 | } |
101 | }; |
102 | } // unnamed namespace |
103 | |
104 | namespace QTest { |
105 | |
106 | static const char *ptIncidentType2String(QAbstractTestLogger::IncidentTypes type) |
107 | { |
108 | switch (type) { |
109 | case QAbstractTestLogger::Skip: |
110 | return "SKIP " ; |
111 | case QAbstractTestLogger::Pass: |
112 | return "PASS " ; |
113 | case QAbstractTestLogger::XFail: |
114 | return "XFAIL " ; |
115 | case QAbstractTestLogger::Fail: |
116 | return "FAIL! " ; |
117 | case QAbstractTestLogger::XPass: |
118 | return "XPASS " ; |
119 | case QAbstractTestLogger::BlacklistedPass: |
120 | return "BPASS " ; |
121 | case QAbstractTestLogger::BlacklistedFail: |
122 | return "BFAIL " ; |
123 | case QAbstractTestLogger::BlacklistedXPass: |
124 | return "BXPASS " ; |
125 | case QAbstractTestLogger::BlacklistedXFail: |
126 | return "BXFAIL " ; |
127 | } |
128 | Q_UNREACHABLE_RETURN(nullptr); |
129 | } |
130 | |
131 | static const char *benchmarkResult2String() |
132 | { |
133 | return "RESULT " ; |
134 | } |
135 | |
136 | static const char *ptMessageType2String(QAbstractTestLogger::MessageTypes type) |
137 | { |
138 | switch (type) { |
139 | case QAbstractTestLogger::QDebug: |
140 | return "QDEBUG " ; |
141 | case QAbstractTestLogger::QInfo: |
142 | return "QINFO " ; |
143 | case QAbstractTestLogger::QWarning: |
144 | return "QWARN " ; |
145 | case QAbstractTestLogger::QCritical: |
146 | return "QCRITICAL" ; |
147 | case QAbstractTestLogger::QFatal: |
148 | return "QFATAL " ; |
149 | case QAbstractTestLogger::Info: |
150 | return "INFO " ; |
151 | case QAbstractTestLogger::Warn: |
152 | return "WARNING" ; |
153 | } |
154 | Q_UNREACHABLE_RETURN(nullptr); |
155 | } |
156 | |
157 | template <typename T> |
158 | static int countSignificantDigits(T num) |
159 | { |
160 | if (num <= 0) |
161 | return 0; |
162 | |
163 | int digits = 0; |
164 | qreal divisor = 1; |
165 | |
166 | while (num / divisor >= 1) { |
167 | divisor *= 10; |
168 | ++digits; |
169 | } |
170 | |
171 | return digits; |
172 | } |
173 | |
174 | // Pretty-prints a benchmark result using the given number of digits. |
175 | template <typename T> QByteArray formatResult(T number, int significantDigits) |
176 | { |
177 | if (number < T(0)) |
178 | return "NAN" ; |
179 | if (number == T(0)) |
180 | return "0" ; |
181 | |
182 | QByteArray beforeDecimalPoint = QByteArray::number(qint64(number), format: 'f', precision: 0); |
183 | QByteArray afterDecimalPoint = QByteArray::number(number, 'f', 20); |
184 | afterDecimalPoint.remove(index: 0, len: beforeDecimalPoint.size() + 1); |
185 | |
186 | int beforeUse = qMin(a: beforeDecimalPoint.size(), b: significantDigits); |
187 | int beforeRemove = beforeDecimalPoint.size() - beforeUse; |
188 | |
189 | // Replace insignificant digits before the decimal point with zeros. |
190 | beforeDecimalPoint.chop(n: beforeRemove); |
191 | for (int i = 0; i < beforeRemove; ++i) { |
192 | beforeDecimalPoint.append(c: u'0'); |
193 | } |
194 | |
195 | int afterUse = significantDigits - beforeUse; |
196 | |
197 | // leading zeroes after the decimal point does not count towards the digit use. |
198 | if (beforeDecimalPoint == "0" && !afterDecimalPoint.isEmpty()) { |
199 | ++afterUse; |
200 | |
201 | int i = 0; |
202 | while (i < afterDecimalPoint.size() && afterDecimalPoint.at(i) == '0') |
203 | ++i; |
204 | |
205 | afterUse += i; |
206 | } |
207 | |
208 | int afterRemove = afterDecimalPoint.size() - afterUse; |
209 | afterDecimalPoint.chop(n: afterRemove); |
210 | |
211 | char separator = ','; |
212 | char decimalPoint = '.'; |
213 | |
214 | // insert thousands separators |
215 | int length = beforeDecimalPoint.size(); |
216 | for (int i = beforeDecimalPoint.size() -1; i >= 1; --i) { |
217 | if ((length - i) % 3 == 0) |
218 | beforeDecimalPoint.insert(i, c: separator); |
219 | } |
220 | |
221 | QByteArray print; |
222 | print = beforeDecimalPoint; |
223 | if (afterUse > 0) |
224 | print.append(c: decimalPoint); |
225 | |
226 | print += afterDecimalPoint; |
227 | |
228 | |
229 | return print; |
230 | } |
231 | } |
232 | |
233 | /*! \internal |
234 | \class QPlainTestLogger |
235 | \inmodule QtTest |
236 | |
237 | QPlainTestLogger implements basic logging of test results. |
238 | |
239 | The format is Qt-specific and aims to be easy to read. |
240 | */ |
241 | |
242 | void QPlainTestLogger::outputMessage(const char *str) |
243 | { |
244 | #if defined(Q_OS_WIN) |
245 | // Log to system log only if output is not redirected and stderr not preferred |
246 | if (stream == stdout && !QtPrivate::shouldLogToStderr()) { |
247 | OutputDebugStringA(str); |
248 | return; |
249 | } |
250 | #elif defined(Q_OS_ANDROID) |
251 | __android_log_write(ANDROID_LOG_INFO, "QTestLib" , str); |
252 | #endif |
253 | outputString(msg: str); |
254 | } |
255 | |
256 | void QPlainTestLogger::printMessage(MessageSource source, const char *type, const char *msg, |
257 | const char *file, int line) |
258 | { |
259 | QTEST_ASSERT(type); |
260 | QTEST_ASSERT(msg); |
261 | |
262 | QTestCharBuffer messagePrefix; |
263 | |
264 | QTestCharBuffer messageLocation; |
265 | #ifdef Q_OS_WIN |
266 | constexpr const char *INCIDENT_LOCATION_STR = "\n%s(%d) : failure location" ; |
267 | constexpr const char *OTHER_LOCATION_STR = "\n%s(%d) : message location" ; |
268 | #else |
269 | constexpr const char *INCIDENT_LOCATION_STR = "\n Loc: [%s(%d)]" ; |
270 | constexpr const char *OTHER_LOCATION_STR = INCIDENT_LOCATION_STR; |
271 | #endif |
272 | |
273 | if (file) { |
274 | switch (source) { |
275 | case MessageSource::Incident: |
276 | QTest::qt_asprintf(buf: &messageLocation, format: INCIDENT_LOCATION_STR, file, line); |
277 | break; |
278 | case MessageSource::Other: |
279 | QTest::qt_asprintf(buf: &messageLocation, format: OTHER_LOCATION_STR, file, line); |
280 | break; |
281 | } |
282 | } |
283 | |
284 | const char *msgFiller = msg[0] ? " " : "" ; |
285 | QTestCharBuffer testIdentifier; |
286 | QTestPrivate::generateTestIdentifier(identifier: &testIdentifier); |
287 | QTest::qt_asprintf(buf: &messagePrefix, format: "%s: %s%s%s%s\n" , |
288 | type, testIdentifier.data(), msgFiller, msg, messageLocation.data()); |
289 | |
290 | // In colored mode, printf above stripped our nonprintable control characters. |
291 | // Put them back. |
292 | memcpy(dest: messagePrefix.data(), src: type, n: strlen(s: type)); |
293 | |
294 | outputMessage(str: messagePrefix.data()); |
295 | } |
296 | |
297 | void QPlainTestLogger::(const QBenchmarkResult &result) |
298 | { |
299 | FixedBufString<1022> buf; |
300 | buf.appendf(format: "%s: %s::%s" , args: QTest::benchmarkResult2String(), |
301 | args: QTestResult::currentTestObjectName(), args: result.context.slotName.toLatin1().data()); |
302 | |
303 | if (QByteArray tag = result.context.tag.toLocal8Bit(); !tag.isEmpty()) |
304 | buf.appendf(format: ":\"%s\":\n" , args: tag.data()); |
305 | else |
306 | buf.append(text: ":\n" ); |
307 | outputMessage(str: buf); |
308 | } |
309 | |
310 | void QPlainTestLogger::printBenchmarkResults(const QList<QBenchmarkResult> &results) |
311 | { |
312 | using namespace std::chrono; |
313 | FixedBufString<1022> buf; |
314 | auto findResultFor = [&results](QTest::QBenchmarkMetric metric) -> std::optional<qreal> { |
315 | for (const QBenchmarkResult &result : results) { |
316 | if (result.measurement.metric == metric) |
317 | return result.measurement.value; |
318 | } |
319 | return std::nullopt; |
320 | }; |
321 | |
322 | // we need the execution time quite often, so find it first |
323 | qreal executionTime = 0; |
324 | if (auto ns = findResultFor(QTest::WalltimeNanoseconds)) |
325 | executionTime = *ns / (1000 * 1000 * 1000); |
326 | else if (auto ms = findResultFor(QTest::WalltimeMilliseconds)) |
327 | executionTime = *ms / 1000; |
328 | |
329 | for (const QBenchmarkResult &result : results) { |
330 | buf.clear(); |
331 | |
332 | const char * unitText = QTest::benchmarkMetricUnit(metric: result.measurement.metric); |
333 | int significantDigits = QTest::countSignificantDigits(num: result.measurement.value); |
334 | qreal valuePerIteration = qreal(result.measurement.value) / qreal(result.iterations); |
335 | buf.appendf(format: " %s %s%s" , args: QTest::formatResult(number: valuePerIteration, significantDigits).constData(), |
336 | args&: unitText, args: result.setByMacro ? " per iteration" : "" ); |
337 | |
338 | switch (result.measurement.metric) { |
339 | case QTest::BitsPerSecond: |
340 | // for bits/s, we'll use powers of 10 (1 Mbit/s = 1000 kbit/s = 1000000 bit/s) |
341 | buf.appendScaled<1000>(value: result.measurement.value, unit: "bit/s" ); |
342 | break; |
343 | case QTest::BytesPerSecond: |
344 | // for B/s, we'll use powers of 2 (1 MB/s = 1024 kB/s = 1048576 B/s) |
345 | buf.appendScaled<1024>(value: result.measurement.value, unit: "B/s" ); |
346 | break; |
347 | |
348 | case QTest::CPUCycles: |
349 | case QTest::RefCPUCycles: |
350 | if (!qIsNull(d: executionTime)) |
351 | buf.appendScaled(value: result.measurement.value / executionTime, unit: "Hz" ); |
352 | break; |
353 | |
354 | case QTest::Instructions: |
355 | if (auto cycles = findResultFor(QTest::CPUCycles)) { |
356 | buf.appendf(format: ", %.3f instr/cycle" , args: result.measurement.value / *cycles); |
357 | break; |
358 | } |
359 | Q_FALLTHROUGH(); |
360 | |
361 | case QTest::InstructionReads: |
362 | case QTest::Events: |
363 | case QTest::BytesAllocated: |
364 | case QTest::CPUMigrations: |
365 | case QTest::BusCycles: |
366 | case QTest::StalledCycles: |
367 | case QTest::BranchInstructions: |
368 | case QTest::BranchMisses: |
369 | case QTest::CacheReferences: |
370 | case QTest::CacheReads: |
371 | case QTest::CacheWrites: |
372 | case QTest::CachePrefetches: |
373 | case QTest::CacheMisses: |
374 | case QTest::CacheReadMisses: |
375 | case QTest::CacheWriteMisses: |
376 | case QTest::CachePrefetchMisses: |
377 | case QTest::ContextSwitches: |
378 | case QTest::PageFaults: |
379 | case QTest::MinorPageFaults: |
380 | case QTest::MajorPageFaults: |
381 | case QTest::AlignmentFaults: |
382 | case QTest::EmulationFaults: |
383 | if (!qIsNull(d: executionTime)) |
384 | buf.appendScaled(value: result.measurement.value / executionTime, unit: "/sec" ); |
385 | break; |
386 | |
387 | case QTest::FramesPerSecond: |
388 | case QTest::CPUTicks: |
389 | case QTest::WalltimeMilliseconds: |
390 | case QTest::WalltimeNanoseconds: |
391 | break; // no additional information |
392 | } |
393 | |
394 | Q_ASSERT(result.iterations > 0); |
395 | buf.appendf(format: " (total: %s, iterations: %d)\n" , |
396 | args: QTest::formatResult(number: result.measurement.value, significantDigits).constData(), |
397 | args: result.iterations); |
398 | |
399 | outputMessage(str: buf); |
400 | } |
401 | } |
402 | |
403 | QPlainTestLogger::QPlainTestLogger(const char *filename) |
404 | : QAbstractTestLogger(filename) |
405 | { |
406 | } |
407 | |
408 | QPlainTestLogger::~QPlainTestLogger() = default; |
409 | |
410 | void QPlainTestLogger::startLogging() |
411 | { |
412 | QAbstractTestLogger::startLogging(); |
413 | |
414 | char buf[1024]; |
415 | if (QTestLog::verboseLevel() < 0) { |
416 | qsnprintf(str: buf, n: sizeof(buf), fmt: "Testing %s\n" , QTestResult::currentTestObjectName()); |
417 | } else { |
418 | qsnprintf(str: buf, n: sizeof(buf), |
419 | fmt: "********* Start testing of %s *********\n" |
420 | "Config: Using QtTest library " QTEST_VERSION_STR |
421 | ", %s, %s %s\n" , QTestResult::currentTestObjectName(), QLibraryInfo::build(), |
422 | qPrintable(QSysInfo::productType()), qPrintable(QSysInfo::productVersion())); |
423 | } |
424 | outputMessage(str: buf); |
425 | } |
426 | |
427 | void QPlainTestLogger::stopLogging() |
428 | { |
429 | char buf[1024]; |
430 | const int timeMs = qRound(d: QTestLog::msecsTotalTime()); |
431 | if (QTestLog::verboseLevel() < 0) { |
432 | qsnprintf(str: buf, n: sizeof(buf), fmt: "Totals: %d passed, %d failed, %d skipped, %d blacklisted, %dms\n" , |
433 | QTestLog::passCount(), QTestLog::failCount(), |
434 | QTestLog::skipCount(), QTestLog::blacklistCount(), timeMs); |
435 | } else { |
436 | qsnprintf(str: buf, n: sizeof(buf), |
437 | fmt: "Totals: %d passed, %d failed, %d skipped, %d blacklisted, %dms\n" |
438 | "********* Finished testing of %s *********\n" , |
439 | QTestLog::passCount(), QTestLog::failCount(), |
440 | QTestLog::skipCount(), QTestLog::blacklistCount(), timeMs, |
441 | QTestResult::currentTestObjectName()); |
442 | } |
443 | outputMessage(str: buf); |
444 | |
445 | QAbstractTestLogger::stopLogging(); |
446 | } |
447 | |
448 | |
449 | void QPlainTestLogger::enterTestFunction(const char * /*function*/) |
450 | { |
451 | if (QTestLog::verboseLevel() >= 1) |
452 | printMessage(source: MessageSource::Other, type: QTest::ptMessageType2String(type: Info), msg: "entering" ); |
453 | } |
454 | |
455 | void QPlainTestLogger::leaveTestFunction() |
456 | { |
457 | } |
458 | |
459 | void QPlainTestLogger::addIncident(IncidentTypes type, const char *description, |
460 | const char *file, int line) |
461 | { |
462 | // suppress B?PASS and B?XFAIL in silent mode |
463 | if ((type == Pass || type == BlacklistedPass || type == XFail || type == BlacklistedXFail) |
464 | && QTestLog::verboseLevel() < 0) |
465 | return; |
466 | |
467 | printMessage(source: MessageSource::Incident, type: QTest::ptIncidentType2String(type), msg: description, file, line); |
468 | } |
469 | |
470 | void QPlainTestLogger::addBenchmarkResults(const QList<QBenchmarkResult> &results) |
471 | { |
472 | // suppress benchmark results in silent mode |
473 | if (QTestLog::verboseLevel() < 0 || results.isEmpty()) |
474 | return; |
475 | |
476 | printBenchmarkResultsHeader(result: results.first()); |
477 | printBenchmarkResults(results); |
478 | } |
479 | |
480 | void QPlainTestLogger::addMessage(QtMsgType type, const QMessageLogContext &context, const QString &message) |
481 | { |
482 | QAbstractTestLogger::addMessage(type, context, message); |
483 | } |
484 | |
485 | void QPlainTestLogger::addMessage(MessageTypes type, const QString &message, |
486 | const char *file, int line) |
487 | { |
488 | // suppress non-fatal messages in silent mode |
489 | if (type != QFatal && QTestLog::verboseLevel() < 0) |
490 | return; |
491 | |
492 | printMessage(source: MessageSource::Other, type: QTest::ptMessageType2String(type), qPrintable(message), file, line); |
493 | } |
494 | |
495 | QT_END_NAMESPACE |
496 | |