Kitz Forum

Broadband Related => Router Monitoring Software => Topic started by: Korben_dallas on November 11, 2013, 09:02:57 PM

Title: HG612 Stats Stopped Working
Post by: Korben_dallas on November 11, 2013, 09:02:57 PM
HI,

I have been running the latest few versions of HG612 stats successfully since the BTOR update of the HG612 successfully until about 04:00Hrs on 10/11/13 when it stopped.  subsequently I have rebooted the P.C and the program doesn't run although it is still running the task via Task Scheduler.

Am getting multiple occurrences of 'Ongoing_Isrunning' but on looking at Task Scheduler I can only ever see one instance running.  Other than this the only other thing I can see is that the router it shows that Internet was disconnected and then reconnected on the 10/11/13 - '[Internet connected] IP address: 146.90.133.143, Sunday, November 10,2013 05:58:23 [Internet disconnected] Sunday, November 10,2013 05:57:48'.

Any one any ideas,  I have downloaded the very latest version of the programs 8/11 however the issue persists.

Cheers
Title: Re: HG612 Stats Stopped Working
Post by: Bald_Eagle1 on November 11, 2013, 09:59:09 PM
It looks like you are possibly being affected by the Microsoft duplicated Task bug.

We can see that HG612_stats.exe started at 04:00:02 & it then started again, 2 seconds later:-


***********************************************************************************
10/11/2013  4:00:02.44 -   In [HG612_stats.exe] - At the start of the main() function
10/11/2013  4:00:03.27 - **** [HG612_stats.exe] - get_login_data() OK! Status = 1.
=============================

User Name     : admin

Login IP      : 192.168.1.100

Login Time    : 2013-11-10 04:00:05

Login TimeLen :




   *********************************************************************************************
**********************************************************************************
   10/11/2013  4:00:04.54 - **** [HG612_current_stats.exe] - reply(display login) O.K. Status = 0.
   10/11/2013  4:00:04.59 - **** [HG612_current_stats.exe] - get_login_data() OK! Status = 0.
   =============================

User Name     : admin

Login IP      : 192.168.1.100

Login Time    : 2013-11-10 04:00:07

Login TimeLen :


   10/11/2013  4:00:06.90 - Normal End of [HG612_current_stats.exe]
   *********************************************************************************************








This happened again at 04:14:02, followed 2 seconds later at 04:14:04 by a duplicated instance:-

***********************************************************************************
10/11/2013  4:14:02.90 -   In [HG612_stats.exe] - At the start of the main() function


***********************************************************************************
10/11/2013  4:14:04.52 -   In [HG612_stats.exe] - At the start of the main() function
10/11/2013  4:14:12.25 - ONGOING-ISRUNNING-041405-434.TXT - *** In exit_2_instances - Closing ERROR.LOG. Status = 1,
10/11/2013  4:14:12.32 - ONGOING-ISRUNNING-041405-891.TXT - *** In exit_2_instances - Closing ERROR.LOG. Status = 1, 



It now seems that you have 1 or more stuck instances of HG612_stats.exe and/or HG612_current_stats.exe.

These stuck instances can be ended via Task Manager.

That may start things off on an even keel again.


It may be worth carefully checking Task Scheduler's history for the task.
I suspect you will see occasional instances started within a seconfd or two of each other.





Microsoft did release a hotfix for this issue, which cured it at my end when I eventually installed it.

The link for the hotfix is:-

http://support.microsoft.com/kb/2461249/en-us?sd=rss&spid=14019


I would only use the hotfix as a last resort though.


Possibly deleting the task via Ronski's Editor/GUI & creating a new one could fix the issue.


Which version of Windows do you use?

Title: Re: HG612 Stats Stopped Working
Post by: Korben_dallas on November 11, 2013, 10:40:59 PM
Hi BE,

Many thanks for looking at this, I will look to delete and recreate the task.  One thing I did notice not right away but just before I saw your mail that the HG612 stas.exe was showing up on Task Scheduler on the details tab with a status of 'Suspended'  Never seen this status before and it wouldn't let me end it.

Am on Windows 8.1 64bit been on this since 17th October.

Will let you know how I got on,  shame it had stopped at 04:00 as I would have liked to see it capture the Resync.  Ever since BTOR updated the Hg612 am now getting a resync at least once a week, prior to this it could be a good few months between resyncs.

Cheers
Title: Re: HG612 Stats Stopped Working
Post by: Korben_dallas on November 11, 2013, 11:22:13 PM
Hi BE,

