Servoy Server will not start

[bevil]

Dear community

I have an odd problem with Servoy server refusing to start (where it was fine before we cloned a disk, and everything else works (mail server / web server / calendar server / file server etc.))

Servoy is v. 6.1.2 with Postgres 9 on a Mac Mini server running Mac OS X 10.8.5. I start postgres with a terminal command (postgres_db/bin/pg_ctl start -D database -l postgres_db/postgres_log.txt), and it starts perfectly. The log shows no issues (vacuuming etc. but no errors). I then try to start Servoy server (by sh servoy_server.sh in the terminal) and it goes to the next line as expected, but then produces another prompt. Server does not start up. Servoy log shows "servoy does not start databases", but Postgres is started by my postgres start line, and the correct databases are there and accessible in PGAdmin.

Not sure what to look at as everything looks as though it is starting up, but servoy server does not, and because it doesn't, the server log shows nothing, and I don't know where to look.

I have tried changing port (to 5431 because the server - being 10.8 - has its own postgres built in). Didn't help.

any ideas would be gratefully received..



Bevil

[ngervasi]

Can you paste the content of both log files (servoy_log.txt and server.log)?

[conor]

Hi
I'm one of Bevil's colleagues. Here are the logfiles:
servoy_log.txt

Code: Select all

2013-09-23 16:52:48,178 ERROR [main] com.servoy.j2db.util.Debug - Cannot start repository:  [ ]
com.servoy.j2db.persistence.RepositoryException: Error checking repository
        at com.servoy.j2db.server.Za.Za.Zb(Za.java:34)
        at com.servoy.j2db.server.Za.Za.<init>(Za.java:1684)
        at com.servoy.j2db.server.Za.Za.<init>(Za.java:706)
        at com.servoy.j2db.server.Za.Zo.Za(Zo.java:8)
        at com.servoy.j2db.server.main.ApplicationServer.main(ApplicationServer.java:686)
Caused by: org.postgresql.util.PSQLException: FATAL: role "DBA" does not exist
        at org.postgresql.core.v3.ConnectionFactoryImpl.readStartupMessages(ConnectionFactoryImpl.java:469)
        at org.postgresql.core.v3.ConnectionFactoryImpl.openConnectionImpl(ConnectionFactoryImpl.java:112)
        at org.postgresql.core.ConnectionFactory.openConnection(ConnectionFactory.java:66)
        at org.postgresql.jdbc2.AbstractJdbc2Connection.<init>(AbstractJdbc2Connection.java:125)
        at org.postgresql.jdbc3.AbstractJdbc3Connection.<init>(AbstractJdbc3Connection.java:30)
        at org.postgresql.jdbc3.Jdbc3Connection.<init>(Jdbc3Connection.java:24)
        at org.postgresql.Driver.makeConnection(Driver.java:393)
        at org.postgresql.Driver.connect(Driver.java:267)
        at org.apache.commons.dbcp.DriverConnectionFactory.createConnection(DriverConnectionFactory.java:38)
        at com.servoy.j2db.datasource.Zp.createConnection(Zp.java:5)
        at com.servoy.j2db.datasource.Ze.createConnection(Ze.java:5)
        at org.apache.commons.dbcp.PoolableConnectionFactory.makeObject(PoolableConnectionFactory.java:582)
        at org.apache.commons.pool.impl.GenericObjectPool.borrowObject(GenericObjectPool.java:1158)
        at org.apache.commons.dbcp.PoolingDataSource.getConnection(PoolingDataSource.java:106)
        at com.servoy.j2db.datasource.Za.getConnection(Za.java:14)
        at com.servoy.j2db.datasource.jmx.ManagedBasicPoolingDataSource.getConnection(ManagedBasicPoolingDataSource.java:34)
        at com.servoy.j2db.server.Za.Zo.getRawConnection(Zo.java:1272)
        at com.servoy.j2db.server.Za.Zo.Zf(Zo.java:644)
        at com.servoy.j2db.server.Za.Za.Zb(Za.java:1625)
        ... 4 more
