thr3ads.net - samba - [Samba] PDC + LDAP, cannot access LDAP when not root [Sep 2005]

If this information is useful, please help other people find it:
Share via:

David Clymer

2005-Sep-27 22:45 UTC

[Samba] PDC + LDAP, cannot access LDAP when not root

I'm using Debian Sarge, Samba (3.1.14a) with the ldapsam backend, and
OpenLDAP (2.2.23).

When attempting to join an Windows XP+SP2 computer (BILLGATES) to my
domain (WORKGROUP), using the Administrator account, I am told by
windows: 'Access denied.'

The logs (attached) seem to indicate that the user Administrator is
being authenticated (which would have? to use LDAP), but when It goes to
add the computer to the domain, it fails. Apparently because samba is
unable to access LDAP:

smbldap_open: cannot access LDAP when not root..

nobody and Administrator are the only users on the domain.

An interesting phenomenon that I've observed (perhaps it is related?):

testbox:/etc/samba# pdbedit -L
Administrator:998:Administrator
nobody:65534:nobody
testbox:/etc/samba# net -U Administrator rpc group members 'Domain
Computers'
Password:
WORKGROUP\BILLGATES$
testbox:/etc/samba# net -U Administrator rpc group members 'Domain
Admins'
Password:
WORKGROUP\Administrator
testbox:/etc/samba# net -U Administrator rpc group members
'Administrators'
Password:
[2005/09/27 16:05:11, 0] rpc_client/cli_pipe.c:rpc_api_pipe(435)
  cli_pipe: return critical error. Error was Call timed out: server did not
respond after 10000 milliseconds
Couldn't list alias members

I don't understand why Administrators group listing fails, while the
others don't.

Google searches yielded a bunch of similar problems for early versions
of samba 3.0, related to modification of user groups. However that bug
was supposedly fixed, and I've seen no reports of it occuring in later
versions. There are no open bugs, that I could find, related to this on
bugzilla.samba.org.

Is there any type of (mis)configuration that could result in the same
sort of symptom?

attached is my smb.conf, smbldap.conf, and my samba log output (debug
level=4)

I would be very grateful for any ideas, FMs to R, magic wands, etc. that
anyone might have to offer.


-davidc 

--
The day dawned much like any other day, except that the date was
different. -Geoff Blackwell (Dishonorable mention 2004 Bulwer-Lytton Bad
Fiction Contest)
-------------- next part --------------
[2005/09/19 16:51:51, 3] smbd/process.c:process_smb(1091)
  Transaction 1 of length 137
[2005/09/19 16:51:51, 3] smbd/process.c:switch_message(886)
  switch message SMBnegprot (pid 17585) conn 0x0
[2005/09/19 16:51:51, 3] smbd/sec_ctx.c:set_sec_ctx(288)
  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0
[2005/09/19 16:51:51, 3] smbd/negprot.c:reply_negprot(461)
  Requested protocol [PC NETWORK PROGRAM 1.0]
[2005/09/19 16:51:51, 3] smbd/negprot.c:reply_negprot(461)
  Requested protocol [LANMAN1.0]
[2005/09/19 16:51:51, 3] smbd/negprot.c:reply_negprot(461)
  Requested protocol [Windows for Workgroups 3.1a]
[2005/09/19 16:51:51, 3] smbd/negprot.c:reply_negprot(461)
  Requested protocol [LM1.2X002]
[2005/09/19 16:51:51, 3] smbd/negprot.c:reply_negprot(461)
  Requested protocol [LANMAN2.1]
[2005/09/19 16:51:51, 3] smbd/negprot.c:reply_negprot(461)
  Requested protocol [NT LM 0.12]
[2005/09/19 16:51:51, 3] smbd/negprot.c:reply_nt1(333)
  using SPNEGO
[2005/09/19 16:51:51, 3] smbd/negprot.c:reply_negprot(555)
  Selected protocol NT LM 0.12
[2005/09/19 16:51:51, 3] smbd/process.c:process_smb(1091)
  Transaction 2 of length 240
[2005/09/19 16:51:51, 3] smbd/process.c:switch_message(886)
  switch message SMBsesssetupX (pid 17585) conn 0x0
[2005/09/19 16:51:51, 3] smbd/sec_ctx.c:set_sec_ctx(288)
  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0
[2005/09/19 16:51:51, 3] smbd/sesssetup.c:reply_sesssetup_and_X(655)
  wct=12 flg2=0xc807
[2005/09/19 16:51:51, 2] smbd/sesssetup.c:setup_new_vc_session(608)
  setup_new_vc_session: New VC == 0, if NT4.x compatible we would close all old
resources.
[2005/09/19 16:51:51, 3] smbd/sesssetup.c:reply_sesssetup_and_X_spnego(535)
  Doing spnego session setup
[2005/09/19 16:51:51, 3] smbd/sesssetup.c:reply_sesssetup_and_X_spnego(566)
  NativeOS=[Windows 2002 Service Pack 2 2600] NativeLanMan=[Windows 2002 5.1]
PrimaryDomain=[]
[2005/09/19 16:51:51, 3] smbd/sesssetup.c:reply_spnego_negotiate(444)
  Got OID 1 3 6 1 4 1 311 2 2 10
[2005/09/19 16:51:51, 3] smbd/sesssetup.c:reply_spnego_negotiate(447)
  Got secblob of size 40
[2005/09/19 16:51:51, 3] libsmb/ntlmssp.c:debug_ntlmssp_flags(62)
  Got NTLMSSP neg_flags=0xe2088297
    NTLMSSP_NEGOTIATE_UNICODE
    NTLMSSP_NEGOTIATE_OEM
    NTLMSSP_REQUEST_TARGET
    NTLMSSP_NEGOTIATE_SIGN
    NTLMSSP_NEGOTIATE_LM_KEY
    NTLMSSP_NEGOTIATE_NTLM
    NTLMSSP_NEGOTIATE_ALWAYS_SIGN
    NTLMSSP_NEGOTIATE_NTLM2
    NTLMSSP_NEGOTIATE_128
    NTLMSSP_NEGOTIATE_KEY_EXCH
[2005/09/19 16:51:51, 3] smbd/process.c:process_smb(1091)
  Transaction 3 of length 376
[2005/09/19 16:51:51, 3] smbd/process.c:switch_message(886)
  switch message SMBsesssetupX (pid 17585) conn 0x0
[2005/09/19 16:51:51, 3] smbd/sec_ctx.c:set_sec_ctx(288)
  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0
[2005/09/19 16:51:51, 3] smbd/sesssetup.c:reply_sesssetup_and_X(655)
  wct=12 flg2=0xc807
[2005/09/19 16:51:51, 2] smbd/sesssetup.c:setup_new_vc_session(608)
  setup_new_vc_session: New VC == 0, if NT4.x compatible we would close all old
resources.
[2005/09/19 16:51:51, 3] smbd/sesssetup.c:reply_sesssetup_and_X_spnego(535)
  Doing spnego session setup
[2005/09/19 16:51:51, 3] smbd/sesssetup.c:reply_sesssetup_and_X_spnego(566)
  NativeOS=[Windows 2002 Service Pack 2 2600] NativeLanMan=[Windows 2002 5.1]
PrimaryDomain=[]
[2005/09/19 16:51:51, 3] libsmb/ntlmssp.c:ntlmssp_server_auth(606)
  Got user=[administrator] domain=[WORKGROUP] workstation=[BILLGATES] len1=24
len2=24
[2005/09/19 16:51:51, 3] smbd/sec_ctx.c:push_sec_ctx(256)
  push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1
[2005/09/19 16:51:51, 3] smbd/uid.c:push_conn_ctx(365)
  push_conn_ctx(0) : conn_ctx_stack_ndx = 0
[2005/09/19 16:51:51, 3] smbd/sec_ctx.c:set_sec_ctx(288)
  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1
[2005/09/19 16:51:51, 3] smbd/sec_ctx.c:pop_sec_ctx(386)
  pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0
[2005/09/19 16:51:51, 3] auth/auth.c:check_ntlm_password(219)
  check_ntlm_password:  Checking password for unmapped user
[WORKGROUP]\[administrator]@[BILLGATES] with the new password interface
[2005/09/19 16:51:51, 3] auth/auth.c:check_ntlm_password(222)
  check_ntlm_password:  mapped user is: [WORKGROUP]\[administrator]@[BILLGATES]
[2005/09/19 16:51:51, 3] smbd/sec_ctx.c:push_sec_ctx(256)
  push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1
[2005/09/19 16:51:51, 3] smbd/uid.c:push_conn_ctx(365)
  push_conn_ctx(0) : conn_ctx_stack_ndx = 0
[2005/09/19 16:51:51, 3] smbd/sec_ctx.c:set_sec_ctx(288)
  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1
[2005/09/19 16:51:51, 2] lib/smbldap.c:smbldap_open_connection(692)
  smbldap_open_connection: connection opened
[2005/09/19 16:51:51, 3] lib/smbldap.c:smbldap_connect_system(866)
  ldap_connect_system: succesful connection to the LDAP server
  ldap_connect_system: LDAP server does support paged results
[2005/09/19 16:51:51, 4] lib/smbldap.c:smbldap_open(929)
  The LDAP server is succesfully connected
[2005/09/19 16:51:51, 2] passdb/pdb_ldap.c:init_sam_from_ldap(499)
  init_sam_from_ldap: Entry found for user: Administrator
[2005/09/19 16:51:51, 3] smbd/sec_ctx.c:pop_sec_ctx(386)
  pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0
[2005/09/19 16:51:51, 4] libsmb/ntlm_check.c:ntlm_password_check(326)
  ntlm_password_check: Checking NT MD4 password
[2005/09/19 16:51:51, 4] auth/auth_sam.c:sam_account_ok(119)
  sam_account_ok: Checking SMB password for user Administrator
[2005/09/19 16:51:51, 3] smbd/sec_ctx.c:push_sec_ctx(256)
  push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1
[2005/09/19 16:51:51, 3] smbd/uid.c:push_conn_ctx(365)
  push_conn_ctx(0) : conn_ctx_stack_ndx = 0
[2005/09/19 16:51:51, 3] smbd/sec_ctx.c:set_sec_ctx(288)
  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1
[2005/09/19 16:51:51, 3] smbd/sec_ctx.c:push_sec_ctx(256)
  push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 2
[2005/09/19 16:51:51, 3] smbd/uid.c:push_conn_ctx(365)
  push_conn_ctx(0) : conn_ctx_stack_ndx = 1
[2005/09/19 16:51:51, 3] smbd/sec_ctx.c:set_sec_ctx(288)
  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 2
[2005/09/19 16:51:51, 3] smbd/sec_ctx.c:pop_sec_ctx(386)
  pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 1
[2005/09/19 16:51:51, 3] smbd/sec_ctx.c:push_sec_ctx(256)
  push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 2
[2005/09/19 16:51:51, 3] smbd/uid.c:push_conn_ctx(365)
  push_conn_ctx(0) : conn_ctx_stack_ndx = 1
[2005/09/19 16:51:51, 3] smbd/sec_ctx.c:set_sec_ctx(288)
  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 2
[2005/09/19 16:51:51, 2] passdb/pdb_ldap.c:init_group_from_ldap(2000)
  init_group_from_ldap: Entry found for group: 544
[2005/09/19 16:51:51, 3] smbd/sec_ctx.c:pop_sec_ctx(386)
  pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 1
[2005/09/19 16:51:51, 3] smbd/sec_ctx.c:pop_sec_ctx(386)
  pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0
[2005/09/19 16:51:51, 3] lib/privileges.c:get_privileges(249)
  get_privileges: No privileges assigned to SID
[S-1-5-21-4087610795-3070336623-1441377821-2996]
[2005/09/19 16:51:51, 3] lib/privileges.c:get_privileges(249)
  get_privileges: No privileges assigned to SID
[S-1-5-21-4087610795-3070336623-1441377821-512]
[2005/09/19 16:51:51, 3] lib/privileges.c:get_privileges(249)
  get_privileges: No privileges assigned to SID [S-1-5-2]
[2005/09/19 16:51:51, 3] lib/privileges.c:get_privileges(249)
  get_privileges: No privileges assigned to SID [S-1-5-11]
[2005/09/19 16:51:51, 3] auth/auth.c:check_ntlm_password(268)
  check_ntlm_password: sam authentication for user [administrator] succeeded
[2005/09/19 16:51:51, 3] smbd/sec_ctx.c:push_sec_ctx(256)
  push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1
[2005/09/19 16:51:51, 3] smbd/uid.c:push_conn_ctx(365)
  push_conn_ctx(0) : conn_ctx_stack_ndx = 0
[2005/09/19 16:51:51, 3] smbd/sec_ctx.c:set_sec_ctx(288)
  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1
[2005/09/19 16:51:51, 4] auth/pampass.c:smb_pam_start(459)
  smb_pam_start: PAM: Init user: Administrator
[2005/09/19 16:51:51, 4] auth/pampass.c:smb_pam_start(476)
  smb_pam_start: PAM: setting rhost to: 192.168.10.169
[2005/09/19 16:51:51, 4] auth/pampass.c:smb_pam_start(485)
  smb_pam_start: PAM: setting tty
[2005/09/19 16:51:51, 4] auth/pampass.c:smb_pam_start(493)
  smb_pam_start: PAM: Init passed for user: Administrator
[2005/09/19 16:51:51, 4] auth/pampass.c:smb_pam_account(551)
  smb_pam_account: PAM: Account Management for User: Administrator
[2005/09/19 16:51:51, 4] auth/pampass.c:smb_pam_account(570)
  smb_pam_account: PAM: Account OK for User: Administrator
[2005/09/19 16:51:51, 4] auth/pampass.c:smb_pam_end(440)
  smb_pam_end: PAM: PAM_END OK.
[2005/09/19 16:51:51, 3] smbd/sec_ctx.c:pop_sec_ctx(386)
  pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0
[2005/09/19 16:51:51, 2] auth/auth.c:check_ntlm_password(305)
  check_ntlm_password:  authentication for user [administrator] ->
[administrator] -> [Administrator] succeeded
[2005/09/19 16:51:51, 3] libsmb/ntlmssp_sign.c:ntlmssp_sign_init(319)
  NTLMSSP Sign/Seal - Initialising with flags:
[2005/09/19 16:51:51, 3] libsmb/ntlmssp.c:debug_ntlmssp_flags(62)
  Got NTLMSSP neg_flags=0x60088215
    NTLMSSP_NEGOTIATE_UNICODE
    NTLMSSP_REQUEST_TARGET
    NTLMSSP_NEGOTIATE_SIGN
    NTLMSSP_NEGOTIATE_NTLM
    NTLMSSP_NEGOTIATE_ALWAYS_SIGN
    NTLMSSP_NEGOTIATE_NTLM2
    NTLMSSP_NEGOTIATE_128
    NTLMSSP_NEGOTIATE_KEY_EXCH
[2005/09/19 16:51:51, 3] smbd/password.c:register_vuid(222)
  User name: Administrator	Real name: Administrator
[2005/09/19 16:51:51, 3] smbd/password.c:register_vuid(241)
  UNIX uid 998 is UNIX user Administrator, and will be vuid 100
[2005/09/19 16:51:51, 4] auth/pampass.c:smb_pam_start(459)
  smb_pam_start: PAM: Init user: Administrator
[2005/09/19 16:51:51, 4] auth/pampass.c:smb_pam_start(476)
  smb_pam_start: PAM: setting rhost to: 192.168.10.169
[2005/09/19 16:51:51, 4] auth/pampass.c:smb_pam_start(485)
  smb_pam_start: PAM: setting tty
[2005/09/19 16:51:51, 4] auth/pampass.c:smb_pam_start(493)
  smb_pam_start: PAM: Init passed for user: Administrator
[2005/09/19 16:51:51, 4] auth/pampass.c:smb_internal_pam_session(630)
  smb_internal_pam_session: PAM: tty set to: smb/17585/100
[2005/09/19 16:51:51, 4] auth/pampass.c:smb_pam_end(440)
  smb_pam_end: PAM: PAM_END OK.
[2005/09/19 16:51:51, 3] smbd/password.c:register_vuid(270)
  Adding homes service for user 'Administrator' using home directory:
'/home/Administrator'
[2005/09/19 16:51:51, 3] param/loadparm.c:lp_add_home(2368)
  adding home's share [Administrator] for user 'Administrator' at
'/home/Administrator'
[2005/09/19 16:51:51, 3] smbd/process.c:process_smb(1091)
  Transaction 4 of length 82
[2005/09/19 16:51:51, 3] smbd/process.c:switch_message(886)
  switch message SMBtconX (pid 17585) conn 0x0
[2005/09/19 16:51:51, 3] smbd/sec_ctx.c:set_sec_ctx(288)
  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0
[2005/09/19 16:51:51, 4] smbd/reply.c:reply_tcon_and_X(407)
  Client requested device type [?????] for share [IPC$]
[2005/09/19 16:51:51, 3] smbd/service.c:make_connection_snum(479)
  Connect path is '/tmp' for service [IPC$]
[2005/09/19 16:51:51, 4] rpc_server/srv_srvsvc_nt.c:get_share_security(217)
  get_share_security: using default secdesc for IPC$
[2005/09/19 16:51:51, 3] lib/util_seaccess.c:se_access_check(251)
[2005/09/19 16:51:51, 3] lib/util_seaccess.c:se_access_check(252)
  se_access_check: user sid is S-1-5-21-4087610795-3070336623-1441377821-2996
  se_access_check: also S-1-5-21-4087610795-3070336623-1441377821-512
  se_access_check: also S-1-1-0
  se_access_check: also S-1-5-2
  se_access_check: also S-1-5-11
  se_access_check: also S-1-5-32-544
[2005/09/19 16:51:51, 3] smbd/vfs.c:vfs_init_default(206)
  Initialising default vfs hooks
[2005/09/19 16:51:51, 4] rpc_server/srv_srvsvc_nt.c:get_share_security(217)
  get_share_security: using default secdesc for IPC$
