Kitz ADSL Broadband Information
adsl spacer  
Support this site
Home Broadband ISPs Tech Routers Wiki Forum
 
     
   Compare ISP   Rate your ISP
   Glossary   Glossary
 
Please login or register.

Login with username, password and session length
Advanced search  

News:

Pages: 1 [2] 3 4

Author Topic: hg612 modem stats request reference log rotation  (Read 11976 times)

Chrysalis

  • Content Team
  • Addicted Kitizen
  • *
  • Posts: 7382
  • VM Gig1 - AAISP L2TP
Re: hg612 modem stats request reference log rotation
« Reply #15 on: June 10, 2015, 05:13:29 PM »

I will get back to you as soon as possible BE but last day or so I been very busy.

But it is important whenever you test i/o performance to make sure is uncached   Reading an entire log is indeed inefficient.

Will try to get you the info you requested by end of tonight.
Logged

Bald_Eagle1

  • Helpful
  • Kitizen
  • *
  • Posts: 2721
Re: hg612 modem stats request reference log rotation
« Reply #16 on: June 11, 2015, 10:43:06 PM »

Please try the attached version of graphpd.exe.

This version now starts at the end of the file & works backward to find the start point of the data to be used for the period specified.

In other words, it does not read the whole file to count the total rows & then read it again until it finds the starting row for the period specified.

It is slightly quicker, but it doesn't seem to make all that much difference on my system when working with a modem_stats.log that is around 185 MB in size.

It might make a bigger difference on your RAID system though as the file reading element is now much reduced.


I'd be very interested to see your graphpd_ERROR.LOG entries for the old version AND this new version in order to compare the timings.




Logged

Chrysalis

  • Content Team
  • Addicted Kitizen
  • *
  • Posts: 7382
  • VM Gig1 - AAISP L2TP
Re: hg612 modem stats request reference log rotation
« Reply #17 on: June 12, 2015, 10:31:12 AM »

will do as soon as I can, as I need to reboot to flush the cache but cant do so with open unsaved work.
Logged

Ronski

  • Moderator
  • Kitizen
  • *
  • Posts: 4300
Re: hg612 modem stats request reference log rotation
« Reply #18 on: June 12, 2015, 08:21:16 PM »

At BE1's request I have run some tests on my server. My server is an i3 540 runnging at 3ghz

C: drive is an Intel SSD and the OS drive, this is where HG612 stats normally lives
G: drive is a single Samsung HDD 5400rpm
F: drive is two of the above in Raid 1
I: drive is 6 x 3TB WD Reds in raid 6

Both raids are software, the raid 1 is on the motherboard, and the raid 6 is on a Highpoint controller.

My server was not rebooted between tests, I don't have the time to do that and others may be watching recordings stored on the server, I simply cut and pasted the folder between drives and then plotted the same data.

I plotted 60 days using the same data each time.

Drive Original program        New Program

C:       391s                                255
G:      239s                                265s
F:       260s                                215s
I:        298s                                261s

1 day

C:      23s                                   26s

Now it's quite possible the log file was still in some cache due to the cut and paste so the above results could be flawed. Plotting 60 days on my office PC SSD using a log that hasn't been accessed since the last reboot only took  127 seconds. It's clearly the plotting that takes the time, reading the file is very quick when watching the DOS window.

Chrysalis, if your system is taking 4 minutes to plot one days worth of graphs then I think something is clearly wrong, have you run a disc benchmark against your raid 1 setup? Are you using Intel ports on your motherboard and the correct Intel drivers?
Logged
Formerly restrained by ECI and ali,  now surfing along at 390/36  ;D

Chrysalis

  • Content Team
  • Addicted Kitizen
  • *
  • Posts: 7382
  • VM Gig1 - AAISP L2TP
Re: hg612 modem stats request reference log rotation
« Reply #19 on: June 12, 2015, 09:48:17 PM »

Ronski as I said before the amount I plot is completely irrelevant, whats relevant is the size of the log, as BE confirmed the entire log is read.

I could do tests now but they will be flawed as the file will be cached, I need to wait until I can reboot this system.

The hdd's are on my sata3 intel controller using intel's drivers, but intel now optimise their drivers for ssd's.

I have benchmarked the drives individually and they are running within expected performance, however what I havent done yet is benchmark the raid1 filesystem.

When the file is cached I can open it in under a second.

Also bear in mind due to the nature of how the log is written to, the chances are its very fragmented on my hdd and hence lots of random seeks to read it.
« Last Edit: June 12, 2015, 09:51:38 PM by Chrysalis »
Logged

Chrysalis

  • Content Team
  • Addicted Kitizen
  • *
  • Posts: 7382
  • VM Gig1 - AAISP L2TP
