ntop / ntopng

Web-based Traffic and Security Network Traffic Monitoring
http://www.ntop.org
GNU General Public License v3.0
6.16k stars 648 forks source link

Errors logged: "attempt to index a nil value (local 'schema')" #8609

Closed rreiner closed 1 week ago

rreiner commented 1 month ago

Environment:

What happened: Receiving these log messages:


[25/06/2024 21:12:00]  [System] [System Error] [system]  System error detected in ntopng, please report it. Error message: ...re/ntopng/scripts/lua/modules/timeseries/drivers/rrd.lua:102: attempt to index a nil value (local 'schema')
[25/06/2024 21:12:00]  [System] [System Error] [system]  System error detected in ntopng, please report it. Error message: ...re/ntopng/scripts/lua/modules/timeseries/drivers/rrd.lua:102: attempt to index a nil value (local 'schema')
[25/06/2024 21:12:00]  [System] [System Error] [system]  System error detected in ntopng, please report it. Error message: ...re/ntopng/scripts/lua/modules/timeseries/drivers/rrd.lua:102: attempt to index a nil value (local 'schema')
[25/06/2024 21:12:00]  [System] [System Error] [system]  System error detected in ntopng, please report it. Error message: ...re/ntopng/scripts/lua/modules/timeseries/drivers/rrd.lua:102: attempt to index a nil value (local 'schema')
[25/06/2024 21:12:00]  [System] [System Error] [system]  System error detected in ntopng, please report it. Error message: ...re/ntopng/scripts/lua/modules/timeseries/drivers/rrd.lua:102: attempt to index a nil value (local 'schema')
[01/07/2024 21:15:01]  [System] [System Error] [system]  System error detected in ntopng, please report it. Error message: ...re/ntopng/scripts/lua/modules/timeseries/drivers/rrd.lua:102: attempt to index a nil value (local 'schema')
[01/07/2024 21:15:01]  [System] [System Error] [system]  System error detected in ntopng, please report it. Error message: ...re/ntopng/scripts/lua/modules/timeseries/drivers/rrd.lua:102: attempt to index a nil value (local 'schema')
[01/07/2024 21:15:01]  [System] [System Error] [system]  System error detected in ntopng, please report it. Error message: ...re/ntopng/scripts/lua/modules/timeseries/drivers/rrd.lua:102: attempt to index a nil value (local 'schema')
[01/07/2024 21:15:01]  [System] [System Error] [system]  System error detected in ntopng, please report it. Error message: ...re/ntopng/scripts/lua/modules/timeseries/drivers/rrd.lua:102: attempt to index a nil value (local 'schema')
[01/07/2024 21:15:00]  [System] [System Error] [system]  System error detected in ntopng, please report it. Error message: ...re/ntopng/scripts/lua/modules/timeseries/drivers/rrd.lua:102: attempt to index a nil value (local 'schema')

How did you reproduce it? Running normally.

Debug Information:

● ntopng.service - ntopng high-speed web-based traffic monitoring and analysis tool
     Loaded: loaded (/etc/systemd/system/ntopng.service; enabled; preset: enabled)
     Active: active (running) since Tue 2024-08-06 22:26:54 EDT; 10h ago
    Process: 359823 ExecStartPre=/bin/sh -c /usr/bin/ntopng-utils-manage-config -a check-restore  && /usr/bin/ntopng-utils-manage-config -a restore || true (code=exited, status=0/SUCCESS)
    Process: 359844 ExecStartPre=/bin/sh -c /bin/cat /etc/ntopng/ntopng.conf > /run/ntopng.conf.raw (code=exited, status=0/SUCCESS)
    Process: 359846 ExecStartPre=/bin/sh -c /bin/cat /etc/ntopng/ntopng.conf.d/*.conf >> /run/ntopng.conf.raw 2>/dev/null || true (code=exited, status=0/SUCCESS)
    Process: 359848 ExecStartPre=/bin/sh -c /bin/sed "/^[ ]*-e.*$\|^[ ]*-G.*\|^[ ]*--daemon.*\|[ ]*--pid.*/s/^/#/" /run/ntopng.conf.raw > /run/ntopng.conf (code=exited, status=0/SUCCESS)
   Main PID: 359850 (ntopng-main)
      Tasks: 31 (limit: 1576)
        CPU: 1h 24min 13.708s
     CGroup: /system.slice/ntopng.service
             └─359850 /usr/bin/ntopng /run/ntopng.conf

