Use of Bucket.open --ram ?

Toit

#Use of Bucket.open --ram ?

Thread channel in help

bitphlipphar 02/24/2023 07:17 PM

I will take a look first thing Monday morning if not before! Thanks

davidg238 02/24/2023 07:36 PM

thx, https://github.com/davidg238/test_bucket (To recreate issue. Always helpful to actually push)(edited)

GitHub - davidg238/test_bucket

Contribute to davidg238/test_bucket development by creating an account on GitHub.

bitphlipphar 02/25/2023 05:55 AM

I can (trivially) reproduce the issue. Will look into a fix

bitphlipphar 02/25/2023 06:09 AM

Found the problem. Pretty embarassing

bitphlipphar 02/25/2023 06:10 AM

We store the key/value mapping as a encoding.tison encoded message, but the decoder rejects messages that have extra bits at the end and I always pass it the full buffer.

bitphlipphar 02/25/2023 06:11 AM

The fix is to store the encoded message size in addition to the encoded message. Pretty simple.

bitphlipphar 02/25/2023 06:26 AM

Fix is here: https://github.com/toitlang/toit/pull/1439.

Build software better, together

GitHub is where people build software. More than 100 million people use GitHub to discover, fork, and contribute to over 330 million projects.

bitphlipphar 02/25/2023 06:26 AM

Will get this rolled out into Jaguar v1.9.2 early next week.

bitphlipphar 02/25/2023 06:29 AM

Thanks for reporting this, @davidg238!

bitphlipphar 02/25/2023 12:35 PM

Fix landed on main.

bitphlipphar 02/27/2023 08:39 PM

Fix shipped in Jaguar v1.9.3. Give it a spin, @davidg238

davidg238 02/28/2023 06:41 AM

Thx. I don't know what to tell you. Using https://github.com/davidg238/sleepy_sensor and your Makefile. The test.toit works:

rst:0x5 (DEEPSLEEP_RESET),boot:0x13 (SPI_FAST_FLASH_BOOT)
configsip: 0, SPIWP:0xee
clk_drv:0x00,q_drv:0x00,d_drv:0x00,cs0_drv:0x00,hd_drv:0x00,wp_drv:0x00
mode:DIO, clock div:2
load:0x3fff0030,len:184
load:0x40078000,len:12700
ho 0 tail 12 room 4
load:0x40080400,len:2916
entry 0x400805c4
E (53) psram: No PSRAM detected
E (53) spiram: SPI RAM supported, but not found.
[toit] INFO: starting <v2.0.0-alpha.55>
starting
.... ezSBC Feather 09c2e1345a79 started
storing {"ti": "273"}
size 3 after storing
Entering deep sleep for 15000ms
ets Jul 29 2019 12:21:46

rst:0x5 (DEEPSLEEP_RESET),boot:0x13 (SPI_FAST_FLASH_BOOT)
configsip: 0, SPIWP:0xee
clk_drv:0x00,q_drv:0x00,d_drv:0x00,cs0_drv:0x00,hd_drv:0x00,wp_drv:0x00
mode:DIO, clock div:2
load:0x3fff0030,len:184
load:0x40078000,len:12700
ho 0 tail 12 room 4
load:0x40080400,len:2916
entry 0x400805c4
E (53) psram: No PSRAM detected
E (53) spiram: SPI RAM supported, but not found.
[toit] INFO: starting <v2.0.0-alpha.55>
starting
.... ezSBC Feather 09c2e1345a79 started
storing {"ti": "288"}
size 4 after storing
data: {"ti": "243"}
data: {"ti": "258"}
data: {"ti": "273"}
data: {"ti": "288"}
buffer emptied, size now 0
Entering deep sleep for 15000ms
ets Jul 29 2019 12:21:46

GitHub - davidg238/sleepy_sensor

Contribute to davidg238/sleepy_sensor development by creating an account on GitHub.

bitphlipphar 02/28/2023 06:44 AM

That's good, no? I expect there is a follow up

davidg238 02/28/2023 06:46 AM

but when I try to run sleepy_sensor.toit, when it attempts to unload the buffer, I get an exception (then loop):

davidg238 02/28/2023 06:47 AM

(hit discord limit, apologies for delay)

davidg238 02/28/2023 06:47 AM

