common_time_server.cpp revision 4c57eda9f4c87bb22eb0acdd2dab4d1757d4280b
1/*
2 * Copyright (C) 2012 The Android Open Source Project
3 *
4 * Licensed under the Apache License, Version 2.0 (the "License");
5 * you may not use this file except in compliance with the License.
6 * You may obtain a copy of the License at
7 *
8 *      http://www.apache.org/licenses/LICENSE-2.0
9 *
10 * Unless required by applicable law or agreed to in writing, software
11 * distributed under the License is distributed on an "AS IS" BASIS,
12 * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
13 * See the License for the specific language governing permissions and
14 * limitations under the License.
15 */
16
17/*
18 * A service that exchanges time synchronization information between
19 * a master that defines a timeline and clients that follow the timeline.
20 */
21
22#define LOG_TAG "common_time"
23#include <utils/Log.h>
24
25#include <arpa/inet.h>
26#include <assert.h>
27#include <fcntl.h>
28#include <inttypes.h>
29#include <linux/if_ether.h>
30#include <net/if.h>
31#include <net/if_arp.h>
32#include <netinet/ip.h>
33#include <poll.h>
34#include <stdio.h>
35#include <sys/eventfd.h>
36#include <sys/ioctl.h>
37#include <sys/stat.h>
38#include <sys/types.h>
39#include <sys/socket.h>
40
41#include <common_time/local_clock.h>
42#include <binder/IPCThreadState.h>
43#include <binder/ProcessState.h>
44#include <utils/Timers.h>
45
46#include "common_clock_service.h"
47#include "common_time_config_service.h"
48#include "common_time_server.h"
49#include "common_time_server_packets.h"
50#include "clock_recovery.h"
51#include "common_clock.h"
52
53#define MAX_INT ((int)0x7FFFFFFF)
54
55namespace android {
56
57const char*    CommonTimeServer::kDefaultMasterElectionAddr = "255.255.255.255";
58const uint16_t CommonTimeServer::kDefaultMasterElectionPort = 8886;
59const uint64_t CommonTimeServer::kDefaultSyncGroupID = 1;
60const uint8_t  CommonTimeServer::kDefaultMasterPriority = 1;
61const uint32_t CommonTimeServer::kDefaultMasterAnnounceIntervalMs = 10000;
62const uint32_t CommonTimeServer::kDefaultSyncRequestIntervalMs = 1000;
63const uint32_t CommonTimeServer::kDefaultPanicThresholdUsec = 50000;
64const bool     CommonTimeServer::kDefaultAutoDisable = true;
65const int      CommonTimeServer::kSetupRetryTimeoutMs = 30000;
66const int64_t  CommonTimeServer::kNoGoodDataPanicThresholdUsec = 600000000ll;
67const uint32_t CommonTimeServer::kRTTDiscardPanicThreshMultiplier = 5;
68
69// timeout value representing an infinite timeout
70const int CommonTimeServer::kInfiniteTimeout = -1;
71
72/*** Initial state constants ***/
73
74// number of WhoIsMaster attempts sent before giving up
75const int CommonTimeServer::kInitial_NumWhoIsMasterRetries = 6;
76
77// timeout used when waiting for a response to a WhoIsMaster request
78const int CommonTimeServer::kInitial_WhoIsMasterTimeoutMs = 500;
79
80/*** Client state constants ***/
81
82// number of sync requests that can fail before a client assumes its master
83// is dead
84const int CommonTimeServer::kClient_NumSyncRequestRetries = 10;
85
86/*** Master state constants ***/
87
88/*** Ronin state constants ***/
89
90// number of WhoIsMaster attempts sent before declaring ourselves master
91const int CommonTimeServer::kRonin_NumWhoIsMasterRetries = 20;
92
93// timeout used when waiting for a response to a WhoIsMaster request
94const int CommonTimeServer::kRonin_WhoIsMasterTimeoutMs = 500;
95
96/*** WaitForElection state constants ***/
97
98// how long do we wait for an announcement from a master before
99// trying another election?
100const int CommonTimeServer::kWaitForElection_TimeoutMs = 12500;
101
102CommonTimeServer::CommonTimeServer()
103    : Thread(false)
104    , mState(ICommonClock::STATE_INITIAL)
105    , mClockRecovery(&mLocalClock, &mCommonClock)
106    , mSocket(-1)
107    , mLastPacketRxLocalTime(0)
108    , mTimelineID(ICommonClock::kInvalidTimelineID)
109    , mClockSynced(false)
110    , mCommonClockHasClients(false)
111    , mStateChangeLog("Recent State Change Events", 30)
112    , mElectionLog("Recent Master Election Traffic", 30)
113    , mBadPktLog("Recent Bad Packet RX Info", 8)
114    , mInitial_WhoIsMasterRequestTimeouts(0)
115    , mClient_MasterDeviceID(0)
116    , mClient_MasterDevicePriority(0)
117    , mRonin_WhoIsMasterRequestTimeouts(0) {
118    // zero out sync stats
119    resetSyncStats();
120
121    // Setup the master election endpoint to use the default.
122    struct sockaddr_in* meep =
123        reinterpret_cast<struct sockaddr_in*>(&mMasterElectionEP);
124    memset(&mMasterElectionEP, 0, sizeof(mMasterElectionEP));
125    inet_aton(kDefaultMasterElectionAddr, &meep->sin_addr);
126    meep->sin_family = AF_INET;
127    meep->sin_port   = htons(kDefaultMasterElectionPort);
128
129    // Zero out the master endpoint.
130    memset(&mMasterEP, 0, sizeof(mMasterEP));
131    mMasterEPValid    = false;
132    mBindIfaceValid   = false;
133    setForceLowPriority(false);
134
135    // Set all remaining configuration parameters to their defaults.
136    mDeviceID                 = 0;
137    mSyncGroupID              = kDefaultSyncGroupID;
138    mMasterPriority           = kDefaultMasterPriority;
139    mMasterAnnounceIntervalMs = kDefaultMasterAnnounceIntervalMs;
140    mSyncRequestIntervalMs    = kDefaultSyncRequestIntervalMs;
141    mPanicThresholdUsec       = kDefaultPanicThresholdUsec;
142    mAutoDisable              = kDefaultAutoDisable;
143
144    // Create the eventfd we will use to signal our thread to wake up when
145    // needed.
146    mWakeupThreadFD = eventfd(0, EFD_NONBLOCK);
147
148    // seed the random number generator (used to generated timeline IDs)
149    srand48(static_cast<unsigned int>(systemTime()));
150}
151
152CommonTimeServer::~CommonTimeServer() {
153    shutdownThread();
154
155    // No need to grab the lock here.  We are in the destructor; if the the user
156    // has a thread in any of the APIs while the destructor is being called,
157    // there is a threading problem a the application level we cannot reasonably
158    // do anything about.
159    cleanupSocket_l();
160
161    if (mWakeupThreadFD >= 0) {
162        close(mWakeupThreadFD);
163        mWakeupThreadFD = -1;
164    }
165}
166
167bool CommonTimeServer::startServices() {
168    // start the ICommonClock service
169    mICommonClock = CommonClockService::instantiate(*this);
170    if (mICommonClock == NULL)
171        return false;
172
173    // start the ICommonTimeConfig service
174    mICommonTimeConfig = CommonTimeConfigService::instantiate(*this);
175    if (mICommonTimeConfig == NULL)
176        return false;
177
178    return true;
179}
180
181bool CommonTimeServer::threadLoop() {
182    // Register our service interfaces.
183    if (!startServices())
184        return false;
185
186    // Hold the lock while we are in the main thread loop.  It will release the
187    // lock when it blocks, and hold the lock at all other times.
188    mLock.lock();
189    runStateMachine_l();
190    mLock.unlock();
191
192    IPCThreadState::self()->stopProcess();
193    return false;
194}
195
196bool CommonTimeServer::runStateMachine_l() {
197    if (!mLocalClock.initCheck())
198        return false;
199
200    if (!mCommonClock.init(mLocalClock.getLocalFreq()))
201        return false;
202
203    // Enter the initial state.
204    becomeInitial("startup");
205
206    // run the state machine
207    while (!exitPending()) {
208        struct pollfd pfds[2];
209        int rc, timeout;
210        int eventCnt = 0;
211        int64_t wakeupTime;
212        uint32_t t1, t2;
213        bool needHandleTimeout = false;
214
215        // We are always interested in our wakeup FD.
216        pfds[eventCnt].fd      = mWakeupThreadFD;
217        pfds[eventCnt].events  = POLLIN;
218        pfds[eventCnt].revents = 0;
219        eventCnt++;
220
221        // If we have a valid socket, then we are interested in what it has to
222        // say as well.
223        if (mSocket >= 0) {
224            pfds[eventCnt].fd      = mSocket;
225            pfds[eventCnt].events  = POLLIN;
226            pfds[eventCnt].revents = 0;
227            eventCnt++;
228        }
229
230        t1 = static_cast<uint32_t>(mCurTimeout.msecTillTimeout());
231        t2 = static_cast<uint32_t>(mClockRecovery.applyRateLimitedSlew());
232        timeout = static_cast<int>(t1 < t2 ? t1 : t2);
233
234        // Note, we were holding mLock when this function was called.  We
235        // release it only while we are blocking and hold it at all other times.
236        mLock.unlock();
237        rc          = poll(pfds, eventCnt, timeout);
238        wakeupTime  = mLocalClock.getLocalTime();
239        mLock.lock();
240
241        // Is it time to shutdown?  If so, don't hesitate... just do it.
242        if (exitPending())
243            break;
244
245        // Did the poll fail?  This should never happen and is fatal if it does.
246        if (rc < 0) {
247            ALOGE("%s:%d poll failed", __PRETTY_FUNCTION__, __LINE__);
248            return false;
249        }
250
251        if (rc == 0) {
252            needHandleTimeout = !mCurTimeout.msecTillTimeout();
253            if (needHandleTimeout)
254                mCurTimeout.setTimeout(kInfiniteTimeout);
255        }
256
257        // Were we woken up on purpose?  If so, clear the eventfd with a read.
258        if (pfds[0].revents)
259            clearPendingWakeupEvents_l();
260
261        // Is out bind address dirty?  If so, clean up our socket (if any).
262        // Alternatively, do we have an active socket but should be auto
263        // disabled?  If so, release the socket and enter the proper sync state.
264        bool droppedSocket = false;
265        if (mBindIfaceDirty || ((mSocket >= 0) && shouldAutoDisable())) {
266            cleanupSocket_l();
267            mBindIfaceDirty = false;
268            droppedSocket = true;
269        }
270
271        // Do we not have a socket but should have one?  If so, try to set one
272        // up.
273        if ((mSocket < 0) && mBindIfaceValid && !shouldAutoDisable()) {
274            if (setupSocket_l()) {
275                // Success!  We are now joining a new network (either coming
276                // from no network, or coming from a potentially different
277                // network).  Force our priority to be lower so that we defer to
278                // any other masters which may already be on the network we are
279                // joining.  Later, when we enter either the client or the
280                // master state, we will clear this flag and go back to our
281                // normal election priority.
282                setForceLowPriority(true);
283                switch (mState) {
284                    // If we were in initial (whether we had a immediately
285                    // before this network or not) we want to simply reset the
286                    // system and start again.  Forcing a transition from
287                    // INITIAL to INITIAL should do the job.
288                    case CommonClockService::STATE_INITIAL:
289                        becomeInitial("bound interface");
290                        break;
291
292                    // If we were in the master state, then either we were the
293                    // master in a no-network situation, or we were the master
294                    // of a different network and have moved to a new interface.
295                    // In either case, immediately transition to Ronin at low
296                    // priority.  If there is no one in the network we just
297                    // joined, we will become master soon enough.  If there is,
298                    // we want to be certain to defer master status to the
299                    // existing timeline currently running on the network.
300                    //
301                    case CommonClockService::STATE_MASTER:
302                        becomeRonin("leaving networkless mode");
303                        break;
304
305                    // If we were in any other state (CLIENT, RONIN, or
306                    // WAIT_FOR_ELECTION) then we must be moving from one
307                    // network to another.  We have lost our old master;
308                    // transition to RONIN in an attempt to find a new master.
309                    // If there are none out there, we will just assume
310                    // responsibility for the timeline we used to be a client
311                    // of.
312                    default:
313                        becomeRonin("bound interface");
314                        break;
315                }
316            } else {
317                // That's odd... we failed to set up our socket.  This could be
318                // due to some transient network change which will work itself
319                // out shortly; schedule a retry attempt in the near future.
320                mCurTimeout.setTimeout(kSetupRetryTimeoutMs);
321            }
322
323            // One way or the other, we don't have any data to process at this
324            // point (since we just tried to bulid a new socket).  Loop back
325            // around and wait for the next thing to do.
326            continue;
327        } else if (droppedSocket) {
328            // We just lost our socket, and for whatever reason (either no
329            // config, or auto disable engaged) we are not supposed to rebuild
330            // one at this time.  We are not going to rebuild our socket until
331            // something about our config/auto-disabled status changes, so we
332            // are basically in network-less mode.  If we are already in either
333            // INITIAL or MASTER, just stay there until something changes.  If
334            // we are in any other state (CLIENT, RONIN or WAIT_FOR_ELECTION),
335            // then transition to either INITIAL or MASTER depending on whether
336            // or not our timeline is valid.
337            mStateChangeLog.log(ANDROID_LOG_INFO, LOG_TAG,
338                    "Entering networkless mode interface is %s, "
339                    "shouldAutoDisable = %s",
340                    mBindIfaceValid ? "valid" : "invalid",
341                    shouldAutoDisable() ? "true" : "false");
342            if ((mState != ICommonClock::STATE_INITIAL) &&
343                (mState != ICommonClock::STATE_MASTER)) {
344                if (mTimelineID == ICommonClock::kInvalidTimelineID)
345                    becomeInitial("network-less mode");
346                else
347                    becomeMaster("network-less mode");
348            }
349
350            continue;
351        }
352
353        // Time to handle the timeouts?
354        if (needHandleTimeout) {
355            if (!handleTimeout())
356                ALOGE("handleTimeout failed");
357            continue;
358        }
359
360        // Does our socket have data for us (assuming we still have one, we
361        // may have RXed a packet at the same time as a config change telling us
362        // to shut our socket down)?  If so, process its data.
363        if ((mSocket >= 0) && (eventCnt > 1) && (pfds[1].revents)) {
364            mLastPacketRxLocalTime = wakeupTime;
365            if (!handlePacket())
366                ALOGE("handlePacket failed");
367        }
368    }
369
370    cleanupSocket_l();
371    return true;
372}
373
374void CommonTimeServer::clearPendingWakeupEvents_l() {
375    int64_t tmp;
376    read(mWakeupThreadFD, &tmp, sizeof(tmp));
377}
378
379void CommonTimeServer::wakeupThread_l() {
380    int64_t tmp = 1;
381    write(mWakeupThreadFD, &tmp, sizeof(tmp));
382}
383
384void CommonTimeServer::cleanupSocket_l() {
385    if (mSocket >= 0) {
386        close(mSocket);
387        mSocket = -1;
388    }
389}
390
391void CommonTimeServer::shutdownThread() {
392    // Flag the work thread for shutdown.
393    this->requestExit();
394
395    // Signal the thread in case its sleeping.
396    mLock.lock();
397    wakeupThread_l();
398    mLock.unlock();
399
400    // Wait for the thread to exit.
401    this->join();
402}
403
404bool CommonTimeServer::setupSocket_l() {
405    int rc;
406    bool ret_val = false;
407    struct sockaddr_in* ipv4_addr = NULL;
408    char masterElectionEPStr[64];
409    const int one = 1;
410
411    // This should never be needed, but if we happened to have an old socket
412    // lying around, be sure to not leak it before proceeding.
413    cleanupSocket_l();
414
415    // If we don't have a valid endpoint to bind to, then how did we get here in
416    // the first place?  Regardless, we know that we are going to fail to bind,
417    // so don't even try.
418    if (!mBindIfaceValid)
419        return false;
420
421    sockaddrToString(mMasterElectionEP, true, masterElectionEPStr,
422                     sizeof(masterElectionEPStr));
423    mStateChangeLog.log(ANDROID_LOG_INFO, LOG_TAG,
424                        "Building socket :: bind = %s master election = %s",
425                        mBindIface.string(), masterElectionEPStr);
426
427    // TODO: add proper support for IPv6.  Right now, we block IPv6 addresses at
428    // the configuration interface level.
429    if (AF_INET != mMasterElectionEP.ss_family) {
430        mStateChangeLog.log(ANDROID_LOG_WARN, LOG_TAG,
431                            "TODO: add proper IPv6 support");
432        goto bailout;
433    }
434
435    // open a UDP socket for the timeline serivce
436    mSocket = socket(AF_INET, SOCK_DGRAM, IPPROTO_UDP);
437    if (mSocket < 0) {
438        mStateChangeLog.log(ANDROID_LOG_ERROR, LOG_TAG,
439                            "Failed to create socket (errno = %d)", errno);
440        goto bailout;
441    }
442
443    // Bind to the selected interface using Linux's spiffy SO_BINDTODEVICE.
444    struct ifreq ifr;
445    memset(&ifr, 0, sizeof(ifr));
446    snprintf(ifr.ifr_name, sizeof(ifr.ifr_name), "%s", mBindIface.string());
447    ifr.ifr_name[sizeof(ifr.ifr_name) - 1] = 0;
448    rc = setsockopt(mSocket, SOL_SOCKET, SO_BINDTODEVICE,
449                    (void *)&ifr, sizeof(ifr));
450    if (rc) {
451        mStateChangeLog.log(ANDROID_LOG_ERROR, LOG_TAG,
452                            "Failed to bind socket at to interface %s "
453                            "(errno = %d)", ifr.ifr_name, errno);
454        goto bailout;
455    }
456
457    // Bind our socket to INADDR_ANY and the master election port.  The
458    // interface binding we made using SO_BINDTODEVICE should limit us to
459    // traffic only on the interface we are interested in.  We need to bind to
460    // INADDR_ANY and the specific master election port in order to be able to
461    // receive both unicast traffic and master election multicast traffic with
462    // just a single socket.
463    struct sockaddr_in bindAddr;
464    ipv4_addr = reinterpret_cast<struct sockaddr_in*>(&mMasterElectionEP);
465    memcpy(&bindAddr, ipv4_addr, sizeof(bindAddr));
466    bindAddr.sin_addr.s_addr = INADDR_ANY;
467    rc = bind(mSocket,
468              reinterpret_cast<const sockaddr *>(&bindAddr),
469              sizeof(bindAddr));
470    if (rc) {
471        mStateChangeLog.log(ANDROID_LOG_ERROR, LOG_TAG,
472                            "Failed to bind socket to port %hu (errno = %d)",
473                            ntohs(bindAddr.sin_port), errno);
474        goto bailout;
475    }
476
477    if (0xE0000000 == (ntohl(ipv4_addr->sin_addr.s_addr) & 0xF0000000)) {
478        // If our master election endpoint is a multicast address, be sure to join
479        // the multicast group.
480        struct ip_mreq mreq;
481        mreq.imr_multiaddr = ipv4_addr->sin_addr;
482        mreq.imr_interface.s_addr = htonl(INADDR_ANY);
483        rc = setsockopt(mSocket, IPPROTO_IP, IP_ADD_MEMBERSHIP,
484                        &mreq, sizeof(mreq));
485        if (rc == -1) {
486            ALOGE("Failed to join multicast group at %s.  (errno = %d)",
487                 masterElectionEPStr, errno);
488            goto bailout;
489        }
490
491        // disable loopback of multicast packets
492        const int zero = 0;
493        rc = setsockopt(mSocket, IPPROTO_IP, IP_MULTICAST_LOOP,
494                        &zero, sizeof(zero));
495        if (rc == -1) {
496            mStateChangeLog.log(ANDROID_LOG_ERROR, LOG_TAG,
497                                "Failed to disable multicast loopback "
498                                "(errno = %d)", errno);
499            goto bailout;
500        }
501    } else
502    if (ntohl(ipv4_addr->sin_addr.s_addr) == 0xFFFFFFFF) {
503        // If the master election address is the broadcast address, then enable
504        // the broadcast socket option
505        rc = setsockopt(mSocket, SOL_SOCKET, SO_BROADCAST, &one, sizeof(one));
506        if (rc == -1) {
507            mStateChangeLog.log(ANDROID_LOG_ERROR, LOG_TAG,
508                                "Failed to enable broadcast (errno = %d)",
509                                errno);
510            goto bailout;
511        }
512    } else {
513        // If the master election address is neither broadcast, nor multicast,
514        // then we are misconfigured.  The config API layer should prevent this
515        // from ever happening.
516        goto bailout;
517    }
518
519    // Set the TTL of sent packets to 1.  (Time protocol sync should never leave
520    // the local subnet)
521    rc = setsockopt(mSocket, IPPROTO_IP, IP_TTL, &one, sizeof(one));
522    if (rc == -1) {
523        mStateChangeLog.log(ANDROID_LOG_ERROR, LOG_TAG,
524                            "Failed to set TTL to %d (errno = %d)", one, errno);
525        goto bailout;
526    }
527
528    // get the device's unique ID
529    if (!assignDeviceID())
530        goto bailout;
531
532    ret_val = true;
533
534bailout:
535    if (!ret_val)
536        cleanupSocket_l();
537    return ret_val;
538}
539
540// generate a unique device ID that can be used for arbitration
541bool CommonTimeServer::assignDeviceID() {
542    if (!mBindIfaceValid)
543        return false;
544
545    struct ifreq ifr;
546    memset(&ifr, 0, sizeof(ifr));
547    ifr.ifr_addr.sa_family = AF_INET;
548    strlcpy(ifr.ifr_name, mBindIface.string(), IFNAMSIZ);
549
550    int rc = ioctl(mSocket, SIOCGIFHWADDR, &ifr);
551    if (rc) {
552        ALOGE("%s:%d ioctl failed", __PRETTY_FUNCTION__, __LINE__);
553        return false;
554    }
555
556    if (ifr.ifr_addr.sa_family != ARPHRD_ETHER) {
557        ALOGE("%s:%d got non-Ethernet address", __PRETTY_FUNCTION__, __LINE__);
558        return false;
559    }
560
561    mDeviceID = 0;
562    for (int i = 0; i < ETH_ALEN; i++) {
563        mDeviceID = (mDeviceID << 8) | ifr.ifr_hwaddr.sa_data[i];
564    }
565
566    return true;
567}
568
569// generate a new timeline ID
570void CommonTimeServer::assignTimelineID() {
571    do {
572        mTimelineID = (static_cast<uint64_t>(lrand48()) << 32)
573                    |  static_cast<uint64_t>(lrand48());
574    } while (mTimelineID == ICommonClock::kInvalidTimelineID);
575}
576
577// Select a preference between the device IDs of two potential masters.
578// Returns true if the first ID wins, or false if the second ID wins.
579bool CommonTimeServer::arbitrateMaster(
580        uint64_t deviceID1, uint8_t devicePrio1,
581        uint64_t deviceID2, uint8_t devicePrio2) {
582    return ((devicePrio1 >  devicePrio2) ||
583           ((devicePrio1 == devicePrio2) && (deviceID1 > deviceID2)));
584}
585
586static void hexDumpToString(const uint8_t* src, size_t src_len,
587                            char* dst, size_t dst_len) {
588    size_t offset = 0;
589    size_t i;
590
591    for (i = 0; (i < src_len) && (offset < dst_len); ++i) {
592        int res;
593        if (0 == (i % 16)) {
594            res = snprintf(dst + offset, dst_len - offset, "\n%04zx :", i);
595            if (res < 0)
596                break;
597            offset += res;
598            if (offset >= dst_len)
599                break;
600        }
601
602        res = snprintf(dst + offset, dst_len - offset, " %02x", src[i]);
603        if (res < 0)
604            break;
605        offset += res;
606    }
607
608    dst[dst_len - 1] = 0;
609}
610
611bool CommonTimeServer::handlePacket() {
612    uint8_t buf[256];
613    struct sockaddr_storage srcAddr;
614    socklen_t srcAddrLen = sizeof(srcAddr);
615
616    ssize_t recvBytes = recvfrom(
617            mSocket, buf, sizeof(buf), 0,
618            reinterpret_cast<const sockaddr *>(&srcAddr), &srcAddrLen);
619
620    if (recvBytes < 0) {
621        mBadPktLog.log(ANDROID_LOG_ERROR, LOG_TAG,
622                       "recvfrom failed (res %d, errno %d)",
623                       recvBytes, errno);
624        return false;
625    }
626
627    UniversalTimeServicePacket pkt;
628    if (pkt.deserializePacket(buf, recvBytes, mSyncGroupID) < 0) {
629        char hex[256];
630        char srcEPStr[64];
631
632        hexDumpToString(buf, static_cast<size_t>(recvBytes), hex, sizeof(hex));
633        sockaddrToString(srcAddr, true, srcEPStr, sizeof(srcEPStr));
634
635        mBadPktLog.log("Failed to parse %d byte packet from %s.%s",
636                       recvBytes, srcEPStr, hex);
637        return false;
638    }
639
640    bool result;
641    switch (pkt.packetType) {
642        case TIME_PACKET_WHO_IS_MASTER_REQUEST:
643            result = handleWhoIsMasterRequest(&pkt.p.who_is_master_request,
644                                              srcAddr);
645            break;
646
647        case TIME_PACKET_WHO_IS_MASTER_RESPONSE:
648            result = handleWhoIsMasterResponse(&pkt.p.who_is_master_response,
649                                               srcAddr);
650            break;
651
652        case TIME_PACKET_SYNC_REQUEST:
653            result = handleSyncRequest(&pkt.p.sync_request, srcAddr);
654            break;
655
656        case TIME_PACKET_SYNC_RESPONSE:
657            result = handleSyncResponse(&pkt.p.sync_response, srcAddr);
658            break;
659
660        case TIME_PACKET_MASTER_ANNOUNCEMENT:
661            result = handleMasterAnnouncement(&pkt.p.master_announcement,
662                                              srcAddr);
663            break;
664
665        default: {
666            char srcEPStr[64];
667            sockaddrToString(srcAddr, true, srcEPStr, sizeof(srcEPStr));
668
669            mBadPktLog.log(ANDROID_LOG_WARN, LOG_TAG,
670                           "unknown packet type (%d) from %s",
671                           pkt.packetType, srcEPStr);
672
673            result = false;
674        } break;
675    }
676
677    return result;
678}
679
680bool CommonTimeServer::handleTimeout() {
681    // If we have no socket, then this must be a timeout to retry socket setup.
682    if (mSocket < 0)
683        return true;
684
685    switch (mState) {
686        case ICommonClock::STATE_INITIAL:
687            return handleTimeoutInitial();
688        case ICommonClock::STATE_CLIENT:
689            return handleTimeoutClient();
690        case ICommonClock::STATE_MASTER:
691            return handleTimeoutMaster();
692        case ICommonClock::STATE_RONIN:
693            return handleTimeoutRonin();
694        case ICommonClock::STATE_WAIT_FOR_ELECTION:
695            return handleTimeoutWaitForElection();
696    }
697
698    return false;
699}
700
701bool CommonTimeServer::handleTimeoutInitial() {
702    if (++mInitial_WhoIsMasterRequestTimeouts ==
703            kInitial_NumWhoIsMasterRetries) {
704        // none of our attempts to discover a master succeeded, so make
705        // this device the master
706        return becomeMaster("initial timeout");
707    } else {
708        // retry the WhoIsMaster request
709        return sendWhoIsMasterRequest();
710    }
711}
712
713bool CommonTimeServer::handleTimeoutClient() {
714    if (shouldPanicNotGettingGoodData())
715        return becomeInitial("timeout panic, no good data");
716
717    if (mClient_SyncRequestPending) {
718        mClient_SyncRequestPending = false;
719
720        if (++mClient_SyncRequestTimeouts < kClient_NumSyncRequestRetries) {
721            // a sync request has timed out, so retry
722            return sendSyncRequest();
723        } else {
724            // The master has failed to respond to a sync request for too many
725            // times in a row.  Assume the master is dead and start electing
726            // a new master.
727            return becomeRonin("master not responding");
728        }
729    } else {
730        // initiate the next sync request
731        return sendSyncRequest();
732    }
733}
734
735bool CommonTimeServer::handleTimeoutMaster() {
736    // send another announcement from the master
737    return sendMasterAnnouncement();
738}
739
740bool CommonTimeServer::handleTimeoutRonin() {
741    if (++mRonin_WhoIsMasterRequestTimeouts == kRonin_NumWhoIsMasterRetries) {
742        // no other master is out there, so we won the election
743        return becomeMaster("no better masters detected");
744    } else {
745        return sendWhoIsMasterRequest();
746    }
747}
748
749bool CommonTimeServer::handleTimeoutWaitForElection() {
750    return becomeRonin("timeout waiting for election conclusion");
751}
752
753bool CommonTimeServer::handleWhoIsMasterRequest(
754        const WhoIsMasterRequestPacket* request,
755        const sockaddr_storage& srcAddr) {
756    // Skip our own messages which come back via broadcast loopback.
757    if (request->senderDeviceID == mDeviceID)
758        return true;
759
760    char srcEPStr[64];
761    sockaddrToString(srcAddr, true, srcEPStr, sizeof(srcEPStr));
762    mElectionLog.log("RXed WhoIs master request while in state %s.  "
763                     "src %s reqTID %016llx ourTID %016llx",
764                     stateToString(mState), srcEPStr,
765                     request->timelineID, mTimelineID);
766
767    if (mState == ICommonClock::STATE_MASTER) {
768        // is this request related to this master's timeline?
769        if (request->timelineID != ICommonClock::kInvalidTimelineID &&
770            request->timelineID != mTimelineID)
771            return true;
772
773        WhoIsMasterResponsePacket pkt;
774        pkt.initHeader(mTimelineID, mSyncGroupID);
775        pkt.deviceID = mDeviceID;
776        pkt.devicePriority = effectivePriority();
777
778        mElectionLog.log("TXing WhoIs master resp to %s while in state %s.  "
779                         "ourTID %016llx ourGID %016llx ourDID %016llx "
780                         "ourPrio %u",
781                         srcEPStr, stateToString(mState),
782                         mTimelineID, mSyncGroupID,
783                         pkt.deviceID, pkt.devicePriority);
784
785        uint8_t buf[256];
786        ssize_t bufSz = pkt.serializePacket(buf, sizeof(buf));
787        if (bufSz < 0)
788            return false;
789
790        ssize_t sendBytes = sendto(
791                mSocket, buf, bufSz, 0,
792                reinterpret_cast<const sockaddr *>(&srcAddr),
793                sizeof(srcAddr));
794        if (sendBytes == -1) {
795            ALOGE("%s:%d sendto failed", __PRETTY_FUNCTION__, __LINE__);
796            return false;
797        }
798    } else if (mState == ICommonClock::STATE_RONIN) {
799        // if we hear a WhoIsMaster request from another device following
800        // the same timeline and that device wins arbitration, then we will stop
801        // trying to elect ourselves master and will instead wait for an
802        // announcement from the election winner
803        if (request->timelineID != mTimelineID)
804            return true;
805
806        if (arbitrateMaster(request->senderDeviceID,
807                            request->senderDevicePriority,
808                            mDeviceID,
809                            effectivePriority()))
810            return becomeWaitForElection("would lose election");
811
812        return true;
813    } else if (mState == ICommonClock::STATE_INITIAL) {
814        // If a group of devices booted simultaneously (e.g. after a power
815        // outage) and all of them are in the initial state and there is no
816        // master, then each device may time out and declare itself master at
817        // the same time.  To avoid this, listen for
818        // WhoIsMaster(InvalidTimeline) requests from peers.  If we would lose
819        // arbitration against that peer, reset our timeout count so that the
820        // peer has a chance to become master before we time out.
821        if (request->timelineID == ICommonClock::kInvalidTimelineID &&
822                arbitrateMaster(request->senderDeviceID,
823                                request->senderDevicePriority,
824                                mDeviceID,
825                                effectivePriority())) {
826            mInitial_WhoIsMasterRequestTimeouts = 0;
827        }
828    }
829
830    return true;
831}
832
833bool CommonTimeServer::handleWhoIsMasterResponse(
834        const WhoIsMasterResponsePacket* response,
835        const sockaddr_storage& srcAddr) {
836    // Skip our own messages which come back via broadcast loopback.
837    if (response->deviceID == mDeviceID)
838        return true;
839
840    char srcEPStr[64];
841    sockaddrToString(srcAddr, true, srcEPStr, sizeof(srcEPStr));
842    mElectionLog.log("RXed WhoIs master response while in state %s.  "
843                     "src %s respTID %016llx respDID %016llx respPrio %u "
844                     "ourTID %016llx",
845                     stateToString(mState), srcEPStr,
846                     response->timelineID,
847                     response->deviceID,
848                     static_cast<uint32_t>(response->devicePriority),
849                     mTimelineID);
850
851    if (mState == ICommonClock::STATE_INITIAL || mState == ICommonClock::STATE_RONIN) {
852        return becomeClient(srcAddr,
853                            response->deviceID,
854                            response->devicePriority,
855                            response->timelineID,
856                            "heard whois response");
857    } else if (mState == ICommonClock::STATE_CLIENT) {
858        // if we get multiple responses because there are multiple devices
859        // who believe that they are master, then follow the master that
860        // wins arbitration
861        if (arbitrateMaster(response->deviceID,
862                            response->devicePriority,
863                            mClient_MasterDeviceID,
864                            mClient_MasterDevicePriority)) {
865            return becomeClient(srcAddr,
866                                response->deviceID,
867                                response->devicePriority,
868                                response->timelineID,
869                                "heard whois response");
870        }
871    }
872
873    return true;
874}
875
876bool CommonTimeServer::handleSyncRequest(const SyncRequestPacket* request,
877                                         const sockaddr_storage& srcAddr) {
878    SyncResponsePacket pkt;
879    pkt.initHeader(mTimelineID, mSyncGroupID);
880
881    if ((mState == ICommonClock::STATE_MASTER) &&
882        (mTimelineID == request->timelineID)) {
883        int64_t rxLocalTime = mLastPacketRxLocalTime;
884        int64_t rxCommonTime;
885
886        // If we are master on an actual network and have actual clients, then
887        // we are no longer low priority.
888        setForceLowPriority(false);
889
890        if (OK != mCommonClock.localToCommon(rxLocalTime, &rxCommonTime)) {
891            return false;
892        }
893
894        int64_t txLocalTime = mLocalClock.getLocalTime();;
895        int64_t txCommonTime;
896        if (OK != mCommonClock.localToCommon(txLocalTime, &txCommonTime)) {
897            return false;
898        }
899
900        pkt.nak = 0;
901        pkt.clientTxLocalTime  = request->clientTxLocalTime;
902        pkt.masterRxCommonTime = rxCommonTime;
903        pkt.masterTxCommonTime = txCommonTime;
904    } else {
905        pkt.nak = 1;
906        pkt.clientTxLocalTime  = 0;
907        pkt.masterRxCommonTime = 0;
908        pkt.masterTxCommonTime = 0;
909    }
910
911    uint8_t buf[256];
912    ssize_t bufSz = pkt.serializePacket(buf, sizeof(buf));
913    if (bufSz < 0)
914        return false;
915
916    ssize_t sendBytes = sendto(
917            mSocket, &buf, bufSz, 0,
918            reinterpret_cast<const sockaddr *>(&srcAddr),
919            sizeof(srcAddr));
920    if (sendBytes == -1) {
921        ALOGE("%s:%d sendto failed", __PRETTY_FUNCTION__, __LINE__);
922        return false;
923    }
924
925    return true;
926}
927
928bool CommonTimeServer::handleSyncResponse(
929        const SyncResponsePacket* response,
930        const sockaddr_storage& srcAddr) {
931    if (mState != ICommonClock::STATE_CLIENT)
932        return true;
933
934    assert(mMasterEPValid);
935    if (!sockaddrMatch(srcAddr, mMasterEP, true)) {
936        char srcEP[64], expectedEP[64];
937        sockaddrToString(srcAddr, true, srcEP, sizeof(srcEP));
938        sockaddrToString(mMasterEP, true, expectedEP, sizeof(expectedEP));
939        ALOGI("Dropping sync response from unexpected address."
940             " Expected %s Got %s", expectedEP, srcEP);
941        return true;
942    }
943
944    if (response->nak) {
945        // if our master is no longer accepting requests, then we need to find
946        // a new master
947        return becomeRonin("master NAK'ed");
948    }
949
950    mClient_SyncRequestPending = 0;
951    mClient_SyncRequestTimeouts = 0;
952    mClient_PacketRTTLog.logRX(response->clientTxLocalTime,
953                               mLastPacketRxLocalTime);
954
955    bool result;
956    if (!(mClient_SyncRespsRXedFromCurMaster++)) {
957        // the first request/response exchange between a client and a master
958        // may take unusually long due to ARP, so discard it.
959        result = true;
960    } else {
961        int64_t clientTxLocalTime  = response->clientTxLocalTime;
962        int64_t clientRxLocalTime  = mLastPacketRxLocalTime;
963        int64_t masterTxCommonTime = response->masterTxCommonTime;
964        int64_t masterRxCommonTime = response->masterRxCommonTime;
965
966        int64_t rtt       = (clientRxLocalTime - clientTxLocalTime);
967        int64_t avgLocal  = (clientTxLocalTime + clientRxLocalTime) >> 1;
968        int64_t avgCommon = (masterTxCommonTime + masterRxCommonTime) >> 1;
969
970        // if the RTT of the packet is significantly larger than the panic
971        // threshold, we should simply discard it.  Its better to do nothing
972        // than to take cues from a packet like that.
973        int64_t rttCommon = mCommonClock.localDurationToCommonDuration(rtt);
974        if (rttCommon > (static_cast<int64_t>(mPanicThresholdUsec) *
975                         kRTTDiscardPanicThreshMultiplier)) {
976            ALOGV("Dropping sync response with RTT of %" PRId64 " uSec", rttCommon);
977            mClient_ExpiredSyncRespsRXedFromCurMaster++;
978            if (shouldPanicNotGettingGoodData())
979                return becomeInitial("RX panic, no good data");
980            return true;
981        } else {
982            result = mClockRecovery.pushDisciplineEvent(avgLocal, avgCommon, rttCommon);
983            mClient_LastGoodSyncRX = clientRxLocalTime;
984
985            if (result) {
986                // indicate to listeners that we've synced to the common timeline
987                notifyClockSync();
988            } else {
989                ALOGE("Panic!  Observed clock sync error is too high to tolerate,"
990                        " resetting state machine and starting over.");
991                notifyClockSyncLoss();
992                return becomeInitial("panic");
993            }
994        }
995    }
996
997    mCurTimeout.setTimeout(mSyncRequestIntervalMs);
998    return result;
999}
1000
1001bool CommonTimeServer::handleMasterAnnouncement(
1002        const MasterAnnouncementPacket* packet,
1003        const sockaddr_storage& srcAddr) {
1004    uint64_t newDeviceID   = packet->deviceID;
1005    uint8_t  newDevicePrio = packet->devicePriority;
1006    uint64_t newTimelineID = packet->timelineID;
1007
1008    // Skip our own messages which come back via broadcast loopback.
1009    if (newDeviceID == mDeviceID)
1010        return true;
1011
1012    char srcEPStr[64];
1013    sockaddrToString(srcAddr, true, srcEPStr, sizeof(srcEPStr));
1014    mElectionLog.log("RXed master announcement while in state %s.  "
1015                     "src %s srcDevID %lld srcPrio %u srcTID %016llx",
1016                     stateToString(mState), srcEPStr,
1017                     newDeviceID, static_cast<uint32_t>(newDevicePrio),
1018                     newTimelineID);
1019
1020    if (mState == ICommonClock::STATE_INITIAL ||
1021        mState == ICommonClock::STATE_RONIN ||
1022        mState == ICommonClock::STATE_WAIT_FOR_ELECTION) {
1023        // if we aren't currently following a master, then start following
1024        // this new master
1025        return becomeClient(srcAddr,
1026                            newDeviceID,
1027                            newDevicePrio,
1028                            newTimelineID,
1029                            "heard master announcement");
1030    } else if (mState == ICommonClock::STATE_CLIENT) {
1031        // if the new master wins arbitration against our current master,
1032        // then become a client of the new master
1033        if (arbitrateMaster(newDeviceID,
1034                            newDevicePrio,
1035                            mClient_MasterDeviceID,
1036                            mClient_MasterDevicePriority))
1037            return becomeClient(srcAddr,
1038                                newDeviceID,
1039                                newDevicePrio,
1040                                newTimelineID,
1041                                "heard master announcement");
1042    } else if (mState == ICommonClock::STATE_MASTER) {
1043        // two masters are competing - if the new one wins arbitration, then
1044        // cease acting as master
1045        if (arbitrateMaster(newDeviceID, newDevicePrio,
1046                            mDeviceID, effectivePriority()))
1047            return becomeClient(srcAddr, newDeviceID,
1048                                newDevicePrio, newTimelineID,
1049                                "heard master announcement");
1050    }
1051
1052    return true;
1053}
1054
1055bool CommonTimeServer::sendWhoIsMasterRequest() {
1056    assert(mState == ICommonClock::STATE_INITIAL || mState == ICommonClock::STATE_RONIN);
1057
1058    // If we have no socket, then we must be in the unconfigured initial state.
1059    // Don't report any errors, just don't try to send the initial who-is-master
1060    // query.  Eventually, our network will either become configured, or we will
1061    // be forced into network-less master mode by higher level code.
1062    if (mSocket < 0) {
1063        assert(mState == ICommonClock::STATE_INITIAL);
1064        return true;
1065    }
1066
1067    bool ret = false;
1068    WhoIsMasterRequestPacket pkt;
1069    pkt.initHeader(mSyncGroupID);
1070    pkt.senderDeviceID = mDeviceID;
1071    pkt.senderDevicePriority = effectivePriority();
1072
1073    uint8_t buf[256];
1074    ssize_t bufSz = pkt.serializePacket(buf, sizeof(buf));
1075    if (bufSz >= 0) {
1076        char dstEPStr[64];
1077        sockaddrToString(mMasterElectionEP, true, dstEPStr, sizeof(dstEPStr));
1078        mElectionLog.log("TXing WhoIs master request to %s while in state %s.  "
1079                         "ourTID %016llx ourGID %016llx ourDID %016llx "
1080                         "ourPrio %u",
1081                         dstEPStr, stateToString(mState),
1082                         mTimelineID, mSyncGroupID,
1083                         pkt.senderDeviceID, pkt.senderDevicePriority);
1084
1085        ssize_t sendBytes = sendto(
1086                mSocket, buf, bufSz, 0,
1087                reinterpret_cast<const sockaddr *>(&mMasterElectionEP),
1088                sizeof(mMasterElectionEP));
1089        if (sendBytes < 0)
1090            ALOGE("WhoIsMaster sendto failed (errno %d)", errno);
1091        ret = true;
1092    }
1093
1094    if (mState == ICommonClock::STATE_INITIAL) {
1095        mCurTimeout.setTimeout(kInitial_WhoIsMasterTimeoutMs);
1096    } else {
1097        mCurTimeout.setTimeout(kRonin_WhoIsMasterTimeoutMs);
1098    }
1099
1100    return ret;
1101}
1102
1103bool CommonTimeServer::sendSyncRequest() {
1104    // If we are sending sync requests, then we must be in the client state and
1105    // we must have a socket (when we have no network, we are only supposed to
1106    // be in INITIAL or MASTER)
1107    assert(mState == ICommonClock::STATE_CLIENT);
1108    assert(mSocket >= 0);
1109
1110    bool ret = false;
1111    SyncRequestPacket pkt;
1112    pkt.initHeader(mTimelineID, mSyncGroupID);
1113    pkt.clientTxLocalTime = mLocalClock.getLocalTime();
1114
1115    if (!mClient_FirstSyncTX)
1116        mClient_FirstSyncTX = pkt.clientTxLocalTime;
1117
1118    mClient_PacketRTTLog.logTX(pkt.clientTxLocalTime);
1119
1120    uint8_t buf[256];
1121    ssize_t bufSz = pkt.serializePacket(buf, sizeof(buf));
1122    if (bufSz >= 0) {
1123        ssize_t sendBytes = sendto(
1124                mSocket, buf, bufSz, 0,
1125                reinterpret_cast<const sockaddr *>(&mMasterEP),
1126                sizeof(mMasterEP));
1127        if (sendBytes < 0)
1128            ALOGE("SyncRequest sendto failed (errno %d)", errno);
1129        ret = true;
1130    }
1131
1132    mClient_SyncsSentToCurMaster++;
1133    mCurTimeout.setTimeout(mSyncRequestIntervalMs);
1134    mClient_SyncRequestPending = true;
1135
1136    return ret;
1137}
1138
1139bool CommonTimeServer::sendMasterAnnouncement() {
1140    bool ret = false;
1141    assert(mState == ICommonClock::STATE_MASTER);
1142
1143    // If we are being asked to send a master announcement, but we have no
1144    // socket, we must be in network-less master mode.  Don't bother to send the
1145    // announcement, and don't bother to schedule a timeout.  When the network
1146    // comes up, the work thread will get poked and start the process of
1147    // figuring out who the current master should be.
1148    if (mSocket < 0) {
1149        mCurTimeout.setTimeout(kInfiniteTimeout);
1150        return true;
1151    }
1152
1153    MasterAnnouncementPacket pkt;
1154    pkt.initHeader(mTimelineID, mSyncGroupID);
1155    pkt.deviceID = mDeviceID;
1156    pkt.devicePriority = effectivePriority();
1157
1158    uint8_t buf[256];
1159    ssize_t bufSz = pkt.serializePacket(buf, sizeof(buf));
1160    if (bufSz >= 0) {
1161        char dstEPStr[64];
1162        sockaddrToString(mMasterElectionEP, true, dstEPStr, sizeof(dstEPStr));
1163        mElectionLog.log("TXing Master announcement to %s while in state %s.  "
1164                         "ourTID %016llx ourGID %016llx ourDID %016llx "
1165                         "ourPrio %u",
1166                         dstEPStr, stateToString(mState),
1167                         mTimelineID, mSyncGroupID,
1168                         pkt.deviceID, pkt.devicePriority);
1169
1170        ssize_t sendBytes = sendto(
1171                mSocket, buf, bufSz, 0,
1172                reinterpret_cast<const sockaddr *>(&mMasterElectionEP),
1173                sizeof(mMasterElectionEP));
1174        if (sendBytes < 0)
1175            ALOGE("MasterAnnouncement sendto failed (errno %d)", errno);
1176        ret = true;
1177    }
1178
1179    mCurTimeout.setTimeout(mMasterAnnounceIntervalMs);
1180    return ret;
1181}
1182
1183bool CommonTimeServer::becomeClient(const sockaddr_storage& masterEP,
1184                                    uint64_t masterDeviceID,
1185                                    uint8_t  masterDevicePriority,
1186                                    uint64_t timelineID,
1187                                    const char* cause) {
1188    char newEPStr[64], oldEPStr[64];
1189    sockaddrToString(masterEP, true, newEPStr, sizeof(newEPStr));
1190    sockaddrToString(mMasterEP, mMasterEPValid, oldEPStr, sizeof(oldEPStr));
1191
1192    mStateChangeLog.log(ANDROID_LOG_INFO, LOG_TAG,
1193            "%s --> CLIENT (%s) :%s"
1194            " OldMaster: %02x-%014llx::%016llx::%s"
1195            " NewMaster: %02x-%014llx::%016llx::%s",
1196            stateToString(mState), cause,
1197            (mTimelineID != timelineID) ? " (new timeline)" : "",
1198            mClient_MasterDevicePriority, mClient_MasterDeviceID,
1199            mTimelineID, oldEPStr,
1200            masterDevicePriority, masterDeviceID,
1201            timelineID, newEPStr);
1202
1203    if (mTimelineID != timelineID) {
1204        // start following a new timeline
1205        mTimelineID = timelineID;
1206        mClockRecovery.reset(true, true);
1207        notifyClockSyncLoss();
1208    } else {
1209        // start following a new master on the existing timeline
1210        mClockRecovery.reset(false, true);
1211    }
1212
1213    mMasterEP = masterEP;
1214    mMasterEPValid = true;
1215
1216    // If we are on a real network as a client of a real master, then we should
1217    // no longer force low priority.  If our master disappears, we should have
1218    // the high priority bit set during the election to replace the master
1219    // because this group was a real group and not a singleton created in
1220    // networkless mode.
1221    setForceLowPriority(false);
1222
1223    mClient_MasterDeviceID = masterDeviceID;
1224    mClient_MasterDevicePriority = masterDevicePriority;
1225    resetSyncStats();
1226
1227    setState(ICommonClock::STATE_CLIENT);
1228
1229    // add some jitter to when the various clients send their requests
1230    // in order to reduce the likelihood that a group of clients overload
1231    // the master after receiving a master announcement
1232    usleep((lrand48() % 100) * 1000);
1233
1234    return sendSyncRequest();
1235}
1236
1237bool CommonTimeServer::becomeMaster(const char* cause) {
1238    uint64_t oldTimelineID = mTimelineID;
1239    if (mTimelineID == ICommonClock::kInvalidTimelineID) {
1240        // this device has not been following any existing timeline,
1241        // so it will create a new timeline and declare itself master
1242        assert(!mCommonClock.isValid());
1243
1244        // set the common time basis
1245        mCommonClock.setBasis(mLocalClock.getLocalTime(), 0);
1246
1247        // assign an arbitrary timeline iD
1248        assignTimelineID();
1249
1250        // notify listeners that we've created a common timeline
1251        notifyClockSync();
1252    }
1253
1254    mStateChangeLog.log(ANDROID_LOG_INFO, LOG_TAG,
1255            "%s --> MASTER (%s) : %s timeline %016llx",
1256            stateToString(mState), cause,
1257            (oldTimelineID == mTimelineID) ? "taking ownership of"
1258                                           : "creating new",
1259            mTimelineID);
1260
1261    memset(&mMasterEP, 0, sizeof(mMasterEP));
1262    mMasterEPValid = false;
1263    mClient_MasterDevicePriority = effectivePriority();
1264    mClient_MasterDeviceID = mDeviceID;
1265    mClockRecovery.reset(false, true);
1266    resetSyncStats();
1267
1268    setState(ICommonClock::STATE_MASTER);
1269    return sendMasterAnnouncement();
1270}
1271
1272bool CommonTimeServer::becomeRonin(const char* cause) {
1273    // If we were the client of a given timeline, but had never received even a
1274    // single time sync packet, then we transition back to Initial instead of
1275    // Ronin.  If we transition to Ronin and end up becoming the new Master, we
1276    // will be unable to service requests for other clients because we never
1277    // actually knew what time it was.  By going to initial, we ensure that
1278    // other clients who know what time it is, but would lose master arbitration
1279    // in the Ronin case, will step up and become the proper new master of the
1280    // old timeline.
1281
1282    char oldEPStr[64];
1283    sockaddrToString(mMasterEP, mMasterEPValid, oldEPStr, sizeof(oldEPStr));
1284    memset(&mMasterEP, 0, sizeof(mMasterEP));
1285    mMasterEPValid = false;
1286
1287    if (mCommonClock.isValid()) {
1288        mStateChangeLog.log(ANDROID_LOG_INFO, LOG_TAG,
1289             "%s --> RONIN (%s) : lost track of previously valid timeline "
1290             "%02x-%014llx::%016llx::%s (%d TXed %d RXed %d RXExpired)",
1291             stateToString(mState), cause,
1292             mClient_MasterDevicePriority, mClient_MasterDeviceID,
1293             mTimelineID, oldEPStr,
1294             mClient_SyncsSentToCurMaster,
1295             mClient_SyncRespsRXedFromCurMaster,
1296             mClient_ExpiredSyncRespsRXedFromCurMaster);
1297
1298        mRonin_WhoIsMasterRequestTimeouts = 0;
1299        setState(ICommonClock::STATE_RONIN);
1300        return sendWhoIsMasterRequest();
1301    } else {
1302        mStateChangeLog.log(ANDROID_LOG_INFO, LOG_TAG,
1303             "%s --> INITIAL (%s) : never synced timeline "
1304             "%02x-%014llx::%016llx::%s (%d TXed %d RXed %d RXExpired)",
1305             stateToString(mState), cause,
1306             mClient_MasterDevicePriority, mClient_MasterDeviceID,
1307             mTimelineID, oldEPStr,
1308             mClient_SyncsSentToCurMaster,
1309             mClient_SyncRespsRXedFromCurMaster,
1310             mClient_ExpiredSyncRespsRXedFromCurMaster);
1311
1312        return becomeInitial("ronin, no timeline");
1313    }
1314}
1315
1316bool CommonTimeServer::becomeWaitForElection(const char* cause) {
1317    mStateChangeLog.log(ANDROID_LOG_INFO, LOG_TAG,
1318         "%s --> WAIT_FOR_ELECTION (%s) : dropping out of election,"
1319         " waiting %d mSec for completion.",
1320         stateToString(mState), cause, kWaitForElection_TimeoutMs);
1321
1322    setState(ICommonClock::STATE_WAIT_FOR_ELECTION);
1323    mCurTimeout.setTimeout(kWaitForElection_TimeoutMs);
1324    return true;
1325}
1326
1327bool CommonTimeServer::becomeInitial(const char* cause) {
1328    mStateChangeLog.log(ANDROID_LOG_INFO, LOG_TAG,
1329                        "Entering INITIAL (%s), total reset.",
1330                        cause);
1331
1332    setState(ICommonClock::STATE_INITIAL);
1333
1334    // reset clock recovery
1335    mClockRecovery.reset(true, true);
1336
1337    // reset internal state bookkeeping.
1338    mCurTimeout.setTimeout(kInfiniteTimeout);
1339    memset(&mMasterEP, 0, sizeof(mMasterEP));
1340    mMasterEPValid = false;
1341    mLastPacketRxLocalTime = 0;
1342    mTimelineID = ICommonClock::kInvalidTimelineID;
1343    mClockSynced = false;
1344    mInitial_WhoIsMasterRequestTimeouts = 0;
1345    mClient_MasterDeviceID = 0;
1346    mClient_MasterDevicePriority = 0;
1347    mRonin_WhoIsMasterRequestTimeouts = 0;
1348    resetSyncStats();
1349
1350    // send the first request to discover the master
1351    return sendWhoIsMasterRequest();
1352}
1353
1354void CommonTimeServer::notifyClockSync() {
1355    if (!mClockSynced) {
1356        mClockSynced = true;
1357        mICommonClock->notifyOnTimelineChanged(mTimelineID);
1358    }
1359}
1360
1361void CommonTimeServer::notifyClockSyncLoss() {
1362    if (mClockSynced) {
1363        mClockSynced = false;
1364        mICommonClock->notifyOnTimelineChanged(
1365                ICommonClock::kInvalidTimelineID);
1366    }
1367}
1368
1369void CommonTimeServer::setState(ICommonClock::State s) {
1370    mState = s;
1371}
1372
1373const char* CommonTimeServer::stateToString(ICommonClock::State s) {
1374    switch(s) {
1375        case ICommonClock::STATE_INITIAL:
1376            return "INITIAL";
1377        case ICommonClock::STATE_CLIENT:
1378            return "CLIENT";
1379        case ICommonClock::STATE_MASTER:
1380            return "MASTER";
1381        case ICommonClock::STATE_RONIN:
1382            return "RONIN";
1383        case ICommonClock::STATE_WAIT_FOR_ELECTION:
1384            return "WAIT_FOR_ELECTION";
1385        default:
1386            return "unknown";
1387    }
1388}
1389
1390void CommonTimeServer::sockaddrToString(const sockaddr_storage& addr,
1391                                        bool addrValid,
1392                                        char* buf, size_t bufLen) {
1393    if (!bufLen || !buf)
1394        return;
1395
1396    if (addrValid) {
1397        switch (addr.ss_family) {
1398            case AF_INET: {
1399                const struct sockaddr_in* sa =
1400                    reinterpret_cast<const struct sockaddr_in*>(&addr);
1401                unsigned long a = ntohl(sa->sin_addr.s_addr);
1402                uint16_t      p = ntohs(sa->sin_port);
1403                snprintf(buf, bufLen, "%lu.%lu.%lu.%lu:%hu",
1404                        ((a >> 24) & 0xFF), ((a >> 16) & 0xFF),
1405                        ((a >>  8) & 0xFF),  (a        & 0xFF), p);
1406            } break;
1407
1408            case AF_INET6: {
1409                const struct sockaddr_in6* sa =
1410                    reinterpret_cast<const struct sockaddr_in6*>(&addr);
1411                const uint8_t* a = sa->sin6_addr.s6_addr;
1412                uint16_t       p = ntohs(sa->sin6_port);
1413                snprintf(buf, bufLen,
1414                        "%02X%02X:%02X%02X:%02X%02X:%02X%02X:"
1415                        "%02X%02X:%02X%02X:%02X%02X:%02X%02X port %hd",
1416                        a[0], a[1], a[ 2], a[ 3], a[ 4], a[ 5], a[ 6], a[ 7],
1417                        a[8], a[9], a[10], a[11], a[12], a[13], a[14], a[15],
1418                        p);
1419            } break;
1420
1421            default:
1422                snprintf(buf, bufLen,
1423                         "<unknown sockaddr family %d>", addr.ss_family);
1424                break;
1425        }
1426    } else {
1427        snprintf(buf, bufLen, "<none>");
1428    }
1429
1430    buf[bufLen - 1] = 0;
1431}
1432
1433bool CommonTimeServer::sockaddrMatch(const sockaddr_storage& a1,
1434                                     const sockaddr_storage& a2,
1435                                     bool matchAddressOnly) {
1436    if (a1.ss_family != a2.ss_family)
1437        return false;
1438
1439    switch (a1.ss_family) {
1440        case AF_INET: {
1441            const struct sockaddr_in* sa1 =
1442                reinterpret_cast<const struct sockaddr_in*>(&a1);
1443            const struct sockaddr_in* sa2 =
1444                reinterpret_cast<const struct sockaddr_in*>(&a2);
1445
1446            if (sa1->sin_addr.s_addr != sa2->sin_addr.s_addr)
1447                return false;
1448
1449            return (matchAddressOnly || (sa1->sin_port == sa2->sin_port));
1450        } break;
1451
1452        case AF_INET6: {
1453            const struct sockaddr_in6* sa1 =
1454                reinterpret_cast<const struct sockaddr_in6*>(&a1);
1455            const struct sockaddr_in6* sa2 =
1456                reinterpret_cast<const struct sockaddr_in6*>(&a2);
1457
1458            if (memcmp(&sa1->sin6_addr, &sa2->sin6_addr, sizeof(sa2->sin6_addr)))
1459                return false;
1460
1461            return (matchAddressOnly || (sa1->sin6_port == sa2->sin6_port));
1462        } break;
1463
1464        // Huh?  We don't deal in non-IPv[46] addresses.  Not sure how we got
1465        // here, but we don't know how to comapre these addresses and simply
1466        // default to a no-match decision.
1467        default: return false;
1468    }
1469}
1470
1471bool CommonTimeServer::shouldPanicNotGettingGoodData() {
1472    if (mClient_FirstSyncTX) {
1473        int64_t now = mLocalClock.getLocalTime();
1474        int64_t delta = now - (mClient_LastGoodSyncRX
1475                             ? mClient_LastGoodSyncRX
1476                             : mClient_FirstSyncTX);
1477        int64_t deltaUsec = mCommonClock.localDurationToCommonDuration(delta);
1478
1479        if (deltaUsec >= kNoGoodDataPanicThresholdUsec)
1480            return true;
1481    }
1482
1483    return false;
1484}
1485
1486void CommonTimeServer::PacketRTTLog::logTX(int64_t txTime) {
1487    txTimes[wrPtr] = txTime;
1488    rxTimes[wrPtr] = 0;
1489    wrPtr = (wrPtr + 1) % RTT_LOG_SIZE;
1490    if (!wrPtr)
1491        logFull = true;
1492}
1493
1494void CommonTimeServer::PacketRTTLog::logRX(int64_t txTime, int64_t rxTime) {
1495    if (!logFull && !wrPtr)
1496        return;
1497
1498    uint32_t i = logFull ? wrPtr : 0;
1499    do {
1500        if (txTimes[i] == txTime) {
1501            rxTimes[i] = rxTime;
1502            break;
1503        }
1504        i = (i + 1) % RTT_LOG_SIZE;
1505    } while (i != wrPtr);
1506}
1507
1508}  // namespace android
1509