collective / sauna.reload

Instant code reloading for Plone using a fork loop.
http://pypi.python.org/pypi/sauna.reload/
Other
11 stars 5 forks source link

Child dies after boot-up #3

Closed miohtama closed 12 years ago

miohtama commented 12 years ago

Hi,

This issue plagues me on OSX Snow Leopard and Lion

sauna.reload correctly reloads Plone site. However, after the reload, when the request hits the site the site dies (SIGCHLD). After this all subsequent requests cause the site die also.

The log:

    Child died on bootup. Pausing fork loop for now. 
    Fix possible errors and save edits and we'll try booting again. 
    Waiting... 

    ... (edit a file) ...

    2012-06-01 14:27:36 INFO sauna.reload.parent Got 'modified' event on /fast/xxx3/...
    2012-06-01 14:27:36 INFO sauna.reload.parent Not sending SIGINT because we already killed the child. Just scheduling new fork.
    2012-06-01 14:27:37 INFO sauna.reload.child Forked new child. Installing reloadable products...
    2012-06-01 14:27:37 INFO ZEO.cache created temporary cache file '<fdopen>'
    2012-06-01 14:27:37 INFO ZEO.ClientStorage zeostorage Testing connection <ManagedClientConnection ('127.0.0.1', 13000)>
    2012-06-01 14:27:37 INFO ZEO.zrpc.Connection(C) (127.0.0.1:13000) received handshake 'Z3101'
    2012-06-01 14:27:37 INFO ZEO.ClientStorage zeostorage Server authentication protocol None
    2012-06-01 14:27:37 INFO ZEO.ClientStorage zeostorage Connected to storage: ('localhost', 13000)
    2012-06-01 14:27:37 INFO ZEO.ClientStorage zeostorage No verification necessary -- empty cache
    /fast/buildout-cache/eggs/zope.configuration-3.7.4-py2.6.egg/zope/configuration/config.py:706: DeprecationWarning: Using <five:implements /> in File "/fast/xxx3/src/xxx-packages/Products.PloneArticle/Products/PloneArticle/implements.zcml", line 6.2-9.8
        <implements
    ...

    2012-06-01 14:27:38 INFO sauna.reload.child Booted up new child in 0.983772993088 seconds. PID 15034

    ... (then try to open any page) ...

    2012-06-01 14:28:41 INFO CMFFormController /fast/buildout-cache/eggs/Products.PloneFormGen-1.7.1-py2.6.egg/Products/PloneFormGen/skins/PloneFormGen/fg_base_view_p3.cpt: No default action specified for status success, content type ANY.  Users of IE can submit pages using the return key, resulting in no button in the REQUEST.  Please specify a default action for this case. 

    2012-06-01 14:28:41 INFO CMFFormController /fast/buildout-cache/eggs/Products.PloneFormGen-1.7.1-py2.6.egg/Products/PloneFormGen/skins/PloneFormGen/fg_base_view_p3.cpt: No default action specified for status success, content type ANY.  Users of IE can submit pages using the return key, resulting in no button in the REQUEST.  Please specify a default action for this case. 

    2012-06-01 14:28:41 INFO CMFFormController /fast/buildout-cache/eggs/Products.PloneFormGen-1.7.1-py2.6.egg/Products/PloneFormGen/skins/PloneFormGen/fg_embedded_view_p3.cpt: No default action specified for status success, content type ANY.  Users of IE can submit pages using the return key, resulting in no button in the REQUEST.  Please specify a default action for this case. 

    2012-06-01 14:28:41 INFO CMFFormController /fast/buildout-cache/eggs/Products.PloneFormGen-1.7.1-py2.6.egg/Products/PloneFormGen/skins/PloneFormGen/fg_embedded_view_p3.cpt: No default action specified for status success, content type ANY.  Users of IE can submit pages using the return key, resulting in no button in the REQUEST.  Please specify a default action for this case. 

    2012-06-01 14:28:41 WARNING OFS.Uninstalled Could not import class 'TextIndex' from module 'Products.PluginIndexes.TextIndex.TextIndex'
    2012-06-01 14:28:41 WARNING OFS.Uninstalled Could not import class 'Lexicon' from module 'Products.PluginIndexes.TextIndex.Lexicon'

    2012-06-01 14:28:43 INFO Plone Debug: xxx_user 
    xxx_lc         http://localhost:8080/xxxx....    
    /fast/xxx3/src/xxx-packages/plonetheme.xxxexternal/plonetheme/xxxexternal/browser/viewlets/common.py:227: DeprecationWarning: The actions method of the context state view was called without a category argument. This is deprecated and won't be supported anymore in Plone 5.
      self.user_actions = context_state.actions().get('user', None)
    2012-06-01 14:28:45 INFO SignalHandler Caught signal SIGCHLD

    Child died on bootup. Pausing fork loop for now. 
    Fix possible errors and save edits and we'll try booting again. 
    Waiting... 

