Show enters and exits. Hide enters and exits.
| 00:30:49 | burkelibbey | So as a totally random experiment, I'm rewriting a class's inheritance hierarchy to add Class#exclude(module). It works, but methods that have previously been called still have their lookup cached, apparently. |
| 00:31:05 | burkelibbey | Is there any way to clear the method lookup cache? or am I misinterpreting what's happening? |
| 00:32:50 | evan | burkelibbey: Rubinius::VM.reset_method_cache(name) |
| 00:34:09 | burkelibbey | wicked, thanks! |
| 00:34:25 | burkelibbey | off to the pub for hack night :) back in 15 |
| 00:34:31 | evan | :D |
| 00:35:33 | imajes | nice |
| 00:35:36 | imajes | ooh |
| 00:35:40 | imajes | that reminds me to call coachella |
| 00:36:01 | brixen | heh, which part, the reset method cache? |
| 00:36:20 | brixen | is your #todo method cached and stale? |
| 00:42:14 | kronos_vano | evan, Are you sure that it related defined? I think it more related undef than define? |
| 00:42:21 | kronos_vano | that's what I got: http://gist.github.com/295273 |
| 00:42:31 | evan | well |
| 00:42:37 | evan | it's defined? thats giving you the wrong answer |
| 00:42:41 | evan | so yes, it's a defined? spec. |
| 00:42:45 | kronos_vano | ok |
| 00:43:08 | evan | ug |
| 00:43:08 | evan | no |
| 00:43:13 | evan | that gist is bad |
| 00:43:13 | evan | bad |
| 00:43:20 | evan | don't reuse my other fixture |
| 00:43:26 | evan | write another one |
| 00:43:27 | brixen | kronos_vano: can you please separate whitespace change from code change also |
| 00:43:34 | evan | in the defined fixture file |
| 00:44:07 | kronos_vano | sorry sorry sorry |
| 00:44:22 | brixen | it's ok, just giving you feedback |
| 00:45:04 | evan | you shouldn't have any changes to fixtures/super.rb |
| 00:46:39 | kronos_vano | I should create fixtures/defined.rb with my example and use it. Rigth? |
| 00:46:47 | kronos_vano | *right |
| 00:49:09 | evan | yes |
| 00:50:11 | evan | I really want holochat. |
| 01:43:52 | tony | hey guys, anyone encountered problems with mysql gem when serving a rails app via rbx script/server |
| 01:45:29 | tony | here's the error if anyone is interested: http://pastie.org/810401 |
| 01:48:41 | evan | tony_: hm, ok, looks like we're missing something in capi |
| 01:48:49 | evan | tony_: would you do |
| 01:49:01 | evan | bin/rbx gem list |
| 01:49:07 | evan | and pastie the output |
| 01:49:22 | tony | evan: sure thing, thanks for help |
| 01:50:20 | tony | http://pastie.org/810406 |
| 01:50:58 | evan | ok |
| 01:54:30 | kronos_vano | rb_define_global_const call rb_define_const with rb_cObject. pretty simple to implement it in rubinius. But there is no specs for it. |
| 01:56:21 | tony | yeah, i just tried rubinius today, still too fresh, but wanna dig into it.. btw, great work evan & the crew! |
| 01:58:43 | tony | lol, btw fib is super fast, > 1.9.1 > 1.8.7. I'm loving it! |
| 02:00:54 | evan | :D |
| 02:01:07 | evan | adding rb_define_global_const is trivial |
| 02:01:09 | evan | i'll do it now. |
| 02:01:15 | evan | tony_: you using rubinius from git? |
| 02:01:29 | tony | yep |
| 02:01:33 | evan | k |
| 02:10:02 | evan | tony_: did you have any troubles getting all those gems installed? |
| 02:11:21 | boyscout | Add rb_define_global_const to C-API - 6db232e - Evan Phoenix |
| 02:11:50 | tony | evan, webrat won't install, i can pastie the errors if you want |
| 02:11:51 | evan | tony_: you'll need to run rake again after you update |
| 02:12:00 | evan | and also you'll probably need to reinstall the mysql gem |
| 02:12:07 | tony | evan, i am on it |
| 02:12:08 | evan | to force it to relink |
| 02:12:16 | evan | yeah, i'll take the errors from webrat |
| 02:15:43 | tony | evan, i have some progress on mysql, but it continues to whine: /opt/rubinius/gems/1.8/gems/mysql-2.8.1/lib/mysql_api.so: undefined symbol: rb_big2ll |
| 02:15:54 | evan | ok, missing a few more things |
| 02:16:00 | evan | thanks for working through this with me |
| 02:16:06 | evan | i don't have the mysql bindings installed here to test locally |
| 02:16:10 | evan | maybe I should do that... |
| 02:16:21 | evan | tony_: are you on OS X? |
| 02:16:24 | boyscout | CI: rubinius: 6db232e successful: 3041 files, 11843 examples, 36124 expectations, 0 failures, 0 errors |
| 02:16:24 | tony | evan, no prob at all.. i kinda hate to bug you |
| 02:16:32 | evan | tony_: nah, no problem at all. |
| 02:16:32 | tony | I'm on Ubuntu 9.10 x64 |
| 02:16:38 | evan | you're helping us flush things out. |
| 02:17:01 | tony | no prob at all, glad i can help |
| 02:17:07 | evan | hm |
| 02:17:22 | evan | i'm trying to recall how you force linux to binding all the dynamic symbols on load rather than lazily... |
| 02:17:32 | evan | that way we'll be able to see all the missing functions at once. |
| 02:18:23 | evan | ah |
| 02:18:27 | evan | run this |
| 02:18:40 | evan | LD_BIND_NOW=1 <command to run rails> |
| 02:20:43 | tony | evan, i ran it, still the same output: http://pastie.org/810441 |
| 02:21:03 | evan | mm |
| 02:21:03 | evan | ok |
| 02:23:25 | tony | webrat output greater than 100k, pastie won't take it.. anyone knows an alternative? |
| 02:23:38 | evan | gist |
| 02:23:45 | evan | i might not need tho whole thing |
| 02:23:48 | evan | is there a backtrace in there? |
| 02:23:51 | evan | probably toward the end |
| 02:24:42 | tony | webrat http://gist.github.com/295421 |
| 02:24:50 | tony | oops too late :) |
| 02:25:52 | tony | just a note, nokogiri installed with no probs |
| 02:26:24 | evan | hm |
| 02:26:25 | evan | thats weird |
| 02:26:31 | evan | does webrat contain nokogiri inside it? |
| 02:26:39 | evan | oh wait |
| 02:26:40 | evan | those are warnings |
| 02:26:41 | evan | i see. |
| 02:27:04 | evan | well |
| 02:27:09 | evan | your gist has nokogiri not installing |
| 02:27:10 | tony | yeah, line 1352 refers to nokogiri: make: *** [nokogiri.so] Error 1 |
| 02:27:32 | evan | is 1.4.1 the latest nokogiri? |
| 02:28:12 | tony | it did pull it though, as you may see in the gem list.. didn't install it explicitly it was there after webrat failure |
| 02:28:21 | tony | i'll check for nokogiri |
| 02:30:13 | kronos_vano | Yep 1.4.1 is latest (/ 2009/12/10) |
| 02:31:12 | tony | ouch, my bad.. nokogiri did not install, it fails.. mixed it up with 1.8's gem repo.. sorry about that |
| 02:31:20 | evan | tony_: np. |
| 02:31:26 | evan | nokogiri should work |
| 02:31:32 | evan | i spent some time with those guys on it... |
| 02:31:37 | tony | evan, do you want nokogiri's error output |
| 02:31:39 | evan | we'll need to ask them about it |
| 02:31:45 | tony | ok |
| 02:36:24 | boyscout | Add rb_big2ll to C-API - e8549a9 - Evan Phoenix |
| 02:36:27 | evan | ok, i went through the mysql C code |
| 02:36:30 | evan | i think we got them all |
| 02:36:34 | evan | update and give that a shot. |
| 02:37:12 | tony | k |
| 02:37:35 | evan | hm |
| 02:37:37 | evan | just did |
| 02:37:42 | evan | bin/rbx gem install nokogiri |
| 02:37:43 | evan | and it went fine |
| 02:38:13 | evan | tony_: try removing the nokogiri directory in gems/ |
| 02:38:25 | evan | and install it again, maybe there is some weird old .o files or something |
| 02:38:34 | tony | ok |
| 02:40:23 | tony | mysql: /opt/rubinius/gems/1.8/gems/mysql-2.8.1/lib/mysql_api.so: undefined symbol: rb_gc |
| 02:42:14 | evan | ack. |
| 02:42:18 | evan | we're getting there! |
| 02:42:26 | tony | :D |
| 02:42:50 | evan | why the heck is mysql forcing the GC to run |
| 02:42:57 | evan | i think i'll just stub out rb_gc() |
| 02:43:05 | evan | any use of that seems like an MRI hack. |
| 02:43:33 | evan | hm, we already have an rb_gc_start() |
| 02:44:51 | tony | hate to digress, but reinstalled nokogiri from scratch on mri no prob, still fails on rbx with xml_sax_parser.o: could not read symbols: Bad value |
| 02:45:10 | evan | hm |
| 02:45:11 | evan | thats just doing |
| 02:45:15 | evan | bin/rbx gem install nokogiri |
| 02:45:15 | evan | ? |
| 02:45:19 | tony | yep |
| 02:45:22 | evan | hm |
| 02:45:23 | evan | ok |
| 02:45:28 | evan | puzzling. |
| 02:45:31 | evan | i'll have to try on linux |
| 02:45:36 | evan | i think it's some link flags |
| 02:45:39 | tony | don't know if it makes a difference, but i installed rubinius into /opt/rubinius |
| 02:45:47 | evan | shouldn't matter. |
| 02:45:53 | tony | added it to path so i am doing rbx gem install nokogiri |
| 02:45:55 | tony | k |
| 02:46:42 | evan | ah |
| 02:46:43 | evan | sure |
| 02:46:44 | evan | thats fine. |
| 02:48:24 | evan | kronos_vano: your patch for $~ is fine, but you need a spec for rpartition |
| 02:48:28 | evan | kronos_vano: that it sets $~ |
| 02:49:06 | kronos_vano | Already working on it |
| 02:49:36 | kronos_vano | evan, I should create patch for rubyspec or rubinius? |
| 02:49:46 | evan | either is fine |
| 02:49:53 | evan | it will get sync from one to the other |
| 02:49:57 | kronos_vano | ok |
| 02:50:19 | boyscout | Stub out rb_gc() in C-API - 616c0a8 - Evan Phoenix |
| 02:50:21 | evan | tony_: round 3! |
| 02:50:27 | evan | or 4 |
| 02:50:28 | evan | anyway. |
| 02:50:30 | tony | on it |
| 02:50:30 | evan | :) |
| 02:50:33 | tony | :D |
| 02:53:13 | boyscout | CI: Commit e8549a9 failed. http://github.com/evanphx/rubinius/commit/e8549a914c70ef583a5e3fad604744bf48c9cf58 |
| 02:53:21 | tony | at the risk of sounding stupid, installing gems takes almost three times more than with mri.. so i'm still waiting for mysql to reinstall |
| 02:54:18 | tony | mysql: /opt/rubinius/gems/1.8/gems/mysql-2.8.1/lib/mysql_api.so: undefined symbol: rb_str_freeze |
| 02:54:42 | tony | oh man, you hate me by now |
| 02:56:15 | evan | nah! |
| 02:56:17 | evan | this is fun! |
| 02:56:30 | tony | :D |
| 02:56:32 | evan | we're just doing a funny run/test cycle |
| 02:56:34 | evan | ok, let me do that one. |
| 02:56:42 | evan | we're on a roll |
| 02:56:44 | tony | sure thing, thanks man! |
| 02:56:44 | evan | why stop now! |
| 02:57:28 | tony | 10pm in mich, nowhere to go :D |
| 02:57:35 | evan | :D |
| 02:57:44 | kronos_vano | evan, http://gist.github.com/295450 is it ok? |
| 02:58:16 | evan | yeah! |
| 02:58:21 | evan | though, is that affects or effects |
| 02:58:26 | evan | I can never remember. |
| 02:58:40 | kronos_vano | hm |
| 02:58:40 | tony | affects :D |
| 02:58:53 | kronos_vano | ok I'll bundle all it stuff in one patch |
| 02:58:55 | evan | thanks tony_! |
| 02:58:58 | evan | kronos_vano: cool. |
| 02:59:11 | tony | np :D |
| 03:00:23 | kronos_vano | evan, updated |
| 03:01:08 | evan | kronos_vano: do you have commit rights to rubinius? |
| 03:01:12 | evan | i thought you did |
| 03:01:14 | kronos_vano | no |
| 03:04:43 | evan | we should fix that! |
| 03:05:32 | evan | would you like it now so you can commit your last patch? or should I commit your patch and you can commit your own from now on |
| 03:05:34 | evan | ? |
| 03:07:08 | kronos_vano | np, I can do it myself. |
| 03:10:10 | evan | ok |
| 03:10:17 | evan | whats your github name? |
| 03:10:21 | kronos_vano | kronos |
| 03:10:36 | evan | k |
| 03:11:02 | evan | ok, you're added |
| 03:11:06 | evan | go ahead and commit! |
| 03:11:20 | kronos_vano | coooooooooooooooool |
| 03:11:22 | kronos_vano | YAHOOOOOO |
| 03:11:27 | evan | :) |
| 03:11:40 | tony | lol congrats kronos_vano |
| 03:11:54 | evan | kronos_vano: be good! |
| 03:12:04 | kronos_vano | evan, of cource! |
| 03:12:14 | kronos_vano | *course |
| 03:13:47 | kronos_vano | evan, What about spec? Should i change it or not in rubinius repo |
| 03:13:55 | evan | ah |
| 03:13:58 | evan | i'm glad you asked |
| 03:13:58 | evan | so |
| 03:14:07 | evan | you can commit them in rubinius only |
| 03:14:07 | evan | BUT |
| 03:14:23 | evan | you must always commit to spec/ruby standalone |
| 03:14:24 | evan | meaning |
| 03:14:33 | evan | if a commit touches spec/ruby, it must only touch spec/ruby |
| 03:14:44 | evan | don't mix implementation and spec |
| 03:14:47 | kronos_vano | Ok, I got it |
| 03:15:04 | evan | that allows brixen to sync them easily. |
| 03:15:15 | kronos_vano | so my patch is wrong. I should split it in two commits! |
| 03:15:53 | evan | yep |
| 03:16:03 | evan | i should have told you earlier |
| 03:16:04 | evan | my mistake. |
| 03:16:11 | kronos_vano | np |
| 03:21:50 | evan | tony_: almost done with freeze |
| 03:22:08 | tony | evan, ok |
| 03:27:50 | boyscout | Implement rb_obj_freeze and rb_str_freeze in C-API - 3411175 - Evan Phoenix |
| 03:27:51 | evan | tony_: round 5... |
| 03:27:52 | evan | GO! |
| 03:29:49 | tony | evan, lol, almost there |
| 03:33:22 | tony | i'm definitely a party breaker: http://pastie.org/810525 -- rbx gem install mysql fails now |
| 03:34:21 | tony | i went ahead and rm -r'd mysql gem directory so can't confirm if rbx script/server got any better |
| 03:35:07 | evan | tony_: hrm. |
| 03:35:08 | evan | one sec |
| 03:35:09 | evan | i'll fix! |
| 03:35:42 | tony | ok take your time, no worries |
| 03:35:57 | evan | oops! |
| 03:35:59 | evan | it's easy. |
| 03:38:39 | tony | yeah, rb_str_set_len and rb_thread_start_timer are missing |
| 03:38:50 | slava | evan my main man |
| 03:39:09 | evan | tony_: eh? |
| 03:39:45 | tony | evan, checking for rb_str_set_len()... no; checking for rb_thread_start_timer()... no |
| 03:40:03 | tony | came from the output of rbx gem install mysql |
| 03:40:07 | slava | evan: can fibers migrate between native threads? |
| 03:40:16 | evan | tony_: yeah, i think we can ignore that for now. |
| 03:40:19 | evan | slava: not yet |
| 03:40:23 | evan | but i know how to allow that. |
| 03:40:31 | tony | evan, ok |
| 03:40:31 | evan | i'm going to do that soon. |
| 03:42:40 | boyscout | Fix rb_str_freeze to return the object passed in - b1673f3 - Evan Phoenix |
| 03:42:58 | tony | on it |
| 03:44:36 | boyscout | CI: Commit 3411175 failed. http://github.com/evanphx/rubinius/commit/34111751b9afc0f314506a875662577a5ef23ac9 |
| 03:45:32 | evan | oh uho. |
| 03:46:38 | tony | evan, b1673f3 fixed mysql gem installation prob, new one on rbx script/server: /opt/rubinius/gems/1.8/gems/mysql-2.8.1/lib/mysql_api.so: undefined symbol: ULL2NUM |
| 03:46:43 | evan | k |
| 03:46:45 | evan | on it! |
| 03:46:54 | tony | :D |
| 03:49:30 | boyscout | Repair $~ variable - fe80773 - Ivan Samsonov |
| 03:55:26 | boyscout | Add spec for checking that rpartition affects $~ - c9765e5 - Ivan Samsonov |
| 03:56:45 | boyscout | Add ULL2NUM alias for rb_ull2inum - e06c8c8 - Evan Phoenix |
| 03:56:45 | boyscout | Improve range check for rb_big2ll - 5c513d9 - Evan Phoenix |
| 03:56:55 | evan | tony_: ok, give that a shot. |
| 03:57:56 | tony | on it |
| 04:01:30 | tony | evan, it crashes now with a Segmentation fault |
| 04:01:37 | tony | no other errors |
| 04:01:41 | evan | k |
| 04:01:49 | evan | i'm going to do this on my linux machine now |
| 04:01:55 | tony | ok |
| 04:01:57 | evan | since debugging a segfault over IRC is less than fun. |
| 04:02:11 | tony | lol, k. thanks! |
| 04:07:00 | boyscout | CI: Commit fe80773 failed. http://github.com/evanphx/rubinius/commit/fe80773ea8a0f4dc4d647eccff5758092d27d066 |
| 04:28:37 | evan | tony_: hm, i got the mysql tests to run... |
| 04:28:59 | evan | tony_: so i'll need you to run under gdb and get me a backtrace |
| 04:30:27 | tony | ok, can you tell me what to run :D |
| 04:36:33 | evan | gdb --args rbx <command to run rails> |
| 04:36:44 | evan | then run |
| 04:36:48 | evan | it should run and when it crashes |
| 04:36:49 | evan | do |
| 04:36:52 | evan | bt 100 |
| 04:36:54 | evan | to get a backtrace |
| 04:40:25 | tony | evan, ok this is what bt 100 gives me http://pastie.org/810593 |
| 04:40:48 | evan | ah! cool! |
| 04:40:51 | evan | it's not in mysql at all. |
| 04:40:57 | evan | a NEW bug! |
| 04:41:05 | tony | :D |
| 04:41:09 | evan | ok type |
| 04:41:10 | evan | frame 3 |
| 04:41:16 | evan | p call_farme->print_backtrace(state) |
| 04:41:26 | evan | your terminal should print out a ruby style backtrace |
| 04:41:29 | tony | thanks for getting me up to speed with gdb, i'm totally unfamiliar :D |
| 04:41:32 | evan | which you can paste me |
| 04:41:35 | evan | tony_: no prob. |
| 04:42:35 | tony | (gdb) p call_farme->print_backtrace(state) |
| 04:42:35 | tony | No symbol "call_farme" in current context. |
| 04:43:05 | evan | frame |
| 04:43:10 | evan | not farme |
| 04:43:10 | evan | sorry |
| 04:43:12 | evan | call_frame |
| 04:43:50 | tony | http://pastie.org/810594 |
| 04:43:58 | tony | np |
| 04:44:27 | evan | damn. |
| 04:44:29 | evan | ok |
| 04:46:30 | evan | ok, lets do this |
| 04:46:44 | evan | touch vm/builtin/regexp.cpp |
| 04:46:47 | tony | frame 3 output: #3 0x000000000055d1b2 in jit_stub_regexp_search_region (state=0x42bd6c0, call_frame=0x7fffec7a6a68, recv=<value optimized out>, |
| 04:46:47 | tony | ra0=0x7fffee3d6a58, ra1=0x10, ra2=0x7fffee3d6880, ra3=0x2) at vm/gen/primitives_glue.gen.cpp:18649 |
| 04:46:47 | tony | 18649 ret = self->match_region(state, a0, a1, a2, a3); |
| 04:46:48 | evan | rake -q build DEV=1 |
| 04:47:00 | tony | ok |
| 04:47:05 | tony | rbx rake? |
| 04:47:06 | evan | you can exit gdb |
| 04:47:23 | evan | yeah, rubinius's rake |
| 04:47:29 | evan | to recompiled part of rubinius |
| 04:47:36 | tony | alright |
| 04:47:41 | evan | then we'll run the gdb command again |
| 04:47:46 | evan | and get a new backtrace |
| 04:53:58 | tony | ok i tried it, it's the same output |
| 05:01:15 | tony | tried the whole thing again, just to make sure i didn't miss something, but i get the same output as in http://pastie.org/810594 |
| 05:01:20 | evan | the EXACT same? |
| 05:01:28 | evan | i need the backtrace |
| 05:01:32 | evan | it's probably not exactly the same |
| 05:01:32 | tony | yes |
| 05:01:35 | evan | but looks similar |
| 05:01:46 | tony | let's see, i'll repaste |
| 05:03:16 | tony | this is the whole thing: http://pastie.org/810604 |
| 05:03:56 | evan | no no no |
| 05:04:06 | evan | you've missed the most important part |
| 05:04:09 | evan | do |
| 05:04:10 | evan | frame 0 |
| 05:04:12 | evan | bt 10 |
| 05:04:17 | evan | and pastie me that output |
| 05:05:06 | tony | oops, sorry bout that, here it is: http://pastie.org/810607 |
| 05:06:07 | tony | It ends where it says More stacks follow |
| 05:06:09 | evan | and you ran the touch and the rake line before doing this? |
| 05:06:26 | evan | the touch is important |
| 05:06:29 | tony | yes, touch, rake, installed the gem again, gdb'd script/server |
| 05:06:31 | evan | as is the DEV=1 on the end of rake |
| 05:06:41 | evan | hm |
| 05:06:41 | tony | yes |
| 05:06:41 | evan | ok |
| 05:06:55 | evan | for run |
| 05:06:57 | evan | lets do this |
| 05:07:03 | tony | ok |
| 05:07:05 | evan | gdb --args bin/rbx -Xint script/server |
| 05:08:12 | tony | ok i did it, and typed run |
| 05:08:28 | tony | Program received signal SIGTRAP, Trace/breakpoint trap. |
| 05:08:28 | tony | 0x0000000000000000 in ?? () |
| 05:09:22 | evan | can you get a backtrace? |
| 05:09:27 | evan | bt 10 |
| 05:10:03 | tony | http://pastie.org/810612 |
| 05:10:25 | evan | what the fuck. |
| 05:10:26 | evan | hm. |
| 05:10:39 | evan | do |
| 05:10:40 | evan | bt 30 |
| 05:11:21 | tony | http://pastie.org/810615 |
| 05:13:07 | evan | hrm |
| 05:13:20 | evan | well, i'm not sure what to tell ya |
| 05:13:29 | evan | is the rails app your running a private one? |
| 05:13:39 | tony | i see |
| 05:13:46 | tony | it's just a test app |
| 05:13:56 | tony | i.e. empty |
| 05:14:11 | evan | how do you have it configured? |
| 05:14:16 | evan | I know sqlite3 is the default |
| 05:14:26 | tony | rails -d mysql testapp |
| 05:14:29 | evan | if you want, tar up the app |
| 05:14:34 | evan | ah ok. |
| 05:14:39 | evan | let me do some poking |
| 05:15:01 | tony | alrighty, if you're tired, we can leave for some other time |
| 05:15:20 | tony | leave it* |
| 05:20:54 | tony | evan, i gotta go, i'll try it on arch linux over the weekend to see if it's specific to my ubuntu install or something, maybe it's not worth fixing it further now that those methods were added |
| 05:21:05 | tony | thanks for help! |
| 05:21:15 | evan | hey, i should be thanking you! |
| 05:21:16 | evan | :) |
| 05:22:16 | tony | you're very welcome! keep up the good work! you inspired me to contribute once i get to know the codebase better and gdb obviously :) |
| 05:22:35 | tony | good night! |
| 06:17:55 | rue | That was a reasonably fast debug cycle. |
| 07:50:02 | dbussink | evan: ping? |
| 07:50:14 | evan | sup |
| 07:50:17 | evan | just headed to bed |
| 07:50:43 | scoopr | woo, clang is self-hosting! |
| 07:51:32 | evan | i saw! pretty awesome. |
| 07:52:00 | slava | yeah |
| 07:54:06 | evan | dbussink: yes? |
| 07:54:16 | dbussink | evan: about http://github.com/evanphx/rubinius/commit/d94820f9de66a5f236dc03198b724e3a8b1a1cc8 |
| 07:54:26 | dbussink | evan: doesn't that return a null pointer into ruby space? |
| 07:54:33 | evan | yep |
| 07:54:39 | evan | thats how we unwind exceptions |
| 07:54:47 | dbussink | ah ok, that explains |
| 07:54:51 | evan | NULL is a sentinal value |
| 07:55:01 | evan | that is checked for to see if an unwind is happening |
| 07:55:03 | slava | yo evan |
| 07:55:12 | evan | rather than depending on dwarf or setjmp/longjmp, etc. |
| 07:55:24 | evan | we use a very simple, very portable, and pretty darn fast way. |
| 07:55:29 | dbussink | evan: ah ok, makes sense then yeah |
| 07:55:57 | evan | hey! look at that |
| 07:56:06 | evan | a sample rails app using mysql |
| 07:56:12 | evan | and it's working |
| 07:56:31 | dbussink | i actually had a sqlite3 one running too |
| 07:56:33 | evan | just have to figure out why tony_'s was failing |
| 07:56:48 | evan | yeah, this is after tony_ and I sprinted on getting the mysql gem working |
| 07:56:53 | evan | it is now working |
| 07:56:53 | evan | :) |
| 07:56:59 | dbussink | cool :) |
| 11:47:00 | maharg | evan: looks like the issue with mongrel and 4000 requests is fixed. Maybe it was one of the capi changes? I don't see anything specifically addressing it. |
| 12:09:42 | dbussink | maharg: accepting a socket was using ffi previously, which isn't interruptable from ruby |
| 12:09:55 | dbussink | now it uses a primitive, which probably fixes the issue |
| 12:12:01 | dbussink | maharg: i'll close the ticket, you can file a new one if something similar comes up again then |
| 12:12:36 | dbussink | maharg: http://github.com/evanphx/rubinius/commit/b412c1b1c22a727f34cbaa651e4044de9c8af997 |
| 12:13:46 | slava | aww, evan is moving IO into the VM |
| 12:14:20 | dbussink | slava: well, the other solution is to try to fix ffi so it's interruptable |
| 12:14:37 | slava | what do you mean yb being interruptible? |
| 12:14:43 | dbussink | slava: he probably has some clever trick for it, but this was easier i think |
| 12:15:12 | dbussink | slava: well, problem was that for example raising an exception in a thread should interrupt a socket#accept |
| 12:15:25 | dbussink | but that wasn't happening, since it was just waiting in the ffi call |
| 12:28:14 | slava | so thread A can interrupt thread B's call to accept? |
| 12:28:52 | slava | is accept called on a non-blocking fd? |
| 12:45:50 | dbussink | slava: well, looks like evan solved it now by releasing the gil, which was probably the biggest issue then |
| 16:55:10 | evan | slava: the fd was blocking |
| 17:01:45 | rue | Blocking IO should have a theme song |
| 17:30:39 | evan | rue: maybe we could redo the charlie's angels theme song for blocking io |
| 21:40:31 | maharg | evan, dbussink: ah, this one? http://github.com/evanphx/rubinius/commit/b412c1b1c22a727f34cbaa651e4044de9c8af997 |
| 21:40:42 | evan | maharg: yep. |
| 21:43:06 | maharg | it's pretty cool to see the JITer work its magic as you ab thousands of requests at a mongrel server |
| 21:44:25 | evan | yeah! |
| 21:44:40 | evan | all the request handling should heat right up |
| 21:44:47 | evan | maharg: hows it performing? |
| 21:45:43 | maharg | with the framework code I'm working on, it seems to peak at around half the requests per second as MRI |
| 21:46:40 | evan | ok |
| 21:46:52 | evan | I suspect a lot of that is that we haven't done much optimizing of IO |
| 21:47:02 | maharg | yeah, I expect that's the case |
| 21:47:22 | maharg | given what the other, more computationally focused, benchmarks show |
| 21:47:43 | evan | yeah |
| 21:48:05 | evan | maharg: if you get a chance |
| 21:48:07 | evan | do a run with |
| 21:48:11 | evan | -Xint -P |
| 21:48:26 | evan | so we can get some profiling info out of it. |
| 21:48:38 | evan | -Xint because I still haven't fixed the JIT profiler |
| 21:49:56 | brixen | maharg: would be interesting to know the diff between runs with -Xint and without |
| 21:50:05 | evan | yeah |
| 21:50:06 | brixen | ie, how much the jit is helping |
| 21:53:38 | maharg | that a build option or an rbx flag? |
| 21:54:40 | evan | no |
| 21:54:43 | evan | bin/rbx -Xint ... |
| 21:59:33 | maharg | huh |
| 21:59:36 | maharg | -P is pretty sweet |
| 22:00:17 | maharg | so, MRI gets about 800rps, rbx no flags gets about 400, rbx -Xint -P gets about 91 |
| 22:00:26 | brixen | wowsers |
| 22:00:31 | brixen | goooo jit |
| 22:00:50 | evan | maharg: oh |
| 22:00:52 | evan | try -Xint |
| 22:00:53 | evan | no -P |
| 22:00:55 | brixen | maharg: what about -Xint |
| 22:00:57 | brixen | heh, yeah |
| 22:00:58 | evan | the -P adds a lot. |
| 22:01:12 | brixen | well, -P shouldn't add terribly much |
| 22:01:22 | brixen | at least it didn't used to |
| 22:01:29 | maharg | without -P it gets about 250 |
| 22:01:34 | evan | ok |
| 22:01:38 | brixen | hm, more than I thought |
| 22:01:40 | evan | still, JIT is making a nice dent. |
| 22:01:46 | brixen | yeah |
| 22:02:01 | evan | brixen: he's hammering it, so building the profiler tree takes time |
| 22:02:09 | brixen | ahh ok, sure |
| 22:02:18 | brixen | maharg: can you gist the -P output? |
| 22:02:21 | maharg | http://gist.github.com/296316 |
| 22:02:25 | maharg | was already on it |
| 22:02:27 | brixen | heh |
| 22:02:49 | brixen | wow, #fill |
| 22:03:03 | evan | exactly. |
| 22:03:24 | evan | it's IO. |
| 22:04:04 | maharg | yeah that's pretty brutal, 45 calls dominating 81% of execution time. |
| 22:04:13 | evan | something about that feels off. |
| 22:04:27 | evan | because you did how many requests? |
| 22:04:29 | maharg | god, textpad's search is so painful |
| 22:04:38 | maharg | that would have been somewhere around 5-10k |
| 22:04:43 | maharg | it does seem very off |
| 22:04:52 | evan | i'd expect at least that many fills then. |
| 22:05:15 | evan | would you mind making your mechanism for benchmarking this available? |
| 22:05:21 | evan | i'd love to play around with it |
| 22:05:56 | brixen | man, 58 F and sunny here |
| 22:06:06 | brixen | did I fall asleep and wake up in june? |
| 22:06:37 | evan | the rain just moved down to here |
| 22:06:46 | brixen | bummer heh |
| 22:08:18 | evan | nah |
| 22:08:22 | evan | we need all the rain we can get. |
| 22:08:26 | evan | the more the better. |
| 22:09:35 | maharg | it's just the server being hammered with apache bench (ab). Can't release the code for the server just yet, though. |
| 22:10:28 | evan | maharg: np. |
| 22:10:40 | evan | it's mongrel serving up some site then? |
| 22:10:49 | evan | I can do a generic mongrel benchmark |
| 22:11:09 | evan | since we think it's IO, thats probably good no matter what. |
| 22:12:15 | maharg | yeah, it's working two things: my framework's path dispatching and IO, and I think it does pretty well on the dispatching. I could actually whip up a benchmark to test that theory, but it seems pretty obvious to me |
| 22:15:32 | evan | ok |
| 22:49:31 | evan | every usage of rb_gc_start in an extension should come with a wrist slap |
| 22:51:39 | brixen | mongrel use that? |
| 22:51:52 | evan | no, but it's a few places |
| 22:52:00 | evan | and the mysql extension runs rb_gc() IN A LOOP |
| 22:52:04 | evan | ON EVERY ROW |
| 22:52:07 | brixen | omg |
| 22:52:08 | brixen | wow |
| 22:52:10 | evan | yeah. |
| 22:52:13 | evan | exactly. |
| 22:52:22 | brixen | man |
| 22:52:29 | brixen | how do you even describe that? |
| 22:52:40 | brixen | what were they thinking doesn't really cut it |
| 22:52:41 | brixen | heh |
| 22:52:41 | evan | oh, i'm wrong |
| 22:52:45 | evan | it's for every result |
| 22:52:50 | evan | but it's not a loop |
| 22:52:50 | brixen | ok |
| 22:52:55 | evan | and there is their own guard for some reason |
| 22:53:01 | evan | they run the GC every X results |
| 22:53:04 | evan | X is ... |
| 22:53:12 | evan | UG |
| 22:53:13 | evan | 20 |
| 22:53:27 | evan | every 20 queries it runs the GC. |
| 22:53:33 | evan | so it's not per row of the result |
| 22:53:34 | evan | but still! |
| 22:53:37 | brixen | yeah |
| 22:53:48 | evan | thats ridiculous |
| 22:54:00 | evan | thats why I made our rb_gc() just an empty function. |
| 22:54:23 | maharg | I think it's because it was rather spammy with the ruby objects which degraded performance a lot and the maintainer changed and that was the 'easiest' solution. Ie. it was creating so many objects that performance was better when it was running the GC all the time |
| 22:54:28 | brixen | does the jit turn it into nothing? |
| 22:54:54 | evan | brixen: the JIT doesn't run on the C extensions... |
| 22:54:57 | brixen | yeah, I wondered if it was an MRI perf hack |
| 22:55:09 | brixen | evan: ah of course |
| 22:55:20 | evan | but anyway |
| 22:55:23 | maharg | I seem to recall seeing discussion about it as it was happening, and it really did perform very badly |
| 22:55:24 | evan | yes, an MRI hack entirely. |
| 22:56:02 | brixen | evan: if we got clang working for compiling ext code, seems we could see that :) |
| 22:56:31 | evan | dude |
| 22:56:34 | evan | i've thought about it |
| 22:56:43 | maharg | http://railsexpress.de/blog/articles/2006/10/05/make-ruby-mysql-create-less-garbage/ |
| 22:56:44 | brixen | you saw the clang announce? |
| 22:56:44 | evan | i think that post 1.0 |
| 22:56:46 | evan | i'll do that. |
| 22:56:47 | evan | yeah |
| 22:56:50 | brixen | cool |
| 22:56:51 | evan | post 1.0 |
| 22:56:57 | evan | i wanna have clang embedded in |
| 22:57:02 | evan | and be able to JIT C extensions |
| 22:57:04 | evan | so you can do |
| 22:57:08 | evan | require "mysql.c" |
| 22:57:20 | brixen | pure evil |
| 22:57:29 | scoopr | "rubyinline" |
| 22:57:38 | evan | I can also then clean up the extension code! |
| 22:57:43 | evan | to make handles cheaper |
| 22:57:55 | evan | by transforming clang's trees |
| 22:58:21 | brixen | only create handles if the pointer escapes? |
| 22:58:27 | evan | right |
| 22:58:32 | brixen | awesome |
| 22:58:49 | evan | and fixup an object pointers on the C stack |
| 22:59:00 | brixen | ah yes |
| 22:59:05 | evan | so they're accessed via a GC viewable structure |
| 23:20:11 | maharg | so running just the request processing, it actually still shows pretty similar characteristics without network IO (though it's still filling a StringIO object for every req). 3132r/s with MRI, 5462r/s rubinius if I give it 20k requests to warm up (fairly linear improvements up to that point using more requests for warmup, starting at about 1256r/s with 1k warmup requests), and 1165r/s with no -Xint |
| 23:20:33 | maharg | er wait |
| 23:20:48 | maharg | rbx with 20k should be 1830r/s |
| 23:21:03 | maharg | 20k warmup and jit running |
| 23:21:10 | maharg | 5462 was total running time |
| 23:21:38 | evan | er |
| 23:21:40 | evan | now i'm confused |
| 23:21:47 | evan | say the numbers again in full :) |
| 23:21:55 | maharg | 3132req/s MRI |
| 23:22:17 | maharg | 1830req/s rbx with 20k requests warmup before actually benchmarking |
| 23:22:29 | maharg | 1165req/s rbx -Xint |
| 23:23:02 | evan | what was the 5462? |
| 23:23:20 | maharg | total ms for the run after warmup |
| 23:23:36 | maharg | there are a lot of numbers on my screen right now heh |
| 23:23:48 | evan | :D |
| 23:23:48 | evan | ok |
| 23:26:23 | evan | so still about 50% |
| 23:26:53 | maharg | This is the -P for this benchmark: http://gist.github.com/296381 |
| 23:27:11 | evan | you ran -P with -Xint |
| 23:27:13 | evan | right? |
| 23:27:21 | maharg | yep |
| 23:27:23 | evan | k |
| 23:27:53 | maharg | the === are probably from hash lookups, there's a fair amount of that in the dispatching |
| 23:27:54 | evan | a LOT of Dir.glob stuff |
| 23:28:06 | evan | are you doing a lot of Dir[] ? |
| 23:28:06 | maharg | yeah that's all well before the benchmark though |
| 23:28:12 | evan | well |
| 23:28:15 | evan | it shouldn't show up then :) |
| 23:28:29 | evan | hm. |
| 23:28:31 | maharg | heh, it's still in the same process and run of the script |
| 23:28:44 | maharg | can I turn on the profiler only for a segment of code? |
| 23:28:52 | brixen | yeah, you can |
| 23:29:08 | brixen | peek in kernel/delta/profiler.rb |
| 23:29:27 | brixen | pr = Rubinius::Profiler::Instrumenter.new |
| 23:29:33 | brixen | pr.profile { # do some work here } |
| 23:30:58 | evan | HI BEN |
| 23:32:02 | boyscout | Remove errant NULL check - 588c6a3 - Evan Phoenix |
| 23:32:03 | boyscout | Refactor code out of rubinius::VM - 9b196bb - Evan Phoenix |
| 23:32:03 | boyscout | Remove Globals& from VM - d6416f8 - Evan Phoenix |
| 23:32:03 | boyscout | Remove VM::mailbox_ - 92db01f - Evan Phoenix |
| 23:32:06 | benschwarz | HI EVAN |
| 23:32:09 | evan | that was a nice friday refactoring |
| 23:32:28 | benschwarz | You good evan? |
| 23:32:51 | evan | yeah, good, good. |
| 23:32:54 | evan | you? |
| 23:33:26 | benschwarz | I'm good. Waiting to go for eggs after sharing a lot of sake with mr egan |
| 23:33:44 | evan | a sake saturday? |
| 23:33:57 | benschwarz | Friday night, saturday morning now |
| 23:34:31 | maharg | http://gist.github.com/296389 |
| 23:35:05 | evan | wtf |
| 23:35:14 | evan | why is there 140k calls to Rubinius::VM.reset_method_cache |
| 23:35:26 | evan | are you redefining a method on every request? |
| 23:35:50 | maharg | shouldn't be, no |
| 23:36:05 | evan | so, run with |
| 23:36:10 | evan | -Xint -Xprofiler.graph -P |
| 23:36:19 | evan | you'll get a call graph profile output |
| 23:36:25 | evan | find reset_method_cache in the output |
| 23:36:38 | evan | and paste the entry for it |
| 23:36:46 | evan | it should show the callers |
| 23:41:01 | boyscout | CI: rubinius: 92db01f successful: 3041 files, 11848 examples, 36134 expectations, 0 failures, 0 errors |
| 23:46:37 | rue | The question is whether rb_gc() was used...but whether it worked :D |
| 23:47:43 | evan | the question is NOT whether, you mean? |
| 23:48:04 | rue | To whether, or not to whether! :/ |
| 23:48:06 | rue | Yes |
| 23:51:43 | maharg | ah I see what it is |
| 23:52:03 | maharg | I'm doing an extend on the IO object I'm outputing to |
| 23:52:39 | evan | ah. |
| 23:52:42 | evan | thats bad news. |
| 23:53:12 | evan | thats got ugly cache implications |
| 23:54:24 | rue | Heh, xxx |
| 23:54:40 | rue | maharg: Not #includeable? |
| 23:55:10 | maharg | it probably makes more sense for it to encapsulate rather than extend anyways |
| 23:55:16 | evan | we can make it faster anyway, but yeah, extending an object per request blows up the cache a lot. |
| 23:56:07 | maharg | this is some code that goes back to my very earliest days with ruby like 4 years ago |
| 23:57:17 | evan | :) |
| 23:58:54 | rue | maharg: Used to be cleverer? :) |