NanoPi Neo2 Porting Mender to Openwrt

I also now see thie error with above,

It should say:

root@phero-neo2-openwrt_mender:~# cat /data/mender/device_type
device_type=phero-neo2-openwrt_mender

arghh + thanks
dunno why they pay us so much: its just typing…

you are correct: got mender client running under procd

had initial problem with update partition mounted (by automount), caused update failure, fixed to not automount. Even after, update failed, why?, log:

2019-03-27 08:57:57 +0000 UTC info: State transition: update-store [Download] -> fetch-install-retry-wait [Download] 2019-03-27 08:57:57 +0000 UTC debug: handle fetch install retry state 2019-03-27 08:57:57 +0000 UTC debug: wait 1m0s before next fetch/install attempt 2019-03-27 08:58:57 +0000 UTC debug: wait complete 2019-03-27 08:58:57 +0000 UTC info: State transition: fetch-install-retry-wait [Download] -> update-fetch [Download] 2019-03-27 08:58:57 +0000 UTC debug: handle update fetch state 2019-03-27 08:58:57 +0000 UTC debug: status reported, response 204 No Content 2019-03-27 08:58:57 +0000 UTC debug: Received fetch update response &{200 OK 200 HTTP/1.1 1 1 map[Server:[openresty/1.13.6.2] Connection:[keep-alive] Last-Modified:[Wed, 27 Mar 2019 08:51:01 GMT] X-Content-Type-Options:[nosniff] Content-Length:[11732480] Etag:["ee9870c9808bdcfba27f50caab85bd47"] Strict-Transport-Security:[max-age=63072000; includeSubdomains; preload] Accept-Ranges:[bytes] Date:[Wed, 27 Mar 2019 08:58:57 GMT] Content-Type:[application/vnd.mender-artifact] Content-Security-Policy:[block-all-mixed-content] Vary:[Origin] X-Amz-Request-Id:[158FC51FF47F3BB7] X-Xss-Protection:[1; mode=block] X-Frame-Options:[DENY]] 0x4000462480 11732480 [] false false map[] 0x4000362300 0x400036e0b0}+ 2019-03-27 08:58:57 +0000 UTC info: State transition: update-fetch [Download] -> update-store [Download] 2019-03-27 08:58:57 +0000 UTC debug: handle update install state 2019-03-27 08:58:57 +0000 UTC debug: status reported, response 204 No Content 2019-03-27 08:58:57 +0000 UTC debug: Read data from device manifest file: device_type=phero-neo2-openwrt_mender 2019-03-27 08:58:57 +0000 UTC debug: Found needed line: device_type=phero-neo2-openwrt_mender 2019-03-27 08:58:57 +0000 UTC debug: Current manifest data: phero-neo2-openwrt_mender 2019-03-27 08:58:57 +0000 UTC info: no public key was provided for authenticating the artifact 2019-03-27 08:58:57 +0000 UTC debug: checking if device [phero-neo2-openwrt_mender] is on compatibile device list: [phero-neo2-openwrt_mender] 2019-03-27 08:58:57 +0000 UTC debug: installing update phero-neo2-openwrt_mender-ext4-rootfs.img of size 3827302400 2019-03-27 08:58:57 +0000 UTC debug: Trying to install update of size: 3827302400 2019-03-27 08:58:57 +0000 UTC debug: Inactive partition: /dev/mmcblk0p3 2019-03-27 08:58:57 +0000 UTC info: native sector size of block device /dev/mmcblk0p3 is 512, we will write in chunks of 1048576 2019-03-27 08:58:57 +0000 UTC info: opening device /dev/mmcblk0p3 for writing 2019-03-27 08:58:57 +0000 UTC info: partition /dev/mmcblk0p3 size: 3827302400 2019-03-27 09:04:19 +0000 UTC error: Download connection broken: unexpected EOF 2019-03-27 09:04:19 +0000 UTC info: Resuming download in 1m0s 2019-03-27 09:05:19 +0000 UTC info: Attempting to resume artifact download from offset 8961495 2019-03-27 09:05:19 +0000 UTC debug: Content-Range received from server: 'bytes 8961495-11732479/11732480' 2019-03-27 09:05:26 +0000 UTC info: wrote 3827302400/3827302400 bytes of update to device /dev/mmcblk0p3 2019-03-27 09:05:27 +0000 UTC debug: installer: successfully read artifact [name: phero-neo2-openwrt_mender-20190327; version: 2; compatible devices: [phero-neo2-openwrt_mender]] 2019-03-27 09:05:27 +0000 UTC debug: status reported, response 204 No Content 2019-03-27 09:05:27 +0000 UTC info: State transition: update-store [Download] -> update-install [ArtifactInstall] 2019-03-27 09:05:27 +0000 UTC debug: statescript: timeout for executing scripts is not defined; using default of 1m0s seconds 2019-03-27 09:05:27 +0000 UTC debug: statescript: timeout for executing scripts is not defined; using default of 1m0s seconds 2019-03-27 09:05:27 +0000 UTC debug: status reported, response 204 No Content 2019-03-27 09:05:27 +0000 UTC debug: Inactive partition: /dev/mmcblk0p3 2019-03-27 09:05:27 +0000 UTC debug: Marking inactive partition (/dev/mmcblk0p3) as the new boot candidate. 2019-03-27 09:05:27 +0000 UTC info: Enabling partition with new image installed to be a boot candidate: 3 2019-03-27 09:05:27 +0000 UTC debug: Have U-Boot variable: mender_check_saveenv_canary=1 2019-03-27 09:05:27 +0000 UTC debug: List of U-Boot variables:map[mender_check_saveenv_canary:1] 2019-03-27 09:05:27 +0000 UTC debug: Have U-Boot variable: mender_saveenv_canary=1 2019-03-27 09:05:27 +0000 UTC debug: List of U-Boot variables:map[mender_saveenv_canary:1] 2019-03-27 09:05:27 +0000 UTC debug: Marking inactive partition as a boot candidate successful. 2019-03-27 09:05:27 +0000 UTC info: State transition: update-install [ArtifactInstall] -> reboot [ArtifactReboot_Enter] 2019-03-27 09:05:27 +0000 UTC debug: statescript: timeout for executing scripts is not defined; using default of 1m0s seconds 2019-03-27 09:05:27 +0000 UTC debug: statescript: timeout for executing scripts is not defined; using default of 1m0s seconds 2019-03-27 09:05:27 +0000 UTC debug: handling reboot state 2019-03-27 09:05:27 +0000 UTC debug: status reported, response 204 No Content 2019-03-27 09:05:27 +0000 UTC info: rebooting device 2019-03-27 09:05:27 +0000 UTC info: Mender rebooting from active partition: /dev/mmcblk0p2 2019-03-27 08:55:33 +0000 UTC error: got invalid entrypoint into the state machine: state: reboot 2019-03-27 08:55:33 +0000 UTC info: State transition: init [none] -> update-error [ArtifactFailure] 2019-03-27 08:55:33 +0000 UTC debug: transitioning to error state 2019-03-27 08:55:33 +0000 UTC debug: statescript: timeout for executing scripts is not defined; using default of 1m0s seconds 2019-03-27 08:55:33 +0000 UTC debug: handle update error state 2019-03-27 08:55:33 +0000 UTC info: State transition: update-error [ArtifactFailure] -> update-status-report [none] 2019-03-27 08:55:33 +0000 UTC debug: handle update status report state 2019-03-27 08:55:33 +0000 UTC error: failed to report status: Put https://mender.privacyhero.com/api/devices/v1/deployments/device/deployments/e9327836-919f-4c4f-8398-534145cae7af/status: dial tcp: lookup mender.privacyhero.com on [::1]:53: read udp [::1]:58126->[::1]:53: read: connection refused 2019-03-27 08:55:33 +0000 UTC error: error reporting update status: reporting status failed: Put https://mender.privacyhero.com/api/devices/v1/deployments/device/deployments/e9327836-919f-4c4f-8398-534145cae7af/status: dial tcp: lookup mender.privacyhero.com on [::1]:53: read udp [::1]:58126->[::1]:53: read: connection refused 2019-03-27 08:55:33 +0000 UTC error: failed to send status to server: transient error: reporting status failed: Put https://mender.privacyhero.com/api/devices/v1/deployments/device/deployments/e9327836-919f-4c4f-8398-534145cae7af/status: dial tcp: lookup mender.privacyhero.com on [::1]:53: read udp [::1]:58126->[::1]:53: read: connection refused 2019-03-27 08:55:33 +0000 UTC info: State transition: update-status-report [ArtifactFailure] -> update-retry-report [none] 2019-03-27 09:06:46 +0000 UTC debug: wait complete 2019-03-27 09:06:46 +0000 UTC info: State transition: update-retry-report [ArtifactFailure] -> update-status-report [ArtifactFailure] 2019-03-27 09:06:46 +0000 UTC debug: handle update status report state 2019-03-27 09:06:47 +0000 UTC debug: status reported, response 204 No Content 2019-03-27 09:06:47 +0000 UTC debug: attempting to upload deployment logs for failed update

Regards;
Bill

2019-03-27 08:55:33 +0000 UTC error: failed to report status: Put https://mender.privacyhero.com/api/devices/v1/deployments/device/deployments/e9327836-919f-4c4f-8398-534145cae7af/status: dial tcp: lookup mender.privacyhero.com on [::1]:53: read udp [::1]:58126->[::1]:53: read: connection refused 2019-03-27 08:55:33

It seems that it is not able to connect to the server after update, in which case it will mark the update as failed and roll-back.

do you ever sleep?:grinning:

Yes, I suspect maybe IPV6 or port 53 related. My N/W infrastructure is complex and may be an issue. Wireshark…, standby

Oh this is actually root of the problem,

08:55:33 +0000 UTC error: got invalid entrypoint into the state machine: state: reboot

Which indicates that it actually did not switch root partition when you updated and reboot, which hints that there is something wrong with U-boot environment.

Did you check if all steps pass in our integration checklist,

https://docs.mender.io/1.7/devices/yocto-project/bootloader-support/u-boot/integration-checklist

Specifically steps 6 to 10

Will re-verify, some changes after last checklist run may have broken things…

verified: both uboot and linux can set and read each others variables

Think I know what is wrong. The replacement image does not autoinstall and start mender client @firstboot. Standby…

Walking trough the log,

