TEST(Log, oskar_log_section)
{
oskar_log_set_term_priority(OSKAR_LOG_DEBUG);
oskar_log_section('E', "%s", "message");
oskar_log_section('W', "%s", "message");
oskar_log_section('M', "%s", "message");
oskar_log_section('D', "%s", "message");
}
TEST(Log, special_methods)
{
/*oskar_log_create(OSKAR_LOG_NONE, OSKAR_LOG_DEBUG);*/
oskar_log_set_term_priority(OSKAR_LOG_DEBUG);
oskar_log_warning("This is a warning");
oskar_log_error("This is an error");
oskar_log_section('M', "This is a section");
oskar_log_section('W', "This is a warning section");
oskar_log_section('D', "This is a debug section");
}
TEST(Log, special_methods)
{
oskar_Log* log = 0;
/*log = oskar_log_create(OSKAR_LOG_WARNING, OSKAR_LOG_DEBUG);*/
oskar_log_warning(log, "This is a warning");
oskar_log_error(log, "This is an error");
oskar_log_section(log, 'M', "This is a section!");
oskar_log_section(log, 'W', "This is a warning section!");
oskar_log_section(log, 'D', "This is a warning section!");
if (log) oskar_log_free(log);
}
TEST(Log, oskar_log_section)
{
oskar_Log* log = 0;
oskar_log_section(log, 'E', "%s", "message");
oskar_log_section(log, 'W', "%s", "message");
oskar_log_section(log, 'M', "%s", "message");
oskar_log_section(log, 'D', "%s", "message");
if (log) oskar_log_free(log);
}
void oskar_interferometer_set_sky_model(oskar_Interferometer* h,
const oskar_Sky* sky, int* status)
{
int i;
if (*status || !h || !sky) return;
/* Clear the old chunk set. */
for (i = 0; i < h->num_sky_chunks; ++i)
oskar_sky_free(h->sky_chunks[i], status);
free(h->sky_chunks);
h->sky_chunks = 0;
h->num_sky_chunks = 0;
/* Split up the sky model into chunks and store them. */
h->num_sources_total = oskar_sky_num_sources(sky);
if (h->num_sources_total > 0)
oskar_sky_append_to_set(&h->num_sky_chunks, &h->sky_chunks,
h->max_sources_per_chunk, sky, status);
h->init_sky = 0;
/* Print summary data. */
if (h->log)
{
oskar_log_section(h->log, 'M', "Sky model summary");
oskar_log_value(h->log, 'M', 0, "Num. sources", "%d",
h->num_sources_total);
oskar_log_value(h->log, 'M', 0, "Num. chunks", "%d",
h->num_sky_chunks);
}
}
static void record_timing(oskar_Simulator* h)
{
/* Obtain component times. */
int i;
double t_copy = 0., t_clip = 0., t_E = 0., t_K = 0., t_join = 0.;
double t_correlate = 0., t_compute = 0., t_components = 0.;
double *compute_times;
compute_times = (double*) calloc(h->num_devices, sizeof(double));
for (i = 0; i < h->num_devices; ++i)
{
compute_times[i] = oskar_timer_elapsed(h->d[i].tmr_compute);
t_copy += oskar_timer_elapsed(h->d[i].tmr_copy);
t_clip += oskar_timer_elapsed(h->d[i].tmr_clip);
t_join += oskar_timer_elapsed(h->d[i].tmr_join);
t_E += oskar_timer_elapsed(h->d[i].tmr_E);
t_K += oskar_timer_elapsed(h->d[i].tmr_K);
t_correlate += oskar_timer_elapsed(h->d[i].tmr_correlate);
t_compute += compute_times[i];
}
t_components = t_copy + t_clip + t_E + t_K + t_join + t_correlate;
/* Record time taken. */
oskar_log_section(h->log, 'M', "Simulation timing");
oskar_log_value(h->log, 'M', 0, "Total wall time", "%.3f s",
oskar_timer_elapsed(h->tmr_sim));
for (i = 0; i < h->num_devices; ++i)
oskar_log_value(h->log, 'M', 0, "Compute", "%.3f s [Device %i]",
compute_times[i], i);
oskar_log_value(h->log, 'M', 0, "Write", "%.3f s",
oskar_timer_elapsed(h->tmr_write));
oskar_log_message(h->log, 'M', 0, "Compute components:");
oskar_log_value(h->log, 'M', 1, "Copy", "%4.1f%%",
(t_copy / t_compute) * 100.0);
oskar_log_value(h->log, 'M', 1, "Horizon clip", "%4.1f%%",
(t_clip / t_compute) * 100.0);
oskar_log_value(h->log, 'M', 1, "Jones E", "%4.1f%%",
(t_E / t_compute) * 100.0);
oskar_log_value(h->log, 'M', 1, "Jones K", "%4.1f%%",
(t_K / t_compute) * 100.0);
oskar_log_value(h->log, 'M', 1, "Jones join", "%4.1f%%",
(t_join / t_compute) * 100.0);
oskar_log_value(h->log, 'M', 1, "Jones correlate", "%4.1f%%",
(t_correlate / t_compute) * 100.0);
oskar_log_value(h->log, 'M', 1, "Other", "%4.1f%%",
((t_compute - t_components) / t_compute) * 100.0);
free(compute_times);
}
void oskar_telescope_log_summary(const oskar_Telescope* telescope, int* status)
{
if (*status) return;
oskar_log_section('M', "Telescope model summary");
oskar_log_value('M', 0, "Longitude [deg]", "%.3f",
oskar_telescope_lon_rad(telescope) * 180.0 / M_PI);
oskar_log_value('M', 0, "Latitude [deg]", "%.3f",
oskar_telescope_lat_rad(telescope) * 180.0 / M_PI);
oskar_log_value('M', 0, "Altitude [m]", "%.0f",
oskar_telescope_alt_metres(telescope));
oskar_log_value('M', 0, "Num. stations", "%d",
oskar_telescope_num_stations(telescope));
oskar_log_value('M', 0, "Max station size", "%d",
oskar_telescope_max_station_size(telescope));
oskar_log_value('M', 0, "Max station depth", "%d",
oskar_telescope_max_station_depth(telescope));
oskar_log_value('M', 0, "Identical stations", "%s",
oskar_telescope_identical_stations(telescope) ? "true" : "false");
}
void oskar_log_free(void)
{
oskar_Log* log;
char time_str[80];
const time_t unix_time = time(NULL);
struct tm* timeinfo = localtime(&unix_time);
strftime(time_str, sizeof(time_str), "%Y-%m-%d, %H:%M:%S (%Z)", timeinfo);
oskar_log_section('M', "OSKAR-%s ending at %s.",
OSKAR_VERSION_STR, time_str);
log = oskar_log_handle();
if (log->file) fclose(log->file);
log->file = 0;
if (!log->keep_file && log->name && strlen(log->name) > 0)
{
FILE* f = fopen(log->name, "r");
if (f)
{
fclose(f);
remove(log->name);
}
}
free(log->name);
log->name = 0;
}
void oskar_simulator_run(oskar_Simulator* h, int* status)
{
int i, num_threads = 1, num_vis_blocks;
if (*status) return;
/* Check the visibilities are going somewhere. */
if (!h->vis_name
#ifndef OSKAR_NO_MS
&& !h->ms_name
#endif
)
{
oskar_log_error(h->log, "No output file specified.");
#ifdef OSKAR_NO_MS
if (h->ms_name)
oskar_log_error(h->log,
"OSKAR was compiled without Measurement Set support.");
#endif
*status = OSKAR_ERR_FILE_IO;
return;
}
/* Initialise if required. */
oskar_simulator_check_init(h, status);
/* Get the number of visibility blocks to be processed. */
num_vis_blocks = oskar_simulator_num_vis_blocks(h);
/* Record memory usage. */
if (h->log && !*status)
{
oskar_log_section(h->log, 'M', "Initial memory usage");
#ifdef OSKAR_HAVE_CUDA
for (i = 0; i < h->num_gpus; ++i)
oskar_cuda_mem_log(h->log, 0, h->gpu_ids[i]);
#endif
system_mem_log(h->log);
oskar_log_section(h->log, 'M', "Starting simulation...");
}
/* Start simulation timer. */
oskar_timer_start(h->tmr_sim);
/*-----------------------------------------------------------------------
*-- START OF MULTITHREADED SIMULATION CODE -----------------------------
*-----------------------------------------------------------------------*/
/* Loop over blocks of observation time, running simulation and file
* writing one block at a time. Simulation and file output are overlapped
* by using double buffering, and a dedicated thread is used for file
* output.
*
* Thread 0 is used for file writes.
* Threads 1 to n (mapped to compute devices) do the simulation.
*
* Note that no write is launched on the first loop counter (as no
* data are ready yet) and no simulation is performed for the last loop
* counter (which corresponds to the last block + 1) as this iteration
* simply writes the last block.
*/
#ifdef _OPENMP
num_threads = h->num_devices + 1;
omp_set_num_threads(num_threads);
omp_set_nested(0);
#else
oskar_log_warning(h->log, "OpenMP not found: Using one compute device.");
#endif
oskar_simulator_reset_work_unit_index(h);
#pragma omp parallel
{
int b, thread_id = 0, device_id = 0;
/* Get host thread ID and device ID. */
#ifdef _OPENMP
thread_id = omp_get_thread_num();
device_id = thread_id - 1;
#endif
/* Loop over simulation time blocks (+1, for the last write). */
for (b = 0; b < num_vis_blocks + 1; ++b)
{
if ((thread_id > 0 || num_threads == 1) && b < num_vis_blocks)
oskar_simulator_run_block(h, b, device_id, status);
if (thread_id == 0 && b > 0)
{
oskar_VisBlock* block;
block = oskar_simulator_finalise_block(h, b - 1, status);
oskar_simulator_write_block(h, block, b - 1, status);
}
/* Barrier 1: Reset work unit index. */
#pragma omp barrier
if (thread_id == 0)
oskar_simulator_reset_work_unit_index(h);
/* Barrier 2: Synchronise before moving to the next block. */
#pragma omp barrier
if (thread_id == 0 && b < num_vis_blocks && h->log && !*status)
oskar_log_message(h->log, 'S', 0, "Block %*i/%i (%3.0f%%) "
"complete. Simulation time elapsed: %.3f s",
disp_width(num_vis_blocks), b+1, num_vis_blocks,
100.0 * (b+1) / (double)num_vis_blocks,
oskar_timer_elapsed(h->tmr_sim));
}
}
/*-----------------------------------------------------------------------
*-- END OF MULTITHREADED SIMULATION CODE -------------------------------
*-----------------------------------------------------------------------*/
/* Record memory usage. */
if (h->log && !*status)
{
oskar_log_section(h->log, 'M', "Final memory usage");
#ifdef OSKAR_HAVE_CUDA
for (i = 0; i < h->num_gpus; ++i)
oskar_cuda_mem_log(h->log, 0, h->gpu_ids[i]);
#endif
system_mem_log(h->log);
}
/* If there are sources in the simulation and the station beam is not
* normalised to 1.0 at the phase centre, the values of noise RMS
* may give a very unexpected S/N ratio!
* The alternative would be to scale the noise to match the station
* beam gain but that would require knowledge of the station beam
* amplitude at the phase centre for each time and channel. */
if (h->log && oskar_telescope_noise_enabled(h->tel) && !*status)
{
int have_sources, amp_calibrated;
have_sources = (h->num_sky_chunks > 0 &&
oskar_sky_num_sources(h->sky_chunks[0]) > 0);
amp_calibrated = oskar_station_normalise_final_beam(
oskar_telescope_station_const(h->tel, 0));
if (have_sources && !amp_calibrated)
{
const char* a = "WARNING: System noise added to visibilities";
const char* b = "without station beam normalisation enabled.";
const char* c = "This will give an invalid signal to noise ratio.";
oskar_log_line(h->log, 'W', ' '); oskar_log_line(h->log, 'W', '*');
oskar_log_message(h->log, 'W', -1, a);
oskar_log_message(h->log, 'W', -1, b);
oskar_log_message(h->log, 'W', -1, c);
oskar_log_line(h->log, 'W', '*'); oskar_log_line(h->log, 'W', ' ');
}
}
/* Record times and summarise output files. */
if (h->log && !*status)
{
size_t log_size = 0;
char* log_data;
oskar_log_set_value_width(h->log, 25);
record_timing(h);
oskar_log_section(h->log, 'M', "Simulation complete");
oskar_log_message(h->log, 'M', 0, "Output(s):");
if (h->vis_name)
oskar_log_value(h->log, 'M', 1,
"OSKAR binary file", "%s", h->vis_name);
if (h->ms_name)
oskar_log_value(h->log, 'M', 1,
"Measurement Set", "%s", h->ms_name);
/* Write simulation log to the output files. */
log_data = oskar_log_file_data(h->log, &log_size);
#ifndef OSKAR_NO_MS
if (h->ms)
oskar_ms_add_history(h->ms, "OSKAR_LOG", log_data, log_size);
#endif
if (h->vis)
oskar_binary_write(h->vis, OSKAR_CHAR, OSKAR_TAG_GROUP_RUN,
OSKAR_TAG_RUN_LOG, 0, log_size, log_data, status);
free(log_data);
}
/* Finalise. */
oskar_simulator_finalise(h, status);
}
void oskar_interferometer_run(oskar_Interferometer* h, int* status)
{
int i, num_threads;
oskar_Thread** threads = 0;
ThreadArgs* args = 0;
if (*status || !h) return;
/* Check the visibilities are going somewhere. */
if (!h->vis_name
#ifndef OSKAR_NO_MS
&& !h->ms_name
#endif
)
{
oskar_log_error(h->log, "No output file specified.");
#ifdef OSKAR_NO_MS
if (h->ms_name)
oskar_log_error(h->log,
"OSKAR was compiled without Measurement Set support.");
#endif
*status = OSKAR_ERR_FILE_IO;
return;
}
/* Initialise if required. */
oskar_interferometer_check_init(h, status);
/* Set up worker threads. */
num_threads = h->num_devices + 1;
oskar_barrier_set_num_threads(h->barrier, num_threads);
threads = (oskar_Thread**) calloc(num_threads, sizeof(oskar_Thread*));
args = (ThreadArgs*) calloc(num_threads, sizeof(ThreadArgs));
for (i = 0; i < num_threads; ++i)
{
args[i].h = h;
args[i].num_threads = num_threads;
args[i].thread_id = i;
}
/* Record memory usage. */
if (h->log && !*status)
{
oskar_log_section(h->log, 'M', "Initial memory usage");
#ifdef OSKAR_HAVE_CUDA
for (i = 0; i < h->num_gpus; ++i)
oskar_cuda_mem_log(h->log, 0, h->gpu_ids[i]);
#endif
system_mem_log(h->log);
oskar_log_section(h->log, 'M', "Starting simulation...");
}
/* Start simulation timer. */
oskar_timer_start(h->tmr_sim);
/* Set status code. */
h->status = *status;
/* Start the worker threads. */
oskar_interferometer_reset_work_unit_index(h);
for (i = 0; i < num_threads; ++i)
threads[i] = oskar_thread_create(run_blocks, (void*)&args[i], 0);
/* Wait for worker threads to finish. */
for (i = 0; i < num_threads; ++i)
{
oskar_thread_join(threads[i]);
oskar_thread_free(threads[i]);
}
free(threads);
free(args);
/* Get status code. */
*status = h->status;
/* Record memory usage. */
if (h->log && !*status)
{
oskar_log_section(h->log, 'M', "Final memory usage");
#ifdef OSKAR_HAVE_CUDA
for (i = 0; i < h->num_gpus; ++i)
oskar_cuda_mem_log(h->log, 0, h->gpu_ids[i]);
#endif
system_mem_log(h->log);
}
/* If there are sources in the simulation and the station beam is not
* normalised to 1.0 at the phase centre, the values of noise RMS
* may give a very unexpected S/N ratio!
* The alternative would be to scale the noise to match the station
* beam gain but that would require knowledge of the station beam
* amplitude at the phase centre for each time and channel. */
if (h->log && oskar_telescope_noise_enabled(h->tel) && !*status)
{
int have_sources, amp_calibrated;
have_sources = (h->num_sky_chunks > 0 &&
oskar_sky_num_sources(h->sky_chunks[0]) > 0);
amp_calibrated = oskar_station_normalise_final_beam(
oskar_telescope_station_const(h->tel, 0));
if (have_sources && !amp_calibrated)
{
const char* a = "WARNING: System noise added to visibilities";
const char* b = "without station beam normalisation enabled.";
const char* c = "This will give an invalid signal to noise ratio.";
oskar_log_line(h->log, 'W', ' '); oskar_log_line(h->log, 'W', '*');
oskar_log_message(h->log, 'W', -1, a);
oskar_log_message(h->log, 'W', -1, b);
oskar_log_message(h->log, 'W', -1, c);
oskar_log_line(h->log, 'W', '*'); oskar_log_line(h->log, 'W', ' ');
}
}
/* Record times and summarise output files. */
if (h->log && !*status)
{
size_t log_size = 0;
char* log_data;
oskar_log_set_value_width(h->log, 25);
record_timing(h);
oskar_log_section(h->log, 'M', "Simulation complete");
oskar_log_message(h->log, 'M', 0, "Output(s):");
if (h->vis_name)
oskar_log_value(h->log, 'M', 1,
"OSKAR binary file", "%s", h->vis_name);
if (h->ms_name)
oskar_log_value(h->log, 'M', 1,
"Measurement Set", "%s", h->ms_name);
/* Write simulation log to the output files. */
log_data = oskar_log_file_data(h->log, &log_size);
#ifndef OSKAR_NO_MS
if (h->ms)
oskar_ms_add_history(h->ms, "OSKAR_LOG", log_data, log_size);
#endif
if (h->vis)
oskar_binary_write(h->vis, OSKAR_CHAR, OSKAR_TAG_GROUP_RUN,
OSKAR_TAG_RUN_LOG, 0, log_size, log_data, status);
free(log_data);
}
/* Finalise. */
oskar_interferometer_finalise(h, status);
}