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
43struct 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
56static map<uintptr_t, PossibleRace*>* races_map;
57
58// Data about a call site.
59struct CallSite {
60  int thread_id;
61  uintptr_t pc;
62};
63
64struct TypedCallSites {
65  vector<CallSite> reads;
66  vector<CallSite> writes;
67};
68
69// data address -> ([write callsites], [read callsites])
70typedef map<uintptr_t, TypedCallSites> AddressMap;
71
72static TSLock racecheck_lock;
73static AddressMap* racecheck_map;
74// data addresses that are ignored (they have already been reported)
75static set<uintptr_t>* ignore_addresses;
76
77// starting pc of the trace -> visit count
78// used to reduce the sleep time for hot traces
79typedef map<uintptr_t, int> VisitCountMap;
80static VisitCountMap* visit_count_map;
81
82static 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 */
90bool 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
118static 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*/
137static 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 */
156static 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*/
180static 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 */
226bool 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. */
265void 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. */
292static 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. */
323static 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
332class 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. */
358static 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 */
396int 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 */
424void 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
441void 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