Compatibility issues with AMD platform and ASMedia USB controller

[ReimuNotMoe]

OS: Debian 10 Kernel: 5.9.10

I tried mode=SDRAM and mode=SPINAND, and none of them worked.

Program output:

image0 ./980uimage
Failed

NUC980 UART output:

NUC980 IBR 20180813
Boot from USB
DDR-OK
=======================================
Run firmware code
CPU: 300MHz, DDR: 300MHz, SYS: 300MHz, PCLK: 150MHz
Parse NuWriter command line
=======================================
SPI NOR ID=0x0000ffff  _spi_type =0
SPI NOR ID=0x0000ffff  _spi_type =0

SPI NAND: Auto Detect
ID=[0xefaa21]
BlockPerFlash = 1024, PagePerBlock = 64
PageSize = 2048, SpareArea = 64
QuadReadCmd    = 0x6b
ReadStatusCmd  = 0xff
WriteStatusCmd = 0xff
StatusValue    = 0xff
Dummybyte      = 0x1

NAND ID=[0][0][0][0]
PowerOn setting 0x5f6000d4
BlockPerFlash=1023, PagePerBlock=64, PageSize=2048

eMMC1/SD1 eMMCBlockSize=0xffff0115(-65259)

Finish get INFO!!

Some relevant strace logs:

