Issue Details (XML | Word | Printable)

Key: CORE-1999
Type: Improvement Improvement
Status: Closed Closed
Resolution: Fixed
Priority: Minor Minor
Assignee: Vlad Khorsun
Reporter: Oleg Matveyev
Votes: 5
Watchers: 4
Operations

If you were logged in you would be able to see more operations.
Firebird Core

TimeStamp in the every line output gbak.exe utility

Created: 17/Jul/08 07:20 AM   Updated: 10/Nov/15 06:08 PM
Component/s: API / Client Library, Engine, GBAK, SVCMGR
Affects Version/s: None
Fix Version/s: 3.0 RC1, 2.5.5

File Attachments: 1. Zip Archive core_1999_25.zip (2 kB)

Issue Links:
Depend
 

Planning Status: Considered for inclusion
Target: 3.0 RC1
QA Status: Done successfully
Test Details: Note: failing of this test can be evidence of regression in fixed CORE-4897.


 Description  « Hide
Hi, All.
For the best analyze time of database restore, very helpful show date and time in every line output gbak:

17.07.2008 14:16:01 gbak: activating and creating deferred index RDB$PRIMARY1
17.07.2008 14:18:10 gbak: activating and creating deferred index RDB$FOREIGN319
17.07.2008 14:19:15 gbak: committing metadata
17.07.2008 14:20:24 gbak:finishing, closing, and going home

P.S. Output optionaly, by switch -pi (performance info) for gbak.exe


 All   Comments   Change History   Subversion Commits      Sort Order: Ascending order - Click to sort in descending order
Jiri Cincura added a comment - 18/Jul/08 07:04 AM
-pi isn't probably the right name. I would rather see something like "show timestamps" or -st. Or just "timestamps" -ts".

Valdir Marcos added a comment - 21/Apr/09 12:30 PM
Could you also calculate the time spent (Finish Timestamp - Start Timestamp) as the last information printed?
Could you extend those information to the other FB utilities like gfix, gstat, isql, nbackup, etc?

All those timestamp information would be very helpful.

Brenden Walker added a comment - 04/Jan/13 10:07 PM
Just chiming in that we (DRB Systems Inc) would like to see this enhancement implemented.

Vlad Khorsun added a comment - 26/Jul/15 08:54 PM - edited
gbak verbose output with runtime statistics

gbak now could show some runtime statistics in its verbose output. New command-
line switch STATISTICS is added to define which statistics items should be
used. Currently there are support for four items is implemented:
  time total - time spend since start of gbak process
  time delta - time spend since previous output line
  page reads - number of pages read since previous output line
  page writes - number of pages write since previous output line.

  Mandatory string parameter of STATISTICS switch is used to specify necessary
stats items. Every stats item is identified by its own characters:
  T - time total
  D - time delta
  R - page reads
  W - page writes.

  Order and case of characters in parameter value is not important, i.e. "TDRW"
and "WdrT" is the same. If verbose output was not specified (i.e. nor VERBOSE
nor VERBINT is not present), STATISTICS will have no effect. Both time items
shows time in seconds with milliseconds (3 digits after decimal point). Other
items shown as whole numbers.

  For users convenience, two special lines in verbose output is added:
- line with stats headers (only specified items are present), printed before
other lines with statistics:

gbak: time delta reads writes

- line with total statistics, printed after end of main process:

gbak: 46.684 0.002 171 82442 total statistics

In this line both time items have the same meaning as in other lines but
read\write items show summary values.


  New feature is fully supported at Services API. New SPB item is introduced:

#define isc_spb_bkp_stat 15

and its synonim

#define isc_spb_res_stat isc_spb_bkp_stat

Usage
isc_spb_bkp_stat, <len>, <string>
isc_spb_res_stat, <len>, <string>

where
<len> is 2-bytes length of following string parameter, and
<string> is 1-4 bytes string with one character per stats item.

fbsvcmgr utility also updated and supports new SPB tags.
  

  Examples:
a) gbak usage screen with description of new switch
    -ST(ATISTICS) TDRW show statistics:
        T time from start
        D delta time
        R page reads
        W page writes
  
b) show total time since gbak start
-STATISTICS T

c) show delta time and page reads
-STATISTICS DR

d) show all stat items
-STATISTICS TDRW

e) sample of gbak output

firebird>gbak -v -stat tdrw -r a.fbk a.fdb
gbak:opened file a.fbk
gbak: time delta reads writes
gbak: 0.173 0.173 0 0 transportable backup -- data in XDR format
gbak: 0.175 0.002 0 0 backup file is compressed
gbak: 0.177 0.001 0 0 backup version is 10
gbak: 0.270 0.092 0 650 created database a.fdb, page_size 8192 bytes
gbak: 0.273 0.002 0 2 started transaction
...
gbak: 18.661 0.002 0 0 restoring data for table TEST1
gbak: 18.698 0.036 0 0 10000 records restored
...
gbak: 25.177 0.036 0 0 1770000 records restored
gbak: 25.220 0.042 0 1633 1780000 records restored
...
gbak: 38.702 0.002 0 0 restoring privilege for user SYSDBA
gbak: 38.707 0.004 22 0 creating indexes
gbak: 45.015 6.308 82 38394 activating and creating deferred index T2_VAL
...
gbak: 46.682 0.008 4 13 finishing, closing, and going home
gbak: 46.684 0.002 171 82442 total statistics
gbak:adjusting the ONLINE and FORCED WRITES flags

Vlad Khorsun added a comment - 30/Jul/15 08:33 AM
Depending on users feedback it could be backported into v2.5

Vlad Khorsun added a comment - 27/Oct/15 11:25 AM
Backported into v2.5.5

Pavel Zotov added a comment - 30/Oct/15 11:07 AM
> Vlad Khorsun added a comment - 27/Oct/15 11:25 AM
> Backported into v2.5.5

It seems that FBSVCMGR of 2.5.5 does not understand 'res_stat tdrw' as command arguments.

command #1
==========

C:\MIX\firebird\fb25\bin\fbsvcmgr localhost:service_mgr user SYSDBA password masterkey action_restore bkp_file C:/MIX/firebird/QA/fbt-repo/tmp/tmp_core_1999_25.fbk dbname C:/MIX/firebird/QA/fbt-repo/tmp/tmp_core_1999_25.fd1 res_replace verbose

STDOUT: <runs OK, producing verbose output of restoring process>.
STDERR: empty.

command #2
===========
C:\MIX\firebird\fb25\bin\fbsvcmgr localhost:service_mgr user SYSDBA password masterkey action_restore bkp_file C:/MIX/firebird/QA/fbt-repo/tmp/tmp_core_1999_25.fbk dbname C:/MIX/firebird/QA/fbt-repo/tmp/tmp_core_1999_25.fd1 res_replace verbose res_stat tdrw

STDERR: unrecognized service parameter block


Checked on Firebird Trace utility version WI-V2.5.5.26949 Firebird 2.5
Test .fbk is in attached .zip file

Vlad Khorsun added a comment - 10/Nov/15 06:08 PM
Fixed, thanks