Database error on startup

We've had TeamCity installed for a couple months so far with no issues. However, today the Teamcity server is failing to startup and is giving the following message when trying to hit the web interface.

jetbrains.buildServer.serverSide.db.UnexpectedDBException: Failed to maintain database schema on startup. SQL error: User not found: SASQL exception: User not found: SA   at jetbrains.buildServer.serverSide.db.TeamCityDatabaseManager.ensureActualSchema(TeamCityDatabaseManager.java:100)   at jetbrains.buildServer.rootDispatcher.TeamCityDispatcherServlet.processStartupServerInternal(TeamCityDispatcherServlet.java:120)   at jetbrains.buildServer.rootDispatcher.TeamCityDispatcherServlet.processServerStartup(TeamCityDispatcherServlet.java:60)   at jetbrains.buildServer.rootDispatcher.TeamCityDispatcherServlet.access$000(TeamCityDispatcherServlet.java:76)   at jetbrains.buildServer.rootDispatcher.TeamCityDispatcherServlet$1.run(TeamCityDispatcherServlet.java:2)   at java.lang.Thread.run(Unknown Source)caused by: java.sql.SQLException: User not found: SA   at org.hsqldb.jdbc.Util.sqlException(Unknown Source)   at org.hsqldb.jdbc.jdbcConnection.<init>(Unknown Source)   at org.hsqldb.jdbcDriver.getConnection(Unknown Source)   at org.hsqldb.jdbcDriver.connect(Unknown Source)   at jetbrains.buildServer.serverSide.db.jdbcLoader.JdbcDataSource.getConnection(JdbcDataSource.java:15)   at jetbrains.buildServer.serverSide.db.TeamCityDatabaseManager.ensureActualSchema(TeamCityDatabaseManager.java:113)   at jetbrains.buildServer.rootDispatcher.TeamCityDispatcherServlet.processStartupServerInternal(TeamCityDispatcherServlet.java:120)   at jetbrains.buildServer.rootDispatcher.TeamCityDispatcherServlet.processServerStartup(TeamCityDispatcherServlet.java:60)   at jetbrains.buildServer.rootDispatcher.TeamCityDispatcherServlet.access$000(TeamCityDispatcherServlet.java:76)   at jetbrains.buildServer.rootDispatcher.TeamCityDispatcherServlet$1.run(TeamCityDispatcherServlet.java:2)   at java.lang.Thread.run(Unknown Source)

We did not set up a separate SQL instance when installed TeamCity. No changes were made to this machine recently that I'm aware of.

Can anybody help me diagnose this? Unfortunately, I have bugs to be fixing and a deadline to meet, so this is a bad time for the integration server to go down. Any help would be greatly appreciated.

Thanks!

7 comments

More information.. We found the following entry in teamcity-server.log:

[2010-05-21 15:15:56,160]   INFO - rverSide.db.TeamCityDataSource - Using the following database settings:
database type: HSQLDB
database driver: org.hsqldb.jdbcDriver
connection: jdbc:hsqldb:file:C:/Users/paulj/.BuildServer/system/buildserver
login as: <empty>

I'm curious to why my login is <empty>. Where is this login information set? Could it have been wiped out somehow?

0

Still dead in the water right now. This has become a crash course in HSQLDB for me at a time when I need to be doing dev work. Can anyone please help?

I've tried running a database backup so that I can upgrade the product in hopes that might magically cure my problem. As probably obvious, I get same error running the backup command. See below...

TeamCity maintenance tool. Copyright 2010 JetBrains s.r.o. All Rights Reserved.

Command line arguments: backup -C -D -L -P
Using TeamCity data directory: C:\Users\paulj\.BuildServer
Using internal database.
Using source database
        database type: HSQLDB
        database driver: org.hsqldb.jdbcDriver
        connection: jdbc:hsqldb:file:C:/Users/paulj/.BuildServer/system/buildserver
        login as: <empty>
