libaums icon indicating copy to clipboard operation
libaums copied to clipboard

crash when calling init method of UsbMassStorageDevice.

Open airheadork opened this issue 2 years ago • 7 comments

Problem

crash when setup device

Expected behavior

succed to get the root directory

Actual behavior

crash when calling init method of UsbMassStorageDevice.

Stacktrace of Excpetion

FATAL EXCEPTION: main
Process: com.aispeech.dui.dds.usbotgdemo, PID: 1252
java.lang.RuntimeException: Error receiving broadcast Intent { act=com.newsmy.farosh.USB_PERMISSION flg=0x10 hwFlg=0x100 (has extras) } in com.aispeech.dui.dds.usbotgdemo.MainActivity$1@e688b84
	at android.app.LoadedApk$ReceiverDispatcher$Args.lambda$getRunnable$0$LoadedApk$ReceiverDispatcher$Args(LoadedApk.java:1796)
	at android.app.-$$Lambda$LoadedApk$ReceiverDispatcher$Args$_BumDX2UKsnxLVrE6UJsJZkotuA.run(Unknown Source:2)
	at android.os.Handler.handleCallback(Handler.java:900)
	at android.os.Handler.dispatchMessage(Handler.java:103)
	at android.os.Looper.loop(Looper.java:219)
	at android.app.ActivityThread.main(ActivityThread.java:8668)
	at java.lang.reflect.Method.invoke(Native Method)
	at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:513)
	at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:1109)
Caused by: java.lang.IllegalArgumentException
	at java.nio.Buffer.limit(Buffer.java:290)
	at java.nio.ByteBuffer.limit(ByteBuffer.java:818)
	at me.jahnen.libaums.core.driver.scsi.ScsiBlockDevice.transferOneCommand(ScsiBlockDevice.kt:270)
	at me.jahnen.libaums.core.driver.scsi.ScsiBlockDevice.transferCommand(ScsiBlockDevice.kt:154)
	at me.jahnen.libaums.core.driver.scsi.ScsiBlockDevice.initAttempt(ScsiBlockDevice.kt:105)
	at me.jahnen.libaums.core.driver.scsi.ScsiBlockDevice.init(ScsiBlockDevice.kt:83)
	at me.jahnen.libaums.core.UsbMassStorageDevice.setupDevice(UsbMassStorageDevice.kt:138)
	at me.jahnen.libaums.core.UsbMassStorageDevice.init(UsbMassStorageDevice.kt:100)
	at com.aispeech.dui.dds.usbotgdemo.MainActivity.setupDevice(MainActivity.java:118)
	at com.aispeech.dui.dds.usbotgdemo.MainActivity.access$000(MainActivity.java:25)
	at com.aispeech.dui.dds.usbotgdemo.MainActivity$1.onReceive(MainActivity.java:42)
	at android.app.LoadedApk$ReceiverDispatcher$Args.lambda$getRunnable$0$LoadedApk$ReceiverDispatcher$Args(LoadedApk.java:1786)
	at android.app.-$$Lambda$LoadedApk$ReceiverDispatcher$Args$_BumDX2UKsnxLVrE6UJsJZkotuA.run(Unknown Source:2) 
	at android.os.Handler.handleCallback(Handler.java:900) 
	at android.os.Handler.dispatchMessage(Handler.java:103) 
	at android.os.Looper.loop(Looper.java:219) 
	at android.app.ActivityThread.main(ActivityThread.java:8668) 
	at java.lang.reflect.Method.invoke(Native Method) 
	at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:513) 
	at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:1109) 

Code where problem occurs

discoverDevice

	usbManager = (UsbManager) getSystemService(Context.USB_SERVICE);
	massStorageDevices = UsbMassStorageDevice.getMassStorageDevices(this);
	if (massStorageDevices.length == 0){
		return;
	}
	usbDevice = intent.getParcelableExtra(UsbManager.EXTRA_DEVICE);

	Log.i("MainActivity :: " , "usbManager.hasPermission == " + usbManager.hasPermission(usbDevice));

	if (usbDevice != null && usbManager.hasPermission(usbDevice)){
		setupDevice();
	}else {
		PendingIntent pendingIntent = PendingIntent.getBroadcast(this
				, 0, new Intent(ACTION_USB_PERMISSION), 0);
		usbManager.requestPermission(massStorageDevices[0].getUsbDevice(), pendingIntent);
	}
}

setup Device

private void setupDevice() {
	try {
		Log.e("MainActivity", "massStorageDevices size: " + massStorageDevices.length);
		massStorageDevices[0].init();
		Log.i("MainActivity", "massStorageDevices init success ");
		// we always use the first partition of the device
		FileSystem currentFs = massStorageDevices[0].getPartitions().get(0).getFileSystem();
		UsbFile root = currentFs.getRootDirectory();
		textView.setText(root.getName());

	} catch (IOException e) {
		Log.i("MainActivity", "setupDevice: exception == "+ e.getMessage());
	}
}

