From b57be7670c63de0b8f52e5bd21af99921f93bdf3 Mon Sep 17 00:00:00 2001 From: Matthew Raymer Date: Fri, 5 Sep 2025 04:02:53 +0000 Subject: [PATCH] refactor: improve logging levels and environment configuration - Fix logging levels: change verbose debugging from info to debug level - TestView: component mounting, boot-time config, URL flow testing - main.capacitor.ts: deeplink processing steps and router state - HomeView: API call details, component state updates, template rendering - Remove redundant environment variable override in vite.config.common.mts - Environment loading via dotenv works correctly - Manual override was defensive programming but unnecessary - Simplifies configuration and reduces maintenance burden - Add comprehensive Playwright timeout behavior documentation - README.md: detailed timeout types, failure behavior, debugging guide - TESTING.md: timeout failure troubleshooting and common scenarios - Clarifies that timeout failures indicate real issues, not flaky tests - Fix TypeScript configuration for .mts imports - tsconfig.node.json: add allowImportingTsExtensions for Vite config files - Resolves import path linting errors for .mts extensions All changes maintain existing functionality while improving code quality and reducing log noise in production environments. --- src/main.capacitor.ts | 10 +++--- src/views/HomeView.vue | 8 ++--- src/views/TestView.vue | 8 ++--- test-playwright/README.md | 70 ++++++++++++++++++++++++++++++++++++++ test-playwright/TESTING.md | 46 ++++++++++++++++++++++++- tsconfig.node.json | 3 +- vite.config.common.mts | 6 +--- 7 files changed, 131 insertions(+), 20 deletions(-) diff --git a/src/main.capacitor.ts b/src/main.capacitor.ts index 19cbf4e7..c97efce8 100644 --- a/src/main.capacitor.ts +++ b/src/main.capacitor.ts @@ -69,18 +69,18 @@ const deepLinkHandler = new DeepLinkHandler(router); */ const handleDeepLink = async (data: { url: string }) => { const { url } = data; - logger.info(`[Main] šŸŒ Deeplink received from Capacitor: ${url}`); + logger.debug(`[Main] šŸŒ Deeplink received from Capacitor: ${url}`); try { // Wait for router to be ready - logger.info(`[Main] ā³ Waiting for router to be ready...`); + logger.debug(`[Main] ā³ Waiting for router to be ready...`); await router.isReady(); - logger.info(`[Main] āœ… Router is ready, processing deeplink`); + logger.debug(`[Main] āœ… Router is ready, processing deeplink`); // Process the deeplink - logger.info(`[Main] šŸš€ Starting deeplink processing`); + logger.debug(`[Main] šŸš€ Starting deeplink processing`); await deepLinkHandler.handleDeepLink(url); - logger.info(`[Main] āœ… Deeplink processed successfully`); + logger.debug(`[Main] āœ… Deeplink processed successfully`); } catch (error) { logger.error(`[Main] āŒ Deeplink processing failed:`, { url, diff --git a/src/views/HomeView.vue b/src/views/HomeView.vue index 67de90ba..aeb5f381 100644 --- a/src/views/HomeView.vue +++ b/src/views/HomeView.vue @@ -742,7 +742,7 @@ export default class HomeView extends Vue { }); if (this.activeDid) { - logger.info("[HomeView] loadNewOffers() - activeDid found, calling API", { + logger.debug("[HomeView] loadNewOffers() - activeDid found, calling API", { activeDid: this.activeDid, apiServer: this.apiServer, isRegistered: this.isRegistered, @@ -768,7 +768,7 @@ export default class HomeView extends Vue { this.numNewOffersToUser = offersToUserData.data.length; this.newOffersToUserHitLimit = offersToUserData.hitLimit; - logger.info("[HomeView] loadNewOffers() - updated component state", { + logger.debug("[HomeView] loadNewOffers() - updated component state", { activeDid: this.activeDid, numNewOffersToUser: this.numNewOffersToUser, newOffersToUserHitLimit: this.newOffersToUserHitLimit, @@ -794,7 +794,7 @@ export default class HomeView extends Vue { this.numNewOffersToUserProjects = offersToUserProjects.data.length; this.newOffersToUserProjectsHitLimit = offersToUserProjects.hitLimit; - logger.info("[HomeView] loadNewOffers() - all API calls completed", { + logger.debug("[HomeView] loadNewOffers() - all API calls completed", { numNewOffersToUser: this.numNewOffersToUser, numNewOffersToUserProjects: this.numNewOffersToUserProjects, shouldRenderElement: !!this.numNewOffersToUser, @@ -803,7 +803,7 @@ export default class HomeView extends Vue { }); // Additional logging for template rendering debugging - logger.info("[HomeView] loadNewOffers() - template rendering check", { + logger.debug("[HomeView] loadNewOffers() - template rendering check", { numNewOffersToUser: this.numNewOffersToUser, numNewOffersToUserProjects: this.numNewOffersToUserProjects, totalNewOffers: diff --git a/src/views/TestView.vue b/src/views/TestView.vue index ef602468..a4d0e272 100644 --- a/src/views/TestView.vue +++ b/src/views/TestView.vue @@ -625,12 +625,12 @@ export default class Help extends Vue { * Uses PlatformServiceMixin for database access */ async mounted() { - logger.info( + logger.debug( "[TestView] šŸš€ Component mounting - starting URL flow tracking", ); // Boot-time logging for initial configuration - logger.info("[TestView] šŸŒ Boot-time configuration detected:", { + logger.debug("[TestView] šŸŒ Boot-time configuration detected:", { platform: process.env.VITE_PLATFORM, defaultEndorserApiServer: process.env.VITE_DEFAULT_ENDORSER_API_SERVER, defaultPartnerApiServer: process.env.VITE_DEFAULT_PARTNER_API_SERVER, @@ -996,7 +996,7 @@ export default class Help extends Vue { this.urlTestResults = []; try { - logger.info("[TestView] šŸ”¬ Starting comprehensive URL flow test"); + logger.debug("[TestView] šŸ”¬ Starting comprehensive URL flow test"); this.addUrlTestResult("šŸš€ Starting URL flow test..."); // Test 1: Current state @@ -1124,7 +1124,7 @@ export default class Help extends Vue { ); this.addUrlTestResult(`\nāœ… URL flow test completed successfully!`); - logger.info("[TestView] āœ… URL flow test completed successfully"); + logger.debug("[TestView] āœ… URL flow test completed successfully"); } catch (error) { const errorMsg = `āŒ URL flow test failed: ${error instanceof Error ? error.message : String(error)}`; this.addUrlTestResult(errorMsg); diff --git a/test-playwright/README.md b/test-playwright/README.md index b0a403fa..4aea68e3 100644 --- a/test-playwright/README.md +++ b/test-playwright/README.md @@ -97,6 +97,69 @@ The test suite uses predefined test users, with User #0 having registration priv More details available in TESTING.md +## Timeout Behavior + +**Important**: Playwright tests will fail if any operation exceeds its specified timeout. This is intentional behavior to catch performance issues and ensure tests don't hang indefinitely. + +### Timeout Types and Defaults + +1. **Test Timeout**: 45 seconds (configured in `playwright.config-local.ts`) + - Maximum time for entire test to complete + - Test fails if exceeded + +2. **Expect Timeout**: 5 seconds (Playwright default) + - Maximum time for assertions (`expect()`) to pass + - Test fails if assertion doesn't pass within timeout + +3. **Action Timeout**: No default limit + - Maximum time for actions (`click()`, `fill()`, etc.) + - Can be set per action if needed + +4. **Function Timeout**: Specified per `waitForFunction()` call + - Example: `{ timeout: 5000 }` = 5 seconds + - **Test will fail if function doesn't return true within timeout** + +### Common Timeout Patterns in Tests + +```typescript +// Wait for UI element to appear (5 second timeout) +await page.waitForFunction(() => { + const buttons = document.querySelectorAll('div[role="alert"] button'); + return Array.from(buttons).some(button => button.textContent?.includes('No')); +}, { timeout: 5000 }); + +// If this times out, the test FAILS immediately +``` + +### Why Tests Fail on Timeout + +- **Performance Issues**: Slow UI rendering or network requests +- **Application Bugs**: Missing elements or broken functionality +- **Test Environment Issues**: Server not responding or browser problems +- **Race Conditions**: Elements not ready when expected + +### Timeout Configuration + +To adjust timeouts for specific tests: + +```typescript +test('slow test', async ({ page }) => { + test.setTimeout(120000); // 2 minutes for entire test + + await expect(page.locator('button')).toBeVisible({ timeout: 15000 }); // 15 seconds for assertion + + await page.click('button', { timeout: 10000 }); // 10 seconds for action +}); +``` + +### Debugging Timeout Failures + +1. **Check Test Logs**: Look for timeout error messages +2. **Run with Tracing**: `--trace on` to see detailed execution +3. **Run Headed**: `--headed` to watch test execution visually +4. **Check Server Logs**: Verify backend is responding +5. **Increase Timeout**: Temporarily increase timeout to see if it's a performance issue + ## Troubleshooting Common issues and solutions: @@ -105,6 +168,7 @@ Common issues and solutions: - Some tests may fail intermittently - try rerunning - Check Endorser server logs for backend issues - Verify test environment setup + - **Timeout failures indicate real performance or functionality issues** 2. **Mobile Testing** - Ensure XCode/Android Studio is running @@ -116,6 +180,12 @@ Common issues and solutions: - Reset IndexedDB if needed - Check service worker status +4. **Timeout Issues** + - Check if UI elements are loading slowly + - Verify server response times + - Consider if timeout values are appropriate for the operation + - Use `--headed` mode to visually debug timeout scenarios + For more detailed troubleshooting, see TESTING.md. ## Contributing diff --git a/test-playwright/TESTING.md b/test-playwright/TESTING.md index 3174c895..1efbd7ff 100644 --- a/test-playwright/TESTING.md +++ b/test-playwright/TESTING.md @@ -85,13 +85,57 @@ mkdir -p profiles/dev2 && \ firefox --no-remote --profile $(realpath profiles/dev2) --devtools --new-window http://localhost:8080 ``` +## Timeout Behavior + +**Critical Understanding**: Playwright tests will **fail immediately** if any timeout is exceeded. This is intentional behavior to catch performance issues and ensure tests don't hang indefinitely. + +### Key Timeout Facts + +- **Test Timeout**: 45 seconds (entire test must complete) +- **Expect Timeout**: 5 seconds (assertions must pass) +- **Function Timeout**: As specified (e.g., `{ timeout: 5000 }` = 5 seconds) +- **Action Timeout**: No default limit (can be set per action) + +### What Happens on Timeout + +```typescript +// This will FAIL the test if buttons don't appear within 5 seconds +await page.waitForFunction(() => { + const buttons = document.querySelectorAll('div[role="alert"] button'); + return Array.from(buttons).some(button => button.textContent?.includes('No')); +}, { timeout: 5000 }); +``` + +**If timeout exceeded**: Test fails immediately with `TimeoutError` - no recovery, no continuation. + +### Debugging Timeout Failures + +1. **Visual Debugging**: Run with `--headed` to watch test execution +2. **Tracing**: Use `--trace on` for detailed execution logs +3. **Server Check**: Verify Endorser server is responding quickly +4. **Performance**: Check if UI elements are loading slowly +5. **Timeout Adjustment**: Temporarily increase timeout to isolate performance vs functionality issues + +### Common Timeout Scenarios + +- **UI Elements Not Appearing**: Check if alerts/dialogs are rendering correctly +- **Network Delays**: Verify server response times +- **Race Conditions**: Elements not ready when expected +- **Browser Issues**: Slow rendering or JavaScript execution + ## Troubleshooting 1. Identity Errors: - "No keys for ID" errors may occur when current account was erased - Account switching can cause issues with erased accounts -2. If you find yourself wanting to see the testing process try something like this: +2. **Timeout Failures**: + - **These are NOT flaky tests** - they indicate real performance or functionality issues + - Check server logs for slow responses + - Verify UI elements are rendering correctly + - Use `--headed` mode to visually debug the issue + +3. If you find yourself wanting to see the testing process try something like this: ``` npx playwright test -c playwright.config-local.ts test-playwright/60-new-activity.spec.ts --grep "New offers for another user" --headed diff --git a/tsconfig.node.json b/tsconfig.node.json index 6aa7b5c6..a5def798 100644 --- a/tsconfig.node.json +++ b/tsconfig.node.json @@ -4,7 +4,8 @@ "skipLibCheck": true, "module": "ESNext", "moduleResolution": "bundler", - "allowSyntheticDefaultImports": true + "allowSyntheticDefaultImports": true, + "allowImportingTsExtensions": true }, "include": ["vite.config.*"] } \ No newline at end of file diff --git a/vite.config.common.mts b/vite.config.common.mts index 2783adf0..047192d5 100644 --- a/vite.config.common.mts +++ b/vite.config.common.mts @@ -20,11 +20,7 @@ export async function createBuildConfig(platform: string): Promise { // Set platform - PWA is always enabled for web platforms process.env.VITE_PLATFORM = platform; - // Set development API servers for local development - if (process.env.NODE_ENV === 'development') { - process.env.VITE_DEFAULT_ENDORSER_API_SERVER = 'http://localhost:3000'; - process.env.VITE_DEFAULT_PARTNER_API_SERVER = 'http://localhost:3000'; - } + // Environment variables are loaded from .env files via dotenv.config() above return { base: "/",