don't waste your time, I did something dumb, will advise tomorrow

bitphlipphar 02/28/2023 06:50 AM

Looking forward to it. For what it's worth, you don't have to store string values in the buckets, so you should be able to just store the kind of maps you're using to structure your data.

bitphlipphar 02/28/2023 07:01 AM

davidg238 02/28/2023 06:55 PM

note the "clearing RTC memory: invalid checksum". Is the following a normal boot sequence?

david@MSI-7D43:~$ jag monitor
Starting serial monitor of port '/dev/ttyUSB0' ...
ets Jul 29 2019 12:21:46

rst:0x1 (POWERON_RESET),boot:0x13 (SPI_FAST_FLASH_BOOT)
configsip: 0, SPIWP:0xee
clk_drv:0x00,q_drv:0x00,d_drv:0x00,cs0_drv:0x00,hd_drv:0x00,wp_drv:0x00
mode:DIO, clock div:2
load:0x3fff0030,len:184
load:0x40078000,len:12700
ho 0 tail 12 room 4
load:0x40080400,len:2916
entry 0x400805c4
E (586) psram: No PSRAM detected
E (586) spiram: SPI RAM supported, but not found.
[toit] INFO: starting <v2.0.0-alpha.55>
[toit] DEBUG: clearing RTC memory: invalid checksum
[wifi] DEBUG: connecting
[wifi] DEBUG: connected
[wifi] INFO: network address dynamically assigned through dhcp {ip: 192.168.0.244}
[wifi] INFO: dns server address dynamically assigned through dhcp {ip: [192.168.0.1]}
[jaguar] INFO: running Jaguar device 'hungry-egg' (id: '2a1e7668-614e-4ff0-aa36-6b047b432d52') on 'http://192.168.0.244:9000'

bitphlipphar 02/28/2023 06:55 PM

Yeah, that looks pretty normal.

bitphlipphar 02/28/2023 06:56 PM

You shouldn't see that after deep sleep.

davidg238 02/28/2023 06:56 PM

I am focussed on test2.toit in the repo , which excludes deep sleep

davidg238 02/28/2023 06:56 PM

for speed/simplicity

davidg238 02/28/2023 06:57 PM

I am getting errors like:

david@MSI-7D43:~$ jag monitor -a
Starting serial monitor of port '/dev/ttyUSB0' ...
[jaguar] INFO: program e033b5d1-6478-5145-a783-6b674c445811 started
starting
.... ezSBC Feather 09c2e1345a79 started
stored {"ti": 1197, "v": 3.0}, size now 1
stored {"ti": 1202, "v": 4.0}, size now 2
stored {"ti": 1207, "v": 3.0}, size now 3
stored {"ti": 1212, "v": 4.0}, size now 4
stored {"ti": 1217, "v": 4.0}, size now 5
stored {"ti": 1222, "v": 4.0}, size now 6

******************************************************************************
EXCEPTION error. 
WRONG_OBJECT_TYPE
  0: decode                    <sdk>/encoding/tison.toit:41:3
  1: Bucket.get                <sdk>/system/storage.toit:84:29
  2: Bucket.get                <sdk>/system/storage.toit:73:12
  3: BufferStore.get_buff_     admin.toit:24:22
  4: BufferStore.size          admin.toit:37:12
  5: main                      test2.toit:45:19
******************************************************************************

[jaguar] ERROR: program e033b5d1-6478-5145-a783-6b674c445811 stopped - exit code 1

davidg238 02/28/2023 06:57 PM

I thought maybe it was to do with floating point battery voltage, formatting the float ... so I switched to a random number

davidg238 02/28/2023 06:57 PM

still unpredictable

bitphlipphar 02/28/2023 06:58 PM

I can take a look in 20 minutes or so!

davidg238 02/28/2023 06:58 PM

again, will keep working to isolate for you, just an fyi

davidg238 02/28/2023 07:00 PM

there is a clear.toit to re-initialize the buffer?

bitphlipphar 02/28/2023 07:00 PM

List.from get_buff looks odd.

bitphlipphar 02/28/2023 07:01 PM

Is that to copy it?

davidg238 02/28/2023 07:01 PM

that was the issue the tison delivered non-resizable Lists

bitphlipphar 02/28/2023 07:02 PM

Ah. Got it.