airheadork avatar Mar 20 '23 07:03 airheadork

Hmm can you tell me what the value of position and transfer length are, here: https://github.com/magnusja/libaums/blob/develop/libaums/src/main/java/me/jahnen/libaums/core/driver/scsi/ScsiBlockDevice.kt#L270

magnusja avatar Mar 20 '23 15:03 magnusja

Hello Magnus, seems like I have a similar issue. In my case, it dies when the transfer length and position are both 18 (it's not right on the first call of transferOneCommand, but the third? one). The code can be traced up to line 280 (as indicated in the error log below) and then jump straight to the Illegal argument exception...

java.lang.IllegalArgumentException
13:48:12.269  W  	at java.nio.Buffer.limit(Buffer.java:290)
13:48:12.275  W  	at java.nio.ByteBuffer.limit(ByteBuffer.java:818)
13:48:12.281  W  	at me.jahnen.libaums.core.driver.scsi.ScsiBlockDevice.transferOneCommand(ScsiBlockDevice.kt:280)
13:48:12.286  W  	at me.jahnen.libaums.core.driver.scsi.ScsiBlockDevice.requestSense(ScsiBlockDevice.kt:222)
13:48:12.300  W  	at me.jahnen.libaums.core.driver.scsi.ScsiBlockDevice.handleCommandResult(ScsiBlockDevice.kt:207)
13:48:12.305  W  	at me.jahnen.libaums.core.driver.scsi.ScsiBlockDevice.transferCommand(ScsiBlockDevice.kt:155)
13:48:12.310  W  	at me.jahnen.libaums.core.driver.scsi.ScsiBlockDevice.transferCommandWithoutDataPhase(ScsiBlockDevice.kt:199)
13:48:12.314  W  	at me.jahnen.libaums.core.driver.scsi.ScsiBlockDevice.initAttempt(ScsiBlockDevice.kt:115)
13:48:12.318  W  	at me.jahnen.libaums.core.driver.scsi.ScsiBlockDevice.init(ScsiBlockDevice.kt:83)
13:48:12.322  W  	at me.jahnen.libaums.core.UsbMassStorageDevice.setupDevice(UsbMassStorageDevice.kt:138)
13:48:12.327  W  	at me.jahnen.libaums.core.UsbMassStorageDevice.init(UsbMassStorageDevice.kt:100)
13:48:12.331  W  	at cz.test.MainActivity.readOutCurrSettings(MainActivity.java:1110)
13:48:12.335  W  	at cz.test.MainActivity$9.onReceive(MainActivity.java:1031)
13:48:12.339  W  	at android.app.LoadedApk$ReceiverDispatcher$Args.lambda$getRunnable$0$LoadedApk$ReceiverDispatcher$Args(LoadedApk.java:1646)
13:48:12.343  W  	at android.app.-$$Lambda$LoadedApk$ReceiverDispatcher$Args$_BumDX2UKsnxLVrE6UJsJZkotuA.run(Unknown Source:2)
13:48:12.347  W  	at android.os.Handler.handleCallback(Handler.java:883)
13:48:12.354  W  	at android.os.Handler.dispatchMessage(Handler.java:100)
13:48:12.356  W  	at android.os.Looper.loop(Looper.java:237)
13:48:12.358  W  	at android.app.ActivityThread.main(ActivityThread.java:8167)
13:48:12.359  W  	at java.lang.reflect.Method.invoke(Native Method)
13:48:12.361  W  	at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:496)
13:48:12.363  W  	at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:1100)

Other than that, the issue emerges after I call device.init(). The device is retrieved by UsbMassStorageDevice.getMassStorageDevices and interestingly enough, for one USB flash drive it failed, but other it went through...

Not sure if it will help or not, but these are the test devices USBDevices read out by the library:

THIS is the one that is not working correctly

