[squid-users] NTLM Authentication

From: John Sayce <jsayce_at_asdlighting.com>
Date: Mon, 14 Nov 2011 14:50:02 +0000

I have squid configured and working fine with ntlm authentication, however about once a week access to the throughput will slow and I can be presented with access denied messages. Restarting squid instantly fixes the problem. My configuration is relatively simple as bellow. I don't have a large user base. There's only 60 users and the problem is instantly gone upon restarting squid which suggests to me that it's not simply be a problem of load as the log would suggest. I wondered if it was a single computer or application causing the issue but I'm not sure how to find out.

http_port 8080

auth_param ntlm program c:/squid/libexec/mswin_ntlm_auth.exe
auth_param ntlm children 30
external_acl_type win_domain_group children=30 ttl=120 %LOGIN c:/squid/libexec/mswin_check_lm_group.exe -G

acl all src 0.0.0.0/0.0.0.0
acl nocache dstdomain "C:\squid\etc\nocache_domains.acl"
acl unauthenticatednet src "C:\squid\etc\unrestrictedaddresses.acl"
acl blocked src "C:\squid\etc\restrictedaddresses.acl"
acl inetallowgroup external win_domain_group InternetAllow
acl inetrestrictgroup external win_domain_group InternetRestricted
acl localhost src 127.0.0.1/255.255.255.255
acl localnet proxy_auth REQUIRED src 192.168.0.0/255.255.255.0
acl denied_domains dstdomain "C:\squid\etc\denied_domains.acl"
acl allowed_domains dstdomain "C:\squid\etc\allowed_domains.acl"
acl allowed_addresses dst "C:\squid\etc\allowed_addresses.acl"
acl manager proto cache_object

always_direct allow nocache
http_access allow manager monitor
http_access deny localhost
http_access deny blocked
http_access allow unauthenticatednet
http_access allow allowed_domains
http_access allow allowed_addresses
http_access deny inetrestrictgroup denied_domains
http_access allow inetrestrictgroup
http_access allow inetallowgroup
http_access deny all

cache_mem 500 MB
maximum_object_size_in_memory 1 MB
cache_dir ufs c:/squid/var/cache 7000 16 512

access_log C:\squid\var\logs\access.log squid.

My cache log would seem to suggest that it's related to the ntlm helper processes. Eg

