00:00:52 we're getting pizza ;-) 00:16:31 new emc2, emc2-dev, axis (1.2a2) packages in the breezy repository 01:01:00 ok - back 01:25:50 well, on my laptop with BDI 4.2x (kernel 2.6.9-adeos), I can run BDI at 24 uS PERIOD, and there's no slowdown in the GUI. 01:26:31 Running EMC2 with stepgen at BASE_PERIOD=50 uS, the machine is basically unusable, though it doesn't quite crash 01:27:17 I can see individual lines of text in konsole being drawn in parts, desktop icon lables are drawn as the shadow first then the text, etc. 01:27:42 the CPU is a PIII 1 GHz, 512M RAM 01:27:58 video is a Rage mobility. I'm not sure if it's shared memory or not 01:33:17 looking at the tmax times (which are reported on this BDI, luckily): 01:33:30 parport.0.read.tmax = 16762 01:33:40 parport.0.write.tmax = 19276 01:34:04 stepgen.make-pulses.tmax = 15086 01:34:25 and that's over 50 uS total, so there's at least one problem 01:34:36 those parport numbers look exceedingly high to me 01:39:50 I'll be around if you have any questions. doing misc chores though, so I may not respond immediately 01:46:54 ok, now this is just wacky. after a while running (but not actually executing any programs or anything), parport.0.write.tmax is now 7028277 (!) 01:48:26 either this kernel isn't providing correct times, something is really screwed up on this computer (possible, it's a laptop), or there are gremlins in the parport code 02:03:10 wow 02:04:50 running stepper-inch here tends to bog things down a bit too 02:06:13 I changed hal_parport.c so that parport.write is a null function (only sets port=arg, does no outb), and tmax is still 14248 02:06:42 this time, the nasty function is motion-command-handler.tmax, at 6996430 02:07:09 that implies that something is interrupting the RT code that takes about 7mS 02:07:24 again, this is a laptop, so some weird things may be going on, but the BDI kernel doesn't have apm / acpi support, AFAIK 02:07:26 yes it does 02:10:26 I'm getting 17uS for parport read, 20 for write 02:10:32 (tmax) 02:10:43 13uS for makepulses 02:10:48 that's what I get, for the most part 02:10:55 a couple microseconds more, maybe 02:11:05 but that's a long time for two outb instructions 02:11:10 steve_stallings has quit 02:13:06 scoping the .timee params to see typicals 02:14:12 between 7.5 and 8uS most of the time 02:14:36 ok - there's definitely something wrong with the laptop. now several of the tmax params are 7-ish ms 02:14:54 something in the background 02:15:23 yeah, but what can be "background" ro RT tasks? 02:15:26 to 02:15:34 an interrupt 02:15:49 one that adeos/rtai isn't catching somehow 02:15:50 or shared video, on that machine (possibly) 02:16:01 not for 7ms 02:16:10 nope 02:18:10 my best estimate of "typical" base thread execution is 40uS when the scope is sampleing in that thread 02:18:33 my laptop would crap out (missed realtime deadlines) whenever the processor fan turned on or off 02:18:44 no bios settings or kernel settings would fix it 02:19:01 I still say laptops are useless for emc, even though some people seem to be able to use them 02:19:28 some laptops are useless 02:19:38 with no reliable way of knowing which ones 02:19:40 it's an interesting data point though, that the BDI emc works perfectly at 24 uS, and emc2 doesn't work at 50 uS 02:19:51 on the same machine, same kernel, same boot 02:19:54 well, hal does add some overhead 02:20:10 we've long known that emc2 can't run as tight as emc1 02:20:14 yes, but I hope it isn't that much 02:20:16 I didn't know it was a factor of 2 though 02:20:16 it seems worse lately 02:20:29 I think it is worse lately, I just can't pinpoint when it started 02:21:16 it's not an ADEOS / kernel version thing, because I'm seeing this on an older BDI (middle of last year) 02:21:53 if we weren't in kernel space, we could profile 02:22:06 I wonder if we could come up with something that would give a similar kind of information 02:22:14 tmax ;) 02:22:16 and if the profiling code didn't add time 02:22:24 tmax and time 02:22:28 you can measure how much time it adds 02:23:24 jeez, 51uS for ddt !?! 02:23:51 hmmm - on my "normal" emc machine, I'm now getting an error that librs274.so cannot be opened (with axis, after full make, and axis install) 02:24:13 rip or install? 02:24:24 methinks something in RTAI / RTAPI has changed, and task switching is slightly fubar'ed 02:24:27 RIP 02:24:50 I'm gonna take a look at just running stepgen alone 02:24:57 parport alone, etc 02:26:27 I'm recompiling, just to be sure that I did all the right stuff (--enable-run-in-place ... ) 02:26:39 SWPadnos: in your axis directory, sudo rm -r build, then env EMCROOT=.... python setup.py build, look for this line: 02:26:42 g++ -pthread -shared build/temp.linux-i686-2.4/extensions/gcodemodule.o -L/usr/src/emc2/lib -lrs274 -lnml -lm -lstdc++ -o build/lib.linux-i686-2.4/gcode.so -Wl,-rpath,/usr/src/emc2/lib 02:27:00 the -rpath should be your emc2's lib directory 02:27:07 ok - in a couple of minutes, once the emc2 build finishes 02:29:23 5uS typical for sum2 02:29:32 all it does is add a couple floats 02:29:45 I have a hunch 02:29:50 in my config I have 9 ddt 02:29:54 3 for each axis 02:30:09 but they're in the 1mS thread, so not so noticable 02:30:09 or is it 2? 02:30:15 ah 02:34:36 yes, the rpath looks correct 02:34:57 ldd /usr/lib/python2.4/site-packages/gcode.so 02:35:03 python2.3? 02:35:06 wherever it is 02:35:08 argh 02:35:09 where do the kernel headers live? 02:35:29 ok, the configure option is "--enable-run-in-place", right? 02:35:34 yes 02:35:34 yes 02:35:55 the final messages from configure will reflect that if it was recognized 02:35:57 jmkasunich: are you asking me? 02:36:04 asking anyone who knows 02:36:14 well, now I get an error with the emc script: /usr/local/share/emc/tcl/bin/pickconfig.tcl: No such file or directory 02:36:18 /usr/src/linux-headers-[version] 02:36:30 thanks 02:36:40 SWPadnos: look in Makefile.inc and check RUN_IN_PLACE 02:36:47 I bet you didn't get it set 02:37:15 true enough 02:37:26 type caarrreeeffullllly 02:37:40 aaarrrrgggghhhh!!! 02:37:47 run-in=place 02:37:55 bastards 02:38:09 whoever put two keys next to each other should be shot 02:39:26 ok, now I'm back to this error: 02:39:38 /Project/emc2/bin/milltask: error while loading shared libraries: librs274.so: cannot open sharedobject file: No such file or directory 02:39:56 are you sure your cvs is updated? 02:40:03 a devel checkout, not anon? 02:40:10 absolutely devel 02:40:17 I'm sure I fixed this 02:40:21 this was running before, I'm not sure why I recompiled 02:40:41 in Makefile.inc what is LIB_DIR? 02:41:05 well, it's not up to dat, Entries shows 1.52, and the last commit brought it to 1.55 02:41:18 aha 02:41:20 (Makefile) 02:41:44 maybe I should try better to remember which machine I actually did the cvs up on ;) 02:42:30 as jmk says, EBKAC 02:42:33 haha 02:42:44 heh - I see a Problem with that :) 02:42:54 or, no problem, I guess 02:43:44 cradek, do you know what made your kernel provide timing information to RTAI? 02:43:57 the older BDI does, I think BDI 4.30 doesn't 02:44:19 SWPadnos: no, but any interested party could surely wade through the kernel configs 02:45:15 surely they could 02:45:25 fscking RTAI crap shit trash 02:45:40 looks like jmk found the problem 02:45:47 heh 02:45:54 the calls to rtapi_get_time (which translate into calls to RTAI) are taking far longer than the actual code 02:46:13 whee. 02:46:38 and the recent change is because until cradek started asking about overrun detection, I knew they didn't work well anyway, so I had them commented out 02:46:44 heh 02:46:53 oh so it's my fault 02:46:55 rdtsc is a serializing instruction, I think 02:47:01 that may be part of the problem 02:47:06 its not rdtsc at all 02:47:10 good 02:47:14 its what rtai does before/after that 02:47:28 I replaced the calls to rtai with calls to the rdtsc macro itself 02:47:35 multiply / divide (several times)? 02:47:39 (so the results are in clocks, not ns) 02:47:49 numbers less than 1000 for sum2 02:48:22 then I kept the rdtsc for the calulations, but uncommented the calls to RTAI, and the numbers became 9000+ 02:48:36 ouch 02:48:39 damn 02:48:41 so we're taking a 5-7uS hit at everh HAL function 02:48:42 in cycles, or ns? 02:48:49 9000 is cycles 02:48:55 about 6-7uS 02:49:26 well - I guess we now know. good job 02:49:32 yeah nice find 02:50:10 rtapi_get_time calls rt_get_cpu_time_ns() 02:50:26 which apparently is a horrible pig 02:51:03 so timing is going away again 02:51:04 as I recall, all that did was call the kernel get_time_ns, which was rdtsc + scaling 02:51:12 or get_cpu_time_ns 02:51:18 it didn't look that bad 02:51:26 that blows my mind - why would the authors of a REALTIME OS make the function you call to measure time so fscking slow 02:51:46 well, somewhere in there is something ugly 02:53:12 I'm sorely tempted to change rtapi_get_time to return time in clocks, use rdtsc, and say fsck it 02:53:20 yep - just do that. 02:53:33 I'm afraid of portability issues tho 02:53:35 we can find a way around my dual-core issue when the time comes 02:54:05 apparently, it's there on all Pentium chips, and possibly the 486 as well 02:54:14 on that issue: I seem to recall designing RTAPI so that on a SMP box it runs all RT tasks on the same CPU 02:54:23 dunno how that works on dual core 02:54:37 I think dual core == SMP 02:54:53 it may work, in which case the RT tasks would always read the same TSC 02:54:55 its not on 486 I don't think, but I'm not worried about those, they're old even by my standards 02:54:59 what about AMD, etc>? 02:55:10 (although it seems to work fine here) 02:55:12 amd has it 02:55:30 the problem is that the TSCs on dual-cores aren't synced on the Athlon X2 or the Opteron 02:55:42 I think instead of changing rtapi_get_time, I'll add rtapi_get_clocks to the API 02:56:08 I wouldn't bother with that. The whole reason for get_clocks would be to get the time 02:56:28 just to make it clear to the caller that he isn't getting ns 02:57:14 I think I was the main opponent to using rdtsc, but I think the potential problems (in a couple of years) aren't anywhere near as important as the performance gain today 02:57:30 make it ns though (not sure exactly how to do that) 02:57:49 can't do that 02:58:01 even a divide is faster than rt_get_... 02:58:07 at least not for version 2.0 02:58:19 the problem is getting the cal factor 02:58:19 can't do what? 02:58:35 right -cat /proc/cpuinfo | grep MHz 02:58:42 what is the system clock? it ain't easy tpo find out in a portable way 02:59:31 'cat /proc/cpuinfo | grep MHz' should be pretty portable across all Linux systems 02:59:38 how do you get it from /proc into the rtapi kernel module 02:59:44 one sec 02:59:52 (especially if its a deb, you can't compile it in) 03:00:06 yeah I had that idea for about 5 seconds 03:00:31 does it need to be compiled in? 03:00:43 you can dereference something pretty quickly 03:00:54 it needs to be available to the internals of rtapi.ko 03:01:08 hmm, I guess you could pass it as an insmod parameter 03:01:16 one more thing for the realtime script to do ;-) 03:01:19 heh 03:01:55 it's probably somewhere in the kernel already - else they wouldn't be able to do get_cpu_time_ns 03:02:13 you don't want to go there 03:02:23 I was reading, and my head almost exploded 03:02:30 heh 03:02:42 I bet you can get it from sysctl(2) 03:02:43 CPUs that slow the clock during the idle task, CPUs that stop the clock during the idle task 03:02:58 kernel code that resyncs the TSC every time the idle task exits 03:02:59 yes - those are a problem 03:03:09 truly sick shit for someone used to embedded 03:06:08 well - the kernel has do_gettimeofday 03:06:18 returns a timeval 03:07:00 look at rtai_rtapi.c line 529 03:07:18 I used do_gettimeofday, it caused problems on some systems, alex commented it out 03:07:34 hmmm 03:08:08 http://lxr.linux.no/ident?i=do_gettimeofday 03:08:41 it's in this file (for 1.6.11) http://lxr.linux.no/source/kernel/time.c 03:08:45 2.6.11 03:09:05 alex didn't say what kind of problems 03:09:19 maybe it's not suitable to call from a RT task 03:09:39 could be, or it's just not there sometimes 03:09:41 yeah that's a lousy comment 03:10:13 looking at time.c, it seems that the function isn't defined if CONFIG_TIME_INTERPOLATION isn't true 03:11:45 when speaking of RTAI, what is "immediate mode"? 03:12:33 whoops. bedtime. 03:12:44 see you guys later (like Thursday) 03:12:58 ok goodnight 03:13:36 http://lxr.linux.no/source/arch/i386/kernel/time.c#L95 03:14:25 SWPadnos: see you 03:14:30 see you 03:14:38 SWPadnos is now known as SWP_Away 03:35:28 ahhhhhhh, thats better 03:35:46 running stepper-inch, the system is FAR more responsive now 03:35:54 cool 03:37:11 parport read is about 2500 clocks, write is about 5200, stepgen-makepulses is about 400 03:38:35 I think over 80% of the time in the RT threads was being spend in that damned time measuring function 03:39:44 I'm glad you found it 03:39:49 me too 03:40:03 emc2 was starting to get a bad reputation 03:40:48 now... do I announce to folks that HEAD has a fairly important fix in it, or do we need to do some further checking of the build system before we cause a stampede to CVS? 03:41:23 wait a bit, jepler's looking for a problem that's maybe in pickconfig 03:41:51 I'm gonna commit my changes, the commit message won't cause a rush 03:41:57 ok 03:42:19 but answering the folks who say "why do I need to set BASE_PERIOD to 200uS", that will cause a rush 03:42:54 yeah... 03:49:06 hmm - I actually thought about the bug you just fixed, but it was in the middle of something else and I forgot about it 03:49:47 now I just have to hope that rdtsc is implemented on all the compile farm slots 03:52:09 ? 03:52:15 what bug I just fixed? 03:52:45 oh, it was jepler 03:52:53 duplicate dirs in configs-path 03:53:09 ah 03:54:25 I think rdtsc exists on true pentiums, and anything newer from intel. It at least exists on K6es and newer from AMD. Not sure about oddballs. 03:55:19 wonder if I should make new packages now 03:55:33 dunno 03:55:47 I'd let the compile farm run thru its paces first 03:55:52 * jmkasunich goes to start it 03:56:36 chris@buster2:/usr/src/emc2$ scripts/emc 03:56:36 sed: -e expression #1, char 0: no previous regular expression 03:56:36 Machine configuration directory is '' 03:56:36 Machine configuration file is '' 03:57:49 did you hit cancel or OK? 03:58:05 neither, this is before that 03:58:08 I see the problem 03:59:08 jepler's change has an unintended consequence when emc is run with no args 03:59:13 cradek: oops! 03:59:50 you want me to fix it 03:59:50 ? 03:59:58 I'm already typing commit 04:00:12 done 04:00:32 thanks 04:00:59 interesting time behavior here... parport write is very consistent at about 5200 clocks, but a couple times a second it jumps to 12000 clocks or more 04:02:39 jmkasunich: does it sometimes do more than one outb? 04:02:51 it always does the same number 04:02:55 which is 2 04:03:04 one to the data port, one to the control port 04:03:15 HAL provides all the outputs, even if they aren't in use 04:03:35 emc1 would skip the outbs if those outputs had not changed 04:03:37 I can get flurries of the long ones when I move the mouse 04:03:47 huh 04:04:52 one reason for things to get long during other activity is cache 04:05:09 if the only thing running is RT code, it remains in cache from one thread execution to the next 04:05:11 jepler: can you make doubleclick work while you're in there? 04:05:23 if lots of user space stuff is going on, cache gets overrwitten 04:06:47 that probably accounts for the small scale jitter 04:06:59 there is a hard floor at about 5100 clocks 04:07:31 then a distribution of runs that vary from 5100 to about 5300 (most under 5125) 04:09:20 then nothing between 5400 and 12000 04:09:42 12000 to 15000 happen maybe 1% of the time 04:09:51 when very active 04:11:45 drat 04:11:56 jepler used [ file normalize ] 04:12:09 that isn't available on older tcl (pre 8.4) 04:12:12 oops 04:12:42 dunno if thats a factor or not for emc 04:13:13 do you have any idea what tcl versions are on what bdis? 04:13:20 obviously it's ok for ubuntu 04:13:28 I'm trying to figure out what I have here 04:13:40 tclsh --version and similar doesn't work 04:14:05 chris@buster2:~$ tclsh 04:14:05 % info tclversion 04:14:05 8.4 04:14:27 same here 04:14:31 I'll check the farm 04:16:01 BDI-2.x has 8.0, BDI-TNG has 8.3, BDI-Live has 8.4 04:16:18 so it's fine right now? 04:16:23 yeah 04:16:37 -2.x and -TNG are on the chopping block IMHO 04:17:37 and it's looking worse and worse for them as work continues 04:20:21 quite a weekend 04:20:41 45 commits "yesterday" (CIA is on UTC I think) 04:20:54 122 so far this month 04:22:07 wow 04:23:03 http://cia.navi.cx/stats/project/emc 04:23:25 we've averaged a commit every 7.5 hours for almost a year and a half 04:23:44 new emc2, emc2-dev, emc2-axis packages in the breezy repository (again) 04:23:50 cool 04:24:13 hope I got everything in there 04:24:41 compile farm is happy (two slots anyway), so my rtapi change didn't bust anything 04:24:49 its a shame we can't actually test on the far 04:24:52 great 04:24:57 I can't see any way to automate it tho 04:25:19 you could insert and remove a module, but that's a lousy test. 04:25:46 the only real test would be to start emc and run 3dchips or something 04:25:52 yeah. 04:26:01 probably can't do that automated. 04:26:08 and even that only tests a fraction of the system - only one gui, only one config 04:26:30 as far as you can tell, the current HEAD will compile and run both in place and installed? 04:26:37 yes 04:27:04 we need to make a tarball while it is pseudo-stable, before the next wild session like these last few days 04:27:22 and we need to communicate some changes, like --enable-run-in-place 04:27:25 maybe it's better to make tags 04:27:41 the timing bug is significant enough that I want to announce the fix 04:27:41 there's nowhere to put a tarball where people will look for it. 04:27:54 alex was/is hosting daily tarballs 04:28:04 but you're right, gotta point people to them 04:28:10 yeah, but I don't think anyone is using them unless cvs breaks 04:28:38 tags can be moved, right? 04:28:43 sure 04:28:55 so we could have a tag TESTING, that always points to the latest reasonable stable thing 04:29:07 yes I think we could 04:29:17 and a wiki page that tells testers both how to get it and compile it, and what to expect 04:29:45 IMO that's what my debs are for 04:29:45 "foo is known not to work, but bar and baz should, if they don't please report it" 04:30:04 I make a new one when I think something important has changed, and everything's in a sane state 04:47:24 steves_logging has joined #emc-devel 05:47:48 jmkasunich has quit 08:23:47 cradek: just fyi, make tgz is not working at the moment, we might want to add that back 08:24:23 HiAlex... latest debs are not working either 08:24:51 LawrenceG: yes they are, since last night 08:25:07 logo var is missing from pickconfig.tcl 08:25:16 and my config dirs are empty 08:25:54 /etc/emc2/sample-configs/stepper has NO files 08:27:01 if fixed logo var by adding >>set logo ""<< at line 36 of pickconfig.tcl 08:28:02 I seem to be missing emc2-wizard.gif as well which shoed up the logo error 08:28:29 showed 08:29:29 Those files must not be in the debs.... I removed and installed emc2 several times even a fresh deb download 08:30:30 I was hoping to test the timing fixes on this old 200mhz unit 08:45:34 I can see the files in the deb, the config dirs get created, but the ini files are not being placed into the directories 08:46:50 To test, uninstall emc2 and rm -rf /etc/emc2, then reinstall deb 08:57:17 where did you get the debs from? 08:57:35 cradek: In case you didnt catch above.... latest emc2 debs contain but do not install any sample configs... /etc/emc2 has sample dirs, but no contents... a du /etc/emc2 shows only 52 blocks 08:57:53 from the .ro repository 08:58:06 dunno, not sure, probably not fully done yet 08:58:13 * alex_joni has a plane to catch in an hour 08:58:28 np.... I need to get to bed... 1am here 08:58:53 I had a version from a couple of days ago working 08:59:07 lots of changes this weekend... good show 09:09:22 indeed 09:49:48 * alex_joni goes away for a while 09:49:54 alex_joni is now known as alex_joni_away 12:35:02 LawrenceG: if you dpkg --purge emc2 and then apt-get install emc2, do you get config files? 17:16:07 ok I think I reproduced the problem, not sure if I understand it fully 17:16:17 if you apt-get remove emc2, it preserves the configuration files in /etc 17:16:32 if you remove them with rm, it also preserves that (?) 17:17:28 so ... don't do that 17:17:45 dpkg --purge emc2 and then reinstall should fix your problem 18:10:09 cradek: Thanks... that has restored the sample ini's. When running stepper-inch, /usr/bin/milltask errors out when trying to load librs274.so.. a search of my hd does not find this file anywhere 19:11:46 LawrenceG: I fixed that - updated packages available 19:22:40 cradek: Thanks... downloading now 19:24:36 LawrenceG: should be smooth from here on - alpha19 was the first package I made with the new build system. 19:25:37 cradek: np... hope I havent been a pest... the deb idea is fantastic.... 19:26:08 not at all, I really appreciate your testing and good bug reports 19:26:43 you are helping make this smooth for when we make the big release 19:26:52 yea... the more people that can try out the new stuff, the faster its gets stable 19:28:55 running cds now in sepper_in YEA!! 19:29:02 yay! 19:31:30 it runs quite well on a P200..... 19:32:10 great, jmk made an important fix yesterday that should have made it run much faster (reduced BASE_PERIOD possible) 19:37:14 axis-sim seems to be another story... I get a blank axis window and 100% cpu usage forever...maybe some update is being scheduled faster than it can run... no errors on cmd line 19:38:11 hmm 19:38:19 can you run other opengl programs like glxgears? 19:38:26 buy faster computer 19:40:48 that could be the problem..... glxgears comes up, runs a few revs and stalls out... hmm this is an old matrox card 19:41:29 I'm surprised, but Mesa, the software GL renderer, might have trouble on such a slow machine 19:41:35 I get an update about every 20 seconds... xorg is the cpu hog 19:41:54 hmm, doesn't seem like it should be that slow. 19:43:33 its so slow I can see it rendering each face of each tooth! 19:44:53 let me check my xorg config and see what is turned on 19:45:14 you could try turning off DRI 19:47:52 hmmm I notice in the Module sectopn, that I am loading GLcore... that may be the matrox accellerator 19:48:13 as I understand it, that may be bad with RT? 19:48:20 no, that's fine I think 19:48:36 but try commenting out Load "dri" 19:48:39