Jira (FACT-2678) Facter sometimes pollutes the calling processes environment (race condition)

[Nick Maludy (Jira)]

Nick Maludy created an issue

Facter / FACT-2678 Facter sometimes pollutes the calling processes environment (race condition) Issue Type: Bug Affects Versions: FACT 4.0.26, FACT 4.0.21 Assignee: Unassigned Components: Facter 4 Created: 2020/06/23 11:56 AM Priority: Normal Reporter: Nick Maludy When running Bolt, we were noticing that the LANG and LC_ALL environment variables were being set to 'C' sometimes when our plans and tasks were being executed. This was causing issues for plans/tasks that expected other encodings such as UTF-8.   Doing a bunch of debugging, with the help of Nick Lewis , we were able to find that Facter has a race condition that can pollute the LANG and LC_ALL environment variables and leaves them set to 'C'.   Here is the code in question: https://github.com/puppetlabs/facter/blob/4.x/lib/custom_facts/core/execution/base.rb As you can see, it saves the LANG and LC_ALL environment variables that are changed and then restores then when the command completes. However, Facter runs multi-threaded, and so there is a race condition of multiple threads running at the same time, saving and restoring environment variables.   Take the following scenario as an example: You have threads t1 and t2, and LANG is set to en_US.UTF-8   t1 starts, saves LANG=en_US.UTF-8 and modifies LANG=C, LC_ALL=C t1 runs its command t2 starts, saves LANG=C, LC_ALL=C because of t1 above t2 runs its command t1 finishes and restores LANG=en_US.UTF-8 and LC_ALL='' t2 finishes and restores LANG=C and LC_ALL=C This exact race condition is demonstrated in the logs below. I've added in outputs to the execute() and with_env() functions: [tid=34510640] facter execute(): cat /proc/self/mounts [tid=34510640] facter with_env() BEGIN ENV[LANG] = en_US.UTF-8 [tid=34512720] facter execute(): uname -m && uname -n && uname -p && uname -r && uname -s && uname -v [tid=34512720] facter with_env() BEGIN ENV[LANG] = C [tid=29460540] facter execute(): which lsb_release [tid=29460540] facter with_env() BEGIN ENV[LANG] = C [tid=34510640] facter with_env() END = en_US.UTF-8 [tid=29460540] facter with_env() END = C [tid=29460540] facter execute(): lsb_release -a [tid=29460540] facter with_env() END ENV[LANG] = C [tid=34512720] facter with_env() END = C [tid=29460540] facter with_env() END = C   I've noticed that Facter is using Open3.capture3() here: https://github.com/puppetlabs/facter/blob/4.x/lib/custom_facts/core/execution/base.rb#L85     Curious if we could potentially pass in a copied and modified environment hash instead of actually modifying the actual processes environment to avoid this race condition?   According to the docs, it looks like Open3.capture3 accepts an `env` argument: https://docs.ruby-lang.org/en/2.0.0/Open3.html#method-i-capture3 Add Comment

