HM01B0 PIO driver desync

[sfe-SparkFro]

The HM01B0 PIO driver appears to have a desync issue, where bits and/or bytes are lost in the datastream, resulting in corrupted images.

As a test, I pointed the camera at the following test image:

Sometimes the frame is mostly fine, but the top and/or bottom are corrupted:

Sometimes there are weird color shifts:

Much of the time, there is a "static" appearance:

Sometimes all of these artifacts appear several times in a single image (this also has a significant shift in the color wheel's position to the left):

I suspect this is caused by a desync with the pixel stream from the camera. I'm really not sure why this would be, because the driver uses the PIO and DMA with almost zero CPU input except for the vsync IRQ (I believe this finishes in ~100us from previous testing). It's especially bizarre, because I have some test code in Arduino that sets up the PIO and DMA in almost exactly the same way, and it works totally fine there.

The images above were captured by triggering the camera one frame at a time, so there shouldn't be any issues with the same buffer getting overwritten or anything like that.

[sfe-SparkFro]

Debug code:

# Assuming `camera` and `display` are set up by boot.py
import cv2
import time
from machine import Pin

# Open camera
camera.open()

# Set camera to standby mode
camera.writeRegister(camera.MODE_SELECT, camera.HIMAX_MODE_STANDBY)

# Set nframes to 1 so we can trigger 1 frame at a time
camera.writeRegister(camera.PMU_AUTOSLEEP_FRAMECNT, 1)

# Disable vsync IRQ, we'll run it manually later
Pin(camera.pin_vsync).irq(handler=None)

def trigger():
    # Call the vsync handler to be ready for the next frame
    camera._vsync_handler()

    print("DMA count before trigger:", camera.dma.count)
    
    # Trigger 1 frame from the camera
    camera.writeRegister(camera.MODE_SELECT, camera.HIMAX_MODE_STREAMING_NFRAMES)

    # Wait for the frame to be ready
    time.sleep(0.1)

    print("DMA count after trigger:", camera.dma.count)

    # Read and display the frame
    success, frame = camera.read()
    cv2.imshow(display, frame)

def saveFrame(filename):
    # Save the current frame to a file
    success, frame = camera.read()
    if success:
        cv2.imwrite(filename, frame)

while True:
    trigger()

    print("Press 's' to save the frame, 'q' to quit, or any other key to continue.")
    key = cv2.waitKey(0)
    if key == ord('s'):
        filename = input("Enter filename to save the frame: ")
        saveFrame(filename)
    elif key == ord('q'):
        break

Running the code after a hard reset, slowly iterating frame by frame looks good:

DMA count before trigger: 79056
DMA count after trigger: 0
Press 's' to save the frame, 'q' to quit, or any other key to continue.
DMA count before trigger: 79056
DMA count after trigger: 0
Press 's' to save the frame, 'q' to quit, or any other key to continue.
DMA count before trigger: 79056
DMA count after trigger: 0
Press 's' to save the frame, 'q' to quit, or any other key to continue.
Enter filename to save the frame: sd/1.png

Pressing 4 keys simultaneously to trigger 4 frames in rapid succession, eventually causes some data to be missed, as indicated by DMA count after trigger: 0 and the corrupted image:

DMA count before trigger: 79056
DMA count after trigger: 0
Press 's' to save the frame, 'q' to quit, or any other key to continue.
DMA count before trigger: 79056
DMA count after trigger: 1
Press 's' to save the frame, 'q' to quit, or any other key to continue.
DMA count before trigger: 79056
DMA count after trigger: 0
Press 's' to save the frame, 'q' to quit, or any other key to continue.
DMA count before trigger: 79056
DMA count after trigger: 0
Press 's' to save the frame, 'q' to quit, or any other key to continue.
Enter filename to save the frame: sd/2.png

All subsequent frames look the same way, even when iterating slowly. Pressing 4 keys simultaneously again, eventually causes some data to be missed in the same way, resulting in a different image (and subsequent images look the same way):

DMA count before trigger: 79056
DMA count after trigger: 12
Press 's' to save the frame, 'q' to quit, or any other key to continue.
DMA count before trigger: 79056
DMA count after trigger: 0
Press 's' to save the frame, 'q' to quit, or any other key to continue.
DMA count before trigger: 79056
DMA count after trigger: 0
Press 's' to save the frame, 'q' to quit, or any other key to continue.
DMA count before trigger: 79056
DMA count after trigger: 0
Press 's' to save the frame, 'q' to quit, or any other key to continue.
Enter filename to save the frame: sd/3.png

[sfe-SparkFro]

I wonder if the problem is the PIO state machine just misses a few (or several) bits, so its FIFO buffer has a few bits already shifted into it before the next frame starts, resulting in the whole frame being offset by a few bits. Will see about trying to ensure the PIO FIFO is properly cleared between frames

[sfe-SparkFro]

Yep, the ISR was not getting cleared. Improved with c02bd1f, so if a desync occurs, then subsequent frames are no longer affected.

However, desyncs still occur. Given that the ISR has extra bits in it after a desync, that indicates the root problem is with the PIO desyncing, and probably not the DMA. I wonder if the PIO clock source is set to the peripheral clock (48MHz, I think) instead of the system clock (150MHz). Since the camera outputs at 24MHz, then a slight variation in clock frequencies could cause the PIO state machine to miss some bits here and there.

[sfe-SparkFro]

I wonder if the PIO clock source is set to the peripheral clock (48MHz, I think) instead of the system clock (150MHz). Since the camera outputs at 24MHz, then a slight variation in clock frequencies could cause the PIO state machine to miss some bits here and there.

Actually, that's countered by the fact that running the debug code above works fine when slowly iterating through frames. It only seems to happen when frames come in quickly. Perhaps the vsync handler isn't running soon enough? But the desync clearly occurs in the middle of the frame, not the start. Maybe it's just relatively rare, but common enough to be observed frequently at 30 fps?

[sfe-SparkFro]

Nope, it's not a rare thing, nor does it appear to be a speed thing. Seems to be an issue with the vsync pin. New debug code:

# Assuming `camera` and `display` are set up by boot.py
import cv2
import time
from machine import Pin

# Open camera
camera.open()

# Set camera to standby mode
camera.writeRegister(camera.MODE_SELECT, camera.HIMAX_MODE_STANDBY)

# Set nframes to 1 so we can trigger 1 frame at a time
camera.writeRegister(camera.PMU_AUTOSLEEP_FRAMECNT, 1)

# Disable vsync IRQ, we'll run it manually later
Pin(camera.pin_vsync).irq(handler=None)

def trigger():
    # Call the vsync handler to be ready for the next frame
    camera._vsync_handler()

    # Trigger 1 frame from the camera
    camera.writeRegister(camera.MODE_SELECT, camera.HIMAX_MODE_STREAMING_NFRAMES)

    # Wait for falling edge of vsync
    while Pin(camera.pin_vsync).value() == 0:
        pass
    while Pin(camera.pin_vsync).value() == 1:
        pass
    
    # Delay to ensure the frame is ready
    time.sleep(0.1)

    # Read and display the frame
    success, frame = camera.read()
    cv2.imshow(display, frame)

def saveFrame(filename):
    # Save the current frame to a file
    success, frame = camera.read()
    if success:
        cv2.imwrite(filename, frame)

frame_count = 0
desync_count = 0

while True:
    trigger()

    frame_count += 1
    if camera.dma.count != 0:
        print("After", frame_count, "frames, DMA count is:", camera.dma.count)
        desync_count += 1

    key = cv2.waitKey(1)
    if key == ord('q'):
        break

print(frame_count, "frames captured,", desync_count, "desyncs detected.")

With the loops at # Wait for falling edge of vsync commented out, the images all look great and the following is printed:

Output:

22 frames captured, 0 desyncs detected.

With the loops at # Wait for falling edge of vsync not commented out, many of the images are corrupted and the following is printed:

Output:

After 1 frames, DMA count is: 2
After 3 frames, DMA count is: 2
After 6 frames, DMA count is: 4
After 12 frames, DMA count is: 2
After 16 frames, DMA count is: 1
After 17 frames, DMA count is: 2
After 18 frames, DMA count is: 1
After 22 frames, DMA count is: 4
After 23 frames, DMA count is: 1
After 24 frames, DMA count is: 2
After 26 frames, DMA count is: 3
After 28 frames, DMA count is: 2
After 30 frames, DMA count is: 1
30 frames captured, 13 desyncs detected.

Other test runs resulted in up to 2/3 of frames getting desynced.

The only difference between these 2 tests is waiting for a falling edge on the vsync pin. Its really not clear to me why polling the pin would affect anything, but that could possibly explain why desyncs occur in the first place when the vsync handler is enabled (the debug code above disables it)

[sfe-SparkFro]

Fixed by f99b1c8

Current hypothesis - when the DMA needs to transfer to the PSRAM (basically everything is in PSRAM here), there is some overhead with every transfer (possibly requiring the CPU, I should read up on that). When transferring single bytes at a time, the overhead is close to the limit of what can be handled, so polling the vsync pin (or possibly doing other stuff) causes some transfers to be missed. Or something like that. Truthfully, I'm not really certain, but it seems to work great now, so just gonna move on!