/mswin_check_lm_group.exe Can't find DC for local domain 'asd'
2011/11/14 11:31:57| storeUfsCreate: Failed to create c:/squid/var/cache/01/C2/00058467 ((13) Permission denied)
/mswin_check_lm_group.exe Can't find DC for local domain 'asd'
/mswin_check_lm_group.exe Can't find DC for local domain 'asd'
2011/11/14 12:15:40| clientTryParseRequest: FD 361 (192.168.0.252:2504) Invalid Request
2011/11/14 12:26:41| sslWriteClient: FD 1062: write failure: (10054) WSAECONNRESET, Connection reset by peer..
2011/11/14 12:37:12| sslReadClient: FD 370: read failure: (10053) WSAECONNABORTED, Software caused connection abort.
2011/11/14 12:41:31| WARNING: All ntlmauthenticator processes are busy.
2011/11/14 12:41:31| WARNING: up to 34 pending requests queued
/mswin_check_lm_group.exe Can't find DC for local domain 'asd'
/mswin_check_lm_group.exe Can't find DC for local domain 'asd'
/mswin_check_lm_group.exe Can't find DC for local domain 'asd'
2011/11/14 12:45:11| WARNING: All ntlmauthenticator processes are busy.
2011/11/14 12:45:11| WARNING: up to 30 pending requests queued
2011/11/14 12:45:11| Consider increasing the number of ntlmauthenticator processes to at least 60 in your config file.
2011/11/14 12:45:41| WARNING: All ntlmauthenticator processes are busy.
2011/11/14 12:45:41| WARNING: up to 36 pending requests queued
2011/11/14 12:45:41| Consider increasing the number of ntlmauthenticator processes to at least 66 in your config file.
2011/11/14 12:46:11| WARNING: All ntlmauthenticator processes are busy.
2011/11/14 12:46:11| WARNING: up to 42 pending requests queued
2011/11/14 12:46:11| Consider increasing the number of ntlmauthenticator processes to at least 72 in your config file.
/mswin_check_lm_group.exe Can't find DC for local domain 'asd'
/mswin_check_lm_group.exe Can't find DC for local domain 'asd'
/mswin_check_lm_group.exe Can't find DC for local domain 'asd'
/mswin_check_lm_group.exe Can't find DC for local domain 'asd'
/mswin_check_lm_group.exe Can't find DC for local domain 'asd'
2011/11/14 12:47:06| WARNING: All ntlmauthenticator processes are busy.
2011/11/14 12:47:06| WARNING: up to 55 pending requests queued
2011/11/14 12:47:06| Consider increasing the number of ntlmauthenticator processes to at least 85 in your config file.
/mswin_check_lm_group.exe Can't find DC for local domain 'asd'
/mswin_check_lm_group.exe Can't find DC for local domain 'asd'
2011/11/14 12:52:25| sslReadClient: FD 1062: read failure: (10053) WSAECONNABORTED, Software caused connection abort.
2011/11/14 13:13:51| clientTryParseRequest: FD 907 (192.168.0.148:1812) Invalid Request
2011/11/14 13:13:55| clientTryParseRequest: FD 907 (192.168.0.148:1831) Invalid Request
2011/11/14 13:16:50| clientTryParseRequest: FD 1454 (192.168.0.148:1874) Invalid Request
2011/11/14 13:16:53| clientTryParseRequest: FD 1440 (192.168.0.148:1867) Invalid Request
2011/11/14 13:21:07| clientTryParseRequest: FD 1254 (192.168.0.148:1927) Invalid Request
2011/11/14 13:21:10| clientTryParseRequest: FD 763 (192.168.0.148:1919) Invalid Request
2011/11/14 13:22:30| clientTryParseRequest: FD 621 (192.168.0.148:1958) Invalid Request
2011/11/14 13:22:34| clientTryParseRequest: FD 894 (192.168.0.148:1949) Invalid Request
2011/11/14 13:41:35| clientTryParseRequest: FD 1019 (192.168.0.148:2331) Invalid Request
2011/11/14 13:41:35| clientTryParseRequest: FD 1004 (192.168.0.148:2360) Invalid Request
/mswin_check_lm_group.exe Can't find DC for local domain 'asd'
2011/11/14 13:51:23| CACHEMGR: <unknown>@192.168.0.14 requesting 'menu'
2011/11/14 13:51:27| CACHEMGR: <unknown>@192.168.0.14 requesting 'events'
2011/11/14 13:51:32| CACHEMGR: <unknown>@192.168.0.14 requesting 'ipcache'
2011/11/14 13:51:43| CACHEMGR: <unknown>@192.168.0.14 requesting 'fqdncache'
2011/11/14 13:51:50| CACHEMGR: <unknown>@192.168.0.14 requesting 'ntlmauthenticator'
2011/11/14 13:51:59| CACHEMGR: <unknown>@192.168.0.14 requesting 'http_headers'
2011/11/14 13:52:05| CACHEMGR: <unknown>@192.168.0.14 requesting 'info'
/mswin_check_lm_group.exe Can't find DC for local domain 'asd'
/mswin_check_lm_group.exe Can't find DC for local domain 'asd'
/mswin_check_lm_group.exe Can't find DC for local domain 'asd'
2011/11/14 13:52:26| CACHEMGR: <unknown>@192.168.0.14 requesting 'server_list'
2011/11/14 13:52:35| CACHEMGR: <unknown>@192.168.0.14 requesting 'pending_objects'
2011/11/14 13:54:38| sslReadClient: FD 454: read failure: (10053) WSAECONNABORTED, Software caused connection abort.
2011/11/14 13:54:38| sslReadClient: FD 885: read failure: (10053) WSAECONNABORTED, Software caused connection abort.
2011/11/14 13:54:38| sslReadClient: FD 896: read failure: (10053) WSAECONNABORTED, Software caused connection abort.
2011/11/14 13:54:38| sslReadClient: FD 977: read failure: (10053) WSAECONNABORTED, Software caused connection abort.
2011/11/14 13:54:38| sslReadClient: FD 1075: read failure: (10053) WSAECONNABORTED, Software caused connection abort.
2011/11/14 13:54:38| sslReadClient: FD 1129: read failure: (10053) WSAECONNABORTED, Software caused connection abort.
2011/11/14 13:54:38| sslReadClient: FD 1132: read failure: (10053) WSAECONNABORTED, Software caused connection abort.
2011/11/14 13:54:38| sslReadClient: FD 1136: read failure: (10053) WSAECONNABORTED, Software caused connection abort.
2011/11/14 13:54:38| sslReadClient: FD 1141: read failure: (10053) WSAECONNABORTED, Software caused connection abort.
2011/11/14 13:54:38| sslReadClient: FD 1142: read failure: (10053) WSAECONNABORTED, Software caused connection abort.
2011/11/14 13:54:38| sslReadClient: FD 1173: read failure: (10053) WSAECONNABORTED, Software caused connection abort.
2011/11/14 13:54:38| sslReadClient: FD 1176: read failure: (10053) WSAECONNABORTED, Software caused connection abort.
/mswin_check_lm_group.exe Can't find DC for local domain 'asd'
/mswin_check_lm_group.exe Can't find DC for local domain 'asd'
/mswin_check_lm_group.exe Can't find DC for local domain 'asd'
/mswin_check_lm_group.exe Can't find DC for local domain 'asd'
/mswin_check_lm_group.exe Can't find DC for local domain 'asd'
/mswin_check_lm_group.exe Can't find DC for local domain 'asd'
/mswin_check_lm_group.exe Can't find DC for local domain 'asd'
/mswin_check_lm_group.exe Can't find DC for local domain 'asd'
/mswin_check_lm_group.exe Can't find DC for local domain 'asd'