2013-09-23 16:52:48,207 ERROR [main] com.servoy.j2db.util.Debug - Do note Servoy server does not start any database! [ ]
2013-09-23 17:11:50,172 WARN [Worker-4] com.servoy.j2db.util.Debug - Undocumented scriptable type exposed to JS: com.drmaison.plugin.usermanager.Client. [ ]
2013-09-23 17:11:50,187 WARN [Worker-4] com.servoy.j2db.util.Debug - Undocumented scriptable type exposed to JS: com.drmaison.plugin.usermanager.Server. [ ]
2013-09-23 17:11:50,187 WARN [Worker-4] com.servoy.j2db.util.Debug - Undocumented scriptable type exposed to JS: com.drmaison.plugin.usermanager.DBMapping. [ ]
2013-09-23 17:11:50,188 WARN [Worker-4] com.servoy.j2db.util.Debug - Undocumented scriptable type exposed to JS: com.drmaison.plugin.usermanager.BatchProcessor. [ ]
2013-09-23 17:11:50,188 WARN [Worker-4] com.servoy.j2db.util.Debug - Undocumented scriptable type exposed to JS: com.drmaison.plugin.usermanager.Client. [ ]
2013-09-23 17:11:50,188 WARN [Worker-4] com.servoy.j2db.util.Debug - Undocumented scriptable type exposed to JS: com.drmaison.plugin.usermanager.JSHashMap. [ ]
2013-09-23 17:11:50,188 WARN [Worker-4] com.servoy.j2db.util.Debug - Undocumented scriptable type exposed to JS: com.drmaison.plugin.usermanager.JSServerFile. [ ]
2013-09-23 17:11:50,188 WARN [Worker-4] com.servoy.j2db.util.Debug - Undocumented scriptable type exposed to JS: com.drmaison.plugin.usermanager.JSServerFile. [ ]
2013-09-23 17:11:53,257 ERROR [Worker-9] com.servoy.j2db.server.Za.Zo - Final get connection failure for server repository_server in 1 times [ ]
2013-09-23 17:11:53,264 ERROR [Worker-9] com.servoy.j2db.server.Za.Zo - Final get connection failure for server interiors in 1 times [ ]
2013-09-23 17:11:53,264 ERROR [main] com.servoy.j2db.server.Za.Zo - sql exception in load tables [ ]
org.postgresql.util.PSQLException: FATAL: role "DBA" does not exist
        at org.postgresql.core.v3.ConnectionFactoryImpl.readStartupMessages(ConnectionFactoryImpl.java:469)
        at org.postgresql.core.v3.ConnectionFactoryImpl.openConnectionImpl(ConnectionFactoryImpl.java:112)
        at org.postgresql.core.ConnectionFactory.openConnection(ConnectionFactory.java:66)
        at org.postgresql.jdbc2.AbstractJdbc2Connection.<init>(AbstractJdbc2Connection.java:125)
        at org.postgresql.jdbc3.AbstractJdbc3Connection.<init>(AbstractJdbc3Connection.java:30)
        at org.postgresql.jdbc3.Jdbc3Connection.<init>(Jdbc3Connection.java:24)
        at org.postgresql.Driver.makeConnection(Driver.java:393)
        at org.postgresql.Driver.connect(Driver.java:267)
        at org.apache.commons.dbcp.DriverConnectionFactory.createConnection(DriverConnectionFactory.java:38)
        at com.servoy.j2db.datasource.Zp.createConnection(Zp.java:5)
        at com.servoy.j2db.datasource.Ze.createConnection(Ze.java:5)
        at org.apache.commons.dbcp.PoolableConnectionFactory.makeObject(PoolableConnectionFactory.java:582)
        at org.apache.commons.pool.impl.GenericObjectPool.borrowObject(GenericObjectPool.java:1158)
        at org.apache.commons.dbcp.PoolingDataSource.getConnection(PoolingDataSource.java:106)
        at com.servoy.j2db.datasource.Za.getConnection(Za.java:14)
        at com.servoy.j2db.datasource.jmx.ManagedBasicPoolingDataSource.getConnection(ManagedBasicPoolingDataSource.java:34)
        at com.servoy.j2db.server.Za.Zo.getRawConnection(Zo.java:1272)
        at com.servoy.j2db.server.Za.Zo.Zf(Zo.java:644)
        at com.servoy.j2db.server.Za.Zo.Za(Zo.java:721)
        at com.servoy.j2db.server.Za.Zo.Zk(Zo.java:1044)
        at com.servoy.j2db.server.Za.Zo.Za(Zo.java:869)
        at com.servoy.j2db.server.Za.Zo.getViewNames(Zo.java:214)
        at com.servoy.eclipse.ui.views.solutionexplorer.SolutionExplorerTreeContentProvider.handleServerViewsNode(SolutionExplorerTreeContentProvider.java:837)
        at com.servoy.eclipse.ui.views.solutionexplorer.SolutionExplorerTreeContentProvider.addServersNodeChildren(SolutionExplorerTreeContentProvider.java:824)
        at com.servoy.eclipse.ui.views.solutionexplorer.SolutionExplorerTreeContentProvider.refreshServerList(SolutionExplorerTreeContentProvider.java:2011)
        at com.servoy.eclipse.ui.views.solutionexplorer.SolutionExplorerView$17$1.runInUIThread(SolutionExplorerView.java:1888)
        at org.eclipse.ui.progress.UIJob$1.run(UIJob.java:95)
        at org.eclipse.swt.widgets.RunnableLock.run(RunnableLock.java:35)
        at org.eclipse.swt.widgets.Synchronizer.runAsyncMessages(Synchronizer.java:135)
        at org.eclipse.swt.widgets.Display.runAsyncMessages(Display.java:3938)
        at org.eclipse.swt.widgets.Display.observerProc(Display.java:3525)
        at org.eclipse.swt.internal.cocoa.OS.objc_msgSendSuper(Native Method)
        at org.eclipse.swt.widgets.Display.applicationNextEventMatchingMask(Display.java:4879)
        at org.eclipse.swt.widgets.Display.applicationProc(Display.java:5226)
        at org.eclipse.swt.internal.cocoa.OS.objc_msgSendSuper(Native Method)
        at org.eclipse.swt.widgets.Widget.callSuper(Widget.java:220)
        at org.eclipse.swt.widgets.Widget.mouseDownSuper(Widget.java:1092)
        at org.eclipse.swt.widgets.Tree.mouseDownSuper(Tree.java:2052)
        at org.eclipse.swt.widgets.Widget.mouseDown(Widget.java:1084)
        at org.eclipse.swt.widgets.Control.mouseDown(Control.java:2528)
        at org.eclipse.swt.widgets.Tree.mouseDown(Tree.java:2007)
        at org.eclipse.swt.widgets.Display.windowProc(Display.java:5471)
        at org.eclipse.swt.internal.cocoa.OS.objc_msgSendSuper(Native Method)
        at org.eclipse.swt.widgets.Widget.callSuper(Widget.java:220)
        at org.eclipse.swt.widgets.Widget.windowSendEvent(Widget.java:2095)
        at org.eclipse.swt.widgets.Shell.windowSendEvent(Shell.java:2253)
        at org.eclipse.swt.widgets.Display.windowProc(Display.java:5535)
        at org.eclipse.swt.internal.cocoa.OS.objc_msgSendSuper(Native Method)
        at org.eclipse.swt.widgets.Display.applicationSendEvent(Display.java:4989)
        at org.eclipse.swt.widgets.Display.applicationProc(Display.java:5138)
        at org.eclipse.swt.internal.cocoa.OS.objc_msgSend(Native Method)
        at org.eclipse.swt.internal.cocoa.NSApplication.sendEvent(NSApplication.java:128)
        at org.eclipse.swt.widgets.Display.readAndDispatch(Display.java:3610)
        at org.eclipse.ui.internal.Workbench.runEventLoop(Workbench.java:2701)
        at org.eclipse.ui.internal.Workbench.runUI(Workbench.java:2665)
        at org.eclipse.ui.internal.Workbench.access$4(Workbench.java:2499)
        at org.eclipse.ui.internal.Workbench$7.run(Workbench.java:679)
        at org.eclipse.core.databinding.observable.Realm.runWithDefault(Realm.java:332)
        at org.eclipse.ui.internal.Workbench.createAndRunWorkbench(Workbench.java:668)
        at org.eclipse.ui.PlatformUI.createAndRunWorkbench(PlatformUI.java:149)
        at org.eclipse.ui.internal.ide.application.IDEApplication.start(IDEApplication.java:123)
        at org.eclipse.equinox.internal.app.EclipseAppHandle.run(EclipseAppHandle.java:196)
        at org.eclipse.core.runtime.internal.adaptor.EclipseAppLauncher.runApplication(EclipseAppLauncher.java:110)
        at org.eclipse.core.runtime.internal.adaptor.EclipseAppLauncher.start(EclipseAppLauncher.java:79)
        at org.eclipse.core.runtime.adaptor.EclipseStarter.run(EclipseStarter.java:344)
        at org.eclipse.core.runtime.adaptor.EclipseStarter.run(EclipseStarter.java:179)
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
        at java.lang.reflect.Method.invoke(Method.java:597)
        at org.eclipse.equinox.launcher.Main.invokeFramework(Main.java:622)
        at org.eclipse.equinox.launcher.Main.basicRun(Main.java:577)
        at org.eclipse.equinox.launcher.Main.run(Main.java:1410)
