Error: parse_rfc_3339 failed - wrong length at line 1 column 60 (500)

[dcsapak]

i do not think that this error has anything to do with storage, but i am unable to reproduce it until now...

 

[ferrets]

i do not think that this error has anything to do with storage, but i am unable to reproduce it until now...

I've met the same problem, backup task report error on pve cluster, like

INFO: Finished Backup of VM 111 (00:00:05)
INFO: Backup finished at 2020-10-02 01:45:08
ERROR: Backup job failed - upload log failed: Error: parse_rfc_3339 failed - wrong length at line 1 column 60

TASK ERROR: upload log failed: Error: parse_rfc_3339 failed - wrong length at line 1 column 60

the backup seems finished and pbs is able to confirm and verify the backup, except the pve cluster has some error log and stop the backup process after the first vm backup.

the backup can be done by adding multiple backup tasks, one vm each, but the cluster is filled by error logs.


I've done some google about rfc 3339, it's about timestamp. But even I've synchronized the time, I still got this error.

 

[dcsapak]

I've met the same problem, backup task report error on pve cluster, like

can you post the output of 'pveversion -v' of the cluster and proxmox-backup-client version --repository "yourrepository"

 

[ferrets]

can you post the output of 'pveversion -v' of the cluster and proxmox-backup-client version --repository "yourrepository"

root@pve2:~# pveversion -v
proxmox-ve: 6.2-2 (running kernel: 5.4.60-1-pve)
pve-manager: 6.2-12 (running version: 6.2-12/b287dd27)
pve-kernel-5.4: 6.2-7
pve-kernel-helper: 6.2-7
pve-kernel-5.4.65-1-pve: 5.4.65-1
pve-kernel-5.4.60-1-pve: 5.4.60-2
pve-kernel-5.4.34-1-pve: 5.4.34-2
ceph-fuse: 12.2.11+dfsg1-2.1+b1
corosync: 3.0.4-pve1
criu: 3.11-3
glusterfs-client: 5.5-3
ifupdown: residual config
ifupdown2: 3.0.0-1+pve3
ksm-control-daemon: 1.3-1
libjs-extjs: 6.0.1-10
libknet1: 1.16-pve1
libproxmox-acme-perl: 1.0.5
libpve-access-control: 6.1-2
libpve-apiclient-perl: 3.0-3
libpve-common-perl: 6.2-2
libpve-guest-common-perl: 3.1-3
libpve-http-server-perl: 3.0-6
libpve-storage-perl: 6.2-6
libqb0: 1.0.5-1
libspice-server1: 0.14.2-4~pve6+1
lvm2: 2.03.02-pve4
lxc-pve: 4.0.3-1
lxcfs: 4.0.3-pve3
novnc-pve: 1.1.0-1
proxmox-backup-client: 0.8.21-1
proxmox-mini-journalreader: 1.1-1
proxmox-widget-toolkit: 2.2-12
pve-cluster: 6.1-8
pve-container: 3.2-2
pve-docs: 6.2-6
pve-edk2-firmware: 2.20200531-1
pve-firewall: 4.1-3
pve-firmware: 3.1-3
pve-ha-manager: 3.1-1
pve-i18n: 2.2-1
pve-qemu-kvm: 5.1.0-2
pve-xtermjs: 4.7.0-2
qemu-server: 6.2-14
smartmontools: 7.1-pve2
spiceterm: 3.1-1
vncterm: 1.6-2
zfsutils-linux: 0.8.4-pve1

root@pve2:~# proxmox-backup-client version
client version: 0.8.21

not sure what is "yourrepository" , but about the apt repo, I've added a "pve-no-subscription", a file with something like this

root@pve2:/etc/apt/sources.list.d# cat pve-no-subscription.list
deb http://download.proxmox.com/debian/pve buster pve-no-subscription

 

[arteck]

INFO: Finished Backup of VM 111 (00:00:05)
INFO: Backup finished at 2020-10-02 01:45:08
ERROR: Backup job failed - upload log failed: Error: parse_rfc_3339 failed - wrong length at line 1 column 60

TASK ERROR: upload log failed: Error: parse_rfc_3339 failed - wrong length at line 1 column 60

check your storage settings ..the crypto key was my problem in vers 0.9.0.. deactivate this option help

 

[ferrets]

check your storage settings ..the crypto key was my problem in vers 0.9.0.. deactivate this option help

nailed it! problem solved. thank you for the reply.
and I think I have to redo all the backups.

 

[fabian]

could you please post the strings stored under 'created' and 'modified' in /etc/pve/priv/storage/STORAGEID.enc (where STORAGEID is the storage ID of your PBS storage)? note: don't post the 'data' string, it contains the actual encryption key data!!

 

[ferrets]

could you please post the strings stored under 'created' and 'modified' in /etc/pve/priv/storage/STORAGEID.enc (where STORAGEID is the storage ID of your PBS storage)? note: don't post the 'data' string, it contains the actual encryption key data!!

