Hi Paolo, > The issue is persistent across reloads, correct?
Correct. And since the other aggregates seem to work normal I hope that this time the hardware is not the reason ;) > Enable debug only for the plugin, ie. "debug[TMPflowSRC]: true", > then check the log file to see if the problem is somehow with > the database. Here are the results: Apr 8 21:25:17 traffic pmacctd[15489]: INFO ( default/core ): Start logging ... Apr 8 21:25:17 traffic pmacctd[15489]: INFO ( inbound/mysql ): plugin_pipe_size=40960000 bytes plugin_buffer_size=163840 bytes Apr 8 21:25:17 traffic pmacctd[15489]: INFO ( inbound/mysql ): ctrl channel: obtained=212992 bytes target=2000 bytes Apr 8 21:25:17 traffic pmacctd[15489]: INFO ( outbound/mysql ): plugin_pipe_size=40960000 bytes plugin_buffer_size=163840 bytes Apr 8 21:25:17 traffic pmacctd[15489]: INFO ( outbound/mysql ): ctrl channel: obtained=212992 bytes target=2000 bytes Apr 8 21:25:17 traffic pmacctd[15489]: INFO ( TMPflowSRC/mysql ): plugin_pipe_size=40960000 bytes plugin_buffer_size=163840 bytes Apr 8 21:25:17 traffic pmacctd[15489]: INFO ( TMPflowSRC/mysql ): ctrl channel: obtained=212992 bytes target=2000 bytes Apr 8 21:25:17 traffic pmacctd[15489]: INFO ( TMPflowDST/mysql ): plugin_pipe_size=40960000 bytes plugin_buffer_size=163840 bytes Apr 8 21:25:17 traffic pmacctd[15489]: INFO ( TMPflowDST/mysql ): ctrl channel: obtained=212992 bytes target=2000 bytes Apr 8 21:25:17 traffic pmacctd[15492]: DEBUG ( /etc/pmacct/networks ): [networks table IPv4] nh: peer asn: 0 asn: 0 net: xxx.yyy.64.0 mask: 20 Apr 8 21:25:17 traffic pmacctd[15492]: DEBUG ( /etc/pmacct/networks ): [networks table IPv4] nh: peer asn: 0 asn: 0 net: xxx.yyy.48.0 mask: 20 Apr 8 21:25:17 traffic pmacctd[15492]: DEBUG ( /etc/pmacct/networks ): [networks table IPv4] nh: peer asn: 0 asn: 0 net: xxx.yyy.164.0 mask: 24 Apr 8 21:25:17 traffic pmacctd[15492]: DEBUG ( /etc/pmacct/networks ): [networks table IPv4] nh: peer asn: 0 asn: 0 net: xxx.yyy.4.0 mask: 22 Apr 8 21:25:17 traffic pmacctd[15492]: DEBUG ( /etc/pmacct/networks ): [networks table IPv4] nh: peer asn: 0 asn: 0 net: xxx.yyy.104.0 mask: 22 Apr 8 21:25:17 traffic pmacctd[15492]: DEBUG ( /etc/pmacct/networks ): [networks table IPv4] nh: peer asn: 0 asn: 0 net: xxx.yyy.114.0 mask: 23 Apr 8 21:25:17 traffic pmacctd[15492]: DEBUG ( /etc/pmacct/networks ): IPv4 Networks Cache successfully created: 99991 entries. Apr 8 21:25:17 traffic pmacctd[15492]: DEBUG ( /etc/pmacct/networks ): [networks table IPv6] nh: peer_asn: 0 asn: 0 net: 2a00:xyza:: mask: 32 Apr 8 21:25:17 traffic pmacctd[15492]: DEBUG ( /etc/pmacct/networks ): IPv6 Networks Cache successfully created: 32771 entries. Apr 8 21:25:17 traffic kernel: [22097.047614] device eth0 entered promiscuous mode Apr 8 21:25:17 traffic pmacctd[15489]: OK ( default/core ): link type is: 1 Apr 8 21:26:01 traffic pmacctd[15494]: INFO ( TMPflowDST/mysql ): *** Purging cache - START (PID: 15494) *** Apr 8 21:26:01 traffic pmacctd[15495]: INFO ( TMPflowSRC/mysql ): *** Purging cache - START (PID: 15495) *** Apr 8 21:26:01 traffic pmacctd[15499]: INFO ( outbound/mysql ): *** Purging cache - START (PID: 15499) *** Apr 8 21:26:01 traffic pmacctd[15498]: INFO ( inbound/mysql ): *** Purging cache - START (PID: 15498) *** Apr 8 21:26:01 traffic pmacctd[15495]: DEBUG ( TMPflowSRC/mysql ): 36 VALUES statements sent to the MySQL server. Apr 8 21:26:01 traffic pmacctd[15495]: INFO ( TMPflowSRC/mysql ): *** Purging cache - END (PID: 15495, QN: 36, ET: 0) *** Apr 8 21:26:01 traffic pmacctd[15494]: INFO ( TMPflowDST/mysql ): *** Purging cache - END (PID: 15494, QN: 556, ET: 0) *** Apr 8 21:26:01 traffic pmacctd[15498]: INFO ( inbound/mysql ): *** Purging cache - END (PID: 15498, QN: 1878, ET: 0) *** Apr 8 21:26:01 traffic pmacctd[15499]: INFO ( outbound/mysql ): *** Purging cache - END (PID: 15499, QN: 2333, ET: 0) *** Apr 8 21:27:01 traffic pmacctd[15520]: INFO ( outbound/mysql ): *** Purging cache - START (PID: 15520) *** Apr 8 21:27:01 traffic pmacctd[15521]: INFO ( inbound/mysql ): *** Purging cache - START (PID: 15521) *** Apr 8 21:27:01 traffic pmacctd[15524]: INFO ( TMPflowSRC/mysql ): *** Purging cache - START (PID: 15524) *** Apr 8 21:27:01 traffic pmacctd[15526]: INFO ( TMPflowDST/mysql ): *** Purging cache - START (PID: 15526) *** Apr 8 21:27:01 traffic pmacctd[15524]: DEBUG ( TMPflowSRC/mysql ): 57 VALUES statements sent to the MySQL server. Apr 8 21:27:01 traffic pmacctd[15524]: INFO ( TMPflowSRC/mysql ): *** Purging cache - END (PID: 15524, QN: 57, ET: 0) *** Apr 8 21:27:01 traffic pmacctd[15526]: INFO ( TMPflowDST/mysql ): *** Purging cache - END (PID: 15526, QN: 645, ET: 0) *** Apr 8 21:27:01 traffic pmacctd[15521]: INFO ( inbound/mysql ): *** Purging cache - END (PID: 15521, QN: 1665, ET: 0) *** Apr 8 21:27:01 traffic pmacctd[15520]: INFO ( outbound/mysql ): *** Purging cache - END (PID: 15520, QN: 2213, ET: 0) *** If I interpret the log correct some data is logged, but with 36 and 57 entries far far away from the expectation. > If log is clear, meaning no entries are written > out, i'd recommend to remove anything that can be potentially > filtering so: aggregate_filter, networks_file and ports_file: > see if this changes anything. Let's take it from there. After commenting the following lines out: !aggregate_filter[TMPflowSRC]: udp !networks_file[TMPflowSRC]: /etc/pmacct/networks !ports_file[TMPflowSRC]: /etc/pmacct/portsudp The results looks same (expect capturing to much data) Apr 8 21:38:01 traffic pmacctd[15800]: DEBUG ( TMPflowSRC/mysql ): 60329 VALUES statements sent to the MySQL server. Apr 8 21:38:01 traffic pmacctd[15800]: ERROR ( TMPflowSRC/mysql ): Duplicate entry '2014-04-08 21:37:00-176.227.218.237-tcp-38820' for key 'PRIMARY'#012 Apr 8 21:38:01 traffic pmacctd[15800]: INFO ( TMPflowSRC/mysql ): *** Purging cache - END (PID: 15800, QN: 60329, ET: 0) *** Apr 8 21:38:27 traffic pmacctd[15768]: WARN ( TMPflowSRC/mysql ): purging process (CAUSE: safe action) Apr 8 21:38:27 traffic pmacctd[15833]: INFO ( TMPflowSRC/mysql ): *** Purging cache - START (PID: 15833) *** Apr 8 21:38:32 traffic pmacctd[15833]: DEBUG ( TMPflowSRC/mysql ): 70000 VALUES statements sent to the MySQL server. Apr 8 21:38:32 traffic pmacctd[15833]: INFO ( TMPflowSRC/mysql ): *** Purging cache - END (PID: 15833, QN: 70000, ET: 5) *** Apr 8 21:38:49 traffic pmacctd[15768]: WARN ( TMPflowSRC/mysql ): purging process (CAUSE: safe action) Apr 8 21:38:49 traffic pmacctd[15835]: INFO ( TMPflowSRC/mysql ): *** Purging cache - START (PID: 15835) *** Apr 8 21:38:50 traffic pmacctd[15835]: DEBUG ( TMPflowSRC/mysql ): 70000 VALUES statements sent to the MySQL server. After enabling the networks_file[TMPflowSRC]: /etc/pmacct/networks again still too much data but otherwise ok: Apr 8 21:43:43 traffic pmacctd[16033]: WARN ( TMPflowSRC/mysql ): purging process (CAUSE: safe action) Apr 8 21:43:43 traffic pmacctd[16035]: INFO ( TMPflowSRC/mysql ): *** Purging cache - START (PID: 16035) *** Apr 8 21:43:47 traffic pmacctd[16035]: DEBUG ( TMPflowSRC/mysql ): 70000 VALUES statements sent to the MySQL server. Apr 8 21:43:47 traffic pmacctd[16035]: INFO ( TMPflowSRC/mysql ): *** Purging cache - END (PID: 16035, QN: 70000, ET: 4) *** Apr 8 21:44:01 traffic pmacctd[16041]: INFO ( TMPflowSRC/mysql ): *** Purging cache - START (PID: 16041) *** Apr 8 21:44:01 traffic pmacctd[16038]: INFO ( inbound/mysql ): *** Purging cache - START (PID: 16038) *** Apr 8 21:44:01 traffic pmacctd[16037]: INFO ( outbound/mysql ): *** Purging cache - START (PID: 16037) *** Apr 8 21:44:01 traffic pmacctd[16043]: INFO ( TMPflowDST/mysql ): *** Purging cache - START (PID: 16043) *** Apr 8 21:44:01 traffic pmacctd[16038]: INFO ( inbound/mysql ): *** Purging cache - END (PID: 16038, QN: 1383, ET: 0) *** Apr 8 21:44:01 traffic pmacctd[16043]: INFO ( TMPflowDST/mysql ): *** Purging cache - END (PID: 16043, QN: 532, ET: 0) *** Apr 8 21:44:01 traffic pmacctd[16037]: INFO ( outbound/mysql ): *** Purging cache - END (PID: 16037, QN: 1783, ET: 0) *** Apr 8 21:44:01 traffic pmacctd[16041]: DEBUG ( TMPflowSRC/mysql ): 53435 VALUES statements sent to the MySQL server. Apr 8 21:44:01 traffic pmacctd[16041]: ERROR ( TMPflowSRC/mysql ): Duplicate entry '2014-04-08 21:43:00-xxx.yyy.75.20-tcp-20080' for key 'PRIMARY'#012 Apr 8 21:44:01 traffic pmacctd[16041]: INFO ( TMPflowSRC/mysql ): *** Purging cache - END (PID: 16041, QN: 53435, ET: 0) *** Apr 8 21:44:32 traffic pmacctd[16033]: WARN ( TMPflowSRC/mysql ): purging process (CAUSE: safe action) Apr 8 21:44:32 traffic pmacctd[16066]: INFO ( TMPflowSRC/mysql ): *** Purging cache - START (PID: 16066) *** Apr 8 21:44:35 traffic pmacctd[16066]: DEBUG ( TMPflowSRC/mysql ): 70000 VALUES statements sent to the MySQL server. Apr 8 21:44:35 traffic pmacctd[16066]: INFO ( TMPflowSRC/mysql ): *** Purging cache - END (PID: 16066, QN: 70000, ET: 3) *** Enabling aggregate_filter[TMPflowSRC]: udp networks_file[TMPflowSRC]: /etc/pmacct/networks reduces the amount of data: Apr 8 21:47:01 traffic pmacctd[16151]: DEBUG ( TMPflowSRC/mysql ): 13881 VALUES statements sent to the MySQL server. Apr 8 21:48:01 traffic pmacctd[16178]: DEBUG ( TMPflowSRC/mysql ): 29502 VALUES statements sent to the MySQL server. Apr 8 21:49:01 traffic pmacctd[16205]: DEBUG ( TMPflowSRC/mysql ): 29167 VALUES statements sent to the MySQL server. BUT the error occurred, only IPv6 with a very small amount of the traffic show up. Enabling networks_file[TMPflowSRC]: /etc/pmacct/networks ports_file[TMPflowSRC]: /etc/pmacct/portsudp works without problems (only generating too much data since tcp is not needed.) So the problem seem to result in the use of the „aggregate_filter[TMPflowSRC]: udp“ which is kind of strange since the aggregate TMPflowDST uses the same without problems. Ideas? Running without the aggregate_filter is a good quick workaround but seems a strange error to me. regards Johannes > On Tue, Apr 08, 2014 at 05:50:50PM +0200, Johannes Formann wrote: >> Hi, >> >> I have a strange problem again. I already tested the newest CVS version but >> it persists: >> >> I use four aggregates: >> - inbound: incoming traffic for local IPs >> - outbound: outgoing traffic for local ips >> - TMPflowSRC: short time local outgoing udp traffic (with a short port list) >> - TMPflowDST: short time udp traffic (after destination address) to be able >> to identify potential outgoing ddos >> >> Everything worked fine for some time but today I found that TMPflowSRC >> accounts almost no traffic anymore and if its accounts mostly IPv6 >> addresses. Sadly in this network IPv6 traffic is less than 4% so there must >> be some fault in my configuration. >> >> With debug enabled the initialization of the three aggregates with a network >> filter looks identical, so there shouldn’t be the problem. >> commenting out the port-List didn’t help either. >> >> My configuration: >> >> ! pmacctd configuration >> ! >> ! >> ! >> daemonize: true >> pidfile: /var/run/pmacctd.pid >> syslog: daemon >> ! >> aggregate[inbound]: dst_host >> aggregate[outbound]: src_host,proto >> aggregate[TMPflowSRC]: src_host,src_port,proto >> aggregate[TMPflowDST]: dst_host,proto >> aggregate_filter[TMPflowSRC]: udp >> aggregate_filter[TMPflowDST]: udp >> plugins: mysql[inbound], mysql[outbound], mysql[TMPflowSRC], >> mysql[TMPflowDST] >> sql_table[inbound]: acct_%Y_%m_in >> sql_table[outbound]: acct_%Y_%m_out >> sql_table[TMPflowSRC]: acct_TMPflowSRC >> sql_table[TMPflowDST]: acct_TMPflowDST >> sql_table_schema[inbound]: /etc/pmacct/inbound.schema >> sql_table_schema[outbound]: /etc/pmacct/outbound.schema >> networks_file[inbound]: /etc/pmacct/networks >> networks_file[outbound]: /etc/pmacct/networks >> networks_file[TMPflowSRC]: /etc/pmacct/networks >> ports_file[TMPflowSRC]: /etc/pmacct/portsudp >> >> networks_file_filter: true >> >> interface: eth0 >> >> ! storage methods >> sql_db: pmacct >> sql_table_version: 4 >> sql_passwd: <secret> >> sql_user: pmacct >> sql_refresh_time: 60 >> sql_optimize_clauses: true >> sql_history: 1m >> sql_history_roundoff: m >> sql_multi_values: 12000000 >> sql_cache_entries: 64000 >> >> pmacctd_flow_buffer_buckets: 4096 >> >> sql_dont_try_update: true >> >> plugin_buffer_size: 163840 >> plugin_pipe_size: 40960000 >> >> Any ideas where to look? >> >> greetings >> >> Johannes >> _______________________________________________ >> pmacct-discussion mailing list >> http://www.pmacct.net/#mailinglists > > _______________________________________________ > pmacct-discussion mailing list > http://www.pmacct.net/#mailinglists _______________________________________________ pmacct-discussion mailing list http://www.pmacct.net/#mailinglists
