Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Add log timestamp #455

Open
wants to merge 1 commit into
base: master
Choose a base branch
from
Open

Add log timestamp #455

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
1 commit
Select commit
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
8 changes: 4 additions & 4 deletions include/chia/phase1.hpp
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -281,7 +281,7 @@ void compute_f1(const uint8_t* id, int num_threads, DS* T1_sort)
output.close();
T1_sort->finish();

std::cout << "[P1] Table 1 took " << (get_wall_time_micros() - begin) / 1e6 << " sec" << std::endl;
std::cout << get_curr_datetime() << " [P1] Table 1 took " << (get_wall_time_micros() - begin) / 1e6 << " sec" << std::endl;
}

template<typename T, typename S, typename R, typename DS_L, typename DS_R>
Expand Down Expand Up @@ -400,7 +400,7 @@ uint64_t compute_matches( int R_index, int num_threads,
R_sort->finish();
}
if(num_written < num_found) {
// std::cout << "[P1] Lost " << num_found - num_written
// std::cout << get_curr_datetime() << " [P1] Lost " << num_found - num_written
// << " matches due to 32-bit overflow." << std::endl;
}
return num_written;
Expand Down Expand Up @@ -443,7 +443,7 @@ uint64_t compute_table( int R_index, int num_threads,
if(R_tmp) {
R_tmp->close();
}
std::cout << "[P1] Table " << R_index << " took " << (get_wall_time_micros() - begin) / 1e6 << " sec"
std::cout << get_curr_datetime() << " [P1] Table " << R_index << " took " << (get_wall_time_micros() - begin) / 1e6 << " sec"
<< ", found " << num_matches << " matches" << std::endl;
return num_matches;
}
Expand Down Expand Up @@ -504,7 +504,7 @@ void compute( const input_t& input, output_t& out,
out.table[5] = tmp_6.get_info();
out.table[6] = tmp_7.get_info();

std::cout << "Phase 1 took " << (get_wall_time_micros() - total_begin) / 1e6 << " sec" << std::endl;
std::cout << get_curr_datetime() << " Phase 1 took " << (get_wall_time_micros() - total_begin) / 1e6 << " sec" << std::endl;
}


