Roel van Meer
2006-Jul-12 15:36 UTC
[Samba] continuous access to printer causes high memory usage
Hi list,
I am trying to track down a printer-related problem.
The most important symptom is a smbd process using almost all memory on
my machine (up to 800 MB, at the specific case of which I've posted the
logs.) At some point the VM will kill the smbd process, freeing the memory.
Apart from this, samba keeps on running fine.
Investigation of a level 3 debug log of this process has shown that the
client (a Windows XP machine) is accessing one of the samba printers almost
continuously, with four rpc calls: SPOOLSS_OPENPRINTEREX,
SPOOLSS_GETPRINTERDATA, SPOOLSS_CLOSEPRINTER and SPOOLSS_ENUMJOBS.
The printer driver is installed on the samba server. The client is
configured to use the printer via a Samba port. When the printer is removed
from the client, the rapid calls stop. When the printer is installed again,
the calls again occur in rapid succession.
Attached you'll find an excerpt of the output of 'ps', my smb.conf
and a
piece of the log file.
I've seen this problem at a few different machines, with samba versions
3.0.20, 3.0.22 and 3.0.23 and different clients (all Windows 2000 or XP).
All machines are running Slackware 10.1. The only solution I have found so
far is removing the printers from the client.
I have been wondering if this problem can be caused by an absent or invalid
deviced mode for this printer.
Does anyone have a clue about what might cause this? Or a hint about where
to look further? I'm more than willing to provide more detailed information.
Thanks in advance,
roel
-------------- next part --------------
# /etc/samba/smb.conf
# $Id: smb.conf,v 1.35 2005/09/26 08:47:52 rolek Exp $
[global]
workgroup = WG
netbios name = SERVER
server string = server
interfaces = 192.168.1.255/24 127.255.255.255/8
bind interfaces only = Yes
hosts allow = 192.168.1. 127.0.0.1
encrypt passwords = Yes
null passwords = Yes
username map = /etc/samba/smbusers
log file = /var/log/samba/samba.log
max log size=350k
max open files = 4000
syslog = 0
domain logons = Yes
logon script = %U.bat
logon path = \\server\%U\.profileNT
logon drive = H:
logon home = \\server\%U
os level = 254
preferred master = Yes
domain master = Yes
local master = Yes
wins support = Yes
time server = Yes
name resolve order = host wins bcast
passdb backend = ldapsam:ldap://localhost
ldap suffix = dc=tecobv,dc=nl
ldap machine suffix = ou=users
ldap user suffix = ou=users
ldap group suffix = ou=Groups
ldap idmap suffix = ou=Idmap
ldap admin dn = cn=admin,dc=tecobv,dc=nl
idmap backend = ldap:ldap://localhost
idmap uid = 10000-20000
idmap gid = 10000-20000
printing = cups
min print space = 1000
create mask = 0660
force create mode = 0660
directory mask = 0770
force directory mode = 0770
oplocks = No
level2 oplocks = No
[printers]
comment = All Printers
path = /var/spool/print/tmp
create mask = 0700
guest ok = Yes
printable = Yes
printing = cups
use client driver = No
min print space = 2000
[print$]
comment = Printer Drivers
path = /var/spool/samba/drivers
guest ok = Yes
browsable = yes
readonly = yes
write list = root,@Administrators
-------------- next part --------------
---> Memory usage:
root@server:~# ps axfuw | grep smbd
root 12652 0.0 0.2 8868 2320 ? Ss Jul11 0:00 /usr/sbin/smbd -D
root 12656 0.0 0.2 9264 2972 ? S Jul11 0:00 \_
/usr/sbin/smbd -D
root 31433 0.0 0.4 9368 4880 ? S 08:28 0:02 \_
/usr/sbin/smbd -D
user1 31842 0.2 77.8 872844 803180 ? S 08:46 1:21 \_
/usr/sbin/smbd -D
user2 32035 0.0 0.5 12200 5764 ? S 08:54 0:00 \_
/usr/sbin/smbd -D
user3 32292 0.0 2.5 35092 26056 ? S 09:03 0:02 \_
/usr/sbin/smbd -D
root 9788 0.0 0.3 9180 3496 ? S 16:01 0:00 \_
/usr/sbin/smbd -D
---> Excerpt from samba.log
[2006/07/12 14:51:21, 3] smbd/process.c:process_smb(1110)
Transaction 429419 of length 332
[2006/07/12 14:51:21, 3] smbd/process.c:switch_message(914)
switch message SMBtrans (pid 31842) conn 0x84b3a98
[2006/07/12 14:51:21, 3] smbd/sec_ctx.c:set_sec_ctx(241)
setting sec ctx (1008, 100) - sec_ctx_stack_ndx = 0
[2006/07/12 14:51:21, 3] smbd/ipc.c:handle_trans(373)
trans <\PIPE\> data=244 params=0 setup=2
[2006/07/12 14:51:21, 3] smbd/ipc.c:named_pipe(340)
named pipe command on <> name
[2006/07/12 14:51:21, 3] smbd/ipc.c:api_fd_reply(300)
Got API command 0x26 on pipe "spoolss" (pnum 71da)
[2006/07/12 14:51:21, 3] rpc_server/srv_pipe_hnd.c:free_pipe_context(529)
free_pipe_context: destroying talloc pool of size 0
[2006/07/12 14:51:21, 3] rpc_server/srv_pipe.c:api_rpcTNP(2265)
api_rpcTNP: rpc command: SPOOLSS_OPENPRINTEREX
checking name: \\teco-server\HP LaserJet 3050 Series PCL 5e
[2006/07/12 14:51:21, 3]
rpc_server/srv_spoolss_nt.c:set_printer_hnd_printertype(408)
Setting printer type=\\teco-server\HP LaserJet 3050 Series PCL 5e
[2006/07/12 14:51:21, 3] lib/access.c:check_access(313)
check_access: no hostnames in host allow/deny list.
[2006/07/12 14:51:21, 2] lib/access.c:check_access(324)
Allowed connection from (192.168.22.243)
[2006/07/12 14:51:21, 3] lib/util_seaccess.c:se_access_check(250)
[2006/07/12 14:51:21, 3] lib/util_seaccess.c:se_access_check(251)
se_access_check: user sid is S-1-5-21-976746554-266313863-47890339-3016
se_access_check: also S-1-5-21-976746554-266313863-47890339-100
se_access_check: also S-1-1-0
se_access_check: also S-1-5-2
se_access_check: also S-1-5-11
[2006/07/12 14:51:21, 3] rpc_server/srv_pipe_hnd.c:free_pipe_context(529)
free_pipe_context: destroying talloc pool of size 196
[2006/07/12 14:51:21, 3] smbd/process.c:process_smb(1110)
Transaction 429420 of length 168
[2006/07/12 14:51:21, 3] smbd/process.c:switch_message(914)
switch message SMBtrans (pid 31842) conn 0x84b3a98
[2006/07/12 14:51:21, 3] smbd/ipc.c:handle_trans(373)
trans <\PIPE\> data=80 params=0 setup=2
[2006/07/12 14:51:21, 3] smbd/ipc.c:named_pipe(340)
named pipe command on <> name
[2006/07/12 14:51:21, 3] smbd/ipc.c:api_fd_reply(300)
Got API command 0x26 on pipe "spoolss" (pnum 71da)
[2006/07/12 14:51:21, 3] rpc_server/srv_pipe_hnd.c:free_pipe_context(529)
free_pipe_context: destroying talloc pool of size 0
[2006/07/12 14:51:21, 3] rpc_server/srv_pipe.c:api_rpcTNP(2265)
api_rpcTNP: rpc command: SPOOLSS_GETPRINTERDATA
[2006/07/12 14:51:21, 3] rpc_server/srv_pipe_hnd.c:free_pipe_context(529)
free_pipe_context: destroying talloc pool of size 22
[2006/07/12 14:51:21, 3] smbd/process.c:process_smb(1110)
Transaction 429421 of length 132
[2006/07/12 14:51:21, 3] smbd/process.c:switch_message(914)
switch message SMBtrans (pid 31842) conn 0x84b3a98
[2006/07/12 14:51:21, 3] smbd/ipc.c:handle_trans(373)
trans <\PIPE\> data=44 params=0 setup=2
[2006/07/12 14:51:21, 3] smbd/ipc.c:named_pipe(340)
named pipe command on <> name
[2006/07/12 14:51:21, 3] smbd/ipc.c:api_fd_reply(300)
Got API command 0x26 on pipe "spoolss" (pnum 71da)
[2006/07/12 14:51:21, 3] rpc_server/srv_pipe_hnd.c:free_pipe_context(529)
free_pipe_context: destroying talloc pool of size 0
[2006/07/12 14:51:21, 3] rpc_server/srv_pipe.c:api_rpcTNP(2265)
api_rpcTNP: rpc command: SPOOLSS_CLOSEPRINTER
[2006/07/12 14:51:21, 3] rpc_server/srv_lsa_hnd.c:close_policy_hnd(200)
Closed policy
[2006/07/12 14:51:21, 3] rpc_server/srv_pipe_hnd.c:free_pipe_context(529)
free_pipe_context: destroying talloc pool of size 0
[2006/07/12 14:51:21, 3] smbd/process.c:process_smb(1110)
Transaction 429422 of length 332
[2006/07/12 14:51:21, 3] smbd/process.c:switch_message(914)
switch message SMBtrans (pid 31842) conn 0x84b3a98
[2006/07/12 14:51:21, 3] smbd/ipc.c:handle_trans(373)
trans <\PIPE\> data=244 params=0 setup=2
[2006/07/12 14:51:21, 3] smbd/ipc.c:named_pipe(340)
named pipe command on <> name
[2006/07/12 14:51:21, 3] smbd/ipc.c:api_fd_reply(300)
Got API command 0x26 on pipe "spoolss" (pnum 7402)
[2006/07/12 14:51:21, 3] rpc_server/srv_pipe_hnd.c:free_pipe_context(529)
free_pipe_context: destroying talloc pool of size 0
[2006/07/12 14:51:21, 3] rpc_server/srv_pipe.c:api_rpcTNP(2265)
api_rpcTNP: rpc command: SPOOLSS_OPENPRINTEREX
checking name: \\teco-server\HP LaserJet 3050 Series PCL 5e
[2006/07/12 14:51:21, 3]
rpc_server/srv_spoolss_nt.c:set_printer_hnd_printertype(408)
Setting printer type=\\teco-server\HP LaserJet 3050 Series PCL 5e
[2006/07/12 14:51:21, 3] lib/access.c:check_access(313)
check_access: no hostnames in host allow/deny list.
[2006/07/12 14:51:21, 2] lib/access.c:check_access(324)
Allowed connection from (192.168.22.243)
[2006/07/12 14:51:21, 3] lib/util_seaccess.c:se_access_check(250)
[2006/07/12 14:51:21, 3] lib/util_seaccess.c:se_access_check(251)
se_access_check: user sid is S-1-5-21-976746554-266313863-47890339-3016
se_access_check: also S-1-5-21-976746554-266313863-47890339-100
se_access_check: also S-1-1-0
se_access_check: also S-1-5-2
se_access_check: also S-1-5-11
[2006/07/12 14:51:21, 3] rpc_server/srv_pipe_hnd.c:free_pipe_context(529)
free_pipe_context: destroying talloc pool of size 196
[2006/07/12 14:51:21, 3] smbd/process.c:process_smb(1110)
Transaction 429423 of length 152
[2006/07/12 14:51:21, 3] smbd/process.c:switch_message(914)
switch message SMBtrans (pid 31842) conn 0x84b3a98
[2006/07/12 14:51:21, 3] smbd/ipc.c:handle_trans(373)
trans <\PIPE\> data=64 params=0 setup=2
[2006/07/12 14:51:21, 3] smbd/ipc.c:named_pipe(340)
named pipe command on <> name
[2006/07/12 14:51:21, 3] smbd/ipc.c:api_fd_reply(300)
Got API command 0x26 on pipe "spoolss" (pnum 71da)
[2006/07/12 14:51:21, 3] rpc_server/srv_pipe_hnd.c:free_pipe_context(529)
free_pipe_context: destroying talloc pool of size 0
[2006/07/12 14:51:21, 3] rpc_server/srv_pipe.c:api_rpcTNP(2265)
api_rpcTNP: rpc command: SPOOLSS_ENUMJOBS
[2006/07/12 14:51:21, 3] rpc_server/srv_pipe_hnd.c:free_pipe_context(529)
free_pipe_context: destroying talloc pool of size 0
[2006/07/12 14:51:21, 3] smbd/process.c:process_smb(1110)
Transaction 429424 of length 132
[2006/07/12 14:51:21, 3] smbd/process.c:switch_message(914)
switch message SMBtrans (pid 31842) conn 0x84b3a98
[2006/07/12 14:51:21, 3] smbd/ipc.c:handle_trans(373)
trans <\PIPE\> data=44 params=0 setup=2
[2006/07/12 14:51:21, 3] smbd/ipc.c:named_pipe(340)
named pipe command on <> name
[2006/07/12 14:51:21, 3] smbd/ipc.c:api_fd_reply(300)
Got API command 0x26 on pipe "spoolss" (pnum 71da)
[2006/07/12 14:51:21, 3] rpc_server/srv_pipe_hnd.c:free_pipe_context(529)
free_pipe_context: destroying talloc pool of size 0
[2006/07/12 14:51:21, 3] rpc_server/srv_pipe.c:api_rpcTNP(2265)
api_rpcTNP: rpc command: SPOOLSS_CLOSEPRINTER
[2006/07/12 14:51:21, 3] rpc_server/srv_lsa_hnd.c:close_policy_hnd(200)
Closed policy
[2006/07/12 14:51:21, 3] rpc_server/srv_pipe_hnd.c:free_pipe_context(529)
free_pipe_context: destroying talloc pool of size 0
[2006/07/12 14:51:21, 3] smbd/process.c:process_smb(1110)
Transaction 429425 of length 76
[2006/07/12 14:51:21, 3] smbd/process.c:switch_message(914)
switch message SMBtrans2 (pid 31842) conn 0x84b1288
[2006/07/12 14:51:21, 3] smbd/sec_ctx.c:set_sec_ctx(241)
setting sec ctx (1008, 100) - sec_ctx_stack_ndx = 0
[2006/07/12 14:51:21, 3] smbd/trans2.c:call_trans2qfilepathinfo(2852)
call_trans2qfilepathinfo: TRANSACT2_QFILEINFO: level = 1004
[2006/07/12 14:51:21, 3] smbd/trans2.c:call_trans2qfilepathinfo(2959)
call_trans2qfilepathinfo My Documents/My Pictures (fnum = 7850) level=1004
call=7 total_data=0
[2006/07/12 14:51:21, 3] smbd/process.c:process_smb(1110)
Transaction 429426 of length 76
[2006/07/12 14:51:21, 3] smbd/process.c:switch_message(914)
switch message SMBtrans2 (pid 31842) conn 0x84b1288
[2006/07/12 14:51:21, 3] smbd/trans2.c:call_trans2qfilepathinfo(2852)
call_trans2qfilepathinfo: TRANSACT2_QFILEINFO: level = 1005
[2006/07/12 14:51:21, 3] smbd/trans2.c:call_trans2qfilepathinfo(2959)
call_trans2qfilepathinfo My Documents/My Pictures (fnum = 7850) level=1005
call=7 total_data=0
[2006/07/12 14:51:21, 3] smbd/process.c:process_smb(1110)
Transaction 429427 of length 76
[2006/07/12 14:51:21, 3] smbd/process.c:switch_message(914)
switch message SMBtrans2 (pid 31842) conn 0x84b1288
[2006/07/12 14:51:21, 3] smbd/trans2.c:call_trans2qfilepathinfo(2852)
call_trans2qfilepathinfo: TRANSACT2_QFILEINFO: level = 1004
[2006/07/12 14:51:21, 3] smbd/trans2.c:call_trans2qfilepathinfo(2959)
call_trans2qfilepathinfo My Documents/My Pictures (fnum = 7850) level=1004
call=7 total_data=0
[2006/07/12 14:51:21, 3] smbd/process.c:process_smb(1110)
Transaction 429428 of length 45
[2006/07/12 14:51:21, 3] smbd/process.c:switch_message(914)
switch message SMBclose (pid 31842) conn 0x84b1288
[2006/07/12 14:51:21, 3] smbd/reply.c:reply_close(3298)
close directory fnum=7850
[2006/07/12 14:51:21, 3] smbd/process.c:process_smb(1110)
Transaction 429429 of length 180
[2006/07/12 14:51:21, 3] smbd/process.c:switch_message(914)
switch message SMBntcreateX (pid 31842) conn 0x84b1288
[2006/07/12 14:51:21, 3] smbd/msdfs.c:dfs_redirect(435)
dfs_redirect: Not redirecting teco-server/friedel/My Documents/My Pictures.
[2006/07/12 14:51:21, 3] smbd/msdfs.c:dfs_redirect(439)
dfs_redirect: Path converted to non-dfs path My Documents/My Pictures
[2006/07/12 14:51:21, 3] smbd/dosmode.c:unix_mode(147)
unix_mode(My Documents/My Pictures) returning 0600
[2006/07/12 14:51:21, 3] smbd/process.c:process_smb(1110)
Transaction 429430 of length 76
[2006/07/12 14:51:21, 3] smbd/process.c:switch_message(914)
switch message SMBtrans2 (pid 31842) conn 0x84b1288
[2006/07/12 14:51:21, 3] smbd/trans2.c:call_trans2qfilepathinfo(2852)
call_trans2qfilepathinfo: TRANSACT2_QFILEINFO: level = 1004
[2006/07/12 14:51:21, 3] smbd/trans2.c:call_trans2qfilepathinfo(2959)
call_trans2qfilepathinfo My Documents/My Pictures (fnum = 7852) level=1004
call=7 total_data=0
[2006/07/12 14:51:21, 3] smbd/process.c:process_smb(1110)
Transaction 429431 of length 76
[2006/07/12 14:51:21, 3] smbd/process.c:switch_message(914)
switch message SMBtrans2 (pid 31842) conn 0x84b1288
[2006/07/12 14:51:21, 3] smbd/trans2.c:call_trans2qfilepathinfo(2852)
call_trans2qfilepathinfo: TRANSACT2_QFILEINFO: level = 1005
[2006/07/12 14:51:21, 3] smbd/trans2.c:call_trans2qfilepathinfo(2959)
call_trans2qfilepathinfo My Documents/My Pictures (fnum = 7852) level=1005
call=7 total_data=0
[2006/07/12 14:51:21, 3] smbd/process.c:process_smb(1110)
Transaction 429432 of length 76
[2006/07/12 14:51:21, 3] smbd/process.c:switch_message(914)
switch message SMBtrans2 (pid 31842) conn 0x84b1288
[2006/07/12 14:51:21, 3] smbd/trans2.c:call_trans2qfilepathinfo(2852)
call_trans2qfilepathinfo: TRANSACT2_QFILEINFO: level = 1004
[2006/07/12 14:51:21, 3] smbd/trans2.c:call_trans2qfilepathinfo(2959)
call_trans2qfilepathinfo My Documents/My Pictures (fnum = 7852) level=1004
call=7 total_data=0
[2006/07/12 14:51:21, 3] smbd/process.c:process_smb(1110)
Transaction 429433 of length 45
[2006/07/12 14:51:21, 3] smbd/process.c:switch_message(914)
switch message SMBclose (pid 31842) conn 0x84b1288
[2006/07/12 14:51:21, 3] smbd/reply.c:reply_close(3298)
close directory fnum=7852
[2006/07/12 14:51:21, 3] smbd/process.c:process_smb(1110)
Transaction 429434 of length 180
[2006/07/12 14:51:21, 3] smbd/process.c:switch_message(914)
switch message SMBntcreateX (pid 31842) conn 0x84b1288
[2006/07/12 14:51:21, 3] smbd/msdfs.c:dfs_redirect(435)
dfs_redirect: Not redirecting teco-server/friedel/My Documents/My Pictures.
[2006/07/12 14:51:21, 3] smbd/msdfs.c:dfs_redirect(439)
dfs_redirect: Path converted to non-dfs path My Documents/My Pictures
[2006/07/12 14:51:21, 3] smbd/dosmode.c:unix_mode(147)
unix_mode(My Documents/My Pictures) returning 0600
[2006/07/12 14:51:21, 3] smbd/process.c:process_smb(1110)
Transaction 429435 of length 76
[2006/07/12 14:51:21, 3] smbd/process.c:switch_message(914)
switch message SMBtrans2 (pid 31842) conn 0x84b1288
[2006/07/12 14:51:21, 3] smbd/trans2.c:call_trans2qfilepathinfo(2852)
call_trans2qfilepathinfo: TRANSACT2_QFILEINFO: level = 1004
[2006/07/12 14:51:21, 3] smbd/trans2.c:call_trans2qfilepathinfo(2959)
call_trans2qfilepathinfo My Documents/My Pictures (fnum = 7854) level=1004
call=7 total_data=0
[2006/07/12 14:51:21, 3] smbd/process.c:process_smb(1110)
Transaction 429436 of length 76
[2006/07/12 14:51:21, 3] smbd/process.c:switch_message(914)
switch message SMBtrans2 (pid 31842) conn 0x84b1288
[2006/07/12 14:51:21, 3] smbd/trans2.c:call_trans2qfilepathinfo(2852)
call_trans2qfilepathinfo: TRANSACT2_QFILEINFO: level = 1005
[2006/07/12 14:51:21, 3] smbd/trans2.c:call_trans2qfilepathinfo(2959)
call_trans2qfilepathinfo My Documents/My Pictures (fnum = 7854) level=1005
call=7 total_data=0
[2006/07/12 14:51:21, 3] smbd/process.c:process_smb(1110)
Transaction 429437 of length 76
[2006/07/12 14:51:21, 3] smbd/process.c:switch_message(914)
switch message SMBtrans2 (pid 31842) conn 0x84b1288
[2006/07/12 14:51:21, 3] smbd/trans2.c:call_trans2qfilepathinfo(2852)
call_trans2qfilepathinfo: TRANSACT2_QFILEINFO: level = 1004
[2006/07/12 14:51:21, 3] smbd/trans2.c:call_trans2qfilepathinfo(2959)
call_trans2qfilepathinfo My Documents/My Pictures (fnum = 7854) level=1004
call=7 total_data=0
[2006/07/12 14:51:21, 3] smbd/process.c:process_smb(1110)
Transaction 429438 of length 45
[2006/07/12 14:51:21, 3] smbd/process.c:switch_message(914)
switch message SMBclose (pid 31842) conn 0x84b1288
[2006/07/12 14:51:21, 3] smbd/reply.c:reply_close(3298)
close directory fnum=7854
[2006/07/12 14:51:21, 3] smbd/process.c:process_smb(1110)
Transaction 429439 of length 180
[2006/07/12 14:51:21, 3] smbd/process.c:switch_message(914)
switch message SMBntcreateX (pid 31842) conn 0x84b1288
[2006/07/12 14:51:21, 3] smbd/msdfs.c:dfs_redirect(435)
dfs_redirect: Not redirecting teco-server/friedel/My Documents/My Pictures.
[2006/07/12 14:51:21, 3] smbd/msdfs.c:dfs_redirect(439)
dfs_redirect: Path converted to non-dfs path My Documents/My Pictures
[2006/07/12 14:51:21, 3] smbd/dosmode.c:unix_mode(147)
unix_mode(My Documents/My Pictures) returning 0600
[2006/07/12 14:51:21, 3] smbd/process.c:process_smb(1110)
Transaction 429440 of length 76
[2006/07/12 14:51:21, 3] smbd/process.c:switch_message(914)
switch message SMBtrans2 (pid 31842) conn 0x84b1288
[2006/07/12 14:51:21, 3] smbd/trans2.c:call_trans2qfilepathinfo(2852)
call_trans2qfilepathinfo: TRANSACT2_QFILEINFO: level = 1004
[2006/07/12 14:51:21, 3] smbd/trans2.c:call_trans2qfilepathinfo(2959)
call_trans2qfilepathinfo My Documents/My Pictures (fnum = 7856) level=1004
call=7 total_data=0
[2006/07/12 14:51:21, 3] smbd/process.c:process_smb(1110)
Transaction 429441 of length 76
[2006/07/12 14:51:21, 3] smbd/process.c:switch_message(914)
switch message SMBtrans2 (pid 31842) conn 0x84b1288
[2006/07/12 14:51:21, 3] smbd/trans2.c:call_trans2qfilepathinfo(2852)
call_trans2qfilepathinfo: TRANSACT2_QFILEINFO: level = 1005
[2006/07/12 14:51:21, 3] smbd/trans2.c:call_trans2qfilepathinfo(2959)
call_trans2qfilepathinfo My Documents/My Pictures (fnum = 7856) level=1005
call=7 total_data=0
[2006/07/12 14:51:21, 3] smbd/process.c:process_smb(1110)
Transaction 429442 of length 76
[2006/07/12 14:51:21, 3] smbd/process.c:switch_message(914)
switch message SMBtrans2 (pid 31842) conn 0x84b1288
[2006/07/12 14:51:21, 3] smbd/trans2.c:call_trans2qfilepathinfo(2852)
call_trans2qfilepathinfo: TRANSACT2_QFILEINFO: level = 1004
[2006/07/12 14:51:21, 3] smbd/trans2.c:call_trans2qfilepathinfo(2959)
call_trans2qfilepathinfo My Documents/My Pictures (fnum = 7856) level=1004
call=7 total_data=0
[2006/07/12 14:51:21, 3] smbd/process.c:process_smb(1110)
Transaction 429443 of length 45
[2006/07/12 14:51:21, 3] smbd/process.c:switch_message(914)
switch message SMBclose (pid 31842) conn 0x84b1288
[2006/07/12 14:51:21, 3] smbd/reply.c:reply_close(3298)
close directory fnum=7856
[2006/07/12 14:51:21, 3] smbd/process.c:process_smb(1110)
Transaction 429444 of length 180
[2006/07/12 14:51:21, 3] smbd/process.c:switch_message(914)
switch message SMBntcreateX (pid 31842) conn 0x84b1288
[2006/07/12 14:51:21, 3] smbd/msdfs.c:dfs_redirect(435)
dfs_redirect: Not redirecting teco-server/friedel/My Documents/My Pictures.
[2006/07/12 14:51:21, 3] smbd/msdfs.c:dfs_redirect(439)
dfs_redirect: Path converted to non-dfs path My Documents/My Pictures
[2006/07/12 14:51:21, 3] smbd/dosmode.c:unix_mode(147)
unix_mode(My Documents/My Pictures) returning 0600
[2006/07/12 14:51:22, 3] smbd/process.c:process_smb(1110)
Transaction 429445 of length 76
[2006/07/12 14:51:22, 3] smbd/process.c:switch_message(914)
switch message SMBtrans2 (pid 31842) conn 0x84b1288
[2006/07/12 14:51:22, 3] smbd/trans2.c:call_trans2qfilepathinfo(2852)
call_trans2qfilepathinfo: TRANSACT2_QFILEINFO: level = 1004
[2006/07/12 14:51:22, 3] smbd/trans2.c:call_trans2qfilepathinfo(2959)
call_trans2qfilepathinfo My Documents/My Pictures (fnum = 7858) level=1004
call=7 total_data=0
[2006/07/12 14:51:22, 3] smbd/process.c:process_smb(1110)
Transaction 429446 of length 76
[2006/07/12 14:51:22, 3] smbd/process.c:switch_message(914)
switch message SMBtrans2 (pid 31842) conn 0x84b1288
[2006/07/12 14:51:22, 3] smbd/trans2.c:call_trans2qfilepathinfo(2852)
call_trans2qfilepathinfo: TRANSACT2_QFILEINFO: level = 1005
[2006/07/12 14:51:22, 3] smbd/trans2.c:call_trans2qfilepathinfo(2959)
call_trans2qfilepathinfo My Documents/My Pictures (fnum = 7858) level=1005
call=7 total_data=0
[2006/07/12 14:51:22, 3] smbd/process.c:process_smb(1110)
Transaction 429447 of length 76
[2006/07/12 14:51:22, 3] smbd/process.c:switch_message(914)
switch message SMBtrans2 (pid 31842) conn 0x84b1288
[2006/07/12 14:51:22, 3] smbd/trans2.c:call_trans2qfilepathinfo(2852)
call_trans2qfilepathinfo: TRANSACT2_QFILEINFO: level = 1004
[2006/07/12 14:51:22, 3] smbd/trans2.c:call_trans2qfilepathinfo(2959)
call_trans2qfilepathinfo My Documents/My Pictures (fnum = 7858) level=1004
call=7 total_data=0
[2006/07/12 14:51:22, 3] smbd/process.c:process_smb(1110)
Transaction 429448 of length 45
[2006/07/12 14:51:22, 3] smbd/process.c:switch_message(914)
switch message SMBclose (pid 31842) conn 0x84b1288
[2006/07/12 14:51:22, 3] smbd/reply.c:reply_close(3298)
close directory fnum=7858
[2006/07/12 14:51:22, 3] smbd/process.c:process_smb(1110)
Transaction 429449 of length 180
[2006/07/12 14:51:22, 3] smbd/process.c:switch_message(914)
switch message SMBntcreateX (pid 31842) conn 0x84b1288
[2006/07/12 14:51:22, 3] smbd/msdfs.c:dfs_redirect(435)
dfs_redirect: Not redirecting teco-server/friedel/My Documents/My Pictures.
[2006/07/12 14:51:22, 3] smbd/msdfs.c:dfs_redirect(439)
dfs_redirect: Path converted to non-dfs path My Documents/My Pictures
[2006/07/12 14:51:22, 3] smbd/dosmode.c:unix_mode(147)
unix_mode(My Documents/My Pictures) returning 0600
[2006/07/12 14:51:22, 3] smbd/sec_ctx.c:set_sec_ctx(241)
setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0
[2006/07/12 14:51:22, 3] smbd/process.c:process_smb(1110)
Transaction 429450 of length 76
[2006/07/12 14:51:22, 3] smbd/process.c:switch_message(914)
switch message SMBtrans2 (pid 31842) conn 0x84b1288
[2006/07/12 14:51:22, 3] smbd/sec_ctx.c:set_sec_ctx(241)
setting sec ctx (1008, 100) - sec_ctx_stack_ndx = 0
[2006/07/12 14:51:22, 3] smbd/trans2.c:call_trans2qfilepathinfo(2852)
call_trans2qfilepathinfo: TRANSACT2_QFILEINFO: level = 1004
[2006/07/12 14:51:22, 3] smbd/trans2.c:call_trans2qfilepathinfo(2959)
call_trans2qfilepathinfo My Documents/My Pictures (fnum = 7860) level=1004
call=7 total_data=0
[2006/07/12 14:51:22, 3] smbd/process.c:process_smb(1110)
Transaction 429451 of length 76
[2006/07/12 14:51:22, 3] smbd/process.c:switch_message(914)
switch message SMBtrans2 (pid 31842) conn 0x84b1288
[2006/07/12 14:51:22, 3] smbd/trans2.c:call_trans2qfilepathinfo(2852)
call_trans2qfilepathinfo: TRANSACT2_QFILEINFO: level = 1005
[2006/07/12 14:51:22, 3] smbd/trans2.c:call_trans2qfilepathinfo(2959)
call_trans2qfilepathinfo My Documents/My Pictures (fnum = 7860) level=1005
call=7 total_data=0
[2006/07/12 14:51:22, 3] smbd/process.c:process_smb(1110)
Transaction 429452 of length 76
[2006/07/12 14:51:22, 3] smbd/process.c:switch_message(914)
switch message SMBtrans2 (pid 31842) conn 0x84b1288
[2006/07/12 14:51:22, 3] smbd/trans2.c:call_trans2qfilepathinfo(2852)
call_trans2qfilepathinfo: TRANSACT2_QFILEINFO: level = 1004
[2006/07/12 14:51:22, 3] smbd/trans2.c:call_trans2qfilepathinfo(2959)
call_trans2qfilepathinfo My Documents/My Pictures (fnum = 7860) level=1004
call=7 total_data=0
[2006/07/12 14:51:22, 3] smbd/process.c:process_smb(1110)
Transaction 429453 of length 45
[2006/07/12 14:51:22, 3] smbd/process.c:switch_message(914)
switch message SMBclose (pid 31842) conn 0x84b1288
[2006/07/12 14:51:22, 3] smbd/reply.c:reply_close(3298)
close directory fnum=7860
[2006/07/12 14:51:22, 3] smbd/process.c:process_smb(1110)
Transaction 429454 of length 180
[2006/07/12 14:51:22, 3] smbd/process.c:switch_message(914)
switch message SMBntcreateX (pid 31842) conn 0x84b1288
[2006/07/12 14:51:22, 3] smbd/msdfs.c:dfs_redirect(435)
dfs_redirect: Not redirecting teco-server/friedel/My Documents/My Pictures.
[2006/07/12 14:51:22, 3] smbd/msdfs.c:dfs_redirect(439)
dfs_redirect: Path converted to non-dfs path My Documents/My Pictures
[2006/07/12 14:51:22, 3] smbd/dosmode.c:unix_mode(147)
unix_mode(My Documents/My Pictures) returning 0600
[2006/07/12 14:51:22, 3] smbd/process.c:process_smb(1110)
Transaction 429455 of length 332
[2006/07/12 14:51:22, 3] smbd/process.c:switch_message(914)
switch message SMBtrans (pid 31842) conn 0x84b3a98
[2006/07/12 14:51:22, 3] smbd/sec_ctx.c:set_sec_ctx(241)
setting sec ctx (1008, 100) - sec_ctx_stack_ndx = 0
[2006/07/12 14:51:22, 3] smbd/ipc.c:handle_trans(373)
trans <\PIPE\> data=244 params=0 setup=2
[2006/07/12 14:51:22, 3] smbd/ipc.c:named_pipe(340)
named pipe command on <> name
[2006/07/12 14:51:22, 3] smbd/ipc.c:api_fd_reply(300)
Got API command 0x26 on pipe "spoolss" (pnum 71da)
[2006/07/12 14:51:22, 3] rpc_server/srv_pipe_hnd.c:free_pipe_context(529)
free_pipe_context: destroying talloc pool of size 0
[2006/07/12 14:51:22, 3] rpc_server/srv_pipe.c:api_rpcTNP(2265)
api_rpcTNP: rpc command: SPOOLSS_OPENPRINTEREX
checking name: \\teco-server\HP LaserJet 3050 Series PCL 5e
[2006/07/12 14:51:22, 3]
rpc_server/srv_spoolss_nt.c:set_printer_hnd_printertype(408)
Setting printer type=\\teco-server\HP LaserJet 3050 Series PCL 5e
[2006/07/12 14:51:22, 3] lib/access.c:check_access(313)
check_access: no hostnames in host allow/deny list.
[2006/07/12 14:51:22, 2] lib/access.c:check_access(324)
Allowed connection from (192.168.22.243)
[2006/07/12 14:51:22, 3] lib/util_seaccess.c:se_access_check(250)
[2006/07/12 14:51:22, 3] lib/util_seaccess.c:se_access_check(251)
se_access_check: user sid is S-1-5-21-976746554-266313863-47890339-3016
se_access_check: also S-1-5-21-976746554-266313863-47890339-100
se_access_check: also S-1-1-0
se_access_check: also S-1-5-2
se_access_check: also S-1-5-11
[2006/07/12 14:51:22, 3] rpc_server/srv_pipe_hnd.c:free_pipe_context(529)
free_pipe_context: destroying talloc pool of size 196
[2006/07/12 14:51:22, 3] smbd/process.c:process_smb(1110)
Transaction 429456 of length 132
[2006/07/12 14:51:22, 3] smbd/process.c:switch_message(914)
switch message SMBtrans (pid 31842) conn 0x84b3a98
[2006/07/12 14:51:22, 3] smbd/ipc.c:handle_trans(373)
trans <\PIPE\> data=44 params=0 setup=2
[2006/07/12 14:51:22, 3] smbd/ipc.c:named_pipe(340)
named pipe command on <> name
[2006/07/12 14:51:22, 3] smbd/ipc.c:api_fd_reply(300)
Got API command 0x26 on pipe "spoolss" (pnum 71da)
[2006/07/12 14:51:22, 3] rpc_server/srv_pipe_hnd.c:free_pipe_context(529)
free_pipe_context: destroying talloc pool of size 0
[2006/07/12 14:51:22, 3] rpc_server/srv_pipe.c:api_rpcTNP(2265)
api_rpcTNP: rpc command: SPOOLSS_CLOSEPRINTER
[2006/07/12 14:51:22, 3] rpc_server/srv_lsa_hnd.c:close_policy_hnd(200)
Closed policy
[2006/07/12 14:51:22, 3] rpc_server/srv_pipe_hnd.c:free_pipe_context(529)
free_pipe_context: destroying talloc pool of size 0
[2006/07/12 14:51:22, 3] smbd/process.c:process_smb(1110)
Transaction 429457 of length 332
[2006/07/12 14:51:22, 3] smbd/process.c:switch_message(914)
switch message SMBtrans (pid 31842) conn 0x84b3a98
[2006/07/12 14:51:22, 3] smbd/ipc.c:handle_trans(373)
trans <\PIPE\> data=244 params=0 setup=2
[2006/07/12 14:51:22, 3] smbd/ipc.c:named_pipe(340)
named pipe command on <> name
[2006/07/12 14:51:22, 3] smbd/ipc.c:api_fd_reply(300)
Got API command 0x26 on pipe "spoolss" (pnum 71da)
[2006/07/12 14:51:22, 3] rpc_server/srv_pipe_hnd.c:free_pipe_context(529)
free_pipe_context: destroying talloc pool of size 0
[2006/07/12 14:51:22, 3] rpc_server/srv_pipe.c:api_rpcTNP(2265)
api_rpcTNP: rpc command: SPOOLSS_OPENPRINTEREX
checking name: \\teco-server\HP LaserJet 3050 Series PCL 5e
[2006/07/12 14:51:22, 3]
rpc_server/srv_spoolss_nt.c:set_printer_hnd_printertype(408)
Setting printer type=\\teco-server\HP LaserJet 3050 Series PCL 5e
[2006/07/12 14:51:22, 3] lib/access.c:check_access(313)
check_access: no hostnames in host allow/deny list.
[2006/07/12 14:51:22, 2] lib/access.c:check_access(324)
Allowed connection from (192.168.22.243)
[2006/07/12 14:51:22, 3] lib/util_seaccess.c:se_access_check(250)
[2006/07/12 14:51:22, 3] lib/util_seaccess.c:se_access_check(251)
se_access_check: user sid is S-1-5-21-976746554-266313863-47890339-3016
se_access_check: also S-1-5-21-976746554-266313863-47890339-100
se_access_check: also S-1-1-0
se_access_check: also S-1-5-2
se_access_check: also S-1-5-11
[2006/07/12 14:51:22, 3] rpc_server/srv_pipe_hnd.c:free_pipe_context(529)
free_pipe_context: destroying talloc pool of size 196
[2006/07/12 14:51:22, 3] smbd/process.c:process_smb(1110)
Transaction 429458 of length 152
[2006/07/12 14:51:22, 3] smbd/process.c:switch_message(914)
switch message SMBtrans (pid 31842) conn 0x84b3a98
[2006/07/12 14:51:22, 3] smbd/ipc.c:handle_trans(373)
trans <\PIPE\> data=64 params=0 setup=2
[2006/07/12 14:51:22, 3] smbd/ipc.c:named_pipe(340)
named pipe command on <> name
[2006/07/12 14:51:22, 3] smbd/ipc.c:api_fd_reply(300)
Got API command 0x26 on pipe "spoolss" (pnum 71da)
[2006/07/12 14:51:22, 3] rpc_server/srv_pipe_hnd.c:free_pipe_context(529)
free_pipe_context: destroying talloc pool of size 0
[2006/07/12 14:51:22, 3] rpc_server/srv_pipe.c:api_rpcTNP(2265)
api_rpcTNP: rpc command: SPOOLSS_ENUMJOBS
[2006/07/12 14:51:22, 3] rpc_server/srv_pipe_hnd.c:free_pipe_context(529)
free_pipe_context: destroying talloc pool of size 0
[2006/07/12 14:51:22, 3] smbd/process.c:process_smb(1110)
Transaction 429459 of length 132
[2006/07/12 14:51:22, 3] smbd/process.c:switch_message(914)
switch message SMBtrans (pid 31842) conn 0x84b3a98
[2006/07/12 14:51:22, 3] smbd/ipc.c:handle_trans(373)
trans <\PIPE\> data=44 params=0 setup=2
[2006/07/12 14:51:22, 3] smbd/ipc.c:named_pipe(340)
named pipe command on <> name
[2006/07/12 14:51:22, 3] smbd/ipc.c:api_fd_reply(300)
Got API command 0x26 on pipe "spoolss" (pnum 71da)
[2006/07/12 14:51:22, 3] rpc_server/srv_pipe_hnd.c:free_pipe_context(529)
free_pipe_context: destroying talloc pool of size 0
[2006/07/12 14:51:22, 3] rpc_server/srv_pipe.c:api_rpcTNP(2265)
api_rpcTNP: rpc command: SPOOLSS_CLOSEPRINTER
[2006/07/12 14:51:22, 3] rpc_server/srv_lsa_hnd.c:close_policy_hnd(200)
Closed policy
[2006/07/12 14:51:22, 3] rpc_server/srv_pipe_hnd.c:free_pipe_context(529)
free_pipe_context: destroying talloc pool of size 0
Daniel Martin
2006-Jul-13 02:38 UTC
[Samba] continuous access to printer causes high memory usage
Hello, We?ve experiencing similar problems (CPU and memory usage). Then we followed some tips of the website below and it solved our problems http://www.cups.org/articles.php?L264 I hope it helps Roel van Meer escreveu:> Hi list, > > I am trying to track down a printer-related problem. > > The most important symptom is a smbd process using almost all memory > on my machine (up to 800 MB, at the specific case of which I've posted > the logs.) At some point the VM will kill the smbd process, freeing > the memory. Apart from this, samba keeps on running fine. > > Investigation of a level 3 debug log of this process has shown that > the client (a Windows XP machine) is accessing one of the samba > printers almost continuously, with four rpc calls: > SPOOLSS_OPENPRINTEREX, SPOOLSS_GETPRINTERDATA, SPOOLSS_CLOSEPRINTER > and SPOOLSS_ENUMJOBS. > The printer driver is installed on the samba server. The client is > configured to use the printer via a Samba port. When the printer is > removed from the client, the rapid calls stop. When the printer is > installed again, the calls again occur in rapid succession. > > Attached you'll find an excerpt of the output of 'ps', my smb.conf and > a piece of the log file. > I've seen this problem at a few different machines, with samba > versions 3.0.20, 3.0.22 and 3.0.23 and different clients (all Windows > 2000 or XP). All machines are running Slackware 10.1. The only > solution I have found so far is removing the printers from the client. > > I have been wondering if this problem can be caused by an absent or > invalid > deviced mode for this printer. > > Does anyone have a clue about what might cause this? Or a hint about > where to look further? I'm more than willing to provide more detailed > information. > > Thanks in advance, > > roel > ------------------------------------------------------------------------ > > # /etc/samba/smb.conf > # $Id: smb.conf,v 1.35 2005/09/26 08:47:52 rolek Exp $ > [global] > workgroup = WG > netbios name = SERVER > server string = server > > interfaces = 192.168.1.255/24 127.255.255.255/8 > bind interfaces only = Yes > hosts allow = 192.168.1. 127.0.0.1 > > encrypt passwords = Yes > null passwords = Yes > username map = /etc/samba/smbusers > > log file = /var/log/samba/samba.log > max log size=350k > max open files = 4000 > syslog = 0 > > domain logons = Yes > logon script = %U.bat > logon path = \\server\%U\.profileNT > logon drive = H: > logon home = \\server\%U > > os level = 254 > preferred master = Yes > domain master = Yes > local master = Yes > > wins support = Yes > time server = Yes > name resolve order = host wins bcast > > passdb backend = ldapsam:ldap://localhost > ldap suffix = dc=tecobv,dc=nl > ldap machine suffix = ou=users > ldap user suffix = ou=users > ldap group suffix = ou=Groups > ldap idmap suffix = ou=Idmap > ldap admin dn = cn=admin,dc=tecobv,dc=nl > idmap backend = ldap:ldap://localhost > idmap uid = 10000-20000 > idmap gid = 10000-20000 > > printing = cups > min print space = 1000 > > create mask = 0660 > force create mode = 0660 > directory mask = 0770 > force directory mode = 0770 > oplocks = No > level2 oplocks = No > > [printers] > comment = All Printers > path = /var/spool/print/tmp > create mask = 0700 > guest ok = Yes > printable = Yes > printing = cups > use client driver = No > min print space = 2000 > > [print$] > comment = Printer Drivers > path = /var/spool/samba/drivers > guest ok = Yes > browsable = yes > readonly = yes > write list = root,@Administrators > > ------------------------------------------------------------------------ > > ---> Memory usage: > root@server:~# ps axfuw | grep smbd > root 12652 0.0 0.2 8868 2320 ? Ss Jul11 0:00 /usr/sbin/smbd -D > root 12656 0.0 0.2 9264 2972 ? S Jul11 0:00 \_ /usr/sbin/smbd -D > root 31433 0.0 0.4 9368 4880 ? S 08:28 0:02 \_ /usr/sbin/smbd -D > user1 31842 0.2 77.8 872844 803180 ? S 08:46 1:21 \_ /usr/sbin/smbd -D > user2 32035 0.0 0.5 12200 5764 ? S 08:54 0:00 \_ /usr/sbin/smbd -D > user3 32292 0.0 2.5 35092 26056 ? S 09:03 0:02 \_ /usr/sbin/smbd -D > root 9788 0.0 0.3 9180 3496 ? S 16:01 0:00 \_ /usr/sbin/smbd -D > > ---> Excerpt from samba.log > > [2006/07/12 14:51:21, 3] smbd/process.c:process_smb(1110) > Transaction 429419 of length 332 > [2006/07/12 14:51:21, 3] smbd/process.c:switch_message(914) > switch message SMBtrans (pid 31842) conn 0x84b3a98 > [2006/07/12 14:51:21, 3] smbd/sec_ctx.c:set_sec_ctx(241) > setting sec ctx (1008, 100) - sec_ctx_stack_ndx = 0 > [2006/07/12 14:51:21, 3] smbd/ipc.c:handle_trans(373) > trans <\PIPE\> data=244 params=0 setup=2 > [2006/07/12 14:51:21, 3] smbd/ipc.c:named_pipe(340) > named pipe command on <> name > [2006/07/12 14:51:21, 3] smbd/ipc.c:api_fd_reply(300) > Got API command 0x26 on pipe "spoolss" (pnum 71da) > [2006/07/12 14:51:21, 3] rpc_server/srv_pipe_hnd.c:free_pipe_context(529) > free_pipe_context: destroying talloc pool of size 0 > [2006/07/12 14:51:21, 3] rpc_server/srv_pipe.c:api_rpcTNP(2265) > api_rpcTNP: rpc command: SPOOLSS_OPENPRINTEREX > checking name: \\teco-server\HP LaserJet 3050 Series PCL 5e > [2006/07/12 14:51:21, 3] rpc_server/srv_spoolss_nt.c:set_printer_hnd_printertype(408) > Setting printer type=\\teco-server\HP LaserJet 3050 Series PCL 5e > [2006/07/12 14:51:21, 3] lib/access.c:check_access(313) > check_access: no hostnames in host allow/deny list. > [2006/07/12 14:51:21, 2] lib/access.c:check_access(324) > Allowed connection from (192.168.22.243) > [2006/07/12 14:51:21, 3] lib/util_seaccess.c:se_access_check(250) > [2006/07/12 14:51:21, 3] lib/util_seaccess.c:se_access_check(251) > se_access_check: user sid is S-1-5-21-976746554-266313863-47890339-3016 > se_access_check: also S-1-5-21-976746554-266313863-47890339-100 > se_access_check: also S-1-1-0 > se_access_check: also S-1-5-2 > se_access_check: also S-1-5-11 > [2006/07/12 14:51:21, 3] rpc_server/srv_pipe_hnd.c:free_pipe_context(529) > free_pipe_context: destroying talloc pool of size 196 > [2006/07/12 14:51:21, 3] smbd/process.c:process_smb(1110) > Transaction 429420 of length 168 > [2006/07/12 14:51:21, 3] smbd/process.c:switch_message(914) > switch message SMBtrans (pid 31842) conn 0x84b3a98 > [2006/07/12 14:51:21, 3] smbd/ipc.c:handle_trans(373) > trans <\PIPE\> data=80 params=0 setup=2 > [2006/07/12 14:51:21, 3] smbd/ipc.c:named_pipe(340) > named pipe command on <> name > [2006/07/12 14:51:21, 3] smbd/ipc.c:api_fd_reply(300) > Got API command 0x26 on pipe "spoolss" (pnum 71da) > [2006/07/12 14:51:21, 3] rpc_server/srv_pipe_hnd.c:free_pipe_context(529) > free_pipe_context: destroying talloc pool of size 0 > [2006/07/12 14:51:21, 3] rpc_server/srv_pipe.c:api_rpcTNP(2265) > api_rpcTNP: rpc command: SPOOLSS_GETPRINTERDATA > [2006/07/12 14:51:21, 3] rpc_server/srv_pipe_hnd.c:free_pipe_context(529) > free_pipe_context: destroying talloc pool of size 22 > [2006/07/12 14:51:21, 3] smbd/process.c:process_smb(1110) > Transaction 429421 of length 132 > [2006/07/12 14:51:21, 3] smbd/process.c:switch_message(914) > switch message SMBtrans (pid 31842) conn 0x84b3a98 > [2006/07/12 14:51:21, 3] smbd/ipc.c:handle_trans(373) > trans <\PIPE\> data=44 params=0 setup=2 > [2006/07/12 14:51:21, 3] smbd/ipc.c:named_pipe(340) > named pipe command on <> name > [2006/07/12 14:51:21, 3] smbd/ipc.c:api_fd_reply(300) > Got API command 0x26 on pipe "spoolss" (pnum 71da) > [2006/07/12 14:51:21, 3] rpc_server/srv_pipe_hnd.c:free_pipe_context(529) > free_pipe_context: destroying talloc pool of size 0 > [2006/07/12 14:51:21, 3] rpc_server/srv_pipe.c:api_rpcTNP(2265) > api_rpcTNP: rpc command: SPOOLSS_CLOSEPRINTER > [2006/07/12 14:51:21, 3] rpc_server/srv_lsa_hnd.c:close_policy_hnd(200) > Closed policy > [2006/07/12 14:51:21, 3] rpc_server/srv_pipe_hnd.c:free_pipe_context(529) > free_pipe_context: destroying talloc pool of size 0 > [2006/07/12 14:51:21, 3] smbd/process.c:process_smb(1110) > Transaction 429422 of length 332 > [2006/07/12 14:51:21, 3] smbd/process.c:switch_message(914) > switch message SMBtrans (pid 31842) conn 0x84b3a98 > [2006/07/12 14:51:21, 3] smbd/ipc.c:handle_trans(373) > trans <\PIPE\> data=244 params=0 setup=2 > [2006/07/12 14:51:21, 3] smbd/ipc.c:named_pipe(340) > named pipe command on <> name > [2006/07/12 14:51:21, 3] smbd/ipc.c:api_fd_reply(300) > Got API command 0x26 on pipe "spoolss" (pnum 7402) > [2006/07/12 14:51:21, 3] rpc_server/srv_pipe_hnd.c:free_pipe_context(529) > free_pipe_context: destroying talloc pool of size 0 > [2006/07/12 14:51:21, 3] rpc_server/srv_pipe.c:api_rpcTNP(2265) > api_rpcTNP: rpc command: SPOOLSS_OPENPRINTEREX > checking name: \\teco-server\HP LaserJet 3050 Series PCL 5e > [2006/07/12 14:51:21, 3] rpc_server/srv_spoolss_nt.c:set_printer_hnd_printertype(408) > Setting printer type=\\teco-server\HP LaserJet 3050 Series PCL 5e > [2006/07/12 14:51:21, 3] lib/access.c:check_access(313) > check_access: no hostnames in host allow/deny list. > [2006/07/12 14:51:21, 2] lib/access.c:check_access(324) > Allowed connection from (192.168.22.243) > [2006/07/12 14:51:21, 3] lib/util_seaccess.c:se_access_check(250) > [2006/07/12 14:51:21, 3] lib/util_seaccess.c:se_access_check(251) > se_access_check: user sid is S-1-5-21-976746554-266313863-47890339-3016 > se_access_check: also S-1-5-21-976746554-266313863-47890339-100 > se_access_check: also S-1-1-0 > se_access_check: also S-1-5-2 > se_access_check: also S-1-5-11 > [2006/07/12 14:51:21, 3] rpc_server/srv_pipe_hnd.c:free_pipe_context(529) > free_pipe_context: destroying talloc pool of size 196 > [2006/07/12 14:51:21, 3] smbd/process.c:process_smb(1110) > Transaction 429423 of length 152 > [2006/07/12 14:51:21, 3] smbd/process.c:switch_message(914) > switch message SMBtrans (pid 31842) conn 0x84b3a98 > [2006/07/12 14:51:21, 3] smbd/ipc.c:handle_trans(373) > trans <\PIPE\> data=64 params=0 setup=2 > [2006/07/12 14:51:21, 3] smbd/ipc.c:named_pipe(340) > named pipe command on <> name > [2006/07/12 14:51:21, 3] smbd/ipc.c:api_fd_reply(300) > Got API command 0x26 on pipe "spoolss" (pnum 71da) > [2006/07/12 14:51:21, 3] rpc_server/srv_pipe_hnd.c:free_pipe_context(529) > free_pipe_context: destroying talloc pool of size 0 > [2006/07/12 14:51:21, 3] rpc_server/srv_pipe.c:api_rpcTNP(2265) > api_rpcTNP: rpc command: SPOOLSS_ENUMJOBS > [2006/07/12 14:51:21, 3] rpc_server/srv_pipe_hnd.c:free_pipe_context(529) > free_pipe_context: destroying talloc pool of size 0 > [2006/07/12 14:51:21, 3] smbd/process.c:process_smb(1110) > Transaction 429424 of length 132 > [2006/07/12 14:51:21, 3] smbd/process.c:switch_message(914) > switch message SMBtrans (pid 31842) conn 0x84b3a98 > [2006/07/12 14:51:21, 3] smbd/ipc.c:handle_trans(373) > trans <\PIPE\> data=44 params=0 setup=2 > [2006/07/12 14:51:21, 3] smbd/ipc.c:named_pipe(340) > named pipe command on <> name > [2006/07/12 14:51:21, 3] smbd/ipc.c:api_fd_reply(300) > Got API command 0x26 on pipe "spoolss" (pnum 71da) > [2006/07/12 14:51:21, 3] rpc_server/srv_pipe_hnd.c:free_pipe_context(529) > free_pipe_context: destroying talloc pool of size 0 > [2006/07/12 14:51:21, 3] rpc_server/srv_pipe.c:api_rpcTNP(2265) > api_rpcTNP: rpc command: SPOOLSS_CLOSEPRINTER > [2006/07/12 14:51:21, 3] rpc_server/srv_lsa_hnd.c:close_policy_hnd(200) > Closed policy > [2006/07/12 14:51:21, 3] rpc_server/srv_pipe_hnd.c:free_pipe_context(529) > free_pipe_context: destroying talloc pool of size 0 > [2006/07/12 14:51:21, 3] smbd/process.c:process_smb(1110) > Transaction 429425 of length 76 > [2006/07/12 14:51:21, 3] smbd/process.c:switch_message(914) > switch message SMBtrans2 (pid 31842) conn 0x84b1288 > [2006/07/12 14:51:21, 3] smbd/sec_ctx.c:set_sec_ctx(241) > setting sec ctx (1008, 100) - sec_ctx_stack_ndx = 0 > [2006/07/12 14:51:21, 3] smbd/trans2.c:call_trans2qfilepathinfo(2852) > call_trans2qfilepathinfo: TRANSACT2_QFILEINFO: level = 1004 > [2006/07/12 14:51:21, 3] smbd/trans2.c:call_trans2qfilepathinfo(2959) > call_trans2qfilepathinfo My Documents/My Pictures (fnum = 7850) level=1004 call=7 total_data=0 > [2006/07/12 14:51:21, 3] smbd/process.c:process_smb(1110) > Transaction 429426 of length 76 > [2006/07/12 14:51:21, 3] smbd/process.c:switch_message(914) > switch message SMBtrans2 (pid 31842) conn 0x84b1288 > [2006/07/12 14:51:21, 3] smbd/trans2.c:call_trans2qfilepathinfo(2852) > call_trans2qfilepathinfo: TRANSACT2_QFILEINFO: level = 1005 > [2006/07/12 14:51:21, 3] smbd/trans2.c:call_trans2qfilepathinfo(2959) > call_trans2qfilepathinfo My Documents/My Pictures (fnum = 7850) level=1005 call=7 total_data=0 > [2006/07/12 14:51:21, 3] smbd/process.c:process_smb(1110) > Transaction 429427 of length 76 > [2006/07/12 14:51:21, 3] smbd/process.c:switch_message(914) > switch message SMBtrans2 (pid 31842) conn 0x84b1288 > [2006/07/12 14:51:21, 3] smbd/trans2.c:call_trans2qfilepathinfo(2852) > call_trans2qfilepathinfo: TRANSACT2_QFILEINFO: level = 1004 > [2006/07/12 14:51:21, 3] smbd/trans2.c:call_trans2qfilepathinfo(2959) > call_trans2qfilepathinfo My Documents/My Pictures (fnum = 7850) level=1004 call=7 total_data=0 > [2006/07/12 14:51:21, 3] smbd/process.c:process_smb(1110) > Transaction 429428 of length 45 > [2006/07/12 14:51:21, 3] smbd/process.c:switch_message(914) > switch message SMBclose (pid 31842) conn 0x84b1288 > [2006/07/12 14:51:21, 3] smbd/reply.c:reply_close(3298) > close directory fnum=7850 > [2006/07/12 14:51:21, 3] smbd/process.c:process_smb(1110) > Transaction 429429 of length 180 > [2006/07/12 14:51:21, 3] smbd/process.c:switch_message(914) > switch message SMBntcreateX (pid 31842) conn 0x84b1288 > [2006/07/12 14:51:21, 3] smbd/msdfs.c:dfs_redirect(435) > dfs_redirect: Not redirecting teco-server/friedel/My Documents/My Pictures. > [2006/07/12 14:51:21, 3] smbd/msdfs.c:dfs_redirect(439) > dfs_redirect: Path converted to non-dfs path My Documents/My Pictures > [2006/07/12 14:51:21, 3] smbd/dosmode.c:unix_mode(147) > unix_mode(My Documents/My Pictures) returning 0600 > [2006/07/12 14:51:21, 3] smbd/process.c:process_smb(1110) > Transaction 429430 of length 76 > [2006/07/12 14:51:21, 3] smbd/process.c:switch_message(914) > switch message SMBtrans2 (pid 31842) conn 0x84b1288 > [2006/07/12 14:51:21, 3] smbd/trans2.c:call_trans2qfilepathinfo(2852) > call_trans2qfilepathinfo: TRANSACT2_QFILEINFO: level = 1004 > [2006/07/12 14:51:21, 3] smbd/trans2.c:call_trans2qfilepathinfo(2959) > call_trans2qfilepathinfo My Documents/My Pictures (fnum = 7852) level=1004 call=7 total_data=0 > [2006/07/12 14:51:21, 3] smbd/process.c:process_smb(1110) > Transaction 429431 of length 76 > [2006/07/12 14:51:21, 3] smbd/process.c:switch_message(914) > switch message SMBtrans2 (pid 31842) conn 0x84b1288 > [2006/07/12 14:51:21, 3] smbd/trans2.c:call_trans2qfilepathinfo(2852) > call_trans2qfilepathinfo: TRANSACT2_QFILEINFO: level = 1005 > [2006/07/12 14:51:21, 3] smbd/trans2.c:call_trans2qfilepathinfo(2959) > call_trans2qfilepathinfo My Documents/My Pictures (fnum = 7852) level=1005 call=7 total_data=0 > [2006/07/12 14:51:21, 3] smbd/process.c:process_smb(1110) > Transaction 429432 of length 76 > [2006/07/12 14:51:21, 3] smbd/process.c:switch_message(914) > switch message SMBtrans2 (pid 31842) conn 0x84b1288 > [2006/07/12 14:51:21, 3] smbd/trans2.c:call_trans2qfilepathinfo(2852) > call_trans2qfilepathinfo: TRANSACT2_QFILEINFO: level = 1004 > [2006/07/12 14:51:21, 3] smbd/trans2.c:call_trans2qfilepathinfo(2959) > call_trans2qfilepathinfo My Documents/My Pictures (fnum = 7852) level=1004 call=7 total_data=0 > [2006/07/12 14:51:21, 3] smbd/process.c:process_smb(1110) > Transaction 429433 of length 45 > [2006/07/12 14:51:21, 3] smbd/process.c:switch_message(914) > switch message SMBclose (pid 31842) conn 0x84b1288 > [2006/07/12 14:51:21, 3] smbd/reply.c:reply_close(3298) > close directory fnum=7852 > [2006/07/12 14:51:21, 3] smbd/process.c:process_smb(1110) > Transaction 429434 of length 180 > [2006/07/12 14:51:21, 3] smbd/process.c:switch_message(914) > switch message SMBntcreateX (pid 31842) conn 0x84b1288 > [2006/07/12 14:51:21, 3] smbd/msdfs.c:dfs_redirect(435) > dfs_redirect: Not redirecting teco-server/friedel/My Documents/My Pictures. > [2006/07/12 14:51:21, 3] smbd/msdfs.c:dfs_redirect(439) > dfs_redirect: Path converted to non-dfs path My Documents/My Pictures > [2006/07/12 14:51:21, 3] smbd/dosmode.c:unix_mode(147) > unix_mode(My Documents/My Pictures) returning 0600 > [2006/07/12 14:51:21, 3] smbd/process.c:process_smb(1110) > Transaction 429435 of length 76 > [2006/07/12 14:51:21, 3] smbd/process.c:switch_message(914) > switch message SMBtrans2 (pid 31842) conn 0x84b1288 > [2006/07/12 14:51:21, 3] smbd/trans2.c:call_trans2qfilepathinfo(2852) > call_trans2qfilepathinfo: TRANSACT2_QFILEINFO: level = 1004 > [2006/07/12 14:51:21, 3] smbd/trans2.c:call_trans2qfilepathinfo(2959) > call_trans2qfilepathinfo My Documents/My Pictures (fnum = 7854) level=1004 call=7 total_data=0 > [2006/07/12 14:51:21, 3] smbd/process.c:process_smb(1110) > Transaction 429436 of length 76 > [2006/07/12 14:51:21, 3] smbd/process.c:switch_message(914) > switch message SMBtrans2 (pid 31842) conn 0x84b1288 > [2006/07/12 14:51:21, 3] smbd/trans2.c:call_trans2qfilepathinfo(2852) > call_trans2qfilepathinfo: TRANSACT2_QFILEINFO: level = 1005 > [2006/07/12 14:51:21, 3] smbd/trans2.c:call_trans2qfilepathinfo(2959) > call_trans2qfilepathinfo My Documents/My Pictures (fnum = 7854) level=1005 call=7 total_data=0 > [2006/07/12 14:51:21, 3] smbd/process.c:process_smb(1110) > Transaction 429437 of length 76 > [2006/07/12 14:51:21, 3] smbd/process.c:switch_message(914) > switch message SMBtrans2 (pid 31842) conn 0x84b1288 > [2006/07/12 14:51:21, 3] smbd/trans2.c:call_trans2qfilepathinfo(2852) > call_trans2qfilepathinfo: TRANSACT2_QFILEINFO: level = 1004 > [2006/07/12 14:51:21, 3] smbd/trans2.c:call_trans2qfilepathinfo(2959) > call_trans2qfilepathinfo My Documents/My Pictures (fnum = 7854) level=1004 call=7 total_data=0 > [2006/07/12 14:51:21, 3] smbd/process.c:process_smb(1110) > Transaction 429438 of length 45 > [2006/07/12 14:51:21, 3] smbd/process.c:switch_message(914) > switch message SMBclose (pid 31842) conn 0x84b1288 > [2006/07/12 14:51:21, 3] smbd/reply.c:reply_close(3298) > close directory fnum=7854 > [2006/07/12 14:51:21, 3] smbd/process.c:process_smb(1110) > Transaction 429439 of length 180 > [2006/07/12 14:51:21, 3] smbd/process.c:switch_message(914) > switch message SMBntcreateX (pid 31842) conn 0x84b1288 > [2006/07/12 14:51:21, 3] smbd/msdfs.c:dfs_redirect(435) > dfs_redirect: Not redirecting teco-server/friedel/My Documents/My Pictures. > [2006/07/12 14:51:21, 3] smbd/msdfs.c:dfs_redirect(439) > dfs_redirect: Path converted to non-dfs path My Documents/My Pictures > [2006/07/12 14:51:21, 3] smbd/dosmode.c:unix_mode(147) > unix_mode(My Documents/My Pictures) returning 0600 > [2006/07/12 14:51:21, 3] smbd/process.c:process_smb(1110) > Transaction 429440 of length 76 > [2006/07/12 14:51:21, 3] smbd/process.c:switch_message(914) > switch message SMBtrans2 (pid 31842) conn 0x84b1288 > [2006/07/12 14:51:21, 3] smbd/trans2.c:call_trans2qfilepathinfo(2852) > call_trans2qfilepathinfo: TRANSACT2_QFILEINFO: level = 1004 > [2006/07/12 14:51:21, 3] smbd/trans2.c:call_trans2qfilepathinfo(2959) > call_trans2qfilepathinfo My Documents/My Pictures (fnum = 7856) level=1004 call=7 total_data=0 > [2006/07/12 14:51:21, 3] smbd/process.c:process_smb(1110) > Transaction 429441 of length 76 > [2006/07/12 14:51:21, 3] smbd/process.c:switch_message(914) > switch message SMBtrans2 (pid 31842) conn 0x84b1288 > [2006/07/12 14:51:21, 3] smbd/trans2.c:call_trans2qfilepathinfo(2852) > call_trans2qfilepathinfo: TRANSACT2_QFILEINFO: level = 1005 > [2006/07/12 14:51:21, 3] smbd/trans2.c:call_trans2qfilepathinfo(2959) > call_trans2qfilepathinfo My Documents/My Pictures (fnum = 7856) level=1005 call=7 total_data=0 > [2006/07/12 14:51:21, 3] smbd/process.c:process_smb(1110) > Transaction 429442 of length 76 > [2006/07/12 14:51:21, 3] smbd/process.c:switch_message(914) > switch message SMBtrans2 (pid 31842) conn 0x84b1288 > [2006/07/12 14:51:21, 3] smbd/trans2.c:call_trans2qfilepathinfo(2852) > call_trans2qfilepathinfo: TRANSACT2_QFILEINFO: level = 1004 > [2006/07/12 14:51:21, 3] smbd/trans2.c:call_trans2qfilepathinfo(2959) > call_trans2qfilepathinfo My Documents/My Pictures (fnum = 7856) level=1004 call=7 total_data=0 > [2006/07/12 14:51:21, 3] smbd/process.c:process_smb(1110) > Transaction 429443 of length 45 > [2006/07/12 14:51:21, 3] smbd/process.c:switch_message(914) > switch message SMBclose (pid 31842) conn 0x84b1288 > [2006/07/12 14:51:21, 3] smbd/reply.c:reply_close(3298) > close directory fnum=7856 > [2006/07/12 14:51:21, 3] smbd/process.c:process_smb(1110) > Transaction 429444 of length 180 > [2006/07/12 14:51:21, 3] smbd/process.c:switch_message(914) > switch message SMBntcreateX (pid 31842) conn 0x84b1288 > [2006/07/12 14:51:21, 3] smbd/msdfs.c:dfs_redirect(435) > dfs_redirect: Not redirecting teco-server/friedel/My Documents/My Pictures. > [2006/07/12 14:51:21, 3] smbd/msdfs.c:dfs_redirect(439) > dfs_redirect: Path converted to non-dfs path My Documents/My Pictures > [2006/07/12 14:51:21, 3] smbd/dosmode.c:unix_mode(147) > unix_mode(My Documents/My Pictures) returning 0600 > [2006/07/12 14:51:22, 3] smbd/process.c:process_smb(1110) > Transaction 429445 of length 76 > [2006/07/12 14:51:22, 3] smbd/process.c:switch_message(914) > switch message SMBtrans2 (pid 31842) conn 0x84b1288 > [2006/07/12 14:51:22, 3] smbd/trans2.c:call_trans2qfilepathinfo(2852) > call_trans2qfilepathinfo: TRANSACT2_QFILEINFO: level = 1004 > [2006/07/12 14:51:22, 3] smbd/trans2.c:call_trans2qfilepathinfo(2959) > call_trans2qfilepathinfo My Documents/My Pictures (fnum = 7858) level=1004 call=7 total_data=0 > [2006/07/12 14:51:22, 3] smbd/process.c:process_smb(1110) > Transaction 429446 of length 76 > [2006/07/12 14:51:22, 3] smbd/process.c:switch_message(914) > switch message SMBtrans2 (pid 31842) conn 0x84b1288 > [2006/07/12 14:51:22, 3] smbd/trans2.c:call_trans2qfilepathinfo(2852) > call_trans2qfilepathinfo: TRANSACT2_QFILEINFO: level = 1005 > [2006/07/12 14:51:22, 3] smbd/trans2.c:call_trans2qfilepathinfo(2959) > call_trans2qfilepathinfo My Documents/My Pictures (fnum = 7858) level=1005 call=7 total_data=0 > [2006/07/12 14:51:22, 3] smbd/process.c:process_smb(1110) > Transaction 429447 of length 76 > [2006/07/12 14:51:22, 3] smbd/process.c:switch_message(914) > switch message SMBtrans2 (pid 31842) conn 0x84b1288 > [2006/07/12 14:51:22, 3] smbd/trans2.c:call_trans2qfilepathinfo(2852) > call_trans2qfilepathinfo: TRANSACT2_QFILEINFO: level = 1004 > [2006/07/12 14:51:22, 3] smbd/trans2.c:call_trans2qfilepathinfo(2959) > call_trans2qfilepathinfo My Documents/My Pictures (fnum = 7858) level=1004 call=7 total_data=0 > [2006/07/12 14:51:22, 3] smbd/process.c:process_smb(1110) > Transaction 429448 of length 45 > [2006/07/12 14:51:22, 3] smbd/process.c:switch_message(914) > switch message SMBclose (pid 31842) conn 0x84b1288 > [2006/07/12 14:51:22, 3] smbd/reply.c:reply_close(3298) > close directory fnum=7858 > [2006/07/12 14:51:22, 3] smbd/process.c:process_smb(1110) > Transaction 429449 of length 180 > [2006/07/12 14:51:22, 3] smbd/process.c:switch_message(914) > switch message SMBntcreateX (pid 31842) conn 0x84b1288 > [2006/07/12 14:51:22, 3] smbd/msdfs.c:dfs_redirect(435) > dfs_redirect: Not redirecting teco-server/friedel/My Documents/My Pictures. > [2006/07/12 14:51:22, 3] smbd/msdfs.c:dfs_redirect(439) > dfs_redirect: Path converted to non-dfs path My Documents/My Pictures > [2006/07/12 14:51:22, 3] smbd/dosmode.c:unix_mode(147) > unix_mode(My Documents/My Pictures) returning 0600 > [2006/07/12 14:51:22, 3] smbd/sec_ctx.c:set_sec_ctx(241) > setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0 > [2006/07/12 14:51:22, 3] smbd/process.c:process_smb(1110) > Transaction 429450 of length 76 > [2006/07/12 14:51:22, 3] smbd/process.c:switch_message(914) > switch message SMBtrans2 (pid 31842) conn 0x84b1288 > [2006/07/12 14:51:22, 3] smbd/sec_ctx.c:set_sec_ctx(241) > setting sec ctx (1008, 100) - sec_ctx_stack_ndx = 0 > [2006/07/12 14:51:22, 3] smbd/trans2.c:call_trans2qfilepathinfo(2852) > call_trans2qfilepathinfo: TRANSACT2_QFILEINFO: level = 1004 > [2006/07/12 14:51:22, 3] smbd/trans2.c:call_trans2qfilepathinfo(2959) > call_trans2qfilepathinfo My Documents/My Pictures (fnum = 7860) level=1004 call=7 total_data=0 > [2006/07/12 14:51:22, 3] smbd/process.c:process_smb(1110) > Transaction 429451 of length 76 > [2006/07/12 14:51:22, 3] smbd/process.c:switch_message(914) > switch message SMBtrans2 (pid 31842) conn 0x84b1288 > [2006/07/12 14:51:22, 3] smbd/trans2.c:call_trans2qfilepathinfo(2852) > call_trans2qfilepathinfo: TRANSACT2_QFILEINFO: level = 1005 > [2006/07/12 14:51:22, 3] smbd/trans2.c:call_trans2qfilepathinfo(2959) > call_trans2qfilepathinfo My Documents/My Pictures (fnum = 7860) level=1005 call=7 total_data=0 > [2006/07/12 14:51:22, 3] smbd/process.c:process_smb(1110) > Transaction 429452 of length 76 > [2006/07/12 14:51:22, 3] smbd/process.c:switch_message(914) > switch message SMBtrans2 (pid 31842) conn 0x84b1288 > [2006/07/12 14:51:22, 3] smbd/trans2.c:call_trans2qfilepathinfo(2852) > call_trans2qfilepathinfo: TRANSACT2_QFILEINFO: level = 1004 > [2006/07/12 14:51:22, 3] smbd/trans2.c:call_trans2qfilepathinfo(2959) > call_trans2qfilepathinfo My Documents/My Pictures (fnum = 7860) level=1004 call=7 total_data=0 > [2006/07/12 14:51:22, 3] smbd/process.c:process_smb(1110) > Transaction 429453 of length 45 > [2006/07/12 14:51:22, 3] smbd/process.c:switch_message(914) > switch message SMBclose (pid 31842) conn 0x84b1288 > [2006/07/12 14:51:22, 3] smbd/reply.c:reply_close(3298) > close directory fnum=7860 > [2006/07/12 14:51:22, 3] smbd/process.c:process_smb(1110) > Transaction 429454 of length 180 > [2006/07/12 14:51:22, 3] smbd/process.c:switch_message(914) > switch message SMBntcreateX (pid 31842) conn 0x84b1288 > [2006/07/12 14:51:22, 3] smbd/msdfs.c:dfs_redirect(435) > dfs_redirect: Not redirecting teco-server/friedel/My Documents/My Pictures. > [2006/07/12 14:51:22, 3] smbd/msdfs.c:dfs_redirect(439) > dfs_redirect: Path converted to non-dfs path My Documents/My Pictures > [2006/07/12 14:51:22, 3] smbd/dosmode.c:unix_mode(147) > unix_mode(My Documents/My Pictures) returning 0600 > [2006/07/12 14:51:22, 3] smbd/process.c:process_smb(1110) > Transaction 429455 of length 332 > [2006/07/12 14:51:22, 3] smbd/process.c:switch_message(914) > switch message SMBtrans (pid 31842) conn 0x84b3a98 > [2006/07/12 14:51:22, 3] smbd/sec_ctx.c:set_sec_ctx(241) > setting sec ctx (1008, 100) - sec_ctx_stack_ndx = 0 > [2006/07/12 14:51:22, 3] smbd/ipc.c:handle_trans(373) > trans <\PIPE\> data=244 params=0 setup=2 > [2006/07/12 14:51:22, 3] smbd/ipc.c:named_pipe(340) > named pipe command on <> name > [2006/07/12 14:51:22, 3] smbd/ipc.c:api_fd_reply(300) > Got API command 0x26 on pipe "spoolss" (pnum 71da) > [2006/07/12 14:51:22, 3] rpc_server/srv_pipe_hnd.c:free_pipe_context(529) > free_pipe_context: destroying talloc pool of size 0 > [2006/07/12 14:51:22, 3] rpc_server/srv_pipe.c:api_rpcTNP(2265) > api_rpcTNP: rpc command: SPOOLSS_OPENPRINTEREX > checking name: \\teco-server\HP LaserJet 3050 Series PCL 5e > [2006/07/12 14:51:22, 3] rpc_server/srv_spoolss_nt.c:set_printer_hnd_printertype(408) > Setting printer type=\\teco-server\HP LaserJet 3050 Series PCL 5e > [2006/07/12 14:51:22, 3] lib/access.c:check_access(313) > check_access: no hostnames in host allow/deny list. > [2006/07/12 14:51:22, 2] lib/access.c:check_access(324) > Allowed connection from (192.168.22.243) > [2006/07/12 14:51:22, 3] lib/util_seaccess.c:se_access_check(250) > [2006/07/12 14:51:22, 3] lib/util_seaccess.c:se_access_check(251) > se_access_check: user sid is S-1-5-21-976746554-266313863-47890339-3016 > se_access_check: also S-1-5-21-976746554-266313863-47890339-100 > se_access_check: also S-1-1-0 > se_access_check: also S-1-5-2 > se_access_check: also S-1-5-11 > [2006/07/12 14:51:22, 3] rpc_server/srv_pipe_hnd.c:free_pipe_context(529) > free_pipe_context: destroying talloc pool of size 196 > [2006/07/12 14:51:22, 3] smbd/process.c:process_smb(1110) > Transaction 429456 of length 132 > [2006/07/12 14:51:22, 3] smbd/process.c:switch_message(914) > switch message SMBtrans (pid 31842) conn 0x84b3a98 > [2006/07/12 14:51:22, 3] smbd/ipc.c:handle_trans(373) > trans <\PIPE\> data=44 params=0 setup=2 > [2006/07/12 14:51:22, 3] smbd/ipc.c:named_pipe(340) > named pipe command on <> name > [2006/07/12 14:51:22, 3] smbd/ipc.c:api_fd_reply(300) > Got API command 0x26 on pipe "spoolss" (pnum 71da) > [2006/07/12 14:51:22, 3] rpc_server/srv_pipe_hnd.c:free_pipe_context(529) > free_pipe_context: destroying talloc pool of size 0 > [2006/07/12 14:51:22, 3] rpc_server/srv_pipe.c:api_rpcTNP(2265) > api_rpcTNP: rpc command: SPOOLSS_CLOSEPRINTER > [2006/07/12 14:51:22, 3] rpc_server/srv_lsa_hnd.c:close_policy_hnd(200) > Closed policy > [2006/07/12 14:51:22, 3] rpc_server/srv_pipe_hnd.c:free_pipe_context(529) > free_pipe_context: destroying talloc pool of size 0 > [2006/07/12 14:51:22, 3] smbd/process.c:process_smb(1110) > Transaction 429457 of length 332 > [2006/07/12 14:51:22, 3] smbd/process.c:switch_message(914) > switch message SMBtrans (pid 31842) conn 0x84b3a98 > [2006/07/12 14:51:22, 3] smbd/ipc.c:handle_trans(373) > trans <\PIPE\> data=244 params=0 setup=2 > [2006/07/12 14:51:22, 3] smbd/ipc.c:named_pipe(340) > named pipe command on <> name > [2006/07/12 14:51:22, 3] smbd/ipc.c:api_fd_reply(300) > Got API command 0x26 on pipe "spoolss" (pnum 71da) > [2006/07/12 14:51:22, 3] rpc_server/srv_pipe_hnd.c:free_pipe_context(529) > free_pipe_context: destroying talloc pool of size 0 > [2006/07/12 14:51:22, 3] rpc_server/srv_pipe.c:api_rpcTNP(2265) > api_rpcTNP: rpc command: SPOOLSS_OPENPRINTEREX > checking name: \\teco-server\HP LaserJet 3050 Series PCL 5e > [2006/07/12 14:51:22, 3] rpc_server/srv_spoolss_nt.c:set_printer_hnd_printertype(408) > Setting printer type=\\teco-server\HP LaserJet 3050 Series PCL 5e > [2006/07/12 14:51:22, 3] lib/access.c:check_access(313) > check_access: no hostnames in host allow/deny list. > [2006/07/12 14:51:22, 2] lib/access.c:check_access(324) > Allowed connection from (192.168.22.243) > [2006/07/12 14:51:22, 3] lib/util_seaccess.c:se_access_check(250) > [2006/07/12 14:51:22, 3] lib/util_seaccess.c:se_access_check(251) > se_access_check: user sid is S-1-5-21-976746554-266313863-47890339-3016 > se_access_check: also S-1-5-21-976746554-266313863-47890339-100 > se_access_check: also S-1-1-0 > se_access_check: also S-1-5-2 > se_access_check: also S-1-5-11 > [2006/07/12 14:51:22, 3] rpc_server/srv_pipe_hnd.c:free_pipe_context(529) > free_pipe_context: destroying talloc pool of size 196 > [2006/07/12 14:51:22, 3] smbd/process.c:process_smb(1110) > Transaction 429458 of length 152 > [2006/07/12 14:51:22, 3] smbd/process.c:switch_message(914) > switch message SMBtrans (pid 31842) conn 0x84b3a98 > [2006/07/12 14:51:22, 3] smbd/ipc.c:handle_trans(373) > trans <\PIPE\> data=64 params=0 setup=2 > [2006/07/12 14:51:22, 3] smbd/ipc.c:named_pipe(340) > named pipe command on <> name > [2006/07/12 14:51:22, 3] smbd/ipc.c:api_fd_reply(300) > Got API command 0x26 on pipe "spoolss" (pnum 71da) > [2006/07/12 14:51:22, 3] rpc_server/srv_pipe_hnd.c:free_pipe_context(529) > free_pipe_context: destroying talloc pool of size 0 > [2006/07/12 14:51:22, 3] rpc_server/srv_pipe.c:api_rpcTNP(2265) > api_rpcTNP: rpc command: SPOOLSS_ENUMJOBS > [2006/07/12 14:51:22, 3] rpc_server/srv_pipe_hnd.c:free_pipe_context(529) > free_pipe_context: destroying talloc pool of size 0 > [2006/07/12 14:51:22, 3] smbd/process.c:process_smb(1110) > Transaction 429459 of length 132 > [2006/07/12 14:51:22, 3] smbd/process.c:switch_message(914) > switch message SMBtrans (pid 31842) conn 0x84b3a98 > [2006/07/12 14:51:22, 3] smbd/ipc.c:handle_trans(373) > trans <\PIPE\> data=44 params=0 setup=2 > [2006/07/12 14:51:22, 3] smbd/ipc.c:named_pipe(340) > named pipe command on <> name > [2006/07/12 14:51:22, 3] smbd/ipc.c:api_fd_reply(300) > Got API command 0x26 on pipe "spoolss" (pnum 71da) > [2006/07/12 14:51:22, 3] rpc_server/srv_pipe_hnd.c:free_pipe_context(529) > free_pipe_context: destroying talloc pool of size 0 > [2006/07/12 14:51:22, 3] rpc_server/srv_pipe.c:api_rpcTNP(2265) > api_rpcTNP: rpc command: SPOOLSS_CLOSEPRINTER > [2006/07/12 14:51:22, 3] rpc_server/srv_lsa_hnd.c:close_policy_hnd(200) > Closed policy > [2006/07/12 14:51:22, 3] rpc_server/srv_pipe_hnd.c:free_pipe_context(529) > free_pipe_context: destroying talloc pool of size 0 >-- ___________________________________________________________________________________________________ Atenciosamente, Daniel Felipe Martin GetNet - Tecnologia em Captura e Processamento de Transa??es Infra-estrutura Fone: +55 (51) 3598-9800 Fax: +55 (51) 3598-9801 Ramal 2301 __________________________________________________________________________________________________
Martin Zielinski
2006-Jul-13 06:57 UTC
[Samba] continuous access to printer causes high memory usage
Hello, although this should not occur on W2k client machines, please take a look at the "Windows XP SP2 slow printing solution" thread. http://lists.samba.org/archive/samba/2004-November/096146.html and http://lists.samba.org/archive/samba/2004-November/096492.html The symptoms are the same as you described. 2nd make shure, that you are not using some older (!) Kyo KX drivers. ~ Martin Roel van Meer wrote:> Hi list, > > I am trying to track down a printer-related problem. > > The most important symptom is a smbd process using almost all memory on > my machine (up to 800 MB, at the specific case of which I've posted the > logs.) At some point the VM will kill the smbd process, freeing the > memory. Apart from this, samba keeps on running fine. > > Investigation of a level 3 debug log of this process has shown that the > client (a Windows XP machine) is accessing one of the samba printers > almost continuously, with four rpc calls: SPOOLSS_OPENPRINTEREX, > SPOOLSS_GETPRINTERDATA, SPOOLSS_CLOSEPRINTER and SPOOLSS_ENUMJOBS. > The printer driver is installed on the samba server. The client is > configured to use the printer via a Samba port. When the printer is > removed from the client, the rapid calls stop. When the printer is > installed again, the calls again occur in rapid succession. > > Attached you'll find an excerpt of the output of 'ps', my smb.conf and a > piece of the log file. > I've seen this problem at a few different machines, with samba versions > 3.0.20, 3.0.22 and 3.0.23 and different clients (all Windows 2000 or > XP). All machines are running Slackware 10.1. The only solution I have > found so far is removing the printers from the client. > > I have been wondering if this problem can be caused by an absent or invalid > deviced mode for this printer. > > Does anyone have a clue about what might cause this? Or a hint about > where to look further? I'm more than willing to provide more detailed > information. > > Thanks in advance, > > roel >-- Martin Zielinski mz@seh.de Software Development SEH Computertechnik GmbH www.seh.de