PS C:\test\oob\mbed-os> mbed test -m k64f -t arm --icetea -v [mbed] Working path "C:\test\oob\mbed-os" (program) [mbed] Auto-installing missing Python modules... [mbed] Exec "c:\python27\python.exe -u C:\test\oob\mbed-os\tools\run_icetea.py -m k64f -t arm -v --application-list" in "C:\test\oob\mbed-os" [mbed] Exec "c:\python27\python.exe -u C:\test\oob\mbed-os\tools\test.py -t arm -m k64f --source . --build .\BUILD\tests\K64F\ARM --test-spec .\BUILD\tests\K64F\ARM\test_spec.json --build-data .\BUILD\tests\K64F\ARM\build_data.json -n TEST_APPS-device-socket_app,TEST_APPS-device-exampleapp -v --icet ea" in "C:\test\oob\mbed-os" Building library mbed-build (K64F, ARM) Scan: mbed-os Macros: -DCOMPONENT_SD=1 -DDEVICE_EMAC=1 -D__MBED__=1 -DDEVICE_I2CSLAVE=1 -D__FPU_PRESENT=1 -DTARGET_Freescale -DDEVICE_PORTINOUT=1 -DTARGET_RTOS_M4_M7 -DDEVICE_RTC=1 -DMBED_BUILD_TIMESTAMP=1536296941.54 -D__CMSIS_RTOS -DFSL_RTOS_MBED -DDEVICE_STORAGE=1 -DTARGET_KPSDK_MCUS -DDEVICE_USTICKER=1 -DDEVI CE_CRC=1 -DTARGET_CORTEX_M -DTARGET_KSDK2_MCUS -DTARGET_LIKE_CORTEX_M4 -DDEVICE_ANALOGOUT=1 -DTARGET_M4 -DTARGET_K64F -DDEVICE_SPI_ASYNCH=1 -DDEVICE_LPTICKER=1 -DDEVICE_PWMOUT=1 -DDEVICE_INTERRUPTIN=1 -DTARGET_Freescale_EMAC -DTARGET_CORTEX -DDEVICE_I2C=1 -DDEVICE_PORTOUT=1 -D__CORTEX_M4 -DDEVICE_ST DIO_MESSAGES=1 -DCPU_MK64FN1M0VMD12 -DTARGET_LIKE_MBED -DTARGET_FF_ARDUINO -DTARGET_KPSDK_CODE -DTARGET_RELEASE -DDEVICE_SERIAL_FC=1 -DFEATURE_STORAGE=1 -DDEVICE_TRNG=1 -D__MBED_CMSIS_RTOS_CM -DDEVICE_SLEEP=1 -DTARGET_FRDM -DTARGET_MCUXpresso_MCUS -DDEVICE_SPI=1 -DTOOLCHAIN_ARM_STD -DDEVICE_SPISLAVE =1 -DDEVICE_ANALOGIN=1 -DDEVICE_SERIAL=1 -DDEVICE_SERIAL_ASYNCH=1 -DDEVICE_FLASH=1 -DDEVICE_PORTIN=1 -DTOOLCHAIN_ARM -DTARGET_MCU_K64F -DARM_MATH_CM4 Building project exampleapp (K64F, ARM) Scan: ARM Scan: exampleapp Macros: -DCOMPONENT_SD=1 -DDEVICE_EMAC=1 -D__MBED__=1 -DDEVICE_I2CSLAVE=1 -D__FPU_PRESENT=1 -DTARGET_Freescale -DDEVICE_PORTINOUT=1 -DTARGET_RTOS_M4_M7 -DDEVICE_RTC=1 -DDEVICE_SERIAL_ASYNCH=1 -D__CMSIS_RTOS -DFSL_RTOS_MBED -DDEVICE_STORAGE=1 -DTARGET_KPSDK_MCUS -DDEVICE_USTICKER=1 -DDEVICE_CRC=1 -DT ARGET_CORTEX_M -DTARGET_KSDK2_MCUS -DTARGET_LIKE_CORTEX_M4 -DDEVICE_ANALOGOUT=1 -DTARGET_M4 -DTARGET_K64F -DDEVICE_SPI_ASYNCH=1 -DDEVICE_LPTICKER=1 -DDEVICE_PWMOUT=1 -DDEVICE_INTERRUPTIN=1 -DTARGET_Freescale_EMAC -DTARGET_CORTEX -DDEVICE_I2C=1 -DDEVICE_PORTOUT=1 -D__CORTEX_M4 -DMBED_BUILD_TIMESTAMP= 1536296943.77 -DDEVICE_STDIO_MESSAGES=1 -DCPU_MK64FN1M0VMD12 -DTARGET_LIKE_MBED -DTARGET_FF_ARDUINO -DTARGET_KPSDK_CODE -DTARGET_RELEASE -DDEVICE_SERIAL_FC=1 -DFEATURE_STORAGE=1 -DDEVICE_TRNG=1 -D__MBED_CMSIS_RTOS_CM -DDEVICE_SLEEP=1 -DTARGET_FRDM -DTARGET_MCUXpresso_MCUS -DDEVICE_SPI=1 -DTOOLCHAIN_ ARM_STD -DDEVICE_SPISLAVE=1 -DDEVICE_ANALOGIN=1 -DDEVICE_SERIAL=1 -DDEVICE_FLASH=1 -DDEVICE_PORTIN=1 -DTOOLCHAIN_ARM -DTARGET_MCU_K64F -DARM_MATH_CM4 Compile [100.0%]: main.cpp Compile: C:\armcc5\bin\armcc -c --gnu -Otime --split_sections --apcs=interwork --brief_diagnostics --restrict --multibyte_chars -O3 --cpu=Cortex-M4.fp --md --no_depend_system_headers --c99 -D__ASSERT_MSG --cpp --no_rtti --no_vla -DMBED_ROM_START=0x0 -DMBED_ROM_SIZE=0x100000 -DCOMPONENT_SD=1 -DDEVICE _EMAC=1 -D__MBED__=1 -DDEVICE_I2CSLAVE=1 -D__FPU_PRESENT=1 -DTARGET_Freescale -DDEVICE_PORTINOUT=1 -DTARGET_RTOS_M4_M7 -DDEVICE_RTC=1 -DDEVICE_SERIAL_ASYNCH=1 -D__CMSIS_RTOS -DFSL_RTOS_MBED -DDEVICE_STORAGE=1 -DTARGET_KPSDK_MCUS -DDEVICE_USTICKER=1 -DDEVICE_CRC=1 -DTARGET_CORTEX_M -DTARGET_KSDK2_MCU S -DTARGET_LIKE_CORTEX_M4 -DDEVICE_ANALOGOUT=1 -DTARGET_M4 -DTARGET_K64F -DDEVICE_SPI_ASYNCH=1 -DDEVICE_LPTICKER=1 -DDEVICE_PWMOUT=1 -DDEVICE_INTERRUPTIN=1 -DTARGET_Freescale_EMAC -DTARGET_CORTEX -DDEVICE_I2C=1 -DDEVICE_PORTOUT=1 -D__CORTEX_M4 -DMBED_BUILD_TIMESTAMP=1536296943.77 -DDEVICE_STDIO_MESS AGES=1 -DCPU_MK64FN1M0VMD12 -DTARGET_LIKE_MBED -DTARGET_FF_ARDUINO -DTARGET_KPSDK_CODE -DTARGET_RELEASE -DDEVICE_SERIAL_FC=1 -DFEATURE_STORAGE=1 -DDEVICE_TRNG=1 -D__MBED_CMSIS_RTOS_CM -DDEVICE_SLEEP=1 -DTARGET_FRDM -DTARGET_MCUXpresso_MCUS -DDEVICE_SPI=1 -DTOOLCHAIN_ARM_STD -DDEVICE_SPISLAVE=1 -DDEV ICE_ANALOGIN=1 -DDEVICE_SERIAL=1 -DDEVICE_FLASH=1 -DDEVICE_PORTIN=1 -DTOOLCHAIN_ARM -DTARGET_MCU_K64F -DARM_MATH_CM4 --preinclude=.\BUILD\tests\K64F\ARM\.\TEST_APPS\device\exampleapp\mbed_config.h --via .\BUILD\tests\K64F\ARM\.\TEST_APPS\device\exampleapp\.includes_895b2ab81b63f7802dcdfbd091e92739.t xt --depend BUILD\tests\K64F\ARM\TEST_APPS\device\exampleapp\TEST_APPS\device\exampleapp\main.d -o BUILD\tests\K64F\ARM\TEST_APPS\device\exampleapp\TEST_APPS\device\exampleapp\main.o .\TEST_APPS\device\exampleapp\main.cpp [Error] main.cpp@22,0: #35: #error directive: [NOT_SUPPORTED] Skipping example application. [DEBUG] Return: 1 [DEBUG] Output: ".\TEST_APPS\device\exampleapp\main.cpp", line 22: Error: #35: #error directive: [NOT_SUPPORTED] Skipping example application. [DEBUG] Output: .\TEST_APPS\device\exampleapp\main.cpp: 0 warnings, 1 error Building project socket_app (K64F, ARM) Scan: ARM Scan: socket_app Macros: -DCOMPONENT_SD=1 -DDEVICE_EMAC=1 -D__MBED__=1 -DDEVICE_I2CSLAVE=1 -D__FPU_PRESENT=1 -DTARGET_Freescale -DDEVICE_PORTINOUT=1 -DTARGET_RTOS_M4_M7 -DDEVICE_RTC=1 -DDEVICE_SERIAL_ASYNCH=1 -D__CMSIS_RTOS -DFSL_RTOS_MBED -DDEVICE_STORAGE=1 -DTARGET_KPSDK_MCUS -DDEVICE_USTICKER=1 -DDEVICE_CRC=1 -DT ARGET_CORTEX_M -DTARGET_KSDK2_MCUS -DTARGET_LIKE_CORTEX_M4 -DDEVICE_ANALOGOUT=1 -DTARGET_M4 -DTARGET_K64F -DDEVICE_SPI_ASYNCH=1 -DDEVICE_LPTICKER=1 -DDEVICE_PWMOUT=1 -DDEVICE_INTERRUPTIN=1 -DTARGET_Freescale_EMAC -DTARGET_CORTEX -DDEVICE_I2C=1 -DDEVICE_PORTOUT=1 -D__CORTEX_M4 -DDEVICE_STDIO_MESSAGES =1 -DCPU_MK64FN1M0VMD12 -DTARGET_LIKE_MBED -DTARGET_FF_ARDUINO -DTARGET_KPSDK_CODE -DTARGET_RELEASE -DDEVICE_SERIAL_FC=1 -DFEATURE_STORAGE=1 -DDEVICE_TRNG=1 -D__MBED_CMSIS_RTOS_CM -DDEVICE_SLEEP=1 -DMBED_BUILD_TIMESTAMP=1536296944.1 -DTARGET_FRDM -DTARGET_MCUXpresso_MCUS -DDEVICE_SPI=1 -DTOOLCHAIN_A RM_STD -DDEVICE_SPISLAVE=1 -DDEVICE_ANALOGIN=1 -DDEVICE_SERIAL=1 -DDEVICE_FLASH=1 -DDEVICE_PORTIN=1 -DTOOLCHAIN_ARM -DTARGET_MCU_K64F -DARM_MATH_CM4 Link: socket_app Link: C:\armcc5\bin\armlink --via .\BUILD\tests\K64F\ARM\.\TEST_APPS\device\socket_app\.link_options.txt [DEBUG] Return: 0 [DEBUG] Errors: "C:\Users\toywat01\AppData\Local\Temp\p1900-3", line 124 (column 3): Warning: L6312W: Empty Execution region description for region RW_IRAM1 [DEBUG] Errors: Finished: 0 information, 1 warning and 0 error messages. Elf2Bin: socket_app FromELF: C:\armcc5\bin\fromelf --bin -o .\BUILD\tests\K64F\ARM\.\TEST_APPS\device\socket_app\socket_app.bin .\BUILD\tests\K64F\ARM\.\TEST_APPS\device\socket_app\socket_app.elf [DEBUG] Return: 0 +---------------------------------+------------+----------+-----------+ | Module | .text | .data | .bss | +---------------------------------+------------+----------+-----------+ | TEST_APPS\device | 11214(+0) | 24(+0) | 1256(+0) | | [lib]\c_w.l | 20980(+0) | 48(+0) | 618(+0) | | [lib]\cpp_ws.l | 5096(+0) | 55(+0) | 40(+0) | | [lib]\cpprt_w.l | 525(+0) | 0(+0) | 0(+0) | | [lib]\fz_wm.l | 1296(+0) | 0(+0) | 0(+0) | | [lib]\m_wm.l | 746(+0) | 0(+0) | 0(+0) | | anon$$obj.o | 32(+0) | 0(+0) | 1024(+0) | | components\storage | 46(+0) | 0(+0) | 0(+0) | | components\wifi | 10(+0) | 0(+0) | 0(+0) | | drivers\FlashIAP.o | 84(+0) | 0(+0) | 0(+0) | | drivers\InterruptIn.o | 33(+0) | 0(+0) | 0(+0) | | drivers\SerialBase.o | 1090(+0) | 0(+0) | 0(+0) | | drivers\UARTSerial.o | 1976(+0) | 0(+0) | 0(+0) | | events\EventQueue.o | 66(+0) | 0(+0) | 0(+0) | | events\equeue | 1386(+0) | 0(+0) | 0(+0) | | events\mbed_shared_queues.o | 405(+0) | 8(+0) | 1564(+0) | | features\cellular | 52(+0) | 0(+0) | 0(+0) | | features\frameworks | 8795(+0) | 0(+0) | 2140(+0) | | features\lwipstack | 46573(+0) | 247(+0) | 44587(+0) | | features\mbedtls | 38(+0) | 0(+0) | 0(+0) | | features\nanostack | 26(+0) | 0(+0) | 0(+0) | | features\netsocket | 10412(+0) | 116(+0) | 648(+0) | | features\storage | 30(+0) | 0(+0) | 184(+0) | | hal\mbed_critical_section_api.o | 144(+0) | 2(+0) | 0(+0) | | hal\mbed_gpio.o | 94(+0) | 0(+0) | 0(+0) | | hal\mbed_pinmap_common.o | 276(+0) | 0(+0) | 0(+0) | | hal\mbed_sleep_manager.o | 228(+0) | 24(+0) | 0(+0) | | hal\mbed_ticker_api.o | 1058(+0) | 0(+0) | 0(+0) | | hal\mbed_us_ticker_api.o | 72(+0) | 4(+0) | 64(+0) | | platform\FileBase.o | 164(+0) | 4(+0) | 40(+0) | | platform\FileHandle.o | 52(+0) | 0(+0) | 0(+0) | | platform\FilePath.o | 212(+0) | 0(+0) | 0(+0) | | platform\mbed_alloc_wrappers.o | 12(+0) | 0(+0) | 0(+0) | | platform\mbed_assert.o | 84(+0) | 0(+0) | 0(+0) | | platform\mbed_board.o | 182(+0) | 0(+0) | 0(+0) | | platform\mbed_critical.o | 216(+0) | 4(+0) | 0(+0) | | platform\mbed_error.o | 920(+0) | 12(+0) | 104(+0) | | platform\mbed_retarget.o | 1714(+0) | 80(+0) | 372(+0) | | platform\mbed_wait_api_rtos.o | 68(+0) | 0(+0) | 0(+0) | | rtos\EventFlags.o | 226(+0) | 0(+0) | 0(+0) | | rtos\Kernel.o | 44(+0) | 8(+0) | 0(+0) | | rtos\Mutex.o | 350(+0) | 0(+0) | 0(+0) | | rtos\Semaphore.o | 300(+0) | 0(+0) | 0(+0) | | rtos\TARGET_CORTEX | 14601(+0) | 2294(+0) | 4588(+0) | | rtos\ThisThread.o | 236(+0) | 0(+0) | 0(+0) | | rtos\Thread.o | 1290(+0) | 0(+0) | 0(+0) | | targets\TARGET_Freescale | 15057(+0) | 105(+0) | 324(+0) | | Subtotals | 148511(+0) | 3035(+0) | 57553(+0) | +---------------------------------+------------+----------+-----------+ Total Static RAM memory (data + bss): 60588(+0) bytes Total Flash memory (text + data): 151546(+0) bytes Image: BUILD/tests/K64F/ARM/TEST_APPS/device/socket_app/socket_app.bin Memory map breakdown for built projects (values in Bytes): +------------+--------+-----------+------------+-------------+ | name | target | toolchain | static_ram | total_flash | +------------+--------+-----------+------------+-------------+ | socket_app | K64F | ARM | 60588 | 151546 | +------------+--------+-----------+------------+-------------+ Build successes: * K64F::ARM::MBED-BUILD * K64F::ARM::TEST_APPS-DEVICE-SOCKET_APP Build skips: * K64F::ARM::TEST_APPS-DEVICE-EXAMPLEAPP [mbed] Exec "c:\python27\python.exe -u C:\test\oob\mbed-os\tools\run_icetea.py -m k64f -t arm -v --build-data .\BUILD\tests\K64F\ARM\build_data.json --test-suite .\BUILD\tests\K64F\ARM\test_suite.json" in "C:\test\oob\mbed-os" 14:09:13.759 Registering execution wide plugins: 14:09:13.759 Registering plugin LocalAllocator 14:09:13.762 Execution wide plugins loaded and registered. 14:09:13.769 Using Icetea version 1.0.1 14:09:13.769 Generating suite from command line. 14:09:13.773 Importing testcases for filtering 14:09:13.801 Filtering testcases 14:09:13.802 Suite creation complete. 14:09:13.825 Test cases prepared. +-------+--------------------------------+----------+-------+---------+---------------------+--------------------------+---------+-------------------+ | Index | Name | Status | Type | Subtype | Group | Component | Feature | Allowed platforms | +-------+--------------------------------+----------+-------+---------+---------------------+--------------------------+---------+-------------------+ | 1 | test_cmdline | released | smoke | | testcases\example | ['cmdline'] | | | | 2 | UDPSOCKET_BIND_PORT | released | smoke | socket | testcases\netsocket | ['mbed-os', 'netsocket'] | | | | 3 | TCPSOCKET_BIND_PORT | released | smoke | socket | testcases\netsocket | ['mbed-os', 'netsocket'] | | | | 4 | TCPSERVER_ACCEPT | released | smoke | socket | testcases\netsocket | ['mbed-os', 'netsocket'] | | | | 5 | TCPSOCKET_ECHOTEST_BURST_SHORT | released | smoke | socket | testcases\netsocket | ['mbed-os', 'netsocket'] | | | +-------+--------------------------------+----------+-------+---------+---------------------+--------------------------+---------+-------------------+ cleaning up Icetea log directory. 14:09:14.285 Registering execution wide plugins: 14:09:14.286 Registering plugin LocalAllocator 14:09:14.288 Execution wide plugins loaded and registered. 14:09:14.295 Using Icetea version 1.0.1 14:09:14.296 Loading suite from file 14:09:14.299 Importing testcases for filtering 14:09:14.326 Filtering testcases 14:09:14.326 Suite creation complete. 14:09:14.355 Test cases prepared. 14:09:14.355 Starting suite. 14:09:14.357 Test suite repeats: 1 14:09:14.361 Starting repeat 1 of 1 14:09:14.367 Starting next test case: test_cmdline 14:09:14.371 Iteration 1 of 1 14:09:14.375 Test case retries: 0 14:09:14.381 Starting test case run. 14:09:14.384 Starting test case test_cmdline 14:09:14.388 TC 'test_cmdline' will be skipped because of 'Test requiring application binary not build' detect GIT info by folder: 'C:\test\oob\mbed-os\TEST_APPS' all git_info: {'commitid': '3fb5781af180c32a6062f050d59cdf93654b3e9f', 'scm': 'unknown', 'git_path': 'TEST_APPS', 'scm_path': 'unknown', 'scm_link': '', 'branch': 'HEAD', 'url': 'https://github.com/ARMmbed/mbed-os/', 'scm_group': 'unknown'} 14:09:14.770 Skipping test case test_cmdline 14:09:14.772 Test case test_cmdline skipped. 14:09:14.773 Starting next test case: UDPSOCKET_BIND_PORT 14:09:14.778 Iteration 1 of 1 14:09:14.782 Test case retries: 0 14:09:14.786 Starting test case run. 14:09:14.792 Starting test case UDPSOCKET_BIND_PORT 14:09:14.801 14:09:14.802 START TEST CASE EXECUTION: 'UDPSOCKET_BIND_PORT' 14:09:14.805 14:09:14.812 | TC MainThread: Start Test case 'UDPSOCKET_BIND_PORT' 14:09:14.815 | TC MainThread: Environment configurations: 14:09:14.819 | TC MainThread: {'extApps': {'kittyExe': 'C:\\Program Files (x86)\\PuTTY\\kitty.exe', 'puttyExe': 'C:\\Program Files (x86)\\PuTTY\\putty.exe'}, 'sniffer': {'iface': 'Sniffer'}} 14:09:14.823 | TC MainThread: TC configurations: 14:09:14.828 | TC MainThread: {'compatible': {'automation': {'value': True}, 'framework': {'name': 'Icetea', 'version': '>=1.0.0-rc1'}, 'hw': {'value': True}}, 'component': ['mbed-os', 'netsocket'], 'name': 'UDPSOCKET_BIND_PORT', 'purpose': 'Verify UDPSocket can be created, opened and port binded', 'requirements': {'duts': {'*': {'application': {'bin': u'.\\BUILD\\tests\\K64F\\ARM\\.\\TEST_APPS\\device\\socket_app\\socket_app.bin', 'name': u'TEST_APPS-device-socket_app'}, 'count': 1, 'type': u'hardware'}, '1': {'nick': u'dut1'}}, 'external': {'apps': []}}, 'status': 'released', 'sub_type': None, 'subtype': 'socket', 'title': 'udpsocket open and bind port', 'type': 'smoke'} 14:09:14.835 | TC MainThread: ====setUpTestBench==== 14:09:14.842 | TC MainThread: Configurations seems to be ok 14:09:14.855 | TC MainThread: Registering plugin FileApi 14:09:14.859 | TC MainThread: Registering plugin AssertPlugin 14:09:14.865 | TC MainThread: Registering plugin default_parsers 14:09:14.869 | TC MainThread: Registering plugin HttpApi 14:09:14.875 | TC MainThread: Registering plugin ip_test_parsers 14:09:14.881 | TC MainThread: ====setUpTestBench==== 14:09:14.884 | TC MainThread: --------------------- 14:09:14.888 | TC MainThread: Initialize DUT's connections 14:09:14.892 | RSP MainThread: Using allocator LocalAllocator 14:09:14.898 | RSP MainThread: Allocating duts with the following configurations: 14:09:14.903 | RSP MainThread: {'allowed_platforms': [], 'nick': u'dut1', 'type': u'hardware', 'application': {'bin': u'.\\BUILD\\tests\\K64F\\ARM\\.\\TEST_APPS\\device\\socket_app\\socket_app.bin', 'name': u'TEST_APPS-device-socket_app'}} 14:09:14.905 | RSP MainThread: Allocating 1 duts. 14:09:14.971 | LAL MainThread: Allocated device 0240000028884e450057700f6bf000108021000097969900 14:09:14.973 | RSP MainThread: Allocation successful 14:09:14.982 | D1 Thread-13: Flashing dev: 0240000028884e450057700f6bf000108021000097969900 14:09:14.983 | FLS Thread-13: [{'target_id_mbed_htm': u'0240000028884e450057700f6bf000108021000097969900', 'mount_point': 'E:', 'product_id': u'0204', 'vendor_id': u'0d28', 'target_id': u'0240000028884e450057700f6bf000108021000097969900', 'serial_port': u'COM15', 'target_id_usb_id': u'0240000028 884e450057700f6bf000108021000097969900', 'platform_name': u'K64F', 'state': 'allocated', 'directory_entries': ['MBED.HTM', 'DETAILS.TXT'], 'device_type': 'daplink'}] 14:09:14.983 | FLS Thread-13: Flashing: 0240000028884e450057700f6bf000108021000097969900 14:09:15.028 | FLS Thread-13: sendBreak to device to reboot 14:09:15.278 | FLS Thread-13: reset completed 14:09:15.395 | FLS Thread-13: read source file 14:09:15.395 | FLS Thread-13: SHA1: 7fc4990b744857e7e10580a9ec6ae92cd22aeab8 14:09:15.397 | FLS Thread-13: copying file: ".\BUILD\tests\K64F\ARM\.\TEST_APPS\device\socket_app\socket_app.bin" to "E:\socket_app.bin" 1 file(s) copied. 14:09:23.342 | FLS Thread-13: copy finished 14:09:27.444 | FLS Thread-13: sendBreak to device to reboot 14:09:27.694 | FLS Thread-13: reset completed 14:09:28.112 | FLS Thread-13: verifying flash 14:09:28.115 | FLS Thread-13: ready 14:09:28.117 | FLS Thread-13: 0240000028884e450057700f6bf000108021000097969900 flash success 14:09:28.119 | TC Thread-13: flash ready 14:09:28.124 | TC Thread-13: Use board K64F as "D1" (id: 0240000028884e450057700f6bf000108021000097969900) 14:09:28.178 | TC MainThread: Allocated following duts: 14:09:28.180 | D1 MainThread: DutSerial COM15 14:09:28.180 | D1 MainThread: Configuration for this DUT: {'allowed_platforms': [], 'nick': u'dut1', 'allocated': {'target_id_mbed_htm': u'0240000028884e450057700f6bf000108021000097969900', 'mount_point': 'E:', 'product_id': u'0204', 'vendor_id': u'0d28', 'target_id': u'0240000028884e450057700f6bf000108021000097969900', 'serial_port': u'COM15', 'target_id _usb_id': u'0240000028884e450057700f6bf000108021000097969900', 'platform_name': u'K64F', 'state': 'allocated', 'directory_entries': ['MBED.HTM', 'DETAILS.TXT'], 'device_type': 'daplink'}, 'type': u'hardware', 'application': {'bin': u'.\\BUILD\\tests\\K64F\\ARM\\.\\TEST_APPS\\device\\socket_app\\sock et_app.bin', 'name': u'TEST_APPS-device-socket_app'}} +----------+--------------+ | COM port | Location | +----------+--------------+ | COM15 | X = 0, Y = 0 | +----------+--------------+ 14:09:28.203 | <-> DutThread: Start DUT communication 14:09:28.203 | D1 <-> MainThread: Open Connection for 'D1' using 'COM15' baudrate: 115200 14:09:28.213 | D1 <-> MainThread: Use normal serial write mode 14:09:28.217 | TC MainThread: Waiting for dut 1 to initialize. 14:09:28.217 | TC MainThread: Cli initialized. 14:09:28.221 | D1 <-> MainThread: CMD set --retcode true, timeout=1536297018, time=1536296968 14:09:28.226 | D1 --> DutThread: set --retcode true />set --retcode true DutThread: />s 14:09:28.286 | D1 <-- DutThread: retcode: 0 14:09:28.288 | D1 <-> DutThread: Got response 14:09:28.289 | D1 <-> MainThread: CMD echo off, timeout=1536297018, time=1536296968 14:09:28.293 | D1 --> DutThread: echo off />echo off 6 | D1 <-- DutThread: /> 14:09:28.336 | D1 <-- DutThread: ECHO is off 14:09:28.346 | D1 <-- DutThread: retcode: 0 14:09:28.348 | D1 <-> DutThread: Got response 14:09:28.357 | D1 <-> MainThread: CMD set --vt100 off, timeout=1536297018, time=1536296968 14:09:28.358 | D1 --> DutThread: set --vt100 off 14:09:28.367 | D1 <-- DutThread: retcode: 0 14:09:28.368 | D1 <-> DutThread: Got response 14:09:28.372 | D1 <-> MainThread: CMD set dut "COM15", timeout=1536297018, time=1536296968 14:09:28.374 | D1 --> DutThread: set dut "COM15" 14:09:28.387 | D1 <-- DutThread: retcode: 0 14:09:28.388 | D1 <-> DutThread: Got response 14:09:28.388 | D1 <-> MainThread: CMD set testcase "", timeout=1536297018, time=1536296968 14:09:28.394 | D1 --> DutThread: set testcase "" 14:09:28.417 | D1 <-- DutThread: retcode: 0 14:09:28.417 | D1 <-> DutThread: Got response 14:09:28.424 | TC MainThread: DUT[0]: COM15 14:09:28.426 | TC MainThread: Initialized 1 dut for this testcase. 14:09:28.428 | TC MainThread: Skip Sniffing NW data 14:09:28.433 | TC MainThread: ------TC SET UP--------- 14:09:28.437 | D1 <-> MainThread: CMD ifup, timeout=1536297018, time=1536296968 14:09:28.441 | D1 --> DutThread: ifup 14:09:29.441 | D1 MainThread: Waiting for response... timeout=48 14:09:30.443 | D1 MainThread: Waiting for response... timeout=47 14:09:31.444 | D1 MainThread: Waiting for response... timeout=46 14:09:32.444 | D1 MainThread: Waiting for response... timeout=45 14:09:32.457 | D1 <-- DutThread: IPv4 if addr: 10.128.4.56 14:09:32.467 | D1 <-- DutThread: MAC-48: 86:47:c6:a7:b9:c6 14:09:32.486 | D1 <-- DutThread: retcode: 0 14:09:32.487 | D1 <-> DutThread: Got response 14:09:32.506 | TC MainThread: {'MAC': u'86:47:c6:a7:b9:c6', 'address': {'ll': '', 'globals': [], 'ipv4': u'10.128.4.56', 'ipv6': []}} 14:09:32.507 | TC MainThread: ------TC START--------- 14:09:32.509 | D1 <-> MainThread: CMD socket new UDPSocket, timeout=1536297022, time=1536296972 14:09:32.515 | D1 --> DutThread: socket new UDPSocket 14:09:32.536 | D1 <-- DutThread: new socket. sid: 0 14:09:32.546 | D1 <-- DutThread: retcode: 0 14:09:32.548 | D1 <-> DutThread: Got response 14:09:32.578 | TC MainThread: {'data_type': None, 'sent_bytes': None, 'address': None, 'socket_id': u'0', 'loop_id': None, 'printed_bytes': None, 'received_bytes': None, 'data': '', 'port': None} 14:09:32.579 | D1 <-> MainThread: CMD socket 0 open, timeout=1536297022, time=1536296972 14:09:32.581 | D1 --> DutThread: socket 0 open 14:09:32.596 | D1 <-- DutThread: retcode: 0 14:09:32.598 | D1 <-> DutThread: Got response 14:09:32.611 | TC MainThread: {'data_type': None, 'sent_bytes': None, 'address': None, 'socket_id': None, 'loop_id': None, 'printed_bytes': None, 'received_bytes': None, 'data': '', 'port': None} 14:09:32.612 | D1 <-> MainThread: CMD socket 0 bind port 1024, timeout=1536297022, time=1536296972 14:09:32.614 | D1 --> DutThread: socket 0 bind port 1024 14:09:32.627 | D1 <-- DutThread: Socket::bind(1024) 14:09:32.637 | D1 <-- DutThread: retcode: 0 14:09:32.638 | D1 <-> DutThread: Got response 14:09:32.644 | TC MainThread: {'data_type': None, 'sent_bytes': None, 'address': None, 'socket_id': None, 'loop_id': None, 'printed_bytes': None, 'received_bytes': None, 'data': '', 'port': None} 14:09:32.645 | D1 <-> MainThread: CMD socket 0 delete, timeout=1536297022, time=1536296972 14:09:32.648 | D1 --> DutThread: socket 0 delete 14:09:32.677 | D1 <-- DutThread: retcode: 0 14:09:32.677 | D1 <-> DutThread: Got response 14:09:32.680 | TC MainThread: {'data_type': None, 'sent_bytes': None, 'address': None, 'socket_id': None, 'loop_id': None, 'printed_bytes': None, 'received_bytes': None, 'data': '', 'port': None} 14:09:32.684 | TC MainThread: -----------TC END----------- 14:09:32.687 | TC MainThread: TC PASS 14:09:32.691 | TC MainThread: ====TC TEAR DOWN==== 14:09:32.697 | D1 <-> MainThread: CMD ifdown, timeout=1536297022, time=1536296972 14:09:32.701 | D1 --> DutThread: ifdown 14:09:32.717 | D1 <-- DutThread: retcode: 0 14:09:32.717 | D1 <-> DutThread: Got response 14:09:32.733 | TC MainThread: ====tearDownTestBench==== 14:09:32.733 | TC MainThread: Close node connections 14:09:32.733 | D1 <-> MainThread: Close 'D1' connection 14:09:32.739 | D1 <-> MainThread: CMD echo on, timeout=1536297022, time=1536296972 14:09:32.743 | D1 --> DutThread: echo on 14:09:32.766 | D1 <-- DutThread: ECHO is on 14:09:32.776 | D1 <-- DutThread: retcode: 0 14:09:32.778 | D1 <-> DutThread: Got response 14:09:32.806 | D1 <-> MainThread: CMD set --vt100 on, timeout=1536297022, time=1536296972 14:09:32.808 | D1 --> DutThread: set --vt100 on 14:09:32.826 | D1 <-- DutThread: retcode: 0 14:09:32.828 | D1 <-> DutThread: Got response 14:09:32.838 | D1 <-> MainThread: CMD set --retcode false, timeout=0, time=1536296972 14:09:32.839 | D1 --> DutThread: set --retcode false />set --retcode false DutThread: /> 14:09:32.888 | <-> DutThread: End DUT communication 14:09:32.888 | D1 <-> MainThread: Close port 'COM15' 14:09:32.911 | TC MainThread: Close node threads 14:09:32.911 | TC MainThread: Skip Sniffing NW data 14:09:32.913 | TC MainThread: Stop external services if any 14:09:32.917 | TC MainThread: retcode: 0, preliminaryVerdict: True 14:09:32.921 | TC MainThread: Test 'UDPSOCKET_BIND_PORT' PASS 14:09:32.926 Test bench returned return code 0 detect GIT info by folder: 'C:\test\oob\mbed-os\TEST_APPS\testcases\netsocket\SOCKET_BIND_PORT.py' all git_info: {'commitid': '3fb5781af180c32a6062f050d59cdf93654b3e9f', 'scm': 'unknown', 'git_path': 'TEST_APPS/testcases/netsocket/SOCKET_BIND_PORT.py', 'scm_path': 'unknown', 'scm_link': '', 'branch': 'HEAD', 'url': 'https://github.com/ARMmbed/mbed-os/', 'scm_group': 'unknown'} 14:09:33.305 | TC MainThread: {'scm': 'unknown', 'commitId': '', 'branch': 'HEAD', 'url': 'https://github.com/ARMmbed/mbed-os/', 'scm_group': 'unknown', 'commitid': '3fb5781af180c32a6062f050d59cdf93654b3e9f', 'git_path': 'TEST_APPS/testcases/netsocket/SOCKET_BIND_PORT.py', 'scm_path': 'unknown', 'scm_link': ''} 14:09:33.315 Duration: 18.121 seconds 14:09:33.315 Test case UDPSOCKET_BIND_PORT passed. 14:09:33.315 Starting next test case: TCPSOCKET_BIND_PORT 14:09:33.319 Iteration 1 of 1 14:09:33.323 Test case retries: 0 14:09:33.328 Starting test case run. 14:09:33.334 Starting test case TCPSOCKET_BIND_PORT 14:09:33.342 14:09:33.344 START TEST CASE EXECUTION: 'TCPSOCKET_BIND_PORT' 14:09:33.346 14:09:33.355 | TC MainThread: Start Test case 'TCPSOCKET_BIND_PORT' 14:09:33.357 | TC MainThread: Environment configurations: 14:09:33.361 | TC MainThread: {'extApps': {'kittyExe': 'C:\\Program Files (x86)\\PuTTY\\kitty.exe', 'puttyExe': 'C:\\Program Files (x86)\\PuTTY\\putty.exe'}, 'sniffer': {'iface': 'Sniffer'}} 14:09:33.367 | TC MainThread: TC configurations: 14:09:33.371 | TC MainThread: {'compatible': {'automation': {'value': True}, 'framework': {'name': 'Icetea', 'version': '>=1.0.0-rc1'}, 'hw': {'value': True}}, 'component': ['mbed-os', 'netsocket'], 'name': 'TCPSOCKET_BIND_PORT', 'purpose': 'Verify TCPSocket can be created, opened and port binded', 'requirements': {'duts': {'*': {'application': {'bin': u'.\\BUILD\\tests\\K64F\\ARM\\.\\TEST_APPS\\device\\socket_app\\socket_app.bin', 'name': u'TEST_APPS-device-socket_app'}, 'count': 1, 'type': u'hardware'}, '1': {'nick': u'dut1'}}, 'external': {'apps': []}}, 'status': 'released', 'sub_type': None, 'subtype': 'socket', 'title': 'tcpsocket open and bind port', 'type': 'smoke'} 14:09:33.375 | TC MainThread: ====setUpTestBench==== 14:09:33.382 | TC MainThread: Configurations seems to be ok 14:09:33.398 | TC MainThread: Registering plugin FileApi 14:09:33.403 | TC MainThread: Registering plugin AssertPlugin 14:09:33.407 | TC MainThread: Registering plugin default_parsers 14:09:33.411 | TC MainThread: Registering plugin HttpApi 14:09:33.417 | TC MainThread: Registering plugin ip_test_parsers 14:09:33.424 | TC MainThread: ====setUpTestBench==== 14:09:33.424 | TC MainThread: --------------------- 14:09:33.430 | TC MainThread: Initialize DUT's connections 14:09:33.436 | RSP MainThread: Allocating duts with the following configurations: 14:09:33.440 | RSP MainThread: {'allowed_platforms': [], 'nick': u'dut1', 'type': u'hardware', 'application': {'bin': u'.\\BUILD\\tests\\K64F\\ARM\\.\\TEST_APPS\\device\\socket_app\\socket_app.bin', 'name': u'TEST_APPS-device-socket_app'}} 14:09:33.444 | RSP MainThread: Allocating 1 duts. 14:09:33.509 | LAL MainThread: Allocated device 0240000028884e450057700f6bf000108021000097969900 14:09:33.510 | RSP MainThread: Allocation successful 14:09:33.517 | D1 Thread-39: Skipping flash, not needed. 14:09:33.519 | TC Thread-39: flash ready 14:09:33.519 | TC Thread-39: Use board K64F as "D1" (id: 0240000028884e450057700f6bf000108021000097969900) 14:09:33.617 | TC MainThread: Allocated following duts: 14:09:33.618 | D1 MainThread: DutSerial COM15 14:09:33.618 | D1 MainThread: Configuration for this DUT: {'allowed_platforms': [], 'nick': u'dut1', 'allocated': {'target_id_mbed_htm': u'0240000028884e450057700f6bf000108021000097969900', 'mount_point': 'E:', 'product_id': u'0204', 'vendor_id': u'0d28', 'target_id': u'0240000028884e450057700f6bf000108021000097969900', 'serial_port': u'COM15', 'target_id _usb_id': u'0240000028884e450057700f6bf000108021000097969900', 'platform_name': u'K64F', 'state': 'allocated', 'directory_entries': ['MBED.HTM', 'DETAILS.TXT'], 'device_type': 'daplink'}, 'type': u'hardware', 'application': {'bin': u'.\\BUILD\\tests\\K64F\\ARM\\.\\TEST_APPS\\device\\socket_app\\sock et_app.bin', 'name': u'TEST_APPS-device-socket_app'}} +----------+--------------+ | COM port | Location | +----------+--------------+ | COM15 | X = 0, Y = 0 | +----------+--------------+ 14:09:33.638 | <-> DutThread: Start DUT communication 14:09:33.638 | D1 <-> MainThread: Open Connection for 'D1' using 'COM15' baudrate: 115200 14:09:33.648 | D1 <-> MainThread: Use normal serial write mode 14:09:33.651 | TC MainThread: Waiting for dut 1 to initialize. 14:09:33.651 | TC MainThread: Cli initialized. 14:09:33.654 | D1 <-> MainThread: CMD set --retcode true, timeout=1536297023, time=1536296973 14:09:33.658 | D1 --> DutThread: set --retcode true />set --retcode true DutThread: />s 14:09:33.720 | D1 <-- DutThread: retcode: 0 14:09:33.721 | D1 <-> DutThread: Got response 14:09:33.772 | D1 <-> MainThread: CMD echo off, timeout=1536297023, time=1536296973 14:09:33.773 | D1 --> DutThread: echo off />echo off 0 | D1 <-- DutThread: /> 14:09:33.811 | D1 <-- DutThread: ECHO is off 14:09:33.831 | D1 <-- DutThread: retcode: 0 14:09:33.832 | D1 <-> DutThread: Got response 14:09:33.835 | D1 <-> MainThread: CMD set --vt100 off, timeout=1536297023, time=1536296973 14:09:33.836 | D1 --> DutThread: set --vt100 off 14:09:33.861 | D1 <-- DutThread: retcode: 0 14:09:33.861 | D1 <-> DutThread: Got response 14:09:33.868 | D1 <-> MainThread: CMD set dut "COM15", timeout=1536297023, time=1536296973 14:09:33.868 | D1 --> DutThread: set dut "COM15" 14:09:33.891 | D1 <-- DutThread: retcode: 0 14:09:33.891 | D1 <-> DutThread: Got response 14:09:33.900 | D1 <-> MainThread: CMD set testcase "", timeout=1536297023, time=1536296973 14:09:33.901 | D1 --> DutThread: set testcase "" 14:09:33.921 | D1 <-- DutThread: retcode: 0 14:09:33.921 | D1 <-> DutThread: Got response 14:09:33.931 | TC MainThread: DUT[0]: COM15 14:09:33.933 | TC MainThread: Initialized 1 dut for this testcase. 14:09:33.933 | TC MainThread: Skip Sniffing NW data 14:09:33.937 | TC MainThread: ------TC SET UP--------- 14:09:33.941 | D1 <-> MainThread: CMD ifup, timeout=1536297023, time=1536296973 14:09:33.946 | D1 --> DutThread: ifup 14:09:34.946 | D1 MainThread: Waiting for response... timeout=48 14:09:34.960 | D1 <-- DutThread: IPv4 if addr: 10.128.4.80 14:09:34.980 | D1 <-- DutThread: MAC-48: 86:47:c6:a7:b9:c6 14:09:35.000 | D1 <-- DutThread: retcode: 0 14:09:35.002 | D1 <-> DutThread: Got response 14:09:35.009 | TC MainThread: {'MAC': u'86:47:c6:a7:b9:c6', 'address': {'ll': '', 'globals': [], 'ipv4': u'10.128.4.80', 'ipv6': []}} 14:09:35.010 | TC MainThread: ------TC START--------- 14:09:35.013 | D1 <-> MainThread: CMD socket new TCPSocket, timeout=1536297025, time=1536296975 14:09:35.016 | D1 --> DutThread: socket new TCPSocket 14:09:35.030 | D1 <-- DutThread: new socket. sid: 1 14:09:35.040 | D1 <-- DutThread: retcode: 0 14:09:35.042 | D1 <-> DutThread: Got response 14:09:35.048 | TC MainThread: {'data_type': None, 'sent_bytes': None, 'address': None, 'socket_id': u'1', 'loop_id': None, 'printed_bytes': None, 'received_bytes': None, 'data': '', 'port': None} 14:09:35.049 | D1 <-> MainThread: CMD socket 1 open, timeout=1536297025, time=1536296975 14:09:35.052 | D1 --> DutThread: socket 1 open 14:09:35.071 | D1 <-- DutThread: retcode: 0 14:09:35.072 | D1 <-> DutThread: Got response 14:09:35.082 | TC MainThread: {'data_type': None, 'sent_bytes': None, 'address': None, 'socket_id': None, 'loop_id': None, 'printed_bytes': None, 'received_bytes': None, 'data': '', 'port': None} 14:09:35.084 | D1 <-> MainThread: CMD socket 1 bind port 1024, timeout=1536297025, time=1536296975 14:09:35.085 | D1 --> DutThread: socket 1 bind port 1024 14:09:35.111 | D1 <-- DutThread: Socket::bind(1024) 14:09:35.121 | D1 <-- DutThread: retcode: 0 14:09:35.121 | D1 <-> DutThread: Got response 14:09:35.148 | TC MainThread: {'data_type': None, 'sent_bytes': None, 'address': None, 'socket_id': None, 'loop_id': None, 'printed_bytes': None, 'received_bytes': None, 'data': '', 'port': None} 14:09:35.148 | D1 <-> MainThread: CMD socket 1 delete, timeout=1536297025, time=1536296975 14:09:35.150 | D1 --> DutThread: socket 1 delete 14:09:35.171 | D1 <-- DutThread: retcode: 0 14:09:35.171 | D1 <-> DutThread: Got response 14:09:35.180 | TC MainThread: {'data_type': None, 'sent_bytes': None, 'address': None, 'socket_id': None, 'loop_id': None, 'printed_bytes': None, 'received_bytes': None, 'data': '', 'port': None} 14:09:35.181 | TC MainThread: -----------TC END----------- 14:09:35.183 | TC MainThread: TC PASS 14:09:35.187 | TC MainThread: ====TC TEAR DOWN==== 14:09:35.190 | D1 <-> MainThread: CMD ifdown, timeout=1536297025, time=1536296975 14:09:35.194 | D1 --> DutThread: ifdown 14:09:35.210 | D1 <-- DutThread: retcode: 0 14:09:35.211 | D1 <-> DutThread: Got response 14:09:35.226 | TC MainThread: ====tearDownTestBench==== 14:09:35.226 | TC MainThread: Close node connections 14:09:35.226 | D1 <-> MainThread: Close 'D1' connection 14:09:35.232 | D1 <-> MainThread: CMD echo on, timeout=1536297025, time=1536296975 14:09:35.236 | D1 --> DutThread: echo on 14:09:35.250 | D1 <-- DutThread: ECHO is on 14:09:35.260 | D1 <-- DutThread: retcode: 0 14:09:35.262 | D1 <-> DutThread: Got response 14:09:35.267 | D1 <-> MainThread: CMD set --vt100 on, timeout=1536297025, time=1536296975 14:09:35.269 | D1 --> DutThread: set --vt100 on 14:09:35.290 | D1 <-- DutThread: retcode: 0 14:09:35.292 | D1 <-> DutThread: Got response 14:09:35.299 | D1 <-> MainThread: CMD set --retcode false, timeout=0, time=1536296975 14:09:35.301 | D1 --> DutThread: set --retcode false />set --retcode false DutThread: /> 14:09:35.342 | <-> DutThread: End DUT communication 14:09:35.342 | D1 <-> MainThread: Close port 'COM15' 14:09:35.365 | TC MainThread: Close node threads 14:09:35.367 | TC MainThread: Skip Sniffing NW data 14:09:35.367 | TC MainThread: Stop external services if any 14:09:35.371 | TC MainThread: retcode: 0, preliminaryVerdict: True 14:09:35.377 | TC MainThread: Test 'TCPSOCKET_BIND_PORT' PASS 14:09:35.381 Test bench returned return code 0 detect GIT info by folder: 'C:\test\oob\mbed-os\TEST_APPS\testcases\netsocket\SOCKET_BIND_PORT.py' all git_info: {'commitid': '3fb5781af180c32a6062f050d59cdf93654b3e9f', 'scm': 'unknown', 'git_path': 'TEST_APPS/testcases/netsocket/SOCKET_BIND_PORT.py', 'scm_path': 'unknown', 'scm_link': '', 'branch': 'HEAD', 'url': 'https://github.com/ARMmbed/mbed-os/', 'scm_group': 'unknown'} 14:09:35.759 | TC MainThread: {'scm': 'unknown', 'commitId': '', 'branch': 'HEAD', 'url': 'https://github.com/ARMmbed/mbed-os/', 'scm_group': 'unknown', 'commitid': '3fb5781af180c32a6062f050d59cdf93654b3e9f', 'git_path': 'TEST_APPS/testcases/netsocket/SOCKET_BIND_PORT.py', 'scm_path': 'unknown', 'scm_link': ''} 14:09:35.770 Duration: 2.034 seconds 14:09:35.770 Test case TCPSOCKET_BIND_PORT passed. 14:09:35.772 Starting next test case: TCPSERVER_ACCEPT 14:09:35.776 Iteration 1 of 1 14:09:35.780 Test case retries: 0 14:09:35.786 Starting test case run. 14:09:35.789 Starting test case TCPSERVER_ACCEPT 14:09:35.799 14:09:35.799 START TEST CASE EXECUTION: 'TCPSERVER_ACCEPT' 14:09:35.803 14:09:35.811 | TC MainThread: Start Test case 'TCPSERVER_ACCEPT' 14:09:35.812 | TC MainThread: Environment configurations: 14:09:35.819 | TC MainThread: {'extApps': {'kittyExe': 'C:\\Program Files (x86)\\PuTTY\\kitty.exe', 'puttyExe': 'C:\\Program Files (x86)\\PuTTY\\putty.exe'}, 'sniffer': {'iface': 'Sniffer'}} 14:09:35.822 | TC MainThread: TC configurations: 14:09:35.828 | TC MainThread: {'author': 'Juha Ylinen ', 'compatible': {'automation': {'value': True}, 'framework': {'name': 'Icetea', 'version': '>=1.0.0-rc1'}, 'hw': {'value': True}}, 'component': ['mbed-os', 'netsocket'], 'name': 'TCPSERVER_ACCEPT', 'purpose': 'Test that TCPServer::bind(), TCPServer::listen() and TCPServer::accept() works', 'requirements': {'duts': {'*': {'application': {'bin': u'.\\BUILD\\tests\\K64F\\ARM\\.\\TEST_APPS\\device\\socket_app\\socket_app.bin', 'name': u'TEST_APPS-device-socket_app'}, 'count': 2, 'type': u'hardware'}, '1': {'nick': u'dut1'}, '2': {'nick': u'dut2'}}, 'external': {'apps': []}}, 'status': 'released', 'sub_type': None, 'subtype': 'socket', 'title': 'TCPSERVER_ACCEPT', 'type': 'smoke'} 14:09:35.832 | TC MainThread: ====setUpTestBench==== 14:09:35.838 | TC MainThread: Configurations seems to be ok 14:09:35.855 | TC MainThread: Registering plugin FileApi 14:09:35.858 | TC MainThread: Registering plugin AssertPlugin 14:09:35.862 | TC MainThread: Registering plugin default_parsers 14:09:35.868 | TC MainThread: Registering plugin HttpApi 14:09:35.872 | TC MainThread: Registering plugin ip_test_parsers 14:09:35.880 | TC MainThread: ====setUpTestBench==== 14:09:35.881 | TC MainThread: --------------------- 14:09:35.885 | TC MainThread: Initialize DUT's connections 14:09:35.891 | RSP MainThread: Allocating duts with the following configurations: 14:09:35.894 | RSP MainThread: {'allowed_platforms': [], 'nick': u'dut1', 'type': u'hardware', 'application': {'bin': u'.\\BUILD\\tests\\K64F\\ARM\\.\\TEST_APPS\\device\\socket_app\\socket_app.bin', 'name': u'TEST_APPS-device-socket_app'}} 14:09:35.898 | RSP MainThread: {'allowed_platforms': [], 'nick': u'dut2', 'type': u'hardware', 'application': {'bin': u'.\\BUILD\\tests\\K64F\\ARM\\.\\TEST_APPS\\device\\socket_app\\socket_app.bin', 'name': u'TEST_APPS-device-socket_app'}} 14:09:35.904 | RSP MainThread: Allocating 2 duts. 14:09:35.963 | LAL MainThread: Allocated device 0240000028884e450057700f6bf000108021000097969900 14:09:35.963 | LAL MainThread: Skipping device 0240000028884e450057700f6bf000108021000097969900 because it was already allocated 14:09:35.963 | TC MainThread: setUpBench Throw exception Traceback (most recent call last): File "c:\python27\lib\site-packages\icetea_lib\bench.py", line 1119, in run self.__setup_bench() File "c:\python27\lib\site-packages\icetea_lib\bench.py", line 1360, in __setup_bench self.__init_duts() File "c:\python27\lib\site-packages\icetea_lib\bench.py", line 790, in __init_duts allocations = self._resource_provider.allocate_duts(self.resource_configuration) File "c:\python27\lib\site-packages\icetea_lib\ResourceProvider\ResourceProvider.py", line 87, in allocate_duts raise ResourceInitError(error) ResourceInitError: No suitable local device available 14:09:35.967 | TC MainThread: Test Case fails because of: No suitable local device available 14:09:35.970 | TC MainThread: ====tearDownTestBench==== 14:09:35.982 | TC MainThread: Close node connections 14:09:35.986 | TC MainThread: Skip Sniffing NW data 14:09:35.990 | TC MainThread: Stop external services if any 14:09:35.993 | TC MainThread: retcode: 1000, preliminaryVerdict: None 14:09:35.996 | TC MainThread: Test 'TCPSERVER_ACCEPT' FAIL, reason: No suitable local device available 14:09:36.000 Test bench returned return code 1000 detect GIT info by folder: 'C:\test\oob\mbed-os\TEST_APPS\testcases\netsocket\TCPSERVER_ACCEPT.py' all git_info: {'commitid': '3fb5781af180c32a6062f050d59cdf93654b3e9f', 'scm': 'unknown', 'git_path': 'TEST_APPS/testcases/netsocket/TCPSERVER_ACCEPT.py', 'scm_path': 'unknown', 'scm_link': '', 'branch': 'HEAD', 'url': 'https://github.com/ARMmbed/mbed-os/', 'scm_group': 'unknown'} 14:09:36.381 | TC MainThread: {'scm': 'unknown', 'commitId': '', 'branch': 'HEAD', 'url': 'https://github.com/ARMmbed/mbed-os/', 'scm_group': 'unknown', 'commitid': '3fb5781af180c32a6062f050d59cdf93654b3e9f', 'git_path': 'TEST_APPS/testcases/netsocket/TCPSERVER_ACCEPT.py', 'scm_path': 'unknown', 'scm_link': ''} 14:09:36.391 Duration: 0.196 seconds 14:09:36.391 Test case TCPSERVER_ACCEPT failed, No retries left. 14:09:36.392 Starting next test case: TCPSOCKET_ECHOTEST_BURST_SHORT 14:09:36.397 Iteration 1 of 1 14:09:36.401 Test case retries: 0 14:09:36.404 Starting test case run. 14:09:36.408 Starting test case TCPSOCKET_ECHOTEST_BURST_SHORT 14:09:36.417 14:09:36.417 START TEST CASE EXECUTION: 'TCPSOCKET_ECHOTEST_BURST_SHORT' 14:09:36.421 14:09:36.426 | TC MainThread: Start Test case 'TCPSOCKET_ECHOTEST_BURST_SHORT' 14:09:36.427 | TC MainThread: Environment configurations: 14:09:36.431 | TC MainThread: {'extApps': {'kittyExe': 'C:\\Program Files (x86)\\PuTTY\\kitty.exe', 'puttyExe': 'C:\\Program Files (x86)\\PuTTY\\putty.exe'}, 'sniffer': {'iface': 'Sniffer'}} 14:09:36.436 | TC MainThread: TC configurations: 14:09:36.440 | TC MainThread: {'author': 'Juha Ylinen ', 'compatible': {'automation': {'value': True}, 'framework': {'name': 'Icetea', 'version': '>=1.0.0-rc1'}, 'hw': {'value': True}}, 'component': ['mbed-os', 'netsocket'], 'name': 'TCPSOCKET_ECHOTEST_BURST_SHORT', 'purpose': 'Verify that TCPSocket can send burst of packets to echo server and read incoming packets', 'requirements': {'duts': {'*': {'application': {'bin': u'.\\BUILD\\tests\\K64F\\ARM\\.\\TEST_APPS\\device\\socket_app\\socket_app.bin', 'name': u'TEST_APPS-device-socket_app'}, 'count': 1, 'type': u'hardware'}, '1': {'nick': u'dut1'}}, 'external': {'apps': []}}, 'status': 'released', 'sub_type': None, 'subtype': 'socket', 'title': 'TCPSOCKET_ECHOTEST_BURST_SHORT', 'type': 'smoke'} 14:09:36.444 | TC MainThread: ====setUpTestBench==== 14:09:36.447 | TC MainThread: Configurations seems to be ok 14:09:36.463 | TC MainThread: Registering plugin FileApi 14:09:36.466 | TC MainThread: Registering plugin AssertPlugin 14:09:36.470 | TC MainThread: Registering plugin default_parsers 14:09:36.474 | TC MainThread: Registering plugin HttpApi 14:09:36.479 | TC MainThread: Registering plugin ip_test_parsers 14:09:36.486 | TC MainThread: ====setUpTestBench==== 14:09:36.486 | TC MainThread: --------------------- 14:09:36.490 | TC MainThread: Initialize DUT's connections 14:09:36.494 | RSP MainThread: Allocating duts with the following configurations: 14:09:36.497 | RSP MainThread: {'allowed_platforms': [], 'nick': u'dut1', 'type': u'hardware', 'application': {'bin': u'.\\BUILD\\tests\\K64F\\ARM\\.\\TEST_APPS\\device\\socket_app\\socket_app.bin', 'name': u'TEST_APPS-device-socket_app'}} 14:09:36.502 | RSP MainThread: Allocating 1 duts. 14:09:36.561 | LAL MainThread: Allocated device 0240000028884e450057700f6bf000108021000097969900 14:09:36.562 | RSP MainThread: Allocation successful 14:09:36.569 | D1 Thread-67: Skipping flash, not needed. 14:09:36.569 | TC Thread-67: flash ready 14:09:36.569 | TC Thread-67: Use board K64F as "D1" (id: 0240000028884e450057700f6bf000108021000097969900) 14:09:36.667 | TC MainThread: Allocated following duts: 14:09:36.667 | D1 MainThread: DutSerial COM15 14:09:36.667 | D1 MainThread: Configuration for this DUT: {'allowed_platforms': [], 'nick': u'dut1', 'allocated': {'target_id_mbed_htm': u'0240000028884e450057700f6bf000108021000097969900', 'mount_point': 'E:', 'product_id': u'0204', 'vendor_id': u'0d28', 'target_id': u'0240000028884e450057700f6bf000108021000097969900', 'serial_port': u'COM15', 'target_id _usb_id': u'0240000028884e450057700f6bf000108021000097969900', 'platform_name': u'K64F', 'state': 'allocated', 'directory_entries': ['MBED.HTM', 'DETAILS.TXT'], 'device_type': 'daplink'}, 'type': u'hardware', 'application': {'bin': u'.\\BUILD\\tests\\K64F\\ARM\\.\\TEST_APPS\\device\\socket_app\\sock et_app.bin', 'name': u'TEST_APPS-device-socket_app'}} +----------+--------------+ | COM port | Location | +----------+--------------+ | COM15 | X = 0, Y = 0 | +----------+--------------+ 14:09:36.684 | <-> DutThread: Start DUT communication 14:09:36.686 | D1 <-> MainThread: Open Connection for 'D1' using 'COM15' baudrate: 115200 14:09:36.694 | D1 <-> MainThread: Use normal serial write mode 14:09:36.696 | TC MainThread: Waiting for dut 1 to initialize. 14:09:36.696 | TC MainThread: Cli initialized. 14:09:36.700 | D1 <-> MainThread: CMD set --retcode true, timeout=1536297026, time=1536296976 14:09:36.703 | D1 --> DutThread: set --retcode true />set --retcode true DutThread: />s 14:09:36.756 | D1 <-- DutThread: retcode: 0 14:09:36.756 | D1 <-> DutThread: Got response 14:09:36.766 | D1 <-> MainThread: CMD echo off, timeout=1536297026, time=1536296976 14:09:36.767 | D1 --> DutThread: echo off />echo off 6 | D1 <-- DutThread: /> 14:09:36.805 | D1 <-- DutThread: ECHO is off 14:09:36.825 | D1 <-- DutThread: retcode: 0 14:09:36.826 | D1 <-> DutThread: Got response 14:09:36.831 | D1 <-> MainThread: CMD set --vt100 off, timeout=1536297026, time=1536296976 14:09:36.832 | D1 --> DutThread: set --vt100 off 14:09:36.855 | D1 <-- DutThread: retcode: 0 14:09:36.857 | D1 <-> DutThread: Got response 14:09:36.862 | D1 <-> MainThread: CMD set dut "COM15", timeout=1536297026, time=1536296976 14:09:36.864 | D1 --> DutThread: set dut "COM15" 14:09:36.885 | D1 <-- DutThread: retcode: 0 14:09:36.887 | D1 <-> DutThread: Got response 14:09:36.894 | D1 <-> MainThread: CMD set testcase "", timeout=1536297026, time=1536296976 14:09:36.895 | D1 --> DutThread: set testcase "" 14:09:36.915 | D1 <-- DutThread: retcode: 0 14:09:36.917 | D1 <-> DutThread: Got response 14:09:36.927 | TC MainThread: DUT[0]: COM15 14:09:36.927 | TC MainThread: Initialized 1 dut for this testcase. 14:09:36.927 | TC MainThread: Skip Sniffing NW data 14:09:36.931 | TC MainThread: ------TC SET UP--------- 14:09:36.937 | D1 <-> MainThread: CMD ifup, timeout=1536297026, time=1536296976 14:09:36.940 | D1 --> DutThread: ifup 14:09:37.940 | D1 MainThread: Waiting for response... timeout=48 14:09:37.956 | D1 <-- DutThread: IPv4 if addr: 10.128.4.80 14:09:37.976 | D1 <-- DutThread: MAC-48: 86:47:c6:a7:b9:c6 14:09:37.996 | D1 <-- DutThread: retcode: 0 14:09:37.996 | D1 <-> DutThread: Got response 14:09:38.003 | TC MainThread: {'MAC': u'86:47:c6:a7:b9:c6', 'address': {'ll': '', 'globals': [], 'ipv4': u'10.128.4.80', 'ipv6': []}} 14:09:38.005 | TC MainThread: ------TC START--------- 14:09:38.006 | D1 <-> MainThread: CMD socket new TCPSocket, timeout=1536297028, time=1536296978 14:09:38.009 | D1 --> DutThread: socket new TCPSocket 14:09:38.026 | D1 <-- DutThread: new socket. sid: 2 14:09:38.036 | D1 <-- DutThread: retcode: 0 14:09:38.036 | D1 <-> DutThread: Got response 14:09:38.040 | TC MainThread: {'data_type': None, 'sent_bytes': None, 'address': None, 'socket_id': u'2', 'loop_id': None, 'printed_bytes': None, 'received_bytes': None, 'data': '', 'port': None} 14:09:38.042 | D1 <-> MainThread: CMD socket 2 open, timeout=1536297028, time=1536296978 14:09:38.046 | D1 --> DutThread: socket 2 open 14:09:38.055 | D1 <-- DutThread: retcode: 0 14:09:38.056 | D1 <-> DutThread: Got response 14:09:38.061 | TC MainThread: {'data_type': None, 'sent_bytes': None, 'address': None, 'socket_id': None, 'loop_id': None, 'printed_bytes': None, 'received_bytes': None, 'data': '', 'port': None} 14:09:38.062 | D1 <-> MainThread: CMD socket 2 connect echo.mbedcloudtesting.com 7, timeout=1536297028, time=1536296978 14:09:38.065 | D1 --> DutThread: socket 2 connect echo.mbedcloudtesting.com 7 14:09:38.085 | D1 <-- DutThread: Host name: echo.mbedcloudtesting.com port: 7 14:09:38.476 | D1 <-- DutThread: retcode: 0 14:09:38.476 | D1 <-> DutThread: Got response 14:09:38.479 | TC MainThread: {'data_type': None, 'sent_bytes': None, 'address': None, 'socket_id': None, 'loop_id': None, 'printed_bytes': None, 'received_bytes': None, 'data': '', 'port': u'7'} 14:09:38.482 | D1 <-> MainThread: CMD socket 2 send DINMUSVFCXBPNVQDNYHYFXJBBIPIJAHYBKXEVYHRDBEQKYUJBVIOQMZIRMBRAJVMESBOPCNHIXLQRSSTFCQNIDCZBGBDAYEIPRGD, timeout=1536297028, time=1536296978 14:09:38.486 | D1 --> DutThread: socket 2 send DINMUSVFCXBPNVQDNYHYFXJBBIPIJAHYBKXEVYHRDBEQKYUJBVIOQMZIRMBRAJVMESBOPCNHIXLQRSSTFCQNIDCZBGBDAYEIPRGD 14:09:38.506 | D1 <-- DutThread: sent: 100 bytes 14:09:38.526 | D1 <-- DutThread: TCPSocket::send() returned: 100 14:09:38.536 | D1 <-- DutThread: retcode: 0 14:09:38.536 | D1 <-> DutThread: Got response 14:09:38.549 | TC MainThread: {'data_type': None, 'sent_bytes': 100, 'address': None, 'socket_id': None, 'loop_id': None, 'printed_bytes': None, 'received_bytes': None, 'data': '', 'port': None} 14:09:38.549 | D1 <-> MainThread: CMD socket 2 send YWZUOUVSWJGAXLCNLDDVVKNWCNGTXWUDPLSHDMQPFMVUQKUFMQIMHCWPBNEGAKDHKFEXIJHFWCPMRPEWBLVLVHXMOATTQBOYVJPIKVZIESNUEGRKIADWXBWXHXQHJRGTRESCLLBGRZWPLGYNZMVBJPISJLYIJJSGPQNQJVMGGMDSEPBKBVJXPMVRLQSLZIEJXVVVBZBT, timeout=1536297028, time=1536296978 14:09:38.551 | D1 --> DutThread: socket 2 send YWZUOUVSWJGAXLCNLDDVVKNWCNGTXWUDPLSHDMQPFMVUQKUFMQIMHCWPBNEGAKDHKFEXIJHFWCPMRPEWBLVLVHXMOATTQBOYVJPIKVZIESNUEGRKIADWXBWXHXQHJRGTRESCLLBGRZWPLGYNZMVBJPISJLYIJJSGPQNQJVMGGMDSEPBKBVJXPMVRLQSLZIEJXVVVBZBT 14:09:38.585 | D1 <-- DutThread: sent: 200 bytes 14:09:38.595 | D1 <-- DutThread: TCPSocket::send() returned: 200 14:09:38.615 | D1 <-- DutThread: retcode: 0 14:09:38.617 | D1 <-> DutThread: Got response 14:09:38.664 | TC MainThread: {'data_type': None, 'sent_bytes': 200, 'address': None, 'socket_id': None, 'loop_id': None, 'printed_bytes': None, 'received_bytes': None, 'data': '', 'port': None} 14:09:38.664 | D1 <-> MainThread: CMD socket 2 send BTVSXFNBVIPEIKIVPRBMSGFXDOHBKFVCUZWTITGKBZQZLIDLVINDOGKAAVLTXWFBILPVZQIYYQBHFCLDVWTKWFUPJUVXOHJPJWXOPNXNJYIDHYHUGZNLCIDIYUIRIRKWYDUNFQGFKJLYYSEIWOWABNACPZVGLEDODRDBDAULLCENAXYNLCSAOZEXCRZIDCLCWUCMSKQXJDMPCQWEXNSSGRAZRIOEYQASRQIQGEOMXFTBMTFIAICHDFWZ LUVQYUWZHDZDAFNZBIFFDHGENECQGMYMFEBNFGQWLEVCORXKEWAX, timeout=1536297028, time=1536296978 14:09:38.665 | D1 --> DutThread: socket 2 send BTVSXFNBVIPEIKIVPRBMSGFXDOHBKFVCUZWTITGKBZQZLIDLVINDOGKAAVLTXWFBILPVZQIYYQBHFCLDVWTKWFUPJUVXOHJPJWXOPNXNJYIDHYHUGZNLCIDIYUIRIRKWYDUNFQGFKJLYYSEIWOWABNACPZVGLEDODRDBDAULLCENAXYNLCSAOZEXCRZIDCLCWUCMSKQXJDMPCQWEXNSSGRAZRIOEYQASRQIQGEOMXFTBMTFIAICHDFWZLUVQY UWZHDZDAFNZBIFFDHGENECQGMYMFEBNFGQWLEVCORXKEWAX 14:09:38.706 | D1 <-- DutThread: sent: 300 bytes 14:09:38.726 | D1 <-- DutThread: TCPSocket::send() returned: 300 14:09:38.736 | D1 <-- DutThread: retcode: 0 14:09:38.736 | D1 <-> DutThread: Got response 14:09:38.779 | TC MainThread: {'data_type': None, 'sent_bytes': 300, 'address': None, 'socket_id': None, 'loop_id': None, 'printed_bytes': None, 'received_bytes': None, 'data': '', 'port': None} 14:09:38.779 | D1 <-> MainThread: CMD socket 2 send LGMDWOGCSGGAUKUVOJPNPOEKJMKLUGQAIANBQOUKNHWDDCLNGPPMLLQXFPCFFFGDKYQYEXYJVBJBVXEWLUNBOFBAWQHHITKNSZRARRQCHGKKEITTFSOORRAI, timeout=1536297028, time=1536296978 14:09:38.780 | D1 --> DutThread: socket 2 send LGMDWOGCSGGAUKUVOJPNPOEKJMKLUGQAIANBQOUKNHWDDCLNGPPMLLQXFPCFFFGDKYQYEXYJVBJBVXEWLUNBOFBAWQHHITKNSZRARRQCHGKKEITTFSOORRAI 14:09:38.805 | D1 <-- DutThread: sent: 120 bytes 14:09:38.815 | D1 <-- DutThread: TCPSocket::send() returned: 120 14:09:38.835 | D1 <-- DutThread: retcode: 0 14:09:38.836 | D1 <-> DutThread: Got response 14:09:38.844 | TC MainThread: {'data_type': None, 'sent_bytes': 120, 'address': None, 'socket_id': None, 'loop_id': None, 'printed_bytes': None, 'received_bytes': None, 'data': '', 'port': None} 14:09:38.845 | D1 <-> MainThread: CMD socket 2 send EOSGTPQVWWIBTMTHKSYTYDBHHNOCUDZLPUHFTNDXPKFIQEEOTNLRUQCZEKYSRKQDMPNUSECWLRFYITEQHQIAVRTPIPLBSQGJELZTAZHZZQAMRAWUUCKVCJFSCXJHKJVNPSSXMVWCWXEETNFRABQVMTSBTFRLWTFRUVKYGNLDSSSKFORKVOHAVESAVLMCAOJUSZZPPUGVKLWCVWHSUUJIYVUKRDRRASZEPHNITIIXMKEPUXBCNNZLEXCV XJJYKXXTSFFRVKLMPLLKYWTSRASSIXRZTTJEFFWJSFYWJOCRUQTILTTVKMMGSOCAZDIBUGMWMSXSUKQQATDUUAZPBLKUFWVIRESOXBRHKZLNWPHSKVEZOZXOHZLGJXESFJLGCYUIBPWTDJVMOUUVIJUMNMJCWEXWJHLJKIJFZPCBXXOJUNDEKYQVVCRZFBUSWFJXTCXHRGZCEUXEOYLWHFQUEGUPQTJYPUSTWPTILLNDZNSUULLCNOVSFBGT, timeout=1536297028, time=1536296978 14:09:38.845 | D1 --> DutThread: socket 2 send EOSGTPQVWWIBTMTHKSYTYDBHHNOCUDZLPUHFTNDXPKFIQEEOTNLRUQCZEKYSRKQDMPNUSECWLRFYITEQHQIAVRTPIPLBSQGJELZTAZHZZQAMRAWUUCKVCJFSCXJHKJVNPSSXMVWCWXEETNFRABQVMTSBTFRLWTFRUVKYGNLDSSSKFORKVOHAVESAVLMCAOJUSZZPPUGVKLWCVWHSUUJIYVUKRDRRASZEPHNITIIXMKEPUXBCNNZLEXCVXJJYK XXTSFFRVKLMPLLKYWTSRASSIXRZTTJEFFWJSFYWJOCRUQTILTTVKMMGSOCAZDIBUGMWMSXSUKQQATDUUAZPBLKUFWVIRESOXBRHKZLNWPHSKVEZOZXOHZLGJXESFJLGCYUIBPWTDJVMOUUVIJUMNMJCWEXWJHLJKIJFZPCBXXOJUNDEKYQVVCRZFBUSWFJXTCXHRGZCEUXEOYLWHFQUEGUPQTJYPUSTWPTILLNDZNSUULLCNOVSFBGT 14:09:39.125 | D1 <-- DutThread: sent: 500 bytes 14:09:39.145 | D1 <-- DutThread: TCPSocket::send() returned: 500 14:09:39.165 | D1 <-- DutThread: retcode: 0 14:09:39.167 | D1 <-> DutThread: Got response 14:09:39.209 | TC MainThread: {'data_type': None, 'sent_bytes': 500, 'address': None, 'socket_id': None, 'loop_id': None, 'printed_bytes': None, 'received_bytes': None, 'data': '', 'port': None} 14:09:39.210 | D1 <-> MainThread: CMD socket 2 recv 1220, timeout=1536297029, time=1536296979 14:09:39.210 | D1 --> DutThread: socket 2 recv 1220 14:09:39.226 | D1 <-- DutThread: received: 536 bytes 14:09:39.236 | D1 <-- DutThread: string data, printing 536 bytes: 14:09:39.256 | D1 <-- DutThread: 0000: DINMUSVFCXBPNVQDNYHY 14:09:39.266 | D1 <-- DutThread: 0020: FXJBBIPIJAHYBKXEVYHR 14:09:39.286 | D1 <-- DutThread: 0040: DBEQKYUJBVIOQMZIRMBR 14:09:39.305 | D1 <-- DutThread: 0060: AJVMESBOPCNHIXLQRSST 14:09:39.315 | D1 <-- DutThread: 0080: FCQNIDCZBGBDAYEIPRGD 14:09:39.335 | D1 <-- DutThread: 0100: YWZUOUVSWJGAXLCNLDDV 14:09:39.345 | D1 <-- DutThread: 0120: VKNWCNGTXWUDPLSHDMQP 14:09:39.365 | D1 <-- DutThread: 0140: FMVUQKUFMQIMHCWPBNEG 14:09:39.375 | D1 <-- DutThread: 0160: AKDHKFEXIJHFWCPMRPEW 14:09:39.395 | D1 <-- DutThread: 0180: BLVLVHXMOATTQBOYVJPI 14:09:39.415 | D1 <-- DutThread: 0200: KVZIESNUEGRKIADWXBWX 14:09:39.426 | D1 <-- DutThread: 0220: HXQHJRGTRESCLLBGRZWP 14:09:39.446 | D1 <-- DutThread: 0240: LGYNZMVBJPISJLYIJJSG 14:09:39.456 | D1 <-- DutThread: 0260: PQNQJVMGGMDSEPBKBVJX 14:09:39.476 | D1 <-- DutThread: 0280: PMVRLQSLZIEJXVVVBZBT 14:09:39.486 | D1 <-- DutThread: 0300: BTVSXFNBVIPEIKIVPRBM 14:09:39.506 | D1 <-- DutThread: 0320: SGFXDOHBKFVCUZWTITGK 14:09:39.516 | D1 <-- DutThread: 0340: BZQZLIDLVINDOGKAAVLT 14:09:39.536 | D1 <-- DutThread: 0360: XWFBILPVZQIYYQBHFCLD 14:09:39.555 | D1 <-- DutThread: 0380: VWTKWFUPJUVXOHJPJWXO 14:09:39.565 | D1 <-- DutThread: 0400: PNXNJYIDHYHUGZNLCIDI 14:09:39.585 | D1 <-- DutThread: 0420: YUIRIRKWYDUNFQGFKJLY 14:09:39.595 | D1 <-- DutThread: 0440: YSEIWOWABNACPZVGLEDO 14:09:39.615 | D1 <-- DutThread: 0460: DRDBDAULLCENAXYNLCSA 14:09:39.625 | D1 <-- DutThread: 0480: OZEXCRZIDCLCWUCMSKQX 14:09:39.645 | D1 <-- DutThread: 0500: JDMPCQWEXNSSGRAZRIOE 14:09:39.655 | D1 <-- DutThread: 0520: YQASRQIQGEOMXFTB 14:09:39.676 | D1 <-- DutThread: Printed 536 bytes 14:09:39.696 | D1 <-- DutThread: TCPSocket::recv() returned: 536 14:09:39.706 | D1 <-- DutThread: retcode: 0 14:09:39.707 | D1 <-> DutThread: Got response 14:09:39.723 | TC MainThread: {'data_type': u'string', 'sent_bytes': None, 'address': None, 'socket_id': None, 'loop_id': None, 'printed_bytes': 536, 'received_bytes': 536, 'data': u'DINMUSVFCXBPNVQDNYHYFXJBBIPIJAHYBKXEVYHRDBEQKYUJBVIOQMZIRMBRAJVMESBOPCNHIXLQRSSTFCQNIDCZBGBDAYEIPRGDYWZUOUVSWJGAX LCNLDDVVKNWCNGTXWUDPLSHDMQPFMVUQKUFMQIMHCWPBNEGAKDHKFEXIJHFWCPMRPEWBLVLVHXMOATTQBOYVJPIKVZIESNUEGRKIADWXBWXHXQHJRGTRESCLLBGRZWPLGYNZMVBJPISJLYIJJSGPQNQJVMGGMDSEPBKBVJXPMVRLQSLZIEJXVVVBZBTBTVSXFNBVIPEIKIVPRBMSGFXDOHBKFVCUZWTITGKBZQZLIDLVINDOGKAAVLTXWFBILPVZQIYYQBHFCLDVWTKWFUPJUVXOHJPJWXOPNXNJYIDHYHUG ZNLCIDIYUIRIRKWYDUNFQGFKJLYYSEIWOWABNACPZVGLEDODRDBDAULLCENAXYNLCSAOZEXCRZIDCLCWUCMSKQXJDMPCQWEXNSSGRAZRIOEYQASRQIQGEOMXFTB', 'port': None} 14:09:39.724 | D1 <-> MainThread: CMD socket 2 recv 1220, timeout=1536297029, time=1536296979 14:09:39.726 | D1 --> DutThread: socket 2 recv 1220 14:09:39.756 | D1 <-- DutThread: received: 536 bytes 14:09:39.766 | D1 <-- DutThread: string data, printing 536 bytes: 14:09:39.786 | D1 <-- DutThread: 0000: MTFIAICHDFWZLUVQYUWZ 14:09:39.805 | D1 <-- DutThread: 0020: HDZDAFNZBIFFDHGENECQ 14:09:39.815 | D1 <-- DutThread: 0040: GMYMFEBNFGQWLEVCORXK 14:09:39.835 | D1 <-- DutThread: 0060: EWAXLGMDWOGCSGGAUKUV 14:09:39.845 | D1 <-- DutThread: 0080: OJPNPOEKJMKLUGQAIANB 14:09:39.865 | D1 <-- DutThread: 0100: QOUKNHWDDCLNGPPMLLQX 14:09:39.875 | D1 <-- DutThread: 0120: FPCFFFGDKYQYEXYJVBJB 14:09:39.895 | D1 <-- DutThread: 0140: VXEWLUNBOFBAWQHHITKN 14:09:39.905 | D1 <-- DutThread: 0160: SZRARRQCHGKKEITTFSOO 14:09:39.926 | D1 <-- DutThread: 0180: RRAIEOSGTPQVWWIBTMTH 14:09:39.946 | D1 <-- DutThread: 0200: KSYTYDBHHNOCUDZLPUHF 14:09:39.956 | D1 <-- DutThread: 0220: TNDXPKFIQEEOTNLRUQCZ 14:09:39.976 | D1 <-- DutThread: 0240: EKYSRKQDMPNUSECWLRFY 14:09:39.986 | D1 <-- DutThread: 0260: ITEQHQIAVRTPIPLBSQGJ 14:09:40.006 | D1 <-- DutThread: 0280: ELZTAZHZZQAMRAWUUCKV 14:09:40.016 | D1 <-- DutThread: 0300: CJFSCXJHKJVNPSSXMVWC 14:09:40.036 | D1 <-- DutThread: 0320: WXEETNFRABQVMTSBTFRL 14:09:40.046 | D1 <-- DutThread: 0340: WTFRUVKYGNLDSSSKFORK 14:09:40.065 | D1 <-- DutThread: 0360: VOHAVESAVLMCAOJUSZZP 14:09:40.085 | D1 <-- DutThread: 0380: PUGVKLWCVWHSUUJIYVUK 14:09:40.095 | D1 <-- DutThread: 0400: RDRRASZEPHNITIIXMKEP 14:09:40.115 | D1 <-- DutThread: 0420: UXBCNNZLEXCVXJJYKXXT 14:09:40.125 | D1 <-- DutThread: 0440: SFFRVKLMPLLKYWTSRASS 14:09:40.145 | D1 <-- DutThread: 0460: IXRZTTJEFFWJSFYWJOCR 14:09:40.155 | D1 <-- DutThread: 0480: UQTILTTVKMMGSOCAZDIB 14:09:40.176 | D1 <-- DutThread: 0500: UGMWMSXSUKQQATDUUAZP 14:09:40.196 | D1 <-- DutThread: 0520: BLKUFWVIRESOXBRH 14:09:40.206 | D1 <-- DutThread: Printed 536 bytes 14:09:40.226 | D1 <-- DutThread: TCPSocket::recv() returned: 536 14:09:40.236 | D1 <-- DutThread: retcode: 0 14:09:40.236 | D1 <-> DutThread: Got response 14:09:40.240 | TC MainThread: {'data_type': u'string', 'sent_bytes': None, 'address': None, 'socket_id': None, 'loop_id': None, 'printed_bytes': 536, 'received_bytes': 536, 'data': u'MTFIAICHDFWZLUVQYUWZHDZDAFNZBIFFDHGENECQGMYMFEBNFGQWLEVCORXKEWAXLGMDWOGCSGGAUKUVOJPNPOEKJMKLUGQAIANBQOUKNHWDDCLNG PPMLLQXFPCFFFGDKYQYEXYJVBJBVXEWLUNBOFBAWQHHITKNSZRARRQCHGKKEITTFSOORRAIEOSGTPQVWWIBTMTHKSYTYDBHHNOCUDZLPUHFTNDXPKFIQEEOTNLRUQCZEKYSRKQDMPNUSECWLRFYITEQHQIAVRTPIPLBSQGJELZTAZHZZQAMRAWUUCKVCJFSCXJHKJVNPSSXMVWCWXEETNFRABQVMTSBTFRLWTFRUVKYGNLDSSSKFORKVOHAVESAVLMCAOJUSZZPPUGVKLWCVWHSUUJIYVUKRDRRASZEPHNIT IIXMKEPUXBCNNZLEXCVXJJYKXXTSFFRVKLMPLLKYWTSRASSIXRZTTJEFFWJSFYWJOCRUQTILTTVKMMGSOCAZDIBUGMWMSXSUKQQATDUUAZPBLKUFWVIRESOXBRH', 'port': None} 14:09:40.243 | D1 <-> MainThread: CMD socket 2 recv 1220, timeout=1536297030, time=1536296980 14:09:40.246 | D1 --> DutThread: socket 2 recv 1220 14:09:40.266 | D1 <-- DutThread: received: 100 bytes 14:09:40.286 | D1 <-- DutThread: string data, printing 100 bytes: 14:09:40.296 | D1 <-- DutThread: 0000: KZLNWPHSKVEZOZXOHZLG 14:09:40.315 | D1 <-- DutThread: 0020: JXESFJLGCYUIBPWTDJVM 14:09:40.335 | D1 <-- DutThread: 0040: OUUVIJUMNMJCWEXWJHLJ 14:09:40.345 | D1 <-- DutThread: 0060: KIJFZPCBXXOJUNDEKYQV 14:09:40.365 | D1 <-- DutThread: 0080: VCRZFBUSWFJXTCXHRGZC 14:09:40.375 | D1 <-- DutThread: Printed 100 bytes 14:09:40.395 | D1 <-- DutThread: TCPSocket::recv() returned: 100 14:09:40.405 | D1 <-- DutThread: retcode: 0 14:09:40.407 | D1 <-> DutThread: Got response 14:09:40.410 | TC MainThread: {'data_type': u'string', 'sent_bytes': None, 'address': None, 'socket_id': None, 'loop_id': None, 'printed_bytes': 100, 'received_bytes': 100, 'data': u'KZLNWPHSKVEZOZXOHZLGJXESFJLGCYUIBPWTDJVMOUUVIJUMNMJCWEXWJHLJKIJFZPCBXXOJUNDEKYQVVCRZFBUSWFJXTCXHRGZC', 'port': No ne} 14:09:40.411 | D1 <-> MainThread: CMD socket 2 recv 1220, timeout=1536297030, time=1536296980 14:09:40.417 | D1 --> DutThread: socket 2 recv 1220 14:09:40.426 | D1 <-- DutThread: received: 48 bytes 14:09:40.436 | D1 <-- DutThread: string data, printing 48 bytes: 14:09:40.456 | D1 <-- DutThread: 0000: EUXEOYLWHFQUEGUPQTJY 14:09:40.476 | D1 <-- DutThread: 0020: PUSTWPTILLNDZNSUULLC 14:09:40.486 | D1 <-- DutThread: 0040: NOVSFBGT 14:09:40.506 | D1 <-- DutThread: Printed 48 bytes 14:09:40.516 | D1 <-- DutThread: TCPSocket::recv() returned: 48 14:09:40.536 | D1 <-- DutThread: retcode: 0 14:09:40.536 | D1 <-> DutThread: Got response 14:09:40.579 | TC MainThread: {'data_type': u'string', 'sent_bytes': None, 'address': None, 'socket_id': None, 'loop_id': None, 'printed_bytes': 48, 'received_bytes': 48, 'data': u'EUXEOYLWHFQUEGUPQTJYPUSTWPTILLNDZNSUULLCNOVSFBGT', 'port': None} 14:09:40.581 | D1 <-> MainThread: CMD socket 2 send TKCYXZYISTASYREIFXGUHPPTMNDCHLIIIDMJCTZHJRUYFOIWWXZHGGDYAMXVDMHTOFTFZDLRJXUPSQHGFOZQVJEMYXCJSPJNGSAK, timeout=1536297030, time=1536296980 14:09:40.582 | D1 --> DutThread: socket 2 send TKCYXZYISTASYREIFXGUHPPTMNDCHLIIIDMJCTZHJRUYFOIWWXZHGGDYAMXVDMHTOFTFZDLRJXUPSQHGFOZQVJEMYXCJSPJNGSAK 14:09:40.615 | D1 <-- DutThread: sent: 100 bytes 14:09:40.625 | D1 <-- DutThread: TCPSocket::send() returned: 100 14:09:40.645 | D1 <-- DutThread: retcode: 0 14:09:40.647 | D1 <-> DutThread: Got response 14:09:40.694 | TC MainThread: {'data_type': None, 'sent_bytes': 100, 'address': None, 'socket_id': None, 'loop_id': None, 'printed_bytes': None, 'received_bytes': None, 'data': '', 'port': None} 14:09:40.696 | D1 <-> MainThread: CMD socket 2 send ZGNHOGOMFVEOBZUHOJKBQAKZXSHEBDBMQNXEDPUNNXPEFHPBRUVFTCFIXZVQRUYLNKKOKPNICWGIVFIIKAUMEWYIDGEGSJNFSTFYOOMGZPGTIUNAFNSBPEYOMROLYEJCQPSAXAQTRFIITTSNACJOIWBQFSPVCQBDCNLXFKYXYWVNPJWXJVQMCXYQGIQHAAJXMPDYBVUP, timeout=1536297030, time=1536296980 14:09:40.697 | D1 --> DutThread: socket 2 send ZGNHOGOMFVEOBZUHOJKBQAKZXSHEBDBMQNXEDPUNNXPEFHPBRUVFTCFIXZVQRUYLNKKOKPNICWGIVFIIKAUMEWYIDGEGSJNFSTFYOOMGZPGTIUNAFNSBPEYOMROLYEJCQPSAXAQTRFIITTSNACJOIWBQFSPVCQBDCNLXFKYXYWVNPJWXJVQMCXYQGIQHAAJXMPDYBVUP 14:09:40.726 | D1 <-- DutThread: sent: 200 bytes 14:09:40.736 | D1 <-- DutThread: TCPSocket::send() returned: 200 14:09:40.756 | D1 <-- DutThread: retcode: 0 14:09:40.756 | D1 <-> DutThread: Got response 14:09:40.759 | TC MainThread: {'data_type': None, 'sent_bytes': 200, 'address': None, 'socket_id': None, 'loop_id': None, 'printed_bytes': None, 'received_bytes': None, 'data': '', 'port': None} 14:09:40.763 | D1 <-> MainThread: CMD socket 2 send HEZAIJGWTASUDBXDEAAGSVVNFFSHXBVNLLBZAMYWVIBLFLDXPRBWCNLFFIFQMBGRLWLWGOFRCKQVMSIFDGEFQTCUAGANMJJTPINAGKSVJYJQPSIUPBFFLPBTNVEMIZVMPYEYHBVOZAPSKWINQECIZTVWGHHGCWUXWFRKQQNOFRHDORBCVIDPVGXSXURUTRJCXPYFHIGLDAPYDGHBNREXXYNRBGKKYBWCQXCJRAHEXMFBCGWNVJFUQRON KRRVTSNVKQXPGFYTGCADUWZHDYTKVYPEZRAWUOYULWSRYFDVJEKY, timeout=1536297030, time=1536296980 14:09:40.767 | D1 --> DutThread: socket 2 send HEZAIJGWTASUDBXDEAAGSVVNFFSHXBVNLLBZAMYWVIBLFLDXPRBWCNLFFIFQMBGRLWLWGOFRCKQVMSIFDGEFQTCUAGANMJJTPINAGKSVJYJQPSIUPBFFLPBTNVEMIZVMPYEYHBVOZAPSKWINQECIZTVWGHHGCWUXWFRKQQNOFRHDORBCVIDPVGXSXURUTRJCXPYFHIGLDAPYDGHBNREXXYNRBGKKYBWCQXCJRAHEXMFBCGWNVJFUQRONKRRVT SNVKQXPGFYTGCADUWZHDYTKVYPEZRAWUOYULWSRYFDVJEKY 14:09:40.815 | D1 <-- DutThread: sent: 300 bytes 14:09:40.825 | D1 <-- DutThread: TCPSocket::send() returned: 300 14:09:40.845 | D1 <-- DutThread: retcode: 0 14:09:40.846 | D1 <-> DutThread: Got response 14:09:40.881 | TC MainThread: {'data_type': None, 'sent_bytes': 300, 'address': None, 'socket_id': None, 'loop_id': None, 'printed_bytes': None, 'received_bytes': None, 'data': '', 'port': None} 14:09:40.881 | D1 <-> MainThread: CMD socket 2 send JBMCCEEUWFEDEMRXMLJZLAITGBDSYPXQUWXRFSDLOMOJDJDCBSNQEMAGWLCOXPMILLRVVIYWXVKDDJNEDTUPMRXJPHMICRYRADWWSKTVLBKKZNFHWIJWFMHR, timeout=1536297030, time=1536296980 14:09:40.881 | D1 --> DutThread: socket 2 send JBMCCEEUWFEDEMRXMLJZLAITGBDSYPXQUWXRFSDLOMOJDJDCBSNQEMAGWLCOXPMILLRVVIYWXVKDDJNEDTUPMRXJPHMICRYRADWWSKTVLBKKZNFHWIJWFMHR 14:09:40.905 | D1 <-- DutThread: sent: 120 bytes 14:09:40.926 | D1 <-- DutThread: TCPSocket::send() returned: 120 14:09:40.936 | D1 <-- DutThread: retcode: 0 14:09:40.937 | D1 <-> DutThread: Got response 14:09:40.944 | TC MainThread: {'data_type': None, 'sent_bytes': 120, 'address': None, 'socket_id': None, 'loop_id': None, 'printed_bytes': None, 'received_bytes': None, 'data': '', 'port': None} 14:09:40.946 | D1 <-> MainThread: CMD socket 2 send UAPVCYWHLKEKSRJRDOWYXPJQGBPUXYEWWBUXSIJDNFLXIADRTYETOMLFNUSXRQLMHHKOXYRHWVLNXGJDQGIWTHTRUHLZMSAQMTGKUZFVTESSXZLCKSHTNALNNAHOXVLEFUKXSHLBIOVKXZHKEUNOHYXARHFAFSAORRLLHGVILYGHITNUTBVPLOLIGOJSPDORMFVGCWBOLQDBHTKXVCNCJSCVEABOHZGNQZJCUWZNQMPUWBUWLAIBKHXL XFUUXREZJIWZQXRMAVKYYAFJDRGYCAIUJDZEHULLRJZMWUROZSFZHUKSSMGKJRTAMUBLBPWWGRBGEAXNOXWLCKIPJEEPCFNSCBIECTUSXSAMGFSKZYPNWGLSLQVAECAZOOXTKHHZPXSRJDICFRPWGLWOLNDIJCFOKFVTLPAACMTNGDTTGXTPWCVEGSKNSJSCFOAOMXYWGZQWQAXWDQJPSBWNIQDLRXKLDGJPMWJQKBTBVXXGBPXRMDRZEGCO, timeout=1536297030, time=1536296980 14:09:40.947 | D1 --> DutThread: socket 2 send UAPVCYWHLKEKSRJRDOWYXPJQGBPUXYEWWBUXSIJDNFLXIADRTYETOMLFNUSXRQLMHHKOXYRHWVLNXGJDQGIWTHTRUHLZMSAQMTGKUZFVTESSXZLCKSHTNALNNAHOXVLEFUKXSHLBIOVKXZHKEUNOHYXARHFAFSAORRLLHGVILYGHITNUTBVPLOLIGOJSPDORMFVGCWBOLQDBHTKXVCNCJSCVEABOHZGNQZJCUWZNQMPUWBUWLAIBKHXLXFUUX REZJIWZQXRMAVKYYAFJDRGYCAIUJDZEHULLRJZMWUROZSFZHUKSSMGKJRTAMUBLBPWWGRBGEAXNOXWLCKIPJEEPCFNSCBIECTUSXSAMGFSKZYPNWGLSLQVAECAZOOXTKHHZPXSRJDICFRPWGLWOLNDIJCFOKFVTLPAACMTNGDTTGXTPWCVEGSKNSJSCFOAOMXYWGZQWQAXWDQJPSBWNIQDLRXKLDGJPMWJQKBTBVXXGBPXRMDRZEGCO 14:09:41.236 | D1 <-- DutThread: sent: 500 bytes 14:09:41.256 | D1 <-- DutThread: TCPSocket::send() returned: 500 14:09:41.266 | D1 <-- DutThread: retcode: 0 14:09:41.266 | D1 <-> DutThread: Got response 14:09:41.309 | TC MainThread: {'data_type': None, 'sent_bytes': 500, 'address': None, 'socket_id': None, 'loop_id': None, 'printed_bytes': None, 'received_bytes': None, 'data': '', 'port': None} 14:09:41.311 | D1 <-> MainThread: CMD socket 2 recv 1220, timeout=1536297031, time=1536296981 14:09:41.312 | D1 --> DutThread: socket 2 recv 1220 14:09:41.325 | D1 <-- DutThread: received: 100 bytes 14:09:41.345 | D1 <-- DutThread: string data, printing 100 bytes: 14:09:41.365 | D1 <-- DutThread: 0000: TKCYXZYISTASYREIFXGU 14:09:41.375 | D1 <-- DutThread: 0020: HPPTMNDCHLIIIDMJCTZH 14:09:41.395 | D1 <-- DutThread: 0040: JRUYFOIWWXZHGGDYAMXV 14:09:41.405 | D1 <-- DutThread: 0060: DMHTOFTFZDLRJXUPSQHG 14:09:41.426 | D1 <-- DutThread: 0080: FOZQVJEMYXCJSPJNGSAK 14:09:41.436 | D1 <-- DutThread: Printed 100 bytes 14:09:41.456 | D1 <-- DutThread: TCPSocket::recv() returned: 100 14:09:41.466 | D1 <-- DutThread: retcode: 0 14:09:41.467 | D1 <-> DutThread: Got response 14:09:41.474 | TC MainThread: {'data_type': u'string', 'sent_bytes': None, 'address': None, 'socket_id': None, 'loop_id': None, 'printed_bytes': 100, 'received_bytes': 100, 'data': u'TKCYXZYISTASYREIFXGUHPPTMNDCHLIIIDMJCTZHJRUYFOIWWXZHGGDYAMXVDMHTOFTFZDLRJXUPSQHGFOZQVJEMYXCJSPJNGSAK', 'port': No ne} 14:09:41.476 | D1 <-> MainThread: CMD socket 2 recv 1220, timeout=1536297031, time=1536296981 14:09:41.477 | D1 --> DutThread: socket 2 recv 1220 14:09:41.506 | D1 <-- DutThread: received: 500 bytes 14:09:41.516 | D1 <-- DutThread: string data, printing 500 bytes: 14:09:41.536 | D1 <-- DutThread: 0000: ZGNHOGOMFVEOBZUHOJKB 14:09:41.546 | D1 <-- DutThread: 0020: QAKZXSHEBDBMQNXEDPUN 14:09:41.565 | D1 <-- DutThread: 0040: NXPEFHPBRUVFTCFIXZVQ 14:09:41.575 | D1 <-- DutThread: 0060: RUYLNKKOKPNICWGIVFII 14:09:41.595 | D1 <-- DutThread: 0080: KAUMEWYIDGEGSJNFSTFY 14:09:41.605 | D1 <-- DutThread: 0100: OOMGZPGTIUNAFNSBPEYO 14:09:41.625 | D1 <-- DutThread: 0120: MROLYEJCQPSAXAQTRFII 14:09:41.645 | D1 <-- DutThread: 0140: TTSNACJOIWBQFSPVCQBD 14:09:41.655 | D1 <-- DutThread: 0160: CNLXFKYXYWVNPJWXJVQM 14:09:41.676 | D1 <-- DutThread: 0180: CXYQGIQHAAJXMPDYBVUP 14:09:41.686 | D1 <-- DutThread: 0200: HEZAIJGWTASUDBXDEAAG 14:09:41.706 | D1 <-- DutThread: 0220: SVVNFFSHXBVNLLBZAMYW 14:09:41.716 | D1 <-- DutThread: 0240: VIBLFLDXPRBWCNLFFIFQ 14:09:41.736 | D1 <-- DutThread: 0260: MBGRLWLWGOFRCKQVMSIF 14:09:41.756 | D1 <-- DutThread: 0280: DGEFQTCUAGANMJJTPINA 14:09:41.766 | D1 <-- DutThread: 0300: GKSVJYJQPSIUPBFFLPBT 14:09:41.786 | D1 <-- DutThread: 0320: NVEMIZVMPYEYHBVOZAPS 14:09:41.796 | D1 <-- DutThread: 0340: KWINQECIZTVWGHHGCWUX 14:09:41.815 | D1 <-- DutThread: 0360: WFRKQQNOFRHDORBCVIDP 14:09:41.825 | D1 <-- DutThread: 0380: VGXSXURUTRJCXPYFHIGL 14:09:41.845 | D1 <-- DutThread: 0400: DAPYDGHBNREXXYNRBGKK 14:09:41.855 | D1 <-- DutThread: 0420: YBWCQXCJRAHEXMFBCGWN 14:09:41.875 | D1 <-- DutThread: 0440: VJFUQRONKRRVTSNVKQXP 14:09:41.895 | D1 <-- DutThread: 0460: GFYTGCADUWZHDYTKVYPE 14:09:41.905 | D1 <-- DutThread: 0480: ZRAWUOYULWSRYFDVJEKY 14:09:41.926 | D1 <-- DutThread: Printed 500 bytes 14:09:41.936 | D1 <-- DutThread: TCPSocket::recv() returned: 500 14:09:41.956 | D1 <-- DutThread: retcode: 0 14:09:41.957 | D1 <-> DutThread: Got response 14:09:41.990 | TC MainThread: {'data_type': u'string', 'sent_bytes': None, 'address': None, 'socket_id': None, 'loop_id': None, 'printed_bytes': 500, 'received_bytes': 500, 'data': u'ZGNHOGOMFVEOBZUHOJKBQAKZXSHEBDBMQNXEDPUNNXPEFHPBRUVFTCFIXZVQRUYLNKKOKPNICWGIVFIIKAUMEWYIDGEGSJNFSTFYOOMGZPGTIUNAF NSBPEYOMROLYEJCQPSAXAQTRFIITTSNACJOIWBQFSPVCQBDCNLXFKYXYWVNPJWXJVQMCXYQGIQHAAJXMPDYBVUPHEZAIJGWTASUDBXDEAAGSVVNFFSHXBVNLLBZAMYWVIBLFLDXPRBWCNLFFIFQMBGRLWLWGOFRCKQVMSIFDGEFQTCUAGANMJJTPINAGKSVJYJQPSIUPBFFLPBTNVEMIZVMPYEYHBVOZAPSKWINQECIZTVWGHHGCWUXWFRKQQNOFRHDORBCVIDPVGXSXURUTRJCXPYFHIGLDAPYDGHBNREXX YNRBGKKYBWCQXCJRAHEXMFBCGWNVJFUQRONKRRVTSNVKQXPGFYTGCADUWZHDYTKVYPEZRAWUOYULWSRYFDVJEKY', 'port': None} 14:09:41.992 | D1 <-> MainThread: CMD socket 2 recv 1220, timeout=1536297031, time=1536296981 14:09:41.993 | D1 --> DutThread: socket 2 recv 1220 14:09:42.016 | D1 <-- DutThread: received: 536 bytes 14:09:42.036 | D1 <-- DutThread: string data, printing 536 bytes: 14:09:42.046 | D1 <-- DutThread: 0000: JBMCCEEUWFEDEMRXMLJZ 14:09:42.065 | D1 <-- DutThread: 0020: LAITGBDSYPXQUWXRFSDL 14:09:42.075 | D1 <-- DutThread: 0040: OMOJDJDCBSNQEMAGWLCO 14:09:42.095 | D1 <-- DutThread: 0060: XPMILLRVVIYWXVKDDJNE 14:09:42.105 | D1 <-- DutThread: 0080: DTUPMRXJPHMICRYRADWW 14:09:42.125 | D1 <-- DutThread: 0100: SKTVLBKKZNFHWIJWFMHR 14:09:42.145 | D1 <-- DutThread: 0120: UAPVCYWHLKEKSRJRDOWY 14:09:42.155 | D1 <-- DutThread: 0140: XPJQGBPUXYEWWBUXSIJD 14:09:42.176 | D1 <-- DutThread: 0160: NFLXIADRTYETOMLFNUSX 14:09:42.186 | D1 <-- DutThread: 0180: RQLMHHKOXYRHWVLNXGJD 14:09:42.206 | D1 <-- DutThread: 0200: QGIWTHTRUHLZMSAQMTGK 14:09:42.216 | D1 <-- DutThread: 0220: UZFVTESSXZLCKSHTNALN 14:09:42.236 | D1 <-- DutThread: 0240: NAHOXVLEFUKXSHLBIOVK 14:09:42.246 | D1 <-- DutThread: 0260: XZHKEUNOHYXARHFAFSAO 14:09:42.266 | D1 <-- DutThread: 0280: RRLLHGVILYGHITNUTBVP 14:09:42.286 | D1 <-- DutThread: 0300: LOLIGOJSPDORMFVGCWBO 14:09:42.296 | D1 <-- DutThread: 0320: LQDBHTKXVCNCJSCVEABO 14:09:42.315 | D1 <-- DutThread: 0340: HZGNQZJCUWZNQMPUWBUW 14:09:42.325 | D1 <-- DutThread: 0360: LAIBKHXLXFUUXREZJIWZ 14:09:42.345 | D1 <-- DutThread: 0380: QXRMAVKYYAFJDRGYCAIU 14:09:42.355 | D1 <-- DutThread: 0400: JDZEHULLRJZMWUROZSFZ 14:09:42.375 | D1 <-- DutThread: 0420: HUKSSMGKJRTAMUBLBPWW 14:09:42.385 | D1 <-- DutThread: 0440: GRBGEAXNOXWLCKIPJEEP 14:09:42.405 | D1 <-- DutThread: 0460: CFNSCBIECTUSXSAMGFSK 14:09:42.426 | D1 <-- DutThread: 0480: ZYPNWGLSLQVAECAZOOXT 14:09:42.436 | D1 <-- DutThread: 0500: KHHZPXSRJDICFRPWGLWO 14:09:42.456 | D1 <-- DutThread: 0520: LNDIJCFOKFVTLPAA 14:09:42.466 | D1 <-- DutThread: Printed 536 bytes 14:09:42.486 | D1 <-- DutThread: TCPSocket::recv() returned: 536 14:09:42.496 | D1 <-- DutThread: retcode: 0 14:09:42.496 | D1 <-> DutThread: Got response 14:09:42.506 | TC MainThread: {'data_type': u'string', 'sent_bytes': None, 'address': None, 'socket_id': None, 'loop_id': None, 'printed_bytes': 536, 'received_bytes': 536, 'data': u'JBMCCEEUWFEDEMRXMLJZLAITGBDSYPXQUWXRFSDLOMOJDJDCBSNQEMAGWLCOXPMILLRVVIYWXVKDDJNEDTUPMRXJPHMICRYRADWWSKTVLBKKZNFHW IJWFMHRUAPVCYWHLKEKSRJRDOWYXPJQGBPUXYEWWBUXSIJDNFLXIADRTYETOMLFNUSXRQLMHHKOXYRHWVLNXGJDQGIWTHTRUHLZMSAQMTGKUZFVTESSXZLCKSHTNALNNAHOXVLEFUKXSHLBIOVKXZHKEUNOHYXARHFAFSAORRLLHGVILYGHITNUTBVPLOLIGOJSPDORMFVGCWBOLQDBHTKXVCNCJSCVEABOHZGNQZJCUWZNQMPUWBUWLAIBKHXLXFUUXREZJIWZQXRMAVKYYAFJDRGYCAIUJDZEHULLRJZMW UROZSFZHUKSSMGKJRTAMUBLBPWWGRBGEAXNOXWLCKIPJEEPCFNSCBIECTUSXSAMGFSKZYPNWGLSLQVAECAZOOXTKHHZPXSRJDICFRPWGLWOLNDIJCFOKFVTLPAA', 'port': None} 14:09:42.506 | D1 <-> MainThread: CMD socket 2 recv 1220, timeout=1536297032, time=1536296982 14:09:42.507 | D1 --> DutThread: socket 2 recv 1220 14:09:42.536 | D1 <-- DutThread: received: 36 bytes 14:09:42.546 | D1 <-- DutThread: string data, printing 36 bytes: 14:09:42.565 | D1 <-- DutThread: 0000: CMTNGDTTGXTPWCVEGSKN 14:09:42.575 | D1 <-- DutThread: 0020: SJSCFOAOMXYWGZQW 14:09:42.595 | D1 <-- DutThread: Printed 36 bytes 14:09:42.605 | D1 <-- DutThread: TCPSocket::recv() returned: 36 14:09:42.625 | D1 <-- DutThread: retcode: 0 14:09:42.627 | D1 <-> DutThread: Got response 14:09:42.671 | TC MainThread: {'data_type': u'string', 'sent_bytes': None, 'address': None, 'socket_id': None, 'loop_id': None, 'printed_bytes': 36, 'received_bytes': 36, 'data': u'CMTNGDTTGXTPWCVEGSKNSJSCFOAOMXYWGZQW', 'port': None} 14:09:42.671 | D1 <-> MainThread: CMD socket 2 recv 1220, timeout=1536297032, time=1536296982 14:09:42.673 | D1 --> DutThread: socket 2 recv 1220 14:09:42.686 | D1 <-- DutThread: received: 48 bytes 14:09:42.706 | D1 <-- DutThread: string data, printing 48 bytes: 14:09:42.716 | D1 <-- DutThread: 0000: QAXWDQJPSBWNIQDLRXKL 14:09:42.736 | D1 <-- DutThread: 0020: DGJPMWJQKBTBVXXGBPXR 14:09:42.746 | D1 <-- DutThread: 0040: MDRZEGCO 14:09:42.766 | D1 <-- DutThread: Printed 48 bytes 14:09:42.776 | D1 <-- DutThread: TCPSocket::recv() returned: 48 14:09:42.796 | D1 <-- DutThread: retcode: 0 14:09:42.796 | D1 <-> DutThread: Got response 14:09:42.835 | TC MainThread: {'data_type': u'string', 'sent_bytes': None, 'address': None, 'socket_id': None, 'loop_id': None, 'printed_bytes': 48, 'received_bytes': 48, 'data': u'QAXWDQJPSBWNIQDLRXKLDGJPMWJQKBTBVXXGBPXRMDRZEGCO', 'port': None} 14:09:42.836 | D1 <-> MainThread: CMD socket 2 delete, timeout=1536297032, time=1536296982 14:09:42.838 | D1 --> DutThread: socket 2 delete 14:09:42.855 | D1 <-- DutThread: retcode: 0 14:09:42.857 | D1 <-> DutThread: Got response 14:09:42.868 | TC MainThread: {'data_type': None, 'sent_bytes': None, 'address': None, 'socket_id': None, 'loop_id': None, 'printed_bytes': None, 'received_bytes': None, 'data': '', 'port': None} 14:09:42.869 | TC MainThread: -----------TC END----------- 14:09:42.871 | TC MainThread: TC PASS 14:09:42.875 | TC MainThread: ====TC TEAR DOWN==== 14:09:42.880 | D1 <-> MainThread: CMD ifdown, timeout=1536297032, time=1536296982 14:09:42.884 | D1 --> DutThread: ifdown 14:09:42.905 | D1 <-- DutThread: retcode: 0 14:09:42.907 | D1 <-> DutThread: Got response 14:09:42.914 | TC MainThread: ====tearDownTestBench==== 14:09:42.915 | TC MainThread: Close node connections 14:09:42.917 | D1 <-> MainThread: Close 'D1' connection 14:09:42.921 | D1 <-> MainThread: CMD echo on, timeout=1536297032, time=1536296982 14:09:42.927 | D1 --> DutThread: echo on 14:09:42.936 | D1 <-- DutThread: ECHO is on 14:09:42.956 | D1 <-- DutThread: retcode: 0 14:09:42.957 | D1 <-> DutThread: Got response 14:09:42.990 | D1 <-> MainThread: CMD set --vt100 on, timeout=1536297032, time=1536296982 14:09:42.990 | D1 --> DutThread: set --vt100 on 14:09:43.016 | D1 <-- DutThread: retcode: 0 14:09:43.016 | D1 <-> DutThread: Got response 14:09:43.022 | D1 <-> MainThread: CMD set --retcode false, timeout=0, time=1536296983 14:09:43.023 | D1 --> DutThread: set --retcode false 14:09:43.075 | <-> DutThread: End DUT communication 14:09:43.076 | D1 <-> MainThread: Close port 'COM15' 14:09:43.095 | TC MainThread: Close node threads 14:09:43.095 | TC MainThread: Skip Sniffing NW data 14:09:43.096 | TC MainThread: Stop external services if any 14:09:43.101 | TC MainThread: retcode: 0, preliminaryVerdict: True 14:09:43.105 | TC MainThread: Test 'TCPSOCKET_ECHOTEST_BURST_SHORT' PASS 14:09:43.111 Test bench returned return code 0 detect GIT info by folder: 'C:\test\oob\mbed-os\TEST_APPS\testcases\netsocket\TCPSOCKET_ECHOTEST_BURST_SHORT.py' all git_info: {'commitid': '3fb5781af180c32a6062f050d59cdf93654b3e9f', 'scm': 'unknown', 'git_path': 'TEST_APPS/testcases/netsocket/TCPSOCKET_ECHOTEST_BURST_SHORT.py', 'scm_path': 'unknown', 'scm_link': '', 'branch': 'HEAD', 'url': 'https://github.com/ARMmbed/mbed-os/', 'scm_group': 'unknown'} 14:09:43.492 | TC MainThread: {'scm': 'unknown', 'commitId': '', 'branch': 'HEAD', 'url': 'https://github.com/ARMmbed/mbed-os/', 'scm_group': 'unknown', 'commitid': '3fb5781af180c32a6062f050d59cdf93654b3e9f', 'git_path': 'TEST_APPS/testcases/netsocket/TCPSOCKET_ECHOTEST_BURST_SHORT.py', 'scm_pat h': 'unknown', 'scm_link': ''} 14:09:43.502 Duration: 6.691 seconds 14:09:43.503 Test case TCPSOCKET_ECHOTEST_BURST_SHORT passed. +--------------------------------+--------------+------------------------------------+---------------------------------------------+-----------+----------+ | Testcase | Verdict | Fail Reason | Skip Reason | platforms | duration | +--------------------------------+--------------+------------------------------------+---------------------------------------------+-----------+----------+ | test_cmdline | skip | | Test requiring application binary not build | | 0 | | UDPSOCKET_BIND_PORT | pass | | | K64F | 18.121 | | TCPSOCKET_BIND_PORT | pass | | | K64F | 2.034 | | TCPSERVER_ACCEPT | inconclusive | No suitable local device available | | | 0.196 | | TCPSOCKET_ECHOTEST_BURST_SHORT | pass | | | K64F | 6.691 | +--------------------------------+--------------+------------------------------------+---------------------------------------------+-----------+----------+ +---------------+----------------+ | Summary | | +---------------+----------------+ | Final Verdict | INCONCLUSIVE | | count | 5 | | passrate | 100.00 % | | pass | 3 | | skip | 1 | | inconclusive | 1 | | Duration | 0:00:27.042000 | +---------------+----------------+ 14:09:43.543 | RSP MainThread: Cleaning up ResourceProvider. 14:09:43.553 | RSP MainThread: Cleaning up allocator. 14:09:43.559 Cleanup done. PS C:\test\oob\mbed-os>