SWDEV-204509: re-enable printf on all platforms (including CentOS)

printf was previously disabled for two reasons: 1. The format string was parsed using std::regex, which is broken on CentOS. This dependence on std::regex is now replaced with simpler parsing of the format string using string::find_first_of. 2. One unit test in particular, early_finalize, was crashing on the Jenkins build that uses an Ubuntu 16.04 container. The crash was traced to a segfault when trying to flush/delete the printf buffer when the application exits. The reason for the segfault is not yet understood, but simply disabling the deletion removes the crash. Note that the printf buffer is no longer valid at the point of deletion, and the contents of the buffer are flushed after every kernel returns. In addition, this change sets HCC_ENABLE_PRINTF to 0 in the LIT tests by default, and sets it to 1 only for the printf tests under tests/Unit/Printf. See the following github PRs for more details: ROCm#1185 ROCm#1199 ROCm#1169 Change-Id: I7d390745c3abdf3aa3722a3cdab586368ea03771
david-salinas · Oct 23, 2019 · c693458 · c693458
1 parent 9400da6
commit c693458
Show file tree

Hide file tree

Showing 12 changed files with 108 additions and 111 deletions.
diff --git a/include/hc_printf.hpp b/include/hc_printf.hpp
@@ -6,7 +6,6 @@
 #include <cassert>
 #include <atomic>
 #include <string>
-#include <regex>
 #include <iostream>
 #include <algorithm>
 
@@ -15,16 +14,11 @@
 
 // The printf on the accelerator is only enabled when
 // The HCC_ENABLE_ACCELERATOR_PRINTF is defined
-
-// Disabling hc::printf it's broken on certain platform
-// and this experimental feature is not longer being maintained.  
-#ifdef HCC_ENABLE_ACCELERATOR_PRINTF
-  #undef HCC_ENABLE_ACCELERATOR_PRINTF
-  #warning "The experimental hc::printf is no longer supported and is disabled"
-#endif
+//
+//#define HCC_ENABLE_ACCELERATOR_PRINTF (1)
 
 // Indicate whether hc::printf is supported
-//#define HC_FEATURE_PRINTF (1)
+#define HC_FEATURE_PRINTF (1)
 
 // Enable extra debug messages
 #define HC_PRINTF_DEBUG  (0)
