diff -r 345b1ca54e88 -r 039a3e647356 kerneltest/f32test/server/t_rcache.cpp --- a/kerneltest/f32test/server/t_rcache.cpp Wed Sep 15 13:42:27 2010 +0300 +++ b/kerneltest/f32test/server/t_rcache.cpp Wed Oct 13 16:04:24 2010 +0300 @@ -434,7 +434,7 @@ // delete file first to ensure it's contents are not in the cache (file may be be on the closed file queue) r = fs.Delete(aFile); - test_Value(r, r == KErrNone || r == KErrNotFound); + test(r == KErrNone || r == KErrNotFound); r = aFileWrite.Replace(fs,aFile,EFileShareAny|EFileWrite|EFileReadDirectIO|EFileWriteDirectIO); test_KErrNone(r); @@ -556,7 +556,7 @@ RFile file; TInt r = fs.Connect(); - test_KErrNone(r); + test (r == KErrNone); startTime.HomeTime(); @@ -695,7 +695,7 @@ #endif r = DeleteAll(gSessionPath); - test_Value(r, r == KErrNone || r == KErrInUse); + test(r == KErrNone || r == KErrInUse); // Simple case filling/reading the cache from different threads test.Next(_L("File fits in: read sync (another thread) + read sync + read async\n")); @@ -715,7 +715,7 @@ buf = _L("Read File"); r = gThread2.Create(buf,ReadFileT,KDefaultStackSize,KHeapSize,KMaxHeapSize,NULL); - test_KErrNone(r); + test(r == KErrNone); gThread2.Resume(); client.Wait(); @@ -737,7 +737,7 @@ #endif r = DeleteAll(gSessionPath); - test_Value(r, r == KErrNone || r == KErrInUse); + test(r == KErrNone || r == KErrInUse); test.Next(_L("File doesn't fit in: read sync + read sync + read async\n")); @@ -760,7 +760,7 @@ r = DeleteAll(gSessionPath); - test_Value(r, r == KErrNone || r == KErrInUse); + test(r == KErrNone || r == KErrInUse); test.Next(_L("File doesn't fit in: read sync (another thread) + read sync + read async\n")); @@ -780,7 +780,7 @@ buf = _L("Read Big File"); r = gThread2.Create(buf,ReadFileT,KDefaultStackSize,KHeapSize,KMaxHeapSize,NULL); - test_KErrNone(r); + test(r == KErrNone); gThread2.Resume(); client.Wait(); @@ -802,7 +802,7 @@ #endif r = DeleteAll(gSessionPath); - test_Value(r, r == KErrNone || r == KErrInUse); + test(r == KErrNone || r == KErrInUse); test.End(); } @@ -823,13 +823,13 @@ test(res2 == KErrNone && lBufSec != NULL); lBufReadPtr.Set(lBufSec->Des()); - test_KErrNone(r); + test(r == KErrNone); r = fs.SetSessionPath(gSessionPath); // delete file first to ensure it's contents are not in the cache (file may be be on the closed file queue) r = fs.Delete(gFirstFile); - test_Value(r, r == KErrNone || r == KErrNotFound); + test(r == KErrNone || r == KErrNotFound); r = file.Create(fs,gFirstFile,EFileShareAny|EFileWrite|EFileReadDirectIO|EFileWriteDirectIO); @@ -944,7 +944,7 @@ TBuf<20> buf2 = _L("Write Two Files 2"); r = gThread2.Create(buf2,WriteFileT2,KDefaultStackSize*2,KHeapSize,KMaxHeapSize,NULL); - test_KErrNone(r); + test(r == KErrNone); gThread1.Resume(); gThread2.Resume(); @@ -984,10 +984,10 @@ RTest test(_L("T_RCACHE")); RFs fs; TInt r = fs.Connect(); - test_KErrNone(r); + test(r == KErrNone); r = fs.SetSessionPath(gSessionPath); - test_KErrNone(r); + test(r == KErrNone); r = WriteFile(fs, gSecondFile, gSecondFileSize, KBlockSize, gBufWritePtr, EThreadSignal); test_KErrNone(r); @@ -1069,7 +1069,7 @@ TPtr8 dummyPtr(NULL, 0); TRAPD(res,dummy = HBufC8::NewL(4)); - test_Value(res, res== KErrNone && dummy != NULL); + test(res == KErrNone && dummy != NULL); dummyPtr.Set(dummy->Des()); FillBuffer(dummyPtr, 4, '1'); @@ -1297,7 +1297,7 @@ HBufC8* bigBuf = NULL; const TInt KBigBifferSize = 32 * 1024; TRAPD(res,bigBuf = HBufC8::NewL(KBigBifferSize)); - test_Value(res, res== KErrNone && bigBuf != NULL); + test(res == KErrNone && bigBuf != NULL); TPtr8 bigBufWritePtr(NULL, 0); bigBufWritePtr.Set(bigBuf->Des()); @@ -1315,7 +1315,7 @@ // delete file first to ensure it's contents are not in the cache (file may be on the closed file queue) r = TheFs.Delete(path); - test_Value(r, r == KErrNone || r == KErrNotFound); + test(r == KErrNone || r == KErrNotFound); r = file.Create(TheFs,path,EFileShareAny|EFileWrite|EFileReadDirectIO|EFileWriteDirectIO); if(r == KErrAlreadyExists) @@ -1353,7 +1353,7 @@ TPtr8 bufPtr(NULL, 0); TRAPD(res,buf = HBufC8::NewL(2)); - test_Value(res, res== KErrNone && buf != NULL); + test(res == KErrNone && buf != NULL); bufPtr.Set(buf->Des()); directory = gSessionPath; @@ -1399,7 +1399,7 @@ // get number of items on Page Cache TFileCacheStats startPageCacheStats; TInt r = controlIo(TheFs,gDrive, KControlIoFileCacheStats, startPageCacheStats); - test_Value(r, r == KErrNone || r == KErrNotSupported); + test(r==KErrNone || r == KErrNotSupported); test.Printf(_L("Number of page cache lines on free list at beginning=%d\n"),startPageCacheStats.iFreeCount); test.Printf(_L("Number of page cache lines on used list at beginning=%d\n"),startPageCacheStats.iUsedCount); test.Printf(_L("Number of files on closed queue=%d\n"),startPageCacheStats.iFilesOnClosedQueue); @@ -1409,7 +1409,7 @@ #if defined(_DEBUG) || defined(_DEBUG_RELEASE) // get number of items on Page Cache r = controlIo(TheFs,gDrive, KControlIoFileCacheStats, startPageCacheStats); - test_Value(r, r == KErrNone || r == KErrNotSupported); + test(r==KErrNone || r == KErrNotSupported); test.Printf(_L("Number of page cache lines on free list at end=%d\n"),startPageCacheStats.iFreeCount); test.Printf(_L("Number of page cache lines on used list at end=%d\n"),startPageCacheStats.iUsedCount); test.Printf(_L("Number of files on closed queue=%d\n"),startPageCacheStats.iFilesOnClosedQueue); @@ -1446,7 +1446,7 @@ */ LOCAL_C void TestReadAhead() - { +{ TInt r = 0,tcreate; RFile fileRead; HBufC8* dummy = NULL; @@ -1454,11 +1454,33 @@ TUint32 initTicks = 0; TUint32 finalTicks = 0; + TTimeIntervalMicroSeconds timeTakenReadFirst(0); + TTimeIntervalMicroSeconds timeTakenReadSubsequent(0); + + // On NAND/FAT and NOR/LFFS drives, due to the lack of DMA support, the read-ahead is likely to happen + // BEFORE control is returned to this test app - for NAND this could be fixed by adding + // "FileCacheReadAsync OFF" to the estart.txt file, but we can't do this on the integrator as it has no + // estart.txt file. Also, we can't set "FileCacheReadAsync OFF" for LFFS as it kills the LFFS background + // processing (!) + // So... it's only really worth testing on MMC. + _LIT(KFATName,"FAT"); + TDriveInfo driveInfo; + test(TheFs.Drive(driveInfo, gDrive) == KErrNone); + TFileName fileSystem; + r = TheFs.FileSystemName(fileSystem, gDrive); + fileSystem.UpperCase(); + test((r==KErrNone)||(r==KErrNotFound)); + // ONLY test on MMC + if ((driveInfo.iType != EMediaHardDisk) || (fileSystem.Compare(KFATName) != 0)) + { + test.Printf(_L("Skipping read-ahead testing (drive is not MMC)...\n")); + return; + } //--Find out if the drive is sync/async at this point and print information TPckgBuf drvSyncBuf; r = TheFs.QueryVolumeInfoExt(gDrive, EIsDriveSync, drvSyncBuf); - test_KErrNone(r); + test(r == KErrNone); const TBool bDrvSync = drvSyncBuf(); if(bDrvSync) test.Printf(_L("Drive D: is synchronous\n")); @@ -1468,7 +1490,7 @@ // use a fast counter as this is more accurate than using TTime TInt fastCounterFreq; r = HAL::Get(HAL::EFastCounterFrequency, fastCounterFreq); - test_KErrNone(r); + test(r == KErrNone); test.Printf(_L("HAL::EFastCounterFrequency %d\n"), fastCounterFreq); // Bind this thread to CPU 0. This is so that timer deltas don't drift from @@ -1479,7 +1501,7 @@ const TInt KReadLen = 28 * KOneK; TRAPD(res,dummy = HBufC8::NewL(KReadLen)); - test_Value(res, res== KErrNone && dummy != NULL); + test(res == KErrNone && dummy != NULL); dummyPtr.Set(dummy->Des()); @@ -1492,81 +1514,82 @@ r = fileRead.Open(TheFs,gFirstFile,EFileShareAny|EFileRead|EFileReadBuffered|EFileReadAheadOn); test_KErrNone(r); -#if defined(_DEBUG) || defined(_DEBUG_RELEASE) - TFileCacheStats fileCacheStats; - r = controlIo(TheFs,gDrive, KControlIoFileCacheStats, fileCacheStats); + // Read #1 + test.Printf(_L("Issuing read #1...\n")); + initTicks = User::FastCounter(); + r = fileRead.Read(dummyPtr); + finalTicks = User::FastCounter(); test_KErrNone(r); - TInt totalBytesRead = fileCacheStats.iUncachedBytesRead; - test.Printf(_L("totalBytesRead %d\n"), totalBytesRead); - TInt bytesRead = 0; - TInt filePos = 0; + + timeTakenReadFirst = TicksToMsec(initTicks, finalTicks, fastCounterFreq); + test.Printf(_L("first read time %d \n"), I64LOW(timeTakenReadFirst.Int64())); + + // Read #2 + test.Printf(_L("Issuing read #2...\n")); + r = fileRead.Read(dummyPtr); + + // Read #3 + test.Printf(_L("Issuing read #3......resulting in read-ahead #1\n")); + r = fileRead.Read(dummyPtr); + + // Wait for the read ahead #1 to be done - this should be approx the same size as previous read (KReadLen) + test.Printf(_L("Wait for read-ahead #1...\n")); + User::After(I64LOW(timeTakenReadFirst.Int64()) * 3 / 2); + + + test.Printf(_L("Issuing read #4...resulting in read-ahead #2\n")); + initTicks = User::FastCounter(); + r = fileRead.Read(dummyPtr); + finalTicks = User::FastCounter(); + test_KErrNone(r); + timeTakenReadSubsequent = TicksToMsec(initTicks, finalTicks, fastCounterFreq); + + test.Printf(_L("read time: %d \n"), I64LOW(timeTakenReadSubsequent.Int64())); + +#if !defined(__WINS__) + // NB the read-ahead on LFFS occurs "synchronously" i.e. it occurs before control is returned + // to the caller. However it's not a good idea to mark the drive as synchronous (FileCacheReadAsync OFF) + // as this causes the drive thread's priority to be lowered which kills the LFFS background processing (!) + if (gPagedRom) + test.Printf(_L("Skipping timing test on paged ROM\n")); + else + test(timeTakenReadSubsequent.Int64() < timeTakenReadFirst.Int64()); #endif - const TInt KReadCount = 6; - #define PAGE_ROUND_UP(x) ((x + 4095) & (-4096)) - TInt expectedBytesRead[KReadCount] = - { - PAGE_ROUND_UP(KReadLen), // read #0 from media - PAGE_ROUND_UP(KReadLen), // read #1 from media - PAGE_ROUND_UP(KReadLen*2), // read #2 from media, read-ahead #1 of length KReadLen - PAGE_ROUND_UP(KReadLen*2), // read #3 from cache, read-ahead #2 of length KReadLen * 2 - PAGE_ROUND_UP(KReadLen*4), // read #4 from cache, read-ahead #3 of length KReadLen * 4 - 0, // read #5 from cache, no read-ahead - }; - TTimeIntervalMicroSeconds readTimes[KReadCount]; + // The read ahead #2 should now be in progress - this should be approx KReadLen * 2 + // so this read will take result in the next read taking longer than normal (about double) + test.Printf(_L("Issuing read #5......resulting in read-ahead #3\n")); + initTicks = User::FastCounter(); + r = fileRead.Read(dummyPtr); + finalTicks = User::FastCounter(); + test_KErrNone(r); + timeTakenReadSubsequent = TicksToMsec(initTicks, finalTicks, fastCounterFreq); + test.Printf(_L("read time: %d\n"), I64LOW(timeTakenReadSubsequent.Int64())); - for (TInt n=0; n= 2) - { - test.Printf(_L("Wait %u uS for read-ahead ...\n"), readAheadTime); - User::After(readAheadTime); - } + // The third read should be very quick as the previous read-ahead should have already buffered the data + test.Printf(_L("Issuing read #6......resulting in read-ahead #4\n")); + initTicks = User::FastCounter(); + r = fileRead.Read(dummyPtr); + finalTicks = User::FastCounter(); + test_KErrNone(r); + timeTakenReadSubsequent = TicksToMsec(initTicks, finalTicks, fastCounterFreq); + test.Printf(_L("read time: %d\n"), I64LOW(timeTakenReadSubsequent.Int64())); -#if defined(_DEBUG) || defined(_DEBUG_RELEASE) - // check the number of bytes read from the media is as expected. i.e. including the read-ahead length - // Keep waiting if it's not for up to 10 seconds - const TInt KMaxWaitTime = 10000000; // 10 secs - TInt waitTime; - for (waitTime=0; waitTime = 3) - { - if (readTimes[n].Int64() >= readTimes[0].Int64()) - test.Printf(_L("WARNING: Subsequent read not faster despite read-ahead !!!\n")); - } -#endif - } + fileRead.Close(); r = DeleteAll(gSessionPath); @@ -1574,7 +1597,8 @@ delete dummy; test.End(); - } + +} /** Main tests function */ @@ -1585,7 +1609,7 @@ // turn OFF lock failure mode TBool simulatelockFailureMode = EFalse; TInt r = controlIo(TheFs, gDrive, KControlIoSimulateLockFailureMode, simulatelockFailureMode); - test_KErrNone(r); + test (r == KErrNone); #endif TBuf16<45> dir; @@ -1605,7 +1629,7 @@ TRAPD(res,gBuf = HBufC8::NewL(KBlockSize+1)); - test_Value(res, res== KErrNone && gBuf != NULL); + test(res == KErrNone && gBuf != NULL); gBufWritePtr.Set(gBuf->Des()); FillBuffer(gBufWritePtr, KBlockSize, 'A'); @@ -1640,7 +1664,7 @@ // turn lock failure mode back ON (if enabled) simulatelockFailureMode = ETrue; r = controlIo(TheFs, gDrive, KControlIoSimulateLockFailureMode, simulatelockFailureMode); - test_KErrNone(r); + test (r == KErrNone); #endif }