Re: hg612 modem stats request reference log rotation
« Reply #20 on: June 12, 2015, 10:08:12 PM »

I have tried to flush without a reboot using a tool but it stays cached.

note if you make a copy of the file and then read the copy, its more likely to be a sequential read with faster performance and as such isnt a reliable test.

I will try to do this tommorow or maybe even later tonight.

renaming a file is ok, but not copy/move.
Logged

NewtronStar

  • Kitizen
  • ****
  • Posts: 4898
Re: hg612 modem stats request reference log rotation
« Reply #21 on: June 12, 2015, 10:29:14 PM »

I think something is clearly wrong, have you run a disc benchmark against your raid 1 setup? Are you using Intel ports on your motherboard and the correct Intel drivers?

Disk corruption will show up as excessive reads on a disk it's trying to read data that's damaged or the segment were the file resides on the disk is damaged, i would run a chkdsk /f from the safemode boot options, as no matter how large the file is be it cached or not it should not be thrashing away to read data.
Logged

Chrysalis

  • Content Team
  • Addicted Kitizen
  • *
  • Posts: 7382
  • VM Gig1 - AAISP L2TP
Re: hg612 modem stats request reference log rotation
« Reply #22 on: June 13, 2015, 10:57:00 AM »

ok attached is 30 day run, old debug graphd exe and with file cached. I will follow this up doing same test after reboot, then will reboot a 2nd time and test with the new exe.

Code: [Select]
13/06/2015 10:57:55.306 - Start of [graphpd.exe] v 5.1.0.2
13/06/2015 10:57:55.306 - The program full path is      F:\Drivers\HG612\HG612_Modem_Stats_Programs-CURRENT\Scripts\GraphPD.exe
13/06/2015 10:57:55.306 - The program directory path is F:\Drivers\HG612\HG612_Modem_Stats_Programs-CURRENT\Scripts\
13/06/2015 10:57:55.306 - DEBUG_COMMENTS = YES
13/06/2015 10:57:58.397 - You entered (or it was determined) a period of 30 d
13/06/2015 10:57:58.397 - Log file name wasn't entered - Using default modem_stats.log and subfolders
13/06/2015 10:57:58.398 - F:\Drivers\HG612\HG612_Modem_Stats_Programs-CURRENT\Ongoing_Stats\modem_stats.log opened for reading
13/06/2015 10:57:58.400 - Log file & path not specified. Creating SUBFOLDER: F:\Drivers\HG612\HG612_Modem_Stats_Programs-CURRENT\Ongoing_Stats\Ongoing_Stats_20150613-1057-30Days
13/06/2015 10:57:58.400 - Creating F:\Drivers\HG612\HG612_Modem_Stats_Programs-CURRENT\Ongoing_Stats\Ongoing_Stats_20150613-1057-30Days\GDATA$$
13/06/2015 10:57:59.501 - GDATA$$ created
13/06/2015 10:58:00.915 - Data from GDATA$$ starts at 08/05/2015 07:59 & ends at 07/06/2015 21:45
13/06/2015 10:58:00.916 - START of piped plotting with gnuplot
13/06/2015 10:58:34.291 -   END of piped plotting with gnuplot
13/06/2015 10:58:34.431 - START of creating montage(s) with gnuplot
13/06/2015 10:58:35.543 -   END of creating montage(s) with gnuplot
13/06/2015 10:58:35.548 - GDATA$$ deleted
13/06/2015 10:58:35.548 - End of graphpd. 43200 samples i.e. 30 Days of data should have been plotted
« Last Edit: June 13, 2015, 11:00:48 AM by Chrysalis »
Logged

Chrysalis

  • Content Team
  • Addicted Kitizen
  • *
  • Posts: 7382
  • VM Gig1 - AAISP L2TP
Re: hg612 modem stats request reference log rotation
« Reply #23 on: June 13, 2015, 11:11:14 AM »

ok now 30 day graph with same log, after reboot.

