uPortal IRC Logs-2010-06-28

Owned by Apereo Infrastructure
Last updated: Jun 28, 2010Version comment
8 min read

[07:44:18 CDT(-0500)] * jessm (~Jess@c-71-232-3-151.hsd1.ma.comcast.net) has joined ##uportal
[07:51:11 CDT(-0500)] * colinclark (~colin@bas2-toronto09-1176444420.dsl.bell.ca) has joined ##uportal
[08:28:51 CDT(-0500)] * JoeMoore (89d88117@gateway/web/freenode/ip.137.216.129.23) has joined ##uportal
[08:59:43 CDT(-0500)] * michelled (~michelled@142.150.154.141) has joined ##uportal
[09:31:53 CDT(-0500)] * jsumners (~jsumners@168.28.245.176) has joined ##uportal
[09:32:48 CDT(-0500)] <jsumners> i have installed the quick start bundle. when i click the login button i get a page that says "CAS is unavailable". i have not been able to figure out why. any suggestions?
[09:36:27 CDT(-0500)] * athena (~athena@c-76-121-97-221.hsd1.wa.comcast.net) has joined ##uportal
[09:54:27 CDT(-0500)] * holdorph (~holdorph@wsip-72-215-204-133.ph.ph.cox.net) has joined ##uportal
[09:55:57 CDT(-0500)] * colinclark (~colin@142.150.154.130) has joined ##uportal
[09:57:15 CDT(-0500)] * bsparks (~bsparks@wsip-72-215-204-133.ph.ph.cox.net) has joined ##uportal
[10:00:43 CDT(-0500)] * EricDalquist (~dalquist@2607:f388:e:0:221:9bff:fe37:e768) has joined ##uportal
[10:22:02 CDT(-0500)] <jsumners> i have installed the quick start bundle. when i click the login button i get a page that says "CAS is unavailable". i have not been able to figure out why. any suggestions?
[10:22:53 CDT(-0500)] <EricDalquist> how did you do the installation? All that should be necessary is extracting the tar.gz archive and running "ant start"
[10:23:08 CDT(-0500)] <jsumners> that's it
[10:23:27 CDT(-0500)] <jsumners> are there any special ports that need to be accessible?
[10:23:43 CDT(-0500)] <EricDalquist> huh, no it should all just be using port 8080
[10:23:57 CDT(-0500)] <jsumners> okay
[10:24:17 CDT(-0500)] <EricDalquist> the next step would be looking in the tomcat/logs directory
[10:24:24 CDT(-0500)] <EricDalquist> first at the cas log
[10:24:29 CDT(-0500)] <jsumners> those have been useless
[10:24:31 CDT(-0500)] <EricDalquist> and then if there is nothing there in the catalina.out log
[10:24:49 CDT(-0500)] <EricDalquist> and it is a tomcat error saying the CAS web application is not available?
[10:26:17 CDT(-0500)] <jsumners> http://tinypic.com/r/nycp07/6
[10:26:39 CDT(-0500)] <EricDalquist> interesting
[10:27:08 CDT(-0500)] <EricDalquist> but the initial uPortal view loaded just fine?
[10:27:17 CDT(-0500)] <jsumners> yep
[10:27:44 CDT(-0500)] <jsumners> the only change i have made it to add an authenticator (following the documentation) for my local Active Directory
[10:28:02 CDT(-0500)] <EricDalquist> did it work before that change?
[10:28:21 CDT(-0500)] <jsumners> i can't recall, but i don't think so. i'm about to comment out those changes and verify
[10:31:00 CDT(-0500)] <jsumners> same problem
[10:31:27 CDT(-0500)] <EricDalquist> could you try a completely fresh quickstart install just to be sure?
[10:31:30 CDT(-0500)] <jsumners> i commented out all of my changes to "pom.xml" and "deployerConfigContext.xml"
[10:31:48 CDT(-0500)] <EricDalquist> I don't think we've seen a case where uportal worked but cas failed before
[10:35:03 CDT(-0500)] <jsumners> same problem
[10:35:09 CDT(-0500)] <bsparks> that happened to me once, I believe that some of the portlets like webproxyportlets would not start. I think that I ended up undeploying all of the items and re-running ant initportal
[10:35:38 CDT(-0500)] <EricDalquist> do you have another hsql instance running by chance?
[10:35:46 CDT(-0500)] <jsumners> i simply extracted the tarball and ran `./ant.sh start`
[10:35:49 CDT(-0500)] <jsumners> no
[10:36:00 CDT(-0500)] <jsumners> this is a VM dedicated solely to testing out uPortal
[10:36:02 CDT(-0500)] <EricDalquist> and there are no errors in the cas log?
[10:37:46 CDT(-0500)] <jsumners> http://pastebin.com/ZWNQz55s
[10:41:06 CDT(-0500)] <EricDalquist> huh, I'm not sure
[10:41:22 CDT(-0500)] <EricDalquist> perhaps an email to the CAS list asking what makes CAS display that message
[10:43:21 CDT(-0500)] <jsumners> the only thing that looks suspicious to me is line number 58
[10:43:40 CDT(-0500)] <jsumners> but it is a warning and not an error
[10:44:00 CDT(-0500)] <EricDalquist> yeah
[10:44:08 CDT(-0500)] <EricDalquist> and I would assume it would fall back to just en
[10:46:58 CDT(-0500)] <jsumners> thank you for the assistance
[10:47:40 CDT(-0500)] * awills (~awills@wsip-72-215-204-133.ph.ph.cox.net) has joined ##uportal
[10:51:19 CDT(-0500)] <EricDalquist> no problem, sorry I couldn't help more
[11:23:06 CDT(-0500)] * lfuller (~sparhk@wsip-72-215-204-133.ph.ph.cox.net) has joined ##uportal
[11:43:23 CDT(-0500)] * colinclark (~colin@142.150.154.130) has joined ##uportal
[12:21:23 CDT(-0500)] * Sememmon (~Sememmon@unaffiliated/sememmon) has joined ##uportal
[12:26:06 CDT(-0500)] * michelled (~michelled@142.150.154.141) has joined ##uportal
[12:29:25 CDT(-0500)] * colinclark (~colin@142.150.154.130) has joined ##uportal
[12:35:03 CDT(-0500)] <jsumners> has anyone here used anything other than uPortal?
[12:35:29 CDT(-0500)] <EricDalquist> I did oracle portal development, but that was back in 2002-2004
[12:36:23 CDT(-0500)] <jsumners> that one isn't even on my consideration list
[12:36:40 CDT(-0500)] <EricDalquist> that's a good thing (smile)
[12:36:51 CDT(-0500)] <jsumners> (smile)
[12:38:46 CDT(-0500)] <jsumners> although, i will have to integrate with Banner at some point
[12:43:07 CDT(-0500)] <holdorph> Unicon has experience with Liferay
[12:43:39 CDT(-0500)] <jsumners> i'm not very pleased with the Liferay documentation
[12:43:46 CDT(-0500)] <jsumners> basically, it doesn't really exist
[12:44:08 CDT(-0500)] <jsumners> so far uPortal has had much better documentation
[13:07:45 CDT(-0500)] * lfuller (~sparhk@wsip-72-215-204-133.ph.ph.cox.net) has joined ##uportal
[13:07:45 CDT(-0500)] * JoeMoore (89d88117@gateway/web/freenode/ip.137.216.129.23) has joined ##uportal
[13:07:45 CDT(-0500)] * jsumners (~jsumners@168.28.245.176) has joined ##uportal
[13:07:45 CDT(-0500)] * athena (~athena@c-76-121-97-221.hsd1.wa.comcast.net) has joined ##uportal
[13:07:45 CDT(-0500)] * EricDalquist (~dalquist@2607:f388:e:0:221:9bff:fe37:e768) has joined ##uportal
[13:07:45 CDT(-0500)] * Sememmon (~Sememmon@unaffiliated/sememmon) has joined ##uportal
[13:07:45 CDT(-0500)] * michelled (~michelled@142.150.154.141) has joined ##uportal
[13:07:45 CDT(-0500)] * colinclark (~colin@142.150.154.130) has joined ##uportal
[13:07:45 CDT(-0500)] * awills (~awills@wsip-72-215-204-133.ph.ph.cox.net) has joined ##uportal
[13:07:45 CDT(-0500)] * bsparks (~bsparks@wsip-72-215-204-133.ph.ph.cox.net) has joined ##uportal
[13:07:45 CDT(-0500)] * holdorph (~holdorph@wsip-72-215-204-133.ph.ph.cox.net) has joined ##uportal
[13:07:45 CDT(-0500)] * ChanServ (ChanServ@services.) has joined ##uportal
[13:08:00 CDT(-0500)] <athena> jsumners: really glad to hear you're finding the documentation useful so far
[13:08:05 CDT(-0500)] <athena> we're working really hard to improve it
[13:30:10 CDT(-0500)] <jsumners> good to hear
[13:37:05 CDT(-0500)] * jen (4c7961dd@gateway/web/freenode/ip.76.121.97.221) has joined ##uportal
[13:37:09 CDT(-0500)] <jen> just testing!
[13:39:12 CDT(-0500)] <JoeMoore> Test reply to athena
[13:39:22 CDT(-0500)] <athena> hey there (smile)
[13:39:44 CDT(-0500)] <JoeMoore> Is there some problem with starting with is
[13:40:52 CDT(-0500)] <athena> glad you made it in (smile)
[13:55:02 CDT(-0500)] <JoeMoore> anyone recognize No INIT_STRUCT_ID in UP_USER_LAYOUT for USER_ID: 23 and LAYOUT_ID: 1 on 3.2-patches branch?
[13:56:33 CDT(-0500)] <JoeMoore> With much help from Unicon, I've done a reasonable amount of local configuration work on what used to be 48609
[13:57:35 CDT(-0500)] <JoeMoore> Now (20795), when an LDAP user logs in, they get the good old Sorry, but uPortal encountered an error that is preventing it from rendering. The error must be corrected by system administrators. Try again later.
[14:00:00 CDT(-0500)] <EricDalquist> what user is user 23?
[14:00:15 CDT(-0500)] <JoeMoore> Brand new user from LDAP
[14:00:23 CDT(-0500)] <JoeMoore> I just did initdb
[14:00:42 CDT(-0500)] <EricDalquist> weird, they should be getting a default layout setup on first login
[14:00:56 CDT(-0500)] <JoeMoore> Right now, I'm running initdb from 48609 without re-deploying to see if it's related to initial database setup
[14:01:28 CDT(-0500)] <JoeMoore> We're MS SQL--so if anything has been changed about relationships (enforcement where not enforced, etc) that may be a clue
[14:01:47 CDT(-0500)] <EricDalquist> nothing wrt layouts
[14:02:09 CDT(-0500)] <EricDalquist> there were some changes in 3.2 for the channel object model
[14:02:17 CDT(-0500)] <JoeMoore> any changes in curnunos (sp?)
[14:02:22 CDT(-0500)] <EricDalquist> but the layout DAO code hasn't really been touched since 2.x
[14:02:25 CDT(-0500)] <EricDalquist> not that I know of
[14:03:35 CDT(-0500)] <JoeMoore> Of course, my merging of local with vendor changes could have broken something-I haven't gone back through that step by step-I just thought someone may recognize a chunk of code that's been touched
[14:06:08 CDT(-0500)] <JoeMoore> One significant thing that Jen helped with is moving to database dlm. That road wasn't entirely smooth--but it all seems to work well in 48609.
[14:07:36 CDT(-0500)] <JoeMoore> Just restarted after shutdown, initdb from 48609, restart--same result. No surprise given what you've told me.
[14:08:29 CDT(-0500)] <JoeMoore> I think I'll open a JIRA and go back through the most suspect configuration areas. This is the order I'll do them in unless you give me extra guidance:
[14:09:41 CDT(-0500)] <JoeMoore> Build vanilla 20795
[14:10:23 CDT(-0500)] <JoeMoore> Switch to port 80 and add server name so I can test outside localhost
[14:10:40 CDT(-0500)] <JoeMoore> add ldap login
[14:10:59 CDT(-0500)] <JoeMoore> make sure it works to that point (DLM will still be xml based)
[14:11:09 CDT(-0500)] <JoeMoore> switch to SQL
[14:11:35 CDT(-0500)] <JoeMoore> switch to database dlm
[14:11:51 CDT(-0500)] <JoeMoore> add jdbc login back in
[14:12:12 CDT(-0500)] <JoeMoore> (jdbc is another set of users--they work OK)
[14:12:41 CDT(-0500)] <EricDalquist> sounds great
[14:12:46 CDT(-0500)] <EricDalquist> that's a very good test plan
[14:12:58 CDT(-0500)] <EricDalquist> sorry I don't have a faster approach to figuring it out for you
[14:13:36 CDT(-0500)] <JoeMoore> OK--I won't bother chat until I have something new to report.
[14:17:26 CDT(-0500)] <jsumners> reading http://www.unicon.net/node/970 i'm unclear about how clustering works for uPortal. in our current setup we have 1 resource server (basically an NFS server for channels and LDAP) and 5 "portal" servers. is this how uPortal works?
[14:20:42 CDT(-0500)] <athena> that faq is actually sort of outdated - most of uportal does support clustering
[14:20:54 CDT(-0500)] <athena> but i don't think you need a separate resource server, no
[14:21:07 CDT(-0500)] <athena> EricDalquist is probably the expert on uportal clustering these days
[14:21:31 CDT(-0500)] <EricDalquist> so uPortal supports replication of navigation state and has since 2.6
[14:21:58 CDT(-0500)] <EricDalquist> you need to add the <distributable> element to the uPortal web.xml
[14:22:10 CDT(-0500)] <EricDalquist> and configure session replication in your servlet container
[14:22:51 CDT(-0500)] <jsumners> that would mean subsequent requests could be forwarded to any server, not just the first one the client was balanced to?
[14:23:00 CDT(-0500)] <EricDalquist> portlet state replication is completely outside of uPortal's control, each portlet application would need to have a fully serializable session and have the <distributable> element set as well
[14:23:01 CDT(-0500)] <EricDalquist> channel state has never been and never will be replicated
[14:23:05 CDT(-0500)] <EricDalquist> right
[14:23:24 CDT(-0500)] <jsumners> nice
[14:23:29 CDT(-0500)] <EricDalquist> the normal configuration is sticky sessions, so under normal usage users always hit the same server
[14:23:57 CDT(-0500)] <EricDalquist> after the user's request is complete tomcat (or whatever container you use) serializes the user's session data and sends it out to all the other servers in its cluster
[14:24:12 CDT(-0500)] <EricDalquist> when a server fails the users are re-balanced
[14:24:30 CDT(-0500)] <jsumners> excellent. i think that answers my question. thank you
[14:24:34 CDT(-0500)] <EricDalquist> and on their first request the tomcat instance they are now on deserializes their session
[14:24:38 CDT(-0500)] <athena> eric do you have some documentation on configuring that servlet container that we could add to the manual?
[14:24:51 CDT(-0500)] <jsumners> that would be very good
[14:24:51 CDT(-0500)] <EricDalquist> its simply tomcat's session replication config
[14:24:56 CDT(-0500)] <athena> awesome
[14:25:07 CDT(-0500)] <athena> i'll make a note that we should add all the above to a page in the config section (smile)
[14:25:08 CDT(-0500)] <EricDalquist> there isn't anything special portal-wise other than adding that <distributable>element
[14:25:20 CDT(-0500)] <EricDalquist> there are already notes in the manual about setting up a clustered ehcache config
[14:25:28 CDT(-0500)] <athena> great
[14:25:32 CDT(-0500)] <EricDalquist> so that cached data is invalidated in the cluster
[14:27:08 CDT(-0500)] <athena> so that stats problem that curtis reported
[14:27:15 CDT(-0500)] <athena> i just took a look at his thread dump in TDA
[14:27:15 CDT(-0500)] <EricDalquist> yeah
[14:27:43 CDT(-0500)] <athena> and those PortalEvent-14 style threads actually have like 20 threads locking on the same monitor
[14:28:43 CDT(-0500)] <JoeMoore> FYI, I created up-2725 for the above problem with an attached log. If someone could spend a few minutes looking at the log, it might save me a couple hours working back through our config
[14:28:55 CDT(-0500)] <EricDalquist> thanks JoeMoore
[14:29:04 CDT(-0500)] <EricDalquist> athena: did he post the dump?
[14:29:20 CDT(-0500)] <EricDalquist> because if all 20 threads in the pool are idle they will all be waiting on the monitor for the task queue
[14:29:22 CDT(-0500)] <EricDalquist> waiting for work
[14:29:32 CDT(-0500)] <EricDalquist> and if he is seeing events in his log file that isn't the problem
[14:29:33 CDT(-0500)] <athena> just sent it to me, though i can ask him if he minds having it posted publicly
[14:31:15 CDT(-0500)] <EricDalquist> scratch that last comment
[14:31:23 CDT(-0500)] <EricDalquist> loggingEventHandler and queueingEventHandler are at the same level
[14:31:41 CDT(-0500)] <EricDalquist> so queueingEventHandler adds events to a concurrent queue
[14:32:01 CDT(-0500)] <EricDalquist> and there is supposed to be a scheduled task from quartz that runs once/second to flush the queue to the db
[14:33:46 CDT(-0500)] <athena> so presumably either the queuing event handler or the quartz task aren't running as expected
[14:34:02 CDT(-0500)] <athena> it's possible to update the log configuration without restarting the portal, right?
[14:34:35 CDT(-0500)] <EricDalquist> I think uportal has log4j setup to monitor the config for changes
[14:34:45 CDT(-0500)] <EricDalquist> the queuing event handler doesn't really run anything
[14:35:13 CDT(-0500)] <EricDalquist> https://source.jasig.org/uPortal/tags/rel-3-1-2-GA/uportal-impl/src/main/resources/properties/contexts/statsContext.xml
[14:35:37 CDT(-0500)] <EricDalquist> the portalEventMulticaster writes out events to handlers asynchronously
[14:35:48 CDT(-0500)] <EricDalquist> for loggingEventHandler they go to the log
[14:35:54 CDT(-0500)] <athena> makes sense
[14:35:56 CDT(-0500)] <EricDalquist> for queueingEventHandler they get added to the queue
[14:36:15 CDT(-0500)] <EricDalquist> so the failure of flush() to be called also explains his memory usage issue
[14:36:15 CDT(-0500)] <athena> is that queue exposed to JMX?
[14:36:20 CDT(-0500)] <athena> yeah
[14:36:20 CDT(-0500)] <EricDalquist> events just get added
[14:36:23 CDT(-0500)] <athena> seems like a likely candidate
[14:36:25 CDT(-0500)] <EricDalquist> I don't think so
[14:36:37 CDT(-0500)] <EricDalquist> seems like a handy change to jmxContext though
[14:37:08 CDT(-0500)] <athena> yeah
[14:37:29 CDT(-0500)] <athena> not an immediate help in this situation, but a good change for the future
[14:53:12 CDT(-0500)] * bsparks (~bsparks@wsip-72-215-204-133.ph.ph.cox.net) has joined ##uportal
[15:03:54 CDT(-0500)] <athena> from logging, sounds like the quartz job isn't running
[15:04:12 CDT(-0500)] <EricDalquist> weird that it would just stop working
[15:06:30 CDT(-0500)] <athena> yeah
[15:06:34 CDT(-0500)] <athena> not sure what to make of that
[16:08:54 CDT(-0500)] * EricDalquist (~apollo@76.210.67.136) has joined ##uportal
[19:47:18 CDT(-0500)] * JoeMoore (42117642@gateway/web/freenode/ip.66.17.118.66) has joined ##uportal
[22:22:14 CDT(-0500)] * Sememmon (~Sememmon@unaffiliated/sememmon) has joined ##uportal
[22:56:00 CDT(-0500)] * Sememmon (~Sememmon@unaffiliated/sememmon) has joined ##uportal