Skip to end of metadata
Go to start of metadata

You are viewing an old version of this page. View the current version.

Compare with Current View Page History

« Previous Version 30 Current »

[03:21:12 EDT(-0400)] * lfuller (~sparhk@wsip-72-215-204-133.ph.ph.cox.net) has left ##uportal
[08:39:27 EDT(-0400)] * michelled (~michelled@142.150.154.101) has joined ##uportal
[08:41:27 EDT(-0400)] * jessm (~Jess@c-71-232-3-151.hsd1.ma.comcast.net) has joined ##uportal
[10:20:25 EDT(-0400)] * EricDalquist (~dalquist@2607:f388:e:0:221:9bff:fe37:e768) has joined ##uportal
[10:41:01 EDT(-0400)] <athena> hey EricDalquist - there seems to be a weird bug with the portal stats db logging
[10:41:11 EDT(-0400)] <athena> such that initdb doesn't work if you have it turned on
[10:41:18 EDT(-0400)] <EricDalquist> weird
[10:41:27 EDT(-0400)] <athena> it looks like the stats recorder is running during the db import and causing the failure, sort of
[10:41:31 EDT(-0400)] <athena> let me paste the stack trace
[10:42:23 EDT(-0400)] <athena> http://uportal.pastebin.com/acB2UCcJ
[10:42:32 EDT(-0400)] <athena> do you have any suggestions as to what to do about it?
[10:43:19 EDT(-0400)] <EricDalquist> hrm
[10:43:22 EDT(-0400)] <EricDalquist> well it should work
[10:43:32 EDT(-0400)] <EricDalquist> the stats code should be setup to log but swallow exceptions
[10:43:41 EDT(-0400)] <EricDalquist> so that a stats failure doesn't take down the portal
[10:43:46 EDT(-0400)] <athena> gotcha
[10:43:56 EDT(-0400)] <athena> right now it seems to be breaking the build
[10:44:05 EDT(-0400)] <athena> or maybe it's not
[10:44:15 EDT(-0400)] <athena> but it seemed like it was
[10:44:18 EDT(-0400)] <EricDalquist> do you actually end with a build failure?
[10:44:30 EDT(-0400)] <EricDalquist> so it looks like the events are getting queued
[10:44:42 EDT(-0400)] <EricDalquist> but there isn't a flush call before context shutdown
[10:44:46 EDT(-0400)] <athena> yeah let me try it again and see
[10:44:47 EDT(-0400)] <EricDalquist> so destroy tries to do a flush
[10:44:54 EDT(-0400)] <EricDalquist> but not all of the needed beans are available
[10:45:00 EDT(-0400)] <athena> gotcha
[10:45:09 EDT(-0400)] <EricDalquist> due to the terribleness of the static groups code
[10:45:23 EDT(-0400)] <athena> lol
[10:45:31 EDT(-0400)] <athena> the horror (smile)
[10:58:02 EDT(-0400)] * holdorph (~holdorph@wsip-72-215-204-133.ph.ph.cox.net) has joined ##uportal
[11:02:16 EDT(-0400)] * colinclark (~colin@142.150.154.101) has joined ##uportal
[11:34:19 EDT(-0400)] * lfuller (~sparhk@wsip-72-215-204-133.ph.ph.cox.net) has joined ##uportal
[11:47:33 EDT(-0400)] * colinclark (~colin@142.150.154.101) has joined ##uportal
[11:49:22 EDT(-0400)] <athena> yeah, i guess all the channels really did import
[11:49:37 EDT(-0400)] <athena> i guess i can just tell the user that there's nothing really wrong and to ignore the stack trace?
[11:49:50 EDT(-0400)] <EricDalquist> yeah, not optimal
[11:49:57 EDT(-0400)] <EricDalquist> but functionally its fine
[11:55:33 EDT(-0400)] * colinclark (~colin@142.150.154.148) has joined ##uportal
[12:09:34 EDT(-0400)] * awills (~awills@wsip-72-215-204-133.ph.ph.cox.net) has joined ##uportal
[13:03:23 EDT(-0400)] * Sememmon (~Sememmon@unaffiliated/sememmon) has joined ##uportal
[13:25:21 EDT(-0400)] * Sememmon (~Sememmon@unaffiliated/sememmon) has joined ##uportal
[13:46:43 EDT(-0400)] * michelled (~michelled@142.150.154.101) has joined ##uportal
[14:02:31 EDT(-0400)] <awills> is anyone else seeing these? (apologies if this is oft-discussed) http://uportal.pastebin.com/KJimxu95
[14:03:22 EDT(-0400)] * colinclark (~colin@142.150.154.148) has joined ##uportal
[14:04:28 EDT(-0400)] <EricDalquist> awills: that's usually from a timeout
[14:04:38 EDT(-0400)] <EricDalquist> so the portlet thread is still running in the background
[14:04:45 EDT(-0400)] <EricDalquist> but the request & response are no longer valid
[14:05:06 EDT(-0400)] <awills> rendering timeout then? not session timeout
[14:05:11 EDT(-0400)] <EricDalquist> yeah
[14:06:17 EDT(-0400)] <awills> anyone planning an enhancement to prevent the stack trace?
[14:06:27 EDT(-0400)] <awills> you just worked on this for 3.3 right?
[14:06:37 EDT(-0400)] <EricDalquist> will be for 3.3
[14:06:40 EDT(-0400)] <EricDalquist> haven't yet
[14:06:56 EDT(-0400)] <EricDalquist> the plan would be to add logic to the request/response wrappers passed to pluto
[14:07:07 EDT(-0400)] <EricDalquist> that watches for a timeout boolean flag
[14:07:52 EDT(-0400)] <EricDalquist> when the renderer gives up on a thread set that flag so that further access of the request/response result in a 'good' exception
[14:08:22 EDT(-0400)] <awills> gotcha
[14:09:08 EDT(-0400)] <EricDalquist> no idea what it would take in 3.0-3.2
[14:09:14 EDT(-0400)] <EricDalquist> I don't think it would be terribly difficult
[14:09:22 EDT(-0400)] <EricDalquist> but I've never looked into it
[14:09:23 EDT(-0400)] <athena> we might want to increase the default timeout for portlet publishing types in the meantime?
[14:10:27 EDT(-0400)] <EricDalquist> yeah
[14:10:30 EDT(-0400)] <awills> that makes sense, i think
[14:10:33 EDT(-0400)] <EricDalquist> 500ms is rather short
[14:10:35 EDT(-0400)] <awills> 5000?
[14:10:44 EDT(-0400)] <EricDalquist> maybe 1500
[14:10:47 EDT(-0400)] <awills> that's normally what many of us do
[14:10:56 EDT(-0400)] <EricDalquist> don't want the portal to appear slow to someone not familiar
[14:11:07 EDT(-0400)] <awills> true
[14:12:02 EDT(-0400)] <athena> 1500 sounds pretty reasonable
[14:12:12 EDT(-0400)] <athena> and is an easy change to make
[14:12:36 EDT(-0400)] <holdorph> 1.5 seconds ?
[14:12:56 EDT(-0400)] <EricDalquist> figure that would be reasonable if you're targeting 2 second page load times
[14:13:32 EDT(-0400)] <holdorph> who's targeting 2 second page load times?
[14:13:51 EDT(-0400)] <holdorph> that's a pretty aggressive goal, not one I hear too many trying to achieve
[14:13:58 EDT(-0400)] <holdorph> not impossible, but pretty aggressive
[14:14:04 EDT(-0400)] <EricDalquist> that's our front page goal
[14:14:31 EDT(-0400)] <EricDalquist> I think the all but one or two of the portlets on our home tab have a 2 second or smaller timeout
[14:15:05 EDT(-0400)] <holdorph> but we're talking about the defaults for all portlets included in the default distribution
[14:15:14 EDT(-0400)] <holdorph> not a finely tuned portal front page
[14:15:46 EDT(-0400)] <EricDalquist> defaults for new portlets
[14:16:13 EDT(-0400)] <holdorph> ok. still i would make the same point
[14:16:18 EDT(-0400)] <EricDalquist> I don't think we're having issues with the defaults for the published portlets
[14:16:23 EDT(-0400)] <holdorph> we're talking about the generic case, not a finely tuned case.
[14:16:30 EDT(-0400)] <awills> i'm good with anything 1.5 to 5... any bump is better than the status quo
[14:16:36 EDT(-0400)] <EricDalquist> true
[14:17:27 EDT(-0400)] <holdorph> I'd probably bump it to at least 5 seconds, I'd probably even consider 10 seconds. it's not hard to change back down, if someone feels like they have a 'rogue' portlet that's running too much
[14:29:29 EDT(-0400)] * EricDalquist (~dalquist@2607:f388:e:0:221:9bff:fe37:e768) has joined ##uportal
[14:30:37 EDT(-0400)] * colinclark_ (~colin@142.150.154.101) has joined ##uportal
[16:25:53 EDT(-0400)] <awills> EricDalquist – what do you think of a patch like this for the stack trace i brought up earlier...http://uportal.pastebin.com/3zigXekC
[16:27:34 EDT(-0400)] <EricDalquist> I don't think you could swallow the exception like that
[16:28:06 EDT(-0400)] <EricDalquist> since if no exception is thrown I think the portal expects the channel to have rendered correctly
[16:28:15 EDT(-0400)] <EricDalquist> you could wrap the thrown exception in case of timeout
[16:28:21 EDT(-0400)] <awills> look at UserInstanceManagerImpl 96-98... does something similar
[16:28:33 EDT(-0400)] <EricDalquist> I don't have uPortal source handy right now ...
[16:29:23 EDT(-0400)] <awills> what use can uP have for it, if the respose is already sent? you thinking of rendering cache?
[16:29:50 EDT(-0400)] <EricDalquist> I'm thinking CError
[16:30:05 EDT(-0400)] <EricDalquist> the error handling may not display correctly if you don't re-throw there
[16:30:14 EDT(-0400)] <awills> but this is in a situation where the channel has already timed out
[16:30:42 EDT(-0400)] <EricDalquist> ah true
[16:30:55 EDT(-0400)] <EricDalquist> I would recommend at least logging the exception though
[16:31:07 EDT(-0400)] <EricDalquist> I really dislike code that has an exception and chooses not to log it
[16:31:26 EDT(-0400)] <awills> ah i follow... is debug good enough?
[16:31:34 EDT(-0400)] <EricDalquist> if you don't want to scare people with a stack trace have info just log the message with e.tostring
[16:31:42 EDT(-0400)] <EricDalquist> and debug log message, e
[16:32:12 EDT(-0400)] <awills> b/c the reason i'm looking at it is specifically to get the stack trace out of portal.log, if it's (essentially) benign
[16:32:31 EDT(-0400)] <EricDalquist> right
[16:32:31 EDT(-0400)] <awills> yeah info() the msg, then debug() the stack trace sounds good
[16:32:44 EDT(-0400)] <EricDalquist> maybe even WARN the message
[16:32:49 EDT(-0400)] <EricDalquist> since timeouts are bad things
[16:33:07 EDT(-0400)] <EricDalquist> I realize you get the info from CError too
[16:33:37 EDT(-0400)] <awills> so like this: http://uportal.pastebin.com/Mt2Te689
[16:33:47 EDT(-0400)] <awills> yeah WARN is good
[16:33:53 EDT(-0400)] <EricDalquist> log.debug(ise) should be log.debug(ise, ise)
[16:34:03 EDT(-0400)] <EricDalquist> the first argument is always the message
[16:34:14 EDT(-0400)] <EricDalquist> if you want a stack trace you have to have a 2nd arg
[16:34:42 EDT(-0400)] <awills> log.debug(ise.getMessage(), ise);
[16:35:02 EDT(-0400)] <EricDalquist> yeah that will work too
[16:35:17 EDT(-0400)] <EricDalquist> commons logging does a toString on the first arg
[16:35:20 EDT(-0400)] <awills> great... i'll sanity check it here
[16:35:29 EDT(-0400)] <EricDalquist> and for most exception types toString == getMessage
[16:35:38 EDT(-0400)] <awills> gotcha
[16:37:54 EDT(-0400)] <awills> what's the semaphore doing there... it's a really long method... can't see all moving parts
[16:39:00 EDT(-0400)] <EricDalquist> grouped rendering
[16:39:16 EDT(-0400)] <EricDalquist> uportal channels have this ability to sync groups of them rendering on a page
[16:39:28 EDT(-0400)] <EricDalquist> so you can make Channels A & B complete rendering before going on to C
[16:39:42 EDT(-0400)] <EricDalquist> so much code that just gets deleted for 3.3 (big grin)
[16:39:45 EDT(-0400)] <awills> how many use that feature?
[16:39:55 EDT(-0400)] <EricDalquist> I think you need it for ICC
[16:39:59 EDT(-0400)] <EricDalquist> but don't touch it
[16:40:09 EDT(-0400)] <EricDalquist> other parts of the framework do depend on it being there even if not used
[16:40:13 EDT(-0400)] <EricDalquist> and you can deadlock things (tongue)
[16:40:57 EDT(-0400)] <awills> yeah no good... what i'm wondering is whether i really need a separate try/catch for this... rather than merely adding a chatch to the existing try
[16:53:35 EDT(-0400)] <awills> umm... i don't think that other catch block does anything
[16:54:01 EDT(-0400)] <awills> the groupRenderingKey is always already checked-in by the time you get there
[16:54:54 EDT(-0400)] <awills> oops, misspoke: the "this.setException(e);" part does something, but the semaphore stuff looks to be a no-op
[16:58:30 EDT(-0400)] * michelled (~michelled@142.150.154.101) has joined ##uportal
[16:59:11 EDT(-0400)] * michelled_ (~michelled@142.150.154.101) has joined ##uportal
[18:58:00 EDT(-0400)] * Sememmon (~Sememmon@unaffiliated/sememmon) has joined ##uportal
[21:33:12 EDT(-0400)] * michelled (~michelled@CPE001310472ade-CM0011aefd3ca8.cpe.net.cable.rogers.com) has joined ##uportal

  • No labels