Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Incoming_packet : Read Error (-1)! on v1.0.0 #27

Closed
smokeythebandit opened this issue Oct 21, 2019 · 15 comments
Closed

Incoming_packet : Read Error (-1)! on v1.0.0 #27

smokeythebandit opened this issue Oct 21, 2019 · 15 comments

Comments

@smokeythebandit
Copy link

smokeythebandit commented Oct 21, 2019

Seems like v1.0.0 offers much improvements over previous versions, nice going!

I've tried running v1.0.0 on our iMX.6 based product, but there is an USB read error.

UMTP outputs this information:

Oct 21 10:35:25 Voyagerk46xOO sudo[475]: [uMTPrd - 10:35:25 - Info] uMTP Responder
Oct 21 10:35:25 Voyagerk46xOO sudo[475]: [uMTPrd - 10:35:25 - Info] Version: v1.0.0 compiled the Oct 21 2019@11:34:59
Oct 21 10:35:25 Voyagerk46xOO sudo[475]: [uMTPrd - 10:35:25 - Info] (c) 2018 - 2019 Viveris Technologies
Oct 21 10:35:25 Voyagerk46xOO sudo[475]: [uMTPrd - 10:35:25 - Info] Add storage Projects - Root Path: /Voyager/Projects - Flags: 0x00000000
Oct 21 10:35:25 Voyagerk46xOO sudo[475]: [uMTPrd - 10:35:25 - Info] Add storage Licenses - Root Path: /Voyager/Licenses - Flags: 0x00000000
Oct 21 10:35:25 Voyagerk46xOO sudo[475]: [uMTPrd - 10:35:25 - Info] USB Device path : /dev/umtp/ep0
Oct 21 10:35:25 Voyagerk46xOO sudo[475]: [uMTPrd - 10:35:25 - Info] USB In End point path : /dev/umtp/ep1
Oct 21 10:35:25 Voyagerk46xOO sudo[475]: [uMTPrd - 10:35:25 - Info] USB Out End point path : /dev/umtp/ep2
Oct 21 10:35:25 Voyagerk46xOO sudo[475]: [uMTPrd - 10:35:25 - Info] USB Event End point path : /dev/umtp/ep3
Oct 21 10:35:25 Voyagerk46xOO sudo[475]: [uMTPrd - 10:35:25 - Info] USB Max packet size : 0x200 bytes
Oct 21 10:35:25 Voyagerk46xOO sudo[475]: [uMTPrd - 10:35:25 - Info] Manufacturer string : Microflown Technologies B.V.
Oct 21 10:35:25 Voyagerk46xOO sudo[475]: [uMTPrd - 10:35:25 - Info] Product string : Voyager
Oct 21 10:35:25 Voyagerk46xOO sudo[475]: [uMTPrd - 10:35:25 - Info] Serial string : 0000000
Oct 21 10:35:25 Voyagerk46xOO sudo[475]: [uMTPrd - 10:35:25 - Info] Interface string : MTP
Oct 21 10:35:25 Voyagerk46xOO sudo[475]: [uMTPrd - 10:35:25 - Info] USB Vendor ID : 0x1D6B
Oct 21 10:35:25 Voyagerk46xOO sudo[475]: [uMTPrd - 10:35:25 - Info] USB Product ID : 0x0100
Oct 21 10:35:25 Voyagerk46xOO sudo[475]: [uMTPrd - 10:35:25 - Info] USB class ID : 0x06
Oct 21 10:35:25 Voyagerk46xOO sudo[475]: [uMTPrd - 10:35:25 - Info] USB subclass ID : 0x01
Oct 21 10:35:25 Voyagerk46xOO sudo[475]: [uMTPrd - 10:35:25 - Info] USB Protocol ID : 0x01
Oct 21 10:35:25 Voyagerk46xOO sudo[475]: [uMTPrd - 10:35:25 - Info] USB Device version : 0x3008
Oct 21 10:35:25 Voyagerk46xOO sudo[475]: [uMTPrd - 10:35:25 - Info] USB FunctionFS Mode
Oct 21 10:35:25 Voyagerk46xOO sudo[475]: [uMTPrd - 10:35:25 - Info] Wait for connection : 0
Oct 21 10:35:25 Voyagerk46xOO sudo[475]: [uMTPrd - 10:35:25 - Info] Loop on disconnect : 1
Oct 21 10:35:25 Voyagerk46xOO sudo[475]: [uMTPrd - 10:35:25 - Info] Show hidden files : 1
Oct 21 10:35:25 Voyagerk46xOO sudo[475]: [uMTPrd - 10:35:25 - Info] inotify : yes
Oct 21 10:35:25 Voyagerk46xOO sudo[476]: pam_unix(sudo:session): session closed for user root
Oct 21 10:35:25 Voyagerk46xOO systemd[1]: Started umtp startup.
Oct 21 10:35:31 Voyagerk46xOO sudo[475]: [uMTPrd - 10:35:31 - Error] incoming_packet : Read Error (-1)!
Oct 21 10:47:07 Voyagerk46xOO sudo[475]: [uMTPrd - 10:47:07 - Error] incoming_packet : Read Error (-1)!
Oct 21 10:47:14 Voyagerk46xOO sudo[475]: [uMTPrd - 10:47:14 - Error] incoming_packet : Read Error (-1)!

Was previously working on v0.14.1
Device does show up on both Windows 10 and Debian, but neither of them can see the mounted storage.
Our host device runs kernel 5.2.19 with an realtime patch.

@smokeythebandit
Copy link
Author

When I change usb_max_packet_size from 0x200 to 0x100 umtp sometimes works.

@jfdelnero
Copy link
Member

Can you rebuild the umtpd with the "DEBUG" flag and post the result ?

@a1ien
Copy link

a1ien commented Oct 29, 2019

same error

[uMTPrd - 13:24:34 - Info] USB Device path : /dev/ffs-mtp/ep0
[uMTPrd - 13:24:34 - Info] USB In End point path : /dev/ffs-mtp/ep1
[uMTPrd - 13:24:34 - Info] USB Out End point path : /dev/ffs-mtp/ep2
[uMTPrd - 13:24:34 - Info] USB Event End point path : /dev/ffs-mtp/ep3
[uMTPrd - 13:24:34 - Info] USB Max packet size : 0x200 bytes
[uMTPrd - 13:24:34 - Info] Manufacturer string : Viveris Technologies
[uMTPrd - 13:24:34 - Info] Product string : The Viveris Product !
[uMTPrd - 13:24:34 - Info] Serial string : 01234567
[uMTPrd - 13:24:34 - Info] Interface string : MTP
[uMTPrd - 13:24:34 - Info] USB Vendor ID : 0x1D6B
[uMTPrd - 13:24:34 - Info] USB Product ID : 0x0100
[uMTPrd - 13:24:34 - Info] USB class ID : 0x06
[uMTPrd - 13:24:34 - Info] USB subclass ID : 0x01
[uMTPrd - 13:24:34 - Info] USB Protocol ID : 0x01
[uMTPrd - 13:24:34 - Info] USB Device version : 0x3008
[uMTPrd - 13:24:34 - Info] USB FunctionFS Mode
[uMTPrd - 13:24:34 - Info] Wait for connection : 0
[uMTPrd - 13:24:34 - Info] Loop on disconnect : 1
[uMTPrd - 13:24:34 - Info] Show hidden files : 1
[uMTPrd - 13:24:34 - Info] inotify : yes
[uMTPrd - 13:24:34 - Debug] fill_if_descriptor:
[uMTPrd - 13:24:34 - Debug] 09 04 00 00 03 06 01 01 01                       .........        
[uMTPrd - 13:24:34 - Debug] fill_ep_descriptor:
[uMTPrd - 13:24:34 - Debug] 07 05 81 02 00 02 00                             .......          
[uMTPrd - 13:24:34 - Debug] fill_ep_descriptor:
[uMTPrd - 13:24:34 - Debug] 07 05 02 02 00 02 00                             .......          
[uMTPrd - 13:24:34 - Debug] fill_ep_descriptor:
[uMTPrd - 13:24:34 - Debug] 07 05 83 03 1C 00 06                             .......          
[uMTPrd - 13:24:34 - Debug] fill_if_descriptor:
[uMTPrd - 13:24:34 - Debug] 09 04 00 00 03 06 01 01 01                       .........        
[uMTPrd - 13:24:34 - Debug] fill_ep_descriptor:
[uMTPrd - 13:24:34 - Debug] 07 05 81 02 00 02 00                             .......          
[uMTPrd - 13:24:34 - Debug] fill_ep_descriptor:
[uMTPrd - 13:24:34 - Debug] 07 05 02 02 00 02 00                             .......          
[uMTPrd - 13:24:34 - Debug] fill_ep_descriptor:
[uMTPrd - 13:24:34 - Debug] 07 05 83 03 1C 00 06                             .......          
[uMTPrd - 13:24:34 - Debug] init_usb_mtp_gadget :
[uMTPrd - 13:24:34 - Debug] 03 00 00 00 50 00 00 00 03 00 00 00 04 00 00 00  ....P........... 
[uMTPrd - 13:24:34 - Debug] 04 00 00 00 09 04 00 00 03 06 01 01 01 07 05 81  ................ 
[uMTPrd - 13:24:34 - Debug] 02 00 02 00 07 05 02 02 00 02 00 07 05 83 03 1C  ................ 
[uMTPrd - 13:24:34 - Debug] 00 06 09 04 00 00 03 06 01 01 01 07 05 81 02 00  ................ 
[uMTPrd - 13:24:34 - Debug] 02 00 07 05 02 02 00 02 00 07 05 83 03 1C 00 06  ................ 
[uMTPrd - 13:24:34 - Debug] write string :
[uMTPrd - 13:24:34 - Debug] 02 00 00 00 16 00 00 00 01 00 00 00 01 00 00 00  ................ 
[uMTPrd - 13:24:34 - Debug] 09 04 4D 54 50 00 00 00 00 00 00 00 00 00 00 00  ..MTP........... 
[uMTPrd - 13:24:34 - Debug] 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00  ................ 
[uMTPrd - 13:24:34 - Debug] 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00  ................ 
[uMTPrd - 13:24:34 - Debug] 00 00 00 00 00 00 00 00 00 00 00 [ 1725.808689] read strings
00 00 00 00 00  ................ 
[uMTPrd - 13:24:34 - Debug] 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00  ................ 
[uMTPrd - 13:24:34 - Debug] 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00  ................ 
[uMTPrd - 13:24:34 - Debug] 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00  ................ 
[uMTPrd - 13:24:34 - Debug] 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00  ................ 
[uMTPrd - 13:24:34 - Debug] 00 00                                            ..               
[uMTPrd - 13:24:34 - Debug] init_usb_mtp_gadget : USB config done
[uMTPrd - 13:24:34 - Debug] uMTP Responder : FunctionFS Mode - entering handle_ffs_ep0
[uMTPrd - 13:24:34 - Debug] handle_ffs_ep0 : Entering...
# ls /sys/class/udc/ > cfg/usb_gadget/g1/UDC
[uMTPrd - 13:24:42 - Debug] 1 event(s)
[uMTPrd - 13:24:42 - Debug] EP0 FFS BIND
[uMTPrd - 13:24:42 - Debug] Select without timeout
# [ 1734.040503] configfs-gadget gadget: high-speed config #1: c
[uMTPrd - 13:24:42 - Debug] 1 event(s)
[uMTPrd - 13:24:42 - Debug] EP0 FFS ENABLE
[uMTPrd - 13:24:42 - Debug] Init end point /dev/ffs-mtp/ep1 (0)
[uMTPrd - 13:24:42 - Debug] init_ep (0):
[uMTPrd - 13:24:42 - Debug] 01 00 00 00 07 05 81 02 00 02 00 07 05 81 02 00  ................ 
[uMTPrd - 13:24:42 - Debug] 02 00                                            ..               
[uMTPrd - 13:24:42 - Debug] init_ep (0): FunctionFS Mode - Don't write the endpoint descriptor.
[uMTPrd - 13:24:42 - Debug] Init end point /dev/ffs-mtp/ep2 (1)
[uMTPrd - 13:24:42 - Debug] init_ep (1):
[uMTPrd - 13:24:42 - Debug] 01 00 00 00 07 05 02 02 00 02 00 07 05 02 02 00  ................ 
[uMTPrd - 13:24:42 - Debug] 02 00                                            ..               
[uMTPrd - 13:24:42 - Debug] init_ep (1): FunctionFS Mode - Don't write the endpoint descriptor.
[uMTPrd - 13:24:42 - Debug] Init end point /dev/ffs-mtp/ep3 (2)
[uMTPrd - 13:24:42 - Debug] init_ep (2):
[uMTPrd - 13:24:42 - Debug] 01 00 00 00 07 05 83 03 1C 00 06 07 05 83 03 1C  ................ 
[uMTPrd - 13:24:42 - Debug] 00 06                                            ..               
[uMTPrd - 13:24:42 - Debug] init_ep (2): FunctionFS Mode - Don't write the endpoint descriptor.
[uMTPrd - 13:24:42 - Debug] Select without timeout
[uMTPrd - 13:24:51 - Error] incoming_packet : Read Error (-1)!
[uMTPrd - 13:24:51 - Debug] 1 event(s)
[uMTPrd - 13:24:51 - Debug] EP0 FFS DISABLE
[uMTPrd - 13:24:51 - Debug] deinit_fs_db called
[uMTPrd - 13:24:51 - Debug] Select without timeout
[ 1742.866694] configfs-gadget gadget: high-speed config #1: c
[uMTPrd - 13:24:51 - Debug] 1 event(s)
[uMTPrd - 13:24:51 - Debug] EP0 FFS ENABLE
[uMTPrd - 13:24:51 - Debug] Select without timeout

@a1ien
Copy link

a1ien commented Oct 29, 2019

2106863 broken commit
If revert all work good

@a1ien
Copy link

a1ien commented Oct 29, 2019

also after e075230 I see many reset on usb

[  359.029142] usb 1-1: reset high-speed USB device number 2 using ci_hdrc
[  364.026522] usb 1-1: reset high-speed USB device number 2 using ci_hdrc
[  366.536551] usb 1-1: reset high-speed USB device number 2 using ci_hdrc
[  369.026542] usb 1-1: reset high-speed USB device number 2 using ci_hdrc
[  373.846474] usb 1-1: reset high-speed USB device number 2 using ci_hdrc

@jfdelnero
Copy link
Member

@a1ien : Same target ? (i.MX 6 ?)

@a1ien
Copy link

a1ien commented Oct 29, 2019

Yes, same target. And same kernel version. But without realtime patch

@jfdelnero
Copy link
Member

Can you try to just change CONFIG_MAX_TX_USB_BUFFER_SIZE and CONFIG_MAX_RX_USB_BUFFER_SIZE to 2048 ?

@a1ien
Copy link

a1ien commented Oct 30, 2019

With this config

#define CONFIG_MAX_TX_USB_BUFFER_SIZE (4*512)   // Must be a multiple of 512 and less than CONFIG_READ_FILE_BUFFER_SIZE 
#define CONFIG_MAX_RX_USB_BUFFER_SIZE (4*512)

