JNA Error in Server Log

Andy Barnard2 years ago

Hi,

In April this year, after quite a while running on a Win7 VM with 100% reliability, I updated a server I support for a local transport charity to a Win10 VM, from traccar 4.14 to 4.15 and from MySQL 5.7 to MySQL 8.0. All seems to work for the most part as before, but as of this morning (June 15th) since April we have had two occasions where the tracker system stops responding (no response to web interface, no location updates to database). The Traccar service is running & restarting it doesn't help. Reboot the VM and it all works again.

The second time this happened, I noticed the following in the logs at the time the Traccar service stopped responding:

2022-06-15 01:14:07 ERROR: HikariPool-1 - Exception during pool initialization. - Connection refused: connect - ConnectException (... < DataManager:131 < *:90 < Context:298 < Main:120 < ...)
2022-06-15 01:14:08 ERROR: Main method error - Connection refused: connect - ConnectException (... < DataManager:131 < *:90 < Context:298 < Main:120 < ...)
2022-06-15 01:14:08  WARN: JNA: Callback org.traccar.WindowsService$ServiceMain@4f4c4b1a threw the following exception - Connection refused: connect - ConnectException (... < DataManager:131 < *:90 < Context:298 < Main:120 < ...)

Can anyone point me to the problem?

Regards,
Andy

Anton Tananaev2 years ago

The error indicates that your database was inaccessible.

Andy Barnard2 years ago

Thanks for this, the MySQL database is on the same virtual machine.
If/when the issue happens again I will investigate the health of the MySQL80 service and also see if I can access the database from MySQL workbench.

Andy Barnard2 years ago

Hi,

Well the issue did happen again. Suspiciously close to the monthly Microsoft updates. As the logs (below) indicate an issue accessing the database, I checked the database service (MySQL80) and it is still running. I checked that the database is accessible on the VM using MySQL workbench - the database is still accessible. I checked that the database is accessible from outside the VM by running a small python SQL script to locate the vehicles in the database - the database is still accessible, but the time of the last update on any vehicle is yesterday at 17:47.

So at 17:50, something happened. Checking the update logs, the 2022-07 update (KB5015807) was applied on the 13th July. The last time I had the issue was when the 22-06 update (KB5014699) was applied.

So I conclude that Traccar is unable to access the traccar database after monthly updates from Microsoft. Restarting the VM clears the issue.

The error logs are, this time:

2022-07-13 17:50:51 ERROR: HikariPool-1 - Exception during pool initialization. - Connection refused: connect - ConnectException (... < DataManager:131 < *:90 < Context:298 < Main:120 < ...)
2022-07-13 17:50:51 ERROR: Main method error - Connection refused: connect - ConnectException (... < DataManager:131 < *:90 < Context:298 < Main:120 < ...)
2022-07-13 17:50:51  WARN: JNA: Callback org.traccar.WindowsService$ServiceMain@4f4c4b1a threw the following exception - Connection refused: connect - ConnectException (... < DataManager:131 < *:90 < Context:298 < Main:120 < ...)
Anton Tananaev2 years ago

Did you check a network connection through the workbench? MySQL has several options for connection.

Andy Barnard2 years ago

Yes, I think so. The database connections that worked when Traccar did not were as follows:

  1. SQL Workbench from the machine hosting the VM on which traccar and the database is running is:
    Connection Method: Standard (TCP/IP) to localhost:3306
  2. MySQL connection from a separate machine on the LAN direct to the traccar database (i.e. not using traccar app) using python script as follows
import mysql.connector
traccardb = mysql.connector.connect(
    host="192.168.1.5",
    user="myusername",
    password="mypassword",
    database="mytraccardatabase"
    )
    dbase = traccardb.cursor()
    dbase.execute("SELECT name, positionid FROM tc_devices WHERE groupid='1';")
    vehicleLocations = dbase.fetchall()

I think I have at least two potential solutions to the issue of unplanned downtime which are

  1. Apply MS updates manually and restart
  2. Use an OS other than W10 for the server

Of these, option (2) is my favourite, but the 'IT resilience manager' prefers W10 :-)

I don't know what W10, or traccar client/server, or MySQL80 is doing in detail at the point of updates, but restarting the traccar service on its own does not clear the issue. Which I think is odd. Restarting the machine clears the issue until the next MS monthly update. YMMV.

Anton Tananaev2 years ago

Does the issue happen after a reboot? Maybe the issue is that you don't have service dependencies configured.

Andy Barnard2 years ago

I hadn't thought of that. After a reboot the system works flawlessly until the next W10 monthly update. When the system is failed, like earlier today, both the traccar service and the MySQL80 service are running. Restarting the traccar service &/or the MySQL80 service does not clear the issue. In that failed state, the MySQL80 service appears to respond to queries, but the traccar logs apparently show that it has lost connection to the database.

For service dependencies, I assume you mean that the traccar service should be configured to depend on MySQL80 service? Should it depend on any other services?

I have checked the dependencies on the VM and neither the traccar service or the MySQL80 service have any dependencies at all. Where can I find a list of dependencies? Should traccar depend on a JVM service for example?

Anton Tananaev2 years ago

There's no JVM service. Traccar only needs to depend on MySQL in your case.

Andy Barnard2 years ago

OK, I'll add a dependency on MySQL80 and see if it survives next months updates.... thanks.