Wed Jan 28 010:09:47 UTC 2009 Marcel Smit <msmit@remedy.nl>

        * tests/Bug_3559_Regression:
        * tests/Bug_3559_Regression/Bug_3559_Regression_Test.cpp:
        * tests/Bug_3559_Regression/Bug_3559_Regression_Test.mpc:
        * tests/Bug_3559_Regression/run_test.pl:
          
          Added a new regression test for bug 3559. 
          This test is there to check whether the logging framework
          logs timestamps when -ORBVerboseLogging and -ORBLogFile 
          are set. The test initializes the ORB with -ORBVerboseLogging 
          set to 0, 1 and 2. This test checks whether the logging flags are 
          set properly and afterward it checks the generated log file.

4 files changed, 266 insertions, 0 deletions

diff --git a/TAO/ChangeLog b/TAO/ChangeLog
index dadd672a0ff..d103fc650dd 100644
--- a/TAO/ChangeLog
+++ b/TAO/ChangeLog
@@ -1,3 +1,17 @@
+Wed Jan 28 010:09:47 UTC 2009  Marcel Smit  <msmit@remedy.nl>
+
+        * tests/Bug_3559_Regression:
+        * tests/Bug_3559_Regression/Bug_3559_Regression_Test.cpp:
+        * tests/Bug_3559_Regression/Bug_3559_Regression_Test.mpc:
+        * tests/Bug_3559_Regression/run_test.pl:
+          
+          Added a new regression test for bug 3559. 
+          This test is there to check whether the logging framework
+          logs timestamps when -ORBVerboseLogging and -ORBLogFile 
+          are set. The test initializes the ORB with -ORBVerboseLogging 
+          set to 0, 1 and 2. This test checks whether the logging flags are 
+          set properly and afterward it checks the generated log file.
+
 Wed Jan 28 08:59:25 UTC 2009  Vladimir Zykov  <vz@prismtech.com>
 
         * tests/Sequence_Unit_Tests/unbounded_sequence_cdr_ut.cpp:
diff --git a/TAO/tests/Bug_3559_Regression/Bug_3559_Regression_Test.cpp b/TAO/tests/Bug_3559_Regression/Bug_3559_Regression_Test.cpp
new file mode 100644
index 00000000000..c83b9353fc5
--- /dev/null
+++ b/TAO/tests/Bug_3559_Regression/Bug_3559_Regression_Test.cpp
@@ -0,0 +1,213 @@
+// $Id$
+
+#include "tao/ORB.h"
+#include "ace/Get_Opt.h"
+#include "ace/Log_Msg.h"
+#include "ace/OS_NS_stdio.h"
+#include "ace/ace.h"
+
+ACE_RCSID (Bug_3559_Regression,
+           server,
+           "$Id$")
+
+const ACE_TCHAR* log_file_;
+
+
+int
+parse_args(int argc, ACE_TCHAR* argv[])
+{
+  ACE_Get_Opt get_opts(argc, argv, ACE_TEXT("l:"));
+
+  int c;
+
+  while ((c = get_opts()) != -1)
+    {
+      switch (c)
+      {
+        case 'l':
+          log_file_ = get_opts.opt_arg();
+          return 0;
+      }
+    }
+  return 1;
+}
+
+
+int 
+check_logging()
+{
+  ACE_TCHAR buf[1024];
+  FILE* fp = ACE_OS::fopen (ACE_TEXT (log_file_),
+                            ACE_TEXT ("r"));
+
+  if (fp == 0)
+    {
+      ACE_ERROR ((LM_ERROR,
+                  ACE_TEXT ("error opening log file %s\n"),
+                  log_file_));
+      return 1;
+    }
+
+
+  while (ACE_OS::fgets (buf, sizeof (buf), fp) != 0)
+    {
+      ///When verbose is on, a line contains a timestamp and and LM_ string
+      if  (strstr (buf,"LM_") != 0)
+        {
+          ACE_DEBUG((LM_DEBUG, 
+                     ACE_TEXT("Test OK, a timestamp was found\n")));
+          (void) ACE_OS::fclose (fp);
+          return 0;
+        }
+    }
+  ACE_ERROR ((LM_ERROR,
+              ACE_TEXT ("Test failed, no timestamp found in log\n")));
+  (void) ACE_OS::fclose (fp);
+  return 1;
+}
+
+int
+check_flags(const u_long& flags, const int& verbose)
+{
+  int result = 0;
+  switch (verbose)
+    {
+      case 0:
+        /// Both VERBOSE and VERBOSE_LITE should be set
+        if ((flags & ACE_Log_Msg::VERBOSE) == 0 &&
+            (flags & ACE_Log_Msg::VERBOSE_LITE) == 0)
+          {
+            ACE_DEBUG ((LM_ERROR,
+                        ACE_TEXT("Test failed: Verbose flag not set properly when verbose=0\n")));
+            result = 1;
+          }
+        break;
+      case 1:
+        /// VERBOSE_LITE should be set
+        if ((flags & ACE_Log_Msg::VERBOSE_LITE) == 0)
+          {
+            ACE_DEBUG ((LM_ERROR,
+                        ACE_TEXT("Test failed: Verbose flag not set properly when verbose=1\n")));
+            result = 1;
+          }
+        break;
+      default:
+        /// VERBOSE should be set
+        if ((flags & ACE_Log_Msg::VERBOSE) == 0)
+          {
+            ACE_DEBUG ((LM_ERROR,
+                        ACE_TEXT("Test failed: Verbose flag not set properly when verbose=unknown\n")));
+            result = 1;
+          }
+        break;
+    }
+  return result;
+}
+
+int
+ACE_TMAIN(int argc, ACE_TCHAR *argv[])
+{
+  int result = 0;
+  int extra_argc = 25;
+
+  try
+    {
+      if (parse_args(argc, argv) != 0)
+      {
+        ACE_ERROR((LM_ERROR,
+                   ACE_TEXT("Usage:\n\n")
+                   ACE_TEXT("OPTIONS:\n\n")
+                   ACE_TEXT("\t[-l Log file]\n\n")));
+        result = 1;
+      }
+
+      for (int verbose = 0; verbose < 3 && result == 0; verbose++)
+        {
+          ACE_DEBUG ((LM_DEBUG,
+                      ACE_TEXT ("Start ORB_init with ORBVerboseLogging=%d\n"),
+                      verbose));
+
+          ACE_TCHAR **extra = 0;
+          ACE_NEW_RETURN (extra, ACE_TCHAR *[extra_argc], -1);
+          extra[0] = ACE::strnew (ACE_TEXT ("-ORBCDRTradeoff"));
+          extra[1] = ACE::strnew (ACE_TEXT ("2048"));
+          extra[2] = ACE::strnew (ACE_TEXT ("-ORBCollocation"));
+          extra[3] = ACE::strnew (ACE_TEXT ("per-orb"));
+          extra[4] = ACE::strnew (ACE_TEXT ("-ORBDebug"));
+          extra[5] = ACE::strnew (ACE_TEXT ("-ORBDebugLevel"));
+          extra[6] = ACE::strnew (ACE_TEXT ("10"));
+          extra[7] = ACE::strnew (ACE_TEXT ("-ORBDefaultInitRef"));
+          extra[8] = ACE::strnew (ACE_TEXT ("corbaloc::localhost:4177"));
+          extra[9] = ACE::strnew (ACE_TEXT ("-ORBDottedDecimalAddresses"));
+          extra[10] = ACE::strnew (ACE_TEXT ("1"));
+          extra[11] = ACE::strnew (ACE_TEXT ("-ORBId"));
+          extra[12] = ACE::strnew (ACE_TEXT ("Client"));
+          extra[13] = ACE::strnew (ACE_TEXT ("-ORBListenEndpoints"));
+          extra[14] = ACE::strnew (ACE_TEXT ("iiop://:4178"));
+          extra[15] = ACE::strnew (ACE_TEXT ("-ORBLogFile"));
+          ACE_NEW_RETURN (extra[16],
+            ACE_TCHAR[ACE_OS::strlen(log_file_) + 1],
+                          -1);
+          ACE_OS::sprintf (extra[16], "%s", log_file_);
+          extra[17] = ACE::strnew (ACE_TEXT ("-ORBNegotiateCodesets"));
+          extra[18] = ACE::strnew (ACE_TEXT ("0"));
+          extra[19] = ACE::strnew (ACE_TEXT ("-ORBNodelay"));
+          extra[20] = ACE::strnew (ACE_TEXT ("1"));
+          extra[21] = ACE::strnew (ACE_TEXT ("-ORBSvcConfDirective"));
+          extra[22] = ACE::strnew (ACE_TEXT ("\"static Client_Strategy_Factory '-ORBWaitStrategy mt_noupcall'\""));
+          extra[23] = ACE::strnew (ACE_TEXT ("-ORBVerboseLogging"));
+          ACE_NEW_RETURN (extra[24],
+                          ACE_TCHAR[2],
+                          -1);
+          ACE_OS::sprintf (extra[24], "%d", verbose);
+
+          ACE_TCHAR **largv = new ACE_TCHAR *[argc+extra_argc];
+          for (int i = 0; i < argc; i++)
+            largv[i] = argv[i];
+
+          ACE_DEBUG ((LM_DEBUG,"server adding args: "));
+          for (int i = 0; i < extra_argc; i++)
+            {
+              ACE_DEBUG ((LM_DEBUG, "%s ", extra[i]));
+              largv[argc+i] = extra[i];
+            }
+          ACE_DEBUG ((LM_DEBUG, "\n"));
+
+          argc += extra_argc;
+          
+          ACE_TCHAR orb_name[25];
+          ACE_OS::sprintf(orb_name, "VERBOSE_LOGGING_TEST_%d", verbose);
+
+          CORBA::ORB_var orb = CORBA::ORB_init (argc, largv, orb_name);
+          
+          u_long log_flags = ACE_Log_Msg::instance()->flags();
+
+          ACE_DEBUG ((LM_DEBUG,
+                      ACE_TEXT ("log flags %d verbose: %d\n"),
+                      log_flags, verbose));
+
+          result += check_flags(log_flags, verbose);
+          
+          orb->destroy ();
+          orb = CORBA::ORB::_nil();
+
+          for (int i = 0; i < extra_argc; i++)
+            ACE::strdelete (extra[i]);
+          delete [] extra;
+          delete [] largv;
+        }
+    }
+  catch (const CORBA::Exception& ex)
+    {
+      ex._tao_print_exception ("Exception caught:");
+      return 1;
+    }
+  
+  result += check_logging();
+  if (result == 0)
+    ACE_DEBUG((LM_DEBUG, ACE_TEXT("Test passed")));
+  else
+    ACE_ERROR ((LM_ERROR, ACE_TEXT ("Test failed. Result: %d"), 
+                result));
+  return result;
+}
diff --git a/TAO/tests/Bug_3559_Regression/Bug_3559_Regression_Test.mpc b/TAO/tests/Bug_3559_Regression/Bug_3559_Regression_Test.mpc
new file mode 100644
index 00000000000..7398d598257
--- /dev/null
+++ b/TAO/tests/Bug_3559_Regression/Bug_3559_Regression_Test.mpc
@@ -0,0 +1,8 @@
+// -*- MPC -*-
+// $Id$
+
+project(*Server): taoserver {
+  Source_Files {
+    Bug_3559_Regression_Test.cpp
+  }
+}
\ No newline at end of file
diff --git a/TAO/tests/Bug_3559_Regression/run_test.pl b/TAO/tests/Bug_3559_Regression/run_test.pl
new file mode 100755
index 00000000000..835cb633b67
--- /dev/null
+++ b/TAO/tests/Bug_3559_Regression/run_test.pl
@@ -0,0 +1,31 @@
+eval '(exit $?0)' && eval 'exec perl -S $0 ${1+"$@"}'
+     & eval 'exec perl -S $0 $argv:q'
+     if 0;
+
+# $Id$
+# -*- perl -*-
+
+use lib "$ENV{ACE_ROOT}/bin";
+use PerlACE::TestTarget;
+
+$debug_level = '0';
+
+foreach $i (@ARGV) {
+    if ($i eq '-debug') {
+        $debug_level = '10';
+    }
+}
+
+my $server = PerlACE::TestTarget::create_target (1) || die "Create target 1 failed\n";
+
+$orb_log = "ORBLog.log";
+$server->LocalFile ($orb_log);
+$server->DeleteFile ($orb_log);
+
+$SV = $server->CreateProcess ("server", "-l $orb_log");
+
+$SV->Spawn ();
+     
+$SV->WaitKill ($server->ProcessStopWaitInterval());
+
+exit 0;