USB driver not working well with unaligned content

[fjtrujy]

👋
I have been facing some issues with USB drivers when using fwrite from unaligned 4-byte buffers...
Given the next example:

    // Use mass: device to write to a file
    chdir("mass:/");

    // Open a file in binary write mode
    FILE *file = fopen("dummy_file.bin", "wb");
    if (file == NULL) {
        perror("Error opening file");
        return 1;
    }

    unsigned char *dummy_content = (unsigned char *)malloc(2000);

    for (int i = 0; i < 2000; i++) {
        dummy_content[i] = (unsigned char)(i % 256); // Fill with values from 0 to 255
    }

    unsigned char *dummy_content_offset = dummy_content
    printf("Dummy content address is %p, offset address is %p\n", dummy_content, dummy_content_offset);

    // Write the dummy content to the file
    size_t toWrite = 1200;
    size_t elements_written = fwrite(dummy_content_offset, 1, toWrite, file);
    if (elements_written != toWrite) {
        perror("Error writing to file");
        fclose(file);
        free(dummy_content);
        SleepThread();
        return 1;
    }

    // Close the file
    fclose(file);
    free(dummy_content);
    printf("Dummy content written to file successfully.\n");

It works as expected, however, if we replace unsigned char *dummy_content_offset = dummy_content with unsigned char *dummy_content_offset = dummy_content + 6 to force having an offset, it fails due to alignment issues on the USB driver.

    // Use mass: device to write to a file
    chdir("mass:/");

    // Open a file in binary write mode
    FILE *file = fopen("dummy_file.bin", "wb");
    if (file == NULL) {
        perror("Error opening file");
        return 1;
    }

    unsigned char *dummy_content = (unsigned char *)malloc(2000);

    for (int i = 0; i < 2000; i++) {
        dummy_content[i] = (unsigned char)(i % 256); // Fill with values from 0 to 255
    }

    // create a pointer with 6 bits offset
    unsigned char *dummy_content_offset = dummy_content + 6;
    printf("Dummy content address is %p, offset address is %p\n", dummy_content, dummy_content_offset);

    // Write the dummy content to the file
    size_t toWrite = 1200;
    size_t elements_written = fwrite(dummy_content_offset, 1, toWrite, file);
    if (elements_written != toWrite) {
        perror("Error writing to file");
        fclose(file);
        free(dummy_content);
        SleepThread();
        return 1;
    }

    // Close the file
    fclose(file);
    free(dummy_content);
    printf("Dummy content written to file successfully.\n");

Compiling PS2SDK with DEBUG=1 we can have some extra information.

Without offset:

ELF host:/Users/fjtrujy/Projects/helloWorldPS2/fwrite.elf with entry point at 0x1051784 is executing.
ELF changed, active CRC 1F441695 (host:/Users/fjtrujy/Projects/helloWorldPS2/fwrite.elf)
Applying core settings...
Updating CPU configuration...
EE/iR5900 Recompiler Reset
Get Reboot Request From EE
PlayStation 2 ======== Soft reboot
IOP Realtime Kernel Ver.0.9.1
    Copyright 1999 (C) Sony Computer Entertainment Inc. 
Reboot service module.(99/11/10)
cdvd driver module version 0.1.1 (C)SCEI
Load File service.(99/11/05)
Multi Threaded Fileio module.(99/11/15) 
iop heap service (99/11/03)
Poweroff_Handler: Poweroff installed
fileXio: fileXio: fileXio RPC Server v1.00
Copyright (c) 2003 adresd
fileXio: fileXio: RPC Initialize
mcman_cex: _start...
mcman_cex: registering exports...
mcman_cex: initPS2com...
mcman_cex: mcman_initPS2com registering secrman_mc_command callback
mcman_cex: mcman_initPS2com registering mcman_getcnum callback
mcman_cex: initPS1PDAcom...
mcman_cex: initcache...
mcman_cex: mcman_initcache
mcman_cex: initdev...
mcserv: _start...
mcserv: registering exports...
mcserv: starting RPC thread...
mcserv: _start returns MODULE_RESIDENT_END...
Block Device Manager (BDM) v1.1
BDM: bdm_init
BDM: part_init
BDM: connecting fs MBR
BDM: connecting fs GPT
BDM: BDM event thread running
BDM FatFs driver (FAT/exFAT) v1.4
FatFs: InitFS
FatFs: fs_reset
FatFs: _fs_init_lock
FatFs: fs_init
BDM: connecting fs fatfs
FreeUsbd v.0.1.2
usbd: library entries...
usbd: Threads and events...
usbd: Intr handler...
usbd: HCD thread...
usbd: Callback thread...
usbd: HCD init...
usbd: Host Controller...
usbd: HC reset done
usbd: Structs...
usbd: Hub driver...
usbd: Enabling interrupts...
usbd: Init done
usbd: RHSC
usbd: RHSC
usbmass_bd: USB MASS Driver v1.1
usbmass_bd: scsi_init
usbmass_bd: usb_mass_init
usbmass_bd: sceUsbdRegisterLdd=0
usbmass_bd: update thread running
cdfs Filedriver vDRIVER_UNIT_VERSION
Re-edited by fjtrujy
Original implementation
by A.Lee (aka Hiryu) & Nicholas Van Veen (aka Sjeep)
CDFS: Initializing 'cdfs' file driver.
DEV9 device driver v1.0 - Copyright (c) 2003 Marcus R. Brown
dev9: CXD9611 detected.
usbd: timer expired
usbd: RHSC
usbd: RHSC
usbd: timer expired
usbd: timer expired
usbd: searching driver for dev 2, FA 02
usbmass_bd: probe: devId=2
usbmass_bd: usb_mass_findDevice devId 2
usbmass_bd: bNumInterfaces 1
usbmass_bd: bInterfaceClass 8 bInterfaceSubClass 6 bInterfaceProtocol 50
usbd: Driver found (mass-stor)
usbmass_bd: connect: devId=2
usbmass_bd: usb_mass_findDevice devId 2
usbmass_bd: register Input endpoint id =1 addr=81 packetSize=64
usbmass_bd: register Output endpoint id =2 addr=02 packetSize=512
usbmass_bd: connect ok: epI=1, epO=2
usbmass_bd: setting configuration controlEp=0, confNum=1 
usbmass_bd: callback: res 0, bytes 0, arg 1dc990 
usbmass_bd: setting interface controlEp=0, interface=0 altSetting=0
usbmass_bd: callback: res 0, bytes 0, arg 1dc990 
usbmass_bd: scsi_connect
usbmass_bd: scsi_warmup
usbmass_bd: callback: res 0, bytes 1, arg 1dc8c0 
usbmass_bd: scsi->get_max_lun 0
usbmass_bd: scsi_cmd_inquiry
usbmass_bd: usb_queue_cmd
usbmass_bd: callback: res 0, bytes 31, arg 1dc878 
usbmass_bd: callback: res 0, bytes 13, arg 1dc840 
usbmass_bd: bulk csw result: 0, csw.status: 0
usbmass_bd: Vendor: QEMU
usbmass_bd: Product: USB Drive
usbmass_bd: Revision: 1.00
usbmass_bd: scsi_cmd_test_unit_ready
usbmass_bd: usb_queue_cmd
usbmass_bd: callback: res 0, bytes 31, arg 1dc878 
usbmass_bd: callback: res 0, bytes 13, arg 1dc840 
usbmass_bd: bulk csw result: 0, csw.status: 0
usbmass_bd: scsi_cmd_read_capacity
usbmass_bd: usb_queue_cmd
usbmass_bd: callback: res 0, bytes 31, arg 1dc878 
usbmass_bd: callback: res 0, bytes 13, arg 1dc840 
usbmass_bd: bulk csw result: 0, csw.status: 0
usbmass_bd: 0 524288-byte logical blocks: (0MB / 512MiB)
BDM: connecting device usb0p0 id=0x0
BDM: bd_cache_create
BDM: bdm_try_mount(usb0p0)
BDM: part_connect_mbr
BDM: - list:   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0  devread:    0, evict  0 [      -1], add [8]
usbmass_bd: scsi_read: sector=0x0000000000000000, count=8
usbmass_bd: scsi_cmd_rw_sector - 0x0000000000000000 159d88 0x0008
usbmass_bd: usb_queue_cmd
usbmass_bd: callback: res 0, bytes 31, arg 1e5820 
usbmass_bd: callback: res 0, bytes 13, arg 1e57e8 
usbmass_bd: bulk csw result: 0, csw.status: 0
Found MBR disk
BDM: part_connect_gpt
BDM: GPT partition table header signature is invalid: RRaA
FatFs: connect_bd
FatFs: connect_bd: trying to mount to index 0
FatFs: fatfs_fs_driver_mount_bd
FatFs: check_fs returned 0 at LBA 0x0000000000000000
BDM: usb0p0 mounted to fatfs
DEV9: Unknown 16bit read at address 10000020 value 0
dev9: SPEED chip 'ES2', revision 11
dev9: CXD9611 (SSBUS Buffer) driver start.
fileXio: GetStat Request 'host:/Users/fjtrujy/Projects/helloWorldPS2'
fileXio: Open Request 'mass:/dummy_file.bin' f:0x602 m:0x1b6
FatFs: fs_open: /dummy_file.bin flags=602 mode=1B6
FatFs: fs_find_free_fil_structure
BDM: - list:   4   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0  devread:    8, evict  1 [      -1], add [8]
usbmass_bd: scsi_read: sector=0x0000000000001fa2, count=8
usbmass_bd: scsi_cmd_rw_sector - 0x0000000000001fa2 15ad88 0x0008
usbmass_bd: usb_queue_cmd
usbmass_bd: callback: res 0, bytes 31, arg 1f60e0 
usbmass_bd: callback: res 0, bytes 13, arg 1f60a8 
usbmass_bd: bulk csw result: 0, csw.status: 0
BDM: _write(8098, 0)
usbmass_bd: scsi_write: sector=0x0000000000001fa2, count=1
usbmass_bd: scsi_cmd_rw_sector - 0x0000000000001fa2 989b8 0x0001
usbmass_bd: usb_queue_cmd
usbmass_bd: callback: res 0, bytes 31, arg 1f6150 
usbmass_bd: callback: res 0, bytes 13, arg 1f6118 
usbmass_bd: bulk csw result: 0, csw.status: 0
BDM: - list:   3   1   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0  devread:   16, evict  2 [      -1], add [8]
usbmass_bd: scsi_read: sector=0x0000000000000020, count=8
usbmass_bd: scsi_cmd_rw_sector - 0x0000000000000020 15bd88 0x0008
usbmass_bd: usb_queue_cmd
usbmass_bd: callback: res 0, bytes 31, arg 1f6118 
usbmass_bd: callback: res 0, bytes 13, arg 1f60e0 
usbmass_bd: bulk csw result: 0, csw.status: 0
BDM: _write(32, 0)
usbmass_bd: scsi_write: sector=0x0000000000000020, count=1
usbmass_bd: scsi_cmd_rw_sector - 0x0000000000000020 989b8 0x0001
usbmass_bd: usb_queue_cmd
usbmass_bd: callback: res 0, bytes 31, arg 1f61b0 
usbmass_bd: callback: res 0, bytes 13, arg 1f6178 
usbmass_bd: bulk csw result: 0, csw.status: 0
BDM: _write(4065, 0)
usbmass_bd: scsi_write: sector=0x0000000000000fe1, count=1
usbmass_bd: scsi_cmd_rw_sector - 0x0000000000000fe1 989b8 0x0001
usbmass_bd: usb_queue_cmd
usbmass_bd: callback: res 0, bytes 31, arg 1f61b0 
usbmass_bd: callback: res 0, bytes 13, arg 1f6178 
usbmass_bd: bulk csw result: 0, csw.status: 0
BDM: - list:   3   0   1   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0  devread:   24, evict  3 [      -1], add [8]
usbmass_bd: scsi_read: sector=0x0000000000001fa2, count=8
usbmass_bd: scsi_cmd_rw_sector - 0x0000000000001fa2 15cd88 0x0008
usbmass_bd: usb_queue_cmd
usbmass_bd: callback: res 0, bytes 31, arg 1f6178 
usbmass_bd: callback: res 0, bytes 13, arg 1f6140 
usbmass_bd: bulk csw result: 0, csw.status: 0
fileXio: GetStat Request 'mass:/dummy_file.bin'
FatFs: fs_getstat: unit 0 name /dummy_file.bin
fileXio: Write Request fd:2, size:1024
FatFs: fs_write
BDM: - list:   2   0   0   1   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0  devread:   32, evict  4 [      -1], add [8]
usbmass_bd: scsi_read: sector=0x0000000000000020, count=8
usbmass_bd: scsi_cmd_rw_sector - 0x0000000000000020 15dd88 0x0008
usbmass_bd: usb_queue_cmd
usbmass_bd: callback: res 0, bytes 31, arg 1f65f8 
usbmass_bd: callback: res 0, bytes 13, arg 1f65c0 
usbmass_bd: bulk csw result: 0, csw.status: 0
BDM: _write(8116, 0)
usbmass_bd: scsi_write: sector=0x0000000000001fb4, count=1
usbmass_bd: scsi_cmd_rw_sector - 0x0000000000001fb4 51a00 0x0001
usbmass_bd: usb_queue_cmd
usbmass_bd: callback: res 0, bytes 31, arg 1f66e0 
usbmass_bd: callback: res 0, bytes 13, arg 1f66a8 
usbmass_bd: bulk csw result: 0, csw.status: 0
BDM: _write(8117, 0)
usbmass_bd: scsi_write: sector=0x0000000000001fb5, count=1
usbmass_bd: scsi_cmd_rw_sector - 0x0000000000001fb5 51c00 0x0001
usbmass_bd: usb_queue_cmd
usbmass_bd: callback: res 0, bytes 31, arg 1f66e0 
usbmass_bd: callback: res 0, bytes 13, arg 1f66a8 
usbmass_bd: bulk csw result: 0, csw.status: 0
fileXio: Write Request fd:2, size:176
FatFs: fs_write
BDM: _write(32, 0)
usbmass_bd: scsi_write: sector=0x0000000000000020, count=1
usbmass_bd: scsi_cmd_rw_sector - 0x0000000000000020 989b8 0x0001
usbmass_bd: usb_queue_cmd
usbmass_bd: callback: res 0, bytes 31, arg 1f66b8 
usbmass_bd: callback: res 0, bytes 13, arg 1f6680 
usbmass_bd: bulk csw result: 0, csw.status: 0
BDM: _write(4065, 0)
usbmass_bd: scsi_write: sector=0x0000000000000fe1, count=1
usbmass_bd: scsi_cmd_rw_sector - 0x0000000000000fe1 989b8 0x0001
usbmass_bd: usb_queue_cmd
usbmass_bd: callback: res 0, bytes 31, arg 1f66b8 
usbmass_bd: callback: res 0, bytes 13, arg 1f6680 
usbmass_bd: bulk csw result: 0, csw.status: 0
FatFs: fs_write
fileXio: Close Request fd:2
FatFs: fs_close
BDM: _write(8118, 0)
usbmass_bd: scsi_write: sector=0x0000000000001fb6, count=1
usbmass_bd: scsi_cmd_rw_sector - 0x0000000000001fb6 989b8 0x0001
usbmass_bd: usb_queue_cmd
usbmass_bd: callback: res 0, bytes 31, arg 1f61c0 
usbmass_bd: callback: res 0, bytes 13, arg 1f6188 
usbmass_bd: bulk csw result: 0, csw.status: 0
BDM: _write(8098, 0)
usbmass_bd: scsi_write: sector=0x0000000000001fa2, count=1
usbmass_bd: scsi_cmd_rw_sector - 0x0000000000001fa2 989b8 0x0001
usbmass_bd: usb_queue_cmd
usbmass_bd: callback: res 0, bytes 31, arg 1f61c0 
usbmass_bd: callback: res 0, bytes 13, arg 1f6188 
usbmass_bd: bulk csw result: 0, csw.status: 0
BDM: _write(1, 0)
usbmass_bd: scsi_write: sector=0x0000000000000001, count=1
usbmass_bd: scsi_cmd_rw_sector - 0x0000000000000001 989b8 0x0001
usbmass_bd: usb_queue_cmd
usbmass_bd: callback: res 0, bytes 31, arg 1f61e8 
usbmass_bd: callback: res 0, bytes 13, arg 1f61b0 
usbmass_bd: bulk csw result: 0, csw.status: 0
BDM: _flush
usbmass_bd: scsi_flush
fileXio: Devctl Request 'dev9x:' cmd:17410

With offset:

ELF host:/Users/fjtrujy/Projects/helloWorldPS2/fwrite.elf with entry point at 0x1051784 is executing.
ELF changed, active CRC 19520736 (host:/Users/fjtrujy/Projects/helloWorldPS2/fwrite.elf)
Applying core settings...
Updating CPU configuration...
EE/iR5900 Recompiler Reset
Get Reboot Request From EE
PlayStation 2 ======== Soft reboot
IOP Realtime Kernel Ver.0.9.1
    Copyright 1999 (C) Sony Computer Entertainment Inc. 
Reboot service module.(99/11/10)
cdvd driver module version 0.1.1 (C)SCEI
Load File service.(99/11/05)
Multi Threaded Fileio module.(99/11/15) 
iop heap service (99/11/03)
Poweroff_Handler: Poweroff installed
fileXio: fileXio: fileXio RPC Server v1.00
Copyright (c) 2003 adresd
fileXio: fileXio: RPC Initialize
mcman_cex: _start...
mcman_cex: registering exports...
mcman_cex: initPS2com...
mcman_cex: mcman_initPS2com registering secrman_mc_command callback
mcman_cex: mcman_initPS2com registering mcman_getcnum callback
mcman_cex: initPS1PDAcom...
mcman_cex: initcache...
mcman_cex: mcman_initcache
mcman_cex: initdev...
mcserv: _start...
mcserv: registering exports...
mcserv: starting RPC thread...
mcserv: _start returns MODULE_RESIDENT_END...
Block Device Manager (BDM) v1.1
BDM: bdm_init
BDM: part_init
BDM: connecting fs MBR
BDM: connecting fs GPT
BDM: BDM event thread running
BDM FatFs driver (FAT/exFAT) v1.4
FatFs: InitFS
FatFs: fs_reset
FatFs: _fs_init_lock
FatFs: fs_init
BDM: connecting fs fatfs
FreeUsbd v.0.1.2
usbd: library entries...
usbd: Threads and events...
usbd: Intr handler...
usbd: HCD thread...
usbd: Callback thread...
usbd: HCD init...
usbd: Host Controller...
usbd: HC reset done
usbd: Structs...
usbd: Hub driver...
usbd: Enabling interrupts...
usbd: Init done
usbd: RHSC
usbd: RHSC
usbmass_bd: USB MASS Driver v1.1
usbmass_bd: scsi_init
usbmass_bd: usb_mass_init
usbmass_bd: sceUsbdRegisterLdd=0
usbmass_bd: update thread running
cdfs Filedriver vDRIVER_UNIT_VERSION
Re-edited by fjtrujy
Original implementation
by A.Lee (aka Hiryu) & Nicholas Van Veen (aka Sjeep)
CDFS: Initializing 'cdfs' file driver.
DEV9 device driver v1.0 - Copyright (c) 2003 Marcus R. Brown
dev9: CXD9611 detected.
usbd: timer expired
usbd: RHSC
usbd: RHSC
usbd: timer expired
usbd: timer expired
usbd: searching driver for dev 2, FA 02
usbmass_bd: probe: devId=2
usbmass_bd: usb_mass_findDevice devId 2
usbmass_bd: bNumInterfaces 1
usbmass_bd: bInterfaceClass 8 bInterfaceSubClass 6 bInterfaceProtocol 50
usbd: Driver found (mass-stor)
usbmass_bd: connect: devId=2
usbmass_bd: usb_mass_findDevice devId 2
usbmass_bd: register Input endpoint id =1 addr=81 packetSize=64
usbmass_bd: register Output endpoint id =2 addr=02 packetSize=512
usbmass_bd: connect ok: epI=1, epO=2
usbmass_bd: setting configuration controlEp=0, confNum=1 
usbmass_bd: callback: res 0, bytes 0, arg 1dc990 
usbmass_bd: setting interface controlEp=0, interface=0 altSetting=0
usbmass_bd: callback: res 0, bytes 0, arg 1dc990 
usbmass_bd: scsi_connect
usbmass_bd: scsi_warmup
usbmass_bd: callback: res 0, bytes 1, arg 1dc8c0 
usbmass_bd: scsi->get_max_lun 0
usbmass_bd: scsi_cmd_inquiry
usbmass_bd: usb_queue_cmd
usbmass_bd: callback: res 0, bytes 31, arg 1dc878 
usbmass_bd: callback: res 0, bytes 13, arg 1dc840 
usbmass_bd: bulk csw result: 0, csw.status: 0
usbmass_bd: Vendor: QEMU
usbmass_bd: Product: USB Drive
usbmass_bd: Revision: 1.00
usbmass_bd: scsi_cmd_test_unit_ready
usbmass_bd: usb_queue_cmd
usbmass_bd: callback: res 0, bytes 31, arg 1dc878 
usbmass_bd: callback: res 0, bytes 13, arg 1dc840 
usbmass_bd: bulk csw result: 0, csw.status: 0
usbmass_bd: scsi_cmd_read_capacity
usbmass_bd: usb_queue_cmd
usbmass_bd: callback: res 0, bytes 31, arg 1dc878 
usbmass_bd: callback: res 0, bytes 13, arg 1dc840 
usbmass_bd: bulk csw result: 0, csw.status: 0
usbmass_bd: 0 524288-byte logical blocks: (0MB / 512MiB)
BDM: connecting device usb0p0 id=0x0
BDM: bd_cache_create
BDM: bdm_try_mount(usb0p0)
BDM: part_connect_mbr
BDM: - list:   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0  devread:    0, evict  0 [      -1], add [8]
usbmass_bd: scsi_read: sector=0x0000000000000000, count=8
usbmass_bd: scsi_cmd_rw_sector - 0x0000000000000000 159d88 0x0008
usbmass_bd: usb_queue_cmd
usbmass_bd: callback: res 0, bytes 31, arg 1e5820 
usbmass_bd: callback: res 0, bytes 13, arg 1e57e8 
usbmass_bd: bulk csw result: 0, csw.status: 0
Found MBR disk
BDM: part_connect_gpt
BDM: GPT partition table header signature is invalid: RRaA
FatFs: connect_bd
FatFs: connect_bd: trying to mount to index 0
FatFs: fatfs_fs_driver_mount_bd
FatFs: check_fs returned 0 at LBA 0x0000000000000000
BDM: usb0p0 mounted to fatfs
DEV9: Unknown 16bit read at address 10000020 value 0
dev9: SPEED chip 'ES2', revision 11
dev9: CXD9611 (SSBUS Buffer) driver start.
fileXio: GetStat Request 'host:/Users/fjtrujy/Projects/helloWorldPS2'
fileXio: Open Request 'mass:/dummy_file.bin' f:0x602 m:0x1b6
FatFs: fs_open: /dummy_file.bin flags=602 mode=1B6
FatFs: fs_find_free_fil_structure
BDM: - list:   4   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0  devread:    8, evict  1 [      -1], add [8]
usbmass_bd: scsi_read: sector=0x0000000000001fa2, count=8
usbmass_bd: scsi_cmd_rw_sector - 0x0000000000001fa2 15ad88 0x0008
usbmass_bd: usb_queue_cmd
usbmass_bd: callback: res 0, bytes 31, arg 1f60e0 
usbmass_bd: callback: res 0, bytes 13, arg 1f60a8 
usbmass_bd: bulk csw result: 0, csw.status: 0
fileXio: GetStat Request 'mass:/dummy_file.bin'
FatFs: fs_getstat: unit 0 name /dummy_file.bin
fileXio: Write Request fd:2, size:1024
FatFs: fs_write
BDM: _write(8098, 0)
usbmass_bd: scsi_write: sector=0x0000000000001fa2, count=1
usbmass_bd: scsi_cmd_rw_sector - 0x0000000000001fa2 989b8 0x0001
usbmass_bd: usb_queue_cmd
usbmass_bd: callback: res 0, bytes 31, arg 1f6630 
usbmass_bd: callback: res 0, bytes 13, arg 1f65f8 
usbmass_bd: bulk csw result: 0, csw.status: 0
BDM: - list:   3   1   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0  devread:   16, evict  2 [      -1], add [8]
usbmass_bd: scsi_read: sector=0x0000000000000020, count=8
usbmass_bd: scsi_cmd_rw_sector - 0x0000000000000020 15bd88 0x0008
usbmass_bd: usb_queue_cmd
usbmass_bd: callback: res 0, bytes 31, arg 1f65f8 
usbmass_bd: callback: res 0, bytes 13, arg 1f65c0 
usbmass_bd: bulk csw result: 0, csw.status: 0
BDM: _write(32, 0)
usbmass_bd: scsi_write: sector=0x0000000000000020, count=1
usbmass_bd: scsi_cmd_rw_sector - 0x0000000000000020 989b8 0x0001
usbmass_bd: usb_queue_cmd
usbmass_bd: callback: res 0, bytes 31, arg 1f66b8 
usbmass_bd: callback: res 0, bytes 13, arg 1f6680 
usbmass_bd: bulk csw result: 0, csw.status: 0
BDM: _write(4065, 0)
usbmass_bd: scsi_write: sector=0x0000000000000fe1, count=1
usbmass_bd: scsi_cmd_rw_sector - 0x0000000000000fe1 989b8 0x0001
usbmass_bd: usb_queue_cmd
usbmass_bd: callback: res 0, bytes 31, arg 1f66b8 
usbmass_bd: callback: res 0, bytes 13, arg 1f6680 
usbmass_bd: bulk csw result: 0, csw.status: 0
FatFs: fs_write
BDM: _write(8115, 0)
usbmass_bd: scsi_write: sector=0x0000000000001fb3, count=1
usbmass_bd: scsi_cmd_rw_sector - 0x0000000000001fb3 989b8 0x0001
usbmass_bd: usb_queue_cmd
usbmass_bd: callback: res 0, bytes 31, arg 1f6630 
usbmass_bd: callback: res 0, bytes 13, arg 1f65f8 
usbmass_bd: bulk csw result: 0, csw.status: 0
BDM: - list:   3   0   1   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0   0  devread:   24, evict  3 [      -1], add [8]
usbmass_bd: scsi_read: sector=0x0000000000000020, count=8
usbmass_bd: scsi_cmd_rw_sector - 0x0000000000000020 15cd88 0x0008
usbmass_bd: usb_queue_cmd
usbmass_bd: callback: res 0, bytes 31, arg 1f65f8 
usbmass_bd: callback: res 0, bytes 13, arg 1f65c0 
usbmass_bd: bulk csw result: 0, csw.status: 0
BDM: _write(8116, 0)
usbmass_bd: scsi_write: sector=0x0000000000001fb4, count=1
usbmass_bd: scsi_cmd_rw_sector - 0x0000000000001fb4 51bc6 0x0001
usbmass_bd: usb_queue_cmd
usbmass_bd: callback: res 0, bytes 31, arg 1f66e0 
usbmass_bd: ERROR: bulk data transfer 262. Clearing HALT state.
usbmass_bd: callback: res 4, bytes 0, arg 1f66a8 
usbmass_bd: ERROR: sending clear halt 4
usbmass_bd: callback: res 4, bytes 0, arg 1f66a8 
usbmass_bd: bulk csw.status returnSize: 0 != 13
usbmass_bd: bulk csw result: 4, csw.status: 0
usbmass_bd: callback: res 4, bytes 0, arg 1f66a8 
usbmass_bd: ERROR: sending clear halt 4
usbmass_bd: ERROR: usb_bulk_manage_status error 4 ...
usbmass_bd: callback: res 4, bytes 0, arg 1f66a8 
usbmass_bd: bulk csw.status returnSize: 0 != 13
usbmass_bd: bulk csw result: 4, csw.status: 0
usbmass_bd: ERROR: usb_bulk_manage_status call reset recovery ...
usbmass_bd: callback: res 0, bytes 0, arg 1f66a8 
usbmass_bd: callback: res 4, bytes 0, arg 1f6670 
usbmass_bd: ERROR: sending clear halt 4
usbmass_bd: ERROR: sending reset 4 to device 2.
usbmass_bd: scsi_cmd_rw_sector - 0x0000000000001fb4 51bc6 0x0001
usbmass_bd: usb_queue_cmd
usbmass_bd: Rejecting I/O to offline device 2.
usbmass_bd: scsi_cmd_rw_sector - 0x0000000000001fb4 51bc6 0x0001
usbmass_bd: usb_queue_cmd
usbmass_bd: Rejecting I/O to offline device 2.
usbmass_bd: scsi_cmd_rw_sector - 0x0000000000001fb4 51bc6 0x0001
usbmass_bd: usb_queue_cmd
usbmass_bd: Rejecting I/O to offline device 2.
usbmass_bd: scsi_cmd_rw_sector - 0x0000000000001fb4 51bc6 0x0001
usbmass_bd: usb_queue_cmd
usbmass_bd: Rejecting I/O to offline device 2.
usbmass_bd: scsi_cmd_rw_sector - 0x0000000000001fb4 51bc6 0x0001
usbmass_bd: usb_queue_cmd
usbmass_bd: Rejecting I/O to offline device 2.
usbmass_bd: scsi_cmd_rw_sector - 0x0000000000001fb4 51bc6 0x0001
usbmass_bd: usb_queue_cmd
usbmass_bd: Rejecting I/O to offline device 2.
usbmass_bd: scsi_cmd_rw_sector - 0x0000000000001fb4 51bc6 0x0001
usbmass_bd: usb_queue_cmd
usbmass_bd: Rejecting I/O to offline device 2.
usbmass_bd: scsi_cmd_rw_sector - 0x0000000000001fb4 51bc6 0x0001
usbmass_bd: usb_queue_cmd
usbmass_bd: Rejecting I/O to offline device 2.
usbmass_bd: scsi_cmd_rw_sector - 0x0000000000001fb4 51bc6 0x0001
usbmass_bd: usb_queue_cmd
usbmass_bd: Rejecting I/O to offline device 2.
usbmass_bd: scsi_cmd_rw_sector - 0x0000000000001fb4 51bc6 0x0001
usbmass_bd: usb_queue_cmd
usbmass_bd: Rejecting I/O to offline device 2.
usbmass_bd: scsi_cmd_rw_sector - 0x0000000000001fb4 51bc6 0x0001
usbmass_bd: usb_queue_cmd
usbmass_bd: Rejecting I/O to offline device 2.
usbmass_bd: scsi_cmd_rw_sector - 0x0000000000001fb4 51bc6 0x0001
usbmass_bd: usb_queue_cmd
usbmass_bd: Rejecting I/O to offline device 2.
usbmass_bd: scsi_cmd_rw_sector - 0x0000000000001fb4 51bc6 0x0001
usbmass_bd: usb_queue_cmd
usbmass_bd: Rejecting I/O to offline device 2.
usbmass_bd: scsi_cmd_rw_sector - 0x0000000000001fb4 51bc6 0x0001
usbmass_bd: usb_queue_cmd
usbmass_bd: Rejecting I/O to offline device 2.
usbmass_bd: scsi_cmd_rw_sector - 0x0000000000001fb4 51bc6 0x0001
usbmass_bd: usb_queue_cmd
usbmass_bd: Rejecting I/O to offline device 2.
usbmass_bd: ERROR: unable to write sector after 16 tries (sector=0x0000000000001fb4, count=1)
fileXio: Write Request fd:2, size:1024
FatFs: fs_write
read/write allocate memory 4000
Error writing to file: Function not implemented
fileXio: Close Request fd:2
FatFs: fs_close
BDM: _write(32, 0)
usbmass_bd: scsi_write: sector=0x0000000000000020, count=1
usbmass_bd: scsi_cmd_rw_sector - 0x0000000000000020 989b8 0x0001
usbmass_bd: usb_queue_cmd
usbmass_bd: Rejecting I/O to offline device 2.
usbmass_bd: scsi_cmd_rw_sector - 0x0000000000000020 989b8 0x0001
usbmass_bd: usb_queue_cmd
usbmass_bd: Rejecting I/O to offline device 2.
usbmass_bd: scsi_cmd_rw_sector - 0x0000000000000020 989b8 0x0001
usbmass_bd: usb_queue_cmd
usbmass_bd: Rejecting I/O to offline device 2.
usbmass_bd: scsi_cmd_rw_sector - 0x0000000000000020 989b8 0x0001
usbmass_bd: usb_queue_cmd
usbmass_bd: Rejecting I/O to offline device 2.
usbmass_bd: scsi_cmd_rw_sector - 0x0000000000000020 989b8 0x0001
usbmass_bd: usb_queue_cmd
usbmass_bd: Rejecting I/O to offline device 2.
usbmass_bd: scsi_cmd_rw_sector - 0x0000000000000020 989b8 0x0001
usbmass_bd: usb_queue_cmd
usbmass_bd: Rejecting I/O to offline device 2.
usbmass_bd: scsi_cmd_rw_sector - 0x0000000000000020 989b8 0x0001
usbmass_bd: usb_queue_cmd
usbmass_bd: Rejecting I/O to offline device 2.
usbmass_bd: scsi_cmd_rw_sector - 0x0000000000000020 989b8 0x0001
usbmass_bd: usb_queue_cmd
usbmass_bd: Rejecting I/O to offline device 2.
usbmass_bd: scsi_cmd_rw_sector - 0x0000000000000020 989b8 0x0001
usbmass_bd: usb_queue_cmd
usbmass_bd: Rejecting I/O to offline device 2.
usbmass_bd: scsi_cmd_rw_sector - 0x0000000000000020 989b8 0x0001
usbmass_bd: usb_queue_cmd
usbmass_bd: Rejecting I/O to offline device 2.
usbmass_bd: scsi_cmd_rw_sector - 0x0000000000000020 989b8 0x0001
usbmass_bd: usb_queue_cmd
usbmass_bd: Rejecting I/O to offline device 2.
usbmass_bd: scsi_cmd_rw_sector - 0x0000000000000020 989b8 0x0001
usbmass_bd: usb_queue_cmd
usbmass_bd: Rejecting I/O to offline device 2.
usbmass_bd: scsi_cmd_rw_sector - 0x0000000000000020 989b8 0x0001
usbmass_bd: usb_queue_cmd
usbmass_bd: Rejecting I/O to offline device 2.
usbmass_bd: scsi_cmd_rw_sector - 0x0000000000000020 989b8 0x0001
usbmass_bd: usb_queue_cmd
usbmass_bd: Rejecting I/O to offline device 2.
usbmass_bd: scsi_cmd_rw_sector - 0x0000000000000020 989b8 0x0001
usbmass_bd: usb_queue_cmd
usbmass_bd: Rejecting I/O to offline device 2.
usbmass_bd: scsi_cmd_rw_sector - 0x0000000000000020 989b8 0x0001
usbmass_bd: usb_queue_cmd
usbmass_bd: Rejecting I/O to offline device 2.
usbmass_bd: ERROR: unable to write sector after 16 tries (sector=0x0000000000000020, count=1)

