canique / gateway

Tools and How-Tos related to Canique Gateway and Canique Radio Hat for Raspberry Pi
https://www.canique.com/gateway
2 stars 0 forks source link

SW asks for Encryption Key, directions say Password... #4

Closed earlthesquirrel closed 1 year ago

earlthesquirrel commented 1 year ago

In adding the first (and only) sensor I have, it's asks:

sudo -u cnq canique-sensor-keytool set You will be asked for the sensor UID and the sensor radio password. Repeat this step for every sensor you want to connect.

However, on the screen it asks :

i@caniquepi:~ $ sudo -u cnq canique-sensor-keytool set Enter UID (number): XXXXX Enter Radio Encryption Key:

Is Encryption Key Password? (that's what I entered, but not sure if it's correct...)

canique commented 1 year ago

You have a rev 0.8 hardware as far as I know. Like the documentation says you do not need to setup any password at all. You can skip this step altogether, it has already been done for you. It's stored in the EEPROM.

The radio encryption key is a short password, yes, specific to a sensor, different for every sensor

earlthesquirrel commented 1 year ago

Ok, so is it the Sensor Radio Password from the same paper with the MQTT info? That's what I used (and I didn't skip this...sadly...) Right now it looks like gateway is up and running... But sensor is not connecting... At least it doesn't show up on either cockpit. I can login to the cloud one and also see the local one. The dialog doesn't quite show all the info. See picture : Screenshot 2023-03-20 at 4 16 25 PM

canique commented 1 year ago

Yes the sensor radio password will be on the sheet with the info. The info you're searching for looks like this

Sensor #xxx123456xxx
Radio Password: xxxxxxxx

The sensor UID is always a number. When prompted for it, you need to enter it without any preceding hash sign. The sensor password is alphanumeric, you should have an info on your sheet saying "Radio Passwords never contain the upper case letters I (upper case i), O and Z." (This is so there are no misunderstandings between zero an O, one and I, and two and Z.)

What does journalctl -f -u canique-radio-bridge say?

1) If it says "Decrypt failed", then you're receiving sensor msgs but have the password not setup up correctly. 2) At some point right after startup of canique-radio-bridge, it should say "Gateway Module initialized" - that's exactly when the radio will start listening. If it doesn't say that at startup, then the time is unknown or unsychronized and we'll have to look at the NTP setup. 3) If you see "Gateway Module initialized" but no msgs at all, no valid msgs, no "Decrypt failed", then the sensor is not transmitting. Possible reasons:

canique commented 1 year ago

By the way: case is important (upper/lowercase), so password needs to be entered exactly as on the info sheet.

earlthesquirrel commented 1 year ago

pi@caniquepi:~ $ journalctl -f -u canique-radio-bridge -- Journal begins at Mon 2023-02-20 20:23:30 EST. -- Mar 20 16:02:44 caniquepi python[1749]: [GW Log] Local node setup complete Mar 20 16:02:44 caniquepi python[1749]: NTP synchronized: True Mar 20 16:02:44 caniquepi python[1749]: Waking Gateway Hat up Mar 20 16:11:07 caniquepi python[1749]: RECV MSG on topic gw/249006/setSensorRadioKey/359506 Mar 20 16:11:07 caniquepi python[1749]: Transmitting peer key for UID 359506 Mar 20 16:33:45 caniquepi python[1749]: NTP synchronized: True Mar 20 17:04:45 caniquepi python[1749]: NTP synchronized: True Mar 20 17:35:46 caniquepi python[1749]: NTP synchronized: True Mar 20 18:06:46 caniquepi python[1749]: NTP synchronized: True Mar 20 18:37:47 caniquepi python[1749]: NTP synchronized: True Mar 20 19:08:47 caniquepi python[1749]: NTP synchronized: True Mar 20 19:39:48 caniquepi python[1749]: NTP synchronized: True Mar 20 20:10:48 caniquepi python[1749]: NTP synchronized: True Mar 20 20:41:48 caniquepi python[1749]: NTP synchronized: True Mar 20 21:12:49 caniquepi python[1749]: NTP synchronized: True Mar 20 21:43:49 caniquepi python[1749]: NTP synchronized: True Mar 20 22:14:50 caniquepi python[1749]: NTP synchronized: True Mar 20 22:45:50 caniquepi python[1749]: NTP synchronized: True Mar 20 23:16:51 caniquepi python[1749]: NTP synchronized: True Mar 20 23:47:51 caniquepi python[1749]: NTP synchronized: True Mar 21 00:18:52 caniquepi python[1749]: NTP synchronized: True Mar 21 00:49:52 caniquepi python[1749]: NTP synchronized: True

No Decrypt failed messages. So I don't think it's getting any data from the sensor. For sensor debugging, I unscrewed it from the case so I could see the LED. I tried a Duracell battery to start with (and checked the voltage). No luck. I have an energizer ultimate lithium battery (which starts at like 1.7 or 1.8 volts). In both cases I got the initial flash of the led. But no data showing up.

Then went downstairs last night and got a fresh Duracell from a brand new package. Same lighting of the LED, but no data.

The sensor is sitting on that same mouse pad that I took the picture of the raspberry pi, so shouldn't be a noise or distance issue.

Thoughts?

earlthesquirrel commented 1 year ago

Backing up in the journal, here's the full top of the log (so it "looks like" the gateway started ok) FYI - The battery was taken out and put back in many times since the gateway started.

