Print

Please login or register.
1 Hour 1 Day 1 Week 1 Month Forever
Login with username, password and session length

[kitzuser87430]

Hello
Carrying on where AlecR left off....

I am trying to use this program with my hg635 on my adsl line.

I have used your attached version of hg612_stats.exe...and using the hg622 option.

here is a copy of my ongoing error log file when i manually run hg612_run.exe

Code: [Select]

16/10/2015 17:44:21.77 - ONGOING-ISRUNNING-174421-745.TXT - Start of [HG612_stats.exe] - **** Version 5.1.0.3 30/07/2015 ****
16/10/2015 17:44:21.87 - ONGOING-ISRUNNING-174421-745.TXT - Immediately after ini_parse() - About to determine the OS version. ERROR.LOG status = 0,
16/10/2015 17:44:21.88 - ONGOING-ISRUNNING-174421-745.TXT - *** Windows version = [6.2.9200] ***
16/10/2015 17:44:21.90 - ONGOING-ISRUNNING-174421-745.TXT - In [HG612_stats.exe] - After obtaining the OS version. ERROR.LOG status = 0,
16/10/2015 17:44:21.92 - ONGOING-ISRUNNING-174421-745.TXT - From ini file, Modem_type = HG622. Status = 0,
16/10/2015 17:44:21.94 - ONGOING-ISRUNNING-174421-745.TXT - ERROR.LOG successfully opened. Status = 1,
16/10/2015 17:44:22.10 - ONGOING-ISRUNNING-174421-745.TXT - **** From IsRunningVB.exe, dslstatssampling.exe is *NOT* running
16/10/2015 17:44:22.27 - ONGOING-ISRUNNING-174421-745.TXT - ONGOING-ISRUNNING-174421-745.TXT created. Status = 1,
16/10/2015 17:44:22.74 - ONGOING-ISRUNNING-174421-745.TXT - There are 1 instances of HG612_stats.exe running. Status = 1,
16/10/2015 17:44:22.75 - ONGOING-ISRUNNING-174421-745.TXT - Continuing as there are only 1 instances of HG612_stats.exe running **. Status = 1,
16/10/2015 17:44:22.77 - ONGOING-ISRUNNING-174421-745.TXT - WSAStartup() SUCCESSFUL!!! Status = 1,
16/10/2015 17:44:22.78 - ONGOING-ISRUNNING-174421-745.TXT - hg612ip = 10.10.11.245, HG612PORT = 23. Status = 1,
16/10/2015 17:44:22.79 - ONGOING-ISRUNNING-174421-745.TXT - getaddrinfo() O.K. Status = 1,
16/10/2015 17:44:22.81 - ONGOING-ISRUNNING-174421-745.TXT - socket() O.K. Status = 1,
16/10/2015 17:44:22.82 - ONGOING-ISRUNNING-174421-745.TXT - sockfd = 300, "res->ai_addrlen" = 16 connect() ERROR CODE = 0. Status = 1,
16/10/2015 17:44:22.83 - ONGOING-ISRUNNING-174421-745.TXT - connect() O.K. Status = 1,
16/10/2015 17:44:22.85 - ONGOING-ISRUNNING-174421-745.TXT - *************************************************************************
16/10/2015 17:44:22.86 - ONGOING-ISRUNNING-174421-745.TXT - At start of expect("gin:"), times in loop = 01 *** numbytes = 0
16/10/2015 17:44:22.87 - ONGOING-ISRUNNING-174421-745.TXT - ****** PC_Speed is set as "SLOW" in the ini file, times in loop = 01 *** numbytes = 0
16/10/2015 17:44:22.89 - ONGOING-ISRUNNING-174421-745.TXT - At start of expect("gin:"), sleeping for 0.000 seconds *** numbytes = 0
16/10/2015 17:44:22.90 - ONGOING-ISRUNNING-174421-745.TXT - numbytes received from recv(sockfd, rxbuf, RXBUFSIZE-1, 0) = 9
16/10/2015 17:44:22.91 - ONGOING-ISRUNNING-174421-745.TXT - Still in expect("gin:") loop, times in loop = 02
16/10/2015 17:44:42.84 - ONGOING-ISRUNNING-174421-745.TXT - Still in expect("gin:") loop, times in loop = 03
16/10/2015 17:44:42.85 - ONGOING-ISRUNNING-174421-745.TXT - Still in expect("gin:") loop, times in loop = 04
16/10/2015 17:44:42.87 - ONGOING-ISRUNNING-174421-745.TXT - In expect("gin:"). Because times in loop = 5, sleeping for 0.000 seconds *** numbytes = 0
16/10/2015 17:44:42.88 - ONGOING-ISRUNNING-174421-745.TXT - Still in expect("gin:") loop, times in loop = 05
16/10/2015 17:44:42.89 - ONGOING-ISRUNNING-174421-745.TXT - Still in expect("gin:") loop, times in loop = 06
16/10/2015 17:44:42.91 - ONGOING-ISRUNNING-174421-745.TXT - Still in expect("gin:") loop, times in loop = 07
16/10/2015 17:44:42.92 - ONGOING-ISRUNNING-174421-745.TXT - Still in expect("gin:") loop, times in loop = 08
16/10/2015 17:44:42.93 - ONGOING-ISRUNNING-174421-745.TXT - Still in expect("gin:") loop, times in loop = 09
16/10/2015 17:44:42.94 - ONGOING-ISRUNNING-174421-745.TXT - End of expect("gin:")
16/10/2015 17:44:42.95 - ONGOING-ISRUNNING-174421-745.TXT - *************************************************************************
16/10/2015 17:44:42.97 - ONGOING-ISRUNNING-174421-745.TXT - expect("gin:") O.K. Status = 1.
16/10/2015 17:44:42.98 - ONGOING-ISRUNNING-174421-745.TXT - reply(config.Username) O.K. Status = 1.
16/10/2015 17:44:42.99 - ONGOING-ISRUNNING-174421-745.TXT - Username from HG612_stats.ini = "**************". Status = 1.
16/10/2015 17:44:43.00 - ONGOING-ISRUNNING-174421-745.TXT - *************************************************************************
16/10/2015 17:44:43.02 - ONGOING-ISRUNNING-174421-745.TXT - At start of expect("ssword:"), times in loop = 01 *** numbytes = 0
16/10/2015 17:44:43.03 - ONGOING-ISRUNNING-174421-745.TXT - ****** PC_Speed is set as "SLOW" in the ini file, times in loop = 01 *** numbytes = 0
16/10/2015 17:44:43.04 - ONGOING-ISRUNNING-174421-745.TXT - At start of expect("ssword:"), sleeping for 0.000 seconds *** numbytes = 0
16/10/2015 17:44:43.05 - ONGOING-ISRUNNING-174421-745.TXT - Still in expect("ssword:") loop, times in loop = 02
16/10/2015 17:44:43.07 - ONGOING-ISRUNNING-174421-745.TXT - Still in expect("ssword:") loop, times in loop = 03
16/10/2015 17:44:43.08 - ONGOING-ISRUNNING-174421-745.TXT - Still in expect("ssword:") loop, times in loop = 04
16/10/2015 17:44:43.09 - ONGOING-ISRUNNING-174421-745.TXT - In expect("ssword:"). Because times in loop = 5, sleeping for 0.000 seconds *** numbytes = 0
16/10/2015 17:44:43.10 - ONGOING-ISRUNNING-174421-745.TXT - Still in expect("ssword:") loop, times in loop = 05
16/10/2015 17:44:43.12 - ONGOING-ISRUNNING-174421-745.TXT - Still in expect("ssword:") loop, times in loop = 06
16/10/2015 17:44:43.13 - ONGOING-ISRUNNING-174421-745.TXT - Still in expect("ssword:") loop, times in loop = 07
16/10/2015 17:44:43.14 - ONGOING-ISRUNNING-174421-745.TXT - Still in expect("ssword:") loop, times in loop = 08
16/10/2015 17:44:43.15 - ONGOING-ISRUNNING-174421-745.TXT - Still in expect("ssword:") loop, times in loop = 09
16/10/2015 17:44:43.17 - ONGOING-ISRUNNING-174421-745.TXT - End of expect("ssword:")
16/10/2015 17:44:43.18 - ONGOING-ISRUNNING-174421-745.TXT - *************************************************************************
16/10/2015 17:44:43.19 - ONGOING-ISRUNNING-174421-745.TXT - expect("ssword:") O.K. Status = 1.
16/10/2015 17:44:43.20 - ONGOING-ISRUNNING-174421-745.TXT - reply(config.Password) O.K. Status = 1.
16/10/2015 17:44:43.21 - ONGOING-ISRUNNING-174421-745.TXT - Password from HG612_stats.ini = "2*********". Status = 1.
16/10/2015 17:44:43.23 - ONGOING-ISRUNNING-174421-745.TXT - *************************************************************************
16/10/2015 17:44:43.24 - ONGOING-ISRUNNING-174421-745.TXT - At start of expect("ATP>"), times in loop = 01 *** numbytes = 0
16/10/2015 17:44:43.25 - ONGOING-ISRUNNING-174421-745.TXT - ****** PC_Speed is set as "SLOW" in the ini file, times in loop = 01 *** numbytes = 0
16/10/2015 17:44:43.26 - ONGOING-ISRUNNING-174421-745.TXT - At start of expect("ATP>"), sleeping for 0.000 seconds *** numbytes = 0
16/10/2015 17:44:43.28 - ONGOING-ISRUNNING-174421-745.TXT - Still in expect("ATP>") loop, times in loop = 02
16/10/2015 17:44:43.29 - ONGOING-ISRUNNING-174421-745.TXT - ERROR!!! - recv failed with error code 10053
16/10/2015 17:44:43.30 - ONGOING-ISRUNNING-174421-745.TXT - ERROR!!! - numbytes received from recv(sockfd, rxbuf, RXBUFSIZE-1, 0) = -1. Returning to main() function
16/10/2015 17:44:43.31 - ONGOING-ISRUNNING-174421-745.TXT - **** expect("ATP>") FAILED!!! - exiting. Status = 1.
16/10/2015 17:44:43.32 - ONGOING-ISRUNNING-174421-745.TXT - Now in exit. Status = 1,
16/10/2015 17:44:43.34 - ONGOING-ISRUNNING-174421-745.TXT - *** WSACleanup has completed.
16/10/2015 17:44:43.35 - ONGOING-ISRUNNING-174421-745.TXT - *** About to free(txbuf).
16/10/2015 17:44:43.36 - ONGOING-ISRUNNING-174421-745.TXT - *** txbuf has been freed.
16/10/2015 17:44:43.37 - ONGOING-ISRUNNING-174421-745.TXT - *** About to free(rxbuf).
16/10/2015 17:44:43.38 - ONGOING-ISRUNNING-174421-745.TXT - *** rxbuf has been freed.
16/10/2015 17:44:43.39 - ONGOING-ISRUNNING-174421-745.TXT - *** Now checking for resyncs - There are 1 instances of HG612_stats.exe running.
16/10/2015 17:44:43.40 - ONGOING-ISRUNNING-174421-745.TXT - ONGOING-ISRUNNING-174421-745.TXT DELETED - Status = 1,
16/10/2015 17:44:43.42 - ONGOING-ISRUNNING-174421-745.TXT - *** Scheduled snapshot logging is switched ON.
16/10/2015 17:44:43.43 - ONGOING-ISRUNNING-174421-745.TXT - *** Scheduled snapshot logging is NOT due yet.
16/10/2015 17:44:43.44 - ONGOING-ISRUNNING-174421-745.TXT - *** Scheduled Daily graphing is NOT switched on.
16/10/2015 17:44:43.45 - ONGOING-ISRUNNING-174421-745.TXT - End of [HG612_stats.exe], Closing ERROR.LOG. Status = 1,
16/10/2015 17:44:43.46 - ONGOING-ISRUNNING-174421-745.TXT - ERROR.LOG successfully closed. Status = 0,
16/10/2015 17:44:43.47 - ONGOING-ISRUNNING-174421-745.TXT - total_sleep_time = 0.000 seconds
16/10/2015 17:44:43.48 - ONGOING-ISRUNNING-174421-745.TXT - Normal End of [HG612_stats.exe]
16/10/2015 17:44:43.52 - ONGOING-ISRUNNING-174421-745.TXT - End of [HG612_stats.exe] WebStats is NOT switched ON
 
Thanks Ian

Modified code to add full debugging error

[Ronski]

Hi Ian, unfortunately I can't help with this as the stats collection is BaldEagle1 side of things, hopefully he will see your post and reply.

[Bald_Eagle1]

Hi kitzuser87430,

I've seen your query & I'll try to assist.

[kitzuser87430]

Thanks...no rush.

Ian

[Bald_Eagle1]

AlecR had previously mentioned it takes a long time to login to the HG635.

It seems that on your system, there was a 20 second pause between the 2nd attempt and the 3rd whilst awaiting the "Login:" prompt:-

16/10/2015 17:44:22.89 - ONGOING-ISRUNNING-174421-745.TXT - At start of expect("gin:"), sleeping for 0.000 seconds *** numbytes = 0
16/10/2015 17:44:22.90 - ONGOING-ISRUNNING-174421-745.TXT - numbytes received from recv(sockfd, rxbuf, RXBUFSIZE-1, 0) = 9
16/10/2015 17:44:22.91 - ONGOING-ISRUNNING-174421-745.TXT - Still in expect("gin:") loop, times in loop = 02
16/10/2015 17:44:42.84 - ONGOING-ISRUNNING-174421-745.TXT - Still in expect("gin:") loop, times in loop = 03
16/10/2015 17:44:42.85 - ONGOING-ISRUNNING-174421-745.TXT - Still in expect("gin:") loop, times in loop = 04
16/10/2015 17:44:42.87 - ONGOING-ISRUNNING-174421-745.TXT - In expect("gin:"). Because times in loop = 5, sleeping for 0.000 seconds *** numbytes = 0
16/10/2015 17:44:42.88 - ONGOING-ISRUNNING-174421-745.TXT - Still in expect("gin:") loop, times in loop = 05
16/10/2015 17:44:42.89 - ONGOING-ISRUNNING-174421-745.TXT - Still in expect("gin:") loop, times in loop = 06
16/10/2015 17:44:42.91 - ONGOING-ISRUNNING-174421-745.TXT - Still in expect("gin:") loop, times in loop = 07
16/10/2015 17:44:42.92 - ONGOING-ISRUNNING-174421-745.TXT - Still in expect("gin:") loop, times in loop = 08
16/10/2015 17:44:42.93 - ONGOING-ISRUNNING-174421-745.TXT - Still in expect("gin:") loop, times in loop = 09
16/10/2015 17:44:42.94 - ONGOING-ISRUNNING-174421-745.TXT - End of expect("gin:")
16/10/2015 17:44:42.95 - ONGOING-ISRUNNING-174421-745.TXT - *************************************************************************
16/10/2015 17:44:42.97 - ONGOING-ISRUNNING-174421-745.TXT - expect("gin:") O.K. Status = 1.


 * Do you see the same pause if logging in manually via Telnet?


