[squid-users] squid 5.2: ntlm_fake_auth refuse to valid credentials
David Touzeau
david at articatech.com
Thu Nov 11 01:12:04 UTC 2021
Hi,
i would like to use ntlm_fake_auth but it seems Squid refuse to switch
to authenticated user and return a 407 to the browser and squid never
accept credentials.
What i missing ?
Configuration seems simple:
auth_param ntlm program /lib/squid3/ntlm_fake_auth -v
auth_param ntlm children 20 startup=5 idle=1 concurrency=0 queue-size=80
on-persistent-overload=ERR
acl AUTHENTICATED proxy_auth REQUIRED
http_access deny !AUTHENTICATED
Here the debug mode;
2021/11/11 01:36:16.862 kid1| 14,3| ipcache.cc(614)
ipcache_gethostbyname: ipcache_gethostbyname: 'www.squid-cache.org', flags=1
2021/11/11 01:36:16.862 kid1| 28,3| Ip.cc(538) match: aclIpMatchIp:
'212.199.163.170' NOT found
2021/11/11 01:36:16.862 kid1| 28,3| Ip.cc(538) match: aclIpMatchIp:
'196.200.160.70' NOT found
2021/11/11 01:36:16.862 kid1| 28,3| Acl.cc(151) matches: checked:
NetworksBlackLists = 0
2021/11/11 01:36:16.862 kid1| 28,3| Acl.cc(151) matches: checked:
http_access#29 = 0
2021/11/11 01:36:16.862 kid1| 28,5| Checklist.cc(397) bannedAction:
Action 'DENIED/0' is not banned
2021/11/11 01:36:16.862 kid1| 28,5| Acl.cc(124) matches: checking
http_access#30
2021/11/11 01:36:16.862 kid1| 28,5| Acl.cc(124) matches: checking
NormalPorts
2021/11/11 01:36:16.862 kid1| 24,7| SBuf.cc(212) append: from c-string
to id SBuf1021843
2021/11/11 01:36:16.862 kid1| 24,7| SBuf.cc(160) rawSpace: reserving 13
for SBuf1021843
2021/11/11 01:36:16.862 kid1| 24,7| SBuf.cc(865) reAlloc: SBuf1021843
new store capacity: 40
2021/11/11 01:36:16.862 kid1| 28,3| StringData.cc(33) match:
aclMatchStringList: checking 'MyPortNameID1'
2021/11/11 01:36:16.862 kid1| 28,3| StringData.cc(36) match:
aclMatchStringList: 'MyPortNameID1' found
2021/11/11 01:36:16.862 kid1| 28,3| Acl.cc(151) matches: checked:
NormalPorts = 1
2021/11/11 01:36:16.862 kid1| 28,5| Acl.cc(124) matches: checking
!AUTHENTICATED
2021/11/11 01:36:16.862 kid1| 28,5| Acl.cc(124) matches: checking
AUTHENTICATED
2021/11/11 01:36:16.862 kid1| 29,4| UserRequest.cc(354) authenticate: No
connection authentication type
2021/11/11 01:36:16.862 kid1| 29,5| User.cc(36) User: Initialised
auth_user '0x5570e8c4d240'.
2021/11/11 01:36:16.862 kid1| 29,5| UserRequest.cc(99) UserRequest:
initialised request 0x5570e8cdacf0
2021/11/11 01:36:16.862 kid1| 24,7| SBuf.cc(212) append: from c-string
to id SBuf1021846
2021/11/11 01:36:16.862 kid1| 24,7| SBuf.cc(160) rawSpace: reserving 61
for SBuf1021846
2021/11/11 01:36:16.862 kid1| 24,7| SBuf.cc(865) reAlloc: SBuf1021846
new store capacity: 128
2021/11/11 01:36:16.862 kid1| 29,5| UserRequest.cc(77) valid: Validated.
Auth::UserRequest '0x5570e8cdacf0'.
2021/11/11 01:36:16.862 kid1| 29,5| UserRequest.cc(77) valid: Validated.
Auth::UserRequest '0x5570e8cdacf0'.
2021/11/11 01:36:16.862 kid1| 33,2| client_side.cc(507) setAuth: Adding
connection-auth to local=192.168.90.170:3128 remote=192.168.90.10:50746
FD 12 flags=1 from new NTLM handshake request
2021/11/11 01:36:16.862 kid1| 29,5| UserRequest.cc(77) valid: Validated.
Auth::UserRequest '0x5570e8cdacf0'.
2021/11/11 01:36:16.862 kid1| 28,3| AclProxyAuth.cc(131) checkForAsync:
checking password via authenticator
2021/11/11 01:36:16.862 kid1| 29,5| UserRequest.cc(77) valid: Validated.
Auth::UserRequest '0x5570e8cdacf0'.
2021/11/11 01:36:16.862 kid1| 84,5| helper.cc(1292)
StatefulGetFirstAvailable: StatefulGetFirstAvailable: Running servers 5
2021/11/11 01:36:16.862 kid1| 84,5| helper.cc(1309)
StatefulGetFirstAvailable: StatefulGetFirstAvailable: returning srv-Hlpr66
2021/11/11 01:36:16.862 kid1| 5,5| AsyncCall.cc(26) AsyncCall: The
AsyncCall helperStatefulDispatchWriteDone constructed,
this=0x5570e8c8f8e0 [call581993]
2021/11/11 01:36:16.862 kid1| 5,5| Write.cc(35) Write: local=[::]
remote=[::] FD 10 flags=1: sz 60: asynCall 0x5570e8c8f8e0*1
2021/11/11 01:36:16.862 kid1| 5,5| ModEpoll.cc(117) SetSelect: FD 10,
type=2, handler=1, client_data=0x7f9e5d8a75a8, timeout=0
2021/11/11 01:36:16.862 kid1| 84,5| helper.cc(1430)
helperStatefulDispatch: helperStatefulDispatch: Request sent to
ntlmauthenticator #Hlpr66, 60 bytes
2021/11/11 01:36:16.862 kid1| 28,4| Acl.cc(72) AuthenticateAcl:
returning 2 sending credentials to helper.
2021/11/11 01:36:16.862 kid1| 28,3| Acl.cc(151) matches: checked:
AUTHENTICATED = -1 async
2021/11/11 01:36:16.862 kid1| 28,3| Acl.cc(151) matches: checked:
!AUTHENTICATED = -1 async
2021/11/11 01:36:16.862 kid1| 28,3| Acl.cc(151) matches: checked:
http_access#30 = -1 async
2021/11/11 01:36:16.862 kid1| 28,3| Acl.cc(151) matches: checked:
http_access = -1 async
2021/11/11 01:36:16.862 kid1| 33,4| Server.cc(90) readSomeData:
local=192.168.90.170:3128 remote=192.168.90.10:50746 FD 12 flags=1:
reading request...
2021/11/11 01:36:16.862 kid1| 33,5| AsyncCall.cc(26) AsyncCall: The
AsyncCall Server::doClientRead constructed, this=0x5570e87cfd50 [call581994]
2021/11/11 01:36:16.862 kid1| 5,5| Read.cc(57) comm_read_base:
comm_read, queueing read for local=192.168.90.170:3128
remote=192.168.90.10:50746 FD 12 flags=1; asynCall 0x5570e87cfd50*1
2021/11/11 01:36:16.862 kid1| 5,5| ModEpoll.cc(117) SetSelect: FD 12,
type=1, handler=1, client_data=0x7f9e5d8a7678, timeout=0
2021/11/11 01:36:16.862 kid1| 33,5| AsyncJob.cc(154) callEnd:
Http1::Server status out: [ job17296]
2021/11/11 01:36:16.862 kid1| 33,5| AsyncCallQueue.cc(57) fireNext:
leaving Server::doClientRead(local=192.168.90.170:3128
remote=192.168.90.10:50746 FD 12 flags=1, data=0x5570e8c63468)
2021/11/11 01:36:16.862 kid1| 5,5| Write.cc(66) HandleWrite: local=[::]
remote=[::] FD 10 flags=1: off 0, sz 60.
2021/11/11 01:36:16.862 kid1| 5,5| Write.cc(108) HandleWrite: write()
returns 60
2021/11/11 01:36:16.862 kid1| 5,3| IoCallback.cc(116) finish: called for
local=[::] remote=[::] FD 10 flags=1 (0, 0)
2021/11/11 01:36:16.862 kid1| 5,5| AsyncCall.cc(93) ScheduleCall:
IoCallback.cc(135) will call helperStatefulDispatchWriteDone(local=[::]
remote=[::] FD 10 flags=1, data=0x5570e8731e08, size=60,
buf=0x5570e8d2c1a0) [call581993]
ntlm_fake_auth.cc(170): pid=4454 :2021/11/11 01:36:16.862 kid1| 5,5|
AsyncCallQueue.cc(55) fireNext: entering
helperStatefulDispatchWriteDone(local=[::] remote=[::] FD 10 flags=1,
data=0x5570e8731e08, size=60, buf=0x5570e8d2c1a0)
Got 'YR' from Squid with data:
2021/11/11 01:36:16.862 kid1| 5,5| AsyncCall.cc(38) make: make call
helperStatefulDispatchWriteDone [call581993]
[0000] 4E 54 4C 4D 53 53 50 00 01 00 00 00 07 82 08 A2 NTLMSSP. ........
2021/11/11 01:36:16.862 kid1| 5,5| AsyncCallQueue.cc(57) fireNext:
leaving helperStatefulDispatchWriteDone(local=[::] remote=[::] FD 10
flags=1, data=0x5570e8731e08, size=60, buf=0x5570e8d2c1a0)
[0010] 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ........ ........
2021/11/11 01:36:16.862 kid1| 5,5| ModEpoll.cc(117) SetSelect: FD 10,
type=2, handler=0, client_data=0, timeout=0
[0020] 0A 00 63 45 00 00 00 0F ..cE....
*ntlm_fake_auth.cc(197): pid=4454 :sending 'TT' to squid with data:*
*[0000] 4E 54 4C 4D 53 53 50 00 02 00 00 00 09 00 09 00 NTLMSSP. ........*
*2021/11/11 01:36:16.862 kid1| 5,3| Read.cc(145) HandleRead: FD 10, size
32767, retval 72, errno 0*
*[0010] AE AA AA AA 07 82 08 A2 E8 DB F0 45 D4 04 00 32 ........ ...E...2*
*2021/11/11 01:36:16.862 kid1| 5,3| IoCallback.cc(116) finish: called
for local=[::] remote=[::] FD 10 flags=1 (0, 0)*
*[0020] 00 00 00 00 00 00 3A 00 57 4F 52 4B 47 52 4F 55 ........ WORKGROU*
*[0030] 50 * P
2021/11/11 01:36:16.862 kid1| 5,4| AsyncCall.cc(93) ScheduleCall:
IoCallback.cc(135) will call helperStatefulHandleRead(local=[::]
remote=[::] FD 10 flags=1, data=0x5570e8752b18, size=72,
buf=0x5570e87635b0) [call581969]
2021/11/11 01:36:16.862 kid1| 5,4| AsyncCallQueue.cc(55) fireNext:
entering helperStatefulHandleRead(local=[::] remote=[::] FD 10 flags=1,
data=0x5570e8752b18, size=72, buf=0x5570e87635b0)
2021/11/11 01:36:16.862 kid1| 5,4| AsyncCall.cc(38) make: make call
helperStatefulHandleRead [call581969]
2021/11/11 01:36:16.862 kid1| 84,5| helper.cc(1081)
helperStatefulHandleRead: helperStatefulHandleRead: 72 bytes from
ntlmauthenticator #Hlpr66
2021/11/11 01:36:16.862 kid1| 84,3| helper.cc(1103)
helperStatefulHandleRead: helperStatefulHandleRead: end of reply found
2021/11/11 01:36:16.862 kid1| 84,3| Reply.cc(41) finalize: Parsing
helper buffer
2021/11/11 01:36:16.862 kid1| 84,3| Reply.cc(59) finalize: Buff length
is larger than 2
*2021/11/11 01:36:16.862 kid1| 29,4| UserRequest.cc(306) HandleReply:
Need to challenge the client with a server token:
'TlRMTVNTUAACAAAACQAJAK6qqqoHggii6NvwRdQEADIAAAAAAAA6AFdPUktHUk9VUA=='*
2021/11/11 01:36:16.862 kid1| 29,5| UserRequest.cc(77) valid: Validated.
Auth::UserRequest '0x5570e8cdacf0'.
2021/11/11 01:36:16.862 kid1| 28,5| InnerNode.cc(94) resumeMatchingAt:
checking http_access at 29
2021/11/11 01:36:16.862 kid1| 28,5| Checklist.cc(397) bannedAction:
Action 'DENIED/0' is not banned
2021/11/11 01:36:16.862 kid1| 28,5| InnerNode.cc(94) resumeMatchingAt:
checking http_access#30 at 1
2021/11/11 01:36:16.862 kid1| 28,5| InnerNode.cc(94) resumeMatchingAt:
checking !AUTHENTICATED at 0
2021/11/11 01:36:16.862 kid1| 28,5| Acl.cc(124) matches: checking
AUTHENTICATED
2021/11/11 01:36:16.862 kid1| 29,5| UserRequest.cc(77) valid: Validated.
Auth::UserRequest '0x5570e8cdacf0'.
2021/11/11 01:36:16.862 kid1| 29,5| UserRequest.cc(77) valid: Validated.
Auth::UserRequest '0x5570e8cdacf0'.
*2021/11/11 01:36:16.862 kid1| 29,2| UserRequest.cc(197) authenticate:
need to challenge client
'TlRMTVNTUAACAAAACQAJAK6qqqoHggii6NvwRdQEADIAAAAAAAA6AFdPUktHUk9VUA=='!*
2021/11/11 01:36:16.862 kid1| 29,5| UserRequest.cc(77) valid: Validated.
Auth::UserRequest '0x5570e8cdacf0'.
2021/11/11 01:36:16.862 kid1| 28,4| Acl.cc(78) AuthenticateAcl:
returning 3 sending authentication challenge.
2021/11/11 01:36:16.862 kid1| 28,3| Checklist.cc(63) markFinished:
0x5570e876da88 answer AUTH_REQUIRED for AuthenticateAcl exception
*2021/11/11 01:36:16.862 kid1| 28,3| Acl.cc(151) matches: checked:
AUTHENTICATED = -1*
2021/11/11 01:36:16.863 kid1| 28,3| InnerNode.cc(97) resumeMatchingAt:
checked: !AUTHENTICATED = -1
2021/11/11 01:36:16.863 kid1| 28,3| InnerNode.cc(97) resumeMatchingAt:
checked: http_access#30 = -1
2021/11/11 01:36:16.863 kid1| 28,3| InnerNode.cc(97) resumeMatchingAt:
checked: http_access = -1
2021/11/11 01:36:16.863 kid1| 28,3| Checklist.cc(163) checkCallback:
ACLChecklist::checkCallback: 0x5570e876da88 answer=AUTH_REQUIRED
2021/11/11 01:36:16.863 kid1| 85,2| client_side_request.cc(759)
clientAccessCheckDone: The request GET http://www.squid-cache.org/ is
AUTH_REQUIRED; last ACL checked: AUTHENTICATED
2021/11/11 01:36:16.863 kid1| 85,5| client_side_request.cc(775)
clientAccessCheckDone: *Access Denied*: http://www.squid-cache.org/
2021/11/11 01:36:16.863 kid1| 85,5| client_side_request.cc(776)
clientAccessCheckDone: AclMatchedName = AUTHENTICATED
2021/11/11 01:36:16.863 kid1| 33,5| client_side_request.cc(779)
clientAccessCheckDone: Proxy Auth Message = Authentication in progress
2021/11/11 01:36:16.863 kid1| 28,4| FilledChecklist.cc(67)
~ACLFilledChecklist: ACLFilledChecklist destroyed 0x7fff22f7a0b0
2021/11/11 01:36:16.863 kid1| 28,4| Checklist.cc(197) ~ACLChecklist:
ACLChecklist::~ACLChecklist: destroyed 0x7fff22f7a0b0
2021/11/11 01:36:16.863 kid1| 28,4| FilledChecklist.cc(67)
~ACLFilledChecklist: ACLFilledChecklist destroyed 0x7fff22f7a0b0
2021/11/11 01:36:16.863 kid1| 28,4| Checklist.cc(197) ~ACLChecklist:
ACLChecklist::~ACLChecklist: destroyed 0x7fff22f7a0b0
2021/11/11 01:36:16.863 kid1| 85,5| client_side_request.cc(1445)
sslBumpAccessCheck: cannot SslBump this request
2021/11/11 01:36:16.863 kid1| 73,3| HttpRequest.cc(662) storeId: sent
back effectiveRequestUrl: http://www.squid-cache.org/
2021/11/11 01:36:16.863 kid1| 24,7| SBuf.cc(160) rawSpace: reserving 1
for SBuf1021849
2021/11/11 01:36:16.863 kid1| 24,7| SBuf.cc(167) rawSpace: SBuf1021849
not growing
2021/11/11 01:36:16.863 kid1| 20,3| store.cc(785) storeCreatePureEntry:
storeCreateEntry: 'http://www.squid-cache.org/'
2021/11/11 01:36:16.863 kid1| 20,5| store.cc(347) StoreEntry: StoreEntry
constructed, this=0x5570e87b5620
2021/11/11 01:36:16.863 kid1| 20,3| MemObject.cc(101) MemObject:
MemObject constructed, this=0x5570e8ad2990
2021/11/11 01:36:16.863 kid1| 55,7| HttpHeader.cc(152) HttpHeader:
init-ing hdr: 0x5570e8c55128 owner: 3
2021/11/11 01:36:16.863 kid1| 88,3| MemObject.cc(84) setUris:
0x5570e8ad2990 storeId: http://www.squid-cache.org/
2021/11/11 01:36:16.863 kid1| 24,7| SBuf.cc(85) assign: assigning
SBuf1021850 from SBuf1021792
2021/11/11 01:36:16.863 kid1| 20,3| store.cc(444) lock: storeCreateEntry
locked key [null_store_key] e:=V/0x5570e87b5620*1
2021/11/11 01:36:16.863 kid1| 20,3| store.cc(586) setPrivateKey: 01
e:=V/0x5570e87b5620*1
2021/11/11 01:36:16.863 kid1| 20,3| store.cc(422) hashInsert:
StoreEntry::hashInsert: Inserting Entry e:=XIV/0x5570e87b5620*1 key
'771C000000000000A607000001000000'
2021/11/11 01:36:16.863 kid1| 20,3| store.cc(444) lock:
clientReplyContext::setReplyToStoreEntry locked key
771C000000000000A607000001000000 e:=XIV/0x5570e87b5620*2
2021/11/11 01:36:16.863 kid1| 4,4| errorpage.cc(604) errorAppendEntry:
Creating an error page for entry 0x5570e87b5620 with errorstate
0x5570e8c527b8 page id 2
2021/11/11 01:36:16.863 kid1| 55,7| HttpHeader.cc(152) HttpHeader:
init-ing hdr: 0x5570e8ddec88 owner: 3
2021/11/11 01:36:16.863 kid1| 4,2| errorpage.cc(1259) BuildContent: No
existing error page language negotiated for ERR_CACHE_ACCESS_DENIED.
Using default error file.
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.squid-cache.org/pipermail/squid-users/attachments/20211111/e2e5d121/attachment-0001.htm>
More information about the squid-users
mailing list