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:

Author Topic: HG612 Not Producing Graphs at Scheduled times  (Read 1745 times)

cwaite

  • Member
  • **
  • Posts: 50
HG612 Not Producing Graphs at Scheduled times
« on: September 17, 2017, 03:00:30 PM »

I have Set HG612 Modem Log and Stats Viewer to Automatically Generate the last 24 hours of Stats at 6am every morning but it does not generate anything I have checked the Ongoing Error Log and this is what I get every morning at 6am


17/09/2017 05:59:02.054 - In [Upload.exe] - Start of upload process
17/09/2017 05:59:02.332 - Now exiting [Upload.exe]


17/09/2017 06:00:00.903 - [ IN HG612_stats.EXE ] - Start of 1 minute sampling - delayed by user setting of 0 seconds
17/09/2017 06:00:02.620 - *** ERROR!!! - Now in get_data_exit as times_in_loop was 500. Status = 1.
17/09/2017 06:00:02.842 - About to close(sockfd)
17/09/2017 06:00:02.842 - About to freeadddrinfo(res)
17/09/2017 06:00:02.958 - *** In get_data_exit - Abnormal end of HG612_stats.exe program, EXIT error code = 99. Status = 1.
17/09/2017 06:00:02.958 - *** In get_data_exit - Closing ERROR.LOG. Status = 1.


17/09/2017 06:01:00.863 - [ IN HG612_stats.EXE ] - Start of 1 minute sampling - delayed by user setting of 0 seconds
17/09/2017 06:01:02.049 - End of HG612_stats.exe program, closing ERROR.LOG


If I run the graphs manually they work fine!

Does anyone know, how to fix this problem, I am running the latest version of HG612 Modem Log and Stats viewer on Windows 10 Home 64bit (Creators edition, fully patched)


Logged

Ronski

  • Moderator
  • Kitizen
  • *
  • Posts: 3296
Re: HG612 Not Producing Graphs at Scheduled times
« Reply #1 on: September 17, 2017, 04:47:31 PM »

There's not much there that means anything to me. Perhaps turn on extensive error logging, which can be found in the GUI on the settings tab & then Additional settings tab, and then once it's gone 6am post the relevant section of the log and I'll see if there is anything more meaningful.

Unfortunately Bald_Eagle1 who wrote the logging & graphing code has not been on the forums since January.
Logged
Formerly restrained by ECI and ali,  now surfing along at 390/36  ;D

cwaite

  • Member
  • **
  • Posts: 50
Re: HG612 Not Producing Graphs at Scheduled times
« Reply #2 on: September 18, 2017, 04:43:33 PM »

Ok have turned on the extensive logging here is the log:

18/09/2017 05:59:02.611 - End of HG612_stats.exe program, EXIT error code = 0
18/09/2017 05:59:02.611 - End of HG612_stats.exe program, closing ERROR.LOG


18/09/2017 05:59:02.752 - In [Upload.exe] - Start of upload process
18/09/2017 05:59:03.065 - Now exiting [Upload.exe]


18/09/2017 06:00:01.189 - [ IN HG612_stats.EXE ] - Start of 1 minute sampling - delayed by user setting of 0 seconds
18/09/2017 06:00:01.595 - HG612_current_stats.exe was NOT running
18/09/2017 06:00:01.595 - Temp File ONGOING-ISRUNNING-060001-048.TXT was created
18/09/2017 06:00:02.017 - malloc() O.K.
18/09/2017 06:00:02.017 - Initializing Winsock
18/09/2017 06:00:02.017 - WSAStartup() SUCCESSFUL!!!
18/09/2017 06:00:02.017 - Starting getaddrinfo()
18/09/2017 06:00:02.017 - getaddrinfo() O.K.
18/09/2017 06:00:02.017 - Starting socket()
18/09/2017 06:00:02.017 - socket() O.K.
18/09/2017 06:00:02.017 - Starting connect()
18/09/2017 06:00:02.017 - connect() O.K.
18/09/2017 06:00:02.282 - About to reply(xdslcmd info --stats)
18/09/2017 06:00:02.298 - reply(xdslcmd info --stats) O.K.
18/09/2017 06:00:02.298 - get_data() O.K.
18/09/2017 06:00:02.298 - Modem in use = HG612
18/09/2017 06:00:02.298 - About to determine the xDSL mode
18/09/2017 06:00:02.298 - About to parse_stats()
18/09/2017 06:00:02.298 - parse_stats completed
18/09/2017 06:00:02.329 - VDSL2 mode detected so about to reply(xdslcmd info --pbParams)
18/09/2017 06:00:02.329 - reply(xdslcmd info --pbParams) O.K.
18/09/2017 06:00:02.329 - get_data() O.K.
18/09/2017 06:00:02.329 - About to parse_pbParams_data()
18/09/2017 06:00:02.345 - parse_pbParams_data() completed
18/09/2017 06:00:02.345 - reply(xdslcmd --version) O.K.
18/09/2017 06:00:02.360 - get_data() O.K.
18/09/2017 06:00:02.360 - parse_version() completed
18/09/2017 06:00:02.360 - reply(equipcmd swversion display) O.K.
18/09/2017 06:00:02.392 - parse_swversion() completed
18/09/2017 06:00:02.392 - get_data() for --swversion O.K.
18/09/2017 06:00:02.423 - reply(xdslcmd --Bits) O.K.
18/09/2017 06:00:02.970 - *** ERROR!!! - Now in get_data_exit as times_in_loop was 500. Status = 1.
18/09/2017 06:00:02.970 - Temp File ONGOING_GET_DATA_ERROR-060002-970.TXT was created
18/09/2017 06:00:03.220 - About to close(sockfd)
18/09/2017 06:00:03.220 - About to freeadddrinfo(res)
18/09/2017 06:00:03.220 - About to WSACleanup()
18/09/2017 06:00:03.236 - About to free(txbuf)
18/09/2017 06:00:03.252 - About to free(rxbuf)
18/09/2017 06:00:03.314 - ONGOING-ISRUNNING-060001-048.TXT DELETED
18/09/2017 06:00:03.330 - *** In get_data_exit - Abnormal end of HG612_stats.exe program, EXIT error code = 99. Status = 1.
18/09/2017 06:00:03.330 - *** In get_data_exit - Closing ERROR.LOG. Status = 1.