[pid 85486] openat(AT_FDCWD, "./980uimage", O_RDONLY) = 10
[pid 85486] fstat(1, {st_mode=S_IFCHR|0600, st_rdev=makedev(0x88, 0x11), ...}) = 0
[pid 85486] write(1, "image0 ./980uimage\n", 19image0 ./980uimage
) = 19
[pid 85486] fstat(10, {st_mode=S_IFREG|0644, st_size=2475768, ...}) = 0
[pid 85486] fstat(10, {st_mode=S_IFREG|0644, st_size=2475768, ...}) = 0
[pid 85486] lseek(10, 2473984, SEEK_SET) = 2473984
[pid 85486] read(10, "\0\230.f\363D\367\312\326x\334\271\342\315\26xFVim'5\v\321\314vb\207\315\t\250\2"..., 1784) = 1784
[pid 85486] lseek(10, 0, SEEK_SET)      = 0
[pid 85486] mmap(NULL, 2478080, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f5fd651e000
[pid 85486] timerfd_settime(8, TFD_TIMER_ABSTIME, {it_interval={tv_sec=0, tv_nsec=0}, it_value={tv_sec=2463466, tv_nsec=320371000}}, NULL) = 0
[pid 85486] ioctl(9, USBDEVFS_SUBMITURB, 0x55cee75e4df0) = 0
[pid 85486] poll([{fd=6, events=POLLIN}, {fd=8, events=POLLIN}, {fd=9, events=POLLOUT}], 3, 60000) = 1 ([{fd=9, revents=POLLOUT}])
[pid 85486] ioctl(9, USBDEVFS_REAPURBNDELAY, 0x7fff33fe4cf0) = 0
[pid 85486] timerfd_settime(8, 0, {it_interval={tv_sec=0, tv_nsec=0}, it_value={tv_sec=0, tv_nsec=0}}, NULL) = 0
[pid 85486] ioctl(9, USBDEVFS_REAPURBNDELAY, 0x7fff33fe4cf0) = -1 EAGAIN (Resource temporarily unavailable)
[pid 85486] timerfd_settime(8, TFD_TIMER_ABSTIME, {it_interval={tv_sec=0, tv_nsec=0}, it_value={tv_sec=2463466, tv_nsec=320663000}}, NULL) = 0
[pid 85486] ioctl(9, USBDEVFS_SUBMITURB, 0x55cee75f3050) = 0
[pid 85486] poll([{fd=6, events=POLLIN}, {fd=8, events=POLLIN}, {fd=9, events=POLLOUT}], 3, 60000) = 1 ([{fd=9, revents=POLLOUT}])
[pid 85486] ioctl(9, USBDEVFS_REAPURBNDELAY, 0x7fff33fe4cf0) = 0
[pid 85486] timerfd_settime(8, 0, {it_interval={tv_sec=0, tv_nsec=0}, it_value={tv_sec=0, tv_nsec=0}}, NULL) = 0
[pid 85486] ioctl(9, USBDEVFS_REAPURBNDELAY, 0x7fff33fe4cf0) = -1 EAGAIN (Resource temporarily unavailable)
[pid 85486] timerfd_settime(8, TFD_TIMER_ABSTIME, {it_interval={tv_sec=0, tv_nsec=0}, it_value={tv_sec=2463466, tv_nsec=320945000}}, NULL) = 0
[pid 85486] ioctl(9, USBDEVFS_SUBMITURB, 0x55cee75f2ef0) = 0
[pid 85486] poll([{fd=6, events=POLLIN}, {fd=8, events=POLLIN}, {fd=9, events=POLLOUT}], 3, 60000) = 1 ([{fd=9, revents=POLLOUT}])
[pid 85486] ioctl(9, USBDEVFS_REAPURBNDELAY, 0x7fff33fe4cf0) = 0
[pid 85486] timerfd_settime(8, 0, {it_interval={tv_sec=0, tv_nsec=0}, it_value={tv_sec=0, tv_nsec=0}}, NULL) = 0
[pid 85486] ioctl(9, USBDEVFS_REAPURBNDELAY, 0x7fff33fe4cf0) = -1 EAGAIN (Resource temporarily unavailable)
[pid 85486] read(10, "'\5\31VgJ\n\nag_Y\0%\306\270\0\0\200\0\0\0\200\0\366\254\30\343\5\2\2\0"..., 2473984) = 2473984
[pid 85486] read(10, "\0\230.f\363D\367\312\326x\334\271\342\315\26xFVim'5\v\321\314vb\207\315\t\250\2"..., 4096) = 1784
[pid 85486] close(10)                   = 0
[pid 85486] timerfd_settime(8, TFD_TIMER_ABSTIME, {it_interval={tv_sec=0, tv_nsec=0}, it_value={tv_sec=2463466, tv_nsec=322342000}}, NULL) = 0
[pid 85486] ioctl(9, USBDEVFS_SUBMITURB, 0x55cee75f2ef0) = 0
[pid 85486] poll([{fd=6, events=POLLIN}, {fd=8, events=POLLIN}, {fd=9, events=POLLOUT}], 3, 60000) = 1 ([{fd=9, revents=POLLOUT}])
[pid 85486] ioctl(9, USBDEVFS_REAPURBNDELAY, 0x7fff33fe4cf0) = 0
[pid 85486] timerfd_settime(8, 0, {it_interval={tv_sec=0, tv_nsec=0}, it_value={tv_sec=0, tv_nsec=0}}, NULL) = 0
[pid 85486] ioctl(9, USBDEVFS_REAPURBNDELAY, 0x7fff33fe4cf0) = -1 EAGAIN (Resource temporarily unavailable)
[pid 85486] timerfd_settime(8, TFD_TIMER_ABSTIME, {it_interval={tv_sec=0, tv_nsec=0}, it_value={tv_sec=2463466, tv_nsec=322597000}}, NULL) = 0
[pid 85486] ioctl(9, USBDEVFS_SUBMITURB, 0x55cee75f2ef0) = 0
[pid 85486] poll([{fd=6, events=POLLIN}, {fd=8, events=POLLIN}, {fd=9, events=POLLOUT}], 3, 60000) = 1 ([{fd=9, revents=POLLOUT}])
[pid 85486] ioctl(9, USBDEVFS_REAPURBNDELAY, 0x7fff33fe4cf0) = 0
[pid 85486] timerfd_settime(8, 0, {it_interval={tv_sec=0, tv_nsec=0}, it_value={tv_sec=0, tv_nsec=0}}, NULL) = 0
[pid 85486] ioctl(9, USBDEVFS_REAPURBNDELAY, 0x7fff33fe4cf0) = -1 EAGAIN (Resource temporarily unavailable)
[pid 85486] timerfd_settime(8, TFD_TIMER_ABSTIME, {it_interval={tv_sec=0, tv_nsec=0}, it_value={tv_sec=2463466, tv_nsec=327390000}}, NULL) = 0
[pid 85486] ioctl(9, USBDEVFS_SUBMITURB, 0x55cee75f2ef0) = 0
[pid 85486] poll([{fd=6, events=POLLIN}, {fd=8, events=POLLIN}, {fd=9, events=POLLOUT}], 3, 60000) = 1 ([{fd=9, revents=POLLOUT}])
[pid 85486] ioctl(9, USBDEVFS_REAPURBNDELAY, 0x7fff33fe4cf0) = 0
[pid 85486] timerfd_settime(8, 0, {it_interval={tv_sec=0, tv_nsec=0}, it_value={tv_sec=0, tv_nsec=0}}, NULL) = 0
[pid 85486] ioctl(9, USBDEVFS_REAPURBNDELAY, 0x7fff33fe4cf0) = -1 EAGAIN (Resource temporarily unavailable)
[pid 85486] write(1, "Failed\n", 7Failed
)     = 7
[pid 85486] write(7, "\1", 1)           = 1
[pid 85486] close(9)                    = 0
[pid 85486] read(6, "\1", 1)            = 1
[pid 85486] poll([{fd=6, events=POLLIN}, {fd=8, events=POLLIN}], 2, 0) = 0 (Timeout)
[pid 85486] write(7, "\1", 1)           = 1
[pid 85486] close(6)                    = 0
[pid 85486] close(7)                    = 0
[pid 85486] close(8)                    = 0
[pid 85486] write(5, "\1", 1)           = 1
[pid 85487] <... poll resumed> )        = 1 ([{fd=4, revents=POLLIN}])
[pid 85486] futex(0x7f5fd6f7b9d0, FUTEX_WAIT, 85487, NULL <unfinished ...>
[pid 85487] read(4, "\1", 1)            = 1
[pid 85487] madvise(0x7f5fd677b000, 8368128, MADV_DONTNEED) = 0
[pid 85487] exit(0)                     = ?
[pid 85486] <... futex resumed> )       = 0
[pid 85487] +++ exited with 0 +++
close(3)                                = 0
close(4)                                = 0
close(5)                                = 0
exit_group(-1)                          = ?
+++ exited with 255 +++