found usb device:
/dev/bus/usb/001/003=UsbDevice[mName=/dev/bus/usb/001/003,mVendorId=1423,mProductId=25479,mClass=0,mSubclass=0,mProtocol=0,mManufacturerName=USB,mProductName=Mass Storage,mVersion=1.03,mSerialNumberReader=android.hardware.usb.IUsbSerialReader$Stub$Proxy@f2660a0,mConfigurations=[
                UsbConfiguration[mId=1,mName=null,mAttributes=128,mMaxPower=50,mInterfaces=[
                UsbInterface[mId=0,mAlternateSetting=0,mName=null,mClass=8,mSubclass=6,mProtocol=80,mEndpoints=[
                UsbEndpoint[mAddress=1,mAttributes=2,mMaxPacketSize=512,mInterval=0]
                UsbEndpoint[mAddress=130,mAttributes=2,mMaxPacketSize=512,mInterval=0]]]]
14:13:00.067  I  Found usb interface: UsbInterface[mId=0,mAlternateSetting=0,mName=null,mClass=8,mSubclass=6,mProtocol=80,mEndpoints=[
                UsbEndpoint[mAddress=1,mAttributes=2,mMaxPacketSize=512,mInterval=0]
                UsbEndpoint[mAddress=130,mAttributes=2,mMaxPacketSize=512,mInterval=0]]
14:13:00.068  I  Found usb endpoint: UsbEndpoint[mAddress=1,mAttributes=2,mMaxPacketSize=512,mInterval=0]
14:13:00.069  I  Found usb endpoint: UsbEndpoint[mAddress=130,mAttributes=2,mMaxPacketSize=512,mInterval=0]

This one initializes ok

found usb device: /dev/bus/usb/001/002=UsbDevice[mName=/dev/bus/usb/001/002,mVendorId=2385,mProductId=5658,mClass=0,mSubclass=0,mProtocol=0,mManufacturerName=Kingston,mProductName=DataTraveler 410,mVersion=1.00,mSerialNumberReader=android.hardware.usb.IUsbSerialReader$Stub$Proxy@e7e6579,mConfigurations=[
                 UsbConfiguration[mId=1,mName=null,mAttributes=128,mMaxPower=150,mInterfaces=[
                 UsbInterface[mId=0,mAlternateSetting=0,mName=null,mClass=8,mSubclass=6,mProtocol=80,mEndpoints=[
                 UsbEndpoint[mAddress=129,mAttributes=2,mMaxPacketSize=512,mInterval=0]
                 UsbEndpoint[mAddress=2,mAttributes=2,mMaxPacketSize=512,mInterval=0]]]]
14:10:53.709  I  Found usb interface: UsbInterface[mId=0,mAlternateSetting=0,mName=null,mClass=8,mSubclass=6,mProtocol=80,mEndpoints=[
                 UsbEndpoint[mAddress=129,mAttributes=2,mMaxPacketSize=512,mInterval=0]
                 UsbEndpoint[mAddress=2,mAttributes=2,mMaxPacketSize=512,mInterval=0]]
14:10:53.710  I  Found usb endpoint: UsbEndpoint[mAddress=129,mAttributes=2,mMaxPacketSize=512,mInterval=0]
14:10:53.710  I  Found usb endpoint: UsbEndpoint[mAddress=2,mAttributes=2,mMaxPacketSize=512,mInterval=0]

If there will be anything you need from me just let me know I will try to provide as much information as I can....

xzeman43 avatar Mar 22 '23 13:03 xzeman43

So your device fails when trying to test if the unit is ready. The OP has the problem that the ScsiInquiry does not work.

So afaik testing if the unit is ready, has no data phase. But your device seems to respond with some more data.

magnusja avatar Mar 23 '23 18:03 magnusja

Then I am sorry for exploiting this thread. However, it is interesting that both devices are standard USB disks formatted to the same filesystem. I will try to dig deeper and find out why they do no behave the same.

xzeman43 avatar Mar 24 '23 06:03 xzeman43

So your device fails when trying to test if the unit is ready. The OP has the problem that the ScsiInquiry does not work.

So afaik testing if the unit is ready, has no data phase. But your device seems to respond with some more data.

Hello, so quick update on the issue you described. For whatever reason I did not see it straight away but it seems that the error occurs if the device.init() happens too fast after the device attachment. When I launch the procedure straight from UsbManager.ACTION_USB_DEVICE_ATTACHED callback without any delay, 99/100 attempts fail on the java.lang.IllegalArgumentException .However, when I introduce a slight delay (one sec seems stable) after the USB attach event, it works flawlessly. Maybe it will be a pleasant update to have a method that will be checking for this specific issue - it seems like after the USB attach broadcast, there is still some initialization running in the background that messes up with your library.

xzeman43 avatar Mar 27 '23 15:03 xzeman43

Hello, I also bumped into this regression. The workaround is to wait 900+ms before calling init. It only happens on certain USB drives, not sandisk, mostly older usb 2 and no-name ones. It was ok on 0.9.1, couldn't get intermediate versions to build due to some dependency issues, and then it is in both 0.9.4 and 0.10.0.

viktor76525 avatar May 11 '23 01:05 viktor76525

Hello, I also bumped into this regression. The workaround is to wait 900+ms before calling init. It only happens on certain USB drives, not sandisk, mostly older usb 2 and no-name ones. It was ok on 0.9.1, couldn't get intermediate versions to build due to some dependency issues, and then it is in both 0.9.4 and 0.10.0.

Yes, that seems in line with my observations. But still, from time to time it breaks the connection with the device and it has to be reconnected. So the solution was quick and easy to implement, but somehow its not 100% bulletproof.

xzeman43 avatar May 11 '23 06:05 xzeman43