Service Stops Straight Away

Aidan Cox 8 years ago

Hi,

Great product. Just tested your Demo and am impressed.
I am just testing setting up a local server.
When i start the service it stops straight away - I have posted the below log files.

I can see this;

INFO|5292/0|Service traccar|18-02-24 21:47:17|Caused by: java.net.BindException: Address already in use: bind

What address is in use, is that the port?

I have tried a few ramdom ports on;
C:\Program Files\Traccar\conf\default.xml

I see no reason for the ones i have tried to be in use.

Thank you kindly for any support

Regards

...
INFO|wrapper|Service traccar|18-02-24 21:39:20|Win service terminated
WARNING|wrapper|Service traccar|18-02-24 21:47:09|YAJSW: yajsw-stable-12.11
WARNING|wrapper|Service traccar|18-02-24 21:47:09|OS   : Windows 10/10.0/amd64
WARNING|wrapper|Service traccar|18-02-24 21:47:09|JVM  : Oracle Corporation/1.8.0_161/C:\Program Files\Java\jre1.8.0_161/64
INFO|wrapper|Service traccar|18-02-24 21:47:10|start delay: 0
INFO|wrapper|Service traccar|18-02-24 21:47:10|started process with pid 5292
INFO|5292/0|Service traccar|18-02-24 21:47:11|[INFO] StandardFileSystemManager - Using "C:\WINDOWS\TEMP\vfs_cache" as temporary files store.
INFO|5292/0|Service traccar|18-02-24 21:47:12|[main] INFO com.zaxxer.hikari.HikariDataSource - HikariPool-1 - Starting...
INFO|5292/0|Service traccar|18-02-24 21:47:12|[main] INFO com.zaxxer.hikari.HikariDataSource - HikariPool-1 - Start completed.
INFO|5292/0|Service traccar|18-02-24 21:47:13|INFO 2/24/18 9:47 PM: liquibase: Clearing database change log checksums
INFO|5292/0|Service traccar|18-02-24 21:47:13|INFO 2/24/18 9:47 PM: liquibase: Successfully acquired change log lock
INFO|5292/0|Service traccar|18-02-24 21:47:13|INFO 2/24/18 9:47 PM: liquibase: Successfully released change log lock
INFO|5292/0|Service traccar|18-02-24 21:47:13|INFO 2/24/18 9:47 PM: liquibase: Successfully acquired change log lock
INFO|5292/0|Service traccar|18-02-24 21:47:15|INFO 2/24/18 9:47 PM: liquibase: Reading from PUBLIC.DATABASECHANGELOG
INFO|5292/0|Service traccar|18-02-24 21:47:16|INFO 2/24/18 9:47 PM: liquibase: Reading from PUBLIC.DATABASECHANGELOG
INFO|5292/0|Service traccar|18-02-24 21:47:16|INFO 2/24/18 9:47 PM: liquibase: ./schema/changelog-master.xml: changelog-3.8::changelog-3.8-dropuniquetoken::author: Change set changelog-3.8::changelog-3.8-dropuniquetoken::author failed, but failOnError was false.  Error: Constraint "UK_USER_TOKEN" not found; SQL statement:
INFO|5292/0|Service traccar|18-02-24 21:47:16|ALTER TABLE PUBLIC.users DROP CONSTRAINT uk_user_token [90057-196] [Failed SQL: ALTER TABLE PUBLIC.users DROP CONSTRAINT uk_user_token]
INFO|5292/0|Service traccar|18-02-24 21:47:16|INFO 2/24/18 9:47 PM: liquibase: Successfully released change log lock
INFO|5292/0|Service traccar|18-02-24 21:47:16|[main] INFO org.eclipse.jetty.util.log - Logging initialized @5716ms
INFO|5292/0|Service traccar|18-02-24 21:47:17|java.lang.reflect.InvocationTargetException
INFO|5292/0|Service traccar|18-02-24 21:47:17|	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
INFO|5292/0|Service traccar|18-02-24 21:47:17|	at sun.reflect.NativeMethodAccessorImpl.invoke(Unknown Source)
INFO|5292/0|Service traccar|18-02-24 21:47:17|	at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
INFO|5292/0|Service traccar|18-02-24 21:47:17|	at java.lang.reflect.Method.invoke(Unknown Source)
INFO|5292/0|Service traccar|18-02-24 21:47:17|	at org.rzo.yajsw.app.WrapperJVMMain.executeMain(WrapperJVMMain.java:60)
INFO|5292/0|Service traccar|18-02-24 21:47:17|	at org.rzo.yajsw.app.WrapperJVMMain.main(WrapperJVMMain.java:43)
INFO|5292/0|Service traccar|18-02-24 21:47:17|Caused by: org.jboss.netty.channel.ChannelException: Failed to bind to: 0.0.0.0/0.0.0.0:5040
INFO|5292/0|Service traccar|18-02-24 21:47:17|	at org.jboss.netty.bootstrap.ServerBootstrap.bind(ServerBootstrap.java:272)
INFO|5292/0|Service traccar|18-02-24 21:47:17|	at org.traccar.TrackerServer.start(TrackerServer.java:117)
INFO|5292/0|Service traccar|18-02-24 21:47:17|	at org.traccar.ServerManager.start(ServerManager.java:81)
INFO|5292/0|Service traccar|18-02-24 21:47:17|	at org.traccar.Main.main(Main.java:38)
INFO|5292/0|Service traccar|18-02-24 21:47:17|	... 6 more
INFO|5292/0|Service traccar|18-02-24 21:47:17|Caused by: java.net.BindException: Address already in use: bind
INFO|5292/0|Service traccar|18-02-24 21:47:17|	at sun.nio.ch.Net.bind0(Native Method)
INFO|5292/0|Service traccar|18-02-24 21:47:17|	at sun.nio.ch.Net.bind(Unknown Source)
INFO|5292/0|Service traccar|18-02-24 21:47:17|	at sun.nio.ch.Net.bind(Unknown Source)
INFO|5292/0|Service traccar|18-02-24 21:47:17|	at sun.nio.ch.ServerSocketChannelImpl.bind(Unknown Source)
INFO|5292/0|Service traccar|18-02-24 21:47:17|	at sun.nio.ch.ServerSocketAdaptor.bind(Unknown Source)
INFO|5292/0|Service traccar|18-02-24 21:47:17|	at org.jboss.netty.channel.socket.nio.NioServerBoss$RegisterTask.run(NioServerBoss.java:193)
INFO|5292/0|Service traccar|18-02-24 21:47:17|	at org.jboss.netty.channel.socket.nio.AbstractNioSelector.processTaskQueue(AbstractNioSelector.java:391)
INFO|5292/0|Service traccar|18-02-24 21:47:17|	at org.jboss.netty.channel.socket.nio.AbstractNioSelector.run(AbstractNioSelector.java:315)
INFO|5292/0|Service traccar|18-02-24 21:47:17|	at org.jboss.netty.channel.socket.nio.NioServerBoss.run(NioServerBoss.java:42)
INFO|5292/0|Service traccar|18-02-24 21:47:17|	at org.jboss.netty.util.ThreadRenamingRunnable.run(ThreadRenamingRunnable.java:108)
INFO|5292/0|Service traccar|18-02-24 21:47:17|	at org.jboss.netty.util.internal.DeadLockProofWorker$1.run(DeadLockProofWorker.java:42)
INFO|5292/0|Service traccar|18-02-24 21:47:17|	at java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)
INFO|5292/0|Service traccar|18-02-24 21:47:17|	at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
INFO|5292/0|Service traccar|18-02-24 21:47:17|	at java.lang.Thread.run(Unknown Source)
INFO|wrapper|Service traccar|18-02-24 21:47:18|calling onStop
INFO|wrapper|Service traccar|18-02-24 21:47:18|Win service stop - timeout: 30000
INFO|wrapper|Service traccar|18-02-24 21:47:18|Win service wrapper.control -> stopping application
INFO|wrapper|Service traccar|18-02-24 21:47:18|Win service stop - after shutdown
INFO|wrapper|Service traccar|18-02-24 21:47:18|Win service stop - before notify
INFO|wrapper|Service traccar|18-02-24 21:47:18|Win service terminated
Anton Tananaev 8 years ago

