Am having some difficulty getting OpenMRS up and debugging, but I just downloaded the official 1.8.2 WAR from the website, removed all the modules, restarted tomcat, and added HTML form entry using the download from web option. Below is what I see with debug level logging switched on... I'm pretty confused... the module starts up fine.
DEBUG - ModuleListController.onSubmit(206) |2011-12-19 12:22:40,844| Module id: htmlformentry DEBUG - ModuleClassLoader.getUrls(207) |2011-12-19 12:22:40,853| Expanding /lib folder in module DEBUG - ModuleUtil.expandJar(478) |2011-12-19 12:22:40,855| Creating parent dirs: /tmp/tomcat6-tmp/1324289787118.openmrs-lib-cache/htmlformentry/lib DEBUG - ModuleUtil.expandJar(478) |2011-12-19 12:22:40,856| Creating parent dirs: /tmp/tomcat6-tmp/1324289787118.openmrs-lib-cache/htmlformentry/lib DEBUG - ModuleUtil.expand(524) |2011-12-19 12:22:40,856| expanding: lib/htmlformentry-api-1.8.1.jar DEBUG - ModuleClassLoader.getUrls(217) |2011-12-19 12:22:40,863| Adding file to results: /tmp/tomcat6-tmp/1324289787118.openmrs-lib-cache/htmlformentry/lib/htmlformentry-api-1.8.1.jar DEBUG - ModuleClassLoader.<init>(82) |2011-12-19 12:22:40,864| URLs length: 2 DEBUG - ModuleFactory.getExtensions(984) |2011-12-19 12:22:40,866| Getting extensions defined by : org.openmrs.admin.list|html DEBUG - ModuleFactory.startModuleInternal(489) |2011-12-19 12:22:40,866| Adding to mapping ext: org.openmrs.admin.list|html ext.class: class org.openmrs.module.htmlformentry.extension.html.AdminList DEBUG - ModuleFactory.getExtensions(984) |2011-12-19 12:22:40,866| Getting extensions defined by : org.openmrs.module.web.extension.FormEntryHandler|html DEBUG - ModuleFactory.startModuleInternal(489) |2011-12-19 12:22:40,867| Adding to mapping ext: org.openmrs.module.web.extension.FormEntryHandler|html ext.class: class org.openmrs.module.htmlformentry.extension.html.FormEntryHandlerExtension DEBUG - ModuleFactory.runDiff(649) |2011-12-19 12:22:40,882| version:column 1.0.0:1.2.0 DEBUG - ModuleFactory.runDiff(650) |2011-12-19 12:22:40,883| compare: -1 DEBUG - ModuleFactory.runDiff(649) |2011-12-19 12:22:40,887| version:column 1.1.0:1.2.0 DEBUG - ModuleFactory.runDiff(650) |2011-12-19 12:22:40,887| compare: -1 DEBUG - ModuleFactory.runDiff(649) |2011-12-19 12:22:40,913| version:column 1.2.0:1.2.0 DEBUG - ModuleFactory.runDiff(650) |2011-12-19 12:22:40,913| compare: 0 INFO - LoggingAdvice.invoke(109) |2011-12-19 12:22:40,928| In method AdministrationService.saveGlobalProperty. Arguments: GlobalProperty=property: htmlformentry.started value: true, INFO - LoggingAdvice.invoke(134) |2011-12-19 12:22:40,929| Exiting method saveGlobalProperty INFO - LoggingAdvice.invoke(109) |2011-12-19 12:22:41,046| In method AdministrationService.saveGlobalProperty. Arguments: GlobalProperty=property: htmlformentry.mandatory value: false, INFO - LoggingAdvice.invoke(134) |2011-12-19 12:22:41,047| Exiting method saveGlobalProperty *INFO - HtmlFormEntryActivator.startup(35) |2011-12-19 12:22:41,050| Starting HTML Form Entry Module* *INFO - HtmlFormEntryActivator.startup(35) |2011-12-19 12:22:41,050| Starting HTML Form Entry Module* DEBUG - WebModuleUtil.startModule(114) |2011-12-19 12:22:41,052| trying to start module htmlformentry DEBUG - WebModuleUtil.startModule(127) |2011-12-19 12:22:41,053| Copying message property file: fr DEBUG - WebModuleUtil.startModule(127) |2011-12-19 12:22:41,054| Copying message property file: en DEBUG - WebModuleUtil.startModule(127) |2011-12-19 12:22:41,056| Copying message property file: es DEBUG - WebModuleUtil.startModule(161) |2011-12-19 12:22:41,057| Done copying messages DEBUG - WebModuleUtil.startModule(178) |2011-12-19 12:22:41,058| Entry name: META-INF/ DEBUG - WebModuleUtil.startModule(178) |2011-12-19 12:22:41,058| Entry name: META-INF/MANIFEST.MF ... On 19 December 2011 10:18, Ben Wolfe <[email protected]> wrote: > I quickly looked over the calls and I don't see why it would be called > twice either. Is a module failing to start? If thats the case the spring > context would be refreshed twice and so the .started methods would be > called twice. > > Can you debug and put a breakpoint on that method and look at the > stacktrace? (or just print the stacktrace from that method to the logs) > > Ben > > On Fri, Dec 16, 2011 at 1:18 PM, Rowan Seymour <[email protected]> wrote: > >> I've now noticed on 3 different machines with OpenMRS 1.8.2 and 1.8.3, >> sometimes module activator startup methods are called twice. I can see this >> from modules which write something to the log when they are being started >> >> For example... >> >> INFO - LoggingAdvice.invoke(109) |2011-12-14 18:48:43,003| In method >> SchedulerService.restoreFromMemento. Arguments: OpenmrsMemento=null, >> INFO - LoggingAdvice.invoke(134) |2011-12-14 18:48:43,004| Exiting method >> restoreFromMemento >> *INFO - JMXActivator.started(33) |2011-12-14 18:48:43,005| Starting JMX >> Module* >> INFO - SchedulerServiceInterceptor.afterReturning(36) |2011-12-14 >> 18:48:43,020| schedules service >> INFO - JMXActivator.started(37) |2011-12-14 18:48:43,027| Registered >> management beans >> INFO - FrameworkServlet.initServletBean(301) |2011-12-14 18:48:43,028| >> FrameworkServlet 'openmrs': initialization started >> INFO - SchedulerServiceInterceptor.afterReturning(36) |2011-12-14 >> 18:48:43,057| schedules service >> INFO - ContextRefreshListener.onApplicationEvent(37) |2011-12-14 >> 18:48:43,063| Refreshed management beans >> INFO - FrameworkServlet.initServletBean(320) |2011-12-14 18:48:43,064| >> FrameworkServlet 'openmrs': initialization completed in 35 ms >> WARN - CommonsLoggingOutput.warn(59) |2011-12-14 18:48:43,099| Setting >> extra type info to overloaded methods may fail with <parameter .../> >> ERROR - CommonsLoggingOutput.error(75) |2011-12-14 18:48:43,100| >> Parameter mismatch parsing signatures section in dwr.xml on line: >> DWRProgramWorkflowService.updatePatientProgram(Integer patientProgramId, >> String enrollmentDateYmd, String completionDateYmd, Integer locationId) >> *INFO - JMXActivator.started(33) |2011-12-14 18:48:43,100| Starting JMX >> Module* >> INFO - SchedulerServiceInterceptor.afterReturning(36) |2011-12-14 >> 18:48:43,112| schedules service >> INFO - JMXActivator.started(37) |2011-12-14 18:48:43,118| Registered >> management beans >> INFO - ModuleListController.formBackingObject(261) |2011-12-14 >> 18:48:43,140| Returning 5 modules >> INFO - SchedulerServiceInterceptor.afterReturning(36) |2011-12-14 >> 18:48:46,198| schedules service >> INFO - SchedulerServiceInterceptor.afterReturning(36) |2011-12-14 >> 18:48:46,201| schedules service >> >> I've also noticed it with modules like that one that use >> BaseModuleActivator, but also HTML Form Entry which uses the old Activator >> interface. >> >> Haven't been able to figure out why yet... >> >> -- >> >> *Dr Rowan Seymour** >> Partners In Health, Rwanda* >> Tel: +250783835665 >> >> ------------------------------ >> Click here to >> unsubscribe<[email protected]?body=SIGNOFF%20openmrs-devel-l>from >> OpenMRS Developers' mailing list > > > ------------------------------ > Click here to > unsubscribe<[email protected]?body=SIGNOFF%20openmrs-devel-l>from > OpenMRS Developers' mailing list -- *Rowan Seymour* tel: +250 783835665 http://twitter.com/rowanseymour _________________________________________ To unsubscribe from OpenMRS Developers' mailing list, send an e-mail to [email protected] with "SIGNOFF openmrs-devel-l" in the body (not the subject) of your e-mail. [mailto:[email protected]?body=SIGNOFF%20openmrs-devel-l]