Code: [Select]
13/06/2015 11:07:39.020 - Start of [graphpd.exe] v 5.1.0.2
13/06/2015 11:07:39.020 - The program full path is      F:\Drivers\HG612\HG612_Modem_Stats_Programs-CURRENT\Scripts\GraphPD.exe
13/06/2015 11:07:39.020 - The program directory path is F:\Drivers\HG612\HG612_Modem_Stats_Programs-CURRENT\Scripts\
13/06/2015 11:07:39.020 - DEBUG_COMMENTS = YES
13/06/2015 11:07:43.824 - You entered (or it was determined) a period of 30 d
13/06/2015 11:07:43.824 - Log file name wasn't entered - Using default modem_stats.log and subfolders
13/06/2015 11:07:43.825 - F:\Drivers\HG612\HG612_Modem_Stats_Programs-CURRENT\Ongoing_Stats\modem_stats.log opened for reading
13/06/2015 11:07:43.825 - Log file & path not specified. Creating SUBFOLDER: F:\Drivers\HG612\HG612_Modem_Stats_Programs-CURRENT\Ongoing_Stats\Ongoing_Stats_20150613-1107-30Days
13/06/2015 11:07:43.825 - Creating F:\Drivers\HG612\HG612_Modem_Stats_Programs-CURRENT\Ongoing_Stats\Ongoing_Stats_20150613-1107-30Days\GDATA$$
13/06/2015 11:10:05.142 - GDATA$$ created
13/06/2015 11:10:06.557 - Data from GDATA$$ starts at 08/05/2015 07:59 & ends at 07/06/2015 21:45
13/06/2015 11:10:06.557 - START of piped plotting with gnuplot
13/06/2015 11:10:39.881 -   END of piped plotting with gnuplot
13/06/2015 11:10:40.474 - START of creating montage(s) with gnuplot
13/06/2015 11:10:41.938 -   END of creating montage(s) with gnuplot
13/06/2015 11:10:41.940 - GDATA$$ deleted
13/06/2015 11:10:41.940 - End of graphpd. 43200 samples i.e. 30 Days of data should have been plotted
Logged

Chrysalis

  • Content Team
  • Addicted Kitizen
  • *
  • Posts: 7382
  • VM Gig1 - AAISP L2TP
Re: hg612 modem stats request reference log rotation
« Reply #24 on: June 13, 2015, 11:19:49 AM »

here is using the new graphd, significantly quicker although was longer then I expected. ?I am about to do a 4th test, I will copy the file, rename the copy to be the current file, reboot and it should be quicker due to sequential reads, assuming my hdd's have enough sequential empty blocks left.

Code: [Select]
13/06/2015 11:17:18.792 - Start of [graphpd.exe] v 5.1.0.3
13/06/2015 11:17:18.792 - The program full path is      F:\Drivers\HG612\HG612_Modem_Stats_Programs-CURRENT\Scripts\GraphPD.exe
13/06/2015 11:17:18.792 - The program directory path is F:\Drivers\HG612\HG612_Modem_Stats_Programs-CURRENT\Scripts\
13/06/2015 11:17:18.792 - DEBUG_COMMENTS = YES
13/06/2015 11:17:21.447 - You entered (or it was determined) a period of 30 d
13/06/2015 11:17:21.447 - Log file name wasn't entered - Using default modem_stats.log and subfolders
13/06/2015 11:17:21.447 - F:\Drivers\HG612\HG612_Modem_Stats_Programs-CURRENT\Ongoing_Stats\modem_stats.log opened for reading
13/06/2015 11:17:21.447 - Log file & path not specified. Creating SUBFOLDER: F:\Drivers\HG612\HG612_Modem_Stats_Programs-CURRENT\Ongoing_Stats\Ongoing_Stats_20150613-1117-30Days
13/06/2015 11:17:21.447 - Creating F:\Drivers\HG612\HG612_Modem_Stats_Programs-CURRENT\Ongoing_Stats\Ongoing_Stats_20150613-1117-30Days\GDATA$$
13/06/2015 11:18:21.090 - GDATA$$ created
13/06/2015 11:18:21.092 - Data from GDATA$$ starts at 08/05/2015 07:59 & ends at 07/06/2015 21:45
13/06/2015 11:18:21.093 - START of piped plotting with gnuplot
13/06/2015 11:18:54.262 -   END of piped plotting with gnuplot
13/06/2015 11:18:54.575 - START of creating montage(s) with gnuplot
13/06/2015 11:18:55.788 -   END of creating montage(s) with gnuplot
13/06/2015 11:18:55.792 - GDATA$$ deleted
13/06/2015 11:18:55.792 - End of graphpd. 43200 samples i.e. 30 Days of data should have been plotted[/b]
Logged

Chrysalis

  • Content Team
  • Addicted Kitizen
  • *
  • Posts: 7382
  • VM Gig1 - AAISP L2TP
Re: hg612 modem stats request reference log rotation
« Reply #25 on: June 13, 2015, 11:31:16 AM »

finally here is using a copy of the file, after a reboot, with new binary, can see its much quicker due to no or at least less fragmentation.  Bear in mind this is not a realistic result, as these large logs several months long will be fragmented.  After some household and personal chores I will do some diagnosis and tests on my raid filesystem to see if that has an issue as well.

