|
1 // Copyright (c) 2007-2009 Nokia Corporation and/or its subsidiary(-ies). |
|
2 // All rights reserved. |
|
3 // This component and the accompanying materials are made available |
|
4 // under the terms of "Eclipse Public License v1.0" |
|
5 // which accompanies this distribution, and is available |
|
6 // at the URL "http://www.eclipse.org/legal/epl-v10.html". |
|
7 // |
|
8 // Initial Contributors: |
|
9 // Nokia Corporation - initial contribution. |
|
10 // |
|
11 // Contributors: |
|
12 // |
|
13 // Description: |
|
14 // |
|
15 |
|
16 #include <opensystemtrace.h> |
|
17 #include <uloggerclient.h> |
|
18 #include "te_multiparttrace.h" |
|
19 #include "uloggerconfig.h" |
|
20 |
|
21 |
|
22 |
|
23 //const data for testing purposes |
|
24 const TTraceId KTestTraceId = 10245; |
|
25 const TClassification KTestClassification = 254; |
|
26 _LIT(KLogPath, "c:\\logs\\ulogger\\multitrace.utf"); |
|
27 |
|
28 //global variables |
|
29 TInt fillPattern = 123; |
|
30 TInt dataSize = 255; |
|
31 TInt traceMethod = 0; |
|
32 static const TComponentId KMyTestUid = 12345678; |
|
33 TInt ordinal = 0; |
|
34 TInt tarcerecords_expected = 0; |
|
35 |
|
36 |
|
37 template<typename T> |
|
38 T ReadTypeFromBuffer(const TUint8* aData, TInt& aOffset) |
|
39 { |
|
40 T p = *((T*)(aData+aOffset)); |
|
41 aOffset += sizeof(T); |
|
42 return p; |
|
43 } |
|
44 |
|
45 |
|
46 CCTe_multiparttrace::CCTe_multiparttrace() |
|
47 { |
|
48 SetTestStepName(KMultiTraceTestStep); |
|
49 } |
|
50 |
|
51 |
|
52 CCTe_multiparttrace::~CCTe_multiparttrace() |
|
53 { |
|
54 } |
|
55 |
|
56 |
|
57 |
|
58 TVerdict CCTe_multiparttrace::doTestStepPreambleL() |
|
59 { |
|
60 INFO_PRINTF1(_L("*** This test case is aimed to test multipart-traces ***")); |
|
61 |
|
62 //delete old trace log |
|
63 RFs fs; |
|
64 User::LeaveIfError( fs.Connect() ); |
|
65 fs.Delete(KLogPath); |
|
66 |
|
67 // added this code to ensure directories created on hardware |
|
68 TInt err = fs.MkDirAll(KLogPath); |
|
69 if( err != KErrNone && err != KErrAlreadyExists) |
|
70 { |
|
71 ERR_PRINTF2(_L("RFs::MkDirAll failed with error %d"), err); |
|
72 } |
|
73 |
|
74 |
|
75 fs.Close(); |
|
76 |
|
77 |
|
78 |
|
79 //enable ULogger/Trace to log test traces |
|
80 INFO_PRINTF1(_L("INFO: configuring ULogger...")); |
|
81 User::LeaveIfError( iUlogger.Connect() ); |
|
82 CClearConfig configIni; |
|
83 configIni.Clear(iUlogger); |
|
84 |
|
85 iUlogger.SetSecondaryFilteringEnabled(EFalse); |
|
86 |
|
87 _LIT8(KUloggerFilePlugin, "uloggerfileplugin"); |
|
88 |
|
89 |
|
90 err = iUlogger.ActivateOutputPlugin(KUloggerFilePlugin); |
|
91 if( err != KErrNone && err != KErrAlreadyExists) |
|
92 { |
|
93 ERR_PRINTF2(_L("ActivateOutputPlugin failed with error %d"), err); |
|
94 User::LeaveIfError(err); |
|
95 } |
|
96 TPluginConfiguration pluginConf; |
|
97 pluginConf.SetKey(_L8("output_path")); |
|
98 pluginConf.SetValue(KLogPath); |
|
99 User::LeaveIfError( iUlogger.SetPluginConfigurations(KUloggerFilePlugin, pluginConf) ); |
|
100 |
|
101 CArrayFixFlat<TUint8>* array = new (ELeave) CArrayFixFlat<TUint8>(4); |
|
102 CleanupStack::PushL(array); |
|
103 array->AppendL(KTestClassification); |
|
104 User::LeaveIfError( iUlogger.SetPrimaryFiltersEnabled(*array, ETrue)); |
|
105 CleanupStack::PopAndDestroy(array); |
|
106 |
|
107 User::LeaveIfError( iUlogger.Restart()); |
|
108 |
|
109 iUlogger.Close(); |
|
110 |
|
111 return TestStepResult(); |
|
112 } |
|
113 |
|
114 |
|
115 |
|
116 TVerdict CCTe_multiparttrace::doTestStepL() |
|
117 { |
|
118 INFO_PRINTF1(_L("*** CCTe_multiparttrace::doTestStepL ***")); |
|
119 |
|
120 //generate trace data |
|
121 traceMethod = ETraceUsingTraceBig; |
|
122 TInt e = GenerateTraceDataL((CCTe_multiparttrace::TTraceMethod)traceMethod, dataSize, fillPattern); |
|
123 if(e != KErrNone) |
|
124 { |
|
125 INFO_PRINTF2(_L("ERROR: generating trace data failed (%d)"), e); |
|
126 SetTestStepResult(EFail); |
|
127 return TestStepResult(); |
|
128 } |
|
129 |
|
130 |
|
131 //stop ulogger |
|
132 INFO_PRINTF1(_L("INFO: stopping ULogger...")); |
|
133 User::LeaveIfError( iUlogger.Connect() ); |
|
134 User::LeaveIfError( iUlogger.Stop() ); |
|
135 iUlogger.Close(); |
|
136 |
|
137 return TestStepResult(); |
|
138 } |
|
139 |
|
140 |
|
141 TVerdict CCTe_multiparttrace::doTestStepPostambleL() |
|
142 { |
|
143 INFO_PRINTF1(_L("*** CCTe_multiparttrace::doTestStepPostambleL ***")); |
|
144 |
|
145 //validate the data that we just logged |
|
146 TInt e = KErrNone; |
|
147 if((e=CheckDataL((CCTe_multiparttrace::TTraceMethod)traceMethod, dataSize, fillPattern)) != KErrNone) |
|
148 { |
|
149 INFO_PRINTF2(_L("ERROR: checking data failed (%d)"), e); |
|
150 SetTestStepResult(EFail); |
|
151 } |
|
152 |
|
153 //delete log file |
|
154 RFs fs; |
|
155 User::LeaveIfError( fs.Connect() ); |
|
156 fs.Delete(KLogPath); |
|
157 |
|
158 return TestStepResult(); |
|
159 } |
|
160 |
|
161 |
|
162 TInt CCTe_multiparttrace::GenerateTraceDataL(TTraceMethod aTraceMethod, TUint aMaxDataSize, TUint8 aFillPattern) |
|
163 { |
|
164 INFO_PRINTF4(_L("*** CCTe_multiparttrace::GenerateTraceDataL(%d, %d, %d) ***"), aTraceMethod, aMaxDataSize, aFillPattern); |
|
165 TInt e = KErrNone; |
|
166 |
|
167 INFO_PRINTF1(_L("INFO: generating trace data...")); |
|
168 TInt i,k; |
|
169 //generate and send data using desired Ost API |
|
170 TUint8* data = (TUint8*)User::Alloc(aMaxDataSize); |
|
171 for(i=0; i<aMaxDataSize; ++i) |
|
172 { |
|
173 //fill data with pattern provided |
|
174 for(k=0; k<i; ++k) |
|
175 data[k] = i-k; |
|
176 |
|
177 //send trace |
|
178 TBool loggedFlag=EFalse; |
|
179 if(aTraceMethod == ETraceUsingTraceBig) |
|
180 { |
|
181 loggedFlag = OstTrace(TTraceContext(KMyTestUid, KTestClassification), KTestTraceId, (const TAny*)data, i); |
|
182 //loggedFlag = BTraceContextBig(KTestClassification, 0, KMyTestUid, (const TAny*)data, i); |
|
183 } |
|
184 |
|
185 |
|
186 if(!loggedFlag) |
|
187 { |
|
188 INFO_PRINTF2(_L("ERROR: trace %d not logged!"), i); |
|
189 e = KErrGeneral; |
|
190 break; |
|
191 } |
|
192 } |
|
193 |
|
194 if(e==KErrNone) |
|
195 { |
|
196 //INFO_PRINTF1(_L("INFO: data sent")); |
|
197 } |
|
198 else |
|
199 INFO_PRINTF2(_L("ERROR: data sendiung failed (%d)"), e); |
|
200 |
|
201 //cleanup |
|
202 delete [] data; |
|
203 |
|
204 return e; |
|
205 } |
|
206 |
|
207 |
|
208 TInt CCTe_multiparttrace::CheckDataL(TTraceMethod aTraceMethod, TUint aMaxDataSize, TUint8 aFillPattern) |
|
209 { |
|
210 INFO_PRINTF4(_L("*** CCTe_multiparttrace::CheckDataL(%d, %d, %d) ***"), aTraceMethod, aMaxDataSize, aFillPattern); |
|
211 |
|
212 INFO_PRINTF2(_L("INFO: opening log file... %S"), &(KLogPath())); |
|
213 RFs fs; |
|
214 RFile file; |
|
215 User::LeaveIfError( fs.Connect() ); |
|
216 |
|
217 TInt err = file.Open(fs, KLogPath, EFileRead); |
|
218 if(err != KErrNone) |
|
219 { |
|
220 INFO_PRINTF3(_L("ERROR: opening log file error: err = %d filename=%S"), err, &(KLogPath())); |
|
221 return err; |
|
222 } |
|
223 |
|
224 //read trace log file |
|
225 TInt size = 0; |
|
226 file.Size(size); |
|
227 if(size > 0) |
|
228 { |
|
229 INFO_PRINTF2(_L("INFO: Trace Log file size: %d"), size); |
|
230 HBufC8* data = HBufC8::NewLC(size); |
|
231 TPtr8 p(data->Des()); |
|
232 User::LeaveIfError( file.Read(p) ); |
|
233 const TUint8* dataPtr = p.Ptr(); |
|
234 err = ValidateTraceDataL(dataPtr, p.Length(), dataSize, fillPattern); |
|
235 CleanupStack::PopAndDestroy(data); |
|
236 } |
|
237 else{ |
|
238 err = KErrGeneral; |
|
239 } |
|
240 |
|
241 //cleanup |
|
242 file.Close(); |
|
243 fs.Close(); |
|
244 |
|
245 return err; |
|
246 } |
|
247 |
|
248 |
|
249 TInt CCTe_multiparttrace::ValidateTraceDataL(const TUint8* aDataPtr, TUint aDataSize, TUint aTraceRecords, TUint8 /*aFillPattern*/) |
|
250 { |
|
251 INFO_PRINTF1(_L("*** CCTe_multiparttrace::ValidateTraceDataL ***")); |
|
252 |
|
253 TUint8* tracePtr = (TUint8*)aDataPtr; |
|
254 TInt traceSize = aDataSize; |
|
255 |
|
256 TUint8 recSize=0, flags=0, category=0; //subCategory=0; |
|
257 TInt32 flags2=0;//, contextId=0, extra=0, timestamp2=0, pc=0; |
|
258 TBool missing = EFalse; |
|
259 TInt offset = 0; |
|
260 //TInt currentTraceSize=0; |
|
261 const TUint8* endPtr = tracePtr+traceSize; |
|
262 //parse trace data |
|
263 TInt traceRecordCounter=0; |
|
264 TInt testRecordCounter=0; |
|
265 |
|
266 while(tracePtr < endPtr) |
|
267 { |
|
268 User::After(100); |
|
269 //INFO_PRINTF1(_L(" ")); |
|
270 traceRecordCounter++; |
|
271 offset = 0; |
|
272 recSize = flags = flags2 /*= extra*/ = category /*= subCategory = contextId */= 0; |
|
273 missing = EFalse; |
|
274 |
|
275 //read trace header |
|
276 recSize = tracePtr[BTrace::ESizeIndex]; |
|
277 flags = tracePtr[BTrace::EFlagsIndex]; |
|
278 category = tracePtr[BTrace::ECategoryIndex]; |
|
279 //subCategory = tracePtr[BTrace::ESubCategoryIndex]; |
|
280 offset += 4; |
|
281 |
|
282 //read header extension |
|
283 if(flags & BTrace::EHeader2Present) |
|
284 flags2 = ReadTypeFromBuffer<TInt32>(tracePtr, offset); |
|
285 if(flags & BTrace::ETimestampPresent) |
|
286 ReadTypeFromBuffer<TInt32>(tracePtr, offset); |
|
287 if(flags & BTrace::ETimestamp2Present) |
|
288 /*timestamp2 =*/ ReadTypeFromBuffer<TInt32>(tracePtr, offset); |
|
289 if(flags & BTrace::EContextIdPresent) |
|
290 /*contextId =*/ ReadTypeFromBuffer<TInt32>(tracePtr, offset); |
|
291 if(flags & BTrace::EPcPresent) |
|
292 { |
|
293 /*pc = */ ReadTypeFromBuffer<TInt32>(tracePtr, offset); |
|
294 //INFO_PRINTF1(_L("INFO: PC present")); |
|
295 } |
|
296 if(flags & BTrace::EExtraPresent) |
|
297 { |
|
298 //extra = ETrue; |
|
299 ReadTypeFromBuffer<TInt32>(tracePtr, offset); |
|
300 //INFO_PRINTF1(_L("INFO: EXTRA present")); |
|
301 } |
|
302 |
|
303 |
|
304 if(flags & BTrace::ECpuIdMask) |
|
305 { |
|
306 //INFO_PRINTF1(_L("INFO: CPUID present")); |
|
307 } |
|
308 |
|
309 |
|
310 if(flags & BTrace::ERecordTruncated) |
|
311 { |
|
312 //trauncated = ETrue; |
|
313 } |
|
314 if(flags & BTrace::EMissingRecord) |
|
315 missing = ETrue; |
|
316 |
|
317 if(missing) |
|
318 { |
|
319 INFO_PRINTF1(_L("ERROR: ***** !!! MISSING TRACES ERROR !!! *****")); |
|
320 return KErrCorrupt; //indicates corrupted trace data |
|
321 } |
|
322 |
|
323 TInt _payloadSize = recSize-offset; |
|
324 //INFO_PRINTF2(_L("INFO: payloadSize = %d"), _payloadSize); |
|
325 |
|
326 //parse payload |
|
327 if(category == KTestClassification) |
|
328 { |
|
329 if(flags2 & BTrace::EMultipartFlagMask) |
|
330 { |
|
331 // TInt32 d1 = *(TUint32*)(tracePtr+offset); //total trace size |
|
332 // TInt32 d2 = *(TUint32*)(tracePtr+offset+4); //offset in collected data or UID |
|
333 // TUint8 d3 = *(TUint8*)(tracePtr+offset+8); //UID or random val |
|
334 // TUint8 d4_01 = *(TUint8*)(tracePtr+offset+12); //TraceId |
|
335 // TUint8 d4_02 = *(TUint8*)(tracePtr+offset+13); //reserved |
|
336 // TUint8 d5 = *(TUint8*)(tracePtr+offset+14); //TraceId |
|
337 |
|
338 //INFO_PRINTF7(_L("INFO: trace data: %d, %d, %d, %d, %d, %d)"), d1, d2, d3, d4_01, d4_02, d5); |
|
339 //INFO_PRINTF2(_L("INFO: trace number: %d"), testRecordCounter); |
|
340 |
|
341 //check TMultipart flag (and not CPU ID) |
|
342 switch(flags2 & BTrace::EMultipartFlagMask) |
|
343 { |
|
344 case BTrace::EMultipartFirst: |
|
345 { |
|
346 //TInt32 d1 = *(TUint32*) (tracePtr+offset); //extra size (Total trace size) |
|
347 //TInt32 d2 = *(TUint32*) (tracePtr+offset+4); //UID |
|
348 //TInt16 d3_01 = *(TUint16*) (tracePtr+offset+8); //TraceId |
|
349 //TInt16 d3_02 = *(TUint16*) (tracePtr+offset+10); //reserved |
|
350 //TUint8 d4 = *(TUint8*) (tracePtr+offset+12); //payload 1 |
|
351 //INFO_PRINTF6(_L("FIRST TRACE: %d, %d, %d, %d, %d"), d1, d2, d3_01, d3_02, d4); |
|
352 |
|
353 //+4 is to mask TraceId and reserved value (2+2) |
|
354 if(ValidateTracePayloadL((const TUint8*)tracePtr+offset, _payloadSize, testRecordCounter, ETrue, testRecordCounter, ETrue, EFalse) != KErrNone) |
|
355 return KErrGeneral; |
|
356 } break; |
|
357 |
|
358 case BTrace::EMultipartMiddle: |
|
359 { |
|
360 TInt32 d1 = *(TUint32*)(tracePtr+offset); //extra size (Total trace size) |
|
361 TInt32 d2 = *(TUint32*)(tracePtr+offset+4); //current offset |
|
362 //TUint8 d3 = *(TUint8*)(tracePtr+offset+8); //payload 1 |
|
363 //INFO_PRINTF4(_L("MIDDLE TRACE: %d, %d, %d"), d1, d2, d3); |
|
364 |
|
365 if(ValidateTracePayloadL((const TUint8*)tracePtr+offset, _payloadSize, testRecordCounter, ETrue, d1-d2, EFalse, EFalse) != KErrNone) |
|
366 return KErrGeneral; |
|
367 } break; |
|
368 |
|
369 case BTrace::EMultipartLast: |
|
370 { |
|
371 TInt32 d1 = *(TUint32*)(tracePtr+offset); //extra size (Total trace size) |
|
372 TInt32 d2 = *(TUint32*)(tracePtr+offset+4); //current offset |
|
373 //TUint8 d3 = *(TUint8*)(tracePtr+offset+8); //payload 1 |
|
374 //INFO_PRINTF4(_L("LAST TRACE: %d, %d, %d"), d1, d2, d3); |
|
375 |
|
376 if(ValidateTracePayloadL((const TUint8*)tracePtr+offset, _payloadSize, testRecordCounter, ETrue, d1-d2, EFalse, ETrue) != KErrNone) |
|
377 return KErrGeneral; |
|
378 |
|
379 testRecordCounter++; |
|
380 } break; |
|
381 |
|
382 default: |
|
383 { |
|
384 INFO_PRINTF1(_L("ERROR: wrong value of flags2")); |
|
385 return KErrGeneral; |
|
386 }//break; |
|
387 } |
|
388 |
|
389 |
|
390 } |
|
391 else //not multiparted trace |
|
392 { |
|
393 if(ValidateTracePayloadL((const TUint8*)tracePtr+offset, _payloadSize, testRecordCounter, EFalse, testRecordCounter, ETrue, ETrue) != KErrNone) |
|
394 return KErrGeneral; |
|
395 testRecordCounter++; |
|
396 } |
|
397 } |
|
398 |
|
399 tracePtr = BTrace::NextRecord((TAny*)tracePtr); |
|
400 } |
|
401 |
|
402 INFO_PRINTF2(_L("INFO: %d trace records parsed"), traceRecordCounter); |
|
403 INFO_PRINTF2(_L("INFO: %d test trace records parsed"), testRecordCounter); |
|
404 if(testRecordCounter != aTraceRecords) |
|
405 { |
|
406 INFO_PRINTF3(_L("ERROR: wrong number of trace records with desired category (%d vs %d)"), testRecordCounter, aTraceRecords); |
|
407 return KErrGeneral; |
|
408 } |
|
409 |
|
410 return KErrNone; |
|
411 } |
|
412 |
|
413 |
|
414 TInt CCTe_multiparttrace::ValidateTracePayloadL(const TUint8* aDataPtr, TUint aDataSize, TInt aTotalTraceSize, TBool aMultiPart, TUint8 aExpectedFirstVal, TBool aFirstTrace, TBool aLastTrace) |
|
415 { |
|
416 TInt offset = 0; |
|
417 |
|
418 //check some metadata that is stored in payload |
|
419 if(aFirstTrace) |
|
420 { |
|
421 ordinal = 0; |
|
422 |
|
423 if(aMultiPart) |
|
424 { |
|
425 TUint totalTraceSize = (TUint32) *(TUint32*)((TUint8*)aDataPtr+offset); |
|
426 offset+=4; |
|
427 if(totalTraceSize != aExpectedFirstVal) |
|
428 { |
|
429 INFO_PRINTF3(_L("ERROR: wrong totalTraceSize value (%d vs %d)"), totalTraceSize, aExpectedFirstVal); |
|
430 return KErrGeneral; |
|
431 } |
|
432 } |
|
433 |
|
434 TUint32 uid = (TUint32) *(TUint32*)((TUint8*)aDataPtr+offset); |
|
435 offset += 4; |
|
436 if(uid != KMyTestUid) |
|
437 { |
|
438 INFO_PRINTF3(_L("ERROR: wrong uid value (%d vs %d)"), uid, KMyTestUid); |
|
439 return KErrGeneral; |
|
440 } |
|
441 |
|
442 |
|
443 //read and test Ost TraceId |
|
444 TUint16 traceId = (TUint16) *(TUint16*)((TUint8*)aDataPtr+offset); |
|
445 if(traceId != KTestTraceId) |
|
446 { |
|
447 INFO_PRINTF3(_L("ERROR: wrong traceId value (%d vs %d)"), traceId, KTestTraceId); |
|
448 return KErrGeneral; |
|
449 } |
|
450 offset += 2; |
|
451 |
|
452 //read reserved value (not used by Ost at the moment) |
|
453 //TUint16 unused = (TUint16) *(TUint16*)((TUint8*)aDataPtr+offset); |
|
454 offset += 2; |
|
455 } |
|
456 else if(aMultiPart) |
|
457 { |
|
458 //non-first multipart trace |
|
459 TUint totalTraceSize = (TUint32) *(TUint32*)((TUint8*)aDataPtr+offset); |
|
460 offset+=4; |
|
461 |
|
462 if(totalTraceSize != aTotalTraceSize) |
|
463 { |
|
464 INFO_PRINTF3(_L("ERROR: wrong totalTraceSize (in MIDDLE or LAST multipart trace) value (%d vs %d)"), totalTraceSize, aTotalTraceSize); |
|
465 return KErrGeneral; |
|
466 } |
|
467 |
|
468 //TUint32 tracerDataOffset = tracerDataOffset = (TUint32) *(TUint32*)((TUint8*)aDataPtr+offset); |
|
469 offset+=4; |
|
470 |
|
471 } |
|
472 |
|
473 //validate content of the trace data |
|
474 TInt expectedVal = aExpectedFirstVal; |
|
475 TBool reallyFirstRecord = aFirstTrace; |
|
476 while (offset < aDataSize) |
|
477 { |
|
478 TUint8 d = *((TUint8*)aDataPtr+offset); |
|
479 ++ordinal; |
|
480 |
|
481 if(reallyFirstRecord) |
|
482 { |
|
483 tarcerecords_expected = d; |
|
484 reallyFirstRecord = EFalse; |
|
485 } |
|
486 |
|
487 if (d != expectedVal) |
|
488 { |
|
489 INFO_PRINTF3(_L("ERROR: wrong data value (%d vs %d)"), d, expectedVal); |
|
490 return KErrGeneral; |
|
491 } |
|
492 ++offset; |
|
493 --expectedVal; |
|
494 } |
|
495 |
|
496 if(offset != aDataSize) |
|
497 { |
|
498 INFO_PRINTF3(_L("ERROR: wrong payload size (%d vs %d)"), offset, aDataSize); |
|
499 return KErrGeneral; |
|
500 } |
|
501 |
|
502 if(aLastTrace && tarcerecords_expected != ordinal) |
|
503 { |
|
504 INFO_PRINTF3(_L("ERROR: wrong number of traces (%d vs %d)"), tarcerecords_expected, ordinal); |
|
505 return KErrGeneral; |
|
506 } |
|
507 |
|
508 //INFO_PRINTF1(_L("INFO: trace data checked")); |
|
509 return KErrNone; |
|
510 } |
|
511 |