weixin_39956036
weixin_39956036
2021-01-03 05:14

Processes fork()'ing without limits (With OpenBSD)

Hi,

I'm actually using the latest version of your DansGuardian fork (2.12.0.7.2), which I downloaded fro numsys.eu just yesterday, which I suspect to be quite similar to the e2guardian for now (I discovered e2guardian just now).

I'm running it under OpenBSD 5.3 (latest version), but there seems to be an issue with it: at some point, for some reason I can't figure out, it just starts spawning processes (forking) beyond the maxchildren limit and filling up the processes table. This happened twice for me already -- the first time it filled up the process table up to 1310 processes (the normal limit, when maxchildren was at 120 I think). I then increased kern.maxproc to 8192, and this morning the same thing happened.

I compiled it with the following options:


$ /usr/local/sbin/dansguardian-2.12.0.7 -v
DansGuardian 2.12.0.7 http://numsys.eu - Unofficial Release ! -

Built with:  '--with-proxygroup=_dansguardian' '--with-proxyuser=_dansguardian' '--enable-segv-backtrace=no' '--prefix=' '--exec-prefix=/usr/local'

By the way, I'm using it because the latest "official" release of DansGuardian was having issues as well. Primarily, it would "freeze" at some point for unspecified amounts of time under medium load, and then resume operation. This release threw the error "Error connecting to proxy", which I didn't experience when trying out your release, although I did experience these freezes at some points. I already upgraded squid from 2.7 to 3.1, and the problem doesn't seem to be there... I'm beginning to suspect of the OS, but when I try to look to find for errors or anything there, I can't find any... Do you have a clue of what may be causing this?

Also, the hardware we're running it on is quite old (a Celeron with 512MB of RAM), which we intend to replace shortly but, again, other than seeing the CPU at 100% at some points, I don't see other limits being reached, or the machine becoming totally unresponsive.

Thank you very much for your work!

该提问来源于开源项目:e2guardian/e2guardian

  • 点赞
  • 写回答
  • 关注问题
  • 收藏
  • 复制链接分享
  • 邀请回答

