[imp] attachments causes 2 messages + 2 attachments + double size
Scott Mcdermott
mcdermot at questra.com
Thu Feb 6 20:22:38 PST 2003
I am using RH8.0 patched current as of today (including the PHP update
they just gave out, but it had this problem before.)
IMP 3.1, Horde 2.1.
I can't for the life of me get attachments to work right. I have
increased all my size limits, mem limits, file upload limits, HTTP POST
limits, LimitRequestBody, all to insane limits. The problem isn't size,
it's like þhis:
every time I send mails with attachments, the following happens:
- two mails are sent instead of one
- both messages have identical text in the non-attachment body
- one mail has two zero-byte attachments with the filename that
I attached
- the other mail has one attachment that is *exactly* double the
size of the uploaded attachment (this doesn't vary with
attachment size), another zero-byte attachment, and again both
having the filename that I attached. After saving the files
it looks like it's just the output of "cat file file >
attachment"
eg if I send a mail with 6M attachment, "file" I'll get:
mail1: 12M attachment "file"
0M attachment "file"
mail2: 0M attachment "file"
0M attachment "file"
this problem is extremely bizarre and I can't figure out what is wrong.
This whole setup worked fine on my RH6.2 system with hand-built PHP!
what gives? Anyone seen this before?
the below is log snips from this sequence:
- restart apache
- send one test message without attachments (works fine)
- send other test message with attachments (this was a several
minute upload -- yes my timeouts are all exorbitant too) and
watch the double-problem
Feb 6 19:30:00 server httpd[7605]: [info] Init: Initializing OpenSSL library
Feb 6 19:30:00 server httpd[7605]: [info] Init: Seeding PRNG with 648 bytes of entropy
Feb 6 19:30:00 server httpd[7605]: [info] Loading certificate & private key of SSL-aware server
Feb 6 19:30:00 server httpd[7605]: [info] Init: Generating temporary RSA private keys (512/1024 bits)
Feb 6 19:30:01 server httpd[7605]: [info] Init: Generating temporary DH parameters (512/1024 bits)
Feb 6 19:30:01 server httpd[7605]: [info] Init: Initializing (virtual) servers for SSL
Feb 6 19:30:01 server httpd[7605]: [info] Configuring server for SSL protocol
Feb 6 19:30:01 server httpd[7605]: [info] Server: Apache/2.0.40, Interface: mod_ssl/2.0.40, Library: OpenSSL/0.9.6b
Feb 6 19:30:02 server httpd: httpd startup succeeded
Feb 6 19:30:02 server httpd[7610]: [notice] Digest: generating secret for digest authentication ...
Feb 6 19:30:02 server httpd[7610]: [notice] Digest: done
Feb 6 19:30:02 server httpd[7610]: [info] Init: Initializing OpenSSL library
Feb 6 19:30:03 server httpd[7610]: [info] Init: Seeding PRNG with 648 bytes of entropy
Feb 6 19:30:03 server httpd[7610]: [info] Loading certificate & private key of SSL-aware server
Feb 6 19:30:03 server httpd[7610]: [info] Init: Generating temporary RSA private keys (512/1024 bits)
Feb 6 19:30:03 server httpd[7610]: [info] Init: Generating temporary DH parameters (512/1024 bits)
Feb 6 19:30:03 server httpd[7610]: [info] Init: Initializing (virtual) servers for SSL
Feb 6 19:30:03 server httpd[7610]: [info] Configuring server for SSL protocol
Feb 6 19:30:03 server httpd[7610]: [info] Server: Apache/2.0.40, Interface: mod_ssl/2.0.40, Library: OpenSSL/0.9.6b
Feb 6 19:30:03 server httpd[7610]: [notice] Apache/2.0.40 configured -- resuming normal operations
Feb 6 19:30:03 server httpd[7610]: [info] Server built: Oct 9 2002 08:01:13
Feb 6 19:30:03 server httpd[7613]: [info] Connection to child 0 established (server server.domain.tld:443, client 66.82.208.1)
Feb 6 19:30:03 server httpd[7613]: [info] Seeding PRNG with 648 bytes of entropy
Feb 6 19:30:08 server httpd[7613]: [info] Initial (No.1) HTTPS request received for child 0 (server server.domain.tld:443)
Feb 6 19:30:10 server httpd[7613]: [info] Connection to child 0 closed with standard shutdown(server server.domain.tld:443, client 66.82.208.1)
Feb 6 19:30:11 server httpd[7614]: [info] Connection to child 1 established (server server.domain.tld:443, client 66.82.208.1)
Feb 6 19:30:11 server httpd[7614]: [info] Seeding PRNG with 648 bytes of entropy
Feb 6 19:30:14 server httpd[7614]: [info] Initial (No.1) HTTPS request received for child 1 (server server.domain.tld:443)
Feb 6 19:30:14 server HORDE[7614]: [imp] Session timeout for client [66.82.208.1] [on line 79 of "/var/www/vhosts/mail/htdocs/login.php"]
Feb 6 19:30:16 server HORDà[7614]: [info] Connection to child 1 closed with standard shutdown(server server.domain.tld:443, client 66.82.208.1)
Feb 6 19:30:18 server httpd[7615]: [info] Connection to child 2 established (server server.domain.tld:443, client 66.82.208.1)
Feb 6 19:30:18 server httpd[7615]: [info] Seeding PRNG with 648 bytes of entropy
Feb 6 19:30:22 server httpd[7615]: [info] Connection to child 2 closed with standard shutdown(server server.domain.tld:443, client 66.82.208.1)
Feb 6 19:30:27 server httpd[7616]: [info] Connection to child 3 established (server server.domain.tld:443, client 64.212.207.154)
Feb 6 19:30:27 server httpd[7616]: [info] Seeding PRNG with 648 bytes of entropy
Feb 6 19:30:31 server httpd[7616]: [info] Initial (No.1) HTTPS request received for child 3 (server server.domain.tld:443)
Feb 6 19:30:31 server httpd[7616]: [info] Subsequent (No.2) HTTPS request received for child 3 (server server.domain.tld:443)
Feb 6 19:30:32 server httpd[7616]: [info] Subsequent (No.3) HTTPS request received for child 3 (server server.domain.tld:443)
Feb 6 19:30:47 server httpd[7616]: [info] Subsequent (No.5) HTTPS request received for child 3 (server server.domain.tld:443)
Feb 6 19:30:47 server HORDE[7616]: [imp] Login success for testimap [64.212.207.154] to {server.domain.tld:143} [on line 64 of "/var/www/vhosts/mail/htdocs/redirect.php"]
Feb 6 19:30:48 server HORDE[7616]: [info] Subsequent (No.6) HTTPS request received for child 3 (server server.domain.tld:443)
Feb 6 19:30:48 server httpd[7617]: [info] Connection to child 4 established (server server.domain.tld:443, client 64.212.207.154)
Feb 6 19:30:48 server httpd[7617]: [info] Seeding PRNG with 648 bytes of entropy
Feb 6 19:30:49 server ¸ '^H^E[7616]: [info] Subsequent (No.7) HTTPS request received for child 3 (server server.domain.tld:443)
Feb 6 19:30:49 server httpd[7617]: [info] Subsequent (No.2) HTTPS request received for child 4 (server server.domain.tld:443)
Feb 6 19:30:49 server ¸ '^H^E[7616]: [info] Subsequent (No.8) HTTPS request received for child 3 (server server.domain.tld:443)
Feb 6 19:30:49 server ¸ '^H^E[7616]: [info] Subsequent (No.9) HTTPS request received for child 3 (server server.domain.tld:443)
Feb 6 19:30:50 server httpd[7617]: [info] Subsequent (No.5) HTTPS request received for child 4 (server server.domain.tld:443)
Feb 6 19:30:50 server httpd[7617]: [info] Subsequent (No.6) HTTPS request received for child 4 (server server.domain.tld:443)
Feb 6 19:30:50 server ¸ '^H^E[7616]: [info] Subsequent (No.12) HTTPS request received for child 3 (server server.domain.tld:443)
Feb 6 19:30:50 server httpd[7617]: [info] Subsequent (No.7) HTTPS request received for child 4 (server server.domain.tld:443)
Feb 6 19:30:50 server ¸ '^H^E[7616]: [info] Subsequent (No.13) HTTPS request received for child 3 (server server.domain.tld:443)
Feb 6 19:30:50 server httpd[7617]: [info] Subsequent (No.8) HTTPS request received for child 4 (server server.domain.tld:443)
Feb 6 19:30:54 server ¸ '^H^E[7616]: [info] Subsequent (No.14) HTTPS request received for child 3 (server server.domain.tld:443)
Feb 6 19:30:55 server httpd[7617]: [info] Subsequent (No.10) HTTPS request received for child 4 (server server.domain.tld:443)
Feb 6 19:30:55 server ð^_'^H^E[7616]: [info] Subsequent (No.16) HTTPS request received for child 3 (server server.domain.tld:443)
Feb 6 19:30:55 server httpd[7617]: [info] Subsequent (No.11) HTTPS request received for child 4 (server server.domain.tld:443)
Feb 6 19:30:55 server httpd[7617]: [info] Subsequent (No.12) HTTPS request received for child 4 (server server.domain.tld:443)
Feb 6 19:31:09 server ð^_'^H^E[7616]: [info] Subsequent (No.18) HTTPS request received for child 3 (server server.domain.tld:443)
Feb 6 19:31:10 server HORDE[7616]: [imp] 64.212.207.154 Message sent to smcdermott at domain.tld from testimap [on line 813 of "/var/www/vhosts/mail/htdocs/compose.php"]
Feb 6 19:31:10 server postfix/pickup[6616]: 81B97338E4: uid=48 from=<testimap at domain.tld>
Feb 6 19:31:10 server postfix/cleanup[7623]: 81B97338E4: message-id=<1044577870.3e42fe4e20091 at server.domain.tld>
Feb 6 19:31:10 server postfix/nqmgr[979]: 81B97338E4: from=<testimap at domain.tld>, size=633, nrcpt=1 (queue active)
Feb 6 19:31:10 server postfix/smtp[7625]: 81B97338E4: to=<smcdermott at domain.tld>, relay=mailrelay.domain.tld[10.20.8.25], delay=0, status=sent (250 ok 1044577870 qp 23222)
Feb 6 19:31:12 server httpd[7617]: [info] Connection to child 4 closed with standard shutdown(server server.domain.tld:443, client 64.212.207.154)
Feb 6 19:31:12 server HORDE[7616]: [info] Subsequent (No.19) HTTPS request received for child 3 (server server.domain.tld:443)
Feb 6 19:31:13 server httpd[7613]: [info] Connection to child 0 established (server server.domain.tld:443, client 64.212.207.154)
Feb 6 19:31:13 server httpd[7613]: [info] Seeding PRNG with 648 bytes of entropy
Feb 6 19:31:13 server httpd[7613]: [info] Subsequent (No.2) HTTPS request received for child 0 (server server.domain.tld:443)
Feb 6 19:31:13 server miss^X[7616]: [info] Subsequent (No.21) HTTPS request received for child 3 (server server.domain.tld:443)
Feb 6 19:31:14 server httpd[7613]: [info] Subsequent (No.3) HTTPS request received for child 0 (server server.domain.tld:443)
Feb 6 19:31:14 server httpd[7613]: [info] Subsequent (No.4) HTTPS request received for child 0 (server server.domain.tld:443)
Feb 6 19:31:31 server miss^X[7616]: [info] Connection to child 3 closed with standard shutdown(server server.domain.tld:443, client 64.212.207.154)
Feb 6 19:31:31 server httpd[7613]: [info] Connection to child 0 closed with standard shutdown(server server.domain.tld:443, client 64.212.207.154)
Feb 6 19:32:33 server HORDà[7614]: [info] Connection to child 1 established (server server.domain.tld:443, client 64.212.207.154)
Feb 6 19:32:33 server HORDà[7614]: [info] Seeding PRNG with 648 bytes of entropy
Feb 6 19:32:33 server HORDà[7614]: [info] Initial (No.1) HTTPS request received for child 1 (server server.domain.tld:443)
Feb 6 19:40:18 server httpd[7615]: [info] Connection to child 2 established (server server.domain.tld:443, client 64.212.207.154)
Feb 6 19:40:18 server httpd[7615]: [info] Seeding PRNG with 648 bytes of entropy
Feb 6 19:40:19 server 4adf58&uniq=10765472083e42fe50b9dd81044578028579[7614]: [info] Subsequent (No.3) HTTPS request received for child 1 (server server.domain.tld:443)
Feb 6 19:40:19 server httpd[7615]: [info] Subsequent (No.3) HTTPS request received for child 2 (server server.domain.tld:443)
Feb 6 19:40:19 server 4adf58&uniq=10765472083e42fe50b9dd81044578028579[7614]: [info] Subsequent (No.4) HTTPS request received for child 1 (server server.domain.tld:443)
Feb 6 19:40:19 server 4adf58&uniq=10765472083e42fe50b9dd81044578028579[7614]: [info] Subsequent (No.5) HTTPS request received for child 1 (server server.domain.tld:443)
Feb 6 19:40:36 server httpd[7615]: [info] Connection to child 2 closed with standard shutdown(server server.domain.tld:443, client 64.212.207.154)
Feb 6 19:40:36 server 4adf58&uniq=10765472083e42fe50b9dd81044578028579[7614]: [info] Connection to child 1 closed with standard shutdown(server server.domain.tld:443, client 64.212.207.154)
Feb 6 19:43:20 server httpd[7617]: [info] Connection to child 4 established (server server.domain.tld:443, client 64.212.207.154)
Feb 6 19:43:20 server httpd[7617]: [info] Seeding PRNG with 648 bytes of entropy
Feb 6 19:43:20 server httpd[7617]: [info] Initial (No.1) HTTPS request received for child 4 (server server.domain.tld:443)
Feb 6 19:43:21 server httpd[7617]: PHP Warning: fopen("/tmp/impattgukXTM", "rb") - No such file or directory in /var/www/vhosts/mail/htdocs/compose.php on line 319
Feb 6 19:43:21 server httpd[7617]: PHP Warning: stat failed for /tmp/impattgukXTM (errno=2 - No such file or directory) in /var/www/vhosts/mail/htdocs/compose.php on line 320
Feb 6 19:43:21 server httpd[7617]: PHP Warning: fread(): supplied argument is not a valid File-Handle resource in /var/www/vhosts/mail/htdocs/compose.php on line 320
Feb 6 19:43:21 server httpd[7617]: PHP Warning: fclose(): supplied argument is not a valid File-Handle resource in /var/www/vhosts/mail/htdocs/compose.php on line 321
Feb 6 19:43:21 server httpd[7617]: PHP Warning: unlink() failed (No such file or directory) in /var/www/vhosts/mail/htdocs/compose.php on line 322
Feb 6 19:43:24 server HORDE[7617]: [imp] 64.212.207.154 Message sent to smcdermott at domain.tld from testimap [on line 813 of "/var/www/vhosts/mail/htdocs/compose.php"]
Feb 6 19:43:24 server postfix/pickup[6616]: 9D6E9338E4: uid=48 from=<testimap at domain.tld>
Feb 6 19:43:24 server postfix/cleanup[7646]: 9D6E9338E4: message-id=<1044578602.3e43012acdda6 at server.domain.tld>
Feb 6 19:43:25 server miss^X[7616]: [info] Connection to child 3 established (server server.domain.tld:443, client 64.212.207.154)
Feb 6 19:43:25 server miss^X[7616]: [info] Seeding PRNG with 648 bytes of entropy
Feb 6 19:43:25 server miss^X[7616]: [info] Initial (No.1) HTTPS request received for child 3 (server server.domain.tld:443)
Feb 6 19:43:26 server postfix/nqmgr[979]: 9D6E9338E4: from=<testimap at domain.tld>, size=17435126, nrcpt=1 (queue active)
Feb 6 19:43:26 server arr[7616]: PHP Warning: fopen("/tmp/impattgukXTM", "rb") - No such file or directory in /var/www/vhosts/mail/htdocs/compose.php on line 319
Feb 6 19:43:26 server arr[7616]: PHP Warning: stat failed for /tmp/impattgukXTM (errno=2 - No such file or directory) in /var/www/vhosts/mail/htdocs/compose.php on line 320
Feb 6 19:43:26 server arr[7616]: PHP Warning: fread(): supplied argument is not a valid File-Handle resource in /var/www/vhosts/mail/htdocs/compose.php on line 320
Feb 6 19:43:26 server arr[7616]: PHP Warning: fclose(): supplied argument is not a valid File-Handle resource in /var/www/vhosts/mail/htdocs/compose.php on line 321
Feb 6 19:43:26 server arr[7616]: PHP Warning: unlink() failed (No such file or directory) in /var/www/vhosts/mail/htdocs/compose.php on line 322
Feb 6 19:43:26 server arr[7616]: PHP Warning: fopen("/tmp/impattgukXTM", "rb") - No such file or directory in /var/www/vhosts/mail/htdocs/compose.php on line 319
Feb 6 19:43:26 server arr[7616]: PHP Warning: stat failed for /tmp/impattgukXTM (errno=2 - No such file or directory) in /var/www/vhosts/mail/htdocs/compose.php on line 320
Feb 6 19:43:26 server arr[7616]: PHP Warning: fread(): supplied argument is not a valid File-Handle resource in /var/www/vhosts/mail/htdocs/compose.php on line 320
Feb 6 19:43:26 server arr[7616]: PHP Warning: fclose(): supplied argument is not a valid File-Handle resource in /var/www/vhosts/mail/htdocs/compose.php on line 321
Feb 6 19:43:26 server arr[7616]: PHP Warning: unlink() failed (No such file or directory) in /var/www/vhosts/mail/htdocs/compose.php on line 322
Feb 6 19:43:26 server postfix/pickup[6616]: CBAA8338E5: uid=48 from=<testimap at domain.tld>
Feb 6 19:43:26 server postfix/cleanup[7646]: CBAA8338E5: message-id=<1044578606.3e43012eae246 at server.domain.tld>
Feb 6 19:43:26 server HORDE[7616]: [imp] 64.212.207.154 Message sent to smcdermott at domain.tld from testimap [on line 813 of "/var/www/vhosts/mail/htdocs/compose.php"]
Feb 6 19:43:26 server postfix/nqmgr[979]: CBAA8338E5: from=<testimap at domain.tld>, size=1327, nrcpt=1 (queue active)
Feb 6 19:43:26 server postfix/smtp[7651]: CBAA8338E5: to=<smcdermott at domain.tld>, relay=mailrelay.domain.tld[10.20.8.25], delay=0, status=sent (250 ok 1044578606 qp 23607)
Feb 6 19:43:31 server postfix/smtp[7648]: 9D6E9338E4: to=<smcdermott at domain.tld>, relay=mailrelay.domain.tld[10.20.8.25], delay=8, status=sent (250 ok 1044578611 qp 23604)
Feb 6 19:43:42 server HORDE[7616]: [info] Connection to child 3 closed with standard shutdown(server server.domain.tld:443, client 64.212.207.154)
Note the bizarre syslog corruption and nonsensical errors (no there are
no permissions problems on /tmp/)
also note that I am sending to localhost via smtp, but have tried also
invoking /usr/lib/sendmail directly, etc. My postfix message limits are
all maxed out.
I'm really perplexed here...known bugs in IMP3.1/Horde2.1 ? I couldn't
find any references in the mail archives to anything remotely like this
(but they were pretty large and I only looked for a couple of hours :)
Any help is greatly appreciated! Thanks.
More information about the imp
mailing list