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 } 446