Stop_recording_screen is not working since v1.21.0

kim_jaden · November 6, 2021, 2:43am

The http multipart upload method of Stop Screen Recoding is not working since v1.21.0.
It was working well before. (v1.18.3)

client code(java)

driver.stopRecordingScreen(
                AndroidStopScreenRecordingOptions
                        .stopScreenRecordingOptions()
                        .withUploadOptions(
                                ScreenRecordingUploadOptions.uploadOptions()
                                        .withHttpMethod(ScreenRecordingUploadOptions.RequestMethod.POST)
                                        .withRemotePath("http://xxx.com/xxx/upload")));

appium server log

[HTTP] --> POST /wd/hub/session/1af89777-7f82-412b-8aa8-3421374d6537/appium/stop_recording_screen
[HTTP] {"options":{"remotePath":"http://xxx.com/xxx/upload","method":"POST"}}
[debug] [W3C (1af89777)] Calling AppiumDriver.stopRecordingScreen() with args: [{"remotePath":"http://xxx.com/xxx/upload","method":"POST"},"1af89777-7f82-412b-8aa8-3421374d6537"]
[debug] [ADB] Getting IDs of all 'screenrecord' processes
[debug] [ADB] Running '/Users/jaden/Library/Android/sdk/platform-tools/adb -P 5037 -s 261c029e35037ece shell pgrep -f \(\[\[:blank:\]\]\|\^\)screenrecord\(\[\[:blank:\]\]\|\$\)'
[debug] [ADB] Running '/Users/jaden/Library/Android/sdk/platform-tools/adb -P 5037 -s 261c029e35037ece shell kill -2 13156'
[debug] [ADB] Getting IDs of all 'screenrecord' processes
[debug] [ADB] Running '/Users/jaden/Library/Android/sdk/platform-tools/adb -P 5037 -s 261c029e35037ece shell pgrep -f \(\[\[:blank:\]\]\|\^\)screenrecord\(\[\[:blank:\]\]\|\$\)'
[debug] [ADB] Getting IDs of all 'screenrecord' processes
[debug] [ADB] Running '/Users/jaden/Library/Android/sdk/platform-tools/adb -P 5037 -s 261c029e35037ece shell pgrep -f \(\[\[:blank:\]\]\|\^\)screenrecord\(\[\[:blank:\]\]\|\$\)'
[debug] [ADB] Running '/Users/jaden/Library/Android/sdk/platform-tools/adb -P 5037 -s 261c029e35037ece pull /sdcard/4f0d62c0.mp4 /var/folders/ts/1stgb4vx56s6_1ggnlynqsvr0000gn/T/2021105-48445-12gfkb6.ofzli/4f0d62c0.mp4'
[debug] [ADB] Running '/Users/jaden/Library/Android/sdk/platform-tools/adb -P 5037 -s 261c029e35037ece shell rm -rf /sdcard/4f0d62c0.mp4'
[Support] Uploading '/var/folders/ts/1stgb4vx56s6_1ggnlynqsvr0000gn/T/2021105-48445-12gfkb6.ofzli/4f0d62c0.mp4' of 459.88 KB size to 'http://xxx.com/xxx/upload'
[debug] [Support] Performing POST to http://xxx.com/xxx/upload with options (excluding data): {"url":"http://xxx.com/xxx/upload","method":"POST","timeout":5000,"maxContentLength":null,"maxBodyLength":null,"headers":{"Content-Length":470920,"content-type":"multipart/form-data; boundary=--------------------------328415246938466489542414"}}
[debug] [W3C (1af89777)] Encountered internal error running command: Error: timeout of 5000ms exceeded
[debug] [W3C (1af89777)]     at createError (/usr/local/lib/node_modules/appium/node_modules/axios/lib/core/createError.js:16:15)
[debug] [W3C (1af89777)]     at RedirectableRequest.handleRequestTimeout (/usr/local/lib/node_modules/appium/node_modules/axios/lib/adapters/http.js:280:16)
[debug] [W3C (1af89777)]     at RedirectableRequest.emit (events.js:376:20)
[debug] [W3C (1af89777)]     at Timeout._onTimeout (/usr/local/lib/node_modules/appium/node_modules/follow-redirects/index.js:165:12)
[debug] [W3C (1af89777)]     at listOnTimeout (internal/timers.js:555:17)
[debug] [W3C (1af89777)]     at processTimers (internal/timers.js:498:7)
[HTTP] <-- POST /wd/hub/session/1af89777-7f82-412b-8aa8-3421374d6537/appium/stop_recording_screen 500 6471 ms - 549

server(uploading video) log - java, spring

