lyndsey-ferguson/fastlane-plugin-test_center

Logs from simulators empty

Closed this issue ยท 30 comments

New Issue Checklist

  • Updated fastlane-plugin-test_center to the latest version
  • I read the README.md
  • I reviewed the example(s) for the action(s) I am using
  • I have removed any sensitive data such as passwords, authentication tokens, or anything else I do not want to world to see

If you love this fastlane plugin, consider sponsoring it or asking your company to sponsor it. I would really appreciate any
gesture: https://github.com/sponsors/lyndsey-ferguson. ๐Ÿ˜

Issue Description

From @lilyball

Finally tried it v3.11.5. I don't know what's going on but the .logarchives it produced were completely empty. Nothing at all in the folders. I don't know why the stderr of the log collect is piped to /dev/null, it seems like it would be useful output to have. It does appear to be referencing the correct device UUID (finally) so I don't know why there's nothing here. Because test_center moves the logarchives itself without invoking loggable shell commands I can't see what it's doing, to see if it's somehow screwing it up.

The last log collect in the run I just did looks like

xcrun simctl spawn --standalone 541925A2-E7B2-444B-9D99-42989349DC03 log collect --output /Users/jenkins/workspace/JOBNAME/fastlane/test_output/TARGET/TARGETTests-batch-3/system_logs-iPhone\ 8\ Clone\ 3\ TestCenter::Helper::MultiScanManager::SimulatorHelper\<70242128102320\>_iOS_13.4.logarchive 2>/dev/null

No output of course.

Complete output when running fastlane, including the stack trace and command used
[INSERT OUTPUT HERE]

Environment

๐Ÿšซ fastlane environment ๐Ÿšซ

Stack

Key Value
OS 10.15.5
Ruby 2.4.1
Bundler? false
Git git version 2.25.0
Installation Source ~/.rbenv/versions/2.4.1/bin/fastlane
Host Mac OS X 10.15.5 (19F101)
Ruby Lib Dir ~/.rbenv/versions/2.4.1/lib
OpenSSL Version OpenSSL 1.1.0j 20 Nov 2018
Is contained false
Is homebrew false
Is installed via Fabric.app false
Xcode Path /Applications/Xcode11.4.1.app/Contents/Developer/
Xcode Version 11.4.1

System Locale

Variable Value
LANG en_US.UTF-8 โœ…
LC_ALL
LANGUAGE

fastlane files:

`./fastlane/Fastfile`
require_relative 'test_center_utils'

# Retrieves the example code from each action and runs it to ensure that everything
# is working as intended.
lane :run_examples do
  action_examples.values.flatten.each do |example_code_snippet|
    # rubocop:disable Security/Eval
    eval(example_code_snippet)
    # rubocop:enable Security/Eval
  end
end

lane :testing do
  scan(
    workspace: File.absolute_path('../AtomicBoy/AtomicBoy.xcworkspace'),
    scheme: 'AtomicBoy',
    buildlog_path: "logs/scan/",
    derived_data_path: "DerivedData",
    fail_build: false,
    result_bundle: true,
    include_simulator_logs: true,
    device: "iPhone 8"
  )
end

No Appfile found

fastlane gems

Gem Version Update-Status
fastlane 2.149.1 ๐Ÿšซ Update available

Loaded fastlane plugins:

Plugin Version Update-Status
fastlane-plugin-test_center 3.11.5 โœ… Up-To-Date
Loaded gems
Gem Version
did_you_mean 1.1.0
slack-notifier 2.3.2
rouge 2.0.7
xcpretty 0.3.0
terminal-notifier 2.0.0
terminal-table 1.8.0
multipart-post 2.0.0
word_wrap 1.0.0
public_suffix 2.0.5
colored 1.2
highline 1.7.10
commander-fastlane 4.4.6
http-cookie 1.0.3
faraday-cookie_jar 0.0.6
gh_inspector 1.1.3
mini_magick 4.10.1
multi_xml 0.6.0
rubyzip 1.3.0
security 0.1.3
xcpretty-travis-formatter 1.0.0
jwt 2.1.0
uber 0.1.0
declarative-option 0.1.0
representable 3.0.4
retriable 3.1.2
mini_mime 1.0.2
httpclient 2.8.3
google-api-client 0.38.0
nanaimo 0.2.6
colored2 3.1.2
claide 1.0.3
CFPropertyList 3.0.2
atomos 0.1.3
xcodeproj 1.17.0
unicode-display_width 1.7.0
plist 3.5.0
addressable 2.7.0
tty-screen 0.8.0
tty-cursor 0.7.1
tty-spinner 0.9.3
babosa 1.0.3
excon 0.75.0
faraday 1.0.1
unf_ext 0.0.7.7
unf 0.1.4
domain_name 0.5.20190701
faraday_middleware 1.0.0
fastimage 2.1.7
json 2.3.0
dotenv 2.7.5
bundler 2.1.4
naturally 2.2.0
simctl 1.6.8
declarative 0.0.20
multi_json 1.14.1
signet 0.14.0
os 1.1.0
memoist 0.16.2
googleauth 0.13.0
digest-crc 0.5.1
google-cloud-errors 1.0.1
google-cloud-env 1.3.2
google-cloud-core 1.5.0
google-cloud-storage 1.26.2
emoji_regex 1.0.1
aws-eventstream 1.1.0
aws-sigv4 1.2.1
aws-partitions 1.337.0
jmespath 1.4.0
aws-sdk-core 3.102.1
aws-sdk-kms 1.35.0
aws-sdk-s3 1.72.0
openssl 2.0.3
io-console 0.4.6
mini_portile2 2.4.0
nokogiri 1.10.9
rbnacl 7.1.1
ffi 1.13.1
psych 2.2.2
ox 2.12.1
xctest_list 1.1.8
colorize 0.8.1

