Something wrong with BBL

[XLR8NSS]

Last night I checked the latest update by scanning/flashing/bbl my truck(E38/T43) That all worked fine. This morning when I got in and started it up there was a SES light on so I checked the DTC's(V2 did this fine also).

There was one for the ECM and one for the TCM. I didn't have anything to write them down with and was in a hurry. I know one of them was P0700 and the other was something strange like UC0730(may not be right). I cleared them which the V2 did fine again.

Before I backed out of the driveway I started recording data and everything looked fine. The drive to work was 44 minutes and when I got there the timer was still counting but, the data was frozen. When I tried to exit logging, the V2 never saved any data in the file. The file was there on the SD card but, it was only 2KB in length which I'm guessing is just from stuff in the file that EFILive uses. No actual data was logged. :(

When I used the BBL last night I just tested it for about a minute and it saved the file fine. I'm not sure how far into the trip today the V2 got messed up since there was no data or time log to look at.

On Monday I will try to log again on the way to work and keep an eye on the unit to see if it messes up again and how long it takes.

Just a heads up on a possible issue.

[XLR8NSS]

Ok, I tried the BBL again this morning on the way to work. I was using a SD card and once again everything was fine after hitting F1 Record Data. Less than 6 minutes into the trip though the data froze on the screen while the timer was still counting. I unplugged everything and went on my way to work.

This afternoon on the way outta work I changed the file system over to internal memory. Again everything was fine. I saved a short file while everything was still reading just to see if it saved anything. It did and I started another log file right after it. Everything appeared to be going fine and then sometime in the trip the data froze on the screen once again. :( Trying to drive and keep track of this stuff is tough though so I don't know exactly when. lol

I rebooted the V2 and selected my ECM again(while driving) but, when I hit record the data froze on the first frame. I also tried unpluggin the V2 for a bit with the same results.

When I got to the house I turned the truck off, unplugged the V2, waited a bit, and tried again, no dice. Data just freezes on the first frame.

When the data freezes and you exit logging it does not save a file but, if you enter logging again it saves a log file from the previous try. The thing is there is no data in the logs.

It doesn't seem anyone else is having this trouble so maybe it is a platform specific problem?

[lakingslayer]

Does it do this when logging to the internal memory of the V2? If not try to refomat your SD card and try again. If the problem is still there try another SD card. Just my suggestions.

[XLR8NSS]

Yes, it does it with the SD card and internal memory both. :(

I have another SD card I will try tomorrow.

[XLR8NSS]

BTW, I also set the low power mode to 200 minutes so that it wouldn't kick in while logging. Wasn't sure what affect it would have so I just "disabled" it.

[lakingslayer]

I tried this on the way home and just so we are clear I'm logging a LLY diesel. I logged a lot of data on the V2 and the data was continuously updating for over 20 minutes. I paused it for a couple minutes and then resumed logging. I then saved the file and started a new one. It seemed to log just fine. I just plugged in the SC card to my computer and at about 3/4 of the way into the file the data just stops and the timer in the bottom of the Scan tool doesn't update the time. It does this on both files I logged. The pause I did shows up in the data log as well as the data it took after I resumed logging up until the counter freezes. Not sure if my issue is related to XLR8NSS's one or not but I thought I'd share since they seem to be similar.

[lakingslayer]

Mine did the same thing XLR8NSS's is doing this morning. I logged my whole trip to work which is about 40 minutes. I even checked it about 3/4 of the way here and it was still updating the display with data. when I parked at work I was going to rev the engine and stop logging to see if the data I pulled off the unit was a complete log and there was just some formatting issues with the data but my V2 data was frozen like XLR8NSS has stated. I hit the pause key and the screen went back to the screen to start logging data and the data screen disappeared. Also I could not start logging data again.

[XLR8NSS]

Well, that is great and sucks all at the same time. :D ;)

Ok, this morning instead of BBL again I lugged the laptop out to try some pass through logging.

I had no issues this morning except for the amount of frames exceeded the set limit under the logging tab in the scan tool. I got about 20 minutes of my 40+ minutes drive logged with no problems.

NOW, on the way home I was going to log again in pass through mode but, when I would hit the button to start recording data on the dashboard page the PIDS would show some bogus(IAT -40, ECT -40, etc) data and lock up. It was just like the V2 in that it would capture one frame of data and lock up. I could not get it to log again even restarting the software, unplugging everything, turning off the truck, etc. It would only capture one frame of bogus data and lock up. The only difference was I was trying to log some DMA spark pids(for E38) that I didn't have selected in the morning.

These are some strange issues.

Paul - Is there anyway to run a log in the backround, while scanning, of what is going on internally to the software/hardware? I don't know of any other way to report this except by just explaining what is going on.

[Blacky]

It certainly sounds like a bug in the FlashScan firmware. I will implement some sort of trace feature inside FlashScan that can track what is happening and hopefully detect the cause of the problem.

I have been adding tracing to the EFILive_Explorer program to help resolve,some drag-drop problems. I have also been adding extra tracing oiptions to the tuning tool software to try and find some Duramax reflashing issues.

I guess its just my week for adding tracing options. Hopefully I will have a trace version ready to track down the problem in a day or two. Definitely before the weekend.

Regards
Paul

[Blacky]

One thing to note, if the filesystem (internal flash or SD Card) fills up while data logging the file will be saved but all data will be lost. Unfortunately that's just the way the FAT file system works.

FlashScan will warn if the target file system is more than 95% full prior to starting a log file.

However, I presume your SD cards anr not filling up. It would take a lot of logging to fill an SD card.

P.S. I have already made several changes to the way data is captured and logged. Specifically the interleaving of receiving OBDII data and writing the data to the log file has been rewritten to make more efficient use of the time between data frame reception. That change may actually be the solution.

Regards
Paul

[XLR8NSS]

SD card definately wasn't filling up, fresh 512MB card(formatted with V2). Maybe a feature to add in the future would be to have the V2 automatically stop logging and save a file if the filesystem is within a set percentage of being full.

Sounds good Paul. I look forward to the update.

[lakingslayer]

I have had zero issues with pass through logging. I logged 42 minutes the other day and all the data is there. I also look forward to the next release to hopefully help with this issue.

[lakingslayer]

Well, that is great and sucks all at the same time. :D ;)

