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 
55 namespace android {
56 
57 const char*    CommonTimeServer::kDefaultMasterElectionAddr = "255.255.255.255";
58 const uint16_t CommonTimeServer::kDefaultMasterElectionPort = 8886;
59 const uint64_t CommonTimeServer::kDefaultSyncGroupID = 1;
60 const uint8_t  CommonTimeServer::kDefaultMasterPriority = 1;
61 const uint32_t CommonTimeServer::kDefaultMasterAnnounceIntervalMs = 10000;
62 const uint32_t CommonTimeServer::kDefaultSyncRequestIntervalMs = 1000;
63 const uint32_t CommonTimeServer::kDefaultPanicThresholdUsec = 50000;
64 const bool     CommonTimeServer::kDefaultAutoDisable = true;
65 const int      CommonTimeServer::kSetupRetryTimeoutMs = 30000;
66 const int64_t  CommonTimeServer::kNoGoodDataPanicThresholdUsec = 600000000ll;
67 const uint32_t CommonTimeServer::kRTTDiscardPanicThreshMultiplier = 5;
68 
69 // timeout value representing an infinite timeout
70 const int CommonTimeServer::kInfiniteTimeout = -1;
71 
72 /*** Initial state constants ***/
73 
74 // number of WhoIsMaster attempts sent before giving up
75 const int CommonTimeServer::kInitial_NumWhoIsMasterRetries = 6;
76 
77 // timeout used when waiting for a response to a WhoIsMaster request
78 const 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
84 const 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
91 const int CommonTimeServer::kRonin_NumWhoIsMasterRetries = 20;
92 
93 // timeout used when waiting for a response to a WhoIsMaster request
94 const 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?
100 const int CommonTimeServer::kWaitForElection_TimeoutMs = 12500;
101 
CommonTimeServer()102 CommonTimeServer::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 | EFD_CLOEXEC);
147 
148     // seed the random number generator (used to generated timeline IDs)
149     srand48(static_cast<unsigned int>(systemTime()));
150 }
151 
~CommonTimeServer()152 CommonTimeServer::~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 
startServices()167 bool 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 
threadLoop()181 bool 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 
runStateMachine_l()196 bool 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 
clearPendingWakeupEvents_l()374 void CommonTimeServer::clearPendingWakeupEvents_l() {
375     int64_t tmp;
376     read(mWakeupThreadFD, &tmp, sizeof(tmp));
377 }
378 
wakeupThread_l()379 void CommonTimeServer::wakeupThread_l() {
380     int64_t tmp = 1;
381     write(mWakeupThreadFD, &tmp, sizeof(tmp));
382 }
383 
cleanupSocket_l()384 void CommonTimeServer::cleanupSocket_l() {
385     if (mSocket >= 0) {
386         close(mSocket);
387         mSocket = -1;
388     }
389 }
390 
shutdownThread()391 void 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 
setupSocket_l()404 bool 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 
534 bailout:
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
assignDeviceID()541 bool 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
assignTimelineID()570 void 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.
arbitrateMaster(uint64_t deviceID1,uint8_t devicePrio1,uint64_t deviceID2,uint8_t devicePrio2)579 bool 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 
hexDumpToString(const uint8_t * src,size_t src_len,char * dst,size_t dst_len)586 static 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 
handlePacket()611 bool 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<sockaddr *>(&srcAddr), &srcAddrLen);
619 
620     if (recvBytes < 0) {
621         mBadPktLog.log(ANDROID_LOG_ERROR, LOG_TAG, "recvfrom failed (%s)",
622                        strerror(errno));
623         return false;
624     }
625 
626     UniversalTimeServicePacket pkt;
627     if (pkt.deserializePacket(buf, recvBytes, mSyncGroupID) < 0) {
628         char hex[256];
629         char srcEPStr[64];
630 
631         hexDumpToString(buf, static_cast<size_t>(recvBytes), hex, sizeof(hex));
632         sockaddrToString(srcAddr, true, srcEPStr, sizeof(srcEPStr));
633 
634         mBadPktLog.log("Failed to parse %d byte packet from %s.%s",
635                        recvBytes, srcEPStr, hex);
636         return false;
637     }
638 
639     bool result;
640     switch (pkt.packetType) {
641         case TIME_PACKET_WHO_IS_MASTER_REQUEST:
642             result = handleWhoIsMasterRequest(&pkt.p.who_is_master_request,
643                                               srcAddr);
644             break;
645 
646         case TIME_PACKET_WHO_IS_MASTER_RESPONSE:
647             result = handleWhoIsMasterResponse(&pkt.p.who_is_master_response,
648                                                srcAddr);
649             break;
650 
651         case TIME_PACKET_SYNC_REQUEST:
652             result = handleSyncRequest(&pkt.p.sync_request, srcAddr);
653             break;
654 
655         case TIME_PACKET_SYNC_RESPONSE:
656             result = handleSyncResponse(&pkt.p.sync_response, srcAddr);
657             break;
658 
659         case TIME_PACKET_MASTER_ANNOUNCEMENT:
660             result = handleMasterAnnouncement(&pkt.p.master_announcement,
661                                               srcAddr);
662             break;
663 
664         default: {
665             char srcEPStr[64];
666             sockaddrToString(srcAddr, true, srcEPStr, sizeof(srcEPStr));
667 
668             mBadPktLog.log(ANDROID_LOG_WARN, LOG_TAG,
669                            "unknown packet type (%d) from %s",
670                            pkt.packetType, srcEPStr);
671 
672             result = false;
673         } break;
674     }
675 
676     return result;
677 }
678 
handleTimeout()679 bool CommonTimeServer::handleTimeout() {
680     // If we have no socket, then this must be a timeout to retry socket setup.
681     if (mSocket < 0)
682         return true;
683 
684     switch (mState) {
685         case ICommonClock::STATE_INITIAL:
686             return handleTimeoutInitial();
687         case ICommonClock::STATE_CLIENT:
688             return handleTimeoutClient();
689         case ICommonClock::STATE_MASTER:
690             return handleTimeoutMaster();
691         case ICommonClock::STATE_RONIN:
692             return handleTimeoutRonin();
693         case ICommonClock::STATE_WAIT_FOR_ELECTION:
694             return handleTimeoutWaitForElection();
695     }
696 
697     return false;
698 }
699 
handleTimeoutInitial()700 bool CommonTimeServer::handleTimeoutInitial() {
701     if (++mInitial_WhoIsMasterRequestTimeouts ==
702             kInitial_NumWhoIsMasterRetries) {
703         // none of our attempts to discover a master succeeded, so make
704         // this device the master
705         return becomeMaster("initial timeout");
706     } else {
707         // retry the WhoIsMaster request
708         return sendWhoIsMasterRequest();
709     }
710 }
711 
handleTimeoutClient()712 bool CommonTimeServer::handleTimeoutClient() {
713     if (shouldPanicNotGettingGoodData())
714         return becomeInitial("timeout panic, no good data");
715 
716     if (mClient_SyncRequestPending) {
717         mClient_SyncRequestPending = false;
718 
719         if (++mClient_SyncRequestTimeouts < kClient_NumSyncRequestRetries) {
720             // a sync request has timed out, so retry
721             return sendSyncRequest();
722         } else {
723             // The master has failed to respond to a sync request for too many
724             // times in a row.  Assume the master is dead and start electing
725             // a new master.
726             return becomeRonin("master not responding");
727         }
728     } else {
729         // initiate the next sync request
730         return sendSyncRequest();
731     }
732 }
733 
handleTimeoutMaster()734 bool CommonTimeServer::handleTimeoutMaster() {
735     // send another announcement from the master
736     return sendMasterAnnouncement();
737 }
738 
handleTimeoutRonin()739 bool CommonTimeServer::handleTimeoutRonin() {
740     if (++mRonin_WhoIsMasterRequestTimeouts == kRonin_NumWhoIsMasterRetries) {
741         // no other master is out there, so we won the election
742         return becomeMaster("no better masters detected");
743     } else {
744         return sendWhoIsMasterRequest();
745     }
746 }
747 
handleTimeoutWaitForElection()748 bool CommonTimeServer::handleTimeoutWaitForElection() {
749     return becomeRonin("timeout waiting for election conclusion");
750 }
751 
handleWhoIsMasterRequest(const WhoIsMasterRequestPacket * request,const sockaddr_storage & srcAddr)752 bool CommonTimeServer::handleWhoIsMasterRequest(
753         const WhoIsMasterRequestPacket* request,
754         const sockaddr_storage& srcAddr) {
755     // Skip our own messages which come back via broadcast loopback.
756     if (request->senderDeviceID == mDeviceID)
757         return true;
758 
759     char srcEPStr[64];
760     sockaddrToString(srcAddr, true, srcEPStr, sizeof(srcEPStr));
761     mElectionLog.log("RXed WhoIs master request while in state %s.  "
762                      "src %s reqTID %016llx ourTID %016llx",
763                      stateToString(mState), srcEPStr,
764                      request->timelineID, mTimelineID);
765 
766     if (mState == ICommonClock::STATE_MASTER) {
767         // is this request related to this master's timeline?
768         if (request->timelineID != ICommonClock::kInvalidTimelineID &&
769             request->timelineID != mTimelineID)
770             return true;
771 
772         WhoIsMasterResponsePacket pkt;
773         pkt.initHeader(mTimelineID, mSyncGroupID);
774         pkt.deviceID = mDeviceID;
775         pkt.devicePriority = effectivePriority();
776 
777         mElectionLog.log("TXing WhoIs master resp to %s while in state %s.  "
778                          "ourTID %016llx ourGID %016llx ourDID %016llx "
779                          "ourPrio %u",
780                          srcEPStr, stateToString(mState),
781                          mTimelineID, mSyncGroupID,
782                          pkt.deviceID, pkt.devicePriority);
783 
784         uint8_t buf[256];
785         ssize_t bufSz = pkt.serializePacket(buf, sizeof(buf));
786         if (bufSz < 0)
787             return false;
788 
789         ssize_t sendBytes = sendto(
790                 mSocket, buf, bufSz, 0,
791                 reinterpret_cast<const sockaddr *>(&srcAddr),
792                 sizeof(srcAddr));
793         if (sendBytes == -1) {
794             ALOGE("%s:%d sendto failed", __PRETTY_FUNCTION__, __LINE__);
795             return false;
796         }
797     } else if (mState == ICommonClock::STATE_RONIN) {
798         // if we hear a WhoIsMaster request from another device following
799         // the same timeline and that device wins arbitration, then we will stop
800         // trying to elect ourselves master and will instead wait for an
801         // announcement from the election winner
802         if (request->timelineID != mTimelineID)
803             return true;
804 
805         if (arbitrateMaster(request->senderDeviceID,
806                             request->senderDevicePriority,
807                             mDeviceID,
808                             effectivePriority()))
809             return becomeWaitForElection("would lose election");
810 
811         return true;
812     } else if (mState == ICommonClock::STATE_INITIAL) {
813         // If a group of devices booted simultaneously (e.g. after a power
814         // outage) and all of them are in the initial state and there is no
815         // master, then each device may time out and declare itself master at
816         // the same time.  To avoid this, listen for
817         // WhoIsMaster(InvalidTimeline) requests from peers.  If we would lose
818         // arbitration against that peer, reset our timeout count so that the
819         // peer has a chance to become master before we time out.
820         if (request->timelineID == ICommonClock::kInvalidTimelineID &&
821                 arbitrateMaster(request->senderDeviceID,
822                                 request->senderDevicePriority,
823                                 mDeviceID,
824                                 effectivePriority())) {
825             mInitial_WhoIsMasterRequestTimeouts = 0;
826         }
827     }
828 
829     return true;
830 }
831 
handleWhoIsMasterResponse(const WhoIsMasterResponsePacket * response,const sockaddr_storage & srcAddr)832 bool CommonTimeServer::handleWhoIsMasterResponse(
833         const WhoIsMasterResponsePacket* response,
834         const sockaddr_storage& srcAddr) {
835     // Skip our own messages which come back via broadcast loopback.
836     if (response->deviceID == mDeviceID)
837         return true;
838 
839     char srcEPStr[64];
840     sockaddrToString(srcAddr, true, srcEPStr, sizeof(srcEPStr));
841     mElectionLog.log("RXed WhoIs master response while in state %s.  "
842                      "src %s respTID %016llx respDID %016llx respPrio %u "
843                      "ourTID %016llx",
844                      stateToString(mState), srcEPStr,
845                      response->timelineID,
846                      response->deviceID,
847                      static_cast<uint32_t>(response->devicePriority),
848                      mTimelineID);
849 
850     if (mState == ICommonClock::STATE_INITIAL || mState == ICommonClock::STATE_RONIN) {
851         return becomeClient(srcAddr,
852                             response->deviceID,
853                             response->devicePriority,
854                             response->timelineID,
855                             "heard whois response");
856     } else if (mState == ICommonClock::STATE_CLIENT) {
857         // if we get multiple responses because there are multiple devices
858         // who believe that they are master, then follow the master that
859         // wins arbitration
860         if (arbitrateMaster(response->deviceID,
861                             response->devicePriority,
862                             mClient_MasterDeviceID,
863                             mClient_MasterDevicePriority)) {
864             return becomeClient(srcAddr,
865                                 response->deviceID,
866                                 response->devicePriority,
867                                 response->timelineID,
868                                 "heard whois response");
869         }
870     }
871 
872     return true;
873 }
874 
handleSyncRequest(const SyncRequestPacket * request,const sockaddr_storage & srcAddr)875 bool CommonTimeServer::handleSyncRequest(const SyncRequestPacket* request,
876                                          const sockaddr_storage& srcAddr) {
877     SyncResponsePacket pkt;
878     pkt.initHeader(mTimelineID, mSyncGroupID);
879 
880     if ((mState == ICommonClock::STATE_MASTER) &&
881         (mTimelineID == request->timelineID)) {
882         int64_t rxLocalTime = mLastPacketRxLocalTime;
883         int64_t rxCommonTime;
884 
885         // If we are master on an actual network and have actual clients, then
886         // we are no longer low priority.
887         setForceLowPriority(false);
888 
889         if (OK != mCommonClock.localToCommon(rxLocalTime, &rxCommonTime)) {
890             return false;
891         }
892 
893         int64_t txLocalTime = mLocalClock.getLocalTime();;
894         int64_t txCommonTime;
895         if (OK != mCommonClock.localToCommon(txLocalTime, &txCommonTime)) {
896             return false;
897         }
898 
899         pkt.nak = 0;
900         pkt.clientTxLocalTime  = request->clientTxLocalTime;
901         pkt.masterRxCommonTime = rxCommonTime;
902         pkt.masterTxCommonTime = txCommonTime;
903     } else {
904         pkt.nak = 1;
905         pkt.clientTxLocalTime  = 0;
906         pkt.masterRxCommonTime = 0;
907         pkt.masterTxCommonTime = 0;
908     }
909 
910     uint8_t buf[256];
911     ssize_t bufSz = pkt.serializePacket(buf, sizeof(buf));
912     if (bufSz < 0)
913         return false;
914 
915     ssize_t sendBytes = sendto(
916             mSocket, &buf, bufSz, 0,
917             reinterpret_cast<const sockaddr *>(&srcAddr),
918             sizeof(srcAddr));
919     if (sendBytes == -1) {
920         ALOGE("%s:%d sendto failed", __PRETTY_FUNCTION__, __LINE__);
921         return false;
922     }
923 
924     return true;
925 }
926 
handleSyncResponse(const SyncResponsePacket * response,const sockaddr_storage & srcAddr)927 bool CommonTimeServer::handleSyncResponse(
928         const SyncResponsePacket* response,
929         const sockaddr_storage& srcAddr) {
930     if (mState != ICommonClock::STATE_CLIENT)
931         return true;
932 
933     assert(mMasterEPValid);
934     if (!sockaddrMatch(srcAddr, mMasterEP, true)) {
935         char srcEP[64], expectedEP[64];
936         sockaddrToString(srcAddr, true, srcEP, sizeof(srcEP));
937         sockaddrToString(mMasterEP, true, expectedEP, sizeof(expectedEP));
938         ALOGI("Dropping sync response from unexpected address."
939              " Expected %s Got %s", expectedEP, srcEP);
940         return true;
941     }
942 
943     if (response->nak) {
944         // if our master is no longer accepting requests, then we need to find
945         // a new master
946         return becomeRonin("master NAK'ed");
947     }
948 
949     mClient_SyncRequestPending = 0;
950     mClient_SyncRequestTimeouts = 0;
951     mClient_PacketRTTLog.logRX(response->clientTxLocalTime,
952                                mLastPacketRxLocalTime);
953 
954     bool result;
955     if (!(mClient_SyncRespsRXedFromCurMaster++)) {
956         // the first request/response exchange between a client and a master
957         // may take unusually long due to ARP, so discard it.
958         result = true;
959     } else {
960         int64_t clientTxLocalTime  = response->clientTxLocalTime;
961         int64_t clientRxLocalTime  = mLastPacketRxLocalTime;
962         int64_t masterTxCommonTime = response->masterTxCommonTime;
963         int64_t masterRxCommonTime = response->masterRxCommonTime;
964 
965         int64_t rtt       = (clientRxLocalTime - clientTxLocalTime);
966         int64_t avgLocal  = (clientTxLocalTime + clientRxLocalTime) >> 1;
967         int64_t avgCommon = (masterTxCommonTime + masterRxCommonTime) >> 1;
968 
969         // if the RTT of the packet is significantly larger than the panic
970         // threshold, we should simply discard it.  Its better to do nothing
971         // than to take cues from a packet like that.
972         int64_t rttCommon = mCommonClock.localDurationToCommonDuration(rtt);
973         if (rttCommon > (static_cast<int64_t>(mPanicThresholdUsec) *
974                          kRTTDiscardPanicThreshMultiplier)) {
975             ALOGV("Dropping sync response with RTT of %" PRId64 " uSec", rttCommon);
976             mClient_ExpiredSyncRespsRXedFromCurMaster++;
977             if (shouldPanicNotGettingGoodData())
978                 return becomeInitial("RX panic, no good data");
979             return true;
980         } else {
981             result = mClockRecovery.pushDisciplineEvent(avgLocal, avgCommon, rttCommon);
982             mClient_LastGoodSyncRX = clientRxLocalTime;
983 
984             if (result) {
985                 // indicate to listeners that we've synced to the common timeline
986                 notifyClockSync();
987             } else {
988                 ALOGE("Panic!  Observed clock sync error is too high to tolerate,"
989                         " resetting state machine and starting over.");
990                 notifyClockSyncLoss();
991                 return becomeInitial("panic");
992             }
993         }
994     }
995 
996     mCurTimeout.setTimeout(mSyncRequestIntervalMs);
997     return result;
998 }
999 
handleMasterAnnouncement(const MasterAnnouncementPacket * packet,const sockaddr_storage & srcAddr)1000 bool CommonTimeServer::handleMasterAnnouncement(
1001         const MasterAnnouncementPacket* packet,
1002         const sockaddr_storage& srcAddr) {
1003     uint64_t newDeviceID   = packet->deviceID;
1004     uint8_t  newDevicePrio = packet->devicePriority;
1005     uint64_t newTimelineID = packet->timelineID;
1006 
1007     // Skip our own messages which come back via broadcast loopback.
1008     if (newDeviceID == mDeviceID)
1009         return true;
1010 
1011     char srcEPStr[64];
1012     sockaddrToString(srcAddr, true, srcEPStr, sizeof(srcEPStr));
1013     mElectionLog.log("RXed master announcement while in state %s.  "
1014                      "src %s srcDevID %lld srcPrio %u srcTID %016llx",
1015                      stateToString(mState), srcEPStr,
1016                      newDeviceID, static_cast<uint32_t>(newDevicePrio),
1017                      newTimelineID);
1018 
1019     if (mState == ICommonClock::STATE_INITIAL ||
1020         mState == ICommonClock::STATE_RONIN ||
1021         mState == ICommonClock::STATE_WAIT_FOR_ELECTION) {
1022         // if we aren't currently following a master, then start following
1023         // this new master
1024         return becomeClient(srcAddr,
1025                             newDeviceID,
1026                             newDevicePrio,
1027                             newTimelineID,
1028                             "heard master announcement");
1029     } else if (mState == ICommonClock::STATE_CLIENT) {
1030         // if the new master wins arbitration against our current master,
1031         // then become a client of the new master
1032         if (arbitrateMaster(newDeviceID,
1033                             newDevicePrio,
1034                             mClient_MasterDeviceID,
1035                             mClient_MasterDevicePriority))
1036             return becomeClient(srcAddr,
1037                                 newDeviceID,
1038                                 newDevicePrio,
1039                                 newTimelineID,
1040                                 "heard master announcement");
1041     } else if (mState == ICommonClock::STATE_MASTER) {
1042         // two masters are competing - if the new one wins arbitration, then
1043         // cease acting as master
1044         if (arbitrateMaster(newDeviceID, newDevicePrio,
1045                             mDeviceID, effectivePriority()))
1046             return becomeClient(srcAddr, newDeviceID,
1047                                 newDevicePrio, newTimelineID,
1048                                 "heard master announcement");
1049     }
1050 
1051     return true;
1052 }
1053 
sendWhoIsMasterRequest()1054 bool CommonTimeServer::sendWhoIsMasterRequest() {
1055     assert(mState == ICommonClock::STATE_INITIAL || mState == ICommonClock::STATE_RONIN);
1056 
1057     // If we have no socket, then we must be in the unconfigured initial state.
1058     // Don't report any errors, just don't try to send the initial who-is-master
1059     // query.  Eventually, our network will either become configured, or we will
1060     // be forced into network-less master mode by higher level code.
1061     if (mSocket < 0) {
1062         assert(mState == ICommonClock::STATE_INITIAL);
1063         return true;
1064     }
1065 
1066     bool ret = false;
1067     WhoIsMasterRequestPacket pkt;
1068     pkt.initHeader(mSyncGroupID);
1069     pkt.senderDeviceID = mDeviceID;
1070     pkt.senderDevicePriority = effectivePriority();
1071 
1072     uint8_t buf[256];
1073     ssize_t bufSz = pkt.serializePacket(buf, sizeof(buf));
1074     if (bufSz >= 0) {
1075         char dstEPStr[64];
1076         sockaddrToString(mMasterElectionEP, true, dstEPStr, sizeof(dstEPStr));
1077         mElectionLog.log("TXing WhoIs master request to %s while in state %s.  "
1078                          "ourTID %016llx ourGID %016llx ourDID %016llx "
1079                          "ourPrio %u",
1080                          dstEPStr, stateToString(mState),
1081                          mTimelineID, mSyncGroupID,
1082                          pkt.senderDeviceID, pkt.senderDevicePriority);
1083 
1084         ssize_t sendBytes = sendto(
1085                 mSocket, buf, bufSz, 0,
1086                 reinterpret_cast<const sockaddr *>(&mMasterElectionEP),
1087                 sizeof(mMasterElectionEP));
1088         if (sendBytes < 0)
1089             ALOGE("WhoIsMaster sendto failed (errno %d)", errno);
1090         ret = true;
1091     }
1092 
1093     if (mState == ICommonClock::STATE_INITIAL) {
1094         mCurTimeout.setTimeout(kInitial_WhoIsMasterTimeoutMs);
1095     } else {
1096         mCurTimeout.setTimeout(kRonin_WhoIsMasterTimeoutMs);
1097     }
1098 
1099     return ret;
1100 }
1101 
sendSyncRequest()1102 bool CommonTimeServer::sendSyncRequest() {
1103     // If we are sending sync requests, then we must be in the client state and
1104     // we must have a socket (when we have no network, we are only supposed to
1105     // be in INITIAL or MASTER)
1106     assert(mState == ICommonClock::STATE_CLIENT);
1107     assert(mSocket >= 0);
1108 
1109     bool ret = false;
1110     SyncRequestPacket pkt;
1111     pkt.initHeader(mTimelineID, mSyncGroupID);
1112     pkt.clientTxLocalTime = mLocalClock.getLocalTime();
1113 
1114     if (!mClient_FirstSyncTX)
1115         mClient_FirstSyncTX = pkt.clientTxLocalTime;
1116 
1117     mClient_PacketRTTLog.logTX(pkt.clientTxLocalTime);
1118 
1119     uint8_t buf[256];
1120     ssize_t bufSz = pkt.serializePacket(buf, sizeof(buf));
1121     if (bufSz >= 0) {
1122         ssize_t sendBytes = sendto(
1123                 mSocket, buf, bufSz, 0,
1124                 reinterpret_cast<const sockaddr *>(&mMasterEP),
1125                 sizeof(mMasterEP));
1126         if (sendBytes < 0)
1127             ALOGE("SyncRequest sendto failed (errno %d)", errno);
1128         ret = true;
1129     }
1130 
1131     mClient_SyncsSentToCurMaster++;
1132     mCurTimeout.setTimeout(mSyncRequestIntervalMs);
1133     mClient_SyncRequestPending = true;
1134 
1135     return ret;
1136 }
1137 
sendMasterAnnouncement()1138 bool CommonTimeServer::sendMasterAnnouncement() {
1139     bool ret = false;
1140     assert(mState == ICommonClock::STATE_MASTER);
1141 
1142     // If we are being asked to send a master announcement, but we have no
1143     // socket, we must be in network-less master mode.  Don't bother to send the
1144     // announcement, and don't bother to schedule a timeout.  When the network
1145     // comes up, the work thread will get poked and start the process of
1146     // figuring out who the current master should be.
1147     if (mSocket < 0) {
1148         mCurTimeout.setTimeout(kInfiniteTimeout);
1149         return true;
1150     }
1151 
1152     MasterAnnouncementPacket pkt;
1153     pkt.initHeader(mTimelineID, mSyncGroupID);
1154     pkt.deviceID = mDeviceID;
1155     pkt.devicePriority = effectivePriority();
1156 
1157     uint8_t buf[256];
1158     ssize_t bufSz = pkt.serializePacket(buf, sizeof(buf));
1159     if (bufSz >= 0) {
1160         char dstEPStr[64];
1161         sockaddrToString(mMasterElectionEP, true, dstEPStr, sizeof(dstEPStr));
1162         mElectionLog.log("TXing Master announcement to %s while in state %s.  "
1163                          "ourTID %016llx ourGID %016llx ourDID %016llx "
1164                          "ourPrio %u",
1165                          dstEPStr, stateToString(mState),
1166                          mTimelineID, mSyncGroupID,
1167                          pkt.deviceID, pkt.devicePriority);
1168 
1169         ssize_t sendBytes = sendto(
1170                 mSocket, buf, bufSz, 0,
1171                 reinterpret_cast<const sockaddr *>(&mMasterElectionEP),
1172                 sizeof(mMasterElectionEP));
1173         if (sendBytes < 0)
1174             ALOGE("MasterAnnouncement sendto failed (errno %d)", errno);
1175         ret = true;
1176     }
1177 
1178     mCurTimeout.setTimeout(mMasterAnnounceIntervalMs);
1179     return ret;
1180 }
1181 
becomeClient(const sockaddr_storage & masterEP,uint64_t masterDeviceID,uint8_t masterDevicePriority,uint64_t timelineID,const char * cause)1182 bool CommonTimeServer::becomeClient(const sockaddr_storage& masterEP,
1183                                     uint64_t masterDeviceID,
1184                                     uint8_t  masterDevicePriority,
1185                                     uint64_t timelineID,
1186                                     const char* cause) {
1187     char newEPStr[64], oldEPStr[64];
1188     sockaddrToString(masterEP, true, newEPStr, sizeof(newEPStr));
1189     sockaddrToString(mMasterEP, mMasterEPValid, oldEPStr, sizeof(oldEPStr));
1190 
1191     mStateChangeLog.log(ANDROID_LOG_INFO, LOG_TAG,
1192             "%s --> CLIENT (%s) :%s"
1193             " OldMaster: %02x-%014llx::%016llx::%s"
1194             " NewMaster: %02x-%014llx::%016llx::%s",
1195             stateToString(mState), cause,
1196             (mTimelineID != timelineID) ? " (new timeline)" : "",
1197             mClient_MasterDevicePriority, mClient_MasterDeviceID,
1198             mTimelineID, oldEPStr,
1199             masterDevicePriority, masterDeviceID,
1200             timelineID, newEPStr);
1201 
1202     if (mTimelineID != timelineID) {
1203         // start following a new timeline
1204         mTimelineID = timelineID;
1205         mClockRecovery.reset(true, true);
1206         notifyClockSyncLoss();
1207     } else {
1208         // start following a new master on the existing timeline
1209         mClockRecovery.reset(false, true);
1210     }
1211 
1212     mMasterEP = masterEP;
1213     mMasterEPValid = true;
1214 
1215     // If we are on a real network as a client of a real master, then we should
1216     // no longer force low priority.  If our master disappears, we should have
1217     // the high priority bit set during the election to replace the master
1218     // because this group was a real group and not a singleton created in
1219     // networkless mode.
1220     setForceLowPriority(false);
1221 
1222     mClient_MasterDeviceID = masterDeviceID;
1223     mClient_MasterDevicePriority = masterDevicePriority;
1224     resetSyncStats();
1225 
1226     setState(ICommonClock::STATE_CLIENT);
1227 
1228     // add some jitter to when the various clients send their requests
1229     // in order to reduce the likelihood that a group of clients overload
1230     // the master after receiving a master announcement
1231     usleep((lrand48() % 100) * 1000);
1232 
1233     return sendSyncRequest();
1234 }
1235 
becomeMaster(const char * cause)1236 bool CommonTimeServer::becomeMaster(const char* cause) {
1237     uint64_t oldTimelineID = mTimelineID;
1238     if (mTimelineID == ICommonClock::kInvalidTimelineID) {
1239         // this device has not been following any existing timeline,
1240         // so it will create a new timeline and declare itself master
1241         assert(!mCommonClock.isValid());
1242 
1243         // set the common time basis
1244         mCommonClock.setBasis(mLocalClock.getLocalTime(), 0);
1245 
1246         // assign an arbitrary timeline iD
1247         assignTimelineID();
1248 
1249         // notify listeners that we've created a common timeline
1250         notifyClockSync();
1251     }
1252 
1253     mStateChangeLog.log(ANDROID_LOG_INFO, LOG_TAG,
1254             "%s --> MASTER (%s) : %s timeline %016llx",
1255             stateToString(mState), cause,
1256             (oldTimelineID == mTimelineID) ? "taking ownership of"
1257                                            : "creating new",
1258             mTimelineID);
1259 
1260     memset(&mMasterEP, 0, sizeof(mMasterEP));
1261     mMasterEPValid = false;
1262     mClient_MasterDevicePriority = effectivePriority();
1263     mClient_MasterDeviceID = mDeviceID;
1264     mClockRecovery.reset(false, true);
1265     resetSyncStats();
1266 
1267     setState(ICommonClock::STATE_MASTER);
1268     return sendMasterAnnouncement();
1269 }
1270 
becomeRonin(const char * cause)1271 bool CommonTimeServer::becomeRonin(const char* cause) {
1272     // If we were the client of a given timeline, but had never received even a
1273     // single time sync packet, then we transition back to Initial instead of
1274     // Ronin.  If we transition to Ronin and end up becoming the new Master, we
1275     // will be unable to service requests for other clients because we never
1276     // actually knew what time it was.  By going to initial, we ensure that
1277     // other clients who know what time it is, but would lose master arbitration
1278     // in the Ronin case, will step up and become the proper new master of the
1279     // old timeline.
1280 
1281     char oldEPStr[64];
1282     sockaddrToString(mMasterEP, mMasterEPValid, oldEPStr, sizeof(oldEPStr));
1283     memset(&mMasterEP, 0, sizeof(mMasterEP));
1284     mMasterEPValid = false;
1285 
1286     if (mCommonClock.isValid()) {
1287         mStateChangeLog.log(ANDROID_LOG_INFO, LOG_TAG,
1288              "%s --> RONIN (%s) : lost track of previously valid timeline "
1289              "%02x-%014llx::%016llx::%s (%d TXed %d RXed %d RXExpired)",
1290              stateToString(mState), cause,
1291              mClient_MasterDevicePriority, mClient_MasterDeviceID,
1292              mTimelineID, oldEPStr,
1293              mClient_SyncsSentToCurMaster,
1294              mClient_SyncRespsRXedFromCurMaster,
1295              mClient_ExpiredSyncRespsRXedFromCurMaster);
1296 
1297         mRonin_WhoIsMasterRequestTimeouts = 0;
1298         setState(ICommonClock::STATE_RONIN);
1299         return sendWhoIsMasterRequest();
1300     } else {
1301         mStateChangeLog.log(ANDROID_LOG_INFO, LOG_TAG,
1302              "%s --> INITIAL (%s) : never synced timeline "
1303              "%02x-%014llx::%016llx::%s (%d TXed %d RXed %d RXExpired)",
1304              stateToString(mState), cause,
1305              mClient_MasterDevicePriority, mClient_MasterDeviceID,
1306              mTimelineID, oldEPStr,
1307              mClient_SyncsSentToCurMaster,
1308              mClient_SyncRespsRXedFromCurMaster,
1309              mClient_ExpiredSyncRespsRXedFromCurMaster);
1310 
1311         return becomeInitial("ronin, no timeline");
1312     }
1313 }
1314 
becomeWaitForElection(const char * cause)1315 bool CommonTimeServer::becomeWaitForElection(const char* cause) {
1316     mStateChangeLog.log(ANDROID_LOG_INFO, LOG_TAG,
1317          "%s --> WAIT_FOR_ELECTION (%s) : dropping out of election,"
1318          " waiting %d mSec for completion.",
1319          stateToString(mState), cause, kWaitForElection_TimeoutMs);
1320 
1321     setState(ICommonClock::STATE_WAIT_FOR_ELECTION);
1322     mCurTimeout.setTimeout(kWaitForElection_TimeoutMs);
1323     return true;
1324 }
1325 
becomeInitial(const char * cause)1326 bool CommonTimeServer::becomeInitial(const char* cause) {
1327     mStateChangeLog.log(ANDROID_LOG_INFO, LOG_TAG,
1328                         "Entering INITIAL (%s), total reset.",
1329                         cause);
1330 
1331     setState(ICommonClock::STATE_INITIAL);
1332 
1333     // reset clock recovery
1334     mClockRecovery.reset(true, true);
1335 
1336     // reset internal state bookkeeping.
1337     mCurTimeout.setTimeout(kInfiniteTimeout);
1338     memset(&mMasterEP, 0, sizeof(mMasterEP));
1339     mMasterEPValid = false;
1340     mLastPacketRxLocalTime = 0;
1341     mTimelineID = ICommonClock::kInvalidTimelineID;
1342     mClockSynced = false;
1343     mInitial_WhoIsMasterRequestTimeouts = 0;
1344     mClient_MasterDeviceID = 0;
1345     mClient_MasterDevicePriority = 0;
1346     mRonin_WhoIsMasterRequestTimeouts = 0;
1347     resetSyncStats();
1348 
1349     // send the first request to discover the master
1350     return sendWhoIsMasterRequest();
1351 }
1352 
notifyClockSync()1353 void CommonTimeServer::notifyClockSync() {
1354     if (!mClockSynced) {
1355         mClockSynced = true;
1356         mICommonClock->notifyOnTimelineChanged(mTimelineID);
1357     }
1358 }
1359 
notifyClockSyncLoss()1360 void CommonTimeServer::notifyClockSyncLoss() {
1361     if (mClockSynced) {
1362         mClockSynced = false;
1363         mICommonClock->notifyOnTimelineChanged(
1364                 ICommonClock::kInvalidTimelineID);
1365     }
1366 }
1367 
setState(ICommonClock::State s)1368 void CommonTimeServer::setState(ICommonClock::State s) {
1369     mState = s;
1370 }
1371 
stateToString(ICommonClock::State s)1372 const char* CommonTimeServer::stateToString(ICommonClock::State s) {
1373     switch(s) {
1374         case ICommonClock::STATE_INITIAL:
1375             return "INITIAL";
1376         case ICommonClock::STATE_CLIENT:
1377             return "CLIENT";
1378         case ICommonClock::STATE_MASTER:
1379             return "MASTER";
1380         case ICommonClock::STATE_RONIN:
1381             return "RONIN";
1382         case ICommonClock::STATE_WAIT_FOR_ELECTION:
1383             return "WAIT_FOR_ELECTION";
1384         default:
1385             return "unknown";
1386     }
1387 }
1388 
sockaddrToString(const sockaddr_storage & addr,bool addrValid,char * buf,size_t bufLen)1389 void CommonTimeServer::sockaddrToString(const sockaddr_storage& addr,
1390                                         bool addrValid,
1391                                         char* buf, size_t bufLen) {
1392     if (!bufLen || !buf)
1393         return;
1394 
1395     if (addrValid) {
1396         switch (addr.ss_family) {
1397             case AF_INET: {
1398                 const struct sockaddr_in* sa =
1399                     reinterpret_cast<const struct sockaddr_in*>(&addr);
1400                 unsigned long a = ntohl(sa->sin_addr.s_addr);
1401                 uint16_t      p = ntohs(sa->sin_port);
1402                 snprintf(buf, bufLen, "%lu.%lu.%lu.%lu:%hu",
1403                         ((a >> 24) & 0xFF), ((a >> 16) & 0xFF),
1404                         ((a >>  8) & 0xFF),  (a        & 0xFF), p);
1405             } break;
1406 
1407             case AF_INET6: {
1408                 const struct sockaddr_in6* sa =
1409                     reinterpret_cast<const struct sockaddr_in6*>(&addr);
1410                 const uint8_t* a = sa->sin6_addr.s6_addr;
1411                 uint16_t       p = ntohs(sa->sin6_port);
1412                 snprintf(buf, bufLen,
1413                         "%02X%02X:%02X%02X:%02X%02X:%02X%02X:"
1414                         "%02X%02X:%02X%02X:%02X%02X:%02X%02X port %hd",
1415                         a[0], a[1], a[ 2], a[ 3], a[ 4], a[ 5], a[ 6], a[ 7],
1416                         a[8], a[9], a[10], a[11], a[12], a[13], a[14], a[15],
1417                         p);
1418             } break;
1419 
1420             default:
1421                 snprintf(buf, bufLen,
1422                          "<unknown sockaddr family %d>", addr.ss_family);
1423                 break;
1424         }
1425     } else {
1426         snprintf(buf, bufLen, "<none>");
1427     }
1428 
1429     buf[bufLen - 1] = 0;
1430 }
1431 
sockaddrMatch(const sockaddr_storage & a1,const sockaddr_storage & a2,bool matchAddressOnly)1432 bool CommonTimeServer::sockaddrMatch(const sockaddr_storage& a1,
1433                                      const sockaddr_storage& a2,
1434                                      bool matchAddressOnly) {
1435     if (a1.ss_family != a2.ss_family)
1436         return false;
1437 
1438     switch (a1.ss_family) {
1439         case AF_INET: {
1440             const struct sockaddr_in* sa1 =
1441                 reinterpret_cast<const struct sockaddr_in*>(&a1);
1442             const struct sockaddr_in* sa2 =
1443                 reinterpret_cast<const struct sockaddr_in*>(&a2);
1444 
1445             if (sa1->sin_addr.s_addr != sa2->sin_addr.s_addr)
1446                 return false;
1447 
1448             return (matchAddressOnly || (sa1->sin_port == sa2->sin_port));
1449         } break;
1450 
1451         case AF_INET6: {
1452             const struct sockaddr_in6* sa1 =
1453                 reinterpret_cast<const struct sockaddr_in6*>(&a1);
1454             const struct sockaddr_in6* sa2 =
1455                 reinterpret_cast<const struct sockaddr_in6*>(&a2);
1456 
1457             if (memcmp(&sa1->sin6_addr, &sa2->sin6_addr, sizeof(sa2->sin6_addr)))
1458                 return false;
1459 
1460             return (matchAddressOnly || (sa1->sin6_port == sa2->sin6_port));
1461         } break;
1462 
1463         // Huh?  We don't deal in non-IPv[46] addresses.  Not sure how we got
1464         // here, but we don't know how to comapre these addresses and simply
1465         // default to a no-match decision.
1466         default: return false;
1467     }
1468 }
1469 
shouldPanicNotGettingGoodData()1470 bool CommonTimeServer::shouldPanicNotGettingGoodData() {
1471     if (mClient_FirstSyncTX) {
1472         int64_t now = mLocalClock.getLocalTime();
1473         int64_t delta = now - (mClient_LastGoodSyncRX
1474                              ? mClient_LastGoodSyncRX
1475                              : mClient_FirstSyncTX);
1476         int64_t deltaUsec = mCommonClock.localDurationToCommonDuration(delta);
1477 
1478         if (deltaUsec >= kNoGoodDataPanicThresholdUsec)
1479             return true;
1480     }
1481 
1482     return false;
1483 }
1484 
logTX(int64_t txTime)1485 void CommonTimeServer::PacketRTTLog::logTX(int64_t txTime) {
1486     txTimes[wrPtr] = txTime;
1487     rxTimes[wrPtr] = 0;
1488     wrPtr = (wrPtr + 1) % RTT_LOG_SIZE;
1489     if (!wrPtr)
1490         logFull = true;
1491 }
1492 
logRX(int64_t txTime,int64_t rxTime)1493 void CommonTimeServer::PacketRTTLog::logRX(int64_t txTime, int64_t rxTime) {
1494     if (!logFull && !wrPtr)
1495         return;
1496 
1497     uint32_t i = logFull ? wrPtr : 0;
1498     do {
1499         if (txTimes[i] == txTime) {
1500             rxTimes[i] = rxTime;
1501             break;
1502         }
1503         i = (i + 1) % RTT_LOG_SIZE;
1504     } while (i != wrPtr);
1505 }
1506 
1507 }  // namespace android
1508