[Puppet Users] 'puppet storeconfigs export' killed

Hi,

I currently have a MySQL database containing all Puppet storeconfigs. My
intention is to migrate to PuppetDB on a PostgreSQL server, so the first
step is to use the 'storeconfigs' face to export all the DB to a file
PuppetDB can later consume. But the 'puppet storeconfigs export' command
always ends up being killed, I suspect due to some sort of OOM issue. I
have tried different environments, different Puppet / Ruby / whatever
versions, different hardware... No matter what, it always ends up the same.

The process starts well, connects to the database and fetches all the data,
but then it seems to get stuck after this output line:
Info: Connecting to mysql2 database: puppet

Meanwhile, a CPU is working and the amount of memory used by this process
increases constantly. I have tried on several servers, one with up to 28GB
of RAM, and it died the same way.

Here are the facts of my last attempt:

The execution output:

[root@ST-L226-ROGTORG ~]# time puppet storeconfigs --verbose --debug export
Debug: Using settings: adding file resource 'confdir':
'File[/etc/puppet]{:path=>"/etc/puppet", :ensure=>:directory,
:loglevel=>:debug, :links=>:follow, :backup=>false}'
Debug: Using settings: adding file resource 'vardir':
'File[/var/lib/puppet]{:path=>"/var/lib/puppet", :ensure=>:directory,
:loglevel=>:debug, :links=>:follow, :backup=>false}'
Debug: Failed to load library 'ldap' for feature 'ldap'
Debug: Puppet::Type::User::ProviderLdap: feature ldap is missing
Debug: Puppet::Type::User::ProviderDirectoryservice: file /usr/bin/dsimport
does not exist
Debug: Puppet::Type::User::ProviderPw: file pw does not exist
Debug: Puppet::Type::User::ProviderUser_role_add: file roleadd does not
exist
Debug: Failed to load library 'ldap' for feature 'ldap'
Debug: Puppet::Type::Group::ProviderLdap: feature ldap is missing
Debug: Puppet::Type::Group::ProviderDirectoryservice: file /usr/bin/dscl
does not exist
Debug: Puppet::Type::Group::ProviderPw: file pw does not exist
Debug: Using settings: adding file resource 'logdir':
'File[/var/log/puppet]{:path=>"/var/log/puppet", :mode=>"750",
:owner=>"puppet", :group=>"puppet", :ensure=>:directory, :loglevel=>:debug,
:links=>:follow, :backup=>false}'
Debug: Using settings: adding file resource 'statedir':
'File[/var/lib/puppet/state]{:path=>"/var/lib/puppet/state", :mode=>"1755",
:ensure=>:directory, :loglevel=>:debug, :links=>:follow, :backup=>false}'
Debug: Using settings: adding file resource 'rundir':
'File[/var/run/puppet]{:path=>"/var/run/puppet", :mode=>"755",
:owner=>"puppet", :group=>"puppet", :ensure=>:directory, :loglevel=>:debug,
:links=>:follow, :backup=>false}'
Debug: Using settings: adding file resource 'libdir':
'File[/var/lib/puppet/lib]{:path=>"/var/lib/puppet/lib",
:ensure=>:directory, :loglevel=>:debug, :links=>:follow, :backup=>false}'
Debug: Using settings: adding file resource 'certdir':
'File[/var/lib/puppet/ssl/certs]{:path=>"/var/lib/puppet/ssl/certs",
:owner=>"puppet", :ensure=>:directory, :loglevel=>:debug, :links=>:follow,
:backup=>false}'
Debug: Using settings: adding file resource 'ssldir':
'File[/var/lib/puppet/ssl]{:path=>"/var/lib/puppet/ssl", :mode=>"771",
:owner=>"puppet", :ensure=>:directory, :loglevel=>:debug, :links=>:follow,
:backup=>false}'
Debug: Using settings: adding file resource 'publickeydir':
'File[/var/lib/puppet/ssl/public_keys]{:path=>"/var/lib/puppet/ssl/public_keys",
:owner=>"puppet", :ensure=>:directory, :loglevel=>:debug, :links=>:follow,
:backup=>false}'
Debug: Using settings: adding file resource 'requestdir':
'File[/var/lib/puppet/ssl/certificate_requests]{:path=>"/var/lib/puppet/ssl/certificate_requests",
:owner=>"puppet", :ensure=>:directory, :loglevel=>:debug, :links=>:follow,
:backup=>false}'
Debug: Using settings: adding file resource 'privatekeydir':
'File[/var/lib/puppet/ssl/private_keys]{:path=>"/var/lib/puppet/ssl/private_keys",
:mode=>"750", :owner=>"puppet", :ensure=>:directory, :loglevel=>:debug,
:links=>:follow, :backup=>false}'
Debug: Using settings: adding file resource 'privatedir':
'File[/var/lib/puppet/ssl/private]{:path=>"/var/lib/puppet/ssl/private",
:mode=>"750", :owner=>"puppet", :ensure=>:directory, :loglevel=>:debug,
:links=>:follow, :backup=>false}'
Debug: Using settings: adding file resource 'manifestdir':
'File[/etc/puppet/manifests]{:path=>"/etc/puppet/manifests",
:ensure=>:directory, :loglevel=>:debug, :links=>:follow, :backup=>false}'
Debug: Using settings: adding file resource 'masterhttplog':
'File[/var/log/puppet/masterhttp.log]{:path=>"/var/log/puppet/masterhttp.log",
:mode=>"660", :owner=>"puppet", :group=>"puppet", :ensure=>:file,
:loglevel=>:debug, :links=>:follow, :backup=>false}'
Debug: Using settings: adding file resource 'bucketdir':
'File[/var/lib/puppet/bucket]{:path=>"/var/lib/puppet/bucket",
:mode=>"750", :owner=>"puppet", :group=>"puppet", :ensure=>:directory,
:loglevel=>:debug, :links=>:follow, :backup=>false}'
Debug: Using settings: adding file resource 'rest_authconfig':
'File[/etc/puppet/auth.conf]{:path=>"/etc/puppet/auth.conf",
:ensure=>:file, :loglevel=>:debug, :links=>:follow, :backup=>false}'
Debug: Using settings: adding file resource 'yamldir':
'File[/var/lib/puppet/yaml]{:path=>"/var/lib/puppet/yaml", :mode=>"750",
:owner=>"puppet", :group=>"puppet", :ensure=>:directory, :loglevel=>:debug,
:links=>:follow, :backup=>false}'
Debug: Using settings: adding file resource 'server_datadir':
'File[/var/lib/puppet/server_data]{:path=>"/var/lib/puppet/server_data",
:mode=>"750", :owner=>"puppet", :group=>"puppet", :ensure=>:directory,
:loglevel=>:debug, :links=>:follow, :backup=>false}'
Debug: Using settings: adding file resource 'reportdir':
'File[/var/lib/puppet/reports]{:path=>"/var/lib/puppet/reports",
:mode=>"750", :owner=>"puppet", :group=>"puppet", :ensure=>:directory,
:loglevel=>:debug, :links=>:follow, :backup=>false}'
Debug: Using settings: adding file resource 'railslog':
'File[/var/log/puppet/rails.log]{:path=>"/var/log/puppet/rails.log",
:mode=>"600", :owner=>"puppet", :group=>"puppet", :ensure=>:file,
:loglevel=>:debug, :links=>:follow, :backup=>false}'
Debug: /File[/var/lib/puppet/state]: Autorequiring File[/var/lib/puppet]
Debug: /File[/var/lib/puppet/lib]: Autorequiring File[/var/lib/puppet]
Debug: /File[/var/lib/puppet/ssl/certs]: Autorequiring
File[/var/lib/puppet/ssl]
Debug: /File[/var/lib/puppet/ssl]: Autorequiring File[/var/lib/puppet]
Debug: /File[/var/lib/puppet/ssl/public_keys]: Autorequiring
File[/var/lib/puppet/ssl]
Debug: /File[/var/lib/puppet/ssl/certificate_requests]: Autorequiring
File[/var/lib/puppet/ssl]
Debug: /File[/var/lib/puppet/ssl/private_keys]: Autorequiring
File[/var/lib/puppet/ssl]
Debug: /File[/var/lib/puppet/ssl/private]: Autorequiring
File[/var/lib/puppet/ssl]
Debug: /File[/etc/puppet/manifests]: Autorequiring File[/etc/puppet]
Debug: /File[/var/log/puppet/masterhttp.log]: Autorequiring
File[/var/log/puppet]
Debug: /File[/var/lib/puppet/bucket]: Autorequiring File[/var/lib/puppet]
Debug: /File[/etc/puppet/auth.conf]: Autorequiring File[/etc/puppet]
Debug: /File[/var/lib/puppet/yaml]: Autorequiring File[/var/lib/puppet]
Debug: /File[/var/lib/puppet/server_data]: Autorequiring
File[/var/lib/puppet]
Debug: /File[/var/lib/puppet/reports]: Autorequiring File[/var/lib/puppet]
Debug: /File[/var/log/puppet/rails.log]: Autorequiring File[/var/log/puppet]
Debug: Finishing transaction 34502460
Info: Connecting to mysql2 database: puppet
Killed