2013-09-23 17:11:53,267 ERROR [Worker-9] com.servoy.j2db.server.Za.Zo - Final get connection failure for server log_server in 1 times [ ]
2013-09-23 17:11:53,281 ERROR [main] com.servoy.j2db.util.Debug - Throwable [ ]
com.servoy.j2db.persistence.RepositoryException: org.postgresql.util.PSQLException: FATAL: role "DBA" does not exist FATAL: role "DBA" does not exist
        at com.servoy.j2db.server.Za.Zo.Za(Zo.java:747)
        at com.servoy.j2db.server.Za.Zo.Zk(Zo.java:1044)
        at com.servoy.j2db.server.Za.Zo.Za(Zo.java:869)
        at com.servoy.j2db.server.Za.Zo.getViewNames(Zo.java:214)
        at com.servoy.eclipse.ui.views.solutionexplorer.SolutionExplorerTreeContentProvider.handleServerViewsNode(SolutionExplorerTreeContentProvider.java:837)
        at com.servoy.eclipse.ui.views.solutionexplorer.SolutionExplorerTreeContentProvider.addServersNodeChildren(SolutionExplorerTreeContentProvider.java:824)
        at com.servoy.eclipse.ui.views.solutionexplorer.SolutionExplorerTreeContentProvider.refreshServerList(SolutionExplorerTreeContentProvider.java:2011)
        at com.servoy.eclipse.ui.views.solutionexplorer.SolutionExplorerView$17$1.runInUIThread(SolutionExplorerView.java:1888)
        at org.eclipse.ui.progress.UIJob$1.run(UIJob.java:95)
        at org.eclipse.swt.widgets.RunnableLock.run(RunnableLock.java:35)
        at org.eclipse.swt.widgets.Synchronizer.runAsyncMessages(Synchronizer.java:135)
        at org.eclipse.swt.widgets.Display.runAsyncMessages(Display.java:3938)
        at org.eclipse.swt.widgets.Display.observerProc(Display.java:3525)
        at org.eclipse.swt.internal.cocoa.OS.objc_msgSendSuper(Native Method)
        at org.eclipse.swt.widgets.Display.applicationNextEventMatchingMask(Display.java:4879)
        at org.eclipse.swt.widgets.Display.applicationProc(Display.java:5226)
        at org.eclipse.swt.internal.cocoa.OS.objc_msgSendSuper(Native Method)
        at org.eclipse.swt.widgets.Widget.callSuper(Widget.java:220)
        at org.eclipse.swt.widgets.Widget.mouseDownSuper(Widget.java:1092)
        at org.eclipse.swt.widgets.Tree.mouseDownSuper(Tree.java:2052)
        at org.eclipse.swt.widgets.Widget.mouseDown(Widget.java:1084)
        at org.eclipse.swt.widgets.Control.mouseDown(Control.java:2528)
        at org.eclipse.swt.widgets.Tree.mouseDown(Tree.java:2007)
        at org.eclipse.swt.widgets.Display.windowProc(Display.java:5471)
        at org.eclipse.swt.internal.cocoa.OS.objc_msgSendSuper(Native Method)
        at org.eclipse.swt.widgets.Widget.callSuper(Widget.java:220)
        at org.eclipse.swt.widgets.Widget.windowSendEvent(Widget.java:2095)
        at org.eclipse.swt.widgets.Shell.windowSendEvent(Shell.java:2253)
        at org.eclipse.swt.widgets.Display.windowProc(Display.java:5535)
        at org.eclipse.swt.internal.cocoa.OS.objc_msgSendSuper(Native Method)
        at org.eclipse.swt.widgets.Display.applicationSendEvent(Display.java:4989)
        at org.eclipse.swt.widgets.Display.applicationProc(Display.java:5138)
        at org.eclipse.swt.internal.cocoa.OS.objc_msgSend(Native Method)
        at org.eclipse.swt.internal.cocoa.NSApplication.sendEvent(NSApplication.java:128)
        at org.eclipse.swt.widgets.Display.readAndDispatch(Display.java:3610)
        at org.eclipse.ui.internal.Workbench.runEventLoop(Workbench.java:2701)
        at org.eclipse.ui.internal.Workbench.runUI(Workbench.java:2665)
        at org.eclipse.ui.internal.Workbench.access$4(Workbench.java:2499)
        at org.eclipse.ui.internal.Workbench$7.run(Workbench.java:679)
        at org.eclipse.core.databinding.observable.Realm.runWithDefault(Realm.java:332)
        at org.eclipse.ui.internal.Workbench.createAndRunWorkbench(Workbench.java:668)
        at org.eclipse.ui.PlatformUI.createAndRunWorkbench(PlatformUI.java:149)
        at org.eclipse.ui.internal.ide.application.IDEApplication.start(IDEApplication.java:123)
        at org.eclipse.equinox.internal.app.EclipseAppHandle.run(EclipseAppHandle.java:196)
        at org.eclipse.core.runtime.internal.adaptor.EclipseAppLauncher.runApplication(EclipseAppLauncher.java:110)
        at org.eclipse.core.runtime.internal.adaptor.EclipseAppLauncher.start(EclipseAppLauncher.java:79)
        at org.eclipse.core.runtime.adaptor.EclipseStarter.run(EclipseStarter.java:344)
        at org.eclipse.core.runtime.adaptor.EclipseStarter.run(EclipseStarter.java:179)
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
        at java.lang.reflect.Method.invoke(Method.java:597)
        at org.eclipse.equinox.launcher.Main.invokeFramework(Main.java:622)
        at org.eclipse.equinox.launcher.Main.basicRun(Main.java:577)
        at org.eclipse.equinox.launcher.Main.run(Main.java:1410)


