Puppet: System Administration Automated

Support

Ticket #1009 (closed defect: fixed)

Opened 10 months ago

Last modified 9 months ago

pkgdmg fails to install packages

Reported by: mccune Assigned to: luke
Priority: normal Milestone:
Component: client Version: 0.24.1
Severity: normal Keywords: pkgdmg plist nil NilClass
Cc: Triage Stage: Ready for checkin
Attached Patches: Code Complexity: Unknown

Description

I encountered this issue on 14 January, and struggled a bit.

Consider the following puppet script: 

#!/usr/bin/env puppet

package { "Firefox-2.0.0.7-1.pkg.dmg":
  provider => pkgdmg,
  ensure => installed,
  source => "http://northstarlabs.net/pub/Firefox-2.0.0.7-1.pkg.dmg";
}

Trying to install a simple package on Mac OS X 10.5.1 with Puppet 0.24.1, I'm getting the following exception: 

nutburner:~ root# puppet --trace -vd ~mccune/Developer/mw08/trunk/puppet/tools/firefox.pp
debug: Creating default schedules
debug: Prefetching pkgdmg resources for package
debug: //Package[Firefox-2.0.0.7-1.pkg.dmg]: Changing ensure
debug: //Package[Firefox-2.0.0.7-1.pkg.dmg]: 1 change(s)
/Library/Ruby/Site/1.8/puppet/util/plist/parser.rb:67: warning: already initialized constant TEXT
/Library/Ruby/Site/1.8/puppet/util/plist/parser.rb:68: warning: already initialized constant XMLDECL_PATTERN
/Library/Ruby/Site/1.8/puppet/util/plist/parser.rb:69: warning: already initialized constant DOCTYPE_PATTERN
/Library/Ruby/Site/1.8/puppet/util/plist/parser.rb:70: warning: already initialized constant COMMENT_START
/Library/Ruby/Site/1.8/puppet/util/plist/parser.rb:71: warning: already initialized constant COMMENT_END
/Library/Ruby/Site/1.8/puppet/util/plist.rb:21: warning: already initialized constant VERSION
debug: Puppet::Type::Package::ProviderPkgdmg: Executing '/usr/bin/hdiutil mount -plist -nobrowse -readonly -noidme -mountrandom /tmp /Library/WebSe
rver/Documents/packages/Firefox-2.0.0.7-1.pkg.dmg'
/Library/Ruby/Site/1.8/puppet/util/plist/parser.rb:44:in `tag_start'
/Library/Ruby/Site/1.8/puppet/util/plist/parser.rb:96:in `parse'
/Library/Ruby/Site/1.8/puppet/util/plist/parser.rb:28:in `parse_xml'
/Library/Ruby/Site/1.8/puppet/provider/package/pkgdmg.rb:150:in `installpkgdmg'
/System/Library/Frameworks/Ruby.framework/Versions/1.8/usr/lib/ruby/1.8/open-uri.rb:32:in `open_uri_original_open'/System/Library/Frameworks/Ruby.framework/Versions/1.8/usr/lib/ruby/1.8/open-uri.rb:32:in `open'
/Library/Ruby/Site/1.8/puppet/provider/package/pkgdmg.rb:148:in `installpkgdmg'
/Library/Ruby/Site/1.8/puppet/provider/package/pkgdmg.rb:189:in `install'
/Library/Ruby/Site/1.8/puppet/type/package.rb:52:in `set_present'
/Library/Ruby/Site/1.8/puppet/property.rb:164:in `send'
/Library/Ruby/Site/1.8/puppet/property.rb:164:in `call_valuemethod'
/Library/Ruby/Site/1.8/puppet/property.rb:350:in `set'
/Library/Ruby/Site/1.8/puppet/property.rb:422:in `sync'
/Library/Ruby/Site/1.8/puppet/propertychange.rb:81:in `go'
/Library/Ruby/Site/1.8/puppet/propertychange.rb:109:in `forward'
/Library/Ruby/Site/1.8/puppet/transaction.rb:119:in `apply_changes'
/Library/Ruby/Site/1.8/puppet/transaction.rb:111:in `collect'
/Library/Ruby/Site/1.8/puppet/transaction.rb:111:in `apply_changes'
/Library/Ruby/Site/1.8/puppet/transaction.rb:83:in `apply'
/Library/Ruby/Site/1.8/puppet/transaction.rb:240:in `eval_resource'
/Library/Ruby/Site/1.8/puppet/util.rb:444:in `thinmark'
/System/Library/Frameworks/Ruby.framework/Versions/1.8/usr/lib/ruby/1.8/benchmark.rb:293:in `measure'
/System/Library/Frameworks/Ruby.framework/Versions/1.8/usr/lib/ruby/1.8/benchmark.rb:307:in `realtime'
/Library/Ruby/Site/1.8/puppet/util.rb:443:in `thinmark'
/Library/Ruby/Site/1.8/puppet/transaction.rb:239:in `eval_resource'
/Library/Ruby/Site/1.8/puppet/transaction.rb:311:in `evaluate'
/Library/Ruby/Site/1.8/puppet/util.rb:444:in `thinmark'
/System/Library/Frameworks/Ruby.framework/Versions/1.8/usr/lib/ruby/1.8/benchmark.rb:293:in `measure'
/System/Library/Frameworks/Ruby.framework/Versions/1.8/usr/lib/ruby/1.8/benchmark.rb:307:in `realtime'
/Library/Ruby/Site/1.8/puppet/util.rb:443:in `thinmark'
/Library/Ruby/Site/1.8/puppet/transaction.rb:310:in `evaluate'
/Library/Ruby/Site/1.8/puppet/transaction.rb:304:in `collect'
/Library/Ruby/Site/1.8/puppet/transaction.rb:304:in `evaluate'
/Library/Ruby/Site/1.8/puppet/node/catalog.rb:102:in `apply'
/usr/bin/puppet:209
/Library/Ruby/Site/1.8/puppet/util/plist/parser.rb:44:in `tag_start'
/Library/Ruby/Site/1.8/puppet/util/plist/parser.rb:96:in `parse'
/Library/Ruby/Site/1.8/puppet/util/plist/parser.rb:28:in `parse_xml'/Library/Ruby/Site/1.8/puppet/provider/package/pkgdmg.rb:150:in `installpkgdmg'
/System/Library/Frameworks/Ruby.framework/Versions/1.8/usr/lib/ruby/1.8/open-uri.rb:32:in `open_uri_original_open'
/System/Library/Frameworks/Ruby.framework/Versions/1.8/usr/lib/ruby/1.8/open-uri.rb:32:in `open'
/Library/Ruby/Site/1.8/puppet/provider/package/pkgdmg.rb:148:in `installpkgdmg'
/Library/Ruby/Site/1.8/puppet/provider/package/pkgdmg.rb:189:in `install'
/Library/Ruby/Site/1.8/puppet/type/package.rb:52:in `set_present'
/Library/Ruby/Site/1.8/puppet/property.rb:164:in `send'
/Library/Ruby/Site/1.8/puppet/property.rb:164:in `call_valuemethod'
/Library/Ruby/Site/1.8/puppet/property.rb:350:in `set'
/Library/Ruby/Site/1.8/puppet/property.rb:422:in `sync'
/Library/Ruby/Site/1.8/puppet/propertychange.rb:81:in `go'
/Library/Ruby/Site/1.8/puppet/propertychange.rb:109:in `forward'
/Library/Ruby/Site/1.8/puppet/transaction.rb:119:in `apply_changes'
/Library/Ruby/Site/1.8/puppet/transaction.rb:111:in `collect'
/Library/Ruby/Site/1.8/puppet/transaction.rb:111:in `apply_changes'
/Library/Ruby/Site/1.8/puppet/transaction.rb:83:in `apply'
/Library/Ruby/Site/1.8/puppet/transaction.rb:240:in `eval_resource'
/Library/Ruby/Site/1.8/puppet/util.rb:444:in `thinmark'
/System/Library/Frameworks/Ruby.framework/Versions/1.8/usr/lib/ruby/1.8/benchmark.rb:293:in `measure'
/System/Library/Frameworks/Ruby.framework/Versions/1.8/usr/lib/ruby/1.8/benchmark.rb:307:in `realtime'
/Library/Ruby/Site/1.8/puppet/util.rb:443:in `thinmark'
/Library/Ruby/Site/1.8/puppet/transaction.rb:239:in `eval_resource'
/Library/Ruby/Site/1.8/puppet/transaction.rb:311:in `evaluate'
/Library/Ruby/Site/1.8/puppet/util.rb:444:in `thinmark'
/System/Library/Frameworks/Ruby.framework/Versions/1.8/usr/lib/ruby/1.8/benchmark.rb:293:in `measure'
/System/Library/Frameworks/Ruby.framework/Versions/1.8/usr/lib/ruby/1.8/benchmark.rb:307:in `realtime'
/Library/Ruby/Site/1.8/puppet/util.rb:443:in `thinmark'
/Library/Ruby/Site/1.8/puppet/transaction.rb:310:in `evaluate'
/Library/Ruby/Site/1.8/puppet/transaction.rb:304:in `collect'
/Library/Ruby/Site/1.8/puppet/transaction.rb:304:in `evaluate'
/Library/Ruby/Site/1.8/puppet/node/catalog.rb:102:in `apply'
/usr/bin/puppet:209
err: //Package[Firefox-2.0.0.7-1.pkg.dmg]/ensure: change from absent to present failed: Could not set present on ensure: undefined method `new' for nil:NilClass at /Users/mccune/Developer/mw08/trunk/puppet/tools/firefox.pp:7

