Feature - Implemented Relogging to improve ping

[MCroft]

I am also unsure what the correct behavior should be, but perhaps a wording change would help.

buf.append(" Press 'Yes' if you are satisfied with the current connection.");
    buf.append(" Press 'No' to log out and back in to try for a better connection.");
    buf.append(" Press 'Cancel' to do neither; you will automatically reconnect when you make a server request.");

 

[Veracity]

Press 'Cancel' to log out.

(If you are seeing this dialog from the Login Frame, that will obviously mean "try to log in again". If you are timing in - either because KoL silently timed you out or you used a "timein" command - and rejected the ping test on the timein, you still have the GUI and are logged out.

 

[fronobulax]

Built and ran 27452.

I didn't like the ping and so said No several times. I finally said Yes and it appears my login script was being run several times.

 

[MCroft]

Putting on the testing cap:
1: How does this work for headless users? Do they get a popup, or do they get a dialog, and can they set a default?

2: What happens if the GUI pops up and I leave it long enough to timeout again and then say (yes/no/cancel)?
tests:
no: fine. connects again and works.
yes: fine, but it's maybe not using the ping we tested.
cancel: no different than current: you are in the gui, timed out.

I wonder if this should have a timeout, e.g. after 30 seconds, assume yes.

 

[Veracity]

Putting on the testing cap:
1: How does this work for headless users? Do they get a popup, or do they get a dialog, and can they set a default?

Headless users get a question. They can type y, n, or return to get yes/no/cancel.
They can set pingLogin to false to skip the test.
Eventually, there will be a setting for how to automate login, and thereby have the tests but skip the dialogue.

2: What happens if the GUI pops up and I leave it long enough to timeout again and then say (yes/no/cancel)?
tests:
no: fine. connects again and works.
yes: fine, but it's maybe not using the ping we tested.
cancel: no different than current: you are in the gui, timed out.

I wonder if this should have a timeout, e.g. after 30 seconds, assume yes.

How long does it take for Kol to time out? 15 minutes?

Interesting question. Yes assumes you are logged in. If you are not, presumably we timein the very first request that redirects back to login.php. I’ll have to try that.

 

[Veracity]

Built and ran 27452.

I didn't like the ping and so said No several times. I finally said Yes and it appears my login script was being run several times.

Interesting.

Well, I want to refactor such that doing up to N ping tests and dialogs can be automated and only results in the top level login proceeding to login and timeout.

Currently, I brlieve that only the deepest is doing that - and I have seen no evidence of multiple login/timein sequences executing - so I have no idea how your observation happens.

But I will fix it.

 

[gausie]

Just a quick note that I ran this solution by CDM and he is happy with us doing it. The current state of KoL code makes it impossible for them to distribute servers well once a client has logged in so this is going to happen until they do a big (and planned, sort of) refactor of the session-handling code.

 

[Veracity]

This PR does almost everything else I had planned:

automate login ping tests by Veracity0 · Pull Request #1813 · kolmafia/kolmafia

Count ping test attempts when you are logging it. If you get an acceptable ping test on attempt N, only complete login/timein when you unwind back to attempt 1. When timing in to try for a better c...

github.com

1. Count ping test attempts when you are logging in.
   If you get an acceptable ping test on attempt N, only complete login/timein when you unwind back to attempt 1.
2. When timing in to try for a better connection, via timein command or equivalent, only issue logout request if you are currently logged in.
3. When you log in for the first time, if you are in stealth mode (/q), remove that for the purpose of saving setting actual user name and reading Preferences, as alway.
   If you did NOT log in with /q, add that to the name field of the LoginRequest, so that all subsequent timeins are done in stealth mode.
4. When doing a ping test at login, if it you got redirected away from api.php (afterlife.php, for example), do not compare the measured ping time with saved historical ping times, which are only api.php.
5. Add 2 new properties:

• pingLoginCount (defaults to 0) the number of times you are willing to let KoLmafia automatically retry ping tests, looking for a successful goal or threshold average. If 0, no automation; a failed test will pop up the usual yes/no/cancel dialog asking if you want to accept, retry, or bail.
• pingLoginFail - logout or login - the action taken if we cannot get a successfull average ping time after pingLoginCount attempts have been made. login means "accept it and remain logged in". logout means "log out in despair" and try again when you timein.

1. These properties are configurable on the Connection Options panel in both the Login Frame and Preferences/General
2. In preferences, that panel has two more lines:
   Latest ping test average time was 35 msec.
   (That auto-updates each time you execute a ping test - when attempting to timein, for example.)
   Try for a better connection: [Time In]
   (Press the button to logout (if needed) and time in, using all the options as configured above.

 

[fronobulax]

I built and ran with this. Login script running multiple times has been addressed. Thank you.

I am not sure /q is working as expected if I understand the expectations. Three characters, all on each other's contact list so there are messages about activities. Logged in with each one without /q requested by me. Each one had high pings and was allowed to retry. First character logged in. Second character logs in. First character gets messages about second logging in. Third character logs in. First and second character get messages about third logging in. Timestamps as expected for logins within a ten minute period - these were not obviously messages from yesterday.

I am fine with the behavior as is but since it doesn't match what I thought was expected I will comment (and probably get my expectations corrected)

 

[Veracity]

Yeah. It looks like setting /q occurs iff the property is set.
I'll see what I can do.

Edit: I updated the PR and it seems to do the right thing now.

 

[Veracity]

Revision r27454 has all of that.

The only remaining work I see from above is adding some RuntimeFunctions to do pingy stuff

PingTest ping(string page, int count)
PingTest ping() - uses the "default" page and count - "api.php" and 10 - for a ping that affects historical properties
PingTest ping(string property) - "pingLatest", "pingShortest", or "pingLongest"

PingTest will be an anonymous record with all the stats.
We do this for other RuntimeFunctions, too.

I'm not completely sure how the program handles this. Define a record identical to the one we return?
Would be nice - and pretty easy - if we had a "var" type.
In any case, improving support for anonymous records will come in subsequent PRs.

This project is SO close to being implemented...

 

[Veracity]

I added those RuntimeLibrary functions:

record PingTest
{
    string page;
    int count;
    int low;
    int high;
    int total;
    int bytes;
    int average;
    int bps;
};

PingTest result0 = ping();
PingTest result1 = ping("pingLatest");
PingTest result2 = ping(100, "api.php");

Unfortunately, ASH today, will not allow that (although JS will).

> get pingLatest

api.php:10:24:29:271:19620:27

> ash ping("pingLatest")

Returned: record {string page; int count; int low; int high; int total; int bytes; int average; int bps;}
page => api.php
count => 10
low => 24
high => 29
total => 271
bytes => 19620
average => 27
bps => 72398

> js ping("pingLatest")

Returned: aggregate string [string]
average => 27
bps => 72398
bytes => 19620
count => 10
high => 29
low => 24
page => api.php
total => 271

As you can see, the function returns a record with the expected fields, but ASH will not let you save it in a named record with the identical structure. I have a bug report and a fix to ASH coded up, ready for a PR, after I write some tests.

Modulo the ASH fix, I believe this project is complete.

Unless there are more feedback/suggestions/bug reports.

 

[Shiverwarp]

Interestingly api.php ping does not seem to correlate to my actual performance in game, council.php does however.

This may just be that hitting api.php is quicker so it's harder to notice a bad server

 

[Veracity]

Got any metrics? It should be easy enough to convert your perceived “actual performance in game” into numerical data.

When “performance” seems slow, do “ping 100 api.php” and “ping 100 council.php” and save the results.

When “performance” seems fast, ditto.

Lets see some actual data.

Thanks.

 

[fronobulax]

I ran today with /q not specified by me. All of the characters rejected one or more login times.

When all three had logged in:

The first had a message that the second had logged in and had logged out.
The first had a message that the third had logged in and had logged out.
The second had a message that the third had logged in and had logged out.

Before this work I would have expected:

The first had a message that the second had logged in.
The first had a message that the third had logged in.
The second had a message that the third had logged in.

 

[Veracity]

Logged in via the Login Frame? And by “/q not specified by me”, you mean the “Stealth Login” checkbox was unchecked, right?

 

[Veracity]

OK, I now understand how stealth login used to work.

1) If you login without /q, your contacts will be alerted. When you log out, they will be alerted again.
2) If you login with /q, your contacts will not be alerted. When you log out, they will still not be alerted.
3) As coded, KoLmafia stripped off and ignored whether or not you actually typed /q; the ONLY thing that affected whether it was added to your username when requesting login.php was the preference checkbox on the Login Frame.
4) That includes logging in via the cli with the “login” command. You started up with -CLI and typed “login name/q” and thought that was a stealth login? Unless the checkbox on the Login Frame was checked, nope. You typed “login name” and thought that was NOT a stealth login? If the checkbox was checked last time you were on the Login Frame, too bad. Stealthy you are.

