Foreman » Installer

I tried to trace the issue a little further, the only explanation I came up with is that the hostname of my testserver (bootstraptest01) is producing the problems... other machines with names like foreman01 install fine

From trace it looks like a problem in puppet, could you please send the output of puppet --version? How did you install puppet? Also could you run facter hostname and facter fqdn to see whether it works?

EDIT: sorry, from repolist I suppose you have latest puppet from puppetlabs repo, right?

We did see this briefly on our automated tests a few weeks ago, but it's since disappeared. Another user in IRC last week reported it too, but he thought the problem went away after a general yum update.

The only other info I have is that it only appeared with Puppet 3.4.2, not 2.7.2x from EPEL.

If you have a core dump, I'd suggest opening a support case with Red Hat, as the crash is from /usr/bin/ruby.

I created a support case with Red Hat, I'll keep this ticket updated :)
I use the latest puppet, all packages are the newest versions from their respective repositories.
If I have some spare time later I may try to look into the core dump with their respective debug packages but my skills are limited there :)

Thanks

Red Hat came back to me and claimed that it crashes because of a currupted bins, they are working on solving the issue.

In case anyone is interested, the backtrace with debugging symbols :)

bt
#0  0x0000003652c32925 in raise () from /lib64/libc.so.6
#1  0x0000003652c34105 in abort () from /lib64/libc.so.6
#2  0x00007f5b7167bb23 in rb_bug (fmt=0x7f5b7171422c "Segmentation fault") at error.c:213
#3  0x00007f5b716e3fec in sigsegv (sig=11) at signal.c:634
#4  <signal handler called>
#5  0x00007f5b716e7404 in st_foreach (table=0x7f5b6c3b2058, func=0x7f5b7169f2c0 <mark_entry>, arg=2) at st.c:487
#6  0x00007f5b7169f162 in gc_mark_children (ptr=<value optimized out>, lev=1) at gc.c:1063
#7  0x00007f5b7169ed0f in mark_locations_array (x=<value optimized out>, n=33889) at gc.c:690
#8  0x00007f5b7169f5b7 in garbage_collect () at gc.c:1493
#9  0x00007f5b716a022f in ruby_xmalloc (size=<value optimized out>) at gc.c:153
#10 0x00007f5b716a062d in ruby_xcalloc (n=<value optimized out>, size=<value optimized out>) at gc.c:174
#11 0x00007f5b716e7ba6 in st_init_table_with_size (type=0x7f5b71934860, size=11) at st.c:164
#12 0x00007f5b7166c269 in flatten (ary=140030631337440, level=-1, modified=0x7fff4148951c) at array.c:3139
#13 0x00007f5b7166c58f in rb_ary_flatten (argc=<value optimized out>, argv=<value optimized out>, ary=140030631337440) at array.c:3252
#14 0x00007f5b7168a6a5 in rb_call0 (klass=140030721096760, recv=140030631337440, id=7105, oid=<value optimized out>, argc=0, argv=0x0, body=0x7f5b71636540, flags=0) at eval.c:5968
#15 0x00007f5b7168aac7 in rb_call (klass=140030721096760, recv=140030631337440, mid=7105, argc=0, argv=0x0, scope=0, self=<value optimized out>) at eval.c:6251
#16 0x00007f5b71687602 in rb_eval (self=140030665413080, n=0x7f5b6e5923f8) at eval.c:3530
#17 0x00007f5b7168a5c3 in rb_call0 (klass=140030670071360, recv=140030665413080, id=68705, oid=<value optimized out>, argc=<value optimized out>, argv=<value optimized out>, 
    body=0x7f5b6e592ce0, flags=2) at eval.c:6147
#18 0x00007f5b7168aac7 in rb_call (klass=140030670071360, recv=140030665413080, mid=68705, argc=2, argv=0x7fff4148aaa0, scope=1, self=<value optimized out>) at eval.c:6251
#19 0x00007f5b716874fb in rb_eval (self=140030665413080, n=0x7f5b6e593488) at eval.c:3545
#20 0x00007f5b7168a5c3 in rb_call0 (klass=140030670071360, recv=140030665413080, id=68737, oid=<value optimized out>, argc=<value optimized out>, argv=<value optimized out>, 
    body=0x7f5b6e5935c8, flags=2) at eval.c:6147
