Plesk 9.2.3: New Postfix error "Unprocessed command"

[ISSchuster]

Same here... Nothing changed... Unbelievable...

Dec 13 18:42:14 kallisto before-queue[683]: Unprocessed command: .0pt;
Dec 13 18:42:14 kallisto before-remote[684]: Unprocessed command: .0pt;
Dec 13 18:45:00 kallisto before-queue[996]: Unprocessed command: .0pt;
Dec 13 18:45:00 kallisto before-remote[997]: Unprocessed command: .0pt;
Dec 13 18:47:46 kallisto before-queue[1133]: Unprocessed command: .0pt;
Dec 13 18:47:46 kallisto before-remote[1134]: Unprocessed command: .0pt;
Dec 13 18:50:32 kallisto before-queue[1483]: Unprocessed command: .0pt;
Dec 13 18:50:32 kallisto before-remote[1484]: Unprocessed command: .0pt;
Dec 13 18:53:17 kallisto before-queue[1608]: Unprocessed command: .0pt;
Dec 13 18:53:17 kallisto before-remote[1609]: Unprocessed command: .0pt;
Dec 13 19:18:51 kallisto before-queue[3851]: Unprocessed command: eadlines2
Dec 13 19:18:51 kallisto before-remote[3853]: Unprocessed command: eadlines2
Dec 13 19:56:30 kallisto before-remote[7024]: Unprocessed command:
Dec 13 20:37:50 kallisto before-queue[11370]: Unprocessed command: eadlines2
Dec 13 20:37:50 kallisto before-remote[11371]: Unprocessed command: eadlines2
Dec 13 21:19:50 kallisto before-remote[14677]: Unprocessed command:
Dec 13 21:21:18 kallisto before-queue[14788]: Unprocessed command:
Dec 13 21:21:18 kallisto before-remote[14790]: Unprocessed command:
Dec 13 21:57:59 kallisto before-queue[18400]: Unprocessed command: eadlines2
Dec 13 21:57:59 kallisto before-remote[18401]: Unprocessed command: eadlines2
Dec 13 22:43:10 kallisto before-remote[22188]: Unprocessed command:
Dec 13 23:20:27 kallisto before-queue[26628]: Unprocessed command: eadlines2
Dec 13 23:20:28 kallisto before-remote[26630]: Unprocessed command: eadlines2
Dec 14 00:06:30 kallisto before-remote[30873]: Unprocessed command:

 

[IgorG]

I have informed developers about problems with provided fix. They are working on it. I will update this thread with results as soon as I receive it.

 

[IgorG]

Can anybody provide a full message for reproducing this problem with installed fix? I will show to developers.

 

[mfichtner]

Can anybody provide a full message for reproducing this problem with installed fix? I will show to developers.

I didn't see this bug again after installing the fix mentioned above. But now, after installing "Parallels Plesk Panel 9.2.3 Update 1", which -- presumably -- should include that same fix, the bug is back.

Attached is a message that has triggered the "Unprocessed command" error described above. I was able to grab the complete content of this message because it was sent from another one of my own servers (which uses neither Plesk nor Postfix). So I had access to the mail queue of the sending machine.

One aspect that might be interesting to the developers: I was able to "fix" this message by opening it in a text editor and saving it in a manner that ensures all line-ending are proper CRLF sequences. When the server tried to re-send the "fixed" message a couple of minutes later, it went through without triggering any errors on the Plesk/Postfix machine.

So, it looks like the "Unprocessed command" bug might be triggered by messages that use improper line-endings or that contain a mix of both CRLF sequences and isolated LF characters.

Hope this helps!

 

[mfichtner]

Here is workaround for fixing this problem. Please try it and update this thread with results.

Can this workaround still be used after installing "Parallels Plesk Panel 9.2.3 Update 1" (a.k.a. psa-hotfix3-9.2.3)? Or would that break Postfix?

 

[Raymond Smith]

We are also habing this issue

We installed the patch, interesting that it is almost 100K larger than the original file and we are still getting:

Jan 7 08:35:41 fido before-remote[10096]: Unprocessed command:
Jan 7 08:35:41 fido before-remote[9520]: Unprocessed command:
Jan 7 08:39:20 fido before-queue[11810]: Unprocessed command:
Jan 7 08:39:20 fido before-remote[11811]: Unprocessed command:
Jan 7 08:42:04 fido before-remote[11030]: Unprocessed command:
Jan 7 08:42:32 fido before-remote[11225]: Unprocessed command: mmessage
Jan 7 08:42:32 fido before-remote[11225]: Unprocessed command: margin:0px=3b
Jan 7 08:42:32 fido before-queue[11224]: Unprocessed command: {
Jan 7 08:44:07 fido before-remote[11741]: Unprocessed command: .style3
Jan 7 08:44:07 fido before-remote[11741]: Unprocessed command:
Jan 7 08:44:07 fido before-queue[11740]: Unprocessed command:
Jan 7 08:44:20 fido before-remote[11819]: Unprocessed command:
Jan 7 08:46:03 fido before-remote[12349]: Unprocessed command: .style3
Jan 7 08:46:03 fido before-remote[12349]: Unprocessed command:
Jan 7 08:46:03 fido before-queue[12348]: Unprocessed command:
Jan 7 08:46:36 fido before-remote[12556]: Unprocessed command:
Jan 7 08:48:12 fido before-remote[13012]: Unprocessed command: mmessage
Jan 7 08:48:12 fido before-remote[13012]: Unprocessed command: margin:0px=3b
Jan 7 08:48:12 fido before-queue[13011]: Unprocessed command: {
Jan 7 08:48:52 fido before-remote[13152]: Unprocessed command:
Jan 7 08:51:02 fido before-remote[13619]: Unprocessed command: .style3
Jan 7 08:51:02 fido before-remote[13619]: Unprocessed command:
Jan 7 08:51:02 fido before-queue[13618]: Unprocessed command:
Jan 7 08:51:08 fido before-remote[13650]: Unprocessed command:
Jan 7 08:52:44 fido before-remote[12881]: Unprocessed command:
Jan 7 08:53:23 fido before-remote[14356]: Unprocessed command:
Jan 7 08:53:52 fido before-remote[14455]: Unprocessed command: mmessage
Jan 7 08:53:52 fido before-remote[14455]: Unprocessed command: margin:0px=3b
Jan 7 08:53:52 fido before-queue[14454]: Unprocessed command: {
Jan 7 08:54:45 fido before-remote[13303]: Unprocessed command:
Jan 7 08:55:43 fido before-remote[14942]: Unprocessed command:
Jan 7 08:57:56 fido before-remote[15707]: Unprocessed command:
Jan 7 08:59:33 fido before-remote[16108]: Unprocessed command: mmessage
Jan 7 08:59:33 fido before-remote[16108]: Unprocessed command: margin:0px=3b
Jan 7 08:59:33 fido before-queue[16107]: Unprocessed command: {
Jan 7 09:00:12 fido before-remote[16357]: Unprocessed command:
Jan 7 09:01:04 fido before-remote[16653]: Unprocessed command: .style3
Jan 7 09:01:04 fido before-remote[16653]: Unprocessed command:
Jan 7 09:01:04 fido before-queue[16652]: Unprocessed command:
Jan 7 09:02:28 fido before-remote[17121]: Unprocessed command:
Jan 7 09:04:05 fido before-remote[17688]: Unprocessed command: .style3
Jan 7 09:04:05 fido before-remote[17688]: Unprocessed command:
Jan 7 09:04:05 fido before-queue[17687]: Unprocessed command:
Jan 7 09:04:44 fido before-remote[17843]: Unprocessed command:
Jan 7 09:05:13 fido before-remote[17989]: Unprocessed command: mmessage
Jan 7 09:05:13 fido before-remote[17989]: Unprocessed command: margin:0px=3b
Jan 7 09:05:13 fido before-queue[17988]: Unprocessed command: {
Jan 7 09:07:00 fido before-remote[20444]: Unprocessed command:


Also I get a message to postmaster for each one.....

 

[IgorG]

I have updated mentioned workaround with new version of patched files. Please try it and update thread with results.

 

[NateC]

My server's been updated with the newest patch, I will post a further update after I let it bake awhile.

 

[NateC]

Still occasional errors, different and not as common tho:

Feb 1 15:04:36 plesk-chi postfix/smtpd[10897]: warning: timeout talking to proxy 127.0.0.1:10025
Feb 1 15:04:36 plesk-chi before-queue[10900]: Lost connection
Feb 1 15:04:36 plesk-chi before-queue[10900]: Some error occured
Feb 1 15:04:36 plesk-chi postfix/spawn[10761]: warning: command /usr/lib/plesk-9.0/postfix-queue exit status 2
55
Feb 1 15:04:36 plesk-chi before-remote[10901]: Lost connection
Feb 1 15:04:36 plesk-chi before-remote[10901]: Some error occured
Feb 1 15:04:36 plesk-chi postfix/smtpd[10902]: disconnect from localhost[127.0.0.1]
Feb 1 15:04:36 plesk-chi postfix/spawn[10763]: warning: command /usr/lib/plesk-9.0/postfix-queue exit status 2
55

Could be I'm just not allowing enough time, but the messages that have issues were not large.

The binary with md5sum 'f8ad3bc68202fac408c71bbbb7d2a9d8' still works fine for me.. think it was from Plesk 9.2.x.

 

[karesmakro]

I can confirm this issue. Sometimes, there are bounced messages belongs to unprocessed commands. Most time this problem concerns mailinglists. But never had the chance, to get this bounced mail.
Today a new status report from mailinglist debian.org arrived about bounced mails and ,thanks to debian.org, they gave me a link, to view the bounced mail, which is in attachement.

System: Debian Etch
architecture: 64-bit
Plesk 9.2.3 (but not installed update from dec)

@support: can you please remove the attachement after download? Thanks

 

[karesmakro]

One update: I've installed the update, but nothing changed.
Since two days I've a problem again with a newsletter sender. What I can see, if process for mail accepting is starting, there are generated two postfix-queue instances, which will never end!

Is there another resolution, for get postfix working correctly? I don't wan't to change back to qmail!

I let you know, this is a untolerable situation and not acceptable, so my last way is to change the system, if I found the time.

 

[IgorG]

Please confirm that you have installed patch for fixing "Unprocessed command" issue and you have these errors in maillog? If it is true - submit ticket to support team for the further investigation and fixing. You will be refunded for this ticket if fix for this bug really doesn't work for you and it is confirmed by support.