Mar 20 16:02:39 caniquepi systemd[1]: Started Canique Radio Bridge. Mar 20 16:02:40 caniquepi python[1749]: RSSI threshold -98 Mar 20 16:02:40 caniquepi python[1749]: Hard resetting Gateway Hat Mar 20 16:02:40 caniquepi python[1749]: Dropped root privileges Mar 20 16:02:40 caniquepi python[1749]: user ID real/effective/saved (112, 112, 112) Mar 20 16:02:40 caniquepi python[1749]: Suppl. groups [20], effective group 995, real group 995 Mar 20 16:02:43 caniquepi python[1749]: [GW Log] Gateway Module started up Mar 20 16:02:43 caniquepi python[1749]: Starting serial interface RX... Mar 20 16:02:43 caniquepi python[1749]: Starting serial interface TX... Mar 20 16:02:44 caniquepi python[1749]: Connected to MQTT broker. flags 1. rc 0. props {'topic_aliasmaximum': [10], 'receive> Mar 20 16:02:44 caniquepi python[1749]: Subscribing to tx/# Mar 20 16:02:44 caniquepi python[1749]: Subscribing to gw/249006/setSensorRadioKey/+ Mar 20 16:02:44 caniquepi python[1749]: Subscribing to gw/249006/removeSensorRadioKey/+ Mar 20 16:02:44 caniquepi python[1749]: Gateway Info: Mar 20 16:02:44 caniquepi python[1749]: Firmware Revision: 12169 Mar 20 16:02:44 caniquepi python[1749]: Unique ID: 249006 Mar 20 16:02:44 caniquepi python[1749]: Hat Type: Canique Gateway Hat Mar 20 16:02:44 caniquepi python[1749]: Hardware Revision: 0.8.0 Mar 20 16:02:44 caniquepi python[1749]: Build Date: 17.2.2023 Mar 20 16:02:44 caniquepi python[1749]: S/N: J53GX5R6V1NG Mar 20 16:02:44 caniquepi python[1749]: Radio: 868 MHz, H/W Mar 20 16:02:44 caniquepi python[1749]: Sent local node setup for node 1, network 10 Mar 20 16:02:44 caniquepi python[1749]: Subscribed mid #1 props {} qos (1, 0, 0, 0) Mar 20 16:02:44 caniquepi python[1749]: [GW Log] Local sender ID 1 Mar 20 16:02:44 caniquepi python[1749]: [GW Log] Local node setup complete Mar 20 16:02:44 caniquepi python[1749]: NTP synchronized: True Mar 20 16:02:44 caniquepi python[1749]: Waking Gateway Hat up Mar 20 16:11:07 caniquepi python[1749]: RECV MSG on topic gw/249006/setSensorRadioKey/359506 Mar 20 16:11:07 caniquepi python[1749]: Transmitting peer key for UID 359506 Mar 20 16:33:45 caniquepi python[1749]: NTP synchronized: True Mar 20 17:04:45 caniquepi python[1749]: NTP synchronized: True Mar 20 17:35:46 caniquepi python[1749]: NTP synchronized: True Mar 20 18:06:46 caniquepi python[1749]: NTP synchronized: True Mar 20 18:37:47 caniquepi python[1749]: NTP synchronized: True Mar 20 19:08:47 caniquepi python[1749]: NTP synchronized: True

earlthesquirrel commented 1 year ago

BTW, The password which I entered was from the paper and is all upper case. (Also, the prompt still needs to be adjusted or the instructions need to... because password in one place, encryption key in the other.... so they don't match, word wise)

earlthesquirrel commented 1 year ago

Oh and just FYI the values in the dialog are Danish (which I suspect makes sense for you :-) ) Google translate let me know what you were intending... but it didn't pick up the US English set up of the Raspberry Pi.

canique commented 1 year ago

"Gateway Module initialized" is missing. This most probably means something wrong with time sync (=> radio hat does not know the time)

I'll give you some instructions tomorrow... It's not the sensor, that's for sure. There is no sense in replacing the battery. The radio is not even turned on because it does not know the time.

earlthesquirrel commented 1 year ago

I have a local NTP stratum 1 server in my network. I'll try updating the local config (as I have for other Pi's) to use that.... It's an additional manual step I take on the other devices in my network... (but I'll be interested in your notes as well)

canique commented 1 year ago

I'm going to try to reproduce the problem on a Raspi3B tomorrow with fresh OS (no manual changes), same radio hat revision, with coin cell installed/removed.

NTP seems ok - the linux command "timedatectl show" is internally run and evaluated. "NTP synchronized: True" is output if the command outputs "NTP=yes" and "NTPSynchronized=yes".

Some output is missing, though. E.g. "Success setting date/time.", "Gateway startup counter xxxx" I'll find out why, but it can take some time.

earlthesquirrel commented 1 year ago

FYI, my time set up normally uses NTP, so that mucked up stuff.... and got it to were it was failing like the 3B+ But I undid that and made sure timedatectl was properly configured and running right. Now that is back, I'm getting:

Mar 21 23:57:13 caniquepi systemd[1]: Started Canique Radio Bridge. Mar 21 23:57:14 caniquepi python[946]: RSSI threshold -98 Mar 21 23:57:14 caniquepi python[946]: Hard resetting Gateway Hat Mar 21 23:57:14 caniquepi python[946]: Dropped root privileges Mar 21 23:57:14 caniquepi python[946]: user ID real/effective/saved (112, 112, 112) Mar 21 23:57:14 caniquepi python[946]: Suppl. groups [20], effective group 995, real group 995 Mar 21 23:57:17 caniquepi python[946]: [GW Log] Gateway Module started up Mar 21 23:57:17 caniquepi python[946]: Starting serial interface RX... Mar 21 23:57:17 caniquepi python[946]: Starting serial interface TX... Mar 21 23:57:18 caniquepi python[946]: Connected to MQTT broker. flags 1. rc 0. props {'topic_alias_maximum': [10], 'receive_maximum': [1], 'session_expiry_interval': 1209600}. Mar 21 23:57:18 caniquepi python[946]: Subscribing to tx/# Mar 21 23:57:18 caniquepi python[946]: Subscribing to gw/249006/setSensorRadioKey/+ Mar 21 23:57:18 caniquepi python[946]: Subscribing to gw/249006/removeSensorRadioKey/+ Mar 21 23:57:18 caniquepi python[946]: Gateway Info: Mar 21 23:57:18 caniquepi python[946]: Firmware Revision: 12169 Mar 21 23:57:18 caniquepi python[946]: Unique ID: 249006 Mar 21 23:57:18 caniquepi python[946]: Hat Type: Canique Gateway Hat Mar 21 23:57:18 caniquepi python[946]: Hardware Revision: 0.8.0 Mar 21 23:57:18 caniquepi python[946]: Build Date: 17.2.2023 Mar 21 23:57:18 caniquepi python[946]: S/N: J53GX5R6V1NG Mar 21 23:57:18 caniquepi python[946]: Radio: 868 MHz, H/W Mar 21 23:57:18 caniquepi python[946]: Sent local node setup for node 1, network 10 Mar 21 23:57:18 caniquepi python[946]: Subscribed mid #1 props {} qos (1, 0, 0, 0)