I deleted the old task and created one via the GUI however I needed to rename the current modem log as both the GUI version of the Editor and the Original gave an 'Array Error, Out of Bounds',  unfortunately I didn't capture this.

So far it seems to be running ok.
Title: Re: HG612 Stats Stopped Working
Post by: Ronski on November 12, 2013, 07:21:21 AM
I've just downloaded your modem log as I was intrigued what caused the error in the GUI. If you are running the latest GUI there should be an error log in the scripts/Editor folder - you should have got a red error button appear, and clicking that opens the error log.

Anyway this is the GUI error log I got from your modem log.

Code: [Select]
12/11/2013 07:10:53 - Error reading modem log.
12/11/2013 07:10:53 - Error message: Conversion from string "" to type 'Double' is not valid.
12/11/2013 07:10:53 - Fields in log: 561
12/11/2013 07:10:53 - Array  fields: , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , , ,
12/11/2013 07:10:53 - Line     read: A                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                 
12/11/2013 07:10:53 - Read   length: 700

From this I can see that the last line of the modem log contains nothing but 564 spaces (confirmed by checking with a hex editor), and I suspect that it is this that is tripping up BE's program, as he reads in the last line to work some things out. BE needs to add some error trapping to trap errors like this gracefully. As to why BE's program wrote 564 spaces to the log file I've no idea, I might be able to find something in the other logs but need to be going to work.
Title: Re: HG612 Stats Stopped Working
Post by: Korben_dallas on November 12, 2013, 08:09:28 PM
Thanks for having a look.

I checked the folder but couldn't see a error file, but do remember the pop-up message,  I wonder if the error file was maybe cleared when I renamed the original modem log to old and a new one was created ?.

HG612 seems to be running still, need to look at the stats myself and maybe log a call with PlusNet, just had a resync at 19:40 which hasn't happened before normally only during the early hours and whilst these were infrequent prior to BT's handywork they seem to be more frequent now or is it just co-incidence ?
Title: Re: HG612 Stats Stopped Working
Post by: Bald_Eagle1 on November 12, 2013, 09:00:36 PM
This may/may not be related.

It seems I had left a loop in HG612_current_stats.exe which kicks in on some systems when HG612_stats.exe is running.
This only seems to happen when HG612_stats.exe has been slowed down by something else running on the PC.

i.e. HG612_current_stats waited for HG612_stats to complete (to avoid both programs competing to access the modem at the same time).

BUT, HG612_stats also waited for HG612_current_stats to complete, so starting an 'almost' never ending loop.

I now have a timer running that once a certain time has elapsed, HG612_current_stats now continues anyway, thus breaking the loop.


Please try the attached version of HG612_current_stats.exe & let me know if there is any improvement or not.


Title: Re: HG612 Stats Stopped Working
Post by: Korben_dallas on November 12, 2013, 10:10:37 PM
Hi BE,

Have downloaded and installed the new version, will monitor and let you know how it goes.

Many thanks
Title: Re: HG612 Stats Stopped Working
Post by: DeadMan on November 12, 2013, 11:09:03 PM
That version still did not solve my issue. How do I get the logs you need to diagnose the problem?

EDIT: I have an ERROR.LOG file in the ongoing stats folder that is 660MB in size! Also ERROR.LOG_file_ERROR which is 95mb. Delete?
Title: Re: HG612 Stats Stopped Working
Post by: Bald_Eagle1 on November 12, 2013, 11:25:06 PM
This message lists the relevant logs & where they are stored:-

http://forum.kitz.co.uk/index.php?topic=13051.msg249531#msg249531

Some of those are likely to be quite large files.

You could always copy them to a temporary folder & edit them to reduce their size before zipping them & posting them as attachments, making sure you retain the relevant data from the times the problem occurs.
Title: Re: HG612 Stats Stopped Working
Post by: Bald_Eagle1 on November 12, 2013, 11:32:07 PM
That version still did not solve my issue. How do I get the logs you need to diagnose the problem?

EDIT: I have an ERROR.LOG file in the ongoing stats folder that is 660MB in size! Also ERROR.LOG_file_ERROR which is 95mb. Delete?

You can delete them, but only after you have posted the relevant information.
They are 2 of the most important/useful files for debugging information.