This message was sent by Atlassian Jira (v8.5.2#805002-sha1:a66f935)

[Nick Maludy (Jira)]

Nick Maludy updated an issue

Facter / FACT-2678 Facter sometimes pollutes the calling processes environment (race condition)

Change By: Nick Maludy

When running Bolt, we were noticing that the LANG and LC_ALL environment variables were being set to 'C' sometimes when our plans and tasks were being executed. This was causing issues for plans/tasks that expected other encodings such as UTF-8.

Doing a bunch of debugging, with the help of [~nick] , we were able to find that Facter has a race condition that can pollute the LANG and LC_ALL environment variables and leaves them set to 'C'.

Here is the code in question: [https://github.com/puppetlabs/facter/blob/4.x/lib/custom_facts/core/execution/base.rb] As you can see, it saves the LANG and LC_ALL environment variables that are changed and then restores then when the command completes. However, Facter runs multi-threaded, and so there is a race condition of multiple threads running at the same time, saving and restoring environment variables.   Take the following scenario as an example: You have threads t1 and t2, and LANG is set to en_US.UTF-8

* t1 starts, saves LANG=en_US.UTF-8 and modifies LANG=C, LC_ALL=C * t1 runs its command * t2 starts, saves LANG=C, LC_ALL=C because of t1 above * t2 runs its command * t1 finishes and restores LANG=en_US.UTF-8 and LC_ALL='' * t2 finishes and restores LANG=C and LC_ALL=C

This exact race condition is demonstrated in the logs below. I've added in outputs to the execute() and with_env() functions:

{code:java}

[tid=34510640] facter execute(): cat /proc/self/mounts [tid=34510640] facter with_env() BEGIN ENV[LANG] = en_US.UTF-8 [tid=34512720] facter execute(): uname -m && uname -n && uname -p && uname -r && uname -s && uname -v [tid=34512720] facter with_env() BEGIN ENV[LANG] = C [tid=29460540] facter execute(): which lsb_release [tid=29460540] facter with_env() BEGIN ENV[LANG] = C

[tid=34510640] facter with_env() END ENV[LANG] = en_US.UTF-8 [tid=29460540] facter with_env() END ENV[LANG] = C

[tid=29460540] facter execute(): lsb_release -a [tid=29460540] facter with_env() END ENV[LANG] = C

[tid=34512720] facter with_env() END ENV[LANG] = C [tid=29460540] facter with_env() END ENV[LANG] = C{code}

I've noticed that Facter is using Open3.capture3() here: [https://github.com/puppetlabs/facter/blob/4.x/lib/custom_facts/core/execution/base.rb#L85]     Curious if we could potentially pass in a copied and modified environment hash instead of actually modifying the actual processes environment to avoid this race condition?   According to the docs, it looks like Open3.capture3 accepts an `env` argument:

[ https://docs.ruby-lang.org/en/2.0.0/Open3.html#method-i-capture3 ]

Add Comment

[Mihai Buzgau (Jira)]

Mihai Buzgau updated an issue

Facter / FACT-2678 Facter sometimes pollutes the calling processes environment (race condition)

Change By: Mihai Buzgau Sub-team: ghost

Add Comment

[Mihai Buzgau (Jira)]

Mihai Buzgau updated an issue

Facter / FACT-2678 Facter sometimes pollutes the calling processes environment (race condition)

Change By: Mihai Buzgau Team: Night's Watch

Add Comment

[Mihai Buzgau (Jira)]

Mihai Buzgau updated an issue

Facter / FACT-2678 Facter sometimes pollutes the calling processes environment (race condition)

Change By: Mihai Buzgau Sprint: ready for triage

Add Comment

[Bogdan Irimie (Jira)]

Bogdan Irimie updated an issue

Facter / FACT-2678 Facter sometimes pollutes the calling processes environment (race condition)

Change By: Bogdan Irimie Sprint: ready for triage ghost - 2020-06-24

Add Comment

[Bogdan Irimie (Jira)]

Bogdan Irimie assigned an issue to Bogdan Irimie

Facter / FACT-2678 Facter sometimes pollutes the calling processes environment (race condition)

Change By: Bogdan Irimie Assignee: Bogdan Irimie

Add Comment

[Bogdan Irimie (Jira)]

Bogdan Irimie commented on FACT-2678

Re: Facter sometimes pollutes the calling processes environment (race condition) Nick Maludy and Nick Lewis great job, you are right, there is a race condition. We managed to reproduce it with # frozen_string_literal: true   describe Facter::Core::Execution::Posix do subject(:posix) { Facter::Core::Execution::Posix }   describe '#execute' do context 'when two threads have race condition' do it 'keeps LANG variable' do pc = posix.new t1 = Thread.new do pc.execute('sleep 2') end sleep 1 t2 = Thread.new do pc.execute('sleep 3') end t2.join expect(ENV['LANG']).to eq('en_GB.UTF-8') end end end end

Add Comment