wwatson
Well-known member
I am having a minor issue with MSC and USB thumb drives on power up. When I have a T4.x connected to a PC USB port and power up the PC the T4.x will not complete the initialization process. Here is the response:
The USBHub control callback just keeps repeating as seen above.
While the the PC is still powered I unplug the USB cable for the T4.x and plug it back in and get this:
I have tested this with all three versions of MSC and get the same results. It only happens with USB thumb drives. The slowest USB drives I have ever seen All other USB drives like SSD, USB card readers and USB HDD's through a SATA to USB adapter do not seem to exhibit this condition.
This is the test sketch I am using:
I know Paul and Robin are really busy right now with it only being the two of them that are running the show so this post is meant to be a point of reference. It just means if using thumb drives (at least in my case) you may have to power up the PC with the T4.x unplugged then plug it in after the PC is powered up. I am using Linux with the latest Arduino and TD1.52.
I have not seen this problem with USB devices like USB keyboards and USB mice.
Code:
USB2 PLL running
reset waited 6
USBHS_ASYNCLISTADDR = 0
USBHS_PERIODICLISTBASE = 2000E000
periodictable = 2000E000
port change: 10001803
connect
begin reset
port change: 18001205
port enabled
end recovery
new_Device: 480 Mbit/sec
new_Pipe
enumeration:
enumeration:
enumeration:
Device Descriptor:
12 01 00 02 09 00 01 40 E3 05 08 06 63 77 00 01 00 01
VendorID = 05E3, ProductID = 0608, Version = 7763
Class/Subclass/Protocol = 9(Hub) / 0 / 1(Single-TT)
Number of Configurations = 1
enumeration:
enumeration:
Product: USB2.0 Hub
enumeration:
Config data length = 25
enumeration:
Configuration Descriptor:
09 02 19 00 01 01 00 E0 32
NumInterfaces = 1
ConfigurationValue = 1
09 04 00 00 01 09 00 00 00
Interface = 0
Number of endpoints = 1
Class/Subclass/Protocol = 9(Hub) / 0 / 0
07 05 81 03 01 00 0C
Endpoint = 1 IN
Type = Interrupt
Max Size = 1
Polling Interval = 12
enumeration:
USBHub memory usage = 960
USBHub claim_device this=200034C0
found possible interface, altsetting=0
number of interfaces found = 1
USBHub control callback
09 29 04 E0 00 32 64 00 FF 00 00 00 00 00 00 00
Hub ports = 4
USBHub control callback
USBHub control callback
USBHub control callback
USBHub control callback
power turned on to all ports
device addr = 1
new_Pipe
allocate_interrupt_pipe_bandwidth
ep interval = 12
interval = 256
best_bandwidth = 2, at offset = 0
pipe cap1 = F0012101
HUB Callback (member)
status = 2
getstatus, port = 1
USBHub control callback
01 01 01 00
New Port Status
status=10101 port=1
state=0
Device is present:
Has Power
USBHub control callback
Port Status Cleared, port=1
timer event (19999 us): Debounce Timer, this = 200034C0, timer = 200037D8
ports in use bitmask = 2
getstatus, port = 1
USBHub control callback
01 01 00 00
New Port Status
status=101 port=1
state=2
Device is present:
Has Power
timer event (19999 us): Debounce Timer, this = 200034C0, timer = 200037D8
ports in use bitmask = 2
getstatus, port = 1
USBHub control callback
01 01 00 00
New Port Status
status=101 port=1
state=3
Device is present:
Has Power
timer event (19999 us): Debounce Timer, this = 200034C0, timer = 200037D8
ports in use bitmask = 2
getstatus, port = 1
USBHub control callback
01 01 00 00
New Port Status
status=101 port=1
state=4
Device is present:
Has Power
timer event (19999 us): Debounce Timer, this = 200034C0, timer = 200037D8
ports in use bitmask = 2
getstatus, port = 1
USBHub control callback
01 01 00 00
New Port Status
status=101 port=1
state=5
Device is present:
Has Power
timer event (19999 us): Debounce Timer, this = 200034C0, timer = 200037D8
ports in use bitmask = 2
getstatus, port = 1
USBHub control callback
01 01 00 00
New Port Status
status=101 port=1
state=6
Device is present:
Has Power
sending reset
send_setreset
USBHub control callback
unhandled setup, message = 40323
timer event (19999 us): Debounce Timer, this = 200034C0, timer = 200037D8
ports in use bitmask = 0
HUB Callback (member)
status = 2
getstatus, port = 1
USBHub control callback
03 05 10 00
New Port Status
status=100503 port=1
state=7
Device is present:
Enabled, speed = 480 Mbit/sec
Has Power
USBHub control callback
unhandled setup, message = 140123
timer event (29999 us): Hello, I'm resettimer, this = 200034C0, timer = 200037F4
port_doing_reset = 1
PORT_RECOVERY
new_Device: 480 Mbit/sec
new_Pipe
HUB Callback (member)
status = 2
getstatus, port = 1
USBHub control callback
00 01 01 00
New Port Status
status=10100 port=1
state=9
Has Power
disconnect_Device:
USBDriver (available_drivers) list: 2000B880 -> 2000BC40 -> 20003100 -> 2000C660 -> 2000C280
USBDriver (dev->drivers) list: (empty
USBDriver (available_drivers) list: 2000B880 -> 2000BC40 -> 20003100 -> 2000C660 -> 2000C280
delete_Pipe 2000C300
remove QH from async schedule
Free transfers
* 536929472 * remove * free
* 536929536
* 536929408 * remove * defer free until QH
* 536922080
Free transfers attached to QH
* 536929536
* 536929408
* 536921088
* Delete Pipe completed
removed Device_t from devlist
USBHub control callback
Port Status Cleared, port=1
HUB Callback (member)
status = 2
getstatus, port = 1
USBHub control callback
01 01 01 00
New Port Status
status=10101 port=1
state=1
Device is present:
Has Power
USBHub control callback
Port Status Cleared, port=1
timer event (19999 us): Debounce Timer, this = 200034C0, timer = 200037D8
ports in use bitmask = 2
getstatus, port = 1
USBHub control callback
01 01 00 00
New Port Status
status=101 port=1
state=2
Device is present:
Has Power
timer event (19999 us): Debounce Timer, this = 200034C0, timer = 200037D8
ports in use bitmask = 2
getstatus, port = 1
USBHub control callback
01 01 00 00
New Port Status
status=101 port=1
state=3
Device is present:
Has Power
timer event (19999 us): Debounce Timer, this = 200034C0, timer = 200037D8
ports in use bitmask = 2
getstatus, port = 1
USBHub control callback
01 01 00 00
New Port Status
status=101 port=1
state=4
Device is present:
Has Power
timer event (19999 us): Debounce Timer, this = 200034C0, timer = 200037D8
ports in use bitmask = 2
getstatus, port = 1
USBHub control callback
01 01 00 00
New Port Status
status=101 port=1
state=5
Device is present:
Has Power
timer event (19999 us): Debounce Timer, this = 200034C0, timer = 200037D8
ports in use bitmask = 2
getstatus, port = 1
USBHub control callback
01 01 00 00
New Port Status
status=101 port=1
state=6
Device is present:
Has Power
timer event (19999 us): Debounce Timer, this = 200034C0, timer = 200037D8
ports in use bitmask = 2
getstatus, port = 1
USBHub control callback
01 01 00 00
New Port Status
status=101 port=1
state=6
Device is present:
Has Power
timer event (19999 us): Debounce Timer, this = 200034C0, timer = 200037D8
ports in use bitmask = 2
getstatus, port = 1
USBHub control callback
01 01 00 00
New Port Status
status=101 port=1
state=6
Device is present:
Has Power
timer event (19999 us): Debounce Timer, this = 200034C0, timer = 200037D8
ports in use bitmask = 2
getstatus, port = 1
USBHub control callback
01 01 00 00
New Port Status
status=101 port=1
state=6
Device is present:
Has Power
timer event (19999 us): Debounce Timer, this = 200034C0, timer = 200037D8
ports in use bitmask = 2
getstatus, port = 1
USBHub control callback
01 01 00 00
New Port Status
status=101 port=1
state=6
Device is present:
Has Power
timer event (19999 us): Debounce Timer, this = 200034C0, timer = 200037D8
ports in use bitmask = 2
getstatus, port = 1
USBHub control callback
01 01 00 00
New Port Status
status=101 port=1
state=6
Device is present:
Has Power
And just keeps repeating the USBHub control callback...
The USBHub control callback just keeps repeating as seen above.
While the the PC is still powered I unplug the USB cable for the T4.x and plug it back in and get this:
Code:
USB2 PLL running
reset waited 6
USBHS_ASYNCLISTADDR = 0
USBHS_PERIODICLISTBASE = 2000E000
periodictable = 2000E000
port change: 10001803
connect
begin reset
port change: 18001205
port enabled
end recovery
new_Device: 480 Mbit/sec
new_Pipe
enumeration:
enumeration:
enumeration:
Device Descriptor:
12 01 00 02 09 00 01 40 E3 05 08 06 63 77 00 01 00 01
VendorID = 05E3, ProductID = 0608, Version = 7763
Class/Subclass/Protocol = 9(Hub) / 0 / 1(Single-TT)
Number of Configurations = 1
enumeration:
enumeration:
Product: USB2.0 Hub
enumeration:
Config data length = 25
enumeration:
Configuration Descriptor:
09 02 19 00 01 01 00 E0 32
NumInterfaces = 1
ConfigurationValue = 1
09 04 00 00 01 09 00 00 00
Interface = 0
Number of endpoints = 1
Class/Subclass/Protocol = 9(Hub) / 0 / 0
07 05 81 03 01 00 0C
Endpoint = 1 IN
Type = Interrupt
Max Size = 1
Polling Interval = 12
enumeration:
USBHub memory usage = 960
USBHub claim_device this=200034C0
found possible interface, altsetting=0
number of interfaces found = 1
USBHub control callback
09 29 04 E0 00 32 64 00 FF 00 00 00 00 00 00 00
Hub ports = 4
USBHub control callback
USBHub control callback
USBHub control callback
USBHub control callback
power turned on to all ports
device addr = 1
new_Pipe
allocate_interrupt_pipe_bandwidth
ep interval = 12
interval = 256
best_bandwidth = 2, at offset = 0
pipe cap1 = F0012101
HUB Callback (member)
status = 2
getstatus, port = 1
USBHub control callback
01 01 01 00
New Port Status
status=10101 port=1
state=0
Device is present:
Has Power
USBHub control callback
Port Status Cleared, port=1
timer event (19999 us): Debounce Timer, this = 200034C0, timer = 200037D8
ports in use bitmask = 2
getstatus, port = 1
USBHub control callback
01 01 00 00
New Port Status
status=101 port=1
state=2
Device is present:
Has Power
timer event (19999 us): Debounce Timer, this = 200034C0, timer = 200037D8
ports in use bitmask = 2
getstatus, port = 1
USBHub control callback
01 01 00 00
New Port Status
status=101 port=1
state=3
Device is present:
Has Power
timer event (19999 us): Debounce Timer, this = 200034C0, timer = 200037D8
ports in use bitmask = 2
getstatus, port = 1
USBHub control callback
01 01 00 00
New Port Status
status=101 port=1
state=4
Device is present:
Has Power
timer event (19999 us): Debounce Timer, this = 200034C0, timer = 200037D8
ports in use bitmask = 2
getstatus, port = 1
USBHub control callback
01 01 00 00
New Port Status
status=101 port=1
state=5
Device is present:
Has Power
timer event (19999 us): Debounce Timer, this = 200034C0, timer = 200037D8
ports in use bitmask = 2
getstatus, port = 1
USBHub control callback
01 01 00 00
New Port Status
status=101 port=1
state=6
Device is present:
Has Power
sending reset
send_setreset
USBHub control callback
unhandled setup, message = 40323
timer event (19999 us): Debounce Timer, this = 200034C0, timer = 200037D8
ports in use bitmask = 0
HUB Callback (member)
status = 2
getstatus, port = 1
USBHub control callback
03 05 10 00
New Port Status
status=100503 port=1
state=7
Device is present:
Enabled, speed = 480 Mbit/sec
Has Power
USBHub control callback
unhandled setup, message = 140123
timer event (29999 us): Hello, I'm resettimer, this = 200034C0, timer = 200037F4
port_doing_reset = 1
PORT_RECOVERY
new_Device: 480 Mbit/sec
new_Pipe
enumeration:
enumeration:
enumeration:
Device Descriptor:
12 01 10 02 00 00 00 40 51 09 66 16 01 00 01 02 03 01
VendorID = 0951, ProductID = 1666, Version = 0001
Class/Subclass/Protocol = 0 / 0 / 0
Number of Configurations = 1
enumeration:
enumeration:
Manufacturer: Kingston
enumeration:
Product: DataTraveler 3.0
enumeration:
Serial Number: D067E516489AF1B0B60F06F0
enumeration:
Config data length = 32
enumeration:
Configuration Descriptor:
09 02 20 00 01 01 00 80 96
NumInterfaces = 1
ConfigurationValue = 1
09 04 00 00 02 08 06 50 00
Interface = 0
Number of endpoints = 2
Class/Subclass/Protocol = 8(Mass Storage) / 6(SCSI) / 80(Bulk Only)
07 05 81 02 00 02 FF
Endpoint = 1 IN
Type = Bulk
Max Size = 512
Polling Interval = 255
07 05 02 02 00 02 FF
Endpoint = 2 OUT
Type = Bulk
Max Size = 512
Polling Interval = 255
enumeration:
USBHub memory usage = 960
USBHub claim_device this=2000B880
USBHub memory usage = 960
USBHub claim_device this=2000BC40
USBHub memory usage = 960
USBHub claim_device this=20003100
msController claim this=2000C660
msController claim this=2000C280
Descriptor 4 = INTERFACE
msController claim this=2000C660
09 04 00 00 02 08 06 50 00 07 05 81 02 00 02 FF 07 05 02 02 00 02 FF
numendpoint=2
endpointIn=81
endpointOut=2
packet size in (msController) = 512
packet size out (msController) = 512
polling intervalIn = 255
polling intervalOut = 255
new_Pipe
new_Pipe
Descriptor 5 = ENDPOINT
Descriptor 5 = ENDPOINT
I have tested this with all three versions of MSC and get the same results. It only happens with USB thumb drives. The slowest USB drives I have ever seen All other USB drives like SSD, USB card readers and USB HDD's through a SATA to USB adapter do not seem to exhibit this condition.
This is the test sketch I am using:
Code:
#include "Arduino.h"
#include "MassStorage.h"
#include "msc.h"
USBHost myusb;
USBHub hub1(myusb);
USBHub hub2(myusb);
USBHub hub3(myusb);
USBHub hub4(myusb);
void setup() {
while(!Serial);
Serial.printf("Sketch to demonstrate power up problem with MSC and USBHost_t36\n");
Serial.printf("Debug output must be uncommented in USBHost_t36.h\n");
myusb.begin();
}
void loop() {
}
I know Paul and Robin are really busy right now with it only being the two of them that are running the show so this post is meant to be a point of reference. It just means if using thumb drives (at least in my case) you may have to power up the PC with the T4.x unplugged then plug it in after the PC is powered up. I am using Linux with the latest Arduino and TD1.52.
I have not seen this problem with USB devices like USB keyboards and USB mice.