> -----Ursprüngliche Nachricht-----
> Von: Joe Lewis [mailto:[email protected]] Im Auftrag von jlewis
> Gesendet: Mittwoch, 23. Mai 2012 17:38
> An: [email protected]
> Cc: Pöchtrager, Bernhard
> Betreff: Re: Module: Mod_Dialup (ap_mpm_register_timed_callback)
>
> On Wed, 23 May 2012 06:43:33 +0000
> "Pöchtrager, Bernhard" <[email protected]> wrote:
>
> > > -----Ursprüngliche Nachricht-----
> > > Von: Joe Lewis [mailto:[email protected]] Im Auftrag von Joe
> > > Lewis Gesendet: Dienstag, 22. Mai 2012 17:40
> > > An: [email protected]
> > > Betreff: Re: Module: Mod_Dialup (ap_mpm_register_timed_callback)
> > >
> > >
> > >
> > > On 05/22/2012 12:27 AM, Pöchtrager, Bernhard wrote:
> > > > Hello
> > > >
> > > > I am trying to work with asynchronous requests.
> > > > With synchronous requests everything WORKS fine.
> > > > I write it like mod_dialup.c.
> > > > The result is that every second request is unsuccessful (The
> > > > Browser is
> > > loading the whole time).
> > > Bernhard;
> > >
> > > Do you mean that the connection just appears to be loading? Does it
> > > timeout? Or does the page successfully load?
> > >
> > > Do you see error messages? Are you logging anything to help debug
> > > this? Can you share things like - what you are trying to accomplish,
> > > code, etc?
> > >
> > > Joe
> > >
> >
> > Thanks for your reply.
> > The "complete" explanation was in the first e-mail (apended at the
> > end). I write it again with more information.
> >
> > I am trying to work with asynchronous requests.
> > With synchronous requests everything WORKS fine.
> > I write it like mod_dialup.c.
> > The result is that every second request is unsuccessful (The Browser
> > is loading the whole time). I put some logging-code into the programm.
> > The result ist that the first request works well. When I make a second
> > request the handler doesn't start at all. I get no error and no
> > logging-output. I even log the event.c file, but I get nothing. The
> > request is loading the whole time (I think until he reachs the
> > time-out). After I cancel the request I can make another successful
> > request. When I make another request I have the same problem. I mean
> > every second request is unsuccessful. I even looked with Wireshark on
> > the packages. When the problem appears he got only a few packages. I
> > think the problem is in the line " rv =
> > ap_queue_pop_something(worker_queue, &csd, &cs, &ptrans, &te);" in
> the
> > methode "static void *APR_THREAD_FUNC worker_thread(apr_thread_t
> > * thd, void *dummy)" in the event.c file. I think that the first
> > request isn't finished completely.
> >
> > The relevant Code of the handler is (the change from sync to async):
> >
> ap_mpm_register_timed_callback(apr_time_from_msec(1000),callback,prr);
> > return SUSPENDED;
> >
> > The callback method:
> > static void callback(void* data)
> > {
> > request_rec* prr = (request_rec*) data;
> > ap_finalize_request_protocol(prr);
> > ap_process_request_after_handler(prr);
> > }
> > Do you have any ideas?
> >
>
> Since you are developing your own MPM, I'd suggest getting an strace
> (Linux) or something akin to truss (BSD). You need to find out exactly what
> your MPM is doing when the first request "finishes", and then when the
> second one starts up. strace will give you a LOT of information, and the more
> information you have, the better.
>
> Joe
I created two files. One file with a strace of a successful request and one
with a strace of an unsuccessful request.
The first significant differences between these two requests are following
lines.
4171 <... futex resumed> ) = -1 EAGAIN (Resource temporarily
unavailable)
4170 <... futex resumed> ) = -1 EAGAIN (Resource temporarily
unavailable)
4169 <... futex resumed> ) = -1 EAGAIN (Resource temporarily
unavailable)
4168 <... futex resumed> ) = -1 EAGAIN (Resource temporarily
unavailable)
4167 <... futex resumed> ) = -1 EAGAIN (Resource temporarily
unavailable)
4166 <... futex resumed> ) = -1 EAGAIN (Resource temporarily
unavailable)
4164 <... futex resumed> ) = -1 EAGAIN (Resource temporarily
unavailable)
4171 futex(0x1eda654, FUTEX_WAIT_PRIVATE, 42, NULL <unfinished ...>
4170 futex(0x1eda654, FUTEX_WAIT_PRIVATE, 42, NULL <unfinished ...>
4169 futex(0x1eda654, FUTEX_WAIT_PRIVATE, 42, NULL <unfinished ...>
4168 futex(0x1eda654, FUTEX_WAIT_PRIVATE, 42, NULL <unfinished ...>
4167 futex(0x1eda654, FUTEX_WAIT_PRIVATE, 42, NULL <unfinished ...>
4166 futex(0x1eda654, FUTEX_WAIT_PRIVATE, 42, NULL <unfinished ...>
4164 futex(0x1eda654, FUTEX_WAIT_PRIVATE, 42, NULL <unfinished ...>
Well I think that the first request didn't finish correctly. But what can I do?
Do you have any ideas?
Bernhard
4172 epoll_wait(16, <unfinished ...>
4171 futex(0x1eda654, FUTEX_WAIT_PRIVATE, 38, NULL <unfinished ...>
4170 futex(0x1eda654, FUTEX_WAIT_PRIVATE, 38, NULL <unfinished ...>
4169 futex(0x1eda654, FUTEX_WAIT_PRIVATE, 38, NULL <unfinished ...>
4168 futex(0x1eda654, FUTEX_WAIT_PRIVATE, 38, NULL <unfinished ...>
4167 futex(0x1eda654, FUTEX_WAIT_PRIVATE, 38, NULL <unfinished ...>
4166 futex(0x1eda654, FUTEX_WAIT_PRIVATE, 38, NULL <unfinished ...>
4165 futex(0x1eda654, FUTEX_WAIT_PRIVATE, 42, NULL <unfinished ...>
4164 futex(0x1eda654, FUTEX_WAIT_PRIVATE, 40, NULL <unfinished ...>
4155 restart_syscall(<... resuming interrupted call ...> <unfinished ...>
4154 futex(0x7f47ac000a34, FUTEX_WAIT_PRIVATE, 1, NULL <unfinished ...>
4153 futex(0x7f47b8000a34, FUTEX_WAIT_PRIVATE, 9, NULL <unfinished ...>
4152 futex(0x7f47b400b3c4, FUTEX_WAIT_PRIVATE, 5, NULL <unfinished ...>
4151 futex(0x7f47c0000b74, FUTEX_WAIT_PRIVATE, 1, NULL <unfinished ...>
4150 futex(0x7f47bc005f84, FUTEX_WAIT_PRIVATE, 1, NULL <unfinished ...>
4149 restart_syscall(<... resuming interrupted call ...> <unfinished ...>
4148 restart_syscall(<... resuming interrupted call ...> <unfinished ...>
4147 recvfrom(12, <unfinished ...>
4146 restart_syscall(<... resuming interrupted call ...> <unfinished ...>
4145 restart_syscall(<... resuming interrupted call ...> <unfinished ...>
4144 restart_syscall(<... resuming interrupted call ...> <unfinished ...>
4052 restart_syscall(<... resuming interrupted call ...> <unfinished ...>
4042 select(10, [7 9], NULL, NULL, {8, 957792} <unfinished ...>
4035 read(4, <unfinished ...>
4171 <... futex resumed> ) = -1 EAGAIN (Resource temporarily
unavailable)
4170 <... futex resumed> ) = -1 EAGAIN (Resource temporarily
unavailable)
4169 <... futex resumed> ) = -1 EAGAIN (Resource temporarily
unavailable)
4168 <... futex resumed> ) = -1 EAGAIN (Resource temporarily
unavailable)
4167 <... futex resumed> ) = -1 EAGAIN (Resource temporarily
unavailable)
4166 <... futex resumed> ) = -1 EAGAIN (Resource temporarily
unavailable)
4164 <... futex resumed> ) = -1 EAGAIN (Resource temporarily
unavailable)
4171 futex(0x1eda654, FUTEX_WAIT_PRIVATE, 42, NULL <unfinished ...>
4170 futex(0x1eda654, FUTEX_WAIT_PRIVATE, 42, NULL <unfinished ...>
4169 futex(0x1eda654, FUTEX_WAIT_PRIVATE, 42, NULL <unfinished ...>
4168 futex(0x1eda654, FUTEX_WAIT_PRIVATE, 42, NULL <unfinished ...>
4167 futex(0x1eda654, FUTEX_WAIT_PRIVATE, 42, NULL <unfinished ...>
4166 futex(0x1eda654, FUTEX_WAIT_PRIVATE, 42, NULL <unfinished ...>
4164 futex(0x1eda654, FUTEX_WAIT_PRIVATE, 42, NULL <unfinished ...>
4172 <... epoll_wait resumed> {}, 8, 100) = 0
4172 epoll_wait(16, {}, 8, 100) = 0
4172 epoll_wait(16, {}, 8, 100) = 0
4172 epoll_wait(16, {}, 8, 100) = 0
4172 epoll_wait(16, {}, 8, 100) = 0
4172 epoll_wait(16, {}, 8, 100) = 0
4172 epoll_wait(16, <unfinished ...>
4149 <... restart_syscall resumed> ) = -1 ETIMEDOUT (Connection timed out)
4149 futex(0x2f48a28, FUTEX_WAKE_PRIVATE, 1) = 0
4149 futex(0x7f47c4000a34, FUTEX_WAIT_BITSET_PRIVATE|FUTEX_CLOCK_REALTIME, 1,
{1337849329, 261730000}, ffffffff <unfinished ...>
4172 <... epoll_wait resumed> {}, 8, 100) = 0
4172 epoll_wait(16, {}, 8, 100) = 0
4172 epoll_wait(16, {}, 8, 100) = 0
4172 epoll_wait(16, {}, 8, 100) = 0
4172 epoll_wait(16, {}, 8, 100) = 0
4172 epoll_wait(16, {}, 8, 100) = 0
4172 epoll_wait(16, {}, 8, 100) = 0
4172 epoll_wait(16, {}, 8, 100) = 0
4172 epoll_wait(16, {}, 8, 100) = 0
4172 epoll_wait(16, {}, 8, 100) = 0
4172 epoll_wait(16, <unfinished ...>
4149 <... futex resumed> ) = -1 ETIMEDOUT (Connection timed out)
4149 futex(0x2f48a28, FUTEX_WAKE_PRIVATE, 1) = 0
4149 futex(0x7f47c4000a34, FUTEX_WAIT_BITSET_PRIVATE|FUTEX_CLOCK_REALTIME, 1,
{1337849330, 262141000}, ffffffff <unfinished ...>
4172 <... epoll_wait resumed> {}, 8, 100) = 0
4172 epoll_wait(16, {}, 8, 100) = 0
4172 epoll_wait(16, {}, 8, 100) = 0
4172 epoll_wait(16, {}, 8, 100) = 0
4172 epoll_wait(16, <unfinished ...>
4148 <... restart_syscall resumed> ) = -1 ETIMEDOUT (Connection timed out)
4148 futex(0x3081920, FUTEX_WAKE_PRIVATE, 1) = 0
4148 futex(0x30818f4, FUTEX_WAIT_BITSET_PRIVATE|FUTEX_CLOCK_REALTIME, 1139,
{1337849332, 133423000}, ffffffff <unfinished ...>
4172 <... epoll_wait resumed> {}, 8, 100) = 0
4172 epoll_wait(16, {}, 8, 100) = 0
4172 epoll_wait(16, {}, 8, 100) = 0
4172 epoll_wait(16, {}, 8, 100) = 0
4172 epoll_wait(16, {}, 8, 100) = 0
4172 epoll_wait(16, {}, 8, 100) = 0
4172 epoll_wait(16, <unfinished ...>
4149 <... futex resumed> ) = -1 ETIMEDOUT (Connection timed out)
4149 futex(0x2f48a28, FUTEX_WAKE_PRIVATE, 1) = 0
4149 futex(0x7f47c4000a34, FUTEX_WAIT_BITSET_PRIVATE|FUTEX_CLOCK_REALTIME, 1,
{1337849331, 262507000}, ffffffff <unfinished ...>
4172 <... epoll_wait resumed> {}, 8, 100) = 0
4172 epoll_wait(16, {}, 8, 100) = 0
4172 epoll_wait(16, {}, 8, 100) = 0
4172 epoll_wait(16, {}, 8, 100) = 0
4172 epoll_wait(16, {}, 8, 100) = 0
4172 epoll_wait(16, {}, 8, 100) = 0
4172 epoll_wait(16, {}, 8, 100) = 0
4172 epoll_wait(16, {}, 8, 100) = 0
4172 epoll_wait(16, {}, 8, 100) = 0
4172 epoll_wait(16, {}, 8, 100) = 0
4172 epoll_wait(16, <unfinished ...>
4149 <... futex resumed> ) = -1 ETIMEDOUT (Connection timed out)
4149 futex(0x2f48a28, FUTEX_WAKE_PRIVATE, 1) = 0
4149 futex(0x7f47c4000a34, FUTEX_WAIT_BITSET_PRIVATE|FUTEX_CLOCK_REALTIME, 1,
{1337849332, 262796000}, ffffffff <unfinished ...>
4172 <... epoll_wait resumed> {}, 8, 100) = 0
4172 epoll_wait(16, {}, 8, 100) = 0
4172 epoll_wait(16, {}, 8, 100) = 0
4172 epoll_wait(16, {}, 8, 100) = 0
4172 epoll_wait(16, {}, 8, 100) = 0
4172 epoll_wait(16, {}, 8, 100) = 0
4172 epoll_wait(16, {}, 8, 100) = 0
4172 epoll_wait(16, {}, 8, 100) = 0
4172 epoll_wait(16, {}, 8, 100) = 0
4172 epoll_wait(16, <unfinished ...>
4155 <... restart_syscall resumed> ) = -1 ETIMEDOUT (Connection timed out)
4155 futex(0x2f70e28, FUTEX_WAKE_PRIVATE, 1) = 0
4155 futex(0x2f71654, FUTEX_WAIT_BITSET_PRIVATE|FUTEX_CLOCK_REALTIME, 1,
{1337849337, 108940000}, ffffffff <unfinished ...>
4148 <... futex resumed> ) = -1 ETIMEDOUT (Connection timed out)
4148 futex(0x3081920, FUTEX_WAKE_PRIVATE, 1) = 0
4148 futex(0x30818f4, FUTEX_WAIT_BITSET_PRIVATE|FUTEX_CLOCK_REALTIME, 1141,
{1337849334, 633805000}, ffffffff <unfinished ...>
4172 <... epoll_wait resumed> {}, 8, 100) = 0
4172 epoll_wait(16, <unfinished ...>
4149 <... futex resumed> ) = -1 ETIMEDOUT (Connection timed out)
4149 futex(0x2f48a28, FUTEX_WAKE_PRIVATE, 1) = 0
4149 futex(0x7f47c4000a34, FUTEX_WAIT_BITSET_PRIVATE|FUTEX_CLOCK_REALTIME, 1,
{1337849333, 263114000}, ffffffff <unfinished ...>
4172 <... epoll_wait resumed> {}, 8, 100) = 0
4172 epoll_wait(16, {}, 8, 100) = 0
4172 epoll_wait(16, {}, 8, 100) = 0
4172 epoll_wait(16, <unfinished ...>
4145 <... restart_syscall resumed> ) = -1 ETIMEDOUT (Connection timed out)
4145 futex(0xb8b4a40, FUTEX_WAKE_PRIVATE, 1) = 0
4145 futex(0xb8b4a14, FUTEX_WAIT_BITSET_PRIVATE|FUTEX_CLOCK_REALTIME, 1027,
{1337849332, 526588000}, ffffffff) = -1 ETIMEDOUT (Connection timed out)
4145 futex(0xb8b4a40, FUTEX_WAKE_PRIVATE, 1) = 0
4145 futex(0xb8b4a14, FUTEX_WAIT_BITSET_PRIVATE|FUTEX_CLOCK_REALTIME, 1029,
{1337849337, 526728000}, ffffffff <unfinished ...>
4172 <... epoll_wait resumed> {}, 8, 100) = 0
4172 epoll_wait(16, {}, 8, 100) = 0
4172 epoll_wait(16, {}, 8, 100) = 0
4172 epoll_wait(16, {}, 8, 100) = 0
4172 epoll_wait(16, {}, 8, 100) = 0
4172 epoll_wait(16, {}, 8, 100) = 0
4172 epoll_wait(16, {}, 8, 100) = 0
4172 epoll_wait(16, <unfinished ...>
4149 <... futex resumed> ) = -1 ETIMEDOUT (Connection timed out)
4149 futex(0x2f48a28, FUTEX_WAKE_PRIVATE, 1) = 0
4149 futex(0x7f47c4000a34, FUTEX_WAIT_BITSET_PRIVATE|FUTEX_CLOCK_REALTIME, 1,
{1337849334, 263440000}, ffffffff <unfinished ...>
4172 <... epoll_wait resumed> {}, 8, 100) = 0
4172 epoll_wait(16, {}, 8, 100) = 0
4172 epoll_wait(16, {}, 8, 100) = 0
4172 epoll_wait(16, {}, 8, 100) = 0
4172 epoll_wait(16, {}, 8, 100) = 0
4172 epoll_wait(16, {}, 8, 100) = 0
4172 epoll_wait(16, {}, 8, 100) = 0
4172 epoll_wait(16, {}, 8, 100) = 0
4172 epoll_wait(16, {}, 8, 100) = 0
4172 epoll_wait(16, {}, 8, 100) = 0
4172 epoll_wait(16, <unfinished ...>
4149 <... futex resumed> ) = -1 ETIMEDOUT (Connection timed out)
4149 futex(0x2f48a28, FUTEX_WAKE_PRIVATE, 1) = 0
4149 futex(0x7f47c4000a34, FUTEX_WAIT_BITSET_PRIVATE|FUTEX_CLOCK_REALTIME, 1,
{1337849335, 263656000}, ffffffff <unfinished ...>
4172 <... epoll_wait resumed> {}, 8, 100) = 0
4172 epoll_wait(16, {}, 8, 100) = 0
4172 epoll_wait(16, {}, 8, 100) = 0
4172 epoll_wait(16, {}, 8, 100) = 0
4172 epoll_wait(16, <unfinished ...>
4148 <... futex resumed> ) = -1 ETIMEDOUT (Connection timed out)
4148 futex(0x3081920, FUTEX_WAKE_PRIVATE, 1) = 0
4148 futex(0x30818f4, FUTEX_WAIT_BITSET_PRIVATE|FUTEX_CLOCK_REALTIME, 1143,
{1337849337, 134012000}, ffffffff <unfinished ...>
4172 <... epoll_wait resumed> {}, 8, 100) = 0
4172 epoll_wait(16, {}, 8, 100) = 0
4172 epoll_wait(16, {}, 8, 100) = 0
4172 epoll_wait(16, {}, 8, 100) = 0
4172 epoll_wait(16, {}, 8, 100) = 0
4172 epoll_wait(16, {}, 8, 100) = 0
4172 epoll_wait(16, <unfinished ...>
4149 <... futex resumed> ) = -1 ETIMEDOUT (Connection timed out)
4149 futex(0x2f48a28, FUTEX_WAKE_PRIVATE, 1) = 0
4149 futex(0x7f47c4000a34, FUTEX_WAIT_BITSET_PRIVATE|FUTEX_CLOCK_REALTIME, 1,
{1337849336, 264025000}, ffffffff <unfinished ...>
4172 <... epoll_wait resumed> {}, 8, 100) = 0
4172 epoll_wait(16, {}, 8, 100) = 0
4172 epoll_wait(16, {}, 8, 100) = 0
4172 epoll_wait(16, <unfinished ...>
4052 <... restart_syscall resumed> ) = 0
4052 nanosleep({30, 0}, <unfinished ...>
4172 <... epoll_wait resumed> {}, 8, 100) = 0
4172 epoll_wait(16, {}, 8, 100) = 0
4172 epoll_wait(16, {}, 8, 100) = 0
4172 epoll_wait(16, {}, 8, 100) = 0
4172 epoll_wait(16, {}, 8, 100) = 0
4172 epoll_wait(16, {}, 8, 100) = 0
4172 epoll_wait(16, <unfinished ...>
4172 epoll_wait(16, <unfinished ...>
4171 futex(0x1eda654, FUTEX_WAIT_PRIVATE, 42, NULL <unfinished ...>
4170 futex(0x1eda654, FUTEX_WAIT_PRIVATE, 42, NULL <unfinished ...>
4169 futex(0x1eda654, FUTEX_WAIT_PRIVATE, 42, NULL <unfinished ...>
4168 futex(0x1eda654, FUTEX_WAIT_PRIVATE, 42, NULL <unfinished ...>
4167 futex(0x1eda654, FUTEX_WAIT_PRIVATE, 42, NULL <unfinished ...>
4166 futex(0x1eda654, FUTEX_WAIT_PRIVATE, 42, NULL <unfinished ...>
4165 futex(0x1eda654, FUTEX_WAIT_PRIVATE, 42, NULL <unfinished ...>
4164 futex(0x1eda654, FUTEX_WAIT_PRIVATE, 42, NULL <unfinished ...>
4155 restart_syscall(<... resuming interrupted call ...> <unfinished ...>
4154 futex(0x7f47ac000a34, FUTEX_WAIT_PRIVATE, 1, NULL <unfinished ...>
4153 futex(0x7f47b8000a34, FUTEX_WAIT_PRIVATE, 9, NULL <unfinished ...>
4152 futex(0x7f47b400b3c4, FUTEX_WAIT_PRIVATE, 5, NULL <unfinished ...>
4151 futex(0x7f47c0000b74, FUTEX_WAIT_PRIVATE, 1, NULL <unfinished ...>
4150 futex(0x7f47bc005f84, FUTEX_WAIT_PRIVATE, 1, NULL <unfinished ...>
4149 restart_syscall(<... resuming interrupted call ...> <unfinished ...>
4148 restart_syscall(<... resuming interrupted call ...> <unfinished ...>
4147 recvfrom(12, <unfinished ...>
4146 restart_syscall(<... resuming interrupted call ...> <unfinished ...>
4145 restart_syscall(<... resuming interrupted call ...> <unfinished ...>
4144 restart_syscall(<... resuming interrupted call ...> <unfinished ...>
4052 restart_syscall(<... resuming interrupted call ...> <unfinished ...>
4042 select(10, [7 9], NULL, NULL, {11, 437062} <unfinished ...>
4035 read(4, <unfinished ...>
4172 <... epoll_wait resumed> {}, 8, 100) = 0
4172 epoll_wait(16, <unfinished ...>
4149 <... restart_syscall resumed> ) = -1 ETIMEDOUT (Connection timed out)
4149 futex(0x2f48a28, FUTEX_WAKE_PRIVATE, 1) = 0
4149 futex(0x7f47c4000a34, FUTEX_WAIT_BITSET_PRIVATE|FUTEX_CLOCK_REALTIME, 1,
{1337849371, 272736000}, ffffffff <unfinished ...>
4172 <... epoll_wait resumed> {}, 8, 100) = 0
4172 epoll_wait(16, {}, 8, 100) = 0
4172 epoll_wait(16, {}, 8, 100) = 0
4172 epoll_wait(16, {}, 8, 100) = 0
4172 epoll_wait(16, {}, 8, 100) = 0
4172 epoll_wait(16, {}, 8, 100) = 0
4172 epoll_wait(16, {}, 8, 100) = 0
4172 epoll_wait(16, {}, 8, 100) = 0
4172 epoll_wait(16, {}, 8, 100) = 0
4172 epoll_wait(16, {}, 8, 100) = 0
4172 epoll_wait(16, <unfinished ...>
4149 <... futex resumed> ) = -1 ETIMEDOUT (Connection timed out)
4149 futex(0x2f48a28, FUTEX_WAKE_PRIVATE, 1) = 0
4149 futex(0x7f47c4000a34, FUTEX_WAIT_BITSET_PRIVATE|FUTEX_CLOCK_REALTIME, 1,
{1337849372, 273024000}, ffffffff <unfinished ...>
4172 <... epoll_wait resumed> {}, 8, 100) = 0
4172 epoll_wait(16, {}, 8, 100) = 0
4172 epoll_wait(16, {}, 8, 100) = 0
4172 epoll_wait(16, {}, 8, 100) = 0
4172 epoll_wait(16, {}, 8, 100) = 0
4172 epoll_wait(16, {}, 8, 100) = 0
4172 epoll_wait(16, {}, 8, 100) = 0
4172 epoll_wait(16, {}, 8, 100) = 0
4172 epoll_wait(16, <unfinished ...>
4155 <... restart_syscall resumed> ) = -1 ETIMEDOUT (Connection timed out)
4155 futex(0x2f70e28, FUTEX_WAKE_PRIVATE, 1) = 0
4155 futex(0x2f71654, FUTEX_WAIT_BITSET_PRIVATE|FUTEX_CLOCK_REALTIME, 1,
{1337849377, 110039000}, ffffffff <unfinished ...>
4148 <... restart_syscall resumed> ) = -1 ETIMEDOUT (Connection timed out)
4148 futex(0x3081920, FUTEX_WAKE_PRIVATE, 1) = 0
4148 futex(0x30818f4, FUTEX_WAIT_BITSET_PRIVATE|FUTEX_CLOCK_REALTIME, 1173,
{1337849374, 636065000}, ffffffff <unfinished ...>
4172 <... epoll_wait resumed> {}, 8, 100) = 0
4172 epoll_wait(16, {}, 8, 100) = 0
4172 epoll_wait(16, <unfinished ...>
4149 <... futex resumed> ) = -1 ETIMEDOUT (Connection timed out)
4149 futex(0x2f48a28, FUTEX_WAKE_PRIVATE, 1) = 0
4149 futex(0x7f47c4000a34, FUTEX_WAIT_BITSET_PRIVATE|FUTEX_CLOCK_REALTIME, 1,
{1337849373, 273212000}, ffffffff <unfinished ...>
4172 <... epoll_wait resumed> {}, 8, 100) = 0
4172 epoll_wait(16, {}, 8, 100) = 0
4172 epoll_wait(16, <unfinished ...>
4145 <... restart_syscall resumed> ) = -1 ETIMEDOUT (Connection timed out)
4145 futex(0xb8b4a40, FUTEX_WAKE_PRIVATE, 1) = 0
4145 futex(0xb8b4a14, FUTEX_WAIT_BITSET_PRIVATE|FUTEX_CLOCK_REALTIME, 1059,
{1337849372, 529087000}, ffffffff) = -1 ETIMEDOUT (Connection timed out)
4145 futex(0xb8b4a40, FUTEX_WAKE_PRIVATE, 1) = 0
4145 futex(0xb8b4a14, FUTEX_WAIT_BITSET_PRIVATE|FUTEX_CLOCK_REALTIME, 1061,
{1337849377, 529293000}, ffffffff <unfinished ...>
4172 <... epoll_wait resumed> {}, 8, 100) = 0
4172 epoll_wait(16, {}, 8, 100) = 0
4172 epoll_wait(16, {}, 8, 100) = 0
4172 epoll_wait(16, {{EPOLLIN, {u32=33460864, u64=33460864}}}, 8, 100) = 1
4172 accept(3, {sa_family=AF_INET, sin_port=htons(45383),
sin_addr=inet_addr("127.0.0.1")}, [16]) = 25
4172 fcntl(25, F_GETFD) = 0
4172 fcntl(25, F_SETFD, FD_CLOEXEC) = 0
4172 futex(0x1eda654, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x1eda650, {FUTEX_OP_SET,
0, FUTEX_OP_CMP_GT, 1}) = 1
4171 <... futex resumed> ) = 0
4172 futex(0x1eda600, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
4171 futex(0x1eda600, FUTEX_WAIT_PRIVATE, 2, NULL <unfinished ...>
4172 <... futex resumed> ) = 0
4171 <... futex resumed> ) = -1 EAGAIN (Resource temporarily
unavailable)
4172 epoll_wait(16, <unfinished ...>
4171 futex(0x1eda600, FUTEX_WAKE_PRIVATE, 1) = 0
4171 write(2, "event.c=>Bernhard... Socket wird ausgef\303\274hrt!\n", 46) = 46
4171 mprotect(0x7f47dc056000, 8192, PROT_READ|PROT_WRITE) = 0
4171 getsockname(25, {sa_family=AF_INET, sin_port=htons(17080),
sin_addr=inet_addr("127.0.0.1")}, [16]) = 0
4171 fcntl(25, F_GETFL) = 0x2 (flags O_RDWR)
4171 fcntl(25, F_SETFL, O_RDWR|O_NONBLOCK) = 0
4171 write(2, "Werde ich bei jedem Request aufgerufen? 1\n", 42) = 42
4171 mprotect(0x7f47dc058000, 8192, PROT_READ|PROT_WRITE) = 0
4171 mprotect(0x7f47dc05a000, 8192, PROT_READ|PROT_WRITE) = 0
4171 read(25, "GET /fsc/fscasp/content/bin/test.dll?h HTTP/1.1\r\nHost:
localhost:17080\r\nUser-Agent: Mozilla/5.0 (X11; U; Linux x86_64; en-US;
rv:1.9.2.24) Gecko/20111109 CentOS/3.6.24-3.el6.centos
Firefox/3.6.24\r\nAccept:
text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8\r\nAccept-Language:
en-us,en;q=0.5\r\nAccept-Encoding: gzip,deflate\r\nAccept-Charset:
ISO-8859-1,utf-8;q=0.7,*;q=0.7\r\nKeep-Alive: 115\r\nConnection:
keep-alive\r\nAuthorization: Basic
QWRtaW5pc3RyYXRvcjpGYWJhODg4OA==\r\nCache-Control: max-age=0\r\n\r\n", 8000) =
509
4171 stat("/opt/software/share/web/WebService_100/asp/content/bin/test.dll",
0x7f47a97faa90) = -1 ENOENT (No such file or directory)
4171 lstat("/opt", {st_dev=makedev(8, 1), st_ino=786433, st_mode=S_IFDIR|0755,
st_nlink=5, st_uid=0, st_gid=0, st_blksize=4096, st_blocks=8, st_size=4096,
st_atime=2012/05/24-10:08:09, st_mtime=2012/05/02-11:40:38,
st_ctime=2012/05/02-11:40:38}) = 0
4171 lstat("/opt/software", {st_dev=makedev(8, 1), st_ino=790927,
st_mode=S_IFDIR|S_ISGID|0755, st_nlink=8, st_uid=500, st_gid=500,
st_blksize=4096, st_blocks=8, st_size=4096, st_atime=2012/05/24-10:08:10,
st_mtime=2012/05/02-11:51:03, st_ctime=2012/05/02-11:51:03}) = 0
4171 lstat("/opt/software/share", {st_dev=makedev(8, 1), st_ino=791048,
st_mode=S_IFDIR|S_ISGID|0755, st_nlink=11, st_uid=500, st_gid=500,
st_blksize=4096, st_blocks=8, st_size=4096, st_atime=2012/05/24-10:08:10,
st_mtime=2012/05/02-11:54:50, st_ctime=2012/05/02-11:54:50}) = 0
4171 lstat("/opt/software/share/web", {st_dev=makedev(8, 1), st_ino=920462,
st_mode=S_IFDIR|S_ISGID|0770, st_nlink=6, st_uid=500, st_gid=500,
st_blksize=4096, st_blocks=8, st_size=4096, st_atime=2012/05/24-10:08:39,
st_mtime=2012/05/04-10:12:49, st_ctime=2012/05/04-10:12:49}) = 0
4171 lstat("/opt/software/share/web/WebService_100", {st_dev=makedev(8, 1),
st_ino=920464, st_mode=S_IFDIR|S_ISGID|0755, st_nlink=3, st_uid=500,
st_gid=500, st_blksize=4096, st_blocks=8, st_size=4096,
st_atime=2012/05/24-10:17:07, st_mtime=2012/05/11-09:42:44,
st_ctime=2012/05/24-10:17:07}) = 0
4171 lstat("/opt/software/share/web/WebService_100/asp", {st_dev=makedev(8,
1), st_ino=920465, st_mode=S_IFDIR|S_ISGID|0755, st_nlink=5, st_uid=500,
st_gid=500, st_blksize=4096, st_blocks=8, st_size=4096,
st_atime=2012/05/24-10:17:07, st_mtime=2012/05/01-20:42:15,
st_ctime=2012/05/24-10:17:07}) = 0
4171 lstat("/opt/software/share/web/WebService_100/asp/content",
{st_dev=makedev(8, 1), st_ino=920476, st_mode=S_IFDIR|S_ISGID|0755, st_nlink=4,
st_uid=500, st_gid=500, st_blksize=4096, st_blocks=8, st_size=4096,
st_atime=2012/05/24-10:17:07, st_mtime=2012/05/02-11:55:07,
st_ctime=2012/05/24-10:17:07}) = 0
4171 lstat("/opt/software/share/web/WebService_100/asp/content/bin",
{st_dev=makedev(8, 1), st_ino=920479, st_mode=S_IFDIR|S_ISGID|0750, st_nlink=2,
st_uid=500, st_gid=500, st_blksize=4096, st_blocks=8, st_size=4096,
st_atime=2012/05/24-10:17:08, st_mtime=2012/05/01-20:42:15,
st_ctime=2012/05/24-10:17:08}) = 0
4171 lstat("/opt/software/share/web/WebService_100/asp/content/bin/test.dll",
0x7f47a97faa90) = -1 ENOENT (No such file or directory)
4171 mprotect(0x7f47dc05c000, 8192, PROT_READ|PROT_WRITE) = 0
4171 open("/etc/software/web/htpasswd", O_RDONLY|O_CLOEXEC) = 26
4171 fstat(26, {st_dev=makedev(8, 1), st_ino=1313476, st_mode=S_IFREG|0770,
st_nlink=1, st_uid=500, st_gid=500, st_blksize=4096, st_blocks=8, st_size=28,
st_atime=2012/05/24-10:21:50, st_mtime=2012/05/02-11:55:07,
st_ctime=2012/05/02-11:55:07}) = 0
4171 read(26, "Administrator:v/2/Ks9kEARuQ\n", 4096) = 28
4171 close(26) = 0
4171 write(2, "Aufruf ap_invoke_handler \303\274ber methode
ap_process_async_request\n", 64) = 64
4171 write(2, "invoke-Handler\n", 15) = 15
4171 write(2, "Bernhard... Der Handler wird aufgerufen!\n", 41) = 41
4171 write(2, "Bernhard... fscvext_handler\n", 28) = 28
4171 write(2, "event.c=>Bernhard... timed_callback wird aufgerufen\n", 52) = 52
4171 write(2, "Bernhard... Der Status ist 4 XXX\n", 33) = 33
4171 write(2, "event.c=>Bernhard... das ist ein Test\n", 38) = 38
4171 write(2, "Workers online1\n", 16) = 16
4171 futex(0x1eda654, FUTEX_WAIT_PRIVATE, 44, NULL <unfinished ...>
4172 <... epoll_wait resumed> {}, 8, 100) = 0
4172 epoll_wait(16, <unfinished ...>
4149 <... futex resumed> ) = -1 ETIMEDOUT (Connection timed out)
4149 futex(0x2f48a28, FUTEX_WAKE_PRIVATE, 1) = 0
4149 futex(0x7f47c4000a34, FUTEX_WAIT_BITSET_PRIVATE|FUTEX_CLOCK_REALTIME, 1,
{1337849374, 273518000}, ffffffff <unfinished ...>
4172 <... epoll_wait resumed> {}, 8, 902) = 0
4172 futex(0x1eda654, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x1eda650, {FUTEX_OP_SET,
0, FUTEX_OP_CMP_GT, 1}) = 1
4170 <... futex resumed> ) = 0
4172 futex(0x1eda600, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
4170 futex(0x1eda600, FUTEX_WAIT_PRIVATE, 2, NULL <unfinished ...>
4172 <... futex resumed> ) = 0
4170 <... futex resumed> ) = -1 EAGAIN (Resource temporarily
unavailable)
4172 epoll_wait(16, <unfinished ...>
4170 futex(0x1eda600, FUTEX_WAKE_PRIVATE, 1) = 0
4170 write(2, "Bernhard... der callback wurde erfolgreich
ausgef\303\274hrt!\n", 56) = 56
4170 mprotect(0x7f47cc03f000, 8192, PROT_READ|PROT_WRITE) = 0
4170 mprotect(0x7f47cc041000, 8192, PROT_READ|PROT_WRITE) = 0
4170 mprotect(0x7f47cc043000, 8192, PROT_READ|PROT_WRITE) = 0
4170 mprotect(0x7f47cc045000, 8192, PROT_READ|PROT_WRITE) = 0
4170 writev(25, [{"HTTP/1.1 200 OK\r\nDate: Thu, 24 May 2012 08:49:32
GMT\r\nServer: Apache\r\nExpires: 0\r\nCache-Control: no-cache\r\nPragma:
no-cache\r\nContent-Length: 1057\r\nKeep-Alive: timeout=120\r\nConnection:
Keep-Alive\r\nContent-Type: text/html\r\nContent-Language: en\r\n\r\n", 245},
{"<html><body><i>Status</i><br>up 28m13s ticks 1337849373803 waiting 0 running
0 threads 0 requests 0<br>pid 4035<br>current date time 24.05.2012
10:49:33<br><br><i>Settings</i><br><table
border='1'>\n<tr><td>VERSION</td><td>12.9.9.500</td></tr><tr><td>FSCVEXT_MAXTHREADS</td><td>8</td></tr><tr><td>FSCVEXT_MAXWAITMSECS</td><td>0</td></tr><tr><td>FSCVEXT_MAXDELAYMSECS</td><td>300000</td></tr><tr><td>FSCVEXT_MAXREQUESTMSECS</td><td>300000</td></tr><tr><td>FSCVEXT_MAXSERVICEMSECS</td><td>600000</td></tr><tr><td>FSCVEXT_PRELOADUSERS</td><td>5000</td></tr><tr><td>FSCVEXT_PRELOADWORKSTATIONS</td><td>5000</td></tr><tr><td>FSCVEXT_PROCESSAFFINITYMASK</td><td>0x00000000</td></tr><tr><td>FSCVEXT_COINITFLAGS</td><td>0x00000000</td></tr><tr><td>FSCVEXT_USETHREADPOOL</td><td>YES</td></tr><tr><td>FSCVEXT_CHECKTHREADS</td><td>YES</td></tr><tr><td>FSCVEXT_CHECKSERVICE</td><td>NO</td></tr></table>\n<br><i>Running</i><br><table
border='1'>\n<tr><td>msecs</td><td>delay/time</td><td>id</td><td>content
I/O</td><td>who</td><td>what</td>"..., 1057}], 2) = 1302
4170 write(2, "Bernhard... Status=OK Exit=1!\n", 30) = 30
4170 write(2, "Bernhard... status vom request ist -1 (OK=0,
HTTP_OK=200,DECLINED=-1 & SUSPENDED=-3. Wert von ap_run_quick_handler: -1)\n",
120) = 120
4170 write(2, "Bernhard... ap_process_request_after_handler wurde erfolgreich
ausgef\303\274hrt!\n", 76) = 76
4170 write(2, "event.c=>Bernhard... das ist ein Test\n", 38) = 38
4170 write(2, "Workers online1\n", 16) = 16
4170 futex(0x1eda654, FUTEX_WAIT_PRIVATE, 46, NULL <unfinished ...>
4172 <... epoll_wait resumed> {}, 8, 100) = 0
4172 epoll_wait(16, {}, 8, 100) = 0
4172 epoll_wait(16, {}, 8, 100) = 0
4172 epoll_wait(16, {}, 8, 100) = 0
4172 epoll_wait(16, <unfinished ...>
4149 <... futex resumed> ) = -1 ETIMEDOUT (Connection timed out)
4149 futex(0x2f48a28, FUTEX_WAKE_PRIVATE, 1) = 0
4149 futex(0x7f47c4000a34, FUTEX_WAIT_BITSET_PRIVATE|FUTEX_CLOCK_REALTIME, 1,
{1337849375, 274075000}, ffffffff <unfinished ...>
4172 <... epoll_wait resumed> {}, 8, 100) = 0
4172 epoll_wait(16, {}, 8, 100) = 0
4172 epoll_wait(16, {}, 8, 100) = 0
4172 epoll_wait(16, {}, 8, 100) = 0
4172 epoll_wait(16, <unfinished ...>
4148 <... futex resumed> ) = -1 ETIMEDOUT (Connection timed out)
4148 futex(0x3081920, FUTEX_WAKE_PRIVATE, 1) = 0
4148 futex(0x30818f4, FUTEX_WAIT_BITSET_PRIVATE|FUTEX_CLOCK_REALTIME, 1175,
{1337849377, 136288000}, ffffffff <unfinished ...>
4172 <... epoll_wait resumed> {}, 8, 100) = 0
4172 epoll_wait(16, {}, 8, 100) = 0
4172 epoll_wait(16, {}, 8, 100) = 0
4172 epoll_wait(16, {}, 8, 100) = 0
4172 epoll_wait(16, {}, 8, 100) = 0
4172 epoll_wait(16, {}, 8, 100) = 0
4172 epoll_wait(16, <unfinished ...>
4149 <... futex resumed> ) = -1 ETIMEDOUT (Connection timed out)
4149 futex(0x2f48a28, FUTEX_WAKE_PRIVATE, 1) = 0
4149 futex(0x7f47c4000a34, FUTEX_WAIT_BITSET_PRIVATE|FUTEX_CLOCK_REALTIME, 1,
{1337849376, 274432000}, ffffffff <unfinished ...>
4172 <... epoll_wait resumed> {}, 8, 100) = 0
4172 epoll_wait(16, {}, 8, 100) = 0
4172 epoll_wait(16, {}, 8, 100) = 0
4172 epoll_wait(16, {}, 8, 100) = 0
4172 epoll_wait(16, {}, 8, 100) = 0
4172 epoll_wait(16, <unfinished ...>
