Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Error while loading startup script: buffer too small. #86

Closed
pascalzauberzeug opened this issue Nov 5, 2024 · 2 comments · Fixed by #89
Closed

Error while loading startup script: buffer too small. #86

pascalzauberzeug opened this issue Nov 5, 2024 · 2 comments · Fixed by #89
Assignees
@JensOgorek
Labels
bug Something isn't working
Milestone
0.6.0

Comments

@pascalzauberzeug
Copy link
Contributor

While setting up new robot brains, I noticed that 0.5.3 is not working correctly.
I get the following error which occurred with both long and short configurations. Both work with 0.5.2

2024-11-04 16:06:21.594 [DEBUG] rosys/hardware/communication/serial_communication.py:72: read: error while loading startup script: buffer too small. discarded line.@7f

full restart log:

2024-11-04 16:06:20.141 [DEBUG] rosys/hardware/communication/serial_communication.py:80: send: core.restart()@43
2024-11-04 16:06:20.265 [DEBUG] rosys/hardware/communication/serial_communication.py:72: read: I (13) boot: ESP-IDF v5.3.1 2nd stage bootloader
2024-11-04 16:06:20.274 [DEBUG] rosys/hardware/communication/serial_communication.py:72: read: I (13) boot: compile time Oct 28 2024 15:56:02
2024-11-04 16:06:20.285 [DEBUG] rosys/hardware/communication/serial_communication.py:72: read: I (13) boot: Multicore bootloader
2024-11-04 16:06:20.295 [DEBUG] rosys/hardware/communication/serial_communication.py:72: read: I (13) boot: chip revision: v3.0
2024-11-04 16:06:20.306 [DEBUG] rosys/hardware/communication/serial_communication.py:72: read: I (16) boot.esp32: SPI Speed   : 40MHz
2024-11-04 16:06:20.316 [DEBUG] rosys/hardware/communication/serial_communication.py:72: read: I (20) boot.esp32: SPI Mode    : DIO
2024-11-04 16:06:20.327 [DEBUG] rosys/hardware/communication/serial_communication.py:72: read: I (23) boot.esp32: SPI Flash Size : 8MB
2024-11-04 16:06:20.337 [DEBUG] rosys/hardware/communication/serial_communication.py:72: read: I (27) boot: Enabling RNG early entropy source...
2024-11-04 16:06:20.348 [DEBUG] rosys/hardware/communication/serial_communication.py:72: read: I (31) boot: Partition Table:
2024-11-04 16:06:20.359 [DEBUG] rosys/hardware/communication/serial_communication.py:72: read: I (34) boot: ## Label      Usage     Type ST Offset  Length
2024-11-04 16:06:20.369 [DEBUG] rosys/hardware/communication/serial_communication.py:72: read: I (40) boot: 0 nvs       WiFi data    01 02 00009000 00006000
2024-11-04 16:06:20.380 [DEBUG] rosys/hardware/communication/serial_communication.py:72: read: I (47) boot: 1 otadata     OTA data     01 00 0000f000 00002000
2024-11-04 16:06:20.390 [DEBUG] rosys/hardware/communication/serial_communication.py:72: read: I (53) boot: 2 phy_init     RF data     01 01 00011000 00001000
2024-11-04 16:06:20.401 [DEBUG] rosys/hardware/communication/serial_communication.py:72: read: I (60) boot: 3 ota_0      OTA app     00 10 00020000 001f0000
2024-11-04 16:06:20.411 [DEBUG] rosys/hardware/communication/serial_communication.py:72: read: I (66) boot: 4 ota_1      OTA app     00 11 00210000 001f0000
2024-11-04 16:06:20.422 [DEBUG] rosys/hardware/communication/serial_communication.py:72: read: I (73) boot: 5 coredump     Unknown data   01 03 00400000 00020000
2024-11-04 16:06:20.433 [DEBUG] rosys/hardware/communication/serial_communication.py:72: read: I (79) boot: End of partition table
2024-11-04 16:06:20.443 [DEBUG] rosys/hardware/communication/serial_communication.py:72: read: I (82) esp_image: segment 0: paddr=00020020 vaddr=3f400020 size=6e09ch (450716) map
2024-11-04 16:06:20.454 [DEBUG] rosys/hardware/communication/serial_communication.py:72: read: I (244) esp_image: segment 1: paddr=0008e0c4 vaddr=3ff80000 size=00004h (   4) load
2024-11-04 16:06:20.464 [DEBUG] rosys/hardware/communication/serial_communication.py:72: read: I (245) esp_image: segment 2: paddr=0008e0d0 vaddr=3ffbdb60 size=01f48h ( 8008) load
2024-11-04 16:06:20.475 [DEBUG] rosys/hardware/communication/serial_communication.py:72: read: I (251) esp_image: segment 3: paddr=00090020 vaddr=400d0020 size=10cf04h (1101572) map
2024-11-04 16:06:20.813 [DEBUG] rosys/hardware/communication/serial_communication.py:72: read: I (633) esp_image: segment 4: paddr=0019cf2c vaddr=3ffbfaa8 size=0430ch ( 17164) load
2024-11-04 16:06:20.822 [DEBUG] rosys/hardware/communication/serial_communication.py:72: read: I (640) esp_image: segment 5: paddr=001a1240 vaddr=40080000 size=1dabch (121532) load
2024-11-04 16:06:20.884 [DEBUG] rosys/hardware/communication/serial_communication.py:72: read: I (703) boot: Loaded app from partition at offset 0x20000
2024-11-04 16:06:20.895 [DEBUG] rosys/hardware/communication/serial_communication.py:72: read: I (703) boot: Disabling RNG early entropy source...
2024-11-04 16:06:20.905 [DEBUG] rosys/hardware/communication/serial_communication.py:72: read: I (713) cpu_start: Multicore app
2024-11-04 16:06:21.028 [DEBUG] rosys/hardware/communication/serial_communication.py:72: read: I (721) cpu_start: Pro cpu start user code
2024-11-04 16:06:21.039 [DEBUG] rosys/hardware/communication/serial_communication.py:72: read: I (721) cpu_start: cpu freq: 160000000 Hz
2024-11-04 16:06:21.050 [DEBUG] rosys/hardware/communication/serial_communication.py:72: read: I (722) app_init: Application information:
2024-11-04 16:06:21.060 [DEBUG] rosys/hardware/communication/serial_communication.py:72: read: I (722) app_init: Project name:   lizard
2024-11-04 16:06:21.071 [DEBUG] rosys/hardware/communication/serial_communication.py:72: read: I (725) app_init: App version:   v0.5.3
2024-11-04 16:06:21.081 [DEBUG] rosys/hardware/communication/serial_communication.py:72: read: I (729) app_init: Compile time:   Oct 28 2024 15:55:56
2024-11-04 16:06:21.092 [DEBUG] rosys/hardware/communication/serial_communication.py:72: read: I (734) app_init: ELF file SHA256: 8743894e9...
2024-11-04 16:06:21.102 [DEBUG] rosys/hardware/communication/serial_communication.py:72: read: I (739) app_init: ESP-IDF:     v5.3.1
2024-11-04 16:06:21.113 [DEBUG] rosys/hardware/communication/serial_communication.py:72: read: I (742) efuse_init: Min chip rev:   v0.0
2024-11-04 16:06:21.124 [DEBUG] rosys/hardware/communication/serial_communication.py:72: read: I (746) efuse_init: Max chip rev:   v3.99 
2024-11-04 16:06:21.134 [DEBUG] rosys/hardware/communication/serial_communication.py:72: read: I (750) efuse_init: Chip rev:     v3.0
2024-11-04 16:06:21.145 [DEBUG] rosys/hardware/communication/serial_communication.py:72: read: I (754) heap_init: Initializing. RAM available for dynamic allocation:
2024-11-04 16:06:21.156 [DEBUG] rosys/hardware/communication/serial_communication.py:72: read: I (761) heap_init: At 3FFAFF10 len 000000F0 (0 KiB): DRAM
2024-11-04 16:06:21.166 [DEBUG] rosys/hardware/communication/serial_communication.py:72: read: I (765) heap_init: At 3FFB6388 len 00001C78 (7 KiB): DRAM
2024-11-04 16:06:21.177 [DEBUG] rosys/hardware/communication/serial_communication.py:72: read: I (771) heap_init: At 3FFB9A20 len 00004108 (16 KiB): DRAM
2024-11-04 16:06:21.188 [DEBUG] rosys/hardware/communication/serial_communication.py:72: read: I (776) heap_init: At 3FFD5358 len 0000ACA8 (43 KiB): DRAM
2024-11-04 16:06:21.198 [DEBUG] rosys/hardware/communication/serial_communication.py:72: read: I (781) heap_init: At 3FFE0440 len 00003AE0 (14 KiB): D/IRAM
2024-11-04 16:06:21.209 [DEBUG] rosys/hardware/communication/serial_communication.py:72: read: I (786) heap_init: At 3FFE4350 len 0001BCB0 (111 KiB): D/IRAM
2024-11-04 16:06:21.219 [DEBUG] rosys/hardware/communication/serial_communication.py:72: read: I (792) heap_init: At 4009DABC len 00002544 (9 KiB): IRAM
2024-11-04 16:06:21.230 [DEBUG] rosys/hardware/communication/serial_communication.py:72: read: I (799) spi_flash: detected chip: generic
2024-11-04 16:06:21.240 [DEBUG] rosys/hardware/communication/serial_communication.py:72: read: I (801) spi_flash: flash io: dio
2024-11-04 16:06:21.250 [DEBUG] rosys/hardware/communication/serial_communication.py:72: read: W (804) spi_flash: Detected size(16384k) larger than the size in the binary image header(8192k). Using the size in the binary image header.
2024-11-04 16:06:21.261 [DEBUG] rosys/hardware/communication/serial_communication.py:72: read: W (816) pcnt(legacy): legacy driver is deprecated, please migrate to `driver/pulse_cnt.h`
2024-11-04 16:06:21.271 [DEBUG] rosys/hardware/communication/serial_communication.py:72: read: W (824) i2c: This driver is an old driver, please migrate your application code to adapt `driver/i2c_master.h`
2024-11-04 16:06:21.282 [DEBUG] rosys/hardware/communication/serial_communication.py:72: read: I (835) esp_core_dump_flash: Init core dump to flash
2024-11-04 16:06:21.293 [DEBUG] rosys/hardware/communication/serial_communication.py:72: read: I (839) esp_core_dump_flash: Found partition 'coredump' @ 400000 131072 bytes
2024-11-04 16:06:21.303 [DEBUG] rosys/hardware/communication/serial_communication.py:72: read: I (846) coexist: coex firmware version: 4482466
2024-11-04 16:06:21.314 [DEBUG] rosys/hardware/communication/serial_communication.py:72: read: I (851) main_task: Started o
2024-11-04 16:06:21.324 [DEBUG] rosys/hardware/communication/serial_communication.py:72: read: Ready.
2024-11-04 16:06:21.335 [DEBUG] rosys/hardware/communication/serial_communication.py:72: read: I (891) BTDM_INIT: BT controller compile version [b022216]
2024-11-04 16:06:21.346 [DEBUG] rosys/hardware/communication/serial_communication.py:72: read: I (891) BTDM_INIT: Bluetooth MAC: 90:38:0c:ac:7e:d6
2024-11-04 16:06:21.356 [DEBUG] rosys/hardware/communication/serial_communication.py:72: read: I (891) phy_init: phy_version 4830,54550f7,Jun 20 2024,14:22:08
2024-11-04 16:06:21.377 [DEBUG] rosys/hardware/communication/serial_communication.py:72: read: I (1201) esp_zeug/FrtosUtil: Task [ble_host] executing on core [PRO]
2024-11-04 16:06:21.459 [DEBUG] rosys/hardware/communication/serial_communication.py:72: read: I (1241) gpio: GPIO[25]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 
2024-11-04 16:06:21.470 [DEBUG] rosys/hardware/communication/serial_communication.py:72: read: I (1241) gpio: GPIO[14]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 
2024-11-04 16:06:21.480 [DEBUG] rosys/hardware/communication/serial_communication.py:72: read: I (1251) NimBLE: Failed to restore IRKs from store; status=8
2024-11-04 16:06:21.491 [DEBUG] rosys/hardware/communication/serial_communication.py:72: read: 
2024-11-04 16:06:21.502 [DEBUG] rosys/hardware/communication/serial_communication.py:72: read: I (1261) NimBLE: GAP procedure initiated: advertise; 
2024-11-04 16:06:21.512 [DEBUG] rosys/hardware/communication/serial_communication.py:72: read: I (1261) NimBLE: disc_mode=2
2024-11-04 16:06:21.523 [DEBUG] rosys/hardware/communication/serial_communication.py:72: read: I (1261) NimBLE: adv_channel_map=0 own_addr_type=0 adv_filter_policy=0 adv_itvl_min=0 adv_itvl_max=0
2024-11-04 16:06:21.533 [DEBUG] rosys/hardware/communication/serial_communication.py:72: read: I (1271) NimBLE: 
2024-11-04 16:06:21.544 [DEBUG] rosys/hardware/communication/serial_communication.py:72: read: 
2024-11-04 16:06:21.594 [DEBUG] rosys/hardware/communication/serial_communication.py:72: read: error while loading startup script: buffer too small. discarded line.@7f

