Device can't register with API

~/open-balena# git describe
v2.0.2
~/balena-intel$ git describe
v2.50.0+rev1

After built and flashed image I’ve got next issues with resin_supervisor:

resin_supervisor logs:
[error] LogBackend: server responded with status code: 401
[event] Event: Device bootstrap {}
[info] New device detected. Provisioning…
[debug] Supervisor API listening on allowed interfaces only
[info] Supervisor API successfully started on port 48484
[event] Event: Device bootstrap failed, retrying {“delay”:30000,“error”:{“message”:“User ID must be a valid integer”,“stack”:“Error: User ID must be a valid integer\n at /usr/src/app/dist/app.js:2:2608401\n at PassThroughHandlerContext.finallyHandler (/usr/src/app/dist/app.js:2:1720911)\n at PassThroughHandlerContext.tryCatcher (/usr/src/app/dist/app.js:2:227165)\n at Promise._settlePromiseFromHandler (/usr/src/app/dist/app.js:2:1680441)\n at Promise._settlePromise (/usr/src/app/dist/app.js:2:1681724)\n at Promise._settlePromise0 (/usr/src/app/dist/app.js:2:1682764)\n at Promise._settlePromises (/usr/src/app/dist/app.js:2:1684472)\n at _drainQueueStep (/usr/src/app/dist/app.js:2:1687406)\n at _drainQueue (/usr/src/app/dist/app.js:2:1687302)\n at Async._drainQueues (/usr/src/app/dist/app.js:2:1688619)\n at Immediate.Async.drainQueues [as _onImmediate] (/usr/src/app/dist/app.js:2:1687211)\n at processImmediate (internal/timers.js:456:21)”}}
[event] Event: Device bootstrap {}

image:
Reporting scan results
-
host: my-custom-hostname.local
address: 10.193.0.106
dockerInfo:
Containers: 1
ContainersRunning: 1
ContainersPaused: 0
ContainersStopped: 0
Images: 2
Driver: overlay2
SystemTime: 2020-05-27T05:58:36.464489576Z
KernelVersion: 5.2.10-yocto-standard
OperatingSystem: balenaOS 2.50.0+rev1
Architecture: x86_64
dockerVersion:
Version: 18.09.17-dev
ApiVersion: 1.39

api log:
May 27 05:56:36 1f779bcb180d api[1467]: Error registering device User ID must be a valid integer BadRequestError: User ID must be a valid integer
May 27 05:56:36 1f779bcb180d api[1467]: at Promise.try (/usr/src/app/src/routes/devices.ts:17:15)
May 27 05:56:36 1f779bcb180d api[1467]: From previous event:
May 27 05:56:36 1f779bcb180d api[1467]: at exports.register (/usr/src/app/src/routes/devices.ts:14:45)
May 27 05:56:36 1f779bcb180d api[1467]: at Layer.handle [as handle_request] (/usr/src/app/node_modules/express/lib/router/layer.js:95:5)
May 27 05:56:36 1f779bcb180d api[1467]: at next (/usr/src/app/node_modules/express/lib/router/route.js:137:13)
May 27 05:56:36 1f779bcb180d api[1467]: at runCallback (timers.js:705:18)
May 27 05:56:36 1f779bcb180d api[1467]: at tryOnImmediate (timers.js:676:5)
May 27 05:56:36 1f779bcb180d api[1467]: at processImmediate (timers.js:658:5)
May 27 05:56:36 1f779bcb180d api[1467]: at process.topLevelDomainCallback (domain.js:120:23)

I dumped registration requests:

Image -> API:
172.27.0.9.44590 > 172.27.0.7.80: Flags [P.], cksum 0x5a08 (incorrect -> 0x8d5b), seq 1:412, ack 1, win 502, options [nop,nop,TS val 173104418 ecr 2583009283], length 411: HTTP, length: 411
POST /device/register HTTP/1.1
Authorization: Bearer IRHMTQsQsBJmuoHm0j24CjWhmPehFSlN
host: api.openbalena.local
accept: application/json
content-type: application/json
content-length: 138
Connection: close
X-Forwarded-Proto: https
X-Forwarded-For: 10.193.0.106

	{"application":1,"uuid":"30caf5b02e1329f8daa993b7538d892c","device_type":"genericx86-64-ext","api_key":"e0334b89b1de301007e576266ab44e3b"}[!http]

