You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@subversion.apache.org by speedy <sp...@3d-io.com> on 2007/08/02 20:55:44 UTC
[performance problem report] svn up performance bug?
Hello SVN crew,
I've noticed that working copy nop "svn up" takes 20-30sec in our
working environment, compared to svn st --show_updates which
takes 1sec to finish up.
The server is svnserve 1.3.2 / reiserfs / linux and client is
command line svn 1.4.3 / NTFS / Windows XP, connected with 1Gbit
LAN. Working copy is 8.6GB, 36k files, 16k folders.
File access tracing using Filemon revealed:
**************** svn up LOG STARTS HERE
1 9:00:48 PM cmd.exe:2856 IRP_MJ_DIRECTORY_CONTROL C:\Program Files\subversion\bin\ SUCCESS FileBothDirectoryInformation: svn.EXE
... loads DLLs, loads access rights here ...
336 9:00:48 PM svn.exe:2324 IRP_MJ_CREATE H:\!!pr_assets_new\.svn\entries SUCCESS Options: Open Access: Read
337 9:00:48 PM svn.exe:2324 IRP_MJ_READ H:\!!pr_assets_new\.svn\entries SUCCESS Offset: 0 Length: 80
338 9:00:48 PM svn.exe:2324 IRP_MJ_CLEANUP H:\!!pr_assets_new\.svn\entries SUCCESS
339 9:00:48 PM svn.exe:2324 IRP_MJ_CREATE H:\!!pr_assets_new\.svn\lock SUCCESS Options: Create Access: 00120196
340 9:00:48 PM svn.exe:2324 IRP_MJ_CLEANUP H:\!!pr_assets_new\.svn\lock SUCCESS
341 9:00:48 PM svn.exe:2324 IRP_MJ_CLOSE H:\!!pr_assets_new\.svn\lock SUCCESS
342 9:00:48 PM svn.exe:2324 IRP_MJ_CREATE H:\!!pr_assets_new\.svn\entries SUCCESS Options: Open Access: Read
343 9:00:48 PM svn.exe:2324 IRP_MJ_READ H:\!!pr_assets_new\.svn\entries SUCCESS Offset: 0 Length: 16384
344 9:00:48 PM svn.exe:2324 FASTIO_READ H:\!!pr_assets_new\.svn\entries END OF FILE Offset: 1612 Length: 16384
345 9:00:48 PM svn.exe:2324 IRP_MJ_CLEANUP H:\!!pr_assets_new\.svn\entries SUCCESS
346 9:00:48 PM svn.exe:2324 IRP_MJ_CLOSE H:\!!pr_assets_new\.svn\entries SUCCESS
347 9:00:48 PM svn.exe:2324 IRP_MJ_CREATE H:\!!pr_assets_new\cooked_graphics\.svn\entries SUCCESS Options: Open Access: Read
348 9:00:48 PM svn.exe:2324 IRP_MJ_READ H:\!!pr_assets_new\cooked_graphics\.svn\entries SUCCESS Offset: 0 Length: 80
349 9:00:48 PM svn.exe:2324 IRP_MJ_CLEANUP H:\!!pr_assets_new\cooked_graphics\.svn\entries SUCCESS
350 9:00:48 PM svn.exe:2324 IRP_MJ_CREATE H:\!!pr_assets_new\cooked_graphics\.svn\lock SUCCESS Options: Create Access: 00120196
351 9:00:48 PM svn.exe:2324 IRP_MJ_CLEANUP H:\!!pr_assets_new\cooked_graphics\.svn\lock SUCCESS
352 9:00:48 PM svn.exe:2324 IRP_MJ_CLOSE H:\!!pr_assets_new\cooked_graphics\.svn\lock SUCCESS
353 9:00:48 PM svn.exe:2324 IRP_MJ_CREATE H:\!!pr_assets_new\cooked_graphics\.svn\entries SUCCESS Options: Open Access: Read
354 9:00:48 PM svn.exe:2324 IRP_MJ_READ H:\!!pr_assets_new\cooked_graphics\.svn\entries SUCCESS Offset: 0 Length: 16384
355 9:00:48 PM svn.exe:2324 FASTIO_READ H:\!!pr_assets_new\cooked_graphics\.svn\entries END OF FILE Offset: 337 Length: 16384
356 9:00:48 PM svn.exe:2324 IRP_MJ_CLEANUP H:\!!pr_assets_new\cooked_graphics\.svn\entries SUCCESS
357 9:00:48 PM svn.exe:2324 IRP_MJ_CLOSE H:\!!pr_assets_new\cooked_graphics\.svn\entries SUCCESS
.. traverses more folders ..
15529 9:00:48 PM svn.exe:2324 IRP_MJ_CREATE H:\!!pr_assets_new\raw_graphics\items\itm_loc_01_xray_glasses\.svn\entries SUCCESS Options: Open Access: Read
15530 9:00:48 PM svn.exe:2324 IRP_MJ_READ H:\!!pr_assets_new\raw_graphics\items\itm_loc_01_xray_glasses\.svn\entries SUCCESS Offset: 0 Length: 80
15531 9:00:48 PM svn.exe:2324 IRP_MJ_CLEANUP H:\!!pr_assets_new\raw_graphics\items\itm_loc_01_xray_glasses\.svn\entries SUCCESS
15532 9:00:48 PM svn.exe:2324 IRP_MJ_CREATE H:\!!pr_assets_new\raw_graphics\items\itm_loc_01_xray_glasses\.svn\lock SUCCESS Options: Create Access: 00120196
15533 9:00:48 PM svn.exe:2324 IRP_MJ_CLEANUP H:\!!pr_assets_new\raw_graphics\items\itm_loc_01_xray_glasses\.svn\lock SUCCESS
15534 9:00:48 PM svn.exe:2324 IRP_MJ_CLOSE H:\!!pr_assets_new\raw_graphics\items\itm_loc_01_xray_glasses\.svn\lock SUCCESS
15535 9:00:48 PM svn.exe:2324 IRP_MJ_CREATE H:\!!pr_assets_new\raw_graphics\items\itm_loc_01_xray_glasses\.svn\entries SUCCESS Options: Open Access: Read
15536 9:00:48 PM svn.exe:2324 IRP_MJ_READ H:\!!pr_assets_new\raw_graphics\items\itm_loc_01_xray_glasses\.svn\entries SUCCESS Offset: 0 Length: 16384
15537 9:00:48 PM svn.exe:2324 FASTIO_READ H:\!!pr_assets_new\raw_graphics\items\itm_loc_01_xray_glasses\.svn\entries END OF FILE Offset: 846 Length: 16384
15538 9:00:48 PM svn.exe:2324 IRP_MJ_CLEANUP H:\!!pr_assets_new\raw_graphics\items\itm_loc_01_xray_glasses\.svn\entries SUCCESS
15539 9:00:48 PM svn.exe:2324 IRP_MJ_CLOSE H:\!!pr_assets_new\raw_graphics\items\itm_loc_01_xray_glasses\.svn\entries SUCCESS
15540 9:00:48 PM svn.exe:2324 IRP_MJ_CREATE H:\!!pr_assets_new\raw_graphics\items\itm_loc_01_lunchbox2\.svn\entries SUCCESS Options: Open Access: Read
15541 9:00:48 PM svn.exe:2324 IRP_MJ_READ H:\!!pr_assets_new\raw_graphics\items\itm_loc_01_lunchbox2\.svn\entries SUCCESS Offset: 0 Length: 80
15542 9:00:48 PM svn.exe:2324 IRP_MJ_CLEANUP H:\!!pr_assets_new\raw_graphics\items\itm_loc_01_lunchbox2\.svn\entries SUCCESS
15543 9:00:48 PM svn.exe:2324 IRP_MJ_CREATE H:\!!pr_assets_new\raw_graphics\items\itm_loc_01_lunchbox2\.svn\lock SUCCESS Options: Create Access: 00120196
.. here comes the strange stuff (some kind of lock waiting?) ..
15544 9:00:48 PM svn.exe:2324 IRP_MJ_WRITE* H:\$LogFile SUCCESS Offset: 3289088 Length: 65536
15545 9:00:48 PM svn.exe:2324 IRP_MJ_WRITE* H:\$LogFile SUCCESS Offset: 3354624 Length: 65536
15546 9:00:48 PM svn.exe:2324 IRP_MJ_WRITE* H:\$LogFile SUCCESS Offset: 3420160 Length: 8192
15547 9:00:48 PM svn.exe:2324 IRP_MJ_WRITE* H:\$LogFile SUCCESS Offset: 8192 Length: 4096
15548 9:00:48 PM svn.exe:2324 IRP_MJ_WRITE* H:\$Directory SUCCESS Offset: 0 Length: 4096
15549 9:00:48 PM svn.exe:2324 IRP_MJ_WRITE* H:\$Mft SUCCESS Offset: 32768 Length: 12288
15550 9:00:48 PM svn.exe:2324 IRP_MJ_WRITE* H:\$Mft SUCCESS Offset: 0 Length: 4096
15551 9:00:48 PM svn.exe:2324 IRP_MJ_WRITE* H:\$Directory SUCCESS Offset: 0 Length: 4096
15552 9:00:48 PM svn.exe:2324 IRP_MJ_WRITE* H:\$Directory SUCCESS Offset: 0 Length: 4096
15553 9:00:48 PM svn.exe:2324 IRP_MJ_WRITE* H:\$Directory SUCCESS Offset: 0 Length: 4096
15554 9:00:48 PM svn.exe:2324 IRP_MJ_WRITE* H:\$Directory SUCCESS Offset: 0 Length: 4096
15555 9:00:48 PM svn.exe:2324 IRP_MJ_WRITE* H:\$Directory SUCCESS Offset: 0 Length: 4096
15556 9:00:48 PM svn.exe:2324 IRP_MJ_WRITE* H:\$Directory SUCCESS Offset: 0 Length: 4096
15557 9:00:48 PM svn.exe:2324 IRP_MJ_WRITE* H:\$Directory SUCCESS Offset: 8192 Length: 4096
15558 9:00:48 PM svn.exe:2324 IRP_MJ_WRITE* H:\$Directory SUCCESS Offset: 4096 Length: 4096
15559 9:00:48 PM svn.exe:2324 IRP_MJ_WRITE* H:\$Directory SUCCESS Offset: 0 Length: 4096
15560 9:00:48 PM svn.exe:2324 IRP_MJ_WRITE* H:\$Directory SUCCESS Offset: 0 Length: 4096
15561 9:00:48 PM svn.exe:2324 IRP_MJ_WRITE* H:\$Directory SUCCESS Offset: 0 Length: 4096
.. after 9 sec of it decides to continue traversing folders ..
17141 9:00:57 PM svn.exe:2324 IRP_MJ_WRITE* H:\$Mft SUCCESS Offset: 341528576 Length: 4096
17142 9:00:57 PM svn.exe:2324 IRP_MJ_WRITE* H:\$Mft SUCCESS Offset: 341536768 Length: 16384
17143 9:00:57 PM svn.exe:2324 IRP_MJ_WRITE* H:\$Mft SUCCESS Offset: 341557248 Length: 8192
17144 9:00:57 PM svn.exe:2324 IRP_MJ_WRITE* H:\$Mft SUCCESS Offset: 341569536 Length: 8192
17145 9:00:57 PM svn.exe:2324 IRP_MJ_WRITE* H:\$Mft SUCCESS Offset: 341581824 Length: 4096
17146 9:00:57 PM svn.exe:2324 IRP_MJ_WRITE* H:\$Mft SUCCESS Offset: 341590016 Length: 4096
17147 9:00:57 PM svn.exe:2324 IRP_MJ_WRITE* H:\$Mft SUCCESS Offset: 341602304 Length: 4096
17148 9:00:57 PM svn.exe:2324 IRP_MJ_WRITE* H:\$Mft SUCCESS Offset: 341610496 Length: 20480
17149 9:00:57 PM svn.exe:2324 IRP_MJ_WRITE* H:\$Mft SUCCESS Offset: 341635072 Length: 16384
17150 9:00:57 PM svn.exe:2324 IRP_MJ_WRITE* H:\$Mft SUCCESS Offset: 343379968 Length: 4096
17151 9:00:57 PM svn.exe:2324 IRP_MJ_WRITE* H:\$Mft SUCCESS Offset: 343584768 Length: 4096
17152 9:00:57 PM svn.exe:2324 IRP_MJ_WRITE* H:\$LogFile SUCCESS Offset: 12288 Length: 4096
17153 9:00:57 PM svn.exe:2324 IRP_MJ_WRITE* H:\$LogFile SUCCESS Offset: 4096 Length: 4096
17154 9:00:57 PM svn.exe:2324 IRP_MJ_CLEANUP H:\!!pr_assets_new\raw_graphics\items\itm_loc_01_lunchbox2\.svn\lock SUCCESS
17155 9:00:57 PM svn.exe:2324 IRP_MJ_CLOSE H:\!!pr_assets_new\raw_graphics\items\itm_loc_01_lunchbox2\.svn\lock SUCCESS
17156 9:00:57 PM svn.exe:2324 IRP_MJ_CREATE H:\!!pr_assets_new\raw_graphics\items\itm_loc_01_lunchbox2\.svn\entries SUCCESS Options: Open Access: Read
17157 9:00:57 PM svn.exe:2324 IRP_MJ_READ H:\!!pr_assets_new\raw_graphics\items\itm_loc_01_lunchbox2\.svn\entries SUCCESS Offset: 0 Length: 16384
17158 9:00:57 PM svn.exe:2324 FASTIO_READ H:\!!pr_assets_new\raw_graphics\items\itm_loc_01_lunchbox2\.svn\entries END OF FILE Offset: 675 Length: 16384
17159 9:00:57 PM svn.exe:2324 IRP_MJ_CLEANUP H:\!!pr_assets_new\raw_graphics\items\itm_loc_01_lunchbox2\.svn\entries SUCCESS
17160 9:00:57 PM svn.exe:2324 IRP_MJ_CLOSE H:\!!pr_assets_new\raw_graphics\items\itm_loc_01_lunchbox2\.svn\entries SUCCESS
.. here it traverses folders in a similar manner ..
40101 9:00:58 PM svn.exe:2324 IRP_MJ_SET_INFORMATION H:\!!pr_assets_new\cooked_graphics\infos\texts\english\.svn\lock SUCCESS Delete
40102 9:00:58 PM svn.exe:2324 IRP_MJ_CLEANUP H:\!!pr_assets_new\cooked_graphics\infos\texts\english\.svn\lock SUCCESS
40103 9:00:58 PM svn.exe:2324 IRP_MJ_CLOSE H:\!!pr_assets_new\cooked_graphics\infos\texts\english\.svn\lock SUCCESS
40104 9:00:58 PM svn.exe:2324 FASTIO_QUERY_OPEN H:\!!pr_assets_new\cooked_graphics\infos\texts\.svn\lock SUCCESS Attributes: A
40105 9:00:58 PM svn.exe:2324 IRP_MJ_CREATE H:\!!pr_assets_new\cooked_graphics\infos\texts\.svn\lock SUCCESS Options: Open Access: 00100100
40106 9:00:58 PM svn.exe:2324 IRP_MJ_SET_INFORMATION H:\!!pr_assets_new\cooked_graphics\infos\texts\.svn\lock SUCCESS FileBasicInformation
40107 9:00:58 PM svn.exe:2324 IRP_MJ_CLEANUP H:\!!pr_assets_new\cooked_graphics\infos\texts\.svn\lock SUCCESS
40108 9:00:58 PM svn.exe:2324 IRP_MJ_CLOSE H:\!!pr_assets_new\cooked_graphics\infos\texts\.svn\lock SUCCESS
40109 9:00:58 PM svn.exe:2324 IRP_MJ_CREATE H:\!!pr_assets_new\cooked_graphics\infos\texts\.svn\lock SUCCESS Options: Open Access: 00010080
40110 9:00:58 PM svn.exe:2324 IRP_MJ_QUERY_INFORMATION H:\!!pr_assets_new\cooked_graphics\infos\texts\.svn\lock SUCCESS FileAttributeTagInformation
.. again comes the strange stuff ..
41085 9:00:58 PM svn.exe:2324 IRP_MJ_WRITE* H:\$Directory SUCCESS Offset: 0 Length: 4096
41086 9:00:58 PM svn.exe:2324 IRP_MJ_WRITE* H:\$Directory SUCCESS Offset: 0 Length: 4096
41087 9:00:58 PM svn.exe:2324 IRP_MJ_WRITE* H:\$Directory SUCCESS Offset: 0 Length: 4096
41088 9:00:58 PM svn.exe:2324 IRP_MJ_WRITE* H:\$Directory SUCCESS Offset: 0 Length: 4096
41089 9:00:58 PM svn.exe:2324 IRP_MJ_WRITE* H:\$Directory SUCCESS Offset: 0 Length: 4096
41090 9:00:58 PM svn.exe:2324 IRP_MJ_WRITE* H:\$Directory SUCCESS Offset: 0 Length: 4096
41091 9:00:58 PM svn.exe:2324 IRP_MJ_WRITE* H:\$Directory SUCCESS Offset: 0 Length: 4096
41092 9:00:58 PM svn.exe:2324 IRP_MJ_WRITE* H:\$Directory SUCCESS Offset: 0 Length: 4096
41093 9:00:58 PM svn.exe:2324 IRP_MJ_WRITE* H:\$Directory SUCCESS Offset: 0 Length: 4096
41094 9:00:58 PM svn.exe:2324 IRP_MJ_WRITE* H:\$Directory SUCCESS Offset: 0 Length: 4096
41095 9:00:59 PM svn.exe:2324 IRP_MJ_WRITE* H:\$Directory SUCCESS Offset: 0 Length: 4096
41096 9:00:59 PM svn.exe:2324 IRP_MJ_WRITE* H:\$Directory SUCCESS Offset: 0 Length: 4096
41097 9:00:59 PM svn.exe:2324 IRP_MJ_WRITE* H:\$Directory SUCCESS Offset: 0 Length: 4096
41098 9:00:59 PM svn.exe:2324 IRP_MJ_WRITE* H:\$Directory SUCCESS Offset: 0 Length: 4096
41099 9:00:59 PM svn.exe:2324 IRP_MJ_WRITE* H:\$Directory SUCCESS Offset: 0 Length: 4096
41100 9:00:59 PM svn.exe:2324 IRP_MJ_WRITE* H:\$Directory SUCCESS Offset: 0 Length: 4096
41101 9:00:59 PM svn.exe:2324 IRP_MJ_WRITE* H:\$Directory SUCCESS Offset: 0 Length: 4096
41102 9:00:59 PM svn.exe:2324 IRP_MJ_WRITE* H:\$Directory SUCCESS Offset: 0 Length: 4096
41103 9:00:59 PM svn.exe:2324 IRP_MJ_WRITE* H:\$Directory SUCCESS Offset: 0 Length: 4096
41104 9:00:59 PM svn.exe:2324 IRP_MJ_WRITE* H:\$Directory SUCCESS Offset: 0 Length: 4096
41105 9:00:59 PM svn.exe:2324 IRP_MJ_WRITE* H:\$Directory SUCCESS Offset: 0 Length: 4096
.. and after 9 sec it decides to continue ..
42706 9:01:08 PM svn.exe:2324 IRP_MJ_WRITE* H:\$Mft SUCCESS Offset: 332206080 Length: 4096
42707 9:01:08 PM svn.exe:2324 IRP_MJ_WRITE* H:\$Mft SUCCESS Offset: 332218368 Length: 8192
42708 9:01:08 PM svn.exe:2324 IRP_MJ_WRITE* H:\$Mft SUCCESS Offset: 332242944 Length: 4096
42709 9:01:08 PM svn.exe:2324 IRP_MJ_WRITE* H:\$Mft SUCCESS Offset: 332509184 Length: 4096
42710 9:01:08 PM svn.exe:2324 IRP_MJ_WRITE* H:\$Mft SUCCESS Offset: 332521472 Length: 4096
42711 9:01:08 PM svn.exe:2324 IRP_MJ_WRITE* H:\$Mft SUCCESS Offset: 332541952 Length: 4096
42712 9:01:08 PM svn.exe:2324 IRP_MJ_WRITE* H:\$Mft SUCCESS Offset: 332578816 Length: 8192
42713 9:01:08 PM svn.exe:2324 IRP_MJ_WRITE* H:\$Mft SUCCESS Offset: 332627968 Length: 4096
42714 9:01:08 PM svn.exe:2324 IRP_MJ_WRITE* H:\$LogFile SUCCESS Offset: 12288 Length: 4096
42715 9:01:08 PM svn.exe:2324 IRP_MJ_WRITE* H:\$LogFile SUCCESS Offset: 0 Length: 4096
42716 9:01:08 PM svn.exe:2324 IRP_MJ_CLEANUP H:\!!pr_assets_new\cooked_graphics\characters\chr_hall_of_fame_avatar\cameras\.svn\lock SUCCESS
42717 9:01:08 PM svn.exe:2324 IRP_MJ_CLOSE H:\!!pr_assets_new\cooked_graphics\characters\chr_hall_of_fame_avatar\cameras\.svn\lock SUCCESS
42718 9:01:08 PM svn.exe:2324 IRP_MJ_CREATE H:\!!pr_assets_new\cooked_graphics\characters\chr_hall_of_fame_avatar\cameras\.svn\lock SUCCESS Options
.. traverses some more folders ..
43361 9:01:08 PM svn.exe:2324 IRP_MJ_CLEANUP H:\!!pr_assets_new\.svn\lock SUCCESS
43362 9:01:08 PM svn.exe:2324 IRP_MJ_CLOSE H:\!!pr_assets_new\.svn\lock SUCCESS
43363 9:01:09 PM svn.exe:2324 IRP_MJ_CLEANUP H:\!!pr_assets_new SUCCESS
43364 9:01:09 PM svn.exe:2324 IRP_MJ_CLOSE H:\!!pr_assets_new SUCCESS
**************** svn up LOG ENDS HERE
ps. please keep me in CC: as I am not subscribed to the mail-list.
--
Best regards,
speedy mailto:speedy@3d-io.com
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@subversion.tigris.org
For additional commands, e-mail: users-help@subversion.tigris.org