General 200 Hz logging speed on stock 1G ECU

[basshead]

Hi all!
Posting in this part of the forum since i haven't got 30 newbie posts... How am i gonna get those.

Oh well.

Here's my 200 sample/second logger demo.

Enjoy!

You must be logged in to view this image or video.

200hz 1G Logger - YouTube

 

[basshead]

I wanted to bump this old video so some doubters out there can open their eyes.

200 samples/second means 5 ms intervals. That's fast.


Reffering to this thread:
http://www.dsmtuners.com/forums/newreply.php?do=newreply&p=153382403

It looks like a lot of reading comprehension fail here.

Basshead are you going to start up a new thread of the same type, ardy to DSM, so you won't have to worry about cluttering up this thread with your own information and source ? I seemed to me you didn't want to clutter this particular thread.

BTW the stock 1g logging can't be any faster it's 1ms polling, and it does not reuse sensor data like tunerpro does. You should know this by the link in this thread by the original poster. Tuner pro only appears to be polling fast but only 1 sensor is actually updating per line. If you've upped the baud rate it helps by a very tiny margin, the whole section needs a rewrite.

If I had a ECU I could use my Jim stim from a 454 build, but I don't so I work with what I have.

-"It looks like a lot of reading comprehension fail here." Curtis.

Yes that is why i am going to explain this ONCE more to you and i hope you pay close attention this time.

Say you can parse 10 samples/second.
You will get values 1 to 10 in this example. Clock is at a constant fixed speed as it is in any MCU out there. Simply put it does not wait for anything.

OK;

First example:

Sample		Data		Time		Interval
						
1		1		0,100		0,100
2		2		0,200		0,100
3		3		0,300		0,100
4		4		0,400		0,100
5		5		0,500		0,100
6		6		0,600		0,100
7		7		0,700		0,100
8		8		0,800		0,100
9		9		0,900		0,100
10		10		1,000		0,100

Time for second example, this time the interval is lower (which means we are allowing the MCU some more speed, and less time for this procedure):

Sample		Data		Time		Interval
						
1		1		0,100		0,033
2		1		0,131		0,033
3		1		0,162		0,033
4		2		0,193		0,033
5		2		0,224		0,033
6		2		0,255		0,033
7		3		0,286		0,033
8		3		0,317		0,033
9		3		0,348		0,033
10		4		0,379		0,033
11		4		0,410		0,033
12		4		0,441		0,033
13		5		0,472		0,033
14		5		0,503		0,033
15		5		0,534		0,033
16		6		0,566		0,033
17		6		0,597		0,033
18		6		0,628		0,033
19		7		0,659		0,033
20		7		0,690		0,033
21		7		0,721		0,033
22		8		0,752		0,033
23		8		0,783		0,033
24		8		0,814		0,033
25		9		0,845		0,033
26		9		0,876		0,033
27		9		0,907		0,033
28		10		0,938		0,033
29		10		0,969		0,033
30		10		1,000		0,033

The time is constant, the interval is constant, the sample count is linear, BUT what is happening to the data cells?
Since the MCU has less time to read and output the data the logger software steps in. The logger software notices that the MCU did not respond before timeout or sent back garbage data, therefore we need to duplicate the last valid value for the last request. This is standard procedure and it's called padding.
If the code of the logger just discarded the last valid value before this timeout there would be a empty register and the log would look like a saw tooth.

Do you understand now how it works?

The serial line is never full of data, i.e. there is now buffer or queue, it's emptied the nano second you read it. And the MCU changes state again to get ready to process the next command. This value is then stored inside the reciever, in our example the data logger.
So your claim that TP duplicates data is true, only in the time period of the timeout. When this timeout has expired it's resetting the recieve register. BUT if it recieves valid data TP does NOT duplicate data. I have done experiments up to 10.000 samples/second into TP.
It's all about baud rate, timeouts, etc. No magic. Oh BTW don't use JAVA to build a fast logger...

These logger example are slow. Not even at stock ECU logger speed.
Imagine a 200 samples/second log, that's 5 ms. 1 ms to send, 1 ms to listen, 1 ms to process, 1 ms to reply, 1 ms timeout.
To come even close to 5 ms response time you need to re-write the ECU logger code. As i did.

ECMtunings newer logger does 1000 samples/second. That's pretty amazing!