[2005/09/19 16:51:51, 3] lib/util_seaccess.c:se_access_check(251)
[2005/09/19 16:51:51, 3] lib/util_seaccess.c:se_access_check(252)
  se_access_check: user sid is S-1-5-21-4087610795-3070336623-1441377821-2996
  se_access_check: also S-1-5-21-4087610795-3070336623-1441377821-512
  se_access_check: also S-1-1-0
  se_access_check: also S-1-5-2
  se_access_check: also S-1-5-11
  se_access_check: also S-1-5-32-544
[2005/09/19 16:51:51, 3] smbd/sec_ctx.c:set_sec_ctx(288)
  setting sec ctx (998, 544) - sec_ctx_stack_ndx = 0
[2005/09/19 16:51:51, 3] smbd/service.c:make_connection_snum(642)
  billgates (192.168.10.169) connect to service IPC$ initially as user
Administrator (uid=998, gid=544) (pid 17585)
[2005/09/19 16:51:51, 3] smbd/sec_ctx.c:set_sec_ctx(288)
  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0
[2005/09/19 16:51:51, 3] smbd/reply.c:reply_tcon_and_X(455)
  tconX service=IPC$ 
[2005/09/19 16:51:51, 3] smbd/process.c:process_smb(1091)
  Transaction 5 of length 104
[2005/09/19 16:51:51, 3] smbd/process.c:switch_message(886)
  switch message SMBntcreateX (pid 17585) conn 0x837e010
[2005/09/19 16:51:51, 3] smbd/sec_ctx.c:set_sec_ctx(288)
  setting sec ctx (998, 544) - sec_ctx_stack_ndx = 0
[2005/09/19 16:51:51, 4] smbd/vfs.c:vfs_ChDir(660)
  vfs_ChDir to /tmp
[2005/09/19 16:51:51, 4] smbd/nttrans.c:nt_open_pipe(497)
  nt_open_pipe: Opening pipe \lsarpc.
[2005/09/19 16:51:51, 3] smbd/nttrans.c:nt_open_pipe(514)
  nt_open_pipe: Known pipe lsarpc opening.
[2005/09/19 16:51:51, 4] rpc_server/srv_pipe_hnd.c:open_rpc_pipe_p(178)
  Open pipe requested lsarpc (pipes_open=0)
[2005/09/19 16:51:51, 4] rpc_server/srv_pipe_hnd.c:make_internal_rpc_pipe_p(278)
  Create pipe requested lsarpc
[2005/09/19 16:51:51, 4] rpc_server/srv_pipe_hnd.c:make_internal_rpc_pipe_p(370)
  Created internal pipe lsarpc (pipes_open=0)
[2005/09/19 16:51:51, 4] rpc_server/srv_pipe_hnd.c:open_rpc_pipe_p(257)
  Opened pipe lsarpc with handle 7056 (pipes_open=1)
[2005/09/19 16:51:51, 3] smbd/process.c:process_smb(1091)
  Transaction 6 of length 140
[2005/09/19 16:51:51, 3] smbd/process.c:switch_message(886)
  switch message SMBwriteX (pid 17585) conn 0x837e010
[2005/09/19 16:51:51, 4] smbd/uid.c:change_to_user(194)
  change_to_user: Skipping user change - already user
[2005/09/19 16:51:51, 4] rpc_server/srv_pipe_hnd.c:get_rpc_pipe(1168)
  search for pipe pnum=7056
[2005/09/19 16:51:51, 3] rpc_server/srv_pipe.c:api_pipe_bind_req(887)
  api_pipe_bind_req: \PIPE\lsarpc -> \PIPE\lsass
[2005/09/19 16:51:51, 3] rpc_server/srv_pipe.c:check_bind_req(762)
  check_bind_req for \PIPE\lsarpc
[2005/09/19 16:51:51, 3] smbd/pipes.c:reply_pipe_write_and_X(199)
  writeX-IPC pnum=7056 nwritten=72
[2005/09/19 16:51:51, 3] smbd/process.c:process_smb(1091)
  Transaction 7 of length 63
[2005/09/19 16:51:51, 3] smbd/process.c:switch_message(886)
  switch message SMBreadX (pid 17585) conn 0x837e010
[2005/09/19 16:51:51, 4] smbd/uid.c:change_to_user(194)
  change_to_user: Skipping user change - already user
[2005/09/19 16:51:51, 4] rpc_server/srv_pipe_hnd.c:get_rpc_pipe(1168)
  search for pipe pnum=7056
[2005/09/19 16:51:51, 3] smbd/pipes.c:reply_pipe_read_and_X(242)
  readX-IPC pnum=7056 min=1024 max=1024 nread=68
[2005/09/19 16:51:51, 3] smbd/process.c:process_smb(1091)
  Transaction 8 of length 176
[2005/09/19 16:51:51, 3] smbd/process.c:switch_message(886)
  switch message SMBtrans (pid 17585) conn 0x837e010
[2005/09/19 16:51:51, 4] smbd/uid.c:change_to_user(194)
  change_to_user: Skipping user change - already user
[2005/09/19 16:51:51, 3] smbd/ipc.c:reply_trans(539)
  trans <\PIPE\> data=88 params=0 setup=2
[2005/09/19 16:51:51, 3] smbd/ipc.c:named_pipe(334)
  named pipe command on <> name
[2005/09/19 16:51:51, 4] rpc_server/srv_pipe_hnd.c:get_rpc_pipe(1168)
  search for pipe pnum=7056
[2005/09/19 16:51:51, 3] smbd/ipc.c:api_fd_reply(294)
  Got API command 0x26 on pipe "lsarpc" (pnum 7056)
[2005/09/19 16:51:51, 3] rpc_server/srv_pipe_hnd.c:free_pipe_context(542)
  free_pipe_context: destroying talloc pool of size 0
[2005/09/19 16:51:51, 4] rpc_server/srv_pipe.c:api_rpcTNP(1531)
  api_rpcTNP: lsarpc op 0x2c - api_rpcTNP: rpc command: LSA_OPENPOLICY2
[2005/09/19 16:51:51, 3] lib/util_seaccess.c:se_access_check(251)
[2005/09/19 16:51:51, 3] lib/util_seaccess.c:se_access_check(252)
  se_access_check: user sid is S-1-5-21-4087610795-3070336623-1441377821-2996
  se_access_check: also S-1-5-21-4087610795-3070336623-1441377821-512
  se_access_check: also S-1-1-0
  se_access_check: also S-1-5-2
  se_access_check: also S-1-5-11
  se_access_check: also S-1-5-32-544
[2005/09/19 16:51:51, 4] rpc_server/srv_lsa_hnd.c:create_policy_hnd(142)
  Opened policy hnd[1] [000] 00 00 00 00 01 00 00 00  00 00 00 00 E7 24 2F 43 
........ .....$/C
  [010] B1 44 00 00                                       .D.. 
[2005/09/19 16:51:51, 3] rpc_server/srv_pipe_hnd.c:free_pipe_context(542)
  free_pipe_context: destroying talloc pool of size 818
[2005/09/19 16:51:51, 3] smbd/process.c:process_smb(1091)
  Transaction 9 of length 134
[2005/09/19 16:51:51, 3] smbd/process.c:switch_message(886)
  switch message SMBtrans (pid 17585) conn 0x837e010
[2005/09/19 16:51:51, 4] smbd/uid.c:change_to_user(194)
  change_to_user: Skipping user change - already user
[2005/09/19 16:51:51, 3] smbd/ipc.c:reply_trans(539)
  trans <\PIPE\> data=46 params=0 setup=2
[2005/09/19 16:51:51, 3] smbd/ipc.c:named_pipe(334)
  named pipe command on <> name
[2005/09/19 16:51:51, 4] rpc_server/srv_pipe_hnd.c:get_rpc_pipe(1168)
  search for pipe pnum=7056
[2005/09/19 16:51:51, 3] smbd/ipc.c:api_fd_reply(294)
  Got API command 0x26 on pipe "lsarpc" (pnum 7056)
[2005/09/19 16:51:51, 3] rpc_server/srv_pipe_hnd.c:free_pipe_context(542)
  free_pipe_context: destroying talloc pool of size 0
[2005/09/19 16:51:51, 4] rpc_server/srv_pipe.c:api_rpcTNP(1531)
  api_rpcTNP: lsarpc op 0x2e - unknown
[2005/09/19 16:51:51, 3] rpc_server/srv_pipe_hnd.c:free_pipe_context(542)
  free_pipe_context: destroying talloc pool of size 0
[2005/09/19 16:51:51, 3] smbd/process.c:process_smb(1091)
  Transaction 10 of length 134
[2005/09/19 16:51:51, 3] smbd/process.c:switch_message(886)
  switch message SMBtrans (pid 17585) conn 0x837e010
[2005/09/19 16:51:51, 4] smbd/uid.c:change_to_user(194)
  change_to_user: Skipping user change - already user
[2005/09/19 16:51:51, 3] smbd/ipc.c:reply_trans(539)
  trans <\PIPE\> data=46 params=0 setup=2
[2005/09/19 16:51:51, 3] smbd/ipc.c:named_pipe(334)
  named pipe command on <> name
[2005/09/19 16:51:51, 4] rpc_server/srv_pipe_hnd.c:get_rpc_pipe(1168)
  search for pipe pnum=7056
[2005/09/19 16:51:51, 3] smbd/ipc.c:api_fd_reply(294)
  Got API command 0x26 on pipe "lsarpc" (pnum 7056)
[2005/09/19 16:51:51, 3] rpc_server/srv_pipe_hnd.c:free_pipe_context(542)
  free_pipe_context: destroying talloc pool of size 0
[2005/09/19 16:51:51, 4] rpc_server/srv_pipe.c:api_rpcTNP(1531)
  api_rpcTNP: lsarpc op 0x7 - api_rpcTNP: rpc command: LSA_QUERYINFOPOLICY
[2005/09/19 16:51:51, 4]
rpc_server/srv_lsa_hnd.c:find_policy_by_hnd_internal(162)
  Found policy hnd[0] [000] 00 00 00 00 01 00 00 00  00 00 00 00 E7 24 2F 43 
........ .....$/C
  [010] B1 44 00 00                                       .D.. 
[2005/09/19 16:51:51, 3] rpc_server/srv_pipe_hnd.c:free_pipe_context(542)
  free_pipe_context: destroying talloc pool of size 20
[2005/09/19 16:51:51, 3] smbd/process.c:process_smb(1091)
  Transaction 11 of length 104
[2005/09/19 16:51:51, 3] smbd/process.c:switch_message(886)
  switch message SMBntcreateX (pid 17585) conn 0x837e010
[2005/09/19 16:51:51, 4] smbd/uid.c:change_to_user(194)
  change_to_user: Skipping user change - already user
[2005/09/19 16:51:51, 4] smbd/nttrans.c:nt_open_pipe(497)
  nt_open_pipe: Opening pipe \winreg.
[2005/09/19 16:51:51, 3] smbd/nttrans.c:nt_open_pipe(514)
  nt_open_pipe: Known pipe winreg opening.
[2005/09/19 16:51:51, 4] rpc_server/srv_pipe_hnd.c:open_rpc_pipe_p(178)
  Open pipe requested winreg (pipes_open=1)
[2005/09/19 16:51:51, 4] rpc_server/srv_pipe_hnd.c:make_internal_rpc_pipe_p(278)
  Create pipe requested winreg
[2005/09/19 16:51:51, 4] rpc_server/srv_pipe_hnd.c:make_internal_rpc_pipe_p(370)
  Created internal pipe winreg (pipes_open=1)
[2005/09/19 16:51:51, 4] rpc_server/srv_pipe_hnd.c:open_rpc_pipe_p(257)
  Opened pipe winreg with handle 7057 (pipes_open=2)
[2005/09/19 16:51:51, 3] smbd/process.c:process_smb(1091)
  Transaction 12 of length 140
[2005/09/19 16:51:51, 3] smbd/process.c:switch_message(886)
  switch message SMBwriteX (pid 17585) conn 0x837e010
[2005/09/19 16:51:51, 4] smbd/uid.c:change_to_user(194)
  change_to_user: Skipping user change - already user
[2005/09/19 16:51:51, 4] rpc_server/srv_pipe_hnd.c:get_rpc_pipe(1168)
  search for pipe pnum=7057
[2005/09/19 16:51:51, 3] rpc_server/srv_pipe.c:api_pipe_bind_req(887)
  api_pipe_bind_req: \PIPE\winreg -> \PIPE\winreg
[2005/09/19 16:51:51, 3] rpc_server/srv_pipe.c:check_bind_req(762)
  check_bind_req for \PIPE\winreg
[2005/09/19 16:51:51, 3] smbd/pipes.c:reply_pipe_write_and_X(199)
  writeX-IPC pnum=7057 nwritten=72
[2005/09/19 16:51:51, 3] smbd/process.c:process_smb(1091)
  Transaction 13 of length 63
[2005/09/19 16:51:51, 3] smbd/process.c:switch_message(886)
  switch message SMBreadX (pid 17585) conn 0x837e010
[2005/09/19 16:51:51, 4] smbd/uid.c:change_to_user(194)
  change_to_user: Skipping user change - already user
[2005/09/19 16:51:51, 4] rpc_server/srv_pipe_hnd.c:get_rpc_pipe(1168)
  search for pipe pnum=7057
[2005/09/19 16:51:51, 3] smbd/pipes.c:reply_pipe_read_and_X(242)
  readX-IPC pnum=7057 min=1024 max=1024 nread=68
[2005/09/19 16:51:51, 3] smbd/process.c:process_smb(1091)
  Transaction 14 of length 124
[2005/09/19 16:51:51, 3] smbd/process.c:switch_message(886)
  switch message SMBtrans (pid 17585) conn 0x837e010
[2005/09/19 16:51:51, 4] smbd/uid.c:change_to_user(194)
  change_to_user: Skipping user change - already user
[2005/09/19 16:51:51, 3] smbd/ipc.c:reply_trans(539)
  trans <\PIPE\> data=36 params=0 setup=2
[2005/09/19 16:51:51, 3] smbd/ipc.c:named_pipe(334)
  named pipe command on <> name
[2005/09/19 16:51:51, 4] rpc_server/srv_pipe_hnd.c:get_rpc_pipe(1168)
  search for pipe pnum=7057
[2005/09/19 16:51:51, 3] smbd/ipc.c:api_fd_reply(294)
  Got API command 0x26 on pipe "winreg" (pnum 7057)
[2005/09/19 16:51:51, 3] rpc_server/srv_pipe_hnd.c:free_pipe_context(542)
  free_pipe_context: destroying talloc pool of size 0
[2005/09/19 16:51:51, 4] rpc_server/srv_pipe.c:api_rpcTNP(1531)
  api_rpcTNP: winreg op 0x2 - api_rpcTNP: rpc command: REG_OPEN_HKLM
[2005/09/19 16:51:51, 4] rpc_server/srv_lsa_hnd.c:create_policy_hnd(142)
  Opened policy hnd[1] [000] 00 00 00 00 02 00 00 00  00 00 00 00 E7 24 2F 43 
........ .....$/C
  [010] B1 44 00 00                                       .D.. 
[2005/09/19 16:51:51, 3] rpc_server/srv_pipe_hnd.c:free_pipe_context(542)
  free_pipe_context: destroying talloc pool of size 0
[2005/09/19 16:51:51, 3] smbd/process.c:process_smb(1091)
  Transaction 15 of length 272
[2005/09/19 16:51:51, 3] smbd/process.c:switch_message(886)
  switch message SMBtrans (pid 17585) conn 0x837e010
[2005/09/19 16:51:51, 4] smbd/uid.c:change_to_user(194)
  change_to_user: Skipping user change - already user
[2005/09/19 16:51:51, 3] smbd/ipc.c:reply_trans(539)
  trans <\PIPE\> data=184 params=0 setup=2
[2005/09/19 16:51:51, 3] smbd/ipc.c:named_pipe(334)
  named pipe command on <> name
[2005/09/19 16:51:51, 4] rpc_server/srv_pipe_hnd.c:get_rpc_pipe(1168)
  search for pipe pnum=7057
[2005/09/19 16:51:51, 3] smbd/ipc.c:api_fd_reply(294)
  Got API command 0x26 on pipe "winreg" (pnum 7057)
[2005/09/19 16:51:51, 3] rpc_server/srv_pipe_hnd.c:free_pipe_context(542)
  free_pipe_context: destroying talloc pool of size 0
[2005/09/19 16:51:51, 4] rpc_server/srv_pipe.c:api_rpcTNP(1531)
  api_rpcTNP: winreg op 0xf - api_rpcTNP: rpc command: REG_OPEN_ENTRY
[2005/09/19 16:51:51, 4]
rpc_server/srv_lsa_hnd.c:find_policy_by_hnd_internal(162)
  Found policy hnd[0] [000] 00 00 00 00 02 00 00 00  00 00 00 00 E7 24 2F 43 
........ .....$/C
  [010] B1 44 00 00                                       .D.. 
[2005/09/19 16:51:51, 4] rpc_server/srv_lsa_hnd.c:create_policy_hnd(142)
  Opened policy hnd[2] [000] 00 00 00 00 03 00 00 00  00 00 00 00 E7 24 2F 43 
........ .....$/C
  [010] B1 44 00 00                                       .D.. 
[2005/09/19 16:51:51, 3] rpc_server/srv_pipe_hnd.c:free_pipe_context(542)
  free_pipe_context: destroying talloc pool of size 110
[2005/09/19 16:51:52, 3] smbd/process.c:process_smb(1091)
  Transaction 16 of length 236
[2005/09/19 16:51:52, 3] smbd/process.c:switch_message(886)
  switch message SMBtrans (pid 17585) conn 0x837e010
[2005/09/19 16:51:52, 4] smbd/uid.c:change_to_user(194)
  change_to_user: Skipping user change - already user
[2005/09/19 16:51:52, 3] smbd/ipc.c:reply_trans(539)
  trans <\PIPE\> data=148 params=0 setup=2
[2005/09/19 16:51:52, 3] smbd/ipc.c:named_pipe(334)
  named pipe command on <> name
[2005/09/19 16:51:52, 4] rpc_server/srv_pipe_hnd.c:get_rpc_pipe(1168)
  search for pipe pnum=7057
