dryark / stf_ios_support

Central repo to connect and document components/repos needed for IOS stf support
Other
153 stars 65 forks source link

Coordinator startup incomplete - Video stream does not start #39

Closed pespinel closed 4 years ago

pespinel commented 4 years ago

INFO[0000] Process start - video_enabler proc=video_enabler type=proc_start INFO[0000] Process start - device_trigger proc=device_trigger type=proc_start INFO[0000] Process start - stf_provider client_hostname=mac-519802 client_ip=192.168.1.37 proc=stf_provider server_hostname=127.0.0.1 server_ip=127.0.0.1 type=proc_start INFO[0000] New Interface class=0a subclass=00 type=iface_body uuid=5324bbc2322... INFO[0000] New Interface class=02 subclass=0d type=iface_body uuid=5324bbc2322... INFO[0000] New Interface class=ff subclass=fe type=iface_body uuid=5324bbc2322... INFO[0000] New Interface class=06 subclass=01 type=iface_body uuid=5324bbc2322... INFO[0000] Device object created dev_ios_port=9240 dev_name="iPhone Boe" dev_uuid=5324bbc2322... type=devd_create vid_port=8000 vnc_port=5901 wda_port=8100 INFO[0000] Device connected dev_name="iPhone Boe" dev_uuid=5324bbc2322... type=dev_connect INFO[0000] Process start - ffmpeg ops="[-f avfoundation -i iPhone Boe -pixel_format bgr0 -f mjpeg -bsf:v mjpegadump -bsf:v mjpeg2jpeg -r 10 -vsync 2 -nostats pipe:1]" proc=ffmpeg type=proc_start uuid=5324bbc2322... INFO[0000] Process start - mirrorfeed mirrorfeed_bin=bin/mirrorfeed pipe=video_pipes/pipe_8000 port=8000 proc=mirrorfeed tunName=en0 type=proc_start uuid=5324bbc2322... WARN[0000] Process end - ffmpeg proc=ffmpeg type=proc_end uuid=5324bbc2322... INFO[0000] Process start - ffmpeg ops="[-f avfoundation -i iPhone Boe -pixel_format bgr0 -f mjpeg -bsf:v mjpegadump -bsf:v mjpeg2jpeg -r 10 -vsync 2 -nostats pipe:1]" proc=ffmpeg type=proc_start uuid=5324bbc2322...

Captura de pantalla 2020-04-14 a las 18 48 49
nanoscopic commented 4 years ago

A full successful start will contain the log messags "VIdeo - interface available", "Video - first frame", and "Process start - stf_provider". The last log message you see when starting it up fully will be "WDA Running".

In your case it appears to be stuck getting the video to work. Make sure your device is unlocked and on a visible shome screen.

You can also open quicktime player, start a movie recording, and click your ios device from the dropdown next to the recording button to ensure that live video does work streaming from your phone to your osx machine.

pespinel commented 4 years ago

@nanoscopic Yes, i am able to see and record the iPhone screen with QuickTime Player. I have no passcode and the device is unlock in the Springboard.

Captura de pantalla 2020-04-15 a las 9 16 23

pespinel commented 4 years ago

@nanoscopic After waiting for some minutes, this crash report dialog has appeared:

Process: ffmpeg [3242] **Path: /Users/USER/Desktop/*/ffmpeg** Identifier: ffmpeg Version: 0 Code Type: X86-64 (Native) Parent Process: coordinator [2523] Responsible: iTerm2 [1262] User ID: 501 Date/Time: 2020-04-15 10:10:43.651 +0200 OS Version: Mac OS X 10.15.4 (19E287) Report Version: 12

Am i missing some configuration?

nanoscopic commented 4 years ago

There is nothing about ffmpeg that should cause a crash. Besides the "video permission" lines of code the ffmpeg fork is otherwise identical to ffmpeg upstream. I haven't seen it crash before. It often just doesn't work because permissions in OSX are wonky.

What needs to be determined to help you is to figure out where exactly the video streaming is failing. What I have seen, and many others have encountered also, is that often OSX will simply prevent ffmpeg from capturing video frames from the phone, and not give a prompt to allow. Typically rerunning a few times will make a dialog box appear to allow permissions. Have you ever seen the dialog box to allow video permission and accepted it, when running coordinator/stf_ios_support?

Once you have "accepted" that permission it will appear in System Preferences. System Preferences -> Security and Privacy -> Camera. If you are running through iTerm ( as it appears above ) then you should see "iTerm" appear in the list of apps with permission to "your camera".

If iTerm does not appear in that list, then you will not be able to start coordinator/stf_ios_support as it requires camera permission.

There is a utility script tcc.pl in stf_ios_support/util. If you run ./tcc.pl getcamera that will list the internal information about exactly which apps are being allowed to access phone video. The entry on my system looks like this:

S Req = anchor apple generic and identifier "com.googlecode.iterm2" and (certificate leaf[field.1.2.840.113635.100.6.1.9] /* exists */ or certificate 1[field.1.2.840.113635.100.6.2.6] /* exists */ and certificate leaf[field.1.2.840.113635.100.6.1.13] /* exists */ and certificate leaf[subject.OU] = H7V7XYVQ7D)
Client = 'com.googlecode.iterm2'
  Possible Match = /Applications/iTerm.app
  Possible Match Identity = anchor apple generic and identifier "com.googlecode.iterm2" and (certificate leaf[field.1.2.840.113635.100.6.1.9] /* exists */ or certificate 1[field.1.2.840.113635.100.6.2.6] /* exists */ and certificate leaf[field.1.2.840.113635.100.6.1.13] /* exists */ and certificate leaf[subject.OU] = H7V7XYVQ7D)

Try looking in System Preferenes and/or running the utility script.

You can additionally use the utility tcc.pl script to add the permission, but you will first need to disable SIP ( system integrity protection ) on your mac for the script to be able to alter the permissions.

Once you disable SIP ( using csrutil disable in recovery mode ), then you can run ./tcc.pl addcamera [path to iTerm] in order to add camera permission.

If / once you have camera permission there are more things that can be checked after that.

pespinel commented 4 years ago

@nanoscopic iTerm has already permission as i can see when executing the script you mentioned:

CS Req =
Client = 'com.googlecode.iterm2'
  Possible Match = /Applications/iTerm.app
  Possible Match Identity = anchor apple generic and identifier "com.googlecode.iterm2" and (certificate leaf[field.1.2.840.113635.100.6.1.9] /* exists */ or certificate 1[field.1.2.840.113635.100.6.2.6] /* exists */ and certificate leaf[field.1.2.840.113635.100.6.1.13] /* exists */ and certificate leaf[subject.OU] = H7V7XYVQ7D)
[Pablo@mac-519802 util ]$ ./tcc.pl hascamera /Applications/iTerm.app
yes

Have you ever seen the dialog box to allow video permission and accepted it, when running coordinator/stf_ios_support?

No i haven't and i tried with different apps, iTerm and the native terminal from macOS

pespinel commented 4 years ago

@nanoscopic I'm running the "make" command just to ensure that everything is ok and now i'm getting the following error:

