diff --git a/osrepodbmgr.Core/ChangeLog b/osrepodbmgr.Core/ChangeLog index 09df852..42716a5 100644 --- a/osrepodbmgr.Core/ChangeLog +++ b/osrepodbmgr.Core/ChangeLog @@ -1,3 +1,13 @@ +2017-05-19 Natalia Portillo + + * SQLite.cs: + * Workers/Files.cs: + * Workers/Database.cs: + * Workers/VirusTotal.cs: + * Workers/Compression.cs: + * Workers/DiscImageChef.cs: + Added some performance counters. + 2017-05-19 Natalia Portillo * Workers/VirusTotal.cs: diff --git a/osrepodbmgr.Core/SQLite.cs b/osrepodbmgr.Core/SQLite.cs index 3e6ab32..6b2b624 100644 --- a/osrepodbmgr.Core/SQLite.cs +++ b/osrepodbmgr.Core/SQLite.cs @@ -96,7 +96,9 @@ namespace osrepodbmgr.Core SQLiteCommand dbCmd = dbCon.CreateCommand(); string sql; +#if DEBUG Console.WriteLine("Creating osrepodbmgr table"); +#endif sql = "CREATE TABLE osrepodbmgr ( version INTEGER, name TEXT )"; dbCmd.CommandText = sql; @@ -106,11 +108,15 @@ namespace osrepodbmgr.Core dbCmd.CommandText = sql; dbCmd.ExecuteNonQuery(); +#if DEBUG Console.WriteLine("Creating oses table"); +#endif dbCmd.CommandText = Schema.OSesTableSql; dbCmd.ExecuteNonQuery(); +#if DEBUG Console.WriteLine("Creating files table"); +#endif dbCmd.CommandText = Schema.FilesTableSql; dbCmd.ExecuteNonQuery(); diff --git a/osrepodbmgr.Core/Workers/Compression.cs b/osrepodbmgr.Core/Workers/Compression.cs index 33aea86..b2086ff 100644 --- a/osrepodbmgr.Core/Workers/Compression.cs +++ b/osrepodbmgr.Core/Workers/Compression.cs @@ -188,6 +188,9 @@ namespace osrepodbmgr.Core break; } +#if DEBUG + stopwatch.Restart(); +#endif foreach(KeyValuePair file in Context.hashes) { if(UpdateProgress != null) @@ -251,6 +254,10 @@ namespace osrepodbmgr.Core counter++; } +#if DEBUG + stopwatch.Stop(); + Console.WriteLine("Core.CompressFiles(): Took {0} seconds to compress files", stopwatch.Elapsed.TotalSeconds); +#endif if(Context.metadata != null) { @@ -319,6 +326,9 @@ namespace osrepodbmgr.Core string lsarfilename = unarfilename.Replace("unar", "lsar"); string lsarPath = Path.Combine(unarFolder, lsarfilename + extension); +#if DEBUG + stopwatch.Restart(); +#endif Process lsarProcess = new Process(); lsarProcess.StartInfo.FileName = lsarPath; lsarProcess.StartInfo.CreateNoWindow = true; @@ -328,7 +338,11 @@ namespace osrepodbmgr.Core lsarProcess.Start(); string lsarOutput = lsarProcess.StandardOutput.ReadToEnd(); lsarProcess.WaitForExit(); - +#if DEBUG + stopwatch.Stop(); + Console.WriteLine("Core.OpenArchive(): Took {0} seconds to list archive contents", stopwatch.Elapsed.TotalSeconds); + stopwatch.Restart(); +#endif long counter = 0; string format = null; JsonTextReader jsReader = new JsonTextReader(new StringReader(lsarOutput)); @@ -343,6 +357,10 @@ namespace osrepodbmgr.Core format = jsReader.Value.ToString(); } } +#if DEBUG + stopwatch.Stop(); + Console.WriteLine("Core.OpenArchive(): Took {0} seconds to process archive contents", stopwatch.Elapsed.TotalSeconds); +#endif Context.unzipWithUnAr = false; Context.archiveFormat = format; @@ -368,6 +386,9 @@ namespace osrepodbmgr.Core if(Context.usableDotNetZip) { +#if DEBUG + stopwatch.Restart(); +#endif ZipFile zf = ZipFile.Read(Context.path, new ReadOptions { Encoding = Encoding.UTF8 }); foreach(ZipEntry ze in zf) { @@ -378,6 +399,10 @@ namespace osrepodbmgr.Core break; } } +#if DEBUG + stopwatch.Stop(); + Console.WriteLine("Core.OpenArchive(): Took {0} seconds to navigate in search of Mac OS X metadata", stopwatch.Elapsed.TotalSeconds); +#endif } } @@ -437,6 +462,9 @@ namespace osrepodbmgr.Core { try { +#if DEBUG + stopwatch.Restart(); +#endif ZipFile zf = ZipFile.Read(Context.path, new ReadOptions { Encoding = Encoding.UTF8 }); zf.ExtractExistingFile = ExtractExistingFileAction.OverwriteSilently; zf.ExtractProgress += Zf_ExtractProgress; @@ -466,6 +494,9 @@ namespace osrepodbmgr.Core return; } +#if DEBUG + stopwatch.Restart(); +#endif Context.unarProcess = new Process(); Context.unarProcess.StartInfo.FileName = Settings.Current.UnArchiverPath; Context.unarProcess.StartInfo.CreateNoWindow = true; @@ -484,6 +515,10 @@ namespace osrepodbmgr.Core Context.unarProcess.WaitForExit(); Context.unarProcess.Close(); Context.unarProcess = null; +#if DEBUG + stopwatch.Stop(); + Console.WriteLine("Core.ExtractArchive(): Took {0} seconds to extract archive contents using UnAr", stopwatch.Elapsed.TotalSeconds); +#endif if(Finished != null) Finished(); @@ -513,9 +548,14 @@ namespace osrepodbmgr.Core string.Format("{0} / {1}", e.BytesTransferred, e.TotalBytesToTransfer), e.BytesTransferred, e.TotalBytesToTransfer); - Console.WriteLine("{0}", e.EventType); if(e.EventType == ZipProgressEventType.Extracting_AfterExtractAll && Finished != null) + { +#if DEBUG + stopwatch.Stop(); + Console.WriteLine("Core.Zf_ExtractProgress(): Took {0} seconds to extract archive contents using DotNetZip", stopwatch.Elapsed.TotalSeconds); +#endif Finished(); + } } public static void CompressTo() @@ -575,6 +615,9 @@ namespace osrepodbmgr.Core if(UpdateProgress != null) UpdateProgress("", "Creating folders...", 3, 100); +#if DEBUG + stopwatch.Restart(); +#endif counter = 0; foreach(DBFolder folder in folders) { @@ -590,9 +633,16 @@ namespace osrepodbmgr.Core counter++; } +#if DEBUG + stopwatch.Stop(); + Console.WriteLine("Core.CompressTo(): Took {0} seconds to add folders to ZIP", stopwatch.Elapsed.TotalSeconds); +#endif counter = 3; Context.hashes = new Dictionary(); +#if DEBUG + stopwatch.Restart(); +#endif foreach(DBOSFile file in files) { if(UpdateProgress != null) @@ -609,7 +659,11 @@ namespace osrepodbmgr.Core counter++; } - +#if DEBUG + stopwatch.Stop(); + Console.WriteLine("Core.CompressTo(): Took {0} seconds to add files to ZIP", stopwatch.Elapsed.TotalSeconds); + stopwatch.Restart(); +#endif zipCounter = 0; zipCurrentEntryName = ""; zf.Save(); @@ -721,7 +775,13 @@ namespace osrepodbmgr.Core Failed("An error occurred creating ZIP file."); if(e.EventType == ZipProgressEventType.Saving_Completed && Finished != null) + { +#if DEBUG + stopwatch.Stop(); + Console.WriteLine("Core.Zf_SaveProgress(): Took {0} seconds to compress files to ZIP", stopwatch.Elapsed.TotalSeconds); +#endif Finished(); + } } } } diff --git a/osrepodbmgr.Core/Workers/Database.cs b/osrepodbmgr.Core/Workers/Database.cs index fb9b44d..cc94cfc 100644 --- a/osrepodbmgr.Core/Workers/Database.cs +++ b/osrepodbmgr.Core/Workers/Database.cs @@ -38,11 +38,21 @@ namespace osrepodbmgr.Core { try { +#if DEBUG + stopwatch.Restart(); +#endif List oses; dbCore.DBOps.GetAllOSes(out oses); +#if DEBUG + stopwatch.Stop(); + Console.WriteLine("Core.GetAllOSes(): Took {0} seconds to get OSes from database", stopwatch.Elapsed.TotalSeconds); +#endif if(AddOS != null) { +#if DEBUG + stopwatch.Restart(); +#endif int counter = 0; // TODO: Check file name and existence foreach(DBEntry os in oses) @@ -58,6 +68,10 @@ namespace osrepodbmgr.Core counter++; } +#if DEBUG + stopwatch.Stop(); + Console.WriteLine("Core.GetAllOSes(): Took {0} seconds to add OSes to the GUI", stopwatch.Elapsed.TotalSeconds); +#endif } if(Finished != null) @@ -77,6 +91,9 @@ namespace osrepodbmgr.Core try { long counter = 0; +#if DEBUG + stopwatch.Restart(); +#endif foreach(KeyValuePair kvp in Context.hashes) { if(UpdateProgress != null) @@ -87,11 +104,19 @@ namespace osrepodbmgr.Core counter++; } - +#if DEBUG + stopwatch.Stop(); + Console.WriteLine("Core.CheckDbForFiles(): Took {0} seconds to checks for file knowledge in the DB", stopwatch.Elapsed.TotalSeconds); + stopwatch.Restart(); +#endif if(UpdateProgress != null) UpdateProgress(null, "Retrieving OSes from database", counter, Context.hashes.Count); List oses; dbCore.DBOps.GetAllOSes(out oses); +#if DEBUG + stopwatch.Stop(); + Console.WriteLine("Core.CheckDbForFiles(): Took {0} seconds get all OSes from DB", stopwatch.Elapsed.TotalSeconds); +#endif if(oses != null && oses.Count > 0) { @@ -99,6 +124,9 @@ namespace osrepodbmgr.Core oses.CopyTo(osesArray); long osCounter = 0; +#if DEBUG + stopwatch.Restart(); +#endif foreach(DBEntry os in osesArray) { if(UpdateProgress != null) @@ -125,6 +153,10 @@ namespace osrepodbmgr.Core if(oses.Count == 0) break; // No OSes left } +#if DEBUG + stopwatch.Stop(); + Console.WriteLine("Core.CheckDbForFiles(): Took {0} seconds correlate all files with all known OSes", stopwatch.Elapsed.TotalSeconds); +#endif } if(AddOS != null) @@ -158,6 +190,9 @@ namespace osrepodbmgr.Core try { long counter = 0; +#if DEBUG + stopwatch.Restart(); +#endif foreach(KeyValuePair kvp in Context.hashes) { if(UpdateProgress != null) @@ -178,6 +213,10 @@ namespace osrepodbmgr.Core counter++; } +#if DEBUG + stopwatch.Stop(); + Console.WriteLine("Core.AddFilesToDb(): Took {0} seconds to add all files to the database", stopwatch.Elapsed.TotalSeconds); +#endif if(UpdateProgress != null) UpdateProgress(null, "Adding OS information", counter, Context.hashes.Count); @@ -186,6 +225,9 @@ namespace osrepodbmgr.Core UpdateProgress(null, "Creating OS table", counter, Context.hashes.Count); dbCore.DBOps.CreateTableForOS(Context.dbInfo.id); +#if DEBUG + stopwatch.Restart(); +#endif counter = 0; foreach(KeyValuePair kvp in Context.hashes) { @@ -196,7 +238,11 @@ namespace osrepodbmgr.Core counter++; } - +#if DEBUG + stopwatch.Stop(); + Console.WriteLine("Core.AddFilesToDb(): Took {0} seconds to add all files to the OS in the database", stopwatch.Elapsed.TotalSeconds); + stopwatch.Restart(); +#endif counter = 0; foreach(KeyValuePair kvp in Context.foldersDict) { @@ -207,6 +253,10 @@ namespace osrepodbmgr.Core counter++; } +#if DEBUG + stopwatch.Stop(); + Console.WriteLine("Core.AddFilesToDb(): Took {0} seconds to add all folders to the database", stopwatch.Elapsed.TotalSeconds); +#endif if(Finished != null) Finished(); @@ -305,6 +355,9 @@ namespace osrepodbmgr.Core List files; +#if DEBUG + stopwatch.Restart(); +#endif while(dbCore.DBOps.GetFiles(out files, offset, page)) { if(files.Count == 0) @@ -319,6 +372,10 @@ namespace osrepodbmgr.Core offset += page; } +#if DEBUG + stopwatch.Stop(); + Console.WriteLine("Core.GetFilesFromDb(): Took {0} seconds to get all files from the database", stopwatch.Elapsed.TotalSeconds); +#endif if(Finished != null) Finished(); diff --git a/osrepodbmgr.Core/Workers/DiscImageChef.cs b/osrepodbmgr.Core/Workers/DiscImageChef.cs index 0534c1b..bfec184 100644 --- a/osrepodbmgr.Core/Workers/DiscImageChef.cs +++ b/osrepodbmgr.Core/Workers/DiscImageChef.cs @@ -90,9 +90,16 @@ namespace osrepodbmgr.Core try { +#if DEBUG + stopwatch.Restart(); +#endif if(UpdateProgress != null) UpdateProgress(null, "Detecting image format", 2, maxProgress); _imageFormat = ImageFormat.Detect(inputFilter); +#if DEBUG + stopwatch.Stop(); + Console.WriteLine("Core.AddMedia(): Took {0} seconds to detect image format", stopwatch.Elapsed.TotalSeconds); +#endif if(_imageFormat == null) { @@ -127,6 +134,9 @@ namespace osrepodbmgr.Core if(UpdateProgress != null) UpdateProgress(null, "Hashing image file", 3, maxProgress); +#if DEBUG + stopwatch.Restart(); +#endif byte[] data; long position = 0; while(position < (fi.Length - 524288)) @@ -151,6 +161,10 @@ namespace osrepodbmgr.Core imgChkWorker.Update(data); fs.Close(); +#if DEBUG + stopwatch.Stop(); + Console.WriteLine("Core.AddMedia(): Took {0} seconds to hash image file", stopwatch.Elapsed.TotalSeconds); +#endif List imgChecksums = imgChkWorker.End(); @@ -192,6 +206,9 @@ namespace osrepodbmgr.Core currentProgress = 3; +#if DEBUG + stopwatch.Restart(); +#endif foreach(MediaTagType tagType in _imageFormat.ImageInfo.readableMediaTags) { currentProgress++; @@ -342,6 +359,10 @@ namespace osrepodbmgr.Core break; } } +#if DEBUG + stopwatch.Stop(); + Console.WriteLine("Core.AddMedia(): Took {0} seconds to hash media tags", stopwatch.Elapsed.TotalSeconds); +#endif try { @@ -451,6 +472,9 @@ namespace osrepodbmgr.Core ulong sectors = (ulong)(xmlTrk.EndSector - xmlTrk.StartSector + 1); ulong doneSectors = 0; +#if DEBUG + stopwatch.Restart(); +#endif while(doneSectors < sectors) { byte[] sector; @@ -474,6 +498,10 @@ namespace osrepodbmgr.Core } List trkChecksums = trkChkWorker.End(); +#if DEBUG + stopwatch.Stop(); + Console.WriteLine("Core.AddMedia(): Took {0} seconds to hash track {1}", stopwatch.Elapsed.TotalSeconds, trk.TrackSequence); +#endif xmlTrk.Checksums = trkChecksums.ToArray(); @@ -518,6 +546,9 @@ namespace osrepodbmgr.Core sectors = (ulong)(xmlTrk.EndSector - xmlTrk.StartSector + 1); doneSectors = 0; +#if DEBUG + stopwatch.Restart(); +#endif while(doneSectors < sectors) { byte[] sector; @@ -543,6 +574,10 @@ namespace osrepodbmgr.Core List subChecksums = subChkWorker.End(); xmlTrk.SubChannel.Checksums = subChecksums.ToArray(); +#if DEBUG + stopwatch.Stop(); + Console.WriteLine("Core.AddMedia(): Took {0} seconds to hash subchannel of track {1}", stopwatch.Elapsed.TotalSeconds, trk.TrackSequence); +#endif if(UpdateProgress2 != null) UpdateProgress2(null, null, 0, 0); @@ -551,6 +586,9 @@ namespace osrepodbmgr.Core if(UpdateProgress != null) UpdateProgress(null, "Checking filesystems", maxProgress - 1, maxProgress); +#if DEBUG + stopwatch.Restart(); +#endif List partitions = new List(); foreach(PartPlugin _partplugin in plugins.PartPluginsList.Values) @@ -648,6 +686,10 @@ namespace osrepodbmgr.Core if(lstFs.Count > 0) xmlTrk.FileSystemInformation[0].FileSystems = lstFs.ToArray(); } +#if DEBUG + stopwatch.Stop(); + Console.WriteLine("Core.AddMedia(): Took {0} seconds to check all filesystems on track {1}", stopwatch.Elapsed.TotalSeconds, trk.TrackSequence); +#endif trksLst.Add(xmlTrk); } @@ -716,6 +758,9 @@ namespace osrepodbmgr.Core currentProgress = 3; +#if DEBUG + stopwatch.Restart(); +#endif foreach(MediaTagType tagType in _imageFormat.ImageInfo.readableMediaTags) { currentProgress++; @@ -803,6 +848,10 @@ namespace osrepodbmgr.Core break; } } +#if DEBUG + stopwatch.Stop(); + Console.WriteLine("Core.AddMedia(): Took {0} seconds to hash media tags", stopwatch.Elapsed.TotalSeconds); +#endif string dskType, dskSubType; DiscImageChef.Metadata.MediaType.MediaTypeToString(_imageFormat.ImageInfo.mediaType, out dskType, out dskSubType); @@ -819,6 +868,9 @@ namespace osrepodbmgr.Core if(UpdateProgress != null) UpdateProgress(null, "Checking filesystems", maxProgress - 1, maxProgress); +#if DEBUG + stopwatch.Restart(); +#endif List partitions = new List(); foreach(PartPlugin _partplugin in plugins.PartPluginsList.Values) @@ -901,6 +953,10 @@ namespace osrepodbmgr.Core if(lstFs.Count > 0) sidecar.BlockMedia[0].FileSystemInformation[0].FileSystems = lstFs.ToArray(); } +#if DEBUG + stopwatch.Stop(); + Console.WriteLine("Core.AddMedia(): Took {0} seconds to check all filesystems", stopwatch.Elapsed.TotalSeconds); +#endif // TODO: Implement support for getting CHS if(UpdateProgress != null) diff --git a/osrepodbmgr.Core/Workers/Files.cs b/osrepodbmgr.Core/Workers/Files.cs index 5e29e42..118e6f9 100644 --- a/osrepodbmgr.Core/Workers/Files.cs +++ b/osrepodbmgr.Core/Workers/Files.cs @@ -66,10 +66,22 @@ namespace osrepodbmgr.Core try { +#if DEBUG + stopwatch.Restart(); +#endif Context.files = new List(Directory.EnumerateFiles(filesPath, "*", SearchOption.AllDirectories)); Context.files.Sort(); +#if DEBUG + stopwatch.Stop(); + Console.WriteLine("Core.FindFiles(): Took {0} seconds to find all files", stopwatch.Elapsed.TotalSeconds); + stopwatch.Restart(); +#endif Context.folders = new List(Directory.EnumerateDirectories(filesPath, "*", SearchOption.AllDirectories)); Context.folders.Sort(); +#if DEBUG + stopwatch.Stop(); + Console.WriteLine("Core.FindFiles(): Took {0} seconds to find all folders", stopwatch.Elapsed.TotalSeconds); +#endif if(Finished != null) Finished(); } @@ -116,6 +128,9 @@ namespace osrepodbmgr.Core // End for metadata +#if DEBUG + stopwatch.Restart(); +#endif long counter = 1; foreach(string file in Context.files) { @@ -378,7 +393,11 @@ namespace osrepodbmgr.Core Context.hashes.Add(relpath, dbFile); counter++; } - +#if DEBUG + stopwatch.Stop(); + Console.WriteLine("Core.HashFiles(): Took {0} seconds to hash all files", stopwatch.Elapsed.TotalSeconds); + stopwatch.Restart(); +#endif counter = 1; foreach(string folder in Context.folders) { @@ -405,6 +424,10 @@ namespace osrepodbmgr.Core Context.foldersDict.Add(relpath, dbFolder); counter++; } +#if DEBUG + stopwatch.Stop(); + Console.WriteLine("Core.HashFiles(): Took {0} seconds to iterate all folders", stopwatch.Elapsed.TotalSeconds); +#endif if(foundMetadata) { @@ -522,6 +545,9 @@ namespace osrepodbmgr.Core FileStream inFs = new FileStream(Context.path, FileMode.Open, FileAccess.Read); FileStream outFs = new FileStream(Context.tmpFolder, FileMode.Create, FileAccess.Write); +#if DEBUG + stopwatch.Restart(); +#endif byte[] buffer = new byte[bufferSize]; while((inFs.Position + bufferSize) <= inFs.Length) @@ -542,6 +568,10 @@ namespace osrepodbmgr.Core inFs.Close(); outFs.Close(); +#if DEBUG + stopwatch.Stop(); + Console.WriteLine("Core.CopyFile(): Took {0} seconds to copy file", stopwatch.Elapsed.TotalSeconds); +#endif if(Finished != null) Finished(); @@ -597,6 +627,9 @@ namespace osrepodbmgr.Core if(UpdateProgress != null) UpdateProgress("", "Creating folders...", 3, 100); +#if DEBUG + stopwatch.Restart(); +#endif counter = 0; foreach(DBFolder folder in folders) { @@ -611,7 +644,14 @@ namespace osrepodbmgr.Core counter++; } +#if DEBUG + stopwatch.Stop(); + Console.WriteLine("Core.SaveAs(): Took {0} seconds to create all folders", stopwatch.Elapsed.TotalSeconds); +#endif +#if DEBUG + stopwatch.Restart(); +#endif counter = 3; foreach(DBOSFile file in files) { @@ -718,6 +758,10 @@ namespace osrepodbmgr.Core counter++; } +#if DEBUG + stopwatch.Stop(); + Console.WriteLine("Core.SaveAs(): Took {0} seconds to create all files", stopwatch.Elapsed.TotalSeconds); +#endif if(Finished != null) Finished(); diff --git a/osrepodbmgr.Core/Workers/VirusTotal.cs b/osrepodbmgr.Core/Workers/VirusTotal.cs index e5d627c..aec60b1 100644 --- a/osrepodbmgr.Core/Workers/VirusTotal.cs +++ b/osrepodbmgr.Core/Workers/VirusTotal.cs @@ -306,8 +306,13 @@ namespace osrepodbmgr.Core #if DEBUG stopwatch.Restart(); #endif + int counter = 0; while(fResult.ResponseCode == VirusTotalNET.ResponseCodes.ReportResponseCode.StillQueued) { + // Timeout... + if(counter == 10) + break; + // Wait 15 seconds so we fall in the 4 requests/minute Thread.Sleep(15000); @@ -315,6 +320,8 @@ namespace osrepodbmgr.Core { fResult = await vTotal.GetFileReport(file.Sha256); }).Wait(); + + counter++; } #if DEBUG stopwatch.Stop();