If you see, we start to suffer errors likes this one:

BDM: _write(8116, 0)
usbmass_bd: scsi_write: sector=0x0000000000001fb4, count=1
usbmass_bd: scsi_cmd_rw_sector - 0x0000000000001fb4 51bc6 0x0001
usbmass_bd: usb_queue_cmd
usbmass_bd: callback: res 0, bytes 31, arg 1f66e0 
usbmass_bd: ERROR: bulk data transfer 262. Clearing HALT state.
usbmass_bd: callback: res 4, bytes 0, arg 1f66a8 
usbmass_bd: ERROR: sending clear halt 4

Where bulk data transfer 262 262=0x106 which is

#define USB_RC_BADALIGN    0x106

from iop/usb/usbd/include/usbd.h

Official documentation for FatFs - Generic FAT Filesystem Module mentioned in the dread and dwrite information about possible alignment issues:
http://elm-chan.org/fsw/ff/doc/dread.html
http://elm-chan.org/fsw/ff/doc/dwrite.html

There are some considerations about the memory addres passed via buff. It is not that always aligned with the word boundary, because the argument is defined as BYTE*. The unaligned transfer request can occure at [direct transfer](http://elm-chan.org/fsw/ff/doc/appnote.html#fs1). If the bus architecture, especially DMA controller, does not allow unaligned memory access, it should be solved in this function. If it is the case, there are some workarounds described below to avoid this issue.

- Convert word transfer to byte transfer with some trick in this function. - Recommended.
- On the f_read() calls, avoid long read request that includes a whole of sector. - Any direct transfer never occures.
- On the f_read(fp, data, btw, bw) calls, make sure that (((UINT)data & 3) == (f_tell(fp) & 3)) is true. - Word alignment of buff is guaranteed.

This is something that I actually see reflected on the execution...
Let's follow the callback functions:

/**** PREVIOUSLY LIBC + LIBCGLUE ******/
ee/rpc/filexio/src/fileXio_rpc.c ==> fileXioWrite
iop/fs/filexio/src/fileXio_iop.c ==> fileXioRpc_Write
iop/fs/filexio/src/fileXio_iop.c ==> fileXio_Write_RPC
iop/system/iomanx/src/iomanX.c ==> iomanX_write
iop/fs/bdmfs_fatfs/src/fs_driver.c ==> fs_write
iop/fs/bdmfs_fatfs/src/ff.c ==> f_write
iop/fs/bdmfs_fatfs/src/diskio.c ==> disk_write 
iop/fs/libbdm/src/bd_cache.c ===> _write
iop/usb/usbmass_bd/src/scsi.c ===> scsi_write
iop/usb/usbmass_bd/src/scsi.c ===> scsi_cmd_rw_sector
iop/usb/usbmass_bd/src/usb_mass.c ===> usb_queue_cmd
iop/usb/usbd/src/interface.c ==> sceUsbdTransferPipe  ==> ENDS HERE WITH USB_RC_BADALIGN

Buffer is aligned till it reaches the iop/fs/bdmfs_fatfs/src/ff.c ==> f_write function where it plays with buffer index, producing already an unaligned buffer. Is important to mention that code from f_write belong to fsw library.
So, why it is failing?
It fails because on the sceUsbdTransferPipe we have the next condition:

else if (ep->alignFlag && ((u32)data & 3))
            res = USB_RC_BADALIGN;

If you see it check if data is aligned with ((u32)data & 3)), but it only check it if the ep->alignFlag is different that 0.

