Capítulo IV: Resultados
4.2 Discusión
If errors are reported in a backup operation, review the logs for any errors or inconsistencies.
There are a number of logs to check. .
IBM Tivoli Storage Manager activity log
The IBM Tivoli Storage Manager activity log contains all messages normally sent to the server console during a server operation. The activity log can be monitored using either administrative client command line or the IBM Tivoli Storage Manager ISC Web interface. The Example 6-10 on page 180, shows the contents of the activity log related to a Data Protection backup. You can see the start session for the node to backup, the start session for the proxy agent (in this case, we are using VSS) and the completion status of the backup, including statistics.
Example 6-10 IBM Tivoli Storage Manager activity log
tsm: ZAIRE>q actlog begint=07:19:19
02/19/08 07:19:19 ANR0406I Session 335 started for node CLUSQL01_DAILY (TDP MSSQL Win32) (Tcp/Ip libra.itso-sj.ibm.com(1266)).
(SESSION: 335)
02/19/08 07:19:20 ANR0406I Session 336 started for node LIBRA_VSS (WinNT) (Tcp/Ip libra.itso-sj.ibm.com(1293)). (SESSION: 336) 02/19/08 07:19:20 ANR0397I Session 336 for node LIBRA_VSS has begun a proxy session for node CLUSQL01_DAILY. (SESSION: 336)
02/19/08 07:19:21 ANE4940I (Session: 336, Node: CLUSQL01_DAILY) Performing a full, TSM backup of object 'SqlServerWriter' component
02/19/08 07:19:21 ANE4940I (Session: 336, Node: CLUSQL01_DAILY) Performing a full, TSM backup of object 'SqlServerWriter' component 'DBTest1' using shadow copy.(SESSION: 336)
02/19/08 07:19:21 ANE4940I (Session: 336, Node: CLUSQL01_DAILY) Performing a full, TSM backup of object 'SqlServerWriter' component 'DBTest2' using shadow copy.(SESSION: 336)
02/19/08 07:19:21 ANE4940I (Session: 336, Node: CLUSQL01_DAILY) Performing a full, TSM backup of object 'SqlServerWriter' component 'DBTest3' using shadow copy.(SESSION: 336)
02/19/08 07:19:21 ANE4940I (Session: 336, Node: CLUSQL01_DAILY) Performing a full, TSM backup of object 'SqlServerWriter' component 'DBTest6' using shadow copy.(SESSION: 336)
02/19/08 07:19:22 ANE4940I (Session: 336, Node: CLUSQL01_DAILY) Performing a full, TSM backup of object 'SqlServerWriter' component 'LogShippingDB' using shadow copy.(SESSION: 336)
02/19/08 07:19:22 ANE4940I (Session: 336, Node: CLUSQL01_DAILY) Performing a full, TSM backup of object 'SqlServerWriter' component 'TEst4' using shadow copy.(SESSION: 336)
02/19/08 07:19:22 ANE4940I (Session: 336, Node: CLUSQL01_DAILY) Performing a full, TSM backup of object 'SqlServerWriter' component 'master' using shadow copy.(SESSION: 336)
02/19/08 07:19:22 ANE4940I (Session: 336, Node: CLUSQL01_DAILY) Performing a full, TSM backup of object 'SqlServerWriter' component 'model' using shadow copy.(SESSION: 336)
02/19/08 07:19:23 ANE4940I (Session: 336, Node: CLUSQL01_DAILY) Performing a full, TSM backup of object 'SqlServerWriter' component 'msdb' using shadow copy.(SESSION: 336)
02/19/08 07:19:23 ANR0406I Session 337 started for node LIBRA_VSS (WinNT) (Tcp/Ip libra.itso-sj.ibm.com(1324)). (SESSION: 337) 02/19/08 07:19:23 ANR0397I Session 337 for node LIBRA_VSS has begun a proxy session for node CLUSQL01_DAILY. (SESSION: 337)
02/19/08 07:19:36 ANR0406I Session 338 started for node LIBRA_VSS (WinNT) (Tcp/Ip libra.itso-sj.ibm.com(1345)). (SESSION: 338) 02/19/08 07:19:36 ANR0397I Session 338 for node LIBRA_VSS has begun a proxy session for node CLUSQL01_DAILY. (SESSION: 338)
02/19/08 07:20:08 ANR8337I LTO volume 027AKK mounted in drive 3580_1 (/dev/rmt0). (SESSION: 338)
02/19/08 07:20:08 ANR0511I Session 338 opened output volume 027AKK.
(SESSION: 338)
02/19/08 07:20:24 ANE4941I (Session: 338, Node: CLUSQL01_DAILY) Backup of object 'SqlServerWriter' component 'DBTest1' finished successfully.(SESSION: 338)
02/19/08 07:20:39 ANE4941I (Session: 338, Node: CLUSQL01_DAILY) Backup of object 'SqlServerWriter' component 'DBTest2' finished successfully.(SESSION: 338)
02/19/08 07:20:53 ANE4941I (Session: 338, Node: CLUSQL01_DAILY) Backup of object 'SqlServerWriter' component 'DBTest3' finished successfully.(SESSION: 338)
02/19/08 07:21:08 ANE4941I (Session: 338, Node: CLUSQL01_DAILY) Backup of object 'SqlServerWriter' component 'DBTest6' finished successfully.(SESSION: 338)
02/19/08 07:21:22 ANE4941I (Session: 338, Node: CLUSQL01_DAILY) Backup of object 'SqlServerWriter' component 'DBSales7' finished
successfully.(SESSION: 338)
02/19/08 07:21:37 ANE4941I (Session: 338, Node: CLUSQL01_DAILY) Backup of
object 'SqlServerWriter' component 'LogShippingDB' finished successfully.(SESSION: 338)
02/19/08 07:21:52 ANE4941I (Session: 338, Node: CLUSQL01_DAILY) Backup of object 'SqlServerWriter' component 'TEst4' finished successfully.(SESSION: 338)
02/19/08 07:22:06 ANE4941I (Session: 338, Node: CLUSQL01_DAILY) Backup of object 'SqlServerWriter' component 'master' finished successfully.(SESSION: 338)
02/19/08 07:22:16 ANE4941I (Session: 338, Node: CLUSQL01_DAILY) Backup of object 'SqlServerWriter' component 'model' finished successfully.(SESSION: 338)
02/19/08 07:22:22 ANE4941I (Session: 338, Node: CLUSQL01_DAILY) Backup of object 'SqlServerWriter' component 'msdb' finished successfully.(SESSION: 338)
02/19/08 07:22:22 ANR0514I Session 338 closed volume 027AKK. (SESSION: 338) 02/19/08 07:22:27 ANR0399I Session 337 for node LIBRA_VSS has ended a proxy session for node CLUSQL01_DAILY. (SESSION: 337)
02/19/08 07:22:27 ANE4952I (Session: 336, Node: CLUSQL01_DAILY) Total number of objects inspected: 140 (SESSION: 336) 02/19/08 07:22:27 ANR0403I Session 337 ended for node LIBRA_VSS (WinNT).
(SESSION: 337)
02/19/08 07:22:27 ANE4954I (Session: 336, Node: CLUSQL01_DAILY) Total number of objects backed up: 140 (SESSION: 336) 02/19/08 07:22:27 ANE4958I (Session: 336, Node: CLUSQL01_DAILY) Total number of objects updated: 0 (SESSION: 336) 02/19/08 07:22:27 ANE4960I (Session: 336, Node: CLUSQL01_DAILY) Total number of objects rebound: 0 (SESSION: 336) 02/19/08 07:22:27 ANE4957I (Session: 336, Node: CLUSQL01_DAILY) Total number of objects deleted: 0 (SESSION: 336) 02/19/08 07:22:27 ANE4970I (Session: 336, Node: CLUSQL01_DAILY) Total number of objects expired: 0 (SESSION: 336) 02/19/08 07:22:27 ANE4959I (Session: 336, Node: CLUSQL01_DAILY) Total number of objects failed: 0 (SESSION: 336) 02/19/08 07:22:27 ANE4961I (Session: 336, Node: CLUSQL01_DAILY) Total number of bytes transferred: 40.02 MB (SESSION: 336) 02/19/08 07:22:27 ANE4963I (Session: 336, Node: CLUSQL01_DAILY) Data transfer time: 55.50 sec (SESSION:
336)
02/19/08 07:22:27 ANE4966I (Session: 336, Node: CLUSQL01_DAILY) Network data transfer rate: 738.47 KB/sec (SESSION:
336)
02/19/08 07:22:27 ANE4967I (Session: 336, Node: CLUSQL01_DAILY) Aggregate data transfer rate: 219.11 KB/sec (SESSION: 336) 02/19/08 07:22:27 ANE4968I (Session: 336, Node: CLUSQL01_DAILY) Objects compressed by: 0% (SESSION: 336) 02/19/08 07:22:27 ANE4964I (Session: 336, Node: CLUSQL01_DAILY) Elapsed processing time: 00:03:07 (SESSION: 336) 02/19/08 07:22:27 ANR0399I Session 336 for node LIBRA_VSS has ended a proxy session for node CLUSQL01_DAILY. (SESSION: 336)
02/19/08 07:22:27 ANR0403I Session 336 ended for node LIBRA_VSS (WinNT).
(SESSION: 336)
02/19/08 07:22:27 ANR0399I Session 338 for node LIBRA_VSS has ended a proxy session for node CLUSQL01_DAILY. (SESSION: 338)
02/19/08 07:22:27 ANR0403I Session 338 ended for node LIBRA_VSS (WinNT).
02/19/08 07:22:27 ANR0403I Session 335 ended for node CLUSQL01_DAILY (TDP MSSQL Win32). (SESSION: 335)
For more information about the IBM Tivoli Storage Manager server activity log, see the Tivoli Storage Manager Administrator Guide.
Data Protection for SQL log
Data Protection for SQL logs output to the file tdpsql.log in the Data Protection for SQL installation directory; by default, this is C:\Program Files\tivoli\tsm\TDPSQL. To change this location, use the parameter /logfile=e:\tsmlogs\sqlfull_db_daily.log. Example 6-11 on page 183 shows some sample output.
Example 6-11 Log SQL sqlfull_db_daily.log
=========================================================================
02/19/2008 08:48:08 Number of Stripes specified : 1 02/19/2008 08:48:08 Estimate : 'DBTest2', 'DBTest3', 'DBTest6', 'LogShippingDB', 'TEst4', 'master', 'model', 'msdb'
02/19/2008 09:15:48 Backup Type : full 02/19/2008 09:15:48 Backup Destination : TSM 02/19/2008 09:15:48 Local DSMAGENT Node : libra_vss 02/19/2008 09:15:48 Offload to Remote DSMAGENT Node :
02/19/2008 09:15:48 Mount Wait : Yes
02/19/2008 09:15:48 ---02/19/2008 09:18:55 VSS Backup operation completed with rc = 0
02/19/2008 09:18:55 Files Examined : 140
02/19/2008 09:18:55 Files Completed : 140 02/19/2008 09:18:55 Files Failed : 0
02/19/2008 09:18:55 Total Bytes : 41970349
IBM Tivoli Storage Manager API log
The IBM Tivoli Storage Manager API log, dsierror.log, s located n the Data Protection installation directory. For example, authentication problem messages are logged in this file, as shown in Example 6-12 on page 184.
Example 6-12 TSM dsierror.log
02/19/2008 08:44:54 ANS1025E Session rejected: Authentication failure 02/19/2008 08:46:21 ANS1025E Session rejected: Authentication failure 02/19/2008 08:46:30 ANS1025E Session rejected: Authentication failure 02/19/2008 08:47:07 ANS1025E Session rejected: Authentication failure 02/19/2008 08:47:19 ANS1025E Session rejected: Authentication failure 02/19/2008 08:47:33 ANS1025E Session rejected: Authentication failure
Windows Event log
Using Event Viewer and event logs, you can gather information about hardware, software and system problems. The VSS snapshot operations write detailed information to the Application log.
The SQL Server writes event information for the Windows event log. You can look for backup messages. See Figure 6-9 on page 184, Figure 6-10 on page 185, Figure 6-11 on page 185 and Figure 6-12 on page 186.
Figure 6-10 VSS backup information
Figure 6-11 LUN information on VSS backup
Figure 6-12 Hardware provider information on VSS backup
Staging directory log files
Staging directory log files are generated when a VSS backup is initiated. For every VSS operation that is run, a new subdirectory is created with the current date and time stamp. In our scenario, this is F:\adsm.sys\vss_staging\CLUSQL01_DAILY\9.43.86.45. Where the drive F:\ you configure on dsm.opt for your local DSMAgent, the CLUSQL01_DAILY is the node name and the 9.43.86.45 is the Tivoli Storage Manager TCP/IP Address. Within this directory you would find audit log files which are created for each SQL database. These files will check the VSS volumes for any errors, before using the volumes.
Additional log files
You need to check the backup-archive client log files, these files also contain output from the VSS backups:
dsmsched.log: To check the result of the schedules
dsmerror.log: If you have VSS errors, you can check the backup-archive dsmerror.log
agtsverr.log: This file is located in the backup-archive installation directory and contains information about VSS backup
dsmwebcl.log: This file is located in the backup-archive installation directory and contains the DSMagent.
If your storage supports VSS instant restore, and you are using this function, check also the fle IBMVSS.log.