Error on upgrade to 3.8 on linux - Step by step

nalberto 9 years ago

Hi I tried to upgrade to 3.8 but the web interface won't start.
My previous instance was running 3.7 with MySQL as db.

This is what I did

    cd /opt
    rm traccar -R
    rm traccar.run
    wget https://github.com/tananaev/traccar/releases/download/v3.8/traccar-linux-3.8.zip
    unzip traccar-linux-3.8.zip
    sudo ./traccar.run

    changed the config file traccar/conf/default.xml web.port to 80
    changed the config file traccar/conf/traccar.xml to the mysql credential as per previous config file

    sudo /opt/traccar/bin/startDaemon.sh

    results in "Service traccar started"

When I get to the site on I get a "500 - server error"

Not sure when to look to debug this

Help please

Anton Tananaev 9 years ago

Check both server and wrapper log files for any errors and warnings.

nalberto 9 years ago

Error seems to come from the mysql db setup
If I set it up to use the default h2 driver it works.

wrapper log gives me this when trying to use mysql

INFO|wrapper|Service traccar|16-11-30 06:40:10|posix_spawn pid 4991
INFO|wrapper|Service traccar|16-11-30 06:40:10|started process 4991
INFO|wrapper|Service traccar|16-11-30 06:40:10|started process with pid 4991
INFO|4991/0|Service traccar|16-11-30 06:40:12|[INFO] StandardFileSystemManager - Using "/tmp/vfs_cache" as temporary files store.
INFO|4991/0|Service traccar|16-11-30 06:40:13|[main] INFO com.zaxxer.hikari.HikariDataSource - HikariPool-1 - Started.
INFO|4991/0|Service traccar|16-11-30 06:40:15|Failed to generate a seed from SecureRandom within {} seconds. Not enough entrophy?
INFO|4991/0|Service traccar|16-11-30 06:40:15|3
INFO|4991/0|Service traccar|16-11-30 06:40:17|java.lang.reflect.InvocationTargetException
INFO|4991/0|Service traccar|16-11-30 06:40:17|	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
INFO|4991/0|Service traccar|16-11-30 06:40:17|	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
INFO|4991/0|Service traccar|16-11-30 06:40:17|	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
INFO|4991/0|Service traccar|16-11-30 06:40:17|	at java.lang.reflect.Method.invoke(Method.java:498)
INFO|4991/0|Service traccar|16-11-30 06:40:17|	at org.rzo.yajsw.app.WrapperJVMMain.executeMain(WrapperJVMMain.java:60)
INFO|4991/0|Service traccar|16-11-30 06:40:17|	at org.rzo.yajsw.app.WrapperJVMMain.main(WrapperJVMMain.java:43)
INFO|4991/0|Service traccar|16-11-30 06:40:17|Caused by: com.zaxxer.hikari.pool.HikariPool$PoolInitializationException: Failed to initialize pool: Could not create connection to database server. Attempted reconnect 3 times. Giving up.
INFO|4991/0|Service traccar|16-11-30 06:40:17|	at com.zaxxer.hikari.pool.HikariPool.checkFailFast(HikariPool.java:514)
INFO|4991/0|Service traccar|16-11-30 06:40:17|	at com.zaxxer.hikari.pool.HikariPool.<init>(HikariPool.java:107)
INFO|4991/0|Service traccar|16-11-30 06:40:17|	at com.zaxxer.hikari.HikariDataSource.<init>(HikariDataSource.java:71)
INFO|4991/0|Service traccar|16-11-30 06:40:17|	at org.traccar.database.DataManager.initDatabase(DataManager.java:112)
INFO|4991/0|Service traccar|16-11-30 06:40:17|	at org.traccar.database.DataManager.<init>(DataManager.java:67)
INFO|4991/0|Service traccar|16-11-30 06:40:17|	at org.traccar.Context.init(Context.java:167)
INFO|4991/0|Service traccar|16-11-30 06:40:17|	at org.traccar.Main.main(Main.java:35)
INFO|4991/0|Service traccar|16-11-30 06:40:17|	... 6 more
INFO|4991/0|Service traccar|16-11-30 06:40:17|Caused by: com.mysql.jdbc.exceptions.jdbc4.MySQLNonTransientConnectionException: Could not create connection to database server. Attempted reconnect 3 times. Giving up.
INFO|4991/0|Service traccar|16-11-30 06:40:17|	at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
INFO|4991/0|Service traccar|16-11-30 06:40:17|	at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62)
INFO|4991/0|Service traccar|16-11-30 06:40:17|	at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
INFO|4991/0|Service traccar|16-11-30 06:40:17|	at java.lang.reflect.Constructor.newInstance(Constructor.java:423)
INFO|4991/0|Service traccar|16-11-30 06:40:17|	at com.mysql.jdbc.Util.handleNewInstance(Util.java:425)
INFO|4991/0|Service traccar|16-11-30 06:40:17|	at com.mysql.jdbc.Util.getInstance(Util.java:408)
INFO|4991/0|Service traccar|16-11-30 06:40:17|	at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:918)
INFO|4991/0|Service traccar|16-11-30 06:40:17|	at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:897)
INFO|4991/0|Service traccar|16-11-30 06:40:17|	at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:886)
INFO|4991/0|Service traccar|16-11-30 06:40:17|	at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:860)
INFO|4991/0|Service traccar|16-11-30 06:40:17|	at com.mysql.jdbc.ConnectionImpl.connectWithRetries(ConnectionImpl.java:2163)
INFO|4991/0|Service traccar|16-11-30 06:40:17|	at com.mysql.jdbc.ConnectionImpl.createNewIO(ConnectionImpl.java:2088)
INFO|4991/0|Service traccar|16-11-30 06:40:17|	at com.mysql.jdbc.ConnectionImpl.<init>(ConnectionImpl.java:806)
INFO|4991/0|Service traccar|16-11-30 06:40:17|	at com.mysql.jdbc.JDBC4Connection.<init>(JDBC4Connection.java:47)
INFO|4991/0|Service traccar|16-11-30 06:40:17|	at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
INFO|4991/0|Service traccar|16-11-30 06:40:17|	at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62)
INFO|4991/0|Service traccar|16-11-30 06:40:17|	at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
INFO|4991/0|Service traccar|16-11-30 06:40:17|	at java.lang.reflect.Constructor.newInstance(Constructor.java:423)
INFO|4991/0|Service traccar|16-11-30 06:40:17|	at com.mysql.jdbc.Util.handleNewInstance(Util.java:425)
INFO|4991/0|Service traccar|16-11-30 06:40:17|	at com.mysql.jdbc.ConnectionImpl.getInstance(ConnectionImpl.java:410)
INFO|4991/0|Service traccar|16-11-30 06:40:17|	at com.mysql.jdbc.NonRegisteringDriver.connect(NonRegisteringDriver.java:328)
INFO|4991/0|Service traccar|16-11-30 06:40:17|	at com.zaxxer.hikari.util.DriverDataSource.getConnection(DriverDataSource.java:95)
INFO|4991/0|Service traccar|16-11-30 06:40:17|	at com.zaxxer.hikari.util.DriverDataSource.getConnection(DriverDataSource.java:101)
INFO|4991/0|Service traccar|16-11-30 06:40:17|	at com.zaxxer.hikari.pool.PoolBase.newConnection(PoolBase.java:341)
INFO|4991/0|Service traccar|16-11-30 06:40:17|	at com.zaxxer.hikari.pool.HikariPool.checkFailFast(HikariPool.java:508)
INFO|4991/0|Service traccar|16-11-30 06:40:17|	... 12 more
INFO|4991/0|Service traccar|16-11-30 06:40:17|Caused by: com.mysql.jdbc.exceptions.jdbc4.MySQLSyntaxErrorException: Access denied for user 'webuser'@'localhost' to database 'fleettrac'
INFO|4991/0|Service traccar|16-11-30 06:40:17|	at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
INFO|4991/0|Service traccar|16-11-30 06:40:17|	at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62)
INFO|4991/0|Service traccar|16-11-30 06:40:17|	at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
INFO|4991/0|Service traccar|16-11-30 06:40:17|	at java.lang.reflect.Constructor.newInstance(Constructor.java:423)
INFO|4991/0|Service traccar|16-11-30 06:40:17|	at com.mysql.jdbc.Util.handleNewInstance(Util.java:425)
INFO|4991/0|Service traccar|16-11-30 06:40:17|	at com.mysql.jdbc.Util.getInstance(Util.java:408)
INFO|4991/0|Service traccar|16-11-30 06:40:17|	at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:943)
INFO|4991/0|Service traccar|16-11-30 06:40:17|	at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3970)
INFO|4991/0|Service traccar|16-11-30 06:40:17|	at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3906)
INFO|4991/0|Service traccar|16-11-30 06:40:17|	at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:873)
INFO|4991/0|Service traccar|16-11-30 06:40:17|	at com.mysql.jdbc.MysqlIO.proceedHandshakeWithPluggableAuthentication(MysqlIO.java:1710)
INFO|4991/0|Service traccar|16-11-30 06:40:17|	at com.mysql.jdbc.MysqlIO.doHandshake(MysqlIO.java:1226)
INFO|4991/0|Service traccar|16-11-30 06:40:17|	at com.mysql.jdbc.ConnectionImpl.coreConnect(ConnectionImpl.java:2253)
INFO|4991/0|Service traccar|16-11-30 06:40:17|	at com.mysql.jdbc.ConnectionImpl.connectWithRetries(ConnectionImpl.java:2104)
INFO|4991/0|Service traccar|16-11-30 06:40:17|	... 26 more
INFO|wrapper|Service traccar|16-11-30 06:40:17|waitpid 4991 59136
INFO|wrapper|Service traccar|16-11-30 06:40:17|exit code posix process: 59136 application: 0
Anton Tananaev 9 years ago

