SQL Server Performance Forum – Threads Archive

database not available?

Hi,
I had an issue with database not available in the morning today, but I’m not sure why. I have an application where the users need to access the database to retrieve their password to login successfully, but due to this unavailability, they can’t login. But after a while, without me doing anything, the users can login again, which to me means database available again. I have looked at the database log, but am not sure what is it that caused the failure. I have cut and paste it here, is there anything that tells? 2004-04-29 06:09:04.71 server Microsoft SQL Server 2000 – 8.00.679 (Intel X86)
Aug 26 2002 15:09:48
Copyright (c) 1988-2000 Microsoft Corporation
Enterprise Edition on Windows NT 5.0 (Build 2195: Service Pack 2) 2004-04-29 06:09:04.73 server Copyright (C) 1988-2000 Microsoft Corporation.
2004-04-29 06:09:04.73 server All rights reserved.
2004-04-29 06:09:04.73 server Server Process ID is 1616.
2004-04-29 06:09:04.73 server Logging SQL Server messages in file ‘E

rogram FilesMicrosoft SQL ServerMSSQLlogERRORLOG’.
2004-04-29 06:09:04.81 server SQL Server is starting at priority class ‘normal'(4 CPUs detected).
2004-04-29 06:09:04.95 server SQL Server configured for thread mode processing.
2004-04-29 06:09:04.96 server Using dynamic lock allocation. [2500] Lock Blocks, [5000] Lock Owner Blocks.
2004-04-29 06:09:05.18 server Attempting to initialize Distributed Transaction Coordinator.
2004-04-29 06:09:08.11 spid3 Starting up database ‘master’.
2004-04-29 06:09:08.84 spid3 0 transactions rolled back in database ‘master’ (1).
2004-04-29 06:09:08.86 spid3 Recovery is checkpointing database ‘master’ (1)
2004-04-29 06:09:09.07 server Using ‘SSNETLIB.DLL’ version ‘8.0.568’.
2004-04-29 06:09:09.07 spid5 Starting up database ‘model’.
2004-04-29 06:09:09.10 spid3 Server name is ‘VIRTUALMSSQL’.
2004-04-29 06:09:09.10 spid8 Starting up database ‘msdb’.
2004-04-29 06:09:09.10 spid9 Starting up database ‘dbSATAtest’.
2004-04-29 06:09:09.10 spid10 Starting up database ‘OTBTS’.
2004-04-29 06:09:09.10 spid11 Starting up database ‘dbSATA’.
2004-04-29 06:09:09.12 spid12 Starting up database ‘dbFund’.
2004-04-29 06:09:09.17 spid13 Starting up database ‘dbSATAArchival’.
2004-04-29 06:09:09.17 spid14 Starting up database ‘dbRIS’.
2004-04-29 06:09:09.23 spid15 Starting up database ‘WHP’.
2004-04-29 06:09:09.25 spid16 Starting up database ‘HelpDesk’.
2004-04-29 06:09:09.29 server SuperSocket Info: Bind failed on TCP port 1433.
2004-04-29 06:09:09.29 server SQL server listening on 192.168.2.228: 1433.
2004-04-29 06:09:09.32 spid17 Starting up database ‘patient’.
2004-04-29 06:09:09.60 server SQL server listening on TCP, Shared Memory, Named Pipes.
2004-04-29 06:09:09.60 server SQL Server is ready for client connections
2004-04-29 06:09:09.92 spid13 1 transactions rolled forward in database ‘dbSATAArchival’ (9).
2004-04-29 06:09:10.03 spid13 0 transactions rolled back in database ‘dbSATAArchival’ (9).
2004-04-29 06:09:10.04 spid5 Clearing tempdb database.
2004-04-29 06:09:10.09 spid15 17 transactions rolled forward in database ‘WHP’ (11).
2004-04-29 06:09:10.10 spid11 Analysis of database ‘dbSATA’ (7) is 100% complete (approximately 0 more seconds)
2004-04-29 06:09:10.12 spid8 77 transactions rolled forward in database ‘msdb’ (4).
2004-04-29 06:09:10.14 spid13 Recovery is checkpointing database ‘dbSATAArchival’ (9)
2004-04-29 06:09:10.18 spid11 Recovery of database ‘dbSATA’ (7) is 0% complete (approximately 3 more seconds) (Phase 2 of 3).
2004-04-29 06:09:10.18 spid15 0 transactions rolled back in database ‘WHP’ (11).
2004-04-29 06:09:10.34 spid8 0 transactions rolled back in database ‘msdb’ (4).
2004-04-29 06:09:10.35 spid15 Recovery is checkpointing database ‘WHP’ (11)
2004-04-29 06:09:10.42 spid8 Recovery is checkpointing database ‘msdb’ (4)
2004-04-29 06:09:10.57 spid10 7 transactions rolled forward in database ‘OTBTS’ (6).
2004-04-29 06:09:10.65 spid10 0 transactions rolled back in database ‘OTBTS’ (6).
2004-04-29 06:09:10.73 spid10 Recovery is checkpointing database ‘OTBTS’ (6)
2004-04-29 06:09:12.01 spid11 Recovery of database ‘dbSATA’ (7) is 100% complete (approximately 0 more seconds) (Phase 2 of 3).
2004-04-29 06:09:12.04 spid11 2524 transactions rolled forward in database ‘dbSATA’ (7).
2004-04-29 06:09:12.26 spid16 41 transactions rolled forward in database ‘HelpDesk’ (12).
2004-04-29 06:09:12.34 spid16 0 transactions rolled back in database ‘HelpDesk’ (12).
2004-04-29 06:09:12.34 spid11 0 transactions rolled back in database ‘dbSATA’ (7).
2004-04-29 06:09:12.37 spid16 Recovery is checkpointing database ‘HelpDesk’ (12)
2004-04-29 06:09:12.40 spid11 Recovery is checkpointing database ‘dbSATA’ (7)
2004-04-29 06:09:13.54 spid5 Starting up database ‘tempdb’.
2004-04-29 06:09:13.67 spid5 Analysis of database ‘tempdb’ (2) is 100% complete (approximately 0 more seconds)
2004-04-29 06:09:14.18 spid3 Recovery complete.
2004-04-29 06:09:14.18 spid3 SQL global counter collection task is created.
2004-04-29 06:09:15.64 spid52 Using ‘xpsqlbot.dll’ version ‘2000.80.194’ to execute extended stored procedure ‘xp_qv’.
2004-04-29 08:25:12.65 spid62 Using ‘xpstar.dll’ version ‘2000.80.658’ to execute extended stored procedure ‘sp_MSgetversion’.

