|
Re: Need help deciphering client trace info
2000-02-15 03:41:08
|
Subject: |
Re: Need help deciphering client trace info |
|
From: |
"Mauro M. TINELLI" <Mauro.TINELLI AT ST DOT COM> |
|
Date: |
Tue, 15 Feb 2000 09:41:08 +0100 |
B (sorry can't figure out your name),
we too are having problems with some Novell clients when the FileSpaces
are of some Gigs and the client memory isn't "enough". The ADSM client,
sometimes, absorbes all the resources and hang the machine.
Did you try with an -incrbydate option?
Your observations are interesting, although they fail on the ADSM
feature which should differentiate it from all the other backup products
"progressive incremental backup". It might be a "border line" case but
it's interesting.
Thank you
Mauro, STM
> 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 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
> 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
> 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 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
> 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
> 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
> tell me what this time accounts for? Any other observations or
> suggestions? TIA.
|
|
|