real 66m35.810s
user 9m42.143s
sys 6m31.294s


My /etc/puppet/puppet.conf file:

[main]
     # The Puppet log directory.
     # The default value is '$vardir/log'.
     logdir = /var/log/puppet

     # Where Puppet PID files are kept.
     # The default value is '$vardir/run'.
     rundir = /var/run/puppet

     # Where SSL certificates are kept.
     # The default value is '$confdir/ssl'.
     ssldir = $vardir/ssl

     facts_terminus = inventory_active_record

     storeconfigs = true
     dbadapter = mysql2
     dbserver = roger-test.ofi.softonic.lan
     dbname = puppet
     dbuser = puppet
     dbpassword =
     dbconnections = 20

[agent]
     # The file in which puppetd stores a list of the classes
     # associated with the retrieved configuratiion. Can be loaded in
     # the separate ``puppet`` executable using the ``--loadclasses``
     # option.
     # The default value is '$confdir/classes.txt'.
     classfile = $vardir/classes.txt

     # Where puppetd caches the local configuration. An
     # extension indicating the cache format is added automatically.
     # The default value is '$confdir/localconfig'.
     localconfig = $vardir/localconfig

Packages:

[root@ST-L226-ROGTORG ~]# rpm -qa | egrep -i "(puppet|ruby)" | sort
libselinux-ruby-2.1.13-15.fc19.x86_64
puppet-3.3.1-1.fc19.noarch
puppetdb-terminus-1.5.0-1.fc19.noarch
puppetlabs-release-19-2.noarch
ruby-2.0.0.247-15.fc19.x86_64
ruby-augeas-0.5.0-1.fc19.x86_64
ruby-devel-2.0.0.247-15.fc19.x86_64
ruby-irb-2.0.0.247-15.fc19.noarch
ruby-libs-2.0.0.247-15.fc19.x86_64
ruby-rgen-0.6.5-1.fc19.noarch
ruby-shadow-1.4.1-19.fc19.x86_64
rubygem-activemodel-3.2.13-1.fc19.noarch
rubygem-activerecord-3.2.13-1.fc19.noarch
rubygem-activesupport-3.2.13-1.fc19.noarch
rubygem-arel-3.0.2-3.fc19.noarch
rubygem-bigdecimal-1.2.0-15.fc19.x86_64
rubygem-builder-3.1.4-3.fc19.noarch
rubygem-i18n-0.6.1-3.fc19.noarch
rubygem-io-console-0.4.2-15.fc19.x86_64
rubygem-json-1.7.7-100.fc19.x86_64
rubygem-multi_json-1.7.1-1.fc19.noarch
rubygem-mysql2-0.3.13-1.fc19.x86_64
rubygem-psych-2.0.0-15.fc19.x86_64
rubygem-rdoc-4.0.1-1.fc19.noarch
rubygems-2.0.10-106.fc19.noarch
rubygem-tzinfo-0.3.35-1.fc19.noarch
rubypick-1.1.0-1.fc19.noarch