18/09/2017 06:01:01.193 - [ IN HG612_stats.EXE ] - Start of 1 minute sampling - delayed by user setting of 0 seconds
18/09/2017 06:01:01.615 - HG612_current_stats.exe was NOT running
18/09/2017 06:01:01.615 - Temp File ONGOING-ISRUNNING-060101-037.TXT was created
18/09/2017 06:01:02.068 - malloc() O.K.
18/09/2017 06:01:02.068 - Initializing Winsock
18/09/2017 06:01:02.068 - WSAStartup() SUCCESSFUL!!!
18/09/2017 06:01:02.068 - Starting getaddrinfo()
18/09/2017 06:01:02.068 - getaddrinfo() O.K.
18/09/2017 06:01:02.068 - Starting socket()
18/09/2017 06:01:02.068 - socket() O.K.
18/09/2017 06:01:02.068 - Starting connect()
18/09/2017 06:01:02.068 - connect() O.K.
18/09/2017 06:01:02.334 - About to reply(xdslcmd info --stats)
18/09/2017 06:01:02.349 - reply(xdslcmd info --stats) O.K.
18/09/2017 06:01:02.349 - get_data() O.K.
18/09/2017 06:01:02.349 - Modem in use = HG612
18/09/2017 06:01:02.349 - About to determine the xDSL mode
18/09/2017 06:01:02.349 - About to parse_stats()
18/09/2017 06:01:02.365 - parse_stats completed
18/09/2017 06:01:02.381 - VDSL2 mode detected so about to reply(xdslcmd info --pbParams)
18/09/2017 06:01:02.381 - reply(xdslcmd info --pbParams) O.K.
18/09/2017 06:01:02.381 - get_data() O.K.
18/09/2017 06:01:02.381 - About to parse_pbParams_data()
18/09/2017 06:01:02.396 - parse_pbParams_data() completed
18/09/2017 06:01:02.396 - reply(xdslcmd --version) O.K.
18/09/2017 06:01:02.412 - get_data() O.K.
18/09/2017 06:01:02.412 - parse_version() completed
18/09/2017 06:01:02.412 - reply(equipcmd swversion display) O.K.
18/09/2017 06:01:02.459 - parse_swversion() completed
18/09/2017 06:01:02.459 - get_data() for --swversion O.K.
18/09/2017 06:01:02.459 - About to exit Busybox
18/09/2017 06:01:02.459 - Busybox exited
18/09/2017 06:01:02.459 - About to exit ATP
18/09/2017 06:01:02.459 - ATP exited
18/09/2017 06:01:02.459 - Logged out of modem O.K.
18/09/2017 06:01:02.459 - Current data harvested at 1505710860 seconds past the epoch
18/09/2017 06:01:02.459 - About to get_log_data()
18/09/2017 06:01:02.459 - Previous log stats date/time = 1505710740 seconds past the epoch
18/09/2017 06:01:02.459 - time_difference = 2 minutes
18/09/2017 06:01:02.459 - WARNING!!! time_difference is more than 1 minute - Ignoring previous logged time
18/09/2017 06:01:02.474 - About to calc_ES_delta()
18/09/2017 06:01:02.474 - About to calc_RSCorr_delta()
18/09/2017 06:01:02.474 - ds_RSCorr_THIS_PERIOD = 333
18/09/2017 06:01:02.474 - us_RSCorr_THIS_PERIOD = 0
18/09/2017 06:01:02.474 - About to calc_RSUnCorr_delta()
18/09/2017 06:01:02.474 - About to calc_RS_delta()
18/09/2017 06:01:02.474 - About to calc_OHF_delta()
18/09/2017 06:01:02.474 - About to calc_OHFErr_delta()
18/09/2017 06:01:02.474 - About to calc_HEC_delta()
18/09/2017 06:01:02.474 - About to calc_CRC_delta()
18/09/2017 06:01:02.474 - About to calc_FEC_delta()
18/09/2017 06:01:02.474 - About to calc_Bitswap_delta()
18/09/2017 06:01:02.474 - About to calc_Bearer_1_RSCorr_delta()
18/09/2017 06:01:02.474 - ds_Bearer_1_RSCorr_THIS_PERIOD = 0
18/09/2017 06:01:02.474 - us_Bearer_1_RSCorr_THIS_PERIOD = 0
18/09/2017 06:01:02.474 - Appending data to F:\HG612_Modem_Stats\Ongoing_Stats\modem_stats.log
18/09/2017 06:01:02.474 - Closing MSLOGFILE.log
18/09/2017 06:01:02.490 - END of 1 minute sampling
18/09/2017 06:01:02.506 - About to close(sockfd)
18/09/2017 06:01:02.506 - About to freeadddrinfo(res)
18/09/2017 06:01:02.506 - About to WSACleanup()
18/09/2017 06:01:02.537 - About to free(txbuf)
18/09/2017 06:01:02.552 - About to free(rxbuf)
18/09/2017 06:01:02.568 - Current  sync speeds are     DS 22400 kbps      US 3664 kbps, AS = 492408
18/09/2017 06:01:02.568 - Previous sync speeds were    DS 22400 kbps      US 3664 kbps, AS = 492288
18/09/2017 06:01:02.568 - Sync speeds have NOT changed since the previous data harvest
18/09/2017 06:01:02.584 - ONGOING-ISRUNNING-060101-037.TXT DELETED
Logged

