Project

General

Profile

Actions

Bug #7600

closed

mentat-statistician.py - Unable to update RRD database

Added by Rajmund Hruška over 1 year ago. Updated about 1 year ago.

Status:
Closed
Priority:
Normal
Category:
Development - Core
Target version:
Start date:
07/23/2022
Due date:
% Done:

100%

Estimated time:
To be discussed:
No

Description

2022-07-22 15:50:04,750 ERROR: "Unable to update RRD database 'nodename.cz_cesnet_vm_wardentesting' in file '/var/mentat/rrds/nodename.cz_cesnet_vm_wardentesting.rrd' with value '1' and timestamp '1658490600': /var/mentat/rrds/nodename.cz_cesnet_vm_wardentesting.rrd: illegal attempt to update using time 1658490600 when last update time is 1658497500 (minimum one second step)" 
2022-07-22 15:50:04,750 ERROR: "Unable to update RRD database 'nodename._totals' in file '/var/mentat/rrds/nodename._totals.rrd' with value '0' and timestamp '1658490600': /var/mentat/rrds/nodename._totals.rrd: illegal attempt to update using time 1658490600 when last update time is 1658490600 (minimum one second step)" 
2022-07-22 15:50:04,752 ERROR: "Unable to update RRD database 'nodename.cz_avcr_nemea_hoststats' in file '/var/mentat/rrds/nodename.cz_avcr_nemea_hoststats.rrd' with value '0' and timestamp '1658490600': /var/mentat/rrds/nodename.cz_avcr_nemea_hoststats.rrd: illegal attempt to update using time 1658490600 when last update time is 1658490600 (minimum one second step)" 
2022-07-22 15:50:04,753 ERROR: "Unable to update RRD database 'nodename.cz_casablanca_nemea_blacklist' in file '/var/mentat/rrds/nodename.cz_casablanca_nemea_blacklist.rrd' with value '0' and timestamp '1658490600': /var/mentat/rrds/nodename.cz_casablanca_nemea_blacklist.rrd: illegal attempt to update using time 1658490600 when last update time is 1658490600 (minimum one second step)" 
2022-07-22 15:50:04,754 ERROR: "Unable to update RRD database 'nodename.cz_casablanca_nemea_bruteforce' in file '/var/mentat/rrds/nodename.cz_casablanca_nemea_bruteforce.rrd' with value '0' and timestamp '1658490600': /var/mentat/rrds/nodename.cz_casablanca_nemea_bruteforce.rrd: illegal attempt to update using time 1658490600 when last update time is 1658490600 (minimum one second step)" 
2022-07-22 15:50:04,755 ERROR: "Unable to update RRD database 'nodename.cz_casablanca_nemea_hoststats' in file '/var/mentat/rrds/nodename.cz_casablanca_nemea_hoststats.rrd' with value '0' and timestamp '1658490600': /var/mentat/rrds/nodename.cz_casablanca_nemea_hoststats.rrd: illegal attempt to update using time 1658490600 when last update time is 1658490600 (minimum one second step)" 
2022-07-22 15:50:04,756 ERROR: "Unable to update RRD database 'nodename.cz_casablanca_nemea_vportscan' in file '/var/mentat/rrds/nodename.cz_casablanca_nemea_vportscan.rrd' with value '0' and timestamp '1658490600': /var/mentat/rrds/nodename.cz_casablanca_nemea_vportscan.rrd: illegal attempt to update using time 1658490600 when last update time is 1658490600 (minimum one second step)" 
2022-07-22 15:50:04,757 ERROR: "Unable to update RRD database 'nodename.cz_cesnet_collector_nemea_miner_detector_ml' in file '/var/mentat/rrds/nodename.cz_cesnet_collector_nemea_miner_detector_ml.rrd' with value '0' and timestamp '1658490600': /var/mentat/rrds/nodename.cz_cesnet_collector_nemea_miner_detector_ml.rrd: illegal attempt to update using time 1658490600 when last update time is 1658490600 (minimum one second step)" 
2022-07-22 15:50:04,757 ERROR: "Unable to update RRD database 'nodename.cz_cesnet_collector_nemea_ssh_bruteforce_ml' in file '/var/mentat/rrds/nodename.cz_cesnet_collector_nemea_ssh_bruteforce_ml.rrd' with value '0' and timestamp '1658490600': /var/mentat/rrds/nodename.cz_cesnet_collector_nemea_ssh_bruteforce_ml.rrd: illegal attempt to update using time 1658490600 when last update time is 1658490600 (minimum one second step)" 
2022-07-22 15:50:04,771 ERROR: "Unable to update RRD database 'nodename.cz_cesnet_nemea_blacklist' in file '/var/mentat/rrds/nodename.cz_cesnet_nemea_blacklist.rrd' with value '0' and timestamp '1658490600': /var/mentat/rrds/nodename.cz_cesnet_nemea_blacklist.rrd: illegal attempt to update using time 1658490600 when last update time is 1658490600 (minimum one second step)" 
2022-07-22 15:50:04,771 ERROR: "Unable to update RRD database 'nodename.cz_cesnet_nemea_bruteforce' in file '/var/mentat/rrds/nodename.cz_cesnet_nemea_bruteforce.rrd' with value '0' and timestamp '1658490600': /var/mentat/rrds/nodename.cz_cesnet_nemea_bruteforce.rrd: illegal attempt to update using time 1658490600 when last update time is 1658490600 (minimum one second step)" 
2022-07-22 15:50:04,772 ERROR: "Unable to update RRD database 'nodename.cz_cesnet_nemea_hoststats' in file '/var/mentat/rrds/nodename.cz_cesnet_nemea_hoststats.rrd' with value '0' and timestamp '1658490600': /var/mentat/rrds/nodename.cz_cesnet_nemea_hoststats.rrd: illegal attempt to update using time 1658490600 when last update time is 1658490600 (minimum one second step)" 
2022-07-22 15:50:04,780 ERROR: "Unable to update RRD database 'nodename.cz_cesnet_syslog_sshd_block' in file '/var/mentat/rrds/nodename.cz_cesnet_syslog_sshd_block.rrd' with value '0' and timestamp '1658490600': /var/mentat/rrds/nodename.cz_cesnet_syslog_sshd_block.rrd: illegal attempt to update using time 1658490600 when last update time is 1658490600 (minimum one second step)" 
2022-07-22 15:50:04,781 ERROR: "Unable to update RRD database 'nodename.cz_cesnet_tmc_log_analyzer' in file '/var/mentat/rrds/nodename.cz_cesnet_tmc_log_analyzer.rrd' with value '0' and timestamp '1658490600': /var/mentat/rrds/nodename.cz_cesnet_tmc_log_analyzer.rrd: illegal attempt to update using time 1658490600 when last update time is 1658490600 (minimum one second step)" 
2022-07-22 15:50:04,784 ERROR: "Unable to update RRD database 'nodename.cz_cvut_sin_haas1_cowrie' in file '/var/mentat/rrds/nodename.cz_cvut_sin_haas1_cowrie.rrd' with value '0' and timestamp '1658490600': /var/mentat/rrds/nodename.cz_cvut_sin_haas1_cowrie.rrd: illegal attempt to update using time 1658490600 when last update time is 1658490600 (minimum one second step)" 
2022-07-22 15:50:04,793 ERROR: "Unable to update RRD database 'nodename.cz_tul_ward_cowrie' in file '/var/mentat/rrds/nodename.cz_tul_ward_cowrie.rrd' with value '0' and timestamp '1658490600': /var/mentat/rrds/nodename.cz_tul_ward_cowrie.rrd: illegal attempt to update using time 1658490600 when last update time is 1658490600 (minimum one second step)" 

