Infinite recursion when KNAPSACK_PRO_LOG_LEVEL is set to debug

[dmytro-workday]

Hi,

We have set KNAPSACK_PRO_LOG_LEVEL=debug and KNAPSACK_PRO_LOG_DIR=log, which leads to the following backtrace:

[2024-08-15 12:56:16] [2024-08-15 12:56:16] [NODE=4] SystemStackError: stack level too deep (SystemStackError)
[2024-08-15 12:56:16] [2024-08-15 12:56:16] [NODE=4] /builds/app/vendor/bundle/ruby/3.2.0/gems/knapsack_pro-7.8.0/lib/knapsack_pro/config/env.rb:240:in `map'
[2024-08-15 12:56:16] [2024-08-15 12:56:16] [NODE=4] /builds/app/vendor/bundle/ruby/3.2.0/gems/knapsack_pro-7.8.0/lib/knapsack_pro/config/env.rb:240:in `detected_ci'
[2024-08-15 12:56:16] [2024-08-15 12:56:16] [NODE=4] /builds/app/vendor/bundle/ruby/3.2.0/gems/knapsack_pro-7.8.0/lib/knapsack_pro/config/env.rb:292:in `ci_env_for'
[2024-08-15 12:56:16] [2024-08-15 12:56:16] [NODE=4] /builds/app/vendor/bundle/ruby/3.2.0/gems/knapsack_pro-7.8.0/lib/knapsack_pro/config/env.rb:282:in `env_for'
[2024-08-15 12:56:16] [2024-08-15 12:56:16] [NODE=4] /builds/app/vendor/bundle/ruby/3.2.0/gems/knapsack_pro-7.8.0/lib/knapsack_pro/config/env.rb:20:in `ci_node_index'
[2024-08-15 12:56:16] [2024-08-15 12:56:16] [NODE=4] /builds/app/vendor/bundle/ruby/3.2.0/gems/knapsack_pro-7.8.0/lib/knapsack_pro.rb:99:in `logger'
[2024-08-15 12:56:16] [2024-08-15 12:56:16] [NODE=4] /builds/app/vendor/bundle/ruby/3.2.0/gems/knapsack_pro-7.8.0/lib/knapsack_pro/config/env.rb:285:in `env_for'
[2024-08-15 12:56:16] [2024-08-15 12:56:16] [NODE=4] /builds/app/vendor/bundle/ruby/3.2.0/gems/knapsack_pro-7.8.0/lib/knapsack_pro/config/env.rb:20:in `ci_node_index'
[2024-08-15 12:56:16] [2024-08-15 12:56:16] [NODE=4] /builds/app/vendor/bundle/ruby/3.2.0/gems/knapsack_pro-7.8.0/lib/knapsack_pro.rb:99:in `logger'
[2024-08-15 12:56:16] [2024-08-15 12:56:16] [NODE=4] /builds/app/vendor/bundle/ruby/3.2.0/gems/knapsack_pro-7.8.0/lib/knapsack_pro/config/env.rb:285:in `env_for'
[2024-08-15 12:56:16] [2024-08-15 12:56:16] [NODE=4] /builds/app/vendor/bundle/ruby/3.2.0/gems/knapsack_pro-7.8.0/lib/knapsack_pro/config/env.rb:20:in `ci_node_index'
[2024-08-15 12:56:16] [2024-08-15 12:56:16] [NODE=4] /builds/app/vendor/bundle/ruby/3.2.0/gems/knapsack_pro-7.8.0/lib/knapsack_pro.rb:99:in `logger'

Seems like the issue is related to the following warnings, throws when the logging directory is not enabled:

You have set the environment variable KNAPSACK_PRO_CI_NODE_TOTAL to 36 which could be automatically determined from the CI environment as 9.
You have set the environment variable KNAPSACK_PRO_CI_NODE_INDEX to 1 which could be automatically determined from the CI environment as 0.

The configuration we used is similar to the FAQ answer here:

https://knapsackpro.com/faq/question/parallel_tests-with-knapsack_pro-on-parallel-ci-nodes

[ArturT]

@dmytro-workday Could you work around the issue while we look into it? Or is this preventing you from using Knapsack Pro?

[dmytro-workday]

Yes. We have removed the _LOG_ variables for now and assigning the logger ourselves instead:

logger = Logger.new("log/knapsack_pro_node_#{KnapsackPro::Config::Env.ci_node_index}.log")
logger.level = ::Logger::DEBUG
KnapsackPro.logger = logger

[karoisuzvards]

@ArturT seems that there are some issues (though not sure if related) - only following items are found in log/knapsack_pro_node_N.log:

# Logfile created on 2025-07-09 11:11:48 +0000 by logger.rb/v1.7.0
D, [2025-07-09T11:15:27.924828 #579] DEBUG -- : [knapsack_pro] Global test execution duration: 03m 38s
I, [2025-07-09T11:15:27.925020 #579]  INFO -- : [knapsack_pro] You have set the environment variable KNAPSACK_PRO_CI_NODE_INDEX to 20 which could be automatically determined from the CI environment as 2.
I, [2025-07-09T11:15:27.925104 #579]  INFO -- : [knapsack_pro] You have set the environment variable KNAPSACK_PRO_CI_NODE_INDEX to 20 which could be automatically determined from the CI environment as 2.
D, [2025-07-09T11:17:29.742483 #774] DEBUG -- : [knapsack_pro] Global test execution duration: 01m 53s
I, [2025-07-09T11:17:29.742735 #774]  INFO -- : [knapsack_pro] You have set the environment variable KNAPSACK_PRO_CI_NODE_INDEX to 20 which could be automatically determined from the CI environment as 2.
I, [2025-07-09T11:17:29.742852 #774]  INFO -- : [knapsack_pro] You have set the environment variable KNAPSACK_PRO_CI_NODE_INDEX to 20 which could be automatically determined from the CI environment as 2.

its only observable for cucumber, for rspec its fine - for cucumber the logger setup code in env.rb

KnapsackPro::Adapters::CucumberAdapter.bind
logger = Logger.new("log/knapsack_pro_node_#{KnapsackPro::Config::Env.ci_node_index}.log")
logger.level = ::Logger::DEBUG
KnapsackPro.logger = logger

[ArturT]

I've managed to reproduce the issue locally. I'll bring this up to our team.

@ArturT seems that there are some issues (though not sure if related) - only following items are found in log/knapsack_pro_node_N.log:

# Logfile created on 2025-07-09 11:11:48 +0000 by logger.rb/v1.7.0
D, [2025-07-09T11:15:27.924828 #579] DEBUG -- : [knapsack_pro] Global test execution duration: 03m 38s
I, [2025-07-09T11:15:27.925020 #579]  INFO -- : [knapsack_pro] You have set the environment variable KNAPSACK_PRO_CI_NODE_INDEX to 20 which could be automatically determined from the CI environment as 2.
I, [2025-07-09T11:15:27.925104 #579]  INFO -- : [knapsack_pro] You have set the environment variable KNAPSACK_PRO_CI_NODE_INDEX to 20 which could be automatically determined from the CI environment as 2.
D, [2025-07-09T11:17:29.742483 #774] DEBUG -- : [knapsack_pro] Global test execution duration: 01m 53s
I, [2025-07-09T11:17:29.742735 #774]  INFO -- : [knapsack_pro] You have set the environment variable KNAPSACK_PRO_CI_NODE_INDEX to 20 which could be automatically determined from the CI environment as 2.
I, [2025-07-09T11:17:29.742852 #774]  INFO -- : [knapsack_pro] You have set the environment variable KNAPSACK_PRO_CI_NODE_INDEX to 20 which could be automatically determined from the CI environment as 2.

its only observable for cucumber, for rspec its fine - for cucumber the logger setup code in env.rb

KnapsackPro::Adapters::CucumberAdapter.bind
logger = Logger.new("log/knapsack_pro_node_#{KnapsackPro::Config::Env.ci_node_index}.log")
logger.level = ::Logger::DEBUG
KnapsackPro.logger = logger

It's not related. Are you referring to a situation when some messages are logged in the log file and some are not (they are still in the stdout)?

This is happening because the following logger configuration snippet is loaded after some messages are already printed to stdout by the Knapsack Pro logger.

KnapsackPro::Adapters::CucumberAdapter.bind
logger = Logger.new("log/knapsack_pro_node_#{KnapsackPro::Config::Env.ci_node_index}.log")
logger.level = ::Logger::DEBUG
KnapsackPro.logger = logger

There is no simple way to avoid that if you keep logger configuration in env.rb.

The best approach would be to set KNAPSACK_PRO_LOG_DIR=log, then log/knapsack_pro_node_#{KnapsackPro::Config::Env.ci_node_index}.log is a default log file. No need to add the snippet to the env.rb for Cucumber.

Please try KNAPSACK_PRO_LOG_DIR=log. If you encounter the issue let us know.

[karoisuzvards]

@ArturT issue is still present as in original message.

it starts here:

lib/knapsack_pro.rb:100

default_logger = Logger.new("#{KnapsackPro::Config::Env.log_dir}/knapsack_pro_node_#{KnapsackPro::Config::Env.ci_node_index}.log")

then it calls into:

KnapsackPro::Config::Env.ci_node_index

def ci_node_index
   (env_for('KNAPSACK_PRO_CI_NODE_INDEX', :node_index) || 0).to_i
end

then it ends up in KnapsackPro::Config::Env.env_for and calls KnapsackPro.logger again and loops:

if !knapsack_env_value.nil? && !ci_env_value.nil? && knapsack_env_value != ci_env_value.to_s
  KnapsackPro.logger.info("You have set the environment variable #{knapsack_env_name} to #{knapsack_env_value} which could be automatically determined from the CI environment as #{ci_env_value}.")
end

This message is redundant when using parallel_tests gem together with knapsack_pro: https://docs.knapsackpro.com/ruby/parallel_tests/

maybe we could avoid printing "... could be automatically determined ..." message if ENV["TEST_ENV_NUMBER"] is present and avoid infinite recursion?

[ArturT]

We've released a fix in the knapsack_pro 8.3.2 version. Please update it in your project.