[11:00:03 CST(-0600)] <jwennmacher> I noticed the intelliJ JASIG license expires on March 13, 2013. Will it get renewed?
[11:00:30 CST(-0600)] <EricDalquist> hrm, I'm assuming so
[11:00:37 CST(-0600)] <EricDalquist> I can check with Scott
[11:00:40 CST(-0600)] <EricDalquist> I think he was currating it
[11:01:28 CST(-0600)] <jwennmacher> thx
[11:02:49 CST(-0600)] <EricDalquist> is there a wiki page where the current license info is documented?
[11:03:43 CST(-0600)] <cwaymire> EricDalquist: hey, you got a few minutes? I am seeing a really odd issue with uPortal that appears to be perhaps platform specific.
[11:03:48 CST(-0600)] <EricDalquist> sure
[11:05:18 CST(-0600)] <cwaymire> I noticed last week that after I sync'd up my uPortal master branch from jasig everything broke. The portal stands up fine but as soon as I login and it attempts to render (for example) the portal administration portlet it fails with and then the error portlet also fails to render. The log files indicate pretty much nothing other then that the servlet service threw an exception.
[11:05:35 CST(-0600)] <cwaymire> I have confirmed that 4.0.9 works fine, but rel-patches 4.0 does not
[11:05:47 CST(-0600)] <cwaymire> i have a gist with the pertinent logs i can post
[11:05:51 CST(-0600)] <EricDalquist> that would be great
[11:05:55 CST(-0600)] <cwaymire> https://gist.github.com/waymirec/4755751
[11:05:55 CST(-0600)] <cwaymire> https://gist.github.com/waymirec/4755754
[11:06:11 CST(-0600)] <cwaymire> the first is from the localhost log and the second is from the uportal.log
[11:06:42 CST(-0600)] <cwaymire> Drew has confirmed that he sees no issues (windows 7) while James is having the same problem. James is running the same platform I am (Linux Mint)
[11:06:52 CST(-0600)] <EricDalquist> huh
[11:06:57 CST(-0600)] <EricDalquist> what version of tomcat are you using?
[11:07:01 CST(-0600)] <cwaymire> 7.0.35
[11:09:06 CST(-0600)] <EricDalquist> I'll update to tc 7.0.35
[11:09:09 CST(-0600)] <EricDalquist> and give it a try locally
[11:09:17 CST(-0600)] <cwaymire> what version are you running?
[11:09:22 CST(-0600)] <cwaymire> i can also try downgrading real quick
[11:09:33 CST(-0600)] <jwennmacher> FYI. I'm on 7.0.29.
[11:13:03 CST(-0600)] <cwaymire> I believe drew was running 7.0.35 as well
[11:16:04 CST(-0600)] <EricDalquist> starting tomcat ...
[11:17:26 CST(-0600)] <EricDalquist> looks good to me
[11:17:37 CST(-0600)] <EricDalquist> have you both tried clean tomcat installs?
[11:18:00 CST(-0600)] <cwaymire> yes. I went so far as to completely re-install my O/S
[11:18:11 CST(-0600)] <EricDalquist> ...
[11:18:17 CST(-0600)] <cwaymire> after nothing else worked
[11:18:38 CST(-0600)] <jwennmacher> I am just starting the isolation/validation process
[11:18:40 CST(-0600)] <cwaymire> I wanted to rule out any and all local environment issues so did a completely clean install
[11:18:41 CST(-0600)] <EricDalquist> so all the webapps appear to start correctly in catalina.out?
[11:18:51 CST(-0600)] <cwaymire> yeah. there are no errors at deployment time
[11:19:20 CST(-0600)] <cwaymire> it is only when I login and it attempts to render that the errors come up. and it only seems to affect the "internal" portlets that are bundled within the uportal war
[11:19:39 CST(-0600)] <EricDalquist> so it works as guest?
[11:19:55 CST(-0600)] <cwaymire> Yeah. I see no errors at the guest page
[11:20:25 CST(-0600)] <EricDalquist> uhg
[11:20:25 CST(-0600)] <cwaymire> but if I log in as the basic admin user, and it attempts to render the portal administrator portlet it fails
[11:20:29 CST(-0600)] <EricDalquist> @#$@#$ pluto ....
[11:21:20 CST(-0600)] <EricDalquist> ok ... I'm going to publish a pluto snapshot
[11:21:28 CST(-0600)] <EricDalquist> that I want you to try
[11:21:34 CST(-0600)] <EricDalquist> it will take a little bit
[11:21:47 CST(-0600)] <EricDalquist> but pluto is failing to chain the root exception for the UnavailableException
[11:22:29 CST(-0600)] <cwaymire> ok.
[11:24:55 CST(-0600)] <EricDalquist> ok cwaymire
[11:25:03 CST(-0600)] <drewwills> EricDalquist you're a Pluto contrib, do i remember right?
[11:25:07 CST(-0600)] <EricDalquist> yeah
[11:25:15 CST(-0600)] <EricDalquist> I'm the most active pluto dev in the last 12 months 
[11:25:23 CST(-0600)] <EricDalquist> so if you guys ever see bugs/issues
[11:25:25 CST(-0600)] <EricDalquist> we can get them fixed
[11:25:29 CST(-0600)] <EricDalquist> so
[11:25:33 CST(-0600)] <drewwills> maybe you can un-swollow (disgorge?) this exception for the tuture then
[11:25:35 CST(-0600)] <EricDalquist> setup https://repository.apache.org/content/repositories/snapshots as a snapshot repo
[11:25:47 CST(-0600)] <EricDalquist> and update to pluto 2.1.0-SNAPSHOT
[11:26:00 CST(-0600)] <EricDalquist> you'll need to do a full "ant clean deploy-war"
[11:26:01 CST(-0600)] <EricDalquist> ack
[11:26:07 CST(-0600)] <EricDalquist> "ant clean deploy-ear"
[11:26:13 CST(-0600)] <EricDalquist> to get the shared libraries cleaned out
[11:26:20 CST(-0600)] <cwaymire> ok
[11:27:07 CST(-0600)] <EricDalquist> https://gist.github.com/edalquist/4755946
[11:27:09 CST(-0600)] <EricDalquist> that is the change
[11:27:15 CST(-0600)] <EricDalquist> just added an initCause
[11:27:25 CST(-0600)] <EricDalquist> hopefully that will let us track down the root of the problem
[11:29:55 CST(-0600)] <EricDalquist> also wanted to welcome tlev (Tim Levett), he is one of two new developers that just joined the MyUW team
[11:30:21 CST(-0600)] <tlev> hello
[11:30:35 CST(-0600)] <jwennmacher> hello. welcome aboard
[11:30:56 CST(-0600)] <tlev> thank you, glad to be here
[11:52:58 CST(-0600)] <cwaymire> EricDalquist: I got everything cleaned and recompiled using the 2.1.0-SNAPSHOT but I don't see any additional logging.
[11:53:58 CST(-0600)] <cwaymire> still just indicates that servlet.service() threw an exception and then the portlet is unavailable. no detalis.
[11:54:00 CST(-0600)] <cwaymire> *details
[12:27:55 CST(-0600)] <drewwills> Welcome tlev – glad to have you!
[12:44:23 CST(-0600)] <cwaymire> EricDalquist: Looking at where the change was made, it is within the catch block for the UnavailableException exception. The problem, if I understand this correctly, is that that exception is indicating that the portlet is unavailable, not WHY its unavailable. Prior to that exception there is a SEVERE log indicating that the servlet.service() threw an exception which I imagine is what caused the portlet to become unavailable which then resulted in
[12:44:23 CST(-0600)] <cwaymire> the UnavailableException.
[12:44:37 CST(-0600)] <cwaymire> so what I need to find is what exception is being thrown by the servlet.service()
[13:03:06 CST(-0600)] <EricDalquist> hrm
[13:03:57 CST(-0600)] <EricDalquist> ok ...
[13:04:02 CST(-0600)] <EricDalquist> oh
[13:04:07 CST(-0600)] <EricDalquist> are you deploying to /uPortal?
[13:04:12 CST(-0600)] <EricDalquist> or are you using a different context path?
[13:04:26 CST(-0600)] <EricDalquist> I should have looked at this code first
[13:04:44 CST(-0600)] <EricDalquist> that exception is because the portlet init was not called
[13:10:14 CST(-0600)] <EricDalquist> so the next question is why
[13:12:41 CST(-0600)] <cwaymire> deploying to /uPortal
[13:13:20 CST(-0600)] <EricDalquist> how are you starting tomcat?
[13:13:27 CST(-0600)] <EricDalquist> cli/eclipse/...
[13:14:29 CST(-0600)] <cwaymire> CLI
[13:15:41 CST(-0600)] <EricDalquist> after you start tomcat
[13:15:49 CST(-0600)] <EricDalquist> can you do a "kill -3" of the tomcat process?
[13:15:58 CST(-0600)] <EricDalquist> I want to see if there are a ton of Timer-* threads
[13:16:08 CST(-0600)] <EricDalquist> those are the threads that pluto starts to do the portlet init work
[13:20:07 CST(-0600)] <jwennmacher> cwaymire: Did you get 4.0.9 or 4.0.9.1 operational? I got 4.0.9.1 to start up in tomcat6, but it is failing in tomcat 7.0.35 with the following in localhost.date.log
[13:20:08 CST(-0600)] <jwennmacher> SEVERE: Servlet.service() for servlet [RenderingDispatcherServlet] in context with path [/uPortal] threw exception [Filter execution threw an exception] with root cause
[13:20:08 CST(-0600)] <jwennmacher> java.lang.AbstractMethodError
[13:20:08 CST(-0600)] <jwennmacher> This is different than what you see right?
[13:20:37 CST(-0600)] <cwaymire> EricDalquist: https://gist.github.com/waymirec/4756843
[13:21:05 CST(-0600)] <cwaymire> jwennmacher: I fired it up in TC6. Dont believe I tried 4.0.9.1 in TC7
[13:22:27 CST(-0600)] <cwaymire> EricDalquist: I do indeed seed a bunch of Timer threads.
[13:26:56 CST(-0600)] <EricDalquist> oh
[13:27:04 CST(-0600)] <EricDalquist> uP 4.0.10 is the first release with TC7 support
[13:27:14 CST(-0600)] <EricDalquist> 4.0.9 will only work in TC6
[13:27:34 CST(-0600)] <EricDalquist> ok ... so somehow the portlet container isn't registering correctly
[13:28:19 CST(-0600)] <jwennmacher> OK thanks EricDalquist
[13:30:03 CST(-0600)] <EricDalquist> so the normal process is:
[13:30:03 CST(-0600)] <EricDalquist> the pluto servlet that gets stuck in each web.xml gets init called
[13:30:28 CST(-0600)] <EricDalquist> that does some very basic processing of portlet.xml and then tries to register the portlet via a static method which exists in shared/lib
[13:30:51 CST(-0600)] <EricDalquist> if the portal has not started yet that registration results in a timer that runs like 1/second to retry registration
[13:31:08 CST(-0600)] <EricDalquist> when the portal init happens the portal injects a reference to the container object into that static method
[13:31:19 CST(-0600)] <EricDalquist> and all of the timer threads should then complete registration
[13:31:25 CST(-0600)] <EricDalquist> something in that process is breaking
[13:31:33 CST(-0600)] <EricDalquist> but why it is breaking for just the two of you ...
[13:31:34 CST(-0600)] <EricDalquist> oh
[13:31:37 CST(-0600)] <EricDalquist> did you setup shared/lib?
[13:31:53 CST(-0600)] <EricDalquist> hrm ... actally I'd guess yes or youd see class not found errors
[13:33:13 CST(-0600)] <cwaymire> yeah. the shared.loader is defined in catalina.properties and it is indeed dumping all the libraries there.
[13:33:30 CST(-0600)] <cwaymire> I just wonder if its some kind of TC7 bug on linux
[13:33:43 CST(-0600)] <EricDalquist> but it works for me on xubuntu 12.10 ...
[13:33:48 CST(-0600)] <cwaymire> hrmm
[13:33:50 CST(-0600)] <cwaymire> odd
[13:33:51 CST(-0600)] <EricDalquist> with 7.0.35
[13:34:00 CST(-0600)] <cwaymire> we're both running mint which is ubuntu-based
[13:34:32 CST(-0600)] <jwennmacher> I won't say yet that I'm seeing the exact same thing as cwaymire. I'm trying to get rel-4-0-patches up and running on TC7 now
[13:36:48 CST(-0600)] <cwaymire> jwennmacher: you're just in denial 
[13:37:21 CST(-0600)] <jwennmacher> No, I just want to make sure I didn't hose something else up that's earlier in the process
[13:40:08 CST(-0600)] <cwaymire> EricDalquist: another odd thing is it's not doing it for the portlets outside of the uportal war
[13:40:16 CST(-0600)] <EricDalquist> yeah
[13:40:33 CST(-0600)] <EricDalquist> I wonder if there is some extra jar in the uportal-war classpath?
[13:40:50 CST(-0600)] <EricDalquist> can you see if tehre are any dupes between what is in shared-lib and what is in uPortal/WEB-INF/lib?
[13:41:19 CST(-0600)] <cwaymire> ok
[13:43:22 CST(-0600)] <drewwills> Thanks for your help tracking this item down EricDalquist
[13:43:34 CST(-0600)] <EricDalquist> np
[13:44:24 CST(-0600)] <jwennmacher> cwaymire so you were able to get 4.0.9 working with TC6, but haven't had anything working with TC7 is that where you are at?
[13:45:15 CST(-0600)] <cwaymire> EricDalquist: no dupes
[13:45:21 CST(-0600)] <cwaymire> jwennmacher: yep
[13:46:42 CST(-0600)] <cwaymire> the problem occurred early last week. not sure if it was coincidence or not but it started right after I did a pull from jasig on the master branch and tried to stand it back up. I was running TC6 at the time.
[13:46:55 CST(-0600)] <cwaymire> drew mentioned that we should be on TC7 with master so I switched to TC7 and the problem persisted.
[13:47:48 CST(-0600)] <cwaymire> after troubleshooting and getting no where I tested 4.0.9.1 on TC6 and it worked fine. Tried rel-4-0-patches on TC6 and it failed with this same problem.
[13:48:11 CST(-0600)] <cwaymire> to rule out my machine as a problem I did a complete o/S reinstall
[13:49:10 CST(-0600)] <EricDalquist> cwaymire: in your thread dump
[13:49:13 CST(-0600)] <EricDalquist> actually
[13:49:19 CST(-0600)] <EricDalquist> can you just post that thread dump?
[13:49:25 CST(-0600)] <jwennmacher> cwaymire: OK Now I'm on latest in rel-4-0-patches with TC 7.0.35 and Java 1.6.0.35. I get the admin portlets up and running.
[13:49:25 CST(-0600)] <cwaymire> i did
[13:49:34 CST(-0600)] <cwaymire> its in the gist i pasted agove
[13:49:36 CST(-0600)] <cwaymire> above
[13:49:38 CST(-0600)] <EricDalquist> ah ok
[13:50:03 CST(-0600)] <jwennmacher> so I'm going to try master now
[13:50:06 CST(-0600)] <EricDalquist> AHAH!
[13:50:29 CST(-0600)] <EricDalquist> https://gist.github.com/waymirec/4756843#file-tomcat-thread-dump-L287
[13:50:32 CST(-0600)] <EricDalquist> that is the problem
[13:50:45 CST(-0600)] <EricDalquist> wtf is doing an FTP call on portlet init?
[13:51:17 CST(-0600)] <EricDalquist> so portlet init is synchronized (that was a terrible hack to fix a threading bug, really the whole portlet init lifecycle needs a rewrite)
[13:51:20 CST(-0600)] <EricDalquist> but that portlet
[13:51:26 CST(-0600)] <EricDalquist> no idea which one really from that info
[13:51:33 CST(-0600)] <EricDalquist> is hanging during init
[13:51:58 CST(-0600)] <EricDalquist> and if you look, every other Timer-* thread is waiting on a lock held by Timer-35
[13:52:30 CST(-0600)] <EricDalquist> so ... do you guys have a customized properties config or something?
[13:53:15 CST(-0600)] <cwaymire> the only things I changed on mine after cloning it was the build.properties
[13:53:25 CST(-0600)] <cwaymire> to specify where tomcat is and where maven is
[13:54:08 CST(-0600)] <cwaymire> and again to make sure it wasnt something on my end I deleted my uportal fork, and re-forked from master
[13:54:15 CST(-0600)] <EricDalquist> huh
[13:54:25 CST(-0600)] <EricDalquist> any ideas what could be triggering that ftp connection then?
[13:55:24 CST(-0600)] <cwaymire> is that indicating that its making an ftp call to retrieve properties?
[13:55:45 CST(-0600)] <EricDalquist> that is what it is looking liker
[13:56:23 CST(-0600)] <EricDalquist> ok let me see if I can do another pluto tweak
[13:56:26 CST(-0600)] <EricDalquist> to help us track this down
[13:57:43 CST(-0600)] <cwaymire> grep'ing through the source hte only referneces I see to ftp are in some JS files in the SimpleContentPortlet.
[13:58:43 CST(-0600)] <EricDalquist> ok
[13:58:50 CST(-0600)] <EricDalquist> try switching to pluto 2.1.0-SNAPSHOT
[13:59:00 CST(-0600)] <EricDalquist> you'll need to do a "mvn clean install -U"
[13:59:08 CST(-0600)] <EricDalquist> to grab the newest snapshot
[13:59:16 CST(-0600)] <EricDalquist> it names the timer threads with the portle name
[13:59:24 CST(-0600)] <cwaymire> thats the same snapshot you posted earlier right?
[13:59:37 CST(-0600)] <EricDalquist> yeah I just deployed another update
[14:01:45 CST(-0600)] <cwaymire> ok. wiped out my local pluto repository just to be certain. cleaned and rebuilding now.
[14:02:06 CST(-0600)] <EricDalquist> ok
[14:02:27 CST(-0600)] <EricDalquist> maybe now that we have more dev time here some of this ancilary pluto cleanup can actually get done
[14:02:36 CST(-0600)] <EricDalquist> like actually using concurrent apis for context init
[14:02:41 CST(-0600)] <EricDalquist> and not starting a billion timer thread
[14:08:36 CST(-0600)] <cwaymire> EricDalquist: "Pluto Portlet Init - SelfEditAccount" daemon prio=10 tid=0x00007fb3db219000 nid=0x750d runnable [0x00007fb43afe2000]
[14:08:38 CST(-0600)] <cwaymire> thats the culprit
[14:08:51 CST(-0600)] <EricDalquist> huh
[14:09:03 CST(-0600)] <EricDalquist> so something about how that loads ...
[14:09:11 CST(-0600)] <EricDalquist> mind tracking down the spring context/prop files for it?
[14:09:16 CST(-0600)] <cwaymire> sure
[14:10:18 CST(-0600)] <jwennmacher> update: I just built upstream/master using TC 7.0.35 and I'm running
[14:10:28 CST(-0600)] <jwennmacher> so it is just you now Chris
[14:18:23 CST(-0600)] <cwaymire> I just fixed it
[14:19:08 CST(-0600)] <cwaymire> I edited the primaryPropertyPlaceholderConfigurer bean within the applicationContext.xml and removed the 2 overrides.properties values
[14:19:10 CST(-0600)] <cwaymire> and the problem went away
[14:19:35 CST(-0600)] <cwaymire> it must have been interpreting those as remote url's?
[14:19:56 CST(-0600)] <EricDalquist> weird
[14:19:59 CST(-0600)]
[14:19:59 CST(-0600)]
[14:20:03 CST(-0600)] <cwaymire> those are the values I dumped
[14:20:16 CST(-0600)] <EricDalquist> huh
[14:20:24 CST(-0600)] <cwaymire> I dont have a PORTAL_HOME defined
[14:20:30 CST(-0600)] <EricDalquist> ohhh
[14:20:34 CST(-0600)] <cwaymire> and my CATALINA_HOME Is "/opt/tomcat/tomcat-7.0.35"
[14:20:44 CST(-0600)] <EricDalquist> so it is all drew's fault!
[14:20:45 CST(-0600)] <EricDalquist>
[14:20:58 CST(-0600)] <EricDalquist> can you open a bug
[14:21:26 CST(-0600)] <EricDalquist> essentially drew's patch about config file's external to the project needs fixing
[14:21:34 CST(-0600)] <EricDalquist> so that if those env_vars aren't explicitly set
[14:21:37 CST(-0600)] <EricDalquist> something sets them to sane defaults
[14:23:08 CST(-0600)] <cwaymire> yeah. I just briefed him on the findings.
[14:23:11 CST(-0600)] <cwaymire> i'll open a bug for it
[14:23:23 CST(-0600)] <cwaymire> man that was a nasty one
[14:23:24 CST(-0600)] <EricDalquist> thanks
[14:23:26 CST(-0600)] <EricDalquist> yeah
[14:23:31 CST(-0600)] <EricDalquist> well one little bug
[14:23:37 CST(-0600)] <EricDalquist> compounded by some terrible design in pluto
[14:29:34 CST(-0600)] <jwennmacher> EricDalquist: I found this RE intelliJ license: https://wiki.jasig.org/display/JSG/IntelliJ+IDEA. I got the license from Chris who also uses intelliJ.
[14:29:42 CST(-0600)] <EricDalquist> thanks
[14:34:33 CST(-0600)] <EricDalquist> scott just directed me to dima
[14:34:41 CST(-0600)] <EricDalquist> so I'd say go check with him next
[14:35:28 CST(-0600)] <cwaymire> EricDalquist: changing the line from "file:/$ " to "file:$ " got rid of the problem. seems like that forward slash would not be necessary anyways as the environment variable (if defined) should point to an absolute path
[14:35:43 CST(-0600)] <cwaymire> perhaps it was interpreting file:// as a remote url?
[14:35:46 CST(-0600)] <EricDalquist> yes
[14:35:49 CST(-0600)] <EricDalquist> that was my guess
[14:35:58 CST(-0600)] <EricDalquist> XXX:// implies network protocol
[14:36:07 CST(-0600)] <cwaymire> yep.
[14:36:29 CST(-0600)] <cwaymire> ok. i'll get with drew and get it tested out and then submit a fix
[14:36:41 CST(-0600)] <cwaymire> want to test it on windows to be sure
[14:38:22 CST(-0600)] <EricDalquist> yup
[14:38:26 CST(-0600)] <EricDalquist> I appreciate that
[14:40:50 CST(-0600)] <cwaymire> EricDalquist: any idea why that problem would manifest for me, and not for drew and apparently not for james either? and you said it worked fine for you on xubuntu?
[14:41:09 CST(-0600)] <EricDalquist> could be your local network
[14:41:18 CST(-0600)] <EricDalquist> like maybe unicon's firewall caused the connection to hang
[14:41:25 CST(-0600)] <EricDalquist> but for others it just fails?
[14:41:45 CST(-0600)] <cwaymire> hrmmm yeah possibly
[14:42:03 CST(-0600)] <cwaymire> but not sure then why drew didnt have that issue nor james. we're all on the same network.
[14:42:17 CST(-0600)] <cwaymire> not that important I guess at this juncture. just glad to be rid of it.
[14:44:47 CST(-0600)] <jwennmacher> EricDalquist: Did you want me to check with Dima? I'm not sure who that is.
[14:45:21 CST(-0600)] <EricDalquist> oh yeah ... Dimitry K. he is a uniconver
[14:45:25 CST(-0600)] <EricDalquist> uniconer*
[14:45:33 CST(-0600)] <EricDalquist> works with bill thompson primarily on cas stuff I think
[14:45:46 CST(-0600)] <cwaymire> Dimitry is who I got the intellij license from
[14:46:07 CST(-0600)] <EricDalquist> yeah so he would be the point of contact to get a new license I believe
[14:46:12 CST(-0600)] <EricDalquist> if he isn't let me know again
[14:46:25 CST(-0600)] <EricDalquist> and we'll try and just setup a new contact point with intellij
[14:47:44 CST(-0600)] <cwaymire> I do know that anyone can submit for an intellij opensource license. you just have to demonstrate that you are a contributor on a project with at least 3 mos of recent activity. I imagine if the license expires and there's no plan/process in place to renew it then any commiter on the project can probably request for a license for the project.
[14:48:02 CST(-0600)] <EricDalquist> yeah
[14:48:16 CST(-0600)] <EricDalquist> we can probably be better about that and move it into the jasig infrastructure group
[14:48:24 CST(-0600)] <EricDalquist> or we can check with intellij
[14:48:39 CST(-0600)] <EricDalquist> they might just want each person to request their own
[14:48:57 CST(-0600)] <cwaymire> I requested one before I knew unicon had one. They directed me to Dimitry to request the JASIG license