Merge branch 'feature/test_idf_monitor' into 'master'

Test the IDF Monitor through sockets

See merge request idf/esp-idf!2556

.gitignore

@@ -43,6 +43,9 @@ tools/unit-test-app/build
 tools/unit-test-app/builds
 tools/unit-test-app/output
 
+# IDF monitor test
+tools/test_idf_monitor/outputs
+
 # AWS IoT Examples require device-specific certs/keys
 examples/protocols/aws_iot/*/main/certs/*.pem.*
 

.gitlab-ci.yml

@@ -328,6 +328,17 @@ test_build_system:
     - cd test_build_system
     - ${IDF_PATH}/tools/ci/test_build_system.sh
 
+test_idf_monitor:
+  <<: *host_test_template
+  artifacts:
+    when: on_failure
+    paths:
+      - tools/test_idf_monitor/outputs/*
+    expire_in: 1 week
+  script:
+    - cd ${IDF_PATH}/tools/test_idf_monitor
+    - ./run_test_idf_monitor.py
+
 test_esp_err_to_name_on_host:
   <<: *host_test_template
   script:

tools/ci/executable-list.txt

@@ -33,3 +33,4 @@ tools/kconfig/streamline_config.pl
 tools/kconfig/conf
 tools/kconfig/mconf
 tools/windows/eclipse_make.sh
+tools/test_idf_monitor/run_test_idf_monitor.py

tools/idf_monitor.py

@@ -135,10 +135,11 @@ class ConsoleReader(StoppableThread):
     """ Read input keys from the console and push them to the queue,
     until stopped.
     """
-    def __init__(self, console, event_queue):
+    def __init__(self, console, event_queue, test_mode):
         super(ConsoleReader, self).__init__()
         self.console = console
         self.event_queue = event_queue
+        self.test_mode = test_mode
 
     def run(self):
         self.console.setup()
@@ -155,6 +156,13 @@ def run(self):
                             time.sleep(0.1)
                         if not self.alive:
                             break
+                    elif self.test_mode:
+                        # In testing mode the stdin is connected to PTY but is not used for input anything. For PTY
+                        # the canceling by fcntl.ioctl isn't working and would hang in self.console.getkey().
+                        # Therefore, we avoid calling it.
+                        while self.alive:
+                            time.sleep(0.1)
+                        break
                     c = self.console.getkey()
                 except KeyboardInterrupt:
                     c = '\x03'
@@ -164,7 +172,7 @@ def run(self):
             self.console.cleanup()
 
     def _cancel(self):
-        if os.name == 'posix':
+        if os.name == 'posix' and not self.test_mode:
             # this is the way cancel() is implemented in pyserial 3.3 or newer,
             # older pyserial (3.1+) has cancellation implemented via 'select',
             # which does not work when console sends an escape sequence response
@@ -175,6 +183,8 @@ def _cancel(self):
             #
             # note that TIOCSTI is not implemented in WSL / bash-on-Windows.
             # TODO: introduce some workaround to make it work there.
+            #
+            # Note: This would throw exception in testing mode when the stdin is connected to PTY.
             import fcntl, termios
             fcntl.ioctl(self.console.fd, termios.TIOCSTI, b'\0')
 
@@ -265,6 +275,12 @@ def match(self, line):
         # We need something more than "*.N" for printing.
         return self._dict.get("*", self.LEVEL_N) > self.LEVEL_N
 
+class SerialStopException(Exception):
+    """
+    This exception is used for stopping the IDF monitor in testing mode.
+    """
+    pass
+
 class Monitor(object):
     """
     Monitor application main class.
@@ -293,8 +309,9 @@ def getkey_patched(self):
 
             self.console.getkey = types.MethodType(getkey_patched, self.console)
 
+        socket_mode = serial_instance.port.startswith("socket://") # testing hook - data from serial can make exit the monitor
         self.serial = serial_instance
-        self.console_reader = ConsoleReader(self.console, self.event_queue)
+        self.console_reader = ConsoleReader(self.console, self.event_queue, socket_mode)
         self.serial_reader = SerialReader(self.serial, self.event_queue)
         self.elf_file = elf_file
         self.make = make
@@ -317,6 +334,7 @@ def getkey_patched(self):
         self._invoke_processing_last_line_timer = None
         self._force_line_print = False
         self._output_enabled = True
+        self._serial_check_exit = socket_mode
 
     def invoke_processing_last_line(self):
         self.event_queue.put((TAG_SERIAL_FLUSH, b''), False)
@@ -344,6 +362,8 @@ def main_loop(self):
                     self.handle_serial_input(data, finalize_line=True)
                 else:
                     raise RuntimeError("Bad event data %r" % ((event_tag,data),))
+        except SerialStopException:
+            pass
         finally:
             try:
                 self.console_reader.stop()
@@ -384,6 +404,8 @@ def handle_serial_input(self, data, finalize_line=False):
             self._last_line_part = sp.pop()
         for line in sp:
             if line != b"":
+                if self._serial_check_exit and line == self.exit_key:
+                    raise SerialStopException()
                 if self._output_enabled and (self._force_line_print or self._line_matcher.match(line)):
                     self.console.write_bytes(line + b'\n')
                     self.handle_possible_pc_address_in_line(line)

tools/test_idf_monitor/README.md

@@ -0,0 +1,13 @@
+# Project for testing the IDF monitor
+
+Use `run_test_idf_monitor.py` in order to run the test.
+
+New tests can be added into `test_list` of `run_test_idf_monitor.py` and placing the corresponding files into the
+`tests` directory.
+
+Note: The `idf_monitor` is tested by a dummy ELF file which was generated by running the following commands::
+
+    dd if=/dev/zero of=tmp.bin bs=1 count=4
+    xtensa-esp32-elf-objcopy -I binary -O elf32-xtensa-le -B xtensa tmp.bin tmp.o
+    xtensa-esp32-elf-ld --defsym _start=0x40000000 tmp.o -o dummy.elf
+    chmod -x dummy.elf

tools/test_idf_monitor/run_test_idf_monitor.py

@@ -0,0 +1,119 @@
+#!/usr/bin/env python
+#
+# Copyright 2018 Espressif Systems (Shanghai) PTE LTD
+#
+# Licensed under the Apache License, Version 2.0 (the "License");
+# you may not use this file except in compliance with the License.
+# You may obtain a copy of the License at
+#
+#     http://www.apache.org/licenses/LICENSE-2.0
+#
+# Unless required by applicable law or agreed to in writing, software
+# distributed under the License is distributed on an "AS IS" BASIS,
+# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+# See the License for the specific language governing permissions and
+# limitations under the License.
+
+import os
+import signal
+import time
+import subprocess
+import pty
+
+test_list = (
+        # Add new tests here. All files should be placed in in_dir. Columns are:
+        # Input file            Filter string                                               File with expected output
+        ('in1.txt',             '',                                                         'in1f1.txt'),
+        ('in1.txt',             '*:V',                                                      'in1f1.txt'),
+        ('in1.txt',             'hello_world',                                              'in1f2.txt'),
+        ('in1.txt',             '*:N',                                                      'in1f3.txt'),
+        ('in2.txt',             'boot mdf_device_handle:I mesh:E vfs:I',                    'in2f1.txt'),
+        ('in2.txt',             'vfs',                                                      'in2f2.txt'),
+        )
+
+in_dir = 'tests/'       # tests are in this directory
+out_dir = 'outputs/'    # test results are written to this directory (kept only for debugging purposes)
+socat_in = './socatfile'# temporary socat file (deleted after run)
+monitor_error_output = out_dir + 'monitor_error_output'
+elf_file = './dummy.elf'  # ELF file used for starting the monitor
+idf_monitor = '{}/tools/idf_monitor.py'.format(os.getenv("IDF_PATH"))
+
+class SocatRunner:
+    """
+    Runs socat in the background for creating a socket.
+    """
+    def __enter__(self):
+        # Wait for a connection on port 2399 and then run "tail" which will send the file content to that port. Tail
+        # is used because it can start even when the file doesn't exists and remains running after the file has been
+        # processed. This way the idf_monitor can end the communication when it received the content. Using regular
+        # "cat" would invoke exception in idf_monitor.
+        # Note: "-c 1GB" option is used to force sending the whole file under the assumption that all testing files
+        # will be much smaller than 1G.
+        # Note: A temporary file socat_in is used in order to be able to start socat only once instead of for each test.
+        socat_cmd = ['socat',
+                '-U', # unidirectional pipe from file to port
+                'TCP4-LISTEN:2399,reuseaddr,fork',
+                'exec:"tail -c 1GB -F ' + socat_in + '"']
+        print ' '.join(socat_cmd)
+        self._socat_process = subprocess.Popen(socat_cmd, preexec_fn=os.setsid) # See __exit__ for os.setsid
+        return self
+
+    def __exit__(self, type, value, traceback):
+        # self._socat_process.terminate() doesn't enough because each connection to the port starts a new socat and a
+        # tail processes
+        os.killpg(os.getpgid(self._socat_process.pid), signal.SIGTERM)
+        # Note: this terminates all the processes but makes the script UNIX-only
+
+def cleanup():
+    try:
+        os.remove(socat_in)
+    except:
+        # ignore if the file doesn't exist
+        pass
+
+def main():
+    start = time.time()
+    cleanup() # avoid sending old content
+    if not os.path.exists(out_dir):
+        os.mkdir(out_dir)
+    try:
+        with SocatRunner():
+            # Sleep is necessary to make sure that socat is already listening. Only one sleep is used per run (this is
+            # another reason while the temporary socat_in file is used instead of directly reading the test files).
+            time.sleep(1)
+            for t in test_list:
+                print 'Running test on {} with filter "{}" and expecting {}'.format(t[0], t[1], t[2])
+                with open(in_dir + t[0], "r") as input_file, open(socat_in, "w") as socat_file:
+                    print 'cat {} > {}'.format(input_file.name, socat_file.name)
+                    for line in input_file:
+                        socat_file.write(line)
+                    idf_exit_sequence = b'\x1d\n'
+                    print 'echo "<exit>" >> {}'.format(socat_file.name)
+                    socat_file.write(idf_exit_sequence)
+                monitor_cmd = [idf_monitor,
+                        '--port', 'socket://localhost:2399',
+                        '--print_filter', t[1],
+                        elf_file]
+                with open(out_dir + t[2], "w") as mon_out_f, open(monitor_error_output, "w") as mon_err_f:
+                    try:
+                        (master_fd, slave_fd) = pty.openpty()
+                        print ' '.join(monitor_cmd),
+                        print ' > {} 2> {} < {}'.format(mon_out_f.name, mon_err_f.name, os.ttyname(slave_fd))
+                        proc = subprocess.Popen(monitor_cmd, stdin=slave_fd, stdout=mon_out_f, stderr=mon_err_f,
+                                close_fds=True)
+                        proc.wait()
+                    finally:
+                        os.close(slave_fd)
+                        os.close(master_fd)
+                diff_cmd = ['diff', in_dir + t[2], out_dir + t[2]]
+                print ' '.join(diff_cmd)
+                subprocess.check_call(diff_cmd)
+                print 'Test has passed'
+    finally:
+        cleanup()
+
+    end = time.time()
+    print 'Execution took {:.2f} seconds'.format(end - start)
+
+if __name__ == "__main__":
+    main()

tools/test_idf_monitor/tests/in1.txt

@@ -0,0 +1,91 @@
+ets Jun  8 2016 00:22:57
+
+rst:0x1 (POWERON_RESET),boot:0x33 (SPI_FAST_FLASH_BOOT)
+configsip: 0, SPIWP:0xee
+clk_drv:0x00,q_drv:0x00,d_drv:0x00,cs0_drv:0x00,hd_drv:0x00,wp_drv:0x00
+mode:DIO, clock div:2
+load:0x3fff0018,len:4
+load:0x3fff001c,len:5728
+ho 0 tail 12 room 4
+load:0x40078000,len:0
+load:0x40078000,len:14944
+entry 0x4007862c
+I (30) boot: ESP-IDF v3.1-dev-1320-gec1fb521b-dirty 2nd stage bootloader
+I (30) boot: compile time 09:31:02
+I (40) boot: Enabling RNG early entropy source...
+I (41) boot: SPI Speed      : 40MHz
+I (41) boot: SPI Mode       : DIO
+I (45) boot: SPI Flash Size : 4MB
+I (49) boot: Partition Table:
+I (53) boot: ## Label            Usage          Type ST Offset   Length
+I (60) boot:  0 nvs              WiFi data        01 02 00009000 00006000
+I (68) boot:  1 phy_init         RF data          01 01 0000f000 00001000
+I (75) boot:  2 factory          factory app      00 00 00010000 00100000
+I (83) boot: End of partition table
+I (87) esp_image: segment 0: paddr=0x00010020 vaddr=0x3f400020 size=0x058ac ( 22700) map
+I (104) esp_image: segment 1: paddr=0x000158d4 vaddr=0x3ffb0000 size=0x022a0 (  8864) load
+I (108) esp_image: segment 2: paddr=0x00017b7c vaddr=0x40080000 size=0x00400 (  1024) load
+0x40080000: _iram_start at /home/dragon/esp/esp-idf/components/freertos/xtensa_vectors.S:1685
+
+I (114) esp_image: segment 3: paddr=0x00017f84 vaddr=0x40080400 size=0x0808c ( 32908) load
+I (136) esp_image: segment 4: paddr=0x00020018 vaddr=0x400d0018 size=0x11e88 ( 73352) map
+0x400d0018: _flash_cache_start at ??:?
+
+I (162) esp_image: segment 5: paddr=0x00031ea8 vaddr=0x4008848c size=0x00670 (  1648) load
+0x4008848c: esp_rom_spiflash_program_page_internal at /home/dragon/esp/esp-idf/components/spi_flash/spi_flash_rom_patch.c:412
+
+I (163) esp_image: segment 6: paddr=0x00032520 vaddr=0x400c0000 size=0x00000 (     0) load
+I (174) boot: Loaded app from partition at offset 0x10000
+I (175) boot: Disabling RNG early entropy source...
+I (180) cpu_start: Pro cpu up.
+I (184) cpu_start: Starting app cpu, entry point is 0x40080e54
+0x40080e54: call_start_cpu1 at /home/dragon/esp/esp-idf/components/esp32/cpu_start.c:225
+
+I (0) cpu_start: App cpu up.
+I (195) heap_init: Initializing. RAM available for dynamic allocation:
+D (201) heap_init: New heap initialised at 0x3ffae6e0
+I (206) heap_init: At 3FFAE6E0 len 00001920 (6 KiB): DRAM
+D (212) heap_init: New heap initialised at 0x3ffb32f0
+I (218) heap_init: At 3FFB32F0 len 0002CD10 (179 KiB): DRAM
+I (224) heap_init: At 3FFE0440 len 00003BC0 (14 KiB): D/IRAM
+I (230) heap_init: At 3FFE4350 len 0001BCB0 (111 KiB): D/IRAM
+D (237) heap_init: New heap initialised at 0x40088afc
+I (242) heap_init: At 40088AFC len 00017504 (93 KiB): IRAM
+I (248) cpu_start: Pro cpu start user code
+D (260) clk: RTC_SLOW_CLK calibration value: 3181466
+D (269) intr_alloc: Connected src 46 to int 2 (cpu 0)
+D (270) intr_alloc: Connected src 57 to int 3 (cpu 0)
+D (271) intr_alloc: Connected src 24 to int 9 (cpu 0)
+I (276) cpu_start: Starting scheduler on PRO CPU.
+D (0) intr_alloc: Connected src 25 to int 2 (cpu 1)
+I (0) cpu_start: Starting scheduler on APP CPU.
+D (291) heap_init: New heap initialised at 0x3ffe0440
+D (301) heap_init: New heap initialised at 0x3ffe4350
+D (311) intr_alloc: Connected src 16 to int 12 (cpu 0)
+D (311) hello_world: debug1
+
+W (311) hello_world: warning1
+V (321) hello_world: verbose1
+E (321) hello_world: error1
+I (321) hello_world: info1
+
+regular printf
+D (331) another_world: another debug
+
+I (331) example: Periodic timer called, time since boot: 507065 us
+V (341) another_world: another verbose another very long
+W (341) another_world: another warning very long
+V (351) another_world: another verbose
+E (351) another_world: another error
+I (361) another_world: Register 0x40080000
+0x40080000: _iram_start at /home/dragon/esp/esp-idf/components/freertos/xtensa_vectors.S:1685
+
+D (361) hello_world: debug2
+W (371) hello_world: warning2
+
+V (371) hello_world: verbose2
+E (371) hello_world: error2
+I (381) hello_world: info2
+noeol 0x400800000x40080000: _iram_start at /home/dragon/esp/esp-idf/components/freertos/xtensa_vectors.S:1685
+
+