http://pastebin.com/N6cPSt3w


server.log has nothing particularly relevant. I don't think servoy makes it far enough into a launch to write anything to that logfile. Here's the last bit anyway:

Code: Select all

   

    Sep 18, 2013 4:45:20 PM UserManagerServer INFO: UserManagerPro-Plugin 2.1.6 is registered to Templeton-Smith Ltd. with a site license for 50 concurrent users.
    Sep 18, 2013 4:45:20 PM UserManagerServer DEBUG: Saved license info to server's settings file.
    Sep 18, 2013 4:45:20 PM UserManagerServer DEBUG: Starting dead client check
    Sep 18, 2013 4:45:20 PM UserManagerServer DEBUG: Updated client info for client with ID 4B1497D8-5E04-4942-9744-229DA9BAA684
    Sep 18, 2013 4:45:20 PM UserManagerServer DEBUG: Debug level set to "ALL",
    Sep 18, 2013 4:49:34 PM UserManagerServer DEBUG: Unregistered client with ID 4B1497D8-5E04-4942-9744-229DA9BAA684
    Sep 18, 2013 5:00:02 PM UserManagerServer DEBUG: Starting dead client check
    Sep 18, 2013 5:00:02 PM UserManagerServer INFO: Registered client with ID 7F5B6EC2-8D47-4B9D-9BB6-41ADC1E71360. Server has now 1 of a maxium of 50 registered clients
    Sep 18, 2013 5:00:02 PM UserManagerServer INFO: UserManagerPro-Plugin 2.1.6 is registered to Templeton-Smith Ltd. with a site license for 50 concurrent users.
    Sep 18, 2013 5:00:02 PM UserManagerServer DEBUG: Saved license info to server's settings file.
    Sep 18, 2013 5:00:02 PM UserManagerServer DEBUG: Starting dead client check
    Sep 18, 2013 5:00:02 PM UserManagerServer DEBUG: Updated client info for client with ID 7F5B6EC2-8D47-4B9D-9BB6-41ADC1E71360
    Sep 18, 2013 5:00:02 PM UserManagerServer DEBUG: Debug level set to "ALL",
    Sep 18, 2013 5:00:41 PM UserManagerServer DEBUG: Unregistered client with ID 7F5B6EC2-8D47-4B9D-9BB6-41ADC1E71360
    Sep 19, 2013 10:30:30 AM UserManagerServer DEBUG: Starting dead client check
    Sep 19, 2013 10:30:30 AM UserManagerServer INFO: Registered client with ID 1737FC73-CE00-457B-BCB6-CD0E1E7FDAFD. Server has now 1 of a maxium of 50 registered clients
    Sep 19, 2013 10:30:30 AM UserManagerServer INFO: UserManagerPro-Plugin 2.1.6 is registered to Templeton-Smith Ltd. with a site license for 50 concurrent users.
    Sep 19, 2013 10:30:30 AM UserManagerServer DEBUG: Saved license info to server's settings file.
    Sep 19, 2013 10:30:30 AM UserManagerServer DEBUG: Starting dead client check
    Sep 19, 2013 10:30:30 AM UserManagerServer DEBUG: Updated client info for client with ID 1737FC73-CE00-457B-BCB6-CD0E1E7FDAFD
    Sep 19, 2013 10:30:30 AM UserManagerServer DEBUG: Debug level set to "ALL",
    Sep 19, 2013 10:34:36 AM UserManagerServer DEBUG: Unregistered client with ID 1737FC73-CE00-457B-BCB6-CD0E1E7FDAFD



