HG612 Stats GUI

RONSKI

The first tab in the GUI with the summary data is very useful. Is there any chance of having that as a standalone graph in current stats please? I am setting up remote viewing at the moment...

Also, you are reporting Line attenuation - on my current HG612 pbParams data, the figure you are reporting is actually the Signal attenuation, not the Line attenuation,. At my end they are very different, signal at 23.5 while Line is 18.1 on D1. (HG6123B and d24 Firmware)

There is some discussion on this and other things on this thread.

I'll raid my piggy bank later for you to aid the cause...

Hi Tony,

The table on the summary stats page is created and updated every time stats are logged, so it's not an image. Could you read the modem log file to update your webpage, although this may cause problems for the logging software.

I might also be able to capture an image of the table, but that will require the GUI to be open or BaldEagle might be able to produce an image with the relevant details when producing the other graphs, I'll ask him.

I'll also ask him about the Signal & line attenuation, as he knows what stats are what and I just display the stats.

Ok, I had assumed it was already an image of the live data since it's not selectable as text but not to worry. All the information is available already but it is so nicely presented by you it seemed a shame not to make use of it

The stats in question look like this originally for me as text in pbParams:

VDSL Band Status	U0	U1	U2	U3	U4	D1	D2	D3
  Line Attenuation(dB):	4.5	37.3	53.3	N/A	N/A	18.1	48.0	75.4
Signal Attenuation(dB):	4.5	37.3	52.9	N/A	N/A	25.1	47.7	N/A

but the GUI summary page shows 25.1 as the D1 Line attenuation at my end. They are in the second tab of course.

I thought I had an email from BaldEagle which told me which fields to use for what regarding the attenuation, but can't seem to find the appropriate email, I'll have to await his reply. I've asked him to have a look at this thread.

If you hover the mouse over the values in the tables on the first two tabs it will actually tell you where the data comes from. Where it says field xx, that would be the column number if you was to open the Modem_Stats.log in a spreadsheet, it's just a CSV file. Don't work on the live file though, as the logging software won't be able to update it.

Edit: On mine, on the connection stats tab line attenuation is shown as 21.6, I don't have this value on the pbParams tab. They also come from two different fields in the modem log.

Edited by R0NSKI (Thu 26-Jun-14 20:37:29)

Thanks. I might be wrong but I guess the file you use is especially generated by BaldEagle to get an easily parsed compact record format rather than store the original modem data files. The data we are talking about comes via the pbParams command that you show the output from in Tab 2 (although not in its original format) as there is nowhere else I know of to get it.

One possible problem might be that the later 24j unlocked firmware in combo with the 3B HG612 modem gives sl different data output to the earlier version and might throw out the parsing of the files depending what he used to code from?

There are additional lines of data over the earlier versions in the xdslcmd info --stats Connection Stats output for instance, and Path 0 has changed to Bearer 0 in that output. And the data entry "LOM: " appears now six times and wasn't there before in the time period summaries at the end (what is LOM?)

Probably unlikely though as file dates show it has been updated recently.

Anyway, still a good job though.

LOM�Loss of multiframe

Thanks! Not sure I've got any to lose...

Seriously Off Topic, but for any motorsport fans out there, the Goodwood Festival of Speed is live all three days from Goodwood. Quality feed. Pick it up off their site or Google 'daily telegraph goodwood' as they are also carrying it. I normally go as it's close to me but couldn't make it this time.

Tbailey2 thank you very much for your donation, much appreciated.

The data I use comes from two files, the modem stats log file, and the xlogfile. The xlogfile is rewritten, and the other is just appended to by HG612 stats every minute. The GUI just watches the log file and when it's updated it reads the data required from both.

We have both coded to allow for the changes in the newer firmware, so it should all be covered.

BE1 has replied to my email, this is what he said regarding the attenuation figures.

It appears that what your GUI reports as Line Attenuation is actually the overall attenuation (24.9dB DS & 0.0 dB US).

I have no idea how the HG612 calculates the overall value though.

These (overall) Line & Signal values also come from the linediag data in the Plink log:-

LATN(dB):     24.9         0.0
SATN(dB):     0.0         0.0


They are quite meaningless for a VDSL2 connection, but they are actually more informative from an ADSL connection.
'Better' Line & Signal Attenuation values per band come from the pbParams data for VDSL2 connections which is already reported as a 'picture' in the current/snapshot montage.

So it seems I may need to change the caption to include overall in it.

He also said he'll take a look at producing an image, but can't promise anything.

Best get back to work, tea breaks over.

Edit: As part of quote was missing.

Edited by R0NSKI (Fri 27-Jun-14 18:25:41)

I'm on the case (in between a long list of other things I have to get done).


@ tbailey2:-


Do you actually want a graphic or a text file?

Here's an example of a basic text file using the same data as in the first GUI tab.
At the moment it will be stored in the same folder as modem_stats.log & xlogfile:-