What I'm having difficulty with is that using irb, puppet/util/plist is able to parse the XML file just fine.

Change History

01/15/08 20:02:40 changed by mccune

What I'm struggling with is that Plist::parse_xml behaves differently when running under ruby-debug versus irb.

In irb: 

>> foo = "<?xml version=\"1.0\" encoding=\"UTF-8\"?>\n<!DOCTYPE plist PUBLIC \"-//Apple//DTD PLIST 1.0//EN\" \"http://www.apple.com/DTDs/PropertyList-1.0.dtd\">\n<plist version=\"1.0\">\n<dict>\n\t<key>system-entities</key>\n\t<array>\n\t\t<dict>\n\t\t\t<key>content-hint</key>\n\t\t\t<string>Apple_partition_map</string>\n\t\t\t<key>dev-entry</key>\n\t\t\t<string>/dev/disk2s1</string>\n\t\t\t<key>potentially-mountable</key>\n\t\t\t<integer>0</integer>\n\t\t\t<key>unmapped-content-hint</key>\n\t\t\t<string>Apple_partition_map</string>\n\t\t</dict>\n\t\t<dict>\n\t\t\t<key>content-hint</key>\n\t\t\t<string>Apple_partition_scheme</string>\n\t\t\t<key>dev-entry</key>\n\t\t\t<string>/dev/disk2</string>\n\t\t\t<key>potentially-mountable</key>\n\t\t\t<integer>0</integer>\n\t\t\t<key>unmapped-content-hint</key>\n\t\t\t<string>Apple_partition_scheme</string>\n\t\t</dict>\n\t\t<dict>\n\t\t\t<key>content-hint</key>\n\t\t\t<string>Apple_HFS</string>\n\t\t\t<key>dev-entry</key>\n\t\t\t<string>/dev/disk2s2</string>\n\t\t\t<key>mount-point</key>\n\t\t\t<string>/tmp/dmg.OcIbDo</string>\n\t\t\t<key>potentially-mountable</key>\n\t\t\t<integer>1</integer>\n\t\t\t<key>unmapped-content-hint</key>\n\t\t\t<string>Apple_HFS</string>\n\t\t\t<key>volume-kind</key>\n\t\t\t<string>hfs</string>\n\t\t</dict>\n\t</array>\n</dict>\n</plist>\n"
>> Plist::parse_xml foo=> {"system-entities"
=>[{"dev-entry"=>"/dev/disk2s1", "content-hint"=>"Apple_partition_map", "unmapped-content-hint"=>"Apple_partition_map", "potentially-mountable"=>0}, {"dev-entry"=>"/dev/disk2", "content-hint"=>"Apple_partition_scheme", "unmapped-content-hint"=>"Apple_partition_scheme", "potentially-mountable"=>0}, {"dev-entry"=>"/dev/disk2s2", "mount-point"=>"/tmp/dmg.OcIbDo", "volume-kind"=>"hfs", "content-hint"=>"Apple_HFS", "unmapped-content-hint"=>"Apple_HFS", "potentially-mountable"=>1}]}
>>

