Package: munin Version: 2.0.10-1 Severity: important Dear Maintainer,
I'm using Munin with TLS since many years without any problems. Now I've setup a new Munin master with v2.0.x on a new machine (the old master is still running v1.4.x) and ran into some problems with TLS enabled communication between master and node. My setup is as follows: * Munin master and node on the same machine. * Connections through localhost. (IPv4/IPv6) * Tested with v2.0.6-3 (Wheezy) and 2.0.10-1 (Experimental). * On master and node "tls enabled" and "tls_verify_certificate no". * Custom "tls_private_key" and "tls_certificate" on both configs. Now the problem: * The master connects to the node, TLS stuff handshake, ... * He gets all plugins and requests the config for "open_inodes". * He gets the response from the node with the full config. * He wants to fetch the plugin: fetch open_inodes * The node executes the plugin and returns the output. * The master doesn't receive the plugin's output. * After 60 seconds a timeout on both sides occurs. * ERROR! The output from munin-cron and munin-node with --debug flag is attached. Without TLS or with an old master version it works without any problems. Regards, Christian -- System Information: Debian Release: 7.0 APT prefers testing-updates APT policy: (500, 'testing-updates'), (500, 'testing') Architecture: amd64 (x86_64) Kernel: Linux 3.2.0-4-amd64 (SMP w/1 CPU core) Locale: LANG=de_AT.UTF-8, LC_CTYPE=de_AT.UTF-8 (charmap=UTF-8) Shell: /bin/sh linked to /bin/dash Versions of packages munin depends on: ii adduser 3.113+nmu3 ii cron 3.0pl1-124 ii libdate-manip-perl 6.32-1 pn libdigest-md5-perl <none> ii libfile-copy-recursive-perl 0.38-1 ii libhtml-template-perl 2.91-1 ii libio-socket-inet6-perl 2.69-2 ii liblog-log4perl-perl 1.29-1 ii librrds-perl 1.4.7-2 pn libstorable-perl <none> ii liburi-perl 1.60-1 ii munin-common 2.0.10-1 ii perl [libtime-hires-perl] 5.14.2-16 ii perl-modules 5.14.2-16 ii rrdtool 1.4.7-2 ii ttf-dejavu 2.33-3 Versions of packages munin recommends: pn munin-doc <none> ii munin-node 2.0.10-1 Versions of packages munin suggests: ii apache2-mpm-prefork [httpd] 2.2.22-12 ii elinks [www-browser] 0.12~pre5-9 ii libapache2-mod-fcgid 1:2.3.6-1.2 ii libnet-ssleay-perl 1.48-1+b1 ii links2 [www-browser] 2.7-1 ii lynx-cur [www-browser] 2.8.8dev.12-2 ii w3m [www-browser] 0.5.3-8 -- Configuration Files: /etc/munin/apache.conf changed [not included] /etc/munin/munin.conf changed [not included] -- no debconf information
2013/02/05-11:48:46 [6138] In pre_loop_hook. # Processing plugin configuration from /etc/munin/plugin-conf.d/munin-node 2013/02/05-11:48:46 [6138] Configuring open_inodes 2013/02/05-11:48:46 [6138] Adding to node host.example.org 2013/02/05-11:48:46 [6138] Configuring processes 2013/02/05-11:48:46 [6138] Adding to node host.example.org 2013/02/05-11:48:46 [6138] Configuring if_eth0 2013/02/05-11:48:46 [6138] Adding to node host.example.org 2013/02/05-11:48:46 [6138] Configuring users 2013/02/05-11:48:46 [6138] Adding to node host.example.org 2013/02/05-11:48:46 [6138] Configuring df 2013/02/05-11:48:46 [6138] Adding to node host.example.org 2013/02/05-11:48:46 [6138] Configuring swap 2013/02/05-11:48:46 [6138] Adding to node host.example.org 2013/02/05-11:48:46 [6138] Configuring uptime 2013/02/05-11:48:46 [6138] Adding to node host.example.org 2013/02/05-11:48:46 [6138] Configuring if_lo 2013/02/05-11:48:46 [6138] Adding to node host.example.org 2013/02/05-11:48:46 [6138] Configuring ip_***** 2013/02/05-11:48:46 [6138] Adding to node host.example.org 2013/02/05-11:48:46 [6138] Configuring load 2013/02/05-11:48:46 [6138] Adding to node host.example.org 2013/02/05-11:48:46 [6138] Configuring ntp_offset 2013/02/05-11:48:46 [6138] Adding to node host.example.org 2013/02/05-11:48:46 [6138] Configuring fw_conntrack 2013/02/05-11:48:46 [6138] Adding to node host.example.org 2013/02/05-11:48:46 [6138] Configuring cpu 2013/02/05-11:48:46 [6138] Adding to node host.example.org 2013/02/05-11:48:46 [6138] Configuring df_inode 2013/02/05-11:48:46 [6138] Adding to node host.example.org 2013/02/05-11:48:46 [6138] Configuring apt_all 2013/02/05-11:48:46 [6138] Adding to node host.example.org 2013/02/05-11:48:46 [6138] Configuring forks 2013/02/05-11:48:46 [6138] Adding to node host.example.org 2013/02/05-11:48:46 [6138] Configuring diskstats 2013/02/05-11:48:46 [6138] Adding to node host.example.org 2013/02/05-11:48:46 [6138] Adding to multigraph plugins 2013/02/05-11:48:46 [6138] Configuring open_files 2013/02/05-11:48:46 [6138] Adding to node host.example.org 2013/02/05-11:48:46 [6138] Configuring memory 2013/02/05-11:48:46 [6138] Adding to node host.example.org 2013/02/05-11:48:46 [6138] Configuring munin_stats 2013/02/05-11:48:46 [6138] Adding to node host.example.org 2013/02/05-11:48:46 [6138] Configuring ip_***** 2013/02/05-11:48:46 [6138] Adding to node host.example.org 2013/02/05-11:48:46 [6138] Configuring fw_packets 2013/02/05-11:48:46 [6138] Adding to node host.example.org 2013/02/05-11:48:46 [6138] Finished configuring services Use of uninitialized value in pattern match (m//) at /usr/share/perl5/Net/Server.pm line 600. 2013/02/05-11:49:12 [6354] DEBUG: > # munin node at host.example.org 2013/02/05-11:49:12 [6354] DEBUG: < STARTTLS 2013/02/05-11:49:12 [6354] DEBUG: Running command 'STARTTLS'. 2013/02/05-11:49:12 [6354] [TLS] Enabling TLS. 2013/02/05-11:49:12 [6354] [TLS] Available cipher list: Cipher list: ECDHE-RSA-AES256-GCM-SHA384, ECDHE-RSA-AES256-GCM-SHA384, ECDHE-ECDSA-AES256-GCM-SHA384, ECDHE-RSA-AES256-SHA384, ECDHE-ECDSA-AES256-SHA384, ECDHE-RSA-AES256-SHA, ECDHE-ECDSA-AES256-SHA, SRP-DSS-AES-256-CBC-SHA, SRP-RSA-AES-256-CBC-SHA, DHE-DSS-AES256-GCM-SHA384, DHE-RSA-AES256-GCM-SHA384, DHE-RSA-AES256-SHA256, DHE-DSS-AES256-SHA256, DHE-RSA-AES256-SHA, DHE-DSS-AES256-SHA, DHE-RSA-CAMELLIA256-SHA, DHE-DSS-CAMELLIA256-SHA, ECDH-RSA-AES256-GCM-SHA384, ECDH-ECDSA-AES256-GCM-SHA384, ECDH-RSA-AES256-SHA384, ECDH-ECDSA-AES256-SHA384, ECDH-RSA-AES256-SHA, ECDH-ECDSA-AES256-SHA, AES256-GCM-SHA384, AES256-SHA256, AES256-SHA, CAMELLIA256-SHA, PSK-AES256-CBC-SHA, ECDHE-RSA-DES-CBC3-SHA, ECDHE-ECDSA-DES-CBC3-SHA, SRP-DSS-3DES-EDE-CBC-SHA, SRP-RSA-3DES-EDE-CBC-SHA, EDH-RSA-DES-CBC3-SHA, EDH-DSS-DES-CBC3-SHA, ECDH-RSA-DES-CBC3-SHA, ECDH-ECDSA-DES-CBC3-SHA, DES-CBC3-SHA, PSK-3DES-EDE-CBC-SHA, ECDHE-RSA-AES128-GCM-SHA256, ECDHE-EC DSA-AES128-GCM-SHA256, ECDHE-RSA-AES128-SHA256, ECDHE-ECDSA-AES128-SHA256, ECDHE-RSA-AES128-SHA, ECDHE-ECDSA-AES128-SHA, SRP-DSS-AES-128-CBC-SHA, SRP-RSA-AES-128-CBC-SHA, DHE-DSS-AES128-GCM-SHA256, DHE-RSA-AES128-GCM-SHA256, DHE-RSA-AES128-SHA256, DHE-DSS-AES128-SHA256, DHE-RSA-AES128-SHA, DHE-DSS-AES128-SHA, DHE-RSA-SEED-SHA, DHE-DSS-SEED-SHA, DHE-RSA-CAMELLIA128-SHA, DHE-DSS-CAMELLIA128-SHA, ECDH-RSA-AES128-GCM-SHA256, ECDH-ECDSA-AES128-GCM-SHA256, ECDH-RSA-AES128-SHA256, ECDH-ECDSA-AES128-SHA256, ECDH-RSA-AES128-SHA, ECDH-ECDSA-AES128-SHA, AES128-GCM-SHA256, AES128-SHA256, AES128-SHA, SEED-SHA, CAMELLIA128-SHA, PSK-AES128-CBC-SHA, ECDHE-RSA-RC4-SHA, ECDHE-ECDSA-RC4-SHA, ECDH-RSA-RC4-SHA, ECDH-ECDSA-RC4-SHA, RC4-SHA, RC4-MD5, PSK-RC4-SHA, EDH-RSA-DES-CBC-SHA, EDH-DSS-DES-CBC-SHA, DES-CBC-SHA, EXP-EDH-RSA-DES-CBC-SHA, EXP-EDH-DSS-DES-CBC-SHA, EXP-DES-CBC-SHA, EXP-RC2-CBC-MD5, EXP-RC4-MD5\n. 2013/02/05-11:49:12 [6354] [TLS] Accept/Connect: 1, 1 2013/02/05-11:49:12 [6354] [TLS] Done Accept/Connect 2013/02/05-11:49:12 [6354] [TLS] TLS enabled. 2013/02/05-11:49:12 [6354] [TLS] Cipher `AES256-GCM-SHA384'. 2013/02/05-11:49:12 [6354] [TLS] client cert: Subject Name: undefined\nIssuer Name: undefined 2013/02/05-11:49:12 [6354] DEBUG: Returned from starttls. 2013/02/05-11:49:12 [6354] DEBUG: < cap multigraph dirtyconfig 2013/02/05-11:49:12 [6354] DEBUG: < cap multigraph dirtyconfig 2013/02/05-11:49:12 [6354] DEBUG: Running command 'cap multigraph dirtyconfig'. 2013/02/05-11:49:12 [6354] DEBUG: > cap multigraph dirtyconfig 2013/02/05-11:49:12 [6354] DEBUG: > cap multigraph dirtyconfig 2013/02/05-11:49:12 [6354] DEBUG: < list host.example.org 2013/02/05-11:49:12 [6354] DEBUG: < list host.example.org 2013/02/05-11:49:12 [6354] DEBUG: Running command 'list host.example.org'. 2013/02/05-11:49:12 [6354] DEBUG: > open_inodes processes if_eth0 users df swap uptime if_lo ip_***** load ntp_offset fw_conntrack cpu df_inode apt_all forks diskstats open_files memory munin_stats ip_***** fw_packets 2013/02/05-11:49:12 [6354] DEBUG: > open_inodes processes if_eth0 users df swap uptime if_lo ip_***** load ntp_offset fw_conntrack cpu df_inode apt_all forks diskstats open_files memory munin_stats ip_***** fw_packets 2013/02/05-11:49:12 [6354] DEBUG: > 2013/02/05-11:49:12 [6354] DEBUG: > 2013/02/05-11:49:12 [6354] DEBUG: < config open_inodes 2013/02/05-11:49:12 [6354] DEBUG: < config open_inodes 2013/02/05-11:49:12 [6354] DEBUG: Running command 'config open_inodes'. 2013/02/05-11:49:12 [6354] DEBUG: > graph_title Inode table usage 2013/02/05-11:49:12 [6354] DEBUG: > graph_title Inode table usage 2013/02/05-11:49:12 [6354] DEBUG: > graph_args --base 1000 -l 0 2013/02/05-11:49:12 [6354] DEBUG: > graph_args --base 1000 -l 0 2013/02/05-11:49:12 [6354] DEBUG: > graph_vlabel number of open inodes 2013/02/05-11:49:12 [6354] DEBUG: > graph_vlabel number of open inodes 2013/02/05-11:49:12 [6354] DEBUG: > graph_category system 2013/02/05-11:49:12 [6354] DEBUG: > graph_category system 2013/02/05-11:49:12 [6354] DEBUG: > graph_info This graph monitors the Linux open inode table. 2013/02/05-11:49:12 [6354] DEBUG: > graph_info This graph monitors the Linux open inode table. 2013/02/05-11:49:12 [6354] DEBUG: > used.label open inodes 2013/02/05-11:49:12 [6354] DEBUG: > used.label open inodes 2013/02/05-11:49:12 [6354] DEBUG: > used.info The number of currently open inodes. 2013/02/05-11:49:12 [6354] DEBUG: > used.info The number of currently open inodes. 2013/02/05-11:49:12 [6354] DEBUG: > max.label inode table size 2013/02/05-11:49:12 [6354] DEBUG: > max.label inode table size 2013/02/05-11:49:12 [6354] DEBUG: > max.info The size of the system inode table. This is dynamically adjusted by the kernel. 2013/02/05-11:49:12 [6354] DEBUG: > max.info The size of the system inode table. This is dynamically adjusted by the kernel. 2013/02/05-11:49:12 [6354] DEBUG: > . 2013/02/05-11:49:12 [6354] DEBUG: > . 2013/02/05-11:49:12 [6354] DEBUG: < fetch open_inodes 2013/02/05-11:49:12 [6354] DEBUG: < fetch open_inodes 2013/02/05-11:49:12 [6354] DEBUG: Running command 'fetch open_inodes'. 2013/02/05-11:49:12 [6354] DEBUG: > used.value 4086 2013/02/05-11:49:12 [6354] DEBUG: > used.value 4086 2013/02/05-11:49:12 [6354] DEBUG: > max.value 4759 2013/02/05-11:49:12 [6354] DEBUG: > max.value 4759 2013/02/05-11:49:12 [6354] DEBUG: > . 2013/02/05-11:49:12 [6354] DEBUG: > . 2013/02/05-11:50:12 [6354] Node side timeout while processing: '<waiting for input from master, previous was 'fetch open_inodes'>'
munin-cron.debug
Description: Binary data
