Possible buffer overflow in 5D Mark III

[a1ex]

Here's some code which causes ERR02 - Card1 cannot be accessed.

Code Select Expand


FILE* f = FIO_CreateFileEx("A:/test.log");
for (int i = 0; i < 1000; i++)
    FIO_WriteFile(f, "Will it blend?\n", 15);
FIO_CloseFile(f);


On the other hand, this code runs fine:

Code Select Expand


for (int i = 0; i < 1000; i++)
{
    FILE* f = FIO_CreateFileEx("A:/test.log");
    FIO_WriteFile(f, "Will it blend?\n", 15);
    FIO_CloseFile(f);
}


What could be wrong?

[g3gg0]

did you check the returncode of FIO_WriteFile?
maybe the write buffer gets full and if writing into a full buffer would cause such behavior?

[a1ex]

Good point, I'll try.

However, even if you put a large delay between FIO_WriteFile calls (let's say 30 seconds), the problem still occurs after roughly 100 lines.

I've discovered this by running bulb ramping, and it was stopping after 116 pictures. At every picture, ML writes a line to BRAMP.LOG. Disabling bulb ramp logging allowed me to get over 500 pictures without any problem.

I'll try this code snippet on all cameras.

[g3gg0]

weird.

there was a "FIO_Flush" or similar somewhere. maybe calling it explicitely helps?
does that happen after an exact amount of bytes or call count?

[a1ex]

Call count (a bit above 100), regardless of buffer length as far as I could tell. I'll also try with more, round buffer sizes (like 1K or 1M) and FIO_Flush.

[a1ex]

Some updates:

- tried the code snippet on 5D2, it was almost instant and without any issue. On 5D3 the LED light stays on for a couple of seconds, then it fails when taking a picture.
- return code is always 15, and there is noticeable slowdown at 130th call.
- 0xff30a6c0 FIO_Flush_maybe accepts a string as argument (a file name), I've expected it to accept a file handle (as returned by FIO_Open or FIO_CreateFile).

[nanomad]

Did you test with one card or with both in?

[a1ex]

Only one CF card (same card in both 5D2 and 5D3).

[nanomad]

Here it looks like a "resource starvation" issue. Maybe on the 5D III writes are somehow quequed to a temporary buffer  to cope with a possible slower write speed on the other card and you're running out of "buffer space". Or, but I'm just speculating here, the way you're calling FIO_WriteFile FIO_OpenFile is actually translated to "Write to both cards" hence the error Card1 cannot be accessed.

[a1ex]

Yes, sounds like some buffer is getting full. What puzzled me is that bulb ramping stopped 4 times after exactly 116 pictures (with ERR02). Log files were correctly saved.

The two cards are A:/ (CF card) and B:/ (SD card), and for now ML uses A:/ .

Maybe there's some extra argument to one of those FIO calls, but I could't figure out from assembler code.

[nanomad]

Well it should be as easy as testing with two cards in. If the error goes away then we know where to look

[a1ex]

Hm, with the SD card it worked fine, and now with the CF card works too. Go figure.

[a1ex]

The bug appeared again. Formatted cards a few times, did not fix anything. Did some more testing.

So, this works fine:

Code Select Expand


    FILE* f = FIO_CreateFileEx("A:/testb.log");
    for (int i = 0; i < 1000; i++)
        FIO_WriteFile(f, YUV422_LV_BUFFER_1, 512);
    FIO_CloseFile(f);


Any number lower than 512 (tried 511, 256, 128, 64, 16, 15) results in failure (ERR02 when taking a picture). 513 is bad, 1024 is OK, 768 is bad.

So, the size argument should be always multiple of 512?!

[a1ex]

The number of FIO_WriteFile calls after which the failure occurs is quite predictable and depends on buffer size.

1: fails at 12290'th call
2: fails at 6146'th call
3: fails at 4098'th call
4: fails at 3074'th call
15: 821
16: 771
64: 194
128: 98
300: 42
511: 25
512: OK for at least 15.000 calls
513: 89
514: 25
768: fails at 60th call
1024: OK for at least 15.000 calls
1025: 13

So, for buffer sizes under 512, the number of calls after which this routine fails is roughly 12290/buf_size.

[a1ex]

I was able to get a debug log via cache hacks by writing it to the SD card.

http://pastebin.com/Tj1VDdJq

The error is not present on my 2GB class 2 SD card (the only one that is still alive), neither with the 32GB CF, but only with the 16GB one.

Adding a bmp_printf in the hijacked DebugMsg seems to solve the problem.

[1%]

On my camera write speed is different depending on the buffer size. Maybe all of this is related.

[a1ex]

Yes, seems to be timing-related. There might be a buffer of size=12288 and the camera crashes when overflowing it.

[a1ex]

I was able to "fix" the error with this code inside the modified DebugMsg from dm-spy:

Code Select Expand


    if (class == 34 && level == 1) // cfDMAWriteBlk
    {
        for (int i = 0; i < 5000; i++)
            asm("nop");
    }


With 4000 NOP's it fails, with 4500 it's hit and miss. With msleep(10) instead of the nop loop, it's also OK.

[dadinio13]

I have a 5D MARK III
I used raw ML for 1 year without ever having had real problem.
Yesterday I shoot a music clip and suddenly I have a memory full error maybe card. I try with another CF and I get the same error. I also try to format the CF in the camera and the computer, I format the SD and reinstall ML above (via macboot command), I try with another new CF card and without card SD so without ML. still the same problem. I even updated the case in 1.2.3 without ML and with just an SD or CF card into the slot and it works without a sudden it works not. I realized that the memory card was not involved. It looks exactly was your problem alex, was it a problem of the crack or the camera?

[a1ex]

I'm not convinced it's the same problem (your description is very vague).

[dadinio13]

no matter what card i use (cf or sd even with a new one) once two i have the "logo" (of canon) with buffer rising in normal record and finally stop recording and show me the err.02.
In raw i get "card maybe full".
I hope you can maybe help me with that because it looks like the same problem.

[a1ex]

If you get err.02, try enabling the card workaround from Prefs menu. It enables the NOP trick described above (which works well for my card).

If you are wondering: the issue was not solved in 1.2.3.

[dadinio13]

So the issue is from Canon and not from ML?
I have a lexar 1000X 32GB and until yesterday everything was working pretty well.
It is possible that this problem occurs like that overnight ?

[a1ex]

The issue I'm talking about in this thread is from Canon.

Yours... I don't know.