Skip to content

Commit 51f7b23

Browse files
magnumrippermagnumripper
committed
OpenCL: Add color to error output
Also prefix log entries with "OpenCL:" for clarity.
1 parent 94b6998 commit 51f7b23

File tree

4 files changed

+54
-77
lines changed

4 files changed

+54
-77
lines changed

‎src/gpu_common.c‎

Lines changed: 13 additions & 26 deletions
Original file line numberDiff line numberDiff line change
@@ -458,7 +458,7 @@ int id2adl(const hw_bus busInfo) {
458458
void gpu_check_temp(void)
459459
{
460460
#if HAVE_LIBDL
461-
static int warned, warnedTemperature;
461+
static int warnedTemperature;
462462
int i, hot_gpu = 0, alerts = 0;
463463

464464
if (gpu_temp_limit < 0)
@@ -472,13 +472,8 @@ void gpu_check_temp(void)
472472
dev_get_temp[dev](temp_dev_id[dev], &temp, &fan, &util, &cl, &ml);
473473

474474
if (temp > 125 || temp < 10) {
475-
if (!warned++) {
476-
log_event("Device %d probably invalid temp reading (%d%sC).",
477-
dev + 1, temp, gpu_degree_sign);
478-
fprintf(stderr,
479-
"Device %d probably invalid temp reading (%d%sC).\n",
480-
dev + 1, temp, gpu_degree_sign);
481-
}
475+
WARN_AND_LOG_ONCE(color_warning, stderr, "GPU device %d probably invalid temp reading (%d%sC)",
476+
dev + 1, temp, gpu_degree_sign);
482477
return;
483478
}
484479

@@ -492,15 +487,10 @@ void gpu_check_temp(void)
492487
if (cool_gpu_down == 1)
493488
warnedTemperature++;
494489

495-
log_event("Device %d overheat (%d%sC, fan %s), %s%s.",
496-
dev + 1, temp, gpu_degree_sign, s_fan,
497-
(cool_gpu_down > 0) ? "sleeping" : "aborting job",
498-
(hot_gpu) ? " again" : "");
499-
fprintf(stderr,
500-
"Device %d overheat (%d%sC, fan %s), %s%s.\n",
501-
dev + 1, temp, gpu_degree_sign, s_fan,
502-
(cool_gpu_down > 0) ? "sleeping" : "aborting job",
503-
(hot_gpu) ? " again" : "");
490+
WARN_AND_LOG(color_warning, stderr, "GPU device %d overheat (%d%sC, fan %s), %s%s",
491+
dev + 1, temp, gpu_degree_sign, s_fan,
492+
(cool_gpu_down > 0) ? "sleeping" : "aborting job",
493+
(hot_gpu) ? " again" : "");
504494
}
505495
hot_gpu = 1;
506496
/***
@@ -526,17 +516,14 @@ void gpu_check_temp(void)
526516
event_abort++;
527517
} else {
528518

529-
if (hot_gpu && options.verbosity > VERB_DEFAULT &&
530-
!warnedTemperature) {
519+
if (hot_gpu && options.verbosity > VERB_DEFAULT && !warnedTemperature) {
531520
char s_fan[16] = "n/a";
532521
if (fan >= 0)
533522
sprintf(s_fan, "%u%%", fan);
534523

535-
log_event("Device %d is waking up (%d%sC, fan %s).",
536-
dev + 1, temp, gpu_degree_sign, s_fan);
537-
fprintf(stderr,
538-
"Device %d is waking up (%d%sC, fan %s).\n",
539-
dev + 1, temp, gpu_degree_sign, s_fan);
524+
WARN_AND_LOG(color_warning, stderr,
525+
"GPU device %d is waking up (%d%sC, fan %s)",
526+
dev + 1, temp, gpu_degree_sign, s_fan);
540527
}
541528
hot_gpu = 0;
542529
}
@@ -557,15 +544,15 @@ void gpu_log_temp(void)
557544

558545
fan = temp = util = -1;
559546
dev_get_temp[dev](temp_dev_id[dev], &temp, &fan, &util, &cl, &ml);
560-
n = sprintf(s_gpu, "Device %d:", dev + 1);
547+
n = sprintf(s_gpu, "GPU device %d:", dev + 1);
561548
if (temp >= 0)
562549
n += sprintf(s_gpu + n, " temp: %u%sC", temp, gpu_degree_sign);
563550
if (util > 0)
564551
n += sprintf(s_gpu + n, " util: %u%%", util);
565552
if (fan >= 0)
566553
n += sprintf(s_gpu + n, " fan: %u%%", fan);
567554
if (temp >= 0 || util > 0 || fan > 0)
568-
log_event("- %s", s_gpu);
555+
log_event("%s", s_gpu);
569556
}
570557
#endif
571558
}

‎src/opencl_autotune.h‎

Lines changed: 3 additions & 6 deletions
Original file line numberDiff line numberDiff line change
@@ -156,10 +156,7 @@ static void autotune_run_extra(struct fmt_main *self, unsigned int rounds,
156156

157157
default:
158158
if (cfg_lws < 0) {
159-
fprintf(stderr,
160-
"Error: AutotuneLWS must be a positive number (now set to %d)\n",
161-
cfg_lws);
162-
error();
159+
error_msg("Error: AutotuneLWS must be a positive number (now set to %d)\n", cfg_lws);
163160
}
164161
if (cpu(device_info[gpu_id]))
165162
local_work_size =
@@ -234,7 +231,7 @@ static void autotune_run_extra(struct fmt_main *self, unsigned int rounds,
234231
uint32_t lws, gws, mpi_lws, mpi_gws;
235232

236233
if (john_main_process)
237-
log_event("- Enforcing same work sizes on all MPI nodes");
234+
log_event("OpenCL: Enforcing same work sizes on all MPI nodes");
238235
lws = local_work_size;
239236
gws = global_work_size;
240237
MPI_Allreduce(&lws, &mpi_lws, 1, MPI_UNSIGNED, MPI_MIN, MPI_COMM_WORLD);
@@ -276,7 +273,7 @@ static void autotune_run_extra(struct fmt_main *self, unsigned int rounds,
276273
create_clobj(global_work_size, self);
277274

278275
if (!self_test_running && (!homogenous || john_main_process))
279-
log_event("- OpenCL LWS: "Zu"%s, GWS: "Zu" %s("Zu" blocks)",
276+
log_event("OpenCL: LWS: "Zu"%s, GWS: "Zu" %s("Zu" blocks)",
280277
local_work_size,
281278
(need_best_lws && !needed_best_gws) ? " (auto-tuned)" : "",
282279
global_work_size,

‎src/opencl_common.c‎

Lines changed: 34 additions & 41 deletions
Original file line numberDiff line numberDiff line change
@@ -423,7 +423,7 @@ static void load_opencl_environment()
423423
num_platforms = 0;
424424

425425
if (num_platforms < 1 && options.verbosity > VERB_LEGACY)
426-
fprintf(stderr, "%u: No OpenCL platforms were found: %s\n",
426+
fprintf_color(color_warning, stderr, "%u: OpenCL: No platforms were found: %s\n",
427427
NODE, get_error_name(ret));
428428

429429
for (i = 0; i < num_platforms; i++) {
@@ -439,7 +439,7 @@ static void load_opencl_environment()
439439

440440
if (num_devices < 1 && options.verbosity > VERB_LEGACY)
441441
fprintf(stderr,
442-
"%u: No OpenCL devices were found on platform #%d: %s\n",
442+
"%u: OpenCL: No devices were found on platform #%d: %s\n",
443443
NODE, i, get_error_name(ret));
444444

445445
// Save platform and devices information
@@ -562,7 +562,7 @@ static int start_opencl_device(int sequential_id, int *err_type)
562562
&devices[sequential_id], NULL, NULL, &ret_code);
563563

564564
if (ret_code != CL_SUCCESS) {
565-
fprintf(stderr, "%u: Error creating context for device %d "
565+
fprintf_color(color_warning, stderr, "%u: Error creating OpenCL context for device %d "
566566
"(%d:%d): %s\n",
567567
NODE, sequential_id + 1,
568568
get_platform_id(sequential_id),
@@ -575,7 +575,7 @@ static int start_opencl_device(int sequential_id, int *err_type)
575575
devices[sequential_id], 0, &ret_code);
576576

577577
if (ret_code != CL_SUCCESS) {
578-
fprintf(stderr, "%u: Error creating command queue for "
578+
fprintf_color(color_warning, stderr, "%u: Error creating OpenCL command queue for "
579579
"device %d (%d:%d): %s\n", NODE,
580580
sequential_id + 1, get_platform_id(sequential_id),
581581
get_device_id(sequential_id), get_error_name(ret_code));
@@ -599,12 +599,12 @@ static void add_device_to_list(int sequential_id)
599599
if (found < 0) {
600600
#if HAVE_MPI
601601
if (mpi_p > 1)
602-
fprintf(stderr, "%u@%s: ", mpi_id + 1, mpi_name);
602+
fprintf_color(color_warning, stderr, "%u@%s: ", mpi_id + 1, mpi_name);
603603
#elif OS_FORK
604604
if (options.fork)
605-
fprintf(stderr, "%u: ", options.node_min);
605+
fprintf_color(color_warning, stderr, "%u: ", options.node_min);
606606
#endif
607-
fprintf(stderr, "Error: --device must be between 1 and %d "
607+
fprintf_color(color_error, stderr, "Error: --device must be between 1 and %d "
608608
"(the number of devices available).\n",
609609
get_number_of_available_devices());
610610
error();
@@ -615,12 +615,12 @@ static void add_device_to_list(int sequential_id)
615615
if (! start_opencl_device(sequential_id, &i)) {
616616
#if HAVE_MPI
617617
if (mpi_p > 1)
618-
fprintf(stderr, "%u@%s: ", mpi_id + 1, mpi_name);
618+
fprintf_color(color_warning, stderr, "%u@%s: ", mpi_id + 1, mpi_name);
619619
#elif OS_FORK
620620
if (options.fork)
621-
fprintf(stderr, "%u: ", options.node_min);
621+
fprintf_color(color_warning, stderr, "%u: ", options.node_min);
622622
#endif
623-
fprintf(stderr, "Device id %d not working correctly,"
623+
fprintf_color(color_warning, stderr, "OpenCL device id %d not working correctly,"
624624
" skipping.\n", sequential_id + 1);
625625
return;
626626
}
@@ -736,12 +736,12 @@ static void build_device_list(const char *device_list[MAX_GPU_DEVICES])
736736
trial_list[i] != CL_DEVICE_TYPE_DEFAULT);
737737
}
738738
else if (!isdigit(ARCH_INDEX(device_list[n][0]))) {
739-
fprintf(stderr, "Error: --device must be numerical, "
739+
fprintf_color(color_error, stderr, "Error: --device must be numerical, "
740740
"or one of \"all\", \"cpu\", \"gpu\" and\n"
741741
"\"acc[elerator]\".\n");
742742
error();
743743
} else if (device_list[n][0] == '0') {
744-
fprintf(stderr, "Error: --device must be between 1 and %d "
744+
fprintf_color(color_error, stderr, "Error: --device must be between 1 and %d "
745745
"(the number of devices available).\n",
746746
get_number_of_available_devices());
747747
error();
@@ -813,7 +813,7 @@ void opencl_load_environment(void)
813813

814814
// Ensure that there is at least one OpenCL device available
815815
if (get_number_of_available_devices() == 0) {
816-
fprintf(stderr, "No OpenCL devices found\n");
816+
fprintf_color(color_error, stderr, "No OpenCL devices found\n");
817817
if (benchmark_running) {
818818
opencl_initialized = 1;
819819
opencl_unavailable = 1;
@@ -859,7 +859,7 @@ void opencl_load_environment(void)
859859

860860
// No working OpenCL device was found
861861
if (get_number_of_devices_in_use() == 0) {
862-
fprintf(stderr, "No OpenCL devices found\n");
862+
fprintf_color(color_error, stderr, "No OpenCL devices found\n");
863863
error();
864864
}
865865
#if OS_FORK
@@ -961,7 +961,7 @@ unsigned int opencl_get_vector_width(int sequential_id, int size)
961961
"clGetDeviceInfo for long vector width");
962962
break;
963963
default:
964-
fprintf(stderr, "%s() called with unknown type\n", __FUNCTION__);
964+
fprintf_color(color_error, stderr, "%s() called with unknown type\n", __FUNCTION__);
965965
error();
966966
}
967967
ocl_v_width = v_width;
@@ -1123,7 +1123,7 @@ static void print_device_info(int sequential_id)
11231123
"", "",
11241124
#endif
11251125
device_name, board_name);
1126-
log_event("Device %d: %s%s", sequential_id + 1, device_name, board_name);
1126+
log_event("OpenCL: Device %d: %s%s", sequential_id + 1, device_name, board_name);
11271127
}
11281128

11291129
static char *get_build_opts(int sequential_id, const char *opts)
@@ -1240,7 +1240,7 @@ void opencl_build(int sequential_id, const char *opts, int save, const char *fil
12401240
if (!getcwd(old_cwd, sizeof(old_cwd))) {
12411241
old_cwd[0] = 0;
12421242
if (old_cwd_fd < 0)
1243-
fprintf(stderr, "Warning: Cannot save current directory: %s\n", strerror(errno));
1243+
fprintf_color(color_warning, stderr, "Warning: Cannot save current directory: %s\n", strerror(errno));
12441244
}
12451245
if (chdir(john_home))
12461246
pexit("chdir: %s", john_home);
@@ -1249,7 +1249,7 @@ void opencl_build(int sequential_id, const char *opts, int save, const char *fil
12491249
build_code = clBuildProgram(*program, 0, NULL, build_opts, NULL, NULL);
12501250
if ((old_cwd_fd >= 0 || old_cwd[0]) && /* We'll only have errno when we attempt a *chdir() here */
12511251
(old_cwd_fd < 0 || fchdir(old_cwd_fd)) && (!old_cwd[0] || chdir(old_cwd)))
1252-
fprintf(stderr, "Warning: Cannot restore current directory: %s\n", strerror(errno));
1252+
fprintf_color(color_warning, stderr, "Warning: Cannot restore current directory: %s\n", strerror(errno));
12531253
if (old_cwd_fd >= 0)
12541254
close(old_cwd_fd);
12551255