Could you try setting PC speed to FAST via the GUI in order to slow down program flow to make allowance for a slower modem & let me see the resulting log file?

This may assist.
If not, I have some other ideas to try one at a time.

[kitzuser87430]

OK

Changed pc speed (edit of ini) to FAST

Code: [Select]


18/10/2015 14:47:30.33 - ONGOING-ISRUNNING-144730-306.TXT - Start of [HG612_stats.exe] - **** Version 5.1.0.3 30/07/2015 ****
18/10/2015 14:47:30.44 - ONGOING-ISRUNNING-144730-306.TXT - Immediately after ini_parse() - About to determine the OS version. ERROR.LOG status = 0,
18/10/2015 14:47:30.45 - ONGOING-ISRUNNING-144730-306.TXT - *** Windows version = [6.2.9200] ***
18/10/2015 14:47:30.46 - ONGOING-ISRUNNING-144730-306.TXT - In [HG612_stats.exe] - After obtaining the OS version. ERROR.LOG status = 0,
18/10/2015 14:47:30.48 - ONGOING-ISRUNNING-144730-306.TXT - From ini file, Modem_type = HG622. Status = 0,
18/10/2015 14:47:30.51 - ONGOING-ISRUNNING-144730-306.TXT - ERROR.LOG successfully opened. Status = 1,
18/10/2015 14:47:30.65 - ONGOING-ISRUNNING-144730-306.TXT - **** From IsRunningVB.exe, dslstatssampling.exe is *NOT* running
18/10/2015 14:47:30.79 - ONGOING-ISRUNNING-144730-306.TXT - ONGOING-ISRUNNING-144730-306.TXT created. Status = 1,
18/10/2015 14:47:31.17 - ONGOING-ISRUNNING-144730-306.TXT - There are 1 instances of HG612_stats.exe running. Status = 1,
18/10/2015 14:47:31.29 - ONGOING-ISRUNNING-144730-306.TXT - Continuing as there are only 1 instances of HG612_stats.exe running **. Status = 1,
18/10/2015 14:47:31.31 - ONGOING-ISRUNNING-144730-306.TXT - WSAStartup() SUCCESSFUL!!! Status = 1,
18/10/2015 14:47:31.32 - ONGOING-ISRUNNING-144730-306.TXT - hg612ip = 10.10.11.245, HG612PORT = 23. Status = 1,
18/10/2015 14:47:31.33 - ONGOING-ISRUNNING-144730-306.TXT - getaddrinfo() O.K. Status = 1,
18/10/2015 14:47:31.34 - ONGOING-ISRUNNING-144730-306.TXT - socket() O.K. Status = 1,
18/10/2015 14:47:31.36 - ONGOING-ISRUNNING-144730-306.TXT - sockfd = 232, "res->ai_addrlen" = 16 connect() ERROR CODE = 0. Status = 1,
18/10/2015 14:47:31.37 - ONGOING-ISRUNNING-144730-306.TXT - connect() O.K. Status = 1,
18/10/2015 14:47:31.38 - ONGOING-ISRUNNING-144730-306.TXT - *************************************************************************
18/10/2015 14:47:31.39 - ONGOING-ISRUNNING-144730-306.TXT - At start of expect("gin:"), times in loop = 01 *** numbytes = 0
18/10/2015 14:47:31.40 - ONGOING-ISRUNNING-144730-306.TXT - ****** PC_Speed is set as "FAST" in the ini file, times in loop = 01 *** numbytes = 0
18/10/2015 14:47:31.42 - ONGOING-ISRUNNING-144730-306.TXT - At start of expect("gin:"), sleeping for 0.500 seconds *** numbytes = 0
18/10/2015 14:47:31.93 - ONGOING-ISRUNNING-144730-306.TXT - numbytes received from recv(sockfd, rxbuf, RXBUFSIZE-1, 0) = 9
18/10/2015 14:47:31.95 - ONGOING-ISRUNNING-144730-306.TXT - Still in expect("gin:") loop, times in loop = 02
18/10/2015 14:47:51.38 - ONGOING-ISRUNNING-144730-306.TXT - Still in expect("gin:") loop, times in loop = 03
18/10/2015 14:47:51.39 - ONGOING-ISRUNNING-144730-306.TXT - Still in expect("gin:") loop, times in loop = 04
18/10/2015 14:47:51.40 - ONGOING-ISRUNNING-144730-306.TXT - In expect("gin:"). Because times in loop = 5, sleeping for 0.500 seconds *** numbytes = 0
18/10/2015 14:47:51.91 - ONGOING-ISRUNNING-144730-306.TXT - Still in expect("gin:") loop, times in loop = 05
18/10/2015 14:47:51.92 - ONGOING-ISRUNNING-144730-306.TXT - Still in expect("gin:") loop, times in loop = 06
18/10/2015 14:47:51.94 - ONGOING-ISRUNNING-144730-306.TXT - Still in expect("gin:") loop, times in loop = 07
18/10/2015 14:47:51.95 - ONGOING-ISRUNNING-144730-306.TXT - Still in expect("gin:") loop, times in loop = 08
18/10/2015 14:47:51.96 - ONGOING-ISRUNNING-144730-306.TXT - Still in expect("gin:") loop, times in loop = 09
18/10/2015 14:47:51.97 - ONGOING-ISRUNNING-144730-306.TXT - End of expect("gin:")
18/10/2015 14:47:51.98 - ONGOING-ISRUNNING-144730-306.TXT - *************************************************************************
18/10/2015 14:47:51.99 - ONGOING-ISRUNNING-144730-306.TXT - expect("gin:") O.K. Status = 1.
18/10/2015 14:47:52.01 - ONGOING-ISRUNNING-144730-306.TXT - reply(config.Username) O.K. Status = 1.
18/10/2015 14:47:52.02 - ONGOING-ISRUNNING-144730-306.TXT - Username from HG612_stats.ini = "**********". Status = 1.
18/10/2015 14:47:52.03 - ONGOING-ISRUNNING-144730-306.TXT - *************************************************************************
18/10/2015 14:47:52.04 - ONGOING-ISRUNNING-144730-306.TXT - At start of expect("ssword:"), times in loop = 01 *** numbytes = 0
18/10/2015 14:47:52.05 - ONGOING-ISRUNNING-144730-306.TXT - ****** PC_Speed is set as "FAST" in the ini file, times in loop = 01 *** numbytes = 0
18/10/2015 14:47:52.06 - ONGOING-ISRUNNING-144730-306.TXT - At start of expect("ssword:"), sleeping for 0.500 seconds *** numbytes = 0
18/10/2015 14:47:52.58 - ONGOING-ISRUNNING-144730-306.TXT - ERROR!!! - recv failed with error code 10053
18/10/2015 14:47:52.59 - ONGOING-ISRUNNING-144730-306.TXT - ERROR!!! - numbytes received from recv(sockfd, rxbuf, RXBUFSIZE-1, 0) = -1. Returning to main() function
18/10/2015 14:47:52.60 - ONGOING-ISRUNNING-144730-306.TXT - **** expect("ssword:") FAILED!!! - exiting. Status = 1.
18/10/2015 14:47:52.61 - ONGOING-ISRUNNING-144730-306.TXT - Now in exit. Status = 1,
18/10/2015 14:47:52.62 - ONGOING-ISRUNNING-144730-306.TXT - *** WSACleanup has completed.
18/10/2015 14:47:52.63 - ONGOING-ISRUNNING-144730-306.TXT - *** About to free(txbuf).
18/10/2015 14:47:52.64 - ONGOING-ISRUNNING-144730-306.TXT - *** txbuf has been freed.
18/10/2015 14:47:52.66 - ONGOING-ISRUNNING-144730-306.TXT - *** About to free(rxbuf).
18/10/2015 14:47:52.67 - ONGOING-ISRUNNING-144730-306.TXT - *** rxbuf has been freed.
18/10/2015 14:47:52.68 - ONGOING-ISRUNNING-144730-306.TXT - *** Now checking for resyncs - There are 1 instances of HG612_stats.exe running.
18/10/2015 14:47:52.69 - ONGOING-ISRUNNING-144730-306.TXT - ONGOING-ISRUNNING-144730-306.TXT DELETED - Status = 1,
18/10/2015 14:47:52.70 - ONGOING-ISRUNNING-144730-306.TXT - *** Scheduled snapshot logging is switched ON.
18/10/2015 14:47:52.71 - ONGOING-ISRUNNING-144730-306.TXT - *** Scheduled snapshot logging is NOT due yet.
18/10/2015 14:47:52.73 - ONGOING-ISRUNNING-144730-306.TXT - *** Scheduled Daily graphing is NOT switched on.
18/10/2015 14:47:52.74 - ONGOING-ISRUNNING-144730-306.TXT - End of [HG612_stats.exe], Closing ERROR.LOG. Status = 1,
18/10/2015 14:47:52.75 - ONGOING-ISRUNNING-144730-306.TXT - ERROR.LOG successfully closed. Status = 0,
18/10/2015 14:47:52.76 - ONGOING-ISRUNNING-144730-306.TXT - total_sleep_time = 1.500 seconds
18/10/2015 14:47:52.77 - ONGOING-ISRUNNING-144730-306.TXT - Normal End of [HG612_stats.exe]
18/10/2015 14:47:52.81 - ONGOING-ISRUNNING-144730-306.TXT - End of [HG612_stats.exe] WebStats is NOT switched ON
 
