Add timing information to debug output to understand if

timeouts on package builders are real.

PR:		201743
Approved by:	mentors (implicit)

2 files changed, 74 insertions, 74 deletions

diff --git a/devel/ice/files/patch-cpp-test-Glacier2-override-Client.cpp b/devel/ice/files/patch-cpp-test-Glacier2-override-Client.cpp
index 4a6ab66a0902..bb1fd02c28ce 100644
--- a/devel/ice/files/patch-cpp-test-Glacier2-override-Client.cpp
+++ b/devel/ice/files/patch-cpp-test-Glacier2-override-Client.cpp
@@ -4,105 +4,105 @@
  
      {
          cout << "testing server request override... " << flush;
-+        cout << __LINE__ << endl;
++        cout << __LINE__ << " (" << time(nullptr) << ")" << endl;
          Ice::Context ctx;
-+        cout << __LINE__ << endl;
++        cout << __LINE__ << " (" << time(nullptr) << ")" << endl;
          ctx["serverOvrd"] = "test";
-+        cout << __LINE__ << endl;
++        cout << __LINE__ << " (" << time(nullptr) << ")" << endl;
          for(int i = 0; i < 5; i++)
          {
-+        cout << __LINE__ << endl;
++        cout << __LINE__ << " (" << time(nullptr) << ")" << endl;
              oneway->initiateCallback(onewayR, i, ctx);
-+        cout << __LINE__ << endl;
++        cout << __LINE__ << " (" << time(nullptr) << ")" << endl;
              oneway->initiateCallback(onewayR, i, ctx);
-+        cout << __LINE__ << endl;
++        cout << __LINE__ << " (" << time(nullptr) << ")" << endl;
              oneway->initiateCallback(onewayR, i, ctx);
-+        cout << __LINE__ << endl;
++        cout << __LINE__ << " (" << time(nullptr) << ")" << endl;
              IceUtil::ThreadControl::sleep(IceUtil::Time::milliSeconds(100));
-+        cout << __LINE__ << endl;
++        cout << __LINE__ << " (" << time(nullptr) << ")" << endl;
              test(callbackReceiverImpl->callbackOK(1, i) < 3);
-+        cout << __LINE__ << endl;
++        cout << __LINE__ << " (" << time(nullptr) << ")" << endl;
          }
-+        cout << __LINE__ << endl;
++        cout << __LINE__ << " (" << time(nullptr) << ")" << endl;
          oneway->initiateCallback(twowayR, 0);
-+        cout << __LINE__ << endl;
++        cout << __LINE__ << " (" << time(nullptr) << ")" << endl;
          test(callbackReceiverImpl->callbackOK(1, 0) == 0);
-+        cout << __LINE__ << endl;
++        cout << __LINE__ << " (" << time(nullptr) << ")" << endl;
  
          int count = 0;
          int nRetry = 0;
          do
          {
-+        cout << __LINE__ << endl;
++        cout << __LINE__ << " (" << time(nullptr) << ")" << endl;
              callbackReceiverImpl->hold();
-+        cout << __LINE__ << endl;
++        cout << __LINE__ << " (" << time(nullptr) << ")" << endl;
              oneway->initiateCallbackWithPayload(onewayR, ctx);
-+        cout << __LINE__ << endl;
++        cout << __LINE__ << " (" << time(nullptr) << ")" << endl;
              oneway->initiateCallbackWithPayload(onewayR, ctx);
-+        cout << __LINE__ << endl;
++        cout << __LINE__ << " (" << time(nullptr) << ")" << endl;
              oneway->initiateCallbackWithPayload(onewayR, ctx);
-+        cout << __LINE__ << endl;
++        cout << __LINE__ << " (" << time(nullptr) << ")" << endl;
              oneway->initiateCallbackWithPayload(onewayR, ctx);
-+        cout << __LINE__ << endl;
++        cout << __LINE__ << " (" << time(nullptr) << ")" << endl;
              oneway->initiateCallbackWithPayload(onewayR, ctx);
-+        cout << __LINE__ << endl;
++        cout << __LINE__ << " (" << time(nullptr) << ")" << endl;
              oneway->initiateCallbackWithPayload(onewayR, ctx);
-+        cout << __LINE__ << endl;
++        cout << __LINE__ << " (" << time(nullptr) << ")" << endl;
              oneway->initiateCallbackWithPayload(onewayR, ctx);
-+        cout << __LINE__ << endl;
++        cout << __LINE__ << " (" << time(nullptr) << ")" << endl;
              oneway->initiateCallbackWithPayload(onewayR, ctx);
-+        cout << __LINE__ << endl;
++        cout << __LINE__ << " (" << time(nullptr) << ")" << endl;
              oneway->initiateCallbackWithPayload(onewayR, ctx);
-+        cout << __LINE__ << endl;
++        cout << __LINE__ << " (" << time(nullptr) << ")" << endl;
              oneway->initiateCallbackWithPayload(onewayR, ctx);
-+        cout << __LINE__ << endl;
++        cout << __LINE__ << " (" << time(nullptr) << ")" << endl;
              oneway->initiateCallback(twowayR, 0);
-+        cout << __LINE__ << endl;
++        cout << __LINE__ << " (" << time(nullptr) << ")" << endl;
              IceUtil::ThreadControl::sleep(IceUtil::Time::milliSeconds(200 + nRetry * 200));
-+        cout << __LINE__ << endl;
++        cout << __LINE__ << " (" << time(nullptr) << ")" << endl;
              callbackReceiverImpl->activate();
-+        cout << __LINE__ << endl;
++        cout << __LINE__ << " (" << time(nullptr) << ")" << endl;
              test(callbackReceiverImpl->callbackOK(1, 0) == 0);
-+        cout << __LINE__ << endl;
++        cout << __LINE__ << " (" << time(nullptr) << ")" << endl;
              count = callbackReceiverImpl->callbackWithPayloadOK(0);
-+        cout << __LINE__ << endl;
++        cout << __LINE__ << " (" << time(nullptr) << ")" << endl;
              callbackReceiverImpl->callbackWithPayloadOK(count);
-+        cout << __LINE__ << endl;
++        cout << __LINE__ << " (" << time(nullptr) << ")" << endl;
          }
          while(count == 10 && nRetry++ < 10);
-+        cout << __LINE__ << endl;
++        cout << __LINE__ << " (" << time(nullptr) << ")" << endl;
          test(count < 10);
-+        cout << __LINE__ << endl;
++        cout << __LINE__ << " (" << time(nullptr) << ")" << endl;
  
          oneway->initiateCallbackWithPayload(twowayR);
-+        cout << __LINE__ << endl;
++        cout << __LINE__ << " (" << time(nullptr) << ")" << endl;
          oneway->initiateCallbackWithPayload(twowayR);
-+        cout << __LINE__ << endl;
++        cout << __LINE__ << " (" << time(nullptr) << ")" << endl;
          callbackReceiverImpl->hold();
-+        cout << __LINE__ << endl;
++        cout << __LINE__ << " (" << time(nullptr) << ")" << endl;
          oneway->initiateCallbackWithPayload(twowayR);
-+        cout << __LINE__ << endl;
++        cout << __LINE__ << " (" << time(nullptr) << ")" << endl;
          oneway->initiateCallback(onewayR, 0, ctx);
-+        cout << __LINE__ << endl;
++        cout << __LINE__ << " (" << time(nullptr) << ")" << endl;
          oneway->initiateCallback(onewayR, 0, ctx);
-+        cout << __LINE__ << endl;
++        cout << __LINE__ << " (" << time(nullptr) << ")" << endl;
          oneway->initiateCallback(onewayR, 0, ctx);
-+        cout << __LINE__ << endl;
++        cout << __LINE__ << " (" << time(nullptr) << ")" << endl;
          oneway->initiateCallback(onewayR, 0, ctx);
-+        cout << __LINE__ << endl;
++        cout << __LINE__ << " (" << time(nullptr) << ")" << endl;
          oneway->initiateCallback(onewayR, 0, ctx);
-+        cout << __LINE__ << endl;
++        cout << __LINE__ << " (" << time(nullptr) << ")" << endl;
          oneway->initiateCallbackWithPayload(twowayR);
-+        cout << __LINE__ << endl;
++        cout << __LINE__ << " (" << time(nullptr) << ")" << endl;
          IceUtil::ThreadControl::sleep(IceUtil::Time::milliSeconds(1000));
-+        cout << __LINE__ << endl;
++        cout << __LINE__ << " (" << time(nullptr) << ")" << endl;
          callbackReceiverImpl->activate();
-+        cout << __LINE__ << endl;
++        cout << __LINE__ << " (" << time(nullptr) << ")" << endl;
          test(callbackReceiverImpl->callbackWithPayloadOK(4) == 0);
-+        cout << __LINE__ << endl;
++        cout << __LINE__ << " (" << time(nullptr) << ")" << endl;
          
          int remainingCallbacks = callbackReceiverImpl->callbackOK(1, 0);
-+        cout << __LINE__ << endl;
++        cout << __LINE__ << " (" << time(nullptr) << ")" << endl;
          //
          // Occasionally, Glacier2 flushes in the middle of our 5
          // callbacks, so we get more than 1 callback
@@ -110,43 +110,43 @@
          // time to receive this (these) extra callback(s).
          //
          test(remainingCallbacks <= 4);
-+        cout << __LINE__ << endl;
++        cout << __LINE__ << " (" << time(nullptr) << ")" << endl;
          if(remainingCallbacks > 0)
          {
-+        cout << __LINE__ << endl;
++        cout << __LINE__ << " (" << time(nullptr) << ")" << endl;
              test(callbackReceiverImpl->callbackOK(remainingCallbacks, 0) == 0);
          }
-+        cout << __LINE__ << endl;
++        cout << __LINE__ << " (" << time(nullptr) << ")" << endl;
          
          ctx["_fwd"] = "O";
-+        cout << __LINE__ << endl;
++        cout << __LINE__ << " (" << time(nullptr) << ")" << endl;
  
          oneway->initiateCallbackWithPayload(twowayR);
-+        cout << __LINE__ << endl;
++        cout << __LINE__ << " (" << time(nullptr) << ")" << endl;
          callbackReceiverImpl->hold();
-+        cout << __LINE__ << endl;
++        cout << __LINE__ << " (" << time(nullptr) << ")" << endl;
          oneway->initiateCallbackWithPayload(twowayR);
-+        cout << __LINE__ << endl;
++        cout << __LINE__ << " (" << time(nullptr) << ")" << endl;
          oneway->initiateCallback(onewayR, 0, ctx);
-+        cout << __LINE__ << endl;
++        cout << __LINE__ << " (" << time(nullptr) << ")" << endl;
          oneway->initiateCallback(onewayR, 0, ctx);
-+        cout << __LINE__ << endl;
++        cout << __LINE__ << " (" << time(nullptr) << ")" << endl;
          oneway->initiateCallback(onewayR, 0, ctx);
-+        cout << __LINE__ << endl;
++        cout << __LINE__ << " (" << time(nullptr) << ")" << endl;
          oneway->initiateCallback(onewayR, 0, ctx);
-+        cout << __LINE__ << endl;
++        cout << __LINE__ << " (" << time(nullptr) << ")" << endl;
          oneway->initiateCallback(onewayR, 0, ctx);
-+        cout << __LINE__ << endl;
++        cout << __LINE__ << " (" << time(nullptr) << ")" << endl;
          oneway->initiateCallbackWithPayload(twowayR);
-+        cout << __LINE__ << endl;
++        cout << __LINE__ << " (" << time(nullptr) << ")" << endl;
          IceUtil::ThreadControl::sleep(IceUtil::Time::milliSeconds(200));
-+        cout << __LINE__ << endl;
++        cout << __LINE__ << " (" << time(nullptr) << ")" << endl;
          callbackReceiverImpl->activate();
-+        cout << __LINE__ << endl;
++        cout << __LINE__ << " (" << time(nullptr) << ")" << endl;
          test(callbackReceiverImpl->callbackWithPayloadOK(3) == 0);
-+        cout << __LINE__ << endl;
++        cout << __LINE__ << " (" << time(nullptr) << ")" << endl;
          test(callbackReceiverImpl->callbackOK(1, 0) == 0);
-+        cout << __LINE__ << endl;
++        cout << __LINE__ << " (" << time(nullptr) << ")" << endl;
  
          cout << "ok" << endl;
      }
