def evaluate_leaderboard(follower_service):
"""
Starts/changes/stops the time follower service according to
who the current clock master is.
"""
if not leaderboard:
logger.debug("nobody on the leader board.")
if follower_service is not None:
follower_service.terminate()
return None
current_leader = leaderboard[0]
leader_ep = discovery.peer_address(current_leader.uuid)
leader_addr = urlparse(leader_ep).netloc.split(':')[0]
logger.info('Following <{}>'.format(current_leader))
if follower_service is None:
# make new follower
follower_service = Clock_Sync_Follower(leader_addr,
port=current_leader.port,
interval=10,
time_fn=time_fn,
jump_fn=jump_fn,
slew_fn=slew_fn)
else:
# update follower_service
follower_service.host = leader_addr
follower_service.port = current_leader.port
return follower_service
def evaluate_leaderboard(self):
if not self.leaderboard:
logger.debug("nobody on the leader board.")
return
current_leader = self.leaderboard[0]
if self.discovery.uuid() != current_leader.uuid:
# we are not the leader!
leader_ep = self.discovery.peer_address(current_leader.uuid)
leader_addr = urlparse(leader_ep).netloc.split(':')[0]
if self.follower_service is None:
# make new follower
self.follower_service = Clock_Sync_Follower(leader_addr,
port=current_leader.port,
interval=10,
time_fn=self.get_time,
jump_fn=self.jump_time,
slew_fn=self.slew_time)
else:
# update follower_service
self.follower_service.host = leader_addr
self.follower_service.port = current_leader.port
return
# we are the leader
logger.debug("we are the leader")
if self.follower_service is not None:
self.follower_service.terminate()
self.follower_service = None
if not self.has_been_master:
self.has_been_master = 1.
logger.debug('Become clock master with rank {}'.format(self.rank))
self.announce_clock_master_info()
def _handle_wake_up(self,socket,network,wake_up_fun):
socket.recv()
#timeout events are used for pupil sync.
#annouce masterhood every interval time:
if isinstance(self.time_sync_node,Clock_Sync_Master):
network.shouts(self.group, SYNC_TIME_MASTER_ANNOUNCE+"%s"%self.clock_master_worthiness()+msg_delimeter+'%s'%self.time_sync_node.port)
elif self._time_grandmaster:
self.time_sync_node = Clock_Sync_Master(time_fn=self.get_time)
network.shouts(self.group, SYNC_TIME_MASTER_ANNOUNCE+"%s"%self.clock_master_worthiness()+msg_delimeter+'%s'%self.time_sync_node.port)
# synced slave: see if we should become master if we dont hear annoncement within time.
elif isinstance(self.time_sync_node,Clock_Sync_Follower) and not self.time_sync_node.offset_remains:
if self.get_unadjusted_time()-self.last_master_announce > self.time_sync_wait_interval_short:
self.time_sync_node.terminate()
self.time_sync_node = Clock_Sync_Master(time_fn=self.get_time)
network.shouts(self.group, SYNC_TIME_MASTER_ANNOUNCE+"%s"%self.clock_master_worthiness()+msg_delimeter+'%s'%self.time_sync_node.port)
# unsynced slave or none should wait longer but eventually take over
elif self.get_unadjusted_time()-self.last_master_announce > self.time_sync_wait_interval_long:
if self.time_sync_node:
self.time_sync_node.terminate()
self.time_sync_node = Clock_Sync_Master(time_fn=self.get_time)
network.shouts(self.group, SYNC_TIME_MASTER_ANNOUNCE+"%s"%self.clock_master_worthiness()+msg_delimeter+'%s'%self.time_sync_node.port)
t = Timer(self.time_sync_announce_interval, wake_up_fun)
t.daemon = True
t.start()
def handle_msg(self,uuid,name,msg,n):
#Clock Sync master announce logic
if SYNC_TIME_MASTER_ANNOUNCE in msg:
self.last_master_announce = self.get_monotonic_time()
worthiness,port = msg.replace(SYNC_TIME_MASTER_ANNOUNCE,'').split(msg_delimeter)
foreign_master_worthiness = float(worthiness)
foreign_master_port = int(port)
forein_master_uuid = UUID(bytes=uuid)
foreign_master_address = n.peer_address(forein_master_uuid)
foreign_master_ip = foreign_master_address.split('//')[-1].split(':')[0] # tcp://10.0.1.68:59149
if isinstance(self.sync_node,Clock_Sync_Master):
# who should yield?
if not self.was_adjusted() and foreign_master_adjusted:
should_yield = True
elif self.nerver_adjusted() and (not foreign_master_adjusted):
should_yield = False
else:
if n.uuid().int > forein_master_uuid.int:
self.should_yield = False
else:
self.should_yield = True
if should_yield:
logger.warning("Yield Clock_Sync_Master to %s@%s"%(name,new_master))
self.sync_node.stop()
self.sync_node = Clock_Sync_Follower(foreign_master_ip,port=foreign_master_port,interval=10,time_fn=self.get_time,jump_fn=self.jump_time,slew_fn=self.set_time)
else:
logger.warning("Dominate as Clock_Sync_Master")
n.shouts(self.group, SYNC_TIME_MASTER_ANNOUNCE+"%s"%self.clock_master_worthiness()+msg_delimeter+'%s'%self.sync_node.port)
elif isinstance(self.sync_node,Clock_Sync_Follower):
self.sync_node.host = foreign_master_ip
self.sync_node.port = foreign_master_port
else:
self.sync_node = Clock_Sync_Follower(foreign_master_ip,port=foreign_master_port,interval=10,time_fn=self.get_time,jump_fn=self.jump_time,slew_fn=self.set_time)
logger.debug("Clock synced with %s"%foreign_master_ip)
elif NOTIFICATION in msg :
notification_str = msg.replace(NOTIFICATION,'')
try:
notification = eval(notification_str)
except Exception as e:
logger.error('Recevied mal-formed remote notification. Payload:"%s"'%notification_str)
else:
# This remote notification does not need to be network propagated again.
notification['network_propagate'] = False
# We also add some info on where it came from.
notification['source'] = 'pupil_sync'
notification['sync_node_name'] = name
notification['sync_node_uuid'] = uuid
# Finally we fire it.
self.notify_all(notification)
else:
logger.warning('Received unknown message pattern. Payload:"%s"'%msg)
def handle_msg(self,uuid,name,msg,n):
#Clock Sync master announce logic
if sync_time_master_announce in msg:
self.last_master_announce = self.get_monotonic_time()
worthiness,port = msg.replace(sync_time_master_announce,'').split(msg_delimeter)
foreign_master_worthiness = float(worthiness)
foreign_master_port = int(port)
forein_master_uuid = UUID(bytes=uuid)
foreign_master_address = n.peer_address(forein_master_uuid)
foreign_master_ip = foreign_master_address.split('//')[-1].split(':')[0] # tcp://10.0.1.68:59149
if isinstance(self.sync_node,Clock_Sync_Master):
# who should yield?
if not self.was_adjusted() and foreign_master_adjusted:
should_yield = True
elif self.nerver_adjusted() and (not foreign_master_adjusted):
should_yield = False
else:
if n.uuid().int > forein_master_uuid.int:
self.should_yield = False
else:
self.should_yield = True
if should_yield:
logger.warning("Yield Clock_Sync_Master to %s@%s"%(name,new_master))
self.sync_node.stop()
self.sync_node = Clock_Sync_Follower(foreign_master_ip,port=foreign_master_port,interval=10,time_fn=self.get_time,jump_fn=self.jump_time,slew_fn=self.set_time)
else:
logger.warning("Dominate as Clock_Sync_Master")
n.shouts(self.group, sync_time_master_announce+"%s"%self.clock_master_worthiness()+msg_delimeter+'%s'%self.sync_node.port)
elif isinstance(self.sync_node,Clock_Sync_Follower):
self.sync_node.host = foreign_master_ip
self.sync_node.port = foreign_master_port
else:
self.sync_node = Clock_Sync_Follower(foreign_master_ip,port=foreign_master_port,interval=10,time_fn=self.get_time,jump_fn=self.jump_time,slew_fn=self.set_time)
logger.debug("Clock synced with %s"%foreign_master_ip)
elif start_rec in msg :
session_name = msg.replace(start_rec,'')
self.notify_all({'subject':'rec_should_start','session_name':session_name,'network_propagate':False})
elif stop_rec in msg:
self.notify_all({'subject':'rec_should_stop','network_propagate':False})
elif start_cal in msg:
self.notify_all({'subject':'cal_should_start'})
elif stop_cal in msg:
self.notify_all({'subject':'cal_should_stop'})
elif user_event in msg:
payload = msg.replace(user_event,'')
user_event_name,timestamp = payload.split('@')
self.notify_all({'subject':'remote_user_event','user_event_name':user_event_name,'timestamp':float(timestamp),'network_propagate':False,'sender':name,'received_timestamp':self.g_pool.capture.get_timestamp()})
def evaluate_leaderboard(self):
if not self.leaderboard:
logger.debug("nobody on the leader board.")
return
current_leader = self.leaderboard[0]
if self.discovery.uuid() != current_leader.uuid:
# we are not the leader!
leader_ep = self.discovery.peer_address(current_leader.uuid)
leader_addr = urlparse(leader_ep).netloc.split(':')[0]
if self.follower_service is None:
# make new follower
self.follower_service = Clock_Sync_Follower(leader_addr,
port=current_leader.port,
interval=10,
time_fn=self.get_time,
jump_fn=self.jump_time,
slew_fn=self.slew_time)
else:
# update follower_service
self.follower_service.host = leader_addr
self.follower_service.port = current_leader.port
return
# we are the leader
logger.debug("we are the leader")
if self.follower_service is not None:
self.follower_service.terminate()
self.follower_service = None
if not self.has_been_master:
self.has_been_master = 1.
logger.debug('Become clock master with rank {}'.format(self.rank))
self.announce_clock_master_info()
def _handle_msg(self, uuid, name, msg, node):
#Clock Sync master announce logic
if SYNC_TIME_MASTER_ANNOUNCE in msg:
self.last_master_announce = self.get_unadjusted_time()
worthiness, port = msg.replace(SYNC_TIME_MASTER_ANNOUNCE,
'').split(msg_delimeter)
foreign_master_worthiness = float(worthiness)
foreign_master_port = int(port)
forein_master_uuid = UUID(bytes=uuid)
foreign_master_address = node.peer_address(forein_master_uuid)
foreign_master_ip = foreign_master_address.split('//')[-1].split(
':')[0] # tcp://10.0.1.68:59149
if isinstance(self.time_sync_node, Clock_Sync_Master):
# who should yield?
if self.clock_master_worthiness() == foreign_master_worthiness:
should_yield = node.uuid().int < forein_master_uuid.int
else:
should_yield = self.clock_master_worthiness(
) < foreign_master_worthiness
if should_yield:
logger.warning("Yield Clock_Sync_Master to %s@%s" %
(name, foreign_master_ip))
self.time_sync_node.stop()
self.time_sync_node = Clock_Sync_Follower(
foreign_master_ip,
port=foreign_master_port,
interval=10,
time_fn=self.get_time,
jump_fn=self.jump_time,
slew_fn=self.set_time)
else:
logger.warning("Dominate as Clock_Sync_Master")
node.shouts(
self.group, SYNC_TIME_MASTER_ANNOUNCE +
"%s" % self.clock_master_worthiness() + msg_delimeter +
'%s' % self.time_sync_node.port)
elif isinstance(self.time_sync_node, Clock_Sync_Follower):
self.time_sync_node.host = foreign_master_ip
self.time_sync_node.port = foreign_master_port
else:
self.time_sync_node = Clock_Sync_Follower(
foreign_master_ip,
port=foreign_master_port,
interval=10,
time_fn=self.get_time,
jump_fn=self.jump_time,
slew_fn=self.set_time)
logger.debug("Clock synced with %s" % foreign_master_ip)
elif TIMESTAMP_REQ in msg:
node.whisper(UUID(bytes=uuid), TIMESTAMP + '%s' % self.get_time())
elif NOTIFICATION in msg:
notification_str = msg.replace(NOTIFICATION, '')
try:
notification = eval(notification_str)
except Exception as e:
logger.error(
'Recevied mal-formed remote notification. Payload:"%s"' %
notification_str)
else:
# This remote notification does not need to be network propagated again.
notification['network_propagate'] = False
# We also add some info on where it came from.
notification['source'] = 'pupil_sync'
notification['sync_node_name'] = name
notification['sync_node_uuid'] = uuid
# Finally we fire it.
self.notify_all(notification)
else:
logger.warning('Received unknown message pattern. Payload:"%s"' %
msg)
def thread_loop(self, context, pipe):
n = Pyre(self.name)
n.join(self.group)
n.start()
poller = zmq.Poller()
poller.register(pipe, zmq.POLLIN)
poller.register(n.socket(), zmq.POLLIN)
front, back = zhelper.zcreate_pipe(context)
poller.register(back, zmq.POLLIN)
def wake_up():
#on app close this timer calls a closed socket. We simply catch it here.
try:
front.send('wake_up')
except Exception as e:
logger.debug('Orphaned timer thread raised error: %s' % e)
t = Timer(self.time_sync_announce_interval, wake_up)
t.daemon = True
t.start()
while (True):
try:
#this should not fail but it does sometimes. We need to clean this out.
# I think we are not treating sockets correclty as they are not thread-save.
items = dict(poller.poll())
except zmq.ZMQError:
logger.warning('Socket fail.')
continue
if back in items and items[back] == zmq.POLLIN:
back.recv()
#timeout events are used for pupil sync.
#annouce masterhood every interval time:
if isinstance(self.time_sync_node, Clock_Sync_Master):
n.shouts(
self.group, SYNC_TIME_MASTER_ANNOUNCE +
"%s" % self.clock_master_worthiness() + msg_delimeter +
'%s' % self.time_sync_node.port)
# synced slave: see if we should become master if we dont hear annoncement within time.
elif isinstance(self.time_sync_node, Clock_Sync_Follower
) and not self.time_sync_node.offset_remains:
if self.get_unadjusted_time(
) - self.last_master_announce > self.time_sync_wait_interval_short:
self.time_sync_node.terminate()
self.time_sync_node = Clock_Sync_Master(
time_fn=self.get_time)
n.shouts(
self.group, SYNC_TIME_MASTER_ANNOUNCE +
"%s" % self.clock_master_worthiness() +
msg_delimeter + '%s' % self.time_sync_node.port)
# unsynced slave or none should wait longer but eventually take over
elif self.get_unadjusted_time(
) - self.last_master_announce > self.time_sync_wait_interval_long:
if self.time_sync_node:
self.time_sync_node.terminate()
self.time_sync_node = Clock_Sync_Master(
time_fn=self.get_time)
n.shouts(
self.group, SYNC_TIME_MASTER_ANNOUNCE +
"%s" % self.clock_master_worthiness() + msg_delimeter +
'%s' % self.time_sync_node.port)
t = Timer(self.time_sync_announce_interval, wake_up)
t.daemon = True
t.start()
if pipe in items and items[pipe] == zmq.POLLIN:
message = pipe.recv()
# message to quit
if message.decode('utf-8') == exit_thread:
break
else:
logger.debug("Shout '%s' to '%s' " % (message, self.group))
n.shouts(self.group, message)
if n.socket() in items and items[n.socket()] == zmq.POLLIN:
cmds = n.recv()
msg_type = cmds.pop(0)
msg_type = msg_type.decode('utf-8')
if msg_type == "SHOUT":
uuid, name, group, msg = cmds
logger.debug("'%s' shouts '%s'." % (name, msg))
self._handle_msg(uuid, name, msg, n)
elif msg_type == "WHISPER":
uuid, name, msg = cmds
logger.debug("'%s/' whispers '%s'." % (name, msg))
self._handle_msg_whisper(uuid, name, msg, n)
elif msg_type == "JOIN":
uuid, name, group = cmds
if group == self.group:
self.group_members[uuid] = name
self.update_gui()
elif msg_type == "EXIT":
uuid, name = cmds
try:
del self.group_members[uuid]
except KeyError:
pass
else:
self.update_gui()
# elif msg_type == "LEAVE":
# uuid,name,group = cmds
# elif msg_type == "ENTER":
# uuid,name,headers,ip = cmds
# logger.warning((uuid,'name',headers,ip))
else:
pass
logger.debug('thread_loop closing.')
self.thread_pipe = None
n.stop()
class Pupil_Sync(Plugin):
"""Synchonize behaviour of Pupil captures
across the local network
"""
def __init__(self, g_pool,name='unnamed Pupil',group='default group'):
super(Pupil_Sync, self).__init__(g_pool)
self.order = .01 #excecute first
self.name = name
self.group = group
self.group_members = {}
self.menu = None
self.group_menu = None
#variables for the time sync logic
self.sync_node = None
self.last_master_announce = self.get_monotonic_time()
#constants for the time sync logic
self.time_sync_announce_interval = 5
self.time_sync_wait_interval_short = self.time_sync_announce_interval * 3
self.time_sync_wait_interval_long = self.time_sync_announce_interval * 4
self.context = zmq.Context()
self.thread_pipe = zhelper.zthread_fork(self.context, self.thread_loop)
def clock_master_worthiness(self):
'''
How worthy am I to be the clock master?
A measure 0 (unworthy) to 1 (destined)
tie-breaking is does via bigger uuid.int
At current this is done via
'''
if self.g_pool.timebase.value == 0:
return 0.
else:
return 0.5
###time sync fns these are used by the time sync node to get and adjust time
def get_monotonic_time(self):
#return time not influced by outside clocks.
return self.g_pool.capture.get_now()
def get_time(self):
return self.g_pool.capture.get_timestamp()
def set_time(self,offset):
self.g_pool.timebase.value +=offset
def jump_time(self,offset):
ok_to_change = True
for p in self.g_pool.plugins:
if p.class_name == 'Recorder':
if p.running:
ok_to_change = False
logger.error("Request to change timebase during recording ignored. Turn off recording first.")
break
if ok_to_change:
self.set_time(offset)
logger.info("Pupil Sync has adjusted the clock by %ss"%offset)
return True
else:
return False
def sync_status_info(self):
if self.sync_node is None:
return 'Waiting for time sync msg.'
else:
return str(self.sync_node)
def init_gui(self):
help_str = "Synchonize behaviour of Pupil captures across the local network."
self.menu = ui.Growing_Menu('Pupil Sync')
self.menu.append(ui.Button('Close',self.close))
self.menu.append(ui.Info_Text(help_str))
self.menu.append(ui.Text_Input('name',self,setter=self.set_name,label='Name'))
self.menu.append(ui.Text_Input('group',self,setter=self.set_group,label='Group'))
help_str = "All pupil nodes of one group share a Master clock."
self.menu.append(ui.Info_Text(help_str))
self.menu.append(ui.Text_Input('sync status',getter=self.sync_status_info,setter=lambda _: _))
# self.menu[-1].read_only = True
self.group_menu = ui.Growing_Menu('Other Pupils')
self.menu.append(self.group_menu)
self.g_pool.sidebar.append(self.menu)
self.update_gui()
def update_gui(self):
if self.group_menu:
self.group_menu.elements[:] = []
for uuid in self.group_members.keys():
self.group_menu.append(ui.Info_Text("%s"%self.group_members[uuid]))
def set_name(self,new_name):
self.name = new_name
if self.thread_pipe:
self.thread_pipe.send(exit_thread)
while self.thread_pipe:
sleep(.01)
self.thread_pipe = zhelper.zthread_fork(self.context, self.thread_loop)
def set_group(self,new_name):
self.group = new_name
if self.thread_pipe:
self.thread_pipe.send(exit_thread)
while self.thread_pipe:
sleep(.01)
self.group_members = {}
self.update_gui()
self.thread_pipe = zhelper.zthread_fork(self.context, self.thread_loop)
def close(self):
self.alive = False
def deinit_gui(self):
if self.menu:
self.g_pool.sidebar.remove(self.menu)
self.menu = None
def thread_loop(self,context,pipe):
n = Pyre(self.name)
n.join(self.group)
n.start()
poller = zmq.Poller()
poller.register(pipe, zmq.POLLIN)
poller.register(n.socket(), zmq.POLLIN)
front,back = zhelper.zcreate_pipe(context)
poller.register(back, zmq.POLLIN)
def wake_up():
#on app close this timer calls a closed socket. We simply catch it here.
try:
front.send('wake_up')
except Exception as e:
logger.debug('Orphaned timer thread raised error: %s'%e)
t = Timer(self.time_sync_announce_interval, wake_up)
t.daemon = True
t.start()
while(True):
try:
#this should not fail but it does sometimes. We need to clean this out.
# I think we are not treating sockets correclty as they are not thread-save.
items = dict(poller.poll())
except zmq.ZMQError:
logger.warning('Socket fail.')
continue
if back in items and items[back] == zmq.POLLIN:
back.recv()
#timeout events are used for pupil sync.
#annouce masterhood every interval time:
if isinstance(self.sync_node,Clock_Sync_Master):
n.shouts(self.group, SYNC_TIME_MASTER_ANNOUNCE+"%s"%self.clock_master_worthiness()+msg_delimeter+'%s'%self.sync_node.port)
# synced slave: see if we should become master if we dont hear annoncement within time.
elif isinstance(self.sync_node,Clock_Sync_Follower) and not self.sync_node.offset_remains:
if self.get_monotonic_time()-self.last_master_announce > self.time_sync_wait_interval_short:
self.sync_node.terminate()
self.sync_node = Clock_Sync_Master(time_fn=self.get_time)
n.shouts(self.group, SYNC_TIME_MASTER_ANNOUNCE+"%s"%self.clock_master_worthiness()+msg_delimeter+'%s'%self.sync_node.port)
# unsynced slave or none should wait longer but eventually take over
elif self.get_monotonic_time()-self.last_master_announce > self.time_sync_wait_interval_long:
if self.sync_node:
self.sync_node.terminate()
self.sync_node = Clock_Sync_Master(time_fn=self.get_time)
n.shouts(self.group, SYNC_TIME_MASTER_ANNOUNCE+"%s"%self.clock_master_worthiness()+msg_delimeter+'%s'%self.sync_node.port)
t = Timer(self.time_sync_announce_interval, wake_up)
t.daemon = True
t.start()
if pipe in items and items[pipe] == zmq.POLLIN:
message = pipe.recv()
# message to quit
if message.decode('utf-8') == exit_thread:
break
else:
logger.debug("Shout '%s' to '%s' " %(message,self.group))
n.shouts(self.group, message)
if n.socket() in items and items[n.socket()] == zmq.POLLIN:
cmds = n.recv()
msg_type = cmds.pop(0)
msg_type = msg_type.decode('utf-8')
if msg_type == "SHOUT":
uuid,name,group,msg = cmds
logger.debug("'%s' shouts '%s'."%(name,msg))
self.handle_msg(uuid,name,msg,n)
elif msg_type == "WHISPER":
uuid,name,msg = cmds
logger.debug("'%s/' whispers '%s'."%(name,msg))
self.handle_msg_whisper(uuid,name,msg,n)
elif msg_type == "JOIN":
uuid,name,group = cmds
if group == self.group:
self.group_members[uuid] = name
self.update_gui()
elif msg_type == "EXIT":
uuid,name = cmds
try:
del self.group_members[uuid]
except KeyError:
pass
else:
self.update_gui()
# elif msg_type == "LEAVE":
# uuid,name,group = cmds
# elif msg_type == "ENTER":
# uuid,name,headers,ip = cmds
# logger.warning((uuid,'name',headers,ip))
else:
pass
logger.debug('thread_loop closing.')
self.thread_pipe = None
n.stop()
def handle_msg(self,uuid,name,msg,n):
#Clock Sync master announce logic
if SYNC_TIME_MASTER_ANNOUNCE in msg:
self.last_master_announce = self.get_monotonic_time()
worthiness,port = msg.replace(SYNC_TIME_MASTER_ANNOUNCE,'').split(msg_delimeter)
foreign_master_worthiness = float(worthiness)
foreign_master_port = int(port)
forein_master_uuid = UUID(bytes=uuid)
foreign_master_address = n.peer_address(forein_master_uuid)
foreign_master_ip = foreign_master_address.split('//')[-1].split(':')[0] # tcp://10.0.1.68:59149
if isinstance(self.sync_node,Clock_Sync_Master):
# who should yield?
if not self.was_adjusted() and foreign_master_adjusted:
should_yield = True
elif self.nerver_adjusted() and (not foreign_master_adjusted):
should_yield = False
else:
if n.uuid().int > forein_master_uuid.int:
self.should_yield = False
else:
self.should_yield = True
if should_yield:
logger.warning("Yield Clock_Sync_Master to %s@%s"%(name,new_master))
self.sync_node.stop()
self.sync_node = Clock_Sync_Follower(foreign_master_ip,port=foreign_master_port,interval=10,time_fn=self.get_time,jump_fn=self.jump_time,slew_fn=self.set_time)
else:
logger.warning("Dominate as Clock_Sync_Master")
n.shouts(self.group, SYNC_TIME_MASTER_ANNOUNCE+"%s"%self.clock_master_worthiness()+msg_delimeter+'%s'%self.sync_node.port)
elif isinstance(self.sync_node,Clock_Sync_Follower):
self.sync_node.host = foreign_master_ip
self.sync_node.port = foreign_master_port
else:
self.sync_node = Clock_Sync_Follower(foreign_master_ip,port=foreign_master_port,interval=10,time_fn=self.get_time,jump_fn=self.jump_time,slew_fn=self.set_time)
logger.debug("Clock synced with %s"%foreign_master_ip)
elif NOTIFICATION in msg :
notification_str = msg.replace(NOTIFICATION,'')
try:
notification = eval(notification_str)
except Exception as e:
logger.error('Recevied mal-formed remote notification. Payload:"%s"'%notification_str)
else:
# This remote notification does not need to be network propagated again.
notification['network_propagate'] = False
# We also add some info on where it came from.
notification['source'] = 'pupil_sync'
notification['sync_node_name'] = name
notification['sync_node_uuid'] = uuid
# Finally we fire it.
self.notify_all(notification)
else:
logger.warning('Received unknown message pattern. Payload:"%s"'%msg)
def handle_msg_whisper(self,peer,name,msg,node):
logger.warning('%s %s %s %s'%(peer,name,msg,node))
def on_notify(self,notification):
# notifications that carry 'network_porpagate':True are turned into a string and sent to all peers.
if notification.get('network_propagate',False):
self.thread_pipe.send(NOTIFICATION+repr(notification))
def get_init_dict(self):
return {'name':self.name,'group':self.group}
def cleanup(self):
"""gets called when the plugin get terminated.
This happens either volunatily or forced.
"""
if self.sync_node:
self.sync_node.terminate()
self.deinit_gui()
self.thread_pipe.send(exit_thread)
while self.thread_pipe:
sleep(.01)
self.context.destroy()
def thread_loop(self,context,pipe):
n = Pyre(self.name)
n.join(self.group)
n.start()
poller = zmq.Poller()
poller.register(pipe, zmq.POLLIN)
poller.register(n.socket(), zmq.POLLIN)
front,back = zhelper.zcreate_pipe(context)
poller.register(back, zmq.POLLIN)
def wake_up():
#on app close this timer calls a closed socket. We simply catch it here.
try:
front.send('wake_up')
except Exception as e:
logger.debug('Orphaned timer thread raised error: %s'%e)
t = Timer(self.time_sync_announce_interval, wake_up)
t.daemon = True
t.start()
while(True):
try:
#this should not fail but it does sometimes. We need to clean this out.
# I think we are not treating sockets correclty as they are not thread-save.
items = dict(poller.poll())
except zmq.ZMQError:
logger.warning('Socket fail.')
continue
if back in items and items[back] == zmq.POLLIN:
back.recv()
#timeout events are used for pupil sync.
#annouce masterhood every interval time:
if isinstance(self.sync_node,Clock_Sync_Master):
n.shouts(self.group, SYNC_TIME_MASTER_ANNOUNCE+"%s"%self.clock_master_worthiness()+msg_delimeter+'%s'%self.sync_node.port)
# synced slave: see if we should become master if we dont hear annoncement within time.
elif isinstance(self.sync_node,Clock_Sync_Follower) and not self.sync_node.offset_remains:
if self.get_monotonic_time()-self.last_master_announce > self.time_sync_wait_interval_short:
self.sync_node.terminate()
self.sync_node = Clock_Sync_Master(time_fn=self.get_time)
n.shouts(self.group, SYNC_TIME_MASTER_ANNOUNCE+"%s"%self.clock_master_worthiness()+msg_delimeter+'%s'%self.sync_node.port)
# unsynced slave or none should wait longer but eventually take over
elif self.get_monotonic_time()-self.last_master_announce > self.time_sync_wait_interval_long:
if self.sync_node:
self.sync_node.terminate()
self.sync_node = Clock_Sync_Master(time_fn=self.get_time)
n.shouts(self.group, SYNC_TIME_MASTER_ANNOUNCE+"%s"%self.clock_master_worthiness()+msg_delimeter+'%s'%self.sync_node.port)
t = Timer(self.time_sync_announce_interval, wake_up)
t.daemon = True
t.start()
if pipe in items and items[pipe] == zmq.POLLIN:
message = pipe.recv()
# message to quit
if message.decode('utf-8') == exit_thread:
break
else:
logger.debug("Shout '%s' to '%s' " %(message,self.group))
n.shouts(self.group, message)
if n.socket() in items and items[n.socket()] == zmq.POLLIN:
cmds = n.recv()
msg_type = cmds.pop(0)
msg_type = msg_type.decode('utf-8')
if msg_type == "SHOUT":
uuid,name,group,msg = cmds
logger.debug("'%s' shouts '%s'."%(name,msg))
self.handle_msg(uuid,name,msg,n)
elif msg_type == "WHISPER":
uuid,name,msg = cmds
logger.debug("'%s/' whispers '%s'."%(name,msg))
self.handle_msg_whisper(uuid,name,msg,n)
elif msg_type == "JOIN":
uuid,name,group = cmds
if group == self.group:
self.group_members[uuid] = name
self.update_gui()
elif msg_type == "EXIT":
uuid,name = cmds
try:
del self.group_members[uuid]
except KeyError:
pass
else:
self.update_gui()
# elif msg_type == "LEAVE":
# uuid,name,group = cmds
# elif msg_type == "ENTER":
# uuid,name,headers,ip = cmds
# logger.warning((uuid,'name',headers,ip))
else:
pass
logger.debug('thread_loop closing.')
self.thread_pipe = None
n.stop()
class Pupil_Sync_Node(object):
"""Talk to Pupil Captures across the network.
Synchronize time with other Pupil Captures.
time_grandmaster forces all other sync nodes to follow this nodes time.
A Note on system clock jitter
during tests using a Mac and Linux machine on a 3ms latency network with network jitter of ~50us
it became apparent that even on Linux not all clocks are created equal:
on MacOS time.time appears to have low jitter (<1ms)
on Linux (Ubunut Python 2.7) time.time shows more jitter (<3ms)
it is thus recommended for Linux to use uvc.get_time_monotonic.
"""
def __init__(self, name='unnamed Pupil',group='default group',time_grandmaster=False):
super(Pupil_Sync_Node, self).__init__()
self.name = name
self.group = group
self.group_members = {}
self._time_grandmaster = time_grandmaster
#variables for the time sync logic
self.time_sync_node = None
self.last_master_announce = self.get_unadjusted_time()
#constants for the time sync logic
self.time_sync_announce_interval = 5
self.time_sync_wait_interval_short = self.time_sync_announce_interval * 3
self.time_sync_wait_interval_long = self.time_sync_announce_interval * 4
self.context = zmq.Context()
self.thread_pipe = zhelper.zthread_fork(self.context, self._thread_loop)
self.timebase = 0.0 #this is the time offset
def on_notify(self,notification):
'''
this get called when a notification is received. Overwrite as needed.
'''
print notification
def notify_all(self,notification):
'''
call this to notify other sync nodes use notfication format and add network_propagate:True
'''
# notifications that carry 'network_porpagate':True are turned into a string and sent to all peers.
if notification.get('network_propagate',False):
self.thread_pipe.send(NOTIFICATION+repr(notification))
def get_time(self):
'''
return synchorinzed timestamps
'''
return time()-self.timebase
def get_unadjusted_time(self):
'''
return timestamps not influced by outside clocks.
'''
return time()
###time sync fns these are used by the time sync node to get and adjust time
def set_time(self,offset):
self.timebase +=offset
def jump_time(self,offset):
ok_to_change = True
if ok_to_change:
self.set_time(offset)
logger.info("Pupil Sync has adjusted the clock by %ss"%offset)
return True
else:
return False
def clock_master_worthiness(self):
'''
How worthy am I to be the clock master?
A measure 0 (unworthy) to 1 (destined)
tie-breaking is does via bigger uuid.int
'''
if self._time_grandmaster:
return 1.
else:
return 0.
def sync_status_info(self):
if self.time_sync_node is None:
return 'Waiting for time sync msg.'
else:
return str(self.time_sync_node)
def set_name(self,new_name):
self.name = new_name
if self.thread_pipe:
self.thread_pipe.send(exit_thread)
while self.thread_pipe:
sleep(.01)
self.thread_pipe = zhelper.zthread_fork(self.context, self._thread_loop)
def set_group(self,new_name):
self.group = new_name
if self.thread_pipe:
self.thread_pipe.send(exit_thread)
while self.thread_pipe:
sleep(.01)
self.group_members = {}
self.thread_pipe = zhelper.zthread_fork(self.context, self._thread_loop)
def request_group_timestamps(self):
'''
Request timestamps from all nodes.
'''
self.thread_pipe.send(TIMESTAMP_REQ)
def node_timestamps_response(self,uuid,name,msg):
'''
request_group_timestamps response callback.
'''
print name,msg
def _thread_loop(self,context,pipe):
n = Pyre(self.name)
n.join(self.group)
n.start()
poller = zmq.Poller()
poller.register(pipe, zmq.POLLIN)
poller.register(n.socket(), zmq.POLLIN)
front,back = zhelper.zcreate_pipe(context)
poller.register(back, zmq.POLLIN)
def wake_up():
#on app close this timer calls a closed socket. We simply catch it here.
try:
front.send('wake_up')
except Exception as e:
logger.debug('Orphaned timer thread raised error: %s'%e)
if self._time_grandmaster:
t = Timer(0.1, wake_up)
else:
t = Timer(self.time_sync_announce_interval, wake_up)
t.daemon = True
t.start()
while(True):
try:
#this should not fail but it does sometimes. We need to clean this out.
# I think we are not treating sockets correclty as they are not thread-save.
items = dict(poller.poll())
except zmq.ZMQError:
logger.warning('Socket fail.')
continue
if back in items and items[back] == zmq.POLLIN:
self._handle_wake_up(back,n,wake_up)
if pipe in items and items[pipe] == zmq.POLLIN:
if self._handle_internal(pipe,n):
break
if n.socket() in items and items[n.socket()] == zmq.POLLIN:
self._handle_network(n)
else:
pass
logger.debug('_thread_loop closing.')
self.thread_pipe = None
n.stop()
def _handle_internal(self,socket,network):
message = socket.recv()
# message to quit
if message.decode('utf-8') == exit_thread:
return True
else:
logger.debug("Shout '%s' to '%s' " %(message,self.group))
network.shouts(self.group, message)
return False
def _handle_network(self,network):
cmds = network.recv()
msg_type = cmds.pop(0)
msg_type = msg_type.decode('utf-8')
if msg_type == "SHOUT":
uuid,name,group,msg = cmds
logger.debug("'%s' shouts '%s'."%(name,msg))
self._handle_msg(uuid,name,msg,network)
elif msg_type == "WHISPER":
uuid,name,msg = cmds
logger.debug("'%s/' whispers '%s'."%(name,msg))
self._handle_msg_whisper(uuid,name,msg,network)
elif msg_type == "JOIN":
uuid,name,group = cmds
if group == self.group:
self.group_members[uuid] = name
elif msg_type == "EXIT":
uuid,name = cmds
try:
del self.group_members[uuid]
except KeyError:
cmds = [uuid,name,None]
else:
cmds = [uuid,name,self.group]
# elif msg_type == "LEAVE":
# uuid,name,group = cmds
# elif msg_type == "ENTER":
# uuid,name,headers,ip = cmds
# logger.warning((uuid,'name',headers,ip))
return (msg_type, cmds)
def _handle_wake_up(self,socket,network,wake_up_fun):
socket.recv()
#timeout events are used for pupil sync.
#annouce masterhood every interval time:
if isinstance(self.time_sync_node,Clock_Sync_Master):
network.shouts(self.group, SYNC_TIME_MASTER_ANNOUNCE+"%s"%self.clock_master_worthiness()+msg_delimeter+'%s'%self.time_sync_node.port)
elif self._time_grandmaster:
self.time_sync_node = Clock_Sync_Master(time_fn=self.get_time)
network.shouts(self.group, SYNC_TIME_MASTER_ANNOUNCE+"%s"%self.clock_master_worthiness()+msg_delimeter+'%s'%self.time_sync_node.port)
# synced slave: see if we should become master if we dont hear annoncement within time.
elif isinstance(self.time_sync_node,Clock_Sync_Follower) and not self.time_sync_node.offset_remains:
if self.get_unadjusted_time()-self.last_master_announce > self.time_sync_wait_interval_short:
self.time_sync_node.terminate()
self.time_sync_node = Clock_Sync_Master(time_fn=self.get_time)
network.shouts(self.group, SYNC_TIME_MASTER_ANNOUNCE+"%s"%self.clock_master_worthiness()+msg_delimeter+'%s'%self.time_sync_node.port)
# unsynced slave or none should wait longer but eventually take over
elif self.get_unadjusted_time()-self.last_master_announce > self.time_sync_wait_interval_long:
if self.time_sync_node:
self.time_sync_node.terminate()
self.time_sync_node = Clock_Sync_Master(time_fn=self.get_time)
network.shouts(self.group, SYNC_TIME_MASTER_ANNOUNCE+"%s"%self.clock_master_worthiness()+msg_delimeter+'%s'%self.time_sync_node.port)
t = Timer(self.time_sync_announce_interval, wake_up_fun)
t.daemon = True
t.start()
def _handle_msg(self,uuid,name,msg,node):
#Clock Sync master announce logic
if SYNC_TIME_MASTER_ANNOUNCE in msg:
self.last_master_announce = self.get_unadjusted_time()
worthiness,port = msg.replace(SYNC_TIME_MASTER_ANNOUNCE,'').split(msg_delimeter)
foreign_master_worthiness = float(worthiness)
foreign_master_port = int(port)
forein_master_uuid = UUID(bytes=uuid)
foreign_master_address = node.peer_address(forein_master_uuid)
foreign_master_ip = foreign_master_address.split('//')[-1].split(':')[0] # tcp://10.0.1.68:59149
if isinstance(self.time_sync_node,Clock_Sync_Master):
# who should yield?
if self.clock_master_worthiness() == foreign_master_worthiness:
should_yield = node.uuid().int < forein_master_uuid.int
else:
should_yield = self.clock_master_worthiness() < foreign_master_worthiness
if should_yield:
logger.warning("Yield Clock_Sync_Master to %s@%s"%(name,foreign_master_ip))
self.time_sync_node.stop()
self.time_sync_node = Clock_Sync_Follower(foreign_master_ip,port=foreign_master_port,interval=10,time_fn=self.get_time,jump_fn=self.jump_time,slew_fn=self.set_time)
else:
logger.warning("Dominate as Clock_Sync_Master")
node.shouts(self.group, SYNC_TIME_MASTER_ANNOUNCE+"%s"%self.clock_master_worthiness()+msg_delimeter+'%s'%self.time_sync_node.port)
elif isinstance(self.time_sync_node,Clock_Sync_Follower):
self.time_sync_node.host = foreign_master_ip
self.time_sync_node.port = foreign_master_port
else:
self.time_sync_node = Clock_Sync_Follower(foreign_master_ip,port=foreign_master_port,interval=10,time_fn=self.get_time,jump_fn=self.jump_time,slew_fn=self.set_time)
logger.debug("Clock synced with %s"%foreign_master_ip)
elif TIMESTAMP_REQ in msg:
node.whisper(UUID(bytes=uuid),TIMESTAMP+'%s'%self.get_time())
elif NOTIFICATION in msg :
notification_str = msg.replace(NOTIFICATION,'')
try:
notification = eval(notification_str)
except Exception as e:
logger.error('Recevied mal-formed remote notification. Payload:"%s"'%notification_str)
else:
# This remote notification does not need to be network propagated again.
notification['network_propagate'] = False
# We also add some info on where it came from.
notification['source'] = 'pupil_sync'
notification['sync_node_name'] = name
notification['sync_node_uuid'] = uuid
# Finally we fire it.
self.on_notify(notification)
else:
logger.warning('Received unknown message pattern. Payload:"%s"'%msg)
def _handle_msg_whisper(self,uuid,name,msg,node):
if TIMESTAMP_REQ in msg:
node.whisper(UUID(bytes=uuid),TIMESTAMP+'%s'%self.get_time())
elif TIMESTAMP in msg:
self.node_timestamps_response(uuid,name,float(msg.replace(TIMESTAMP,"")))
logger.warning('%s %s %s %s'%(uuid,name,msg,node))
def close(self):
"""gets called when the plugin get terminated.
This happens either volunatily or forced.
"""
if self.time_sync_node:
self.time_sync_node.terminate()
self.thread_pipe.send(exit_thread)
while self.thread_pipe:
sleep(.01)
self.context.destroy()
def on_notify(self, notification):
"""Synchronize time of Actors across local network.
The notification scheme is used to handle interal timing
and to talk to remote pers via the `Pupil_Groups` plugin.
Reacts to notifications:
``time_sync.master_announcement``: React accordingly to annouce notification from remote peer.
``time_sync.master_announce_interval``: Re-annouce clock masterhood.
``time_sync.master_announce_timeout``: React accordingly when no master announcement has appeard whithin timeout.
Emits notifications:
``time_sync.master_announcement``: Announce masterhood to remote peers (remote notification).
``time_sync.master_announce_interval``: Re-announce masterhood reminder (delayed notification).
``time_sync.master_announce_timeout``: Timeout for foreind master announcement (delayed notification).
"""
if notification['subject'].startswith('time_sync.master_announcement'):
if self.is_master:
if notification['worthiness'] > self.clock_master_worthiness():
#We need to yield.
self.time_sync_node.stop()
self.time_sync_node = None
else:
#Denounce the lesser competition.
n = {
'subject': 'time_sync.master_announcement',
'host': self.time_sync_node.host,
'port': self.time_sync_node.port,
'worthiness': self.clock_master_worthiness(),
'remote_notify': 'all'
}
self.notify_all(n)
if self.is_follower:
# update follower info
self.time_sync_node.host = notification['host']
self.time_sync_node.port = notification['port']
if self.is_nothing:
# Create follower.
logger.debug("Clock will sync with {}".format(
notification['host']))
self.time_sync_node = Clock_Sync_Follower(
notification['host'],
port=notification['port'],
interval=10,
time_fn=self.get_time,
jump_fn=self.jump_time,
slew_fn=self.slew_time)
if not self.is_master:
#(Re)set the timer.
self.notify_all(self.master_announce_timeout_notification)
elif notification['subject'].startswith(
'time_sync.master_announce_timeout'):
if self.is_master:
pass
else:
#We have not heard from a master in too long.
logger.info("Elevate self to clock master.")
self.time_sync_node = Clock_Sync_Master(
self.g_pool.get_timestamp)
n = {
'subject': 'time_sync.master_announcement',
'host': self.time_sync_node.host,
'port': self.time_sync_node.port,
'worthiness': self.clock_master_worthiness(),
'remote_notify': 'all'
}
self.notify_all(n)
self.notify_all(self.master_announce_interval_notification)
elif notification['subject'].startswith(
'time_sync.master_announce_interval'):
# The time has come to remind others of our master hood.
if self.is_master:
n = {
'subject': 'time_sync.master_announcement',
'host': self.time_sync_node.host,
'port': self.time_sync_node.port,
'worthiness': self.clock_master_worthiness(),
'remote_notify': 'all'
}
self.notify_all(n)
# Set the next annouce timer.
self.notify_all(self.master_announce_interval_notification)
class Time_Sync(Plugin):
"""Synchronize time across local network.
Implements the Pupil Time Sync protocol.
Acts as clock service and as follower if required.
See `time_sync_spec.md` for details.
"""
icon_chr = chr(0xec15)
icon_font = 'pupil_icons'
def __init__(self, g_pool, node_name=None, sync_group_prefix='default', base_bias=1.):
super().__init__(g_pool)
self.sync_group_prefix = sync_group_prefix
self.discovery = None
self.leaderboard = []
self.has_been_master = 0.
self.has_been_synced = 0.
self.tie_breaker = random.random()
self.base_bias = base_bias
self.master_service = Clock_Sync_Master(self.g_pool.get_timestamp)
self.follower_service = None # only set if there is a better server than us
self.restart_discovery(node_name)
@property
def sync_group(self):
return self.sync_group_prefix + '-time_sync-' + __protocol_version__
@sync_group.setter
def sync_group(self, full_name):
self.sync_group_prefix = full_name.rsplit('-time_sync-' + __protocol_version__, maxsplit=1)[0]
def init_ui(self):
self.add_menu()
self.menu.label = 'Network Time Sync'
help_str = "Synchonize time of Pupil Captures across the local network."
self.menu.append(ui.Info_Text('Protocol version: ' + __protocol_version__))
self.menu.append(ui.Info_Text(help_str))
help_str = "All pupil nodes of one group share a Master clock."
self.menu.append(ui.Info_Text(help_str))
self.menu.append(ui.Text_Input('node_name', self, label='Node Name', setter=self.restart_discovery))
self.menu.append(ui.Text_Input('sync_group_prefix', self, label='Sync Group', setter=self.change_sync_group))
def sync_status():
if self.follower_service:
return str(self.follower_service)
else:
return 'Clock Master'
self.menu.append(ui.Text_Input('sync status', getter=sync_status, setter=lambda _: _, label='Status'))
def set_bias(bias):
if bias < 0:
bias = 0.
self.base_bias = bias
self.announce_clock_master_info()
self.evaluate_leaderboard()
help_str = "The clock service with the highest bias becomes clock master."
self.menu.append(ui.Info_Text(help_str))
self.menu.append(ui.Text_Input('base_bias', self, label='Master Bias', setter=set_bias))
self.menu.append(ui.Text_Input('leaderboard', self, label='Master Nodes in Group'))
def recent_events(self, events):
should_announce = False
for evt in self.discovery.recent_events():
if evt.type == 'SHOUT':
try:
self.update_leaderboard(evt.peer_uuid, evt.peer_name, float(evt.msg[0]), int(evt.msg[1]))
except Exception as e:
logger.debug('Garbage raised `{}` -- dropping.'.format(e))
self.evaluate_leaderboard()
elif evt.type == 'JOIN' and evt.group == self.sync_group:
should_announce = True
elif (evt.type == 'LEAVE' and evt.group == self.sync_group) or evt.type == 'EXIT':
self.remove_from_leaderboard(evt.peer_uuid)
self.evaluate_leaderboard()
if should_announce:
self.announce_clock_master_info()
if not self.has_been_synced and self.follower_service and self.follower_service.in_sync:
self.has_been_synced = 1.
self.announce_clock_master_info()
self.evaluate_leaderboard()
def update_leaderboard(self, uuid, name, rank, port):
for cs in self.leaderboard:
if cs.uuid == uuid:
if (cs.rank != rank) or (cs.port != port):
self.remove_from_leaderboard(cs.uuid)
break
else:
# no changes. Just leave as is
return
# clock service was not encountered before or has changed adding it to leaderboard
cs = Clock_Service(uuid, name, rank, port)
heappush(self.leaderboard, cs)
logger.debug('{} added'.format(cs))
def remove_from_leaderboard(self, uuid):
for cs in self.leaderboard:
if cs.uuid == uuid:
self.leaderboard.remove(cs)
logger.debug('{} removed'.format(cs))
break
def evaluate_leaderboard(self):
if not self.leaderboard:
logger.debug("nobody on the leader board.")
return
current_leader = self.leaderboard[0]
if self.discovery.uuid() != current_leader.uuid:
# we are not the leader!
leader_ep = self.discovery.peer_address(current_leader.uuid)
leader_addr = urlparse(leader_ep).netloc.split(':')[0]
if self.follower_service is None:
# make new follower
self.follower_service = Clock_Sync_Follower(leader_addr,
port=current_leader.port,
interval=10,
time_fn=self.get_time,
jump_fn=self.jump_time,
slew_fn=self.slew_time)
else:
# update follower_service
self.follower_service.host = leader_addr
self.follower_service.port = current_leader.port
return
# we are the leader
logger.debug("we are the leader")
if self.follower_service is not None:
self.follower_service.terminate()
self.follower_service = None
if not self.has_been_master:
self.has_been_master = 1.
logger.debug('Become clock master with rank {}'.format(self.rank))
self.announce_clock_master_info()
def announce_clock_master_info(self):
self.discovery.shout(self.sync_group, [repr(self.rank).encode(),
repr(self.master_service.port).encode()])
self.update_leaderboard(self.discovery.uuid(), self.node_name, self.rank, self.master_service.port)
@property
def rank(self):
return 4*self.base_bias + 2*self.has_been_master + self.has_been_synced + self.tie_breaker
def get_time(self):
return self.g_pool.get_timestamp()
def slew_time(self, offset):
self.g_pool.timebase.value += offset
def jump_time(self, offset):
ok_to_change = True
for p in self.g_pool.plugins:
if p.class_name == 'Recorder':
if p.running:
ok_to_change = False
logger.error("Request to change timebase during recording ignored. Turn off recording first.")
break
if ok_to_change:
self.slew_time(offset)
logger.info("Pupil Sync has adjusted the clock by {}s".format(offset))
return True
else:
return False
def restart_discovery(self, name):
if self.discovery:
if self.discovery.name() == name:
return
else:
self.discovery.leave(self.sync_group)
self.discovery.stop()
self.leaderboard = []
self.node_name = name or gethostname()
self.discovery = Pyre(self.node_name)
# Either joining network for the first time or rejoining the same group.
self.discovery.join(self.sync_group)
self.discovery.start()
self.announce_clock_master_info()
def change_sync_group(self, new_group_prefix):
if new_group_prefix != self.sync_group_prefix:
self.discovery.leave(self.sync_group)
self.leaderboard = []
if self.follower_service:
self.follower_service.terminate()
self.follower = None
self.sync_group_prefix = new_group_prefix
self.discovery.join(self.sync_group)
self.announce_clock_master_info()
def deinit_ui(self):
self.remove_menu()
def get_init_dict(self):
return {'node_name': self.node_name,
'sync_group_prefix': self.sync_group_prefix,
'base_bias': self.base_bias}
def cleanup(self):
self.discovery.leave(self.sync_group)
self.discovery.stop()
self.master_service.stop()
if self.follower_service:
self.follower_service.stop()
self.master_service = None
self.follower_service = None
self.discovery = None
class Time_Sync(Plugin):
"""Synchronize time across local network.
Implements the Pupil Time Sync protocol.
Acts as clock service and as follower if required.
See `time_sync_spec.md` for details.
"""
def __init__(self, g_pool, node_name=None, sync_group_prefix='default', base_bias=1.):
super().__init__(g_pool)
self.menu = None
self.sync_group_prefix = sync_group_prefix
self.discovery = None
self.leaderboard = []
self.has_been_master = 0.
self.has_been_synced = 0.
self.tie_breaker = random.random()
self.base_bias = base_bias
self.master_service = Clock_Sync_Master(self.g_pool.get_timestamp)
self.follower_service = None # only set if there is a better server than us
self.restart_discovery(node_name)
@property
def sync_group(self):
return self.sync_group_prefix + '-time_sync-' + __protocol_version__
@sync_group.setter
def sync_group(self, full_name):
self.sync_group_prefix = full_name.rsplit('-time_sync-' + __protocol_version__, maxsplit=1)[0]
def init_gui(self):
def close():
self.alive = False
help_str = "Synchonize time of Pupil Captures across the local network."
self.menu = ui.Growing_Menu('Network Time Sync')
self.menu.collapsed = True
self.menu.append(ui.Button('Close', close))
self.menu.append(ui.Info_Text('Protocol version: ' + __protocol_version__))
self.menu.append(ui.Info_Text(help_str))
help_str = "All pupil nodes of one group share a Master clock."
self.menu.append(ui.Info_Text(help_str))
self.menu.append(ui.Text_Input('node_name', self, label='Node Name', setter=self.restart_discovery))
self.menu.append(ui.Text_Input('sync_group_prefix', self, label='Sync Group', setter=self.change_sync_group))
def sync_status():
if self.follower_service:
return str(self.follower_service)
else:
return 'Clock Master'
self.menu.append(ui.Text_Input('sync status', getter=sync_status, setter=lambda _: _, label='Status'))
def set_bias(bias):
if bias < 0:
bias = 0.
self.base_bias = bias
self.announce_clock_master_info()
self.evaluate_leaderboard()
help_str = "The clock service with the highest bias becomes clock master."
self.menu.append(ui.Info_Text(help_str))
self.menu.append(ui.Text_Input('base_bias', self, label='Master Bias', setter=set_bias))
self.menu.append(ui.Text_Input('leaderboard', self, label='Master Nodes in Group'))
self.g_pool.sidebar.append(self.menu)
def recent_events(self, events):
should_announce = False
for evt in self.discovery.recent_events():
if evt.type == 'SHOUT':
try:
self.update_leaderboard(evt.peer_uuid, evt.peer_name, float(evt.msg[0]), int(evt.msg[1]))
except Exception as e:
logger.debug('Garbage raised `{}` -- dropping.'.format(e))
self.evaluate_leaderboard()
elif evt.type == 'JOIN' and evt.group == self.sync_group:
should_announce = True
elif (evt.type == 'LEAVE' and evt.group == self.sync_group) or evt.type == 'EXIT':
self.remove_from_leaderboard(evt.peer_uuid)
self.evaluate_leaderboard()
if should_announce:
self.announce_clock_master_info()
if not self.has_been_synced and self.follower_service and self.follower_service.in_sync:
self.has_been_synced = 1.
self.announce_clock_master_info()
self.evaluate_leaderboard()
def update_leaderboard(self, uuid, name, rank, port):
for cs in self.leaderboard:
if cs.uuid == uuid:
if (cs.rank != rank) or (cs.port != port):
self.remove_from_leaderboard(cs.uuid)
break
else:
# no changes. Just leave as is
return
# clock service was not encountered before or has changed adding it to leaderboard
cs = Clock_Service(uuid, name, rank, port)
heappush(self.leaderboard, cs)
logger.debug('{} added'.format(cs))
def remove_from_leaderboard(self, uuid):
for cs in self.leaderboard:
if cs.uuid == uuid:
self.leaderboard.remove(cs)
logger.debug('{} removed'.format(cs))
break
def evaluate_leaderboard(self):
if not self.leaderboard:
logger.debug("nobody on the leader board.")
return
current_leader = self.leaderboard[0]
if self.discovery.uuid() != current_leader.uuid:
# we are not the leader!
leader_ep = self.discovery.peer_address(current_leader.uuid)
leader_addr = urlparse(leader_ep).netloc.split(':')[0]
if self.follower_service is None:
# make new follower
self.follower_service = Clock_Sync_Follower(leader_addr,
port=current_leader.port,
interval=10,
time_fn=self.get_time,
jump_fn=self.jump_time,
slew_fn=self.slew_time)
else:
# update follower_service
self.follower_service.host = leader_addr
self.follower_service.port = current_leader.port
return
# we are the leader
logger.debug("we are the leader")
if self.follower_service is not None:
self.follower_service.terminate()
self.follower_service = None
if not self.has_been_master:
self.has_been_master = 1.
logger.debug('Become clock master with rank {}'.format(self.rank))
self.announce_clock_master_info()
def announce_clock_master_info(self):
self.discovery.shout(self.sync_group, [repr(self.rank).encode(),
repr(self.master_service.port).encode()])
self.update_leaderboard(self.discovery.uuid(), self.node_name, self.rank, self.master_service.port)
@property
def rank(self):
return 4*self.base_bias + 2*self.has_been_master + self.has_been_synced + self.tie_breaker
def get_time(self):
return self.g_pool.get_timestamp()
def slew_time(self, offset):
self.g_pool.timebase.value += offset
def jump_time(self, offset):
ok_to_change = True
for p in self.g_pool.plugins:
if p.class_name == 'Recorder':
if p.running:
ok_to_change = False
logger.error("Request to change timebase during recording ignored. Turn off recording first.")
break
if ok_to_change:
self.slew_time(offset)
logger.info("Pupil Sync has adjusted the clock by {}s".format(offset))
return True
else:
return False
def restart_discovery(self, name):
if self.discovery:
if self.discovery.name() == name:
return
else:
self.discovery.leave(self.sync_group)
self.discovery.stop()
self.leaderboard = []
self.node_name = name or gethostname()
self.discovery = Pyre(self.node_name)
# Either joining network for the first time or rejoining the same group.
self.discovery.join(self.sync_group)
self.discovery.start()
self.announce_clock_master_info()
def change_sync_group(self, new_group_prefix):
if new_group_prefix != self.sync_group_prefix:
self.discovery.leave(self.sync_group)
self.leaderboard = []
if self.follower_service:
self.follower_service.terminate()
self.follower = None
self.sync_group_prefix = new_group_prefix
self.discovery.join(self.sync_group)
self.announce_clock_master_info()
def deinit_gui(self):
if self.menu:
self.g_pool.sidebar.remove(self.menu)
self.menu = None
def get_init_dict(self):
return {'node_name': self.node_name,
'sync_group_prefix': self.sync_group_prefix,
'base_bias': self.base_bias}
def cleanup(self):
self.deinit_gui()
self.discovery.leave(self.sync_group)
self.discovery.stop()
self.master_service.stop()
if self.follower_service:
self.follower_service.stop()
self.master_service = None
self.follower_service = None
self.discovery = None
class Pupil_Sync(Plugin):
"""Synchonize behaviour of Pupil captures
across the local network
"""
def __init__(self, g_pool, name='unnamed Pupil', group='default group'):
super(Pupil_Sync, self).__init__(g_pool)
self.order = .01 #excecute first
self.name = name
self.group = group
self.group_members = {}
self.menu = None
self.group_menu = None
#variables for the time sync logic
self.time_sync_node = None
self.last_master_announce = self.get_unadjusted_time()
#constants for the time sync logic
self.time_sync_announce_interval = 5
self.time_sync_wait_interval_short = self.time_sync_announce_interval * 3
self.time_sync_wait_interval_long = self.time_sync_announce_interval * 4
self.context = zmq.Context()
self.thread_pipe = zhelper.zthread_fork(self.context, self.thread_loop)
def clock_master_worthiness(self):
'''
How worthy am I to be the clock master?
A measure 0 (unworthy) to 1 (destined)
tie-breaking is does via bigger uuid.int
At current this is done via
'''
if self.g_pool.timebase.value == 0:
return 0.
else:
return 0.5
###time sync fns these are used by the time sync node to get and adjust time
def get_unadjusted_time(self):
#return time not influced by outside clocks.
return self.g_pool.capture.get_now()
def get_time(self):
return self.g_pool.capture.get_timestamp()
def set_time(self, offset):
self.g_pool.timebase.value += offset
def jump_time(self, offset):
ok_to_change = True
for p in self.g_pool.plugins:
if p.class_name == 'Recorder':
if p.running:
ok_to_change = False
logger.error(
"Request to change timebase during recording ignored. Turn off recording first."
)
break
if ok_to_change:
self.set_time(offset)
logger.info("Pupil Sync has adjusted the clock by %ss" % offset)
return True
else:
return False
def sync_status_info(self):
if self.time_sync_node is None:
return 'Waiting for time sync msg.'
else:
return str(self.time_sync_node)
def init_gui(self):
help_str = "Synchonize behaviour of Pupil captures across the local network."
self.menu = ui.Growing_Menu('Pupil Sync')
self.menu.append(ui.Button('Close', self.close))
self.menu.append(ui.Info_Text(help_str))
self.menu.append(
ui.Text_Input('name', self, setter=self.set_name, label='Name'))
self.menu.append(
ui.Text_Input('group', self, setter=self.set_group, label='Group'))
help_str = "All pupil nodes of one group share a Master clock."
self.menu.append(ui.Info_Text(help_str))
self.menu.append(
ui.Text_Input('sync status',
getter=self.sync_status_info,
setter=lambda _: _))
# self.menu[-1].read_only = True
self.group_menu = ui.Growing_Menu('Other Pupils')
self.menu.append(self.group_menu)
self.g_pool.sidebar.append(self.menu)
self.update_gui()
def update_gui(self):
if self.group_menu:
self.group_menu.elements[:] = []
for uuid in self.group_members.keys():
self.group_menu.append(
ui.Info_Text("%s" % self.group_members[uuid]))
def set_name(self, new_name):
self.name = new_name
if self.thread_pipe:
self.thread_pipe.send(exit_thread)
while self.thread_pipe:
sleep(.01)
self.thread_pipe = zhelper.zthread_fork(self.context, self.thread_loop)
def set_group(self, new_name):
self.group = new_name
if self.thread_pipe:
self.thread_pipe.send(exit_thread)
while self.thread_pipe:
sleep(.01)
self.group_members = {}
self.update_gui()
self.thread_pipe = zhelper.zthread_fork(self.context, self.thread_loop)
def close(self):
self.alive = False
def deinit_gui(self):
if self.menu:
self.g_pool.sidebar.remove(self.menu)
self.menu = None
def thread_loop(self, context, pipe):
n = Pyre(self.name)
n.join(self.group)
n.start()
poller = zmq.Poller()
poller.register(pipe, zmq.POLLIN)
poller.register(n.socket(), zmq.POLLIN)
front, back = zhelper.zcreate_pipe(context)
poller.register(back, zmq.POLLIN)
def wake_up():
#on app close this timer calls a closed socket. We simply catch it here.
try:
front.send('wake_up')
except Exception as e:
logger.debug('Orphaned timer thread raised error: %s' % e)
t = Timer(self.time_sync_announce_interval, wake_up)
t.daemon = True
t.start()
while (True):
try:
#this should not fail but it does sometimes. We need to clean this out.
# I think we are not treating sockets correclty as they are not thread-save.
items = dict(poller.poll())
except zmq.ZMQError:
logger.warning('Socket fail.')
continue
if back in items and items[back] == zmq.POLLIN:
back.recv()
#timeout events are used for pupil sync.
#annouce masterhood every interval time:
if isinstance(self.time_sync_node, Clock_Sync_Master):
n.shouts(
self.group, SYNC_TIME_MASTER_ANNOUNCE +
"%s" % self.clock_master_worthiness() + msg_delimeter +
'%s' % self.time_sync_node.port)
# synced slave: see if we should become master if we dont hear annoncement within time.
elif isinstance(self.time_sync_node, Clock_Sync_Follower
) and not self.time_sync_node.offset_remains:
if self.get_unadjusted_time(
) - self.last_master_announce > self.time_sync_wait_interval_short:
self.time_sync_node.terminate()
self.time_sync_node = Clock_Sync_Master(
time_fn=self.get_time)
n.shouts(
self.group, SYNC_TIME_MASTER_ANNOUNCE +
"%s" % self.clock_master_worthiness() +
msg_delimeter + '%s' % self.time_sync_node.port)
# unsynced slave or none should wait longer but eventually take over
elif self.get_unadjusted_time(
) - self.last_master_announce > self.time_sync_wait_interval_long:
if self.time_sync_node:
self.time_sync_node.terminate()
self.time_sync_node = Clock_Sync_Master(
time_fn=self.get_time)
n.shouts(
self.group, SYNC_TIME_MASTER_ANNOUNCE +
"%s" % self.clock_master_worthiness() + msg_delimeter +
'%s' % self.time_sync_node.port)
t = Timer(self.time_sync_announce_interval, wake_up)
t.daemon = True
t.start()
if pipe in items and items[pipe] == zmq.POLLIN:
message = pipe.recv()
# message to quit
if message.decode('utf-8') == exit_thread:
break
else:
logger.debug("Shout '%s' to '%s' " % (message, self.group))
n.shouts(self.group, message)
if n.socket() in items and items[n.socket()] == zmq.POLLIN:
cmds = n.recv()
msg_type = cmds.pop(0)
msg_type = msg_type.decode('utf-8')
if msg_type == "SHOUT":
uuid, name, group, msg = cmds
logger.debug("'%s' shouts '%s'." % (name, msg))
self._handle_msg(uuid, name, msg, n)
elif msg_type == "WHISPER":
uuid, name, msg = cmds
logger.debug("'%s/' whispers '%s'." % (name, msg))
self._handle_msg_whisper(uuid, name, msg, n)
elif msg_type == "JOIN":
uuid, name, group = cmds
if group == self.group:
self.group_members[uuid] = name
self.update_gui()
elif msg_type == "EXIT":
uuid, name = cmds
try:
del self.group_members[uuid]
except KeyError:
pass
else:
self.update_gui()
# elif msg_type == "LEAVE":
# uuid,name,group = cmds
# elif msg_type == "ENTER":
# uuid,name,headers,ip = cmds
# logger.warning((uuid,'name',headers,ip))
else:
pass
logger.debug('thread_loop closing.')
self.thread_pipe = None
n.stop()
def _handle_msg(self, uuid, name, msg, node):
#Clock Sync master announce logic
if SYNC_TIME_MASTER_ANNOUNCE in msg:
self.last_master_announce = self.get_unadjusted_time()
worthiness, port = msg.replace(SYNC_TIME_MASTER_ANNOUNCE,
'').split(msg_delimeter)
foreign_master_worthiness = float(worthiness)
foreign_master_port = int(port)
forein_master_uuid = UUID(bytes=uuid)
foreign_master_address = node.peer_address(forein_master_uuid)
foreign_master_ip = foreign_master_address.split('//')[-1].split(
':')[0] # tcp://10.0.1.68:59149
if isinstance(self.time_sync_node, Clock_Sync_Master):
# who should yield?
if self.clock_master_worthiness() == foreign_master_worthiness:
should_yield = node.uuid().int < forein_master_uuid.int
else:
should_yield = self.clock_master_worthiness(
) < foreign_master_worthiness
if should_yield:
logger.warning("Yield Clock_Sync_Master to %s@%s" %
(name, foreign_master_ip))
self.time_sync_node.stop()
self.time_sync_node = Clock_Sync_Follower(
foreign_master_ip,
port=foreign_master_port,
interval=10,
time_fn=self.get_time,
jump_fn=self.jump_time,
slew_fn=self.set_time)
else:
logger.warning("Dominate as Clock_Sync_Master")
node.shouts(
self.group, SYNC_TIME_MASTER_ANNOUNCE +
"%s" % self.clock_master_worthiness() + msg_delimeter +
'%s' % self.time_sync_node.port)
elif isinstance(self.time_sync_node, Clock_Sync_Follower):
self.time_sync_node.host = foreign_master_ip
self.time_sync_node.port = foreign_master_port
else:
self.time_sync_node = Clock_Sync_Follower(
foreign_master_ip,
port=foreign_master_port,
interval=10,
time_fn=self.get_time,
jump_fn=self.jump_time,
slew_fn=self.set_time)
logger.debug("Clock synced with %s" % foreign_master_ip)
elif TIMESTAMP_REQ in msg:
node.whisper(UUID(bytes=uuid), TIMESTAMP + '%s' % self.get_time())
elif NOTIFICATION in msg:
notification_str = msg.replace(NOTIFICATION, '')
try:
notification = eval(notification_str)
except Exception as e:
logger.error(
'Recevied mal-formed remote notification. Payload:"%s"' %
notification_str)
else:
# This remote notification does not need to be network propagated again.
notification['network_propagate'] = False
# We also add some info on where it came from.
notification['source'] = 'pupil_sync'
notification['sync_node_name'] = name
notification['sync_node_uuid'] = uuid
# Finally we fire it.
self.notify_all(notification)
else:
logger.warning('Received unknown message pattern. Payload:"%s"' %
msg)
def _handle_msg_whisper(self, uuid, name, msg, node):
if TIMESTAMP_REQ in msg:
node.whisper(UUID(bytes=uuid), TIMESTAMP + '%s' % self.get_time())
else:
logger.warning('%s %s %s %s' % (uuid, name, msg, node))
def on_notify(self, notification):
# notifications that carry 'network_porpagate':True are turned into a string and sent to all peers.
if notification.get('network_propagate', False):
self.thread_pipe.send(NOTIFICATION + repr(notification))
def get_init_dict(self):
return {'name': self.name, 'group': self.group}
def cleanup(self):
"""gets called when the plugin get terminated.
This happens either volunatily or forced.
"""
if self.time_sync_node:
self.time_sync_node.terminate()
self.deinit_gui()
self.thread_pipe.send(exit_thread)
while self.thread_pipe:
sleep(.01)
self.context.destroy()
class Time_Sync(Plugin):
"""Synchronize time across local network.
Implements the Pupil Time Sync protocol.
Acts as clock service and as follower if required.
See `time_sync_spec.md` for details.
"""
icon_chr = chr(0xEC15)
icon_font = "pupil_icons"
def __init__(self,
g_pool,
node_name=None,
sync_group_prefix="default",
base_bias=1.0):
super().__init__(g_pool)
self.sync_group_prefix = sync_group_prefix
self.discovery = None
self.leaderboard = []
self.has_been_master = 0.0
self.has_been_synced = 0.0
self.tie_breaker = random.random()
self.base_bias = base_bias
self.sync_group_members = {}
self.master_service = Clock_Sync_Master(self.g_pool.get_timestamp)
self.follower_service = None # only set if there is a better server than us
self.restart_discovery(node_name)
@property
def sync_group(self):
return self.sync_group_prefix + "-time_sync-" + __protocol_version__
@sync_group.setter
def sync_group(self, full_name):
self.sync_group_prefix = full_name.rsplit("-time_sync-" +
__protocol_version__,
maxsplit=1)[0]
def init_ui(self):
self.add_menu()
self.menu.label = "Network Time Sync"
help_str = "Synchonize time of Pupil Captures across the local network."
self.menu.append(
ui.Info_Text("Protocol version: " + __protocol_version__))
self.menu.append(ui.Info_Text(help_str))
help_str = "All pupil nodes of one group share a Master clock."
self.menu.append(ui.Info_Text(help_str))
self.menu.append(
ui.Text_Input("node_name",
self,
label="Node Name",
setter=self.restart_discovery))
self.menu.append(
ui.Text_Input(
"sync_group_prefix",
self,
label="Sync Group",
setter=self.change_sync_group,
))
def sync_status():
if self.follower_service:
return str(self.follower_service)
else:
return "Clock Master"
self.menu.append(
ui.Text_Input("sync status",
getter=sync_status,
setter=lambda _: _,
label="Status"))
def set_bias(bias):
if bias < 0:
bias = 0.0
self.base_bias = bias
self.announce_clock_master_info()
self.evaluate_leaderboard()
help_str = "The clock service with the highest bias becomes clock master."
self.menu.append(ui.Info_Text(help_str))
self.menu.append(
ui.Text_Input("base_bias",
self,
label="Master Bias",
setter=set_bias))
self.menu.append(
ui.Text_Input("leaderboard", self, label="Master Nodes in Group"))
self.sync_group_members_menu = ui.Growing_Menu("Sync Group Members")
self.menu.append(self.sync_group_members_menu)
def recent_events(self, events):
should_announce = False
for evt in self.discovery.recent_events():
if evt.type == "SHOUT":
try:
self.update_leaderboard(evt.peer_uuid, evt.peer_name,
float(evt.msg[0]), int(evt.msg[1]))
except Exception as e:
logger.debug("Garbage raised `{}` -- dropping.".format(e))
self.evaluate_leaderboard()
elif evt.type == "JOIN" and evt.group == self.sync_group:
should_announce = True
self.insert_sync_group_member(evt.peer_uuid, evt.peer_name)
elif (evt.type == "LEAVE"
and evt.group == self.sync_group) or evt.type == "EXIT":
self.remove_from_leaderboard(evt.peer_uuid)
self.evaluate_leaderboard()
self.remove_sync_group_member(evt.peer_uuid)
if should_announce:
self.announce_clock_master_info()
if (not self.has_been_synced and self.follower_service
and self.follower_service.in_sync):
self.has_been_synced = 1.0
self.announce_clock_master_info()
self.evaluate_leaderboard()
def update_leaderboard(self, uuid, name, rank, port):
for cs in self.leaderboard:
if cs.uuid == uuid:
if (cs.rank != rank) or (cs.port != port):
self.remove_from_leaderboard(cs.uuid)
break
else:
# no changes. Just leave as is
return
# clock service was not encountered before or has changed adding it to leaderboard
cs = Clock_Service(uuid, name, rank, port)
heappush(self.leaderboard, cs)
logger.debug("{} added".format(cs))
def remove_from_leaderboard(self, uuid):
for cs in self.leaderboard:
if cs.uuid == uuid:
self.leaderboard.remove(cs)
logger.debug("{} removed".format(cs))
break
def evaluate_leaderboard(self):
if not self.leaderboard:
logger.debug("nobody on the leader board.")
return
current_leader = self.leaderboard[0]
if self.discovery.uuid() != current_leader.uuid:
# we are not the leader!
leader_ep = self.discovery.peer_address(current_leader.uuid)
leader_addr = urlparse(leader_ep).netloc.split(":")[0]
if self.follower_service is None:
# make new follower
self.follower_service = Clock_Sync_Follower(
leader_addr,
port=current_leader.port,
interval=10,
time_fn=self.get_time,
jump_fn=self.jump_time,
slew_fn=self.slew_time,
)
else:
# update follower_service
self.follower_service.host = leader_addr
self.follower_service.port = current_leader.port
return
# we are the leader
logger.debug("we are the leader")
if self.follower_service is not None:
self.follower_service.terminate()
self.follower_service = None
if not self.has_been_master:
self.has_been_master = 1.0
logger.debug("Become clock master with rank {}".format(self.rank))
self.announce_clock_master_info()
def insert_sync_group_member(self, uuid, name):
member_text = ui.Info_Text(name)
self.sync_group_members[uuid] = member_text
self.sync_group_members_menu.append(member_text)
self.sync_group_members_menu.elements.sort(
key=lambda text_field: text_field.text)
def insert_all_sync_group_members_from_group(self, group):
for uuid in self.discovery.peers_by_group(group):
name = self.discovery.get_peer_name(uuid)
self.insert_sync_group_member(uuid, name)
def remove_all_sync_group_members(self):
for uuid in list(self.sync_group_members.keys()):
self.remove_sync_group_member(uuid)
def remove_sync_group_member(self, uuid):
try:
self.sync_group_members_menu.remove(self.sync_group_members[uuid])
del self.sync_group_members[uuid]
except KeyError:
logger.debug("Peer has already been removed from members list.")
def announce_clock_master_info(self):
self.discovery.shout(
self.sync_group,
[
repr(self.rank).encode(),
repr(self.master_service.port).encode()
],
)
self.update_leaderboard(self.discovery.uuid(), self.node_name,
self.rank, self.master_service.port)
@property
def rank(self):
return (4 * self.base_bias + 2 * self.has_been_master +
self.has_been_synced + self.tie_breaker)
def get_time(self):
return self.g_pool.get_timestamp()
def slew_time(self, offset):
self.g_pool.timebase.value += offset
def jump_time(self, offset):
ok_to_change = True
for p in self.g_pool.plugins:
if p.class_name == "Recorder":
if p.running:
ok_to_change = False
logger.error(
"Request to change timebase during recording ignored. Turn off recording first."
)
break
if ok_to_change:
self.slew_time(offset)
logger.info(
"Pupil Sync has adjusted the clock by {}s".format(offset))
return True
else:
return False
def restart_discovery(self, name):
if self.discovery:
if self.discovery.name() == name:
return
else:
self.remove_all_sync_group_members()
self.discovery.leave(self.sync_group)
self.discovery.stop()
self.leaderboard = []
self.node_name = name or gethostname()
self.discovery = Pyre(self.node_name)
# Either joining network for the first time or rejoining the same group.
self.discovery.join(self.sync_group)
self.discovery.start()
self.announce_clock_master_info()
def change_sync_group(self, new_group_prefix):
if new_group_prefix != self.sync_group_prefix:
self.remove_all_sync_group_members()
self.discovery.leave(self.sync_group)
self.leaderboard = []
if self.follower_service:
self.follower_service.terminate()
self.follower = None
self.sync_group_prefix = new_group_prefix
self.discovery.join(self.sync_group)
self.insert_all_sync_group_members_from_group(self.sync_group)
self.announce_clock_master_info()
def deinit_ui(self):
for uuid in list(self.sync_group_members.keys()):
self.remove_sync_group_member(uuid)
self.remove_menu()
def get_init_dict(self):
return {
"node_name": self.node_name,
"sync_group_prefix": self.sync_group_prefix,
"base_bias": self.base_bias,
}
def cleanup(self):
self.discovery.leave(self.sync_group)
self.discovery.stop()
self.master_service.stop()
if self.follower_service:
self.follower_service.stop()
self.master_service = None
self.follower_service = None
self.discovery = None
class Pupil_Sync_Node(object):
"""Talk to Pupil Captures across the network.
Synchronize time with other Pupil Captures.
time_grandmaster forces all other sync nodes to follow this nodes time.
A Note on system clock jitter
during tests using a Mac and Linux machine on a 3ms latency network with network jitter of ~50us
it became apparent that even on Linux not all clocks are created equal:
on MacOS time.time appears to have low jitter (<1ms)
on Linux (Ubunut Python 2.7) time.time shows more jitter (<3ms)
it is thus recommended for Linux to use uvc.get_time_monotonic.
"""
def __init__(self,
name='unnamed Pupil',
group='default group',
time_grandmaster=False):
super(Pupil_Sync_Node, self).__init__()
self.name = name
self.group = group
self.group_members = {}
self.menu = None
self.group_menu = None
self._time_grandmaster = time_grandmaster
#variables for the time sync logic
self.time_sync_node = None
self.last_master_announce = self.get_unadjusted_time()
#constants for the time sync logic
self.time_sync_announce_interval = 5
self.time_sync_wait_interval_short = self.time_sync_announce_interval * 3
self.time_sync_wait_interval_long = self.time_sync_announce_interval * 4
self.context = zmq.Context()
self.thread_pipe = zhelper.zthread_fork(self.context,
self._thread_loop)
self.timebase = 0.0 #this is the time offset
def start_recording(self, session_name=""):
'''call this to start recording on all other Pupil Sync Nodes
'''
self.notify_all({
'subject': 'should_start_recording',
'session_name': session_name,
'network_propagate': True
})
def stop_recording(self):
'''call this to start recording on all other Pupil Sync Nodes
'''
self.notify_all({
'subject': 'should_stop_recording',
'network_propagate': True
})
def start_calibration(self):
'''call this to start recording on all other Pupil Sync Nodes
'''
self.notify_all({
'subject': 'should_start_calibration',
'network_propagate': True
})
def stop_calibration(self):
'''call this to start recording on all other Pupil Sync Nodes
'''
self.notify_all({
'subject': 'should_stop_calibration',
'network_propagate': True
})
def on_notify(self, notification):
'''
this get called when a notification is received. Overwrite as needed.
'''
print notification
def notify_all(self, notification):
'''
call this to notify other sync nodes use notfication format and add network_propagate:True
'''
# notifications that carry 'network_porpagate':True are turned into a string and sent to all peers.
if notification.get('network_propagate', False):
self.thread_pipe.send(NOTIFICATION + repr(notification))
def get_time(self):
'''
return synchorinzed timestamps
'''
return time() - self.timebase
def get_unadjusted_time(self):
'''
return timestamps not influced by outside clocks.
'''
return time()
###time sync fns these are used by the time sync node to get and adjust time
def set_time(self, offset):
self.timebase += offset
def jump_time(self, offset):
ok_to_change = True
if ok_to_change:
self.set_time(offset)
logger.info("Pupil Sync has adjusted the clock by %ss" % offset)
return True
else:
return False
def clock_master_worthiness(self):
'''
How worthy am I to be the clock master?
A measure 0 (unworthy) to 1 (destined)
tie-breaking is does via bigger uuid.int
'''
if self._time_grandmaster:
return 1.
else:
return 0.
def sync_status_info(self):
if self.time_sync_node is None:
return 'Waiting for time sync msg.'
else:
return str(self.time_sync_node)
def set_name(self, new_name):
self.name = new_name
if self.thread_pipe:
self.thread_pipe.send(exit_thread)
while self.thread_pipe:
sleep(.01)
self.thread_pipe = zhelper.zthread_fork(self.context,
self._thread_loop)
def set_group(self, new_name):
self.group = new_name
if self.thread_pipe:
self.thread_pipe.send(exit_thread)
while self.thread_pipe:
sleep(.01)
self.group_members = {}
self.update_gui()
self.thread_pipe = zhelper.zthread_fork(self.context,
self._thread_loop)
def request_group_timestamps(self):
'''
Request timestamps from all nodes.
'''
self.thread_pipe.send(TIMESTAMP_REQ)
def node_timestamps_response(self, uuid, name, msg):
'''
request_group_timestamps response callback.
'''
print name, msg
def _thread_loop(self, context, pipe):
n = Pyre(self.name)
n.join(self.group)
n.start()
poller = zmq.Poller()
poller.register(pipe, zmq.POLLIN)
poller.register(n.socket(), zmq.POLLIN)
front, back = zhelper.zcreate_pipe(context)
poller.register(back, zmq.POLLIN)
def wake_up():
#on app close this timer calls a closed socket. We simply catch it here.
try:
front.send('wake_up')
except Exception as e:
logger.debug('Orphaned timer thread raised error: %s' % e)
if self._time_grandmaster:
t = Timer(0.1, wake_up)
else:
t = Timer(self.time_sync_announce_interval, wake_up)
t.daemon = True
t.start()
while (True):
try:
#this should not fail but it does sometimes. We need to clean this out.
# I think we are not treating sockets correclty as they are not thread-save.
items = dict(poller.poll())
except zmq.ZMQError:
logger.warning('Socket fail.')
continue
if back in items and items[back] == zmq.POLLIN:
back.recv()
#timeout events are used for pupil sync.
#annouce masterhood every interval time:
if isinstance(self.time_sync_node, Clock_Sync_Master):
n.shouts(
self.group, SYNC_TIME_MASTER_ANNOUNCE +
"%s" % self.clock_master_worthiness() + msg_delimeter +
'%s' % self.time_sync_node.port)
elif self._time_grandmaster:
self.time_sync_node = Clock_Sync_Master(
time_fn=self.get_time)
n.shouts(
self.group, SYNC_TIME_MASTER_ANNOUNCE +
"%s" % self.clock_master_worthiness() + msg_delimeter +
'%s' % self.time_sync_node.port)
# synced slave: see if we should become master if we dont hear annoncement within time.
elif isinstance(self.time_sync_node, Clock_Sync_Follower
) and not self.time_sync_node.offset_remains:
if self.get_unadjusted_time(
) - self.last_master_announce > self.time_sync_wait_interval_short:
self.time_sync_node.terminate()
self.time_sync_node = Clock_Sync_Master(
time_fn=self.get_time)
n.shouts(
self.group, SYNC_TIME_MASTER_ANNOUNCE +
"%s" % self.clock_master_worthiness() +
msg_delimeter + '%s' % self.time_sync_node.port)
# unsynced slave or none should wait longer but eventually take over
elif self.get_unadjusted_time(
) - self.last_master_announce > self.time_sync_wait_interval_long:
if self.time_sync_node:
self.time_sync_node.terminate()
self.time_sync_node = Clock_Sync_Master(
time_fn=self.get_time)
n.shouts(
self.group, SYNC_TIME_MASTER_ANNOUNCE +
"%s" % self.clock_master_worthiness() + msg_delimeter +
'%s' % self.time_sync_node.port)
t = Timer(self.time_sync_announce_interval, wake_up)
t.daemon = True
t.start()
if pipe in items and items[pipe] == zmq.POLLIN:
message = pipe.recv()
# message to quit
if message.decode('utf-8') == exit_thread:
break
else:
logger.debug("Shout '%s' to '%s' " % (message, self.group))
n.shouts(self.group, message)
if n.socket() in items and items[n.socket()] == zmq.POLLIN:
cmds = n.recv()
msg_type = cmds.pop(0)
msg_type = msg_type.decode('utf-8')
if msg_type == "SHOUT":
uuid, name, group, msg = cmds
logger.debug("'%s' shouts '%s'." % (name, msg))
self._handle_msg(uuid, name, msg, n)
elif msg_type == "WHISPER":
uuid, name, msg = cmds
logger.debug("'%s/' whispers '%s'." % (name, msg))
self._handle_msg_whisper(uuid, name, msg, n)
elif msg_type == "JOIN":
uuid, name, group = cmds
if group == self.group:
self.group_members[uuid] = name
elif msg_type == "EXIT":
uuid, name = cmds
try:
del self.group_members[uuid]
except KeyError:
pass
# elif msg_type == "LEAVE":
# uuid,name,group = cmds
# elif msg_type == "ENTER":
# uuid,name,headers,ip = cmds
# logger.warning((uuid,'name',headers,ip))
else:
pass
logger.debug('_thread_loop closing.')
self.thread_pipe = None
n.stop()
def _handle_msg(self, uuid, name, msg, node):
#Clock Sync master announce logic
if SYNC_TIME_MASTER_ANNOUNCE in msg:
self.last_master_announce = self.get_unadjusted_time()
worthiness, port = msg.replace(SYNC_TIME_MASTER_ANNOUNCE,
'').split(msg_delimeter)
foreign_master_worthiness = float(worthiness)
foreign_master_port = int(port)
forein_master_uuid = UUID(bytes=uuid)
foreign_master_address = node.peer_address(forein_master_uuid)
foreign_master_ip = foreign_master_address.split('//')[-1].split(
':')[0] # tcp://10.0.1.68:59149
if isinstance(self.time_sync_node, Clock_Sync_Master):
# who should yield?
if self.clock_master_worthiness() == foreign_master_worthiness:
should_yield = node.uuid().int < forein_master_uuid.int
else:
should_yield = self.clock_master_worthiness(
) < foreign_master_worthiness
if should_yield:
logger.warning("Yield Clock_Sync_Master to %s@%s" %
(name, foreign_master_ip))
self.time_sync_node.stop()
self.time_sync_node = Clock_Sync_Follower(
foreign_master_ip,
port=foreign_master_port,
interval=10,
time_fn=self.get_time,
jump_fn=self.jump_time,
slew_fn=self.set_time)
else:
logger.warning("Dominate as Clock_Sync_Master")
node.shouts(
self.group, SYNC_TIME_MASTER_ANNOUNCE +
"%s" % self.clock_master_worthiness() + msg_delimeter +
'%s' % self.time_sync_node.port)
elif isinstance(self.time_sync_node, Clock_Sync_Follower):
self.time_sync_node.host = foreign_master_ip
self.time_sync_node.port = foreign_master_port
else:
self.time_sync_node = Clock_Sync_Follower(
foreign_master_ip,
port=foreign_master_port,
interval=10,
time_fn=self.get_time,
jump_fn=self.jump_time,
slew_fn=self.set_time)
logger.debug("Clock synced with %s" % foreign_master_ip)
elif TIMESTAMP_REQ in msg:
node.whisper(UUID(bytes=uuid), TIMESTAMP + '%s' % self.get_time())
elif NOTIFICATION in msg:
notification_str = msg.replace(NOTIFICATION, '')
try:
notification = eval(notification_str)
except Exception as e:
logger.error(
'Recevied mal-formed remote notification. Payload:"%s"' %
notification_str)
else:
# This remote notification does not need to be network propagated again.
notification['network_propagate'] = False
# We also add some info on where it came from.
notification['source'] = 'pupil_sync'
notification['sync_node_name'] = name
notification['sync_node_uuid'] = uuid
# Finally we fire it.
self.on_notify(notification)
else:
logger.warning('Received unknown message pattern. Payload:"%s"' %
msg)
def _handle_msg_whisper(self, uuid, name, msg, node):
if TIMESTAMP_REQ in msg:
node.whisper(UUID(bytes=uuid), TIMESTAMP + '%s' % self.get_time())
elif TIMESTAMP in msg:
self.node_timestamps_response(uuid, name,
float(msg.replace(TIMESTAMP, "")))
logger.warning('%s %s %s %s' % (uuid, name, msg, node))
def close(self):
"""gets called when the plugin get terminated.
This happens either volunatily or forced.
"""
if self.time_sync_node:
self.time_sync_node.terminate()
self.thread_pipe.send(exit_thread)
while self.thread_pipe:
sleep(.01)
self.context.destroy()
