/* Copyright (c) 2008-2010, Google Inc.
* All rights reserved.
*
* Redistribution and use in source and binary forms, with or without
* modification, are permitted provided that the following conditions are
* met:
*
* * Redistributions of source code must retain the above copyright
* notice, this list of conditions and the following disclaimer.
* * Neither the name of Google Inc. nor the names of its
* contributors may be used to endorse or promote products derived from
* this software without specific prior written permission.
*
* THIS SOFTWARE IS PROVIDED BY THE COPYRIGHT HOLDERS AND CONTRIBUTORS
* "AS IS" AND ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT
* LIMITED TO, THE IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR
* A PARTICULAR PURPOSE ARE DISCLAIMED. IN NO EVENT SHALL THE COPYRIGHT
* OWNER OR CONTRIBUTORS BE LIABLE FOR ANY DIRECT, INDIRECT, INCIDENTAL,
* SPECIAL, EXEMPLARY, OR CONSEQUENTIAL DAMAGES (INCLUDING, BUT NOT
* LIMITED TO, PROCUREMENT OF SUBSTITUTE GOODS OR SERVICES; LOSS OF USE,
* DATA, OR PROFITS; OR BUSINESS INTERRUPTION) HOWEVER CAUSED AND ON ANY
* THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT LIABILITY, OR TORT
* (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY OUT OF THE USE
* OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE.
*/
// This file is part of ThreadSanitizer, a dynamic data race detector.
// Author: Evgeniy Stepanov.
#include <stdio.h>
#include <stdlib.h>
#include <string.h>
#include <vector>
#include <set>
#include <iterator>
#include <algorithm>
#include "ts_lock.h"
#include "ts_util.h"
#include "ts_race_verifier.h"
#include "thread_sanitizer.h"
struct PossibleRace {
PossibleRace() : pc(0), reported(false) {}
// racy instruction
uintptr_t pc;
// concurrent traces
vector<uintptr_t> traces;
// report text
string report;
// whether this race has already been reported
bool reported;
};
// pc -> race
static map<uintptr_t, PossibleRace*>* races_map;
// Data about a call site.
struct CallSite {
int thread_id;
uintptr_t pc;
};
struct TypedCallSites {
vector<CallSite> reads;
vector<CallSite> writes;
};
// data address -> ([write callsites], [read callsites])
typedef map<uintptr_t, TypedCallSites> AddressMap;
static TSLock racecheck_lock;
static AddressMap* racecheck_map;
// data addresses that are ignored (they have already been reported)
static set<uintptr_t>* ignore_addresses;
// starting pc of the trace -> visit count
// used to reduce the sleep time for hot traces
typedef map<uintptr_t, int> VisitCountMap;
static VisitCountMap* visit_count_map;
static int n_reports;
/**
* Given max and min pc of a trace (both inclusive!), returns whether this trace
* is interesting to us at all (via the return value), and whether it should be
* instrumented fully (*instrument_pc=0), or 1 instruction only. In the latter
* case, *instrument_pc contains the address of the said instruction.
*/
bool RaceVerifierGetAddresses(uintptr_t min_pc, uintptr_t max_pc,
uintptr_t* instrument_pc) {
uintptr_t pc = 0;
for (map<uintptr_t, PossibleRace*>::iterator it = races_map->begin();
it != races_map->end(); ++it) {
PossibleRace* race = it->second;
if (race->reported)
continue;
if (race->pc >= min_pc && race->pc <= max_pc) {
if (pc) {
// Two race candidates in one trace. Just instrument it fully.
*instrument_pc = 0;
return true;
}
pc = race->pc;
}
for (vector<uintptr_t>::iterator it2 = race->traces.begin();
it2 != race->traces.end(); ++it2) {
if (*it2 >= min_pc && *it2 <= max_pc) {
*instrument_pc = 0;
return true;
}
}
}
*instrument_pc = pc;
return !!pc;
}
static void UpdateSummary() {
if (!G_flags->summary_file.empty()) {
char buff[100];
snprintf(buff, sizeof(buff),
"RaceVerifier: %d report(s) verified\n", n_reports);
// We overwrite the contents of this file with the new summary.
// We don't do that at the end because even if we crash later
// we will already have the summary.
OpenFileWriteStringAndClose(G_flags->summary_file, buff);
}
}
/* Build and print a race report for a data address. Does not print stack traces
and symbols and all the fancy stuff - we don't have that info. Used when we
don't have a ready report - for unexpected races and for
--race-verifier-extra races.
racecheck_lock must be held by the current thread.
*/
static void PrintRaceReportEmpty(uintptr_t addr) {
TypedCallSites* typedCallSites = &(*racecheck_map)[addr];
vector<CallSite>& writes = typedCallSites->writes;
vector<CallSite>& reads = typedCallSites->reads;
for (vector<CallSite>::const_iterator it = writes.begin();
it != writes.end(); ++ it) {
Printf(" write at %p\n", it->pc);
}
for (vector<CallSite>::const_iterator it = reads.begin();
it != reads.end(); ++ it) {
Printf(" read at %p\n", it->pc);
}
}
/* Find a PossibleRace that matches current accesses (racecheck_map) to the
given data address.
racecheck_lock must be held by the current thread.
*/
static PossibleRace* FindRaceForAddr(uintptr_t addr) {
TypedCallSites* typedCallSites = &(*racecheck_map)[addr];
vector<CallSite>& writes = typedCallSites->writes;
vector<CallSite>& reads = typedCallSites->reads;
for (vector<CallSite>::const_iterator it = writes.begin();
it != writes.end(); ++ it) {
map<uintptr_t, PossibleRace*>::iterator it2 = races_map->find(it->pc);
if (it2 != races_map->end())
return it2->second;
}
for (vector<CallSite>::const_iterator it = reads.begin();
it != reads.end(); ++ it) {
map<uintptr_t, PossibleRace*>::iterator it2 = races_map->find(it->pc);
if (it2 != races_map->end())
return it2->second;
}
return NULL;
}
/* Prints a race report for the given data address, either finding one in a
matching PossibleRace, or just printing pc's of the mops.
racecheck_lock must be held by the current thread.
*/
static void PrintRaceReport(uintptr_t addr) {
PossibleRace* race = FindRaceForAddr(addr);
if (race) {
ExpectedRace* expected_race = ThreadSanitizerFindExpectedRace(addr);
if (expected_race)
expected_race->count++;
bool is_expected = !!expected_race;
bool is_unverifiable = is_expected && !expected_race->is_verifiable;
if (is_expected && !is_unverifiable && !G_flags->show_expected_races)
return;
if (is_unverifiable)
Printf("WARNING: Confirmed a race that was marked as UNVERIFIABLE:\n");
else
Printf("WARNING: Confirmed a race:\n");
const string& report = race->report;
if (report.empty()) {
PrintRaceReportEmpty(addr);
} else {
Printf("%s", report.c_str());
}
// Suppress future reports for this race.
race->reported = true;
ignore_addresses->insert(addr);
n_reports++;
} else {
Printf("Warning: unexpected race found!\n");
PrintRaceReportEmpty(addr);
n_reports ++;
}
UpdateSummary();
}
/**
* This function is called before the mop delay.
* @param thread_id Thread id.
* @param addr Data address.
* @param pc Instruction pc.
* @param is_w Whether this is a write (true) or a read (false).
* @return True if this access is interesting to us at all. If true, the caller
* should delay and then call RaceVerifierEndAccess. If false, it should do
* nothing more for this mop.
*/
bool RaceVerifierStartAccess(int thread_id, uintptr_t addr, uintptr_t pc,
bool is_w) {
CallSite callSite;
callSite.thread_id = thread_id;
callSite.pc = pc;
racecheck_lock.Lock();
if (debug_race_verifier)
Printf("[%d] pc %p %s addr %p start\n", thread_id, pc,
is_w ? "write" : "read", addr);
if (ignore_addresses->count(addr)) {
racecheck_lock.Unlock();
return false;
}
TypedCallSites* typedCallSites = &(*racecheck_map)[addr];
vector<CallSite>& writes = typedCallSites->writes;
vector<CallSite>& reads = typedCallSites->reads;
(is_w ? writes : reads).push_back(callSite);
if (writes.size() > 0 && writes.size() + reads.size() > 1) {
bool is_race = false;
for (size_t i = 0; !is_race && i < writes.size(); ++i) {
for (size_t j = 0; !is_race && j < writes.size(); ++j)
if (writes[i].thread_id != writes[j].thread_id)
is_race = true;
for (size_t j = 0; !is_race && j < reads.size(); ++j)
if (writes[i].thread_id != reads[j].thread_id)
is_race = true;
}
if (is_race)
PrintRaceReport(addr);
}
racecheck_lock.Unlock();
return true;
}
/* This function is called after the mop delay, only if RaceVerifierStartAccess
returned true. The arguments are exactly the same. */
void RaceVerifierEndAccess(int thread_id, uintptr_t addr, uintptr_t pc,
bool is_w) {
racecheck_lock.Lock();
if (debug_race_verifier)
Printf("[%d] pc %p %s addr %p end\n", thread_id, pc,
is_w ? "write" : "read", addr);
if (ignore_addresses->count(addr)) {
racecheck_lock.Unlock();
return;
}
TypedCallSites* typedCallSites = &(*racecheck_map)[addr];
vector<CallSite>& vec =
is_w ? typedCallSites->writes : typedCallSites->reads;
for (int i = vec.size() - 1; i >= 0; --i) {
if (vec[i].thread_id == thread_id) {
vec.erase(vec.begin() + i);
break;
}
}
racecheck_lock.Unlock();
}
/* Parse a race description that appears in TSan logs after the words
"Race verifier data: ", not including the said words. It looks like
"pc,trace[,trace]...", without spaces. */
static PossibleRace* ParseRaceInfo(const string& raceInfo) {
PossibleRace* race = new PossibleRace();
const char* p = raceInfo.c_str();
while (true) {
char* end;
uintptr_t addr = my_strtol(p, &end, 16);
if (p == end) {
Printf("Parse error: %s\n", p);
exit(1);
}
if (!race->pc)
race->pc = addr;
else
race->traces.push_back(addr);
while (*end == '\n' || *end == '\r')
++end;
if (*end == '\0') {
// raceInfo already ends with \n
Printf("Possible race: %s", raceInfo.c_str());
return race;
}
if (*end != ',') {
Printf("Parse error: comma expected: %s\n", end);
delete race;
return NULL;
}
p = end + 1;
}
}
/* Parse a race description and add it to races_map. */
static void RaceVerifierParseRaceInfo(const string& raceInfo) {
PossibleRace* race = ParseRaceInfo(raceInfo);
if (race)
(*races_map)[race->pc] = race;
else
Printf("Bad raceInfo: %s\n", raceInfo.c_str());
}
class StringStream {
public:
StringStream(const string &s) : s_(s), data_(s.c_str()), p_(data_) {}
bool Eof() {
return !*p_;
}
string NextLine() {
const char* first = p_;
while (*p_ && *p_ != '\n') {
++p_;
}
if (*p_)
++p_;
return string(first, p_ - first);
}
private:
const string& s_;
const char* data_;
const char* p_;
};
/* Parse a TSan log and add all race verifier info's from it to our storage of
possible races. */
static void RaceVerifierParseFile(const string& fileName) {
Printf("Reading race data from %s\n", fileName.c_str());
const string RACEINFO_MARKER = "Race verifier data: ";
string log = ReadFileToString(fileName, true /* die_if_failed */);
StringStream ss(log);
string* desc = NULL;
int count = 0;
while (!ss.Eof()) {
string line = ss.NextLine();
size_t pos;
if ((line.find("WARNING: Possible data race during") !=
string::npos) ||
(line.find("WARNING: Expected data race during") !=
string::npos)) {
desc = new string();
(*desc) += line;
} else if ((pos = line.find(RACEINFO_MARKER)) != string::npos) {
pos += RACEINFO_MARKER.size();
string raceInfo = line.substr(pos);
PossibleRace* race = ParseRaceInfo(raceInfo);
(*desc) += "}}}\n";
race->report = *desc;
(*races_map)[race->pc] = race;
count ++;
delete desc;
desc = NULL;
} else if (desc) {
(*desc) += line;
}
}
Printf("Got %d possible races\n", count);
}
/**
* Return the time to sleep for the given trace.
* @param trace_pc The starting pc of the trace.
* @return Time to sleep in ms, or 0 if this trace should be ignored.
*/
int RaceVerifierGetSleepTime(uintptr_t trace_pc) {
racecheck_lock.Lock();
int visit_count = ++(*visit_count_map)[trace_pc];
int tm;
if (visit_count < 20) {
tm = G_flags->race_verifier_sleep_ms;
} else if (visit_count < 200) {
tm = G_flags->race_verifier_sleep_ms / 10;
} else {
tm = 0;
}
if (debug_race_verifier) {
if (visit_count == 20) {
Printf("RaceVerifier: Trace %x: sleep time reduced.\n", trace_pc);
} else if (visit_count == 200) {
Printf("RaceVerifier: Trace %x: ignored.\n", trace_pc);
}
}
racecheck_lock.Unlock();
return tm;
}
/**
* Init the race verifier. Should be called exactly once before any other
* functions in this file.
* @param fileNames Names of TSan log to parse.
* @param raceInfos Additional race description strings.
*/
void RaceVerifierInit(const vector<string>& fileNames,
const vector<string>& raceInfos) {
races_map = new map<uintptr_t, PossibleRace*>();
racecheck_map = new AddressMap();
visit_count_map = new VisitCountMap();
ignore_addresses = new set<uintptr_t>();
for (vector<string>::const_iterator it = fileNames.begin();
it != fileNames.end(); ++it) {
RaceVerifierParseFile(*it);
}
for (vector<string>::const_iterator it = raceInfos.begin();
it != raceInfos.end(); ++it) {
RaceVerifierParseRaceInfo(*it);
}
}
void RaceVerifierFini() {
Report("RaceVerifier summary: verified %d race(s)\n", n_reports);
int n_errors = GetNumberOfFoundErrors();
SetNumberOfFoundErrors(n_errors + n_reports);
}