Short configuration:

#startup.liz for rb44 
bluetooth = Bluetooth("RB44")

# Expander Socket 1 rs485_v05
serial = Serial(26, 27, 115200, 1)
p0 = Expander(serial, 25, 14)

rdyp_status = Input(39)
vdp_status = p0.Input(39)

core.output("core.millis core.heap rdyp_status.level vdp_status.level")

rdyp = Output(15)
en3 = Output(12)
en3.on()
rdyp.on()

Long configuration:

#startup.liz for rb44 
bluetooth = Bluetooth("RB44")

# Expander Socket 1 rs485_v05
serial = Serial(26, 27, 115200, 1)
p0 = Expander(serial, 25, 14)
s1_rs485 = p0.Serial(26, 27, 9600, 2)
s1_rs485.unmute()
s1_out_1 = p0.Output(15)
s1_in_1 = p0.Input(13)
str socket_1 = "rs485_v05"

# Socket 2 oogiir_v07
s2_out_1 = Output(5)
s2_out_2 = Output(4)
s2_in_1 = Input(36)
s2_in_2 = Input(13)
str socket_2 = "oogiir_v07"

# Socket 3 can_v04
s3_can = Can(32, 33, 1000000)
s3_can.unmute()
s3_out_1 = p0.Output(2)
s3_in_1 = p0.Input(14)
str socket_3 = "can_v04"

