kernel/log.cc

   1 /*
   2  *  yosys -- Yosys Open SYnthesis Suite
   3  *
   4  *  Copyright (C) 2012  Clifford Wolf <clifford@clifford.at>
   5  *
   6  *  Permission to use, copy, modify, and/or distribute this software for any
   7  *  purpose with or without fee is hereby granted, provided that the above
   8  *  copyright notice and this permission notice appear in all copies.
   9  *
  10  *  THE SOFTWARE IS PROVIDED "AS IS" AND THE AUTHOR DISCLAIMS ALL WARRANTIES
  11  *  WITH REGARD TO THIS SOFTWARE INCLUDING ALL IMPLIED WARRANTIES OF
  12  *  MERCHANTABILITY AND FITNESS. IN NO EVENT SHALL THE AUTHOR BE LIABLE FOR
  13  *  ANY SPECIAL, DIRECT, INDIRECT, OR CONSEQUENTIAL DAMAGES OR ANY DAMAGES
  14  *  WHATSOEVER RESULTING FROM LOSS OF USE, DATA OR PROFITS, WHETHER IN AN
  15  *  ACTION OF CONTRACT, NEGLIGENCE OR OTHER TORTIOUS ACTION, ARISING OUT OF
  16  *  OR IN CONNECTION WITH THE USE OR PERFORMANCE OF THIS SOFTWARE.
  17  *
  18  */
  19
  20 #include "kernel/yosys.h"
  21 #include "libs/sha1/sha1.h"
  22 #include "backends/ilang/ilang_backend.h"
  23
  24 #if !defined(_WIN32) || defined(__MINGW32__)
  25 #  include <sys/time.h>
  26 #endif
  27
  28 #include <stdlib.h>
  29 #include <stdio.h>
  30 #include <string.h>
  31 #include <stdarg.h>
  32 #include <vector>
  33 #include <list>
  34
  35 YOSYS_NAMESPACE_BEGIN
  36
  37 std::vector<FILE*> log_files;
  38 std::vector<std::ostream*> log_streams;
  39 FILE *log_errfile = NULL;
  40 SHA1 *log_hasher = NULL;
  41
  42 bool log_time = false;
  43 bool log_cmd_error_throw = false;
  44 int log_verbose_level;
  45
  46 std::vector<int> header_count;
  47 std::set<RTLIL::IdString> log_id_cache;
  48 std::list<std::string> string_buf;
  49 int string_buf_size = 0;
  50
  51 static struct timeval initial_tv = { 0, 0 };
  52 static bool next_print_log = false;
  53 static int log_newline_count = 0;
  54
  55 #if defined(_WIN32) && !defined(__MINGW32__)
  56 // this will get time information and return it in timeval, simulating gettimeofday()
  57 int gettimeofday(struct timeval *tv, struct timezone *tz)
  58 {
  59         LARGE_INTEGER counter;
  60         LARGE_INTEGER freq;
  61
  62         QueryPerformanceFrequency(&freq);
  63         QueryPerformanceCounter(&counter);
  64
  65         counter.QuadPart *= 1000000;
  66         counter.QuadPart /= freq.QuadPart;
  67
  68         tv->tv_sec = long(counter.QuadPart / 1000000);
  69         tv->tv_usec = counter.QuadPart % 1000000;
  70
  71         return 0;
  72 }
  73 #endif
  74
  75 void logv(const char *format, va_list ap)
  76 {
  77         while (format[0] == '\n' && format[1] != 0) {
  78                 log("\n");
  79                 format++;
  80         }
  81
  82         std::string str = vstringf(format, ap);
  83
  84         if (str.empty())
  85                 return;
  86
  87         size_t nnl_pos = str.find_last_not_of('\n');
  88         if (nnl_pos == std::string::npos)
  89                 log_newline_count += GetSize(str);
  90         else
  91                 log_newline_count = GetSize(str) - nnl_pos - 1;
  92
  93         if (log_hasher)
  94                 log_hasher->update(str);
  95
  96         if (log_time)
  97         {
  98                 std::string time_str;
  99
 100                 if (next_print_log || initial_tv.tv_sec == 0) {
 101                         next_print_log = false;
 102                         struct timeval tv;
 103                         gettimeofday(&tv, NULL);
 104                         if (initial_tv.tv_sec == 0)
 105                                 initial_tv = tv;
 106                         if (tv.tv_usec < initial_tv.tv_usec) {
 107                                 tv.tv_sec--;
 108                                 tv.tv_usec += 1000000;
 109                         }
 110                         tv.tv_sec -= initial_tv.tv_sec;
 111                         tv.tv_usec -= initial_tv.tv_usec;
 112                         time_str += stringf("[%05d.%06d] ", int(tv.tv_sec), int(tv.tv_usec));
 113                 }
 114
 115                 if (format[0] && format[strlen(format)-1] == '\n')
 116                         next_print_log = true;
 117
 118                 for (auto f : log_files)
 119                         fputs(time_str.c_str(), f);
 120
 121                 for (auto f : log_streams)
 122                         *f << time_str;
 123         }
 124
 125         for (auto f : log_files)
 126                 fputs(str.c_str(), f);
 127
 128         for (auto f : log_streams)
 129                 *f << str;
 130 }
 131
 132 void logv_header(const char *format, va_list ap)
 133 {
 134         bool pop_errfile = false;
 135
 136         log_spacer();
 137         if (header_count.size() > 0)
 138                 header_count.back()++;
 139
 140         if (int(header_count.size()) <= log_verbose_level && log_errfile != NULL) {
 141                 log_files.push_back(log_errfile);
 142                 pop_errfile = true;
 143         }
 144
 145         for (int c : header_count)
 146                 log("%d.", c);
 147         log(" ");
 148         logv(format, ap);
 149         log_flush();
 150
 151         if (pop_errfile)
 152                 log_files.pop_back();
 153 }
 154
 155 void logv_error(const char *format, va_list ap)
 156 {
 157         if (log_errfile != NULL)
 158                 log_files.push_back(log_errfile);
 159
 160         log("ERROR: ");
 161         logv(format, ap);
 162         log_flush();
 163         exit(1);
 164 }
 165
 166 void log(const char *format, ...)
 167 {
 168         va_list ap;
 169         va_start(ap, format);
 170         logv(format, ap);
 171         va_end(ap);
 172 }
 173
 174 void log_header(const char *format, ...)
 175 {
 176         va_list ap;
 177         va_start(ap, format);
 178         logv_header(format, ap);
 179         va_end(ap);
 180 }
 181
 182 void log_error(const char *format, ...)
 183 {
 184         va_list ap;
 185         va_start(ap, format);
 186         logv_error(format, ap);
 187 }
 188
 189 void log_cmd_error(const char *format, ...)
 190 {
 191         va_list ap;
 192         va_start(ap, format);
 193
 194         if (log_cmd_error_throw) {
 195                 log("ERROR: ");
 196                 logv(format, ap);
 197                 log_flush();
 198                 throw log_cmd_error_exception();
 199         }
 200
 201         logv_error(format, ap);
 202 }
 203
 204 void log_spacer()
 205 {
 206         while (log_newline_count < 2)
 207                 log("\n");
 208 }
 209
 210 void log_push()
 211 {
 212         header_count.push_back(0);
 213 }
 214
 215 void log_pop()
 216 {
 217         header_count.pop_back();
 218         log_id_cache.clear();
 219         string_buf.clear();
 220         string_buf_size = 0;
 221         log_flush();
 222 }
 223
 224 void log_reset_stack()
 225 {
 226         while (header_count.size() > 1)
 227                 header_count.pop_back();
 228         log_id_cache.clear();
 229         string_buf.clear();
 230         string_buf_size = 0;
 231         log_flush();
 232 }
 233
 234 void log_flush()
 235 {
 236         for (auto f : log_files)
 237                 fflush(f);
 238
 239         for (auto f : log_streams)
 240                 f->flush();
 241 }
 242
 243 void log_dump_val_worker(RTLIL::SigSpec v) {
 244         log("%s", log_signal(v));
 245 }
 246
 247 const char *log_signal(const RTLIL::SigSpec &sig, bool autoint)
 248 {
 249         std::stringstream buf;
 250         ILANG_BACKEND::dump_sigspec(buf, sig, autoint);
 251
 252         if (string_buf_size < 100)
 253                 string_buf_size++;
 254         else
 255                 string_buf.pop_front();
 256         string_buf.push_back(buf.str());
 257
 258         return string_buf.back().c_str();
 259 }
 260
 261 const char *log_id(RTLIL::IdString str)
 262 {
 263         log_id_cache.insert(str);
 264         const char *p = str.c_str();
 265         if (p[0] == '\\' && p[1] != '$' && p[1] != 0)
 266                 return p+1;
 267         return p;
 268 }
 269
 270 void log_cell(RTLIL::Cell *cell, std::string indent)
 271 {
 272         std::stringstream buf;
 273         ILANG_BACKEND::dump_cell(buf, indent, cell);
 274         log("%s", buf.str().c_str());
 275 }
 276
 277 // ---------------------------------------------------
 278 // This is the magic behind the code coverage counters
 279 // ---------------------------------------------------
 280 #ifdef YOSYS_ENABLE_COVER
 281
 282 std::map<std::string, std::pair<std::string, int>> extra_coverage_data;
 283
 284 void cover_extra(std::string parent, std::string id, bool increment) {
 285         if (extra_coverage_data.count(id) == 0) {
 286                 for (CoverData *p = __start_yosys_cover_list; p != __stop_yosys_cover_list; p++)
 287                         if (p->id == parent)
 288                                 extra_coverage_data[id].first = stringf("%s:%d:%s", p->file, p->line, p->func);
 289                 log_assert(extra_coverage_data.count(id));
 290         }
 291         if (increment)
 292                 extra_coverage_data[id].second++;
 293 }
 294
 295 std::map<std::string, std::pair<std::string, int>> get_coverage_data()
 296 {
 297         std::map<std::string, std::pair<std::string, int>> coverage_data;
 298
 299         for (auto &it : pass_register) {
 300                 std::string key = stringf("passes.%s", it.first.c_str());
 301                 coverage_data[key].first = stringf("%s:%d:%s", __FILE__, __LINE__, __FUNCTION__);
 302                 coverage_data[key].second += it.second->call_counter;
 303         }
 304
 305         for (auto &it : extra_coverage_data) {
 306                 if (coverage_data.count(it.first))
 307                         log("WARNING: found duplicate coverage id \"%s\".\n", it.first.c_str());
 308                 coverage_data[it.first].first = it.second.first;
 309                 coverage_data[it.first].second += it.second.second;
 310         }
 311
 312         for (CoverData *p = __start_yosys_cover_list; p != __stop_yosys_cover_list; p++) {
 313                 if (coverage_data.count(p->id))
 314                         log("WARNING: found duplicate coverage id \"%s\".\n", p->id);
 315                 coverage_data[p->id].first = stringf("%s:%d:%s", p->file, p->line, p->func);
 316                 coverage_data[p->id].second += p->counter;
 317         }
 318
 319         for (auto &it : coverage_data)
 320                 if (!it.second.first.compare(0, strlen(YOSYS_SRC "/"), YOSYS_SRC "/"))
 321                         it.second.first = it.second.first.substr(strlen(YOSYS_SRC "/"));
 322
 323         return coverage_data;
 324 }
 325
 326 #endif
 327
 328 YOSYS_NAMESPACE_END
 329