Failed: Could not take a connection from data source: User not found: SA
SQL exception: User not found: SA
jetbrains.buildServer.serverSide.db.DBException: Could not take a connection from data source: User not found: SA
SQL exception: User not found: SA
        at jetbrains.buildServer.serverSide.db.DBFunctions.create(DBFunctions.java:187)
        at jetbrains.buildServer.serverSide.maintenance.BackupRestoreRunner.ensureSourceDB(BackupRestoreRunner.java:554)

        at jetbrains.buildServer.serverSide.maintenance.BackupRestoreRunner.mainMain(BackupRestoreRunner.java:65)
        at jetbrains.buildServer.serverSide.maintenance.BackupRestoreRunner.main(BackupRestoreRunner.java:30)
Caused by: java.sql.SQLException: User not found: SA
        at org.hsqldb.jdbc.Util.sqlException(Unknown Source)
        at org.hsqldb.jdbc.jdbcConnection.<init>(Unknown Source)
        at org.hsqldb.jdbcDriver.getConnection(Unknown Source)
        at org.hsqldb.jdbcDriver.connect(Unknown Source)
        at jetbrains.buildServer.serverSide.db.jdbcLoader.JdbcDataSource.getConnection(JdbcDataSource.java:15)
        at jetbrains.buildServer.serverSide.db.DBFunctions.create(DBFunctions.java:474)
        ... 3 more
Done.

0

Update: I manually backed up the Data Directory, and did an uninstall/upgrade to 5.1.3. Unfortunately, still getting the exact same error even after that. I'm running out of ideas. Any help would be very much appreciated.

Error, again:

Ooops, something went wrong...

Error on step: Maintaining the database schema...

Failed to maintain database schema on startup. SQL error: User not found: SA
SQL exception: User not found: SA
0

Deeper digging into the error logs. It appears maybe our error may have started during the clean operation.

Still no fix, but the error after cleanup was slightly different:  "UnexpectedDBException: Unexpected exception when trying to connect from TeamCityDataSource: Cannot create PoolableConnectionFactory (User not found: SA)"

Log entries below...