I can't say i have noticed any delay in logging into the hg635.

Ian

[Bald_Eagle1]

Could you please change the modem type to HG635 in the ini file & try the attached version of HG612_stats.exe to see if we can get any further?

Again, sight of the log will be needed.

[kitzuser87430]

Thanks be; here is the latest error log.

Code: [Select]

18/10/2015 22:01:10.47 - ONGOING-ISRUNNING-220110-452.TXT - Start of [HG612_stats.exe] - **** Version 5.2.0.0 23/08/2015 ****
18/10/2015 22:01:10.57 - ONGOING-ISRUNNING-220110-452.TXT - Immediately after ini_parse() - About to determine the OS version. ERROR.LOG status = 0,
18/10/2015 22:01:10.58 - ONGOING-ISRUNNING-220110-452.TXT - *** Windows version = [6.2.9200] ***
18/10/2015 22:01:10.60 - ONGOING-ISRUNNING-220110-452.TXT - In [HG612_stats.exe] - After obtaining the OS version. ERROR.LOG status = 0,
18/10/2015 22:01:10.62 - ONGOING-ISRUNNING-220110-452.TXT - From ini file, Modem_type = HG635. Status = 0,
18/10/2015 22:01:10.64 - ONGOING-ISRUNNING-220110-452.TXT - ERROR.LOG successfully opened. Status = 1,
18/10/2015 22:01:10.67 - ONGOING-ISRUNNING-220110-452.TXT - **** From IsRunningVB.vbs, dslstatssampling.exe *IS* running 1 instances - seconds past the minute = 10
18/10/2015 22:01:23.48 - ONGOING-ISRUNNING-220110-452.TXT - **** Total time waited for dslstatssampling.exe = 12.50 seconds
18/10/2015 22:01:36.82 - ONGOING-ISRUNNING-220110-452.TXT - ONGOING-ISRUNNING-220110-452.TXT created. Status = 1,
18/10/2015 22:01:37.27 - ONGOING-ISRUNNING-220110-452.TXT - There are 1 instances of HG612_stats.exe running. Status = 1,
18/10/2015 22:01:37.28 - ONGOING-ISRUNNING-220110-452.TXT - Continuing as there are only 1 instances of HG612_stats.exe running **. Status = 1,
18/10/2015 22:01:37.30 - ONGOING-ISRUNNING-220110-452.TXT - WSAStartup() SUCCESSFUL!!! Status = 1,
18/10/2015 22:01:37.31 - ONGOING-ISRUNNING-220110-452.TXT - hg612ip = 10.10.11.245, HG612PORT = 23. Status = 1,
18/10/2015 22:01:37.32 - ONGOING-ISRUNNING-220110-452.TXT - getaddrinfo() O.K. Status = 1,
18/10/2015 22:01:37.33 - ONGOING-ISRUNNING-220110-452.TXT - socket() O.K. Status = 1,
18/10/2015 22:01:37.34 - ONGOING-ISRUNNING-220110-452.TXT - sockfd = 292, "res->ai_addrlen" = 16 connect() ERROR CODE = 0. Status = 1,
18/10/2015 22:01:37.36 - ONGOING-ISRUNNING-220110-452.TXT - connect() O.K. Status = 1,
 