Files

mentat-statistician.py.log (3.74 MB) mentat-statistician.py.log Rajmund Hruška, 07/23/2022 09:39 AM
Actions #1

Updated by Rajmund Hruška over 1 year ago

  • Target version changed from 2.10 to 2.11
Actions #2

Updated by Rajmund Hruška over 1 year ago

  • Status changed from New to Resolved
  • % Done changed from 0 to 100

There was an issue with updating items which didn't appear in the current run of mentat-statistician. Wrong variable was tested, it should be fixed now.

Actions #3

Updated by Rajmund Hruška over 1 year ago

  • Status changed from Resolved to In Review

Merged into devel.

Actions #4

Updated by Rajmund Hruška over 1 year ago

We had a couple of errors such as this on mentat-alt:

2022-09-29 19:35:03,938 ERROR: "Unable to update RRD database 'nodename.cz_cvut_sin_butcher_hugo_dionaea' in file '/var/mentat/rrds/nodename.cz_cvut_sin_butcher_hugo_dionaea.rrd' with value '0' and timestamp '1664465700': /var/mentat/rrds/nodename.cz_cvut_sin_butcher_hugo_dionaea.rrd: illegal attempt to update using time 1664465700 when last update time is 1664466900 (minimum one second step)" 

I am not sure whether this is an issue or not. It's possible that wrong values were stored before the fix and now the right values are written.

