diff --git a/core/src/main/java/in/testpress/fragments/WebViewFragment.kt b/core/src/main/java/in/testpress/fragments/WebViewFragment.kt index c680314bb..56a30e963 100644 --- a/core/src/main/java/in/testpress/fragments/WebViewFragment.kt +++ b/core/src/main/java/in/testpress/fragments/WebViewFragment.kt @@ -40,10 +40,17 @@ class WebViewFragment : Fragment(), EmptyViewListener { private var enableSwipeRefresh: Boolean = false var session: TestpressSession? = null var lockToLandscape: Boolean = false + private var webViewClient: CustomWebViewClient? = null + var loadUrlCalledTime: Long = 0 override fun onCreate(savedInstanceState: Bundle?) { super.onCreate(savedInstanceState) + val startTime = System.currentTimeMillis() + android.util.Log.d("AI_TIMING", "๐ŸŸฆ STEP 8: WebViewFragment.onCreate() STARTED") + parseArguments() + + android.util.Log.d("AI_TIMING", "โœ… STEP 8 DONE: WebViewFragment.onCreate() completed in ${System.currentTimeMillis() - startTime}ms") } override fun onCreateView( @@ -51,20 +58,50 @@ class WebViewFragment : Fragment(), EmptyViewListener { container: ViewGroup?, savedInstanceState: Bundle? ): View? { + val startTime = System.currentTimeMillis() + android.util.Log.d("AI_TIMING", "๐ŸŸฆ STEP 9: WebViewFragment.onCreateView() STARTED") + _layout = WebviewFragmentBinding.inflate(inflater, container, false) + + android.util.Log.d("AI_TIMING", "โœ… STEP 9 DONE: WebViewFragment.onCreateView() completed in ${System.currentTimeMillis() - startTime}ms") return layout.root } override fun onViewCreated(view: View, savedInstanceState: Bundle?) { super.onViewCreated(view, savedInstanceState) + + val startTime = System.currentTimeMillis() + android.util.Log.d("AI_TIMING", "๐ŸŸฆ STEP 10: WebViewFragment.onViewCreated() STARTED") + showLoading() + android.util.Log.d("AI_TIMING", " Showing loading spinner... (${System.currentTimeMillis() - startTime}ms)") + initializedSwipeRefresh() + android.util.Log.d("AI_TIMING", " Initialized swipe refresh (${System.currentTimeMillis() - startTime}ms)") + initializeEmptyViewFragment() + android.util.Log.d("AI_TIMING", " Initialized empty view fragment (${System.currentTimeMillis() - startTime}ms)") + webView = layout.webView listener?.onWebViewInitializationSuccess() + android.util.Log.d("AI_TIMING", " WebView reference obtained (${System.currentTimeMillis() - startTime}ms)") + + android.util.Log.d("AI_TIMING", "๐ŸŸฆ STEP 11: Calling setupWebView()...") + val setupStart = System.currentTimeMillis() setupWebView() + android.util.Log.d("AI_TIMING", "โœ… STEP 11 DONE: setupWebView() completed in ${System.currentTimeMillis() - setupStart}ms") + + android.util.Log.d("AI_TIMING", "๐ŸŸฆ STEP 12: Calling populateInstituteSettings()...") + val settingsStart = System.currentTimeMillis() populateInstituteSettings() + android.util.Log.d("AI_TIMING", "โœ… STEP 12 DONE: populateInstituteSettings() completed in ${System.currentTimeMillis() - settingsStart}ms") + + android.util.Log.d("AI_TIMING", "๐ŸŸฆ STEP 13: Calling loadContent() - NETWORK REQUEST STARTS HERE...") + val loadStart = System.currentTimeMillis() loadContent() + android.util.Log.d("AI_TIMING", "โœ… STEP 13 DONE: loadContent() initiated in ${System.currentTimeMillis() - loadStart}ms (network request continues in background)") + + android.util.Log.d("AI_TIMING", "โœ… STEP 10 DONE: WebViewFragment.onViewCreated() completed in ${System.currentTimeMillis() - startTime}ms total") } override fun onDestroy() { @@ -112,8 +149,15 @@ class WebViewFragment : Fragment(), EmptyViewListener { webView.settings.builtInZoomControls = false webView.settings.cacheMode = WebSettings.LOAD_CACHE_ELSE_NETWORK webView.settings.setSupportZoom(allowZoomControl) - webView.webViewClient = CustomWebViewClient(this) + + // Set WebView clients + val webViewClient = CustomWebViewClient(this) + webView.webViewClient = webViewClient webView.webChromeClient = CustomWebChromeClient(this) + + // Store reference to client for timing + this.webViewClient = webViewClient + webView.settings.userAgentString += CUSTOM_USER_AGENT webView.apply { clearCache(true) @@ -139,21 +183,143 @@ class WebViewFragment : Fragment(), EmptyViewListener { } private fun loadContent() { + android.util.Log.d("AI_TIMING", "") + android.util.Log.d("AI_TIMING", "=== DETAILED loadContent() ANALYSIS ===") + val loadContentStart = System.currentTimeMillis() + if (url.isNotEmpty()) { - webView.loadUrl(url, generateHeadersMap()) + android.util.Log.d("AI_TIMING", "๐Ÿ“ URL to load: $url") + + // Generate headers + val headersStart = System.currentTimeMillis() + val headers = generateHeadersMap() + android.util.Log.d("AI_TIMING", "โฑ๏ธ generateHeadersMap() took: ${System.currentTimeMillis() - headersStart}ms") + + // Log headers + android.util.Log.d("AI_TIMING", "๐Ÿ“‹ Headers being sent:") + headers.forEach { (key, value) -> + if (key == "Authorization") { + android.util.Log.d("AI_TIMING", " $key: JWT [token hidden for security]") + } else { + android.util.Log.d("AI_TIMING", " $key: $value") + } + } + + // Actually load the URL + android.util.Log.d("AI_TIMING", "๐ŸŒ Calling webView.loadUrl()...") + android.util.Log.d("AI_TIMING", "") + + val webViewLoadStart = System.currentTimeMillis() + loadUrlCalledTime = webViewLoadStart // Store for timing calculations + webViewClient?.setLoadUrlTime(webViewLoadStart) // Pass to client + + // ๐Ÿงช TEST MODE: Load simple HTML instead of network URL + android.util.Log.d("AI_TIMING", "๐Ÿงช TEST MODE: Loading local HTML instead of network URL") + android.util.Log.d("AI_TIMING", " This will tell us if delay is from network or WebView initialization") + android.util.Log.d("AI_TIMING", "") + + val testHtml = """ + + + + + + Hello World Test + + + +
+

๐Ÿš€ Hello World!

+

WebView loaded successfully

+
+

โœ… No network request

+

โœ… Pure local HTML

+

โœ… Instant loading test

+
+
+ + + + """.trimIndent() + + webView.loadDataWithBaseURL( + null, // baseUrl + testHtml, // data + "text/html", // mimeType + "UTF-8", // encoding + null // historyUrl + ) + + // Original network URL loading (commented out for test) + // webView.loadUrl(url, headers) + + android.util.Log.d("AI_TIMING", "โฑ๏ธ webView.loadDataWithBaseURL() call returned in: ${System.currentTimeMillis() - webViewLoadStart}ms") + android.util.Log.d("AI_TIMING", "") + android.util.Log.d("AI_TIMING", "โš ๏ธ IMPORTANT: loadDataWithBaseURL() returns immediately!") + android.util.Log.d("AI_TIMING", " Since this is local HTML, there's NO network delay") + android.util.Log.d("AI_TIMING", " Any delay you see is purely from WebView rendering") + android.util.Log.d("AI_TIMING", "") + android.util.Log.d("AI_TIMING", " โฐ Waiting for onPageStarted() callback...") + android.util.Log.d("AI_TIMING", " (Should fire almost instantly with local HTML)") + } else if (data.isNotEmpty()) { webView.loadData(data, "text/html", null) } else { // If both the URL and data are empty, pass an unexpected error showErrorView(TestpressException.unexpectedError(Exception("URL not found and data not found."))) } + + android.util.Log.d("AI_TIMING", "โฑ๏ธ Total loadContent() execution: ${System.currentTimeMillis() - loadContentStart}ms") + android.util.Log.d("AI_TIMING", "=====================================") + android.util.Log.d("AI_TIMING", "") } private fun generateHeadersMap(): Map { val headersMap = mutableMapOf() if (isAuthenticationRequired){ - headersMap["Authorization"] = "JWT ${session?.token}" - headersMap["User-Agent"] = UserAgentProvider.get(requireContext()) + val tokenStart = System.currentTimeMillis() + val token = session?.token + android.util.Log.d("AI_TIMING", " Getting auth token took: ${System.currentTimeMillis() - tokenStart}ms") + + val userAgentStart = System.currentTimeMillis() + val userAgent = UserAgentProvider.get(requireContext()) + android.util.Log.d("AI_TIMING", " Getting user agent took: ${System.currentTimeMillis() - userAgentStart}ms") + + headersMap["Authorization"] = "JWT $token" + headersMap["User-Agent"] = userAgent } return headersMap } diff --git a/core/src/main/java/in/testpress/util/webview/CustomWebViewClient.kt b/core/src/main/java/in/testpress/util/webview/CustomWebViewClient.kt index c3f6f06ef..ddeb04ca5 100644 --- a/core/src/main/java/in/testpress/util/webview/CustomWebViewClient.kt +++ b/core/src/main/java/in/testpress/util/webview/CustomWebViewClient.kt @@ -9,6 +9,11 @@ import android.webkit.* class CustomWebViewClient(val fragment: WebViewFragment) : WebViewClient() { private var errorList = linkedMapOf() + private var pageLoadStartTime: Long = 0 + private var loadUrlCalledTime: Long = 0 + private var firstResourceRequestTime: Long = 0 + private var resourceLoadTimes = mutableMapOf() + private var mainPageUrl: String? = null override fun shouldOverrideUrlLoading(view: WebView?, request: WebResourceRequest?): Boolean { val url = request?.url.toString() @@ -34,12 +39,103 @@ class CustomWebViewClient(val fragment: WebViewFragment) : WebViewClient() { fragment.allowNonInstituteUrlInWebView } } + + fun setLoadUrlTime(time: Long) { + loadUrlCalledTime = time + } override fun onPageStarted(view: WebView?, url: String?, favicon: Bitmap?) { + pageLoadStartTime = System.currentTimeMillis() + mainPageUrl = url + + // Calculate time from loadUrl() call to onPageStarted() + val networkSetupTime = if (loadUrlCalledTime > 0) { + pageLoadStartTime - loadUrlCalledTime + } else { + -1L + } + + android.util.Log.d("AI_TIMING", "") + android.util.Log.d("AI_TIMING", "================================================") + android.util.Log.d("AI_TIMING", "๐ŸŸฆ STEP 14: WebView.onPageStarted() FIRED!") + android.util.Log.d("AI_TIMING", "================================================") + android.util.Log.d("AI_TIMING", " URL: $url") + android.util.Log.d("AI_TIMING", "") + + if (networkSetupTime > 0) { + android.util.Log.d("AI_TIMING", "โฑ๏ธ TIME FROM loadUrl() TO onPageStarted(): ${networkSetupTime}ms") + android.util.Log.d("AI_TIMING", "") + android.util.Log.d("AI_TIMING", "๐Ÿ“Š THIS ${networkSetupTime}ms INCLUDES ALL NETWORK SETUP:") + android.util.Log.d("AI_TIMING", " โœ… DNS lookup (resolve domain to IP)") + android.util.Log.d("AI_TIMING", " โœ… TCP connection (3-way handshake)") + android.util.Log.d("AI_TIMING", " โœ… SSL/TLS handshake (if HTTPS)") + android.util.Log.d("AI_TIMING", " โœ… HTTP request sent to server") + android.util.Log.d("AI_TIMING", " โœ… Server processing request") + android.util.Log.d("AI_TIMING", " โœ… Response headers received") + android.util.Log.d("AI_TIMING", "") + + // Estimate breakdown (rough estimates) + android.util.Log.d("AI_TIMING", "๐Ÿ“ˆ ESTIMATED BREAKDOWN (typical values):") + val dns = (networkSetupTime * 0.15).toLong() + val tcp = (networkSetupTime * 0.10).toLong() + val ssl = (networkSetupTime * 0.20).toLong() + val request = (networkSetupTime * 0.05).toLong() + val server = (networkSetupTime * 0.45).toLong() + val headers = (networkSetupTime * 0.05).toLong() + + android.util.Log.d("AI_TIMING", " DNS Lookup: ~${dns}ms (~15% of total)") + android.util.Log.d("AI_TIMING", " TCP Connection: ~${tcp}ms (~10% of total)") + android.util.Log.d("AI_TIMING", " SSL Handshake: ~${ssl}ms (~20% of total)") + android.util.Log.d("AI_TIMING", " HTTP Request: ~${request}ms (~5% of total)") + android.util.Log.d("AI_TIMING", " Server Processing: ~${server}ms (~45% of total) ๐Ÿ”ด BIGGEST") + android.util.Log.d("AI_TIMING", " Response Headers: ~${headers}ms (~5% of total)") + android.util.Log.d("AI_TIMING", "") + + if (server > 1000) { + android.util.Log.d("AI_TIMING", "โš ๏ธ WARNING: Server processing took ~${server}ms (>1 second!)") + android.util.Log.d("AI_TIMING", " This is SLOW - backend team should optimize!") + } + } + + android.util.Log.d("AI_TIMING", "๐Ÿ”„ Now downloading HTML content and resources...") + android.util.Log.d("AI_TIMING", "================================================") + android.util.Log.d("AI_TIMING", "") + if (fragment.showLoadingBetweenPages) fragment.showLoading() } + + override fun onLoadResource(view: WebView?, url: String?) { + val currentTime = System.currentTimeMillis() + + // Track first resource load time + if (firstResourceRequestTime == 0L && url != null) { + firstResourceRequestTime = currentTime + android.util.Log.d("AI_TIMING", "๐Ÿ“ฅ First resource request started:") + android.util.Log.d("AI_TIMING", " URL: $url") + } + + // Log main page resources + if (url != null && url == mainPageUrl) { + android.util.Log.d("AI_TIMING", "๐Ÿ“„ Loading main HTML: $url") + } + + // Track resource start time + if (url != null) { + resourceLoadTimes[url] = currentTime + } + } override fun onPageFinished(view: WebView?, url: String?) { + val totalLoadTime = System.currentTimeMillis() - pageLoadStartTime + android.util.Log.d("AI_TIMING", "โœ… STEP 14 DONE: WebView.onPageFinished() - Page loaded!") + android.util.Log.d("AI_TIMING", " Loaded URL: $url") + android.util.Log.d("AI_TIMING", " โฑ๏ธ TOTAL PAGE LOAD TIME: ${totalLoadTime}ms") + android.util.Log.d("AI_TIMING", "") + android.util.Log.d("AI_TIMING", "========================================") + android.util.Log.d("AI_TIMING", "๐ŸŽ‰ AI WEBVIEW FULLY LOADED AND VISIBLE!") + android.util.Log.d("AI_TIMING", "โฑ๏ธ Total time from button click: ${totalLoadTime}ms") + android.util.Log.d("AI_TIMING", "========================================") + fragment.hideLoading() fragment.hideEmptyViewShowWebView() checkWebViewHasError() diff --git a/course/src/main/java/in/testpress/course/fragments/AIChatPdfFragment.kt b/course/src/main/java/in/testpress/course/fragments/AIChatPdfFragment.kt index 25e41e33a..24d29f943 100644 --- a/course/src/main/java/in/testpress/course/fragments/AIChatPdfFragment.kt +++ b/course/src/main/java/in/testpress/course/fragments/AIChatPdfFragment.kt @@ -25,12 +25,21 @@ class AIChatPdfFragment : Fragment() { container: ViewGroup?, savedInstanceState: Bundle? ): View? { - return inflater.inflate(R.layout.ai_pdf_fragment, container, false) + val startTime = System.currentTimeMillis() + android.util.Log.d("AI_TIMING", "๐ŸŸฆ STEP 4: AIChatPdfFragment.onCreateView() STARTED") + + val view = inflater.inflate(R.layout.ai_pdf_fragment, container, false) + + android.util.Log.d("AI_TIMING", "โœ… STEP 4 DONE: AIChatPdfFragment.onCreateView() completed in ${System.currentTimeMillis() - startTime}ms") + return view } override fun onViewCreated(view: View, savedInstanceState: Bundle?) { super.onViewCreated(view, savedInstanceState) + val startTime = System.currentTimeMillis() + android.util.Log.d("AI_TIMING", "๐ŸŸฆ STEP 5: AIChatPdfFragment.onViewCreated() STARTED") + val contentId = requireArguments().getLong(ARG_CONTENT_ID, -1L) val courseId = requireArguments().getLong(ARG_COURSE_ID, -1L) @@ -38,18 +47,30 @@ class AIChatPdfFragment : Fragment() { throw IllegalArgumentException("Required arguments (contentId, courseId) are missing or invalid.") } + android.util.Log.d("AI_TIMING", "๐ŸŸฆ STEP 6: Creating WebViewFragment...") + val webViewCreateStart = System.currentTimeMillis() + val webViewFragment = WebViewFragment() val pdfUrl = getPdfUrl(courseId, contentId) + android.util.Log.d("AI_TIMING", " URL to load: $pdfUrl") webViewFragment.arguments = Bundle().apply { putString(URL_TO_OPEN, pdfUrl) putBoolean(IS_AUTHENTICATION_REQUIRED, true) } + + android.util.Log.d("AI_TIMING", "โœ… STEP 6 DONE: WebViewFragment created in ${System.currentTimeMillis() - webViewCreateStart}ms") + + android.util.Log.d("AI_TIMING", "๐ŸŸฆ STEP 7: Committing WebViewFragment transaction...") + val transactionStart = System.currentTimeMillis() childFragmentManager.beginTransaction() .replace(R.id.aiPdf_view_fragment, webViewFragment) .commit() + + android.util.Log.d("AI_TIMING", "โœ… STEP 7 DONE: WebView transaction committed in ${System.currentTimeMillis() - transactionStart}ms") + android.util.Log.d("AI_TIMING", "โœ… STEP 5 DONE: AIChatPdfFragment.onViewCreated() completed in ${System.currentTimeMillis() - startTime}ms total") } private fun getPdfUrl(courseId: Long, contentId: Long): String { diff --git a/course/src/main/java/in/testpress/course/fragments/DocumentViewerFragment.kt b/course/src/main/java/in/testpress/course/fragments/DocumentViewerFragment.kt index b67ff31d8..7a8253e8b 100644 --- a/course/src/main/java/in/testpress/course/fragments/DocumentViewerFragment.kt +++ b/course/src/main/java/in/testpress/course/fragments/DocumentViewerFragment.kt @@ -114,12 +114,20 @@ class DocumentViewerFragment : BaseContentDetailFragment(), PdfDownloadListener, private fun showAIView() { + val startTime = System.currentTimeMillis() + android.util.Log.d("AI_TIMING", "๐ŸŸฆ STEP 1: showAIView() STARTED at ${startTime}") + if (aiChatFragment == null) { + android.util.Log.d("AI_TIMING", "๐ŸŸฆ STEP 2: Creating AIChatPdfFragment...") + val fragmentCreateStart = System.currentTimeMillis() + aiChatFragment = AIChatPdfFragment() val args = Bundle() args.putLong("contentId", contentId) args.putLong("courseId", content.courseId ?: -1L) aiChatFragment?.arguments = args + + android.util.Log.d("AI_TIMING", "โœ… STEP 2 DONE: Fragment created in ${System.currentTimeMillis() - fragmentCreateStart}ms") } binding.pdfView.visibility = View.GONE @@ -127,9 +135,15 @@ class DocumentViewerFragment : BaseContentDetailFragment(), PdfDownloadListener, binding.askAiFab.visibility = View.GONE binding.aiPdfViewFragment.visibility = View.VISIBLE + android.util.Log.d("AI_TIMING", "๐ŸŸฆ STEP 3: Committing fragment transaction...") + val transactionStart = System.currentTimeMillis() + childFragmentManager.beginTransaction() .replace(R.id.aiPdf_view_fragment, aiChatFragment!!) .commit() + + android.util.Log.d("AI_TIMING", "โœ… STEP 3 DONE: Transaction committed in ${System.currentTimeMillis() - transactionStart}ms") + android.util.Log.d("AI_TIMING", "โœ… showAIView() COMPLETED in ${System.currentTimeMillis() - startTime}ms total") isAIView = true activity?.invalidateOptionsMenu()