nano33ble/test/
linear_log_test.rs

1// Licensed under the Apache License, Version 2.0 or the MIT License.
2// SPDX-License-Identifier: Apache-2.0 OR MIT
3// Copyright Tock Contributors 2022.
4
5//! Tests the log storage interface in linear mode. For testing in circular mode, see
6//! log_test.rs.
7//!
8//! The testing framework creates a non-circular log storage interface in flash and performs a
9//! series of writes and syncs to ensure that the non-circular log properly denies overly-large
10//! writes once it is full. For testing all of the general capabilities of the log storage
11//! interface, see log_test.rs.
12//!
13//! To run the test, uncomment the following line to the nano33ble boot sequence:
14//!
15//! ```rust
16//! test::linear_log_test::run(
17//!     mux_alarm,
18//!     &nrf52840_peripherals.nrf52.nvmc,
19//! );
20//! ```
21//!
22//! and use the `USER` and `RESET` buttons to manually erase the log and reboot the imix,
23//! respectively.
24
25use capsules_core::virtualizers::virtual_alarm::{MuxAlarm, VirtualMuxAlarm};
26use capsules_extra::log;
27use core::cell::Cell;
28use core::ptr::addr_of_mut;
29use kernel::debug_verbose;
30use kernel::hil::flash;
31use kernel::hil::log::{LogRead, LogReadClient, LogWrite, LogWriteClient};
32use kernel::hil::time::{Alarm, AlarmClient, ConvertTicks};
33use kernel::static_init;
34use kernel::storage_volume;
35use kernel::utilities::cells::{NumericCellExt, TakeCell};
36use kernel::ErrorCode;
37use nrf52840::{
38    nvmc::{NrfPage, Nvmc},
39    rtc::Rtc,
40};
41
42// Allocate 8 KiB volume for log storage (the nano33ble page size is 4 KiB).
43storage_volume!(LINEAR_TEST_LOG, 8);
44
45pub unsafe fn run(mux_alarm: &'static MuxAlarm<'static, Rtc>, flash_controller: &'static Nvmc) {
46    // Set up flash controller.
47    flash_controller.configure_writeable();
48    flash_controller.configure_eraseable();
49    let pagebuffer = static_init!(NrfPage, NrfPage::default());
50
51    // Create actual log storage abstraction on top of flash.
52    let log = static_init!(
53        Log,
54        log::Log::new(&LINEAR_TEST_LOG, flash_controller, pagebuffer, false)
55    );
56    flash::HasClient::set_client(flash_controller, log);
57    kernel::deferred_call::DeferredCallClient::register(log);
58
59    let alarm = static_init!(
60        VirtualMuxAlarm<'static, Rtc>,
61        VirtualMuxAlarm::new(mux_alarm)
62    );
63    alarm.setup();
64
65    // Create and run test for log storage.
66    let test = static_init!(
67        LogTest<VirtualMuxAlarm<'static, Rtc>>,
68        LogTest::new(log, &mut *addr_of_mut!(BUFFER), alarm, &TEST_OPS)
69    );
70    log.set_read_client(test);
71    log.set_append_client(test);
72    test.alarm.set_alarm_client(test);
73
74    test.run();
75}
76
77static TEST_OPS: [TestOp; 9] = [
78    TestOp::Read,
79    // Write to first page.
80    TestOp::Write(64),
81    TestOp::Write(2400),
82    // Write to next page, too large to fit on first.
83    TestOp::Write(2432),
84    // Write should fail, not enough space remaining.
85    TestOp::Write(2448),
86    // Write should succeed, enough space for a smaller entry.
87    TestOp::Write(72),
88    // Read back everything to verify and sync.
89    TestOp::Read,
90    TestOp::Sync,
91    // Write should still fail after sync.
92    TestOp::Write(2464),
93];
94
95// Buffer for reading from and writing to in the log tests.
96static mut BUFFER: [u8; 2480] = [0; 2480];
97// Time to wait in between log operations.
98const WAIT_MS: u32 = 100;
99
100// A single operation within the test.
101#[derive(Clone, Copy, PartialEq, Debug)]
102enum TestOp {
103    Read,
104    Write(usize),
105    Sync,
106}
107
108type Log = log::Log<'static, Nvmc>;
109
110struct LogTest<A: 'static + Alarm<'static>> {
111    log: &'static Log,
112    buffer: TakeCell<'static, [u8]>,
113    alarm: &'static A,
114    ops: &'static [TestOp],
115    op_index: Cell<usize>,
116}
117
118impl<A: 'static + Alarm<'static>> LogTest<A> {
119    fn new(
120        log: &'static Log,
121        buffer: &'static mut [u8],
122        alarm: &'static A,
123        ops: &'static [TestOp],
124    ) -> LogTest<A> {
125        debug_verbose!(
126            "Log recovered from flash (Start and end entry IDs: {:?} to {:?})",
127            log.log_start(),
128            log.log_end()
129        );
130
131        LogTest {
132            log,
133            buffer: TakeCell::new(buffer),
134            alarm,
135            ops,
136            op_index: Cell::new(0),
137        }
138    }
139
140    fn run(&self) {
141        if self.op_index.get() == self.ops.len() {
142            debug_verbose!("Success!")
143        } else {
144            debug_verbose!(
145                "Executing operation {} of {} - {:?}.",
146                self.op_index.get() + 1,
147                self.ops.len(),
148                self.ops[self.op_index.get()]
149            );
150            match self.ops[self.op_index.get()] {
151                TestOp::Read => self.read(),
152                TestOp::Write(length) => self.write(length),
153                TestOp::Sync => self.sync(),
154            }
155        }
156    }
157
158    fn read(&self) {
159        match self.buffer.take() {
160            Some(buffer) => {
161                // Clear buffer first to make debugging more sane.
162                for e in buffer.iter_mut() {
163                    *e = 0;
164                }
165
166                match self.log.read(buffer, buffer.len()) {
167                    Ok(()) => debug_verbose!("Dispatched asynchronous read operation."),
168                    Err((return_code, buffer)) => {
169                        self.buffer.replace(buffer);
170                        match return_code {
171                            ErrorCode::FAIL => {
172                                // No more entries, start writing again.
173                                debug_verbose!(
174                                    "READ DONE: READ OFFSET: {:?} / WRITE OFFSET: {:?}",
175                                    self.log.next_read_entry_id(),
176                                    self.log.log_end()
177                                );
178                                self.op_index.increment();
179                                self.run();
180                            }
181                            ErrorCode::BUSY => {
182                                debug_verbose!("Flash busy, waiting before reattempting read");
183                                self.wait();
184                            }
185                            _ => panic!("READ FAILED: {:?}", return_code),
186                        }
187                    }
188                }
189            }
190            None => panic!("NO BUFFER"),
191        }
192    }
193
194    fn write(&self, len: usize) {
195        self.buffer
196            .take()
197            .map(move |buffer| {
198                let expect_write_fail = self.log.log_end() + len > LINEAR_TEST_LOG.len();
199
200                // Set buffer value.
201                for i in 0..buffer.len() {
202                    buffer[i] = if i < len {
203                        len as u8
204                    } else {
205                        0
206                    };
207                }
208
209                if let Err((error, original_buffer)) = self.log.append(buffer, len) {
210                    self.buffer.replace(original_buffer);
211
212                    match error {
213                        ErrorCode::FAIL =>
214                            if expect_write_fail {
215                                debug_verbose!(
216                                    "Write failed on {} byte write, as expected",
217                                    len
218                                );
219                                self.op_index.increment();
220                                self.run();
221                            } else {
222                                panic!(
223                                    "Write failed unexpectedly on {} byte write (read entry ID: {:?}, append entry ID: {:?})",
224                                    len,
225                                    self.log.next_read_entry_id(),
226                                    self.log.log_end()
227                                );
228                            }
229                        ErrorCode::BUSY => self.wait(),
230                        _ => panic!("WRITE FAILED: {:?}", error),
231                    }
232                } else if expect_write_fail {
233                    panic!(
234                        "Write succeeded unexpectedly on {} byte write (read entry ID: {:?}, append entry ID: {:?})",
235                        len,
236                        self.log.next_read_entry_id(),
237                        self.log.log_end()
238                    );
239                }
240            })
241            .unwrap();
242    }
243
244    fn sync(&self) {
245        match self.log.sync() {
246            Ok(()) => (),
247            error => panic!("Sync failed: {:?}", error),
248        }
249    }
250
251    fn wait(&self) {
252        let delay = self.alarm.ticks_from_ms(WAIT_MS);
253        let now = self.alarm.now();
254        self.alarm.set_alarm(now, delay);
255    }
256}
257
258impl<A: Alarm<'static>> LogReadClient for LogTest<A> {
259    fn read_done(&self, buffer: &'static mut [u8], length: usize, error: Result<(), ErrorCode>) {
260        match error {
261            Ok(()) => {
262                // Verify correct value was read.
263                assert!(length > 0);
264                for i in 0..length {
265                    if buffer[i] != length as u8 {
266                        panic!(
267                            "Read incorrect value {} at index {}, expected {}",
268                            buffer[i], i, length
269                        );
270                    }
271                }
272
273                debug_verbose!("Successful read of size {}", length);
274                self.buffer.replace(buffer);
275                self.wait();
276            }
277            _ => {
278                panic!("Read failed unexpectedly!");
279            }
280        }
281    }
282
283    fn seek_done(&self, _error: Result<(), ErrorCode>) {
284        unreachable!();
285    }
286}
287
288impl<A: Alarm<'static>> LogWriteClient for LogTest<A> {
289    fn append_done(
290        &self,
291        buffer: &'static mut [u8],
292        length: usize,
293        records_lost: bool,
294        error: Result<(), ErrorCode>,
295    ) {
296        assert!(!records_lost);
297        match error {
298            Ok(()) => {
299                debug_verbose!("Write succeeded on {} byte write, as expected", length);
300
301                self.buffer.replace(buffer);
302                self.op_index.increment();
303                self.wait();
304            }
305            error => panic!("WRITE FAILED IN CALLBACK: {:?}", error),
306        }
307    }
308
309    fn sync_done(&self, error: Result<(), ErrorCode>) {
310        if error == Ok(()) {
311            debug_verbose!(
312                "SYNC DONE: READ OFFSET: {:?} / WRITE OFFSET: {:?}",
313                self.log.next_read_entry_id(),
314                self.log.log_end()
315            );
316        } else {
317            panic!("Sync failed: {:?}", error);
318        }
319
320        self.op_index.increment();
321        self.run();
322    }
323
324    fn erase_done(&self, _error: Result<(), ErrorCode>) {
325        unreachable!();
326    }
327}
328
329impl<A: Alarm<'static>> AlarmClient for LogTest<A> {
330    fn alarm(&self) {
331        self.run();
332    }
333}
nano33ble/test/linear_log_test.rs

nano33ble/test/
linear_log_test.rs
