ScheduledExecutorService在1分鐘的計劃中滑倒10分鐘（systemd - journald fault）

Question

我有一個應執行器服務，應該每分鐘將一些事情寫入磁盤。

它計劃是這樣的：

scheduledCacheDump = new ScheduledThreadPoolExecutor(1); 
    scheduledCacheDump.scheduleAtFixedRate(this::saveCachedRecords, 
              60, 
              60, 
              TimeUnit.SECONDS 
    ); 

任務會使用由主線程填充共享列表，所以它是名單上的同步：

private void saveCachedRecords() { 
     LOG.info(String.format("Scheduled record dump to disk. We have %d records to save.", recordCache.size())); 
     synchronized (recordCache) { 
      Iterator<Record> iterator = recordCache.iterator(); 
      while (iterator.hasNext()) { 
       // save record to disk 
       iterator.remove(); 
      } 
     } 
    } 

我的名單宣佈因此：

private final List<Record> recordCache = new ArrayList<>(); 

主線程按批次接收數據，所以每隔一秒左右，它會收到30個r它將它緩存在列表中。剩下的時間在插座上等待。

什麼我不明白的是，從日誌中，我的計劃任務往往與方式更觸發1分鐘之間：看

sept. 16 09:30:43 Scheduled record dump to disk. We have 27 records to save. sept. 16 09:31:43 Scheduled record dump to disk. We have 27 records to save. sept. 16 09:32:43 Scheduled record dump to disk. We have 27 records to save. sept. 16 09:33:43 Scheduled record dump to disk. We have 27 records to save. sept. 16 09:34:43 Scheduled record dump to disk. We have 27 records to save. sept. 16 09:35:43 Scheduled record dump to disk. We have 27 records to save. sept. 16 09:42:43 Scheduled record dump to disk. We have 27 records to save. sept. 16 09:43:43 Scheduled record dump to disk. We have 27 records to save. sept. 16 09:44:43 Scheduled record dump to disk. We have 27 records to save. sept. 16 09:45:43 Scheduled record dump to disk. We have 27 records to save. sept. 16 09:46:43 Scheduled record dump to disk. We have 27 records to save. sept. 16 09:55:43 Scheduled record dump to disk. We have 27 records to save. sept. 16 09:56:43 Scheduled record dump to disk. We have 27 records to save. sept. 16 09:57:43 Scheduled record dump to disk. We have 27 records to save. sept. 16 09:58:43 Scheduled record dump to disk. We have 27 records to save. sept. 16 09:59:43 Scheduled record dump to disk. We have 27 records to save. sept. 16 10:04:43 Scheduled record dump to disk. We have 27 records to save. sept. 16 10:05:43 Scheduled record dump to disk. We have 27 records to save. sept. 16 10:06:43 Scheduled record dump to disk. We have 27 records to save.

在此：

• sept。 16 09:59:43計劃記錄轉儲到磁盤。我們有27條記錄要保存。
• sept。 16 10:04:43計劃記錄轉儲到磁盤。我們有27條記錄要保存。

=>5分鐘

甚至：

• 九月16 09:46:43計劃記錄轉儲到磁盤。我們有27條記錄要保存。
• sept。 16 09:55:43計劃記錄轉儲到磁盤。我們有27條記錄要保存。

=>9分鐘

我的日誌是在synchronized()範圍，所以我不知道如果任務實際調度在時間和鎖等待10分鐘，或者如果它僅僅是一個真正的調度問題。我將把它移出它，但通常我無法理解一個線程可以在每秒鐘釋放的鎖上停留10分鐘。

我該如何調查？

有關信息：它運行的機器是KVM機器，這可能是一個因素嗎？

Answer 1

Oh my ..

這根本不是Java的錯。這是systemd的錯。

我的進程作爲systemd服務運行，所以我從systemd-journald中取得的日誌。 並猜測systemd中有什麼限制。而我的守護進程會擊中它的調度被觸發時，所以我想這樣的行PLENTY：

Suppressed 570 messages from /system.slice/xxx.service Suppressed 769 messages from /system.slice/xxx.service Suppressed 745 messages from /system.slice/xxx.service Suppressed 729 messages from /system.slice/xxx.service Suppressed 717 messages from /system.slice/xxx.service Suppressed 95 messages from /system.slice/xxx.service Suppressed 543 messages from /system.slice/xxx.service

所以..是啊，我取消了對journald節流，我現在每分鐘有我的痕跡。

的解決方案是：

• 編輯/etc/systemd/journald.conf
• 添加一行：RateLimitInterval=0末
• 執行systemctl restart systemd-journald
• 執行systemctl restart myservice

現在我所有的事情進展順利。

我會更新標題以備將來參考:)