Skip to content

AtomVM: Invalid startup avmpack. size=524288 #58

@Rashidwi

Description

@Rashidwi

I've had my development system working reliably for some time but in the last couple of days I now always get this error.

I've checked and double checked everything and I can't see what would be causing this.

esp idf v5.5 for esp32-s2 is installed and working. their hello_world or blink is fine.

Atomvm 6.6 is installed and there are no issues in building or flashing.
The partitions-elixir.csv is used.

In my blinky app the mix.exs:

      atomvm: [
          start: Blinky,
          flash_offset: 0x250000,
          chip: "esp32-s2",
          port: "/dev/ttyACM0",
   ]

Blinky does have a start/0

defmodule Blinky do
  # suppress warnings when compileing the VM
  # not needed or recommended for user apps.
  @compile {:no_warn_undefined, [GPIO]}
  @pin 15

  def start() do
    GPIO.set_pin_mode(@pin, :output)
    loop(@pin, :low)
  end
...

This also compiles and flashes without error. But, the Atomvm is always reporting:

AtomVM: Invalid startup avmpack. size=524288

When I first started development on AtomVM I used to get this error before I realised the correct order of flashing. But I now have many lines of code that have been working fine, until a couple of days ago.

This is the boot log with verbose turned on:

Rebooting...
ESP-ROM:esp32s2-rc4-20191025
Build:Oct 25 2019
rst:0xc (RTC_SW_CPU_RST),boot:0x8 (SPI_FAST_FLASH_BOOT)
Saved PC:0x4002590a
SPIWP:0xee
mode:DIO, clock div:1
load:0x3ffe5110,len:0x22c8
load:0x4004a000,len:0xe04
load:0x4004e000,len:0x3948
entry 0x4004a230
I (26) boot: ESP-IDF v5.5 2nd stage bootloader
I (26) boot: compile time Aug 19 2025 17:45:01
D (26) bootloader_flash: XMC chip detected by RDID (00204016), skip.
D (29) bootloader_flash: mmu set block paddr=0x00000000 (was 0xffffffff)
D (36) bootloader_flash: mmu set block paddr=0x00000000 (was 0xffffffff)
D (42) bootloader_flash: mmu set block paddr=0x00000000 (was 0xffffffff)
D (48) bootloader_flash: mmu set block paddr=0x00000000 (was 0xffffffff)
D (55) bootloader_flash: mmu set block paddr=0x00000000 (was 0xffffffff)
D (61) bootloader_flash: mmu set block paddr=0x00000000 (was 0xffffffff)
I (68) boot: chip revision: v1.0
I (71) boot: efuse block revision: v0.2
D (74) boot.esp32s2: magic e9
D (77) boot.esp32s2: segments 03
D (80) boot.esp32s2: spi_mode 02
D (83) boot.esp32s2: spi_speed 0f
D (86) boot.esp32s2: spi_size 02
I (89) boot.esp32s2: SPI Speed : 80MHz
I (93) boot.esp32s2: SPI Mode : DIO
I (96) boot.esp32s2: SPI Flash Size : 4MB
D (100) boot: Enabling RTCWDT(9000 ms)
I (104) boot: Enabling RNG early entropy source...
D (108) bootloader_flash: rodata starts from paddr=0x00008000, size=0xc00, will be mapped to vaddr=0x3f000000
V (118) bootloader_flash: after mapping, starting from paddr=0x00000000 and vaddr=0x3f000000, 0x10000 bytes are mapped
D (128) boot: mapped partition table 0x8000 at 0x3f008000
D (133) flash_parts: partition table verified, 6 entries
I (138) boot: Partition Table:
I (141) boot: ## Label Usage Type ST Offset Length
D (148) boot: load partition table entry 0x3f008000
D (152) boot: type=1 subtype=2
I (155) boot: 0 nvs WiFi data 01 02 00009000 00006000
D (161) boot: load partition table entry 0x3f008020
D (166) boot: type=1 subtype=1
I (169) boot: 1 phy_init RF data 01 01 0000f000 00001000
D (175) boot: load partition table entry 0x3f008040
D (180) boot: type=0 subtype=0
I (183) boot: 2 factory factory app 00 00 00010000 001c0000
D (189) boot: load partition table entry 0x3f008060
D (194) boot: type=1 subtype=1
I (197) boot: 3 boot.avm RF data 01 01 001d0000 00080000
D (203) boot: load partition table entry 0x3f008080
D (208) boot: type=1 subtype=1
I (211) boot: 4 main.avm RF data 01 01 00250000 00100000
I (217) boot: End of partition table
D (221) boot: Trying partition index -1 offs 0x10000 size 0x1c0000
D (227) esp_image: reading image header @ 0x10000
D (231) bootloader_flash: mmu set block paddr=0x00010000 (was 0xffffffff)
D (238) bootloader_flash: mmu set block paddr=0x00010000 (was 0xffffffff)
D (244) bootloader_flash: mmu set block paddr=0x00010000 (was 0xffffffff)
D (251) bootloader_flash: mmu set block paddr=0x00010000 (was 0xffffffff)
D (257) bootloader_flash: mmu set block paddr=0x00010000 (was 0xffffffff)
D (264) bootloader_flash: mmu set block paddr=0x00010000 (was 0xffffffff)
D (270) esp_image: image header: 0xe9 0x07 0x02 0x02 4002557c
V (276) esp_image: loading segment header 0 at offset 0x10018
D (281) bootloader_flash: mmu set block paddr=0x00010000 (was 0xffffffff)
D (288) bootloader_flash: mmu set block paddr=0x00010000 (was 0xffffffff)
V (294) esp_image: segment data length 0x33dd0 data starts 0x10020
V (300) esp_image: MMU page size 0x10000
V (304) esp_image: segment 0 map_segment 1 segment_data_offs 0x10020 load_addr 0x3f000020
I (311) esp_image: segment 0: paddr=00010020 vaddr=3f000020 size=33dd0h (212432) map
D (319) esp_image: free data page_count 0x00000038
D (323) bootloader_flash: rodata starts from paddr=0x00010020, size=0x33dd0, will be mapped to vaddr=0x3f000000
V (333) bootloader_flash: after mapping, starting from paddr=0x00010000 and vaddr=0x3f000000, 0x40000 bytes are mapped
V (386) esp_image: loading segment header 1 at offset 0x43df0
D (386) bootloader_flash: mmu set block paddr=0x00040000 (was 0xffffffff)
D (386) bootloader_flash: mmu set block paddr=0x00040000 (was 0xffffffff)
V (393) esp_image: segment data length 0x20 data starts 0x43df8
V (398) esp_image: MMU page size 0x10000
V (402) esp_image: segment 1 map_segment 0 segment_data_offs 0x43df8 load_addr 0x3ff9e040
I (410) esp_image: segment 1: paddr=00043df8 vaddr=3ff9e040 size=00020h ( 32) load
D (418) esp_image: free data page_count 0x00000038
D (422) bootloader_flash: rodata starts from paddr=0x00043df8, size=0x20, will be mapped to vaddr=0x3f000000
V (432) bootloader_flash: after mapping, starting from paddr=0x00040000 and vaddr=0x3f000000, 0x10000 bytes are mapped
V (442) esp_image: loading segment header 2 at offset 0x43e18
D (447) bootloader_flash: mmu set block paddr=0x00040000 (was 0xffffffff)
D (454) bootloader_flash: mmu set block paddr=0x00040000 (was 0xffffffff)
V (461) esp_image: segment data length 0x3c74 data starts 0x43e20
V (466) esp_image: MMU page size 0x10000
V (470) esp_image: segment 2 map_segment 0 segment_data_offs 0x43e20 load_addr 0x3ffcf9f0
I (478) esp_image: segment 2: paddr=00043e20 vaddr=3ffcf9f0 size=03c74h ( 15476) load
D (485) esp_image: free data page_count 0x00000038
D (490) bootloader_flash: rodata starts from paddr=0x00043e20, size=0x3c74, will be mapped to vaddr=0x3f000000
V (500) bootloader_flash: after mapping, starting from paddr=0x00040000 and vaddr=0x3f000000, 0x10000 bytes are mapped
V (514) esp_image: loading segment header 3 at offset 0x47a94
D (516) bootloader_flash: mmu set block paddr=0x00040000 (was 0xffffffff)
D (522) bootloader_flash: mmu set block paddr=0x00040000 (was 0xffffffff)
V (529) esp_image: segment data length 0x857c data starts 0x47a9c
V (534) esp_image: MMU page size 0x10000
V (538) esp_image: segment 3 map_segment 0 segment_data_offs 0x47a9c load_addr 0x40024000
I (546) esp_image: segment 3: paddr=00047a9c vaddr=40024000 size=0857ch ( 34172) load
D (553) esp_image: free data page_count 0x00000038
D (558) bootloader_flash: rodata starts from paddr=0x00047a9c, size=0x857c, will be mapped to vaddr=0x3f000000
V (568) bootloader_flash: after mapping, starting from paddr=0x00040000 and vaddr=0x3f000000, 0x20000 bytes are mapped
V (587) esp_image: loading segment header 4 at offset 0x50018
D (587) bootloader_flash: mmu set block paddr=0x00050000 (was 0xffffffff)
D (590) bootloader_flash: mmu set block paddr=0x00050000 (was 0xffffffff)
V (597) esp_image: segment data length 0x12549c data starts 0x50020
V (603) esp_image: MMU page size 0x10000
V (606) esp_image: segment 4 map_segment 1 segment_data_offs 0x50020 load_addr 0x40080020
I (614) esp_image: segment 4: paddr=00050020 vaddr=40080020 size=12549ch (1201308) map
D (622) esp_image: free data page_count 0x00000038
D (626) bootloader_flash: rodata starts from paddr=0x00050020, size=0x12549c, will be mapped to vaddr=0x3f000000
V (636) bootloader_flash: after mapping, starting from paddr=0x00050000 and vaddr=0x3f000000, 0x130000 bytes are mapped
V (882) esp_image: loading segment header 5 at offset 0x1754bc
D (883) bootloader_flash: mmu set block paddr=0x00170000 (was 0xffffffff)
D (883) bootloader_flash: mmu set block paddr=0x00170000 (was 0xffffffff)
V (890) esp_image: segment data length 0x1346c data starts 0x1754c4
V (896) esp_image: MMU page size 0x10000
V (899) esp_image: segment 5 map_segment 0 segment_data_offs 0x1754c4 load_addr 0x4002c57c
I (907) esp_image: segment 5: paddr=001754c4 vaddr=4002c57c size=1346ch ( 78956) load
D (915) esp_image: free data page_count 0x00000038
D (919) bootloader_flash: rodata starts from paddr=0x001754c4, size=0x1346c, will be mapped to vaddr=0x3f000000
V (929) bootloader_flash: after mapping, starting from paddr=0x00170000 and vaddr=0x3f000000, 0x20000 bytes are mapped
V (959) esp_image: loading segment header 6 at offset 0x188930
D (959) bootloader_flash: mmu set block paddr=0x00180000 (was 0xffffffff)
D (960) bootloader_flash: mmu set block paddr=0x00180000 (was 0xffffffff)
V (967) esp_image: segment data length 0x40 data starts 0x188938
V (972) esp_image: MMU page size 0x10000
V (976) esp_image: segment 6 map_segment 0 segment_data_offs 0x188938 load_addr 0x40070000
I (984) esp_image: segment 6: paddr=00188938 vaddr=40070000 size=00040h ( 64) load
D (991) esp_image: free data page_count 0x00000038
D (996) bootloader_flash: rodata starts from paddr=0x00188938, size=0x40, will be mapped to vaddr=0x3f000000
V (1006) bootloader_flash: after mapping, starting from paddr=0x00180000 and vaddr=0x3f000000, 0x10000 bytes are mapped
V (1016) esp_image: image start 0x00010000 end of last section 0x00188978
D (1023) bootloader_flash: mmu set block paddr=0x00180000 (was 0xffffffff)
D (1029) bootloader_flash: mmu set block paddr=0x00180000 (was 0xffffffff)
D (1036) bootloader_flash: mmu set block paddr=0x00180000 (was 0xffffffff)
D (1042) bootloader_flash: mmu set block paddr=0x00180000 (was 0xffffffff)
D (1049) bootloader_flash: mmu set block paddr=0x00180000 (was 0xffffffff)
D (1056) bootloader_flash: mmu set block paddr=0x00180000 (was 0xffffffff)
D (1062) bootloader_flash: mmu set block paddr=0x00180000 (was 0xffffffff)
D (1069) bootloader_flash: mmu set block paddr=0x00180000 (was 0xffffffff)
D (1075) bootloader_flash: mmu set block paddr=0x00180000 (was 0xffffffff)
D (1082) bootloader_flash: mmu set block paddr=0x00180000 (was 0xffffffff)
D (1089) boot: Calculated hash: c252750b92e3fdcf9b2b3ad8d423aca9d210a84dcf2380065f4cd25060e76b8e
I (1110) boot: Loaded app from partition at offset 0x10000
I (1110) boot: Disabling RNG early entropy source...
D (1110) boot: Mapping segment 0 as DROM
D (1113) boot: Mapping segment 4 as IROM
D (1116) boot: calling set_cache_and_start_app
D (1121) boot: configure drom and irom and start
V (1125) boot: rodata starts from paddr=0x00010020, vaddr=0x3f000020, size=0x33dd0
V (1132) boot: after mapping rodata, starting from paddr=0x00010000 and vaddr=0x3f000000, 0x40000 bytes are mapped
V (1142) boot: mapped one page of the rodata, from paddr=0x00010000 and vaddr=0x3f3f0000, 0x10000 bytes are mapped
V (1152) boot: text starts from paddr=0x00050020, vaddr=0x40080020, size=0x12549c
V (1160) boot: after mapping text, starting from paddr=0x00050000 and vaddr=0x40080000, 0x130000 bytes are mapped
D (1170) boot: start: 0x4002557c
I (1184) cache: Instruction cache : size 8KB, 4Ways, cache line size 32Byte
I (1184) cache: Data cache : size 8KB, 4Ways, cache line size 32Byte
I (1188) cpu_start: Unicore app
I (1202) cpu_start: Pro cpu start user code
I (1202) cpu_start: cpu freq: 160000000 Hz
I (1202) app_init: Application information:
I (1204) app_init: Project name: atomvm-esp32
I (1209) app_init: App version: 1
I (1212) app_init: Compile time: Aug 19 2025 17:44:59
I (1217) app_init: ELF file SHA256: c92b634d9...
I (1222) app_init: ESP-IDF: v5.5
I (1226) efuse_init: Min chip rev: v0.0
I (1230) efuse_init: Max chip rev: v1.99
I (1234) efuse_init: Chip rev: v1.0
I (1238) heap_init: Initializing. RAM available for dynamic allocation:
I (1244) heap_init: At 3FFD81F8 len 00023E08 (143 KiB): RAM
I (1249) heap_init: At 3FFFC000 len 00003A10 (14 KiB): RAM
I (1254) heap_init: At 3FF9E060 len 00001F88 (7 KiB): RTCRAM
I (1261) spi_flash: detected chip: generic
I (1264) spi_flash: flash io: dio
W (1267) i2c: This driver is an old driver, please migrate your application code to adapt driver/i2c_master.h
I (1277) main_task: Started on CPU0
I (1277) main_task: Calling app_main()