after remove encryption key and re added, no error seen....
maybe install a older package and upgrade to 0.8.21 can reproduce the problem?

 

[shartenauer]

after remove encryption key and re added, no error seen....
maybe install a older package and upgrade to 0.8.21 can reproduce the problem?

The problem is the creation of the encryption key via GUI.

Encryption key created with GUI:
{"kdf":null,"created":"2020-10-09T19:50:48.853858383+02:00","modified":"2020-10-09T19:50:48.853858383+02:00","data":"qA7c3YMtAospGDSZkSOV/ibhaUfa0TH0TyyPPw0bO2s="}

Encryption key created with Console - pvesm set <storage-id> --encryption-key autogen:
{"kdf":null,"created":"2020-10-09T20:19:33+02:00","modified":"2020-10-09T20:19:33+02:00","data":"qUgj7Czgv0K9FQFQKUYeEn7Oog++Z1nZO4K71Edb0hw="}

When I create the encryption key with the console everything is fine.

Best regards
Stephan

 

[ferrets]

The problem is the creation of the encryption key via GUI.

Encryption key created with GUI:
{"kdf":null,"created":"2020-10-09T19:50:48.853858383+02:00","modified":"2020-10-09T19:50:48.853858383+02:00","data":"qA7c3YMtAospGDSZkSOV/ibhaUfa0TH0TyyPPw0bO2s="}

Encryption key created with Console - pvesm set <storage-id> --encryption-key autogen:
{"kdf":null,"created":"2020-10-09T20:19:33+02:00","modified":"2020-10-09T20:19:33+02:00","data":"qUgj7Czgv0K9FQFQKUYeEn7Oog++Z1nZO4K71Edb0hw="}

When I create the encryption key with the console everything is fine.

Best regards
Stephan

after upgrade to version 0.9, looks like the problem had been solved.

 

[shartenauer]

after upgrade to version 0.9, looks like the problem had been solved.

No, the problem is also in version 0.9 of PBS

 

[fabian]

No, the problem is also in version 0.9 of PBS

you need to remove the subsecond parts from the timestamps. those were only generated by some old versions. a newly generated key should never have those parts added, no matter whether with the GUI or with the CLI (both run the same command).

 

[shartenauer]

you need to remove the subsecond parts from the timestamps. those were only generated by some old versions. a newly generated key should never have those parts added, no matter whether with the GUI or with the CLI (both run the same command).

Yes, that's true, if I remove the additional parts of the timestamp it is working.
But if I create the encryption key with CLI it's ok, with the GUI it's not.
Both created with PBS 0.9.

 

[fabian]

Yes, that's true, if I remove the additional parts of the timestamp it is working.
But if I create the encryption key with CLI it's ok, with the GUI it's not.
Both created with PBS 0.9.

is this a cluster? if so, maybe the node that the GUI call gets executed on is outdated? the GUi and pvesm make the same call to 'proxmox-backup-client' ..

 

[linum]

I also get the following error:

ERROR: Backup job failed - upload log failed: Error: parse_rfc_3339 failed - wrong length at line 1 column 60

The backup server is a target for 3 proxmox servers. Two of them can backup just fine, only one fail with this error.

The complete log is:

INFO: starting new backup job: vzdump --mailnotification always --compress zstd --storage baku-povi --quiet 1 --mailto bigbrother@linum.com --all 1 --mode snapshot
INFO: Starting Backup of VM 7206 (qemu)
INFO: Backup started at 2020-10-15 09:15:02
INFO: status = running
INFO: VM Name: anolo.office
INFO: include disk 'scsi0' 'zfs03:vm-7206-disk-0' 64G
INFO: backup mode: snapshot
INFO: ionice priority: 7
INFO: creating Proxmox Backup Server archive 'vm/7206/2020-10-15T07:15:02Z'
INFO: issuing guest-agent 'fs-freeze' command
INFO: enabling encryption
INFO: issuing guest-agent 'fs-thaw' command
INFO: started backup task '93f10849-5db6-4e4a-a29e-2c8d0958ba9f'
INFO: resuming VM again
INFO: scsi0: dirty-bitmap status: OK (168.0 MiB of 64.0 GiB dirty)
INFO: using fast incremental mode (dirty-bitmap), 168.0 MiB dirty of 64.0 GiB total
INFO: 100% (168.0 MiB of 168.0 MiB) in  2s, read: 84.0 MiB/s, write: 78.0 MiB/s
INFO: backup was done incrementally, reused 63.85 GiB (99%)
INFO: transferred 168.00 MiB in 2 seconds (84.0 MiB/s)
INFO: Finished Backup of VM 7206 (00:00:03)
INFO: Backup finished at 2020-10-15 09:15:05
ERROR: Backup job failed - upload log failed: Error: parse_rfc_3339 failed - wrong length at line 1 column 60