[yachen]

Does execute with sudo help?

[ReimuNotMoe]

Does execute with sudo help?

I'm using the root account directly. So there shouldn't be any permission-related problems.

[ReimuNotMoe]

I tried the Windows version of NuWriter in VirtualBox VM and it worked.

I noticed the following behavior: When the NUC980 is firstly connected to PC, it will appear as a USB device with no strings at all.

[2505754.777819] usb 3-1.4.1: New USB device found, idVendor=0416, idProduct=5963, bcdDevice= 1.00
[2505754.777825] usb 3-1.4.1: New USB device strings: Mfr=0, Product=0, SerialNumber=0

And after opening the Windows version of NuWriter in VM, the NUC980 disconnected and reconnected with a USB device with Product and Mfr strings.

[2505755.315372] usb 3-1.4.1: reset full-speed USB device number 17 using xhci_hcd
[2505771.296785] usb 3-1.4.1: USB disconnect, device number 17
[2505771.475256] usb 3-1.4.1: new full-speed USB device number 18 using xhci_hcd
[2505771.557161] usb 3-1.4.1: not running at top speed; connect to a high speed hub
[2505771.562162] usb 3-1.4.1: New USB device found, idVendor=0416, idProduct=5963, bcdDevice= 1.00
[2505771.562170] usb 3-1.4.1: New USB device strings: Mfr=1, Product=2, SerialNumber=0
[2505771.562174] usb 3-1.4.1: Product: Nuvoton ARM
[2505771.562177] usb 3-1.4.1: Manufacturer: USB Dev

I guess this is a necessary step before actually flashing the image. However, I haven't observed this behavior when running the Linux version of NuWriter. This may be the problem.

[yachen]

I guess this is a necessary step before actually flashing the image. However, I haven't observed this behavior when running the Linux version of NuWriter. This may be the problem.

That's right. The flash stage is performed by xusb.bin. If you unplug/plug USB cable after program failed, can you see the correct USB device using lsusb commnad?

[ReimuNotMoe]

I guess this is a necessary step before actually flashing the image. However, I haven't observed this behavior when running the Linux version of NuWriter. This may be the problem.

That's right. The flash stage is performed by xusb.bin. If you unplug/plug USB cable after program failed, can you see the correct USB device using lsusb commnad?

Yes, I can.