But in the debugger: 

(rdb:1) e xml_str
"<?xml version=\"1.0\" encoding=\"UTF-8\"?>\n<!DOCTYPE plist PUBLIC \"-//Apple//DTD PLIST 1.0//EN\" \"http://www.apple.com/DTDs/PropertyList-1.0.dtd\">\n<plist version=\"1.0\">\n<dict>\n\t<key>system-entities</key>\n\t<array>\n\t\t<dict>\n\t\t\t<key>content-hint</key>\n\t\t\t<string>Apple_partition_map</string>\n\t\t\t<key>dev-entry</key>\n\t\t\t<string>/dev/disk2s1</string>\n\t\t\t<key>potentially-mountable</key>\n\t\t\t<integer>0</integer>\n\t\t\t<key>unmapped-content-hint</key>\n\t\t\t<string>Apple_partition_map</string>\n\t\t</dict>\n\t\t<dict>\n\t\t\t<key>content-hint</key>\n\t\t\t<string>Apple_partition_scheme</string>\n\t\t\t<key>dev-entry</key>\n\t\t\t<string>/dev/disk2</string>\n\t\t\t<key>potentially-mountable</key>\n\t\t\t<integer>0</integer>\n\t\t\t<key>unmapped-content-hint</key>\n\t\t\t<string>Apple_partition_scheme</string>\n\t\t</dict>\n\t\t<dict>\n\t\t\t<key>content-hint</key>\n\t\t\t<string>Apple_HFS</string>\n\t\t\t<key>dev-entry</key>\n\t\t\t<string>/dev/disk2s2</string>\n\t\t\t<key>mount-point</key>\n\t\t\t<string>/tmp/dmg.OcIbDo</string>\n\t\t\t<key>potentially-mountable</key>\n\t\t\t<integer>1</integer>\n\t\t\t<key>unmapped-content-hint</key>\n\t\t\t<string>Apple_HFS</string>\n\t\t\t<key>volume-kind</key>\n\t\t\t<string>hfs</string>\n\t\t</dict>\n\t</array>\n</dict>\n</plist>\n"