Aug 07 09:16:08 pinkeye ntopng[359850]: INSERT INTO flow_alerts (alert_id, alert_status, alert_category, interface_id, tstamp, tstamp_end, severity, ip_version, cli_ip, srv_ip, cli_port, srv_port, vlan_id, is_cli_attacker, is_cli_victim, is_srv_attacker, is_srv_victim, proto, l7_proto, l7_master_proto, l7_cat, cli_name, srv_name, cli_country, srv_country, cli_blacklisted, srv_blacklisted, cli_location, srv_location, cli2srv_bytes, srv2cli_bytes, cli2srv_pkts, srv2cli_pkts, first_seen, community_id, score, flow_risk_bitmap, alerts_map, cli_host_pool_id, srv_host_pool_id, cli_network, srv_network, probe_ip, input_snmp, output_snmp, json, info) VALUES (88, 1, 3, 3, 1723036564, 1723036566, 3, 4, '10.248.0.100', '10.248.0.5', 16545, 3000, 0, 0, 0, 0, 0, 6, 26, 7, 5, 'whiplash', 'pinkeye', '', '', 0, 0, 1, 1, 767, 1296, 5, 5, 1723036564, '1:t1lUMoY9iEe4GOq0vIK9fbeAQ7A=', 10, 281474976710656, X'010000000000000000000000', 0, 0, 0, 0, '0.0.0.0', 0, 0, '{"ntopng.key":368138682,"hash_entry_id":50409142,"alert_generation": {"script_key":"ndpi_periodic_flow","subdir":"flow"},"proto": {"http": {"last_method":"GET","last_return_code":200,"last_url":"pinkeye:3000\/lua\/rest\/v2\/get\/interface\/top\/hosts.lua?ifid=3&epoch_begin=1723036264&epoch_end=1723036564&new_charts=true","last_user_agent":"Mozilla\/5.0 (Windows NT 10.0; Win64; x64; rv:129.0) Gecko\/20100101 Firefox\/129.0","last_server":"ntopng 6.1.240807 [Debian GNU\/Linux 12 (bookworm) [aarch64]]","server_name":"pinkeye"},"confidence":1},"traffic_stats": {},"alert_score": {"88":10}}', 'pinkeye:3000/lua/rest/v2/get/interface/top/hosts.lua?ifid=3&epoch_begin=1723036264&epoch_end=1723036564&new_charts=true');
Aug 07 09:16:08 pinkeye ntopng[359850]: 07/Aug/2024 09:16:08 [SQLiteAlertStore.cpp:162] ERROR: SQL Error: database disk image is malformed
                                        INSERT INTO flow_alerts (alert_id, alert_status, alert_category, interface_id, tstamp, tstamp_end, severity, ip_version, cli_ip, srv_ip, cli_port, srv_port, vlan_id, is_cli_attacker, is_cli_victim, is_srv_attacker, is_srv_victim, proto, l7_proto, l7_master_proto, l7_cat, cli_name, srv_name, cli_country, srv_country, cli_blacklisted, srv_blacklisted, cli_location, srv_location, cli2srv_bytes, srv2cli_bytes, cli2srv_pkts, srv2cli_pkts, first_seen, community_id, score, flow_risk_bitmap, alerts_map, cli_host_pool_id, srv_host_pool_id, cli_network, srv_network, probe_ip, input_snmp, output_snmp, json, info) VALUES (88, 1, 3, 3, 1723036564, 1723036566, 3, 4, '10.248.0.100', '10.248.0.5', 16546, 3000, 0, 0, 0, 0, 0, 6, 26, 7, 5, 'whiplash', 'pinkeye', '', '', 0, 0, 1, 1, 798, 1235, 5, 5, 1723036564, '1:ecFjaWVAjsJ/KHzvEOSBvt2mFhY=', 10, 281474976710656, X'010000000000000000000000', 0, 0, 0, 0, '0.0.0.0', 0, 0, '{"ntopng.key":368138938,"hash_entry_id":50409143,"alert_generation": {"script_key":"ndpi_periodic_flow","subdir":"flow"},"proto": {"http": {"last_method":"GET","last_return_code":200,"last_url":"pinkeye:3000\/lua\/rest\/v2\/get\/interface\/l7\/stats.lua?ifid=3&epoch_begin=1723036264&epoch_end=1723036564&new_charts=true&breed=true&ndpistats_mode=count","last_user_agent":"Mozilla\/5.0 (Windows NT 10.0; Win64; x64; rv:129.0) Gecko\/20100101 Firefox\/129.0","last_server":"ntopng 6.1.240807 [Debian GNU\/Linux 12 (bookworm) [aarch64]]","server_name":"pinkeye"},"confidence":1},"traffic_stats": {},"alert_score": {"88":10}}', 'pinkeye:3000/lua/rest/v2/get/interface/l7/stats.lua?ifid=3&epoch_begin=1723036264&epoch_end=1723036564&new_charts=true&breed=true&ndpistats_mode=count');
Aug 07 09:16:08 pinkeye ntopng[359850]: 07/Aug/2024 09:16:08 [SQLiteAlertStore.cpp:162] ERROR: SQL Error: database disk image is malformed
Aug 07 09:16:08 pinkeye ntopng[359850]: INSERT INTO flow_alerts (alert_id, alert_status, alert_category, interface_id, tstamp, tstamp_end, severity, ip_version, cli_ip, srv_ip, cli_port, srv_port, vlan_id, is_cli_attacker, is_cli_victim, is_srv_attacker, is_srv_victim, proto, l7_proto, l7_master_proto, l7_cat, cli_name, srv_name, cli_country, srv_country, cli_blacklisted, srv_blacklisted, cli_location, srv_location, cli2srv_bytes, srv2cli_bytes, cli2srv_pkts, srv2cli_pkts, first_seen, community_id, score, flow_risk_bitmap, alerts_map, cli_host_pool_id, srv_host_pool_id, cli_network, srv_network, probe_ip, input_snmp, output_snmp, json, info) VALUES (88, 1, 3, 3, 1723036564, 1723036566, 3, 4, '10.248.0.100', '10.248.0.5', 16546, 3000, 0, 0, 0, 0, 0, 6, 26, 7, 5, 'whiplash', 'pinkeye', '', '', 0, 0, 1, 1, 798, 1235, 5, 5, 1723036564, '1:ecFjaWVAjsJ/KHzvEOSBvt2mFhY=', 10, 281474976710656, X'010000000000000000000000', 0, 0, 0, 0, '0.0.0.0', 0, 0, '{"ntopng.key":368138938,"hash_entry_id":50409143,"alert_generation": {"script_key":"ndpi_periodic_flow","subdir":"flow"},"proto": {"http": {"last_method":"GET","last_return_code":200,"last_url":"pinkeye:3000\/lua\/rest\/v2\/get\/interface\/l7\/stats.lua?ifid=3&epoch_begin=1723036264&epoch_end=1723036564&new_charts=true&breed=true&ndpistats_mode=count","last_user_agent":"Mozilla\/5.0 (Windows NT 10.0; Win64; x64; rv:129.0) Gecko\/20100101 Firefox\/129.0","last_server":"ntopng 6.1.240807 [Debian GNU\/Linux 12 (bookworm) [aarch64]]","server_name":"pinkeye"},"confidence":1},"traffic_stats": {},"alert_score": {"88":10}}', 'pinkeye:3000/lua/rest/v2/get/interface/l7/stats.lua?ifid=3&epoch_begin=1723036264&epoch_end=1723036564&new_charts=true&breed=true&ndpistats_mode=count');
Aug 07 09:16:08 pinkeye ntopng[359850]: 07/Aug/2024 09:16:08 [SQLiteAlertStore.cpp:162] ERROR: SQL Error: database disk image is malformed
                                        INSERT INTO flow_alerts (alert_id, alert_status, alert_category, interface_id, tstamp, tstamp_end, severity, ip_version, cli_ip, srv_ip, cli_port, srv_port, vlan_id, is_cli_attacker, is_cli_victim, is_srv_attacker, is_srv_victim, proto, l7_proto, l7_master_proto, l7_cat, cli_name, srv_name, cli_country, srv_country, cli_blacklisted, srv_blacklisted, cli_location, srv_location, cli2srv_bytes, srv2cli_bytes, cli2srv_pkts, srv2cli_pkts, first_seen, community_id, score, flow_risk_bitmap, alerts_map, cli_host_pool_id, srv_host_pool_id, cli_network, srv_network, probe_ip, input_snmp, output_snmp, json, info) VALUES (88, 1, 3, 3, 1723036564, 1723036566, 3, 4, '10.248.0.100', '10.248.0.5', 16547, 3000, 0, 0, 0, 0, 0, 6, 26, 7, 5, 'whiplash', 'pinkeye', '', '', 0, 0, 1, 1, 805, 1208, 5, 5, 1723036564, '1:/Uqko0aeGujaUYzw/OSMa792cB8=', 10, 281474976710656, X'010000000000000000000000', 0, 0, 0, 0, '0.0.0.0', 0, 0, '{"ntopng.key":368139194,"hash_entry_id":50409144,"alert_generation": {"script_key":"ndpi_periodic_flow","subdir":"flow"},"proto": {"http": {"last_method":"GET","last_return_code":200,"last_url":"pinkeye:3000\/lua\/rest\/v2\/get\/interface\/l7\/stats.lua?ifid=3&epoch_begin=1723036264&epoch_end=1723036564&new_charts=true&breed=true&ndpistats_mode=sinceStartup","last_user_agent":"Mozilla\/5.0 (Windows NT 10.0; Win64; x64; rv:129.0) Gecko\/20100101 Firefox\/129.0","last_server":"ntopng 6.1.240807 [Debian GNU\/Linux 12 (bookworm) [aarch64]]","server_name":"pinkeye"},"confidence":1},"traffic_stats": {},"alert_score": {"88":10}}', 'pinkeye:3000/lua/rest/v2/get/interface/l7/stats.lua?ifid=3&epoch_begin=1723036264&epoch_end=1723036564&new_charts=true&breed=true&ndpistats_mode=sinceStartup');
