xapian-core/tests/perftest/perftest.cc

   1 /** @file
   2  * @brief performance tests for Xapian.
   3  */
   4 /* Copyright 2008 Lemur Consulting Ltd
   5  * Copyright 2008,2009,2010,2012,2013,2015 Olly Betts
   6  *
   7  * This program is free software; you can redistribute it and/or
   8  * modify it under the terms of the GNU General Public License as
   9  * published by the Free Software Foundation; either version 2 of the
  10  * License, or (at your option) any later version.
  11  *
  12  * This program is distributed in the hope that it will be useful,
  13  * but WITHOUT ANY WARRANTY; without even the implied warranty of
  14  * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
  15  * GNU General Public License for more details.
  16  *
  17  * You should have received a copy of the GNU General Public License
  18  * along with this program; if not, write to the Free Software
  19  * Foundation, Inc., 51 Franklin St, Fifth Floor, Boston, MA  02110-1301
  20  * USA
  21  */
  22
  23 #include <config.h>
  24 #include "perftest.h"
  25
  26 #include "backendmanager.h"
  27 #include "freemem.h"
  28 #include "omassert.h"
  29 #include "perftest/perftest_all.h"
  30 #include "realtime.h"
  31 #include "runprocess.h"
  32 #include "str.h"
  33 #include "stringutils.h"
  34 #include "testrunner.h"
  35 #include "testsuite.h"
  36
  37 #include <cstdlib>
  38 #include <iostream>
  39
  40 #include "safeunistd.h"
  41 #ifdef HAVE_SYS_UTSNAME_H
  42 # include <sys/utsname.h>
  43 #endif
  44
  45 #ifdef __WIN32__
  46 # include "safewindows.h"
  47 # include "safewinsock2.h"
  48 #endif
  49
  50 using namespace std;
  51
  52 PerfTestLogger logger;
  53
  54 static string
  55 escape_xml(const string & str)
  56 {
  57     string res;
  58     string::size_type p = 0;
  59     while (p < str.size()) {
  60         char ch = str[p++];
  61         switch (ch) {
  62             case '<':
  63                 res += "&lt;";
  64                 continue;
  65             case '>':
  66                 res += "&gt;";
  67                 continue;
  68             case '&':
  69                 res += "&amp;";
  70                 continue;
  71             case '"':
  72                 res += "&quot;";
  73                 continue;
  74             default:
  75                 res += ch;
  76         }
  77     }
  78     return res;
  79 }
  80
  81 PerfTestLogger::PerfTestLogger()
  82         : testcase_started(false),
  83           indexing_started(false),
  84           searching_started(false),
  85           diversifying_started(false)
  86 {}
  87
  88 PerfTestLogger::~PerfTestLogger()
  89 {
  90     close();
  91 }
  92
  93 /// Get the hostname.
  94 static string
  95 get_hostname()
  96 {
  97 #ifdef __WIN32__
  98     char buf[256];
  99     WORD WSAVerReq = MAKEWORD(1, 1);
 100     WSADATA WSAData;
 101
 102     if (WSAStartup(WSAVerReq, &WSAData) != 0) {
 103         // wrong winsock dlls?
 104         return string();
 105     }
 106     if (gethostname(buf, sizeof(buf)) != 0) {
 107         *buf = '\0';
 108     }
 109     WSACleanup();
 110     return buf;
 111 #elif defined HAVE_SYS_UTSNAME_H
 112     struct utsname uname_buf;
 113     if (uname(&uname_buf) != 0) {
 114         uname_buf.nodename[0] = '\0';
 115     }
 116     return uname_buf.nodename;
 117 #elif defined HAVE_GETHOSTNAME
 118     char buf[256];
 119     if (gethostname(buf, sizeof(buf)) != 0) {
 120         *buf = '\0';
 121     }
 122     return buf;
 123 #else
 124     return string();
 125 #endif
 126 }
 127
 128 /// Get the load average.
 129 static string
 130 get_loadavg()
 131 {
 132 #ifdef __WIN32__
 133     return string();
 134 #else
 135     string loadavg;
 136     try {
 137         loadavg = stdout_to_string("uptime 2>/dev/null | sed 's/.*: \\([0-9][0-9]*\\)/\\1/;s/, .*//'");
 138     } catch (const NoSuchProgram&) {
 139     } catch (const ReadError&) {
 140     }
 141     return loadavg;
 142 #endif
 143 }
 144
 145 /// Get the number of processors.
 146 static string
 147 get_ncpus()
 148 {
 149     string ncpus;
 150 #ifdef __WIN32__
 151     SYSTEM_INFO siSysInfo;
 152     GetSystemInfo(&siSysInfo);
 153     ncpus = str(siSysInfo.dwNumberOfProcessors);
 154 #else
 155     try {
 156         // Works on Linux, at least back to kernel 2.2.26.
 157         ncpus = stdout_to_string("getconf _NPROCESSORS_ONLN 2>/dev/null | grep -v '[^0-9]'");
 158     } catch (const NoSuchProgram&) {
 159     } catch (const ReadError&) {
 160     }
 161     if (ncpus.empty())
 162         try {
 163             // Works on OpenBSD (and apparently FreeBSD and Darwin).
 164             ncpus = stdout_to_string("sysctl hw.ncpu 2>/dev/null | sed 's/.*=//'");
 165         } catch (const NoSuchProgram&) {
 166         } catch (const ReadError&) {
 167         }
 168     if (ncpus.empty())
 169         try {
 170             // Works on Solaris and OSF/1.
 171             ncpus = stdout_to_string("PATH=/usr/sbin:$PATH psrinfo 2>/dev/null | grep -c on-line");
 172         } catch (const NoSuchProgram&) {
 173         } catch (const ReadError&) {
 174         }
 175     if (ncpus.empty())
 176         try {
 177             // Works on Linux, just in case the getconf version doesn't.
 178             // Different architectures have different formats for /proc/cpuinfo
 179             // so this won't work as widely as getconf _NPROCESSORS_ONLN will.
 180             ncpus = stdout_to_string("grep -c processor /proc/cpuinfo 2>/dev/null");
 181         } catch (const NoSuchProgram&) {
 182         } catch (const ReadError&) {
 183         }
 184 #endif
 185     return ncpus;
 186 }
 187
 188 /// Get details of the OS and distribution.
 189 static string
 190 get_distro()
 191 {
 192     string distro;
 193 #ifdef __WIN32__
 194     OSVERSIONINFO osvi;
 195     ZeroMemory(&osvi, sizeof(OSVERSIONINFO));
 196     osvi.dwOSVersionInfoSize = sizeof(OSVERSIONINFO);
 197 #ifdef _MSC_VER
 198 // GetVersionEx() is deprecated, but none of the suggested replacements seems
 199 // to actually provide the functionality we want here...
 200 # pragma warning(push)
 201 # pragma warning(disable:4996)
 202 #endif
 203     GetVersionEx(&osvi);
 204 #ifdef _MSC_VER
 205 # pragma warning(pop)
 206 #endif
 207     distro = "Microsoft Windows v";
 208     distro += str(osvi.dwMajorVersion);
 209     distro += '.';
 210     distro += str(osvi.dwMinorVersion);
 211     distro += '.';
 212     distro += str(osvi.dwBuildNumber);
 213 #else
 214     try {
 215         distro = stdout_to_string("perftest/get_machine_info 2>/dev/null");
 216     } catch (const NoSuchProgram&) {
 217     } catch (const ReadError&) {
 218     }
 219 #endif
 220     return distro;
 221 }
 222
 223 /// Get the git commit for HEAD.
 224 static string
 225 get_commit_ref()
 226 {
 227     string commit_ref;
 228     try {
 229         commit_ref = stdout_to_string("cd \"$srcdir\" && git log -n1 --abbrev-commit --format=%h");
 230     } catch (const NoSuchProgram&) {
 231     } catch (const ReadError&) {
 232     }
 233
 234     return commit_ref;
 235 }
 236
 237 bool
 238 PerfTestLogger::open(const string & logpath)
 239 {
 240     out.open(logpath.c_str(), ios::out | ios::binary | ios::trunc);
 241     if (!out.is_open()) {
 242         cerr << "Couldn't open output logfile '" << logpath << "'\n";
 243         return false;
 244     }
 245
 246     string loadavg = get_loadavg();
 247     string hostname = get_hostname();
 248     string ncpus = get_ncpus();
 249     string distro = get_distro();
 250
 251     // Write header, and details of the machine.
 252     write("<?xml version=\"1.0\" encoding=\"UTF-8\"?>\n<testrun>\n"
 253           " <machineinfo>\n");
 254     if (!hostname.empty())
 255         write("  <hostname>" + hostname + "</hostname>\n");
 256     if (!loadavg.empty())
 257         write("  <loadavg>" + loadavg + "</loadavg>\n");
 258     if (!ncpus.empty())
 259         write("  <ncpus>" + ncpus + "</ncpus>\n");
 260     if (!distro.empty())
 261         write("  <distro>" + distro + "</distro>\n");
 262     write("  <physmem>" + str(get_total_physical_memory()) + "</physmem>\n");
 263     write(" </machineinfo>\n");
 264
 265     const string & commit_ref = get_commit_ref();
 266
 267     write(" <sourceinfo>\n");
 268     if (!commit_ref.empty())
 269         write("  <commitref>" + commit_ref + "</commitref>\n");
 270     write("  <version>" + string(Xapian::version_string()) + "</version>\n");
 271     write(" </sourceinfo>\n");
 272
 273     return true;
 274 }
 275
 276 void
 277 PerfTestLogger::write(const string & text)
 278 {
 279     out.write(text.data(), text.size());
 280     out.flush();
 281 }
 282
 283 void
 284 PerfTestLogger::close()
 285 {
 286     repetition_end();
 287     if (out.is_open()) {
 288         write("</testrun>\n");
 289         out.close();
 290     }
 291 }
 292
 293 void
 294 PerfTestLogger::indexing_begin(const string & dbname,
 295                                const std::map<std::string, std::string> & params)
 296 {
 297     searching_end();
 298     indexing_end();
 299     write("  <indexrun dbname=\"" + dbname + "\">\n   <params>\n");
 300     std::map<std::string, std::string>::const_iterator i;
 301     for (i = params.begin(); i != params.end(); ++i) {
 302         write("    <param name=\"" + i->first + "\">" + escape_xml(i->second) + "</param>\n");
 303     }
 304     i = params.find("flush_threshold");
 305     if (i == params.end()) {
 306         Xapian::doccount flush_threshold = 0;
 307         const char *p = getenv("XAPIAN_FLUSH_THRESHOLD");
 308         if (p)
 309             flush_threshold = atoi(p);
 310         if (flush_threshold == 0)
 311             flush_threshold = 10000;
 312         write("    <param name=\"flush_threshold\">" +
 313               escape_xml(str(flush_threshold)) + "</param>\n");
 314     }
 315     write("   </params>\n");
 316     indexing_addcount = 0;
 317     indexing_unlogged_changes = false;
 318     indexing_timer = RealTime::now();
 319     last_indexlog_timer = indexing_timer;
 320     indexing_started = true;
 321
 322     indexing_log();
 323 }
 324
 325 void
 326 PerfTestLogger::indexing_log()
 327 {
 328     Assert(indexing_started);
 329     last_indexlog_timer = RealTime::now();
 330     double elapsed(last_indexlog_timer - indexing_timer);
 331     write("   <item>"
 332           "<time>" + str(elapsed) + "</time>"
 333           "<adds>" + str(indexing_addcount) + "</adds>"
 334           "</item>\n");
 335     indexing_unlogged_changes = false;
 336 }
 337
 338 void
 339 PerfTestLogger::indexing_add()
 340 {
 341     ++indexing_addcount;
 342     indexing_unlogged_changes = true;
 343     // Log every 1000 documents
 344     if (indexing_addcount % 1000 == 0) {
 345         indexing_log();
 346     } else {
 347         // Or after 5 seconds
 348         double now = RealTime::now();
 349         if (now > last_indexlog_timer + 5)
 350             indexing_log();
 351     }
 352 }
 353
 354 void
 355 PerfTestLogger::indexing_end()
 356 {
 357     if (indexing_started) {
 358         indexing_log();
 359         write("  </indexrun>\n");
 360         indexing_started = false;
 361     }
 362 }
 363
 364 void
 365 PerfTestLogger::searching_start(const string & description)
 366 {
 367     indexing_end();
 368     searching_end();
 369     write("   <searchrun>\n"
 370           "    <description>" + escape_xml(description) + "</description>\n");
 371     searching_started = true;
 372     search_start();
 373 }
 374
 375 void
 376 PerfTestLogger::search_start()
 377 {
 378     searching_timer = RealTime::now();
 379 }
 380
 381 void
 382 PerfTestLogger::search_end(const Xapian::Query & query,
 383                            const Xapian::MSet & mset)
 384 {
 385     Assert(searching_started);
 386     double elapsed(RealTime::now() - searching_timer);
 387     write("    <search>"
 388           "<time>" + str(elapsed) + "</time>"
 389           "<query>" + escape_xml(query.get_description()) + "</query>"
 390           "<mset>"
 391           "<size>" + str(mset.size()) + "</size>"
 392           "<lb>" + str(mset.get_matches_lower_bound()) + "</lb>"
 393           "<est>" + str(mset.get_matches_estimated()) + "</est>"
 394           "<ub>" + str(mset.get_matches_upper_bound()) + "</ub>"
 395           "</mset>"
 396           "</search>\n");
 397     search_start();
 398 }
 399
 400 void
 401 PerfTestLogger::searching_end()
 402 {
 403     if (searching_started) {
 404         write("   </searchrun>\n");
 405         searching_started = false;
 406     }
 407 }
 408
 409 void
 410 PerfTestLogger::diversifying_start(const string & description)
 411 {
 412     indexing_end();
 413     searching_end();
 414     write("   <diversifyrun>\n"
 415           "    <description>" + escape_xml(description) + "</description>\n");
 416     diversifying_started = true;
 417     diversify_start();
 418 }
 419
 420 void
 421 PerfTestLogger::diversify_start()
 422 {
 423     diversifying_timer = RealTime::now();
 424 }
 425
 426 void
 427 PerfTestLogger::diversify_end(Xapian::doccount k,
 428                               Xapian::doccount r,
 429                               const Xapian::DocumentSet & dset)
 430 {
 431     Assert(diversifying_started);
 432     double elapsed(RealTime::now() - diversifying_timer);
 433     write("    <diversify>"
 434           "<time>" + str(elapsed) + "</time>"
 435           "<dset>"
 436           "<k>" + str(k) + "</k>"
 437           "<r>" + str(r) + "</r>"
 438           "<size>" + str(dset.size()) + "</size>"
 439           "</dset>"
 440           "</diversify>\n");
 441     diversify_start();
 442 }
 443
 444 void
 445 PerfTestLogger::diversifying_end()
 446 {
 447     if (diversifying_started) {
 448         write("   </diversifyrun>\n");
 449         diversifying_started = false;
 450     }
 451 }
 452
 453 void
 454 PerfTestLogger::testcase_begin(const string & testcase)
 455 {
 456     testcase_end();
 457     write(" <testcase name=\"" + testcase + "\" backend=\"" +
 458           backendmanager->get_dbtype() + "\" repnum=\"" +
 459           str(repetition_number) + "\">\n");
 460     testcase_started = true;
 461 }
 462
 463 void
 464 PerfTestLogger::testcase_end()
 465 {
 466     indexing_end();
 467     if (testcase_started) {
 468         write(" </testcase>\n");
 469         testcase_started = false;
 470     }
 471 }
 472
 473 void
 474 PerfTestLogger::repetition_begin(int num)
 475 {
 476     repetition_end();
 477     repetition_number = num;
 478 }
 479
 480 void
 481 PerfTestLogger::repetition_end()
 482 {
 483     testcase_end();
 484 }
 485
 486
 487 class PerfTestRunner : public TestRunner
 488 {
 489     string repetitions_string;
 490     mutable bool repetitions_parsed;
 491     mutable int repetitions;
 492   public:
 493     PerfTestRunner()
 494             : repetitions_parsed(false), repetitions(5)
 495     {
 496         test_driver::add_command_line_option("repetitions", 'r',
 497                                              &repetitions_string);
 498     }
 499
 500     int run() const {
 501         int result = 0;
 502         if (!repetitions_parsed) {
 503             if (!repetitions_string.empty()) {
 504                 repetitions = atoi(repetitions_string.c_str());
 505             }
 506             repetitions_parsed = true;
 507         }
 508         for (int i = 0; i != repetitions; ++i) {
 509             logger.repetition_begin(i + 1);
 510 #include "perftest/perftest_collated.h"
 511             logger.repetition_end();
 512         }
 513         return result;
 514     }
 515 };
 516
 517 int main(int argc, char **argv)
 518 {
 519     if (!logger.open("perflog.xml"))
 520         return 1;
 521
 522     PerfTestRunner runner;
 523
 524     return runner.run_tests(argc, argv);
 525 }