You have a port conflict with some other process on your system:

Caused by: org.jboss.netty.channel.ChannelException: Failed to bind to: 0.0.0.0/0.0.0.0:5040
Aidan Cox 8 years ago

Thanks,

And i guess that can be changed in the config file for line;

    <entry key='carscop.port'>5040</entry>
Anton Tananaev 8 years ago

Yes, you can change port or just remove the line. This problem has been discussed many times before.

Aidan Cox 8 years ago
INFO|10636/0|Service traccar|18-02-24 22:03:56|Caused by: org.jboss.netty.channel.ChannelException: Failed to bind to: 0.0.0.0/0.0.0.0:5037

Another one in use
Is it normal to have so many ports in use on a default install? I can't say i'm running much on my Windows 10 PC in terms of port using software.

Regards

Anton Tananaev 8 years ago

That's an Android Debug Bridge (adb) port.

Traccar server uses separate port for each protocol, so obviously it needs a lot of them.

Aidan Cox 8 years ago

Fair comment, haden't looked into the port specifics - Thanks.
Your response is fantastic, and help is great.
Regards,
Aidan

misosz 8 years ago

Hi ihave this problem.

[main] INFO com.zaxxer.hikari.HikariDataSource - HikariPool-1 - Starting...
[main] INFO com.zaxxer.hikari.HikariDataSource - HikariPool-1 - Start completed.
INFO 2/25/18 7:27 AM: liquibase: Clearing database change log checksums
INFO 2/25/18 7:27 AM: liquibase: Successfully acquired change log lock
INFO 2/25/18 7:27 AM: liquibase: Successfully released change log lock
INFO 2/25/18 7:27 AM: liquibase: Successfully acquired change log lock
INFO 2/25/18 7:28 AM: liquibase: Reading from MyTraccarDB.DATABASECHANGELOG
INFO 2/25/18 7:28 AM: liquibase: Reading from MyTraccarDB.DATABASECHANGELOG
INFO 2/25/18 7:28 AM: liquibase: ./schema/changelog-master.xml: changelog-3.8::changelog-3.8-dropuniquetoken::author: Change set changelog-3.8::changelog-3.8-dropuniquetoken::author failed, but failOnError was false.  Error: Can't DROP 'uk_user_token'; check that column/key exists [Failed SQL: ALTER TABLE MyTraccarDB.users DROP KEY uk_user_token]
INFO 2/25/18 7:28 AM: liquibase: Successfully released change log lock
[main] WARN com.zaxxer.hikari.pool.ProxyConnection - HikariPool-1 - Connection com.mysql.jdbc.JDBC4Connection@6449f9 marked as broken because of SQLSTATE(08S01), ErrorCode(0)
com.mysql.jdbc.exceptions.jdbc4.CommunicationsException: Communications link failure