generated on: 2020-07-08

I've noticed this issue as well. Note that setting include_simulator_logs to false still attempts to include them. If you look at the logs, it says include_simulator_logs = true

I also see this. The simulator logs are empty. I stopped the code before any moving of the logs was done and they were still empty. I thought, "perhaps there is some relationship to the existence of the sims they came from", and stopped deleting them after the runs were done, "still empty".

They are also empty when I do not specify the parallel test runs option.

When I use plain scan, the logarchive is also empty.

I'll update the Issue with my environment info and @lchinigioli-eb @lilyball, can you compare?

See the details of the Environment section of the Issue description above.

Use this command:

fastlane env

Also, @lchinigioli-eb @lilyball, can you try with just plain scan to see if the logs are empty?

I upgraded to Xcode 11.5, and the same error is occurring on an iOS 13.5 simulator.

I'm getting a blank logarchive with a regular scan() too. If I run the same log collect by hand (since the sim still exists after the scan) I get

log: failed to collect LiveData: No such file or directory (2)
Archive successfully written to /Users/lilyball/system_logs-iPhone 8_iOS_13.5.logarchive

This has a successful error code though. And if I do log show instead I get a complete failure as

Error from getpwuid_r: 0 (Undefined error: 0)
log: Could not open local log store: Connection to logd failed

I don't know if the log show error is actually useful though, it's complaining that it can't connect to logd which isn't surprising as the simulator is currently shut down. But the log collect error looks a bit different.

Booting the simulator allows me to then collect logs, but what I collected doesn't include the test run. And after shutting it down again, the log collect operation once again fails.

FWIW I'm doing this with Simulator.app not running. My expectation is that for the headless UI Test run xcode is booting the simulator, testing, and shutting it down again, before logs can be collected. It's possible that having the simulator already booted prior to running the tests would keep it booted afterwards; if so, then multi_scan can work around this by explicitly booting its simulator clones up front and then shutting them down after scan is finished doing its stuff. Or possibly just doing this when scan was instructed to collect simulator logs.

I validated that xcode is indeed booting the device, running tests, and shutting it down again before fastlane has a chance to collect logs. I also validated that booting the device first keeps it booted. The problem, however, is fastlane is still passing the --standalone flag to xcrun simctl spawn and that makes the command fail regardless of the booted status.

This plugin could still work around this by not passing the flag to spawn at all and doing the collection itself instead the correct way (spawn the sim before running tests, collect logs without the --standalone flag, shut down the sim). fastlane should of course fix the bug itself too but having this plugin handle it directly means the fix will work for all versions of fastlane.

I filed fastlane/fastlane#16800 against fastlane.

Thanks for investigating this so thoroughly and filing the bug report for fastlane.

@lilyball, can you modify your Pluginfile per my instructions below, run bundle install, and then run your fastlane again (with the --verbose flag)?

Pluginfile:

gem 'fastlane-plugin-test_center', :git => "https://github.com/lyndsey-ferguson/fastlane-plugin-test_center.git", :branch => "issue-248-fix-empty-sim-logs"

If there are still problems, please let me know and attach the console output as a text file to this issue (makes it easier for me to review). If it works, please let me know.

@lilyball, can you modify your Pluginfile per my instructions below, run bundle install, and then run your fastlane again (with the --verbose flag)?

Pluginfile:

