[Rust] String standard qui ne veut pas se réallouer au delà de 1 ko

Bonjour,

Si je vous écris c’est que cela fait plusieurs jours que je bloque sur un problème en Rust que je n’explique pas. Je n’ai pas une grande expérience en Rust, je suis plutôt à l’aise avec le C et C++. Ce projet est justement pour apprendre à m’en servir.

Le code source en entier est disponible ici. Je vais isoler la partie qui nous intéresse mais je pense que le contexte peut compter. L’archive du code source contient aussi une sortie de valgrind, au cas oùe.

Pour résumer, le logiciel récupère les données d’un glucomètre. On lui envoie une commande via USB (via le protocole Hid, j’utilise la bibliothèque hidapi pour ça) et je récupère en gros la sortie qui est un CSV géant de plusieurs milliers de lignes. L’appareil renvoie environ 50 octets par ligne (et donc par opération de lecture) et je dois boucler pour récupérer l’ensemble des valeurs. Une somme de contrôle finale juste après la dernière ligne permet de s’assurer que l’ensemble des données a bien été lu.

Globalement j’ai une fonction qui a une chaine de caractères standards en Rust qui accumule ces données ligne par ligne jusqu’à la fin de la transmission.

Là où ça se complique, c’est que cette chaine qui augmente progressivement par réallocation automatique (comme spécifié par la doc) génère une erreur mémoire quand sa capacité doit dépasser 1024 octets. C’est toujours autour de cette valeur qui fait pivot entre le bon et le mauvais comportement.

La sortie est celle-ci :

Reponse len: 49
Content capacity: 744
Content len: 721
Response: xxxxxxxxxxxxxxxxxxxxxx (49 octets)

Reponse len: 48
malloc_consolidate(): unaligned fastbin chunk detected
fish: Job 1, 'cargo run' terminated by signal SIGABRT (Abandon)

La valeur de la réponse a été caviardée, confidentialité oblige. Ce n’est pas important si ce n’est que c’est une chaine de caractère de 49 octets.

La sortie de GDB est :

