From owner-freebsd-usb@FreeBSD.ORG Wed Jun 15 23:20:07 2005 Return-Path: X-Original-To: freebsd-usb@hub.freebsd.org Delivered-To: freebsd-usb@hub.freebsd.org Received: from mx1.FreeBSD.org (mx1.freebsd.org [216.136.204.125]) by hub.freebsd.org (Postfix) with ESMTP id DEA5D16A41C for ; Wed, 15 Jun 2005 23:20:07 +0000 (GMT) (envelope-from gnats@FreeBSD.org) Received: from freefall.freebsd.org (freefall.freebsd.org [216.136.204.21]) by mx1.FreeBSD.org (Postfix) with ESMTP id B799A43D1F for ; Wed, 15 Jun 2005 23:20:07 +0000 (GMT) (envelope-from gnats@FreeBSD.org) Received: from freefall.freebsd.org (gnats@localhost [127.0.0.1]) by freefall.freebsd.org (8.13.3/8.13.3) with ESMTP id j5FNK71A028252 for ; Wed, 15 Jun 2005 23:20:07 GMT (envelope-from gnats@freefall.freebsd.org) Received: (from gnats@localhost) by freefall.freebsd.org (8.13.3/8.13.1/Submit) id j5FNK798028251; Wed, 15 Jun 2005 23:20:07 GMT (envelope-from gnats) Date: Wed, 15 Jun 2005 23:20:07 GMT Message-Id: <200506152320.j5FNK798028251@freefall.freebsd.org> To: freebsd-usb@FreeBSD.org From: Rojer Cc: Subject: Re: usb/81621: external hd hangs under load on ehci X-BeenThere: freebsd-usb@freebsd.org X-Mailman-Version: 2.1.5 Precedence: list Reply-To: Rojer List-Id: FreeBSD support for USB List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Wed, 15 Jun 2005 23:20:08 -0000 The following reply was made to PR usb/81621; it has been noted by GNATS. From: Rojer To: bug-followup@FreeBSD.org, gerrit@pmp.uni-hannover.de Cc: Subject: Re: usb/81621: external hd hangs under load on ehci Date: Thu, 16 Jun 2005 03:12:20 +0400 This is a cryptographically signed message in MIME format. --------------ms070408050607000308000506 Content-Type: text/plain; charset=KOI8-R; format=flowed Content-Transfer-Encoding: 7bit same situation here. ehci, transfers stalls for about a minute, then resumes, then stalls again... finishes successfully, no errors. additional observations: 1) the stall usually lasts about a minute. 2) it happens when accessing the device through filesystem (msdosfs in this case), it never happens when accessing the device directly and sequentially, e.g.: # dd if=/dev/da0 of=/ftp/misc/ZZ bs=64k ^C49369+0 records in 49368+0 records out 3235381248 bytes transferred in 295.937268 secs (10932659 bytes/sec) (the speed is bound mainly by the device itself in this case.) # dd if=/mnt/IHP/testfile of=/dev/null bs=64k load: 0.02 cmd: dd 2692 [getblk] 0.01u 3.26s 0% 712k 11171+0 records in 11171+0 records out 732102656 bytes transferred in 94.251015 secs (7767584 bytes/sec) load: 0.01 cmd: dd 2692 [getblk] 0.01u 3.38s 0% 712k load: 0.01 cmd: dd 2692 [getblk] 0.01u 3.38s 0% 712k load: 0.01 cmd: dd 2692 [getblk] 0.01u 3.38s 0% 712k 11562+0 records in 11562+0 records out 757727232 bytes transferred in 162.903896 secs (4651376 bytes/sec) load: 0.08 cmd: dd 2692 [getblk] 0.01u 3.94s 0% 712k 13478+0 records in 13478+0 records out 883294208 bytes transferred in 178.969938 secs (4935433 bytes/sec) load: 0.12 cmd: dd 2692 [getblk] 0.01u 4.55s 0% 712k load: 0.10 cmd: dd 2692 [getblk] 0.01u 4.55s 0% 712k load: 0.07 cmd: dd 2692 [getblk] 0.01u 4.55s 0% 712k load: 0.05 cmd: dd 2692 [getblk] 0.01u 4.55s 0% 712k 15527+0 records in 15527+0 records out 1017577472 bytes transferred in 261.654513 secs (3889012 bytes/sec) 16383+1 records in 16383+1 records out 1073739776 bytes transferred in 268.807717 secs (3994453 bytes/sec) msdosfs cuts speed significantly (down to 7767584 bytes/sec) but that's bearably, only if the transfer wouldn't stall completely shortly after. 3) it never happens when writing to the device. # dd if=/dev/zero of=/mnt/IHP/testfile bs=64k count=16383 16383+0 records in 16383+0 records out 1073676288 bytes transferred in 166.050668 secs (6465956 bytes/sec) # dd if=/dev/zero of=/mnt/IHP/testfile2 bs=64k count=16383 16383+0 records in 16383+0 records out 1073676288 bytes transferred in 166.053733 secs (6465836 bytes/sec) the speed is low, but no stalls during transfer. 4) i have tried turning on various debug options. all in all, i couldn't catch the moment transfer freezes - due to massive amounts of debug output produced during transfer, the system is crawling and the stall just never happens. however, with "camcontrol debug -ST all" turned on during the stall, the first few messages of debug output look like these: Jun 16 03:01:18 gw kernel: (xpt0:xpt0:0:-1:-1): debugging flags now 6 Jun 16 03:01:18 gw kernel: (xpt0:xpt0:0:-1:-1): xpt_free_path Jun 16 03:01:18 gw kernel: (xpt0:xpt0:0:-1:-1): xpt_release_path ... Jun 16 03:02:14 gw kernel: (da0:umass-sim0:0:0:0): xpt_done Jun 16 03:02:14 gw kernel: (da0:umass-sim0:0:0:0): camisr Jun 16 03:02:14 gw kernel: (da0:umass-sim0:0:0:0): xpt_action Jun 16 03:02:15 gw kernel: (da0:umass-sim0:0:0:0): xpt_done Jun 16 03:02:15 gw kernel: (da0:umass-sim0:0:0:0): camisr Jun 16 03:02:15 gw kernel: (da0:umass-sim0:0:0:0): xpt_schedule Jun 16 03:02:15 gw kernel: (da0:umass-sim0:0:0:0): added periph to queue Jun 16 03:02:15 gw kernel: (da0:umass-sim0:0:0:0): calling xpt_run_devq Jun 16 03:02:15 gw kernel: (da0:umass-sim0:0:0:0): xpt_setup_ccb ... and with hw.usb.debug=0x00020000: Jun 16 01:58:36 gw kernel: usb_add_task: task=0xc195346c Jun 16 01:58:36 gw kernel: usb_task_thread: woke up task=0xc195346c Jun 16 01:58:36 gw kernel: usb_schedsoftintr: polling=0 Jun 16 01:58:36 gw kernel: usb_transfer_complete: pipe=0xc1960280 xfer=0xc1953400 status=15 actlen=0 Jun 16 01:58:36 gw kernel: usb_freemem: large free Jun 16 01:58:36 gw kernel: usb_block_freemem: size=8192 Jun 16 01:58:36 gw kernel: usb_transfer_complete: repeat=0 new head=0 Jun 16 01:58:36 gw kernel: usbd_transfer: xfer=0xc1926e00, flags=0, pipe=0xc1960780, running=0 ... given these observations, i suppose that this might not be usb problem after all, rather msdosfs or buffer management code could cause this behavior. what else can i do to track this problem further? -- Deomid Ryabkov aka Rojer myself@rojer.pp.ru rojer@sysadmins.ru ICQ: 8025844 --------------ms070408050607000308000506 Content-Type: application/x-pkcs7-signature; name="smime.p7s" Content-Transfer-Encoding: base64 Content-Disposition: attachment; filename="smime.p7s" Content-Description: S/MIME Cryptographic Signature MIAGCSqGSIb3DQEHAqCAMIACAQExCzAJBgUrDgMCGgUAMIAGCSqGSIb3DQEHAQAAoIIJIzCC AuwwggJVoAMCAQICAw5jHTANBgkqhkiG9w0BAQQFADBiMQswCQYDVQQGEwJaQTElMCMGA1UE ChMcVGhhd3RlIENvbnN1bHRpbmcgKFB0eSkgTHRkLjEsMCoGA1UEAxMjVGhhd3RlIFBlcnNv bmFsIEZyZWVtYWlsIElzc3VpbmcgQ0EwHhcNMDUwNDAxMDkwNjQzWhcNMDYwNDAxMDkwNjQz WjBfMRAwDgYDVQQEEwdSeWFia292MQ8wDQYDVQQqEwZEZW9taWQxFzAVBgNVBAMTDkRlb21p ZCBSeWFia292MSEwHwYJKoZIhvcNAQkBFhJteXNlbGZAcm9qZXIucHAucnUwggEiMA0GCSqG SIb3DQEBAQUAA4IBDwAwggEKAoIBAQDEKoweumUc1/YHtlscU5xKozcKOd3lLyAZ1SM3rZvn iJ9VAuj9TafODcu+SoJ6sU+Crshl2Nkq/oCs6dynEqyn/jZxGm/mEYxJ+KekBQceLejdFktQ rOuXmjLpipESMO7w1amFn6w3pJgWXex2mcN6hcET2cUdSHjSYxLUXKCQTtzJbcPEHZ+vgEq9 1TA4UcFeZ3d1Ax6q2A2Fs/wvFxtLUC46fq80R7lOxsJA6mxKNOJnbZTCqf8sWF5SyEnNBBj0 yyIHfKl+iMwsqSESg5hc0l9/m6aLV24KtKtvWIEu3RQXflc380xZanF4gvAq8/NADlfEH4Rx SpNOJdgxZga1AgMBAAGjLzAtMB0GA1UdEQQWMBSBEm15c2VsZkByb2plci5wcC5ydTAMBgNV HRMBAf8EAjAAMA0GCSqGSIb3DQEBBAUAA4GBAEaynMcbL7KaxmVMfJWXD7X4ftDolZ2CpPPN yoVJAIXaIHpI0JuiCnQSZivL6BvtYUNyzNAR6ceh87yWoQEJxw1cV2IgUlQ+Z3/+7brumNdb YwCuf3C/LlamOP5zpHDOH1euXLJe8664lC5lIaf70yO6jN7LXHwBNs73qyB7tvY/MIIC7DCC AlWgAwIBAgIDDmMdMA0GCSqGSIb3DQEBBAUAMGIxCzAJBgNVBAYTAlpBMSUwIwYDVQQKExxU aGF3dGUgQ29uc3VsdGluZyAoUHR5KSBMdGQuMSwwKgYDVQQDEyNUaGF3dGUgUGVyc29uYWwg RnJlZW1haWwgSXNzdWluZyBDQTAeFw0wNTA0MDEwOTA2NDNaFw0wNjA0MDEwOTA2NDNaMF8x EDAOBgNVBAQTB1J5YWJrb3YxDzANBgNVBCoTBkRlb21pZDEXMBUGA1UEAxMORGVvbWlkIFJ5 YWJrb3YxITAfBgkqhkiG9w0BCQEWEm15c2VsZkByb2plci5wcC5ydTCCASIwDQYJKoZIhvcN AQEBBQADggEPADCCAQoCggEBAMQqjB66ZRzX9ge2WxxTnEqjNwo53eUvIBnVIzetm+eIn1UC 6P1Np84Ny75KgnqxT4KuyGXY2Sr+gKzp3KcSrKf+NnEab+YRjEn4p6QFBx4t6N0WS1Cs65ea MumKkRIw7vDVqYWfrDekmBZd7HaZw3qFwRPZxR1IeNJjEtRcoJBO3Mltw8Qdn6+ASr3VMDhR wV5nd3UDHqrYDYWz/C8XG0tQLjp+rzRHuU7GwkDqbEo04mdtlMKp/yxYXlLISc0EGPTLIgd8 qX6IzCypIRKDmFzSX3+bpotXbgq0q29YgS7dFBd+VzfzTFlqcXiC8Crz80AOV8QfhHFKk04l 2DFmBrUCAwEAAaMvMC0wHQYDVR0RBBYwFIESbXlzZWxmQHJvamVyLnBwLnJ1MAwGA1UdEwEB /wQCMAAwDQYJKoZIhvcNAQEEBQADgYEARrKcxxsvsprGZUx8lZcPtfh+0OiVnYKk883KhUkA hdogekjQm6IKdBJmK8voG+1hQ3LM0BHpx6HzvJahAQnHDVxXYiBSVD5nf/7tuu6Y11tjAK5/ cL8uVqY4/nOkcM4fV65csl7zrriULmUhp/vTI7qM3stcfAE2zverIHu29j8wggM/MIICqKAD AgECAgENMA0GCSqGSIb3DQEBBQUAMIHRMQswCQYDVQQGEwJaQTEVMBMGA1UECBMMV2VzdGVy biBDYXBlMRIwEAYDVQQHEwlDYXBlIFRvd24xGjAYBgNVBAoTEVRoYXd0ZSBDb25zdWx0aW5n MSgwJgYDVQQLEx9DZXJ0aWZpY2F0aW9uIFNlcnZpY2VzIERpdmlzaW9uMSQwIgYDVQQDExtU aGF3dGUgUGVyc29uYWwgRnJlZW1haWwgQ0ExKzApBgkqhkiG9w0BCQEWHHBlcnNvbmFsLWZy ZWVtYWlsQHRoYXd0ZS5jb20wHhcNMDMwNzE3MDAwMDAwWhcNMTMwNzE2MjM1OTU5WjBiMQsw CQYDVQQGEwJaQTElMCMGA1UEChMcVGhhd3RlIENvbnN1bHRpbmcgKFB0eSkgTHRkLjEsMCoG A1UEAxMjVGhhd3RlIFBlcnNvbmFsIEZyZWVtYWlsIElzc3VpbmcgQ0EwgZ8wDQYJKoZIhvcN AQEBBQADgY0AMIGJAoGBAMSmPFVzVftOucqZWh5owHUEcJ3f6f+jHuy9zfVb8hp2vX8MOmHy v1HOAdTlUAow1wJjWiyJFXCO3cnwK4Vaqj9xVsuvPAsH5/EfkTYkKhPPK9Xzgnc9A74r/rsY Pge/QIACZNenprufZdHFKlSFD0gEf6e20TxhBEAeZBlyYLf7AgMBAAGjgZQwgZEwEgYDVR0T AQH/BAgwBgEB/wIBADBDBgNVHR8EPDA6MDigNqA0hjJodHRwOi8vY3JsLnRoYXd0ZS5jb20v VGhhd3RlUGVyc29uYWxGcmVlbWFpbENBLmNybDALBgNVHQ8EBAMCAQYwKQYDVR0RBCIwIKQe MBwxGjAYBgNVBAMTEVByaXZhdGVMYWJlbDItMTM4MA0GCSqGSIb3DQEBBQUAA4GBAEiM0VCD 6gsuzA2jZqxnD3+vrL7CF6FDlpSdf0whuPg2H6otnzYvwPQcUCCTcDz9reFhYsPZOhl+hLGZ GwDFGguCdJ4lUJRix9sncVcljd2pnDmOjCBPZV+V2vf3h9bGCE6u9uo05RAaWzVNd+NWIXiC 3CEZNd4ksdMdRv9dX2VPMYIDOzCCAzcCAQEwaTBiMQswCQYDVQQGEwJaQTElMCMGA1UEChMc VGhhd3RlIENvbnN1bHRpbmcgKFB0eSkgTHRkLjEsMCoGA1UEAxMjVGhhd3RlIFBlcnNvbmFs IEZyZWVtYWlsIElzc3VpbmcgQ0ECAw5jHTAJBgUrDgMCGgUAoIIBpzAYBgkqhkiG9w0BCQMx CwYJKoZIhvcNAQcBMBwGCSqGSIb3DQEJBTEPFw0wNTA2MTUyMzEyMjBaMCMGCSqGSIb3DQEJ BDEWBBQWw6nac5k7nfKsrGaUjO2ksD3uNTBSBgkqhkiG9w0BCQ8xRTBDMAoGCCqGSIb3DQMH MA4GCCqGSIb3DQMCAgIAgDANBggqhkiG9w0DAgIBQDAHBgUrDgMCBzANBggqhkiG9w0DAgIB KDB4BgkrBgEEAYI3EAQxazBpMGIxCzAJBgNVBAYTAlpBMSUwIwYDVQQKExxUaGF3dGUgQ29u c3VsdGluZyAoUHR5KSBMdGQuMSwwKgYDVQQDEyNUaGF3dGUgUGVyc29uYWwgRnJlZW1haWwg SXNzdWluZyBDQQIDDmMdMHoGCyqGSIb3DQEJEAILMWugaTBiMQswCQYDVQQGEwJaQTElMCMG A1UEChMcVGhhd3RlIENvbnN1bHRpbmcgKFB0eSkgTHRkLjEsMCoGA1UEAxMjVGhhd3RlIFBl cnNvbmFsIEZyZWVtYWlsIElzc3VpbmcgQ0ECAw5jHTANBgkqhkiG9w0BAQEFAASCAQA8obxt M9KEo78Kz8CjL1KvG13t+RrBeueiBXEa1uTFtw3V7BLVlaBmdhyxFKdrvdTfulmJtca05uHb ufF3aLCXLEC7gS3ki5q9p8LFahXXdUclmUSN8DFwVcs51j04dH5/hks8jqLWD+zhK1l8TjFG d9InM4NSpnhEAoOGRS5EXIEcA359rma6/6PTqdjw9H5FH3tSXkCJMqh2xtiTGFpbGB/9xyHC bo21LknXTaSOENo6QSVmV7AgnDOjsi2kernYRTV0nZeJDpf0ffZ12FvnFMKC0A8yFL7nQLJA uRsU1oC4wpRRUX3oII8tTJ86pRbVowmZM2F/lJW9Wn0+bMCzAAAAAAAA --------------ms070408050607000308000506--