Text

1 23 45 67 89 1011 1213 1415 1617 1819 2021 2223 2425 2627

________________________________________________________________________________________________________________  This information shows the latest ONGOING stats obtained at 09:49 on 28/06/2014 ________________________________________________________________________________________________________________  Connection up time: 2 days 5 hours 46 minutes & 27 seconds              Last Resync recorded at 24/06/2014 05:49  Firmware version: A2pv6C038m.d24j                                       Retrain Reason: 0________________________________________________________________________________________________________________                          Downstream      Upstream                                        Downstream      Upstream                Sync (kbps)    18703          3785                           Interleaving        367             1 Attainable rate (kbps)    21312          3803                                    INP       3.00          0.00        Attenuation (dB)     24.9           0.0        SNR Margin (dB)      6.2           6.3            Power (dBmV)     12.5           6.9                            SES (total)          0             0RSUnCorr errors (delta)        0             0                RSUnCorr errors (total)       4085             0 Errored seconds (delta)        0             0                Errored seconds (total)        113            25       Bitswaps (delta)        0             0                       Bitswaps (total)     105619          1579      CRC errors (delta)        0             0                     CRC errors (total)        215            29     HEC errors (delta)        0             0                     HEC errors (total)        941             0      FEC errors (delta)        0             0                     FEC errors (total)     468851            40________________________________________________________________________________________________________________  .

With more work, I could convert it into a jpeg or a png graphic.

It's very kind of you to even look at it, I was hoping it was already available. A graphic would be ideal if you can do it.

A question - the regular stats collection every xx hours. For me it runs for a while but then stops and there is no new directory created or indeed, any additions to the error logs past the time the last one was created. Looks like a process has stopped?

The every minute data logging carries on okay. If I use the GUI to reset the period it starts the x-hourly current stats creation again the next time it's due and carries on for a while...

The problem may be that the CPU is maxing out a lot - I am going to move both DSLStats and HG612 Stats to another machine tomorrow that has many more cores and is a lot faster.

I'm playing around and in the process of collecting all the data the program produces and putting it into a remote server database parsed out into enough fields to make querying historic data easier. Like show me all graphs produced over a stated period for a given graph. I suppose if I also parsed the stats files as well, you could add to that 'and CRC errors > 237' or whatever

How far this could be taken I don't know as it's early days but it'll take a lot of time to get running as you may well guess. Could/would you FTP the stats up to a remote server if needed immedietaly after they are produced?

Edit: I'm running Windows 8.1 Update 64-bit with all available updates but am moving it all to a Windows 7 64-bit machine.

Edited by tbailey2 (Sat 28-Jun-14 17:53:07)

In reply to a post by tbailey2:

A question - the regular stats collection every xx hours. For me it runs for a while but then stops and there is no new directory created or indeed, any additions to the error logs past the time the last one was created. Looks like a process has stopped?

The every minute data logging carries on okay. If I use the GUI to reset the period it starts the x-hourly current stats creation again the next time it's due and carries on for a while...

Hmmm. That's odd.
The every minute logging task actually triggers the every xx hours logging/graphing.

From the ONGOING_ERROR.LOG:-

28/06/2014 06:00:03.962 - Scheduled snapshot logging is switched ON via the ini file
28/06/2014 06:00:03.962 - Current_Stats_Datum = 06
28/06/2014 06:00:03.962 - Current_Stats_Interval = 6
28/06/2014 06:00:03.962 - (Time in Hours - Datum) Modulus Interval i.e. (6 - 6) % 6 = 0
28/06/2014 06:00:03.962 - (Time in Minutes) = 00
28/06/2014 06:00:03.977 - *** Scheduled snapshot logging IS due, running [HG612_current_stats.exe]



Then from Login_events.txt, evidence that HG612_current_stats.exe has started & logged in to the HG612:-


***********************************************************************************
28/06/2014 6:00:00.21 - Start of [HG612_stats.exe]
28/06/2014 6:00:00.23 - Immediately after "chdir(C:\HG612_Modem_Stats\Scripts)"
28/06/2014 6:00:00.24 - Immediately before ini_parse()
28/06/2014 6:00:00.28 - **** ini file opened for reading O.K. ****
28/06/2014 6:00:00.29 - Immediately after ini_parse()
28/06/2014 6:00:00.37 - From [HG612_stats.ini], the ongoing log_file = "C:\HG612_Modem_Stats\Ongoing_Stats\modem_stats.log"
28/06/2014 6:00:02.09 - **** [HG612_stats.exe] - get_login_data() OK! Status = 1.
=============================

User Name : admin

Login IP : 192.168.1.100

Login Time : 2014-06-28 06:00:00

Login TimeLen :


28/06/2014 6:00:04.14 - Normal End of [HG612_stats.exe]
**********************************************************************************