gem 'fastlane-plugin-test_center', :git => "https://github.com/lyndsey-ferguson/fastlane-plugin-test_center.git", :branch => "issue-248-fix-empty-sim-logs"

If there are still problems, please let me know and attach the console output as a text file to this issue (makes it easier for me to review). If it works, please let me know.

I've done so and I'm still getting the same issue (w/ multi_scan):

[15:07:59]: ------------------------------
[15:07:59]: --- Collecting system logs ---
[15:07:59]: ------------------------------
[15:07:59]: $ xcrun simctl spawn --standalone B59DD497-3099-4D96-80BC-62BBAD7A0D96 log collect --output /Users/distiller/project/build/test_output/system_logs-iPhone\ 11\ Pro_iOS_13.4.1.logarchive 2>/dev/null

@lchinigioli-eb are you saying that you updated your Gemfile as per the instructions, ran bundle install and simctl is still spawning with the --standalone flag?

If so, can you re-run it with the --verbose flag and provide the logs? Also, can you include the output from fastlane env here to help me confirm that you have everything I think you have?

@lyndsey-ferguson let me double check

@lyndsey-ferguson sorry for the delay. It turned out that I had some problems and I wanted to clear the ground a bit before providing information. So, we have this problem while using multi_scan for UITests. Notice (in the attached logs) that include_simulator_logs is set to true even when we disabled it. I've updated the PluginFile using gem 'fastlane-plugin-test_center', :git => "https://github.com/lyndsey-ferguson/fastlane-plugin-test_center.git", :branch => "issue-248-fix-empty-sim-logs" and I've also updated Fastlane. Let me know if this helps.

output.txt
fastlane_env.txt
output_verbose.txt

@lchinigioli-eb a couple of things:

  1. I don't think that the --verbose flag is being used, the logs don't have anything that I can use (it would tell me where it is incorrectly setting scan values, etc.).
  2. Does your Gemfile.lock have this at the top?
