search

kmsquire / Logging.jl

Logging package for julia
Other
43 stars 26 forks source link

default root logger output results in a `TTY(invalid status, ...)` on 0.4 #28

Open rofinn opened 8 years ago

rofinn commented 8 years ago

So I initially came across this problem when I found this.

julia> using Logging
WARNING: Method definition info(Any...) in module Base at util.jl:334 overwritten in module Logging at /Users/rory/.julia/v0.4/Logging/src/Logging.jl:61.
WARNING: Method definition warn(Any...) in module Base at util.jl:364 overwritten in module Logging at /Users/rory/.julia/v0.4/Logging/src/Logging.jl:61.

julia> Logging.configure(level=DEBUG)
Logger(root,DEBUG,Base.TTY(invalid status, 0 bytes waiting),root)

julia> Logging.info("blah")

signal (11): Segmentation fault: 11
uv_write2 at /Users/rory/.playground/src/julia-0.4_2015-11-30/Contents/Resources/julia/lib/julia/libjulia.dylib (unknown line)
uv_write at /Users/rory/.playground/src/julia-0.4_2015-11-30/Contents/Resources/julia/lib/julia/libjulia.dylib (unknown line)
jl_uv_write at /Users/osx/buildbot/slave/package_osx10_9-x64/build/src/jl_uv.c:358
uv_write at /Users/rory/.playground/src/julia-0.4_2015-11-30/Contents/Resources/julia/lib/julia/sys.dylib (unknown line)
buffer_or_write at /Users/rory/.playground/src/julia-0.4_2015-11-30/Contents/Resources/julia/lib/julia/sys.dylib (unknown line)
write at /Users/rory/.playground/src/julia-0.4_2015-11-30/Contents/Resources/julia/lib/julia/sys.dylib (unknown line)
print at /Users/rory/.playground/src/julia-0.4_2015-11-30/Contents/Resources/julia/lib/julia/sys.dylib (unknown line)
jlcall_print_19103 at /Users/rory/.playground/src/julia-0.4_2015-11-30/Contents/Resources/julia/lib/julia/sys.dylib (unknown line)
jl_apply at /Users/osx/buildbot/slave/package_osx10_9-x64/build/src/./julia.h:1325
with_output_color at util.jl:316
jl_apply at /Users/osx/buildbot/slave/package_osx10_9-x64/build/src/gf.c:1691
jl_apply at /Users/osx/buildbot/slave/package_osx10_9-x64/build/src/./julia.h:1325
print_with_color at util.jl:320
jl_apply at /Users/osx/buildbot/slave/package_osx10_9-x64/build/src/gf.c:1691
info at /Users/rory/.julia/v0.4/Logging/src/Logging.jl:53
info at /Users/rory/.julia/v0.4/Logging/src/Logging.jl:61
jl_apply at /Users/osx/buildbot/slave/package_osx10_9-x64/build/src/gf.c:1691
jl_apply at /Users/osx/buildbot/slave/package_osx10_9-x64/build/src/interpreter.c:55
eval at /Users/osx/buildbot/slave/package_osx10_9-x64/build/src/interpreter.c:213
jl_toplevel_eval_flex at /Users/osx/buildbot/slave/package_osx10_9-x64/build/src/toplevel.c:527
jl_toplevel_eval_in at /Users/osx/buildbot/slave/package_osx10_9-x64/build/src/builtins.c:579
eval_user_input at REPL.jl:62
jlcall_eval_user_input_21249 at  (unknown line)
jl_apply at /Users/osx/buildbot/slave/package_osx10_9-x64/build/src/./julia.h:1325
anonymous at REPL.jl:92
jl_apply at /Users/osx/buildbot/slave/package_osx10_9-x64/build/src/task.c:241
fish: 'julia' terminated by signal SIGSEGV (Address boundary error)

I can confirm that is isn't related to some other packages I have installed as I tried this with a fresh package directory. Similarly, I've tested that this happens on both v0.4.0 and v0.4.1.

My temporary solution is to specify the output with:

julia> using Logging
WARNING: Method definition info(Any...) in module Base at util.jl:334 overwritten in module Logging at /Users/rory/.julia/v0.4/Logging/src/Logging.jl:61.
WARNING: Method definition warn(Any...) in module Base at util.jl:364 overwritten in module Logging at /Users/rory/.julia/v0.4/Logging/src/Logging.jl:61.

julia> Logging.configure(output=STDOUT, level=DEBUG)
Logger(root,DEBUG,Base.TTY(open, 0 bytes waiting),root)

julia> Logging.info("blah")
06-Dec 19:07:28:INFO:root:blah
kmsquire commented 8 years ago

@Rory-Finnegan, sorry not to respond sooner. I working back through older issues in various packages I own/have a stake in.

Unfortunately, it's totally unclear to me what it is happening here. I've run the same commands on OSX and don't have any problems.

When you get the chance, can you:

  1. verify this is still happening on v0.4.3 (that's what I'm running)
  2. if so, give the output of versioninfo()
  3. provide more details about your setup--I notice playground in the backtrace output above, which suggests that you might be running julia in a slightly non-standard way?
rofinn commented 8 years ago

@kmsquire No worries, I don't think this is a huge issue anyways.

Yes, this is being run inside a playground, which changes PATH to look in .playground/bin first for the julia executable (a symlink to an installed binary in a shared ~/.playground directory). It also has its own package directory.

So, running it with v0.4.3 still produces the same error.

julia> versioninfo(true)
Julia Version 0.4.3
Commit a2f713d (2016-01-12 21:37 UTC)
Platform Info:
  System: Darwin (x86_64-apple-darwin13.4.0)
  CPU: Intel(R) Core(TM) i7-5557U CPU @ 3.10GHz
  WORD_SIZE: 64
  uname: Darwin 15.0.0 Darwin Kernel Version 15.0.0: Sat Sep 19 15:53:46 PDT 2015; root:xnu-3247.10.11~1/RELEASE_X86_64 x86_64 i386
Memory: 16.0 GB (1154.23046875 MB free)
Uptime: 86989.0 sec
Load Avg:  2.060546875  1.97802734375  2.001953125
Intel(R) Core(TM) i7-5557U CPU @ 3.10GHz:
       speed         user         nice          sys         idle          irq
#1  3100 MHz      69027 s          0 s      75449 s     315635 s          0 s
#2  3100 MHz      30624 s          0 s      25430 s     404048 s          0 s
#3  3100 MHz      59875 s          0 s      62566 s     337662 s          0 s
#4  3100 MHz      32337 s          0 s      26401 s     401364 s          0 s

  BLAS: libopenblas (USE64BITINT DYNAMIC_ARCH NO_AFFINITY Haswell)
  LAPACK: libopenblas64_
  LIBM: libopenlibm
  LLVM: libLLVM-3.3
Environment:
  HOME = /Users/rory
  JULIA_HISTORY = /Users/rory/repos/Fox.jl/.playground/.julia_history
  JULIA_PKGDIR = /Users/rory/repos/Fox.jl/.playground/packages
  OMF_PATH = /Users/rory/.local/share/omf
  ORIGINAL_PATH = /usr/local/bin/usr/local/sbin/usr/bin/bin/usr/sbin/sbin/opt/X11/bin/usr/texbin
  PATH = /Users/rory/.playground/src/julia-0.4_2016-01-17/Contents/Resources/julia/bin:/Users/rory/.playground/src/julia-0.4_2016-01-17/Contents/Resources/julia/libexec/git-core:/Users/rory/.playground/bin:/Users/rory/bin:/Users/rory/repos/julia:/usr/local/opt/coreutils/libexec/gnubin:/usr/local/heroku/bin:/opt/X11/bin:/usr/texbin::/usr/local/bin:/usr/bin:/bin:/usr/local/sbin:/usr/sbin:/sbin
  TERM = linux
  XPC_FLAGS = 0x0
  FONTCONFIG_PATH = /Users/rory/.playground/src/julia-0.4_2016-01-17/Contents/Resources/julia/etc/fonts