Still no Gateway Initialized, but does dhow Gateway Module started up.

Could I have gotten old code from Github?

earlthesquirrel commented 1 year ago

Ok, another piece of data.

On the last two restarts, it initially fails but if I restart it, it provides the output as above...

It first outputs : Mar 22 00:06:40 caniquepi systemd[1]: Started Canique Radio Bridge. Mar 22 00:06:42 caniquepi python[653]: RSSI threshold -98 Mar 22 00:06:42 caniquepi python[653]: Hard resetting Gateway Hat Mar 22 00:06:42 caniquepi python[653]: Dropped root privileges Mar 22 00:06:42 caniquepi python[653]: user ID real/effective/saved (112, 112, 112) Mar 22 00:06:42 caniquepi python[653]: Suppl. groups [20], effective group 995, real group 995 Mar 22 00:06:48 caniquepi python[653]: Timed out waiting for Radio Hat to start up. Is Radio Hat connected? Exiting. Mar 22 00:06:48 caniquepi systemd[1]: canique-radio-bridge.service: Main process exited, code=exited, status=3/NOTIMPLEMENTED Mar 22 00:06:48 caniquepi systemd[1]: canique-radio-bridge.service: Failed with result 'exit-code'. Mar 22 00:06:48 caniquepi systemd[1]: canique-radio-bridge.service: Consumed 1.335s CPU time.

Then after a restart the output from previous comment.

earlthesquirrel commented 1 year ago

Correction... right now it's not starting... so I'm confused...

canique commented 1 year ago

Something with your UART is not working.

I have just taken a Sandisk Ultra 16GB A1 SD card, installed Raspberry OS Lite 32 Bit on it, then ran the setup instructions 1:1 on a Raspberry 3B, and had no troubles.

There are some differences though 1) I have no coin cell installed. 2) Timezone is Europe/Vienna

I will upload exact instructions of what I did, and also upload an image of the SD card in the course of the day, so you can clone it 1:1.

Could I have gotten old code from Github?

Good question. Please run dpkg -l | grep canique The output should be:

ii  canique-local-cockpit                0.2                              all          Canique Local Cockpit is a Web GUI for Canique Devices.
ii  canique-mqtt-tools                   0.4.8                            armhf        Canique Bridge stores MQTT messages to InfluxDB, and runs MQTT logic (alarms etc)
ii  canique-radio-bridge                 0.8.2                            armhf        Canique Message Gateway translates msgs between IP and 433/868 MHz
ii  canique-web-conf                     0.4                              all          Nginx and PHP configuration for CANIQUE
canique commented 1 year ago

This is the output after booting up, after the hat has been physically attached.

Command: journalctl -n200 -u canique-radio-bridge

