Help me debug my stack trace

ruby-talk
1

So currently ruby is hung using 100% CPU on my machine.

Some questions:
1) does anybody else have this happen to them?
2) does anybody else have a chunk of code that reliably causes ruby to
leak memory?

Anyway here are some sample stack traces, if anybody has any pointers.
Thanks!
-R

  1 24540 select$UNIX2003:entry
  1 24523 select$DARWIN_EXTSN:entry
  1 23368 _sysenter_trap:entry
  1 22941 ruby_stack_length:entry
  1 23392 memcpy:entry
  1 23094 rb_lastline_get:entry
  1 22804 rb_svar:entry
  1 23095 rb_lastline_set:entry
  1 22804 rb_svar:entry
  1 23092 rb_backref_get:entry
  1 22804 rb_svar:entry
  1 23093 rb_backref_set:entry
  1 22804 rb_svar:entry
  1 23991 _setjmp:entry
  1 23392 memcpy:entry
  1 23094 rb_lastline_get:entry
  1 22804 rb_svar:entry
  1 23095 rb_lastline_set:entry
  1 22804 rb_svar:entry
  1 23092 rb_backref_get:entry
  1 22804 rb_svar:entry
  1 23093 rb_backref_set:entry
  1 22804 rb_svar:entry
  1 23992 _longjmp:entry
  1 24032 time:entry
  1 28005 fegetenv:entry
  1 23952 gettimeofday:entry
  1 23953 __commpage_gettimeofday:entry
  1 28000 fesetenv:entry
  1 22874 rb_thread_schedule:entry
  1 22806 is_ruby_native_thread:entry
  1 23481 pthread_self:entry
  1 23868 pthread_equal:entry
  1 23356 memset:entry
  1 23356 memset:entry
  1 23356 memset:entry
  1 23952 gettimeofday:entry
  1 23953 __commpage_gettimeofday:entry
  1 24540 select$UNIX2003:entry
  1 24523 select$DARWIN_EXTSN:entry
  1 23368 _sysenter_trap:entry
  1 22943 rb_gc_force_recycle:entry
  1 22871 rb_need_block:entry
  1 22960 rb_newobj:entry
  1 23991 _setjmp:entry
  1 22749 rb_scan_args:entry
  1 22987 rb_io_taint_check:entry
  1 22790 rb_check_frozen:entry
  1 23015 rb_io_check_closed:entry
  1 24902 fseeko:entry
  1 23383 __error:entry
  1 24293 flockfile:entry
  1 23481 pthread_self:entry
  1 23409 pthread_mutex_lock:entry
  1 23471 spin_lock:entry
  1 23472 _spin_unlock:entry
  1 24177 _fseeko:entry
  1 24180 _ftello:entry
  1 24155 __sflush:entry
  1 24181 _sseek:entry
  1 23383 __error:entry
  1 23383 __error:entry

these errors are disconcerting

  1 24182 __sseek:entry
  1 23895 lseek:entry
  1 23383 __error:entry
  1 23383 __error:entry
  1 23383 __error:entry
  1 24184 __srefill:entry
  1 24185 _sread:entry
  1 24186 __sread:entry
  1 23377 read:entry
  1 23368 _sysenter_trap:entry
  1 24294 funlockfile:entry
  1 23481 pthread_self:entry
  1 23410 pthread_mutex_unlock:entry
  1 23471 spin_lock:entry
  1 23472 _spin_unlock:entry
  1 23383 __error:entry
  1 24919 clearerr:entry
  1 24293 flockfile:entry
  1 23481 pthread_self:entry
  1 23409 pthread_mutex_lock:entry
  1 23471 spin_lock:entry
  1 23472 _spin_unlock:entry
  1 24294 funlockfile:entry
  1 23481 pthread_self:entry
  1 23410 pthread_mutex_unlock:entry
  1 23471 spin_lock:entry
  1 23472 _spin_unlock:entry
  1 22987 rb_io_taint_check:entry
  1 22790 rb_check_frozen:entry
  1 23015 rb_io_check_closed:entry
  1 24212 fileno:entry
  1 24293 flockfile:entry
  1 23481 pthread_self:entry
  1 23409 pthread_mutex_lock:entry
  1 23471 spin_lock:entry
  1 23472 _spin_unlock:entry
  1 24294 funlockfile:entry
  1 23481 pthread_self:entry
  1 23410 pthread_mutex_unlock:entry
  1 23471 spin_lock:entry
  1 23472 _spin_unlock:entry
  1 23887 fstat:entry
  1 23368 _sysenter_trap:entry
  1 23242 rb_time_new:entry
  1 22962 ruby_xmalloc:entry
  1 23385 malloc:entry
  1 23386 malloc_zone_malloc:entry
  1 23387 szone_malloc:entry
  1 23471 spin_lock:entry
  1 23416 tiny_malloc_from_free_list:entry
  1 23448 tiny_free_list_add_ptr:entry
  1 23472 _spin_unlock:entry
  1 22961 rb_data_object_alloc:entry
  1 22960 rb_newobj:entry
  1 22788 rb_check_type:entry
  1 22788 rb_check_type:entry
  1 22867 rb_funcall:entry
  1 22788 rb_check_type:entry
  1 22788 rb_check_type:entry
  1 22756 rb_cmpint:entry
  1 24032 time:entry
  1 28005 fegetenv:entry
  1 23952 gettimeofday:entry
  1 23953 __commpage_gettimeofday:entry
  1 28000 fesetenv:entry
  1 23244 rb_time_interval:entry
  1 22883 rb_thread_wait_for:entry
  1 23952 gettimeofday:entry
  1 23953 __commpage_gettimeofday:entry
  1 22874 rb_thread_schedule:entry
  1 22806 is_ruby_native_thread:entry
  1 23481 pthread_self:entry
  1 23868 pthread_equal:entry
  1 23356 memset:entry
  1 23356 memset:entry
  1 23356 memset:entry
  1 23952 gettimeofday:entry
  1 23953 __commpage_gettimeofday:entry
  1 24540 select$UNIX2003:entry
  1 24523 select$DARWIN_EXTSN:entry
  1 23368 _sysenter_trap:entry
  1 23367 cerror:entry
  1 23382 cthread_set_errno_self:entry
  1 23383 __error:entry
  1 23383 __error:entry

there seem to be some thread problems?

  1 23899 pthread_testcancel$UNIX2003:entry
  1 23399 _pthread_testcancel:entry
  1 23471 spin_lock:entry
  1 23472 _spin_unlock:entry
  1 23398 nanosleep$UNIX2003:entry
  1 23399 _pthread_testcancel:entry
  1 23471 spin_lock:entry
  1 23472 _spin_unlock:entry
  1 24628 clock_get_time:entry
  1 23406 mig_get_reply_port:entry
  1 23407 mach_msg:entry
  1 23327 mach_msg_trap:entry
  1 23368 _sysenter_trap:entry
  1 23400 __semwait_signal:entry
  1 23368 _sysenter_trap:entry
  1 23367 cerror:entry
  1 23382 cthread_set_errno_self:entry
  1 23383 __error:entry
  1 23383 __error:entry
  1 23899 pthread_testcancel$UNIX2003:entry
  1 23399 _pthread_testcancel:entry
  1 23471 spin_lock:entry
  1 23472 _spin_unlock:entry
  1 23398 nanosleep$UNIX2003:entry
  1 23399 _pthread_testcancel:entry
  1 23471 spin_lock:entry
  1 23472 _spin_unlock:entry
  1 24628 clock_get_time:entry
  1 23406 mig_get_reply_port:entry
  1 23407 mach_msg:entry
  1 23327 mach_msg_trap:entry
  1 23368 _sysenter_trap:entry
  1 23400 __semwait_signal:entry
  1 23368 _sysenter_trap:entry
  1 23356 memset:entry
  1 23356 memset:entry
  1 23356 memset:entry
  1 23952 gettimeofday:entry
  1 23953 __commpage_gettimeofday:entry
  1 24540 select$UNIX2003:entry
  1 24523 select$DARWIN_EXTSN:entry
  1 23368 _sysenter_trap:entry
  1 22941 ruby_stack_length:entry
  1 23392 memcpy:entry
  1 23094 rb_lastline_get:entry
  1 22804 rb_svar:entry
  1 23095 rb_lastline_set:entry
  1 22804 rb_svar:entry
  1 23092 rb_backref_get:entry
  1 22804 rb_svar:entry
  1 23093 rb_backref_set:entry
  1 22804 rb_svar:entry
  1 23991 _setjmp:entry
  1 23392 memcpy:entry
  1 23094 rb_lastline_get:entry
  1 22804 rb_svar:entry
  1 23095 rb_lastline_set:entry
  1 22804 rb_svar:entry
  1 23092 rb_backref_get:entry
  1 22804 rb_svar:entry