Ok, this morning instead of BBL again I lugged the laptop out to try some pass through logging.

I had no issues this morning except for the amount of frames exceeded the set limit under the logging tab in the scan tool. I got about 20 minutes of my 40+ minutes drive logged with no problems.

NOW, on the way home I was going to log again in pass through mode but, when I would hit the button to start recording data on the dashboard page the PIDS would show some bogus(IAT -40, ECT -40, etc) data and lock up. It was just like the V2 in that it would capture one frame of data and lock up. I could not get it to log again even restarting the software, unplugging everything, turning off the truck, etc. It would only capture one frame of bogus data and lock up. The only difference was I was trying to log some DMA spark pids(for E38) that I didn't have selected in the morning.

These are some strange issues.

Paul - Is there anyway to run a log in the backround, while scanning, of what is going on internally to the software/hardware? I don't know of any other way to report this except by just explaining what is going on.

It's not so bad since I can log pass through mode with the laptop and these days I don't do a whole lot of logging. I have two years worth of logs so I'm about logged out on this truck.

[Blacky]

Maybe a feature to add in the future would be to have the V2 automatically stop logging and save a file if the filesystem is within a set percentage of being full.

I tried that, but the function to return the free space on the volume can take 2-3 seconds depending on the state of the filesystem. That is too long to spend checking between writing frames to the file system.

There are a number of ways to resolve the problem, just none that I have implemented yet.

Regards
Paul

[Highlander]

One useful way would be to read the available space before logging and determine the ammount of time that can be logged in that space and therefore know the limit and save it before you hit the limit..

[Blacky]

One useful way would be to read the available space before logging and determine the ammount of time that can be logged in that space and therefore know the limit and save it before you hit the limit..

That will most likely be the final solution.

Regards
Paul

[lakingslayer]

FWIW I tried just viewing but not logging data this morning on my way to work and the V2 did not lock up at all. It ran for about 45minutes straight.

[XLR8NSS]

The latest firmware 2.05.15 Dec 19 seems to have taken care of this issue. I filled up the internal memory today with a log on the way to work. I will test it out with a SD card tomorrow

[XLR8NSS]

Ahhh crap, I BBLd today with the SD card in and it's still doing this. I tried it on the way to work and the way home.

The frame counter for the first log was stopped around 18000 something but, the timer and PIDS were still updating.

The frame counter on the second log was stopped around 21000 something and again the timer and PIDS were still updating.

Both logs were 40-60 minutes in length. A log file and trace file were saved for both attempts but, no data was in either log file. I am sending both trace files to you Paul to take a look at.

This did not happen yesterday when I logged to the internal memory.

Trace files on the way.

2.05.15 Dec 19

[Blacky]

Thanks for the trace files. I have been able to reproduce the problem. It is being caused by a "failed write" to the SD card. When that happens the BBL code goes into pause mode - i.e. you should see the left green LED flashing. Under normal circumstances, to exit pause mode and return to normal logging you would press the Ok button.

That also explains why nothing appears to get written to the SD card. The "close file" command is not updating the FAT32 entry and probably corrupting the FAT32 file system (in unknown ways). I recommend re-formatting the SD card before trying the firmware that I will release once this bug is fixed.

However, this situation is not normal so pressing Ok will probably not help as the very next frame will fail again - restarting the whole "pause log mode" again.

The "failed write" to the SD card is due to a bug in the FlashScan firmware (not due to any fault in the SD card). I am chasing it down now... it is taking a loooooooong time because I have to wait about 20-30 minutes for the erorr to occur each time I make a change.

Regards
Paul

[Blacky]