# Socket 4 empty

# Socket 5 iigiir_v02
s5_in_1 = p0.Input(35)
s5_in_2 = p0.Input(18)
s5_in_3 = p0.Input(21)
s5_in_4 = p0.Input(19)
str socket_5 = "iigiir_v02"

# Socket 6 empty

imu = Imu()

rdyp_status = Input(39)
vdp_status = p0.Input(39)

core.output("core.millis core.heap rdyp_status.level vdp_status.level socket_1 s1_in_1.level socket_2 s2_in_1.level s2_in_2.level socket_3 s3_in_1.level socket_5 s5_in_1.level s5_in_2.level s5_in_3.level s5_in_4.level")

rdyp = Output(15)
en3 = Output(12)
en3.on()
rdyp.on()
@pascalzauberzeug pascalzauberzeug added the bug Something isn't working label Nov 5, 2024
@pascalzauberzeug pascalzauberzeug added this to the 0.6.0 milestone Nov 5, 2024
@JensOgorek JensOgorek self-assigned this Nov 5, 2024
@JensOgorek
Copy link
Contributor

The bug happens inside the serial.cpp, so in our case, when we use the expander.

>>> pos: -1, buffer_len: 1024
error while loading startup script: buffer too small. discarded line.

Normally this should not be possible

int Serial::read_line(char *buffer, size_t buffer_len) const {
    int pos = uart_pattern_pop_pos(this->uart_num);
    if (pos >= buffer_len) {
        echo(">>> pos: %d, buffer_len: %zu", pos, buffer_len);
...

When uart_pattern_pop_pos returns -1, it means no newline pattern was found. But the if case should not let that case happen.

@JensOgorek JensOgorek mentioned this issue Nov 5, 2024
Merged
@JensOgorek JensOgorek linked a pull request Nov 5, 2024 that will close this issue
Buffer comparison cast fix #89
Merged
@JensOgorek
Copy link
Contributor

Fix is within #89

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@JensOgorek JensOgorek

Labels
bug Something isn't working
Projects
None yet
Milestone
0.6.0
Development

Successfully merging a pull request may close this issue.

Buffer comparison cast fix zauberzeug/lizard
2 participants
@JensOgorek @pascalzauberzeug