• Home
  • Line#
  • Scopes#
  • Navigate#
  • Raw
  • Download
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 {
PossibleRacePossibleRace44   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  */
RaceVerifierGetAddresses(uintptr_t min_pc,uintptr_t max_pc,uintptr_t * instrument_pc)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 
UpdateSummary()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 */
PrintRaceReportEmpty(uintptr_t addr)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  */
FindRaceForAddr(uintptr_t addr)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 */
PrintRaceReport(uintptr_t addr)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  */
RaceVerifierStartAccess(int thread_id,uintptr_t addr,uintptr_t pc,bool is_w)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. */
RaceVerifierEndAccess(int thread_id,uintptr_t addr,uintptr_t pc,bool is_w)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. */
ParseRaceInfo(const string & raceInfo)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. */
RaceVerifierParseRaceInfo(const string & raceInfo)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:
StringStream(const string & s)334   StringStream(const string &s) : s_(s), data_(s.c_str()), p_(data_) {}
335 
Eof()336   bool Eof() {
337     return !*p_;
338   }
339 
NextLine()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. */
RaceVerifierParseFile(const string & fileName)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  */
RaceVerifierGetSleepTime(uintptr_t trace_pc)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  */
RaceVerifierInit(const vector<string> & fileNames,const vector<string> & raceInfos)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 
RaceVerifierFini()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