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 > <[email protected]<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 [email protected] <javascript:>. > > To post to this group, send email to > > [email protected]<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 [email protected]. To post to this group, send email to [email protected]. Visit this group at http://groups.google.com/group/puppet-users. For more options, visit https://groups.google.com/groups/opt_out.