In any case, points 1 and 2 mean it is useless to try to make time-ins stealthy, whether or not your initial login was not stealthy; your contacts will be alerted the first time you log out and will not be alerted for any subsequent login/logout in the session.

I’m inclined to just give up on trying to rationalize that. Your contacts will just have to see a flurry of login/logout/login messages as you try for a better connection.

 

[Shiverwarp]

Got any metrics? It should be easy enough to convert your perceived “actual performance in game” into numerical data.

When “performance” seems slow, do “ping 100 api.php” and “ping 100 council.php” and save the results.

When “performance” seems fast, ditto.

Lets see some actual data.

Thanks.

On an "okay-to-bad" performing server (in my subjective feeling) I was getting from api.php:

> ash ping()

Preference pingLatest changed from council.php:10:127:176:1464:26880:146 to api.php:10:73:90:768:19620:76
Returned: record {string page; int count; int low; int high; int total; int bytes; int average; int bps;}
page => api.php
count => 10
low => 73
high => 90
total => 768
bytes => 19620
average => 76
bps => 25546

And on that same server, from council.php:

> ash ping(10, "council.php")

Preference pingLatest changed from api.php:10:73:90:768:19620:76 to council.php:10:138:288:1810:26760:181
Returned: record {string page; int count; int low; int high; int total; int bytes; int average; int bps;}
page => council.php
count => 10
low => 138
high => 288
total => 1810
bytes => 26760
average => 181
bps => 14784