API->Image:
172.27.0.7.80 > 172.27.0.9.44590: Flags [P.], cksum 0x59ad (incorrect -> 0xa5c2), seq 1:321, ack 412, win 506, options [nop,nop,TS val 2583009285 ecr 173104418], length 320: HTTP, length: 320
HTTP/1.1 400 Bad Request
X-Frame-Options: DENY
X-Content-Type-Options: nosniff
Vary: X-HTTP-Method-Override, Accept-Encoding
Content-Type: text/html; charset=utf-8
Content-Length: 31
ETag: W/“1f-r3Rq8CkioN55WTv27jYOdSfTcF8”
Date: Wed, 27 May 2020 06:56:40 GMT
Connection: close

	User ID must be a valid integer[!http]

Tried with official Intel-NUC v2.50.1 dev image - the same issue:
[event] Event: Device bootstrap failed, retrying {"delay":30000,"error":{"message":"User ID must be a valid integer","stack":"Error: User ID must be a valid integer\n at /usr/src/app/dist/app.js:2:2630094\n at PassThroughHandlerContext.finallyHandler (/usr/src/app/dist/app.js:2:1748917)\n at PassThroughHandlerContext.tryCatcher (/usr/src/app/dist/app.js:2:220284)\n at Promise._settlePromiseFromHandler (/usr/src/app/dist/app.js:2:1708447)\n at Promise._settlePromise (/usr/src/app/dist/app.js:2:1709730)\n at Promise._settlePromise0 (/usr/src/app/dist/app.js:2:1710770)\n at Promise._settlePromises (/usr/src/app/dist/app.js:2:1712478)\n at _drainQueueStep (/usr/src/app/dist/app.js:2:1715412)\n at _drainQueue (/usr/src/app/dist/app.js:2:1715308)\n at Async._drainQueues (/usr/src/app/dist/app.js:2:1716625)\n at Immediate.Async.drainQueues [as _onImmediate] (/usr/src/app/dist/app.js:2:1715217)\n at processImmediate (internal/timers.js:456:21)"}}

Hi,

According to the the logs, looks like you’re running openBalena not balenaCloud, right? And how do you get the image? Since something is wrong with the registration request from the supervisor to the API since user field is missing here (To register a device, your request should include user, application, device_type, ‘uuid’ and apikey)

It would be great if you can provide us more details about what you’re doing so it will really help us investigate the issue here.

  1. Yes - I’m using open-balena

  2. I built generic x86_64 ext image from tag 2.50.0

  3. prepared conf.json with ssh keys:

    {
    “applicationName”: “MyApp”,
    “applicationId”: 1,
    “deviceType”: “genericx86-64-ext”,
    “userId”: 2,
    “username”: “root”,
    “appUpdatePollInterval”: 600000,
    “listenPort”: 48484,
    “vpnPort”: 443,
    “apiEndpoint”: “https://api.openbalena.local”,
    “vpnEndpoint”: “vpn.openbalena.local”,
    “registryEndpoint”: “registry.openbalena.local”,
    “deltaEndpoint”: “https://delta.openbalena.local”,
    “pubnubSubscribeKey”: “”,
    “pubnubPublishKey”: “”,
    “mixpanelToken”: “unused”,
    “balenaRootCA”: “LS0tLS1CRUdJTiBDRVJUSUZJ

    0FURS0tLS0tCg==”,
    “apiKey”: “IRHMTQsQsBJmuoHm0j24CjWhmPehFSlN”,
    “files”: {
    “network/network.config”: “[service_home_ethernet]\nType=ethernet\nNameservers=10.193.0.1”
    },
    “os”: {
    “sshKeys”: [
    “ssh-rsa ssh-rsa AAAAB3NzaC1yc2…”
    ]
    },
    “hostname”: “my-custom-hostname”,
    “persistentLogging”: true,
    “country”: “CN”,
    “ntpServers”: “cn.pool.ntp.org resinio.pool.ntp.org”,
    “dnsServers”: “10.193.0.1”
    }

