Skip to content

Instantly share code, notes, and snippets.

@jschoch
Last active August 18, 2019 17:02
Show Gist options
  • Save jschoch/e751d9cab644a43536cc6da4d688a018 to your computer and use it in GitHub Desktop.
Save jschoch/e751d9cab644a43536cc6da4d688a018 to your computer and use it in GitHub Desktop.
3.22 vs 4.0 idf
:~/diff_test$ diff a b
5,10c5,10
< load:0x3fff001c,len:6264
< load:0x40078000,len:10180
< load:0x40080400,len:6712
< entry 0x40080768
< I (28) boot: ESP-IDF v3.2.2-dirty 2nd stage bootloader
< I (28) boot: compile time 18:26:31
---
> load:0x3fff001c,len:6552
> load:0x40078000,len:11368
> load:0x40080400,len:6692
> entry 0x40080770
> I (28) boot: ESP-IDF v4.0-dev-1443-g39f090a 2nd stage bootloader
> I (28) boot: compile time 22:20:19
12,27c12,24
< I (33) boot: SPI Speed : 40MHz
< I (37) boot: SPI Mode : DIO
< I (41) boot: SPI Flash Size : 4MB
< I (45) boot: Partition Table:
< I (49) boot: ## Label Usage Type ST Offset Length
< I (56) boot: 0 nvs WiFi data 01 02 00009000 00005000
< I (64) boot: 1 otadata OTA data 01 00 0000e000 00002000
< I (71) boot: 2 app0 OTA app 00 10 00010000 00140000
< I (79) boot: 3 app1 OTA app 00 11 00150000 00140000
< I (86) boot: 4 spiffs Unknown data 01 82 00290000 00170000
< I (94) boot: End of partition table
< I (98) boot: No factory image, trying OTA 0
< I (103) esp_image: segment 0: paddr=0x00010020 vaddr=0x3f400020 size=0x14800 ( 83968) map
< I (141) esp_image: segment 1: paddr=0x00024828 vaddr=0x3ffbdb60 size=0x02a04 ( 10756) load
< I (146) esp_image: segment 2: paddr=0x00027234 vaddr=0x40080000 size=0x00400 ( 1024) load
< 0x40080000: _WindowOverflow4 at /home/oldidf/esp-idf-v3.2.2/components/freertos/xtensa_vectors.S:1779
---
> I (34) boot: SPI Speed : 40MHz
> I (38) boot: SPI Mode : DIO
> I (42) boot: SPI Flash Size : 2MB
> I (46) boot: Partition Table:
> I (50) boot: ## Label Usage Type ST Offset Length
> I (57) boot: 0 nvs WiFi data 01 02 00009000 00006000
> I (65) boot: 1 phy_init RF data 01 01 0000f000 00001000
> I (72) boot: 2 factory factory app 00 00 00010000 00100000
> I (80) boot: End of partition table
> I (84) esp_image: segment 0: paddr=0x00010020 vaddr=0x3f400020 size=0x12f68 ( 77672) map
> I (121) esp_image: segment 1: paddr=0x00022f90 vaddr=0x3ffbdb60 size=0x05b1c ( 23324) load
> I (130) esp_image: segment 2: paddr=0x00028ab4 vaddr=0x40080000 size=0x00400 ( 1024) load
> 0x40080000: _WindowOverflow4 at /home/schoch/dev/esp-idf/components/freertos/xtensa_vectors.S:1778
29,30c26,27
< I (148) esp_image: segment 3: paddr=0x0002763c vaddr=0x40080400 size=0x089d4 ( 35284) load
< I (171) esp_image: segment 4: paddr=0x00030018 vaddr=0x400d0018 size=0x4193c (268604) map
---
> I (131) esp_image: segment 3: paddr=0x00028ebc vaddr=0x40080400 size=0x07154 ( 29012) load
> I (151) esp_image: segment 4: paddr=0x00030018 vaddr=0x400d0018 size=0x45ce4 (285924) map
33,34c30,31
< I (266) esp_image: segment 5: paddr=0x0007195c vaddr=0x40088dd4 size=0x09960 ( 39264) load
< 0x40088dd4: r_ld_fm_clk_isr at ??:?
---
> I (253) esp_image: segment 5: paddr=0x00075d04 vaddr=0x40087554 size=0x0cc30 ( 52272) load
> 0x40087554: r_ld_fm_sket_isr at ??:?
36,40c33,43
< I (293) boot: Loaded app from partition at offset 0x10000
< I (293) boot: Disabling RNG early entropy source...
< I (294) cpu_start: Pro cpu up.
< I (297) cpu_start: Starting app cpu, entry point is 0x4008102c
< 0x4008102c: call_start_cpu1 at /home/oldidf/esp-idf-v3.2.2/components/esp32/cpu_start.c:246
---
> I (289) boot: Loaded app from partition at offset 0x10000
> I (289) boot: Disabling RNG early entropy source...
> I (289) cpu_start: Pro cpu up.
> I (293) cpu_start: Application information:
> I (298) cpu_start: Project name: volkhin_nixie_timer
> I (304) cpu_start: App version: b6aeb21
> I (309) cpu_start: Compile time: Aug 17 2019 22:20:59
> I (315) cpu_start: ELF file SHA256: ecbc3de4d0867ab6...
> I (321) cpu_start: ESP-IDF: v4.0-dev-1443-g39f090a
> I (327) cpu_start: Starting app cpu, entry point is 0x400812e0
> 0x400812e0: call_start_cpu1 at /home/schoch/dev/esp-idf/components/esp32/cpu_start.c:281
43,53c46,59
< I (308) heap_init: Initializing. RAM available for dynamic allocation:
< I (314) heap_init: At 3FFAFF10 len 000000F0 (0 KiB): DRAM
< I (320) heap_init: At 3FFB7468 len 00000B98 (2 KiB): DRAM
< I (327) heap_init: At 3FFB9A20 len 00004108 (16 KiB): DRAM
< I (333) heap_init: At 3FFBDB5C len 00000004 (0 KiB): DRAM
< I (339) heap_init: At 3FFD1EB0 len 0000E150 (56 KiB): DRAM
< I (345) heap_init: At 3FFE0440 len 00003AE0 (14 KiB): D/IRAM
< I (351) heap_init: At 3FFE4350 len 0001BCB0 (111 KiB): D/IRAM
< I (358) heap_init: At 40092734 len 0000D8CC (54 KiB): IRAM
< I (364) cpu_start: Pro cpu start user code
< I (158) cpu_start: Starting scheduler on PRO CPU.
---
> I (337) heap_init: Initializing. RAM available for dynamic allocation:
> I (344) heap_init: At 3FFAFF10 len 000000F0 (0 KiB): DRAM
> I (350) heap_init: At 3FFB7468 len 00000B98 (2 KiB): DRAM
> I (356) heap_init: At 3FFB9A20 len 00004108 (16 KiB): DRAM
> I (362) heap_init: At 3FFBDB5C len 00000004 (0 KiB): DRAM
> I (369) heap_init: At 3FFD4BA0 len 0000B460 (45 KiB): DRAM
> I (375) heap_init: At 3FFE0440 len 00003AE0 (14 KiB): D/IRAM
> I (381) heap_init: At 3FFE4350 len 0001BCB0 (111 KiB): D/IRAM
> I (387) heap_init: At 40094184 len 0000BE7C (47 KiB): IRAM
> I (394) cpu_start: Pro cpu start user code
> I (412) spi_flash: detected chip: generic
> I (412) spi_flash: flash io: dio
> W (413) spi_flash: Detected size(4096k) larger than the size in the binary image header(2048k). Using the size in the binary image header.
> I (423) cpu_start: Starting scheduler on PRO CPU.
56,108c62,123
< [00:00:00.160] LOG -- btstack_run_loop_freertos.c.260: run loop task 0x3ffbc5d8
< [00:00:00.167] LOG -- btstack_run_loop_freertos.c.263: run loop init, queue item size 8
< [00:00:00.175] LOG -- main.c.272: transport_register_packet_handler
< [00:00:00.197] LOG -- btstack_tlv.c.48: TLV Instance 0x3f409f60
< [00:00:00.198] LOG -- btstack_tlv_esp32.c.54: tag 42544400 -> 42544400
< [00:00:00.198] LOG -- btstack_tlv_esp32.c.68: read tag 42544400
< [00:00:00.204] LOG -- btstack_tlv_esp32.c.54: tag 42544401 -> 42544401
< [00:00:00.210] LOG -- btstack_tlv_esp32.c.68: read tag 42544401
< [00:00:00.216] LOG -- btstack_tlv_esp32.c.54: tag 42544402 -> 42544402
< [00:00:00.222] LOG -- btstack_tlv_esp32.c.68: read tag 42544402
< [00:00:00.228] LOG -- btstack_tlv_esp32.c.54: tag 42544403 -> 42544403
< [00:00:00.234] LOG -- btstack_tlv_esp32.c.68: read tag 42544403
< [00:00:00.240] LOG -- btstack_tlv_esp32.c.54: tag 42544404 -> 42544404
< [00:00:00.246] LOG -- btstack_tlv_esp32.c.68: read tag 42544404
< [00:00:00.251] LOG -- btstack_tlv_esp32.c.54: tag 42544405 -> 42544405
< [00:00:00.258] LOG -- btstack_tlv_esp32.c.68: read tag 42544405
< [00:00:00.263] LOG -- btstack_tlv_esp32.c.54: tag 42544406 -> 42544406
< [00:00:00.270] LOG -- btstack_tlv_esp32.c.68: read tag 42544406
< [00:00:00.275] LOG -- btstack_tlv_esp32.c.54: tag 42544407 -> 42544407
< [00:00:00.281] LOG -- btstack_tlv_esp32.c.68: read tag 42544407
< [00:00:00.287] LOG -- btstack_tlv_esp32.c.54: tag 42544408 -> 42544408
< [00:00:00.293] LOG -- btstack_tlv_esp32.c.68: read tag 42544408
< [00:00:00.299] LOG -- btstack_tlv_esp32.c.54: tag 42544409 -> 42544409
< [00:00:00.305] LOG -- btstack_tlv_esp32.c.68: read tag 42544409
< [00:00:00.311] LOG -- btstack_tlv_esp32.c.54: tag 4254440a -> 4254440A
< [00:00:00.317] LOG -- btstack_tlv_esp32.c.68: read tag 4254440A
< [00:00:00.323] LOG -- btstack_tlv_esp32.c.54: tag 4254440b -> 4254440B
< [00:00:00.329] LOG -- btstack_tlv_esp32.c.68: read tag 4254440B
< [00:00:00.335] LOG -- btstack_tlv_esp32.c.54: tag 4254440c -> 4254440C
< [00:00:00.341] LOG -- btstack_tlv_esp32.c.68: read tag 4254440C
< [00:00:00.347] LOG -- btstack_tlv_esp32.c.54: tag 4254440d -> 4254440D
< [00:00:00.353] LOG -- btstack_tlv_esp32.c.68: read tag 4254440D
< [00:00:00.358] LOG -- btstack_tlv_esp32.c.54: tag 4254440e -> 4254440E
< [00:00:00.365] LOG -- btstack_tlv_esp32.c.68: read tag 4254440E
< [00:00:00.370] LOG -- btstack_tlv_esp32.c.54: tag 4254440f -> 4254440F
< [00:00:00.377] LOG -- btstack_tlv_esp32.c.68: read tag 4254440F
< [00:00:00.382] LOG -- le_device_db_tlv.c.161: num valid le device entries 0
< I (389) main.cpp: btstack_main
< I (395) main.cpp: queue created
< [00:00:00.397] LOG -- rfcomm.c.2443: RFCOMM_REGISTER_SERVICE channel #4 mtu 65535 flow_control 0 credits 10
< [00:00:00.406] LOG -- l2cap.c.3511: L2CAP_REGISTER_SERVICE psm 0x3 mtu 65535
< [00:00:00.413] LOG -- l2cap.c.3511: L2CAP_REGISTER_SERVICE psm 0x1 mtu 65535
< [00:00:00.420] LOG -- hci.c.2931: hci_power_control: 1, current mode 0I (420) OUTPUT: output_task started
< I (430) OUTPUT: GPIO is configured
<
< [00:00:00.434] LOG -- main.c.204: transport_init
< [00:00:00.438] LOG -- main.c.220: transport_open
< I (443) BTDM_INIT: BT controller compile version [d53bd19]
< I (449) system_api: Base MAC address is not set, read default base MAC address from BLK0 of EFUSE
< I (527) phy: phy_version: 4008, 544f89f, Jan 24 2019, 14:54:06, 0, 0
< [00:00:00.842] LOG -- main.c.251: transport: configure SCO over HCI, result 0x0000
< [00:00:00.842] LOG -- hci.c.4063: BTSTACK_EVENT_STATE 1
< I (844) main.cpp: sta_mac=a4:cf:12:6c:2d:a4
---
> [00:00:00.441] LOG -- btstack_run_loop_freertos.c.260: run loop task 0x3ffbc6f8
> [00:00:00.448] LOG -- btstack_run_loop_freertos.c.263: run loop init, queue item size 8
> [00:00:00.456] LOG -- main.c.273: transport_register_packet_handler
> [00:00:00.469] LOG -- btstack_tlv.c.48: TLV Instance 0x3f4056d4
> [00:00:00.470] LOG -- btstack_tlv_esp32.c.54: tag 42544400 -> 42544400
> [00:00:00.473] LOG -- btstack_tlv_esp32.c.68: read tag 42544400
> [00:00:00.479] LOG -- btstack_tlv_esp32.c.54: tag 42544401 -> 42544401
> [00:00:00.485] LOG -- btstack_tlv_esp32.c.68: read tag 42544401
> [00:00:00.491] LOG -- btstack_tlv_esp32.c.54: tag 42544402 -> 42544402
> [00:00:00.497] LOG -- btstack_tlv_esp32.c.68: read tag 42544402
> [00:00:00.503] LOG -- btstack_tlv_esp32.c.54: tag 42544403 -> 42544403
> [00:00:00.509] LOG -- btstack_tlv_esp32.c.68: read tag 42544403
> [00:00:00.515] LOG -- btstack_tlv_esp32.c.54: tag 42544404 -> 42544404
> [00:00:00.521] LOG -- btstack_tlv_esp32.c.68: read tag 42544404
> [00:00:00.527] LOG -- btstack_tlv_esp32.c.54: tag 42544405 -> 42544405
> [00:00:00.533] LOG -- btstack_tlv_esp32.c.68: read tag 42544405
> [00:00:00.538] LOG -- btstack_tlv_esp32.c.54: tag 42544406 -> 42544406
> [00:00:00.545] LOG -- btstack_tlv_esp32.c.68: read tag 42544406
> [00:00:00.550] LOG -- btstack_tlv_esp32.c.54: tag 42544407 -> 42544407
> [00:00:00.557] LOG -- btstack_tlv_esp32.c.68: read tag 42544407
> [00:00:00.562] LOG -- btstack_tlv_esp32.c.54: tag 42544408 -> 42544408
> [00:00:00.568] LOG -- btstack_tlv_esp32.c.68: read tag 42544408
> [00:00:00.574] LOG -- btstack_tlv_esp32.c.54: tag 42544409 -> 42544409
> [00:00:00.580] LOG -- btstack_tlv_esp32.c.68: read tag 42544409
> [00:00:00.586] LOG -- btstack_tlv_esp32.c.54: tag 4254440a -> 4254440A
> [00:00:00.592] LOG -- btstack_tlv_esp32.c.68: read tag 4254440A
> [00:00:00.598] LOG -- btstack_tlv_esp32.c.54: tag 4254440b -> 4254440B
> [00:00:00.604] LOG -- btstack_tlv_esp32.c.68: read tag 4254440B
> [00:00:00.610] LOG -- btstack_tlv_esp32.c.54: tag 4254440c -> 4254440C
> [00:00:00.616] LOG -- btstack_tlv_esp32.c.68: read tag 4254440C
> [00:00:00.622] LOG -- btstack_tlv_esp32.c.54: tag 4254440d -> 4254440D
> [00:00:00.628] LOG -- btstack_tlv_esp32.c.68: read tag 4254440D
> [00:00:00.634] LOG -- btstack_tlv_esp32.c.54: tag 4254440e -> 4254440E
> [00:00:00.640] LOG -- btstack_tlv_esp32.c.68: read tag 4254440E
> [00:00:00.646] LOG -- btstack_tlv_esp32.c.54: tag 4254440f -> 4254440F
> [00:00:00.652] LOG -- btstack_tlv_esp32.c.68: read tag 4254440F
> [00:00:00.657] LOG -- le_device_db_tlv.c.161: num valid le device entries 0
> I (664) main.c: btstack_main
> [00:00:00.668] LOG -- rfcomm.c.2443: RFCOMM_REGISTER_SERVICE channel #4 mtu 65535 flow_control 0 credits 10
> [00:00:00.677] LOG -- l2cap.c.3511: L2CAP_REGISTER_SERVICE psm 0x3 mtu 65535
> [00:00:00.684] LOG -- l2cap.c.3511: L2CAP_REGISTER_SERVICE psm 0x1 mtu 65535
> I (691) OUTPUT: output_task started
> I (691) alexa.c: timer_task started
> I (696) gpio: GPIO[12]| InputEn: 0| OutputEn: 1| OpenDrain: 0| Pullup: 0| Pulldown: 1| Intr:0
> I (709) gpio: GPIO[13]| InputEn: 0| OutputEn: 1| OpenDrain: 0| Pullup: 0| Pulldown: 1| Intr:0
> I (718) gpio: GPIO[14]| InputEn: 0| OutputEn: 1| OpenDrain: 0| Pullup: 0| Pulldown: 1| Intr:0
> I (727) OUTPUT: GPIO is configured
> I (731) OUTPUT: output: 0 0 0
> [00:00:00.735] LOG -- hci.c.2931: hci_power_control: 1, current mode 0
> [00:00:00.741] LOG -- main.c.205: transport_init
> [00:00:00.745] LOG -- main.c.221: transport_open
> I (750) BTDM_INIT: BT controller compile version [2f7e614]
> I (756) system_api: Base MAC address is not set, read default base MAC address from BLK0 of EFUSE
> I (799) SPI: Pins used: miso=25, mosi=23, sck=19, cs=22
> I (800) SPI: display device added to spi bus (1)
> I (800) SPI: attached display device, speed=8000000
> I (805) SPI: bus uses native pins: false
> I (809) SPI: display init...
> I (875) phy: phy_version: 4102, 2fa7a43, Jul 15 2019, 13:06:06, 0, 0
> [00:00:01.191] LOG -- main.c.252: transport: configure SCO over HCI, result 0x0000
> [00:00:01.191] LOG -- hci.c.4063: BTSTACK_EVENT_STATE 1
> I (1196) main.c: sta_mac=a4:cf:12:6c:2d:a4
111,125c126,140
< [00:00:00.854] LOG -- hci.c.1975: Manufacturer: 0x0060
< [00:00:00.859] LOG -- hci.c.1889: local name:
< [00:00:00.860] LOG -- hci.c.1648: Received local name, need baud change 0
< [00:00:00.870] LOG -- hci.c.1986: Local supported commands summary 0x3f
< [00:00:00.876] LOG -- hci.c.1937: Local Address, Status: 0x00: Addr: A4:CF:12:6C:2D:A6
< [00:00:00.884] LOG -- hci.c.1906: hci_read_buffer_size: ACL size module 1021 -> used 1021, count 9 / SCO size 255, count 4
< [00:00:00.894] LOG -- hci.c.1964: Packet types cc18, eSCO 1
< [00:00:00.896] LOG -- hci.c.1967: BR/EDR support 1, LE support 1
< [00:00:00.932] LOG -- hci.c.4181: BTSTACK_EVENT_DISCOVERABLE_ENABLED 1
< [00:00:00.934] LOG -- hci.c.1917: hci_le_read_buffer_size: size 251, count 10
< [00:00:00.935] LOG -- hci.c.1756: Supported commands 30
< [00:00:00.940] LOG -- hci.c.1924: hci_le_read_maximum_data_length: tx octets 251, tx time 2120 us
< [00:00:00.954] LOG -- hci.c.1930: hci_le_read_white_list_size: size 12
< [00:00:00.958] LOG -- hci.c.1512: hci_init_done -> HCI_STATE_WORKING
< [00:00:00.960] LOG -- hci.c.4063: BTSTACK_EVENT_STATE 2
---
> [00:00:01.203] LOG -- hci.c.1975: Manufacturer: 0x0060
> [00:00:01.206] LOG -- hci.c.1889: local name:
> [00:00:01.209] LOG -- hci.c.1648: Received local name, need baud change 0
> [00:00:01.218] LOG -- hci.c.1986: Local supported commands summary 0x3f
> [00:00:01.222] LOG -- hci.c.1937: Local Address, Status: 0x00: Addr: A4:CF:12:6C:2D:A6
> [00:00:01.232] LOG -- hci.c.1906: hci_read_buffer_size: ACL size module 1021 -> used 1021, count 9 / SCO size 255, count 4
> [00:00:01.241] LOG -- hci.c.1964: Packet types cc18, eSCO 1
> [00:00:01.245] LOG -- hci.c.1967: BR/EDR support 1, LE support 1
> [00:00:01.272] LOG -- hci.c.4181: BTSTACK_EVENT_DISCOVERABLE_ENABLED 1
> [00:00:01.274] LOG -- hci.c.1917: hci_le_read_buffer_size: size 251, count 10
> [00:00:01.275] LOG -- hci.c.1756: Supported commands 30
> [00:00:01.281] LOG -- hci.c.1924: hci_le_read_maximum_data_length: tx octets 251, tx time 2120 us
> [00:00:01.292] LOG -- hci.c.1930: hci_le_read_white_list_size: size 12
> [00:00:01.297] LOG -- hci.c.1512: hci_init_done -> HCI_STATE_WORKING
> [00:00:01.301] LOG -- hci.c.4063: BTSTACK_EVENT_STATE 2
127,133c142,302
< [00:00:00.968] LOG -- l2cap.c.1885: L2CAP_CREATE_CHANNEL addr 74:75:48:D5:32:E3 psm 0x1 mtu 1691 -> local mtu 1691
< [00:00:00.978] LOG -- l2cap.c.1864: channel 0x3ffdc544, local_cid 0x0040
< [00:00:00.984] LOG -- hci.c.3762: Create_connection to 74:75:48:D5:32:E3
< [00:00:00.990] LOG -- hci.c.186: create_connection_for_addr 74:75:48:D5:32:E3, type ff
< [00:00:00.998] LOG -- hci.c.3774: conn state 0
< [00:00:01.005] LOG -- hci.c.2016: command status (create connection), status 0, connection 0x3ffdcd3c, addr 74:75:48:D5:32:E3, type ff
< I (1934) OUTPUT: no queue 0
---
> [00:00:01.308] LOG -- l2cap.c.1885: L2CAP_CREATE_CHANNEL addr 74:75:48:D5:32:E3 psm 0x1 mtu 1691 -> local mtu 1691
> [00:00:01.318] LOG -- l2cap.c.1864: channel 0x3ffbb114, local_cid 0x0040
> [00:00:01.325] LOG -- hci.c.3762: Create_connection to 74:75:48:D5:32:E3
> [00:00:01.331] LOG -- hci.c.186: create_connection_for_addr 74:75:48:D5:32:E3, type ff
> [00:00:01.338] LOG -- hci.c.3774: conn state 0
> [00:00:01.343] LOG -- hci.c.2016: command status (create connection), status 0, connection 0x3ffe436c, addr 74:75:48:D5:32:E3, type ff
> I (1614) SPI: ok
> I (1621) SPI: Max rd speed = 1000000
> I (1621) SPI: Changed speed to 26666666
> I (1735) OUTPUT: output: 0 0 0
> [00:00:01.739] LOG -- hci.c.2100: Connection_complete (status=0) 74:75:48:D5:32:E3
> [00:00:01.739] LOG -- hci.c.2113: New connection: handle 129, 74:75:48:D5:32:E3
> [00:00:01.744] LOG -- hci.c.4132: BTSTACK_EVENT_NR_CONNECTIONS_CHANGED 1
> [00:00:01.751] LOG -- l2cap.c.1794: connection complete con_handle 0081 - for channel 0x3ffbb114 cid 0x0040
> [00:00:01.761] LOG -- hci.c.2162: HCI_EVENT_READ_REMOTE_SUPPORTED_FEATURES_COMPLETE, bonding flags 6, eSCO 1
> [00:00:01.770] LOG -- l2cap.c.2217: remote supported features, channel 0x3ffbb114, cid 0040 - state 4
> [00:00:01.778] LOG -- l2cap.c.1822: l2cap received remote supported features, sec_level_0_allowed for psm 1 = 1
> [00:00:01.789] LOG -- l2cap.c.1100: l2cap_stop_rtx for local cid 0x40
> [00:00:01.794] LOG -- l2cap.c.1109: l2cap_start_rtx for local cid 0x40
> [00:00:01.823] LOG -- l2cap.c.2550: L2CAP signaling handler code 3, state 10
> [00:00:01.824] LOG -- l2cap.c.1100: l2cap_stop_rtx for local cid 0x40
> [00:00:01.826] LOG -- l2cap.c.1116: l2cap_start_ertx for local cid 0x40
> [00:00:01.832] LOG -- l2cap.c.1100: l2cap_stop_rtx for local cid 0x40
> [00:00:01.862] LOG -- l2cap.c.2550: L2CAP signaling handler code 3, state 10
> [00:00:01.862] LOG -- l2cap.c.1100: l2cap_stop_rtx for local cid 0x40
> [00:00:01.865] LOG -- l2cap.c.1100: l2cap_stop_rtx for local cid 0x40
> [00:00:01.870] LOG -- l2cap.c.1109: l2cap_start_rtx for local cid 0x40
> [00:00:01.877] LOG -- l2cap.c.2550: L2CAP signaling handler code 4, state 11
> [00:00:01.884] LOG -- l2cap.c.2550: L2CAP signaling handler code 5, state 11
> [00:00:01.890] LOG -- l2cap.c.1100: l2cap_stop_rtx for local cid 0x40
> [00:00:01.896] LOG -- l2cap.c.2481: l2cap_signaling_handle_configure_response
> [00:00:01.904] LOG -- l2cap.c.905: L2CAP_EVENT_CHANNEL_OPENED status 0x0 addr 74:75:48:D5:32:E3 handle 0x81 psm 0x1 local_cid 0x40 remote_cid 0x40 local_mtu 1691, remote_mtu 672, flush_timeout 0
> [00:00:01.966] LOG -- l2cap.c.1864: channel 0x3ffbb228, local_cid 0x0041
> [00:00:01.966] LOG -- hci.c.4266: gap_request_security_level requested level 0, planned level 0, current level 0
> [00:00:01.972] LOG -- hci.c.4163: hci_emit_security_level 0 for handle 81
> [00:00:01.978] LOG -- l2cap.c.2224: l2cap - security level update for handle 0x0081
> [00:00:01.985] LOG -- l2cap.c.2234: channel 0x3ffbb228, cid 0041 - state 5: actual 0 >= required 0?
> [00:00:01.994] LOG -- l2cap.c.939: L2CAP_EVENT_INCOMING_CONNECTION addr 74:75:48:D5:32:E3 handle 0x81 psm 0x1 local_cid 0x41 remote_cid 0x41
> [00:00:02.007] LOG -- l2cap.c.2345: L2CAP_ACCEPT_CONNECTION local_cid 0x41
> [00:00:02.013] LOG -- l2cap.c.2234: channel 0x3ffbb114, cid 0040 - state 12: actual 0 >= required 0?
> [00:00:02.022] LOG -- l2cap.c.1100: l2cap_stop_rtx for local cid 0x41
> [00:00:02.028] LOG -- l2cap.c.1109: l2cap_start_rtx for local cid 0x41
> [00:00:02.042] LOG -- l2cap.c.1921: L2CAP_DISCONNECT local_cid 0x40 reason 0x0
> [00:00:02.046] LOG -- l2cap.c.2550: L2CAP signaling handler code 4, state 11
> [00:00:02.049] LOG -- l2cap.c.2550: L2CAP signaling handler code 5, state 11
> [00:00:02.055] LOG -- l2cap.c.1100: l2cap_stop_rtx for local cid 0x41
> [00:00:02.061] LOG -- l2cap.c.2481: l2cap_signaling_handle_configure_response
> [00:00:02.068] LOG -- l2cap.c.905: L2CAP_EVENT_CHANNEL_OPENED status 0x0 addr 74:75:48:D5:32:E3 handle 0x81 psm 0x1 local_cid 0x41 remote_cid 0x41 local_mtu 1691, remote_mtu 672, flush_timeout 0
> [00:00:02.085] LOG -- l2cap.c.2550: L2CAP signaling handler code 7, state 13
> [00:00:02.092] LOG -- l2cap.c.933: L2CAP_EVENT_CHANNEL_CLOSED local_cid 0x40
> [00:00:02.098] LOG -- sdp_client.c.472: SDP Client disconnected.
> I (2104) main.c: SDP query done.
> [00:00:02.108] LOG -- l2cap.c.1100: l2cap_stop_rtx for local cid 0x40
> [00:00:02.145] LOG -- l2cap.c.2550: L2CAP signaling handler code 6, state 12
> [00:00:02.145] LOG -- l2cap.c.933: L2CAP_EVENT_CHANNEL_CLOSED local_cid 0x41
> [00:00:02.147] LOG -- l2cap.c.1100: l2cap_stop_rtx for local cid 0x41
> I (2735) OUTPUT: output: 0 0 0
> I (3735) OUTPUT: output: 0 0 0
> I (4735) OUTPUT: output: 0 0 0
> [00:00:04.784] LOG -- hci.c.2169: HCI_EVENT_LINK_KEY_REQUEST
> [00:00:04.784] LOG -- hci.c.3467: responding to link key request
> [00:00:04.784] LOG -- btstack_tlv_esp32.c.54: tag 42544c00 -> 42544C00
> [00:00:04.790] LOG -- btstack_tlv_esp32.c.68: read tag 42544C00
> [00:00:04.796] LOG -- btstack_tlv_esp32.c.54: tag 42544c01 -> 42544C01
> [00:00:04.802] LOG -- btstack_tlv_esp32.c.68: read tag 42544C01
> [00:00:04.808] LOG -- btstack_tlv_esp32.c.54: tag 42544c02 -> 42544C02
> [00:00:04.814] LOG -- btstack_tlv_esp32.c.68: read tag 42544C02
> [00:00:04.819] LOG -- btstack_tlv_esp32.c.54: tag 42544c03 -> 42544C03
> [00:00:04.826] LOG -- btstack_tlv_esp32.c.68: read tag 42544C03
> [00:00:04.831] LOG -- btstack_tlv_esp32.c.54: tag 42544c04 -> 42544C04
> [00:00:04.838] LOG -- btstack_tlv_esp32.c.68: read tag 42544C04
> [00:00:04.843] LOG -- btstack_tlv_esp32.c.54: tag 42544c05 -> 42544C05
> [00:00:04.849] LOG -- btstack_tlv_esp32.c.68: read tag 42544C05
> [00:00:04.855] LOG -- btstack_tlv_esp32.c.54: tag 42544c06 -> 42544C06
> [00:00:04.861] LOG -- btstack_tlv_esp32.c.68: read tag 42544C06
> [00:00:04.867] LOG -- btstack_tlv_esp32.c.54: tag 42544c07 -> 42544C07
> [00:00:04.873] LOG -- btstack_tlv_esp32.c.68: read tag 42544C07
> [00:00:04.879] LOG -- btstack_tlv_esp32.c.54: tag 42544c08 -> 42544C08
> [00:00:04.885] LOG -- btstack_tlv_esp32.c.68: read tag 42544C08
> [00:00:04.891] LOG -- btstack_tlv_esp32.c.54: tag 42544c09 -> 42544C09
> [00:00:04.897] LOG -- btstack_tlv_esp32.c.68: read tag 42544C09
> [00:00:04.903] LOG -- btstack_tlv_esp32.c.54: tag 42544c0a -> 42544C0A
> [00:00:04.909] LOG -- btstack_tlv_esp32.c.68: read tag 42544C0A
> [00:00:04.915] LOG -- btstack_tlv_esp32.c.54: tag 42544c0b -> 42544C0B
> [00:00:04.921] LOG -- btstack_tlv_esp32.c.68: read tag 42544C0B
> [00:00:04.927] LOG -- btstack_tlv_esp32.c.54: tag 42544c0c -> 42544C0C
> [00:00:04.933] LOG -- btstack_tlv_esp32.c.68: read tag 42544C0C
> [00:00:04.938] LOG -- btstack_tlv_esp32.c.54: tag 42544c0d -> 42544C0D
> [00:00:04.945] LOG -- btstack_tlv_esp32.c.68: read tag 42544C0D
> [00:00:04.950] LOG -- btstack_tlv_esp32.c.54: tag 42544c0e -> 42544C0E
> [00:00:04.956] LOG -- btstack_tlv_esp32.c.68: read tag 42544C0E
> [00:00:04.962] LOG -- btstack_tlv_esp32.c.54: tag 42544c0f -> 42544C0F
> [00:00:04.968] LOG -- btstack_tlv_esp32.c.68: read tag 42544C0F
> [00:00:04.975] LOG -- btstack_link_key_db_tlv.c.95: tag 42544c0f, addr 74:75:48:D5:32:E3
> [00:00:05.093] LOG -- hci.c.4163: hci_emit_security_level 2 for handle 81
> [00:00:05.093] LOG -- l2cap.c.2224: l2cap - security level update for handle 0x0081
> [00:00:05.101] LOG -- l2cap.c.1864: channel 0x3ffbb114, local_cid 0x0042
> [00:00:05.102] LOG -- hci.c.4266: gap_request_security_level requested level 2, planned level 0, current level 2
> [00:00:05.112] LOG -- hci.c.4163: hci_emit_security_level 2 for handle 81
> [00:00:05.119] LOG -- l2cap.c.2224: l2cap - security level update for handle 0x0081
> [00:00:05.126] LOG -- l2cap.c.2234: channel 0x3ffbb114, cid 0042 - state 5: actual 2 >= required 2?
> [00:00:05.135] LOG -- l2cap.c.939: L2CAP_EVENT_INCOMING_CONNECTION addr 74:75:48:D5:32:E3 handle 0x81 psm 0x3 local_cid 0x42 remote_cid 0x40
> [00:00:05.147] LOG -- rfcomm.c.304: rfcomm_max_frame_size_for_l2cap_mtu: 1691 -> 1686
> [00:00:05.155] LOG -- rfcomm.c.1004: L2CAP_EVENT_INCOMING_CONNECTION (l2cap_cid 0x42) for BLUETOOTH_PROTOCOL_RFCOMM => accept
> [00:00:05.166] LOG -- l2cap.c.2345: L2CAP_ACCEPT_CONNECTION local_cid 0x42
> [00:00:05.173] LOG -- l2cap.c.1100: l2cap_stop_rtx for local cid 0x42
> [00:00:05.179] LOG -- l2cap.c.1109: l2cap_start_rtx for local cid 0x42
> [00:00:05.185] LOG -- l2cap.c.2550: L2CAP signaling handler code 4, state 11
> [00:00:05.192] LOG -- l2cap.c.2401: Remote MTU 1013
> [00:00:05.196] LOG -- l2cap.c.2550: L2CAP signaling handler code 5, state 11
> [00:00:05.203] LOG -- l2cap.c.1100: l2cap_stop_rtx for local cid 0x42
> [00:00:05.209] LOG -- l2cap.c.2481: l2cap_signaling_handle_configure_response
> [00:00:05.216] LOG -- l2cap.c.905: L2CAP_EVENT_CHANNEL_OPENED status 0x0 addr 74:75:48:D5:32:E3 handle 0x81 psm 0x3 local_cid 0x42 remote_cid 0x40 local_mtu 1691, remote_mtu 1013, flush_timeout 0
> [00:00:05.233] LOG -- rfcomm.c.1031: L2CAP_EVENT_CHANNEL_OPENED for BLUETOOTH_PROTOCOL_RFCOMM, status 0
> [00:00:05.242] LOG -- rfcomm.c.304: rfcomm_max_frame_size_for_l2cap_mtu: 1691 -> 1686
> [00:00:05.250] LOG -- rfcomm.c.1150: Received SABM #0
> [00:00:05.255] LOG -- rfcomm.c.1290: Sending UA #0
> [00:00:05.259] LOG -- rfcomm.c.868: Multiplexer up and running
> [00:00:05.285] LOG -- rfcomm.c.1566: Received UIH Parameter Negotiation Command for #8, credits 7
> [00:00:05.285] LOG -- rfcomm.c.425: rfcomm_channel_create for service 0x3ffbdb0c, channel 4 --- list of channels:
> [00:00:05.293] LOG -- rfcomm.c.1886: -> Inform app
> [00:00:05.297] LOG -- rfcomm.c.173: RFCOMM_EVENT_INCOMING_CONNECTION addr 74:75:48:D5:32:E3 channel #4 cid 0x01
> I (5307) main.c: Accepting RFCOMM connection from 74:75:48:D5:32:E3, cid: 1
> [00:00:05.315] LOG -- rfcomm.c.2502: RFCOMM_ACCEPT_CONNECTION cid 0x01
> [00:00:05.321] LOG -- rfcomm.c.1914: Sending UIH Parameter Negotiation Respond for #8
> [00:00:05.329] LOG -- rfcomm.c.1703: rfcomm_channel_ready_for_incoming_dlc_setup state var 0003
> [00:00:05.347] LOG -- rfcomm.c.1532: Received SABM #8
> [00:00:05.348] LOG -- rfcomm.c.1918: Sending UA #8
> [00:00:05.348] LOG -- rfcomm.c.1703: rfcomm_channel_ready_for_incoming_dlc_setup state var 000b
> [00:00:05.354] LOG -- rfcomm.c.1923: Incomping setup done, requesting send MSC CMD and send Credits
> [00:00:05.364] LOG -- rfcomm.c.1585: Received MSC CMD for #8,
> [00:00:05.369] LOG -- rfcomm.c.1695: rfcomm_channel_ready_for_open state 8, flags needed 0020, current 1c1b, rf credits 7
> [00:00:05.380] LOG -- rfcomm.c.1846: Sending MSC RSP for #8
> [00:00:05.385] LOG -- rfcomm.c.2009: Sending MSC CMD for #8
> [00:00:05.390] LOG -- rfcomm.c.1695: rfcomm_channel_ready_for_open state 8, flags needed 0020, current 701b, rf credits 7
> [00:00:05.401] LOG -- rfcomm.c.1592: Received MSC RSP for #8
> [00:00:05.406] LOG -- rfcomm.c.1695: rfcomm_channel_ready_for_open state 8, flags needed 0020, current 703b, rf credits 7
> [00:00:05.417] LOG -- rfcomm.c.1372: RFCOMM data UIH_PF, new credits channel 0x01: 33, now 40
> [00:00:05.425] LOG -- rfcomm.c.1695: rfcomm_channel_ready_for_open state 8, flags needed 0020, current 703b, rf credits 40
> [00:00:05.436] LOG -- rfcomm.c.2016: Providing credits for #8
> [00:00:05.442] LOG -- rfcomm.c.1695: rfcomm_channel_ready_for_open state 8, flags needed 0020, current e03b, rf credits 40
> [00:00:05.452] LOG -- rfcomm.c.1335: rfcomm_channel_opened!
> [00:00:05.457] LOG -- rfcomm.c.191: RFCOMM_EVENT_CHANNEL_OPENED status 0x0 addr 74:75:48:D5:32:E3 handle 0x81 channel #4 cid 0x01 mtu 1008
> I (5470) main.c: Got RFCOMM data on channel 1
> I (5475) main.c: Alexa Gadgets Toolkit packet, checksum: 09 db
> I (5481) alexa.c: Parsing Directive
> I (5486) alexa.c: name = Discover, namespace=Alexa.Discovery
> scope type:
> scope token:
> I (5494) alexa.c: Creating discover response event
> I (5501) main.c: rfcomm_request_can_send_now_event
> I (5506) main.c: RFCOMM_EVENT_CAN_SEND_NOW
> I (5735) OUTPUT: output: 0 0 0
> I (6122) main.c: Got RFCOMM data on channel 1
> I (6123) main.c: Alexa Gadgets Toolkit packet, checksum: 18 33
> I (6123) alexa.c: Parsing Directive
> I (6127) alexa.c: name = StateUpdate, namespace=Alexa.Gadget.StateListener
> state name: timeinfo
> state value: 2019-08-17T22:27:26-07:00
> I (6140) alexa.c: time info: 119 7 17 22 27 26, 1566080846
> I (6735) OUTPUT: output: 0 0 0
schoch@LAPTOP-AB698MBS:~/diff_test$ vi A
schoch@LAPTOP-AB698MBS:~/diff_test$ vi a
schoch@LAPTOP-AB698MBS:~/diff_test$
schoch@LAPTOP-AB698MBS:~/diff_test$
schoch@LAPTOP-AB698MBS:~/diff_test$
schoch@LAPTOP-AB698MBS:~/diff_test$
schoch@LAPTOP-AB698MBS:~/diff_test$
schoch@LAPTOP-AB698MBS:~/diff_test$
schoch@LAPTOP-AB698MBS:~/diff_test$
schoch@LAPTOP-AB698MBS:~/diff_test$
schoch@LAPTOP-AB698MBS:~/diff_test$
schoch@LAPTOP-AB698MBS:~/diff_test$
schoch@LAPTOP-AB698MBS:~/diff_test$
schoch@LAPTOP-AB698MBS:~/diff_test$
schoch@LAPTOP-AB698MBS:~/diff_test$
schoch@LAPTOP-AB698MBS:~/diff_test$
schoch@LAPTOP-AB698MBS:~/diff_test$
schoch@LAPTOP-AB698MBS:~/diff_test$
schoch@LAPTOP-AB698MBS:~/diff_test$
schoch@LAPTOP-AB698MBS:~/diff_test$
schoch@LAPTOP-AB698MBS:~/diff_test$
schoch@LAPTOP-AB698MBS:~/diff_test$
schoch@LAPTOP-AB698MBS:~/diff_test$
schoch@LAPTOP-AB698MBS:~/diff_test$
schoch@LAPTOP-AB698MBS:~/diff_test$
schoch@LAPTOP-AB698MBS:~/diff_test$
schoch@LAPTOP-AB698MBS:~/diff_test$ diff a b
5,10c5,10
< load:0x3fff001c,len:6264
< load:0x40078000,len:10180
< load:0x40080400,len:6712
< entry 0x40080768
< I (28) boot: ESP-IDF v3.2.2-dirty 2nd stage bootloader
< I (28) boot: compile time 18:26:31
---
> load:0x3fff001c,len:6552
> load:0x40078000,len:11368
> load:0x40080400,len:6692
> entry 0x40080770
> I (28) boot: ESP-IDF v4.0-dev-1443-g39f090a 2nd stage bootloader
> I (28) boot: compile time 22:20:19
12,27c12,24
< I (33) boot: SPI Speed : 40MHz
< I (37) boot: SPI Mode : DIO
< I (41) boot: SPI Flash Size : 4MB
< I (45) boot: Partition Table:
< I (49) boot: ## Label Usage Type ST Offset Length
< I (56) boot: 0 nvs WiFi data 01 02 00009000 00005000
< I (64) boot: 1 otadata OTA data 01 00 0000e000 00002000
< I (71) boot: 2 app0 OTA app 00 10 00010000 00140000
< I (79) boot: 3 app1 OTA app 00 11 00150000 00140000
< I (86) boot: 4 spiffs Unknown data 01 82 00290000 00170000
< I (94) boot: End of partition table
< I (98) boot: No factory image, trying OTA 0
< I (103) esp_image: segment 0: paddr=0x00010020 vaddr=0x3f400020 size=0x14800 ( 83968) map
< I (141) esp_image: segment 1: paddr=0x00024828 vaddr=0x3ffbdb60 size=0x02a04 ( 10756) load
< I (146) esp_image: segment 2: paddr=0x00027234 vaddr=0x40080000 size=0x00400 ( 1024) load
< 0x40080000: _WindowOverflow4 at /home/oldidf/esp-idf-v3.2.2/components/freertos/xtensa_vectors.S:1779
---
> I (34) boot: SPI Speed : 40MHz
> I (38) boot: SPI Mode : DIO
> I (42) boot: SPI Flash Size : 2MB
> I (46) boot: Partition Table:
> I (50) boot: ## Label Usage Type ST Offset Length
> I (57) boot: 0 nvs WiFi data 01 02 00009000 00006000
> I (65) boot: 1 phy_init RF data 01 01 0000f000 00001000
> I (72) boot: 2 factory factory app 00 00 00010000 00100000
> I (80) boot: End of partition table
> I (84) esp_image: segment 0: paddr=0x00010020 vaddr=0x3f400020 size=0x12f68 ( 77672) map
> I (121) esp_image: segment 1: paddr=0x00022f90 vaddr=0x3ffbdb60 size=0x05b1c ( 23324) load
> I (130) esp_image: segment 2: paddr=0x00028ab4 vaddr=0x40080000 size=0x00400 ( 1024) load
> 0x40080000: _WindowOverflow4 at /home/schoch/dev/esp-idf/components/freertos/xtensa_vectors.S:1778
29,30c26,27
< I (148) esp_image: segment 3: paddr=0x0002763c vaddr=0x40080400 size=0x089d4 ( 35284) load
< I (171) esp_image: segment 4: paddr=0x00030018 vaddr=0x400d0018 size=0x4193c (268604) map
---
> I (131) esp_image: segment 3: paddr=0x00028ebc vaddr=0x40080400 size=0x07154 ( 29012) load
> I (151) esp_image: segment 4: paddr=0x00030018 vaddr=0x400d0018 size=0x45ce4 (285924) map
33,34c30,31
< I (266) esp_image: segment 5: paddr=0x0007195c vaddr=0x40088dd4 size=0x09960 ( 39264) load
< 0x40088dd4: r_ld_fm_clk_isr at ??:?
---
> I (253) esp_image: segment 5: paddr=0x00075d04 vaddr=0x40087554 size=0x0cc30 ( 52272) load
> 0x40087554: r_ld_fm_sket_isr at ??:?
36,40c33,43
< I (293) boot: Loaded app from partition at offset 0x10000
< I (293) boot: Disabling RNG early entropy source...
< I (294) cpu_start: Pro cpu up.
< I (297) cpu_start: Starting app cpu, entry point is 0x4008102c
< 0x4008102c: call_start_cpu1 at /home/oldidf/esp-idf-v3.2.2/components/esp32/cpu_start.c:246
---
> I (289) boot: Loaded app from partition at offset 0x10000
> I (289) boot: Disabling RNG early entropy source...
> I (289) cpu_start: Pro cpu up.
> I (293) cpu_start: Application information:
> I (298) cpu_start: Project name: volkhin_nixie_timer
> I (304) cpu_start: App version: b6aeb21
> I (309) cpu_start: Compile time: Aug 17 2019 22:20:59
> I (315) cpu_start: ELF file SHA256: ecbc3de4d0867ab6...
> I (321) cpu_start: ESP-IDF: v4.0-dev-1443-g39f090a
> I (327) cpu_start: Starting app cpu, entry point is 0x400812e0
> 0x400812e0: call_start_cpu1 at /home/schoch/dev/esp-idf/components/esp32/cpu_start.c:281
43,53c46,59
< I (308) heap_init: Initializing. RAM available for dynamic allocation:
< I (314) heap_init: At 3FFAFF10 len 000000F0 (0 KiB): DRAM
< I (320) heap_init: At 3FFB7468 len 00000B98 (2 KiB): DRAM
< I (327) heap_init: At 3FFB9A20 len 00004108 (16 KiB): DRAM
< I (333) heap_init: At 3FFBDB5C len 00000004 (0 KiB): DRAM
< I (339) heap_init: At 3FFD1EB0 len 0000E150 (56 KiB): DRAM
< I (345) heap_init: At 3FFE0440 len 00003AE0 (14 KiB): D/IRAM
< I (351) heap_init: At 3FFE4350 len 0001BCB0 (111 KiB): D/IRAM
< I (358) heap_init: At 40092734 len 0000D8CC (54 KiB): IRAM
< I (364) cpu_start: Pro cpu start user code
< I (158) cpu_start: Starting scheduler on PRO CPU.
---
> I (337) heap_init: Initializing. RAM available for dynamic allocation:
> I (344) heap_init: At 3FFAFF10 len 000000F0 (0 KiB): DRAM
> I (350) heap_init: At 3FFB7468 len 00000B98 (2 KiB): DRAM
> I (356) heap_init: At 3FFB9A20 len 00004108 (16 KiB): DRAM
> I (362) heap_init: At 3FFBDB5C len 00000004 (0 KiB): DRAM
> I (369) heap_init: At 3FFD4BA0 len 0000B460 (45 KiB): DRAM
> I (375) heap_init: At 3FFE0440 len 00003AE0 (14 KiB): D/IRAM
> I (381) heap_init: At 3FFE4350 len 0001BCB0 (111 KiB): D/IRAM
> I (387) heap_init: At 40094184 len 0000BE7C (47 KiB): IRAM
> I (394) cpu_start: Pro cpu start user code
> I (412) spi_flash: detected chip: generic
> I (412) spi_flash: flash io: dio
> W (413) spi_flash: Detected size(4096k) larger than the size in the binary image header(2048k). Using the size in the binary image header.
> I (423) cpu_start: Starting scheduler on PRO CPU.
56,108c62,123
< [00:00:00.160] LOG -- btstack_run_loop_freertos.c.260: run loop task 0x3ffbc5d8
< [00:00:00.167] LOG -- btstack_run_loop_freertos.c.263: run loop init, queue item size 8
< [00:00:00.175] LOG -- main.c.272: transport_register_packet_handler
< [00:00:00.197] LOG -- btstack_tlv.c.48: TLV Instance 0x3f409f60
< [00:00:00.198] LOG -- btstack_tlv_esp32.c.54: tag 42544400 -> 42544400
< [00:00:00.198] LOG -- btstack_tlv_esp32.c.68: read tag 42544400
< [00:00:00.204] LOG -- btstack_tlv_esp32.c.54: tag 42544401 -> 42544401
< [00:00:00.210] LOG -- btstack_tlv_esp32.c.68: read tag 42544401
< [00:00:00.216] LOG -- btstack_tlv_esp32.c.54: tag 42544402 -> 42544402
< [00:00:00.222] LOG -- btstack_tlv_esp32.c.68: read tag 42544402
< [00:00:00.228] LOG -- btstack_tlv_esp32.c.54: tag 42544403 -> 42544403
< [00:00:00.234] LOG -- btstack_tlv_esp32.c.68: read tag 42544403
< [00:00:00.240] LOG -- btstack_tlv_esp32.c.54: tag 42544404 -> 42544404
< [00:00:00.246] LOG -- btstack_tlv_esp32.c.68: read tag 42544404
< [00:00:00.251] LOG -- btstack_tlv_esp32.c.54: tag 42544405 -> 42544405
< [00:00:00.258] LOG -- btstack_tlv_esp32.c.68: read tag 42544405
< [00:00:00.263] LOG -- btstack_tlv_esp32.c.54: tag 42544406 -> 42544406
< [00:00:00.270] LOG -- btstack_tlv_esp32.c.68: read tag 42544406
< [00:00:00.275] LOG -- btstack_tlv_esp32.c.54: tag 42544407 -> 42544407
< [00:00:00.281] LOG -- btstack_tlv_esp32.c.68: read tag 42544407
< [00:00:00.287] LOG -- btstack_tlv_esp32.c.54: tag 42544408 -> 42544408
< [00:00:00.293] LOG -- btstack_tlv_esp32.c.68: read tag 42544408
< [00:00:00.299] LOG -- btstack_tlv_esp32.c.54: tag 42544409 -> 42544409
< [00:00:00.305] LOG -- btstack_tlv_esp32.c.68: read tag 42544409
< [00:00:00.311] LOG -- btstack_tlv_esp32.c.54: tag 4254440a -> 4254440A
< [00:00:00.317] LOG -- btstack_tlv_esp32.c.68: read tag 4254440A
< [00:00:00.323] LOG -- btstack_tlv_esp32.c.54: tag 4254440b -> 4254440B
< [00:00:00.329] LOG -- btstack_tlv_esp32.c.68: read tag 4254440B
< [00:00:00.335] LOG -- btstack_tlv_esp32.c.54: tag 4254440c -> 4254440C
< [00:00:00.341] LOG -- btstack_tlv_esp32.c.68: read tag 4254440C
< [00:00:00.347] LOG -- btstack_tlv_esp32.c.54: tag 4254440d -> 4254440D
< [00:00:00.353] LOG -- btstack_tlv_esp32.c.68: read tag 4254440D
< [00:00:00.358] LOG -- btstack_tlv_esp32.c.54: tag 4254440e -> 4254440E
< [00:00:00.365] LOG -- btstack_tlv_esp32.c.68: read tag 4254440E
< [00:00:00.370] LOG -- btstack_tlv_esp32.c.54: tag 4254440f -> 4254440F
< [00:00:00.377] LOG -- btstack_tlv_esp32.c.68: read tag 4254440F
< [00:00:00.382] LOG -- le_device_db_tlv.c.161: num valid le device entries 0
< I (389) main.cpp: btstack_main
< I (395) main.cpp: queue created
< [00:00:00.397] LOG -- rfcomm.c.2443: RFCOMM_REGISTER_SERVICE channel #4 mtu 65535 flow_control 0 credits 10
< [00:00:00.406] LOG -- l2cap.c.3511: L2CAP_REGISTER_SERVICE psm 0x3 mtu 65535
< [00:00:00.413] LOG -- l2cap.c.3511: L2CAP_REGISTER_SERVICE psm 0x1 mtu 65535
< [00:00:00.420] LOG -- hci.c.2931: hci_power_control: 1, current mode 0I (420) OUTPUT: output_task started
< I (430) OUTPUT: GPIO is configured
<
< [00:00:00.434] LOG -- main.c.204: transport_init
< [00:00:00.438] LOG -- main.c.220: transport_open
< I (443) BTDM_INIT: BT controller compile version [d53bd19]
< I (449) system_api: Base MAC address is not set, read default base MAC address from BLK0 of EFUSE
< I (527) phy: phy_version: 4008, 544f89f, Jan 24 2019, 14:54:06, 0, 0
< [00:00:00.842] LOG -- main.c.251: transport: configure SCO over HCI, result 0x0000
< [00:00:00.842] LOG -- hci.c.4063: BTSTACK_EVENT_STATE 1
< I (844) main.cpp: sta_mac=a4:cf:12:6c:2d:a4
---
> [00:00:00.441] LOG -- btstack_run_loop_freertos.c.260: run loop task 0x3ffbc6f8
> [00:00:00.448] LOG -- btstack_run_loop_freertos.c.263: run loop init, queue item size 8
> [00:00:00.456] LOG -- main.c.273: transport_register_packet_handler
> [00:00:00.469] LOG -- btstack_tlv.c.48: TLV Instance 0x3f4056d4
> [00:00:00.470] LOG -- btstack_tlv_esp32.c.54: tag 42544400 -> 42544400
> [00:00:00.473] LOG -- btstack_tlv_esp32.c.68: read tag 42544400
> [00:00:00.479] LOG -- btstack_tlv_esp32.c.54: tag 42544401 -> 42544401
> [00:00:00.485] LOG -- btstack_tlv_esp32.c.68: read tag 42544401
> [00:00:00.491] LOG -- btstack_tlv_esp32.c.54: tag 42544402 -> 42544402
> [00:00:00.497] LOG -- btstack_tlv_esp32.c.68: read tag 42544402
> [00:00:00.503] LOG -- btstack_tlv_esp32.c.54: tag 42544403 -> 42544403
> [00:00:00.509] LOG -- btstack_tlv_esp32.c.68: read tag 42544403
> [00:00:00.515] LOG -- btstack_tlv_esp32.c.54: tag 42544404 -> 42544404
> [00:00:00.521] LOG -- btstack_tlv_esp32.c.68: read tag 42544404
> [00:00:00.527] LOG -- btstack_tlv_esp32.c.54: tag 42544405 -> 42544405
> [00:00:00.533] LOG -- btstack_tlv_esp32.c.68: read tag 42544405
> [00:00:00.538] LOG -- btstack_tlv_esp32.c.54: tag 42544406 -> 42544406
> [00:00:00.545] LOG -- btstack_tlv_esp32.c.68: read tag 42544406
> [00:00:00.550] LOG -- btstack_tlv_esp32.c.54: tag 42544407 -> 42544407
> [00:00:00.557] LOG -- btstack_tlv_esp32.c.68: read tag 42544407
> [00:00:00.562] LOG -- btstack_tlv_esp32.c.54: tag 42544408 -> 42544408
> [00:00:00.568] LOG -- btstack_tlv_esp32.c.68: read tag 42544408
> [00:00:00.574] LOG -- btstack_tlv_esp32.c.54: tag 42544409 -> 42544409
> [00:00:00.580] LOG -- btstack_tlv_esp32.c.68: read tag 42544409
> [00:00:00.586] LOG -- btstack_tlv_esp32.c.54: tag 4254440a -> 4254440A
> [00:00:00.592] LOG -- btstack_tlv_esp32.c.68: read tag 4254440A
> [00:00:00.598] LOG -- btstack_tlv_esp32.c.54: tag 4254440b -> 4254440B
> [00:00:00.604] LOG -- btstack_tlv_esp32.c.68: read tag 4254440B
> [00:00:00.610] LOG -- btstack_tlv_esp32.c.54: tag 4254440c -> 4254440C
> [00:00:00.616] LOG -- btstack_tlv_esp32.c.68: read tag 4254440C
> [00:00:00.622] LOG -- btstack_tlv_esp32.c.54: tag 4254440d -> 4254440D
> [00:00:00.628] LOG -- btstack_tlv_esp32.c.68: read tag 4254440D
> [00:00:00.634] LOG -- btstack_tlv_esp32.c.54: tag 4254440e -> 4254440E
> [00:00:00.640] LOG -- btstack_tlv_esp32.c.68: read tag 4254440E
> [00:00:00.646] LOG -- btstack_tlv_esp32.c.54: tag 4254440f -> 4254440F
> [00:00:00.652] LOG -- btstack_tlv_esp32.c.68: read tag 4254440F
> [00:00:00.657] LOG -- le_device_db_tlv.c.161: num valid le device entries 0
> I (664) main.c: btstack_main
> [00:00:00.668] LOG -- rfcomm.c.2443: RFCOMM_REGISTER_SERVICE channel #4 mtu 65535 flow_control 0 credits 10
> [00:00:00.677] LOG -- l2cap.c.3511: L2CAP_REGISTER_SERVICE psm 0x3 mtu 65535
> [00:00:00.684] LOG -- l2cap.c.3511: L2CAP_REGISTER_SERVICE psm 0x1 mtu 65535
> I (691) OUTPUT: output_task started
> I (691) alexa.c: timer_task started
> I (696) gpio: GPIO[12]| InputEn: 0| OutputEn: 1| OpenDrain: 0| Pullup: 0| Pulldown: 1| Intr:0
> I (709) gpio: GPIO[13]| InputEn: 0| OutputEn: 1| OpenDrain: 0| Pullup: 0| Pulldown: 1| Intr:0
> I (718) gpio: GPIO[14]| InputEn: 0| OutputEn: 1| OpenDrain: 0| Pullup: 0| Pulldown: 1| Intr:0
> I (727) OUTPUT: GPIO is configured
> I (731) OUTPUT: output: 0 0 0
> [00:00:00.735] LOG -- hci.c.2931: hci_power_control: 1, current mode 0
> [00:00:00.741] LOG -- main.c.205: transport_init
> [00:00:00.745] LOG -- main.c.221: transport_open
> I (750) BTDM_INIT: BT controller compile version [2f7e614]
> I (756) system_api: Base MAC address is not set, read default base MAC address from BLK0 of EFUSE
> I (799) SPI: Pins used: miso=25, mosi=23, sck=19, cs=22
> I (800) SPI: display device added to spi bus (1)
> I (800) SPI: attached display device, speed=8000000
> I (805) SPI: bus uses native pins: false
> I (809) SPI: display init...
> I (875) phy: phy_version: 4102, 2fa7a43, Jul 15 2019, 13:06:06, 0, 0
> [00:00:01.191] LOG -- main.c.252: transport: configure SCO over HCI, result 0x0000
> [00:00:01.191] LOG -- hci.c.4063: BTSTACK_EVENT_STATE 1
> I (1196) main.c: sta_mac=a4:cf:12:6c:2d:a4
111,125c126,140
< [00:00:00.854] LOG -- hci.c.1975: Manufacturer: 0x0060
< [00:00:00.859] LOG -- hci.c.1889: local name:
< [00:00:00.860] LOG -- hci.c.1648: Received local name, need baud change 0
< [00:00:00.870] LOG -- hci.c.1986: Local supported commands summary 0x3f
< [00:00:00.876] LOG -- hci.c.1937: Local Address, Status: 0x00: Addr: A4:CF:12:6C:2D:A6
< [00:00:00.884] LOG -- hci.c.1906: hci_read_buffer_size: ACL size module 1021 -> used 1021, count 9 / SCO size 255, count 4
< [00:00:00.894] LOG -- hci.c.1964: Packet types cc18, eSCO 1
< [00:00:00.896] LOG -- hci.c.1967: BR/EDR support 1, LE support 1
< [00:00:00.932] LOG -- hci.c.4181: BTSTACK_EVENT_DISCOVERABLE_ENABLED 1
< [00:00:00.934] LOG -- hci.c.1917: hci_le_read_buffer_size: size 251, count 10
< [00:00:00.935] LOG -- hci.c.1756: Supported commands 30
< [00:00:00.940] LOG -- hci.c.1924: hci_le_read_maximum_data_length: tx octets 251, tx time 2120 us
< [00:00:00.954] LOG -- hci.c.1930: hci_le_read_white_list_size: size 12
< [00:00:00.958] LOG -- hci.c.1512: hci_init_done -> HCI_STATE_WORKING
< [00:00:00.960] LOG -- hci.c.4063: BTSTACK_EVENT_STATE 2
---
> [00:00:01.203] LOG -- hci.c.1975: Manufacturer: 0x0060
> [00:00:01.206] LOG -- hci.c.1889: local name:
> [00:00:01.209] LOG -- hci.c.1648: Received local name, need baud change 0
> [00:00:01.218] LOG -- hci.c.1986: Local supported commands summary 0x3f
> [00:00:01.222] LOG -- hci.c.1937: Local Address, Status: 0x00: Addr: A4:CF:12:6C:2D:A6
> [00:00:01.232] LOG -- hci.c.1906: hci_read_buffer_size: ACL size module 1021 -> used 1021, count 9 / SCO size 255, count 4
> [00:00:01.241] LOG -- hci.c.1964: Packet types cc18, eSCO 1
> [00:00:01.245] LOG -- hci.c.1967: BR/EDR support 1, LE support 1
> [00:00:01.272] LOG -- hci.c.4181: BTSTACK_EVENT_DISCOVERABLE_ENABLED 1
> [00:00:01.274] LOG -- hci.c.1917: hci_le_read_buffer_size: size 251, count 10
> [00:00:01.275] LOG -- hci.c.1756: Supported commands 30
> [00:00:01.281] LOG -- hci.c.1924: hci_le_read_maximum_data_length: tx octets 251, tx time 2120 us
> [00:00:01.292] LOG -- hci.c.1930: hci_le_read_white_list_size: size 12
> [00:00:01.297] LOG -- hci.c.1512: hci_init_done -> HCI_STATE_WORKING
> [00:00:01.301] LOG -- hci.c.4063: BTSTACK_EVENT_STATE 2
127,151c142,302
< [00:00:00.968] LOG -- l2cap.c.1885: L2CAP_CREATE_CHANNEL addr 74:75:48:D5:32:E3 psm 0x1 mtu 1691 -> local mtu 1691
< [00:00:00.978] LOG -- l2cap.c.1864: channel 0x3ffdc544, local_cid 0x0040
< [00:00:00.984] LOG -- hci.c.3762: Create_connection to 74:75:48:D5:32:E3
< [00:00:00.990] LOG -- hci.c.186: create_connection_for_addr 74:75:48:D5:32:E3, type ff
< [00:00:00.998] LOG -- hci.c.3774: conn state 0
< [00:00:01.005] LOG -- hci.c.2016: command status (create connection), status 0, connection 0x3ffdcd3c, addr 74:75:48:D5:32:E3, type ff
< I (1934) OUTPUT: no queue 0
< I (5239) OUTPUT: no queue 0
< I (8539) OUTPUT: no queue 0
< I (11839) OUTPUT: no queue 0
< I (15139) OUTPUT: no queue 0
< I (18439) OUTPUT: no queue 0
< I (21739) OUTPUT: no queue 0
< I (25039) OUTPUT: no queue 0
< I (28339) OUTPUT: no queue 0
< I (31639) OUTPUT: no queue 0
< I (34939) OUTPUT: no queue 0
< I (38239) OUTPUT: no queue 0
< I (41539) OUTPUT: no queue 0
< [00:00:44.336] LOG -- hci.c.2100: Connection_complete (status=34) 74:75:48:D5:32:E3
< [00:00:44.337] LOG -- hci.c.1829: Outgoing connection to 74:75:48:D5:32:E3 failed
< [00:00:44.340] LOG -- l2cap.c.905: L2CAP_EVENT_CHANNEL_OPENED status 0x22 addr 74:75:48:D5:32:E3 handle 0xffff psm 0x1 local_cid 0x40 remote_cid 0x0 local_mtu 1691, remote_mtu 672, flush_timeout 0
< [00:00:44.357] LOG -- sdp_client.c.448: SDP Client Connection failed, status 0x22.
< I (44364) main.cpp: SDP query failed 0x22
< [00:00:44.369] LOG -- l2cap.c.1100: l2cap_stop_rtx for local cid 0x40
---
> [00:00:01.308] LOG -- l2cap.c.1885: L2CAP_CREATE_CHANNEL addr 74:75:48:D5:32:E3 psm 0x1 mtu 1691 -> local mtu 1691
> [00:00:01.318] LOG -- l2cap.c.1864: channel 0x3ffbb114, local_cid 0x0040
> [00:00:01.325] LOG -- hci.c.3762: Create_connection to 74:75:48:D5:32:E3
> [00:00:01.331] LOG -- hci.c.186: create_connection_for_addr 74:75:48:D5:32:E3, type ff
> [00:00:01.338] LOG -- hci.c.3774: conn state 0
> [00:00:01.343] LOG -- hci.c.2016: command status (create connection), status 0, connection 0x3ffe436c, addr 74:75:48:D5:32:E3, type ff
> I (1614) SPI: ok
> I (1621) SPI: Max rd speed = 1000000
> I (1621) SPI: Changed speed to 26666666
> I (1735) OUTPUT: output: 0 0 0
> [00:00:01.739] LOG -- hci.c.2100: Connection_complete (status=0) 74:75:48:D5:32:E3
> [00:00:01.739] LOG -- hci.c.2113: New connection: handle 129, 74:75:48:D5:32:E3
> [00:00:01.744] LOG -- hci.c.4132: BTSTACK_EVENT_NR_CONNECTIONS_CHANGED 1
> [00:00:01.751] LOG -- l2cap.c.1794: connection complete con_handle 0081 - for channel 0x3ffbb114 cid 0x0040
> [00:00:01.761] LOG -- hci.c.2162: HCI_EVENT_READ_REMOTE_SUPPORTED_FEATURES_COMPLETE, bonding flags 6, eSCO 1
> [00:00:01.770] LOG -- l2cap.c.2217: remote supported features, channel 0x3ffbb114, cid 0040 - state 4
> [00:00:01.778] LOG -- l2cap.c.1822: l2cap received remote supported features, sec_level_0_allowed for psm 1 = 1
> [00:00:01.789] LOG -- l2cap.c.1100: l2cap_stop_rtx for local cid 0x40
> [00:00:01.794] LOG -- l2cap.c.1109: l2cap_start_rtx for local cid 0x40
> [00:00:01.823] LOG -- l2cap.c.2550: L2CAP signaling handler code 3, state 10
> [00:00:01.824] LOG -- l2cap.c.1100: l2cap_stop_rtx for local cid 0x40
> [00:00:01.826] LOG -- l2cap.c.1116: l2cap_start_ertx for local cid 0x40
> [00:00:01.832] LOG -- l2cap.c.1100: l2cap_stop_rtx for local cid 0x40
> [00:00:01.862] LOG -- l2cap.c.2550: L2CAP signaling handler code 3, state 10
> [00:00:01.862] LOG -- l2cap.c.1100: l2cap_stop_rtx for local cid 0x40
> [00:00:01.865] LOG -- l2cap.c.1100: l2cap_stop_rtx for local cid 0x40
> [00:00:01.870] LOG -- l2cap.c.1109: l2cap_start_rtx for local cid 0x40
> [00:00:01.877] LOG -- l2cap.c.2550: L2CAP signaling handler code 4, state 11
> [00:00:01.884] LOG -- l2cap.c.2550: L2CAP signaling handler code 5, state 11
> [00:00:01.890] LOG -- l2cap.c.1100: l2cap_stop_rtx for local cid 0x40
> [00:00:01.896] LOG -- l2cap.c.2481: l2cap_signaling_handle_configure_response
> [00:00:01.904] LOG -- l2cap.c.905: L2CAP_EVENT_CHANNEL_OPENED status 0x0 addr 74:75:48:D5:32:E3 handle 0x81 psm 0x1 local_cid 0x40 remote_cid 0x40 local_mtu 1691, remote_mtu 672, flush_timeout 0
> [00:00:01.966] LOG -- l2cap.c.1864: channel 0x3ffbb228, local_cid 0x0041
> [00:00:01.966] LOG -- hci.c.4266: gap_request_security_level requested level 0, planned level 0, current level 0
> [00:00:01.972] LOG -- hci.c.4163: hci_emit_security_level 0 for handle 81
> [00:00:01.978] LOG -- l2cap.c.2224: l2cap - security level update for handle 0x0081
> [00:00:01.985] LOG -- l2cap.c.2234: channel 0x3ffbb228, cid 0041 - state 5: actual 0 >= required 0?
> [00:00:01.994] LOG -- l2cap.c.939: L2CAP_EVENT_INCOMING_CONNECTION addr 74:75:48:D5:32:E3 handle 0x81 psm 0x1 local_cid 0x41 remote_cid 0x41
> [00:00:02.007] LOG -- l2cap.c.2345: L2CAP_ACCEPT_CONNECTION local_cid 0x41
> [00:00:02.013] LOG -- l2cap.c.2234: channel 0x3ffbb114, cid 0040 - state 12: actual 0 >= required 0?
> [00:00:02.022] LOG -- l2cap.c.1100: l2cap_stop_rtx for local cid 0x41
> [00:00:02.028] LOG -- l2cap.c.1109: l2cap_start_rtx for local cid 0x41
> [00:00:02.042] LOG -- l2cap.c.1921: L2CAP_DISCONNECT local_cid 0x40 reason 0x0
> [00:00:02.046] LOG -- l2cap.c.2550: L2CAP signaling handler code 4, state 11
> [00:00:02.049] LOG -- l2cap.c.2550: L2CAP signaling handler code 5, state 11
> [00:00:02.055] LOG -- l2cap.c.1100: l2cap_stop_rtx for local cid 0x41
> [00:00:02.061] LOG -- l2cap.c.2481: l2cap_signaling_handle_configure_response
> [00:00:02.068] LOG -- l2cap.c.905: L2CAP_EVENT_CHANNEL_OPENED status 0x0 addr 74:75:48:D5:32:E3 handle 0x81 psm 0x1 local_cid 0x41 remote_cid 0x41 local_mtu 1691, remote_mtu 672, flush_timeout 0
> [00:00:02.085] LOG -- l2cap.c.2550: L2CAP signaling handler code 7, state 13
> [00:00:02.092] LOG -- l2cap.c.933: L2CAP_EVENT_CHANNEL_CLOSED local_cid 0x40
> [00:00:02.098] LOG -- sdp_client.c.472: SDP Client disconnected.
> I (2104) main.c: SDP query done.
> [00:00:02.108] LOG -- l2cap.c.1100: l2cap_stop_rtx for local cid 0x40
> [00:00:02.145] LOG -- l2cap.c.2550: L2CAP signaling handler code 6, state 12
> [00:00:02.145] LOG -- l2cap.c.933: L2CAP_EVENT_CHANNEL_CLOSED local_cid 0x41
> [00:00:02.147] LOG -- l2cap.c.1100: l2cap_stop_rtx for local cid 0x41
> I (2735) OUTPUT: output: 0 0 0
> I (3735) OUTPUT: output: 0 0 0
> I (4735) OUTPUT: output: 0 0 0
> [00:00:04.784] LOG -- hci.c.2169: HCI_EVENT_LINK_KEY_REQUEST
> [00:00:04.784] LOG -- hci.c.3467: responding to link key request
> [00:00:04.784] LOG -- btstack_tlv_esp32.c.54: tag 42544c00 -> 42544C00
> [00:00:04.790] LOG -- btstack_tlv_esp32.c.68: read tag 42544C00
> [00:00:04.796] LOG -- btstack_tlv_esp32.c.54: tag 42544c01 -> 42544C01
> [00:00:04.802] LOG -- btstack_tlv_esp32.c.68: read tag 42544C01
> [00:00:04.808] LOG -- btstack_tlv_esp32.c.54: tag 42544c02 -> 42544C02
> [00:00:04.814] LOG -- btstack_tlv_esp32.c.68: read tag 42544C02
> [00:00:04.819] LOG -- btstack_tlv_esp32.c.54: tag 42544c03 -> 42544C03
> [00:00:04.826] LOG -- btstack_tlv_esp32.c.68: read tag 42544C03
> [00:00:04.831] LOG -- btstack_tlv_esp32.c.54: tag 42544c04 -> 42544C04
> [00:00:04.838] LOG -- btstack_tlv_esp32.c.68: read tag 42544C04
> [00:00:04.843] LOG -- btstack_tlv_esp32.c.54: tag 42544c05 -> 42544C05
> [00:00:04.849] LOG -- btstack_tlv_esp32.c.68: read tag 42544C05
> [00:00:04.855] LOG -- btstack_tlv_esp32.c.54: tag 42544c06 -> 42544C06
> [00:00:04.861] LOG -- btstack_tlv_esp32.c.68: read tag 42544C06
> [00:00:04.867] LOG -- btstack_tlv_esp32.c.54: tag 42544c07 -> 42544C07
> [00:00:04.873] LOG -- btstack_tlv_esp32.c.68: read tag 42544C07
> [00:00:04.879] LOG -- btstack_tlv_esp32.c.54: tag 42544c08 -> 42544C08
> [00:00:04.885] LOG -- btstack_tlv_esp32.c.68: read tag 42544C08
> [00:00:04.891] LOG -- btstack_tlv_esp32.c.54: tag 42544c09 -> 42544C09
> [00:00:04.897] LOG -- btstack_tlv_esp32.c.68: read tag 42544C09
> [00:00:04.903] LOG -- btstack_tlv_esp32.c.54: tag 42544c0a -> 42544C0A
> [00:00:04.909] LOG -- btstack_tlv_esp32.c.68: read tag 42544C0A
> [00:00:04.915] LOG -- btstack_tlv_esp32.c.54: tag 42544c0b -> 42544C0B
> [00:00:04.921] LOG -- btstack_tlv_esp32.c.68: read tag 42544C0B
> [00:00:04.927] LOG -- btstack_tlv_esp32.c.54: tag 42544c0c -> 42544C0C
> [00:00:04.933] LOG -- btstack_tlv_esp32.c.68: read tag 42544C0C
> [00:00:04.938] LOG -- btstack_tlv_esp32.c.54: tag 42544c0d -> 42544C0D
> [00:00:04.945] LOG -- btstack_tlv_esp32.c.68: read tag 42544C0D
> [00:00:04.950] LOG -- btstack_tlv_esp32.c.54: tag 42544c0e -> 42544C0E
> [00:00:04.956] LOG -- btstack_tlv_esp32.c.68: read tag 42544C0E
> [00:00:04.962] LOG -- btstack_tlv_esp32.c.54: tag 42544c0f -> 42544C0F
> [00:00:04.968] LOG -- btstack_tlv_esp32.c.68: read tag 42544C0F
> [00:00:04.975] LOG -- btstack_link_key_db_tlv.c.95: tag 42544c0f, addr 74:75:48:D5:32:E3
> [00:00:05.093] LOG -- hci.c.4163: hci_emit_security_level 2 for handle 81
> [00:00:05.093] LOG -- l2cap.c.2224: l2cap - security level update for handle 0x0081
> [00:00:05.101] LOG -- l2cap.c.1864: channel 0x3ffbb114, local_cid 0x0042
> [00:00:05.102] LOG -- hci.c.4266: gap_request_security_level requested level 2, planned level 0, current level 2
> [00:00:05.112] LOG -- hci.c.4163: hci_emit_security_level 2 for handle 81
> [00:00:05.119] LOG -- l2cap.c.2224: l2cap - security level update for handle 0x0081
> [00:00:05.126] LOG -- l2cap.c.2234: channel 0x3ffbb114, cid 0042 - state 5: actual 2 >= required 2?
> [00:00:05.135] LOG -- l2cap.c.939: L2CAP_EVENT_INCOMING_CONNECTION addr 74:75:48:D5:32:E3 handle 0x81 psm 0x3 local_cid 0x42 remote_cid 0x40
> [00:00:05.147] LOG -- rfcomm.c.304: rfcomm_max_frame_size_for_l2cap_mtu: 1691 -> 1686
> [00:00:05.155] LOG -- rfcomm.c.1004: L2CAP_EVENT_INCOMING_CONNECTION (l2cap_cid 0x42) for BLUETOOTH_PROTOCOL_RFCOMM => accept
> [00:00:05.166] LOG -- l2cap.c.2345: L2CAP_ACCEPT_CONNECTION local_cid 0x42
> [00:00:05.173] LOG -- l2cap.c.1100: l2cap_stop_rtx for local cid 0x42
> [00:00:05.179] LOG -- l2cap.c.1109: l2cap_start_rtx for local cid 0x42
> [00:00:05.185] LOG -- l2cap.c.2550: L2CAP signaling handler code 4, state 11
> [00:00:05.192] LOG -- l2cap.c.2401: Remote MTU 1013
> [00:00:05.196] LOG -- l2cap.c.2550: L2CAP signaling handler code 5, state 11
> [00:00:05.203] LOG -- l2cap.c.1100: l2cap_stop_rtx for local cid 0x42
> [00:00:05.209] LOG -- l2cap.c.2481: l2cap_signaling_handle_configure_response
> [00:00:05.216] LOG -- l2cap.c.905: L2CAP_EVENT_CHANNEL_OPENED status 0x0 addr 74:75:48:D5:32:E3 handle 0x81 psm 0x3 local_cid 0x42 remote_cid 0x40 local_mtu 1691, remote_mtu 1013, flush_timeout 0
> [00:00:05.233] LOG -- rfcomm.c.1031: L2CAP_EVENT_CHANNEL_OPENED for BLUETOOTH_PROTOCOL_RFCOMM, status 0
> [00:00:05.242] LOG -- rfcomm.c.304: rfcomm_max_frame_size_for_l2cap_mtu: 1691 -> 1686
> [00:00:05.250] LOG -- rfcomm.c.1150: Received SABM #0
> [00:00:05.255] LOG -- rfcomm.c.1290: Sending UA #0
> [00:00:05.259] LOG -- rfcomm.c.868: Multiplexer up and running
> [00:00:05.285] LOG -- rfcomm.c.1566: Received UIH Parameter Negotiation Command for #8, credits 7
> [00:00:05.285] LOG -- rfcomm.c.425: rfcomm_channel_create for service 0x3ffbdb0c, channel 4 --- list of channels:
> [00:00:05.293] LOG -- rfcomm.c.1886: -> Inform app
> [00:00:05.297] LOG -- rfcomm.c.173: RFCOMM_EVENT_INCOMING_CONNECTION addr 74:75:48:D5:32:E3 channel #4 cid 0x01
> I (5307) main.c: Accepting RFCOMM connection from 74:75:48:D5:32:E3, cid: 1
> [00:00:05.315] LOG -- rfcomm.c.2502: RFCOMM_ACCEPT_CONNECTION cid 0x01
> [00:00:05.321] LOG -- rfcomm.c.1914: Sending UIH Parameter Negotiation Respond for #8
> [00:00:05.329] LOG -- rfcomm.c.1703: rfcomm_channel_ready_for_incoming_dlc_setup state var 0003
> [00:00:05.347] LOG -- rfcomm.c.1532: Received SABM #8
> [00:00:05.348] LOG -- rfcomm.c.1918: Sending UA #8
> [00:00:05.348] LOG -- rfcomm.c.1703: rfcomm_channel_ready_for_incoming_dlc_setup state var 000b
> [00:00:05.354] LOG -- rfcomm.c.1923: Incomping setup done, requesting send MSC CMD and send Credits
> [00:00:05.364] LOG -- rfcomm.c.1585: Received MSC CMD for #8,
> [00:00:05.369] LOG -- rfcomm.c.1695: rfcomm_channel_ready_for_open state 8, flags needed 0020, current 1c1b, rf credits 7
> [00:00:05.380] LOG -- rfcomm.c.1846: Sending MSC RSP for #8
> [00:00:05.385] LOG -- rfcomm.c.2009: Sending MSC CMD for #8
> [00:00:05.390] LOG -- rfcomm.c.1695: rfcomm_channel_ready_for_open state 8, flags needed 0020, current 701b, rf credits 7
> [00:00:05.401] LOG -- rfcomm.c.1592: Received MSC RSP for #8
> [00:00:05.406] LOG -- rfcomm.c.1695: rfcomm_channel_ready_for_open state 8, flags needed 0020, current 703b, rf credits 7
> [00:00:05.417] LOG -- rfcomm.c.1372: RFCOMM data UIH_PF, new credits channel 0x01: 33, now 40
> [00:00:05.425] LOG -- rfcomm.c.1695: rfcomm_channel_ready_for_open state 8, flags needed 0020, current 703b, rf credits 40
> [00:00:05.436] LOG -- rfcomm.c.2016: Providing credits for #8
> [00:00:05.442] LOG -- rfcomm.c.1695: rfcomm_channel_ready_for_open state 8, flags needed 0020, current e03b, rf credits 40
> [00:00:05.452] LOG -- rfcomm.c.1335: rfcomm_channel_opened!
> [00:00:05.457] LOG -- rfcomm.c.191: RFCOMM_EVENT_CHANNEL_OPENED status 0x0 addr 74:75:48:D5:32:E3 handle 0x81 channel #4 cid 0x01 mtu 1008
> I (5470) main.c: Got RFCOMM data on channel 1
> I (5475) main.c: Alexa Gadgets Toolkit packet, checksum: 09 db
> I (5481) alexa.c: Parsing Directive
> I (5486) alexa.c: name = Discover, namespace=Alexa.Discovery
> scope type:
> scope token:
> I (5494) alexa.c: Creating discover response event
> I (5501) main.c: rfcomm_request_can_send_now_event
> I (5506) main.c: RFCOMM_EVENT_CAN_SEND_NOW
> I (5735) OUTPUT: output: 0 0 0
> I (6122) main.c: Got RFCOMM data on channel 1
> I (6123) main.c: Alexa Gadgets Toolkit packet, checksum: 18 33
> I (6123) alexa.c: Parsing Directive
> I (6127) alexa.c: name = StateUpdate, namespace=Alexa.Gadget.StateListener
> state name: timeinfo
> state value: 2019-08-17T22:27:26-07:00
> I (6140) alexa.c: time info: 119 7 17 22 27 26, 1566080846
> I (6735) OUTPUT: output: 0 0 0
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment