Hi,
I'm currently stuck with a strange performance problem with my James
3.0-beta3 when I'm running our integration tests.
As you can see from the extract of the james-server.log, James takes
about 15 seconds from the time where the SMTP connection is closed to
the time where the email is sent to the remote delivery gateway.
According to the log-File the TcpTransport seems to be the problem.
Log-Output with DEBUG enabled:
INFO 2013-06-06 15:53:14,663 | pool-14-thread-12 |
smtpserver | ID=21754426 Connection closed for
127.0.0.1 (127.0.0.1)
DEBUG 2013-06-06 15:53:14,664 | dequeuer-2 |
TransactionContext | Begin:TX:ID:TP-59968-1370526743782-3:1:1
DEBUG 2013-06-06 15:53:14,670 | dequeuer-2 |
CachingConnectionFactory | Creating cached JMS Session for mode 0:
ActiveMQSession {id=ID:TP-59968-1370526743782-3:1:14,started=true}
DEBUG 2013-06-06 15:53:14,670 | spooler-1 |
mailspooler | ==== Begin processing mail
Mail1370526794622-977f4719-b1e2-4d48-8d5e-8d2dda4df9a4====
... lines ommitted
DEBUG 2013-06-06 15:53:14,710 | spooler-1 |
MulticastProcessor | Done sequential processing 1 exchanges
DEBUG 2013-06-06 15:53:16,959 | dmlc-2 |
TcpTransport | Stopping transport tcp://localhost:61616
DEBUG 2013-06-06 15:53:22,960 | dmlc-2 |
TcpTransport | Stopping transport tcp://localhost:61616
DEBUG 2013-06-06 15:53:23,101 | Remote delivery thread (3) |
ActiveMQSession | ID:TP-59968-1370526743782-3:1:4
Transaction Commit :null
DEBUG 2013-06-06 15:53:23,102 | Remote delivery thread (3) |
ActiveMQMessageConsumer | remove:
ID:TP-59968-1370526743782-3:1:4:4, lastDeliveredSequenceId:0
... lines ommitted
DEBUG 2013-06-06 15:53:24,672 | dequeuer-2 |
ActiveMQSession | ID:TP-59968-1370526743782-3:1:14
Transaction Commit :null
DEBUG 2013-06-06 15:53:24,672 | dequeuer-2 |
ActiveMQMessageConsumer | remove:
ID:TP-59968-1370526743782-3:1:14:1, lastDeliveredSequenceId:0
DEBUG 2013-06-06 15:53:24,672 | VMTransport |
AbstractRegion | james removing consumer:
ID:TP-59968-1370526743782-3:1:14:1 for destination: queue://spool
DEBUG 2013-06-06 15:53:24,672 | VMTransport | Queue
| remove sub: QueueSubscription:
consumer=ID:TP-59968-1370526743782-3:1:14:1, destinations=1,
dispatched=0, delivered=0, pending=0, lastDeliveredSeqId: 0, dequeues:
0, dispatched: 1, inflight: 1
DEBUG 2013-06-06 15:53:24,673 | VMTransport |
AbstractRegion | james adding consumer:
ID:TP-59968-1370526743782-3:1:14:2 for destination: queue://spool
DEBUG 2013-06-06 15:53:28,961 | dmlc-2 |
TcpTransport | Stopping transport tcp://localhost:61616
DEBUG 2013-06-06 15:53:29,776 | spooler-1 |
BeanProcessor | Setting bean invocation result on the
OUT message: [org.apache.james.core.MailImpl@17c84ad]
DEBUG 2013-06-06 15:53:29,777 | spooler-1 |
ChoiceProcessor | #0 -
org.apache.james.mailetcontainer.impl.camel.MatcherMatch@4af1f4 matches:
false for: Exchange[Message: org.apache.james.core.MailImpl@17c84ad]
... lines ommitted
INFO 2013-06-06 15:53:30,268 | Remote delivery thread (3) |
mailetcontext | Attempting delivery of
Mail1370526794622-977f4719-b1e2-4d48-8d5e-8d2dda4df9a4-!814652-!34457 to
host 127.0.0.1 at 127.0.0.1 from
bounce+bissc6cwb1q5swcn-B=127.0.0.1@localhost for addresses
[[email protected]]
INFO 2013-06-06 15:53:30,300 | Remote delivery thread (3) |
mailetcontext | Mail
(Mail1370526794622-977f4719-b1e2-4d48-8d5e-8d2dda4df9a4-!814652-!34457)
sent successfully to 127.0.0.1 at 127.0.0.1 from
bounce+bissc6cwb1q5swcn-B=127.0.0.1@localhost for [[email protected]]
The problem occurs on my Windows 7 machine as well as on our Jenkins
which runs on Linux.
Does anybody know of this issue or does anybody have a hint for me?
Thanks
Markus
