I'm trying to figure out why I'm getting permission denied when trying
to print from one user account only. all others work fine.
the print server is configured as a domain controller backed by ldap.
aarcane@density:/var/log$ sudo testparm -s
Load smb config files from /etc/samba/smb.conf
rlimit_max: rlimit_max (1024) below minimum Windows limit (16384)
Processing section "[homes]"
Processing section "[netlogon]"
Processing section "[profiles]"
Processing section "[printers]"
Processing section "[print$]"
Processing section "[downloads]"
Processing section "[backups]"
Processing section "[videos]"
Processing section "[music]"
Processing section "[ebooks]"
Processing section "[games]"
Processing section "[misc]"
Processing section "[www]"
Loaded services file OK.
Server role: ROLE_DOMAIN_PDC
[global]
workgroup = TEMPEST
server string = File/Print Services (%h)
map to guest = Bad User
obey pam restrictions = Yes
passdb backend = ldapsam:ldap://density.aarcane.info/
log level = 4
syslog = 0
log file = /var/log/samba.log
max log size = 1000
socket options = TCP_NODELAY IPTOS_LOWDELAY SO_KEEPALIVE
SO_RCVBUF=8192 SO_SNDBUF=8192
printcap name = cups
add machine script = sudo /usr/sbin/smbldap-useradd -t 0 -w "%u"
logon script = logon.cmd
logon path = \\%N\profiles\%U
logon drive = V:
domain logons = Yes
os level = 30
preferred master = Yes
domain master = Yes
dns proxy = No
ldap admin dn = cn=admin,dc=aarcane,dc=info
ldap group suffix = ou=Groups
ldap idmap suffix = ou=Idmap
ldap machine suffix = ou=Machines
ldap passwd sync = yes
ldap suffix = dc=aarcane,dc=info
ldap ssl = no
ldap user suffix = ou=People
usershare allow guests = Yes
panic action = /usr/share/samba/panic-action %d
[homes]
comment = Home Directories
valid users = %S
read only = No
create mask = 0750
directory mask = 0750
browseable = No
[netlogon]
comment = Network Logon Service
path = /tank/samba/netlogon
guest ok = Yes
browseable = No
[profiles]
comment = Users profiles
path = /tank/samba/profiles
create mask = 01600
directory mask = 01700
guest ok = Yes
browseable = No
[printers]
comment = All Printers
path = /var/spool/samba
guest ok = Yes
printable = Yes
browseable = No
[print$]
comment = Printer Drivers
path = /var/lib/samba/printers
write list = root, @PrintAdmin
[misclenaeous shares omitted]
the printer has permissions granted to group ml-2851-nd (which is the
same model as the printer), "Print" checkbox is checked in permissions
window in windows.
getent shows: aarcane@density:/var/log$ getent group ml-2851-nd
ml-2851-nd:*:10013:reesie,debra,aarcane
reesie and debra can print fine, aarcane can't.
another printer is titled f4440, same as above.
aarcane@density:/var/log$ getent group f4440
f4440:*:10012:reesie,aarcane
reesie and aarcane can both print fine.
aside from the one group difference, both printers have the following
permissions:
CREATOR OWNER: Manage Documents
specific group: Print
PrintAdmin: All 3
Domain Admins: all 3
if I add special user permissions to the printer ml-2851-nd
"IZANAMI\aarcane" I can then print to the ml-2851-nd. it shouldn't be
needed, but it is.
The following is log output at level >= 3 of me trying to double-click
the printer from windows 7 explorer (I typed in \\density and
double-clicked the printer), which yields "Operation could not be
completed (error 0x05). Access is denied."
as you can see, there's no mention of the word "denied" in the
following log, so I can't figure out where or why it's getting
denied. I've checked all my permissions repeatedly, and can find no
problems.
[2011/05/15 14:41:13.466276, 3] smbd/process.c:1485(process_smb)
Transaction 1818 of length 2196 (0 toread)
[2011/05/15 14:41:13.466410, 3] smbd/process.c:1294(switch_message)
switch message SMBtrans (pid 6487) conn 0xb8fd6490
[2011/05/15 14:41:13.466457, 4] smbd/uid.c:257(change_to_user)
change_to_user: Skipping user change - already user
[2011/05/15 14:41:13.466518, 3] smbd/ipc.c:545(handle_trans)
trans <\PIPE\> data=2108 params=0 setup=2
[2011/05/15 14:41:13.466570, 3] smbd/ipc.c:496(named_pipe)
named pipe command on <> name
[2011/05/15 14:41:13.466617, 3] smbd/ipc.c:460(api_fd_reply)
Got API command 0x26 on pipe "spoolss" (pnum 2f54)
[2011/05/15 14:41:13.466686, 3]
rpc_server/srv_pipe_hnd.c:344(free_pipe_context)
free_pipe_context: destroying talloc pool of size 0
[2011/05/15 14:41:13.466736, 4] rpc_server/srv_pipe.c:2403(api_rpcTNP)
api_rpcTNP: \spoolss op 0x8 - api_rpcTNP: rpc command:
SPOOLSS_GETPRINTER
[2011/05/15 14:41:13.466804, 4]
rpc_server/srv_lsa_hnd.c:219(find_policy_by_hnd_internal)
Found policy hnd[0] [0000] 00 00 00 00 36 00 00 00 00 00 00 00 D0
4D 71 46 ....6... .....MqF
[0010] 57 19 00 00 W...
[2011/05/15 14:41:13.466942, 4]
rpc_server/srv_lsa_hnd.c:219(find_policy_by_hnd_internal)
Found policy hnd[0] [0000] 00 00 00 00 36 00 00 00 00 00 00 00 D0
4D 71 46 ....6... .....MqF
[0010] 57 19 00 00 W...
[2011/05/15 14:41:13.467088, 4]
rpc_server/srv_spoolss_nt.c:379(get_printer_snum)
short name:F4440
[2011/05/15 14:41:13.467553, 3]
rpc_server/srv_pipe_hnd.c:344(free_pipe_context)
free_pipe_context: destroying talloc pool of size 26
[2011/05/15 14:41:13.467760, 3] smbd/process.c:1485(process_smb)
Transaction 1819 of length 2196 (0 toread)
[2011/05/15 14:41:13.467804, 3] smbd/process.c:1294(switch_message)
switch message SMBtrans (pid 6487) conn 0xb8fd6490
[2011/05/15 14:41:13.467845, 4] smbd/uid.c:257(change_to_user)
change_to_user: Skipping user change - already user
[2011/05/15 14:41:13.467886, 3] smbd/ipc.c:545(handle_trans)
trans <\PIPE\> data=2108 params=0 setup=2
[2011/05/15 14:41:13.467923, 3] smbd/ipc.c:496(named_pipe)
named pipe command on <> name
[2011/05/15 14:41:13.467972, 3] smbd/ipc.c:460(api_fd_reply)
Got API command 0x26 on pipe "spoolss" (pnum 2f5b)
[2011/05/15 14:41:13.468023, 3]
rpc_server/srv_pipe_hnd.c:344(free_pipe_context)
free_pipe_context: destroying talloc pool of size 0
[2011/05/15 14:41:13.468060, 4] rpc_server/srv_pipe.c:2403(api_rpcTNP)
api_rpcTNP: \spoolss op 0x8 - api_rpcTNP: rpc command:
SPOOLSS_GETPRINTER
[2011/05/15 14:41:13.468111, 4]
rpc_server/srv_lsa_hnd.c:219(find_policy_by_hnd_internal)
Found policy hnd[0] [0000] 00 00 00 00 36 00 00 00 00 00 00 00 D0
4D 71 46 ....6... .....MqF
[0010] 57 19 00 00 W...
[2011/05/15 14:41:13.468216, 4]
rpc_server/srv_lsa_hnd.c:219(find_policy_by_hnd_internal)
Found policy hnd[0] [0000] 00 00 00 00 36 00 00 00 00 00 00 00 D0
4D 71 46 ....6... .....MqF
[0010] 57 19 00 00 W...
[2011/05/15 14:41:13.468322, 4]
rpc_server/srv_spoolss_nt.c:379(get_printer_snum)
short name:F4440
[2011/05/15 14:41:13.468681, 3]
rpc_server/srv_pipe_hnd.c:344(free_pipe_context)
free_pipe_context: destroying talloc pool of size 26
[2011/05/15 14:41:13.468828, 3] smbd/process.c:1485(process_smb)
Transaction 1820 of length 176 (0 toread)
[2011/05/15 14:41:13.468878, 3] smbd/process.c:1294(switch_message)
switch message SMBtrans (pid 6487) conn 0xb8fd6490
[2011/05/15 14:41:13.468915, 4] smbd/uid.c:257(change_to_user)
change_to_user: Skipping user change - already user
[2011/05/15 14:41:13.468953, 3] smbd/ipc.c:545(handle_trans)
trans <\PIPE\> data=88 params=0 setup=2
[2011/05/15 14:41:13.468999, 3] smbd/ipc.c:496(named_pipe)
named pipe command on <> name
[2011/05/15 14:41:13.469045, 3] smbd/ipc.c:460(api_fd_reply)
Got API command 0x26 on pipe "spoolss" (pnum 2f54)
[2011/05/15 14:41:13.469095, 3]
rpc_server/srv_pipe_hnd.c:344(free_pipe_context)
free_pipe_context: destroying talloc pool of size 0
[2011/05/15 14:41:13.469156, 4] rpc_server/srv_pipe.c:2403(api_rpcTNP)
api_rpcTNP: \spoolss op 0x1a - api_rpcTNP: rpc command:
SPOOLSS_GETPRINTERDATA
[2011/05/15 14:41:13.469208, 4]
rpc_server/srv_lsa_hnd.c:219(find_policy_by_hnd_internal)
Found policy hnd[0] [0000] 00 00 00 00 36 00 00 00 00 00 00 00 D0
4D 71 46 ....6... .....MqF
[0010] 57 19 00 00 W...
[2011/05/15 14:41:13.469331, 4]
rpc_server/srv_spoolss_nt.c:8577(_spoolss_GetPrinterDataEx)
_spoolss_GetPrinterDataEx
[2011/05/15 14:41:13.469367, 4]
rpc_server/srv_lsa_hnd.c:219(find_policy_by_hnd_internal)
Found policy hnd[0] [0000] 00 00 00 00 36 00 00 00 00 00 00 00 D0
4D 71 46 ....6... .....MqF
[0010] 57 19 00 00 W...
[2011/05/15 14:41:13.469495, 4]
rpc_server/srv_spoolss_nt.c:379(get_printer_snum)
short name:F4440
[2011/05/15 14:41:13.469784, 3]
rpc_server/srv_pipe_hnd.c:344(free_pipe_context)
free_pipe_context: destroying talloc pool of size 0
[2011/05/15 14:41:13.469918, 3] smbd/process.c:1485(process_smb)
Transaction 1821 of length 106 (0 toread)
[2011/05/15 14:41:13.469967, 3] smbd/process.c:1294(switch_message)
switch message SMBntcreateX (pid 6487) conn 0xb8fd6490
[2011/05/15 14:41:13.470003, 4] smbd/uid.c:257(change_to_user)
change_to_user: Skipping user change - already user
[2011/05/15 14:41:13.470063, 4] smbd/nttrans.c:283(nt_open_pipe)
nt_open_pipe: Opening pipe \spoolss.
[2011/05/15 14:41:13.470121, 4]
rpc_server/srv_pipe_hnd.c:99(make_internal_rpc_pipe_p)
Create pipe requested \spoolss
[2011/05/15 14:41:13.470193, 3] smbd/sec_ctx.c:210(push_sec_ctx)
push_sec_ctx(10001, 513) : sec_ctx_stack_ndx = 1
[2011/05/15 14:41:13.470242, 3] smbd/uid.c:429(push_conn_ctx)
push_conn_ctx(101) : conn_ctx_stack_ndx = 0
[2011/05/15 14:41:13.470279, 3] smbd/sec_ctx.c:310(set_sec_ctx)
setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1
[2011/05/15 14:41:13.471146, 3] smbd/sec_ctx.c:418(pop_sec_ctx)
pop_sec_ctx (10001, 513) - sec_ctx_stack_ndx = 0
[2011/05/15 14:41:13.471290, 4] lib/substitute.c:504(automount_server)
Home server: density
[2011/05/15 14:41:13.471361, 3] smbd/sec_ctx.c:210(push_sec_ctx)
push_sec_ctx(10001, 513) : sec_ctx_stack_ndx = 1
[2011/05/15 14:41:13.471415, 3] smbd/uid.c:429(push_conn_ctx)
push_conn_ctx(101) : conn_ctx_stack_ndx = 0
[2011/05/15 14:41:13.471458, 3] smbd/sec_ctx.c:310(set_sec_ctx)
setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1
[2011/05/15 14:41:13.471538, 3] smbd/sec_ctx.c:418(pop_sec_ctx)
pop_sec_ctx (10001, 513) - sec_ctx_stack_ndx = 0
[2011/05/15 14:41:13.471599, 4]
rpc_server/srv_pipe_hnd.c:162(make_internal_rpc_pipe_p)
Created internal pipe \spoolss (pipes_open=0)
[2011/05/15 14:41:13.471712, 3] smbd/process.c:1485(process_smb)
Transaction 1822 of length 2244 (0 toread)
[2011/05/15 14:41:13.471761, 3] smbd/process.c:1294(switch_message)
switch message SMBtrans (pid 6487) conn 0xb8fd6490
[2011/05/15 14:41:13.471811, 4] smbd/uid.c:257(change_to_user)
change_to_user: Skipping user change - already user
[2011/05/15 14:41:13.471865, 3] smbd/ipc.c:545(handle_trans)
trans <\PIPE\> data=2156 params=0 setup=2
[2011/05/15 14:41:13.471913, 3] smbd/ipc.c:496(named_pipe)
named pipe command on <> name
[2011/05/15 14:41:13.471954, 3] smbd/ipc.c:460(api_fd_reply)
Got API command 0x26 on pipe "spoolss" (pnum 2f54)
[2011/05/15 14:41:13.472017, 3]
rpc_server/srv_pipe_hnd.c:344(free_pipe_context)
free_pipe_context: destroying talloc pool of size 0
[2011/05/15 14:41:13.472063, 4] rpc_server/srv_pipe.c:2403(api_rpcTNP)
api_rpcTNP: \spoolss op 0x35 - api_rpcTNP: rpc command:
SPOOLSS_GETPRINTERDRIVER2
[2011/05/15 14:41:13.472138, 4]
rpc_server/srv_spoolss_nt.c:5126(_spoolss_GetPrinterDriver2)
_spoolss_GetPrinterDriver2
[2011/05/15 14:41:13.472183, 4]
rpc_server/srv_lsa_hnd.c:219(find_policy_by_hnd_internal)
Found policy hnd[0] [0000] 00 00 00 00 36 00 00 00 00 00 00 00 D0
4D 71 46 ....6... .....MqF
[0010] 57 19 00 00 W...
[2011/05/15 14:41:13.472304, 4]
rpc_server/srv_lsa_hnd.c:219(find_policy_by_hnd_internal)
Found policy hnd[0] [0000] 00 00 00 00 36 00 00 00 00 00 00 00 D0
4D 71 46 ....6... .....MqF
[0010] 57 19 00 00 W...
[2011/05/15 14:41:13.472422, 4]
rpc_server/srv_spoolss_nt.c:379(get_printer_snum)
short name:F4440
[2011/05/15 14:41:13.472804, 3]
rpc_server/srv_pipe_hnd.c:344(free_pipe_context)
free_pipe_context: destroying talloc pool of size 0
[2011/05/15 14:41:13.472928, 3] smbd/process.c:1485(process_smb)
Transaction 1823 of length 106 (0 toread)
[2011/05/15 14:41:13.472970, 3] smbd/process.c:1294(switch_message)
switch message SMBntcreateX (pid 6487) conn 0xb8fd6490
[2011/05/15 14:41:13.473004, 4] smbd/uid.c:257(change_to_user)
change_to_user: Skipping user change - already user
[2011/05/15 14:41:13.473041, 4] smbd/nttrans.c:283(nt_open_pipe)
nt_open_pipe: Opening pipe \spoolss.
[2011/05/15 14:41:13.473088, 4]
rpc_server/srv_pipe_hnd.c:99(make_internal_rpc_pipe_p)
Create pipe requested \spoolss
[2011/05/15 14:41:13.473148, 3] smbd/sec_ctx.c:210(push_sec_ctx)
push_sec_ctx(10001, 513) : sec_ctx_stack_ndx = 1
[2011/05/15 14:41:13.473188, 3] smbd/uid.c:429(push_conn_ctx)
push_conn_ctx(101) : conn_ctx_stack_ndx = 0
[2011/05/15 14:41:13.473220, 3] smbd/sec_ctx.c:310(set_sec_ctx)
setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1
[2011/05/15 14:41:13.473315, 3] smbd/sec_ctx.c:418(pop_sec_ctx)
pop_sec_ctx (10001, 513) - sec_ctx_stack_ndx = 0
[2011/05/15 14:41:13.473375, 4] lib/substitute.c:504(automount_server)
Home server: density
[2011/05/15 14:41:13.473429, 3] smbd/sec_ctx.c:210(push_sec_ctx)
push_sec_ctx(10001, 513) : sec_ctx_stack_ndx = 1
[2011/05/15 14:41:13.473469, 3] smbd/uid.c:429(push_conn_ctx)
push_conn_ctx(101) : conn_ctx_stack_ndx = 0
[2011/05/15 14:41:13.473502, 3] smbd/sec_ctx.c:310(set_sec_ctx)
setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1
[2011/05/15 14:41:13.473570, 3] smbd/sec_ctx.c:418(pop_sec_ctx)
pop_sec_ctx (10001, 513) - sec_ctx_stack_ndx = 0
[2011/05/15 14:41:13.473615, 4]
rpc_server/srv_pipe_hnd.c:162(make_internal_rpc_pipe_p)
Created internal pipe \spoolss (pipes_open=0)
[2011/05/15 14:41:13.473692, 3] smbd/process.c:1485(process_smb)
Transaction 1824 of length 2196 (0 toread)
[2011/05/15 14:41:13.473731, 3] smbd/process.c:1294(switch_message)
switch message SMBtrans (pid 6487) conn 0xb8fd6490
[2011/05/15 14:41:13.473764, 4] smbd/uid.c:257(change_to_user)
change_to_user: Skipping user change - already user
[2011/05/15 14:41:13.473802, 3] smbd/ipc.c:545(handle_trans)
trans <\PIPE\> data=2108 params=0 setup=2
[2011/05/15 14:41:13.473839, 3] smbd/ipc.c:496(named_pipe)
named pipe command on <> name
[2011/05/15 14:41:13.473871, 3] smbd/ipc.c:460(api_fd_reply)
Got API command 0x26 on pipe "spoolss" (pnum 2f54)
[2011/05/15 14:41:13.473917, 3]
rpc_server/srv_pipe_hnd.c:344(free_pipe_context)
free_pipe_context: destroying talloc pool of size 0
[2011/05/15 14:41:13.473953, 4] rpc_server/srv_pipe.c:2403(api_rpcTNP)
api_rpcTNP: \spoolss op 0x8 - api_rpcTNP: rpc command:
SPOOLSS_GETPRINTER
[2011/05/15 14:41:13.474007, 4]
rpc_server/srv_lsa_hnd.c:219(find_policy_by_hnd_internal)
Found policy hnd[0] [0000] 00 00 00 00 36 00 00 00 00 00 00 00 D0
4D 71 46 ....6... .....MqF
[0010] 57 19 00 00 W...
[2011/05/15 14:41:13.474112, 4]
rpc_server/srv_lsa_hnd.c:219(find_policy_by_hnd_internal)
Found policy hnd[0] [0000] 00 00 00 00 36 00 00 00 00 00 00 00 D0
4D 71 46 ....6... .....MqF
[0010] 57 19 00 00 W...
[2011/05/15 14:41:13.474212, 4]
rpc_server/srv_spoolss_nt.c:379(get_printer_snum)
short name:F4440
[2011/05/15 14:41:13.475005, 3]
rpc_server/srv_pipe_hnd.c:344(free_pipe_context)
free_pipe_context: destroying talloc pool of size 1342
[2011/05/15 14:41:13.475164, 3] smbd/process.c:1485(process_smb)
Transaction 1825 of length 106 (0 toread)
[2011/05/15 14:41:13.475209, 3] smbd/process.c:1294(switch_message)
switch message SMBntcreateX (pid 6487) conn 0xb8fd6490
[2011/05/15 14:41:13.475243, 4] smbd/uid.c:257(change_to_user)
change_to_user: Skipping user change - already user
[2011/05/15 14:41:13.475281, 4] smbd/nttrans.c:283(nt_open_pipe)
nt_open_pipe: Opening pipe \spoolss.
[2011/05/15 14:41:13.475327, 4]
rpc_server/srv_pipe_hnd.c:99(make_internal_rpc_pipe_p)
Create pipe requested \spoolss
[2011/05/15 14:41:13.475386, 3] smbd/sec_ctx.c:210(push_sec_ctx)
push_sec_ctx(10001, 513) : sec_ctx_stack_ndx = 1
[2011/05/15 14:41:13.475427, 3] smbd/uid.c:429(push_conn_ctx)
push_conn_ctx(101) : conn_ctx_stack_ndx = 0
[2011/05/15 14:41:13.475460, 3] smbd/sec_ctx.c:310(set_sec_ctx)
setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1
[2011/05/15 14:41:13.475536, 3] smbd/sec_ctx.c:418(pop_sec_ctx)
pop_sec_ctx (10001, 513) - sec_ctx_stack_ndx = 0
[2011/05/15 14:41:13.475596, 4] lib/substitute.c:504(automount_server)
Home server: density
[2011/05/15 14:41:13.475653, 3] smbd/sec_ctx.c:210(push_sec_ctx)
push_sec_ctx(10001, 513) : sec_ctx_stack_ndx = 1
[2011/05/15 14:41:13.475695, 3] smbd/uid.c:429(push_conn_ctx)
push_conn_ctx(101) : conn_ctx_stack_ndx = 0
[2011/05/15 14:41:13.475729, 3] smbd/sec_ctx.c:310(set_sec_ctx)
setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1
[2011/05/15 14:41:13.475800, 3] smbd/sec_ctx.c:418(pop_sec_ctx)
pop_sec_ctx (10001, 513) - sec_ctx_stack_ndx = 0
[2011/05/15 14:41:13.475876, 4]
rpc_server/srv_pipe_hnd.c:162(make_internal_rpc_pipe_p)
Created internal pipe \spoolss (pipes_open=0)
[2011/05/15 14:41:13.476725, 3] smbd/process.c:1485(process_smb)
Transaction 1826 of length 228 (0 toread)
[2011/05/15 14:41:13.476887, 3] smbd/process.c:1294(switch_message)
switch message SMBwriteX (pid 6487) conn 0xb8fd6490
[2011/05/15 14:41:13.476930, 4] smbd/uid.c:257(change_to_user)
change_to_user: Skipping user change - already user
[2011/05/15 14:41:13.477031, 3]
rpc_server/srv_pipe.c:1667(api_pipe_bind_req)
api_pipe_bind_req: \PIPE\spoolss -> \PIPE\spoolss
[2011/05/15 14:41:13.477080, 3]
rpc_server/srv_pipe.c:998(check_bind_req)
check_bind_req for \spoolss
[2011/05/15 14:41:13.477151, 3] smbd/pipes.c:352(pipe_write_andx_done)
writeX-IPC nwritten=160
[2011/05/15 14:41:13.477242, 3] smbd/process.c:1485(process_smb)
Transaction 1827 of length 228 (0 toread)
[2011/05/15 14:41:13.477290, 3] smbd/process.c:1294(switch_message)
switch message SMBwriteX (pid 6487) conn 0xb8fd6490
[2011/05/15 14:41:13.477342, 4] smbd/uid.c:257(change_to_user)
change_to_user: Skipping user change - already user
[2011/05/15 14:41:13.477399, 3]
rpc_server/srv_pipe.c:1667(api_pipe_bind_req)
api_pipe_bind_req: \PIPE\spoolss -> \PIPE\spoolss
[2011/05/15 14:41:13.477441, 3]
rpc_server/srv_pipe.c:998(check_bind_req)
check_bind_req for \spoolss
[2011/05/15 14:41:13.477519, 3] smbd/pipes.c:352(pipe_write_andx_done)
writeX-IPC nwritten=160
[2011/05/15 14:41:13.477597, 3] smbd/process.c:1485(process_smb)
Transaction 1828 of length 228 (0 toread)
[2011/05/15 14:41:13.477643, 3] smbd/process.c:1294(switch_message)
switch message SMBwriteX (pid 6487) conn 0xb8fd6490
[2011/05/15 14:41:13.477684, 4] smbd/uid.c:257(change_to_user)
change_to_user: Skipping user change - already user
[2011/05/15 14:41:13.477743, 3]
rpc_server/srv_pipe.c:1667(api_pipe_bind_req)
api_pipe_bind_req: \PIPE\spoolss -> \PIPE\spoolss
[2011/05/15 14:41:13.477787, 3]
rpc_server/srv_pipe.c:998(check_bind_req)
check_bind_req for \spoolss
[2011/05/15 14:41:13.477867, 3] smbd/pipes.c:352(pipe_write_andx_done)
writeX-IPC nwritten=160
[2011/05/15 14:41:13.477942, 3] smbd/process.c:1485(process_smb)
Transaction 1829 of length 63 (0 toread)
[2011/05/15 14:41:13.477989, 3] smbd/process.c:1294(switch_message)
switch message SMBreadX (pid 6487) conn 0xb8fd6490
[2011/05/15 14:41:13.478024, 4] smbd/uid.c:257(change_to_user)
change_to_user: Skipping user change - already user
[2011/05/15 14:41:13.478074, 3] smbd/pipes.c:462(pipe_read_andx_done)
readX-IPC min=1024 max=1024 nread=68
[2011/05/15 14:41:13.478161, 3] smbd/process.c:1485(process_smb)
Transaction 1830 of length 63 (0 toread)
[2011/05/15 14:41:13.478212, 3] smbd/process.c:1294(switch_message)
switch message SMBreadX (pid 6487) conn 0xb8fd6490
[2011/05/15 14:41:13.478247, 4] smbd/uid.c:257(change_to_user)
change_to_user: Skipping user change - already user
[2011/05/15 14:41:13.478295, 3] smbd/pipes.c:462(pipe_read_andx_done)
readX-IPC min=1024 max=1024 nread=68
[2011/05/15 14:41:13.478367, 3] smbd/process.c:1485(process_smb)
Transaction 1831 of length 63 (0 toread)
[2011/05/15 14:41:13.478426, 3] smbd/process.c:1294(switch_message)
switch message SMBreadX (pid 6487) conn 0xb8fd6490
[2011/05/15 14:41:13.478463, 4] smbd/uid.c:257(change_to_user)
change_to_user: Skipping user change - already user
[2011/05/15 14:41:13.478511, 3] smbd/pipes.c:462(pipe_read_andx_done)
readX-IPC min=1024 max=1024 nread=68
[2011/05/15 14:41:13.478596, 3] smbd/process.c:1485(process_smb)
Transaction 1832 of length 288 (0 toread)
[2011/05/15 14:41:13.478643, 3] smbd/process.c:1294(switch_message)
switch message SMBtrans (pid 6487) conn 0xb8fd6490
[2011/05/15 14:41:13.478679, 4] smbd/uid.c:257(change_to_user)
change_to_user: Skipping user change - already user
[2011/05/15 14:41:13.478721, 3] smbd/ipc.c:545(handle_trans)
trans <\PIPE\> data=200 params=0 setup=2
[2011/05/15 14:41:13.478768, 3] smbd/ipc.c:496(named_pipe)
named pipe command on <> name
[2011/05/15 14:41:13.478849, 3] smbd/ipc.c:460(api_fd_reply)
Got API command 0x26 on pipe "spoolss" (pnum 2fb5)
[2011/05/15 14:41:13.478908, 3]
rpc_server/srv_pipe_hnd.c:344(free_pipe_context)
free_pipe_context: destroying talloc pool of size 169
[2011/05/15 14:41:13.478957, 4] rpc_server/srv_pipe.c:2403(api_rpcTNP)
api_rpcTNP: \spoolss op 0x45 - api_rpcTNP: rpc command:
SPOOLSS_OPENPRINTEREX
checking name: \\Density\F4440
[2011/05/15 14:41:13.479069, 4]
rpc_server/srv_lsa_hnd.c:191(create_policy_hnd_internal)
Opened policy hnd[3] [0000] 00 00 00 00 97 00 00 00 00 00 00 00 D0
4D 79 48 ........ .....MyH
[0010] 57 19 00 00 W...
[2011/05/15 14:41:13.479191, 3]
rpc_server/srv_spoolss_nt.c:396(set_printer_hnd_printertype)
Setting printer type=\\Density\F4440
Printer is a printer
[2011/05/15 14:41:13.479247, 4]
rpc_server/srv_spoolss_nt.c:436(set_printer_hnd_name)
Setting printer name=\\Density\F4440 (len=15)
set_printer_hnd_name: Printer found: F4440 -> F4440
[2011/05/15 14:41:13.479508, 4]
rpc_server/srv_lsa_hnd.c:219(find_policy_by_hnd_internal)
Found policy hnd[0] [0000] 00 00 00 00 97 00 00 00 00 00 00 00 D0
4D 79 48 ........ .....MyH
[0010] 57 19 00 00 W...
[2011/05/15 14:41:13.479677, 4]
rpc_server/srv_lsa_hnd.c:219(find_policy_by_hnd_internal)
Found policy hnd[0] [0000] 00 00 00 00 97 00 00 00 00 00 00 00 D0
4D 79 48 ........ .....MyH
[0010] 57 19 00 00 W...
[2011/05/15 14:41:13.479801, 4]
rpc_server/srv_spoolss_nt.c:379(get_printer_snum)
short name:F4440
[2011/05/15 14:41:13.481016, 4]
rpc_server/srv_spoolss_nt.c:1732(_spoolss_OpenPrinterEx)
Setting printer access = PRINTER_ACCESS_USE
[2011/05/15 14:41:13.481138, 3]
rpc_server/srv_pipe_hnd.c:344(free_pipe_context)
free_pipe_context: destroying talloc pool of size 0
[2011/05/15 14:41:13.481291, 3] smbd/process.c:1485(process_smb)
Transaction 1833 of length 300 (0 toread)
[2011/05/15 14:41:13.481342, 3] smbd/process.c:1294(switch_message)
switch message SMBtrans (pid 6487) conn 0xb8fd6490
[2011/05/15 14:41:13.481381, 4] smbd/uid.c:257(change_to_user)
change_to_user: Skipping user change - already user
[2011/05/15 14:41:13.481433, 3] smbd/ipc.c:545(handle_trans)
trans <\PIPE\> data=212 params=0 setup=2
[2011/05/15 14:41:13.481481, 3] smbd/ipc.c:496(named_pipe)
named pipe command on <> name
[2011/05/15 14:41:13.481522, 3] smbd/ipc.c:460(api_fd_reply)
Got API command 0x26 on pipe "spoolss" (pnum 2fb6)
[2011/05/15 14:41:13.481578, 3]
rpc_server/srv_pipe_hnd.c:344(free_pipe_context)
free_pipe_context: destroying talloc pool of size 169
[2011/05/15 14:41:13.481625, 4] rpc_server/srv_pipe.c:2403(api_rpcTNP)
api_rpcTNP: \spoolss op 0x45 - api_rpcTNP: rpc command:
SPOOLSS_OPENPRINTEREX
checking name: \\Density\ML-2851-ND
[2011/05/15 14:41:13.481719, 4]
rpc_server/srv_lsa_hnd.c:191(create_policy_hnd_internal)
Opened policy hnd[4] [0000] 00 00 00 00 98 00 00 00 00 00 00 00 D0
4D 79 48 ........ .....MyH
[0010] 57 19 00 00 W...
[2011/05/15 14:41:13.481847, 3]
rpc_server/srv_spoolss_nt.c:396(set_printer_hnd_printertype)
Setting printer type=\\Density\ML-2851-ND
Printer is a printer
[2011/05/15 14:41:13.481893, 4]
rpc_server/srv_spoolss_nt.c:436(set_printer_hnd_name)
Setting printer name=\\Density\ML-2851-ND (len=20)
set_printer_hnd_name: Printer found: ML-2851-ND -> ML-2851-ND
[2011/05/15 14:41:13.482066, 4]
rpc_server/srv_lsa_hnd.c:219(find_policy_by_hnd_internal)
Found policy hnd[0] [0000] 00 00 00 00 98 00 00 00 00 00 00 00 D0
4D 79 48 ........ .....MyH
[0010] 57 19 00 00 W...
[2011/05/15 14:41:13.482176, 4]
rpc_server/srv_lsa_hnd.c:219(find_policy_by_hnd_internal)
Found policy hnd[0] [0000] 00 00 00 00 98 00 00 00 00 00 00 00 D0
4D 79 48 ........ .....MyH
[0010] 57 19 00 00 W...
[2011/05/15 14:41:13.482300, 4]
rpc_server/srv_spoolss_nt.c:379(get_printer_snum)
short name:ML-2851-ND
[2011/05/15 14:41:13.483541, 4]
rpc_server/srv_spoolss_nt.c:1732(_spoolss_OpenPrinterEx)
Setting printer access = PRINTER_ACCESS_USE
[2011/05/15 14:41:13.483657, 3]
rpc_server/srv_pipe_hnd.c:344(free_pipe_context)
free_pipe_context: destroying talloc pool of size 0
[2011/05/15 14:41:13.483795, 3] smbd/process.c:1485(process_smb)
Transaction 1834 of length 288 (0 toread)
[2011/05/15 14:41:13.483841, 3] smbd/process.c:1294(switch_message)
switch message SMBtrans (pid 6487) conn 0xb8fd6490
[2011/05/15 14:41:13.483879, 4] smbd/uid.c:257(change_to_user)
change_to_user: Skipping user change - already user
[2011/05/15 14:41:13.483923, 3] smbd/ipc.c:545(handle_trans)
trans <\PIPE\> data=200 params=0 setup=2
[2011/05/15 14:41:13.483965, 3] smbd/ipc.c:496(named_pipe)
named pipe command on <> name
[2011/05/15 14:41:13.484001, 3] smbd/ipc.c:460(api_fd_reply)
Got API command 0x26 on pipe "spoolss" (pnum 2fb7)
[2011/05/15 14:41:13.484051, 3]
rpc_server/srv_pipe_hnd.c:344(free_pipe_context)
free_pipe_context: destroying talloc pool of size 169
[2011/05/15 14:41:13.484107, 4] rpc_server/srv_pipe.c:2403(api_rpcTNP)
api_rpcTNP: \spoolss op 0x45 - api_rpcTNP: rpc command:
SPOOLSS_OPENPRINTEREX
checking name: \\Density\F4440
[2011/05/15 14:41:13.484196, 4]
rpc_server/srv_lsa_hnd.c:191(create_policy_hnd_internal)
Opened policy hnd[5] [0000] 00 00 00 00 99 00 00 00 00 00 00 00 D0
4D 79 48 ........ .....MyH
[0010] 57 19 00 00 W...
[2011/05/15 14:41:13.484323, 3]
rpc_server/srv_spoolss_nt.c:396(set_printer_hnd_printertype)
Setting printer type=\\Density\F4440
Printer is a printer
[2011/05/15 14:41:13.484377, 4]
rpc_server/srv_spoolss_nt.c:436(set_printer_hnd_name)
Setting printer name=\\Density\F4440 (len=15)
set_printer_hnd_name: Printer found: F4440 -> F4440
[2011/05/15 14:41:13.484633, 4]
rpc_server/srv_lsa_hnd.c:219(find_policy_by_hnd_internal)
Found policy hnd[0] [0000] 00 00 00 00 99 00 00 00 00 00 00 00 D0
4D 79 48 ........ .....MyH
[0010] 57 19 00 00 W...
[2011/05/15 14:41:13.484740, 4]
rpc_server/srv_lsa_hnd.c:219(find_policy_by_hnd_internal)
Found policy hnd[0] [0000] 00 00 00 00 99 00 00 00 00 00 00 00 D0
4D 79 48 ........ .....MyH
[0010] 57 19 00 00 W...
[2011/05/15 14:41:13.484857, 4]
rpc_server/srv_spoolss_nt.c:379(get_printer_snum)
short name:F4440
[2011/05/15 14:41:13.486039, 4]
rpc_server/srv_spoolss_nt.c:1732(_spoolss_OpenPrinterEx)
Setting printer access = PRINTER_ACCESS_USE
[2011/05/15 14:41:13.486167, 3]
rpc_server/srv_pipe_hnd.c:344(free_pipe_context)
free_pipe_context: destroying talloc pool of size 0
[2011/05/15 14:41:13.486313, 3] smbd/process.c:1485(process_smb)
Transaction 1835 of length 132 (0 toread)
[2011/05/15 14:41:13.486371, 3] smbd/process.c:1294(switch_message)
switch message SMBtrans (pid 6487) conn 0xb8fd6490
[2011/05/15 14:41:13.486409, 4] smbd/uid.c:257(change_to_user)
change_to_user: Skipping user change - already user
[2011/05/15 14:41:13.486455, 3] smbd/ipc.c:545(handle_trans)
trans <\PIPE\> data=44 params=0 setup=2
[2011/05/15 14:41:13.486502, 3] smbd/ipc.c:496(named_pipe)
named pipe command on <> name
[2011/05/15 14:41:13.486544, 3] smbd/ipc.c:460(api_fd_reply)
Got API command 0x26 on pipe "spoolss" (pnum 2fb5)
[2011/05/15 14:41:13.486598, 3]
rpc_server/srv_pipe_hnd.c:344(free_pipe_context)
free_pipe_context: destroying talloc pool of size 0
[2011/05/15 14:41:13.486643, 4] rpc_server/srv_pipe.c:2403(api_rpcTNP)
api_rpcTNP: \spoolss op 0x1d - api_rpcTNP: rpc command:
SPOOLSS_CLOSEPRINTER
[2011/05/15 14:41:13.486704, 4]
rpc_server/srv_lsa_hnd.c:219(find_policy_by_hnd_internal)
Found policy hnd[2] [0000] 00 00 00 00 97 00 00 00 00 00 00 00 D0
4D 79 48 ........ .....MyH
[0010] 57 19 00 00 W...
[2011/05/15 14:41:13.486831, 4]
rpc_server/srv_lsa_hnd.c:219(find_policy_by_hnd_internal)
Found policy hnd[2] [0000] 00 00 00 00 97 00 00 00 00 00 00 00 D0
4D 79 48 ........ .....MyH
[0010] 57 19 00 00 W...
[2011/05/15 14:41:13.487026, 4]
rpc_server/srv_lsa_hnd.c:219(find_policy_by_hnd_internal)
Found policy hnd[2] [0000] 00 00 00 00 97 00 00 00 00 00 00 00 D0
4D 79 48 ........ .....MyH
[0010] 57 19 00 00 W...
[2011/05/15 14:41:13.487149, 3]
rpc_server/srv_lsa_hnd.c:258(close_policy_hnd)
Closed policy
[2011/05/15 14:41:13.487196, 3]
rpc_server/srv_pipe_hnd.c:344(free_pipe_context)
free_pipe_context: destroying talloc pool of size 0
[2011/05/15 14:41:13.487305, 3] smbd/process.c:1485(process_smb)
Transaction 1836 of length 106 (0 toread)
[2011/05/15 14:41:13.487352, 3] smbd/process.c:1294(switch_message)
switch message SMBntcreateX (pid 6487) conn 0xb8fd6490
[2011/05/15 14:41:13.487393, 4] smbd/uid.c:257(change_to_user)
change_to_user: Skipping user change - already user
[2011/05/15 14:41:13.487440, 4] smbd/nttrans.c:283(nt_open_pipe)
nt_open_pipe: Opening pipe \spoolss.
[2011/05/15 14:41:13.487499, 4]
rpc_server/srv_pipe_hnd.c:99(make_internal_rpc_pipe_p)
Create pipe requested \spoolss
[2011/05/15 14:41:13.487570, 3] smbd/sec_ctx.c:210(push_sec_ctx)
push_sec_ctx(10001, 513) : sec_ctx_stack_ndx = 1
[2011/05/15 14:41:13.487624, 3] smbd/uid.c:429(push_conn_ctx)
push_conn_ctx(101) : conn_ctx_stack_ndx = 0
[2011/05/15 14:41:13.487662, 3] smbd/sec_ctx.c:310(set_sec_ctx)
setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1
[2011/05/15 14:41:13.487763, 3] smbd/sec_ctx.c:418(pop_sec_ctx)
pop_sec_ctx (10001, 513) - sec_ctx_stack_ndx = 0
[2011/05/15 14:41:13.487839, 4] lib/substitute.c:504(automount_server)
Home server: density
[2011/05/15 14:41:13.487899, 3] smbd/sec_ctx.c:210(push_sec_ctx)
push_sec_ctx(10001, 513) : sec_ctx_stack_ndx = 1
[2011/05/15 14:41:13.487946, 3] smbd/uid.c:429(push_conn_ctx)
push_conn_ctx(101) : conn_ctx_stack_ndx = 0
[2011/05/15 14:41:13.487987, 3] smbd/sec_ctx.c:310(set_sec_ctx)
setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1
[2011/05/15 14:41:13.488063, 3] smbd/sec_ctx.c:418(pop_sec_ctx)
pop_sec_ctx (10001, 513) - sec_ctx_stack_ndx = 0
[2011/05/15 14:41:13.488121, 4]
rpc_server/srv_pipe_hnd.c:162(make_internal_rpc_pipe_p)
Created internal pipe \spoolss (pipes_open=0)
[2011/05/15 14:41:13.488198, 3] smbd/process.c:1485(process_smb)
Transaction 1837 of length 132 (0 toread)
[2011/05/15 14:41:13.488244, 3] smbd/process.c:1294(switch_message)
switch message SMBtrans (pid 6487) conn 0xb8fd6490
[2011/05/15 14:41:13.488285, 4] smbd/uid.c:257(change_to_user)
change_to_user: Skipping user change - already user
[2011/05/15 14:41:13.488328, 3] smbd/ipc.c:545(handle_trans)
trans <\PIPE\> data=44 params=0 setup=2
[2011/05/15 14:41:13.488372, 3] smbd/ipc.c:496(named_pipe)
named pipe command on <> name
[2011/05/15 14:41:13.488412, 3] smbd/ipc.c:460(api_fd_reply)
Got API command 0x26 on pipe "spoolss" (pnum 2fb6)
[2011/05/15 14:41:13.488461, 3]
rpc_server/srv_pipe_hnd.c:344(free_pipe_context)
free_pipe_context: destroying talloc pool of size 0
[2011/05/15 14:41:13.488499, 4] rpc_server/srv_pipe.c:2403(api_rpcTNP)
api_rpcTNP: \spoolss op 0x1d - api_rpcTNP: rpc command:
SPOOLSS_CLOSEPRINTER
[2011/05/15 14:41:13.488548, 4]
rpc_server/srv_lsa_hnd.c:219(find_policy_by_hnd_internal)
Found policy hnd[1] [0000] 00 00 00 00 98 00 00 00 00 00 00 00 D0
4D 79 48 ........ .....MyH
[0010] 57 19 00 00 W...
[2011/05/15 14:41:13.488673, 4]
rpc_server/srv_lsa_hnd.c:219(find_policy_by_hnd_internal)
Found policy hnd[1] [0000] 00 00 00 00 98 00 00 00 00 00 00 00 D0
4D 79 48 ........ .....MyH
[0010] 57 19 00 00 W...
[2011/05/15 14:41:13.488801, 4]
rpc_server/srv_lsa_hnd.c:219(find_policy_by_hnd_internal)
Found policy hnd[1] [0000] 00 00 00 00 98 00 00 00 00 00 00 00 D0
4D 79 48 ........ .....MyH
[0010] 57 19 00 00 W...
[2011/05/15 14:41:13.488939, 3]
rpc_server/srv_lsa_hnd.c:258(close_policy_hnd)
Closed policy
[2011/05/15 14:41:13.488979, 3]
rpc_server/srv_pipe_hnd.c:344(free_pipe_context)
free_pipe_context: destroying talloc pool of size 0
[2011/05/15 14:41:13.489080, 3] smbd/process.c:1485(process_smb)
Transaction 1838 of length 45 (0 toread)
[2011/05/15 14:41:13.489127, 3] smbd/process.c:1294(switch_message)
switch message SMBclose (pid 6487) conn 0xb8fd6490
[2011/05/15 14:41:13.489167, 4] smbd/uid.c:257(change_to_user)
change_to_user: Skipping user change - already user
[2011/05/15 14:41:13.489208, 3] smbd/reply.c:4634(reply_close)
close fd=-1 fnum=12213 (numopen=7)
[2011/05/15 14:41:13.489299, 3] smbd/process.c:1485(process_smb)
Transaction 1839 of length 2196 (0 toread)
[2011/05/15 14:41:13.489345, 3] smbd/process.c:1294(switch_message)
switch message SMBtrans (pid 6487) conn 0xb8fd6490
[2011/05/15 14:41:13.489385, 4] smbd/uid.c:257(change_to_user)
change_to_user: Skipping user change - already user
[2011/05/15 14:41:13.489430, 3] smbd/ipc.c:545(handle_trans)
trans <\PIPE\> data=2108 params=0 setup=2
[2011/05/15 14:41:13.489474, 3] smbd/ipc.c:496(named_pipe)
named pipe command on <> name
[2011/05/15 14:41:13.489513, 3] smbd/ipc.c:460(api_fd_reply)
Got API command 0x26 on pipe "spoolss" (pnum 2f54)
[2011/05/15 14:41:13.489565, 3]
rpc_server/srv_pipe_hnd.c:344(free_pipe_context)
free_pipe_context: destroying talloc pool of size 0
[2011/05/15 14:41:13.489609, 4] rpc_server/srv_pipe.c:2403(api_rpcTNP)
api_rpcTNP: \spoolss op 0x8 - api_rpcTNP: rpc command:
SPOOLSS_GETPRINTER
[2011/05/15 14:41:13.489669, 4]
rpc_server/srv_lsa_hnd.c:219(find_policy_by_hnd_internal)
Found policy hnd[1] [0000] 00 00 00 00 36 00 00 00 00 00 00 00 D0
4D 71 46 ....6... .....MqF
[0010] 57 19 00 00 W...
[2011/05/15 14:41:13.489789, 4]
rpc_server/srv_lsa_hnd.c:219(find_policy_by_hnd_internal)
Found policy hnd[1] [0000] 00 00 00 00 36 00 00 00 00 00 00 00 D0
4D 71 46 ....6... .....MqF
[0010] 57 19 00 00 W...
[2011/05/15 14:41:13.489904, 4]
rpc_server/srv_spoolss_nt.c:379(get_printer_snum)
short name:F4440
[2011/05/15 14:41:13.490324, 3]
rpc_server/srv_pipe_hnd.c:344(free_pipe_context)
free_pipe_context: destroying talloc pool of size 26
[2011/05/15 14:41:13.490455, 3] smbd/process.c:1485(process_smb)
Transaction 1840 of length 228 (0 toread)
[2011/05/15 14:41:13.490504, 3] smbd/process.c:1294(switch_message)
switch message SMBwriteX (pid 6487) conn 0xb8fd6490
[2011/05/15 14:41:13.490544, 4] smbd/uid.c:257(change_to_user)
change_to_user: Skipping user change - already user
[2011/05/15 14:41:13.490608, 3]
rpc_server/srv_pipe.c:1667(api_pipe_bind_req)
api_pipe_bind_req: \PIPE\spoolss -> \PIPE\spoolss
[2011/05/15 14:41:13.490650, 3]
rpc_server/srv_pipe.c:998(check_bind_req)
check_bind_req for \spoolss
[2011/05/15 14:41:13.490707, 3] smbd/pipes.c:352(pipe_write_andx_done)
writeX-IPC nwritten=160
[2011/05/15 14:41:13.492242, 3] smbd/process.c:1485(process_smb)
Transaction 1841 of length 63 (0 toread)
[2011/05/15 14:41:13.492360, 3] smbd/process.c:1294(switch_message)
switch message SMBreadX (pid 6487) conn 0xb8fd6490
[2011/05/15 14:41:13.492400, 4] smbd/uid.c:257(change_to_user)
change_to_user: Skipping user change - already user
[2011/05/15 14:41:13.492474, 3] smbd/pipes.c:462(pipe_read_andx_done)
readX-IPC min=1024 max=1024 nread=68
[2011/05/15 14:41:13.493123, 3] smbd/process.c:1485(process_smb)
Transaction 1842 of length 288 (0 toread)
[2011/05/15 14:41:13.493237, 3] smbd/process.c:1294(switch_message)
switch message SMBtrans (pid 6487) conn 0xb8fd6490
[2011/05/15 14:41:13.493275, 4] smbd/uid.c:257(change_to_user)
change_to_user: Skipping user change - already user
[2011/05/15 14:41:13.493327, 3] smbd/ipc.c:545(handle_trans)
trans <\PIPE\> data=200 params=0 setup=2
[2011/05/15 14:41:13.493375, 3] smbd/ipc.c:496(named_pipe)
named pipe command on <> name
[2011/05/15 14:41:13.493438, 3] smbd/ipc.c:460(api_fd_reply)
Got API command 0x26 on pipe "spoolss" (pnum 2fb8)
[2011/05/15 14:41:13.493497, 3]
rpc_server/srv_pipe_hnd.c:344(free_pipe_context)
free_pipe_context: destroying talloc pool of size 169
[2011/05/15 14:41:13.493546, 4] rpc_server/srv_pipe.c:2403(api_rpcTNP)
api_rpcTNP: \spoolss op 0x45 - api_rpcTNP: rpc command:
SPOOLSS_OPENPRINTEREX
checking name: \\Density\F4440
[2011/05/15 14:41:13.493644, 4]
rpc_server/srv_lsa_hnd.c:191(create_policy_hnd_internal)
Opened policy hnd[4] [0000] 00 00 00 00 9A 00 00 00 00 00 00 00 D0
4D 79 48 ........ .....MyH
[0010] 57 19 00 00 W...
[2011/05/15 14:41:13.493765, 3]
rpc_server/srv_spoolss_nt.c:396(set_printer_hnd_printertype)
Setting printer type=\\Density\F4440
Printer is a printer
[2011/05/15 14:41:13.493820, 4]
rpc_server/srv_spoolss_nt.c:436(set_printer_hnd_name)
Setting printer name=\\Density\F4440 (len=15)
set_printer_hnd_name: Printer found: F4440 -> F4440
[2011/05/15 14:41:13.494069, 4]
rpc_server/srv_lsa_hnd.c:219(find_policy_by_hnd_internal)
Found policy hnd[0] [0000] 00 00 00 00 9A 00 00 00 00 00 00 00 D0
4D 79 48 ........ .....MyH
[0010] 57 19 00 00 W...
[2011/05/15 14:41:13.494199, 4]
rpc_server/srv_lsa_hnd.c:219(find_policy_by_hnd_internal)
Found policy hnd[0] [0000] 00 00 00 00 9A 00 00 00 00 00 00 00 D0
4D 79 48 ........ .....MyH
[0010] 57 19 00 00 W...
[2011/05/15 14:41:13.494320, 4]
rpc_server/srv_spoolss_nt.c:379(get_printer_snum)
short name:F4440
[2011/05/15 14:41:13.495569, 4]
rpc_server/srv_spoolss_nt.c:1732(_spoolss_OpenPrinterEx)
Setting printer access = PRINTER_ACCESS_USE
[2011/05/15 14:41:13.495700, 3]
rpc_server/srv_pipe_hnd.c:344(free_pipe_context)
free_pipe_context: destroying talloc pool of size 0
[2011/05/15 14:41:13.495850, 3] smbd/process.c:1485(process_smb)
Transaction 1843 of length 45 (0 toread)
[2011/05/15 14:41:13.495900, 3] smbd/process.c:1294(switch_message)
switch message SMBclose (pid 6487) conn 0xb8fd6490
[2011/05/15 14:41:13.495937, 4] smbd/uid.c:257(change_to_user)
change_to_user: Skipping user change - already user
[2011/05/15 14:41:13.495974, 3] smbd/reply.c:4634(reply_close)
close fd=-1 fnum=12214 (numopen=6)
[2011/05/15 14:41:13.496116, 3] smbd/process.c:1485(process_smb)
Transaction 1844 of length 176 (0 toread)
[2011/05/15 14:41:13.496162, 3] smbd/process.c:1294(switch_message)
switch message SMBtrans (pid 6487) conn 0xb8fd6490
[2011/05/15 14:41:13.496198, 4] smbd/uid.c:257(change_to_user)
change_to_user: Skipping user change - already user
[2011/05/15 14:41:13.496238, 3] smbd/ipc.c:545(handle_trans)
trans <\PIPE\> data=88 params=0 setup=2
[2011/05/15 14:41:13.496284, 3] smbd/ipc.c:496(named_pipe)
named pipe command on <> name
[2011/05/15 14:41:13.496326, 3] smbd/ipc.c:460(api_fd_reply)
Got API command 0x26 on pipe "spoolss" (pnum 2f54)
[2011/05/15 14:41:13.496381, 3]
rpc_server/srv_pipe_hnd.c:344(free_pipe_context)
free_pipe_context: destroying talloc pool of size 0
[2011/05/15 14:41:13.496425, 4] rpc_server/srv_pipe.c:2403(api_rpcTNP)
api_rpcTNP: \spoolss op 0x1a - api_rpcTNP: rpc command:
SPOOLSS_GETPRINTERDATA
[2011/05/15 14:41:13.496493, 4]
rpc_server/srv_lsa_hnd.c:219(find_policy_by_hnd_internal)
Found policy hnd[2] [0000] 00 00 00 00 36 00 00 00 00 00 00 00 D0
4D 71 46 ....6... .....MqF
[0010] 57 19 00 00 W...
[2011/05/15 14:41:13.496631, 4]
rpc_server/srv_spoolss_nt.c:8577(_spoolss_GetPrinterDataEx)
_spoolss_GetPrinterDataEx
[2011/05/15 14:41:13.496668, 4]
rpc_server/srv_lsa_hnd.c:219(find_policy_by_hnd_internal)
Found policy hnd[2] [0000] 00 00 00 00 36 00 00 00 00 00 00 00 D0
4D 71 46 ....6... .....MqF
[0010] 57 19 00 00 W...
[2011/05/15 14:41:13.496791, 4]
rpc_server/srv_spoolss_nt.c:379(get_printer_snum)
short name:F4440
[2011/05/15 14:41:13.497174, 3]
rpc_server/srv_pipe_hnd.c:344(free_pipe_context)
free_pipe_context: destroying talloc pool of size 0
[2011/05/15 14:41:13.497295, 3] smbd/process.c:1485(process_smb)
Transaction 1845 of length 132 (0 toread)
[2011/05/15 14:41:13.497343, 3] smbd/process.c:1294(switch_message)
switch message SMBtrans (pid 6487) conn 0xb8fd6490
[2011/05/15 14:41:13.497379, 4] smbd/uid.c:257(change_to_user)
change_to_user: Skipping user change - already user
[2011/05/15 14:41:13.497419, 3] smbd/ipc.c:545(handle_trans)
trans <\PIPE\> data=44 params=0 setup=2
[2011/05/15 14:41:13.497464, 3] smbd/ipc.c:496(named_pipe)
named pipe command on <> name
[2011/05/15 14:41:13.497504, 3] smbd/ipc.c:460(api_fd_reply)
Got API command 0x26 on pipe "spoolss" (pnum 2fb8)
[2011/05/15 14:41:13.497553, 3]
rpc_server/srv_pipe_hnd.c:344(free_pipe_context)
free_pipe_context: destroying talloc pool of size 0
[2011/05/15 14:41:13.497596, 4] rpc_server/srv_pipe.c:2403(api_rpcTNP)
api_rpcTNP: \spoolss op 0x1d - api_rpcTNP: rpc command:
SPOOLSS_CLOSEPRINTER
[2011/05/15 14:41:13.497650, 4]
rpc_server/srv_lsa_hnd.c:219(find_policy_by_hnd_internal)
Found policy hnd[0] [0000] 00 00 00 00 9A 00 00 00 00 00 00 00 D0
4D 79 48 ........ .....MyH
[0010] 57 19 00 00 W...
[2011/05/15 14:41:13.497782, 4]
rpc_server/srv_lsa_hnd.c:219(find_policy_by_hnd_internal)
Found policy hnd[0] [0000] 00 00 00 00 9A 00 00 00 00 00 00 00 D0
4D 79 48 ........ .....MyH
[0010] 57 19 00 00 W...
[2011/05/15 14:41:13.497900, 4]
rpc_server/srv_lsa_hnd.c:219(find_policy_by_hnd_internal)
Found policy hnd[0] [0000] 00 00 00 00 9A 00 00 00 00 00 00 00 D0
4D 79 48 ........ .....MyH
[0010] 57 19 00 00 W...
[2011/05/15 14:41:13.498026, 3]
rpc_server/srv_lsa_hnd.c:258(close_policy_hnd)
Closed policy
[2011/05/15 14:41:13.498067, 3]
rpc_server/srv_pipe_hnd.c:344(free_pipe_context)
free_pipe_context: destroying talloc pool of size 0
[2011/05/15 14:41:13.498168, 3] smbd/process.c:1485(process_smb)
Transaction 1846 of length 106 (0 toread)
[2011/05/15 14:41:13.498214, 3] smbd/process.c:1294(switch_message)
switch message SMBntcreateX (pid 6487) conn 0xb8fd6490
[2011/05/15 14:41:13.498251, 4] smbd/uid.c:257(change_to_user)
change_to_user: Skipping user change - already user
[2011/05/15 14:41:13.498289, 4] smbd/nttrans.c:283(nt_open_pipe)
nt_open_pipe: Opening pipe \spoolss.
[2011/05/15 14:41:13.498346, 4]
rpc_server/srv_pipe_hnd.c:99(make_internal_rpc_pipe_p)
Create pipe requested \spoolss
[2011/05/15 14:41:13.498414, 3] smbd/sec_ctx.c:210(push_sec_ctx)
push_sec_ctx(10001, 513) : sec_ctx_stack_ndx = 1
[2011/05/15 14:41:13.498462, 3] smbd/uid.c:429(push_conn_ctx)
push_conn_ctx(101) : conn_ctx_stack_ndx = 0
[2011/05/15 14:41:13.498503, 3] smbd/sec_ctx.c:310(set_sec_ctx)
setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1
[2011/05/15 14:41:13.498597, 3] smbd/sec_ctx.c:418(pop_sec_ctx)
pop_sec_ctx (10001, 513) - sec_ctx_stack_ndx = 0
[2011/05/15 14:41:13.498665, 4] lib/substitute.c:504(automount_server)
Home server: density
[2011/05/15 14:41:13.498722, 3] smbd/sec_ctx.c:210(push_sec_ctx)
push_sec_ctx(10001, 513) : sec_ctx_stack_ndx = 1
[2011/05/15 14:41:13.498769, 3] smbd/uid.c:429(push_conn_ctx)
push_conn_ctx(101) : conn_ctx_stack_ndx = 0
[2011/05/15 14:41:13.498810, 3] smbd/sec_ctx.c:310(set_sec_ctx)
setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1
[2011/05/15 14:41:13.498893, 3] smbd/sec_ctx.c:418(pop_sec_ctx)
pop_sec_ctx (10001, 513) - sec_ctx_stack_ndx = 0
[2011/05/15 14:41:13.498973, 4]
rpc_server/srv_pipe_hnd.c:162(make_internal_rpc_pipe_p)
Created internal pipe \spoolss (pipes_open=0)
[2011/05/15 14:41:13.499050, 3] smbd/process.c:1485(process_smb)
Transaction 1847 of length 2244 (0 toread)
[2011/05/15 14:41:13.499096, 3] smbd/process.c:1294(switch_message)
switch message SMBtrans (pid 6487) conn 0xb8fd6490
[2011/05/15 14:41:13.499132, 4] smbd/uid.c:257(change_to_user)
change_to_user: Skipping user change - already user
[2011/05/15 14:41:13.499192, 3] smbd/ipc.c:545(handle_trans)
trans <\PIPE\> data=2156 params=0 setup=2
[2011/05/15 14:41:13.499239, 3] smbd/ipc.c:496(named_pipe)
named pipe command on <> name
[2011/05/15 14:41:13.499272, 3] smbd/ipc.c:460(api_fd_reply)
Got API command 0x26 on pipe "spoolss" (pnum 2f54)
[2011/05/15 14:41:13.499321, 3]
rpc_server/srv_pipe_hnd.c:344(free_pipe_context)
free_pipe_context: destroying talloc pool of size 0
[2011/05/15 14:41:13.499367, 4] rpc_server/srv_pipe.c:2403(api_rpcTNP)
api_rpcTNP: \spoolss op 0x35 - api_rpcTNP: rpc command:
SPOOLSS_GETPRINTERDRIVER2
[2011/05/15 14:41:13.499429, 4]
rpc_server/srv_spoolss_nt.c:5126(_spoolss_GetPrinterDriver2)
_spoolss_GetPrinterDriver2
[2011/05/15 14:41:13.499470, 4]
rpc_server/srv_lsa_hnd.c:219(find_policy_by_hnd_internal)
Found policy hnd[1] [0000] 00 00 00 00 36 00 00 00 00 00 00 00 D0
4D 71 46 ....6... .....MqF
[0010] 57 19 00 00 W...
[2011/05/15 14:41:13.499588, 4]
rpc_server/srv_lsa_hnd.c:219(find_policy_by_hnd_internal)
Found policy hnd[1] [0000] 00 00 00 00 36 00 00 00 00 00 00 00 D0
4D 71 46 ....6... .....MqF
[0010] 57 19 00 00 W...
[2011/05/15 14:41:13.499704, 4]
rpc_server/srv_spoolss_nt.c:379(get_printer_snum)
short name:F4440
[2011/05/15 14:41:13.500045, 3]
rpc_server/srv_pipe_hnd.c:344(free_pipe_context)
free_pipe_context: destroying talloc pool of size 0
[2011/05/15 14:41:13.500161, 3] smbd/process.c:1485(process_smb)
Transaction 1848 of length 45 (0 toread)
[2011/05/15 14:41:13.500208, 3] smbd/process.c:1294(switch_message)
switch message SMBclose (pid 6487) conn 0xb8fd6490
[2011/05/15 14:41:13.500249, 4] smbd/uid.c:257(change_to_user)
change_to_user: Skipping user change - already user
[2011/05/15 14:41:13.500289, 3] smbd/reply.c:4634(reply_close)
close fd=-1 fnum=12216 (numopen=6)
[2011/05/15 14:41:13.501024, 3] smbd/process.c:1485(process_smb)
Transaction 1849 of length 228 (0 toread)
[2011/05/15 14:41:13.501136, 3] smbd/process.c:1294(switch_message)
switch message SMBwriteX (pid 6487) conn 0xb8fd6490
[2011/05/15 14:41:13.501176, 4] smbd/uid.c:257(change_to_user)
change_to_user: Skipping user change - already user
[2011/05/15 14:41:13.501255, 3]
rpc_server/srv_pipe.c:1667(api_pipe_bind_req)
api_pipe_bind_req: \PIPE\spoolss -> \PIPE\spoolss
[2011/05/15 14:41:13.501301, 3]
rpc_server/srv_pipe.c:998(check_bind_req)
check_bind_req for \spoolss
[2011/05/15 14:41:13.501359, 3] smbd/sec_ctx.c:310(set_sec_ctx)
setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0