Actions #5

Updated by Rajmund Hruška over 1 year ago

  • Status changed from In Review to In Progress
  • % Done changed from 100 to 10
Actions #6

Updated by Rajmund Hruška over 1 year ago

I checked ssl_access.log of mentat-hub. In the last 14 days, someone clicked on /mentat/performance (which uses RRDs) on 21/Nov/2022:14:24:40. There are also two bot accesses (YandexBot/3.0 and DataForSeoBot/1.0) on November 22.

Actions #7

Updated by Rajmund Hruška over 1 year ago

I think I finally know where is the issue.

I noticed that the last time there was an error, the first error message was

2023-01-08 23:35:04,987 ERROR: "Unable to update RRD database 'category.Attemt_Exploit' in file '/var/mentat/rrds/category.Attemt_Exploit.rrd' with value '1' and timestamp '1673213700': /var/mentat/rrds/category.Attemt_Exploit.rrd: illegal attempt to update using time 1673213700 when last update time is 1673217000 (minimum one second step)" 

When I checked the log, I couldn't find category.Attemt_Exploit before this error. Today I noticed that there is a typo which made me realize that I couldn't find category.Attemt_Exploit because it didn't exist before!

So the issue is that when the new RRD database file is created, the current time is used as the default value. (In fact, it's current time minus 5 minutes that's why the log says 23:35 but timestamp is 1673217000 which is 23:30.) But statistician is processing events which are 1 hour older.

Actions #8

Updated by Rajmund Hruška over 1 year ago

  • Status changed from In Progress to Resolved
  • % Done changed from 10 to 100

Should be finally fixed in b33b4b6f.

Actions #9

Updated by Rajmund Hruška over 1 year ago

  • Status changed from Resolved to In Review

Merged into devel and deployed on mentat-alt.

Actions #10

Updated by Rajmund Hruška over 1 year ago

Today, there was this error from mentat-hub:

2023-01-17 12:35:05,482 ERROR: "Unable to update RRD database 'nodename.cz_cesnet_auror_scanner' in file '/var/mentat/rrds/nodename.cz_cesnet_auror_scanner.rrd' with value '1312' and timestamp '1673951700': /var/mentat/rrds/nodename.cz_cesnet_auror_scanner.rrd: illegal attempt to update using time 1673951700 when last update time is 1673955000 (minimum one second step)" 

But there is no error from mentat-alt, so it seems that the issue is indeed solved.

Actions #11

Updated by Rajmund Hruška about 1 year ago

  • Status changed from In Review to Closed
Actions

Also available in: Atom PDF