The following document contains screen snippets from a live demo showing the Eloquence features forward-logging and recovery, database auditing and server replication. The screen snippets have been taken on Linux, but the same demo could also be performed on HP-UX with only minor changes (e.g. in path names like /etc/init.d versus /sbin/init.d).
In this section we will just have a brief look at the sample database server that is used during this demonstration. It is a small Eloquence B.07.10 database server with a single database named TOYDB. It is installed in the home directory of a demo user and uses dedicated TCP port numbers that differ from the default Eloquence port numbers. This way we can run the demo without interfering with an existing Eloquence installation.
Here is a brief look at our config and volume files...
demo@linux:~> /etc/init.d/eloq6 info demo eloqdb6 instance id = demo configuration file = /home/demo/eloqdb6.cfg service = 3000 args = run prefix = automatic start = 0 user = demo demo@linux:~> /etc/init.d/eloq6 status demo eloqdb6[demo] process is active (pid 31462) running demo@linux:~> ll insgesamt 76 drwxr-xr-x 2 demo users 48 2007-11-07 00:42 bin drwx------ 2 demo users 80 2007-11-07 00:42 Documents -rw-r--r-- 1 demo users 20824 2007-11-07 01:05 eloqdb6.cfg -r--r--r-- 1 demo users 21684 2007-11-07 01:05 eloqdb6.cfg,v -rw-r--r-- 1 demo users 25249 2007-11-07 01:51 eloqdb6.log drwxr-xr-x 2 demo users 48 2007-11-07 01:47 log drwxr-xr-x 2 demo users 80 2007-11-07 00:42 public_html drwxr-xr-x 2 demo users 80 2007-11-07 01:48 tmp drwxr-xr-x 2 demo users 144 2007-11-07 01:51 vol demo@linux:~> ll vol insgesamt 7688 -rw------- 1 demo users 2621440 2007-11-07 01:51 db-01.vol -rw------- 1 demo users 2621440 2007-11-07 01:06 db-02.vol -rw------- 1 demo users 2621440 2007-11-07 01:51 log-1.vol demo@linux:~> dbvoldump -c eloqdb6.cfg ELOQUENCE DBVOLDUMP (C) Copyright 2005 Marxmeier Software AG (B.07.10) ID Type Path 1 DATA /home/demo/vol/db-01.vol 2 DATA /home/demo/vol/db-02.vol 3 LOG /home/demo/vol/log-1.vol ID Type Cur.Sz Ext.Sz Max.Sz Free Used 1 DATA 2.5 1.0 0.0 1.6 0.9 2 DATA 2.5 1.0 0.0 2.5 0.0 3 LOG 2.5 1.0 0.0 2.5 0.0We use rcs for tracking config changes, so we can show where we customized the supplied template file...
demo@linux:~> rcsdiff -r1.1 eloqdb6.cfg =================================================================== RCS file: eloqdb6.cfg,v retrieving revision 1.1 diff -r1.1 eloqdb6.cfg 2c2 < # @(#) $Revision: 1.1 $ --- > # @(#) $Revision: 1.3 $ 29c29 < #Title = --- > Title = demo server 41,42c41,42 < #Service = eloqdb < #ServiceHttp = --- > Service = 3000 > ServiceHttp = 3080 56c56 < #panic = restart --- > panic = exit 66,67c66,67 < UID = eloqdb < GID = eloqdb --- > UID = demo > GID = users 114c114 < #LogFile = syslog --- > LogFile = /home/demo/eloqdb6.log 171c171 < #LogFlags = *0 --- > LogFlags = *1E2 460a461 > Temp = /home/demo/tmp 517,519c518,520 < < # List of data base volumes. Initially empty. < # This is usually filled in by dbvolcreate and dbvolextend utilities --- > Root = /home/demo/vol/db-01.vol > Vol02 = /home/demo/vol/db-02.vol > Log03 = /home/demo/vol/log-1.volNotice that we have ServiceHttp enabled so that we can monitor the database server status with a web browser. We also have configured the server to use a dedicated logfile instead of syslog, so we do not have our database related messages mixed with other syslog content. We also use LogFlags beyond the *0 default; this way our logfile contains info on client connections including extended audit info like user name and program name.
In the live demo we ran a session that opens the database and holds a lock, so we could view examples of the status web pages. The resulting web pages are not included here, but you can view similar pages on the web at the following web site location: http://eloquence.marxmeier.com/support/B0710/doc/http-status/index.html
The database server is running under our demo user and we have configured the START_STOP_AS_ROOT setting in /etc/sysconfig/eloquence6 so that we do not need root access for controlling our own server.
We are using a non-default port number for the server, so we need to remember setting the EQ_DBSERVER environment variable in our sessions:
demo@linux:~> env | grep EQ EQ_DBSERVER=:3000Here some info on the small TOYDB database that we use...
demo@linux:~> dbdumpcat -t 31 ELOQUENCE DBDUMPCAT (C) Copyright 2005 Marxmeier Software AG (B.07.10) ------------------------------------------- #31 sysdb (1 entries) ------------------------------------------- |dbid|name |flags |nodeid| ------------------------------------------- |11 |TOYDB |04000000|100 | ------------------------------------------- demo@linux:~> dbinfo toydb ELOQUENCE DBINFO (C) Copyright 2005 Marxmeier Software AG (B.07.10) Processing database: toydb SET NAME RECLEN CAPACITY ENTRIES ---------------- --- - ------ -------- -------- PRODUCTS 001 M 30 1456 10 CUSTOMERS 002 M 260 229 8 ORDER-MASTER 003 A 8 1456 15 INVOICES 004 D 40 1149 1 ORDERS 005 D 18 1771 15 ORDER-DETAILS 006 D 20 1771 15 demo@linux:~> dbtables -s toydb ELOQUENCE DBTABLES (C) Copyright 2005 Marxmeier Software AG (B.07.10) . . . D A T A S E T F I E L D S Data Set Name Set Item Name Item Item Recd Item Item Item Num Num Type Ofs Cnt Len Role PRODUCTS 1 PRODUCT-NO 15 X6 0 1 6 Srch PRODUCT-NAME 14 X16 6 1 16 PRICE 12 P4 22 1 4 PRODUCT-LINE 13 X2 26 1 2 QUANTITY 16 I2 28 1 2 . . .
In this section, we enable forward logging for our database server, take an online backup, perform a couple of transactions against our server and then simulate a user error that damages our data. We then perform the recovery steps by restoring the backup and rolling forward up to a point in time that is shortly before our simulated disaster.
Here are the changes for enabling forward logging...
demo@linux:~> rcsdiff eloqdb6.cfg =================================================================== RCS file: eloqdb6.cfg,v retrieving revision 1.3 diff -r1.3 eloqdb6.cfg 476c476 < #FwLog = /data/fwlog/fw-%N.log --- > FwLog = /home/demo/log/fw-%N.log 511c511 < #EnableAudit = 0 --- > EnableAudit = 1Notice that we also enable the auditing feature with above config changes; this is not really required by this specific part of the demo, but it will be helpful in the next section as it will save us another server restart.
We need to restart the database server to activate the config changes...
demo@linux:~> /etc/init.d/eloq6 restart demo Stopping eloqdb6[demo] daemon done Starting eloqdb6[demo] daemon done demo@linux:~> tail -20 eloqdb6.log Wed 07 01:59:18 (31462) D1: Eloquence database server shutting down Wed 07 01:59:18 (31462) D0: Eloquence data base server terminated ** Wed Nov 7 01:59:19 2007 Flags = [*1E2] Wed 07 01:59:19 (31878) D1: Eloquence data base server initializing Wed 07 01:59:19 (31879) D0: Server patch level PE71-0708130 Wed 07 01:59:19 (31879) D1: [0] /home/demo/vol/db-01.vol Wed 07 01:59:19 (31879) D1: [1] /home/demo/vol/db-02.vol Wed 07 01:59:19 (31879) D1: [2] /home/demo/vol/log-1.vol Wed 07 01:59:19 (31879) D1: Starting 4 TIO threads Wed 07 01:59:19 (31879) D1: TIO Queue size 40 Wed 07 01:59:19 (31879) C1: Setting up buffer cache: 8192 buffers Wed 07 01:59:19 (31879) L1: volume recovery: state of committed transactions is OK Wed 07 01:59:19 (31879) L1: volume recovery: state of volume is OK Wed 07 01:59:19 (31879) L0: created new forward-log segment (/home/demo/log/fw-1-1.log) Wed 07 01:59:20 (31879) D1: Scheduler semaphore semid = 3375107 Wed 07 01:59:20 (31879) D1: Communication buffer size = 1314816 Wed 07 01:59:20 (31879) D1: Communication buffer shmid = 179077122 Wed 07 01:59:20 (31879) D0: Eloquence database server activeHe is the first forward log that is being written to...
demo@linux:~> ll log insgesamt 4 -rw------- 1 demo users 115 2007-11-07 01:59 fw-1-1.log demo@linux:~> dbctl -u dba forwardlog status Forward-logging is enabled. Forward-log is '/home/demo/log/fw-1-1.log'.Now we perform an online backup, which is the base for recovery...
Notice that backup mode switches to a new forward-log generation number, which is also recorded inside the volume files. This way the server is able to identify the matching logfiles in case of recovery.
demo@linux:~> dbctl -u dba backup start On-line backup mode has been started. demo@linux:~> dbctl -u dba forwardlog status Forward-logging is enabled. Forward-log is '/home/demo/log/fw-2-1.log'. demo@linux:~> ll log insgesamt 8 -rw------- 1 demo users 124 2007-11-07 02:00 fw-1-1.log -rw------- 1 demo users 115 2007-11-07 02:02 fw-2-1.log demo@linux:~> tar cvzf tmp/backup-1.tar.gz eloqdb6.cfg vol/db*.vol eloqdb6.cfg vol/db-01.vol vol/db-02.volNotice that we only backup the server config and the data volume files, which are stable and consistent during online backup mode. In real life we would probably also backup the forward-logs that were created since our last backup, excluding the currently active log. For bigger systems we might even want to backup or copy the finished forward logs in regular intervals to limit the window of vulnerability.
Notice that stopping online backup mode does not switch logs...
demo@linux:~> dbctl -u dba backup stop On-line backup mode has been stopped. demo@linux:~> ll log insgesamt 8 -rw------- 1 demo users 124 2007-11-07 02:00 fw-1-1.log -rw------- 1 demo users 115 2007-11-07 02:02 fw-2-1.logNow we perform some database transactions. Out of a habit, I am using the query3k utility...
demo@linux:~> query3k B.07.10.04 Eloquence QUERY3K WED, NOV 7, 2007, 2:02 AM Copyright 2004-2007 Marxmeier Software AG Copyright 2004 Hewlett-Packard Development Company, L.P. >base=toydb PASSWORD = >> MODE = >>1 >add products PRODUCT-NO =>>4711 PRODUCT-NAME =>>eau de cologne PRICE =>>123 PRODUCT-LINE =>>xy QUANTITY =>>456 PRODUCT-NO =>>// >exitWe also create a test database TOYDB.TEST using export and import...
demo@linux:~> prschema toydb >tmp/toydb.schema ELOQUENCE PRSCHEMA (C) Copyright 2005 Marxmeier Software AG (B.07.10) demo@linux:~> dbexport -s tmp/toydb.export toydb ELOQUENCE DBEXPORT (C) Copyright 2005 Marxmeier Software AG (B.07.10) demo@linux:~> schema -b toydb.test tmp/toydb.schema ELOQUENCE SCHEMA (C) Copyright 2005 Marxmeier Software AG (B.07.10) PAGE 1 TOYDB.TEST ELOQUENCE SCHEMA PROCESSOR B.07.10 BEGIN DATA BASE TOYDB; *** (WARNING #21) Database name already specified (ignored) in line 4 Number of warnings : 1 Item name count : 23 Index item name count : 0 Data set count : 6 Collating sequence count: 0 *** Database catalog created demo@linux:~> dbcreate toydb.test ELOQUENCE DBCREATE (C) Copyright 2005 Marxmeier Software AG (B.07.10) demo@linux:~> dbimport -s tmp/toydb.export toydb.test ELOQUENCE DBIMPORT (C) Copyright 2005 Marxmeier Software AG (B.07.10) importing from database TOYDBSo we now have TOYDB and TOYDB.TEST ...
demo@linux:~> dbinfo toydb ELOQUENCE DBINFO (C) Copyright 2005 Marxmeier Software AG (B.07.10) Processing database: toydb SET NAME RECLEN CAPACITY ENTRIES ---------------- --- - ------ -------- -------- PRODUCTS 001 M 30 1456 11 CUSTOMERS 002 M 260 229 8 ORDER-MASTER 003 A 8 1456 15 INVOICES 004 D 40 1149 1 ORDERS 005 D 18 1771 15 ORDER-DETAILS 006 D 20 1771 15 demo@linux:~> dbinfo toydb.test ELOQUENCE DBINFO (C) Copyright 2005 Marxmeier Software AG (B.07.10) Processing database: toydb.test SET NAME RECLEN CAPACITY ENTRIES ---------------- --- - ------ -------- -------- PRODUCTS 001 M 30 1456 11 CUSTOMERS 002 M 260 229 8 ORDER-MASTER 003 A 8 1456 15 INVOICES 004 D 40 1149 1 ORDERS 005 D 18 1771 15 ORDER-DETAILS 006 D 20 1771 15Another transaction to our TOYDB database...
demo@linux:~> query3k B.07.10.04 Eloquence QUERY3K WED, NOV 7, 2007, 2:04 AM Copyright 2004-2007 Marxmeier Software AG Copyright 2004 Hewlett-Packard Development Company, L.P. >b=toydb PASSWORD = >> MODE = >>1 >find products.product-no=4711 1 ENTRIES QUALIFIED >replace price="0"; end >list products PRODUC PRODUCT-NAME PRICE PR QUANTI A00003 POKER DICE SET 125 10 500 A00008 POSTER PAINTS 95 30 1250 A00009 COLOURING BOOK 65 30 1000 A00001 PACK OF CARDS 75 10 1500 A00010 ERASER GIFT SET 185 30 1500 A00002 LUDO SET 1250 10 750 A00005 15" PINK RABBIT 1745 20 200 A00007 SET OF CRAYONS 175 30 500 A00004 12" TEDDY BEAR 1525 20 250 A00006 SET OF PANDAS 2500 20 150 4711 eau de cologne 0 xy 456 >exitAnd finally we erase our test database...
demo@linux:~> dberase toydb ELOQUENCE DBERASE (C) Copyright 2005 Marxmeier Software AG (B.07.10)Ooops! Faux pas! By pressing Return too early, we erased the wrong database. Ouch! ;-)
demo@linux:~> dbinfo toydb # notice the missing .TEST ELOQUENCE DBINFO (C) Copyright 2005 Marxmeier Software AG (B.07.10) Processing database: toydb SET NAME RECLEN CAPACITY ENTRIES ---------------- --- - ------ -------- -------- PRODUCTS 001 M 30 0 0 CUSTOMERS 002 M 260 0 0 ORDER-MASTER 003 A 8 0 0 INVOICES 004 D 40 0 0 ORDERS 005 D 18 0 0 ORDER-DETAILS 006 D 20 0 0To recover from this (intentional) "disaster" we will first restore the most recent backup and then apply the logged transactions up to a point short before the (pretended) user error.
For finding the "right" point in time, it pays off that we are running our database server with LogFlags *1E2 instead of the default *0 settings. The extended audit events of log level E1 and E2 are quite helpful in finding out which user ran which program against the database recently...
demo@linux:~> grep -e E1: -e E2: eloqdb6.log | tail -20 Wed 07 02:04:07 (31879) E2: [9] Audit: uid{1003}pid{31934}pname{dbcreate toydb.test} Wed 07 02:04:07 (31879) E1: [9] Login: "dba" from 127.0.0.1/demo Wed 07 02:04:27 (31879) E2: [9] Audit: protocol{8}os{Linux}ip{127.0.0.1}user{demo} Wed 07 02:04:27 (31879) E2: [9] Audit: uid{1003}pid{31935}pname{dbimport -s tmp/toydb.export toydb.test} Wed 07 02:04:27 (31879) E1: [9] Login: "public" from 127.0.0.1/demo Wed 07 02:04:34 (31879) E2: [9] Audit: protocol{8}os{Linux}ip{127.0.0.1}user{demo} Wed 07 02:04:34 (31879) E2: [9] Audit: uid{1003}pid{31936}pname{dbinfo toydb} Wed 07 02:04:34 (31879) E1: [9] Login: "public" from 127.0.0.1/demo Wed 07 02:04:39 (31879) E2: [9] Audit: protocol{8}os{Linux}ip{127.0.0.1}user{demo} Wed 07 02:04:39 (31879) E2: [9] Audit: uid{1003}pid{31938}pname{dbinfo toydb.test} Wed 07 02:04:39 (31879) E1: [9] Login: "public" from 127.0.0.1/demo Wed 07 02:04:49 (31879) E2: [9] Audit: protocol{9}os{Linux}ip{127.0.0.1}user{demo} Wed 07 02:04:49 (31879) E2: [9] Audit: uid{1003}pid{31939}pname{query3k} Wed 07 02:04:49 (31879) E1: [9] Login: "public" from 127.0.0.1/demo Wed 07 02:05:23 (31879) E2: [9] Audit: protocol{8}os{Linux}ip{127.0.0.1}user{demo} Wed 07 02:05:23 (31879) E2: [9] Audit: uid{1003}pid{31940}pname{dberase toydb} Wed 07 02:05:23 (31879) E1: [9] Login: "dba" from 127.0.0.1/demo Wed 07 02:05:51 (31879) E2: [9] Audit: protocol{8}os{Linux}ip{127.0.0.1}user{demo} Wed 07 02:05:51 (31879) E2: [9] Audit: uid{1003}pid{31942}pname{dbinfo toydb} Wed 07 02:05:51 (31879) E1: [9] Login: "public" from 127.0.0.1/demoSo our recovery should better not re-apply the dberase step.
For recovering, we shutdown the damaged database server, restore the data volumes from our most recent backup, create a fresh and matching log volume (optional in case of a clean shutdown), and finally use dbrecover to re-apply the logged transactions...
demo@linux:~> /etc/init.d/eloq6 stop demo Stopping eloqdb6[demo] daemon done demo@linux:~> tar xvzf tmp/backup-1.tar.gz vol vol/db-01.vol vol/db-02.vol demo@linux:~> rm vol/log-1.vol demo@linux:~> dbvolextend -R -v -c eloqdb6.cfg ELOQUENCE DBVOLEXTEND (C) Copyright 2005 Marxmeier Software AG (B.07.10) Reading configuration ... Opening root volume Restoring log volume /home/demo/vol/log-1.vol Closing volume ... done. demo@linux:~> dbvoldump -c eloqdb6.cfg ELOQUENCE DBVOLDUMP (C) Copyright 2005 Marxmeier Software AG (B.07.10) ID Type Path 1 DATA /home/demo/vol/db-01.vol 2 DATA /home/demo/vol/db-02.vol 3 LOG /home/demo/vol/log-1.vol ID Type Cur.Sz Ext.Sz Max.Sz Free Used 1 DATA 2.5 1.0 0.0 1.6 0.9 2 DATA 2.5 1.0 0.0 2.5 0.0 3 LOG 2.5 1.0 0.0 2.5 0.0 demo@linux:~> ll log insgesamt 396 -rw------- 1 demo users 124 2007-11-07 02:00 fw-1-1.log -rw------- 1 demo users 400951 2007-11-07 02:07 fw-2-1.logImportant: Do not attempt to restart the database server before you run dbrecover! This would increase the internal log generation number and modify the volume files. The forward logs are then no longer matching and cannot be applied without repeating the restore step.
(Note: incremental recovery is possible when starting the server in slave mode)
demo@linux:~> dbrecover -help ELOQUENCE DBRECOVER (C) Copyright 2005 Marxmeier Software AG (B.07.10) usage: dbrecover [options] options: -t tmpdir - directory to be used for temporary files -v - verbose -d flags - debug flags -c cfg - configuration file name -T timestamp - recover until point in time (incl.) timestamp formats: YYYY-MM-DD HH:MM:SS MM/DD/YYYY HH:MM:SS DD.MM.YYYY HH:MM:SS note: any character may be used to separate date and time time part is optional (defaults to 00:00:00) demo@linux:~> dbrecover -v -c eloqdb6.cfg -T "2007-11-07 02:05" ELOQUENCE DBRECOVER (C) Copyright 2005 Marxmeier Software AG (B.07.10) Opening root volume ... Recovering until Wed Nov 7 02:05:00 2007 (incl.) Recovering from forward-log ... R1: processing forward-log file: '/home/demo/log/fw-2-1.log' R1: stopping recovery on timestamp: 2007-11-07 02:05:11 1005 actions have been successfully recovered. Database environment is now up-to-date until Wed Nov 7 02:04:26 2007. done. demo@linux:~> ll log insgesamt 396 -rw------- 1 demo users 124 2007-11-07 02:00 fw-1-1.log -rw------- 1 demo users 400951 2007-11-07 02:07 fw-2-1.log(We move the "old" forward logs away, so that they don't interfere with the new server startup. In our specific example this would not happen are we did not exclude a larger number of logfiles from the recovery.)
demo@linux:~> mv log/fw* tmpStart the recovered server and monitor startup messages...
demo@linux:~> /etc/init.d/eloq6 start demo Starting eloqdb6[demo] daemon done demo@linux:~> tail -20 eloqdb6.log Wed 07 02:07:07 (31879) T1: [3] Starting server shutdown ... Wed 07 02:07:07 (31879) T1: [3] Exiting thread kernel ... Wed 07 02:07:07 (31879) D1: Eloquence database server shutting down Wed 07 02:07:07 (31879) D0: Eloquence data base server terminated ** Wed Nov 7 02:12:24 2007 Flags = [*1E2] Wed 07 02:12:24 (32173) D1: Eloquence data base server initializing Wed 07 02:12:24 (32174) D0: Server patch level PE71-0708130 Wed 07 02:12:24 (32174) D1: [0] /home/demo/vol/db-01.vol Wed 07 02:12:24 (32174) D1: [1] /home/demo/vol/db-02.vol Wed 07 02:12:24 (32174) D1: [2] /home/demo/vol/log-1.vol Wed 07 02:12:24 (32174) D1: Starting 4 TIO threads Wed 07 02:12:24 (32174) D1: TIO Queue size 40 Wed 07 02:12:24 (32174) C1: Setting up buffer cache: 8192 buffers Wed 07 02:12:24 (32174) L0: created new forward-log segment (/home/demo/log/fw-4-1.log) Wed 07 02:12:25 (32174) D1: Scheduler semaphore semid = 3932163 Wed 07 02:12:25 (32174) D1: Communication buffer size = 1314816 Wed 07 02:12:25 (32174) D1: Communication buffer shmid = 179109890 Wed 07 02:12:25 (32174) D0: Eloquence database server active demo@linux:~> ll log insgesamt 4 -rw------- 1 demo users 115 2007-11-07 02:12 fw-4-1.log demo@linux:~> dbctl -u dba forwardlog status Forward-logging is enabled. Forward-log is '/home/demo/log/fw-4-1.log'.A brief check if our recovered databases look OK...
demo@linux:~> dbdumpcat -t 31 ELOQUENCE DBDUMPCAT (C) Copyright 2005 Marxmeier Software AG (B.07.10) ------------------------------------------- #31 sysdb (2 entries) ------------------------------------------- |dbid|name |flags |nodeid| ------------------------------------------- |11 |TOYDB |04000000|100 | |12 |TOYDB.TEST |04000000|120 | ------------------------------------------- demo@linux:~> dbinfo toydb ELOQUENCE DBINFO (C) Copyright 2005 Marxmeier Software AG (B.07.10) Processing database: toydb SET NAME RECLEN CAPACITY ENTRIES ---------------- --- - ------ -------- -------- PRODUCTS 001 M 30 1456 11 CUSTOMERS 002 M 260 229 8 ORDER-MASTER 003 A 8 1456 15 INVOICES 004 D 40 1149 1 ORDERS 005 D 18 1771 15 ORDER-DETAILS 006 D 20 1771 15 demo@linux:~> dbexport -s - toydb products ELOQUENCE DBEXPORT (C) Copyright 2005 Marxmeier Software AG (B.07.10) # DATABASE = TOYDB # SET 1 = PRODUCTS "A00003","POKER DICE SET",125,"10",500 "A00008","POSTER PAINTS",95,"30",1250 "A00009","COLOURING BOOK",65,"30",1000 "A00001","PACK OF CARDS",75,"10",1500 "A00010","ERASER GIFT SET",185,"30",1500 "A00002","LUDO SET",1250,"10",750 "A00005","15\" PINK RABBIT",1745,"20",200 "A00007","SET OF CRAYONS",175,"30",500 "A00004","12\" TEDDY BEAR",1525,"20",250 "A00006","SET OF PANDAS",2500,"20",150 "4711","eau de cologne",123,"xy",456Did you notice that our product 4711 still has the original price 123 instead of the value 0 that we updated shortly before the dberase accident? We did not specify seconds for dbrecover -T and thus missed the very last database transaction. In real life the gap would typically be larger with more users working on the database until we notice our accident and begin taking corrective actions. Database auditing (see next section) could actually be used in such a case to research such transactions in the forward logs.
In this section we examine the forward logs collected during the previous part of the demo.
demo@linux:~> fwaudit -help ELOQUENCE FWAUDIT (C) Copyright 2005 Marxmeier Software AG (B.07.10) usage: fwaudit [options] file [...] options: -help - show usage (this list) -o filename - write binary audit output to file (- for stdout) -c comment - write clear-text comment into binary audit file -e expr - specify filter expression -f filename - read filter expression from file -r - print clear-text report -i number - print values of the first 'number' items -I itemlist - print values of specified items (comma- or space-separated) -v - print progress info / report details (-vv: more details)The fwaudit -r option reports contents in text format...
demo@linux:~> fwaudit -r tmp/fw*log | more ELOQUENCE FWAUDIT (C) Copyright 2005 Marxmeier Software AG (B.07.10) SIGN-ON session:5 connection time: 2007-11-07 02:02:38 protocol{9}os{Linux}ip{127.0.0.1}user{demo}login{public}conntime{1194397358} uid{1003}pid{31929}pname{query3k} DBPUT TOYDB.PRODUCTS (#111) recno:11 session:5 timestamp: 2007-11-07 02:02:58 SIGN-ON session:10 connection time: 2007-11-07 02:04:26 protocol{8}os{Linux}ip{127.0.0.1}user{demo}login{public}conntime{1194397466} uid{1003}pid{31935}pname{dbimport -s tmp/toydb.export toydb.test} DBPUT TOYDB.TEST.PRODUCTS (#131) recno:1 session:10 timestamp: 2007-11-07 02:04:26 DBPUT TOYDB.TEST.PRODUCTS (#131) recno:2 session:10 timestamp: 2007-11-07 02:04:26 DBPUT TOYDB.TEST.PRODUCTS (#131) recno:3 session:10 timestamp: 2007-11-07 02:04:26 . . .Option -e allows "filter expressions", e.g. to see only TOYDB transactions...
demo@linux:~> fwaudit -r -e "toydb.*" tmp/fw*log ELOQUENCE FWAUDIT (C) Copyright 2005 Marxmeier Software AG (B.07.10) SIGN-ON session:5 connection time: 2007-11-07 02:02:38 protocol{9}os{Linux}ip{127.0.0.1}user{demo}login{public}conntime{1194397358} uid{1003}pid{31929}pname{query3k} DBPUT TOYDB.PRODUCTS (#111) recno:11 session:5 timestamp: 2007-11-07 02:02:58 SIGN-ON session:13 connection time: 2007-11-07 02:04:48 protocol{9}os{Linux}ip{127.0.0.1}user{demo}login{public}conntime{1194397488} uid{1003}pid{31939}pname{query3k} DBUPDATE TOYDB.PRODUCTS (#111) recno:11 session:13 timestamp: 2007-11-07 02:05:11We drill down to only DBUPDATEs and use -v for more details...
demo@linux:~> fwaudit -r -v -e "dbupdate and toydb.*" tmp/fw*log ELOQUENCE FWAUDIT (C) Copyright 2005 Marxmeier Software AG (B.07.10) processing file: tmp/fw-1-1.log processing file: tmp/fw-2-1.log SIGN-ON session:13 connection time: 2007-11-07 02:04:48 protocol{9}os{Linux}ip{127.0.0.1}user{demo}login{public}conntime{1194397488} uid{1003}pid{31939}pname{query3k} DBUPDATE TOYDB.PRODUCTS (#111) recno:11 session:13 timestamp: 2007-11-07 02:05:11 PRODUCT-NO : "4711" PRODUCT-NAME : "eau de cologne" -PRICE : 123 +PRICE : 0 PRODUCT-LINE : "xy" QUANTITY : 456(The - and + prefixes denote old and new values)
We can also use -I to select the item names of interest...
demo@linux:~> fwaudit -r -e "toydb.*" -I product-no,price tmp/fw*log ELOQUENCE FWAUDIT (C) Copyright 2005 Marxmeier Software AG (B.07.10) SIGN-ON session:5 connection time: 2007-11-07 02:02:38 protocol{9}os{Linux}ip{127.0.0.1}user{demo}login{public}conntime{1194397358} uid{1003}pid{31929}pname{query3k} DBPUT TOYDB.PRODUCTS (#111) recno:11 session:5 timestamp: 2007-11-07 02:02:58 PRODUCT-NO : "4711" PRICE : 123 SIGN-ON session:13 connection time: 2007-11-07 02:04:48 protocol{9}os{Linux}ip{127.0.0.1}user{demo}login{public}conntime{1194397488} uid{1003}pid{31939}pname{query3k} DBUPDATE TOYDB.PRODUCTS (#111) recno:11 session:13 timestamp: 2007-11-07 02:05:11 PRODUCT-NO : "4711" -PRICE : 123 +PRICE : 0The -o option can be used to archive only the audit information from the forwarg-logs, which typically also contain recovery related data. The resulting binary audit format files are more compact and can also collapse multiple forward logfiles into a single audit archive...
demo@linux:~> YMD=$(date +'%Y%m%d') demo@linux:~> echo $YMD 20071107 demo@linux:~> fwaudit -v -o tmp/audit-$YMD.log tmp/fw*.log ELOQUENCE FWAUDIT (C) Copyright 2005 Marxmeier Software AG (B.07.10) processing file: tmp/fw-1-1.log processing file: tmp/fw-2-1.log demo@linux:~> ll tmp/fw*log tmp/audit*log -rw-r--r-- 1 demo users 5735 2007-11-07 02:27 tmp/audit-20071107.log -rw------- 1 demo users 124 2007-11-07 02:00 tmp/fw-1-1.log -rw------- 1 demo users 400951 2007-11-07 02:07 tmp/fw-2-1.logHere another nice little fwaudit example, providing DBPUT statistics...
demo@linux:~> fwaudit -r tmp/audit-20071107.log | awk '$1=="DBPUT" {print $1 FS $2}' | sort | uniq -c ELOQUENCE FWAUDIT (C) Copyright 2005 Marxmeier Software AG (B.07.10) 1 DBPUT TOYDB.PRODUCTS 8 DBPUT TOYDB.TEST.CUSTOMERS 1 DBPUT TOYDB.TEST.INVOICES 15 DBPUT TOYDB.TEST.ORDER-DETAILS 15 DBPUT TOYDB.TEST.ORDERS 11 DBPUT TOYDB.TEST.PRODUCTS
In this section we will configure our small database server for replication. For the sake of simplicity we will place the slave server on the same system into a subdirectory of the demo user. We will thus need to adjust the config file of the slave server to use separate directories for its files and different TCP port numbers for its services. When running master server and slave server on separate systems, this might not be neccessary.
We first change the master server config from standalone to master role.
(we use rcs as convenient method to track config changes; not required)
demo@linux:~> ci -l eloqdb6.cfg eloqdb6.cfg,v <-- eloqdb6.cfg new revision: 1.4; previous revision: 1.3 enter log message, terminated with single '.' or end of file: >> config with forward logging, but before replication >> . done(we modified the config file with vi here, rcsdiff shows the change)
demo@linux:~> rcsdiff eloqdb6.cfg =================================================================== RCS file: eloqdb6.cfg,v retrieving revision 1.4 diff -r1.4 eloqdb6.cfg 295c295 < #Role = Standalone --- > Role = masterConfig change needs server restart for activation...
demo@linux:~> /etc/init.d/eloq6 restart demo Stopping eloqdb6[demo] daemon done Starting eloqdb6[demo] daemon done demo@linux:~> tail -20 eloqdb6.log Wed 07 02:34:45 (32174) D0: Eloquence data base server terminated ** Wed Nov 7 02:34:46 2007 Flags = [*1E2] Wed 07 02:34:46 (32501) D1: Eloquence data base server initializing Wed 07 02:34:46 (32502) D0: Server patch level PE71-0708130 Wed 07 02:34:46 (32502) D0: Server is configured as a replication MASTER server Wed 07 02:34:46 (32502) D1: [0] /home/demo/vol/db-01.vol Wed 07 02:34:46 (32502) D1: [1] /home/demo/vol/db-02.vol Wed 07 02:34:46 (32502) D1: [2] /home/demo/vol/log-1.vol Wed 07 02:34:46 (32502) D1: Starting 4 TIO threads Wed 07 02:34:46 (32502) D1: TIO Queue size 40 Wed 07 02:34:46 (32502) C1: Setting up buffer cache: 8192 buffers Wed 07 02:34:46 (32502) L1: volume recovery: state of committed transactions is OK Wed 07 02:34:46 (32502) L1: volume recovery: state of volume is OK Wed 07 02:34:46 (32502) L0: created new forward-log segment (/home/demo/log/fw-5-1.log) Wed 07 02:34:47 (32502) D1: Scheduler semaphore semid = 4128771 Wed 07 02:34:47 (32502) D1: Communication buffer size = 1314816 Wed 07 02:34:47 (32502) D1: Communication buffer shmid = 179142658 Wed 07 02:34:47 (32502) D0: Eloquence database server activeNow we prepare a subdirectory for the slave server, copy our master server config as a starting point, and perform several adjustments, especially setting the Role to "slave". You can see the changes in rcsdiff output...
demo@linux:~> mkdir slave demo@linux:~> cp eloqdb6.cfg slave demo@linux:~> cd slave demo@linux:~/slave> ci -l eloqdb6.cfg eloqdb6.cfg,v <-- eloqdb6.cfg enter description, terminated with single '.' or end of file: NOTE: This is NOT the log message! >> slave config based on master config >> . initial revision: 1.1 done(imagine use of your favourite editor here ;-)
demo@linux:~/slave> rcsdiff eloqdb6.cfg =================================================================== RCS file: eloqdb6.cfg,v retrieving revision 1.1 diff -r1.1 eloqdb6.cfg 29c29 < Title = demo server --- > Title = demo slave server 41,42c41,42 < Service = 3000 < ServiceHttp = 3080 --- > Service = 4000 > ServiceHttp = 4080 114c114 < LogFile = /home/demo/eloqdb6.log --- > LogFile = /home/demo/slave/eloqdb6.log 295c295 < Role = master --- > Role = slave 476c476 < FwLog = /home/demo/log/fw-%N.log --- > FwLog = /home/demo/slave/log/fw-%N.log 518,520c518,520 < Root = /home/demo/vol/db-01.vol < Vol02 = /home/demo/vol/db-02.vol < Log03 = /home/demo/vol/log-1.vol --- > Root = /home/demo/slave/vol/db-01.vol > Vol02 = /home/demo/slave/vol/db-02.vol > Log03 = /home/demo/slave/vol/log-1.vol demo@linux:~/slave> /etc/init.d/eloq6 info demo-slave eloqdb6 instance id = demo-slave configuration file = /home/demo/slave/eloqdb6.cfg service = 4000 args = run prefix = automatic start = 0 user = demoNext we clone a copy of the master server by using online backup mode for copying the data volumes, create a clean log volume and bring up the slave server. In real life you could also restore the slave volumes from your most recent backup, as long as all the forward logs matching the backup time are still available...
demo@linux:~/slave> mkdir vol log demo@linux:~/slave> dbctl -s 3000 -u dba backup start On-line backup mode has been started. demo@linux:~/slave> cp ../vol/db*.vol ./vol demo@linux:~/slave> ll vol insgesamt 5125 -rw------- 1 demo users 2621440 2007-11-07 02:41 db-01.vol -rw------- 1 demo users 2621440 2007-11-07 02:41 db-02.vol demo@linux:~/slave> dbctl -s 3000 -u dba backup stop On-line backup mode has been stopped. demo@linux:~/slave> ll insgesamt 48 -rw-r--r-- 1 demo users 20855 2007-11-07 02:39 eloqdb6.cfg -r--r--r-- 1 demo users 21044 2007-11-07 02:36 eloqdb6.cfg,v drwxr-xr-x 2 demo users 48 2007-11-07 02:40 log drwxr-xr-x 2 demo users 112 2007-11-07 02:41 vol demo@linux:~/slave> ll vol insgesamt 5125 -rw------- 1 demo users 2621440 2007-11-07 02:41 db-01.vol -rw------- 1 demo users 2621440 2007-11-07 02:41 db-02.vol demo@linux:~/slave> dbvolextend -R -vc eloqdb6.cfg ELOQUENCE DBVOLEXTEND (C) Copyright 2005 Marxmeier Software AG (B.07.10) Reading configuration ... Opening root volume Restoring log volume /home/demo/slave/vol/log-1.vol Closing volume ... done. demo@linux:~/slave> ll vol insgesamt 7688 -rw------- 1 demo users 2621440 2007-11-07 02:42 db-01.vol -rw------- 1 demo users 2621440 2007-11-07 02:41 db-02.vol -rw------- 1 demo users 2621440 2007-11-07 02:42 log-1.volWith config and volumes in place, we start the slave server...
demo@linux:~/slave> /etc/init.d/eloq6 start demo-slave Starting eloqdb6[demo-slave] daemon done demo@linux:~/slave> tail -20 eloqdb6.log ** Wed Nov 7 02:43:25 2007 Flags = [*1E2] Wed 07 02:43:25 (32757) D1: Eloquence data base server initializing Wed 07 02:43:25 (32758) D0: Server patch level PE71-0708130 Wed 07 02:43:25 (32758) D0: Server is configured as a replication SLAVE server Wed 07 02:43:25 (32758) D1: [0] /home/demo/slave/vol/db-01.vol Wed 07 02:43:25 (32758) D1: [1] /home/demo/slave/vol/db-02.vol Wed 07 02:43:25 (32758) D1: [2] /home/demo/slave/vol/log-1.vol Wed 07 02:43:25 (32758) D1: Starting 4 TIO threads Wed 07 02:43:25 (32758) D1: TIO Queue size 40 Wed 07 02:43:25 (32758) C1: Setting up buffer cache: 8192 buffers Wed 07 02:43:26 (32758) D1: Scheduler semaphore semid = 4259845 Wed 07 02:43:26 (32758) D1: Communication buffer size = 1314816 Wed 07 02:43:26 (32758) D1: Communication buffer shmid = 179175427 Wed 07 02:43:26 (32758) D0: Eloquence database server active demo@linux:~/slave> /etc/init.d/eloq6 status eloqsd process is not active unused eloqdb6[eloqdb] process is not active unused eloqdb6[demo] process is active (pid 32502) running eloqdb6[demo-slave] process is active (pid 32758) runningWe can use dbctl to check the replication status of master and slave servers. In our case, both show the same checkpoint and timestamp because there was no database activity on our master while we set up the slave. In real life the master server would contents would have "advanced in time", so that the slave server initially lags behind.
demo@linux:~/slave> dbctl -s 3000 replication status Server is configured as MASTER Last checkpoint is 6-1.1 (2007-11-07 02:34:46) Forward-logging has been enabled. Forward-log is '/home/demo/log/fw-6-1.log'. demo@linux:~/slave> dbctl -s 4000 replication status Server is configured as SLAVE Last checkpoint is 6-1.1 (2007-11-07 02:34:46) Forward-logging has been enabled.To start replication between the two servers, we run the dbrepl utility on the master. In this demo we used a separate terminal so we can see its diagnostic messages; in real life, dbrepl would be run as a "nohup" background process.
When started, dbrepl retrieves the replication status from the slave server, locates the appropriate starting point in the forward-logs of the master, and begins replicating transactions. After catching up with the master server (if there was any backlog), it follows new master transactions close to real time.
# ... (separate terminal window) # # demo@linux:~> dbrepl -v -c eloqdb6.cfg :4000 # R1: processing forward-log file: '/home/demo/log/fw-6-1.log' # R1: found synchronization point with slave server # R1: slave server is up-to-date until 2007-11-07 02:41:07 # # ... (dbrepl continues running)To verify the replication, we use query3k or any other utility to perform some database update on the master server. We can then use query3k or dbexport or any other appropriate utility to check if the update has been propagated to the slave server correctly...
demo@linux:~> EQ_DBSERVER=:3000 query3k B.07.10.04 Eloquence QUERY3K WED, NOV 7, 2007, 2:47 AM Copyright 2004-2007 Marxmeier Software AG Copyright 2004 Hewlett-Packard Development Company, L.P. >base=toydb PASSWORD = >> MODE = >>1 >add products PRODUCT-NO =>>4712 PRODUCT-NAME =>>dont care PRICE =>>321 PRODUCT-LINE =>>xx QUANTITY =>>789 PRODUCT-NO =>>// >exit demo@linux:~> EQ_DBSERVER=:4000 dbexport -s - toydb products ELOQUENCE DBEXPORT (C) Copyright 2005 Marxmeier Software AG (B.07.10) # DATABASE = TOYDB # SET 1 = PRODUCTS "A00003","POKER DICE SET",125,"10",500 "A00008","POSTER PAINTS",95,"30",1250 "A00009","COLOURING BOOK",65,"30",1000 "A00001","PACK OF CARDS",75,"10",1500 "A00010","ERASER GIFT SET",185,"30",1500 "A00002","LUDO SET",1250,"10",750 "A00005","15\" PINK RABBIT",1745,"20",200 "A00007","SET OF CRAYONS",175,"30",500 "A00004","12\" TEDDY BEAR",1525,"20",250 "A00006","SET OF PANDAS",2500,"20",150 "4711","eau de cologne",123,"xy",456 "4712","dont care",321,"xx",789dbctl also shows an updated replication status and timestamp now...
demo@linux:~> dbctl -s 3000 replication status Server is configured as MASTER Last checkpoint is 6-1.13 (2007-11-07 02:48:47) Forward-logging has been enabled. Forward-log is '/home/demo/log/fw-6-1.log'. demo@linux:~> dbctl -s 4000 replication status Server is configured as SLAVE Last checkpoint is 6-1.13 (2007-11-07 02:48:47) Forward-logging has been enabled. Forward-log is '/home/demo/slave/log/fw-6-1.log'.When using forward logging and replication, you have to keep in mind to implement appropriate scripts and procedures for housekeeping the forward-logs in such a way that they are not deleted before dbrepl has processed them.
If you are also using the FwLog option on the slave server, to maintain replicated copies of the master forward-logs on the slave (in addition to the replicated databases), you will also need to implement appropriate housekeeping procedures on the slave system.
(End of Demo)