18:18:01.483 [http-nio-8080-exec-1] ERROR o.a.c.c.C.[.[.[.[dispatcherServlet] - Servlet.service() for servlet [dispatcherServlet] in context with path [] threw exception [Request processing failed; nested exception is org.springframework.web.multipart.MultipartException: Failed to parse multipart servlet request; nested exception is java.io.IOException: org.apache.tomcat.util.http.fileupload.impl.IOFileUploadException: Processing of multipart/form-data request failed. Stream ended unexpectedly] with root cause
org.apache.tomcat.util.http.fileupload.MultipartStream$MalformedStreamException: Stream ended unexpectedly
        at org.apache.tomcat.util.http.fileupload.MultipartStream$ItemInputStream.makeAvailable(MultipartStream.java:983)
        at org.apache.tomcat.util.http.fileupload.MultipartStream$ItemInputStream.read(MultipartStream.java:881)
        at java.io.FilterInputStream.read(FilterInputStream.java:133)
        at org.apache.tomcat.util.http.fileupload.util.LimitedInputStream.read(LimitedInputStream.java:132)
        at java.io.FilterInputStream.read(FilterInputStream.java:107)
        at org.apache.tomcat.util.http.fileupload.util.Streams.copy(Streams.java:98)
        at org.apache.tomcat.util.http.fileupload.FileUploadBase.parseRequest(FileUploadBase.java:293)
        at org.apache.catalina.connector.Request.parseParts(Request.java:2870)
        at org.apache.catalina.connector.Request.getParts(Request.java:2772)
        at org.apache.catalina.connector.RequestFacade.getParts(RequestFacade.java:1098)
        at org.springframework.web.multipart.support.StandardMultipartHttpServletRequest.parseRequest(StandardMultipartHttpServletRequest.java:95)
        at org.springframework.web.multipart.support.StandardMultipartHttpServletRequest.<init>(StandardMultipartHttpServletRequest.java:88)
        at org.springframework.web.multipart.support.StandardServletMultipartResolver.resolveMultipart(StandardServletMultipartResolver.java:87)
        at org.springframework.web.servlet.DispatcherServlet.checkMultipart(DispatcherServlet.java:1178)
        at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:1012)
        at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:943)
        at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:1006)
        at org.springframework.web.servlet.FrameworkServlet.doPost(FrameworkServlet.java:909)
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:660)
        at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:883)
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:741)
        at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:231)
        at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
        at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:53)
        at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
        at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
        at org.springframework.web.filter.RequestContextFilter.doFilterInternal(RequestContextFilter.java:100)
        at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119)
        at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
        at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
        at org.springframework.web.filter.FormContentFilter.doFilterInternal(FormContentFilter.java:93)
        at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119)
        at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
        at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
        at org.springframework.web.filter.CharacterEncodingFilter.doFilterInternal(CharacterEncodingFilter.java:201)
        at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119)
        at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
        at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
        at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:202)
        at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:96)
        at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:541)
        at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:139)
        at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:92)
        at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:74)
        at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:343)
        at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:373)
        at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:65)
        at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:868)
        at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1594)
        at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
        at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
        at java.lang.Thread.run(Thread.java:748)

Since v1.21.0, http request body’s stream ended without boundary and received file size might be short in comparison with real file size.
http request body - v1.21.0 (ended without boundary)

----------------------------912052405112153489367376^M
Content-Disposition: form-data; name="file"; filename="0558297b.mp4"^M
Content-Type: video/mp4^M
^M
^@^@^@^Xftypmp42^@^@^@^@isommp42^@^HM�mdat^@^@��e�O��^^�^@^B^B>NNNNNNNNNNNNNNNNNNNNNNNNNN
....
@^@A:^@^@Bs^@^@E^Z^@^@1�^@^@Ba^@

http request body - v1.20.2 (ended with boundary)

----------------------------108704645643769408004555^M
Content-Disposition: form-data; name="file"; filename="d1b476ef.mp4"^M
Content-Type: video/mp4^M
^M
^@^@^@^Xftypmp42^@^@^@^@isommp42^@^F��mdat^@^@��e�O��^^�^@^B^B>NNNNNNNNNNNNNNNNNNNNNNNNNNNNN
....
^@^@^@^A^@^@^@^C^@^@^@^H^@^@^@^A^@^@^@^\stco^@^@^@^@^@^@^@^C^@^@^@ ^@^C�C^@^E�w^M
----------------------------108704645643769408004555--^M

In my case, the file size is 432.70 KB (appium server log) but received size at uploading http server is 432.55 KB(442936 bytes).

mykola-mokhnach · November 6, 2021, 7:14pm

Have you tried the same scenario with the most recent server version or appium@beta?
It could be this is a bug in the axios library itself, which might be fixed with recent patches.

kim_jaden · November 7, 2021, 2:53am

Yes, I’v tried it with v1.21, v1.22, v1.22.1-rc.4(last published), and v1.23.0-beta.0.
But, the results are the same.

mykola-mokhnach · November 7, 2021, 7:45am

I’d say there must be a regression issue in the form-data library that we use to prepare multipart requests. I’ve created a bug report to them: https://github.com/form-data/form-data/issues/518

kim_jaden · November 15, 2021, 8:01am

I didn’t know that “fileFieldName” option was added.
These options were released in Java client v7.4.0. - https://github.com/appium/java-client/releases/tag/v7.4.0
Upgrading client version and adding the “fileFieldName” option solved the problem.
It would be good if this document(https://appium.io/docs/en/commands/device/recording-screen/stop-recording-screen/) is updated.

mykola-mokhnach · November 15, 2021, 8:36am

You are welcome to create a PR yourself and improve the documentation. Unfortunately we don’t have much resources to always maintain it up to date.