Similar config for Intel-NUC image:

{
“applicationName”: “nucapp”,
“applicationId”: 2,
“deviceType”: “intel-nuc”,
“userId”: 2,
“username”: “root”,
“appUpdatePollInterval”: 600000,
“listenPort”: 48484,
“vpnPort”: 443,
“apiEndpoint”: “https://api.openbalena.local”,
“vpnEndpoint”: “vpn.openbalena.local”,
“registryEndpoint”: “registry.openbalena.local”,
“deltaEndpoint”: “https://delta.openbalena.local”,
“pubnubSubscribeKey”: “”,
“pubnubPublishKey”: “”,
“mixpanelToken”: “unused”,
“balenaRootCA”: “LS0tLS1CRUdJTiBDRVJUSUZJQ0FU

FURS0tLS0tCg==”,
“apiKey”: “g6YVfKz646XYcQS6uidoNc0TWUUUyd6c”,
“files”: {
“network/network.config”: “[service_home_ethernet]\nType=ethernet\nNameservers=10.193.0.1”
},
“os”: {
“sshKeys”: [
“ssh-rsa ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAACAQC…”
]
},
“hostname”: “nucapp”,
“persistentLogging”: true,
“country”: “CN”,
“ntpServers”: “cn.pool.ntp.org resinio.pool.ntp.org”,
“dnsServers”: “10.193.0.1”
}

In both cases I see the same error about user id

I used next command for initial configuration of the images:
DEBUG=1 NODE_EXTRA_CA_CERTS=~/Workspace/tmp/ca.crt balena os configure ~/Workspace/tmp/balenaos/resin-image-flasher-genericx86-64-ext-20200526030056.rootfs.resinos-img --application MyApp --version 2.50.0

DEBUG=1 NODE_EXTRA_CA_CERTS=~/Workspace/tmp/ca.crt balena os configure ~/Workspace/tmp/balenaos/balena.img --application nucapp --version 2.50.1

After that I mounted images and updated conf.json with values I provided above.

  1. hdiutil attach -imagekey diskimage-class=CRawDiskImage -nomount ~/Workspace/tmp/balenaos/balena.img
  2. sudo cp ~/conf_nuc.json /Vaolumes/flash-boot/config.json
    3.hdiutil detach /dev/disk2

Next step - fash:
sudo DEBUG=1 NODE_EXTRA_CA_CERTS=~/Workspace/tmp/ca.crt balena local flash ~/Workspace/tmp/balenaos/resin-image-flasher-genericx86-64-ext-20200526030056.rootfs.resinos-img

Next step - install on hardware and reboot

Apps were created in open-balena before image reconfiguration:
DEBUG=1 NODE_EXTRA_CA_CERTS=~/Workspace/tmp/ca.crt balena apps
[debug] original argv0=“node” argv=[/Users/harry/.nvm/versions/node/v12.16.1/bin/node,/Users/harry/.nvm/versions/node/v12.16.1/bin/balena,apps] length=3
[debug] new argv=[/Users/harry/.nvm/versions/node/v12.16.1/bin/node,/Users/harry/.nvm/versions/node/v12.16.1/bin/balena,apps] length=3
ID APP NAME DEVICE TYPE ONLINE DEVICES DEVICE COUNT
1 MyApp genericx86-64-ext 0 0
2 nucapp intel-nuc 0 0

Supervisor version:

cat /tmp/update-supervisor.conf
# This file represents the last known version of the supervisor
SUPERVISOR_IMAGE=balena/amd64-supervisor
SUPERVISOR_TAG=v11.4.1

Hi,

I think there are something we can try here to dig deeper into the issue. First, can you please extract the original config.json file and compare with the updated version? And can you flash the image without modifying to see if it works? To make sure that everything works fine and the updated config.json is the problem here.

STEP 1.
Original config.json from Inet-NUC image before os configure:
cat /Volumes/flash-boot/config.json
{
“deviceType”: “intel-nuc”,
“hostname”: “balena”,
“localMode”: true,
“persistentLogging”: false
}