I'm positive the MySQL server receives the query and returns the data,
according to MySQL's slow-queries.log:

# Time: 131008 17:06:14
# User@Host: puppet[puppet] @ [172.20.59.127]
# Thread_id: 169 Schema: puppet Last_errno: 0 Killed: 0
# Query_time: 189.509563 Lock_time: 0.000136 Rows_sent: 6168111
Rows_examined: 12712154 Rows_affected: 0 Rows_read: 18446744073709551613
# Bytes_sent: 2426331478 Tmp_tables: 0 Tmp_disk_tables: 0
Tmp_table_sizes: 0
# InnoDB_trx_id: A93
SET timestamp=1381244774;
SELECT `hosts`.`id` AS t0_r0, `hosts`.`name` AS t0_r1, `hosts`.`ip` AS
t0_r2, `hosts`.`environment` AS t0_r3, `hosts`.`last_compile` AS t0_r4,
`hosts`.`last_freshcheck` AS t0_r5, `
hosts`.`last_report` AS t0_r6, `hosts`.`updated_at` AS t0_r7,
`hosts`.`source_file_id` AS t0_r8, `hosts`.`created_at` AS t0_r9,
`resources`.`id` AS t1_r0, `resources`.`title` AS t1
_r1, `resources`.`restype` AS t1_r2, `resources`.`host_id` AS t1_r3,
`resources`.`source_file_id` AS t1_r4, `resources`.`exported` AS t1_r5,
`resources`.`line` AS t1_r6, `resources
`.`updated_at` AS t1_r7, `resources`.`created_at` AS t1_r8,
`param_values`.`id` AS t2_r0, `param_values`.`value` AS t2_r1,
`param_values`.`param_name_id` AS t2_r2, `param_values`.`
line` AS t2_r3, `param_values`.`resource_id` AS t2_r4,
`param_values`.`updated_at` AS t2_r5, `param_values`.`created_at` AS t2_r6,
`puppet_tags`.`id` AS t3_r0, `puppet_tags`.`name`
  AS t3_r1, `puppet_tags`.`updated_at` AS t3_r2, `puppet_tags`.`created_at`