[2005/09/19 16:51:52, 3] smbd/ipc.c:api_fd_reply(294)
  Got API command 0x26 on pipe "winreg" (pnum 7057)
[2005/09/19 16:51:52, 3] rpc_server/srv_pipe_hnd.c:free_pipe_context(542)
  free_pipe_context: destroying talloc pool of size 0
[2005/09/19 16:51:52, 4] rpc_server/srv_pipe.c:api_rpcTNP(1531)
  api_rpcTNP: winreg op 0x11 - api_rpcTNP: rpc command: REG_INFO
[2005/09/19 16:51:52, 4]
rpc_server/srv_lsa_hnd.c:find_policy_by_hnd_internal(162)
  Found policy hnd[0] [000] 00 00 00 00 03 00 00 00  00 00 00 00 E7 24 2F 43 
........ .....$/C
  [010] B1 44 00 00                                       .D.. 
[2005/09/19 16:51:52, 3] rpc_server/srv_pipe_hnd.c:free_pipe_context(542)
  free_pipe_context: destroying talloc pool of size 46
[2005/09/19 16:51:52, 3] smbd/process.c:process_smb(1091)
  Transaction 17 of length 132
[2005/09/19 16:51:52, 3] smbd/process.c:switch_message(886)
  switch message SMBtrans (pid 17585) conn 0x837e010
[2005/09/19 16:51:52, 4] smbd/uid.c:change_to_user(194)
  change_to_user: Skipping user change - already user
[2005/09/19 16:51:52, 3] smbd/ipc.c:reply_trans(539)
  trans <\PIPE\> data=44 params=0 setup=2
[2005/09/19 16:51:52, 3] smbd/ipc.c:named_pipe(334)
  named pipe command on <> name
[2005/09/19 16:51:52, 4] rpc_server/srv_pipe_hnd.c:get_rpc_pipe(1168)
  search for pipe pnum=7057
[2005/09/19 16:51:52, 3] smbd/ipc.c:api_fd_reply(294)
  Got API command 0x26 on pipe "winreg" (pnum 7057)
[2005/09/19 16:51:52, 3] rpc_server/srv_pipe_hnd.c:free_pipe_context(542)
  free_pipe_context: destroying talloc pool of size 0
[2005/09/19 16:51:52, 4] rpc_server/srv_pipe.c:api_rpcTNP(1531)
  api_rpcTNP: winreg op 0x5 - api_rpcTNP: rpc command: REG_CLOSE
[2005/09/19 16:51:52, 4]
rpc_server/srv_lsa_hnd.c:find_policy_by_hnd_internal(162)
  Found policy hnd[0] [000] 00 00 00 00 03 00 00 00  00 00 00 00 E7 24 2F 43 
........ .....$/C
  [010] B1 44 00 00                                       .D.. 
[2005/09/19 16:51:52, 4]
rpc_server/srv_lsa_hnd.c:find_policy_by_hnd_internal(162)
  Found policy hnd[0] [000] 00 00 00 00 03 00 00 00  00 00 00 00 E7 24 2F 43 
........ .....$/C
  [010] B1 44 00 00                                       .D.. 
[2005/09/19 16:51:52, 3] rpc_server/srv_lsa_hnd.c:close_policy_hnd(200)
  Closed policy
[2005/09/19 16:51:52, 3] rpc_server/srv_pipe_hnd.c:free_pipe_context(542)
  free_pipe_context: destroying talloc pool of size 0
[2005/09/19 16:51:52, 3] smbd/process.c:process_smb(1091)
  Transaction 18 of length 132
[2005/09/19 16:51:52, 3] smbd/process.c:switch_message(886)
  switch message SMBtrans (pid 17585) conn 0x837e010
[2005/09/19 16:51:52, 4] smbd/uid.c:change_to_user(194)
  change_to_user: Skipping user change - already user
[2005/09/19 16:51:52, 3] smbd/ipc.c:reply_trans(539)
  trans <\PIPE\> data=44 params=0 setup=2
[2005/09/19 16:51:52, 3] smbd/ipc.c:named_pipe(334)
  named pipe command on <> name
[2005/09/19 16:51:52, 4] rpc_server/srv_pipe_hnd.c:get_rpc_pipe(1168)
  search for pipe pnum=7057
[2005/09/19 16:51:52, 3] smbd/ipc.c:api_fd_reply(294)
  Got API command 0x26 on pipe "winreg" (pnum 7057)
[2005/09/19 16:51:52, 3] rpc_server/srv_pipe_hnd.c:free_pipe_context(542)
  free_pipe_context: destroying talloc pool of size 0
[2005/09/19 16:51:52, 4] rpc_server/srv_pipe.c:api_rpcTNP(1531)
  api_rpcTNP: winreg op 0x5 - api_rpcTNP: rpc command: REG_CLOSE
[2005/09/19 16:51:52, 4]
rpc_server/srv_lsa_hnd.c:find_policy_by_hnd_internal(162)
  Found policy hnd[0] [000] 00 00 00 00 02 00 00 00  00 00 00 00 E7 24 2F 43 
........ .....$/C
  [010] B1 44 00 00                                       .D.. 
[2005/09/19 16:51:52, 4]
rpc_server/srv_lsa_hnd.c:find_policy_by_hnd_internal(162)
  Found policy hnd[0] [000] 00 00 00 00 02 00 00 00  00 00 00 00 E7 24 2F 43 
........ .....$/C
  [010] B1 44 00 00                                       .D.. 
[2005/09/19 16:51:52, 3] rpc_server/srv_lsa_hnd.c:close_policy_hnd(200)
  Closed policy
[2005/09/19 16:51:52, 3] rpc_server/srv_pipe_hnd.c:free_pipe_context(542)
  free_pipe_context: destroying talloc pool of size 0
[2005/09/19 16:51:52, 3] smbd/process.c:process_smb(1091)
  Transaction 19 of length 45
[2005/09/19 16:51:52, 3] smbd/process.c:switch_message(886)
  switch message SMBclose (pid 17585) conn 0x837e010
[2005/09/19 16:51:52, 4] smbd/uid.c:change_to_user(194)
  change_to_user: Skipping user change - already user
[2005/09/19 16:51:52, 4] rpc_server/srv_pipe_hnd.c:get_rpc_pipe(1168)
  search for pipe pnum=7057
[2005/09/19 16:51:52, 4] rpc_server/srv_pipe_hnd.c:close_rpc_pipe_hnd(1081)
  closed pipe name winreg pnum=7057 (pipes_open=1)
[2005/09/19 16:51:52, 3] smbd/process.c:process_smb(1091)
  Transaction 20 of length 108
[2005/09/19 16:51:52, 3] smbd/process.c:switch_message(886)
  switch message SMBntcreateX (pid 17585) conn 0x837e010
[2005/09/19 16:51:52, 4] smbd/uid.c:change_to_user(194)
  change_to_user: Skipping user change - already user
[2005/09/19 16:51:52, 4] smbd/nttrans.c:nt_open_pipe(497)
  nt_open_pipe: Opening pipe \NETLOGON.
[2005/09/19 16:51:52, 3] smbd/nttrans.c:nt_open_pipe(514)
  nt_open_pipe: Known pipe NETLOGON opening.
[2005/09/19 16:51:52, 4] rpc_server/srv_pipe_hnd.c:open_rpc_pipe_p(178)
  Open pipe requested NETLOGON (pipes_open=1)
[2005/09/19 16:51:52, 4] rpc_server/srv_pipe_hnd.c:make_internal_rpc_pipe_p(278)
  Create pipe requested NETLOGON
[2005/09/19 16:51:52, 4] rpc_server/srv_pipe_hnd.c:make_internal_rpc_pipe_p(370)
  Created internal pipe NETLOGON (pipes_open=1)
[2005/09/19 16:51:52, 4] rpc_server/srv_pipe_hnd.c:open_rpc_pipe_p(257)
  Opened pipe NETLOGON with handle 7058 (pipes_open=2)
[2005/09/19 16:51:52, 3] smbd/process.c:process_smb(1091)
  Transaction 21 of length 140
[2005/09/19 16:51:52, 3] smbd/process.c:switch_message(886)
  switch message SMBwriteX (pid 17585) conn 0x837e010
[2005/09/19 16:51:52, 4] smbd/uid.c:change_to_user(194)
  change_to_user: Skipping user change - already user
[2005/09/19 16:51:52, 4] rpc_server/srv_pipe_hnd.c:get_rpc_pipe(1168)
  search for pipe pnum=7058
[2005/09/19 16:51:52, 3] rpc_server/srv_pipe.c:api_pipe_bind_req(887)
  api_pipe_bind_req: \PIPE\NETLOGON -> \PIPE\lsass
[2005/09/19 16:51:52, 3] rpc_server/srv_pipe.c:check_bind_req(762)
  check_bind_req for \PIPE\NETLOGON
[2005/09/19 16:51:52, 3] smbd/pipes.c:reply_pipe_write_and_X(199)
  writeX-IPC pnum=7058 nwritten=72
[2005/09/19 16:51:52, 3] smbd/process.c:process_smb(1091)
  Transaction 22 of length 63
[2005/09/19 16:51:52, 3] smbd/process.c:switch_message(886)
  switch message SMBreadX (pid 17585) conn 0x837e010
[2005/09/19 16:51:52, 4] smbd/uid.c:change_to_user(194)
  change_to_user: Skipping user change - already user
[2005/09/19 16:51:52, 4] rpc_server/srv_pipe_hnd.c:get_rpc_pipe(1168)
  search for pipe pnum=7058
[2005/09/19 16:51:52, 3] smbd/pipes.c:reply_pipe_read_and_X(242)
  readX-IPC pnum=7058 min=1024 max=1024 nread=68
[2005/09/19 16:51:52, 3] smbd/process.c:process_smb(1091)
  Transaction 23 of length 188
[2005/09/19 16:51:52, 3] smbd/process.c:switch_message(886)
  switch message SMBtrans (pid 17585) conn 0x837e010
[2005/09/19 16:51:52, 4] smbd/uid.c:change_to_user(194)
  change_to_user: Skipping user change - already user
[2005/09/19 16:51:52, 3] smbd/ipc.c:reply_trans(539)
  trans <\PIPE\> data=100 params=0 setup=2
[2005/09/19 16:51:52, 3] smbd/ipc.c:named_pipe(334)
  named pipe command on <> name
[2005/09/19 16:51:52, 4] rpc_server/srv_pipe_hnd.c:get_rpc_pipe(1168)
  search for pipe pnum=7058
[2005/09/19 16:51:52, 3] smbd/ipc.c:api_fd_reply(294)
  Got API command 0x26 on pipe "NETLOGON" (pnum 7058)
[2005/09/19 16:51:52, 3] rpc_server/srv_pipe_hnd.c:free_pipe_context(542)
  free_pipe_context: destroying talloc pool of size 0
[2005/09/19 16:51:52, 4] rpc_server/srv_pipe.c:api_rpcTNP(1531)
  api_rpcTNP: NETLOGON op 0x4 - api_rpcTNP: rpc command: NET_REQCHAL
[2005/09/19 16:51:52, 3] rpc_server/srv_pipe_hnd.c:free_pipe_context(542)
  free_pipe_context: destroying talloc pool of size 38
[2005/09/19 16:51:52, 3] smbd/process.c:process_smb(1091)
  Transaction 24 of length 45
[2005/09/19 16:51:52, 3] smbd/process.c:switch_message(886)
  switch message SMBclose (pid 17585) conn 0x837e010
[2005/09/19 16:51:52, 4] smbd/uid.c:change_to_user(194)
  change_to_user: Skipping user change - already user
[2005/09/19 16:51:52, 4] rpc_server/srv_pipe_hnd.c:get_rpc_pipe(1168)
  search for pipe pnum=7058
[2005/09/19 16:51:52, 4] rpc_server/srv_pipe_hnd.c:close_rpc_pipe_hnd(1081)
  closed pipe name NETLOGON pnum=7058 (pipes_open=1)
[2005/09/19 16:51:52, 3] smbd/process.c:process_smb(1091)
  Transaction 25 of length 108
[2005/09/19 16:51:52, 3] smbd/process.c:switch_message(886)
  switch message SMBntcreateX (pid 17585) conn 0x837e010
[2005/09/19 16:51:52, 4] smbd/uid.c:change_to_user(194)
  change_to_user: Skipping user change - already user
[2005/09/19 16:51:52, 4] smbd/nttrans.c:nt_open_pipe(497)
  nt_open_pipe: Opening pipe \NETLOGON.
[2005/09/19 16:51:52, 3] smbd/nttrans.c:nt_open_pipe(514)
  nt_open_pipe: Known pipe NETLOGON opening.
[2005/09/19 16:51:52, 4] rpc_server/srv_pipe_hnd.c:open_rpc_pipe_p(178)
  Open pipe requested NETLOGON (pipes_open=1)
[2005/09/19 16:51:52, 4] rpc_server/srv_pipe_hnd.c:make_internal_rpc_pipe_p(278)
  Create pipe requested NETLOGON
[2005/09/19 16:51:52, 4] rpc_server/srv_pipe_hnd.c:make_internal_rpc_pipe_p(370)
  Created internal pipe NETLOGON (pipes_open=1)
[2005/09/19 16:51:52, 4] rpc_server/srv_pipe_hnd.c:open_rpc_pipe_p(257)
  Opened pipe NETLOGON with handle 7059 (pipes_open=2)
[2005/09/19 16:51:52, 3] smbd/process.c:process_smb(1091)
  Transaction 26 of length 140
[2005/09/19 16:51:52, 3] smbd/process.c:switch_message(886)
  switch message SMBwriteX (pid 17585) conn 0x837e010
[2005/09/19 16:51:52, 4] smbd/uid.c:change_to_user(194)
  change_to_user: Skipping user change - already user
[2005/09/19 16:51:52, 4] rpc_server/srv_pipe_hnd.c:get_rpc_pipe(1168)
  search for pipe pnum=7059
[2005/09/19 16:51:52, 3] rpc_server/srv_pipe.c:api_pipe_bind_req(887)
  api_pipe_bind_req: \PIPE\NETLOGON -> \PIPE\lsass
[2005/09/19 16:51:52, 3] rpc_server/srv_pipe.c:check_bind_req(762)
  check_bind_req for \PIPE\NETLOGON
[2005/09/19 16:51:52, 3] smbd/pipes.c:reply_pipe_write_and_X(199)
  writeX-IPC pnum=7059 nwritten=72
[2005/09/19 16:51:52, 3] smbd/process.c:process_smb(1091)
  Transaction 27 of length 63
[2005/09/19 16:51:52, 3] smbd/process.c:switch_message(886)
  switch message SMBreadX (pid 17585) conn 0x837e010
[2005/09/19 16:51:52, 4] smbd/uid.c:change_to_user(194)
  change_to_user: Skipping user change - already user
[2005/09/19 16:51:52, 4] rpc_server/srv_pipe_hnd.c:get_rpc_pipe(1168)
  search for pipe pnum=7059
[2005/09/19 16:51:52, 3] smbd/pipes.c:reply_pipe_read_and_X(242)
  readX-IPC pnum=7059 min=1024 max=1024 nread=68
[2005/09/19 16:51:52, 3] smbd/process.c:process_smb(1091)
  Transaction 28 of length 224
[2005/09/19 16:51:52, 3] smbd/process.c:switch_message(886)
  switch message SMBtrans (pid 17585) conn 0x837e010
[2005/09/19 16:51:52, 4] smbd/uid.c:change_to_user(194)
  change_to_user: Skipping user change - already user
[2005/09/19 16:51:52, 3] smbd/ipc.c:reply_trans(539)
  trans <\PIPE\> data=136 params=0 setup=2
[2005/09/19 16:51:52, 3] smbd/ipc.c:named_pipe(334)
  named pipe command on <> name
[2005/09/19 16:51:52, 4] rpc_server/srv_pipe_hnd.c:get_rpc_pipe(1168)
  search for pipe pnum=7059
[2005/09/19 16:51:52, 3] smbd/ipc.c:api_fd_reply(294)
  Got API command 0x26 on pipe "NETLOGON" (pnum 7059)
[2005/09/19 16:51:52, 3] rpc_server/srv_pipe_hnd.c:free_pipe_context(542)
  free_pipe_context: destroying talloc pool of size 0
[2005/09/19 16:51:52, 4] rpc_server/srv_pipe.c:api_rpcTNP(1531)
  api_rpcTNP: NETLOGON op 0x5 - api_rpcTNP: rpc command: NET_AUTH
[2005/09/19 16:51:52, 3] rpc_server/srv_pipe_hnd.c:free_pipe_context(542)
  free_pipe_context: destroying talloc pool of size 60
[2005/09/19 16:51:52, 3] smbd/process.c:process_smb(1091)
  Transaction 29 of length 45
[2005/09/19 16:51:52, 3] smbd/process.c:switch_message(886)
  switch message SMBclose (pid 17585) conn 0x837e010
[2005/09/19 16:51:52, 4] smbd/uid.c:change_to_user(194)
  change_to_user: Skipping user change - already user
[2005/09/19 16:51:52, 4] rpc_server/srv_pipe_hnd.c:get_rpc_pipe(1168)
  search for pipe pnum=7059
[2005/09/19 16:51:52, 4] rpc_server/srv_pipe_hnd.c:close_rpc_pipe_hnd(1081)
  closed pipe name NETLOGON pnum=7059 (pipes_open=1)
[2005/09/19 16:51:52, 3] smbd/process.c:process_smb(1091)
  Transaction 30 of length 132
[2005/09/19 16:51:52, 3] smbd/process.c:switch_message(886)
  switch message SMBtrans (pid 17585) conn 0x837e010
[2005/09/19 16:51:52, 4] smbd/uid.c:change_to_user(194)
  change_to_user: Skipping user change - already user
[2005/09/19 16:51:52, 3] smbd/ipc.c:reply_trans(539)
  trans <\PIPE\> data=44 params=0 setup=2
[2005/09/19 16:51:52, 3] smbd/ipc.c:named_pipe(334)
  named pipe command on <> name
[2005/09/19 16:51:52, 4] rpc_server/srv_pipe_hnd.c:get_rpc_pipe(1168)
  search for pipe pnum=7056