This flag is set when registering the endpoints

usbmass_bd: register Input endpoint id =1 addr=81 packetSize=64
usbmass_bd: register Output endpoint id =2 addr=02 packetSize=512

We generate 2 different endpoint, one for reading from USB (INPUT), and another one for writing (OUTPUT).

If we see how this is done is through the function usb_bulk_probeEndpoint in iop/usb/usbmass_bd/src/usb_mass.c

/* test that endpoint is bulk endpoint and if so, update device info */
static void usb_bulk_probeEndpoint(int devId, mass_dev *dev, UsbEndpointDescriptor *endpoint)
{
    if (endpoint->bmAttributes == USB_ENDPOINT_XFER_BULK) {
        if ((endpoint->bEndpointAddress & USB_ENDPOINT_DIR_MASK) == USB_DIR_OUT && dev->bulkEpO < 0) {
            /* When sceUsbdOpenPipe() is used to work around the hardware errata that occurs when an unaligned memory address is specified,
               some USB devices become incompatible. Hence it is preferable to do alignment correction in software instead. */
            dev->bulkEpO = sceUsbdOpenPipeAligned(devId, endpoint);
            M_DEBUG("register Output endpoint id =%i addr=%02X packetSize=%i\n", dev->bulkEpO, endpoint->bEndpointAddress, (unsigned short int)endpoint->wMaxPacketSizeHB << 8 | endpoint->wMaxPacketSizeLB);
        } else
            /* Open this pipe with sceUsbdOpenPipe, to allow unaligned addresses to be used.
               According to the Sony documentation and the USBD code,
               there is always an alignment check if the pipe is opened with the sceUsbdOpenPipeAligned(),
               even when there is never any correction for the bulk out pipe. */
            if ((endpoint->bEndpointAddress & USB_ENDPOINT_DIR_MASK) == USB_DIR_IN && dev->bulkEpI < 0) {
                dev->bulkEpI = sceUsbdOpenPipe(devId, endpoint);
                M_DEBUG("register Input endpoint id =%i addr=%02X packetSize=%i\n", dev->bulkEpI, endpoint->bEndpointAddress, (unsigned short int)endpoint->wMaxPacketSizeHB << 8 | endpoint->wMaxPacketSizeLB);
            }
    }
}