AS t3_r3 FROM `hosts` LEFT OUTER JOIN `resources` ON `resources`.`host_id`
= `hosts`.`id` LEFT OUTER JOIN
  `param_values` ON `param_values`.`resource_id` = `resources`.`id` LEFT
OUTER JOIN `resource_tags` ON `resource_tags`.`resource_id` =
`resources`.`id` LEFT OUTER JOIN `puppet_tags`
  ON `puppet_tags`.`id` = `resource_tags`.`puppet_tag_id` WHERE
`resources`.`exported` = 1;


When the process gets stuck, an strace shows a constant and very quick flow
of:

30666 stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2593, ...}) = 0

The final moments of the strace showed:

30667 restart_syscall(<... resuming interrupted call ...> <unfinished ...>
30666 mremap(0x7f7aa4d0a000, 2732032, 2752512, MREMAP_MAYMOVE) =
0x7f7aa4d0a000
30666 brk(0) = 0x23aaea000
30666 brk(0x23ab0b000) = 0x23ab0b000
30666 brk(0) = 0x23ab0b000
30666 brk(0x23ab2c000) = 0x23ab2c000
30666 brk(0) = 0x23ab2c000
30666 brk(0x23ab4d000) = 0x23ab4d000
... then lots of...
30666 stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2593, ...}) = 0
30666 stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2593, ...}) = 0
30666 stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2593, ...}) = 0
... and finally ...
30666 stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2593, ...}) = 0
30666 stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2593, ...}) = 0
30666 stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2593, ...}) = 0
30667 +++ killed by SIGKILL +++
30666 +++ killed by SIGKILL +++

Any idea of what is happening? Am I doing something wrong?

Thanks!

Roger Torrentsgenerós