18/10/2015 22:01:37.38 - ONGOING-ISRUNNING-220110-452.TXT - ********** About to use HG622/HG635 replynocr() code **********
18/10/2015 22:01:37.39 - ONGOING-ISRUNNING-220110-452.TXT - ********** The HG622/HG635 replynocr() code was accepted. Status = 1. **********
18/10/2015 22:01:37.40 - ONGOING-ISRUNNING-220110-452.TXT - *************************************************************************
18/10/2015 22:01:37.42 - ONGOING-ISRUNNING-220110-452.TXT - At start of expect("gin:"), times in loop = 01 *** numbytes = 0
18/10/2015 22:01:37.43 - ONGOING-ISRUNNING-220110-452.TXT - ****** PC_Speed is set as "FAST" in the ini file, times in loop = 01 *** numbytes = 0
18/10/2015 22:01:37.44 - ONGOING-ISRUNNING-220110-452.TXT - At start of expect("gin:"), sleeping for 0.500 seconds *** numbytes = 0
18/10/2015 22:01:37.96 - ONGOING-ISRUNNING-220110-452.TXT - numbytes received from recv(sockfd, rxbuf, RXBUFSIZE-1, 0) = 151
18/10/2015 22:01:37.97 - ONGOING-ISRUNNING-220110-452.TXT - End of expect("gin:")
18/10/2015 22:01:37.98 - ONGOING-ISRUNNING-220110-452.TXT - "gin:" WAS received
18/10/2015 22:01:37.99 - ONGOING-ISRUNNING-220110-452.TXT - *************************************************************************
18/10/2015 22:01:38.00 - ONGOING-ISRUNNING-220110-452.TXT - expect("gin:") O.K. Status = 1.
18/10/2015 22:01:38.01 - ONGOING-ISRUNNING-220110-452.TXT - reply(config.Username) O.K. Status = 1.
18/10/2015 22:01:38.03 - ONGOING-ISRUNNING-220110-452.TXT - Username from HG612_stats.ini = "**************". Status = 1.
18/10/2015 22:01:38.04 - ONGOING-ISRUNNING-220110-452.TXT - *************************************************************************
18/10/2015 22:01:38.05 - ONGOING-ISRUNNING-220110-452.TXT - At start of expect("ssword:"), times in loop = 01 *** numbytes = 0
18/10/2015 22:01:38.06 - ONGOING-ISRUNNING-220110-452.TXT - ****** PC_Speed is set as "FAST" in the ini file, times in loop = 01 *** numbytes = 0
18/10/2015 22:01:38.08 - ONGOING-ISRUNNING-220110-452.TXT - At start of expect("ssword:"), sleeping for 0.500 seconds *** numbytes = 0
18/10/2015 22:01:38.59 - ONGOING-ISRUNNING-220110-452.TXT - numbytes received from recv(sockfd, rxbuf, RXBUFSIZE-1, 0) = 15
18/10/2015 22:01:38.60 - ONGOING-ISRUNNING-220110-452.TXT - End of expect("ssword:")
18/10/2015 22:01:38.61 - ONGOING-ISRUNNING-220110-452.TXT - "ssword:" WAS received
18/10/2015 22:01:38.63 - ONGOING-ISRUNNING-220110-452.TXT - *************************************************************************
18/10/2015 22:01:38.64 - ONGOING-ISRUNNING-220110-452.TXT - expect("ssword:") O.K. Status = 1.
18/10/2015 22:01:38.65 - ONGOING-ISRUNNING-220110-452.TXT - reply(config.Password) O.K. Status = 1.
18/10/2015 22:01:38.66 - ONGOING-ISRUNNING-220110-452.TXT - Password from HG612_stats.ini = "**************". Status = 1.
18/10/2015 22:01:38.68 - ONGOING-ISRUNNING-220110-452.TXT - *************************************************************************
18/10/2015 22:01:38.69 - ONGOING-ISRUNNING-220110-452.TXT - At start of expect("ATP>"), times in loop = 01 *** numbytes = 0
18/10/2015 22:01:38.70 - ONGOING-ISRUNNING-220110-452.TXT - ****** PC_Speed is set as "FAST" in the ini file, times in loop = 01 *** numbytes = 0
18/10/2015 22:01:38.71 - ONGOING-ISRUNNING-220110-452.TXT - At start of expect("ATP>"), sleeping for 0.500 seconds *** numbytes = 0
18/10/2015 22:01:39.23 - ONGOING-ISRUNNING-220110-452.TXT - numbytes received from recv(sockfd, rxbuf, RXBUFSIZE-1, 0) = 6
18/10/2015 22:01:39.24 - ONGOING-ISRUNNING-220110-452.TXT - End of expect("ATP>")
18/10/2015 22:01:39.25 - ONGOING-ISRUNNING-220110-452.TXT - "ATP>" WAS received
18/10/2015 22:01:39.26 - ONGOING-ISRUNNING-220110-452.TXT - *************************************************************************
18/10/2015 22:01:39.28 - ONGOING-ISRUNNING-220110-452.TXT - expect("ATP>") O.K. Status = 1.
18/10/2015 22:01:39.29 - ONGOING-ISRUNNING-220110-452.TXT - **** reply(config.Shell) O.K. Status = 1.
18/10/2015 22:01:39.30 - ONGOING-ISRUNNING-220110-452.TXT - *************************************************************************
18/10/2015 22:01:39.31 - ONGOING-ISRUNNING-220110-452.TXT - At start of expect("$ "), times in loop = 01 *** numbytes = 0
18/10/2015 22:01:39.32 - ONGOING-ISRUNNING-220110-452.TXT - ****** PC_Speed is set as "FAST" in the ini file, times in loop = 01 *** numbytes = 0
18/10/2015 22:01:39.34 - ONGOING-ISRUNNING-220110-452.TXT - At start of expect("$ "), sleeping for 0.500 seconds *** numbytes = 0
18/10/2015 22:01:39.85 - ONGOING-ISRUNNING-220110-452.TXT - numbytes received from recv(sockfd, rxbuf, RXBUFSIZE-1, 0) = 100
18/10/2015 22:01:39.86 - ONGOING-ISRUNNING-220110-452.TXT - End of expect("$ ")
18/10/2015 22:01:39.90 - ONGOING-ISRUNNING-220110-452.TXT - "$ " WAS received
18/10/2015 22:01:39.91 - ONGOING-ISRUNNING-220110-452.TXT - *************************************************************************
18/10/2015 22:01:39.92 - ONGOING-ISRUNNING-220110-452.TXT - The prompt "$ " *WAS* received. Sleeping for 0.100 seconds. Status = 1,
18/10/2015 22:01:40.03 - ONGOING-ISRUNNING-220110-452.TXT - Reaching this point means logging in to the modem was successful. Status = 1,
18/10/2015 22:01:40.05 - ONGOING-ISRUNNING-220110-452.TXT - reply(xdslcmd info --stats) O.K. Status = 1, return value = 0
18/10/2015 22:01:40.06 - ONGOING-ISRUNNING-220110-452.TXT - **** At start of get_data("xdslcmd info --stats")
18/10/2015 22:01:40.07 - ONGOING-ISRUNNING-220110-452.TXT - In get_data(#01). *** This was included in data received:- xdslcmd info --stats - (numbyes = 1956, index = 1956)

I had to kill hg612_stats.exe; it did not gracefully close after a few mins.

[Bald_Eagle1]

So, it looks like it is logging in correctly now.

Could you please post a copy of all the output from the xdslcmd info --stats command for me to examine?

It seems as though I need to adjust something when parsing the raw data & the preparation for storing it in the ongoing modem_stats.log file.

It's possible that a file named xlogfile.txt was created in the Ongoing_Stats folder that should contain the raw data.

I do have an older copy of this file from your connection for comparison purposes from when you were using the HG612 in May 2014.

[kitzuser87430]

OK

Code: [Select]

$ xdslcmd info --stats
xdslcmd: ADSL driver and PHY status
Status: Showtime
Retrain Reason: 1
Max:    Upstream rate = 932 Kbps, Downstream rate = 7324 Kbps
Channel:        Interleaved, Upstream rate = 768 Kbps, Downstream rate = 7040 Kbps

Link Power State:       L0
Mode:                   G.DMT
StandardUsed:           G.992.1_Annex_B
TPS-TC:                 ATM Mode
Trellis:                ON
Line Status:            No Defect
Training Status:        Showtime
                Down            Up
SNR (dB):        5.1             6.0
Attn(dB):        46.0            27.0
Pwr(dBm):        20.0            12.5
                        G.dmt framing
K:              221(0)          25
R:              16              16
S:              1               8
D:              32              4
                        Counters
                        Path 0
SF:             88355567                88371594
SFErr:          6983            607
RS:             88355567                88371594
RSCorr:         9258659         15761
RSUnCorr:       142469          0
LinkRetrain:    0
InitErrors:     0
InitTimeouts:   0
LossOfFraming:  0

                        Path 0
HEC:            138370          557
OCD:            105             0
LCD:            105             0
Total Cells:    3464729223              0
Data Cells:     565199423               0
Drop Cells:     0
Bit Errors:     9950039         0

ES:             5902            0
SES:            352             0
UAS:            104             104
AS:             1502319

                        Path 0
INP:            1.08            1.18
PER:            1.75            1.75
delay:          8.00            8.00
OR:             32.00           32.00

Bitswap:        267526          118

UPBOkle:        7738
actualCE:       0
SNRmode:        0
AtucPhys SNRmode:       0
Total time = 1 days 9 hours 26 min 55 sec
FEC:            17588952                0
CRC:            28837           0
ES:             5902            0
SES:            352             0
UAS:            104             104
LOS:            3               0
LOF:            17              0
Latest 15 minutes time = 11 min 55 sec
FEC:            559             0
CRC:            0               0
ES:             0               0
SES:            0               0
UAS:            0               0
LOS:            0               0
LOF:            0               0
Previous 15 minutes time = 15 min 0 sec
FEC:            658             0
CRC:            4               0
ES:             3               0
SES:            0               0
UAS:            0               0
LOS:            0               0
LOF:            0               0
Latest 1 day time = 9 hours 26 min 55 sec
FEC:            37597           0
CRC:            104             0
ES:             42              0
SES:            0               0
UAS:            0               0
LOS:            0               0
LOF:            0               0
Previous 1 day time = 24 hours 0 sec
FEC:            937427          0
CRC:            470             0
ES:             173             0
SES:            5               0
UAS:            0               0
LOS:            0               0
LOF:            0               0
Since Link time = 17 days 9 hours 18 min 37 sec
FEC:            9258659         15761
CRC:            6983            607
ES:             2624            0
SES:            56              0
UAS:            0               0
LOS:            0               0
LOF:            0               0
$

The Ongoing_Stats folder is empty.

[Bald_Eagle1]

That's quite a bit different to what I was expecting.

The first step now though is to get the program to at least store the raw data in the xlogfile.txt file.


I have added a bit of code for the HG635 & other modems that use the '$' symbol as the prompt.
Could you please try the attached version & let me know how you get on?

If the xlogfile.txt is created, could you please post it, even if you ended up having to kill HG612_stats.exe



If you wish to make this process of gradual elimination easier/quicker by doing it via email, please PM your email address to me.

[kitzuser87430]

PM sent...

xlogfile attached, had to kill hg612_stats.

[Bald_Eagle1]

Thanks Ian,

I might be a while working things out, but I now have enough data to work with for now.

[Bald_Eagle1]

Update:

I think I now have a version that will work with a HG635 on your G.DMT connection.

I have sent a couple of emails to you, one of which has the test version 5.0.0.2 attached.