Code: [Select]
13/06/2015 11:29:19.284 - Start of [graphpd.exe] v 5.1.0.3
13/06/2015 11:29:19.284 - The program full path is      F:\Drivers\HG612\HG612_Modem_Stats_Programs-CURRENT\Scripts\GraphPD.exe
13/06/2015 11:29:19.284 - The program directory path is F:\Drivers\HG612\HG612_Modem_Stats_Programs-CURRENT\Scripts\
13/06/2015 11:29:19.284 - DEBUG_COMMENTS = YES
13/06/2015 11:29:21.052 - You entered (or it was determined) a period of 30 d
13/06/2015 11:29:21.052 - Log file name wasn't entered - Using default modem_stats.log and subfolders
13/06/2015 11:29:21.053 - F:\Drivers\HG612\HG612_Modem_Stats_Programs-CURRENT\Ongoing_Stats\modem_stats.log opened for reading
13/06/2015 11:29:21.053 - Log file & path not specified. Creating SUBFOLDER: F:\Drivers\HG612\HG612_Modem_Stats_Programs-CURRENT\Ongoing_Stats\Ongoing_Stats_20150613-1129-30Days
13/06/2015 11:29:21.053 - Creating F:\Drivers\HG612\HG612_Modem_Stats_Programs-CURRENT\Ongoing_Stats\Ongoing_Stats_20150613-1129-30Days\GDATA$$
13/06/2015 11:29:24.982 - GDATA$$ created
13/06/2015 11:29:24.983 - Data from GDATA$$ starts at 08/05/2015 07:59 & ends at 07/06/2015 21:45
13/06/2015 11:29:24.984 - START of piped plotting with gnuplot
13/06/2015 11:29:58.310 -   END of piped plotting with gnuplot
13/06/2015 11:29:58.950 - START of creating montage(s) with gnuplot
13/06/2015 11:30:00.207 -   END of creating montage(s) with gnuplot
13/06/2015 11:30:00.210 - GDATA$$ deleted
13/06/2015 11:30:00.210 - End of graphpd. 43200 samples i.e. 30 Days of data should have been plotted
Logged

Chrysalis

  • Content Team
  • Addicted Kitizen
  • *
  • Posts: 7382
  • VM Gig1 - AAISP L2TP
Re: hg612 modem stats request reference log rotation
« Reply #26 on: June 13, 2015, 11:36:28 AM »

Before I do my offline stuff, here is some notes.

1 - once it is cached it will stay cached for a while, how long is an unknown as it depends on amount of free ram in the system and pressure on the system to flush it, in my case it does stay cached over night but I know it doesnt stay cached over a few days.
2 - Based on #1 if one is running daily ongoing graphs its possible that serves to refresh the cache and hide the problem.
3 - I do not run scheduled on going graphs, only snapshot graphs.  Which means generally when I do a manual run, it is not cached.
Logged

Bald_Eagle1

  • Helpful
  • Kitizen
  • *
  • Posts: 2721
Re: hg612 modem stats request reference log rotation
« Reply #27 on: June 13, 2015, 07:57:53 PM »

Ronski as I said before the amount I plot is completely irrelevant, whats relevant is the size of the log, as BE confirmed the entire log is read.



The amount being plotted did have & still does have some relevance, both in time taken to read the ongoing log & the time taken to create the temporary file for the actual plotting.


The temporary file is then read row by row a number of times to obtain the data for each individual graph.

Plotting the data for 1 day uses 1440 samples (rows of data).

Plotting 30 days uses 43200 samples & so on.

A lot more graphs are created for G.INP active connections which will also have added more time for the whole process compared to the time taken for non-G.INP active connections.


Logged

Bald_Eagle1

  • Helpful
  • Kitizen
  • *
  • Posts: 2721
Re: hg612 modem stats request reference log rotation
« Reply #28 on: June 13, 2015, 08:03:50 PM »

here is using the new graphd, significantly quicker although was longer then I expected.

13/06/2015 11:17:21.447 - Creating F:\Drivers\HG612\HG612_Modem_Stats_Programs-CURRENT\Ongoing_Stats\Ongoing_Stats_20150613-1117-30Days\GDATA$$
13/06/2015 11:18:21.090 - GDATA$$ created


Was that using the log cached or non-cached?

Logged

NewtronStar

  • Kitizen
  • ****
  • Posts: 4898
Re: hg612 modem stats request reference log rotation
« Reply #29 on: June 13, 2015, 08:06:23 PM »

I Just noticed when running the GraphPD the DOS text shows up as G.INP enabled which is not the case since 13th of may  ???

Its ok it much see the G.INP stats when this line was disabled a month ago  :blush:
« Last Edit: June 13, 2015, 08:16:34 PM by NewtronStar »
Logged
Pages: 1 [2] 3 4
 

anything