(gdb) bt
#0  0x00007ffff6d73292 in raise () at /lib64/libc.so.6
#1  0x00007ffff6d5c8a4 in abort () at /lib64/libc.so.6
#2  0x00007ffff6db5cd7 in __libc_message () at /lib64/libc.so.6
#3  0x00007ffff6dbd94c in annobin_top_check.start () at /lib64/libc.so.6
#4  0x00007ffff6dbe9ec in malloc_consolidate () at /lib64/libc.so.6
#5  0x00007ffff6dc08b0 in _int_malloc () at /lib64/libc.so.6
#6  0x00007ffff6dc1b3a in _int_realloc () at /lib64/libc.so.6
#7  0x00007ffff6dc2f56 in realloc () at /lib64/libc.so.6
#8  0x00005555556374dd in alloc::alloc::realloc (ptr=0x55555572d1a0, layout=..., new_size=1488) at /builddir/build/BUILD/rustc-1.50.0-src/library/alloc/src/alloc.rs:122
#9  0x00005555556371bd in alloc::alloc::Global::grow_impl (self=0x7fffffffd398, ptr=..., old_layout=..., new_layout=..., zeroed=false) at /builddir/build/BUILD/rustc-1.50.0-src/library/alloc/src/alloc.rs:198
#10 0x0000555555637934 in alloc::alloc::{{impl}}::grow (self=0x7fffffffd398, ptr=..., old_layout=..., new_layout=...) at /builddir/build/BUILD/rustc-1.50.0-src/library/alloc/src/alloc.rs:251
#11 0x000055555563240d in alloc::raw_vec::finish_grow<alloc::alloc::Global> (new_layout=..., current_memory=..., alloc=0x7fffffffd398) at /builddir/build/BUILD/rustc-1.50.0-src/library/alloc/src/raw_vec.rs:487
#12 0x00005555556329a7 in alloc::raw_vec::RawVec<u8, alloc::alloc::Global>::grow_amortized<u8,alloc::alloc::Global> (self=0x7fffffffd398, len=721, additional=48) at /builddir/build/BUILD/rustc-1.50.0-src/library/alloc/src/raw_vec.rs:422
#13 0x00005555556325b4 in alloc::raw_vec::RawVec<u8, alloc::alloc::Global>::try_reserve<u8,alloc::alloc::Global> (self=0x7fffffffd398, len=721, additional=48) at /builddir/build/BUILD/rustc-1.50.0-src/library/alloc/src/raw_vec.rs:311
#14 0x0000555555632b43 in alloc::raw_vec::RawVec<u8, alloc::alloc::Global>::reserve<u8,alloc::alloc::Global> (self=0x7fffffffd398, len=721, additional=48) at /builddir/build/BUILD/rustc-1.50.0-src/library/alloc/src/raw_vec.rs:305
#15 0x0000555555636cb9 in alloc::vec::Vec<u8, alloc::alloc::Global>::reserve<u8,alloc::alloc::Global> (self=0x7fffffffd398, additional=48) at /builddir/build/BUILD/rustc-1.50.0-src/library/alloc/src/vec.rs:697
#16 0x0000555555636ab3 in alloc::vec::Vec<u8, alloc::alloc::Global>::append_elements<u8,alloc::alloc::Global> (self=0x7fffffffd398, other=...) at /builddir/build/BUILD/rustc-1.50.0-src/library/alloc/src/vec.rs:1469
#17 0x00005555556367ef in alloc::vec::{{impl}}::spec_extend<u8,alloc::alloc::Global> (self=0x7fffffffd398, iterator=...) at /builddir/build/BUILD/rustc-1.50.0-src/library/alloc/src/vec.rs:2606
#18 0x0000555555636b73 in alloc::vec::Vec<u8, alloc::alloc::Global>::extend_from_slice<u8,alloc::alloc::Global> (self=0x7fffffffd398, other=...) at /builddir/build/BUILD/rustc-1.50.0-src/library/alloc/src/vec.rs:1807
#19 0x000055555558cd45 in alloc::string::String::push_str (self=0x7fffffffd398, string=...) at /builddir/build/BUILD/rustc-1.50.0-src/library/alloc/src/string.rs:821
#20 0x000055555558d127 in alloc::string::{{impl}}::add_assign (self=0x7fffffffd398, other=...) at /builddir/build/BUILD/rustc-1.50.0-src/library/alloc/src/string.rs:2023
#21 0x000055555557414a in glucoviewer::drivers::freestyle::Freestyle::send_command_txt (self=0x555555720fa0, command=...) at /home/Renault/Programmation/Glycémie/glucoviewer/src/drivers/freestyle.rs:281
#22 0x0000555555574431 in glucoviewer::drivers::freestyle::Freestyle::get_multi_records (self=0x555555720fa0, command=...) at /home/Renault/Programmation/Glycémie/glucoviewer/src/drivers/freestyle.rs:299
#23 0x0000555555575ef0 in glucoviewer::drivers::freestyle::{{impl}}::read (self=0x555555720fa0) at /home/Renault/Programmation/Glycémie/glucoviewer/src/drivers/freestyle.rs:520
#24 0x00005555555927f3 in glucoviewer::main () at /home/Renault/Programmation/Glycémie/glucoviewer/src/main.rs:50

Ce qui correspond à la fonction suivante :

    fn send_command_txt(&self, command: &[u8]) -> Result<String, String> {
        let mut content = String::new();

        match self.send_command(self.request_id, command) {
            Ok(_ret) => (),
            Err(_err) => return Err(String::new()),
        }

        loop {
            let message = self.read_response();
            let response = String::from_utf8(message.payload).unwrap();

            if message.id != self.reply_id {
                return Err(String::from("Wrong message id as reply"));
            }

            println!("Content capacity: {}", content.capacity());
            println!("Content len: {}", content.len());
            println!("Response: {}", response);
            println!("Reponse len: {}", response.len());
            content += &response;

            if Response::message_complete(&response) {
                break;
            }
        }

        let response = Response::new(content);

        if !response.status || !response.verify_checksum() {
            return Err(String::from("Invalid response"));
        }

        // Remove '\r\n' sequence at the end of the message
        Ok(response.message.trim().to_string())
    }

Plus exactement à la ligne content += &response;

Par ailleurs si je remplace l’initialisation de content par String:with_capacity(1024 * 2) j’obtiens le même résultat mais au niveau de la définition de cette variable et non plus à la concaténation comme l’indique GDB :

