[JENKINS-65118] Support Plugin fails to include the agent logs due to `FileNotFoundException` in the cache

In rare occasion, the Support Plugin is pruning agent item from a cache (in one thread) and after that another thread shows an exception that it cannot retrieve the log file for the cached entry that was just deleted:

2021-02-07 04:58:14.623+0000 [id=25855]	INFO	c.c.j.s.impl.SmartLogCleaner$2#run: The agent is no longer available, cache entry /var/jenkins_home/support/winsw/9e19c509 was deleted

2021-02-07 04:58:14.628+0000 [id=25853]	WARNING	c.c.j.support.impl.SlaveLogs#addContents: Could not retrieve some of the remote node extra logs

java.io.FileNotFoundException: /var/jenkins_home/support/cache/9e19c509/all_2020-12-08_20.40.00.log (No such file or directory)

	at java.io.FileInputStream.open0(Native Method)

	at java.io.FileInputStream.open(FileInputStream.java:195)

	at java.io.FileInputStream.(FileInputStream.java:138)

	at com.cloudbees.jenkins.support.impl.SmartLogFetcher$FileHash.(SmartLogFetcher.java:155)

	at com.cloudbees.jenkins.support.impl.SmartLogFetcher$ForNode.getLogFiles(SmartLogFetcher.java:92)

	at com.cloudbees.jenkins.support.impl.SlaveLogs$2.call(SlaveLogs.java:168)

	at com.cloudbees.jenkins.support.impl.SlaveLogs$2.call(SlaveLogs.java:163)

	at jenkins.util.ContextResettingExecutorService$2.call(ContextResettingExecutorService.java:46)

	at jenkins.security.ImpersonatingExecutorService$2.call(ImpersonatingExecutorService.java:71)

	at java.util.concurrent.FutureTask.run(FutureTask.java:266)

	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)

	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)

Caused: java.util.concurrent.ExecutionException

	at java.util.concurrent.FutureTask.report(FutureTask.java:122)

	at java.util.concurrent.FutureTask.get(FutureTask.java:206)

	at com.cloudbees.jenkins.support.impl.SlaveLogs.addContents(SlaveLogs.java:136)

	at com.cloudbees.jenkins.support.SupportPlugin$1.visit(SupportPlugin.java:301)

	at com.cloudbees.jenkins.support.SupportPlugin.appendManifestContents(SupportPlugin.java:488)

	at com.cloudbees.jenkins.support.SupportPlugin.writeBundle(SupportPlugin.java:325)

	at com.cloudbees.jenkins.support.SupportPlugin.writeBundle(SupportPlugin.java:298)

	at com.cloudbees.jenkins.support.SupportPlugin.writeBundle(SupportPlugin.java:294)

	at com.cloudbees.jenkins.support.SupportPlugin$PeriodicWorkImpl.lambda$doRun$0(SupportPlugin.java:858)

	at java.lang.Thread.run(Thread.java:748)

Both thread should work on the same view of nodes.

From duemir:

Maybe it is not a cleanup thread that deletes them but there is a cache key collision so one logs retrieval thread is pruning log files that it thinks no longer need while other thread is trying to read them.

The collision can happen since the cache key is just 8 last characters of MD5.

---
Originally reported by allan_burdajewicz, imported from: Support Plugin fails to include the agent logs due to `FileNotFoundException` in the cache

• status: Open
  
• priority: Minor
  
• component(s): support-core-plugin
  
• resolution: Unresolved
  
• votes: 0
  
• watchers: 2
  
• imported: 20251212-090250
  

Raw content of original issue

In rare occasion, the Support Plugin is pruning agent item from a cache (in one thread) and after that another thread shows an exception that it cannot retrieve the log file for the cached entry that was just deleted:




2021-02-07 04:58:14.623+0000 [id=25855]	INFO	c.c.j.s.impl.SmartLogCleaner$2#run: The agent is no longer available, cache entry /var/jenkins_home/support/winsw/9e19c509 was deleted

2021-02-07 04:58:14.628+0000 [id=25853]	WARNING	c.c.j.support.impl.SlaveLogs#addContents: Could not retrieve some of the remote node extra logs

java.io.FileNotFoundException: /var/jenkins_home/support/cache/9e19c509/all_2020-12-08_20.40.00.log (No such file or directory)

	at java.io.FileInputStream.open0(Native Method)

	at java.io.FileInputStream.open(FileInputStream.java:195)

	at java.io.FileInputStream.<init>(FileInputStream.java:138)

	at com.cloudbees.jenkins.support.impl.SmartLogFetcher$FileHash.<init>(SmartLogFetcher.java:155)

	at com.cloudbees.jenkins.support.impl.SmartLogFetcher$ForNode.getLogFiles(SmartLogFetcher.java:92)

	at com.cloudbees.jenkins.support.impl.SlaveLogs$2.call(SlaveLogs.java:168)

	at com.cloudbees.jenkins.support.impl.SlaveLogs$2.call(SlaveLogs.java:163)

	at jenkins.util.ContextResettingExecutorService$2.call(ContextResettingExecutorService.java:46)

	at jenkins.security.ImpersonatingExecutorService$2.call(ImpersonatingExecutorService.java:71)

	at java.util.concurrent.FutureTask.run(FutureTask.java:266)

	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)

	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)

Caused: java.util.concurrent.ExecutionException

	at java.util.concurrent.FutureTask.report(FutureTask.java:122)

	at java.util.concurrent.FutureTask.get(FutureTask.java:206)

	at com.cloudbees.jenkins.support.impl.SlaveLogs.addContents(SlaveLogs.java:136)

	at com.cloudbees.jenkins.support.SupportPlugin$1.visit(SupportPlugin.java:301)

	at com.cloudbees.jenkins.support.SupportPlugin.appendManifestContents(SupportPlugin.java:488)

	at com.cloudbees.jenkins.support.SupportPlugin.writeBundle(SupportPlugin.java:325)

	at com.cloudbees.jenkins.support.SupportPlugin.writeBundle(SupportPlugin.java:298)

	at com.cloudbees.jenkins.support.SupportPlugin.writeBundle(SupportPlugin.java:294)

	at com.cloudbees.jenkins.support.SupportPlugin$PeriodicWorkImpl.lambda$doRun$0(SupportPlugin.java:858)

	at java.lang.Thread.run(Thread.java:748)





Both thread should work on the same view of nodes. 


From duemir:


Maybe it is not a cleanup thread that deletes them but there is a cache key collision so one logs retrieval thread is pruning log files that it thinks no longer need while other thread is trying to read them.

The collision can happen since the cache key is just 8 last characters of MD5.