Page Comparison

[01:41:50 EDT(-0400)] * EiNZTEiN (n=einztein@di140.opencominc.com) has joined ##uportal
[08:51:46 EDT(-0400)] * jessm (n=Jess@142.150.154.101) has joined ##uportal
[09:21:31 EDT(-0400)] * dstn (n=dstn@unaffiliated/dstn) has joined ##uportal
[09:41:11 EDT(-0400)] * anastasiac (n=team@142.150.154.160) has joined ##uportal
[09:57:09 EDT(-0400)] * jessm (n=Jess@user147-69.wireless.utoronto.ca) has joined ##uportal
[09:58:14 EDT(-0400)] * EricDalquist (n=dalquist@bohemia.doit.wisc.edu) has joined ##uportal
[10:11:48 EDT(-0400)] * colinclark (n=colin@142.150.154.101) has joined ##uportal
[10:51:56 EDT(-0400)] * lennar1 (n=sparhk@wsip-98-174-242-39.ph.ph.cox.net) has joined ##uportal
[11:08:25 EDT(-0400)] * EiNZTEiN (n=einztein@205.241.143.3) has joined ##uportal
[11:09:18 EDT(-0400)] * EiNZTEiN_ (n=einztein@205.241.143.3) has joined ##uportal
[11:15:10 EDT(-0400)] * athena7 (n=athena7@128.187.197.191) has joined ##uportal
[11:17:20 EDT(-0400)] * holdorph (n=holdorph@wsip-98-174-242-39.ph.ph.cox.net) has joined ##uportal
[11:22:47 EDT(-0400)] * chrisdoyle (n=chrisdoy@mtw160-1.ippl.jhu.edu) has joined ##uportal
[12:01:28 EDT(-0400)] * chrisdoyle (n=chrisdoy@mtw160-1.ippl.jhu.edu) has left ##uportal
[12:39:46 EDT(-0400)] * awills (n=awills@wsip-98-174-242-39.ph.ph.cox.net) has joined ##uportal
[13:22:41 EDT(-0400)] * jessm (n=Jess@142.150.154.101) has joined ##uportal
[13:33:23 EDT(-0400)] * awills (n=awills@wsip-98-174-242-39.ph.ph.cox.net) has left ##uportal
[13:39:14 EDT(-0400)] <EricDalquist> just came here looking for awills
[13:39:17 EDT(-0400)] <EricDalquist> and just missed him{color}
[13:45:35 EDT(-0400)] * awills (n=awills@wsip-98-174-242-39.ph.ph.cox.net) has joined ##uportal
[13:46:17 EDT(-0400)] <awills> hey EricDalquist
[13:46:28 EDT(-0400)] <EricDalquist> hey
[13:46:34 EDT(-0400)] <EricDalquist> working on the caching stuff a bit more
[13:46:43 EDT(-0400)] <EricDalquist> I think I have it pretty much ready to go
[13:46:56 EDT(-0400)] <EricDalquist> we'll have some documentation to do around using scripting though
[13:47:00 EDT(-0400)] <awills> nice, and tyvm
[13:47:17 EDT(-0400)] <awills> in terms of how best to leverage the cache?
[13:47:29 EDT(-0400)] <EricDalquist> so what I've found is:
[13:47:41 EDT(-0400)] <EricDalquist> Groovy already does compiled script caching on a per-engine basis
[13:47:51 EDT(-0400)] <awills> well that's a bonus
[13:47:55 EDT(-0400)] <EricDalquist> so by using a single ScriptEngine caching is done
[13:48:10 EDT(-0400)] <EricDalquist> the downside is we need to make sure people avoid using expressions in script strings at all costs
[13:48:21 EDT(-0400)] <awills> ah, good point
[13:48:22 EDT(-0400)] <EricDalquist> since there is no way to clear those groovy managed cache entries
[13:48:37 EDT(-0400)] <awills> heh, gotcha
[13:49:16 EDT(-0400)] <EricDalquist> I'm doing a profile on the full export of an environment here to see what it says
[13:49:53 EDT(-0400)] <EricDalquist> I think I have all of the dynamic scripts fixed on the export side
[13:50:04 EDT(-0400)] <EricDalquist> a lot of it is just adding additional with-attribute elements around the script
[13:50:08 EDT(-0400)]

