Traccar stops responding

nick_iles9 years ago

Hi Anton

Thanks for the great support. Having got everything integrated between Traccar and OpenGTS, what I am seeing is Traccar stops receiving messages after a few have been passed, the last message not being decoded extract as below:

2015-07-04 15:56:34 INFO: Query not provided: database.updateLatestPosition
2015-07-04 15:58:36 DEBUG: [6C82FA6C: 5007 <- 82.132.217.233] - HEX: 242442343836323130363032323037353133317c4141244750524d432c3135353833342e30302c412c353132332e38393537312c4e2c30303031382e34323636302c572c302e3034392c2c3034303731352c2c2c412a36457c312e37357c312e30337c312e34317c3030303030303030303030307c32303135303730343135353833347c30333639303030307c30303030303030307c34463643333937367c303030307c302e303030307c303031397c384241420d0a
2015-07-04 15:58:36 INFO: device: 862106022075131, time: Sat Jul 04 15:58:34 UTC 2015, lat: 51.398261833333336, lon: -0.30711
2015-07-04 15:58:36 INFO: Query not provided: database.updateLatestPosition
2015-07-04 15:58:57 DEBUG: [6C82FA6C: 5007 <- 82.132.217.233] - HEX: 242442343836323130363032323037353133317c3631244750524d432c3135353835352e30302c412c353132332e38393535392c4e2c30303031382e34323538322c572c302e3032382c2c3034303731352c2c2c412a36427c322e31347c312e33307c312e37307c3030303030303030303030307c32303135303730343135353835357c30333639303030307c30303030303030307c34463643333937367c303030307c302e303030307c303032307c463734330d0a
2015-07-04 15:58:57 INFO: device: 862106022075131, time: Sat Jul 04 15:58:55 UTC 2015, lat: 51.398259833333334, lon: -0.307097
2015-07-04 15:58:57 INFO: Query not provided: database.updateLatestPosition
2015-07-04 16:00:37 DEBUG: [6C82FA6C: 5007 <- 82.132.217.233] - HEX: 242442343836323130363032323037353133317c4141244750524d432c3136303033352e30302c412c353132332e38393435352c4e2c30303031382e34323438322c572c302e3032372c2c3034303731352c2c2c412a36307c312e35367c302e39307c312e32377c3030303030303030303030307c32303135303730343136303033357c30333639303030307c30303030303030307c34463643333937367c303030307c302e303030307c303032317c443732450d0a
2015-07-04 16:00:37 INFO: device: 862106022075131, time: Sat Jul 04 16:00:35 UTC 2015, lat: 51.3982425, lon: -0.30708033333333334
2015-07-04 16:34:28 DEBUG: [F142E7DB: 5007 <- 213.205.232.86] - HEX: 242442343836323130363032323036383431377c4141244750524d432c3136333432342e30302c412c353132332e38393033362c4e2c30303031382e34333434342c572c302e3036302c2c3034303731352c2c2c412a36457c332e31367c312e39307c322e35327c3030303030303030303030307c32303135303730343136333432367c30333834303030307c30303030303030307c30383739303337367c303030307c302e303030307c303030317c334443330d0a

I have checked the logs for Wrapper and also confirmed traccar is still running and it is. Any ideas on where to look?

Nick

nick_iles9 years ago

Just to add, the above is the end of the log, there is no decode line for the last entry. This is with 2 or 3 devices active. Seems to stop after a certain number of messages are sent. Devices are TZone Avl-02 I wonder whether connections are being closed properly?

nick_iles9 years ago

Also now tried it with the iOS client, same behaviour. The server seems to take 7 or 8 data updates then doesn't take any more- nothing recorded in log past the first 7 or 8.

Nick

Anton Tananaev9 years ago

Can I see your config file? Also, what are the specs of your hardware?

nick_iles9 years ago

Box is a virtual server on MS Azure. 768mb ram. Only running traccar and opengts. oS is CEntos 7

Config file follows shortly

nick_iles9 years ago

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

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

<properties>

<!-- SERVER CONFIG -->

<entry key='web.enable'>false</entry>
<entry key='web.port'>8082</entry>
<entry key='web.path'>/opt/traccar/web</entry>