On a "good" performing server (again, in just subjective "feeling" while playing), from api.php:

> ash ping()

Preference pingLatest changed from api.php:10:64:76:678:19620:67 to api.php:10:74:81:765:19620:76
Returned: record {string page; int count; int low; int high; int total; int bytes; int average; int bps;}
page => api.php
count => 10
low => 74
high => 81
total => 765
bytes => 19620
average => 76
bps => 25647

So the same average as the "okay-to-bad" server, however when checking council again:

> ash ping(10, "council.php")

Preference pingLatest changed from api.php:10:74:81:765:19620:76 to council.php:10:109:194:1339:26760:133
Returned: record {string page; int count; int low; int high; int total; int bytes; int average; int bps;}
page => council.php
count => 10
low => 109
high => 194
total => 1339
bytes => 26760
average => 133
bps => 19985

Significantly better than the previous server (which matches up with my perceived experience)

 

[Veracity]

My login ping test with api.php gave me 24 msec.

api.php:

> ping 100 api

100 pings to api.php at 21-91 msec apiece (total = 2743, average = 27) = 71527 bytes/second

> repeat 9

Repetition 1 of 9...
100 pings to api.php at 21-36 msec apiece (total = 2506, average = 25) = 78292 bytes/second
Repetition 2 of 9...
100 pings to api.php at 20-37 msec apiece (total = 2588, average = 25) = 75811 bytes/second
Repetition 3 of 9...
100 pings to api.php at 22-53 msec apiece (total = 2725, average = 27) = 72000 bytes/second
Repetition 4 of 9...
100 pings to api.php at 21-88 msec apiece (total = 2615, average = 26) = 75028 bytes/second
Repetition 5 of 9...
100 pings to api.php at 21-42 msec apiece (total = 2553, average = 25) = 76850 bytes/second
Repetition 6 of 9...
100 pings to api.php at 21-38 msec apiece (total = 2605, average = 26) = 75316 bytes/second
Repetition 7 of 9...
100 pings to api.php at 19-34 msec apiece (total = 2546, average = 25) = 77062 bytes/second
Repetition 8 of 9...
100 pings to api.php at 21-38 msec apiece (total = 2533, average = 25) = 77457 bytes/second
Repetition 9 of 9...
100 pings to api.php at 20-35 msec apiece (total = 2527, average = 25) = 77641 bytes/second

council.php:

> ping 100 council

100 pings to council.php at 66-148 msec apiece (total = 9224, average = 92) = 93284 bytes/second

> repeat 9