(gdb) bt
#0  0x00007ffff6d73292 in raise () at /lib64/libc.so.6
#1  0x00007ffff6d5c8a4 in abort () at /lib64/libc.so.6
#2  0x00007ffff6db5cd7 in __libc_message () at /lib64/libc.so.6
#3  0x00007ffff6dbd94c in annobin_top_check.start () at /lib64/libc.so.6
#4  0x00007ffff6dbe9ec in malloc_consolidate () at /lib64/libc.so.6
#5  0x00007ffff6dc08b0 in _int_malloc () at /lib64/libc.so.6
#6  0x00007ffff6dc2541 in malloc () at /lib64/libc.so.6
#7  0x00005555555e68ec in alloc::alloc::alloc (layout=...) at /builddir/build/BUILD/rustc-1.50.0-src/library/alloc/src/alloc.rs:86
#8  0x00005555555e69aa in alloc::alloc::Global::alloc_impl (self=0x7fffffffd158, layout=..., zeroed=false) at /builddir/build/BUILD/rustc-1.50.0-src/library/alloc/src/alloc.rs:166
#9  0x00005555555e6d0a in alloc::alloc::{{impl}}::allocate (self=0x7fffffffd158, layout=...) at /builddir/build/BUILD/rustc-1.50.0-src/library/alloc/src/alloc.rs:226
#10 0x00005555555e1fd0 in alloc::raw_vec::RawVec<u8, alloc::alloc::Global>::allocate_in<u8,alloc::alloc::Global> (capacity=2048, init=alloc::raw_vec::AllocInit::Uninitialized, alloc=...)
    at /builddir/build/BUILD/rustc-1.50.0-src/library/alloc/src/raw_vec.rs:188
#11 0x00005555555e407d in alloc::raw_vec::RawVec<u8, alloc::alloc::Global>::with_capacity_in<u8,alloc::alloc::Global> (capacity=2048, alloc=...) at /builddir/build/BUILD/rustc-1.50.0-src/library/alloc/src/raw_vec.rs:129
#12 0x00005555555e51cf in alloc::vec::Vec<u8, alloc::alloc::Global>::with_capacity_in<u8,alloc::alloc::Global> (capacity=2048, alloc=...) at /builddir/build/BUILD/rustc-1.50.0-src/library/alloc/src/vec.rs:498
#13 0x00005555555e4b66 in alloc::vec::Vec<u8, alloc::alloc::Global>::with_capacity<u8> (capacity=2048) at /builddir/build/BUILD/rustc-1.50.0-src/library/alloc/src/vec.rs:364
#14 0x000055555558cbc4 in alloc::string::String::with_capacity (capacity=2048) at /builddir/build/BUILD/rustc-1.50.0-src/library/alloc/src/string.rs:408
#15 0x0000555555573cb3 in glucoviewer::drivers::freestyle::Freestyle::send_command_txt (self=0x555555721fa0, command=...) at /home/Renault/Programmation/Glycémie/glucoviewer/src/drivers/freestyle.rs:262
#16 0x0000555555574441 in glucoviewer::drivers::freestyle::Freestyle::get_multi_records (self=0x555555721fa0, command=...) at /home/Renault/Programmation/Glycémie/glucoviewer/src/drivers/freestyle.rs:299
#17 0x0000555555575f00 in glucoviewer::drivers::freestyle::{{impl}}::read (self=0x555555721fa0) at /home/Renault/Programmation/Glycémie/glucoviewer/src/drivers/freestyle.rs:520
#18 0x0000555555592853 in glucoviewer::main () at /home/Renault/Programmation/Glycémie/glucoviewer/src/main.rs:50

Par contre, si j’utilise valgrind pour m’aider, le programme se déroule parfaitement. Et je ne trouve rien de pertinent dans sa sortie. Je me demande si cela n’est pas lié au fait que justement son allocateur mémoire est différent et qu’on ne tombe pas dans ce cas, et de fait ne trouve rien de suspect.

J’utilise Rust 1.50 sur Fedora 34. J’ai essayé au cas où sur une Ubuntu 20.10, même phénomène.

Ne vous préoccupez pas du code sur la partie graphique qui est en travaux, il n’est pas exécuté dans le cas qui m’intéresse.

