Roger Torrentsgenerós
2013-Oct-08 17:22 UTC
[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 -- You received this message because you are subscribed to the Google Groups "Puppet Users" group. To unsubscribe from this group and stop receiving emails from it, send an email to puppet-users+unsubscribe@googlegroups.com. To post to this group, send email to puppet-users@googlegroups.com. Visit this group at http://groups.google.com/group/puppet-users. For more options, visit https://groups.google.com/groups/opt_out.
Roger Torrentsgenerós
2013-Oct-11 12:21 UTC
[Puppet Users] Re: ''puppet storeconfigs export'' killed
Just an update. This is what strace shows at the point where the process finishes fetching data from the MySQL database: 17169 read(4, "38:31\373\373\0232013-07-15 17:38:32\373\023201"..., 16384) = 384 17169 read(4, "3:00:07\0074113192\27xavier.ofi.softo"..., 16384) = 16000 17169 read(4, "305566\17some.user\003194\00222\00741"..., 16384) = 384 17169 read(4, "192\0232013-04-02 16:11:44\0232013-04-"..., 16384) = 8534 17169 gettimeofday({1381493430, 91178}, NULL) = 0 17169 rt_sigprocmask(SIG_BLOCK, NULL, [], 8) = 0 17169 rt_sigprocmask(SIG_BLOCK, NULL, [], 8) = 0 17169 rt_sigprocmask(SIG_BLOCK, NULL, [], 8) = 0 17169 rt_sigprocmask(SIG_BLOCK, NULL, [], 8) = 0 17169 mmap(NULL, 49348608, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f41c7266000 17169 stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2593, ...}) = 0 17169 stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2593, ...}) = 0 17169 stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2593, ...}) = 0 Beyond this point, tons of exactly the same line, CPU at 100% and memory usage increasing until it fills RAM and swap space, and then the SIGKILL shown above. Roger On Tuesday, October 8, 2013 7:22:20 PM UTC+2, Roger Torrentsgenerós wrote:> > > 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 >-- You received this message because you are subscribed to the Google Groups "Puppet Users" group. To unsubscribe from this group and stop receiving emails from it, send an email to puppet-users+unsubscribe@googlegroups.com. To post to this group, send email to puppet-users@googlegroups.com. Visit this group at http://groups.google.com/group/puppet-users. For more options, visit https://groups.google.com/groups/opt_out.
Roger Torrentsgenerós
2013-Oct-16 08:23 UTC
[Puppet Users] Re: ''puppet storeconfigs export'' killed
Well I finally did it. First thing to do is to specify a timezone to avoid the massive amount of: 17169 stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2593, ...}) = 0 Issuing ''# export TZ=:/etc/localtime'' prior to launching the Puppet face is enough. Then, in my particular case I had to use a VM with 42GB of RAM to deal with a 1.4GB MySQL database. After more than 2 hours of processing, a .tgz file with the ridiculous size of 1.7MB was created. So if your export process gets killed and you see OOM messages in your dmesg, you''ll need more RAM in your server. Roger On Friday, October 11, 2013 2:21:12 PM UTC+2, Roger Torrentsgenerós wrote:> > > Just an update. This is what strace shows at the point where the process > finishes fetching data from the MySQL database: > > 17169 read(4, "38:31\373\373\0232013-07-15 17:38:32\373\023201"..., 16384) > = 384 > 17169 read(4, "3:00:07\0074113192\27xavier.ofi.softo"..., 16384) = 16000 > 17169 read(4, "305566\17some.user\003194\00222\00741"..., 16384) = 384 > 17169 read(4, "192\0232013-04-02 16:11:44\0232013-04-"..., 16384) = 8534 > 17169 gettimeofday({1381493430, 91178}, NULL) = 0 > 17169 rt_sigprocmask(SIG_BLOCK, NULL, [], 8) = 0 > 17169 rt_sigprocmask(SIG_BLOCK, NULL, [], 8) = 0 > 17169 rt_sigprocmask(SIG_BLOCK, NULL, [], 8) = 0 > 17169 rt_sigprocmask(SIG_BLOCK, NULL, [], 8) = 0 > 17169 mmap(NULL, 49348608, PROT_READ|PROT_WRITE, > MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f41c7266000 > 17169 stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2593, ...}) = 0 > 17169 stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2593, ...}) = 0 > 17169 stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2593, ...}) = 0 > > Beyond this point, tons of exactly the same line, CPU at 100% and memory > usage increasing until it fills RAM and swap space, and then the SIGKILL > shown above. > > Roger > > On Tuesday, October 8, 2013 7:22:20 PM UTC+2, Roger Torrentsgenerós wrote: >> >> >> 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 >> >-- You received this message because you are subscribed to the Google Groups "Puppet Users" group. To unsubscribe from this group and stop receiving emails from it, send an email to puppet-users+unsubscribe@googlegroups.com. To post to this group, send email to puppet-users@googlegroups.com. Visit this group at http://groups.google.com/group/puppet-users. For more options, visit https://groups.google.com/groups/opt_out.
Ken Barber
2013-Oct-17 08:40 UTC
Re: [Puppet Users] Re: ''puppet storeconfigs export'' killed
Roger, Can you raise this as a bug in our bug tracker? http://projects.puppetlabs.com/projects/puppetdb ken. On Wed, Oct 16, 2013 at 9:23 AM, Roger Torrentsgenerós <gumdeu@gmail.com> wrote:> > Well I finally did it. > > First thing to do is to specify a timezone to avoid the massive amount of: > > > 17169 stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2593, ...}) = 0 > > Issuing ''# export TZ=:/etc/localtime'' prior to launching the Puppet face is > enough. > > Then, in my particular case I had to use a VM with 42GB of RAM to deal with > a 1.4GB MySQL database. After more than 2 hours of processing, a .tgz file > with the ridiculous size of 1.7MB was created. > > So if your export process gets killed and you see OOM messages in your > dmesg, you''ll need more RAM in your server. > > Roger > > > On Friday, October 11, 2013 2:21:12 PM UTC+2, Roger Torrentsgenerós wrote: >> >> >> Just an update. This is what strace shows at the point where the process >> finishes fetching data from the MySQL database: >> >> 17169 read(4, "38:31\373\373\0232013-07-15 17:38:32\373\023201"..., 16384) >> = 384 >> 17169 read(4, "3:00:07\0074113192\27xavier.ofi.softo"..., 16384) = 16000 >> 17169 read(4, "305566\17some.user\003194\00222\00741"..., 16384) = 384 >> 17169 read(4, "192\0232013-04-02 16:11:44\0232013-04-"..., 16384) = 8534 >> 17169 gettimeofday({1381493430, 91178}, NULL) = 0 >> 17169 rt_sigprocmask(SIG_BLOCK, NULL, [], 8) = 0 >> 17169 rt_sigprocmask(SIG_BLOCK, NULL, [], 8) = 0 >> 17169 rt_sigprocmask(SIG_BLOCK, NULL, [], 8) = 0 >> 17169 rt_sigprocmask(SIG_BLOCK, NULL, [], 8) = 0 >> 17169 mmap(NULL, 49348608, PROT_READ|PROT_WRITE, >> MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f41c7266000 >> 17169 stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2593, ...}) >> 0 >> 17169 stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2593, ...}) >> 0 >> 17169 stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2593, ...}) >> 0 >> >> Beyond this point, tons of exactly the same line, CPU at 100% and memory >> usage increasing until it fills RAM and swap space, and then the SIGKILL >> shown above. >> >> Roger >> >> On Tuesday, October 8, 2013 7:22:20 PM UTC+2, Roger Torrentsgenerós wrote: >>> >>> >>> 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 > > -- > You received this message because you are subscribed to the Google Groups > "Puppet Users" group. > To unsubscribe from this group and stop receiving emails from it, send an > email to puppet-users+unsubscribe@googlegroups.com. > To post to this group, send email to puppet-users@googlegroups.com. > Visit this group at http://groups.google.com/group/puppet-users. > For more options, visit https://groups.google.com/groups/opt_out.-- You received this message because you are subscribed to the Google Groups "Puppet Users" group. To unsubscribe from this group and stop receiving emails from it, send an email to puppet-users+unsubscribe@googlegroups.com. To post to this group, send email to puppet-users@googlegroups.com. Visit this group at http://groups.google.com/group/puppet-users. For more options, visit https://groups.google.com/groups/opt_out.
Roger Torrentsgenerós
2013-Oct-18 12:56 UTC
Re: [Puppet Users] Re: ''puppet storeconfigs export'' killed
Done http://projects.puppetlabs.com/issues/22912 On Thursday, October 17, 2013 10:40:12 AM UTC+2, Ken Barber wrote:> > Roger, > > Can you raise this as a bug in our bug tracker? > > http://projects.puppetlabs.com/projects/puppetdb > > ken. > > On Wed, Oct 16, 2013 at 9:23 AM, Roger Torrentsgenerós <gum...@gmail.com<javascript:>> > wrote: > > > > Well I finally did it. > > > > First thing to do is to specify a timezone to avoid the massive amount > of: > > > > > > 17169 stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2593, ...}) > = 0 > > > > Issuing ''# export TZ=:/etc/localtime'' prior to launching the Puppet face > is > > enough. > > > > Then, in my particular case I had to use a VM with 42GB of RAM to deal > with > > a 1.4GB MySQL database. After more than 2 hours of processing, a .tgz > file > > with the ridiculous size of 1.7MB was created. > > > > So if your export process gets killed and you see OOM messages in your > > dmesg, you''ll need more RAM in your server. > > > > Roger > > > > > > On Friday, October 11, 2013 2:21:12 PM UTC+2, Roger Torrentsgenerós > wrote: > >> > >> > >> Just an update. This is what strace shows at the point where the > process > >> finishes fetching data from the MySQL database: > >> > >> 17169 read(4, "38:31\373\373\0232013-07-15 17:38:32\373\023201"..., > 16384) > >> = 384 > >> 17169 read(4, "3:00:07\0074113192\27xavier.ofi.softo"..., 16384) = > 16000 > >> 17169 read(4, "305566\17some.user\003194\00222\00741"..., 16384) = 384 > >> 17169 read(4, "192\0232013-04-02 16:11:44\0232013-04-"..., 16384) = > 8534 > >> 17169 gettimeofday({1381493430, 91178}, NULL) = 0 > >> 17169 rt_sigprocmask(SIG_BLOCK, NULL, [], 8) = 0 > >> 17169 rt_sigprocmask(SIG_BLOCK, NULL, [], 8) = 0 > >> 17169 rt_sigprocmask(SIG_BLOCK, NULL, [], 8) = 0 > >> 17169 rt_sigprocmask(SIG_BLOCK, NULL, [], 8) = 0 > >> 17169 mmap(NULL, 49348608, PROT_READ|PROT_WRITE, > >> MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f41c7266000 > >> 17169 stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2593, ...}) > = > >> 0 > >> 17169 stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2593, ...}) > = > >> 0 > >> 17169 stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2593, ...}) > = > >> 0 > >> > >> Beyond this point, tons of exactly the same line, CPU at 100% and > memory > >> usage increasing until it fills RAM and swap space, and then the > SIGKILL > >> shown above. > >> > >> Roger > >> > >> On Tuesday, October 8, 2013 7:22:20 PM UTC+2, Roger Torrentsgenerós > wrote: > >>> > >>> > >>> 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 > > > > -- > > You received this message because you are subscribed to the Google > Groups > > "Puppet Users" group. > > To unsubscribe from this group and stop receiving emails from it, send > an > > email to puppet-users...@googlegroups.com <javascript:>. > > To post to this group, send email to puppet...@googlegroups.com<javascript:>. > > > Visit this group at http://groups.google.com/group/puppet-users. > > For more options, visit https://groups.google.com/groups/opt_out. >-- You received this message because you are subscribed to the Google Groups "Puppet Users" group. To unsubscribe from this group and stop receiving emails from it, send an email to puppet-users+unsubscribe@googlegroups.com. To post to this group, send email to puppet-users@googlegroups.com. Visit this group at http://groups.google.com/group/puppet-users. For more options, visit https://groups.google.com/groups/opt_out.
Apparently Analagous Threads
- Storeconfigs purge Perl
- Cleaning Out Stored Configs
- Deleting an exported resource
- [Bug 99396] New: Crash in nouveau_dri.so when switching apps with alt-tab in Gnome
- Could not retrieve catalog from remote server: Error 400 on SERVER: cannot generate tempfile `/var/lib/puppet/yaml/facts/vagrant1.localdomain.yaml20131009-16545-8oie5i-9'