2021-03-17 09:04:35,925 DEBUG [oncommand] [unifiedManagerScheduler_QuartzSchedulerThread] [o.quartz.core.QuartzSchedulerThread] batch acquisition of 0 triggers 2021-03-17 09:04:36,507 DEBUG [oncommand] [default task-607] [o.s.s.w.u.m.AntPathRequestMatcher] Checking match of request : '/api/private/event-count-summary'; against '/apis/**' 2021-03-17 09:04:36,513 DEBUG [oncommand] [default task-607] [o.s.s.w.u.m.AntPathRequestMatcher] Checking match of request : '/api/private/event-count-summary'; against '/api/**' 2021-03-17 09:04:36,513 DEBUG [oncommand] [default task-607] [o.s.security.web.FilterChainProxy] /api/private/event-count-summary at position 1 of 1 in additional filter chain; firing Filter: 'NoOpFilter' 2021-03-17 09:04:36,514 DEBUG [oncommand] [default task-607] [o.s.security.web.FilterChainProxy] /api/private/event-count-summary reached end of additional filter chain; proceeding with original chain 2021-03-17 09:04:36,514 DEBUG [oncommand] [default task-607] [o.s.s.w.u.m.AntPathRequestMatcher] Checking match of request : '/api/private/event-count-summary'; against '/api/**' 2021-03-17 09:04:36,514 DEBUG [oncommand] [default task-607] [o.s.security.web.FilterChainProxy] /api/private/event-count-summary at position 1 of 13 in additional filter chain; firing Filter: 'PreSecurityAuditLoggerConfigFilter' 2021-03-17 09:04:36,514 DEBUG [oncommand] [default task-607] [o.s.security.web.FilterChainProxy] /api/private/event-count-summary at position 2 of 13 in additional filter chain; firing Filter: 'RestCorsFilter' 2021-03-17 09:04:36,514 DEBUG [oncommand] [default task-607] [o.s.security.web.FilterChainProxy] /api/private/event-count-summary at position 3 of 13 in additional filter chain; firing Filter: 'ChannelProcessingFilter' 2021-03-17 09:04:36,514 DEBUG [oncommand] [default task-607] [o.s.s.w.a.c.ChannelProcessingFilter] Request: FilterInvocation: URL: /api/private/event-count-summary; ConfigAttributes: [REQUIRES_SECURE_CHANNEL] 2021-03-17 09:04:36,514 DEBUG [oncommand] [default task-607] [o.s.security.web.FilterChainProxy] /api/private/event-count-summary at position 4 of 13 in additional filter chain; firing Filter: 'SecurityContextPersistenceFilter' 2021-03-17 09:04:36,515 DEBUG [oncommand] [default task-607] [o.s.s.w.c.HttpSessionSecurityContextRepository] Obtained a valid SecurityContext from SPRING_SECURITY_CONTEXT: 'org.springframework.security.core.context.SecurityContextImpl@7d493e6e: Authentication: org.springframework.security.authentication.UsernamePasswordAuthenticationToken@7d493e6e: Principal: admin; Credentials: [PROTECTED]; Authenticated: true; Details: org.springframework.security.web.authentication.WebAuthenticationDetails@ffffe21a: RemoteIpAddress: 172.20.230.62; SessionId: null; Granted Authorities: com.netapp.dfm.core.authentication.RbacPrivilegeGrantedAuthorityAdapter@299e7eec, com.netapp.dfm.core.authentication.RbacPrivilegeGrantedAuthorityAdapter@157b1fb, com.netapp.dfm.core.authentication.RbacPrivilegeGrantedAuthorityAdapter@316f967d, com.netapp.dfm.core.authentication.RbacPrivilegeGrantedAuthorityAdapter@61697995' 2021-03-17 09:04:36,515 DEBUG [oncommand] [default task-607] [o.s.security.web.FilterChainProxy] /api/private/event-count-summary at position 5 of 13 in additional filter chain; firing Filter: 'TemporaryTokenAuthenticationFilter' 2021-03-17 09:04:36,515 DEBUG [oncommand] [default task-607] [o.s.security.web.FilterChainProxy] /api/private/event-count-summary at position 6 of 13 in additional filter chain; firing Filter: 'BasicAuthenticationFilter' 2021-03-17 09:04:36,515 DEBUG [oncommand] [default task-607] [o.s.security.web.FilterChainProxy] /api/private/event-count-summary at position 7 of 13 in additional filter chain; firing Filter: 'AnonymousAuthenticationFilter' 2021-03-17 09:04:36,515 DEBUG [oncommand] [default task-607] [o.s.s.w.a.AnonymousAuthenticationFilter] SecurityContextHolder not populated with anonymous token, as it already contained: 'org.springframework.security.authentication.UsernamePasswordAuthenticationToken@7d493e6e: Principal: admin; Credentials: [PROTECTED]; Authenticated: true; Details: org.springframework.security.web.authentication.WebAuthenticationDetails@ffffe21a: RemoteIpAddress: 172.20.230.62; SessionId: null; Granted Authorities: com.netapp.dfm.core.authentication.RbacPrivilegeGrantedAuthorityAdapter@299e7eec, com.netapp.dfm.core.authentication.RbacPrivilegeGrantedAuthorityAdapter@157b1fb, com.netapp.dfm.core.authentication.RbacPrivilegeGrantedAuthorityAdapter@316f967d, com.netapp.dfm.core.authentication.RbacPrivilegeGrantedAuthorityAdapter@61697995' 2021-03-17 09:04:36,515 DEBUG [oncommand] [default task-607] [o.s.security.web.FilterChainProxy] /api/private/event-count-summary at position 8 of 13 in additional filter chain; firing Filter: 'CsrfFilter' 2021-03-17 09:04:36,515 DEBUG [oncommand] [default task-607] [o.s.security.web.FilterChainProxy] /api/private/event-count-summary at position 9 of 13 in additional filter chain; firing Filter: 'ExceptionTranslationFilter' 2021-03-17 09:04:36,515 DEBUG [oncommand] [default task-607] [o.s.security.web.FilterChainProxy] /api/private/event-count-summary at position 10 of 13 in additional filter chain; firing Filter: 'FilterSecurityInterceptor' 2021-03-17 09:04:36,515 DEBUG [oncommand] [default task-607] [o.s.s.w.u.m.AntPathRequestMatcher] Checking match of request : '/api/private/event-count-summary'; against '/api/management-server/admin/session' 2021-03-17 09:04:36,515 DEBUG [oncommand] [default task-607] [o.s.s.w.u.m.AntPathRequestMatcher] Checking match of request : '/api/private/event-count-summary'; against '/api/management-server/admin/mfaenabled' 2021-03-17 09:04:36,515 DEBUG [oncommand] [default task-607] [o.s.s.w.u.m.AntPathRequestMatcher] Checking match of request : '/api/private/event-count-summary'; against '/api/management-server/admin/environment' 2021-03-17 09:04:36,515 DEBUG [oncommand] [default task-607] [o.s.s.w.u.m.AntPathRequestMatcher] Checking match of request : '/api/private/event-count-summary'; against '/api/management-server/admin/refresh-hostname' 2021-03-17 09:04:36,515 DEBUG [oncommand] [default task-607] [o.s.s.w.u.m.AntPathRequestMatcher] Checking match of request : '/api/private/event-count-summary'; against '/api/management-server/admin/refresh-logging-config' 2021-03-17 09:04:36,515 DEBUG [oncommand] [default task-607] [o.s.s.w.u.m.AntPathRequestMatcher] Checking match of request : '/api/private/event-count-summary'; against '/api/management-server/admin/log-failed-tasks' 2021-03-17 09:04:36,516 DEBUG [oncommand] [default task-607] [o.s.s.w.u.m.AntPathRequestMatcher] Checking match of request : '/api/private/event-count-summary'; against '/api/management-server/admin/dump-threads' 2021-03-17 09:04:36,516 DEBUG [oncommand] [default task-607] [o.s.s.w.u.m.AntPathRequestMatcher] Checking match of request : '/api/private/event-count-summary'; against '/api/management-server/admin/dump-heap' 2021-03-17 09:04:36,516 DEBUG [oncommand] [default task-607] [o.s.s.w.u.m.AntPathRequestMatcher] Checking match of request : '/api/private/event-count-summary'; against '/api/management-server/admin/resetpassword/**' 2021-03-17 09:04:36,516 DEBUG [oncommand] [default task-607] [o.s.s.w.u.m.AntPathRequestMatcher] Checking match of request : '/api/private/event-count-summary'; against '/api/management-server/upload-file' 2021-03-17 09:04:36,516 DEBUG [oncommand] [default task-607] [o.s.s.w.u.m.AntPathRequestMatcher] Checking match of request : '/api/private/event-count-summary'; against '/api/**' 2021-03-17 09:04:36,516 DEBUG [oncommand] [default task-607] [o.s.s.w.a.i.FilterSecurityInterceptor] Secure object: FilterInvocation: URL: /api/private/event-count-summary; Attributes: [IS_AUTHENTICATED_FULLY] 2021-03-17 09:04:36,516 DEBUG [oncommand] [default task-607] [o.s.s.w.a.i.FilterSecurityInterceptor] Previously Authenticated: org.springframework.security.authentication.UsernamePasswordAuthenticationToken@7d493e6e: Principal: admin; Credentials: [PROTECTED]; Authenticated: true; Details: org.springframework.security.web.authentication.WebAuthenticationDetails@ffffe21a: RemoteIpAddress: 172.20.230.62; SessionId: null; Granted Authorities: com.netapp.dfm.core.authentication.RbacPrivilegeGrantedAuthorityAdapter@299e7eec, com.netapp.dfm.core.authentication.RbacPrivilegeGrantedAuthorityAdapter@157b1fb, com.netapp.dfm.core.authentication.RbacPrivilegeGrantedAuthorityAdapter@316f967d, com.netapp.dfm.core.authentication.RbacPrivilegeGrantedAuthorityAdapter@61697995 2021-03-17 09:04:36,516 DEBUG [oncommand] [default task-607] [o.s.s.access.vote.AffirmativeBased] Voter: org.springframework.security.access.vote.RoleVoter@32dbec4, returned: 0 2021-03-17 09:04:36,516 DEBUG [oncommand] [default task-607] [o.s.s.access.vote.AffirmativeBased] Voter: org.springframework.security.access.vote.AuthenticatedVoter@3c721928, returned: 1 2021-03-17 09:04:36,516 DEBUG [oncommand] [default task-607] [o.s.s.w.a.i.FilterSecurityInterceptor] Authorization successful 2021-03-17 09:04:36,516 DEBUG [oncommand] [default task-607] [o.s.s.w.a.i.FilterSecurityInterceptor] RunAsManager did not change Authentication object 2021-03-17 09:04:36,516 DEBUG [oncommand] [default task-607] [o.s.security.web.FilterChainProxy] /api/private/event-count-summary at position 11 of 13 in additional filter chain; firing Filter: 'PostSecurityAuditLoggerConfigFilter' 2021-03-17 09:04:36,517 DEBUG [admin] [default task-607] [o.s.security.web.FilterChainProxy] /api/private/event-count-summary at position 12 of 13 in additional filter chain; firing Filter: 'SqlInjectionFilter' 2021-03-17 09:04:36,517 DEBUG [admin] [default task-607] [o.s.security.web.FilterChainProxy] /api/private/event-count-summary at position 13 of 13 in additional filter chain; firing Filter: 'NetAppAPIFilter' 2021-03-17 09:04:36,517 DEBUG [admin] [default task-607] [o.s.security.web.FilterChainProxy] /api/private/event-count-summary reached end of additional filter chain; proceeding with original chain 2021-03-17 09:04:36,518 DEBUG [admin] [default task-607] [o.s.w.s.m.m.a.RequestMappingHandlerMapping] Mapped to com.netapp.dfm.provision.rest.controller.v2.EventCountSummaryController#getEventCountSummary(HttpServletRequest) 2021-03-17 09:04:36,519 DEBUG [admin] [default task-607] [o.s.t.jta.JtaTransactionManager] Creating new transaction with name [com.netapp.dfm.provision.service.v2.EventCountSummaryService.getEventCountSummary]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT,readOnly 2021-03-17 09:04:36,520 DEBUG [admin] [default task-607] [o.s.jdbc.core.JdbcTemplate] Executing SQL query [SELECT e.impactArea as `impactArea`, evt.severity as `severity`, count(*) as `eventCounter` FROM ocum.event AS e LEFT JOIN ocum.eventtypevalue AS evt ON evt.id=e.value_id WHERE (e.state='NEW' OR e.state='ACKNOWLEDGED') AND evt.impactLevel<>3 AND (UNIX_TIMESTAMP(e.eventTimestamp) * 1000 > 1615388676520) AND evt.severity > 1 AND isContinuous=true AND maintenance=false GROUP BY evt.severity, e.impactArea] 2021-03-17 09:04:36,520 DEBUG [admin] [default task-607] [o.s.jdbc.datasource.DataSourceUtils] Fetching JDBC Connection from DataSource 2021-03-17 09:04:36,522 DEBUG [admin] [default task-607] [o.s.jdbc.core.JdbcTemplate] Executing SQL query [SELECT e.source_resourceType AS `resourceType`, evt.mitigationAction AS `mitigationAction`, COUNT(*) AS `eventCounter` FROM ocum.event AS e LEFT JOIN ocum.eventtypevalue AS evt ON evt.id=e.value_id WHERE (e.state='NEW' OR e.state='ACKNOWLEDGED') AND evt.impactLevel=3 AND maintenance=false GROUP BY evt.mitigationAction, e.source_resourceType;] 2021-03-17 09:04:36,523 DEBUG [admin] [default task-607] [o.s.t.jta.JtaTransactionManager] Initiating transaction commit 2021-03-17 09:04:36,524 DEBUG [admin] [default task-607] [o.s.w.s.m.m.a.HttpEntityMethodProcessor] Using 'application/hal+json', given [application/json, text/plain, */*] and supported [application/hal+json] 2021-03-17 09:04:36,524 DEBUG [admin] [default task-607] [o.s.w.s.m.m.a.HttpEntityMethodProcessor] Writing [Resource { content: com.netapp.dfm.provision.rest.dto.v2.EventCountSummaryDto@35539fdb, links: [= ? and time <= ? order by time asc] 2021-03-17 09:06:16,977 DEBUG [oncommand] [pool-40-thread-1] [o.s.jdbc.datasource.DataSourceUtils] Fetching JDBC Connection from DataSource 2021-03-17 09:06:16,978 DEBUG [oncommand] [pool-40-thread-1] [o.s.jdbc.core.JdbcTemplate] Executing prepared SQL query 2021-03-17 09:06:16,978 DEBUG [oncommand] [pool-40-thread-1] [o.s.jdbc.core.JdbcTemplate] Executing prepared SQL statement [SELECT * from acquisition.ds_attrs where ds_id = ? AND name LIKE "netappstorageperformance.clock.polling.offset" ] 2021-03-17 09:06:16,978 DEBUG [oncommand] [pool-40-thread-1] [o.s.jdbc.datasource.DataSourceUtils] Fetching JDBC Connection from DataSource 2021-03-17 09:06:16,980 DEBUG [oncommand] [pool-40-thread-1] [o.s.jdbc.core.JdbcTemplate] Executing prepared SQL query 2021-03-17 09:06:16,980 DEBUG [oncommand] [pool-40-thread-1] [o.s.jdbc.core.JdbcTemplate] Executing prepared SQL statement [SELECT * FROM netapp_model_view.node_full WHERE objid=?] 2021-03-17 09:06:16,980 DEBUG [oncommand] [pool-40-thread-1] [o.s.jdbc.datasource.DataSourceUtils] Fetching JDBC Connection from DataSource 2021-03-17 09:06:16,982 DEBUG [oncommand] [pool-40-thread-1] [o.s.jdbc.core.JdbcTemplate] Executing prepared SQL query 2021-03-17 09:06:16,982 DEBUG [oncommand] [pool-40-thread-1] [o.s.jdbc.core.JdbcTemplate] Executing prepared SQL statement [SELECT * from acquisition.ds_attrs where ds_id = ? AND name LIKE "netappstorageperformance.clock.polling.offset" ] 2021-03-17 09:06:16,982 DEBUG [oncommand] [pool-40-thread-1] [o.s.jdbc.datasource.DataSourceUtils] Fetching JDBC Connection from DataSource 2021-03-17 09:06:16,984 DEBUG [oncommand] [pool-40-thread-1] [o.s.jdbc.core.JdbcTemplate] Executing SQL query [SELECT COALESCE(SUM (totalOps) , 0) FROM netapp_performance.sample_node WHERE time=1615989862040 AND objid in (74,6) ] 2021-03-17 09:06:16,984 DEBUG [oncommand] [pool-40-thread-1] [o.s.jdbc.datasource.DataSourceUtils] Fetching JDBC Connection from DataSource 2021-03-17 09:06:16,988 DEBUG [oncommand] [pool-40-thread-1] [o.s.jdbc.core.JdbcTemplate] Executing prepared SQL query 2021-03-17 09:06:16,988 DEBUG [oncommand] [pool-40-thread-1] [o.s.jdbc.core.JdbcTemplate] Executing prepared SQL statement [SELECT * FROM netapp_model_view.resource_aggregate_full WHERE clusterId=?] 2021-03-17 09:06:16,988 DEBUG [oncommand] [pool-40-thread-1] [o.s.jdbc.datasource.DataSourceUtils] Fetching JDBC Connection from DataSource 2021-03-17 09:06:16,989 DEBUG [oncommand] [pool-40-thread-1] [o.s.jdbc.core.JdbcTemplate] Executing prepared SQL query 2021-03-17 09:06:16,989 DEBUG [oncommand] [pool-40-thread-1] [o.s.jdbc.core.JdbcTemplate] Executing prepared SQL statement [SELECT * FROM opm.resource_capability_stats WHERE resourceId IN (?, ?, ?, ?)] 2021-03-17 09:06:16,989 DEBUG [oncommand] [pool-40-thread-1] [o.s.jdbc.datasource.DataSourceUtils] Fetching JDBC Connection from DataSource 2021-03-17 09:06:16,990 DEBUG [oncommand] [pool-40-thread-1] [o.s.t.jta.JtaTransactionManager] Creating new transaction with name [com.netapp.ipc.services.performance.service.NodePerformanceQueryService.getSamples]: PROPAGATION_REQUIRES_NEW,ISOLATION_DEFAULT 2021-03-17 09:06:16,997 DEBUG [oncommand] [pool-40-thread-1] [o.s.t.jta.JtaTransactionManager] Initiating transaction commit 2021-03-17 09:06:16,997 DEBUG [oncommand] [pool-40-thread-1] [o.s.jdbc.core.JdbcTemplate] Executing prepared SQL query 2021-03-17 09:06:16,997 DEBUG [oncommand] [pool-40-thread-1] [o.s.jdbc.core.JdbcTemplate] Executing prepared SQL statement [SELECT * FROM netapp_model_view.node_full WHERE objid=?] 2021-03-17 09:06:16,997 DEBUG [oncommand] [pool-40-thread-1] [o.s.jdbc.datasource.DataSourceUtils] Fetching JDBC Connection from DataSource 2021-03-17 09:06:16,999 DEBUG [oncommand] [pool-40-thread-1] [o.s.jdbc.core.JdbcTemplate] Executing prepared SQL query 2021-03-17 09:06:16,999 DEBUG [oncommand] [pool-40-thread-1] [o.s.jdbc.core.JdbcTemplate] Executing prepared SQL statement [SELECT * from opm.acquisition_info where clusterId = ? and time >= ? and time <= ? order by time asc] 2021-03-17 09:06:16,999 DEBUG [oncommand] [pool-40-thread-1] [o.s.jdbc.datasource.DataSourceUtils] Fetching JDBC Connection from DataSource 2021-03-17 09:06:17,000 DEBUG [oncommand] [pool-40-thread-1] [o.s.jdbc.core.JdbcTemplate] Executing prepared SQL query 2021-03-17 09:06:17,000 DEBUG [oncommand] [pool-40-thread-1] [o.s.jdbc.core.JdbcTemplate] Executing prepared SQL statement [SELECT * from acquisition.ds_attrs where ds_id = ? AND name LIKE "netappstorageperformance.clock.polling.offset" ] 2021-03-17 09:06:17,000 DEBUG [oncommand] [pool-40-thread-1] [o.s.jdbc.datasource.DataSourceUtils] Fetching JDBC Connection from DataSource 2021-03-17 09:06:17,000 DEBUG [oncommand] [pool-40-thread-1] [o.s.jdbc.core.JdbcTemplate] Executing prepared SQL query 2021-03-17 09:06:17,000 DEBUG [oncommand] [pool-40-thread-1] [o.s.jdbc.core.JdbcTemplate] Executing prepared SQL statement [SELECT * FROM netapp_model_view.node_full WHERE objid=?] 2021-03-17 09:06:17,000 DEBUG [oncommand] [pool-40-thread-1] [o.s.jdbc.datasource.DataSourceUtils] Fetching JDBC Connection from DataSource 2021-03-17 09:06:17,001 DEBUG [oncommand] [pool-40-thread-1] [o.s.jdbc.core.JdbcTemplate] Executing prepared SQL query 2021-03-17 09:06:17,002 DEBUG [oncommand] [pool-40-thread-1] [o.s.jdbc.core.JdbcTemplate] Executing prepared SQL statement [SELECT * from acquisition.ds_attrs where ds_id = ? AND name LIKE "netappstorageperformance.clock.polling.offset" ] 2021-03-17 09:06:17,002 DEBUG [oncommand] [pool-40-thread-1] [o.s.jdbc.datasource.DataSourceUtils] Fetching JDBC Connection from DataSource 2021-03-17 09:06:17,112 INFO [oncommand] [org.springframework.jms.listener.DefaultMessageListenerContainer#1-1] [com.netapp.ipc.jms.OCIE_Events] OCIE JMS notification message received: {DatasourceName=twm-co-netapp-3.ttg.pvt, DatasourceID=1, StartTime=1615989976961, SummaryTime=1615986000000, Success=true, MessageType=SUMMARY_COMPLETE, DurationTime=137} 2021-03-17 09:06:17,191 INFO [oncommand] [pool-40-thread-1] [c.n.i.a.c.HeadroomEngine] Calculated Observation final 89.0 35898.72220814463 2021-03-17 09:06:17,283 INFO [oncommand] [pool-40-thread-1] [c.n.i.a.c.HeadroomEngine] Calculated Observation final 79.0 10072.545875020012 2021-03-17 09:06:17,351 INFO [oncommand] [pool-40-thread-1] [c.n.i.a.c.HeadroomEngine] Calculated Observation final 83.0 3630.3963875141685 2021-03-17 09:06:17,586 INFO [oncommand] [pool-40-thread-1] [c.n.i.a.c.HeadroomEngine] Calculated Observation final 91.0 36946.1421738813 2021-03-17 09:06:17,586 INFO [oncommand] [pool-40-thread-1] [c.n.i.a.c.HeadroomEngine] Latency factor is zero 2021-03-17 09:06:17,637 INFO [oncommand] [pool-40-thread-1] [c.n.i.a.c.HeadroomEngine] Calculated Observation final 90.0 1157.229736354247 2021-03-17 09:06:17,776 INFO [oncommand] [pool-40-thread-1] [c.n.i.a.c.HeadroomEngine] Calculated Observation final 75.0 1687.323469665414 2021-03-17 09:06:17,776 INFO [oncommand] [pool-40-thread-1] [c.n.i.a.c.HeadroomEngine] Measured util 0.09759580343961716 or local ops 174.13299560546875 is low, using seedIOPS 1862.0 for resource at index 1. 2021-03-17 09:06:17,776 INFO [oncommand] [pool-40-thread-1] [c.n.i.a.c.HeadroomEngine] Measured util 0.17915800213813782 or local ops 347.63299560546875 is low, using seedIOPS 1862.0 for resource at index 2. 2021-03-17 09:06:17,776 INFO [oncommand] [pool-40-thread-1] [c.n.i.a.c.HeadroomEngine] Measured util 2.855180025100708 or local ops 93.7667007446289 is low, using seedIOPS 1862.0 for resource at index 3. 2021-03-17 09:06:17,776 INFO [oncommand] [pool-40-thread-1] [c.n.i.a.c.HeadroomEngine] Measured util 4.10837984085083 or local ops 921.6300048828125 is low, using seedIOPS 33783.0 for resource at index 5. 2021-03-17 09:06:17,776 INFO [oncommand] [pool-40-thread-1] [c.n.i.a.c.HeadroomFailoverPlanning] Internal: 0.004456480033695698, User: 41.89413487842325, Resource Index: 4, Resource Index: 5, Final currentHAUsedHeadroom: 55.864788477942604 2021-03-17 09:06:17,776 INFO [oncommand] [pool-40-thread-1] [c.n.i.a.c.HeadroomFailoverPlanning] Internal: 0.004456480033695698, User: 41.89413487842325, Resource Index: 5, Resource Index: 4, Final currentHAUsedHeadroom: 55.864788477942604 2021-03-17 09:06:17,776 INFO [oncommand] [pool-40-thread-1] [c.n.i.a.c.CurrentHeadroom] Total number of resources : 6 2021-03-17 09:06:17,776 INFO [oncommand] [pool-40-thread-1] [c.n.i.a.c.CurrentHeadroom] Total for Headroom Calculations : 0.773 seconds 2021-03-17 09:06:17,776 INFO [oncommand] [pool-40-thread-1] [c.n.i.a.c.CurrentHeadroom] Total time in current headroom : 0.773 seconds 2021-03-17 09:06:17,777 DEBUG [oncommand] [pool-40-thread-1] [o.s.t.jta.JtaTransactionManager] Creating new transaction with name [com.netapp.ipc.services.statistics.headroom.service.HeadroomStatService.insertAggrStats]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT 2021-03-17 09:06:17,777 DEBUG [oncommand] [pool-40-thread-1] [o.s.jdbc.core.JdbcTemplate] Executing prepared SQL update 2021-03-17 09:06:17,777 DEBUG [oncommand] [pool-40-thread-1] [o.s.jdbc.core.JdbcTemplate] Executing prepared SQL statement [DELETE FROM netapp_performance.sample_opm_headroom_aggr_1 WHERE objid=? AND time=?] 2021-03-17 09:06:17,777 DEBUG [oncommand] [pool-40-thread-1] [o.s.jdbc.datasource.DataSourceUtils] Fetching JDBC Connection from DataSource 2021-03-17 09:06:17,779 DEBUG [oncommand] [pool-40-thread-1] [o.s.jdbc.core.JdbcTemplate] Executing SQL batch update [INSERT INTO netapp_performance.sample_opm_headroom_aggr_1 (objid,time,`empty`,cOperationalPointAllWorkloads,cOperationalPointInternalWorkloads,isObservationBased,mConfidenceLevel,mOptimalPointLatency,mOptimalPointOps,mOptimalPointUtil,mcOptimalPointLatency,mcOptimalPointOps,mcOptimalPointUtil,oOperationalPointAllWorkloads,oOperationalPointInternalWorkloads,obConfidenceLevel,obOptimalPointLatency,obOptimalPointOps,obOptimalPointUtil,obcOptimalPointLatency,obcOptimalPointOps,obcOptimalPointUtil,serviceTime,cHRoomUsedPercent,cHRoomUsedNoInternalPercent,availableOps) VALUES (?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?)] 2021-03-17 09:06:17,779 DEBUG [oncommand] [pool-40-thread-1] [o.s.jdbc.core.JdbcTemplate] Executing prepared SQL statement [INSERT INTO netapp_performance.sample_opm_headroom_aggr_1 (objid,time,`empty`,cOperationalPointAllWorkloads,cOperationalPointInternalWorkloads,isObservationBased,mConfidenceLevel,mOptimalPointLatency,mOptimalPointOps,mOptimalPointUtil,mcOptimalPointLatency,mcOptimalPointOps,mcOptimalPointUtil,oOperationalPointAllWorkloads,oOperationalPointInternalWorkloads,obConfidenceLevel,obOptimalPointLatency,obOptimalPointOps,obOptimalPointUtil,obcOptimalPointLatency,obcOptimalPointOps,obcOptimalPointUtil,serviceTime,cHRoomUsedPercent,cHRoomUsedNoInternalPercent,availableOps) VALUES (?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?)] 2021-03-17 09:06:17,779 DEBUG [oncommand] [pool-40-thread-1] [o.s.jdbc.support.JdbcUtils] JDBC driver supports batch updates 2021-03-17 09:06:17,780 DEBUG [oncommand] [pool-40-thread-1] [o.s.jdbc.core.StatementCreatorUtils] JDBC getParameterType call failed - using fallback method instead: java.sql.SQLFeatureNotSupportedException: Getting parameter type metadata are not supported 2021-03-17 09:06:17,780 DEBUG [oncommand] [pool-40-thread-1] [o.s.jdbc.core.StatementCreatorUtils] JDBC getParameterType call failed - using fallback method instead: java.sql.SQLFeatureNotSupportedException: Getting parameter type metadata are not supported 2021-03-17 09:06:17,780 DEBUG [oncommand] [pool-40-thread-1] [o.s.jdbc.core.StatementCreatorUtils] JDBC getParameterType call failed - using fallback method instead: java.sql.SQLFeatureNotSupportedException: Getting parameter type metadata are not supported 2021-03-17 09:06:17,780 DEBUG [oncommand] [pool-40-thread-1] [o.s.jdbc.core.StatementCreatorUtils] JDBC getParameterType call failed - using fallback method instead: java.sql.SQLFeatureNotSupportedException: Getting parameter type metadata are not supported 2021-03-17 09:06:17,780 DEBUG [oncommand] [pool-40-thread-1] [o.s.jdbc.core.JdbcTemplate] Executing SQL batch update [INSERT INTO netapp_performance.sample_opm_headroom_aggr_1 (objid,time,`empty`,cOperationalPointAllWorkloads,cOperationalPointInternalWorkloads,isObservationBased,mConfidenceLevel,mOptimalPointLatency,mOptimalPointOps,mOptimalPointUtil,mcOptimalPointLatency,mcOptimalPointOps,mcOptimalPointUtil,oOperationalPointAllWorkloads,oOperationalPointInternalWorkloads,obConfidenceLevel,obOptimalPointLatency,obOptimalPointOps,obOptimalPointUtil,obcOptimalPointLatency,obcOptimalPointOps,obcOptimalPointUtil,serviceTime,cHRoomUsedPercent,cHRoomUsedNoInternalPercent,availableOps) VALUES (?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?)] 2021-03-17 09:06:17,780 DEBUG [oncommand] [pool-40-thread-1] [o.s.jdbc.core.JdbcTemplate] Executing prepared SQL statement [INSERT INTO netapp_performance.sample_opm_headroom_aggr_1 (objid,time,`empty`,cOperationalPointAllWorkloads,cOperationalPointInternalWorkloads,isObservationBased,mConfidenceLevel,mOptimalPointLatency,mOptimalPointOps,mOptimalPointUtil,mcOptimalPointLatency,mcOptimalPointOps,mcOptimalPointUtil,oOperationalPointAllWorkloads,oOperationalPointInternalWorkloads,obConfidenceLevel,obOptimalPointLatency,obOptimalPointOps,obOptimalPointUtil,obcOptimalPointLatency,obcOptimalPointOps,obcOptimalPointUtil,serviceTime,cHRoomUsedPercent,cHRoomUsedNoInternalPercent,availableOps) VALUES (?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?)] 2021-03-17 09:06:17,780 DEBUG [oncommand] [pool-40-thread-1] [o.s.jdbc.support.JdbcUtils] JDBC driver supports batch updates 2021-03-17 09:06:17,781 DEBUG [oncommand] [pool-40-thread-1] [o.s.jdbc.core.StatementCreatorUtils] JDBC getParameterType call failed - using fallback method instead: java.sql.SQLFeatureNotSupportedException: Getting parameter type metadata are not supported 2021-03-17 09:06:17,781 DEBUG [oncommand] [pool-40-thread-1] [o.s.jdbc.core.StatementCreatorUtils] JDBC getParameterType call failed - using fallback method instead: java.sql.SQLFeatureNotSupportedException: Getting parameter type metadata are not supported 2021-03-17 09:06:17,781 DEBUG [oncommand] [pool-40-thread-1] [o.s.jdbc.core.StatementCreatorUtils] JDBC getParameterType call failed - using fallback method instead: java.sql.SQLFeatureNotSupportedException: Getting parameter type metadata are not supported 2021-03-17 09:06:17,781 DEBUG [oncommand] [pool-40-thread-1] [o.s.jdbc.core.StatementCreatorUtils] JDBC getParameterType call failed - using fallback method instead: java.sql.SQLFeatureNotSupportedException: Getting parameter type metadata are not supported 2021-03-17 09:06:17,781 DEBUG [oncommand] [pool-40-thread-1] [o.s.t.jta.JtaTransactionManager] Initiating transaction commit 2021-03-17 09:06:17,784 DEBUG [oncommand] [pool-40-thread-1] [o.s.t.jta.JtaTransactionManager] Creating new transaction with name [com.netapp.ipc.services.statistics.headroom.service.HeadroomStatService.insertNodeStats]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT 2021-03-17 09:06:17,784 DEBUG [oncommand] [pool-40-thread-1] [o.s.jdbc.core.JdbcTemplate] Executing prepared SQL update 2021-03-17 09:06:17,784 DEBUG [oncommand] [pool-40-thread-1] [o.s.jdbc.core.JdbcTemplate] Executing prepared SQL statement [DELETE FROM netapp_performance.sample_opm_headroom_cpu WHERE objid=? AND time=?] 2021-03-17 09:06:17,784 DEBUG [oncommand] [pool-40-thread-1] [o.s.jdbc.datasource.DataSourceUtils] Fetching JDBC Connection from DataSource 2021-03-17 09:06:17,785 DEBUG [oncommand] [pool-40-thread-1] [o.s.t.jta.JtaTransactionManager] Participating in existing transaction 2021-03-17 09:06:17,785 DEBUG [oncommand] [pool-40-thread-1] [o.s.jdbc.core.JdbcTemplate] Executing SQL batch update [INSERT INTO netapp_performance.sample_opm_headroom_cpu (objid,time,`empty`,cOperationalPointAllWorkloads,cOperationalPointInternalWorkloads,haLatencyProjection,isObservationBased,mConfidenceLevel,mOptimalPointLatency,mOptimalPointOps,mOptimalPointUtil,mcOptimalPointLatency,mcOptimalPointOps,mcOptimalPointUtil,oOperationalPointAllWorkloads,oOperationalPointInternalWorkloads,obConfidenceLevel,obOptimalPointLatency,obOptimalPointOps,obOptimalPointUtil,obcOptimalPointLatency,obcOptimalPointOps,obcOptimalPointUtil,serviceTime,cHRoomUsedPercent,cHRoomUsedNoInternalPercent,haHRoomUsedProjection,haUtilProjection,haOpsProjection, haHRoomUsedNoInternalProjection, availableOps)VALUES (?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?)] 2021-03-17 09:06:17,785 DEBUG [oncommand] [pool-40-thread-1] [o.s.jdbc.core.JdbcTemplate] Executing prepared SQL statement [INSERT INTO netapp_performance.sample_opm_headroom_cpu (objid,time,`empty`,cOperationalPointAllWorkloads,cOperationalPointInternalWorkloads,haLatencyProjection,isObservationBased,mConfidenceLevel,mOptimalPointLatency,mOptimalPointOps,mOptimalPointUtil,mcOptimalPointLatency,mcOptimalPointOps,mcOptimalPointUtil,oOperationalPointAllWorkloads,oOperationalPointInternalWorkloads,obConfidenceLevel,obOptimalPointLatency,obOptimalPointOps,obOptimalPointUtil,obcOptimalPointLatency,obcOptimalPointOps,obcOptimalPointUtil,serviceTime,cHRoomUsedPercent,cHRoomUsedNoInternalPercent,haHRoomUsedProjection,haUtilProjection,haOpsProjection, haHRoomUsedNoInternalProjection, availableOps)VALUES (?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?)] 2021-03-17 09:06:17,785 DEBUG [oncommand] [pool-40-thread-1] [o.s.jdbc.support.JdbcUtils] JDBC driver supports batch updates 2021-03-17 09:06:17,786 DEBUG [oncommand] [pool-40-thread-1] [o.s.jdbc.core.StatementCreatorUtils] JDBC getParameterType call failed - using fallback method instead: java.sql.SQLFeatureNotSupportedException: Getting parameter type metadata are not supported 2021-03-17 09:06:17,786 DEBUG [oncommand] [pool-40-thread-1] [o.s.jdbc.core.StatementCreatorUtils] JDBC getParameterType call failed - using fallback method instead: java.sql.SQLFeatureNotSupportedException: Getting parameter type metadata are not supported 2021-03-17 09:06:17,786 DEBUG [oncommand] [pool-40-thread-1] [o.s.jdbc.core.StatementCreatorUtils] JDBC getParameterType call failed - using fallback method instead: java.sql.SQLFeatureNotSupportedException: Getting parameter type metadata are not supported 2021-03-17 09:06:17,786 DEBUG [oncommand] [pool-40-thread-1] [o.s.jdbc.core.StatementCreatorUtils] JDBC getParameterType call failed - using fallback method instead: java.sql.SQLFeatureNotSupportedException: Getting parameter type metadata are not supported 2021-03-17 09:06:17,786 DEBUG [oncommand] [pool-40-thread-1] [o.s.jdbc.core.JdbcTemplate] Executing SQL batch update [INSERT INTO netapp_performance.sample_opm_headroom_cpu (objid,time,`empty`,cOperationalPointAllWorkloads,cOperationalPointInternalWorkloads,haLatencyProjection,isObservationBased,mConfidenceLevel,mOptimalPointLatency,mOptimalPointOps,mOptimalPointUtil,mcOptimalPointLatency,mcOptimalPointOps,mcOptimalPointUtil,oOperationalPointAllWorkloads,oOperationalPointInternalWorkloads,obConfidenceLevel,obOptimalPointLatency,obOptimalPointOps,obOptimalPointUtil,obcOptimalPointLatency,obcOptimalPointOps,obcOptimalPointUtil,serviceTime,cHRoomUsedPercent,cHRoomUsedNoInternalPercent,haHRoomUsedProjection,haUtilProjection,haOpsProjection, haHRoomUsedNoInternalProjection, availableOps)VALUES (?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?)] 2021-03-17 09:06:17,786 DEBUG [oncommand] [pool-40-thread-1] [o.s.jdbc.core.JdbcTemplate] Executing prepared SQL statement [INSERT INTO netapp_performance.sample_opm_headroom_cpu (objid,time,`empty`,cOperationalPointAllWorkloads,cOperationalPointInternalWorkloads,haLatencyProjection,isObservationBased,mConfidenceLevel,mOptimalPointLatency,mOptimalPointOps,mOptimalPointUtil,mcOptimalPointLatency,mcOptimalPointOps,mcOptimalPointUtil,oOperationalPointAllWorkloads,oOperationalPointInternalWorkloads,obConfidenceLevel,obOptimalPointLatency,obOptimalPointOps,obOptimalPointUtil,obcOptimalPointLatency,obcOptimalPointOps,obcOptimalPointUtil,serviceTime,cHRoomUsedPercent,cHRoomUsedNoInternalPercent,haHRoomUsedProjection,haUtilProjection,haOpsProjection, haHRoomUsedNoInternalProjection, availableOps)VALUES (?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?)] 2021-03-17 09:06:17,786 DEBUG [oncommand] [pool-40-thread-1] [o.s.jdbc.support.JdbcUtils] JDBC driver supports batch updates 2021-03-17 09:06:17,787 DEBUG [oncommand] [pool-40-thread-1] [o.s.jdbc.core.StatementCreatorUtils] JDBC getParameterType call failed - using fallback method instead: java.sql.SQLFeatureNotSupportedException: Getting parameter type metadata are not supported 2021-03-17 09:06:17,787 DEBUG [oncommand] [pool-40-thread-1] [o.s.jdbc.core.StatementCreatorUtils] JDBC getParameterType call failed - using fallback method instead: java.sql.SQLFeatureNotSupportedException: Getting parameter type metadata are not supported 2021-03-17 09:06:17,787 DEBUG [oncommand] [pool-40-thread-1] [o.s.jdbc.core.StatementCreatorUtils] JDBC getParameterType call failed - using fallback method instead: java.sql.SQLFeatureNotSupportedException: Getting parameter type metadata are not supported 2021-03-17 09:06:17,787 DEBUG [oncommand] [pool-40-thread-1] [o.s.jdbc.core.StatementCreatorUtils] JDBC getParameterType call failed - using fallback method instead: java.sql.SQLFeatureNotSupportedException: Getting parameter type metadata are not supported 2021-03-17 09:06:17,787 DEBUG [oncommand] [pool-40-thread-1] [o.s.t.jta.JtaTransactionManager] Initiating transaction commit 2021-03-17 09:06:17,790 INFO [oncommand] [pool-40-thread-1] [c.n.ipc.common.util.TimeTracker] TIME TRACK RESULTS: Headroom engine stats generation for cluster : 1 Overall Time : 833ms Time Differences between Marks: (DFP: Diff from Prior [ms], DFB: Diff From Begining [ms]) Mark Description DFP DFB --------------------------------------------------------------------- Retrieved stats from service 27 27 Providing stats to headroom engine 0 27 Retrieved stats from headroom engine 792 819 Persisting headroom engine stats in the database 0 819 Finished persisting headroom engine stats in the database 14 833 2021-03-17 09:06:17,790 DEBUG [oncommand] [pool-40-thread-1] [o.s.t.jta.JtaTransactionManager] Creating new transaction with name [com.netapp.ipc.services.threshold.service.ThresholdPolicyService.getPolicyIdsByObjKey]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT 2021-03-17 09:06:17,790 DEBUG [oncommand] [pool-40-thread-1] [o.s.t.jta.JtaTransactionManager] Initiating transaction commit 2021-03-17 09:06:17,790 DEBUG [oncommand] [pool-40-thread-1] [o.s.t.jta.JtaTransactionManager] Creating new transaction with name [com.netapp.ipc.services.threshold.service.ThresholdPolicyService.getPolicyIdsByObjKey]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT 2021-03-17 09:06:17,790 DEBUG [oncommand] [pool-40-thread-1] [o.s.t.jta.JtaTransactionManager] Initiating transaction commit 2021-03-17 09:06:17,790 DEBUG [oncommand] [pool-40-thread-1] [o.s.t.jta.JtaTransactionManager] Creating new transaction with name [com.netapp.ipc.services.threshold.service.ThresholdPolicyService.getPolicyIdsByObjKey]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT 2021-03-17 09:06:17,790 DEBUG [oncommand] [pool-40-thread-1] [o.s.t.jta.JtaTransactionManager] Initiating transaction commit 2021-03-17 09:06:17,790 DEBUG [oncommand] [pool-40-thread-1] [o.s.t.jta.JtaTransactionManager] Creating new transaction with name [com.netapp.ipc.services.threshold.service.ThresholdPolicyService.getPolicyIdsByObjKey]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT 2021-03-17 09:06:17,790 DEBUG [oncommand] [pool-40-thread-1] [o.s.t.jta.JtaTransactionManager] Initiating transaction commit 2021-03-17 09:06:17,791 DEBUG [oncommand] [pool-40-thread-1] [o.s.t.jta.JtaTransactionManager] Creating new transaction with name [com.netapp.ipc.services.threshold.service.ThresholdPolicyService.getConformancePolicies]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT 2021-03-17 09:06:17,791 DEBUG [oncommand] [pool-40-thread-1] [o.s.t.jta.JtaTransactionManager] Initiating transaction commit 2021-03-17 09:06:17,791 DEBUG [oncommand] [pool-40-thread-1] [o.s.t.jta.JtaTransactionManager] Creating new transaction with name [com.netapp.ipc.services.threshold.service.ThresholdPolicyService.getConformancePolicies]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT 2021-03-17 09:06:17,791 DEBUG [oncommand] [pool-40-thread-1] [o.s.t.jta.JtaTransactionManager] Initiating transaction commit 2021-03-17 09:06:17,791 DEBUG [oncommand] [pool-40-thread-1] [o.s.t.jta.JtaTransactionManager] Creating new transaction with name [com.netapp.ipc.services.threshold.service.ThresholdPolicyService.getConformancePolicies]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT 2021-03-17 09:06:17,791 DEBUG [oncommand] [pool-40-thread-1] [o.s.t.jta.JtaTransactionManager] Initiating transaction commit 2021-03-17 09:06:17,791 DEBUG [oncommand] [pool-40-thread-1] [o.s.t.jta.JtaTransactionManager] Creating new transaction with name [com.netapp.ipc.services.threshold.service.ThresholdPolicyService.getConformancePolicies]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT 2021-03-17 09:06:17,791 DEBUG [oncommand] [pool-40-thread-1] [o.s.t.jta.JtaTransactionManager] Initiating transaction commit 2021-03-17 09:06:17,791 DEBUG [oncommand] [pool-40-thread-1] [o.s.t.jta.JtaTransactionManager] Creating new transaction with name [com.netapp.ipc.services.threshold.service.ThresholdPolicyService.getTCIPoliciesByPolicyTypes]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT 2021-03-17 09:06:17,791 DEBUG [oncommand] [pool-40-thread-1] [o.s.t.jta.JtaTransactionManager] Initiating transaction commit 2021-03-17 09:06:17,792 DEBUG [oncommand] [pool-41-thread-1] [o.s.jdbc.core.JdbcTemplate] Executing prepared SQL query 2021-03-17 09:06:17,792 DEBUG [oncommand] [pool-41-thread-1] [o.s.jdbc.core.JdbcTemplate] Executing prepared SQL statement [SELECT lun.*, volume.nodeId nodeId, volume.aggregateId aggregateId, aggr.name aggregateName, node.name nodeName FROM netapp_model_view.lun_full lun, netapp_model_view.volume_full volume LEFT OUTER JOIN netapp_model_view.aggregate aggr ON volume.aggregateId=aggr.objid LEFT OUTER JOIN netapp_model_view.node node ON volume.nodeId=node.objid WHERE lun.objid=? AND lun.volumeId = volume.objId] 2021-03-17 09:06:17,792 DEBUG [oncommand] [pool-41-thread-1] [o.s.jdbc.datasource.DataSourceUtils] Fetching JDBC Connection from DataSource 2021-03-17 09:06:17,795 INFO [oncommand] [pool-41-thread-1] [c.n.i.s.a.c.ConformanceAnalysisService] Conformance check complete. 0 results for clusterId = 1, sampleTime = 1615989862040(Wed Mar 17 09:04:22 CDT 2021) 2021-03-17 09:06:17,795 INFO [oncommand] [pool-41-thread-1] [c.n.i.a.common.AnalysisService] Conformance analysis phase 2 took 0 ms 2021-03-17 09:06:17,795 INFO [oncommand] [pool-41-thread-1] [c.n.i.a.common.AnalysisService] Static analysis phase 2 took 0 ms 2021-03-17 09:06:17,795 INFO [oncommand] [pool-41-thread-1] [c.n.scalemonitor.ScaleMonitorProbe] Dynamic analysis phase 2 took 0 ms 2021-03-17 09:06:17,796 DEBUG [oncommand] [pool-41-thread-1] [o.s.jdbc.core.JdbcTemplate] Executing prepared SQL query 2021-03-17 09:06:17,796 DEBUG [oncommand] [pool-41-thread-1] [o.s.jdbc.core.JdbcTemplate] Executing prepared SQL statement [SELECT * FROM netapp_model_view.node WHERE clusterId IN (?)] 2021-03-17 09:06:17,796 DEBUG [oncommand] [pool-41-thread-1] [o.s.jdbc.datasource.DataSourceUtils] Fetching JDBC Connection from DataSource 2021-03-17 09:06:17,797 DEBUG [oncommand] [pool-41-thread-1] [o.s.t.jta.JtaTransactionManager] Creating new transaction with name [com.netapp.ipc.services.threshold.service.ThresholdPolicyService.getTCIPoliciesByPolicyTypes]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT 2021-03-17 09:06:17,797 DEBUG [oncommand] [pool-41-thread-1] [o.s.t.jta.JtaTransactionManager] Initiating transaction commit 2021-03-17 09:06:17,797 INFO [oncommand] [pool-41-thread-1] [c.n.i.a.t.NodeUtilizationHAPairPolicyService] ThresholdPolicy policy is ThresholdPolicy [id=3, name=TCI_HEADROOM_UTILIZATION_HA_PAIR_POLICY, elementType=CLUSTER_NODE, description=TCI Internal Policy, isEnabled=true, thresholds=[com.netapp.ipc.domain.threshold.Threshold@b84d9224], hidden=true, policyType=TCI] 2021-03-17 09:06:17,798 INFO [oncommand] [pool-41-thread-1] [c.n.i.a.t.NodeUtilizationHAPairPolicyService] The threshold is [com.netapp.ipc.domain.threshold.Threshold@b84d9224] 2021-03-17 09:06:17,798 DEBUG [oncommand] [pool-41-thread-1] [o.s.t.jta.JtaTransactionManager] Creating new transaction with name [com.netapp.ipc.services.performance.service.NodePerformanceQueryService.getSamples]: PROPAGATION_REQUIRES_NEW,ISOLATION_DEFAULT 2021-03-17 09:06:17,803 DEBUG [oncommand] [pool-41-thread-1] [o.s.t.jta.JtaTransactionManager] Initiating transaction commit 2021-03-17 09:06:17,803 DEBUG [oncommand] [pool-41-thread-1] [o.s.jdbc.core.JdbcTemplate] Executing prepared SQL query 2021-03-17 09:06:17,804 DEBUG [oncommand] [pool-41-thread-1] [o.s.jdbc.core.JdbcTemplate] Executing prepared SQL statement [SELECT * FROM netapp_model_view.node_full WHERE objid=?] 2021-03-17 09:06:17,804 DEBUG [oncommand] [pool-41-thread-1] [o.s.jdbc.datasource.DataSourceUtils] Fetching JDBC Connection from DataSource 2021-03-17 09:06:17,805 DEBUG [oncommand] [pool-41-thread-1] [o.s.jdbc.core.JdbcTemplate] Executing prepared SQL query 2021-03-17 09:06:17,805 DEBUG [oncommand] [pool-41-thread-1] [o.s.jdbc.core.JdbcTemplate] Executing prepared SQL statement [SELECT * from opm.acquisition_info where clusterId = ? and time >= ? and time <= ? order by time asc] 2021-03-17 09:06:17,805 DEBUG [oncommand] [pool-41-thread-1] [o.s.jdbc.datasource.DataSourceUtils] Fetching JDBC Connection from DataSource 2021-03-17 09:06:17,806 DEBUG [oncommand] [pool-41-thread-1] [o.s.jdbc.core.JdbcTemplate] Executing prepared SQL query 2021-03-17 09:06:17,806 DEBUG [oncommand] [pool-41-thread-1] [o.s.jdbc.core.JdbcTemplate] Executing prepared SQL statement [SELECT * from acquisition.ds_attrs where ds_id = ? AND name LIKE "netappstorageperformance.clock.polling.offset" ] 2021-03-17 09:06:17,806 DEBUG [oncommand] [pool-41-thread-1] [o.s.jdbc.datasource.DataSourceUtils] Fetching JDBC Connection from DataSource 2021-03-17 09:06:17,807 DEBUG [oncommand] [pool-41-thread-1] [o.s.t.jta.JtaTransactionManager] Creating new transaction with name [com.netapp.ipc.services.performance.service.OpmHeadRoomCPUPerformanceQueryService.getSamples]: PROPAGATION_REQUIRES_NEW,ISOLATION_DEFAULT 2021-03-17 09:06:17,810 DEBUG [oncommand] [pool-41-thread-1] [o.s.t.jta.JtaTransactionManager] Initiating transaction commit 2021-03-17 09:06:17,810 DEBUG [oncommand] [pool-41-thread-1] [o.s.jdbc.core.JdbcTemplate] Executing prepared SQL query 2021-03-17 09:06:17,810 DEBUG [oncommand] [pool-41-thread-1] [o.s.jdbc.core.JdbcTemplate] Executing prepared SQL statement [SELECT * FROM netapp_model_view.node_full WHERE objid=?] 2021-03-17 09:06:17,810 DEBUG [oncommand] [pool-41-thread-1] [o.s.jdbc.datasource.DataSourceUtils] Fetching JDBC Connection from DataSource 2021-03-17 09:06:17,811 DEBUG [oncommand] [pool-41-thread-1] [o.s.jdbc.core.JdbcTemplate] Executing prepared SQL query 2021-03-17 09:06:17,811 DEBUG [oncommand] [pool-41-thread-1] [o.s.jdbc.core.JdbcTemplate] Executing prepared SQL statement [SELECT * from opm.acquisition_info where clusterId = ? and time >= ? and time <= ? order by time asc] 2021-03-17 09:06:17,811 DEBUG [oncommand] [pool-41-thread-1] [o.s.jdbc.datasource.DataSourceUtils] Fetching JDBC Connection from DataSource 2021-03-17 09:06:17,812 DEBUG [oncommand] [pool-41-thread-1] [o.s.jdbc.core.JdbcTemplate] Executing prepared SQL query 2021-03-17 09:06:17,812 DEBUG [oncommand] [pool-41-thread-1] [o.s.jdbc.core.JdbcTemplate] Executing prepared SQL statement [SELECT * from acquisition.ds_attrs where ds_id = ? AND name LIKE "netappstorageperformance.clock.polling.offset" ] 2021-03-17 09:06:17,812 DEBUG [oncommand] [pool-41-thread-1] [o.s.jdbc.datasource.DataSourceUtils] Fetching JDBC Connection from DataSource 2021-03-17 09:06:17,814 DEBUG [oncommand] [pool-41-thread-1] [o.s.jdbc.core.JdbcTemplate] Executing prepared SQL query 2021-03-17 09:06:17,814 DEBUG [oncommand] [pool-41-thread-1] [o.s.jdbc.core.JdbcTemplate] Executing prepared SQL statement [SELECT objid FROM netapp_model_view.node WHERE clusterId=?] 2021-03-17 09:06:17,814 DEBUG [oncommand] [pool-41-thread-1] [o.s.jdbc.datasource.DataSourceUtils] Fetching JDBC Connection from DataSource 2021-03-17 09:06:17,815 DEBUG [oncommand] [pool-41-thread-1] [o.s.t.jta.JtaTransactionManager] Creating new transaction with name [com.netapp.ipc.services.threshold.service.ThresholdPolicyService.getTCIPoliciesByPolicyTypes]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT 2021-03-17 09:06:17,815 DEBUG [oncommand] [pool-41-thread-1] [o.s.t.jta.JtaTransactionManager] Initiating transaction commit 2021-03-17 09:06:17,815 DEBUG [oncommand] [pool-41-thread-1] [o.s.jdbc.core.JdbcTemplate] Executing prepared SQL query 2021-03-17 09:06:17,815 DEBUG [oncommand] [pool-41-thread-1] [o.s.jdbc.core.JdbcTemplate] Executing prepared SQL statement [SELECT a.*, aocm.tieringFullnessThreshold,aocm.usedSpace FROM netapp_model_view.aggregate_full a left join netapp_model_view.aggregate_objectstore_config_mapping_full aocm on a.objid = aocm.aggregateId WHERE a.nodeId IN (?)] 2021-03-17 09:06:17,815 DEBUG [oncommand] [pool-41-thread-1] [o.s.jdbc.datasource.DataSourceUtils] Fetching JDBC Connection from DataSource 2021-03-17 09:06:17,817 DEBUG [oncommand] [pool-41-thread-1] [o.s.t.jta.JtaTransactionManager] Creating new transaction with name [com.netapp.ipc.services.performance.service.AggregatePerformanceQueryService.getSamples]: PROPAGATION_REQUIRES_NEW,ISOLATION_DEFAULT 2021-03-17 09:06:17,820 DEBUG [oncommand] [pool-41-thread-1] [o.s.t.jta.JtaTransactionManager] Initiating transaction commit 2021-03-17 09:06:17,820 DEBUG [oncommand] [pool-41-thread-1] [o.s.jdbc.core.JdbcTemplate] Executing prepared SQL query 2021-03-17 09:06:17,820 DEBUG [oncommand] [pool-41-thread-1] [o.s.jdbc.core.JdbcTemplate] Executing prepared SQL statement [SELECT a.*, aocm.tieringFullnessThreshold,aocm.usedSpace FROM netapp_model_view.aggregate_full a left join netapp_model_view.aggregate_objectstore_config_mapping_full aocm on a.objid = aocm.aggregateId where a.objid=?] 2021-03-17 09:06:17,820 DEBUG [oncommand] [pool-41-thread-1] [o.s.jdbc.datasource.DataSourceUtils] Fetching JDBC Connection from DataSource 2021-03-17 09:06:17,822 DEBUG [oncommand] [pool-41-thread-1] [o.s.jdbc.core.JdbcTemplate] Executing prepared SQL query 2021-03-17 09:06:17,822 DEBUG [oncommand] [pool-41-thread-1] [o.s.jdbc.core.JdbcTemplate] Executing prepared SQL statement [SELECT * from opm.acquisition_info where clusterId = ? and time >= ? and time <= ? order by time asc] 2021-03-17 09:06:17,822 DEBUG [oncommand] [pool-41-thread-1] [o.s.jdbc.datasource.DataSourceUtils] Fetching JDBC Connection from DataSource 2021-03-17 09:06:17,822 DEBUG [oncommand] [pool-41-thread-1] [o.s.jdbc.core.JdbcTemplate] Executing prepared SQL query 2021-03-17 09:06:17,822 DEBUG [oncommand] [pool-41-thread-1] [o.s.jdbc.core.JdbcTemplate] Executing prepared SQL statement [SELECT * from acquisition.ds_attrs where ds_id = ? AND name LIKE "netappstorageperformance.clock.polling.offset" ] 2021-03-17 09:06:17,822 DEBUG [oncommand] [pool-41-thread-1] [o.s.jdbc.datasource.DataSourceUtils] Fetching JDBC Connection from DataSource 2021-03-17 09:06:17,825 DEBUG [oncommand] [pool-41-thread-1] [o.s.t.jta.JtaTransactionManager] Creating new transaction with name [com.netapp.ipc.services.threshold.service.ThresholdPolicyService.getTCIPoliciesByPolicyTypes]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT 2021-03-17 09:06:17,825 DEBUG [oncommand] [pool-41-thread-1] [o.s.t.jta.JtaTransactionManager] Initiating transaction commit 2021-03-17 09:06:17,825 DEBUG [oncommand] [pool-41-thread-1] [o.s.jdbc.core.JdbcTemplate] Executing prepared SQL query 2021-03-17 09:06:17,825 DEBUG [oncommand] [pool-41-thread-1] [o.s.jdbc.core.JdbcTemplate] Executing prepared SQL statement [SELECT a.*, aocm.tieringFullnessThreshold,aocm.usedSpace FROM netapp_model_view.aggregate_full a left join netapp_model_view.aggregate_objectstore_config_mapping_full aocm on a.objid = aocm.aggregateId WHERE a.nodeId IN (?)] 2021-03-17 09:06:17,825 DEBUG [oncommand] [pool-41-thread-1] [o.s.jdbc.datasource.DataSourceUtils] Fetching JDBC Connection from DataSource 2021-03-17 09:06:17,827 DEBUG [oncommand] [pool-41-thread-1] [o.s.t.jta.JtaTransactionManager] Creating new transaction with name [com.netapp.ipc.services.performance.service.AggregatePerformanceQueryService.getSamples]: PROPAGATION_REQUIRES_NEW,ISOLATION_DEFAULT 2021-03-17 09:06:17,830 DEBUG [oncommand] [pool-41-thread-1] [o.s.t.jta.JtaTransactionManager] Initiating transaction commit 2021-03-17 09:06:17,830 DEBUG [oncommand] [pool-41-thread-1] [o.s.jdbc.core.JdbcTemplate] Executing prepared SQL query 2021-03-17 09:06:17,830 DEBUG [oncommand] [pool-41-thread-1] [o.s.jdbc.core.JdbcTemplate] Executing prepared SQL statement [SELECT a.*, aocm.tieringFullnessThreshold,aocm.usedSpace FROM netapp_model_view.aggregate_full a left join netapp_model_view.aggregate_objectstore_config_mapping_full aocm on a.objid = aocm.aggregateId where a.objid=?] 2021-03-17 09:06:17,830 DEBUG [oncommand] [pool-41-thread-1] [o.s.jdbc.datasource.DataSourceUtils] Fetching JDBC Connection from DataSource 2021-03-17 09:06:17,832 DEBUG [oncommand] [pool-41-thread-1] [o.s.jdbc.core.JdbcTemplate] Executing prepared SQL query 2021-03-17 09:06:17,832 DEBUG [oncommand] [pool-41-thread-1] [o.s.jdbc.core.JdbcTemplate] Executing prepared SQL statement [SELECT * from opm.acquisition_info where clusterId = ? and time >= ? and time <= ? order by time asc] 2021-03-17 09:06:17,832 DEBUG [oncommand] [pool-41-thread-1] [o.s.jdbc.datasource.DataSourceUtils] Fetching JDBC Connection from DataSource 2021-03-17 09:06:17,833 DEBUG [oncommand] [pool-41-thread-1] [o.s.jdbc.core.JdbcTemplate] Executing prepared SQL query 2021-03-17 09:06:17,833 DEBUG [oncommand] [pool-41-thread-1] [o.s.jdbc.core.JdbcTemplate] Executing prepared SQL statement [SELECT * from acquisition.ds_attrs where ds_id = ? AND name LIKE "netappstorageperformance.clock.polling.offset" ] 2021-03-17 09:06:17,833 DEBUG [oncommand] [pool-41-thread-1] [o.s.jdbc.datasource.DataSourceUtils] Fetching JDBC Connection from DataSource 2021-03-17 09:06:17,833 INFO [oncommand] [pool-41-thread-1] [c.n.i.a.common.AnalysisService] TCI analysis phase 2 took 37 ms 2021-03-17 09:06:17,834 INFO [oncommand] [pool-41-thread-1] [c.n.i.a.c.ReasoningEngineService] Invoking Reasoning Engine 2021-03-17 09:06:17,834 INFO [oncommand] [pool-41-thread-1] [c.n.i.a.c.ReasoningEngineService] PERSISTING Node Performance Capacity Used count of : 0 2021-03-17 09:06:17,834 INFO [oncommand] [pool-41-thread-1] [c.n.i.a.c.ReasoningEngineService] PERSISTING QoS Threshold count of : 0 2021-03-17 09:06:17,834 DEBUG [oncommand] [pool-41-thread-1] [o.s.t.jta.JtaTransactionManager] Creating new transaction with name [com.netapp.ocum.event.service.PerformanceEventService.renewEventsForInProgressRemediations]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT 2021-03-17 09:06:17,834 DEBUG [oncommand] [pool-41-thread-1] [o.s.jdbc.core.JdbcTemplate] Executing prepared SQL query 2021-03-17 09:06:17,834 DEBUG [oncommand] [pool-41-thread-1] [o.s.jdbc.core.JdbcTemplate] Executing prepared SQL statement [SELECT * FROM opm.event_remediation_view WHERE clusterId=?] 2021-03-17 09:06:17,834 DEBUG [oncommand] [pool-41-thread-1] [o.s.jdbc.datasource.DataSourceUtils] Fetching JDBC Connection from DataSource 2021-03-17 09:06:17,841 DEBUG [oncommand] [pool-41-thread-1] [o.s.t.jta.JtaTransactionManager] Initiating transaction commit 2021-03-17 09:06:17,841 DEBUG [oncommand] [pool-41-thread-1] [o.s.t.jta.JtaTransactionManager] Creating new transaction with name [com.netapp.ocum.event.service.PerformanceEventService.updateEventsToObsolete]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT 2021-03-17 09:06:17,841 DEBUG [oncommand] [pool-41-thread-1] [o.s.t.jta.JtaTransactionManager] Participating in existing transaction 2021-03-17 09:06:17,841 DEBUG [oncommand] [pool-41-thread-1] [o.s.jdbc.datasource.DataSourceUtils] Fetching JDBC Connection from DataSource 2021-03-17 09:06:17,843 DEBUG [oncommand] [pool-41-thread-1] [o.s.t.jta.JtaTransactionManager] Initiating transaction commit 2021-03-17 09:06:17,843 DEBUG [oncommand] [pool-41-thread-1] [o.s.jdbc.core.JdbcTemplate] Executing prepared SQL update 2021-03-17 09:06:17,843 DEBUG [oncommand] [pool-41-thread-1] [o.s.jdbc.core.JdbcTemplate] Executing prepared SQL statement [UPDATE opm.acquisition_info SET analysisDuration = ? where time = ? and clusterId = ?] 2021-03-17 09:06:17,843 DEBUG [oncommand] [pool-41-thread-1] [o.s.jdbc.datasource.DataSourceUtils] Fetching JDBC Connection from DataSource 2021-03-17 09:06:17,846 INFO [oncommand] [pool-41-thread-1] [c.n.i.a.common.AnalysisService] Completed analysis on cluster: 1 for time: Wed Mar 17 09:04:22 CDT 2021 and it took 51 ms 2021-03-17 09:06:17,868 DEBUG [oncommand] [pool-37-thread-1] [o.s.jdbc.core.JdbcTemplate] Executing SQL query [SELECT * FROM opm.ext_server_config] 2021-03-17 09:06:17,868 DEBUG [oncommand] [pool-37-thread-1] [o.s.jdbc.datasource.DataSourceUtils] Fetching JDBC Connection from DataSource 2021-03-17 09:06:17,869 DEBUG [oncommand] [pool-37-thread-1] [o.s.jdbc.core.JdbcTemplate] Executing prepared SQL query 2021-03-17 09:06:17,869 DEBUG [oncommand] [pool-37-thread-1] [o.s.jdbc.core.JdbcTemplate] Executing prepared SQL statement [SELECT * FROM opm.ext_data_config WHERE serverId=?] 2021-03-17 09:06:17,869 DEBUG [oncommand] [pool-37-thread-1] [o.s.jdbc.datasource.DataSourceUtils] Fetching JDBC Connection from DataSource 2021-03-17 09:06:19,015 DEBUG [oncommand] [unifiedManagerScheduler_QuartzSchedulerThread] [o.quartz.core.QuartzSchedulerThread] batch acquisition of 0 triggers 2021-03-17 09:06:22,362 DEBUG [oncommand] [taskScheduler-3] [o.s.jdbc.datasource.DataSourceUtils] Fetching JDBC Connection from DataSource 2021-03-17 09:06:22,364 DEBUG [oncommand] [taskScheduler-3] [o.s.jdbc.datasource.DataSourceUtils] Fetching JDBC Connection from DataSource 2021-03-17 09:06:22,365 DEBUG [oncommand] [taskScheduler-3] [o.s.jdbc.datasource.DataSourceUtils] Fetching JDBC Connection from DataSource 2021-03-17 09:06:22,368 DEBUG [oncommand] [taskScheduler-3] [o.s.jdbc.datasource.DataSourceUtils] Fetching JDBC Connection from DataSource 2021-03-17 09:06:22,369 DEBUG [oncommand] [taskScheduler-3] [o.s.jdbc.datasource.DataSourceUtils] Fetching JDBC Connection from DataSource 2021-03-17 09:06:22,370 DEBUG [oncommand] [taskScheduler-3] [o.s.jdbc.datasource.DataSourceUtils] Fetching JDBC Connection from DataSource 2021-03-17 09:06:22,370 DEBUG [oncommand] [taskScheduler-3] [o.s.jdbc.datasource.DataSourceUtils] Fetching JDBC Connection from DataSource 2021-03-17 09:06:22,373 DEBUG [oncommand] [taskScheduler-3] [o.s.jdbc.datasource.DataSourceUtils] Fetching JDBC Connection from DataSource 2021-03-17 09:06:22,374 DEBUG [oncommand] [taskScheduler-3] [o.s.jdbc.datasource.DataSourceUtils] Fetching JDBC Connection from DataSource 2021-03-17 09:06:42,675 DEBUG [oncommand] [unifiedManagerScheduler_QuartzSchedulerThread] [o.quartz.core.QuartzSchedulerThread] batch acquisition of 0 triggers 2021-03-17 09:06:47,224 DEBUG [oncommand] [default task-607] [o.s.s.w.u.m.AntPathRequestMatcher] Checking match of request : '/api/private/event-count-summary'; against '/apis/**' 2021-03-17 09:06:47,225 DEBUG [oncommand] [default task-607] [o.s.s.w.u.m.AntPathRequestMatcher] Checking match of request : '/api/private/event-count-summary'; against '/api/**' 2021-03-17 09:06:47,225 DEBUG [oncommand] [default task-607] [o.s.security.web.FilterChainProxy] /api/private/event-count-summary at position 1 of 1 in additional filter chain; firing Filter: 'NoOpFilter' 2021-03-17 09:06:47,225 DEBUG [oncommand] [default task-607] [o.s.security.web.FilterChainProxy] /api/private/event-count-summary reached end of additional filter chain; proceeding with original chain 2021-03-17 09:06:47,225 DEBUG [oncommand] [default task-607] [o.s.s.w.u.m.AntPathRequestMatcher] Checking match of request : '/api/private/event-count-summary'; against '/api/**' 2021-03-17 09:06:47,225 DEBUG [oncommand] [default task-607] [o.s.security.web.FilterChainProxy] /api/private/event-count-summary at position 1 of 13 in additional filter chain; firing Filter: 'PreSecurityAuditLoggerConfigFilter' 2021-03-17 09:06:47,225 DEBUG [oncommand] [default task-607] [o.s.security.web.FilterChainProxy] /api/private/event-count-summary at position 2 of 13 in additional filter chain; firing Filter: 'RestCorsFilter' 2021-03-17 09:06:47,225 DEBUG [oncommand] [default task-607] [o.s.security.web.FilterChainProxy] /api/private/event-count-summary at position 3 of 13 in additional filter chain; firing Filter: 'ChannelProcessingFilter' 2021-03-17 09:06:47,225 DEBUG [oncommand] [default task-607] [o.s.s.w.a.c.ChannelProcessingFilter] Request: FilterInvocation: URL: /api/private/event-count-summary; ConfigAttributes: [REQUIRES_SECURE_CHANNEL] 2021-03-17 09:06:47,225 DEBUG [oncommand] [default task-607] [o.s.security.web.FilterChainProxy] /api/private/event-count-summary at position 4 of 13 in additional filter chain; firing Filter: 'SecurityContextPersistenceFilter' 2021-03-17 09:06:47,225 DEBUG [oncommand] [default task-607] [o.s.s.w.c.HttpSessionSecurityContextRepository] Obtained a valid SecurityContext from SPRING_SECURITY_CONTEXT: 'org.springframework.security.core.context.SecurityContextImpl@7d493e6e: Authentication: org.springframework.security.authentication.UsernamePasswordAuthenticationToken@7d493e6e: Principal: admin; Credentials: [PROTECTED]; Authenticated: true; Details: org.springframework.security.web.authentication.WebAuthenticationDetails@ffffe21a: RemoteIpAddress: 172.20.230.62; SessionId: null; Granted Authorities: com.netapp.dfm.core.authentication.RbacPrivilegeGrantedAuthorityAdapter@299e7eec, com.netapp.dfm.core.authentication.RbacPrivilegeGrantedAuthorityAdapter@157b1fb, com.netapp.dfm.core.authentication.RbacPrivilegeGrantedAuthorityAdapter@316f967d, com.netapp.dfm.core.authentication.RbacPrivilegeGrantedAuthorityAdapter@61697995' 2021-03-17 09:06:47,225 DEBUG [oncommand] [default task-607] [o.s.security.web.FilterChainProxy] /api/private/event-count-summary at position 5 of 13 in additional filter chain; firing Filter: 'TemporaryTokenAuthenticationFilter' 2021-03-17 09:06:47,225 DEBUG [oncommand] [default task-607] [o.s.security.web.FilterChainProxy] /api/private/event-count-summary at position 6 of 13 in additional filter chain; firing Filter: 'BasicAuthenticationFilter' 2021-03-17 09:06:47,225 DEBUG [oncommand] [default task-607] [o.s.security.web.FilterChainProxy] /api/private/event-count-summary at position 7 of 13 in additional filter chain; firing Filter: 'AnonymousAuthenticationFilter' 2021-03-17 09:06:47,225 DEBUG [oncommand] [default task-607] [o.s.s.w.a.AnonymousAuthenticationFilter] SecurityContextHolder not populated with anonymous token, as it already contained: 'org.springframework.security.authentication.UsernamePasswordAuthenticationToken@7d493e6e: Principal: admin; Credentials: [PROTECTED]; Authenticated: true; Details: org.springframework.security.web.authentication.WebAuthenticationDetails@ffffe21a: RemoteIpAddress: 172.20.230.62; SessionId: null; Granted Authorities: com.netapp.dfm.core.authentication.RbacPrivilegeGrantedAuthorityAdapter@299e7eec, com.netapp.dfm.core.authentication.RbacPrivilegeGrantedAuthorityAdapter@157b1fb, com.netapp.dfm.core.authentication.RbacPrivilegeGrantedAuthorityAdapter@316f967d, com.netapp.dfm.core.authentication.RbacPrivilegeGrantedAuthorityAdapter@61697995' 2021-03-17 09:06:47,225 DEBUG [oncommand] [default task-607] [o.s.security.web.FilterChainProxy] /api/private/event-count-summary at position 8 of 13 in additional filter chain; firing Filter: 'CsrfFilter' 2021-03-17 09:06:47,225 DEBUG [oncommand] [default task-607] [o.s.security.web.FilterChainProxy] /api/private/event-count-summary at position 9 of 13 in additional filter chain; firing Filter: 'ExceptionTranslationFilter' 2021-03-17 09:06:47,225 DEBUG [oncommand] [default task-607] [o.s.security.web.FilterChainProxy] /api/private/event-count-summary at position 10 of 13 in additional filter chain; firing Filter: 'FilterSecurityInterceptor' 2021-03-17 09:06:47,225 DEBUG [oncommand] [default task-607] [o.s.s.w.u.m.AntPathRequestMatcher] Checking match of request : '/api/private/event-count-summary'; against '/api/management-server/admin/session' 2021-03-17 09:06:47,225 DEBUG [oncommand] [default task-607] [o.s.s.w.u.m.AntPathRequestMatcher] Checking match of request : '/api/private/event-count-summary'; against '/api/management-server/admin/mfaenabled' 2021-03-17 09:06:47,225 DEBUG [oncommand] [default task-607] [o.s.s.w.u.m.AntPathRequestMatcher] Checking match of request : '/api/private/event-count-summary'; against '/api/management-server/admin/environment' 2021-03-17 09:06:47,225 DEBUG [oncommand] [default task-607] [o.s.s.w.u.m.AntPathRequestMatcher] Checking match of request : '/api/private/event-count-summary'; against '/api/management-server/admin/refresh-hostname' 2021-03-17 09:06:47,225 DEBUG [oncommand] [default task-607] [o.s.s.w.u.m.AntPathRequestMatcher] Checking match of request : '/api/private/event-count-summary'; against '/api/management-server/admin/refresh-logging-config' 2021-03-17 09:06:47,225 DEBUG [oncommand] [default task-607] [o.s.s.w.u.m.AntPathRequestMatcher] Checking match of request : '/api/private/event-count-summary'; against '/api/management-server/admin/log-failed-tasks' 2021-03-17 09:06:47,225 DEBUG [oncommand] [default task-607] [o.s.s.w.u.m.AntPathRequestMatcher] Checking match of request : '/api/private/event-count-summary'; against '/api/management-server/admin/dump-threads' 2021-03-17 09:06:47,225 DEBUG [oncommand] [default task-607] [o.s.s.w.u.m.AntPathRequestMatcher] Checking match of request : '/api/private/event-count-summary'; against '/api/management-server/admin/dump-heap' 2021-03-17 09:06:47,225 DEBUG [oncommand] [default task-607] [o.s.s.w.u.m.AntPathRequestMatcher] Checking match of request : '/api/private/event-count-summary'; against '/api/management-server/admin/resetpassword/**' 2021-03-17 09:06:47,225 DEBUG [oncommand] [default task-607] [o.s.s.w.u.m.AntPathRequestMatcher] Checking match of request : '/api/private/event-count-summary'; against '/api/management-server/upload-file' 2021-03-17 09:06:47,225 DEBUG [oncommand] [default task-607] [o.s.s.w.u.m.AntPathRequestMatcher] Checking match of request : '/api/private/event-count-summary'; against '/api/**' 2021-03-17 09:06:47,225 DEBUG [oncommand] [default task-607] [o.s.s.w.a.i.FilterSecurityInterceptor] Secure object: FilterInvocation: URL: /api/private/event-count-summary; Attributes: [IS_AUTHENTICATED_FULLY] 2021-03-17 09:06:47,225 DEBUG [oncommand] [default task-607] [o.s.s.w.a.i.FilterSecurityInterceptor] Previously Authenticated: org.springframework.security.authentication.UsernamePasswordAuthenticationToken@7d493e6e: Principal: admin; Credentials: [PROTECTED]; Authenticated: true; Details: org.springframework.security.web.authentication.WebAuthenticationDetails@ffffe21a: RemoteIpAddress: 172.20.230.62; SessionId: null; Granted Authorities: com.netapp.dfm.core.authentication.RbacPrivilegeGrantedAuthorityAdapter@299e7eec, com.netapp.dfm.core.authentication.RbacPrivilegeGrantedAuthorityAdapter@157b1fb, com.netapp.dfm.core.authentication.RbacPrivilegeGrantedAuthorityAdapter@316f967d, com.netapp.dfm.core.authentication.RbacPrivilegeGrantedAuthorityAdapter@61697995 2021-03-17 09:06:47,226 DEBUG [oncommand] [default task-607] [o.s.s.access.vote.AffirmativeBased] Voter: org.springframework.security.access.vote.RoleVoter@32dbec4, returned: 0 2021-03-17 09:06:47,226 DEBUG [oncommand] [default task-607] [o.s.s.access.vote.AffirmativeBased] Voter: org.springframework.security.access.vote.AuthenticatedVoter@3c721928, returned: 1 2021-03-17 09:06:47,226 DEBUG [oncommand] [default task-607] [o.s.s.w.a.i.FilterSecurityInterceptor] Authorization successful 2021-03-17 09:06:47,226 DEBUG [oncommand] [default task-607] [o.s.s.w.a.i.FilterSecurityInterceptor] RunAsManager did not change Authentication object 2021-03-17 09:06:47,226 DEBUG [oncommand] [default task-607] [o.s.security.web.FilterChainProxy] /api/private/event-count-summary at position 11 of 13 in additional filter chain; firing Filter: 'PostSecurityAuditLoggerConfigFilter' 2021-03-17 09:06:47,226 DEBUG [admin] [default task-607] [o.s.security.web.FilterChainProxy] /api/private/event-count-summary at position 12 of 13 in additional filter chain; firing Filter: 'SqlInjectionFilter' 2021-03-17 09:06:47,226 DEBUG [admin] [default task-607] [o.s.security.web.FilterChainProxy] /api/private/event-count-summary at position 13 of 13 in additional filter chain; firing Filter: 'NetAppAPIFilter' 2021-03-17 09:06:47,226 DEBUG [admin] [default task-607] [o.s.security.web.FilterChainProxy] /api/private/event-count-summary reached end of additional filter chain; proceeding with original chain 2021-03-17 09:06:47,227 DEBUG [admin] [default task-607] [o.s.w.s.m.m.a.RequestMappingHandlerMapping] Mapped to com.netapp.dfm.provision.rest.controller.v2.EventCountSummaryController#getEventCountSummary(HttpServletRequest) 2021-03-17 09:06:47,228 DEBUG [admin] [default task-607] [o.s.t.jta.JtaTransactionManager] Creating new transaction with name [com.netapp.dfm.provision.service.v2.EventCountSummaryService.getEventCountSummary]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT,readOnly 2021-03-17 09:06:47,228 DEBUG [admin] [default task-607] [o.s.jdbc.core.JdbcTemplate] Executing SQL query [SELECT e.impactArea as `impactArea`, evt.severity as `severity`, count(*) as `eventCounter` FROM ocum.event AS e LEFT JOIN ocum.eventtypevalue AS evt ON evt.id=e.value_id WHERE (e.state='NEW' OR e.state='ACKNOWLEDGED') AND evt.impactLevel<>3 AND (UNIX_TIMESTAMP(e.eventTimestamp) * 1000 > 1615388807228) AND evt.severity > 1 AND isContinuous=true AND maintenance=false GROUP BY evt.severity, e.impactArea] 2021-03-17 09:06:47,228 DEBUG [admin] [default task-607] [o.s.jdbc.datasource.DataSourceUtils] Fetching JDBC Connection from DataSource 2021-03-17 09:06:47,230 DEBUG [admin] [default task-607] [o.s.jdbc.core.JdbcTemplate] Executing SQL query [SELECT e.source_resourceType AS `resourceType`, evt.mitigationAction AS `mitigationAction`, COUNT(*) AS `eventCounter` FROM ocum.event AS e LEFT JOIN ocum.eventtypevalue AS evt ON evt.id=e.value_id WHERE (e.state='NEW' OR e.state='ACKNOWLEDGED') AND evt.impactLevel=3 AND maintenance=false GROUP BY evt.mitigationAction, e.source_resourceType;] 2021-03-17 09:06:47,231 DEBUG [admin] [default task-607] [o.s.t.jta.JtaTransactionManager] Initiating transaction commit 2021-03-17 09:06:47,232 DEBUG [admin] [default task-607] [o.s.w.s.m.m.a.HttpEntityMethodProcessor] Using 'application/hal+json', given [application/json, text/plain, */*] and supported [application/hal+json] 2021-03-17 09:06:47,232 DEBUG [admin] [default task-607] [o.s.w.s.m.m.a.HttpEntityMethodProcessor] Writing [Resource { content: com.netapp.dfm.provision.rest.dto.v2.EventCountSummaryDto@70fab7c2, links: [3 AND (UNIX_TIMESTAMP(e.eventTimestamp) * 1000 > 1615388852276) AND evt.severity > 1 AND isContinuous=true AND maintenance=false GROUP BY evt.severity, e.impactArea] 2021-03-17 09:07:32,276 DEBUG [admin] [default task-607] [o.s.jdbc.datasource.DataSourceUtils] Fetching JDBC Connection from DataSource 2021-03-17 09:07:32,278 DEBUG [admin] [default task-607] [o.s.jdbc.core.JdbcTemplate] Executing SQL query [SELECT e.source_resourceType AS `resourceType`, evt.mitigationAction AS `mitigationAction`, COUNT(*) AS `eventCounter` FROM ocum.event AS e LEFT JOIN ocum.eventtypevalue AS evt ON evt.id=e.value_id WHERE (e.state='NEW' OR e.state='ACKNOWLEDGED') AND evt.impactLevel=3 AND maintenance=false GROUP BY evt.mitigationAction, e.source_resourceType;] 2021-03-17 09:07:32,278 DEBUG [admin] [default task-607] [o.s.t.jta.JtaTransactionManager] Initiating transaction commit 2021-03-17 09:07:32,279 DEBUG [admin] [default task-607] [o.s.w.s.m.m.a.HttpEntityMethodProcessor] Using 'application/hal+json', given [application/json, text/plain, */*] and supported [application/hal+json] 2021-03-17 09:07:32,280 DEBUG [admin] [default task-607] [o.s.w.s.m.m.a.HttpEntityMethodProcessor] Writing [Resource { content: com.netapp.dfm.provision.rest.dto.v2.EventCountSummaryDto@6369e527, links: [3 AND (UNIX_TIMESTAMP(e.eventTimestamp) * 1000 > 1615388897304) AND evt.severity > 1 AND isContinuous=true AND maintenance=false GROUP BY evt.severity, e.impactArea] 2021-03-17 09:08:17,304 DEBUG [admin] [default task-607] [o.s.jdbc.datasource.DataSourceUtils] Fetching JDBC Connection from DataSource 2021-03-17 09:08:17,307 DEBUG [admin] [default task-607] [o.s.jdbc.core.JdbcTemplate] Executing SQL query [SELECT e.source_resourceType AS `resourceType`, evt.mitigationAction AS `mitigationAction`, COUNT(*) AS `eventCounter` FROM ocum.event AS e LEFT JOIN ocum.eventtypevalue AS evt ON evt.id=e.value_id WHERE (e.state='NEW' OR e.state='ACKNOWLEDGED') AND evt.impactLevel=3 AND maintenance=false GROUP BY evt.mitigationAction, e.source_resourceType;] 2021-03-17 09:08:17,308 DEBUG [admin] [default task-607] [o.s.t.jta.JtaTransactionManager] Initiating transaction commit 2021-03-17 09:08:17,309 DEBUG [admin] [default task-607] [o.s.w.s.m.m.a.HttpEntityMethodProcessor] Using 'application/hal+json', given [application/json, text/plain, */*] and supported [application/hal+json] 2021-03-17 09:08:17,310 DEBUG [admin] [default task-607] [o.s.w.s.m.m.a.HttpEntityMethodProcessor] Writing [Resource { content: com.netapp.dfm.provision.rest.dto.v2.EventCountSummaryDto@2d1c3f9e, links: [3 AND (UNIX_TIMESTAMP(e.eventTimestamp) * 1000 > 1615388942341) AND evt.severity > 1 AND isContinuous=true AND maintenance=false GROUP BY evt.severity, e.impactArea] 2021-03-17 09:09:02,342 DEBUG [admin] [default task-607] [o.s.jdbc.datasource.DataSourceUtils] Fetching JDBC Connection from DataSource 2021-03-17 09:09:02,343 DEBUG [admin] [default task-607] [o.s.jdbc.core.JdbcTemplate] Executing SQL query [SELECT e.source_resourceType AS `resourceType`, evt.mitigationAction AS `mitigationAction`, COUNT(*) AS `eventCounter` FROM ocum.event AS e LEFT JOIN ocum.eventtypevalue AS evt ON evt.id=e.value_id WHERE (e.state='NEW' OR e.state='ACKNOWLEDGED') AND evt.impactLevel=3 AND maintenance=false GROUP BY evt.mitigationAction, e.source_resourceType;] 2021-03-17 09:09:02,344 DEBUG [admin] [default task-607] [o.s.t.jta.JtaTransactionManager] Initiating transaction commit 2021-03-17 09:09:02,345 DEBUG [admin] [default task-607] [o.s.w.s.m.m.a.HttpEntityMethodProcessor] Using 'application/hal+json', given [application/json, text/plain, */*] and supported [application/hal+json] 2021-03-17 09:09:02,345 DEBUG [admin] [default task-607] [o.s.w.s.m.m.a.HttpEntityMethodProcessor] Writing [Resource { content: com.netapp.dfm.provision.rest.dto.v2.EventCountSummaryDto@64538170, links: [3 AND (UNIX_TIMESTAMP(e.eventTimestamp) * 1000 > 1615388987380) AND evt.severity > 1 AND isContinuous=true AND maintenance=false GROUP BY evt.severity, e.impactArea] 2021-03-17 09:09:47,380 DEBUG [admin] [default task-614] [o.s.jdbc.datasource.DataSourceUtils] Fetching JDBC Connection from DataSource 2021-03-17 09:09:47,382 DEBUG [admin] [default task-614] [o.s.jdbc.core.JdbcTemplate] Executing SQL query [SELECT e.source_resourceType AS `resourceType`, evt.mitigationAction AS `mitigationAction`, COUNT(*) AS `eventCounter` FROM ocum.event AS e LEFT JOIN ocum.eventtypevalue AS evt ON evt.id=e.value_id WHERE (e.state='NEW' OR e.state='ACKNOWLEDGED') AND evt.impactLevel=3 AND maintenance=false GROUP BY evt.mitigationAction, e.source_resourceType;] 2021-03-17 09:09:47,382 DEBUG [admin] [default task-614] [o.s.t.jta.JtaTransactionManager] Initiating transaction commit 2021-03-17 09:09:47,383 DEBUG [admin] [default task-614] [o.s.w.s.m.m.a.HttpEntityMethodProcessor] Using 'application/hal+json', given [application/json, text/plain, */*] and supported [application/hal+json] 2021-03-17 09:09:47,384 DEBUG [admin] [default task-614] [o.s.w.s.m.m.a.HttpEntityMethodProcessor] Writing [Resource { content: com.netapp.dfm.provision.rest.dto.v2.EventCountSummaryDto@32d1dec7, links: [3 AND (UNIX_TIMESTAMP(e.eventTimestamp) * 1000 > 1615389032406) AND evt.severity > 1 AND isContinuous=true AND maintenance=false GROUP BY evt.severity, e.impactArea] 2021-03-17 09:10:32,406 DEBUG [admin] [default task-607] [o.s.jdbc.datasource.DataSourceUtils] Fetching JDBC Connection from DataSource 2021-03-17 09:10:32,408 DEBUG [admin] [default task-607] [o.s.jdbc.core.JdbcTemplate] Executing SQL query [SELECT e.source_resourceType AS `resourceType`, evt.mitigationAction AS `mitigationAction`, COUNT(*) AS `eventCounter` FROM ocum.event AS e LEFT JOIN ocum.eventtypevalue AS evt ON evt.id=e.value_id WHERE (e.state='NEW' OR e.state='ACKNOWLEDGED') AND evt.impactLevel=3 AND maintenance=false GROUP BY evt.mitigationAction, e.source_resourceType;] 2021-03-17 09:10:32,408 DEBUG [admin] [default task-607] [o.s.t.jta.JtaTransactionManager] Initiating transaction commit 2021-03-17 09:10:32,409 DEBUG [admin] [default task-607] [o.s.w.s.m.m.a.HttpEntityMethodProcessor] Using 'application/hal+json', given [application/json, text/plain, */*] and supported [application/hal+json] 2021-03-17 09:10:32,409 DEBUG [admin] [default task-607] [o.s.w.s.m.m.a.HttpEntityMethodProcessor] Writing [Resource { content: com.netapp.dfm.provision.rest.dto.v2.EventCountSummaryDto@71f119d7, links: [= ? and time <= ? order by time asc] 2021-03-17 09:11:16,959 DEBUG [oncommand] [pool-40-thread-1] [o.s.jdbc.datasource.DataSourceUtils] Fetching JDBC Connection from DataSource 2021-03-17 09:11:16,960 DEBUG [oncommand] [pool-40-thread-1] [o.s.jdbc.core.JdbcTemplate] Executing prepared SQL query 2021-03-17 09:11:16,961 DEBUG [oncommand] [pool-40-thread-1] [o.s.jdbc.core.JdbcTemplate] Executing prepared SQL statement [SELECT * from acquisition.ds_attrs where ds_id = ? AND name LIKE "netappstorageperformance.clock.polling.offset" ] 2021-03-17 09:11:16,961 DEBUG [oncommand] [pool-40-thread-1] [o.s.jdbc.datasource.DataSourceUtils] Fetching JDBC Connection from DataSource 2021-03-17 09:11:16,962 DEBUG [oncommand] [pool-40-thread-1] [o.s.jdbc.core.JdbcTemplate] Executing prepared SQL query 2021-03-17 09:11:16,962 DEBUG [oncommand] [pool-40-thread-1] [o.s.jdbc.core.JdbcTemplate] Executing prepared SQL statement [SELECT * FROM netapp_model_view.node_full WHERE objid=?] 2021-03-17 09:11:16,962 DEBUG [oncommand] [pool-40-thread-1] [o.s.jdbc.datasource.DataSourceUtils] Fetching JDBC Connection from DataSource 2021-03-17 09:11:16,963 DEBUG [oncommand] [pool-40-thread-1] [o.s.jdbc.core.JdbcTemplate] Executing prepared SQL query 2021-03-17 09:11:16,963 DEBUG [oncommand] [pool-40-thread-1] [o.s.jdbc.core.JdbcTemplate] Executing prepared SQL statement [SELECT * from acquisition.ds_attrs where ds_id = ? AND name LIKE "netappstorageperformance.clock.polling.offset" ] 2021-03-17 09:11:16,963 DEBUG [oncommand] [pool-40-thread-1] [o.s.jdbc.datasource.DataSourceUtils] Fetching JDBC Connection from DataSource 2021-03-17 09:11:16,965 DEBUG [oncommand] [pool-40-thread-1] [o.s.jdbc.core.JdbcTemplate] Executing SQL query [SELECT COALESCE(SUM (totalOps) , 0) FROM netapp_performance.sample_node WHERE time=1615990162041 AND objid in (74,6) ] 2021-03-17 09:11:16,965 DEBUG [oncommand] [pool-40-thread-1] [o.s.jdbc.datasource.DataSourceUtils] Fetching JDBC Connection from DataSource 2021-03-17 09:11:16,966 DEBUG [oncommand] [pool-40-thread-1] [o.s.jdbc.core.JdbcTemplate] Executing prepared SQL query 2021-03-17 09:11:16,966 DEBUG [oncommand] [pool-40-thread-1] [o.s.jdbc.core.JdbcTemplate] Executing prepared SQL statement [SELECT * FROM netapp_model_view.resource_aggregate_full WHERE clusterId=?] 2021-03-17 09:11:16,966 DEBUG [oncommand] [pool-40-thread-1] [o.s.jdbc.datasource.DataSourceUtils] Fetching JDBC Connection from DataSource 2021-03-17 09:11:16,967 DEBUG [oncommand] [pool-40-thread-1] [o.s.jdbc.core.JdbcTemplate] Executing prepared SQL query 2021-03-17 09:11:16,967 DEBUG [oncommand] [pool-40-thread-1] [o.s.jdbc.core.JdbcTemplate] Executing prepared SQL statement [SELECT * FROM opm.resource_capability_stats WHERE resourceId IN (?, ?, ?, ?)] 2021-03-17 09:11:16,967 DEBUG [oncommand] [pool-40-thread-1] [o.s.jdbc.datasource.DataSourceUtils] Fetching JDBC Connection from DataSource 2021-03-17 09:11:16,971 DEBUG [oncommand] [pool-40-thread-1] [o.s.t.jta.JtaTransactionManager] Creating new transaction with name [com.netapp.ipc.services.performance.service.NodePerformanceQueryService.getSamples]: PROPAGATION_REQUIRES_NEW,ISOLATION_DEFAULT 2021-03-17 09:11:16,976 DEBUG [oncommand] [pool-40-thread-1] [o.s.t.jta.JtaTransactionManager] Initiating transaction commit 2021-03-17 09:11:16,976 DEBUG [oncommand] [pool-40-thread-1] [o.s.jdbc.core.JdbcTemplate] Executing prepared SQL query 2021-03-17 09:11:16,976 DEBUG [oncommand] [pool-40-thread-1] [o.s.jdbc.core.JdbcTemplate] Executing prepared SQL statement [SELECT * FROM netapp_model_view.node_full WHERE objid=?] 2021-03-17 09:11:16,976 DEBUG [oncommand] [pool-40-thread-1] [o.s.jdbc.datasource.DataSourceUtils] Fetching JDBC Connection from DataSource 2021-03-17 09:11:16,978 DEBUG [oncommand] [pool-40-thread-1] [o.s.jdbc.core.JdbcTemplate] Executing prepared SQL query 2021-03-17 09:11:16,978 DEBUG [oncommand] [pool-40-thread-1] [o.s.jdbc.core.JdbcTemplate] Executing prepared SQL statement [SELECT * from opm.acquisition_info where clusterId = ? and time >= ? and time <= ? order by time asc] 2021-03-17 09:11:16,978 DEBUG [oncommand] [pool-40-thread-1] [o.s.jdbc.datasource.DataSourceUtils] Fetching JDBC Connection from DataSource 2021-03-17 09:11:16,980 DEBUG [oncommand] [pool-40-thread-1] [o.s.jdbc.core.JdbcTemplate] Executing prepared SQL query 2021-03-17 09:11:16,980 DEBUG [oncommand] [pool-40-thread-1] [o.s.jdbc.core.JdbcTemplate] Executing prepared SQL statement [SELECT * from acquisition.ds_attrs where ds_id = ? AND name LIKE "netappstorageperformance.clock.polling.offset" ] 2021-03-17 09:11:16,980 DEBUG [oncommand] [pool-40-thread-1] [o.s.jdbc.datasource.DataSourceUtils] Fetching JDBC Connection from DataSource 2021-03-17 09:11:16,981 DEBUG [oncommand] [pool-40-thread-1] [o.s.jdbc.core.JdbcTemplate] Executing prepared SQL query 2021-03-17 09:11:16,981 DEBUG [oncommand] [pool-40-thread-1] [o.s.jdbc.core.JdbcTemplate] Executing prepared SQL statement [SELECT * FROM netapp_model_view.node_full WHERE objid=?] 2021-03-17 09:11:16,981 DEBUG [oncommand] [pool-40-thread-1] [o.s.jdbc.datasource.DataSourceUtils] Fetching JDBC Connection from DataSource 2021-03-17 09:11:16,982 DEBUG [oncommand] [pool-40-thread-1] [o.s.jdbc.core.JdbcTemplate] Executing prepared SQL query 2021-03-17 09:11:16,982 DEBUG [oncommand] [pool-40-thread-1] [o.s.jdbc.core.JdbcTemplate] Executing prepared SQL statement [SELECT * from acquisition.ds_attrs where ds_id = ? AND name LIKE "netappstorageperformance.clock.polling.offset" ] 2021-03-17 09:11:16,982 DEBUG [oncommand] [pool-40-thread-1] [o.s.jdbc.datasource.DataSourceUtils] Fetching JDBC Connection from DataSource 2021-03-17 09:11:17,150 INFO [oncommand] [pool-40-thread-1] [c.n.i.a.c.HeadroomEngine] Calculated Observation final 94.0 42258.24376326951 2021-03-17 09:11:17,269 INFO [oncommand] [pool-40-thread-1] [c.n.i.a.c.HeadroomEngine] Calculated Observation final 79.0 11804.016804763563 2021-03-17 09:11:17,371 INFO [oncommand] [pool-40-thread-1] [c.n.i.a.c.HeadroomEngine] Calculated Observation final 81.0 5077.360413212799 2021-03-17 09:11:17,441 DEBUG [oncommand] [default task-607] [o.s.s.w.u.m.AntPathRequestMatcher] Checking match of request : '/api/private/event-count-summary'; against '/apis/**' 2021-03-17 09:11:17,441 DEBUG [oncommand] [default task-607] [o.s.s.w.u.m.AntPathRequestMatcher] Checking match of request : '/api/private/event-count-summary'; against '/api/**' 2021-03-17 09:11:17,441 DEBUG [oncommand] [default task-607] [o.s.security.web.FilterChainProxy] /api/private/event-count-summary at position 1 of 1 in additional filter chain; firing Filter: 'NoOpFilter' 2021-03-17 09:11:17,441 DEBUG [oncommand] [default task-607] [o.s.security.web.FilterChainProxy] /api/private/event-count-summary reached end of additional filter chain; proceeding with original chain 2021-03-17 09:11:17,441 DEBUG [oncommand] [default task-607] [o.s.s.w.u.m.AntPathRequestMatcher] Checking match of request : '/api/private/event-count-summary'; against '/api/**' 2021-03-17 09:11:17,441 DEBUG [oncommand] [default task-607] [o.s.security.web.FilterChainProxy] /api/private/event-count-summary at position 1 of 13 in additional filter chain; firing Filter: 'PreSecurityAuditLoggerConfigFilter' 2021-03-17 09:11:17,441 DEBUG [oncommand] [default task-607] [o.s.security.web.FilterChainProxy] /api/private/event-count-summary at position 2 of 13 in additional filter chain; firing Filter: 'RestCorsFilter' 2021-03-17 09:11:17,442 DEBUG [oncommand] [default task-607] [o.s.security.web.FilterChainProxy] /api/private/event-count-summary at position 3 of 13 in additional filter chain; firing Filter: 'ChannelProcessingFilter' 2021-03-17 09:11:17,442 DEBUG [oncommand] [default task-607] [o.s.s.w.a.c.ChannelProcessingFilter] Request: FilterInvocation: URL: /api/private/event-count-summary; ConfigAttributes: [REQUIRES_SECURE_CHANNEL] 2021-03-17 09:11:17,442 DEBUG [oncommand] [default task-607] [o.s.security.web.FilterChainProxy] /api/private/event-count-summary at position 4 of 13 in additional filter chain; firing Filter: 'SecurityContextPersistenceFilter' 2021-03-17 09:11:17,442 DEBUG [oncommand] [default task-607] [o.s.s.w.c.HttpSessionSecurityContextRepository] Obtained a valid SecurityContext from SPRING_SECURITY_CONTEXT: 'org.springframework.security.core.context.SecurityContextImpl@7d493e6e: Authentication: org.springframework.security.authentication.UsernamePasswordAuthenticationToken@7d493e6e: Principal: admin; Credentials: [PROTECTED]; Authenticated: true; Details: org.springframework.security.web.authentication.WebAuthenticationDetails@ffffe21a: RemoteIpAddress: 172.20.230.62; SessionId: null; Granted Authorities: com.netapp.dfm.core.authentication.RbacPrivilegeGrantedAuthorityAdapter@299e7eec, com.netapp.dfm.core.authentication.RbacPrivilegeGrantedAuthorityAdapter@157b1fb, com.netapp.dfm.core.authentication.RbacPrivilegeGrantedAuthorityAdapter@316f967d, com.netapp.dfm.core.authentication.RbacPrivilegeGrantedAuthorityAdapter@61697995' 2021-03-17 09:11:17,442 DEBUG [oncommand] [default task-607] [o.s.security.web.FilterChainProxy] /api/private/event-count-summary at position 5 of 13 in additional filter chain; firing Filter: 'TemporaryTokenAuthenticationFilter' 2021-03-17 09:11:17,442 DEBUG [oncommand] [default task-607] [o.s.security.web.FilterChainProxy] /api/private/event-count-summary at position 6 of 13 in additional filter chain; firing Filter: 'BasicAuthenticationFilter' 2021-03-17 09:11:17,442 DEBUG [oncommand] [default task-607] [o.s.security.web.FilterChainProxy] /api/private/event-count-summary at position 7 of 13 in additional filter chain; firing Filter: 'AnonymousAuthenticationFilter' 2021-03-17 09:11:17,443 DEBUG [oncommand] [default task-607] [o.s.s.w.a.AnonymousAuthenticationFilter] SecurityContextHolder not populated with anonymous token, as it already contained: 'org.springframework.security.authentication.UsernamePasswordAuthenticationToken@7d493e6e: Principal: admin; Credentials: [PROTECTED]; Authenticated: true; Details: org.springframework.security.web.authentication.WebAuthenticationDetails@ffffe21a: RemoteIpAddress: 172.20.230.62; SessionId: null; Granted Authorities: com.netapp.dfm.core.authentication.RbacPrivilegeGrantedAuthorityAdapter@299e7eec, com.netapp.dfm.core.authentication.RbacPrivilegeGrantedAuthorityAdapter@157b1fb, com.netapp.dfm.core.authentication.RbacPrivilegeGrantedAuthorityAdapter@316f967d, com.netapp.dfm.core.authentication.RbacPrivilegeGrantedAuthorityAdapter@61697995' 2021-03-17 09:11:17,443 DEBUG [oncommand] [default task-607] [o.s.security.web.FilterChainProxy] /api/private/event-count-summary at position 8 of 13 in additional filter chain; firing Filter: 'CsrfFilter' 2021-03-17 09:11:17,443 DEBUG [oncommand] [default task-607] [o.s.security.web.FilterChainProxy] /api/private/event-count-summary at position 9 of 13 in additional filter chain; firing Filter: 'ExceptionTranslationFilter' 2021-03-17 09:11:17,443 DEBUG [oncommand] [default task-607] [o.s.security.web.FilterChainProxy] /api/private/event-count-summary at position 10 of 13 in additional filter chain; firing Filter: 'FilterSecurityInterceptor' 2021-03-17 09:11:17,443 DEBUG [oncommand] [default task-607] [o.s.s.w.u.m.AntPathRequestMatcher] Checking match of request : '/api/private/event-count-summary'; against '/api/management-server/admin/session' 2021-03-17 09:11:17,443 DEBUG [oncommand] [default task-607] [o.s.s.w.u.m.AntPathRequestMatcher] Checking match of request : '/api/private/event-count-summary'; against '/api/management-server/admin/mfaenabled' 2021-03-17 09:11:17,443 DEBUG [oncommand] [default task-607] [o.s.s.w.u.m.AntPathRequestMatcher] Checking match of request : '/api/private/event-count-summary'; against '/api/management-server/admin/environment' 2021-03-17 09:11:17,443 DEBUG [oncommand] [default task-607] [o.s.s.w.u.m.AntPathRequestMatcher] Checking match of request : '/api/private/event-count-summary'; against '/api/management-server/admin/refresh-hostname' 2021-03-17 09:11:17,443 DEBUG [oncommand] [default task-607] [o.s.s.w.u.m.AntPathRequestMatcher] Checking match of request : '/api/private/event-count-summary'; against '/api/management-server/admin/refresh-logging-config' 2021-03-17 09:11:17,443 DEBUG [oncommand] [default task-607] [o.s.s.w.u.m.AntPathRequestMatcher] Checking match of request : '/api/private/event-count-summary'; against '/api/management-server/admin/log-failed-tasks' 2021-03-17 09:11:17,443 DEBUG [oncommand] [default task-607] [o.s.s.w.u.m.AntPathRequestMatcher] Checking match of request : '/api/private/event-count-summary'; against '/api/management-server/admin/dump-threads' 2021-03-17 09:11:17,443 DEBUG [oncommand] [default task-607] [o.s.s.w.u.m.AntPathRequestMatcher] Checking match of request : '/api/private/event-count-summary'; against '/api/management-server/admin/dump-heap' 2021-03-17 09:11:17,443 DEBUG [oncommand] [default task-607] [o.s.s.w.u.m.AntPathRequestMatcher] Checking match of request : '/api/private/event-count-summary'; against '/api/management-server/admin/resetpassword/**' 2021-03-17 09:11:17,443 DEBUG [oncommand] [default task-607] [o.s.s.w.u.m.AntPathRequestMatcher] Checking match of request : '/api/private/event-count-summary'; against '/api/management-server/upload-file' 2021-03-17 09:11:17,443 DEBUG [oncommand] [default task-607] [o.s.s.w.u.m.AntPathRequestMatcher] Checking match of request : '/api/private/event-count-summary'; against '/api/**' 2021-03-17 09:11:17,443 DEBUG [oncommand] [default task-607] [o.s.s.w.a.i.FilterSecurityInterceptor] Secure object: FilterInvocation: URL: /api/private/event-count-summary; Attributes: [IS_AUTHENTICATED_FULLY] 2021-03-17 09:11:17,443 DEBUG [oncommand] [default task-607] [o.s.s.w.a.i.FilterSecurityInterceptor] Previously Authenticated: org.springframework.security.authentication.UsernamePasswordAuthenticationToken@7d493e6e: Principal: admin; Credentials: [PROTECTED]; Authenticated: true; Details: org.springframework.security.web.authentication.WebAuthenticationDetails@ffffe21a: RemoteIpAddress: 172.20.230.62; SessionId: null; Granted Authorities: com.netapp.dfm.core.authentication.RbacPrivilegeGrantedAuthorityAdapter@299e7eec, com.netapp.dfm.core.authentication.RbacPrivilegeGrantedAuthorityAdapter@157b1fb, com.netapp.dfm.core.authentication.RbacPrivilegeGrantedAuthorityAdapter@316f967d, com.netapp.dfm.core.authentication.RbacPrivilegeGrantedAuthorityAdapter@61697995 2021-03-17 09:11:17,444 DEBUG [oncommand] [default task-607] [o.s.s.access.vote.AffirmativeBased] Voter: org.springframework.security.access.vote.RoleVoter@32dbec4, returned: 0 2021-03-17 09:11:17,444 DEBUG [oncommand] [default task-607] [o.s.s.access.vote.AffirmativeBased] Voter: org.springframework.security.access.vote.AuthenticatedVoter@3c721928, returned: 1 2021-03-17 09:11:17,444 DEBUG [oncommand] [default task-607] [o.s.s.w.a.i.FilterSecurityInterceptor] Authorization successful 2021-03-17 09:11:17,444 DEBUG [oncommand] [default task-607] [o.s.s.w.a.i.FilterSecurityInterceptor] RunAsManager did not change Authentication object 2021-03-17 09:11:17,444 DEBUG [oncommand] [default task-607] [o.s.security.web.FilterChainProxy] /api/private/event-count-summary at position 11 of 13 in additional filter chain; firing Filter: 'PostSecurityAuditLoggerConfigFilter' 2021-03-17 09:11:17,444 DEBUG [admin] [default task-607] [o.s.security.web.FilterChainProxy] /api/private/event-count-summary at position 12 of 13 in additional filter chain; firing Filter: 'SqlInjectionFilter' 2021-03-17 09:11:17,444 DEBUG [admin] [default task-607] [o.s.security.web.FilterChainProxy] /api/private/event-count-summary at position 13 of 13 in additional filter chain; firing Filter: 'NetAppAPIFilter' 2021-03-17 09:11:17,444 DEBUG [admin] [default task-607] [o.s.security.web.FilterChainProxy] /api/private/event-count-summary reached end of additional filter chain; proceeding with original chain 2021-03-17 09:11:17,445 DEBUG [admin] [default task-607] [o.s.w.s.m.m.a.RequestMappingHandlerMapping] Mapped to com.netapp.dfm.provision.rest.controller.v2.EventCountSummaryController#getEventCountSummary(HttpServletRequest) 2021-03-17 09:11:17,445 DEBUG [admin] [default task-607] [o.s.t.jta.JtaTransactionManager] Creating new transaction with name [com.netapp.dfm.provision.service.v2.EventCountSummaryService.getEventCountSummary]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT,readOnly 2021-03-17 09:11:17,446 DEBUG [admin] [default task-607] [o.s.jdbc.core.JdbcTemplate] Executing SQL query [SELECT e.impactArea as `impactArea`, evt.severity as `severity`, count(*) as `eventCounter` FROM ocum.event AS e LEFT JOIN ocum.eventtypevalue AS evt ON evt.id=e.value_id WHERE (e.state='NEW' OR e.state='ACKNOWLEDGED') AND evt.impactLevel<>3 AND (UNIX_TIMESTAMP(e.eventTimestamp) * 1000 > 1615389077446) AND evt.severity > 1 AND isContinuous=true AND maintenance=false GROUP BY evt.severity, e.impactArea] 2021-03-17 09:11:17,446 DEBUG [admin] [default task-607] [o.s.jdbc.datasource.DataSourceUtils] Fetching JDBC Connection from DataSource 2021-03-17 09:11:17,448 DEBUG [admin] [default task-607] [o.s.jdbc.core.JdbcTemplate] Executing SQL query [SELECT e.source_resourceType AS `resourceType`, evt.mitigationAction AS `mitigationAction`, COUNT(*) AS `eventCounter` FROM ocum.event AS e LEFT JOIN ocum.eventtypevalue AS evt ON evt.id=e.value_id WHERE (e.state='NEW' OR e.state='ACKNOWLEDGED') AND evt.impactLevel=3 AND maintenance=false GROUP BY evt.mitigationAction, e.source_resourceType;] 2021-03-17 09:11:17,449 DEBUG [admin] [default task-607] [o.s.t.jta.JtaTransactionManager] Initiating transaction commit 2021-03-17 09:11:17,452 DEBUG [admin] [default task-607] [o.s.w.s.m.m.a.HttpEntityMethodProcessor] Using 'application/hal+json', given [application/json, text/plain, */*] and supported [application/hal+json] 2021-03-17 09:11:17,452 DEBUG [admin] [default task-607] [o.s.w.s.m.m.a.HttpEntityMethodProcessor] Writing [Resource { content: com.netapp.dfm.provision.rest.dto.v2.EventCountSummaryDto@5a365fb4, links: [