(But than again my Arduino logger does a minimum of 10.000 samples/second and a medium speed 0f 40.000 samples/second...)


You really need to stop backpedaling and read some books on how these fundamental things work. And get you a proper simulator setup. You cannot write proper code without debugging it. It's like science; verify it or it never happened.
Coding is exact science, id does not give you better results than you put in. Garbage in, garbage out.

Your efforts to do code without a proper simulator setup is at best mediocre, i guess. But since you cannot verify that it's working under all conditions you are potentially putting out harmful software. Keep that in mind.


If there are some more topics you are unsure of, just say so and i will do my best to explain them to you.

 

[hakcenter]

I surely don't appreciate the condescending tone, hopefully that can be removed next time around.

I really wanted to talk about Ardy to ECU but this is the wrong thread.

Can we talk stock before improvements that way there is a foundation of which to build upon?

I've got a log from TP using a stock ecu up to about 3.5 seconds, using intervals 25ms, and a pattern emerges. Every 24 lines only 1 sensor actually gets updated the rest are padded. Over 3.5 seconds that pattern never changed. Do you have a longer log that shows a stock ecu that talks faster without being padded ?

The same seemed to hold true to the old palm logger mmcd. At one point before EOL the developer migrated from polling timeouts to interrupts with que depth ie if data then.

On that same note, it doesn't really matter what language the logging is written in. ECMLink is still using java, and the RXTX library. That library is extremely noisey, and uses a heartbeat to notify changes in que depth, RTS/DTR/CTS etc. And if you're impressed with the speed ECMLink achieves, looks like language doesn't matter at all.

Still talking stock here.

 

[basshead]

The condescending tone is not on intent. You have to keep in mind that English is not my native language. Swedish is.


Back on topic:

This mod i am showing here is on pure stock E931 base code.
Only SwD SD conversion and the logger mod.

Without doing radical re-write of the code the logger is able to do 200 Hz steady.
With some more radical coding it does 300 Hz, and add even more punch it does 400 Hz.

Then there is the total re-write. Well now we are talking a minimum of 1000 Hz.

Thing to keep in mind, always, is that you do not measure 5-6 items at a time to do speed measurments. You do just one single stable signal.
Say you get a moderate speed of 200 Hz on one item, if you need to log 5 items you get 200/5 = 40 samples/second each.

You can never get a padded free log out of any seriously coded logging software since it has a built in time scaler that will scale to the next level once the padding is closing in on one sigle read in a timeout window.
This is because the polling is not time-dependent. It's time linear. This means that the log is time stamped linearly no matter if there is errors recieved or something else goes wrong.
For example the way you did the logging in your software was time-dependent and produced smooth nice lines at set time intervals, or even at non-linear intervals. My guess is that you simply wait for data to show up on the line before time stamping.
That is nice for the eye to watch but it's unusable for a tuner since he does not have proper time scaling. Don't feel bad, there are several other loggers out there doing this.
This topic is actually way beyond the workings of just our ECU and needs to be studied for a time before the Eureka moment comes.

The best loggers have infinite time scaling, of course there are no such thing. But serious dataloggers like TunerPro does a very good job.
And hats of to ECMtuning for using JAVA to accomplish those speeds.
But the heartbeat mode in our ECU is not active during logging. It's either ON or OFF.
Either the ECU is in Serial mode or it's in Heartbeat mode. Those two modes are not compatible with each other.

My basic ADX is available at Marks M's TunerPro site and can be used to verify everything i say.
The timeouts are very dependant on the logger cable hardware. And the logging PC or laptop.
The range of timeouts goes down to as low as 1 ms on good hardware.
Since you have a solid following i will not provide you with any logs since they are so easy to pull. What i can provide is pictures of the logs.


Yes the Arduino logger is a totally different topic.

 

[hakcenter]

I wasn't talking about the ECU heartbeat 0x00.


RXTX java library, uses a 1ms heartbeat to communicate back to java of serial port changes. Including updating the size of the rx / tx que depth, clear to send, data terminal ready, Xor, Xoff, etc.

Without ECMLink chimining in if they are interrupt driven there is only speculation as to what is actually happening.


So the last question on stock, are you including the padding as part of actual data throughput ?

 

[basshead]

Ah ok. Thanks for the heads up on the Java heartbeat.