(gdb) f 5
#5  0x00007f5b716e7404 in st_foreach (table=0x7f5b6c3b2058, func=0x7f5b7169f2c0 <mark_entry>, arg=2) at st.c:487
487        for(ptr = table->bins[i]; ptr != 0;) {
(gdb) p *table
$7 = {type = 0x2147, num_bins = 1902389232, num_entries = 32603, bins = 0x4c}
(gdb) p *0x4c
Cannot access memory at address 0x4c

I hit this as well with 64-bit RHEL 6.5 and puppet 3.4.2 from Puppet Labs repository. I think my first run of foreman-installer completed (but with errors) and all subsequent runs were aborted by this core dump.

I rolled back to an lvm snapshot from before I ran foreman-installer, removed puppet 3.4.2, and installed 2.7.23 from EPEL instead. That solved the problem.

Just for reference, this was raised to the (private) BZ: https://bugzilla.redhat.com/show_bug.cgi?id=1064340. Currently waiting on more detailed analysis. Thanks to Klaas for raising the case.

just a heads up, RedHat is taking their time to fix this. I got an email today that basicly states that nothing has changed since their initial analysis ... :)

Adding lsof output, not many native extensions there:

 lsof -np 4540
COMMAND  PID USER   FD   TYPE DEVICE SIZE/OFF   NODE NAME
puppet  4540 root  cwd    DIR    8,1     4096     49 /root
puppet  4540 root  rtd    DIR    8,1     4096      2 /
puppet  4540 root  txt    REG    8,1     5184  15266 /usr/bin/ruby
puppet  4540 root  mem    REG    8,1    35696  15701 /usr/lib64/ruby/site_ruby/1.8/x86_64-linux/json/ext/generator.so
puppet  4540 root  mem    REG    8,1    20792  15702 /usr/lib64/ruby/site_ruby/1.8/x86_64-linux/json/ext/parser.so
puppet  4540 root  mem    REG    8,1     9864  17296 /usr/lib64/ruby/site_ruby/1.8/x86_64-linux/shadow.so
puppet  4540 root  mem    REG    8,1   208040  14506 /usr/lib64/ruby/site_ruby/1.8/x86_64-linux/selinux.so
puppet  4540 root  mem    REG    8,1  1380832   5208 /usr/lib64/libxml2.so.2.7.6
puppet  4540 root  mem    REG    8,1    89224  14510 /usr/lib64/libfa.so.1.4.0
puppet  4540 root  mem    REG    8,1   312888  14508 /usr/lib64/libaugeas.so.0.16.0
puppet  4540 root  mem    REG    8,1    13464  17291 /usr/lib64/ruby/site_ruby/1.8/x86_64-linux/_augeas.so
puppet  4540 root  mem    REG    8,1    12408  15233 /usr/lib64/ruby/1.8/x86_64-linux/digest/sha2.so
puppet  4540 root  mem    REG    8,1    38280  15255 /usr/lib64/ruby/1.8/x86_64-linux/zlib.so
puppet  4540 root  mem    REG    8,1     5368  15230 /usr/lib64/ruby/1.8/x86_64-linux/digest/md5.so
puppet  4540 root  mem    REG    8,1    15128  15245 /usr/lib64/ruby/1.8/x86_64-linux/racc/cparse.so
puppet  4540 root  mem    REG    8,1    48536  15249 /usr/lib64/ruby/1.8/x86_64-linux/socket.so
puppet  4540 root  mem    REG    8,1     5368  15232 /usr/lib64/ruby/1.8/x86_64-linux/digest/sha1.so
puppet  4540 root  mem    REG    8,1    12720  15253 /usr/lib64/ruby/1.8/x86_64-linux/syslog.so
puppet  4540 root  mem    REG    8,1    65928   4448 /lib64/libnss_files-2.12.so
puppet  4540 root  mem    REG    8,1    19296  15251 /usr/lib64/ruby/1.8/x86_64-linux/strscan.so
puppet  4540 root  mem    REG    8,1    16664  15238 /usr/lib64/ruby/1.8/x86_64-linux/iconv.so
puppet  4540 root  mem    REG    8,1   267248  15241 /usr/lib64/ruby/1.8/x86_64-linux/nkf.so
puppet  4540 root  mem    REG    8,1     5192  15236 /usr/lib64/ruby/1.8/x86_64-linux/fcntl.so
puppet  4540 root  mem    REG    8,1    12384  15228 /usr/lib64/ruby/1.8/x86_64-linux/digest.so
puppet  4540 root  mem    REG    8,1   122040   4957 /lib64/libselinux.so.1
puppet  4540 root  mem    REG    8,1   110960   4458 /lib64/libresolv-2.12.so
puppet  4540 root  mem    REG    8,1    10192   6623 /lib64/libkeyutils.so.1.3
puppet  4540 root  mem    REG    8,1    43728   6635 /lib64/libkrb5support.so.0.1
puppet  4540 root  mem    REG    8,1    88600   4858 /lib64/libz.so.1.2.3
puppet  4540 root  mem    REG    8,1   174840   6631 /lib64/libk5crypto.so.3.1
puppet  4540 root  mem    REG    8,1    14664   4876 /lib64/libcom_err.so.2.1
puppet  4540 root  mem    REG    8,1   941920   6633 /lib64/libkrb5.so.3.3
puppet  4540 root  mem    REG    8,1   277704   6627 /lib64/libgssapi_krb5.so.2.2
puppet  4540 root  mem    REG    8,1  1946880   8603 /usr/lib64/libcrypto.so.1.0.1e
puppet  4540 root  mem    REG    8,1   436984   8605 /usr/lib64/libssl.so.1.0.1e
puppet  4540 root  mem    REG    8,1   265096  15242 /usr/lib64/ruby/1.8/x86_64-linux/openssl.so
puppet  4540 root  mem    REG    8,1   119912  15252 /usr/lib64/ruby/1.8/x86_64-linux/syck.so
puppet  4540 root  mem    REG    8,1    20752  15250 /usr/lib64/ruby/1.8/x86_64-linux/stringio.so
puppet  4540 root  mem    REG    8,1    10968  15235 /usr/lib64/ruby/1.8/x86_64-linux/etc.so
puppet  4540 root  mem    REG    8,1    16472  15254 /usr/lib64/ruby/1.8/x86_64-linux/thread.so
puppet  4540 root  mem    REG    8,1   469528   3860 /lib64/libfreebl3.so
puppet  4540 root  mem    REG    8,1    90880     34 /lib64/libgcc_s-4.4.7-20120601.so.1
puppet  4540 root  mem    REG    8,1  1921216   4432 /lib64/libc-2.12.so
puppet  4540 root  mem    REG    8,1   596264   4440 /lib64/libm-2.12.so
puppet  4540 root  mem    REG    8,1    40400   4436 /lib64/libcrypt-2.12.so
puppet  4540 root  mem    REG    8,1    19536   4438 /lib64/libdl-2.12.so
puppet  4540 root  mem    REG    8,1    43832   4460 /lib64/librt-2.12.so
puppet  4540 root  mem    REG    8,1   142640   4456 /lib64/libpthread-2.12.so
puppet  4540 root  mem    REG    8,1   948192  15223 /usr/lib64/libruby.so.1.8.7
puppet  4540 root  mem    REG    8,1   154520   4424 /lib64/ld-2.12.so
puppet  4540 root    0r  FIFO    0,8      0t0  49923 pipe
puppet  4540 root    1u   CHR  136,2      0t0      5 /dev/pts/2
puppet  4540 root    2u   CHR  136,2      0t0      5 /dev/pts/2
puppet  4540 root    3u   REG    8,1   484659 141552 /var/log/foreman-installer/foreman-installer.log