STEP 2.
sudo DEBUG=1 NODE_EXTRA_CA_CERTS=~/Workspace/tmp/ca.crt balena os configure ~/Workspace/tmp/balenaos/balena.img --application nucapp --version 2.50.1
Password:
[debug] original argv0=“node” argv=[/Users/harry/.nvm/versions/node/v12.16.1/bin/node,/Users/harry/.nvm/versions/node/v12.16.1/bin/balena,os,configure,/Users/harry/Workspace/tmp/balenaos/balena.img,–application,nucapp,–version,2.50.1] length=9
[debug] new argv=[/Users/harry/.nvm/versions/node/v12.16.1/bin/node,/Users/harry/.nvm/versions/node/v12.16.1/bin/balena,os:configure,/Users/harry/Workspace/tmp/balenaos/balena.img,–application,nucapp,–version,2.50.1] length=8
? Network Connection ethernet
Configuring operating system image

STEP 3. mount, read, unmount
cat /Volumes/flash-boot/config.json
{
“applicationName”: “nucapp”,
“applicationId”: 2,
“deviceType”: “intel-nuc”,
“userId”: 2,
“username”: “root”,
“appUpdatePollInterval”: 600000,
“listenPort”: 48484,
“vpnPort”: 443,
“apiEndpoint”: “https://api.openbalena.local”,
“vpnEndpoint”: “vpn.openbalena.local”,
“registryEndpoint”: “registry.openbalena.local”,
“deltaEndpoint”: “https://delta.openbalena.local”,
“pubnubSubscribeKey”: “”,
“pubnubPublishKey”: “”,
“mixpanelToken”: “unused”,
“balenaRootCA”: “LS0tLS1CRUdJTiBDRVJUSUZJQ0FURS0tLS0tCk1JSUZZekNDQTB1Z0F3SUJBZ0lVYXdxQU5UNW02d3

zNoeTJqbDJ2K29GbUxFCi9xZ1pNV3ZndlpZdWZ1SUdreC9CSGszL3VvSkl1YVdUQUNxYysrVm9Qc0wg==”,
“apiKey”: “JClB5B8oPU0E4NJXT4VfLQrxzvRyoSnc”,
“files”: {
“network/network.config”: “[service_home_ethernet]\nType=ethernet\nNameservers=8.8.8.8,8.8.4.4”
}
}

STEP 4. install

STEP 5. login:
Reporting scan results

host: c405737.local
address: 10.193.0.101
dockerInfo:
Containers: 1
ContainersRunning: 1
ContainersPaused: 0
ContainersStopped: 0
Images: 2
Driver: aufs
SystemTime: 2020-05-27T08:30:57.762203726Z
KernelVersion: 5.2.10-yocto-standard
OperatingSystem: balenaOS 2.50.1+rev1
Architecture: x86_64
dockerVersion:
Version: 18.09.17-dev
ApiVersion: 1.39

STEP 6. supervisor:
CERTS ISSUE!!!
root@c405737:~# balena logs -f resin_supervisor
WARNING: ca-certificates.crt does not contain exactly one certificate or CRL: skipping
Warning: Ignoring extra certs from /etc/ssl/certs/balenaRootCA.pem, load failed: error:02001002:system library:fopen:No such file or directory
[info] Supervisor v11.4.10 starting up…
[debug] Starting event tracker
[debug] Starting logging infrastructure
[debug] Starting api binder
[event] Event: Supervisor start {}
[error] LogBackend: unexpected error: Error: self signed certificate in certificate chain
[error] at TLSSocket.onConnectSecure (_tls_wrap.js:1474:34)
[error] at TLSSocket.emit (events.js:310:20)
[error] at TLSSocket._finishInit (_tls_wrap.js:917:8)
[error] at TLSWrap.ssl.onhandshakedone (_tls_wrap.js:687:12)
[debug] Performing database cleanup for container log timestamps

STEP 6.1 FIX CERTS ISSUE:
root@c405737:~# balena exec -it resin_supervisor sh
add NODE_EXTRA_CA_CERTS with right path to entry.sh and save

modprobe ip6_tables || true
export NODE_EXTRA_CA_CERTS=/usr/local/share/ca-certificates/balenaRootCA.crt
if [ “${LIVEPUSH}” = “1” ]; then