You need to look at the end of the error log before this. Also, have you looked at the application and system logs on the SQL Server to see if there is any information there? MeanOldDBA
[email protected] When life gives you a lemon, fire the DBA.

Check any database maintenance job was running during that time. Satya SKJ
Moderator
http://www.SQL-Server-Performance.Com/forum
This posting is provided â€œAS ISâ€ with no rights for the sake of knowledge sharing.

I have looked at the end of the error log before this log, and they shows: DateSourceMessage 2004-04-28 09:54:26.12 serverMicrosoft SQL Server 2000 – 8.00.679 (Intel X86) … 2004-04-28 09:54:26.15 serverLogging SQL Server messages in file ‘E

rogram FilesMicrosoft SQL ServerMSSQ 2004-04-28 09:54:26.15 serverServer Process ID is 2060. 2004-04-28 09:54:26.15 serverAll rights reserved. 2004-04-28 09:54:26.15 serverCopyright (C) 1988-2000 Microsoft Corporation. 2004-04-28 09:54:26.21 serverSQL Server is starting at priority class ‘normal'(4 CPUs detected). 2004-04-28 09:54:26.40 serverSQL Server configured for thread mode processing. 2004-04-28 09:54:26.42 serverUsing dynamic lock allocation. [2500] Lock Blocks, [5000] Lock Owner Blocks. 2004-04-28 09:54:26.50 serverAttempting to initialize Distributed Transaction Coordinator. 2004-04-28 09:54:29.03 spid3Starting up database ‘master’. 2004-04-28 09:54:29.76 spid3Recovery is checkpointing database ‘master’ (1) 2004-04-28 09:54:29.76 spid30 transactions rolled back in database ‘master’ (1). 2004-04-28 09:54:29.82 spid5Starting up database ‘model’. 2004-04-28 09:54:29.82 serverUsing ‘SSNETLIB.DLL’ version ‘8.0.568’. 2004-04-28 09:54:29.87 spid9Starting up database ‘dbSATAtest’. 2004-04-28 09:54:29.87 spid8Starting up database ‘msdb’. 2004-04-28 09:54:29.87 spid3Server name is ‘VIRTUALMSSQL’. 2004-04-28 09:54:29.89 spid12Starting up database ‘dbFund’. 2004-04-28 09:54:29.89 spid11Starting up database ‘dbSATA’. 2004-04-28 09:54:29.89 spid10Starting up database ‘OTBTS’. 2004-04-28 09:54:29.92 serverSQL server listening on 192.168.2.228: 1433. 2004-04-28 09:54:29.92 serverSuperSocket Info: Bind failed on TCP port 1433. 2004-04-28 09:54:29.95 spid14Starting up database ‘dbRIS’. 2004-04-28 09:54:29.95 spid13Starting up database ‘dbSATAArchival’. 2004-04-28 09:54:29.96 spid15Starting up database ‘WHP’. 2004-04-28 09:54:30.00 spid16Starting up database ‘HelpDesk’. 2004-04-28 09:54:30.06 spid17Starting up database ‘patient’. 2004-04-28 09:54:30.20 serverSQL Server is ready for client connections 2004-04-28 09:54:30.20 serverSQL server listening on TCP, Shared Memory, Named Pipes. 2004-04-28 09:54:30.40 spid5Clearing tempdb database. 2004-04-28 09:54:31.95 spid5Starting up database ‘tempdb’. 2004-04-28 09:54:31.98 spid5Analysis of database ‘tempdb’ (2) is 100% complete (approximately 0 more second 2004-04-28 09:54:52.39 spid3Recovery complete. 2004-04-28 09:54:52.40 spid3SQL global counter collection task is created. 2004-04-28 09:54:53.23 spid62Using ‘xpsqlbot.dll’ version ‘2000.80.194’ to execute extended stored procedure 2004-04-28 09:58:02.77 spid95Using ‘xpstar.dll’ version ‘2000.80.658’ to execute extended stored procedure ‘ 2004-04-28 12:49:30.76 spid91DBCC TRACEON 208, server process ID (SPID) 91. 2004-04-28 21:00:14.71 backupDatabase backed up: Database: dbSATAArchival, creation date(time): 2004/01/28(1 2004-04-28 21:00:23.02 backupDatabase backed up: Database: dbSATAArchival, creation date(time): 2004/01/28(1 I find the above seems normal. About the system and application log, I have looked at them, and most of the problems I received are printers. In application log, I have error from MSSQLServer about "SuperSocket Info: Bind failed on TCP port 1433. But this has happened so often, that I don’t think is the error…. whatever is showing on the INFO for application log, it’s showing on the database log… [<img src=’/community/emoticons/emotion-6.gif’ alt=’