Namely: json, shadow, selinux, augeas.

I am trying SystemTap now to see latest pure ruby method calls before the coredump. Looks good so far, but slow. Waiting for another run to finish.

The bug does not seem to be stable.

/usr/lib/ruby/site_ruby/1.8/puppet/parser/type_loader.rb:91: [BUG] rb_gc_mark(): unknown data type 0x30(0x7f003d895ed8) non object

/usr/lib/ruby/site_ruby/1.8/puppet/parser/type_loader.rb:91: [BUG] Segmentation fault

/usr/lib/ruby/site_ruby/1.8/puppet/parser/type_loader.rb:91: [BUG] rb_gc_mark() called for broken object

At least I have top method calls when segfault was raised:

414956x Hash.[]
347066x String.==
292584x StringScanner.match?
225574x Object.==
157227x Object.method
153018x String.[]
132849x Object.respond_to?
120069x Hash.[]=
118181x Class.exist?
112672x Class.basename
112369x Regexp.to_s
111858x Pathname.chop_basename
110421x Object.hash
98185x Hash.default
96394x Array.unshift
95196x Array.each
91555x String.rindex
89526x Class.new
85597x String.=~
78612x Method.==
76487x Object.dup
75959x Class.join
75205x Object.send
72871x String.initialize_copy
72667x Array.[]
70509x String.+
70234x Object.is_a?
68105x Array.empty?
67787x Symbol.to_s

Tracking down individual method calls before the sigsegv is a challange, I can see all of them, but it's a log 2 gigs long. Too much detailed. Let's see if I can find a way to filter this out.

With -O0 I can see the ruby object that is causing the segfault on my system:

(gdb) f 3
#3  0x00007f3794494dd6 in gc_mark_children (ptr=139876675993304, lev=2) at gc.c:1080
1080            rb_bug("rb_gc_mark(): unknown data type 0x%lx(0x%lx) %s",
(gdb) p *obj
$6 = {as = {free = {flags = 128097008, next = 0x7a29120}, basic = {flags = 128097008, klass = 128094496}, object = {basic = {
        flags = 128097008, klass = 128094496}, iv_tbl = 0x7f379395bed8}, klass = {basic = {flags = 128097008, 
        klass = 128094496}, iv_tbl = 0x7f379395bed8, m_tbl = 0x7f379395bed8, super = 139876675993320}, flonum = {basic = {
        flags = 128097008, klass = 128094496}, value = 6.9108260262758527e-310}, string = {basic = {flags = 128097008, 
        klass = 128094496}, len = 139876675993304, ptr = 0x7f379395bed8 "\360\232\242\a", aux = {capa = 139876675993320, 
        shared = 139876675993320}}, array = {basic = {flags = 128097008, klass = 128094496}, len = 139876675993304, aux = {
        capa = 139876675993304, shared = 139876675993304}, ptr = 0x7f379395bee8}, regexp = {basic = {flags = 128097008, 
        klass = 128094496}, ptr = 0x7f379395bed8, len = 139876675993304, str = 0x7f379395bee8 "ؾ\225\223\067\177"}, hash = {
      basic = {flags = 128097008, klass = 128094496}, tbl = 0x7f379395bed8, iter_lev = -1818902824, 
      ifnone = 139876675993320}, data = {basic = {flags = 128097008, klass = 128094496}, 
      dmark = 0x7f379395bed8 <main_arena+88>, dfree = 0x7f379395bed8 <main_arena+88>, data = 0x7f379395bee8}, rstruct = {
      basic = {flags = 128097008, klass = 128094496}, len = 139876675993304, ptr = 0x7f379395bed8}, bignum = {basic = {
        flags = 128097008, klass = 128094496}, sign = -40 '\330', len = 139876675993304, digits = 0x7f379395bee8}, file = {
      basic = {flags = 128097008, klass = 128094496}, fptr = 0x7f379395bed8}, node = {flags = 128097008, 
      nd_file = 0x7a29120 "h\037]\214\067\177", u1 = {node = 0x7f379395bed8, id = 139876675993304, value = 139876675993304, 
        cfunc = 0x7f379395bed8 <main_arena+88>, tbl = 0x7f379395bed8}, u2 = {node = 0x7f379395bed8, id = 139876675993304, 
        argc = 139876675993304, value = 139876675993304}, u3 = {node = 0x7f379395bee8, id = 139876675993320, 
        state = 139876675993320, entry = 0x7f379395bee8, cnt = 139876675993320, value = 139876675993320}}, match = {basic = {
        flags = 128097008, klass = 128094496}, str = 139876675993304, regs = 0x7f379395bed8}, varmap = {super = {
        flags = 128097008, klass = 128094496}, id = 139876675993304, val = 139876675993304, next = 0x7f379395bee8}, scope = {
      super = {flags = 128097008, klass = 128094496}, local_tbl = 0x7f379395bed8, local_vars = 0x7f379395bed8, 
      flags = -1818902808}}}

I thought memory map will point on a native extension, but it is in the main heap :-(

I need to go for today, but I am suspicious that some libraries which are carried by puppetlabs RHEL repo are built incorrectly with ABI breakage. The biggest candidate is ruby-shadow where we can se major upgrade on February 2014: https://yum.puppetlabs.com/el/6/dependencies/x86_64/

Will investigate this tomorrow.

Ok that was false suspicion. I wonder if the upgrade to SCL 193 ruby is the only way of fixing this.

I ran into the same issue; Fully updated RHEL 6.5, with Ruby 1.8.7, same segfault with the ruby installer. After installing Ruby 1.9.3 (ruby193) from RHSCL repo, the foreman-install completed successfully now. An uninstall of 1.8.7 was not required.

Ugly workaround: (Only if you have more than 4 GB of memory):

Edit /usr/bin/puppet and add this line to the top:

GC.disable = true

Then run the installer and remove this one.

GC.disable = true

or GC.disable

I am also running into this problem. I can reproduce it consistantly. Things I've tried

puppet 3.7
puppet 3.6
yum upgrade
rvm + ruby 1.9.3
rvm + ruby 2.1.2

All still have the same crash. I've not been able to work around this.

Update

foreman 1.6.0 does not appear to have this problem. It installed sucessfully.