davidg238 02/28/2023 07:03 PM

(think I got the evaluation paths right, so that is the only place it is needed)

davidg238 02/28/2023 07:07 PM

if you look at the first "test" in test2.toit, if I uncomment that + change loop to >=3, it work fine:

[jaguar] INFO: program cdca5a03-c7ca-52f0-88bf-e727749a4e0c started
starting
.... ezSBC Feather 09c2e1345a79 started
stored {"ti": 2077, "v": 3}, size now 1
stored {"ti": 2082, "v": 3}, size now 2
stored {"ti": 2087, "v": 4}, size now 3
buffer full, emptying
data: {"ti": 2077, "v": 3}
data: {"ti": 2082, "v": 3}
data: {"ti": 2087, "v": 4}
buffer emptied, size now 0
stored {"ti": 2092, "v": 3}, size now 1
stored {"ti": 2097, "v": 3}, size now 2
stored {"ti": 2102, "v": 3}, size now 3
buffer full, emptying
data: {"ti": 2092, "v": 3}
data: {"ti": 2097, "v": 3}
data: {"ti": 2102, "v": 3}
buffer emptied, size now 0

davidg238 02/28/2023 07:08 PM

and there is no way 10 iterations is exhausting RTC memory

bitphlipphar 02/28/2023 07:09 PM

No, it looks odd. You can do the tison encoding without storing in RTC memory and then we can look at the sizes.

davidg238 02/28/2023 07:09 PM

... so just changing to 10 iterations, blew out:

[jaguar] INFO: program bbd19ddf-d50c-543e-9731-fc0be3e86827 started
starting
.... ezSBC Feather 09c2e1345a79 started
stored {"ti": 2250, "v": 4}, size now 1
stored {"ti": 2255, "v": 3}, size now 2
stored {"ti": 2260, "v": 3}, size now 3
stored {"ti": 2265, "v": 4}, size now 4
stored {"ti": 2270, "v": 3}, size now 5
stored {"ti": 2275, "v": 4}, size now 6

******************************************************************************
EXCEPTION error. 
WRONG_OBJECT_TYPE
  0: decode                    <sdk>/encoding/tison.toit:41:3
  1: Bucket.get                <sdk>/system/storage.toit:84:29
  2: Bucket.get                <sdk>/system/storage.toit:73:12
  3: BufferStore.get_buff_     admin.toit:24:22
  4: BufferStore.size          admin.toit:37:12
  5: main                      test2.toit:45:19
******************************************************************************

[jaguar] ERROR: program bbd19ddf-d50c-543e-9731-fc0be3e86827 stopped - exit code 1

bitphlipphar 02/28/2023 07:09 PM

It feels like a platform bug.

davidg238 02/28/2023 07:11 PM

will make some direct tison encoding tests, as you suggest

davidg238 02/28/2023 07:38 PM

... maybe it is in the remove_first, since I am storing a ListSlice_ ... some flakiness ?
I found this when I recoded using a List as a buffer, the first loop of 10 worked, but on the 11th add I got:

buffer emptied, size now 0

******************************************************************************
EXCEPTION error. 
SLICE_CANNOT_CHANGE_SIZE
  0: ListSlice_.resize         <sdk>/core/collections.toit:1792:5
  1: List.add                  <sdk>/core/collections.toit:289:7
  2: main                      tison.toit:34:15
******************************************************************************

davidg238 02/28/2023 07:39 PM

if my_buffer.size >= 10:
      print "buffer full, emptying"
      entry := null
      while my_buffer.size > 0:
        entry = my_buffer.first
        print "data: $entry"
        my_buffer = List.from my_buffer[1..]
      print "buffer emptied, size now $my_buffer.size"

in a test case seems more stable

bitphlipphar 02/28/2023 07:39 PM

Yeah. I thought about that too. You can try doing buffer[1..].copy.

bitphlipphar 02/28/2023 07:42 PM

Let me look into this.

bitphlipphar 02/28/2023 07:57 PM

I can reproduce on my Mac.

davidg238 02/28/2023 07:58 PM

fwiw, v1.0.5 of the repo has the buffer[1..].copy change. So you can reproduce an issue, outside my code?

davidg238 02/28/2023 07:58 PM

small numbers of iterations (5) "seem" to work ... 10, no go