Repetition 1 of 9...
100 pings to council.php at 68-147 msec apiece (total = 8868, average = 88) = 97063 bytes/second
Repetition 2 of 9...
100 pings to council.php at 64-130 msec apiece (total = 8465, average = 84) = 101691 bytes/second
Repetition 3 of 9...
100 pings to council.php at 67-123 msec apiece (total = 8770, average = 87) = 98114 bytes/second
Repetition 4 of 9...
100 pings to council.php at 60-141 msec apiece (total = 8690, average = 86) = 99003 bytes/second
Repetition 5 of 9...
100 pings to council.php at 64-131 msec apiece (total = 8460, average = 84) = 101730 bytes/second
Repetition 6 of 9...
100 pings to council.php at 67-123 msec apiece (total = 8852, average = 88) = 97218 bytes/second
Repetition 7 of 9...
100 pings to council.php at 67-124 msec apiece (total = 8803, average = 88) = 97732 bytes/second
Repetition 8 of 9...
100 pings to council.php at 65-205 msec apiece (total = 9474, average = 94) = 90835 bytes/second
Repetition 9 of 9...
100 pings to council.php at 66-149 msec apiece (total = 9010, average = 90) = 95473 bytes/second

I have my ping preferences set to require a login ping test of no more than 30.

I'll remove that requirement and see how things look when I have a "bad" ping test.

 

[Veracity]

This time, I timed in to get a login ping test of 77 msec.

api.php

> ping 100 api

100 pings to api.php at 37-85 msec apiece (total = 5367, average = 53) = 36556 bytes/second

> repeat 9

Repetition 1 of 9...
100 pings to api.php at 34-79 msec apiece (total = 5123, average = 51) = 38297 bytes/second
Repetition 2 of 9...
100 pings to api.php at 38-138 msec apiece (total = 6573, average = 65) = 29849 bytes/second
Repetition 3 of 9...
100 pings to api.php at 35-95 msec apiece (total = 5603, average = 56) = 35016 bytes/second
Repetition 4 of 9...
100 pings to api.php at 33-90 msec apiece (total = 5061, average = 50) = 38767 bytes/second
Repetition 5 of 9...
100 pings to api.php at 34-90 msec apiece (total = 4587, average = 45) = 42773 bytes/second
Repetition 6 of 9...
100 pings to api.php at 33-79 msec apiece (total = 4953, average = 49) = 39612 bytes/second
Repetition 7 of 9...
100 pings to api.php at 36-77 msec apiece (total = 4983, average = 49) = 39373 bytes/second
Repetition 8 of 9...
100 pings to api.php at 36-88 msec apiece (total = 4797, average = 47) = 40900 bytes/second
Repetition 9 of 9...
100 pings to api.php at 34-94 msec apiece (total = 5016, average = 50) = 39114 bytes/second

Definitely worse than my previous tests where I had a login ping time of 24 msec.

council.php:

> ping 100 council

100 pings to council.php at 91-159 msec apiece (total = 11304, average = 113) = 76114 bytes/second

> repeat 9

Repetition 1 of 9...
100 pings to council.php at 88-142 msec apiece (total = 10360, average = 103) = 83055 bytes/second
Repetition 2 of 9...
100 pings to council.php at 87-149 msec apiece (total = 10638, average = 106) = 80930 bytes/second
Repetition 3 of 9...
100 pings to council.php at 88-140 msec apiece (total = 10403, average = 104) = 82706 bytes/second
Repetition 4 of 9...
100 pings to council.php at 87-137 msec apiece (total = 10407, average = 104) = 82721 bytes/second
Repetition 5 of 9...
100 pings to council.php at 89-157 msec apiece (total = 10509, average = 105) = 81866 bytes/second
Repetition 6 of 9...
100 pings to council.php at 87-146 msec apiece (total = 10279, average = 102) = 83716 bytes/second
Repetition 7 of 9...
100 pings to council.php at 90-162 msec apiece (total = 11157, average = 111) = 77095 bytes/second
Repetition 8 of 9...
100 pings to council.php at 88-176 msec apiece (total = 10489, average = 104) = 82040 bytes/second
Repetition 9 of 9...
100 pings to council.php at 86-159 msec apiece (total = 10398, average = 103) = 82717 bytes/second

For me, both api.php and council.php were slower on this connection than on the previous one.
Which is to say, for me, both pages are "correlated" with the speed of the connection.

I have no explanation for why api.php is not slower for you on a connection where council.php is slower.