[libomptarget][amdgpu] Refactor debug printing

[JonChesterfield]

Summary

Move most debug printing in rtl.cpp behind DP() macro
Adjust the print output for gpu arch mismatch when the architectures match
Convert an assert into graceful failure

[JonChesterfield]

Converted fprintf and printf to DP. Left one fprintf in place because it chooses at runtime whether to write to stdout or stderr and this change was mostly interested in dropping the error messages of the format:

Possible gpu arch mismatch: device: gfx906, image:gfx906 please check compiler flag: -march=<gpu>

openmp/libomptarget/plugins/amdgpu/src/rtl.cpp

1498

Primary change is here. This is a relatively common error message and it looks bad when the two strings it claims are likely to be different are identical.

[jdoerfert]

LG

[JonChesterfield]

openmp/libomptarget/plugins/amdgpu/src/rtl.cpp

290

Changed a couple of integer prints to the string format in passing

[ronlieb]

openmp/libomptarget/plugins/amdgpu/src/rtl.cpp

1500

could we retain fprintf for the if part if this code, it is helpful to users when they miscompile one arch and run on another.

1900–1908

could we keep all the fprintf's under runtime control of STARTUP_DEBUG ,its helpful to turn this on separately then all the DP traces,

[JonChesterfield]

openmp/libomptarget/plugins/amdgpu/src/rtl.cpp

1900–1908

I can make my peace with that as it's still behind an environment variable. Will wait to see if anyone else comments.

[JonChesterfield]

If I understand correctly this is no problem for aomp as the DP-wrapped prints can be enabled by default, therefore landing as is. Probably more iteration needed on these print messages and those elsewhere in the library.