GIT
  remote: https://github.com/lyndsey-ferguson/fastlane-plugin-test_center.git
  revision: a7336bc97a2224106bf260ba78f76e8b3125bb69
  branch: issue-248-fix-empty-sim-logs
  specs:
    fastlane-plugin-test_center (3.11.5)
      colorize
      json
      plist
      xcodeproj
      xctest_list (>= 1.1.8)
  1. You indicate that your call to multi_scan has include_simulator_logs: false (or doesn't specify it all). I see from your logs that a Scanfile is being loaded. Does it have that value? You can see from the logs that a Scanfile was found: Scanfile found: overriding multi_scan options with it's values..

@lyndsey-ferguson ๐Ÿ‘‹ :

  1. I'm having problems on the circleci instance. Not sure why the --verbose doesn't work there. Maybe it's been overwritten by any configuration. Let me check. (Things work nice locally ๐Ÿ˜• ).
  2. My Gemfile.lock has that exact same thing:
  GIT
  remote: https://github.com/lyndsey-ferguson/fastlane-plugin-test_center.git
  revision: a7336bc97a2224106bf260ba78f76e8b3125bb69
  branch: issue-248-fix-empty-sim-logs
  specs:
    fastlane-plugin-test_center (3.11.5)
      colorize
      json
      plist
      xcodeproj
      xctest_list (>= 1.1.8)
  1. Our Scanfile:
# For more information about this configuration visit
# https://docs.fastlane.tools/actions/scan/#scanfile

# In general, you can use the options available
# fastlane scan --help

# Remove the # in front of the line to enable the option

# open_report(true)

clean(true)

# Enable skip_build to skip debug builds for faster test performance
skip_build(false)

# Enable/Disable include_simulator_logs
include_simulator_logs(false)

It doesn't have a lot of things. We introduced it as an attempt to disable the simulator logs, but still that seems enabled according to the logs:

(I've intentionally removed other values)
+------------------------------------------------+-----------------------------------------------------+
|                                       Summary for scan 2.152.0                                       |
+------------------------------------------------+-----------------------------------------------------+
| include_simulator_logs                         | true                                                |
+------------------------------------------------+-----------------------------------------------------+

Thanks in advance for checking

@lchinigioli-eb thank you for your patience and persistence. I believe that I have found the issue.

Can you modify your Pluginfile per my instructions below, run bundle install, and then run your fastlane again (with the --verbose flag)?

Pluginfile:

gem 'fastlane-plugin-test_center', :git => "https://github.com/lyndsey-ferguson/fastlane-plugin-test_center.git", :branch => "issue-248-fix-empty-sim-logs"

The git commit SHA in your Gemfile.lock should be 2ada8c7010d9c2fb050808e81067fab933878d32.

With regards to the --verbose flag in CircleCI's systems, I don't have insight into their system (or your setup), but I find it suspect that you're not getting the extended logs. All it really does is set a flag in the Fastlane process instance that allows calls to FastlaneCore::UI.verbose to print to the console.

You're correct that scan is receiving true, that is definite. Can you output the env variable before multi_scan is called?

puts "SCAN_INCLUDE_SIMULATOR_LOGS: #{ENV['SCAN_INCLUDE_SIMULATOR_LOGS']}"
# I'm guessing that something, CircleCI, is setting `SCAN_INCLUDE_SIMULATOR_LOGS=true` somewhere.

That is the only other thing that I can think of that overrides that setting.

If there are still problems, please let me know and attach the console output as a text file to this issue (makes it easier for me to review). If it works, please let me know.

@lyndsey-ferguson I had already modified the plugin file per your instructions. This way, bundle install didn't modify the SHA in Gemfile.lock to 2ada8c7010d9c2fb050808e81067fab933878d32.
Is this correct?
gem 'fastlane-plugin-test_center', :git => "https://github.com/lyndsey-ferguson/fastlane-plugin-test_center.git", :branch => "issue-248-fix-empty-sim-logs"

What happens is that sometimes Gem will see that you already have a reference to the branch, and it won't update the SHA. I believe that you can edit the commit SHA in the Gemfile.lock file directly to be the desired value. Or, if you don't mind, for testing purposes, just delete the Gemfile.lock file and bundle install.

So, the bad news is that I have a huge mess on my end because I cannot get the verbose flag to take effect. The good news is that it worked with your latest fix!

faslane_env_7_17.txt
output_7_17.txt

So, your logs indicate that turning off include_simulator_logs worked and it didn't try to get the logs. Can you test turning on :include_simulator_logs by setting it to true and confirm it doesn't xcrun simctl spawn --standalone ... and instead gets logs without the --standalone flag?

This looks good to me. I've got a different error but might be on my end:

[worker 2] [11:18:43]: $ xcrun simctl spawn 30A83B96-0686-4296-A042-46A764775465 log collect --output /Users/l*/*/iOS-*/build/test_output/AcceptanceTests-batch-2/system_logs-iPhone\ 11\ Pro\ Clone\ 2\ TestCenter::Helper::MultiScanManager::SimulatorHelper\<70284804004240\>_iOS_13.5.logarchive 2>/dev/null

output_include_sim_logs.txt

(This was local, I will provide further details for what happened on circleci)

Pretty much same failure at circleci, still unrelated with the original problem

+--------------------+----+
|      Test Results       |
+--------------------+----+
| Number of tests    | 17 |
| Number of failures | 0  |
+--------------------+----+

[14:52:28]: ------------------------------
[14:52:28]: --- Collecting system logs ---
[14:52:28]: ------------------------------
[14:52:28]: $ xcrun simctl spawn 31B3475D-84A9-4304-AC89-99A8E49A8814 log collect --output /Users/distiller/project/build/test_output/AcceptanceTests-batch-1/system_logs-iPhone\ 11\ Pro_iOS_13.4.1.logarchive 2>/dev/null

[14:52:28]: Exit status: 165
+---------------------------+--------------------------------------------------------+
|                                    Lane Context                                    |
+---------------------------+--------------------------------------------------------+
| DEFAULT_PLATFORM          | ios                                                    |
| PLATFORM_NAME             | ios                                                    |
| LANE_NAME                 | ios acceptance_tests                                   |
| ORIGINAL_DEFAULT_KEYCHAIN | "/Users/distiller/Library/Keychains/login.keychain-db" |
+---------------------------+--------------------------------------------------------+
[14:52:28]: Exit status: 165

+------+----------------------------+-------------+
|                fastlane summary                 |
+------+----------------------------+-------------+
| Step | Action                     | Time (in s) |
+------+----------------------------+-------------+
| 1    | Verifying fastlane version | 0           |
| 2    | default_platform           | 0           |
| 3    | xcode_select               | 0           |
| 4    | setup_circle_ci            | 0           |
| ๐Ÿ’ฅ   | multi_scan                 | 408         |
+------+----------------------------+-------------+

[14:52:28]: fastlane finished with errors

[!] Exit status: 165

Exited with code exit status 1
CircleCI received exit code 1

@lilyball I would appreciate it if you could test this: I'd like to confirm that this addresses your concerns. If you're too busy right now, I can merge this on Friday and we can open up another issue if there are remaining problems.

I finally got a chance to test this, and I finally have logs! ๐ŸŽ‰

Thanks for letting me know! AND thanks for taking the time to report the other issues.