ctrl+d
balena stop resin_supervisor
sleep 5

STEP 7. Checking supervisor logs:
root@c405737:~# balena logs -f resin_supervisor

info] Supervisor v11.4.10 starting up…
[debug] Starting event tracker
[debug] Starting logging infrastructure
[debug] Starting api binder
[event] Event: Supervisor start {}
[debug] Performing database cleanup for container log timestamps
[info] Previous engine snapshot was not stored. Skipping cleanup.
[debug] Handling of local mode switch is completed
[error] LogBackend: server responded with status code: 401
[debug] Connectivity check enabled: true
[debug] Starting periodic check for IP addresses
[info] Reporting initial state, supervisor version and API info
[debug] VPN status path exists.
[info] Waiting for connectivity…
(node:1) [DEP0005] DeprecationWarning: Buffer() is deprecated due to security and usability issues. Please use the Buffer.alloc(), Buffer.allocUnsafe(), or Buffer.from() methods instead.
[info] Attempting to load any preloaded applications
[info] Starting API server
[info] Applying target state
[debug] Ensuring device is provisioned
[event] Event: Device bootstrap {}
[info] New device detected. Provisioning…
[event] Event: Device bootstrap failed, retrying {“delay”:30000,“error”:{“message”:“User ID must be a valid integer”,“stack”:“Error: User ID must be a valid integer\n at /usr/src/app/dist/app.js:2:2630094\n at PassThroughHandlerContext.finallyHandler (/usr/src/app/dist/app.js:2:1748917)\n at PassThroughHandlerContext.tryCatcher (/usr/src/app/dist/app.js:2:220284)\n at Promise._settlePromiseFromHandler (/usr/src/app/dist/app.js:2:1708447)\n at Promise._settlePromise (/usr/src/app/dist/app.js:2:1709730)\n at Promise._settlePromise0 (/usr/src/app/dist/app.js:2:1710770)\n at Promise._settlePromises (/usr/src/app/dist/app.js:2:1712478)\n at _drainQueueStep (/usr/src/app/dist/app.js:2:1715412)\n at _drainQueue (/usr/src/app/dist/app.js:2:1715308)\n at Async._drainQueues (/usr/src/app/dist/app.js:2:1716625)\n at Immediate.Async.drainQueues [as _onImmediate] (/usr/src/app/dist/app.js:2:1715217)\n at processImmediate (internal/timers.js:456:21)”}}
[debug] Supervisor API listening on allowed interfaces only
[info] Supervisor API successfully started on port 48484

I found that params should be passed like described here:

But how and where from supervisor reads them???

The supervisor will send all the content of config.json to the register method and the value of userId can be Int or string (as long as it can be parsed to Int) so it’s weird, can you please check the content of /mnt/boot/config.json on the device?

How to debug it at deployed instance to ensure, that config.json variables had been read and supervisor structures are populated with them?

You guys delete these fields from supervisor I guess, please confirm - https://github.com/balena-io/balena-supervisor/commit/913418bb37aafe1e66dcc9cd6e1f84e89dee4712

And what should I do next?

Which version of open-balena-api are you using? We dropped the requirement for user ID, so I think you’ll just need to update.

I also created another topic about update - open-balena-api v0.76.3 sql migrations

My current versions:
cat compose/versions
export OPENBALENA_API_VERSION_TAG=v0.19.5
#export OPENBALENA_API_VERSION_TAG=v0.48.1
#export OPENBALENA_API_VERSION_TAG=v0.66.0
export OPENBALENA_DB_VERSION_TAG=latest
export OPENBALENA_MDNS_PUBLISHER_VERSION_TAG=v1.7.6
export OPENBALENA_REGISTRY_VERSION_TAG=v2.11.1
#export OPENBALENA_REGISTRY_VERSION_TAG=v2.13.7
export OPENBALENA_S3_VERSION_TAG=v2.9.6
export OPENBALENA_VPN_VERSION_TAG=v9.13.4

If I’ll update, could you please provide me exact versions, which are compatible with each other?

Let’s continue support in the other thread, as I feel these issues can be solved with the same actions.

Okay, lets move to https://forums.balena.io/t/open-balena-api-v0-76-3-sql-migrations