Re: [etch-users] How can I debug what happens on Etch server when a client does --list-files

SourceForge Headquarters 225 Broadway Suite 1600 San Diego, CA 92101 +1 (858) 422-6466

We've also seen intermittent segfaults from the libxml gem.  In the 3.19.0 release I added support for the nokogiri XML library.  I'd recommend you try that. Install the nokogiri gem, then set "xmllib=nokogiri" in your shell environment before starting Unicorn.

I plan to make nokogiri the default in an upcoming release as it seems to be more stable than libxml.

Jason

On May 26, 2011, at 10:29 AM, Johnston, Nathaniel wrote:

> An update on this,
> 
> I updated to libxml-ruby-v2.0.6, and now the issue is a little different.  After I start the server, I can serve one request, and then I get a segfault.  I just started up the server, and I run the first request, which is "etch -n --debug /etc/issue.net".  The output on the server is the facter load, and this at the end:
> 
>>   Fact Load (9.6ms)   SELECT * FROM "facts" WHERE ("facts"."client_id" = 1) 
>>   Original Load (0.3ms)   SELECT * FROM "originals" WHERE ("originals"."client_id" = 1 AND "originals"."file" = '/etc/issue.net') LIMIT 1
>>   EtchConfig Load (0.3ms)   SELECT * FROM "etch_configs" WHERE ("etch_configs"."client_id" = 1 AND "etch_configs"."file" = '/etc/issue.net') LIMIT 1
>> Completed in 873ms (View: 1, DB: 40) | 200 OK [http://etch.sys.comcast.net/files]
> 
> 
> Here is what the client sees, after the big hash of facts:
> 
>> Response from server:
>> '<?xml version="1.0" encoding="UTF-8"?>
>> <files>
>>   <configs>
>>     <config filename="/etc/issue.net">
>>         <file>
>>                 <!--
>>                         By default files will be owned by root,
>>                         but you can change that.  If this user or
>>                         group doesn't exist UID 0 and GID 0 will
>>                         be used as a faillback.
>>                   -->
>>                 <owner>root</owner>
>>                 <group>sys</group>
>>                 <perms>644</perms>
>> 
>>                 
>>         <contents>KioqKioqKioqKioqKioqKioqKioqKioqKioqKioqKioqKioqKioqKioqKioq
>> KioqKioqKioqKioKV0FSTklORzoKICAgIAogIFRoaXMgc3lzdGVtICBpcyBz
>> b2xlbHkgZm9yICB0aGUgdXNlIG9mIGF1dGhvcml6ZWQgIENvbWNhc3QgZW1w
>> bG95ZWVzCiAgYW5kIGNvbnRyYWN0b3JzLgogICAgCiAgQ29tY2FzdCAgcmVz
>> ZXJ2ZXMgdGhlIHJpZ2h0ICBhdCBhbnkgIHRpbWUgdG8gIG1vbml0b3IgdXNh
>> Z2UgIG9mIHRoaXMKICBzeXN0ZW0gdG8gZW5zdXJlIGNvbXBsaWFuY2Ugd2l0
>> aCB0aGlzIHBvbGljeSwgYWxsIGFwcGxpY2FibGUgQ29tY2FzdAogIHBvbGlj
>> aWVzIHRoYXQgYXBwbHkgdG8gZWxlY3Ryb25pYyBjb21tdW5pY2F0aW9ucywg
>> YW5kIGFsbCBhcHBsaWNhYmxlCiAgbGF3cy4KICAgIAogIFlvdXIgdXNlIG9m
>> IHRoaXMgc3lzdGVtIGNvbnN0aXR1dGVzIHlvdXIgYWNjZXB0YW5jZSBvZiBh
>> bmQgYWdyZWVtZW50CiAgdG8gYWxsICBhcHBsaWNhYmxlIENvbWNhc3QgZWxl
>> Y3Ryb25pYyAgY29tbXVuaWNhdGlvbnMgcG9saWNpZXMsIHlvdXIKICBjb25z
>> ZW50IHRvIG1vbml0b3JpbmcgYnkgQ29tY2FzdCwgIGFuZCB5b3VyIGV4cHJl
>> c3MgYWdyZWVtZW50IHRvIHVzZQogIHRoaXMgc3lzdGVtIGluIGNvbXBsaWFu
>> Y2Ugd2l0aCBhbGwgYXBwbGljYWJsZSBsYXdzLgogICAgCiAgQW55IHVuYXV0
>> aG9yaXplZCAgdXNlIG9mIG9yICBhY2Nlc3MgdG8gdGhpcyAgc3lzdGVtIG1h
>> eSByZXN1bHQgIGluIGEKICByZXZvY2F0aW9uIG9mIHlvdXIgdXNlciAgcHJp
>> dmlsZWdlcywgb3RoZXIgZGlzY2lwbGluYXJ5IGFjdGlvbiB1cCB0bwogIGFu
>> ZCBpbmNsdWRpbmcgdGVybWluYXRpb24gb2YgZW1wbG95bWVudCBvciBjb250
>> cmFjdCwgb3IgcmVmZXJyYWxzIHRvCiAgbGF3IGVuZm9yY2VtZW50ICBvZmZp
>> Y2lhbHMgaW5jbHVkaW5nICB0aGUgcHJvdmlzaW9uIGV2aWRlbmNlICBvZiBh
>> bnkKICB1bmF1dGhvcml6ZWQgdXNlIG9yIGFjY2VzcyB0byBsYXcgZW5mb3Jj
>> ZW1lbnQuCioqKioqKioqKioqKioqKioqKioqKioqKioqKioqKioqKioqKioq
>> KioqKioqKioqKioqKioqKioqKioqKioqIAoK
>> </contents></file>
>> </config>
>>   </configs>
>>   <allcommands/>
>>   <retrycommands/>
>> </files>
>> '
>> Processing config for /etc/issue.net
>> Processing /etc/issue.net
>> No change to /etc/issue.net necessary
> 
> 
> Then I run the same command again exactly as before.  Here is what the server logs see:
> 
>> /opt/comcast/platform/etch/lib/ruby/gems/1.8/gems/libxml-ruby-2.0.6/lib/libxml/node.rb:61: [BUG] Segmentation fault
>> ruby 1.8.7 (2011-02-18 patchlevel 334) [x86_64-linux], MBARI 0x6770, Ruby Enterprise Edition 2011.03
>> 
>> E, [2011-05-26T17:26:34.509706 #2212] ERROR -- : reaped #<Process::Status: pid=2213,signaled(SIGIOT=6)> worker=0
>> Exception `Errno::ECHILD' at /opt/comcast/platform/etch/lib/ruby/gems/1.8/gems/unicorn-3.6.2/lib/unicorn/http_server.rb:401 - No child processes
>> I, [2011-05-26T17:26:34.509984 #2212]  INFO -- : worker=0 spawning...
> 
> 
> Here is what the client sees, after the hash of facts:
> 
>> end of file reached
>> /opt/comcast/platform/etch/lib/ruby/1.8/net/protocol.rb:135:in `sysread'
>> /opt/comcast/platform/etch/lib/ruby/1.8/net/protocol.rb:135:in `rbuf_fill'
>> /opt/comcast/platform/etch/lib/ruby/1.8/timeout.rb:67:in `timeout'
>> /opt/comcast/platform/etch/lib/ruby/1.8/timeout.rb:101:in `timeout'
>> /opt/comcast/platform/etch/lib/ruby/1.8/net/protocol.rb:134:in `rbuf_fill'
>> /opt/comcast/platform/etch/lib/ruby/1.8/net/protocol.rb:116:in `readuntil'
>> /opt/comcast/platform/etch/lib/ruby/1.8/net/protocol.rb:126:in `readline'
>> /opt/comcast/platform/etch/lib/ruby/1.8/net/http.rb:2028:in `read_status_line'
>> /opt/comcast/platform/etch/lib/ruby/1.8/net/http.rb:2017:in `read_new'
>> /opt/comcast/platform/etch/lib/ruby/1.8/net/http.rb:1051:in `request'
>> /opt/comcast/platform/etch/lib/ruby/gems/1.8/gems/etch-3.19.0/lib/etchclient.rb:339:in `process_until_done'
>> /opt/comcast/platform/etch/lib/ruby/gems/1.8/gems/etch-3.19.0/lib/etchclient.rb:312:in `times'
>> /opt/comcast/platform/etch/lib/ruby/gems/1.8/gems/etch-3.19.0/lib/etchclient.rb:312:in `process_until_done'
>> /opt/comcast/platform/etch/lib/ruby/gems/1.8/gems/etch-3.19.0/lib/etchclient.rb:240:in `catch'
>> /opt/comcast/platform/etch/lib/ruby/gems/1.8/gems/etch-3.19.0/lib/etchclient.rb:240:in `process_until_done'
>> /opt/comcast/platform/etch/lib/ruby/gems/1.8/gems/etch-3.19.0/bin/etch:109
>> /opt/comcast/etch/bin/etch:19:in `load'
>> /opt/comcast/etch/bin/etch:19
> 
> 
> So, what can I do from here?
> 
> Thanks,
> 
> --N.
> 
> 
> 
> On May 25, 2011, at 3:16 PM, Johnston, Nathaniel wrote:
> 
>> EtchMen,
>> 
>> I am having an issue where I see the Etch server segfaulting each time I try and run Etch, even if I use the --list-files or the --dry-run methods.  Here's how it happens.  First, I start up the Etch server.  Here is what it outputs on startup:
>> 
>>> # unicorn_rails -d -p 38240 
>>> {:daemonize=>false,
>>>  :app=>
>>>   #<Proc:0x000000000eaf56c8@/opt/comcast/platform/etch/lib/ruby/gems/1.8/gems/unicorn-3.6.2/bin/unicorn_rails:135>,
>>>  :unicorn_options=>{:listeners=>[]}}
>>> Exception `Errno::EEXIST' at /opt/comcast/platform/etch/lib/ruby/1.8/fileutils.rb:243 - File exists - tmp/cache
>>> Exception `Errno::EEXIST' at /opt/comcast/platform/etch/lib/ruby/1.8/fileutils.rb:243 - File exists - tmp/pids
>>> Exception `Errno::EEXIST' at /opt/comcast/platform/etch/lib/ruby/1.8/fileutils.rb:243 - File exists - tmp/sessions
>>> Exception `Errno::EEXIST' at /opt/comcast/platform/etch/lib/ruby/1.8/fileutils.rb:243 - File exists - tmp/sockets
>>> I, [2011-05-25T19:11:33.677699 #19746]  INFO -- : listening on addr=0.0.0.0:38240 fd=3
>>> I, [2011-05-25T19:11:33.677935 #19746]  INFO -- : worker=0 spawning...
>>> I, [2011-05-25T19:11:33.678549 #19746]  INFO -- : master process ready
>>> Exception `NameError' at /opt/comcast/platform/etch/lib/ruby/gems/1.8/gems/unicorn-3.6.2/lib/unicorn/http_server.rb:499 - uninitialized constant Unicorn::HttpServer::OpenSSL
>>> I, [2011-05-25T19:11:33.679040 #19747]  INFO -- : worker=0 spawned pid=19747
>>> I, [2011-05-25T19:11:33.679169 #19747]  INFO -- : Refreshing Gem list
>>> Exception `NoMethodError' at /opt/comcast/platform/etch/lib/ruby/1.8/rational.rb:82 - undefined method `gcd' for Rational(1, 2):Rational
>>> Exception `Gem::LoadError' at /opt/comcast/platform/etch/lib/ruby/site_ruby/1.8/rubygems.rb:274 - can't activate activerecord (~> 2.3.11, runtime) for ["searchlogic-2.5.6"], already activated activerecord-2.3.8 for ["rails-2.3.8"]
>>> Exception `Gem::LoadError' at /opt/comcast/platform/etch/lib/ruby/site_ruby/1.8/rubygems.rb:861 - RubyGem version error: builder(3.0.0 not ~> 2.1.2)
>>> 
>>> Exception `TypeError' at (eval):4 - can't modify frozen object
>>> Exception `MissingSourceFile' at /opt/comcast/platform/etch/lib/ruby/site_ruby/1.8/rubygems/custom_require.rb:29 - no such file to load -- fast_xs
>>> Exception `MissingSourceFile' at /opt/comcast/platform/etch/lib/ruby/site_ruby/1.8/rubygems/custom_require.rb:29 - no such file to load -- json
>>> Using Ext extension for JSON.
>>> Exception `Gem::LoadError' at /opt/comcast/platform/etch/lib/ruby/site_ruby/1.8/rubygems.rb:861 - Could not find RubyGem activerecord-sqlite3-adapter (>= 0)
>>> 
>>> Exception `NameError' at /opt/comcast/platform/etch/lib/ruby/gems/1.8/gems/activesupport-2.3.8/lib/active_support/dependencies.rb:443 - uninitialized constant ActionDispatch
>>> Exception `MissingSourceFile' at /opt/comcast/platform/etch/lib/ruby/site_ruby/1.8/rubygems/custom_require.rb:29 - no such file to load -- ruby-debug
>>> Exception `MissingSourceFile' at /opt/comcast/platform/etch/lib/ruby/site_ruby/1.8/rubygems/custom_require.rb:29 - no such file to load -- classtree
>>> Exception `MissingSourceFile' at /opt/comcast/platform/etch/lib/ruby/site_ruby/1.8/rubygems/custom_require.rb:35 - no such file to load -- classtree
>>> Exception `MissingSourceFile' at /opt/comcast/platform/etch/lib/ruby/gems/1.8/gems/activesupport-2.3.8/lib/active_support/dependencies.rb:162 - no such file to load -- classtree
>>> Exception `MissingSourceFile' at /opt/comcast/platform/etch/lib/ruby/site_ruby/1.8/rubygems/custom_require.rb:29 - no such file to load -- methodsig
>>> Exception `MissingSourceFile' at /opt/comcast/platform/etch/lib/ruby/site_ruby/1.8/rubygems/custom_require.rb:35 - no such file to load -- methodsig
>>> Exception `MissingSourceFile' at /opt/comcast/platform/etch/lib/ruby/gems/1.8/gems/activesupport-2.3.8/lib/active_support/dependencies.rb:162 - no such file to load -- methodsig
>>> => Debugger enabled
>>> worker=0 ready
>> 
>> 
>> I run a simple command on the etch client, which seems to bomb, although the error messaging is enigmatic:
>> 
>>> [root@jumphst-ch-2p tmp]# etch /etc/yum.conf
>>> Saving temporary copy of original file:  /etc/yum.conf -> /var/etch/orig/etc/yum.conf.TMP
>>> 1 block
>>> end of file reached
>> 
>> 
>> Etch server segfaults.  Here is what it says, although I cut the output off for brevity when it was restating messages from the startup block of logs, above.
>> 
>>> Exception `MissingSourceFile' at /opt/comcast/platform/etch/lib/ruby/site_ruby/1.8/rubygems/custom_require.rb:29 - no such file to load -- sqlite3
>>> Exception `MissingSourceFile' at /opt/comcast/platform/etch/lib/ruby/site_ruby/1.8/rubygems/custom_require.rb:29 - no such file to load -- libxml
>>> /opt/comcast/platform/etch/lib/ruby/gems/1.8/gems/libxml-ruby-1.1.2/lib/libxml/node.rb:57: [BUG] Segmentation fault
>>> ruby 1.8.7 (2011-02-18 patchlevel 334) [x86_64-linux], MBARI 0x6770, Ruby Enterprise Edition 2011.03
>>> 
>>> E, [2011-05-25T19:12:23.940838 #19746] ERROR -- : reaped #<Process::Status: pid=19756,signaled(SIGIOT=6)> worker=0
>>> Exception `Errno::ECHILD' at /opt/comcast/platform/etch/lib/ruby/gems/1.8/gems/unicorn-3.6.2/lib/unicorn/http_server.rb:401 - No child processes
>>> I, [2011-05-25T19:12:23.941145 #19746]  INFO -- : worker=0 spawning...
>>> Exception `NameError' at /opt/comcast/platform/etch/lib/ruby/gems/1.8/gems/unicorn-3.6.2/lib/unicorn/http_server.rb:499 - uninitialized constant Unicorn::HttpServer::OpenSSL
>>> I, [2011-05-25T19:12:23.942207 #19758]  INFO -- : worker=0 spawned pid=19758
>>> I, [2011-05-25T19:12:23.942324 #19758]  INFO -- : Refreshing Gem list
>> 
>> 
>> Here is the output of `gem list --local`:
>> 
>>> *** LOCAL GEMS ***
>>> 
>>> actionmailer (2.3.8)
>>> actionpack (2.3.8)
>>> activerecord (2.3.11, 2.3.8)
>>> activeresource (2.3.8)
>>> activesupport (2.3.11, 2.3.8)
>>> builder (3.0.0)
>>> bundler (1.0.13)
>>> columnize (0.3.2)
>>> etch (3.19.0)
>>> facter (1.5.8)
>>> fast_xs (0.8.0)
>>> gem2rpm (0.6.0)
>>> i18n (0.6.0)
>>> json (1.5.1)
>>> kgio (2.4.0)
>>> libxml-ruby (1.1.2)
>>> linecache (0.43)
>>> memcache-client (1.8.5)
>>> nokogiri (1.4.4)
>>> rack (1.1.2)
>>> rails (2.3.8)
>>> rake (0.8.7)
>>> ruby-debug (0.10.4)
>>> ruby-debug-base (0.10.4)
>>> searchlogic (2.5.6)
>>> sqlite3-ruby (1.2.5)
>>> tmail (1.2.7.1)
>>> tzinfo (0.3.27)
>>> unicorn (3.6.2)
>>> will_paginate (2.3.15)
>> 
>> 
>> --N.
>> ------------------------------------------------------------------------------
>> vRanger cuts backup time in half-while increasing security.
>> With the market-leading solution for virtual backup and recovery, 
>> you get blazing-fast, flexible, and affordable data protection.
>> Download your free trial now. 
>> http://p.sf.net/sfu/quest-d2dcopy1_______________________________________________
>> etch-users mailing list
>> etc...@li...
>> https://lists.sourceforge.net/lists/listinfo/etch-users
> 
> 
> ------------------------------------------------------------------------------
> vRanger cuts backup time in half-while increasing security.
> With the market-leading solution for virtual backup and recovery, 
> you get blazing-fast, flexible, and affordable data protection.
> Download your free trial now. 
> http://p.sf.net/sfu/quest-d2dcopy1_______________________________________________
> etch-users mailing list
> etc...@li...
> https://lists.sourceforge.net/lists/listinfo/etch-users