detected empty handle

smileluo · Apr 18, 2023

I found some strange log recectly,my version is: Version: 7.3-3,the log is as below:

Apr 18 19:00:08 postfix pmgproxy[1125188]: detected empty handle
Apr 18 19:00:13 postfix pmgproxy[1125188]: detected empty handle
Apr 18 19:00:18 postfix pmgproxy[1125188]: detected empty handle
Apr 18 19:00:23 postfix pmgproxy[1125188]: detected empty handle
Apr 18 19:00:28 postfix pmgproxy[1125188]: detected empty handle
Apr 18 19:00:32 postfix pmg-smtp-filter[1133794]: starting database maintenance
Apr 18 19:00:32 postfix pmg-smtp-filter[1133794]: end database maintenance (4 ms)
Apr 18 19:00:33 postfix pmgproxy[1125188]: detected empty handle
Apr 18 19:00:38 postfix pmgproxy[1125188]: detected empty handle
Apr 18 19:00:43 postfix pmgproxy[1125188]: detected empty handle
Apr 18 19:00:48 postfix pmgproxy[1125188]: detected empty handle
Apr 18 19:00:53 postfix pmgproxy[1125188]: detected empty handle
Apr 18 19:00:59 postfix pmgproxy[1125188]: detected empty handle
Apr 18 19:01:04 postfix pmgproxy[1125188]: detected empty handle
Apr 18 19:01:09 postfix pmgproxy[1125188]: detected empty handle
Apr 18 19:01:14 postfix pmgproxy[1125188]: detected empty handle
Apr 18 19:01:19 postfix pmgproxy[1125188]: detected empty handle
Apr 18 19:01:24 postfix pmgproxy[1125188]: detected empty handle
Apr 18 19:01:29 postfix pmgproxy[1125188]: detected empty handle
Apr 18 19:01:34 postfix pmgproxy[1125188]: detected empty handle
Apr 18 19:01:36 postfix pmgmirror[881470]: starting cluster synchronization
Apr 18 19:01:36 postfix pmgmirror[881470]: cluster synchronization finished (0 errors, 0.00 seconds (files 0.00, database 0.00, config 0.00))
Apr 18 19:01:39 postfix pmgproxy[1125188]: detected empty handle
Apr 18 19:01:44 postfix pmgproxy[1125188]: detected empty handle
Apr 18 19:01:49 postfix pmgproxy[1125188]: detected empty handle
Apr 18 19:01:54 postfix pmgproxy[1125188]: detected empty handle
Apr 18 19:01:59 postfix pmgproxy[1125188]: detected empty handle
Apr 18 19:02:04 postfix pmgproxy[1125188]: detected empty handle
Apr 18 19:02:09 postfix pmgproxy[1125188]: detected empty handle
Apr 18 19:02:12 postfix pmgpolicy[881454]: starting policy database maintenance (greylist, rbl)
Apr 18 19:02:12 postfix pmgpolicy[881454]: end policy database maintenance (12 ms, 1 ms)
Apr 18 19:02:14 postfix pmgproxy[1125188]: detected empty handle
Apr 18 19:02:19 postfix pmgproxy[1125188]: detected empty handle
Apr 18 19:02:24 postfix pmgproxy[1125188]: detected empty handle
Apr 18 19:02:29 postfix pmgproxy[1125188]: detected empty handle

dcsapak · Apr 19, 2023

AFAICS the code where this can trigger didn't change recently

it basically says that during a client disconnect the internal connection handle vanished... on idea really why this should happen (and so often like in your case)
can you check the access log if there are unusual api/web requests? (/var/log/pmgproxy/pmgproxy.log* )

smileluo · Apr 23, 2023

It is no such issue recently,maybe that day some bad man is doing bad thing on my server.

RolandK · Jul 1, 2023

that message also happens with pveproxy. it may have the same detection mechanism. https://forum.proxmox.com/threads/j...pveproxy-452651-detected-empty-handle.128830/

the question is, what's causing it

RolandK · Jul 1, 2023

Bash:

root@pbsvm:/var/log/pveproxy# cat access.log|grep ":10:06:"
::ffff:192.168.179.90 - root@pam [01/07/2023:10:06:02 +0200] "GET /api2/json/cluster/resources HTTP/1.1" 200 455
::ffff:192.168.179.90 - root@pam [01/07/2023:10:06:02 +0200] "GET /api2/json/cluster/tasks HTTP/1.1" 200 976
::ffff:192.168.179.90 - root@pam [01/07/2023:10:06:05 +0200] "GET /api2/json/cluster/resources HTTP/1.1" 200 455
::ffff:192.168.179.90 - root@pam [01/07/2023:10:06:05 +0200] "GET /api2/json/cluster/tasks HTTP/1.1" 200 986
::ffff:192.168.179.90 - root@pam [01/07/2023:10:06:08 +0200] "GET /api2/json/cluster/resources HTTP/1.1" 200 455
::ffff:192.168.179.90 - root@pam [01/07/2023:10:06:08 +0200] "GET /api2/json/cluster/tasks HTTP/1.1" 200 986
::ffff:192.168.179.90 - root@pam [01/07/2023:10:06:11 +0200] "GET /api2/json/cluster/resources HTTP/1.1" 200 455
::ffff:192.168.179.90 - root@pam [01/07/2023:10:06:11 +0200] "GET /api2/json/cluster/tasks HTTP/1.1" 200 986
::ffff:192.168.179.90 - root@pam [01/07/2023:10:06:14 +0200] "GET /api2/json/cluster/resources HTTP/1.1" 200 456
::ffff:192.168.179.90 - root@pam [01/07/2023:10:06:14 +0200] "GET /api2/json/cluster/tasks HTTP/1.1" 200 992
::ffff:192.168.179.90 - root@pam [01/07/2023:10:06:17 +0200] "GET /api2/json/cluster/resources HTTP/1.1" 200 456
::ffff:192.168.179.90 - root@pam [01/07/2023:10:06:17 +0200] "GET /api2/json/cluster/tasks HTTP/1.1" 200 992
::ffff:192.168.179.90 - root@pam [01/07/2023:10:06:20 +0200] "GET /api2/json/cluster/resources HTTP/1.1" 200 456
::ffff:192.168.179.90 - root@pam [01/07/2023:10:06:20 +0200] "GET /api2/json/cluster/tasks HTTP/1.1" 200 992
::ffff:192.168.179.90 - root@pam [01/07/2023:10:06:27 +0200] "GET /api2/json/cluster/tasks HTTP/1.1" 200 972
::ffff:192.168.179.90 - root@pam [01/07/2023:10:06:27 +0200] "GET /api2/json/cluster/resources HTTP/1.1" 200 455
::ffff:192.168.179.90 - root@pam [01/07/2023:10:06:39 +0200] "GET /api2/json/cluster/tasks HTTP/1.1" 200 988
::ffff:192.168.179.90 - root@pam [01/07/2023:10:06:39 +0200] "GET /api2/json/cluster/resources HTTP/1.1" 200 455
::ffff:192.168.179.90 - root@pam [01/07/2023:10:06:42 +0200] "GET /api2/json/cluster/resources HTTP/1.1" 200 455
::ffff:192.168.179.90 - root@pam [01/07/2023:10:06:42 +0200] "GET /api2/json/cluster/tasks HTTP/1.1" 200 988
::ffff:192.168.179.90 - root@pam [01/07/2023:10:06:45 +0200] "GET /api2/json/cluster/resources HTTP/1.1" 200 455
::ffff:192.168.179.90 - root@pam [01/07/2023:10:06:45 +0200] "GET /api2/json/cluster/tasks HTTP/1.1" 200 992
::ffff:192.168.179.90 - root@pam [01/07/2023:10:06:48 +0200] "GET /api2/json/cluster/resources HTTP/1.1" 200 455
::ffff:192.168.179.90 - root@pam [01/07/2023:10:06:49 +0200] "GET /api2/json/cluster/tasks HTTP/1.1" 200 992
::ffff:192.168.179.90 - root@pam [01/07/2023:10:06:51 +0200] "GET /api2/json/cluster/resources HTTP/1.1" 200 455
::ffff:192.168.179.90 - root@pam [01/07/2023:10:06:52 +0200] "GET /api2/json/cluster/tasks HTTP/1.1" 200 992
::ffff:192.168.179.90 - root@pam [01/07/2023:10:06:55 +0200] "GET /api2/json/cluster/resources HTTP/1.1" 200 456
::ffff:192.168.179.90 - root@pam [01/07/2023:10:06:55 +0200] "GET /api2/json/cluster/tasks HTTP/1.1" 200 974
::ffff:192.168.179.90 - root@pam [01/07/2023:10:06:58 +0200] "GET /api2/json/cluster/resources HTTP/1.1" 200 456
::ffff:192.168.179.90 - root@pam [01/07/2023:10:06:58 +0200] "GET /api2/json/cluster/tasks HTTP/1.1" 200 974
root@pbsvm:/var/log/pveproxy# journalctl -u pveproxy|grep empty|grep " 10:06"
Jul 01 10:06:01 pbsvm pveproxy[30960]: detected empty handle
Jul 01 10:06:06 pbsvm pveproxy[30960]: detected empty handle
Jul 01 10:06:11 pbsvm pveproxy[30960]: detected empty handle
Jul 01 10:06:16 pbsvm pveproxy[30960]: detected empty handle
Jul 01 10:06:21 pbsvm pveproxy[30960]: detected empty handle

Lucaaa · Dec 13, 2023

Getting it me too:


Dec 13 00:14:56 pom3nvme pveproxy[427632]: detected empty handle
Dec 13 00:15:30 pom3nvme pveproxy[427633]: detected empty handle
Dec 13 00:15:35 pom3nvme pveproxy[427633]: detected empty handle
Dec 13 00:15:40 pom3nvme pveproxy[427633]: detected empty handle
Dec 13 00:15:45 pom3nvme pveproxy[427633]: detected empty handle
Dec 13 00:15:47 pom3nvme pveproxy[427632]: detected empty handle
Dec 13 00:15:50 pom3nvme pveproxy[427633]: detected empty handle
Dec 13 00:15:52 pom3nvme pveproxy[427632]: detected empty handle


pveversion -v
proxmox-ve: 8.1.0 (running kernel: 6.5.11-4-pve)
pve-manager: 8.1.3 (running version: 8.1.3/b46aac3b42da5d15)
proxmox-kernel-helper: 8.1.0
pve-kernel-6.2: 8.0.5
proxmox-kernel-6.5: 6.5.11-7
proxmox-kernel-6.5.11-7-pve-signed: 6.5.11-7
proxmox-kernel-6.5.11-6-pve-signed: 6.5.11-6
proxmox-kernel-6.5.11-4-pve-signed: 6.5.11-4
proxmox-kernel-6.2.16-20-pve: 6.2.16-20
proxmox-kernel-6.2: 6.2.16-20
pve-kernel-6.2.16-3-pve: 6.2.16-3
ceph-fuse: 17.2.6-pve1+3
corosync: 3.1.7-pve3
criu: 3.17.1-2
glusterfs-client: 10.3-5
ifupdown2: 3.2.0-1+pmx7
ksm-control-daemon: 1.4-1
libjs-extjs: 7.0.0-4
libknet1: 1.28-pve1
libproxmox-acme-perl: 1.5.0
libproxmox-backup-qemu0: 1.4.1
libproxmox-rs-perl: 0.3.1
libpve-access-control: 8.0.7
libpve-apiclient-perl: 3.3.1
libpve-common-perl: 8.1.0
libpve-guest-common-perl: 5.0.6
libpve-http-server-perl: 5.0.5
libpve-network-perl: 0.9.5
libpve-rs-perl: 0.8.7
libpve-storage-perl: 8.0.5
libspice-server1: 0.15.1-1
lvm2: 2.03.16-2
lxc-pve: 5.0.2-4
lxcfs: 5.0.3-pve4
novnc-pve: 1.4.0-3
proxmox-backup-client: 3.1.2-1
proxmox-backup-file-restore: 3.1.2-1
proxmox-kernel-helper: 8.1.0
proxmox-mail-forward: 0.2.2
proxmox-mini-journalreader: 1.4.0
proxmox-widget-toolkit: 4.1.3
pve-cluster: 8.0.5
pve-container: 5.0.8
pve-docs: 8.1.3
pve-edk2-firmware: 4.2023.08-2
pve-firewall: 5.0.3
pve-firmware: 3.9-1
pve-ha-manager: 4.0.3
pve-i18n: 3.1.4
pve-qemu-kvm: 8.1.2-4
pve-xtermjs: 5.3.0-2
qemu-server: 8.0.10
smartmontools: 7.3-pve1
spiceterm: 3.3.0
swtpm: 0.8.0+pve1
vncterm: 1.8.0
zfsutils-linux: 2.2.2-pve1

RolandK · Dec 13, 2023

there is a bugzilla report for this: https://bugzilla.proxmox.com/show_bug.cgi?id=4816

Lucaaa · Dec 13, 2023

The issue seems originating from this:

Code:

ipcc_send_rec[1] failed: Permission denied

Lucaaa · Dec 13, 2023

This is generating timeouts over the Proxmox Web interface.

RolandK · Dec 13, 2023

where do you see this message?

Lucaaa · Dec 13, 2023

journalctl

RolandK · Dec 16, 2023

in which log/unit exactly ?

dperezu76 · Mar 12, 2024

Someone know that is it the issue i have the same problem?

jellium · May 9, 2024

I had

RolandK said:
in which log/unit exactly ?

I believe `journalctl -f -b 0` for instance.

jellium · May 9, 2024

I had the same problem.
I don't know where it originated from.
For what it's worth, after restarting pveproxy (with command pveproxy restart) the error no longer shows up.

pagalba-com · Sep 27, 2024

jellium said:
I had the same problem.
I don't know where it originated from.
For what it's worth, after restarting pveproxy (with command pveproxy restart) the error no longer shows up.

same here, systemctl restart pveproxy made it go away.

Search

Search

detected empty handle

smileluo

Member

dcsapak

Proxmox Staff Member

smileluo

Member

RolandK

Renowned Member

RolandK

Renowned Member

Lucaaa

Member

RolandK

Renowned Member

Lucaaa

Member

Lucaaa

Member

RolandK

Renowned Member

Lucaaa

Member

RolandK

Renowned Member

dperezu76

New Member

jellium

New Member

jellium

New Member

pagalba-com

New Member