Looks like the problem is with database user permissions:

Access denied for user 'webuser'@'localhost' to database 'fleettrac'
nalberto 9 years ago

Yep sorry for that. I can now go on the web interface.

But I cannot edit a device. It returns this error when trying to save device info.
Any idea?

Unrecognized field "phone" (class org.traccar.model.Device), not marked as ignorable (9 known properties: "positionId", "name", "uniqueId", "status", "attributes", "geofenceIds", "groupId", "id", "lastUpdate"]) at [Source: org.glassfish.jersey.message.internal.ReaderInterceptorExecutor$UnCloseableInputStream@18d54b21; line: 1, column: 265] (through reference chain: org.traccar.model.Device["phone"])

I checked the db and the phone field does exist in devices table. So the db has been upgraded.

mysql> show columns from devices;
+------------+---------------+------+-----+---------+----------------+
| Field      | Type          | Null | Key | Default | Extra          |
+------------+---------------+------+-----+---------+----------------+
| id         | int(11)       | NO   | PRI | NULL    | auto_increment |
| name       | varchar(128)  | NO   |     | NULL    |                |
| uniqueid   | varchar(128)  | NO   | UNI | NULL    |                |
| lastupdate | timestamp     | YES  |     | NULL    |                |
| positionid | int(11)       | YES  |     | NULL    |                |
| groupid    | int(11)       | YES  | MUL | NULL    |                |
| attributes | varchar(4000) | YES  |     | NULL    |                |
| phone      | varchar(128)  | YES  |     | NULL    |                |
| model      | varchar(128)  | YES  |     | NULL    |                |
| contact    | varchar(512)  | YES  |     | NULL    |                |
| category   | varchar(128)  | YES  |     | NULL    |                |
+------------+---------------+------+-----+---------+----------------+
11 rows in set (0.00 sec)
nalberto 9 years ago

Ignore my last messsage. I had two instances running on different ports. Now resolved all good. Thanks
Nic