I think the crucial part is 2012-06-01 14:28:45 INFO SignalHandler Caught signal SIGCHLD. Any idea what this could mean? Also Child died on bootup error message is misleading maybe because the child already booted?

Did not have this issue with sauna.reload 0.3.0 AFAIK

miohtama commented 12 years ago

Looks like child die regarless whether it is reloaded or not (first request kills)

miohtama commented 12 years ago

Some more debug revealed: INFO sauna.reload.parent Child 15441 exited, reasons terminated by signal 11,

miohtama commented 12 years ago

11 = SIGSEGV.

Lovely!

miohtama commented 12 years ago

OSX core dump instructions https://developer.apple.com/library/mac/#technotes/tn2004/tn2124.html

miohtama commented 12 years ago

FYI Plone dumps 576M core

miohtama commented 12 years ago

C traceback

(gdb) bt

0 0x00007fff904dadf2 in select$DARWIN_EXTSN ()

    #1  0x00000001071d4ed0 in select_select ()
    #2  0x0000000106537337 in PyEval_EvalFrameEx ()
    #3  0x000000010653a517 in PyEval_EvalCodeEx ()
    #4  0x000000010653a6c8 in fast_function ()
    #5  0x00000001065373e9 in PyEval_EvalFrameEx ()
    #6  0x000000010653a653 in fast_function ()
    #7  0x00000001065373e9 in PyEval_EvalFrameEx ()
    #8  0x000000010653a653 in fast_function ()
    #9  0x00000001065373e9 in PyEval_EvalFrameEx ()
    #10 0x000000010653a653 in fast_function ()
    #11 0x00000001065373e9 in PyEval_EvalFrameEx ()
    #12 0x000000010653a653 in fast_function ()
    #13 0x00000001065373e9 in PyEval_EvalFrameEx ()
    #14 0x000000010653a517 in PyEval_EvalCodeEx ()
    #15 0x000000010653a596 in PyEval_EvalCode ()
    #16 0x00000001065591c4 in PyRun_FileExFlags ()
    #17 0x000000010655a458 in PyRun_SimpleFileExFlags ()
    #18 0x0000000106567f99 in Py_Main ()
    #19 0x000000010649f834 in start ()

FYI gdb wires up 1,8 GB memory so your machine will crawl when running it

miohtama commented 12 years ago

Other threads:

(gdb) info threads 4 0x00007fff904dabca in __psynch_cvwait () 3 0x00007fff87679a91 in _dispatch_barrier_async_f_slow () 2 0x00007fff904dadf2 in select$DARWIN_EXTSN ()

miohtama commented 12 years ago

It is caused by IPython / ipdb.

The mechanism is still unknown, but other projects have had similar problems:

https://github.com/ipython/ipython/issues/711/

Solution: Don't put import ipdb ; ipdb.set_trace() to your code if it crashes with sauna.reload.