New device, gives error

HP Koopman5 years ago

I've configured Traccar to auto add a new device, and send all parameters to a different dataparser (forwarding)

When adding a new device, it did add it to the database, but it did not forward the data because of this error:

2019-01-15 15:33:31  WARN: Automatic device registration error - Duplicate entry '352093088503478' for key 'imei' - MySQLIntegrityConstraintViolationException (... < QueryBuilder:480 < DataManager:458 < BaseObjectManager:90 < ...)

It kept rejecting data because of the error.

This is my config file:

<?xml version='1.0' encoding='UTF-8'?>

<!DOCTYPE properties SYSTEM 'http://java.sun.com/dtd/properties.dtd'>

<properties>
    <!-- Logging aanzetten tijdens development -->

    <entry key='logger.enable'>true</entry>
    <entry key='logger.level'>all</entry>
    <entry key='logger.file'>./logs/tracker-server.log</entry>
    <entry key='commands.queueing'>true</entry>

    <!-- Database Configuratie -->
    <entry key='database.driver'>com.mysql.jdbc.Driver</entry>
    <entry key='database.url'>jdbc:mysql://localhost/tracking?useSSL=false&amp;allowMultiQueries=true&amp;autoReconnect=true&amp;useUnicode=yes&amp;characterEncoding=UTF-8&amp;sessionVariables=sql_mode=''</entry>
    <entry key='database.user'>....</entry>
    <entry key='database.password'>....</entry>
    
    <!-- Onbekende voertuigen niet negeren -->
    <entry key='database.ignoreUnknown'>false</entry>

    <!-- Traccar vraagt voertuigen op uit database -->
       <entry key='database.selectDevices'>SELECT t_imei AS id, t_imei AS uniqueId , name AS name FROM vehicles WHERE t_imei REGEXP '^[0-9]+$';</entry>
       <!-- Indien onbekend, voeg nieuw voertuig toe -->
    <entry key='database.insertDevice'>INSERT INTO vehicles (name, t_imei) VALUES (:uniqueId, :uniqueId)</entry>
       <entry key='database.registerUnknown'>true</entry>
    <!-- Traccar foppen door zelf geen data toe te voegen aan de database -->
    <entry key='database.insertPosition'>SELECT 1</entry>
    

    <!-- PROTOCOL CONFIG -->
    <entry key='teltonika.port'>5027</entry>

    <!-- FORWARDING CONFIG -->
    <entry key='forward.enable'>true</entry>
    <entry key='forward.url'>http://localhost:80/parse/parse.php?imei={uniqueId}&amp;attributes={attributes}&amp;latitude={latitude}&amp;longitude={longitude}&amp;altitude={altitude}&amp;speed={speed}&amp;course={course}&amp;accuracy={accuracy}&amp;status={status}&amp;protocol={protocol}&amp;deviceTime={deviceTime}&amp;fixTime={fixTime}&amp;valid={valid}</entry>
   
    <entry key='server.timeout'>120</entry>
   
</properties>

And this is the full log. I first started the device to configure it, and I added it to the vehicle an hour after that. That's when I got the error;
```
2019-01-15 14:29:21 INFO: [efefcddb] connected
2019-01-15 14:29:22 INFO: [efefcddb: 5027 < IP] HEX: 000f333532303933303838353033343738
2019-01-15 14:29:22 INFO: Automatically registered device 352093088503478
2019-01-15 14:29:22 INFO: [efefcddb: 5027 > IP] HEX: 01
2019-01-15 14:29:22 INFO: Query not provided: database.insertStatistics
2019-01-15 14:29:22 INFO: Query not provided: database.updateDeviceExtended
2019-01-15 14:29:24 INFO: [efefcddb: 5027 < IP] HEX: 000000000000018608030000016851eab02600000000000000000000000000000000000d0003430000440000426042000a9100000000000000009200000000000000009300000000000000009400000000000000009500000000000000009600000000000000009700000000000000009800000000000000009900000000000000009a00000000000000000000016851eaa13900000000000000000000000000000000000d0003430000440000426061000a9100000000000000009200000000000000009300000000000000009400000000000000009500000000000000009600000000000000009700000000000000009800000000000000009900000000000000009a00000000000000000000016851eaa12600000000000000000000000000000000000d0003430000440000426061000a9100000000000000009200000000000000009300000000000000009400000000000000009500000000000000009600000000000000009700000000000000009800000000000000009900000000000000009a00000000000000000300002426
2019-01-15 14:29:24 INFO: [efefcddb: 5027 > IP] HEX: 00000003
2019-01-15 14:29:24 INFO: Query not provided: database.updateDeviceExtended
2019-01-15 14:29:24 INFO: Query not provided: database.updateLatestPosition
2019-01-15 14:29:24 INFO: [efefcddb] id: 352093088503478, time: 2019-01-15 14:29:21, lat: 0.00000, lon: 0.00000, course: 0.0
2019-01-15 14:29:24 INFO: [efefcddb] id: 352093088503478, time: 2019-01-15 14:29:17, lat: 0.00000, lon: 0.00000, course: 0.0
2019-01-15 14:29:24 TRACE: [DEBUG] Released scope instance {0} on thread {1}
2019-01-15 14:29:24 INFO: [efefcddb] id: 352093088503478, time: 2019-01-15 14:29:17, lat: 0.00000, lon: 0.00000, course: 0.0
2019-01-15 14:29:24 TRACE: [DEBUG] Released scope instance {0} on thread {1}
2019-01-15 14:29:24 TRACE: [DEBUG] Released scope instance {0} on thread {1}
2019-01-15 14:29:24 INFO: [efefcddb: 5027 < IP] HEX: 000000000000018608030000016851eaa11200000000000000000000000000000000000d0003430000440000426061000a9100000000000000009200000000000000009300000000000000009400000000000000009500000000000000009600000000000000009700000000000000009800000000000000009900000000000000009a00000000000000000000016851ea2b5600000000000000000000000000000000000d0003430000440000426056000a9100000000000000009200000000000000009300000000000000009400000000000000009500000000000000009600000000000000009700000000000000009800000000000000009900000000000000009a00000000000000000000016851e9dc5b00000000000000000000000000000000000d0003430000440000426052000a9100000000000000009200000000000000009300000000000000009400000000000000009500000000000000009600000000000000009700000000000000009800000000000000009900000000000000009a0000000000000000030000b840
2019-01-15 14:29:24 INFO: [efefcddb: 5027 > IP] HEX: 00000003
2019-01-15 14:29:24 INFO: Query not provided: database.updateDeviceExtended
2019-01-15 14:29:24 INFO: [efefcddb] id: 352093088503478, time: 2019-01-15 14:29:17, lat: 0.00000, lon: 0.00000, course: 0.0
2019-01-15 14:29:24 INFO: [efefcddb] id: 352093088503478, time: 2019-01-15 14:28:47, lat: 0.00000, lon: 0.00000, course: 0.0
2019-01-15 14:29:24 INFO: [efefcddb] id: 352093088503478, time: 2019-01-15 14:28:27, lat: 0.00000, lon: 0.00000, course: 0.0
2019-01-15 14:29:24 TRACE: [DEBUG] Released scope instance {0} on thread {1}
2019-01-15 14:29:24 TRACE: [DEBUG] Released scope instance {0} on thread {1}
2019-01-15 14:29:24 TRACE: [DEBUG] Released scope instance {0} on thread {1}
2019-01-15 14:29:24 INFO: [efefcddb: 5027 < IP] HEX: 000000000000008408010000016851e940f600000000000000000000000000000000000d0003430000440000426062000a9100000000000000009200000000000000009300000000000000009400000000000000009500000000000000009600000000000000009700000000000000009800000000000000009900000000000000009a000000000000000001000043dc
2019-01-15 14:29:24 INFO: [efefcddb: 5027 > IP] HEX: 00000001
2019-01-15 14:29:24 INFO: Query not provided: database.updateDeviceExtended
2019-01-15 14:29:24 INFO: [efefcddb] id: 352093088503478, time: 2019-01-15 14:27:47, lat: 0.00000, lon: 0.00000, course: 0.0
2019-01-15 14:29:24 TRACE: [DEBUG] Released scope instance {0} on thread {1}
2019-01-15 14:29:42 DEBUG: HikariPool-1 - Pool stats (total=10, active=0, idle=10, waiting=0)
2019-01-15 14:29:53 INFO: [efefcddb: 5027 < IP] HEX: 000000000000018608030000016851eb255600000000000000000000000000000000000d000343000044000042605a000a9100000000000000009200000000000000009300000000000000009400000000000000009500000000000000009600000000000000009700000000000000009800000000000000009900000000000000009a00000000000000000000016851eb11ce00000000000000000000000000000000000d0003430000440000426051000a9100000000000000009200000000000000009300000000000000009400000000000000009500000000000000009600000000000000009700000000000000009800000000000000009900000000000000009a00000000000000000000016851eafe4600000000000000000000000000000000000d0003430000440000426052000a9100000000000000009200000000000000009300000000000000009400000000000000009500000000000000009600000000000000009700000000000000009800000000000000009900000000000000009a0000000000000000030000fec2
2019-01-15 14:29:53 INFO: [efefcddb: 5027 > IP] HEX: 00000003
2019-01-15 14:29:53 INFO: Query not provided: database.updateDeviceExtended
2019-01-15 14:29:53 INFO: Query not provided: database.updateLatestPosition
2019-01-15 14:29:53 INFO: [efefcddb] id: 352093088503478, time: 2019-01-15 14:29:51, lat: 0.00000, lon: 0.00000, course: 0.0
2019-01-15 14:29:53 INFO: [efefcddb] id: 352093088503478, time: 2019-01-15 14:29:46, lat: 0.00000, lon: 0.00000, course: 0.0
2019-01-15 14:29:53 INFO: [efefcddb] id: 352093088503478, time: 2019-01-15 14:29:41, lat: 0.00000, lon: 0.00000, course: 0.0
2019-01-15 14:29:53 TRACE: [DEBUG] Released scope instance {0} on thread {1}
2019-01-15 14:29:53 TRACE: [DEBUG] Released scope instance {0} on thread {1}
2019-01-15 14:29:53 TRACE: [DEBUG] Released scope instance {0} on thread {1}
2019-01-15 14:29:53 INFO: [efefcddb: 5027 < IP] HEX: 000000000000018608030000016851eaf30f00000000000000000000000000000000000d000343000044000042606b000a9100000000000000009200000000000000009300000000000000009400000000000000009500000000000000009600000000000000009700000000000000009800000000000000009900000000000000009a00000000000000000000016851eaf2fb00000000000000000000000000000000000d000343000044000042606b000a9100000000000000009200000000000000009300000000000000009400000000000000009500000000000000009600000000000000009700000000000000009800000000000000009900000000000000009a00000000000000000000016851eac3ae00000000000000000000000000000000000d000343000044000042604b000a9100000000000000009200000000000000009300000000000000009400000000000000009500000000000000009600000000000000009700000000000000009800000000000000009900000000000000009a00000000000000000300003f4c
2019-01-15 14:29:53 INFO: [efefcddb: 5027 > IP] HEX: 00000003
2019-01-15 14:29:53 INFO: Query not provided: database.updateDeviceExtended
2019-01-15 14:29:53 INFO: [efefcddb] id: 352093088503478, time: 2019-01-15 14:29:38, lat: 0.00000, lon: 0.00000, course: 0.0
2019-01-15 14:29:53 INFO: [efefcddb] id: 352093088503478, time: 2019-01-15 14:29:38, lat: 0.00000, lon: 0.00000, course: 0.0
2019-01-15 14:29:53 INFO: [efefcddb] id: 352093088503478, time: 2019-01-15 14:29:26, lat: 0.00000, lon: 0.00000, course: 0.0
2019-01-15 14:29:53 TRACE: [DEBUG] Released scope instance {0} on thread {1}
2019-01-15 14:29:53 TRACE: [DEBUG] Released scope instance {0} on thread {1}
2019-01-15 14:29:53 TRACE: [DEBUG] Released scope instance {0} on thread {1}
2019-01-15 14:30:12 DEBUG: HikariPool-1 - Pool stats (total=10, active=0, idle=10, waiting=0)
2019-01-15 14:30:42 DEBUG: HikariPool-1 - Pool stats (total=10, active=0, idle=10, waiting=0)
2019-01-15 14:31:12 DEBUG: HikariPool-1 - Pool stats (total=10, active=0, idle=10, waiting=0)
2019-01-15 14:31:20 DEBUG: HikariPool-1 - Closing connection com.mysql.jdbc.JDBC4Connection@1d051bdd: (connection has passed maxLifetime)
2019-01-15 14:31:20 DEBUG: HikariPool-1 - Added connection com.mysql.jdbc.JDBC4Connection@5a77e630
2019-01-15 14:31:42 DEBUG: HikariPool-1 - Pool stats (total=10, active=0, idle=10, waiting=0)
2019-01-15 14:31:46 DEBUG: HikariPool-1 - Closing connection com.mysql.jdbc.JDBC4Connection@7cbb2f80: (connection has passed maxLifetime)
2019-01-15 14:31:46 DEBUG: HikariPool-1 - Added connection com.mysql.jdbc.JDBC4Connection@53f1031a
2019-01-15 14:31:51 DEBUG: HikariPool-1 - Closing connection com.mysql.jdbc.JDBC4Connection@9cd78e8: (connection has passed maxLifetime)
2019-01-15 14:31:51 DEBUG: HikariPool-1 - Added connection com.mysql.jdbc.JDBC4Connection@79fb4d3e
2019-01-15 14:31:53 INFO: [efefcddb] timed out
2019-01-15 14:31:53 INFO: [efefcddb] disconnected
2019-01-15 14:31:53 INFO: Query not provided: database.updateDeviceExtended

Some time in between

2019-01-15 15:33:29 INFO: [4ec25369] connected
2019-01-15 15:33:31 INFO: [4ec25369: 5027 < IP2] HEX: 000f333532303933303838353033343738
2019-01-15 15:33:31 WARN: Automatic device registration error - Duplicate entry '352093088503478' for key 'imei' - MySQLIntegrityConstraintViolationException (... < QueryBuilder:480 < DataManager:458 < BaseObjectManager:90 < ...)
2019-01-15 15:33:31 INFO: [4ec25369: 5027 > IP2] HEX: 00
2019-01-15 15:33:32 INFO: [4ec25369] disconnected
2019-01-15 15:33:42 DEBUG: HikariPool-1 - Pool stats (total=10, active=0, idle=10, waiting=0)
2019-01-15 15:33:59 DEBUG: HikariPool-1 - Closing connection com.mysql.jdbc.JDBC4Connection@750c848c: (connection has passed maxLifetime)
2019-01-15 15:33:59 DEBUG: HikariPool-1 - Added connection com.mysql.jdbc.JDBC4Connection@21a7fbb0
2019-01-15 15:34:12 DEBUG: HikariPool-1 - Pool stats (total=10, active=0, idle=10, waiting=0)
2019-01-15 15:34:35 INFO: [dfea5e86] connected
2019-01-15 15:34:36 INFO: [dfea5e86: 5027 < IP2] HEX: 000f333532303933303838353033343738
2019-01-15 15:34:36 WARN: Automatic device registration error - Duplicate entry '352093088503478' for key 'imei' - MySQLIntegrityConstraintViolationException (... < QueryBuilder:480 < DataManager:458 < BaseObjectManager:90 < ...)
2019-01-15 15:34:36 INFO: [dfea5e86: 5027 > IP2] HEX: 00```

Anton Tananaev5 years ago

I don't see how that is possible, unless you have two devices with same id reporting at the same time.

HP Koopman5 years ago

Yeah it seemed weird to me too. Is it because the device changed it's IP address?
It absolutely wasn't 2 devices with the same id, as I am only using one device right now.
Rebooting the server fixed the problem, maybe it doesn't check for all vehicles every time?

HP Koopman5 years ago

I need a follow up on this, it has happened again today. The server response >>00 to the device and the device stops sending.
I get duplicate entry error again, but when I used this device last week, it was working (it connected for the first time, was added to database, and started sending data)
When I try today, the same device gives error duplicate entry.

When I restart the server it accepts the device. Where does it go wrong?

Alper5 years ago

It says duplicate entry lol. You have registered same device twice

Anton Tananaev5 years ago

Alper, you should probably read thread more carefully. We are discussing a problem with auto-registration here.