‘ />]

This looks like your database is restarting every morning. You don’t want it to do this do you???? SuperSocket Info: Bind failed on TCP port 1433 I would be worrying about this. Have your network guys put a trace on this to see if there is a problem. If you want to take a shotgun approach (which I sometimes prefer if it’s production), replace the network card and cable and have them place it into a new port. This could cause you all kinds of problems on a SQL Server. MeanOldDBA
[email protected] When life gives you a lemon, fire the DBA.

No, rebooting the database everyday is not what we wanted. Anyway, the database is not rebooted everyday. 29 April morning seems to be an exception. So that log means it’s rebooted. I’m asking the network guys to look at if there are any hardware problem during that time. BTW, is there any way to find if there is a reboot scheduled? Ok, I will get the guys to look into the port problem. Thanks!

Normally it’s not something "scheduled". We had a problem with a server rebooting once and it was because someone installed the BACKUP EXEC Open File agent. Apparently there was a bug with that and SQL Server. That was fun figuring out. We had it happen once by installing a new KBM. Cheery, cheery. What processes are happening on the server when it reboots? Can you identify anything running at all besides the crazy port problems? MeanOldDBA
[email protected] When life gives you a lemon, fire the DBA.

hmm… I’m not too sure what do you mean by "BACKUP EXEC Open File agent" Is it a program in MSSQL? I need the system side guys to get back to me about stuff running in the server. Meanwhile I will look at the schedule jobs. Will let you know <img src=’/community/emoticons/emotion-1.gif’ alt=’

‘ />

BACKUP EXEC is the third party tool from Veritas (I think) to backup the databases, if you’re not using so then ignore it. For that TCP/IP bind failed error, refer to this KBA http://support.microsoft.com/default.aspx?scid=kb;en-us;319578&sd=tech]. HTH Satya SKJ
Moderator
http://www.SQL-Server-Performance.Com/forum
This posting is provided â€œAS ISâ€ with no rights for the sake of knowledge sharing.