<entry key='geocoder.enable'>true</entry>
<entry key='geocoder.type'>google</entry>

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

<!-- DATABASE CONFIG -->

<entry key='database.driver'>com.mysql.jdbc.Driver</entry>
<entry key='database.url'>jdbc:mysql://localhost:3306/gts?allowMultiQueries=true</entry>
<entry key='database.user'>dbroot</entry>
<entry key='database.password'>xxx</entry>
<entry key='database.selectDevicesAll'>
SELECT imeiNumber AS id, imeiNumber AS uniqueId FROM Device WHERE imeiNumber REGEXP '^[0-9]+$';
</entry>
<entry key='database.insertPosition'>
START TRANSACTION;
UPDATE Device SET lastValidLatitude = :latitude, lastValidLongitude = :longitude, lastGPSTimestamp = UNIX_TIMESTAMP(:time), lastUpdateTime = UNIX_TIMESTAMP(NOW()) WHERE imeiNumber = :deviceID;
SELECT @accountID := accountID, @deviceID := deviceID FROM Device WHERE imeiNumber = :device_id;
INSERT INTO EventData (accountID, deviceID, timestamp, statusCode, latitude, longitude, speedKPH, heading, altitude, rawData, creationTime, address)
VALUES (@accountID, @deviceID, UNIX_TIMESTAMP(:time), 0, :latitude, :longitude, :speed * 1.852, :course, :altitude, '', UNIX_TIMESTAMP(NOW()), :address);
COMMIT;
</entry>

<!-- PROTOCOL CONFIG -->

...

</properties>

Anton Tananaev9 years ago

If you are using Traccar version 3, you need to change ":device_id" to ":deviceId".

Please follow instructions here:
https://www.traccar.org/opengts/

nick_iles9 years ago

made that amendment - thought we had corrected that when we reported the openGTS integration bug the other day. Anyway have run again using ios updating and it has run for approx 11 updates this time finishing:

2015-07-04 22:43:23 INFO: device: 1001, time: Sat Jul 04 22:43:23 UTC 2015, lat: 51.398331666666664, lon: -0.30729999999999996
2015-07-04 22:47:28 DEBUG: [13377688: 5005 <- 94.174.27.186] - HEX: 24504749442c313030312a30300d0a
[scouttrack@scouttrack logs]$ tail tracker-server.log
2015-07-04 22:42:58 INFO: device: 1001, time: Sat Jul 04 22:42:58 UTC 2015, lat: 51.39828, lon: -0.30721166666666666
2015-07-04 22:42:58 INFO: Query not provided: database.updateLatestPosition
2015-07-04 22:43:09 DEBUG: [BB219047: 5005 <- 94.174.27.186] - HEX: 244750524d432c3232343330392e3030302c412c353132332e393032302c4e2c30303031382e343236332c572c302e30302c302e30302c3034303731352c2c2a30300d0a
2015-07-04 22:43:09 DEBUG: [BB219047: 5005 -> 94.174.27.186] - HEX: 4f4b310d0a
2015-07-04 22:43:09 INFO: device: 1001, time: Sat Jul 04 22:43:09 UTC 2015, lat: 51.39836666666667, lon: -0.307105
2015-07-04 22:43:09 INFO: Query not provided: database.updateLatestPosition
2015-07-04 22:43:23 DEBUG: [BB219047: 5005 <- 94.174.27.186] - HEX: 244750524d432c3232343332332e3030302c412c353132332e383939392c4e2c30303031382e343338302c572c302e30302c302e30302c3034303731352c2c2a30300d0a
2015-07-04 22:43:23 DEBUG: [BB219047: 5005 -> 94.174.27.186] - HEX: 4f4b310d0a
2015-07-04 22:43:23 INFO: device: 1001, time: Sat Jul 04 22:43:23 UTC 2015, lat: 51.398331666666664, lon: -0.30729999999999996
2015-07-04 22:47:28 DEBUG: [13377688: 5005 <- 94.174.27.186] - HEX: 24504749442c313030312a30300d0a

Anton Tananaev9 years ago