Aug 07 09:16:08 pinkeye ntopng[359850]: 07/Aug/2024 09:16:08 [SQLiteAlertStore.cpp:162] ERROR: SQL Error: database disk image is malformed
Aug 07 09:16:08 pinkeye ntopng[359850]: INSERT INTO flow_alerts (alert_id, alert_status, alert_category, interface_id, tstamp, tstamp_end, severity, ip_version, cli_ip, srv_ip, cli_port, srv_port, vlan_id, is_cli_attacker, is_cli_victim, is_srv_attacker, is_srv_victim, proto, l7_proto, l7_master_proto, l7_cat, cli_name, srv_name, cli_country, srv_country, cli_blacklisted, srv_blacklisted, cli_location, srv_location, cli2srv_bytes, srv2cli_bytes, cli2srv_pkts, srv2cli_pkts, first_seen, community_id, score, flow_risk_bitmap, alerts_map, cli_host_pool_id, srv_host_pool_id, cli_network, srv_network, probe_ip, input_snmp, output_snmp, json, info) VALUES (88, 1, 3, 3, 1723036564, 1723036566, 3, 4, '10.248.0.100', '10.248.0.5', 16547, 3000, 0, 0, 0, 0, 0, 6, 26, 7, 5, 'whiplash', 'pinkeye', '', '', 0, 0, 1, 1, 805, 1208, 5, 5, 1723036564, '1:/Uqko0aeGujaUYzw/OSMa792cB8=', 10, 281474976710656, X'010000000000000000000000', 0, 0, 0, 0, '0.0.0.0', 0, 0, '{"ntopng.key":368139194,"hash_entry_id":50409144,"alert_generation": {"script_key":"ndpi_periodic_flow","subdir":"flow"},"proto": {"http": {"last_method":"GET","last_return_code":200,"last_url":"pinkeye:3000\/lua\/rest\/v2\/get\/interface\/l7\/stats.lua?ifid=3&epoch_begin=1723036264&epoch_end=1723036564&new_charts=true&breed=true&ndpistats_mode=sinceStartup","last_user_agent":"Mozilla\/5.0 (Windows NT 10.0; Win64; x64; rv:129.0) Gecko\/20100101 Firefox\/129.0","last_server":"ntopng 6.1.240807 [Debian GNU\/Linux 12 (bookworm) [aarch64]]","server_name":"pinkeye"},"confidence":1},"traffic_stats": {},"alert_score": {"88":10}}', 'pinkeye:3000/lua/rest/v2/get/interface/l7/stats.lua?ifid=3&epoch_begin=1723036264&epoch_end=1723036564&new_charts=true&breed=true&ndpistats_mode=sinceStartup');
Aug 07 09:16:08 pinkeye ntopng[359850]: 07/Aug/2024 09:16:08 [SQLiteAlertStore.cpp:162] ERROR: SQL Error: database disk image is malformed
                                        INSERT INTO flow_alerts (alert_id, alert_status, alert_category, interface_id, tstamp, tstamp_end, severity, ip_version, cli_ip, srv_ip, cli_port, srv_port, vlan_id, is_cli_attacker, is_cli_victim, is_srv_attacker, is_srv_victim, proto, l7_proto, l7_master_proto, l7_cat, cli_name, srv_name, cli_country, srv_country, cli_blacklisted, srv_blacklisted, cli_location, srv_location, cli2srv_bytes, srv2cli_bytes, cli2srv_pkts, srv2cli_pkts, first_seen, community_id, score, flow_risk_bitmap, alerts_map, cli_host_pool_id, srv_host_pool_id, cli_network, srv_network, probe_ip, input_snmp, output_snmp, json, info) VALUES (101, 1, 1, 3, 1723036561, 1723036568, 4, 4, '10.248.0.242', '54.212.7.120', 60894, 443, 0, 0, 0, 0, 0, 6, 91, 0, 5, 'WYZEC1-JZ-2CAA8E206496', 'ec2-54-212-7-120.us-west-2.compute.amazonaws.com', '', 'US', 0, 0, 1, 0, 272, 140, 4, 2, 1723036561, '1:m3T6GSjEvDvjh7xms700kgL7QVk=', 50, 36028797018963968, X'20000000000000000000000000', 0, 0, 0, 65535, '0.0.0.0', 0, 0, '{"ntopng.key":1103995486,"hash_entry_id":50409137,"alert_generation": {"script_key":"ndpi_probing_attempt","subdir":"flow","flow_risk_info":"{\"55\":\"TCP connection with unidirectional traffic\"}"},"proto": {"tls": {"tls_version":0,"client_requested_server_name":""},"confidence":0},"traffic_stats": {},"alert_score": {"101":50},"risk_id":55}', '');
