common_time: Turn the logging up to 11

Hand merge from ics-aah

> DO NOT MERGE: common_time: Turn the logging up to 11
>
> Actually, despite the CL title, no addition log messages are being
> sent to logcat.  Generally speaking, the common_time service tends to
> be rather quiet from a log perspective.  Events related to master
> election and arbitration as well as state changes tend to be
> infrequent in steady state operation.  Unfortunately, if there is a
> problem with the system, it frequently gets pushed out of logcat by
> other messages and is missing from the logs when a bugreport is
> finally taken.
>
> This change adds a utility class which can be used to store the last N
> log message in a ring buffer to be dumped later during a dumpsys
> operation.  Three internal log buffers were added to the system.  One
> to record messages having to do with state transitions.  Another was
> added to record traffic relating to master election, and one final
> buffer to record basic data on packets which were received but
> discarded for any reason.  During a bugreport, these common_time.clock
> service will be able to dump these messages regardless of the amt of
> other logcat activity, which should assist in debugging long running
> issues.
>
> Change-Id: Ic3bbf7480c8978f9bf82bafaba04cf4586db60cf
> Signed-off-by: John Grossman <johngro@google.com>

Change-Id: If7156d41ce4553d5ba5c3a8e1dd616564a569711
Signed-off-by: John Grossman <johngro@google.com>
diff --git a/services/common_time/clock_recovery.cpp b/services/common_time/clock_recovery.cpp
index 4a5b2ef..3a7c70c 100644
--- a/services/common_time/clock_recovery.cpp
+++ b/services/common_time/clock_recovery.cpp
@@ -225,6 +225,9 @@
     if (current_point == min_rtt || rtt < control_thresh_) {
         delta_f = delta = nominal_common_time - observed_common;
 
+        last_error_est_valid_ = true;
+        last_error_est_usec_ = delta;
+
         // Compute the error then clamp to the panic threshold.  If we ever
         // exceed this amt of error, its time to panic and reset the system.
         // Given that the error in the measurement of the error could be as
@@ -258,7 +261,6 @@
 
     // Save error terms for later.
     last_delta_f_ = delta_f;
-    last_delta_ = delta;
 
     // Clamp CO to +/- 100ppm.
     if (CO < COmin)
@@ -295,8 +297,8 @@
 int32_t ClockRecoveryLoop::getLastErrorEstimate() {
     Mutex::Autolock lock(&lock_);
 
-    if (last_delta_valid_)
-        return last_delta_;
+    if (last_error_est_valid_)
+        return last_error_est_usec_;
     else
         return ICommonClock::kErrorEstimateUnknown;
 }
@@ -310,8 +312,8 @@
     }
 
     if (frequency) {
-        last_delta_valid_ = false;
-        last_delta_ = 0;
+        last_error_est_valid_ = false;
+        last_error_est_usec_ = 0;
         last_delta_f_ = 0.0;
         CO = 0.0f;
         lastCObias = CObias = 0.0f;
diff --git a/services/common_time/clock_recovery.h b/services/common_time/clock_recovery.h
index 20fbf96..b6c87ff 100644
--- a/services/common_time/clock_recovery.h
+++ b/services/common_time/clock_recovery.h
@@ -108,8 +108,8 @@
 
     // parameters maintained while running and reset during a reset
     // of the frequency correction.
-    bool    last_delta_valid_;
-    int32_t last_delta_;
+    bool    last_error_est_valid_;
+    int32_t last_error_est_usec_;
     float last_delta_f_;
     int32_t integrated_error_;
     int32_t tgt_correction_;
diff --git a/services/common_time/common_time_server.cpp b/services/common_time/common_time_server.cpp
index 0125709..16be8f1 100644
--- a/services/common_time/common_time_server.cpp
+++ b/services/common_time/common_time_server.cpp
@@ -107,6 +107,9 @@
     , mTimelineID(ICommonClock::kInvalidTimelineID)
     , mClockSynced(false)
     , mCommonClockHasClients(false)
+    , mStateChangeLog("Recent State Change Events", 30)
+    , mElectionLog("Recent Master Election Traffic", 30)
+    , mBadPktLog("Recent Bad Packet RX Info", 8)
     , mInitial_WhoIsMasterRequestTimeouts(0)
     , mClient_MasterDeviceID(0)
     , mClient_MasterDevicePriority(0)
@@ -330,10 +333,11 @@
             // we are in any other state (CLIENT, RONIN or WAIT_FOR_ELECTION),
             // then transition to either INITIAL or MASTER depending on whether
             // or not our timeline is valid.
-            ALOGI("Entering networkless mode interface is %s, "
-                 "shouldAutoDisable = %s",
-                 mBindIfaceValid ? "valid" : "invalid",
-                 shouldAutoDisable() ? "true" : "false");
+            mStateChangeLog.log(ANDROID_LOG_INFO, LOG_TAG,
+                    "Entering networkless mode interface is %s, "
+                    "shouldAutoDisable = %s",
+                    mBindIfaceValid ? "valid" : "invalid",
+                    shouldAutoDisable() ? "true" : "false");
             if ((mState != ICommonClock::STATE_INITIAL) &&
                 (mState != ICommonClock::STATE_MASTER)) {
                 if (mTimelineID == ICommonClock::kInvalidTimelineID)
@@ -415,20 +419,23 @@
 
     sockaddrToString(mMasterElectionEP, true, masterElectionEPStr,
                      sizeof(masterElectionEPStr));
-    ALOGI("Building socket :: bind = %s master election = %s",
-         mBindIface.string(), masterElectionEPStr);
+    mStateChangeLog.log(ANDROID_LOG_INFO, LOG_TAG,
+                        "Building socket :: bind = %s master election = %s",
+                        mBindIface.string(), masterElectionEPStr);
 
     // TODO: add proper support for IPv6.  Right now, we block IPv6 addresses at
     // the configuration interface level.
     if (AF_INET != mMasterElectionEP.ss_family) {
-        ALOGW("TODO: add proper IPv6 support");
+        mStateChangeLog.log(ANDROID_LOG_WARN, LOG_TAG,
+                            "TODO: add proper IPv6 support");
         goto bailout;
     }
 
     // open a UDP socket for the timeline serivce
     mSocket = socket(AF_INET, SOCK_DGRAM, IPPROTO_UDP);
     if (mSocket < 0) {
-        ALOGE("Failed to create socket (errno = %d)", errno);
+        mStateChangeLog.log(ANDROID_LOG_ERROR, LOG_TAG,
+                            "Failed to create socket (errno = %d)", errno);
         goto bailout;
     }
 
@@ -440,8 +447,9 @@
     rc = setsockopt(mSocket, SOL_SOCKET, SO_BINDTODEVICE,
                     (void *)&ifr, sizeof(ifr));
     if (rc) {
-        ALOGE("Failed to bind socket at to interface %s (errno = %d)",
-              ifr.ifr_name, errno);
+        mStateChangeLog.log(ANDROID_LOG_ERROR, LOG_TAG,
+                            "Failed to bind socket at to interface %s "
+                            "(errno = %d)", ifr.ifr_name, errno);
         goto bailout;
     }
 
@@ -459,8 +467,9 @@
               reinterpret_cast<const sockaddr *>(&bindAddr),
               sizeof(bindAddr));
     if (rc) {
-        ALOGE("Failed to bind socket to port %hu (errno = %d)",
-              ntohs(bindAddr.sin_port), errno);
+        mStateChangeLog.log(ANDROID_LOG_ERROR, LOG_TAG,
+                            "Failed to bind socket to port %hu (errno = %d)",
+                            ntohs(bindAddr.sin_port), errno);
         goto bailout;
     }
 
@@ -483,17 +492,20 @@
         rc = setsockopt(mSocket, IPPROTO_IP, IP_MULTICAST_LOOP,
                         &zero, sizeof(zero));
         if (rc == -1) {
-            ALOGE("Failed to disable multicast loopback (errno = %d)", errno);
+            mStateChangeLog.log(ANDROID_LOG_ERROR, LOG_TAG,
+                                "Failed to disable multicast loopback "
+                                "(errno = %d)", errno);
             goto bailout;
         }
     } else
     if (ntohl(ipv4_addr->sin_addr.s_addr) == 0xFFFFFFFF) {
         // If the master election address is the broadcast address, then enable
         // the broadcast socket option
-        const int one = 1;
         rc = setsockopt(mSocket, SOL_SOCKET, SO_BROADCAST, &one, sizeof(one));
         if (rc == -1) {
-            ALOGE("Failed to enable broadcast (errno = %d)", errno);
+            mStateChangeLog.log(ANDROID_LOG_ERROR, LOG_TAG,
+                                "Failed to enable broadcast (errno = %d)",
+                                errno);
             goto bailout;
         }
     } else {
@@ -507,7 +519,8 @@
     // the local subnet)
     rc = setsockopt(mSocket, IPPROTO_IP, IP_TTL, &one, sizeof(one));
     if (rc == -1) {
-        ALOGE("Failed to set TTL to %d (errno = %d)", one, errno);
+        mStateChangeLog.log(ANDROID_LOG_ERROR, LOG_TAG,
+                            "Failed to set TTL to %d (errno = %d)", one, errno);
         goto bailout;
     }
 
@@ -569,6 +582,31 @@
            ((devicePrio1 == devicePrio2) && (deviceID1 > deviceID2)));
 }
 
