Server stops after some time because of locked table

BB6 years ago

Hi.
I'm fighting a little bit to set up Traccar on my Arch Linux server. So far I've manage to start server with MySQL (MariaDB) as a DB.
But after some short period of time server stops itself because of:

Jul 25 13:50:27 SERVERNAME traccar[1310]: Exception in thread "main" java.lang.RuntimeException: liquibase.exception.LockException: Could not acquire change log lock.  Currently locked by SERVERIP (192.168>
Jul 25 13:50:27 SERVERNAME traccar[1310]:         at org.traccar.Main.run(Main.java:152)
Jul 25 13:50:27 SERVERNAME traccar[1310]:         at org.traccar.Main.main(Main.java:104)
Jul 25 13:50:27 SERVERNAME traccar[1310]: Caused by: liquibase.exception.LockException: Could not acquire change log lock.  Currently locked by SERVERIP (SERVERIP) since 7/25/19, 12:42 PM
Jul 25 13:50:27 SERVERNAME traccar[1310]:         at liquibase.lockservice.StandardLockService.waitForLock(StandardLockService.java:230)
Jul 25 13:50:27 SERVERNAME traccar[1310]:         at liquibase.Liquibase.clearCheckSums(Liquibase.java:1442)
Jul 25 13:50:27 SERVERNAME traccar[1310]:         at org.traccar.database.DataManager.initDatabaseSchema(DataManager.java:310)
Jul 25 13:50:27 SERVERNAME traccar[1310]:         at org.traccar.database.DataManager.<init>(DataManager.java:90)
Jul 25 13:50:27 SERVERNAME traccar[1310]:         at org.traccar.Context.init(Context.java:292)
Jul 25 13:50:27 SERVERNAME traccar[1310]:         at org.traccar.Main.run(Main.java:110)
Jul 25 13:50:27 SERVERNAME traccar[1310]:         ... 1 more

And Traccar's shows:

[...]
2019-07-25 13:50:07  INFO: SELECT `LOCKED` FROM traccar.DATABASECHANGELOGLOCK WHERE ID=1
2019-07-25 13:50:07  INFO: Waiting for changelog lock....
2019-07-25 13:50:17  INFO: SELECT `LOCKED` FROM traccar.DATABASECHANGELOGLOCK WHERE ID=1
2019-07-25 13:50:17  INFO: Waiting for changelog lock....
2019-07-25 13:50:27  INFO: SELECT ID,`LOCKED`,LOCKGRANTED,LOCKEDBY FROM traccar.DATABASECHANGELOGLOCK WHERE ID=1
2019-07-25 13:50:27 ERROR: Main method error - Could not acquire change log lock.  Currently locked by SERVERIP (SERVERIP) since 7/25/19, 12:42 PM - LockException (... < DataManager:310 < *:90 < Context:292 < Main:110 < ...)

The connection config:

<entry key='database.driver'>com.mysql.cj.jdbc.Driver</entry>
<entry key='database.url'>jdbc:mysql://localhost:3306/traccar?serverTimezone=UTC&useSSL=false&allowMultiQueries=true&autoReconnect=true&useUnicode=yes&characterEncoding=UTF-8&sessionVariables=sql_mode=''</entry>
<entry key='database.user'>traccar</entry>
<entry key='database.password'>PASSWORD</entry>

User traccar has all the privileges except for GRANT.
I can't pinpoint where the problem is...
As a bonus this is how the server start is loged:

2019-07-25 13:45:24  INFO: HikariPool-1 - Starting...
2019-07-25 13:45:25  INFO: HikariPool-1 - Start completed.
2019-07-25 13:45:27  INFO: Clearing database change log checksums
2019-07-25 13:45:27  INFO: SELECT COUNT(*) FROM traccar.DATABASECHANGELOGLOCK
2019-07-25 13:45:27  INFO: SELECT COUNT(*) FROM traccar.DATABASECHANGELOGLOCK

And there's a lot of SELECT 'LOCKED' FROM traccar.DATABASECHANGELOGLOCK WHERE ID=1 in 10s interval.

BB6 years ago

Ok I did some digging meanwhile and found something about DB being lock for some reason after some errors happened somewhere (yup, very vague). Setting LOCKED=0 in DATABASECHANGELOGLOCK showed that there were probably issues during init DB setup because starting server yield some DB creation issues. For me easiest thing was to drop all tables and run the server again so it would create whatever it needed.
Now it looks like it's alive:

2019-07-25 14:54:58  INFO: Successfully released change log lock
2019-07-25 14:54:58  INFO: Logging initialized @162946ms to org.eclipse.jetty.util.log.Slf4jLog
2019-07-25 14:54:59  INFO: Your platform does not provide complete low-level API for accessing direct buffers reliably. Unless explicitly requested, heap buffer will always be preferred to avoid potential system instability.
2019-07-25 14:55:00  INFO: Operating system name: Linux version: 5.1.9-arch1-1-ARCH architecture: amd64
2019-07-25 14:55:00  INFO: Java runtime name: OpenJDK 64-Bit Server VM vendor: Oracle Corporation version: 11.0.3-ojdkbuild+7
2019-07-25 14:55:00  INFO: Memory limit heap: 942mb non-heap: 0mb
2019-07-25 14:55:00  INFO: Character encoding: UTF-8 charset: UTF-8
2019-07-25 14:55:00  INFO: Version: 4.4
2019-07-25 14:55:00  INFO: Starting server...
2019-07-25 14:55:01  INFO: jetty-9.4.18.v20190429; built: 2019-04-29T20:42:08.989Z; git: e1bc35120a6617ee3df052294e433f3a25ce7097; jvm 11.0.3-ojdkbuild+7
2019-07-25 14:55:01  INFO: Started o.t.w.@5d7f8467{/,null,AVAILABLE}
2019-07-25 14:55:01  INFO: DefaultSessionIdManager workerName=node0
2019-07-25 14:55:01  INFO: No SessionScavenger set, using defaults
2019-07-25 14:55:01  INFO: node0 Scavenging every 660000ms
2019-07-25 14:55:04  INFO: Started o.e.j.s.ServletContextHandler@2336cd91{/,null,AVAILABLE}
2019-07-25 14:55:04  INFO: Started ServerConnector@646c0a67{HTTP/1.1,[http/1.1]}{0.0.0.0:8082}
2019-07-25 14:55:04  INFO: Started @168421ms