Aug 07 09:16:08 pinkeye ntopng[359850]: 07/Aug/2024 09:16:08 [SQLiteAlertStore.cpp:162] ERROR: SQL Error: database disk image is malformed
Aug 07 09:16:08 pinkeye ntopng[359850]: INSERT INTO flow_alerts (alert_id, alert_status, alert_category, interface_id, tstamp, tstamp_end, severity, ip_version, cli_ip, srv_ip, cli_port, srv_port, vlan_id, is_cli_attacker, is_cli_victim, is_srv_attacker, is_srv_victim, proto, l7_proto, l7_master_proto, l7_cat, cli_name, srv_name, cli_country, srv_country, cli_blacklisted, srv_blacklisted, cli_location, srv_location, cli2srv_bytes, srv2cli_bytes, cli2srv_pkts, srv2cli_pkts, first_seen, community_id, score, flow_risk_bitmap, alerts_map, cli_host_pool_id, srv_host_pool_id, cli_network, srv_network, probe_ip, input_snmp, output_snmp, json, info) VALUES (101, 1, 1, 3, 1723036561, 1723036568, 4, 4, '10.248.0.242', '54.212.7.120', 60894, 443, 0, 0, 0, 0, 0, 6, 91, 0, 5, 'WYZEC1-JZ-2CAA8E206496', 'ec2-54-212-7-120.us-west-2.compute.amazonaws.com', '', 'US', 0, 0, 1, 0, 272, 140, 4, 2, 1723036561, '1:m3T6GSjEvDvjh7xms700kgL7QVk=', 50, 36028797018963968, X'20000000000000000000000000', 0, 0, 0, 65535, '0.0.0.0', 0, 0, '{"ntopng.key":1103995486,"hash_entry_id":50409137,"alert_generation": {"script_key":"ndpi_probing_attempt","subdir":"flow","flow_risk_info":"{\"55\":\"TCP connection with unidirectional traffic\"}"},"proto": {"tls": {"tls_version":0,"client_requested_server_name":""},"confidence":0},"traffic_stats": {},"alert_score": {"101":50},"risk_id":55}', '');
MatteoBiscosi commented 1 month ago

Hi @rreiner this is not an issue related to ntopng; the error: ERROR: SQL Error: database disk image is malformed means that the database is corrupted. What you can try to do (at least to keep some data) is: cd /var/lib/ntopng/ Here you should find some directories, one per interface, go to each directories and in there you should find a folder called: alerts; e.g. cd /var/lib/ntopng/1/alerts Here you can find the files used for DBs (e.g. alert_store_v11.db). You can try to recover as much data as possible by running: sqlite3 alert_store_v11.db ".recover" | sqlite3 new.db After that rename again the new.db into alert_store_v11.db (the recover command should try to keep the uncorrupted files)

Regarding the first issue i added a couple of traces because i'm not able to understand where it failed from those traces. i'll run new builds and a new update should be available for tomorrow, if you can update and let me know.