http://pastebin.com/2ipLcpN1

Cheers
-
C

[ngervasi]

This is your problem:

Code: Select all

2013-09-23 16:52:48,178 ERROR [main] com.servoy.j2db.util.Debug - Cannot start repository:  [ ]
com.servoy.j2db.persistence.RepositoryException: Error checking repository
        at com.servoy.j2db.server.Za.Za.Zb(Za.java:34)
        at com.servoy.j2db.server.Za.Za.<init>(Za.java:1684)
        at com.servoy.j2db.server.Za.Za.<init>(Za.java:706)
        at com.servoy.j2db.server.Za.Zo.Za(Zo.java:8)
        at com.servoy.j2db.server.main.ApplicationServer.main(ApplicationServer.java:686)
Caused by: org.postgresql.util.PSQLException: FATAL: role "DBA" does not exist

The postgres user "DBA" does not exist. You can either create that pg user (and assign correct permissions) or use another existing pg user in your servoy.properties file.

[bevil]

Hi Nicola

Thank you for the reply.

I have seen that error before with other Servoy issues - it usually means that the database has not started. In this case though, I can log into the Postgres database with PGAdmin using DBA as user. The database seems to be running normally, the repository and log databases are there and have data, as does my actual database file.. All is good on the Postgres side.

[ngervasi]

Weird, the error message is very clear: "role "DBA" does not exist". I presume that servoy server is running on the same machine as postgres, can you try to connect using psql from the command line using the same credentials from your servoy.properties file? Maybe the db is not accepting TCP connections from localhost.

[bevil]

I have solved this by changing the postgres connection parameter from 'localhost' to '*'

I don't know why this would have been required through the cloning of the HD, but it solved the problem.. (there is not route from the router to the server on port 5432, so I don't think there is a security risk by allowing this)