###########################################################

   ###    ########  #######  ##     ## ##     ## ##     ##
  ## ##      ##    ##     ## ###   ### ##     ## ###   ###
 ##   ##     ##    ##     ## #### #### ##     ## #### ####
##     ##    ##    ##     ## ## ### ## ##     ## ## ### ##
#########    ##    ##     ## ##     ##  ##   ##  ##     ##
##     ##    ##    ##     ## ##     ##   ## ##   ##     ##
##     ##    ##     #######  ##     ##    ###    ##     ##

###########################################################

I (1327) AtomVM: Starting AtomVM revision 0.6.6
I (1337) sys: Loaded BEAM partition boot.avm at address 0x1d0000 (size=524288 bytes)
I (1357) network_driver: Initialized network interface
I (1357) network_driver: Created default event loop
E (1367) AtomVM: Invalid startup avmpack. size=524288

abort() was called at PC 0x4008d72a on core 0

Backtrace: 0x4002591d:0x3ffdac60 0x4003001d:0x3ffdac80 0x40038e51:0x3ffdaca0 0x4008d72a:0x3ffdad10 0x401a4a38:0x3ffdad50 0x40030e55:0x3ffdad80

ELF file SHA256: c92b634d9

The blinky.avm:

packbeam -l blinky.avm
Elixir.Blinky.beam *
Elixir.CCPrecompiler.beam
Elixir.CCPrecompiler.CompilationScript.beam
Elixir.CCPrecompiler.UniversalBinary.beam
Elixir.ElixirMake.Artefact.beam
Elixir.ElixirMake.Compiler.beam
Elixir.ElixirMake.Downloader.beam
Elixir.ElixirMake.Downloader.Httpc.beam
Elixir.ElixirMake.Precompiler.beam
Elixir.Mix.Tasks.Compile.ElixirMake.beam
Elixir.Mix.Tasks.ElixirMake.Checksum.beam
Elixir.Mix.Tasks.ElixirMake.Precompile.beam
Elixir.Fine.beam
Elixir.Inspect.Pythonx.Object.beam
Elixir.Pythonx.beam
Elixir.Pythonx.AST.beam
Elixir.Pythonx.Application.beam
Elixir.Pythonx.Encoder.beam
Elixir.Pythonx.Encoder.Atom.beam
Elixir.Pythonx.Encoder.BitString.beam
Elixir.Pythonx.Encoder.Float.beam
Elixir.Pythonx.Encoder.Integer.beam
Elixir.Pythonx.Encoder.List.beam
Elixir.Pythonx.Encoder.Map.beam
Elixir.Pythonx.Encoder.MapSet.beam
Elixir.Pythonx.Encoder.Pythonx.Object.beam
Elixir.Pythonx.Encoder.Tuple.beam
Elixir.Pythonx.Error.beam
Elixir.Pythonx.Janitor.beam
Elixir.Pythonx.NIF.beam
Elixir.Pythonx.Object.beam
Elixir.Pythonx.Utils.beam
Elixir.Pythonx.Uv.beam
Elixir.ExAtomVM.beam
Elixir.ExAtomVM.EsptoolHelper.beam
Elixir.ExAtomVM.PackBEAM.beam
Elixir.Mix.Tasks.Atomvm.Check.beam
Elixir.Mix.Tasks.Atomvm.Esp32.EraseFlash.beam
Elixir.Mix.Tasks.Atomvm.Esp32.Flash.beam
Elixir.Mix.Tasks.Atomvm.Esp32.Info.beam
Elixir.Mix.Tasks.Atomvm.Esp32.Install.beam
Elixir.Mix.Tasks.Atomvm.Packbeam.beam
Elixir.Mix.Tasks.Atomvm.Pico.Flash.beam
Elixir.Mix.Tasks.Atomvm.Stm32.Flash.beam
Elixir.Mix.Tasks.Atomvm.Uf2create.beam

I would be immensely grateful if someone could take a look and suggest what on earth I've done to break it!

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Type

    No type

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions