We are having troubles in some SQL 2005/2008 databases.
The problem is that the backup group starts at 6:00a.m it takes more than 6 hours until finishes, BUT we see that first backup starts making after 4 hours, so it has 4 hours of ¿¿"previous checks"?? Don't know what is happening here
OUR ENVIROMENT:
Networker Server : 8.2.1
Networker Client: 8.2.1
Networker Microsoft Client: 8.2.1.7
SaveCommand: nsrsqlsv
SaveSet: MSSQL:
Databases: More than 400 databases in this client
LOG:
If I put nsrsqlsv -D5, I see the output, and its very large. I paste some "previous checks" that I can see here (after a lot of lines, it starts backup of databases)
(nsr/db_apps/bsmsql/sqlutil.c)6533:query SQL server with SELECT sys.databases.name, sys.database_mirroring.mirroring_state, sys.database_mirroring.mirroring_role, sys.database_mirroring.mirroring_partner_name, sys.database_mirroring.mirroring_witness_name, sys.database_mirroring.mirroring_safety_level FROM sys.database_mirroring JOIN sys.databases ON (sys.database_mirroring.database_id = sys.databases.database_id) WHERE sys.databases.name = N'DATABASE1' failed
nsr/db_apps/bsmsql/sqlutil.c(6534): Exiting bsQueryYukonDatabaseStatus(), database DATABASE1 not in mirror relationship.
raw_WillExecute: 'SELECT COUNT(*) FROM master.sys.master_files AS dbfiles INNER JOIN master..sysdatabases AS dbnames ON dbfiles.database_id = dbnames.dbid WHERE dbnames.name = 'DATABASE1' and dbfiles.type = 2'
raw_ExecuteComplete:'SELECT COUNT(*) FROM master.sys.master_files AS dbfiles INNER JOIN master..sysdatabases AS dbnames ON dbfiles.database_id = dbnames.dbid WHERE dbnames.name = 'DATABASE1' and dbfiles.type = 2' execute complete
raw_WillExecute: 'select top 1 name from msdb..backupset where database_name = N'DATABASE1' AND (type = 'D' OR type = 'L') order by backup_finish_date DESC '
raw_ExecuteComplete:'select top 1 name from msdb..backupset where database_name = N'DATABASE1' AND (type = 'D' OR type = 'L') order by backup_finish_date DESC ' execute complete
raw_WillExecute: 'select top 1 is_copy_only from msdb..backupset where database_name = N'DATABASE1' order by backup_finish_date DESC '
raw_ExecuteComplete:'select top 1 is_copy_only from msdb..backupset where database_name = N'DATABASE1' order by backup_finish_date DESC ' execute complete
raw_WillExecute: 'select distinct bs.database_name, bs.type, bs.name from msdb..backupset bs, master..sysdatabases sd where bs.database_name = N'DATABASE1' AND sd.name = N'DATABASE1' AND bs.type = 'D' AND bs.backup_start_date > sd.crdate AND bs.name = N'LegatoNWMSQL'
'
raw_ExecuteComplete:'select distinct bs.database_name, bs.type, bs.name from msdb..backupset bs, master..sysdatabases sd where bs.database_name = N'DATABASE1' AND sd.name = N'DATABASE1' AND bs.type = 'D' AND bs.backup_start_date > sd.crdate AND bs.name = N'LegatoNWMSQL'
raw_WillExecute: 'SELECT TOP 1 rh.destination_database_name, rh.restore_date, bs.backup_start_date, bs.type FROM msdb..restorehistory rh, msdb..backupset bs WHERE rh.destination_database_name=N'DATABASE1' AND bs.type='D' AND bs.database_name=N'DATABASE1' AND rh.restore_date > ( SELECT TOP 1 bs.backup_start_date FROM msdb..backupset bs, master..sysdatabases sd WHERE bs.database_name = N'DATABASE1' AND sd.name = N'DATABASE1' AND bs.type = 'D' AND bs.backup_start_date > sd.crdate ORDER BY bs.backup_start_date DESC) ORDER BY bs.backup_start_date DESC
'
raw_ExecuteComplete:'SELECT TOP 1 rh.destination_database_name, rh.restore_date, bs.backup_start_date, bs.type FROM msdb..restorehistory rh, msdb..backupset bs WHERE rh.destination_database_name=N'DATABASE1' AND bs.type='D' AND bs.database_name=N'DATABASE1' AND rh.restore_date > ( SELECT TOP 1 bs.backup_start_date FROM msdb..backupset bs, master..sysdatabases sd WHERE bs.database_name = N'DATABASE1' AND sd.name = N'DATABASE1' AND bs.type = 'D' AND bs.backup_start_date > sd.crdate ORDER BY bs.backup_start_date DESC) ORDER BY bs.backup_start_date DESC
(nsr/db_apps/bsmsql/sqlutil.c)6533:query SQL server with SELECT sys.databases.name, sys.database_mirroring.mirroring_state, sys.database_mirroring.mirroring_role, sys.database_mirroring.mirroring_partner_name, sys.database_mirroring.mirroring_witness_name, sys.database_mirroring.mirroring_safety_level FROM sys.database_mirroring JOIN sys.databases ON (sys.database_mirroring.database_id = sys.databases.database_id) WHERE sys.databases.name = N'DATABASE1' failed
nsr/db_apps/bsmsql/sqlutil.c(6534): Exiting bsQueryYukonDatabaseStatus(), database DATABASE1 not in mirror relationship.
Which version of NMM do you use? There are couple of them. Initial GA release had mutex issue, but if you use latests one (8.2.1.8 for example) you should be good.
Also, was this always slow? Do you have 400 clients under single instance or multiple instances? If multiple, do you run those at the same time? I do not have 400 DBs on single host, but I can assume that might be a bit of overkill too - especially when using instance based backup as discovery part happens first.
I am using 8.2.1.7, and before, I was using 8.2.1.2. With both of them happens the same.
It is a Microsoft Cluster with 5 instances. 1 of them has 500 Dababase. Other one has 300 Database. The second one starts backing up after 1 hour, and the first one after 4 hours...
The thing is that two months ago, it started backup inmediately...
From the log posted it is hard to say anything as there is one timestamp so one can't get an idea which calls takes how much time. I assume it if run once ok and then it changed, it might not be an issue on code side of NMM. Just for the sake of the test, what happens if you try to manually define DBs and have them backed up that way? Do you also see wait? When this was faster in the past, was DB also running on the same node as now? Was there failover and speeds have changed since?
If I put in saveset "MSSQL:DB1 MSSQL:DB2 ......" it happens the same.
Yesterday a weird thing happened to me with this group. I launched a full backup manually "savegrp -vvv -l full -G GROUP" and it start backuping up inmediately. It took 2 hours instead of 6.
Not sure if I understood correctly. Did you say that first bakcup (I assume full) takes around 4 hours and subsequent backups (incremental) takes about 6 hours?
Do you have any type of debug level set? If so that will introduce further delays, so please make sure there is no debug in place.
Incremental one is transaction logs while level full is DB backup. So, next question to ask is do you see this during DB backups (which you didn't last time) or only during transaction log backups?
Yes, full backup takes 4 hours, while log backup takes 6 hours. But If I look in "SQL Server Logs", I see that backups begins with a delay of 4 hours after group starts...
I don't have any debug level set. Not in the "backup command", neither in the "Group Options".
ble1
6 Operator
•
14354 Posts
•
56186 Points
1515
0
Posted November 16th, 2015 03:00
Which version of NMM do you use? There are couple of them. Initial GA release had mutex issue, but if you use latests one (8.2.1.8 for example) you should be good.