work. But low speed( around 6.7MB/s) and periodical kernel print

[  949.297272] usb 1-1: reset high-speed USB device number 2 using ci_hdrc
[  951.797233] usb 1-1: reset high-speed USB device number 2 using ci_hdrc
[  956.817297] usb 1-1: reset high-speed USB device number 2 using ci_hdrc
[  986.797248] usb 1-1: reset high-speed USB device number 2 using ci_hdrc

If if change CONFIG_READ_FILE_BUFFER_SIZE to 16*1024
I get seeped around 3.7MB/s and no kernel message.

@jfdelnero
Copy link
Member

jfdelnero commented Oct 30, 2019

Ok thanks. It is quite strange that reducing CONFIG_READ_FILE_BUFFER_SIZE suppress the kernel message. It looks like there is a timing or USB buffer overflow issue in the iMX USB driver. Reducing these buffers just make uMTPrd slower and write and read data chunk size to the usb stack are lower.
I am not sure yet if this a uMTPrd or a iMX USB driver issue. At least now we know the workaround.
This may need to turn these build configuration into some config file options.

@jfdelnero
Copy link
Member

@a1ien
I have just added the possibility to set the buffers size in the config file. All is on the trunk.
Can you test this version ?

@a1ien
Copy link

a1ien commented Nov 18, 2019

I will try this Wednesday

@a1ien
Copy link

a1ien commented Nov 20, 2019

With option in config I make more test.
For stable work i set

usb_max_rd_buffer_size 0x200     
usb_max_wr_buffer_size 0x200  

If set to 0x400 I prosodical get usb 1-1: reset high-speed USB device number 2 using ci_hdrc
But it's maybe because imx connect to hub with many usb device.

@ttmms
Copy link

ttmms commented Mar 18, 2020

EDIT: Sorry for confusion. Setting above mentioned buffers indeed solved the problem, I just thought they were default values since they were commented out, but I didn't read the comments very well...

I'm also getting read errors with the current master branch and default config files and starting with umtprd-ffs.sh. Connecting to Windows, I get nothing. Connecting to Linux, device is recognized with correct name but trying to open it fails (and file manager crashes). Trying to mount manually with jmtpfs gives PTP_ERROR_IO: failed to open session, trying again after resetting USB interface and eventually MtpErrorCantOpenDevice

@jfdelnero
Copy link
Member

EDIT: Sorry for confusion. Setting above mentioned buffers indeed solved the problem, I just thought they were default values since they were commented out, but I didn't read the comments very well...

ok fine. I suppose you are using an iMX 6 based hardware ?

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

4 participants