Brian Silverman | f44f124 | 2015-12-05 20:19:48 -0500 | [diff] [blame^] | 1 | #include "aos/common/logging/binary_log_file.h" |
Brian Silverman | 003ba4b | 2014-02-10 16:56:18 -0800 | [diff] [blame] | 2 | |
| 3 | #include <stdio.h> |
Brian Silverman | 003ba4b | 2014-02-10 16:56:18 -0800 | [diff] [blame] | 4 | #include <string.h> |
| 5 | #include <sys/mman.h> |
| 6 | #include <sys/stat.h> |
| 7 | #include <unistd.h> |
Brian Silverman | 8a2e714 | 2014-03-12 22:17:34 -0700 | [diff] [blame] | 8 | #include <signal.h> |
| 9 | #include <setjmp.h> |
Brian Silverman | 003ba4b | 2014-02-10 16:56:18 -0800 | [diff] [blame] | 10 | |
| 11 | namespace aos { |
| 12 | namespace logging { |
| 13 | namespace linux_code { |
| 14 | namespace { |
| 15 | |
| 16 | unsigned long SystemPageSize() { |
| 17 | static unsigned long r = sysconf(_SC_PAGESIZE); |
| 18 | return r; |
| 19 | } |
| 20 | |
| 21 | } // namespace |
| 22 | |
| 23 | LogFileAccessor::LogFileAccessor(int fd, bool writable) |
| 24 | : fd_(fd), writable_(writable), offset_(0), current_(0), position_(0) { |
| 25 | // Check to make sure that mmap will allow mmaping in chunks of kPageSize. |
| 26 | if (SystemPageSize() > kPageSize || (kPageSize % SystemPageSize()) != 0) { |
| 27 | LOG(FATAL, "system page size (%lu) not factor of kPageSize (%zd).\n", |
| 28 | SystemPageSize(), kPageSize); |
| 29 | } |
| 30 | |
| 31 | MapNextPage(); |
| 32 | } |
| 33 | |
Brian Silverman | 003ba4b | 2014-02-10 16:56:18 -0800 | [diff] [blame] | 34 | void LogFileAccessor::Sync() const { |
| 35 | msync(current_, kPageSize, MS_ASYNC | MS_INVALIDATE); |
| 36 | } |
| 37 | |
Brian Silverman | f5ca4d0 | 2015-03-01 16:52:24 -0500 | [diff] [blame] | 38 | void LogFileAccessor::SkipToLastSeekablePage() { |
| 39 | CHECK(definitely_use_mmap()); |
| 40 | |
| 41 | struct stat info; |
| 42 | if (fstat(fd_, &info) == -1) { |
| 43 | PLOG(FATAL, "fstat(%d, %p) failed", fd_, &info); |
| 44 | } |
| 45 | |
| 46 | CHECK((info.st_size % kPageSize) == 0); |
| 47 | const auto last_readable_page_number = (info.st_size / kPageSize) - 1; |
| 48 | const auto last_seekable_page_number = |
| 49 | last_readable_page_number / kSeekPages * kSeekPages; |
| 50 | const off_t new_offset = last_seekable_page_number * kPageSize; |
| 51 | // We don't want to go backwards... |
| 52 | if (new_offset > offset_) { |
| 53 | Unmap(current_); |
| 54 | offset_ = new_offset; |
| 55 | MapNextPage(); |
| 56 | } |
| 57 | } |
| 58 | |
| 59 | // The only way to tell is using fstat, but we don't really want to be making a |
| 60 | // syscall every single time somebody wants to know the answer, so it gets |
| 61 | // cached in is_last_page_. |
Brian Silverman | f778031 | 2014-02-16 17:26:15 -0800 | [diff] [blame] | 62 | bool LogFileAccessor::IsLastPage() { |
Brian Silverman | 65e569d | 2014-10-24 15:43:20 -0400 | [diff] [blame] | 63 | if (is_last_page_ != Maybe::kUnknown) { |
| 64 | return is_last_page_ == Maybe::kYes; |
Brian Silverman | f778031 | 2014-02-16 17:26:15 -0800 | [diff] [blame] | 65 | } |
| 66 | |
Brian Silverman | 003ba4b | 2014-02-10 16:56:18 -0800 | [diff] [blame] | 67 | struct stat info; |
| 68 | if (fstat(fd_, &info) == -1) { |
Brian Silverman | 01be000 | 2014-05-10 15:44:38 -0700 | [diff] [blame] | 69 | PLOG(FATAL, "fstat(%d, %p) failed", fd_, &info); |
Brian Silverman | 003ba4b | 2014-02-10 16:56:18 -0800 | [diff] [blame] | 70 | } |
Brian Silverman | 9747834 | 2014-02-16 20:26:31 -0800 | [diff] [blame] | 71 | bool r = offset_ == static_cast<off_t>(info.st_size - kPageSize); |
Brian Silverman | 65e569d | 2014-10-24 15:43:20 -0400 | [diff] [blame] | 72 | is_last_page_ = r ? Maybe::kYes : Maybe::kNo; |
Brian Silverman | f778031 | 2014-02-16 17:26:15 -0800 | [diff] [blame] | 73 | return r; |
Brian Silverman | 003ba4b | 2014-02-10 16:56:18 -0800 | [diff] [blame] | 74 | } |
| 75 | |
| 76 | void LogFileAccessor::MapNextPage() { |
| 77 | if (writable_) { |
| 78 | if (ftruncate(fd_, offset_ + kPageSize) == -1) { |
Brian Silverman | 01be000 | 2014-05-10 15:44:38 -0700 | [diff] [blame] | 79 | PLOG(FATAL, "ftruncate(%d, %zd) failed", fd_, kPageSize); |
Brian Silverman | 003ba4b | 2014-02-10 16:56:18 -0800 | [diff] [blame] | 80 | } |
| 81 | } |
Brian Silverman | 65e569d | 2014-10-24 15:43:20 -0400 | [diff] [blame] | 82 | |
| 83 | if (use_read_ == Maybe::kYes) { |
| 84 | ssize_t todo = kPageSize; |
| 85 | while (todo > 0) { |
| 86 | ssize_t result = read(fd_, current_ + (kPageSize - todo), todo); |
| 87 | if (result == -1) { |
| 88 | PLOG(FATAL, "read(%d, %p, %zu) failed", fd_, |
| 89 | current_ + (kPageSize - todo), todo); |
Brian Silverman | 5c222b6 | 2014-12-20 16:42:54 -0800 | [diff] [blame] | 90 | } else if (result == 0) { |
| 91 | memset(current_, 0, todo); |
| 92 | result = todo; |
Brian Silverman | 65e569d | 2014-10-24 15:43:20 -0400 | [diff] [blame] | 93 | } |
| 94 | todo -= result; |
| 95 | } |
| 96 | CHECK_EQ(0, todo); |
| 97 | } else { |
| 98 | current_ = static_cast<char *>( |
| 99 | mmap(NULL, kPageSize, PROT_READ | (writable_ ? PROT_WRITE : 0), |
| 100 | MAP_SHARED, fd_, offset_)); |
| 101 | if (current_ == MAP_FAILED) { |
| 102 | if (!writable_ && use_read_ == Maybe::kUnknown && errno == ENODEV) { |
| 103 | LOG(INFO, "Falling back to reading the file using read(2).\n"); |
| 104 | use_read_ = Maybe::kYes; |
| 105 | current_ = new char[kPageSize]; |
| 106 | MapNextPage(); |
| 107 | return; |
| 108 | } else { |
| 109 | PLOG(FATAL, |
| 110 | "mmap(NULL, %zd, PROT_READ [ | PROT_WRITE], MAP_SHARED, %d, %jd)" |
| 111 | " failed", |
| 112 | kPageSize, fd_, static_cast<intmax_t>(offset_)); |
| 113 | } |
| 114 | } else { |
| 115 | use_read_ = Maybe::kNo; |
| 116 | } |
| 117 | if (madvise(current_, kPageSize, MADV_SEQUENTIAL | MADV_WILLNEED) == -1) { |
| 118 | PLOG(WARNING, "madvise(%p, %zd, MADV_SEQUENTIAL | MADV_WILLNEED) failed", |
| 119 | current_, kPageSize); |
| 120 | } |
Brian Silverman | 8a2e714 | 2014-03-12 22:17:34 -0700 | [diff] [blame] | 121 | } |
Brian Silverman | 003ba4b | 2014-02-10 16:56:18 -0800 | [diff] [blame] | 122 | offset_ += kPageSize; |
| 123 | } |
| 124 | |
| 125 | void LogFileAccessor::Unmap(void *location) { |
Brian Silverman | 65e569d | 2014-10-24 15:43:20 -0400 | [diff] [blame] | 126 | CHECK_NE(Maybe::kUnknown, use_read_); |
| 127 | |
| 128 | if (use_read_ == Maybe::kNo) { |
| 129 | if (munmap(location, kPageSize) == -1) { |
| 130 | PLOG(FATAL, "munmap(%p, %zd) failed", location, kPageSize); |
| 131 | } |
Brian Silverman | 003ba4b | 2014-02-10 16:56:18 -0800 | [diff] [blame] | 132 | } |
Brian Silverman | 65e569d | 2014-10-24 15:43:20 -0400 | [diff] [blame] | 133 | is_last_page_ = Maybe::kUnknown; |
Brian Silverman | ab5ba47 | 2014-04-18 15:26:14 -0700 | [diff] [blame] | 134 | position_ = 0; |
| 135 | } |
| 136 | |
| 137 | const LogFileMessageHeader *LogFileReader::ReadNextMessage(bool wait) { |
| 138 | LogFileMessageHeader *r; |
| 139 | do { |
| 140 | r = static_cast<LogFileMessageHeader *>( |
| 141 | static_cast<void *>(¤t()[position()])); |
| 142 | if (wait) { |
Brian Silverman | f5ca4d0 | 2015-03-01 16:52:24 -0500 | [diff] [blame] | 143 | CHECK(definitely_use_mmap()); |
Brian Silverman | ab5ba47 | 2014-04-18 15:26:14 -0700 | [diff] [blame] | 144 | if (futex_wait(&r->marker) != 0) continue; |
| 145 | } |
| 146 | if (r->marker == 2) { |
| 147 | Unmap(current()); |
| 148 | MapNextPage(); |
| 149 | CheckCurrentPageReadable(); |
| 150 | r = static_cast<LogFileMessageHeader *>(static_cast<void *>(current())); |
| 151 | } |
| 152 | } while (wait && r->marker == 0); |
| 153 | if (r->marker == 0) { |
| 154 | return NULL; |
| 155 | } |
| 156 | IncrementPosition(sizeof(LogFileMessageHeader) + r->name_size + |
| 157 | r->message_size); |
| 158 | if (position() >= kPageSize) { |
| 159 | // It's a lot better to blow up here rather than getting SIGBUS errors the |
| 160 | // next time we try to read... |
| 161 | LOG(FATAL, "corrupt log file running over page size\n"); |
| 162 | } |
| 163 | return r; |
Brian Silverman | 003ba4b | 2014-02-10 16:56:18 -0800 | [diff] [blame] | 164 | } |
| 165 | |
Brian Silverman | 8a2e714 | 2014-03-12 22:17:34 -0700 | [diff] [blame] | 166 | // This mess is because the only not completely hackish way to do this is to set |
| 167 | // up a handler for SIGBUS/SIGSEGV that siglongjmps out to avoid either the |
| 168 | // instruction being repeated infinitely (and more signals being delivered) or |
| 169 | // (with SA_RESETHAND) the signal killing the process. |
| 170 | namespace { |
| 171 | |
| 172 | void *volatile fault_address; |
| 173 | sigjmp_buf jump_context; |
| 174 | |
| 175 | void CheckCurrentPageReadableHandler(int /*signal*/, siginfo_t *info, void *) { |
| 176 | fault_address = info->si_addr; |
| 177 | |
| 178 | siglongjmp(jump_context, 1); |
| 179 | } |
| 180 | |
| 181 | } // namespace |
Brian Silverman | ab5ba47 | 2014-04-18 15:26:14 -0700 | [diff] [blame] | 182 | void LogFileReader::CheckCurrentPageReadable() { |
Brian Silverman | 65e569d | 2014-10-24 15:43:20 -0400 | [diff] [blame] | 183 | if (definitely_use_read()) return; |
| 184 | |
Brian Silverman | 8a2e714 | 2014-03-12 22:17:34 -0700 | [diff] [blame] | 185 | if (sigsetjmp(jump_context, 1) == 0) { |
| 186 | struct sigaction action; |
| 187 | action.sa_sigaction = CheckCurrentPageReadableHandler; |
| 188 | sigemptyset(&action.sa_mask); |
| 189 | action.sa_flags = SA_RESETHAND | SA_SIGINFO; |
| 190 | struct sigaction previous_bus, previous_segv; |
| 191 | if (sigaction(SIGBUS, &action, &previous_bus) == -1) { |
Brian Silverman | 01be000 | 2014-05-10 15:44:38 -0700 | [diff] [blame] | 192 | PLOG(FATAL, "sigaction(SIGBUS(=%d), %p, %p) failed", |
| 193 | SIGBUS, &action, &previous_bus); |
Brian Silverman | 8a2e714 | 2014-03-12 22:17:34 -0700 | [diff] [blame] | 194 | } |
| 195 | if (sigaction(SIGSEGV, &action, &previous_segv) == -1) { |
Brian Silverman | 01be000 | 2014-05-10 15:44:38 -0700 | [diff] [blame] | 196 | PLOG(FATAL, "sigaction(SIGSEGV(=%d), %p, %p) failed", |
| 197 | SIGSEGV, &action, &previous_segv); |
Brian Silverman | 8a2e714 | 2014-03-12 22:17:34 -0700 | [diff] [blame] | 198 | } |
| 199 | |
Brian Silverman | ab5ba47 | 2014-04-18 15:26:14 -0700 | [diff] [blame] | 200 | char __attribute__((unused)) c = current()[0]; |
Brian Silverman | 8a2e714 | 2014-03-12 22:17:34 -0700 | [diff] [blame] | 201 | |
| 202 | if (sigaction(SIGBUS, &previous_bus, NULL) == -1) { |
Brian Silverman | 01be000 | 2014-05-10 15:44:38 -0700 | [diff] [blame] | 203 | PLOG(FATAL, "sigaction(SIGBUS(=%d), %p, NULL) failed", |
| 204 | SIGBUS, &previous_bus); |
Brian Silverman | 8a2e714 | 2014-03-12 22:17:34 -0700 | [diff] [blame] | 205 | } |
| 206 | if (sigaction(SIGSEGV, &previous_segv, NULL) == -1) { |
Brian Silverman | 01be000 | 2014-05-10 15:44:38 -0700 | [diff] [blame] | 207 | PLOG(FATAL, "sigaction(SIGSEGV(=%d), %p, NULL) failed", |
| 208 | SIGSEGV, &previous_segv); |
Brian Silverman | 8a2e714 | 2014-03-12 22:17:34 -0700 | [diff] [blame] | 209 | } |
| 210 | } else { |
Brian Silverman | ab5ba47 | 2014-04-18 15:26:14 -0700 | [diff] [blame] | 211 | if (fault_address == current()) { |
Brian Silverman | 8a2e714 | 2014-03-12 22:17:34 -0700 | [diff] [blame] | 212 | LOG(FATAL, "could not read 1 byte at offset 0x%jx into log file\n", |
Brian Silverman | ab5ba47 | 2014-04-18 15:26:14 -0700 | [diff] [blame] | 213 | static_cast<uintmax_t>(offset())); |
Brian Silverman | 8a2e714 | 2014-03-12 22:17:34 -0700 | [diff] [blame] | 214 | } else { |
| 215 | LOG(FATAL, "faulted at %p, not %p like we were (maybe) supposed to\n", |
Brian Silverman | ab5ba47 | 2014-04-18 15:26:14 -0700 | [diff] [blame] | 216 | fault_address, current()); |
Brian Silverman | 8a2e714 | 2014-03-12 22:17:34 -0700 | [diff] [blame] | 217 | } |
| 218 | } |
| 219 | } |
| 220 | |
Brian Silverman | ab5ba47 | 2014-04-18 15:26:14 -0700 | [diff] [blame] | 221 | LogFileMessageHeader *LogFileWriter::GetWritePosition(size_t message_size) { |
Brian Silverman | f5ca4d0 | 2015-03-01 16:52:24 -0500 | [diff] [blame] | 222 | if (NeedNewPageFor(message_size)) ForceNewPage(); |
Brian Silverman | ab5ba47 | 2014-04-18 15:26:14 -0700 | [diff] [blame] | 223 | LogFileMessageHeader *const r = static_cast<LogFileMessageHeader *>( |
| 224 | static_cast<void *>(¤t()[position()])); |
| 225 | IncrementPosition(message_size); |
| 226 | return r; |
| 227 | } |
| 228 | |
Brian Silverman | f5ca4d0 | 2015-03-01 16:52:24 -0500 | [diff] [blame] | 229 | // A number of seekable pages, not the actual file offset, is stored in *cookie. |
| 230 | bool LogFileWriter::ShouldClearSeekableData(off_t *cookie, |
| 231 | size_t next_message_size) const { |
| 232 | off_t next_message_page = (offset() / kPageSize) - 1; |
| 233 | if (NeedNewPageFor(next_message_size)) { |
| 234 | ++next_message_page; |
| 235 | } |
| 236 | const off_t current_seekable_page = next_message_page / kSeekPages; |
| 237 | CHECK_LE(*cookie, current_seekable_page); |
| 238 | const bool r = *cookie != current_seekable_page; |
| 239 | *cookie = current_seekable_page; |
| 240 | return r; |
| 241 | } |
| 242 | |
| 243 | bool LogFileWriter::NeedNewPageFor(size_t bytes) const { |
| 244 | return position() + bytes + (kAlignment - (bytes % kAlignment)) + |
| 245 | sizeof(aos_futex) > |
| 246 | kPageSize; |
| 247 | } |
| 248 | |
| 249 | void LogFileWriter::ForceNewPage() { |
| 250 | char *const temp = current(); |
| 251 | MapNextPage(); |
| 252 | if (futex_set_value( |
| 253 | static_cast<aos_futex *>(static_cast<void *>(&temp[position()])), |
| 254 | 2) == -1) { |
| 255 | PLOG(WARNING, "readers will hang because futex_set_value(%p, 2) failed", |
| 256 | &temp[position()]); |
| 257 | } |
| 258 | Unmap(temp); |
| 259 | } |
| 260 | |
Brian Silverman | 003ba4b | 2014-02-10 16:56:18 -0800 | [diff] [blame] | 261 | } // namespace linux_code |
| 262 | } // namespace logging |
| 263 | } // namespace aos |