I have the following code (running in LINQPad) which takes tens of thousands of CSV files and concatenates them to create a single file.
Each CSV file has two lines: a header line and a data line. I need the header line only once, then the rest of the lines are data.
However, it appears to be getting slower as it runs over the course of several minutes. Why is it doing this, and what can I do to make it faster overall?
Each file is only 3KB apiece. For example, the output below was from a run of about 55K files and the resulting CSV file was just under 8MB.
// Directory path - This is the directory where all of the csv's you want to combine reside
var path = @"E:\a1";
// Destination path - Needs to be different from the directory Path we defined in the first step. This is where the combined csv file will be placed
var destination = @"E:\MasterFileA1.csv";
var dirInfo = new DirectoryInfo(path);
var enumFiles = dirInfo.EnumerateFiles("*.csv", SearchOption.TopDirectoryOnly);
int counter = 0;
string header;
string data;
DateTime start = DateTime.Now;
TimeSpan elapsed;
FileStream stream = new FileStream(destination, FileMode.Append, FileAccess.Write);
StreamWriter writer = new StreamWriter(stream);
foreach(var file in enumFiles)
{
StreamReader reader = new StreamReader(file.FullName);
header = reader.ReadLine();
data = reader.ReadLine();
reader.Close();
if (counter == 0)
{
writer.WriteLine(header);
}
writer.WriteLine(data);
counter++;
if (counter % 1000 == 0)
{
//writer.Flush();
elapsed = DateTime.Now.Subtract(start);
Console.WriteLine("Processed: " + counter + " files. Elapsed Time: " + String.Format("{0}:{1}", elapsed.Minutes, elapsed.Seconds) +
" Time per file: " + Math.Round(elapsed.TotalMilliseconds/counter, 4) + " ms");
}
}
writer.Flush();
writer.Close();
Output via Console
:
Processed: 1000 files. Elapsed Time: 0:2 Time per file: 2.574 ms Processed: 2000 files. Elapsed Time: 0:4 Time per file: 2.4671 ms Processed: 3000 files. Elapsed Time: 0:7 Time per file: 2.4406 ms Processed: 4000 files. Elapsed Time: 0:9 Time per file: 2.4353 ms Processed: 5000 files. Elapsed Time: 0:12 Time per file: 2.4227 ms Processed: 6000 files. Elapsed Time: 0:14 Time per file: 2.4123 ms Processed: 7000 files. Elapsed Time: 0:17 Time per file: 2.4495 ms Processed: 8000 files. Elapsed Time: 0:19 Time per file: 2.4368 ms Processed: 9000 files. Elapsed Time: 0:21 Time per file: 2.4285 ms Processed: 10000 files. Elapsed Time: 0:24 Time per file: 2.4231 ms Processed: 11000 files. Elapsed Time: 0:26 Time per file: 2.4167 ms Processed: 12000 files. Elapsed Time: 0:28 Time per file: 2.4118 ms Processed: 13000 files. Elapsed Time: 0:31 Time per file: 2.4104 ms Processed: 14000 files. Elapsed Time: 0:33 Time per file: 2.4094 ms Processed: 15000 files. Elapsed Time: 0:36 Time per file: 2.4062 ms Processed: 16000 files. Elapsed Time: 0:38 Time per file: 2.4031 ms Processed: 17000 files. Elapsed Time: 0:40 Time per file: 2.4009 ms Processed: 18000 files. Elapsed Time: 0:43 Time per file: 2.4004 ms Processed: 19000 files. Elapsed Time: 0:45 Time per file: 2.3979 ms Processed: 20000 files. Elapsed Time: 0:47 Time per file: 2.3955 ms Processed: 21000 files. Elapsed Time: 0:50 Time per file: 2.3945 ms Processed: 22000 files. Elapsed Time: 0:52 Time per file: 2.3936 ms Processed: 23000 files. Elapsed Time: 0:55 Time per file: 2.3987 ms Processed: 24000 files. Elapsed Time: 0:57 Time per file: 2.3981 ms Processed: 25000 files. Elapsed Time: 0:59 Time per file: 2.3968 ms Processed: 26000 files. Elapsed Time: 1:2 Time per file: 2.3966 ms Processed: 27000 files. Elapsed Time: 1:4 Time per file: 2.3945 ms Processed: 28000 files. Elapsed Time: 1:7 Time per file: 2.3938 ms Processed: 29000 files. Elapsed Time: 1:9 Time per file: 2.3934 ms Processed: 30000 files. Elapsed Time: 1:11 Time per file: 2.3927 ms Processed: 31000 files. Elapsed Time: 1:23 Time per file: 2.6784 ms Processed: 32000 files. Elapsed Time: 1:35 Time per file: 2.9779 ms Processed: 33000 files. Elapsed Time: 1:47 Time per file: 3.2714 ms Processed: 34000 files. Elapsed Time: 2:0 Time per file: 3.5462 ms Processed: 35000 files. Elapsed Time: 2:12 Time per file: 3.7953 ms Processed: 36000 files. Elapsed Time: 2:25 Time per file: 4.0352 ms Processed: 37000 files. Elapsed Time: 2:38 Time per file: 4.2769 ms Processed: 38000 files. Elapsed Time: 2:50 Time per file: 4.4893 ms Processed: 39000 files. Elapsed Time: 3:3 Time per file: 4.6924 ms Processed: 40000 files. Elapsed Time: 3:15 Time per file: 4.8848 ms Processed: 41000 files. Elapsed Time: 3:27 Time per file: 5.0673 ms Processed: 42000 files. Elapsed Time: 3:40 Time per file: 5.2461 ms Processed: 43000 files. Elapsed Time: 3:53 Time per file: 5.4223 ms Processed: 44000 files. Elapsed Time: 4:5 Time per file: 5.5781 ms Processed: 45000 files. Elapsed Time: 4:17 Time per file: 5.7302 ms Processed: 46000 files. Elapsed Time: 4:30 Time per file: 5.8799 ms Processed: 47000 files. Elapsed Time: 4:42 Time per file: 6.0171 ms Processed: 48000 files. Elapsed Time: 4:55 Time per file: 6.1547 ms Processed: 49000 files. Elapsed Time: 5:9 Time per file: 6.3069 ms Processed: 50000 files. Elapsed Time: 5:21 Time per file: 6.4373 ms Processed: 51000 files. Elapsed Time: 5:34 Time per file: 6.5605 ms Processed: 52000 files. Elapsed Time: 5:47 Time per file: 6.6796 ms Processed: 53000 files. Elapsed Time: 5:59 Time per file: 6.7909 ms Processed: 54000 files. Elapsed Time: 6:12 Time per file: 6.9046 ms Processed: 55000 files. Elapsed Time: 6:25 Time per file: 7.0035 ms
Update
This is an unsatisfying result, but I think the problem was that the source and destination path were both on an external HDD connected via USB 3.0. Once I copied the files over and was working only on my local hard drive, the speed of execution stayed constant.
Now working locally, I tested my original code against the suggestions provided by xDaevax - that is, I incorporated using
statements for both the reader and the writer. The results:
- Original code took 2.66 ms per file
- New code took 5.82 ms per file
I assume this is primarily because I was opening a new StreamWriter every time, whereas in the original code I left the StreamWriter open but opened and closed the StreamReader. I also tried adding a using
statement just to the StreamReader (not the Writer) and was the same speed as my original code.
What is the benefit of opening and closing the StreamWriter for each write, if not performance? (this question still hasn't been answered, so if you're reading this and want to contribute, please do so)
Update 2
Implementing Brandon's suggestions for using a StringBuilder
and also reading the input CSV in one interaction, I was able to reduce the time per file by nearly 20% to 2.17 ms. I also just generally used better structure for the program as a whole, and added some formatting to the output.
As a bonus, now that I am accessing the lines of the input CSVs as array elements, I detected a file that wasn't created properly when I hit an "index outside bounds of array" error, so I added a try/catch to handle that and tell me which file it was.
Here's the "final" version (but is tinkering ever really finished?):
void Main()
{
// Directory path
string path = @"C:\a1";
// Destination path (must be different from directory path)
string destination = @"C:\MasterFileA1.csv";
int counter = 0;
TimeSpan globalElapsed;
TimeSpan intervalElapsed;
FileStream stream = new FileStream(destination, FileMode.CreateNew, FileAccess.Write);
StreamWriter writer = new StreamWriter(stream);
StringBuilder sb = new StringBuilder();
// Pull list of files into string array
IEnumerable enumFiles = EnumerateFiles(path);
// Start stopwatches
Stopwatch globalTimer = Stopwatch.StartNew();
Stopwatch intervalTimer = Stopwatch.StartNew();
foreach(FileInfo file in enumFiles)
{
try
{
// Read file
string[] fileText = File.ReadAllLines(file.FullName);
// Append lines to StringBuilder object
if (counter == 0)
{
sb.Append(fileText[0] + "\r\n");
sb.Append(fileText[1] + "\r\n");
}
else
{
sb.Append(fileText[1] + "\r\n");
}
}
catch (Exception e)
{
Console.WriteLine("Error occurred at file " + counter + ": " + file.FullName + ". " + e.Message);
}
// Log progress to console
if (counter % 1000 == 0 && counter != 0)
{
globalElapsed = globalTimer.Elapsed;
intervalElapsed = intervalTimer.Elapsed;
Console.WriteLine("Processed: " + String.Format("{0:00000}",counter) + " files. " +
"Elapsed Time: " + String.Format("{0:00}:{1:00}", globalElapsed.Minutes, globalElapsed.Seconds) + " " +
"Time per file (last 1000): " + String.Format("{0:00.00}", Math.Round(intervalElapsed.TotalMilliseconds / 1000, 2)) + " ms " +
"Time per file (total): " + String.Format("{0:00.00}", Math.Round(globalElapsed.TotalMilliseconds / counter, 2)) + " ms");
intervalTimer.Reset();
intervalTimer.Start();
}
counter++;
}
globalTimer.Stop();
// Write concatenated string to file
writer.Write(sb.ToString());
writer.Flush();
writer.Close();
}
public IEnumerable EnumerateFiles(string path)
{
Console.WriteLine("Enumerating files...");
Stopwatch getFilesTimer = Stopwatch.StartNew();
var enumFiles = new DirectoryInfo(path).EnumerateFiles("*.csv", SearchOption.TopDirectoryOnly);
getFilesTimer.Stop();
TimeSpan getFilesElapsed = getFilesTimer.Elapsed;
Console.WriteLine("Enumeration complete. Time taken: " + getFilesElapsed.TotalMilliseconds + " ms");
return enumFiles;
}
The output:
Enumerating files... Enumeration complete. Time taken: 0.2707 ms Processed: 01000 files. Elapsed Time: 00:02 Time per file (last 1000): 02.38 ms Time per file (total): 02.38 ms Processed: 02000 files. Elapsed Time: 00:04 Time per file (last 1000): 02.23 ms Time per file (total): 02.30 ms Processed: 03000 files. Elapsed Time: 00:06 Time per file (last 1000): 02.27 ms Time per file (total): 02.29 ms Processed: 04000 files. Elapsed Time: 00:09 Time per file (last 1000): 02.26 ms Time per file (total): 02.28 ms Processed: 05000 files. Elapsed Time: 00:11 Time per file (last 1000): 02.31 ms Time per file (total): 02.29 ms Processed: 06000 files. Elapsed Time: 00:13 Time per file (last 1000): 02.07 ms Time per file (total): 02.25 ms Processed: 07000 files. Elapsed Time: 00:15 Time per file (last 1000): 02.02 ms Time per file (total): 02.22 ms Processed: 08000 files. Elapsed Time: 00:17 Time per file (last 1000): 02.08 ms Time per file (total): 02.20 ms Processed: 09000 files. Elapsed Time: 00:19 Time per file (last 1000): 02.32 ms Time per file (total): 02.22 ms Processed: 10000 files. Elapsed Time: 00:22 Time per file (last 1000): 02.32 ms Time per file (total): 02.23 ms Processed: 11000 files. Elapsed Time: 00:24 Time per file (last 1000): 02.33 ms Time per file (total): 02.24 ms Processed: 12000 files. Elapsed Time: 00:26 Time per file (last 1000): 02.33 ms Time per file (total): 02.24 ms Processed: 13000 files. Elapsed Time: 00:29 Time per file (last 1000): 02.09 ms Time per file (total): 02.23 ms Processed: 14000 files. Elapsed Time: 00:31 Time per file (last 1000): 02.18 ms Time per file (total): 02.23 ms Processed: 15000 files. Elapsed Time: 00:33 Time per file (last 1000): 02.01 ms Time per file (total): 02.21 ms Processed: 16000 files. Elapsed Time: 00:35 Time per file (last 1000): 02.02 ms Time per file (total): 02.20 ms Processed: 17000 files. Elapsed Time: 00:37 Time per file (last 1000): 02.01 ms Time per file (total): 02.19 ms Processed: 18000 files. Elapsed Time: 00:39 Time per file (last 1000): 02.01 ms Time per file (total): 02.18 ms Processed: 19000 files. Elapsed Time: 00:41 Time per file (last 1000): 02.00 ms Time per file (total): 02.17 ms Processed: 20000 files. Elapsed Time: 00:43 Time per file (last 1000): 02.02 ms Time per file (total): 02.16 ms Processed: 21000 files. Elapsed Time: 00:45 Time per file (last 1000): 02.01 ms Time per file (total): 02.16 ms Processed: 22000 files. Elapsed Time: 00:47 Time per file (last 1000): 02.37 ms Time per file (total): 02.17 ms Processed: 23000 files. Elapsed Time: 00:49 Time per file (last 1000): 02.31 ms Time per file (total): 02.17 ms Processed: 24000 files. Elapsed Time: 00:52 Time per file (last 1000): 02.24 ms Time per file (total): 02.18 ms Processed: 25000 files. Elapsed Time: 00:54 Time per file (last 1000): 02.02 ms Time per file (total): 02.17 ms Processed: 26000 files. Elapsed Time: 00:56 Time per file (last 1000): 02.00 ms Time per file (total): 02.16 ms Processed: 27000 files. Elapsed Time: 00:58 Time per file (last 1000): 02.02 ms Time per file (total): 02.16 ms Processed: 28000 files. Elapsed Time: 01:00 Time per file (last 1000): 02.00 ms Time per file (total): 02.15 ms Processed: 29000 files. Elapsed Time: 01:02 Time per file (last 1000): 02.02 ms Time per file (total): 02.15 ms Processed: 30000 files. Elapsed Time: 01:04 Time per file (last 1000): 02.01 ms Time per file (total): 02.14 ms Processed: 31000 files. Elapsed Time: 01:06 Time per file (last 1000): 01.99 ms Time per file (total): 02.14 ms Processed: 32000 files. Elapsed Time: 01:08 Time per file (last 1000): 02.01 ms Time per file (total): 02.13 ms Processed: 33000 files. Elapsed Time: 01:10 Time per file (last 1000): 02.01 ms Time per file (total): 02.13 ms Processed: 34000 files. Elapsed Time: 01:12 Time per file (last 1000): 02.14 ms Time per file (total): 02.13 ms Processed: 35000 files. Elapsed Time: 01:14 Time per file (last 1000): 02.30 ms Time per file (total): 02.14 ms Processed: 36000 files. Elapsed Time: 01:17 Time per file (last 1000): 02.30 ms Time per file (total): 02.14 ms Processed: 37000 files. Elapsed Time: 01:19 Time per file (last 1000): 02.30 ms Time per file (total): 02.14 ms Processed: 38000 files. Elapsed Time: 01:21 Time per file (last 1000): 02.33 ms Time per file (total): 02.15 ms Processed: 39000 files. Elapsed Time: 01:23 Time per file (last 1000): 02.31 ms Time per file (total): 02.15 ms Processed: 40000 files. Elapsed Time: 01:26 Time per file (last 1000): 02.31 ms Time per file (total): 02.16 ms Processed: 41000 files. Elapsed Time: 01:28 Time per file (last 1000): 02.34 ms Time per file (total): 02.16 ms Processed: 42000 files. Elapsed Time: 01:30 Time per file (last 1000): 02.33 ms Time per file (total): 02.17 ms Processed: 43000 files. Elapsed Time: 01:33 Time per file (last 1000): 02.33 ms Time per file (total): 02.17 ms Processed: 44000 files. Elapsed Time: 01:35 Time per file (last 1000): 02.25 ms Time per file (total): 02.17 ms Processed: 45000 files. Elapsed Time: 01:37 Time per file (last 1000): 02.00 ms Time per file (total): 02.17 ms Error occurred at file 45257: C:\a1\W09K6240177_20160726211002_Results.csv. Index was outside the bounds of the array. Processed: 46000 files. Elapsed Time: 01:39 Time per file (last 1000): 02.14 ms Time per file (total): 02.17 ms Processed: 47000 files. Elapsed Time: 01:41 Time per file (last 1000): 01.99 ms Time per file (total): 02.16 ms Processed: 48000 files. Elapsed Time: 01:44 Time per file (last 1000): 02.38 ms Time per file (total): 02.17 ms Processed: 49000 files. Elapsed Time: 01:46 Time per file (last 1000): 02.01 ms Time per file (total): 02.16 ms Processed: 50000 files. Elapsed Time: 01:48 Time per file (last 1000): 02.05 ms Time per file (total): 02.16 ms Processed: 51000 files. Elapsed Time: 01:50 Time per file (last 1000): 02.28 ms Time per file (total): 02.16 ms Processed: 52000 files. Elapsed Time: 01:52 Time per file (last 1000): 02.32 ms Time per file (total): 02.17 ms Processed: 53000 files. Elapsed Time: 01:54 Time per file (last 1000): 02.30 ms Time per file (total): 02.17 ms Processed: 54000 files. Elapsed Time: 01:57 Time per file (last 1000): 02.29 ms Time per file (total): 02.17 ms Processed: 55000 files. Elapsed Time: 01:59 Time per file (last 1000): 01.99 ms Time per file (total): 02.17 ms
StopWatch
type built into theSystem.Diagnostics
namespace instead of using DateTime. It's much more precise and will give you better metrics. Do you have any perfcounter data to see what the memory usage is as time goes on? \$\endgroup\$using
on the input stream \$\endgroup\$IDisposable
and you're supposed to use them withusing
? \$\endgroup\$