In my basic 200 Hz mod there is no padding.

There is no need for transmitter side padding, ever. If you ask me.
Padding is done at the recievers side and should never be done at the sending end since it requires processing power.
TP is the reciever in this case.

You really need to drop the hangup on the padding. It is simply neccessary since it provides a software failsafe and buffer.

Tip on how to make stair stepped logs look nice is to smooth it in Excel.

 

[hakcenter]

I'd just like an answer if you're using the padded data as a part of the calculation for data throughput.

Like your top example, is 10/sec, your second one realistically is still only 10/sec since the data never actually changed but on a multiple of 3.

Just looking for that answer so I can carry on talking about what I've done next.

 

[basshead]

In the examples i gave in post #2 a data rate of 10 given.
That is just an example since the real values would have complicated the explanation.
Yes both are exactly 10 s/s. But as you can see the example no. 2 has greater resolution and can potentially hold more datalog points if we speed the data rate up and shows a correctly written data logger.
In example no. 1 we will get data points overwritten in volatile memory even before they end up in the datalog due to the poorly written time base in the logger software.

You simply cannot feed the elephant more bananas that it already has in it's mouth or it's trunk is holding. Excess bananas will get dropped to the ground.

Or a think of a train; example no. 1 has room for 10 passengers, sitting in their seats. if a 11th passenger would show up on the waiting platform the train would simply ignore the 11th passenger and just pass her by.
On the other hand, in example 2 there are 10 passengers with their dedicated seat number but can freely move around in the train and go to the bistro and have a coffee, even if there is a 11th passenger on the waiting platform and the train needs to stop. The train now holds 11 passengers in the same train.
The train is time, in this case 1 second. 1 second now holds 11 passengers. This means a higher data rate.
(This is not condescending i am just trying to explain this as simply as i can considering the language barrier.)


The stock data rate is somewhere around 50 samples/second depending on RPM, MAF and CPU load. (If those are used in the code still.)


I am not using any padding at all. Not in my ECU code or in my ADX.
The padding is done in the data logger software and is neccessary to provide a accurate time base vs data point perspective.

The data flowing through the data wire is a single byte value ranging from $00 to $FF. If a duplicate would show up at the data logger it will trigger a Error and will get discarded but still flag as a Error.
This duplicate will not originate from the ECU since it does not send duplicates.
Data logger software has strict rules to follow, and it does that to 100%. The ECU does not make any mistakes since it has register to flag and confirm.
When Errors occour it's often the result of provocingly low latency/timeout.

To verify how this works is really simple with a digital oscilloscope. You can see the byte value being "built" on the scope as you turn the TPS, O2, MAP or whatever sensor is logged.


So to conclude once and for all. No padding is done on the send side = ECU or data wire.
Padding is done on the recieving side since we have room for more data than was actually recieved.
Padding is good and shows there is headroom. So padding is our friend.
Padding should never be done at speeds faster than the free rolling internal CPU time base. If done above that time base there will be false padding with duplicates of time stamps. And that is just wrong and very bad. So when reading a padded logfile you first need to glance the time stamp column. If it contains duplicates of time (false padding) then the datalog is garbage and can never be trusted.


Edit: Here is a illustration of what i mean. Here you can see 3 decimal places in time and that is not enough to keep up with the data. (Internally in TP the decimal places are higher... But we cannot see them.) If i push the sample rate over 200 now it will still be valid since you can see the sample count stamp is correct and the counter data is not duplicated.
This shows how hard it is to write a really good and accurate logger.


This is a testlog done at 200 hz and the sample is just 1/10 of a second long.

ScannerPro Engine data log recorded on 01/19/2014 11:36:53		
			Time	Real-time
Sample #          	Seconds	counter
1			0.000	134
2			0.000	138
3			0.010	142
4			0.010	146
5			0.020	150
6			0.020	155
7			0.030	159
8			0.030	163
9			0.040	167
10			0.050	171
11			0.050	175
12			0.060	179
13			0.060	183
14			0.069	187
15			0.069	191
16			0.079	196
17			0.079	200
18			0.089	204
19			0.089	208
20			0.099	212
21			0.099	216
22			0.109	220