If you take a look it uses sceUsbdOpenPipeAligned for USB_DIR_OUT. The sceUsbdOpenPipeAligned is the one that set the alignFlag = 1, which triggers the condition that fails later on the iop/usb/usbd/src/interface.c ==> sceUsbdTransferPipe.

I don't know how to fix it as I don't have enough experience with drivers at that low level... however, I hope all this information is useful for you...

Pinging @sp193 @rickgaiser @davidgfnet @uyjulian as I know you have experience with these kinds of things.

Cheers.

[sp193]

There is a hardware issue in the USB OHCI controller, which causes problems when a certain transfer size is used for outbound flows. The normal version will do some workaround, while the "aligned" version does not (assumption: you provide an aligned memory buffer, which will thus not meet the condition for the hardware bug).
For more details, you may need to refer to the official documentation.

Actually, I did try using the normal function and I recall it somewhat worked. But as Sony remarked, the internal workaround might result in issues with some devices. I recall that writes resulted in corruption on my SanDisk.

Therefore, writes were left to use the aligned variant.

[fjtrujy]

There is a hardware issue in the USB OHCI controller, which causes problems when a certain transfer size is used for outbound flows. The normal version will do some workaround, while the "aligned" version does not (assumption: you provide an aligned memory buffer, which will thus not meet the condition for the hardware bug). For more details, you may need to refer to the official documentation.