[2005/09/19 16:51:52, 3] smbd/ipc.c:api_fd_reply(294)
  Got API command 0x26 on pipe "lsarpc" (pnum 7056)
[2005/09/19 16:51:52, 3] rpc_server/srv_pipe_hnd.c:free_pipe_context(542)
  free_pipe_context: destroying talloc pool of size 0
[2005/09/19 16:51:52, 4] rpc_server/srv_pipe.c:api_rpcTNP(1531)
  api_rpcTNP: lsarpc op 0x0 - api_rpcTNP: rpc command: LSA_CLOSE
[2005/09/19 16:51:52, 4]
rpc_server/srv_lsa_hnd.c:find_policy_by_hnd_internal(162)
  Found policy hnd[0] [000] 00 00 00 00 01 00 00 00  00 00 00 00 E7 24 2F 43 
........ .....$/C
  [010] B1 44 00 00                                       .D.. 
[2005/09/19 16:51:52, 4]
rpc_server/srv_lsa_hnd.c:find_policy_by_hnd_internal(162)
  Found policy hnd[0] [000] 00 00 00 00 01 00 00 00  00 00 00 00 E7 24 2F 43 
........ .....$/C
  [010] B1 44 00 00                                       .D.. 
[2005/09/19 16:51:52, 3] rpc_server/srv_lsa_hnd.c:close_policy_hnd(200)
  Closed policy
[2005/09/19 16:51:52, 3] rpc_server/srv_pipe_hnd.c:free_pipe_context(542)
  free_pipe_context: destroying talloc pool of size 0
[2005/09/19 16:51:52, 3] smbd/process.c:process_smb(1091)
  Transaction 31 of length 45
[2005/09/19 16:51:52, 3] smbd/process.c:switch_message(886)
  switch message SMBclose (pid 17585) conn 0x837e010
[2005/09/19 16:51:52, 4] smbd/uid.c:change_to_user(194)
  change_to_user: Skipping user change - already user
[2005/09/19 16:51:52, 4] rpc_server/srv_pipe_hnd.c:get_rpc_pipe(1168)
  search for pipe pnum=7056
[2005/09/19 16:51:52, 4] rpc_server/srv_pipe_hnd.c:close_rpc_pipe_hnd(1081)
  closed pipe name lsarpc pnum=7056 (pipes_open=0)
[2005/09/19 16:51:52, 3] smbd/process.c:process_smb(1091)
  Transaction 32 of length 43
[2005/09/19 16:51:52, 3] smbd/process.c:switch_message(886)
  switch message SMBulogoffX (pid 17585) conn 0x0
[2005/09/19 16:51:52, 3] smbd/sec_ctx.c:set_sec_ctx(288)
  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0
[2005/09/19 16:51:52, 4] auth/pampass.c:smb_pam_start(459)
  smb_pam_start: PAM: Init user: Administrator
[2005/09/19 16:51:52, 4] auth/pampass.c:smb_pam_start(476)
  smb_pam_start: PAM: setting rhost to: 192.168.10.169
[2005/09/19 16:51:52, 4] auth/pampass.c:smb_pam_start(485)
  smb_pam_start: PAM: setting tty
[2005/09/19 16:51:52, 4] auth/pampass.c:smb_pam_start(493)
  smb_pam_start: PAM: Init passed for user: Administrator
[2005/09/19 16:51:52, 4] auth/pampass.c:smb_internal_pam_session(630)
  smb_internal_pam_session: PAM: tty set to: smb/17585/100
[2005/09/19 16:51:52, 4] auth/pampass.c:smb_pam_end(440)
  smb_pam_end: PAM: PAM_END OK.
[2005/09/19 16:51:52, 3] smbd/reply.c:reply_ulogoffX(1264)
  ulogoffX vuid=100
[2005/09/19 16:51:52, 3] smbd/process.c:process_smb(1091)
  Transaction 33 of length 39
[2005/09/19 16:51:52, 3] smbd/process.c:switch_message(886)
  switch message SMBtdis (pid 17585) conn 0x837e010
[2005/09/19 16:51:52, 3] smbd/sec_ctx.c:set_sec_ctx(288)
  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0
[2005/09/19 16:51:52, 3] smbd/sec_ctx.c:set_sec_ctx(288)
  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0
[2005/09/19 16:51:52, 3] smbd/service.c:close_cnum(830)
  billgates (192.168.10.169) closed connection to service IPC$
[2005/09/19 16:51:52, 3] smbd/connection.c:yield_connection(69)
  Yielding connection to IPC$
[2005/09/19 16:51:52, 4] smbd/vfs.c:vfs_ChDir(660)
  vfs_ChDir to /
[2005/09/19 16:51:52, 3] smbd/sec_ctx.c:set_sec_ctx(288)
  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0
[2005/09/19 16:51:52, 3] smbd/process.c:timeout_processing(1334)
  timeout_processing: End of file from client (client has disconnected).
[2005/09/19 16:51:52, 3] smbd/sec_ctx.c:set_sec_ctx(288)
  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0
[2005/09/19 16:51:52, 2] smbd/server.c:exit_server(609)
  Closing connections
[2005/09/19 16:51:52, 3] smbd/connection.c:yield_connection(69)
  Yielding connection to 
[2005/09/19 16:51:52, 3] smbd/server.c:exit_server(652)
  Server exit (normal exit)
[2005/09/19 16:51:52, 3] smbd/process.c:process_smb(1091)
  Transaction 1 of length 137
[2005/09/19 16:51:52, 3] smbd/process.c:switch_message(886)
  switch message SMBnegprot (pid 17586) conn 0x0
[2005/09/19 16:51:52, 3] smbd/sec_ctx.c:set_sec_ctx(288)
  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0
[2005/09/19 16:51:52, 3] smbd/negprot.c:reply_negprot(461)
  Requested protocol [PC NETWORK PROGRAM 1.0]
[2005/09/19 16:51:52, 3] smbd/negprot.c:reply_negprot(461)
  Requested protocol [LANMAN1.0]
[2005/09/19 16:51:52, 3] smbd/negprot.c:reply_negprot(461)
  Requested protocol [Windows for Workgroups 3.1a]
[2005/09/19 16:51:52, 3] smbd/negprot.c:reply_negprot(461)
  Requested protocol [LM1.2X002]
[2005/09/19 16:51:52, 3] smbd/negprot.c:reply_negprot(461)
  Requested protocol [LANMAN2.1]
[2005/09/19 16:51:52, 3] smbd/negprot.c:reply_negprot(461)
  Requested protocol [NT LM 0.12]
[2005/09/19 16:51:52, 3] smbd/negprot.c:reply_nt1(333)
  using SPNEGO
[2005/09/19 16:51:52, 3] smbd/negprot.c:reply_negprot(555)
  Selected protocol NT LM 0.12
[2005/09/19 16:51:52, 3] smbd/process.c:process_smb(1091)
  Transaction 2 of length 240
[2005/09/19 16:51:52, 3] smbd/process.c:switch_message(886)
  switch message SMBsesssetupX (pid 17586) conn 0x0
[2005/09/19 16:51:52, 3] smbd/sec_ctx.c:set_sec_ctx(288)
  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0
[2005/09/19 16:51:52, 3] smbd/sesssetup.c:reply_sesssetup_and_X(655)
  wct=12 flg2=0xc807
[2005/09/19 16:51:52, 2] smbd/sesssetup.c:setup_new_vc_session(608)
  setup_new_vc_session: New VC == 0, if NT4.x compatible we would close all old
resources.
[2005/09/19 16:51:52, 3] smbd/sesssetup.c:reply_sesssetup_and_X_spnego(535)
  Doing spnego session setup
[2005/09/19 16:51:52, 3] smbd/sesssetup.c:reply_sesssetup_and_X_spnego(566)
  NativeOS=[Windows 2002 Service Pack 2 2600] NativeLanMan=[Windows 2002 5.1]
PrimaryDomain=[]
[2005/09/19 16:51:52, 3] smbd/sesssetup.c:reply_spnego_negotiate(444)
  Got OID 1 3 6 1 4 1 311 2 2 10
[2005/09/19 16:51:52, 3] smbd/sesssetup.c:reply_spnego_negotiate(447)
  Got secblob of size 40
[2005/09/19 16:51:52, 3] libsmb/ntlmssp.c:debug_ntlmssp_flags(62)
  Got NTLMSSP neg_flags=0xe2088297
    NTLMSSP_NEGOTIATE_UNICODE
    NTLMSSP_NEGOTIATE_OEM
    NTLMSSP_REQUEST_TARGET
    NTLMSSP_NEGOTIATE_SIGN
    NTLMSSP_NEGOTIATE_LM_KEY
    NTLMSSP_NEGOTIATE_NTLM
    NTLMSSP_NEGOTIATE_ALWAYS_SIGN
    NTLMSSP_NEGOTIATE_NTLM2
    NTLMSSP_NEGOTIATE_128
    NTLMSSP_NEGOTIATE_KEY_EXCH
[2005/09/19 16:51:52, 3] smbd/process.c:process_smb(1091)
  Transaction 3 of length 376
[2005/09/19 16:51:52, 3] smbd/process.c:switch_message(886)
  switch message SMBsesssetupX (pid 17586) conn 0x0
[2005/09/19 16:51:52, 3] smbd/sec_ctx.c:set_sec_ctx(288)
  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0
[2005/09/19 16:51:52, 3] smbd/sesssetup.c:reply_sesssetup_and_X(655)
  wct=12 flg2=0xc807
[2005/09/19 16:51:52, 2] smbd/sesssetup.c:setup_new_vc_session(608)
  setup_new_vc_session: New VC == 0, if NT4.x compatible we would close all old
resources.
[2005/09/19 16:51:52, 3] smbd/sesssetup.c:reply_sesssetup_and_X_spnego(535)
  Doing spnego session setup
[2005/09/19 16:51:52, 3] smbd/sesssetup.c:reply_sesssetup_and_X_spnego(566)
  NativeOS=[Windows 2002 Service Pack 2 2600] NativeLanMan=[Windows 2002 5.1]
PrimaryDomain=[]
[2005/09/19 16:51:52, 3] libsmb/ntlmssp.c:ntlmssp_server_auth(606)
  Got user=[administrator] domain=[WORKGROUP] workstation=[BILLGATES] len1=24
len2=24
[2005/09/19 16:51:52, 3] smbd/sec_ctx.c:push_sec_ctx(256)
  push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1
[2005/09/19 16:51:52, 3] smbd/uid.c:push_conn_ctx(365)
  push_conn_ctx(0) : conn_ctx_stack_ndx = 0
[2005/09/19 16:51:52, 3] smbd/sec_ctx.c:set_sec_ctx(288)
  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1
[2005/09/19 16:51:52, 3] smbd/sec_ctx.c:pop_sec_ctx(386)
  pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0
[2005/09/19 16:51:52, 3] auth/auth.c:check_ntlm_password(219)
  check_ntlm_password:  Checking password for unmapped user
[WORKGROUP]\[administrator]@[BILLGATES] with the new password interface
[2005/09/19 16:51:52, 3] auth/auth.c:check_ntlm_password(222)
  check_ntlm_password:  mapped user is: [WORKGROUP]\[administrator]@[BILLGATES]
[2005/09/19 16:51:52, 3] smbd/sec_ctx.c:push_sec_ctx(256)
  push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1
[2005/09/19 16:51:52, 3] smbd/uid.c:push_conn_ctx(365)
  push_conn_ctx(0) : conn_ctx_stack_ndx = 0
[2005/09/19 16:51:52, 3] smbd/sec_ctx.c:set_sec_ctx(288)
  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1
[2005/09/19 16:51:52, 2] lib/smbldap.c:smbldap_open_connection(692)
  smbldap_open_connection: connection opened
[2005/09/19 16:51:52, 3] lib/smbldap.c:smbldap_connect_system(866)
  ldap_connect_system: succesful connection to the LDAP server
  ldap_connect_system: LDAP server does support paged results
[2005/09/19 16:51:52, 4] lib/smbldap.c:smbldap_open(929)
  The LDAP server is succesfully connected
[2005/09/19 16:51:52, 2] passdb/pdb_ldap.c:init_sam_from_ldap(499)
  init_sam_from_ldap: Entry found for user: Administrator
[2005/09/19 16:51:52, 3] smbd/sec_ctx.c:pop_sec_ctx(386)
  pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0
[2005/09/19 16:51:52, 4] libsmb/ntlm_check.c:ntlm_password_check(326)
  ntlm_password_check: Checking NT MD4 password
[2005/09/19 16:51:52, 4] auth/auth_sam.c:sam_account_ok(119)
  sam_account_ok: Checking SMB password for user Administrator
[2005/09/19 16:51:52, 3] smbd/sec_ctx.c:push_sec_ctx(256)
  push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1
[2005/09/19 16:51:52, 3] smbd/uid.c:push_conn_ctx(365)
  push_conn_ctx(0) : conn_ctx_stack_ndx = 0
[2005/09/19 16:51:52, 3] smbd/sec_ctx.c:set_sec_ctx(288)
  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1
[2005/09/19 16:51:52, 3] smbd/sec_ctx.c:push_sec_ctx(256)
  push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 2
[2005/09/19 16:51:52, 3] smbd/uid.c:push_conn_ctx(365)
  push_conn_ctx(0) : conn_ctx_stack_ndx = 1
[2005/09/19 16:51:52, 3] smbd/sec_ctx.c:set_sec_ctx(288)
  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 2
[2005/09/19 16:51:52, 3] smbd/sec_ctx.c:pop_sec_ctx(386)
  pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 1
[2005/09/19 16:51:52, 3] smbd/sec_ctx.c:push_sec_ctx(256)
  push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 2
[2005/09/19 16:51:52, 3] smbd/uid.c:push_conn_ctx(365)
  push_conn_ctx(0) : conn_ctx_stack_ndx = 1
[2005/09/19 16:51:52, 3] smbd/sec_ctx.c:set_sec_ctx(288)
  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 2
[2005/09/19 16:51:52, 2] passdb/pdb_ldap.c:init_group_from_ldap(2000)
  init_group_from_ldap: Entry found for group: 544
[2005/09/19 16:51:52, 3] smbd/sec_ctx.c:pop_sec_ctx(386)
  pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 1
[2005/09/19 16:51:52, 3] smbd/sec_ctx.c:pop_sec_ctx(386)
  pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0
[2005/09/19 16:51:52, 3] lib/privileges.c:get_privileges(249)
  get_privileges: No privileges assigned to SID
[S-1-5-21-4087610795-3070336623-1441377821-2996]
[2005/09/19 16:51:52, 3] lib/privileges.c:get_privileges(249)
  get_privileges: No privileges assigned to SID
[S-1-5-21-4087610795-3070336623-1441377821-512]
[2005/09/19 16:51:52, 3] lib/privileges.c:get_privileges(249)
  get_privileges: No privileges assigned to SID [S-1-5-2]
[2005/09/19 16:51:52, 3] lib/privileges.c:get_privileges(249)
  get_privileges: No privileges assigned to SID [S-1-5-11]
[2005/09/19 16:51:52, 3] auth/auth.c:check_ntlm_password(268)
  check_ntlm_password: sam authentication for user [administrator] succeeded
[2005/09/19 16:51:52, 3] smbd/sec_ctx.c:push_sec_ctx(256)
  push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1
[2005/09/19 16:51:52, 3] smbd/uid.c:push_conn_ctx(365)
  push_conn_ctx(0) : conn_ctx_stack_ndx = 0
[2005/09/19 16:51:52, 3] smbd/sec_ctx.c:set_sec_ctx(288)
  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1
[2005/09/19 16:51:52, 4] auth/pampass.c:smb_pam_start(459)
  smb_pam_start: PAM: Init user: Administrator
[2005/09/19 16:51:52, 4] auth/pampass.c:smb_pam_start(476)
  smb_pam_start: PAM: setting rhost to: 192.168.10.169
[2005/09/19 16:51:52, 4] auth/pampass.c:smb_pam_start(485)
  smb_pam_start: PAM: setting tty
[2005/09/19 16:51:52, 4] auth/pampass.c:smb_pam_start(493)
  smb_pam_start: PAM: Init passed for user: Administrator
[2005/09/19 16:51:52, 4] auth/pampass.c:smb_pam_account(551)
  smb_pam_account: PAM: Account Management for User: Administrator
[2005/09/19 16:51:52, 4] auth/pampass.c:smb_pam_account(570)
  smb_pam_account: PAM: Account OK for User: Administrator
[2005/09/19 16:51:52, 4] auth/pampass.c:smb_pam_end(440)
  smb_pam_end: PAM: PAM_END OK.
[2005/09/19 16:51:52, 3] smbd/sec_ctx.c:pop_sec_ctx(386)
  pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0
[2005/09/19 16:51:52, 2] auth/auth.c:check_ntlm_password(305)
  check_ntlm_password:  authentication for user [administrator] ->
[administrator] -> [Administrator] succeeded
[2005/09/19 16:51:52, 3] libsmb/ntlmssp_sign.c:ntlmssp_sign_init(319)
  NTLMSSP Sign/Seal - Initialising with flags:
[2005/09/19 16:51:52, 3] libsmb/ntlmssp.c:debug_ntlmssp_flags(62)
  Got NTLMSSP neg_flags=0x60088215
    NTLMSSP_NEGOTIATE_UNICODE
    NTLMSSP_REQUEST_TARGET
    NTLMSSP_NEGOTIATE_SIGN
    NTLMSSP_NEGOTIATE_NTLM
    NTLMSSP_NEGOTIATE_ALWAYS_SIGN
    NTLMSSP_NEGOTIATE_NTLM2
    NTLMSSP_NEGOTIATE_128
    NTLMSSP_NEGOTIATE_KEY_EXCH
[2005/09/19 16:51:52, 3] smbd/password.c:register_vuid(222)
  User name: Administrator	Real name: Administrator
[2005/09/19 16:51:52, 3] smbd/password.c:register_vuid(241)
  UNIX uid 998 is UNIX user Administrator, and will be vuid 100