[2010-07-23 03:00:02,879]   INFO -  jetbrains.buildServer.CLEANUP - Preparing for clean-up...
[2010-07-23 03:00:02,900]   INFO -  jetbrains.buildServer.CLEANUP - Clean-up started...
[2010-07-23 03:00:02,903]   INFO -  jetbrains.buildServer.CLEANUP -  Processing bt2  'MDX :: MDX Main'
[2010-07-23 03:00:02,903]   INFO -  jetbrains.buildServer.CLEANUP -   Applying policy 'clean ARTIFACTS older than the 2nd successful build'
[2010-07-23 03:00:02,903]   INFO -  jetbrains.buildServer.CLEANUP -   Cleaning from: 'Wed Jul 21 14:11:39 PDT 2010'
[2010-07-23 03:00:02,935]   INFO -  jetbrains.buildServer.CLEANUP -  Processing bt4  'null'
[2010-07-23 03:00:02,935]   INFO -  jetbrains.buildServer.CLEANUP -   Applying policy 'clean EVERYTHING more than 0 day older than the last build'
[2010-07-23 03:00:02,936]   INFO -  jetbrains.buildServer.CLEANUP -   Cleaning from: 'Thu Jul 22 14:00:01 PDT 2010'
[2010-07-23 03:00:02,937]   INFO -  jetbrains.buildServer.CLEANUP - Builds to clean for cleanup level (Clean everything):  1 builds: [123]
[2010-07-23 03:00:02,937]   INFO -  jetbrains.buildServer.CLEANUP - Builds to clean for cleanup level (Clean artifacts):  118 builds: [1, 2, 3, 4, 5, 6, 7, 8, 9, 10, 11, 12, 13, 14, 15, 16, 17, 18, 19, 21, 22, 23, 24, 25, 26, 28, 29, 30, 31, 32, 33, 34, 35, 36, 37, 38, 39, 40, 41, 43, 44, 45, 47, 48, 49, 50, 51, 52, 53, 54, 55, 56, 57, 58, 59, 60, 61, 62, 63, 64, 65, 66, 67, 68, 69, 70, 71, 72, 73, 74, 75, 76, 77, 78, 79, 80, 81, 82, 83, 84, 85, 86, 87, 88, 89, 90, 91, 92, 93, 94, 95, 96, 97, 98, 99, 100, 101, 102, 103, 104, 105, 106, 107, 108, 109, 110, 111, 112, 113, 114, 115, 116, 117, 118, 119, 120, 121, 122]
[2010-07-23 03:00:02,937]   INFO -  jetbrains.buildServer.CLEANUP - Performing cleanup EVERYTHING for 1 builds
[2010-07-23 03:00:02,937]   INFO -  jetbrains.buildServer.CLEANUP - Cleaning extensions data...
[2010-07-23 03:00:02,940]   INFO -  jetbrains.buildServer.CLEANUP - Deleting build logs...
[2010-07-23 03:00:02,968]   INFO -  jetbrains.buildServer.CLEANUP - Cleaning build history data from the database...
[2010-07-23 03:00:02,972]   INFO -  jetbrains.buildServer.CLEANUP - Deleting build promotions: [123]
[2010-07-23 03:00:02,975]   INFO -  jetbrains.buildServer.CLEANUP - Cleaning build statistics history data from the database...
[2010-07-23 03:00:02,975]   INFO -  jetbrains.buildServer.CLEANUP - Deleting build artifacts...
[2010-07-23 03:00:02,977]   INFO -  jetbrains.buildServer.CLEANUP - Performing cleanup ARTIFACTS for 118 builds
[2010-07-23 03:00:02,977]   INFO -  jetbrains.buildServer.CLEANUP - Cleaning extensions data...
[2010-07-23 03:00:03,000]   INFO -  jetbrains.buildServer.CLEANUP - Deleting build artifacts...
[2010-07-23 03:00:03,001]   INFO -  jetbrains.buildServer.CLEANUP - Performing VCS cleanup...
[2010-07-23 03:00:06,895]   INFO -  jetbrains.buildServer.CLEANUP - Global cleanup
[2010-07-23 03:00:06,895]   INFO -  jetbrains.buildServer.CLEANUP -  Running global cleaner DependencyTriggerCleaner
[2010-07-23 03:00:06,895]   INFO -  jetbrains.buildServer.CLEANUP -  Running global cleaner TestFailureRateCollector
[2010-07-23 03:00:06,896]   INFO -   jetbrains.buildServer.SERVER - Loading history of VCS changes...
[2010-07-23 03:00:06,906]   INFO -   jetbrains.buildServer.SERVER - Done loading VCS history: 384 changes loaded
[2010-07-23 03:00:06,946]   INFO -  jetbrains.buildServer.CLEANUP -  Running global cleaner DeleteZombiePersonalChangesFiles
[2010-07-23 03:00:06,946]   INFO -  jetbrains.buildServer.CLEANUP -  Running global cleaner PersonalBuildCleaner
[2010-07-23 03:00:06,947]   INFO -  jetbrains.buildServer.CLEANUP -  Running global cleaner PatchCacheImpl
[2010-07-23 03:00:06,948]   INFO -  jetbrains.buildServer.CLEANUP -  Running global cleaner DuplicatesGeneralDataCleaner
[2010-07-23 03:00:06,948]   INFO -  jetbrains.buildServer.CLEANUP -  Running global cleaner AuditLogDataCleaner
[2010-07-23 03:00:06,963]   INFO -  jetbrains.buildServer.CLEANUP -  Running global cleaner BrokenDependenciesCleaner
[2010-07-23 03:00:06,963]   INFO -  jetbrains.buildServer.CLEANUP -  Running global cleaner OldAgentsCleaner
[2010-07-23 03:00:06,963]   INFO -  jetbrains.buildServer.CLEANUP -  Running global cleaner ClearcaseCacheGeneralDataCleaner
[2010-07-23 03:00:06,964]   INFO -  jetbrains.buildServer.CLEANUP -  Running global cleaner InspectionGeneralDataCleaner
[2010-07-23 03:00:06,964]   INFO -  jetbrains.buildServer.CLEANUP -  Running global cleaner TestInfoTrunkCleaner
[2010-07-23 03:00:06,964]   INFO -  jetbrains.buildServer.CLEANUP -   0 records copied from test_info_trunk to test_info
[2010-07-23 03:00:06,964]   INFO -  jetbrains.buildServer.CLEANUP -  Running global cleaner UnusedVcsRootsCleaner
[2010-07-23 03:00:06,964]   INFO -  jetbrains.buildServer.CLEANUP - Global cleanup finished
[2010-07-23 03:00:08,599]  ERROR -  jetbrains.buildServer.CLEANUP - Unexpected error occured during cleanup
jetbrains.buildServer.serverSide.db.UnexpectedDBException: Unexpected exception when trying to connect from TeamCityDataSource: Cannot create PoolableConnectionFactory (User not found: SA)
SQL exception: Cannot create PoolableConnectionFactory (User not found: SA)
at jetbrains.buildServer.serverSide.db.TeamCityDataSource.connect(TeamCityDataSource.java:7)
at jetbrains.buildServer.serverSide.db.DBFacade.createPoolingDataSource(DBFacade.java:159)
at jetbrains.buildServer.serverSide.db.DBFacade.compact(DBFacade.java:168)
at jetbrains.buildServer.serverSide.impl.cleanup.ServerCleanupManagerImpl.startCleanup(ServerCleanupManagerImpl.java:43)
at jetbrains.buildServer.serverSide.impl.cleanup.ServerCleanupManagerImpl$2.run(ServerCleanupManagerImpl.java:1)
at java.util.TimerThread.mainLoop(Unknown Source)
at java.util.TimerThread.run(Unknown Source)
Caused by: org.apache.commons.dbcp.SQLNestedException: Cannot create PoolableConnectionFactory (User not found: SA)
at org.apache.commons.dbcp.BasicDataSource.createPoolableConnectionFactory(BasicDataSource.java:1549)
at org.apache.commons.dbcp.BasicDataSource.createDataSource(BasicDataSource.java:1388)
at org.apache.commons.dbcp.BasicDataSource.getConnection(BasicDataSource.java:1044)
at jetbrains.buildServer.serverSide.db.TeamCityDataSource.connect(TeamCityDataSource.java:45)
... 6 more
Caused by: java.sql.SQLException: User not found: SA
at org.hsqldb.jdbc.Util.sqlException(Unknown Source)
at org.hsqldb.jdbc.jdbcConnection.<init>(Unknown Source)
at org.hsqldb.jdbcDriver.getConnection(Unknown Source)
at org.hsqldb.jdbcDriver.connect(Unknown Source)
at jetbrains.buildServer.serverSide.db.jdbcLoader.JdbcDataSource.getConnection(JdbcDataSource.java:15)
at jetbrains.buildServer.serverSide.db.TeamCityBasicDataSource$JdbcConnectionFactory.createConnection(TeamCityBasicDataSource.java:2)
at org.apache.commons.dbcp.PoolableConnectionFactory.makeObject(PoolableConnectionFactory.java:582)
at org.apache.commons.dbcp.BasicDataSource.validateConnectionFactory(BasicDataSource.java:1556)
at org.apache.commons.dbcp.BasicDataSource.createPoolableConnectionFactory(BasicDataSource.java:1545)
... 9 more

