improve CDP target injection timing and add discovery diagnostics

res/scripts/client/gui/mods/wotstat_cdp/CDPServer.py

@@ -16,6 +16,13 @@
 class WSClient(WebSocket):
 
   def handle_http_request(self, request):
+    headers = [
+      ('Content-Type', 'application/json'),
+      ('Cache-Control', 'no-store, no-cache, must-revalidate, max-age=0'),
+      ('Pragma', 'no-cache'),
+      ('Expires', '0')
+    ]
+    logger.info("HTTP %s %s" % (request.command, request.path))
     if request.command == 'GET':
       if request.path == '/json/version':
         body = b'''{
@@ -26,14 +33,15 @@ def handle_http_request(self, request):
           "WebKit-Version": "537.36 (@181352)",
           "webSocketDebuggerUrl": "ws://localhost:%d/ws"
         }''' % (self.server.port)
-        return (200, [('Content-Type', 'application/json')], body)
+        return (200, headers, body)
       elif request.path == '/json/list':
 
         items = []
         port = self.server.port
 
         tabs = instance.views.values()
         sortedTabs = sorted(tabs, key=lambda v: v.pageName)
+        logger.info("Serving /json/list with %d CDP targets" % len(sortedTabs))
 
         for view in sortedTabs:
           items.append('''
@@ -49,7 +57,7 @@ def handle_http_request(self, request):
 
         body = ('[%s]' % ','.join(items)).encode('utf-8')
 
-        return (200, [('Content-Type', 'application/json')], body)
+        return (200, headers, body)
 
     return (404, [('Content-Type', 'text/plain; charset=utf-8')], b'Not Found')
 
@@ -113,11 +121,13 @@ def _requestLoop(self, server):
   def viewPopulate(self, view):
     # type: (CDPView) -> None
     self.views[view.pageId] = view
+    logger.info("Registered CDP target %s (%s). Total targets: %d" % (view.pageId, view.pageName, len(self.views)))
 
   def viewDispose(self, view):
     # type: (CDPView) -> None
     if view.pageId in self.views:
       del self.views[view.pageId]
+      logger.info("Disposed CDP target %s (%s). Total targets: %d" % (view.pageId, view.pageName, len(self.views)))
 
   def onViewCommand(self, viewId, command):
     # type: (str, str, typing.Optional[typing.Callable[[typing.Any], None]]) -> None

res/scripts/client/gui/mods/wotstat_cdp/WotstatChromeDevtoolsProtocol.py

@@ -1,3 +1,5 @@
+import BigWorld
+import weakref
 
 from .Logger import Logger, SimpleLoggerBackend
 from .CDPServer import CDPServer
@@ -30,34 +32,136 @@ def __init__(self):
       return
 
     self.tabId = 0
+    self.isDisposed = False
+    self._injectedViews = weakref.WeakKeyDictionary()
+    self._scheduledViews = weakref.WeakKeyDictionary()
+    self._injectRetryCount = 60
 
     self.server = CDPServer(9222)
 
     def onLoading(obj, *args, **kwargs):
       # type: (ViewImpl, Any, Any) -> None
       result = _orig_onLoading(obj, *args, **kwargs)
-
-      className = type(obj).__name__
-      if not resmap.isResMapValidated:
-        logger.error("Resource map is not validated, skipping CDPView injection")
-        return result
-
-      if className == 'CDPView': return result
-      if className == 'MainView': return result
-      if obj.getParentView() and type(obj.getParentView()).__name__ != 'MainView': return result
-
-      print("Injecting CDPView into %s" % className)
+      self._scheduleInject(obj)
+      return result
+
+    ViewImpl._onLoading = onLoading
+
+  def _describeView(self, view):
+    className = type(view).__name__
+    try:
+      parentView = view.getParentView()
+      parentName = type(parentView).__name__ if parentView is not None else 'None'
+    except Exception:
+      parentName = 'Unknown'
+    return '%s[%s]->%s' % (className, hex(id(view)), parentName)
+
+  def _getViewKind(self, view):
+    className = type(view).__name__
+    if className == 'CDPView': return 'skip'
+    if className == 'MainView': return 'skip'
+
+    try:
+      parentView = view.getParentView()
+    except Exception:
+      return 'retry'
+
+    if parentView is None: return 'retry'
+    if type(parentView).__name__ == 'MainView': return 'inject'
+    return 'retry'
+
+  def _getAttemptNumber(self, attemptsLeft):
+    return self._injectRetryCount - attemptsLeft + 1
+
+  def _shouldLogRetry(self, attemptsLeft):
+    attemptNumber = self._getAttemptNumber(attemptsLeft)
+    return attemptNumber <= 3 or attemptNumber % 5 == 0 or attemptsLeft <= 3
+
+  def _scheduleInject(self, view, attemptsLeft=None, delay=0.0):
+    if self.isDisposed: return
+    if view in self._injectedViews: return
+    if view in self._scheduledViews: return
+    if self._getViewKind(view) == 'skip': return
+    if attemptsLeft is None: attemptsLeft = self._injectRetryCount
+    if attemptsLeft == self._injectRetryCount:
+      logger.info("Scheduling CDPView injection for %s" % self._describeView(view))
+
+    self._scheduledViews[view] = True
+
+    def attempt():
+      if self.isDisposed: return
+      self._scheduledViews.pop(view, None)
+      self._injectIfNeeded(view, attemptsLeft)
+
+    BigWorld.callback(delay, attempt)
 
+  def _scheduleRetry(self, view, attemptsLeft):
+    if attemptsLeft <= 0: return
+    nextDelay = self._getRetryDelay(attemptsLeft)
+    if self._shouldLogRetry(attemptsLeft):
+      logger.info("Retrying CDPView injection for %s (attempt %d/%d, next delay %.2fs)" % (
+        self._describeView(view),
+        self._getAttemptNumber(attemptsLeft),
+        self._injectRetryCount,
+        nextDelay
+      ))
+    self._scheduleInject(view, attemptsLeft - 1, nextDelay)
+
+  def _getRetryDelay(self, attemptsLeft):
+    attemptIndex = self._injectRetryCount - attemptsLeft
+    if attemptIndex < 10: return 0.1
+    if attemptIndex < 30: return 0.25
+    return 0.5
+
+  def _injectIfNeeded(self, view, attemptsLeft):
+    if self.isDisposed: return
+    if view in self._injectedViews: return
+
+    viewKind = self._getViewKind(view)
+    if viewKind == 'skip':
+      return
+
+    if viewKind != 'inject':
+      if self._shouldLogRetry(attemptsLeft):
+        logger.info("CDPView injection is waiting for %s because parent view is not ready yet" % self._describeView(view))
+      self._scheduleRetry(view, attemptsLeft)
+      return
+
+    if not resmap.isResMapValidated:
+      if attemptsLeft > 0:
+        if self._shouldLogRetry(attemptsLeft):
+          logger.info("CDPView injection is waiting for %s because resource map is not validated yet" % self._describeView(view))
+        self._scheduleRetry(view, attemptsLeft)
+      else:
+        logger.error("Resource map is not validated, failed to inject CDPView into %s" % type(view).__name__)
+      return
+
+    className = type(view).__name__
+
+    try:
       self.tabId += 1
-      obj.setChildView(
+      pageId = '%s#%d' % (className, self.tabId)
+      logger.info("Injecting CDPView into %s as %s on attempt %d/%d" % (
+        self._describeView(view),
+        pageId,
+        self._getAttemptNumber(attemptsLeft),
+        self._injectRetryCount
+      ))
+      view.setChildView(
         CDPView.viewLayoutID(),
-        CDPView(self.server, className, '%s#%d' % (className, self.tabId))
+        CDPView(self.server, className, pageId)
       )
-
-      return result
-
-    ViewImpl._onLoading = onLoading
+      self._injectedViews[view] = pageId
+    except Exception as e:
+      if attemptsLeft > 0:
+        logger.error("Failed to inject CDPView into %s, retrying: %s" % (className, e))
+        self._scheduleRetry(view, attemptsLeft)
+      else:
+        logger.error("Failed to inject CDPView into %s: %s" % (className, e))
 
   def dispose(self):
+    global _orig_onLoading
+    self.isDisposed = True
+    ViewImpl._onLoading = _orig_onLoading
     logger.info("Stopping WotstatChromeDevtoolsProtocol")
     self.server.dispose()