Salesforce

WorldServer - after enabling Maintenance debug logging, what do Garbage Collection log entries related Project Cleaner mean?

« Go Back

Information

 
TitleWorldServer - after enabling Maintenance debug logging, what do Garbage Collection log entries related Project Cleaner mean?
URL Name000013091
SummaryWhen there is a problem with Garbage Collection mainly because projects are not getting archived or GC does not run, the Garbage Collection entries in the ws.log or ws-legacy.log file do not provide any details to understand why your issues are happening. In order to find out the reasons for this issue, you may want to enable the Maintenance Debug logging. This article explains how to read the content of the log file.
Scope/EnvironmentWorldServer
Question

Per default, the Garbage Collection entries in the ws.log or ws-legacy.log file do not provide many details. All you would find in the logs are entries stating that the Project Cleaner has started to run and entries stating that it was completed successfully. Here is an example:
 
[2020-07-24 00:30:01,048] WARN Completed Project Garbage Collector [57fcb77a] com.idiominc.ws.maintenance.CompletedProjectCleanerGCTask: Starting Completed Project Garbage Collection.
[2020-07-24 00:46:32,457] WARN Completed Project Garbage Collector [57fcb77a] com.idiominc.ws.maintenance.OldTaskCleaner: Deleted 3810 tasks and 27 projects.
[2020-07-24 00:46:32,457] WARN Completed Project Garbage Collector [57fcb77a] com.idiominc.ws.maintenance.CompletedProjectCleanerGCTask: Completed Project Garbage Collection has completed.  Total time: 16 minutes, 31 seconds.

However, sometimes you might have issues. Your projects are not getting archived as expected, or the Project Cleaner is not completing. In order to find out the reasons for this issue, you may want to enable the Maintenance Debug logging in your environment and analyse the content of your Log file once the Project Cleaner has run. Since the Maintenance debug logging can be very verbose, it is recommended to configure your system to create a separate log file for it. The instructions about how to do that can be found in this article:

SDL WorldServer - how to configure a separate Garbage Collector Log and enable Maintenance logging in general.properties

However, reading the content of the log file is not always obvious. What do all those entries mean?
Answer

The Project Cleaner checks all the projects (active or completed/canceled) present in your WorldServer environment. They will be checked one by one based on project name (not project ID or date) and in alphabetical order.  So in your log files, you will find entries related to project starting from A to Z. 

In most environments you will probably find that the requirement for project to be archived is for them to have been completed at least 15, 30 or more days before the Project Cleaner is set to run. This is freely configurable in the Project Cleaner in the setting Number of days project must be complete before deletion. In the example used in this article, the Project Cleaner is configured to remove projects that have been completed at least 1 day ago so please remember this when reading this article.

Also, the examples provided here are related to Project Cleaner working correctly. Possible errors are not described in this know-how article. They will be documented in separate articles. Search the RWS Knowledge Center if you are looking for a specific error or other types of information.

1- This entry states when the Project Cleaner starts to run. Note that in the logs, it is called Completed Project Cleaner.
 
[2020-07-23 08:30:01,054] WARN c.i.w.m.CompletedProjectCleanerGCTask [Completed Project Garbage Collector [2e1ec4f9]] Starting Completed Project Garbage Collection.
[2020-07-23 08:30:01,073] DEBUG c.i.w.m.CompletedProjectCleanerGCTask [Completed Project Garbage Collector [2e1ec4f9]] Calling Garbage Collector: Completed Project Cleaner
[2020-07-23 08:30:01,073] DEBUG c.i.w.m.OldTaskCleaner$2 [Completed Project Garbage Collector [2e1ec4f9]] Task cleaner running
[2020-07-23 08:30:01,086] DEBUG c.i.w.m.OldTaskCleaner [Completed Project Garbage Collector [2e1ec4f9]] Found configuration setting
[2020-07-23 08:30:01,086] DEBUG c.i.w.m.OldTaskCleaner [Completed Project Garbage Collector [2e1ec4f9]] Configuration value: 1
[2020-07-23 08:30:01,086] DEBUG c.i.w.m.OldTaskCleaner [Completed Project Garbage Collector [2e1ec4f9]] Found configuration setting
[2020-07-23 08:30:01,086] DEBUG c.i.w.m.OldTaskCleaner [Completed Project Garbage Collector [2e1ec4f9]] Configuration value: 1
[2020-07-23 08:30:01,086] DEBUG c.i.w.m.OldTaskCleaner$2 [Completed Project Garbage Collector [2e1ec4f9]] Searching through 266 projects
[2020-07-23 08:30:01,101] DEBUG c.i.w.m.OldTaskCleaner [Completed Project Garbage Collector [2e1ec4f9]] Projects completed for 1 day(s) or more will be removed

