[dovecot input plugin] tcp read i/o timeout since telegraf 1.18.3 -> 1.19.0 update

[ray-magini]

Relevant telegraf.conf:

[[inputs.dovecot]]
        type = "global"

Relevant dovecot.conf:

mail_plugins = $mail_plugins old_stats
auth_stats = yes
plugin {
        old_stats_refresh = 10 secs
        old_stats_track_cmds = yes
}
service old-stats {
        fifo_listener old-stats-mail {
                user = dovecot
                group = mail
                mode = 0666
        }
        inet_listener {
                address = 127.0.0.1 ::1
                port = 24242
        }
        process_min_avail=1
}

System info:

OS: CentOS Linux release 7.9.2009 (Core)
Uname: Linux 3.10.0-1160.31.1.el7.x86_64 #1 SMP Thu Jun 10 13:32:12 UTC 2021 x86_64 x86_64 x86_64 GNU/Linux
Telegraf: telegraf-1.19.0-1.x86_64
Dovecot: dovecot23-2.3.11.3-1.gf.el7.x86_64 and dovecot23-pigeonhole-2.3.11.3-1.gf.el7.x86_64

All latest updates are installed on the OS

Steps to reproduce:

1. Update from telegraf 1.18.3 -> 1.19.0
2. Enable the above config in telegraf and dovecot
3. watch the telegraf error log

Expected behavior:

Version 1.19.0 to act like 1.18.3.

In version 1.18.3 the dovecot stats were read via 127.0.0.1:24242 without any error.

Actual behavior:

Since version 1.19.0 the error (see logs below) appears.

There was no other config/update than the update from telegraf 1.18.3 -> 1.19.0.
A tcp connection to 127.0.0.1:24242 is still possible, as before

$ telnet 127.0.0.1 24242
Trying 127.0.0.1...
Connected to 127.0.0.1.
Escape character is '^]'.

Additional info:

Just a note: As per #9223 (telegraf version 1.19.0) there were changes around this plugin made.

Jun 23 07:54:45 mail1 telegraf: 2021-06-23T05:54:45Z E! [inputs.dovecot] Error in plugin: copying message failed for dovecot server '127.0.0.1:24242': read tcp 127.0.0.1:60094->127.0.0.1:24242: i/o timeout
Jun 23 07:54:55 mail1 telegraf: 2021-06-23T05:54:55Z E! [inputs.dovecot] Error in plugin: copying message failed for dovecot server '127.0.0.1:24242': read tcp 127.0.0.1:60102->127.0.0.1:24242: i/o timeout
Jun 23 07:55:05 mail1 telegraf: 2021-06-23T05:55:05Z E! [inputs.dovecot] Error in plugin: copying message failed for dovecot server '127.0.0.1:24242': read tcp 127.0.0.1:60110->127.0.0.1:24242: i/o timeout
Jun 23 07:55:15 mail1 telegraf: 2021-06-23T05:55:15Z E! [inputs.dovecot] Error in plugin: copying message failed for dovecot server '127.0.0.1:24242': read tcp 127.0.0.1:60116->127.0.0.1:24242: i/o timeout
Jun 23 07:55:25 mail1 telegraf: 2021-06-23T05:55:25Z E! [inputs.dovecot] Error in plugin: copying message failed for dovecot server '127.0.0.1:24242': read tcp 127.0.0.1:60124->127.0.0.1:24242: i/o timeout
Jun 23 07:55:35 mail1 telegraf: 2021-06-23T05:55:35Z E! [inputs.dovecot] Error in plugin: copying message failed for dovecot server '127.0.0.1:24242': read tcp 127.0.0.1:60148->127.0.0.1:24242: i/o timeout
Jun 23 07:55:45 mail1 telegraf: 2021-06-23T05:55:45Z E! [inputs.dovecot] Error in plugin: copying message failed for dovecot server '127.0.0.1:24242': read tcp 127.0.0.1:60156->127.0.0.1:24242: i/o timeout

[popey]

Thanks for filing this issue. I'm trying to reproduce this in a lxd container running centos 7. I've got dovecot running, but adding your snippet to the dovecot.conf doesn't result in anything listening on port 24242 for me. Is there any other configuration required, to enable the stats output from dovecot?

[ray-magini]

Hi @popey, thanks for looking into it. Which version of dovecot are you running?

[popey]

I'm using dovecot 2.2.36. I just did a clean container and used yum to install it.

[ray-magini]

ok, in dovecot 2.3 the stats plugin was renamed to old_stats, so you may want to

• try to use stats (https://wiki2.dovecot.org/Statistics/Old)
• or update to dovecot 2.3 (use the GhettoForge repo http://ghettoforge.org/index.php/Usage#Usage or the dovecot repo should work as well https://repo.dovecot.org/)

[popey]

Thanks for the tips.

Ok, confirmed that telegraf 1.19.0 gives:-

2021-06-23T13:08:23Z E! [inputs.dovecot] Error in plugin: copying message failed for dovecot server '10.55.242.189:24242': read tcp 10.55.242.1:54512->10.55.242.189:24242: i/o timeout 

With telegraf 1.18.3 I get:

dovecot,host=ac,server=10.55.242.189,type=global mail_lookup_attr=0i,auth_cache_hits=0i,auth_failures=0i,num_logins=0i,user_cpu=0,read_bytes=0i,auth_successes=0i,read_count=0i,write_bytes=0i,auth_master_successes=0i,auth_db_tempfails=0i,num_cmds=0i,maj_faults=0i,mail_lookup_path=0i,mail_read_count=0i,mail_cache_hits=0i,auth_cache_misses=0i,clock_time=0,min_faults=0i,vol_cs=0i,disk_output=0i,write_count=0i,invol_cs=0i,disk_input=0i,mail_read_bytes=0i,num_connected_sessions=0i,sys_cpu=0 1624453744000000000

So this looks like a regression in 1.19. Thanks again for reporting it.