drivers/misc/block_cache: Add block driver which can add caching to e… by g2gps · Pull Request #10478 · apache/nuttx

g2gps · 2023-09-04T12:23:30Z

Summary

Adds an optional driver which can be used to encapsulate and existing block device and provide caching using a runtime registered configuration.

A few things to note:

The driver includes no automatic flushing, like the generic rwbuffer. Dirty blocks are only flushed on close, when the reference count reaches zero. or in response to a BIOC_FLUSH IOCTL command.
Given the above, it's probably not suitable for removable media.
I've outlined the caching strategy in block_cache.h. It's not the latest and greatest strategy, but it provides a significant performance improvement. We're going to be using this internally, so improvement and fixes will come over time.
I'm not entirely sure if I've placed the driver in the correct location, or if the driver registration method is the most appropriate, but it works.

In general this directly addresses the issues in #9080, but given the enhancement, it would be nice to get this integrated so it's available to the wider community.

Impact

Greatly improves the performance of block devices, assuming sufficient RAM is available.

A summary from #9080, of the speeds I was seeing without caching:

# Write speeds
nsh> dd if=/dev/zero of=/dev/sd0 bs=64 count=1000
64000 bytes copied, 647623 usec, 96 KB/s
nsh> dd if=/dev/zero of=/dev/sd0 bs=512 count=100
51200 bytes copied, 295710 usec, 169 KB/s
nsh> dd if=/dev/zero of=/dev/sd0 bs=4096 count=100
409600 bytes copied, 935538 usec, 427 KB/s
nsh> dd if=/dev/zero of=/dev/sd0 bs=16384 count=100
1638400 bytes copied, 1085459 usec, 1474 KB/s
nsh> dd if=/dev/zero of=/dev/sd0 bs=65536 count=100
6553600 bytes copied, 1515564 usec, 4222 KB/s

# Read speeds:
nsh> dd if=/dev/sd0 of=/dev/null bs=64 count=100
6400 bytes copied, 34671 usec, 180 KB/s
nsh> dd if=/dev/sd0 of=/dev/null bs=512 count=100
51200 bytes copied, 162573 usec, 307 KB/s
nsh> dd if=/dev/sd0 of=/dev/null bs=4096 count=100
409600 bytes copied, 290912 usec, 1374 KB/s
nsh> dd if=/dev/sd0 of=/dev/null bs=16384 count=100
1638400 bytes copied, 292429 usec, 5471 KB/s
nsh> dd if=/dev/sd0 of=/dev/null bs=65536 count=100
6553600 bytes copied, 672012 usec, 9523 KB/s

With caching:

# Write speeds
nsh> dd if=/dev/zero of=/mnt/test bs=64 count=1000
64000 bytes copied, 411442 usec, 151 KB/s
nsh> dd if=/dev/zero of=/mnt/test bs=512 count=100
51200 bytes copied, 45271 usec, 1104 KB/s
nsh> dd if=/dev/zero of=/mnt/test bs=4096 count=100
409600 bytes copied, 63529 usec, 6296 KB/s
dd if=/dev/zero of=/mnt/test bs=16384 count=100
1638400 bytes copied, 122956 usec, 13012 KB/s
nsh> dd if=/dev/zero of=/mnt/test bs=65536 count=100
6553600 bytes copied, 2976539 usec, 2150 KB/s

# Read speeds
nsh> dd if=/mnt/test of=/dev/null bs=64 count=100
6400 bytes copied, 41172 usec, 151 KB/s
nsh> dd if=/mnt/test of=/dev/null bs=512 count=100
51200 bytes copied, 45931 usec, 1088 KB/s
nsh> dd if=/mnt/test of=/dev/null bs=4096 count=100
409600 bytes copied, 62407 usec, 6409 KB/s
nsh> dd if=/mnt/test of=/dev/null bs=16384 count=100
1638400 bytes copied, 104206 usec, 15354 KB/s
nsh> dd if=/mnt/test of=/dev/null bs=65536 count=100
6553600 bytes copied, 1331805 usec, 4805 KB/s

# Copy speeds
nsh> dd if=test of=test2 bs=512 count=100
51200 bytes copied, 62416 usec, 801 KB/s
nsh> dd if=test of=test2 bs=4096 count=100
409600 bytes copied, 97481 usec, 4103 KB/s
nsh> dd if=test of=test2 bs=16384 count=100
1638400 bytes copied, 1174449 usec, 1362 KB/s
nsh> dd if=test of=test2 bs=65536 count=100
6553600 bytes copied, 4261865 usec, 1501 KB/s

Notes:

