diff --git a/include/chia/phase1.hpp b/include/chia/phase1.hpp index 7813bb56..0784e8a8 100644 --- a/include/chia/phase1.hpp +++ b/include/chia/phase1.hpp @@ -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 @@ -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; @@ -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; } @@ -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; } diff --git a/include/chia/phase2.hpp b/include/chia/phase2.hpp index 1b9efc4a..9f7eb3a6 100644 --- a/include/chia/phase2.hpp +++ b/include/chia/phase2.hpp @@ -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(); @@ -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; @@ -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(max_table_size); auto next_bitfield = std::make_shared(max_table_size); @@ -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; } diff --git a/include/chia/phase3.hpp b/include/chia/phase3.hpp index e0e268fe..ac47177c 100644 --- a/include/chia/phase3.hpp +++ b/include/chia/phase3.hpp @@ -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; } @@ -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; } @@ -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; @@ -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; } diff --git a/include/chia/phase4.hpp b/include/chia/phase4.hpp index 036e4452..ff1f7568 100644 --- a/include/chia/phase4.hpp +++ b/include/chia/phase4.hpp @@ -79,7 +79,7 @@ uint64_t compute( FILE* plot_file, const int header_size, std::vector 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; @@ -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); @@ -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] = {}; @@ -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; } diff --git a/include/chia/util.hpp b/include/chia/util.hpp index 5e563a27..c2b068b7 100644 --- a/include/chia/util.hpp +++ b/include/chia/util.hpp @@ -375,6 +375,16 @@ namespace Util { } } +inline +std::string get_curr_datetime() +{ + 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::system_clock::now().time_since_epoch()).count(); diff --git a/src/chia_plot.cpp b/src/chia_plot.cpp index a3008d95..02bebd30 100644 --- a/src/chia_plot.cpp +++ b/src/chia_plot.cpp @@ -62,9 +62,9 @@ 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; @@ -72,17 +72,17 @@ phase4::output_t create_plot( const int num_threads, 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 seed(32); randombytes_buf(seed.data(), seed.size()); @@ -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()); @@ -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; } @@ -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> copy_thread( @@ -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)); } } @@ -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)); } }