The last packet successfully received from the server was 1,385 milliseconds ago.  The last packet sent successfully to the server was 1,374 milliseconds ago.
        at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
        at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62)
        at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
        at java.lang.reflect.Constructor.newInstance(Constructor.java:422)
        at com.mysql.jdbc.Util.handleNewInstance(Util.java:425)
        at com.mysql.jdbc.SQLError.createCommunicationsException(SQLError.java:990)
        at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:3559)
        at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:3459)
        at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3900)
        at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:2527)
        at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:2680)
        at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2484)
        at com.mysql.jdbc.PreparedStatement.executeInternal(PreparedStatement.java:1858)
        at com.mysql.jdbc.PreparedStatement.executeQuery(PreparedStatement.java:1966)
        at com.zaxxer.hikari.pool.ProxyPreparedStatement.executeQuery(ProxyPreparedStatement.java:52)
        at com.zaxxer.hikari.pool.HikariProxyPreparedStatement.executeQuery(HikariProxyPreparedStatement.java)
        at org.traccar.database.QueryBuilder.executeQuery(QueryBuilder.java:421)
        at org.traccar.database.DataManager.getObjects(DataManager.java:445)
        at org.traccar.database.BaseObjectManager.refreshItems(BaseObjectManager.java:58)
        at org.traccar.database.BaseObjectManager.<init>(BaseObjectManager.java:40)
        at org.traccar.database.GroupsManager.<init>(GroupsManager.java:34)
        at org.traccar.Context.init(Context.java:346)
        at org.traccar.Main.main(Main.java:35)
Caused by: java.io.EOFException: Can not read response from server. Expected to read 4 bytes, read 0 bytes before connection was unexpectedly lost.
        at com.mysql.jdbc.MysqlIO.readFully(MysqlIO.java:3011)
        at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:3469)
        ... 16 more
[main] INFO org.eclipse.jetty.util.log - Logging initialized @59675ms
Exception in thread "main" java.lang.NullPointerException
        at org.traccar.database.BaseObjectManager.getAllItems(BaseObjectManager.java:121)
        at org.traccar.database.GroupsManager.getAllItems(GroupsManager.java:60)
        at org.traccar.database.PermissionsManager.refreshDeviceAndGroupPermissions(PermissionsManager.java:104)
        at org.traccar.database.PermissionsManager.<init>(PermissionsManager.java:56)
        at org.traccar.Context.init(Context.java:364)
        at org.traccar.Main.main(Main.java:35)
Anton Tananaev 8 years ago

And how is it related to the topic?

misosz 8 years ago

Service Stop working from day to day.

Anton Tananaev 8 years ago

Sounds like your issue is completely different from the topic and logs are completely different, so please don't comment in this thread.