Try to disable reverse geocoder in the config.

nick_iles9 years ago

made that change to disable geocoder. Testing now. in the meantime i notice in the log that there is not always a 'closing connection' message, see below:

2015-07-04 22:53:55 INFO: device: 1001, time: Sat Jul 04 22:53:55 UTC 2015, lat: 51.39825166666667, lon: -0.30723333333333336
2015-07-04 22:53:55 INFO: Query not provided: database.updateLatestPosition
2015-07-04 22:54:28 DEBUG: [550EB294: 5005 <- 94.174.27.186] - HEX: 244750524d432c3232353432382e3030302c412c353132332e383937372c4e2c30303031382e343332352c572c302e30302c302e30302c3034303731352c2c2a30300d0a
2015-07-04 22:54:28 DEBUG: [550EB294: 5005 -> 94.174.27.186] - HEX: 4f4b310d0a
2015-07-04 22:54:29 INFO: device: 1001, time: Sat Jul 04 22:54:28 UTC 2015, lat: 51.398295, lon: -0.30720833333333336
2015-07-04 22:54:29 INFO: Query not provided: database.updateLatestPosition
2015-07-04 22:54:33 INFO: Closing connection by disconnect
2015-07-04 22:54:37 DEBUG: [A00F2D33: 5005 <- 94.174.27.186] - HEX: 24504749442c313030312a30300d0a
2015-07-04 22:54:37 DEBUG: [A00F2D33: 5005 <- 94.174.27.186] - HEX: 244750524d432c3232353433372e3030302c412c353132332e383937372c4e2c30303031382e343332352c572c302e30302c302e30302c3034303731352c2c2a30300d0a
2015-07-04 22:54:37 DEBUG: [A00F2D33: 5005 -> 94.174.27.186] - HEX: 4f4b310d0a
2015-07-04 22:54:37 INFO: device: 1001, time: Sat Jul 04 22:54:37 UTC 2015, lat: 51.398295, lon: -0.30720833333333336
2015-07-04 22:54:37 INFO: Query not provided: database.updateLatestPosition
2015-07-04 22:55:42 DEBUG: [A00F2D33: 5005 <- 94.174.27.186] - HEX: 244750524d432c3232353534322e3030302c412c353132332e383936302c4e2c30303031382e343334322c572c302e30302c302e30302c3034303731352c2c2a30300d0a
2015-07-04 22:55:42 DEBUG: [A00F2D33: 5005 -> 94.174.27.186] - HEX: 4f4b310d0a
2015-07-04 22:55:42 INFO: device: 1001, time: Sat Jul 04 22:55:42 UTC 2015, lat: 51.398266666666665, lon: -0.30723666666666666
2015-07-04 22:55:42 INFO: Query not provided: database.updateLatestPosition
2015-07-04 22:56:34 DEBUG: [A00F2D33: 5005 <- 94.174.27.186] - HEX: 244750524d432c3232353633342e3030302c412c353132332e383935372c4e2c30303031382e343333312c572c302e30302c302e30302c3034303731352c2c2a30300d0a
2015-07-04 22:56:34 DEBUG: [A00F2D33: 5005 -> 94.174.27.186] - HEX: 4f4b310d0a
2015-07-04 22:56:34 INFO: device: 1001, time: Sat Jul 04 22:56:34 UTC 2015, lat: 51.39826166666667, lon: -0.3072183333333333
2

Anton Tananaev9 years ago

If there is no "closing connection" message, it means the device is still connected to the server.

nick_iles9 years ago

could traccar be running out of 'connections'and if so can this be tweaked? The testing i am doing currently is with the ios client, so easy to control and robust.

nick_iles9 years ago

just tested with geocoder off - same behaviour unfortunately, did about 10 connections this time. Am testing with one device only, the ios client

Anton Tananaev9 years ago

Ten connections shouldn't be a problem. There might be a problem if you have 1000+ connections. In that's the case, the limit is on the OS side, not in Traccar.

nick_iles9 years ago

hmmm - could it be a memory issue? Seems consistently stopping updating after 8-10 device message connections. Am running the v3 latest update.