2019-03-27 09:05:27 +0000 UTC debug: Inactive partition: /dev/mmcblk0p3 
2019-03-27 09:05:27 +0000 UTC debug: Marking inactive partition (/dev/mmcblk0p3) as the new boot candidate. 

This should have updated the environment variables in U-boot, so that the next time device boots it it will boot from /dev/mmcblk0p3

Then it actually triggers the reboot,

2019-03-27 09:05:27 +0000 UTC info: rebooting device 
2019-03-27 09:05:27 +0000 UTC info: Mender rebooting from active partition: /dev/mmcblk0p2 

And once it has booted it is reporting,

2019-03-27 08:55:33 +0000 UTC error: got invalid entrypoint into the state machine: state: reboot 

This indicates that it did not manage to change to /dev/mmcblk0p3 and is instead still on /dev/mmcblk0p2. A bit weird that time went backwards here, but do not think that it would case any problems.

The only thing that I can think of now is that your bootcmd does not respect the mender_boot_part/mender_boot_part_hex

Can you paste your boot.scr from the device.

boot.scr:

some binary preamble...
run mender_setup
setenv loadkernel load  \${mender_uboot_root}  \${kernel_addr_r} /boot/uImage
setenv loaddtb  load \${mender_uboot_root}  \${fdt_addr_r} /boot/dtb
setenv bootargs console=ttyS0,115200 earlyprintk root=${mender_kernel_root_name} rootwait earlycon=uart,mmio32,0x01c28000
setenv uenvcmd run loadkernel \&\& run loaddtb \&\& booti \${kernel_addr_r} - \${fdt_addr_r}
run uenvcmd; run mender_try_to_recover

setenv bootargs console=ttyS0,115200 earlyprintk root=${mender_kernel_root_name} rootwait earlycon=uart,mmio32,0x01c28000

root= should be,

 root=${mender_kernel_root}

Edit: I missed this when you initially posted the script

Another test you can run is,

setenv mender_boot_part 3
setenv mender_boot_part_hex 3
mender_setup
setenv bootargs console=ttyS0,115200 earlyprintk root=${mender_kernel_root} rootwait earlycon=uart,mmio32,0x01c28000
print bootargs

It should show that ${mender_kernel_root} has been expanded to /dev/mmcblk0p3

hmm; neither mender_kernel_root or mender_kernel_root_name are defined, perhaps due to “mender_saveenv_canary=1” when mender_setup called?

fw_printenv:

altbootcmd=run mender_altbootcmd; run bootcmd
arch=arm
baudrate=115200
board=sunxi
board_name=sunxi
boot_a_script=load ${devtype} ${devnum}:${distro_bootpart} ${scriptaddr} ${prefix}${script}; source ${scriptaddr}
boot_efi_binary=if fdt addr ${fdt_addr_r}; then bootefi bootmgr ${fdt_addr_r};else bootefi bootmgr ${fdtcontroladdr};fi;load ${devtype} ${devnum}:${distro_bootpart} ${kernel_addr_r} efi/boot/bootaa64.efi; if fdt addr ${fdt_addr_r}; then bootefi ${kernel_addr_r} ${fdt_addr_r};else bootefi ${kernel_addr_r} ${fdtcontroladdr};fi
boot_extlinux=sysboot ${devtype} ${devnum}:${distro_bootpart} any ${scriptaddr} ${prefix}extlinux/extlinux.conf
boot_net_usb_start=usb start
boot_prefixes=/ /boot/
boot_script_dhcp=boot.scr.uimg
boot_scripts=boot.scr.uimg boot.scr
boot_targets=fel mmc0 usb0 pxe dhcp 
bootcmd=run distro_bootcmd
bootcmd_dhcp=run boot_net_usb_start; if dhcp ${scriptaddr} ${boot_script_dhcp}; then source ${scriptaddr}; fi;setenv efi_fdtfile ${fdtfile}; setenv efi_old_vci ${bootp_vci};setenv efi_old_arch ${bootp_arch};setenv bootp_vci PXEClient:Arch:00011:UNDI:003000;setenv bootp_arch 0xb;if dhcp ${kernel_addr_r}; then tftpboot ${fdt_addr_r} dtb/${efi_fdtfile};if fdt addr ${fdt_addr_r}; then bootefi ${kernel_addr_r} ${fdt_addr_r}; else bootefi ${kernel_addr_r} ${fdtcontroladdr};fi;fi;setenv bootp_vci ${efi_old_vci};setenv bootp_arch ${efi_old_arch};setenv efi_fdtfile;setenv efi_old_arch;setenv efi_old_vci;
bootcmd_fel=if test -n ${fel_booted} && test -n ${fel_scriptaddr}; then echo '(FEL boot)'; source ${fel_scriptaddr}; fi
bootcmd_mmc0=setenv devnum 0; run mmc_boot
bootcmd_pxe=run boot_net_usb_start; dhcp; if pxe get; then pxe boot; fi
bootcmd_usb0=setenv devnum 0; run usb_boot
bootcount=1
bootdelay=2
bootfstype=fat
bootlimit=1
bootm_size=0xa000000
console=ttyS0,115200
cpu=armv8
devnum=0
devplist=1
devtype=mmc
dfu_alt_info_ram=kernel ram 0x40080000 0x1000000;fdt ram 0x4FA00000 0x100000;ramdisk ram 0x4FE00000 0x4000000
distro_bootcmd=for target in ${boot_targets}; do run bootcmd_${target}; done
efi_dtb_prefixes=/ /dtb/ /dtb/current/
ethaddr=02:01:65:f3:03:89
fdt_addr_r=0x4FA00000
fdtcontroladdr=59f4b920
fdtfile=allwinner/sun50i-h5-nanopi-neo2.dtb
fileaddr=4fc00000
filesize=1ea
kernel_addr_r=0x40080000
load_efi_dtb=load ${devtype} ${devnum}:${distro_bootpart} ${fdt_addr_r} ${prefix}${efi_fdtfile}
mender_altbootcmd=if test ${mender_boot_part} = 2; then setenv mender_boot_part 3; setenv mender_boot_part_hex 3; else setenv mender_boot_part 2; setenv mender_boot_part_hex 2; fi; setenv upgrade_available 0; saveenv; run mender_setup
mender_boot_kernel_type=bootm
mender_boot_part=2
mender_boot_part_hex=2
mender_check_saveenv_canary=1
mender_dtb_name=dtb
mender_kernel_name=uImage
mender_linux_test=1
mender_saveenv_canary=1
mender_setup=if test "${mender_saveenv_canary}" != "1"; then setenv mender_saveenv_canary 1; saveenv; fi; if test "${mender_pre_setup_commands}" != ""; then run mender_pre_setup_commands; fi; setenv mender_kernel_root /dev/mmcblk0${mender_boot_part}; if test ${mender_boot_part} = 2; then setenv mender_boot_part_name /dev/mmcblk0p2; else setenv mender_boot_part_name /dev/mmcblk0p3; fi; setenv mender_kernel_root_name ${mender_boot_part_name}; setenv mender_uboot_root mmc 0:${mender_boot_part_hex}; setenv mender_uboot_root_name ${mender_boot_part_name}; setenv expand_bootargs "setenv bootargs \\"${bootargs}\\""; run expand_bootargs; setenv expand_bootargs; if test "${mender_post_setup_commands}" != ""; then run mender_post_setup_commands; fi
mender_try_to_recover=if test ${upgrade_available} = 1; then reset; fi
mender_uboot_boot=mmc 0:1
mender_uboot_dev=0
mender_uboot_if=mmc
mender_uboot_test=1
mmc_boot=if mmc dev ${devnum}; then setenv devtype mmc; run scan_dev_for_boot_part; fi
mmc_bootdev=0
partitions=name=loader1,start=8k,size=32k,uuid=${uuid_gpt_loader1};name=loader2,size=984k,uuid=${uuid_gpt_loader2};name=esp,size=128M,bootable,uuid=${uuid_gpt_esp};name=system,size=-,uuid=${uuid_gpt_system};
preboot=usb start
pxefile_addr_r=0x4FD00000
ramdisk_addr_r=0x4FE00000
scan_dev_for_boot=echo Scanning ${devtype} ${devnum}:${distro_bootpart}...; for prefix in ${boot_prefixes}; do run scan_dev_for_extlinux; run scan_dev_for_scripts; done;run scan_dev_for_efi;
scan_dev_for_boot_part=part list ${devtype} ${devnum} -bootable devplist; env exists devplist || setenv devplist 1; for distro_bootpart in ${devplist}; do if fstype ${devtype} ${devnum}:${distro_bootpart} bootfstype; then run scan_dev_for_boot; fi; done
scan_dev_for_efi=setenv efi_fdtfile ${fdtfile}; for prefix in ${efi_dtb_prefixes}; do if test -e ${devtype} ${devnum}:${distro_bootpart} ${prefix}${efi_fdtfile}; then run load_efi_dtb; fi;done;if test -e ${devtype} ${devnum}:${distro_bootpart} efi/boot/bootaa64.efi; then echo Found EFI removable media binary efi/boot/bootaa64.efi; run boot_efi_binary; echo EFI LOAD FAILED: continuing...; fi; setenv efi_fdtfile
scan_dev_for_extlinux=if test -e ${devtype} ${devnum}:${distro_bootpart} ${prefix}extlinux/extlinux.conf; then echo Found ${prefix}extlinux/extlinux.conf; run boot_extlinux; echo SCRIPT FAILED: continuing...; fi
scan_dev_for_scripts=for script in ${boot_scripts}; do if test -e ${devtype} ${devnum}:${distro_bootpart} ${prefix}${script}; then echo Found U-Boot script ${prefix}${script}; run boot_a_script; echo SCRIPT FAILED: continuing...; fi; done
scriptaddr=0x4FC00000
serial#=8280000165f30389
soc=sunxi
stderr=serial,vidconsole
stdin=serial,usbkbd
stdout=serial,vidconsole
upgrade_available=0
usb_boot=usb start; if usb dev ${devnum}; then setenv devtype usb; run scan_dev_for_boot_part; fi
uuid_gpt_esp=c12a7328-f81f-11d2-ba4b-00a0c93ec93b
uuid_gpt_system=b921b045-1df0-41c3-af44-4c6f280d3fae

@uboot prompt, “run mender_setup”, “printenv mender_kernel_root” (/dev/mmcblk02)
and yet, when linux boots, mender_kernel_root undefined

They are set by mender_setup and not normally saved (meaning that they are not visible in Linux). So that part is ok.

Is there something I can do to boot.scr to have uboot stall @command prompt just before starting linux from boot partition (examine variables)?

Drop this line,

 run uenvcmd; run mender_try_to_recover

Falls through to TFTP boot; before then:
switch to partitions #0 OK
mmc0 is current device
Scanning mmc 0:1…
Found U-Boot script /boot.scr
491 bytes read in 0ms

Executing script at 4fc00000

Saving environment to MMC… Writing to redundant MMC(0)… OK
SCRIPT FAILED: continuing…

Device 0: device type unknown
… is now current device
…then TFTP eth setup …