так может у той стороны проблемы? :)

Сломал глаза читать лог. Постите в режиме "preformated text", не забывайте переносы, и про кнопку "Предпросмотр". А в целом, вроде у вас маленький таймаут стоит ( 08:46:51 --- 08:51:42 ) это меньше 5 мин отводится на передачу письма. Может просто chel.usi.ru не успевает принять письмо за это время.

Попробуйте переслать маленькое, допустим 10 кБайт, вложение.

O_O пять минут это маленький таймаут? :). Потом обычно таймаут не на передачу всего письма а между двумя событиями на сокете, хотя как в постфиксе я не знаю.

Может :)
Но ребята с "той стороны" - "открещиваются". Да и это понятно. Пока мне предъявить им нечего. Единственно что известно - протокол ICMP с той стороны они похоже круто прикрыли - ping до их домена не ходит.

Видимо корень проблеммы можно увидеть только анализируя лог tcpdump.

08:52:50.603339 IP mail.prominform.ru.47353 > mumin.chel.usi.ru.smtp: S 1070307149:1070307149(0) win 5440 <mss 1360,sackOK,timestamp 18017882 0,nop,wscale 2>
08:52:50.641501 IP mumin.chel.usi.ru.smtp > mail.prominform.ru.47353: S 973754258:973754258(0) ack 1070307150 win 5792 <mss 1360,sackOK,timestamp 1803750421
18017882,nop,wscale 0>
08:52:50.641558 IP mail.prominform.ru.47353 > mumin.chel.usi.ru.smtp: . ack 1 win 1360 <nop,nop,timestamp 18017892 1803750421>
08:52:50.755630 IP mumin.chel.usi.ru.smtp > mail.prominform.ru.47353: P 1:24(23) ack 1 win 5792 <nop,nop,timestamp 1803750434 18017892>
08:52:50.755660 IP mail.prominform.ru.47353 > mumin.chel.usi.ru.smtp: . ack 24 win 1360 <nop,nop,timestamp 18017920 1803750434>
08:52:50.755945 IP mail.prominform.ru.47353 > mumin.chel.usi.ru.smtp: P 1:26(25) ack 24 win 1360 <nop,nop,timestamp 18017920 1803750434>
08:52:50.785330 IP mumin.chel.usi.ru.smtp > mail.prominform.ru.47353: . ack 26 win 5792 <nop,nop,timestamp 1803750436 18017920>
08:52:50.786688 IP mumin.chel.usi.ru.smtp > mail.prominform.ru.47353: P 24:140(116) ack 26 win 5792 <nop,nop,timestamp 1803750436 18017920>
08:52:50.787138 IP mail.prominform.ru.47353 > mumin.chel.usi.ru.smtp: P 26:163(137) ack 140 win 1360 <nop,nop,timestamp 18017928 1803750436>
08:52:50.852000 IP mumin.chel.usi.ru.smtp > mail.prominform.ru.47353: . ack 163 win 5792 <nop,nop,timestamp 1803750444 18017928>
08:52:50.922209 IP mumin.chel.usi.ru.smtp > mail.prominform.ru.47353: P 140:205(65) ack 163 win 5792 <nop,nop,timestamp 1803750449 18017928>
08:52:50.922580 IP mail.prominform.ru.47353 > mumin.chel.usi.ru.smtp: . 163:1511(1348) ack 205 win 1360 <nop,nop,timestamp 18017962 1803750449>
08:52:50.922602 IP mail.prominform.ru.47353 > mumin.chel.usi.ru.smtp: . 1511:2859(1348) ack 205 win 1360 <nop,nop,timestamp 18017962 1803750449>
08:52:50.969988 IP mumin.chel.usi.ru.smtp > mail.prominform.ru.47353: . ack 1511 win 8088 <nop,nop,timestamp 1803750455 18017962>
08:52:50.970019 IP mail.prominform.ru.47353 > mumin.chel.usi.ru.smtp: P 2859:4207(1348) ack 205 win 1360 <nop,nop,timestamp 18017974 1803750455>
08:52:50.970029 IP mail.prominform.ru.47353 > mumin.chel.usi.ru.smtp: . 4207:5555(1348) ack 205 win 1360 <nop,nop,timestamp 18017974 1803750455>
08:52:50.997742 IP mumin.chel.usi.ru.smtp > mail.prominform.ru.47353: . ack 2859 win 10784 <nop,nop,timestamp 1803750458 18017962>
08:52:50.997766 IP mail.prominform.ru.47353 > mumin.chel.usi.ru.smtp: . 5555:6903(1348) ack 205 win 1360 <nop,nop,timestamp 18017981 1803750458>
08:52:50.997776 IP mail.prominform.ru.47353 > mumin.chel.usi.ru.smtp: P 6903:8251(1348) ack 205 win 1360 <nop,nop,timestamp 18017981 1803750458>
08:52:51.019996 IP mumin.chel.usi.ru.smtp > mail.prominform.ru.47353: . ack 4207 win 13480 <nop,nop,timestamp 1803750460 18017974>
08:52:51.020036 IP mail.prominform.ru.47353 > mumin.chel.usi.ru.smtp: . 8251:9599(1348) ack 205 win 1360 <nop,nop,timestamp 18017986 1803750460>
08:52:51.020046 IP mail.prominform.ru.47353 > mumin.chel.usi.ru.smtp: . 9599:10947(1348) ack 205 win 1360 <nop,nop,timestamp 18017986 1803750460>
08:52:51.046618 IP mumin.chel.usi.ru.smtp > mail.prominform.ru.47353: . ack 5555 win 16176 <nop,nop,timestamp 1803750463 18017974>
08:52:51.046637 IP mail.prominform.ru.47353 > mumin.chel.usi.ru.smtp: . 10947:12295(1348) ack 205 win 1360 <nop,nop,timestamp 18017993 1803750463>
08:52:51.046646 IP mail.prominform.ru.47353 > mumin.chel.usi.ru.smtp: P 12295:12451(156) ack 205 win 1360 <nop,nop,timestamp 18017993 1803750463>
08:52:51.070918 IP mumin.chel.usi.ru.smtp > mail.prominform.ru.47353: . ack 6903 win 20220 <nop,nop,timestamp 1803750465 18017981>