I believe this problem is now fixed. Turned out to be a clash on the SPI bus between the thermocouple inputs and the SD card. Both devices were using the same SPI bus but were not synchronizing their access correctly. It was always just a matter of time until the thermocouples transmitted their data at exactly the same time as the SD card was reading/writing data.

It was being "masked" by the auto recovery/retry system in FlashScan's SD card read/write implementation which detects failed read/writes and retries them up to 3 times.

For the error to actually cause the log to fail, the thermocouples had to transmit on the SPI bus at exactly the same time as ALL 3 retries of the same read/write sector.

There was only a small chace of it actually occuring - about 1 in 30,000 but when logging >30,000 frames, it was (eventually) inevitable.

I just got done on an 18Mb (4.5 hour) log with zero read/write failures.

P.S. I don't recommend taking such a long log file, the Scan Tool is pretty slow to display that much info. Not to mention it took 4 minutes and 5 seconds to transfer from the SD card (600Kbps).
Just for comparison, the same file (18Mb) transfered off the SD card in 20 seconds using a PC SD-card slot (7.4Mbps).

Regards
Paul

[XLR8NSS]

Wow, excellent detective work Paul. It's kinda like when you're sitting at a stop light in the turn lane and your watching the blinker of the person in front of you. Everyonce in a while no matter how different the blink timing yours and theirs WILL match up. :Eyecrazy:;) Of course that doesn't cause any catastrophic BBL failures. :muahaha: :D

Hopefully your 4.5 hour logging session was on a planned trip. :cheers:

[Biggsy]

Hopefully your 4.5 hour logging session was on a planned trip. :cheers:

I'm guessing it was a bench test ;)

[joecar]

...It's kinda like when you're sitting at a stop light in the turn lane and your watching the blinker of the person in front of you. Everyonce in a while no matter how different the blink timing yours and theirs WILL match up. :Eyecrazy:;) I can do this all day... it completely captures and facinates all my mental faculties... :cheers::cheers::cheers::cheers:

[Biggsy]

I can do this all day... it completely captures and facinates all my mental faculties... :cheers::cheers::cheers::cheers:
Sh*t, I thought I was the only one!!! :D

[Blacky]

I'm guessing it was a bench test ;)
I let it run overnight on the E38 bench setup. Yes, I only got 4.5 hours sleep last night :(
I'm practising for New Year's Eve :beer:

Paul

[Blacky]

Wow, excellent detective work Paul.
Well, I've got the right tools so it make my job a lot easier. But it was not easy to track down. Probably one of the most devious bugs FlashScan has thrown at me in a long time.

The most devious bug ever in the history of FlashScan was the infamous 7ns signal delay about 18 months ago. I still get nightmares about that. I still can't really get my head around what 7ns is. The best my poor brain can picture is: assume something is travelling at 8 million mph, I was trying to measure the equivalent of how long it took to move 1 inch. (hope I got my metric to imperial conversions correct - now my brain is even more fried).

Regards
Paul

[XLR8NSS]

I'm guessing it was a bench test ;)

Good call, I had not thought about that. :D

[XLR8NSS]

Well, I BBL'd 110000 frames today so I guess this issue is taken care of. :D

[Blacky]

Hey, that just reminded me I have one still logging from last night, just went and checked on it. 322,000 frames, no errors and still counting... :notacrook:

Problem now is the time says -15:-07:-53 :bawl: Probably because it logged over the 12:00 midnight boundary - I don't think I'm taking the date into account when calculating the elapsed time.

Time to fix the time machine, more jigawatts required.

Regards
Paul

[TAQuickness]

Can't go wrong with more jigawatts

[XLR8NSS]

Oh I forgot to say, the counter read 110,000 plus it had a " 0 0" after it. Not sure what that is but, it didn't seem to affect the counter.

It looked like this if that is not clear 110000 0 0 . The two extra 0s never changed.

A few more jigawatts and you could go back in time to fix all these bugs before they ever happen. :eek: :Eyecrazy::D

Also, I still can't log anything when selecting E38 auto.

[Blacky]

Oh I forgot to say, the counter read 110,000 plus it had a " 0 0" after it. Not sure what that is but, it didn't seem to affect the counter.

It looked like this if that is not clear 110000 0 0 . The two extra 0s never changed.

A few more jigawatts and you could go back in time to fix all these bugs before they ever happen. :eek: :Eyecrazy::D

Also, I still can't log anything when selecting E38 auto.

The two zeros are the number of read and write sector errors on the SD card. Previously those would count up at a rate of about 1 or 2 every ten minutes. The SD card read/write routines have a 3 loop retry so if an error occured it would normally recover. The times when it did not recover (and logging failed) was when it failed 3 times in a row.

The reason for the failures was because the thermocouple chips were transmitting every 200ms on the SPI bus (the same SPI bus that the SD card uses) without checking first to see if the SD card was currently reading/writing.

After fixing the thermocouple transmit routines, I added the two error counters to observe that the problem was fixed. I left them there so that you guys can see if any errors were occuring (possibly for other reasons). I will remove them before the official release.

Regards
Paul