Bug 129160 - dev-perl/net-server-0.93 causes amavisd to break
Bug#: 129160 Product:  Gentoo Linux Version: unspecified Platform: All
OS/Version: Other Status: RESOLVED Severity: normal Priority: P2
Resolution: FIXED Assigned To: perl@gentoo.org Reported By: eradicator@gentoo.org
Component: Core system
URL: 
Summary: dev-perl/net-server-0.93 causes amavisd to break
Keywords:  
Status Whiteboard: 
Opened: 2006-04-07 11:52 0000
Description:   Opened: 2006-04-07 11:52 0000
amavis is listening on port 10024...

w/0.93 $ echo "Test message" | smtpclient -S localhost -P 10024 my@email.com
SMTPclient: unexpected reply: 451 4.5.0 Error in processing, id=31584-01,
parts_decode_ext FAILED: parsing file(1) results - missing last 1 results at
(eval 44) line 154.

downgrade to 0.90...

w/0.90 $ echo "Test message" | smtpclient -S localhost -P 10024 my@email.com
SMTPclient: delivery: 250 2.6.0 Ok, id=00481-01, from MTA([127.0.0.1]:10025):
250 Ok: queued as 11EE6304B1

In amavisd's log:
Apr  7 11:51:12 mail.outersquare.org /usr/sbin/amavisd[1521]: Net::Server:
2006/04/07-11:51:12 CONNECT TCP Peer: "127.0.0.1:54576" Local:
"127.0.0.1:10024"
Apr  7 11:51:12 mail.outersquare.org /usr/sbin/amavisd[1521]: loaded base
policy bank
Apr  7 11:51:12 mail.outersquare.org /usr/sbin/amavisd[1521]: lookup_ip_acl
(inet_acl): key="127.0.0.1" matches "127.0.0.1", result=1
Apr  7 11:51:12 mail.outersquare.org /usr/sbin/amavisd[1521]: prolong_timer
after new request - timer reset: remaining time = 300 s
Use of uninitialized value in concatenation (.) or string at /usr/sbin/amavisd
line 6741.
Apr  7 11:51:12 mail.outersquare.org /usr/sbin/amavisd[1521]: process_request:
suggested_protocol="" on TCP
Use of uninitialized value in string eq at /usr/sbin/amavisd line 6757.
Use of uninitialized value in string eq at /usr/sbin/amavisd line 6757.
Use of uninitialized value in string eq at /usr/sbin/amavisd line 6769.
Use of uninitialized value in concatenation (.) or string at (eval 39) line
190.
Use of uninitialized value in concatenation (.) or string at (eval 39) line
190.
Use of uninitialized value in concatenation (.) or string at (eval 39) line
190.
Apr  7 11:51:12 mail.outersquare.org /usr/sbin/amavisd[1521]: (01521-01) SMTP>
220 [127.0.0.1] ESMTP amavisd-new service ready
Use of uninitialized value in sprintf at /usr/sbin/amavisd line 1311.
Apr  7 11:51:12 mail.outersquare.org /usr/sbin/amavisd[1521]: (01521-01)
idle_proc, 4: was busy, 5.0 ms, total idle 0.000 s, busy 0.005 s
Apr  7 11:51:12 mail.outersquare.org /usr/sbin/amavisd[1521]: (01521-01)
idle_proc, 5: was idle, 0.7 ms, total idle 0.001 s, busy 0.005 s
Apr  7 11:51:12 mail.outersquare.org /usr/sbin/amavisd[1521]: (01521-01)
prolong_timer after reading SMTP command: remaining time = 300 s
Apr  7 11:51:12 mail.outersquare.org /usr/sbin/amavisd[1521]: (01521-01) SMTP<
HELO cloud.cs.berkeley.edu\r\n
Apr  7 11:51:12 mail.outersquare.org /usr/sbin/amavisd[1521]: (01521-01) SMTP>
250 [127.0.0.1]
Apr  7 11:51:12 mail.outersquare.org /usr/sbin/amavisd[1521]: (01521-01)
idle_proc, 6: was busy, 1.1 ms, total idle 0.001 s, busy 0.006 s
Apr  7 11:51:12 mail.outersquare.org /usr/sbin/amavisd[1521]: (01521-01)
idle_proc, 5: was idle, 0.2 ms, total idle 0.001 s, busy 0.006 s
Apr  7 11:51:12 mail.outersquare.org /usr/sbin/amavisd[1521]: (01521-01)
prolong_timer after reading SMTP command: remaining time = 300 s
Apr  7 11:51:12 mail.outersquare.org /usr/sbin/amavisd[1521]: (01521-01) SMTP<
MAIL FROM: <root@cloud.cs.berkeley.edu>\r\n
Apr  7 11:51:12 mail.outersquare.org /usr/sbin/amavisd[1521]: (01521-01)
prolong_timer after MAIL FROM received - timer reset: remaining time = 300 s
Apr  7 11:51:12 mail.outersquare.org /usr/sbin/amavisd[1521]: (01521-01)
check_mail_begin_task: task_count=1
Apr  7 11:51:12 mail.outersquare.org /usr/sbin/amavisd[1521]: (01521-01)
prepare_tempdir: creating directory
/var/amavis/tmp/amavis-20060407T115112-01521
Apr  7 11:51:12 mail.outersquare.org /usr/sbin/amavisd[1521]: (01521-01)
prepare_tempdir: creating file
/var/amavis/tmp/amavis-20060407T115112-01521/email.txt
Use of uninitialized value in string ne at (eval 39) line 399, <GEN4> line 2.
Use of uninitialized value in split at (eval 39) line 435, <GEN4> line 2.
Apr  7 11:51:12 mail.outersquare.org /usr/sbin/amavisd[1521]: (01521-01) SMTP>
250 2.1.0 Sender root@cloud.cs.berkeley.edu OK
Apr  7 11:51:12 mail.outersquare.org /usr/sbin/amavisd[1521]: (01521-01) lookup
(debug_sender) => undef, "root@cloud.cs.berkeley.edu" does not match
Apr  7 11:51:12 mail.outersquare.org /usr/sbin/amavisd[1521]: (01521-01)
idle_proc, 6: was busy, 4.3 ms, total idle 0.001 s, busy 0.010 s
Apr  7 11:51:12 mail.outersquare.org /usr/sbin/amavisd[1521]: (01521-01)
idle_proc, 5: was idle, 0.3 ms, total idle 0.001 s, busy 0.010 s
Apr  7 11:51:12 mail.outersquare.org /usr/sbin/amavisd[1521]: (01521-01)
prolong_timer after reading SMTP command: remaining time = 300 s
Apr  7 11:51:12 mail.outersquare.org /usr/sbin/amavisd[1521]: (01521-01) SMTP<
RCPT TO: <my@email.com>\r\n
Use of uninitialized value in string ne at (eval 39) line 505, <GEN4> line 3.
Use of uninitialized value in numeric gt (>) at (eval 39) line 519, <GEN4> line
3.
Use of uninitialized value in numeric gt (>) at (eval 39) line 519, <GEN4> line
3.
Apr  7 11:51:12 mail.outersquare.org /usr/sbin/amavisd[1521]: (01521-01) SMTP>
250 2.1.5 Recipient my@email.com OK
Apr  7 11:51:12 mail.outersquare.org /usr/sbin/amavisd[1521]: (01521-01)
idle_proc, 6: was busy, 1.2 ms, total idle 0.001 s, busy 0.012 s
Apr  7 11:51:12 mail.outersquare.org /usr/sbin/amavisd[1521]: (01521-01)
idle_proc, 5: was idle, 0.2 ms, total idle 0.001 s, busy 0.012 s
Apr  7 11:51:12 mail.outersquare.org /usr/sbin/amavisd[1521]: (01521-01)
prolong_timer after reading SMTP command: remaining time = 300 s
Apr  7 11:51:12 mail.outersquare.org /usr/sbin/amavisd[1521]: (01521-01) SMTP<
DATA\r\n
Use of uninitialized value in string ne at (eval 39) line 226, <GEN4> line 4.
Apr  7 11:51:12 mail.outersquare.org /usr/sbin/amavisd[1521]: (01521-01)
prolong_timer after DATA received - timer reset: remaining time = 300 s
Use of uninitialized value in string eq at (eval 39) line 559, <GEN4> line 4.
Use of uninitialized value in string eq at (eval 39) line 559, <GEN4> line 4.
Apr  7 11:51:12 mail.outersquare.org /usr/sbin/amavisd[1521]: (01521-01)
SMTP::10024 /var/amavis/tmp/amavis-20060407T115112-01521:
<root@cloud.cs.berkeley.edu> -> <my@email.com> Received: from
cloud.cs.berkeley.edu ([127.0.0.1]) by localhost (mail.outersquare.org
[127.0.0.1]) (amavisd-new, port 10024) with SMTP id 01521-01 for
<my@email.com>; Fri,  7 Apr 2006 11:51:12 -0700 (PDT)
Apr  7 11:51:12 mail.outersquare.org /usr/sbin/amavisd[1521]: (01521-01) SMTP>
354 End data with <CR><LF>.<CR><LF>
Use of uninitialized value in numeric eq (==) at (eval 39) line 575, <GEN4>
line 4.
Apr  7 11:51:12 mail.outersquare.org /usr/sbin/amavisd[1521]: (01521-01) SMTP<
.\r\n
Apr  7 11:51:12 mail.outersquare.org /usr/sbin/amavisd[1521]: (01521-01)
setting body type: 7BIT (0,0)
Apr  7 11:51:12 mail.outersquare.org /usr/sbin/amavisd[1521]: (01521-01) body
hash: 33fed2341aa0242c069aa645e36c0f9e
Apr  7 11:51:12 mail.outersquare.org /usr/sbin/amavisd[1521]: (01521-01)
Original mail size: 104; quota set to: 102400 bytes
Use of uninitialized value in concatenation (.) or string at /usr/sbin/amavisd
line 6975, <GEN5> line 4.
Use of uninitialized value in string eq at /usr/sbin/amavisd line 7004, <GEN5>
line 4.
Apr  7 11:51:12 mail.outersquare.org /usr/sbin/amavisd[1521]: (01521-01)
Checking: lIdlHBtZeNO6 <root@cloud.cs.berkeley.edu> -> <my@email.com>
Use of uninitialized value in string ne at /usr/sbin/amavisd line 2226, <GEN5>
line 4.
Apr  7 11:51:12 mail.outersquare.org /usr/sbin/amavisd[1521]: (01521-01)
query_keys: my@email.com, my@, email.com, .email.com, .com, .
Use of uninitialized value in concatenation (.) or string at /usr/sbin/amavisd
line 2260, <GEN5> line 4.
Apr  7 11:51:12 mail.outersquare.org /usr/sbin/amavisd[1521]: (01521-01)
lookup_hash(my@email.com), no matches
Apr  7 11:51:12 mail.outersquare.org /usr/sbin/amavisd[1521]: (01521-01) lookup
(bypass_virus_checks) => undef, "my@email.com" does not match
Apr  7 11:51:12 mail.outersquare.org /usr/sbin/amavisd[1521]: (01521-01)
Extracting mime components
Apr  7 11:51:12 mail.outersquare.org /usr/sbin/amavisd[1521]: (01521-01) Issued
a new file name: p001
Apr  7 11:51:12 mail.outersquare.org /usr/sbin/amavisd[1521]: (01521-01)
Charging 13 bytes to remaining quota 102400 (out of 102400, (0%)) - by
mime_decode
Use of uninitialized value in concatenation (.) or string at /usr/sbin/amavisd
line 5518.
Apr  7 11:51:12 mail.outersquare.org /usr/sbin/amavisd[1521]: (01521-01) p001 1
Content-Type: text/plain, size: 13 B, name: 
Use of uninitialized value in string ne at /usr/sbin/amavisd line 5539.
Apr  7 11:51:12 mail.outersquare.org /usr/sbin/amavisd[1521]: (01521-01)
prolong_timer after mime_decode-1: remaining time = 300 s
Apr  7 11:51:12 mail.outersquare.org /usr/sbin/amavisd[1521]: (01521-01)
decode_parts: level=1, #parts=1 : p001
Apr  7 11:51:12 mail.outersquare.org /usr/sbin/amavisd[1527]: (01521-01)
run_command: child process [1527]: Error closing main::stdin: Bad file
descriptor at /usr/sbin/amavisd line 1872.\n
Apr  7 11:51:12 mail.outersquare.org /usr/sbin/amavisd[1521]: (01521-01)
run_command: [1527] /usr/bin/file p001 </dev/null 2>&1
Apr  7 11:51:12 mail.outersquare.org /usr/sbin/amavisd[1521]: (01521-01)
TROUBLE in check_mail: parts_decode_ext FAILED: parsing file(1) results -
missing last 1 results at (eval 44) line 154.
Apr  7 11:51:12 mail.outersquare.org /usr/sbin/amavisd[1521]: (01521-01)
sending SMTP response: "451 4.5.0 Error in processing, id=01521-01,
parts_decode_ext FAILED: parsing file(1) results - missing last 1 results at
(eval 44) line 154."
Apr  7 11:51:12 mail.outersquare.org /usr/sbin/amavisd[1521]: (01521-01) SMTP>
451 4.5.0 Error in processing, id=01521-01, parts_decode_ext FAILED: parsing
file(1) results - missing last 1 results at (eval 44) line 154.
Apr  7 11:51:12 mail.outersquare.org /usr/sbin/amavisd[1521]: (01521-01) timer
stopped after DATA end
Apr  7 11:51:12 mail.outersquare.org /usr/sbin/amavisd[1521]: (01521-01)
PRESERVING EVIDENCE in /var/amavis/tmp/amavis-20060407T115112-01521
Apr  7 11:51:12 mail.outersquare.org /usr/sbin/amavisd[1521]: (01521-01) TIMING
[total 42 ms] - SMTP HELO: 7 (16%)16, SMTP pre-MAIL: 1 (3%)19, mkdir tempdir: 1
(3%)22, create email.txt: 1 (1%)23, SMTP DATA: 6 (14%)37, body_digest: 1
(3%)40, gen_mail_id: 1 (2%)42, mkdir parts: 1 (1%)43, mime_decode: 9 (22%)65,
rundown: 15 (35%)100
Apr  7 11:51:12 mail.outersquare.org /usr/sbin/amavisd[1521]: (01521-01)
idle_proc, 6: was busy, 29.6 ms, total idle 0.001 s, busy 0.041 s
Apr  7 11:51:12 mail.outersquare.org /usr/sbin/amavisd[1521]: (01521-01)
idle_proc, 5: was idle, 0.4 ms, total idle 0.002 s, busy 0.041 s
Apr  7 11:51:12 mail.outersquare.org /usr/sbin/amavisd[1521]: (01521-01)
prolong_timer after reading SMTP command: remaining time = 0 s
Apr  7 11:51:12 mail.outersquare.org /usr/sbin/amavisd[1521]: (01521-01) SMTP<
QUIT\r\n
Use of uninitialized value in string ne at (eval 39) line 226, <GEN4> line 11.
Use of uninitialized value in concatenation (.) or string at (eval 39) line
243, <GEN4> line 11.
Use of uninitialized value in concatenation (.) or string at (eval 39) line
243, <GEN4> line 11.
Apr  7 11:51:12 mail.outersquare.org /usr/sbin/amavisd[1521]: (01521-01) SMTP>
221 2.0.0 [127.0.0.1] amavisd-new closing transmission channel
Apr  7 11:51:12 mail.outersquare.org /usr/sbin/amavisd[1521]: (01521-01)
post_process_request_hook: timer stopped
Apr  7 11:51:12 mail.outersquare.org /usr/sbin/amavisd[1521]: (01521-01)
idle_proc, bye: was busy, 3.2 ms, total idle 0.002 s, busy 0.044 s
Apr  7 11:51:12 mail.outersquare.org /usr/sbin/amavisd[1521]: (01521-01) load:
96 %, total idle 0.002 s, busy 0.044 s
Filehandle STDIN reopened as LOCK only for output at
/usr/lib64/perl5/vendor_perl/5.8.8/Net/Server/PreForkSimple.pm line 244.

