Need help deciphering client trace info
2000-02-14 13:09:18
I've been trying to get one of our Novell 4.1.1 clients ( ADSM client level
3.1.0.7) to get thru an incremental backup of all data in a reasonable
amount of time. It had been taking around 24 hrs. To determine where the
problem is, I ran backups of subsets of data, then took the longest running
subset and ran backups both incrementally and selectively to see if there
was a difference. And WOW, was there. I posted a question here several
weeks ago asking for ideas why this might be. One suggestion I received
was to turn on client tracing using "traceflags instr_client_detail" to
help further determine the problem. I did this, but I don't see in the
ADSM Trace Facility Guide how to interpret the resulting trace info. Any
help would be appreciated. Here is both the activity log and trace info
for both the selective and incremental runs:
Activity log for selective run:
02/11/2000 19:57:28 --- SCHEDULEREC QUERY BEGIN
02/11/2000 19:57:28 --- SCHEDULEREC QUERY END
02/11/2000 19:57:28 Next operation scheduled:
02/11/2000 19:57:28
------------------------------------------------------------
02/11/2000 19:57:28 Schedule Name: E011ERIE1-ALL
02/11/2000 19:57:28 Schedule Name: E011ERIE1-ALL
02/11/2000 19:57:28 Action: Selective
02/11/2000 19:57:28 Objects: vol1:users/ -subdir=yes
02/11/2000 19:57:28 Options:
02/11/2000 19:57:28 Server Window Start: 20:00:00 on 02/11/2000
02/11/2000 19:57:28
------------------------------------------------------------
02/11/2000 20:56:07 Selective Backup processing of 'VOL1:USERS/' finished
02/11/2000 20:56:07 Selective Backup processing of 'VOL1:USERS/' finished
without failure.
02/11/2000 20:56:08 --- SCHEDULEREC OBJECT END E011ERIE1-ALL 02/11/2000
20:00:00
02/11/2000 20:56:08 --- SCHEDULEREC STATUS BEGIN E011ERIE1-ALL 02/11/2000
20:00:00
02/11/2000 20:56:08 Total number of objects inspected: 27,706
02/11/2000 20:56:08 Total number of objects backed up: 27,700
02/11/2000 20:56:08 Total number of objects updated: 0
02/11/2000 20:56:08 Total number of objects rebound: 0
02/11/2000 20:56:08 Total number of objects deleted: 0
02/11/2000 20:56:08 Total number of objects failed: 0
02/11/2000 20:56:08 Total number of bytes transferred: 1.32 GB
02/11/2000 20:56:08 Data transfer time: 2,421.95 sec
02/11/2000 20:56:08 Network data transfer rate: 573.98 KB/sec
02/11/2000 20:56:08 Aggregate data transfer rate: 395.28 KB/sec
02/11/2000 20:56:08 Objects compressed by: 0%
02/11/2000 20:56:08 Elapsed processing time: 00:58:36
02/11/2000 20:56:08 --- SCHEDULEREC STATUS END E011ERIE1-ALL 02/11/2000
20:00:00
02/11/2000 20:56:08 Scheduled event 'E011ERIE1-ALL' completed successfully.
02/11/2000 20:56:08 Sending results for scheduled event 'E011ERIE1-ALL'.
02/11/2000 20:56:08 Results sent to server for scheduled event
'E011ERIE1-ALL'.
Trace info for selective run:
Final Detailed Instrumentation statistics
Elapsed time: 3521.280 sec
Section Total Time(sec) Average Time(msec) Frequency used
------------------------------------------------------------------
Client Setup 1.480 1480.0 1
Client Setup 1.480 1480.0 1
Process Dirs 46.340 21.4 2168
Solve Tree 17.200 17200.0 1
Compute 1.610 0.0 66609
Transaction 193.150 0.8 229993
BeginTxn Verb 0.000 0.0 134
File I/O 326.600 3.5 94309
Compression 0.000 0.0 0
Data Verb 2421.550 36.4 66609
Confirm Verb 5.370 179.0 30
EndTxn Verb 503.470 3757.2 134
Client Cleanup 4.510 4510.0 1
------------------------------------------------------------------
***************************************************************************************************************
***************************************************************************************************************
Activity log for incremental run:
02/13/2000 16:57:25 --- SCHEDULEREC OBJECT BEGIN DIANE-TEST 02/13/2000
17:00:0002/13/2000 16:57:25 --- SCHEDULEREC QUERY BEGIN
02/13/2000 16:57:25 --- SCHEDULEREC QUERY END
02/13/2000 16:57:25 Next operation scheduled:
02/13/2000 16:57:25
------------------------------------------------------------
02/13/2000 16:57:25 Schedule Name: DIANE-TEST
02/13/2000 16:57:25 Schedule Name: DIANE-TEST
02/13/2000 16:57:25 Action: Incremental
02/13/2000 16:57:25 Objects: vol1:users/ -subdir=yes
02/13/2000 16:57:25 Options:
02/13/2000 16:57:25 Server Window Start: 17:00:00 on 02/13/2000
02/13/2000 16:57:25
------------------------------------------------------------
02/13/2000 16:57:25
02/13/2000 16:57:25
Executing scheduled command now.
02/13/2000 16:57:25 --- SCHEDULEREC OBJECT BEGIN DIANE-TEST
02/14/2000 01:06:06 Total number of objects inspected: 27,712
02/14/2000 01:06:06 Total number of objects backed up: 5
02/14/2000 01:06:06 Total number of objects updated: 0
02/14/2000 01:06:06 Total number of objects rebound: 0
02/14/2000 01:06:06 Total number of objects deleted: 13
02/14/2000 01:06:06 Total number of objects failed: 0
02/14/2000 01:06:06 Total number of bytes transferred: 86.45 KB
02/14/2000 01:06:06 Data transfer time: 0.05 sec
02/14/2000 01:06:06 Network data transfer rate: 1,729.08 KB/sec
02/14/2000 01:06:06 Aggregate data transfer rate: 0.00 KB/sec
02/14/2000 01:06:06 Objects compressed by: 0%
02/14/2000 01:06:06 Elapsed processing time: 08:08:41
02/14/2000 01:06:06 --- SCHEDULEREC STATUS END DIANE-TEST 02/13/2000
Trace info for incremental run:
Final Detailed Instrumentation statistics
Elapsed time: 29325.810 sec
Section Total Time(sec) Average Time(msec) Frequency used
------------------------------------------------------------------
Client Setup 0.280 280.0 1
Client Setup 0.280 280.0 1
Process Dirs 72.960 33.6 2169
Solve Tree 0.270 270.0 1
Compute 0.000 0.0 5
Transaction 29249.560 13349.9 2191
BeginTxn Verb 0.000 0.0 1
File I/O 0.160 16.0 10
Compression 0.000 0.0 0
Data Verb 0.050 10.0 5
Confirm Verb 0.000 0.0 0
EndTxn Verb 0.440 440.0 1
Client Cleanup 4.510 4510.0 1
------------------------------------------------------------------
Obviously the transaction time for the incremental run is huge. Can anyone
Obviously the transaction time for the incremental run is huge. Can anyone
tell me what this time accounts for? Any other observations or
suggestions? TIA.
|
<Prev in Thread] |
Current Thread |
[Next in Thread>
|
- Need help deciphering client trace info,
Barbara Andrews <=
|
|
|