Actually, I did try using the normal function and I recall it somewhat worked. But as Sony remarked, the internal workaround might result in issues with some devices. I recall that writes resulted in corruption on my SanDisk.

Therefore, writes were left to use the aligned variant.

Thanks for the reply.
Yes, I was aware of the issue too. You mean the sceUsbdOpenPipeAligned vs sceUsbdOpenPipe, right?
I tried to use the sceUsbdOpenPipeas well and it also generated corrupted data in the USB 😢 .

So this is why I was thinking that the only solution here is to align the buffer before starting the copy, but the thing is, how to align it without losing too much performance and the best function to do it...

[fjtrujy]

Some additional useful info:

1. Initial implementation was done here
   Which uses UsbOpenEndpointAligned for both IN/OUT in the iop/usb/usbhdfsd/src/usb_driver.c file.

2. We changed to UsbOpenEndpoint for both IN/OUT here with the next commit message:

(USBHDFSD) Changed sceUsbdOpenPipeAligned() to sceUsbdOpenPipe(), and removed code that breaks up long transfers (since they're too long to exceed on the IOP).

The change to sceUsbdOpenPipe() is to avoid triggering the driver's checks when the address is misaligned.

3. We changed back tosceUsbdOpenPipeAligned here just for OUT with the next commit message

(USBHDFSD) Added workaround for not 100%-compliant USB devices and fixed faulty logic for writing.

This last commit is more or less the current status we are using for current drivers in terms of READ/WRITES aligned.

@sp193 Do you think it is possible to use UsbOpenEndpoint for writing having in mind the "hardware" error about rounding 63 and 64 sector byte to 62, with some workaround? or do you think is better to try align somehow buffer before producing the writes?

Cheers.

[fjtrujy]

I will add some more debugging info...

1. I have an aligned buffer, which is created with malloc (16 bytes aligned), and then I add 6 extra bytes to transform to unaligned.
2. I want to copy for instance in this case 1200 bytes.
3. newlib split writes in slices of 1024 bytes, so fileXioWrite is called with 1024 bytes length, but the buffer is still unaligned.
4. Then in order to have aligned content, fileXio RPC function aligns it to 64 bytes. To do this, it creates one extra buffer aligned with a size of 64 bytes max, and copies into that extra buffer the unaligned 64 bytes part. In my example it is 58 bytes misaligned to 64 bytes, so this extra buffer has filled 58 bytes.
5. Being on the IOP side already (fileXio_Write_RPC), 2 write executions are produced, first using the extra buffer that contains 58 bytes, so it produces a write of 58 bytes, and everything goes well.
6. The remaining bytes are written using an aligned buffer (the original unaligned one + 58 bytes offset, which is 64 bytes aligned). It will write the remaining bytes 1024 - 58 = 966 bytes.
7. From here, the code reaches FatFS library. On the function f_write from iop/fs/bdmfs_fatfs/src/ff.c it performs some logic and sees that in order to write 966 bytes, it is going to execute 2 different write calls, 454 bytes + 512 bytes, (I suppose it tries to perform writes always with 512 bytes). Then it does first the 512-byte write calls, which means adding an offset of 454 bytes to the original aligned buffer (in my example, for instance, is 0x51b00 + 454 it is 0x51cc6) producing the unaligned buffer, the one that is always failing.

From here I conclude that is possible to have also the same issue having an aligned buffer (even 64 bytes aligned) and producing concrete write length. I will check it...

[sp193]

The payload size restriction of 63 or 64 bytes, refers to the USB frame size (not your request length). Sony wrote that sceUsbdOpenPipe() will internally do some workaround to limit the frame size to 62 bytes. However, this workaround seems to cause corruption with certain USB disks. Therefore, I do not think you can do anything about this, as the only workarounds are already documented by Sony. Only the outbound flow is affected (inbound is not affected).

1. Use sceUsbdOpenPipe() and Sony will work around the hardware bug for you.
2. Or if you cannot use sceUsbdOpenPipe() because your device reacts badly to it, use sceUsbdOpenPipeAligned() with an aligned memory buffer.

In my opinion, you could make some assumptions and declare some limitations.
The PlayStation 2 was from an era where you needed to meet some requirements to get optimal performance, so having and living with documented limitations seems to be perfectly normal to me. Sony even split apart the I/O documentation for each device, rather than documenting I/O functions for general use.

Not all DMA channels could work with unaligned pointers, so this is probably not the only device that will require some copying.

If you want to have a middle-ground, I think you can attempt to design something like what you have found in the RPC code. If I recall right, it works something like this. Please check.

1. Skip the leading unaligned portion (first N bytes).
2. You now have an aligned address. You can read S - 1 sectors of data, directly.
3. Read the first and last sectors of data, and copy the unaligned portions (first N bytes, and last len % sector_size bytes)

Where N is the amount needed to align the buffer.

Something like this strategy is also present in memcpy, if I remember right.