Azure / iotedge

The IoT Edge OSS project
MIT License
1.45k stars 458 forks source link

1.2.0-rc1 edgeHub failure on tier two ARM64 device #3974

Closed dvescovi1 closed 3 years ago

dvescovi1 commented 3 years ago

Expected Behavior

agent and hub should be stable with no other modules deployed

Current Behavior

edgeHub module crashes and restarts, crashes etc.

Steps to Reproduce

Provide a detailed set of steps to reproduce the bug.

  1. deploy hub and agent to ARM64 device running run time 1.0.9.4
  2. no routes defined

Context (Environment)

Output of iotedge check

Click here ``` root@imx8mmevk:~# iotedge check Configuration checks -------------------- √ config.yaml is well-formed - OK √ config.yaml has well-formed connection string - OK √ container engine is installed and functional - OK √ config.yaml has correct hostname - OK [ 7966.521950] docker0: port 1(veth17faf83) entered blocking state [ 7966.527958] docker0: port 1(veth17faf83) entered disabled state [ 7966.534190] device veth17faf83 entered promiscuous mode [ 7966.539583] kauditd_printk_skb: 20 callbacks suppressed [ 7966.539588] audit: type=1700 audit(1605536219.381:1243): dev=veth17faf83 prom=256 old_prom=0 auid=4294967295 uid=0 gid=0 ses=4294967295 [ 7966.540458] IPv6: ADDRCONF(NETDEV_UP): veth17faf83: link is not ready [ 7966.544930] audit: type=1300 audit(1605536219.381:1243): arch=c00000b7 syscall=206 success=yes exit=40 a0=c a1=4001502fc0 a2=28 a3=0 items=0 ppid=1 pid=3513 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=(none) ses=4294967295 comm="dockerd" exe="/usr/bin/dockerd" key=(null) [ 7966.559851] IPv6: ADDRCONF(NETDEV_UP): veth2edfbf1: link is not ready [ 7966.563562] audit: type=1327 audit(1605536219.381:1243): proctitle=2F7573722F62696E2F646F636B657264002D480066643A2F2F [ 7966.590386] IPv6: ADDRCONF(NETDEV_CHANGE): veth2edfbf1: link becomes ready [ 7966.614447] IPv6: ADDRCONF(NETDEV_CHANGE): veth17faf83: link becomes ready [ 7966.621528] docker0: port 1(veth17faf83) entered blocking state [ 7966.627491] docker0: port 1(veth17faf83) entered forwarding state [ 7966.633818] IPv6: ADDRCONF(NETDEV_CHANGE): docker0: link becomes ready [ 7967.052074] eth0: renamed from veth2edfbf1 [ 7967.072557] docker0: port 1(veth17faf83) entered disabled state [ 7967.079658] docker0: port 1(veth17faf83) entered blocking state [ 7967.085620] docker0: port 1(veth17faf83) entered forwarding state [ 7967.447418] docker0: port 1(veth17faf83) entered disabled state [ 7967.454434] veth2edfbf1: renamed from eth0 [ 7967.499362] IPv6: ADDRCONF(NETDEV_UP): veth17faf83: link is not ready [ 7967.508685] IPv6: ADDRCONF(NETDEV_CHANGE): veth17faf83: link becomes ready [ 7967.515758] docker0: port 1(veth17faf83) entered blocking state [ 7967.521732] docker0: port 1(veth17faf83) entered forwarding state [ 7967.530928] docker0: port 1(veth17faf83) entered disabled state [ 7967.540025] device veth17faf83 left promiscuous mode [ 7967.545069] docker0: port 1(veth17faf83) entered disabled state [ 7967.545098] audit: type=1700 audit(1605536220.389:1244): dev=veth17faf83 prom=0 old_prom=256 auid=4294967295 uid=0 gid=0 ses=4294967295 [ 7967.589922] IPv6: ADDRCONF(NETDEV_UP): wlan0: link is not ready [ 7967.595898] IPv6: ADDRCONF(NETDEV_UP): p2p0: link is not ready [ 7967.602994] IPv6: ADDRCONF(NETDEV_UP): wlan0: link is not ready [ 7967.608956] IPv6: ADDRCONF(NETDEV_UP): p2p0: link is not ready [ 7967.615577] IPv6: ADDRCONF(NETDEV_UP): wlan0: link is not ready [ 7967.621629] IPv6: ADDRCONF(NETDEV_UP): p2p0: link is not ready [ 7967.627772] audit: type=1300 audit(1605536220.389:1244): arch=c00000b7 syscall=206 success=yes exit=32 a0=c a1=4000df4240 a2=20 a3=0 items=0 ppid=1 pid=3513 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=(none) ses=4294967295 comm="dockerd" exe="/usr/bin/dockerd" key=(null) [ 7967.654627] audit: type=1327 audit(1605536220.389:1244): proctitle=2F7573722F62696E2F646F636B657264002D480066643A2F2F √ config.yaml has correct URIs for daemon mgmt endpoint - OK ‼ latest security daemon - Warning Installed IoT Edge daemon has version 1.0.9.4 but 1.0.10.2 is the latest stable version available. Please see https://aka.ms/iotedge-update-runtime for update instructions. √ host time is close to real time - OK [ 7968.251455] IPv6: ADDRCONF(NETDEV_UP): veth13d5f4c: link is not ready [ 7968.259445] IPv6: ADDRCONF(NETDEV_CHANGE): veth13d5f4c: link becomes ready [ 7968.268875] docker0: port 1(veth6275e5a) entered blocking state [ 7968.274934] docker0: port 1(veth6275e5a) entered disabled state [ 7968.281255] device veth6275e5a entered promiscuous mode [ 7968.286586] audit: type=1700 audit(1605536221.129:1245): dev=veth6275e5a prom=256 old_prom=0 auid=4294967295 uid=0 gid=0 ses=4294967295 [ 7968.286823] docker0: port 1(veth6275e5a) entered blocking state [ 7968.304696] docker0: port 1(veth6275e5a) entered forwarding state [ 7968.311257] audit: type=1300 audit(1605536221.129:1245): arch=c00000b7 syscall=206 success=yes exit=40 a0=c a1=4000057320 a2=28 a3=0 items=0 ppid=1 pid=3513 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=(none) ses=4294967295 comm="dockerd" exe="/usr/bin/dockerd" key=(null) [ 7968.338163] audit: type=1327 audit(1605536221.129:1245): proctitle=2F7573722F62696E2F646F636B657264002D480066643A2F2F [ 7968.827672] docker0: port 1(veth6275e5a) entered disabled state [ 7968.836167] eth0: renamed from veth13d5f4c [ 7968.859234] IPv6: ADDRCONF(NETDEV_UP): veth6275e5a: link is not ready [ 7968.865907] IPv6: ADDRCONF(NETDEV_CHANGE): veth6275e5a: link becomes ready [ 7968.872988] docker0: port 1(veth6275e5a) entered blocking state [ 7968.878937] docker0: port 1(veth6275e5a) entered forwarding state [ 7969.422459] docker0: port 1(veth6275e5a) entered disabled state [ 7969.429258] veth13d5f4c: renamed from eth0 [ 7969.479876] IPv6: ADDRCONF(NETDEV_UP): veth6275e5a: link is not ready [ 7969.488642] IPv6: ADDRCONF(NETDEV_CHANGE): veth6275e5a: link becomes ready [ 7969.495845] docker0: port 1(veth6275e5a) entered blocking state [ 7969.501828] docker0: port 1(veth6275e5a) entered forwarding state [ 7969.516127] docker0: port 1(veth6275e5a) entered disabled state [ 7969.524824] device veth6275e5a left promiscuous mode [ 7969.529903] docker0: port 1(veth6275e5a) entered disabled state [ 7969.529933] audit: type=1700 audit(1605536222.373:1246): dev=veth6275e5a prom=0 old_prom=256 auid=4294967295 uid=0 gid=0 ses=4294967295 [ 7969.586111] IPv6: ADDRCONF(NETDEV_UP): docker0: link is not ready [ 7969.592396] IPv6: ADDRCONF(NETDEV_UP): wlan0: link is not ready [ 7969.598405] IPv6: ADDRCONF(NETDEV_UP): p2p0: link is not ready √ container time is close to host time - OK ‼ DNS server - Warning Container engine is not configured with DNS server setting, which may impact connectivity to IoT Hub. Please see https://aka.ms/iotedge-prod-checklist-dns for best practices. You can ignore this warning if you are setting DNS server per module in the Edge deployment. ‼ production readiness: certificates - Warning The Edge device is using self-signed automatically-generated development certificates. They will expire in 87 days (at 2021-02-12 02:32:17 UTC) causing module-to-module and downstream device communication to fail on an active deployment. After the certs have expired, restarting the IoT Edge daemon will trigger it to generate new development certs. Please consider using production certificates instead. See https://aka.ms/iotedge-prod-checklist-certs for best practices. ‼ production readiness: container engine - Warning Device is not using a production-supported container engine (moby-engine). Please see https://aka.ms/iotedge-prod-checklist-moby for details. ‼ production readiness: logs policy - Warning Container engine is not configured to rotate module logs which may cause it run out of disk space. Please see https://aka.ms/iotedge-prod-checklist-logs for best practices. You can ignore this warning if you are setting log policy per module in the Edge deployment. ‼ production readiness: Edge Agent's storage directory is persisted on the host filesystem - Warning The edgeAgent module is not configured to persist its /tmp/edgeAgent directory on the host filesystem. Data might be lost if the module is deleted or updated. Please see https://aka.ms/iotedge-storage-host for best practices. ‼ production readiness: Edge Hub's storage directory is persisted on the host filesystem - Warning The edgeHub module is not configured to persist its /tmp/edgeHub directory on the host filesystem. Data might be lost if the module is deleted or updated. Please see https://aka.ms/iotedge-storage-host for best practices. Connectivity checks ------------------- √ host can connect to and perform TLS handshake with IoT Hub AMQP port - OK √ host can connect to and perform TLS handshake with IoT Hub HTTPS / WebSockets port - OK √ host can connect to and perform TLS handshake with IoT Hub MQTT port - OK [ 7970.936153] IPv6: ADDRCONF(NETDEV_UP): veth7fb6834: link is not ready [ 7970.943274] docker0: port 1(vethe1182f4) entered blocking state [ 7970.949264] docker0: port 1(vethe1182f4) entered disabled state [ 7970.955395] device vethe1182f4 entered promiscuous mode [ 7970.961325] IPv6: ADDRCONF(NETDEV_UP): vethe1182f4: link is not ready [ 7970.968216] IPv6: ADDRCONF(NETDEV_CHANGE): vethe1182f4: link becomes ready [ 7970.975287] docker0: port 1(vethe1182f4) entered blocking state [ 7970.981272] docker0: port 1(vethe1182f4) entered forwarding state [ 7970.987528] IPv6: ADDRCONF(NETDEV_CHANGE): veth7fb6834: link becomes ready [ 7970.994636] IPv6: ADDRCONF(NETDEV_CHANGE): docker0: link becomes ready [ 7971.507699] docker0: port 1(vethe1182f4) entered disabled state [ 7971.514765] eth0: renamed from veth7fb6834 [ 7971.539230] IPv6: ADDRCONF(NETDEV_UP): vethe1182f4: link is not ready [ 7971.545914] IPv6: ADDRCONF(NETDEV_CHANGE): vethe1182f4: link becomes ready [ 7971.552978] docker0: port 1(vethe1182f4) entered blocking state [ 7971.558940] docker0: port 1(vethe1182f4) entered forwarding state [ 7972.010893] docker0: port 1(vethe1182f4) entered disabled state [ 7972.016951] veth7fb6834: renamed from eth0 [ 7972.075863] IPv6: ADDRCONF(NETDEV_UP): vethe1182f4: link is not ready [ 7972.084469] IPv6: ADDRCONF(NETDEV_CHANGE): vethe1182f4: link becomes ready [ 7972.091541] docker0: port 1(vethe1182f4) entered blocking state [ 7972.097510] docker0: port 1(vethe1182f4) entered forwarding state [ 7972.107980] docker0: port 1(vethe1182f4) entered disabled state [ 7972.116235] device vethe1182f4 left promiscuous mode [ 7972.121297] docker0: port 1(vethe1182f4) entered disabled state [ 7972.121325] kauditd_printk_skb: 5 callbacks suppressed [ 7972.121330] audit: type=1700 audit(1605536224.965:1248): dev=vethe1182f4 prom=0 old_prom=256 auid=4294967295 uid=0 gid=0 ses=4294967295 [ 7972.181861] IPv6: ADDRCONF(NETDEV_UP): wlan0: link is not ready [ 7972.187855] IPv6: ADDRCONF(NETDEV_UP): p2p0: link is not ready [ 7972.195383] audit: type=1300 audit(1605536224.965:1248): arch=c00000b7 syscall=206 success=yes exit=32 a0=c a1=4000ff1d00 a2=20 a3=0 items=0 ppid=1 pid=3513 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=(none) ses=4294967295 comm="dockerd" exe="/usr/bin/dockerd" key=(null) [ 7972.222255] audit: type=1327 audit(1605536224.965:1248): proctitle=2F7573722F62696E2F646F636B657264002D480066643A2F2F √ container on the default network can connect to IoT Hub AMQP port - OK [ 7972.673071] docker0: port 1(veth9e67432) entered blocking state [ 7972.679112] docker0: port 1(veth9e67432) entered disabled state [ 7972.685379] device veth9e67432 entered promiscuous mode [ 7972.690732] audit: type=1700 audit(1605536225.533:1249): dev=veth9e67432 prom=256 old_prom=0 auid=4294967295 uid=0 gid=0 ses=4294967295 [ 7972.691916] IPv6: ADDRCONF(NETDEV_UP): veth9e67432: link is not ready [ 7972.703128] audit: type=1300 audit(1605536225.533:1249): arch=c00000b7 syscall=206 success=yes exit=40 a0=c a1=40007e1ec0 a2=28 a3=0 items=0 ppid=1 pid=3513 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=(none) ses=4294967295 comm="dockerd" exe="/usr/bin/dockerd" key=(null) [ 7972.709570] docker0: port 1(veth9e67432) entered blocking state [ 7972.736247] audit: type=1327 audit(1605536225.533:1249): proctitle=2F7573722F62696E2F646F636B657264002D480066643A2F2F [ 7972.742120] docker0: port 1(veth9e67432) entered forwarding state [ 7972.744731] IPv6: ADDRCONF(NETDEV_CHANGE): veth9e67432: link becomes ready [ 7973.240178] docker0: port 1(veth9e67432) entered disabled state [ 7973.247458] eth0: renamed from veth324ed87 [ 7973.271255] IPv6: ADDRCONF(NETDEV_UP): veth9e67432: link is not ready [ 7973.277885] IPv6: ADDRCONF(NETDEV_CHANGE): veth9e67432: link becomes ready [ 7973.284956] docker0: port 1(veth9e67432) entered blocking state [ 7973.290918] docker0: port 1(veth9e67432) entered forwarding state [ 7973.785559] docker0: port 1(veth9e67432) entered disabled state [ 7973.792467] veth324ed87: renamed from eth0 [ 7973.835581] IPv6: ADDRCONF(NETDEV_UP): veth9e67432: link is not ready [ 7973.844413] IPv6: ADDRCONF(NETDEV_CHANGE): veth9e67432: link becomes ready [ 7973.851500] docker0: port 1(veth9e67432) entered blocking state [ 7973.857476] docker0: port 1(veth9e67432) entered forwarding state [ 7973.866267] docker0: port 1(veth9e67432) entered disabled state [ 7973.875136] device veth9e67432 left promiscuous mode [ 7973.880220] docker0: port 1(veth9e67432) entered disabled state [ 7973.880253] audit: type=1700 audit(1605536226.725:1250): dev=veth9e67432 prom=0 old_prom=256 auid=4294967295 uid=0 gid=0 ses=4294967295 [ 7973.909111] IPv6: ADDRCONF(NETDEV_UP): wlan0: link is not ready [ 7973.915105] IPv6: ADDRCONF(NETDEV_UP): p2p0: link is not ready [ 7973.922102] IPv6: ADDRCONF(NETDEV_UP): wlan0: link is not ready [ 7973.928063] IPv6: ADDRCONF(NETDEV_UP): p2p0: link is not ready [ 7973.934523] IPv6: ADDRCONF(NETDEV_UP): wlan0: link is not ready [ 7973.940535] IPv6: ADDRCONF(NETDEV_UP): p2p0: link is not ready [ 7973.946749] audit: type=1300 audit(1605536226.725:1250): arch=c00000b7 syscall=206 success=yes exit=32 a0=c a1=40000f5f00 a2=20 a3=0 items=0 ppid=1 pid=3513 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=(none) ses=4294967295 comm="dockerd" exe="/usr/bin/dockerd" key=(null) [ 7973.973594] audit: type=1327 audit(1605536226.725:1250): proctitle=2F7573722F62696E2F646F636B657264002D480066643A2F2F √ container on the default network can connect to IoT Hub HTTPS / WebSockets port - OK [ 7974.521369] IPv6: ADDRCONF(NETDEV_UP): vethb3277d8: link is not ready [ 7974.528264] docker0: port 1(vethdee0b27) entered blocking state [ 7974.534296] docker0: port 1(vethdee0b27) entered disabled state [ 7974.540464] device vethdee0b27 entered promiscuous mode [ 7974.545795] audit: type=1700 audit(1605536227.389:1251): dev=vethdee0b27 prom=256 old_prom=0 auid=4294967295 uid=0 gid=0 ses=4294967295 [ 7974.551091] docker0: port 1(vethdee0b27) entered blocking state [ 7974.563938] docker0: port 1(vethdee0b27) entered forwarding state [ 7974.570434] IPv6: ADDRCONF(NETDEV_CHANGE): vethb3277d8: link becomes ready [ 7975.075420] docker0: port 1(vethdee0b27) entered disabled state [ 7975.082433] eth0: renamed from vethb3277d8 [ 7975.107126] IPv6: ADDRCONF(NETDEV_UP): vethdee0b27: link is not ready [ 7975.113726] IPv6: ADDRCONF(NETDEV_CHANGE): vethdee0b27: link becomes ready [ 7975.120876] docker0: port 1(vethdee0b27) entered blocking state [ 7975.126830] docker0: port 1(vethdee0b27) entered forwarding state [ 7975.548891] docker0: port 1(vethdee0b27) entered disabled state [ 7975.555048] vethb3277d8: renamed from eth0 [ 7975.603200] IPv6: ADDRCONF(NETDEV_UP): vethdee0b27: link is not ready [ 7975.611929] IPv6: ADDRCONF(NETDEV_CHANGE): vethdee0b27: link becomes ready [ 7975.618991] docker0: port 1(vethdee0b27) entered blocking state [ 7975.624973] docker0: port 1(vethdee0b27) entered forwarding state [ 7975.633578] docker0: port 1(vethdee0b27) entered disabled state [ 7975.642001] device vethdee0b27 left promiscuous mode [ 7975.647057] docker0: port 1(vethdee0b27) entered disabled state [ 7975.676266] IPv6: ADDRCONF(NETDEV_UP): wlan0: link is not ready [ 7975.682226] IPv6: ADDRCONF(NETDEV_UP): p2p0: link is not ready [ 7975.689197] IPv6: ADDRCONF(NETDEV_UP): wlan0: link is not ready [ 7975.695168] IPv6: ADDRCONF(NETDEV_UP): p2p0: link is not ready [ 7975.701734] IPv6: ADDRCONF(NETDEV_UP): wlan0: link is not ready [ 7975.707727] IPv6: ADDRCONF(NETDEV_UP): p2p0: link is not ready √ container on the default network can connect to IoT Hub MQTT port - OK [ 7976.250410] IPv6: ADDRCONF(NETDEV_UP): veth8fc6e8a: link is not ready [ 7976.257393] br-a425e4d87bb3: port 2(veth175eeb3) entered blocking state [ 7976.264107] br-a425e4d87bb3: port 2(veth175eeb3) entered disabled state [ 7976.271100] device veth175eeb3 entered promiscuous mode [ 7976.276984] br-a425e4d87bb3: port 2(veth175eeb3) entered blocking state [ 7976.283640] br-a425e4d87bb3: port 2(veth175eeb3) entered forwarding state [ 7976.290776] IPv6: ADDRCONF(NETDEV_CHANGE): veth8fc6e8a: link becomes ready [ 7977.128391] kauditd_printk_skb: 17 callbacks suppressed [ 7977.128395] audit: type=1325 audit(1605536229.989:1257): table=nat family=2 entries=7 [ 7977.141761] audit: type=1300 audit(1605536229.989:1257): arch=c00000b7 syscall=208 success=yes exit=0 a0=4 a1=0 a2=40 a3=aaaae7ebe320 items=0 ppid=34131 pid=34147 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=(none) ses=4294967295 comm="iptables" exe="/usr/sbin/xtables-legacy-multi" key=(null) [ 7977.171482] audit: type=1327 audit(1605536229.989:1257): proctitle=2F7573722F7362696E2F69707461626C6573002D2D77616974002D74006E6174002D49004F5554505554002D64003132372E302E302E3131002D6A00444F434B45525F4F5554505554 [ 7977.190514] audit: type=1325 audit(1605536230.009:1258): table=nat family=2 entries=8 [ 7977.198390] audit: type=1300 audit(1605536230.009:1258): arch=c00000b7 syscall=208 success=yes exit=0 a0=4 a1=0 a2=40 a3=aaaad9e31db0 items=0 ppid=34131 pid=34149 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=(none) ses=4294967295 comm="iptables" exe="/usr/sbin/xtables-legacy-multi" key=(null) [ 7977.227016] audit: type=1327 audit(1605536230.009:1258): proctitle=2F7573722F7362696E2F69707461626C6573002D2D77616974002D74006E6174002D4E00444F434B45525F504F5354524F5554494E47 [ 7977.242722] audit: type=1325 audit(1605536230.021:1259): table=nat family=2 entries=10 [ 7977.250760] audit: type=1300 audit(1605536230.021:1259): arch=c00000b7 syscall=208 success=yes exit=0 a0=4 a1=0 a2=40 a3=aaaaf58e7670 items=0 ppid=34131 pid=34150 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=(none) ses=4294967295 comm="iptables" exe="/usr/sbin/xtables-legacy-multi" key=(null) [ 7977.279373] audit: type=1327 audit(1605536230.021:1259): proctitle=2F7573722F7362696E2F69707461626C6573002D2D77616974002D74006E6174002D4900504F5354524F5554494E47002D64003132372E302E302E3131002D6A00444F434B45525F504F5354524F5554494E47 [ 7977.411524] audit: type=1325 audit(1605536230.033:1260): table=nat family=2 entries=11 [ 7977.483282] br-a425e4d87bb3: port 2(veth175eeb3) entered disabled state [ 7977.492039] eth0: renamed from veth8fc6e8a [ 7977.511692] IPv6: ADDRCONF(NETDEV_UP): veth175eeb3: link is not ready [ 7977.518828] IPv6: ADDRCONF(NETDEV_CHANGE): veth175eeb3: link becomes ready [ 7977.525920] br-a425e4d87bb3: port 2(veth175eeb3) entered blocking state [ 7977.532576] br-a425e4d87bb3: port 2(veth175eeb3) entered forwarding state [ 7977.905410] br-a425e4d87bb3: port 2(veth175eeb3) entered disabled state [ 7977.912323] veth8fc6e8a: renamed from eth0 [ 7977.963767] IPv6: ADDRCONF(NETDEV_UP): veth175eeb3: link is not ready [ 7977.972473] IPv6: ADDRCONF(NETDEV_CHANGE): veth175eeb3: link becomes ready [ 7977.979563] br-a425e4d87bb3: port 2(veth175eeb3) entered blocking state [ 7977.986222] br-a425e4d87bb3: port 2(veth175eeb3) entered forwarding state [ 7977.996825] br-a425e4d87bb3: port 2(veth175eeb3) entered disabled state [ 7978.005834] device veth175eeb3 left promiscuous mode [ 7978.010982] br-a425e4d87bb3: port 2(veth175eeb3) entered disabled state [ 7978.065635] IPv6: ADDRCONF(NETDEV_UP): docker0: link is not ready [ 7978.071910] IPv6: ADDRCONF(NETDEV_UP): wlan0: link is not ready [ 7978.077893] IPv6: ADDRCONF(NETDEV_UP): p2p0: link is not ready √ container on the IoT Edge module network can connect to IoT Hub AMQP port - OK [ 7978.731825] br-a425e4d87bb3: port 2(veth5684d5e) entered blocking state [ 7978.738777] br-a425e4d87bb3: port 2(veth5684d5e) entered disabled state [ 7978.745684] device veth5684d5e entered promiscuous mode [ 7978.751631] IPv6: ADDRCONF(NETDEV_UP): veth59e8fe0: link is not ready [ 7978.758870] br-a425e4d87bb3: port 2(veth5684d5e) entered blocking state [ 7978.765515] br-a425e4d87bb3: port 2(veth5684d5e) entered forwarding state [ 7978.772582] IPv6: ADDRCONF(NETDEV_CHANGE): veth59e8fe0: link becomes ready [ 7979.843144] br-a425e4d87bb3: port 2(veth5684d5e) entered disabled state [ 7979.850306] eth0: renamed from veth59e8fe0 [ 7979.875427] IPv6: ADDRCONF(NETDEV_UP): veth5684d5e: link is not ready [ 7979.882127] IPv6: ADDRCONF(NETDEV_CHANGE): veth5684d5e: link becomes ready [ 7979.889226] br-a425e4d87bb3: port 2(veth5684d5e) entered blocking state [ 7979.895898] br-a425e4d87bb3: port 2(veth5684d5e) entered forwarding state [ 7980.287535] br-a425e4d87bb3: port 2(veth5684d5e) entered disabled state [ 7980.294304] veth59e8fe0: renamed from eth0 [ 7980.332121] IPv6: ADDRCONF(NETDEV_UP): veth5684d5e: link is not ready [ 7980.340340] IPv6: ADDRCONF(NETDEV_CHANGE): veth5684d5e: link becomes ready [ 7980.347497] br-a425e4d87bb3: port 2(veth5684d5e) entered blocking state [ 7980.354171] br-a425e4d87bb3: port 2(veth5684d5e) entered forwarding state [ 7980.377783] br-a425e4d87bb3: port 2(veth5684d5e) entered disabled state [ 7980.388668] device veth5684d5e left promiscuous mode [ 7980.393843] br-a425e4d87bb3: port 2(veth5684d5e) entered disabled state [ 7980.441637] IPv6: ADDRCONF(NETDEV_UP): docker0: link is not ready [ 7980.447889] IPv6: ADDRCONF(NETDEV_UP): wlan0: link is not ready [ 7980.453839] IPv6: ADDRCONF(NETDEV_UP): p2p0: link is not ready √ container on the IoT Edge module network can connect to IoT Hub HTTPS / WebSockets port - OK [ 7980.952356] br-a425e4d87bb3: port 2(veth49c06be) entered blocking state [ 7980.959060] br-a425e4d87bb3: port 2(veth49c06be) entered disabled state [ 7980.965946] device veth49c06be entered promiscuous mode [ 7980.971678] IPv6: ADDRCONF(NETDEV_UP): veth49c06be: link is not ready [ 7980.978298] br-a425e4d87bb3: port 2(veth49c06be) entered blocking state [ 7980.984937] br-a425e4d87bb3: port 2(veth49c06be) entered forwarding state [ 7980.993623] IPv6: ADDRCONF(NETDEV_CHANGE): veth49c06be: link becomes ready [ 7982.075676] br-a425e4d87bb3: port 2(veth49c06be) entered disabled state [ 7982.082962] eth0: renamed from vethce3d4e7 [ 7982.107008] IPv6: ADDRCONF(NETDEV_UP): veth49c06be: link is not ready [ 7982.113621] IPv6: ADDRCONF(NETDEV_CHANGE): veth49c06be: link becomes ready [ 7982.120673] br-a425e4d87bb3: port 2(veth49c06be) entered blocking state [ 7982.127332] br-a425e4d87bb3: port 2(veth49c06be) entered forwarding state [ 7982.506375] br-a425e4d87bb3: port 2(veth49c06be) entered disabled state [ 7982.513709] vethce3d4e7: renamed from eth0 [ 7982.563343] IPv6: ADDRCONF(NETDEV_UP): veth49c06be: link is not ready [ 7982.572028] IPv6: ADDRCONF(NETDEV_CHANGE): veth49c06be: link becomes ready [ 7982.579229] br-a425e4d87bb3: port 2(veth49c06be) entered blocking state [ 7982.585915] br-a425e4d87bb3: port 2(veth49c06be) entered forwarding state [ 7982.601549] br-a425e4d87bb3: port 2(veth49c06be) entered disabled state [ 7982.611707] device veth49c06be left promiscuous mode [ 7982.616756] br-a425e4d87bb3: port 2(veth49c06be) entered disabled state [ 7982.616775] kauditd_printk_skb: 83 callbacks suppressed [ 7982.616779] audit: type=1700 audit(1605536235.461:1288): dev=veth49c06be prom=0 old_prom=256 auid=4294967295 uid=0 gid=0 ses=4294967295 [ 7982.662072] IPv6: ADDRCONF(NETDEV_UP): docker0: link is not ready [ 7982.668321] IPv6: ADDRCONF(NETDEV_UP): wlan0: link is not ready [ 7982.674292] IPv6: ADDRCONF(NETDEV_UP): p2p0: link is not ready [ 7982.680590] audit: type=1300 audit(1605536235.461:1288): arch=c00000b7 syscall=206 success=yes exit=32 a0=c a1=4000cf1fc0 a2=20 a3=0 items=0 ppid=1 pid=3513 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=(none) ses=4294967295 comm="dockerd" exe="/usr/bin/dockerd" key=(null) [ 7982.707445] audit: type=1327 audit(1605536235.461:1288): proctitle=2F7573722F62696E2F646F636B657264002D480066643A2F2F √ container on the IoT Edge module network can connect to IoT Hub MQTT port - OK 16 check(s) succeeded. 7 check(s) raised warnings. Re-run with --verbose for more details. root@imx8mmevk:~# ```

