Uploaded image for project: 'Puppet'
  1. Puppet
  2. PUP-7153

Puppet fails with inscrutable errors when logging large messages on Windows

    Details

    • Type: Bug
    • Status: Closed
    • Priority: Normal
    • Resolution: Fixed
    • Affects Version/s: PUP 4.8.2
    • Fix Version/s: PUP 5.4.0
    • Component/s: Windows
    • Labels:
      None
    • Environment:

      Windows Agent

    • Release Notes:
      Not Needed
    • QA Risk Assessment:
      Manual

      Description

      The Windows event log has limits on the amount of data it will accept when logging a message:

      https://msdn.microsoft.com/en-us/library/windows/desktop/aa363679(v=vs.85).aspx

      These limits can be exceeded by exec resources which log a large volume of data. For example, a verbose recursive copy of a deep directory tree.

      Reproduction Case

      1. Install the Puppet agent on Windows Server 2012 or newer.

      2. Install the Powershell module:

      puppet module install puppetlabs/powershell
      

      3. Create a manifest with the following content:

      # large_output.pp
      exec{'log large output':
        # Repeat a character 32,000 times. Should trigger the event log limit
        command => 'Write-Output ("x" * 32000)',
        provider => powershell,
        logoutput => true,
      }
      

      4. Apply the manifest and send output to the event log:

      puppet apply large_output.pp --logdest=eventlog --logdest=console
      

      Outcome

      The command fails with a terse, cryptic message like:

      PS C:\Users\Administrator> puppet apply test.pp --logdest=eventlog --logdest=console
      Notice: Compiled catalog for pe-201642-agent-win2012 in environment production in 0.27 seconds
      Error: The parameter is incorrect. - ReportEvent
      Error: /Stage[main]/Main/Exec[test log large output]/returns: change from notrun to 0 failed: The parameter is incorrect
      . - ReportEvent
      Notice: Applied catalog in 2.89 seconds
      

      Or:

      PS C:\Users\Administrator> puppet apply test.pp --logdest=eventlog --logdest=console
      Notice: Compiled catalog for pe-201642-agent-win2012 in environment production in 0.27 seconds
      Error: The parameter is incorrect. - ReportEvent
      Error: /Stage[main]/Main/Exec[test log large output]/returns: change from notrun to 0 failed: Too many links. - ReportEvent
      Notice: Applied catalog in 2.89 seconds
      

      Detailed error trace:

      PS C:\Users\Administrator> puppet apply test.pp --logdest=eventlog --logdest=console --trace
      Notice: Compiled catalog for pe-201642-agent-win2012 in environment production in 0.28 seconds
      Error: The parameter is incorrect. - ReportEvent
      C:/Program Files/Puppet Labs/Puppet/sys/ruby/lib/ruby/gems/2.1.0/gems/win32-eventlog-0.6.2/lib/win32/eventlog.rb:717:in
      `report_event'
      C:/Program Files/Puppet Labs/Puppet/sys/ruby/lib/ruby/vendor_ruby/puppet/util/log/destinations.rb:241:in `handle'
      C:/Program Files/Puppet Labs/Puppet/sys/ruby/lib/ruby/vendor_ruby/puppet/util/log.rb:176:in `block in newmessage'
      C:/Program Files/Puppet Labs/Puppet/sys/ruby/lib/ruby/vendor_ruby/puppet/util/log.rb:175:in `each'
      C:/Program Files/Puppet Labs/Puppet/sys/ruby/lib/ruby/vendor_ruby/puppet/util/log.rb:175:in `newmessage'
      C:/Program Files/Puppet Labs/Puppet/sys/ruby/lib/ruby/vendor_ruby/puppet/util/log.rb:268:in `initialize'
      C:/Program Files/Puppet Labs/Puppet/sys/ruby/lib/ruby/vendor_ruby/puppet/util/log.rb:87:in `new'
      C:/Program Files/Puppet Labs/Puppet/sys/ruby/lib/ruby/vendor_ruby/puppet/util/log.rb:87:in `create'
      C:/Program Files/Puppet Labs/Puppet/sys/ruby/lib/ruby/vendor_ruby/puppet/util/logging.rb:12:in `send_log'
      C:/Program Files/Puppet Labs/Puppet/sys/ruby/lib/ruby/vendor_ruby/puppet/util/logging.rb:21:in `block (2 levels) in <mod
      ule:Logging>'
      C:/Program Files/Puppet Labs/Puppet/sys/ruby/lib/ruby/vendor_ruby/puppet/type/exec.rb:154:in `block in sync'
      C:/Program Files/Puppet Labs/Puppet/sys/ruby/lib/ruby/vendor_ruby/puppet/type/exec.rb:153:in `each'
      C:/Program Files/Puppet Labs/Puppet/sys/ruby/lib/ruby/vendor_ruby/puppet/type/exec.rb:153:in `sync'
      C:/Program Files/Puppet Labs/Puppet/sys/ruby/lib/ruby/vendor_ruby/puppet/transaction/resource_harness.rb:236:in `sync'
      C:/Program Files/Puppet Labs/Puppet/sys/ruby/lib/ruby/vendor_ruby/puppet/transaction/resource_harness.rb:134:in `sync_if
      _needed'
      C:/Program Files/Puppet Labs/Puppet/sys/ruby/lib/ruby/vendor_ruby/puppet/transaction/resource_harness.rb:88:in `block in
       perform_changes'
      C:/Program Files/Puppet Labs/Puppet/sys/ruby/lib/ruby/vendor_ruby/puppet/transaction/resource_harness.rb:87:in `each'
      C:/Program Files/Puppet Labs/Puppet/sys/ruby/lib/ruby/vendor_ruby/puppet/transaction/resource_harness.rb:87:in `perform_
      changes'
      C:/Program Files/Puppet Labs/Puppet/sys/ruby/lib/ruby/vendor_ruby/puppet/transaction/resource_harness.rb:21:in `evaluate
      '
      C:/Program Files/Puppet Labs/Puppet/sys/ruby/lib/ruby/vendor_ruby/puppet/transaction.rb:224:in `apply'
      C:/Program Files/Puppet Labs/Puppet/sys/ruby/lib/ruby/vendor_ruby/puppet/transaction.rb:240:in `eval_resource'
      ...
      

      Expected Outcome

      The Puppet Agent should split, truncate or drop large messages and log a better error explaining what happened.

        Attachments

          Issue Links

            Activity

              jsd-sla-details-panel

                People

                • Assignee:
                  jorie Jorie Tappa
                  Reporter:
                  chuck Charlie Sharpsteen
                • Votes:
                  2 Vote for this issue
                  Watchers:
                  6 Start watching this issue

                  Dates

                  • Created:
                    Updated:
                    Resolved: