Service Stops Straight Away

Aidan Cox7 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 Tananaev7 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 Cox7 years ago

Thanks,

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

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

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

Aidan Cox7 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 Tananaev7 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 Cox7 years ago

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

misosz7 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 Tananaev7 years ago

And how is it related to the topic?

misosz7 years ago

Service Stop working from day to day.

Anton Tananaev7 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.