• State Not Answered
  • Replies 42 replies
  • Subscribers 26 subscribers
  • Views 3330 views
  • Users 0 members are here
Attachments (10) Download All
Nordic Case Info
  • Case ID: 267337
Options

MSC exception

user85932

Hi,

Our production uses NRF52840 as the master chip. We encountered a strange problem where two folders have the same name and a file name has illegal characters. 

The probability of this happening is very low, so we can not find the root cause so far. As we know, the file system does not allow a folder with the same name and a file name with illegal characters. What are the possible causes of this problem?

The normal directory structure is shown below.

-----------------------------------------------------------------------------------------

I would like to provide more details for the MSC issue as below.

I attached the nrf_block_dev_qspi.c that I used, you may diff with the original file of the SDK.

There are two major modifications.

1.the issue was reported in this link https://devzone.nordicsemi.com/f/nordic-q-a/36654/usbd_msd-disk-initialization-fails-in-usb-unplug-with-sdk15-0

the difference was I added a timeout for the wait_for_idle()  function because I found it would hang on this function sometimes.

2. add debug message for troubleshooting 

We got the debug log sometimes(please find debug.log), although everything looks good, I thought it was unexpected. 

By the way, there were not any debug logs when the issue "two folders have the same name and a file name has illegal characters"  occurred.

Parents
  • 0

    Hi ,

    Filenames are stored on the QSPI memory just like file contents, so it is possible that there is a remaining bug in block_dev library other than what was fixed in the earlier thread. It is not a known issue though nor can we pinpoint it as this point.

    Can you say more about how early it occurs, and have you found a way to reliably reproduce it?

  • 0 in reply to user7377

    Hi Einar

    I can not find a way to reliably reproduce it so far, and the probability of this happening is very low. It may have happened before this thread, but I'm not 100% sure.
    I believe that there is a bug in block_dev library because I am able to capture the debug logs sometimes.
    By the way, the latest SDK did not fix the issue mentioned in this thread.

  • 0 in reply to user85932

    Hi,

    I agree the debug log looks unexpected and indicates an issue. But I do not  understand the issue enough to say much. I have asked for input from the maintainers and will inform you of any updates. Please let me know any new findings you may have in the mean time, especially if you find a good way to reproduce the issue.

    Update:

    The team has reviewed the code and do not see any good way forward without having a method to easily reproduce the issue. There are a few things we would like to know, though (which again makes more sense when able to reproduce):

    1. What other components (e.g. SoftDevice) are used alongside filesystem in the application that could cause race conditions?
    2. In case there are many other components used alongside filesystem, if your could disable them temporarily and then check out whether the filesystem issue still occurs.
    3. Can you somehow log all of the file operations that are performed? Then we could try to reproduce on our end using this log.
  • 0 in reply to user7377

    1.What other components (e.g. SoftDevice) are used alongside filesystem in the application that could cause race conditions?

    ->Our production is a bicycle computer, the main system chart is below. The UART uses the DMA mode.

    2.In case there are many other components used alongside  filesystem, if you could disable them temporarily and then check out whether the filesystem issue still occurs.

    ->Sorry, it is difficult to disable other components. 

    3.Can you somehow log all of the file operations that are performed? Then we could try to reproduce on our end using this log.

    ->Actually, our system log included the log of all of the file operations that are performed, but I couldn't see any obvious log related to this issue.

    ----------------------------------------------------------------------------------------------------------------------

    I attached the log of another two devices that have a similar issue.

    The app_error.log file records the function that returned the error.

    1.Please find the logs in the app_error.log file. There are some errors related to the file open and delete operation. it just due to the file with illegal characters. (Our system will delete the file that the suffix is not '.fit '  after unplugging the USB)

    2.

    AE-0.28-1609462306-usb_msc_module.c-USBD_fatfsUninit-398-0x1

    ->this log is due to the error while un-initializing the FATFS.

    The other logs due to the unexpected folder.

    According to the log file, I think these logs were caught after this issue happened.

    I attached the fatfs we used, the long file name and the timestamp was enabled.

     

  • 0 in reply to user85932

    Hi,

    Can you explain the logs, perhaps share the code that writes it? I would guess that the last number is the return value from the function, but about the first? Please explain.

    user85932 said:

    2.In case there are many other components used alongside  filesystem, if you could disable them temporarily and then check out whether the filesystem issue still occurs.

    ->Sorry, it is difficult to disable other components. 

    To be frank there is little to go on here, so I think it is important to try to narrow down the issue even though it might seem a bit tedious.

    user85932 said:
    I attached the fatfs we used, the long file name and the timestamp was enabled.

    It does not seem relevant but as this is not something we have used it would be interesting to know if you can reproduce the issue without as well (so _FS_NORTC and _USE_LFN both set to 0)?

  • 0 in reply to user7377
    user7377 said:
    Can you explain the logs, perhaps share the code that writes it? I would guess that the last number is the return value from the function, but about the first? Please explain.

    For example, AE-0.28-1609461906-fit_file.c-FIT_closeDir-68-0x9

    AE: APP error 

    0.28：FW version 

    1609461906:timestamp

    fit_file.c: file name

    FIT_closeDir: function name 

    68: the code line number of source file 

    0x9:the return value from the function.

    By the way, the function FIT_closeDir is the same as f_closedir, I'm simply encapsulating the API of Fatfs.

    fitFileResult_t FIT_openDir(fitDir_t *dp, const char_t *path) {
        fitFileResult_t ret;
        ret = f_opendir(dp, path);
        APP_ERROR_CHECK(ret);
        return ret;
    }
    user7377 said:
    To be frank there is little to go on here, so I think it is important to try to narrow down the issue even though it might seem a bit tedious.

    I see, I will try to reproduce it on nRF52840-DK PCA10056.

    user7377 said:
    It does not seem relevant but as this is not something we have used it would be interesting to know if you can reproduce the issue without as well (so _FS_NORTC and _USE_LFN both set to 0)?

    We had enabled_FS_NORTC and _USE_LFN both set to 1 at the beginning of this project. So I don't know whether this issue can be reproduced if set to 0.

  • 0 in reply to user85932

    Thank you for the explanation. Please let me know if/when you are able to reproduce on a DK, and also if you see a pattern where removing some of your code/modules seems to make the issue less likely to happen.

    • Reply Children
    • 0 in reply to user7377

      Hi Einar,

      I am able to reproduce on a DK without the patch. That means this issue is caused by the unexpected write operation.

      Below is the repeat method.

      1. Press Button 3 to format the disk 
      2. Press Button 1 to create the folder and file.
      3. connect USB to the PC, then you will see a exception file in the Activ folder 

      ----------------------------------------------------------------------------------------------------------------------------------------------

      ---------------------------------------------------------------------------------------------------------------------------------------------

      After the patch was applied, although this issue couldn't be reproduced, I found some unexpected write operation while connect to the PC.  

      the exception log:

      [00:00:00.011,779] <info> app: #1blk_count:1, erase_unit_dirty_blocks:255, erase_required:1

      [00:00:00.022,338] <info> app: #1blk_count:1, erase_unit_dirty_blocks:0, erase_required:0
      [00:00:00.022,338] <info> app: #0:erase_unit_dirty_blocks:0, erase_unit_idx:0xC

      1.connect to the PC, and format the disk via the PC.

      00> [00:00:00.008,850] <info> app: Read req from block 63 size 1(x512) to 20001804
