8138916: Logging write function does not allow for long enough messages
authorrprotacio
Wed, 04 Nov 2015 17:18:59 -0500
changeset 33766 3290cae587f9
parent 33754 49614940dafc
child 33767 394379a4a03d
8138916: Logging write function does not allow for long enough messages Summary: The unified logging framework's vwrite function is updated to allow strings longer than 512 characters, for the sake of messages of non-pre-determined length. Reviewed-by: coleenp, dsamersoff, mlarsson
hotspot/src/os/posix/vm/os_posix.cpp
hotspot/src/os/windows/vm/os_windows.cpp
hotspot/src/share/vm/logging/log.cpp
hotspot/src/share/vm/logging/log.hpp
hotspot/src/share/vm/prims/jni.cpp
hotspot/src/share/vm/runtime/os.hpp
--- a/hotspot/src/os/posix/vm/os_posix.cpp	Mon Aug 18 14:37:55 2014 +0200
+++ b/hotspot/src/os/posix/vm/os_posix.cpp	Wed Nov 04 17:18:59 2015 -0500
@@ -177,6 +177,10 @@
   return aligned_base;
 }
 
+int os::log_vsnprintf(char* buf, size_t len, const char* fmt, va_list args) {
+    return vsnprintf(buf, len, fmt, args);
+}
+
 void os::Posix::print_load_average(outputStream* st) {
   st->print("load average:");
   double loadavg[3];
--- a/hotspot/src/os/windows/vm/os_windows.cpp	Mon Aug 18 14:37:55 2014 +0200
+++ b/hotspot/src/os/windows/vm/os_windows.cpp	Wed Nov 04 17:18:59 2015 -0500
@@ -1608,6 +1608,15 @@
   if (nl != NULL) *nl = '\0';
 }
 
+int os::log_vsnprintf(char* buf, size_t len, const char* fmt, va_list args) {
+  int ret = vsnprintf(buf, len, fmt, args);
+  // Get the correct buffer size if buf is too small
+  if (ret < 0) {
+    return _vscprintf(fmt, args);
+  }
+  return ret;
+}
+
 void os::print_os_info_brief(outputStream* st) {
   os::print_os_info(st);
 }
--- /dev/null	Thu Jan 01 00:00:00 1970 +0000
+++ b/hotspot/src/share/vm/logging/log.cpp	Wed Nov 04 17:18:59 2015 -0500
@@ -0,0 +1,94 @@
+/*
+ * Copyright (c) 2015, Oracle and/or its affiliates. All rights reserved.
+ * DO NOT ALTER OR REMOVE COPYRIGHT NOTICES OR THIS FILE HEADER.
+ *
+ * This code is free software; you can redistribute it and/or modify it
+ * under the terms of the GNU General Public License version 2 only, as
+ * published by the Free Software Foundation.
+ *
+ * This code is distributed in the hope that it will be useful, but WITHOUT
+ * ANY WARRANTY; without even the implied warranty of MERCHANTABILITY or
+ * FITNESS FOR A PARTICULAR PURPOSE.  See the GNU General Public License
+ * version 2 for more details (a copy is included in the LICENSE file that
+ * accompanied this code).
+ *
+ * You should have received a copy of the GNU General Public License version
+ * 2 along with this work; if not, write to the Free Software Foundation,
+ * Inc., 51 Franklin St, Fifth Floor, Boston, MA 02110-1301 USA.
+ *
+ * Please contact Oracle, 500 Oracle Parkway, Redwood Shores, CA 94065 USA
+ * or visit www.oracle.com if you need additional information or have any
+ * questions.
+ *
+ */
+
+#include "precompiled.hpp"
+
+/////////////// Unit tests ///////////////
+
+#ifndef PRODUCT
+
+#include "logging/log.hpp"
+#include "logging/logConfiguration.hpp"
+#include "memory/resourceArea.hpp"
+
+void Test_log_length() {
+  remove("loglengthoutput.txt");
+
+  // Write long message to output file
+  MutexLocker ml(LogConfiguration_lock);
+  LogConfiguration::parse_log_arguments("loglengthoutput.txt", "logging=develop",
+    NULL, NULL, NULL);
+  ResourceMark rm;
+  outputStream* logstream = LogHandle(logging)::develop_stream();
+  logstream->print_cr("01:1234567890-"
+                      "02:1234567890-"
+                      "03:1234567890-"
+                      "04:1234567890-"
+                      "05:1234567890-"
+                      "06:1234567890-"
+                      "07:1234567890-"
+                      "08:1234567890-"
+                      "09:1234567890-"
+                      "10:1234567890-"
+                      "11:1234567890-"
+                      "12:1234567890-"
+                      "13:1234567890-"
+                      "14:1234567890-"
+                      "15:1234567890-"
+                      "16:1234567890-"
+                      "17:1234567890-"
+                      "18:1234567890-"
+                      "19:1234567890-"
+                      "20:1234567890-"
+                      "21:1234567890-"
+                      "22:1234567890-"
+                      "23:1234567890-"
+                      "24:1234567890-"
+                      "25:1234567890-"
+                      "26:1234567890-"
+                      "27:1234567890-"
+                      "28:1234567890-"
+                      "29:1234567890-"
+                      "30:1234567890-"
+                      "31:1234567890-"
+                      "32:1234567890-"
+                      "33:1234567890-"
+                      "34:1234567890-"
+                      "35:1234567890-"
+                      "36:1234567890-"
+                      "37:1234567890-");
+
+  // Look for end of message in output file
+  FILE* fp;
+  fp = fopen("loglengthoutput.txt", "r");
+  assert (fp, "File read error");
+  char output[600];
+  if (fgets(output, 600, fp) != NULL) {
+    assert(strstr(output, "37:1234567890-"), "logging print size error");
+  }
+  fclose(fp);
+  remove("loglengthoutput.txt");
+}
+#endif // PRODUCT
+
--- a/hotspot/src/share/vm/logging/log.hpp	Mon Aug 18 14:37:55 2014 +0200
+++ b/hotspot/src/share/vm/logging/log.hpp	Wed Nov 04 17:18:59 2015 -0500
@@ -29,6 +29,8 @@
 #include "logging/logTagSet.hpp"
 #include "logging/logTag.hpp"
 #include "memory/allocation.hpp"