@@ -49,12 +43,8 @@ namespace hc {
 */
 
 union PrintfPacketData {
-  uint32_t        ui;
-  int32_t         i;
   uint64_t        uli;
   int64_t         li;
-  hc::half        h;
-  float           f;
   double          d;
   void*           ptr;
   const void*     cptr;
@@ -98,14 +88,14 @@ enum PrintfPacketDataType {
 class PrintfPacket {
 public:
   void clear()             [[hc,cpu]] { type = PRINTF_UNUSED; }
-  void set(uint32_t d)     [[hc,cpu]] { type = PRINTF_UINT32_T;       data.ui = d; }
-  void set(int32_t d)      [[hc,cpu]] { type = PRINTF_INT32_T;        data.i = d; }
+  void set(uint32_t d)     [[hc,cpu]] { type = PRINTF_UINT32_T;       data.uli = d; }
+  void set(int32_t d)      [[hc,cpu]] { type = PRINTF_INT32_T;        data.li = d; }
   void set(uint64_t d)     [[hc,cpu]] { type = PRINTF_UINT64_T;       data.uli = d; }
   void set(int64_t d)      [[hc,cpu]] { type = PRINTF_INT64_T;        data.li = d; }
   void set(unsigned long long d) [[hc,cpu]] { type = PRINTF_UINT64_T; data.uli = d; }
   void set(long long d)    [[hc,cpu]] { type = PRINTF_INT64_T;        data.li = d; }
-  void set(hc::half d)     [[hc,cpu]] { type = PRINTF_HALF;           data.h = d; }
-  void set(float d)        [[hc,cpu]] { type = PRINTF_FLOAT;          data.f = d; }
+  void set(hc::half d)     [[hc,cpu]] { type = PRINTF_HALF;           data.d = d; }
+  void set(float d)        [[hc,cpu]] { type = PRINTF_FLOAT;          data.d = d; }
   void set(double d)       [[hc,cpu]] { type = PRINTF_DOUBLE;         data.d = d; }
   void set(void* d)        [[hc,cpu]] { type = PRINTF_VOID_PTR;       data.ptr = d; }
   void set(const void* d)  [[hc,cpu]] { type = PRINTF_CONST_VOID_PTR; data.cptr = d; }
@@ -134,14 +124,14 @@ static inline PrintfPacket* createPrintfBuffer(const unsigned int numElements) {
 
     // Initialize the Header elements of the Printf Buffer
     printfBuffer[PRINTF_BUFFER_SIZE].type = PRINTF_BUFFER_SIZE;
-    printfBuffer[PRINTF_BUFFER_SIZE].data.ui = numElements;
+    printfBuffer[PRINTF_BUFFER_SIZE].data.uli = numElements;
 
     // Header includes a helper string buffer which holds all char* args
     // PrintfPacket is 12 bytes, equivalent string buffer size used
     printfBuffer[PRINTF_STRING_BUFFER].type = PRINTF_STRING_BUFFER;
     printfBuffer[PRINTF_STRING_BUFFER].data.ptr = hc::internal::am_alloc_host_coherent(sizeof(char) * numElements * 12);
     printfBuffer[PRINTF_STRING_BUFFER_SIZE].type = PRINTF_STRING_BUFFER_SIZE;
-    printfBuffer[PRINTF_STRING_BUFFER_SIZE].data.ui = numElements * 12;
+    printfBuffer[PRINTF_STRING_BUFFER_SIZE].data.uli = numElements * 12;
 
     // Using one atomic offset to maintain order and atomicity
     printfBuffer[PRINTF_OFFSETS].type = PRINTF_OFFSETS;
@@ -210,7 +200,7 @@ PrintfError process_str_batch(PrintfPacket* queue, int poffset, unsigned int& so
   unsigned int str_len = string_length(string);
   unsigned int sb_offset = soffset;
   char* string_buffer = (char*) queue[PRINTF_STRING_BUFFER].data.ptr;
-  if (!string_buffer || soffset + str_len + 1 > queue[PRINTF_STRING_BUFFER_SIZE].data.ui){
+  if (!string_buffer || soffset + str_len + 1 > queue[PRINTF_STRING_BUFFER_SIZE].data.uli){
     return PRINTF_STRING_BUFFER_OVERFLOW;
   }
   copy_n(&string_buffer[sb_offset], string, str_len + 1);
@@ -260,10 +250,10 @@ static inline PrintfError printf(PrintfPacket* queue, All... all) [[hc,cpu]] {
   if (!queue) {
     error = PRINTF_BUFFER_NULLPTR;
   }
-  else if (count_arg + 1 + queue[PRINTF_OFFSETS].data.uia[0] > queue[PRINTF_BUFFER_SIZE].data.ui) {
+  else if (count_arg + 1 + queue[PRINTF_OFFSETS].data.uia[0] > queue[PRINTF_BUFFER_SIZE].data.uli) {
     error = PRINTF_BUFFER_OVERFLOW;
   }
-  else if (!queue[PRINTF_STRING_BUFFER].data.ptr || count_char + queue[PRINTF_OFFSETS].data.uia[1] > queue[PRINTF_STRING_BUFFER_SIZE].data.ui){
+  else if (!queue[PRINTF_STRING_BUFFER].data.ptr || count_char + queue[PRINTF_OFFSETS].data.uia[1] > queue[PRINTF_STRING_BUFFER_SIZE].data.uli){
     error = PRINTF_STRING_BUFFER_OVERFLOW;
   }
   else {
@@ -280,10 +270,10 @@ static inline PrintfError printf(PrintfPacket* queue, All... all) [[hc,cpu]] {
     unsigned int poffset = (unsigned int)old_off.uia[0];
     unsigned int soffset = (unsigned int)old_off.uia[1];
 
-    if (poffset + count_arg + 1 > queue[PRINTF_BUFFER_SIZE].data.ui) {
+    if (poffset + count_arg + 1 > queue[PRINTF_BUFFER_SIZE].data.uli) {
       error = PRINTF_BUFFER_OVERFLOW;
     }
-    else if (soffset + count_char > queue[PRINTF_STRING_BUFFER_SIZE].data.ui){
+    else if (soffset + count_char > queue[PRINTF_STRING_BUFFER_SIZE].data.uli){
       error = PRINTF_STRING_BUFFER_OVERFLOW;
     }
     else {

diff --git a/lib/hsa/mcwamp_hsa.cpp b/lib/hsa/mcwamp_hsa.cpp
@@ -3333,89 +3333,106 @@ class HSADevice final : public KalmarDevice
 
 namespace hc {
 
-#ifdef HC_PRINTF_SUPPORT_ENABLE
+static void printArgument(const std::string &spec, const PrintfPacket *ptr) {
+    switch (spec.back()) {
+    case 'c':
+    case 'd':
+    case 'i':
+      std::printf(spec.c_str(), ptr->data.li);
+      return;
+    case 'o':
+    case 'u':
+    case 'x':
+    case 'X':
+      std::printf(spec.c_str(), ptr->data.uli);
+      return;
+    case 'f':
+    case 'F':
+    case 'e':
+    case 'E':
+    case 'g':
+    case 'G':
+    case 'a':
+    case 'A':
+      std::printf(spec.c_str(), ptr->data.d);
+      return;
+    case 's':
+    case 'p':
+      std::printf(spec.c_str(), ptr->data.cptr);
+      return;
+    }
+}
 
-// regex for finding format string specifiers
-static const std::regex specifierPattern("(%){1}[-+#0]*[0-9]*((.)[0-9]+){0,1}([hl]*)([diuoxXfFeEgGaAcsp]){1}");
-static const std::regex signedIntegerPattern("(%){1}[-+#0]*[0-9]*((.)[0-9]+){0,1}([hl]*)([cdi]){1}");
-static const std::regex unsignedIntegerPattern("(%){1}[-+#0]*[0-9]*((.)[0-9]+){0,1}([hl]*)([uoxX]){1}");
-static const std::regex floatPattern("(%){1}[-+#0]*[0-9]*((.)[0-9]+){0,1}([fFeEgGaA]){1}");
-static const std::regex pointerPattern("(%){1}[ps]");
-static const std::regex doubleAmpersandPattern("(%){2}");
-static const std::string ampersand("%");
+void format(const std::string &fmt, const PrintfPacket *ptr, const PrintfPacket *end) {
+  const char conv_specifiers[] = "diuoxXfFeEgGaAcsp";
 
-static inline void processPrintfPackets(PrintfPacket* packets, const unsigned int numPackets) {
+  size_t point = 0;
 
-  for (unsigned int i = 0; i < numPackets; ) {
+  while (true) {
+    // Each segment of the format string delineated by [mark, point)
+    // is handled seprately.
+    auto mark = point;
+    point = fmt.find('%', point);
 
-    unsigned int numPrintfArgs = packets[i++].data.ui;
-    if (numPrintfArgs == 0)
-      continue;
+    // Two different cases where a literal segment is printed out.
+    // 1. When the point reaches the end of the format string.
+    // 2. When the point is at the start of a format specifier.
+    if (point == std::string::npos) {
+      std::printf("%s", &fmt[mark]);
+      return;
+    }
 
-    // get the format
-    unsigned int formatStringIndex = i++;
-    assert(packets[formatStringIndex].type == PRINTF_CHAR_PTR
-           || packets[formatStringIndex].type == PRINTF_CONST_CHAR_PTR);
-    std::string formatString((const char*)packets[formatStringIndex].data.cptr);
-    std::smatch specifierMatches;
-
-#if HC_PRINTF_DEBUG
-    std::printf("%s:%d \t number of matches = %d\n", __FUNCTION__, __LINE__, (int)specifierMatches.size());
-#endif
+    std::printf("%.*s", (int)(point - mark), &fmt[mark]);
 
-    for (unsigned int j = 1; j < numPrintfArgs; ++j, ++i) {
+    mark = point;
+    ++point;
 
-      if (!std::regex_search(formatString, specifierMatches, specifierPattern)) {
-        // More printf argument than format specifier??
-        // Just skip to the next printf request
-        i+=(numPrintfArgs - j);
-        break;
-      }
+    // Handle the simplest specifier, '%%'.
+    if (fmt[point] == '%') {
+      std::printf("%%");
+      ++point;
+      continue;
+    }
 
-      std::string specifier = specifierMatches.str();
-#if HC_PRINTF_DEBUG
-      std::cout << " (specifier found: " << specifier << ") ";
-#endif
+    // If we have run out of arguments, bail out.
+    if (ptr == end) {
+      return;
+    }
 
-      // print the substring before the specifier
-      // clean up all the double ampersands
-      std::string prefix = specifierMatches.prefix();
-      prefix = std::regex_replace(prefix,doubleAmpersandPattern,ampersand);
-      std::printf("%s",prefix.c_str());
-
-      std::smatch specifierTypeMatch;
-      if (std::regex_search(specifier, specifierTypeMatch, unsignedIntegerPattern)) {
-        std::printf(specifier.c_str(), packets[i].data.ui);
-      } else if (std::regex_search(specifier, specifierTypeMatch, signedIntegerPattern)) {
-        std::printf(specifier.c_str(), packets[i].data.i);
-      } else if (std::regex_search(specifier, specifierTypeMatch, floatPattern)) {
-        if (packets[i].type == PRINTF_HALF)
-          std::cout << static_cast<float>(packets[i].data.h);
-        else if (packets[i].type == PRINTF_FLOAT)
-          std::printf(specifier.c_str(), packets[i].data.f);
-        else
-          std::printf(specifier.c_str(), packets[i].data.d);
-      } else if (std::regex_search(specifier, specifierTypeMatch, pointerPattern)) {
-        std::printf(specifier.c_str(), packets[i].data.cptr);
-      }
-      else {
-        assert(false);
-      }
-      formatString = specifierMatches.suffix();
+    // Undefined behaviour if we don't see a conversion specifier.
+    point = fmt.find_first_of(conv_specifiers, point);
+    if (point == std::string::npos) {
+      return;
     }
-    // print the substring after the last specifier
-    // clean up all the double ampersands before printing
-    formatString = std::regex_replace(formatString,doubleAmpersandPattern,ampersand);
-    std::printf("%s",formatString.c_str());
+    ++point;
+
+    // [mark,point) now contains a complete specifier.
+    const std::string spec(fmt, mark, point - mark);
+    printArgument(spec, ptr);
+    ++ptr;
   }
-  std::flush(std::cout);
 }
 
-#else
+static inline void processPrintfPackets(PrintfPacket* packets, const unsigned int numPackets) {
+  auto pkt = packets;
+  auto end = pkt + numPackets;
 
-static inline void processPrintfPackets(PrintfPacket* packets, const unsigned int numPackets) { }
+  while (pkt != end) {
+    unsigned int numPrintfArgs = pkt->data.uli;
+    ++pkt;
+    if (numPrintfArgs == 0)
+      continue;
+
+    // get the format
+    assert(pkt->type == PRINTF_CHAR_PKT || pkt->type == PRINTF_CONST_CHAR_PKT);
+    const std::string formatString((const char*)pkt->data.cptr);
+    ++pkt;
 
-#endif  // #ifdef HC_PRINTF_SUPPORT_ENABLE
+    format(formatString, pkt, end);
+    pkt += numPrintfArgs - 1;
+  }
+  std::flush(std::cout);
+}
 
 static inline void processPrintfBuffer(PrintfPacket* gpuBuffer) {
 
@@ -3425,7 +3442,7 @@ static inline void processPrintfBuffer(PrintfPacket* gpuBuffer) {
 
   // check whether the printf buffer is non-empty
   if (cursor !=  PRINTF_HEADER_SIZE) {
-    unsigned int bufferSize = gpuBuffer[PRINTF_BUFFER_SIZE].data.ui;
+    unsigned int bufferSize = gpuBuffer[PRINTF_BUFFER_SIZE].data.uli;
     unsigned int numPackets = ((bufferSize<cursor)?bufferSize:cursor) - PRINTF_HEADER_SIZE;
 
     processPrintfPackets(gpuBuffer+PRINTF_HEADER_SIZE, numPackets);
@@ -3623,7 +3640,6 @@ class HSAContext final : public KalmarContext
         }
         def = Devices[first_gpu_index + HCC_DEFAULT_GPU];
 
-#ifdef HC_PRINTF_SUPPORT_ENABLE
         // pinned hc::printf_buffer so that the GPUs could access it
         if (hc::printf_buffer_locked_va == nullptr) {
           hsa_status_t status = HSA_STATUS_SUCCESS;
@@ -3632,7 +3648,6 @@ class HSAContext final : public KalmarContext
                                        hsa_agents, agents.size(), (void**)&hc::printf_buffer_locked_va);
           STATUS_CHECK(status, __LINE__);
         }
-#endif
 
         init_success = true;
     }
@@ -3659,7 +3674,11 @@ class HSAContext final : public KalmarContext
         if (!init_success)
           return;
 
-#if HC_PRINTF_SUPPORT_ENABLE
+#if 0
+        // For reasons that we don't understand, the printf buffer
+        // occasionally disappears before this point. As a workaround,
+        // we avoid accessing the printf buffer here.
+        //
         // deallocate the printf buffer
         if (HCC_ENABLE_PRINTF &&
             hc::printf_buffer != nullptr) {
@@ -3668,10 +3687,10 @@ class HSAContext final : public KalmarContext
 
            hc::deletePrintfBuffer(hc::printf_buffer);
         }
+#endif
         status = hsa_amd_memory_unlock(&hc::printf_buffer);
         STATUS_CHECK(status, __LINE__);
         hc::printf_buffer_locked_va = nullptr;
-#endif
 
         // destroy all KalmarDevices associated with this context
         for (auto dev : Devices)
@@ -5827,8 +5846,6 @@ HSACopy::syncCopy() {
 // ----------------------------------------------------------------------
 
 extern "C" void *GetContextImpl() {
-
-#ifdef HC_PRINTF_SUPPORT_ENABLE
   // If hc::printf is enabled, it must be initialized *after* the Kalmar::ctx is created.
   // We only want to do this once, but the call to initPrintfBuffer will recurse back
   // into this getter. We use TLS to make sure the same thread is the one recursing.
@@ -5842,8 +5859,6 @@ extern "C" void *GetContextImpl() {
       });
     }
   }
-#endif
-
   return Kalmar::ctx;
 }
 

diff --git a/scripts/cmake/MCWAMP.cmake b/scripts/cmake/MCWAMP.cmake
@@ -25,10 +25,6 @@ macro(amp_target name )
   add_definitions(-DHCC_MAJOR_VERSION=${HCC_VERSION_MAJOR})
   add_definitions(-DHCC_MINOR_VERSION=${HCC_VERSION_MINOR})
 
-  # printf has to be disable on RHEL/CentOS 7.x due to unstable support of std::regex
-  # Disabling experimental hc::printf on all platforms due to breakage and lack of maintance
-  # target_compile_definitions(${name} PRIVATE HC_PRINTF_SUPPORT_ENABLE)
-
   target_compile_definitions(${name} PRIVATE "GTEST_HAS_TR1_TUPLE=0")
   target_include_directories(${name} SYSTEM PRIVATE ${GTEST_INC_DIR} ${LIBCXX_INC_DIR})
   target_include_directories(${name} PRIVATE ${MCWAMP_INC_DIR})

diff --git a/tests/Unit/Printf/lit.local.cfg b/tests/Unit/Printf/lit.local.cfg
@@ -0,0 +1 @@
+config.environment['HCC_ENABLE_PRINTF'] = "1"
diff --git a/tests/Unit/HSA/no_printf.cpp → tests/Unit/Printf/no_printf.cpp b/tests/Unit/HSA/no_printf.cpp → tests/Unit/Printf/no_printf.cpp
diff --git a/tests/Unit/HSA/printf.cpp → tests/Unit/Printf/printf.cpp b/tests/Unit/HSA/printf.cpp → tests/Unit/Printf/printf.cpp
@@ -1,4 +1,3 @@
-// XFAIL: *
 // RUN: %hc %s -DHCC_ENABLE_ACCELERATOR_PRINTF -lhc_am -o %t.out && %t.out | %FileCheck %s
 
 #include <cassert>

diff --git a/tests/Unit/HSA/printf_error_check.cpp → tests/Unit/Printf/printf_error_check.cpp b/tests/Unit/HSA/printf_error_check.cpp → tests/Unit/Printf/printf_error_check.cpp
@@ -1,4 +1,3 @@
-// XFAIL: *
 // RUN: %hc %s -DHCC_ENABLE_ACCELERATOR_PRINTF -DCHECK_PRINTF_ERROR -lhc_am -o %t.out && %t.out | %FileCheck %s
 
 #include <cassert>

diff --git a/tests/Unit/HSA/printf_excess_args.cpp → tests/Unit/Printf/printf_excess_args.cpp b/tests/Unit/HSA/printf_excess_args.cpp → tests/Unit/Printf/printf_excess_args.cpp
@@ -1,4 +1,3 @@
-// XFAIL: *
 // RUN: %hc %s -DHCC_ENABLE_ACCELERATOR_PRINTF -lhc_am -o %t.out && %t.out | %FileCheck %s
 
 #include <cassert>

diff --git a/tests/Unit/HSA/printf_minimal.cpp → tests/Unit/Printf/printf_minimal.cpp b/tests/Unit/HSA/printf_minimal.cpp → tests/Unit/Printf/printf_minimal.cpp
@@ -1,4 +1,3 @@
-// XFAIL: *
 // RUN: %hc %s -DHCC_ENABLE_ACCELERATOR_PRINTF -lhc_am -o %t.out && %t.out | %FileCheck %s
 
 #include <hc.hpp>

diff --git a/tests/Unit/HSA/printf_ptr_addr.cpp → tests/Unit/Printf/printf_ptr_addr.cpp b/tests/Unit/HSA/printf_ptr_addr.cpp → tests/Unit/Printf/printf_ptr_addr.cpp
@@ -1,4 +1,3 @@
-// XFAIL: *
 // RUN: %hc %s -DHCC_ENABLE_ACCELERATOR_PRINTF -lhc_am -o %t.out && %t.out | %FileCheck %s
 
 #include <hc.hpp>

diff --git a/tests/Unit/HSA/printf_supported_types.cpp → tests/Unit/Printf/printf_supported_types.cpp b/tests/Unit/HSA/printf_supported_types.cpp → tests/Unit/Printf/printf_supported_types.cpp