***********************************************************************************
28/06/2014 6:00:05.92 - In [HG612_current_stats.exe] - At the start of the main() function
28/06/2014 6:00:05.95 - Parameter passed to [HG612_current_stats.exe] = SCHEDULED - i.e. ** AUTOMATICALLY ** initiated via HG612_stats.exe
28/06/2014 6:00:07.61 - **** [HG612_current_stats.exe] - reply(display login) O.K. Status = 1.
28/06/2014 6:00:07.83 - **** [HG612_current_stats.exe] - get_login_data() OK! Status = 1.
From [HG612_current_stats.exe] Login:-
=============================

User Name : admin

Login IP : 192.168.1.100

Login Time : 2014-06-28 06:00:05

Login TimeLen : 1(Secs)


28/06/2014 6:00:12.12 - Normal End of [HG612_current_stats.exe]
*********************************************************************************************




There SHOULD also be some evidence that HG612_current_stats.exe has at least started in CURRENT_ERROR.LOG_file_ERROR.TXT:-

28/06/2014 6:00:05.80 - CURRENT-ISRUNNING-060004-274 - Start of [HG612_current_stats.exe] *** Version 3.0.0.0 - 22/06/14 ***
28/06/2014 6:00:05.97 - CURRENT-ISRUNNING-060004-274 - Immediately after ini_parse() - About to determine the OS version. ERROR.LOG status = 0,
28/06/2014 6:00:05.99 - CURRENT-ISRUNNING-060004-274 - In [HG612_current_stats.exe] - After obtaining the OS version. ERROR.LOG status = 0,
28/06/2014 6:00:06.16 - CURRENT-ISRUNNING-060004-274 - **** From IsRunningVB.exe, dslstatssampling.exe is *NOT* running
28/06/2014 6:00:06.31 - CURRENT-ISRUNNING-060004-274 - Parameter passed to [HG612_current_stats.exe] = SCHEDULED - i.e. ** AUTOMATICALLY ** initiated via HG612_stats.exe


It could just be that there is a clash with DSLStats also attempting to login to the HG612 at the same time.

That shouldn't happen with HG612-Modem-Stats co-operation selected in DSLStats as that will delay DSLStats sampling time until 35 seconds past the minute. i.e. long after HG612 Modem Stats programs have completed.

The problem may be that the CPU is maxing out a lot - I am going to move both DSLStats and HG612 Stats to another machine tomorrow that has many more cores and is a lot faster.

I doubt that being the issue as my programs run reliably on very, very old/slow PCs.
The graphing takes a while on slower PCs, but's done in the background so shouldn't affect actual logging.

I'm playing around and in the process of collecting all the data the program produces and putting it into a remote server database parsed out into enough fields to make querying historic data easier. Like show me all graphs produced over a stated period for a given graph. I suppose if I also parsed the stats files as well, you could add to that 'and CRC errors > 237' or whatever

How far this could be taken I don't know as it's early days but it'll take a lot of time to get running as you may well guess. Could/would you FTP the stats up to a remote server if needed immedietaly after they are produced?

I'm not sure about that.
I would imagine it could be possible though.

Good luck with your efforts.
Let me know if you need any info from me.

Edit: I'm running Windows 8.1 Update 64-bit with all available updates but am moving it all to a Windows 7 64-bit machine.

I use a Windows 7 64-bit machine at my end & see no issues at all.

I suppose Windows 8 / 8.1 does some things differently.
There was an issue for a while when Windows 8 Scheduled Tasks would stop, but that actually stopped the every minute logging task/checks for whether the xx hourly logging was due.

From what you stated above, the every minute task that runs HG612_stats.exe continues to work.

Just to be clear it's a graphic of the display as it is in the GUI - not this text table you show in graphics format - I was after. I guess it won't be possible so please don't worry.

In reply to a post by Bald_Eagle1:

Then from Login_events.txt, evidence that HG612_current_stats.exe has started & logged in to the HG612:-

I'll look at this in more detail tomorrow. It's the Current logging at whatever x hours interval it's set at that's failing not the Ongoing (which you give examples for) which runs okay.

I had set it up to do hourly runs just after 17:00 to see what happened. It ran 18:00, 19:00 and 20:00 okay with the log entries you show for HG612_current_stats.exe starting and ending but for 21:00 there is nothing at all for HG612_current_stats.exe other than the usual HG612_stats.exe minute runs around that time.

One odd thing while all other times are okay, the start time of the runs, for example:
28/06/2014 22:01:29.39

and the normal end time is
28/06/2014 22:01:30.89

But the Login Time in between those two entries reads:
2000-01-04 07:25:57
and it's the same weird Login time every time it runs (but a minute +/- later each time of course)

I'll paste some of the logs in tomorrow and see what happens overnight.

In Current_ERROR_LOG I see the Start of Current Stats Harvesting etc entries okay every hour but again, nothing at all for 21:00 this evening.

I have to admit that the DSLStats cooperation setting wasn't turned on I'd forgotten it was there. It is now though.