00> 
00> [00:00:00.010,131] <info> app: Read req from block 63 size 1(x512) to 20001804
00> 
00> [00:00:00.062,561] <info> app: Write req to block 127 size 2(x512) from 20001804
00> 
00> [00:00:00.063,598] <info> app: #1blk_count:1, erase_unit_dirty_blocks:255, erase_required:1
00> 
00> [00:00:00.063,598] <info> app: erase:addr:F000 block:120, id:15
00> 
00> [00:00:00.073,364] <info> app: Write req to block 129 size 2(x512) from 20001C04
00> 
00> [00:00:00.073,547] <info> app: Write req to block 127 size 2(x512) from 20001804
00> 
00> [00:00:00.074,584] <info> app: #1blk_count:1, erase_unit_dirty_blocks:0, erase_required:0
00> 
00> [00:00:00.074,584] <info> app: #0:erase_unit_dirty_blocks:0, erase_unit_idx:0xF
00> 
00> [00:00:00.074,584] <info> app: src:20004804, blk_size:512, dst:13000, block:152
00> 
00> [00:00:00.075,988] <info> app: Write req to block 129 size 2(x512) from 20001C04
00> 
00> [00:00:00.076,232] <info> app: Write req to block 127 size 2(x512) from 20001804
00> 
00> [00:00:00.077,209] <info> app: #1blk_count:1, erase_unit_dirty_blocks:255, erase_required:1
00> 
00> [00:00:00.077,209] <info> app: erase:addr:F000 block:120, id:15
00> 
00> [00:00:00.086,975] <info> app: Write req to block 129 size 2(x512) from 20001C04
00> 
00> [00:00:00.087,768] <info> app: Write req to block 63 size 1(x512) from 20001804
00> 
00> [00:00:00.088,806] <info> app: Read req from block 63 size 1(x512) to 20001804
00> 
00> [00:00:00.089,111] <info> app: Write req to block 16383 size 1(x512) from 20001804
00> 
00> [00:00:00.089,111] <info> app: writeback_mode:idx:0x7,dirty_blocks:255
00> 
00> [00:00:00.089,111] <info> app: erase:addr:7000 block:56, id:7
00> 
00> [00:00:00.098,876] <info> app: Read req from block 16383 size 1(x512) to 20001804
00> 
00> [00:00:00.099,365] <info> app: Write req to block 71 size 2(x512) from 20001804
00> 
00> [00:00:00.100,341] <info> app: #1blk_count:1, erase_unit_dirty_blocks:255, erase_required:1
00> 
00> [00:00:00.100,341] <info> app: erase:addr:8000 block:64, id:8
00> 
00> [00:00:00.110,656] <info> app: Write req to block 73 size 2(x512) from 20001C04
00> 
00> [00:00:00.110,839] <info> app: Write req to block 75 size 2(x512) from 20001804
00> 
00> [00:00:00.111,022] <info> app: Write req to block 77 size 2(x512) from 20001C04
00> 
00> [00:00:00.111,267] <info> app: Write req to block 79 size 2(x512) from 20001804
00> 
00> [00:00:00.111,267] <info> app: #1blk_count:1, erase_unit_dirty_blocks:255, erase_required:1
00> 
00> [00:00:00.111,267] <info> app: erase:addr:9000 block:72, id:9
00> 
00> [00:00:00.121,643] <info> app: Write req to block 81 size 2(x512) from 20001C04
00> 
00> [00:00:00.121,704] <info> app: Read req from block 71 size 2(x512) to 20001804
00> 
00> [00:00:00.121,948] <info> app: Read req from block 73 size 2(x512) to 20001C04
00> 
00> [00:00:00.122,253] <info> app: Read req from block 75 size 2(x512) to 20001804
00> 
00> [00:00:00.122,497] <info> app: Read req from block 77 size 2(x512) to 20001C04
00> 
00> [00:00:00.122,741] <info> app: Read req from block 79 size 2(x512) to 20001804
00> 
00> [00:00:00.123,046] <info> app: Read req from block 81 size 2(x512) to 20001C04
00> 
00> [00:00:00.123,596] <info> app: Write req to block 83 size 2(x512) from 20001804
00> 
00> [00:00:00.123,779] <info> app: Write req to block 85 size 2(x512) from 20001C04
00> 
00> [00:00:00.123,962] <info> app: Write req to block 87 size 2(x512) from 20001804
00> 
00> [00:00:00.123,962] <info> app: #1blk_count:1, erase_unit_dirty_blocks:255, erase_required:1
00> 
00> [00:00:00.123,962] <info> app: erase:addr:A000 block:80, id:10
00> 
00> [00:00:00.009,399] <info> app: Write req to block 89 size 2(x512) from 20001C04
00> 
00> [00:00:00.009,582] <info> app: Write req to block 91 size 2(x512) from 20001804
00> 
00> [00:00:00.009,826] <info> app: Write req to block 93 size 2(x512) from 20001C04
00> 
00> [00:00:00.009,887] <info> app: Read req from block 83 size 2(x512) to 20001804
00> 
00> [00:00:00.010,131] <info> app: Read req from block 85 size 2(x512) to 20001C04
00> 
00> [00:00:00.010,375] <info> app: Read req from block 87 size 2(x512) to 20001804
00> 
00> [00:00:00.010,681] <info> app: Read req from block 89 size 2(x512) to 20001C04
00> 
00> [00:00:00.010,925] <info> app: Read req from block 91 size 2(x512) to 20001804
00> 
00> [00:00:00.011,230] <info> app: Read req from block 93 size 2(x512) to 20001C04
00> 
00> [00:00:00.011,779] <info> app: Write req to block 95 size 2(x512) from 20001804
00> 
00> [00:00:00.011,779] <info> app: #1blk_count:1, erase_unit_dirty_blocks:255, erase_required:1
00> 
00> [00:00:00.011,779] <info> app: erase:addr:B000 block:88, id:11
00> 
00> [00:00:00.021,728] <info> app: Write req to block 97 size 2(x512) from 20001C04
00> 
00> [00:00:00.021,911] <info> app: Write req to block 99 size 2(x512) from 20001804
00> 
00> [00:00:00.022,094] <info> app: Write req to block 101 size 2(x512) from 20001C04
00> 
00> [00:00:00.022,338] <info> app: Write req to block 103 size 2(x512) from 20001804
00> 
00> [00:00:00.022,338] <info> app: #1blk_count:1, erase_unit_dirty_blocks:0, erase_required:0
00> 
00> [00:00:00.022,338] <info> app: #0:erase_unit_dirty_blocks:0, erase_unit_idx:0xC
00> 
00> [00:00:00.022,338] <info> app: src:20004804, blk_size:512, dst:10000, block:128
00> 
00> [00:00:00.023,498] <info> app: Write req to block 105 size 2(x512) from 20001C04
00> 
00> [00:00:00.023,681] <info> app: Write req to block 107 size 2(x512) from 20001804
00> 
00> [00:00:00.023,864] <info> app: Write req to block 109 size 2(x512) from 20001C04
00> 
00> [00:00:00.024,047] <info> app: Write req to block 111 size 2(x512) from 20001804
00> 
00> [00:00:00.024,047] <info> app: #1blk_count:1, erase_unit_dirty_blocks:0, erase_required:0
00> 
00> [00:00:00.024,047] <info> app: #0:erase_unit_dirty_blocks:0, erase_unit_idx:0xD
00> 
00> [00:00:00.024,047] <info> app: src:20004804, blk_size:512, dst:11000, block:136
00> 
00> [00:00:00.025,207] <info> app: Write req to block 113 size 2(x512) from 20001C04
00> 
00> [00:00:00.025,451] <info> app: Write req to block 115 size 2(x512) from 20001804
00> 
00> [00:00:00.025,573] <info> app: Write req to block 117 size 2(x512) from 20001C04
00> 
00> [00:00:00.025,756] <info> app: Write req to block 119 size 2(x512) from 20001804
00> 
00> [00:00:00.025,756] <info> app: #1blk_count:1, erase_unit_dirty_blocks:0, erase_required:0
00> 
00> [00:00:00.025,756] <info> app: #0:erase_unit_dirty_blocks:0, erase_unit_idx:0xE
00> 
00> [00:00:00.025,756] <info> app: src:20004804, blk_size:512, dst:12000, block:144
00> 
00> [00:00:00.027,221] <info> app: Write req to block 121 size 2(x512) from 20001C04
00> 
00> [00:00:00.027,404] <info> app: Write req to block 123 size 2(x512) from 20001804
00> 
00> [00:00:00.027,526] <info> app: Write req to block 125 size 2(x512) from 20001C04
00> 
00> [00:00:00.027,587] <info> app: Read req from block 95 size 2(x512) to 20001804
00> 
00> [00:00:00.027,832] <info> app: Read req from block 97 size 2(x512) to 20001C04
00> 
00> [00:00:00.028,137] <info> app: Read req from block 99 size 2(x512) to 20001804
00> 
00> [00:00:00.028,381] <info> app: Read req from block 101 size 2(x512) to 20001C04
00> 
00> [00:00:00.028,686] <info> app: Read req from block 103 size 2(x512) to 20001804
00> 
00> [00:00:00.028,930] <info> app: Read req from block 105 size 2(x512) to 20001C04
00> 
00> [00:00:00.029,174] <info> app: Read req from block 107 size 2(x512) to 20001804
00> 
00> [00:00:00.029,479] <info> app: Read req from block 109 size 2(x512) to 20001C04
00> 
00> [00:00:00.029,724] <info> app: Read req from block 111 size 2(x512) to 20001804
00> 
00> [00:00:00.030,029] <info> app: Read req from block 113 size 2(x512) to 20001C04
00> 
00> [00:00:00.030,273] <info> app: Read req from block 115 size 2(x512) to 20001804
00> 
00> [00:00:00.030,517] <info> app: Read req from block 117 size 2(x512) to 20001C04
00> 
00> [00:00:00.030,822] <info> app: Read req from block 119 size 2(x512) to 20001804
00> 
00> [00:00:00.031,066] <info> app: Read req from block 121 size 2(x512) to 20001C04
00> 
00> [00:00:00.031,372] <info> app: Read req from block 123 size 2(x512) to 20001804
00> 
00> [00:00:00.031,616] <info> app: Read req from block 125 size 2(x512) to 20001C04
00> 
00> [00:00:00.032,226] <info> app: Write req to block 63 size 2(x512) from 20001804
00> 
00> [00:00:00.033,264] <info> app: #1blk_count:1, erase_unit_dirty_blocks:255, erase_required:1
00> 
00> [00:00:00.033,264] <info> app: erase:addr:7000 block:56, id:7
00> 
00> [00:00:00.042,785] <info> app: Write req to block 65 size 2(x512) from 20001C04
00> 
00> [00:00:00.042,968] <info> app: Write req to block 67 size 2(x512) from 20001804
00> 
00> [00:00:00.043,151] <info> app: Write req to block 69 size 2(x512) from 20001C04
00> 
00> [00:00:00.043,212] <info> app: Read req from block 63 size 2(x512) to 20001804
00> 
00> [00:00:00.043,518] <info> app: Read req from block 65 size 2(x512) to 20001C04
00> 
00> [00:00:00.043,762] <info> app: Read req from block 67 size 2(x512) to 20001804
00> 
00> [00:00:00.044,067] <info> app: Read req from block 69 size 2(x512) to 20001C04
00> 
00> [00:00:00.044,555] <info> app: Read req from block 0 size 1(x512) to 20001804
00> 
00> [00:00:00.044,738] <info> app: Read req from block 0 size 1(x512) to 20001804
00> 
00> [00:00:00.045,043] <info> app: Write req to block 0 size 1(x512) from 20001804
00> 
00> [00:00:00.046,142] <info> app: Read req from block 0 size 1(x512) to 20001804
00> 
00> [00:00:00.046,508] <info> app: Read req from block 0 size 1(x512) to 20001804
00> 
00> [00:00:00.046,752] <info> app: Read req from block 63 size 2(x512) to 20001804
00> 
00> [00:00:00.047,058] <info> app: Read req from block 65 size 2(x512) to 20001C04
00> 
00> [00:00:00.047,302] <info> app: Read req from block 67 size 2(x512) to 20001804
00> 
00> [00:00:00.047,546] <info> app: Read req from block 69 size 2(x512) to 20001C04
00> 
00> [00:00:00.047,973] <info> app: Read req from block 71 size 2(x512) to 20001804
00> 
00> [00:00:00.048,278] <info> app: Read req from block 73 size 2(x512) to 20001C04
00> 
00> [00:00:00.048,522] <info> app: Read req from block 75 size 2(x512) to 20001804
00> 
00> [00:00:00.048,828] <info> app: Read req from block 77 size 2(x512) to 20001C04
00> 
00> [00:00:00.049,194] <info> app: Read req from block 79 size 2(x512) to 20001804
00> 
00> [00:00:00.049,499] <info> app: Read req from block 81 size 2(x512) to 20001C04
00> 
00> [00:00:00.049,743] <info> app: Read req from block 83 size 2(x512) to 20001804
00> 
00> [00:00:00.049,987] <info> app: Read req from block 85 size 2(x512) to 20001C04
00> 
00> [00:00:00.050,415] <info> app: Read req from block 95 size 2(x512) to 20001804
00> 
00> [00:00:00.050,659] <info> app: Read req from block 97 size 2(x512) to 20001C04
00> 
00> [00:00:00.050,964] <info> app: Read req from block 99 size 2(x512) to 20001804
00> 
00> [00:00:00.051,208] <info> app: Read req from block 101 size 2(x512) to 20001C04
00> 
00> [00:00:00.051,879] <info> app: Read req from block 2 size 1(x512) to 20001804
00> 
00> [00:00:00.052,429] <info> app: Read req from block 63 size 2(x512) to 20001804
00> 
00> [00:00:00.052,673] <info> app: Read req from block 65 size 2(x512) to 20001C04
00> 
00> [00:00:00.052,978] <info> app: Read req from block 67 size 2(x512) to 20001804
00> 
00> [00:00:00.053,222] <info> app: Read req from block 69 size 2(x512) to 20001C04
00> 
00> [00:00:00.053,527] <info> app: Read req from block 71 size 2(x512) to 20001804
00> 
00> [00:00:00.053,771] <info> app: Read req from block 73 size 2(x512) to 20001C04
00> 
00> [00:00:00.054,016] <info> app: Read req from block 75 size 2(x512) to 20001804
00> 
00> [00:00:00.054,321] <info> app: Read req from block 77 size 2(x512) to 20001C04
00> 
00> [00:00:00.054,748] <info> app: Read req from block 127 size 2(x512) to 20001804
00> 
00> [00:00:00.054,992] <info> app: Read req from block 129 size 2(x512) to 20001C04
00> 
00> [00:00:00.055,603] <info> app: Write req to block 95 size 2(x512) from 20001804
00> 
00> [00:00:00.056,579] <info> app: #1blk_count:1, erase_unit_dirty_blocks:255, erase_required:1
00> 
00> [00:00:00.056,579] <info> app: erase:addr:B000 block:88, id:11
00> 
00> [00:00:00.066,589] <info> app: Write req to block 97 size 2(x512) from 20001C04
00> 
00> [00:00:00.066,772] <info> app: Write req to block 99 size 2(x512) from 20001804
00> 
00> [00:00:00.066,955] <info> app: Write req to block 101 size 2(x512) from 20001C04
00> 
00> [00:00:00.066,955] <info> app: Read req from block 0 size 1(x512) to 20001804
00> 
00> [00:00:00.067,260] <info> app: Write req to block 71 size 1(x512) from 20001804
00> 
00> [00:00:00.068,359] <info> app: Write req to block 83 size 1(x512) from 20001804
00> 
00> [00:00:00.068,359] <info> app: writeback_mode:idx:0x8,dirty_blocks:255
00> 
00> [00:00:00.068,359] <info> app: erase:addr:8000 block:64, id:8
00> 
00> [00:00:00.078,735] <info> app: Write req to block 127 size 2(x512) from 20001804
00> 
00> [00:00:00.078,735] <info> app: writeback_mode:idx:0xA,dirty_blocks:255
00> 
00> [00:00:00.078,735] <info> app: erase:addr:A000 block:80, id:10
00> 
00> [00:00:00.088,806] <info> app: #1blk_count:1, erase_unit_dirty_blocks:255, erase_required:1
00> 
00> [00:00:00.088,806] <info> app: erase:addr:F000 block:120, id:15
00> 
00> [00:00:00.098,693] <info> app: Write req to block 129 size 2(x512) from 20001C04
00> 
00> [00:00:00.098,937] <info> app: Write req to block 127 size 2(x512) from 20001804
00> 
00> [00:00:00.099,975] <info> app: #1blk_count:1, erase_unit_dirty_blocks:255, erase_required:1
00> 
00> [00:00:00.099,975] <info> app: erase:addr:F000 block:120, id:15
00> 
00> [00:00:00.109,741] <info> app: Write req to block 129 size 2(x512) from 20001C04
00> 
00> [00:00:00.109,741] <info> app: Read req from block 0 size 1(x512) to 20001804
00> 
00> [00:00:00.109,985] <info> app: Read req from block 63 size 2(x512) to 20001804
00> 
00> [00:00:00.110,229] <info> app: Read req from block 65 size 2(x512) to 20001C04
00> 
00> [00:00:00.110,534] <info> app: Read req from block 67 size 2(x512) to 20001804
00> 
00> [00:00:00.110,778] <info> app: Read req from block 69 size 2(x512) to 20001C04
00> 
00> [00:00:00.111,022] <info> app: Read req from block 71 size 2(x512) to 20001804
00> 
00> [00:00:00.111,328] <info> app: Read req from block 73 size 2(x512) to 20001C04
00> 
00> [00:00:00.111,572] <info> app: Read req from block 75 size 2(x512) to 20001804
00> 
00> [00:00:00.111,877] <info> app: Read req from block 77 size 2(x512) to 20001C04
00> 
00> [00:00:00.112,426] <info> app: Write req to block 127 size 2(x512) from 20001804
00> 
00> [00:00:00.113,403] <info> app: #1blk_count:1, erase_unit_dirty_blocks:255, erase_required:1
00> 
00> [00:00:00.113,403] <info> app: erase:addr:F000 block:120, id:15
00> 
00> [00:00:00.123,168] <info> app: Write req to block 129 size 2(x512) from 20001C04
00> 
00> [00:00:00.123,413] <info> app: Write req to block 127 size 2(x512) from 20001804
00> 
00> [00:00:00.124,450] <info> app: #1blk_count:1, erase_unit_dirty_blocks:255, erase_required:1
00> 
00> [00:00:00.124,450] <info> app: erase:addr:F000 block:120, id:15
00> 
00> [00:00:00.009,033] <info> app: Write req to block 129 size 2(x512) from 20001C04
00> 
00> [00:00:00.009,094] <info> app: Read req from block 0 size 1(x512) to 20001804
00> 
00> [00:00:00.009,460] <info> app: Write req to block 127 size 2(x512) from 20001804
00> 
00> [00:00:00.010,498] <info> app: #1blk_count:1, erase_unit_dirty_blocks:0, erase_required:0
00> 
00> [00:00:00.010,498] <info> app: #0:erase_unit_dirty_blocks:0, erase_unit_idx:0xF
00> 
00> [00:00:00.010,498] <info> app: src:20004804, blk_size:512, dst:13000, block:152
00> 
00> [00:00:00.011,657] <info> app: Write req to block 129 size 2(x512) from 20001C04
00> 
00> [00:00:00.011,779] <info> app: Write req to block 135 size 1(x512) from 20001804
00> 
00> [00:00:00.011,901] <info> app: Write req to block 131 size 1(x512) from 20001804
00> 
00> [00:00:00.012,023] <info> app: Write req to block 71 size 1(x512) from 20001804
00> 
00> [00:00:00.012,023] <info> app: writeback_mode:idx:0x10,dirty_blocks:255
00> 
00> [00:00:00.012,023] <info> app: erase:addr:10000 block:128, id:16
00> 
00> [00:00:00.021,728] <info> app: Write req to block 83 size 1(x512) from 20001804
00> 
00> [00:00:00.021,728] <info> app: writeback_mode:idx:0x8,dirty_blocks:255
00> 
00> [00:00:00.021,728] <info> app: erase:addr:8000 block:64, id:8
00> 
00> [00:00:00.031,921] <info> app: Read req from block 0 size 1(x512) to 20001804
00> 
00> [00:00:00.032,104] <info> app: Read req from block 63 size 2(x512) to 20001804
00> 
00> [00:00:00.032,409] <info> app: Read req from block 65 size 2(x512) to 20001C04
00> 
00> [00:00:00.032,653] <info> app: Read req from block 67 size 2(x512) to 20001804
00> 
00> [00:00:00.032,897] <info> app: Read req from block 69 size 2(x512) to 20001C04
00> 
00> [00:00:00.033,203] <info> app: Read req from block 71 size 2(x512) to 20001804
00> 
00> [00:00:00.033,447] <info> app: Read req from block 73 size 2(x512) to 20001C04
00> 
00> [00:00:00.033,691] <info> app: Read req from block 75 size 2(x512) to 20001804
00> 
00> [00:00:00.033,996] <info> app: Read req from block 77 size 2(x512) to 20001C04
00> 
00> [00:00:00.034,545] <info> app: Read req from block 63 size 1(x512) to 20001804
00>

      2.After formating the disk via the PC,  copy a file to the MSC via the PC 

      00> [00:00:00.052,978] <info> app: Write req to block 1195 size 2(x512) from 20001804
