Mantis Bug Tracker

View Issue Details Jump to Notes ] Print ]
IDProjectCategoryView StatusDate SubmittedLast Update
0000450FirmwareSerial Commspublic2011-11-29 13:222011-12-02 12:17
Reporterdandruczyk 
Assigned Todandruczyk 
PriorityhighSeveritymajorReproducibilityrandom
StatusclosedResolutionno change required 
PlatformOSOS Version
Product Version 
Target VersionFixed in Version 
Summary0000450: Device fails to respond to requests, sometimes for long period (50-150+ attempts)
DescriptionWhen ECU has highspeed streaming enabled, it is much more likely to fail to respond to requests, causing mtx to detect this and re-issue the request until it gets a response. In some cases it needs to reissue an excessive amount, in some cases it took over 150+ times before it got the proper response.

It is much harder to trigger this when highspeed streaming is OFF, but when it's on ( and not disable-able, which is what you keep threatening me with for future versions), it makes the problem much more visible. It tends to take 2-4 tries of the sequence below before you'll get a long running set of retries. binary output and input logs attached. NOTE: these were for a VERY long running period (overnite).
Steps To Reproduce(07:01:12 PM) dandruczyk_home: OK seq of events:
(07:01:12 PM) dandruczyk_home: powerup TA card
(07:01:12 PM) dandruczyk_home: fire up mtx, let it interrogate
(07:01:12 PM) dandruczyk_home: Hard reset ecu via menu,
(07:01:12 PM) dandruczyk_home: reset status counters in menu
(07:01:12 PM) dandruczyk_home: (highspeed streaming is now on due to default on boot)
(07:01:12 PM) dandruczyk_home: within mtx goto vetable tab and click "Get data from ecu" button
(07:01:12 PM) dandruczyk_home: watch terminal window for retries..
(07:02:05 PM) dandruczyk_home: on second attempt it retried 166 times for location ID 263. first attempt only had to retry once, but for 6 different location ID's
(07:02:18 PM) dandruczyk_home: serial HW errors went to 9,
(07:02:36 PM) dandruczyk_home: serial framing errors and serial parity errors went red
TagsNo tags attached.
FirmwareVersion
Issue TypeBug
Risk of Breakagevery low
Attached Fileszip file icon binlogs.zip [^] (61,610 bytes) 2011-11-29 13:22

- Relationships
duplicate of 0000443closeddandruczyk Tunix Weird Issue With Unfound Packets 

-  Notes
(0000753)
dandruczyk (viewer)
2011-11-29 13:28

Sequence of events is correct, however, i had to rerun it as your issue tracker wouldn't accept my binlogs due to being "too large", so I reran it, and hte location ID it ended up looping on was 61444, and it spun for 38 iterations before it got a response.

Serial overruns went up to 2 during this time, and the serial framing errors status went red.