Edit: just spotted in ERROR.LOG why the 21:00 Current Stats run was missed - there was no check for it being due made during minute 00 of the hour as the stats collection overran its time. So your condition that Modulus and minutes both have to be zero was never met as it only checked in minutes 59 and 01 ! Time for bed...

Edited by tbailey2 (Sun 29-Jun-14 00:06:21)

Just to say that I've moved the programs on to the other much faster/8 effective core machine and all seems to be well. The routine stats collection now takes 20 secs rather than up to 90 (!) and there is plenty of unused CPU capacity.

I've also popped into the Modem and turned the time sync on!! However, the recorded Login times are still back in 2000? Maybe it hasn't synced yet, surely it doesn't need a reboot?

Edit: I just found SET_HG612_DATE_AND_TIME ... Seems to have done the trick

Edited by tbailey2 (Sun 29-Jun-14 10:24:28)

In reply to a post by tbailey2:

Just to say that I've moved the programs on to the other much faster/8 effective core machine and all seems to be well. The routine stats collection now takes 20 secs rather than up to 90 (!) and there is plenty of unused CPU capacity.

That still seems a long time.

Is that for current (snapshot) logging & graphing or ongoing logging only?




If you watch out for HG612_stats.exe in Task Manager (Show processes for all users ticked), does it show as running at 'Normal' priority or 'Below Normal priority'?

If it's 'Below Normal priority', deleting & recreating the logging task via the GUI should switch it to 'Normal' priority.


Doing that seems to make quite a significant improvement for most users.

Edit: I just found SET_HG612_DATE_AND_TIME ... Seems to have done the trick

The modem's time sync doesn't work in bridge mode (default setting).

That's why I created the SET_HG612_DATE_AND_TIME.exe program.

SET_HG612_DATE_AND_TIME.exe should always auto-run following a resync, but it doesn't do any harm to run it manually every now & then.


You could always manually set up a Scheduled Task to run it every now & then, but if you do, make sure it starts AFTER normal logging has completed & BEFORE or AFTER DSLStats is due to sample the data.


Just for curiosity, how long does DSLStats sampling take at your end?
It takes around 5 seconds (maybe slightly less) at my end.


Unticking the 'Enable extensive error logging' & 'Enable extra debugging info logging' options in the GUI should speed things up quite a bit, but most of the useful data will be lost, only errors being reported.

That makes it harder to examine what's gone wrong or what was working as intended before it went wrong though.




Finally, do things speed up at all if you completely close the GUI?

Unlike DSLStats, it doesn't actually need to be open or running minimised for automated logging/graphing to continue.

Other things here at the moment but...

Okay on the time.

Timing 20 secs Current stats - here's a recent log entry - unless I'm misreading it

*********************************************************************************** 
29/06/2014 11:29:03.86 -   Start of [HG612_stats.exe] 
29/06/2014 11:29:04.19 -   Immediately after "chdir(C:\HG612_Modem_Stats\Scripts)" 
29/06/2014 11:29:04.49 -   Immediately before ini_parse() 
29/06/2014 11:29:04.80 -   **** ini file opened for reading O.K. **** 
29/06/2014 11:29:05.09 -   Immediately after ini_parse() 
29/06/2014 11:29:06.33 -   From [HG612_stats.ini], the ongoing log_file = "C:\HG612_Modem_Stats\Ongoing_Stats\modem_stats.log" 
29/06/2014 11:29:23.42 -   **** [HG612_stats.exe] - get_login_data() OK! Status = 1. 
=============================

User Name     : admin

Login IP      : 192.168.1.18

Login Time    : 2014-06-29 11:29:19

Login TimeLen : 2(Secs)


29/06/2014 11:29:43.34 -   Normal End of [HG612_stats.exe] 
**********************************************************************************

I don't see a process called HG612_stats.exe ever pop up in Task Manager (all users is on) even around the minute but the current stats are obviously running. I see HG612_run.exe all the time at normal priority and a steady 13% CPU usage.

This machine has 16Gb memory, Xeon CPU E3-1270 V3 Hyperthreaded == 8 effective cores at 3.5Ghz. Rated 7.8 by Windows 7. None of the cores are hitting 100% so not overworked. It's Gigabit connected via a CISCO 200 Smart switch into the modem and rest of the LAN.

Here's another one

29/06/2014 12:10:09.78 -   **** ini file opened for reading O.K. **** 
29/06/2014 12:10:10.13 -   Immediately after ini_parse() 
29/06/2014 12:10:11.62 -   From [HG612_stats.ini], the ongoing log_file = "C:\HG612_Modem_Stats\Ongoing_Stats\modem_stats.log" 
29/06/2014 12:10:31.06 -   **** [HG612_stats.exe] - get_login_data() OK! Status = 1. 
=============================

User Name     : admin

Login IP      : 192.168.1.18

Login Time    : 2014-06-29 12:10:26

Login TimeLen : 3(Secs)


