今天执行碰到个问题,简单地说就是

appium 切换到 webview 下,在 webview 下执行第二个点击操作时操作时,appium session 去 proxying 到 chromedriver 的 session 时请求无响应。
相关信息如下:
设备:OPPO R7
appium 版本:1.5.3
chromedriver 版本:2.25
client 版本:java_client 4.1
app 内置浏览器内核:据开发说是改为了 TX 的 x5 内核
日志如下(从切换 webview 开始,到最后请求无响应结束的所有日志)

2016-11-02 16:51:48:343 - [debug] [AndroidDriver] from: u0_a384,25454,249,1506648,220112,ffffffff,00000000,S,com.aixuedai.axd
2016-11-02 16:51:48:343 - [debug] [AndroidDriver] returning process name: com.aixuedai.axd
2016-11-02 16:51:48:343 - [debug] [AndroidDriver] Found webviews: ["WEBVIEW_com.aixuedai.axd"]
2016-11-02 16:51:48:343 - [debug] [AndroidDriver] Available contexts: ["NATIVE_APP","WEBVIEW_com.aixuedai.axd"]
2016-11-02 16:51:48:343 - [MJSONWP] Responding to client with driver.getContexts() result: ["NATIVE_APP","WEBVIEW_com....
2016-11-02 16:51:48:343 - [HTTP] <-- GET /wd/hub/session/59646e68-67b3-49d1-b89a-73b075a9113e/contexts 200 226 ms - 113
2016-11-02 16:51:48:359 - [HTTP] --> POST /wd/hub/session/59646e68-67b3-49d1-b89a-73b075a9113e/context {"name":"WEBVIEW_com.aixuedai.axd"}
2016-11-02 16:51:48:359 - [MJSONWP] Calling AppiumDriver.setContext() with args: ["WEBVIEW_com.aixuedai.axd"...
2016-11-02 16:51:48:359 - [debug] [AndroidDriver] Getting a list of available webviews
2016-11-02 16:51:48:359 - [debug] [ADB] Getting connected devices...
2016-11-02 16:51:48:375 - [debug] [ADB] 1 device(s) connected
2016-11-02 16:51:48:375 - [debug] [ADB] Running D:\Tools\android-sdk-windows\platform-tools\adb.exe with args: ["-P",5037,"-s","KZZLQSPNKZGEVWK7","shell","cat","/proc/net/unix"]
2016-11-02 16:51:48:422 - [debug] [AndroidDriver] WEBVIEW_25454 mapped to pid 25454
2016-11-02 16:51:48:422 - [debug] [AndroidDriver] Getting process name for webview
2016-11-02 16:51:48:422 - [debug] [ADB] Getting connected devices...
2016-11-02 16:51:48:437 - [debug] [ADB] 1 device(s) connected
2016-11-02 16:51:48:437 - [debug] [ADB] Running D:\Tools\android-sdk-windows\platform-tools\adb.exe with args: ["-P",5037,"-s","KZZLQSPNKZGEVWK7","shell","ps"]
2016-11-02 16:51:48:547 - [debug] [AndroidDriver] Parsed pid: 25454 pkg: com.aixuedai.axd!
2016-11-02 16:51:48:547 - [debug] [AndroidDriver] from: u0_a384,25454,249,1508984,221296,ffffffff,00000000,S,com.aixuedai.axd
2016-11-02 16:51:48:547 - [debug] [AndroidDriver] returning process name: com.aixuedai.axd
2016-11-02 16:51:48:547 - [debug] [AndroidDriver] Found webviews: ["WEBVIEW_com.aixuedai.axd"]
2016-11-02 16:51:48:547 - [debug] [AndroidDriver] Available contexts: ["NATIVE_APP","WEBVIEW_com.aixuedai.axd"]
2016-11-02 16:51:48:547 - [debug] [AndroidDriver] Connecting to chrome-backed webview context 'WEBVIEW_com.aixuedai.axd'
2016-11-02 16:51:48:547 - [debug] [Chromedriver] Changed state to 'starting'
2016-11-02 16:51:48:625 - [Chromedriver] Set chromedriver binary as: C:\Users\hwb\AppData\Roaming\npm\node_modules\appium\node_modules\appium-android-driver\node_modules\appium-chromedriver\chromedriver\win\chromedriver.exe
2016-11-02 16:51:48:625 - [Chromedriver] Killing any old chromedrivers, running: FOR /F "usebackq tokens=5" %a in (`netstat -nao ^| findstr /R /C:"9515 "`) do (FOR /F "usebackq" %b in (`TASKLIST /FI "PID eq %a" ^| findstr /I chromedriver.exe`) do (IF NOT %b=="" TASKKILL /F /PID %a))
2016-11-02 16:51:48:703 - [Chromedriver] No old chromedrivers seemed to exist
2016-11-02 16:51:48:719 - [Chromedriver] Spawning chromedriver with: C:\Users\hwb\AppData\Roaming\npm\node_modules\appium\node_modules\appium-android-driver\node_modules\appium-chromedriver\chromedriver\win\chromedriver.exe --url-base=wd/hub --port=9515 --adb-port=5037
2016-11-02 16:51:49:063 - [Chromedriver] [STDOUT] Starting ChromeDriver 2.25.426923 (0390b88869384d6eb0d5d09729679f934aab9eed) on port 9515
Only local connections are allowed.
2016-11-02 16:51:49:078 - [JSONWP Proxy] Proxying [GET /status] to [GET http://127.0.0.1:9515/wd/hub/status] with no body
2016-11-02 16:51:49:094 - [JSONWP Proxy] Got response with status 200: "{\"sessionId\":\"\",\"stat...
2016-11-02 16:51:49:094 - [JSONWP Proxy] Proxying [POST /session] to [POST http://127.0.0.1:9515/wd/hub/session] with body: {"desiredCapabilities":{"ch...
2016-11-02 16:51:51:735 - [JSONWP Proxy] Got response with status 200: {"sessionId":"c6856afd440d4...
2016-11-02 16:51:51:751 - [debug] [Chromedriver] Changed state to 'online'
2016-11-02 16:51:51:751 - [MJSONWP] Responding to client with driver.setContext() result: null
2016-11-02 16:51:51:751 - [HTTP] <-- POST /wd/hub/session/59646e68-67b3-49d1-b89a-73b075a9113e/context 200 3396 ms - 76
2016-11-02 16:51:54:783 - [HTTP] --> POST /wd/hub/session/59646e68-67b3-49d1-b89a-73b075a9113e/execute {"script":"document.getElementById('J_go').click()","args":[]}
2016-11-02 16:51:54:783 - [MJSONWP] Driver proxy active, passing request on via HTTP proxy
2016-11-02 16:51:54:783 - [JSONWP Proxy] Proxying [POST /wd/hub/session/59646e68-67b3-49d1-b89a-73b075a9113e/execute] to [POST http://127.0.0.1:9515/wd/hub/session/c6856afd440d4877fdb0c07ee0303108/execute] with body: {"script":"document.getElem...
2016-11-02 16:51:54:970 - [JSONWP Proxy] Got response with status 200: {"sessionId":"c6856afd440d4...
2016-11-02 16:51:54:970 - [JSONWP Proxy] Replacing sessionId c6856afd440d4877fdb0c07ee0303108 with 59646e68-67b3-49d1-b89a-73b075a9113e
2016-11-02 16:51:54:970 - [HTTP] <-- POST /wd/hub/session/59646e68-67b3-49d1-b89a-73b075a9113e/execute 200 197 ms - 76
2016-11-02 16:51:58:018 - [HTTP] --> POST /wd/hub/session/59646e68-67b3-49d1-b89a-73b075a9113e/execute {"script":"document.getElementById('J_Submit').click()","args":[]}
2016-11-02 16:51:58:018 - [MJSONWP] Driver proxy active, passing request on via HTTP proxy
2016-11-02 16:51:58:018 - [JSONWP Proxy] Proxying [POST /wd/hub/session/59646e68-67b3-49d1-b89a-73b075a9113e/execute] to [POST http://127.0.0.1:9515/wd/hub/session/c6856afd440d4877fdb0c07ee0303108/execute] with body: {"script":"document.getElem...

可以看到,执行到最后的

2016-11-02 16:51:58:018 - [JSONWP Proxy] Proxying [POST /wd/hub/session/59646e68-67b3-49d1-b89a-73b075a9113e/execute] to [POST http://127.0.0.1:9515/wd/hub/session/c6856afd440d4877fdb0c07ee0303108/execute] with body: {"script":"document.getElem...

这一步后,就再没有收到相应的 response,日志没有报错,运行的 client 脚本也没报错,一直处于运行状态,相关的 java 代码如下:

//调用封装的切换webvie方法切换到webview模式:
appcomm.switchToWebView(driver);

//webview模式下操作app
jse.executeScript("document.getElementById('J_go').click()");
logger.info("****");       
comm.forceWaiting(3000);
jse.executeScript("document.getElementById('J_Submit').click()");
logger.info("****");

奇怪的是,执行第一步

jse.executeScript("document.getElementById('J_go').click()");

可以正常执行,但是执行第二步

jse.executeScript("document.getElementById('J_Submit').click()");

就无响应。请各位大神指教。

问题更新

等待 5 分钟后,appium 终于排除异常,如下:

2016-11-02 17:26:58:101 - [BaseDriver] Shutting down because we waited 300 seconds for a command
2016-11-02 17:26:58:106 - [debug] [AndroidDriver] Shutting down Android driver
2016-11-02 17:26:58:109 - [Appium] Closing session, cause was 'New Command Timeout of 300 seconds expired. Try customizing the timeout using the 'newCommandTimeout' desired capability'
2016-11-02 17:26:58:110 - [Appium] Removing session 59646e68-67b3-49d1-b89a-73b075a9113e from our master session list
2016-11-02 17:26:58:116 - [debug] [AndroidDriver] Stopping chromedriver for context WEBVIEW_com.aixuedai.axd
2016-11-02 17:26:58:119 - [debug] [Chromedriver] Changed state to 'stopping'
2016-11-02 17:26:58:123 - [JSONWP Proxy] Proxying [DELETE /] to [DELETE http://127.0.0.1:9515/wd/hub/session/c6856afd440d4877fdb0c07ee0303108] with no body
2016-11-02 17:26:58:225 - [MJSONWP] Encountered internal error running command: Error: Could not proxy. Proxy error: New Command Timeout of 300 seconds expired. Try customizing the timeout using the 'newCommandTimeout' desired capability
    at doJwpProxy$ (lib/mjsonwp/mjsonwp.js:329:11)
    at tryCatch (C:\Users\hwb\AppData\Roaming\npm\node_modules\appium\node_modules\babel-runtime\regenerator\runtime.js:67:40)
    at GeneratorFunctionPrototype.invoke [as _invoke] (C:\Users\hwb\AppData\Roaming\npm\node_modules\appium\node_modules\babel-runtime\regenerator\runtime.js:315:22)
    at GeneratorFunctionPrototype.prototype.(anonymous function) [as throw] (C:\Users\hwb\AppData\Roaming\npm\node_modules\appium\node_modules\babel-runtime\regenerator\runtime.js:100:21)
    at GeneratorFunctionPrototype.invoke (C:\Users\hwb\AppData\Roaming\npm\node_modules\appium\node_modules\babel-runtime\regenerator\runtime.js:136:37)
    at process._tickCallback (internal/process/next_tick.js:103:7)
2016-11-02 17:31:58:115 - [Chromedriver] [STDERR] [2409.039][SEVERE]: Timed out receiving message from renderer: 600.000

好了,可以断定就是 proxy 的问题。

依然请教各位大神!


↙↙↙阅读原文可查看相关链接,并与作者交流