Unfortunately I cannot get mod_ntlm to work with pages that use Ajax stuff. I've seen other postings elsewhere on the topic where other have the same problem. I refuse to accept the ones that say that NTLM and Ajax can never be partners.
The problem is likely due to the XMLHttpRequests (often in plural) that are fired as part of the page load and possibly later. I think the problem is that Apache sees is quite a few auth requests coming in rapid order as opposed to a traditional page that only triggers one auth request.
I'm quite far from being an expert on NTLM but I know it requires several messages to be passed back and forth before a sequence is finished. With the many auth requests that an Ajax page will trigger it is therefore likely that mod_ntlm will be confused an initiate a new sequence before a previous one has ended.
I've turned on 'debug' in Apache. First I list a normal page load and the NTLM traffic it generates:
As one can see this does not work well. It ends with an error "PDC connection already closed". As far as I can see from the C code it does actually try to take such a scenario into account (i.e. re-authentication from the same client) which is logged as a "silent reauthentication". As can be seen from above this does not in fact happen but I guess it just cannot catch all.
Modern WYSIWIG html editors today use Ajax tricks. If you want to test the problem then test on one of the many wikis that use TinyMCE.
Hope someone can look into this. Thx.
If you would like to refer to this comment somewhere else in this project, copy and paste the following link:
Unfortunately I cannot get mod_ntlm to work with pages that use Ajax stuff. I've seen other postings elsewhere on the topic where other have the same problem. I refuse to accept the ones that say that NTLM and Ajax can never be partners.
The problem is likely due to the XMLHttpRequests (often in plural) that are fired as part of the page load and possibly later. I think the problem is that Apache sees is quite a few auth requests coming in rapid order as opposed to a traditional page that only triggers one auth request.
I'm quite far from being an expert on NTLM but I know it requires several messages to be passed back and forth before a sequence is finished. With the many auth requests that an Ajax page will trigger it is therefore likely that mod_ntlm will be confused an initiate a new sequence before a previous one has ended.
I've turned on 'debug' in Apache. First I list a normal page load and the NTLM traffic it generates:
[Sun Apr 20 23:01:39 2008] [info] [client 10.25.228.178] 1984176 14511 /www/bin/view - NTLMXX-Creating new ntlm_connection: 3
[Sun Apr 20 23:01:39 2008] [debug] mod_ntlm.c(78): [client 10.25.228.178] 1984176 14511 /www/bin/view - got auth_line "TlRMTVNTUAABAAAAB7IIoggACAAyAAAACgAKACgAAAAFASgKAAAAD0RLRDFXUzAzODlORDYwQTYwMH=="
[Sun Apr 20 23:01:39 2008] [debug] mod_ntlm.c(78): [client 10.25.228.178] 1984176 14511 /www/bin/view - got header with host "WS0455", domain "WINDOM01", unicode flag 7
[Sun Apr 20 23:01:39 2008] [info] [client 10.25.228.178] 1984176 14511 /www/bin/view - received msg1 keep-alive: 0, keepalives: 1
[Sun Apr 20 23:01:39 2008] [info] 14511 - SMB_Connect_Server: server - domctrl04, domain - windom01
[Sun Apr 20 23:01:39 2008] [info] 14511 - SMB_Connect_Server: my name - wwwsrv01
[Sun Apr 20 23:01:39 2008] [debug] mod_ntlm.c(95): 14511 - SMB_Connect_Server: address - domctrl04
[Sun Apr 20 23:01:39 2008] [debug] mod_ntlm.c(95): 14511 - RFCNB_Call: start
[Sun Apr 20 23:01:39 2008] [debug] mod_ntlm.c(95): 14511 - RFCNB_Call: Called_Name: DOMCTRL04 Service_Address: domctrl04
[Sun Apr 20 23:01:39 2008] [debug] mod_ntlm.c(95): 14511 - RFCNB_Call: Dest IP - 10.67.11.3, Port – 139
[Sun Apr 20 23:01:39 2008] [debug] mod_ntlm.c(95): 14511 - RFCNB_Call: After RFCNB_IP_Connect 10
[Sun Apr 20 23:01:39 2008] [debug] mod_ntlm.c(95): 14511 - SMB_Connect_Server: after RFCNB_Call con->Trans_Connect = 1
[Sun Apr 20 23:01:39 2008] [info] [client 10.25.228.178] 1984176 14511 /www/bin/view - send WWW-Authenticate "NTLM TlRMTVNTUAACAAAAAAAAACgAAAABggAA3oedqvOTcuQAAAAAAAAAAA=="
[Sun Apr 20 23:01:39 2008] [debug] mod_ntlm.c(78): [client 10.25.228.178] 1984176 14511 /www/bin/view - got auth_line "TlRMTVNTUAADAAAAGAAYAHgAAAAYABgAkAAAABAAEABIAAAADAAMAFgAAAAUABQAZAAAAAAAAACoAAAABYIAAgUBKAoAAAAPTgBEADYAMABBADYAMAAwAEcAMgAwADMAOAAzAEQASwBEADEAVwBTADAAMwA4ADkA9DHDt/1iZG40k3EyqEhKL3zEK4hwFQDWyepETQZlqJ+qoDLhbgb270An3qdRtVVB"
[Sun Apr 20 23:01:39 2008] [debug] mod_ntlm.c(78): [client 10.25.228.178] 1984176 14511 /www/bin/view - got header with host "WS0455", domain "WINDOM01", unicode flag 7
[Sun Apr 20 23:01:39 2008] [info] [client 10.25.228.178] 1984176 14511 /www/bin/view - received msg3
[Sun Apr 20 23:01:39 2008] [info] [client 10.25.228.178] 1984176 14511 /www/bin/view - authenticating user against DC
[Sun Apr 20 23:01:39 2008] [info] 14511 - SMB_Logon_Server: type is NTLM (8)
[Sun Apr 20 23:01:39 2008] [info] 14511 - SMB_Logon_Server: login OK
[Sun Apr 20 23:01:39 2008] [info] [client 10.25.228.178] 1984176 14511 /www/bin/view - NTLM/SMB user: "WINDOM01\\JOHNM": authentication OK.
[Sun Apr 20 23:01:39 2008] [debug] mod_ntlm.c(95): 14548 - Calling apr_global_mutex_child_init with lockfile /var/tmp/aaaHSaqvC
[Sun Apr 20 23:01:42 2008] [debug] mod_ntlm.c(95): 14549 - Calling apr_global_mutex_child_init with lockfile /var/tmp/aaaHSaqvC
[Sun Apr 20 23:01:59 2008] [info] 14511 - NTLMXX-Clearing NTLM connection: 1985232 id: 3
[Sun Apr 20 23:01:59 2008] [info] 14511 - SMB_Discon
Now to a page that Ajax stuff in it:
[Sun Apr 20 23:05:01 2008] [info] [client 10.25.228.178] 1984176 14508 /www/bin/edit/Main/WebHome - NTLMXX-Creating new ntlm_connection: 0, referer: http://wwwsrv01:85/www/bin/view
[Sun Apr 20 23:05:01 2008] [debug] mod_ntlm.c(78): [client 10.25.228.178] 1984176 14508 /www/bin/edit/Main/WebHome - got auth_line "TlRMTVNTUAABAAAAB7IIoggACAAyAAAACgAKACgAAAAFASgKAAAAD0RLRDFXUzAzODlORDYwQTYwMM==", referer: http://wwwsrv01:85/www/bin/view
[Sun Apr 20 23:05:01 2008] [debug] mod_ntlm.c(78): [client 10.25.228.178] 1984176 14508 /www/bin/edit/Main/WebHome - got header with host "WS0455", domain "WINDOM01", unicode flag 7, referer: http://wwwsrv01:85/www/bin/view
[Sun Apr 20 23:05:01 2008] [info] [client 10.25.228.178] 1984176 14508 /www/bin/edit/Main/WebHome - received msg1 keep-alive: 0, keepalives: 1, referer: http://wwwsrv01:85/www/bin/view
[Sun Apr 20 23:05:01 2008] [info] 14508 - SMB_Connect_Server: server - domctrl04, domain - windom01
[Sun Apr 20 23:05:01 2008] [info] 14508 - SMB_Connect_Server: my name - wwwsrv01
[Sun Apr 20 23:05:01 2008] [debug] mod_ntlm.c(95): 14508 - SMB_Connect_Server: address - domctrl04
[Sun Apr 20 23:05:01 2008] [debug] mod_ntlm.c(95): 14508 - RFCNB_Call: start
[Sun Apr 20 23:05:01 2008] [debug] mod_ntlm.c(95): 14508 - RFCNB_Call: Called_Name: DOMCTRL04 Service_Address: domctrl04
[Sun Apr 20 23:05:01 2008] [debug] mod_ntlm.c(95): 14508 - RFCNB_Call: Dest IP - 10.67.11.3, Port – 139
[Sun Apr 20 23:05:01 2008] [debug] mod_ntlm.c(95): 14508 - RFCNB_Call: After RFCNB_IP_Connect 10
[Sun Apr 20 23:05:01 2008] [debug] mod_ntlm.c(95): 14508 - SMB_Connect_Server: after RFCNB_Call con->Trans_Connect = 1
[Sun Apr 20 23:05:01 2008] [info] [client 10.25.228.178] 1984176 14508 /www/bin/edit/Main/WebHome - send WWW-Authenticate "NTLM TlRMTVNTUAACAAAAAAAAACgAAAABggAA9s8RLTEJR0EAAAAAAAAAAA==", referer: http://wwwsrv01:85/www/bin/view
[Sun Apr 20 23:05:01 2008] [debug] mod_ntlm.c(78): [client 10.25.228.178] 1984176 14508 /www/bin/edit/Main/WebHome - got auth_line "TlRMTVNTUAADAAAAGAAYAHgAAAAYABgAkAAAABAAEABIAAAADAAMAFgAAAAUABQAZAAAAAAAAACoAAAABYIAAgUBKAoAAAAPTgBEADYAMABBADYAMAAwAEcAMgAwADMAOAAzAEQASwBEADEAVwBTADAAMwA4ADkAKZUtHB4gDWo7m8agy9tm/y87SPmVMVi+mV3Y/LA9ZgwkxCHoocbGqwARYiYU2zMb", referer: http://wwwsrv01:85/www/bin/view
[Sun Apr 20 23:05:01 2008] [debug] mod_ntlm.c(78): [client 10.25.228.178] 1984176 14508 /www/bin/edit/Main/WebHome - got header with host "WS0455", domain "WINDOM01", unicode flag 7, referer: http://wwwsrv01:85/www/bin/view
[Sun Apr 20 23:05:01 2008] [info] [client 10.25.228.178] 1984176 14508 /www/bin/edit/Main/WebHome - received msg3, referer: http://wwwsrv01:85/www/bin/view
[Sun Apr 20 23:05:01 2008] [info] [client 10.25.228.178] 1984176 14508 /www/bin/edit/Main/WebHome - authenticating user against DC, referer: http://wwwsrv01:85/www/bin/view
[Sun Apr 20 23:05:01 2008] [info] 14508 - SMB_Logon_Server: type is NTLM (8)
[Sun Apr 20 23:05:01 2008] [info] 14508 - SMB_Logon_Server: login OK
[Sun Apr 20 23:05:01 2008] [info] [client 10.25.228.178] 1984176 14508 /www/bin/edit/Main/WebHome - NTLM/SMB user: "WINDOM01\\JOHNM": authentication OK., referer: http://wwwsrv01:85/www/bin/view
[Sun Apr 20 23:05:01 2008] [debug] mod_ntlm.c(78): [client 10.25.228.178] 1984176 14508 /Main/WebHome - got auth_line "TlRMTVNTUAADAAAAGAAYAHgAAAAYABgAkAAAABAAEABIAAAADAAMAFgAAAAUABQAZAAAAAAAAACoAAAABYIAAgUBKAoAAAAPTgBEADYAMABBADYAMAAwAEcAMgAwADMAOAAzAEQASwBEADEAVwBTADAAMwA4ADkAKZUtHB4gDWo7m8agy9tm/y87SPmVMVi+mV3Y/LA9ZgwkxCHoocbGqwARYiYU2zMb", referer: http://wwwsrv01:85/www/bin/view
[Sun Apr 20 23:05:01 2008] [debug] mod_ntlm.c(78): [client 10.25.228.178] 1984176 14508 /Main/WebHome - got header with host "WS0455", domain "WINDOM01", unicode flag 7, referer: http://wwwsrv01:85/www/bin/view
[Sun Apr 20 23:05:01 2008] [info] [client 10.25.228.178] 1984176 14508 /Main/WebHome - received msg3, referer: http://wwwsrv01:85/www/bin/view
[Sun Apr 20 23:05:01 2008] [info] [client 10.25.228.178] 1984176 14508 /Main/WebHome - silent reauthentication, referer: http://wwwsrv01:85/www/bin/view
[Sun Apr 20 23:05:04 2008] [debug] mod_ntlm.c(78): [client 10.25.228.178] 1984176 14508 /www/bin/rest/WysiwygPlugin/tml2html - got auth_line "TlRMTVNTUAABAAAAB7IIoggACAAyAAAACgAKACgAAAAFASgKAAAAD0RLRDFXUzAzODlORDYwQTYwMA==", referer: http://wwwsrv01:85/www/bin/edit/Main/WebHome?t=1208725301
[Sun Apr 20 23:05:04 2008] [debug] mod_ntlm.c(78): [client 10.25.228.178] 1984176 14508 /www/bin/rest/WysiwygPlugin/tml2html - got header with host "WS0455", domain "WINDOM01", unicode flag 7, referer: http://wwwsrv01:85/www/bin/edit/Main/WebHome?t=1208725301
[Sun Apr 20 23:05:04 2008] [info] [client 10.25.228.178] 1984176 14508 /www/bin/rest/WysiwygPlugin/tml2html - received msg1 keep-alive: 0, keepalives: 39, referer: http://wwwsrv01:85/www/bin/edit/Main/WebHome?t=1208725301
[Sun Apr 20 23:05:04 2008] [info] [client 10.25.228.178] 1984176 14508 /www/bin/rest/WysiwygPlugin/tml2html - send WWW-Authenticate "NTLM TlRMTVNTUAACAAAAAAAAACgAAAABggAA9s8RLTEJR0EAAAAAAAAAAA==", referer: http://wwwsrv01:85/www/bin/edit/Main/WebHome?t=1208725301
[Sun Apr 20 23:05:04 2008] [info] [client 10.25.228.178] 1984176 14512 /www/bin/rest/WysiwygPlugin/tml2html - NTLMXX-Creating new ntlm_connection: 4, referer: http://wwwsrv01:85/www/bin/edit/Main/WebHome?t=1208725301
[Sun Apr 20 23:05:04 2008] [debug] mod_ntlm.c(78): [client 10.25.228.178] 1984176 14512 /www/bin/rest/WysiwygPlugin/tml2html - got auth_line "TlRMTVNTUAADAAAAGAAYAHgAAAAYABgAkAAAABAAEABIAAAADAAMAFgAAAAUABQAZAAAAAAAAACoAAAABYIAAgUBKAoAAAAPTgBEADYAMABBADYAMAAwAEcAMgAwADMAOAAzAEQASwBEADEAVwBTADAAMwA4ADkAKZUtHB4gDWo7m8agy9tm/y87SPmVMVi+mV3Y/LA9ZgwkxCHoocbGqwARYiYU2zMb", referer: http://wwwsrv01:85/www/bin/edit/Main/WebHome?t=1208725301
[Sun Apr 20 23:05:04 2008] [debug] mod_ntlm.c(78): [client 10.25.228.178] 1984176 14512 /www/bin/rest/WysiwygPlugin/tml2html - got header with host "WS0455", domain "WINDOM01", unicode flag 0, referer: http://wwwsrv01:85/www/bin/edit/Main/WebHome?t=1208725301
[Sun Apr 20 23:05:04 2008] [info] [client 10.25.228.178] 1984176 14512 /www/bin/rest/WysiwygPlugin/tml2html - received msg3, referer: http://wwwsrv01:85/www/bin/edit/Main/WebHome?t=1208725301
[Sun Apr 20 23:05:04 2008] [error] [client 10.25.228.178] 1984176 14512 /www/bin/rest/WysiwygPlugin/tml2html - PDC connection already closed, referer: http://wwwsrv01:85/www/bin/edit/Main/WebHome?t=1208725301
[Sun Apr 20 23:05:06 2008] [info] 14508 - NTLMXX-Clearing NTLM connection: 1985232 id: 0
[Sun Apr 20 23:05:06 2008] [info] 14508 - SMB_Discon
[Sun Apr 20 23:05:06 2008] [info] 14512 - NTLMXX-Clearing NTLM connection: 1985232 id: 4
As one can see this does not work well. It ends with an error "PDC connection already closed". As far as I can see from the C code it does actually try to take such a scenario into account (i.e. re-authentication from the same client) which is logged as a "silent reauthentication". As can be seen from above this does not in fact happen but I guess it just cannot catch all.
Modern WYSIWIG html editors today use Ajax tricks. If you want to test the problem then test on one of the many wikis that use TinyMCE.
Hope someone can look into this. Thx.
Hi James.
We are experiencing the same issue in our application.
Into the error.log file exists these lines:
(70014)End of file found: proxy: error reading status line from remote server exiwai14.baires.techint.net, referer: http://ebd.exiros.techint.net/ebd/gi/shell.jsp?jsxapppath=/ebd/gi/JSXAPPS/MAIN
538316488 671760 /soapbridge/esb/Services/06-PO/POService/Implementation/POWSDL-service1.serviceagent/POServiceEndpoint1 - PDC connection already closed, referer: http://ebd.exiros.techint.net/ebd/gi/shell.jsp?jsxapppath=/ebd/gi/JSXAPPS/MAIN
Have you solved this issue?
Thanks for all.
Gastón.