Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

unity appears to rewrite log file when using -logFile argument #3

Open
lacostej opened this issue Jul 26, 2017 · 3 comments
Open

unity appears to rewrite log file when using -logFile argument #3

lacostej opened this issue Jul 26, 2017 · 3 comments
Assignees
@lacostej

Comments

@lacostej
Copy link
Member

lacostej commented Jul 26, 2017 •
edited
Loading

running the Example2 leads to some weird lines added at the top of the editor AFTER process started:

Launching external process: /Applications/Unity_5.6.1f1/Unity.app/Contents/Tools64/JobProcess
Launching external process: /Applications/Unity_5.6.1f1/Unity.app/Contents/Tools/UnityShaderCompiler
Launching external process: /Applications/Unity_5.6.1f1/Unity.app/Contents/Tools/UnityShaderCompiler
Launching external process: /Applications/Unity_5.6.1f1/Unity.app/Contents/Tools/UnityShaderCompiler
Launching external process: /Applications/Unity_5.6.1f1/Unity.app/Contents/Tools/UnityShaderCompiler
Launching external process: /Applications/Unity_5.6.1f1/Unity.app/Contents/Tools/UnityShaderCompiler
Launching external process: /Applications/Unity_5.6.1f1/Unity.app/Contents/Tools/UnityShaderCompiler
Launching external process: /Applications/Unity_5.6.1f1/Unity.app/Contents/Tools/UnityShaderCompiler
Launching external process: /Applications/Unity_5.6.1f1/Unity.app/Contents/Tools/UnityShaderCompiler

Tested on Mac with Unity 5.6.1f1

Reported as 939108 on Unity side
@lacostej
Copy link
Member Author

lacostej commented Aug 3, 2017 •
edited
Loading

Executing examples/Example2 from the CLI using 5.6.1f1 on Mac gives different log contents

Here's a cleaned diff:

--- /dev/fd/63  2017-08-03 17:12:29.000000000 +0200
+++ /dev/fd/62  2017-08-03 17:12:29.000000000 +0200
@@ -1,7 +1,11 @@
+setrlimit() failed with errno=1
+Initialize mono
+Mono path[0] = '/Applications/Unity_5.6.1f1/Unity.app/Contents/Managed'
+Mono path[1] = '/Applications/Unity_5.6.1f1/Unity.app/Contents/Mono/lib/mono/2.0'
+Mono config path = '/Applications/Unity_5.6.1f1/Unity.app/Contents/Mono/etc'
+Using monoOptions --debugger-agent=transport=dt_socket,embedding=1,defer=y,address=0.0.0.0:...
 ... Unity[...] NSDocumentController Info.plist warning: The values of CFBundleTypeRole entries must be 'Editor', 'Viewer', 'None', or 'Shell'.
 ...300157 bytes written to /Users/lacostej/Library/Unity/Certificates/CACerts.pem
-.app/Contents/Mono/etc'
-Using monoOptions --debugger-agent=transport=dt_socket,embedding=1,defer=y,address=0.0.0.0:...
 
 LICENSE SYSTEM [...] Next license update check is after...
 
@@ -9,8 +13,6 @@
 
  COMMAND LINE ARGUMENTS:
 /Applications/Unity_5.6.1f1/Unity.app/Contents/MacOS/Unity
--logFile
-./editor_5.6.1f1.log
 -executeMethod
 U3d.EditorRun.Build
 -quit

This is reproduced by doing

version=2017.1.0f3

/Applications/Unity_$version/Unity.app/Contents/MacOS/Unity -projectPath `pwd` -logFile ./editor_$version.log -executeMethod U3d.EditorRun.Build -quit -batchmode
/Applications/Unity_$version/Unity.app/Contents/MacOS/Unity -projectPath `pwd` -executeMethod U3d.EditorRun.Build -quit -batchmode
cp ~/Library/Logs/Unity/Editor.log ./editor_${version}_raw.log

u3dlogdiff.sh editor_5.6.1f1.log editor_5.6.1f1_raw.log