+static void hexDumpToString(const uint8_t* src, size_t src_len,
+                            char* dst, size_t dst_len) {
+    size_t offset;
+    size_t i;
+
+    for (i = 0; (i < src_len) && (offset < dst_len); ++i) {
+        int res;
+        if (0 == (i % 16)) {
+            res = snprintf(dst + offset, dst_len - offset, "\n%04x :", i);
+            if (res < 0)
+                break;
+            offset += res;
+            if (offset >= dst_len)
+                break;
+        }
+
+        res = snprintf(dst + offset, dst_len - offset, " %02x", src[i]);
+        if (res < 0)
+            break;
+        offset += res;
+    }
+
+    dst[dst_len - 1] = 0;
+}
+
 bool CommonTimeServer::handlePacket() {
     uint8_t buf[256];
     struct sockaddr_storage srcAddr;
@@ -579,14 +617,24 @@
             reinterpret_cast<const sockaddr *>(&srcAddr), &srcAddrLen);
 
     if (recvBytes < 0) {
-        ALOGE("%s:%d recvfrom failed", __PRETTY_FUNCTION__, __LINE__);
+        mBadPktLog.log(ANDROID_LOG_ERROR, LOG_TAG,
+                       "recvfrom failed (res %d, errno %d)",
+                       recvBytes, errno);
         return false;
     }
 
     UniversalTimeServicePacket pkt;