[2005/09/19 16:51:52, 4] auth/pampass.c:smb_pam_start(459)
  smb_pam_start: PAM: Init user: Administrator
[2005/09/19 16:51:52, 4] auth/pampass.c:smb_pam_start(476)
  smb_pam_start: PAM: setting rhost to: 192.168.10.169
[2005/09/19 16:51:52, 4] auth/pampass.c:smb_pam_start(485)
  smb_pam_start: PAM: setting tty
[2005/09/19 16:51:52, 4] auth/pampass.c:smb_pam_start(493)
  smb_pam_start: PAM: Init passed for user: Administrator
[2005/09/19 16:51:52, 4] auth/pampass.c:smb_internal_pam_session(630)
  smb_internal_pam_session: PAM: tty set to: smb/17586/100
[2005/09/19 16:51:52, 4] auth/pampass.c:smb_pam_end(440)
  smb_pam_end: PAM: PAM_END OK.
[2005/09/19 16:51:52, 3] smbd/password.c:register_vuid(270)
  Adding homes service for user 'Administrator' using home directory:
'/home/Administrator'
[2005/09/19 16:51:52, 3] param/loadparm.c:lp_add_home(2368)
  adding home's share [Administrator] for user 'Administrator' at
'/home/Administrator'
[2005/09/19 16:51:52, 3] smbd/process.c:process_smb(1091)
  Transaction 4 of length 82
[2005/09/19 16:51:52, 3] smbd/process.c:switch_message(886)
  switch message SMBtconX (pid 17586) conn 0x0
[2005/09/19 16:51:52, 3] smbd/sec_ctx.c:set_sec_ctx(288)
  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0
[2005/09/19 16:51:52, 4] smbd/reply.c:reply_tcon_and_X(407)
  Client requested device type [?????] for share [IPC$]
[2005/09/19 16:51:52, 3] smbd/service.c:make_connection_snum(479)
  Connect path is '/tmp' for service [IPC$]
[2005/09/19 16:51:52, 4] rpc_server/srv_srvsvc_nt.c:get_share_security(217)
  get_share_security: using default secdesc for IPC$
[2005/09/19 16:51:52, 3] lib/util_seaccess.c:se_access_check(251)
[2005/09/19 16:51:52, 3] lib/util_seaccess.c:se_access_check(252)
  se_access_check: user sid is S-1-5-21-4087610795-3070336623-1441377821-2996
  se_access_check: also S-1-5-21-4087610795-3070336623-1441377821-512
  se_access_check: also S-1-1-0
  se_access_check: also S-1-5-2
  se_access_check: also S-1-5-11
  se_access_check: also S-1-5-32-544
[2005/09/19 16:51:52, 3] smbd/vfs.c:vfs_init_default(206)
  Initialising default vfs hooks
[2005/09/19 16:51:52, 4] rpc_server/srv_srvsvc_nt.c:get_share_security(217)
  get_share_security: using default secdesc for IPC$
[2005/09/19 16:51:52, 3] lib/util_seaccess.c:se_access_check(251)
[2005/09/19 16:51:52, 3] lib/util_seaccess.c:se_access_check(252)
  se_access_check: user sid is S-1-5-21-4087610795-3070336623-1441377821-2996
  se_access_check: also S-1-5-21-4087610795-3070336623-1441377821-512
  se_access_check: also S-1-1-0
  se_access_check: also S-1-5-2
  se_access_check: also S-1-5-11
  se_access_check: also S-1-5-32-544
[2005/09/19 16:51:52, 3] smbd/sec_ctx.c:set_sec_ctx(288)
  setting sec ctx (998, 544) - sec_ctx_stack_ndx = 0
[2005/09/19 16:51:52, 3] smbd/service.c:make_connection_snum(642)
  billgates (192.168.10.169) connect to service IPC$ initially as user
Administrator (uid=998, gid=544) (pid 17586)
[2005/09/19 16:51:52, 3] smbd/sec_ctx.c:set_sec_ctx(288)
  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0
[2005/09/19 16:51:52, 3] smbd/reply.c:reply_tcon_and_X(455)
  tconX service=IPC$ 
[2005/09/19 16:51:52, 3] smbd/process.c:process_smb(1091)
  Transaction 5 of length 104
[2005/09/19 16:51:52, 3] smbd/process.c:switch_message(886)
  switch message SMBntcreateX (pid 17586) conn 0x837e080
[2005/09/19 16:51:52, 3] smbd/sec_ctx.c:set_sec_ctx(288)
  setting sec ctx (998, 544) - sec_ctx_stack_ndx = 0
[2005/09/19 16:51:52, 4] smbd/vfs.c:vfs_ChDir(660)
  vfs_ChDir to /tmp
[2005/09/19 16:51:52, 4] smbd/nttrans.c:nt_open_pipe(497)
  nt_open_pipe: Opening pipe \lsarpc.
[2005/09/19 16:51:52, 3] smbd/nttrans.c:nt_open_pipe(514)
  nt_open_pipe: Known pipe lsarpc opening.
[2005/09/19 16:51:52, 4] rpc_server/srv_pipe_hnd.c:open_rpc_pipe_p(178)
  Open pipe requested lsarpc (pipes_open=0)
[2005/09/19 16:51:52, 4] rpc_server/srv_pipe_hnd.c:make_internal_rpc_pipe_p(278)
  Create pipe requested lsarpc
[2005/09/19 16:51:52, 4] rpc_server/srv_pipe_hnd.c:make_internal_rpc_pipe_p(370)
  Created internal pipe lsarpc (pipes_open=0)
[2005/09/19 16:51:52, 4] rpc_server/srv_pipe_hnd.c:open_rpc_pipe_p(257)
  Opened pipe lsarpc with handle 705a (pipes_open=1)
[2005/09/19 16:51:52, 3] smbd/process.c:process_smb(1091)
  Transaction 6 of length 140
[2005/09/19 16:51:52, 3] smbd/process.c:switch_message(886)
  switch message SMBwriteX (pid 17586) conn 0x837e080
[2005/09/19 16:51:52, 4] smbd/uid.c:change_to_user(194)
  change_to_user: Skipping user change - already user
[2005/09/19 16:51:52, 4] rpc_server/srv_pipe_hnd.c:get_rpc_pipe(1168)
  search for pipe pnum=705a
[2005/09/19 16:51:52, 3] rpc_server/srv_pipe.c:api_pipe_bind_req(887)
  api_pipe_bind_req: \PIPE\lsarpc -> \PIPE\lsass
[2005/09/19 16:51:52, 3] rpc_server/srv_pipe.c:check_bind_req(762)
  check_bind_req for \PIPE\lsarpc
[2005/09/19 16:51:52, 3] smbd/pipes.c:reply_pipe_write_and_X(199)
  writeX-IPC pnum=705a nwritten=72
[2005/09/19 16:51:52, 3] smbd/process.c:process_smb(1091)
  Transaction 7 of length 63
[2005/09/19 16:51:52, 3] smbd/process.c:switch_message(886)
  switch message SMBreadX (pid 17586) conn 0x837e080
[2005/09/19 16:51:52, 4] smbd/uid.c:change_to_user(194)
  change_to_user: Skipping user change - already user
[2005/09/19 16:51:52, 4] rpc_server/srv_pipe_hnd.c:get_rpc_pipe(1168)
  search for pipe pnum=705a
[2005/09/19 16:51:52, 3] smbd/pipes.c:reply_pipe_read_and_X(242)
  readX-IPC pnum=705a min=1024 max=1024 nread=68
[2005/09/19 16:51:52, 3] smbd/process.c:process_smb(1091)
  Transaction 8 of length 176
[2005/09/19 16:51:52, 3] smbd/process.c:switch_message(886)
  switch message SMBtrans (pid 17586) conn 0x837e080
[2005/09/19 16:51:52, 4] smbd/uid.c:change_to_user(194)
  change_to_user: Skipping user change - already user
[2005/09/19 16:51:52, 3] smbd/ipc.c:reply_trans(539)
  trans <\PIPE\> data=88 params=0 setup=2
[2005/09/19 16:51:52, 3] smbd/ipc.c:named_pipe(334)
  named pipe command on <> name
[2005/09/19 16:51:52, 4] rpc_server/srv_pipe_hnd.c:get_rpc_pipe(1168)
  search for pipe pnum=705a
[2005/09/19 16:51:52, 3] smbd/ipc.c:api_fd_reply(294)
  Got API command 0x26 on pipe "lsarpc" (pnum 705a)
[2005/09/19 16:51:52, 3] rpc_server/srv_pipe_hnd.c:free_pipe_context(542)
  free_pipe_context: destroying talloc pool of size 0
[2005/09/19 16:51:52, 4] rpc_server/srv_pipe.c:api_rpcTNP(1531)
  api_rpcTNP: lsarpc op 0x2c - api_rpcTNP: rpc command: LSA_OPENPOLICY2
[2005/09/19 16:51:52, 3] lib/util_seaccess.c:se_access_check(251)
[2005/09/19 16:51:52, 3] lib/util_seaccess.c:se_access_check(252)
  se_access_check: user sid is S-1-5-21-4087610795-3070336623-1441377821-2996
  se_access_check: also S-1-5-21-4087610795-3070336623-1441377821-512
  se_access_check: also S-1-1-0
  se_access_check: also S-1-5-2
  se_access_check: also S-1-5-11
  se_access_check: also S-1-5-32-544
[2005/09/19 16:51:52, 4] rpc_server/srv_lsa_hnd.c:create_policy_hnd(142)
  Opened policy hnd[1] [000] 00 00 00 00 01 00 00 00  00 00 00 00 E8 24 2F 43 
........ .....$/C
  [010] B2 44 00 00                                       .D.. 
[2005/09/19 16:51:52, 3] rpc_server/srv_pipe_hnd.c:free_pipe_context(542)
  free_pipe_context: destroying talloc pool of size 818
[2005/09/19 16:51:52, 3] smbd/process.c:process_smb(1091)
  Transaction 9 of length 134
[2005/09/19 16:51:52, 3] smbd/process.c:switch_message(886)
  switch message SMBtrans (pid 17586) conn 0x837e080
[2005/09/19 16:51:52, 4] smbd/uid.c:change_to_user(194)
  change_to_user: Skipping user change - already user
[2005/09/19 16:51:52, 3] smbd/ipc.c:reply_trans(539)
  trans <\PIPE\> data=46 params=0 setup=2
[2005/09/19 16:51:52, 3] smbd/ipc.c:named_pipe(334)
  named pipe command on <> name
[2005/09/19 16:51:52, 4] rpc_server/srv_pipe_hnd.c:get_rpc_pipe(1168)
  search for pipe pnum=705a
[2005/09/19 16:51:52, 3] smbd/ipc.c:api_fd_reply(294)
  Got API command 0x26 on pipe "lsarpc" (pnum 705a)
[2005/09/19 16:51:52, 3] rpc_server/srv_pipe_hnd.c:free_pipe_context(542)
  free_pipe_context: destroying talloc pool of size 0
[2005/09/19 16:51:52, 4] rpc_server/srv_pipe.c:api_rpcTNP(1531)
  api_rpcTNP: lsarpc op 0x2e - unknown
[2005/09/19 16:51:52, 3] rpc_server/srv_pipe_hnd.c:free_pipe_context(542)
  free_pipe_context: destroying talloc pool of size 0
[2005/09/19 16:51:52, 3] smbd/process.c:process_smb(1091)
  Transaction 10 of length 134
[2005/09/19 16:51:52, 3] smbd/process.c:switch_message(886)
  switch message SMBtrans (pid 17586) conn 0x837e080
[2005/09/19 16:51:52, 4] smbd/uid.c:change_to_user(194)
  change_to_user: Skipping user change - already user
[2005/09/19 16:51:52, 3] smbd/ipc.c:reply_trans(539)
  trans <\PIPE\> data=46 params=0 setup=2
[2005/09/19 16:51:52, 3] smbd/ipc.c:named_pipe(334)
  named pipe command on <> name
[2005/09/19 16:51:52, 4] rpc_server/srv_pipe_hnd.c:get_rpc_pipe(1168)
  search for pipe pnum=705a
[2005/09/19 16:51:52, 3] smbd/ipc.c:api_fd_reply(294)
  Got API command 0x26 on pipe "lsarpc" (pnum 705a)
[2005/09/19 16:51:52, 3] rpc_server/srv_pipe_hnd.c:free_pipe_context(542)
  free_pipe_context: destroying talloc pool of size 0
[2005/09/19 16:51:52, 4] rpc_server/srv_pipe.c:api_rpcTNP(1531)
  api_rpcTNP: lsarpc op 0x7 - api_rpcTNP: rpc command: LSA_QUERYINFOPOLICY
[2005/09/19 16:51:52, 4]
rpc_server/srv_lsa_hnd.c:find_policy_by_hnd_internal(162)
  Found policy hnd[0] [000] 00 00 00 00 01 00 00 00  00 00 00 00 E8 24 2F 43 
........ .....$/C
  [010] B2 44 00 00                                       .D.. 
[2005/09/19 16:51:52, 3] rpc_server/srv_pipe_hnd.c:free_pipe_context(542)
  free_pipe_context: destroying talloc pool of size 20
[2005/09/19 16:51:52, 3] smbd/process.c:process_smb(1091)
  Transaction 11 of length 104
[2005/09/19 16:51:52, 3] smbd/process.c:switch_message(886)
  switch message SMBntcreateX (pid 17586) conn 0x837e080
[2005/09/19 16:51:52, 4] smbd/uid.c:change_to_user(194)
  change_to_user: Skipping user change - already user
[2005/09/19 16:51:52, 4] smbd/nttrans.c:nt_open_pipe(497)
  nt_open_pipe: Opening pipe \winreg.
[2005/09/19 16:51:52, 3] smbd/nttrans.c:nt_open_pipe(514)
  nt_open_pipe: Known pipe winreg opening.
[2005/09/19 16:51:52, 4] rpc_server/srv_pipe_hnd.c:open_rpc_pipe_p(178)
  Open pipe requested winreg (pipes_open=1)
[2005/09/19 16:51:52, 4] rpc_server/srv_pipe_hnd.c:make_internal_rpc_pipe_p(278)
  Create pipe requested winreg
[2005/09/19 16:51:52, 4] rpc_server/srv_pipe_hnd.c:make_internal_rpc_pipe_p(370)
  Created internal pipe winreg (pipes_open=1)
[2005/09/19 16:51:52, 4] rpc_server/srv_pipe_hnd.c:open_rpc_pipe_p(257)
  Opened pipe winreg with handle 705b (pipes_open=2)
[2005/09/19 16:51:52, 3] smbd/process.c:process_smb(1091)
  Transaction 12 of length 140
[2005/09/19 16:51:52, 3] smbd/process.c:switch_message(886)
  switch message SMBwriteX (pid 17586) conn 0x837e080
[2005/09/19 16:51:52, 4] smbd/uid.c:change_to_user(194)
  change_to_user: Skipping user change - already user
[2005/09/19 16:51:52, 4] rpc_server/srv_pipe_hnd.c:get_rpc_pipe(1168)
  search for pipe pnum=705b
[2005/09/19 16:51:52, 3] rpc_server/srv_pipe.c:api_pipe_bind_req(887)
  api_pipe_bind_req: \PIPE\winreg -> \PIPE\winreg
[2005/09/19 16:51:52, 3] rpc_server/srv_pipe.c:check_bind_req(762)
  check_bind_req for \PIPE\winreg
[2005/09/19 16:51:52, 3] smbd/pipes.c:reply_pipe_write_and_X(199)
  writeX-IPC pnum=705b nwritten=72
[2005/09/19 16:51:52, 3] smbd/process.c:process_smb(1091)
  Transaction 13 of length 63
[2005/09/19 16:51:52, 3] smbd/process.c:switch_message(886)
  switch message SMBreadX (pid 17586) conn 0x837e080
[2005/09/19 16:51:52, 4] smbd/uid.c:change_to_user(194)
  change_to_user: Skipping user change - already user
[2005/09/19 16:51:52, 4] rpc_server/srv_pipe_hnd.c:get_rpc_pipe(1168)
  search for pipe pnum=705b
[2005/09/19 16:51:52, 3] smbd/pipes.c:reply_pipe_read_and_X(242)
  readX-IPC pnum=705b min=1024 max=1024 nread=68
[2005/09/19 16:51:52, 3] smbd/process.c:process_smb(1091)
  Transaction 14 of length 124
[2005/09/19 16:51:52, 3] smbd/process.c:switch_message(886)
  switch message SMBtrans (pid 17586) conn 0x837e080
[2005/09/19 16:51:52, 4] smbd/uid.c:change_to_user(194)
  change_to_user: Skipping user change - already user
[2005/09/19 16:51:52, 3] smbd/ipc.c:reply_trans(539)
  trans <\PIPE\> data=36 params=0 setup=2
[2005/09/19 16:51:52, 3] smbd/ipc.c:named_pipe(334)
  named pipe command on <> name
[2005/09/19 16:51:52, 4] rpc_server/srv_pipe_hnd.c:get_rpc_pipe(1168)
  search for pipe pnum=705b
[2005/09/19 16:51:52, 3] smbd/ipc.c:api_fd_reply(294)
  Got API command 0x26 on pipe "winreg" (pnum 705b)
[2005/09/19 16:51:52, 3] rpc_server/srv_pipe_hnd.c:free_pipe_context(542)
  free_pipe_context: destroying talloc pool of size 0
[2005/09/19 16:51:52, 4] rpc_server/srv_pipe.c:api_rpcTNP(1531)
  api_rpcTNP: winreg op 0x2 - api_rpcTNP: rpc command: REG_OPEN_HKLM
[2005/09/19 16:51:52, 4] rpc_server/srv_lsa_hnd.c:create_policy_hnd(142)
  Opened policy hnd[1] [000] 00 00 00 00 02 00 00 00  00 00 00 00 E8 24 2F 43 
........ .....$/C
  [010] B2 44 00 00                                       .D.. 
[2005/09/19 16:51:52, 3] rpc_server/srv_pipe_hnd.c:free_pipe_context(542)
  free_pipe_context: destroying talloc pool of size 0
[2005/09/19 16:51:52, 3] smbd/process.c:process_smb(1091)
  Transaction 15 of length 272