Mar 22 12:43:44 raspberrypi3 systemd[1]: Started Canique Radio Bridge. Mar 22 12:43:45 raspberrypi3 python[634]: RSSI threshold -98 Mar 22 12:43:45 raspberrypi3 python[634]: Hard resetting Gateway Hat Mar 22 12:43:45 raspberrypi3 python[634]: Dropped root privileges Mar 22 12:43:45 raspberrypi3 python[634]: user ID real/effective/saved (111, 111, 111) Mar 22 12:43:45 raspberrypi3 python[634]: Suppl. groups [20], effective group 994, real group 994 Mar 22 12:43:48 raspberrypi3 python[634]: [GW Log] Gateway Module started up Mar 22 12:43:48 raspberrypi3 python[634]: Starting serial interface RX... Mar 22 12:43:48 raspberrypi3 python[634]: Starting serial interface TX... Mar 22 12:43:49 raspberrypi3 python[634]: Connected to MQTT broker. flags 0. rc 0. props {'topic_alias_maximum': [10], 'receive_maximum': [1], 'session_expiry_interval': 1> Mar 22 12:43:49 raspberrypi3 python[634]: Subscribing to tx/# Mar 22 12:43:49 raspberrypi3 python[634]: Subscribing to gw/248080/setSensorRadioKey/+ Mar 22 12:43:49 raspberrypi3 python[634]: Subscribing to gw/248080/removeSensorRadioKey/+ Mar 22 12:43:49 raspberrypi3 python[634]: Gateway Info: Mar 22 12:43:49 raspberrypi3 python[634]: Firmware Revision: 12169 Mar 22 12:43:49 raspberrypi3 python[634]: Unique ID: 248080 Mar 22 12:43:49 raspberrypi3 python[634]: Hat Type: Canique Gateway Hat Mar 22 12:43:49 raspberrypi3 python[634]: Hardware Revision: 0.8.0 Mar 22 12:43:49 raspberrypi3 python[634]: Build Date: 22.5.2022 Mar 22 12:43:49 raspberrypi3 python[634]: S/N: xxxxxxxxxxxxxxx Mar 22 12:43:49 raspberrypi3 python[634]: Radio: 868 MHz, H/W Mar 22 12:43:49 raspberrypi3 python[634]: Sent local node setup for node 1, network 10 Mar 22 12:43:49 raspberrypi3 python[634]: Subscribed mid #1 props {} qos (1, 0, 0, 0) Mar 22 12:43:49 raspberrypi3 python[634]: [GW Log] Local sender ID 1 Mar 22 12:43:49 raspberrypi3 python[634]: [GW Log] Local node setup complete Mar 22 12:43:49 raspberrypi3 python[634]: NTP synchronized: False Mar 22 12:43:49 raspberrypi3 python[634]: Requesting Date/Time from Radio Hat Mar 22 12:43:49 raspberrypi3 python[634]: HAT Time: 1900-01-01 00:00:27.672000+00:00 Mar 22 12:43:49 raspberrypi3 python[634]: Not setting system time because given date is before 2023. Mar 22 12:43:49 raspberrypi3 python[634]: Waking Gateway Hat up Mar 22 12:43:49 raspberrypi3 python[634]: [GW Log] Gateway startup counter 66 Mar 22 12:43:49 raspberrypi3 python[634]: [GW Log] Peer setup for UID 359xxx Mar 22 12:43:49 raspberrypi3 python[634]: [GW Log] Peer setup for UID 359xxx ... Mar 22 12:43:49 raspberrypi3 python[634]: [GW Log] Peer setup complete Mar 22 12:43:54 raspberrypi3 python[634]: NTP synchronized: False Mar 22 12:47:07 raspberrypi3 python[634]: NTP synchronized: True Mar 22 12:47:07 raspberrypi3 python[634]: [GW Log] Success setting date/time. Mar 22 12:47:07 raspberrypi3 python[634]: [GW Log] Gateway Module initialized Mar 22 12:47:15 raspberrypi3 python[634]: TX 5 -> RX 1: Decrypt Failed. [12, 1, 5, 64, 26, 228, 164, 120, 128, 42, 140, 213, 133] Connection index: 100 RSSI: -69 > Mar 22 12:47:28 raspberrypi3 python[634]: TX 4 -> RX 1: Decrypt Failed. [12, 1, 4, 64, 137, 12, 100, 52, 159, 164, 6, 63, 35] Connection index: 100 RSSI: -90

canique commented 1 year ago

after a restart of canique-radio-bridge, the output looks like this:

Mar 22 13:01:14 raspberrypi3 python[919]: RSSI threshold -98 Mar 22 13:01:14 raspberrypi3 python[919]: Hard resetting Gateway Hat Mar 22 13:01:15 raspberrypi3 python[919]: Dropped root privileges Mar 22 13:01:15 raspberrypi3 python[919]: user ID real/effective/saved (111, 111, 111) Mar 22 13:01:15 raspberrypi3 python[919]: Suppl. groups [20], effective group 994, real group 994 Mar 22 13:01:17 raspberrypi3 python[919]: [GW Log] Gateway Module started up Mar 22 13:01:17 raspberrypi3 python[919]: Starting serial interface RX... Mar 22 13:01:17 raspberrypi3 python[919]: Starting serial interface TX... Mar 22 13:01:18 raspberrypi3 python[919]: Connected to MQTT broker. flags 1. rc 0. props {'topic_alias_maximum': [10], 'receive_maximum': [1], 'session_expiry_interval': 1> Mar 22 13:01:18 raspberrypi3 python[919]: Subscribing to tx/# Mar 22 13:01:18 raspberrypi3 python[919]: Subscribing to gw/248080/setSensorRadioKey/+ Mar 22 13:01:18 raspberrypi3 python[919]: Subscribing to gw/248080/removeSensorRadioKey/+ Mar 22 13:01:18 raspberrypi3 python[919]: Gateway Info: Mar 22 13:01:18 raspberrypi3 python[919]: Firmware Revision: 12169 Mar 22 13:01:18 raspberrypi3 python[919]: Unique ID: 248080 Mar 22 13:01:18 raspberrypi3 python[919]: Hat Type: Canique Gateway Hat Mar 22 13:01:18 raspberrypi3 python[919]: Hardware Revision: 0.8.0 Mar 22 13:01:18 raspberrypi3 python[919]: Build Date: 22.5.2022 Mar 22 13:01:18 raspberrypi3 python[919]: S/N: xxxxxxxxxxx Mar 22 13:01:18 raspberrypi3 python[919]: Radio: 868 MHz, H/W Mar 22 13:01:18 raspberrypi3 python[919]: Sent local node setup for node 1, network 10 Mar 22 13:01:18 raspberrypi3 python[919]: Subscribed mid #1 props {} qos (1, 0, 0, 0) Mar 22 13:01:18 raspberrypi3 python[919]: [GW Log] Local sender ID 1 Mar 22 13:01:18 raspberrypi3 python[919]: [GW Log] Local node setup complete Mar 22 13:01:18 raspberrypi3 python[919]: NTP synchronized: True Mar 22 13:01:18 raspberrypi3 python[919]: [GW Log] Success setting date/time. Mar 22 13:01:18 raspberrypi3 python[919]: Waking Gateway Hat up Mar 22 13:01:18 raspberrypi3 python[919]: [GW Log] Gateway startup counter 67 Mar 22 13:01:18 raspberrypi3 python[919]: [GW Log] Peer setup for UID 359xxx ... Mar 22 13:01:18 raspberrypi3 python[919]: [GW Log] Peer setup complete Mar 22 13:01:19 raspberrypi3 python[919]: [GW Log] Gateway Module initialized

canique commented 1 year ago

This is the extended installation procedure describing everything step by step: https://github.com/canique/gateway/blob/main/raspberry-pi-radio-hat/install_radiohat_software.md

I also tested the radio hat with coin cell inserted now, did a reboot, no troubles at all.

canique commented 1 year ago

As promised, the image: https://resources.canique.com/radio-hat/raspberry-pi-os-lite-radio-hat-0.1.img

This image (hope I extracted it properly from the SD card) is the OS I've just used during my tests. If you compare it to the steps described in https://github.com/canique/gateway/tree/main/raspberry-pi-radio-hat - only step 1 to 3 has been executed. This image is supposed to get your setup working. It has german keyboard layout configured, but for an initial test this should not be of importance.

While testing this image, please run no other commands before checking whether the communication with the radio is working okay.

A short intro how to install this image:

  1. Download it to a computer
  2. You can run sha256sum raspberry-pi-os-lite-radio-hat-0.1.img to check its checksum. It should equal: 8bb83061864917c9372cb63826bc257e25fe7094804e5a8dc42e3767b237d87a
  3. Flash it to an SD card (min 4GB) - I'd recommend using BalenaEtcher (on Windows) or any tool you trust
  4. Insert it to your Raspberry Pi 3B, with everything connected (hat + antenna + network cable)
  5. Power on your Raspberry Pi
  6. Connect to your Raspberry Pi: ssh pi@x.x.x.x (replace x.x.x.x by its IP address). Enter cnq100 as password.
  7. Check whether radio is okay with journalctl -n200 -u canique-radio-bridge
  8. If everything works ok, you can expand the filesystem so the filesystem uses the whole SD card instead of being limited to ~3GB.
earlthesquirrel commented 1 year ago

Ok, replying to comments, 1:1.

Checking code:

ii  canique-local-cockpit                0.2                              all          Canique Local Cockpit is a Web GUI for Canique Devices.
ii  canique-mqtt-tools                   0.4.8                            armhf        Canique Bridge stores MQTT messages to InfluxDB, and runs MQTT logic (alarms etc)
ii  canique-radio-bridge                 0.8.2                            armhf        Canique Message Gateway translates msgs between IP and 433/868 MHz
ii  canique-web-conf                     0.4                              all          Nginx and PHP configuration for CANIQUE

So looks identical.

earlthesquirrel commented 1 year ago

I'm downloading and will do the initial install. I've always been running with a battery installed.... is this set up without the battery? (at least I'm going to start with no battery). I'll be using Raspberry Pi Imager v.1.7.4 to flash the SD card. (it's a Microcenter branded card, but I've used them without any issues for years). It's a 64GB card. I'm on a Mac, just FYI.

8bb83061864917c9372cb63826bc257e25fe7094804e5a8dc42e3767b237d87a /Users/ebaugh/Downloads/raspberry-pi-os-lite-radio-hat-0.1.img

checksum looks right.

Flashing now (have a work call, so will send this for now...)

canique commented 1 year ago

I've tested it without battery first. Then installed the battery later.

This is a picture from the side taken today, showing the header fully inserted (no blank metal visible). Just to be sure there are no physical connection issues.

0_IMG_20230322_131141

earlthesquirrel commented 1 year ago

Ok, just finishing these steps (call got delayed 15 min :-) )

3. Flash it to an SD card (min 4GB) - I'd recommend using BalenaEtcher (on Windows) or any tool you trust
4. Insert it to your Raspberry Pi 3B, with everything connected (hat + antenna + network cable)
5. Power on your Raspberry Pi
6. Connect to your Raspberry Pi: ssh pi@x.x.x.x (replace x.x.x.x by its IP address). Enter cnq100 as password.

Logged in. FYI, Wifi is off, on mine it was on. (from login note : Wi-Fi is currently blocked by rfkill) Also it says "Use rasp-config to set the country before use." I'm assuming that's for the Wifi. Just trying to note differences.

So running command (#7) pi@raspberrypi3:~ $ journalctl -n200 -u canique-radio-bridge -- Journal begins at Wed 2023-03-22 15:08:00 CET, ends at Wed 2023-03-22 19:10:43 CET. -- Mar 22 15:13:04 raspberrypi3 systemd[1]: Started Canique Radio Bridge. Mar 22 15:13:06 raspberrypi3 python[659]: RSSI threshold -98 Mar 22 15:13:06 raspberrypi3 python[659]: Hard resetting Gateway Hat Mar 22 15:13:06 raspberrypi3 python[659]: Dropped root privileges Mar 22 15:13:06 raspberrypi3 python[659]: user ID real/effective/saved (111, 111, 111) Mar 22 15:13:06 raspberrypi3 python[659]: Suppl. groups [20], effective group 994, real group 994 Mar 22 15:13:11 raspberrypi3 python[659]: Timed out waiting for Radio Hat to start up. Is Radio Hat connected? Exiting. Mar 22 15:13:11 raspberrypi3 systemd[1]: canique-radio-bridge.service: Main process exited, code=exited, status=3/NOTIMPLEMENTED Mar 22 15:13:11 raspberrypi3 systemd[1]: canique-radio-bridge.service: Failed with result 'exit-code'. Mar 22 15:13:11 raspberrypi3 systemd[1]: canique-radio-bridge.service: Consumed 1.345s CPU time.

I've checked the antenna (did that last night) -- Nothing seems to be wrong there.

Didn't do anything (command wise) except logging in and then running the journalctl command.

Going to try to reboot (in case this was a situation of needing the reboot after first start)

Nope, identical output from journalctl command. Also checked the cable from hat to antenna and re-seated it (it seemed to be connected just fine).

Let me dig around and see if I have another RPi 3B..... but so far, nothing obviously wrong with this one. (I even just removed a heat sink that was underneath the board... visually I didn't see it touching anything... at worst the outside of the black battery connection but that's plastic...

I'm running without battery, please confirm that's correct.

earlthesquirrel commented 1 year ago

IMG_0636 IMG_0637

canique commented 1 year ago

The WiFi note is fine, I saw the same msg on my setup. Battery connected or not - the startup msg at the beginning must appear.

The fact that it does not get any data from the hat is abnormal. To me this seems like a hardware issue currently. Hardware wise, the 2 pins making problems are labeled RX and TX on the hat.

If you can get another 3B - perfect. But please also check the power supply. If I'm not mistaken Raspberry 3 needs a 2.5A power supply. So your power supply should be able to deliver at least 2.5A current.

Another important note: The pad where you have your Raspberry on - take something isolated. A paper book, wood (dry, not wet), plastic. But this kind of thing that you have might not isolate electricity perfectly or have static charge.

My Raspberry was on a thick sheet of paper e.g.

earlthesquirrel commented 1 year ago

Ok, on another RPI3B, I moved stuff over, and first boot had the same problem. Did a restart of the service and got this output :

Mar 22 20:20:49 raspberrypi3 systemd[1]: Started Canique Radio Bridge. Mar 22 20:20:50 raspberrypi3 python[962]: RSSI threshold -98 Mar 22 20:20:50 raspberrypi3 python[962]: Hard resetting Gateway Hat Mar 22 20:20:50 raspberrypi3 python[962]: Dropped root privileges Mar 22 20:20:50 raspberrypi3 python[962]: user ID real/effective/saved (111, 111, 111) Mar 22 20:20:50 raspberrypi3 python[962]: Suppl. groups [20], effective group 994, real group 994 Mar 22 20:20:53 raspberrypi3 python[962]: [GW Log] Gateway Module started up Mar 22 20:20:53 raspberrypi3 python[962]: Starting serial interface RX... Mar 22 20:20:53 raspberrypi3 python[962]: Starting serial interface TX... Mar 22 20:20:54 raspberrypi3 python[962]: Connected to MQTT broker. flags 1. rc 0. props {'topic_alias_maximum': [10], 'receive_maximum': [1], 'se> Mar 22 20:20:54 raspberrypi3 python[962]: Subscribing to tx/# Mar 22 20:20:54 raspberrypi3 python[962]: Subscribing to gw/249006/setSensorRadioKey/+ Mar 22 20:20:54 raspberrypi3 python[962]: Subscribing to gw/249006/removeSensorRadioKey/+ Mar 22 20:20:54 raspberrypi3 python[962]: Gateway Info: Mar 22 20:20:54 raspberrypi3 python[962]: Firmware Revision: 12169 Mar 22 20:20:54 raspberrypi3 python[962]: Unique ID: 249006 Mar 22 20:20:54 raspberrypi3 python[962]: Hat Type: Canique Gateway Hat Mar 22 20:20:54 raspberrypi3 python[962]: Hardware Revision: 0.8.0 Mar 22 20:20:54 raspberrypi3 python[962]: Build Date: 17.2.2023 Mar 22 20:20:54 raspberrypi3 python[962]: S/N: J53GX5R6V1NG Mar 22 20:20:54 raspberrypi3 python[962]: Radio: 868 MHz, H/W Mar 22 20:20:54 raspberrypi3 python[962]: Sent local node setup for node 1, network 10 Mar 22 20:20:54 raspberrypi3 python[962]: Subscribed mid #1 props {} qos (1, 0, 0, 0) Mar 22 20:20:54 raspberrypi3 python[962]: [GW Log] Local sender ID 1 Mar 22 20:20:54 raspberrypi3 python[962]: [GW Log] Local node setup complete Mar 22 20:20:54 raspberrypi3 python[962]: NTP synchronized: True Mar 22 20:20:54 raspberrypi3 python[962]: Waking Gateway Hat up

In your first startup you had:

Mar 22 12:43:49 raspberrypi3 python[634]: NTP synchronized: False Mar 22 12:43:49 raspberrypi3 python[634]: Requesting Date/Time from Radio Hat

I noticed that my Pi has a date of 2023. Yours had 1900. I'm wondering if that's part of it.

pi@raspberrypi3:~ $ date Wed 22 Mar 20:23:54 CET 2023

So, going to try to set it to 1900 and restarting...(no luck, the time sync updates too fast)

earlthesquirrel commented 1 year ago

FYI This section is what I see as different :

Mar 22 12:43:49 raspberrypi3 python[634]: NTP synchronized: False Mar 22 12:43:49 raspberrypi3 python[634]: Requesting Date/Time from Radio Hat Mar 22 12:43:49 raspberrypi3 python[634]: HAT Time: 1900-01-01 00:00:27.672000+00:00 Mar 22 12:43:49 raspberrypi3 python[634]: Not setting system time because given date is before 2023. Mar 22 12:43:49 raspberrypi3 python[634]: Waking Gateway Hat up Mar 22 12:43:49 raspberrypi3 python[634]: [GW Log] Gateway startup counter 66 Mar 22 12:43:49 raspberrypi3 python[634]: [GW Log] Peer setup for UID 359xxx Mar 22 12:43:49 raspberrypi3 python[634]: [GW Log] Peer setup for UID 359xxx ... Mar 22 12:43:49 raspberrypi3 python[634]: [GW Log] Peer setup complete Mar 22 12:43:54 raspberrypi3 python[634]: NTP synchronized: False Mar 22 12:47:07 raspberrypi3 python[634]: NTP synchronized: True Mar 22 12:47:07 raspberrypi3 python[634]: [GW Log] Success setting date/time. Mar 22 12:47:07 raspberrypi3 python[634]: [GW Log] Gateway Module initialized Mar 22 12:47:15 raspberrypi3 python[634]: TX 5 -> RX 1: Decrypt Failed. [12, 1, 5, 64, 26, 228, 164, 120, 128, 42, 140, 213, 133] Connection index: 100 RSSI: -69 > Mar 22 12:47:28 raspberrypi3 python[634]: TX 4 -> RX 1: Decrypt Failed. [12, 1, 4, 64, 137, 12, 100, 52, 159, 164, 6, 63, 35] Connection index: 100 RSSI: -90

In reviewing this output, I see that it doesn't set system time because HAT time is old. I have removed the battery from my hat, but I don't know how to put my hat in that same state.

We both see the same BOLD line, but mine never goes past that. Even after changing the RPI board. Is there anything in the firmware that has any sort of check before the line afterwards?

canique commented 1 year ago

My concern is the pad under the Raspberry. Like I said, to me this seems like a hardware issue. At the beginning I thought it's a race condition, but we have the same hardware, same software.

That your raspberry time synchronizes fast, is okay. The output is not always the same. When I do a restart e.g., then NTP is synchronized, and system time is transferred to the hat e.g.

I noticed that my Pi has a date of 2023. Yours had 1900.

You misunderstood that. Raspberry requested the date from the hat, which was found invalid. The 1900 came from the hat because it had no battery. Then it starts with 1900.

My most important question is: What is underneath your Raspberry right now? Did you try it with a sheet of paper or a book?

canique commented 1 year ago

1) Try a different power supply please 2) Put something that is electrically not conductive and does not build statical charge under your Raspberry please.

Maybe this will make a difference.

earlthesquirrel commented 1 year ago

Ok, some progress (but absolutely NO idea why)

I did get this in the Journal :

Mar 22 20:42:33 raspberrypi3 systemd[1]: canique-radio-bridge.service: Consumed 1.316s CPU time. Mar 22 20:42:33 raspberrypi3 systemd[1]: Started Canique Radio Bridge. Mar 22 20:42:34 raspberrypi3 python[1688]: RSSI threshold -98 Mar 22 20:42:34 raspberrypi3 python[1688]: Hard resetting Gateway Hat Mar 22 20:42:34 raspberrypi3 python[1688]: Dropped root privileges Mar 22 20:42:34 raspberrypi3 python[1688]: user ID real/effective/saved (111, 111, 111) Mar 22 20:42:34 raspberrypi3 python[1688]: Suppl. groups [20], effective group 994, real group 994 Mar 22 20:42:37 raspberrypi3 python[1688]: [GW Log] Gateway Module started up Mar 22 20:42:37 raspberrypi3 python[1688]: Starting serial interface RX... Mar 22 20:42:37 raspberrypi3 python[1688]: Starting serial interface TX... Mar 22 20:42:38 raspberrypi3 python[1688]: Connected to MQTT broker. flags 1. rc 0. props {'topic_alias_maximum': [10], 'receive_maximum': [1], 's> Mar 22 20:42:38 raspberrypi3 python[1688]: Subscribing to tx/# Mar 22 20:42:38 raspberrypi3 python[1688]: Subscribing to gw/249006/setSensorRadioKey/+ Mar 22 20:42:38 raspberrypi3 python[1688]: Subscribing to gw/249006/removeSensorRadioKey/+ Mar 22 20:42:38 raspberrypi3 python[1688]: Gateway Info: Mar 22 20:42:38 raspberrypi3 python[1688]: Firmware Revision: 12169 Mar 22 20:42:38 raspberrypi3 python[1688]: Unique ID: 249006 Mar 22 20:42:38 raspberrypi3 python[1688]: Hat Type: Canique Gateway Hat Mar 22 20:42:38 raspberrypi3 python[1688]: Hardware Revision: 0.8.0 Mar 22 20:42:38 raspberrypi3 python[1688]: Build Date: 17.2.2023 Mar 22 20:42:38 raspberrypi3 python[1688]: S/N: J53GX5R6V1NG Mar 22 20:42:38 raspberrypi3 python[1688]: Radio: 868 MHz, H/W Mar 22 20:42:38 raspberrypi3 python[1688]: Sent local node setup for node 1, network 10 Mar 22 20:42:38 raspberrypi3 python[1688]: Subscribed mid #1 props {} qos (1, 0, 0, 0) Mar 22 20:42:38 raspberrypi3 python[1688]: [GW Log] Local sender ID 1 Mar 22 20:42:38 raspberrypi3 python[1688]: [GW Log] Local node setup complete Mar 22 20:42:38 raspberrypi3 python[1688]: NTP synchronized: True Mar 22 20:42:38 raspberrypi3 python[1688]: [GW Log] Success setting date/time. Mar 22 20:42:38 raspberrypi3 python[1688]: Waking Gateway Hat up Mar 22 20:42:38 raspberrypi3 python[1688]: [GW Log] Gateway startup counter 4 Mar 22 20:42:38 raspberrypi3 python[1688]: [GW Log] Peer setup for UID 359506: peer startup counter 26, peer msg counter 5 Mar 22 20:42:38 raspberrypi3 python[1688]: [GW Log] Peer setup complete Mar 22 20:42:38 raspberrypi3 python[1688]: [GW Log] Gateway Module initialized Mar 22 20:43:53 raspberrypi3 python[1688]: Sensor #359506 [Node 2]: deviceType=airsensor;hardwareRevision=1.0.1;buildDate=5.2.2023;radioHighPower=> Mar 22 20:43:53 raspberrypi3 python[1688]: Sensor #359506 [Node 2]: temperature=2529;humidity=2849;voltage=1655; RSSI: -47 Mar 22 20:44:23 raspberrypi3 python[1688]: Sensor #359506 [Node 2]: temperature=2529;humidity=2831; RSSI: -51

I'm not sure if it just woke up after a while or what... I'm going to try removing the battery from the sensor to see if it reconnects. (This all happened while I was trying to enter MQTT info to see if that gave me any more info.... and had a typo in the password '&' which caused some weird behavior as it tried to background the command with not all of the password... doh!).

Can you perhaps generate a version with more debugging output so perhaps we can sort this out?

earlthesquirrel commented 1 year ago

BTW, this new one is in a plastic case bottom. I'll try another power supply...

earlthesquirrel commented 1 year ago

BTW My hat doesn't have a battery either but I don't get the 1900 message...

earlthesquirrel commented 1 year ago

Ok, so we have success! I'm seeing amber light on a bunch and data in the console.. VERY VERY strange behavior..... it started "once" I guess power was ok then?

earlthesquirrel commented 1 year ago

So, what should be my next steps? Put in battery? Change locale?

canique commented 1 year ago

BTW My hat doesn't have a battery either but I don't get the 1900 message...

This is perfectly normal. Your Raspberry syncs the time fast from the NTP server -> hence it does not try to get the time from the hat but instead transmits it to the hat. The preference is: If the Raspberry knows the time, use that time. If it does not know the time, get the time from the hat.

canique commented 1 year ago

Ok, so we have success! I'm seeing amber light on a bunch and data in the console.. VERY VERY strange behavior..... it started "once" I guess power was ok then?

I have no explanation for this.

(This all happened while I was trying to enter MQTT info to see if that gave me any more info.... and had a typo in the password '&' which caused some weird behavior as it tried to background the command with not all of the password... doh!).

Any ampersand in a command (starting a background process) would be gone after the next reboot...

canique commented 1 year ago

So, what should be my next steps? Put in battery? Change locale?

Yes. Both should be fine.

You can also expand the filesystem - https://github.com/canique/gateway/issues/4#issuecomment-1479779142 - step 8.

You can run step 6 from https://github.com/canique/gateway/tree/main/raspberry-pi-radio-hat (setting up cloud connection if not already done).

canique commented 1 year ago

My current guess, is still, that it was a hardware issue. Maybe some electrical charge that build up somewhere where it should not be. see: Mouse pad static charge I had something similar many years ago with a computer mainboard. It would not boot anymore after some handling with it. It was just dead. Even after multiple tries. Then, trying around suddenly made it work again, although, fundamentally nothing had changed at all.

What you can try is: reboot. shutdown. disconnect power. Start up. Just to see if that error ever comes again. When I do this on my side, I cannot reproduce your error even a single time.

  1. You asked for more log output. Will do so.
  2. The "encryption key" vs "password" text will be changed in the next update.
  3. There is one thing peculiar: "Gateway startup counter 4" I bet you have restarted/rebooted more than 4 times in total. The hat will increment a counter on its onboard EEPROM every time the canique-radio-bridge is started/restarted. So even if you attach it to another raspberry, the counter will never decrement or go back to 0. Seeing this counter at only 4 means, it was not incremented often. I can say more about this tomorrow.
canique commented 1 year ago

There's a pre-release available now: canique-radio-bridge 0.8.4 You can install it, after downloading the file, by running sudo dpkg -i canique-radio-bridge_0.8.4_armhf.deb

Following things have changed

The log output looks like this now:

Mar 23 14:29:06 raspberrypi3 python[1999]: RSSI threshold -98 Mar 23 14:29:06 raspberrypi3 python[1999]: Hard resetting Gateway Hat Mar 23 14:29:06 raspberrypi3 python[1999]: [Bootloader] Mar 23 14:29:06 raspberrypi3 python[1999]: [Bootloader] Bootloader v1.1.0 Mar 23 14:29:06 raspberrypi3 python[1999]: [Bootloader] Mar 23 14:29:06 raspberrypi3 python[1999]: [Bootloader] Press d for firmware upload, r to run firmware Mar 23 14:29:06 raspberrypi3 python[1999]: Sent command 'r' (run app) to bootloader. Mar 23 14:29:06 raspberrypi3 python[1999]: [Bootloader] Mar 23 14:29:06 raspberrypi3 python[1999]: [Bootloader] Starting image. Mar 23 14:29:06 raspberrypi3 python[1999]: [GW Log] Gateway Module started up Mar 23 14:29:06 raspberrypi3 python[1999]: Starting serial interface RX... Mar 23 14:29:06 raspberrypi3 python[1999]: Starting serial interface TX... Mar 23 14:29:07 raspberrypi3 python[1999]: Connected to MQTT broker. flags 1. rc 0. props {'topic_alias_maximum': [10], 'receive_maximum': [1], 'session_expiry_interval': 1209600}. Mar 23 14:29:07 raspberrypi3 python[1999]: Subscribing to tx/# Mar 23 14:29:07 raspberrypi3 python[1999]: Subscribing to gw/248080/setSensorRadioKey/+ Mar 23 14:29:07 raspberrypi3 python[1999]: Subscribing to gw/248080/removeSensorRadioKey/+ Mar 23 14:29:07 raspberrypi3 python[1999]: Gateway Info: Mar 23 14:29:07 raspberrypi3 python[1999]: Firmware Revision: 12169 Mar 23 14:29:07 raspberrypi3 python[1999]: Unique ID: 248080 Mar 23 14:29:07 raspberrypi3 python[1999]: Hat Type: Canique Gateway Hat

...

canique commented 1 year ago

Yesterday I mentioned the Gateway startup counter being low. Reason: When you see "Waking Gateway Hat up", the Raspberry sends a command to the hat, upon which the hat will increment its counter and reply with the current counter value. Either the command almost never went through (probable), or the Hat had problems writing to its EEPROM (improbable).

So, again, this seems to have been due to UART communication problems. Like the missing "Gateway Module started up" at the beginning.

canique commented 1 year ago

Possible causes for the troubles so far:

This would explain why the problems were suddenly gone. If they had been on/off problems, occurring sometimes and sometimes not, then my guess would be a race condition in the software.

With the newest software release -at least at startup- (until "Starting serial interface RX...") a race condition is impossible. I can clearly see that all messages, right from the start of the bootloader, are received properly. In addition the Raspberry's serial interface is setup even before the radio hat is reset, even before the bootloader has even started. No chance to miss a message.

This means: If, after installing the latest release, the message "Gateway Module started up" does not appear - even if it's a single time, then this is a clear indication that there is a hardware issue or some fundamental issue with the Raspberry's UART.

canique commented 1 year ago

Other possible cause:

Overtemperature or Undervoltage, see https://github.com/raspberrypi/linux/issues/4123 Quote: "another possibility is that the CPU frequency is being capped due to over-temperature or under-voltage."

You could run tail -1000 /var/log/kern.log and look for an undervoltage warning...

it started "once" I guess power was ok then?

Not necessarily. If you have an undervoltage condition, then everything would make perfectly sense having a bad power supply as the cause. This would also explain why the 3B+ causes more troubles - because it consumes more power and is more demanding to the power supply.

Basically: the PI must not change its core frequency, otherwise the UART baud rate will be wrong, and received data will be garbage.

When I run while true; do echo $(vcgencmd measure_clock core); sleep 1; done in a second terminal I get 400000000 all the time. The important point is that this number does not change (by more than 1).

earlthesquirrel commented 1 year ago

Just to confirm, with new psi, I get frequency(1)=400000000 frequency(1)=400000000 frequency(1)=400000000 frequency(1)=400000000 frequency(1)=400000000 frequency(1)=400000000 frequency(1)=400000000 frequency(1)=400000000 frequency(1)=400000000 frequency(1)=400000000 frequency(1)=400000000 frequency(1)=400000000 frequency(1)=400000000 frequency(1)=400000000 frequency(1)=400000000 frequency(1)=400000000 frequency(1)=400000000 frequency(1)=400000000 frequency(1)=400000000 frequency(1)=400000000 frequency(1)=400000000 frequency(1)=399999000 frequency(1)=400000000 frequency(1)=400000000 frequency(1)=400000000

So I think we're all good.
I started thru updating it to match the configuration I wanted it to have (hostname, etc.). Adjusting timezone, locale, that didn't cause any issues. Changing hostname has tweaked something (thinking it's part of the MQTT setup). I'm going to try the update you posted and see if it resolves it.

canique commented 1 year ago

For the sake of clarity: Basically this issue belongs to #2

It's all part of the same problem: Broken Raspberry UART because of (most probably) undervoltage. Fix: Decent power supply.

Your output looks okay.

Another quick fix (although not proper) would have been to tell the Raspberry to have a fixed core frequency (core_freq=... in config.txt) But this would only be some sort of quick hack with a weak power supply, not a fix for the problem underneath.

I'm closing this issue.