De ce que j’ai lu sur ce genre d’erreurs, cela peut arriver en C++ quand une allocation mémoire mal faite modifie la mémoire interne d’un objet type std::string qui met en branle son fonctionnement. Mais Rust devrait détecter ce genre de cas, et malgré une vérification de ma part je ne vois rien en ce sens. Les avertissements qui me restent de Rust sont des variables non utilisées ou des valeurs de retour non utilisées, mais rien de bien méchant dans mon cas.

Merci d’avance, si jamais vous avez une idée d’où ça pourrait venir je suis preneur. Si vous trouvez des choses choquantes dans mon code, dîtes-le moi aussi, je suis preneur de critiques pour progresser en Rust.

EDIT : discuter de ce problème avec mon canard en plastique, ma fille et un ami n’a rien donné !

Est-ce que le problème se manifeste si tu compiles en debug et en release ?

C’est vrai que je suis toujours en mode debug.

Je viens d’essayer en release, j’ai une erreur de segmentation à l’ouverture du périphérique carrément :

(gdb) bt
#0  0x0000555555584551 in hidapi::HidApi::open ()
#1  0x000055555556d967 in glucoviewer::drivers::HidGlucometer::open ()
#2  0x0000555555576830 in <glucoviewer::drivers::freestyle::Freestyle as glucoviewer::drivers::Glucometer>::open ()
#3  0x000055555557ab3a in glucoviewer::main ()
#4  0x000055555556c533 in std::sys_common::backtrace::__rust_begin_short_backtrace ()
#5  0x000055555556c549 in _ZN3std2rt10lang_start28_$u7b$$u7b$closure$u7d$$u7d$17h337ebedbdf3935b7E.llvm.17090624802015874820 ()
#6  0x0000555555614db7 in std::rt::lang_start_internal ()
#7  0x000055555557b662 in main ()

Donc un peu avant. Valgrind trouve aussi cette zone suspecte mais je ne trouve pas en quoi, ni le compilateur de Rust…