TASK ERROR: upload log failed: Error: parse_rfc_3339 failed - wrong length at line 1 column 60

The pveversion -v output from this backup client system:

pve-manager: 6.2-12 (running version: 6.2-12/b287dd27)
pve-kernel-5.4: 6.2-7
pve-kernel-helper: 6.2-7
pve-kernel-5.4.65-1-pve: 5.4.65-1
pve-kernel-5.4.60-1-pve: 5.4.60-2
ceph-fuse: 12.2.13-pve1
corosync: 3.0.4-pve1
criu: 3.11-3
glusterfs-client: 5.5-3
ifupdown: 0.8.35+pve1
ksm-control-daemon: 1.3-1
libjs-extjs: 6.0.1-10
libknet1: 1.16-pve1
libproxmox-acme-perl: 1.0.5
libpve-access-control: 6.1-3
libpve-apiclient-perl: 3.0-3
libpve-common-perl: 6.2-2
libpve-guest-common-perl: 3.1-3
libpve-http-server-perl: 3.0-6
libpve-storage-perl: 6.2-8
libqb0: 1.0.5-1
libspice-server1: 0.14.2-4~pve6+1
lvm2: 2.03.02-pve4
lxc-pve: 4.0.3-1
lxcfs: 4.0.3-pve3
novnc-pve: 1.1.0-1
proxmox-backup-client: 0.9.0-2
proxmox-mini-journalreader: 1.1-1
proxmox-widget-toolkit: 2.3-1
pve-cluster: 6.2-1
pve-container: 3.2-2
pve-docs: 6.2-6
pve-edk2-firmware: 2.20200531-1
pve-firewall: 4.1-3
pve-firmware: 3.1-3
pve-ha-manager: 3.1-1
pve-i18n: 2.2-1
pve-qemu-kvm: 5.1.0-3
pve-xtermjs: 4.7.0-2
qemu-server: 6.2-15
smartmontools: 7.1-pve2
spiceterm: 3.1-1
vncterm: 1.6-2
zfsutils-linux: 0.8.4-pve2

And the pversion from the backup server:

pve-manager: 6.2-12 (running version: 6.2-12/b287dd27)
pve-kernel-5.4: 6.2-7
pve-kernel-helper: 6.2-7
pve-kernel-5.4.65-1-pve: 5.4.65-1
ceph-fuse: 12.2.11+dfsg1-2.1+b1
corosync: 3.0.4-pve1
criu: 3.11-3
glusterfs-client: 5.5-3
ifupdown: 0.8.35+pve1
ksm-control-daemon: 1.3-1
libjs-extjs: 6.0.1-10
libknet1: 1.16-pve1
libproxmox-acme-perl: 1.0.5
libpve-access-control: 6.1-3
libpve-apiclient-perl: 3.0-3
libpve-common-perl: 6.2-2
libpve-guest-common-perl: 3.1-3
libpve-http-server-perl: 3.0-6
libpve-storage-perl: 6.2-8
libqb0: 1.0.5-1
libspice-server1: 0.14.2-4~pve6+1
lvm2: 2.03.02-pve4
lxc-pve: 4.0.3-1
lxcfs: 4.0.3-pve3
novnc-pve: 1.1.0-1
proxmox-backup-client: 0.9.1-1
proxmox-mini-journalreader: 1.1-1
proxmox-widget-toolkit: 2.3-1
pve-cluster: 6.2-1
pve-container: 3.2-2
pve-docs: 6.2-6
pve-edk2-firmware: 2.20200531-1
pve-firewall: 4.1-3
pve-firmware: 3.1-3
pve-ha-manager: 3.1-1
pve-i18n: 2.2-1
pve-qemu-kvm: 5.1.0-3
pve-xtermjs: 4.7.0-2
qemu-server: 6.2-15
smartmontools: 7.1-pve2
spiceterm: 3.1-1
vncterm: 1.6-2
zfsutils-linux: 0.8.4-pve2

 

[fabian]

please remove the subsecond part of the timestamps in /etc/pve/priv/storage/STORAGEID.enc for that storage definition.

 

[linum]

please remove the subsecond part of the timestamps in /etc/pve/priv/storage/STORAGEID.enc for that storage definition.

Thank you very much, that fixed the problems. Sorry for the noise, I didn't read this in the thread before.

 

[fabian]

no worries. outside of a beta we would have cleaned this up automatically in the parser, but at the moment we try to keep the code lean even if it means not remaining 100% compatible sometimes.

 

[linum]

no worries. outside of a beta we would have cleaned this up automatically in the parser, but at the moment we try to keep the code lean even if it means not remaining 100% compatible sometimes.

Understandable!

And just to note it: The backupserver is awesome! Just a few settings and the backup is really secure even for the common ransomware & stuff like this. Nice work!