search

Hypfer / Valetudo

Cloud replacement for vacuum robots enabling local-only operation
https://valetudo.cloud
Apache License 2.0
6.68k stars 397 forks source link

Valetudo Web interface is not reachable after WiFi disconnect and reconnect #1549

Closed picakia closed 2 years ago

picakia commented 2 years ago

Describe the bug

Valetudo interface is not reachable on local IP address after robot has been disconnected from WiFi access point for about 4-5 minutes. SSH access works and restarting Valetudo service via /etc/init/S11valetudo restart fixes the problem.

To Reproduce

  1. Reset robot Wi-Fi
  2. Connect robot to an access point that can be easily turned off using Valetudo companion
  3. Confirm robot IP address and check if Valetudo interface is reachable and working
  4. Turn off access point for about 4-5 minutes and turn it back on
  5. Wait for robot to connect and try to access Web interface
  6. If Valetudo interface is not reachable try SSH - if it works the bug has been reproduced

Screenshots

Screenshots (click me) ![Valetudo interface working](https://user-images.githubusercontent.com/46346690/184534128-67fb9eab-44c0-40f8-bde8-d170063d21cd.png) ![Valetudo interface after being reconnected](https://user-images.githubusercontent.com/46346690/184534145-36433491-9b5a-46f2-a286-ae43f8cf7197.png) ![Restarting valetudo service](https://user-images.githubusercontent.com/46346690/184534148-f16faebf-ae2b-45e4-985b-977b8f142c78.png)

Vacuum Model

Roborock S5

Valetudo Version

2022.08.0

Expected behavior

After robot has been reconnected to WiFi access point after being disconnected for longer than 5 minutes Valetudo interface should work normally.

Additional context

I used phone access point for testing this behavior. Valetudo log file

Hypfer commented 2 years ago

Strange. Sounds similar to #1521 Unfortunately, it is impossibly to understand the issue from the information provided as they're basically just "hey, broken!".

What confuses me the most is that there is nothing in the Valetudo log. Do you see something in the dmesg output or any other logfile you might find in the FS?

Hypfer commented 2 years ago

Trying out the steps to reproduce with my S5 didn't work out. I've tried it two times and Valetudo is still running fine

fabir-git commented 2 years ago

Strange. Sounds similar to #1521 Unfortunately, it is impossibly to understand the issue from the information provided as they're basically just "hey, broken!".

What confuses me the most is that there is nothing in the Valetudo log. Do you see something in the dmesg output or any other logfile you might find in the FS?

I am having similar issues with my L10Pro (loosing wifi some times after cleaning and some times random). Here ist the dmesg output after the last time the issue occured:

[root@p2029_release:/data/log]# dmesg [ 0.989113] deviceless supply vcc-nand not found, using dummy regulator [ 0.989354] nand:get voltage vcc-nand ok:ffffffc01cef5200 [ 0.989361] nand0_regulator2 none [ 0.989384] deviceless supply none not found, using dummy regulator [ 0.989549] nand:get voltage vcc-io ok:ffffffc01cef5980 [ 0.989554] nand:has already get voltage [ 0.989562] nand_clk_request [ 0.989611] nand_clk_request: get pll rate 1200000000HZ [ 0.989779] [ND]Reset NDFC start 0 0 [ 0.989786] [ND]Reset NDFC end 0 0 [ 0.989852] [NI]find the device:FS33ND04GS108TF10 [ 0.989861] [NI]rawnand support chip 0: ec dc 10 95 56 c6 ec dc [ 0.989908] [NE]rawnand not support chip 1: 03 03 03 03 03 03 03 03 [ 0.989923] id_number_ctl is no used [ 0.989929] [ND]build nand physical connection ok... [ 0.989934] [ND]CE: [ 0.989939] [ND]0 [ND] [ 0.989943] RB: [ 0.989948] [ND]0 <7>[ 0.989953] [ND] [ 0.990181] [ND]check scan data, first_check 4 1! [ 0.990191] [ND]329 interface change ddr_type:0 sclk0:40 sclk1:80 sdr_edo_bak :1 ddr_edo_bak:1 ddr_delay_bak:0 ! [ 0.990199] [ND]mode 6: unchanged, rawnand set to sdr [ 0.990204] [ND]mode 6 [ 0.990217] [ND]_get right timing para, set edo to 1 for sdr nand. [ 0.990224] generic special init [ 0.990229] [ND]nand_physic_info_read start!! [ 0.990929] [ND]physic_info_get_one_copy start!! [ 0.991925] [ND]block 16 page 40 [ 0.992046] [ND]block 16 page 41 [ 0.992167] [ND]block 16 page 42 [ 0.992287] [ND]block 16 page 43 [ 0.992408] [ND]block 16 page 44 [ 0.992528] [ND]block 16 page 45 [ 0.992648] [ND]block 16 page 46 [ 0.992769] [ND]block 16 page 47 [ 0.992889] [ND]block 16 page 48 [ 0.993010] [ND]block 16 page 49 [ 0.993130] [ND]block 16 page 50 [ 0.993251] [ND]block 16 page 51 [ 0.993371] [ND]block 16 page 52 [ 0.993491] [ND]block 16 page 53 [ 0.993612] [ND]block 16 page 54 [ 0.993732] [ND]block 16 page 55 [ 0.993914] [ND]physic info copy is ok [ 0.993934] [ND]rawnand_sp_chips_init 2459 [ 0.993941] [NI]==============show_nctri====================== [ 0.993946] [NI]channel_id: 0 [ 0.993951] [NI]type: 1 [ 0.993956] [NI]chip_cnt: 1 [ 0.993961] [NI]chip_connect_info: 1 [ 0.993966] [NI]rb_connect_info: 1 [ 0.993970] [NI]ce: [ 0.993975] [NI]0 [NI] [ 0.993979] rb: [ 0.993984] [NI]0 <6>[ 0.993988] [NI] [ 0.993993] [NI]dma_type: 1 [ 0.993998] [NI]dma_addr: 5cf0f800 [ 0.994004] [NI]write_wait_rb_before: 1 [ 0.994008] [NI]write_wait_rb_mode: 1 [ 0.994013] [NI]rb_ready_flag: 0 [ 0.994018] [NI]dma_ready_flag: 1 [ 0.994022] [NI]timing ctl: [ 0.994027] [NI]0x100 <6>[ 0.994031] [NI] [ 0.994036] [ND]print ndfc reg: [ 0.994042] [ND]reg_ctl: ffffff8008aad000 0x0f004119 [ 0.994048] [ND]reg_sta: ffffff8008aad004 0x00000f00 [ 0.994054] [ND]reg_int: ffffff8008aad008 0x00000000 [ 0.994060] [ND]reg_timing_ctl: ffffff8008aad00c 0x00000100 [ 0.994066] [ND]reg_timing_cfg: ffffff8008aad010 0x00010095 [ 0.994072] [ND]reg_addr_low: ffffff8008aad014 0x04370000 [ 0.994078] [ND]reg_addr_high: ffffff8008aad018 0x00000000 [ 0.994084] [ND]reg_ndfc_cnt: ffffff8008aad020 0x00000001 [ 0.994090] [ND]reg_cmd: ffffff8008aad024 0x85ec0000 [ 0.994095] [ND]reg_read_cmd_set: ffffff8008aad028 0x00e00530 [ 0.994101] [ND]reg_write_cmd_set: ffffff8008aad02c 0x70008510 [ 0.994107] [ND]reg_io_data: ffffff8008aad300 0x70008510 [ 0.994113] [ND]reg_ecc_ctl: ffffff8008aad034 0x4a800008 [ 0.994118] [ND]reg_ecc_sta: ffffff8008aad038 0x00000000 [ 0.994124] [ND]reg_efr: ffffff8008aad040 0x00000100 [ 0.994130] [ND]reg_err_cnt0: ffffff8008aad050 0x00000000 [ 0.994136] [ND]reg_err_cnt1: ffffff8008aad054 0x00000000 [ 0.994141] [ND]reg_err_cnt2: ffffff8008aad058 0x00000000 [ 0.994147] [ND]reg_err_cnt3: ffffff8008aad05c 0x00000000 [ 0.994153] [ND]reg_user_data_base:ffffff8008aad110 0x00000000 [ 0.994159] [ND]reg_efnand_sta: ffffff8008aad054 0x00000000 [ 0.994164] [ND]reg_spare_area: ffffff8008aad114 0x00000800 [ 0.994170] [ND]reg_pat_id: ffffff8008aad118 0x00000000 [ 0.994176] [ND]reg_dma_cnt: ffffff8008aad214 0x00000000 [ 0.994182] [ND]reg_ram0_base: ffffff8008aad400 0x00000000 [ 0.994188] [ND]reg_ram1_base: ffffff8008aad800 0x00000000 [ 0.994193] [NI]==============show_nctri end====================== [ 0.994198] [NI]==============show_nci====================== [ 0.994202] [NI]id: [ 0.994207] [NI]ec [NI]dc [ 0.994216] [NI]10 [NI]95 [ 0.994226] [NI]56 [NI]ff [ 0.994235] [NI]ff [NI]ff [ 0.994244] [NI] [ 0.994249] [NI]chip_no: 0 [ 0.994254] [NI]nctri_chip_no: 0 [ 0.994259] [NI]driver_no: 0 [ 0.994264] [NI]blk_cnt_per_chip: 4096 [ 0.994269] [NI]sector_cnt_per_page: 4 [ 0.994274] [NI]page_cnt_per_blk: 64 [ 0.994279] [NI]page_offset_for_next_blk: 64 [ 0.994284] [NI]randomizer: 1 [ 0.994289] [NI]read_retry: 0 [ 0.994294] [NI]interface_type: 0 [ 0.994299] [NI]timing_mode: 4 [ 0.994304] [NI]support_change_onfi_timing_mode: 0 [ 0.994309] [NI]support_onfi_ddr2_specific_cfg: 0 [ 0.994315] [NI]support_onfi_io_driver_strength: 0 [ 0.994320] [NI]support_toggle_vendor_specific_cfg:0 [ 0.994325] [NI]support_toggle_only: 0 [ 0.994330] [NI]frequency: 40 [ 0.994335] [NI]ecc_mode: 0 [ 0.994340] [NI]max_erase_times: 60000 [ 0.994345] [NI]page_addr_bytes: 0 [ 0.994350] [NI]sdata_bytes_per_page: 8 [ 0.994355] [NI]nsci chip_no: 0x00000000 [ 0.994361] [NI]nctri channel_id: 0x00000000 [ 0.994366] [NI]multi_plane_read_instr_cmd0: 0x00000000 [ 0.994371] [NI]multi_plane_read_instr_cmd1: 0x00000032 [ 0.994376] [NI]multi_plane_write_instr_cmd0: 0x00000080 [ 0.994382] [NI]multi_plane_write_instr_cmd1: 0x00000011 [ 0.994387] [NI]bad_block_flag_position: 0x00000001 [ 0.994392] [NI]multi_plane_block_offset: 0x00000001 [ 0.994397] [NI]id_number: 0x00000000 [ 0.994402] [NI]================show_nsi==================== [ 0.994407] [NI]chip_cnt: 1 [ 0.994412] [NI]block_nums: 0 [ 0.994417] [NI]================show_nssi==================== [ 0.994422] [NI]super_chip_cnt: 1 [ 0.994427] [NI]super_block_nums: 0 [ 0.994432] [NI]support_two_plane: 1 [ 0.994436] [NI]support_v_interleave:0 [ 0.994442] [NI]support_dual_channel:0 [ 0.994447] [NI]=================show_nsci=================== [ 0.994451] [NI]chip_no: 0 [ 0.994457] [NI]blk_cnt_per_super_chip: 2048 [ 0.994462] [NI]sector_cnt_per_super_page: 8 [ 0.994467] [NI]page_cnt_per_super_blk: 64 [ 0.994472] [NI]page_offset_for_next_super_blk:64 [ 0.994477] [NI]spare_bytes: 16 [ 0.994482] [NI]two_plane: 1 [ 0.994487] [NI]channel_num: 1 [ 0.994492] [NI]vertical_interleave: 0 [ 0.994497] [NI]dual_channel: 0 [ 0.994502] [NI]driver_no: 0 [ 0.994507] [NI]nci_first: 0 0 [ 0.994513] [NI]exit rawnand hardward init [ 0.994521] [ND]nand_secure_storage_init 208 nBlkNum:40 [ 0.994804] [ND]nand_secure_storage_init 226 nand_secure_storage_block:40 [ 0.994811] [ND]nand_secure_storage_init 228 nand_secure_storage_block_bak:41 [ 0.994817] [ND]nand_secure_storage_init 230 MIN_SECURE_STORAGE_BLOCK_NUM:8 [ 0.994823] [ND]nand secure storage ok: 40,41 [ 0.994827] [ND]RawNandHwInit end [ 0.994884] [ND]start block:42 [ 0.994890] [ND]boot start [ 0.994896] [ND]boot :0x1cf28000 [ 0.994901] [ND]boot->magic :0xaa55a5a5 [ 0.994907] [ND]boot->len :0x8000 [ 0.994912] [ND]boot->no_use_block :0x15 [ 0.994917] [ND]boot->uboot_start_block :0x8 [ 0.994923] [ND]boot->uboot_next_block :0x28 [ 0.994928] [ND]boot->logic_start_block :0x15 [ 0.994933] [ND]mbr len :4096 [ 0.994939] [ND]_PARTITION len :2560 [ 0.994944] [ND]_NAND_STORAGE_INFO len :512 [ 0.994949] [ND]_FACTORY_BLOCK len :2048 [ 0.994960] [NE]partition_num: 0,size :0xe6a00,cross_talk 0 [ 0.994966] [NE]part mbr size: 0x400 type: 0 [ 0.994972] [NE]part boot-resource size: 0x200 type: 0 [ 0.994978] [NE]part env size: 0x400 type: 0 [ 0.994984] [NE]part env-redund size: 0x400 type: 0 [ 0.994990] [NE]part boot1 size: 0x6000 type: 0 [ 0.994996] [NE]part rootfs1 size: 0x16000 type: 0 [ 0.995002] [NE]part boot2 size: 0x6000 type: 0 [ 0.995008] [NE]part rootfs2 size: 0x16000 type: 0 [ 0.995013] [NE]part private size: 0x400 type: 0 [ 0.995020] [NE]part misc size: 0x1000 type: 0 [ 0.995046] [NE]part pstore size: 0x400 type: 0 [ 0.995052] [NE]part UDISK size: 0xac400 type: 0 [ 0.995170] [ND]factory bad block:0,1030 PartitionNO:0 [ 0.995247] [ND]factory bad block:0,2047 PartitionNO:0 [ 0.995253] [ND]phy_partition->PartitionNO :0 [ 0.995258] [ND]phy_partition->SectorNumsPerPage :8 [ 0.995264] [ND]phy_partition->PageNumsPerBlk :64 [ 0.995269] [ND]phy_partition->TotalBlkNum :2027 [ 0.995275] [ND]phy_partition->FullBitmapPerPage :8 [ 0.995280] [ND]phy_partition->FreeBlock :0 [ 0.995286] [ND]phy_partition->TotalSectors :944640 [ 0.995291] [ND]phy_partition->StartBlock.Chip_NO :0 [ 0.995297] [ND]phy_partition->StartBlock.Block_NO :21 [ 0.995302] [ND]phy_partition->EndBlock.Chip_NO :0 [ 0.995308] [ND]phy_partition->EndBlock.Block_NO :2047 [ 0.995313] [ND]phy_partition->next_phy_partition :0 [ 0.995319] [ND]phy_partition->PartitionNO 0 FACTORY BAD BLOCK: [ 0.995325] [ND]BAD Chip:0;Block:1030. [ 0.995331] [ND]BAD Chip:0;Block:2047. [ 0.995336] [ND]phy_partition->PartitionNO 0 NEW BAD BLOCK: [ 0.995342] [ND]build 1 phy_partition ! [ 0.995348] [ND]nand_info->type :0 [ 0.995354] [ND]nand_info->SectorNumsPerPage :8 [ 0.995359] [ND]nand_info->BytesUserData :16 [ 0.995364] [ND]nand_info->PageNumsPerBlk :64 [ 0.995370] [ND]nand_info->BlkPerChip :2048 [ 0.995375] [ND]nand_info->FirstBuild :0 [ 0.995381] [ND]nand_info->FullBitmap :0 [ 0.995386] [ND]nand_info->bad_block_addr.Chip_NO :0 [ 0.995392] [ND]nand_info->bad_block_addr.Block_NO :0 [ 0.995397] [ND]nand_info->mbr_block_addr.Chip_NO :0 [ 0.995402] [ND]nand_info->mbr_block_addr.Block_NO :0 [ 0.995408] [ND]nand_info->no_used_block_addr.Chip_NO :0 [ 0.995413] [ND]nand_info->no_used_block_addr.Block_NO :21 [ 0.995419] [ND]nand_info->new_bad_block_addr.Chip_NO :0 [ 0.995425] [ND]nand_info->new_bad_block_addr.Block_NO :0 [ 0.995430] [ND]nand_info->new_bad_page_addr :65535 [ 0.995436] [ND]nand_info->partition_nums :1 [ 0.995441] [ND]sizeof partition:2384 [ 0.995446] [ND]nand_info->partition:0: [ 0.995452] [ND]size:0xe6a00 [ 0.995457] [ND]cross_talk:0x0 [ 0.995462] [ND]attribute:0x0 [ 0.995468] [ND]start: chip:0 block:21 [ 0.995473] [ND]end : chip:0 block:2047 [ 0.995479] [ND]boot :0x1cf28000 [ 0.995484] [ND]boot->magic :0xaa55a5a5 [ 0.995489] [ND]boot->len :0x8000 [ 0.995494] [ND]boot->no_use_block :0x15 [ 0.995500] [ND]boot->uboot_start_block :0x8 [ 0.995505] [ND]boot->uboot_next_block :0x28 [ 0.995510] [ND]boot->logic_start_block :0x15 [ 0.995515] [ND]mbr len :4096 [ 0.995520] [ND]_PARTITION len :2560 [ 0.995526] [ND]_NAND_STORAGE_INFO len :512 [ 0.995531] [ND]_FACTORY_BLOCK len :2048 [ 0.996351] [ND]nand_partition0 [ 0.996365] sunxi nftl version 3.7.004 2020.03.05-14:07 [ 0.996800] [ND]nftl start:2027,182 [ 0.997025] [ND]first [ 0.997032] [ND]fsab [ 1.041114] [ND]fill block 200 [ 1.225314] [NI]nftl bad block: 1009 [ 1.408475] [ND]fill block 1759 [ 1.449140] [ND]fill block 1921 [ 1.475535] [NI]nftl bad block: 2026 [ 1.475542] [ND]before second 2025 1845. [ 1.483387] random: fast init done [ 1.951588] [NI]all block full!! [ 1.951596] [ND]get a new free block [ 1.951608] [ND]free block nums is 82, aec: 0, iec: 0, a_buc: 0, i_buc: 0! [ 1.951617] [ND]not power on gc [82, 36, 120], [2025 1845 180]! [ 1.951622] [NI]nftl ok! [ 1.951630] [NE] reserved panic block 1450! [ 1.951635] [NE] reserved panic block 200! [ 1.951641] [NE] reserved panic block 460! [ 1.952129] [ND]max_erase_times = 60000 [ 1.956806] nand0: p1 p2 p3 p4 p5 p6 p7 p8 p9 p10 p11 [ 1.968438] [NI] panic nand version: 0.4.0 [ 1.968600] [NI] fixup panic nand parition size [ 1.968618] [NI] dev:ffffffc01d6c4890 [ 1.969281] pstore-zone: Registered pstore-blk as pszone backend for Oops Pan ic [ 1.969296] pstore: Registered pstore-zone as persistent store backend [ 1.969302] pstore-blk: using '/dev/nand0p10' [ 1.969307] [NI] panic nand init ok [ 1.969311] [NAND]nand init end [ 1.970550] sunxi-wlan soc@03000000:wlan@0: wlan_busnum (1) [ 1.970564] sunxi-wlan soc@03000000:wlan@0: wlan_power_num (1) [ 1.970597] sunxi-wlan soc@03000000:wlan@0: wlan_power_name (axp806-sw) [ 1.970607] sunxi-wlan soc@03000000:wlan@0: Missing wlan_io_regulator. [ 1.970615] sunxi-wlan soc@03000000:wlan@0: io_regulator_name ((null)) [ 1.970761] sunxi-wlan soc@03000000:wlan@0: request pincrtl handle for device [soc@03000000:wlan@0] failed [ 1.970834] of_get_named_gpiod_flags: parsed 'wlan_regon' property of node '/ soc@03000000/wlan@0[0]' - status (0) [ 1.970845] sunxi-wlan soc@03000000:wlan@0: wlan_regon gpio=198 mul-sel=1 p ull=-1 drv_level=-1 data=0 [ 1.970912] of_get_named_gpiod_flags: can't parse 'chip_en' property of node '/soc@03000000/wlan@0[0]' [ 1.970921] sunxi-wlan soc@03000000:wlan@0: get gpio chip_en failed [ 1.970940] of_get_named_gpiod_flags: parsed 'wlan_hostwake' property of node '/soc@03000000/wlan@0[0]' - status (0) [ 1.970951] sunxi-wlan soc@03000000:wlan@0: wlan_hostwake gpio=199 mul-sel=6 pull=-1 drv_level=-1 data=0 [ 1.971340] sunxi-wlan soc@03000000:wlan@0: clk_name () [ 1.975538] libphy: Fixed MDIO Bus: probed [ 1.975547] tun: Universal TUN/TAP device driver, 1.6 [ 1.975552] tun: (C) 1999-2004 Max Krasnyansky maxk@qualcomm.com [ 1.976326] PPP generic driver version 2.4.2 [ 1.977269] PPP BSD Compression module registered [ 1.977291] PPP Deflate Compression module registered [ 1.977323] PPP MPPE Compression module registered [ 1.977332] NET: Registered protocol family 24 [ 1.977401] ehci_hcd: USB 2.0 'Enhanced' Host Controller (EHCI) Driver [ 1.977894] get ehci0-controller, regulator_io is no nocare [ 1.977901] get ehci0-controller wakeup-source is fail. [ 1.978256] sunxi ehci0-controller don't init wakeup source [ 1.978267] [sunxi-ehci0]: probe, pdev->name: 5101000.ehci0-controller, sunxi _ehci: 0xffffff8008a7eb90, 0x:ffffff8008ac3000, irq_no:168 [ 1.978272] [sunxi-ehci0]: Not init ehci0 [ 1.978525] get ehci1-controller, regulator_io is no nocare [ 1.978532] get ehci1-controller wakeup-source is fail. [ 1.978723] sunxi ehci1-controller don't init wakeup source [ 1.978732] [sunxi-ehci1]: probe, pdev->name: 5200000.ehci1-controller, sunxi _ehci: 0xffffff8008a7f2a0, 0x:ffffff8008acd000, irq_no:16a [ 1.979089] sunxi-ehci 5200000.ehci1-controller: SW USB2.0 'Enhanced' Host Co ntroller (EHCI) Driver [ 1.979201] sunxi-ehci 5200000.ehci1-controller: new USB bus registered, assi gned bus number 1 [ 1.979818] sunxi-ehci 5200000.ehci1-controller: irq 362, io mem 0xffffff8008 acd000 [ 1.995055] sunxi-ehci 5200000.ehci1-controller: USB 0.0 started, EHCI 1.00 [ 1.998998] hub 1-0:1.0: USB hub found [ 1.999127] hub 1-0:1.0: 1 port detected [ 2.001843] ohci_hcd: USB 1.1 'Open' Host Controller (OHCI) Driver [ 2.002368] get ohci0-controller, regulator_io is no nocare [ 2.002376] get ohci0-controller wakeup-source is fail. [ 2.002724] sunxi ohci0-controller don't init wakeup source [ 2.002873] [sunxi-ohci0]: probe, pdev->name: 5101000.ohci0-controller, sunxi _ohci: 0xffffff8008a7ef18 [ 2.002879] [sunxi-ohci0]: Not init ohci0 [ 2.003151] get ohci1-controller, regulator_io is no nocare [ 2.003157] get ohci1-controller wakeup-source is fail. [ 2.003342] sunxi ohci1-controller don't init wakeup source [ 2.003456] [sunxi-ohci1]: probe, pdev->name: 5200000.ohci1-controller, sunxi _ohci: 0xffffff8008a7f628 [ 2.003839] sunxi-ohci 5200000.ohci1-controller: SW USB2.0 'Open' Host Contro ller (OHCI) Driver [ 2.003918] sunxi-ohci 5200000.ohci1-controller: new USB bus registered, assi gned bus number 2 [ 2.004188] sunxi-ohci 5200000.ohci1-controller: irq 363, io mem 0x00000040 [ 2.070877] hub 2-0:1.0: USB hub found [ 2.070983] hub 2-0:1.0: 1 port detected [ 2.073876] usbcore: registered new interface driver uas [ 2.074294] usbcore: registered new interface driver usb-storage [ 2.074485] usbcore: registered new interface driver ums-alauda [ 2.074678] usbcore: registered new interface driver ums-cypress [ 2.074883] usbcore: registered new interface driver ums-datafab [ 2.075099] usbcore: registered new interface driver ums_eneub6250 [ 2.075296] usbcore: registered new interface driver ums-freecom [ 2.075483] usbcore: registered new interface driver ums-isd200 [ 2.075688] usbcore: registered new interface driver ums-jumpshot [ 2.075885] usbcore: registered new interface driver ums-karma [ 2.076077] usbcore: registered new interface driver ums-onetouch [ 2.076385] usbcore: registered new interface driver ums-realtek [ 2.076596] usbcore: registered new interface driver ums-sddr09 [ 2.076789] usbcore: registered new interface driver ums-sddr55 [ 2.076984] usbcore: registered new interface driver ums-usbat [ 2.077146] get usb_serial_number success from boot command line [ 2.079884] axp2101_pek: Setting power key for unsupported AXP variant [ 2.083214] input: axp2101-pek as /devices/platform/soc/7081400.s_twi/i2c-6/6 -0036/axp2101-pek.0/input/input1 [ 2.084479] sunxi_gpadc_init,1831, success [ 2.085308] sunxi_gpadc_setup: get channel scan data failed [ 2.086422] input: sunxi-gpadc0 as /devices/virtual/input/input2 [ 2.089866] sunxi-rtc rtc: rtc core: registered sunxi-rtc as rtc0 [ 2.090096] sunxi-rtc rtc: RTC enabled [ 2.090729] i2c /dev entries driver [ 2.095694] sunxi cedar version 0.1 [ 2.096006] VE: install start!!! [ 2.096006] [ 2.096240] cedar_ve: cedar-ve the get irq is 347 [ 2.096582] VE: line 1811 set the sram data [ 2.096582] [ 2.097496] VE: get debugfs_mpp_root is NULL, please check mpp [ 2.097496] [ 2.097503] VE: sunxi ve debug register driver failed! [ 2.097503] [ 2.097508] VE: install end!!! [ 2.097508] [ 2.109364] [cpu_freq] ERR: Failed register driver [ 2.109371] sunxi_cpufreq_pwm: Failed register driver [ 2.111976] sunxi-mmc sdc1: SD/MMC/SDIO Host Controller Driver(v3.40 2020-4-2 19:06) [ 2.112202] sunxi-mmc sdc1: ctl-spec-caps 8 [ 2.112306] sunxi-mmc sdc1: No vmmc regulator found [ 2.112311] sunxi-mmc sdc1: No vqmmc regulator found [ 2.112316] sunxi-mmc sdc1: No vdmmc regulator found [ 2.112321] sunxi-mmc sdc1: No vd33sw regulator found [ 2.112326] sunxi-mmc sdc1: No vd18sw regulator found [ 2.112330] sunxi-mmc sdc1: No vq33sw regulator found [ 2.112340] sunxi-mmc sdc1: No vq18sw regulator found [ 2.112348] of_get_named_gpiod_flags: can't parse 'card-pwr-gpios' property o f node '/soc@03000000/sdmmc@04021000[0]' [ 2.112366] sunxi-mmc sdc1: Cann't get uart0 pinstate,check if needed [ 2.112976] sunxi-mmc sdc1: set host busy [ 2.113000] sunxi-mmc sdc1: GPIO lookup for consumer cd [ 2.113006] sunxi-mmc sdc1: using device tree for GPIO lookup [ 2.113014] of_get_named_gpiod_flags: can't parse 'cd-gpios' property of node '/soc@03000000/sdmmc@04021000[0]' [ 2.113020] of_get_named_gpiod_flags: can't parse 'cd-gpio' property of node '/soc@03000000/sdmmc@04021000[0]' [ 2.113025] sunxi-mmc sdc1: using lookup tables for GPIO lookup [ 2.113032] sunxi-mmc sdc1: lookup for GPIO cd failed [ 2.113049] sunxi-mmc sdc1: GPIO lookup for consumer wp [ 2.113054] sunxi-mmc sdc1: using device tree for GPIO lookup [ 2.113060] of_get_named_gpiod_flags: can't parse 'wp-gpios' property of node '/soc@03000000/sdmmc@04021000[0]' [ 2.113066] of_get_named_gpiod_flags: can't parse 'wp-gpio' property of node '/soc@03000000/sdmmc@04021000[0]' [ 2.113071] sunxi-mmc sdc1: using lookup tables for GPIO lookup [ 2.113076] sunxi-mmc sdc1: lookup for GPIO wp failed [ 2.113114] of_get_named_gpiod_flags: can't parse 'cd-gpios' property of node '/soc@03000000/sdmmc@04021000[0]' [ 2.113117] mmc:failed to get gpios [ 2.113632] sunxi-mmc sdc1: sdc set ios:clk 0Hz bm PP pm UP vdd 21 width 1 ti ming LEGACY(SDR12) dt B [ 2.113652] sunxi-mmc sdc1: no vqmmc,Check if there is regulator [ 2.131044] sunxi-mmc sdc1: sdc set ios:clk 400000Hz bm PP pm ON vdd 21 width 1 timing LEGACY(SDR12) dt B [ 2.151045] sunxi-mmc sdc1: detmode:manually by software [ 2.151875] sunxi-mmc sdc1: smc 0 p1 err, cmd 52, RTO !! [ 2.152490] usbcore: registered new interface driver usbhid [ 2.152494] usbhid: USB HID core driver [ 2.152697] sunxi-mmc sdc1: smc 0 p1 err, cmd 52, RTO !! [ 2.152715] sunxi-mmc sdc1: sdc set ios:clk 400000Hz bm PP pm ON vdd 21 width 1 timing LEGACY(SDR12) dt B [ 2.155180] sunxi-mmc sdc1: sdc set ios:clk 400000Hz bm PP pm ON vdd 21 width 1 timing LEGACY(SDR12) dt B [ 2.157087] sunxi-mmc sdc1: smc 0 p1 err, cmd 5, RTO !! [ 2.157910] sunxi-mmc sdc1: smc 0 p1 err, cmd 5, RTO !! [ 2.158060] usbcore: registered new interface driver snd-usb-audio [ 2.158727] sunxi-mmc sdc1: smc 0 p1 err, cmd 5, RTO !! [ 2.159543] sunxi-mmc sdc1: smc 0 p1 err, cmd 5, RTO !! [ 2.159564] sunxi-mmc sdc1: sdc set ios:clk 0Hz bm PP pm OFF vdd 0 width 1 ti ming LEGACY(SDR12) dt B [ 2.161379] codec supply avcc not found, using dummy regulator [ 2.161541] [sunxi_internal_codec_probe]: audiocodec avcc set vol failed [ 2.161558] codec supply cpvin not found, using dummy regulator [ 2.161703] [sunxi_internal_codec_probe]: audiocodec cpvin set vol failed [ 2.162236] of_get_named_gpiod_flags: parsed 'gpio-spk' property of node '/so c@03000000/codec@0x05096000[0]' - status (0) [ 2.162384] sunxi-internal-codec codec: [sunxi_internal_codec_probe] codec pr obe finished. [ 2.163766] [sunxi_card_init] card init finished. [ 2.165635] sunxi-codec-machine sndcodec: sun50iw10codec <-> 5096000.cpudai-c ontroller mapping ok [ 2.168513] sunxi-codec-machine sndcodec: [sunxi_card_dev_probe] register car d finished. [ 2.169019] u32 classifier [ 2.169023] Actions configured [ 2.169152] Initializing XFRM netlink socket [ 2.173304] NET: Registered protocol family 10 [ 2.177914] NET: Registered protocol family 17 [ 2.178621] 8021q: 802.1Q VLAN Support v1.8 [ 2.208634] get usb_detect_mode is fail, 22 [ 2.208655] of_get_named_gpiod_flags: parsed 'usb_det_vbus_gpio' property of node '/soc@03000000/usbc0@0[0]' - status (0) [ 2.208667] of_get_named_gpiod_flags: parsed 'usb_id_gpio' property of node ' /soc@03000000/usbc0@0[0]' - status (0) [ 2.209644] of_get_named_gpiod_flags: parsed 'gpios' property of node '/soc@0 3000000/gpio-keys/button-back[0]' - status (0) [ 2.210799] input: soc@03000000:gpio-keys as /devices/platform/soc/soc@030000 00:gpio-keys/input/input3 [ 2.211686] sunxi-rtc rtc: setting system clock to 1970-01-01 00:00:04 UTC (4 ) [ 2.212514] usb0-vbus: disabling [ 2.212543] ALSA device list: [ 2.212547] #0: audiocodec [ 2.216899] VFS: Mounted root (squashfs filesystem) readonly on device 93:7. [ 2.219307] devtmpfs: mounted [ 2.219611] Freeing unused kernel memory: 448K [ 2.819680] random: jsonpath: uninitialized urandom read (4 bytes read) [ 3.165817] random: jsonpath: uninitialized urandom read (4 bytes read) [ 3.173788] random: rngd: uninitialized urandom read (4 bytes read) [ 3.174333] random: crng init done [ 3.174338] random: 2 urandom warning(s) missed due to ratelimiting [ 3.554264] EXT4-fs (nand0p11): mounted filesystem with ordered data mode. Op ts: (null) [ 3.677926] EXT4-fs (nand0p9): mounted filesystem with ordered data mode. Opt s: (null) [ 4.107655] sunxi-wlan soc@03000000:wlan@0: check wlan wlan_power voltage: 33 00000 [ 4.217775] sunxi-wlan soc@03000000:wlan@0: bus_index: 1 [ 4.217781] ----- platform_wifi_power_on sdc_id: 1 [ 4.217816] sunxi-mmc sdc1: sdc set ios:clk 0Hz bm PP pm UP vdd 21 width 1 ti ming LEGACY(SDR12) dt B [ 4.217916] sunxi-mmc sdc1: no vqmmc,Check if there is regulator [ 4.235129] sunxi-mmc sdc1: sdc set ios:clk 400000Hz bm PP pm ON vdd 21 width 1 timing LEGACY(SDR12) dt B [ 4.255774] sunxi-mmc sdc1: sdc set ios:clk 400000Hz bm PP pm ON vdd 21 width 1 timing LEGACY(SDR12) dt B [ 4.258275] sunxi-mmc sdc1: sdc set ios:clk 400000Hz bm PP pm ON vdd 21 width 1 timing LEGACY(SDR12) dt B [ 4.259694] sunxi-mmc sdc1: card claims to support voltages below defined ran ge [ 4.269279] sunxi-mmc sdc1: sdc set ios:clk 400000Hz bm PP pm ON vdd 21 width 1 timing SD-HS(SDR25) dt B [ 4.269381] sunxi-mmc sdc1: sdc set ios:clk 50000000Hz bm PP pm ON vdd 21 wid th 1 timing SD-HS(SDR25) dt B [ 4.269606] sunxi-mmc sdc1: sdc set ios:clk 50000000Hz bm PP pm ON vdd 21 wid th 4 timing SD-HS(SDR25) dt B [ 4.270465] mmc0: new high speed SDIO card at address 0001 [ 4.366092] of_get_named_gpiod_flags: can't parse 'sensor1_power_en' property of node '/soc@03000000/vind@0/sensor@1[0]' [ 4.366146] of_get_named_gpiod_flags: parsed 'sensor1_reset' property of node '/soc@03000000/vind@0/sensor@1[0]' - status (0) [ 4.366159] of_get_named_gpiod_flags: parsed 'sensor1_pwdn' property of node '/soc@03000000/vind@0/sensor@1[0]' - status (0) [ 4.366167] of_get_named_gpiod_flags: can't parse 'sensor1_sm_hs' property of node '/soc@03000000/vind@0/sensor@1[0]' [ 4.366174] of_get_named_gpiod_flags: can't parse 'sensor1_sm_vs' property of node '/soc@03000000/vind@0/sensor@1[0]' [ 4.366272] gpio-0 (?): gpiod_request: status -16 [ 4.366278] gpio-0 (?): gpiod_request: status -16 [ 4.366283] gpio-0 (?): gpiod_request: status -16 [ 4.366288] gpio-0 (?): gpiod_request: status -16 [ 4.366293] gpio-0 (?): gpiod_request: status -16 [ 4.366298] gpio-0 (?): gpiod_request: status -16 [ 4.366302] gpio-0 (?): gpiod_request: status -16 [ 4.366344] gpio-0 (?): gpiod_request: status -16 [ 4.366350] gpio-0 (?): gpiod_request: status -16 [ 4.366355] gpio-0 (?): gpiod_request: status -16 [ 4.366360] gpio-0 (?): gpiod_request: status -16 [ 4.366364] gpio-0 (?): gpiod_request: status -16 [ 4.366369] gpio-0 (?): gpiod_request: status -16 [ 4.366374] gpio-0 (?): gpiod_request: status -16 [ 4.366379] gpio-0 (?): gpiod_request: status -16 [ 4.366384] gpio-0 (?): gpiod_request: status -16 [ 4.366389] gpio-0 (?): gpiod_request: status -16 [ 4.366394] gpio-0 (?): gpiod_request: status -16 [ 4.366399] gpio-0 (?): gpiod_request: status -16 [ 4.366404] gpio-0 (?): gpiod_request: status -16 [ 4.366409] gpio-0 (?): gpiod_request: status -16 [ 4.366414] gpio-0 (?): gpiod_request: status -16 [ 4.366419] gpio-0 (?): gpiod_request: status -16 [ 4.366425] gpio-0 (?): gpiod_request: status -16 [ 4.366430] gpio-0 (?): gpiod_request: status -16 [ 4.366435] gpio-0 (?): gpiod_request: status -16 [ 4.613339] of_get_named_gpiod_flags: parsed 'sensor1_pwm1' property of node '/soc@03000000/vind@0/sensor@1[0]' - status (0) [ 4.613354] of_get_named_gpiod_flags: parsed 'sensor1_pwm2' property of node '/soc@03000000/vind@0/sensor@1[0]' - status (0) [ 4.613366] of_get_named_gpiod_flags: parsed 'sensor1_pwm3' property of node '/soc@03000000/vind@0/sensor@1[0]' - status (0) [ 4.613378] of_get_named_gpiod_flags: parsed 'sensor1_vsync' property of node '/soc@03000000/vind@0/sensor@1[0]' - status (0) [ 4.614132] [sc031gs_mipi]PWR_ON! [ 4.635634] [sc031gs_mipi]PWR_OFF! [ 5.273488] IPv6: ADDRCONF(NETDEV_UP): wlan0: link is not ready [ 5.555065] [ 5.555065] insmod_device_driver [ 5.555065] [ 10.404119] IPv6: ADDRCONF(NETDEV_CHANGE): wlan0: link becomes ready [ 15.384592] [ND]gc_one ok! from: 1 [80 36 120] @nand 756 [ 38.777288] unexport_store: status -22 [ 88.118546] [sc031gs_mipi]PWR_ON! [ 88.146256] [sc031gs_mipi]sensor_s_stream on = 1, 640480 fps: 30 code: 3007 [ 88.185588] [sc031gs_mipi]s_fmt set width = 640, height = 480 [ 157.842230] [ND]gc_one ok! from: 1 [78 36 120] @nand 756 [ 162.308682] [sc031gs_mipi]sensor_s_stream on = 0, 640480 fps: 30 code: 3007 [ 162.312031] [sc031gs_mipi]PWR_OFF!

picakia commented 2 years ago

I reproduced the issue again, right now I'm not sure what causes this behavior since it happens only sometimes. It looks like when this happens there are a lot of get_status timed out in valetudo log. I'm attaching dmesg log as well.

From my testing it happened when I:

  1. Reset WiFi and connected to AP
  2. Removed my map
  3. Started new mapping
  4. Finished mapping
  5. Set up segments
  6. Turned robot off and left it off overnight
  7. Turned it on by placing it on the dock
  8. Turning phone AP on after robot finished booting
  9. Trying to connect to valetudo which resulted in valetudo interface showing loading symbols on every switch and menu Screenshot_20220816-124412
  10. A little bit later Valetudo interface is not reachable in any way

In addition if you want and have some free time we can organize debugging session via Telegram where I can give you ssh access to the robot while it is in bugged state since ssh always works. Thanks for quick response and for making awesome software for our vaccums! valetudo.log dmesg.log valetudo_config.json.log (github does not like json - remove .log)

Hypfer commented 2 years ago

Thank you for looking into this further.

Unfortunately, it is unlikely that this issue can be solved in a reasonable amount of time. The logs attached don't show anything too concerning. No segfault of a valetudo binary nor it shutting down. I have absolutely no idea what is going on there but it is likely that the issue lies in the firmware and not the Valetudo code.

Regarding the get_status timeouts, I'm also at a loss. It could be the miio_client not running because there is no wifi connection but it also could be the miio_client rejecting our messages because it thinks that they are duplicates even when they aren't. I've seen that behavior before but I wasn't ever able to understand why it is happening.

As the miio_client is distributed as a binary, we can only resort to ghidra to see what it does. Building our own miio_client could be a solution to that but no one yet bothered to do that.

Apart from that, there's also an issue with the retry logic in Valetudo where it could handle the miio_client not responding more gracefully. No idea when and how though.

As your issues seem to be caused by an unstable wifi connection, I'd suggest just fixing that as it is a few orders of magnitude easier than figuring out what strange edge case it is triggering. Furthermore, not having a stable wifi connection isn't a desirable state to permanently have so it's not like it would be some ugly workaround to fix that.