timeout, no packet found in GENERIC_READ queue for sequence 134 (86), locID 61444
Re-issued command sent, seq 135!
timeout, no packet found in GENERIC_READ queue for sequence 135 (87), locID 61444
Re-issued command sent, seq 136!
timeout, no packet found in GENERIC_READ queue for sequence 136 (88), locID 61444
Re-issued command sent, seq 137!
timeout, no packet found in GENERIC_READ queue for sequence 137 (89), locID 61444
Re-issued command sent, seq 138!
timeout, no packet found in GENERIC_READ queue for sequence 138 (8A), locID 61444
Re-issued command sent, seq 139!
timeout, no packet found in GENERIC_READ queue for sequence 139 (8B), locID 61444
Re-issued command sent, seq 140!
timeout, no packet found in GENERIC_READ queue for sequence 140 (8C), locID 61444
Re-issued command sent, seq 141!
timeout, no packet found in GENERIC_READ queue for sequence 141 (8D), locID 61444
Re-issued command sent, seq 142!
timeout, no packet found in GENERIC_READ queue for sequence 142 (8E), locID 61444
Re-issued command sent, seq 143!
timeout, no packet found in GENERIC_READ queue for sequence 143 (8F), locID 61444
Re-issued command sent, seq 144!
timeout, no packet found in GENERIC_READ queue for sequence 144 (90), locID 61444
Re-issued command sent, seq 145!
timeout, no packet found in GENERIC_READ queue for sequence 145 (91), locID 61444
Re-issued command sent, seq 146!
timeout, no packet found in GENERIC_READ queue for sequence 146 (92), locID 61444
Re-issued command sent, seq 147!
timeout, no packet found in GENERIC_READ queue for sequence 147 (93), locID 61444
Re-issued command sent, seq 148!
timeout, no packet found in GENERIC_READ queue for sequence 148 (94), locID 61444
Re-issued command sent, seq 149!
timeout, no packet found in GENERIC_READ queue for sequence 149 (95), locID 61444
Re-issued command sent, seq 150!
timeout, no packet found in GENERIC_READ queue for sequence 150 (96), locID 61444
Re-issued command sent, seq 151!
timeout, no packet found in GENERIC_READ queue for sequence 151 (97), locID 61444
Re-issued command sent, seq 152!
timeout, no packet found in GENERIC_READ queue for sequence 152 (98), locID 61444
Re-issued command sent, seq 153!
timeout, no packet found in GENERIC_READ queue for sequence 153 (99), locID 61444
Re-issued command sent, seq 154!
timeout, no packet found in GENERIC_READ queue for sequence 154 (9A), locID 61444
Re-issued command sent, seq 155!
timeout, no packet found in GENERIC_READ queue for sequence 155 (9B), locID 61444
Re-issued command sent, seq 156!
timeout, no packet found in GENERIC_READ queue for sequence 156 (9C), locID 61444
Re-issued command sent, seq 157!
timeout, no packet found in GENERIC_READ queue for sequence 157 (9D), locID 61444
Re-issued command sent, seq 158!
timeout, no packet found in GENERIC_READ queue for sequence 158 (9E), locID 61444
Re-issued command sent, seq 159!
timeout, no packet found in GENERIC_READ queue for sequence 159 (9F), locID 61444
Re-issued command sent, seq 160!
timeout, no packet found in GENERIC_READ queue for sequence 160 (A0), locID 61444
Re-issued command sent, seq 161!
timeout, no packet found in GENERIC_READ queue for sequence 161 (A1), locID 61444
Re-issued command sent, seq 162!
timeout, no packet found in GENERIC_READ queue for sequence 162 (A2), locID 61444
Re-issued command sent, seq 163!
timeout, no packet found in GENERIC_READ queue for sequence 163 (A3), locID 61444
Re-issued command sent, seq 164!
timeout, no packet found in GENERIC_READ queue for sequence 164 (A4), locID 61444
Re-issued command sent, seq 165!
timeout, no packet found in GENERIC_READ queue for sequence 165 (A5), locID 61444
Re-issued command sent, seq 166!
timeout, no packet found in GENERIC_READ queue for sequence 166 (A6), locID 61444
Re-issued command sent, seq 167!
timeout, no packet found in GENERIC_READ queue for sequence 167 (A7), locID 61444
Re-issued command sent, seq 168!
timeout, no packet found in GENERIC_READ queue for sequence 168 (A8), locID 61444
Re-issued command sent, seq 169!
timeout, no packet found in GENERIC_READ queue for sequence 169 (A9), locID 61444
Re-issued command sent, seq 170!
timeout, no packet found in GENERIC_READ queue for sequence 170 (AA), locID 61444
Re-issued command sent, seq 171!
timeout, no packet found in GENERIC_READ queue for sequence 171 (AB), locID 61444
Re-issued command sent, seq 172!
timeout, no packet found in GENERIC_READ queue for sequence 172 (AC), locID 61444
Re-issued command sent, seq 173!
gui_handlers.c: LEAVE() after stop_realtime
gui_handlers.c: LEAVE() after stop_lv_playback
gui_handlers.c: LEAVE() after stop_datalogging
gui_handlers.c: LEAVE() before burn
gui_handlers.c: LEAVE() after burn
gui_handlers.c: LEAVE() configuration saved
threads.c: thread_dispatcher()
        MegaTunix is closing, Thread exiting !!
gui_handlers.c: LEAVE() after iochannel
User avatar (0000758)
Fred (administrator)
2011-11-29 14:46

0.2.0 does not exist, and thus can't be the product version.
User avatar (0000759)
Fred (administrator)
2011-11-29 14:59

What is the value of the time out used for those requests? I need it to fake MTX connecting without involving MTX. Stats from the attached bin logs are presented below.

From FreeEMS To MTX: 5462 packets, 100% good

General issues :
5515 leading characters were dropped - replies are likely in here, but why are they missing starts? I need to attempt to reproduce independent of MTX.
376 false starts occurred - expected
376 double start bytes occurred - matches above = good = no partial packets between starts.
0 stray part packets occurred - ditto.
0 chars lost from false starts - ditto.

From MTX To FreeEMS: 961 packets, 100% good

General issues :
0 leading characters were dropped
0 false starts occurred
0 double start bytes occurred
0 stray part packets occurred
0 chars lost from false starts

Req/Resp
    Packet of type 0000 / 0 was found 2 times!
    Packet of type 0x0001 / 1 was found 2 times!

    Packet of type 0x0002 / 2 was found 2 times!
    Packet of type 0x0003 / 3 was found 2 times!

    Packet of type 0x000a / 10 was found 1 times! - request hard reset, no reply expected

    Packet of type 0x0104 / 260 was found 120 times!
    Packet of type 0x0105 / 261 was found 76 times! - 44 missing replies, 26 bytes each, inc stop, not including start

    Packet of type 0x0190 / 400 was found 792 times!
    Packet of type 0x0191 / 401 was found 5338 times! - inconclusive streaming included

    Packet of type 0x0194 / 404 was found 1 times!
    Packet of type 0x0195 / 405 was found 1 times!

    Packet of type 0xda5e / 55902 was found 2 times!
    Packet of type 0xda5f / 55903 was found 2 times!

    Packet of type 0xeef0 / 61168 was found 1 times!
    Packet of type 0xeef1 / 61169 was found 1 times!

    Packet of type 0xeef2 / 61170 was found 1 times!
    Packet of type 0xeef3 / 61171 was found 1 times!

    Packet of type 0xeef4 / 61172 was found 1 times!
    Packet of type 0xeef5 / 61173 was found 1 times!

    Packet of type 0xf8e0 / 63712 was found 38 times!
    Packet of type 0xf8e1 / 63713 was found 38 times!
User avatar (0000767)
Fred (administrator)
2011-11-30 13:56

This is a fault in the MTX threading and packet dispatch model. Resolving and assigning, close when MTX is fixed or reopen if you have proof otherwise. Marking duplicate of 0000443 where information and saleae log are attached.


Copyright © 2000 - 2011 MantisBT Group
Powered by Mantis Bugtracker