И в конце:

08:52:57.180891 IP mumin.chel.usi.ru.smtp > mail.prominform.ru.47353: . ack 103495 win 57964 <nop,nop,timestamp 1803751076 18019514,nop,nop,sack 3 {487142371:487143719}{487139675:487141023}{487136979:487138327}>
08:53:02.481721 IP mail.prominform.ru.47353 > mumin.chel.usi.ru.smtp: . 100799:102147(1348) ack 205 win 1360 <nop,nop,timestamp 18020852 1803750791>
08:53:02.530751 IP mumin.chel.usi.ru.smtp > mail.prominform.ru.47353: P ack 103495 win 57964 <nop,nop,timestamp 1803751076 18018409>
08:53:02.530779 IP mail.prominform.ru.47353 > mumin.chel.usi.ru.smtp: . 103495:104843(1348) ack 205 win 1360 <nop,nop,timestamp 18020864 1803751076>
08:53:02.581028 IP mumin.chel.usi.ru.smtp > mail.prominform.ru.47353: . ack 106191 win 55268 <nop,nop,timestamp 1803751616 18020864


После чего все "замирает" :(

Вложение 10 Кб - уходит тутже. Вложение 100кб - уже не отправляется :(

mail:~ # mailq
-Queue ID- --Size-- ----Arrival Time---- -Sender/Recipient-------
0B8FF1172D1*  145945 Wed May 13 09:14:48  xxx@prominform.ru
                                          yyy@chel.usi.ru

Про форматирование - понял :)
Лог postfix а можно посмотреть здесь: 
http://www.postfix.ru/viewtopic.php?t=19842

По логам /var/log/mail видно - отправка письма 10Кб - около 2-х секунд. 
Следовательно 100Кб - должно оправляться примерно 20 сек - не больше.
Значит дело не в таймауте 5 мин :(

попробуй вырубить selective acknowledgment. Так же, возможно, из-за вырубленного icmp не проходят need to frag пакеты. Попробуй mtu до 1300 уменьшить, но это вряд ли поможет. И пусть те засранцы врубят icmp ненадолго.

Почему у тебя tcp-окно такое маленькое? Признавайся, крутил sysctl "для увеличения производительности"?

Re:Вложение 10 Кб - уходит тутже. Вложение 100кб - уже не отправляется

1. Это мне напоминает схожую проблему (правда, дело было на почтовике с sendmail) - http://www.opennet.ru/openforum/vsluhforumID1/81651.html
Не установлен ли у вас часом какой-нить тормозящий фильтр на postfix'e?

2. По поводу самого сообщения "timed out while sending message body"
- когда-то собирала инфу по схожей проблеме на sendmail
http://linux.ufaras.ru/timeout.html

>Так же, возможно, из-за вырубленного icmp не проходят need to frag пакеты
У себя вроде необходимые типы ICMP открыты. В ADSL модеме -тоже.

mail:/etc/postfix # iptables-save | grep icmp
-A INPUT -p icmp -m icmp --icmp-type 8 -j ACCEPT
-A INPUT -p icmp -m icmp --icmp-type 0 -j ACCEPT
-A INPUT -p icmp -m icmp --icmp-type 11 -j ACCEPT
-A INPUT -p icmp -m icmp --icmp-type 3 -j ACCEPT
-A OUTPUT -p icmp -m icmp --icmp-type 0 -j ACCEPT
-A OUTPUT -p icmp -m icmp --icmp-type 8 -j ACCEPT
-A OUTPUT -p icmp -m icmp --icmp-type 3 -j ACCEPT

>Попробуй mtu до 1300 уменьшить, но это вряд ли поможет
Пробовал и в модеме и на сетевой карте синхронно - не помогает.

>Почему у тебя tcp-окно такое маленькое? 
"В наследство" от предыдущего админа мне такое перешло :)

>Признавайся, крутил sysctl "для увеличения производительности"?
За себя скажу - я не крутил :). Только это никак на реально выставленные сейчас параметры не влияет. Знать бы что смотреть.

> У себя вроде необходимые типы ICMP открыты. В ADSL модеме -тоже.

Я про другой сервер говорил. Попроси их убрать фаервол ненадолго.

И покажи sysctl -a | grep tcp

>Я про другой сервер говорил. Попроси их убрать фаервол ненадолго

Организация - УралСвязьинформ. Наврядли они это сделают. Но попросил их сделать это для нашего статического IP mail.prominform.ru.
Жду ответа.

> покажи sysctl -a | grep tcp

mail:/ # sysctl -a | grep tcp
error: "Success" reading key "dev.parport.parport0.autoprobe3"
error: "Success" reading key "dev.parport.parport0.autoprobe2"
error: "Success" reading key "dev.parport.parport0.autoprobe1"
error: "Success" reading key "dev.parport.parport0.autoprobe0"
error: "Success" reading key "dev.parport.parport0.autoprobe"
error: "Operation not permitted" reading key "net.ipv6.route.flush"
error: "Operation not permitted" reading key "net.ipv4.route.flush"
net.ipv4.netfilter.ip_conntrack_tcp_max_retrans = 3
net.ipv4.netfilter.ip_conntrack_tcp_be_liberal = 0
net.ipv4.netfilter.ip_conntrack_tcp_loose = 3
net.ipv4.netfilter.ip_conntrack_tcp_timeout_max_retrans = 300
net.ipv4.netfilter.ip_conntrack_tcp_timeout_close = 10
net.ipv4.netfilter.ip_conntrack_tcp_timeout_time_wait = 120
net.ipv4.netfilter.ip_conntrack_tcp_timeout_last_ack = 30
net.ipv4.netfilter.ip_conntrack_tcp_timeout_close_wait = 60
net.ipv4.netfilter.ip_conntrack_tcp_timeout_fin_wait = 120
net.ipv4.netfilter.ip_conntrack_tcp_timeout_established = 432000
net.ipv4.netfilter.ip_conntrack_tcp_timeout_syn_recv = 60
net.ipv4.netfilter.ip_conntrack_tcp_timeout_syn_sent = 120
net.ipv4.tcp_dma_copybreak = 1024
net.ipv4.tcp_abc = 1
net.ipv4.tcp_congestion_control = reno
net.ipv4.tcp_tso_win_divisor = 3
net.ipv4.tcp_moderate_rcvbuf = 1
net.ipv4.tcp_no_metrics_save = 0
net.ipv4.tcp_low_latency = 0
net.ipv4.tcp_frto = 0
net.ipv4.tcp_tw_reuse = 0
net.ipv4.tcp_adv_win_scale = 2
net.ipv4.tcp_app_win = 31
net.ipv4.tcp_rmem = 4096        87380   174760
net.ipv4.tcp_wmem = 4096        16384   131072
net.ipv4.tcp_mem = 12288        16384   24576
net.ipv4.tcp_dsack = 1
net.ipv4.tcp_ecn = 0
net.ipv4.tcp_reordering = 3
net.ipv4.tcp_fack = 1
net.ipv4.tcp_orphan_retries = 0
net.ipv4.tcp_max_syn_backlog = 1024
net.ipv4.tcp_rfc1337 = 0
net.ipv4.tcp_stdurg = 0
net.ipv4.tcp_abort_on_overflow = 0
net.ipv4.tcp_tw_recycle = 0
net.ipv4.tcp_syncookies = 1
net.ipv4.tcp_fin_timeout = 60
net.ipv4.tcp_retries2 = 15
net.ipv4.tcp_retries1 = 3
net.ipv4.tcp_keepalive_intvl = 75
net.ipv4.tcp_keepalive_probes = 9
net.ipv4.tcp_keepalive_time = 7200
net.ipv4.tcp_max_tw_buckets = 180000
net.ipv4.tcp_max_orphans = 4096
net.ipv4.tcp_synack_retries = 5
net.ipv4.tcp_syn_retries = 5
net.ipv4.tcp_retrans_collapse = 1
net.ipv4.tcp_sack = 1
net.ipv4.tcp_window_scaling = 1
net.ipv4.tcp_timestamps = 1