bitphlipphar 02/28/2023 08:10 PM

Yeah. I know what the problem is now

bitphlipphar 02/28/2023 08:10 PM

It's pretty weeeeeiiiiirrrrd.

bitphlipphar 02/28/2023 08:11 PM

But totally reproducible.

bitphlipphar 02/28/2023 08:11 PM

And very much fixable.

bitphlipphar 02/28/2023 08:13 PM

When we send byte arrays across the messaging boundary, we sometimes steal the memory and transfer it without copying. That does mean that we end up dropping the cached byte arrays service side, which means that they turn up as empty arrays (non-decodeable) after that.

davidg238 02/28/2023 08:22 PM

ah, ok ... np, none of this is urgent. I was just updating an article on power-saving. Can wait til next release

davidg238 02/28/2023 08:23 PM

thx for your time

bitphlipphar 02/28/2023 08:31 PM

Thank you for the report! It is a really easy fix, but I just need to think a bit about how to make it efficient.

bitphlipphar 03/01/2023 12:46 PM

I've improved the testing and fixed the issue you were bitten by in Jaguar v1.9.4. I hope things work better for you with the latest bits

davidg238 03/02/2023 08:30 PM

I am using flash for testing now, I cannot get --ram to retain values between deep_sleep (using LiPo backed ESPs). This is the simplest example I could think of, to reproduce:

import system.storage
import esp32

// with ram it fails, flash it works
bucket := storage.Bucket.open --ram "/admin"

main:

  list := bucket.get "mail"  --if_absent= (: bucket["mail"] = [ ])
  
/* the alternative loop, not using deep sleep, works for ram and flash
  5.repeat:
    print "list  $bucket["mail"]"
    add Time.now.s_since_epoch
    sleep --ms= 5_000
*/
  print "list  $bucket["mail"]"
  add Time.now.s_since_epoch
  esp32.deep_sleep (Duration --s=10)

add entry/any -> none:
    buffer := List.from bucket["mail"]
    buffer.add entry
    bucket["mail"] = buffer

bitphlipphar 03/02/2023 08:58 PM

Can you show me the message you get on the serial output when it boots after the deep sleep?

bitphlipphar 03/02/2023 09:02 PM

I am a bit surprised that this is so hard to get to work, but we will get there. We hope to spin up more on-device testing (maybe emulated using qemu) to catch these issues quicker.

davidg238 03/02/2023 09:09 PM

david@MSI-7D43:~$ jag monitor -a
Starting serial monitor of port '/dev/ttyUSB0' ...
[wifi] INFO: network address dynamically assigned through dhcp {ip: 192.168.0.240}
[wifi] INFO: dns server address dynamically assigned through dhcp {ip: [192.168.0.1]}
[jaguar] INFO: running Jaguar device 'dev04' (id: '1e74b0ec-6156-4672-b7ba-a53ba5c8b18c') on 'http://192.168.0.240:9000'
[jaguar] INFO: denied request, header: 'X-Jaguar-Device-ID' was '288f65b5-7b34-450f-938e-04f19e99029d' not '1e74b0ec-6156-4672-b7ba-a53ba5c8b18c'
[jaguar] INFO: container 'sleep2' installed and started
list  []
Entering deep sleep for 10000ms
ets Jul 29 2019 12:21:46

rst:0x5 (DEEPSLEEP_RESET),boot:0x13 (SPI_FAST_FLASH_BOOT)
configsip: 0, SPIWP:0xee
clk_drv:0x00,q_drv:0x00,d_drv:0x00,cs0_drv:0x00,hd_drv:0x00,wp_drv:0x00
mode:DIO, clock div:2
load:0x3fff0030,len:184
load:0x40078000,len:12700
ho 0 tail 12 room 4
load:0x40080400,len:2916
entry 0x400805c4
E (53) psram: No PSRAM detected
E (53) spiram: SPI RAM supported, but not found.
[toit] INFO: starting <v2.0.0-alpha.58>
[jaguar] INFO: container 'sleep2' started
list  []
Entering deep sleep for 10000ms
ets Jul 29 2019 12:21:46

