Skip to content

HTTPS clone URL

Subversion checkout URL

You can clone with HTTPS or Subversion.

Download ZIP

Loading…

Use Chef::Log as a global logging resource during tests. #32

Closed
crekev opened this Issue · 3 comments

2 participants

@crekev

Hi,

It will be GREAT, if minitest-chef-handler will use Chef::Log as a global logging resource during tests.

I'm using chef-solo and doing calls like:

$ /usr/bin/chef-solo -j ~/chef/chef_run.json -c ~/chef/config/solo.rb -l debug -L ~/chef/chef_run-20120829134843.log

after the chef-run, I see in the logfile (-L) output like this:

[Wed, 29 Aug 2012 13:39:10 +0000] INFO: Running report handlers
[Wed, 29 Aug 2012 13:39:10 +0000] INFO: Gem memcached is already installed - skipping
[Wed, 29 Aug 2012 13:39:10 +0000] DEBUG: service[memcached]: falling back to process table inspection
[Wed, 29 Aug 2012 13:39:10 +0000] DEBUG: service[memcached]: attempting to match 'memcached' (/memcached/) against process list
[Wed, 29 Aug 2012 13:39:10 +0000] DEBUG: service[memcached]: running: true
[Wed, 29 Aug 2012 13:39:10 +0000] DEBUG: service[memcached]: runlevel 6, action stop, priority 20
[Wed, 29 Aug 2012 13:39:10 +0000] DEBUG: service[memcached]: runlevel 5, action start, priority 20
[Wed, 29 Aug 2012 13:39:10 +0000] DEBUG: service[memcached]: runlevel 4, action start, priority 20
[Wed, 29 Aug 2012 13:39:10 +0000] DEBUG: service[memcached]: runlevel 3, action start, priority 20
[Wed, 29 Aug 2012 13:39:10 +0000] DEBUG: service[memcached]: runlevel 2, action start, priority 20
[Wed, 29 Aug 2012 13:39:10 +0000] DEBUG: service[memcached]: runlevel 1, action stop, priority 20
[Wed, 29 Aug 2012 13:39:10 +0000] DEBUG: service[memcached]: runlevel 0, action stop, priority 20
[Wed, 29 Aug 2012 13:39:11 +0000] INFO: Report handlers complete
[Wed, 29 Aug 2012 13:39:11 +0000] DEBUG: Exiting

the Minitest's output is missing.

I was expecting to see something like this (important when there are broken tests):

[Wed, 29 Aug 2012 14:28:29 +0000] INFO: Running report handlers
[Wed, 29 Aug 2012 14:28:29 +0000] INFO: Gem memcached   is already installed - skipping
Run options: -v --seed 21695

# Running tests:

MemcacheTest#test_access_service_on_127_0_0_1 = 0.01 s = F
MemcacheTest#test_memcache_access_via_tcp_on_private_ip = 0.00 s = .
MemcacheTest#test_access_service_on_private_ip = 0.00 s = F
MemcacheTest#test_service_started = [Wed, 29 Aug 2012 14:28:30 +0000] DEBUG: service[memcached]: falling back to process table inspection
[Wed, 29 Aug 2012 14:28:30 +0000] DEBUG: service[memcached]: attempting to match 'memcached' (/memcached/) against process list
[Wed, 29 Aug 2012 14:28:30 +0000] DEBUG: service[memcached]: running: true
[Wed, 29 Aug 2012 14:28:30 +0000] DEBUG: service[memcached]: runlevel 6, action stop, priority 20
[Wed, 29 Aug 2012 14:28:30 +0000] DEBUG: service[memcached]: runlevel 5, action start, priority 20
[Wed, 29 Aug 2012 14:28:30 +0000] DEBUG: service[memcached]: runlevel 4, action start, priority 20
[Wed, 29 Aug 2012 14:28:30 +0000] DEBUG: service[memcached]: runlevel 3, action start, priority 20
[Wed, 29 Aug 2012 14:28:30 +0000] DEBUG: service[memcached]: runlevel 2, action start, priority 20
[Wed, 29 Aug 2012 14:28:30 +0000] DEBUG: service[memcached]: runlevel 1, action stop, priority 20
[Wed, 29 Aug 2012 14:28:30 +0000] DEBUG: service[memcached]: runlevel 0, action stop, priority 20
0.05 s = .
MemcacheTest#test_memcache_access_via_tcp_on_localhost = 0.00 s = .
MemcacheTest#test_access_service_on_localhost = 0.00 s = F
MemcacheTest#test_memcache_access_via_tcp_on_127_0_0_1 = 0.00 s = .
MemcacheTest#test_exist_monit_configuration_file = 0.00 s = .
MemcacheTest#test_exist_service_configuration_file = 0.00 s = .


Finished tests in 0.068186s, 131.9919 tests/s, 483.9703 assertions/s.

  1) Failure:
test_access_service_on_127_0_0_1(MemcacheTest) [/opt/cookbooks/memcached/tests/default_test.rb:67]:
xyzxyzxyzxyzxyzxyzxyzxyzxyzxyz.
Expected "xyzxyzxyzxyzxyzxyzxyzxyzxyzxyz" to be nil.

  2) Failure:
test_access_service_on_private_ip(MemcacheTest) [/opt/cookbooks/memcached/tests/default_test.rb:67]:
xyzxyzxyzxyzxyzxyzxyzxyzxyzxyz.
Expected "xyzxyzxyzxyzxyzxyzxyzxyzxyzxyz" to be nil.

  3) Failure:
test_access_service_on_localhost(MemcacheTest) [/opt/cookbooks/memcached/tests/default_test.rb:67]:
xyzxyzxyzxyzxyzxyzxyzxyzxyzxyz.
Expected "xyzxyzxyzxyzxyzxyzxyzxyzxyzxyz" to be nil.

9 tests, 33 assertions, 3 failures, 0 errors, 0 skips
[Wed, 29 Aug 2012 14:28:30 +0000] INFO: Report handlers complete
[Wed, 29 Aug 2012 14:28:30 +0000] ERROR: Running exception handlers
[Wed, 29 Aug 2012 14:28:30 +0000] ERROR: Exception handlers complete
[Wed, 29 Aug 2012 14:28:30 +0000] DEBUG: Re-raising exception: RuntimeError - MiniTest failed with 3 failure(s) and 0 error(s).
...(stacktrace)````

I get the right output when running chef-solo in the console logging to STDOUT.



Thanks,
Christian
@calavera
Owner

we can probably fix that setting the minitest output, something like this:

Minitest::Unit.output = Chef::Log

although I'm not sure if Chef::Log is really an output stream

@calavera calavera closed this in a725968
@calavera
Owner

I've released the version 0.6.2 that fixes this problem.

@crekev

I solved the problem a bit different (git://gist.github.com/4016688.git). Your way is very elegant, but it leaves some important information out of the logs like the timestamps and formatting is not consistent.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Something went wrong with that request. Please try again.