@@ -1267,7 +1267,7 @@ void opencl_build(int sequential_id, const char *opts, int save, const char *fil
12671267
"clGetProgramBuildInfo II");
12681268

12691269
uint64_t end = john_get_nano();
1270-
log_event("- build time: %ss", ns2string(end - start));
1270+
log_event("OpenCL: Kernel build time: %ss", ns2string(end - start));
12711271

12721272
char *cleaned_log = build_log;
12731273
if (cfg_get_bool(SECTION_OPTIONS, SUBSECTION_OPENCL, "MuteBogusWarnings", 1) &&
@@ -1380,9 +1380,9 @@ cl_int opencl_build_from_binary(int sequential_id, cl_program *program, const ch
13801380
}
13811381
// Nvidia may return a single '\n' that we ignore
13821382
else if (options.verbosity >= LOG_VERB && strlen(build_log) > 1)
1383-
fprintf(stderr, "Binary Build log: %s\n", build_log);
1383+
fprintf(stderr, "Binary build log: %s\n", build_log);
13841384

1385-
log_event("- build time: %ss", ns2string(end - start));
1385+
log_event("OpenCL: Kernel build time: %ss", ns2string(end - start));
13861386
if (options.verbosity >= VERB_MAX)
13871387
fprintf(stderr, "Build time: %ss\n", ns2string(end - start));
13881388
MEM_FREE(build_log);
@@ -2185,7 +2185,7 @@ size_t opencl_read_source(const char *kernel_filename, char **kernel_source)
21852185
read_size = fread(*kernel_source, sizeof(char), source_size, fp);
21862186
if (read_size != source_size)
21872187
fprintf(stderr,
2188-
"Error reading source: expected "Zu", got "Zu" bytes (%s).\n",
2188+
"OpenCL error reading kernel source: expected "Zu", got "Zu" bytes (%s).\n",
21892189
source_size, read_size,
21902190
feof(fp) ? "EOF" : strerror(errno));
21912191
fclose(fp);
@@ -2285,38 +2285,38 @@ void opencl_build_kernel(const char *kernel_filename, int sequential_id, const c
22852285
*/
22862286
if (gpu_nvidia(device_info[sequential_id]) && !platform_apple(get_platform_id(sequential_id))) {
22872287
if (john_main_process || !cfg_get_bool(SECTION_OPTIONS, SUBSECTION_MPI, "MPIAllGPUsSame", 0))
2288-
log_event("- Kernel binary caching disabled for this platform/device");
2288+
LOG_ONCE("OpenCL: Kernel binary caching disabled for this platform/device");
22892289
use_cache = 0;
22902290
} else
22912291
#endif
22922292
if (getenv("DUMP_BINARY")) {
2293-
log_event("- DUMP_BINARY is set, ignoring cached kernel");
2293+
LOG_ONCE("OpenCL: DUMP_BINARY is set, ignoring cached kernel");
22942294
use_cache = 0;
22952295
} else {
22962296
use_cache = !stat(path_expand(bin_name), &bin_stat);
22972297

22982298
if (use_cache && !stat(path_expand(kernel_filename), &source_stat) &&
22992299
source_stat.st_mtime > bin_stat.st_mtime) {
23002300
use_cache = 0;
2301-
log_event("- cached kernel may be stale, ignoring");
2301+
log_event("OpenCL: Cached kernel may be stale, ignoring");
23022302
}
23032303
}
23042304

23052305
// Select the kernel to run.
23062306
if (use_cache) {
23072307
size_t program_size = opencl_read_source(bin_name, &kernel_source);
23082308

2309-
log_event("- Building kernel from cached binary");
2309+
log_event("OpenCL: Building kernel from cached binary");
23102310
ret_code = opencl_build_from_binary(sequential_id, &program[sequential_id], kernel_source, program_size);
23112311
if (ret_code != CL_SUCCESS)
2312-
log_event("- Build from cached binary failed");
2312+
log_event("OpenCL: Build from cached binary failed");
23132313
}
23142314

23152315
if (!use_cache || ret_code != CL_SUCCESS) {
2316-
log_event("- Building kernel from source and caching binary");
2316+
log_event("OpenCL: Building kernel from source and caching binary");
23172317
if (warn && options.verbosity > VERB_DEFAULT) {
23182318
fflush(stdout);
2319-
fprintf(stderr, "Building the kernel, this could take a while\n");
2319+
fprintf(stderr, "Building the OpenCL kernel, this could take a while\n");
23202320
}
23212321
opencl_read_source(kernel_filename, &kernel_source);
23222322
opencl_build(sequential_id, opts, 1, bin_name, &program[sequential_id], kernel_filename, kernel_source);
@@ -2374,14 +2374,9 @@ int opencl_prepare_dev(int sequential_id)
23742374
if (gpu_nvidia(device_info[sequential_id])) {
23752375
opencl_avoid_busy_wait[sequential_id] = cfg_get_bool(SECTION_OPTIONS, SUBSECTION_GPU,
23762376
"AvoidBusyWait", 1);
2377-
static int warned;
2378-
23792377
/* Remove next line once (nearly) all formats has got the macros */
23802378
if (!opencl_avoid_busy_wait[sequential_id])
2381-
if (!warned) {
2382-
warned = 1;
2383-
log_event("- Busy-wait reduction %sabled", opencl_avoid_busy_wait[sequential_id] ? "en" : "dis");
2384-
}
2379+
LOG_ONCE("OpenCL: Busy-wait reduction %sabled", opencl_avoid_busy_wait[sequential_id] ? "en" : "dis");
23852380
}
23862381
#endif
23872382

@@ -2900,11 +2895,10 @@ void opencl_list_devices(void)
29002895
ret = clGetPlatformIDs(MAX_PLATFORMS, platform_list, &num_platforms);
29012896

29022897
if (!num_platforms)
2903-
fprintf(stderr, "Error: No OpenCL-capable platforms were detected"
2904-
" by the installed OpenCL driver.\n");
2898+
fprintf_color(color_error, stderr, "Error: No platforms were detected by the installed OpenCL driver.\n");
29052899

29062900
if (ret != CL_SUCCESS && options.verbosity > VERB_LEGACY)
2907-
fprintf(stderr, "Throw clError: clGetPlatformIDs() = %s\n",
2901+
fprintf_color(color_warning, stderr, "Throw clError: clGetPlatformIDs() = %s\n",
29082902
get_error_name(ret));
29092903

29102904
for (i = 0; i < num_platforms; i++) {
@@ -2915,7 +2909,7 @@ void opencl_list_devices(void)
29152909

29162910
if ((ret != CL_SUCCESS || num_devices < 1) &&
29172911
options.verbosity > VERB_LEGACY)
2918-
fprintf(stderr, "No OpenCL devices was found on platform #%d"
2912+
fprintf_color(color_warning, stderr, "No OpenCL devices was found on platform #%d"
29192913
", clGetDeviceIDs() = %s\n",
29202914
i, get_error_name(ret));
29212915

@@ -2940,8 +2934,7 @@ void opencl_list_devices(void)
29402934
printf(" Platform extensions: %s\n", dname);
29412935
}
29422936
}
2943-
fprintf(stderr, "Error: No OpenCL-capable devices were detected"
2944-
" by the installed OpenCL driver.\n\n");
2937+
fprintf_color(color_error, stderr, "Error: No devices were detected by the installed OpenCL driver.\n\n");
29452938
return;
29462939
}
29472940
/* Initialize OpenCL environment */

0 commit comments

Comments
 (0)