Summary: | Inconsistent log level practices | ||
---|---|---|---|
Product: | Tomcat 9 | Reporter: | AnhT <anuhan> |
Component: | Catalina | Assignee: | Tomcat Developers Mailing List <dev> |
Status: | RESOLVED FIXED | ||
Severity: | enhancement | CC: | anuhan |
Priority: | P2 | ||
Version: | 9.0.16 | ||
Target Milestone: | ----- | ||
Hardware: | PC | ||
OS: | All | ||
Attachments: | Patch fille |
Description
AnhT
2019-03-09 04:06:54 UTC
Created attachment 36480 [details]
Patch fille
Modify the log levels to INFO in file apache-tomcat-9.0.16-src\java\org\apache\catalina\util\LifecycleMBeanBase.java.
Nice find. I did a search of the code base. It wasn't perfect but I found 2 instances of INFO, 7 of WARN and 8 of ERROR. Generally, the ERROR logs were related to a more general failure to start or stop a component. JMX registration should not fail and breakage is likely if it does so WARN seems more appropriate here. I'll get this fixed shortly. Hi, Mark Thomas. Thank you very much for your prompt response. There are other 6 inconsistent logging practices shown below, and I think the ERROR level is more appropriate to them. ============StandardService.java=================== full path: tomcat\java\org\apache\catalina\core\StandardService.java log line num: 137; 144; 149; 155 132 if (getState().isAvailable()) { 133 if (this.engine != null) { 134 try { 135 this.engine.start(); 136 } catch (LifecycleException e) { 137 log.warn(sm.getString("standardService.engine.startFailed"), e); 138 } 139 } 140 // Restart MapperListener to pick up new engine. 141 try { 142 mapperListener.stop(); 143 } catch (LifecycleException e) { 144 log.warn(sm.getString("standardService.mapperListener.stopFailed"), e); 145 } 146 try { 147 mapperListener.start(); 148 } catch (LifecycleException e) { 149 log.warn(sm.getString("standardService.mapperListener.startFailed"), e); 150 } 151 if (oldEngine != null) { 152 try { 153 oldEngine.stop(); 154 } catch (LifecycleException e) { 155 log.warn(sm.getString("standardService.engine.stopFailed"), e); 156 } 157 } 158 } ============HostConfig.java=================== full path: tomcat\java\org\apache\catalina\startup\HostConfig.java log line num: 1414 1396 Context context = (Context) host.findChild(app.name); 1397 if (context.getState().isAvailable()) { 1398 if (fileToRemove != null && newDocBase != null) { 1399 context.addLifecycleListener( 1400 new ExpandedDirectoryRemovalListener(fileToRemove, newDocBase)); 1401 } 1402 // Reload catches and logs exceptions 1403 context.reload(); 1404 } else { 1405 // If the context was not started (for example an error 1406 // in web.xml) we'll still get to try to start 1407 if (fileToRemove != null && newDocBase != null) { 1408 ExpandWar.delete(fileToRemove); 1409 context.setDocBase(newDocBase); 1410 } 1411 try { 1412 context.start(); 1413 } catch (Exception e) { 1414 log.warn(sm.getString 1415 ("hostConfig.context.restart", app.name), e); 1416 } 1417 } =============LifecycleBase.java======================= full path: tomcat\java\org\apache\catalina\util\LifecycleBase.java log line num: 296 290 if (LifecycleState.FAILED.equals(state)) { 291 try { 292 // Triggers clean-up 293 stop(); 294 } catch (LifecycleException e) { 295 // Just log. Still want to destroy. 296 log.warn(sm.getString( 297 "lifecycleBase.destroyStopFail", toString()), e); 298 } 299 } Hi, Mark Thomas. Thank you very much for your prompt response. There are other inconsistent logging practices shown below, and I think the ERROR level is more appropriate to following 6 log statements. ============StandardService.java=================== file path: apache-tomcat-9.0.16-src\java\org\apache\catalina\core\StandardService.java log line num: 137; 144; 149; 155 132 if (getState().isAvailable()) { 133 if (this.engine != null) { 134 try { 135 this.engine.start(); 136 } catch (LifecycleException e) { 137 log.warn(sm.getString("standardService.engine.startFailed"), e); 138 } 139 } 140 // Restart MapperListener to pick up new engine. 141 try { 142 mapperListener.stop(); 143 } catch (LifecycleException e) { 144 log.warn(sm.getString("standardService.mapperListener.stopFailed"), e); 145 } 146 try { 147 mapperListener.start(); 148 } catch (LifecycleException e) { 149 log.warn(sm.getString("standardService.mapperListener.startFailed"), e); 150 } 151 if (oldEngine != null) { 152 try { 153 oldEngine.stop(); 154 } catch (LifecycleException e) { 155 log.warn(sm.getString("standardService.engine.stopFailed"), e); 156 } 157 } 158 } ============HostConfig.java=================== file path: apache-tomcat-9.0.16-src\java\org\apache\catalina\startup\HostConfig.java log line num: 1414 1411 try { 1412 context.start(); 1413 } catch (Exception e) { 1414 log.warn(sm.getString 1415 ("hostConfig.context.restart", app.name), e); 1416 } =============LifecycleBase.java======================= file path: apache-tomcat-9.0.16-src\java\org\apache\catalina\util\LifecycleBase.java log line num: 296 290 if (LifecycleState.FAILED.equals(state)) { 291 try { 292 // Triggers clean-up 293 stop(); 294 } catch (LifecycleException e) { 295 // Just log. Still want to destroy. 296 log.warn(sm.getString( 297 "lifecycleBase.destroyStopFail", toString()), e); 298 } 299 } ***Following 10 logging statements are assigned to ERROR level in code***** =============StandardService.java======================= file path: apache-tomcat-9.0.16-srct\java\org\apache\catalina\core\StandardService.java log line num: 293; 348 290 try { 291 connectors[j].stop(); 292 } catch (LifecycleException e) { 293 log.error(sm.getString( 294 "standardService.connector.stopFailed", 295 connectors[j]), e); 296 } 345 try { 346 ex.start(); 347 } catch (LifecycleException x) { 348 log.error(sm.getString("standardService.executor.start"), x); 349 } =============StandardPipeline.java==================== file path: apache-tomcat-9.0.16-src\java\org\apache\catalina\core\StandardPipeline.java log line num: 293; 345 290 try { 291 ((Lifecycle) valve).start(); 292 } catch (LifecycleException e) { 293 log.error(sm.getString("standardPipeline.basic.start"), e); 294 return; 295 } 342 try { 343 ((Lifecycle) valve).start(); 344 } catch (LifecycleException e) { 345 log.error(sm.getString("standardPipeline.valve.start"), e); 346 } =============CombinedRealm.java====================== file path:apache-tomcat-9.0.16-src\java\org\apache\catalina\realm\CombinedRealm.java log line num:249 244 try { 245 ((Lifecycle) realm).start(); 246 } catch (LifecycleException e) { 247 // If realm doesn't start can't authenticate against it 248 iter.remove(); 249 log.error(sm.getString("combinedRealm.realmStartFail", 250 realm.getClass().getName()), e); 251 } =============StandardContext.java====================== file path: apache-tomcat-9.0.16-src\java\org\apache\catalina\core\StandardContext.java log line num: 1844; 1899; 3750 1841 try { 1842 ((Lifecycle) oldLoader).stop(); 1843 } catch (LifecycleException e) { 1844 log.error(sm.getString("standardContext.setLoader.stop"), e); 1845 } 1895 try { 1896 ((Lifecycle) oldManager).stop(); 1897 ((Lifecycle) oldManager).destroy(); 1898 } catch (LifecycleException e) { 1899 log.error(sm.getString("standardContext.setManager.stop"), e); 1900 } 3747 try { 3748 stop(); 3749 } catch (LifecycleException e) { 3750 log.error( 3751 sm.getString("standardContext.stoppingContext", getName()), e); 3752 } =============ContainerBase.java======================== file path:apache-tomcat-9.0.16-src\java\org\apache\catalina\core\ContainerBase.java log line num: 437; 650 434 try { 435 ((Lifecycle) cluster).start(); 436 } catch (LifecycleException e) { 437 log.error(sm.getString("containerBase.cluster.start"), e); 438 } 647 try { 648 ((Lifecycle) realm).start(); 649 } catch (LifecycleException e) { 650 log.error(sm.getString("containerBase.realm.start"), e); 651 } (In reply to AnhT from comment #3) > Hi, Mark Thomas. Thank you very much for your prompt response. > There are other 6 inconsistent logging practices shown below, and I think > the ERROR level is more appropriate to them. > ============StandardService.java=================== > full path: tomcat\java\org\apache\catalina\core\StandardService.java > log line num: 137; 144; 149; 155 > > 132 if (getState().isAvailable()) { > 133 if (this.engine != null) { > 134 try { > 135 this.engine.start(); > 136 } catch (LifecycleException e) { > 137 > log.warn(sm.getString("standardService.engine.startFailed"), e); > 138 } > 139 } > 140 // Restart MapperListener to pick up new engine. > 141 try { > 142 mapperListener.stop(); > 143 } catch (LifecycleException e) { > 144 > log.warn(sm.getString("standardService.mapperListener.stopFailed"), e); > 145 } > 146 try { > 147 mapperListener.start(); > 148 } catch (LifecycleException e) { > 149 > log.warn(sm.getString("standardService.mapperListener.startFailed"), e); > 150 } > 151 if (oldEngine != null) { > 152 try { > 153 oldEngine.stop(); > 154 } catch (LifecycleException e) { > 155 > log.warn(sm.getString("standardService.engine.stopFailed"), e); > 156 } > 157 } > 158 } > > ============HostConfig.java=================== > full path: tomcat\java\org\apache\catalina\startup\HostConfig.java > log line num: 1414 > > 1396 Context context = (Context) host.findChild(app.name); > 1397 if (context.getState().isAvailable()) { > 1398 if (fileToRemove != null && newDocBase != null) { > 1399 context.addLifecycleListener( > 1400 new > ExpandedDirectoryRemovalListener(fileToRemove, newDocBase)); > 1401 } > 1402 // Reload catches and logs exceptions > 1403 context.reload(); > 1404 } else { > 1405 // If the context was not started (for example an error > 1406 // in web.xml) we'll still get to try to start > 1407 if (fileToRemove != null && newDocBase != null) { > 1408 ExpandWar.delete(fileToRemove); > 1409 context.setDocBase(newDocBase); > 1410 } > 1411 try { > 1412 context.start(); > 1413 } catch (Exception e) { > 1414 log.warn(sm.getString > 1415 ("hostConfig.context.restart", app.name), e); > 1416 } > 1417 } > > =============LifecycleBase.java======================= > full path: tomcat\java\org\apache\catalina\util\LifecycleBase.java > log line num: 296 > > 290 if (LifecycleState.FAILED.equals(state)) { > 291 try { > 292 // Triggers clean-up > 293 stop(); > 294 } catch (LifecycleException e) { > 295 // Just log. Still want to destroy. > 296 log.warn(sm.getString( > 297 "lifecycleBase.destroyStopFail", toString()), e); > 298 } > 299 } I present the details in Comment 4. Please ignore this comment. The log levels for the JMX (de-)registration messages have been addressed in: - master for 9.0.18 onwards - 8.5.x for 8.5.40 onwards - 7.0.x for 7.0.94 onwards I'll look at the Lifecycle issues next but please can I ask that you open a new bug report if you find any further issues. Separate bug reports makes it easier to track what has been fixed and what hasn't. (In reply to Mark Thomas from comment #6) > The log levels for the JMX (de-)registration messages have been addressed in: > - master for 9.0.18 onwards > - 8.5.x for 8.5.40 onwards > - 7.0.x for 7.0.94 onwards > > I'll look at the Lifecycle issues next but please can I ask that you open a > new bug report if you find any further issues. Separate bug reports makes it > easier to track what has been fixed and what hasn't. OK, I will report the bugs in new page, thanks for your response. We should probably recommend using PRs for multiple simple changes like this one. Fixed in: - master for 9.0.18 onwards - 8.5.x for 8.5.40 onwards - 7.0.x for 7.0.94 onwards The GH Issues / GH PR/ BZ discussion is probably one for the dev@ list |