[2005/09/19 16:51:52, 3] smbd/process.c:switch_message(886)
  switch message SMBtrans (pid 17586) conn 0x837e080
[2005/09/19 16:51:52, 4] smbd/uid.c:change_to_user(194)
  change_to_user: Skipping user change - already user
[2005/09/19 16:51:52, 3] smbd/ipc.c:reply_trans(539)
  trans <\PIPE\> data=184 params=0 setup=2
[2005/09/19 16:51:52, 3] smbd/ipc.c:named_pipe(334)
  named pipe command on <> name
[2005/09/19 16:51:52, 4] rpc_server/srv_pipe_hnd.c:get_rpc_pipe(1168)
  search for pipe pnum=705b
[2005/09/19 16:51:52, 3] smbd/ipc.c:api_fd_reply(294)
  Got API command 0x26 on pipe "winreg" (pnum 705b)
[2005/09/19 16:51:52, 3] rpc_server/srv_pipe_hnd.c:free_pipe_context(542)
  free_pipe_context: destroying talloc pool of size 0
[2005/09/19 16:51:52, 4] rpc_server/srv_pipe.c:api_rpcTNP(1531)
  api_rpcTNP: winreg op 0xf - api_rpcTNP: rpc command: REG_OPEN_ENTRY
[2005/09/19 16:51:52, 4]
rpc_server/srv_lsa_hnd.c:find_policy_by_hnd_internal(162)
  Found policy hnd[0] [000] 00 00 00 00 02 00 00 00  00 00 00 00 E8 24 2F 43 
........ .....$/C
  [010] B2 44 00 00                                       .D.. 
[2005/09/19 16:51:52, 4] rpc_server/srv_lsa_hnd.c:create_policy_hnd(142)
  Opened policy hnd[2] [000] 00 00 00 00 03 00 00 00  00 00 00 00 E8 24 2F 43 
........ .....$/C
  [010] B2 44 00 00                                       .D.. 
[2005/09/19 16:51:52, 3] rpc_server/srv_pipe_hnd.c:free_pipe_context(542)
  free_pipe_context: destroying talloc pool of size 110
[2005/09/19 16:51:52, 3] smbd/process.c:process_smb(1091)
  Transaction 16 of length 236
[2005/09/19 16:51:52, 3] smbd/process.c:switch_message(886)
  switch message SMBtrans (pid 17586) conn 0x837e080
[2005/09/19 16:51:52, 4] smbd/uid.c:change_to_user(194)
  change_to_user: Skipping user change - already user
[2005/09/19 16:51:52, 3] smbd/ipc.c:reply_trans(539)
  trans <\PIPE\> data=148 params=0 setup=2
[2005/09/19 16:51:52, 3] smbd/ipc.c:named_pipe(334)
  named pipe command on <> name
[2005/09/19 16:51:52, 4] rpc_server/srv_pipe_hnd.c:get_rpc_pipe(1168)
  search for pipe pnum=705b
[2005/09/19 16:51:52, 3] smbd/ipc.c:api_fd_reply(294)
  Got API command 0x26 on pipe "winreg" (pnum 705b)
[2005/09/19 16:51:52, 3] rpc_server/srv_pipe_hnd.c:free_pipe_context(542)
  free_pipe_context: destroying talloc pool of size 0
[2005/09/19 16:51:52, 4] rpc_server/srv_pipe.c:api_rpcTNP(1531)
  api_rpcTNP: winreg op 0x11 - api_rpcTNP: rpc command: REG_INFO
[2005/09/19 16:51:52, 4]
rpc_server/srv_lsa_hnd.c:find_policy_by_hnd_internal(162)
  Found policy hnd[0] [000] 00 00 00 00 03 00 00 00  00 00 00 00 E8 24 2F 43 
........ .....$/C
  [010] B2 44 00 00                                       .D.. 
[2005/09/19 16:51:52, 3] rpc_server/srv_pipe_hnd.c:free_pipe_context(542)
  free_pipe_context: destroying talloc pool of size 46
[2005/09/19 16:51:52, 3] smbd/process.c:process_smb(1091)
  Transaction 17 of length 132
[2005/09/19 16:51:52, 3] smbd/process.c:switch_message(886)
  switch message SMBtrans (pid 17586) conn 0x837e080
[2005/09/19 16:51:52, 4] smbd/uid.c:change_to_user(194)
  change_to_user: Skipping user change - already user
[2005/09/19 16:51:52, 3] smbd/ipc.c:reply_trans(539)
  trans <\PIPE\> data=44 params=0 setup=2
[2005/09/19 16:51:52, 3] smbd/ipc.c:named_pipe(334)
  named pipe command on <> name
[2005/09/19 16:51:52, 4] rpc_server/srv_pipe_hnd.c:get_rpc_pipe(1168)
  search for pipe pnum=705b
[2005/09/19 16:51:52, 3] smbd/ipc.c:api_fd_reply(294)
  Got API command 0x26 on pipe "winreg" (pnum 705b)
[2005/09/19 16:51:52, 3] rpc_server/srv_pipe_hnd.c:free_pipe_context(542)
  free_pipe_context: destroying talloc pool of size 0
[2005/09/19 16:51:52, 4] rpc_server/srv_pipe.c:api_rpcTNP(1531)
  api_rpcTNP: winreg op 0x5 - api_rpcTNP: rpc command: REG_CLOSE
[2005/09/19 16:51:52, 4]
rpc_server/srv_lsa_hnd.c:find_policy_by_hnd_internal(162)
  Found policy hnd[0] [000] 00 00 00 00 03 00 00 00  00 00 00 00 E8 24 2F 43 
........ .....$/C
  [010] B2 44 00 00                                       .D.. 
[2005/09/19 16:51:52, 4]
rpc_server/srv_lsa_hnd.c:find_policy_by_hnd_internal(162)
  Found policy hnd[0] [000] 00 00 00 00 03 00 00 00  00 00 00 00 E8 24 2F 43 
........ .....$/C
  [010] B2 44 00 00                                       .D.. 
[2005/09/19 16:51:52, 3] rpc_server/srv_lsa_hnd.c:close_policy_hnd(200)
  Closed policy
[2005/09/19 16:51:52, 3] rpc_server/srv_pipe_hnd.c:free_pipe_context(542)
  free_pipe_context: destroying talloc pool of size 0
[2005/09/19 16:51:52, 3] smbd/process.c:process_smb(1091)
  Transaction 18 of length 132
[2005/09/19 16:51:52, 3] smbd/process.c:switch_message(886)
  switch message SMBtrans (pid 17586) conn 0x837e080
[2005/09/19 16:51:52, 4] smbd/uid.c:change_to_user(194)
  change_to_user: Skipping user change - already user
[2005/09/19 16:51:52, 3] smbd/ipc.c:reply_trans(539)
  trans <\PIPE\> data=44 params=0 setup=2
[2005/09/19 16:51:52, 3] smbd/ipc.c:named_pipe(334)
  named pipe command on <> name
[2005/09/19 16:51:52, 4] rpc_server/srv_pipe_hnd.c:get_rpc_pipe(1168)
  search for pipe pnum=705b
[2005/09/19 16:51:52, 3] smbd/ipc.c:api_fd_reply(294)
  Got API command 0x26 on pipe "winreg" (pnum 705b)
[2005/09/19 16:51:52, 3] rpc_server/srv_pipe_hnd.c:free_pipe_context(542)
  free_pipe_context: destroying talloc pool of size 0
[2005/09/19 16:51:52, 4] rpc_server/srv_pipe.c:api_rpcTNP(1531)
  api_rpcTNP: winreg op 0x5 - api_rpcTNP: rpc command: REG_CLOSE
[2005/09/19 16:51:52, 4]
rpc_server/srv_lsa_hnd.c:find_policy_by_hnd_internal(162)
  Found policy hnd[0] [000] 00 00 00 00 02 00 00 00  00 00 00 00 E8 24 2F 43 
........ .....$/C
  [010] B2 44 00 00                                       .D.. 
[2005/09/19 16:51:52, 4]
rpc_server/srv_lsa_hnd.c:find_policy_by_hnd_internal(162)
  Found policy hnd[0] [000] 00 00 00 00 02 00 00 00  00 00 00 00 E8 24 2F 43 
........ .....$/C
  [010] B2 44 00 00                                       .D.. 
[2005/09/19 16:51:52, 3] rpc_server/srv_lsa_hnd.c:close_policy_hnd(200)
  Closed policy
[2005/09/19 16:51:52, 3] rpc_server/srv_pipe_hnd.c:free_pipe_context(542)
  free_pipe_context: destroying talloc pool of size 0
[2005/09/19 16:51:52, 3] smbd/process.c:process_smb(1091)
  Transaction 19 of length 45
[2005/09/19 16:51:52, 3] smbd/process.c:switch_message(886)
  switch message SMBclose (pid 17586) conn 0x837e080
[2005/09/19 16:51:52, 4] smbd/uid.c:change_to_user(194)
  change_to_user: Skipping user change - already user
[2005/09/19 16:51:52, 4] rpc_server/srv_pipe_hnd.c:get_rpc_pipe(1168)
  search for pipe pnum=705b
[2005/09/19 16:51:52, 4] rpc_server/srv_pipe_hnd.c:close_rpc_pipe_hnd(1081)
  closed pipe name winreg pnum=705b (pipes_open=1)
[2005/09/19 16:51:53, 3] smbd/process.c:process_smb(1091)
  Transaction 20 of length 100
[2005/09/19 16:51:53, 3] smbd/process.c:switch_message(886)
  switch message SMBntcreateX (pid 17586) conn 0x837e080
[2005/09/19 16:51:53, 4] smbd/uid.c:change_to_user(194)
  change_to_user: Skipping user change - already user
[2005/09/19 16:51:53, 4] smbd/nttrans.c:nt_open_pipe(497)
  nt_open_pipe: Opening pipe \samr.
[2005/09/19 16:51:53, 3] smbd/nttrans.c:nt_open_pipe(514)
  nt_open_pipe: Known pipe samr opening.
[2005/09/19 16:51:53, 4] rpc_server/srv_pipe_hnd.c:open_rpc_pipe_p(178)
  Open pipe requested samr (pipes_open=1)
[2005/09/19 16:51:53, 4] rpc_server/srv_pipe_hnd.c:make_internal_rpc_pipe_p(278)
  Create pipe requested samr
[2005/09/19 16:51:53, 4] rpc_server/srv_pipe_hnd.c:make_internal_rpc_pipe_p(370)
  Created internal pipe samr (pipes_open=1)
[2005/09/19 16:51:53, 4] rpc_server/srv_pipe_hnd.c:open_rpc_pipe_p(257)
  Opened pipe samr with handle 705c (pipes_open=2)
[2005/09/19 16:51:53, 3] smbd/process.c:process_smb(1091)
  Transaction 21 of length 140
[2005/09/19 16:51:53, 3] smbd/process.c:switch_message(886)
  switch message SMBwriteX (pid 17586) conn 0x837e080
[2005/09/19 16:51:53, 4] smbd/uid.c:change_to_user(194)
  change_to_user: Skipping user change - already user
[2005/09/19 16:51:53, 4] rpc_server/srv_pipe_hnd.c:get_rpc_pipe(1168)
  search for pipe pnum=705c
[2005/09/19 16:51:53, 3] rpc_server/srv_pipe.c:api_pipe_bind_req(887)
  api_pipe_bind_req: \PIPE\samr -> \PIPE\lsass
[2005/09/19 16:51:53, 3] rpc_server/srv_pipe.c:check_bind_req(762)
  check_bind_req for \PIPE\samr
[2005/09/19 16:51:53, 3] smbd/pipes.c:reply_pipe_write_and_X(199)
  writeX-IPC pnum=705c nwritten=72
[2005/09/19 16:51:53, 3] smbd/process.c:process_smb(1091)
  Transaction 22 of length 63
[2005/09/19 16:51:53, 3] smbd/process.c:switch_message(886)
  switch message SMBreadX (pid 17586) conn 0x837e080
[2005/09/19 16:51:53, 4] smbd/uid.c:change_to_user(194)
  change_to_user: Skipping user change - already user
[2005/09/19 16:51:53, 4] rpc_server/srv_pipe_hnd.c:get_rpc_pipe(1168)
  search for pipe pnum=705c
[2005/09/19 16:51:53, 3] smbd/pipes.c:reply_pipe_read_and_X(242)
  readX-IPC pnum=705c min=1024 max=1024 nread=68
[2005/09/19 16:51:53, 3] smbd/process.c:process_smb(1091)
  Transaction 23 of length 168
[2005/09/19 16:51:53, 3] smbd/process.c:switch_message(886)
  switch message SMBtrans (pid 17586) conn 0x837e080
[2005/09/19 16:51:53, 4] smbd/uid.c:change_to_user(194)
  change_to_user: Skipping user change - already user
[2005/09/19 16:51:53, 3] smbd/ipc.c:reply_trans(539)
  trans <\PIPE\> data=80 params=0 setup=2
[2005/09/19 16:51:53, 3] smbd/ipc.c:named_pipe(334)
  named pipe command on <> name
[2005/09/19 16:51:53, 4] rpc_server/srv_pipe_hnd.c:get_rpc_pipe(1168)
  search for pipe pnum=705c
[2005/09/19 16:51:53, 3] smbd/ipc.c:api_fd_reply(294)
  Got API command 0x26 on pipe "samr" (pnum 705c)
[2005/09/19 16:51:53, 3] rpc_server/srv_pipe_hnd.c:free_pipe_context(542)
  free_pipe_context: destroying talloc pool of size 0
[2005/09/19 16:51:53, 4] rpc_server/srv_pipe.c:api_rpcTNP(1531)
  api_rpcTNP: samr op 0x40 - unknown
[2005/09/19 16:51:53, 3] rpc_server/srv_pipe_hnd.c:free_pipe_context(542)
  free_pipe_context: destroying talloc pool of size 0
[2005/09/19 16:51:53, 3] smbd/process.c:process_smb(1091)
  Transaction 24 of length 45
[2005/09/19 16:51:53, 3] smbd/process.c:switch_message(886)
  switch message SMBclose (pid 17586) conn 0x837e080
[2005/09/19 16:51:53, 4] smbd/uid.c:change_to_user(194)
  change_to_user: Skipping user change - already user
[2005/09/19 16:51:53, 4] rpc_server/srv_pipe_hnd.c:get_rpc_pipe(1168)
  search for pipe pnum=705c
[2005/09/19 16:51:53, 4] rpc_server/srv_pipe_hnd.c:close_rpc_pipe_hnd(1081)
  closed pipe name samr pnum=705c (pipes_open=1)
[2005/09/19 16:51:53, 3] smbd/process.c:process_smb(1091)
  Transaction 25 of length 100
[2005/09/19 16:51:53, 3] smbd/process.c:switch_message(886)
  switch message SMBntcreateX (pid 17586) conn 0x837e080
[2005/09/19 16:51:53, 4] smbd/uid.c:change_to_user(194)
  change_to_user: Skipping user change - already user
[2005/09/19 16:51:53, 4] smbd/nttrans.c:nt_open_pipe(497)
  nt_open_pipe: Opening pipe \samr.
[2005/09/19 16:51:53, 3] smbd/nttrans.c:nt_open_pipe(514)
  nt_open_pipe: Known pipe samr opening.
[2005/09/19 16:51:53, 4] rpc_server/srv_pipe_hnd.c:open_rpc_pipe_p(178)
  Open pipe requested samr (pipes_open=1)
[2005/09/19 16:51:53, 4] rpc_server/srv_pipe_hnd.c:make_internal_rpc_pipe_p(278)
  Create pipe requested samr
[2005/09/19 16:51:53, 4] rpc_server/srv_pipe_hnd.c:make_internal_rpc_pipe_p(370)
  Created internal pipe samr (pipes_open=1)
[2005/09/19 16:51:53, 4] rpc_server/srv_pipe_hnd.c:open_rpc_pipe_p(257)
  Opened pipe samr with handle 705d (pipes_open=2)
[2005/09/19 16:51:53, 3] smbd/process.c:process_smb(1091)
  Transaction 26 of length 140
[2005/09/19 16:51:53, 3] smbd/process.c:switch_message(886)
  switch message SMBwriteX (pid 17586) conn 0x837e080
[2005/09/19 16:51:53, 4] smbd/uid.c:change_to_user(194)
  change_to_user: Skipping user change - already user
[2005/09/19 16:51:53, 4] rpc_server/srv_pipe_hnd.c:get_rpc_pipe(1168)
  search for pipe pnum=705d
[2005/09/19 16:51:53, 3] rpc_server/srv_pipe.c:api_pipe_bind_req(887)
  api_pipe_bind_req: \PIPE\samr -> \PIPE\lsass
[2005/09/19 16:51:53, 3] rpc_server/srv_pipe.c:check_bind_req(762)
  check_bind_req for \PIPE\samr
[2005/09/19 16:51:53, 3] smbd/pipes.c:reply_pipe_write_and_X(199)
  writeX-IPC pnum=705d nwritten=72
[2005/09/19 16:51:53, 3] smbd/process.c:process_smb(1091)
  Transaction 27 of length 63
[2005/09/19 16:51:53, 3] smbd/process.c:switch_message(886)
  switch message SMBreadX (pid 17586) conn 0x837e080
[2005/09/19 16:51:53, 4] smbd/uid.c:change_to_user(194)
  change_to_user: Skipping user change - already user
[2005/09/19 16:51:53, 4] rpc_server/srv_pipe_hnd.c:get_rpc_pipe(1168)
  search for pipe pnum=705d
[2005/09/19 16:51:53, 3] smbd/pipes.c:reply_pipe_read_and_X(242)
  readX-IPC pnum=705d min=1024 max=1024 nread=68
[2005/09/19 16:51:53, 3] smbd/process.c:process_smb(1091)
  Transaction 28 of length 156
[2005/09/19 16:51:53, 3] smbd/process.c:switch_message(886)
  switch message SMBtrans (pid 17586) conn 0x837e080
[2005/09/19 16:51:53, 4] smbd/uid.c:change_to_user(194)
  change_to_user: Skipping user change - already user
