Okay, I finally figured out what I was doing, and would like to change
the issue to one on logging.
My SocketManager.service() method was execing code that should have been
in initialize. I was using a variable that is set in configure().
The reason it took me so long to find is that I was throwing a
ServiceException, but it was not being logged. Code follows:
public void service (ServiceManager manager) throws ServiceException
{
...
if (!m_manager.hasService(m_handler)) {
throw new ServiceException ("Handler, " + m_handler
+ ", is not valid.");
}
...
}
I expected my exception to cause some kind of log event, but there isn't
any. I inserted a logging line just before the throw and then from there
it all made sense. Mostly this is my fault for being an Avalon novice,
but I'm at a loss for why ServiceException disappears into the framework
ether.
Corey
On Tue, 2002-09-10 at 21:19, Corey Jewett wrote:
> I'm going to trim out the less relevant stuff for size, if you need the
> full files let me know. I also rebuilt fortress off of tonights CVS just
> to be sure.
>
> public class Manager extends DaemonService implements Configurable,
> Initializable {
>
> ...
> /** Called when DaemonService is started. */
> public boolean startup () {
> ... sanity checks, logs and returns false on failure.
>
> // m_servers is a vector of strings from configure().
> for (int i = 0; i < m_servers.size(); i++) {
> String s = m_servers.elementAt(i).toString();
>
> if (getLogger().isDebugEnabled()) {
> getLogger().debug("Attempting to lookup: " + s);
> }
>
> try {
> //TODO: Figure out why components are not initializing on lookup.
> // Otherwise save the configuration and perform lifecycle here???
> m_servers.setElementAt(m_manager.lookup(s), i);
>
> if (getLogger().isDebugEnabled()) {
> getLogger().debug("Found SocketManager: " + s);
> }
>
> } catch (ServiceException se) {
> ... returns false after logging.
> }
>
> ... generate log
> }
>
> ... generate log
> return true;
> }
>
> ...
> }
>
> public abstract class DaemonService extends StartableService {
> ...
> }
>
> public abstract class StartableService extends AbstractLogEnabled
> implements Runnable, Serviceable, Startable {
> ... complete class attached.
> }
>
> /** This class is looked up by Manager, it should be seeing the full
> lifecycle, but is not. */
> public class SocketManager extends StartableService implements
> Configurable {
> ... complete class attached.
> }
>
> Finally I have two logs, both at the debug level. The first is my code,
> axrs.sm-http should have logs indicating SocketManager: configure(),
> run(); and StartableService: service(), start(). Instead only the
> service() log appears.
>
> DEBUG 2002-09-10 21:02:01.090 [axrs ] (): No
> Container.EXTENSION_MANAGER is given, installing default lifecycle
> extension manager with 0 extensions
> DEBUG 2002-09-10 21:02:01.178 [axrs ] ():
> Component axrs.SocketManager uses handler
> org.apache.excalibur.fortress.handler.PerThreadComponentHandler
> DEBUG 2002-09-10 21:02:01.187 [axrs ] ():
> Component axrs.Manager uses handler
> org.apache.excalibur.fortress.handler.PerThreadComponentHandler
> DEBUG 2002-09-10 21:02:01.210 [axrs.manager ] ():
> Being serviced.
> DEBUG 2002-09-10 21:02:01.211 [axrs.manager ] ():
> Being configured.
> DEBUG 2002-09-10 21:02:01.211 [axrs.manager ] ():
> Being initialized.
> DEBUG 2002-09-10 21:02:01.212 [axrs.manager ] ():
> Manager has: axrs.SocketManager
> DEBUG 2002-09-10 21:02:01.212 [axrs.manager ] ():
> Initialized.
> DEBUG 2002-09-10 21:02:01.212 [axrs.manager ] ():
> Started
> DEBUG 2002-09-10 21:02:01.214 [axrs.manager ] ():
> Starting up.
> DEBUG 2002-09-10 21:02:01.214 [axrs.manager ] ():
> Attempting to lookup: axrs.SocketManager
> DEBUG 2002-09-10 21:02:01.219 [axrs.sm-http ] ():
> Being serviced.
> DEBUG 2002-09-10 21:02:01.220 [axrs.manager ] ():
> Found SocketManager: axrs.SocketManager
> DEBUG 2002-09-10 21:02:01.220 [axrs.manager ] ():
> Found: axrs.SocketManager
> DEBUG 2002-09-10 21:02:01.221 [axrs.manager ] ():
> Started.
> DEBUG 2002-09-10 21:02:01.221 [axrs.manager ] ():
> Running
> DEBUG 2002-09-10 21:02:01.221 [axrs.manager ] ():
> Going to sleep.
>
>
>
> For completeness I've also included the system log:
>
> DEBUG 2002-09-10 21:02:00.511 [axrs.system.roles.defaults ] ():
> setup role: name='cache', role='org.apache.excalibur.cache.Cache',
> class='org.apache.excalibur.cache.impl.DefaultCache',
> handler='org.apache.excalibur.fortress.handler.ThreadSafeComponentHandler'
> DEBUG 2002-09-10 21:02:00.630 [axrs.system.roles.defaults ] ():
> setup role: name='lru-cache', role='org.apache.excalibur.cache.Cache',
> class='org.apache.excalibur.cache.impl.LRUCache',
> handler='org.apache.excalibur.fortress.handler.ThreadSafeComponentHandler'
> DEBUG 2002-09-10 21:02:00.637 [axrs.system.roles.defaults ] ():
> setup role: name='jdbc-datasource',
> role='org.apache.avalon.excalibur.datasource.DataSourceComponent',
> class='org.apache.avalon.excalibur.datasource.JdbcDataSource',
> handler='org.apache.excalibur.fortress.handler.ThreadSafeComponentHandler'
> DEBUG 2002-09-10 21:02:00.644 [axrs.system.roles.defaults ] ():
> setup role: name='j2ee-datasource',
> role='org.apache.avalon.excalibur.datasource.DataSourceComponent',
> class='org.apache.avalon.excalibur.datasource.J2eeDataSource',
> handler='org.apache.excalibur.fortress.handler.ThreadSafeComponentHandler'
> DEBUG 2002-09-10 21:02:00.645 [axrs.system.roles.defaults ] ():
> setup role: name='informix-datasource',
> role='org.apache.avalon.excalibur.datasource.DataSourceComponent',
> class='org.apache.avalon.excalibur.datasource.InformixDataSource',
> handler='org.apache.excalibur.fortress.handler.ThreadSafeComponentHandler'
> DEBUG 2002-09-10 21:02:00.647 [axrs.system.roles.defaults ] ():
> setup role: name='i18n',
> role='org.apache.excalibur.xmlbundle.BundleSelector',
> class='org.apache.excalibur.xmlbundle.BundleSelector',
> handler='org.apache.excalibur.fortress.handler.ThreadSafeComponentHandler'
> DEBUG 2002-09-10 21:02:00.654 [axrs.system.roles.defaults ] ():
> setup role: name='monitor',
> role='org.apache.avalon.excalibur.monitor.Monitor',
> class='org.apache.avalon.excalibur.monitor.ActiveMonitor',
> handler='org.apache.excalibur.fortress.handler.ThreadSafeComponentHandler'
> DEBUG 2002-09-10 21:02:00.658 [axrs.system.roles.defaults ] ():
> setup role: name='passive-monitor',
> role='org.apache.avalon.excalibur.monitor.Monitor',
> class='org.apache.avalon.excalibur.monitor.PassiveMonitor',
> handler='org.apache.excalibur.fortress.handler.ThreadSafeComponentHandler'
> DEBUG 2002-09-10 21:02:00.660 [axrs.system.roles.defaults ] ():
> setup role: name='xalan-xpath',
> role='org.apache.avalon.excalibur.xml.xpath.XPathProcessor',
> class='org.apache.avalon.excalibur.xml.xpath.XPathProcessorImpl',
> handler='org.apache.excalibur.fortress.handler.ThreadSafeComponentHandler'
> DEBUG 2002-09-10 21:02:00.661 [axrs.system.roles.defaults ] ():
> setup role: name='jaxpath',
> role='org.apache.avalon.excalibur.xml.xpath.XPathProcessor',
> class='org.apache.avalon.excalibur.xml.xpath.JaxenProcessorImpl',
> handler='org.apache.excalibur.fortress.handler.ThreadSafeComponentHandler'
> DEBUG 2002-09-10 21:02:00.663 [axrs.system.roles.defaults ] ():
> setup role: name='resolver',
> role='org.apache.excalibur.source.SourceResolver',
> class='org.apache.excalibur.source.impl.SourceResolverImpl',
> handler='org.apache.excalibur.fortress.handler.ThreadSafeComponentHandler'
> DEBUG 2002-09-10 21:02:00.672 [axrs.system.roles.defaults ] ():
> setup role: name='parser',
> role='org.apache.avalon.excalibur.xml.Parser',
> class='org.apache.avalon.excalibur.xml.JaxpParser',
> handler='org.apache.excalibur.fortress.handler.PerThreadComponentHandler'
> DEBUG 2002-09-10 21:02:00.674 [axrs.system.roles.defaults ] ():
> setup role: name='xerces-parser',
> role='org.apache.avalon.excalibur.xml.Parser',
> class='org.apache.avalon.excalibur.xml.XercesParser',
> handler='org.apache.excalibur.fortress.handler.FactoryComponentHandler'
> DEBUG 2002-09-10 21:02:00.684 [axrs.system.roles ] ():
> setup role: name='http-handler', role='axrs.handlers.HTTPHandler',
> class='axrs.handlers.HTTPHandler',
> handler='org.apache.excalibur.fortress.handler.PerThreadComponentHandler'
> DEBUG 2002-09-10 21:02:00.685 [axrs.system.roles ] ():
> setup role: name='sm-standard', role='axrs.SocketManager',
> class='axrs.SocketManager',
> handler='org.apache.excalibur.fortress.handler.PerThreadComponentHandler'
> DEBUG 2002-09-10 21:02:00.692 [axrs.system.roles ] ():
> setup role: name='manager', role='axrs.Manager', class='axrs.Manager',
> handler='org.apache.excalibur.fortress.handler.PerThreadComponentHandler'
> DEBUG 2002-09-10 21:02:00.930 [axrs.system.instrument ] ():
> Registering Instrumentable: instrument-manager
> DEBUG 2002-09-10 21:02:00.957 [axrs.system.instrument ] ():
> Registering Instrument: instrument-manager.total-memory
> DEBUG 2002-09-10 21:02:01.005 [axrs.system.instrument ] ():
> Registering Instrument: instrument-manager.free-memory
> DEBUG 2002-09-10 21:02:01.012 [axrs.system.instrument ] ():
> Registering Instrument: instrument-manager.memory
> DEBUG 2002-09-10 21:02:01.018 [axrs.system.instrument ] ():
> Registering Instrument: instrument-manager.active-thread-count
> DEBUG 2002-09-10 21:02:01.096 [axrs.system.roles ] ():
> looking up class with shorthand 'sm-standard' returning
> 'axrs.SocketManager'
> DEBUG 2002-09-10 21:02:01.103 [axrs.system.roles ] ():
> looking up handler class with class 'axrs.SocketManager' returning
> 'org.apache.excalibur.fortress.handler.PerThreadComponentHandler'
> DEBUG 2002-09-10 21:02:01.110 [axrs.system.roles ] ():
> looking up role with class 'axrs.SocketManager' returning
> 'axrs.SocketManager'
> DEBUG 2002-09-10 21:02:01.151 [axrs.system.instrument ] ():
> Registering Instrumentable: PerThreadComponentHandler
> DEBUG 2002-09-10 21:02:01.158 [axrs.system.instrument ] ():
> Registering Child Instrumentable: PerThreadComponentHandler.sm-http
> DEBUG 2002-09-10 21:02:01.165 [axrs.system.instrument ] ():
> Registering Instrument: PerThreadComponentHandler.sm-http.creates
> DEBUG 2002-09-10 21:02:01.171 [axrs.system.instrument ] ():
> Registering Instrument: PerThreadComponentHandler.sm-http.destroys
> DEBUG 2002-09-10 21:02:01.180 [axrs.system.roles ] ():
> looking up class with shorthand 'manager' returning 'axrs.Manager'
> DEBUG 2002-09-10 21:02:01.185 [axrs.system.roles ] ():
> looking up handler class with class 'axrs.Manager' returning
> 'org.apache.excalibur.fortress.handler.PerThreadComponentHandler'
> DEBUG 2002-09-10 21:02:01.185 [axrs.system.roles ] ():
> looking up role with class 'axrs.Manager' returning 'axrs.Manager'
> DEBUG 2002-09-10 21:02:01.186 [axrs.system.instrument ] ():
> Registering Instrumentable: PerThreadComponentHandler
> DEBUG 2002-09-10 21:02:01.186 [axrs.system.instrument ] ():
> Registering Child Instrumentable: PerThreadComponentHandler.manager
> DEBUG 2002-09-10 21:02:01.187 [axrs.system.instrument ] ():
> Registering Instrument: PerThreadComponentHandler.manager.creates
> DEBUG 2002-09-10 21:02:01.187 [axrs.system.instrument ] ():
> Registering Instrument: PerThreadComponentHandler.manager.destroys
> DEBUG 2002-09-10 21:02:01.199 [axrs.system.handler.perthread ] ():
> ComponentHandler initialized for: axrs.Manager
> DEBUG 2002-09-10 21:02:01.200 [axrs.system.factory ] ():
> ComponentFactory creating new instance of axrs.Manager.
> DEBUG 2002-09-10 21:02:01.200 [axrs.system.factory ] ():
> logger attribute is manager
> DEBUG 2002-09-10 21:02:01.215 [axrs.system.handler.perthread ] ():
> ComponentHandler initialized for: axrs.SocketManager
> DEBUG 2002-09-10 21:02:01.218 [axrs.system.factory ] ():
> ComponentFactory creating new instance of axrs.SocketManager.
> DEBUG 2002-09-10 21:02:01.218 [axrs.system.factory ] ():
> logger attribute is sm-http
>
>
>
> On Tue, 2002-09-10 at 05:26, Berin Loritsch wrote:
> > Hmmm. I will double check the code--it should be functioning
> > properly. I would like to ask to to make sure that there was
> > no exceptions thrown durring Configurable or Serviceable stages.
> >
> > > -----Original Message-----
> > > From: Corey Jewett [mailto:[EMAIL PROTECTED]]
> > > Sent: Tuesday, September 10, 2002 12:24 AM
> > > To: [EMAIL PROTECTED]
> > > Subject: [Fortress] Lifecycle not running.
> > >
> > >
> > > I am probably totally overlooking something, but here goes...
> > >
> > > I have a class SocketManager:
> > >
> > > public class SocketManager extends StartableService
> > > implements Configurable {
> > > ...
> > > }
> > >
> > > StartableService looks like this:
> > >
> > > public abstract class StartableService extends AbstractLogEnabled
> > > implements Runnable, Serviceable, Startable {
> > > ...
> > > }
> > >
> > > My understanding is that when I lookup SocketManager (which is
> > > successful) then configure(), service(), and start() should be called.
> > >
> > > Instead, according to my logs it's only being serviced. Any
> > > pointers would be appreciated.
> > >
> > > Corey
> > >
> > >
> > > --
> > > To unsubscribe, e-mail:
> > > <mailto:avalon-users-> [EMAIL PROTECTED]>
> > > For
> > > additional commands,
> > > e-mail: <mailto:[EMAIL PROTECTED]>
> > >
> >
> >
> > --
> > To unsubscribe, e-mail: <mailto:[EMAIL PROTECTED]>
> > For additional commands, e-mail: <mailto:[EMAIL PROTECTED]>
> >
>
> ----
>
> package axrs;
>
> import java.io.IOException;
> import java.net.InetAddress;
> import java.net.ServerSocket;
> import java.net.Socket;
> import java.net.UnknownHostException;
>
> import org.apache.avalon.framework.configuration.Configurable;
> import org.apache.avalon.framework.configuration.Configuration;
> import org.apache.avalon.framework.configuration.ConfigurationException;
> import org.apache.avalon.framework.service.Serviceable;
> import org.apache.avalon.framework.service.ServiceException;
> import org.apache.avalon.framework.service.ServiceManager;
>
> /**
> * Each SocketDirector manages a serverSocket and directs all incoming requests
> * to the appropriate protohandler.
> *
> * @todo Add inet addy based ACLs here.
> * @todo Need to enable Secure Sockets, or a hook for subclassing.
> */
> public class SocketManager extends StartableService implements Configurable {
>
> static String ROLE = "axrs.SocketManager";
>
> /** The port for ServerSocket to bind to. */
> protected int m_port = -1;
>
> /** Set to ServerSocket default of 50, if not set in configuration. */
> protected int m_backlog = 50;
>
> /** If not specified then invoke ServerSocket(port) and bind to default. */
> protected InetAddress m_inetaddr = null;
>
> /** The shorthand of the sockethandler to pass incoming sockets to. */
> protected String m_handler = null;
>
> /** The ServerSocket */
> protected ServerSocket m_socket = null;
>
> /** Set if the component is configured. */
> protected boolean m_configured = false;
>
> /** The unique name of this instance. */
> protected String m_name = null;
>
> /** NOP */
> public SocketManager () {}
>
> /**
> * Expects a configuration with the following attributes:
> * + name (String) Required, the unique name of the socketmanager.
> * + port (int) Required, the port to bind to.
> * + backlog (int) Optional, defaults to 50, see ServerSocket docs.
> * + inetaddr (String) Optional, the InetAddress to bind to.
> * + so_timeout (int) Optional, interval for ServerSocket to unblock,
> * if set it should be > 0.
> *
> * Additionally a single nested element which is the handler for the socket.
> * The nested element may itself have attributes or nested elements that
> * define it's configuration, if any.
> */
> public void configure (Configuration conf) throws ConfigurationException {
> if (m_configured) {
> throw new ConfigurationException ("Already configured.");
> }
>
> if (getLogger().isDebugEnabled()) {
> getLogger().debug("Being configured.");
> }
>
> // what is my backlog?
> m_backlog = conf.getAttributeAsInteger("backlog", m_backlog);
>
> // what is my inet?
> String ia = conf.getAttribute("inetaddr", null);
> if (ia != null) {
> try {
> m_inetaddr = InetAddress.getByName(ia);
> } catch (UnknownHostException uhe) {
> throw new ConfigurationException("Unknown Host: " + ia);
> }
> } else {
> if (getLogger().isWarnEnabled()) {
> getLogger().warn("No inetaddr, did you mean to do this?");
> }
> }
>
> // What's my name?
> m_name = conf.getAttribute("name", null);
> if (m_name == null) {
> throw new ConfigurationException("Name not specified.");
> }
>
> // what is my port?
> m_port = conf.getAttributeAsInteger("port", -1);
> if (m_port == -1) {
> throw new ConfigurationException("Port not defined.");
> }
>
> // what is my handler?
> m_handler = conf.getAttribute("protohandler", null);
> if (m_handler == null) {
> throw new ConfigurationException("No handler specified.");
> }
>
> if (getLogger().isDebugEnabled()) {
> getLogger().debug(conf.getName() + " configured.");
> }
>
> // Configuration was valid.
> m_configured = true;
> }
>
> public void service (ServiceManager manager) throws ServiceException {
> super.service(manager);
>
> // Can the handler be loaded?
> if (!m_manager.hasService(m_handler)) {
> throw new ServiceException ("Handler, " + m_handler
> + ", is not valid.");
> }
>
> // Preempt any lazy loading of the handler to confirm it's usability.
> m_manager.release(m_manager.lookup(m_handler));
> }
>
> public void run () {
> m_executing = false; // until configuration verified.
> if (!m_configured) {
> getLogger().fatalError(
> "Attempted execution of SocketRunner w/o configuring.");
> return;
> }
>
> // Instantiate socket using inet?
> try {
> if (m_inetaddr != null) {
> m_socket = new ServerSocket(m_port, m_backlog, m_inetaddr);
> } else {
> m_socket = new ServerSocket(m_port, m_backlog);
> }
> } catch (IOException ioe) {
> getLogger().fatalError("Unable to create ServerSocket.", ioe);
> }
>
> // ServerSocket was properly configured, so now we're executing.
> m_executing = true;
>
> if (getLogger().isDebugEnabled()) {
> getLogger().debug("ServerSocket configured, beginning to accept
>connections.");
> }
>
> // Start accepting connections.
> while (m_executing) {
> try {
> Socket s = m_socket.accept();
>
> //TODO: Need to fork off the SocketHandler in a runner.
> SocketHandler sh = retrieveHandler();
> sh.handle(s);
>
> } catch (IOException ioe) {
> if (!m_executing) {
> // SO_TIMEOUT, m_socket is still alive, but dying.
> // Time to close the socket.
> try {
> m_socket.close();
> } catch (IOException ioe2) {
> getLogger().warn("Failed to close socket.", ioe2);
> }
> } else {
> getLogger().error("Socket closed unexpectedly.", ioe);
> m_executing = false;
> }
> } catch (Exception e) {
> getLogger().fatalError("Problems retrieving handler.", e);
> m_executing = false;
> }
> }
> }
>
>
> /**
> * Hook for extending the SocketManager to add SocketHandlers. Note only
> * extend this method if specifying the appropriate
> */
> protected SocketHandler retrieveHandler () throws Exception {
> return (SocketHandler)m_manager.lookup(m_handler);
> }
> }
> ----
>
> package axrs;
>
> import org.apache.avalon.framework.activity.Startable;
> import org.apache.avalon.framework.logger.AbstractLogEnabled;
> import org.apache.avalon.framework.service.Serviceable;
> import org.apache.avalon.framework.service.ServiceException;
> import org.apache.avalon.framework.service.ServiceManager;
>
> /**
> * Extending classes will implicitly be spawned as a separate thread.
> *
> * TODO: Funny as it is, this class is not threadsafe. Needs a mutex.
> *
> * @author <a href="mailto:[EMAIL PROTECTED]";>Corey Jewett</a>
> * @version CVS $Revision: 1.2 $ $Date: 2002/08/02 20:22:54 $
> */
> public abstract class StartableService extends AbstractLogEnabled
> implements Runnable, Serviceable, Startable {
>
> /** Set if the component is executing. */
> protected boolean m_executing = false;
>
> /** The executing thread of server. */
> protected Thread m_thread = null;
>
> /** Set if the component has been serviced. */
> protected boolean m_serviced = false;
>
> /** The ServiceManager, if we've been serviced. */
> protected ServiceManager m_manager = null;
>
> /** If we're not already serviced, and the manager is not null... */
> public void service (ServiceManager manager) throws ServiceException {
> if (m_serviced) {
> if (getLogger().isDebugEnabled()) {
> getLogger().debug("Already been serviced.");
> }
>
> return;
> }
>
> if (manager != null) {
> if (getLogger().isDebugEnabled()) {
> getLogger().debug("Being serviced.");
> }
>
> m_serviced = true;
> m_manager = manager;
> }
> }
>
> /**
> * Starts the container, implicitly invokes run() in a new thread.
> * Guarantees that the container is in a startable state, sets m_executing
> * to true, and create/starts m_thread.
> */
> public void start () {
> if (m_thread != null) {
> if (getLogger().isErrorEnabled()) {
> getLogger().error("Already started.");
> }
>
> return;
> }
>
> if (getLogger().isDebugEnabled()) {
> getLogger().debug("Started");
> }
>
> m_executing = true;
> m_thread = new Thread(this);
> m_thread.start();
> }
>
> /**
> * Interrupts the thread in run().
> * Guarantees that the container is in a stopable state (i.e. it was
> * properly started at some earlier time.), Calls m_thread.interrupt(),
> * sets m_executing to false. Note that m_thread is NOT set to null, that
> * is the responsiblity of run().
> * @see run()
> */
> public void stop () {
> if (!m_executing) {
> if (getLogger().isErrorEnabled()) {
> getLogger().error("Never started.");
> }
>
> return;
> }
>
> if (getLogger().isDebugEnabled()) {
> getLogger().debug("Shutdown initiated.");
> }
>
> m_thread.interrupt();
> m_executing = false;
> }
>
> /**
> * Contains the logic for subclass execution. Responsible for confirming:
> * that m_executing == true before executing any logic, that m_thread =
> * null if the logic finishes normally (the container may immediately be
> * restarted).
> * @see start()
> */
> public abstract void run ();
> }
>
> ----
>
> --
> To unsubscribe, e-mail: <mailto:[EMAIL PROTECTED]>
> For additional commands, e-mail: <mailto:[EMAIL PROTECTED]>
--
To unsubscribe, e-mail: <mailto:[EMAIL PROTECTED]>
For additional commands, e-mail: <mailto:[EMAIL PROTECTED]>