Device Information

Runtime Versions

Logs

iotedged logs ``` ```
edge-agent logs ``` ```
edge-hub logs ``` root@imx8mmevk:~# iotedge logs edgeHub 2020-11-16 14:01:08 +00:00 Starting Edge Hub Nov 16 14:01:08.501 INFO watchdog: Starting Watchdog Nov 16 14:01:08.501 INFO watchdog: Registering shutdown signal listener Nov 16 14:01:08.502 INFO watchdog: MQTT broker is disabled Nov 16 14:01:08.502 INFO watchdog::child: Launched Edge Hub process with pid 10 2020-11-16 14:01:08.678 +00:00 Edge Hub Main() <6> 2020-11-16 14:01:11.616 +00:00 [INF] - Installing certificates [CN=iotedged workload ca:02/12/2021 02:32:17],[CN=Test Edge Device CA:02/12/2021 02:32:17],[CN=Test Edge Owner CA:02/12/2021 02:32:17] to Root <6> 2020-11-16 14:01:11.749 +00:00 [INF] - Installing certificates [CN=Test Edge Owner CA:02/12/2021 02:32:17] to Root <6> 2020-11-16 14:01:11.782 +00:00 [INF] - Enabling SSL protocols: Tls, Tls11, Tls12 <6> 2020-11-16 14:01:12.174 +00:00 [INF] - Experimental features configuration: {"Enabled":false,"DisableCloudSubscriptions":false,"DisableConnectivityCheck":false,"EnableNestedEdge":false,"EnableMqttBroker":false} <6> 2020-11-16 14:01:13.797 +00:00 [INF] - Created persistent store at /tmp/edgeHub <6> 2020-11-16 14:01:13.983 +00:00 [INF] - Created device scope identities cache <6> 2020-11-16 14:01:14.011 +00:00 [INF] - Starting refresh of device scope identities cache <6> 2020-11-16 14:01:14.012 +00:00 [INF] - Initializing Edge Hub <6> 2020-11-16 14:01:14.013 +00:00 [INF] - █████╗ ███████╗██╗ ██╗██████╗ ███████╗ ██╔══██╗╚══███╔╝██║ ██║██╔══██╗██╔════╝ ███████║ ███╔╝ ██║ ██║██████╔╝█████╗ ██╔══██║ ███╔╝ ██║ ██║██╔══██╗██╔══╝ ██║ ██║███████╗╚██████╔╝██║ ██║███████╗ ╚═╝ ╚═╝╚══════╝ ╚═════╝ ╚═╝ ╚═╝╚══════╝ ██╗ ██████╗ ████████╗ ███████╗██████╗ ██████╗ ███████╗ ██║██╔═══██╗╚══██╔══╝ ██╔════╝██╔══██╗██╔════╝ ██╔════╝ ██║██║ ██║ ██║ █████╗ ██║ ██║██║ ███╗█████╗ ██║██║ ██║ ██║ ██╔══╝ ██║ ██║██║ ██║██╔══╝ ██║╚██████╔╝ ██║ ███████╗██████╔╝╚██████╔╝███████╗ ╚═╝ ╚═════╝ ╚═╝ ╚══════╝╚═════╝ ╚═════╝ ╚══════╝ <6> 2020-11-16 14:01:14.017 +00:00 [INF] - Version - 1.2.0-rc1.36607244 (dd8b529d67fcc0fc5adaa92ecf4d1758dfed4eaf) <6> 2020-11-16 14:01:14.018 +00:00 [INF] - OptimizeForPerformance=False <6> 2020-11-16 14:01:14.018 +00:00 [INF] - MessageAckTimeoutSecs=30 <6> 2020-11-16 14:01:14.021 +00:00 [INF] - Loaded server certificate with expiration date of "2021-02-12T02:32:17.0000000+00:00" <6> 2020-11-16 14:01:14.050 +00:00 [INF] - Using Asp Net server for metrics <6> 2020-11-16 14:01:14.128 +00:00 [INF] - Started task to cleanup processed and stale messages <6> 2020-11-16 14:01:14.246 +00:00 [INF] - Created new message store <6> 2020-11-16 14:01:14.533 +00:00 [INF] - Created DeviceConnectivityManager with connected check frequency 00:05:00 and disconnected check frequency 00:02:00 <6> 2020-11-16 14:01:14.669 +00:00 [INF] - Initialized storing twin manager <6> 2020-11-16 14:01:14.719 +00:00 [INF] - Initializing configuration <6> 2020-11-16 14:01:14.797 +00:00 [INF] - New device connection for device imx8mmevk-manual-2/$edgeHub <6> 2020-11-16 14:01:14.807 +00:00 [INF] - Client imx8mmevk-manual-2/$edgeHub connected to edgeHub, processing existing subscriptions. <6> 2020-11-16 14:01:15.002 +00:00 [INF] - Attempting to connect to IoT Hub for client imx8mmevk-manual-2/$edgeHub via AMQP... <6> 2020-11-16 14:01:15.076 +00:00 [INF] - Processing pending subscriptions for imx8mmevk-manual-2/$edgeHub <6> 2020-11-16 14:01:16.048 +00:00 [INF] - Done refreshing device scope identities cache. Waiting for 60 minutes. <6> 2020-11-16 14:01:16.193 +00:00 [INF] - Starting timer to authenticate connections with a period of 300 seconds <6> 2020-11-16 14:01:16.215 +00:00 [INF] - Experimental features configuration: {"Enabled":false,"DisableCloudSubscriptions":false,"DisableConnectivityCheck":false,"EnableNestedEdge":false,"EnableMqttBroker":false} <4> 2020-11-16 14:01:16.241 +00:00 [WRN] - Empty edge hub configuration received. Ignoring... <6> 2020-11-16 14:01:16.445 +00:00 [INF] - Scheduling server certificate renewal for "2021-02-12T02:29:47.0007206Z". <6> 2020-11-16 14:01:16.451 +00:00 [INF] - Starting protocol heads - (MQTT, AMQP, HTTP) <6> 2020-11-16 14:01:16.460 +00:00 [INF] - Starting MQTT head <6> 2020-11-16 14:01:16.556 +00:00 [INF] - Initializing TLS endpoint on port 8883 for MQTT head. <6> 2020-11-16 14:01:16.781 +00:00 [INF] - Starting AMQP head <6> 2020-11-16 14:01:16.831 +00:00 [INF] - Started MQTT head <6> 2020-11-16 14:01:17.030 +00:00 [INF] - Started AMQP head <6> 2020-11-16 14:01:17.036 +00:00 [INF] - Starting HTTP head <6> 2020-11-16 14:01:17.317 +00:00 [INF] - Exiting disconnected state <6> 2020-11-16 14:01:17.394 +00:00 [INF] - Received device connected callback <6> 2020-11-16 14:01:17.485 +00:00 [INF] - Device connected to cloud, processing subscriptions for connected clients. <6> 2020-11-16 14:01:17.496 +00:00 [INF] - Processing subscriptions for client imx8mmevk-manual-2/$edgeHub on device connected to cloud. <6> 2020-11-16 14:01:17.498 +00:00 [INF] - Skipping imx8mmevk-manual-2/$edgeHub for subscription processing, as it is currently being processed. <6> 2020-11-16 14:01:17.511 +00:00 [INF] - Device scope identities refresh is ready because a refresh was signalled. <6> 2020-11-16 14:01:17.516 +00:00 [INF] - Starting refresh of device scope identities cache <6> 2020-11-16 14:01:17.553 +00:00 [INF] - Entering connected state <6> 2020-11-16 14:01:17.571 +00:00 [INF] - Cloud connection for imx8mmevk-manual-2/$edgeHub is True <6> 2020-11-16 14:01:17.585 +00:00 [INF] - Connection status for imx8mmevk-manual-2/$edgeHub changed to ConnectionEstablished <6> 2020-11-16 14:01:17.592 +00:00 [INF] - Client imx8mmevk-manual-2/$edgeHub connected to cloud, processing existing subscriptions. <6> 2020-11-16 14:01:17.593 +00:00 [INF] - Skipping imx8mmevk-manual-2/$edgeHub for subscription processing, as it is currently being processed. <6> 2020-11-16 14:01:17.607 +00:00 [INF] - Created cloud proxy for client imx8mmevk-manual-2/$edgeHub via AMQP, with client operation timeout 20 seconds. <6> 2020-11-16 14:01:17.631 +00:00 [INF] - Initialized cloud proxy a1be5c34-05f1-4861-b69c-8cc4b7f45386 for imx8mmevk-manual-2/$edgeHub <6> 2020-11-16 14:01:17.638 +00:00 [INF] - Created cloud connection for client imx8mmevk-manual-2/$edgeHub <4> 2020-11-16 14:01:17.988 +00:00 [WRN] - Overriding address(es) '"http://+:80"'. Binding to endpoints defined in "UseKestrel()" instead. <0> 2020-11-16 14:01:18.048 +00:00 [FTL] - Unable to start Kestrel. System.Net.Sockets.SocketException (13): Permission denied at System.Net.Sockets.Socket.UpdateStatusAfterSocketErrorAndThrowException(SocketError error, String callerName) at System.Net.Sockets.Socket.DoBind(EndPoint endPointSnapshot, SocketAddress socketAddress) at System.Net.Sockets.Socket.Bind(EndPoint localEP) at Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets.SocketConnectionListener.Bind() at Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets.SocketTransportFactory.BindAsync(EndPoint endpoint, CancellationToken cancellationToken) at Microsoft.AspNetCore.Server.Kestrel.Core.KestrelServer.<>c__DisplayClass21_0`1.<g__OnBind|0>d.MoveNext() --- End of stack trace from previous location where exception was thrown --- at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.AddressBinder.BindEndpointAsync(ListenOptions endpoint, AddressBindContext context) at Microsoft.AspNetCore.Server.Kestrel.Core.ListenOptions.BindAsync(AddressBindContext context) at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.AddressBinder.EndpointsStrategy.BindAsync(AddressBindContext context) at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.AddressBinder.BindAsync(IServerAddressesFeature addresses, KestrelServerOptions serverOptions, ILogger logger, Func`2 createBinding) at Microsoft.AspNetCore.Server.Kestrel.Core.KestrelServer.StartAsync[TContext](IHttpApplication`1 application, CancellationToken cancellationToken) <3> 2020-11-16 14:01:18.128 +00:00 [ERR] - Error starting protocol heads: Permission denied <6> 2020-11-16 14:01:18.128 +00:00 [INF] - Stopping the protocol heads... <6> 2020-11-16 14:01:18.130 +00:00 [INF] - Closing protocol heads - (MQTT, AMQP, HTTP) <6> 2020-11-16 14:01:18.136 +00:00 [INF] - Stopping <6> 2020-11-16 14:01:18.184 +00:00 [INF] - Closing HTTP head <6> 2020-11-16 14:01:18.189 +00:00 [INF] - Closed HTTP head <6> 2020-11-16 14:01:18.286 +00:00 [INF] - Processing pending subscriptions for imx8mmevk-manual-2/$edgeHub <6> 2020-11-16 14:01:18.315 +00:00 [INF] - Updated reported properties for imx8mmevk-manual-2/$edgeHub <6> 2020-11-16 14:01:18.437 +00:00 [INF] - Done refreshing device scope identities cache. Waiting for 60 minutes. <6> 2020-11-16 14:01:18.914 +00:00 [INF] - Obtained edge hub config from module twin <6> 2020-11-16 14:01:18.942 +00:00 [INF] - No routes set in the edge hub <6> 2020-11-16 14:01:18.946 +00:00 [INF] - Updated message store TTL to 7200 seconds <6> 2020-11-16 14:01:18.947 +00:00 [INF] - Updated the edge hub store and forward configuration <6> 2020-11-16 14:01:18.969 +00:00 [INF] - Started operation Get EdgeHub config <6> 2020-11-16 14:01:18.971 +00:00 [INF] - Initialized edge hub configuration <6> 2020-11-16 14:01:19.989 +00:00 [INF] - Updated reported properties for imx8mmevk-manual-2/$edgeHub <6> 2020-11-16 14:01:33.294 +00:00 [INF] - Stopped <6> 2020-11-16 14:01:33.295 +00:00 [INF] - Protocol heads stopped. <6> 2020-11-16 14:01:33.311 +00:00 [INF] - Stopping <6> 2020-11-16 14:01:33.312 +00:00 [INF] - Stopped <6> 2020-11-16 14:01:33.333 +00:00 [INF] - Shutdown complete. <6> 2020-11-16 14:01:33.336 +00:00 [INF] - Termination requested, initiating shutdown. <6> 2020-11-16 14:01:33.336 +00:00 [INF] - Waiting for cleanup to finish <6> 2020-11-16 14:01:33.336 +00:00 [INF] - Done with cleanup. Shutting down. Nov 16 14:01:33.509 INFO watchdog::child: Edge Hub process has stopped Nov 16 14:01:33.509 INFO watchdog: Successfully stopped Edge Hub process Nov 16 14:01:33.509 INFO watchdog: Stopped Watchdog process 2020-11-16 14:01:46 +00:00 Starting Edge Hub Nov 16 14:01:46.332 INFO watchdog: Starting Watchdog Nov 16 14:01:46.332 INFO watchdog: Registering shutdown signal listener Nov 16 14:01:46.333 INFO watchdog: MQTT broker is disabled Nov 16 14:01:46.333 INFO watchdog::child: Launched Edge Hub process with pid 9 2020-11-16 14:01:46.497 +00:00 Edge Hub Main() <6> 2020-11-16 14:01:49.344 +00:00 [INF] - Installing certificates [CN=iotedged workload ca:02/12/2021 02:32:17],[CN=Test Edge Device CA:02/12/2021 02:32:17],[CN=Test Edge Owner CA:02/12/2021 02:32:17] to Root <6> 2020-11-16 14:01:49.478 +00:00 [INF] - Installing certificates [CN=Test Edge Owner CA:02/12/2021 02:32:17] to Root <6> 2020-11-16 14:01:49.493 +00:00 [INF] - Enabling SSL protocols: Tls, Tls11, Tls12 <6> 2020-11-16 14:01:49.884 +00:00 [INF] - Experimental features configuration: {"Enabled":false,"DisableCloudSubscriptions":false,"DisableConnectivityCheck":false,"EnableNestedEdge":false,"EnableMqttBroker":false} <6> 2020-11-16 14:01:51.529 +00:00 [INF] - Created persistent store at /tmp/edgeHub <6> 2020-11-16 14:01:51.695 +00:00 [INF] - Initializing Edge Hub <6> 2020-11-16 14:01:51.696 +00:00 [INF] - █████╗ ███████╗██╗ ██╗██████╗ ███████╗ ██╔══██╗╚══███╔╝██║ ██║██╔══██╗██╔════╝ ███████║ ███╔╝ ██║ ██║██████╔╝█████╗ ██╔══██║ ███╔╝ ██║ ██║██╔══██╗██╔══╝ ██║ ██║███████╗╚██████╔╝██║ ██║███████╗ ╚═╝ ╚═╝╚══════╝ ╚═════╝ ╚═╝ ╚═╝╚══════╝ ██╗ ██████╗ ████████╗ ███████╗██████╗ ██████╗ ███████╗ ██║██╔═══██╗╚══██╔══╝ ██╔════╝██╔══██╗██╔════╝ ██╔════╝ ██║██║ ██║ ██║ █████╗ ██║ ██║██║ ███╗█████╗ ██║██║ ██║ ██║ ██╔══╝ ██║ ██║██║ ██║██╔══╝ ██║╚██████╔╝ ██║ ███████╗██████╔╝╚██████╔╝███████╗ ╚═╝ ╚═════╝ ╚═╝ ╚══════╝╚═════╝ ╚═════╝ ╚══════╝ <6> 2020-11-16 14:01:51.701 +00:00 [INF] - Version - 1.2.0-rc1.36607244 (dd8b529d67fcc0fc5adaa92ecf4d1758dfed4eaf) <6> 2020-11-16 14:01:51.701 +00:00 [INF] - OptimizeForPerformance=False <6> 2020-11-16 14:01:51.701 +00:00 [INF] - MessageAckTimeoutSecs=30 <6> 2020-11-16 14:01:51.705 +00:00 [INF] - Loaded server certificate with expiration date of "2021-02-12T02:32:17.0000000+00:00" <6> 2020-11-16 14:01:51.737 +00:00 [INF] - Using Asp Net server for metrics <6> 2020-11-16 14:01:51.844 +00:00 [INF] - Started task to cleanup processed and stale messages <6> 2020-11-16 14:01:51.967 +00:00 [INF] - Created new message store <6> 2020-11-16 14:01:52.173 +00:00 [INF] - Created device scope identities cache <6> 2020-11-16 14:01:52.204 +00:00 [INF] - Starting refresh of device scope identities cache <6> 2020-11-16 14:01:52.276 +00:00 [INF] - Created DeviceConnectivityManager with connected check frequency 00:05:00 and disconnected check frequency 00:02:00 <6> 2020-11-16 14:01:52.389 +00:00 [INF] - Initialized storing twin manager <6> 2020-11-16 14:01:52.433 +00:00 [INF] - Initializing configuration <6> 2020-11-16 14:01:52.494 +00:00 [INF] - New device connection for device imx8mmevk-manual-2/$edgeHub <6> 2020-11-16 14:01:52.504 +00:00 [INF] - Client imx8mmevk-manual-2/$edgeHub connected to edgeHub, processing existing subscriptions. <6> 2020-11-16 14:01:52.663 +00:00 [INF] - Attempting to connect to IoT Hub for client imx8mmevk-manual-2/$edgeHub via AMQP... <6> 2020-11-16 14:01:52.741 +00:00 [INF] - Processing pending subscriptions for imx8mmevk-manual-2/$edgeHub <6> 2020-11-16 14:01:53.856 +00:00 [INF] - Starting timer to authenticate connections with a period of 300 seconds <6> 2020-11-16 14:01:53.885 +00:00 [INF] - Experimental features configuration: {"Enabled":false,"DisableCloudSubscriptions":false,"DisableConnectivityCheck":false,"EnableNestedEdge":false,"EnableMqttBroker":false} <6> 2020-11-16 14:01:54.006 +00:00 [INF] - No routes set in the edge hub <6> 2020-11-16 14:01:54.010 +00:00 [INF] - Updated message store TTL to 7200 seconds <6> 2020-11-16 14:01:54.012 +00:00 [INF] - Updated the edge hub store and forward configuration <6> 2020-11-16 14:01:54.115 +00:00 [INF] - Started operation Get EdgeHub config <6> 2020-11-16 14:01:54.117 +00:00 [INF] - Initialized edge hub configuration <6> 2020-11-16 14:01:54.176 +00:00 [INF] - Scheduling server certificate renewal for "2021-02-12T02:29:47.0008413Z". <6> 2020-11-16 14:01:54.183 +00:00 [INF] - Starting protocol heads - (MQTT, AMQP, HTTP) <6> 2020-11-16 14:01:54.196 +00:00 [INF] - Starting MQTT head <6> 2020-11-16 14:01:54.233 +00:00 [INF] - Done refreshing device scope identities cache. Waiting for 60 minutes. <6> 2020-11-16 14:01:54.300 +00:00 [INF] - Initializing TLS endpoint on port 8883 for MQTT head. <6> 2020-11-16 14:01:54.528 +00:00 [INF] - Starting AMQP head <6> 2020-11-16 14:01:54.567 +00:00 [INF] - Started MQTT head <6> 2020-11-16 14:01:54.785 +00:00 [INF] - Started AMQP head <6> 2020-11-16 14:01:54.791 +00:00 [INF] - Starting HTTP head <6> 2020-11-16 14:01:55.083 +00:00 [INF] - Exiting disconnected state <6> 2020-11-16 14:01:55.217 +00:00 [INF] - Received device connected callback <6> 2020-11-16 14:01:55.248 +00:00 [INF] - Device connected to cloud, processing subscriptions for connected clients. <6> 2020-11-16 14:01:55.256 +00:00 [INF] - Processing subscriptions for client imx8mmevk-manual-2/$edgeHub on device connected to cloud. <6> 2020-11-16 14:01:55.258 +00:00 [INF] - Skipping imx8mmevk-manual-2/$edgeHub for subscription processing, as it is currently being processed. <6> 2020-11-16 14:01:55.267 +00:00 [INF] - Device scope identities refresh is ready because a refresh was signalled. <6> 2020-11-16 14:01:55.268 +00:00 [INF] - Starting refresh of device scope identities cache <6> 2020-11-16 14:01:55.325 +00:00 [INF] - Entering connected state <6> 2020-11-16 14:01:55.342 +00:00 [INF] - Cloud connection for imx8mmevk-manual-2/$edgeHub is True <6> 2020-11-16 14:01:55.359 +00:00 [INF] - Connection status for imx8mmevk-manual-2/$edgeHub changed to ConnectionEstablished <6> 2020-11-16 14:01:55.367 +00:00 [INF] - Client imx8mmevk-manual-2/$edgeHub connected to cloud, processing existing subscriptions. <6> 2020-11-16 14:01:55.368 +00:00 [INF] - Skipping imx8mmevk-manual-2/$edgeHub for subscription processing, as it is currently being processed. <6> 2020-11-16 14:01:55.380 +00:00 [INF] - Created cloud proxy for client imx8mmevk-manual-2/$edgeHub via AMQP, with client operation timeout 20 seconds. <6> 2020-11-16 14:01:55.401 +00:00 [INF] - Initialized cloud proxy 91f02965-e4b6-4c02-ac8b-497c72bf3d35 for imx8mmevk-manual-2/$edgeHub <6> 2020-11-16 14:01:55.408 +00:00 [INF] - Created cloud connection for client imx8mmevk-manual-2/$edgeHub <4> 2020-11-16 14:01:55.727 +00:00 [WRN] - Overriding address(es) '"http://+:80"'. Binding to endpoints defined in "UseKestrel()" instead. <0> 2020-11-16 14:01:55.783 +00:00 [FTL] - Unable to start Kestrel. System.Net.Sockets.SocketException (13): Permission denied at System.Net.Sockets.Socket.UpdateStatusAfterSocketErrorAndThrowException(SocketError error, String callerName) at System.Net.Sockets.Socket.DoBind(EndPoint endPointSnapshot, SocketAddress socketAddress) at System.Net.Sockets.Socket.Bind(EndPoint localEP) at Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets.SocketConnectionListener.Bind() at Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets.SocketTransportFactory.BindAsync(EndPoint endpoint, CancellationToken cancellationToken) at Microsoft.AspNetCore.Server.Kestrel.Core.KestrelServer.<>c__DisplayClass21_0`1.<g__OnBind|0>d.MoveNext() --- End of stack trace from previous location where exception was thrown --- at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.AddressBinder.BindEndpointAsync(ListenOptions endpoint, AddressBindContext context) at Microsoft.AspNetCore.Server.Kestrel.Core.ListenOptions.BindAsync(AddressBindContext context) at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.AddressBinder.EndpointsStrategy.BindAsync(AddressBindContext context) at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.AddressBinder.BindAsync(IServerAddressesFeature addresses, KestrelServerOptions serverOptions, ILogger logger, Func`2 createBinding) at Microsoft.AspNetCore.Server.Kestrel.Core.KestrelServer.StartAsync[TContext](IHttpApplication`1 application, CancellationToken cancellationToken) <3> 2020-11-16 14:01:55.874 +00:00 [ERR] - Error starting protocol heads: Permission denied <6> 2020-11-16 14:01:55.874 +00:00 [INF] - Stopping the protocol heads... <6> 2020-11-16 14:01:55.876 +00:00 [INF] - Closing protocol heads - (MQTT, AMQP, HTTP) <6> 2020-11-16 14:01:55.881 +00:00 [INF] - Stopping <6> 2020-11-16 14:01:55.930 +00:00 [INF] - Closing HTTP head <6> 2020-11-16 14:01:55.935 +00:00 [INF] - Closed HTTP head <6> 2020-11-16 14:01:56.031 +00:00 [INF] - Processing pending subscriptions for imx8mmevk-manual-2/$edgeHub <6> 2020-11-16 14:01:56.059 +00:00 [INF] - Updated reported properties for imx8mmevk-manual-2/$edgeHub <6> 2020-11-16 14:01:56.232 +00:00 [INF] - Done refreshing device scope identities cache. Waiting for 60 minutes. <6> 2020-11-16 14:01:56.658 +00:00 [INF] - Obtained edge hub config from module twin <6> 2020-11-16 14:01:57.675 +00:00 [INF] - Updated reported properties for imx8mmevk-manual-2/$edgeHub <6> 2020-11-16 14:02:11.027 +00:00 [INF] - Stopped <6> 2020-11-16 14:02:11.029 +00:00 [INF] - Protocol heads stopped. <6> 2020-11-16 14:02:11.047 +00:00 [INF] - Stopping <6> 2020-11-16 14:02:11.048 +00:00 [INF] - Stopped <6> 2020-11-16 14:02:11.068 +00:00 [INF] - Shutdown complete. <6> 2020-11-16 14:02:11.072 +00:00 [INF] - Termination requested, initiating shutdown. <6> 2020-11-16 14:02:11.072 +00:00 [INF] - Waiting for cleanup to finish <6> 2020-11-16 14:02:11.072 +00:00 [INF] - Done with cleanup. Shutting down. Nov 16 14:02:11.340 INFO watchdog::child: Edge Hub process has stopped Nov 16 14:02:11.341 INFO watchdog: Successfully stopped Edge Hub process Nov 16 14:02:11.341 INFO watchdog: Stopped Watchdog process 2020-11-16 14:02:34 +00:00 Starting Edge Hub Nov 16 14:02:34.115 INFO watchdog: Starting Watchdog Nov 16 14:02:34.115 INFO watchdog: Registering shutdown signal listener Nov 16 14:02:34.116 INFO watchdog: MQTT broker is disabled Nov 16 14:02:34.116 INFO watchdog::child: Launched Edge Hub process with pid 9 2020-11-16 14:02:34.283 +00:00 Edge Hub Main() <6> 2020-11-16 14:02:37.591 +00:00 [INF] - Installing certificates [CN=iotedged workload ca:02/12/2021 02:32:17],[CN=Test Edge Device CA:02/12/2021 02:32:17],[CN=Test Edge Owner CA:02/12/2021 02:32:17] to Root <6> 2020-11-16 14:02:37.725 +00:00 [INF] - Installing certificates [CN=Test Edge Owner CA:02/12/2021 02:32:17] to Root <6> 2020-11-16 14:02:37.740 +00:00 [INF] - Enabling SSL protocols: Tls, Tls11, Tls12 <6> 2020-11-16 14:02:38.134 +00:00 [INF] - Experimental features configuration: {"Enabled":false,"DisableCloudSubscriptions":false,"DisableConnectivityCheck":false,"EnableNestedEdge":false,"EnableMqttBroker":false} <6> 2020-11-16 14:02:39.816 +00:00 [INF] - Created persistent store at /tmp/edgeHub <6> 2020-11-16 14:02:39.992 +00:00 [INF] - Initializing Edge Hub <6> 2020-11-16 14:02:39.994 +00:00 [INF] - ```

Additional Information

root@imx8mmevk:~# root@imx8mmevk:~# iotedge --version iotedge 1.0.9.4 root@imx8mmevk:~# docker --version Docker version 19.03.2-ce, build 6a30dfca03 root@imx8mmevk:~#

I have built two yocto zeus images using mostly the same components (ARM64). Also using github meta-iotedge project (runtime 1.0.9). one is using the raspberry pi 3 as the target (for reference) and the second is my NXP iMX8M mini eval kit. Both images build and load fine and I can load image on respective devices. On both devices everything initially runs fine. I can dump docker version and iotedge version on both and they show exactly the same: iotedge 1.0.9.4 Docker version 19.03.2-ce, build 6a30dfca03

I then deploy edgeHub and agent 1.2.0-rc1 two both devices with no routes defined. The raspberry pi device is stable and run for ever. The iMX8 Mini device the hub crashes.

I am really trying to get the port to iMX8 mini device working as it is needed for our project.

damonbarry commented 3 years ago

@dvescovi1 see #9. Edge hub runs as a non-privileged user, which would normally mean it can't bind to ports below 1024 (e.g., 443), except we build it with CAP_NET_BIND_SERVICE. So your operating system needs to support that capability.

Also, I wouldn't expect iotedged 1.0.9.x to work seamlessly with 1.2.0-rc1 modules. I understand the meta-iotedge repo hasn't been updated for 1.2.0-rc1 (because yocto isn't tier 1, and because 1.2.0-rc1 is pre-release), so your options are limited. Just wanted to clarify.

imZack commented 3 years ago

Also, I wouldn't expect iotedged 1.0.9.x to work seamlessly with 1.2.0-rc1 modules.

Will there be a heads up notice for upgrading from 1.0.9.x to 1.2.0? What's been changed and not backward compatible?

damonbarry commented 3 years ago

@imZack In general, iotedged and modules should be on the same version; we don't support mixing and matching.

dvescovi1 commented 3 years ago

thank you for pointing me to #9 that was exactly my issue. I was using a slightly older kernel version which did not have the file system security features turned on. After enabling

CONFIG_EXT4_FS_SECURITY=y

in the kernel and rebuilding everything is working fine now. ... what a two week journey!

SimonSimCity commented 3 years ago

For others ending up here, consider running the kernel compatibility check provided by the moby team to see what else is missing: https://blog.hypriot.com/post/verify-kernel-container-compatibility/