00> 
00> [00:00:00.053,161] <info> app: Write req to block 1197 size 2(x512) from 20001C04
00> 
00> [00:00:00.053,283] <info> app: Write req to block 1199 size 1(x512) from 20001804
00> 
00> [00:00:00.053,466] <info> app: Write req to block 95 size 2(x512) from 20001804
00> 
00> [00:00:00.053,466] <info> app: writeback_mode:idx:0x95,dirty_blocks:255
00> 
00> [00:00:00.053,466] <info> app: erase:addr:95000 block:1192, id:149
00> 
00> [00:00:00.062,622] <info> app: #1blk_count:1, erase_unit_dirty_blocks:255, erase_required:1
00> 
00> [00:00:00.062,622] <info> app: erase:addr:B000 block:88, id:11
00> 
00> [00:00:00.072,570] <info> app: Write req to block 97 size 2(x512) from 20001C04
00> 
00> [00:00:00.072,753] <info> app: Write req to block 99 size 2(x512) from 20001804
00> 
00> [00:00:00.072,937] <info> app: Write req to block 101 size 2(x512) from 20001C04
00> 
00> [00:00:00.073,242] <info> app: Write req to block 95 size 2(x512) from 20001804
00> 
00> [00:00:00.074,279] <info> app: #1blk_count:1, erase_unit_dirty_blocks:0, erase_required:0
00> 
00> [00:00:00.074,279] <info> app: #0:erase_unit_dirty_blocks:0, erase_unit_idx:0xB
00> 
00> [00:00:00.074,279] <info> app: src:20004804, blk_size:512, dst:F000, block:120
00> 
00> [00:00:00.075,439] <info> app: Write req to block 97 size 2(x512) from 20001C04
00> 
00> [00:00:00.075,622] <info> app: Write req to block 99 size 2(x512) from 20001804
00> 
00> [00:00:00.075,805] <info> app: Write req to block 101 size 2(x512) from 20001C04

      3. Press button 3 to format the disk, and then connect to the PC, you can see some write operation from PC, what I understand, it should have read operation only.

      00> [00:00:00.123,291] <info> app: USB power detected