[2005/09/19 16:51:53, 3] smbd/ipc.c:reply_trans(539)
  trans <\PIPE\> data=68 params=0 setup=2
[2005/09/19 16:51:53, 3] smbd/ipc.c:named_pipe(334)
  named pipe command on <> name
[2005/09/19 16:51:53, 4] rpc_server/srv_pipe_hnd.c:get_rpc_pipe(1168)
  search for pipe pnum=705d
[2005/09/19 16:51:53, 3] smbd/ipc.c:api_fd_reply(294)
  Got API command 0x26 on pipe "samr" (pnum 705d)
[2005/09/19 16:51:53, 3] rpc_server/srv_pipe_hnd.c:free_pipe_context(542)
  free_pipe_context: destroying talloc pool of size 0
[2005/09/19 16:51:53, 4] rpc_server/srv_pipe.c:api_rpcTNP(1531)
  api_rpcTNP: samr op 0x3e - api_rpcTNP: rpc command: SAMR_CONNECT4
[2005/09/19 16:51:53, 3] lib/util_seaccess.c:se_access_check(251)
[2005/09/19 16:51:53, 3] lib/util_seaccess.c:se_access_check(252)
  se_access_check: user sid is S-1-5-21-4087610795-3070336623-1441377821-2996
  se_access_check: also S-1-5-21-4087610795-3070336623-1441377821-512
  se_access_check: also S-1-1-0
  se_access_check: also S-1-5-2
  se_access_check: also S-1-5-11
  se_access_check: also S-1-5-32-544
[2005/09/19 16:51:53, 4] rpc_server/srv_samr_nt.c:access_check_samr_object(189)
  _samr_connect4: access GRANTED (requested: 0x00000030, granted: 0x00000030)
[2005/09/19 16:51:53, 4] rpc_server/srv_lsa_hnd.c:create_policy_hnd(142)
  Opened policy hnd[2] [000] 00 00 00 00 04 00 00 00  00 00 00 00 E9 24 2F 43 
........ .....$/C
  [010] B2 44 00 00                                       .D.. 
[2005/09/19 16:51:53, 3] rpc_server/srv_pipe_hnd.c:free_pipe_context(542)
  free_pipe_context: destroying talloc pool of size 974
[2005/09/19 16:51:53, 3] smbd/process.c:process_smb(1091)
  Transaction 29 of length 140
[2005/09/19 16:51:53, 3] smbd/process.c:switch_message(886)
  switch message SMBtrans (pid 17586) conn 0x837e080
[2005/09/19 16:51:53, 4] smbd/uid.c:change_to_user(194)
  change_to_user: Skipping user change - already user
[2005/09/19 16:51:53, 3] smbd/ipc.c:reply_trans(539)
  trans <\PIPE\> data=52 params=0 setup=2
[2005/09/19 16:51:53, 3] smbd/ipc.c:named_pipe(334)
  named pipe command on <> name
[2005/09/19 16:51:53, 4] rpc_server/srv_pipe_hnd.c:get_rpc_pipe(1168)
  search for pipe pnum=705d
[2005/09/19 16:51:53, 3] smbd/ipc.c:api_fd_reply(294)
  Got API command 0x26 on pipe "samr" (pnum 705d)
[2005/09/19 16:51:53, 3] rpc_server/srv_pipe_hnd.c:free_pipe_context(542)
  free_pipe_context: destroying talloc pool of size 0
[2005/09/19 16:51:53, 4] rpc_server/srv_pipe.c:api_rpcTNP(1531)
  api_rpcTNP: samr op 0x6 - api_rpcTNP: rpc command: SAMR_ENUM_DOMAINS
[2005/09/19 16:51:53, 4]
rpc_server/srv_lsa_hnd.c:find_policy_by_hnd_internal(162)
  Found policy hnd[0] [000] 00 00 00 00 04 00 00 00  00 00 00 00 E9 24 2F 43 
........ .....$/C
  [010] B2 44 00 00                                       .D.. 
[2005/09/19 16:51:53, 3] rpc_server/srv_pipe_hnd.c:free_pipe_context(542)
  free_pipe_context: destroying talloc pool of size 92
[2005/09/19 16:51:53, 3] smbd/process.c:process_smb(1091)
  Transaction 30 of length 170
[2005/09/19 16:51:53, 3] smbd/process.c:switch_message(886)
  switch message SMBtrans (pid 17586) conn 0x837e080
[2005/09/19 16:51:53, 4] smbd/uid.c:change_to_user(194)
  change_to_user: Skipping user change - already user
[2005/09/19 16:51:53, 3] smbd/ipc.c:reply_trans(539)
  trans <\PIPE\> data=82 params=0 setup=2
[2005/09/19 16:51:53, 3] smbd/ipc.c:named_pipe(334)
  named pipe command on <> name
[2005/09/19 16:51:53, 4] rpc_server/srv_pipe_hnd.c:get_rpc_pipe(1168)
  search for pipe pnum=705d
[2005/09/19 16:51:53, 3] smbd/ipc.c:api_fd_reply(294)
  Got API command 0x26 on pipe "samr" (pnum 705d)
[2005/09/19 16:51:53, 3] rpc_server/srv_pipe_hnd.c:free_pipe_context(542)
  free_pipe_context: destroying talloc pool of size 0
[2005/09/19 16:51:53, 4] rpc_server/srv_pipe.c:api_rpcTNP(1531)
  api_rpcTNP: samr op 0x5 - api_rpcTNP: rpc command: SAMR_LOOKUP_DOMAIN
[2005/09/19 16:51:53, 4]
rpc_server/srv_lsa_hnd.c:find_policy_by_hnd_internal(162)
  Found policy hnd[0] [000] 00 00 00 00 04 00 00 00  00 00 00 00 E9 24 2F 43 
........ .....$/C
  [010] B2 44 00 00                                       .D.. 
[2005/09/19 16:51:53, 2] rpc_server/srv_samr_nt.c:_samr_lookup_domain(2580)
  Returning domain sid for domain WORKGROUP ->
S-1-5-21-4087610795-3070336623-1441377821
[2005/09/19 16:51:53, 3] rpc_server/srv_pipe_hnd.c:free_pipe_context(542)
  free_pipe_context: destroying talloc pool of size 18
[2005/09/19 16:51:53, 3] smbd/process.c:process_smb(1091)
  Transaction 31 of length 164
[2005/09/19 16:51:53, 3] smbd/process.c:switch_message(886)
  switch message SMBtrans (pid 17586) conn 0x837e080
[2005/09/19 16:51:53, 4] smbd/uid.c:change_to_user(194)
  change_to_user: Skipping user change - already user
[2005/09/19 16:51:53, 3] smbd/ipc.c:reply_trans(539)
  trans <\PIPE\> data=76 params=0 setup=2
[2005/09/19 16:51:53, 3] smbd/ipc.c:named_pipe(334)
  named pipe command on <> name
[2005/09/19 16:51:53, 4] rpc_server/srv_pipe_hnd.c:get_rpc_pipe(1168)
  search for pipe pnum=705d
[2005/09/19 16:51:53, 3] smbd/ipc.c:api_fd_reply(294)
  Got API command 0x26 on pipe "samr" (pnum 705d)
[2005/09/19 16:51:53, 3] rpc_server/srv_pipe_hnd.c:free_pipe_context(542)
  free_pipe_context: destroying talloc pool of size 0
[2005/09/19 16:51:53, 4] rpc_server/srv_pipe.c:api_rpcTNP(1531)
  api_rpcTNP: samr op 0x7 - api_rpcTNP: rpc command: SAMR_OPEN_DOMAIN
[2005/09/19 16:51:53, 4]
rpc_server/srv_lsa_hnd.c:find_policy_by_hnd_internal(162)
  Found policy hnd[0] [000] 00 00 00 00 04 00 00 00  00 00 00 00 E9 24 2F 43 
........ .....$/C
  [010] B2 44 00 00                                       .D.. 
[2005/09/19 16:51:53, 3] lib/util_seaccess.c:se_access_check(251)
[2005/09/19 16:51:53, 3] lib/util_seaccess.c:se_access_check(252)
  se_access_check: user sid is S-1-5-21-4087610795-3070336623-1441377821-2996
  se_access_check: also S-1-5-21-4087610795-3070336623-1441377821-512
  se_access_check: also S-1-1-0
  se_access_check: also S-1-5-2
  se_access_check: also S-1-5-11
  se_access_check: also S-1-5-32-544
[2005/09/19 16:51:53, 4] rpc_server/srv_samr_nt.c:access_check_samr_object(189)
  _samr_open_domain: access GRANTED (requested: 0x00000211, granted: 0x000d067b)
[2005/09/19 16:51:53, 4] rpc_server/srv_lsa_hnd.c:create_policy_hnd(142)
  Opened policy hnd[3] [000] 00 00 00 00 05 00 00 00  00 00 00 00 E9 24 2F 43 
........ .....$/C
  [010] B2 44 00 00                                       .D.. 
[2005/09/19 16:51:53, 3] rpc_server/srv_pipe_hnd.c:free_pipe_context(542)
  free_pipe_context: destroying talloc pool of size 956
[2005/09/19 16:51:53, 3] smbd/process.c:process_smb(1091)
  Transaction 32 of length 180
[2005/09/19 16:51:53, 3] smbd/process.c:switch_message(886)
  switch message SMBtrans (pid 17586) conn 0x837e080
[2005/09/19 16:51:53, 4] smbd/uid.c:change_to_user(194)
  change_to_user: Skipping user change - already user
[2005/09/19 16:51:53, 3] smbd/ipc.c:reply_trans(539)
  trans <\PIPE\> data=92 params=0 setup=2
[2005/09/19 16:51:53, 3] smbd/ipc.c:named_pipe(334)
  named pipe command on <> name
[2005/09/19 16:51:53, 4] rpc_server/srv_pipe_hnd.c:get_rpc_pipe(1168)
  search for pipe pnum=705d
[2005/09/19 16:51:53, 3] smbd/ipc.c:api_fd_reply(294)
  Got API command 0x26 on pipe "samr" (pnum 705d)
[2005/09/19 16:51:53, 3] rpc_server/srv_pipe_hnd.c:free_pipe_context(542)
  free_pipe_context: destroying talloc pool of size 0
[2005/09/19 16:51:53, 4] rpc_server/srv_pipe.c:api_rpcTNP(1531)
  api_rpcTNP: samr op 0x32 - api_rpcTNP: rpc command: SAMR_CREATE_USER
[2005/09/19 16:51:53, 4]
rpc_server/srv_lsa_hnd.c:find_policy_by_hnd_internal(162)
  Found policy hnd[0] [000] 00 00 00 00 05 00 00 00  00 00 00 00 E9 24 2F 43 
........ .....$/C
  [010] B2 44 00 00                                       .D.. 
[2005/09/19 16:51:53, 3] smbd/sec_ctx.c:push_sec_ctx(256)
  push_sec_ctx(998, 544) : sec_ctx_stack_ndx = 1
[2005/09/19 16:51:53, 3] smbd/uid.c:push_conn_ctx(365)
  push_conn_ctx(100) : conn_ctx_stack_ndx = 0
[2005/09/19 16:51:53, 3] smbd/sec_ctx.c:set_sec_ctx(288)
  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1
[2005/09/19 16:51:53, 4] passdb/pdb_ldap.c:ldapsam_getsampwnam(1334)
  ldapsam_getsampwnam: Unable to locate user [billgates$] count=0
[2005/09/19 16:51:53, 3] smbd/sec_ctx.c:pop_sec_ctx(386)
  pop_sec_ctx (998, 544) - sec_ctx_stack_ndx = 0
[2005/09/19 16:51:53, 3] smbd/sec_ctx.c:push_sec_ctx(256)
  push_sec_ctx(998, 544) : sec_ctx_stack_ndx = 1
[2005/09/19 16:51:53, 3] smbd/uid.c:push_conn_ctx(365)
  push_conn_ctx(100) : conn_ctx_stack_ndx = 0
[2005/09/19 16:51:53, 3] smbd/sec_ctx.c:set_sec_ctx(288)
  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1
[2005/09/19 16:51:53, 2] passdb/pdb_ldap.c:init_group_from_ldap(2000)
  init_group_from_ldap: Entry found for group: 515
[2005/09/19 16:51:53, 3] smbd/sec_ctx.c:pop_sec_ctx(386)
  pop_sec_ctx (998, 544) - sec_ctx_stack_ndx = 0
[2005/09/19 16:51:53, 0] lib/smbldap.c:smbldap_open(882)
  smbldap_open: cannot access LDAP when not root..
[2005/09/19 16:51:53, 1] lib/smbldap.c:another_ldap_try(1011)
  Connection to LDAP server failed for the 1 try!
[2005/09/19 16:51:54, 0] lib/smbldap.c:smbldap_open(882)
  smbldap_open: cannot access LDAP when not root..
[2005/09/19 16:51:54, 1] lib/smbldap.c:another_ldap_try(1011)
  Connection to LDAP server failed for the 2 try!
[2005/09/19 16:51:55, 0] lib/smbldap.c:smbldap_open(882)
  smbldap_open: cannot access LDAP when not root..
[2005/09/19 16:51:55, 1] lib/smbldap.c:another_ldap_try(1011)
  Connection to LDAP server failed for the 3 try!
[2005/09/19 16:51:56, 0] lib/smbldap.c:smbldap_open(882)
  smbldap_open: cannot access LDAP when not root..
[2005/09/19 16:51:56, 1] lib/smbldap.c:another_ldap_try(1011)
  Connection to LDAP server failed for the 4 try!
[2005/09/19 16:51:57, 0] lib/smbldap.c:smbldap_open(882)
  smbldap_open: cannot access LDAP when not root..
[2005/09/19 16:51:57, 1] lib/smbldap.c:another_ldap_try(1011)
  Connection to LDAP server failed for the 5 try!
[2005/09/19 16:51:58, 0] lib/smbldap.c:smbldap_open(882)
  smbldap_open: cannot access LDAP when not root..
[2005/09/19 16:51:58, 1] lib/smbldap.c:another_ldap_try(1011)
  Connection to LDAP server failed for the 6 try!
[2005/09/19 16:51:59, 0] lib/smbldap.c:smbldap_open(882)
  smbldap_open: cannot access LDAP when not root..
[2005/09/19 16:51:59, 1] lib/smbldap.c:another_ldap_try(1011)
  Connection to LDAP server failed for the 7 try!
[2005/09/19 16:52:00, 0] lib/smbldap.c:smbldap_open(882)
  smbldap_open: cannot access LDAP when not root..
[2005/09/19 16:52:00, 1] lib/smbldap.c:another_ldap_try(1011)
  Connection to LDAP server failed for the 8 try!
[2005/09/19 16:52:01, 0] lib/smbldap.c:smbldap_open(882)
  smbldap_open: cannot access LDAP when not root..
[2005/09/19 16:52:01, 1] lib/smbldap.c:another_ldap_try(1011)
  Connection to LDAP server failed for the 9 try!
[2005/09/19 16:52:02, 0] lib/smbldap.c:smbldap_open(882)
  smbldap_open: cannot access LDAP when not root..
[2005/09/19 16:52:02, 1] lib/smbldap.c:another_ldap_try(1011)
  Connection to LDAP server failed for the 10 try!
[2005/09/19 16:52:03, 0] lib/smbldap.c:smbldap_open(882)
  smbldap_open: cannot access LDAP when not root..
[2005/09/19 16:52:03, 1] lib/smbldap.c:another_ldap_try(1011)
  Connection to LDAP server failed for the 11 try!
[2005/09/19 16:52:04, 0] lib/smbldap.c:smbldap_open(882)
  smbldap_open: cannot access LDAP when not root..
[2005/09/19 16:52:04, 1] lib/smbldap.c:another_ldap_try(1011)
  Connection to LDAP server failed for the 12 try!
[2005/09/19 16:52:05, 0] lib/smbldap.c:smbldap_open(882)
  smbldap_open: cannot access LDAP when not root..
[2005/09/19 16:52:05, 1] lib/smbldap.c:another_ldap_try(1011)
  Connection to LDAP server failed for the 13 try!
[2005/09/19 16:52:06, 0] lib/smbldap.c:smbldap_open(882)
  smbldap_open: cannot access LDAP when not root..
[2005/09/19 16:52:06, 1] lib/smbldap.c:another_ldap_try(1011)
  Connection to LDAP server failed for the 14 try!
[2005/09/19 16:52:07, 0] lib/smbldap.c:smbldap_open(882)
  smbldap_open: cannot access LDAP when not root..
[2005/09/19 16:52:07, 1] lib/smbldap.c:another_ldap_try(1011)
  Connection to LDAP server failed for the 15 try!
[2005/09/19 16:52:08, 0] lib/smbldap.c:smbldap_open(882)
  smbldap_open: cannot access LDAP when not root..
[2005/09/19 16:52:08, 1] lib/smbldap.c:another_ldap_try(1011)
  Connection to LDAP server failed for the 16 try!
[2005/09/19 16:52:09, 0] lib/smbldap.c:smbldap_open(882)
  smbldap_open: cannot access LDAP when not root..
[2005/09/19 16:52:09, 1] lib/smbldap.c:another_ldap_try(1011)
  Connection to LDAP server failed for the 17 try!
[2005/09/19 16:52:10, 0] lib/smbldap.c:smbldap_open(882)
  smbldap_open: cannot access LDAP when not root..
[2005/09/19 16:52:10, 1] lib/smbldap.c:another_ldap_try(1011)
  Connection to LDAP server failed for the 18 try!
[2005/09/19 16:52:11, 0] lib/smbldap.c:smbldap_open(882)
  smbldap_open: cannot access LDAP when not root..
[2005/09/19 16:52:11, 1] lib/smbldap.c:another_ldap_try(1011)
  Connection to LDAP server failed for the 19 try!
[2005/09/19 16:52:12, 0] lib/smbldap.c:smbldap_open(882)
  smbldap_open: cannot access LDAP when not root..
[2005/09/19 16:52:12, 1] lib/smbldap.c:another_ldap_try(1011)
  Connection to LDAP server failed for the 20 try!