rst:0x5 (DEEPSLEEP_RESET),boot:0x13 (SPI_FAST_FLASH_BOOT)
configsip: 0, SPIWP:0xee
clk_drv:0x00,q_drv:0x00,d_drv:0x00,cs0_drv:0x00,hd_drv:0x00,wp_drv:0x00
mode:DIO, clock div:2
load:0x3fff0030,len:184
load:0x40078000,len:12700
ho 0 tail 12 room 4
load:0x40080400,len:2916
entry 0x400805c4
E (53) psram: No PSRAM detected
E (53) spiram: SPI RAM supported, but not found.
[toit] INFO: starting <v2.0.0-alpha.58>
[jaguar] INFO: container 'sleep2' started
list  []
Entering deep sleep for 10000ms

bitphlipphar 03/02/2023 09:10 PM

davidg238 03/02/2023 09:13 PM

just swapping --flash yields:

david@MSI-7D43:~$ jag monitor -a
Starting serial monitor of port '/dev/ttyUSB0' ...
[jaguar] INFO: container 'sleep2' installed and started
list  []
Entering deep sleep for 10000ms
ets Jul 29 2019 12:21:46

rst:0x5 (DEEPSLEEP_RESET),boot:0x13 (SPI_FAST_FLASH_BOOT)
configsip: 0, SPIWP:0xee
clk_drv:0x00,q_drv:0x00,d_drv:0x00,cs0_drv:0x00,hd_drv:0x00,wp_drv:0x00
mode:DIO, clock div:2
load:0x3fff0030,len:184
load:0x40078000,len:12700
ho 0 tail 12 room 4
load:0x40080400,len:2916
entry 0x400805c4
E (53) psram: No PSRAM detected
E (53) spiram: SPI RAM supported, but not found.
[toit] INFO: starting <v2.0.0-alpha.58>
[jaguar] INFO: container 'sleep2' started
list  [86]
Entering deep sleep for 10000ms
ets Jul 29 2019 12:21:46

rst:0x5 (DEEPSLEEP_RESET),boot:0x13 (SPI_FAST_FLASH_BOOT)
configsip: 0, SPIWP:0xee
clk_drv:0x00,q_drv:0x00,d_drv:0x00,cs0_drv:0x00,hd_drv:0x00,wp_drv:0x00
mode:DIO, clock div:2
load:0x3fff0030,len:184
load:0x40078000,len:12700
ho 0 tail 12 room 4
load:0x40080400,len:2916
entry 0x400805c4
E (53) psram: No PSRAM detected
E (53) spiram: SPI RAM supported, but not found.
[toit] INFO: starting <v2.0.0-alpha.58>
[jaguar] INFO: container 'sleep2' started
list  [86, 97]
Entering deep sleep for 10000ms
ets Jul 29 2019 12:21:46

rst:0x5 (DEEPSLEEP_RESET),boot:0x13 (SPI_FAST_FLASH_BOOT)
configsip: 0, SPIWP:0xee
clk_drv:0x00,q_drv:0x00,d_drv:0x00,cs0_drv:0x00,hd_drv:0x00,wp_drv:0x00
mode:DIO, clock div:2
load:0x3fff0030,len:184
load:0x40078000,len:12700
ho 0 tail 12 room 4
load:0x40080400,len:2916
entry 0x400805c4
E (53) psram: No PSRAM detected
E (53) spiram: SPI RAM supported, but not found.
[toit] INFO: starting <v2.0.0-alpha.58>
[jaguar] INFO: container 'sleep2' started
list  [86, 97, 107]
Entering deep sleep for 10000ms

bitphlipphar 03/03/2023 05:24 AM

Ugh. That was entirely my fault. We ended up using the non-RTC backed implementation also on the ESP32 due to a mistyped C++ define: https://github.com/toitlang/toit/pull/1462.

Build software better, together

GitHub is where people build software. More than 100 million people use GitHub to discover, fork, and contribute to over 330 million projects.

bitphlipphar 03/03/2023 05:25 AM

I found this version a bit easier to test with Jaguar, because it sometimes stops the deep sleep and lets Jaguar back in control. Also notice the use of bucket.get "mail" --init=: [] which is a nice pattern for buckets and maps.

import system.storage
import esp32

bucket := storage.Bucket.open --ram "/admin"

main:
  list := bucket.get "mail" --init=: []
  print "list = $bucket["mail"]"
  add Time.now.s_since_epoch
  if (random 100) < 90: esp32.deep_sleep (Duration --s=1)