Expand Down
8 changes: 4 additions & 4 deletions include/chia/phase2.hpp
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -46,7 +46,7 @@ void compute_table( int R_index, int num_threads,
R_input.read(&pool, num_threads_read);
pool.close();

std::cout << "[P2] Table " << R_index << " scan took "
std::cout << get_curr_datetime() << " [P2] Table " << R_index << " scan took "
<< (get_wall_time_micros() - begin) / 1e6 << " sec" << std::endl;
}
const auto begin = get_wall_time_micros();
Expand Down Expand Up @@ -116,7 +116,7 @@ void compute_table( int R_index, int num_threads,
if(R_file) {
R_file->flush();
}
std::cout << "[P2] Table " << R_index << " rewrite took "
std::cout << get_curr_datetime() << " [P2] Table " << R_index << " rewrite took "
<< (get_wall_time_micros() - begin) / 1e6 << " sec"
<< ", dropped " << R_table.num_entries - num_written << " entries"
<< " (" << 100 * (1 - double(num_written) / R_table.num_entries) << " %)" << std::endl;
Expand All @@ -138,7 +138,7 @@ void compute( const phase1::output_t& input, output_t& out,
for(const auto& table : input.table) {
max_table_size = std::max(max_table_size, table.num_entries);
}
std::cout << "[P2] max_table_size = " << max_table_size << std::endl;
std::cout << get_curr_datetime() << " [P2] max_table_size = " << max_table_size << std::endl;

auto curr_bitfield = std::make_shared<bitfield>(max_table_size);
auto next_bitfield = std::make_shared<bitfield>(max_table_size);
Expand Down Expand Up @@ -167,7 +167,7 @@ void compute( const phase1::output_t& input, output_t& out,
out.table_7 = table_7.get_info();
out.bitfield_1 = next_bitfield;

std::cout << "Phase 2 took " << (get_wall_time_micros() - total_begin) / 1e6 << " sec" << std::endl;
std::cout << get_curr_datetime() << " Phase 2 took " << (get_wall_time_micros() - total_begin) / 1e6 << " sec" << std::endl;
}


Expand Down
10 changes: 5 additions & 5 deletions include/chia/phase3.hpp
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -195,7 +195,7 @@ void compute_stage1(int L_index, int num_threads,

R_sort_2->finish();

std::cout << "[P3-1] Table " << L_index + 1 << " took "
std::cout << get_curr_datetime() << " [P3-1] Table " << L_index + 1 << " took "
<< (get_wall_time_micros() - begin) / 1e6 << " sec"
<< ", wrote " << R_num_write << " right entries" << std::endl;
}
Expand Down Expand Up @@ -261,7 +261,7 @@ uint32_t WriteHeader(
num_bytes += fwrite((pointers), 8, 10, file) * 8;

fflush(file);
std::cout << "Wrote plot header with " << num_bytes << " bytes" << std::endl;
std::cout << get_curr_datetime() << " Wrote plot header with " << num_bytes << " bytes" << std::endl;
return num_bytes;
}

Expand Down Expand Up @@ -460,9 +460,9 @@ uint64_t compute_stage2(int L_index, int num_threads,
Encoding::ANSFree(kRValues[L_index - 1]);

if(L_num_write < R_num_read) {
// std::cout << "[P3-2] Lost " << R_num_read - L_num_write << " entries due to 32-bit overflow." << std::endl;
// std::cout << get_curr_datetime() << " [P3-2] Lost " << R_num_read - L_num_write << " entries due to 32-bit overflow." << std::endl;
}
std::cout << "[P3-2] Table " << L_index + 1 << " took "
std::cout << get_curr_datetime() << " [P3-2] Table " << L_index + 1 << " took "
<< (get_wall_time_micros() - begin) / 1e6 << " sec"
<< ", wrote " << L_num_write << " left entries"
<< ", " << num_written_final << " final" << std::endl;
Expand Down Expand Up @@ -559,7 +559,7 @@ void compute( phase2::output_t& input, output_t& out,
out.num_written_7 = num_written_final_7;
out.final_pointer_7 = final_pointers[7];

std::cout << "Phase 3 took " << (get_wall_time_micros() - total_begin) / 1e6 << " sec"
std::cout << get_curr_datetime() << " Phase 3 took " << (get_wall_time_micros() - total_begin) / 1e6 << " sec"
", wrote " << num_written_final << " entries to final plot" << std::endl;
}

Expand Down
10 changes: 5 additions & 5 deletions include/chia/phase4.hpp
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -79,7 +79,7 @@ uint64_t compute( FILE* plot_file, const int header_size,

std::vector<uint32_t> C2;

std::cout << "[P4] Starting to write C1 and C3 tables" << std::endl;
std::cout << get_curr_datetime() << " [P4] Starting to write C1 and C3 tables" << std::endl;

struct park_deltas_t {
uint64_t offset = 0;
Expand Down Expand Up @@ -215,8 +215,8 @@ uint64_t compute( FILE* plot_file, const int header_size,
final_file_writer_1 +=
fwrite_at(plot_file, final_file_writer_1, C1_entry_buf, sizeof(C1_entry_buf));

std::cout << "[P4] Finished writing C1 and C3 tables" << std::endl;
std::cout << "[P4] Writing C2 table" << std::endl;
std::cout << get_curr_datetime() << " [P4] Finished writing C1 and C3 tables" << std::endl;
std::cout << get_curr_datetime() << " [P4] Writing C2 table" << std::endl;

for(const uint64_t C2_entry : C2) {
Bits(C2_entry, k).ToBytes(C1_entry_buf);
Expand All @@ -227,7 +227,7 @@ uint64_t compute( FILE* plot_file, const int header_size,
final_file_writer_1 +=
fwrite_at(plot_file, final_file_writer_1, C1_entry_buf, sizeof(C1_entry_buf));

std::cout << "[P4] Finished writing C2 table" << std::endl;
std::cout << get_curr_datetime() << " [P4] Finished writing C2 table" << std::endl;

final_file_writer_1 = header_size - 8 * 3;
uint8_t table_pointer_bytes[8] = {};
Expand Down Expand Up @@ -265,7 +265,7 @@ void compute( const phase3::output_t& input, output_t& out,

std::rename(input.plot_file_name.c_str(), out.plot_file_name.c_str());

std::cout << "Phase 4 took " << (get_wall_time_micros() - total_begin) / 1e6 << " sec"
std::cout << get_curr_datetime() << " Phase 4 took " << (get_wall_time_micros() - total_begin) / 1e6 << " sec"
", final plot size is " << out.plot_size << " bytes" << std::endl;
}

Expand Down
10 changes: 10 additions & 0 deletions include/chia/util.hpp
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -375,6 +375,16 @@ namespace Util {
}
}

inline
std::string get_curr_datetime()
Copy link
Owner

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

there's already a function for that, see get_date_string_ex()

Copy link
Owner

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

you can call that function inside this one

{
time_t now;
time(&now);
char buf[sizeof "YYYY-MM-ddTHH:mm:ssZ"];
strftime(buf, sizeof buf, "%FT%TZ", gmtime(&now));
return std::string( buf );
}

inline
int64_t get_wall_time_micros() {
return std::chrono::duration_cast<std::chrono::microseconds>(std::chrono::system_clock::now().time_since_epoch()).count();
Expand Down
36 changes: 18 additions & 18 deletions src/chia_plot.cpp
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -62,27 +62,27 @@ phase4::output_t create_plot( const int num_threads,
{
const auto total_begin = get_wall_time_micros();

std::cout << "Process ID: " << GETPID() << std::endl;
std::cout << "Number of Threads: " << num_threads << std::endl;
std::cout << "Number of Buckets: 2^" << log_num_buckets
std::cout << get_curr_datetime() << " Process ID: " << GETPID() << std::endl;
std::cout << get_curr_datetime() << " Number of Threads: " << num_threads << std::endl;
std::cout << get_curr_datetime() << " Number of Buckets: 2^" << log_num_buckets
<< " (" << (1 << log_num_buckets) << ")" << std::endl;

bls::G1Element pool_key;
bls::G1Element farmer_key;
try {
pool_key = bls::G1Element::FromByteVector(pool_key_bytes);
} catch(std::exception& ex) {
std::cout << "Invalid poolkey: " << bls::Util::HexStr(pool_key_bytes) << std::endl;
std::cout << get_curr_datetime() << " Invalid poolkey: " << bls::Util::HexStr(pool_key_bytes) << std::endl;
throw;
}
try {
farmer_key = bls::G1Element::FromByteVector(farmer_key_bytes);
} catch(std::exception& ex) {
std::cout << "Invalid farmerkey: " << bls::Util::HexStr(farmer_key_bytes) << std::endl;
std::cout << get_curr_datetime() << " Invalid farmerkey: " << bls::Util::HexStr(farmer_key_bytes) << std::endl;
throw;
}
std::cout << "Pool Public Key: " << bls::Util::HexStr(pool_key.Serialize()) << std::endl;
std::cout << "Farmer Public Key: " << bls::Util::HexStr(farmer_key.Serialize()) << std::endl;
std::cout << get_curr_datetime() << " Pool Public Key: " << bls::Util::HexStr(pool_key.Serialize()) << std::endl;
std::cout << get_curr_datetime() << " Farmer Public Key: " << bls::Util::HexStr(farmer_key.Serialize()) << std::endl;

vector<uint8_t> seed(32);
randombytes_buf(seed.data(), seed.size());
Expand All @@ -109,9 +109,9 @@ phase4::output_t create_plot( const int num_threads,
const std::string plot_name = "plot-k32-" + get_date_string_ex("%Y-%m-%d-%H-%M")
+ "-" + bls::Util::HexStr(params.id.data(), params.id.size());

std::cout << "Working Directory: " << (tmp_dir.empty() ? "$PWD" : tmp_dir) << std::endl;
std::cout << "Working Directory 2: " << (tmp_dir_2.empty() ? "$PWD" : tmp_dir_2) << std::endl;
std::cout << "Plot Name: " << plot_name << std::endl;
std::cout << get_curr_datetime() << " Working Directory: " << (tmp_dir.empty() ? "$PWD" : tmp_dir) << std::endl;
std::cout << get_curr_datetime() << " Working Directory 2: " << (tmp_dir_2.empty() ? "$PWD" : tmp_dir_2) << std::endl;
std::cout << get_curr_datetime() << " Plot Name: " << plot_name << std::endl;

// memo = bytes(pool_public_key) + bytes(farmer_public_key) + bytes(local_master_sk)
params.memo.insert(params.memo.end(), pool_key_bytes.begin(), pool_key_bytes.end());
Expand All @@ -135,7 +135,7 @@ phase4::output_t create_plot( const int num_threads,
phase4::compute(out_3, out_4, num_threads, log_num_buckets, plot_name, tmp_dir, tmp_dir_2);

const auto time_secs = (get_wall_time_micros() - total_begin) / 1e6;
std::cout << "Total plot creation time was "
std::cout << get_curr_datetime() << " Total plot creation time was "
<< time_secs << " sec (" << time_secs / 60. << " min)" << std::endl;
return out_4;
}
Expand Down Expand Up @@ -312,11 +312,11 @@ int main(int argc, char** argv)
std::cout << " - " << GIT_COMMIT_HASH;
#endif
std::cout << std::endl;
std::cout << "Final Directory: " << final_dir << std::endl;
std::cout << get_curr_datetime() << " Final Directory: " << final_dir << std::endl;
if(num_plots >= 0) {
std::cout << "Number of Plots: " << num_plots << std::endl;
std::cout << get_curr_datetime() << " Number of Plots: " << num_plots << std::endl;
} else {
std::cout << "Number of Plots: infinite" << std::endl;
std::cout << get_curr_datetime() << " Number of Plots: infinite" << std::endl;
}

Thread<std::pair<std::string, std::string>> copy_thread(
Expand All @@ -327,11 +327,11 @@ int main(int argc, char** argv)
const auto bytes = final_copy(from_to.first, from_to.second);

const auto time = (get_wall_time_micros() - total_begin) / 1e6;
std::cout << "Copy to " << from_to.second << " finished, took " << time << " sec, "
std::cout << get_curr_datetime() << " Copy to " << from_to.second << " finished, took " << time << " sec, "
<< ((bytes / time) / 1024 / 1024) << " MB/s avg." << std::endl;
break;
} catch(const std::exception& ex) {
std::cout << "Copy to " << from_to.second << " failed with: " << ex.what() << std::endl;
std::cout << get_curr_datetime() << " Copy to " << from_to.second << " failed with: " << ex.what() << std::endl;
std::this_thread::sleep_for(std::chrono::minutes(5));
}
}
Expand All @@ -343,13 +343,13 @@ int main(int argc, char** argv)
std::cout << std::endl << "Process has been interrupted, waiting for copy/rename operations to finish ..." << std::endl;
break;
}
std::cout << "Crafting plot " << i+1 << " out of " << num_plots << std::endl;
std::cout << get_curr_datetime() << " Crafting plot " << i+1 << " out of " << num_plots << std::endl;
const auto out = create_plot(num_threads, log_num_buckets, pool_key, farmer_key, tmp_dir, tmp_dir2);

if(final_dir != tmp_dir)
{
const auto dst_path = final_dir + out.params.plot_name + ".plot";
std::cout << "Started copy to " << dst_path << std::endl;
std::cout << get_curr_datetime() << " Started copy to " << dst_path << std::endl;
copy_thread.take_copy(std::make_pair(out.plot_file_name, dst_path));
}
}
Expand Down