I am having the same type of problem. Users started receiving errors in application which access SQL database. Here is my log: DateSourceMessage
2006-02-28 22:03:41.64 serverMicrosoft SQL Server 2000 – 8.00.194 (Intel X86) …
2006-02-28 22:03:41.67 serverLogging SQL Server messages in file ‘C

rogram FilesMicrosoft SQL ServerMSSQ
2006-02-28 22:03:41.67 serverServer Process ID is 1008.
2006-02-28 22:03:41.67 serverAll rights reserved.
2006-02-28 22:03:41.67 serverCopyright (C) 1988-2000 Microsoft Corporation.
2006-02-28 22:03:41.81 serverSQL Server is starting at priority class ‘normal'(2 CPUs detected).
2006-02-28 22:03:42.07 serverSQL Server configured for thread mode processing.
2006-02-28 22:03:42.09 serverUsing dynamic lock allocation. [2500] Lock Blocks, [5000] Lock Owner Blocks.
2006-02-28 22:03:42.14 serverAttempting to initialize Distributed Transaction Coordinator.
2006-02-28 22:03:42.29 serverFailed to obtain TransactionDispenserInterface: Result Code = 0x8004d01b
2006-02-28 22:03:42.56 spid4Starting up database ‘master’.
2006-02-28 22:03:43.51 spid5Starting up database ‘model’.
2006-02-28 22:03:43.51 serverUsing ‘SSNETLIB.DLL’ version ‘8.0.311’.
2006-02-28 22:03:43.68 spid4Server name is ‘PP02’.
2006-02-28 22:03:43.70 spid9Starting up database ‘pubs’.
2006-02-28 22:03:43.70 spid8Starting up database ‘msdb’.
2006-02-28 22:03:43.81 serverSQL server listening on 127.0.0.1: 1433.
2006-02-28 22:03:43.81 serverSQL server listening on 192.168.1.12: 1433.
2006-02-28 22:03:43.89 spid10Starting up database ‘Northwind’.
2006-02-28 22:03:43.92 spid11Starting up database ‘PROD’.
2006-02-28 22:03:44.01 spid12Starting up database ‘Paceart_Database’.
2006-02-28 22:03:44.10 serverSQL Server is ready for client connections
2006-02-28 22:03:44.10 serverSQL server listening on TCP, Shared Memory, Named Pipes.
2006-02-28 22:03:44.64 spid5Clearing tempdb database.
2006-02-28 22:03:46.31 spid5Starting up database ‘tempdb’.
2006-02-28 22:03:57.57 spid4Recovery complete.
2006-02-28 22:04:02.55 spid51Using ‘xpsqlbot.dll’ version ‘2000.80.194’ to execute extended stored procedure
2006-02-28 23:02:07.89 spid53Using ‘xplog70.dll’ version ‘2000.80.194’ to execute extended stored procedure
2006-03-01 07:40:38.31 spid63The database is not published..
2006-03-01 07:40:38.31 spid63Error: 18757, Severity: 16, State: 1
2006-03-01 07:55:08.61 spid71The database is not published..
2006-03-01 07:55:08.61 spid71Error: 18757, Severity: 16, State: 1
2006-03-01 13:29:41.08 spid94Using ‘xpstar.dll’ version ‘2000.80.194’ to execute extended stored procedure ‘ Thanks,
Kate

quote:Originally posted by satya BACKUP EXEC is the third party tool from Veritas (I think) to backup the databases, if you’re not using so then ignore it. For that TCP/IP bind failed error, refer to this KBA http://support.microsoft.com/default.aspx?scid=kb;en-us;319578&sd=tech]. HTH Satya SKJ
Moderator
http://www.SQL-Server-Performance.Com/forum
This posting is provided â€œAS ISâ€ with no rights for the sake of knowledge sharing.

Hi ya, for the first one, if you get the failed to bind error, can you run the command netstat -a -o from the dos prompt. Look for the line which says 1433 listening or mssql listening. Note down the process id number then open Task Manager, processes tab, add the Process id column and locate the process number to find out what else is on 1433
For the second server, is this an AWE enabled instance? If so then make sure that either SP4 is installed or that the max server memory is not an exact power of 2 like 8192http://support.microsoft.com/?kbid=911845 Cheers
Twan

Is that error happening everytime when database is accessed from application?
Satya SKJ
Contributing Editor & Forums Moderator
http://www.SQL-Server-Performance.Com
This posting is provided â€œAS ISâ€ with no rights for the sake of knowledge sharing.

]]>