Title: Re: HG612 Stats Stopped Working
Post by: DeadMan on November 12, 2013, 11:45:07 PM
Those files are pretty much impossible to edit on a Windows system (I am sure there is an editor that allows you move through large files and save portions but I don't want to mess about finding one that does). Best thing for me was to move them someplace else. Then try to run the current stats exe again and wait for what gets spat out into new log files I have zipped these up along with the rest of the smaller files.
Title: Re: HG612 Stats Stopped Working
Post by: Bald_Eagle1 on November 12, 2013, 11:47:32 PM
Those files are pretty much impossible to edit on a Windows system (I am sure there is an editor that allows you move through large files and save portions but I don't want to mess about finding one that does). Best thing for me was to move them someplace else. Then try to run the current stats exe again and wait for what gets spat out into new log files I have zipped these up along with the rest of the smaller files.

I use TextPad on my Windows system.
It's very quick, it can deal with huge files & it's FREE!!!!

I'll have a look through the logs you have posted.
Title: Re: HG612 Stats Stopped Working
Post by: Bald_Eagle1 on November 12, 2013, 11:58:31 PM
Is this the problem you refer to:-

10/11/2013 21:00:26.692 - Start of GRAPH6.exe
10/11/2013 21:00:26.693 - A log file name was NOT passed to GRAPH6.exe - Exiting GRAPH6.exe

If so, that's probably because you ran GRAPH6.exe directly.

To manually plot 'snapshot' data, you need to run HG612_current_stats.exe to harvest the data & it will run GRAPH6.exe to plot the harvested data.

Alternatively, if you wish to replot old data or plot data from a Plink log that someone has sent to you, just drag & drop the Plink log onto GRAPH6.exe.
It will then plot the graphs in whatever folder the Plink log is stored in.



From your logs, It looks as though the scheduled graphing at 06:00, 14:00 & 22:00 completes as intended.
Is that part O.K?

I'm afraid the snippets from the other logs you posted don't include any of the scheduled event times of 06:00, 14:00 & 22:00, so I can't tell if those times are still O.K. or not.

Title: Re: HG612 Stats Stopped Working
Post by: DeadMan on November 13, 2013, 12:03:48 AM
HG612_current_stats.exe just crashes with an error when run either directly or through the GUI. I have *NO* current stats since the 20th of October in the current stats folder.

I have added a little longer logging using TexPad to save the last hours logs of those massive files.

Title: Re: HG612 Stats Stopped Working
Post by: Bald_Eagle1 on November 13, 2013, 12:12:27 AM
Could you try running HG612_current_stats.exe & then send these logs from the time of the 'crash':-

Current_ERROR.LOG
GRAPH6_ERROR.LOG
ERROR.LOG
ERROR.LOG_file_ERROR.TXT
Login_events.TXT
HG612_stats.ini



Also the same logs from just before to just after a scheduled event may help (say from 22:00 tonight).

 
Title: Re: HG612 Stats Stopped Working
Post by: DeadMan on November 13, 2013, 12:28:10 AM
The logs you have are all from the times it has crashed. Unless there is too much info in them to scour through? I would have to move/delete the existing logs otherwise.
Title: Re: HG612 Stats Stopped Working
Post by: Bald_Eagle1 on November 13, 2013, 12:32:09 AM
I can't see anything from 22:00 tonight in any of the logs.

Have you tried running HG612_current_stats.exe manually yet to see what ends up in the logs?

Also, what is in the last few rows of output on screen before HG612_current_stats.exe crashes?


Title: Re: HG612 Stats Stopped Working
Post by: DeadMan on November 13, 2013, 12:35:36 AM
I run it from a clean install folder and it still crashes (renamed the old folder temporarily) and do not get anything in the current stats folder. All I get is these.
Title: Re: HG612 Stats Stopped Working
Post by: Ronski on November 13, 2013, 07:12:39 AM
Thanks for having a look.

I checked the folder but couldn't see a error file, but do remember the pop-up message,  I wonder if the error file was maybe cleared when I renamed the original modem log to old and a new one was created ?.

HG612 seems to be running still, need to look at the stats myself and maybe log a call with PlusNet, just had a resync at 19:40 which hasn't happened before normally only during the early hours and whilst these were infrequent prior to BT's handywork they seem to be more frequent now or is it just co-incidence ?

The error log won't be deleted, it's possible you're using a version which doesn't create an error log, latest version can be downloaded from the first post in this thread (http://forum.kitz.co.uk/index.php?topic=13078.0)

As for resyncs at unusual times, we had one at work the other day, I'm sure it was 7:30, and I've seen later times as well, although they are generally in the early hours of the morning.
Title: Re: HG612 Stats Stopped Working
Post by: Bald_Eagle1 on November 13, 2013, 07:31:40 AM

I run it from a clean install folder and it still crashes (renamed the old folder temporarily) and do not get anything in the current stats folder. All I get is these.



Assuming you posted the FULL content of your HG612_stats.ini, I get exactly the same symptom if I use it.

The bottom of HG612_stats.ini should look like this:-

Code: [Select]
[Logging]
Ongoing_Logging = YES
Current_Stats = YES
Current_Stats_Interval= 8                                                                               
Current_Stats_Datum = 06


[Editor]
Use_own_tasks= NO

[Event/Error_logging]
Extensive_event_logging= YES




If you don't have these entries in your ini file, add them & resave the file & then try HG612_current_stats.exe:-

Code: [Select]
[Editor]
Use_own_tasks= NO

[Event/Error_logging]
Extensive_event_logging= YES

Title: Re: HG612 Stats Stopped Working
Post by: Ronski on November 13, 2013, 08:11:54 AM
@BE1 the Editor entry does not need to be in the HG612_Stats.ini file, it won't do any harm, but it's left over from a much older version of the GUI editor.

@Deadman Run the latest version of my GUI, alter a setting, and then change it back and save the settings, this should correctly create the ini file.

Title: Re: HG612 Stats Stopped Working
Post by: Korben_dallas on November 13, 2013, 08:45:16 AM
Hi Ronski,

Have downloaded the editor as per the link, so far no further issues with the HG612 prog.  One thing re the resyncs and it seems to coincide with the BT update is that previously the retrain reason was 2 now it is always 1, am just trying to figure out if I should log a call with PlusNet like I say I previously very seldom got resyncs now it is more than weekly.

Cheers
Title: Re: HG612 Stats Stopped Working
Post by: Ronski on November 13, 2013, 10:14:58 AM
I had quite a few resyncs after the firmware changes, but things seem to have settled down now.  It wouldn't hurt to raise a ticket with Plusnet, they can check the logs their end.
Title: Re: HG612 Stats Stopped Working
Post by: DeadMan on November 13, 2013, 04:23:52 PM
I don't know if it was to do with making a forced save in the GUI but it seems it's working again (for now). Is there a way to stop the error log from getting so big in future?
Title: Re: HG612 Stats Stopped Working
Post by: Ronski on November 13, 2013, 05:45:37 PM
Doing a save from within the GUI will save the ini file, and will make sure all options are included.

You can turn off extensive logging, option is on the additional settings tab,  or do as I do and rename the log every so often. Then after a while delete old error logs.

I may even add this functionality to the GUI.
Title: Re: HG612 Stats Stopped Working
Post by: Bald_Eagle1 on November 13, 2013, 11:05:05 PM

@Deadman Run the latest version of my GUI, alter a setting, and then change it back and save the settings, this should correctly create the ini file.



Today's version of HG612_current_stats.exe now defaults to "YES" for Extensive_event_logging (for users that don't have the relevant entry in their ini file).

Other users can still disable it via the GUI if required.

I'll include disabling the debugging logs via the same switch & then I believe it's time to release v 2.0 as an interim measure.


Title: Re: HG612 Stats Stopped Working
Post by: roseway on November 13, 2013, 11:12:42 PM
Quote
I believe it's time to release v 2.0 as an interim measure.

Start a new thread to announce it, and I'll make it sticky to replace the 1.1 announcement.
Title: Re: HG612 Stats Stopped Working
Post by: Bald_Eagle1 on November 13, 2013, 11:18:11 PM
Thanks Eric, will do - possibly after this weekend.

Title: Re: HG612 Stats Stopped Working
Post by: NewtronStar on November 13, 2013, 11:24:47 PM
I believe it's time to release v 2.0 as an interim measure.

as things stand i used r1.1 Hg612_stats and installed the most upto date files from BE1 posts on the forum and also installed rons upto date Settings editor GUI via the forums and all works flawlessly.

It's been hard to keep up so yes V2.0 is very welcome  ;)
Title: Re: HG612 Stats Stopped Working
Post by: Ronski on November 14, 2013, 12:06:15 AM
Thanks Eric, will do - possibly after this weekend.

Did you sort the code for killing stuck instances, or is that coming in a later update?
Title: Re: HG612 Stats Stopped Working
Post by: Bald_Eagle1 on November 14, 2013, 07:56:46 AM
I'm still sussing out how best to use that but I'm really busy work-wise, so it will be in v 2.1 (if improved error trapping doesn't permanently handle potential issues anyway).