Skip to content

Commit 84cfcc2

Browse files
dvandercorpGerrit Code Review
authored and
Gerrit Code Review
committed
Merge "snapuserd: Include the misc device when logging in each snapuserd thread."
2 parents 9c4caa2 + 8d2bd03 commit 84cfcc2

File tree

1 file changed

+60
-56
lines changed

1 file changed

+60
-56
lines changed

fs_mgr/libsnapshot/snapuserd.cpp

+60-56
Original file line numberDiff line numberDiff line change
@@ -28,6 +28,9 @@ using namespace android;
2828
using namespace android::dm;
2929
using android::base::unique_fd;
3030

31+
#define SNAP_LOG(level) LOG(level) << misc_name_ << ": "
32+
#define SNAP_PLOG(level) PLOG(level) << misc_name_ << ": "
33+
3134
static constexpr size_t PAYLOAD_SIZE = (1UL << 16);
3235

3336
static_assert(PAYLOAD_SIZE >= BLOCK_SIZE);
@@ -94,7 +97,7 @@ void Snapuserd::ConstructKernelCowHeader() {
9497
// it will be de-compressed.
9598
bool Snapuserd::ProcessReplaceOp(const CowOperation* cow_op) {
9699
if (!reader_->ReadData(*cow_op, &bufsink_)) {
97-
LOG(ERROR) << "ReadData failed for chunk: " << cow_op->new_block;
100+
SNAP_LOG(ERROR) << "ReadData failed for chunk: " << cow_op->new_block;
98101
return false;
99102
}
100103

@@ -111,7 +114,7 @@ bool Snapuserd::ProcessCopyOp(const CowOperation* cow_op) {
111114
// if the successive blocks are contiguous.
112115
if (!android::base::ReadFullyAtOffset(backing_store_fd_, buffer, BLOCK_SIZE,
113116
cow_op->source * BLOCK_SIZE)) {
114-
LOG(ERROR) << "Copy-op failed. Read from backing store at: " << cow_op->source;
117+
SNAP_LOG(ERROR) << "Copy-op failed. Read from backing store at: " << cow_op->source;
115118
return false;
116119
}
117120

@@ -180,14 +183,14 @@ bool Snapuserd::ReadData(chunk_t chunk, size_t size) {
180183
}
181184

182185
default: {
183-
LOG(ERROR) << "Unknown operation-type found: " << cow_op->type;
186+
SNAP_LOG(ERROR) << "Unknown operation-type found: " << cow_op->type;
184187
ret = false;
185188
break;
186189
}
187190
}
188191

189192
if (!ret) {
190-
LOG(ERROR) << "ReadData failed for operation: " << cow_op->type;
193+
SNAP_LOG(ERROR) << "ReadData failed for operation: " << cow_op->type;
191194
return false;
192195
}
193196

@@ -322,7 +325,7 @@ loff_t Snapuserd::GetMergeStartOffset(void* merged_buffer, void* unmerged_buffer
322325

323326
CHECK(!(*unmerged_exceptions == exceptions_per_area_));
324327

325-
LOG(DEBUG) << "Unmerged_Exceptions: " << *unmerged_exceptions << " Offset: " << offset;
328+
SNAP_LOG(DEBUG) << "Unmerged_Exceptions: " << *unmerged_exceptions << " Offset: " << offset;
326329
return offset;
327330
}
328331

@@ -355,11 +358,11 @@ int Snapuserd::GetNumberOfMergedOps(void* merged_buffer, void* unmerged_buffer,
355358
CHECK(cow_de->new_chunk == 0);
356359
break;
357360
} else {
358-
LOG(ERROR) << "Error in merge operation. Found invalid metadata";
359-
LOG(ERROR) << "merged_de-old-chunk: " << merged_de->old_chunk;
360-
LOG(ERROR) << "merged_de-new-chunk: " << merged_de->new_chunk;
361-
LOG(ERROR) << "cow_de-old-chunk: " << cow_de->old_chunk;
362-
LOG(ERROR) << "cow_de-new-chunk: " << cow_de->new_chunk;
361+
SNAP_LOG(ERROR) << "Error in merge operation. Found invalid metadata";
362+
SNAP_LOG(ERROR) << "merged_de-old-chunk: " << merged_de->old_chunk;
363+
SNAP_LOG(ERROR) << "merged_de-new-chunk: " << merged_de->new_chunk;
364+
SNAP_LOG(ERROR) << "cow_de-old-chunk: " << cow_de->old_chunk;
365+
SNAP_LOG(ERROR) << "cow_de-new-chunk: " << cow_de->new_chunk;
363366
return -1;
364367
}
365368
}
@@ -384,19 +387,19 @@ bool Snapuserd::AdvanceMergedOps(int merged_ops_cur_iter) {
384387

385388
if (!(cow_op->type == kCowReplaceOp || cow_op->type == kCowZeroOp ||
386389
cow_op->type == kCowCopyOp)) {
387-
LOG(ERROR) << "Unknown operation-type found during merge: " << cow_op->type;
390+
SNAP_LOG(ERROR) << "Unknown operation-type found during merge: " << cow_op->type;
388391
return false;
389392
}
390393

391394
merged_ops_cur_iter -= 1;
392-
LOG(DEBUG) << "Merge op found of type " << cow_op->type
393-
<< "Pending-merge-ops: " << merged_ops_cur_iter;
395+
SNAP_LOG(DEBUG) << "Merge op found of type " << cow_op->type
396+
<< "Pending-merge-ops: " << merged_ops_cur_iter;
394397
cowop_iter_->Next();
395398
}
396399

397400
if (cowop_iter_->Done()) {
398401
CHECK(merged_ops_cur_iter == 0);
399-
LOG(DEBUG) << "All cow operations merged successfully in this cycle";
402+
SNAP_LOG(DEBUG) << "All cow operations merged successfully in this cycle";
400403
}
401404

402405
return true;
@@ -407,14 +410,15 @@ bool Snapuserd::ProcessMergeComplete(chunk_t chunk, void* buffer) {
407410
CowHeader header;
408411

409412
if (!reader_->GetHeader(&header)) {
410-
LOG(ERROR) << "Failed to get header";
413+
SNAP_LOG(ERROR) << "Failed to get header";
411414
return false;
412415
}
413416

414417
// ChunkID to vector index
415418
lldiv_t divresult = lldiv(chunk, stride);
416419
CHECK(divresult.quot < vec_.size());
417-
LOG(DEBUG) << "ProcessMergeComplete: chunk: " << chunk << " Metadata-Index: " << divresult.quot;
420+
SNAP_LOG(DEBUG) << "ProcessMergeComplete: chunk: " << chunk
421+
<< " Metadata-Index: " << divresult.quot;
418422

419423
int unmerged_exceptions = 0;
420424
loff_t offset = GetMergeStartOffset(buffer, vec_[divresult.quot].get(), &unmerged_exceptions);
@@ -429,11 +433,11 @@ bool Snapuserd::ProcessMergeComplete(chunk_t chunk, void* buffer) {
429433
header.num_merge_ops += merged_ops_cur_iter;
430434
reader_->UpdateMergeProgress(merged_ops_cur_iter);
431435
if (!writer_->CommitMerge(merged_ops_cur_iter)) {
432-
LOG(ERROR) << "CommitMerge failed...";
436+
SNAP_LOG(ERROR) << "CommitMerge failed...";
433437
return false;
434438
}
435439

436-
LOG(DEBUG) << "Merge success";
440+
SNAP_LOG(DEBUG) << "Merge success";
437441
return true;
438442
}
439443

@@ -513,21 +517,21 @@ bool Snapuserd::ReadMetadata() {
513517
bool prev_copy_op = false;
514518
bool metadata_found = false;
515519

516-
LOG(DEBUG) << "ReadMetadata Start...";
520+
SNAP_LOG(DEBUG) << "ReadMetadata Start...";
517521

518522
if (!reader_->Parse(cow_fd_)) {
519-
LOG(ERROR) << "Failed to parse";
523+
SNAP_LOG(ERROR) << "Failed to parse";
520524
return false;
521525
}
522526

523527
if (!reader_->GetHeader(&header)) {
524-
LOG(ERROR) << "Failed to get header";
528+
SNAP_LOG(ERROR) << "Failed to get header";
525529
return false;
526530
}
527531

528532
CHECK(header.block_size == BLOCK_SIZE);
529533

530-
LOG(DEBUG) << "Merge-ops: " << header.num_merge_ops;
534+
SNAP_LOG(DEBUG) << "Merge-ops: " << header.num_merge_ops;
531535

532536
writer_ = std::make_unique<CowWriter>(options);
533537
writer_->InitializeMerge(cow_fd_.get(), &header);
@@ -563,7 +567,7 @@ bool Snapuserd::ReadMetadata() {
563567

564568
if (!(cow_op->type == kCowReplaceOp || cow_op->type == kCowZeroOp ||
565569
cow_op->type == kCowCopyOp)) {
566-
LOG(ERROR) << "Unknown operation-type found: " << cow_op->type;
570+
SNAP_LOG(ERROR) << "Unknown operation-type found: " << cow_op->type;
567571
return false;
568572
}
569573

@@ -578,7 +582,7 @@ bool Snapuserd::ReadMetadata() {
578582
de->old_chunk = cow_op->new_block;
579583
de->new_chunk = next_free;
580584

581-
LOG(DEBUG) << "Old-chunk: " << de->old_chunk << "New-chunk: " << de->new_chunk;
585+
SNAP_LOG(DEBUG) << "Old-chunk: " << de->old_chunk << "New-chunk: " << de->new_chunk;
582586

583587
// Store operation pointer.
584588
chunk_map_[next_free] = cow_op;
@@ -602,7 +606,7 @@ bool Snapuserd::ReadMetadata() {
602606

603607
if (cowop_riter_->Done()) {
604608
vec_.push_back(std::move(de_ptr));
605-
LOG(DEBUG) << "ReadMetadata() completed; Number of Areas: " << vec_.size();
609+
SNAP_LOG(DEBUG) << "ReadMetadata() completed; Number of Areas: " << vec_.size();
606610
}
607611
}
608612

@@ -614,12 +618,12 @@ bool Snapuserd::ReadMetadata() {
614618
// is aware that merge is completed.
615619
if (num_ops || !metadata_found) {
616620
vec_.push_back(std::move(de_ptr));
617-
LOG(DEBUG) << "ReadMetadata() completed. Partially filled area num_ops: " << num_ops
618-
<< "Areas : " << vec_.size();
621+
SNAP_LOG(DEBUG) << "ReadMetadata() completed. Partially filled area num_ops: " << num_ops
622+
<< "Areas : " << vec_.size();
619623
}
620624

621-
LOG(DEBUG) << "ReadMetadata() completed. chunk_id: " << next_free
622-
<< "Num Sector: " << ChunkToSector(next_free);
625+
SNAP_LOG(DEBUG) << "ReadMetadata() completed. chunk_id: " << next_free
626+
<< "Num Sector: " << ChunkToSector(next_free);
623627

624628
// Initialize the iterator for merging
625629
cowop_iter_ = reader_->GetOpIter();
@@ -643,7 +647,7 @@ void MyLogger(android::base::LogId, android::base::LogSeverity severity, const c
643647
// us the sector number for which IO is issued by dm-snapshot device
644648
bool Snapuserd::ReadDmUserHeader() {
645649
if (!android::base::ReadFully(ctrl_fd_, bufsink_.GetBufPtr(), sizeof(struct dm_user_header))) {
646-
PLOG(ERROR) << "ReadDmUserHeader failed";
650+
SNAP_PLOG(ERROR) << "Control-read failed";
647651
return false;
648652
}
649653

@@ -654,7 +658,7 @@ bool Snapuserd::ReadDmUserHeader() {
654658
bool Snapuserd::WriteDmUserPayload(size_t size) {
655659
if (!android::base::WriteFully(ctrl_fd_, bufsink_.GetBufPtr(),
656660
sizeof(struct dm_user_header) + size)) {
657-
PLOG(ERROR) << "Write to dm-user failed";
661+
SNAP_PLOG(ERROR) << "Write to dm-user failed";
658662
return false;
659663
}
660664

@@ -663,7 +667,7 @@ bool Snapuserd::WriteDmUserPayload(size_t size) {
663667

664668
bool Snapuserd::ReadDmUserPayload(void* buffer, size_t size) {
665669
if (!android::base::ReadFully(ctrl_fd_, buffer, size)) {
666-
PLOG(ERROR) << "ReadDmUserPayload failed";
670+
SNAP_PLOG(ERROR) << "ReadDmUserPayload failed";
667671
return false;
668672
}
669673

@@ -673,7 +677,7 @@ bool Snapuserd::ReadDmUserPayload(void* buffer, size_t size) {
673677
bool Snapuserd::InitCowDevice() {
674678
cow_fd_.reset(open(cow_device_.c_str(), O_RDWR));
675679
if (cow_fd_ < 0) {
676-
PLOG(ERROR) << "Open Failed: " << cow_device_;
680+
SNAP_PLOG(ERROR) << "Open Failed: " << cow_device_;
677681
return false;
678682
}
679683

@@ -690,13 +694,13 @@ bool Snapuserd::InitCowDevice() {
690694
bool Snapuserd::InitBackingAndControlDevice() {
691695
backing_store_fd_.reset(open(backing_store_device_.c_str(), O_RDONLY));
692696
if (backing_store_fd_ < 0) {
693-
PLOG(ERROR) << "Open Failed: " << backing_store_device_;
697+
SNAP_PLOG(ERROR) << "Open Failed: " << backing_store_device_;
694698
return false;
695699
}
696700

697701
ctrl_fd_.reset(open(control_device_.c_str(), O_RDWR));
698702
if (ctrl_fd_ < 0) {
699-
PLOG(ERROR) << "Unable to open " << control_device_;
703+
SNAP_PLOG(ERROR) << "Unable to open " << control_device_;
700704
return false;
701705
}
702706

@@ -709,15 +713,15 @@ bool Snapuserd::Run() {
709713
bufsink_.Clear();
710714

711715
if (!ReadDmUserHeader()) {
712-
LOG(ERROR) << "ReadDmUserHeader failed";
716+
SNAP_LOG(ERROR) << "ReadDmUserHeader failed";
713717
return false;
714718
}
715719

716-
LOG(DEBUG) << "msg->seq: " << std::hex << header->seq;
717-
LOG(DEBUG) << "msg->type: " << std::hex << header->type;
718-
LOG(DEBUG) << "msg->flags: " << std::hex << header->flags;
719-
LOG(DEBUG) << "msg->sector: " << std::hex << header->sector;
720-
LOG(DEBUG) << "msg->len: " << std::hex << header->len;
720+
SNAP_LOG(DEBUG) << "msg->seq: " << std::hex << header->seq;
721+
SNAP_LOG(DEBUG) << "msg->type: " << std::hex << header->type;
722+
SNAP_LOG(DEBUG) << "msg->flags: " << std::hex << header->flags;
723+
SNAP_LOG(DEBUG) << "msg->sector: " << std::hex << header->sector;
724+
SNAP_LOG(DEBUG) << "msg->len: " << std::hex << header->len;
721725

722726
switch (header->type) {
723727
case DM_USER_REQ_MAP_READ: {
@@ -736,7 +740,7 @@ bool Snapuserd::Run() {
736740
CHECK(metadata_read_done_ == true);
737741
CHECK(read_size == BLOCK_SIZE);
738742
ConstructKernelCowHeader();
739-
LOG(DEBUG) << "Kernel header constructed";
743+
SNAP_LOG(DEBUG) << "Kernel header constructed";
740744
} else {
741745
// Convert the sector number to a chunk ID.
742746
//
@@ -747,22 +751,22 @@ bool Snapuserd::Run() {
747751

748752
if (chunk_map_.find(chunk) == chunk_map_.end()) {
749753
if (!ReadDiskExceptions(chunk, read_size)) {
750-
LOG(ERROR) << "ReadDiskExceptions failed for chunk id: " << chunk
751-
<< "Sector: " << header->sector;
754+
SNAP_LOG(ERROR) << "ReadDiskExceptions failed for chunk id: " << chunk
755+
<< "Sector: " << header->sector;
752756
header->type = DM_USER_RESP_ERROR;
753757
} else {
754-
LOG(DEBUG) << "ReadDiskExceptions success for chunk id: " << chunk
755-
<< "Sector: " << header->sector;
758+
SNAP_LOG(DEBUG) << "ReadDiskExceptions success for chunk id: " << chunk
759+
<< "Sector: " << header->sector;
756760
}
757761
} else {
758762
chunk_t num_chunks_read = (offset >> BLOCK_SHIFT);
759763
if (!ReadData(chunk + num_chunks_read, read_size)) {
760-
LOG(ERROR) << "ReadData failed for chunk id: " << chunk
761-
<< "Sector: " << header->sector;
764+
SNAP_LOG(ERROR) << "ReadData failed for chunk id: " << chunk
765+
<< "Sector: " << header->sector;
762766
header->type = DM_USER_RESP_ERROR;
763767
} else {
764-
LOG(DEBUG) << "ReadData success for chunk id: " << chunk
765-
<< "Sector: " << header->sector;
768+
SNAP_LOG(DEBUG) << "ReadData success for chunk id: " << chunk
769+
<< "Sector: " << header->sector;
766770
}
767771
}
768772
}
@@ -817,18 +821,18 @@ bool Snapuserd::Run() {
817821
header->type = DM_USER_RESP_SUCCESS;
818822

819823
if (!ReadDmUserPayload(buffer, read_size)) {
820-
LOG(ERROR) << "ReadDmUserPayload failed for chunk id: " << chunk
821-
<< "Sector: " << header->sector;
824+
SNAP_LOG(ERROR) << "ReadDmUserPayload failed for chunk id: " << chunk
825+
<< "Sector: " << header->sector;
822826
header->type = DM_USER_RESP_ERROR;
823827
}
824828

825829
if (header->type == DM_USER_RESP_SUCCESS && !ProcessMergeComplete(chunk, buffer)) {
826-
LOG(ERROR) << "ProcessMergeComplete failed for chunk id: " << chunk
827-
<< "Sector: " << header->sector;
830+
SNAP_LOG(ERROR) << "ProcessMergeComplete failed for chunk id: " << chunk
831+
<< "Sector: " << header->sector;
828832
header->type = DM_USER_RESP_ERROR;
829833
} else {
830-
LOG(DEBUG) << "ProcessMergeComplete success for chunk id: " << chunk
831-
<< "Sector: " << header->sector;
834+
SNAP_LOG(DEBUG) << "ProcessMergeComplete success for chunk id: " << chunk
835+
<< "Sector: " << header->sector;
832836
}
833837

834838
if (!WriteDmUserPayload(0)) {

0 commit comments

Comments
 (0)