Package Directory: /Users/rory/repos/Fox.jl/.playground/packages/v0.4
4 required packages:
 - ArgParse                      0.3.0
 - Logging                       0.2.0
 - Playground                    0.0.4
 - YAML                          0.1.10
4 additional packages:
 - Codecs                        0.1.5
 - Compat                        0.7.8
 - Dates                         0.4.4
 - TextWrap                      0.1.5

Interestingly, in another playground with the same julia version and same version of Logging.jl installed I don't get the error.

julia> versioninfo(true)
Julia Version 0.4.3
Commit a2f713d (2016-01-12 21:37 UTC)
Platform Info:
  System: Darwin (x86_64-apple-darwin13.4.0)
  CPU: Intel(R) Core(TM) i7-5557U CPU @ 3.10GHz
  WORD_SIZE: 64
  uname: Darwin 15.0.0 Darwin Kernel Version 15.0.0: Sat Sep 19 15:53:46 PDT 2015; root:xnu-3247.10.11~1/RELEASE_X86_64 x86_64 i386
Memory: 16.0 GB (1324.296875 MB free)
Uptime: 87596.0 sec
Load Avg:  1.82275390625  2.1064453125  2.04345703125
Intel(R) Core(TM) i7-5557U CPU @ 3.10GHz:
       speed         user         nice          sys         idle          irq
#1  3100 MHz      69753 s          0 s      76121 s     320308 s          0 s
#2  3100 MHz      30932 s          0 s      25670 s     409573 s          0 s
#3  3100 MHz      60548 s          0 s      63131 s     342495 s          0 s
#4  3100 MHz      32662 s          0 s      26654 s     406858 s          0 s

  BLAS: libopenblas (USE64BITINT DYNAMIC_ARCH NO_AFFINITY Haswell)
  LAPACK: libopenblas64_
  LIBM: libopenlibm
  LLVM: libLLVM-3.3
Environment:
  HOME = /Users/rory
  JULIA_HISTORY = /Users/rory/repos/Playground.jl/.playground/.julia_history
  JULIA_PKGDIR = /Users/rory/repos/Playground.jl/.playground/packages
  OMF_PATH = /Users/rory/.local/share/omf
  ORIGINAL_PATH = /usr/local/bin/usr/local/sbin/usr/bin/bin/usr/sbin/sbin/opt/X11/bin/usr/texbin
  PATH = /Users/rory/.playground/src/julia-0.4_2016-01-17/Contents/Resources/julia/bin:/Users/rory/.playground/src/julia-0.4_2016-01-17/Contents/Resources/julia/libexec/git-core:/Users/rory/.playground/bin:/Users/rory/bin:/Users/rory/repos/julia:/usr/local/opt/coreutils/libexec/gnubin:/usr/local/heroku/bin:/opt/X11/bin:/usr/texbin::/usr/local/bin:/usr/bin:/bin:/usr/local/sbin:/usr/sbin:/sbin
  TERM = linux
  XPC_FLAGS = 0x0
  FONTCONFIG_PATH = /Users/rory/.playground/src/julia-0.4_2016-01-17/Contents/Resources/julia/etc/fonts

Package Directory: /Users/rory/repos/Playground.jl/.playground/packages/v0.4
1 required packages:
 - Playground                    0.0.3+             playground-executable (dirty)
10 additional packages:
 - ArgParse                      0.3.0
 - Codecs                        0.1.5
 - Compat                        0.7.7
 - Dates                         0.4.4
 - DeclarativePackages           0.1.2
 - Lint                          0.1.68
 - Logging                       0.2.0
 - Mocking                       0.0.0-             master (unregistered)
 - TextWrap                      0.1.5
 - YAML                          0.1.10

Maybe something weird is happening with precompilation in the one playground...? I know that precompiling IO references like STDOUT can have weird behaviour, which might explain that prior to the segfault the TTY shows invalid status. It still seems really specific to the one playground though :/ If you want I could also try rebuilding this playground from scratch to see what happens?