(rdb:1) e Plist::parse_xml xml_str
NoMethodError Exception: undefined method `new' for nil:NilClass

01/15/08 21:00:56 changed by mccune

A bit more information. The problem appears to stem from an empty string being used as the key into a hash table. 

debug: Puppet::Type::Package::ProviderPkgdmg: Executing '/usr/bin/hdiutil mount -plist -nobrowse -readonly -noidme -mountrandom /tmp /Library/WebServer/Documents/packages/Firefox-2.0.0.7-1.pkg.dmg'
/Library/Ruby/Site/1.8/puppet/provider/package/pkgdmg.rb:156
ptable = Plist::parse_xml xml_str
(rdb:1) bt /Library/Ruby/Site/1.8/puppet/util/plist/parser.rb:44
Unknown command
(rdb:1) b /Library/Ruby/Site/1.8/puppet/util/plist/parser.rb:44
Breakpoint 1 file /Library/Ruby/Site/1.8/puppet/util/plist/parser.rb, line 44
(rdb:1) c
Breakpoint 1 at /Library/Ruby/Site/1.8/puppet/util/plist/parser.rb:44
/Library/Ruby/Site/1.8/puppet/util/plist/parser.rb:44
@open.push PTag::mappings[name].new
(rdb:1) e name
""
(rdb:1) e PTag::mappings[""].class
NilClass
(rdb:1)

01/15/08 22:03:23 changed by mccune

  • patch changed from None to Code.

Well, here's my solution due to time constraints. I'm advocating replacing the flipping plist parser with a simple string scanner.

in pkgdmg.rb 

  ...

  xml_str = hdiutil "mount", "-plist", "-nobrowse", "-readonly", "-noidme", "-mountrandom", "/tmp", dmg.path

  # ptable = Plist::parse_xml xml_str
  # JJM Filter out all mount-paths into a single array, discard the rest.
  # mounts = ptable['system-entities'].collect { |entity|
  #     entity['mount-point']
  # }.select { |mountloc|; mountloc }

  # JJM THIS IS A HORRIBLE HACK (Well, actually it's not so bad...)
  mounts = xml_str.scan(/<string>(\/tmp.*?)<\/string>/)[0]

  ...

01/22/08 04:03:52 changed by mccune

I've published a fix for this problem.

Please see commit [1b466e954037154dea222659635b251efdd5c739] on branch fix-1009 published at remote mccune-math, http://www.math.ohio-state.edu/~mccune/git/puppet.git

01/22/08 04:29:36 changed by luke

  • stage changed from Unreviewed to Ready for checkin.

01/22/08 04:31:24 changed by mccune

I've also published a fix for this problem in the 0.23.x branch.

Please see commit [f2019b8fcb0cd16dcd2c4dff8f0eeb51ccfc2a23] of branch ticket_1009_0.23.x at remote mccune-math, http://www.math.ohio-state.edu/~mccune/git/puppet.git

02/05/08 07:11:03 changed by luke

  • stage changed from Ready for checkin to Accepted.
  • patch changed from Code to Insufficient.

Unfortunately, the branch for fix-1009 is made off of 'master' rather than '0.24.x', so I can't merge it into 0.24.x.

Can you remake the branch and fix against the 0.24.x branch?

Thanks.

02/12/08 23:24:47 changed by do

This bug is also present on Tiger 10.4.11.

02/15/08 21:18:17 changed by mccune

Sorry about the long delay on this ticket...

I'll merge this as soon as possible.

02/17/08 00:45:21 changed by jamtur01

  • owner changed from community to luke.
  • stage changed from Accepted to Ready for checkin.
  • patch changed from Insufficient to Code.

Made off 0.24.x in commit [eede7604d9da9b453d48465b06de9813602c09b] in branch 0.24.x.

Hope you don't mind mccune - I was doing one of your others and thought I'd do this at the same time.

02/26/08 00:57:38 changed by luke

  • status changed from new to closed.
  • resolution set to fixed.

Pushed.