Skip to content
This repository has been archived by the owner on Sep 6, 2023. It is now read-only.

Commit

Permalink
refactor(logging): rename log prefix from jsr223.jruby to org.openhab…
Browse files Browse the repository at this point in the history
….automation.jruby
  • Loading branch information
jimtng committed Jan 13, 2022
1 parent 017e90b commit 9d3513e
Show file tree
Hide file tree
Showing 6 changed files with 22 additions and 24 deletions.
16 changes: 7 additions & 9 deletions docs/usage/misc/logging.md
Original file line number Diff line number Diff line change
Expand Up @@ -9,25 +9,23 @@ grand_parent: Usage

# Logging

Logging is available everywhere through the logger object.
Logging is available everywhere through the logger object.

Logging placed outside of a rule will have the name of the file appened to the logger name. The following entries are in a file named 'log_test.rb'

```ruby
logger.trace('Test logging at trace') # 2020-12-03 18:05:20.903 [TRACE] [jsr223.jruby.log_test ] - Test logging at trace
logger.debug('Test logging at debug') # 2020-12-03 18:05:32.020 [DEBUG] [jsr223.jruby.log_test ] - Test logging at debug
logger.warn('Test logging at warn') # 2020-12-03 18:05:41.817 [WARN ] [jsr223.jruby.log_test ] - Test logging at warn
logger.info('Test logging at info') # 2020-12-03 18:05:41.817 [INFO ] [jsr223.jruby.log_test ] - Test logging at info
logger.error('Test logging at error') # 2020-12-03 18:06:02.021 [ERROR] [jsr223.jruby.log_test ] - Test logging at error
logger.trace('Test logging at trace') # 2020-12-03 18:05:20.903 [TRACE] [org.openhab.automation.jruby.log_test] - Test logging at trace
logger.debug('Test logging at debug') # 2020-12-03 18:05:32.020 [DEBUG] [org.openhab.automation.jruby.log_test] - Test logging at debug
logger.warn('Test logging at warn') # 2020-12-03 18:05:41.817 [WARN ] [org.openhab.automation.jruby.log_test] - Test logging at warn
logger.info('Test logging at info') # 2020-12-03 18:05:41.817 [INFO ] [org.openhab.automation.jruby.log_test] - Test logging at info
logger.error('Test logging at error') # 2020-12-03 18:06:02.021 [ERROR] [org.openhab.automation.jruby.log_test] - Test logging at error
```

Logging inside of a rule will have the name of the rule appened to the logger name. The following entries are in a file named 'log_test.rb'

```ruby
rule 'foo' do
run { logger.trace('Test logging at trace') } # 2020-12-03 18:05:20.903 [TRACE] [jsr223.jruby.log_test.foo ] - Test logging at trace
run { logger.trace('Test logging at trace') } # 2020-12-03 18:05:20.903 [TRACE] [org.openhab.automation.jruby.log_test.foo] - Test logging at trace
on_start
end
```


20 changes: 10 additions & 10 deletions features/logging.feature
Original file line number Diff line number Diff line change
Expand Up @@ -36,7 +36,7 @@ Feature: logging
logger.info("Hello World!")
"""
When I deploy the rules file named "foo_bar.rb"
Then It should log only "Hello World!" at level "INFO" from 'jsr223.jruby.foo_bar' within 5 seconds
Then It should log only "Hello World!" at level "INFO" from 'org.openhab.automation.jruby.foo_bar' within 5 seconds


Scenario: Logging should include rule name inside a rule
Expand All @@ -49,7 +49,7 @@ Feature: logging
"""
When I deploy the rules file named "log_rule_test.rb"
Then It should log only "Log Test" at level "INFO" from 'jsr223.jruby.log_rule_test.log_test' within 5 seconds
Then It should log only "Log Test" at level "INFO" from 'org.openhab.automation.jruby.log_rule_test.log_test' within 5 seconds

Scenario: Methods called by a rule have the rule file and name in their log name
Given code in a rules file
Expand All @@ -65,38 +65,38 @@ Feature: logging
"""
When I deploy the rules file named "log_file.rb"
Then It should log only "Foo" at level "INFO" from 'jsr223.jruby.log_file.log_test' within 5 seconds
Then It should log only "Foo" at level "INFO" from 'org.openhab.automation.jruby.log_file.log_test' within 5 seconds

Scenario: Logs in after blocks (timers) should have file and rule name in log prefix
Given code in a rules file
"""
rule 'log test' do
on_start
run do
run do
after 1.second do
logger.info('Bar')
end
end
end
"""
When I deploy the rules file named "log_file.rb"
Then It should log only "Bar" at level "INFO" from 'jsr223.jruby.log_file.log_test' within 5 seconds
Then It should log only "Bar" at level "INFO" from 'org.openhab.automation.jruby.log_file.log_test' within 5 seconds

Scenario: Logs in blocks after trigger delays should have file and rule name in log prefix
Given items:
| type | name | state |
| Number | Foo | 0 |
Given items:
| type | name | state |
| Number | Foo | 0 |
Given a rule:
"""
rule 'log test' do
changed Foo, to: 5, for: 3.seconds
run do
run do
logger.info('Baz')
end
end
"""
When I deploy the rules file named "log_file.rb"
And item "Foo" state is changed to "5"
Then It should log only "Baz" at level "INFO" from 'jsr223.jruby.log_file.log_test' within 8 seconds
Then It should log only "Baz" at level "INFO" from 'org.openhab.automation.jruby.log_file.log_test' within 8 seconds


4 changes: 2 additions & 2 deletions features/step_definitions/openhab.rb
Original file line number Diff line number Diff line change
Expand Up @@ -42,7 +42,7 @@

# rubocop:disable Metrics/LineLength
Then('It should log only {string} at level {string} from {string} within {int} seconds') do |entry, level, logger, seconds|
# 2021-11-15 19:24:34.574 [INFO ] [jsr223.jruby.rules.log_test ] - Log Test
# 2021-11-15 19:24:34.574 [INFO ] [org.openhab.automation.jruby.rules.log_test] - Log Test
# Trim level to the right most 36 chars (per logging config)
logger_length = 36
logger = logger[-logger_length, logger_length] if logger.length > logger_length
Expand Down Expand Up @@ -233,7 +233,7 @@ def check_items(added:)
end

Given('(set )log level (to ){word}') do |level|
set_log_level('jsr223.jruby', level)
set_log_level('org.openhab.automation.jruby', level)
set_log_level('org.openhab.automation.jrubyscripting', level)
set_log_level('org.openhab.core.automation', level)
end
Expand Down
2 changes: 1 addition & 1 deletion features/support/env.rb
Original file line number Diff line number Diff line change
Expand Up @@ -22,7 +22,7 @@ def prepare_openhab
end

After('@log_level_changed') do
set_log_level('jsr223.jruby', 'TRACE')
set_log_level('org.openhab.automation.jruby', 'TRACE')
set_log_level('org.openhab.automation.jrubyscripting', 'TRACE')
set_log_level('org.openhab.core.automation', 'TRACE')
end
Expand Down
2 changes: 1 addition & 1 deletion lib/openhab/log/configuration.rb
Original file line number Diff line number Diff line change
Expand Up @@ -6,7 +6,7 @@ module Log
# This module holds global configuration values
module Configuration
# -*- coding: utf-8 -*-
LOG_PREFIX = 'jsr223.jruby'
LOG_PREFIX = 'org.openhab.automation.jruby'

#
# Gets the log prefix
Expand Down
2 changes: 1 addition & 1 deletion rakelib/openhab.rake
Original file line number Diff line number Diff line change
Expand Up @@ -184,7 +184,7 @@ namespace :openhab do
# Set log levels
state(task.name) do
start
karaf('log:set TRACE jsr223')
karaf('log:set TRACE org.openhab.automation.jruby')
karaf('log:set TRACE org.openhab.core.automation')
karaf('log:set TRACE org.openhab.automation.jrubyscripting')
karaf('openhab:users add foo foo administrator')
Expand Down

0 comments on commit 9d3513e

Please sign in to comment.