[2010-07-23 03:00:08,612]   INFO -   jetbrains.buildServer.SERVER - Calculating builds to re-index by search engine after clean-up...
[2010-07-23 03:00:08,612]   INFO -   jetbrains.buildServer.SERVER - The following builds were selected to re-index by search engine: []

0

I finally have gotten our server instance back up and running, but unfortunately could not recover all the historical data or user accounts. I had to backup the data directory, uninstall teamcity, delete the data directory, re-install teamcity and replace the config section from backup. At least we now have a way to run builds again but the historical data is all lost.

We have been evaluating this product on one project in hopes of using it for more projects in the future. We hope to soon be buying the full version and building a solid production server environment with external DB servers. I imagine these problems won't happen in a good environment like that, but for the time being we are stuck with what we have and that was quite a disappointing failure of the product today.

If anyone does have any insight into how this error happened and how we could have recovered from it without losing all the historical data, I would love to hear your advice. Thank you.

0

Hi Paul,

connection: jdbc:hsqldb:file:C:/Users/paulj/.BuildServer/system/buildserver
login as: <empty>

I'm curious to why my login is <empty>. Where is this login information set? Could it have been wiped out somehow?



This is normal.
0

Hi Paul,

as I can see from the logs, the HSQL had crashed and the database had been corrupted. If you've got backup, you can restore data from backup.

For future, I'm highly recommending to use one of external DB systems — MySQL, Postgress, Oracle.
MySQL and Postgress are free; Oracle provides with a free edition of Oracle database (named XE — express edition) with some limitations.

Best regards,
Leonid

0

Please sign in to leave a comment.