...
but most of the time it loops doing this:
  1 23899 pthread_testcancel$UNIX2003:entry
  1 23399 _pthread_testcancel:entry
  1 23471 spin_lock:entry
  1 23472 _spin_unlock:entry
  1 23398 nanosleep$UNIX2003:entry
  1 23399 _pthread_testcancel:entry
  1 23471 spin_lock:entry
  1 23472 _spin_unlock:entry
  1 24628 clock_get_time:entry
  1 23406 mig_get_reply_port:entry
  1 23407 mach_msg:entry
  1 23327 mach_msg_trap:entry
  1 23368 _sysenter_trap:entry
  1 23400 __semwait_signal:entry
  1 23368 _sysenter_trap:entry
  1 23367 cerror:entry
  1 23382 cthread_set_errno_self:entry
  1 23383 __error:entry
  1 23383 __error:entry
  1 23899 pthread_testcancel$UNIX2003:entry

Oh wait--the problem just resolved itself and ruby has returned to
running 3% cpu instead of 100. This is bizarre.

···

--
Posted via http://www.ruby-forum.com/.

2

You'd probably get more replies if you supply some more environmental information like the OS, Ruby version, compiler, Ruby code executed etc.

Kind regards

  robert

···

On 20.05.2008 00:25, Roger Pack wrote:

So currently ruby is hung using 100% CPU on my machine.

Some questions:
1) does anybody else have this happen to them?
2) does anybody else have a chunk of code that reliably causes ruby to
leak memory?

Anyway here are some sample stack traces, if anybody has any pointers.
Thanks!

3

Roger Pack wrote:

So currently ruby is hung using 100% CPU on my machine.

Some questions:
1) does anybody else have this happen to them?
2) does anybody else have a chunk of code that reliably causes ruby to
leak memory?

Anyway here are some sample stack traces, if anybody has any pointers.
Thanks!
-R

  1 24540 select$UNIX2003:entry
  1 24523 select$DARWIN_EXTSN:entry
  1 23368 _sysenter_trap:entry
  1 22941 ruby_stack_length:entry
  1 23392 memcpy:entry

appears that this might be something in common only to mac os 10.5 based
on this thread [1]. Apparently it returns a 'weird' error message for
forcedly closed sockets, so ruby just keeps writing to it and writing to
it [trying to] without successfully writing anything [and select fails,
etc. etc.]

At least, that's my hypothesis. Hard to know if we should come up with
a patch for ruby just to accomodate Leopard. Except that it's pretty
common :slight_smile:
-R

http://www.nabble.com/RabbitMQ-running-at-100--CPU.-td16024387.html

···

--
Posted via http://www.ruby-forum.com/\.

4

It's more than just possible to write rickety code in Ruby, it's
encouraged. If you've got a chunk that's bleeding, let us see.

···

On 20.05.2008 00:25, Roger Pack wrote:

> So currently ruby is hung using 100% CPU on my machine.

> Some questions:
> 1) does anybody else have this happen to them?
> 2) does anybody else have a chunk of code that reliably causes ruby to
> leak memory?

5

Kinda hard to even try help... looks like ancient egypts wrote something
and you try to translate it without rosetta-stone!

···

--
Posted via http://www.ruby-forum.com/.

6

Marc Heiler wrote:

Kinda hard to even try help... looks like ancient egypts wrote something
and you try to translate it without rosetta-stone!

Exactly! :slight_smile:
sorry to post without much specs.
This is OS X 5.1 and Ruby 1.8.6 patchlevel 111 running what seems to be
a 'normal' rails app and it just started sky-rocketing cpu between
requests and wouldn't answer requests for awhile.
Now that I think of it, though, I wonder if the patchlevel 11 is the
culprit. I'll upgrade and see if the problem occurs again.
Thanks!
-R

···

--
Posted via http://www.ruby-forum.com/\.