diff --git a/devel/ice/files/patch-cpp-test-Ice-hold-AllTests.cpp b/devel/ice/files/patch-cpp-test-Ice-hold-AllTests.cpp
index 7dd89df78710..6ba24af1d753 100644
--- a/devel/ice/files/patch-cpp-test-Ice-hold-AllTests.cpp
+++ b/devel/ice/files/patch-cpp-test-Ice-hold-AllTests.cpp
@@ -4,46 +4,46 @@
          ConditionPtr cond = new Condition(true);
          int value = 0;
          Ice::AsyncResultPtr result;
-+        cout << __LINE__ << endl;
++        cout << __LINE__ << " (" << time(nullptr) << ")" << endl;
          while(value < 3000 && cond->value())
          {
 +            if (!value)
-+                cout << __LINE__ << endl;
++                cout << __LINE__ << " (" << time(nullptr) << ")" << endl;
              result = holdSerialized->begin_set(value + 1,
                                                 IceUtilInternal::random(1),
                                                 newCallback_Hold_set(new SetCB(cond, value), 
                                                                      &SetCB::response, 
                                                                      &SetCB::exception));
 +            if (!value)
-+                cout << __LINE__ << endl;
++                cout << __LINE__ << " (" << time(nullptr) << ")" << endl;
              ++value;
              if(value % 100 == 0)
              {
-+                cout << __LINE__ << endl;
++                cout << __LINE__ << " (" << time(nullptr) << ")" << endl;
                  result->waitForSent();
              }
          }
-+        cout << __LINE__ << endl;
++        cout << __LINE__ << " (" << time(nullptr) << ")" << endl;
          result->waitForCompleted();
-+        cout << __LINE__ << endl;
++        cout << __LINE__ << " (" << time(nullptr) << ")" << endl;
          test(cond->value());
-+        cout << __LINE__ << endl;
++        cout << __LINE__ << " (" << time(nullptr) << ")" << endl;
  
          for(int i = 0; i < 10000; ++i)
          {
 +            if (value == 3000)
-+                cout << __LINE__ << endl;
++                cout << __LINE__ << " (" << time(nullptr) << ")" << endl;
              holdSerialized->ice_oneway()->setOneway(value + 1, value);
 +            if (value == 3000)
-+                cout << __LINE__ << endl;
++                cout << __LINE__ << " (" << time(nullptr) << ")" << endl;
              ++value;
              if((i % 100) == 0)
              {
-+                cout << __LINE__ << endl;
++                cout << __LINE__ << " (" << time(nullptr) << ")" << endl;
                  holdSerialized->ice_oneway()->putOnHold(1);
              }
          }
-+        cout << __LINE__ << endl;
++        cout << __LINE__ << " (" << time(nullptr) << ")" << endl;
      }
      cout << "ok" << endl;