2- This is an example of an entry in the GC.log or the ws.log file after Maintenance debugging has been enabled that confirms that the Project Cleaner has found a project that fits the requirement for being archived and has archived it successfully. As you can see in the entry, the Project Cleaner always also checks the Task(s) belonging to a project and enters the TaskID ("Processing task #18870"). If a project has more than one Task, there will be a line for each Task and the correspondent TaskId. In the example below, the project has been found to have been completed more than 1 day ago, which means that it fits the requirement for being archived. This is when the entry That's too old... killing it will be written. Without such an entry, the project is not going to be archived:
 
2020-07-23 10:30:01,580] DEBUG c.i.w.m.OldTaskCleaner$1 [Completed Project Garbage Collector [4d75c32b]] This project has 1 tasks
[2020-07-23 10:30:01,580] DEBUG c.i.w.m.OldTaskCleaner$1 [Completed Project Garbage Collector [4d75c32b]] Processing task #18870
[2020-07-23 10:30:01,580] DEBUG c.i.w.m.OldTaskCleaner$1 [Completed Project Garbage Collector [4d75c32b]] Project was completed 1 day(s) ago
[2020-07-23 10:30:01,580] DEBUG c.i.w.m.OldTaskCleaner$1 [Completed Project Garbage Collector [4d75c32b]] That's too old... killing it
[2020-07-23 10:30:01,580] DEBUG c.i.w.m.OldTaskCleaner [Completed Project Garbage Collector [4d75c32b]] Removing project: Test 2 number:4358
[2020-07-23 10:30:01,923] DEBUG c.i.w.m.OldTaskCleaner$1 [Completed Project Garbage Collector [4d75c32b]] Changes for this project committed.

3- You will also find a lot of entries like the one below. It means that the Project Cleaner has found an active project. Although this entry states Changes for this project committed, this change does not really affect the project and it does not mean that the project will be cleaner/archived. It is just a check:
 
"2020-07-23 15:30:03,579] DEBUG c.i.w.m.OldTaskCleaner$1 [Completed Project Garbage Collector [220c87fe]] Checking project Test IDML Vlad 11.5 #3 number: 3580
[2020-07-23 15:30:03,579] DEBUG c.i.w.m.OldTaskCleaner$1 [Completed Project Garbage Collector [220c87fe]] This project has 1 tasks
[2020-07-23 15:30:03,579] DEBUG c.i.w.m.OldTaskCleaner$1 [Completed Project Garbage Collector [220c87fe]] Processing task #9292
[2020-07-23 15:30:03,579] DEBUG c.i.w.m.OldTaskCleaner$1 [Completed Project Garbage Collector [220c87fe]] Changes for this project committed."


4- The entry below means that the Project Cleaner finds a completed or canceled project that is not a candidate for archiving because its completion date is more recent than the parameter set in the Project Cleaner. So also this entry documents a check, but no real change. In this case, since the minimum requirement for archiving is one day. 0 day(s) does not meet that requirement. If your Project Cleaner is set to collect completed or canceled projects with completion date of at least 15 days, you might find other references like "Project was completed 7 day(s) ago" and no entry about it being "too old":
 
[2020-07-24 11:00:01,482] DEBUG c.i.w.m.OldTaskCleaner$1 [Completed Project Garbage Collector [46b09c1f]] Checking project CRQ-9919 number: 4496
[2020-07-24 11:00:01,482] DEBUG c.i.w.m.OldTaskCleaner$1 [Completed Project Garbage Collector [46b09c1f]] This project has 1 tasks
[2020-07-24 11:00:01,482] DEBUG c.i.w.m.OldTaskCleaner$1 [Completed Project Garbage Collector [46b09c1f]] Processing task #18991
[2020-07-24 11:00:01,482] DEBUG c.i.w.m.OldTaskCleaner$1 [Completed Project Garbage Collector [46b09c1f]] Project was completed 0 day(s) ago
[2020-07-24 11:00:01,482] DEBUG c.i.w.m.OldTaskCleaner$1 [Completed Project Garbage Collector [46b09c1f]] Changes for this project committed.

5- Once a Project Cleaner has finished running in general, you should find this entry in the log file (date and time will obviously vary):
 
[2020-07-24 11:30:04,412] INFO c.i.w.m.OldTaskCleaner [Completed Project Garbage Collector [401eedcc]] Successfully removed old project groups.
[2020-07-24 11:30:04,505] WARN c.i.w.m.CompletedProjectCleanerGCTask [Completed Project Garbage Collector [401eedcc]] Completed Project Garbage Collection has completed.  Total time: 2 minutes, 3 seconds.
Reference
As explained in this article, there are two stored procedure running in the background when the Project Cleaner archives a project:
  1. spDeleteProject
  2. spdeleteunusedprojectgroup
These articles are relevant:

WorldServer - how to configure a separate Garbage Collector Log and enable Maintenance logging in general.properties
WorldServer - what happens in the background when Garbage Collection (Project Cleaner) runs and removes a complete or canceled project from the User Interface?
Attachment 1 
Attachment 2 
Attachment 3 
Attachment 4 
Attachment 5 

Powered by