/Applications/Xcode.app/Contents/Developer/usr/bin/make -C wda_wrapper
go build  -o ../bin/wda_wrapper .
go: finding module for package github.com/go-cmd/cmd
go: found github.com/go-cmd/cmd in github.com/go-cmd/cmd v1.2.0
# wda_wrapper
./wda_wrapper.go:127:19: syntax error: cannot declare in post statement of for loop
./wda_wrapper.go:179:36: syntax error: unexpected { at end of statement
make[1]: *** [../bin/wda_wrapper] Error 2
make: *** [bin/wda_wrapper] Error 2

I think that this is directly related to this PR: https://github.com/tmobile/stf_ios_support/pull/40 The first time i only run the command make dist but when running the command make i'm getting this error.

nanoscopic commented 4 years ago

@pespinel My bad. I accidentally pushed an incomplete update to wda_wrapper. I have pushed the complete changes and made a few improvements to wda_wrapper beyond that also now. Pull the code again and the wda_wrapper error will go away.

Since you do have the permission for iTerm, than it should not be a permission error that is causing your problem.

Since you can see the video in Quicktime, it is not a problem with the video service on the phone itself. ( sometimes that breaks and the phone needs to be rebooted and/or "Reset Media Services" on the phone )

Since you have "ffmpeg end", I'd reccomend looking at ./view_log -proc ffmpeg. There is definitely an issue where ffmpeg is unable to get the video frames and/or is simply crashing on your system. Since you did have it crash already it is possibly an issue with the way ffmpeg built on your system. I've updated the build configuration to build a much more simplified ffmpeg; that will reduce the time to build for ffmpeg significantly and hopefully avoid build issues you may encounter.

I'd suggest to pull down the new changes,rm stf_ios_support/repos/ffmpeg/ffmpeg then rerun make, to rebuild ffmpeg, and see if that makes a difference.

I have also uploaded a prebuilt ffmpeg to https://livxtrm.com/openstf/ffmpeg.tgz You can grab the prebuilt binary from there. Extract it and place it at stf_ios_support/repos/ffmpeg/ffmpeg and it will be used.

nanoscopic commented 4 years ago

Update: I've further altered the Makefile to use the binary release of ffmpeg build directly. This will save time for all users. https://github.com/nanoscopic/ffmpeg/releases

If you rm stf_ios_support/repos/ffmpeg/ffmpeg and run make again the binary will be downloaded automatically.

pespinel commented 4 years ago

ffmpeg is still crashing even using the build from your repo, this is what i see in the logs:

[Pablo@mac-519802 stf_ios_support (master)]$ ./view_log -proc ffmpeg
ffmpeg version git-2019-11-12-1af3bfaea1 Copyright (c) 2000-2019 the FFmpeg developers
  built with Apple clang version 11.0.0 (clang-1100.0.33.12)
  configuration: --prefix=/usr/local --enable-gpl --disable-nonfree --disable-libx264 --disable-libx265 --disable-libxvid --disable-sdl2 --disable-lzma --disable-doc --disable-htmlpages --disable-manpages --disable-podpages --disable-txtpages --disable-decoders --enable-decoder=rawvideo --disable-decoder=h263 --disable-decoder=h264 --disable-decoder=hevc --disable-decoder=mpeg1video --disable-decoder=mpeg2video --disable-decoder=mpeg4 --disable-encoders --enable-encoder=mjpeg --disable-parsers --disable-muxers --enable-muxer=mjpeg --disable-demuxers --enable-demuxer=rawvideo --disable-protocols --enable-protocol=pipe --disable-filters --enable-filter=scale --disable-network --disable-securetransport --disable-bsfs --enable-bsf=mjpeg2jpeg --enable-bsf=mjpega_dump_header --disable-ffprobe --disable-appkit --disable-iconv --disable-debug
: Input/output error
ffmpeg version git-2019-11-12-1af3bfaea1 Copyright (c) 2000-2019 the FFmpeg developers
  built with Apple clang version 11.0.0 (clang-1100.0.33.12)
  configuration: --prefix=/usr/local --enable-gpl --disable-nonfree --disable-libx264 --disable-libx265 --disable-libxvid --disable-sdl2 --disable-lzma --disable-doc --disable-htmlpages --disable-manpages --disable-podpages --disable-txtpages --disable-decoders --enable-decoder=rawvideo --disable-decoder=h263 --disable-decoder=h264 --disable-decoder=hevc --disable-decoder=mpeg1video --disable-decoder=mpeg2video --disable-decoder=mpeg4 --disable-encoders --enable-encoder=mjpeg --disable-parsers --disable-muxers --enable-muxer=mjpeg --disable-demuxers --enable-demuxer=rawvideo --disable-protocols --enable-protocol=pipe --disable-filters --enable-filter=scale --disable-network --disable-securetransport --disable-bsfs --enable-bsf=mjpeg2jpeg --enable-bsf=mjpega_dump_header --disable-ffprobe --disable-appkit --disable-iconv --disable-debug
: Input/output error
ffmpeg version git-2019-11-12-1af3bfaea1 Copyright (c) 2000-2019 the FFmpeg developers
  built with Apple clang version 11.0.0 (clang-1100.0.33.12)
  configuration: --prefix=/usr/local --enable-gpl --disable-nonfree --disable-libx264 --disable-libx265 --disable-libxvid --disable-sdl2 --disable-lzma --disable-doc --disable-htmlpages --disable-manpages --disable-podpages --disable-txtpages --disable-decoders --enable-decoder=rawvideo --disable-decoder=h263 --disable-decoder=h264 --disable-decoder=hevc --disable-decoder=mpeg1video --disable-decoder=mpeg2video --disable-decoder=mpeg4 --disable-encoders --enable-encoder=mjpeg --disable-parsers --disable-muxers --enable-muxer=mjpeg --disable-demuxers --enable-demuxer=rawvideo --disable-protocols --enable-protocol=pipe --disable-filters --enable-filter=scale --disable-network --disable-securetransport --disable-bsfs --enable-bsf=mjpeg2jpeg --enable-bsf=mjpega_dump_header --disable-ffprobe --disable-appkit --disable-iconv --disable-debug
: Input/output error
pespinel commented 4 years ago

BTW @nanoscopic the make command fails always in this step:

./util/signers.pl sign "E3WXXXXXX" "STF Coordinator.app"
Could not find Mac Developer cert for developer OU E3WXXXXXX
make: *** [STF Coordinator.app] Error 1

The build of the WDA-Runner finish successfully always but it can't build the Coordinator.app even i have set my Team ID in the config.json and I can see the Mac developer cert in Keychain.

pespinel commented 4 years ago

@nanoscopic Any update or any other idea in order to try to fix the error with ffmpeg?

Kous92 commented 4 years ago

@pespinel For the Mac Developer Certificate, I have created one from the Apple Developer website and downloaded, it worked for me. Now, ffmpeg is crashing same as yours.

@nanoscopic Do you think that your binary is suitable for all systems (on macOS Catalina 10.15.4) ?

nanoscopic commented 4 years ago

@pespinel Several users have had issues with the way the "automated" signing works. Eg: it just doesn't work for them. For the moment just remove "app" from the top line of the Makefile, and run the coordinator directly without the app. Eg: use ./run or ./bin/coordinator

@pespinel @Kous92 I don't know why exactly ffmpeg is failing for either of you. The binary I created should work on all systems. It isn't exactly "crashing"; what is failing is the ability to use AVFoundation to get the IOS device video stream.

I am in the process of altering the system to not use ffmpeg in that way. The new method will use a modification of this repo to fetch video instead: https://github.com/danielpaulus/quicktime_video_hack

The new process will be ( once complete ):

  1. Raw h264 video stream ( nalus ) will be pulled from IOS devices using qvh ( quicktime_video_hack )
  2. Those nalus will be passed to ffmpeg ( via ffmpeg C library, not via CLI ffmpeg binary ) for decoding into raw frames ( using accelerated hardware decoding via videotoolbox )
  3. The raw frames will be encoded to jpeg using turbo-jpeg.

The new process avoids the permissions nightmare of AVFoundation IOS device streaming, and also simply just works. The AVFoundation stuff is too flaky and besides failing for some users of the project has failed for myself many times for no clear reason.

The new process also will have the advantage that multiple IOS devices per OSX machine will be supported.

pespinel commented 4 years ago

@nanoscopic I don't want to push you or anything like that but by when will it be ready? Do you want me to help you with something? I can help you developing or testing it when your branch is complete.

I've been checking the QVH and seems legit, it worked for me all the times.

Kous92 commented 4 years ago

@nanoscopic @pespinel I have tried QVH also, it worked very well. Also the quality is very good, it's fluid for screen mirrorring. The other alternative with ios-minicap works also, but it's less fluid.

nanoscopic commented 4 years ago

@Kous92 @pespinel I have just pushed a large update to stf_ios_support that enables an entirely new method of video streaming. It is based on QVH as mentioned. Please give it a try and let me know if it resolves some of your issues ( or even just generally works for you ).

pespinel commented 4 years ago

@nanoscopic I'm getting the following error when running the make command:

[Pablo@mac-519802 stf_ios_support (master)]$ make
/Applications/Xcode.app/Contents/Developer/usr/bin/make -C repos/ios_video_stream
make[1]: Nothing to be done for `all'.
/Applications/Xcode.app/Contents/Developer/usr/bin/make -C repos/h264_to_jpeg
./brewser.pl installdeps brew_deps
jpeg-turbo      => version 2.0.4
nanomsg     => version 1.1.5
zeromq      => version 4.3.2
gcc -g hw_decode.c -I ffmpeg/include -I /opt/libjpeg-turbo/include -L ffmpeg/lib -L/opt/libjpeg-turbo/lib -lavcodec -lavutil -lavformat -lturbojpeg -lswscale -lzmq -lnanomsg -o decode
hw_decode.c:18:10: fatal error: 'turbojpeg.h' file not found
#include <turbojpeg.h>
         ^~~~~~~~~~~~~
1 error generated.
make[1]: *** [decode] Error 1
make: *** [repos/h264_to_jpeg/decode] Error 2
Kous92 commented 4 years ago

@pespinel For this error, on the Makefile, the path to the library is incorrect In /repos/h264_to_jpeg/Makefile, at line 5, replace the line by gcc -g hw_decode.c -I ffmpeg/include -I /usr/local/opt/libjpeg-turbo/include -L ffmpeg/lib -L/usr/local/opt/libjpeg-turbo/lib -lavcodec -lavutil -lavformat -lturbojpeg -lswscale -lzmq -lnanomsg -o decode

It should compile after (the fact that /opt is replaced by /usr/local/opt).

@nanoscopic I tested your new implementation of the video, I found some issues with the Makefile of the ios_video_stream, the target should be this: TARGET = ../../bin/ios_video_stream

I have tried to run with the video activated, but I have this:

INFO[0000] Process start - device_trigger                binary=bin/osx_ios_device_trigger proc=device_trigger type=proc_start
INFO[0000] Process start - stf_ios_provider              binary=/usr/local/opt/node@12/bin/node client_hostname=Mini-de-Mobile-001 client_ip= proc=stf_ios_provider server_hostname="localhost:7100" server_ip=127.0.0.1 type=proc_start
INFO[0000] Process start - video_enabler                 binary=bin/osx_ios_video_enabler proc=video_enabler type=proc_start
INFO[0000] New Interface                                 class=0a subclass=00 type=iface_body uuid=9***
INFO[0000] New Interface                                 class=02 subclass=0d type=iface_body uuid=9***
INFO[0000] New Interface                                 class=ff subclass=fe type=iface_body uuid=9***
INFO[0000] New Interface                                 class=06 subclass=01 type=iface_body uuid=9***
INFO[0000] Device object created                         dev_ios_port=9240 dev_name="iPhone X de Koussaïla" dev_uuid=9*** type=devd_create vid_port=8000 vnc_port=5901 wda_port=8100
INFO[0000] Device connected                              dev_name="iPhone X de Koussaïla" dev_uuid=9*** type=dev_connect
INFO[0000] Process start - ios_video_stream              binary=bin/ios_video_stream port=8000 proc=ios_video_stream pullSpec="tcp://127.0.0.1:7879" pushSpec="tcp://127.0.0.1:7878" tunName=en0 type=proc_start uuid=9***
INFO[0000] Process start - h264_to_jpeg                  binary=bin/decode h264SrcSpec="tcp://127.0.0.1:7878" jpegDestSpec="tcp://127.0.0.1:7879" proc=h264_to_jpeg type=proc_start uuid=9***
WARN[0001] Process end - ios_video_stream                proc=ios_video_stream type=proc_end uuid=9***
INFO[0001] Process start - ios_video_stream              binary=bin/ios_video_stream port=8000 proc=ios_video_stream pullSpec="tcp://127.0.0.1:7879" pushSpec="tcp://127.0.0.1:7878" tunName=en0 type=proc_start uuid=9***
WARN[0001] Process end - ios_video_stream                proc=ios_video_stream type=proc_end uuid=9***
INFO[0003] Process start - ios_video_stream              binary=bin/ios_video_stream port=8000 proc=ios_video_stream pullSpec="tcp://127.0.0.1:7879" pushSpec="tcp://127.0.0.1:7878" tunName=en0 type=proc_start uuid=9***
WARN[0003] Process end - ios_video_stream                proc=ios_video_stream type=proc_end uuid=9***
INFO[0008] Process start - ios_video_stream              binary=bin/ios_video_stream port=8000 proc=ios_video_stream pullSpec="tcp://127.0.0.1:7879" pushSpec="tcp://127.0.0.1:7878" tunName=en0 type=proc_start uuid=9***
WARN[0008] Process end - ios_video_stream                proc=ios_video_stream type=proc_end uuid=9***

Of course, WDA won't run until video is working.

{"iserr":true,"line":"  Serial: 9***","proc":"device_trigger","time":"2020-05-07T16:53:40+02:00"}
{"iserr":true,"line":"  Serial: 9***","proc":"device_trigger","time":"2020-05-07T16:53:40+02:00"}
{"iserr":true,"line":"Debugger listening on ws://127.0.0.1:9230/6bfb4ea5-3c9f-4cc2-b946-8f5b472961f5","proc":"stf_ios_provider","time":"2020-05-07T16:53:40+02:00"}
{"iserr":true,"line":"For help, see: https://nodejs.org/en/docs/inspector","proc":"stf_ios_provider","time":"2020-05-07T16:53:40+02:00"}
{"iserr":true,"line":"  Serial: 9***","proc":"device_trigger","time":"2020-05-07T16:53:40+02:00"}
{"iserr":true,"line":"  Serial: 9***","proc":"device_trigger","time":"2020-05-07T16:53:40+02:00"}
{"iserr":true,"line":"  Name: iPhone","proc":"device_trigger","time":"2020-05-07T16:53:40+02:00"}
{"iserr":true,"line":"  Serial: 9***","proc":"device_trigger","time":"2020-05-07T16:53:40+02:00"}
{"iserr":true,"line":"  Product: iPhone 5-8/X","proc":"device_trigger","time":"2020-05-07T16:53:40+02:00"}
{"iserr":true,"line":"  LocationID: 0x14400000","proc":"device_trigger","time":"2020-05-07T16:53:40+02:00"}
{"iserr":true,"line":"","proc":"device_trigger","time":"2020-05-07T16:53:40+02:00"}
{"iserr":true,"line":"2020-05-07T14:53:40.958Z INF/provider 10216 [*] Subscribing to permanent channel \"bps4hc6qSgmpDkru+lpYuw==\"","proc":"stf_ios_provider","time":"2020-05-07T16:53:40+02:00"}
{"iserr":true,"line":"(node:10216) [DEP0005] DeprecationWarning: Buffer() is deprecated due to security and usability issues. Please use the Buffer.alloc(), Buffer.allocUnsafe(), or Buffer.from() methods instead.","proc":"stf_ios_provider","time":"2020-05-07T16:53:40+02:00"}
{"iserr":true,"line":"2020-05-07T14:53:40.969Z INF/provider 10216 [*] Sending output to \"tcp://127.0.0.1:7270\"","proc":"stf_ios_provider","time":"2020-05-07T16:53:40+02:00"}
{"iserr":true,"line":"2020-05-07T14:53:40.971Z INF/provider 10216 [*] Receiving input from \"tcp://127.0.0.1:7250\"","proc":"stf_ios_provider","time":"2020-05-07T16:53:40+02:00"}
{"line":"Could not find interface en0","proc":"ios_video_stream","time":"2020-05-07T16:53:41+02:00","uuid":"9***"}
{"line":"Could not find interface en0","proc":"ios_video_stream","time":"2020-05-07T16:53:41+02:00","uuid":"9***"}
{"line":"Could not find interface en0","proc":"ios_video_stream","time":"2020-05-07T16:53:43+02:00","uuid":"9***"}
{"line":"Could not find interface en0","proc":"ios_video_stream","time":"2020-05-07T16:53:48+02:00","uuid":"9***"}
pespinel commented 4 years ago

Thanks @Kous92 I was able to run the makecommand and it seems to work now. On the other hand i am not able to install the WDA-Runner when executing the run command although the xcode project is signed:

ERRO[0019] WDA Error coro=zmqpull line="[WDA] 2020-05-07 17:19:30.397 xcodebuild[5156:528060] Error Domain=com.apple.dt.MobileDeviceErrorDomain Code=-402620395 \"Unable to install \"WebDriverAgentRunner-Runner\"\" UserInfo={NSLocalizedDescription=Unable to install \"WebDriverAgentRunner-Runner\", NSUnderlyingError=0x7f90c726d9d0 {Error Domain=com.apple.dt.MobileDeviceErrorDomain Code=-402620395 \"A valid provisioning profile for this executable was not found.\" UserInfo={MobileDeviceErrorCode=(0xE8008015), com.apple.dtdevicekit.stacktrace=(" proc=wdaproxy type=wda_error uuid=532XXXXXXXXXXXXXXXXXX

ERRO[0019] Process end - WDAProxy coro=zmqpull proc=wdaproxy type=wdaproxy_ended uuid=532XXXXXXXXXXXXXXXXXX
Kous92 commented 4 years ago

@pespinel Is ios_video_stream working ? Have you made a fresh install ?

pespinel commented 4 years ago

@Kous92 Yes, it's working for me. I can even see the device control pane on the website but the wda_proxy dies after a few seconds:

INFO[0038] WDA Running coro=zmqpull proc=wdaproxy type=wda_started uuid= 532XXXXXXXXXXXXXXXXXX
ERRO[0038] Process end - WDAProxy coro=zmqpull proc=wdaproxy type=wdaproxy_ended uuid= 532XXXXXXXXXXXXXXXXXX
Captura de pantalla 2020-05-07 a las 17 32 03
nanoscopic commented 4 years ago

@pespinel @Kous92 You also should look at the wda wrapper log. stf_ios_support/logs/wda_wrapper_stderr. I am going to add a way to just launch WDA by itself to the coordinator also to help you more easily diagnose WDA issues without launching everything.

While WDA issues are not really an issue with stf_ios_support itself, I will do what I can to make it easier to further diagnose whatever issues you both are having with WDA.

chriiis78 commented 4 years ago

@nanoscopic For the video problem of @Kous92, do you think Could not find interface en0 is related to the Cisco AnyConnect Secure Mobility Client that is installed on the Mac? Even if VPN connection is disabled?

nanoscopic commented 4 years ago

@chriiis78 Yes specifying a network interface in config.json that does not exist will prevent video streaming from working. You need to specify a network interface there that does exist. It should be an interface of which can be reached from wherever STF server is running.

pespinel commented 4 years ago

@nanoscopic Here it is, thanks for the help!

time="2020-05-07T17:35:57+02:00" level=info line="[WDA] 2020-05-07 17:35:57.535614+0200 WebDriverAgentRunner-Runner[1871:1991409] -[UITestingUITests internalImplementation]: unrecognized selector sent to instance 0x2818b4ff0" type=proc_stdout
time="2020-05-07T17:35:57+02:00" level=info line="[WDA] t =     0.02s     Assertion Failure: <unknown>:0: failed: caught \"NSInvalidArgumentException\", \"-[UITestingUITests internalImplementation]: unrecognized selector sent to instance 0x2818b4ff0\"" type=proc_stdout
time="2020-05-07T17:35:57+02:00" level=info line="[WDA] (" type=proc_stdout
time="2020-05-07T17:35:57+02:00" level=info line="[WDA] 0   CoreFoundation                      0x00000001a4d1aa5c 1B9B1E61-8CB4-3903-9870-402C3DE959BB + 1227356" type=proc_stdout
time="2020-05-07T17:35:57+02:00" level=info line="[WDA] 1   libobjc.A.dylib                     0x00000001a4a41fa4 objc_exception_throw + 56" type=proc_stdout
time="2020-05-07T17:35:57+02:00" level=info line="[WDA] 2   CoreFoundation                      0x00000001a4c1e5a8 1B9B1E61-8CB4-3903-9870-402C3DE959BB + 193960" type=proc_stdout
time="2020-05-07T17:35:57+02:00" level=info line="[WDA] 3   CoreFoundation                      0x00000001a4d1eaf4 1B9B1E61-8CB4-3903-9870-402C3DE959BB + 1243892" type=proc_stdout
time="2020-05-07T17:35:57+02:00" level=info line="[WDA] 4   CoreFoundation                      0x00000001a4d20a7c _CF_forwarding_prep_0 + 92" type=proc_stdout
time="2020-05-07T17:35:57+02:00" level=info line="[WDA] 5   WebDriverAgentLib                   0x00000001022585b8 -[FBFailureProofTestCase setUp] + 136" type=proc_stdout
time="2020-05-07T17:35:57+02:00" level=info line="[WDA] 6   XCTest                              0x0000000101012c88 __48-[XCTestCase _performSetUpSequenceWithSelector:]_block_invoke_2 + 492" type=proc_stdout
time="2020-05-07T17:35:57+02:00" level=info line="[WDA] 7   XCTest                              0x00000001010680d8 +[XCTestCase(Failures) performFailableBlock:testCase:testCaseRun:shouldInterruptTest:] + 84" type=proc_stdout
time="2020-05-07T17:35:57+02:00" level=info line="[WDA] 8   XCTest                              0x0000000101067fdc -[XCTestCase(Failures) _performTurningExceptionsIntoFailuresInterruptAfterHandling:block:] + 132" type=proc_stdout
time="2020-05-07T17:35:57+02:00" level=info line="[WDA] 9   XCTest                              0x0000000101012a7c __48-[XCTestCase _performSetUpSequenceWithSelector:]_block_invoke + 116" type=proc_stdout
time="2020-05-07T17:35:57+02:00" level=info line="[WDA] 10  XCTest                              0x0000000101079d7c -[XCTContext _runActivityNamed:type:block:] + 248" type=proc_stdout
time="2020-05-07T17:35:57+02:00" level=info line="[WDA] 11  XCTest                              0x000000010101b480 -[XCTestCase startActivityWithTitle:type:block:] + 200" type=proc_stdout
time="2020-05-07T17:35:57+02:00" level=info line="[WDA] 12  XCTest                              0x000000010101b630 -[XCTestCase startActivityWithTitle:block:] + 72" type=proc_stdout
time="2020-05-07T17:35:57+02:00" level=info line="[WDA] 13  XCTest                              0x00000001010129f8 -[XCTestCase _performSetUpSequenceWithSelector:] + 108" type=proc_stdout
time="2020-05-07T17:35:57+02:00" level=info line="[WDA] 14  XCTest                              0x0000000101010d68 -[XCTestCase invokeTest] + 728" type=proc_stdout
time="2020-05-07T17:35:57+02:00" level=info line="[WDA] 15  XCTest                              0x00000001010128b8 __26-[XCTestCase performTest:]_block_invoke_2 + 44" type=proc_stdout
time="2020-05-07T17:35:57+02:00" level=info line="[WDA] 16  XCTest                              0x00000001010680d8 +[XCTestCase(Failures) performFailableBlock:testCase:testCaseRun:shouldInterruptTest:] + 84" type=proc_stdout
time="2020-05-07T17:35:57+02:00" level=info line="[WDA] 17  XCTest                              0x0000000101067fdc -[XCTestCase(Failures) _performTurningExceptionsIntoFailuresInterruptAfterHandling:block:] + 132" type=proc_stdout
time="2020-05-07T17:35:57+02:00" level=info line="[WDA] 18  XCTest                              0x00000001010127f0 __26-[XCTestCase performTest:]_block_invoke.366 + 96" type=proc_stdout
time="2020-05-07T17:35:57+02:00" level=info line="[WDA] 19  XCTest                              0x000000010107a48c +[XCTContext runInContextForTestCase:block:] + 212" type=proc_stdout
time="2020-05-07T17:35:57+02:00" level=info line="[WDA] 20  XCTest                              0x00000001010120dc -[XCTestCase performTest:] + 540" type=proc_stdout
time="2020-05-07T17:35:57+02:00" level=info line="[WDA] 21  XCTest                              0x000000010105586c -[XCTest runTest] + 60" type=proc_stdout
time="2020-05-07T17:35:57+02:00" level=info line="[WDA] 22  XCTest                              0x000000010100c5c8 __27-[XCTestSuite performTest:]_block_invoke + 268" type=proc_stdout
time="2020-05-07T17:35:57+02:00" level=info line="[WDA] 23  XCTest                              0x000000010100be58 __59-[XCTestSuite _performProtectedSectionForTest:testSection:]_block_invoke + 40" type=proc_stdout
time="2020-05-07T17:35:57+02:00" level=info line="[WDA] 24  XCTest                              0x000000010107a48c +[XCTContext runInContextForTestCase:block:] + 212" type=proc_stdout
time="2020-05-07T17:35:57+02:00" level=info line="[WDA] 25  XCTest                              0x000000010100be00 -[XCTestSuite _performProtectedSectionForTest:testSection:] + 156" type=proc_stdout
time="2020-05-07T17:35:57+02:00" level=info line="[WDA] 26  XCTest                              0x000000010100c150 -[XCTestSuite performTest:] + 320" type=proc_stdout
time="2020-05-07T17:35:57+02:00" level=info line="[WDA] 27  XCTest                              0x000000010105586c -[XCTest runTest] + 60" type=proc_stdout
time="2020-05-07T17:35:57+02:00" level=info line="[WDA] 28  XCTest                              0x000000010100c5c8 __27-[XCTestSuite performTest:]_block_invoke + 268" type=proc_stdout
time="2020-05-07T17:35:57+02:00" level=info line="[WDA] 29  XCTest                              0x000000010100be58 __59-[XCTestSuite _performProtectedSectionForTest:testSection:]_block_invoke + 40" type=proc_stdout
time="2020-05-07T17:35:57+02:00" level=info line="[WDA] 30  XCTest                              0x000000010107a48c +[XCTContext runInContextForTestCase:block:] + 212" type=proc_stdout
time="2020-05-07T17:35:57+02:00" level=info line="[WDA] 31  XCTest                              0x000000010100be00 -[XCTestSuite _performProtectedSectionForTest:testSection:] + 156" type=proc_stdout
time="2020-05-07T17:35:57+02:00" level=info line="[WDA] 32  XCTest                              0x000000010100c150 -[XCTestSuite performTest:] + 320" type=proc_stdout
time="2020-05-07T17:35:57+02:00" level=info line="[WDA] 33  XCTest                              0x000000010105586c -[XCTest runTest] + 60" type=proc_stdout
time="2020-05-07T17:35:57+02:00" level=info line="[WDA] 34  XCTest                              0x000000010100c5c8 __27-[XCTestSuite performTest:]_block_invoke + 268" type=proc_stdout
time="2020-05-07T17:35:57+02:00" level=info line="[WDA] 35  XCTest                              0x000000010100be58 __59-[XCTestSuite _performProtectedSectionForTest:testSection:]_block_invoke + 40" type=proc_stdout
time="2020-05-07T17:35:57+02:00" level=info line="[WDA] 36  XCTest                              0x000000010107a48c +[XCTContext runInContextForTestCase:block:] + 212" type=proc_stdout
time="2020-05-07T17:35:57+02:00" level=info line="[WDA] 37  XCTest                              0x000000010100be00 -[XCTestSuite _performProtectedSectionForTest:testSection:] + 156" type=proc_stdout
time="2020-05-07T17:35:57+02:00" level=info line="[WDA] 38  XCTest                              0x000000010100c150 -[XCTestSuite performTest:] + 320" type=proc_stdout
time="2020-05-07T17:35:57+02:00" level=info line="[WDA] 39  XCTest                              0x000000010105586c -[XCTest runTest] + 60" type=proc_stdout
time="2020-05-07T17:35:57+02:00" level=info line="[WDA] 40  XCTest                              0x000000010108c5f0 __44-[XCTTestRunSession runTestsAndReturnError:]_block_invoke + 176" type=proc_stdout
time="2020-05-07T17:35:57+02:00" level=info line="[WDA] 41  XCTest                              0x000000010108c6f0 __44-[XCTTestRunSession runTestsAndReturnError:]_block_invoke.100 + 108" type=proc_stdout
time="2020-05-07T17:35:57+02:00" level=info line="[WDA] 42  XCTest                              0x0000000101026354 -[XCTestObservationCenter _observeTestExecutionForBlock:] + 588" type=proc_stdout
time="2020-05-07T17:35:57+02:00" level=info line="[WDA] 43  XCTest                              0x000000010108c388 -[XCTTestRunSession runTestsAndReturnError:] + 592" type=proc_stdout
time="2020-05-07T17:35:57+02:00" level=info line="[WDA] 44  XCTest                              0x0000000100ff0bbc -[XCTestDriver runTestsAndReturnError:] + 428" type=proc_stdout
time="2020-05-07T17:35:57+02:00" level=info line="[WDA] 45  XCTest                              0x0000000101076424 _XCTestMain + 2396" type=proc_stdout
time="2020-05-07T17:35:57+02:00" level=info line="[WDA] 46  WebDriverAgentRunner-Runner         0x0000000100fd3818 -[_XCTRunnerAppDelegate applicationWillResignActive:] + 0" type=proc_stdout
time="2020-05-07T17:35:57+02:00" level=info line="[WDA] 47  WebDriverAgentRunner-Runner         0x0000000100fd3720 _XCTRunnerRunTests + 0" type=proc_stdout
time="2020-05-07T17:35:57+02:00" level=info line="[WDA] 48  CoreFoundation                      0x00000001a4c98834 1B9B1E61-8CB4-3903-9870-402C3DE959BB + 694324" type=proc_stdout
time="2020-05-07T17:35:57+02:00" level=info line="[WDA] 49  CoreFoundation                      0x00000001a4c97fd4 1B9B1E61-8CB4-3903-9870-402C3DE959BB + 692180" type=proc_stdout
time="2020-05-07T17:35:57+02:00" level=info line="[WDA] 50  CoreFoundation                      0x00000001a4c93250 1B9B1E61-8CB4-3903-9870-402C3DE959BB + 672336" type=proc_stdout
time="2020-05-07T17:35:57+02:00" level=info line="[WDA] 51  CoreFoundation                      0x00000001a4c92adc CFRunLoopRunSpecific + 464" type=proc_stdout
time="2020-05-07T17:35:57+02:00" level=info line="[WDA] 52  GraphicsServices                    0x00000001aec18328 GSEventRunModal + 104" type=proc_stdout
time="2020-05-07T17:35:57+02:00" level=info line="[WDA] 53  UIKitCore                           0x00000001a8d8dae0 UIApplicationMain + 1936" type=proc_stdout
time="2020-05-07T17:35:57+02:00" level=info line="[WDA] 54  WebDriverAgentRunner-Runner         0x0000000100fd39e4 main + 192" type=proc_stdout
time="2020-05-07T17:35:57+02:00" level=info line="[WDA] 55  libdyld.dylib                       0x00000001a4b1c360 2E3F4750-8B67-398B-8530-8417651B1718 + 4960" type=proc_stdout
time="2020-05-07T17:35:57+02:00" level=info line="[WDA] )" type=proc_stdout
time="2020-05-07T17:35:57+02:00" level=info line="[WDA] t =     0.02s Tear Down" type=proc_stdout
time="2020-05-07T17:35:57+02:00" level=info line="[WDA] Test Case '-[UITestingUITests testRunner]' failed (0.023 seconds)." type=proc_stdout
time="2020-05-07T17:35:57+02:00" level=info line="[WDA] Test Suite 'UITestingUITests' failed at 2020-05-07 17:35:57.556." type=proc_stdout
time="2020-05-07T17:35:57+02:00" level=info line="[WDA] Executed 1 test, with 1 failure (1 unexpected) in 0.023 (0.091) seconds" type=proc_stdout
time="2020-05-07T17:35:57+02:00" level=info line="[WDA] Test Suite 'WebDriverAgentRunner.xctest' failed at 2020-05-07 17:35:57.558." type=proc_stdout
time="2020-05-07T17:35:57+02:00" level=info line="[WDA] Executed 1 test, with 1 failure (1 unexpected) in 0.023 (0.094) seconds" type=proc_stdout
time="2020-05-07T17:35:57+02:00" level=info line="[WDA] Test Suite 'WebDriverAgentLib.framework' started at 2020-05-07 17:35:57.559" type=proc_stdout
time="2020-05-07T17:35:57+02:00" level=info line="[WDA] Test Suite 'WebDriverAgentLib.framework' passed at 2020-05-07 17:35:57.560." type=proc_stdout
time="2020-05-07T17:35:57+02:00" level=info line="[WDA] Executed 0 tests, with 0 failures (0 unexpected) in 0.000 (0.001) seconds" type=proc_stdout
time="2020-05-07T17:35:57+02:00" level=info line="[WDA] Test Suite 'All tests' failed at 2020-05-07 17:35:57.561." type=proc_stdout
time="2020-05-07T17:35:57+02:00" level=info line="[WDA] Executed 1 test, with 1 failure (1 unexpected) in 0.023 (0.098) seconds" type=proc_stdout
time="2020-05-07T17:35:57+02:00" level=info line="[WDA] 2020-05-07 17:35:57.639 xcodebuild[8768:556156] [MT] IDETestOperationsObserverDebug: 3.980 elapsed -- Testing started completed." type=proc_stdout
time="2020-05-07T17:35:57+02:00" level=info line="[WDA] 2020-05-07 17:35:57.639 xcodebuild[8768:556156] [MT] IDETestOperationsObserverDebug: 0.000 sec, +0.000 sec -- start" type=proc_stdout
time="2020-05-07T17:35:57+02:00" level=info line="[WDA] 2020-05-07 17:35:57.639 xcodebuild[8768:556156] [MT] IDETestOperationsObserverDebug: 3.980 sec, +3.980 sec -- end" type=proc_stdout
time="2020-05-07T17:35:57+02:00" level=info line="[WDA] " type=proc_stdout
time="2020-05-07T17:35:57+02:00" level=info line="[WDA] Test session results, code coverage, and logs:" type=proc_stdout
time="2020-05-07T17:35:57+02:00" level=info line="[WDA] /Users/Pablo/Library/Developer/Xcode/DerivedData/temporary-exixulcpbqlcbjecfvnsgzdrecgh/Logs/Test/Test-Transient Testing-2020.05.07_17-35-53-+0200.xcresult" type=proc_stdout
time="2020-05-07T17:35:57+02:00" level=info line="[WDA] " type=proc_stdout
time="2020-05-07T17:35:57+02:00" level=info line="[WDA] Failing tests:" type=proc_stdout
time="2020-05-07T17:35:57+02:00" level=info line="[WDA] WebDriverAgentRunner:" type=proc_stdout
time="2020-05-07T17:35:57+02:00" level=info line="[WDA] -[UITestingUITests testRunner]" type=proc_stdout
time="2020-05-07T17:35:57+02:00" level=info line="[WDA] " type=proc_stdout
time="2020-05-07T17:35:57+02:00" level=info line="[WDA] ** TEST EXECUTE FAILED **" type=proc_stdout
pespinel commented 4 years ago

@pespinel @Kous92 You also should look at the wda wrapper log. stf_ios_support/logs/wda_wrapper_stderr. I am going to add a way to just launch WDA by itself to the coordinator also to help you more easily diagnose WDA issues without launching everything.

While WDA issues are not really an issue with stf_ios_support itself, I will do what I can to make it easier to further diagnose whatever issues you both are having with WDA.

@nanoscopic I don't think that this error is specifically related to the WDA itself. I can run all the tests correctly with the HEAD of master of the official WDA repo. But i'm getting this error when running from the cloned repo of stf_ios_support. I've tried to enable hardened runtime and disable runtime validation of third party libraries without success. Do you have any idea in mind? Thanks

nanoscopic commented 4 years ago

If the "official" WDA ( I assume you mean the Appium fork of the abandoned Facebook repo ) works, then you can use that. The only difference between my fork and the Appium version is a slight patch for clicking on the main system screen.

Please clarify what you mean by "official" WDA; since there is no such thing any more.

The patch is this: https://github.com/nanoscopic/WebDriverAgent/commit/a46fd851ab7e55b973001315ec894e245cffc735

Reviewing the changes since I forked; I don't see anything particular that would "fix" it compared to my fork.

Looks similar to upstream bug here: https://github.com/appium/appium/issues/13274 , but that is quite old and before I forked.

When does the error above occur? On initial startup? Or only after attempting to interact with the device by clicking or hitting buttons in STF?

pespinel commented 4 years ago

@nanoscopic Yes, the one bundled with Appium: https://github.com/appium/WebDriverAgent

As you can see, with this repo all the tests finish successfully but i don't know how to point stf_ios_support to this WDA

Captura de pantalla 2020-05-09 a las 20 52 07

When does the error above occur? On initial startup? Or only after attempting to interact with the device by clicking or hitting buttons in STF?

The error occurs on startup, WDAProxy starts and ends immediately after getting the test error:

INFO[0038] WDA Running coro=zmqpull proc=wdaproxy type=wda_started uuid= 532XXXXXXXXXXXXXXXXXX
ERRO[0038] Process end - WDAProxy coro=zmqpull proc=wdaproxy type=wdaproxy_ended uuid= 532XXXXXXXXXXXXXXXXXX
pespinel commented 4 years ago

@nanoscopic I copied all the files from the WDA repo into repos/WebDriverAgent, and also i compiled it, run all the tests and copied all of this into bin/wda. Now wda-proxy is not crashing on startup:

[Pablo@mac-519802 stf_ios_support (master ✗)]$ ./run
INFO[0000] Process start - device_trigger                binary=bin/osx_ios_device_trigger proc=device_trigger type=proc_start
INFO[0000] Process start - video_enabler                 binary=bin/osx_ios_video_enabler proc=video_enabler type=proc_start
INFO[0000] Process start - stf_ios_provider              binary=/usr/local/opt/node@12/bin/node client_hostname=mac-519802 client_ip=192.168.1.106 proc=stf_ios_provider server_hostname=127.0.0.1 server_ip=127.0.0.1 type=proc_start
INFO[0000] New Interface                                 class=0a subclass=00 type=iface_body uuid= 532XXXXXXXXXXXXXXXXXX
INFO[0000] New Interface                                 class=02 subclass=0d type=iface_body uuid= 532XXXXXXXXXXXXXXXXXX
INFO[0000] New Interface                                 class=ff subclass=fe type=iface_body uuid= 532XXXXXXXXXXXXXXXXXX
INFO[0000] New Interface                                 class=06 subclass=01 type=iface_body uuid= 532XXXXXXXXXXXXXXXXXX
INFO[0000] Device object created                         dev_ios_port=9240 dev_name="iPhone Boe" dev_uuid= 532XXXXXXXXXXXXXXXXXX type=devd_create vid_port=8000 vnc_port=5901 wda_port=8100
INFO[0000] Device connected                              dev_name="iPhone Boe" dev_uuid=5324bbc232232018a2bf6a6b999aba37202043ab type=dev_connect
INFO[0000] Process start - ios_video_stream              binary=bin/ios_video_stream port=8000 proc=ios_video_stream pullSpec="tcp://127.0.0.1:7879" pushSpec="tcp://127.0.0.1:7878" tunName=en0 type=proc_start uuid= 532XXXXXXXXXXXXXXXXXX
INFO[0000] Process start - h264_to_jpeg                  binary=bin/decode h264SrcSpec="tcp://127.0.0.1:7878" jpegDestSpec="tcp://127.0.0.1:7879" proc=h264_to_jpeg type=proc_start uuid= 532XXXXXXXXXXXXXXXXXX
WARN[0000] Process end - ios_video_stream                proc=ios_video_stream type=proc_end uuid= 532XXXXXXXXXXXXXXXXXX
INFO[0000] Process start - ios_video_stream              binary=bin/ios_video_stream port=8000 proc=ios_video_stream pullSpec="tcp://127.0.0.1:7879" pushSpec="tcp://127.0.0.1:7878" tunName=en0 type=proc_start uuid= 532XXXXXXXXXXXXXXXXXX
WARN[0000] Process end - ios_video_stream                proc=ios_video_stream type=proc_end uuid=5324bbc232232018a2bf6a6b999aba37202043ab
INFO[0002] Process start - ios_video_stream              binary=bin/ios_video_stream port=8000 proc=ios_video_stream pullSpec="tcp://127.0.0.1:7879" pushSpec="tcp://127.0.0.1:7878" tunName=en0 type=proc_start uuid= 532XXXXXXXXXXXXXXXXXX
WARN[0002] Process end - ios_video_stream                proc=ios_video_stream type=proc_end uuid= 532XXXXXXXXXXXXXXXXXX
INFO[0004] New Interface                                 class=06 subclass=01 type=iface_body uuid= 532XXXXXXXXXXXXXXXXXX
INFO[0004] New Interface                                 class=ff subclass=2a type=iface_body uuid= 532XXXXXXXXXXXXXXXXXX
INFO[0004] Video - interface available                   dev_name="iPhone Boe" dev_uuid= 532XXXXXXXXXXXXXXXXXX type=vid_interface
INFO[0004] New Interface                                 class=ff subclass=fe type=iface_body uuid= 532XXXXXXXXXXXXXXXXXX
INFO[0007] Process start - WDAProxy                      coro=zmqpull proc=wdaproxy type=wdaproxy_started uuid= 532XXXXXXXXXXXXXXXXXX
INFO[0007] Process start - ios_video_stream              binary=bin/ios_video_stream port=8000 proc=ios_video_stream pullSpec="tcp://127.0.0.1:7879" pushSpec="tcp://127.0.0.1:7878" tunName=en0 type=proc_start uuid= 532XXXXXXXXXXXXXXXXXX
INFO[0010] Process start - stf_device_ios                binary=/usr/local/opt/node@12/bin/node client_ip=192.168.1.106 device_name="iPhone Boe" node_port=9240 proc=stf_device_ios server_host=127.0.0.1 server_ip=127.0.0.1 stream_height=0 stream_width=0 type=proc_start uuid= 532XXXXXXXXXXXXXXXXXX video_port=8000 vnc_scale=2
INFO[0016] WDA Running                                   coro=zmqpull proc=wdaproxy type=wda_started uuid= 532XXXXXXXXXXXXXXXXXX

On the other hand, I can't control the device from the control pane. Taking a look at the wdaproxy logs i can see that there is no session (null)

[11:51:40] 404 POST /session/null/wda/tap/0 (127.0.0.1) 17.58ms

And the wda logs:

Req URI: /session/null/wda/tap/0
{
  "x": 178.14982509613037,
  "y": 544.3466987609863
}
Response to URI: /session/null/wda/tap/0
{
  "value" : {
    "error" : "invalid session id",
    "message" : "Session does not exist",
    "traceback" : "(\n\t0   CoreFoundation                      0x00000001b07d5604 409609CD-8410-38E1-BA5D-BDED609D2018 + 1222148\n\t1   libobjc.A.dylib                     0x00000001b04f7bcc objc_exception_throw + 56\n\t2   CoreFoundation                      0x00000001b06da9e8 409609CD-8410-38E1-BA5D-BDED609D2018 + 195048\n\t3   WebDriverAgentLib                   0x0000000104b26f44 -[FBRoute raiseNoSessionException] + 120\n\t4   WebDriverAgentLib                   0x0000000104b26e5c -[FBRoute decorateRequest:] + 300\n\t5   WebDriverAgentLib                   0x0000000104b261ac -[FBRoute_TargetAction mountRequest:intoResponse:] + 104\n\t6   WebDriverAgentLib                   0x0000000104b0fe10 __37-[FBWebServer registerRouteHandlers:]_block_invoke + 492\n\t7   RoutingHTTPServer                   0x0000000104c324e0 -[RoutingHTTPServer handleRoute:withRequest:response:] + 144\n\t8   RoutingHTTPServer                   0x0000000104c32ca0 __72-[RoutingHTTPServer routeMethod:withPath:parameters:request:connection:]_block_invoke + 44\n\t9   libdispatch.dylib                   0x00000001b049b524 5A83D0CF-8FB9-3727-8A32-012D20A47EC8 + 374052\n\t10  libdispatch.dylib                   0x00000001b044e180 5A83D0CF-8FB9-3727-8A32-012D20A47EC8 + 57728\n\t11  libdispatch.dylib                   0x00000001b049b524 5A83D0CF-8FB9-3727-8A32-012D20A47EC8 + 374052\n\t12  libdispatch.dylib                   0x00000001b044d5b4 5A83D0CF-8FB9-3727-8A32-012D20A47EC8 + 54708\n\t13  CoreFoundation                      0x00000001b0753748 409609CD-8410-38E1-BA5D-BDED609D2018 + 689992\n\t14  CoreFoundation                      0x00000001b074e61c 409609CD-8410-38E1-BA5D-BDED609D2018 + 669212\n\t15  CoreFoundation                      0x00000001b074dc34 CFRunLoopRunSpecific + 424\n\t16  Foundation                          0x00000001b0a90bcc 1A46239D-F2FC-34B6-95BC-9F38869F0C85 + 31692\n\t17  WebDriverAgentLib                   0x0000000104b0e844 -[FBWebServer startServing] + 440\n\t18  WebDriverAgentRunner                0x000000010489fbac -[UITestingUITests testRunner] + 116\n\t19  CoreFoundation                      0x00000001b07db760 409609CD-8410-38E1-BA5D-BDED609D2018 + 1247072\n\t20  CoreFoundation                      0x00000001b06acb40 409609CD-8410-38E1-BA5D-BDED609D2018 + 6976\n\t21  XCTest                              0x00000001031f55f4 __24-[XCTestCase invokeTest]_block_invoke_3 + 52\n\t22  XCTest                              0x00000001031f55a4 __24-[XCTestCase invokeTest]_block_invoke_2 + 312\n\t23  XCTest                              0x00000001032653c0 -[XCTMemoryChecker _assertInvalidObjectsDeallocatedAfterScope:] + 68\n\t24  XCTest                              0x00000001031fffe0 -[XCTestCase assertInvalidObjectsDeallocatedAfterScope:] + 112\n\t25  XCTest                              0x00000001031f543c __24-[XCTestCase invokeTest]_block_invoke.206 + 200\n\t26  XCTest                              0x000000010324c0d8 +[XCTestCase(Failures) performFailableBlock:testCase:testCaseRun:shouldInterruptTest:] + 84\n\t27  XCTest                              0x000000010324bfdc -[XCTestCase(Failures) _performTurningExceptionsIntoFailuresInterruptAfterHandling:block:] + 132\n\t28  XCTest                              0x00000001031f4ef0 -[XCTestCase invokeTest] + 1120\n\t29  XCTest                              0x00000001031f68b8 __26-[XCTestCase performTest:]_block_invoke_2 + 44\n\t30  XCTest                              0x000000010324c0d8 +[XCTestCase(Failures) performFailableBlock:testCase:testCaseRun:shouldInterruptTest:] + 84\n\t31  XCTest                              0x000000010324bfdc -[XCTestCase(Failures) _performTurningExceptionsIntoFailuresInterruptAfterHandling:block:] + 132\n\t32  XCTest                              0x00000001031f67f0 __26-[XCTestCase performTest:]_block_invoke.366 + 96\n\t33  XCTest                              0x000000010325e48c +[XCTContext runInContextForTestCase:block:] + 212\n\t34  XCTest                              0x00000001031f60dc -[XCTestCase performTest:] + 540\n\t35  XCTest                              0x000000010323986c -[XCTest runTest] + 60\n\t36  XCTest                              0x00000001031f05c8 __27-[XCTestSuite performTest:]_block_invoke + 268\n\t37  XCTest                              0x00000001031efe58 __59-[XCTestSuite _performProtectedSectionForTest:testSection:]_block_invoke + 40\n\t38  XCTest                              0x000000010325e48c +[XCTContext runInContextForTestCase:block:] + 212\n\t39  XCTest                              0x00000001031efe00 -[XCTestSuite _performProtectedSectionForTest:testSection:] + 156\n\t40  XCTest                              0x00000001031f0150 -[XCTestSuite performTest:] + 320\n\t41  XCTest                              0x000000010323986c -[XCTest runTest] + 60\n\t42  XCTest                              0x00000001031f05c8 __27-[XCTestSuite performTest:]_block_invoke + 268\n\t43  XCTest                              0x00000001031efe58 __59-[XCTestSuite _performProtectedSectionForTest:testSection:]_block_invoke + 40\n\t44  XCTest                              0x000000010325e48c +[XCTContext runInContextForTestCase:block:] + 212\n\t45  XCTest                              0x00000001031efe00 -[XCTestSuite _performProtectedSectionForTest:testSection:] + 156\n\t46  XCTest                              0x00000001031f0150 -[XCTestSuite performTest:] + 320\n\t47  XCTest                              0x000000010323986c -[XCTest runTest] + 60\n\t48  XCTest                              0x00000001031f05c8 __27-[XCTestSuite performTest:]_block_invoke + 268\n\t49  XCTest                              0x00000001031efe58 __59-[XCTestSuite _performProtectedSectionForTest:testSection:]_block_invoke + 40\n\t50  XCTest                              0x000000010325e48c +[XCTContext runInContextForTestCase:block:] + 212\n\t51  XCTest                              0x00000001031efe00 -[XCTestSuite _performProtectedSectionForTest:testSection:] + 156\n\t52  XCTest                              0x00000001031f0150 -[XCTestSuite performTest:] + 320\n\t53  XCTest                              0x000000010323986c -[XCTest runTest] + 60\n\t54  XCTest                              0x00000001032705f0 __44-[XCTTestRunSession runTestsAndReturnError:]_block_invoke + 176\n\t55  XCTest                              0x00000001032706f0 __44-[XCTTestRunSession runTestsAndReturnError:]_block_invoke.100 + 108\n\t56  XCTest                              0x000000010320a354 -[XCTestObservationCenter _observeTestExecutionForBlock:] + 588\n\t57  XCTest                              0x0000000103270388 -[XCTTestRunSession runTestsAndReturnError:] + 592\n\t58  XCTest                              0x00000001031d4bbc -[XCTestDriver runTestsAndReturnError:] + 428\n\t59  XCTest                              0x000000010325a424 _XCTestMain + 2396\n\t60  WebDriverAgentRunner-Runner         0x0000000102dd3818 -[_XCTRunnerAppDelegate applicationWillResignActive:] + 0\n\t61  WebDriverAgentRunner-Runner         0x0000000102dd3720 _XCTRunnerRunTests + 0\n\t62  CoreFoundation                      0x00000001b0753998 409609CD-8410-38E1-BA5D-BDED609D2018 + 690584\n\t63  CoreFoundation                      0x00000001b0753124 409609CD-8410-38E1-BA5D-BDED609D2018 + 688420\n\t64  CoreFoundation                      0x00000001b074e288 409609CD-8410-38E1-BA5D-BDED609D2018 + 668296\n\t65  CoreFoundation                      0x00000001b074dc34 CFRunLoopRunSpecific + 424\n\t66  GraphicsServices                    0x00000001ba89738c GSEventRunModal + 160\n\t67  UIKitCore                           0x00000001b488022c UIApplicationMain + 1932\n\t68  WebDriverAgentRunner-Runner         0x0000000102dd39e4 main + 192\n\t69  libdyld.dylib                       0x00000001b05d5800 876FB49A-BFBA-37BF-AD37-6FFC90F7F981 + 6144\n)"
  },
  "sessionId" : null
}

Do you have any idea?

BTW, i compared both of the repos (https://github.com/appium/WebDriverAgent and yours) and there is a lot of differences. You can check it just making a diff between both dirs. So i think that the bundled wda in your repo should be updated with the last changes just to avoid more errors like these.

chriiis78 commented 4 years ago

@pespinel I did the same as you copying Appium's WDA. The WDA works, you can click on the Home button and it closes the app on iPhone. Only touch seems not working.

Kous92 commented 4 years ago

@nanoscopic, @pespinel

Actually, I confirm with @chriiis78 that WDA is running, but no video output on STF with Docker or the upstream OpenSTF.

Capture d’écran 2020-05-11 à 16 00 54

If we go on http://localhost:8100, we are on the WDA Proxy web interface and on remote, we can see the screen of the iPhone (below): Capture d’écran 2020-05-11 à 15 51 06

Logs below.

{"iserr":true,"line":"  Serial: 9*********************","proc":"device_trigger","time":"2020-05-11T15:55:11+02:00"}
{"iserr":true,"line":"Debugger listening on ws://127.0.0.1:9230/43e43e51-0359-4321-af3c-8b772d390912","proc":"stf_ios_provider","time":"2020-05-11T15:55:11+02:00"}
{"iserr":true,"line":"For help, see: https://nodejs.org/en/docs/inspector","proc":"stf_ios_provider","time":"2020-05-11T15:55:11+02:00"}
{"iserr":true,"line":"  Serial: 9*********************","proc":"device_trigger","time":"2020-05-11T15:55:11+02:00"}
{"iserr":true,"line":"  Serial: 9*********************","proc":"device_trigger","time":"2020-05-11T15:55:11+02:00"}
{"iserr":true,"line":"  Serial: 9*********************","proc":"device_trigger","time":"2020-05-11T15:55:11+02:00"}
{"iserr":true,"line":"  Name: iPhone","proc":"device_trigger","time":"2020-05-11T15:55:11+02:00"}
{"iserr":true,"line":"  Serial: 9*********************","proc":"device_trigger","time":"2020-05-11T15:55:11+02:00"}
{"iserr":true,"line":"  Product: iPhone 5-8/X","proc":"device_trigger","time":"2020-05-11T15:55:11+02:00"}
{"iserr":true,"line":"  LocationID: 0x14300000","proc":"device_trigger","time":"2020-05-11T15:55:11+02:00"}
{"iserr":true,"line":"","proc":"device_trigger","time":"2020-05-11T15:55:11+02:00"}
{"iserr":true,"line":"{\"err\":\"dial tcp 127.0.0.1:7878: connect: connection refused\",\"level\":\"fatal\",\"msg\":\"Socket connect error\",\"spec\":\"tcp://127.0.0.1:7878\",\"time\":\"2020-05-11T15:55:11+02:00\",\"type\":\"err_socket_connect\"}","proc":"ios_video_stream","time":"2020-05-11T15:55:11+02:00","uuid":"9*********************"}
{"line":"Listening on 192.168.1.80:8000","proc":"ios_video_stream","time":"2020-05-11T15:55:11+02:00","uuid":"9*********************"}
{"iserr":true,"line":"{\"level\":\"info\",\"msg\":\"Closing usb context\",\"time\":\"2020-05-11T15:55:11+02:00\"}","proc":"ios_video_stream","time":"2020-05-11T15:55:11+02:00","uuid":"9*********************"}
{"iserr":true,"line":"{\"level\":\"error\",\"msg\":\"failed connecting to usb - descriptor of interface (-1, 0) in vid=05ac,pid=12a8,bus=20,addr=11,config=5: interface -1 not found, available interfaces 0..3\",\"time\":\"2020-05-11T15:55:11+02:00\"}","proc":"ios_video_stream","time":"2020-05-11T15:55:11+02:00","uuid":"9*********************"}
{"iserr":true,"line":"2020-05-11T13:55:11.955Z INF/provider 4528 [*] Subscribing to permanent channel \"rQegg7SVSgi98WYV8S5New==\"","proc":"stf_ios_provider","time":"2020-05-11T15:55:11+02:00"}
{"iserr":true,"line":"(node:4528) [DEP0005] DeprecationWarning: Buffer() is deprecated due to security and usability issues. Please use the Buffer.alloc(), Buffer.allocUnsafe(), or Buffer.from() methods instead.","proc":"stf_ios_provider","time":"2020-05-11T15:55:11+02:00"}
{"iserr":true,"line":"2020-05-11T13:55:11.969Z INF/provider 4528 [*] Sending output to \"tcp://127.0.0.1:7270\"","proc":"stf_ios_provider","time":"2020-05-11T15:55:11+02:00"}
{"iserr":true,"line":"2020-05-11T13:55:11.972Z INF/provider 4528 [*] Receiving input from \"tcp://127.0.0.1:7250\"","proc":"stf_ios_provider","time":"2020-05-11T15:55:11+02:00"}
{"line":"Listening on 192.168.1.80:8000","proc":"ios_video_stream","time":"2020-05-11T15:55:13+02:00","uuid":"9*********************"}
{"iserr":true,"line":"{\"level\":\"info\",\"msg\":\"Closing usb context\",\"time\":\"2020-05-11T15:55:13+02:00\"}","proc":"ios_video_stream","time":"2020-05-11T15:55:13+02:00","uuid":"9*********************"}
{"iserr":true,"line":"{\"level\":\"error\",\"msg\":\"failed connecting to usb - descriptor of interface (-1, 0) in vid=05ac,pid=12a8,bus=20,addr=11,config=5: interface -1 not found, available interfaces 0..3\",\"time\":\"2020-05-11T15:55:13+02:00\"}","proc":"ios_video_stream","time":"2020-05-11T15:55:13+02:00","uuid":"9*********************"}
{"iserr":true,"line":"  Serial: 9*********************","proc":"device_trigger","time":"2020-05-11T15:55:16+02:00"}
{"iserr":true,"line":"  Serial: 9*********************","proc":"device_trigger","time":"2020-05-11T15:55:16+02:00"}
{"iserr":true,"line":"  Serial: 9*********************","proc":"device_trigger","time":"2020-05-11T15:55:16+02:00"}
{"iserr":true,"line":"2020-05-11T13:55:18.471Z INF/provider 4528 [*] Tracking iOS device","proc":"stf_ios_provider","time":"2020-05-11T15:55:18+02:00"}
{"iserr":true,"line":"2020-05-11T13:55:18.471Z INF/provider 4528 [*]   UUID:    9*********************","proc":"stf_ios_provider","time":"2020-05-11T15:55:18+02:00"}
{"iserr":true,"line":"2020-05-11T13:55:18.471Z INF/provider 4528 [*]   Name:    iPhone X de Koussaïla","proc":"stf_ios_provider","time":"2020-05-11T15:55:18+02:00"}
{"iserr":true,"line":"2020-05-11T13:55:18.471Z INF/provider 4528 [*]   WDAPort: 8100","proc":"stf_ios_provider","time":"2020-05-11T15:55:18+02:00"}
{"iserr":true,"line":"2020-05-11T13:55:18.471Z INF/provider 4528 [*]   VidPort: 8000","proc":"stf_ios_provider","time":"2020-05-11T15:55:18+02:00"}
{"iserr":true,"line":"2020-05-11T13:55:18.475Z INF/provider 4528 [*]   Channel:  u8O/fsaNqlXnrKdN/PmLfmgH8Nk=","proc":"stf_ios_provider","time":"2020-05-11T15:55:18+02:00"}
{"iserr":true,"line":"2020-05-11T13:55:18.476Z INF/provider 4528 [*] IOS Present:  9*********************","proc":"stf_ios_provider","time":"2020-05-11T15:55:18+02:00"}
{"iserr":true,"line":"2020-05-11T13:55:18.517Z INF/provider 4528 [*] sub messsage: 9********************* register","proc":"stf_ios_provider","time":"2020-05-11T15:55:18+02:00"}
{"line":"2020/05/11 15:55:18 main.go:136 freeport 57423","proc":"wdaproxy","time":"2020-05-11T15:55:18+02:00","uuid":"9*********************"}
{"line":"2020/05/11 15:55:18 main.go:235 Open webbrower with http://192.168.1.80:8100","proc":"wdaproxy","time":"2020-05-11T15:55:18+02:00","uuid":"9*********************"}
{"line":"2020/05/11 15:55:18 main.go:139 launch tcp-proxy, listen on 8100","proc":"wdaproxy","time":"2020-05-11T15:55:18+02:00","uuid":"9*********************"}
{"line":"2020/05/11 15:55:18 main.go:161 device name: ","proc":"wdaproxy","time":"2020-05-11T15:55:18+02:00","uuid":"9*********************"}
{"line":"2020/05/11 15:55:18 main.go:163 launch WebDriverAgent(dir=.)","proc":"wdaproxy","time":"2020-05-11T15:55:18+02:00","uuid":"9*********************"}
{"line":"2020/05/11 15:55:18 main.go:146 launch iproxy (udid: \"9*********************\")","proc":"wdaproxy","time":"2020-05-11T15:55:18+02:00","uuid":"9*********************"}
{"line":"Listening on 192.168.1.80:8000","proc":"ios_video_stream","time":"2020-05-11T15:55:18+02:00","uuid":"9*********************"}
{"iserr":true,"line":"{\"level\":\"info\",\"msg\":\"Closing usb context\",\"time\":\"2020-05-11T15:55:18+02:00\"}","proc":"ios_video_stream","time":"2020-05-11T15:55:18+02:00","uuid":"9*********************"}
{"iserr":true,"line":"{\"level\":\"info\",\"msg\":\"Device '9*********************' USB connection ready\",\"time\":\"2020-05-11T15:55:19+02:00\"}","proc":"ios_video_stream","time":"2020-05-11T15:55:19+02:00","uuid":"9*********************"}
{"iserr":true,"line":"{\"level\":\"info\",\"msg\":\"AudioVideo-Stream has started\",\"time\":\"2020-05-11T15:55:19+02:00\"}","proc":"ios_video_stream","time":"2020-05-11T15:55:19+02:00","uuid":"9*********************"}
{"iserr":true,"line":"[h264 @ 0x7fa2cd80b000] SEI type 128 size 304 truncated at 32","proc":"h264_to_jpeg","time":"2020-05-11T15:55:19+02:00","uuid":"9*********************"}
{"iserr":true,"line":"[h264 @ 0x7fa2cd80b000] SEI type 128 size 304 truncated at 23","proc":"h264_to_jpeg","time":"2020-05-11T15:55:19+02:00","uuid":"9*********************"}
{"iserr":true,"line":"[h264 @ 0x7fa2cd808200] decoding for stream 0 failed","proc":"h264_to_jpeg","time":"2020-05-11T15:55:19+02:00","uuid":"9*********************"}
{"iserr":true,"line":"[h264 @ 0x7fa2cf008200] SEI type 128 size 304 truncated at 23","proc":"h264_to_jpeg","time":"2020-05-11T15:55:19+02:00","uuid":"9*********************"}
{"iserr":true,"line":"2020/05/11 15:55:20 handle_events: error: libusb: interrupted [code -10]","proc":"ios_video_stream","time":"2020-05-11T15:55:20+02:00","uuid":"9*********************"}
{"line":"[WDA] Command line invocation:","proc":"wdaproxy","time":"2020-05-11T15:55:21+02:00","uuid":"9*********************"}
{"line":"[WDA] /Applications/Xcode.app/Contents/Developer/usr/bin/xcodebuild test-without-building -xctestrun WebDriverAgentRunner_iphoneos13.4-arm64e.xctestrun -destination id=9*********************","proc":"wdaproxy","time":"2020-05-11T15:55:21+02:00","uuid":"9*********************"}
{"line":"[WDA] ","proc":"wdaproxy","time":"2020-05-11T15:55:21+02:00","uuid":"9*********************"}
{"line":"[WDA] User defaults from command line:","proc":"wdaproxy","time":"2020-05-11T15:55:21+02:00","uuid":"9*********************"}
{"line":"[WDA] IDETestRunSpecificationPath = /Users/kous/STF/STF_iOS_T-Mobile/stf_ios_support/bin/wda/WebDriverAgentRunner_iphoneos13.4-arm64e.xctestrun","proc":"wdaproxy","time":"2020-05-11T15:55:21+02:00","uuid":"9*********************"}
{"line":"[WDA] ","proc":"wdaproxy","time":"2020-05-11T15:55:21+02:00","uuid":"9*********************"}
{"iserr":true,"line":"Debugger listening on ws://0.0.0.0:9240/4115efee-4d5d-49a1-8a2f-9a2c595a45dc","proc":"stf_device_ios","time":"2020-05-11T15:55:21+02:00","uuid":"9*********************"}
{"iserr":true,"line":"For help, see: https://nodejs.org/en/docs/inspector","proc":"stf_device_ios","time":"2020-05-11T15:55:21+02:00","uuid":"9*********************"}
{"iserr":true,"line":"2020/05/11 15:55:22 handle_events: error: libusb: interrupted [code -10]","proc":"ios_video_stream","time":"2020-05-11T15:55:22+02:00","uuid":"9*********************"}
{"iserr":true,"line":"2020-05-11T13:55:22.480Z INF/device:support:push 4544 [9*********************] Sending output to \"tcp://127.0.0.1:7270\"","proc":"stf_device_ios","time":"2020-05-11T15:55:22+02:00","uuid":"9*********************"}
{"iserr":true,"line":"2020-05-11T13:55:22.504Z INF/device 4544 [9*********************] Preparing device","proc":"stf_device_ios","time":"2020-05-11T15:55:22+02:00","uuid":"9*********************"}
{"line":"[WDA] 2020-05-11 15:55:22.929 xcodebuild[4542:49922]  IDETestOperationsObserverDebug: Writing diagnostic log for test session to:","proc":"wdaproxy","time":"2020-05-11T15:55:22+02:00","uuid":"9*********************"}
{"line":"[WDA] /Users/kous/Library/Developer/Xcode/DerivedData/temporary-ctpkfwgkgmukdlbqthkzozkrpnkd/Logs/Test/Test-Transient Testing-2020.05.11_15-55-21-+0200.xcresult/Staging/1_Test/Diagnostics/WebDriverAgentRunner-8D9382CF-A767-466A-9D75-E8336C0C36AC/WebDriverAgentRunner-5EB5AE96-C994-49D1-BFD3-FDBCF7B825A7/Session-WebDriverAgentRunner-2020-05-11_155522-JqEjFr.log","proc":"wdaproxy","time":"2020-05-11T15:55:22+02:00","uuid":"9*********************"}
{"line":"[WDA] 2020-05-11 15:55:22.931 xcodebuild[4542:49726] [MT] IDETestOperationsObserverDebug: (5455A58F-AEF2-4320-BC44-DB5B4A585363) Beginning test session WebDriverAgentRunner-5455A58F-AEF2-4320-BC44-DB5B4A585363 at 2020-05-11 15:55:22.929 with Xcode 11E503a on target 📱\u003cDVTiOSDevice (0x7ffb8c024ea0), iPhone X de Koussaïla, iPhone, 13.4.1 (17E262), 9*********************\u003e {","proc":"wdaproxy","time":"2020-05-11T15:55:22+02:00","uuid":"9*********************"}
{"line":"[WDA] deviceSerialNumber:         F2LW3QPJJCLH","proc":"wdaproxy","time":"2020-05-11T15:55:22+02:00","uuid":"9*********************"}
{"line":"[WDA] identifier:                 9*********************","proc":"wdaproxy","time":"2020-05-11T15:55:22+02:00","uuid":"9*********************"}
{"line":"[WDA] deviceClass:                iPhone","proc":"wdaproxy","time":"2020-05-11T15:55:22+02:00","uuid":"9*********************"}
{"line":"[WDA] deviceName:                 iPhone X de Koussaïla","proc":"wdaproxy","time":"2020-05-11T15:55:22+02:00","uuid":"9*********************"}
{"line":"[WDA] deviceIdentifier:           9*********************","proc":"wdaproxy","time":"2020-05-11T15:55:22+02:00","uuid":"9*********************"}
{"line":"[WDA] productVersion:             13.4.1","proc":"wdaproxy","time":"2020-05-11T15:55:22+02:00","uuid":"9*********************"}
{"line":"[WDA] buildVersion:               17E262","proc":"wdaproxy","time":"2020-05-11T15:55:22+02:00","uuid":"9*********************"}
{"line":"[WDA] deviceSoftwareVersion:      13.4.1 (17E262)","proc":"wdaproxy","time":"2020-05-11T15:55:22+02:00","uuid":"9*********************"}
{"line":"[WDA] deviceArchitecture:         arm64","proc":"wdaproxy","time":"2020-05-11T15:55:22+02:00","uuid":"9*********************"}
{"line":"[WDA] deviceTotalCapacity:        58344312832","proc":"wdaproxy","time":"2020-05-11T15:55:22+02:00","uuid":"9*********************"}
{"line":"[WDA] deviceAvailableCapacity:    3294564352","proc":"wdaproxy","time":"2020-05-11T15:55:22+02:00","uuid":"9*********************"}
{"line":"[WDA] deviceIsTransient:          NO","proc":"wdaproxy","time":"2020-05-11T15:55:22+02:00","uuid":"9*********************"}
{"line":"[WDA] ignored:                    NO","proc":"wdaproxy","time":"2020-05-11T15:55:22+02:00","uuid":"9*********************"}
{"line":"[WDA] deviceIsBusy:               NO","proc":"wdaproxy","time":"2020-05-11T15:55:22+02:00","uuid":"9*********************"}
{"line":"[WDA] deviceIsPaired:             YES","proc":"wdaproxy","time":"2020-05-11T15:55:22+02:00","uuid":"9*********************"}
{"line":"[WDA] deviceIsActivated:          YES","proc":"wdaproxy","time":"2020-05-11T15:55:22+02:00","uuid":"9*********************"}
{"line":"[WDA] deviceActivationState:      Activated","proc":"wdaproxy","time":"2020-05-11T15:55:22+02:00","uuid":"9*********************"}
{"line":"[WDA] isPasscodeLocked:           NO","proc":"wdaproxy","time":"2020-05-11T15:55:22+02:00","uuid":"9*********************"}
{"line":"[WDA] deviceType:                 \u003cDVTDeviceType:0x7ffb8bf22980 Xcode.DeviceType.iPhone\u003e","proc":"wdaproxy","time":"2020-05-11T15:55:22+02:00","uuid":"9*********************"}
{"line":"[WDA] supportedDeviceFamilies:    (","proc":"wdaproxy","time":"2020-05-11T15:55:22+02:00","uuid":"9*********************"}
{"line":"[WDA] 1","proc":"wdaproxy","time":"2020-05-11T15:55:22+02:00","uuid":"9*********************"}
{"line":"[WDA] )","proc":"wdaproxy","time":"2020-05-11T15:55:22+02:00","uuid":"9*********************"}
{"line":"[WDA] applications:              (null)","proc":"wdaproxy","time":"2020-05-11T15:55:22+02:00","uuid":"9*********************"}
{"line":"[WDA] provisioningProfiles:      (null)","proc":"wdaproxy","time":"2020-05-11T15:55:22+02:00","uuid":"9*********************"}
{"line":"[WDA] hasInternalSupport:        NO","proc":"wdaproxy","time":"2020-05-11T15:55:22+02:00","uuid":"9*********************"}
{"line":"[WDA] hasWritableSystem:         NO","proc":"wdaproxy","time":"2020-05-11T15:55:22+02:00","uuid":"9*********************"}
{"line":"[WDA] isSupportedOS:             YES","proc":"wdaproxy","time":"2020-05-11T15:55:22+02:00","uuid":"9*********************"}
{"line":"[WDA] bootArgs:                  (null)","proc":"wdaproxy","time":"2020-05-11T15:55:22+02:00","uuid":"9*********************"}
{"line":"[WDA] nextBootArgs:              (null)","proc":"wdaproxy","time":"2020-05-11T15:55:22+02:00","uuid":"9*********************"}
{"line":"[WDA] connected:                 YES","proc":"wdaproxy","time":"2020-05-11T15:55:22+02:00","uuid":"9*********************"}
{"line":"[WDA] isWirelessEnabled:         NO","proc":"wdaproxy","time":"2020-05-11T15:55:22+02:00","uuid":"9*********************"}
{"line":"[WDA] connectionType:            direct","proc":"wdaproxy","time":"2020-05-11T15:55:22+02:00","uuid":"9*********************"}
{"line":"[WDA] hostname:                  iPhone-X-de-Koussaila.local.","proc":"wdaproxy","time":"2020-05-11T15:55:22+02:00","uuid":"9*********************"}
{"line":"[WDA] bonjourServiceName:        d8:8f:76:61:75:e1@fe80::da8f:76ff:fe61:75e1._apple-mobdev2._tcp.local.","proc":"wdaproxy","time":"2020-05-11T15:55:22+02:00","uuid":"9*********************"}
{"line":"[WDA] activeProxiedDevice:       (null)","proc":"wdaproxy","time":"2020-05-11T15:55:22+02:00","uuid":"9*********************"}
{"line":"[WDA] } (13.4.1 (17E262))","proc":"wdaproxy","time":"2020-05-11T15:55:22+02:00","uuid":"9*********************"}
{"line":"[WDA] 2020-05-11 15:55:22.973 xcodebuild[4542:49726] [MT] IDETestOperationsObserverDebug: (5455A58F-AEF2-4320-BC44-DB5B4A585363) Finished requesting crash reports. Continuing with testing.","proc":"wdaproxy","time":"2020-05-11T15:55:22+02:00","uuid":"9*********************"}
{"iserr":true,"line":"2020-05-11T13:55:23.006Z INF/device:support:sub 4544 [9*********************] Receiving input from \"tcp://127.0.0.1:7250\"","proc":"stf_device_ios","time":"2020-05-11T15:55:23+02:00","uuid":"9*********************"}
{"iserr":true,"line":"2020-05-11T13:55:23.011Z INF/device:support:sub 4544 [9*********************] Subscribing to permanent channel \"*ALL\"","proc":"stf_device_ios","time":"2020-05-11T15:55:23+02:00","uuid":"9*********************"}
{"iserr":true,"line":"2020-05-11T13:55:23.020Z INF/device-ios:plugins:display 4544 [9*********************] Reading display info","proc":"stf_device_ios","time":"2020-05-11T15:55:23+02:00","uuid":"9*********************"}
{"iserr":true,"line":"2020/05/11 15:55:23 handle_events: error: libusb: interrupted [code -10]","proc":"ios_video_stream","time":"2020-05-11T15:55:23+02:00","uuid":"9*********************"}
{"iserr":true,"line":"2020-05-11T13:55:27.033Z INF/device-ios:plugins:identity 4544 [9*********************] Solving identity","proc":"stf_device_ios","time":"2020-05-11T15:55:27+02:00","uuid":"9*********************"}
{"iserr":true,"line":"2020-05-11T13:55:27.184Z INF/device-ios:plugins:solo 4544 [9*********************] Subscribing to permanent channel \"u8O/fsaNqlXnrKdN/PmLfmgH8Nk=\"","proc":"stf_device_ios","time":"2020-05-11T15:55:27+02:00","uuid":"9*********************"}
{"iserr":true,"line":"2020-05-11T13:55:27.186Z INF/device-ios:plugins:solo 4544 [9*********************] Video - width: 1125, height: 2436, url: wss://localhost:7100/frames/192.168.1.80/8000/x","proc":"stf_device_ios","time":"2020-05-11T15:55:27+02:00","uuid":"9*********************"}
{"iserr":true,"line":"2020-05-11T13:55:27.192Z INF/device-ios:plugins:touch 4544 [9*********************] Touch origin is top left","proc":"stf_device_ios","time":"2020-05-11T15:55:27+02:00","uuid":"9*********************"}
{"iserr":true,"line":"2020-05-11T13:55:27.197Z INF/device-ios:plugins:touch 4544 [9*********************] Requesting touch consumer to start","proc":"stf_device_ios","time":"2020-05-11T15:55:27+02:00","uuid":"9*********************"}
{"iserr":true,"line":"2020-05-11T13:55:27.215Z INF/device 4544 [9*********************] Fully operational","proc":"stf_device_ios","time":"2020-05-11T15:55:27+02:00","uuid":"9*********************"}
{"iserr":true,"line":"2020-05-11T13:55:27.226Z INF/device-ios:plugins:solo 4544 [9*********************] Sent ready message","proc":"stf_device_ios","time":"2020-05-11T15:55:27+02:00","uuid":"9*********************"}
{"iserr":true,"line":"2020-05-11T13:55:27.273Z INF/device-ios:plugins:solo 4544 [9*********************] Got Probe; responding with identity","proc":"stf_device_ios","time":"2020-05-11T15:55:27+02:00","uuid":"9*********************"}
{"iserr":true,"line":"2020-05-11T13:55:27.496Z INF/provider 4528 [*] IOS Heartbeat:  9*********************","proc":"stf_ios_provider","time":"2020-05-11T15:55:27+02:00"}
{"line":"[WDA] 2020-05-11 15:55:27.550759+0200 WebDriverAgentRunner-Runner[516:32539] Running tests...","proc":"wdaproxy","time":"2020-05-11T15:55:27+02:00","uuid":"9*********************"}
{"line":"[WDA] Test Suite 'All tests' started at 2020-05-11 15:55:28.129","proc":"wdaproxy","time":"2020-05-11T15:55:28+02:00","uuid":"9*********************"}
{"line":"[WDA] Test Suite 'WebDriverAgentRunner.xctest' started at 2020-05-11 15:55:28.130","proc":"wdaproxy","time":"2020-05-11T15:55:28+02:00","uuid":"9*********************"}
{"line":"[WDA] Test Suite 'UITestingUITests' started at 2020-05-11 15:55:28.130","proc":"wdaproxy","time":"2020-05-11T15:55:28+02:00","uuid":"9*********************"}
{"line":"[WDA] KeyboardAutocorrection","proc":"wdaproxy","time":"2020-05-11T15:55:28+02:00","uuid":"9*********************"}
{"line":"[WDA] ) in CFPrefsPlistSource\u003c0x283400280\u003e (Domain: com.apple.Preferences, User: kCFPreferencesCurrentUser, ByHost: No, Container: (null), Contents Need Refresh: No): setting preferences outside an application's container requires user-preference-write or file-write-data sandbox access","proc":"wdaproxy","time":"2020-05-11T15:55:28+02:00","uuid":"9*********************"}
{"line":"[WDA] KeyboardPrediction","proc":"wdaproxy","time":"2020-05-11T15:55:28+02:00","uuid":"9*********************"}
{"line":"[WDA] ) in CFPrefsPlistSource\u003c0x283400280\u003e (Domain: com.apple.Preferences, User: kCFPreferencesCurrentUser, ByHost: No, Container: (null), Contents Need Refresh: No): setting preferences outside an application's container requires user-preference-write or file-write-data sandbox access","proc":"wdaproxy","time":"2020-05-11T15:55:28+02:00","uuid":"9*********************"}
{"line":"[WDA] DidShowGestureKeyboardIntroduction","proc":"wdaproxy","time":"2020-05-11T15:55:28+02:00","uuid":"9*********************"}
{"line":"2020/05/11 15:55:28 main.go:229 [WDA] successfully started","proc":"wdaproxy","time":"2020-05-11T15:55:28+02:00","uuid":"9*********************"}
{"line":"[WDA] ) in CFPrefsPlistSource\u003c0x283400280\u003e (Domain: com.apple.Preferences, User: kCFPreferencesCurrentUser, ByHost: No, Container: (null), Contents Need Refresh: No): setting preferences outside an application's container requires user-preference-write or file-write-data sandbox access","proc":"wdaproxy","time":"2020-05-11T15:55:28+02:00","uuid":"9*********************"}
{"line":"[WDA] Test Case '-[UITestingUITests testRunner]' started.","proc":"wdaproxy","time":"2020-05-11T15:55:28+02:00","uuid":"9*********************"}
{"line":"[WDA] t =     0.00s Start Test at 2020-05-11 15:55:28.162","proc":"wdaproxy","time":"2020-05-11T15:55:28+02:00","uuid":"9*********************"}
{"line":"[WDA] t =     0.00s Set Up","proc":"wdaproxy","time":"2020-05-11T15:55:28+02:00","uuid":"9*********************"}
{"line":"[WDA] 2020-05-11 15:55:28.169402+0200 WebDriverAgentRunner-Runner[516:32539] Built at May 11 2020 14:01:13","proc":"wdaproxy","time":"2020-05-11T15:55:28+02:00","uuid":"9*********************"}
{"line":"[WDA] 2020-05-11 15:55:28.184259+0200 WebDriverAgentRunner-Runner[516:32539] ServerURLHere-\u003ehttp://192.168.1.6:8100\u003c-ServerURLHere","proc":"wdaproxy","time":"2020-05-11T15:55:28+02:00","uuid":"9*********************"}
{"line":"[WDA] 2020-05-11 15:55:28.184878+0200 WebDriverAgentRunner-Runner[516:32559] Using singleton test manager","proc":"wdaproxy","time":"2020-05-11T15:55:28+02:00","uuid":"9*********************"}
{"iserr":true,"line":"2020/05/11 15:55:29 handle_events: error: libusb: interrupted [code -10]","proc":"ios_video_stream","time":"2020-05-11T15:55:29+02:00","uuid":"9*********************"}
{"iserr":true,"line":"2020/05/11 15:55:33 handle_events: error: libusb: interrupted [code -10]","proc":"ios_video_stream","time":"2020-05-11T15:55:33+02:00","uuid":"9*********************"}
{"iserr":true,"line":"2020-05-11T13:55:34.348Z INF/util:lifecycle 4544 [9*********************] Winding down for graceful exit","proc":"stf_device_ios","time":"2020-05-11T15:55:34+02:00","uuid":"9*********************"}
{"line":"Interface added","proc":"device_trigger","time":"2020-05-11T15:55:34+02:00"}
{"line":"  class: 0a","proc":"device_trigger","time":"2020-05-11T15:55:34+02:00"}
{"line":"  subclass: 00","proc":"device_trigger","time":"2020-05-11T15:55:34+02:00"}
{"line":"  Vendor: 05ac","proc":"device_trigger","time":"2020-05-11T15:55:34+02:00"}
{"line":"  Product: 12a8","proc":"device_trigger","time":"2020-05-11T15:55:34+02:00"}
{"line":"Interface added","proc":"device_trigger","time":"2020-05-11T15:55:34+02:00"}
{"line":"  class: 02","proc":"device_trigger","time":"2020-05-11T15:55:34+02:00"}
{"line":"  subclass: 0d","proc":"device_trigger","time":"2020-05-11T15:55:34+02:00"}
{"line":"  Vendor: 05ac","proc":"device_trigger","time":"2020-05-11T15:55:34+02:00"}
{"line":"  Product: 12a8","proc":"device_trigger","time":"2020-05-11T15:55:34+02:00"}
{"line":"Interface added","proc":"device_trigger","time":"2020-05-11T15:55:34+02:00"}
{"line":"  class: ff","proc":"device_trigger","time":"2020-05-11T15:55:34+02:00"}
{"line":"  subclass: fe","proc":"device_trigger","time":"2020-05-11T15:55:34+02:00"}
{"line":"  Vendor: 05ac","proc":"device_trigger","time":"2020-05-11T15:55:34+02:00"}
{"line":"  Product: 12a8","proc":"device_trigger","time":"2020-05-11T15:55:34+02:00"}
{"line":"Interface added","proc":"device_trigger","time":"2020-05-11T15:55:34+02:00"}
{"line":"  class: 06","proc":"device_trigger","time":"2020-05-11T15:55:34+02:00"}
{"line":"  subclass: 01","proc":"device_trigger","time":"2020-05-11T15:55:34+02:00"}
{"line":"  Vendor: 05ac","proc":"device_trigger","time":"2020-05-11T15:55:34+02:00"}
{"line":"  Product: 12a8","proc":"device_trigger","time":"2020-05-11T15:55:34+02:00"}
{"line":"Device added","proc":"device_trigger","time":"2020-05-11T15:55:34+02:00"}
{"line":"  Number of configurations:6","proc":"device_trigger","time":"2020-05-11T15:55:34+02:00"}
{"line":"Interface added","proc":"device_trigger","time":"2020-05-11T15:55:34+02:00"}
{"line":"  class: ff","proc":"device_trigger","time":"2020-05-11T15:55:34+02:00"}
{"line":"  subclass: 2a","proc":"device_trigger","time":"2020-05-11T15:55:34+02:00"}
{"line":"  Vendor: 05ac","proc":"device_trigger","time":"2020-05-11T15:55:34+02:00"}
{"line":"  Product: 12a8","proc":"device_trigger","time":"2020-05-11T15:55:34+02:00"}
{"line":"Interface added","proc":"device_trigger","time":"2020-05-11T15:55:34+02:00"}
{"line":"  class: ff","proc":"device_trigger","time":"2020-05-11T15:55:34+02:00"}
{"line":"  subclass: fe","proc":"device_trigger","time":"2020-05-11T15:55:34+02:00"}
{"line":"  Vendor: 05ac","proc":"device_trigger","time":"2020-05-11T15:55:34+02:00"}
{"line":"  Product: 12a8","proc":"device_trigger","time":"2020-05-11T15:55:34+02:00"}
{"line":"Interface added","proc":"device_trigger","time":"2020-05-11T15:55:34+02:00"}
{"line":"  class: 06","proc":"device_trigger","time":"2020-05-11T15:55:34+02:00"}
{"line":"  subclass: 01","proc":"device_trigger","time":"2020-05-11T15:55:34+02:00"}
{"line":"  Vendor: 05ac","proc":"device_trigger","time":"2020-05-11T15:55:34+02:00"}
{"line":"  Product: 12a8","proc":"device_trigger","time":"2020-05-11T15:55:34+02:00"}
{"iserr":true,"line":"{\"level\":\"info\",\"msg\":\"Telling device to stop streaming..\",\"time\":\"2020-05-11T15:55:34+02:00\"}","proc":"ios_video_stream","time":"2020-05-11T15:55:34+02:00","uuid":"9*********************"}
{"line":"Got signal interrupt","proc":"ios_video_stream","time":"2020-05-11T15:55:34+02:00","uuid":"9*********************"}
{"iserr":true,"line":"2020-05-11T13:55:34.350Z INF/util:lifecycle 4528 [*] Winding down for graceful exit","proc":"stf_ios_provider","time":"2020-05-11T15:55:34+02:00"}
{"iserr":true,"line":"  Serial: 9*********************","proc":"device_trigger","time":"2020-05-11T15:55:34+02:00"}
{"iserr":true,"line":"Debugger listening on ws://127.0.0.1:9230/4c82fe50-14bd-45ba-b84f-3030f9ef1ada","proc":"stf_ios_provider","time":"2020-05-11T15:55:34+02:00"}
{"iserr":true,"line":"For help, see: https://nodejs.org/en/docs/inspector","proc":"stf_ios_provider","time":"2020-05-11T15:55:34+02:00"}
{"iserr":true,"line":"  Serial: 9*********************","proc":"device_trigger","time":"2020-05-11T15:55:34+02:00"}
{"iserr":true,"line":"  Serial: 9*********************","proc":"device_trigger","time":"2020-05-11T15:55:34+02:00"}
{"iserr":true,"line":"  Name: iPhone","proc":"device_trigger","time":"2020-05-11T15:55:34+02:00"}
{"iserr":true,"line":"  Serial: 9*********************","proc":"device_trigger","time":"2020-05-11T15:55:34+02:00"}
{"iserr":true,"line":"  Product: iPhone 5-8/X","proc":"device_trigger","time":"2020-05-11T15:55:34+02:00"}
{"iserr":true,"line":"  LocationID: 0x14300000","proc":"device_trigger","time":"2020-05-11T15:55:34+02:00"}
{"iserr":true,"line":"","proc":"device_trigger","time":"2020-05-11T15:55:34+02:00"}
{"iserr":true,"line":"2020-05-11T13:55:34.834Z INF/provider 4553 [*] Subscribing to permanent channel \"inCMfYvQQFWdoXd/W64ifQ==\"","proc":"stf_ios_provider","time":"2020-05-11T15:55:34+02:00"}
{"iserr":true,"line":"(node:4553) [DEP0005] DeprecationWarning: Buffer() is deprecated due to security and usability issues. Please use the Buffer.alloc(), Buffer.allocUnsafe(), or Buffer.from() methods instead.","proc":"stf_ios_provider","time":"2020-05-11T15:55:34+02:00"}
{"iserr":true,"line":"2020-05-11T13:55:34.844Z INF/provider 4553 [*] Sending output to \"tcp://127.0.0.1:7270\"","proc":"stf_ios_provider","time":"2020-05-11T15:55:34+02:00"}
{"iserr":true,"line":"2020-05-11T13:55:34.845Z INF/provider 4553 [*] Receiving input from \"tcp://127.0.0.1:7250\"","proc":"stf_ios_provider","time":"2020-05-11T15:55:34+02:00"}

For the config.json, we have set the network interface to en1 (Wi-Fi network) like below:

{
    "xcode_dev_team_id": "************",
    "stf": {
      "ip": "127.0.0.1",
      "hostname": "localhost:7100"
    },
    "video": {
      "enabled": true,
      "use_vnc": false,
      "vnc_scale": 2,
      "vnc_password": "",
      "frame_rate": 10
    },
    "install": {
      "root_path": "./",
      "config_path": "./config.json"
    },
    "network": {
      "interface": "en1"
    }
}
nanoscopic commented 4 years ago

@pespinel @chriiis78 Upstream WDA does not function click, swipe, or drag with real devices ( at least not on the home screen ). There are changes required. I've merged down the latest WDA updates into my fork. Pull and rebuild and it should work

  1. Git pull both repos/WebDriverAgent and repos/wdaproxy ( noticed issues there too )
  2. make cleanwdaproxy
  3. make cleanwda
  4. make
nanoscopic commented 4 years ago

@Kous92 The WDA 8100 screen showing video does not use ios_video_stream to display it's video. That is showing video by way of frames sent out of the WDA deployed on the phone. While that does function and could be routed through to STF, ios_video_stream is supposed to be faster/better ( and currently has issues and is being worked on )

To debug functionality of ios_video_stream you should go to port 8000. Click the "Open" button on the right there and video should appear. I am currently seeing some lag issues with the ios_video_stream method that need to be resolved. Should be resolved in a day or two. If you need/want it working before the ios_video_stream method is stabilized you'll need to use the commit before I added in the new method. ( but it seems like you and others were encountering problems with the old method also )

I have considered adding in optional use of the WDA frame method also. It shouldn't be too hard to do; just haven't had time to do so yet. It just calls screenshot repeatedly. Sometimes it works well; sometimes it is terrible. Right now I'm seeing about 2fps on port 8100 remote control. It is also 1/4 the resolution of the other methods. ( 1/2 in both directions )

pespinel commented 4 years ago

@nanoscopic I did a fresh install and WDA is not crashing anymore but i'm having the same issue. I can see the device in the control pane but i can't click on it (null session):

On the other hand, I can't control the device from the control pane. Taking a look at the wdaproxy logs i can see that there is no session (null)

[11:51:40] 404 POST /session/null/wda/tap/0 (127.0.0.1) 17.58ms

And the wda logs:

Req URI: /session/null/wda/tap/0
{
  "x": 178.14982509613037,
  "y": 544.3466987609863
}
Response to URI: /session/null/wda/tap/0
{
  "value" : {
    "error" : "invalid session id",
    "message" : "Session does not exist",
    "traceback" : "(\n\t0   CoreFoundation                      0x00000001b07d5604 409609CD-8410-38E1-BA5D-BDED609D2018 + 1222148\n\t1   libobjc.A.dylib                     0x00000001b04f7bcc objc_exception_throw + 56\n\t2   CoreFoundation                      0x00000001b06da9e8 409609CD-8410-38E1-BA5D-BDED609D2018 + 195048\n\t3   WebDriverAgentLib                   0x0000000104b26f44 -[FBRoute raiseNoSessionException] + 120\n\t4   WebDriverAgentLib                   0x0000000104b26e5c -[FBRoute decorateRequest:] + 300\n\t5   WebDriverAgentLib                   0x0000000104b261ac -[FBRoute_TargetAction mountRequest:intoResponse:] + 104\n\t6   WebDriverAgentLib                   0x0000000104b0fe10 __37-[FBWebServer registerRouteHandlers:]_block_invoke + 492\n\t7   RoutingHTTPServer                   0x0000000104c324e0 -[RoutingHTTPServer handleRoute:withRequest:response:] + 144\n\t8   RoutingHTTPServer                   0x0000000104c32ca0 __72-[RoutingHTTPServer routeMethod:withPath:parameters:request:connection:]_block_invoke + 44\n\t9   libdispatch.dylib                   0x00000001b049b524 5A83D0CF-8FB9-3727-8A32-012D20A47EC8 + 374052\n\t10  libdispatch.dylib                   0x00000001b044e180 5A83D0CF-8FB9-3727-8A32-012D20A47EC8 + 57728\n\t11  libdispatch.dylib                   0x00000001b049b524 5A83D0CF-8FB9-3727-8A32-012D20A47EC8 + 374052\n\t12  libdispatch.dylib                   0x00000001b044d5b4 5A83D0CF-8FB9-3727-8A32-012D20A47EC8 + 54708\n\t13  CoreFoundation                      0x00000001b0753748 409609CD-8410-38E1-BA5D-BDED609D2018 + 689992\n\t14  CoreFoundation                      0x00000001b074e61c 409609CD-8410-38E1-BA5D-BDED609D2018 + 669212\n\t15  CoreFoundation                      0x00000001b074dc34 CFRunLoopRunSpecific + 424\n\t16  Foundation                          0x00000001b0a90bcc 1A46239D-F2FC-34B6-95BC-9F38869F0C85 + 31692\n\t17  WebDriverAgentLib                   0x0000000104b0e844 -[FBWebServer startServing] + 440\n\t18  WebDriverAgentRunner                0x000000010489fbac -[UITestingUITests testRunner] + 116\n\t19  CoreFoundation                      0x00000001b07db760 409609CD-8410-38E1-BA5D-BDED609D2018 + 1247072\n\t20  CoreFoundation                      0x00000001b06acb40 409609CD-8410-38E1-BA5D-BDED609D2018 + 6976\n\t21  XCTest                              0x00000001031f55f4 __24-[XCTestCase invokeTest]_block_invoke_3 + 52\n\t22  XCTest                              0x00000001031f55a4 __24-[XCTestCase invokeTest]_block_invoke_2 + 312\n\t23  XCTest                              0x00000001032653c0 -[XCTMemoryChecker _assertInvalidObjectsDeallocatedAfterScope:] + 68\n\t24  XCTest                              0x00000001031fffe0 -[XCTestCase assertInvalidObjectsDeallocatedAfterScope:] + 112\n\t25  XCTest                              0x00000001031f543c __24-[XCTestCase invokeTest]_block_invoke.206 + 200\n\t26  XCTest                              0x000000010324c0d8 +[XCTestCase(Failures) performFailableBlock:testCase:testCaseRun:shouldInterruptTest:] + 84\n\t27  XCTest                              0x000000010324bfdc -[XCTestCase(Failures) _performTurningExceptionsIntoFailuresInterruptAfterHandling:block:] + 132\n\t28  XCTest                              0x00000001031f4ef0 -[XCTestCase invokeTest] + 1120\n\t29  XCTest                              0x00000001031f68b8 __26-[XCTestCase performTest:]_block_invoke_2 + 44\n\t30  XCTest                              0x000000010324c0d8 +[XCTestCase(Failures) performFailableBlock:testCase:testCaseRun:shouldInterruptTest:] + 84\n\t31  XCTest                              0x000000010324bfdc -[XCTestCase(Failures) _performTurningExceptionsIntoFailuresInterruptAfterHandling:block:] + 132\n\t32  XCTest                              0x00000001031f67f0 __26-[XCTestCase performTest:]_block_invoke.366 + 96\n\t33  XCTest                              0x000000010325e48c +[XCTContext runInContextForTestCase:block:] + 212\n\t34  XCTest                              0x00000001031f60dc -[XCTestCase performTest:] + 540\n\t35  XCTest                              0x000000010323986c -[XCTest runTest] + 60\n\t36  XCTest                              0x00000001031f05c8 __27-[XCTestSuite performTest:]_block_invoke + 268\n\t37  XCTest                              0x00000001031efe58 __59-[XCTestSuite _performProtectedSectionForTest:testSection:]_block_invoke + 40\n\t38  XCTest                              0x000000010325e48c +[XCTContext runInContextForTestCase:block:] + 212\n\t39  XCTest                              0x00000001031efe00 -[XCTestSuite _performProtectedSectionForTest:testSection:] + 156\n\t40  XCTest                              0x00000001031f0150 -[XCTestSuite performTest:] + 320\n\t41  XCTest                              0x000000010323986c -[XCTest runTest] + 60\n\t42  XCTest                              0x00000001031f05c8 __27-[XCTestSuite performTest:]_block_invoke + 268\n\t43  XCTest                              0x00000001031efe58 __59-[XCTestSuite _performProtectedSectionForTest:testSection:]_block_invoke + 40\n\t44  XCTest                              0x000000010325e48c +[XCTContext runInContextForTestCase:block:] + 212\n\t45  XCTest                              0x00000001031efe00 -[XCTestSuite _performProtectedSectionForTest:testSection:] + 156\n\t46  XCTest                              0x00000001031f0150 -[XCTestSuite performTest:] + 320\n\t47  XCTest                              0x000000010323986c -[XCTest runTest] + 60\n\t48  XCTest                              0x00000001031f05c8 __27-[XCTestSuite performTest:]_block_invoke + 268\n\t49  XCTest                              0x00000001031efe58 __59-[XCTestSuite _performProtectedSectionForTest:testSection:]_block_invoke + 40\n\t50  XCTest                              0x000000010325e48c +[XCTContext runInContextForTestCase:block:] + 212\n\t51  XCTest                              0x00000001031efe00 -[XCTestSuite _performProtectedSectionForTest:testSection:] + 156\n\t52  XCTest                              0x00000001031f0150 -[XCTestSuite performTest:] + 320\n\t53  XCTest                              0x000000010323986c -[XCTest runTest] + 60\n\t54  XCTest                              0x00000001032705f0 __44-[XCTTestRunSession runTestsAndReturnError:]_block_invoke + 176\n\t55  XCTest                              0x00000001032706f0 __44-[XCTTestRunSession runTestsAndReturnError:]_block_invoke.100 + 108\n\t56  XCTest                              0x000000010320a354 -[XCTestObservationCenter _observeTestExecutionForBlock:] + 588\n\t57  XCTest                              0x0000000103270388 -[XCTTestRunSession runTestsAndReturnError:] + 592\n\t58  XCTest                              0x00000001031d4bbc -[XCTestDriver runTestsAndReturnError:] + 428\n\t59  XCTest                              0x000000010325a424 _XCTestMain + 2396\n\t60  WebDriverAgentRunner-Runner         0x0000000102dd3818 -[_XCTRunnerAppDelegate applicationWillResignActive:] + 0\n\t61  WebDriverAgentRunner-Runner         0x0000000102dd3720 _XCTRunnerRunTests + 0\n\t62  CoreFoundation                      0x00000001b0753998 409609CD-8410-38E1-BA5D-BDED609D2018 + 690584\n\t63  CoreFoundation                      0x00000001b0753124 409609CD-8410-38E1-BA5D-BDED609D2018 + 688420\n\t64  CoreFoundation                      0x00000001b074e288 409609CD-8410-38E1-BA5D-BDED609D2018 + 668296\n\t65  CoreFoundation                      0x00000001b074dc34 CFRunLoopRunSpecific + 424\n\t66  GraphicsServices                    0x00000001ba89738c GSEventRunModal + 160\n\t67  UIKitCore                           0x00000001b488022c UIApplicationMain + 1932\n\t68  WebDriverAgentRunner-Runner         0x0000000102dd39e4 main + 192\n\t69  libdyld.dylib                       0x00000001b05d5800 876FB49A-BFBA-37BF-AD37-6FFC90F7F981 + 6144\n)"
  },
  "sessionId" : null
}
chriiis78 commented 4 years ago

@nanoscopic @pespinel I successfully made working the WDA. I used the version 2.15.0 of the Appium WDA https://github.com/appium/WebDriverAgent/commit/ca9eef2f3e19f8906c32dacf286ba1b3065a36cd

With this commit, the sessionId is not null when /status. What's working:

What's not working:

Now, with @Kous92, just the video is not showing on OpenSTF. Currently, we have the video on port :8000 but it's very laggy as @nanoscopic said. At least, the video from the iPhone is processed.

Edit: We were missing with the port in config.json : we can't get video when there is a port number.

We had to use the docker method to start OpenSTF without a port.

Now the video shows on OpenSTF but it's still very laggy (20 seconds at least) and unstable (stops streaming a minute after)

Kous92 commented 4 years ago

Also, the Home button works on any place including home screen itself. For the WDA, above 2.15.0 (2.15.1 and more recent), the sessionId is null.

pespinel commented 4 years ago

@chriiis78 @Kous92 Yes, i've just confirmed all of that. Furthermore the http://localhost:8100/remote endpoint works pretty well despite the fact that the video is a continuous screenshot and it has lag. Here the swipe and send_keys work correctly

@nanoscopic @pespinel I successfully made working the WDA. I used the version 2.15.0 of the Appium WDA appium/WebDriverAgent@ca9eef2

With this commit, the sessionId is not null when /status. What's working:

  • Tap
  • Web Navigation: when an url is specified, it opens the homescreen search bar and write the url -> should it directly open safari and open the website?

What's not working:

  • Swipe -> need a merge of @nanoscopic WDA
  • Keyboard: wda have an error
  • Pasteboard: we don't get (or set?) the phone pasteboard

Now, with @Kous92, just the video is not showing on OpenSTF. Currently, we have the video on port :8000 but it's very laggy as @nanoscopic said. At least, the video from the iPhone is processed.

Also, the Home button works on any place including home screen itself. For the WDA, above 2.15.0 (2.15.1 and more recent), the sessionId is null.

nanoscopic commented 4 years ago

@pespinel @chriiis78 @Kous92 I've updated my fork of WebDriverAgent to be 2.15.0 with the fix for real device interaction. I tested building everything clean and it is working for me.

Kous92 commented 4 years ago

@nanoscopic Thanks for the WDA update, it works fine (on homescreen and apps, we can swipe now). Now, with @chriiis78 we still remain on the video stream problem.

We have picked up on logs some elements from the different processes:

nanoscopic commented 4 years ago

The way the new video streaming is working is that raw h264 nalus are pulled directly from the device, then sent via a nanomsg queue to h264_to_jpeg and decoded into jpeg frames.

Even older mac minis should be able to decode 15fps of h264 nalus and re-encode to jpeg without issue. That is the framerate the code is currently setup to run at. Even at that rate it appears that the nanomsg queue is getting backed up. That quickly ( minutes ) causes the video to fail as it lags further behind.

In order to resolve this I am working on two things:

  1. Add timestamps to the raw h264 nalus as they are sent over, and then discard nalus / skip jpeg encoding for frames if they are old; to prevent the system from getting lagged.
  2. Replace the logging output with something else. It appears the logging within coordinator is causing lock contention of some sort. I've seen the logs get 30+ seconds lagged behind.

Step 1 should make video stable and responsive; at the cost of losing frames. Step 2 should resolve what is actually causing the lag / lock contention / cpu overuse.

Simultaneously with above I am also working on getting multiple devices working simultaneously on a single mac mini. It is my belief based on performance tests I've run that the older ( i5 ) mac minis should be capable of handling 2 ios devices at 10fps each at the same time.

I also investigated how to run 6+ devices simultaneously on a single mac mini. The way to do that is to offload the h264 processing to a jetson nano. I looked into it enough that I did find CUDA code that could be used effectively to simultaneously process 6 h264 streams to jpeg at full frame rate at once on a jetson nano board. It would require a decent amount of work to put it all together but would be neat; since most computers aren't hardware capable of simultaneously decoding many h264 streams.

As far as the "truncated" messages in your log. I've seen those when the header caching is not working properly. For h264_to_jpeg to work properly, there should be a "cache" folder in the CWD of where it is run. That cache folder will then have the headers for h264 ( PPS and SPS units ) written into it. Once they are properly cached those messages should not occur. In my testing it works reliably if I run ios_video_stream and h264_to_jpeg manually. I see weirdness when they are run by stf_ios_support; hence I believe the logging is breaking things.

As for the "libusb: interrupted"; I've only seen that myself when attempting to use multiple IOS devices simultaneously on the same machine. There are bugs in qvh/ios_video_stream that have not yet been resolved that prevent simultaneous devices currently.

The resolution of the video stream is lower than the full video size. Generally it is 1/2 in both directions.

Changing the port to use a "standard" STF is not a matter of tacking ":port" onto the hostname. The hostname is the hostname, nothing else. It isn't a URI. To specify different ports ( the standard ones ) you need to change connect-sub and connect-push in these files: https://github.com/tmobile/stf_ios_support/blob/master/coordinator/proc_stf_provider.go#L28

https://github.com/tmobile/stf_ios_support/blob/master/coordinator/proc_device_unit.go#L20

nanoscopic commented 4 years ago

@Kous92 Today while running ios_video_stream I noticed I get a bunch of the "handle_events: error: libusb: interrupted [code -10]" messages as well. Apparently they are harmless ( so far as I can tell )

chriiis78 commented 4 years ago

@nanoscopic for the video, when we launch OpenSTF with : stf local --bind-app-pub 'tcp://127.0.0.1:7150' --bind-app-dealer 'tcp://127.0.0.1:7160' --bind-app-pull 'tcp://127.0.0.1:7170' --bind-dev-pub 'tcp://127.0.0.1:7250' --bind-dev-dealer 'tcp://127.0.0.1:7260' --bind-dev-pull 'tcp://127.0.0.1:7270'

I think all the ports are binded correctly.

With config.json :

{
    "xcode_dev_team_id": "XXXXXXXXXX",
    "stf": {
      "ip": "127.0.0.1",
      "hostname": "localhost:7100"
    },
    "video": {
      "enabled": true,
      "use_vnc": false,
      "vnc_scale": 2,
      "vnc_password": "",
      "frame_rate": 10
    },
    "install": {
      "root_path": "",
      "config_path": "config.json"
    }
}

We get this error : Capture d’écran 2020-05-14 à 11 29 33

I don't know well wss, what could be wrong?

nanoscopic commented 4 years ago

@chriiis78 Your STF server must be running with https ; and there is a nginx modification needed to add a path back for the video. wss is a websocket with https.

You could alter the path setting to skip the nginx redirection: https://github.com/tmobile/stf_ios_support/blob/master/coordinator/proc_device_unit.go#L25

Alter that line to be ws://[ip address where ios_video_stream is running]:8000/echo To match this: https://github.com/tmobile/stf_ios_support/blob/master/server/nginx/nginx.conf#L79

nanoscopic commented 4 years ago

I've updated ios_video_stream and h264_to_jpeg with timestamps to help debug why video is getting stuck. They can be run in the following way to test:

  1. Go to settings->developer on your IOS device and click "Reset Media Services" ( do this first to get the phone into a stable state... or anytime it gets wonky/refuses to stream video )
  2. Make sure there is a cache folder in your directory
  3. Start the decoder: ./bin/decode nano --in tcp://127.0.0.1:7878 --out tcp://127.0.0.1:7879 --cacheid test --cachedir cache --frameSkip 2
  4. Start ios_video_stream: ./bin/ios_video_stream -stream
  5. ctrl-c / repeat step 4 / step 1 until you get a message saying "AudioVideo-Stream has started" and see a fast scrolling list of unix timestamps. Each timestamp is a single frame of video being sent to the decoder.
  6. Watch the h264_to_jpeg process output messages with MS time to process each frame and iframe messages.
  7. Open a browser to "localhost:8000" and click "Open". Watch video stream.
  8. Watch all the numbers go flying by in the terminal windows seeming to work great for 1-8 minutes while doing stuff on the IOS devvice
  9. Watch video come to a crashing halt; with no timestamps coming from ios_video_stream any more
  10. Repeat 1-9 as desired until you feel satisfied that it works great but is still broken.

Example output of ios_video_stream:

No tunnel specified; listening on all interfaces
Listening on :8000
{"level":"info","msg":"Closing usb context","time":"2020-05-14T20:05:55-07:00"}
{"level":"info","msg":"Device '***484a' USB connection ready","time":"2020-05-14T20:05:55-07:00"}
{"level":"info","msg":"AudioVideo-Stream has started","time":"2020-05-14T20:05:55-07:00"}
1589511955859
1589511955859
1589511955859
1589511955859
...

Example output of h264_to_jpeg:


Receiving data from nanomsg tcp://127.0.0.1:7878
Send data to nanomsg tcp://127.0.0.1:7879
Fetching headers to start decoder
Using cached headers from cache/test
nalu type: SPS, size: 24
nalu type: PPS, size: 12
nalu type: SEI, size: 38
Opening Input
Input Open
Fetching first frame to initialize decoder
nalu type: SPS, size: 20
nalu type: PPS, size: 8
nalu type: SEI, size: 34
 Iframe - size: 43684
Finding stream info
[h264 @ 0x7fe637000000] decoding for stream 0 failed
Finding best stream
Getting hardware config
Initiating decoder
Decoder is started; beginning loop reading frames
Time from start of main till video loop: 2038.485000
MS till drop: -139037221631011
MS till jpeg: 82
MS till drop: 77
...
MS till drop: 3
MS till jpeg: 12
 Iframe - size: 70612 - Timediff:572.654000
MS till drop: 5
MS till jpeg: 12
pespinel commented 4 years ago

I am unable to get the video working in another mac mini. I am following your steps @nanoscopic but always getting this error at the 4th step:

2020/05/15 10:25:17 handle_events: error: libusb: interrupted [code -10]
chriiis78 commented 4 years ago

@nanoscopic I succesfully made the video work on OpenSTF. I altered the line like this

fmt.Sprintf("ws://%s:%d/echo", curIP, o.devd.vidPort)

I tried your updated video stream but it's still very laggy. At the beginning, the delay is about 10 sec and after a minute, the timestamps won't come anymore.

@pespinel you pulled repos ios_video_stream and h264_to_jpeg?

pespinel commented 4 years ago

@chriiis78 Yes, i did a fresh install

chriiis78 commented 4 years ago

@pespinel does the QVH still work?

pespinel commented 4 years ago

No, it's not working at all for me. I'm setting up a remote server with a new iOS device, all it's working but the qvh (I can see the device in the control pane, i can control it trough wdaproxy interface in 8100 but there is no video in :8000 nor the control pane of STF)

chriiis78 commented 4 years ago

Does the QuickTime Player work? Did you gave the video permission for QuickTime? Can you see the video when you use QVH with gstreamer? If all of those work, ios_video_stream should work too... As far I know, the video on :8100 is not related to ios_video_stream