And the cache authentication statistics seem to sugget the same

# FD PID # Requests Flags Time Offset Request
1 7 3204 39410 B R 11.297 0 KK TlRMTVNTUAADAAAAGAAYAGIAAAAYABgAegAAAAYABgBIAAAACgAKAE4AAAAKAAoAWAAAAAAAAACSAAAABYKIogUBKAoAAAAPQQBTAEQAYwBkAHUAdAB5AEMARABVAFQAWQBFHC2/aZo/+gAAAAAAAAAAAAAAAAAAAABsa0q3oRwyDJx4h7JJa4x2NSj6zv+154c=\n
2 10 216 13610 B R 11.281 0 KK TlRMTVNTUAADAAAAGAAYAGIAAAAYABgAegAAAAYABgBIAAAACgAKAE4AAAAKAAoAWAAAAAAAAACSAAAABYKIogUBKAoAAAAPQQBTAEQAYwBkAHUAdAB5AEMARABVAFQAWQB5fpurkDCGsgAAAAAAAAAAAAAAAAAAAABmm++jCp3ZZTwnwbbLXOChE19qEhj7GPU=\n
3 14 1124 7279 B R 11.281 0 KK TlRMTVNTUAADAAAAGAAYAGIAAAAYABgAegAAAAYABgBIAAAACgAKAE4AAAAKAAoAWAAAAAAAAACSAAAABYKIogUBKAoAAAAPQQBTAEQAYwBkAHUAdAB5AEMARABVAFQAWQDjyrQ1V56E6QAAAAAAAAAAAAAAAAAAAABTnsJ8U5vk9Bv05B3wpsMdv08lQZuUHDQ=\n
4 18 204 4915 B R 11.281 0 KK TlRMTVNTUAADAAAAGAAYAGIAAAAYABgAegAAAAYABgBIAAAACgAKAE4AAAAKAAoAWAAAAAAAAACSAAAABYKIogUBKAoAAAAPQQBTAEQAYwBkAHUAdAB5AEMARABVAFQAWQCy/I80NmbX8wAAAAAAAAAAAAAAAAAAAAB7osVkiKP/y2MwtsKQjHSb/p1dqu0mXSE=\n
5 22 2204 3363 B R 8.500 0 KK TlRMTVNTUAADAAAAGAAYAHgAAAAYABgAkAAAAAYABgBIAAAAEAAQAE4AAAAaABoAXgAAAAAAAACoAAAABYKIogUBKAoAAAAPQQBTAEQAZABjAGgAYQBwAG0AYQBuAEEARAAtAEQALQBEAEMASABBAFAATQBBAE4A9TxKkYJ2NT4AAAAAAAAAAAAAAAAAAAAA9HA9v7TRrIbxZEsELl5CKwJPRL2NkhBB\n
6 26 1348 2353 B R 25.157 0 KK TlRMTVNTUAADAAAAGAAYAHwAAAAYABgAlAAAAAYABgBYAAAADgAOAF4AAAAQABAAbAAAAAAAAACsAAAABYKIogYBsB0AAAAPUZKAUw15tyRt85EJs4ds0kEAUwBEAG0AbwBhAGsAbABlAHkATQBBAFIASwBPAC0AUABDAB6mk+ThrF/SAAAAAAAAAAAAAAAAAAAAAJZp8l4RFCai8HhQnbBMbSKJy6rEVxVrmg==\n
7 30 2412 1730 B R 23.266 0 KK TlRMTVNTUAADAAAAGAAYAIwAAABGAUYBpAAAAAYABgBYAAAAFAAUAF4AAAAaABoAcgAAAAAAAADqAQAABYKIogYBsB0AAAAPEx8HE9ghzLxw8YM492xFY0EAUwBEAHIAYQB5AHMAdABlAHcAYQByAHQAUwBMAC0ATAAtAFIAUwBUAEUAVwBBAFIAVAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAopX4fh1/JVMNZ0jonxv6tAQEAAAAAAAAZwPca1aLMAR6hQgDHC3rAAAAAAAIABgBBAFMARAABABYASQBUAC0AUwAtAFMAUQBVAEkARAAxAAQAEgBhAHMAZAAuAGwAbwBjAGEAbAADACoASQBUAC0AUwAtAFMAUQBVAEkARAAxAC4AYQBzAGQALgBsAG8AYwBhAGwABQASAGEAcwBkAC4AbABvAGMAYQBsAAgAMAAwAAAAAAAAAAAAAAAAMAAA62p3iYcwRL/HfxNTKswtnFEfM725J2cpYkavWW7bK98KABAAAAAAAAAAAAAAAAAAAAAAAAkASABIAFQAVABQAC8AcwBhAGYAZQBiAHIAbwB3AHMAaQBuAGcALgBjAGwAaQBlAG4AdABzAC4AZwBvAG8AZwBsAGUALgBjAG8AbQAAAAAAAAAAAA==\n
8 34 2964 1300 B R 22.985 0 KK TlRMTVNTUAADAAAAGAAYAGwAAAAYABgAhAAAAAYABgBIAAAAEAAQAE4AAAAOAA4AXgAAAAAAAACcAAAABYKIogUBKAoAAAAPQQBTAEQAcABiAHIAYQBtAGEAbABsAFIAUgBJAEwARQBZADIATZjadwxp5tQAAAAAAAAAAAAAAAAAAAAASYd9/R8y5Tob3P//U8SEiryla9F3AuZb\n
9 38 3652 1058 B R 22.266 0 KK TlRMTVNTUAADAAAAGAAYAHwAAAAYABgAlAAAAAYABgBYAAAADgAOAF4AAAAQABAAbAAAAAAAAACsAAAABYKIogYBsB0AAAAPPF+U/YqG+gOlBRTXq/IUIUEAUwBEAG0AbwBhAGsAbABlAHkATQBBAFIASwBPAC0AUABDAN5IHWAIqk+YAAAAAAAAAAAAAAAAAAAAABevFlq1IhxtUm4zjn6ilSDN5fS53f7atw==\n
10 42 2200 891 B R 20.579 0 KK TlRMTVNTUAADAAAAGAAYAHgAAAAYABgAkAAAAAYABgBIAAAAEAAQAE4AAAAaABoAXgAAAAAAAACoAAAABYKIogUBKAoAAAAPQQBTAEQAZABjAGgAYQBwAG0AYQBuAEEARAAtAEQALQBEAEMASABBAFAATQBBAE4AE5MB2EGlPgoAAAAAAAAAAAAAAAAAAAAA06USMNi71MJUeIGgpj8Y45bSTt4c5DRk\n
11 46 3364 762 B R 16.016 0 KK TlRMTVNTUAADAAAAGAAYAGoAAAAYABgAggAAAAYABgBIAAAAEgASAE4AAAAKAAoAYAAAAAAAAACaAAAABYKIogUBKAoAAAAPQQBTAEQAbQB0AGUAYQBzAGQAYQBsAGUARABFAEwATAAyAAlLJQN4/8FyAAAAAAAAAAAAAAAAAAAAALR8q9dPWCz468szg0ij8ssVjBQBmiHyjw==\n
12 50 1876 656 B R 15.829 0 KK TlRMTVNTUAADAAAAGAAYAEAAAAAYABgAWAAAAAMAAwBwAAAAEAAQAHMAAAAKAAoAgwAAAAAAAAAAAAAABoKJAvnEl5trx4H7AAAAAAAAAAAAAAAAAAAAAJcpmgeNuFpm1//rUdZ7RbT6sUAKAAyvd2FzZG5hZ2lvc2NoZWNrcHJveHlJVC1TLVNIRUVO\n
13 54 2704 530 B R 14.969 0 KK TlRMTVNTUAADAAAAGAAYAGYAAAAYABgAfgAAAAYABgBIAAAADAAMAE4AAAAMAAwAWgAAAAAAAACWAAAABYKIogUBKAoAAAAPQQBTAEQAYQBiAGEAdAB0AHkAQQBCAEEAVABUAFkASOSjcHhGApYAAAAAAAAAAAAAAAAAAAAAIsubNiwyVHlZqGHG+QJvxqIO1ULBPlxh\n
14 58 1060 515 B R 14.188 0 KK TlRMTVNTUAADAAAAGAAYAGAAAAAYABgAeAAAAAYABgBIAAAADAAMAE4AAAAGAAYAWgAAAAAAAACQAAAABYKIogUBKAoAAAAPQQBTAEQAZAByAGkAbABlAHkAVABDADEAAEdK3MRR+KEAAAAAAAAAAAAAAAAAAAAAxcqMb9xPGOpeDs4orOHjEqewQS16Hvv+\n
15 62 2120 427 B R 13.657 0 KK TlRMTVNTUAADAAAAGAAYAGAAAAAYABgAeAAAAAYABgBIAAAADAAMAE4AAAAGAAYAWgAAAAAAAACQAAAABYKIogUBKAoAAAAPQQBTAEQAZAByAGkAbABlAHkAVABDADEAzr0FNa2gWNwAAAAAAAAAAAAAAAAAAAAA5EBHL3QEr9B2Vdca+JXQML8lqxUeNtWM\n
16 66 3156 379 B R 11.344 0 KK TlRMTVNTUAADAAAAGAAYAGAAAAAYABgAeAAAAAYABgBIAAAADAAMAE4AAAAGAAYAWgAAAAAAAACQAAAABYKIogUBKAoAAAAPQQBTAEQAZAByAGkAbABlAHkAVABDADEAeO04tPjHJMcAAAAAAAAAAAAAAAAAAAAABoOtvGgkCAOA5b1yN2QgcLGy1GbF4Un7\n
17 70 1536 354 R 0.031 0 (none)
18 74 588 313 B R 1.062 0 KK TlRMTVNTUAADAAAAGAAYAGIAAAAYABgAegAAAAYABgBIAAAACgAKAE4AAAAKAAoAWAAAAAAAAACSAAAABYKIogUBKAoAAAAPQQBTAEQAcAByAHkAYQBuAEkAVABNAEEATgBSxn2OwQzZcgAAAAAAAAAAAAAAAAAAAACFZr0y7LOdVFHVxrwOQYX2de4LdsCaeSU=\n
19 78 2556 255 B R 0.094 0 KK TlRMTVNTUAADAAAAGAAYAGAAAAAYABgAeAAAAAYABgBIAAAADAAMAE4AAAAGAAYAWgAAAAAAAACQAAAABYKIogUBKAoAAAAPQQBTAEQAZAByAGkAbABlAHkAVABDADEAtntPAUsUb/IAAAAAAAAAAAAAAAAAAAAAqplCMtJqcK4oIRjNEfTOS60s2qFTBEDJ\n
20 82 3428 233 34.970 0 (none)
21 86 1604 222 29.486 0 (none)
22 90 3672 207 29.032 0 (none)
23 94 3276 179 28.267 0 (none)
24 98 1176 148 25.204 0 (none)
25 102 3584 143 18.531 0 (none)
26 106 3948 149 16.344 0 (none)
27 110 288 128 28.564 0 (none)
28 114 2180 102 26.892 0 (none)
29 118 3580 105 26.892 0 (none)
30 122 3268 93 26.876 0 (none)

Regards John

______________________________________________________________________
This email has been scanned by the MessageLabs Email Security System.
For more information please visit http://www.messagelabs.com/email
______________________________________________________________________
Received on Mon Nov 14 2011 - 14:50:15 MST

This archive was generated by hypermail 2.2.0 : Tue Nov 15 2011 - 12:00:03 MST