(see #10 for u3dlogiff)

So we cannot rely on Initialize mono being there.

Still working on the errors appearing at the top.

@lacostej
Copy link
Member Author

lacostej commented Aug 3, 2017

I tested more with 2017.1.0f3 on mac. I reproduce the overwriting of the top of the file when using the -logFile argument:

 COMMAND LINE ARGUMENTS:
/Applic[usbmuxd] Start listen thread
[usbmuxd] Listen thread started
[usbmuxd] Send listen message
Launching external process: /Applications/Unity_2017.1.0f3/Unity.app/Contents/Tools/JobProcess
Launching external process: /Applications/Unity_2017.1.0f3/Unity.app/Contents/Tools/UnityShaderCompiler
Launching external process: /Applications/Unity_2017.1.0f3/Unity.app/Contents/Tools/UnityShaderCompiler
Launching external process: /Applications/Unity_2017.1.0f3/Unity.app/Contents/Tools/UnityShaderCompiler
Launching external process: /Applications/Unity_2017.1.0f3/Unity.app/Contents/Tools/UnityShaderCompiler
Launching external process: /Applications/Unity_2017.1.0f3/Unity.app/Contents/Tools/UnityShaderCompiler
Launching external process: /Applications/Unity_2017.1.0f3/Unity.app/Contents/Tools/UnityShaderCompiler
Launching external process: /Applications/Unity_2017.1.0f3/Unity.app/Contents/Tools/UnityShaderCompiler
Launching external process: /Applications/Unity_2017.1.0f3/Unity.app/Contents/Tools/UnityShaderCompiler
debugger-agent: Unable to listen on 29
[usbmuxd] Stop listen thread
[usbmuxd] Error: 
[usbmuxd] Listen thread exiting

On other side this behaves properly

version=2017.1.0f3
/Applications/Unity_$version/Unity.app/Contents/MacOS/Unity -projectPath `pwd` -logFile /dev/stdout -executeMethod U3d.EditorRun.Build -quit -batchmode > editor_${version}_piped.log

setrlimit() failed with errno=1
2017-08-03 20:21:46.196 Unity[50887:2615825] NSDocumentController Info.plist warning: The values of CFBundleTypeRole entries must be 'Editor', 'Viewer', 'None', or 'Shell'.
...300157 bytes written to /Users/lacostej/Library/Unity/Certificates/CACerts.pem

LICENSE SYSTEM [201783 20:21:46] No start/stop license dates set

LICENSE SYSTEM [201783 20:21:46] Next license update check is after 2017-08-04T16:43:38

DisplayProgressbar: Unity license

 COMMAND LINE ARGUMENTS:
/Applications/Unity_2017.1.0f3/Unity.app/Contents/MacOS/Unity
-projectPath
/Users/lacostej/Code/WWTK/u3d/examples/Example2
-logFile
/dev/stdout
-executeMethod
U3d.EditorRun.Build
-quit
-batchmode

@lacostej lacostej mentioned this issue Aug 3, 2017
Closed
niezbop added a commit that referenced this issue Oct 1, 2017
@niezbop
u3d/all feature/detect bash on ubuntu on windows (fixed #150) (#155)
0186a68 
* Detect and warn if on Ubuntu on Windows

Add Bash on Ubuntu on Windows detection. Warns the user that the operating
system is not supported before running any command.

* u3d/commands: implementation without commands_caller (#3)
@lacostej
Copy link
Member Author

I followed this issue a bit.

Unity partially fixed this in 2017.1.1f1. From that version and above, when using the -logFile argument, the out of order messages are not written to the top of the logfile, but instead either added at the proper moment, or sent to the error output of the Unity process (something entirely new).

When not using the -logFile argument, the output is sent as expected to the main editor log file.

Here's the script I used to check things and its output

versions=( 5.6.5f1 2017.1.0f3 2017.1.1f1 2017.1.2f1 2017.1.3f1 2017.2.1f1 2017.3.0f2 )

rm -f editor*.log

for version in "${versions[@]}"; do
  echo "Using version $version"
  git checkout -- .
  /Applications/Unity_$version/Unity.app/Contents/MacOS/Unity -projectPath `pwd` -logFile ./editor_${version}_arg.log -executeMethod U3d.EditorRun.Build -quit -batchmode 2&> ./editor_${version}_err.log

  git checkout -- .

  /Applications/Unity_$version/Unity.app/Contents/MacOS/Unity -projectPath `pwd` -executeMethod U3d.EditorRun.Build -quit -batchmode

  cp ~/Library/Logs/Unity/Editor.log ./editor_${version}_raw.log

  git checkout -- .

  u3d -u $version -- -projectPath `pwd` -executeMethod U3d.EditorRun.Build -quit -batchmode -logFile ./editor_${version}_u3d_arg.log
done
-rw-r--r--  1 lacostej  staff  157890 Apr 19 22:42 editor_5.6.5f1_arg.log
-rw-r--r--  1 lacostej  staff       0 Apr 19 22:42 editor_5.6.5f1_err.log
-rw-r--r--  1 lacostej  staff   88309 Apr 19 22:43 editor_5.6.5f1_raw.log
-rw-r--r--  1 lacostej  staff   87479 Apr 19 22:43 editor_5.6.5f1_u3d_arg.log
-rw-r--r--  1 lacostej  staff  189894 Apr 19 22:43 editor_2017.1.0f3_arg.log
-rw-r--r--  1 lacostej  staff       0 Apr 19 22:43 editor_2017.1.0f3_err.log
-rw-r--r--  1 lacostej  staff  104279 Apr 19 22:43 editor_2017.1.0f3_raw.log
-rw-r--r--  1 lacostej  staff  103400 Apr 19 22:43 editor_2017.1.0f3_u3d_arg.log
-rw-r--r--  1 lacostej  staff  159037 Apr 19 22:44 editor_2017.1.1f1_arg.log
-rw-r--r--  1 lacostej  staff     806 Apr 19 22:44 editor_2017.1.1f1_err.log
-rw-r--r--  1 lacostej  staff   97400 Apr 19 22:44 editor_2017.1.1f1_raw.log
-rw-r--r--  1 lacostej  staff   96694 Apr 19 22:44 editor_2017.1.1f1_u3d_arg.log
-rw-r--r--  1 lacostej  staff  191931 Apr 19 21:43 editor_2017.1.2f1_arg.log
-rw-r--r--  1 lacostej  staff     977 Apr 19 21:43 editor_2017.1.2f1_err.log
-rw-r--r--  1 lacostej  staff  104821 Apr 19 21:43 editor_2017.1.2f1_raw.log
-rw-r--r--  1 lacostej  staff  103947 Apr 19 21:43 editor_2017.1.2f1_u3d_arg.log
-rw-r--r--  1 lacostej  staff  169828 Apr 19 21:43 editor_2017.1.3f1_arg.log
-rw-r--r--  1 lacostej  staff     977 Apr 19 21:43 editor_2017.1.3f1_err.log
-rw-r--r--  1 lacostej  staff  103741 Apr 19 21:43 editor_2017.1.3f1_raw.log
-rw-r--r--  1 lacostej  staff  102865 Apr 19 21:44 editor_2017.1.3f1_u3d_arg.log
-rw-r--r--  1 lacostej  staff  91549 Apr 19 21:44 editor_2017.2.1f1_arg.log
-rw-r--r--  1 lacostej  staff    823 Apr 19 21:44 editor_2017.2.1f1_err.log
-rw-r--r--  1 lacostej  staff  30697 Apr 19 21:44 editor_2017.2.1f1_raw.log
-rw-r--r--  1 lacostej  staff  29974 Apr 19 21:44 editor_2017.2.1f1_u3d_arg.log
-rw-r--r--  1 lacostej  staff  111894 Apr 19 21:45 editor_2017.3.0f2_arg.log
-rw-r--r--  1 lacostej  staff     823 Apr 19 21:45 editor_2017.3.0f2_err.log
-rw-r--r--  1 lacostej  staff   32451 Apr 19 21:45 editor_2017.3.0f2_raw.log
-rw-r--r--  1 lacostej  staff   31728 Apr 19 21:45 editor_2017.3.0f2_u3d_arg.log

I asked Unity to clarify if this was intended behavior. I'll wait for their answer if any.

On our side:

  • u3d isn't picking the error output from Unity and not sure if it should.
  • we can't do much with the weird behaviour pre-2017.1.1f1. Those log files are mangled

@lacostej lacostej mentioned this issue Apr 19, 2018
Merged
lacostej added a commit that referenced this issue Apr 20, 2018
@lacostej
Merge pull request #286 from lacostej/support_example
b1fea55 
u3d/examples: support Unity 2017.3+, identified while investigating #3
@lacostej lacostej self-assigned this Apr 20, 2018
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@lacostej lacostej

Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
1 participant
@lacostej