objectKey:Utility:Wsretryjob:Provjobs] 2023-04-22 04:13:36,903 [http-nio-8080-exec-7] INFO domain.JobcontrolController - Auditing for list of JobControl 2023-04-22 04:13:36,922 [http-nio-8080-exec-7] INFO domain.JobcontrolController - Auditing process completed for JobControl 2023-04-22 04:13:36,940 [quartzScheduler_Worker-9] DEBUG jobs.WSRetryJob - WSRETRYJOB start @ Fri Apr 21 22:43:36 UTC 2023 2023-04-22 04:13:36,941 [quartzScheduler_Worker-9] DEBUG services.SaviyntCommonUtilityService - Enter checkAndCleanupExecution 2023-04-22 04:13:36,942 [quartzScheduler_Worker-9] DEBUG services.SaviyntCommonUtilityService - No Multiple provisioning job running on cluster.. start cleanup 2023-04-22 04:13:36,942 [quartzScheduler_Worker-9] DEBUG services.SaviyntCommonUtilityService - Enter deleteEntriesFromProcessingTasks 2023-04-22 04:13:36,942 [quartzScheduler_Worker-9] DEBUG services.SaviyntCommonUtilityService - JobID = null 2023-04-22 04:13:36,943 [quartzScheduler_Worker-9] DEBUG services.SaviyntCommonUtilityService - Exit deleteEntriesFromProcessingTasks 2023-04-22 04:13:36,943 [quartzScheduler_Worker-9] DEBUG services.SaviyntCommonUtilityService - Exit checkAndCleanupExecution 2023-04-22 04:13:36,943 [quartzScheduler_Worker-9] DEBUG jobs.WSRetryJob - multithreadinginwsretry = ###[:]#### 2023-04-22 04:13:36,943 [quartzScheduler_Worker-9] DEBUG jobs.WSRetryJob - upgrademultithradinginwsretry = ###true#### 2023-04-22 04:13:36,943 [quartzScheduler_Worker-9] DEBUG jobs.WSRetryJob - getAllSecuritySystemWithSuccessfulConnection 2023-04-22 04:13:36,946 [quartzScheduler_Worker-9] DEBUG jobs.WSRetryJob - precheck tasks = ##[:]## 2023-04-22 04:13:36,958 [quartzScheduler_Worker-9] DEBUG services.SaviyntCommonUtilityService - Enter fetchProcessingTasks 2023-04-22 04:13:36,960 [quartzScheduler_Worker-9] DEBUG services.SaviyntCommonUtilityService - processingArsTaksSet = [] 2023-04-22 04:13:36,960 [quartzScheduler_Worker-9] DEBUG services.SaviyntCommonUtilityService - Exit fetchProcessingTasks 2023-04-22 04:13:36,962 [quartzScheduler_Worker-9] DEBUG jobs.WSRetryJob - In upgradedwsretry... 2023-04-22 04:13:36,962 [quartzScheduler_Worker-9] DEBUG jobs.WSRetryJob - Enter processupgradedmultithreadedtasks 2023-04-22 04:13:36,962 [quartzScheduler_Worker-9] DEBUG jobs.WSRetryJob - parameters = [securitySystemIDList:[34], systemWithSuccessfulConnection:[1, 33, 34, 6, 7, 8, 9, 10, 11, 12, 13, 14, 16, 17, 21, 23, 24, 25, 26, 27], context:JobExecutionContext: trigger: 'MANUAL_TRIGGER.MT_j7jefcoa0eov job: utility.WSRetryJob fireTime: 'Fri Apr 21 22:43:36 UTC 2023 scheduledFireTime: Fri Apr 21 22:43:36 UTC 2023 previousFireTime: 'null nextFireTime: null isRecovering: false refireCount: 0, ecmImportJob:com.saviynt.ecm.identitywarehouse.domain.EcmImportJob : 22792, taskTypesList:[3], securitySystemList:[34], processingTaskSet:[], successfulConnection:[19, 5, 6, 22, 7, 23, 8, 9, 10, 12, 15], originalJobMap:[securitysystems:34, tasktypes:3, moreoptions:true, updateUser:admin, advquery:, threadcount:, batchsize:undefined]] 2023-04-22 04:13:36,962 [quartzScheduler_Worker-9] DEBUG jobs.WSRetryJob - No ArsRequestKey defined. We need to fetch the tasks using a query and provision using threads. 2023-04-22 04:13:36,962 [quartzScheduler_Worker-9] DEBUG jobs.WSRetryJob - threadcount = 1 2023-04-22 04:13:36,962 [quartzScheduler_Worker-9] DEBUG jobs.WSRetryJob - filterquery: and at.securitysystem in (34) and at.tasktype in (3) and (at.STARTDATE IS NULL OR at.STARTDATE <= UTC_TIMESTAMP()) 2023-04-22 04:13:37,006 [quartzScheduler_Worker-9] DEBUG jobs.WSRetryJob - Total tasks size is less than 500. Setting thread count to 1... 2023-04-22 04:13:37,009 [quartzScheduler_Worker-9] DEBUG services.SaviyntCommonUtilityService - Enter addToProcessingTasks 2023-04-22 04:13:37,009 [quartzScheduler_Worker-9] DEBUG services.SaviyntCommonUtilityService - taskkeyset to add = [[944], [945]] , jobid = 22792 2023-04-22 04:13:37,059 [quartzScheduler_Worker-9] DEBUG services.SaviyntCommonUtilityService - Exit addToProcessingTasks 2023-04-22 04:13:37,059 [quartzScheduler_Worker-9] DEBUG jobs.WSRetryJob - threadUserkeyTaskSetMap: [0:[4=[944], 2521=[945]]] 2023-04-22 04:13:37,060 [quartzScheduler_Worker-9] DEBUG services.ImportUtilityService - Writing job history to import logs for jobID: 22792 2023-04-22 04:13:37,060 [quartzScheduler_Worker-9] DEBUG services.ImportUtilityService - Number of log entries to be written : 2 2023-04-22 04:13:37,072 [quartzScheduler_Worker-9] DEBUG jobs.WSRetryJob - invoking MultipleProvisioningJob from WSRetryJob ID - 22792 group 0 2023-04-22 04:13:37,074 [quartzScheduler_Worker-9] DEBUG jobs.WSRetryJob - ValueMap is [parentJobId:22792, invokingjobcomments:invoked from WSRetryJob ID - 22792 group 0, userkeytasksetlistJSON:[{"4":[944]},{"2521":[945]}], threadNumber:0, originalJobDataMap:{"securitysystems":"34","tasktypes":"3","parentJobId":22792,"moreoptions":"true","updateUser":"admin","advquery":"","threadcount":"","batchsize":"undefined"}] 2023-04-22 04:13:37,224 [quartzScheduler_Worker-2] DEBUG jobs.MultipleProvisioningJob - MultipleProvisioningJob Job Execute Start 2023-04-22 04:13:37,225 [quartzScheduler_Worker-2] DEBUG jobs.MultipleProvisioningJob - job comments - invoked from WSRetryJob ID - 22792 group 0 2023-04-22 04:13:39,245 [quartzScheduler_Worker-2] DEBUG jobs.MultipleProvisioningJob - userkeyTaskSetList after json parse: [[4:[944]], [2521:[945]]] 2023-04-22 04:13:39,245 [quartzScheduler_Worker-2] INFO services.ArsTaskHelperService - Enter fetchSecuritySystemsMap 2023-04-22 04:13:39,245 [quartzScheduler_Worker-2] DEBUG services.ArsTaskHelperService - securitySystemIdList = null 2023-04-22 04:13:39,248 [quartzScheduler_Worker-2] DEBUG services.ArsTaskHelperService - securitySystemMap = [1:1, 2:2, 3:3, 4:4, 5:5, 6:6, 7:7, 8:8, 9:9, 10:10, 11:11, 12:12, 13:13, 14:14, 15:15, 16:16, 17:17, 18:18, 21:21, 22:22, 23:23, 24:24, 25:25, 26:26, 27:27, 28:28, 29:29, 30:30, 31:31, 32:32, 33:33, 34:34] 2023-04-22 04:13:39,248 [quartzScheduler_Worker-2] INFO services.ArsTaskHelperService - Exit fetchSecuritySystemsMap 2023-04-22 04:13:39,249 [quartzScheduler_Worker-2] DEBUG services.ArsTaskService - Qry to pull info on the Request Keys which are pending and are potential for Update account task to be created 2023-04-22 04:13:39,249 [quartzScheduler_Worker-2] DEBUG services.ArsTaskService - SELECT REQUESTKEY,REQUESTACCESSKEY,TASKKEY,ACCOUNTKEY FROM ARSTASKS WHERE status = 1 and UPDATEACCOUNTTASKCREATED = false and ACCOUNTKEY IS NOT NULL AND (ENDDATE IS NULL OR ENDDATE > '2023-04-21 22:43:39') AND (TASKTYPE = 1 OR TASKTYPE = 2) AND TASKKEY IN (944,945) GROUP BY REQUESTKEY, ACCOUNTKEY 2023-04-22 04:13:39,251 [quartzScheduler_Worker-2] DEBUG services.ArsTaskService - Enter populateEntByRuleAdd 2023-04-22 04:13:39,251 [quartzScheduler_Worker-2] DEBUG services.ArsTaskService - Finding rows with query SELECT ARSTASKS.REQUESTKEY,ARSTASKS.TASKKEY,ARSTASKS.REQUESTACCESSKEY,REQUEST_ACCESS_ATTRS.REQUEST_ACCESS_ATTRSKEY FROM ARSTASKS,REQUEST_ACCESS_ATTRS WHERE ARSTASKS.REQUESTACCESSKEY=REQUEST_ACCESS_ATTRS.REQUEST_ACCESS_KEY AND REQUEST_ACCESS_ATTRS.ATTRIBUTE_NAME='ENT_BY_RULE_ADD' AND REQUEST_ACCESS_ATTRS.ATTRIBUTE_VALUE='NEED_TO_BE_EVALUATED' AND ARSTASKS.STATUS=1 AND REQUESTRULETASKCREATED = false AND (ENDDATE IS NULL OR ENDDATE > '2023-04-21 22:43:39') AND ARSTASKS.TASKKEY IN (944,945) GROUP BY ARSTASKS.REQUESTKEY 2023-04-22 04:13:39,253 [quartzScheduler_Worker-2] DEBUG services.ArsTaskService - Exit populateEntByRuleAdd 2023-04-22 04:13:39,253 [quartzScheduler_Worker-2] DEBUG services.ArsTaskService - Qry to pull info on the Request Keys which are pending and have some request key based task to be created 2023-04-22 04:13:39,253 [quartzScheduler_Worker-2] DEBUG services.ArsTaskService - SELECT ARSTASKS.REQUESTKEY,ARSTASKS.TASKKEY,ARSTASKS.REQUESTACCESSKEY,REQUEST_ACCESS_ATTRS.ATTRIBUTE_VALUE FROM ARSTASKS,REQUEST_ACCESS_ATTRS WHERE ARSTASKS.REQUESTACCESSKEY=REQUEST_ACCESS_ATTRS.REQUEST_ACCESS_KEY AND REQUEST_ACCESS_ATTRS.ATTRIBUTE_NAME='ENT_BY_RULE_ADD' AND ARSTASKS.STATUS=1 AND REQUESTRULETASKCREATED = false AND (ENDDATE IS NULL OR ENDDATE > '2023-04-21 22:43:39') AND ARSTASKS.TASKKEY IN (944,945) GROUP BY ARSTASKS.REQUESTKEY,REQUEST_ACCESS_ATTRS.ATTRIBUTE_VALUE 2023-04-22 04:13:39,255 [quartzScheduler_Worker-2] DEBUG services.ArsTaskService - Inside createTasksForSingleDropDownFromRollback.. 2023-04-22 04:13:39,255 [quartzScheduler_Worker-2] DEBUG services.ArsTaskService - isSingleDropdownTaskWithRollback : false 2023-04-22 04:13:39,255 [quartzScheduler_Worker-2] DEBUG services.ArsTaskService - Inside - createRollbackEntriesForSingleDropdownAddTasks 2023-04-22 04:13:39,255 [quartzScheduler_Worker-2] DEBUG services.ArsTaskService - isSingleDropdownTaskWithRollback : false 2023-04-22 04:13:39,257 [quartzScheduler_Worker-2] DEBUG services.ArsTaskService - Inside createTasksForSingleDropDownFromRollback.. 2023-04-22 04:13:39,257 [quartzScheduler_Worker-2] DEBUG services.ArsTaskService - isSingleDropdownTaskWithRollback : false 2023-04-22 04:13:39,257 [quartzScheduler_Worker-2] DEBUG services.ArsTaskService - Inside - createRollbackEntriesForSingleDropdownAddTasks 2023-04-22 04:13:39,257 [quartzScheduler_Worker-2] DEBUG services.ArsTaskService - isSingleDropdownTaskWithRollback : false 2023-04-22 04:13:39,261 [quartzScheduler_Worker-2] DEBUG services.ArsTaskService - Inside processServiceTickets 2023-04-22 04:13:39,262 [quartzScheduler_Worker-2] DEBUG services.ArsTaskService - Start Check Status and Close Tickets 2023-04-22 04:13:39,265 [quartzScheduler_Worker-2] DEBUG services.ArsTaskService - Config for Task Completion Email: null 2023-04-22 04:13:39,265 [quartzScheduler_Worker-2] DEBUG services.ArsTaskService - ticketId=[INC0010027] for SERVICEDESKCONNECTION=23 2023-04-22 04:13:39,268 [quartzScheduler_Worker-2] DEBUG rest.RestProvisioningService - getStatusForTicketIDs being called 2023-04-22 04:13:39,270 [quartzScheduler_Worker-2] DEBUG rest.RestProvisioningService - initializing Provisioning connection 2023-04-22 04:13:39,271 [quartzScheduler_Worker-2] DEBUG rest.RestProvisioningService - extAttList - [com.saviynt.ecm.utility.domain.ExternalconnectionAttributeValue : 659, com.saviynt.ecm.utility.domain.ExternalconnectionAttributeValue : 660, com.saviynt.ecm.utility.domain.ExternalconnectionAttributeValue : 661, com.saviynt.ecm.utility.domain.ExternalconnectionAttributeValue : 662, com.saviynt.ecm.utility.domain.ExternalconnectionAttributeValue : 663, com.saviynt.ecm.utility.domain.ExternalconnectionAttributeValue : 664, com.saviynt.ecm.utility.domain.ExternalconnectionAttributeValue : 665, com.saviynt.ecm.utility.domain.ExternalconnectionAttributeValue : 666, com.saviynt.ecm.utility.domain.ExternalconnectionAttributeValue : 667, com.saviynt.ecm.utility.domain.ExternalconnectionAttributeValue : 668, com.saviynt.ecm.utility.domain.ExternalconnectionAttributeValue : 669, com.saviynt.ecm.utility.domain.ExternalconnectionAttributeValue : 670, com.saviynt.ecm.utility.domain.ExternalconnectionAttributeValue : 671, com.saviynt.ecm.utility.domain.ExternalconnectionAttributeValue : 672, com.saviynt.ecm.utility.domain.ExternalconnectionAttributeValue : 673, com.saviynt.ecm.utility.domain.ExternalconnectionAttributeValue : 674, com.saviynt.ecm.utility.domain.ExternalconnectionAttributeValue : 675, com.saviynt.ecm.utility.domain.ExternalconnectionAttributeValue : 676, com.saviynt.ecm.utility.domain.ExternalconnectionAttributeValue : 677, com.saviynt.ecm.utility.domain.ExternalconnectionAttributeValue : 678, com.saviynt.ecm.utility.domain.ExternalconnectionAttributeValue : 679] 2023-04-22 04:13:39,276 [quartzScheduler_Worker-2] DEBUG rest.RestProvisioningService - ticketStatusJSON: [call:[[name:call1, connection:userAuth, url:https://dev167564.service-now.com/api/now/table/incident?sysparm_query=number{ticketID}&sysparm_limit=1&sysparm_display_value=true, httpMethod:GET, httpHeaders:[Authorization:${access_token}, Content-Type:application/json], httpContentType:application/raw, ticketStatusPath:result.state, ticketStatusValue:[closeD, CLOSED, Closed], disContinueStatusValue:[Closed Incomplete, closed incomplete, CLOSED INCOMPLETE], successResponses:[[:]]]]] 2023-04-22 04:13:39,276 [quartzScheduler_Worker-2] DEBUG rest.RestProvisioningService - createTicketJSON: [call:[[name:call1, connection:userAuth, url:https://dev167564.service-now.com/api/now/table/incident, httpMethod:POST, httpParams:{"u_caller":"Naren Mon","u_short_description":"need it somethingsdf","u_state":"New","u_urgency":"Medium"}, httpHeaders:[Content-Type:application/json, Accept:application/json, Authorization:${access_token}], httpContentType:application/raw, ticketidPath:result.number, ticketStatusPath:result.state, ticketStatusValue:[open, OPEN, Open], successResponses:[200:User Created Successfuly, 201:User Created Successfuly, 204:User Created Successfuly, 205:User Created Successfuly], unsuccessResponses:[400:Create Account Failed, 401:Create Account Failed, 404:Create Account Failed, 405:Create Account Failed, 500:Create Account Failed, 502:Create Account Failed]]]] 2023-04-22 04:13:39,277 [quartzScheduler_Worker-2] DEBUG rest.RestProvisioningService - Total Call: 1 2023-04-22 04:13:39,375 [quartzScheduler_Worker-2] DEBUG rest.RestProvisioningService - Inside pullObjectsByRest 2023-04-22 04:13:39,375 [quartzScheduler_Worker-2] DEBUG services.HttpClientUtilityService - getHttpClient - sslParams : null 2023-04-22 04:13:39,375 [quartzScheduler_Worker-2] DEBUG services.HttpClientUtilityService - getHttpClient - proxyParams : null 2023-04-22 04:13:39,375 [quartzScheduler_Worker-2] DEBUG services.HttpClientUtilityService - getHttpClient - sslSocketFactory : null 2023-04-22 04:13:39,380 [quartzScheduler_Worker-2] DEBUG services.HttpClientUtilityService - getHttpClient - HttpClientBuilder.create().build() called. 2023-04-22 04:13:39,383 [quartzScheduler_Worker-2] DEBUG rest.RestProvisioningService - pullObjectsByRest - responseStatusCode ::null 2023-04-22 04:13:39,383 [quartzScheduler_Worker-2] DEBUG rest.RestProvisioningService - Entered getResponseHeaders method 2023-04-22 04:13:39,383 [quartzScheduler_Worker-2] DEBUG rest.RestProvisioningService - response of getNewStatusForTicketIDs: null 2023-04-22 04:13:39,383 [quartzScheduler_Worker-2] DEBUG rest.RestProvisioningService - Error in closing ticket...response: null 2023-04-22 04:13:39,383 [quartzScheduler_Worker-2] DEBUG rest.RestProvisioningService - ticketsToBeClosed.size=0 2023-04-22 04:13:39,383 [quartzScheduler_Worker-2] DEBUG services.ArsTaskService - completedArsTaskKeySet size= 0 2023-04-22 04:13:39,383 [quartzScheduler_Worker-2] DEBUG services.ArsTaskService - rejectedArsTaskKeySet size= 0 2023-04-22 04:13:39,383 [quartzScheduler_Worker-2] DEBUG services.ArsTaskService - End Check Status And Close Tickets 2023-04-22 04:13:39,391 [quartzScheduler_Worker-2] DEBUG services.ArsTaskService - Found List of Tasks[com.saviynt.ecm.task.ArsTasks : 945] 2023-04-22 04:13:39,396 [quartzScheduler_Worker-2] DEBUG services.ArsTaskService - Calling createServiceTicket with Sec System - serviceNowTrain and tasklist - [2521:[com.saviynt.ecm.task.ArsTasks : 945]] 2023-04-22 04:13:39,396 [quartzScheduler_Worker-2] DEBUG rest.RestProvisioningService - Entering RestProvisioningService : createServiceTicket 2023-04-22 04:13:39,396 [quartzScheduler_Worker-2] DEBUG rest.RestProvisioningService - initializing Provisioning connection 2023-04-22 04:13:39,398 [quartzScheduler_Worker-2] DEBUG rest.RestProvisioningService - extAttList - [com.saviynt.ecm.utility.domain.ExternalconnectionAttributeValue : 659, com.saviynt.ecm.utility.domain.ExternalconnectionAttributeValue : 660, com.saviynt.ecm.utility.domain.ExternalconnectionAttributeValue : 661, com.saviynt.ecm.utility.domain.ExternalconnectionAttributeValue : 662, com.saviynt.ecm.utility.domain.ExternalconnectionAttributeValue : 663, com.saviynt.ecm.utility.domain.ExternalconnectionAttributeValue : 664, com.saviynt.ecm.utility.domain.ExternalconnectionAttributeValue : 665, com.saviynt.ecm.utility.domain.ExternalconnectionAttributeValue : 666, com.saviynt.ecm.utility.domain.ExternalconnectionAttributeValue : 667, com.saviynt.ecm.utility.domain.ExternalconnectionAttributeValue : 668, com.saviynt.ecm.utility.domain.ExternalconnectionAttributeValue : 669, com.saviynt.ecm.utility.domain.ExternalconnectionAttributeValue : 670, com.saviynt.ecm.utility.domain.ExternalconnectionAttributeValue : 671, com.saviynt.ecm.utility.domain.ExternalconnectionAttributeValue : 672, com.saviynt.ecm.utility.domain.ExternalconnectionAttributeValue : 673, com.saviynt.ecm.utility.domain.ExternalconnectionAttributeValue : 674, com.saviynt.ecm.utility.domain.ExternalconnectionAttributeValue : 675, com.saviynt.ecm.utility.domain.ExternalconnectionAttributeValue : 676, com.saviynt.ecm.utility.domain.ExternalconnectionAttributeValue : 677, com.saviynt.ecm.utility.domain.ExternalconnectionAttributeValue : 678, com.saviynt.ecm.utility.domain.ExternalconnectionAttributeValue : 679] 2023-04-22 04:13:39,398 [quartzScheduler_Worker-2] DEBUG rest.RestProvisioningService - ticketStatusJSON: [call:[[name:call1, connection:userAuth, url:https://dev167564.service-now.com/api/now/table/incident?sysparm_query=number{ticketID}&sysparm_limit=1&sysparm_display_value=true, httpMethod:GET, httpHeaders:[Authorization:${access_token}, Content-Type:application/json], httpContentType:application/raw, ticketStatusPath:result.state, ticketStatusValue:[closeD, CLOSED, Closed], disContinueStatusValue:[Closed Incomplete, closed incomplete, CLOSED INCOMPLETE], successResponses:[[:]]]]] 2023-04-22 04:13:39,398 [quartzScheduler_Worker-2] DEBUG rest.RestProvisioningService - createTicketJSON: [call:[[name:call1, connection:userAuth, url:https://dev167564.service-now.com/api/now/table/incident, httpMethod:POST, httpParams:{"u_caller":"Naren Mon","u_short_description":"need it somethingsdf","u_state":"New","u_urgency":"Medium"}, httpHeaders:[Content-Type:application/json, Accept:application/json, Authorization:${access_token}], httpContentType:application/raw, ticketidPath:result.number, ticketStatusPath:result.state, ticketStatusValue:[open, OPEN, Open], successResponses:[200:User Created Successfuly, 201:User Created Successfuly, 204:User Created Successfuly, 205:User Created Successfuly], unsuccessResponses:[400:Create Account Failed, 401:Create Account Failed, 404:Create Account Failed, 405:Create Account Failed, 500:Create Account Failed, 502:Create Account Failed]]]] 2023-04-22 04:13:39,398 [quartzScheduler_Worker-2] DEBUG rest.RestProvisioningService - accTaskMap: [2521:[com.saviynt.ecm.task.ArsTasks : 945]] 2023-04-22 04:13:39,398 [quartzScheduler_Worker-2] DEBUG rest.RestProvisioningService - Validating Password Policy and setting defaults... 2023-04-22 04:13:39,403 [quartzScheduler_Worker-2] DEBUG rest.RestProvisioningService - Manager = null 2023-04-22 04:13:39,403 [quartzScheduler_Worker-2] DEBUG rest.RestProvisioningService - usermanager = null 2023-04-22 04:13:39,410 [quartzScheduler_Worker-2] DEBUG rest.RestProvisioningService - permissionSet = [] 2023-04-22 04:13:39,410 [quartzScheduler_Worker-2] DEBUG rest.RestProvisioningService - entitlementToBeUpdated = 2023-04-22 04:13:39,410 [quartzScheduler_Worker-2] DEBUG rest.RestProvisioningService - combinedAccountRequestbinding: [usermanager:null, endpoint:serviceNowTrain, password:k3QpwrqZk, task:com.saviynt.ecm.task.ArsTasks : 945, benefeciary:com.saviynt.ecm.identitywarehouse.domain.Users : 2521, requestedByDate:2023-04-21T22:43:39+00:00, allEntitlementsValues:, taskIds:[945], user:com.saviynt.ecm.identitywarehouse.domain.Users : 2521, reqAttrs:[:], requestor:com.saviynt.ecm.identitywarehouse.domain.Users : 1, account:ADD :: 2521] 2023-04-22 04:13:39,410 [quartzScheduler_Worker-2] DEBUG rest.RestProvisioningService - Total Call: 1 2023-04-22 04:13:39,448 [quartzScheduler_Worker-2] DEBUG rest.RestProvisioningService - Before httpParams: {"u_caller":"Naren Mon","u_short_description":"need it somethingsdf","u_state":"New","u_urgency":"Medium"} 2023-04-22 04:13:39,457 [quartzScheduler_Worker-2] DEBUG rest.RestProvisioningService - After httpParams: [u_caller:Naren Mon, u_short_description:need it somethingsdf, u_state:New, u_urgency:Medium] 2023-04-22 04:13:39,511 [quartzScheduler_Worker-2] DEBUG rest.RestProvisioningService - Inside pullObjectsByRest 2023-04-22 04:13:39,512 [quartzScheduler_Worker-2] DEBUG services.HttpClientUtilityService - getHttpClient - sslParams : null 2023-04-22 04:13:39,512 [quartzScheduler_Worker-2] DEBUG services.HttpClientUtilityService - getHttpClient - proxyParams : null 2023-04-22 04:13:39,512 [quartzScheduler_Worker-2] DEBUG services.HttpClientUtilityService - getHttpClient - sslSocketFactory : null 2023-04-22 04:13:39,514 [quartzScheduler_Worker-2] DEBUG services.HttpClientUtilityService - getHttpClient - HttpClientBuilder.create().build() called. 2023-04-22 04:13:42,120 [quartzScheduler_Worker-9] DEBUG jobs.WSRetryJob - jobs invoked.... 2023-04-22 04:13:42,851 [quartzScheduler_Worker-2] DEBUG rest.RestProvisioningService - pullObjectsByRest - responseStatusCode ::401 2023-04-22 04:13:42,852 [quartzScheduler_Worker-2] DEBUG rest.RestProvisioningService - Exception in pullObjectsByRest : java.lang.Exception: 401 at com.saviynt.provisoning.rest.RestProvisioningService.pullObjectsByRest(RestProvisioningService.groovy:3725) at com.saviynt.provisoning.rest.RestProvisioningService.createNewServiceTicket(RestProvisioningService.groovy:8451) at com.saviynt.provisoning.rest.RestProvisioningService$_createServiceTicket_closure47.doCall(RestProvisioningService.groovy:8274) at com.saviynt.provisoning.rest.RestProvisioningService.createServiceTicket(RestProvisioningService.groovy:8105) at com.saviynt.ecm.services.ArsTaskService.createTicketOnTarget(ArsTaskService.groovy:6266) at com.saviynt.ecm.services.ArsTaskService$_processServiceTickets_closure99.doCall(ArsTaskService.groovy:6360) at com.saviynt.ecm.services.ArsTaskService.processServiceTickets(ArsTaskService.groovy:6356) at com.saviynt.ecm.services.ArsTaskHelperService.completeAutoProvTasksUpgraded(ArsTaskHelperService.groovy:99) at MultipleProvisioningJob.execute(MultipleProvisioningJob.groovy:202) at org.quartz.core.JobRunShell.run(JobRunShell.java:199) at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:546) 2023-04-22 04:13:42,852 [quartzScheduler_Worker-2] DEBUG rest.RestProvisioningService - Inside token Expiry Exception block. connectionParamMap.refreshTryCount : 0 2023-04-22 04:13:42,852 [quartzScheduler_Worker-2] DEBUG rest.RestProvisioningService - Incrementing connectionParamMap.refreshTryCount : 1 2023-04-22 04:13:42,852 [quartzScheduler_Worker-2] DEBUG rest.RestProvisioningService - maxRefreshTryCount : 5 2023-04-22 04:13:42,853 [quartzScheduler_Worker-2] DEBUG rest.RestUtilService - Calling https://dev167564.service-now.com/oauth_token.do 2023-04-22 04:13:42,853 [quartzScheduler_Worker-2] DEBUG services.HttpClientUtilityService - getHttpClient - sslParams : null 2023-04-22 04:13:42,853 [quartzScheduler_Worker-2] DEBUG services.HttpClientUtilityService - getHttpClient - proxyParams : null 2023-04-22 04:13:42,853 [quartzScheduler_Worker-2] DEBUG services.HttpClientUtilityService - getHttpClient - sslSocketFactory : null 2023-04-22 04:13:42,857 [quartzScheduler_Worker-2] DEBUG services.HttpClientUtilityService - getHttpClient - HttpClientBuilder.create().build() called. 2023-04-22 04:13:44,997 [quartzScheduler_Worker-2] DEBUG rest.RestUtilService - fetching result from response.responseText 2023-04-22 04:13:45,003 [quartzScheduler_Worker-2] DEBUG rest.RestProvisioningService - access token populated for oauth authentication.. 2023-04-22 04:13:45,053 [quartzScheduler_Worker-2] DEBUG rest.RestProvisioningService - connectionParamMap.refreshTryCount = null 2023-04-22 04:13:45,053 [quartzScheduler_Worker-2] DEBUG rest.RestProvisioningService - Inside pullObjectsByRest 2023-04-22 04:13:45,053 [quartzScheduler_Worker-2] DEBUG services.HttpClientUtilityService - getHttpClient - sslParams : null 2023-04-22 04:13:45,053 [quartzScheduler_Worker-2] DEBUG services.HttpClientUtilityService - getHttpClient - proxyParams : null 2023-04-22 04:13:45,053 [quartzScheduler_Worker-2] DEBUG services.HttpClientUtilityService - getHttpClient - sslSocketFactory : null 2023-04-22 04:13:45,056 [quartzScheduler_Worker-2] DEBUG services.HttpClientUtilityService - getHttpClient - HttpClientBuilder.create().build() called. 2023-04-22 04:13:47,602 [quartzScheduler_Worker-2] DEBUG rest.RestProvisioningService - pullObjectsByRest - responseStatusCode ::201 2023-04-22 04:13:47,603 [quartzScheduler_Worker-2] DEBUG rest.RestProvisioningService - Entered getResponseHeaders method 2023-04-22 04:13:47,603 [quartzScheduler_Worker-2] DEBUG rest.RestProvisioningService - responseError : null 2023-04-22 04:13:47,604 [quartzScheduler_Worker-2] DEBUG rest.RestProvisioningService - isAuthError: false 2023-04-22 04:13:47,604 [quartzScheduler_Worker-2] DEBUG rest.RestProvisioningService - pullObjectsByRest - responseMap.size : 1 2023-04-22 04:13:47,604 [quartzScheduler_Worker-2] DEBUG rest.RestProvisioningService - pullObjectsByRest - objectList.size : 1 2023-04-22 04:13:47,604 [quartzScheduler_Worker-2] DEBUG rest.RestProvisioningService - Decrementing connectionParamMap.refreshTryCount : 0 2023-04-22 04:13:47,604 [quartzScheduler_Worker-2] DEBUG rest.RestProvisioningService - response of createNewServiceTicket: [result:[parent:, made_sla:true, caused_by:, watch_list:, upon_reject:cancel, sys_updated_on:2023-04-23 16:40:48, child_incidents:0, hold_reason:, origin_table:, task_effective_number:INC0010029, approval_history:, number:INC0010029, resolved_by:, sys_updated_by:admin, opened_by:[link:https://dev167564.service-now.com/api/now/table/sys_user/6816f79cc0a8016401c5a33be04be441, value:6816f79cc0a8016401c5a33be04be441], user_input:, sys_created_on:2023-04-23 16:40:48, sys_domain:[link:https://dev167564.service-now.com/api/now/table/sys_user_group/global, value:global], state:1, route_reason:, sys_created_by:admin, knowledge:false, order:, calendar_stc:, closed_at:, cmdb_ci:, delivery_plan:, contract:, impact:3, active:true, work_notes_list:, business_service:, business_impact:, priority:5, sys_domain_path:/, rfc:, time_worked:, expected_start:, opened_at:2023-04-23 16:40:48, business_duration:, group_list:, work_end:, caller_id:, reopened_time:, resolved_at:, approval_set:, subcategory:, work_notes:, universal_request:, short_description:, close_code:, correlation_display:, delivery_task:, work_start:, assignment_group:, additional_assignee_list:, business_stc:, cause:, description:, origin_id:, calendar_duration:, close_notes:, notify:1, service_offering:, sys_class_name:incident, closed_by:, follow_up:, parent_incident:, sys_id:5e6784431b92611075f843f8cd4bcb6f, contact_type:, reopened_by:, incident_state:1, urgency:3, problem_id:, company:, reassignment_count:0, activity_due:, assigned_to:, severity:3, comments:, approval:not requested, sla_due:, comments_and_work_notes:, due_date:, sys_mod_count:0, reopen_count:0, sys_tags:, escalation:0, upon_approval:proceed, correlation_id:, location:, category:inquiry]] 2023-04-22 04:13:47,604 [quartzScheduler_Worker-2] DEBUG rest.RestProvisioningService - tempJsonMap for ProvisioningMetadata: [accountComments:;Ticket Number=INC0010029;] 2023-04-22 04:13:47,621 [quartzScheduler_Worker-2] DEBUG rest.RestProvisioningService - taskResult:: true 2023-04-22 04:13:47,621 [quartzScheduler_Worker-2] DEBUG rest.RestProvisioningService - This is success Account Task 2023-04-22 04:13:47,621 [quartzScheduler_Worker-2] DEBUG externalws.ExternalConnectorService - Enter updateServiceTicketToCloudServer 2023-04-22 04:13:47,621 [quartzScheduler_Worker-2] DEBUG externalws.ExternalConnectorService - Enter callcloudwebservice... json 2023-04-22 04:13:47,621 [quartzScheduler_Worker-2] DEBUG externalws.ExternalConnectorService - json is --- {"taskid":null,"comments":"Ticket Number: INC0010029"} 2023-04-22 04:13:47,625 [quartzScheduler_Worker-2] ERROR externalws.ExternalConnectorService - Error in webservice call = null java.lang.NullPointerException 2023-04-22 04:13:47,625 [quartzScheduler_Worker-2] DEBUG externalws.ExternalConnectorService - Exit callcloudwebservice ..json 2023-04-22 04:13:47,625 [quartzScheduler_Worker-2] DEBUG externalws.ExternalConnectorService - Exit updateServiceTicketToCloudServer 2023-04-22 04:13:47,633 [quartzScheduler_Worker-2] DEBUG services.ArsTaskService - Exiting processServiceTickets 2023-04-22 04:13:47,633 [quartzScheduler_Worker-2] DEBUG services.ArsTaskService - Inside processServiceDeskFile 2023-04-22 04:13:47,634 [quartzScheduler_Worker-2] DEBUG services.ArsTaskService - Start Check Status and Close Task 2023-04-22 04:13:47,636 [quartzScheduler_Worker-2] DEBUG services.ArsTaskService - Config for Task Completion Email: null 2023-04-22 04:13:47,636 [quartzScheduler_Worker-2] DEBUG services.ArsTaskService - pendingTasks: [:] 2023-04-22 04:13:47,637 [quartzScheduler_Worker-2] DEBUG services.ArsTaskService - completedArsTaskKeySet size for File= 0 2023-04-22 04:13:47,637 [quartzScheduler_Worker-2] DEBUG services.ArsTaskService - rejectedArsTaskKeySet size for File= 0 2023-04-22 04:13:47,637 [quartzScheduler_Worker-2] DEBUG services.ArsTaskService - End Check Status And Close Tasks 2023-04-22 04:13:47,638 [quartzScheduler_Worker-2] DEBUG services.ArsTaskService - Found List of Tasks in File: [] 2023-04-22 04:13:47,644 [quartzScheduler_Worker-2] DEBUG services.ArsTaskService - Exiting processServiceDeskFile 2023-04-22 04:13:47,644 [quartzScheduler_Worker-2] DEBUG services.ArsTaskHelperService - arsTaskKeySet = [] 2023-04-22 04:13:47,646 [quartzScheduler_Worker-2] DEBUG services.ArsTaskHelperService - Config for Task Completion Emailnull 2023-04-22 04:13:47,647 [quartzScheduler_Worker-2] DEBUG jobs.MultipleProvisioningJob - cleaning gorm. 2023-04-22 04:13:47,654 [quartzScheduler_Worker-2] DEBUG jobs.MultipleProvisioningJob - total records processed = 2 2023-04-22 04:13:47,662 [quartzScheduler_Worker-2] DEBUG services.ImportUtilityService - Writing job history to import logs for jobID: 22793 2023-04-22 04:13:47,662 [quartzScheduler_Worker-2] DEBUG services.ImportUtilityService - Number of log entries to be written : 10 2023-04-22 04:13:47,669 [quartzScheduler_Worker-2] DEBUG integration.ExternalConnectionCallService - Enter consolidateConcurrentChildTriggerLogs 2023-04-22 04:13:47,669 [quartzScheduler_Worker-2] DEBUG services.ImportUtilityService - randomNo: 279 2023-04-22 04:13:48,953 [quartzScheduler_Worker-2] DEBUG services.SaviyntCommonUtilityService - getJobCount - params: [importType:null, jobType:null, secSysId:null, jobName:'WSRetryJob','MultipleProvisioningJob', parentJobId:22792, isMultiJob:true, connectionType:null, callFromRunAllAnalyticsJob:null] 2023-04-22 04:13:48,958 [quartzScheduler_Worker-2] DEBUG services.SaviyntCommonUtilityService - Testing-JobDataMap.size : 9 2023-04-22 04:13:48,959 [quartzScheduler_Worker-2] DEBUG services.SaviyntCommonUtilityService - Testing-JobDataMap.size : 5 2023-04-22 04:13:48,959 [quartzScheduler_Worker-2] DEBUG services.SaviyntCommonUtilityService - jobCount: 1 2023-04-22 04:13:48,959 [quartzScheduler_Worker-2] DEBUG integration.ExternalConnectionCallService - Consolidate child's importlog 2023-04-22 04:13:48,959 [quartzScheduler_Worker-2] DEBUG integration.ExternalConnectionCallService - parentJobId 22792 2023-04-22 04:13:48,984 [quartzScheduler_Worker-2] DEBUG jobs.MultipleProvisioningJob - MultipleProvisioningJob Job End for job id 22793 - jobcomment-invoked from WSRetryJob ID - 22792 group 0 2023-04-22 04:13:48,984 [quartzScheduler_Worker-2] DEBUG jobs.MultipleProvisioningJob - tasks found.. 2023-04-22 04:13:48,984 [quartzScheduler_Worker-2] DEBUG jobs.MultipleProvisioningJob - removing entries from ARSTASKS_EXEC table done 2023-04-22 04:13:48,984 [quartzScheduler_Worker-2] DEBUG services.SaviyntCommonUtilityService - Enter removetasksfromexecution 2023-04-22 04:13:48,984 [quartzScheduler_Worker-2] DEBUG services.SaviyntCommonUtilityService - Entries to remove = [944, 945] 2023-04-22 04:13:48,984 [quartzScheduler_Worker-2] DEBUG services.SaviyntCommonUtilityService - Entries remove start 2023-04-22 04:13:49,021 [quartzScheduler_Worker-2] DEBUG services.SaviyntCommonUtilityService - Entries remove finish 2023-04-22 04:13:49,021 [quartzScheduler_Worker-2] DEBUG services.SaviyntCommonUtilityService - Exit removetasksfromexecution 2023-04-22 04:13:49,021 [quartzScheduler_Worker-2] DEBUG jobs.MultipleProvisioningJob - removing entries from ARSTASKS_EXEC table done 2023-04-22 04:13:49,021 [quartzScheduler_Worker-2] DEBUG jobs.MultipleProvisioningJob - newArsTasks = [[]] 2023-04-22 04:13:49,021 [quartzScheduler_Worker-2] DEBUG jobs.MultipleProvisioningJob - New tasks added in between. Retrigger WSRETRY again 2023-04-22 04:13:49,021 [quartzScheduler_Worker-2] DEBUG jobs.MultipleProvisioningJob - Enter invokejobforremainingtasks 2023-04-22 04:13:49,021 [quartzScheduler_Worker-2] DEBUG jobs.MultipleProvisioningJob - Another WSRetry is already running. 2023-04-22 04:13:49,021 [quartzScheduler_Worker-2] DEBUG jobs.MultipleProvisioningJob - Exit invokejobforremainingtasks 2023-04-22 04:13:49,021 [quartzScheduler_Worker-2] DEBUG jobs.MultipleProvisioningJob - MultipleProvisioningJob Job End for job id 22793 - jobcomment-invoked from WSRetryJob ID - 22792 group 0 2023-04-22 04:14:02,125 [quartzScheduler_Worker-9] DEBUG jobs.WSRetryJob - Job execution completed. 2023-04-22 04:14:02,127 [quartzScheduler_Worker-9] DEBUG jobs.WSRetryJob - Exit processupgradedmultithreadedtasks 2023-04-22 04:14:02,127 [quartzScheduler_Worker-9] DEBUG integration.ExternalConnectionCallService - Enter consolidateConcurrentChildTriggerLogs 2023-04-22 04:14:02,127 [quartzScheduler_Worker-9] DEBUG jobs.WSRetryJob - WSRETRYJOB End @ Fri Apr 21 22:44:02 UTC 2023 2023-04-22 04:14:02,127 [quartzScheduler_Worker-9] DEBUG jobs.WSRetryJob - In Finally .. Cleaning property instance map... 2023-04-22 04:14:02,127 [quartzScheduler_Worker-9] DEBUG jobs.WSRetryJob - In Finally .. Cleaning property instance map... completed. 2023-04-22 04:14:18,030 [http-nio-8080-exec-1] DEBUG log.LoggerService - logFileAndPath: /opt/saviynt/Conf/logs/debugLog.log 2023-04-22 04:14:18,031 [http-nio-8080-exec-1] DEBUG log.LoggerService - Entered getLogFiles 2023-04-22 04:14:18,031 [http-nio-8080-exec-1] DEBUG log.LoggerService - logFiles before sorting : 2023-04-22 04:14:18,031 [http-nio-8080-exec-1] DEBUG log.LoggerService - logFiles after sorting : 2023-04-22 04:14:18,031 [http-nio-8080-exec-1] DEBUG log.LoggerService - Get 1000 lines for debugLog.log