search

magnusja / libaums

Open source library to access USB Mass Storage devices on Android without rooting your device
Apache License 2.0
1.26k stars 270 forks source link

crash when calling init method of UsbMassStorageDevice. #384

Open melonsherbet opened 1 year ago

melonsherbet commented 1 year ago

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());
    }
}
magnusja commented 1 year ago

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

xzeman43 commented 1 year ago

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....

magnusja commented 1 year ago

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.

xzeman43 commented 1 year ago

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 commented 1 year ago

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.

viktor76525 commented 1 year ago

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.

xzeman43 commented 1 year ago

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.