00> 
00> [00:00:00.123,291] <info> app: Un-initializing disk 0 (QSPI)...
00> 
00> [00:00:00.123,291] <info> app: USB ready
00> 
00> [00:00:00.020,629] <info> app: Read req from block 0 size 1(x512) to 20001804
00> 
00> [00:00:00.020,996] <info> app: Read req from block 2 size 1(x512) to 20001804
00> 
00> [00:00:00.021,301] <info> app: Read req from block 0 size 1(x512) to 20001804
00> 
00> [00:00:00.021,484] <info> app: Read req from block 63 size 1(x512) to 20001804
00> 
00> [00:00:00.021,972] <info> app: Read req from block 0 size 1(x512) to 20001804
00> 
00> [00:00:00.022,277] <info> app: Read req from block 0 size 1(x512) to 20001804
00> 
00> [00:00:00.022,460] <info> app: Read req from block 63 size 2(x512) to 20001804
00> 
00> [00:00:00.022,766] <info> app: Read req from block 65 size 2(x512) to 20001C04
00> 
00> [00:00:00.023,010] <info> app: Read req from block 67 size 2(x512) to 20001804
00> 
00> [00:00:00.023,315] <info> app: Read req from block 69 size 2(x512) to 20001C04
00> 
00> [00:00:00.023,559] <info> app: Read req from block 71 size 2(x512) to 20001804
00> 
00> [00:00:00.023,803] <info> app: Read req from block 73 size 2(x512) to 20001C04
00> 
00> [00:00:00.024,108] <info> app: Read req from block 75 size 2(x512) to 20001804
00> 
00> [00:00:00.024,353] <info> app: Read req from block 77 size 2(x512) to 20001C04
00> 
00> [00:00:00.024,902] <info> app: Read req from block 0 size 1(x512) to 20001804
00> 
00> [00:00:00.025,146] <info> app: Read req from block 63 size 2(x512) to 20001804
00> 
00> [00:00:00.025,451] <info> app: Read req from block 65 size 2(x512) to 20001C04
00> 
00> [00:00:00.025,695] <info> app: Read req from block 67 size 2(x512) to 20001804
00> 
00> [00:00:00.026,000] <info> app: Read req from block 69 size 2(x512) to 20001C04
00> 
00> [00:00:00.026,367] <info> app: Read req from block 71 size 2(x512) to 20001804
00> 
00> [00:00:00.026,672] <info> app: Read req from block 73 size 2(x512) to 20001C04
00> 
00> [00:00:00.026,916] <info> app: Read req from block 75 size 2(x512) to 20001804
00> 
00> [00:00:00.027,160] <info> app: Read req from block 77 size 2(x512) to 20001C04
00> 
00> [00:00:00.027,465] <info> app: Read req from block 79 size 2(x512) to 20001804
00> 
00> [00:00:00.027,709] <info> app: Read req from block 81 size 2(x512) to 20001C04
00> 
00> [00:00:00.028,015] <info> app: Read req from block 83 size 2(x512) to 20001804
00> 
00> [00:00:00.028,259] <info> app: Read req from block 85 size 2(x512) to 20001C04
00> 
00> [00:00:00.028,503] <info> app: Read req from block 87 size 2(x512) to 20001804
00> 
00> [00:00:00.028,808] <info> app: Read req from block 89 size 2(x512) to 20001C04
00> 
00> [00:00:00.029,052] <info> app: Read req from block 91 size 2(x512) to 20001804
00> 
00> [00:00:00.029,357] <info> app: Read req from block 93 size 2(x512) to 20001C04
00> 
00> [00:00:00.029,602] <info> app: Read req from block 95 size 2(x512) to 20001804
00> 
00> [00:00:00.029,846] <info> app: Read req from block 97 size 2(x512) to 20001C04
00> 
00> [00:00:00.030,151] <info> app: Read req from block 99 size 2(x512) to 20001804
00> 
00> [00:00:00.030,395] <info> app: Read req from block 101 size 2(x512) to 20001C04
00> 
00> [00:00:00.030,822] <info> app: Read req from block 96 size 2(x512) to 20001804
00> 
00> [00:00:00.031,066] <info> app: Read req from block 98 size 2(x512) to 20001C04
00> 
00> [00:00:00.031,372] <info> app: Read req from block 100 size 2(x512) to 20001804
00> 
00> [00:00:00.031,616] <info> app: Read req from block 102 size 2(x512) to 20001C04
00> 
00> [00:00:00.032,226] <info> app: Read req from block 2 size 1(x512) to 20001804
00> 
00> [00:00:00.032,836] <info> app: Read req from block 63 size 2(x512) to 20001804
00> 
00> [00:00:00.033,081] <info> app: Read req from block 65 size 2(x512) to 20001C04
00> 
00> [00:00:00.033,325] <info> app: Read req from block 67 size 2(x512) to 20001804
00> 
00> [00:00:00.033,630] <info> app: Read req from block 69 size 2(x512) to 20001C04
00> 
00> [00:00:00.033,874] <info> app: Read req from block 71 size 2(x512) to 20001804
00> 
00> [00:00:00.034,179] <info> app: Read req from block 73 size 2(x512) to 20001C04
00> 
00> [00:00:00.034,423] <info> app: Read req from block 75 size 2(x512) to 20001804
00> 
00> [00:00:00.034,667] <info> app: Read req from block 77 size 2(x512) to 20001C04
00> 
00> [00:00:00.035,217] <info> app: Write req to block 63 size 1(x512) from 20001804
00> 
00> [00:00:00.036,254] <info> app: Read req from block 0 size 1(x512) to 20001804
00> 
00> [00:00:00.036,499] <info> app: Read req from block 128 size 2(x512) to 20001804
00> 
00> [00:00:00.037,048] <info> app: Write req to block 96 size 2(x512) from 20001804
00> 
00> [00:00:00.037,048] <info> app: writeback_mode:idx:0x7,dirty_blocks:255
00> 
00> [00:00:00.037,048] <info> app: erase:addr:7000 block:56, id:7
00> 
00> [00:00:00.046,813] <info> app: Write req to block 98 size 2(x512) from 20001C04
00> 
00> [00:00:00.046,997] <info> app: Write req to block 100 size 2(x512) from 20001804
00> 
00> [00:00:00.047,180] <info> app: Write req to block 102 size 2(x512) from 20001C04
00> 
00> [00:00:00.047,302] <info> app: Write req to block 64 size 1(x512) from 20001804
00> 
00> [00:00:00.047,302] <info> app: writeback_mode:idx:0xC,dirty_blocks:255
00> 
00> [00:00:00.047,302] <info> app: erase:addr:C000 block:96, id:12
00> 
00> [00:00:00.057,312] <info> app: Read req from block 0 size 1(x512) to 20001804
00> 
00> [00:00:00.057,678] <info> app: Write req to block 128 size 2(x512) from 20001804
00> 
00> [00:00:00.057,678] <info> app: writeback_mode:idx:0x8,dirty_blocks:255
00> 
00> [00:00:00.057,678] <info> app: erase:addr:8000 block:64, id:8
00> 
00> [00:00:00.067,810] <info> app: Write req to block 63 size 1(x512) from 20001804
00> 
00> [00:00:00.067,810] <info> app: writeback_mode:idx:0x10,dirty_blocks:255
00> 
00> [00:00:00.067,810] <info> app: erase:addr:10000 block:128, id:16
00> 
00> [00:00:00.077,392] <info> app: Read req from block 0 size 1(x512) to 20001804
00> 
00> [00:00:00.077,697] <info> app: Write req to block 64 size 1(x512) from 20001804
00> 
00> [00:00:00.077,697] <info> app: writeback_mode:idx:0x7,dirty_blocks:255
00> 
00> [00:00:00.077,697] <info> app: erase:addr:7000 block:56, id:7
00> 
00> [00:00:00.087,585] <info> app: Write req to block 128 size 2(x512) from 20001804
00> 
00> [00:00:00.087,585] <info> app: writeback_mode:idx:0x8,dirty_blocks:255
00> 
00> [00:00:00.087,585] <info> app: erase:addr:8000 block:64, id:8
00> 
00> [00:00:00.097,778] <info> app: Read req from block 0 size 1(x512) to 20001804
00> 
00> [00:00:00.098,083] <info> app: Write req to block 63 size 1(x512) from 20001804
00> 
00> [00:00:00.098,083] <info> app: writeback_mode:idx:0x10,dirty_blocks:255
00> 
00> [00:00:00.098,083] <info> app: erase:addr:10000 block:128, id:16
00> 
00> [00:00:00.107,788] <info> app: Write req to block 128 size 2(x512) from 20001804
00> 
00> [00:00:00.107,788] <info> app: writeback_mode:idx:0x7,dirty_blocks:255
00> 
00> [00:00:00.107,788] <info> app: erase:addr:7000 block:56, id:7
00> 
00> [00:00:00.117,675] <info> app: Write req to block 64 size 1(x512) from 20001804
00> 
00> [00:00:00.117,675] <info> app: writeback_mode:idx:0x10,dirty_blocks:255
00> 
00> [00:00:00.117,675] <info> app: erase:addr:10000 block:128, id:16
00> 
00> [00:00:00.002,136] <info> app: Read req from block 63 size 1(x512) to 20001804
00> 
00> [00:00:00.002,502] <info> app: Write req to block 63 size 1(x512) from 20001804
00> 
00> [00:00:00.002,502] <info> app: writeback_mode:idx:0x8,dirty_blocks:255
00> 
00> [00:00:00.002,502] <info> app: erase:addr:8000 block:64, id:8
00> 
00> [00:00:00.012,756] <info> app: Write req to block 64 size 1(x512) from 20001804
00> 
00> [00:00:00.012,756] <info> app: writeback_mode:idx:0x7,dirty_blocks:255
00> 
00> [00:00:00.012,756] <info> app: erase:addr:7000 block:56, id:7
00> 
00> [00:00:00.022,338] <info> app: Read req from block 63 size 2(x512) to 20001804
00> 
00> [00:00:00.022,583] <info> app: Read req from block 65 size 2(x512) to 20001C04
00> 
00> [00:00:00.022,888] <info> app: Read req from block 67 size 2(x512) to 20001804
00> 
00> [00:00:00.023,132] <info> app: Read req from block 69 size 2(x512) to 20001C04
00> 
00> [00:00:00.023,437] <info> app: Read req from block 71 size 2(x512) to 20001804
00> 
00> [00:00:00.023,681] <info> app: Read req from block 73 size 2(x512) to 20001C04
00> 
00> [00:00:00.023,986] <info> app: Read req from block 75 size 2(x512) to 20001804
00> 
00> [00:00:00.024,230] <info> app: Read req from block 77 size 2(x512) to 20001C04
00> 
00> [00:00:00.024,780] <info> app: Write req to block 130 size 1(x512) from 20001804
00> 
00> [00:00:00.024,780] <info> app: writeback_mode:idx:0x8,dirty_blocks:255
00> 
00> [00:00:00.024,780] <info> app: erase:addr:8000 block:64, id:8
00> 
00> [00:00:00.035,095] <info> app: Write req to block 128 size 2(x512) from 20001804
00> 
00> [00:00:00.035,217] <info> app: Write req to block 64 size 1(x512) from 20001804
00> 
00> [00:00:00.035,217] <info> app: writeback_mode:idx:0x10,dirty_blocks:255
00> 
00> [00:00:00.035,217] <info> app: erase:addr:10000 block:128, id:16
00> 
00> [00:00:00.044,921] <info> app: Write req to block 128 size 2(x512) from 20001804
00> 
00> [00:00:00.044,921] <info> app: writeback_mode:idx:0x8,dirty_blocks:255
00> 
00> [00:00:00.044,921] <info> app: erase:addr:8000 block:64, id:8
00> 
00> [00:00:00.055,175] <info> app: Write req to block 63 size 1(x512) from 20001804
00> 
00> [00:00:00.056,335] <info> app: Write req to block 132 size 1(x512) from 20001804
00> 
00> [00:00:00.056,335] <info> app: writeback_mode:idx:0x7,dirty_blocks:255
00> 
00> [00:00:00.056,335] <info> app: erase:addr:7000 block:56, id:7
00> 
00> [00:00:00.066,223] <info> app: Write req to block 128 size 2(x512) from 20001804
00> 
00> [00:00:00.066,467] <info> app: Write req to block 128 size 2(x512) from 20001804
00> 
00> [00:00:00.066,528] <info> app: Write req to block 64 size 1(x512) from 20001804
00> 
00> [00:00:00.066,528] <info> app: writeback_mode:idx:0x10,dirty_blocks:255
00> 
00> [00:00:00.066,528] <info> app: erase:addr:10000 block:128, id:16
00> 
00> [00:00:00.076,416] <info> app: Write req to block 63 size 1(x512) from 20001804
00> 
00> [00:00:00.076,416] <info> app: writeback_mode:idx:0x8,dirty_blocks:255
00> 
00> [00:00:00.076,416] <info> app: erase:addr:8000 block:64, id:8
00> 
00> [00:00:00.086,669] <info> app: Write req to block 64 size 1(x512) from 20001804
00> 
00> [00:00:00.086,669] <info> app: writeback_mode:idx:0x7,dirty_blocks:255
00> 
00> [00:00:00.086,669] <info> app: erase:addr:7000 block:56, id:7
00> 
00> [00:00:00.096,435] <info> app: Read req from block 63 size 2(x512) to 20001804
00> 
00> [00:00:00.096,679] <info> app: Read req from block 65 size 2(x512) to 20001C04
00> 
00> [00:00:00.096,984] <info> app: Read req from block 67 size 2(x512) to 20001804
00> 
00> [00:00:00.097,229] <info> app: Read req from block 69 size 2(x512) to 20001C04
00> 
00> [00:00:00.097,534] <info> app: Read req from block 71 size 2(x512) to 20001804
00> 
00> [00:00:00.097,839] <info> app: Read req from block 73 size 2(x512) to 20001C04
00> 
00> [00:00:00.098,083] <info> app: Read req from block 75 size 2(x512) to 20001804
00> 
00> [00:00:00.098,327] <info> app: Read req from block 77 size 2(x512) to 20001C04
00>

      I attached the project file below .

      Please replace the nrf_block_dev_qspi.c of the SDK, I use RTT for logging output and  test on the nRF5_SDK_17.0.2.

    • 0 in reply to user85932

      Hi,

      I have asked the maintainers to review the logs and provide input. I will let you know when we have something.

      Einar

    • 0 in reply to user7377

      Hi Einar, 

      One more finding.

      1.Plug the USB into the PC and create a new file from the PC

      2. Disconnect the USB, and plug the USB into the PC again, the PC pops up the following message.

    • 0 in reply to user85932

      Thanks for the update. I do not have any news from my side atm.

    • 0 in reply to user7377

      Hi,

      Have you had any progress on this issue on your side?

      I had a meeting with the R&D team responsible for this yesterday, and the current state is that after a thorough inspection of the code we cannot see an issue with the blockdevice code that would result in the observed corruption. In other words, we cannot see by analysis, a code path that would result in this. This does not mean that we have ruled out that there is an issue.

      As we are not able to reproduce the corruption itself, we suggest that we provide you with a modified library that has instrumentation to detect some unexpected changes/states/behaviors. Would you be willing to use that in our testing to help narrow down the issue?

      Another hypothesis that came up was that there could be a reentrancy issue where you call from multiple interrupt contexts (into the blockdevice code. Could that be the case?

    Related
    Terms of service