WIKIABOUT

FOR TIPS, gUIDES & TUTORIALS

subscribe to our Youtube

GO TO YOUTUBE

4167 questions

4739 answers

3460 comments

0 members

Most popular tags

fmb920 fmb120 configurator fmb640 sms-commands firmware fmb125 fmb001 configuration unlock-code fmb204 bluetooth canbus fmb140 fota-web fmc640 fmc130 firmware-upgrade fmb130 sms
We are migrating to our new platform at https://community.teltonika.lt. Moving forward, you can continue discussions on this new platform. This current platform will be temporarily maintained for reference purposes.

9127: FMB1xx Device disconnects after receiving a command.

+1 vote
1,398 views
in Vehicle tracking by anonymous

Hello,

We have implemented teltonika devices in our car/scooter sharing platform, but from time to time disconnects happen after sending a command. I believe that there is a bug or some strange race condition in the firmware.

  • We're using FMB120, with DOUT1 and DOUT2 controlling ignition and alarm.
  • Latest official firmware (Ver:03.25.05_00 GPS:AXN_5.10_3333 Hw:FMB120 Mod:33 IMEI:XXX Init:2019-8-27 8:54 Uptime:26264 MAC:001E42A36C26 SPC:1(0) AXL:0 OBD:0 BL:1.6 BT:4)
  • DOUTs are configured as high priority on change and generate records when they are toggled.
  • Movement is controlled by accelerometer. Start delay is 1 sec, stop is 10sec. High priority also.
  • Connection is via TCP, our own backend. We have implemented Codec8, Codec8E and Codec12 in an node.js app.
  • TCP ping is 30
  • Records are generated every 30 seconds while moving and every 300 seconds while stopped.

I think I've managed to reproduce this in the lab, here is a log captured from the device:

[2019.08.27 10:39:50]-[NETWORK] data send to socket: 5, successfull! evt sending: enabled, VR socket: 0

>>> Last record sent to the server and confirmed.

[2019.08.27 10:39:55]-[MovDetect] state changed 0 -> 1 (movI:0, movD:0, spd:-1, delay:10)

[2019.08.27 10:39:55]-[MovDetect] Delaying movement 0 -> 1, cnt:1 tmo:3

[2019.08.27 10:39:56]-[MovDetect] Delaying movement 0 -> 1, cnt:2 tmo:3

[2019.08.27 10:39:57]-[REC.SEND.1] Mode: 0/Home on Stop. Time for next periodic data sending: 104 / 600

[2019.08.27 10:39:57]-[MovDetect] Delayed movement state changed:0 -> 1

[2019.08.27 10:39:57]-[REC.GEN] Eventual high priority record saved @ 0x000004F9

>>> High Priority record generated

[2019.08.27 10:39:57]-[REC.GEN] Record Content:

Timestamp: 1566902397000

(cut)

Record Size: 130 Bytes

[2019.08.27 10:39:57]-[REC.GEN] Priority High/Panic! Min Period:600

[2019.08.27 10:39:58]-[ModeChange] Home on Moving profile is updated and reloaded

>>> Move changed

[2019.08.27 10:40:00]-[NETWORK] [IND] received data from socket!

[2019.08.27 10:40:00]-[NETWORK] notification, socket id: 5 has data which must be read!

[2019.08.27 10:40:00]-[NETWORK] VR socket 0, real socket id: 5, attempt automatic data reading for application

[2019.08.27 10:40:00]-[NETWORK] attempting to read data from socked id (real): 5

[2019.08.27 10:40:00]-[NETWORK.PARSER] Parsing data from 0 socket, data len: 34

DUMP DATA START:

00 00 00 00 00 00 00 16 0C 01 05 00 00 00 0E 73 65 74 64 69 67 6F 75 74 20 30 30 0A 0D 01 00 00 2F D7

DUMP DATA END

[2019.08.27 10:40:00]-[NETWORK.PARSER] GPRS CMD Detected!

[2019.08.27 10:40:00]-[GPRS.CMD] CID: 12, NOD: 1, CMD: 5, data len: 14, CRC: 2FD7