29/06/2014 12:10:52.30 -   Normal End of [HG612_stats.exe] 
**********************************************************************************

HG612_stats.exe had stopped as no stats were being collected. I've restarted it and the priority is normal. Still ~ 20secs though.

And DSLStats takes 11-13 seconds currently.

Edited by tbailey2 (Sun 29-Jun-14 12:38:21)

29/06/2014  9:00:31.85 - CURRENT-ISRUNNING-090026-125 - At start of expect("gin:"), sleeping for 0.000 seconds *** numbytes = 0 
29/06/2014  9:00:32.04 - CURRENT-ISRUNNING-090026-125 - PC_Speed is set as "SLOW" in the ini file, times in loop = 01 *** numbytes = 0 
29/06/2014  9:00:32.24 - CURRENT-ISRUNNING-090026-125 - End of expect("gin:") 
29/06/2014  9:00:32.45 - CURRENT-ISRUNNING-090026-125 - expect("gin:") O.K. Status = 1.

Um. after I spotted the above in a log, I noted in the GUI settings that there is an entry for setting the speed at which the PC comunicates with the modem that I hadn't seen before - and it was set to SLOW! I've changed it to Fast. The minute run now takes a fairly consistent 16 seconds. CPU usage is about 36% max at present and averages 21%.

*********************************************************************************** 
29/06/2014 16:18:00.34 -   Start of [HG612_stats.exe] 
29/06/2014 16:18:00.36 -   Immediately after "chdir(C:\HG612_Modem_Stats\Scripts)" 
29/06/2014 16:18:00.38 -   Immediately before ini_parse() 
29/06/2014 16:18:00.41 -   **** ini file opened for reading O.K. **** 
29/06/2014 16:18:00.43 -   Immediately after ini_parse() 
29/06/2014 16:18:00.56 -   From [HG612_stats.ini], the ongoing log_file = "C:\HG612_Modem_Stats\Ongoing_Stats\modem_stats.log" 
29/06/2014 16:18:07.35 -   **** [HG612_stats.exe] - get_login_data() OK! Status = 1. 
=============================

User Name     : admin
Login IP      : 192.168.1.18
Login Time    : 2014-06-29 16:18:06
Login TimeLen : 

29/06/2014 16:18:17.30 -   Normal End of [HG612_stats.exe] 
********************************************************************************** 


*********************************************************************************** 
29/06/2014 16:19:00.38 -   Start of [HG612_stats.exe] 
29/06/2014 16:19:00.40 -   Immediately after "chdir(C:\HG612_Modem_Stats\Scripts)" 
29/06/2014 16:19:00.42 -   Immediately before ini_parse() 
29/06/2014 16:19:00.45 -   **** ini file opened for reading O.K. **** 
29/06/2014 16:19:00.47 -   Immediately after ini_parse() 
29/06/2014 16:19:00.55 -   From [HG612_stats.ini], the ongoing log_file = "C:\HG612_Modem_Stats\Ongoing_Stats\modem_stats.log" 
29/06/2014 16:19:07.39 -   **** [HG612_stats.exe] - get_login_data() OK! Status = 1. 
=============================

User Name     : admin
Login IP      : 192.168.1.18
Login Time    : 2014-06-29 16:19:06
Login TimeLen : 1(Secs)

29/06/2014 16:19:16.47 -   Normal End of [HG612_stats.exe] 
**********************************************************************************

Something seems to have gone very wrong with the 16:00 Current Stats collection wth only the plink file recorded I can't post it all as it won't get accepted sohave chopped some bits out:

29/06/2014 16:00:12.03 - CURRENT-ISRUNNING-160011-972 - Start of [HG612_current_stats.exe] *** Version 2.1 *** 
29/06/2014 16:00:12.15 - CURRENT-ISRUNNING-160011-972 - Immediately after ini_parse() - About to determine the OS version. ERROR.LOG status = 0, 
29/06/2014 16:00:12.17 - CURRENT-ISRUNNING-160011-972 - In [HG612_current_stats.exe] - After obtaining the OS version. ERROR.LOG status = 0, 
29/06/2014 16:00:12.52 - CURRENT-ISRUNNING-160011-972 - From IsRunningVB.exe, there are 1 instances of HG612_stats.exe running. Status = 1, 
29/06/2014 16:00:12.54 - CURRENT-ISRUNNING-160011-972 - Parameter passed to [HG612_current_stats.exe] = SCHEDULED - i.e. ** AUTOMATICALLY ** initiated via HG612_stats.exe 
29/06/2014 16:00:12.69 - CURRENT-ISRUNNING-160011-972 - [HG612_stats.exe] is still running, waiting another 6 seconds for it to complete or time out 
29/06/2014 16:00:12.71 - CURRENT-ISRUNNING-160011-972 - Creating log file Plink_20140629-1600.log 
29/06/2014 16:00:12.75 - CURRENT-ISRUNNING-160011-972 - ************************************************************************* 
29/06/2014 16:00:12.77 - CURRENT-ISRUNNING-160011-972 - At start of expect("gin:"), sleeping for 0.000 seconds *** numbytes = 0 
29/06/2014 16:00:12.79 - CURRENT-ISRUNNING-160011-972 - PC_Speed is set as "FAST" in the ini file, times in loop = 01 *** numbytes = 0 
29/06/2014 16:00:12.81 - CURRENT-ISRUNNING-160011-972 - Still in expect("gin:") loop, times in loop = 02 
29/06/2014 16:00:12.95 - CURRENT-ISRUNNING-160011-972 - End of expect("gin:") 
29/06/2014 16:00:12.98 - CURRENT-ISRUNNING-160011-972 - expect("gin:") O.K. Status = 1. 
29/06/2014 16:00:12.99 - CURRENT-ISRUNNING-160011-972 - ************************************************************************* 
29/06/2014 16:00:13.01 - CURRENT-ISRUNNING-160011-972 - ************************************************************************* 
29/06/2014 16:00:13.03 - CURRENT-ISRUNNING-160011-972 - At start of expect("ssword:"), sleeping for 0.000 seconds *** numbytes = 0 
29/06/2014 16:00:13.05 - CURRENT-ISRUNNING-160011-972 - PC_Speed is set as "FAST" in the ini file, times in loop = 01 *** numbytes = 0 
29/06/2014 16:00:13.07 - CURRENT-ISRUNNING-160011-972 - Still in expect("ssword:") loop, times in loop = 02 
29/06/2014 16:00:13.22 - CURRENT-ISRUNNING-160011-972 - End of expect("ssword:") 
29/06/2014 16:00:13.24 - CURRENT-ISRUNNING-160011-972 - expect("ssword:") O.K. Status = 1. 
29/06/2014 16:00:13.26 - CURRENT-ISRUNNING-160011-972 - ************************************************************************* 
29/06/2014 16:00:13.28 - CURRENT-ISRUNNING-160011-972 - ************************************************************************* 
29/06/2014 16:00:13.30 - CURRENT-ISRUNNING-160011-972 - At start of expect("ATP>"), sleeping for 0.000 seconds *** numbytes = 0 
29/06/2014 16:00:13.32 - CURRENT-ISRUNNING-160011-972 - PC_Speed is set as "FAST" in the ini file, times in loop = 01 *** numbytes = 0 
29/06/2014 16:00:13.34 - CURRENT-ISRUNNING-160011-972 - Still in expect("ATP>") loop, times in loop = 02 
29/06/2014 16:00:13.51 - CURRENT-ISRUNNING-160011-972 - End of expect("ATP>") 
29/06/2014 16:00:13.53 - CURRENT-ISRUNNING-160011-972 - expect("ATP>") O.K. Status = 1. 
29/06/2014 16:00:13.55 - CURRENT-ISRUNNING-160011-972 - ************************************************************************* 
29/06/2014 16:00:16.41 - CURRENT-ISRUNNING-160011-972 - ************************************************************************* 
29/06/2014 16:00:16.43 - CURRENT-ISRUNNING-160011-972 - At start of expect("# "), sleeping for 0.000 seconds *** numbytes = 0 
29/06/2014 16:00:16.45 - CURRENT-ISRUNNING-160011-972 - PC_Speed is set as "FAST" in the ini file, times in loop = 01 *** numbytes = 0 
29/06/2014 16:00:16.47 - CURRENT-ISRUNNING-160011-972 - Still in expect("# ") loop, times in loop = 02 
29/06/2014 16:00:16.61 - CURRENT-ISRUNNING-160011-972 - End of expect("# ") 
29/06/2014 16:00:16.63 - CURRENT-ISRUNNING-160011-972 - ************************************************************************* 
29/06/2014 16:00:16.65 - CURRENT-ISRUNNING-160011-972 - In get_data(#01). *** This was included in data received:- xdslcmd info --stats - (numbytes = 1536) 
29/06/2014 16:00:16.84 - CURRENT-ISRUNNING-160011-972 - In get_data(#02). *** This was included in data received:- xdslcmd info --stats - (numbytes = 404) 
29/06/2014 16:00:16.87 - CURRENT-ISRUNNING-160011-972 - get_data() for (xdslcmd info --stats) O.K. Status = 1, times in get_data() loop was 002 
29/06/2014 16:00:16.89 - CURRENT-ISRUNNING-160011-972 - ************************************************************************* 
29/06/2014 16:00:16.93 - CURRENT-ISRUNNING-160011-972 - In get_data(#01). *** This was included in data received:- xdslcmd info --pbParams - (numbytes = 1023) 
29/06/2014 16:00:17.12 - CURRENT-ISRUNNING-160011-972 - In get_data(#02). *** This was included in data received:- xdslcmd info --pbParams - (numbytes = 34) 
29/06/2014 16:00:17.15 - CURRENT-ISRUNNING-160011-972 - get_data() for (xdslcmd info --pbParams) O.K. Status = 1, times in get_data() loop was 002 
29/06/2014 16:00:17.17 - CURRENT-ISRUNNING-160011-972 - ************************************************************************* 
29/06/2014 16:00:17.24 - CURRENT-ISRUNNING-160011-972 - In get_data(#01). *** This was included in data received:- xdslcmd info --Bits - (numbytes = 21) 
29/06/2014 16:00:17.26 - CURRENT-ISRUNNING-160011-972 - In get_data(#02). *** This was included in data received:- xdslcmd info --Bits - (numbytes = 4114) 
29/06/2014 16:00:17.28 - CURRENT-ISRUNNING-160011-972 - In get_data(#03). *** This was included in data received:- xdslcmd info --Bits - (numbytes = 3012) 
29/06/2014 16:00:17.30 - CURRENT-ISRUNNING-160011-972 - In get_data(#04). *** This was included in data received:- xdslcmd info --Bits - (numbytes = 2993) 
29/06/2014 16:00:17.32 - CURRENT-ISRUNNING-160011-972 - **** (xdslcmd info --Bits) - Because this is attempt #005, sleeping for 0.500 seconds *** numbytes = 1501 
29/06/2014 16:00:17.84 - CURRENT-ISRUNNING-160011-972 - In get_data(#05). *** This was included in data received:- xdslcmd info --Bits - (numbytes = 1501) 
29/06/2014 16:00:17.86 - CURRENT-ISRUNNING-160011-972 - In get_data(#06). *** This was included in data received:- xdslcmd info --Bits - (numbytes = 37094) 
29/06/2014 16:00:17.88 - CURRENT-ISRUNNING-160011-972 - get_data() for (xdslcmd info --Bits) O.K. Status = 1, times in get_data() loop was 006 
29/06/2014 16:00:17.90 - CURRENT-ISRUNNING-160011-972 - ************************************************************************* 
29/06/2014 16:00:17.92 - CURRENT-ISRUNNING-160011-972 - In get_data(#01). *** This was included in data received:- xdslcmd info --linediag - (numbytes = 25) 
29/06/2014 16:00:17.96 - CURRENT-ISRUNNING-160011-972 - In get_data(#02). *** This was included in data received:- xdslcmd info --linediag - (numbytes = 4100) 
29/06/2014 16:00:17.98 - CURRENT-ISRUNNING-160011-972 - In get_data(#03). *** This was included in data received:- xdslcmd info --linediag - (numbytes = 6168) 
29/06/2014 16:00:18.01 - CURRENT-ISRUNNING-160011-972 - In get_data(#04). *** This was included in data received:- xdslcmd info --linediag - (numbytes = 4654) 
29/06/2014 16:00:18.03 - CURRENT-ISRUNNING-160011-972 - **** (xdslcmd info --linediag) - Because this is attempt #005, sleeping for 0.500 seconds *** numbytes = 3222 
29/06/2014 16:00:18.55 - CURRENT-ISRUNNING-160011-972 - In get_data(#05). *** This was included in data received:- xdslcmd info --linediag - (numbytes = 3222) 
29/06/2014 16:00:18.57 - CURRENT-ISRUNNING-160011-972 - In get_data(#06). *** This was included in data received:- xdslcmd info --linediag - (numbytes = 74674) 
29/06/2014 16:00:18.59 - CURRENT-ISRUNNING-160011-972 - In get_data(#07). *** This was included in data received:- xdslcmd info --linediag - (numbytes = 11680) 
29/06/2014 16:00:18.61 - CURRENT-ISRUNNING-160011-972 - In get_data(#08). *** This was included in data received:- xdslcmd info --linediag - (numbytes = 11840) 
29/06/2014 16:00:18.63 - CURRENT-ISRUNNING-160011-972 - In get_data(#09). *** This was included in data received:- xdslcmd info --linediag - (numbytes = 4880) 
29/06/2014 16:00:18.65 - CURRENT-ISRUNNING-160011-972 - **** (xdslcmd info --linediag) - Because this is attempt #010, sleeping for 0.500 seconds *** numbytes = 7220 
29/06/2014 16:00:19.82 - CURRENT-ISRUNNING-160011-972 - In get_data(#10). *** This was included in data received:- xdslcmd info --linediag - (numbytes = 7220) 
29/06/2014 16:00:19.83 - CURRENT-ISRUNNING-160011-972 - In get_data(#11). *** This was included in data received:- xdslcmd info --linediag - (numbytes = 73220) 
29/06/2014 16:00:19.87 - CURRENT-ISRUNNING-160011-972 - In get_data(#12). *** This was included in data received:- xdslcmd info --linediag - (numbytes = 24340) 
29/06/2014 16:00:19.88 - CURRENT-ISRUNNING-160011-972 - In get_data(#13). *** This was included in data received:- xdslcmd info --linediag - (numbytes = 7071) 
29/06/2014 16:00:19.90 - CURRENT-ISRUNNING-160011-972 - In get_data(#14). *** This was included in data received:- xdslcmd info --linediag - (numbytes = 6955) 
29/06/2014 16:00:19.92 - CURRENT-ISRUNNING-160011-972 - **** (xdslcmd info --linediag) - Because this is attempt #015, sleeping for 0.500 seconds *** numbytes = 7229 
29/06/2014 16:00:20.44 - CURRENT-ISRUNNING-160011-972 - In get_data(#15). *** This was included in data received:- xdslcmd info --linediag - (numbytes = 7229) 
29/06/2014 16:00:20.46 - CURRENT-ISRUNNING-160011-972 - In get_data(#16). *** This was included in data received:- xdslcmd info --linediag - (numbytes = 37872) 
29/06/2014 16:02:20.02 - CURRENT-ISRUNNING-160011-972 - In get_data(#17). *** This was included in data received:- xdslcmd info --linediag - (numbytes = 6) 
29/06/2014 16:07:20.01 - CURRENT-ISRUNNING-160011-972 - In get_data(#18). *** This was included in data received:- xdslcmd info --linediag - (numbytes = 0) 
29/06/2014 16:07:20.03 - CURRENT-ISRUNNING-160011-972 - In get_data(#19). *** This was included in data received:- xdslcmd info --linediag - (numbytes = 0) 
29/06/2014 16:07:20.06 - CURRENT-ISRUNNING-160011-972 - In get_data(#20). *** This was included in data received:- xdslcmd info --linediag - (numbytes = 0) 
29/06/2014 16:07:20.08 - CURRENT-ISRUNNING-160011-972 - In get_data(#21). *** This was included in data received:- xdslcmd info --linediag - (numbytes = 0) 
29/06/2014 16:07:20.10 - CURRENT-ISRUNNING-160011-972 - In get_data(#22). *** This was included in data received:- xdslcmd info --linediag - (numbytes = 0) 

repeated entries the same until


29/06/2014 16:07:30.37 - CURRENT-ISRUNNING-160011-972 - In get_data(#497). *** This was included in data received:- xdslcmd info --linediag - (numbytes = 0) 
29/06/2014 16:07:30.38 - CURRENT-ISRUNNING-160011-972 - In get_data(#498). *** This was included in data received:- xdslcmd info --linediag - (numbytes = 0) 
29/06/2014 16:07:30.41 - CURRENT-ISRUNNING-160011-972 - In get_data(#499). *** This was included in data received:- xdslcmd info --linediag - (numbytes = 0) 
29/06/2014 16:07:30.43 - CURRENT-ISRUNNING-160011-972 - In get_data(#500). *** This was included in data received:- xdslcmd info --linediag - (numbytes = 0) 
29/06/2014 16:07:30.45 - CURRENT-ISRUNNING-160011-972 - *** ERROR!!! - Now in get_data_exit as times_in_loop was 500. Status = 1, 
29/06/2014 16:07:30.47 - CURRENT-ISRUNNING-160011-972 - Temp File CURRENT_GET_DATA_ERROR-160730-457.TXT was created. Status = 1, 
29/06/2014 16:07:30.62 - CURRENT-ISRUNNING-160011-972 - About to close(sockfd). Status = 1, 
29/06/2014 16:07:30.64 - CURRENT-ISRUNNING-160011-972 - *** WSACleanup has completed. 
29/06/2014 16:07:30.66 - CURRENT-ISRUNNING-160011-972 - *** About to free(txbuf). 
29/06/2014 16:07:30.68 - CURRENT-ISRUNNING-160011-972 - *** txbuf has been freed. 
29/06/2014 16:07:30.70 - CURRENT-ISRUNNING-160011-972 - *** About to free(rxbuf). 
29/06/2014 16:07:30.76 - CURRENT-ISRUNNING-160011-972 - *** rxbuf has been freed. 
29/06/2014 16:07:30.78 - CURRENT-ISRUNNING-160011-972 - CURRENT-ISRUNNING-160011-972 DELETED - Status = 1, 
29/06/2014 16:07:30.89 - CURRENT-ISRUNNING-160011-972 - ERROR.LOG successfully closed. Status = 0, 
29/06/2014 16:07:30.91 - CURRENT-ISRUNNING-160011-972 - Abnormal End of [HG612_current_stats.exe] - Status = 0,

Edit
Unless you are timing the minute run from login success to ending in which case it's 9 seconds...

Edited by tbailey2 (Sun 29-Jun-14 19:25:20)

SET_HG612_DATE_AND_TIME is the only way to set the date/time on the modem in bridged mode.

In reply to a post by simon194:

SET_HG612_DATE_AND_TIME is the only way to set the date/time on the modem in bridged mode.

Yes, I found that earlier on this morning thanks.