[posix-app] enhance virtual time for posix app (#3016)

tests/scripts/thread-cert/node_cli.py

@@ -32,6 +32,7 @@ import sys
 import time
 import pexpect
 import re
+import socket
 import ipaddress
 
 import config
@@ -69,6 +70,7 @@ class otCli:
 
         if 'RADIO_DEVICE' in os.environ:
             cmd += ' %s' % os.environ['RADIO_DEVICE']
+            os.environ['NODE_ID'] = str(nodeid)
 
         cmd += ' %d' % nodeid
         print ("%s" % cmd)
@@ -76,13 +78,20 @@ class otCli:
         self.pexpect = pexpect.spawn(cmd, timeout=4)
 
         # Add delay to ensure that the process is ready to receive commands.
-        time.sleep(0.2)
-
+        timeout = 0.4
+        while timeout > 0:
+            self.pexpect.send('\r\n')
+            try:
+                self.pexpect.expect('> ', timeout=0.1)
+                break
+            except pexpect.TIMEOUT:
+                timeout -= 0.1
 
     def __init_ncp_sim(self, nodeid, mode):
         """ Initialize an NCP simulation node. """
         if 'RADIO_DEVICE' in os.environ:
             args = ' %s' % os.environ['RADIO_DEVICE']
+            os.environ['NODE_ID'] = str(nodeid)
         else:
             args = ''
 
@@ -97,10 +106,28 @@ class otCli:
         print ("%s" % cmd)
 
         self.pexpect = pexpect.spawn(cmd, timeout=4)
+
+        # Add delay to ensure that the process is ready to receive commands.
         time.sleep(0.2)
-        self.pexpect.expect('spinel-cli >')
+        self._expect('spinel-cli >')
         self.debug(int(os.getenv('DEBUG', '0')))
 
+    def _expect(self, pattern, timeout=-1, *args, **kwargs):
+        """ Process simulator events until expected the pattern. """
+        if timeout == -1:
+            timeout = self.pexpect.timeout
+
+        assert timeout > 0
+
+        while timeout > 0:
+            try:
+                return self.pexpect.expect(pattern, 0.1, *args, **kwargs)
+            except pexpect.TIMEOUT:
+                timeout -= 0.1
+                self.simulator.go(0)
+                if timeout <= 0:
+                    raise
+
     def __init_soc(self, nodeid):
         """ Initialize a System-on-a-chip node connected via UART. """
         import fdpexpect
@@ -112,26 +139,27 @@ class otCli:
 
     def destroy(self):
         if self.pexpect and self.pexpect.isalive():
-            self.send_command('exit')
-            self.pexpect.expect(pexpect.EOF)
+            print("%d: exit" % self.nodeid)
+            self.pexpect.send('exit\n')
             self.pexpect.terminate()
-            self.pexpect.close(force=True)
+            self._expect(pexpect.EOF)
+            self.pexpect.wait()
             self.pexpect = None
+            sys.stdout.flush()
 
-    def send_command(self, cmd):
+    def send_command(self, cmd, go=True):
         print("%d: %s" % (self.nodeid, cmd))
         self.pexpect.send(cmd + '\n')
+        if go:
+            self.simulator.go(0, nodeid=self.nodeid)
         sys.stdout.flush()
 
-        if isinstance(self.simulator, simulator.VirtualTime):
-            self.simulator.receive_events()
-
     def get_commands(self):
         self.send_command('?')
-        self.pexpect.expect('Commands:')
+        self._expect('Commands:')
         commands = []
         while True:
-            i = self.pexpect.expect(['Done', '(\S+)'])
+            i = self._expect(['Done', '(\S+)'])
             if i != 0:
                 commands.append(self.pexpect.match.groups()[0])
             else:
@@ -141,56 +169,57 @@ class otCli:
     def set_mode(self, mode):
         cmd = 'mode ' + mode
         self.send_command(cmd)
-        self.pexpect.expect('Done')
+        self._expect('Done')
 
     def debug(self, level):
-        self.send_command('debug '+str(level))
+        # `debug` command will not trigger interaction with simulator
+        self.send_command('debug '+ str(level), go=False)
 
     def interface_up(self):
         self.send_command('ifconfig up')
-        self.pexpect.expect('Done')
+        self._expect('Done')
 
     def interface_down(self):
         self.send_command('ifconfig down')
-        self.pexpect.expect('Done')
+        self._expect('Done')
 
     def thread_start(self):
         self.send_command('thread start')
-        self.pexpect.expect('Done')
+        self._expect('Done')
 
     def thread_stop(self):
         self.send_command('thread stop')
-        self.pexpect.expect('Done')
+        self._expect('Done')
 
     def commissioner_start(self):
         cmd = 'commissioner start'
         self.send_command(cmd)
-        self.pexpect.expect('Done')
+        self._expect('Done')
 
     def commissioner_add_joiner(self, addr, psk):
         cmd = 'commissioner joiner add ' + addr + ' ' + psk
         self.send_command(cmd)
-        self.pexpect.expect('Done')
+        self._expect('Done')
 
     def joiner_start(self, pskd='', provisioning_url=''):
         cmd = 'joiner start ' + pskd + ' ' + provisioning_url
         self.send_command(cmd)
-        self.pexpect.expect('Done')
+        self._expect('Done')
 
     def clear_whitelist(self):
         cmd = 'macfilter addr clear'
         self.send_command(cmd)
-        self.pexpect.expect('Done')
+        self._expect('Done')
 
     def enable_whitelist(self):
         cmd = 'macfilter addr whitelist'
         self.send_command(cmd)
-        self.pexpect.expect('Done')
+        self._expect('Done')
 
     def disable_whitelist(self):
         cmd = 'macfilter addr disable'
         self.send_command(cmd)
-        self.pexpect.expect('Done')
+        self._expect('Done')
 
     def add_whitelist(self, addr, rssi=None):
         cmd = 'macfilter addr add ' + addr
@@ -199,19 +228,19 @@ class otCli:
             cmd += ' ' + str(rssi)
 
         self.send_command(cmd)
-        self.pexpect.expect('Done')
+        self._expect('Done')
 
     def remove_whitelist(self, addr):
         cmd = 'macfilter addr remove ' + addr
         self.send_command(cmd)
-        self.pexpect.expect('Done')
+        self._expect('Done')
 
     def get_addr16(self):
         self.send_command('rloc16')
-        i = self.pexpect.expect('([0-9a-fA-F]{4})')
+        i = self._expect('([0-9a-fA-F]{4})')
         if i == 0:
             addr16 = int(self.pexpect.match.groups()[0], 16)
-        self.pexpect.expect('Done')
+        self._expect('Done')
         return addr16
 
     def get_router_id(self):
@@ -220,83 +249,83 @@ class otCli:
 
     def get_addr64(self):
         self.send_command('extaddr')
-        i = self.pexpect.expect('([0-9a-fA-F]{16})')
+        i = self._expect('([0-9a-fA-F]{16})')
         if i == 0:
             addr64 = self.pexpect.match.groups()[0].decode("utf-8")
 
-        self.pexpect.expect('Done')
+        self._expect('Done')
         return addr64
 
     def get_eui64(self):
         self.send_command('eui64')
-        i = self.pexpect.expect('([0-9a-fA-F]{16})')
+        i = self._expect('([0-9a-fA-F]{16})')
         if i == 0:
             addr64 = self.pexpect.match.groups()[0].decode("utf-8")
 
-        self.pexpect.expect('Done')
+        self._expect('Done')
         return addr64
 
     def get_joiner_id(self):
         self.send_command('joinerid')
-        i = self.pexpect.expect('([0-9a-fA-F]{16})')
+        i = self._expect('([0-9a-fA-F]{16})')
         if i == 0:
             addr = self.pexpect.match.groups()[0].decode("utf-8")
-        self.pexpect.expect('Done')
+        self._expect('Done')
         return addr
 
     def get_channel(self):
         self.send_command('channel')
-        i = self.pexpect.expect('(\d+)\r\n')
+        i = self._expect('(\d+)\r?\n')
         if i == 0:
             channel = int(self.pexpect.match.groups()[0])
-        self.pexpect.expect('Done')
+        self._expect('Done')
         return channel
 
     def set_channel(self, channel):
         cmd = 'channel %d' % channel
         self.send_command(cmd)
-        self.pexpect.expect('Done')
+        self._expect('Done')
 
     def get_masterkey(self):
         self.send_command('masterkey')
-        i = self.pexpect.expect('([0-9a-fA-F]{32})')
+        i = self._expect('([0-9a-fA-F]{32})')
         if i == 0:
             masterkey = self.pexpect.match.groups()[0].decode("utf-8")
-        self.pexpect.expect('Done')
+        self._expect('Done')
         return masterkey
 
     def set_masterkey(self, masterkey):
         cmd = 'masterkey ' + masterkey
         self.send_command(cmd)
-        self.pexpect.expect('Done')
+        self._expect('Done')
 
     def get_key_sequence_counter(self):
         self.send_command('keysequence counter')
-        i = self.pexpect.expect('(\d+)\r\n')
+        i = self._expect('(\d+)\r?\n')
         if i == 0:
             key_sequence_counter = int(self.pexpect.match.groups()[0])
-        self.pexpect.expect('Done')
+        self._expect('Done')
         return key_sequence_counter
 
     def set_key_sequence_counter(self, key_sequence_counter):
         cmd = 'keysequence counter %d' % key_sequence_counter
         self.send_command(cmd)
-        self.pexpect.expect('Done')
+        self._expect('Done')
 
     def set_key_switch_guardtime(self, key_switch_guardtime):
         cmd = 'keysequence guardtime %d' % key_switch_guardtime
         self.send_command(cmd)
-        self.pexpect.expect('Done')
+        self._expect('Done')
 
     def set_network_id_timeout(self, network_id_timeout):
         cmd = 'networkidtimeout %d' % network_id_timeout
         self.send_command(cmd)
-        self.pexpect.expect('Done')
+        self._expect('Done')
 
     def get_network_name(self):
         self.send_command('networkname')
         while True:
-            i = self.pexpect.expect(['Done', '(\S+)'])
+            i = self._expect(['Done', '(\S+)'])
             if i != 0:
                 network_name = self.pexpect.match.groups()[0].decode('utf-8')
             else:
@@ -306,103 +335,103 @@ class otCli:
     def set_network_name(self, network_name):
         cmd = 'networkname ' + network_name
         self.send_command(cmd)
-        self.pexpect.expect('Done')
+        self._expect('Done')
 
     def get_panid(self):
         self.send_command('panid')
-        i = self.pexpect.expect('([0-9a-fA-F]{4})')
+        i = self._expect('([0-9a-fA-F]{4})')
         if i == 0:
             panid = int(self.pexpect.match.groups()[0], 16)
-        self.pexpect.expect('Done')
+        self._expect('Done')
         return panid
 
     def set_panid(self, panid):
         cmd = 'panid %d' % panid
         self.send_command(cmd)
-        self.pexpect.expect('Done')
+        self._expect('Done')
 
     def get_partition_id(self):
         self.send_command('leaderpartitionid')
-        i = self.pexpect.expect('(\d+)\r\n')
+        i = self._expect('(\d+)\r?\n')
         if i == 0:
             weight = self.pexpect.match.groups()[0]
-        self.pexpect.expect('Done')
+        self._expect('Done')
         return weight
 
     def set_partition_id(self, partition_id):
         cmd = 'leaderpartitionid %d' % partition_id
         self.send_command(cmd)
-        self.pexpect.expect('Done')
+        self._expect('Done')
 
     def set_router_upgrade_threshold(self, threshold):
         cmd = 'routerupgradethreshold %d' % threshold
         self.send_command(cmd)
-        self.pexpect.expect('Done')
+        self._expect('Done')
 
     def set_router_downgrade_threshold(self, threshold):
         cmd = 'routerdowngradethreshold %d' % threshold
         self.send_command(cmd)
-        self.pexpect.expect('Done')
+        self._expect('Done')
 
     def release_router_id(self, router_id):
         cmd = 'releaserouterid %d' % router_id
         self.send_command(cmd)
-        self.pexpect.expect('Done')
+        self._expect('Done')
 
     def get_state(self):
         states = ['detached', 'child', 'router', 'leader']
         self.send_command('state')
-        match = self.pexpect.expect(states)
-        self.pexpect.expect('Done')
+        match = self._expect(states)
+        self._expect('Done')
         return states[match]
 
     def set_state(self, state):
         cmd = 'state ' + state
         self.send_command(cmd)
-        self.pexpect.expect('Done')
+        self._expect('Done')
 
     def get_timeout(self):
         self.send_command('childtimeout')
-        i = self.pexpect.expect('(\d+)\r\n')
+        i = self._expect('(\d+)\r?\n')
         if i == 0:
             timeout = self.pexpect.match.groups()[0]
-        self.pexpect.expect('Done')
+        self._expect('Done')
         return timeout
 
     def set_timeout(self, timeout):
         cmd = 'childtimeout %d' % timeout
         self.send_command(cmd)
-        self.pexpect.expect('Done')
+        self._expect('Done')
 
     def set_max_children(self, number):
         cmd = 'childmax %d' % number
         self.send_command(cmd)
-        self.pexpect.expect('Done')
+        self._expect('Done')
 
     def get_weight(self):
         self.send_command('leaderweight')
-        i = self.pexpect.expect('(\d+)\r\n')
+        i = self._expect('(\d+)\r?\n')
         if i == 0:
             weight = self.pexpect.match.groups()[0]
-        self.pexpect.expect('Done')
+        self._expect('Done')
         return weight
 
     def set_weight(self, weight):
         cmd = 'leaderweight %d' % weight
         self.send_command(cmd)
-        self.pexpect.expect('Done')
+        self._expect('Done')
 
     def add_ipaddr(self, ipaddr):
         cmd = 'ipaddr add ' + ipaddr
         self.send_command(cmd)
-        self.pexpect.expect('Done')
+        self._expect('Done')
 
     def get_addrs(self):
         addrs = []
         self.send_command('ipaddr')
 
         while True:
-            i = self.pexpect.expect(['(\S+:\S+)\r\n', 'Done'])
+            i = self._expect(['(\S+(:\S*)+)\r?\n', 'Done'])
             if i == 0:
                 addrs.append(self.pexpect.match.groups()[0].decode("utf-8"))
             elif i == 1:
@@ -426,7 +455,7 @@ class otCli:
         self.send_command('eidcache')
 
         while True:
-            i = self.pexpect.expect(['([a-fA-F0-9\:]+) ([a-fA-F0-9]+)\r\n', 'Done'])
+            i = self._expect(['([a-fA-F0-9\:]+) ([a-fA-F0-9]+)\r?\n', 'Done'])
             if i == 0:
                 eid = self.pexpect.match.groups()[0].decode("utf-8")
                 rloc = self.pexpect.match.groups()[1].decode("utf-8")
@@ -439,12 +468,12 @@ class otCli:
     def add_service(self, enterpriseNumber, serviceData, serverData):
         cmd = 'service add ' + enterpriseNumber + ' ' + serviceData+ ' '  + serverData
         self.send_command(cmd)
-        self.pexpect.expect('Done')
+        self._expect('Done')
 
     def remove_service(self, enterpriseNumber, serviceData):
         cmd = 'service remove ' + enterpriseNumber + ' ' + serviceData
         self.send_command(cmd)
-        self.pexpect.expect('Done')
+        self._expect('Done')
 
     def __getLinkLocalAddress(self):
         for ip6Addr in self.get_addrs():
@@ -515,40 +544,40 @@ class otCli:
 
     def get_context_reuse_delay(self):
         self.send_command('contextreusedelay')
-        i = self.pexpect.expect('(\d+)\r\n')
+        i = self._expect('(\d+)\r?\n')
         if i == 0:
             timeout = self.pexpect.match.groups()[0]
-        self.pexpect.expect('Done')
+        self._expect('Done')
         return timeout
 
     def set_context_reuse_delay(self, delay):
         cmd = 'contextreusedelay %d' % delay
         self.send_command(cmd)
-        self.pexpect.expect('Done')
+        self._expect('Done')
 
     def add_prefix(self, prefix, flags, prf = 'med'):
         cmd = 'prefix add ' + prefix + ' ' + flags + ' ' + prf
         self.send_command(cmd)
-        self.pexpect.expect('Done')
+        self._expect('Done')
 
     def remove_prefix(self, prefix):
         cmd = 'prefix remove ' + prefix
         self.send_command(cmd)
-        self.pexpect.expect('Done')
+        self._expect('Done')
 
     def add_route(self, prefix, prf = 'med'):
         cmd = 'route add ' + prefix + ' ' + prf
         self.send_command(cmd)
-        self.pexpect.expect('Done')
+        self._expect('Done')
 
     def remove_route(self, prefix):
         cmd = 'route remove ' + prefix
         self.send_command(cmd)
-        self.pexpect.expect('Done')
+        self._expect('Done')
 
     def register_netdata(self):
         self.send_command('netdataregister')
-        self.pexpect.expect('Done')
+        self._expect('Done')
 
     def energy_scan(self, mask, count, period, scan_duration, ipaddr):
         cmd = 'commissioner energy ' + str(mask) + ' ' + str(count) + ' ' + str(period) + ' ' + str(scan_duration) + ' ' + ipaddr
@@ -560,7 +589,7 @@ class otCli:
         else:
             timeout = 8
 
-        self.pexpect.expect('Energy:', timeout=timeout)
+        self._expect('Energy:', timeout=timeout)
 
     def panid_query(self, panid, mask, ipaddr):
         cmd = 'commissioner panid ' + str(panid) + ' ' + str(mask) + ' ' + ipaddr
@@ -572,14 +601,14 @@ class otCli:
         else:
             timeout = 8
 
-        self.pexpect.expect('Conflict:', timeout=timeout)
+        self._expect('Conflict:', timeout=timeout)
 
     def scan(self):
         self.send_command('scan')
 
         results = []
         while True:
-            i = self.pexpect.expect(['\|\s(\S+)\s+\|\s(\S+)\s+\|\s([0-9a-fA-F]{4})\s\|\s([0-9a-fA-F]{16})\s\|\s(\d+)\r\n',
+            i = self._expect(['\|\s(\S+)\s+\|\s(\S+)\s+\|\s([0-9a-fA-F]{4})\s\|\s([0-9a-fA-F]{16})\s\|\s(\d+)\r?\n',
                                         'Done'])
             if i == 0:
                 results.append(self.pexpect.match.groups())
@@ -595,11 +624,6 @@ class otCli:
 
         self.send_command(cmd)
 
-        try:
-            self.pexpect.expect('Done', timeout=0.01)
-        except pexpect.TIMEOUT:
-            pass
-
         if isinstance(self.simulator, simulator.VirtualTime):
             self.simulator.go(timeout)
 
@@ -607,87 +631,86 @@ class otCli:
         try:
             responders = {}
             while len(responders) < num_responses:
-                i = self.pexpect.expect(['from (\S+):'])
+                i = self._expect(['from (\S+):'])
                 if i == 0:
                     responders[self.pexpect.match.groups()[0]] = 1
-            self.pexpect.expect('\n')
-        except pexpect.TIMEOUT:
+            self._expect('\n')
+        except (pexpect.TIMEOUT, socket.timeout):
             result = False
+            if isinstance(self.simulator, simulator.VirtualTime):
+                self.simulator.sync_devices()
 
         return result
 
     def reset(self):
         self.send_command('reset')
-        try:
-            self.pexpect.expect('Done', timeout=0.01)
-        except pexpect.TIMEOUT:
-            pass
+        time.sleep(0.1)
 
     def set_router_selection_jitter(self, jitter):
         cmd = 'routerselectionjitter %d' % jitter
         self.send_command(cmd)
-        self.pexpect.expect('Done')
+        self._expect('Done')
 
     def set_active_dataset(self, timestamp, panid=None, channel=None, channel_mask=None, master_key=None):
         self.send_command('dataset clear')
-        self.pexpect.expect('Done')
+        self._expect('Done')
 
         cmd = 'dataset activetimestamp %d' % timestamp
         self.send_command(cmd)
-        self.pexpect.expect('Done')
+        self._expect('Done')
 
         if panid != None:
             cmd = 'dataset panid %d' % panid
             self.send_command(cmd)
-            self.pexpect.expect('Done')
+            self._expect('Done')
 
         if channel != None:
             cmd = 'dataset channel %d' % channel
             self.send_command(cmd)
-            self.pexpect.expect('Done')
+            self._expect('Done')
 
         if channel_mask != None:
             cmd = 'dataset channelmask %d' % channel_mask
             self.send_command(cmd)
-            self.pexpect.expect('Done')
+            self._expect('Done')
 
         if master_key != None:
             cmd = 'dataset masterkey ' + master_key
             self.send_command(cmd)
-            self.pexpect.expect('Done')
+            self._expect('Done')
 
         self.send_command('dataset commit active')
-        self.pexpect.expect('Done')
+        self._expect('Done')
 
     def set_pending_dataset(self, pendingtimestamp, activetimestamp, panid=None, channel=None):
         self.send_command('dataset clear')
-        self.pexpect.expect('Done')
+        self._expect('Done')
 
         cmd = 'dataset pendingtimestamp %d' % pendingtimestamp
         self.send_command(cmd)
-        self.pexpect.expect('Done')
+        self._expect('Done')
 
         cmd = 'dataset activetimestamp %d' % activetimestamp
         self.send_command(cmd)
-        self.pexpect.expect('Done')
+        self._expect('Done')
 
         if panid != None:
             cmd = 'dataset panid %d' % panid
             self.send_command(cmd)
-            self.pexpect.expect('Done')
+            self._expect('Done')
 
         if channel != None:
             cmd = 'dataset channel %d' % channel
             self.send_command(cmd)
-            self.pexpect.expect('Done')
+            self._expect('Done')
 
         self.send_command('dataset commit pending')
-        self.pexpect.expect('Done')
+        self._expect('Done')
 
     def announce_begin(self, mask, count, period, ipaddr):
         cmd = 'commissioner announce ' + str(mask) + ' ' + str(count) + ' ' + str(period) + ' ' + ipaddr
         self.send_command(cmd)
-        self.pexpect.expect('Done')
+        self._expect('Done')
 
     def send_mgmt_active_set(self, active_timestamp=None, channel=None, channel_mask=None, extended_panid=None,
                              panid=None, master_key=None, mesh_local=None, network_name=None, binary=None):
@@ -721,7 +744,7 @@ class otCli:
             cmd += 'binary ' + binary + ' '
 
         self.send_command(cmd)
-        self.pexpect.expect('Done')
+        self._expect('Done')
 
     def send_mgmt_pending_set(self, pending_timestamp=None, active_timestamp=None, delay_timer=None, channel=None,
                               panid=None, master_key=None, mesh_local=None, network_name=None):
@@ -751,4 +774,4 @@ class otCli:
             cmd += 'networkname ' + network_name + ' '
 
         self.send_command(cmd)
-        self.pexpect.expect('Done')
+        self._expect('Done')