[2005/09/19 16:52:13, 0] lib/smbldap.c:smbldap_open(882)
  smbldap_open: cannot access LDAP when not root..
[2005/09/19 16:52:13, 0] lib/smbldap.c:smbldap_search_suffix(1176)
  smbldap_search_suffix: Problem during the LDAP search:  (Timed out)
[2005/09/19 16:52:13, 0] rpc_server/srv_samr_nt.c:_samr_create_user(2350)
  could not add user/computer billgates$ to passdb.  Check permissions?
[2005/09/19 16:52:13, 3] rpc_server/srv_pipe_hnd.c:free_pipe_context(542)
  free_pipe_context: destroying talloc pool of size 22
[2005/09/19 16:52:13, 3] smbd/process.c:process_smb(1091)
  Transaction 33 of length 132
[2005/09/19 16:52:13, 3] smbd/process.c:switch_message(886)
  switch message SMBtrans (pid 17586) conn 0x837e080
[2005/09/19 16:52:13, 4] smbd/uid.c:change_to_user(194)
  change_to_user: Skipping user change - already user
[2005/09/19 16:52:13, 3] smbd/ipc.c:reply_trans(539)
  trans <\PIPE\> data=44 params=0 setup=2
[2005/09/19 16:52:13, 3] smbd/ipc.c:named_pipe(334)
  named pipe command on <> name
[2005/09/19 16:52:13, 4] rpc_server/srv_pipe_hnd.c:get_rpc_pipe(1168)
  search for pipe pnum=705d
[2005/09/19 16:52:13, 3] smbd/ipc.c:api_fd_reply(294)
  Got API command 0x26 on pipe "samr" (pnum 705d)
[2005/09/19 16:52:13, 3] rpc_server/srv_pipe_hnd.c:free_pipe_context(542)
  free_pipe_context: destroying talloc pool of size 0
[2005/09/19 16:52:13, 4] rpc_server/srv_pipe.c:api_rpcTNP(1531)
  api_rpcTNP: samr op 0x1 - api_rpcTNP: rpc command: SAMR_CLOSE_HND
[2005/09/19 16:52:13, 4]
rpc_server/srv_lsa_hnd.c:find_policy_by_hnd_internal(162)
  Found policy hnd[0] [000] 00 00 00 00 05 00 00 00  00 00 00 00 E9 24 2F 43 
........ .....$/C
  [010] B2 44 00 00                                       .D.. 
[2005/09/19 16:52:13, 3] rpc_server/srv_lsa_hnd.c:close_policy_hnd(200)
  Closed policy
[2005/09/19 16:52:13, 3] rpc_server/srv_pipe_hnd.c:free_pipe_context(542)
  free_pipe_context: destroying talloc pool of size 0
[2005/09/19 16:52:13, 3] smbd/process.c:process_smb(1091)
  Transaction 34 of length 132
[2005/09/19 16:52:13, 3] smbd/process.c:switch_message(886)
  switch message SMBtrans (pid 17586) conn 0x837e080
[2005/09/19 16:52:13, 4] smbd/uid.c:change_to_user(194)
  change_to_user: Skipping user change - already user
[2005/09/19 16:52:13, 3] smbd/ipc.c:reply_trans(539)
  trans <\PIPE\> data=44 params=0 setup=2
[2005/09/19 16:52:13, 3] smbd/ipc.c:named_pipe(334)
  named pipe command on <> name
[2005/09/19 16:52:13, 4] rpc_server/srv_pipe_hnd.c:get_rpc_pipe(1168)
  search for pipe pnum=705d
[2005/09/19 16:52:13, 3] smbd/ipc.c:api_fd_reply(294)
  Got API command 0x26 on pipe "samr" (pnum 705d)
[2005/09/19 16:52:13, 3] rpc_server/srv_pipe_hnd.c:free_pipe_context(542)
  free_pipe_context: destroying talloc pool of size 0
[2005/09/19 16:52:13, 4] rpc_server/srv_pipe.c:api_rpcTNP(1531)
  api_rpcTNP: samr op 0x1 - api_rpcTNP: rpc command: SAMR_CLOSE_HND
[2005/09/19 16:52:13, 4]
rpc_server/srv_lsa_hnd.c:find_policy_by_hnd_internal(162)
  Found policy hnd[0] [000] 00 00 00 00 04 00 00 00  00 00 00 00 E9 24 2F 43 
........ .....$/C
  [010] B2 44 00 00                                       .D.. 
[2005/09/19 16:52:13, 3] rpc_server/srv_lsa_hnd.c:close_policy_hnd(200)
  Closed policy
[2005/09/19 16:52:13, 3] rpc_server/srv_pipe_hnd.c:free_pipe_context(542)
  free_pipe_context: destroying talloc pool of size 0
[2005/09/19 16:52:13, 3] smbd/process.c:process_smb(1091)
  Transaction 35 of length 45
[2005/09/19 16:52:13, 3] smbd/process.c:switch_message(886)
  switch message SMBclose (pid 17586) conn 0x837e080
[2005/09/19 16:52:13, 4] smbd/uid.c:change_to_user(194)
  change_to_user: Skipping user change - already user
[2005/09/19 16:52:13, 4] rpc_server/srv_pipe_hnd.c:get_rpc_pipe(1168)
  search for pipe pnum=705d
[2005/09/19 16:52:13, 4] rpc_server/srv_pipe_hnd.c:close_rpc_pipe_hnd(1081)
  closed pipe name samr pnum=705d (pipes_open=1)
[2005/09/19 16:52:13, 3] smbd/process.c:process_smb(1091)
  Transaction 36 of length 132
[2005/09/19 16:52:13, 3] smbd/process.c:switch_message(886)
  switch message SMBtrans (pid 17586) conn 0x837e080
[2005/09/19 16:52:13, 4] smbd/uid.c:change_to_user(194)
  change_to_user: Skipping user change - already user
[2005/09/19 16:52:13, 3] smbd/ipc.c:reply_trans(539)
  trans <\PIPE\> data=44 params=0 setup=2
[2005/09/19 16:52:13, 3] smbd/ipc.c:named_pipe(334)
  named pipe command on <> name
[2005/09/19 16:52:13, 4] rpc_server/srv_pipe_hnd.c:get_rpc_pipe(1168)
  search for pipe pnum=705a
[2005/09/19 16:52:13, 3] smbd/ipc.c:api_fd_reply(294)
  Got API command 0x26 on pipe "lsarpc" (pnum 705a)
[2005/09/19 16:52:13, 3] rpc_server/srv_pipe_hnd.c:free_pipe_context(542)
  free_pipe_context: destroying talloc pool of size 0
[2005/09/19 16:52:13, 4] rpc_server/srv_pipe.c:api_rpcTNP(1531)
  api_rpcTNP: lsarpc op 0x0 - api_rpcTNP: rpc command: LSA_CLOSE
[2005/09/19 16:52:13, 4]
rpc_server/srv_lsa_hnd.c:find_policy_by_hnd_internal(162)
  Found policy hnd[0] [000] 00 00 00 00 01 00 00 00  00 00 00 00 E8 24 2F 43 
........ .....$/C
  [010] B2 44 00 00                                       .D.. 
[2005/09/19 16:52:13, 4]
rpc_server/srv_lsa_hnd.c:find_policy_by_hnd_internal(162)
  Found policy hnd[0] [000] 00 00 00 00 01 00 00 00  00 00 00 00 E8 24 2F 43 
........ .....$/C
  [010] B2 44 00 00                                       .D.. 
[2005/09/19 16:52:13, 3] rpc_server/srv_lsa_hnd.c:close_policy_hnd(200)
  Closed policy
[2005/09/19 16:52:13, 3] rpc_server/srv_pipe_hnd.c:free_pipe_context(542)
  free_pipe_context: destroying talloc pool of size 0
[2005/09/19 16:52:13, 3] smbd/process.c:process_smb(1091)
  Transaction 37 of length 45
[2005/09/19 16:52:13, 3] smbd/process.c:switch_message(886)
  switch message SMBclose (pid 17586) conn 0x837e080
[2005/09/19 16:52:13, 4] smbd/uid.c:change_to_user(194)
  change_to_user: Skipping user change - already user
[2005/09/19 16:52:13, 4] rpc_server/srv_pipe_hnd.c:get_rpc_pipe(1168)
  search for pipe pnum=705a
[2005/09/19 16:52:13, 4] rpc_server/srv_pipe_hnd.c:close_rpc_pipe_hnd(1081)
  closed pipe name lsarpc pnum=705a (pipes_open=0)
[2005/09/19 16:52:13, 3] smbd/process.c:process_smb(1091)
  Transaction 38 of length 43
[2005/09/19 16:52:13, 3] smbd/process.c:switch_message(886)
  switch message SMBulogoffX (pid 17586) conn 0x0
[2005/09/19 16:52:13, 3] smbd/sec_ctx.c:set_sec_ctx(288)
  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0
[2005/09/19 16:52:13, 4] auth/pampass.c:smb_pam_start(459)
  smb_pam_start: PAM: Init user: Administrator
[2005/09/19 16:52:13, 4] auth/pampass.c:smb_pam_start(476)
  smb_pam_start: PAM: setting rhost to: 192.168.10.169
[2005/09/19 16:52:13, 4] auth/pampass.c:smb_pam_start(485)
  smb_pam_start: PAM: setting tty
[2005/09/19 16:52:13, 4] auth/pampass.c:smb_pam_start(493)
  smb_pam_start: PAM: Init passed for user: Administrator
[2005/09/19 16:52:13, 4] auth/pampass.c:smb_internal_pam_session(630)
  smb_internal_pam_session: PAM: tty set to: smb/17586/100
[2005/09/19 16:52:13, 4] auth/pampass.c:smb_pam_end(440)
  smb_pam_end: PAM: PAM_END OK.
[2005/09/19 16:52:13, 3] smbd/reply.c:reply_ulogoffX(1264)
  ulogoffX vuid=100
[2005/09/19 16:52:13, 3] smbd/process.c:process_smb(1091)
  Transaction 39 of length 39
[2005/09/19 16:52:13, 3] smbd/process.c:switch_message(886)
  switch message SMBtdis (pid 17586) conn 0x837e080
[2005/09/19 16:52:13, 3] smbd/sec_ctx.c:set_sec_ctx(288)
  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0
[2005/09/19 16:52:13, 3] smbd/sec_ctx.c:set_sec_ctx(288)
  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0
[2005/09/19 16:52:13, 3] smbd/service.c:close_cnum(830)
  billgates (192.168.10.169) closed connection to service IPC$
[2005/09/19 16:52:13, 3] smbd/connection.c:yield_connection(69)
  Yielding connection to IPC$
[2005/09/19 16:52:13, 4] smbd/vfs.c:vfs_ChDir(660)
  vfs_ChDir to /
[2005/09/19 16:52:13, 3] smbd/sec_ctx.c:set_sec_ctx(288)
  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0
[2005/09/19 16:52:13, 3] smbd/process.c:timeout_processing(1334)
  timeout_processing: End of file from client (client has disconnected).
[2005/09/19 16:52:13, 3] smbd/sec_ctx.c:set_sec_ctx(288)
  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0
[2005/09/19 16:52:13, 2] smbd/server.c:exit_server(609)
  Closing connections
[2005/09/19 16:52:13, 3] smbd/connection.c:yield_connection(69)
  Yielding connection to 
[2005/09/19 16:52:13, 3] smbd/server.c:exit_server(652)
  Server exit (normal exit)
-------------- next part --------------

[global]

   workgroup = WORKGROUP
   netbios name = WOOKIE

   server string = %h server (Samba %v)


   wins server = 192.168.10.1

   dns proxy = no

   name resolve order = wins bcast host lmhosts 

   ldap admin dn = cn=admin,dc=hrcsb,dc=org
   ldap group suffix = ou=Groups
   ldap idmap suffix = ou=Idmap
   ldap machine suffix = ou=Computers
   ldap user suffix = ou=Users
   ldap suffix = dc=hrcsb,dc=org
   ldap ssl = no
   ldap timeout = 20

   enable privileges = yes


   log file = /var/log/samba/log.%m

   max log size = 1000

   syslog = 0

   panic action = /usr/share/samba/panic-action %d

   log level = 1

   domain logons = yes

   encrypt passwords = true

   #passdb backend = tdbsam guest
   passdb backend = ldapsam:ldap://ldap2.hrcsb.org

   obey pam restrictions = yes

   invalid users = root


   passwd program = /usr/bin/passwd %u
   passwd chat = *Enter\snew\sUNIX\spassword:* %n\n
*Retype\snew\sUNIX\spassword:* %n\n .


   logon script = logon-scripts\%m.bat
   logon home = \\%L\%U\Profile
   logon path = \\%L\%U\NTProfile
   logon drive = H:

   socket options = TCP_NODELAY


    smb ports = 139 445


[homes]
   comment = Home Directories
   browseable = no

   writable = no

   create mask = 0700

   directory mask = 0700

[netlogon]
   comment = Network Logon Service
   path = /samba/netlogon
   guest ok = yes
   writable = no
   share modes = no

[printers]
   comment = All Printers
   browseable = no
   path = /tmp
   printable = yes
   public = no
   writable = no
   create mode = 0700

[print$]
   comment = Printer Drivers
   path = /var/lib/samba/printers
   browseable = yes
   read only = yes
   guest ok = no



-------------- next part --------------

SID="S-1-5-21-4087610795-3070336623-1441377821"

slaveLDAP="ldap2.hrcsb.org"
slavePort="389"

masterLDAP="ldap2.hrcsb.org"
masterPort="389"

ldapTLS="0"

verify="require"

cafile="/etc/smbldap-tools/ca.pem"

clientcert="/etc/smbldap-tools/smbldap-tools.pem"

clientkey="/etc/smbldap-tools/smbldap-tools.key"

suffix="dc=hrcsb,dc=org"

usersdn="ou=Users,${suffix}"

computersdn="ou=Computers,${suffix}"

groupsdn="ou=Groups,${suffix}"

idmapdn="ou=Idmap,${suffix}"

sambaUnixIdPooldn="sambaDomainName=WORKGROUP,${suffix}"

scope="sub"

hash_encrypt="SSHA"

crypt_salt_format="%s"


userLoginShell="/bin/false"

userHome="/home/%U"

userGecos="Samba User"

defaultUserGid="513"

defaultComputerGid="515"

skeletonDir="/etc/skel"

defaultMaxPasswordAge="99"


userSmbHome
userProfile
userHomeDrive
userScript
mailDomain="hrcsb.org"


with_smbpasswd="0"
smbpasswd="/usr/bin/smbpasswd"

with_slappasswd="0"
slappasswd="/usr/sbin/slappasswd"

David Clymer

2005-Sep-29 16:54 UTC

head link

[Samba] PDC + LDAP, cannot access LDAP when not root (SOLVED)

On Tue, 2005-09-27 at 16:34 -0400, David Clymer wrote:> I'm using Debian Sarge, Samba (3.1.14a) with the ldapsam backend, and
> OpenLDAP (2.2.23).
> 
> When attempting to join an Windows XP+SP2 computer (BILLGATES) to my
> domain (WORKGROUP), using the Administrator account, I am told by
> windows: 'Access denied.'
> 
> The logs (attached) seem to indicate that the user Administrator is
> being authenticated (which would have? to use LDAP), but when It goes to
> add the computer to the domain, it fails. Apparently because samba is
> unable to access LDAP:
> 
> smbldap_open: cannot access LDAP when not root..
> 
> nobody and Administrator are the only users on the domain.
> 
> An interesting phenomenon that I've observed (perhaps it is related?):
> 
> testbox:/etc/samba# pdbedit -L
> Administrator:998:Administrator
> nobody:65534:nobody
> testbox:/etc/samba# net -U Administrator rpc group members 'Domain
Computers'
> Password:
> WORKGROUP\BILLGATES$
> testbox:/etc/samba# net -U Administrator rpc group members 'Domain
Admins'
> Password:
> WORKGROUP\Administrator
> testbox:/etc/samba# net -U Administrator rpc group members
'Administrators'
> Password:
> [2005/09/27 16:05:11, 0] rpc_client/cli_pipe.c:rpc_api_pipe(435)
>   cli_pipe: return critical error. Error was Call timed out: server did not
respond after 10000 milliseconds
> Couldn't list alias members
> 
> I don't understand why Administrators group listing fails, while the
> others don't.
> 
> Google searches yielded a bunch of similar problems for early versions
> of samba 3.0, related to modification of user groups. However that bug
> was supposedly fixed, and I've seen no reports of it occuring in later
> versions. There are no open bugs, that I could find, related to this on
> bugzilla.samba.org.
> 
> Is there any type of (mis)configuration that could result in the same
> sort of symptom?
> 
> attached is my smb.conf, smbldap.conf, and my samba log output (debug
> level=4)
> 
> I would be very grateful for any ideas, FMs to R, magic wands, etc. that
> anyone might have to offer.
> 
The FM to (re)R was the smb.conf man page ;o)

The solution:

add this to smb.conf:

enable privileges = yes

This allows you to grant special privileges to users (see man smb.conf
for more detail)

reload the samba config:

$ smbcontrol smbd reload-config

and grant the necessary rights to Administrator:

$ net -U Administrator rpc rights list
     SeMachineAccountPrivilege  Add machines to domain
      SePrintOperatorPrivilege  Manage printers
           SeAddUsersPrivilege  Add users and groups to the domain
     SeRemoteShutdownPrivilege  Force shutdown from a remote system
       SeDiskOperatorPrivilege  Manage disk shares

$ net -U Administrator rpc rights list Administrator

$ net -U Administrator rpc rights grant Administrator SeMachineAccountPrivilege
Successfully granted rights.

Now one can add machines to the domain. Better yet, the
administrator account does _not_ have to have a uid of 0!

-davidc

--
Under-Achievers Anonymous has an 11-step program.

Reasonably Related Threads

Search for more possibly parallel threads

samba - Sep 2005 - PDC + LDAP, cannot access LDAP when not root

[Samba] PDC + LDAP, cannot access LDAP when not root

[Samba] PDC + LDAP, cannot access LDAP when not root (SOLVED)

Reasonably Related Threads