31条回答

  • weixin_39956036 weixin_39956036 4月前

    Hi,

    Yes, about the "stalling" issue, I did experiment it with the official release too until last week...

    Now that I've upgraded the hardware I've incremented maxchildren especially, to see if this problem keeps happening. I'm going to ask several people to see if they notice an improvement and get back to you.

    What strikes me as odd is that this stalling issues happens even when all the dansguardian processes show up as "idle" or in "select" state, and with CPU loads of almost 0%-5%... That's also why I'm not entirely sure this was originally a hardware issue...

    As a matter of fact, I ran OpenBSD 4.0 (quite old now) with dansguardian 2.8.0.6 on the old hardware before upgrading to OpenBSD 5.3, and the stalling issue never occurred (or was never reported at least) as far as I'm aware... I don't know what kinds of changes were made to Dansguardian between 2.8.0.6 and 2.12.0.3, but these did seem to affect some particular aspects of it, at least under OpenBSD...

    点赞 评论 复制链接分享
  • weixin_39528467 weixin_39528467 4月前

    Ok we will see

    But be careful you can't only change maxchildren

    点赞 评论 复制链接分享
  • weixin_39956036 weixin_39956036 4月前

    Ok, I understand what you mean. I've increased the other values as well to see if performance improves. In the meantime, I'm going to stick with the official release -- if things seem to have improved, I will try moving to your release (with the fix) to see what happens.

    I'll get back with results when I have them.

    Thanks for your help!

    点赞 评论 复制链接分享
  • weixin_39956036 weixin_39956036 4月前

    One more thing to consider when looking for potential roots of this problem: originally, in the dansguardian code (at least as of version 2.12.0.3) there was no "out of bound" checking/correction for getchildslot(). I'm actually running that version and the spawning problem never occurred.

    At some point, between this release and your version:

    1) epoll was added to Linux, AND 2) the checking/correction piece of code was added to epoll part ONLY

    Now, why was 2) necessary? It should not have been there in the first place, unless this behavior was somehow experienced in the epoll version as well at some point...

    点赞 评论 复制链接分享
  • weixin_39528467 weixin_39528467 4月前

    It's exactly what I'm thinking about:-) I will write to Phillip tomorrow (he wrote this part of code)

    Thank for your help, can you send me your real name for the changelog ? But I can write Narwhal2 as you want

    点赞 评论 复制链接分享
  • weixin_39956036 weixin_39956036 4月前

    No problem, my name is Martín Coco :)

    Thanks!

    点赞 评论 复制链接分享
  • weixin_39528467 weixin_39528467 4月前

    Message from Philip

    
    "I've posted a fix (hopefully) on this problem to the master e2guardian branch.    There was an error in mopup_afterkids so that delete_child was not being called when not a linux system - this may be the cause of this problem.
    
    To answer your question re fds when in epoll mode the way the array(s) of children information is held is different from before.
    
    When NOT epoll fds is just a number of array slots and the fd is contained within one the array structures - so it is possible at times that the fd may be higher than fds without affecting the logic. 
    
    With epoll the fd is used as the index for the array, so fd must not exceed fds.   Yes, I have had this happen at certain times (system overloaded, very slow to kill processes etc) so this code protects against this and auto-recovers."
    

    Please can you try this file: https://github.com/fredbcode/e2guardian/blob/master/src/FatController.cpp

    Thank

    点赞 评论 复制链接分享
  • weixin_39956036 weixin_39956036 4月前

    Cool, I'm going to download it, recompile and let you know.

    Thanks!

    点赞 评论 复制链接分享
  • weixin_39956036 weixin_39956036 4月前

    I wanted to let you know that, so far, I haven't run into the forking issue again. Also, I haven't noticed any "out of range" message after recompiling the code with the fix.

    About performance, it does seem to be running better, although I have tuned a bit max_children and other values, and hardware has been upgraded, so I don't know for certain if this could have fixed or impacted that issue as well.

    Thanks for all your help!

    点赞 评论 复制链接分享
  • weixin_39528467 weixin_39528467 4月前

    Ok great, so I will close the ticket There are many complaints about BSD and DansGuardian (Signal 11 bug , crash, etc) I hope this can help

    Changelog here: https://github.com/e2guardian/e2guardian/blob/master/ChangeLog

    Thank very much for your tests and help

    点赞 评论 复制链接分享
  • weixin_39528467 weixin_39528467 4月前

    Do you known the process status (zombie ?) and do you have signal 11 in syslog ? Please, can you post your maxagechildren value ?

    点赞 评论 复制链接分享
  • weixin_39528467 weixin_39528467 4月前

    I need maxagechildren not maxchildren value, it seem that your process never died To find zombies: ps -el | grep dans | grep 'Z' -> For dansguardian ps -el | grep e2gua | grep 'Z' -> For e2guardian

    With maxchildren = 40 and thousands of requests, I never increase beyond 43 process ps -edf | grep dans | wc -l 43

    And I'm trying a little maxagevalue = 50 (very short)

    Oct 17 17:50:21 test e2guardian[18321]: deleted child: fd: 39 pid: -1 Oct 17 17:50:21 test e2guardian[18321]: Fewer than 5 free children - Spawning 20 process(es) Oct 17 17:50:21 test e2guardian[18321]: added child: fd: 39 pid: 18432 Oct 17 17:50:22 test e2guardian[18388]: Child has handled 50 requests and is exiting Oct 17 17:50:22 test e2guardian[18321]: deleted child: fd: 35 pid: -1 Oct 17 17:50:22 test e2guardian[18321]: Fewer than 5 free children - Spawning 20 process(es) Oct 17 17:50:22 test e2guardian[18321]: added child: fd: 35 pid: 18433 Oct 17 17:50:22 test e2guardian[18401]: Child has handled 50 requests and is exiting Oct 17 17:50:22 test e2guardian[18321]: deleted child: fd: 7 pid: -1 Oct 17 17:50:22 test e2guardian[18321]: Fewer than 5 free children - Spawning 20 process(es) Oct 17 17:50:22 test e2guardian[18321]: added child: fd: 7 pid: 18434 Oct 17 17:50:22 test e2guardian[18384]: Child has handled 50 requests and is exiting Oct 17 17:50:22 test e2guardian[18321]: deleted child: fd: 37 pid: -1 Oct 17 17:50:22 test e2guardian[18321]: Fewer than 5 free children - Spawning 20 process(es) Oct 17 17:50:22 test e2guardian[18321]: added child: fd: 37 pid: 18435 Oct 17 17:50:23 test e2guardian[18403]: Child has handled 50 requests and is exiting Oct 17 17:50:23 test e2guardian[18321]: deleted child: fd: 20 pid: -1 Oct 17 17:50:23 test e2guardian[18321]: Fewer than 5 free children - Spawning 20 process(es) Oct 17 17:50:23 test e2guardian[18321]: added child: fd: 20 pid: 18436 Oct 17 17:50:23 test e2guardian[18417]: Child has handled 50 requests and is exiting Oct 17 17:50:23 test e2guardian[18321]: deleted child: fd: 8 pid: -1 Oct 17 17:50:23 test e2guardian[18321]: Fewer than 5 free children - Spawning 20 process(es) Oct 17 17:50:23 test e2guardian[18321]: added child: fd: 8 pid: 18437 Oct 17 17:50:23 test e2guardian[18409]: Child has handled 50 requests and is exiting Oct 17 17:50:23 test e2guardian[18321]: deleted child: fd: 26 pid: -1 Oct 17 17:50:23 test e2guardian[18321]: Fewer than 5 free children - Spawning 20 process(es) Oct 17 17:50:23 test e2guardian[18321]: added child: fd: 26 pid: 18438

    As you can see the process died regularly, I guess there is a bug with openbsd who always create new process

    点赞 评论 复制链接分享
  • weixin_39956036 weixin_39956036 4月前

    Right, sorry, I thought you meant maxchildren. Right now maxagechildren is set to its default, 500.

    I've reverted back to 2.12.0.7 now to see if I run into the problem again to look for zombie processes.

    About OpenBSD creating the processes, is that possible even if the code is checking not to go over the maxchildren value?

    Thanks again!

    点赞 评论 复制链接分享
  • weixin_39528467 weixin_39528467 4月前

    I don't know exactly why, but you never go to syslog(LOG_ERR, "deleted child: fd: %d pid: %d", i, childrenpids[i]); in FatController.ccp

    I tried with Linux without epoll (lile BSD) no problem, maybe DG doesn't enter at all to cullchildren function for some weird reasons

    Can you put a simple line like syslog(LOG_ERR, "test"); just after

    void cullchildren(int num) {

    After that two cases: 1 - You have the line in syslog - The problem seem in this function 2 - You don't have the line, and we need to find why, cullchildren is only called in two places

    Thank

    点赞 评论 复制链接分享
  • weixin_39956036 weixin_39956036 4月前

    Ok, I just tried your test adding the following line to src/FatController.cpp (line number 733 approximately):

    
    [...]
    // kill give number of non-busy children
    void cullchildren(int num)
    {
            syslog(LOG_ERR, "test cullchildren");
    #ifdef DGDEBUG
            std::cout << "culling childs:" << num << std::endl;
    #endif
            int i;
    [...]
    

    I then ran:

    
    make
    make install
    

    And then restarted the dansguardian process (by the way, I don' think this matters, but just in case, I've renamed the binary to dansguardian-2.12.0.7 in order to be able to rever to the official release).

    Now, I let it run for about 15 minutes, after which, all of a sudden, I went from ~125 process to ~907 (!):

    
    tracer:/usr/local/sbin{115}# ps ax | grep dans | wc -l
         125
    tracer:/usr/local/sbin{116}# ps ax | grep dans | wc -l
         907
    

    After noting this I killed it and reverted back to the official release. As for syslog, the test message I introduced appeared twice before killing dansguardian. I attach the contents of /var/log/messages since the start of dansguardian and up to when I kill it.

    
    Oct 17 14:45:10 tracer dansguardian[17974]: Started sucessfully.
    Oct 17 14:45:10 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:45:10 tracer dansguardian[17974]: added child: fd: 13 pid: 14471
    Oct 17 14:45:10 tracer dansguardian[17974]: added child: fd: 14 pid: 20360
    Oct 17 14:45:10 tracer dansguardian[17974]: added child: fd: 15 pid: 30321
    Oct 17 14:45:10 tracer dansguardian[17974]: added child: fd: 16 pid: 12941
    Oct 17 14:45:10 tracer dansguardian[17974]: added child: fd: 17 pid: 28958
    Oct 17 14:45:10 tracer dansguardian[17974]: added child: fd: 18 pid: 47
    Oct 17 14:45:10 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:45:10 tracer dansguardian[17974]: added child: fd: 19 pid: 20297
    Oct 17 14:45:10 tracer dansguardian[17974]: added child: fd: 20 pid: 10517
    Oct 17 14:45:10 tracer dansguardian[17974]: added child: fd: 21 pid: 31285
    Oct 17 14:45:10 tracer dansguardian[17974]: added child: fd: 22 pid: 10603
    Oct 17 14:45:10 tracer dansguardian[17974]: added child: fd: 23 pid: 23315
    Oct 17 14:45:10 tracer dansguardian[17974]: added child: fd: 24 pid: 17271
    Oct 17 14:45:11 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:45:11 tracer dansguardian[17974]: added child: fd: 25 pid: 18490
    Oct 17 14:45:11 tracer dansguardian[17974]: added child: fd: 26 pid: 28662
    Oct 17 14:45:11 tracer dansguardian[17974]: added child: fd: 27 pid: 12716
    Oct 17 14:45:11 tracer dansguardian[17974]: added child: fd: 28 pid: 26147
    Oct 17 14:45:12 tracer dansguardian[17974]: added child: fd: 29 pid: 21289
    Oct 17 14:45:12 tracer dansguardian[17974]: added child: fd: 30 pid: 32365
    Oct 17 14:45:14 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:45:14 tracer dansguardian[17974]: added child: fd: 31 pid: 17918
    Oct 17 14:45:14 tracer dansguardian[17974]: added child: fd: 32 pid: 1614
    Oct 17 14:45:14 tracer dansguardian[17974]: added child: fd: 33 pid: 10420
    Oct 17 14:45:14 tracer dansguardian[17974]: added child: fd: 34 pid: 14188
    Oct 17 14:45:14 tracer dansguardian[17974]: added child: fd: 35 pid: 20980
    Oct 17 14:45:14 tracer dansguardian[17974]: added child: fd: 36 pid: 24999
    Oct 17 14:45:17 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:45:17 tracer dansguardian[17974]: added child: fd: 37 pid: 4042
    Oct 17 14:45:17 tracer dansguardian[17974]: added child: fd: 38 pid: 18953
    Oct 17 14:45:17 tracer dansguardian[17974]: added child: fd: 39 pid: 8491
    Oct 17 14:45:17 tracer dansguardian[17974]: added child: fd: 40 pid: 17767
    Oct 17 14:45:17 tracer dansguardian[17974]: added child: fd: 41 pid: 28530
    Oct 17 14:45:17 tracer dansguardian[17974]: added child: fd: 42 pid: 22400
    Oct 17 14:45:24 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:45:24 tracer dansguardian[17974]: added child: fd: 43 pid: 6386
    Oct 17 14:45:24 tracer dansguardian[17974]: added child: fd: 44 pid: 18401
    Oct 17 14:45:24 tracer dansguardian[17974]: added child: fd: 45 pid: 4990
    Oct 17 14:45:24 tracer dansguardian[17974]: added child: fd: 46 pid: 26854
    Oct 17 14:45:24 tracer dansguardian[17974]: added child: fd: 47 pid: 9740
    Oct 17 14:45:24 tracer dansguardian[17974]: added child: fd: 48 pid: 28260
    Oct 17 14:45:34 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:45:34 tracer dansguardian[17974]: added child: fd: 49 pid: 20308
    Oct 17 14:45:34 tracer dansguardian[17974]: added child: fd: 50 pid: 4594
    Oct 17 14:45:34 tracer dansguardian[17974]: added child: fd: 51 pid: 19813
    Oct 17 14:45:34 tracer dansguardian[17974]: added child: fd: 52 pid: 31065
    Oct 17 14:45:34 tracer dansguardian[17974]: added child: fd: 53 pid: 14703
    Oct 17 14:45:34 tracer dansguardian[17974]: added child: fd: 54 pid: 13740
    Oct 17 14:45:34 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:45:34 tracer dansguardian[17974]: added child: fd: 55 pid: 25450
    Oct 17 14:45:34 tracer dansguardian[17974]: added child: fd: 56 pid: 5609
    Oct 17 14:45:34 tracer dansguardian[17974]: added child: fd: 57 pid: 13724
    Oct 17 14:45:34 tracer dansguardian[17974]: added child: fd: 58 pid: 17309
    Oct 17 14:45:34 tracer dansguardian[17974]: added child: fd: 59 pid: 3955
    Oct 17 14:45:34 tracer dansguardian[17974]: added child: fd: 60 pid: 19579
    Oct 17 14:45:34 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:45:34 tracer dansguardian[17974]: added child: fd: 61 pid: 12749
    Oct 17 14:45:34 tracer dansguardian[17974]: added child: fd: 62 pid: 17807
    Oct 17 14:45:34 tracer dansguardian[17974]: added child: fd: 63 pid: 15771
    Oct 17 14:45:34 tracer dansguardian[17974]: added child: fd: 64 pid: 14374
    Oct 17 14:45:34 tracer dansguardian[17974]: added child: fd: 65 pid: 27314
    Oct 17 14:45:34 tracer dansguardian[17974]: added child: fd: 66 pid: 8630
    Oct 17 14:45:34 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:45:34 tracer dansguardian[17974]: added child: fd: 67 pid: 23372
    Oct 17 14:45:34 tracer dansguardian[17974]: added child: fd: 68 pid: 10568
    Oct 17 14:45:34 tracer dansguardian[17974]: added child: fd: 69 pid: 30236
    Oct 17 14:45:34 tracer dansguardian[17974]: added child: fd: 70 pid: 17917
    Oct 17 14:45:34 tracer dansguardian[17974]: added child: fd: 71 pid: 3811
    Oct 17 14:45:34 tracer dansguardian[17974]: added child: fd: 72 pid: 23625
    Oct 17 14:45:36 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:45:36 tracer dansguardian[17974]: added child: fd: 73 pid: 15934
    Oct 17 14:45:36 tracer dansguardian[17974]: added child: fd: 74 pid: 13318
    Oct 17 14:45:36 tracer dansguardian[17974]: added child: fd: 75 pid: 15269
    Oct 17 14:45:36 tracer dansguardian[17974]: added child: fd: 76 pid: 32493
    Oct 17 14:45:36 tracer dansguardian[17974]: added child: fd: 77 pid: 4350
    Oct 17 14:45:36 tracer dansguardian[17974]: added child: fd: 78 pid: 29324
    Oct 17 14:45:43 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:45:43 tracer dansguardian[17974]: added child: fd: 79 pid: 21967
    Oct 17 14:45:43 tracer dansguardian[17974]: added child: fd: 80 pid: 480
    Oct 17 14:45:43 tracer dansguardian[17974]: added child: fd: 81 pid: 24291
    Oct 17 14:45:43 tracer dansguardian[17974]: added child: fd: 82 pid: 4303
    Oct 17 14:45:43 tracer dansguardian[17974]: added child: fd: 83 pid: 7471
    Oct 17 14:45:43 tracer dansguardian[17974]: added child: fd: 84 pid: 3136
    Oct 17 14:45:53 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:45:53 tracer dansguardian[17974]: added child: fd: 85 pid: 30713
    Oct 17 14:45:53 tracer dansguardian[17974]: added child: fd: 86 pid: 29828
    Oct 17 14:45:53 tracer dansguardian[17974]: added child: fd: 87 pid: 21871
    Oct 17 14:45:53 tracer dansguardian[17974]: added child: fd: 88 pid: 9178
    Oct 17 14:45:53 tracer dansguardian[17974]: added child: fd: 89 pid: 23659
    Oct 17 14:45:53 tracer dansguardian[17974]: added child: fd: 90 pid: 5054
    Oct 17 14:45:54 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:45:54 tracer dansguardian[17974]: added child: fd: 91 pid: 18696
    Oct 17 14:45:54 tracer dansguardian[17974]: added child: fd: 92 pid: 11973
    Oct 17 14:45:54 tracer dansguardian[17974]: added child: fd: 93 pid: 11631
    Oct 17 14:45:54 tracer dansguardian[17974]: added child: fd: 94 pid: 4277
    Oct 17 14:45:54 tracer dansguardian[17974]: added child: fd: 95 pid: 18859
    Oct 17 14:45:54 tracer dansguardian[17974]: added child: fd: 96 pid: 15217
    Oct 17 14:45:58 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:45:58 tracer dansguardian[17974]: added child: fd: 97 pid: 27690
    Oct 17 14:45:58 tracer dansguardian[17974]: added child: fd: 98 pid: 11849
    Oct 17 14:45:58 tracer dansguardian[17974]: added child: fd: 99 pid: 569
    Oct 17 14:45:58 tracer dansguardian[17974]: added child: fd: 100 pid: 13534
    Oct 17 14:45:58 tracer dansguardian[17974]: added child: fd: 101 pid: 9587
    Oct 17 14:45:58 tracer dansguardian[17974]: added child: fd: 102 pid: 13496
    Oct 17 14:45:59 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:45:59 tracer dansguardian[17974]: added child: fd: 103 pid: 11935
    Oct 17 14:45:59 tracer dansguardian[17974]: added child: fd: 104 pid: 6422
    Oct 17 14:45:59 tracer dansguardian[17974]: added child: fd: 105 pid: 2375
    Oct 17 14:45:59 tracer dansguardian[17974]: added child: fd: 106 pid: 3965
    Oct 17 14:45:59 tracer dansguardian[17974]: added child: fd: 107 pid: 11375
    Oct 17 14:45:59 tracer dansguardian[17974]: added child: fd: 108 pid: 10016
    Oct 17 14:46:00 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:46:00 tracer dansguardian[17974]: added child: fd: 109 pid: 8135
    Oct 17 14:46:00 tracer dansguardian[17974]: added child: fd: 110 pid: 14456
    Oct 17 14:46:00 tracer dansguardian[17974]: added child: fd: 111 pid: 11044
    Oct 17 14:46:00 tracer dansguardian[17974]: added child: fd: 112 pid: 31013
    Oct 17 14:46:00 tracer dansguardian[17974]: added child: fd: 113 pid: 11006
    Oct 17 14:46:00 tracer dansguardian[17974]: added child: fd: 114 pid: 11317
    Oct 17 14:46:14 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:46:14 tracer dansguardian[17974]: added child: fd: 115 pid: 28292
    Oct 17 14:46:14 tracer dansguardian[17974]: added child: fd: 116 pid: 31974
    Oct 17 14:46:14 tracer dansguardian[17974]: added child: fd: 117 pid: 2651
    Oct 17 14:46:14 tracer dansguardian[17974]: added child: fd: 118 pid: 15763
    Oct 17 14:46:14 tracer dansguardian[17974]: added child: fd: 119 pid: 18721
    Oct 17 14:46:14 tracer dansguardian[17974]: added child: fd: 120 pid: 3726
    Oct 17 14:48:40 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:48:40 tracer dansguardian[17974]: added child: fd: 121 pid: 11178
    Oct 17 14:48:40 tracer dansguardian[17974]: added child: fd: 122 pid: 18845
    Oct 17 14:48:40 tracer dansguardian[17974]: added child: fd: 123 pid: 8321
    Oct 17 14:48:40 tracer dansguardian[17974]: added child: fd: 124 pid: 32426
    Oct 17 14:53:23 tracer dansguardian[17974]: More than 32 free children - Killing 43 process(es)
    Oct 17 14:53:23 tracer dansguardian[17974]: test cullchildren
    Oct 17 14:53:23 tracer dansguardian[18721]: Child has handled 500 requests and is exiting
    Oct 17 14:53:23 tracer dansguardian[17974]: deleted child: fd: 119 pid: 32426
    Oct 17 14:53:23 tracer dansguardian[17974]: deleted child: fd: 118 pid: 8321
    Oct 17 14:53:23 tracer dansguardian[15763]: Child has handled 500 requests and is exiting
    Oct 17 14:53:23 tracer dansguardian[17974]: deleted child: fd: 117 pid: 18845
    Oct 17 14:53:23 tracer dansguardian[2651]: Child has handled 500 requests and is exiting
    Oct 17 14:53:23 tracer dansguardian[31974]: Child has handled 500 requests and is exiting
    Oct 17 14:53:23 tracer dansguardian[17974]: deleted child: fd: 116 pid: 11178
    Oct 17 14:53:23 tracer dansguardian[17974]: deleted child: fd: 115 pid: 3726
    Oct 17 14:53:23 tracer dansguardian[28292]: Child has handled 500 requests and is exiting
    Oct 17 14:53:23 tracer dansguardian[11317]: Child has handled 500 requests and is exiting
    Oct 17 14:53:23 tracer dansguardian[17974]: deleted child: fd: 114 pid: 18721
    Oct 17 14:53:23 tracer dansguardian[11006]: Child has handled 500 requests and is exiting
    Oct 17 14:53:23 tracer dansguardian[17974]: deleted child: fd: 113 pid: 15763
    Oct 17 14:53:23 tracer dansguardian[31013]: Child has handled 500 requests and is exiting
    Oct 17 14:53:23 tracer dansguardian[17974]: deleted child: fd: 112 pid: 2651
    Oct 17 14:53:23 tracer dansguardian[17974]: deleted child: fd: 111 pid: 31974
    Oct 17 14:53:23 tracer dansguardian[14456]: Child has handled 500 requests and is exiting
    Oct 17 14:53:23 tracer dansguardian[17974]: deleted child: fd: 110 pid: 28292
    Oct 17 14:53:23 tracer dansguardian[8135]: Child has handled 500 requests and is exiting
    Oct 17 14:53:23 tracer dansguardian[17974]: deleted child: fd: 109 pid: 11317
    Oct 17 14:53:23 tracer dansguardian[17974]: deleted child: fd: 108 pid: 11006
    Oct 17 14:53:23 tracer dansguardian[11375]: Child has handled 500 requests and is exiting
    Oct 17 14:53:23 tracer dansguardian[10016]: Child has handled 500 requests and is exiting
    Oct 17 14:53:23 tracer dansguardian[17974]: deleted child: fd: 107 pid: 31013
    Oct 17 14:53:23 tracer dansguardian[17974]: deleted child: fd: 105 pid: 14456
    Oct 17 14:53:23 tracer dansguardian[2375]: Child has handled 500 requests and is exiting
    Oct 17 14:53:23 tracer dansguardian[6422]: Child has handled 500 requests and is exiting
    Oct 17 14:53:23 tracer dansguardian[17974]: deleted child: fd: 104 pid: 8135
    Oct 17 14:53:23 tracer dansguardian[11935]: Child has handled 500 requests and is exiting
    Oct 17 14:53:23 tracer dansguardian[17974]: deleted child: fd: 103 pid: 10016
    Oct 17 14:53:23 tracer dansguardian[13496]: Child has handled 500 requests and is exiting
    Oct 17 14:53:23 tracer dansguardian[17974]: deleted child: fd: 102 pid: 11375
    Oct 17 14:53:23 tracer dansguardian[17974]: deleted child: fd: 101 pid: 3965
    Oct 17 14:53:23 tracer dansguardian[9587]: Child has handled 500 requests and is exiting
    Oct 17 14:53:23 tracer dansguardian[13534]: Child has handled 500 requests and is exiting
    Oct 17 14:53:23 tracer dansguardian[17974]: deleted child: fd: 100 pid: 2375
    Oct 17 14:53:23 tracer dansguardian[569]: Child has handled 500 requests and is exiting
    Oct 17 14:53:23 tracer dansguardian[17974]: deleted child: fd: 99 pid: 6422
    Oct 17 14:53:23 tracer dansguardian[11849]: Child has handled 500 requests and is exiting
    Oct 17 14:53:23 tracer dansguardian[17974]: deleted child: fd: 98 pid: 11935
    Oct 17 14:53:23 tracer dansguardian[27690]: Child has handled 500 requests and is exiting
    Oct 17 14:53:23 tracer dansguardian[17974]: deleted child: fd: 97 pid: 13496
    Oct 17 14:53:23 tracer dansguardian[15217]: Child has handled 500 requests and is exiting
    Oct 17 14:53:23 tracer dansguardian[17974]: deleted child: fd: 96 pid: 9587
    Oct 17 14:53:23 tracer dansguardian[18859]: Child has handled 500 requests and is exiting
    Oct 17 14:53:23 tracer dansguardian[17974]: deleted child: fd: 95 pid: 13534
    Oct 17 14:53:23 tracer dansguardian[4277]: Child has handled 500 requests and is exiting
    Oct 17 14:53:23 tracer dansguardian[17974]: deleted child: fd: 94 pid: 569
    Oct 17 14:53:23 tracer dansguardian[11631]: Child has handled 500 requests and is exiting
    Oct 17 14:53:23 tracer dansguardian[17974]: deleted child: fd: 93 pid: 11849
    Oct 17 14:53:23 tracer dansguardian[11973]: Child has handled 500 requests and is exiting
    Oct 17 14:53:23 tracer dansguardian[17974]: deleted child: fd: 92 pid: 27690
    Oct 17 14:53:23 tracer dansguardian[18696]: Child has handled 500 requests and is exiting
    Oct 17 14:53:23 tracer dansguardian[17974]: deleted child: fd: 91 pid: 15217
    Oct 17 14:53:23 tracer dansguardian[5054]: Child has handled 500 requests and is exiting
    Oct 17 14:53:23 tracer dansguardian[17974]: deleted child: fd: 90 pid: 18859
    Oct 17 14:53:23 tracer dansguardian[23659]: Child has handled 500 requests and is exiting
    Oct 17 14:53:23 tracer dansguardian[17974]: deleted child: fd: 89 pid: 4277
    Oct 17 14:53:23 tracer dansguardian[9178]: Child has handled 500 requests and is exiting
    Oct 17 14:53:23 tracer dansguardian[17974]: deleted child: fd: 88 pid: 11631
    Oct 17 14:53:23 tracer dansguardian[17974]: deleted child: fd: 87 pid: 11973
    Oct 17 14:53:23 tracer dansguardian[21871]: Child has handled 500 requests and is exiting
    Oct 17 14:53:23 tracer dansguardian[29828]: Child has handled 500 requests and is exiting
    Oct 17 14:53:23 tracer dansguardian[17974]: deleted child: fd: 86 pid: 18696
    Oct 17 14:53:23 tracer dansguardian[17974]: deleted child: fd: 85 pid: 5054
    Oct 17 14:53:23 tracer dansguardian[30713]: Child has handled 500 requests and is exiting
    Oct 17 14:53:23 tracer dansguardian[3136]: Child has handled 500 requests and is exiting
    Oct 17 14:53:23 tracer dansguardian[17974]: deleted child: fd: 84 pid: 23659
    Oct 17 14:53:23 tracer dansguardian[7471]: Child has handled 500 requests and is exiting
    Oct 17 14:53:23 tracer dansguardian[17974]: deleted child: fd: 83 pid: 9178
    Oct 17 14:53:23 tracer dansguardian[4303]: Child has handled 500 requests and is exiting
    Oct 17 14:53:23 tracer dansguardian[17974]: deleted child: fd: 82 pid: 21871
    Oct 17 14:53:23 tracer dansguardian[24291]: Child has handled 500 requests and is exiting
    Oct 17 14:53:23 tracer dansguardian[17974]: deleted child: fd: 81 pid: 29828
    Oct 17 14:53:23 tracer dansguardian[480]: Child has handled 500 requests and is exiting
    Oct 17 14:53:23 tracer dansguardian[17974]: deleted child: fd: 80 pid: 30713
    Oct 17 14:53:23 tracer dansguardian[17974]: deleted child: fd: 79 pid: 3136
    Oct 17 14:53:23 tracer dansguardian[21967]: Child has handled 500 requests and is exiting
    Oct 17 14:53:23 tracer dansguardian[29324]: Child has handled 500 requests and is exiting
    Oct 17 14:53:23 tracer dansguardian[17974]: deleted child: fd: 78 pid: 7471
    Oct 17 14:53:23 tracer dansguardian[4350]: Child has handled 500 requests and is exiting
    Oct 17 14:53:23 tracer dansguardian[17974]: deleted child: fd: 77 pid: 4303
    Oct 17 14:53:23 tracer dansguardian[32493]: Child has handled 500 requests and is exiting
    Oct 17 14:53:23 tracer dansguardian[17974]: deleted child: fd: 76 pid: 24291
    Oct 17 14:54:34 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:54:34 tracer dansguardian[17974]: added child: fd: 76 pid: 15496
    Oct 17 14:54:34 tracer dansguardian[17974]: added child: fd: 77 pid: 30717
    Oct 17 14:54:35 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:54:35 tracer dansguardian[17974]: added child: fd: 77 pid: 31923
    Oct 17 14:54:35 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:54:35 tracer dansguardian[17974]: added child: fd: 78 pid: 27374
    Oct 17 14:54:35 tracer dansguardian[17974]: added child: fd: 79 pid: 27787
    Oct 17 14:54:35 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:54:35 tracer last message repeated 2 times
    Oct 17 14:54:35 tracer dansguardian[17974]: No free children from getfreechild(): numchildren = 77, busychildren = 76, waitingfor = 0
    Oct 17 14:54:35 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:54:35 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:54:35 tracer dansguardian[17974]: No free children from getfreechild(): numchildren = 77, busychildren = 76, waitingfor = 0
    Oct 17 14:54:35 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:54:35 tracer dansguardian[17974]: No free children from getfreechild(): numchildren = 77, busychildren = 76, waitingfor = 0
    Oct 17 14:54:35 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:54:35 tracer dansguardian[17974]: No free children from getfreechild(): numchildren = 77, busychildren = 76, waitingfor = 0
    Oct 17 14:54:35 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:54:35 tracer dansguardian[17974]: No free children from getfreechild(): numchildren = 77, busychildren = 76, waitingfor = 0
    Oct 17 14:54:35 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:54:35 tracer dansguardian[17974]: No free children from getfreechild(): numchildren = 77, busychildren = 76, waitingfor = 0
    Oct 17 14:54:35 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:54:35 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:54:35 tracer dansguardian[17974]: No free children from getfreechild(): numchildren = 77, busychildren = 76, waitingfor = 0
    Oct 17 14:54:35 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:54:35 tracer dansguardian[17974]: No free children from getfreechild(): numchildren = 77, busychildren = 76, waitingfor = 0
    Oct 17 14:54:36 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:54:36 tracer last message repeated 4 times
    Oct 17 14:54:36 tracer dansguardian[17974]: No free children from getfreechild(): numchildren = 77, busychildren = 76, waitingfor = 0
    Oct 17 14:54:36 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:54:36 tracer dansguardian[17974]: No free children from getfreechild(): numchildren = 77, busychildren = 76, waitingfor = 0
    Oct 17 14:54:36 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:54:36 tracer dansguardian[17974]: No free children from getfreechild(): numchildren = 77, busychildren = 76, waitingfor = 0
    Oct 17 14:54:36 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:54:36 tracer dansguardian[17974]: No free children from getfreechild(): numchildren = 77, busychildren = 76, waitingfor = 0
    Oct 17 14:54:36 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:54:37 tracer dansguardian[17974]: No free children from getfreechild(): numchildren = 77, busychildren = 76, waitingfor = 0
    Oct 17 14:54:37 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:54:37 tracer last message repeated 3 times
    Oct 17 14:54:37 tracer dansguardian[17974]: No free children from getfreechild(): numchildren = 77, busychildren = 76, waitingfor = 0
    Oct 17 14:54:37 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:54:37 tracer dansguardian[17974]: No free children from getfreechild(): numchildren = 77, busychildren = 76, waitingfor = 0
    Oct 17 14:54:37 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:54:37 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:54:37 tracer dansguardian[17974]: No free children from getfreechild(): numchildren = 77, busychildren = 76, waitingfor = 0
    Oct 17 14:54:37 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:54:37 tracer dansguardian[17974]: No free children from getfreechild(): numchildren = 77, busychildren = 76, waitingfor = 0
    Oct 17 14:54:37 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:54:37 tracer dansguardian[17974]: No free children from getfreechild(): numchildren = 77, busychildren = 76, waitingfor = 0
    Oct 17 14:54:37 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:54:37 tracer dansguardian[17974]: No free children from getfreechild(): numchildren = 77, busychildren = 76, waitingfor = 0
    Oct 17 14:54:37 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:54:37 tracer dansguardian[17974]: No free children from getfreechild(): numchildren = 77, busychildren = 76, waitingfor = 0
    Oct 17 14:54:37 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:54:37 tracer dansguardian[17974]: No free children from getfreechild(): numchildren = 77, busychildren = 76, waitingfor = 0
    Oct 17 14:54:37 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:54:37 tracer dansguardian[17974]: No free children from getfreechild(): numchildren = 77, busychildren = 76, waitingfor = 0
    Oct 17 14:54:37 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:54:37 tracer dansguardian[17974]: No free children from getfreechild(): numchildren = 77, busychildren = 76, waitingfor = 0
    Oct 17 14:54:37 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:54:38 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:54:38 tracer dansguardian[17974]: No free children from getfreechild(): numchildren = 77, busychildren = 76, waitingfor = 0
    Oct 17 14:54:38 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:54:38 tracer dansguardian[17974]: No free children from getfreechild(): numchildren = 77, busychildren = 76, waitingfor = 0
    Oct 17 14:54:38 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:54:38 tracer dansguardian[17974]: No free children from getfreechild(): numchildren = 77, busychildren = 76, waitingfor = 0
    Oct 17 14:54:38 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:54:38 tracer dansguardian[17974]: No free children from getfreechild(): numchildren = 77, busychildren = 76, waitingfor = 0
    Oct 17 14:54:38 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:54:38 tracer dansguardian[17974]: No free children from getfreechild(): numchildren = 77, busychildren = 76, waitingfor = 0
    Oct 17 14:54:38 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:54:38 tracer dansguardian[17974]: No free children from getfreechild(): numchildren = 77, busychildren = 76, waitingfor = 0
    Oct 17 14:54:38 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:54:38 tracer last message repeated 2 times
    Oct 17 14:54:38 tracer dansguardian[17974]: No free children from getfreechild(): numchildren = 77, busychildren = 76, waitingfor = 0
    Oct 17 14:54:38 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:54:38 tracer dansguardian[17974]: No free children from getfreechild(): numchildren = 77, busychildren = 76, waitingfor = 0
    Oct 17 14:54:38 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:54:38 tracer dansguardian[17974]: No free children from getfreechild(): numchildren = 77, busychildren = 76, waitingfor = 0
    Oct 17 14:54:38 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:54:38 tracer dansguardian[17974]: No free children from getfreechild(): numchildren = 77, busychildren = 76, waitingfor = 0
    Oct 17 14:54:38 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:54:38 tracer dansguardian[17974]: No free children from getfreechild(): numchildren = 77, busychildren = 76, waitingfor = 0
    Oct 17 14:54:38 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:54:38 tracer dansguardian[17974]: No free children from getfreechild(): numchildren = 77, busychildren = 76, waitingfor = 0
    Oct 17 14:54:38 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:54:39 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:54:39 tracer dansguardian[17974]: No free children from getfreechild(): numchildren = 77, busychildren = 76, waitingfor = 0
    Oct 17 14:54:39 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:54:39 tracer dansguardian[17974]: No free children from getfreechild(): numchildren = 77, busychildren = 76, waitingfor = 0
    Oct 17 14:54:39 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:54:39 tracer dansguardian[17974]: No free children from getfreechild(): numchildren = 77, busychildren = 76, waitingfor = 0
    Oct 17 14:54:39 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:54:39 tracer dansguardian[17974]: No free children from getfreechild(): numchildren = 77, busychildren = 76, waitingfor = 0
    Oct 17 14:54:39 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:54:39 tracer dansguardian[17974]: No free children from getfreechild(): numchildren = 77, busychildren = 76, waitingfor = 0
    Oct 17 14:54:39 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:54:39 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:54:39 tracer dansguardian[17974]: No free children from getfreechild(): numchildren = 77, busychildren = 76, waitingfor = 0
    Oct 17 14:54:39 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:54:39 tracer dansguardian[17974]: No free children from getfreechild(): numchildren = 77, busychildren = 76, waitingfor = 0
    Oct 17 14:54:39 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:54:39 tracer dansguardian[17974]: No free children from getfreechild(): numchildren = 77, busychildren = 76, waitingfor = 0
    Oct 17 14:54:39 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:54:39 tracer dansguardian[17974]: No free children from getfreechild(): numchildren = 77, busychildren = 76, waitingfor = 0
    Oct 17 14:54:39 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:54:39 tracer dansguardian[17974]: No free children from getfreechild(): numchildren = 77, busychildren = 76, waitingfor = 0
    Oct 17 14:54:39 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:54:39 tracer last message repeated 2 times
    Oct 17 14:54:39 tracer dansguardian[17974]: No free children from getfreechild(): numchildren = 77, busychildren = 76, waitingfor = 0
    Oct 17 14:54:39 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:54:39 tracer dansguardian[17974]: No free children from getfreechild(): numchildren = 77, busychildren = 76, waitingfor = 0
    Oct 17 14:54:39 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:54:40 tracer dansguardian[17974]: No free children from getfreechild(): numchildren = 77, busychildren = 76, waitingfor = 0
    Oct 17 14:54:40 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:54:40 tracer dansguardian[17974]: No free children from getfreechild(): numchildren = 77, busychildren = 76, waitingfor = 0
    Oct 17 14:54:40 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:54:40 tracer dansguardian[17974]: No free children from getfreechild(): numchildren = 77, busychildren = 76, waitingfor = 0
    Oct 17 14:54:40 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:54:40 tracer dansguardian[17974]: No free children from getfreechild(): numchildren = 77, busychildren = 76, waitingfor = 0
    Oct 17 14:54:40 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:54:40 tracer dansguardian[17974]: No free children from getfreechild(): numchildren = 77, busychildren = 76, waitingfor = 0
    Oct 17 14:54:40 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:54:40 tracer dansguardian[17974]: No free children from getfreechild(): numchildren = 77, busychildren = 76, waitingfor = 0
    Oct 17 14:54:40 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:54:40 tracer dansguardian[17974]: No free children from getfreechild(): numchildren = 77, busychildren = 76, waitingfor = 0
    Oct 17 14:54:40 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:54:40 tracer dansguardian[17974]: No free children from getfreechild(): numchildren = 77, busychildren = 76, waitingfor = 0
    Oct 17 14:54:40 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:54:40 tracer dansguardian[17974]: No free children from getfreechild(): numchildren = 77, busychildren = 76, waitingfor = 0
    Oct 17 14:54:40 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:54:40 tracer dansguardian[17974]: No free children from getfreechild(): numchildren = 77, busychildren = 76, waitingfor = 0
    Oct 17 14:54:40 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:54:40 tracer dansguardian[17974]: No free children from getfreechild(): numchildren = 77, busychildren = 76, waitingfor = 0
    Oct 17 14:54:40 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:54:41 tracer dansguardian[17974]: No free children from getfreechild(): numchildren = 77, busychildren = 76, waitingfor = 0
    Oct 17 14:54:41 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:54:41 tracer dansguardian[17974]: No free children from getfreechild(): numchildren = 77, busychildren = 76, waitingfor = 0
    Oct 17 14:54:41 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:54:41 tracer dansguardian[17974]: No free children from getfreechild(): numchildren = 77, busychildren = 76, waitingfor = 0
    Oct 17 14:54:41 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:54:41 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:54:41 tracer dansguardian[17974]: No free children from getfreechild(): numchildren = 77, busychildren = 76, waitingfor = 0
    Oct 17 14:54:41 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:54:41 tracer dansguardian[17974]: No free children from getfreechild(): numchildren = 77, busychildren = 76, waitingfor = 0
    Oct 17 14:54:41 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:54:41 tracer dansguardian[17974]: No free children from getfreechild(): numchildren = 77, busychildren = 76, waitingfor = 0
    Oct 17 14:54:41 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:54:41 tracer dansguardian[17974]: No free children from getfreechild(): numchildren = 77, busychildren = 76, waitingfor = 0
    Oct 17 14:54:41 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:54:41 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:54:41 tracer dansguardian[17974]: No free children from getfreechild(): numchildren = 77, busychildren = 76, waitingfor = 0
    Oct 17 14:54:41 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:54:41 tracer dansguardian[17974]: No free children from getfreechild(): numchildren = 77, busychildren = 76, waitingfor = 0
    Oct 17 14:54:41 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:54:42 tracer dansguardian[17974]: No free children from getfreechild(): numchildren = 77, busychildren = 76, waitingfor = 0
    Oct 17 14:54:42 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:54:42 tracer dansguardian[17974]: No free children from getfreechild(): numchildren = 77, busychildren = 76, waitingfor = 0
    Oct 17 14:54:42 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:54:42 tracer dansguardian[17974]: No free children from getfreechild(): numchildren = 77, busychildren = 76, waitingfor = 0
    Oct 17 14:54:42 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:54:42 tracer dansguardian[17974]: No free children from getfreechild(): numchildren = 77, busychildren = 76, waitingfor = 0
    Oct 17 14:54:42 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:54:42 tracer dansguardian[17974]: No free children from getfreechild(): numchildren = 77, busychildren = 76, waitingfor = 0
    Oct 17 14:54:42 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:54:42 tracer dansguardian[17974]: No free children from getfreechild(): numchildren = 77, busychildren = 76, waitingfor = 0
    Oct 17 14:54:42 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:54:42 tracer dansguardian[17974]: No free children from getfreechild(): numchildren = 77, busychildren = 76, waitingfor = 0
    Oct 17 14:54:42 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:54:42 tracer dansguardian[17974]: No free children from getfreechild(): numchildren = 77, busychildren = 76, waitingfor = 0
    Oct 17 14:54:42 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:54:42 tracer dansguardian[17974]: No free children from getfreechild(): numchildren = 77, busychildren = 76, waitingfor = 0
    Oct 17 14:54:42 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:54:42 tracer dansguardian[17974]: No free children from getfreechild(): numchildren = 77, busychildren = 76, waitingfor = 0
    Oct 17 14:54:42 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:54:42 tracer dansguardian[17974]: No free children from getfreechild(): numchildren = 77, busychildren = 76, waitingfor = 0
    Oct 17 14:54:42 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:54:42 tracer dansguardian[17974]: No free children from getfreechild(): numchildren = 77, busychildren = 76, waitingfor = 0
    Oct 17 14:54:42 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:54:42 tracer dansguardian[17974]: No free children from getfreechild(): numchildren = 77, busychildren = 76, waitingfor = 0
    Oct 17 14:54:42 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:54:42 tracer dansguardian[17974]: No free children from getfreechild(): numchildren = 77, busychildren = 76, waitingfor = 0
    Oct 17 14:54:42 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:54:42 tracer dansguardian[17974]: No free children from getfreechild(): numchildren = 77, busychildren = 76, waitingfor = 0
    Oct 17 14:54:42 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:54:42 tracer dansguardian[17974]: No free children from getfreechild(): numchildren = 77, busychildren = 76, waitingfor = 0
    Oct 17 14:54:42 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:54:42 tracer dansguardian[17974]: No free children from getfreechild(): numchildren = 77, busychildren = 76, waitingfor = 0
    Oct 17 14:54:42 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:54:42 tracer dansguardian[17974]: No free children from getfreechild(): numchildren = 77, busychildren = 76, waitingfor = 0
    Oct 17 14:54:42 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:54:43 tracer dansguardian[17974]: No free children from getfreechild(): numchildren = 77, busychildren = 76, waitingfor = 0
    Oct 17 14:54:43 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:54:43 tracer dansguardian[17974]: No free children from getfreechild(): numchildren = 77, busychildren = 76, waitingfor = 0
    Oct 17 14:54:43 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:54:43 tracer dansguardian[17974]: No free children from getfreechild(): numchildren = 77, busychildren = 76, waitingfor = 0
    Oct 17 14:54:43 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:54:43 tracer dansguardian[17974]: No free children from getfreechild(): numchildren = 77, busychildren = 76, waitingfor = 0
    Oct 17 14:54:43 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:54:43 tracer dansguardian[17974]: No free children from getfreechild(): numchildren = 77, busychildren = 76, waitingfor = 0
    Oct 17 14:54:43 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:54:43 tracer dansguardian[17974]: No free children from getfreechild(): numchildren = 77, busychildren = 76, waitingfor = 0
    Oct 17 14:54:43 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:54:43 tracer dansguardian[17974]: No free children from getfreechild(): numchildren = 77, busychildren = 76, waitingfor = 0
    Oct 17 14:54:43 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:54:43 tracer dansguardian[17974]: No free children from getfreechild(): numchildren = 77, busychildren = 76, waitingfor = 0
    Oct 17 14:54:43 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:54:43 tracer dansguardian[17974]: No free children from getfreechild(): numchildren = 77, busychildren = 76, waitingfor = 0
    Oct 17 14:54:43 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:54:43 tracer dansguardian[17974]: No free children from getfreechild(): numchildren = 77, busychildren = 76, waitingfor = 0
    Oct 17 14:54:43 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:54:43 tracer dansguardian[17974]: No free children from getfreechild(): numchildren = 77, busychildren = 76, waitingfor = 0
    Oct 17 14:54:43 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:54:43 tracer dansguardian[17974]: No free children from getfreechild(): numchildren = 77, busychildren = 76, waitingfor = 0
    Oct 17 14:54:44 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:54:44 tracer dansguardian[17974]: No free children from getfreechild(): numchildren = 77, busychildren = 76, waitingfor = 0
    Oct 17 14:54:44 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:54:44 tracer dansguardian[17974]: No free children from getfreechild(): numchildren = 77, busychildren = 76, waitingfor = 0
    Oct 17 14:54:44 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:54:44 tracer dansguardian[17974]: No free children from getfreechild(): numchildren = 77, busychildren = 76, waitingfor = 0
    Oct 17 14:54:44 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:54:44 tracer dansguardian[17974]: No free children from getfreechild(): numchildren = 77, busychildren = 76, waitingfor = 0
    Oct 17 14:54:44 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:54:44 tracer dansguardian[17974]: No free children from getfreechild(): numchildren = 77, busychildren = 76, waitingfor = 0
    Oct 17 14:54:44 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:54:44 tracer dansguardian[17974]: No free children from getfreechild(): numchildren = 77, busychildren = 76, waitingfor = 0
    Oct 17 14:54:44 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:54:44 tracer dansguardian[17974]: No free children from getfreechild(): numchildren = 77, busychildren = 76, waitingfor = 0
    Oct 17 14:54:44 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:54:44 tracer dansguardian[17974]: No free children from getfreechild(): numchildren = 77, busychildren = 76, waitingfor = 0
    Oct 17 14:54:44 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:54:44 tracer dansguardian[17974]: No free children from getfreechild(): numchildren = 77, busychildren = 76, waitingfor = 0
    Oct 17 14:54:44 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:54:44 tracer dansguardian[17974]: No free children from getfreechild(): numchildren = 77, busychildren = 76, waitingfor = 0
    Oct 17 14:54:44 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:54:44 tracer dansguardian[17974]: No free children from getfreechild(): numchildren = 77, busychildren = 76, waitingfor = 0
    Oct 17 14:54:44 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:54:46 tracer last message repeated 6 times
    Oct 17 14:55:26 tracer last message repeated 3 times
    Oct 17 14:55:26 tracer dansguardian[17974]: No free children from getfreechild(): numchildren = 77, busychildren = 76, waitingfor = 0
    Oct 17 14:55:26 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:55:26 tracer dansguardian[17974]: No free children from getfreechild(): numchildren = 77, busychildren = 76, waitingfor = 0
    Oct 17 14:55:26 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:55:26 tracer dansguardian[17974]: No free children from getfreechild(): numchildren = 77, busychildren = 76, waitingfor = 0
    Oct 17 14:55:26 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:55:27 tracer last message repeated 2 times
    Oct 17 14:55:27 tracer dansguardian[17974]: No free children from getfreechild(): numchildren = 77, busychildren = 76, waitingfor = 0
    Oct 17 14:55:27 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:55:27 tracer dansguardian[17974]: No free children from getfreechild(): numchildren = 77, busychildren = 76, waitingfor = 0
    Oct 17 14:55:27 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:55:27 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:55:27 tracer dansguardian[17974]: No free children from getfreechild(): numchildren = 77, busychildren = 76, waitingfor = 0
    Oct 17 14:55:27 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:55:29 tracer last message repeated 10 times
    Oct 17 14:55:29 tracer dansguardian[27053]: Child has handled 500 requests and is exiting
    Oct 17 14:55:29 tracer dansguardian[13818]: Child has handled 500 requests and is exiting
    Oct 17 14:55:29 tracer dansguardian[25011]: Child has handled 500 requests and is exiting
    Oct 17 14:55:29 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:55:32 tracer last message repeated 7 times
    Oct 17 14:55:32 tracer dansguardian[17974]: test cullchildren
    Oct 17 14:55:32 tracer dansguardian[17974]: deleted child: fd: 75 pid: 480
    Oct 17 14:55:32 tracer dansguardian[17974]: deleted child: fd: 74 pid: 27787
    Oct 17 14:55:32 tracer dansguardian[8885]: Child has handled 500 requests and is exiting
    Oct 17 14:55:32 tracer dansguardian[30321]: Error connecting via IPC socket to log: No such file or directory
    Oct 17 14:55:33 tracer dansguardian[31065]: Error connecting via IPC socket to log: No such file or directory
    Oct 17 14:55:33 tracer dansguardian[31923]: Error connecting via IPC socket to log: No such file or directory
    Oct 17 14:55:33 tracer dansguardian[32111]: Error connecting via IPC socket to log: No such file or directory
    Oct 17 14:55:33 tracer dansguardian[17579]: Error connecting via IPC socket to log: No such file or directory
    

    Thanks again!

    点赞 评论 复制链接分享
  • weixin_39956036 weixin_39956036 4月前

    I can find an additional line when comparing FatController.cpp in official with your release -- there's a

    
    close(i);
    

    In line 761, which I don't know why it's there... Are you trying to close the descriptors from max_children to 1? Or from max_children up to num? That would be the integer itself as far as I can see, but not the descriptor itself. Anyway, I'm not sure I'm correct, I haven't taken a look at C/C++ code for some time now...

    And, also, I don't know if it explains why the 'deleted child' error does not appear in syslog...

    Thanks!

    点赞 评论 复制链接分享
  • weixin_39956036 weixin_39956036 4月前

    Sorry, now that I take a look again, I can see that the 'deleted child' message actually appears (you can actually see it youself in one of my previous comments. Here's a sample of what I posted above:

    
    Oct 17 14:53:23 tracer dansguardian[32493]: Child has handled 500 requests and is exiting
    Oct 17 14:53:23 tracer dansguardian[17974]: deleted child: fd: 76 pid: 24291
    Oct 17 14:54:34 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:54:34 tracer dansguardian[17974]: added child: fd: 76 pid: 15496
    Oct 17 14:54:34 tracer dansguardian[17974]: added child: fd: 77 pid: 30717
    Oct 17 14:54:35 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:54:35 tracer dansguardian[17974]: added child: fd: 77 pid: 31923
    Oct 17 14:54:35 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:54:35 tracer dansguardian[17974]: added child: fd: 78 pid: 27374
    Oct 17 14:54:35 tracer dansguardian[17974]: added child: fd: 79 pid: 27787
    Oct 17 14:54:35 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:54:35 tracer last message repeated 2 times
    Oct 17 14:54:35 tracer dansguardian[17974]: No free children from getfreechild(): numchildren = 77, busychildren = 76, waitingfor = 0
    Oct 17 14:54:35 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:54:35 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:54:35 tracer dansguardian[17974]: No free children from getfreechild(): numchildren = 77, busychildren = 76, waitingfor = 0
    Oct 17 14:54:35 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:54:35 tracer dansguardian[17974]: No free children from getfreechild(): numchildren = 77, busychildren = 76, waitingfor = 0
    Oct 17 14:54:35 tracer dansguardian[17974]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 17 14:54:35 tracer dansguardian[17974]: No free children from getfreechild(): numchildren = 77, busychildren = 76, waitingfor = 0
    

    I don't know if that "close(i);" could somehow be interfering though...

    EDIT: now that I take a closer look, that message must be appearing when "deletechild()" is called, but not cullchildren, as the test message is not appearing before those entries... Sorry for the backs and forths...

    点赞 评论 复制链接分享
  • weixin_39528467 weixin_39528467 4月前

    No it's very strange

    syslog "deleted child" in deletechild() is called only with Epoll (on Linux) Can you change the text to be sure there is no confusion ?

    Something like syslog(LOG_ERR, "deleted child Epoll: fd: %d pid: %d", i, childrenpids[i]); Maybe you miss something, because "test cullchildren" should appear one-time-only after there is a loop who destroy all the old process with "deleted child : fd :" mesage

    点赞 评论 复制链接分享
  • weixin_39956036 weixin_39956036 4月前

    Hi again,

    Taking a closer look at the logs, children ARE deleted from the cullchildren() function. Take a look at the output below:

    
    Oct 17 14:55:32 tracer dansguardian[17974]: test cullchildren
    Oct 17 14:55:32 tracer dansguardian[17974]: deleted child: fd: 75 pid: 480
    Oct 17 14:55:32 tracer dansguardian[17974]: deleted child: fd: 74 pid: 27787
    Oct 17 14:55:32 tracer dansguardian[8885]: Child has handled 500 requests and is exiting
    

    So, this part of the code looks like it's working properly. Now, for some reason, at some point, more childs are spawned beyond max_children... I added some more debugging lines before prefork like this (line ~2715):

    
    syslog(LOG_ERR, "numchildren: %d, o.max_children: %d", numchildren, o.max_children );
    

    Just to check that numchildren never goes beyond max_children. So far I haven't been able to retrigger the problem again, and I had to revert to the official release. I'm going to try again now in a few minutes...

    Also, I notice that many times requests from clients running wget seem to stall, when all the dansguardian process appear as idle. Also, I don't know when or how specifically cullchildren is called, but at some points there would appear to be many idle dansguardian processes doing nothing, and are not being killed/deleted.

    Thanks!

    点赞 评论 复制链接分享
  • weixin_39528467 weixin_39528467 4月前

    "So, this part of the code looks like it's working properly. Now, for some reason, at some point, more childs are spawned beyond max_children... I added some more debugging lines before prefork like this (line ~2715):"

    Also maybe, they are not properly killed ?

    "Also, I notice that many times requests from clients running wget seem to stall, when all the dansguardian process appear as idle."

    It's an usual behaviour there is a saturation, in this case you need to increase the maxchildren number

    点赞 评论 复制链接分享
  • weixin_39528467 weixin_39528467 4月前

    Can you try something, please stress DG without many wget, and stop all the traffic, after some minutes the process number should reduce alone to min_children.

    点赞 评论 复制链接分享
  • weixin_39956036 weixin_39956036 4月前

    Ok, I was able to trigger the spawning problem again about an hour ag -- I ran this test with default values (maxchildren = 120, maxagechildren = 500)

    Here's trimmed the output of messages, in different parts.

    The first part shows normal/expected behaviour; cullchildren() is being called regularly, and childs are deleted. numchildren never goes over max_children:

    
    Oct 18 13:11:32 tracer dansguardian[25]: test cullchildren
    Oct 18 13:11:32 tracer dansguardian[17530]: Child has handled 500 requests and is exiting
    Oct 18 13:11:32 tracer dansguardian[25]: closed 119
    Oct 18 13:11:32 tracer dansguardian[25]: numchildren now: 109
    Oct 18 13:11:32 tracer dansguardian[25]: deleted child: fd: 119 pid: 4614
    Oct 18 13:11:32 tracer dansguardian[29456]: Child has handled 500 requests and is exiting
    Oct 18 13:11:32 tracer dansguardian[25]: closed 118
    Oct 18 13:11:32 tracer dansguardian[25]: numchildren now: 108
    Oct 18 13:11:32 tracer dansguardian[25]: deleted child: fd: 118 pid: 18390
    Oct 18 13:11:32 tracer dansguardian[17680]: Child has handled 500 requests and is exiting
    Oct 18 13:11:32 tracer dansguardian[25]: closed 117
    Oct 18 13:11:32 tracer dansguardian[25]: numchildren now: 107
    Oct 18 13:11:32 tracer dansguardian[25]: deleted child: fd: 117 pid: 18114
    Oct 18 13:11:32 tracer dansguardian[22010]: Child has handled 500 requests and is exiting
    Oct 18 13:11:32 tracer dansguardian[25]: closed 116
    Oct 18 13:11:32 tracer dansguardian[25]: numchildren now: 106
    Oct 18 13:11:32 tracer dansguardian[25]: deleted child: fd: 116 pid: 24135
    Oct 18 13:11:32 tracer dansguardian[30184]: Child has handled 500 requests and is exiting
    Oct 18 13:11:32 tracer dansguardian[25]: closed 115
    Oct 18 13:11:32 tracer dansguardian[25]: numchildren now: 105
    Oct 18 13:11:32 tracer dansguardian[25]: deleted child: fd: 115 pid: 10843
    Oct 18 13:11:32 tracer dansguardian[10073]: Child has handled 500 requests and is exiting
    Oct 18 13:11:32 tracer dansguardian[25]: closed 114
    Oct 18 13:11:32 tracer dansguardian[25]: numchildren now: 104
    Oct 18 13:11:32 tracer dansguardian[25]: deleted child: fd: 114 pid: 17530
    Oct 18 13:11:32 tracer dansguardian[25]: closed 113
    Oct 18 13:11:32 tracer dansguardian[4675]: Child has handled 500 requests and is exiting
    Oct 18 13:11:32 tracer dansguardian[25]: numchildren now: 103
    Oct 18 13:11:32 tracer dansguardian[25]: deleted child: fd: 113 pid: 29456
    Oct 18 13:11:32 tracer dansguardian[22620]: Child has handled 500 requests and is exiting
    Oct 18 13:11:32 tracer dansguardian[25]: closed 112
    Oct 18 13:11:32 tracer dansguardian[25]: numchildren now: 102
    Oct 18 13:11:32 tracer dansguardian[25]: deleted child: fd: 112 pid: 17680
    Oct 18 13:11:32 tracer dansguardian[25]: closed 111
    Oct 18 13:11:32 tracer dansguardian[25051]: Child has handled 500 requests and is exiting
    Oct 18 13:11:32 tracer dansguardian[25]: numchildren now: 101
    Oct 18 13:11:32 tracer dansguardian[25]: deleted child: fd: 111 pid: 22010
    Oct 18 13:11:32 tracer dansguardian[12557]: Child has handled 500 requests and is exiting
    Oct 18 13:11:32 tracer dansguardian[25]: closed 110
    Oct 18 13:11:32 tracer dansguardian[25]: numchildren now: 100
    Oct 18 13:11:32 tracer dansguardian[25]: deleted child: fd: 110 pid: 30184
    Oct 18 13:11:32 tracer dansguardian[32446]: Child has handled 500 requests and is exiting
    Oct 18 13:11:32 tracer dansguardian[25]: closed 109
    Oct 18 13:11:32 tracer dansguardian[25]: numchildren now: 99
    Oct 18 13:11:32 tracer dansguardian[25]: deleted child: fd: 109 pid: 10073
    Oct 18 13:11:32 tracer dansguardian[29067]: Child has handled 500 requests and is exiting
    Oct 18 13:11:32 tracer dansguardian[25]: closed 108
    Oct 18 13:11:32 tracer dansguardian[25]: numchildren now: 98
    Oct 18 13:11:32 tracer dansguardian[25]: deleted child: fd: 108 pid: 4675
    Oct 18 13:11:32 tracer dansguardian[957]: Child has handled 500 requests and is exiting
    Oct 18 13:11:32 tracer dansguardian[25]: closed 107
    Oct 18 13:11:32 tracer dansguardian[25]: numchildren now: 97
    Oct 18 13:11:32 tracer dansguardian[25]: deleted child: fd: 107 pid: 22620
    Oct 18 13:11:32 tracer dansguardian[5485]: Child has handled 500 requests and is exiting
    Oct 18 13:11:32 tracer dansguardian[25]: closed 106
    Oct 18 13:11:32 tracer dansguardian[25]: numchildren now: 96
    Oct 18 13:11:32 tracer dansguardian[25]: deleted child: fd: 106 pid: 25051
    Oct 18 13:11:32 tracer dansguardian[23433]: Child has handled 500 requests and is exiting
    Oct 18 13:11:32 tracer dansguardian[25]: closed 105
    Oct 18 13:11:32 tracer dansguardian[25]: numchildren now: 95
    Oct 18 13:11:32 tracer dansguardian[25]: deleted child: fd: 105 pid: 12557
    Oct 18 13:11:32 tracer dansguardian[31630]: Child has handled 500 requests and is exiting
    Oct 18 13:11:32 tracer dansguardian[25]: closed 104
    Oct 18 13:11:32 tracer dansguardian[25]: numchildren now: 94
    Oct 18 13:11:32 tracer dansguardian[25]: deleted child: fd: 104 pid: 32446
    Oct 18 13:11:32 tracer dansguardian[9955]: Child has handled 500 requests and is exiting
    Oct 18 13:11:32 tracer dansguardian[25]: closed 103
    Oct 18 13:11:32 tracer dansguardian[25]: numchildren now: 93
    Oct 18 13:11:32 tracer dansguardian[25]: deleted child: fd: 103 pid: 29067
    Oct 18 13:11:32 tracer dansguardian[27704]: Child has handled 500 requests and is exiting
    Oct 18 13:11:32 tracer dansguardian[25]: closed 102
    Oct 18 13:11:32 tracer dansguardian[25]: numchildren now: 92
    Oct 18 13:11:32 tracer dansguardian[25]: deleted child: fd: 102 pid: 957
    Oct 18 13:11:32 tracer dansguardian[6446]: Child has handled 500 requests and is exiting
    Oct 18 13:11:32 tracer dansguardian[25]: closed 101
    Oct 18 13:11:32 tracer dansguardian[25]: numchildren now: 91
    Oct 18 13:11:32 tracer dansguardian[25]: deleted child: fd: 101 pid: 5485
    Oct 18 13:11:32 tracer dansguardian[29120]: Child has handled 500 requests and is exiting
    Oct 18 13:11:32 tracer dansguardian[25]: closed 100
    Oct 18 13:11:32 tracer dansguardian[25]: numchildren now: 90
    Oct 18 13:11:32 tracer dansguardian[25]: deleted child: fd: 100 pid: 23433
    Oct 18 13:11:32 tracer dansguardian[19515]: Child has handled 500 requests and is exiting
    Oct 18 13:11:32 tracer dansguardian[25]: closed 99
    Oct 18 13:11:32 tracer dansguardian[25]: numchildren now: 89
    Oct 18 13:11:32 tracer dansguardian[25]: deleted child: fd: 99 pid: 31630
    Oct 18 13:11:32 tracer dansguardian[14055]: Child has handled 500 requests and is exiting
    Oct 18 13:11:32 tracer dansguardian[25]: closed 98
    Oct 18 13:11:32 tracer dansguardian[25]: numchildren now: 88
    Oct 18 13:11:32 tracer dansguardian[25]: deleted child: fd: 98 pid: 9955
    Oct 18 13:11:32 tracer dansguardian[25]: closed 97
    Oct 18 13:11:32 tracer dansguardian[69]: Child has handled 500 requests and is exiting
    Oct 18 13:11:32 tracer dansguardian[25]: numchildren now: 87
    Oct 18 13:11:32 tracer dansguardian[25]: deleted child: fd: 97 pid: 27704
    Oct 18 13:11:32 tracer dansguardian[25]: closed 96
    Oct 18 13:11:32 tracer dansguardian[25]: numchildren now: 86
    Oct 18 13:11:32 tracer dansguardian[25088]: Child has handled 500 requests and is exiting
    Oct 18 13:11:32 tracer dansguardian[25]: deleted child: fd: 96 pid: 6446
    Oct 18 13:11:32 tracer dansguardian[25]: closed 95
    Oct 18 13:11:32 tracer dansguardian[25]: numchildren now: 85
    Oct 18 13:11:32 tracer dansguardian[7138]: Child has handled 500 requests and is exiting
    Oct 18 13:11:32 tracer dansguardian[25]: deleted child: fd: 95 pid: 29120
    Oct 18 13:11:32 tracer dansguardian[25]: closed 94
    Oct 18 13:11:32 tracer dansguardian[11928]: Child has handled 500 requests and is exiting
    Oct 18 13:11:32 tracer dansguardian[25]: numchildren now: 84
    Oct 18 13:11:32 tracer dansguardian[25]: deleted child: fd: 94 pid: 19515
    Oct 18 13:11:32 tracer dansguardian[25]: closed 93
    Oct 18 13:11:32 tracer dansguardian[30935]: Child has handled 500 requests and is exiting
    Oct 18 13:11:32 tracer dansguardian[25]: numchildren now: 83
    Oct 18 13:11:32 tracer dansguardian[25]: deleted child: fd: 93 pid: 14055
    Oct 18 13:11:32 tracer dansguardian[25]: closed 92
    Oct 18 13:11:32 tracer dansguardian[25]: numchildren now: 82
    Oct 18 13:11:32 tracer dansguardian[21425]: Child has handled 500 requests and is exiting
    Oct 18 13:11:32 tracer dansguardian[25]: deleted child: fd: 92 pid: 69
    Oct 18 13:11:32 tracer dansguardian[25]: closed 91
    Oct 18 13:11:32 tracer dansguardian[20160]: Child has handled 500 requests and is exiting
    Oct 18 13:11:32 tracer dansguardian[25]: numchildren now: 81
    Oct 18 13:11:32 tracer dansguardian[25]: deleted child: fd: 91 pid: 25088
    Oct 18 13:11:32 tracer dansguardian[25]: closed 90
    Oct 18 13:11:32 tracer dansguardian[4865]: Child has handled 500 requests and is exiting
    Oct 18 13:11:32 tracer dansguardian[25]: numchildren now: 80
    Oct 18 13:11:32 tracer dansguardian[25]: deleted child: fd: 90 pid: 7138
    Oct 18 13:11:32 tracer dansguardian[25]: closed 89
    Oct 18 13:11:32 tracer dansguardian[9354]: Child has handled 500 requests and is exiting
    Oct 18 13:11:32 tracer dansguardian[25]: numchildren now: 79
    Oct 18 13:11:32 tracer dansguardian[25]: deleted child: fd: 89 pid: 11928
    Oct 18 13:11:32 tracer dansguardian[23474]: Child has handled 500 requests and is exiting
    Oct 18 13:11:32 tracer dansguardian[25]: closed 88
    Oct 18 13:11:32 tracer dansguardian[25]: numchildren now: 78
    Oct 18 13:11:32 tracer dansguardian[25]: deleted child: fd: 88 pid: 30935
    Oct 18 13:11:32 tracer dansguardian[8767]: Child has handled 500 requests and is exiting
    Oct 18 13:11:32 tracer dansguardian[25]: closed 87
    Oct 18 13:11:32 tracer dansguardian[25]: numchildren now: 77
    Oct 18 13:11:32 tracer dansguardian[25]: deleted child: fd: 87 pid: 21425
    Oct 18 13:11:32 tracer dansguardian[17577]: Child has handled 500 requests and is exiting
    Oct 18 13:11:32 tracer dansguardian[25]: closed 86
    Oct 18 13:11:32 tracer dansguardian[25]: numchildren now: 76
    Oct 18 13:11:32 tracer dansguardian[25]: deleted child: fd: 86 pid: 20160
    Oct 18 13:11:32 tracer dansguardian[11471]: Child has handled 500 requests and is exiting
    Oct 18 13:11:32 tracer dansguardian[25]: closed 85
    Oct 18 13:11:32 tracer dansguardian[25]: numchildren now: 75
    Oct 18 13:11:32 tracer dansguardian[25]: deleted child: fd: 85 pid: 4865
    Oct 18 13:11:32 tracer dansguardian[3070]: Child has handled 500 requests and is exiting
    Oct 18 13:11:32 tracer dansguardian[25]: closed 84
    Oct 18 13:11:32 tracer dansguardian[25]: numchildren now: 74
    Oct 18 13:11:32 tracer dansguardian[25]: deleted child: fd: 84 pid: 9354
    Oct 18 13:11:32 tracer dansguardian[26587]: Child has handled 500 requests and is exiting
    Oct 18 13:11:32 tracer dansguardian[25]: closed 83
    Oct 18 13:11:32 tracer dansguardian[25]: numchildren now: 73
    Oct 18 13:11:32 tracer dansguardian[25]: deleted child: fd: 83 pid: 23474
    Oct 18 13:11:32 tracer dansguardian[25]: closed 82
    Oct 18 13:11:32 tracer dansguardian[25]: numchildren now: 72
    Oct 18 13:11:32 tracer dansguardian[25]: deleted child: fd: 82 pid: 8767
    Oct 18 13:11:32 tracer dansguardian[14783]: Child has handled 500 requests and is exiting
    Oct 18 13:11:32 tracer dansguardian[25]: closed 81
    Oct 18 13:11:32 tracer dansguardian[25]: numchildren now: 71
    Oct 18 13:11:32 tracer dansguardian[25]: deleted child: fd: 81 pid: 17577
    Oct 18 13:11:32 tracer dansguardian[21341]: Child has handled 500 requests and is exiting
    Oct 18 13:11:32 tracer dansguardian[25]: closed 80
    Oct 18 13:11:32 tracer dansguardian[25]: numchildren now: 70
    Oct 18 13:11:32 tracer dansguardian[25]: deleted child: fd: 80 pid: 11471
    Oct 18 13:11:32 tracer dansguardian[4344]: Child has handled 500 requests and is exiting
    Oct 18 13:11:32 tracer dansguardian[25]: closed 79
    Oct 18 13:11:32 tracer dansguardian[25]: numchildren now: 69
    Oct 18 13:11:32 tracer dansguardian[25]: deleted child: fd: 79 pid: 3070
    Oct 18 13:11:32 tracer dansguardian[15804]: Child has handled 500 requests and is exiting
    Oct 18 13:11:32 tracer dansguardian[25]: closed 78
    Oct 18 13:11:32 tracer dansguardian[25]: numchildren now: 68
    Oct 18 13:11:32 tracer dansguardian[25]: deleted child: fd: 78 pid: 26587
    Oct 18 13:11:32 tracer dansguardian[5754]: Child has handled 500 requests and is exiting
    Oct 18 13:11:32 tracer dansguardian[25]: closed 76
    Oct 18 13:11:32 tracer dansguardian[25]: numchildren now: 67
    Oct 18 13:11:32 tracer dansguardian[25]: deleted child: fd: 76 pid: 14783
    Oct 18 13:11:32 tracer dansguardian[31621]: Child has handled 500 requests and is exiting
    Oct 18 13:11:32 tracer dansguardian[25]: closed 75
    Oct 18 13:11:32 tracer dansguardian[25]: numchildren now: 66
    Oct 18 13:11:32 tracer dansguardian[25]: deleted child: fd: 75 pid: 21341
    Oct 18 13:11:32 tracer dansguardian[21990]: Child has handled 500 requests and is exiting
    Oct 18 13:11:32 tracer dansguardian[25]: closed 74
    Oct 18 13:11:32 tracer dansguardian[25]: numchildren now: 65
    Oct 18 13:11:32 tracer dansguardian[25]: deleted child: fd: 74 pid: 4344
    Oct 18 13:11:32 tracer dansguardian[17430]: Child has handled 500 requests and is exiting
    Oct 18 13:11:32 tracer dansguardian[25]: closed 73
    Oct 18 13:11:32 tracer dansguardian[25]: numchildren now: 64
    Oct 18 13:11:32 tracer dansguardian[25]: deleted child: fd: 73 pid: 15804
    Oct 18 13:11:32 tracer dansguardian[17210]: Child has handled 500 requests and is exiting
    Oct 18 13:11:32 tracer dansguardian[25]: closed 72
    Oct 18 13:11:32 tracer dansguardian[25]: numchildren now: 63
    Oct 18 13:11:32 tracer dansguardian[25]: deleted child: fd: 72 pid: 22770
    Oct 18 13:11:32 tracer dansguardian[16842]: Child has handled 500 requests and is exiting
    Oct 18 13:11:32 tracer dansguardian[25]: closed 71
    Oct 18 13:11:32 tracer dansguardian[25]: numchildren now: 62
    Oct 18 13:11:32 tracer dansguardian[25]: deleted child: fd: 71 pid: 5754
    Oct 18 13:11:32 tracer dansguardian[25]: closed 70
    Oct 18 13:11:32 tracer dansguardian[23370]: Child has handled 500 requests and is exiting
    Oct 18 13:11:32 tracer dansguardian[25]: numchildren now: 61
    Oct 18 13:11:32 tracer dansguardian[25]: deleted child: fd: 70 pid: 31621
    Oct 18 13:11:32 tracer dansguardian[32395]: Child has handled 500 requests and is exiting
    Oct 18 13:11:32 tracer dansguardian[25]: closed 69
    Oct 18 13:11:32 tracer dansguardian[25]: numchildren now: 60
    Oct 18 13:11:32 tracer dansguardian[25]: deleted child: fd: 69 pid: 21990
    Oct 18 13:11:32 tracer dansguardian[31554]: Child has handled 500 requests and is exiting
    Oct 18 13:11:32 tracer dansguardian[25]: closed 68
    Oct 18 13:11:32 tracer dansguardian[25]: numchildren now: 59
    Oct 18 13:11:32 tracer dansguardian[25]: deleted child: fd: 68 pid: 17430
    Oct 18 13:11:32 tracer dansguardian[2602]: Child has handled 500 requests and is exiting
    Oct 18 13:11:32 tracer dansguardian[25]: closed 67
    Oct 18 13:11:32 tracer dansguardian[25]: numchildren now: 58
    Oct 18 13:11:32 tracer dansguardian[25]: deleted child: fd: 67 pid: 17210
    Oct 18 13:11:32 tracer dansguardian[8990]: Child has handled 500 requests and is exiting
    Oct 18 13:11:32 tracer dansguardian[25]: closed 66
    Oct 18 13:11:32 tracer dansguardian[25]: numchildren now: 57
    Oct 18 13:11:32 tracer dansguardian[25]: deleted child: fd: 66 pid: 16842
    Oct 18 13:11:32 tracer dansguardian[25]: closed 65
    Oct 18 13:11:32 tracer dansguardian[22026]: Child has handled 500 requests and is exiting
    Oct 18 13:11:32 tracer dansguardian[25]: numchildren now: 56
    Oct 18 13:11:32 tracer dansguardian[25]: deleted child: fd: 65 pid: 23370
    Oct 18 13:11:32 tracer dansguardian[25]: closed 64
    Oct 18 13:11:32 tracer dansguardian[7643]: Child has handled 500 requests and is exiting
    Oct 18 13:11:32 tracer dansguardian[25]: numchildren now: 55
    Oct 18 13:11:32 tracer dansguardian[25]: deleted child: fd: 64 pid: 32395
    Oct 18 13:12:00 tracer dansguardian[21911]: Child has handled 500 requests and is exiting
    Oct 18 13:12:01 tracer dansguardian[25]: numchildren: 52, o.max_children: 120
    Oct 18 13:12:01 tracer dansguardian[25]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 18 13:12:01 tracer dansguardian[25]: added child: fd: 4 pid: 30424
    Oct 18 13:12:01 tracer dansguardian[25]: added child: fd: 5 pid: 31480
    Oct 18 13:12:01 tracer dansguardian[25]: added child: fd: 9 pid: 6707
    Oct 18 13:12:01 tracer dansguardian[25]: added child: fd: 12 pid: 18535
    Oct 18 13:12:01 tracer dansguardian[25]: added child: fd: 14 pid: 6299
    Oct 18 13:12:01 tracer dansguardian[25]: added child: fd: 15 pid: 16422
    Oct 18 13:12:09 tracer dansguardian[25]: numchildren: 58, o.max_children: 120
    Oct 18 13:12:09 tracer dansguardian[25]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 18 13:12:09 tracer dansguardian[25]: added child: fd: 19 pid: 22545
    Oct 18 13:12:09 tracer dansguardian[25]: added child: fd: 20 pid: 9805
    Oct 18 13:12:10 tracer dansguardian[25]: added child: fd: 22 pid: 9391
    Oct 18 13:12:10 tracer dansguardian[25]: added child: fd: 23 pid: 14412
    Oct 18 13:12:10 tracer dansguardian[25]: added child: fd: 40 pid: 2351
    Oct 18 13:12:10 tracer dansguardian[25]: added child: fd: 64 pid: 16885
    Oct 18 13:12:16 tracer dansguardian[25]: numchildren: 64, o.max_children: 120
    Oct 18 13:12:16 tracer dansguardian[25]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 18 13:12:16 tracer dansguardian[25]: added child: fd: 65 pid: 10146
    Oct 18 13:12:16 tracer dansguardian[25]: numchildren: 64, o.max_children: 120
    Oct 18 13:12:16 tracer dansguardian[25]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 18 13:12:16 tracer dansguardian[25]: added child: fd: 65 pid: 13541
    

    But, just after this first part, take a look at what starts happening with numchildren -- it doesn't get updated for some reason. So, numchildren gets stuck at '65', but more processes are spawned in groups of 6 (ie, Fewer than 4 free children - Spawning 6 process(es)). That's why the processes keep on adding up. What I don't know is why numchildren gets stuck at 65.

    
    Oct 18 13:12:16 tracer dansguardian[25]: numchildren: 63, o.max_children: 120
    Oct 18 13:12:16 tracer dansguardian[25]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 18 13:12:16 tracer dansguardian[25]: added child: fd: 66 pid: 24165
    Oct 18 13:12:16 tracer dansguardian[25]: added child: fd: 67 pid: 22816
    Oct 18 13:13:20 tracer dansguardian[10019]: Child has handled 500 requests and is exiting
    Oct 18 13:13:44 tracer dansguardian[25]: numchildren: 64, o.max_children: 120
    Oct 18 13:13:44 tracer dansguardian[25]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 18 13:13:44 tracer dansguardian[25]: added child: fd: 11 pid: 22893
    Oct 18 13:13:44 tracer dansguardian[7299]: Child has handled 500 requests and is exiting
    Oct 18 13:13:51 tracer dansguardian[25]: numchildren: 64, o.max_children: 120
    Oct 18 13:13:51 tracer dansguardian[25]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 18 13:13:51 tracer dansguardian[25]: added child: fd: 26 pid: 27571
    Oct 18 13:13:52 tracer dansguardian[25]: numchildren: 65, o.max_children: 120
    Oct 18 13:13:52 tracer dansguardian[25]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 18 13:13:52 tracer dansguardian[25]: numchildren: 65, o.max_children: 120
    Oct 18 13:13:52 tracer dansguardian[25]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 18 13:13:52 tracer dansguardian[25]: numchildren: 65, o.max_children: 120
    Oct 18 13:13:52 tracer dansguardian[25]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 18 13:13:52 tracer dansguardian[25]: numchildren: 65, o.max_children: 120
    Oct 18 13:13:52 tracer dansguardian[25]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 18 13:13:52 tracer dansguardian[25]: numchildren: 65, o.max_children: 120
    Oct 18 13:13:52 tracer dansguardian[25]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 18 13:13:54 tracer dansguardian[25]: numchildren: 65, o.max_children: 120
    Oct 18 13:13:54 tracer dansguardian[25]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 18 13:13:54 tracer dansguardian[25]: numchildren: 65, o.max_children: 120
    Oct 18 13:13:54 tracer dansguardian[25]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 18 13:13:54 tracer dansguardian[25]: numchildren: 65, o.max_children: 120
    Oct 18 13:13:54 tracer dansguardian[25]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 18 13:13:54 tracer dansguardian[25]: numchildren: 65, o.max_children: 120
    Oct 18 13:13:54 tracer dansguardian[25]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 18 13:13:55 tracer dansguardian[25]: numchildren: 65, o.max_children: 120
    Oct 18 13:13:55 tracer dansguardian[25]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 18 13:13:55 tracer dansguardian[25]: numchildren: 65, o.max_children: 120
    Oct 18 13:13:55 tracer dansguardian[25]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 18 13:13:55 tracer dansguardian[25]: numchildren: 65, o.max_children: 120
    Oct 18 13:13:55 tracer dansguardian[25]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 18 13:13:55 tracer dansguardian[25]: No free children from getfreechild(): numchildren = 65, busychildren = 64, waitingfor = 0
    Oct 18 13:13:55 tracer dansguardian[25]: numchildren: 65, o.max_children: 120
    Oct 18 13:13:55 tracer dansguardian[25]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 18 13:13:55 tracer dansguardian[25]: No free children from getfreechild(): numchildren = 65, busychildren = 64, waitingfor = 0
    Oct 18 13:13:55 tracer dansguardian[25]: numchildren: 65, o.max_children: 120
    Oct 18 13:13:55 tracer dansguardian[25]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 18 13:13:55 tracer dansguardian[25]: numchildren: 65, o.max_children: 120
    Oct 18 13:13:55 tracer dansguardian[25]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 18 13:13:55 tracer dansguardian[25]: No free children from getfreechild(): numchildren = 65, busychildren = 64, waitingfor = 0
    Oct 18 13:13:55 tracer dansguardian[25]: numchildren: 65, o.max_children: 120
    Oct 18 13:13:55 tracer dansguardian[25]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 18 13:13:55 tracer dansguardian[25]: numchildren: 65, o.max_children: 120
    Oct 18 13:13:55 tracer dansguardian[25]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 18 13:13:55 tracer dansguardian[25]: No free children from getfreechild(): numchildren = 65, busychildren = 64, waitingfor = 0
    Oct 18 13:13:55 tracer dansguardian[25]: numchildren: 65, o.max_children: 120
    Oct 18 13:13:55 tracer dansguardian[25]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 18 13:13:55 tracer dansguardian[25]: numchildren: 65, o.max_children: 120
    Oct 18 13:13:55 tracer dansguardian[25]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 18 13:13:55 tracer dansguardian[25]: No free children from getfreechild(): numchildren = 65, busychildren = 64, waitingfor = 0
    Oct 18 13:13:55 tracer dansguardian[25]: numchildren: 65, o.max_children: 120
    Oct 18 13:13:55 tracer dansguardian[25]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 18 13:13:55 tracer dansguardian[25]: No free children from getfreechild(): numchildren = 65, busychildren = 64, waitingfor = 0
    Oct 18 13:13:55 tracer dansguardian[25]: numchildren: 65, o.max_children: 120
    Oct 18 13:13:55 tracer dansguardian[25]: Fewer than 4 free children - Spawning 6 process(es)
    

    This goes on and on until I the bsd proc table gets full, after which I try to kill all the processes. One interesting bit is that all the exiting children report exiting after executing 500 requests (maxchildrenage), when I don't think that could have happened...

    
    Oct 18 13:16:54 tracer dansguardian[25]: No free children from getfreechild(): numchildren = 65, busychildren = 64, waitingfor = 0
    Oct 18 13:16:55 tracer dansguardian[25]: numchildren: 65, o.max_children: 120
    Oct 18 13:16:55 tracer dansguardian[13930]: Child has handled 500 requests and is exiting
    Oct 18 13:16:55 tracer dansguardian[25]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 18 13:16:56 tracer /bsd: proc: table is full
    Oct 18 13:16:56 tracer dansguardian[25]: Unable to fork() any more.
    Oct 18 13:16:56 tracer dansguardian[30843]: Child has handled 500 requests and is exiting
    Oct 18 13:16:57 tracer dansguardian[25]: Unable to fork() any more.
    Oct 18 13:16:57 tracer dansguardian[29044]: Child has handled 500 requests and is exiting
    Oct 18 13:16:57 tracer dansguardian[2986]: Child has handled 500 requests and is exiting
    Oct 18 13:16:58 tracer dansguardian[30586]: Child has handled 500 requests and is exiting
    Oct 18 13:16:58 tracer dansguardian[11275]: Child has handled 500 requests and is exiting
    Oct 18 13:16:58 tracer dansguardian[979]: Child has handled 500 requests and is exiting
    Oct 18 13:16:58 tracer dansguardian[13875]: Child has handled 500 requests and is exiting
    Oct 18 13:16:58 tracer dansguardian[19902]: Child has handled 500 requests and is exiting
    Oct 18 13:16:58 tracer dansguardian[25]: numchildren: 65, o.max_children: 120
    Oct 18 13:16:58 tracer dansguardian[25]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 18 13:16:58 tracer dansguardian[25]: numchildren: 65, o.max_children: 120
    Oct 18 13:16:58 tracer dansguardian[25]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 18 13:16:58 tracer dansguardian[25]: Unable to fork() any more.
    Oct 18 13:16:59 tracer dansguardian[8043]: Child has handled 500 requests and is exiting
    Oct 18 13:16:59 tracer dansguardian[15941]: Child has handled 500 requests and is exiting
    Oct 18 13:16:59 tracer dansguardian[4388]: Child has handled 500 requests and is exiting
    Oct 18 13:16:59 tracer dansguardian[25]: Unable to fork() any more.
    Oct 18 13:17:00 tracer dansguardian[23201]: Child has handled 500 requests and is exiting
    Oct 18 13:17:01 tracer dansguardian[25]: Unable to fork() any more.
    Oct 18 13:17:01 tracer dansguardian[16016]: Child has handled 500 requests and is exiting
    Oct 18 13:17:02 tracer dansguardian[25]: numchildren: 65, o.max_children: 120
    Oct 18 13:17:02 tracer dansguardian[25]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 18 13:17:02 tracer dansguardian[25]: numchildren: 65, o.max_children: 120
    Oct 18 13:17:02 tracer dansguardian[25]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 18 13:17:02 tracer dansguardian[25]: Unable to fork() any more.
    Oct 18 13:17:03 tracer dansguardian[25]: numchildren: 65, o.max_children: 120
    Oct 18 13:17:03 tracer dansguardian[25]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 18 13:17:03 tracer dansguardian[18958]: Child has handled 500 requests and is exiting
    Oct 18 13:17:04 tracer dansguardian[28445]: Child has handled 500 requests and is exiting
    Oct 18 13:17:04 tracer dansguardian[25]: Unable to fork() any more.
    Oct 18 13:17:05 tracer dansguardian[25]: Unable to fork() any more.
    Oct 18 13:17:05 tracer dansguardian[1511]: Child has handled 500 requests and is exiting
    Oct 18 13:17:06 tracer /bsd: proc: table is full
    Oct 18 13:17:06 tracer dansguardian[25]: Unable to fork() any more.
    Oct 18 13:17:15 tracer last message repeated 9 times
    Oct 18 13:17:16 tracer /bsd: proc: table is full
    Oct 18 13:17:16 tracer dansguardian[25]: Unable to fork() any more.
    Oct 18 13:17:25 tracer last message repeated 9 times
    Oct 18 13:17:26 tracer /bsd: proc: table is full
    Oct 18 13:17:26 tracer dansguardian[25]: Unable to fork() any more.
    Oct 18 13:17:35 tracer last message repeated 9 times
    Oct 18 13:17:36 tracer /bsd: proc: table is full
    Oct 18 13:17:36 tracer dansguardian[25]: Unable to fork() any more.
    Oct 18 13:17:45 tracer last message repeated 9 times
    Oct 18 13:17:46 tracer /bsd: proc: table is full
    Oct 18 13:17:46 tracer dansguardian[25]: Unable to fork() any more.
    Oct 18 13:17:55 tracer last message repeated 9 times
    Oct 18 13:17:56 tracer /bsd: proc: table is full
    Oct 18 13:17:56 tracer dansguardian[25]: Unable to fork() any more.
    Oct 18 13:18:06 tracer last message repeated 9 times
    Oct 18 13:18:07 tracer /bsd: proc: table is full
    Oct 18 13:18:07 tracer dansguardian[25]: Unable to fork() any more.
    Oct 18 13:18:09 tracer last message repeated 2 times
    Oct 18 13:18:09 tracer dansguardian[30424]: Child has handled 500 requests and is exiting
    Oct 18 13:18:09 tracer dansguardian[31480]: Child has handled 500 requests and is exiting
    Oct 18 13:18:09 tracer dansguardian[6707]: Child has handled 500 requests and is exiting
    Oct 18 13:18:09 tracer dansguardian[14412]: Child has handled 500 requests and is exiting
    Oct 18 13:18:09 tracer dansguardian[18535]: Child has handled 500 requests and is exiting
    Oct 18 13:18:09 tracer dansguardian[12636]: Child has handled 500 requests and is exiting
    Oct 18 13:18:09 tracer dansguardian[11255]: Child has handled 500 requests and is exiting
    Oct 18 13:18:09 tracer dansguardian[5885]: Child has handled 500 requests and is exiting
    Oct 18 13:18:09 tracer dansguardian[6646]: Child has handled 500 requests and is exiting
    Oct 18 13:18:09 tracer dansguardian[21333]: Child has handled 500 requests and is exiting
    Oct 18 13:18:09 tracer dansguardian[4512]: Child has handled 500 requests and is exiting
    Oct 18 13:18:09 tracer dansguardian[19881]: Child has handled 500 requests and is exiting
    Oct 18 13:18:09 tracer dansguardian[10203]: Child has handled 500 requests and is exiting
    Oct 18 13:18:09 tracer dansguardian[12899]: Child has handled 500 requests and is exiting
    Oct 18 13:18:09 tracer dansguardian[27571]: Child has handled 500 requests and is exiting
    Oct 18 13:18:09 tracer dansguardian[3230]: Child has handled 500 requests and is exiting
    Oct 18 13:18:09 tracer dansguardian[27464]: Child has handled 500 requests and is exiting
    Oct 18 13:18:09 tracer dansguardian[15978]: Child has handled 500 requests and is exiting
    Oct 18 13:18:09 tracer dansguardian[28995]: Child has handled 500 requests and is exiting
    Oct 18 13:18:09 tracer dansguardian[29001]: Child has handled 500 requests and is exiting
    Oct 18 13:18:09 tracer dansguardian[890]: Child has handled 500 requests and is exiting
    Oct 18 13:18:09 tracer dansguardian[15539]: Child has handled 500 requests and is exiting
    Oct 18 13:18:09 tracer dansguardian[21228]: Child has handled 500 requests and is exiting
    Oct 18 13:18:09 tracer dansguardian[7562]: Child has handled 500 requests and is exiting
    Oct 18 13:18:09 tracer dansguardian[23161]: Child has handled 500 requests and is exiting
    Oct 18 13:18:09 tracer dansguardian[10224]: Child has handled 500 requests and is exiting
    Oct 18 13:18:09 tracer dansguardian[22893]: Child has handled 500 requests and is exiting
    Oct 18 13:18:09 tracer dansguardian[25488]: Child has handled 500 requests and is exiting
    Oct 18 13:18:10 tracer dansguardian[31540]: Child has handled 500 requests and is exiting
    Oct 18 13:18:09 tracer dansguardian[22816]: Child has handled 500 requests and is exiting
    Oct 18 13:18:10 tracer dansguardian[23289]: Child has handled 500 requests and is exiting
    Oct 18 13:18:10 tracer dansguardian[14401]: Child has handled 500 requests and is exiting
    Oct 18 13:18:11 tracer dansguardian[21453]: Child has handled 500 requests and is exiting
    Oct 18 13:18:11 tracer dansguardian[26697]: Child has handled 500 requests and is exiting
    Oct 18 13:18:11 tracer dansguardian[4791]: Child has handled 500 requests and is exiting
    Oct 18 13:18:11 tracer dansguardian[13887]: Child has handled 500 requests and is exiting
    Oct 18 13:18:11 tracer dansguardian[27475]: Child has handled 500 requests and is exiting
    Oct 18 13:18:11 tracer dansguardian[3364]: Child has handled 500 requests and is exiting
    Oct 18 13:18:11 tracer dansguardian[30719]: Child has handled 500 requests and is exiting
    Oct 18 13:18:11 tracer dansguardian[25887]: Child has handled 500 requests and is exiting
    Oct 18 13:18:11 tracer dansguardian[25265]: Child has handled 500 requests and is exiting
    Oct 18 13:18:11 tracer dansguardian[30615]: Child has handled 500 requests and is exiting
    Oct 18 13:18:11 tracer dansguardian[11421]: Child has handled 500 requests and is exiting
    Oct 18 13:18:12 tracer dansguardian[28980]: Child has handled 500 requests and is exiting
    Oct 18 13:18:12 tracer dansguardian[17452]: Child has handled 500 requests and is exiting
    Oct 18 13:18:12 tracer dansguardian[23594]: Child has handled 500 requests and is exiting
    Oct 18 13:18:12 tracer dansguardian[20772]: Child has handled 500 requests and is exiting
    Oct 18 13:18:12 tracer dansguardian[14766]: Child has handled 500 requests and is exiting
    Oct 18 13:18:12 tracer dansguardian[9702]: Child has handled 500 requests and is exiting
    Oct 18 13:18:12 tracer dansguardian[8733]: Child has handled 500 requests and is exiting
    Oct 18 13:18:12 tracer dansguardian[23685]: Child has handled 500 requests and is exiting
    Oct 18 13:18:12 tracer dansguardian[27177]: Child has handled 500 requests and is exiting
    Oct 18 13:18:12 tracer dansguardian[24459]: Child has handled 500 requests and is exiting
    Oct 18 13:18:12 tracer dansguardian[14176]: Child has handled 500 requests and is exiting
    Oct 18 13:18:13 tracer dansguardian[30875]: Child has handled 500 requests and is exiting
    Oct 18 13:18:13 tracer dansguardian[28297]: Child has handled 500 requests and is exiting
    Oct 18 13:18:13 tracer dansguardian[2808]: Child has handled 500 requests and is exiting
    Oct 18 13:18:13 tracer dansguardian[21978]: Child has handled 500 requests and is exiting
    Oct 18 13:18:13 tracer dansguardian[24167]: Child has handled 500 requests and is exiting
    Oct 18 13:18:13 tracer dansguardian[15704]: Child has handled 500 requests and is exiting
    Oct 18 13:18:13 tracer dansguardian[3033]: Child has handled 500 requests and is exiting
    Oct 18 13:18:13 tracer dansguardian[24376]: Child has handled 500 requests and is exiting
    Oct 18 13:18:13 tracer dansguardian[15761]: Child has handled 500 requests and is exiting
    Oct 18 13:18:13 tracer dansguardian[2175]: Child has handled 500 requests and is exiting
    Oct 18 13:18:14 tracer dansguardian[2506]: Child has handled 500 requests and is exiting
    Oct 18 13:18:14 tracer dansguardian[23225]: Child has handled 500 requests and is exiting
    Oct 18 13:18:14 tracer dansguardian[1942]: Child has handled 500 requests and is exiting
    Oct 18 13:18:14 tracer dansguardian[30272]: Child has handled 500 requests and is exiting
    Oct 18 13:18:14 tracer dansguardian[836]: Child has handled 500 requests and is exiting
    Oct 18 13:18:14 tracer dansguardian[27207]: Child has handled 500 requests and is exiting
    Oct 18 13:18:14 tracer dansguardian[4771]: Child has handled 500 requests and is exiting
    Oct 18 13:18:14 tracer dansguardian[974]: Child has handled 500 requests and is exiting
    Oct 18 13:18:14 tracer dansguardian[31447]: Child has handled 500 requests and is exiting
    Oct 18 13:18:14 tracer dansguardian[16436]: Child has handled 500 requests and is exiting
    Oct 18 13:18:14 tracer dansguardian[5661]: Child has handled 500 requests and is exiting
    Oct 18 13:18:14 tracer dansguardian[19267]: Child has handled 500 requests and is exiting
    Oct 18 13:18:15 tracer dansguardian[16046]: Child has handled 500 requests and is exiting
    Oct 18 13:18:15 tracer dansguardian[5368]: Child has handled 500 requests and is exiting
    Oct 18 13:18:15 tracer dansguardian[17708]: Child has handled 500 requests and is exiting
    Oct 18 13:18:15 tracer dansguardian[26532]: Child has handled 500 requests and is exiting
    Oct 18 13:18:15 tracer dansguardian[10345]: Child has handled 500 requests and is exiting
    Oct 18 13:18:15 tracer dansguardian[20650]: Child has handled 500 requests and is exiting
    Oct 18 13:18:15 tracer dansguardian[13827]: Child has handled 500 requests and is exiting
    Oct 18 13:18:15 tracer dansguardian[1637]: Child has handled 500 requests and is exiting
    Oct 18 13:18:15 tracer dansguardian[22967]: Child has handled 500 requests and is exiting
    Oct 18 13:18:15 tracer dansguardian[11008]: Child has handled 500 requests and is exiting
    Oct 18 13:18:15 tracer dansguardian[13975]: Child has handled 500 requests and is exiting
    Oct 18 13:18:15 tracer dansguardian[1118]: Child has handled 500 requests and is exiting
    Oct 18 13:18:16 tracer dansguardian[2252]: Child has handled 500 requests and is exiting
    Oct 18 13:18:16 tracer dansguardian[6899]: Child has handled 500 requests and is exiting
    Oct 18 13:18:16 tracer dansguardian[32247]: Child has handled 500 requests and is exiting
    Oct 18 13:18:16 tracer dansguardian[28294]: Child has handled 500 requests and is exiting
    Oct 18 13:18:16 tracer dansguardian[17100]: Child has handled 500 requests and is exiting
    Oct 18 13:18:16 tracer dansguardian[11130]: Child has handled 500 requests and is exiting
    Oct 18 13:18:16 tracer dansguardian[29553]: Child has handled 500 requests and is exiting
    Oct 18 13:18:16 tracer dansguardian[23088]: Child has handled 500 requests and is exiting
    Oct 18 13:18:16 tracer dansguardian[14604]: Child has handled 500 requests and is exiting
    Oct 18 13:18:16 tracer dansguardian[18216]: Child has handled 500 requests and is exiting
    Oct 18 13:18:16 tracer dansguardian[16267]: Child has handled 500 requests and is exiting
    Oct 18 13:18:16 tracer dansguardian[19241]: Child has handled 500 requests and is exiting
    Oct 18 13:18:17 tracer dansguardian[4981]: Child has handled 500 requests and is exiting
    Oct 18 13:18:17 tracer dansguardian[27634]: Child has handled 500 requests and is exiting
    Oct 18 13:18:17 tracer dansguardian[25405]: Child has handled 500 requests and is exiting
    Oct 18 13:18:17 tracer dansguardian[24301]: Child has handled 500 requests and is exiting
    Oct 18 13:18:17 tracer dansguardian[32182]: Child has handled 500 requests and is exiting
    Oct 18 13:18:17 tracer dansguardian[21159]: Child has handled 500 requests and is exiting
    Oct 18 13:18:17 tracer dansguardian[17451]: Child has handled 500 requests and is exiting
    Oct 18 13:18:17 tracer dansguardian[29004]: Child has handled 500 requests and is exiting
    Oct 18 13:18:17 tracer dansguardian[25667]: Child has handled 500 requests and is exiting
    Oct 18 13:18:17 tracer dansguardian[28891]: Child has handled 500 requests and is exiting
    Oct 18 13:18:17 tracer dansguardian[24001]: Child has handled 500 requests and is exiting
    Oct 18 13:18:17 tracer dansguardian[11327]: Child has handled 500 requests and is exiting
    Oct 18 13:18:17 tracer dansguardian[19183]: Child has handled 500 requests and is exiting
    Oct 18 13:18:18 tracer dansguardian[21250]: Child has handled 500 requests and is exiting
    Oct 18 13:18:18 tracer dansguardian[29589]: Child has handled 500 requests and is exiting
    Oct 18 13:18:18 tracer dansguardian[5873]: Child has handled 500 requests and is exiting
    Oct 18 13:18:18 tracer dansguardian[24299]: Child has handled 500 requests and is exiting
    Oct 18 13:18:18 tracer dansguardian[18826]: Child has handled 500 requests and is exiting
    Oct 18 13:18:18 tracer dansguardian[15091]: Child has handled 500 requests and is exiting
    Oct 18 13:18:18 tracer dansguardian[14254]: Child has handled 500 requests and is exiting
    Oct 18 13:18:18 tracer dansguardian[4814]: Child has handled 500 requests and is exiting
    Oct 18 13:18:18 tracer dansguardian[27683]: Child has handled 500 requests and is exiting
    Oct 18 13:18:18 tracer dansguardian[3595]: Child has handled 500 requests and is exiting
    Oct 18 13:18:18 tracer dansguardian[10672]: Child has handled 500 requests and is exiting
    Oct 18 13:18:18 tracer dansguardian[30392]: Child has handled 500 requests and is exiting
    Oct 18 13:18:18 tracer dansguardian[25796]: Child has handled 500 requests and is exiting
    Oct 18 13:18:19 tracer dansguardian[25089]: Child has handled 500 requests and is exiting
    Oct 18 13:18:19 tracer dansguardian[17234]: Child has handled 500 requests and is exiting
    Oct 18 13:18:19 tracer dansguardian[30524]: Child has handled 500 requests and is exiting
    Oct 18 13:18:19 tracer dansguardian[13467]: Child has handled 500 requests and is exiting
    Oct 18 13:18:19 tracer dansguardian[20533]: Child has handled 500 requests and is exiting
    Oct 18 13:18:19 tracer dansguardian[1796]: Child has handled 500 requests and is exiting
    Oct 18 13:18:19 tracer dansguardian[8836]: Child has handled 500 requests and is exiting
    Oct 18 13:18:19 tracer dansguardian[331]: Child has handled 500 requests and is exiting
    Oct 18 13:18:19 tracer dansguardian[3587]: Child has handled 500 requests and is exiting
    Oct 18 13:18:19 tracer dansguardian[25038]: Child has handled 500 requests and is exiting
    Oct 18 13:18:19 tracer dansguardian[30383]: Child has handled 500 requests and is exiting
    Oct 18 13:18:19 tracer dansguardian[12840]: Child has handled 500 requests and is exiting
    Oct 18 13:18:19 tracer dansguardian[1033]: Child has handled 500 requests and is exiting
    Oct 18 13:18:19 tracer dansguardian[3612]: Child has handled 500 requests and is exiting
    Oct 18 13:18:20 tracer dansguardian[28040]: Child has handled 500 requests and is exiting
    Oct 18 13:18:20 tracer dansguardian[23867]: Child has handled 500 requests and is exiting
    Oct 18 13:18:20 tracer dansguardian[11146]: Child has handled 500 requests and is exiting
    Oct 18 13:18:20 tracer dansguardian[7567]: Child has handled 500 requests and is exiting
    Oct 18 13:18:20 tracer dansguardian[7993]: Child has handled 500 requests and is exiting
    Oct 18 13:18:20 tracer dansguardian[13489]: Child has handled 500 requests and is exiting
    Oct 18 13:18:20 tracer dansguardian[4681]: Child has handled 500 requests and is exiting
    Oct 18 13:18:20 tracer dansguardian[31697]: Child has handled 500 requests and is exiting
    Oct 18 13:18:20 tracer dansguardian[29415]: Child has handled 500 requests and is exiting
    Oct 18 13:18:20 tracer dansguardian[27215]: Child has handled 500 requests and is exiting
    Oct 18 13:18:20 tracer dansguardian[28595]: Child has handled 500 requests and is exiting
    Oct 18 13:18:20 tracer dansguardian[22986]: Child has handled 500 requests and is exiting
    Oct 18 13:18:20 tracer dansguardian[7030]: Child has handled 500 requests and is exiting
    Oct 18 13:18:20 tracer dansguardian[15421]: Child has handled 500 requests and is exiting
    Oct 18 13:18:20 tracer dansguardian[7108]: Child has handled 500 requests and is exiting
    Oct 18 13:18:21 tracer dansguardian[28039]: Child has handled 500 requests and is exiting
    Oct 18 13:18:21 tracer dansguardian[3307]: Child has handled 500 requests and is exiting
    Oct 18 13:18:21 tracer dansguardian[26988]: Child has handled 500 requests and is exiting
    Oct 18 13:18:21 tracer dansguardian[280]: Child has handled 500 requests and is exiting
    Oct 18 13:18:21 tracer dansguardian[3111]: Child has handled 500 requests and is exiting
    Oct 18 13:18:21 tracer dansguardian[15475]: Child has handled 500 requests and is exiting
    Oct 18 13:18:21 tracer dansguardian[29540]: Child has handled 500 requests and is exiting
    Oct 18 13:18:21 tracer dansguardian[23150]: Child has handled 500 requests and is exiting
    Oct 18 13:18:21 tracer dansguardian[10877]: Child has handled 500 requests and is exiting
    Oct 18 13:18:21 tracer dansguardian[14799]: Child has handled 500 requests and is exiting
    Oct 18 13:18:21 tracer dansguardian[6009]: Child has handled 500 requests and is exiting
    Oct 18 13:18:21 tracer dansguardian[14446]: Child has handled 500 requests and is exiting
    Oct 18 13:18:21 tracer dansguardian[14884]: Child has handled 500 requests and is exiting
    Oct 18 13:18:21 tracer dansguardian[9593]: Child has handled 500 requests and is exiting
    Oct 18 13:18:22 tracer dansguardian[11390]: Child has handled 500 requests and is exiting
    Oct 18 13:18:22 tracer dansguardian[28347]: Child has handled 500 requests and is exiting
    Oct 18 13:18:22 tracer dansguardian[31991]: Child has handled 500 requests and is exiting
    Oct 18 13:18:22 tracer dansguardian[18396]: Child has handled 500 requests and is exiting
    Oct 18 13:18:22 tracer dansguardian[25494]: Child has handled 500 requests and is exiting
    Oct 18 13:18:22 tracer dansguardian[4062]: Child has handled 500 requests and is exiting
    Oct 18 13:18:22 tracer dansguardian[10246]: Child has handled 500 requests and is exiting
    Oct 18 13:18:22 tracer dansguardian[20242]: Child has handled 500 requests and is exiting
    Oct 18 13:18:22 tracer dansguardian[30889]: Child has handled 500 requests and is exiting
    Oct 18 13:18:22 tracer dansguardian[25290]: Child has handled 500 requests and is exiting
    Oct 18 13:18:22 tracer dansguardian[25519]: Child has handled 500 requests and is exiting
    Oct 18 13:18:22 tracer dansguardian[3902]: Child has handled 500 requests and is exiting
    Oct 18 13:18:22 tracer dansguardian[16544]: Child has handled 500 requests and is exiting
    Oct 18 13:18:22 tracer dansguardian[20345]: Child has handled 500 requests and is exiting
    Oct 18 13:18:22 tracer dansguardian[8102]: Child has handled 500 requests and is exiting
    Oct 18 13:18:22 tracer dansguardian[9636]: Child has handled 500 requests and is exiting
    Oct 18 13:18:23 tracer dansguardian[16718]: Child has handled 500 requests and is exiting
    Oct 18 13:18:23 tracer dansguardian[17527]: Child has handled 500 requests and is exiting
    Oct 18 13:18:23 tracer dansguardian[31443]: Child has handled 500 requests and is exiting
    Oct 18 13:18:23 tracer dansguardian[11009]: Child has handled 500 requests and is exiting
    Oct 18 13:18:23 tracer dansguardian[13783]: Child has handled 500 requests and is exiting
    Oct 18 13:18:23 tracer dansguardian[28341]: Child has handled 500 requests and is exiting
    Oct 18 13:18:23 tracer dansguardian[6223]: Child has handled 500 requests and is exiting
    Oct 18 13:18:23 tracer dansguardian[26599]: Child has handled 500 requests and is exiting
    Oct 18 13:18:23 tracer dansguardian[31484]: Child has handled 500 requests and is exiting
    Oct 18 13:18:23 tracer dansguardian[8290]: Child has handled 500 requests and is exiting
    Oct 18 13:18:23 tracer dansguardian[20115]: Child has handled 500 requests and is exiting
    Oct 18 13:18:23 tracer dansguardian[19358]: Child has handled 500 requests and is exiting
    Oct 18 13:18:23 tracer dansguardian[5538]: Child has handled 500 requests and is exiting
    Oct 18 13:18:23 tracer dansguardian[14026]: Child has handled 500 requests and is exiting
    Oct 18 13:18:23 tracer dansguardian[30803]: Child has handled 500 requests and is exiting
    Oct 18 13:18:23 tracer dansguardian[5234]: Child has handled 500 requests and is exiting
    Oct 18 13:18:24 tracer dansguardian[30672]: Child has handled 500 requests and is exiting
    Oct 18 13:18:24 tracer dansguardian[18066]: Child has handled 500 requests and is exiting
    Oct 18 13:18:24 tracer dansguardian[2741]: Child has handled 500 requests and is exiting
    Oct 18 13:18:24 tracer dansguardian[11962]: Child has handled 500 requests and is exiting
    Oct 18 13:18:24 tracer dansguardian[28596]: Child has handled 500 requests and is exiting
    Oct 18 13:18:24 tracer dansguardian[14064]: Child has handled 500 requests and is exiting
    Oct 18 13:18:24 tracer dansguardian[23530]: Child has handled 500 requests and is exiting
    Oct 18 13:18:24 tracer dansguardian[20586]: Child has handled 500 requests and is exiting
    Oct 18 13:18:24 tracer dansguardian[16692]: Child has handled 500 requests and is exiting
    Oct 18 13:18:24 tracer dansguardian[31794]: Child has handled 500 requests and is exiting
    Oct 18 13:18:24 tracer dansguardian[2215]: Child has handled 500 requests and is exiting
    Oct 18 13:18:24 tracer dansguardian[2153]: Child has handled 500 requests and is exiting
    Oct 18 13:18:24 tracer dansguardian[9158]: Child has handled 500 requests and is exiting
    Oct 18 13:18:24 tracer dansguardian[7120]: Child has handled 500 requests and is exiting
    Oct 18 13:18:25 tracer dansguardian[9507]: Child has handled 500 requests and is exiting
    Oct 18 13:18:25 tracer dansguardian[16550]: Child has handled 500 requests and is exiting
    Oct 18 13:18:25 tracer dansguardian[7744]: Child has handled 500 requests and is exiting
    Oct 18 13:18:25 tracer dansguardian[22692]: Child has handled 500 requests and is exiting
    Oct 18 13:18:25 tracer dansguardian[30832]: Child has handled 500 requests and is exiting
    Oct 18 13:18:25 tracer dansguardian[14399]: Child has handled 500 requests and is exiting
    Oct 18 13:18:25 tracer dansguardian[25161]: Child has handled 500 requests and is exiting
    Oct 18 13:18:25 tracer dansguardian[20163]: Child has handled 500 requests and is exiting
    Oct 18 13:18:25 tracer dansguardian[9287]: Child has handled 500 requests and is exiting
    Oct 18 13:18:25 tracer dansguardian[14857]: Child has handled 500 requests and is exiting
    Oct 18 13:18:26 tracer dansguardian[24627]: Child has handled 500 requests and is exiting
    Oct 18 13:18:26 tracer dansguardian[10580]: Child has handled 500 requests and is exiting
    Oct 18 13:18:26 tracer dansguardian[7762]: Child has handled 500 requests and is exiting
    Oct 18 13:18:26 tracer dansguardian[20467]: Child has handled 500 requests and is exiting
    Oct 18 13:18:26 tracer dansguardian[29991]: Child has handled 500 requests and is exiting
    Oct 18 13:18:26 tracer dansguardian[27175]: Child has handled 500 requests and is exiting
    Oct 18 13:18:26 tracer dansguardian[15465]: Child has handled 500 requests and is exiting
    

    If you want I can try generating no traffic to see if DG effectively kills free children, but it looks like that is working properly. The problem seems to appear when spawning new processes -- for some reason numchildren seems to get stuck (ie, it doesn't get updated), and DG just keeps on spawning processes. I don't know what could be triggering this behaviour though... It's also strange that all the childs then exit with the message of 500 requests being handled, but perhaps that due to how they handle the kill signal.

    Thanks again for your help!

    点赞 评论 复制链接分享
  • weixin_39956036 weixin_39956036 4月前

    I'm now taking a look at the prefork() function, towards the end, and I saw the following (again, not really sure if I found something):

    
    #ifdef linux
    /* Epoll linux only */
            if ( sv[0] >= fds ) {
                    if (o.logchildprocs)
                        syslog(LOG_ERR, "Prefork - Child fd (%d) out of range (max %d)", sv[0], fds);   
                    close(sv[0]);
                    kill(child_pid,SIGTERM);
                    return(1);
            };
    #else
            if ((child_slot = getchildslot()) >= 0) {
                    addchild(child_slot, sv[0], child_pid);
    
            };  
    #endif
    
    #ifdef linux
    /* Epoll linux only */
                addchild(sv[0], child_pid);
                e_ev.data.fd = sv[0];
                e_ev.events = EPOLLIN;
                if(epoll_ctl( epfd, EPOLL_CTL_ADD, sv[0], &e_ev )) {
                    #ifdef DGDEBUG
                        std::cout << "epoll_ctl errno:" << errno << " " << strerror(errno) << std::endl;
                    #endif
                        syslog(LOG_ERR, "%s","Error registering child fd in epoll");
                        return(1);
                }
    #endif
    

    Looking at that piece of code, it looks like the linux epoll version has some sort of "safeguard" when adding the child, checking that it doesn't exceeds the maximum amount of fds. On the other hand, this does not seem to exist for the non-epoll version.

    What would happen if, for some reason, a child_slot was NOT found? The DG child would NOT be added to the control structures, numchildren would NOT be incremented, BUT the process child in the OS would continue existing, as no one killed it. In any case, I woulnd't know under what scenarios a child_slot could not be found, but I guess it may be there for a reason...

    点赞 评论 复制链接分享
  • weixin_39528467 weixin_39528467 4月前

    Yes there is a control only for Epoll, there is just a check - DG can create a fork or not - if (child_pid == -1)

    Please, can you try something like this ?

    
    if ((child_slot = getchildslot()) >= 0) {
        if ( sv[0] >= fds ) {
            close(sv[0]);
            kill(child_pid,SIGTERM);
            return(1);
        else {                                
            addchild(child_slot, sv[0], child_pid);
        {
    };  
    
    点赞 评论 复制链接分享
  • weixin_39956036 weixin_39956036 4月前

    Hi,

    Wouldn't that actually be the other way around, like this?

    
                    if ((child_slot = getchildslot()) >= 0) {
                                    if (o.logchildprocs) {
                                            syslog(LOG_ERR, "Adding child to slot %d (pid %d)", child_slot, child_pid);
                                    }
                                    addchild(child_slot, sv[0], child_pid);
                    }
                    else {
                                    if (o.logchildprocs) {
                                            syslog(LOG_ERR, "Prefork - Child fd (%d) out of range (max %d)", sv[0], o.max_children);
                                    }
                                    close(sv[0]);
                                    kill(child_pid,SIGTERM);
                                    return(1);
                    }
    

    I've added some syslog calls as well.

    Thanks again!

    点赞 评论 复制链接分享
  • weixin_39528467 weixin_39528467 4月前

    Maybe, but in this case there is not control like Epoll ( sv[0] >= fds )

    But like we are in unusual behaviour, I think it need some tests with fine changes

    点赞 评论 复制链接分享
  • weixin_39956036 weixin_39956036 4月前

    Right, but I mean, in your message you told me to configure the if line like this:

    
     if ((child_slot = getchildslot()) >= 0) {
    

    When it should actually be:

    
     if ((child_slot = getchildslot()) < 0) {
    

    I actually used your line, but inverted the statements below. Is that OK?

    Thanks!

    点赞 评论 复制链接分享
  • weixin_39528467 weixin_39528467 4月前

    Oh yes. Ok

    点赞 评论 复制链接分享
  • weixin_39956036 weixin_39956036 4月前

    Ok, I've just patched the file and I'm now running the modified version to see what happens...

    One more thing though, is there a particular reason semicolons (;) are added to these "if" statements at the end? For example:

    
            if ((child_slot = getchildslot()) >= 0) {
                    addchild(child_slot, sv[0], child_pid);
    
            };  
    

    I think there's no need for them...

    Thanks!

    点赞 评论 复制链接分享
  • weixin_39956036 weixin_39956036 4月前

    Well, I've just encountered the error, and it does seem like it's not finding any child slot. Effectively, the process is killed after this happens, so I'm not getting the process table filled up. Here's the syslog output:

    
    Oct 21 14:27:59 tracer dansguardian[22658]: added child: fd: 60 pid: 19349
    Oct 21 14:28:00 tracer dansguardian[22658]: numchildren: 57, o.max_children: 120
    Oct 21 14:28:00 tracer dansguardian[22658]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 21 14:28:00 tracer dansguardian[22658]: Adding child to slot 119 (pid 8250)
    Oct 21 14:28:00 tracer dansguardian[22658]: added child: fd: 61 pid: 8250
    Oct 21 14:28:00 tracer dansguardian[22658]: Prefork - Child fd (62) out of range (max 120)
    Oct 21 14:28:00 tracer dansguardian[22658]: numchildren: 58, o.max_children: 120
    Oct 21 14:28:00 tracer dansguardian[22658]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 21 14:28:00 tracer dansguardian[22658]: Prefork - Child fd (62) out of range (max 120)
    Oct 21 14:28:00 tracer dansguardian[22658]: numchildren: 58, o.max_children: 120
    Oct 21 14:28:00 tracer dansguardian[22658]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 21 14:28:00 tracer dansguardian[22658]: Prefork - Child fd (62) out of range (max 120)
    Oct 21 14:28:00 tracer dansguardian[20415]: Child has handled 500 requests and is exiting
    Oct 21 14:28:00 tracer dansguardian[22658]: No free children from getfreechild(): numchildren = 58, busychildren = 55, waitingfor = 0
    Oct 21 14:28:00 tracer dansguardian[22658]: numchildren: 58, o.max_children: 120
    Oct 21 14:28:00 tracer dansguardian[22658]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 21 14:28:00 tracer dansguardian[22658]: Prefork - Child fd (62) out of range (max 120)
    Oct 21 14:28:00 tracer dansguardian[22658]: numchildren: 58, o.max_children: 120
    Oct 21 14:28:00 tracer dansguardian[22658]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 21 14:28:00 tracer dansguardian[22658]: Prefork - Child fd (62) out of range (max 120)
    Oct 21 14:28:00 tracer dansguardian[22658]: No free children from getfreechild(): numchildren = 58, busychildren = 55, waitingfor = 0
    Oct 21 14:28:00 tracer dansguardian[22658]: numchildren: 58, o.max_children: 120
    Oct 21 14:28:00 tracer dansguardian[22658]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 21 14:28:00 tracer dansguardian[22658]: Prefork - Child fd (62) out of range (max 120)
    Oct 21 14:28:00 tracer dansguardian[15863]: Child has handled 500 requests and is exiting
    Oct 21 14:28:00 tracer dansguardian[22658]: numchildren: 58, o.max_children: 120
    Oct 21 14:28:00 tracer dansguardian[22658]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 21 14:28:00 tracer dansguardian[22658]: Prefork - Child fd (62) out of range (max 120)
    Oct 21 14:28:00 tracer dansguardian[22658]: No free children from getfreechild(): numchildren = 58, busychildren = 55, waitingfor = 0
    Oct 21 14:28:00 tracer dansguardian[22658]: numchildren: 58, o.max_children: 120
    Oct 21 14:28:00 tracer dansguardian[22658]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 21 14:28:00 tracer dansguardian[22658]: Prefork - Child fd (62) out of range (max 120)
    Oct 21 14:28:00 tracer dansguardian[22658]: No free children from getfreechild(): numchildren = 58, busychildren = 55, waitingfor = 0
    Oct 21 14:28:00 tracer dansguardian[22658]: numchildren: 58, o.max_children: 120
    Oct 21 14:28:00 tracer dansguardian[22658]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 21 14:28:00 tracer dansguardian[22658]: Prefork - Child fd (62) out of range (max 120)
    Oct 21 14:28:00 tracer dansguardian[22658]: No free children from getfreechild(): numchildren = 58, busychildren = 55, waitingfor = 0
    Oct 21 14:28:00 tracer dansguardian[22658]: numchildren: 58, o.max_children: 120
    Oct 21 14:28:00 tracer dansguardian[22658]: Fewer than 4 free children - Spawning 6 process(es)
    

    This goes on for a while, constantly hitting the logs, until it seems to normalize somehow:

    
    Oct 21 14:56:10 tracer dansguardian[22658]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 21 14:56:10 tracer dansguardian[22658]: Prefork - Child fd (56) out of range (max 120)
    Oct 21 14:56:10 tracer dansguardian[22658]: numchildren: 52, o.max_children: 120
    Oct 21 14:56:10 tracer dansguardian[22658]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 21 14:56:10 tracer dansguardian[22658]: Prefork - Child fd (56) out of range (max 120)
    Oct 21 14:56:10 tracer dansguardian[14869]: Child has handled 500 requests and is exiting
    Oct 21 14:56:10 tracer dansguardian[22658]: numchildren: 52, o.max_children: 120
    Oct 21 14:56:10 tracer dansguardian[22658]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 21 14:56:10 tracer dansguardian[22658]: Prefork - Child fd (56) out of range (max 120)
    Oct 21 14:56:10 tracer dansguardian[22658]: numchildren: 52, o.max_children: 120
    Oct 21 14:56:10 tracer dansguardian[22658]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 21 14:56:10 tracer dansguardian[22658]: Prefork - Child fd (56) out of range (max 120)
    Oct 21 14:56:10 tracer dansguardian[22658]: numchildren: 52, o.max_children: 120
    Oct 21 14:56:10 tracer dansguardian[22658]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 21 14:56:10 tracer dansguardian[22658]: Prefork - Child fd (56) out of range (max 120)
    Oct 21 14:56:10 tracer dansguardian[12873]: Child has handled 500 requests and is exiting
    Oct 21 14:56:11 tracer dansguardian[22658]: numchildren: 52, o.max_children: 120
    Oct 21 14:56:11 tracer dansguardian[22658]: Fewer than 4 free children - Spawning 6 process(es)
    Oct 21 14:56:11 tracer dansguardian[22658]: Prefork - Child fd (56) out of range (max 120)
    Oct 21 14:56:11 tracer dansguardian[20545]: Child has handled 500 requests and is exiting
    Oct 21 14:56:41 tracer dansguardian[17306]: Child has handled 500 requests and is exiting
    Oct 21 14:58:15 tracer dansguardian[23292]: Child has handled 500 requests and is exiting
    Oct 21 14:58:31 tracer dansguardian[28232]: Child has handled 500 requests and is exiting
    Oct 21 14:59:09 tracer dansguardian[22658]: test cullchildren
    Oct 21 14:59:09 tracer dansguardian[22658]: closed 113
    Oct 21 14:59:09 tracer dansguardian[22658]: numchildren now: 48
    Oct 21 14:59:09 tracer dansguardian[22658]: deleted child: fd: 113 pid: 21835
    Oct 21 14:59:09 tracer dansguardian[22658]: closed 112
    Oct 21 14:59:09 tracer dansguardian[22658]: numchildren now: 47
    Oct 21 14:59:09 tracer dansguardian[22658]: deleted child: fd: 112 pid: 16051
    Oct 21 14:59:09 tracer dansguardian[22658]: closed 111
    

    Shortly after I killed the dansguardian process and reverted to the official release.

    So, the question is why is this behaviour is being triggered at that point... Also, I keep experiencing "stalling" problems at some points... By the way, I upgraded the hardware to a somewhat faster AMD 64 X2 with 2GB of RAM this last saturday.

    Thanks!

    点赞 评论 复制链接分享
  • weixin_39528467 weixin_39528467 4月前

    Very interesting, but unfortunately for the moment I have no idea for why this is happening, but if you confirm there are no spawning processes beyond the maxchildren limit at least we have this like temporary fix

    About "stalling" are you sure this is no present with the official release ? Can you post your DG values (timeout, max, min, etc) It surprises me that you have some waitingfor = 0

    I guess perhaps you can increase x2 (No problem with AMD 64 X2 with 2GB of RAM)

    maxchildren maxagechildren maxsparechildren minsparechildren minchildren

    点赞 评论 复制链接分享

相关推荐