------- Comment #1 From Andrej Kacian (RETIRED) 2006-04-07 12:39:28 0000 -------
That's a collateral damage from bugs #128698, #128710, and the fact that I
temporarily didn't have commit access after the latter has been resolved. Sorry
about that.

I've changed amavisd-new-2.3.3-r2 to depend on <=net-server-0.90, and will be
adding 2.4.0 tonight.

------- Comment #2 From Jakub Moc (RETIRED) 2006-04-07 16:59:42 0000 -------
(In reply to comment #1)
> I've changed amavisd-new-2.3.3-r2 to depend on <=net-server-0.90, and will be
> adding 2.4.0 tonight.

Don't want to disappoint you, but that simply doesn't work (Bug 48195). The
only workaround is to add mutual blockers to both ebuilds.  

Deps like <=net-server-0.90 just result in perpetual upgrade/downgrade cycle.

------- Comment #3 From Tuan Van (RETIRED) 2006-04-07 17:43:05 0000 -------
(In reply to comment #2)
> 
> Deps like <=net-server-0.90 just result in perpetual upgrade/downgrade cycle.
> 

got proof ? amavisd-new-2.3.3-r2 and net-server-0.88 are both stable on most
arches. How does one get upgrade/downgrade cycle ( without mixing arch and
~arch )?

------- Comment #4 From Jakub Moc (RETIRED) 2006-04-08 00:12:16 0000 -------
(In reply to comment #3)
> (In reply to comment #2)
> > 
> > Deps like <=net-server-0.90 just result in perpetual upgrade/downgrade cycle.
> > 
> 
> got proof ? 

Sure, read the bug referenced above.

> amavisd-new-2.3.3-r2 and net-server-0.88 are both stable on most
> arches. How does one get upgrade/downgrade cycle ( without mixing arch and
> ~arch )?

Well, that's what this bug is about, isn't it? :) Even if not mixing arch and
~arch, you'll get that cycle as soon as >net-server-0.90 gets keyworded stable
(pretty likely noone will know about this bug when keywording it). All that I'm
saying here is that <= deps don't work and are not honored by portage
correctly. 

If your opinion is that bugs you get when mixing arch and ~arch are invalid,
there's no point in fixing this one. Otherwise, the solution is to block 
>net-server-0.90 in <amavisd-new-2.4* ebuilds and to block <amavisd-new-2.4* in
>net-server-0.90 ebuilds (that way net-server maintainer can also notice that
it shouldn't be marked stable until amavisd-new-2.4 gets stable).

------- Comment #5 From Andrej Kacian (RETIRED) 2006-04-08 03:55:12 0000 -------
Blocking net-server in amavisd-new makes no sense, since repoman doesn't care
about amavisd-new when checking it (in case net-server gets stable keywords).
Depend atoms in amavisd-new are like this:

amavisd-new-2.3.3-r2.ebuild:    <=dev-perl/net-server-0.90
amavisd-new-2.4.0.ebuild:       >=dev-perl/net-server-0.91

I don't know if perl guys want to add amavisd-new blocker to net-server
ebuilds.

------- Comment #6 From Tuan Van (RETIRED) 2006-04-08 09:59:54 0000 -------
(In reply to comment #4)

> Well, that's what this bug is about, isn't it? :) Even if not mixing arch and
> ~arch, you'll get that cycle as soon as >net-server-0.90 gets keyworded stable
> (pretty likely noone will know about this bug when keywording it). All that I'm
> saying here is that <= deps don't work and are not honored by portage
> correctly. 
> 
> If your opinion is that bugs you get when mixing arch and ~arch are invalid,

if one know how to use ~arch version of net-server and arch version of
amavisd-new, I think he/she knows to handle the {up,down}grade thing.

> there's no point in fixing this one. Otherwise, the solution is to block 
> >net-server-0.90 in <amavisd-new-2.4* ebuilds and to block <amavisd-new-2.4* in
> >net-server-0.90 ebuilds (that way net-server maintainer can also notice that
> it shouldn't be marked stable until amavisd-new-2.4 gets stable).
> 

or we file a bug block any future stable marking net-server-0.90. Ebuild
blocking start getting very annoying IMO.

------- Comment #7 From Michael Cummings (RETIRED) 2006-04-08 11:34:03 0000 -------
since most likely net-server will get bumped stable ignorant of this blocker
(and i can say that because i'll probably forget about it after this post) what
work is being done to fix amavisd?

------- Comment #8 From Andrej Kacian (RETIRED) 2006-04-08 13:34:41 0000 -------
I believe there's nothing more to be done on amavisd-new side, apart from dep
atoms mentioned in comment #5.

------- Comment #9 From Jakub Moc (RETIRED) 2006-08-16 04:14:38 0000 -------
*** Bug 144095 has been marked as a duplicate of this bug. ***

------- Comment #10 From Jakub Moc (RETIRED) 2006-08-28 10:58:17 0000 -------
*** Bug 145378 has been marked as a duplicate of this bug. ***