1397 CreateFiles(nFiles,fSize); |
1397 CreateFiles(nFiles,fSize); |
1398 #if defined(_DEBUG) || defined(_DEBUG_RELEASE) |
1398 #if defined(_DEBUG) || defined(_DEBUG_RELEASE) |
1399 // get number of items on Page Cache |
1399 // get number of items on Page Cache |
1400 TFileCacheStats startPageCacheStats; |
1400 TFileCacheStats startPageCacheStats; |
1401 TInt r = controlIo(TheFs,gDrive, KControlIoFileCacheStats, startPageCacheStats); |
1401 TInt r = controlIo(TheFs,gDrive, KControlIoFileCacheStats, startPageCacheStats); |
1402 test(r==KErrNone || r == KErrNotSupported); |
1402 test_Value(r, r == KErrNone || r == KErrNotSupported); |
1403 test.Printf(_L("Number of page cache lines on free list at beginning=%d\n"),startPageCacheStats.iFreeCount); |
1403 test.Printf(_L("Number of page cache lines on free list at beginning=%d\n"),startPageCacheStats.iFreeCount); |
1404 test.Printf(_L("Number of page cache lines on used list at beginning=%d\n"),startPageCacheStats.iUsedCount); |
1404 test.Printf(_L("Number of page cache lines on used list at beginning=%d\n"),startPageCacheStats.iUsedCount); |
1405 test.Printf(_L("Number of files on closed queue=%d\n"),startPageCacheStats.iFilesOnClosedQueue); |
1405 test.Printf(_L("Number of files on closed queue=%d\n"),startPageCacheStats.iFilesOnClosedQueue); |
1406 #endif |
1406 #endif |
1407 FillCache(file,nFiles,fSize); |
1407 FillCache(file,nFiles,fSize); |
1408 |
1408 |
1409 #if defined(_DEBUG) || defined(_DEBUG_RELEASE) |
1409 #if defined(_DEBUG) || defined(_DEBUG_RELEASE) |
1410 // get number of items on Page Cache |
1410 // get number of items on Page Cache |
1411 r = controlIo(TheFs,gDrive, KControlIoFileCacheStats, startPageCacheStats); |
1411 r = controlIo(TheFs,gDrive, KControlIoFileCacheStats, startPageCacheStats); |
1412 test(r==KErrNone || r == KErrNotSupported); |
1412 test_Value(r, r == KErrNone || r == KErrNotSupported); |
1413 test.Printf(_L("Number of page cache lines on free list at end=%d\n"),startPageCacheStats.iFreeCount); |
1413 test.Printf(_L("Number of page cache lines on free list at end=%d\n"),startPageCacheStats.iFreeCount); |
1414 test.Printf(_L("Number of page cache lines on used list at end=%d\n"),startPageCacheStats.iUsedCount); |
1414 test.Printf(_L("Number of page cache lines on used list at end=%d\n"),startPageCacheStats.iUsedCount); |
1415 test.Printf(_L("Number of files on closed queue=%d\n"),startPageCacheStats.iFilesOnClosedQueue); |
1415 test.Printf(_L("Number of files on closed queue=%d\n"),startPageCacheStats.iFilesOnClosedQueue); |
1416 #endif |
1416 #endif |
1417 TestSimpleRead(); |
1417 TestSimpleRead(); |
1444 |
1444 |
1445 /** Read three blocks and waits for the read ahead on the File Server to do its job |
1445 /** Read three blocks and waits for the read ahead on the File Server to do its job |
1446 |
1446 |
1447 */ |
1447 */ |
1448 LOCAL_C void TestReadAhead() |
1448 LOCAL_C void TestReadAhead() |
1449 { |
1449 { |
1450 TInt r = 0,tcreate; |
1450 TInt r = 0,tcreate; |
1451 RFile fileRead; |
1451 RFile fileRead; |
1452 HBufC8* dummy = NULL; |
1452 HBufC8* dummy = NULL; |
1453 TPtr8 dummyPtr(NULL, 0); |
1453 TPtr8 dummyPtr(NULL, 0); |
1454 |
1454 |
1455 TUint32 initTicks = 0; |
1455 TUint32 initTicks = 0; |
1456 TUint32 finalTicks = 0; |
1456 TUint32 finalTicks = 0; |
1457 TTimeIntervalMicroSeconds timeTakenReadFirst(0); |
|
1458 TTimeIntervalMicroSeconds timeTakenReadSubsequent(0); |
|
1459 |
|
1460 // On NAND/FAT and NOR/LFFS drives, due to the lack of DMA support, the read-ahead is likely to happen |
|
1461 // BEFORE control is returned to this test app - for NAND this could be fixed by adding |
|
1462 // "FileCacheReadAsync OFF" to the estart.txt file, but we can't do this on the integrator as it has no |
|
1463 // estart.txt file. Also, we can't set "FileCacheReadAsync OFF" for LFFS as it kills the LFFS background |
|
1464 // processing (!) |
|
1465 // So... it's only really worth testing on MMC. |
|
1466 _LIT(KFATName,"FAT"); |
|
1467 TDriveInfo driveInfo; |
|
1468 test(TheFs.Drive(driveInfo, gDrive) == KErrNone); |
|
1469 TFileName fileSystem; |
|
1470 r = TheFs.FileSystemName(fileSystem, gDrive); |
|
1471 fileSystem.UpperCase(); |
|
1472 test((r==KErrNone)||(r==KErrNotFound)); |
|
1473 // ONLY test on MMC |
|
1474 if ((driveInfo.iType != EMediaHardDisk) || (fileSystem.Compare(KFATName) != 0)) |
|
1475 { |
|
1476 test.Printf(_L("Skipping read-ahead testing (drive is not MMC)...\n")); |
|
1477 return; |
|
1478 } |
|
1479 |
1457 |
1480 //--Find out if the drive is sync/async at this point and print information |
1458 //--Find out if the drive is sync/async at this point and print information |
1481 TPckgBuf<TBool> drvSyncBuf; |
1459 TPckgBuf<TBool> drvSyncBuf; |
1482 r = TheFs.QueryVolumeInfoExt(gDrive, EIsDriveSync, drvSyncBuf); |
1460 r = TheFs.QueryVolumeInfoExt(gDrive, EIsDriveSync, drvSyncBuf); |
1483 test(r == KErrNone); |
1461 test_KErrNone(r); |
1484 const TBool bDrvSync = drvSyncBuf(); |
1462 const TBool bDrvSync = drvSyncBuf(); |
1485 if(bDrvSync) |
1463 if(bDrvSync) |
1486 test.Printf(_L("Drive D: is synchronous\n")); |
1464 test.Printf(_L("Drive D: is synchronous\n")); |
1487 else |
1465 else |
1488 test.Printf(_L("Drive D: is asynchronous\n")); |
1466 test.Printf(_L("Drive D: is asynchronous\n")); |
1489 |
1467 |
1490 // use a fast counter as this is more accurate than using TTime |
1468 // use a fast counter as this is more accurate than using TTime |
1491 TInt fastCounterFreq; |
1469 TInt fastCounterFreq; |
1492 r = HAL::Get(HAL::EFastCounterFrequency, fastCounterFreq); |
1470 r = HAL::Get(HAL::EFastCounterFrequency, fastCounterFreq); |
1493 test(r == KErrNone); |
1471 test_KErrNone(r); |
1494 test.Printf(_L("HAL::EFastCounterFrequency %d\n"), fastCounterFreq); |
1472 test.Printf(_L("HAL::EFastCounterFrequency %d\n"), fastCounterFreq); |
1495 |
1473 |
1496 // Bind this thread to CPU 0. This is so that timer deltas don't drift from |
1474 // Bind this thread to CPU 0. This is so that timer deltas don't drift from |
1497 // scheduling - else, it causes spurious failures. |
1475 // scheduling - else, it causes spurious failures. |
1498 if (UserSvr::HalFunction(EHalGroupKernel, EKernelHalNumLogicalCpus, 0, 0) > 1) |
1476 if (UserSvr::HalFunction(EHalGroupKernel, EKernelHalNumLogicalCpus, 0, 0) > 1) |
1499 (void)UserSvr::HalFunction(EHalGroupKernel, EKernelHalLockThreadToCpu, (TAny *)0, 0); |
1477 (void)UserSvr::HalFunction(EHalGroupKernel, EKernelHalLockThreadToCpu, (TAny *)0, 0); |
1500 |
1478 |
1501 const TInt KReadLen = 28 * KOneK; |
1479 const TInt KReadLen = 28 * KOneK; |
1502 |
1480 |
1503 TRAPD(res,dummy = HBufC8::NewL(KReadLen)); |
1481 TRAPD(res,dummy = HBufC8::NewL(KReadLen)); |
1504 test(res == KErrNone && dummy != NULL); |
1482 test_Value(res, res== KErrNone && dummy != NULL); |
1505 |
1483 |
1506 dummyPtr.Set(dummy->Des()); |
1484 dummyPtr.Set(dummy->Des()); |
1507 |
1485 |
1508 test.Start(_L("Creating test file...")); |
1486 test.Start(_L("Creating test file...")); |
1509 |
1487 |
1512 test.Printf(_L("Time to create the file: %d ms\n"),tcreate); |
1490 test.Printf(_L("Time to create the file: %d ms\n"),tcreate); |
1513 |
1491 |
1514 r = fileRead.Open(TheFs,gFirstFile,EFileShareAny|EFileRead|EFileReadBuffered|EFileReadAheadOn); |
1492 r = fileRead.Open(TheFs,gFirstFile,EFileShareAny|EFileRead|EFileReadBuffered|EFileReadAheadOn); |
1515 test_KErrNone(r); |
1493 test_KErrNone(r); |
1516 |
1494 |
1517 // Read #1 |
1495 #if defined(_DEBUG) || defined(_DEBUG_RELEASE) |
1518 test.Printf(_L("Issuing read #1...\n")); |
1496 TFileCacheStats fileCacheStats; |
1519 initTicks = User::FastCounter(); |
1497 r = controlIo(TheFs,gDrive, KControlIoFileCacheStats, fileCacheStats); |
1520 r = fileRead.Read(dummyPtr); |
1498 test_KErrNone(r); |
1521 finalTicks = User::FastCounter(); |
1499 TInt totalBytesRead = fileCacheStats.iUncachedBytesRead; |
1522 test_KErrNone(r); |
1500 test.Printf(_L("totalBytesRead %d\n"), totalBytesRead); |
1523 |
1501 TInt bytesRead = 0; |
1524 timeTakenReadFirst = TicksToMsec(initTicks, finalTicks, fastCounterFreq); |
1502 TInt filePos = 0; |
1525 test.Printf(_L("first read time %d \n"), I64LOW(timeTakenReadFirst.Int64())); |
1503 #endif |
1526 |
1504 |
1527 // Read #2 |
1505 const TInt KReadCount = 6; |
1528 test.Printf(_L("Issuing read #2...\n")); |
1506 #define PAGE_ROUND_UP(x) ((x + 4095) & (-4096)) |
1529 r = fileRead.Read(dummyPtr); |
1507 TInt expectedBytesRead[KReadCount] = |
1530 |
1508 { |
1531 // Read #3 |
1509 PAGE_ROUND_UP(KReadLen), // read #0 from media |
1532 test.Printf(_L("Issuing read #3......resulting in read-ahead #1\n")); |
1510 PAGE_ROUND_UP(KReadLen), // read #1 from media |
1533 r = fileRead.Read(dummyPtr); |
1511 PAGE_ROUND_UP(KReadLen*2), // read #2 from media, read-ahead #1 of length KReadLen |
1534 |
1512 PAGE_ROUND_UP(KReadLen*2), // read #3 from cache, read-ahead #2 of length KReadLen * 2 |
1535 // Wait for the read ahead #1 to be done - this should be approx the same size as previous read (KReadLen) |
1513 PAGE_ROUND_UP(KReadLen*4), // read #4 from cache, read-ahead #3 of length KReadLen * 4 |
1536 test.Printf(_L("Wait for read-ahead #1...\n")); |
1514 0, // read #5 from cache, no read-ahead |
1537 User::After(I64LOW(timeTakenReadFirst.Int64()) * 3 / 2); |
1515 }; |
1538 |
1516 TTimeIntervalMicroSeconds readTimes[KReadCount]; |
1539 |
1517 |
1540 test.Printf(_L("Issuing read #4...resulting in read-ahead #2\n")); |
1518 for (TInt n=0; n<KReadCount; n++) |
1541 initTicks = User::FastCounter(); |
1519 { |
1542 r = fileRead.Read(dummyPtr); |
1520 |
1543 finalTicks = User::FastCounter(); |
1521 initTicks = User::FastCounter(); |
1544 test_KErrNone(r); |
1522 r = fileRead.Read(dummyPtr); |
1545 timeTakenReadSubsequent = TicksToMsec(initTicks, finalTicks, fastCounterFreq); |
1523 finalTicks = User::FastCounter(); |
1546 |
1524 test_KErrNone(r); |
1547 test.Printf(_L("read time: %d \n"), I64LOW(timeTakenReadSubsequent.Int64())); |
1525 |
|
1526 readTimes[n] = TicksToMsec(initTicks, finalTicks, fastCounterFreq); |
|
1527 test.Printf(_L("%d: read time %d \n"), n, I64LOW(readTimes[n].Int64())); |
|
1528 |
|
1529 TInt readAheadTime = I64LOW(readTimes[0].Int64()) * expectedBytesRead[n] / expectedBytesRead[0]; |
|
1530 // Wait for the read ahead to be done |
|
1531 if (n >= 2) |
|
1532 { |
|
1533 test.Printf(_L("Wait %u uS for read-ahead ...\n"), readAheadTime); |
|
1534 User::After(readAheadTime); |
|
1535 } |
|
1536 |
|
1537 #if defined(_DEBUG) || defined(_DEBUG_RELEASE) |
|
1538 // check the number of bytes read from the media is as expected. i.e. including the read-ahead length |
|
1539 // Keep waiting if it's not for up to 10 seconds |
|
1540 const TInt KMaxWaitTime = 10000000; // 10 secs |
|
1541 TInt waitTime; |
|
1542 for (waitTime=0; waitTime <KMaxWaitTime; waitTime+= readAheadTime) |
|
1543 { |
|
1544 r = controlIo(TheFs,gDrive, KControlIoFileCacheStats, fileCacheStats); |
|
1545 test_KErrNone(r); |
|
1546 bytesRead = fileCacheStats.iUncachedBytesRead - totalBytesRead; |
|
1547 TInt bytesReadExpected = Min(gFirstFileSize - filePos, expectedBytesRead[n]); |
|
1548 |
|
1549 test.Printf(_L("bytesRead %d, bytesReadExpected %d\n"), bytesRead, bytesReadExpected); |
|
1550 |
|
1551 if (bytesRead == bytesReadExpected) |
|
1552 break; |
|
1553 User::After(readAheadTime); |
|
1554 } |
|
1555 test(waitTime < KMaxWaitTime); |
|
1556 totalBytesRead+= bytesRead; |
|
1557 filePos += bytesRead; |
|
1558 #endif |
1548 |
1559 |
1549 #if !defined(__WINS__) |
1560 #if !defined(__WINS__) |
1550 // NB the read-ahead on LFFS occurs "synchronously" i.e. it occurs before control is returned |
1561 // Read #3 should be able to be satisfied entirely from the cache, so should be quicker. If it's not quicker, |
1551 // to the caller. However it's not a good idea to mark the drive as synchronous (FileCacheReadAsync OFF) |
1562 // display a warning rather than failing, because the read-ahead might be hogging the CPU, delaying the read from the cache. |
1552 // as this causes the drive thread's priority to be lowered which kills the LFFS background processing (!) |
1563 if (n >= 3) |
1553 if (gPagedRom) |
1564 { |
1554 test.Printf(_L("Skipping timing test on paged ROM\n")); |
1565 if (readTimes[n].Int64() >= readTimes[0].Int64()) |
1555 else |
1566 test.Printf(_L("WARNING: Subsequent read not faster despite read-ahead !!!\n")); |
1556 test(timeTakenReadSubsequent.Int64() < timeTakenReadFirst.Int64()); |
1567 } |
1557 #endif |
1568 #endif |
1558 |
1569 } |
1559 // The read ahead #2 should now be in progress - this should be approx KReadLen * 2 |
|
1560 // so this read will take result in the next read taking longer than normal (about double) |
|
1561 test.Printf(_L("Issuing read #5......resulting in read-ahead #3\n")); |
|
1562 initTicks = User::FastCounter(); |
|
1563 r = fileRead.Read(dummyPtr); |
|
1564 finalTicks = User::FastCounter(); |
|
1565 test_KErrNone(r); |
|
1566 timeTakenReadSubsequent = TicksToMsec(initTicks, finalTicks, fastCounterFreq); |
|
1567 test.Printf(_L("read time: %d\n"), I64LOW(timeTakenReadSubsequent.Int64())); |
|
1568 |
|
1569 |
|
1570 // this read should take a long time, so don't test |
|
1571 //#if !defined(__WINS__) |
|
1572 // test(gTimeTakenReadBlockFile.Int64() < gTimeTakenBigFile.Int64()); |
|
1573 //#endif |
|
1574 |
|
1575 // The third read should be very quick as the previous read-ahead should have already buffered the data |
|
1576 test.Printf(_L("Issuing read #6......resulting in read-ahead #4\n")); |
|
1577 initTicks = User::FastCounter(); |
|
1578 r = fileRead.Read(dummyPtr); |
|
1579 finalTicks = User::FastCounter(); |
|
1580 test_KErrNone(r); |
|
1581 timeTakenReadSubsequent = TicksToMsec(initTicks, finalTicks, fastCounterFreq); |
|
1582 test.Printf(_L("read time: %d\n"), I64LOW(timeTakenReadSubsequent.Int64())); |
|
1583 |
|
1584 |
|
1585 #if !defined(__WINS__) |
|
1586 if (gPagedRom) |
|
1587 test.Printf(_L("Skipping timing test on paged ROM\n")); |
|
1588 else |
|
1589 test(timeTakenReadSubsequent.Int64() < timeTakenReadFirst.Int64()); |
|
1590 #endif |
|
1591 |
|
1592 |
|
1593 fileRead.Close(); |
1570 fileRead.Close(); |
1594 |
1571 |
1595 r = DeleteAll(gSessionPath); |
1572 r = DeleteAll(gSessionPath); |
1596 test_KErrNone(r); |
1573 test_KErrNone(r); |
1597 |
1574 |
1598 delete dummy; |
1575 delete dummy; |
1599 test.End(); |
1576 test.End(); |
1600 |
1577 } |
1601 } |
|
1602 |
1578 |
1603 /** Main tests function |
1579 /** Main tests function |
1604 */ |
1580 */ |
1605 GLDEF_C void CallTestsL() |
1581 GLDEF_C void CallTestsL() |
1606 { |
1582 { |
1607 #if defined(_DEBUG) || defined(_DEBUG_RELEASE) |
1583 #if defined(_DEBUG) || defined(_DEBUG_RELEASE) |
1608 test.Printf(_L("Disabling Lock Fail simulation ...\n")); |
1584 test.Printf(_L("Disabling Lock Fail simulation ...\n")); |
1609 // turn OFF lock failure mode |
1585 // turn OFF lock failure mode |
1610 TBool simulatelockFailureMode = EFalse; |
1586 TBool simulatelockFailureMode = EFalse; |
1611 TInt r = controlIo(TheFs, gDrive, KControlIoSimulateLockFailureMode, simulatelockFailureMode); |
1587 TInt r = controlIo(TheFs, gDrive, KControlIoSimulateLockFailureMode, simulatelockFailureMode); |
1612 test (r == KErrNone); |
1588 test_KErrNone(r); |
1613 #endif |
1589 #endif |
1614 |
1590 |
1615 TBuf16<45> dir; |
1591 TBuf16<45> dir; |
1616 |
1592 |
1617 RProcess().SetPriority(EPriorityBackground); |
1593 RProcess().SetPriority(EPriorityBackground); |