Support Forum

[phancox]

After upgrading from TS 3.5.73 to TS 4.0.4 we have noticed a significant degradation in response time. Often takes over a minute the first time a task is loaded. Seems from the debug log that it may be taking quite a while to search for information from SCM. Extract below from when task selected to when response returned.

REGARDS
Peter

Code: Select all

2010-08-18 17:30:44,486 DEBUG com.trackstudio.startup.SCMDaemon:run:123 - CLOSE SESSION SCMDaemon
2010-08-18 17:30:46,378 DEBUG com.trackstudio.action.GeneralAction:imports:153 - Login as another user problem diagnostic info: user=phancox; locale=en_AU
2010-08-18 17:30:46,378 DEBUG com.trackstudio.action.GeneralAction:imports:153 - Login as another user problem diagnostic info: user=phancox; locale=en_AU
2010-08-18 17:30:50,605 DEBUG com.trackstudio.startup.SCMDaemon:run:123 - CLOSE SESSION SCMDaemon
2010-08-18 17:30:50,607 DEBUG com.trackstudio.startup.HibernateSession:currentSession:22 - CREATE NEW SESSION
2010-08-18 17:30:50,693 DEBUG com.trackstudio.action.GeneralAction:imports:153 - Login as another user problem diagnostic info: user=phancox; locale=en_AU
2010-08-18 17:30:50,780 DEBUG com.trackstudio.action.GeneralAction:imports:153 - Login as another user problem diagnostic info: user=phancox; locale=en_AU
2010-08-18 17:30:50,781 DEBUG com.trackstudio.kernel.manager.LicenseManager:calculateSupportPeriod:294 - supportPeriod = 189216000000
2010-08-18 17:30:50,781 DEBUG com.trackstudio.kernel.manager.LicenseManager:calculateSupportExpireDate:274 - supportExpireDate = Sat Feb 26 00:00:00 EST 2011
2010-08-18 17:30:50,864 DEBUG com.trackstudio.securedkernel.SecuredSCMAdapterManager:getSCMParents:50 - SCM parent not found
2010-08-18 17:30:51,331 DEBUG com.trackstudio.kernel.manager.IndexManager:getReferenced:1299 - Searching for: 4028008315d17a0101160f4457980074
2010-08-18 17:30:51,332 DEBUG com.trackstudio.kernel.manager.IndexManager:getReferenced:1300 - Searching for (query): +ReferencedTasks:4028008315d17a0101160f4457980074
2010-08-18 17:30:54,477 DEBUG com.trackstudio.kernel.manager.IndexManager:getReferenced:1303 - 0 total matching documents
2010-08-18 17:30:54,651 DEBUG com.trackstudio.kernel.manager.IndexManager:getReferenced:1299 - Searching for: 4028008315d17a0101160f4457980074
2010-08-18 17:30:54,652 DEBUG com.trackstudio.kernel.manager.IndexManager:getReferenced:1300 - Searching for (query): +ReferencedTasks:4028008315d17a0101160f4457980074
2010-08-18 17:31:02,943 DEBUG com.trackstudio.kernel.manager.IndexManager:getReferenced:1303 - 0 total matching documents
2010-08-18 17:31:02,943 DEBUG com.trackstudio.startup.HibernateSession:getStatelessSession:38 - CREATE NEW STATELESS SESSION
2010-08-18 17:31:03,163 DEBUG com.trackstudio.kernel.manager.StepManager:getAvailableMstatusList:86 - userabilities true
2010-08-18 17:31:03,165 DEBUG com.trackstudio.kernel.manager.StepManager:getAvailableMstatusList:86 - userabilities true
2010-08-18 17:31:03,166 DEBUG com.trackstudio.kernel.manager.StepManager:getAvailableMstatusList:86 - userabilities true
2010-08-18 17:31:03,167 DEBUG com.trackstudio.kernel.manager.StepManager:getAvailableMstatusList:86 - userabilities true
2010-08-18 17:31:03,169 DEBUG com.trackstudio.kernel.manager.StepManager:getAvailableMstatusList:86 - userabilities true
2010-08-18 17:31:03,188 DEBUG com.trackstudio.securedkernel.SecuredSCMAdapterManager:getSCMParents:50 - SCM parent not found
2010-08-18 17:31:03,211 DEBUG com.trackstudio.kernel.manager.IndexManager:getSCMreferenceByNumber:959 - Searching for: 1076
2010-08-18 17:31:03,211 DEBUG com.trackstudio.kernel.manager.IndexManager:getSCMreferenceByNumber:960 - Searching for (query): +tasks:1076
2010-08-18 17:31:14,541 DEBUG com.trackstudio.kernel.manager.IndexManager:getSCMreferenceByNumber:963 - 9 total matching documents
2010-08-18 17:31:21,837 DEBUG com.trackstudio.startup.SCMDaemon:run:123 - CLOSE SESSION SCMDaemon
2010-08-18 17:31:21,861 DEBUG com.trackstudio.kernel.manager.IndexManager:getSCMreferenceByNumber:959 - Searching for: 1076
2010-08-18 17:31:21,862 DEBUG com.trackstudio.kernel.manager.IndexManager:getSCMreferenceByNumber:960 - Searching for (query): +tasks:1076
2010-08-18 17:31:24,072 DEBUG com.trackstudio.kernel.manager.IndexManager:getSCMreferenceByNumber:963 - 9 total matching documents
2010-08-18 17:31:24,075 DEBUG com.trackstudio.kernel.manager.IndexManager:getSCMreferenceByNumber:959 - Searching for: 1076
2010-08-18 17:31:24,075 DEBUG com.trackstudio.kernel.manager.IndexManager:getSCMreferenceByNumber:960 - Searching for (query): +tasks:1076
2010-08-18 17:31:29,651 DEBUG com.trackstudio.kernel.manager.IndexManager:getSCMreferenceByNumber:963 - 9 total matching documents
2010-08-18 17:31:35,374 DEBUG com.trackstudio.startup.SCMDaemon:run:123 - CLOSE SESSION SCMDaemon
2010-08-18 17:31:35,375 DEBUG com.trackstudio.kernel.manager.IndexManager:getSCMreferenceByNumber:959 - Searching for: 1076
2010-08-18 17:31:35,376 DEBUG com.trackstudio.kernel.manager.IndexManager:getSCMreferenceByNumber:960 - Searching for (query): +tasks:1076
2010-08-18 17:31:35,971 DEBUG com.trackstudio.kernel.manager.IndexManager:getSCMreferenceByNumber:963 - 9 total matching documents
2010-08-18 17:31:35,974 DEBUG com.trackstudio.securedkernel.SecuredSCMAdapterManager:getSCMParents:50 - SCM parent not found
2010-08-18 17:31:35,979 DEBUG com.trackstudio.action.task.TaskViewAction:page:112 - ts-session808220b1944cd98c53ce517cc055fc8b3c23
2010-08-18 17:31:35,980 DEBUG com.trackstudio.action.task.TaskViewAction:page:112 - SubtasksActionTaskFilterParametersAction
2010-08-18 17:31:35,980 DEBUG com.trackstudio.action.task.TaskViewAction:page:112 - TaskViewActionMessageCreateAction
2010-08-18 17:31:35,981 DEBUG com.trackstudio.action.task.TaskViewAction:page:112 - UserListActionUserFilterParametersAction
2010-08-18 17:31:35,981 DEBUG com.trackstudio.action.task.TaskViewAction:page:112 - JSESSIONID18km577z65mir5omjc0h5xiw3
2010-08-18 17:31:35,982 DEBUG com.trackstudio.action.task.TaskViewAction:page:112 - LOGIN7068616e636f78406474632e636f6d2e6175
2010-08-18 17:31:35,983 DEBUG com.trackstudio.action.task.TaskViewAction:page:112 - SCREEN_NAME5a636f53632f62484850553d
2010-08-18 17:31:35,983 DEBUG com.trackstudio.action.task.TaskViewAction:page:112 - CUSTOMER_UUIDff37dfe2-4896-4cbb-bb1b-33626a69accc
2010-08-18 17:31:35,983 DEBUG com.trackstudio.action.task.TaskViewAction:page:112 - REMEMBER_MEtrue
2010-08-18 17:31:35,984 DEBUG com.trackstudio.action.task.TaskViewAction:page:112 - COMPANY_ID10112
2010-08-18 17:31:35,985 DEBUG com.trackstudio.action.task.TaskViewAction:page:112 - ID424d366c6468634b3041453d
2010-08-18 17:31:35,985 DEBUG com.trackstudio.action.task.TaskViewAction:page:112 - PASSWORD694849484f6949446472633d
2010-08-18 17:31:35,986 DEBUG com.trackstudio.action.task.TaskViewAction:page:112 - UserListActionUserFilterParametersAction
2010-08-18 17:31:35,986 DEBUG com.trackstudio.action.task.TaskViewAction:page:112 - udffieldsearchudflist(ff808081028484bb01028eae7b4a0010)
2010-08-18 17:31:35,987 DEBUG com.trackstudio.action.task.TaskViewAction:page:112 - timer402800831b2ca6b1011b3e43453f000b+0+1282116301516+402800831a47330f011a6b29af460042+0+242+402800b22a6e4b8f012a7ffa384f0027+0+68594+1+0+100+402800b22a6e4b8f012a75cbc02e001e+0+170803+402800b22a0f015d012a65caddf30052+0+147591+402800831ca78032011daee171e90064+0+242+402800b22a6e4b8f012a6e7bd5010002+0+17900+402800b22a0df909012a0e859c220016+0+4839+402800b228a93dd80128c32aaab102e6+0+58805+402800b228a93dd80128fca7876139fd+0+795
2010-08-18 17:31:35,987 DEBUG com.trackstudio.action.task.TaskViewAction:page:112 - SubtasksActionnone
2010-08-18 17:31:35,988 DEBUG com.trackstudio.action.task.TaskViewAction:page:112 - _selectedId
2010-08-18 17:31:35,988 DEBUG com.trackstudio.action.task.TaskViewAction:page:112 - username/METNIcTXRM_
2010-08-18 17:31:35,989 DEBUG com.trackstudio.action.task.TaskViewAction:page:112 - passwordhmBf52LW+A5GHYktowzcuA__
2010-08-18 17:31:35,989 DEBUG com.trackstudio.action.task.TaskViewAction:page:112 - remembermetrue
2010-08-18 17:31:35,990 DEBUG com.trackstudio.action.task.TaskViewAction:page:112 - validationbe92b911759489fb81a5108c2150f109
2010-08-18 17:31:37,368 DEBUG com.trackstudio.startup.SCMDaemon:run:123 - CLOSE SESSION SCMDaemon
2010-08-18 17:31:37,399 DEBUG com.trackstudio.action.GeneralAction:imports:153 - Login as another user problem diagnostic info: user=phancox; locale=en_AU
2010-08-18 17:31:37,400 DEBUG com.trackstudio.action.GeneralAction:imports:153 - Login as another user problem diagnostic info: user=phancox; locale=en_AU
2010-08-18 17:31:37,420 DEBUG com.trackstudio.startup.HibernateSession:currentSession:22 - CREATE NEW SESSION
2010-08-18 17:31:38,928 DEBUG com.trackstudio.action.GeneralAction:imports:153 - Login as another user problem diagnostic info: user=phancox; locale=en_AU
2010-08-18 17:31:38,928 DEBUG com.trackstudio.action.GeneralAction:imports:153 - Login as another user problem diagnostic info: user=phancox; locale=en_AU
2010-08-18 17:31:38,928 DEBUG com.trackstudio.startup.HibernateSession:currentSession:22 - CREATE NEW SESSION
2010-08-18 17:31:38,929 DEBUG com.trackstudio.action.GeneralAction:imports:153 - Login as another user problem diagnostic info: user=phancox; locale=en_AU
2010-08-18 17:31:38,930 DEBUG com.trackstudio.action.GeneralAction:imports:153 - Login as another user problem diagnostic info: user=phancox; locale=en_AU
2010-08-18 17:31:38,930 DEBUG com.trackstudio.kernel.manager.LicenseManager:calculateSupportPeriod:294 - supportPeriod = 189216000000
2010-08-18 17:31:38,931 DEBUG com.trackstudio.kernel.manager.LicenseManager:calculateSupportExpireDate:274 - supportExpireDate = Sat Feb 26 00:00:00 EST 2011
2010-08-18 17:31:38,932 DEBUG com.trackstudio.securedkernel.SecuredSCMAdapterManager:getSCMParents:50 - SCM parent not found
2010-08-18 17:31:38,939 DEBUG com.trackstudio.kernel.manager.IndexManager:getReferenced:1299 - Searching for: 4028008315d17a0101160f4457980074
2010-08-18 17:31:38,940 DEBUG com.trackstudio.kernel.manager.IndexManager:getReferenced:1300 - Searching for (query): +ReferencedTasks:4028008315d17a0101160f4457980074
2010-08-18 17:31:39,104 DEBUG com.trackstudio.kernel.manager.IndexManager:getReferenced:1303 - 0 total matching documents
2010-08-18 17:31:39,106 DEBUG com.trackstudio.kernel.manager.IndexManager:getReferenced:1299 - Searching for: 4028008315d17a0101160f4457980074
2010-08-18 17:31:39,106 DEBUG com.trackstudio.kernel.manager.IndexManager:getReferenced:1300 - Searching for (query): +ReferencedTasks:4028008315d17a0101160f4457980074
2010-08-18 17:31:41,156 DEBUG com.trackstudio.kernel.manager.IndexManager:getReferenced:1303 - 0 total matching documents
2010-08-18 17:31:41,157 DEBUG com.trackstudio.startup.HibernateSession:getStatelessSession:38 - CREATE NEW STATELESS SESSION
2010-08-18 17:31:41,159 DEBUG com.trackstudio.kernel.manager.StepManager:getAvailableMstatusList:86 - userabilities true
2010-08-18 17:31:41,160 DEBUG com.trackstudio.kernel.manager.StepManager:getAvailableMstatusList:86 - userabilities true
2010-08-18 17:31:41,160 DEBUG com.trackstudio.kernel.manager.StepManager:getAvailableMstatusList:86 - userabilities true
2010-08-18 17:31:41,161 DEBUG com.trackstudio.kernel.manager.StepManager:getAvailableMstatusList:86 - userabilities true
2010-08-18 17:31:41,161 DEBUG com.trackstudio.kernel.manager.StepManager:getAvailableMstatusList:86 - userabilities true
2010-08-18 17:31:41,163 DEBUG com.trackstudio.securedkernel.SecuredSCMAdapterManager:getSCMParents:50 - SCM parent not found
2010-08-18 17:31:41,165 DEBUG com.trackstudio.kernel.manager.IndexManager:getSCMreferenceByNumber:959 - Searching for: 1076
2010-08-18 17:31:41,165 DEBUG com.trackstudio.kernel.manager.IndexManager:getSCMreferenceByNumber:960 - Searching for (query): +tasks:1076
2010-08-18 17:31:42,737 DEBUG com.trackstudio.kernel.manager.IndexManager:getSCMreferenceByNumber:963 - 9 total matching documents
2010-08-18 17:31:42,740 DEBUG com.trackstudio.kernel.manager.IndexManager:getSCMreferenceByNumber:959 - Searching for: 1076
2010-08-18 17:31:42,740 DEBUG com.trackstudio.kernel.manager.IndexManager:getSCMreferenceByNumber:960 - Searching for (query): +tasks:1076
2010-08-18 17:31:43,010 DEBUG com.trackstudio.kernel.manager.IndexManager:getSCMreferenceByNumber:963 - 9 total matching documents
2010-08-18 17:31:43,012 DEBUG com.trackstudio.kernel.manager.IndexManager:getSCMreferenceByNumber:959 - Searching for: 1076
2010-08-18 17:31:43,013 DEBUG com.trackstudio.kernel.manager.IndexManager:getSCMreferenceByNumber:960 - Searching for (query): +tasks:1076
2010-08-18 17:31:44,848 DEBUG com.trackstudio.kernel.manager.IndexManager:getSCMreferenceByNumber:963 - 9 total matching documents
2010-08-18 17:31:44,850 DEBUG com.trackstudio.kernel.manager.IndexManager:getSCMreferenceByNumber:959 - Searching for: 1076
2010-08-18 17:31:44,850 DEBUG com.trackstudio.kernel.manager.IndexManager:getSCMreferenceByNumber:960 - Searching for (query): +tasks:1076
2010-08-18 17:31:46,648 DEBUG com.trackstudio.kernel.manager.IndexManager:getSCMreferenceByNumber:963 - 9 total matching documents
2010-08-18 17:31:46,650 DEBUG com.trackstudio.securedkernel.SecuredSCMAdapterManager:getSCMParents:50 - SCM parent not found
2010-08-18 17:31:46,651 DEBUG com.trackstudio.action.task.TaskViewAction:page:112 - ts-session808220b1944cd98c53ce517cc055fc8b3c23
2010-08-18 17:31:46,652 DEBUG com.trackstudio.action.task.TaskViewAction:page:112 - SubtasksActionTaskFilterParametersAction
2010-08-18 17:31:46,652 DEBUG com.trackstudio.action.task.TaskViewAction:page:112 - TaskViewActionMessageCreateAction
2010-08-18 17:31:46,653 DEBUG com.trackstudio.action.task.TaskViewAction:page:112 - UserListActionUserFilterParametersAction
2010-08-18 17:31:46,653 DEBUG com.trackstudio.action.task.TaskViewAction:page:112 - JSESSIONID18km577z65mir5omjc0h5xiw3
2010-08-18 17:31:46,654 DEBUG com.trackstudio.action.task.TaskViewAction:page:112 - LOGIN7068616e636f78406474632e636f6d2e6175
2010-08-18 17:31:46,654 DEBUG com.trackstudio.action.task.TaskViewAction:page:112 - SCREEN_NAME5a636f53632f62484850553d
2010-08-18 17:31:46,655 DEBUG com.trackstudio.action.task.TaskViewAction:page:112 - CUSTOMER_UUIDff37dfe2-4896-4cbb-bb1b-33626a69accc
2010-08-18 17:31:46,655 DEBUG com.trackstudio.action.task.TaskViewAction:page:112 - REMEMBER_MEtrue
2010-08-18 17:31:46,656 DEBUG com.trackstudio.action.task.TaskViewAction:page:112 - COMPANY_ID10112
2010-08-18 17:31:46,656 DEBUG com.trackstudio.action.task.TaskViewAction:page:112 - ID424d366c6468634b3041453d
2010-08-18 17:31:46,657 DEBUG com.trackstudio.action.task.TaskViewAction:page:112 - PASSWORD694849484f6949446472633d
2010-08-18 17:31:46,657 DEBUG com.trackstudio.action.task.TaskViewAction:page:112 - UserListActionUserFilterParametersAction
2010-08-18 17:31:46,658 DEBUG com.trackstudio.action.task.TaskViewAction:page:112 - udffieldsearchudflist(ff808081028484bb01028eae7b4a0010)
2010-08-18 17:31:46,658 DEBUG com.trackstudio.action.task.TaskViewAction:page:112 - timer4028008315d17a0101160f4457980074+0+1282116689733+402800831b2ca6b1011b3e43453f000b+0+388+402800831a47330f011a6b29af460042+0+242+402800b22a6e4b8f012a7ffa384f0027+0+68594+1+0+100+402800b22a6e4b8f012a75cbc02e001e+0+170803+402800b22a0f015d012a65caddf30052+0+147591+402800831ca78032011daee171e90064+0+242+402800b22a6e4b8f012a6e7bd5010002+0+17900+402800b22a0df909012a0e859c220016+0+4839+402800b228a93dd80128c32aaab102e6+0+58805
2010-08-18 17:31:46,659 DEBUG com.trackstudio.action.task.TaskViewAction:page:112 - SubtasksActionnone
2010-08-18 17:31:46,659 DEBUG com.trackstudio.action.task.TaskViewAction:page:112 - _selectedId
2010-08-18 17:31:46,660 DEBUG com.trackstudio.action.task.TaskViewAction:page:112 - username/METNIcTXRM_
2010-08-18 17:31:46,660 DEBUG com.trackstudio.action.task.TaskViewAction:page:112 - passwordhmBf52LW+A5GHYktowzcuA__
2010-08-18 17:31:46,661 DEBUG com.trackstudio.action.task.TaskViewAction:page:112 - remembermetrue
2010-08-18 17:31:46,661 DEBUG com.trackstudio.action.task.TaskViewAction:page:112 - validationbe92b911759489fb81a5108c2150f109
2010-08-18 17:31:46,671 DEBUG com.trackstudio.action.GeneralAction:imports:153 - Login as another user problem diagnostic info: user=phancox; locale=en_AU
2010-08-18 17:31:46,672 DEBUG com.trackstudio.action.GeneralAction:imports:153 - Login as another user problem diagnostic info: user=phancox; locale=en_AU
2010-08-18 17:31:46,678 DEBUG com.trackstudio.startup.HibernateSession:currentSession:22 - CREATE NEW SESSION


[phancox]

Perhaps the SCM reference searching is more memory hungry in TS 4? Our Subversion repositories are quite large and almost every update is tagged with a TrackStudio reference number.

TrackStudio is running in a virtual machine on a VMware ESXi host. Increased the VM's allocated memory from 1 GByte to 2 GByte and response time seems to have returned to approximately 3-4 seconds in most cases.

[admin]

ok, we'll check this.

Please try to disable SCM integration - does it become faster ?

[phancox]

ok, we'll check this.

Please try to disable SCM integration - does it become faster ?

In order to test this for you I'd also have to reconfigure the virtual machine to run with less memory again. I'm happy with performance now that it's got 2 GB memory allocated and not seeing swapping anymore.

Unless you've got other people complaining I'd just close this off as it may have just been specific to our environment.

REGARDS