Et si tu changes d’allocateur (avec #[global_allocator], pour par exemple jemallocator) ?

Je viens d’essayer en debug… et ça marche bien ! Mais en release j’ai la même erreur qu’avec l’allocateur par défaut. Peut être que finalement l’erreur vient de là ?

Merci pour tes suggestions, je vais essayer de les mettre en œuvre.

C’est une bibliothèque libre disponible ici, les bouts unsafe semblent minimes. Après il y a la bibliothèque C sous adjacente évidemment, elle ne sert que d’interface.

Je vais creuser la question, merci pour les pistes.

Je crois avoir trouvé !

Le soucis est que l’objet Hidapi est un sorte de singleton que je ne pouvais pas copier. Du coup quand un pilote compatible était trouvé, lors du déroulement de la liste des périphériques qui dépendait de lui, je lançais la création du pilote avec un pointeur nu de Hidapi. Réflexe à la C c’est mal, je le sais. Et la fameuse fonction hidapi::HidApi::open() s’en servait et était à cause de cela unsafe.

Du coup je contourne le problème en quittant la boucle du listing des périphériques, pour que hidapi puisse être possédé par le pilote du périphérique. En mémorisant le pilote trouvé, je peux lui passer sans encombre cet objet.

Le petit différentiel du correctif :

@@ -4,7 +4,7 @@
 
 use hidapi::HidApi;
 
-type HidCallback = fn(&hidapi::HidApi) -> Box<dyn Glucometer>;
+type HidCallback = fn(hidapi::HidApi) -> Box<dyn Glucometer>;
 
 struct DriverLookup {
    info: DeviceInfo,
@@ -48,13 +48,22 @@
 
    drivers_lookup.push(DriverLookup { info: Freestyle::info(), callback: Freestyle::new });
 
+   let mut driver = drivers_lookup.first().unwrap();
+   let mut found = false;
+
    for device_info in hidapi.device_list() {
        for drv in &drivers_lookup {
            if hid_matches(device_info, &drv.info) {
-               return Some((drv.callback)(&hidapi));
+               driver = drv;
+               found = true;
+               break;
            }
        }
    }
 
+   if found {
+       return Some((driver.callback)(hidapi));
+   }
+
    None
 }
diff '--color=auto' -ru "/home/Renault/T\303\251l\303\251chargements/glucoviewer/src/drivers/freestyle.rs" src/drivers/freestyle.rs
--- "/home/Renault/T\303\251l\303\251chargements/glucoviewer/src/drivers/freestyle.rs"  2021-03-16 01:59:40.029477000 +0100
+++ src/drivers/freestyle.rs    2021-03-17 01:37:10.226828233 +0100
@@ -173,7 +173,7 @@
 }
 
 impl Freestyle {
-   pub fn new(api: &hidapi::HidApi) -> Box<dyn Glucometer> {
+   pub fn new(api: hidapi::HidApi) -> Box<dyn Glucometer> {
        let mut common_map = HashMap::new();
        let mut time_map = HashMap::new();
        let mut history_map = HashMap::new();
diff '--color=auto' -ru "/home/Renault/T\303\251l\303\251chargements/glucoviewer/src/drivers/mod.rs" src/drivers/mod.rs
--- "/home/Renault/T\303\251l\303\251chargements/glucoviewer/src/drivers/mod.rs"    2021-03-16 00:45:41.338865000 +0100
+++ src/drivers/mod.rs  2021-03-17 01:25:56.721109076 +0100
@@ -33,12 +33,12 @@
    name: String,
    vendor_id: u16,
    product_id: u16,
-   hidapi: * const hidapi::HidApi,
+   hidapi: hidapi::HidApi,
    device: Option<hidapi::HidDevice>,
 }
 
 impl HidGlucometer {
-   pub fn new(api: &HidApi, name: String, vendor_id: u16, product_id: u16) -> Self {
+   pub fn new(api: HidApi, name: String, vendor_id: u16, product_id: u16) -> Self {
        println!("Found Hid glucometer {} with id 0x{:X?}:0x{:X?}", name, vendor_id, product_id);
 
        Self {
@@ -64,15 +64,13 @@
    }
 
    pub fn open(&mut self) -> Result<String, io::Error> {
-       unsafe {
-           match (*self.hidapi).open(self.vendor_id, self.product_id) {
-               Ok(dev) => {
-                   dev.set_blocking_mode(true);
-                   self.device = Some(dev);
-                   Ok(String::from("HID device openned"))
-               },
-               Err(_err) => Err(io::Error::new(io::ErrorKind::NotFound, "Device not opened")),
-           }
+       match self.hidapi.open(self.vendor_id, self.product_id) {
+           Ok(dev) => {
+               dev.set_blocking_mode(true);
+               self.device = Some(dev);
+               Ok(String::from("HID device openned"))
+           },
+           Err(_err) => Err(io::Error::new(io::ErrorKind::NotFound, "Device not opened")),
        }
    }

Je me sens mieux.

Cependant, je ne comprends pas trop en quoi malgré tout c’est un problème. Ce pointeur n’étant finalement possédé que par la structure du périphérique et utilisé nul part ailleurs en même temps. Est-ce que le fait que c’était un pointeur nu a invalidé sa zone mémoire une fois la détection effectuée ? Et que les réallocation de la chaîne sont entrés en conflit ?

Moralité :

• Toujours écouter valgrind, la voix de la sagesse, même quand c’est surprenant, comme en C ou C++ ;
• Ne pas oublier de vérifier en mode release, comme en C ou C++, c’est évident mais je n’y avais pas songé ;
• Il y a d’autres allocateurs mémoires faciles à utiliser pour vérifier le comportement au cas où.

Merci pour tes pistes.

Le pointeur oui, mais qui possède les données pointées ? Rust ne garantie pas que les données derrière un pointeur nu restent valides.

Je pensais, du moins si ce dernier n’était ni modifié (ce qui était mon cas), ni détruit volontairement (idem).

Là, tu n’as aucun code qui vérifie cet invariant, une fonction safe qui contient juste un bloc unsafe mais rien qui vérifie les invariants de ce bloc n’a aucune garantie de fonctionner.

Comme le pointeur a été valide et qu’il n’a pas été altéré selon moi, c’était bon. Mais manifestement je me suis trompé. Je dois approfondir ce point dans ma compréhension de Rust.

Il est clair que j’ai eu un mauvais réflexe ici.

(Par ailleurs, de manière générale, si tu te trimbales un pointeur nu en Rust alors que tu n’es pas en train d’écrire un pointeur intelligent, c’est probablement une erreur de design).

Ce bout de code a quelques mois maintenant, je m’y suis remis très récemment et il est vrai que je n’avais pas vu les pointeur intelligents à ce stade en Rust. Merci du conseil !

Oui je vois, ramené à cet exemple c’est évident.

Merci beaucoup.