Re:Вложение 10 Кб - уходит тутже. Вложение 100кб - уже не отправляется

> Не установлен ли у вас часом какой-нить тормозящий фильтр

"Осознанно" - нет :) Как бы это проверить.

> когда-то собирала инфу по схожей проблеме на sendmail

Спасибо за ссылку - интересная подборка. Вроде как подтверждает гипотезу с "проблемным MTU".

Надо только осознать - что делать и где лечить. Меня смущает то, что устрановка мной MTU=512 не дало эффекта. Какой он реальный MTU - непонятно. ICMP от данного сайта не ходит.

>Попроси их убрать фаервол ненадолго

Убрали. По крайней мере пинги до nexus.chel.usi.ru стали ходить. С MTU вроде как все хорошо. Пакеты с общим размером до 1492 байта (определяется протоколом PPPoE на ADSL модеме) ходят.

а проблема при этом решилась?

>а проблема при этом решилась?

Нет, Какимто чудом проскочило одно письмо на 100Кб.
А с письмом 800Кб - так и болтается в очереди.
mail:~ # mailq
-Queue ID- --Size-- ----Arrival Time---- -Sender/Recipient-------
9D9FA1172C4  1215865 Wed May 13 11:59:55  xxx@prominform.ru
(conversation with nexus.chel.usi.ru[212.57.144.30] timed out while sending message body)
                                         ууу@chel.usi.ru

а вы не пробовали отправить письмо по этому адресу из другой сети?
Скажем, с mail.ru или другого доступного вам почтовика

>а вы не пробовали отправить письмо по этому адресу из другой сети

Пробовал с mail.ru - доходят нормально.

Т.к. проблемма не относится к проблеммам postfix, а является сетевой, тема переехала:

http://www.linux.org.ru/view-message.jsp?msgid=3712708&nocache=-129653099...

Решение в моем случае: sysctl net.ipv4.tcp_sack=0

Спасибо все принявшим участие в обсуждении.