[2019.08.27 10:40:00]-[SMS.CMD] DOUT1 NewState:0 Tmo:0 Speed:-1

[2019.08.27 10:40:00]-[IO.APP] Saving DOUT1 State:[0] to Flash

>>> Command received and executed

[2019.08.27 10:40:00]-[REC.GEN] Eventual high priority record saved @ 0x000004FA

[2019.08.27 10:40:00]-[REC.GEN] Record Content:

Timestamp: 1566902400000

Priority : 2

(cut)

Record Size: 130 Bytes

[2019.08.27 10:40:00]-[REC.GEN] Priority High/Panic! Min Period:30

[2019.08.27 10:40:00]-[SMS.CMD] DOUT2 NewState:0 Tmo:0 Speed:-1

[2019.08.27 10:40:00]-[SMS.CMD] DOUT3 NewState:-1 Tmo:0 Speed:-1

[2019.08.27 10:40:00]-[GPRS.CMD] cmd response: DOUT1:0 Timeout:INFINITY DOUT2:0 Timeout:INFINITY

[2019.08.27 10:40:00]-[NETWORK] attempting to send data by VR socked id: 5, data len: 70

[2019.08.27 10:40:00]-[NETWORK] [SEND.DATA.0151] Waiting for socket send result, waiting: 10 sec

[2019.08.27 10:40:00]-[NETWORK] data send to socket: 5, successfull! evt sending: enabled, VR socket: 0

>>> At this point nothing was sent to the server

[2019.08.27 10:40:01]-[REC.SEND.1] WARNING @ 735:No server response to sent records [1], rec sending canceled

>>> Here the device decides that there is no response in time for a record it didn't send and decided to close the socket.

[2019.08.27 10:40:01]-[REC.SEND.1] [CHANGE.STATE.0736] Server: 0, send records => finish

[2019.08.27 10:40:02]-[REC.SEND.1] finish

[2019.08.27 10:40:02]-[NETWORK] attempting to close socked by id: 5

[2019.08.27 10:40:02]-[NETWORK] [SOCKET.CLOSE.0794] Waiting for close result, waiting: 10 sec

[2019.08.27 10:40:02]-[NETWORK] socket closing by id: 5 success! evt sending: enabled

[2019.08.27 10:40:02]-[REC.SEND.1] Caller: 1210, queueing recsend1 task job type: 2/close link

[2019.08.27 10:40:02]-[NETWORK] VR socket 0 closed! Real:5

[2019.08.27 10:40:02]-[REC.SEND.1] socket closing result: 1

[2019.08.27 10:40:02]-[REC.SEND.1] [CHANGE.STATE.0801] Server: 0, finish => finished

[2019.08.27 10:40:02]-[REC.SEND.1] finished

[2019.08.27 10:40:02]-[REC.SEND.1] [CHANGE.STATE.0167] Server: 0, finished => finish

[2019.08.27 10:40:02]-[REC.SEND.1] finish

[2019.08.27 10:40:02]-[REC.SEND.1] [CHANGE.STATE.0801] Server: 0, finish => finished

[2019.08.27 10:40:02]-[REC.SEND.1] finished

After some time device reconnected and sent the records. 

I think a similar issue was described on this topic

(had to remove formatting because of max character limitation, complete log is available here)

1 Answer

0 votes
by anonymous

Hello,

Thank you for your inquiry.

I would suggest to increase data link timeout value. Link: https://wiki.teltonika.lt/view/FMB120_GPRS_settings

Make sure that server sends ACK packets. If there is no ACK packet sent from server, AVL packet will be re-sent on next try when data link will be open. https://wiki.teltonika.lt/view/Codec#Codec_12

Hope this will help. 

Best regards.

by anonymous
Hi,

Server sends ack as soon as packet is received, but the timed out packet was not sent to the server and that's the issue. The packet didn't have any chance to be sent, because codec12 command was received. My timeout is 30 seconds, and from the timeline it's clear that it was not hit.
by anonymous
Nice to see that you found the issue. Thanks!
by anonymous
Well, I found the issue and it's in my first post. I'm searching for a solution.