| Index | Recent Threads | Unanswered Threads | Who's Active | Guidelines | Search |
| World Community Grid Forums
|
| No member browsing this thread |
|
Thread Status: Active Total posts in this thread: 19
|
|
| Author |
|
|
SekeRob
Master Cruncher Joined: Jan 7, 2013 Post Count: 2741 Status: Offline |
Maybe the increased results-live has had performance impact. Amongst various Result API users, the observation is, that 24 hours after valid has elongated to 48 hours+, and even see a result time that got validated and archived my side on June 20, of regular projects, how regular can FAHV be.
Here's a sample of July 4, validated on the 4th of July, no modtyime changes, and it is just sitting there, not wanting to be archived again as it already was. FAHV_1002688_3j3y-7P-P1_Rigid_3817_2 268426 1589755586 fahv Valid 40.80 1.0766 0:01:04:36 1.2442 0 22.19 20.61 86.53% 3986046 1499136113 1 17-07-03 19:43:41 17-07-13 18:23:51 17-07-03 18:23:51 1 17-07-04 02:41:53 (Last ModTime) If the case, time to say goodbye to any straggler copy and give them the "no longer usable" message, but something has caused it to remain there. |
||
|
|
SekeRob
Master Cruncher Joined: Jan 7, 2013 Post Count: 2741 Status: Offline |
Edit: No the final test went into Debug mode at 09:44 UTC: Runtime error '-2147217376 (80041020)': XML Parse Error Some more research of the particular office error, the url send with member name and account key code is expected to take care of the credential checks. This is done every page offset call. It is suggested that your credential checker might not be having or lost the Usain Bolt genomics. "I have found that I get this error when Excel is unable to log into the webpage. The only solution I have found is to browse to the location in Internet Explorer, enter my credentials, and tell Internet Explorer to remember my login. This will work for some time until cookies expire or something and I go and login again." No idea if cookies are involved, hard to believe, but to be sure, have visited IE in a shell to Excel as parent and cleared out history and cookies. The morning verification run spat out 5 beeps on 1095 x250 fetches, precise 263,216 results estimated at start of run (see previous post about the coding-around solution). |
||
|
|
knreed
Former World Community Grid Tech Joined: Nov 8, 2004 Post Count: 4504 Status: Offline Project Badges:
|
Can you add a mechanism to your script that logs the how long it takes to a receive a response to each API call and the start time and end time of the call? I'm testing right now using the IBM account and I am getting a response within 5-6 seconds without any error.
If I can get that log then, I can take a look at what other activity might be going on with the database at that time that might be causing an issue. I'm also curious if there might be a time out that we can simply extend that will allow your queries to complete. The data I asked for will be helpful in figuring that out. |
||
|
|
SekeRob
Master Cruncher Joined: Jan 7, 2013 Post Count: 2741 Status: Offline |
2 lines added just before and after the
----------------------------------------Debug.print "Before page fetch " & I & " @ " & Now() WB.XmlMaps("ResultsStatus_Map1").Import Url:=rURL & pagesz * (I - 1) & sssb, overwrite:=overwrt Debug.print "After page fetch: " & I & " @ " & Now() The output goes to the immediate watch window. The last round post midday stats had 1008 effective calls in 1:00:14 hours, but that's with about 20 minutes post processing, so 40 minutes 2400 seconds for 1008 is 2.4 seconds per fetch of 250 records. On a good day, do 60-70 page fetches per minute from my outback hill. It's like there's a gate opener, and then the door being slammed after N seconds, to then having to renegotiate for the gate to be reopened. Log for 1720 records against my personal account, with testing snail code: Before page fetch 1 @ 12-7-2017 17:55:00 After page fetch: 1 @ 12-7-2017 17:55:01 Before page fetch 2 @ 12-7-2017 17:55:01 After page fetch: 2 @ 12-7-2017 17:55:03 Before page fetch 3 @ 12-7-2017 17:55:03 After page fetch: 3 @ 12-7-2017 17:55:05 Before page fetch 4 @ 12-7-2017 17:55:05 After page fetch: 4 @ 12-7-2017 17:55:07 Before page fetch 5 @ 12-7-2017 17:55:07 After page fetch: 5 @ 12-7-2017 17:55:08 Before page fetch 6 @ 12-7-2017 17:55:08 After page fetch: 6 @ 12-7-2017 17:55:10 Before page fetch 7 @ 12-7-2017 17:55:10 After page fetch: 7 @ 12-7-2017 17:55:12 The overwrite=overwrt var takes care of initial Overwrite=True, which is actually much quicker than the Overwrite=False, which appends data on the fly to the table from pass 2, hence the first url injection taking 1 second to complete, return, write and report timestamp after, the remainder on a 2 second roundtrip. Edit: Times UTC + 2 hours. Dont think you'll be any the wiser without the actual problem cropping up, i.e. I'll keep the debug entries going and post again should this occur again... it will. [Edit 1 times, last edit by SekeRob* at Jul 12, 2017 4:19:22 PM] |
||
|
|
SekeRob
Master Cruncher Joined: Jan 7, 2013 Post Count: 2741 Status: Offline |
Of course, the immediate watch window has a limited buffer (200 lines)... need to 'watch' it, so went to learn a new trick to also output (write) the entries to a log file which generated this abbreviated set
"Before page fetch 1 @ 12-7-2017 20:20:43 (UTC + 2 hours)" "After page fetch: 1 @ 12-7-2017 20:20:44 (UTC + 2 hours)" "Before page fetch 2 @ 12-7-2017 20:20:44 (UTC + 2 hours)" "After page fetch: 2 @ 12-7-2017 20:20:46 (UTC + 2 hours)" "Before page fetch 3 @ 12-7-2017 20:20:46 (UTC + 2 hours)" "After page fetch: 3 @ 12-7-2017 20:20:48 (UTC + 2 hours)" "Before page fetch 4 @ 12-7-2017 20:20:48 (UTC + 2 hours)" "After page fetch: 4 @ 12-7-2017 20:20:50 (UTC + 2 hours)" "Before page fetch 5 @ 12-7-2017 20:20:50 (UTC + 2 hours)" "After page fetch: 5 @ 12-7-2017 20:20:52 (UTC + 2 hours)" "Before page fetch 6 @ 12-7-2017 20:20:52 (UTC + 2 hours)" "After page fetch: 6 @ 12-7-2017 20:20:54 (UTC + 2 hours)" "Before page fetch 7 @ 12-7-2017 20:20:54 (UTC + 2 hours)" "After page fetch: 7 @ 12-7-2017 20:20:55 (UTC + 2 hours)" Of course there had to be a fail fail at page 1 of course Before retry page fetch 1 @ 12-7-2017 20:06:41 After which the script popped the debug window, no entry after close. Will collect a few runs and email them if anything untowards shows up. |
||
|
|
SekeRob
Master Cruncher Joined: Jan 7, 2013 Post Count: 2741 Status: Offline |
Two page 1 stalls this morning, but after that it was sailing through, except page 743 which took 5.78 seconds and a few 4 second entries, noting that last night there seems to have been a major migration... over 300 pages less this morning run.
After page fetch: 718 @ 13-7-2017 08:59:27 (UTC + 2 hours)took 3,47222230629995E-05 After page fetch: 719 @ 13-7-2017 08:59:30 (UTC + 2 hours)took 3,47222230629995E-05 After page fetch: 720 @ 13-7-2017 08:59:32 (UTC + 2 hours)took 2,31481462833472E-05 After page fetch: 721 @ 13-7-2017 08:59:35 (UTC + 2 hours)took 3,47222230629995E-05 After page fetch: 722 @ 13-7-2017 08:59:38 (UTC + 2 hours)took 3,47222230629995E-05 After page fetch: 723 @ 13-7-2017 08:59:41 (UTC + 2 hours)took 3,47222230629995E-05 After page fetch: 724 @ 13-7-2017 08:59:43 (UTC + 2 hours)took 2,31481462833472E-05 After page fetch: 725 @ 13-7-2017 08:59:46 (UTC + 2 hours)took 3,47222230629995E-05 After page fetch: 726 @ 13-7-2017 08:59:48 (UTC + 2 hours)took 2,31481462833472E-05 After page fetch: 727 @ 13-7-2017 08:59:51 (UTC + 2 hours)took 2,31481462833472E-05 After page fetch: 728 @ 13-7-2017 08:59:54 (UTC + 2 hours)took 3,47222230629995E-05 After page fetch: 729 @ 13-7-2017 08:59:57 (UTC + 2 hours)took 3,47222230629995E-05 After page fetch: 730 @ 13-7-2017 08:59:59 (UTC + 2 hours)took 2,31481462833472E-05 After page fetch: 731 @ 13-7-2017 09:00:02 (UTC + 2 hours)took 3,47222230629995E-05 After page fetch: 732 @ 13-7-2017 09:00:05 (UTC + 2 hours)took 3,47222230629995E-05 After page fetch: 733 @ 13-7-2017 09:00:08 (UTC + 2 hours)took 3,47222230629995E-05 After page fetch: 734 @ 13-7-2017 09:00:11 (UTC + 2 hours)took 3,47222230629995E-05 After page fetch: 735 @ 13-7-2017 09:00:14 (UTC + 2 hours)took 3,47222230629995E-05 After page fetch: 736 @ 13-7-2017 09:00:17 (UTC + 2 hours)took 3,47222230629995E-05 After page fetch: 737 @ 13-7-2017 09:00:20 (UTC + 2 hours)took 3,47222230629995E-05 After page fetch: 738 @ 13-7-2017 09:00:22 (UTC + 2 hours)took 2,31481462833472E-05 After page fetch: 739 @ 13-7-2017 09:00:25 (UTC + 2 hours)took 3,47222230629995E-05 After page fetch: 740 @ 13-7-2017 09:00:28 (UTC + 2 hours)took 2,31481535593048E-05 After page fetch: 741 @ 13-7-2017 09:00:31 (UTC + 2 hours)took 3,47222157870419E-05 After page fetch: 742 @ 13-7-2017 09:00:33 (UTC + 2 hours)took 2,31481535593048E-05 After page fetch: 743 @ 13-7-2017 09:00:38 (UTC + 2 hours)took 5,78703693463467E-05 After page fetch: 744 @ 13-7-2017 09:00:40 (UTC + 2 hours)took 2,31481462833472E-05 After page fetch: 745 @ 13-7-2017 09:00:43 (UTC + 2 hours)took 2,31481462833472E-05 After page fetch: 746 @ 13-7-2017 09:00:46 (UTC + 2 hours)took 3,47222230629995E-05 After page fetch: 747 @ 13-7-2017 09:00:49 (UTC + 2 hours)took 3,47222230629995E-05 After page fetch: 748 @ 13-7-2017 09:00:51 (UTC + 2 hours)took 2,31481462833472E-05 After page fetch: 749 @ 13-7-2017 09:00:55 (UTC + 2 hours)took 4,62962998426519E-05 After page fetch: 750 @ 13-7-2017 09:00:58 (UTC + 2 hours)took 3,47222157870419E-05 After page fetch: 751 @ 13-7-2017 09:01:01 (UTC + 2 hours)took 3,47222230629995E-05 After page fetch: 752 @ 13-7-2017 09:01:04 (UTC + 2 hours)took 3,47222230629995E-05 After page fetch: 753 @ 13-7-2017 09:01:07 (UTC + 2 hours)took 3,47222230629995E-05 After page fetch: 754 @ 13-7-2017 09:01:10 (UTC + 2 hours)took 3,47222230629995E-05 After page fetch: 755 @ 13-7-2017 09:01:13 (UTC + 2 hours)took 3,47222230629995E-05 After page fetch: 756 @ 13-7-2017 09:01:16 (UTC + 2 hours)took 3,47222230629995E-05 After page fetch: 757 @ 13-7-2017 09:01:19 (UTC + 2 hours)took 3,47222230629995E-05 After page fetch: 758 @ 13-7-2017 09:01:22 (UTC + 2 hours)took 2,31481535593048E-05 After page fetch: 759 @ 13-7-2017 09:01:25 (UTC + 2 hours)took 3,47222157870419E-05 After page fetch: 760 @ 13-7-2017 09:01:28 (UTC + 2 hours)took 3,47222230629995E-05 After page fetch: 761 @ 13-7-2017 09:01:31 (UTC + 2 hours)took 3,47222230629995E-05 After page fetch: 762 @ 13-7-2017 09:01:33 (UTC + 2 hours)took 2,31481462833472E-05 After page fetch: 763 @ 13-7-2017 09:01:36 (UTC + 2 hours)took 3,47222230629995E-05 After page fetch: 764 @ 13-7-2017 09:01:39 (UTC + 2 hours)took 3,47222230629995E-05 After page fetch: 765 @ 13-7-2017 09:01:42 (UTC + 2 hours)took 3,47222230629995E-05 After page fetch: 766 @ 13-7-2017 09:01:46 (UTC + 2 hours)took 4,62962998426519E-05 After page fetch: 767 @ 13-7-2017 09:01:49 (UTC + 2 hours)took 3,47222157870419E-05 After page fetch: 768 @ 13-7-2017 09:01:52 (UTC + 2 hours)took 3,47222230629995E-05 After page fetch: 769 @ 13-7-2017 09:01:54 (UTC + 2 hours)took 2,31481535593048E-05 After page fetch: 770 @ 13-7-2017 09:01:57 (UTC + 2 hours)took 2,31481462833472E-05 After page fetch: 771 @ 13-7-2017 09:01:59 (UTC + 2 hours)took 2,31481535593048E-05 A slightly improved log version formatting the seconds, to 6 decimal (dont ask why it produces comma decimal when the environment is set to dot decimal) Before page fetch 1 @ 13-7-2017 09:03:26 (UTC + 2 hours) After page fetch: 1 @ 13-7-2017 09:03:27 (UTC + 2 hours) took 1,0000002 Sec. Before page fetch 2 @ 13-7-2017 09:03:27 (UTC + 2 hours) After page fetch: 2 @ 13-7-2017 09:03:29 (UTC + 2 hours) took 1,9999998 Sec. Before page fetch 3 @ 13-7-2017 09:03:29 (UTC + 2 hours) After page fetch: 3 @ 13-7-2017 09:03:32 (UTC + 2 hours) took 3,0000001 Sec. Before page fetch 4 @ 13-7-2017 09:03:32 (UTC + 2 hours) After page fetch: 4 @ 13-7-2017 09:03:34 (UTC + 2 hours) took 1,9999998 Sec. Before page fetch 5 @ 13-7-2017 09:03:34 (UTC + 2 hours) After page fetch: 5 @ 13-7-2017 09:03:36 (UTC + 2 hours) took 2,0000005 Sec. Before page fetch 6 @ 13-7-2017 09:03:36 (UTC + 2 hours) After page fetch: 6 @ 13-7-2017 09:03:39 (UTC + 2 hours) took 3,0000001 Sec. Before page fetch 7 @ 13-7-2017 09:03:39 (UTC + 2 hours) After page fetch: 7 @ 13-7-2017 09:03:41 (UTC + 2 hours) took 1,9999998 Sec. Before page fetch 8 @ 13-7-2017 09:03:41 (UTC + 2 hours) After page fetch: 8 @ 13-7-2017 09:03:42 (UTC + 2 hours) took 0,9999996 Sec. Before page fetch 1 @ 13-7-2017 09:13:40 (UTC + 2 hours) After page fetch: 1 @ 13-7-2017 09:13:41 (UTC + 2 hours) took 1,0000002 Sec. Before page fetch 2 @ 13-7-2017 09:13:41 (UTC + 2 hours) After page fetch: 2 @ 13-7-2017 09:13:43 (UTC + 2 hours) took 1,9999998 Sec. Before page fetch 3 @ 13-7-2017 09:13:43 (UTC + 2 hours) After page fetch: 3 @ 13-7-2017 09:13:45 (UTC + 2 hours) took 1,9999998 Sec. Before page fetch 4 @ 13-7-2017 09:13:45 (UTC + 2 hours) After page fetch: 4 @ 13-7-2017 09:13:47 (UTC + 2 hours) took 1,9999998 Sec. Before page fetch 5 @ 13-7-2017 09:13:47 (UTC + 2 hours) After page fetch: 5 @ 13-7-2017 09:13:49 (UTC + 2 hours) took 2,0000005 Sec. Before page fetch 6 @ 13-7-2017 09:13:49 (UTC + 2 hours) After page fetch: 6 @ 13-7-2017 09:13:51 (UTC + 2 hours) took 1,9999998 Sec. Before page fetch 7 @ 13-7-2017 09:13:51 (UTC + 2 hours) After page fetch: 7 @ 13-7-2017 09:13:52 (UTC + 2 hours) took 1,0000002 Sec. Before page fetch 8 @ 13-7-2017 09:13:52 (UTC + 2 hours) After page fetch: 8 @ 13-7-2017 09:13:53 (UTC + 2 hours) took 0,9999996 Sec. There's no juice here. Will get back when issues repeats again. Long as it runs through unattended, a few seconds here or there are least of the worry. |
||
|
|
knreed
Former World Community Grid Tech Joined: Nov 8, 2004 Post Count: 4504 Status: Offline Project Badges:
|
Any chance that you could also capture the text of the website response in the cases where the popup is triggered?
|
||
|
|
SekeRob
Master Cruncher Joined: Jan 7, 2013 Post Count: 2741 Status: Offline |
Any chance that you could also capture the text of the website response in the cases where the popup is triggered? All I'm getting is those numbers -2147... The accessing of the intertubes is invisible at this time, would have to study if the web response itself can be captured. Meantime the US is awake and it now being near standard that the first page gets a slap in the face during US office hours. Is there another 9600 bps console bottlenecking? Now set to always log, a file then being created of Logbook memname yymmdd hhmm. The latest: If the initial connect fails, there's a 30 second programmed wait. Given the Before page fetcch and Before retry page fetch was 41 seconds, it seems for the timeout to occur 10 seconds have to pass, then all it took was 1 second to turn around the 250 lines and write that to the excel table. "Before page fetch 1 @ 13-7-2017 17:51:40 (UTC + 2 hours)" "Before retry page fetch 1 @ 13-7-2017 17:52:31 (UTC + 2 hours)" "After retry page fetch 1 @ 13-7-2017 17:52:32 (UTC + 2 hours) took 1,0000002 Sec." "Before page fetch 2 @ 13-7-2017 17:52:32 (UTC + 2 hours)" "After page fetch: 2 @ 13-7-2017 17:52:34 (UTC + 2 hours) took 1,9999998 Sec." "Before page fetch 3 @ 13-7-2017 17:52:34 (UTC + 2 hours)" "After page fetch: 3 @ 13-7-2017 17:52:36 (UTC + 2 hours) took 1,9999998 Sec." "Before page fetch 4 @ 13-7-2017 17:52:36 (UTC + 2 hours)" "After page fetch: 4 @ 13-7-2017 17:52:38 (UTC + 2 hours) took 1,9999998 Sec." "Before page fetch 5 @ 13-7-2017 17:52:38 (UTC + 2 hours)" "After page fetch: 5 @ 13-7-2017 17:52:40 (UTC + 2 hours) took 2,0000005 Sec." "Before page fetch 6 @ 13-7-2017 17:52:40 (UTC + 2 hours)" "After page fetch: 6 @ 13-7-2017 17:52:41 (UTC + 2 hours) took 0,9999996 Sec." "Before page fetch 7 @ 13-7-2017 17:52:41 (UTC + 2 hours)" "After page fetch: 7 @ 13-7-2017 17:52:43 (UTC + 2 hours) took 1,9999998 Sec." "Before page fetch 8 @ 13-7-2017 17:52:43 (UTC + 2 hours)" "After page fetch: 8 @ 13-7-2017 17:52:44 (UTC + 2 hours) took 1,0000002 Sec." The retry uses the same url https://www.worldcommunitygrid.org/api/member...me&Modtime=1498671859 When pasting the URL into IE 11, with the Developer console open periodically this shows up, where the debugger frame just shows the same as the standard xml response. DOM7011: The code on this page disabled back and forward caching. For more information, see: http://go.microsoft.com/fwlink/?LinkID=291337 File: results HTML1300: Navigation occurred. File: results SEC7111: HTTPS security is compromised by res://mshtml.dll/xmltreeview.js view-source:https://www.worldcommunitygrid.org/api/member...me&Modtime=1498671859 FireFox has practically the identical developer/debug tools, former actually referring to chrome tools. Which reminds me, anytime I try to post/edit, I get a redirect pop-up on the WCG forums, and whether I want to allow that. [Edit 1 times, last edit by SekeRob* at Jul 13, 2017 4:52:45 PM] |
||
|
|
SekeRob
Master Cruncher Joined: Jan 7, 2013 Post Count: 2741 Status: Offline |
A Sunday, high noon run log excerpt...
"Before page fetch 1 @ 16-7-2017 14:06:19 (UTC + 2 hours)" ... ... "After page fetch: 390 @ 16-7-2017 14:16:29 (UTC + 2 hours) Took 1,0000002 Sec." "Done @16-7-2017 14:16:29 (UTC + 2 hours) for 97466 Results received" That's an average return time of 1.56 seconds, with a filter set to FileDeleteState=0 . Truly haven't seen it as fast as this against the big member account. Consider it had 168 new results in the 6 minute spilltime after the midnight cut-off and only 1 actual miss that was netted during the coffee time period close run. Using the ReceivedTime as sort key essentially gave an estimated set of 200-250 results that were fetched twice [due shifting previously returned results down the fetch list whilst new come in]. This does not bother, as these are eliminated in post processing uniquedatalist step (on ResultId). Picture this: Doing the call, get 250 records written into transition area, copy, paste as append to the data table, clear transition area in 1.56 seconds, and that sustained for 10 minutes, never a hickup, ever incrementing the offset by 250. Pretty impressive. |
||
|
|
|