-    recvBytes = pkt.deserializePacket(buf, recvBytes, mSyncGroupID);
-    if (recvBytes < 0)
+    if (pkt.deserializePacket(buf, recvBytes, mSyncGroupID) < 0) {
+        char hex[256];
+        char srcEPStr[64];
+
+        hexDumpToString(buf, static_cast<size_t>(recvBytes), hex, sizeof(hex));
+        sockaddrToString(srcAddr, true, srcEPStr, sizeof(srcEPStr));
+
+        mBadPktLog.log("Failed to parse %d byte packet from %s.%s",
+                       recvBytes, srcEPStr, hex);
         return false;
+    }
 
     bool result;
     switch (pkt.packetType) {
@@ -614,8 +662,13 @@
             break;
 
         default: {
-            ALOGD("%s:%d unknown packet type(%d)",
-                    __PRETTY_FUNCTION__, __LINE__, pkt.packetType);
+            char srcEPStr[64];
+            sockaddrToString(srcAddr, true, srcEPStr, sizeof(srcEPStr));
+
+            mBadPktLog.log(ANDROID_LOG_WARN, LOG_TAG,
+                           "unknown packet type (%d) from %s",
+                           pkt.packetType, srcEPStr);
+
             result = false;
         } break;
     }
@@ -699,6 +752,14 @@
 bool CommonTimeServer::handleWhoIsMasterRequest(
         const WhoIsMasterRequestPacket* request,
         const sockaddr_storage& srcAddr) {
+
+    char srcEPStr[64];
+    sockaddrToString(srcAddr, true, srcEPStr, sizeof(srcEPStr));
+    mElectionLog.log("RXed WhoIs master request while in state %s.  "
+                     "src %s reqTID %016llx ourTID %016llx",
+                     stateToString(mState), srcEPStr,
+                     request->timelineID, mTimelineID);
+
     if (mState == ICommonClock::STATE_MASTER) {
         // is this request related to this master's timeline?
         if (request->timelineID != ICommonClock::kInvalidTimelineID &&
@@ -710,6 +771,13 @@
         pkt.deviceID = mDeviceID;
         pkt.devicePriority = effectivePriority();
 
+        mElectionLog.log("TXing WhoIs master resp to %s while in state %s.  "
+                         "ourTID %016llx ourGID %016llx ourDID %016llx "
+                         "ourPrio %u",
+                         srcEPStr, stateToString(mState),
+                         mTimelineID, mSyncGroupID,
+                         pkt.deviceID, pkt.devicePriority);
+
         uint8_t buf[256];
         ssize_t bufSz = pkt.serializePacket(buf, sizeof(buf));
         if (bufSz < 0)
@@ -761,6 +829,17 @@
 bool CommonTimeServer::handleWhoIsMasterResponse(
         const WhoIsMasterResponsePacket* response,
         const sockaddr_storage& srcAddr) {
+    char srcEPStr[64];
+    sockaddrToString(srcAddr, true, srcEPStr, sizeof(srcEPStr));
+    mElectionLog.log("RXed WhoIs master response while in state %s.  "
+                     "src %s respTID %016llx respDID %016llx respPrio %u "
+                     "ourTID %016llx",
+                     stateToString(mState), srcEPStr,
+                     response->timelineID,
+                     response->deviceID,
+                     static_cast<uint32_t>(response->devicePriority),
+                     mTimelineID);
+
     if (mState == ICommonClock::STATE_INITIAL || mState == ICommonClock::STATE_RONIN) {
         return becomeClient(srcAddr,
                             response->deviceID,
@@ -917,6 +996,14 @@
     uint8_t  newDevicePrio = packet->devicePriority;
     uint64_t newTimelineID = packet->timelineID;
 
+    char srcEPStr[64];
+    sockaddrToString(srcAddr, true, srcEPStr, sizeof(srcEPStr));
+    mElectionLog.log("RXed master announcement while in state %s.  "
+                     "src %s srcDevID %lld srcPrio %u srcTID %016llx",
+                     stateToString(mState), srcEPStr,
+                     newDeviceID, static_cast<uint32_t>(newDevicePrio),
+                     newTimelineID);
+
     if (mState == ICommonClock::STATE_INITIAL ||
         mState == ICommonClock::STATE_RONIN ||
         mState == ICommonClock::STATE_WAIT_FOR_ELECTION) {
@@ -973,6 +1060,15 @@
     uint8_t buf[256];
     ssize_t bufSz = pkt.serializePacket(buf, sizeof(buf));
     if (bufSz >= 0) {
+        char dstEPStr[64];
+        sockaddrToString(mMasterElectionEP, true, dstEPStr, sizeof(dstEPStr));
+        mElectionLog.log("TXing WhoIs master request to %s while in state %s.  "
+                         "ourTID %016llx ourGID %016llx ourDID %016llx "
+                         "ourPrio %u",
+                         dstEPStr, stateToString(mState),
+                         mTimelineID, mSyncGroupID,
+                         pkt.senderDeviceID, pkt.senderDevicePriority);
+
         ssize_t sendBytes = sendto(
                 mSocket, buf, bufSz, 0,
                 reinterpret_cast<const sockaddr *>(&mMasterElectionEP),
@@ -1049,6 +1145,15 @@
     uint8_t buf[256];
     ssize_t bufSz = pkt.serializePacket(buf, sizeof(buf));
     if (bufSz >= 0) {
+        char dstEPStr[64];
+        sockaddrToString(mMasterElectionEP, true, dstEPStr, sizeof(dstEPStr));
+        mElectionLog.log("TXing Master announcement to %s while in state %s.  "
+                         "ourTID %016llx ourGID %016llx ourDID %016llx "
+                         "ourPrio %u",
+                         dstEPStr, stateToString(mState),
+                         mTimelineID, mSyncGroupID,
+                         pkt.deviceID, pkt.devicePriority);
+
         ssize_t sendBytes = sendto(
                 mSocket, buf, bufSz, 0,
                 reinterpret_cast<const sockaddr *>(&mMasterElectionEP),
@@ -1071,15 +1176,16 @@
     sockaddrToString(masterEP, true, newEPStr, sizeof(newEPStr));
     sockaddrToString(mMasterEP, mMasterEPValid, oldEPStr, sizeof(oldEPStr));
 
-    ALOGI("%s --> CLIENT (%s) :%s"
-         " OldMaster: %02x-%014llx::%016llx::%s"
-         " NewMaster: %02x-%014llx::%016llx::%s",
-         stateToString(mState), cause,
-         (mTimelineID != timelineID) ? " (new timeline)" : "",
-         mClient_MasterDevicePriority, mClient_MasterDeviceID,
-         mTimelineID, oldEPStr,
-         masterDevicePriority, masterDeviceID,
-         timelineID, newEPStr);
+    mStateChangeLog.log(ANDROID_LOG_INFO, LOG_TAG,
+            "%s --> CLIENT (%s) :%s"
+            " OldMaster: %02x-%014llx::%016llx::%s"
+            " NewMaster: %02x-%014llx::%016llx::%s",
+            stateToString(mState), cause,
+            (mTimelineID != timelineID) ? " (new timeline)" : "",
+            mClient_MasterDevicePriority, mClient_MasterDeviceID,
+            mTimelineID, oldEPStr,
+            masterDevicePriority, masterDeviceID,
+            timelineID, newEPStr);
 
     if (mTimelineID != timelineID) {
         // start following a new timeline
@@ -1132,11 +1238,12 @@
         notifyClockSync();
     }
 
-    ALOGI("%s --> MASTER (%s) : %s timeline %016llx",
-         stateToString(mState), cause,
-         (oldTimelineID == mTimelineID) ? "taking ownership of"
-                                        : "creating new",
-         mTimelineID);
+    mStateChangeLog.log(ANDROID_LOG_INFO, LOG_TAG,
+            "%s --> MASTER (%s) : %s timeline %016llx",
+            stateToString(mState), cause,
+            (oldTimelineID == mTimelineID) ? "taking ownership of"
+                                           : "creating new",
+            mTimelineID);
 
     memset(&mMasterEP, 0, sizeof(mMasterEP));
     mMasterEPValid = false;
@@ -1165,7 +1272,8 @@
     mMasterEPValid = false;
 
     if (mCommonClock.isValid()) {
-        ALOGI("%s --> RONIN (%s) : lost track of previously valid timeline "
+        mStateChangeLog.log(ANDROID_LOG_INFO, LOG_TAG,
+             "%s --> RONIN (%s) : lost track of previously valid timeline "
              "%02x-%014llx::%016llx::%s (%d TXed %d RXed %d RXExpired)",
              stateToString(mState), cause,
              mClient_MasterDevicePriority, mClient_MasterDeviceID,
@@ -1178,7 +1286,8 @@
         setState(ICommonClock::STATE_RONIN);
         return sendWhoIsMasterRequest();
     } else {
-        ALOGI("%s --> INITIAL (%s) : never synced timeline "
+        mStateChangeLog.log(ANDROID_LOG_INFO, LOG_TAG,
+             "%s --> INITIAL (%s) : never synced timeline "
              "%02x-%014llx::%016llx::%s (%d TXed %d RXed %d RXExpired)",
              stateToString(mState), cause,
              mClient_MasterDevicePriority, mClient_MasterDeviceID,
@@ -1192,7 +1301,8 @@
 }
 
 bool CommonTimeServer::becomeWaitForElection(const char* cause) {
-    ALOGI("%s --> WAIT_FOR_ELECTION (%s) : dropping out of election,"
+    mStateChangeLog.log(ANDROID_LOG_INFO, LOG_TAG,
+         "%s --> WAIT_FOR_ELECTION (%s) : dropping out of election,"
          " waiting %d mSec for completion.",
          stateToString(mState), cause, kWaitForElection_TimeoutMs);
 
@@ -1202,7 +1312,9 @@
 }
 
 bool CommonTimeServer::becomeInitial(const char* cause) {
-    ALOGI("Entering INITIAL (%s), total reset.", cause);
+    mStateChangeLog.log(ANDROID_LOG_INFO, LOG_TAG,
+                        "Entering INITIAL (%s), total reset.",
+                        cause);
 
     setState(ICommonClock::STATE_INITIAL);
 
diff --git a/services/common_time/common_time_server.h b/services/common_time/common_time_server.h
index b2ad3f0..f6a2419 100644
--- a/services/common_time/common_time_server.h
+++ b/services/common_time/common_time_server.h
@@ -238,6 +238,11 @@
     // interface AND currently active common clock clients.
     bool mCommonClockHasClients;
 
+    // Internal logs used for dumpsys.
+    LogRing                 mStateChangeLog;
+    LogRing                 mElectionLog;
+    LogRing                 mBadPktLog;
+
     // Configuration info
     struct sockaddr_storage mMasterElectionEP;          // Endpoint over which we conduct master election
     String8                 mBindIface;                 // Endpoint for the service to bind to.
diff --git a/services/common_time/common_time_server_api.cpp b/services/common_time/common_time_server_api.cpp
index fb8c261..e157071 100644
--- a/services/common_time/common_time_server_api.cpp
+++ b/services/common_time/common_time_server_api.cpp
@@ -354,6 +354,9 @@
 
         dump_printf("Active Clients : %u\n", activeClients);
         mClient_PacketRTTLog.dumpLog(fd, mCommonClock);
+        mStateChangeLog.dumpLog(fd);
+        mElectionLog.dumpLog(fd);
+        mBadPktLog.dumpLog(fd);
     }
 
     return NO_ERROR;
diff --git a/services/common_time/utils.cpp b/services/common_time/utils.cpp
index 3ed2599..ed2c77d 100644
--- a/services/common_time/utils.cpp
+++ b/services/common_time/utils.cpp
@@ -14,6 +14,9 @@
  * limitations under the License.
  */
 
+#define LOG_TAG "common_time"
+#include <utils/Log.h>
+
 #include "utils.h"
 
 namespace android {
@@ -46,4 +49,116 @@
     return static_cast<int>(delta);
 }
 
+LogRing::LogRing(const char* header, size_t entries)
+    : mSize(entries)
+    , mWr(0)
+    , mIsFull(false)
+    , mHeader(header) {
+    mRingBuffer = new Entry[mSize];
+    if (NULL == mRingBuffer)
+        ALOGE("Failed to allocate log ring with %u entries.", mSize);
+}
+
+LogRing::~LogRing() {
+    if (NULL != mRingBuffer)
+        delete[] mRingBuffer;
+}
+
+void LogRing::log(int prio, const char* tag, const char* fmt, ...) {
+    va_list argp;
+    va_start(argp, fmt);
+    internalLog(prio, tag, fmt, argp);
+    va_end(argp);
+}
+
+void LogRing::log(const char* fmt, ...) {
+    va_list argp;
+    va_start(argp, fmt);
+    internalLog(0, NULL, fmt, argp);
+    va_end(argp);
+}
+
+void LogRing::internalLog(int prio,
+                          const char* tag,
+                          const char* fmt,
+                          va_list argp) {
+    if (NULL != mRingBuffer) {
+        Mutex::Autolock lock(&mLock);
+        String8 s(String8::formatV(fmt, argp));
+        Entry* last = NULL;
+
+        if (mIsFull || mWr)
+            last = &(mRingBuffer[(mWr + mSize - 1) % mSize]);
+
+
+        if ((NULL != last) && !last->s.compare(s)) {
+            gettimeofday(&(last->last_ts), NULL);
+            ++last->count;
+        } else {
+            gettimeofday(&mRingBuffer[mWr].first_ts, NULL);
+            mRingBuffer[mWr].last_ts = mRingBuffer[mWr].first_ts;
+            mRingBuffer[mWr].count = 1;
+            mRingBuffer[mWr].s.setTo(s);
+
+            mWr = (mWr + 1) % mSize;
+            if (!mWr)
+                mIsFull = true;
+        }
+    }
+
+    if (NULL != tag)
+        LOG_PRI_VA(prio, tag, fmt, argp);
+}
+
+void LogRing::dumpLog(int fd) {
+    if (NULL == mRingBuffer)
+        return;
+
+    Mutex::Autolock lock(&mLock);
+
+    if (!mWr && !mIsFull)
+        return;
+
+    char buf[1024];
+    int res;
+    size_t start = mIsFull ? mWr : 0;
+    size_t count = mIsFull ? mSize : mWr;
+    static const char* kTimeFmt = "%a %b %d %Y %H:%M:%S";
+
+    res = snprintf(buf, sizeof(buf), "\n%s\n", mHeader);
+    if (res > 0)
+        write(fd, buf, res);
+
+    for (size_t i = 0; i < count; ++i) {
+        struct tm t;
+        char timebuf[64];
+        char repbuf[96];
+        size_t ndx = (start + i) % mSize;
+
+        if (1 != mRingBuffer[ndx].count) {
+            localtime_r(&mRingBuffer[ndx].last_ts.tv_sec, &t);
+            strftime(timebuf, sizeof(timebuf), kTimeFmt, &t);
+            snprintf(repbuf, sizeof(repbuf),
+                    " (repeated %d times, last was %s.%03ld)",
+                     mRingBuffer[ndx].count,
+                     timebuf,
+                     mRingBuffer[ndx].last_ts.tv_usec / 1000);
+            repbuf[sizeof(repbuf) - 1] = 0;
+        } else {
+            repbuf[0] = 0;
+        }
+
+        localtime_r(&mRingBuffer[ndx].first_ts.tv_sec, &t);
+        strftime(timebuf, sizeof(timebuf), kTimeFmt, &t);
+        res = snprintf(buf, sizeof(buf), "[%2d] %s.%03ld :: %s%s\n", 
+                       i, timebuf,
+                       mRingBuffer[ndx].first_ts.tv_usec / 1000,
+                       mRingBuffer[ndx].s.string(),
+                       repbuf);
+
+        if (res > 0)
+            write(fd, buf, res);
+    }
+}
+
 }  // namespace android
diff --git a/services/common_time/utils.h b/services/common_time/utils.h
index d3545c9..c28cf0a 100644
--- a/services/common_time/utils.h
+++ b/services/common_time/utils.h
@@ -20,6 +20,8 @@
 #include <stdint.h>
 #include <unistd.h>
 
+#include <utils/String8.h>
+#include <utils/threads.h>
 #include <utils/Timers.h>
 
 namespace android {
@@ -43,6 +45,39 @@
     nsecs_t mSystemEndTime;
 };
 
+class LogRing {
+  public:
+    LogRing(const char* header, size_t entries);
+    ~LogRing();
+
+    // Send a log message to logcat as well as storing it in the ring buffer.
+    void log(int prio, const char* tag, const char* fmt, ...);
+
+    // Add a log message the ring buffer, do not send the message to logcat.
+    void log(const char* fmt, ...);
+
+    // Dump the log to an fd (dumpsys style)
+    void dumpLog(int fd);
+
+  private:
+    class Entry {
+      public:
+        uint32_t count;
+        struct timeval first_ts;
+        struct timeval last_ts;
+        String8 s;
+    };
+
+    Mutex  mLock;
+    Entry* mRingBuffer;
+    size_t mSize;
+    size_t mWr;
+    bool   mIsFull;
+    const char* mHeader;
+
+    void internalLog(int prio, const char* tag, const char* fmt, va_list va);
+};
+
 }  // namespace android
 
 #endif  // __UTILS_H__