add entry/any -> none:
  buffer := List.from bucket["mail"]
  buffer.add entry
  bucket["mail"] = buffer

(edited)

bitphlipphar 03/03/2023 05:54 AM

Will send out a new release within a few hours with the (somewhat embarrasing) fix.

davidg238 03/03/2023 05:54 AM

thx. saw the --init, the --ifAbsent has been so common you don't have to think about it. will use

davidg238 03/03/2023 05:55 AM

pls, there is 3 of you ... the amount of code you folk move is amazing

bitphlipphar 03/03/2023 07:31 AM

Fix is included in Jaguar v1.9.6 which should be available shortly.

bitphlipphar 03/03/2023 07:40 AM

It is out. Fingers really crossed

davidg238 03/03/2023 04:09 PM

works for me !! thx for grinding that. and yes random is a clever alternative to a button in many test situations

bitphlipphar 03/03/2023 04:11 PM

Finally. Thank you for reporting back

davidg238 03/03/2023 09:17 PM

there does appear to be an issue the very first time after flashing, only in --ram. Until you write to the slot explicitly, when you read it, you get null. Can't see why the Bucket --init or --if_absent code is not triggered. Take a look at the attached to reproduce, see if it makes sense.

bitphlipphar 03/03/2023 09:20 PM

Will do!

bitphlipphar 03/03/2023 09:22 PM

Isn't it just because 'List.from null' isn't legal?

bitphlipphar 03/03/2023 09:23 PM

I guess you're saying that init should kick in.

davidg238 03/03/2023 09:24 PM

yeah, I can't see why the init does not kick in. thx for looking(edited)

davidg238 03/03/2023 09:25 PM

yet, specifically after you first flash, it happens

bitphlipphar 03/03/2023 09:26 PM

Will try to reproduce and fix! Thanks

bitphlipphar 03/04/2023 05:59 AM

FWIW, list := bucket.get "mail" --init= (: bucket["mail"] = []) should be list := bucket.get "mail" --init=(: [])

bitphlipphar 03/04/2023 05:59 AM

(or just list := bucket.get "mail" --init=: [])

bitphlipphar 03/04/2023 06:02 AM

Oh, I think that's the problem.

davidg238 03/04/2023 06:11 AM

let me retry ... does not explain diff behavior ram & flash

bitphlipphar 03/04/2023 06:12 AM

The bug is that the []= operator doesn't return the value. It returns null.

bitphlipphar 03/04/2023 06:13 AM

(also for flash)

bitphlipphar 03/04/2023 06:13 AM

But maybe you pretty much always have something in flash left over.

bitphlipphar 03/04/2023 06:13 AM

I'll fix the bug.

bitphlipphar 03/04/2023 06:13 AM

So you do initialize the bucket, but the return value is null on the first run.

davidg238 03/04/2023 06:15 AM

... you mean when I reflashed, maybe there was "enough" leftover in flash, to cause different behavior than ram

davidg238 03/04/2023 06:15 AM

bitphlipphar 03/04/2023 06:18 AM

It is the same bug in both ram and flash (and it is one line fix), so it should fail for the --flash case too if you start with an empty flash.(edited)

davidg238 03/04/2023 06:20 AM

(see my bug, and the bug in []=. was just trying to understand the observed difference, but without a raw memory clear function, not possible to user test. np, likely enough)

bitphlipphar 03/04/2023 06:23 AM

You can remove a key from your bucket from another program and try again?

bitphlipphar 03/04/2023 06:23 AM

https://github.com/toitlang/toit/pull/1465

Fix storage.Bucket.[]= return value by kasperl · Pull Request #1465...

davidg238 03/04/2023 06:24 AM

oh remove ... ok

bitphlipphar 03/04/2023 06:41 AM

So my conclusion is that for now the "workaround" is to use --init=: [] and then the next release will fix it so the original code using --if_absent also works as expected.

davidg238 03/04/2023 06:51 AM

yeah. sorry for the buggy report, but serendipitously it found the []= bug .. ok.

bitphlipphar 03/04/2023 06:56 AM

Yeah, it is pretty awesome. Thank you again!

bitphlipphar 03/06/2023 05:49 AM

Jaguar v1.9.7 is out with a fix for the []= issue.

98 messages in total