Today I plugged the NUC980 to a different USB Hub (it's a special one made by me and uses the TI TUSB8041 chip, other hubs generally use VIA or GenesysLogic ones), and now the Linux NuWriter can get through the first step. But it still says Failed. I guess it may be a timing problem?

Or it can be caused by the ASMedia USB controller of my motherboard (Gigabyte X399 AORUS PRO, AMD platform), which is known for not correctly detecting some USB U2F/FIDO Keys. But I haven't encountered any difficulties using MCU programmers like STLink and JLink with it in the past. And the Windows NuWriter is working.

[ReimuNotMoe]

Update: I tried it on my laptop with an Intel CPU, and it worked.

So it may have something to do with compatibility of different USB controllers.

Strace logs (two computers are using the same run.ini and 980uimage):

• AMD - 1st try (image0 ./980uimage Failed): https://pastebin.com/pJT5wBfK
• AMD - 2nd try (Get information failed for Device Failed): https://pastebin.com/xUUvQZRz
• Intel: (first ~500KB due to pastebin size limitation) https://pastebin.com/45W7VRZt

USB controllers on my AMD desktop PC (they're actually made by ASMedia):

01:00.0 USB controller [0c03]: Advanced Micro Devices, Inc. [AMD] X399 Series Chipset USB 3.1 xHCI Controller [1022:43ba] (rev 02)
0a:00.3 USB controller [0c03]: Advanced Micro Devices, Inc. [AMD] USB 3.0 Host controller [1022:145f]
44:00.3 USB controller [0c03]: Advanced Micro Devices, Inc. [AMD] USB 3.0 Host controller [1022:145f]

USB controllers on my Intel laptop:

00:14.0 USB controller [0c03]: Intel Corporation Cannon Lake PCH USB 3.1 xHCI Host Controller [8086:a36d] (rev 10) (prog-if 30 [XHCI])
01:00.2 USB controller [0c03]: NVIDIA Corporation TU116 USB 3.1 Host Controller [10de:1aec] (rev a1) (prog-if 30 [XHCI])

[yachen]

Hi,

We cannot reproduce this problem with our PC. Can you add a delay in nuwriter_cmd/parse.c and see if it works?

        sprintf(XUSB,"%s/%s",NUDATA_PATH,read_xusb_name(nudata.ddr_path));
        xbuf=load_xusb(XUSB,&xlen);
        MSG_DEBUG("XUSB=%s,len=%d\n",XUSB,xlen);
        if(xbuf==NULL) {
                printf("Cannot find xusb.bin\n");
                ret=-1;
                goto EXIT;
        }
        if(XUSBtoDevice(xbuf,xlen)<0) {
                printf("Burn XUSB to Device failed\n");
                ret=-1;
                goto EXIT;
        }
        NUC_CloseUsb();
        sleep(1);  //==========================>Add this line
        while(get_device_num_with_vid_pid(ctx,USB_VENDOR_ID, USB_PRODUCT_ID)!=dev_count) {
                sleep(1);
        }
        ret=NUC_OpenUsb();
        if(ret<0) return -1;
EXIT:

[ReimuNotMoe]

The problem is actually in function UXmodem_SPINAND in UXmodem.c.

The value ack is always zero.

Do you have an idea of what happened?

[ReimuNotMoe]

I turned on your debug macro and added some prints.

And here are the outputs:

argv[1]=run.ini
id=3,mode=SPINAND
DDR ini = NONE/share/nudata/sys_cfg/NUC980DK61Y.ini
nudata.image_num=1
image0_type=0
image0_path=./980uimage
image0_exe_addr=0x00000000
image0_start_offset=0x00200000
ParsingIni END
 (bus 3, device 75)
get count=1
 (bus 3, device 75)
usb port is  3.3.1
head.address=0x00000010,head.filelen=368
write 8/8 bytes to device
write 368/368 bytes to device
receive 4/4 bytes from device
receive 4/4 bytes from device
ack=0x55aa55aa
XUSB=NONE/share/nudata/xusb64.bin,len=54376
sizeof(XBINHEAD)=16
passed xbinhead->address=3f00040
file_len=54360
write 8/8 bytes to device
write 4096/4096 bytes to device
receive 4/4 bytes from device
write 4096/4096 bytes to device
receive 4/4 bytes from device
write 4096/4096 bytes to device
receive 4/4 bytes from device
write 4096/4096 bytes to device
receive 4/4 bytes from device
write 4096/4096 bytes to device
receive 4/4 bytes from device
write 4096/4096 bytes to device
receive 4/4 bytes from device
write 4096/4096 bytes to device
receive 4/4 bytes from device
write 4096/4096 bytes to device
receive 4/4 bytes from device
write 4096/4096 bytes to device
receive 4/4 bytes from device
write 4096/4096 bytes to device
receive 4/4 bytes from device
write 4096/4096 bytes to device
receive 4/4 bytes from device
write 4096/4096 bytes to device
receive 4/4 bytes from device
write 4096/4096 bytes to device
receive 4/4 bytes from device
write 1112/1112 bytes to device
receive 4/4 bytes from device
XUSBtoDevice rcnt=1112,ack=1112
 (bus 3, device 76)
get count=1
 (bus 3, device 76)
usb port is  3.3.1
InfoFromDevice
sizeof(INFO_T) 84 INFO(10)
write 84/84 bytes to device
receive 80/84 bytes from device
receive 4/4 bytes from device
Parsing Run mode
ParseFlashType-SPINAND_M
image0 ./980uimage
write 56/56 bytes to device
receive 4/4 bytes from device
write 4096/4096 bytes to device
receive 4/4 bytes from device
bResult: 0, ack: 0
Failed

The 80/84 mismatch happened here:

[ReimuNotMoe]

Any updates on this?

[schung1218]

Do you have other tools to get more information, eg. USB Protocol Analyzer