Ronski

  • Moderator
  • Kitizen
  • *
  • Posts: 3296
Re: HG612 Not Producing Graphs at Scheduled times
« Reply #3 on: September 18, 2017, 09:02:58 PM »

I've changed mine to extensive logging so I can compare, in the meantime can you confirm what modem you are using please?
Logged
Formerly restrained by ECI and ali,  now surfing along at 390/36  ;D

cwaite

  • Member
  • **
  • Posts: 50
Re: HG612 Not Producing Graphs at Scheduled times
« Reply #4 on: September 19, 2017, 10:24:04 PM »

Yes using a HG612
Logged

Ronski

  • Moderator
  • Kitizen
  • *
  • Posts: 3296
Re: HG612 Not Producing Graphs at Scheduled times
« Reply #5 on: September 20, 2017, 08:04:09 PM »

The error occurs long before it gets to the stage of deciding to generate the graphs, it seems to drop out without logging any modem stats as well, if you look in the log it states: 18/09/2017 06:01:02.459 - time_difference = 2 minutes
18/09/2017 06:01:02.459 - WARNING!!! time_difference is more than 1 minute - Ignoring previous logged time
which implies it didn't record any stats for the last minute.

There is an option to allow for the speed of the PC, might be worth changing that, it's on the same tab as the error logging options.

Only other thing I can think of at the moment is to delete all error log files, turn on 'Enable extra debugging info logging', then once the errors occurred zip up the entire log files and attach them. There might be something in one of the other logs which will tell me what it is. I could do with a couple of hours worth of data - I want to see if it is regularly having errors, rather than just the time the graphs should be produced.

Logged
Formerly restrained by ECI and ali,  now surfing along at 390/36  ;D

cwaite

  • Member
  • **
  • Posts: 50
Re: HG612 Not Producing Graphs at Scheduled times
« Reply #6 on: September 21, 2017, 12:19:39 AM »

There is an option to allow for the speed of the PC, might be worth changing that, it's on the same tab as the error logging options.

Thanks for your help on this so far.

At present its set to Slow what would you recommend I set it to?
Logged

Ronski

  • Moderator
  • Kitizen
  • *
  • Posts: 3296
Re: HG612 Not Producing Graphs at Scheduled times
« Reply #7 on: September 21, 2017, 06:06:23 AM »

Try setting it to fast, if that makes no difference try medium.
Logged
Formerly restrained by ECI and ali,  now surfing along at 390/36  ;D

cwaite

  • Member
  • **
  • Posts: 50
Re: HG612 Not Producing Graphs at Scheduled times
« Reply #8 on: September 22, 2017, 02:01:25 PM »

Thanks I changed the time that it produces the graphs from 6am to 10:15am and curiously it has produced graphs automatically at 10:15am yesterday and today, not sure what's so special about 10:15am but it seems to work.

Thanks for you help, and hope this information helps someone else that may have the same problem!
Logged

Ronski

  • Moderator
  • Kitizen
  • *
  • Posts: 3296
Re: HG612 Not Producing Graphs at Scheduled times
« Reply #9 on: September 22, 2017, 06:45:08 PM »

I wonder if you're getting multiple errors through out the day, and it was just coincidence that you always got an error at the time the graphs should have been produced. Hopefully changing the time has resolved the issue. Thanks for the info.

Looking on MDWS you haven't uploaded a full 24 hours of data in the last few days, so you may well be losing the odd bit of data here there to errors causing the logging to drop out.
« Last Edit: September 22, 2017, 06:47:38 PM by Ronski »
Logged
Formerly restrained by ECI and ali,  now surfing along at 390/36  ;D