The previous tests (from littlefs on SD/eMMC read/write performance is poor #9080) were using a block to character to device, and no filesystem.
The current tests use a FAT filesystem.
The tests with the largest 65K (16K for copy) block sizes exhaust the 2M cache size I'm allocated, so the driver is evicting dirty cache windows to the underlying EMMC, thus performance is slower.

For my cached tests, I was using 32x64KB cache windows, and exposing the driver in 4KB blocks. I.e, it was initialized as follows:

  ret = block_cache_initialize(
      "/dev/mmcsd0",
      "/dev/bmmcsd0",
      128,                   // 64KB cache width
      32,                    // 32 cache sections
      8                      // Expose the EMMC device in 4K blocks

This may not be the 'golden' configuration, it's just a starting point.

Testing

I have local version of sdbench and sdstress from PX4-autopilot, along with our custom applications which I've been using for testing and verification. So far, everything seems to work fine, but there could be unforeseen issues here, thus the current 'draft' status.

Donny9 · 2023-09-04T13:53:16Z

@g2gps you can use fstest, block test or md5 big file to test this pr.

xiaoxiang781216 · 2023-09-04T15:25:22Z

I have local version of sdbench and sdstress from PX4-autopilot, along with our custom applications which I've been using for testing and verification. So far, everything seems to work fine, but there could be unforeseen issues here, thus the current 'draft' status.

how about port sdbench and sdstress back to nuttx/apps?

acassis · 2023-09-04T21:37:50Z

@g2gps any idea why for 64KB block the write performance with copy it worst? Is it because maybe cache misses?

BTW, please add an entry in our https://nuttx.apache.org/docs/latest/components/drivers/block/index.html# Doc to say this feature exists (otherwise it will be a "hidden feature")

g2gps · 2023-09-05T00:53:13Z

@g2gps any idea why for 64KB block the write performance with copy it worst? Is it because maybe cache misses?

It's because the amount of data copied is larger than the total cache size I've allocated, so the cached block driver needs to start unloading dirty blocks to the underlying EMMC. If I repeat the test with a smaller file, the 64KB block size is faster.

nsh> dd if=/dev/zero of=test3 bs=65536 count=16
1048576 bytes copied, 65856 usec, 15549 KB/s
nsh> dd if=test3 of=test4 bs=65536
1048576 bytes copied, 313765 usec, 3263 KB/s

In general, the performance of a read/write/copy operation is going to depend on if the data is already cached, and when it is not, if any existing cached data has been marked dirty and needs to be synchronised.

g2gps · 2023-09-05T00:58:37Z

how about port sdbench and sdstress back to nuttx/apps?

I don't mind pushing what I have back up, I'm just not sure on licencing requirements. Do we need to include both licences, get permission from PX4?

g2gps · 2023-09-05T06:41:54Z

@Donny9 Final results of fstest -n 10 -m /mnt -o 512 -s 8192:

Final memory usage:
VARIABLE  BEFORE   AFTER    DELTA
======== ======== ======== ========
arena       81ffc    81ffc        0
ordblks         2        2        0
mxordblk    77ff8    77ff8        0
uordblks     93f4     93f4        0
fordblks    78c08    78c08        0

I'm not sure how to interpret these results, but I can't see any errors reported during the test.

Using smart_test on the mount point.

nsh> smart_test -w 1024 -l 1024 /mnt/test2
Creating file /mnt/test2 for write mode
Writing test data.  1024 lines to write
1023
Done.

Append test failed
Performing 1024 random seek with write tests
1023
Pass
Creating circular log with 40000 records
Performing 0 circular log record update tests

Pass

I couldn't see the block test of md5 large file.

g2gps · 2023-09-05T11:07:31Z

BTW, please add an entry in our https://nuttx.apache.org/docs/latest/components/drivers/block/index.html# Doc to say this feature exists (otherwise it will be a "hidden feature")

Sorry, I just realized that I missed this. I'll add it to this PR before it can be merged.

FASTSHIFT · 2023-09-15T08:00:04Z

@g2gps
Hi, I tried testing the patch on the device, this is my configuration:

/****************************************************************************
 * Private Functions
 ****************************************************************************/
static void mcu_partition_handler(FAR struct partition_s *part,
                                  FAR void *path) {
  char dev[PATH_MAX];
  char cache_dev[PATH_MAX];
  int ret;

  emmc_partition_options(part);

  snprintf(dev, sizeof(dev), "/dev/source_%s", part->name);
  ret = register_blockpartition(dev, 0, path, part->firstblock, part->nblocks);
  if (ret < 0) {
    ferr("ERROR: Failed to register block device: %s %d\n", part->name, ret);
  }

  snprintf(cache_dev, sizeof(cache_dev), "/dev/%s", part->name);
  block_cache_initialize(dev, cache_dev, 64, 8, 1);

  finfo("Register block device:%s, first:%d, nblocks:%d, blocksize:%d\n",
        part->name, part->firstblock, part->nblocks, part->blocksize);
}

I found that the memory occupied 4M more, and the random access performance dropped significantly.
My test case is to use freetype to load a font file and observe the delay introduced by the file system when accessing the glyph data. Because the glyph data is scattered in various locations in the file, it is suitable to evaluate the performance of the cache strategy.
Test text:

"All human beings are born free and equal in dignity and rights.\n"
"人人生而自由，在尊严和权利上一律平等。\n"

The following is my test data:

Single Block Cache
Total text loading time: 98ms

Detailed time:
(offset: file offset, count: number of bytes read, xx us reading time)

[09/13 08:04:33] [52] [ap] offset = 0, count = 4, 966 us
[09/13 08:04:33] [52] [ap] offset = 0, count = 4, 17 us
[09/13 08:04:33] [52] [ap] offset = 4, count = 8, 20 us
[09/13 08:04:33] [52] [ap] offset = 12, count = 16, 18 us
[09/13 08:04:33] [52] [ap] offset = 28, count = 16, 24 us
[09/13 08:04:33] [52] [ap] offset = 44, count = 16, 23 us
[09/13 08:04:33] [52] [ap] offset = 60, count = 16, 16 us
[09/13 08:04:33] [52] [ap] offset = 76, count = 16, 18 us
[09/13 08:04:33] [52] [ap] offset = 92, count = 16, 17 us
[09/13 08:04:33] [52] [ap] offset = 108, count = 16, 17 us
[09/13 08:04:33] [52] [ap] offset = 124, count = 16, 19 us
[09/13 08:04:33] [52] [ap] offset = 140, count = 16, 16 us
[09/13 08:04:33] [52] [ap] offset = 312, count = 4, 15 us
[09/13 08:04:33] [52] [ap] offset = 156, count = 16, 17 us
[09/13 08:04:33] [52] [ap] offset = 172, count = 16, 16 us
[09/13 08:04:33] [52] [ap] offset = 188, count = 16, 21 us
[09/13 08:04:33] [52] [ap] offset = 204, count = 16, 18 us
[09/13 08:04:33] [52] [ap] offset = 220, count = 16, 18 us
[09/13 08:04:33] [52] [ap] offset = 236, count = 16, 19 us
[09/13 08:04:33] [52] [ap] offset = 252, count = 16, 29 us
[09/13 08:04:33] [52] [ap] offset = 268, count = 16, 22 us
[09/13 08:04:33] [52] [ap] offset = 284, count = 16, 18 us
[09/13 08:04:33] [52] [ap] offset = 12, count = 288, 17 us
[09/13 08:04:33] [52] [ap] offset = 300, count = 54, 19 us
[09/13 08:04:33] [52] [ap] offset = 392, count = 6, 16 us
[09/13 08:04:33] [52] [ap] offset = 398, count = 26, 17 us
[09/13 08:04:33] [52] [ap] offset = 185232, count = 13722, 1038 us
[09/13 08:04:33] [52] [ap] offset = 10872668, count = 6, 586 us
[09/13 08:04:33] [52] [ap] offset = 10872674, count = 432, 31 us
[09/13 08:04:33] [52] [ap] offset = 10873884, count = 32, 15 us
[09/13 08:04:33] [52] [ap] offset = 356, count = 36, 499 us
[09/13 08:04:33] [52] [ap] offset = 11455408, count = 36, 647 us
[09/13 08:04:33] [52] [ap] offset = 424, count = 78, 486 us
[09/13 08:04:33] [52] [ap] offset = 502, count = 8, 27 us
[09/13 08:04:33] [52] [ap] offset = 510, count = 10, 22 us
[09/13 08:04:33] [52] [ap] offset = 11355524, count = 4, 501 us
[09/13 08:04:33] [52] [ap] offset = 11355528, count = 4, 26 us
[09/13 08:04:33] [52] [ap] offset = 10873367, count = 12, 485 us
[09/13 08:04:33] [52] [ap] offset = 10873388, count = 14, 15 us
[09/13 08:04:33] [52] [ap] offset = 198956, count = 8, 504 us
[09/13 08:04:33] [52] [ap] offset = 198964, count = 186188, 2226 us
[09/13 08:04:33] [52] [ap] offset = 198956, count = 8, 492 us
[09/13 08:04:33] [52] [ap] offset = 387612, count = 56, 548 us
[09/13 08:04:33] [52] [ap] offset = 664, count = 2, 503 us
[09/13 08:04:33] [52] [ap] offset = 666, count = 2, 23 us
[09/13 08:04:33] [52] [ap] offset = 11455588, count = 2, 482 us
[09/13 08:04:33] [52] [ap] offset = 11455590, count = 2, 23 us
[09/13 08:04:33] [52] [ap] offset = 387622, count = 46, 501 us
[09/13 08:04:33] [52] [ap] offset = 390496, count = 40, 20 us
[09/13 08:04:33] [52] [ap] offset = 836, count = 2, 541 us
[09/13 08:04:33] [52] [ap] offset = 838, count = 2, 26 us
[09/13 08:04:33] [52] [ap] offset = 11455760, count = 2, 487 us
[09/13 08:04:33] [52] [ap] offset = 11455762, count = 2, 21 us
[09/13 08:04:33] [52] [ap] offset = 390506, count = 30, 490 us
[09/13 08:04:33] [52] [ap] offset = 532, count = 2, 520 us
[09/13 08:04:33] [52] [ap] offset = 534, count = 2, 29 us
[09/13 08:04:33] [52] [ap] offset = 11455456, count = 2, 486 us
[09/13 08:04:33] [52] [ap] offset = 11455458, count = 2, 26 us
[09/13 08:04:33] [52] [ap] offset = 390236, count = 68, 513 us
[09/13 08:04:33] [52] [ap] offset = 820, count = 2, 497 us
[09/13 08:04:33] [52] [ap] offset = 822, count = 2, 25 us
[09/13 08:04:33] [52] [ap] offset = 11455744, count = 2, 478 us
[09/13 08:04:33] [52] [ap] offset = 11455746, count = 2, 24 us
[09/13 08:04:33] [52] [ap] offset = 390246, count = 58, 484 us
[09/13 08:04:33] [52] [ap] offset = 391252, count = 68, 17 us
[09/13 08:04:33] [52] [ap] offset = 872, count = 2, 539 us
[09/13 08:04:33] [52] [ap] offset = 874, count = 2, 36 us
[09/13 08:04:33] [52] [ap] offset = 11455796, count = 2, 490 us
[09/13 08:04:33] [52] [ap] offset = 11455798, count = 2, 25 us
[09/13 08:04:33] [52] [ap] offset = 391262, count = 58, 490 us
[09/13 08:04:33] [52] [ap] offset = 390536, count = 108, 521 us
[09/13 08:04:33] [52] [ap] offset = 840, count = 2, 518 us
[09/13 08:04:33] [52] [ap] offset = 842, count = 2, 22 us
[09/13 08:04:33] [52] [ap] offset = 11455764, count = 2, 489 us
[09/13 08:04:33] [52] [ap] offset = 11455766, count = 2, 22 us
[09/13 08:04:33] [52] [ap] offset = 390546, count = 98, 492 us
[09/13 08:04:33] [52] [ap] offset = 389516, count = 108, 526 us
[09/13 08:04:33] [52] [ap] offset = 792, count = 2, 497 us
[09/13 08:04:33] [52] [ap] offset = 794, count = 2, 23 us
[09/13 08:04:33] [52] [ap] offset = 11455716, count = 2, 486 us
[09/13 08:04:33] [52] [ap] offset = 11455718, count = 2, 21 us
[09/13 08:04:33] [52] [ap] offset = 389526, count = 98, 484 us
[09/13 08:04:33] [52] [ap] offset = 390644, count = 68, 18 us
[09/13 08:04:33] [52] [ap] offset = 844, count = 2, 542 us
[09/13 08:04:33] [52] [ap] offset = 846, count = 2, 25 us
[09/13 08:04:33] [52] [ap] offset = 11455768, count = 2, 572 us
[09/13 08:04:33] [52] [ap] offset = 11455770, count = 2, 26 us
[09/13 08:04:33] [52] [ap] offset = 390654, count = 58, 500 us
[09/13 08:04:33] [52] [ap] offset = 389624, count = 112, 520 us
[09/13 08:04:33] [52] [ap] offset = 796, count = 2, 493 us
[09/13 08:04:33] [52] [ap] offset = 798, count = 2, 24 us
[09/13 08:04:33] [52] [ap] offset = 11455720, count = 2, 475 us
[09/13 08:04:33] [52] [ap] offset = 11455722, count = 2, 25 us
[09/13 08:04:33] [52] [ap] offset = 389634, count = 102, 496 us
[09/13 08:04:33] [52] [ap] offset = 389936, count = 92, 23 us
[09/13 08:04:33] [52] [ap] offset = 808, count = 2, 546 us
[09/13 08:04:33] [52] [ap] offset = 810, count = 2, 26 us
[09/13 08:04:33] [52] [ap] offset = 11455732, count = 2, 483 us
[09/13 08:04:33] [52] [ap] offset = 11455734, count = 2, 25 us
[09/13 08:04:33] [52] [ap] offset = 389946, count = 82, 486 us
[09/13 08:04:33] [52] [ap] offset = 390304, count = 60, 17 us
[09/13 08:04:33] [52] [ap] offset = 824, count = 2, 532 us
[09/13 08:04:33] [52] [ap] offset = 826, count = 2, 29 us
[09/13 08:04:33] [52] [ap] offset = 11455748, count = 2, 482 us
[09/13 08:04:33] [52] [ap] offset = 11455750, count = 2, 23 us
[09/13 08:04:33] [52] [ap] offset = 390314, count = 50, 505 us
[09/13 08:04:33] [52] [ap] offset = 390096, count = 140, 514 us
[09/13 08:04:33] [52] [ap] offset = 816, count = 2, 492 us
[09/13 08:04:33] [52] [ap] offset = 818, count = 2, 20 us
[09/13 08:04:33] [52] [ap] offset = 11455740, count = 2, 484 us
[09/13 08:04:33] [52] [ap] offset = 11455742, count = 2, 26 us
[09/13 08:04:33] [52] [ap] offset = 390106, count = 130, 494 us
[09/13 08:04:33] [52] [ap] offset = 391076, count = 108, 19 us
[09/13 08:04:33] [52] [ap] offset = 864, count = 2, 529 us
[09/13 08:04:33] [52] [ap] offset = 866, count = 2, 30 us
[09/13 08:04:33] [52] [ap] offset = 11455788, count = 2, 489 us
[09/13 08:04:33] [52] [ap] offset = 11455790, count = 2, 26 us
[09/13 08:04:33] [52] [ap] offset = 391086, count = 98, 494 us
[09/13 08:04:33] [52] [ap] offset = 391024, count = 52, 20 us
[09/13 08:04:33] [52] [ap] offset = 860, count = 2, 526 us
[09/13 08:04:33] [52] [ap] offset = 862, count = 2, 28 us
[09/13 08:04:33] [52] [ap] offset = 11455784, count = 2, 491 us
[09/13 08:04:33] [52] [ap] offset = 11455786, count = 2, 24 us
[09/13 08:04:33] [52] [ap] offset = 391034, count = 42, 490 us
[09/13 08:04:33] [52] [ap] offset = 390712, count = 88, 20 us
[09/13 08:04:33] [52] [ap] offset = 848, count = 2, 524 us
[09/13 08:04:33] [52] [ap] offset = 850, count = 2, 26 us
[09/13 08:04:33] [52] [ap] offset = 11455772, count = 2, 490 us
[09/13 08:04:33] [52] [ap] offset = 11455774, count = 2, 22 us
[09/13 08:04:33] [52] [ap] offset = 390722, count = 78, 488 us
[09/13 08:04:33] [52] [ap] offset = 390028, count = 68, 513 us
[09/13 08:04:33] [52] [ap] offset = 812, count = 2, 498 us
[09/13 08:04:33] [52] [ap] offset = 814, count = 2, 23 us
[09/13 08:04:33] [52] [ap] offset = 11455736, count = 2, 490 us
[09/13 08:04:33] [52] [ap] offset = 11455738, count = 2, 23 us
[09/13 08:04:33] [52] [ap] offset = 390038, count = 58, 496 us
[09/13 08:04:33] [52] [ap] offset = 389824, count = 112, 20 us
[09/13 08:04:33] [52] [ap] offset = 804, count = 2, 534 us
[09/13 08:04:33] [52] [ap] offset = 806, count = 2, 28 us
[09/13 08:04:33] [52] [ap] offset = 11455728, count = 2, 492 us
[09/13 08:04:33] [52] [ap] offset = 11455730, count = 2, 24 us
[09/13 08:04:33] [52] [ap] offset = 389834, count = 102, 489 us
[09/13 08:04:33] [52] [ap] offset = 390912, count = 112, 16 us
[09/13 08:04:33] [52] [ap] offset = 856, count = 2, 609 us
[09/13 08:04:33] [52] [ap] offset = 858, count = 2, 28 us
[09/13 08:04:33] [52] [ap] offset = 11455780, count = 2, 487 us
[09/13 08:04:33] [52] [ap] offset = 11455782, count = 2, 26 us
[09/13 08:04:33] [52] [ap] offset = 390922, count = 102, 491 us
[09/13 08:04:33] [52] [ap] offset = 391184, count = 68, 20 us
[09/13 08:04:33] [52] [ap] offset = 868, count = 2, 531 us
[09/13 08:04:33] [52] [ap] offset = 870, count = 2, 25 us
[09/13 08:04:33] [52] [ap] offset = 11455792, count = 2, 488 us
[09/13 08:04:33] [52] [ap] offset = 11455794, count = 2, 24 us
[09/13 08:04:33] [52] [ap] offset = 391194, count = 58, 501 us
[09/13 08:04:33] [52] [ap] offset = 391476, count = 44, 19 us
[09/13 08:04:33] [52] [ap] offset = 888, count = 2, 518 us
[09/13 08:04:33] [52] [ap] offset = 890, count = 2, 26 us
[09/13 08:04:33] [52] [ap] offset = 11455812, count = 2, 487 us
[09/13 08:04:33] [52] [ap] offset = 11455814, count = 2, 27 us
[09/13 08:04:33] [52] [ap] offset = 391486, count = 34, 489 us
[09/13 08:04:33] [52] [ap] offset = 386188, count = 24, 513 us
[09/13 08:04:33] [52] [ap] offset = 588, count = 2, 496 us
[09/13 08:04:33] [52] [ap] offset = 590, count = 2, 26 us
[09/13 08:04:33] [52] [ap] offset = 11455512, count = 2, 496 us
[09/13 08:04:33] [52] [ap] offset = 11455514, count = 2, 25 us
[09/13 08:04:33] [52] [ap] offset = 386198, count = 14, 483 us
[09/13 08:04:33] [52] [ap] offset = 2573696, count = 72, 636 us
[09/13 08:04:33] [52] [ap] offset = 38164, count = 2, 487 us
[09/13 08:04:33] [52] [ap] offset = 38166, count = 2, 25 us
[09/13 08:04:33] [52] [ap] offset = 11493088, count = 2, 502 us
[09/13 08:04:33] [52] [ap] offset = 11493090, count = 2, 22 us
[09/13 08:04:33] [52] [ap] offset = 2573706, count = 62, 485 us
[09/13 08:04:33] [52] [ap] offset = 4904728, count = 96, 610 us
[09/13 08:04:33] [52] [ap] offset = 77480, count = 2, 488 us
[09/13 08:04:33] [52] [ap] offset = 77482, count = 2, 23 us
[09/13 08:04:33] [52] [ap] offset = 11532404, count = 2, 490 us
[09/13 08:04:33] [52] [ap] offset = 11532406, count = 2, 22 us
[09/13 08:04:33] [52] [ap] offset = 4904738, count = 86, 498 us
[09/13 08:04:33] [52] [ap] offset = 5645712, count = 112, 558 us
[09/13 08:04:33] [52] [ap] offset = 88668, count = 2, 501 us
[09/13 08:04:33] [52] [ap] offset = 88670, count = 2, 24 us
[09/13 08:04:33] [52] [ap] offset = 11543592, count = 2, 488 us
[09/13 08:04:33] [52] [ap] offset = 11543594, count = 2, 29 us
[09/13 08:04:33] [52] [ap] offset = 5645722, count = 102, 751 us
[09/13 08:04:33] [52] [ap] offset = 5765880, count = 92, 561 us
[09/13 08:04:33] [52] [ap] offset = 90580, count = 2, 488 us
[09/13 08:04:33] [52] [ap] offset = 90582, count = 2, 24 us
[09/13 08:04:33] [52] [ap] offset = 11545504, count = 2, 464 us
[09/13 08:04:33] [52] [ap] offset = 11545506, count = 2, 24 us
[09/13 08:04:33] [52] [ap] offset = 5765890, count = 82, 475 us
[09/13 08:04:33] [52] [ap] offset = 4908172, count = 96, 514 us
[09/13 08:04:33] [52] [ap] offset = 77552, count = 2, 460 us
[09/13 08:04:33] [52] [ap] offset = 77554, count = 2, 23 us
[09/13 08:04:33] [52] [ap] offset = 11532476, count = 2, 475 us
[09/13 08:04:33] [52] [ap] offset = 11532478, count = 2, 22 us
[09/13 08:04:33] [52] [ap] offset = 4908182, count = 86, 482 us
[09/13 08:04:33] [52] [ap] offset = 9956260, count = 16, 537 us
[09/13 08:04:33] [52] [ap] offset = 168040, count = 2, 466 us
[09/13 08:04:33] [52] [ap] offset = 168042, count = 2, 24 us
[09/13 08:04:33] [52] [ap] offset = 11622964, count = 2, 481 us
[09/13 08:04:33] [52] [ap] offset = 11622966, count = 2, 25 us
[09/13 08:04:33] [52] [ap] offset = 9956270, count = 6, 468 us
[09/13 08:04:33] [52] [ap] offset = 386120, count = 40, 498 us
[09/13 08:04:33] [52] [ap] offset = 580, count = 2, 491 us
[09/13 08:04:33] [52] [ap] offset = 582, count = 2, 22 us
[09/13 08:04:33] [52] [ap] offset = 11455504, count = 2, 478 us
[09/13 08:04:33] [52] [ap] offset = 11455506, count = 2, 26 us
[09/13 08:04:33] [52] [ap] offset = 386130, count = 30, 483 us
[09/13 08:04:33] [52] [ap] offset = 3011568, count = 124, 545 us
[09/13 08:04:33] [52] [ap] offset = 46796, count = 2, 522 us
[09/13 08:04:33] [52] [ap] offset = 46798, count = 2, 26 us
[09/13 08:04:33] [52] [ap] offset = 11501720, count = 2, 482 us
[09/13 08:04:33] [52] [ap] offset = 11501722, count = 2, 36 us
[09/13 08:04:33] [52] [ap] offset = 3011578, count = 114, 494 us
[09/13 08:04:33] [52] [ap] offset = 3308632, count = 248, 561 us
[09/13 08:04:33] [52] [ap] offset = 51796, count = 2, 472 us
[09/13 08:04:33] [52] [ap] offset = 51798, count = 2, 22 us
[09/13 08:04:33] [52] [ap] offset = 11506720, count = 2, 507 us
[09/13 08:04:33] [52] [ap] offset = 11506722, count = 2, 23 us
[09/13 08:04:33] [52] [ap] offset = 3308642, count = 238, 483 us
[09/13 08:04:33] [52] [ap] offset = 2551212, count = 136, 528 us
[09/13 08:04:33] [52] [ap] offset = 37568, count = 2, 460 us
[09/13 08:04:33] [52] [ap] offset = 37570, count = 2, 25 us
[09/13 08:04:33] [52] [ap] offset = 11492492, count = 2, 487 us
[09/13 08:04:33] [52] [ap] offset = 11492494, count = 2, 24 us
[09/13 08:04:33] [52] [ap] offset = 2551222, count = 126, 485 us
[09/13 08:04:33] [52] [ap] offset = 2865244, count = 144, 511 us
[09/13 08:04:33] [52] [ap] offset = 44124, count = 2, 484 us
[09/13 08:04:33] [52] [ap] offset = 44126, count = 2, 21 us
[09/13 08:04:33] [52] [ap] offset = 11499048, count = 2, 471 us
[09/13 08:04:33] [52] [ap] offset = 11499050, count = 2, 21 us
[09/13 08:04:33] [52] [ap] offset = 2865254, count = 134, 483 us
[09/13 08:04:33] [52] [ap] offset = 3992304, count = 164, 578 us
[09/13 08:04:33] [52] [ap] offset = 63288, count = 2, 512 us
[09/13 08:04:33] [52] [ap] offset = 63290, count = 2, 23 us
[09/13 08:04:33] [52] [ap] offset = 11518212, count = 2, 574 us
[09/13 08:04:33] [52] [ap] offset = 11518214, count = 2, 26 us
[09/13 08:04:33] [52] [ap] offset = 3992314, count = 154, 503 us
[09/13 08:04:33] [52] [ap] offset = 2749324, count = 152, 531 us
[09/13 08:04:33] [52] [ap] offset = 41680, count = 2, 520 us
[09/13 08:04:33] [52] [ap] offset = 41682, count = 2, 26 us
[09/13 08:04:33] [52] [ap] offset = 11496604, count = 2, 478 us
[09/13 08:04:33] [52] [ap] offset = 11496606, count = 2, 22 us
[09/13 08:04:33] [52] [ap] offset = 2749334, count = 142, 495 us
[09/13 08:04:33] [52] [ap] offset = 2548124, count = 48, 534 us
[09/13 08:04:33] [52] [ap] offset = 37460, count = 2, 481 us
[09/13 08:04:33] [52] [ap] offset = 37462, count = 2, 25 us
[09/13 08:04:33] [52] [ap] offset = 11492384, count = 2, 501 us
[09/13 08:04:33] [52] [ap] offset = 11492386, count = 2, 25 us
[09/13 08:04:33] [52] [ap] offset = 2548134, count = 38, 495 us
[09/13 08:04:33] [52] [ap] offset = 2547404, count = 28, 518 us
[09/13 08:04:33] [52] [ap] offset = 37420, count = 2, 480 us
[09/13 08:04:33] [52] [ap] offset = 37422, count = 2, 22 us
[09/13 08:04:33] [52] [ap] offset = 11492344, count = 2, 505 us
[09/13 08:04:33] [52] [ap] offset = 11492346, count = 2, 27 us
[09/13 08:04:33] [52] [ap] offset = 2547414, count = 18, 492 us
[09/13 08:04:33] [52] [ap] offset = 3500112, count = 196, 501 us
[09/13 08:04:33] [52] [ap] offset = 55384, count = 2, 508 us
[09/13 08:04:33] [52] [ap] offset = 55386, count = 2, 25 us
[09/13 08:04:33] [52] [ap] offset = 11510308, count = 2, 480 us
[09/13 08:04:33] [52] [ap] offset = 11510310, count = 2, 25 us
[09/13 08:04:33] [52] [ap] offset = 3500122, count = 186, 554 us
[09/13 08:04:33] [52] [ap] offset = 3439528, count = 116, 533 us
[09/13 08:04:33] [52] [ap] offset = 54264, count = 2, 477 us
[09/13 08:04:33] [52] [ap] offset = 54266, count = 2, 25 us
[09/13 08:04:33] [52] [ap] offset = 11509188, count = 2, 457 us
[09/13 08:04:33] [52] [ap] offset = 11509190, count = 2, 22 us
[09/13 08:04:33] [52] [ap] offset = 3439538, count = 106, 484 us
[09/13 08:04:33] [52] [ap] offset = 5284624, count = 240, 509 us
[09/13 08:04:33] [52] [ap] offset = 83792, count = 2, 497 us
[09/13 08:04:33] [52] [ap] offset = 83794, count = 2, 23 us
[09/13 08:04:33] [52] [ap] offset = 11538716, count = 2, 463 us
[09/13 08:04:33] [52] [ap] offset = 11538718, count = 2, 25 us
[09/13 08:04:33] [52] [ap] offset = 5284634, count = 230, 471 us
[09/13 08:04:33] [52] [ap] offset = 558316, count = 76, 566 us
[09/13 08:04:33] [52] [ap] offset = 7328, count = 2, 469 us
[09/13 08:04:33] [52] [ap] offset = 7330, count = 2, 22 us
[09/13 08:04:33] [52] [ap] offset = 11462252, count = 2, 489 us
[09/13 08:04:33] [52] [ap] offset = 11462254, count = 2, 24 us
[09/13 08:04:33] [52] [ap] offset = 558326, count = 66, 487 us

block_cache
Total text loading time: 135ms

Detailed time:

[09/14 06:45:40] [52] [ap] offset = 0, count = 4, 1425us
[09/14 06:45:40] [52] [ap] offset = 0, count = 4, 100us
[09/14 06:45:40] [52] [ap] offset = 4, count = 8, 28us
[09/14 06:45:40] [52] [ap] offset = 12, count = 16, 27us
[09/14 06:45:40] [52] [ap] offset = 28, count = 16, 29us
[09/14 06:45:40] [52] [ap] offset = 44, count = 16, 22us
[09/14 06:45:40] [52] [ap] offset = 60, count = 16, 24us
[09/14 06:45:40] [52] [ap] offset = 76, count = 16, 22us
[09/14 06:45:40] [52] [ap] offset = 92, count = 16, 22us
[09/14 06:45:40] [52] [ap] offset = 108, count = 16, 23us
[09/14 06:45:40] [52] [ap] offset = 124, count = 16, 21us
[09/14 06:45:40] [52] [ap] offset = 140, count = 16, 22us
[09/14 06:45:40] [52] [ap] offset = 312, count = 4, 21us
[09/14 06:45:40] [52] [ap] offset = 156, count = 16, 19us
[09/14 06:45:40] [52] [ap] offset = 172, count = 16, 21us
[09/14 06:45:40] [52] [ap] offset = 188, count = 16, 22us
[09/14 06:45:40] [52] [ap] offset = 204, count = 16, 22us
[09/14 06:45:40] [52] [ap] offset = 220, count = 16, 22us
[09/14 06:45:40] [52] [ap] offset = 236, count = 16, 23us
[09/14 06:45:40] [52] [ap] offset = 252, count = 16, 25us
[09/14 06:45:40] [52] [ap] offset = 268, count = 16, 21us
[09/14 06:45:40] [52] [ap] offset = 284, count = 16, 22us
[09/14 06:45:40] [52] [ap] offset = 12, count = 288, 21us
[09/14 06:45:40] [52] [ap] offset = 300, count = 54, 18us
[09/14 06:45:40] [52] [ap] offset = 392, count = 6, 21us
[09/14 06:45:40] [52] [ap] offset = 398, count = 26, 22us
[09/14 06:45:40] [52] [ap] offset = 185232, count = 13722, 1885us
[09/14 06:45:40] [52] [ap] offset = 10872668, count = 6, 1509us
[09/14 06:45:40] [52] [ap] offset = 10872674, count = 432, 41us
[09/14 06:45:40] [52] [ap] offset = 10873884, count = 32, 20us
[09/14 06:45:40] [52] [ap] offset = 356, count = 36, 463us
[09/14 06:45:40] [52] [ap] offset = 11455408, count = 36, 1553us
[09/14 06:45:40] [52] [ap] offset = 424, count = 78, 921us
[09/14 06:45:40] [52] [ap] offset = 502, count = 8, 46us
[09/14 06:45:40] [52] [ap] offset = 510, count = 10, 25us
[09/14 06:45:40] [52] [ap] offset = 11355524, count = 4, 1655us
[09/14 06:45:40] [52] [ap] offset = 11355528, count = 4, 63us
[09/14 06:45:40] [52] [ap] offset = 10873367, count = 12, 448us
[09/14 06:45:40] [52] [ap] offset = 10873388, count = 14, 21us
[09/14 06:45:40] [52] [ap] offset = 198956, count = 8, 1401us
[09/14 06:45:40] [52] [ap] offset = 198964, count = 186188, 5968us
[09/14 06:45:40] [52] [ap] offset = 198956, count = 8, 446us
[09/14 06:45:40] [52] [ap] offset = 387612, count = 56, 478us
[09/14 06:45:40] [52] [ap] offset = 664, count = 2, 1624us
[09/14 06:45:40] [52] [ap] offset = 666, count = 2, 43us
[09/14 06:45:40] [52] [ap] offset = 11455588, count = 2, 1462us
[09/14 06:45:40] [52] [ap] offset = 11455590, count = 2, 58us
[09/14 06:45:40] [52] [ap] offset = 387622, count = 46, 441us
[09/14 06:45:40] [52] [ap] offset = 390496, count = 40, 23us
[09/14 06:45:40] [52] [ap] offset = 836, count = 2, 457us
[09/14 06:45:40] [52] [ap] offset = 838, count = 2, 34us
[09/14 06:45:40] [52] [ap] offset = 11455760, count = 2, 433us
[09/14 06:45:40] [52] [ap] offset = 11455762, count = 2, 36us
[09/14 06:45:40] [52] [ap] offset = 390506, count = 30, 427us
[09/14 06:45:40] [52] [ap] offset = 532, count = 2, 454us
[09/14 06:45:40] [52] [ap] offset = 534, count = 2, 51us
[09/14 06:45:40] [52] [ap] offset = 11455456, count = 2, 439us
[09/14 06:45:40] [52] [ap] offset = 11455458, count = 2, 32us
[09/14 06:45:40] [52] [ap] offset = 390236, count = 68, 433us
[09/14 06:45:40] [52] [ap] offset = 820, count = 2, 437us
[09/14 06:45:40] [52] [ap] offset = 822, count = 2, 35us
[09/14 06:45:40] [52] [ap] offset = 11455744, count = 2, 437us
[09/14 06:45:40] [52] [ap] offset = 11455746, count = 2, 33us
[09/14 06:45:40] [52] [ap] offset = 390246, count = 58, 718us
[09/14 06:45:40] [52] [ap] offset = 391252, count = 68, 27us
[09/14 06:45:40] [52] [ap] offset = 872, count = 2, 464us
[09/14 06:45:40] [52] [ap] offset = 874, count = 2, 37us
[09/14 06:45:40] [52] [ap] offset = 11455796, count = 2, 430us
[09/14 06:45:40] [52] [ap] offset = 11455798, count = 2, 34us
[09/14 06:45:40] [52] [ap] offset = 391262, count = 58, 424us
[09/14 06:45:40] [52] [ap] offset = 390536, count = 108, 448us
[09/14 06:45:40] [52] [ap] offset = 840, count = 2, 428us
[09/14 06:45:40] [52] [ap] offset = 842, count = 2, 36us
[09/14 06:45:40] [52] [ap] offset = 11455764, count = 2, 440us
[09/14 06:45:40] [52] [ap] offset = 11455766, count = 2, 38us
[09/14 06:45:40] [52] [ap] offset = 390546, count = 98, 424us
[09/14 06:45:40] [52] [ap] offset = 389516, count = 108, 456us
[09/14 06:45:40] [52] [ap] offset = 792, count = 2, 426us
[09/14 06:45:40] [52] [ap] offset = 794, count = 2, 44us
[09/14 06:45:40] [52] [ap] offset = 11455716, count = 2, 445us
[09/14 06:45:40] [52] [ap] offset = 11455718, count = 2, 31us
[09/14 06:45:40] [52] [ap] offset = 389526, count = 98, 423us
[09/14 06:45:40] [52] [ap] offset = 390644, count = 68, 23us
[09/14 06:45:40] [52] [ap] offset = 844, count = 2, 540us
[09/14 06:45:40] [52] [ap] offset = 846, count = 2, 35us
[09/14 06:45:40] [52] [ap] offset = 11455768, count = 2, 433us
[09/14 06:45:40] [52] [ap] offset = 11455770, count = 2, 33us
[09/14 06:45:40] [52] [ap] offset = 390654, count = 58, 435us
[09/14 06:45:40] [52] [ap] offset = 389624, count = 112, 453us
[09/14 06:45:40] [52] [ap] offset = 796, count = 2, 442us
[09/14 06:45:40] [52] [ap] offset = 798, count = 2, 32us
[09/14 06:45:40] [52] [ap] offset = 11455720, count = 2, 421us
[09/14 06:45:40] [52] [ap] offset = 11455722, count = 2, 35us
[09/14 06:45:40] [52] [ap] offset = 389634, count = 102, 435us
[09/14 06:45:40] [52] [ap] offset = 389936, count = 92, 21us
[09/14 06:45:40] [52] [ap] offset = 808, count = 2, 447us
[09/14 06:45:40] [52] [ap] offset = 810, count = 2, 34us
[09/14 06:45:40] [52] [ap] offset = 11455732, count = 2, 428us
[09/14 06:45:40] [52] [ap] offset = 11455734, count = 2, 34us
[09/14 06:45:40] [52] [ap] offset = 389946, count = 82, 439us
[09/14 06:45:40] [52] [ap] offset = 390304, count = 60, 24us
[09/14 06:45:40] [52] [ap] offset = 824, count = 2, 447us
[09/14 06:45:40] [52] [ap] offset = 826, count = 2, 34us
[09/14 06:45:40] [52] [ap] offset = 11455748, count = 2, 449us
[09/14 06:45:40] [52] [ap] offset = 11455750, count = 2, 35us
[09/14 06:45:40] [52] [ap] offset = 390314, count = 50, 442us
[09/14 06:45:40] [52] [ap] offset = 390096, count = 140, 435us
[09/14 06:45:40] [52] [ap] offset = 816, count = 2, 418us
[09/14 06:45:40] [52] [ap] offset = 818, count = 2, 36us
[09/14 06:45:40] [52] [ap] offset = 11455740, count = 2, 439us
[09/14 06:45:40] [52] [ap] offset = 11455742, count = 2, 31us
[09/14 06:45:40] [52] [ap] offset = 390106, count = 130, 420us
[09/14 06:45:40] [52] [ap] offset = 391076, count = 108, 24us
[09/14 06:45:40] [52] [ap] offset = 864, count = 2, 530us
[09/14 06:45:40] [52] [ap] offset = 866, count = 2, 50us
[09/14 06:45:40] [52] [ap] offset = 11455788, count = 2, 441us
[09/14 06:45:40] [52] [ap] offset = 11455790, count = 2, 35us
[09/14 06:45:40] [52] [ap] offset = 391086, count = 98, 434us
[09/14 06:45:40] [52] [ap] offset = 391024, count = 52, 23us
[09/14 06:45:40] [52] [ap] offset = 860, count = 2, 461us
[09/14 06:45:40] [52] [ap] offset = 862, count = 2, 35us
[09/14 06:45:40] [52] [ap] offset = 11455784, count = 2, 442us
[09/14 06:45:40] [52] [ap] offset = 11455786, count = 2, 33us
[09/14 06:45:40] [52] [ap] offset = 391034, count = 42, 426us
[09/14 06:45:40] [52] [ap] offset = 390712, count = 88, 25us
[09/14 06:45:40] [52] [ap] offset = 848, count = 2, 441us
[09/14 06:45:40] [52] [ap] offset = 850, count = 2, 35us
[09/14 06:45:40] [52] [ap] offset = 11455772, count = 2, 451us
[09/14 06:45:40] [52] [ap] offset = 11455774, count = 2, 32us
[09/14 06:45:40] [52] [ap] offset = 390722, count = 78, 434us
[09/14 06:45:40] [52] [ap] offset = 390028, count = 68, 442us
[09/14 06:45:40] [52] [ap] offset = 812, count = 2, 429us
[09/14 06:45:40] [52] [ap] offset = 814, count = 2, 36us
[09/14 06:45:40] [52] [ap] offset = 11455736, count = 2, 437us
[09/14 06:45:40] [52] [ap] offset = 11455738, count = 2, 32us
[09/14 06:45:40] [52] [ap] offset = 390038, count = 58, 444us
[09/14 06:45:40] [52] [ap] offset = 389824, count = 112, 285us
[09/14 06:45:40] [52] [ap] offset = 804, count = 2, 448us
[09/14 06:45:40] [52] [ap] offset = 806, count = 2, 35us
[09/14 06:45:40] [52] [ap] offset = 11455728, count = 2, 450us
[09/14 06:45:40] [52] [ap] offset = 11455730, count = 2, 35us
[09/14 06:45:40] [52] [ap] offset = 389834, count = 102, 430us
[09/14 06:45:40] [52] [ap] offset = 390912, count = 112, 24us
[09/14 06:45:40] [52] [ap] offset = 856, count = 2, 464us
[09/14 06:45:40] [52] [ap] offset = 858, count = 2, 36us
[09/14 06:45:40] [52] [ap] offset = 11455780, count = 2, 432us
[09/14 06:45:40] [52] [ap] offset = 11455782, count = 2, 37us
[09/14 06:45:40] [52] [ap] offset = 390922, count = 102, 432us
[09/14 06:45:40] [52] [ap] offset = 391184, count = 68, 23us
[09/14 06:45:40] [52] [ap] offset = 868, count = 2, 465us
[09/14 06:45:40] [52] [ap] offset = 870, count = 2, 33us
[09/14 06:45:40] [52] [ap] offset = 11455792, count = 2, 427us
[09/14 06:45:40] [52] [ap] offset = 11455794, count = 2, 33us
[09/14 06:45:40] [52] [ap] offset = 391194, count = 58, 429us
[09/14 06:45:40] [52] [ap] offset = 391476, count = 44, 26us
[09/14 06:45:40] [52] [ap] offset = 888, count = 2, 446us
[09/14 06:45:40] [52] [ap] offset = 890, count = 2, 36us
[09/14 06:45:40] [52] [ap] offset = 11455812, count = 2, 473us
[09/14 06:45:40] [52] [ap] offset = 11455814, count = 2, 37us
[09/14 06:45:40] [52] [ap] offset = 391486, count = 34, 435us
[09/14 06:45:40] [52] [ap] offset = 386188, count = 24, 441us
[09/14 06:45:40] [52] [ap] offset = 588, count = 2, 426us
[09/14 06:45:40] [52] [ap] offset = 590, count = 2, 39us
[09/14 06:45:40] [52] [ap] offset = 11455512, count = 2, 426us
[09/14 06:45:40] [52] [ap] offset = 11455514, count = 2, 36us
[09/14 06:45:40] [52] [ap] offset = 386198, count = 14, 443us
[09/14 06:45:40] [52] [ap] offset = 2573696, count = 72, 1872us
[09/14 06:45:40] [52] [ap] offset = 38164, count = 2, 1406us
[09/14 06:45:40] [52] [ap] offset = 38166, count = 2, 32us
[09/14 06:45:40] [52] [ap] offset = 11493088, count = 2, 1056us
[09/14 06:45:40] [52] [ap] offset = 11493090, count = 2, 38us
[09/14 06:45:40] [52] [ap] offset = 2573706, count = 62, 447us
[09/14 06:45:40] [52] [ap] offset = 4904728, count = 96, 1571us
[09/14 06:45:40] [52] [ap] offset = 77480, count = 2, 921us
[09/14 06:45:40] [52] [ap] offset = 77482, count = 2, 40us
[09/14 06:45:40] [52] [ap] offset = 11532404, count = 2, 1089us
[09/14 06:45:40] [52] [ap] offset = 11532406, count = 2, 40us
[09/14 06:45:40] [52] [ap] offset = 4904738, count = 86, 439us
[09/14 06:45:40] [52] [ap] offset = 5645712, count = 112, 1477us
[09/14 06:45:40] [52] [ap] offset = 88668, count = 2, 418us
[09/14 06:45:40] [52] [ap] offset = 88670, count = 2, 42us
[09/14 06:45:40] [52] [ap] offset = 11543592, count = 2, 925us
[09/14 06:45:40] [52] [ap] offset = 11543594, count = 2, 35us
[09/14 06:45:40] [52] [ap] offset = 5645722, count = 102, 441us
[09/14 06:45:40] [52] [ap] offset = 5765880, count = 92, 1529us
[09/14 06:45:40] [52] [ap] offset = 90580, count = 2, 909us
[09/14 06:45:40] [52] [ap] offset = 90582, count = 2, 46us
[09/14 06:45:40] [52] [ap] offset = 11545504, count = 2, 437us
[09/14 06:45:40] [52] [ap] offset = 11545506, count = 2, 35us
[09/14 06:45:40] [52] [ap] offset = 5765890, count = 82, 424us
[09/14 06:45:40] [52] [ap] offset = 4908172, count = 96, 1419us
[09/14 06:45:40] [52] [ap] offset = 77552, count = 2, 1124us
[09/14 06:45:40] [52] [ap] offset = 77554, count = 2, 41us
[09/14 06:45:40] [52] [ap] offset = 11532476, count = 2, 1376us
[09/14 06:45:40] [52] [ap] offset = 11532478, count = 2, 41us
[09/14 06:45:40] [52] [ap] offset = 4908182, count = 86, 450us
[09/14 06:45:40] [52] [ap] offset = 9956260, count = 16, 1512us
[09/14 06:45:40] [52] [ap] offset = 168040, count = 2, 1509us
[09/14 06:45:40] [52] [ap] offset = 168042, count = 2, 34us
[09/14 06:45:40] [52] [ap] offset = 11622964, count = 2, 1423us
[09/14 06:45:40] [52] [ap] offset = 11622966, count = 2, 38us
[09/14 06:45:40] [52] [ap] offset = 9956270, count = 6, 436us
[09/14 06:45:40] [52] [ap] offset = 386120, count = 40, 1424us
[09/14 06:45:40] [52] [ap] offset = 580, count = 2, 1300us
[09/14 06:45:40] [52] [ap] offset = 582, count = 2, 41us
[09/14 06:45:40] [52] [ap] offset = 11455504, count = 2, 1479us
[09/14 06:45:40] [52] [ap] offset = 11455506, count = 2, 59us
[09/14 06:45:40] [52] [ap] offset = 386130, count = 30, 442us
[09/14 06:45:40] [52] [ap] offset = 3011568, count = 124, 1375us
[09/14 06:45:40] [52] [ap] offset = 46796, count = 2, 1361us
[09/14 06:45:40] [52] [ap] offset = 46798, count = 2, 38us
[09/14 06:45:40] [52] [ap] offset = 11501720, count = 2, 1012us
[09/14 06:45:40] [52] [ap] offset = 11501722, count = 2, 39us
[09/14 06:45:40] [52] [ap] offset = 3011578, count = 114, 432us
[09/14 06:45:40] [52] [ap] offset = 3308632, count = 248, 1438us
[09/14 06:45:40] [52] [ap] offset = 51796, count = 2, 424us
[09/14 06:45:40] [52] [ap] offset = 51798, count = 2, 37us
[09/14 06:45:40] [52] [ap] offset = 11506720, count = 2, 916us
[09/14 06:45:40] [52] [ap] offset = 11506722, count = 2, 32us
[09/14 06:45:40] [52] [ap] offset = 3308642, count = 238, 507us
[09/14 06:45:40] [52] [ap] offset = 2551212, count = 136, 1425us
[09/14 06:45:40] [52] [ap] offset = 37568, count = 2, 435us
[09/14 06:45:40] [52] [ap] offset = 37570, count = 2, 35us
[09/14 06:45:40] [52] [ap] offset = 11492492, count = 2, 921us
[09/14 06:45:40] [52] [ap] offset = 11492494, count = 2, 42us
[09/14 06:45:40] [52] [ap] offset = 2551222, count = 126, 430us
[09/14 06:45:40] [52] [ap] offset = 2865244, count = 144, 1445us
[09/14 06:45:40] [52] [ap] offset = 44124, count = 2, 1378us
[09/14 06:45:40] [52] [ap] offset = 44126, count = 2, 36us
[09/14 06:45:40] [52] [ap] offset = 11499048, count = 2, 972us
[09/14 06:45:40] [52] [ap] offset = 11499050, count = 2, 39us
[09/14 06:45:40] [52] [ap] offset = 2865254, count = 134, 433us
[09/14 06:45:40] [52] [ap] offset = 3992304, count = 164, 1637us
[09/14 06:45:40] [52] [ap] offset = 63288, count = 2, 439us
[09/14 06:45:40] [52] [ap] offset = 63290, count = 2, 37us
[09/14 06:45:40] [52] [ap] offset = 11518212, count = 2, 976us
[09/14 06:45:40] [52] [ap] offset = 11518214, count = 2, 40us
[09/14 06:45:40] [52] [ap] offset = 3992314, count = 154, 453us
[09/14 06:45:40] [52] [ap] offset = 2749324, count = 152, 1589us
[09/14 06:45:40] [52] [ap] offset = 41680, count = 2, 416us
[09/14 06:45:40] [52] [ap] offset = 41682, count = 2, 34us
[09/14 06:45:40] [52] [ap] offset = 11496604, count = 2, 968us
[09/14 06:45:40] [52] [ap] offset = 11496606, count = 2, 42us
[09/14 06:45:40] [52] [ap] offset = 2749334, count = 142, 438us
[09/14 06:45:40] [52] [ap] offset = 2548124, count = 48, 1462us
[09/14 06:45:40] [52] [ap] offset = 37460, count = 2, 1476us
[09/14 06:45:40] [52] [ap] offset = 37462, count = 2, 35us
[09/14 06:45:40] [52] [ap] offset = 11492384, count = 2, 918us
[09/14 06:45:40] [52] [ap] offset = 11492386, count = 2, 63us
[09/14 06:45:40] [52] [ap] offset = 2548134, count = 38, 453us
[09/14 06:45:40] [52] [ap] offset = 2547404, count = 28, 438us
[09/14 06:45:40] [52] [ap] offset = 37420, count = 2, 448us
[09/14 06:45:40] [52] [ap] offset = 37422, count = 2, 34us
[09/14 06:45:40] [52] [ap] offset = 11492344, count = 2, 425us
[09/14 06:45:40] [52] [ap] offset = 11492346, count = 2, 39us
[09/14 06:45:40] [52] [ap] offset = 2547414, count = 18, 429us
[09/14 06:45:40] [52] [ap] offset = 3500112, count = 196, 1775us
[09/14 06:45:40] [52] [ap] offset = 55384, count = 2, 425us
[09/14 06:45:40] [52] [ap] offset = 55386, count = 2, 35us
[09/14 06:45:40] [52] [ap] offset = 11510308, count = 2, 1030us
[09/14 06:45:40] [52] [ap] offset = 11510310, count = 2, 37us
[09/14 06:45:40] [52] [ap] offset = 3500122, count = 186, 446us
[09/14 06:45:40] [52] [ap] offset = 3439528, count = 116, 1377us
[09/14 06:45:40] [52] [ap] offset = 54264, count = 2, 420us
[09/14 06:45:40] [52] [ap] offset = 54266, count = 2, 33us
[09/14 06:45:40] [52] [ap] offset = 11509188, count = 2, 440us
[09/14 06:45:40] [52] [ap] offset = 11509190, count = 2, 34us
[09/14 06:45:40] [52] [ap] offset = 3439538, count = 106, 438us
[09/14 06:45:40] [52] [ap] offset = 5284624, count = 240, 1735us
[09/14 06:45:40] [52] [ap] offset = 83792, count = 2, 1453us
[09/14 06:45:40] [52] [ap] offset = 83794, count = 2, 37us
[09/14 06:45:40] [52] [ap] offset = 11538716, count = 2, 976us
[09/14 06:45:40] [52] [ap] offset = 11538718, count = 2, 36us
[09/14 06:45:40] [52] [ap] offset = 5284634, count = 230, 450us
[09/14 06:45:40] [52] [ap] offset = 558316, count = 76, 1517us
[09/14 06:45:40] [52] [ap] offset = 7328, count = 2, 1417us
[09/14 06:45:40] [52] [ap] offset = 7330, count = 2, 38us
[09/14 06:45:40] [52] [ap] offset = 11462252, count = 2, 1385us
[09/14 06:45:40] [52] [ap] offset = 11462254, count = 2, 41us
[09/14 06:45:40] [52] [ap] offset = 558326, count = 66, 452us

File Cache
I tried to implement a file buffer according to my own understanding (currently only read buffering is implemented): https://github.com/FASTSHIFT/mbfc
cache block size = 512
cache num = 8

Total text loading time: 57ms

Detailed time:

[09/13 07:57:14] [52] [ap] offset = 0, count = 4, 1068 us
[09/13 07:57:14] [52] [ap] offset = 0, count = 4, 2 us
[09/13 07:57:14] [52] [ap] offset = 4, count = 8, 0 us
[09/13 07:57:14] [52] [ap] offset = 12, count = 16, 0 us
[09/13 07:57:14] [52] [ap] offset = 28, count = 16, 0 us
[09/13 07:57:14] [52] [ap] offset = 44, count = 16, 1 us
[09/13 07:57:14] [52] [ap] offset = 60, count = 16, 1 us
[09/13 07:57:14] [52] [ap] offset = 76, count = 16, 1 us
[09/13 07:57:14] [52] [ap] offset = 92, count = 16, 1 us
[09/13 07:57:14] [52] [ap] offset = 108, count = 16, 0 us
[09/13 07:57:14] [52] [ap] offset = 124, count = 16, 1 us
[09/13 07:57:14] [52] [ap] offset = 140, count = 16, 1 us
[09/13 07:57:14] [52] [ap] offset = 312, count = 4, 1 us
[09/13 07:57:14] [52] [ap] offset = 156, count = 16, 1 us
[09/13 07:57:14] [52] [ap] offset = 172, count = 16, 0 us
[09/13 07:57:14] [52] [ap] offset = 188, count = 16, 0 us
[09/13 07:57:14] [52] [ap] offset = 204, count = 16, 1 us
[09/13 07:57:14] [52] [ap] offset = 220, count = 16, 0 us
[09/13 07:57:14] [52] [ap] offset = 236, count = 16, 1 us
[09/13 07:57:14] [52] [ap] offset = 252, count = 16, 0 us
[09/13 07:57:14] [52] [ap] offset = 268, count = 16, 1 us
[09/13 07:57:14] [52] [ap] offset = 284, count = 16, 1 us
[09/13 07:57:14] [52] [ap] offset = 12, count = 288, 3 us
[09/13 07:57:14] [52] [ap] offset = 300, count = 54, 2 us
[09/13 07:57:14] [52] [ap] offset = 392, count = 6, 1 us
[09/13 07:57:14] [52] [ap] offset = 398, count = 26, 1 us
[09/13 07:57:14] [52] [ap] offset = 185232, count = 13722, 2003 us
[09/13 07:57:14] [52] [ap] offset = 10872668, count = 6, 616 us
[09/13 07:57:14] [52] [ap] offset = 10872674, count = 432, 68 us
[09/13 07:57:14] [52] [ap] offset = 10873884, count = 32, 54 us
[09/13 07:57:14] [52] [ap] offset = 356, count = 36, 2 us
[09/13 07:57:14] [52] [ap] offset = 11455408, count = 36, 675 us
[09/13 07:57:14] [52] [ap] offset = 424, count = 78, 4 us
[09/13 07:57:14] [52] [ap] offset = 502, count = 8, 2 us
[09/13 07:57:14] [52] [ap] offset = 510, count = 10, 529 us
[09/13 07:57:14] [52] [ap] offset = 11355524, count = 4, 505 us
[09/13 07:57:14] [52] [ap] offset = 11355528, count = 4, 2 us
[09/13 07:57:14] [52] [ap] offset = 10873367, count = 12, 499 us
[09/13 07:57:14] [52] [ap] offset = 10873388, count = 14, 2 us
[09/13 07:57:14] [52] [ap] offset = 198956, count = 8, 5 us
[09/13 07:57:14] [52] [ap] offset = 198964, count = 186188, 17605 us
[09/13 07:57:14] [52] [ap] offset = 198956, count = 8, 4 us
[09/13 07:57:14] [52] [ap] offset = 387612, count = 56, 89 us
[09/13 07:57:14] [52] [ap] offset = 664, count = 2, 600 us
[09/13 07:57:14] [52] [ap] offset = 666, count = 2, 1 us
[09/13 07:57:14] [52] [ap] offset = 11455588, count = 2, 514 us
[09/13 07:57:14] [52] [ap] offset = 11455590, count = 2, 2 us
[09/13 07:57:14] [52] [ap] offset = 387622, count = 46, 509 us
[09/13 07:57:14] [52] [ap] offset = 390496, count = 40, 70 us
[09/13 07:57:14] [52] [ap] offset = 836, count = 2, 570 us
[09/13 07:57:14] [52] [ap] offset = 838, count = 2, 2 us
[09/13 07:57:14] [52] [ap] offset = 11455760, count = 2, 511 us
[09/13 07:57:14] [52] [ap] offset = 11455762, count = 2, 2 us
[09/13 07:57:14] [52] [ap] offset = 390506, count = 30, 508 us
[09/13 07:57:14] [52] [ap] offset = 532, count = 2, 1 us
[09/13 07:57:14] [52] [ap] offset = 534, count = 2, 0 us
[09/13 07:57:14] [52] [ap] offset = 11455456, count = 2, 544 us
[09/13 07:57:14] [52] [ap] offset = 11455458, count = 2, 1 us
[09/13 07:57:14] [52] [ap] offset = 390236, count = 68, 0 us
[09/13 07:57:14] [52] [ap] offset = 820, count = 2, 1 us
[09/13 07:57:14] [52] [ap] offset = 822, count = 2, 0 us
[09/13 07:57:14] [52] [ap] offset = 11455744, count = 2, 0 us
[09/13 07:57:14] [52] [ap] offset = 11455746, count = 2, 0 us
[09/13 07:57:14] [52] [ap] offset = 390246, count = 58, 0 us
[09/13 07:57:14] [52] [ap] offset = 391252, count = 68, 588 us
[09/13 07:57:14] [52] [ap] offset = 872, count = 2, 3 us
[09/13 07:57:14] [52] [ap] offset = 874, count = 2, 1 us
[09/13 07:57:14] [52] [ap] offset = 11455796, count = 2, 1 us
[09/13 07:57:14] [52] [ap] offset = 11455798, count = 2, 1 us
[09/13 07:57:14] [52] [ap] offset = 391262, count = 58, 1 us
[09/13 07:57:14] [52] [ap] offset = 390536, count = 108, 4 us
[09/13 07:57:14] [52] [ap] offset = 840, count = 2, 3 us
[09/13 07:57:14] [52] [ap] offset = 842, count = 2, 1 us
[09/13 07:57:14] [52] [ap] offset = 11455764, count = 2, 0 us
[09/13 07:57:14] [52] [ap] offset = 11455766, count = 2, 0 us
[09/13 07:57:14] [52] [ap] offset = 390546, count = 98, 1 us
[09/13 07:57:14] [52] [ap] offset = 389516, count = 108, 588 us
[09/13 07:57:14] [52] [ap] offset = 792, count = 2, 1 us
[09/13 07:57:14] [52] [ap] offset = 794, count = 2, 1 us
[09/13 07:57:14] [52] [ap] offset = 11455716, count = 2, 1 us
[09/13 07:57:14] [52] [ap] offset = 11455718, count = 2, 1 us
[09/13 07:57:14] [52] [ap] offset = 389526, count = 98, 1 us
[09/13 07:57:14] [52] [ap] offset = 390644, count = 68, 82 us
[09/13 07:57:14] [52] [ap] offset = 844, count = 2, 13 us
[09/13 07:57:14] [52] [ap] offset = 846, count = 2, 1 us
[09/13 07:57:14] [52] [ap] offset = 11455768, count = 2, 1 us
[09/13 07:57:14] [52] [ap] offset = 11455770, count = 2, 1 us
[09/13 07:57:14] [52] [ap] offset = 390654, count = 58, 2 us
[09/13 07:57:14] [52] [ap] offset = 389624, count = 112, 73 us
[09/13 07:57:14] [52] [ap] offset = 796, count = 2, 1 us
[09/13 07:57:14] [52] [ap] offset = 798, count = 2, 1 us
[09/13 07:57:14] [52] [ap] offset = 11455720, count = 2, 1 us
[09/13 07:57:14] [52] [ap] offset = 11455722, count = 2, 0 us
[09/13 07:57:14] [52] [ap] offset = 389634, count = 102, 1 us
[09/13 07:57:14] [52] [ap] offset = 389936, count = 92, 3 us
[09/13 07:57:14] [52] [ap] offset = 808, count = 2, 1 us
[09/13 07:57:14] [52] [ap] offset = 810, count = 2, 0 us
[09/13 07:57:14] [52] [ap] offset = 11455732, count = 2, 0 us
[09/13 07:57:14] [52] [ap] offset = 11455734, count = 2, 0 us
[09/13 07:57:14] [52] [ap] offset = 389946, count = 82, 1 us
[09/13 07:57:14] [52] [ap] offset = 390304, count = 60, 3 us
[09/13 07:57:14] [52] [ap] offset = 824, count = 2, 1 us
[09/13 07:57:14] [52] [ap] offset = 826, count = 2, 0 us
[09/13 07:57:14] [52] [ap] offset = 11455748, count = 2, 0 us
[09/13 07:57:14] [52] [ap] offset = 11455750, count = 2, 0 us
[09/13 07:57:14] [52] [ap] offset = 390314, count = 50, 0 us
[09/13 07:57:14] [52] [ap] offset = 390096, count = 140, 4 us
[09/13 07:57:14] [52] [ap] offset = 816, count = 2, 1 us
[09/13 07:57:14] [52] [ap] offset = 818, count = 2, 1 us
[09/13 07:57:14] [52] [ap] offset = 11455740, count = 2, 0 us
[09/13 07:57:14] [52] [ap] offset = 11455742, count = 2, 0 us
[09/13 07:57:14] [52] [ap] offset = 390106, count = 130, 2 us
[09/13 07:57:14] [52] [ap] offset = 391076, count = 108, 83 us
[09/13 07:57:14] [52] [ap] offset = 864, count = 2, 2 us
[09/13 07:57:14] [52] [ap] offset = 866, count = 2, 1 us
[09/13 07:57:14] [52] [ap] offset = 11455788, count = 2, 1 us
[09/13 07:57:14] [52] [ap] offset = 11455790, count = 2, 1 us
[09/13 07:57:14] [52] [ap] offset = 391086, count = 98, 2 us
[09/13 07:57:14] [52] [ap] offset = 391024, count = 52, 3 us
[09/13 07:57:14] [52] [ap] offset = 860, count = 2, 1 us
[09/13 07:57:14] [52] [ap] offset = 862, count = 2, 0 us
[09/13 07:57:14] [52] [ap] offset = 11455784, count = 2, 0 us
[09/13 07:57:14] [52] [ap] offset = 11455786, count = 2, 0 us
[09/13 07:57:14] [52] [ap] offset = 391034, count = 42, 0 us
[09/13 07:57:14] [52] [ap] offset = 390712, count = 88, 1 us
[09/13 07:57:14] [52] [ap] offset = 848, count = 2, 1 us
[09/13 07:57:14] [52] [ap] offset = 850, count = 2, 0 us
[09/13 07:57:14] [52] [ap] offset = 11455772, count = 2, 1 us
[09/13 07:57:14] [52] [ap] offset = 11455774, count = 2, 0 us
[09/13 07:57:14] [52] [ap] offset = 390722, count = 78, 1 us
[09/13 07:57:14] [52] [ap] offset = 390028, count = 68, 3 us
[09/13 07:57:14] [52] [ap] offset = 812, count = 2, 1 us
[09/13 07:57:14] [52] [ap] offset = 814, count = 2, 1 us
[09/13 07:57:14] [52] [ap] offset = 11455736, count = 2, 1 us
[09/13 07:57:14] [52] [ap] offset = 11455738, count = 2, 0 us
[09/13 07:57:14] [52] [ap] offset = 390038, count = 58, 1 us
[09/13 07:57:14] [52] [ap] offset = 389824, count = 112, 4 us
[09/13 07:57:14] [52] [ap] offset = 804, count = 2, 1 us
[09/13 07:57:14] [52] [ap] offset = 806, count = 2, 1 us
[09/13 07:57:14] [52] [ap] offset = 11455728, count = 2, 0 us
[09/13 07:57:14] [52] [ap] offset = 11455730, count = 2, 0 us
[09/13 07:57:14] [52] [ap] offset = 389834, count = 102, 1 us
[09/13 07:57:14] [52] [ap] offset = 390912, count = 112, 3 us
[09/13 07:57:14] [52] [ap] offset = 856, count = 2, 1 us
[09/13 07:57:14] [52] [ap] offset = 858, count = 2, 2 us
[09/13 07:57:14] [52] [ap] offset = 11455780, count = 2, 0 us
[09/13 07:57:14] [52] [ap] offset = 11455782, count = 2, 0 us
[09/13 07:57:14] [52] [ap] offset = 390922, count = 102, 1 us
[09/13 07:57:14] [52] [ap] offset = 391184, count = 68, 3 us
[09/13 07:57:14] [52] [ap] offset = 868, count = 2, 1 us
[09/13 07:57:14] [52] [ap] offset = 870, count = 2, 1 us
[09/13 07:57:14] [52] [ap] offset = 11455792, count = 2, 0 us
[09/13 07:57:14] [52] [ap] offset = 11455794, count = 2, 0 us
[09/13 07:57:14] [52] [ap] offset = 391194, count = 58, 1 us
[09/13 07:57:14] [52] [ap] offset = 391476, count = 44, 3 us
[09/13 07:57:14] [52] [ap] offset = 888, count = 2, 2 us
[09/13 07:57:14] [52] [ap] offset = 890, count = 2, 1 us
[09/13 07:57:14] [52] [ap] offset = 11455812, count = 2, 1 us
[09/13 07:57:14] [52] [ap] offset = 11455814, count = 2, 0 us
[09/13 07:57:14] [52] [ap] offset = 391486, count = 34, 1 us
[09/13 07:57:14] [52] [ap] offset = 386188, count = 24, 920 us
[09/13 07:57:14] [52] [ap] offset = 588, count = 2, 1 us
[09/13 07:57:14] [52] [ap] offset = 590, count = 2, 0 us
[09/13 07:57:14] [52] [ap] offset = 11455512, count = 2, 0 us
[09/13 07:57:14] [52] [ap] offset = 11455514, count = 2, 0 us
[09/13 07:57:14] [52] [ap] offset = 386198, count = 14, 1 us
[09/13 07:57:14] [52] [ap] offset = 2573696, count = 72, 697 us
[09/13 07:57:14] [52] [ap] offset = 38164, count = 2, 501 us
[09/13 07:57:14] [52] [ap] offset = 38166, count = 2, 3 us
[09/13 07:57:14] [52] [ap] offset = 11493088, count = 2, 651 us
[09/13 07:57:14] [52] [ap] offset = 11493090, count = 2, 2 us
[09/13 07:57:14] [52] [ap] offset = 2573706, count = 62, 1 us
[09/13 07:57:14] [52] [ap] offset = 4904728, count = 96, 666 us
[09/13 07:57:14] [52] [ap] offset = 77480, count = 2, 498 us
[09/13 07:57:14] [52] [ap] offset = 77482, count = 2, 1 us
[09/13 07:57:14] [52] [ap] offset = 11532404, count = 2, 495 us
[09/13 07:57:14] [52] [ap] offset = 11532406, count = 2, 2 us
[09/13 07:57:14] [52] [ap] offset = 4904738, count = 86, 2 us
[09/13 07:57:14] [52] [ap] offset = 5645712, count = 112, 610 us
[09/13 07:57:14] [52] [ap] offset = 88668, count = 2, 531 us
[09/13 07:57:14] [52] [ap] offset = 88670, count = 2, 1 us
[09/13 07:57:14] [52] [ap] offset = 11543592, count = 2, 494 us
[09/13 07:57:14] [52] [ap] offset = 11543594, count = 2, 1 us
[09/13 07:57:14] [52] [ap] offset = 5645722, count = 102, 1 us
[09/13 07:57:14] [52] [ap] offset = 5765880, count = 92, 617 us
[09/13 07:57:14] [52] [ap] offset = 90580, count = 2, 524 us
[09/13 07:57:14] [52] [ap] offset = 90582, count = 2, 2 us
[09/13 07:57:14] [52] [ap] offset = 11545504, count = 2, 501 us
[09/13 07:57:14] [52] [ap] offset = 11545506, count = 2, 1 us
[09/13 07:57:14] [52] [ap] offset = 5765890, count = 82, 1 us
[09/13 07:57:14] [52] [ap] offset = 4908172, count = 96, 578 us
[09/13 07:57:14] [52] [ap] offset = 77552, count = 2, 509 us
[09/13 07:57:14] [52] [ap] offset = 77554, count = 2, 2 us
[09/13 07:57:14] [52] [ap] offset = 11532476, count = 2, 497 us
[09/13 07:57:14] [52] [ap] offset = 11532478, count = 2, 2 us
[09/13 07:57:14] [52] [ap] offset = 4908182, count = 86, 1 us
[09/13 07:57:14] [52] [ap] offset = 9956260, count = 16, 607 us
[09/13 07:57:14] [52] [ap] offset = 168040, count = 2, 502 us
[09/13 07:57:14] [52] [ap] offset = 168042, count = 2, 3 us
[09/13 07:57:14] [52] [ap] offset = 11622964, count = 2, 510 us
[09/13 07:57:14] [52] [ap] offset = 11622966, count = 2, 2 us
[09/13 07:57:14] [52] [ap] offset = 9956270, count = 6, 0 us
[09/13 07:57:14] [52] [ap] offset = 386120, count = 40, 508 us
[09/13 07:57:14] [52] [ap] offset = 580, count = 2, 1 us
[09/13 07:57:14] [52] [ap] offset = 582, count = 2, 0 us
[09/13 07:57:14] [52] [ap] offset = 11455504, count = 2, 1 us
[09/13 07:57:14] [52] [ap] offset = 11455506, count = 2, 0 us
[09/13 07:57:14] [52] [ap] offset = 386130, count = 30, 1 us
[09/13 07:57:14] [52] [ap] offset = 3011568, count = 124, 606 us
[09/13 07:57:14] [52] [ap] offset = 46796, count = 2, 525 us
[09/13 07:57:14] [52] [ap] offset = 46798, count = 2, 3 us
[09/13 07:57:14] [52] [ap] offset = 11501720, count = 2, 505 us
[09/13 07:57:14] [52] [ap] offset = 11501722, count = 2, 1 us
[09/13 07:57:14] [52] [ap] offset = 3011578, count = 114, 546 us
[09/13 07:57:14] [52] [ap] offset = 3308632, count = 248, 615 us
[09/13 07:57:14] [52] [ap] offset = 51796, count = 2, 508 us
[09/13 07:57:14] [52] [ap] offset = 51798, count = 2, 2 us
[09/13 07:57:14] [52] [ap] offset = 11506720, count = 2, 520 us
[09/13 07:57:14] [52] [ap] offset = 11506722, count = 2, 2 us
[09/13 07:57:14] [52] [ap] offset = 3308642, count = 238, 511 us
[09/13 07:57:14] [52] [ap] offset = 2551212, count = 136, 636 us
[09/13 07:57:14] [52] [ap] offset = 37568, count = 2, 519 us
[09/13 07:57:14] [52] [ap] offset = 37570, count = 2, 1 us
[09/13 07:57:14] [52] [ap] offset = 11492492, count = 2, 516 us
[09/13 07:57:14] [52] [ap] offset = 11492494, count = 2, 2 us
[09/13 07:57:14] [52] [ap] offset = 2551222, count = 126, 510 us
[09/13 07:57:14] [52] [ap] offset = 2865244, count = 144, 561 us
[09/13 07:57:14] [52] [ap] offset = 44124, count = 2, 519 us
[09/13 07:57:14] [52] [ap] offset = 44126, count = 2, 2 us
[09/13 07:57:14] [52] [ap] offset = 11499048, count = 2, 515 us
[09/13 07:57:14] [52] [ap] offset = 11499050, count = 2, 1 us
[09/13 07:57:14] [52] [ap] offset = 2865254, count = 134, 1 us
[09/13 07:57:14] [52] [ap] offset = 3992304, count = 164, 625 us
[09/13 07:57:14] [52] [ap] offset = 63288, count = 2, 524 us
[09/13 07:57:14] [52] [ap] offset = 63290, count = 2, 1 us
[09/13 07:57:14] [52] [ap] offset = 11518212, count = 2, 507 us
[09/13 07:57:14] [52] [ap] offset = 11518214, count = 2, 1 us
[09/13 07:57:14] [52] [ap] offset = 3992314, count = 154, 1 us
[09/13 07:57:14] [52] [ap] offset = 2749324, count = 152, 631 us
[09/13 07:57:14] [52] [ap] offset = 41680, count = 2, 508 us
[09/13 07:57:14] [52] [ap] offset = 41682, count = 2, 2 us
[09/13 07:57:14] [52] [ap] offset = 11496604, count = 2, 487 us
[09/13 07:57:14] [52] [ap] offset = 11496606, count = 2, 1 us
[09/13 07:57:14] [52] [ap] offset = 2749334, count = 142, 500 us
[09/13 07:57:14] [52] [ap] offset = 2548124, count = 48, 570 us
[09/13 07:57:14] [52] [ap] offset = 37460, count = 2, 513 us
[09/13 07:57:14] [52] [ap] offset = 37462, count = 2, 1 us
[09/13 07:57:15] [52] [ap] offset = 11492384, count = 2, 520 us
[09/13 07:57:15] [52] [ap] offset = 11492386, count = 2, 1 us
[09/13 07:57:15] [52] [ap] offset = 2548134, count = 38, 508 us
[09/13 07:57:15] [52] [ap] offset = 2547404, count = 28, 587 us
[09/13 07:57:15] [52] [ap] offset = 37420, count = 2, 498 us
[09/13 07:57:15] [52] [ap] offset = 37422, count = 2, 2 us
[09/13 07:57:15] [52] [ap] offset = 11492344, count = 2, 513 us
[09/13 07:57:15] [52] [ap] offset = 11492346, count = 2, 1 us
[09/13 07:57:15] [52] [ap] offset = 2547414, count = 18, 507 us
[09/13 07:57:15] [52] [ap] offset = 3500112, count = 196, 545 us
[09/13 07:57:15] [52] [ap] offset = 55384, count = 2, 518 us
[09/13 07:57:15] [52] [ap] offset = 55386, count = 2, 1 us
[09/13 07:57:15] [52] [ap] offset = 11510308, count = 2, 485 us
[09/13 07:57:15] [52] [ap] offset = 11510310, count = 2, 2 us
[09/13 07:57:15] [52] [ap] offset = 3500122, count = 186, 493 us
[09/13 07:57:15] [52] [ap] offset = 3439528, count = 116, 630 us
[09/13 07:57:15] [52] [ap] offset = 54264, count = 2, 526 us
[09/13 07:57:15] [52] [ap] offset = 54266, count = 2, 1 us
[09/13 07:57:15] [52] [ap] offset = 11509188, count = 2, 581 us
[09/13 07:57:15] [52] [ap] offset = 11509190, count = 2, 1 us
[09/13 07:57:15] [52] [ap] offset = 3439538, count = 106, 556 us
[09/13 07:57:15] [52] [ap] offset = 5284624, count = 240, 558 us
[09/13 07:57:15] [52] [ap] offset = 83792, count = 2, 510 us
[09/13 07:57:15] [52] [ap] offset = 83794, count = 2, 2 us
[09/13 07:57:15] [52] [ap] offset = 11538716, count = 2, 481 us
[09/13 07:57:15] [52] [ap] offset = 11538718, count = 2, 2 us
[09/13 07:57:15] [52] [ap] offset = 5284634, count = 230, 503 us
[09/13 07:57:15] [52] [ap] offset = 558316, count = 76, 634 us
[09/13 07:57:15] [52] [ap] offset = 7328, count = 2, 494 us
[09/13 07:57:15] [52] [ap] offset = 7330, count = 2, 3 us
[09/13 07:57:15] [52] [ap] offset = 11462252, count = 2, 560 us
[09/13 07:57:15] [52] [ap] offset = 11462254, count = 2, 2 us
[09/13 07:57:15] [52] [ap] offset = 558326, count = 66, 512 us

xiaoxiang781216 · 2023-09-16T13:42:52Z

how about port sdbench and sdstress back to nuttx/apps?

I don't mind pushing what I have back up, I'm just not sure on licencing requirements.

PX4 use BSD-3-Clause license, which is compatible with NuttX Apache license, so the license isn't a block issue.

Do we need to include both licences, get permission from PX4?

No, we just need:

Keep their license in the header file
Let the new option in Kconfig depends on ALLOW_BSD_COMPONENTS
Add their copyright to https://github.com/apache/nuttx-apps/blob/master/LICENSE

g2gps · 2023-09-18T04:07:06Z

@FASTSHIFT

Thanks for trying this out. A couple of things

Would you mind enabling CONFIG_BLOCK_CACHE_DEBUG and rerunning that example, so we can see the cache is being used.
What file system are you using?
Is there a Nuttx example application I can use or modify to test this on my end?

…xisting devices. Adds an optional block device driver which can encapsulate and provide block based caching.

g2gps · 2024-09-12T02:47:04Z

I was hoping to revisit this and look at getting this integrated. We've been using this locally on a few of our targets since this PR was opened.

One thing which should be added to the documentation for this feature, is that it is only going to provide a performance benefit if the speed of the RAM on the target is much faster than block device being cached. Otherwise it's unnecessary overhead.

Possibly, I could redo a few of the file system related tests on a QEMU target, with a ramdisk. This would verify the integrity. The performance gain is going to be dependent on the hardware configuration.

xiaoxiang781216 reviewed Sep 4, 2023

View reviewed changes

Comment thread drivers/misc/Kconfig Outdated

Comment thread include/nuttx/drivers/block_cache.h Outdated

Comment thread drivers/misc/block_cache.c Outdated

g2gps mentioned this pull request Sep 5, 2023

arch/risc-v/litex/litex_sdio: Address race condition in eventwait. #10481

Merged

g2gps force-pushed the block-caching branch from 8ecda5d to 45cfed0 Compare September 5, 2023 06:48

g2gps marked this pull request as ready for review September 5, 2023 06:48

g2gps force-pushed the block-caching branch 3 times, most recently from 0ca9f90 to be023e4 Compare September 8, 2023 05:47

This was referenced Oct 23, 2023

testing/sd_stress: Port sdstress testing utility from PX4-Autopilot. apache/nuttx-apps#2150

Merged

testing/sd_bench: Port sdbench testing utility for PX4-Autopilot. apache/nuttx-apps#2164

Merged

drivers/misc/block_cache: Add block driver which can add caching to e…

dece509

…xisting devices. Adds an optional block device driver which can encapsulate and provide block based caching.

g2gps force-pushed the block-caching branch from be023e4 to dece509 Compare September 11, 2024 02:47

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

drivers/misc/block_cache: Add block driver which can add caching to e…#10478

drivers/misc/block_cache: Add block driver which can add caching to e…#10478
g2gps wants to merge 1 commit intoapache:masterfrom
motec-research:block-caching

g2gps commented Sep 4, 2023

Uh oh!

Donny9 commented Sep 4, 2023

Uh oh!

xiaoxiang781216 commented Sep 4, 2023

Uh oh!

Uh oh!

Uh oh!

Uh oh!

acassis commented Sep 4, 2023

Uh oh!

g2gps commented Sep 5, 2023

Uh oh!

g2gps commented Sep 5, 2023

Uh oh!

g2gps commented Sep 5, 2023

Uh oh!

g2gps commented Sep 5, 2023 •

edited

Loading

Uh oh!

FASTSHIFT commented Sep 15, 2023 •

edited

Loading

Uh oh!

xiaoxiang781216 commented Sep 16, 2023

Uh oh!

g2gps commented Sep 18, 2023

Uh oh!

g2gps commented Sep 12, 2024

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

5 participants

Conversation

g2gps commented Sep 4, 2023

Summary

Impact

Testing

Uh oh!

Donny9 commented Sep 4, 2023

Uh oh!

xiaoxiang781216 commented Sep 4, 2023

Uh oh!

Uh oh!

Uh oh!

Uh oh!

acassis commented Sep 4, 2023

Uh oh!

g2gps commented Sep 5, 2023

Uh oh!

g2gps commented Sep 5, 2023

Uh oh!

g2gps commented Sep 5, 2023

Uh oh!

g2gps commented Sep 5, 2023 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

FASTSHIFT commented Sep 15, 2023 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

xiaoxiang781216 commented Sep 16, 2023

Uh oh!

g2gps commented Sep 18, 2023

Uh oh!

g2gps commented Sep 12, 2024

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

5 participants

g2gps commented Sep 5, 2023 •

edited

Loading

FASTSHIFT commented Sep 15, 2023 •

edited

Loading