(core) When reporting email in log metadata, use normalized email.

Summary:
There has been inconsistency in using display email vs normalized email, which
ends up creating some duplication in downstream analyses (e.g. the same user
showing up twice with different capitalization).

1. Add UserProfile.loginEmail field with normalized email to prefer, when set, over the inconsistently used UserProfile.email.
2. In one place where it's not available, normalize the display email manually.
3. Clean up some code in Client.ts.

Unrelated tweak to API Console to be clear when a URL parameter wasn't found (rather than show whatever happens to be the first value).

Several test robustness improvements:
- Misplaced parenthesis in gristWebDriverUtils has been causing optTimeout argument to be ignored in tests, and treated always as indefinite.
- Attempt to fix SortMenu test by ignoring (retrying with logging) errors in waitForServer, which include "script timeout" errors that come from a non-configurable selenium or chromedriver timeout.
- Attempt to improve onNewTab() helper, which plays a role in failing Billing tests.

Test Plan: Tested manually the capitalization of logged emails. Counting on existing tests to catch issues.

Reviewers: georgegevoian

Reviewed By: georgegevoian

Differential Revision: https://phab.getgrist.com/D4188

app/client/apiconsole.ts

@@ -66,6 +66,7 @@ function setExamples(examplesArr: Example[], paramName: string) {
   examplesArr.sort((a, b) => String(a.summary || a.value).localeCompare(String(b.summary || b.value)));
 
   const paramValue = searchParams.get(paramName);
+  let haveCurrentValue = false;
   if (paramValue) {
     // If this value appears among examples, move it to the front and label it as "Current".
     const index = examplesArr.findIndex(v => (String(v.value) == String(paramValue)));
@@ -73,8 +74,10 @@ function setExamples(examplesArr: Example[], paramName: string) {
       const ex = examplesArr.splice(index, 1)[0];
       ex.summary += " (Current)";
       examplesArr.unshift(ex);
+      haveCurrentValue = true;
     }
-  } else {
+  }
+  if (!haveCurrentValue) {
     // When opening an endpoint, parameters with examples are immediately set to the first example.
     // For documents and tables, this would immediately call our custom code,
     // fetching lists of tables/columns. This is especially bad for documents,

app/common/LoginSessionAPI.ts

@@ -2,7 +2,8 @@ import {UserPrefs} from 'app/common/Prefs';
 
 // User profile info for the user. When using Cognito, it is fetched during login.
 export interface UserProfile {
-  email: string;
+  email: string;          // TODO: Used inconsistently: as lowercase login email or display email.
+  loginEmail?: string;    // When set, this is consistently normalized (lowercase) login email.
   name: string;
   picture?: string|null; // when present, a url to a public image of unspecified dimensions.
   anonymous?: boolean;   // when present, asserts whether user is anonymous (not authorized).

app/gen-server/lib/HomeDBManager.ts

@@ -514,9 +514,14 @@ export class HomeDBManager extends EventEmitter {
     if (!user.logins?.[0]?.displayEmail) {
       throw new ApiError("unable to find mandatory user email", 400);
     }
+    const displayEmail = user.logins[0].displayEmail;
+    const loginEmail = user.loginEmail;
     const result: FullUser = {
       id: user.id,
-      email: user.logins[0].displayEmail,
+      email: displayEmail,
+      // Only include loginEmail when it's different, to avoid overhead when FullUser is sent
+      // around, and also to avoid updating too many tests.
+      loginEmail: loginEmail !== displayEmail ? loginEmail : undefined,
       name: user.name,
       picture: user.picture,
       ref: user.ref,
@@ -2391,6 +2396,7 @@ export class HomeDBManager extends EventEmitter {
       const access = userRoleMap[u.id];
       return {
         ...this.makeFullUser(u),
+        loginEmail: undefined,    // Not part of PermissionData.
         access,
         isMember: access !== 'guests',
       };
@@ -2447,6 +2453,7 @@ export class HomeDBManager extends EventEmitter {
       const orgAccess = orgMapWithMembership[u.id] || null;
       return {
         ...this.makeFullUser(u),
+        loginEmail: undefined,    // Not part of PermissionData.
         access: wsMap[u.id] || null,
         parentAccess: roles.getEffectiveRole(orgMap[u.id] || null),
         isMember: orgAccess && orgAccess !== 'guests',
@@ -2509,6 +2516,7 @@ export class HomeDBManager extends EventEmitter {
       const orgAccess = orgMapWithMembership[u.id] || null;
       return {
         ...this.makeFullUser(u),
+        loginEmail: undefined,    // Not part of PermissionData.
         access: docMap[u.id] || null,
         parentAccess: roles.getEffectiveRole(
           roles.getStrongestRole(wsMap[u.id] || null, inheritFromOrg)

app/server/lib/Client.ts

@@ -3,9 +3,10 @@ import {BrowserSettings} from 'app/common/BrowserSettings';
 import {delay} from 'app/common/delay';
 import {CommClientConnect, CommMessage, CommResponse, CommResponseError} from 'app/common/CommTypes';
 import {ErrorWithCode} from 'app/common/ErrorWithCode';
-import {UserProfile} from 'app/common/LoginSessionAPI';
+import {FullUser, UserProfile} from 'app/common/LoginSessionAPI';
 import {TelemetryMetadata} from 'app/common/Telemetry';
 import {ANONYMOUS_USER_EMAIL} from 'app/common/UserAPI';
+import {normalizeEmail} from 'app/common/emails';
 import {User} from 'app/gen-server/entity/User';
 import {HomeDBManager} from 'app/gen-server/lib/HomeDBManager';
 import {ActiveDoc} from 'app/server/lib/ActiveDoc';
@@ -100,11 +101,8 @@ export class Client {
   private _websocketEventHandlers: Array<{event: string, handler: (...args: any[]) => void}> = [];
   private _org: string|null = null;
   private _profile: UserProfile|null = null;
-  private _userId: number|null = null;
+  private _user: FullUser|undefined = undefined;
-  private _userName: string|null = null;
-  private _userRef: string|null = null;
   private _firstLoginAt: Date|null = null;
-  private _isAnonymous: boolean = false;
   private _nextSeqId: number = 0;     // Next sequence-ID for messages sent to the client
 
   // Identifier for the current GristWSConnection object connected to this client.
@@ -424,16 +422,13 @@ export class Client {
 
   public setProfile(profile: UserProfile|null): void {
     this._profile = profile;
-    // Unset userId, so that we look it up again on demand. (Not that userId could change in
+    // Unset user, so that we look it up again on demand.
-    // practice via a change to profile, but let's not make any assumptions here.)
+    this._user = undefined;
-    this._userId = null;
-    this._userName = null;
     this._firstLoginAt = null;
-    this._isAnonymous = !profile;
   }
 
   public getProfile(): UserProfile|null {
-    if (this._isAnonymous) {
+    if (!this._profile) {
       return {
         name: 'Anonymous',
         email: ANONYMOUS_USER_EMAIL,
@@ -446,34 +441,31 @@ export class Client {
     // in the database (important since user name is now exposed via
     // user.Name in granular access support). TODO: might want to
     // subscribe to changes in user name while the document is open.
-    return this._profile ? {
+    return {...this._profile, ...this._user};
-      ...this._profile,
-      ...(this._userName && { name: this._userName }),
-    } : null;
   }
 
   public getCachedUserId(): number|null {
-    return this._userId;
+    return this._user?.id ?? null;
   }
 
   public getCachedUserRef(): string|null {
-    return this._userRef;
+    return this._user?.ref ?? null;
   }
 
   // Returns the userId for profile.email, or null when profile is not set; with caching.
   public async getUserId(dbManager: HomeDBManager): Promise<number|null> {
-    if (!this._userId) {
+    if (!this._user) {
       await this._refreshUser(dbManager);
     }
-    return this._userId;
+    return this._user?.id ?? null;
   }
 
   // Returns the userRef for profile.email, or null when profile is not set; with caching.
   public async getUserRef(dbManager: HomeDBManager): Promise<string|null> {
-    if (!this._userRef) {
+    if (!this._user) {
       await this._refreshUser(dbManager);
     }
-    return this._userRef;
+    return this._user?.ref ?? null;
   }
 
   // Returns the userId for profile.email, or throws 403 error when profile is not set.
@@ -484,10 +476,10 @@ export class Client {
   }
 
   public getLogMeta(meta: {[key: string]: any} = {}) {
-    if (this._profile) { meta.email = this._profile.email; }
+    if (this._profile) { meta.email = this._user?.loginEmail || normalizeEmail(this._profile.email); }
-    // We assume the _userId has already been cached, which will be true always (for all practical
+    // We assume the _user has already been cached, which will be true always (for all practical
     // purposes) because it's set when the Authorizer checks this client.
-    if (this._userId) { meta.userId = this._userId; }
+    if (this._user) { meta.userId = this._user.id; }
     // Likewise for _firstLoginAt, which we learn along with _userId.
     if (this._firstLoginAt) {
       meta.age = Math.floor(moment.duration(moment().diff(this._firstLoginAt)).asDays());
@@ -504,26 +496,16 @@ export class Client {
     const meta: TelemetryMetadata = {};
     // We assume the _userId has already been cached, which will be true always (for all practical
     // purposes) because it's set when the Authorizer checks this client.
-    if (this._userId) { meta.userId = this._userId; }
+    if (this._user) { meta.userId = this._user.id; }
     const altSessionId = this.getAltSessionId();
     if (altSessionId) { meta.altSessionId = altSessionId; }
     return meta;
   }
 
   private async _refreshUser(dbManager: HomeDBManager) {
-    if (this._profile) {
+    const user = this._profile ? await this._fetchUser(dbManager) : dbManager.getAnonymousUser();
-      const user = await this._fetchUser(dbManager);
+    this._user = user ? dbManager.makeFullUser(user) : undefined;
-      this._userId = (user && user.id) || null;
+    this._firstLoginAt = user?.firstLoginAt || null;
-      this._userName = (user && user.name) || null;
-      this._isAnonymous = this._userId && dbManager.getAnonymousUserId() === this._userId || false;
-      this._firstLoginAt = (user && user.firstLoginAt) || null;
-      this._userRef = user?.ref ?? null;
-    } else {
-      this._userId = dbManager.getAnonymousUserId();
-      this._userName = 'Anonymous';
-      this._isAnonymous = true;
-      this._firstLoginAt = null;
-    }
   }
 
   private async _onMessage(message: string): Promise<void> {

app/server/lib/serverUtils.ts

@@ -146,9 +146,10 @@ export function getLogMetaFromDocSession(docSession: OptDocSession) {
   const client = docSession.client;
   const access = getDocSessionAccessOrNull(docSession);
   const user = getDocSessionUser(docSession);
+  const email = user?.loginEmail || user?.email;
   return {
     access,
-    ...(user ? {userId: user.id, email: user.email} : {}),
+    ...(user ? {userId: user.id, email} : {}),
     ...(client ? client.getLogMeta() : {}),   // Client if present will repeat and add to user info.
   };
 }

test/nbrowser/gristUtils.ts

@@ -889,7 +889,7 @@ export async function importFileDialog(filePath: string): Promise<void> {
     await driver.findContent('.test-dp-import-option', /Import from file/i).doClick();
   });
   await driver.findWait('.test-importer-dialog', 5000);
-  await waitForServer();
+  await waitForServer(10_000);
 }
 
 /**
@@ -2821,14 +2821,21 @@ export async function getEnabledOptions(): Promise<SortOption[]> {
  * on whole test suite if needed.
  */
 export async function onNewTab(action: () => Promise<void>) {
+  const currentTab = await driver.getWindowHandle();
   await driver.executeScript("window.open('about:blank', '_blank')");
   const tabs = await driver.getAllWindowHandles();
-  await driver.switchTo().window(tabs[tabs.length - 1]);
+  const newTab = tabs[tabs.length - 1];
+  await driver.switchTo().window(newTab);
   try {
     await action();
   } finally {
-    await driver.close();
+    const newCurrentTab = await driver.getWindowHandle();
-    await driver.switchTo().window(tabs[tabs.length - 2]);
+    if (newCurrentTab === newTab) {
+      await driver.close();
+      await driver.switchTo().window(currentTab);
+    } else {
+      console.log("onNewTab not cleaning up because is not on expected tab");
+    }
   }
 }
 

test/nbrowser/gristWebDriverUtils.ts

@@ -26,15 +26,21 @@ export class GristWebDriverUtils {
    *
    * Simply call this after some request has been made, and when it resolves, you know that request
    * has been processed.
-   * @param optTimeout: Timeout in ms, defaults to 2000.
+   * @param optTimeout: Timeout in ms, defaults to 5000.
    */
-  public async waitForServer(optTimeout: number = 2000) {
+  public async waitForServer(optTimeout: number = 5000) {
     await this.driver.wait(() => this.driver.executeScript(
       "return window.gristApp && (!window.gristApp.comm || !window.gristApp.comm.hasActiveRequests())"
-        + " && window.gristApp.testNumPendingApiRequests() === 0",
+        + " && window.gristApp.testNumPendingApiRequests() === 0"
+      )
+      // The catch is in case executeScript() fails. This is rare but happens occasionally when
+      // browser is busy (e.g. sorting) and doesn't respond quickly enough. The timeout selenium
+      // allows for a response is short (and I see no place to configure it); by catching, we'll
+      // let the call fail until our intended timeout expires.
+      .catch((e) => { console.log("Ignoring executeScript error", String(e)); }),
       optTimeout,
       "Timed out waiting for server requests to complete"
-    ));
+    );
   }
 
   public async waitForSidePanel() {