Evgeniy Stepanov | bec2f0e | 2011-03-05 12:50:33 +0300 | [diff] [blame] | 1 | /* Copyright (c) 2008-2010, Google Inc. |
| 2 | * All rights reserved. |
| 3 | * |
| 4 | * Redistribution and use in source and binary forms, with or without |
| 5 | * modification, are permitted provided that the following conditions are |
| 6 | * met: |
| 7 | * |
| 8 | * * Redistributions of source code must retain the above copyright |
| 9 | * notice, this list of conditions and the following disclaimer. |
| 10 | * * Neither the name of Google Inc. nor the names of its |
| 11 | * contributors may be used to endorse or promote products derived from |
| 12 | * this software without specific prior written permission. |
| 13 | * |
| 14 | * THIS SOFTWARE IS PROVIDED BY THE COPYRIGHT HOLDERS AND CONTRIBUTORS |
| 15 | * "AS IS" AND ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT |
| 16 | * LIMITED TO, THE IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR |
| 17 | * A PARTICULAR PURPOSE ARE DISCLAIMED. IN NO EVENT SHALL THE COPYRIGHT |
| 18 | * OWNER OR CONTRIBUTORS BE LIABLE FOR ANY DIRECT, INDIRECT, INCIDENTAL, |
| 19 | * SPECIAL, EXEMPLARY, OR CONSEQUENTIAL DAMAGES (INCLUDING, BUT NOT |
| 20 | * LIMITED TO, PROCUREMENT OF SUBSTITUTE GOODS OR SERVICES; LOSS OF USE, |
| 21 | * DATA, OR PROFITS; OR BUSINESS INTERRUPTION) HOWEVER CAUSED AND ON ANY |
| 22 | * THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT LIABILITY, OR TORT |
| 23 | * (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY OUT OF THE USE |
| 24 | * OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE. |
| 25 | */ |
| 26 | |
| 27 | // This file is part of ThreadSanitizer, a dynamic data race detector. |
| 28 | // Author: Evgeniy Stepanov. |
| 29 | |
| 30 | #include <stdio.h> |
| 31 | #include <stdlib.h> |
| 32 | #include <string.h> |
| 33 | #include <vector> |
| 34 | #include <set> |
| 35 | #include <iterator> |
| 36 | #include <algorithm> |
| 37 | |
| 38 | #include "ts_lock.h" |
| 39 | #include "ts_util.h" |
| 40 | #include "ts_race_verifier.h" |
| 41 | #include "thread_sanitizer.h" |
| 42 | |
| 43 | struct PossibleRace { |
| 44 | PossibleRace() : pc(0), reported(false) {} |
| 45 | // racy instruction |
| 46 | uintptr_t pc; |
| 47 | // concurrent traces |
| 48 | vector<uintptr_t> traces; |
| 49 | // report text |
| 50 | string report; |
| 51 | // whether this race has already been reported |
| 52 | bool reported; |
| 53 | }; |
| 54 | |
| 55 | // pc -> race |
| 56 | static map<uintptr_t, PossibleRace*>* races_map; |
| 57 | |
| 58 | // Data about a call site. |
| 59 | struct CallSite { |
| 60 | int thread_id; |
| 61 | uintptr_t pc; |
| 62 | }; |
| 63 | |
| 64 | struct TypedCallSites { |
| 65 | vector<CallSite> reads; |
| 66 | vector<CallSite> writes; |
| 67 | }; |
| 68 | |
| 69 | // data address -> ([write callsites], [read callsites]) |
| 70 | typedef map<uintptr_t, TypedCallSites> AddressMap; |
| 71 | |
| 72 | static TSLock racecheck_lock; |
| 73 | static AddressMap* racecheck_map; |
| 74 | // data addresses that are ignored (they have already been reported) |
| 75 | static set<uintptr_t>* ignore_addresses; |
| 76 | |
| 77 | // starting pc of the trace -> visit count |
| 78 | // used to reduce the sleep time for hot traces |
| 79 | typedef map<uintptr_t, int> VisitCountMap; |
| 80 | static VisitCountMap* visit_count_map; |
| 81 | |
| 82 | static int n_reports; |
| 83 | |
| 84 | /** |
| 85 | * Given max and min pc of a trace (both inclusive!), returns whether this trace |
| 86 | * is interesting to us at all (via the return value), and whether it should be |
| 87 | * instrumented fully (*instrument_pc=0), or 1 instruction only. In the latter |
| 88 | * case, *instrument_pc contains the address of the said instruction. |
| 89 | */ |
| 90 | bool RaceVerifierGetAddresses(uintptr_t min_pc, uintptr_t max_pc, |
| 91 | uintptr_t* instrument_pc) { |
| 92 | uintptr_t pc = 0; |
| 93 | for (map<uintptr_t, PossibleRace*>::iterator it = races_map->begin(); |
| 94 | it != races_map->end(); ++it) { |
| 95 | PossibleRace* race = it->second; |
| 96 | if (race->reported) |
| 97 | continue; |
| 98 | if (race->pc >= min_pc && race->pc <= max_pc) { |
| 99 | if (pc) { |
| 100 | // Two race candidates in one trace. Just instrument it fully. |
| 101 | *instrument_pc = 0; |
| 102 | return true; |
| 103 | } |
| 104 | pc = race->pc; |
| 105 | } |
| 106 | for (vector<uintptr_t>::iterator it2 = race->traces.begin(); |
| 107 | it2 != race->traces.end(); ++it2) { |
| 108 | if (*it2 >= min_pc && *it2 <= max_pc) { |
| 109 | *instrument_pc = 0; |
| 110 | return true; |
| 111 | } |
| 112 | } |
| 113 | } |
| 114 | *instrument_pc = pc; |
| 115 | return !!pc; |
| 116 | } |
| 117 | |
| 118 | static void UpdateSummary() { |
| 119 | if (!G_flags->summary_file.empty()) { |
| 120 | char buff[100]; |
| 121 | snprintf(buff, sizeof(buff), |
| 122 | "RaceVerifier: %d report(s) verified\n", n_reports); |
| 123 | // We overwrite the contents of this file with the new summary. |
| 124 | // We don't do that at the end because even if we crash later |
| 125 | // we will already have the summary. |
| 126 | OpenFileWriteStringAndClose(G_flags->summary_file, buff); |
| 127 | } |
| 128 | } |
| 129 | |
| 130 | /* Build and print a race report for a data address. Does not print stack traces |
| 131 | and symbols and all the fancy stuff - we don't have that info. Used when we |
| 132 | don't have a ready report - for unexpected races and for |
| 133 | --race-verifier-extra races. |
| 134 | |
| 135 | racecheck_lock must be held by the current thread. |
| 136 | */ |
| 137 | static void PrintRaceReportEmpty(uintptr_t addr) { |
| 138 | TypedCallSites* typedCallSites = &(*racecheck_map)[addr]; |
| 139 | vector<CallSite>& writes = typedCallSites->writes; |
| 140 | vector<CallSite>& reads = typedCallSites->reads; |
| 141 | for (vector<CallSite>::const_iterator it = writes.begin(); |
| 142 | it != writes.end(); ++ it) { |
| 143 | Printf(" write at %p\n", it->pc); |
| 144 | } |
| 145 | for (vector<CallSite>::const_iterator it = reads.begin(); |
| 146 | it != reads.end(); ++ it) { |
| 147 | Printf(" read at %p\n", it->pc); |
| 148 | } |
| 149 | } |
| 150 | |
| 151 | /* Find a PossibleRace that matches current accesses (racecheck_map) to the |
| 152 | given data address. |
| 153 | |
| 154 | racecheck_lock must be held by the current thread. |
| 155 | */ |
| 156 | static PossibleRace* FindRaceForAddr(uintptr_t addr) { |
| 157 | TypedCallSites* typedCallSites = &(*racecheck_map)[addr]; |
| 158 | vector<CallSite>& writes = typedCallSites->writes; |
| 159 | vector<CallSite>& reads = typedCallSites->reads; |
| 160 | for (vector<CallSite>::const_iterator it = writes.begin(); |
| 161 | it != writes.end(); ++ it) { |
| 162 | map<uintptr_t, PossibleRace*>::iterator it2 = races_map->find(it->pc); |
| 163 | if (it2 != races_map->end()) |
| 164 | return it2->second; |
| 165 | } |
| 166 | for (vector<CallSite>::const_iterator it = reads.begin(); |
| 167 | it != reads.end(); ++ it) { |
| 168 | map<uintptr_t, PossibleRace*>::iterator it2 = races_map->find(it->pc); |
| 169 | if (it2 != races_map->end()) |
| 170 | return it2->second; |
| 171 | } |
| 172 | return NULL; |
| 173 | } |
| 174 | |
| 175 | /* Prints a race report for the given data address, either finding one in a |
| 176 | matching PossibleRace, or just printing pc's of the mops. |
| 177 | |
| 178 | racecheck_lock must be held by the current thread. |
| 179 | */ |
| 180 | static void PrintRaceReport(uintptr_t addr) { |
| 181 | PossibleRace* race = FindRaceForAddr(addr); |
| 182 | if (race) { |
| 183 | ExpectedRace* expected_race = ThreadSanitizerFindExpectedRace(addr); |
| 184 | if (expected_race) |
| 185 | expected_race->count++; |
| 186 | bool is_expected = !!expected_race; |
| 187 | bool is_unverifiable = is_expected && !expected_race->is_verifiable; |
| 188 | |
| 189 | if (is_expected && !is_unverifiable && !G_flags->show_expected_races) |
| 190 | return; |
| 191 | |
| 192 | if (is_unverifiable) |
| 193 | Printf("WARNING: Confirmed a race that was marked as UNVERIFIABLE:\n"); |
| 194 | else |
| 195 | Printf("WARNING: Confirmed a race:\n"); |
| 196 | const string& report = race->report; |
| 197 | if (report.empty()) { |
| 198 | PrintRaceReportEmpty(addr); |
| 199 | } else { |
| 200 | Printf("%s", report.c_str()); |
| 201 | } |
| 202 | // Suppress future reports for this race. |
| 203 | race->reported = true; |
| 204 | ignore_addresses->insert(addr); |
| 205 | |
| 206 | n_reports++; |
| 207 | } else { |
| 208 | Printf("Warning: unexpected race found!\n"); |
| 209 | PrintRaceReportEmpty(addr); |
| 210 | |
| 211 | n_reports ++; |
| 212 | } |
| 213 | UpdateSummary(); |
| 214 | } |
| 215 | |
| 216 | /** |
| 217 | * This function is called before the mop delay. |
| 218 | * @param thread_id Thread id. |
| 219 | * @param addr Data address. |
| 220 | * @param pc Instruction pc. |
| 221 | * @param is_w Whether this is a write (true) or a read (false). |
| 222 | * @return True if this access is interesting to us at all. If true, the caller |
| 223 | * should delay and then call RaceVerifierEndAccess. If false, it should do |
| 224 | * nothing more for this mop. |
| 225 | */ |
| 226 | bool RaceVerifierStartAccess(int thread_id, uintptr_t addr, uintptr_t pc, |
| 227 | bool is_w) { |
| 228 | CallSite callSite; |
| 229 | callSite.thread_id = thread_id; |
| 230 | callSite.pc = pc; |
| 231 | racecheck_lock.Lock(); |
| 232 | |
| 233 | if (debug_race_verifier) |
| 234 | Printf("[%d] pc %p %s addr %p start\n", thread_id, pc, |
| 235 | is_w ? "write" : "read", addr); |
| 236 | |
| 237 | if (ignore_addresses->count(addr)) { |
| 238 | racecheck_lock.Unlock(); |
| 239 | return false; |
| 240 | } |
| 241 | |
| 242 | TypedCallSites* typedCallSites = &(*racecheck_map)[addr]; |
| 243 | vector<CallSite>& writes = typedCallSites->writes; |
| 244 | vector<CallSite>& reads = typedCallSites->reads; |
| 245 | (is_w ? writes : reads).push_back(callSite); |
| 246 | if (writes.size() > 0 && writes.size() + reads.size() > 1) { |
| 247 | bool is_race = false; |
| 248 | for (size_t i = 0; !is_race && i < writes.size(); ++i) { |
| 249 | for (size_t j = 0; !is_race && j < writes.size(); ++j) |
| 250 | if (writes[i].thread_id != writes[j].thread_id) |
| 251 | is_race = true; |
| 252 | for (size_t j = 0; !is_race && j < reads.size(); ++j) |
| 253 | if (writes[i].thread_id != reads[j].thread_id) |
| 254 | is_race = true; |
| 255 | } |
| 256 | if (is_race) |
| 257 | PrintRaceReport(addr); |
| 258 | } |
| 259 | racecheck_lock.Unlock(); |
| 260 | return true; |
| 261 | } |
| 262 | |
| 263 | /* This function is called after the mop delay, only if RaceVerifierStartAccess |
| 264 | returned true. The arguments are exactly the same. */ |
| 265 | void RaceVerifierEndAccess(int thread_id, uintptr_t addr, uintptr_t pc, |
| 266 | bool is_w) { |
| 267 | racecheck_lock.Lock(); |
| 268 | |
| 269 | if (debug_race_verifier) |
| 270 | Printf("[%d] pc %p %s addr %p end\n", thread_id, pc, |
| 271 | is_w ? "write" : "read", addr); |
| 272 | if (ignore_addresses->count(addr)) { |
| 273 | racecheck_lock.Unlock(); |
| 274 | return; |
| 275 | } |
| 276 | |
| 277 | TypedCallSites* typedCallSites = &(*racecheck_map)[addr]; |
| 278 | vector<CallSite>& vec = |
| 279 | is_w ? typedCallSites->writes : typedCallSites->reads; |
| 280 | for (int i = vec.size() - 1; i >= 0; --i) { |
| 281 | if (vec[i].thread_id == thread_id) { |
| 282 | vec.erase(vec.begin() + i); |
| 283 | break; |
| 284 | } |
| 285 | } |
| 286 | racecheck_lock.Unlock(); |
| 287 | } |
| 288 | |
| 289 | /* Parse a race description that appears in TSan logs after the words |
| 290 | "Race verifier data: ", not including the said words. It looks like |
| 291 | "pc,trace[,trace]...", without spaces. */ |
| 292 | static PossibleRace* ParseRaceInfo(const string& raceInfo) { |
| 293 | PossibleRace* race = new PossibleRace(); |
| 294 | const char* p = raceInfo.c_str(); |
| 295 | while (true) { |
| 296 | char* end; |
| 297 | uintptr_t addr = my_strtol(p, &end, 16); |
| 298 | if (p == end) { |
| 299 | Printf("Parse error: %s\n", p); |
| 300 | exit(1); |
| 301 | } |
| 302 | if (!race->pc) |
| 303 | race->pc = addr; |
| 304 | else |
| 305 | race->traces.push_back(addr); |
| 306 | while (*end == '\n' || *end == '\r') |
| 307 | ++end; |
| 308 | if (*end == '\0') { |
| 309 | // raceInfo already ends with \n |
| 310 | Printf("Possible race: %s", raceInfo.c_str()); |
| 311 | return race; |
| 312 | } |
| 313 | if (*end != ',') { |
| 314 | Printf("Parse error: comma expected: %s\n", end); |
| 315 | delete race; |
| 316 | return NULL; |
| 317 | } |
| 318 | p = end + 1; |
| 319 | } |
| 320 | } |
| 321 | |
| 322 | /* Parse a race description and add it to races_map. */ |
| 323 | static void RaceVerifierParseRaceInfo(const string& raceInfo) { |
| 324 | PossibleRace* race = ParseRaceInfo(raceInfo); |
| 325 | if (race) |
| 326 | (*races_map)[race->pc] = race; |
| 327 | else |
| 328 | Printf("Bad raceInfo: %s\n", raceInfo.c_str()); |
| 329 | } |
| 330 | |
| 331 | |
| 332 | class StringStream { |
| 333 | public: |
| 334 | StringStream(const string &s) : s_(s), data_(s.c_str()), p_(data_) {} |
| 335 | |
| 336 | bool Eof() { |
| 337 | return !*p_; |
| 338 | } |
| 339 | |
| 340 | string NextLine() { |
| 341 | const char* first = p_; |
| 342 | while (*p_ && *p_ != '\n') { |
| 343 | ++p_; |
| 344 | } |
| 345 | if (*p_) |
| 346 | ++p_; |
| 347 | return string(first, p_ - first); |
| 348 | } |
| 349 | |
| 350 | private: |
| 351 | const string& s_; |
| 352 | const char* data_; |
| 353 | const char* p_; |
| 354 | }; |
| 355 | |
| 356 | /* Parse a TSan log and add all race verifier info's from it to our storage of |
| 357 | possible races. */ |
| 358 | static void RaceVerifierParseFile(const string& fileName) { |
| 359 | Printf("Reading race data from %s\n", fileName.c_str()); |
| 360 | const string RACEINFO_MARKER = "Race verifier data: "; |
| 361 | string log = ReadFileToString(fileName, true /* die_if_failed */); |
| 362 | StringStream ss(log); |
| 363 | string* desc = NULL; |
| 364 | int count = 0; |
| 365 | while (!ss.Eof()) { |
| 366 | string line = ss.NextLine(); |
| 367 | size_t pos; |
| 368 | if ((line.find("WARNING: Possible data race during") != |
| 369 | string::npos) || |
| 370 | (line.find("WARNING: Expected data race during") != |
| 371 | string::npos)) { |
| 372 | desc = new string(); |
| 373 | (*desc) += line; |
| 374 | } else if ((pos = line.find(RACEINFO_MARKER)) != string::npos) { |
| 375 | pos += RACEINFO_MARKER.size(); |
| 376 | string raceInfo = line.substr(pos); |
| 377 | PossibleRace* race = ParseRaceInfo(raceInfo); |
| 378 | (*desc) += "}}}\n"; |
| 379 | race->report = *desc; |
| 380 | (*races_map)[race->pc] = race; |
| 381 | count ++; |
| 382 | delete desc; |
| 383 | desc = NULL; |
| 384 | } else if (desc) { |
| 385 | (*desc) += line; |
| 386 | } |
| 387 | } |
| 388 | Printf("Got %d possible races\n", count); |
| 389 | } |
| 390 | |
| 391 | /** |
| 392 | * Return the time to sleep for the given trace. |
| 393 | * @param trace_pc The starting pc of the trace. |
| 394 | * @return Time to sleep in ms, or 0 if this trace should be ignored. |
| 395 | */ |
| 396 | int RaceVerifierGetSleepTime(uintptr_t trace_pc) { |
| 397 | racecheck_lock.Lock(); |
| 398 | int visit_count = ++(*visit_count_map)[trace_pc]; |
| 399 | int tm; |
| 400 | if (visit_count < 20) { |
| 401 | tm = G_flags->race_verifier_sleep_ms; |
| 402 | } else if (visit_count < 200) { |
| 403 | tm = G_flags->race_verifier_sleep_ms / 10; |
| 404 | } else { |
| 405 | tm = 0; |
| 406 | } |
| 407 | if (debug_race_verifier) { |
| 408 | if (visit_count == 20) { |
| 409 | Printf("RaceVerifier: Trace %x: sleep time reduced.\n", trace_pc); |
| 410 | } else if (visit_count == 200) { |
| 411 | Printf("RaceVerifier: Trace %x: ignored.\n", trace_pc); |
| 412 | } |
| 413 | } |
| 414 | racecheck_lock.Unlock(); |
| 415 | return tm; |
| 416 | } |
| 417 | |
| 418 | /** |
| 419 | * Init the race verifier. Should be called exactly once before any other |
| 420 | * functions in this file. |
| 421 | * @param fileNames Names of TSan log to parse. |
| 422 | * @param raceInfos Additional race description strings. |
| 423 | */ |
| 424 | void RaceVerifierInit(const vector<string>& fileNames, |
| 425 | const vector<string>& raceInfos) { |
| 426 | races_map = new map<uintptr_t, PossibleRace*>(); |
| 427 | racecheck_map = new AddressMap(); |
| 428 | visit_count_map = new VisitCountMap(); |
| 429 | ignore_addresses = new set<uintptr_t>(); |
| 430 | |
| 431 | for (vector<string>::const_iterator it = fileNames.begin(); |
| 432 | it != fileNames.end(); ++it) { |
| 433 | RaceVerifierParseFile(*it); |
| 434 | } |
| 435 | for (vector<string>::const_iterator it = raceInfos.begin(); |
| 436 | it != raceInfos.end(); ++it) { |
| 437 | RaceVerifierParseRaceInfo(*it); |
| 438 | } |
| 439 | } |
| 440 | |
| 441 | void RaceVerifierFini() { |
| 442 | Report("RaceVerifier summary: verified %d race(s)\n", n_reports); |
| 443 | int n_errors = GetNumberOfFoundErrors(); |
| 444 | SetNumberOfFoundErrors(n_errors + n_reports); |
| 445 | } |