openmp/libomptarget/plugins/amdgpu/src/rtl.cpp

 template <typename Callback> static hsa_status_t FindAgents(Callback CB) {
 
   hsa_status_t err =
       hsa::iterate_agents([&](hsa_agent_t agent) -> hsa_status_t {
         hsa_device_type_t device_type;
         // get_info fails iff HSA runtime not yet initialized
         hsa_status_t err =
             hsa_agent_get_info(agent, HSA_AGENT_INFO_DEVICE, &device_type);
-        if (print_kernel_trace > 0 && err != HSA_STATUS_SUCCESS)
-          printf("rtl.cpp: err %d\n", err);
-        assert(err == HSA_STATUS_SUCCESS);
+
+        if (err != HSA_STATUS_SUCCESS) {
+          if (print_kernel_trace > 0)
+            DP("rtl.cpp: err %s\n", get_error_string(err));
+
+          return err;
+        }
 
         CB(device_type, agent);
         return HSA_STATUS_SUCCESS;
       });
 
   // iterate_agents fails iff HSA runtime not yet initialized
   if (print_kernel_trace > 0 && err != HSA_STATUS_SUCCESS) {
-    printf("rtl.cpp: err %d\n", err);
+    DP("rtl.cpp: err %s\n", get_error_string(err));
   }
 
   return err;
 }
 
 static void callbackQueue(hsa_status_t status, hsa_queue_t *source,
                           void *data) {
   if (status != HSA_STATUS_SUCCESS) {
     const char *status_string;
     if (hsa_status_string(status, &status_string) != HSA_STATUS_SUCCESS) {
       status_string = "unavailable";
     }
-    fprintf(stderr, "[%s:%d] GPU error in queue %p %d (%s)\n", __FILE__,
-            __LINE__, source, status, status_string);
+    DP("[%s:%d] GPU error in queue %p %d (%s)\n", __FILE__, __LINE__, source,
+       status, status_string);
     abort();
   }
 }
 
 namespace core {
 namespace {
 void packet_store_release(uint32_t *packet, uint16_t header, uint16_t rest) {
   __atomic_store_n(packet, header | (rest << 16), __ATOMIC_RELEASE);

 hsa_status_t addKernArgPool(hsa_amd_memory_pool_t MemoryPool, void *Data) {
   std::vector<hsa_amd_memory_pool_t> *Result =
       static_cast<std::vector<hsa_amd_memory_pool_t> *>(Data);
   bool AllocAllowed = false;
   hsa_status_t err = hsa_amd_memory_pool_get_info(
       MemoryPool, HSA_AMD_MEMORY_POOL_INFO_RUNTIME_ALLOC_ALLOWED,
       &AllocAllowed);
   if (err != HSA_STATUS_SUCCESS) {
-    fprintf(stderr, "Alloc allowed in memory pool check failed: %s\n",
-            get_error_string(err));
+    DP("Alloc allowed in memory pool check failed: %s\n",
     return err;
   }
 
   if (!AllocAllowed) {
     // nothing needs to be done here.
     return HSA_STATUS_SUCCESS;
   }
 
   uint32_t GlobalFlags = 0;
   err = hsa_amd_memory_pool_get_info(
       MemoryPool, HSA_AMD_MEMORY_POOL_INFO_GLOBAL_FLAGS, &GlobalFlags);
   if (err != HSA_STATUS_SUCCESS) {
-    fprintf(stderr, "Get memory pool info failed: %s\n", get_error_string(err));
+    DP("Get memory pool info failed: %s\n", get_error_string(err));
     return err;
   }
 
   size_t size = 0;
   err = hsa_amd_memory_pool_get_info(MemoryPool, HSA_AMD_MEMORY_POOL_INFO_SIZE,
                                      &size);
   if (err != HSA_STATUS_SUCCESS) {
-    fprintf(stderr, "Get memory pool size failed: %s\n", get_error_string(err));
+    DP("Get memory pool size failed: %s\n", get_error_string(err));
     return err;
   }
 
   if ((GlobalFlags & HSA_AMD_MEMORY_POOL_GLOBAL_FLAG_FINE_GRAINED) &&
       (GlobalFlags & HSA_AMD_MEMORY_POOL_GLOBAL_FLAG_KERNARG_INIT) &&
       size > 0) {
     Result->push_back(MemoryPool);
   }
 
   return HSA_STATUS_SUCCESS;
 }
 
 std::pair<hsa_status_t, bool>
 isValidMemoryPool(hsa_amd_memory_pool_t MemoryPool) {
   bool AllocAllowed = false;
   hsa_status_t Err = hsa_amd_memory_pool_get_info(
       MemoryPool, HSA_AMD_MEMORY_POOL_INFO_RUNTIME_ALLOC_ALLOWED,
       &AllocAllowed);
   if (Err != HSA_STATUS_SUCCESS) {
-    fprintf(stderr, "Alloc allowed in memory pool check failed: %s\n",
-            get_error_string(Err));
+    DP("Alloc allowed in memory pool check failed: %s\n",
     return {Err, false};
   }
 
   return {HSA_STATUS_SUCCESS, AllocAllowed};
 }
 
 template <typename AccumulatorFunc>
 hsa_status_t collectMemoryPools(const std::vector<hsa_agent_t> &Agents,
                                 AccumulatorFunc Func) {
   for (int DeviceId = 0; DeviceId < Agents.size(); DeviceId++) {
     hsa_status_t Err = hsa::amd_agent_iterate_memory_pools(
         Agents[DeviceId], [&](hsa_amd_memory_pool_t MemoryPool) {
           hsa_status_t Err;
           bool Valid = false;
           std::tie(Err, Valid) = isValidMemoryPool(MemoryPool);
           if (Err != HSA_STATUS_SUCCESS) {
             return Err;
           }
           if (Valid)
             Func(MemoryPool, DeviceId);
           return HSA_STATUS_SUCCESS;
         });
 
     if (Err != HSA_STATUS_SUCCESS) {
-      printf("[%s:%d] %s failed: %s\n", __FILE__, __LINE__,
-             "Iterate all memory pools", get_error_string(Err));
+      DP("[%s:%d] %s failed: %s\n", __FILE__, __LINE__,
       return Err;
     }
   }
 
   return HSA_STATUS_SUCCESS;
 }
 
 std::pair<hsa_status_t, hsa_amd_memory_pool_t>
 FindKernargPool(const std::vector<hsa_agent_t> &HSAAgents) {
   std::vector<hsa_amd_memory_pool_t> KernArgPools;
   for (const auto &Agent : HSAAgents) {
     hsa_status_t err = HSA_STATUS_SUCCESS;
     err = hsa_amd_agent_iterate_memory_pools(
         Agent, addKernArgPool, static_cast<void *>(&KernArgPools));
     if (err != HSA_STATUS_SUCCESS) {
-      printf("[%s:%d] %s failed: %s\n", __FILE__, __LINE__,
-             "Iterate all memory pools", get_error_string(err));
+      DP("[%s:%d] %s failed: %s\n", __FILE__, __LINE__,
       return {err, hsa_amd_memory_pool_t{}};
     }
   }
 
   if (KernArgPools.empty()) {
-    fprintf(stderr, "Unable to find any valid kernarg pool\n");
+    DP("Unable to find any valid kernarg pool\n");
     return {HSA_STATUS_ERROR, hsa_amd_memory_pool_t{}};
   }
 
   return {HSA_STATUS_SUCCESS, KernArgPools[0]};
 }
 
 } // namespace
 } // namespace core
public:
   }
 
   hsa_status_t setupMemoryPools() {
     using namespace std::placeholders;
     hsa_status_t Err;
     Err = core::collectMemoryPools(
         CPUAgents, std::bind(&RTLDeviceInfoTy::addHostMemoryPool, this, _1, _2));
     if (Err != HSA_STATUS_SUCCESS) {
-      fprintf(stderr, "HSA error in collecting memory pools for CPU: %s\n",
-              get_error_string(Err));
+      DP("HSA error in collecting memory pools for CPU: %s\n",
       return Err;
     }
     Err = core::collectMemoryPools(
         HSAAgents, std::bind(&RTLDeviceInfoTy::addDeviceMemoryPool, this, _1, _2));
     if (Err != HSA_STATUS_SUCCESS) {
-      fprintf(stderr,
-              "HSA error in collecting memory pools for offload devices: %s\n",
-              get_error_string(Err));
+      DP("HSA error in collecting memory pools for offload devices: %s\n",
       return Err;
     }
     return HSA_STATUS_SUCCESS;
   }
 
   hsa_amd_memory_pool_t getDeviceMemoryPool(int DeviceId) {
     assert(DeviceId >= 0 && DeviceId < DeviceCoarseGrainedMemoryPools.size() &&
            "Invalid device Id");
for (uint32_t I = 0; I < HSAExecutables.size(); I++) {
       if (Err != HSA_STATUS_SUCCESS) {
         DP("[%s:%d] %s failed: %s\n", __FILE__, __LINE__,
            "Destroying executable", get_error_string(Err));
       }
     }
 
     Err = hsa_shut_down();
     if (Err != HSA_STATUS_SUCCESS) {
-      printf("[%s:%d] %s failed: %s\n", __FILE__, __LINE__, "Shutting down HSA",
-             get_error_string(Err));
+      DP("[%s:%d] %s failed: %s\n", __FILE__, __LINE__, "Shutting down HSA",
     }
   }
 };
 
 pthread_mutex_t SignalPoolT::mutex = PTHREAD_MUTEX_INITIALIZER;
 
 // TODO: May need to drop the trailing to fields until deviceRTL is updated
 struct omptarget_device_environmentTy {
err = hsa_agent_get_info(agent, (hsa_agent_info_t)HSA_AGENT_INFO_NAME,
                            (void *)GetInfoName);
   if (err)
     DeviceInfo.GPUName[device_id] = "--unknown gpu--";
   else {
     DeviceInfo.GPUName[device_id] = GetInfoName;
   }
 
   if (print_kernel_trace & STARTUP_DETAILS)
-    fprintf(stderr, "Device#%-2d CU's: %2d %s\n", device_id,
-            DeviceInfo.ComputeUnits[device_id],
-            DeviceInfo.GPUName[device_id].c_str());
+    DP("Device#%-2d CU's: %2d %s\n", device_id,
 
   // Query attributes to determine number of threads/block and blocks/grid.
   uint16_t workgroup_max_dim[3];
   err = hsa_agent_get_info(agent, HSA_AGENT_INFO_WORKGROUP_MAX_DIM,
                            &workgroup_max_dim);
   if (err != HSA_STATUS_SUCCESS) {
     DeviceInfo.GroupsPerDevice[device_id] = RTLDeviceInfoTy::DefaultNumTeams;
     DP("Error getting grid dims: num groups : %d\n",
static hsa_status_t atmi_calloc(void **ret_ptr, size_t size, int DeviceId) {
   hsa_amd_memory_pool_t MemoryPool = DeviceInfo.getDeviceMemoryPool(DeviceId);
   hsa_status_t err = hsa_amd_memory_pool_allocate(MemoryPool, rounded, 0, &ptr);
   if (err != HSA_STATUS_SUCCESS) {
     return err;
   }
 
   hsa_status_t rc = hsa_amd_memory_fill(ptr, 0, rounded / 4);
   if (rc != HSA_STATUS_SUCCESS) {
-    fprintf(stderr, "zero fill device_state failed with %u\n", rc);
+    DP("zero fill device_state failed with %u\n", rc);
     core::Runtime::Memfree(ptr);
     return HSA_STATUS_ERROR;
   }
 
   *ret_ptr = ptr;
   return HSA_STATUS_SUCCESS;
 }
 
hsa_status_t err = module_register_from_memory_to_place(
                              __ATOMIC_RELEASE);
           }
           return env.before_loading(data, size);
         },
         DeviceInfo.HSAExecutables);
 
     check("Module registering", err);
     if (err != HSA_STATUS_SUCCESS) {
-      fprintf(stderr,
-              "Possible gpu arch mismatch: device:%s, image:%s please check"
-              " compiler flag: -march=<gpu>\n",
-              DeviceInfo.GPUName[device_id].c_str(),
-              get_elf_mach_gfx_name(elf_e_flags(image)));
+      const char *DeviceName = DeviceInfo.GPUName[device_id].c_str();
+      const char *ElfName = get_elf_mach_gfx_name(elf_e_flags(image));
+
+      if (strcmp(DeviceName, ElfName) != 0) {
+        DP("Possible gpu arch mismatch: device:%s, image:%s please check"
+           DeviceName, ElfName);
+      } else {
+        DP("Error loading image onto GPU: %s\n", get_error_string(err));
+      }
+
       return NULL;
     }
 
     err = env.after_loading();
     if (err != HSA_STATUS_SUCCESS) {
       return NULL;
     }
   }
__tgt_target_table *__tgt_rtl_load_binary_locked(int32_t device_id,
   __tgt_offload_entry *HostBegin = image->EntriesBegin;
   __tgt_offload_entry *HostEnd = image->EntriesEnd;
 
   for (__tgt_offload_entry *e = HostBegin; e != HostEnd; ++e) {
 
     if (!e->addr) {
       // The host should have always something in the address to
       // uniquely identify the target region.
-      fprintf(stderr, "Analyzing host entry '<null>' (size = %lld)...\n",
-              (unsigned long long)e->size);
+      DP("Analyzing host entry '<null>' (size = %lld)...\n",
       return NULL;
     }
 
     if (e->size) {
       __tgt_offload_entry entry = *e;
 
       void *varptr;
       uint32_t varsize;
launchVals getLaunchVals(EnvironmentVariables Env, int ConstWGSize,
   int num_groups = 0;
 
   int Max_Teams =
       Env.MaxTeamsDefault > 0 ? Env.MaxTeamsDefault : DeviceNumTeams;
   if (Max_Teams > RTLDeviceInfoTy::HardTeamLimit)
     Max_Teams = RTLDeviceInfoTy::HardTeamLimit;
 
   if (print_kernel_trace & STARTUP_DETAILS) {
-    fprintf(stderr, "RTLDeviceInfoTy::Max_Teams: %d\n",
-            RTLDeviceInfoTy::Max_Teams);
-    fprintf(stderr, "Max_Teams: %d\n", Max_Teams);
-    fprintf(stderr, "RTLDeviceInfoTy::Warp_Size: %d\n",
-            RTLDeviceInfoTy::Warp_Size);
-    fprintf(stderr, "RTLDeviceInfoTy::Max_WG_Size: %d\n",
-            RTLDeviceInfoTy::Max_WG_Size);
-    fprintf(stderr, "RTLDeviceInfoTy::Default_WG_Size: %d\n",
-            RTLDeviceInfoTy::Default_WG_Size);
-    fprintf(stderr, "thread_limit: %d\n", thread_limit);
-    fprintf(stderr, "threadsPerGroup: %d\n", threadsPerGroup);
-    fprintf(stderr, "ConstWGSize: %d\n", ConstWGSize);
+    DP("RTLDeviceInfoTy::Max_Teams: %d\n", RTLDeviceInfoTy::Max_Teams);
+    DP("Max_Teams: %d\n", Max_Teams);
+    DP("RTLDeviceInfoTy::Warp_Size: %d\n", RTLDeviceInfoTy::Warp_Size);
+    DP("RTLDeviceInfoTy::Max_WG_Size: %d\n", RTLDeviceInfoTy::Max_WG_Size);
+    DP("RTLDeviceInfoTy::Default_WG_Size: %d\n",
+    DP("thread_limit: %d\n", thread_limit);
+    DP("threadsPerGroup: %d\n", threadsPerGroup);
+    DP("ConstWGSize: %d\n", ConstWGSize);
   }
   // check for thread_limit() clause
   if (thread_limit > 0) {
     threadsPerGroup = thread_limit;
     DP("Setting threads per block to requested %d\n", thread_limit);
     if (ExecutionMode == GENERIC) { // Add master warp for GENERIC
       threadsPerGroup += RTLDeviceInfoTy::Warp_Size;
       DP("Adding master wavefront: +%d threads\n", RTLDeviceInfoTy::Warp_Size);
     }
     if (threadsPerGroup > RTLDeviceInfoTy::Max_WG_Size) { // limit to max
       threadsPerGroup = RTLDeviceInfoTy::Max_WG_Size;
       DP("Setting threads per block to maximum %d\n", threadsPerGroup);
     }
   }
   // check flat_max_work_group_size attr here
   if (threadsPerGroup > ConstWGSize) {
     threadsPerGroup = ConstWGSize;
     DP("Reduced threadsPerGroup to flat-attr-group-size limit %d\n",
        threadsPerGroup);
   }
   if (print_kernel_trace & STARTUP_DETAILS)
-    fprintf(stderr, "threadsPerGroup: %d\n", threadsPerGroup);
+    DP("threadsPerGroup: %d\n", threadsPerGroup);
   DP("Preparing %d threads\n", threadsPerGroup);
 
   // Set default num_groups (teams)
   if (Env.TeamLimit > 0)
     num_groups = (Max_Teams < Env.TeamLimit) ? Max_Teams : Env.TeamLimit;
   else
     num_groups = Max_Teams;
   DP("Set default num of groups %d\n", num_groups);
 
   if (print_kernel_trace & STARTUP_DETAILS) {
-    fprintf(stderr, "num_groups: %d\n", num_groups);
-    fprintf(stderr, "num_teams: %d\n", num_teams);
+    DP("num_groups: %d\n", num_groups);
+    DP("num_teams: %d\n", num_teams);
   }
 
   // Reduce num_groups if threadsPerGroup exceeds RTLDeviceInfoTy::Max_WG_Size
   // This reduction is typical for default case (no thread_limit clause).
   // or when user goes crazy with num_teams clause.
   // FIXME: We cant distinguish between a constant or variable thread limit.
   // So we only handle constant thread_limits.
   if (threadsPerGroup >
       RTLDeviceInfoTy::Default_WG_Size) //  256 < threadsPerGroup <= 1024
     // Should we round threadsPerGroup up to nearest RTLDeviceInfoTy::Warp_Size
     // here?
     num_groups = (Max_Teams * RTLDeviceInfoTy::Max_WG_Size) / threadsPerGroup;
 
   // check for num_teams() clause
   if (num_teams > 0) {
     num_groups = (num_teams < num_groups) ? num_teams : num_groups;
   }
   if (print_kernel_trace & STARTUP_DETAILS) {
-    fprintf(stderr, "num_groups: %d\n", num_groups);
-    fprintf(stderr, "Env.NumTeams %d\n", Env.NumTeams);
-    fprintf(stderr, "Env.TeamLimit %d\n", Env.TeamLimit);
+    DP("num_groups: %d\n", num_groups);
+    DP("Env.NumTeams %d\n", Env.NumTeams);
+    DP("Env.TeamLimit %d\n", Env.TeamLimit);
   }
 
   if (Env.NumTeams > 0) {
     num_groups = (Env.NumTeams < num_groups) ? Env.NumTeams : num_groups;
     DP("Modifying teams based on Env.NumTeams %d\n", Env.NumTeams);
   } else if (Env.TeamLimit > 0) {
     num_groups = (Env.TeamLimit < num_groups) ? Env.TeamLimit : num_groups;
     DP("Modifying teams based on Env.TeamLimit%d\n", Env.TeamLimit);
if (num_teams <= 0) {
            num_groups, loop_tripcount, threadsPerGroup);
       }
     } else {
       num_groups = num_teams;
     }
     if (num_groups > Max_Teams) {
       num_groups = Max_Teams;
       if (print_kernel_trace & STARTUP_DETAILS)
-        fprintf(stderr, "Limiting num_groups %d to Max_Teams %d \n", num_groups,
-                Max_Teams);
+        DP("Limiting num_groups %d to Max_Teams %d \n", num_groups, Max_Teams);
     }
     if (num_groups > num_teams && num_teams > 0) {
       num_groups = num_teams;
       if (print_kernel_trace & STARTUP_DETAILS)
-        fprintf(stderr, "Limiting num_groups %d to clause num_teams %d \n",
-                num_groups, num_teams);
+        DP("Limiting num_groups %d to clause num_teams %d \n", num_groups,
+           num_teams);
     }
   }
 
   // num_teams clause always honored, no matter what, unless DEFAULT is active.
   if (num_teams > 0) {
     num_groups = num_teams;
     // Cap num_groups to EnvMaxTeamsDefault if set.
     if (Env.MaxTeamsDefault > 0 && num_groups > Env.MaxTeamsDefault)
       num_groups = Env.MaxTeamsDefault;
   }
   if (print_kernel_trace & STARTUP_DETAILS) {
-    fprintf(stderr, "threadsPerGroup: %d\n", threadsPerGroup);
-    fprintf(stderr, "num_groups: %d\n", num_groups);
-    fprintf(stderr, "loop_tripcount: %ld\n", loop_tripcount);
+    DP("threadsPerGroup: %d\n", threadsPerGroup);
+    DP("num_groups: %d\n", num_groups);
+    DP("loop_tripcount: %ld\n", loop_tripcount);
   }
   DP("Final %d num_groups and %d threadsPerGroup\n", num_groups,
      threadsPerGroup);
 
   launchVals res;
   res.WorkgroupSize = threadsPerGroup;
   res.GridSize = threadsPerGroup * num_groups;
   return res;