Wiki Markup
<awills> I think it's a lot easier to avoid phrase expressions in script strings now that you don't have to do things like: '${Attributes.LOCATION}'.split('/')...

[13:50:37 EDT(-0400)]

Wiki Markup
<EricDalquist> the up scripts have a lot of ${sql} and dom related inline phrases

[13:50:52 EDT(-0400)] <awills> gotcha
[13:52:21 EDT(-0400)] <awills> I'm looking forward to what you send back
[14:25:18 EDT(-0400)] <EricDalquist> anyone know if JEXL Expressions are reusable or threadsafe?
[14:35:47 EDT(-0400)] <awills> doesn't look that way: http://mail-archives.apache.org/mod_mbox/commons-user/200610.mbox/%3Cb22dff980610170738kcd7d256hf9afa2ac905a1616@mail.gmail.com%3E
[14:36:24 EDT(-0400)] <EricDalquist> well that says they aren't thread safe
[14:36:29 EDT(-0400)] <EricDalquist> what about reusable?
[14:36:41 EDT(-0400)] <EricDalquist> the next pig on the list is the JEXL parser
[14:36:47 EDT(-0400)] <EricDalquist> at 78% of total CPU time
[14:37:41 EDT(-0400)] <EricDalquist> oh and I had an idea for cleaning up exception handling
[14:37:49 EDT(-0400)] <EricDalquist> but it would be a lot of grunt work to implement
[14:37:59 EDT(-0400)] <awills> still interested to hear it
[14:38:16 EDT(-0400)] <EricDalquist> create some sort of CrnException so that tasks that do try {} catch (throwable t) {} don't keep wrapping an already handled exception
[14:38:46 EDT(-0400)] <EricDalquist> it can be confusing when you get some groovy exception about not being able to run a script, when the real problem was not being able to run some other child task
[14:41:08 EDT(-0400)] <awills> there is something like that... for reporting the location (in xpath) of the error... it's implemented in one or another Decorator so that it doesn't have to be done in each of the Tasks... we vetted the question of whether to "cut off" the stack trace at that point, and (iirc) folks felt it was better to preserve the whole, long context
[14:41:44 EDT(-0400)] <EricDalquist> ah
[14:41:50 EDT(-0400)] <awills> we could revisit that question, and we could also look at changing the error messages to something less confusing (i agree it's misleading)
[14:42:03 EDT(-0400)] <EricDalquist> I think it is more problematic with inlined phrases
[14:42:19 EDT(-0400)] <awills> hmmm... interesting
[14:42:30 EDT(-0400)] <EricDalquist> since with tasks you can make sure you call the proceded method outside of that tasks try/catch
[14:42:41 EDT(-0400)] <EricDalquist> though I imagine some tasks need to be fixed to do that
[14:43:27 EDT(-0400)] <awills> "proceded method?"
[14:43:56 EDT(-0400)] <EricDalquist> sorry
[14:43:57 EDT(-0400)] <EricDalquist> super.performSubtasks(req, res);
[14:44:00 EDT(-0400)] <EricDalquist> like ScriptTask
[14:44:18 EDT(-0400)] <EricDalquist> calls super.performSubtasks(req, res); inside the same try/catch that it executes the script in
[14:44:41 EDT(-0400)] <EricDalquist> so it may erroneously report script execution failure when in reality it was the call to super.performSubtasks(req, res); that failed
[14:44:55 EDT(-0400)] <EricDalquist> in this case super.performSubtasks(req, res); should just be moved out of that script execution try/catch
[14:45:04 EDT(-0400)] <awills> yeah, we could change the practice there to be in a different try/catch... and provide a better message
[14:45:48 EDT(-0400)] <EricDalquist> would it even need to be in one?
[14:46:06 EDT(-0400)] <awills> no, probably not
[14:46:33 EDT(-0400)] <EricDalquist> so reusing JEXL expressions seems to work
[14:46:59 EDT(-0400)] <awills> cool... but you're using a new Context each time? or a ThreadLocal Context or somesuch?
[14:47:22 EDT(-0400)] <EricDalquist> the context is created each time, just like a script context for groovy
[14:47:30 EDT(-0400)] <EricDalquist> but the Expression is cached in a ThreadLocal
[14:47:35 EDT(-0400)] <EricDalquist> so we're not re-parsing that each time
[14:47:40 EDT(-0400)] <awills> gotcha
[14:47:56 EDT(-0400)] <awills> does it help? have you observed it yet?
[14:48:01 EDT(-0400)] <EricDalquist> yeah
[14:48:13 EDT(-0400)] <EricDalquist> it helps, I didn't have pre-run numbers for direct comparison
[14:48:21 EDT(-0400)] <EricDalquist> but I think it was a decent improvement
[14:48:32 EDT(-0400)] <EricDalquist> I'm running it through the profiler again and will have concrete numbers then
[14:48:39 EDT(-0400)] <EricDalquist> I'm down to about 50ms per layout
[14:48:40 EDT(-0400)] <awills> good good... are you getting closer to your 3-hour window?
[14:49:10 EDT(-0400)] <EricDalquist> that's 83 minutes for 100000 layouts
[14:49:20 EDT(-0400)] <EricDalquist> and I can still add threading to the actual export scripts
[14:49:21 EDT(-0400)] <awills> yep, that's what i get too
[14:49:39 EDT(-0400)] <awills> you're close
[14:50:14 EDT(-0400)] <awills> 100k layouts 2 ways + 100k users 2 ways... the rest doesn't take much time anyway
[14:50:14 EDT(-0400)] <EricDalquist> close enough that I'm pretty happy with it
[14:50:29 EDT(-0400)] <awills> great, yeah the improvement is awesome
[14:50:31 EDT(-0400)] <EricDalquist> I think the time per layout will drop with longer runs too
[14:50:43 EDT(-0400)] <EricDalquist> I only have a set of ~ 300 layouts
[14:51:05 EDT(-0400)] <EricDalquist> so that only takes 14 seconds, not much time to benefit from the cache savings or to let the JIT make things faster
[14:51:43 EDT(-0400)] <awills> true... i'm going to step out for lunch... bbl
[14:51:54 EDT(-0400)] <EricDalquist> I have meetings for the next 3 hours
[14:52:00 EDT(-0400)] <EricDalquist> let you know how its going when I get back
[14:52:06 EDT(-0400)] <awills_away> cool
[14:53:55 EDT(-0400)] * jessm (n=Jess@142.150.154.101) has joined ##uportal
[14:57:08 EDT(-0400)] * jessm (n=Jess@142.150.154.101) has joined ##uportal
[15:31:14 EDT(-0400)] * lennar2 (n=sparhk@wsip-98-174-242-39.ph.ph.cox.net) has joined ##uportal
[15:56:38 EDT(-0400)] <EricDalquist> so I have a few second break between meetings. Looks like JEXL Expression caching removed the last of the slow things from the list
[15:57:17 EDT(-0400)] <EricDalquist> what is left are base classloader and java security api calls, none of which look like they are called an excesive number of times
[16:11:18 EDT(-0400)] <athena7> apparently the import/export tool doesn't like it if your URL has "section" in it
[16:16:44 EDT(-0400)] <awills> "section?"
[16:43:26 EDT(-0400)] <awills> EricDalquist still in meetings?
[16:59:55 EDT(-0400)] * jessm (n=Jess@142.150.154.101) has joined ##uportal
[17:01:15 EDT(-0400)] * colinclark (n=colin@142.150.154.101) has joined ##uportal
[17:33:43 EDT(-0400)] <EricDalquist> just got back
[17:34:32 EDT(-0400)] <awills> http://uportal.pastebin.com/m55be473f
[17:35:11 EDT(-0400)] <awills> i believe this simple tweek will clear up issues related to logging out w/ the impersonation stuff in 3.0-patches
[17:35:35 EDT(-0400)] <awills> such as have been discussed on the -user list today
[17:37:12 EDT(-0400)] <EricDalquist> yeah I was just going to look, seemed like the impersontation stuff shouldn't throw in that case
[17:37:45 EDT(-0400)] <EricDalquist> feel free to check that in on 3.0-patches and send out an email about it
[17:37:59 EDT(-0400)] <EricDalquist> you can just use the original jira issue for the impersonation for the commit
[17:38:15 EDT(-0400)] <EricDalquist> since it was never released, no need for jira issues against unreleased code
[17:38:54 EDT(-0400)] <awills> yeah that's what I was hoping to do
[17:39:27 EDT(-0400)] <awills> uP security code & configs makes my head hurt :/
[17:39:32 EDT(-0400)] <EricDalquist> yeah
[17:39:41 EDT(-0400)] <EricDalquist> that's why we stayed away from them for the swapper stuff we did at UW
[17:39:46 EDT(-0400)] <EricDalquist> too much undocumented magic for me
[17:40:32 EDT(-0400)] <awills> yeppers... it's fine w/ me that impersonation becomes a 1st-class feature in uP, supported in the LonginServlet
[17:40:50 EDT(-0400)] <EricDalquist> so the JEXL Expression caching worked well
[17:41:30 EDT(-0400)] <EricDalquist> now the top 3 slowest methods are all classloading related and it looks like it is just base startup time stuff, no more loading classes over and over
[17:42:15 EDT(-0400)] <EricDalquist> though we'll have the same caveat with JEXL expressions that we do with scripts which is 'avoid in-line phrases if at all possible if you want to use cache-all'
[17:42:40 EDT(-0400)] <awills> yeah that's good... i'll get language to that effect in the docs
[17:43:03 EDT(-0400)] <EricDalquist> I'll get a patch put together
[17:43:11 EDT(-0400)] <awills> were you able to use the TaskRequest.getCache() approach?
[17:44:40 EDT(-0400)] <EricDalquist> I haven't gotten to that
[17:44:48 EDT(-0400)] <EricDalquist> I've only had time to continue my original approach
[17:44:59 EDT(-0400)] <EricDalquist> so I'll publish that as a patch and we can talk more after you've taken a look
[17:46:29 EDT(-0400)] <awills> on a completely different note, I have this: http://uportal.pastebin.com/m26444a5
[17:46:45 EDT(-0400)] <awills> and i'm getting "org.springframework.dao.IncorrectResultSizeDataAccessException: Incorrect result size: expected 1, actual 2"
[17:47:15 EDT(-0400)] <EricDalquist> does your query possibly return multiple ldap entries?
[17:47:17 EDT(-0400)] <awills> how to tell the newest LDAP DAO to expect more than 1 row?
[17:47:35 EDT(-0400)] <awills> er, multi-valued attributes
[17:47:54 EDT(-0400)] <EricDalquist> I'm not sure that is multivalued attributes
[17:47:59 EDT(-0400)] <EricDalquist> but I'm not sure
[17:48:02 EDT(-0400)] <EricDalquist> what version of PD?
[17:48:03 EDT(-0400)] <awills> i don't think it's more than 1 entry, i thought it was a multi-valued attribute
[17:48:16 EDT(-0400)] <awills> uP/trunk
[17:49:26 EDT(-0400)] <EricDalquist> so that would be PD 1.5
[17:49:32 EDT(-0400)] <EricDalquist> can you pastebin the stacktrace?
[17:49:32 EDT(-0400)] <awills> maybe you're right... perhaps there are 2 entries w/ the same "sAMAccountName"
[17:49:38 EDT(-0400)] <awills> yep
[17:50:13 EDT(-0400)] <awills> http://uportal.pastebin.com/m60514001
[17:50:56 EDT(-0400)] <awills> hmm... should this be in therre? org.jasig.portal.portlets.swapper.OverwritingPersonAttributeDao.getPerson()
[17:51:28 EDT(-0400)] <EricDalquist> yeah
[17:51:33 EDT(-0400)] <EricDalquist> that's part of the attribute swapper
[17:52:01 EDT(-0400)] <EricDalquist> so it sure looks like person directory thinks ldap is returning two distict sets of attributes
[17:52:07 EDT(-0400)] <EricDalquist> distinct*
[17:52:17 EDT(-0400)] <awills> yeah but would it be in the stack trace if the LdapDao was the one failing?
[17:52:30 EDT(-0400)] <EricDalquist> yeah
[17:52:32 EDT(-0400)] <EricDalquist> it is a wrapper
[17:52:58 EDT(-0400)] <EricDalquist> so it is the top level IPersonAttributeDao now
[17:53:17 EDT(-0400)] <awills> ok
[17:53:19 EDT(-0400)] <EricDalquist> then the cache, then the aggregator, then each source under that
[17:53:51 EDT(-0400)] <EricDalquist> so ... one other thing looking at your config
[17:54:17 EDT(-0400)] <EricDalquist> since PD 1.5 is still under testing the 'queryTemplate' attribute was recently added
[17:54:35 EDT(-0400)] <EricDalquist> in your example config you have "query" commented out
[17:54:48 EDT(-0400)]

Wiki Markup
<EricDalquist> which was "(&(objectCategory=user)(CN={0}))"

[17:54:58 EDT(-0400)] <EricDalquist> do you still need that?
[17:55:00 EDT(-0400)] <awills> yep, what's queryTemplate?
[17:55:30 EDT(-0400)] <EricDalquist> the big change for PD 1.5 is search, it does some of the work of generating the query for you
[17:55:31 EDT(-0400)] <awills> i assumed 'queryAttributeMapping' was doing the work formerly done by 'query'
[17:55:51 EDT(-0400)] <EricDalquist> but if you need additional 'static' checks you can set that up using 'queryTemplate'
[17:57:11 EDT(-0400)] <EricDalquist> http://uportal.pastebin.com/m1dad12a7
[17:57:23 EDT(-0400)] <EricDalquist> that is UWs current person directory 1.5 config
[17:57:33 EDT(-0400)] <EricDalquist> querying two database tables and one LDAP server
[17:57:49 EDT(-0400)] <EricDalquist> in the ldap config we have a queryTemplate set
[17:58:24 EDT(-0400)] <EricDalquist> it provides some static part of the query that is always included, in this case it ands uid=* to the query, so that searches only return users that actually have login ids
[17:58:49 EDT(-0400)] <EricDalquist> also in your example, your query attribute mapping is: <entry key="username" value="sAMAccountName"/>
[17:59:00 EDT(-0400)]

Wiki Markup
<EricDalquist> buy your old query was: <value>(&(objectCategory=user)(CN={0}))</value>

[17:59:10 EDT(-0400)] <awills> should those be reversed?
[17:59:39 EDT(-0400)] <awills> no, the commented out part was from another directory server
[17:59:52 EDT(-0400)] <EricDalquist> ah ok
[18:00:01 EDT(-0400)] <awills> the CN at the current directory looks like "Andrew Wills"
[18:00:05 EDT(-0400)] <EricDalquist> just wanted to make sure that wasn't a mismatch
[18:00:17 EDT(-0400)] <awills> yeah that's a good thing to check
[18:00:55 EDT(-0400)] <awills> so the dn actually looks like "CN=Andrew Wills,etc,etc"
[18:01:16 EDT(-0400)] <awills> the only thing that has a uid-looking value is sAMAccountName
[18:01:44 EDT(-0400)] <EricDalquist> I guess I'd try to find out why there are two of you then
[18:01:57 EDT(-0400)] <EricDalquist> you can also turn on debug logging for the person directory package
[18:02:02 EDT(-0400)] <EricDalquist> which will be very verbose
[18:02:14 EDT(-0400)] <EricDalquist> but would show you exactly what is going on as far as results being returned and what they are
[18:03:47 EDT(-0400)] <awills> "Number of Search Results: 1"
[18:04:20 EDT(-0400)] <awills> if only there were 2 of me
[18:04:21 EDT(-0400)] <EricDalquist> hrm
[18:04:31 EDT(-0400)] <EricDalquist> yeah it could be elsewgere
[18:04:41 EDT(-0400)] <EricDalquist> a bug elsewhere in PD I mean
[18:09:28 EDT(-0400)] <EricDalquist> I'm having fun figuring out how to decompose a groovy script with embedded stuff in it
[18:11:11 EDT(-0400)] <awills> um, yeah... sounds like a blast
[18:11:31 EDT(-0400)] <EricDalquist>
[18:11:42 EDT(-0400)] <EricDalquist> I have in a groovy/script block:
[18:11:43 EDT(-0400)]

Wiki Markup
<EricDalquist> PORTLET_DATA\[1\] = '${jexl(Attributes.NODE.getUniquePath())}';

[18:11:58 EDT(-0400)] <EricDalquist> if I wrap the <groovy> task in a <with>
[18:11:59 EDT(-0400)] <EricDalquist> and do
[18:12:00 EDT(-0400)]

Wiki Markup
<EricDalquist> <attribute key="CHANNEL_PATH">${jexl(Attributes.NODE.getUniquePath())}</attribute>

[18:12:01 EDT(-0400)] <awills> AbstractDefaultAttributePersonAttributeDao.getPerson(): http://uportal.pastebin.com/m2fd09664
[18:12:05 EDT(-0400)] <EricDalquist> it doesn't behave the same way
[18:12:15 EDT(-0400)] <EricDalquist> yup
[18:12:52 EDT(-0400)] <EricDalquist> that is correct, the problem is likely how that uniqueness is determined in the ldap dao (including super classes)
[18:13:04 EDT(-0400)] <EricDalquist> mind pastebining a log?
[18:13:29 EDT(-0400)] <awills> sure, w/ trace or somesuch turned on?
[18:13:59 EDT(-0400)] <EricDalquist> yeah
[18:14:01 EDT(-0400)] <EricDalquist> turn on debug
[18:14:09 EDT(-0400)] <EricDalquist> just for the person directory package though please
[18:18:02 EDT(-0400)] <awills> log4j.logger.org.jasig.services.persondir=DEBUG, R
[18:18:37 EDT(-0400)] <EricDalquist> and log4j.additivity.package=false
[18:18:42 EDT(-0400)] <EricDalquist> http://uportal.pastebin.com/m760bccd
[18:18:50 EDT(-0400)] <EricDalquist> any ideas?
[18:19:41 EDT(-0400)] <awills> what's up w/ that additivity? log4j config makes my head hurt in pretty much the same way that uP security does
[18:19:55 EDT(-0400)] <EricDalquist> if things should be logged more than once
[18:20:25 EDT(-0400)] <EricDalquist> so log4j will send a log entry to the configured logger (R in this case) once for each pattern match
[18:21:03 EDT(-0400)] <EricDalquist> unless that pattern has additivity set to false, in which case it will only send it if it hasn't already logged that log entry
[18:23:36 EDT(-0400)] <EricDalquist> any ideas on that crn issue?
[18:29:16 EDT(-0400)] <awills> looking (had to step away for a sec)
[18:29:39 EDT(-0400)] <awills> yes, i know what it is
[18:30:52 EDT(-0400)] <awills> http://uportal.pastebin.com/m55abf29b
[18:31:01 EDT(-0400)] <EricDalquist> lol
[18:31:21 EDT(-0400)] <awills> yeah, i hit that one now and again
[18:31:31 EDT(-0400)] <awills> there should be a WARN msg
[18:31:44 EDT(-0400)] <EricDalquist> should it just fail-fast?
[18:31:50 EDT(-0400)] <EricDalquist> is there any valid use case for that?
[18:32:09 EDT(-0400)] <awills> whenever something can have subtasks but doesn't find them
[18:32:17 EDT(-0400)] <awills> well yes... a few
[18:32:37 EDT(-0400)] <awills> there are some things that validly may or may not have them
[18:32:45 EDT(-0400)] <EricDalquist> well not having them is one thing
[18:32:52 EDT(-0400)] <EricDalquist> but what about having something completely unexpected?
[18:33:02 EDT(-0400)] <awills> ahhh... ic
[18:33:08 EDT(-0400)] <EricDalquist> someday I'd still love to look into writing a XSD generator for crn
[18:33:18 EDT(-0400)] <awills> that's a good idea... if nothing else, another warning
[18:33:34 EDT(-0400)] <awills> oh me too