With some re-write of the ECU code we can make the time window that TP uses even narrower and get it from the 1/100 of a second interval in the above example to 5/1000 of a second in the next example.
In this next example you can see TP starting to scale into the next level so to speak. Here's no padding at all done. Anywhere.
This is since TP detected we are going even faster in the data rate lane (real-time counter now has a resolution of 1-to-1).

ScannerPro Engine data log recorded on 01/19/2014 12:54:14		
			Time		Real-time
Sample #          	Seconds		counter
1			0.000		244
2			0.004		245
3			0.010		246
4			0.015		247
5			0.020		248
6			0.025		249
7			0.029		250
8			0.034		251
9			0.039		252
10			0.044		253
11			0.049		254
12			0.054		255
13			0.058		0
14			0.063		1
15			0.068		2
16			0.073		3
17			0.078		4
18			0.083		5
19			0.088		6
20			0.092		7
21			0.097		8
22			0.102		9

Third and final example is at 2/1000 of second. That's 2 ms. Now we are approaching ECMlink V3 speeds.
In this third example you will also see proof of the dynamic scaling in TunerPro. Going from 22 samples for the examples above, we now get 51 samples for the same 1/10 of a second time period.

ScannerPro Engine data log recorded on 01/19/2014 13:12:55		
			Time		Real-time
Sample #          	Seconds		counter
1			0.000		106
2			0.002		107
3			0.004		108
4			0.007		109
5			0.009		110
6			0.011		111
7			0.012		112
8			0.014		113
9			0.016		114
10			0.018		115
11			0.020		116
12			0.022		117
13			0.024		118
14			0.026		119
15			0.028		120
16			0.030		121
17			0.032		122
18			0.034		123
19			0.036		124
20			0.038		125
21			0.042		126
22			0.044		127
23			0.046		128
24			0.048		129
25			0.050		130
26			0.051		131
27			0.053		132
28			0.055		133
29			0.057		134
30			0.059		135
31			0.061		136
32			0.062		137
33			0.064		138
34			0.066		139
35			0.068		140
36			0.069		141
37			0.071		142
38			0.073		143
39			0.075		144
40			0.077		145
41			0.079		146
42			0.080		147
43			0.082		148
44			0.085		149
45			0.087		150
46			0.089		151
47			0.091		152
48			0.094		153
49			0.096		154
50			0.099		155
51			0.102		156

These three examples are real world logs pulled from the ECU. It clearly demostrates the ingenious code inside TP.
Hats of once more to Mark Mansur for the logger in TunerPro.

 

[hakcenter]

So what have you actually done ? Baud rates by themselves don't seem to achieve these speeds.

Have you altered the serial port interrupt ? That's where I'm headed I just need a bit more debug information on the bit flags to finish what I've written.

I've gotten the port to unload data at over 175/units sec at 1953 baud. Just couldn't turn off the data spam without a hard reset.

 

[basshead]

How is the development coming Curtis?


In the meanwhile i though a post up a older pic i had lying around.
Not a text based post this time since it would have become to big.


Enjoy!

You must be logged in to view this image or video.

For those offended i appologise for the "self promotion" but i feel this is solid info on fast a data logger can get on the stock ECU.

 

[curt-s]

Maybe I missed something in all the text, but has anybody determined that logging at this rate doesn't impede on the ECUs ability to monitor (react to) and manage the system? I'm assuming the same data bus applies to all facilities, so I've wondered since reading this if it's placing the ECU in a hold state while it services requests and ties up the serial line via the ALDL connection.

 

[basshead]

Sordid, that is a legit question actually.

It's like this; for these kind of speeds we can no longer use the standard protocol. For these speeds it's a total re-write.

Simple enough to make most loggers accept it too.

No worries about resources being tied up. I have tried this all the way up to 17000 RPM and there is no mal effects. At that RPM the CPU is very busy, still i have managed to squeeze out some more power.


Edit: On a side note; the stock ALDL code is capable of a turnaround time of 25-20ms. That makes for 40-50 polls/second. In that elapsed time once the same sensor is polled again it will have moved some 14 clicks. Aleast. For one single sensor/item. If logging more items the step size is even bigger.

Edit2: Yes i try all my mods on my GVR4, I gotta be 100% sure about everything before releasing new code. My debugging/simulation bench is well known and is capable to torture the ECU for hours to find errors.

 

[curt-s]

Makes sense to me