+#include "memory/allocation.inline.hpp"
+#include "runtime/os.hpp"
 #include "utilities/debug.hpp"
 #include "utilities/ostream.hpp"
 
@@ -104,9 +106,20 @@
   static void vwrite(const char* fmt, va_list args) {
     char buf[LogBufferSize];
     size_t prefix_len = LogPrefix<T0, T1, T2, T3, T4>::prefix(buf, sizeof(buf));
-    int ret = vsnprintf(buf + prefix_len, sizeof(buf) - prefix_len, fmt, args);
-    assert(ret >= 0 && (size_t)ret < sizeof(buf), "Log message too long");
-    puts<Level>(buf);
+    // Check that string fits in buffer; resize buffer if necessary
+    int ret = os::log_vsnprintf(buf + prefix_len, sizeof(buf) - prefix_len, fmt, args);
+    assert(ret >= 0, "Log message buffer issue");
+    if ((size_t)ret > sizeof(buf)) {
+      size_t newbuf_len = prefix_len + ret + 1;
+      char* newbuf = NEW_C_HEAP_ARRAY(char, newbuf_len, mtLogging);
+      prefix_len = LogPrefix<T0, T1, T2, T3, T4>::prefix(newbuf, newbuf_len);
+      ret = os::log_vsnprintf(newbuf + prefix_len, newbuf_len - prefix_len, fmt, args);
+      assert(ret >= 0, "Log message buffer issue");
+      puts<Level>(newbuf);
+      FREE_C_HEAP_ARRAY(char, newbuf);
+    } else {
+      puts<Level>(buf);
+    }
   }
 
   template <LogLevelType Level>
--- a/hotspot/src/share/vm/prims/jni.cpp	Mon Aug 18 14:37:55 2014 +0200
+++ b/hotspot/src/share/vm/prims/jni.cpp	Wed Nov 04 17:18:59 2015 -0500
@@ -3869,6 +3869,7 @@
 void Test_linked_list();
 void TestResourcehash_test();
 void TestChunkedList_test();
+void Test_log_length();
 #if INCLUDE_ALL_GCS
 void TestOldFreeSpaceCalculation_test();
 void TestG1BiasedArray_test();
@@ -3909,6 +3910,7 @@
     run_unit_test(ObjectMonitor::sanity_checks());
     run_unit_test(Test_linked_list());
     run_unit_test(TestChunkedList_test());
+    run_unit_test(Test_log_length());
 #if INCLUDE_VM_STRUCTS
     run_unit_test(VMStructs::test());
 #endif
--- a/hotspot/src/share/vm/runtime/os.hpp	Mon Aug 18 14:37:55 2014 +0200
+++ b/hotspot/src/share/vm/runtime/os.hpp	Wed Nov 04 17:18:59 2015 -0500
@@ -589,6 +589,9 @@
   static void *find_agent_function(AgentLibrary *agent_lib, bool check_lib,
                                    const char *syms[], size_t syms_len);
 
+  // Write to stream
+  static int log_vsnprintf(char* buf, size_t len, const char* fmt, va_list args) ATTRIBUTE_PRINTF(3, 0);
+
   // Print out system information; they are called by fatal error handler.
   // Output format may be different on different platforms.
   static void print_os_info(outputStream* st);