Automatic Provisioning is not working

[rambhan]

Hi Team, While trying to provision access to an account, we are facing an issue with the message in the logs: "No ArsRequestKey defined. We need to fetch the tasks using a query and provision using threads." A task was created after running the detect job, and automated provisioning is not happening after running the Wsretry job.

Here is the screenshot of task created - 

Here are the logs -

2023-12-01T11:42:03.374+00:00 ecm-worker jobs.WSRetryJob quartzScheduler_Worker-8-4p6xk DEBUG WSRETRYJOB start @ Fri Dec 01 11:42:03 UTC 2023
2023-12-01T11:42:03.376+00:00 ecm-worker jobs.WSRetryJob quartzScheduler_Worker-8-4p6xk DEBUG ecmConfigBlocking = 0
2023-12-01T11:42:03.376+00:00 ecm-worker jobs.WSRetryJob quartzScheduler_Worker-8-4p6xk DEBUG blockingwsretryenabled = false
2023-12-01T11:42:03.377+00:00 ecm-worker services.SaviyntCommonUtilityService quartzScheduler_Worker-8-4p6xk DEBUG No Multiple provisioning job running on cluster.. start cleanup
2023-12-01T11:42:03.377+00:00 ecm-worker services.SaviyntCommonUtilityService quartzScheduler_Worker-8-4p6xk DEBUG JobID = null
2023-12-01T11:42:03.378+00:00 ecm-worker jobs.WSRetryJob quartzScheduler_Worker-8-4p6xk DEBUG multithreadinginwsretry = ###FALSE####
2023-12-01T11:42:03.378+00:00 ecm-worker jobs.WSRetryJob quartzScheduler_Worker-8-4p6xk DEBUG upgrademultithradinginwsretry = ###TRUE####
2023-12-01T11:42:03.378+00:00 ecm-worker jobs.WSRetryJob quartzScheduler_Worker-8-4p6xk DEBUG alwaysinvokemultthreadingonconnector=[:]
2023-12-01T11:42:03.378+00:00 ecm-worker jobs.WSRetryJob quartzScheduler_Worker-8-4p6xk DEBUG getAllSecuritySystemWithSuccessfulConnection
2023-12-01T11:42:03.410+00:00 ecm-worker jobs.WSRetryJob quartzScheduler_Worker-8-4p6xk DEBUG precheck tasks = ##[:]##
2023-12-01T11:42:03.419+00:00 ecm-worker services.SaviyntCommonUtilityService quartzScheduler_Worker-8-4p6xk DEBUG processingArsTaksSet = []
2023-12-01T11:42:03.421+00:00 ecm-worker jobs.WSRetryJob quartzScheduler_Worker-8-4p6xk DEBUG Not connector server.. defaulting to true
2023-12-01T11:42:03.421+00:00 ecm-worker jobs.WSRetryJob quartzScheduler_Worker-8-4p6xk DEBUG check and invoke multi threading = true...
2023-12-01T11:42:03.421+00:00 ecm-worker jobs.WSRetryJob quartzScheduler_Worker-8-4p6xk DEBUG In upgradedwsretry...
2023-12-01T11:42:03.421+00:00 ecm-worker jobs.WSRetryJob quartzScheduler_Worker-8-4p6xk DEBUG Enter processupgradedmultithreadedtasks
2023-12-01T11:42:03.421+00:00 ecm-worker jobs.WSRetryJob quartzScheduler_Worker-8-4p6xk DEBUG parameters = [securitySystemIDList:[656], connectorserver:false, systemWithSuccessfulConnection:[1, 2, 3, 4, 5, 6, 7, 11, 12, 13, 14, 15, 16, 17, 18, 19, 20, 21, 23, 26, 27, 28, 29, 30, 31, 32, 33, 34, 35, 36, 37, 38, 39, 40, 41, 42, 43, 44, 45, 46, 47, 48, 50, 51, 54, 55, 56, 57, 58, 61, 63, 64, 68, 69, 70, 72, 74, 75, 76, 77, 78, 79, 80, 81, 83, 84, 85, 86, 87, 88, 89, 100, 101, 102, 103, 104, 105, 106, 107, 110, 112, 113, 114, 116, 117, 119, 124, 125, 127, 128, 129, 130, 132, 133, 134, 135, 136, 137, 138, 139, 140, 141, 142, 143, 144, 145, 146, 148, 149, 150, 151, 154, 155, 156, 157, 158, 159, 160, 161, 162, 163, 164, 165, 166, 167, 168, 169, 170, 171, 174, 178, 179, 180, 181, 182, 183, 184, 185, 186, 187, 188, 189, 190, 191, 192, 193, 194, 195, 196, 197, 198, 199, 200, 202, 203, 204, 205, 206, 207, 208, 209, 210, 211, 212, 213, 214, 215, 216, 217, 218, 219, 220, 221, 222, 223, 224, 225, 226, 227, 232, 233, 234, 235, 236, 237, 238, 239, 240, 241, 242, 243, 244, 245, 246, 247, 248, 249, 250, 251, 252, 253, 254, 255, 256, 257, 258, 259, 260, 261, 263, 264, 265, 266, 267, 273, 274, 275, 276, 277, 278, 279, 280, 281, 282, 283, 284, 286, 287, 291, 292, 293, 294, 295, 297, 298, 299, 301, 302, 304, 305, 306, 307, 308, 309, 310, 311, 312, 313, 314, 315, 316, 317, 318, 320, 321, 322, 323, 324, 325, 326, 328, 329, 333, 336, 337, 339, 340, 341, 344, 345, 346, 347, 348, 349, 350, 351, 352, 353, 354, 355, 356, 357, 358, 359, 361, 362, 363, 364, 365, 366, 367, 369, 370, 371, 372, 373, 380, 381, 382, 383, 384, 385, 386, 387, 388, 389, 390, 391, 392, 393, 394, 395, 396, 397, 398, 399, 400, 401, 402, 403, 404, 405, 406, 407, 408, 409, 410, 411, 412, 414, 415, 416, 417, 418, 419, 420, 421, 422, 423, 424, 425, 426, 427, 428, 429, 430, 431, 432, 433, 434, 435, 436, 439, 440, 441, 443, 444, 445, 446, 447, 448, 449, 450, 451, 452, 453, 454, 455, 456, 459, 460, 462, 463, 464, 465, 466, 467, 468, 469, 471, 472, 473, 474, 476, 479, 480, 481, 482, 483, 484, 485, 486, 487, 488, 489, 490, 491, 492, 493, 494, 495, 496, 497, 498, 499, 500, 501, 502, 503, 504, 505, 506, 507, 508, 509, 510, 511, 512, 513, 514, 515, 516, 517, 518, 519, 520, 522, 523, 524, 525, 526, 527, 528, 529, 530, 531, 532, 533, 534, 535, 536, 537, 538, 539, 540, 541, 542, 543, 544, 545, 546, 547, 548, 549, 550, 551, 552, 553, 554, 555, 556, 557, 558, 559, 560, 561, 562, 563, 564, 565, 566, 567, 568, 569, 570, 571, 572, 573, 574, 575, 576, 577, 578, 579, 590, 591, 592, 593, 594, 596, 598, 601, 602, 603, 604, 605, 606, 607, 608, 609, 610, 611, 614, 615, 616, 618, 619, 620, 621, 622, 623, 624, 625, 626, 627, 628, 629, 630, 631, 632, 633, 634, 635, 636, 637, 638, 639, 640, 641, 642, 643, 644, 645, 646, 647, 648, 649, 650, 651, 652, 653, 654, 655, 656], context:JobExecutionContext: trigger: 'MANUAL_TRIGGER.MT_bj13b915jeig job: utility.WSRetryJob fireTime: 'Fri Dec 01 11:42:03 UTC 2023 scheduledFireTime: Fri Dec 01 11:41:58 UTC 2023 previousFireTime: 'null nextFireTime: null isRecovering: false refireCount: 0, ecmImportJob:com.saviynt.ecm.identitywarehouse.domain.EcmImportJob : 189797, taskTypesList:[1], securitySystemList:[656], processingTaskSet:[], successfulConnection:[1, 2, 3, 4, 5, 7, 10, 11, 12, 13, 14, 15, 16, 18, 20, 21, 22, 24, 27, 29, 31, 36, 37, 38, 40, 42, 43, 44, 45, 46, 47, 48, 49, 50, 52, 53, 54, 55, 56, 57, 58, 71, 72, 73, 74, 75, 76, 77, 78, 79, 83, 85, 86, 88, 93, 95, 96, 97, 98, 100, 101, 102, 103, 104, 105, 106, 107, 108, 109, 110, 111, 112, 113, 114, 115, 117, 118, 119, 122, 123, 124, 125, 126, 127, 128, 130, 131, 132, 133, 134, 135, 136, 137, 138, 139, 140, 143, 144, 148, 149, 150, 151, 152, 153, 154, 155, 156, 157, 158, 159, 160, 161, 162, 163, 164, 165, 166, 167, 168, 173, 174, 175, 176, 177, 178, 179, 180, 181, 182, 183, 184, 185, 186, 187, 188, 189, 190, 191, 192, 193, 194, 195, 196, 197, 198, 199, 200, 201, 202, 203, 204, 205, 206, 207, 208, 209, 210, 211, 212, 213, 214, 215, 216, 217, 218, 219, 220, 221, 222, 223, 224, 225, 226, 228, 229, 246, 247, 248, 249, 251, 253, 254, 257, 261, 265, 270, 271, 272, 273, 274, 275, 276, 278, 279, 281, 282, 283, 284, 285, 286, 287, 288, 289, 290, 291, 292, 293, 298, 299, 301, 303, 304, 305, 308, 309, 310, 311, 312, 313, 314, 315, 316, 317, 318, 319, 320, 321, 322, 323, 325, 326, 327, 328, 329, 330, 332, 333, 334, 335, 336, 338, 339, 347, 348, 349, 350, 351, 352, 353, 354, 355, 356, 357, 358, 359, 360, 361, 362, 363, 364, 365, 366, 367, 368, 369, 370, 371, 372, 373, 374, 375, 376, 377, 378, 379, 380, 382, 383, 384, 385, 388, 389, 390, 391, 393, 394, 395, 396, 398, 400, 401, 402, 403, 404, 405, 406, 407, 408, 411, 412, 413, 415, 416, 417, 418, 419, 420, 421, 422, 423, 424, 425, 426, 427, 428, 429, 430, 433, 434, 436, 437, 438, 439, 440, 441, 442, 443, 445, 446, 447, 448, 452, 454, 455, 456, 457, 458, 459, 460, 461, 462, 463, 464, 465, 466, 467, 468, 469, 470, 471, 472, 473, 474, 475, 476, 477, 478, 479, 480, 481, 482, 483, 484, 485, 486, 487, 488, 489, 490, 491, 492, 493, 494, 495, 496, 497, 498, 499, 500, 501, 502, 503, 504, 505, 506, 508, 509, 510, 511, 512, 514, 515, 516, 517, 518, 519, 520, 521, 522, 523, 524, 525, 526, 527, 528, 529, 530, 531, 532, 533, 534, 535, 536, 537, 538, 539, 540, 541, 542, 543, 544, 545, 546, 547, 548, 549, 550, 551, 552, 553, 554, 555, 556, 557, 558, 559, 560, 561, 562, 563, 564, 565, 566, 567, 568, 569, 570, 571, 572, 573, 574, 575, 576, 577, 578, 579, 580, 581, 582, 583, 584, 585, 586, 587, 588, 589, 590, 591, 592, 593, 594, 595, 596, 597, 598, 599, 600, 601, 602, 603, 604, 605, 606, 607, 608, 609, 610, 611, 612, 613, 614, 617, 618, 619, 620, 621, 622, 623, 625, 626, 627, 628, 629, 631, 632, 633, 634, 635, 636, 637, 638, 639, 640, 641, 642, 643, 644, 645, 646, 647, 648, 649, 650, 651, 652, 653, 654, 655, 656, 657, 658, 659, 660, 661, 662, 663, 664, 665, 666, 667, 668, 669, 670, 671, 672, 673, 674, 675, 676, 677], originalJobMap:[tabDetail:, securitysystems:656, cronexpression:0 15 10 * * ? 2099, tasktypes:1, moreoptions:true, updateUser:7000027088, advquery:, batchsize:], systemNameList:[Aloy_AD_SaviyntPOC_Test1]]
2023-12-01T11:42:03.421+00:00 ecm-worker jobs.WSRetryJob quartzScheduler_Worker-8-4p6xk DEBUG No ArsRequestKey defined. We need to fetch the tasks using a query and provision using threads.
2023-12-01T11:42:03.421+00:00 ecm-worker jobs.WSRetryJob quartzScheduler_Worker-8-4p6xk DEBUG filterquery: and at.securitysystem in (656) and at.tasktype in (1) and (at.STARTDATE IS NULL OR at.STARTDATE <= UTC_TIMESTAMP())
2023-12-01T11:42:03.424+00:00 ecm-worker services.ArsTaskHelperService quartzScheduler_Worker-8-4p6xk DEBUG Started preValidateTasksBeforeMapping
2023-12-01T11:42:03.424+00:00 ecm-worker services.ArsTaskHelperService quartzScheduler_Worker-8-4p6xk DEBUG ValidateAccountName
2023-12-01T11:42:03.424+00:00 ecm-worker services.ArsTaskHelperService quartzScheduler_Worker-8-4p6xk DEBUG existingAccNameUserEndMap size..0
2023-12-01T11:42:03.424+00:00 ecm-worker services.ArsTaskHelperService quartzScheduler_Worker-8-4p6xk DEBUG existingAccNameEndMap size..0
2023-12-01T11:42:03.427+00:00 ecm-worker services.ArsTaskHelperService quartzScheduler_Worker-8-4p6xk DEBUG ended preValidateTasksBeforeMapping[]
2023-12-01T11:42:03.427+00:00 ecm-worker services.SaviyntCommonUtilityService quartzScheduler_Worker-8-4p6xk DEBUG getProvisioningThreadCount() method. numberOfTasks : 0
2023-12-01T11:42:03.427+00:00 ecm-worker services.SaviyntCommonUtilityService quartzScheduler_Worker-8-4p6xk DEBUG provTriggerConfig : [initialThreshold:500, steps:[[taskMinCount:500, taskMaxCount:1000, threadUsePercentage:20], [taskMinCount:1000, taskMaxCount:2000, threadUsePercentage:30], [taskMinCount:2000, taskMaxCount:5000, threadUsePercentage:40], [taskMinCount:5000, threadUsePercentage:50]], connectionTimeout:10, readTimeout:30, maxWorkerReplicaCount:5]
2023-12-01T11:42:03.427+00:00 ecm-worker services.SaviyntCommonUtilityService quartzScheduler_Worker-8-4p6xk DEBUG As number of tasks are less than initialThreshold so setting triggerCount : 1. initialThreshold : 500, numberOfTasks : 0
2023-12-01T11:42:03.427+00:00 ecm-worker jobs.WSRetryJob quartzScheduler_Worker-8-4p6xk DEBUG Maximum Trigger Count : 1
2023-12-01T11:42:03.427+00:00 ecm-worker jobs.WSRetryJob quartzScheduler_Worker-8-4p6xk DEBUG Found 0 pending tasks.. Ending the job..
2023-12-01T11:42:03.428+00:00 ecm-worker jobs.WSRetryJob quartzScheduler_Worker-8-4p6xk DEBUG Exit processupgradedmultithreadedtasks
2023-12-01T11:42:03.428+00:00 ecm-worker integration.ExternalConnectionCallService quartzScheduler_Worker-8-4p6xk DEBUG Enter consolidateConcurrentChildTriggerLogs
2023-12-01T11:42:03.428+00:00 ecm-worker integration.ExternalConnectionCallService quartzScheduler_Worker-8-4p6xk DEBUG parentJobId null
2023-12-01T11:42:03.428+00:00 ecm-worker integration.ExternalConnectionCallService quartzScheduler_Worker-8-4p6xk DEBUG jobCount 0
2023-12-01T11:42:03.428+00:00 ecm-worker jobs.WSRetryJob quartzScheduler_Worker-8-4p6xk DEBUG WSRETRYJOB End @ Fri Dec 01 11:42:03 UTC 2023
2023-12-01T11:42:03.428+00:00 ecm-worker jobs.WSRetryJob quartzScheduler_Worker-8-4p6xk DEBUG In Finally .. Cleaning property instance map...
2023-12-01T11:42:03.428+00:00 ecm-worker jobs.WSRetryJob quartzScheduler_Worker-8-4p6xk DEBUG In Finally .. Cleaning property instance map... completed.
2023-12-01T11:42:03.428+00:00 ecm-worker jobs.WSRetryJob quartzScheduler_Worker-8-4p6xk DEBUG Exit WSRetryJOB

[SumathiSomala]

@rambhan Automated Provisioning is enabled in security system?

Can you add below config in CONNECTION CONFIGURATION field of your Endpoint and check once.

{"conf":[{"ADDMEMBERTOENT":"TRUE"},{"ADDUSERTOENT":"TRUE"}]}

If this reply answered your question, please accept it as a solution and kudos.

[rambhan]

Hi @SumathiSomala  Yes, automated provision is set at security system and with this config update at the endpoint - {"conf":[{"ADDMEMBERTOENT":"TRUE"},{"ADDUSERTOENT":"TRUE"}]} is also not working.

[SumathiSomala]

@rambhan We need to fetch the tasks using a query and provision using threads.

Where you have added the query?

Is provisioning working without query?

[rambhan]

Hi @SumathiSomala we were not added any query, yes provisioning was working without adding a query using different service account and for different endpoint and for same accounts.

[rambhan]

@SumathiSomala  we enabled automated provisioning at security system and updated primaryaccounttype at endpoint. Updated a user from UI and then user update rules will get triggered and will re-run the specific technical rule created for that user. We will run detective rules job for creating tasks and run provision wsretry job to complete the task picking up automatically.

[rambhan]

@sk  

Here is the screenshot for wsretry job configuration:

Here is the screenshot of securitysystem key:

Here is the task created for security system:

[This message has been edited by moderator to mask url]

[SumathiSomala]

@rambhan try below in advanced query

and at.tasktype in (1)

[rambhan]

@SumathiSomala after updating the job:

we see this message in the logs.

[sk]

@rambhan : Like I assumed in logs you can clearly see that startdate of task 772 is greater than current date hence they are not getting picked and processed.

[sk]

@rambhan : Can you share the start date of task 772 ? You can get this value from data analyzer. Probably task has future dated start date. Run below query and share the output

select taskkey, taskdate, startdate, tasktype from arstasks where taskkey=772

[rambhan]

@sk here is the screenshot after executing the query:

[sk]

@rambhan : If you see start date is dec 5th hence they are getting skipped.

[rambhan]

@sk yes  thats correct, I've updated the start date and task date as same and able to provision the account. Thanks for helping out real quick. 

@SumathiSomala thanks for prompt responses.

[sk]

@rambhan : From the logs I see job is looking for specific security system key 656 and it didn't find any tasks in that. Can you please share the screenshot of wsretry job configuration?

what is the security system key of Aloy_AD_SaviyntPOC_Test1 ?

If feel wsretry job you are using is limited to one security system which is not same as Aloy_AD_SaviyntPOC_Test1 

[rushikeshvartak]

This occurs when timebound request has been raised for entitlement.