PageRenderTime 39ms CodeModel.GetById 11ms RepoModel.GetById 1ms app.codeStats 0ms

/blog/2015/10/22/append-i/o-performance-on-windows/index.html

https://github.com/indygreg/indygreg.github.com
HTML | 219 lines | 178 code | 30 blank | 11 comment | 0 complexity | d0d235d85ae5bd02b8b47f92d4c46459 MD5 | raw file
    

  1. 

  2. 

  3. 

  4. <!DOCTYPE html PUBLIC "-//W3C//DTD XHTML 1.0 Strict//EN" 
    5. 

  5.     "http://www.w3.org/TR/xhtml1/DTD/xhtml1-strict.dtd">
    6. 

  6. <!--
    7. 

  7. Design by Free CSS Templates
    8. 

  8. http://www.freecsstemplates.org
    9. 

  9. Released for free under a Creative Commons Attribution 2.5 License
    10. 

  10. 

  11. Name       : Pollinating  
    12. 

  12. Description: A two-column, fixed-width design with dark color scheme.
    13. 

  13. Version    : 1.0
    14. 

  14. Released   : 20101114
    15. 

  15. 

  16. -->
    17. 

  17. <html xmlns="http://www.w3.org/1999/xhtml">
    18. 

  18.   <head>
    19. 

  19.     <meta http-equiv="Content-Type" content="text/html; charset=UTF-8"/>
    20. 

  20.     
    21. 

  21.   <title>Gregory Szorc's Digital Home
    22. 

  22.   | Append I/O Performance on Windows
    23. 

  23. </title>
    24. 

  24. <link rel="alternate" type="application/rss+xml" title="RSS 2.0" href="/blog/feed" />
    25. 

  25. <link rel="alternate" type="application/atom+xml" title="Atom 1.0"
    26. 

  26. href="/blog/feed/atom" />
    27. 

  27. <link rel="stylesheet" href="/style/style.css" type="text/css" />
    28. 

  28. <link rel="stylesheet" href="/css/pygments_murphy.css" type="text/css" />
    29. 

  29. 

  30. 

  31.   </head>
    32. 

  32.   <body>
    33. 

  33.     <div id="wrapper">
    34. 

  34.       
    35. 

  35.   <div id="menu">
    36. 

  36.   <ul>
    37. 

  37.     <li><a href="/">Home</a></li>
    38. 

  38.     <li><a href="/blog/">Blog</a></li>
    39. 

  39.     <li><a href="/notes">Notes</a></li>
    40. 

  40.     <li><a href="/work.html">Work</a></li>
    41. 

  41.     <li><a href="/skills.html">Skills</a></li>
    42. 

  42.     <li><a href="/thoughts.html">Thoughts</a></li>
    43. 

  43.     <li><a href="/resume.pdf">Resume</a></li>
    44. 

  44.   </ul>
    45. 

  45. </div>
    46. 

  46. 

  47. 

  48.       <div id="page">
    49. 

  49.         <div id="page-bgtop">
    50. 

  50.           <div id="page-bgbtm">
    51. 

  51.               <div id="content">
    52. 

  52.                 
    53. 

  53. 

  54. <div class="blog_post">
    55. 

  55.   <a name="append-i/o-performance-on-windows"></a>
    56. 

  56.   <h2 class="blog_post_title"><a href="/blog/2015/10/22/append-i/o-performance-on-windows" rel="bookmark" title="Permanent Link to Append I/O Performance on Windows">Append I/O Performance on Windows</a></h2>
    57. 

  57.   <small>October 22, 2015 at 02:15 AM | categories: 
    58. 

  58. 

  59. <a href='/blog/category/mozilla'>Mozilla</a>
    60. 

  60. </small><p/>
    61. 

  61.   <div class="post_prose">
    62. 

  62.     
    63. 

  63.   <p>A few weeks ago, some coworkers were complaining about the relative
    64. 

  64. performance of Mercurial cloning on Windows. I investigated on my
    65. 

  65. brand new i7-6700K Windows 10 desktop machine and sure enough they were
    66. 

  66. correct: cloning times on Windows were several minutes slower than
    67. 

  67. Linux on the same hardware. What gives?</p>
    68. 

  68. <p>I performed a few clones with Python under a profiler. It pointed to a
    69. 

  69. potential slowdown in file I/O. I wanted more details so I fired up
    70. 

  70. <a href="https://technet.microsoft.com/en-us/library/bb896645.aspx">Sysinternals Process Monitor</a>
    71. 

  71. (strace for Windows) and captured data for a clone.</p>
    72. 

  72. <p>As I was looking at the raw system calls related to I/O, something
    73. 

  73. immediately popped out: <em>CloseFile()</em> operations were frequently
    74. 

  74. taking 1-5 <em>milliseconds</em> whereas other operations like opening, reading,
    75. 

  75. and writing files only took 1-5 <em>microseconds</em>. <strong>That's a 1000x
    76. 

  76. difference!</strong></p>
    77. 

  77. <p>I wrote a custom Python script to analyze an export of Process Monitor's
    78. 

  78. data. Sure enough, it said we were spending hundreds of seconds in
    79. 

  79. <em>CloseFile()</em> operations (it was being called a few hundred thousand
    80. 

  80. times). I posted the findings to some mailing lists.
    81. 

  81. <a href="https://groups.google.com/d/msg/mozilla.dev.platform/yupx2ToQ5T4/WAMC_Q-DCAAJ">Follow-ups</a>
    82. 

  82. in Mozilla's dev-platform list pointed me to
    83. 

  83. <a href="http://blogs.msdn.com/b/oldnewthing/archive/2011/09/23/10215586.aspx">an old MSDN blog post</a>
    84. 

  84. where it documents behavior similar to what I was seeing.</p>
    85. 

  85. <p>Long story short, <strong>closing file handles that have been appended to is
    86. 

  86. slow on Windows.</strong> This is apparently due to an implementation detail of
    87. 

  87. NTFS. Writing to a file in place is fine and only takes microseconds for
    88. 

  88. the open, write, and close. But if you append a file, closing the
    89. 

  89. associated file handle is going to take a few milliseconds. Even if you
    90. 

  90. are using Overlapped I/O (async I/O on Windows), the <em>CloseHandle()</em>
    91. 

  91. call to close the file handle blocks the calling thread! Seriously.</p>
    92. 

  92. <p>This behavior is in stark contrast to Linux and OS X, where system I/O
    93. 

  93. functions take microseconds (assuming your I/O subsystem can keep up).</p>
    94. 

  94. <p>There are two ways to work around this issue:</p>
    95. 

  95. <ol>
    96. 

  96. <li>Reduce the amount of file closing operations on appended files.</li>
    97. 

  97. <li>Use multiple threads for I/O on Windows.</li>
    98. 

  98. </ol>
    99. 

  99. <p>Armed with this knowledge, I dug into the guts of Mercurial and
    100. 

  100. proceeded to write a
    101. 

  101. <a href="https://selenic.com/repo/hg/rev/836291420d53">number</a>
    102. 

  102. <a href="https://selenic.com/repo/hg/rev/39d643252b9f">of</a>
    103. 

  103. <a href="https://selenic.com/repo/hg/rev/56a640b0f656">patches</a>
    104. 

  104. that drastically reduced the amount of file I/O system calls during
    105. 

  105. clone and pull operations. While I intend to write a blog post with the
    106. 

  106. full details, <strong>cloning the Firefox repository with Mercurial 3.6 on
    107. 

  107. Windows is now several minutes faster.</strong> Pretty much all of this is due
    108. 

  108. to reducing the number of file close operations by aggressively reusing
    109. 

  109. file handles.</p>
    110. 

  110. <p>I also
    111. 

  111. <a href="https://selenic.com/pipermail/mercurial-devel/2015-September/073788.html">experimented</a>
    112. 

  112. with moving file close operations to a separate thread on Windows. While
    113. 

  113. this change didn't make it into Mercurial 3.6, the results were very
    114. 

  114. promising. Even on Python (which doesn't have real asynchronous threads
    115. 

  115. due to the GIL), moving file closing to a background thread freed up the
    116. 

  116. main thread to do the CPU heavy work of processing data. This made clones
    117. 

  117. several minutes faster. (Python does release the GIL when performing an
    118. 

  118. I/O system call.) Furthermore, <strong>simply creating a dedicated thread for
    119. 

  119. closing file handles made Mercurial faster than 7-zip at writing tens of
    120. 

  120. thousands of files from an uncompressed tar archive</strong>. (I'm not going to
    121. 

  121. post the time for <em>tar</em> on Windows because it is embarassing.) That's a
    122. 

  122. Python process on Windows faster than a native executable that is lauded
    123. 

  123. for its speed (7-zip). Just by offloading file closing to a single
    124. 

  124. separate thread. Crazy.</p>
    125. 

  125. <p>I can optimize file closing in Mercurial all I want. However,
    126. 

  126. Mercurial's storage model relies on several files. For the Firefox
    127. 

  127. repository, we have to write ~225,000 files during clone. Assuming
    128. 

  128. 1ms per file close (which is generous), that's 225s (or 3:45) wall
    129. 

  129. time performing file closes. That's not going to scale. I've already
    130. 

  130. started experimenting with alternative storage modes that initially use
    131. 

  131. 1-6 files. This should enable Mercurial clones to run at over 100 MB/s
    132. 

  132. (yes, Python and Windows can do I/O that quickly if you are smart about
    133. 

  133. things).</p>
    134. 

  134. <p>My primary takeaway is that creating/appending to thousands of files
    135. 

  135. is slow on Windows and should be addressed at the architecture level
    136. 

  136. by not requiring thousands of files and at the implementation level
    137. 

  137. by minimizing the number of file close operations after write.
    138. 

  138. If you absolutely must create/append to thousands of files, use multiple
    139. 

  139. threads for at least closing file handles.</p>
    140. 

  140. <p>My secondary takeaway is that Sysinternals Process Monitor is amazing.
    141. 

  141. I used it against Firefox and immediately found
    142. 

  142. <a href="https://bugzilla.mozilla.org/show_bug.cgi?id=1211090">performance concerns</a>.
    143. 

  143. It can be extremely eye opening to see how your higher-level code
    144. 

  144. is translated into function calls into your operating system and where
    145. 

  145. the performance hot spots are or aren't at the OS level.</p>
    146. 

    147. 

  147.   </div>
    148. 

  148. </div>
    149. 

  149. 

  150. 

  151. 

  152. 

  153.               </div>
    154. 

  154.               
    155. 

  155.           <div id="sidebar">
    156. 

  156.           <ul>
    157. 

  157.             <li>
    158. 

  158.               <h2>Categories</h2>
    159. 

  159.               <ul>
    160. 

  160.                 <li><a href="/blog/category/apple">Apple</a></li>
    161. 

  161.                 <li><a href="/blog/category/bugzilla">Bugzilla</a></li>
    162. 

  162.                 <li><a href="/blog/category/ci">CI</a></li>
    163. 

  163.                 <li><a href="/blog/category/clang">Clang</a></li>
    164. 

  164.                 <li><a href="/blog/category/docker">Docker</a></li>
    165. 

  165.                 <li><a href="/blog/category/firefox">Firefox</a></li>
    166. 

  166.                 <li><a href="/blog/category/git">Git</a></li>
    167. 

  167.                 <li><a href="/blog/category/javascript">JavaScript</a></li>
    168. 

  168.                 <li><a href="/blog/category/mercurial">Mercurial</a></li>
    169. 

  169.                 <li><a href="/blog/category/mozreview">MozReview</a></li>
    170. 

  170.                 <li><a href="/blog/category/mozilla">Mozilla</a></li>
    171. 

  171.                 <li><a href="/blog/category/personal">Personal</a></li>
    172. 

  172.                 <li><a href="/blog/category/programming">Programming</a></li>
    173. 

  173.                 <li><a href="/blog/category/puppet">Puppet</a></li>
    174. 

  174.                 <li><a href="/blog/category/pyoxidizer">PyOxidizer</a></li>
    175. 

  175.                 <li><a href="/blog/category/python">Python</a></li>
    176. 

  176.                 <li><a href="/blog/category/review-board">Review Board</a></li>
    177. 

  177.                 <li><a href="/blog/category/rust">Rust</a></li>
    178. 

  178.                 <li><a href="/blog/category/sync">Sync</a></li>
    179. 

  179.                 <li><a href="/blog/category/browsers">browsers</a></li>
    180. 

  180.                 <li><a href="/blog/category/build-system">build system</a></li>
    181. 

  181.                 <li><a href="/blog/category/code-review">code review</a></li>
    182. 

  182.                 <li><a href="/blog/category/compilers">compilers</a></li>
    183. 

  183.                 <li><a href="/blog/category/internet">internet</a></li>
    184. 

  184.                 <li><a href="/blog/category/logging">logging</a></li>
    185. 

  185.                 <li><a href="/blog/category/mach">mach</a></li>
    186. 

  186.                 <li><a href="/blog/category/make">make</a></li>
    187. 

  187.                 <li><a href="/blog/category/misc">misc</a></li>
    188. 

  188.                 <li><a href="/blog/category/movies">movies</a></li>
    189. 

  189.                 <li><a href="/blog/category/packaging">packaging</a></li>
    190. 

  190.                 <li><a href="/blog/category/pymake">pymake</a></li>
    191. 

  191.                 <li><a href="/blog/category/security">security</a></li>
    192. 

  192.                 <li><a href="/blog/category/sysadmin">sysadmin</a></li>
    193. 

  193.                 <li><a href="/blog/category/testing">testing</a></li>
    194. 

  194.               </ul>
    195. 

  195.             </li>
    196. 

  196.           </ul>
    197. 

  197.         </div>
    198. 

  198. 

  199. 

  200. 

  201.               <div style="clear: both;">&nbsp;</div>
    202. 

  202.           </div>
    203. 

  203.         </div>
    204. 

  204.       </div>
    205. 

  205.       <div id="footer">
    206. 

  206.         
    207. 

  207.   <hr/>
    208. 

  208.   <p>Copyright (c) 2012- Gregory Szorc. All rights reserved. Design by <a href="http://www.freecsstemplates.org/"> CSS Templates</a>.</p>
    209. 

  209. 

  210. 

  211.       </div>
    212. 

  212.     </div>
    213. 

  213.   </body>
    214. 

  214. </html>
    215. 

  215. 

  216. 

  217. 

  218. 

  219. 

  220.