Bug 448417 - Browsing samba causes Windows XP to hang
Summary: Browsing samba causes Windows XP to hang
Keywords:
Status: CLOSED WONTFIX
Alias: None
Product: Fedora
Classification: Fedora
Component: samba
Version: 9
Hardware: i686
OS: Linux
low
medium
Target Milestone: ---
Assignee: Simo Sorce
QA Contact: Fedora Extras Quality Assurance
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2008-05-26 17:02 UTC by Russell Davies
Modified: 2009-07-14 16:31 UTC (History)
1 user (show)

Fixed In Version:
Doc Type: Bug Fix
Doc Text:
Clone Of:
Environment:
Last Closed: 2009-07-14 16:31:31 UTC
Type: ---
Embargoed:


Attachments (Terms of Use)
log.smbd for "log level 10" (48.98 KB, application/octet-stream)
2008-06-25 14:53 UTC, Russell Davies
no flags Details
new Log level 10, using packages current with update mirrors (46.06 KB, application/octet-stream)
2008-06-26 13:39 UTC, Russell Davies
no flags Details

Description Russell Davies 2008-05-26 17:02:46 UTC
From Bugzilla Helper:
User-Agent: Mozilla/5.0 (Windows; U; Windows NT 5.1; en-US; rv:1.8.1.14) Gecko/20080404 Firefox/2.0.0.14

Description of problem:
Attempting to browse a Fedora 9 samba server, (even one configured with a default smb.conf file), from Windows XP causes explorer to hang.  Stopping the samba server (/sbin/service smb stop) immediately causes the XP client to come back to life.  





Version-Release number of selected component (if applicable):
samba-3.2.0-1.pre3.9.fc9.i386

How reproducible:
Always


Steps to Reproduce:
1. Install samba on Fedora 9, with home dirs shared as per default;
2. start smb & stop iptables (for expediency, otherwise configure the samba ports.)
3. From Windows XP, use explorer to open either "\\<server name>" or "\\<server ip>"

Actual Results:
Explorer hangs, until explicitly killed *OR* until the smb service is stopped.     



Expected Results:
Explorer displays shares available on the target server. 

Additional info:

I feel a little conflicted in reporting this issue here, because I know I'll likely get flamed with the usual anti-Microsoft rhetoric.   So, please, let's take it as accepted that we all prefer Linux, even if some of us have to support a Windows environment.  Ultimately, here's the rub: doing the exact same thing (i.e, same smb.conf, same hard disk, and browsing from the same XP machine) works perfectly when using another Fedora installation as the server.  The obvious delta as far as I can see is that the sever that works is Fedora 8, whereas the server that doesn't work is Fedora 9.  Ergo, something changed/broke between Fedora 8 and 9. 

Having said all that, I will note that I can browse the samba server from both Fedora 8 and Fedora 9 clients.

The problem has only started following an upgrade to Fedora 9.  The problem exists on all Fedora 9 servers that I have (3 machines).  The problem does not happen on any of the Fedora 8 servers that I have (2 machines). 

Here's a couple of notes that might just be chaff: 1) When I first saw this problem, I thought that I saw a "gethostbyname" error in the log file, but I've been unable to repeat that.  It *might* therefore be relevant to point out that I'm using dns (and *not* wins) for name resolution.  2) I have also seen a "broken pipe" error associated with ipc.c, although again I can't seem to repeat that. 

Below is the level 3 log file output for a session with my windows machine, where I tried to browse the freshly started smb server.   

I'm putting this as a medium severity, because being able to browse a samba server from a Windows machine is probably an important feature for many corporate users, such as myself. 

>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
[2008/05/26 12:44:01,  3] auth/auth.c:check_ntlm_password(220)
  check_ntlm_password:  Checking password for unmapped user [HOMER]\[russell]@[BLINKY] with the new password interface
[2008/05/26 12:44:01,  3] auth/auth.c:check_ntlm_password(223)
  check_ntlm_password:  mapped user is: [HOMER]\[russell]@[BLINKY]
[2008/05/26 12:44:01,  3] smbd/sec_ctx.c:push_sec_ctx(224)
  push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1
[2008/05/26 12:44:01,  3] smbd/uid.c:push_conn_ctx(357)
  push_conn_ctx(0) : conn_ctx_stack_ndx = 0
[2008/05/26 12:44:01,  3] smbd/sec_ctx.c:set_sec_ctx(324)
  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1
[2008/05/26 12:44:01,  3] smbd/sec_ctx.c:push_sec_ctx(224)
  push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 2
[2008/05/26 12:44:01,  3] smbd/uid.c:push_conn_ctx(357)
  push_conn_ctx(0) : conn_ctx_stack_ndx = 1
[2008/05/26 12:44:01,  3] smbd/sec_ctx.c:set_sec_ctx(324)
  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 2
[2008/05/26 12:44:01,  3] smbd/sec_ctx.c:pop_sec_ctx(432)
  pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 1
[2008/05/26 12:44:01,  3] smbd/sec_ctx.c:push_sec_ctx(224)
  push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 2
[2008/05/26 12:44:01,  3] smbd/uid.c:push_conn_ctx(357)
  push_conn_ctx(0) : conn_ctx_stack_ndx = 1
[2008/05/26 12:44:01,  3] smbd/sec_ctx.c:set_sec_ctx(324)
  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 2
[2008/05/26 12:44:01,  3] smbd/sec_ctx.c:pop_sec_ctx(432)
  pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 1
[2008/05/26 12:44:01,  3] smbd/sec_ctx.c:push_sec_ctx(224)
  push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 2
[2008/05/26 12:44:01,  3] smbd/uid.c:push_conn_ctx(357)
  push_conn_ctx(0) : conn_ctx_stack_ndx = 1
[2008/05/26 12:44:01,  3] smbd/sec_ctx.c:set_sec_ctx(324)
  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 2
[2008/05/26 12:44:01,  3] smbd/sec_ctx.c:pop_sec_ctx(432)
  pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 1
[2008/05/26 12:44:01,  3] smbd/sec_ctx.c:push_sec_ctx(224)
  push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 2
[2008/05/26 12:44:01,  3] smbd/uid.c:push_conn_ctx(357)
  push_conn_ctx(0) : conn_ctx_stack_ndx = 1
[2008/05/26 12:44:01,  3] smbd/sec_ctx.c:set_sec_ctx(324)
  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 2
[2008/05/26 12:44:01,  3] smbd/sec_ctx.c:pop_sec_ctx(432)
  pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 1
[2008/05/26 12:44:01,  3] smbd/sec_ctx.c:pop_sec_ctx(432)
  pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0
[2008/05/26 12:44:01,  3] smbd/sec_ctx.c:push_sec_ctx(224)
  push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1
[2008/05/26 12:44:01,  3] smbd/uid.c:push_conn_ctx(357)
  push_conn_ctx(0) : conn_ctx_stack_ndx = 0
[2008/05/26 12:44:01,  3] smbd/sec_ctx.c:set_sec_ctx(324)
  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1
[2008/05/26 12:44:01,  3] smbd/sec_ctx.c:pop_sec_ctx(432)
  pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0
[2008/05/26 12:44:01,  3] smbd/sec_ctx.c:push_sec_ctx(224)
  push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1
[2008/05/26 12:44:01,  3] smbd/uid.c:push_conn_ctx(357)
  push_conn_ctx(0) : conn_ctx_stack_ndx = 0
[2008/05/26 12:44:01,  3] smbd/sec_ctx.c:set_sec_ctx(324)
  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1
[2008/05/26 12:44:01,  3] smbd/sec_ctx.c:push_sec_ctx(224)
  push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 2
[2008/05/26 12:44:01,  3] smbd/uid.c:push_conn_ctx(357)
  push_conn_ctx(0) : conn_ctx_stack_ndx = 1
[2008/05/26 12:44:01,  3] smbd/sec_ctx.c:set_sec_ctx(324)
  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 2
[2008/05/26 12:44:01,  3] smbd/sec_ctx.c:pop_sec_ctx(432)
  pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 1
[2008/05/26 12:44:01,  3] smbd/sec_ctx.c:push_sec_ctx(224)
  push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 2
[2008/05/26 12:44:01,  3] smbd/uid.c:push_conn_ctx(357)
  push_conn_ctx(0) : conn_ctx_stack_ndx = 1
[2008/05/26 12:44:01,  3] smbd/sec_ctx.c:set_sec_ctx(324)
  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 2
[2008/05/26 12:44:01,  3] smbd/sec_ctx.c:pop_sec_ctx(432)
  pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 1
[2008/05/26 12:44:01,  3] smbd/sec_ctx.c:push_sec_ctx(224)
  push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 2
[2008/05/26 12:44:01,  3] smbd/uid.c:push_conn_ctx(357)
  push_conn_ctx(0) : conn_ctx_stack_ndx = 1
[2008/05/26 12:44:01,  3] smbd/sec_ctx.c:set_sec_ctx(324)
  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 2
[2008/05/26 12:44:01,  3] smbd/sec_ctx.c:pop_sec_ctx(432)
  pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 1
[2008/05/26 12:44:01,  3] smbd/sec_ctx.c:push_sec_ctx(224)
  push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 2
[2008/05/26 12:44:01,  3] smbd/uid.c:push_conn_ctx(357)
  push_conn_ctx(0) : conn_ctx_stack_ndx = 1
[2008/05/26 12:44:01,  3] smbd/sec_ctx.c:set_sec_ctx(324)
  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 2
[2008/05/26 12:44:01,  3] smbd/sec_ctx.c:pop_sec_ctx(432)
  pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 1
[2008/05/26 12:44:01,  3] smbd/sec_ctx.c:push_sec_ctx(224)
  push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 2
[2008/05/26 12:44:01,  3] smbd/uid.c:push_conn_ctx(357)
  push_conn_ctx(0) : conn_ctx_stack_ndx = 1
[2008/05/26 12:44:01,  3] smbd/sec_ctx.c:set_sec_ctx(324)
  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 2
[2008/05/26 12:44:01,  3] smbd/sec_ctx.c:pop_sec_ctx(432)
  pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 1
[2008/05/26 12:44:01,  3] smbd/sec_ctx.c:push_sec_ctx(224)
  push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 2
[2008/05/26 12:44:01,  3] smbd/uid.c:push_conn_ctx(357)
  push_conn_ctx(0) : conn_ctx_stack_ndx = 1
[2008/05/26 12:44:01,  3] smbd/sec_ctx.c:set_sec_ctx(324)
  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 2
[2008/05/26 12:44:01,  3] smbd/sec_ctx.c:pop_sec_ctx(432)
  pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 1
[2008/05/26 12:44:01,  3] smbd/sec_ctx.c:push_sec_ctx(224)
  push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 2
[2008/05/26 12:44:01,  3] smbd/uid.c:push_conn_ctx(357)
  push_conn_ctx(0) : conn_ctx_stack_ndx = 1
[2008/05/26 12:44:01,  3] smbd/sec_ctx.c:set_sec_ctx(324)
  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 2
[2008/05/26 12:44:01,  3] smbd/sec_ctx.c:pop_sec_ctx(432)
  pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 1
[2008/05/26 12:44:01,  3] smbd/sec_ctx.c:push_sec_ctx(224)
  push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 2
[2008/05/26 12:44:01,  3] smbd/uid.c:push_conn_ctx(357)
  push_conn_ctx(0) : conn_ctx_stack_ndx = 1
[2008/05/26 12:44:01,  3] smbd/sec_ctx.c:set_sec_ctx(324)
  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 2
[2008/05/26 12:44:01,  3] smbd/sec_ctx.c:pop_sec_ctx(432)
  pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 1
[2008/05/26 12:44:01,  3] smbd/sec_ctx.c:push_sec_ctx(224)
  push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 2
[2008/05/26 12:44:01,  3] smbd/uid.c:push_conn_ctx(357)
  push_conn_ctx(0) : conn_ctx_stack_ndx = 1
[2008/05/26 12:44:01,  3] smbd/sec_ctx.c:set_sec_ctx(324)
  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 2
[2008/05/26 12:44:01,  3] smbd/sec_ctx.c:pop_sec_ctx(432)
  pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 1
[2008/05/26 12:44:01,  3] smbd/sec_ctx.c:push_sec_ctx(224)
  push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 2
[2008/05/26 12:44:01,  3] smbd/uid.c:push_conn_ctx(357)
  push_conn_ctx(0) : conn_ctx_stack_ndx = 1
[2008/05/26 12:44:01,  3] smbd/sec_ctx.c:set_sec_ctx(324)
  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 2
[2008/05/26 12:44:01,  3] smbd/sec_ctx.c:pop_sec_ctx(432)
  pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 1
[2008/05/26 12:44:01,  3] smbd/sec_ctx.c:push_sec_ctx(224)
  push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 2
[2008/05/26 12:44:01,  3] smbd/uid.c:push_conn_ctx(357)
  push_conn_ctx(0) : conn_ctx_stack_ndx = 1
[2008/05/26 12:44:01,  3] smbd/sec_ctx.c:set_sec_ctx(324)
  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 2
[2008/05/26 12:44:01,  3] smbd/sec_ctx.c:pop_sec_ctx(432)
  pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 1
[2008/05/26 12:44:01,  3] smbd/sec_ctx.c:push_sec_ctx(224)
  push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 2
[2008/05/26 12:44:01,  3] smbd/uid.c:push_conn_ctx(357)
  push_conn_ctx(0) : conn_ctx_stack_ndx = 1
[2008/05/26 12:44:01,  3] smbd/sec_ctx.c:set_sec_ctx(324)
  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 2
[2008/05/26 12:44:01,  3] smbd/sec_ctx.c:pop_sec_ctx(432)
  pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 1
[2008/05/26 12:44:01,  3] smbd/sec_ctx.c:push_sec_ctx(224)
  push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 2
[2008/05/26 12:44:01,  3] smbd/uid.c:push_conn_ctx(357)
  push_conn_ctx(0) : conn_ctx_stack_ndx = 1
[2008/05/26 12:44:01,  3] smbd/sec_ctx.c:set_sec_ctx(324)
  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 2
[2008/05/26 12:44:01,  3] smbd/sec_ctx.c:pop_sec_ctx(432)
  pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 1
[2008/05/26 12:44:01,  3] smbd/sec_ctx.c:push_sec_ctx(224)
  push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 2
[2008/05/26 12:44:01,  3] smbd/uid.c:push_conn_ctx(357)
  push_conn_ctx(0) : conn_ctx_stack_ndx = 1
[2008/05/26 12:44:01,  3] smbd/sec_ctx.c:set_sec_ctx(324)
  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 2
[2008/05/26 12:44:01,  3] smbd/sec_ctx.c:pop_sec_ctx(432)
  pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 1
[2008/05/26 12:44:01,  3] smbd/sec_ctx.c:push_sec_ctx(224)
  push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 2
[2008/05/26 12:44:01,  3] smbd/uid.c:push_conn_ctx(357)
  push_conn_ctx(0) : conn_ctx_stack_ndx = 1
[2008/05/26 12:44:01,  3] smbd/sec_ctx.c:set_sec_ctx(324)
  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 2
[2008/05/26 12:44:01,  3] smbd/sec_ctx.c:pop_sec_ctx(432)
  pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 1
[2008/05/26 12:44:01,  3] smbd/sec_ctx.c:push_sec_ctx(224)
  push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 2
[2008/05/26 12:44:01,  3] smbd/uid.c:push_conn_ctx(357)
  push_conn_ctx(0) : conn_ctx_stack_ndx = 1
[2008/05/26 12:44:01,  3] smbd/sec_ctx.c:set_sec_ctx(324)
  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 2
[2008/05/26 12:44:01,  3] smbd/sec_ctx.c:pop_sec_ctx(432)
  pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 1
[2008/05/26 12:44:01,  3] smbd/sec_ctx.c:pop_sec_ctx(432)
  pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0
[2008/05/26 12:44:01,  3] auth/auth.c:check_ntlm_password(269)
  check_ntlm_password: sam authentication for user [russell] succeeded
[2008/05/26 12:44:01,  3] smbd/sec_ctx.c:push_sec_ctx(224)
  push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1
[2008/05/26 12:44:01,  3] smbd/uid.c:push_conn_ctx(357)
  push_conn_ctx(0) : conn_ctx_stack_ndx = 0
[2008/05/26 12:44:01,  3] smbd/sec_ctx.c:set_sec_ctx(324)
  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1
[2008/05/26 12:44:01,  3] smbd/sec_ctx.c:pop_sec_ctx(432)
  pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0
[2008/05/26 12:44:01,  2] auth/auth.c:check_ntlm_password(308)
  check_ntlm_password:  authentication for user [russell] -> [russell] -> [russell] succeeded
[2008/05/26 12:44:01,  3] smbd/sec_ctx.c:push_sec_ctx(224)
  push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1
[2008/05/26 12:44:01,  3] smbd/uid.c:push_conn_ctx(357)
  push_conn_ctx(0) : conn_ctx_stack_ndx = 0
[2008/05/26 12:44:01,  3] smbd/sec_ctx.c:set_sec_ctx(324)
  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1
[2008/05/26 12:44:01,  3] smbd/sec_ctx.c:pop_sec_ctx(432)
  pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0
[2008/05/26 12:44:01,  3] smbd/sec_ctx.c:push_sec_ctx(224)
  push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1
[2008/05/26 12:44:01,  3] smbd/uid.c:push_conn_ctx(357)
  push_conn_ctx(0) : conn_ctx_stack_ndx = 0
[2008/05/26 12:44:01,  3] smbd/sec_ctx.c:set_sec_ctx(324)
  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1
[2008/05/26 12:44:01,  3] smbd/sec_ctx.c:pop_sec_ctx(432)
  pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0
[2008/05/26 12:44:01,  3] smbd/sec_ctx.c:push_sec_ctx(224)
  push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1
[2008/05/26 12:44:01,  3] smbd/uid.c:push_conn_ctx(357)
  push_conn_ctx(0) : conn_ctx_stack_ndx = 0
[2008/05/26 12:44:01,  3] smbd/sec_ctx.c:set_sec_ctx(324)
  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1
[2008/05/26 12:44:01,  3] smbd/sec_ctx.c:pop_sec_ctx(432)
  pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0
[2008/05/26 12:44:01,  3] lib/privileges.c:get_privileges(63)
  get_privileges: No privileges assigned to SID [S-1-5-21-2185502541-14410569-2829850117-3000]
[2008/05/26 12:44:01,  3] lib/privileges.c:get_privileges(63)
  get_privileges: No privileges assigned to SID [S-1-22-2-1000]
[2008/05/26 12:44:01,  3] lib/privileges.c:get_privileges(63)
  get_privileges: No privileges assigned to SID [S-1-5-2]
[2008/05/26 12:44:01,  3] lib/privileges.c:get_privileges(63)
  get_privileges: No privileges assigned to SID [S-1-5-11]
[2008/05/26 12:44:01,  3] lib/privileges.c:get_privileges(63)
  get_privileges: No privileges assigned to SID [S-1-22-2-100]
[2008/05/26 12:44:01,  3] lib/privileges.c:get_privileges(63)
  get_privileges: No privileges assigned to SID [S-1-22-2-500]
[2008/05/26 12:44:01,  3] lib/privileges.c:get_privileges(63)
  get_privileges: No privileges assigned to SID [S-1-22-2-1500]
[2008/05/26 12:44:01,  3] lib/privileges.c:get_privileges(63)
  get_privileges: No privileges assigned to SID [S-1-22-2-1501]
[2008/05/26 12:44:01,  3] lib/privileges.c:get_privileges(63)
  get_privileges: No privileges assigned to SID [S-1-22-2-1502]
[2008/05/26 12:44:01,  3] lib/privileges.c:get_privileges(63)
  get_privileges: No privileges assigned to SID [S-1-22-2-1503]
[2008/05/26 12:44:01,  3] lib/privileges.c:get_privileges(63)
  get_privileges: No privileges assigned to SID [S-1-22-2-1504]
[2008/05/26 12:44:01,  3] lib/privileges.c:get_privileges(63)
  get_privileges: No privileges assigned to SID [S-1-22-2-1505]
[2008/05/26 12:44:01,  3] lib/privileges.c:get_privileges(63)
  get_privileges: No privileges assigned to SID [S-1-22-2-1506]
[2008/05/26 12:44:01,  3] lib/privileges.c:get_privileges(63)
  get_privileges: No privileges assigned to SID [S-1-22-2-1507]
[2008/05/26 12:44:01,  3] lib/privileges.c:get_privileges(63)
  get_privileges: No privileges assigned to SID [S-1-22-2-1508]
[2008/05/26 12:44:01,  3] lib/privileges.c:get_privileges(63)
  get_privileges: No privileges assigned to SID [S-1-22-2-1509]
[2008/05/26 12:44:01,  3] lib/privileges.c:get_privileges(63)
  get_privileges: No privileges assigned to SID [S-1-22-2-1600]
[2008/05/26 12:44:01,  3] lib/privileges.c:get_privileges(63)
  get_privileges: No privileges assigned to SID [S-1-22-2-1700]
[2008/05/26 12:44:01,  3] lib/privileges.c:get_privileges(63)
  get_privileges: No privileges assigned to SID [S-1-22-2-1701]
[2008/05/26 12:44:01,  3] smbd/sec_ctx.c:push_sec_ctx(224)
  push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1
[2008/05/26 12:44:01,  3] smbd/uid.c:push_conn_ctx(357)
  push_conn_ctx(0) : conn_ctx_stack_ndx = 0
[2008/05/26 12:44:01,  3] smbd/sec_ctx.c:set_sec_ctx(324)
  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1
[2008/05/26 12:44:01,  3] smbd/sec_ctx.c:pop_sec_ctx(432)
  pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0
[2008/05/26 12:44:01,  3] smbd/sec_ctx.c:push_sec_ctx(224)
  push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1
[2008/05/26 12:44:01,  3] smbd/uid.c:push_conn_ctx(357)
  push_conn_ctx(0) : conn_ctx_stack_ndx = 0
[2008/05/26 12:44:01,  3] smbd/sec_ctx.c:set_sec_ctx(324)
  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1
[2008/05/26 12:44:01,  3] smbd/sec_ctx.c:pop_sec_ctx(432)
  pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0
[2008/05/26 12:44:01,  3] smbd/sec_ctx.c:push_sec_ctx(224)
  push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1
[2008/05/26 12:44:01,  3] smbd/uid.c:push_conn_ctx(357)
  push_conn_ctx(0) : conn_ctx_stack_ndx = 0
[2008/05/26 12:44:01,  3] smbd/sec_ctx.c:set_sec_ctx(324)
  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1
[2008/05/26 12:44:01,  3] smbd/sec_ctx.c:pop_sec_ctx(432)
  pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0
[2008/05/26 12:44:01,  3] libsmb/ntlmssp_sign.c:ntlmssp_sign_init(337)
  NTLMSSP Sign/Seal - Initialising with flags:
[2008/05/26 12:44:01,  3] libsmb/ntlmssp.c:debug_ntlmssp_flags(62)
  Got NTLMSSP neg_flags=0xe2088215
[2008/05/26 12:44:01,  3] smbd/password.c:register_existing_vuid(314)
  register_existing_vuid: User name: russell	Real name: Russell Davies
[2008/05/26 12:44:01,  3] smbd/password.c:register_existing_vuid(326)
  register_existing_vuid: UNIX uid 1000 is UNIX user russell, and will be vuid 100
[2008/05/26 12:44:01,  3] smbd/password.c:register_existing_vuid(350)
  Adding homes service for user 'russell' using home directory: '/home/russell'
[2008/05/26 12:44:01,  3] param/loadparm.c:lp_add_home(5846)
  adding home's share [russell] for user 'russell' at '/home/russell'
[2008/05/26 12:44:01,  3] smbd/process.c:process_smb(1554)
  Transaction 3 of length 80 (0 toread)
[2008/05/26 12:44:01,  3] smbd/process.c:switch_message(1366)
  switch message SMBtconX (pid 9305) conn 0x0
[2008/05/26 12:44:01,  3] smbd/sec_ctx.c:set_sec_ctx(324)
  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0
[2008/05/26 12:44:01,  3] smbd/service.c:make_connection_snum(936)
  Connect path is '/tmp' for service [IPC$]
[2008/05/26 12:44:01,  3] lib/util_seaccess.c:se_access_check(249)
[2008/05/26 12:44:01,  3] lib/util_seaccess.c:se_access_check(252)
  se_access_check: user sid is S-1-5-21-2185502541-14410569-2829850117-3000
  se_access_check: also S-1-22-2-1000
  se_access_check: also S-1-1-0
  se_access_check: also S-1-5-2
  se_access_check: also S-1-5-11
  se_access_check: also S-1-22-2-100
  se_access_check: also S-1-22-2-500
  se_access_check: also S-1-22-2-1500
  se_access_check: also S-1-22-2-1501
  se_access_check: also S-1-22-2-1502
  se_access_check: also S-1-22-2-1503
  se_access_check: also S-1-22-2-1504
  se_access_check: also S-1-22-2-1505
  se_access_check: also S-1-22-2-1506
  se_access_check: also S-1-22-2-1507
  se_access_check: also S-1-22-2-1508
  se_access_check: also S-1-22-2-1509
  se_access_check: also S-1-22-2-1600
  se_access_check: also S-1-22-2-1700
  se_access_check: also S-1-22-2-1701
[2008/05/26 12:44:01,  3] smbd/vfs.c:vfs_init_default(96)
  Initialising default vfs hooks
[2008/05/26 12:44:01,  3] smbd/vfs.c:vfs_init_custom(130)
  Initialising custom vfs hooks from [/[Default VFS]/]
[2008/05/26 12:44:01,  3] lib/util_seaccess.c:se_access_check(249)
[2008/05/26 12:44:01,  3] lib/util_seaccess.c:se_access_check(252)
  se_access_check: user sid is S-1-5-21-2185502541-14410569-2829850117-3000
  se_access_check: also S-1-22-2-1000
  se_access_check: also S-1-1-0
  se_access_check: also S-1-5-2
  se_access_check: also S-1-5-11
  se_access_check: also S-1-22-2-100
  se_access_check: also S-1-22-2-500
  se_access_check: also S-1-22-2-1500
  se_access_check: also S-1-22-2-1501
  se_access_check: also S-1-22-2-1502
  se_access_check: also S-1-22-2-1503
  se_access_check: also S-1-22-2-1504
  se_access_check: also S-1-22-2-1505
  se_access_check: also S-1-22-2-1506
  se_access_check: also S-1-22-2-1507
  se_access_check: also S-1-22-2-1508
  se_access_check: also S-1-22-2-1509
  se_access_check: also S-1-22-2-1600
  se_access_check: also S-1-22-2-1700
  se_access_check: also S-1-22-2-1701
[2008/05/26 12:44:01,  3] smbd/sec_ctx.c:set_sec_ctx(324)
  setting sec ctx (1000, 1000) - sec_ctx_stack_ndx = 0
[2008/05/26 12:44:01,  3] smbd/service.c:make_connection_snum(1188)
  blinky (::ffff:10.9.0.21) connect to service IPC$ initially as user russell (uid=1000, gid=1000) (pid 9305)
[2008/05/26 12:44:01,  3] smbd/sec_ctx.c:set_sec_ctx(324)
  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0
[2008/05/26 12:44:01,  3] smbd/reply.c:reply_tcon_and_X(727)
  tconX service=IPC$ 
[2008/05/26 12:44:01,  3] smbd/process.c:process_smb(1554)
  Transaction 4 of length 104 (0 toread)
[2008/05/26 12:44:01,  3] smbd/process.c:switch_message(1366)
  switch message SMBntcreateX (pid 9305) conn 0xb9643618
[2008/05/26 12:44:01,  3] smbd/sec_ctx.c:set_sec_ctx(324)
  setting sec ctx (1000, 1000) - sec_ctx_stack_ndx = 0
[2008/05/26 12:44:01,  3] smbd/nttrans.c:nt_open_pipe(322)
  nt_open_pipe: Known pipe srvsvc opening.
[2008/05/26 12:44:01,  3] smbd/process.c:process_smb(1554)
  Transaction 5 of length 140 (0 toread)
[2008/05/26 12:44:01,  3] smbd/process.c:switch_message(1366)
  switch message SMBwriteX (pid 9305) conn 0xb9643618
[2008/05/26 12:44:01,  3] rpc_server/srv_pipe.c:api_pipe_bind_req(1564)
  api_pipe_bind_req: \PIPE\srvsvc -> \PIPE\srvsvc
[2008/05/26 12:44:01,  3] rpc_server/srv_pipe.c:check_bind_req(991)
  check_bind_req for \PIPE\srvsvc
[2008/05/26 12:44:01,  3] smbd/pipes.c:reply_pipe_write_and_X(251)
  writeX-IPC pnum=7488 nwritten=72
[2008/05/26 12:44:01,  3] smbd/process.c:process_smb(1554)
  Transaction 6 of length 63 (0 toread)
[2008/05/26 12:44:01,  3] smbd/process.c:switch_message(1366)
  switch message SMBreadX (pid 9305) conn 0xb9643618
[2008/05/26 12:44:01,  3] smbd/pipes.c:reply_pipe_read_and_X(301)
  readX-IPC pnum=7488 min=1024 max=1024 nread=68
[2008/05/26 12:44:01,  3] smbd/process.c:process_smb(1554)
  Transaction 7 of length 172 (0 toread)
[2008/05/26 12:44:01,  3] smbd/process.c:switch_message(1366)
  switch message SMBtrans (pid 9305) conn 0xb9643618
[2008/05/26 12:44:01,  3] smbd/ipc.c:handle_trans(436)
  trans <\PIPE\> data=84 params=0 setup=2
[2008/05/26 12:44:01,  3] smbd/ipc.c:named_pipe(387)
  named pipe command on <> name
[2008/05/26 12:44:01,  3] smbd/ipc.c:api_fd_reply(345)
  Got API command 0x26 on pipe "srvsvc" (pnum 7488)
[2008/05/26 12:44:01,  3] rpc_server/srv_pipe_hnd.c:free_pipe_context(519)
  free_pipe_context: destroying talloc pool of size 71
[2008/05/26 12:44:01,  3] rpc_server/srv_pipe.c:api_rpcTNP(2304)
  api_rpcTNP: rpc command: SRVSVC_NETSHAREENUMALL
[2008/05/26 12:44:01,  3] smbd/sec_ctx.c:push_sec_ctx(224)
  push_sec_ctx(1000, 1000) : sec_ctx_stack_ndx = 1
[2008/05/26 12:44:01,  3] smbd/uid.c:push_conn_ctx(357)
  push_conn_ctx(100) : conn_ctx_stack_ndx = 0
[2008/05/26 12:44:01,  3] smbd/sec_ctx.c:set_sec_ctx(324)
  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1
[2008/05/26 12:44:01,  3] smbd/sec_ctx.c:pop_sec_ctx(432)
  pop_sec_ctx (1000, 1000) - sec_ctx_stack_ndx = 0
[2008/05/26 12:44:01,  3] rpc_server/srv_pipe_hnd.c:free_pipe_context(519)
  free_pipe_context: destroying talloc pool of size 290
[2008/05/26 12:44:01,  3] smbd/process.c:process_smb(1554)
  Transaction 8 of length 45 (0 toread)
[2008/05/26 12:44:01,  3] smbd/process.c:switch_message(1366)
  switch message SMBclose (pid 9305) conn 0xb9643618
[2008/05/26 12:44:01,  3] smbd/process.c:process_smb(1554)
  Transaction 9 of length 274 (0 toread)
[2008/05/26 12:44:01,  3] smbd/process.c:switch_message(1366)
  switch message SMBtrans (pid 9305) conn 0xb9643618
[2008/05/26 12:44:01,  3] smbd/ipc.c:handle_trans(436)
  trans <\PIPE\> data=186 params=0 setup=2
[2008/05/26 12:44:01,  3] smbd/ipc.c:named_pipe(387)
  named pipe command on <> name
[2008/05/26 12:44:01,  1] smbd/ipc.c:api_fd_reply(333)
  api_fd_reply: INVALID PIPE HANDLE: 7454
[2008/05/26 12:44:01,  3] smbd/error.c:error_packet_set(61)
  error packet at smbd/ipc.c(334) cmd=37 (SMBtrans) NT_STATUS_INVALID_HANDLE
[2008/05/26 12:44:01,  3] smbd/process.c:process_smb(1554)
  Transaction 10 of length 104 (0 toread)
[2008/05/26 12:44:01,  3] smbd/process.c:switch_message(1366)
  switch message SMBntcreateX (pid 9305) conn 0xb9643618
[2008/05/26 12:44:01,  3] smbd/nttrans.c:nt_open_pipe(322)
  nt_open_pipe: Known pipe wkssvc opening.
[2008/05/26 12:44:01,  3] smbd/process.c:process_smb(1554)
  Transaction 11 of length 140 (0 toread)
[2008/05/26 12:44:01,  3] smbd/process.c:switch_message(1366)
  switch message SMBwriteX (pid 9305) conn 0xb9643618
[2008/05/26 12:44:01,  3] rpc_server/srv_pipe.c:api_pipe_bind_req(1564)
  api_pipe_bind_req: \PIPE\wkssvc -> \PIPE\wkssvc
[2008/05/26 12:44:01,  3] rpc_server/srv_pipe.c:check_bind_req(991)
  check_bind_req for \PIPE\wkssvc
[2008/05/26 12:44:01,  3] smbd/pipes.c:reply_pipe_write_and_X(251)
  writeX-IPC pnum=7489 nwritten=72
[2008/05/26 12:44:01,  3] smbd/process.c:process_smb(1554)
  Transaction 12 of length 63 (0 toread)
[2008/05/26 12:44:01,  3] smbd/process.c:switch_message(1366)
  switch message SMBreadX (pid 9305) conn 0xb9643618
[2008/05/26 12:44:01,  3] smbd/pipes.c:reply_pipe_read_and_X(301)
  readX-IPC pnum=7489 min=1024 max=1024 nread=68
[2008/05/26 12:44:01,  3] smbd/process.c:process_smb(1554)
  Transaction 13 of length 148 (0 toread)
[2008/05/26 12:44:01,  3] smbd/process.c:switch_message(1366)
  switch message SMBtrans (pid 9305) conn 0xb9643618
[2008/05/26 12:44:01,  3] smbd/ipc.c:handle_trans(436)
  trans <\PIPE\> data=60 params=0 setup=2
[2008/05/26 12:44:01,  3] smbd/ipc.c:named_pipe(387)
  named pipe command on <> name
[2008/05/26 12:44:01,  3] smbd/ipc.c:api_fd_reply(345)
  Got API command 0x26 on pipe "wkssvc" (pnum 7489)
[2008/05/26 12:44:01,  3] rpc_server/srv_pipe_hnd.c:free_pipe_context(519)
  free_pipe_context: destroying talloc pool of size 71
[2008/05/26 12:44:01,  3] rpc_server/srv_pipe.c:api_rpcTNP(2304)
  api_rpcTNP: rpc command: WKSSVC_NETWKSTAGETINFO
[2008/05/26 12:44:01,  3] rpc_server/srv_pipe_hnd.c:free_pipe_context(519)
  free_pipe_context: destroying talloc pool of size 38
[2008/05/26 12:44:01,  3] smbd/process.c:process_smb(1554)
  Transaction 14 of length 45 (0 toread)
[2008/05/26 12:44:01,  3] smbd/process.c:switch_message(1366)
  switch message SMBclose (pid 9305) conn 0xb9643618
[2008/05/26 12:44:01,  3] smbd/process.c:process_smb(1554)
  Transaction 15 of length 104 (0 toread)
[2008/05/26 12:44:01,  3] smbd/process.c:switch_message(1366)
  switch message SMBntcreateX (pid 9305) conn 0xb9643618
[2008/05/26 12:44:01,  3] smbd/nttrans.c:nt_open_pipe(322)
  nt_open_pipe: Known pipe srvsvc opening.
[2008/05/26 12:44:01,  3] smbd/process.c:process_smb(1554)
  Transaction 16 of length 140 (0 toread)
[2008/05/26 12:44:01,  3] smbd/process.c:switch_message(1366)
  switch message SMBwriteX (pid 9305) conn 0xb9643618
[2008/05/26 12:44:01,  3] rpc_server/srv_pipe.c:api_pipe_bind_req(1564)
  api_pipe_bind_req: \PIPE\srvsvc -> \PIPE\srvsvc
[2008/05/26 12:44:01,  3] rpc_server/srv_pipe.c:check_bind_req(991)
  check_bind_req for \PIPE\srvsvc
[2008/05/26 12:44:01,  3] smbd/pipes.c:reply_pipe_write_and_X(251)
  writeX-IPC pnum=748a nwritten=72
[2008/05/26 12:44:01,  3] smbd/process.c:process_smb(1554)
  Transaction 17 of length 63 (0 toread)
[2008/05/26 12:44:01,  3] smbd/process.c:switch_message(1366)
  switch message SMBreadX (pid 9305) conn 0xb9643618
[2008/05/26 12:44:01,  3] smbd/pipes.c:reply_pipe_read_and_X(301)
  readX-IPC pnum=748a min=1024 max=1024 nread=68
[2008/05/26 12:44:01,  3] smbd/process.c:process_smb(1554)
  Transaction 18 of length 148 (0 toread)
[2008/05/26 12:44:01,  3] smbd/process.c:switch_message(1366)
  switch message SMBtrans (pid 9305) conn 0xb9643618
[2008/05/26 12:44:01,  3] smbd/ipc.c:handle_trans(436)
  trans <\PIPE\> data=60 params=0 setup=2
[2008/05/26 12:44:01,  3] smbd/ipc.c:named_pipe(387)
  named pipe command on <> name
[2008/05/26 12:44:01,  3] smbd/ipc.c:api_fd_reply(345)
  Got API command 0x26 on pipe "srvsvc" (pnum 748a)
[2008/05/26 12:44:01,  3] rpc_server/srv_pipe_hnd.c:free_pipe_context(519)
  free_pipe_context: destroying talloc pool of size 71
[2008/05/26 12:44:01,  3] rpc_server/srv_pipe.c:api_rpcTNP(2304)
  api_rpcTNP: rpc command: SRVSVC_NETSRVGETINFO
[2008/05/26 12:44:01,  3] rpc_server/srv_pipe_hnd.c:free_pipe_context(519)
  free_pipe_context: destroying talloc pool of size 24
[2008/05/26 12:44:01,  3] smbd/process.c:process_smb(1554)
  Transaction 19 of length 45 (0 toread)
[2008/05/26 12:44:01,  3] smbd/process.c:switch_message(1366)
  switch message SMBclose (pid 9305) conn 0xb9643618
[2008/05/26 12:44:01,  3] smbd/process.c:process_smb(1554)
  Transaction 20 of length 104 (0 toread)
[2008/05/26 12:44:01,  3] smbd/process.c:switch_message(1366)
  switch message SMBntcreateX (pid 9305) conn 0xb9643618
[2008/05/26 12:44:01,  3] smbd/nttrans.c:nt_open_pipe(322)
  nt_open_pipe: Known pipe wkssvc opening.
[2008/05/26 12:44:01,  3] smbd/process.c:process_smb(1554)
  Transaction 21 of length 140 (0 toread)
[2008/05/26 12:44:01,  3] smbd/process.c:switch_message(1366)
  switch message SMBwriteX (pid 9305) conn 0xb9643618
[2008/05/26 12:44:01,  3] rpc_server/srv_pipe.c:api_pipe_bind_req(1564)
  api_pipe_bind_req: \PIPE\wkssvc -> \PIPE\wkssvc
[2008/05/26 12:44:01,  3] rpc_server/srv_pipe.c:check_bind_req(991)
  check_bind_req for \PIPE\wkssvc
[2008/05/26 12:44:01,  3] smbd/pipes.c:reply_pipe_write_and_X(251)
  writeX-IPC pnum=748b nwritten=72
[2008/05/26 12:44:01,  3] smbd/process.c:process_smb(1554)
  Transaction 22 of length 63 (0 toread)
[2008/05/26 12:44:01,  3] smbd/process.c:switch_message(1366)
  switch message SMBreadX (pid 9305) conn 0xb9643618
[2008/05/26 12:44:01,  3] smbd/pipes.c:reply_pipe_read_and_X(301)
  readX-IPC pnum=748b min=1024 max=1024 nread=68
[2008/05/26 12:44:01,  3] smbd/process.c:process_smb(1554)
  Transaction 23 of length 148 (0 toread)
[2008/05/26 12:44:01,  3] smbd/process.c:switch_message(1366)
  switch message SMBtrans (pid 9305) conn 0xb9643618
[2008/05/26 12:44:01,  3] smbd/ipc.c:handle_trans(436)
  trans <\PIPE\> data=60 params=0 setup=2
[2008/05/26 12:44:01,  3] smbd/ipc.c:named_pipe(387)
  named pipe command on <> name
[2008/05/26 12:44:01,  3] smbd/ipc.c:api_fd_reply(345)
  Got API command 0x26 on pipe "wkssvc" (pnum 748b)
[2008/05/26 12:44:01,  3] rpc_server/srv_pipe_hnd.c:free_pipe_context(519)
  free_pipe_context: destroying talloc pool of size 71
[2008/05/26 12:44:01,  3] rpc_server/srv_pipe.c:api_rpcTNP(2304)
  api_rpcTNP: rpc command: WKSSVC_NETWKSTAGETINFO
[2008/05/26 12:44:01,  3] rpc_server/srv_pipe_hnd.c:free_pipe_context(519)
  free_pipe_context: destroying talloc pool of size 38
[2008/05/26 12:44:01,  3] smbd/process.c:process_smb(1554)
  Transaction 24 of length 45 (0 toread)
[2008/05/26 12:44:01,  3] smbd/process.c:switch_message(1366)
  switch message SMBclose (pid 9305) conn 0xb9643618
[2008/05/26 12:44:01,  3] smbd/process.c:process_smb(1554)
  Transaction 25 of length 104 (0 toread)
[2008/05/26 12:44:01,  3] smbd/process.c:switch_message(1366)
  switch message SMBntcreateX (pid 9305) conn 0xb9643618
[2008/05/26 12:44:01,  3] smbd/nttrans.c:nt_open_pipe(322)
  nt_open_pipe: Known pipe srvsvc opening.
[2008/05/26 12:44:01,  3] smbd/process.c:process_smb(1554)
  Transaction 26 of length 140 (0 toread)
[2008/05/26 12:44:01,  3] smbd/process.c:switch_message(1366)
  switch message SMBwriteX (pid 9305) conn 0xb9643618
[2008/05/26 12:44:01,  3] rpc_server/srv_pipe.c:api_pipe_bind_req(1564)
  api_pipe_bind_req: \PIPE\srvsvc -> \PIPE\srvsvc
[2008/05/26 12:44:01,  3] rpc_server/srv_pipe.c:check_bind_req(991)
  check_bind_req for \PIPE\srvsvc
[2008/05/26 12:44:01,  3] smbd/pipes.c:reply_pipe_write_and_X(251)
  writeX-IPC pnum=748c nwritten=72
[2008/05/26 12:44:01,  3] smbd/process.c:process_smb(1554)
  Transaction 27 of length 63 (0 toread)
[2008/05/26 12:44:01,  3] smbd/process.c:switch_message(1366)
  switch message SMBreadX (pid 9305) conn 0xb9643618
[2008/05/26 12:44:01,  3] smbd/pipes.c:reply_pipe_read_and_X(301)
  readX-IPC pnum=748c min=1024 max=1024 nread=68
[2008/05/26 12:44:01,  3] smbd/process.c:process_smb(1554)
  Transaction 28 of length 148 (0 toread)
[2008/05/26 12:44:01,  3] smbd/process.c:switch_message(1366)
  switch message SMBtrans (pid 9305) conn 0xb9643618
[2008/05/26 12:44:01,  3] smbd/ipc.c:handle_trans(436)
  trans <\PIPE\> data=60 params=0 setup=2
[2008/05/26 12:44:01,  3] smbd/ipc.c:named_pipe(387)
  named pipe command on <> name
[2008/05/26 12:44:01,  3] smbd/ipc.c:api_fd_reply(345)
  Got API command 0x26 on pipe "srvsvc" (pnum 748c)
[2008/05/26 12:44:01,  3] rpc_server/srv_pipe_hnd.c:free_pipe_context(519)
  free_pipe_context: destroying talloc pool of size 71
[2008/05/26 12:44:01,  3] rpc_server/srv_pipe.c:api_rpcTNP(2304)
  api_rpcTNP: rpc command: SRVSVC_NETSRVGETINFO
[2008/05/26 12:44:01,  3] rpc_server/srv_pipe_hnd.c:free_pipe_context(519)
  free_pipe_context: destroying talloc pool of size 24
[2008/05/26 12:44:01,  3] smbd/process.c:process_smb(1554)
  Transaction 29 of length 45 (0 toread)
[2008/05/26 12:44:01,  3] smbd/process.c:switch_message(1366)
  switch message SMBclose (pid 9305) conn 0xb9643618
[2008/05/26 12:44:01,  3] smbd/process.c:process_smb(1554)
  Transaction 30 of length 104 (0 toread)
[2008/05/26 12:44:01,  3] smbd/process.c:switch_message(1366)
  switch message SMBntcreateX (pid 9305) conn 0xb9643618
[2008/05/26 12:44:01,  3] smbd/nttrans.c:nt_open_pipe(322)
  nt_open_pipe: Known pipe winreg opening.
[2008/05/26 12:44:01,  3] smbd/process.c:process_smb(1554)
  Transaction 31 of length 140 (0 toread)
[2008/05/26 12:44:01,  3] smbd/process.c:switch_message(1366)
  switch message SMBwriteX (pid 9305) conn 0xb9643618
[2008/05/26 12:44:01,  3] rpc_server/srv_pipe.c:api_pipe_bind_req(1564)
  api_pipe_bind_req: \PIPE\winreg -> \PIPE\winreg
[2008/05/26 12:44:01,  3] rpc_server/srv_pipe.c:check_bind_req(991)
  check_bind_req for \PIPE\winreg
[2008/05/26 12:44:01,  3] smbd/pipes.c:reply_pipe_write_and_X(251)
  writeX-IPC pnum=748d nwritten=72
[2008/05/26 12:44:01,  3] smbd/process.c:process_smb(1554)
  Transaction 32 of length 63 (0 toread)
[2008/05/26 12:44:01,  3] smbd/process.c:switch_message(1366)
  switch message SMBreadX (pid 9305) conn 0xb9643618
[2008/05/26 12:44:01,  3] smbd/pipes.c:reply_pipe_read_and_X(301)
  readX-IPC pnum=748d min=1024 max=1024 nread=68
[2008/05/26 12:44:01,  3] smbd/process.c:process_smb(1554)
  Transaction 33 of length 124 (0 toread)
[2008/05/26 12:44:01,  3] smbd/process.c:switch_message(1366)
  switch message SMBtrans (pid 9305) conn 0xb9643618
[2008/05/26 12:44:01,  3] smbd/ipc.c:handle_trans(436)
  trans <\PIPE\> data=36 params=0 setup=2
[2008/05/26 12:44:01,  3] smbd/ipc.c:named_pipe(387)
  named pipe command on <> name
[2008/05/26 12:44:01,  3] smbd/ipc.c:api_fd_reply(345)
  Got API command 0x26 on pipe "winreg" (pnum 748d)
[2008/05/26 12:44:01,  3] rpc_server/srv_pipe_hnd.c:free_pipe_context(519)
  free_pipe_context: destroying talloc pool of size 71
[2008/05/26 12:44:01,  3] rpc_server/srv_pipe.c:api_rpcTNP(2304)
  api_rpcTNP: rpc command: WINREG_OPENHKLM
[2008/05/26 12:44:01,  3] smbd/sec_ctx.c:push_sec_ctx(224)
  push_sec_ctx(1000, 1000) : sec_ctx_stack_ndx = 1
[2008/05/26 12:44:01,  3] smbd/uid.c:push_conn_ctx(357)
  push_conn_ctx(100) : conn_ctx_stack_ndx = 0
[2008/05/26 12:44:01,  3] smbd/sec_ctx.c:set_sec_ctx(324)
  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1
[2008/05/26 12:44:01,  3] smbd/sec_ctx.c:pop_sec_ctx(432)
  pop_sec_ctx (1000, 1000) - sec_ctx_stack_ndx = 0
[2008/05/26 12:44:01,  3] lib/util_seaccess.c:se_access_check(249)
[2008/05/26 12:44:01,  3] lib/util_seaccess.c:se_access_check(252)
  se_access_check: user sid is S-1-5-21-2185502541-14410569-2829850117-3000
  se_access_check: also S-1-22-2-1000
  se_access_check: also S-1-1-0
  se_access_check: also S-1-5-2
  se_access_check: also S-1-5-11
  se_access_check: also S-1-22-2-100
  se_access_check: also S-1-22-2-500
  se_access_check: also S-1-22-2-1500
  se_access_check: also S-1-22-2-1501
  se_access_check: also S-1-22-2-1502
  se_access_check: also S-1-22-2-1503
  se_access_check: also S-1-22-2-1504
  se_access_check: also S-1-22-2-1505
  se_access_check: also S-1-22-2-1506
  se_access_check: also S-1-22-2-1507
  se_access_check: also S-1-22-2-1508
  se_access_check: also S-1-22-2-1509
  se_access_check: also S-1-22-2-1600
  se_access_check: also S-1-22-2-1700
  se_access_check: also S-1-22-2-1701
[2008/05/26 12:44:01,  3] rpc_server/srv_pipe_hnd.c:free_pipe_context(519)
  free_pipe_context: destroying talloc pool of size 0
[2008/05/26 12:44:01,  3] smbd/process.c:process_smb(1554)
  Transaction 34 of length 232 (0 toread)
[2008/05/26 12:44:01,  3] smbd/process.c:switch_message(1366)
  switch message SMBtrans (pid 9305) conn 0xb9643618
[2008/05/26 12:44:01,  3] smbd/ipc.c:handle_trans(436)
  trans <\PIPE\> data=144 params=0 setup=2
[2008/05/26 12:44:01,  3] smbd/ipc.c:named_pipe(387)
  named pipe command on <> name
[2008/05/26 12:44:01,  3] smbd/ipc.c:api_fd_reply(345)
  Got API command 0x26 on pipe "winreg" (pnum 748d)
[2008/05/26 12:44:01,  3] rpc_server/srv_pipe_hnd.c:free_pipe_context(519)
  free_pipe_context: destroying talloc pool of size 0
[2008/05/26 12:44:01,  3] rpc_server/srv_pipe.c:api_rpcTNP(2304)
  api_rpcTNP: rpc command: WINREG_OPENKEY
[2008/05/26 12:44:01,  3] lib/util_seaccess.c:se_access_check(249)
[2008/05/26 12:44:01,  3] lib/util_seaccess.c:se_access_check(252)
  se_access_check: user sid is S-1-5-21-2185502541-14410569-2829850117-3000
  se_access_check: also S-1-22-2-1000
  se_access_check: also S-1-1-0
  se_access_check: also S-1-5-2
  se_access_check: also S-1-5-11
  se_access_check: also S-1-22-2-100
  se_access_check: also S-1-22-2-500
  se_access_check: also S-1-22-2-1500
  se_access_check: also S-1-22-2-1501
  se_access_check: also S-1-22-2-1502
  se_access_check: also S-1-22-2-1503
  se_access_check: also S-1-22-2-1504
  se_access_check: also S-1-22-2-1505
  se_access_check: also S-1-22-2-1506
  se_access_check: also S-1-22-2-1507
  se_access_check: also S-1-22-2-1508
  se_access_check: also S-1-22-2-1509
  se_access_check: also S-1-22-2-1600
  se_access_check: also S-1-22-2-1700
  se_access_check: also S-1-22-2-1701
[2008/05/26 12:44:01,  3] lib/util_seaccess.c:se_access_check(249)
[2008/05/26 12:44:01,  3] lib/util_seaccess.c:se_access_check(252)
  se_access_check: user sid is S-1-5-21-2185502541-14410569-2829850117-3000
  se_access_check: also S-1-22-2-1000
  se_access_check: also S-1-1-0
  se_access_check: also S-1-5-2
  se_access_check: also S-1-5-11
  se_access_check: also S-1-22-2-100
  se_access_check: also S-1-22-2-500
  se_access_check: also S-1-22-2-1500
  se_access_check: also S-1-22-2-1501
  se_access_check: also S-1-22-2-1502
  se_access_check: also S-1-22-2-1503
  se_access_check: also S-1-22-2-1504
  se_access_check: also S-1-22-2-1505
  se_access_check: also S-1-22-2-1506
  se_access_check: also S-1-22-2-1507
  se_access_check: also S-1-22-2-1508
  se_access_check: also S-1-22-2-1509
  se_access_check: also S-1-22-2-1600
  se_access_check: also S-1-22-2-1700
  se_access_check: also S-1-22-2-1701
[2008/05/26 12:44:01,  3] rpc_server/srv_pipe_hnd.c:free_pipe_context(519)
  free_pipe_context: destroying talloc pool of size 0
[2008/05/26 12:44:01,  3] smbd/process.c:process_smb(1554)
  Transaction 35 of length 132 (0 toread)
[2008/05/26 12:44:01,  3] smbd/process.c:switch_message(1366)
  switch message SMBtrans (pid 9305) conn 0xb9643618
[2008/05/26 12:44:01,  3] smbd/ipc.c:handle_trans(436)
  trans <\PIPE\> data=44 params=0 setup=2
[2008/05/26 12:44:01,  3] smbd/ipc.c:named_pipe(387)
  named pipe command on <> name
[2008/05/26 12:44:01,  3] smbd/ipc.c:api_fd_reply(345)
  Got API command 0x26 on pipe "winreg" (pnum 748d)
[2008/05/26 12:44:01,  3] rpc_server/srv_pipe_hnd.c:free_pipe_context(519)
  free_pipe_context: destroying talloc pool of size 0
[2008/05/26 12:44:01,  3] rpc_server/srv_pipe.c:api_rpcTNP(2304)
  api_rpcTNP: rpc command: WINREG_CLOSEKEY
[2008/05/26 12:44:01,  3] rpc_server/srv_lsa_hnd.c:close_policy_hnd(206)
  Closed policy
[2008/05/26 12:44:01,  3] rpc_server/srv_pipe_hnd.c:free_pipe_context(519)
  free_pipe_context: destroying talloc pool of size 0
[2008/05/26 12:44:01,  3] smbd/process.c:process_smb(1554)
  Transaction 36 of length 45 (0 toread)
[2008/05/26 12:44:01,  3] smbd/process.c:switch_message(1366)
  switch message SMBclose (pid 9305) conn 0xb9643618
[2008/05/26 12:44:01,  3] smbd/process.c:process_smb(1554)
  Transaction 37 of length 86 (0 toread)
[2008/05/26 12:44:01,  3] smbd/process.c:switch_message(1366)
  switch message SMBtconX (pid 9305) conn 0x0
[2008/05/26 12:44:01,  3] smbd/sec_ctx.c:set_sec_ctx(324)
  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0
[2008/05/26 12:44:01,  3] smbd/service.c:make_connection_snum(936)
  Connect path is '/home/russell' for service [russell]
[2008/05/26 12:44:01,  3] lib/util_seaccess.c:se_access_check(249)
[2008/05/26 12:44:01,  3] lib/util_seaccess.c:se_access_check(252)
  se_access_check: user sid is S-1-5-21-2185502541-14410569-2829850117-3000
  se_access_check: also S-1-22-2-1000
  se_access_check: also S-1-1-0
  se_access_check: also S-1-5-2
  se_access_check: also S-1-5-11
  se_access_check: also S-1-22-2-100
  se_access_check: also S-1-22-2-500
  se_access_check: also S-1-22-2-1500
  se_access_check: also S-1-22-2-1501
  se_access_check: also S-1-22-2-1502
  se_access_check: also S-1-22-2-1503
  se_access_check: also S-1-22-2-1504
  se_access_check: also S-1-22-2-1505
  se_access_check: also S-1-22-2-1506
  se_access_check: also S-1-22-2-1507
  se_access_check: also S-1-22-2-1508
  se_access_check: also S-1-22-2-1509
  se_access_check: also S-1-22-2-1600
  se_access_check: also S-1-22-2-1700
  se_access_check: also S-1-22-2-1701
[2008/05/26 12:44:01,  3] smbd/vfs.c:vfs_init_default(96)
  Initialising default vfs hooks
[2008/05/26 12:44:01,  3] smbd/vfs.c:vfs_init_custom(130)
  Initialising custom vfs hooks from [/[Default VFS]/]
[2008/05/26 12:44:01,  3] lib/util_seaccess.c:se_access_check(249)
[2008/05/26 12:44:01,  3] lib/util_seaccess.c:se_access_check(252)
  se_access_check: user sid is S-1-5-21-2185502541-14410569-2829850117-3000
  se_access_check: also S-1-22-2-1000
  se_access_check: also S-1-1-0
  se_access_check: also S-1-5-2
  se_access_check: also S-1-5-11
  se_access_check: also S-1-22-2-100
  se_access_check: also S-1-22-2-500
  se_access_check: also S-1-22-2-1500
  se_access_check: also S-1-22-2-1501
  se_access_check: also S-1-22-2-1502
  se_access_check: also S-1-22-2-1503
  se_access_check: also S-1-22-2-1504
  se_access_check: also S-1-22-2-1505
  se_access_check: also S-1-22-2-1506
  se_access_check: also S-1-22-2-1507
  se_access_check: also S-1-22-2-1508
  se_access_check: also S-1-22-2-1509
  se_access_check: also S-1-22-2-1600
  se_access_check: also S-1-22-2-1700
  se_access_check: also S-1-22-2-1701
[2008/05/26 12:44:01,  3] lib/util_seaccess.c:se_access_check(249)
[2008/05/26 12:44:01,  3] lib/util_seaccess.c:se_access_check(252)
  se_access_check: user sid is S-1-5-21-2185502541-14410569-2829850117-3000
  se_access_check: also S-1-22-2-1000
  se_access_check: also S-1-1-0
  se_access_check: also S-1-5-2
  se_access_check: also S-1-5-11
  se_access_check: also S-1-22-2-100
  se_access_check: also S-1-22-2-500
  se_access_check: also S-1-22-2-1500
  se_access_check: also S-1-22-2-1501
  se_access_check: also S-1-22-2-1502
  se_access_check: also S-1-22-2-1503
  se_access_check: also S-1-22-2-1504
  se_access_check: also S-1-22-2-1505
  se_access_check: also S-1-22-2-1506
  se_access_check: also S-1-22-2-1507
  se_access_check: also S-1-22-2-1508
  se_access_check: also S-1-22-2-1509
  se_access_check: also S-1-22-2-1600
  se_access_check: also S-1-22-2-1700
  se_access_check: also S-1-22-2-1701
[2008/05/26 12:44:01,  3] smbd/sec_ctx.c:set_sec_ctx(324)
  setting sec ctx (1000, 1000) - sec_ctx_stack_ndx = 0
[2008/05/26 12:44:01,  1] smbd/service.c:make_connection_snum(1188)
  blinky (::ffff:10.9.0.21) connect to service russell initially as user russell (uid=1000, gid=1000) (pid 9305)
[2008/05/26 12:44:01,  3] smbd/sec_ctx.c:set_sec_ctx(324)
  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0
[2008/05/26 12:44:01,  3] smbd/reply.c:reply_tcon_and_X(727)
  tconX service=RUSSELL 
[2008/05/26 12:44:01,  3] smbd/process.c:process_smb(1554)
  Transaction 38 of length 80 (0 toread)
[2008/05/26 12:44:01,  3] smbd/process.c:switch_message(1366)
  switch message SMBtrans2 (pid 9305) conn 0xb96454d8
[2008/05/26 12:44:01,  3] smbd/sec_ctx.c:set_sec_ctx(324)
  setting sec ctx (1000, 1000) - sec_ctx_stack_ndx = 0
[2008/05/26 12:44:01,  3] smbd/trans2.c:call_trans2qfilepathinfo(3913)
  call_trans2qfilepathinfo: TRANSACT2_QPATHINFO: level = 1004
[2008/05/26 12:44:01,  3] locking/locking.c:fetch_share_mode_unlocked(856)
  fill_share_mode_lock failed
[2008/05/26 12:44:01,  3] smbd/trans2.c:call_trans2qfilepathinfo(3982)
  call_trans2qfilepathinfo . (fnum = -1) level=1004 call=5 total_data=0
[2008/05/26 12:44:01,  3] smbd/process.c:process_smb(1554)
  Transaction 39 of length 104 (0 toread)
[2008/05/26 12:44:01,  3] smbd/process.c:switch_message(1366)
  switch message SMBtconX (pid 9305) conn 0x0
[2008/05/26 12:44:01,  3] smbd/sec_ctx.c:set_sec_ctx(324)
  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0
[2008/05/26 12:44:01,  3] smbd/service.c:make_connection_snum(936)
  Connect path is '/var/spool/samba' for service [hp_LaserJet_1000]
[2008/05/26 12:44:01,  3] lib/util_seaccess.c:se_access_check(249)
[2008/05/26 12:44:01,  3] lib/util_seaccess.c:se_access_check(252)
  se_access_check: user sid is S-1-5-21-2185502541-14410569-2829850117-3000
  se_access_check: also S-1-22-2-1000
  se_access_check: also S-1-1-0
  se_access_check: also S-1-5-2
  se_access_check: also S-1-5-11
  se_access_check: also S-1-22-2-100
  se_access_check: also S-1-22-2-500
  se_access_check: also S-1-22-2-1500
  se_access_check: also S-1-22-2-1501
  se_access_check: also S-1-22-2-1502
  se_access_check: also S-1-22-2-1503
  se_access_check: also S-1-22-2-1504
  se_access_check: also S-1-22-2-1505
  se_access_check: also S-1-22-2-1506
  se_access_check: also S-1-22-2-1507
  se_access_check: also S-1-22-2-1508
  se_access_check: also S-1-22-2-1509
  se_access_check: also S-1-22-2-1600
  se_access_check: also S-1-22-2-1700
  se_access_check: also S-1-22-2-1701
[2008/05/26 12:44:01,  3] smbd/vfs.c:vfs_init_default(96)
  Initialising default vfs hooks
[2008/05/26 12:44:01,  3] smbd/vfs.c:vfs_init_custom(130)
  Initialising custom vfs hooks from [/[Default VFS]/]
[2008/05/26 12:44:01,  3] lib/util_seaccess.c:se_access_check(249)
[2008/05/26 12:44:01,  3] lib/util_seaccess.c:se_access_check(252)
  se_access_check: user sid is S-1-5-21-2185502541-14410569-2829850117-3000
  se_access_check: also S-1-22-2-1000
  se_access_check: also S-1-1-0
  se_access_check: also S-1-5-2
  se_access_check: also S-1-5-11
  se_access_check: also S-1-22-2-100
  se_access_check: also S-1-22-2-500
  se_access_check: also S-1-22-2-1500
  se_access_check: also S-1-22-2-1501
  se_access_check: also S-1-22-2-1502
  se_access_check: also S-1-22-2-1503
  se_access_check: also S-1-22-2-1504
  se_access_check: also S-1-22-2-1505
  se_access_check: also S-1-22-2-1506
  se_access_check: also S-1-22-2-1507
  se_access_check: also S-1-22-2-1508
  se_access_check: also S-1-22-2-1509
  se_access_check: also S-1-22-2-1600
  se_access_check: also S-1-22-2-1700
  se_access_check: also S-1-22-2-1701
[2008/05/26 12:44:01,  3] lib/util_seaccess.c:se_access_check(249)
[2008/05/26 12:44:01,  3] lib/util_seaccess.c:se_access_check(252)
  se_access_check: user sid is S-1-5-21-2185502541-14410569-2829850117-3000
  se_access_check: also S-1-22-2-1000
  se_access_check: also S-1-1-0
  se_access_check: also S-1-5-2
  se_access_check: also S-1-5-11
  se_access_check: also S-1-22-2-100
  se_access_check: also S-1-22-2-500
  se_access_check: also S-1-22-2-1500
  se_access_check: also S-1-22-2-1501
  se_access_check: also S-1-22-2-1502
  se_access_check: also S-1-22-2-1503
  se_access_check: also S-1-22-2-1504
  se_access_check: also S-1-22-2-1505
  se_access_check: also S-1-22-2-1506
  se_access_check: also S-1-22-2-1507
  se_access_check: also S-1-22-2-1508
  se_access_check: also S-1-22-2-1509
  se_access_check: also S-1-22-2-1600
  se_access_check: also S-1-22-2-1700
  se_access_check: also S-1-22-2-1701
[2008/05/26 12:44:01,  3] smbd/sec_ctx.c:set_sec_ctx(324)
  setting sec ctx (1000, 1000) - sec_ctx_stack_ndx = 0
[2008/05/26 12:44:01,  1] smbd/service.c:make_connection_snum(1188)
  blinky (::ffff:10.9.0.21) connect to service hp_LaserJet_1000 initially as user russell (uid=1000, gid=1000) (pid 9305)
[2008/05/26 12:44:01,  3] smbd/sec_ctx.c:set_sec_ctx(324)
  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0
[2008/05/26 12:44:01,  3] smbd/reply.c:reply_tcon_and_X(727)
  tconX service=HP_LASERJET_1000 
[2008/05/26 12:44:01,  3] smbd/process.c:process_smb(1554)
  Transaction 40 of length 74 (0 toread)
[2008/05/26 12:44:01,  3] smbd/process.c:switch_message(1366)
  switch message SMBsplopen (pid 9305) conn 0xb9645cb8
[2008/05/26 12:44:01,  3] smbd/sec_ctx.c:set_sec_ctx(324)
  setting sec ctx (1000, 1000) - sec_ctx_stack_ndx = 0
[2008/05/26 12:44:01,  3] smbd/sec_ctx.c:push_sec_ctx(224)
  push_sec_ctx(1000, 1000) : sec_ctx_stack_ndx = 1
[2008/05/26 12:44:01,  3] smbd/uid.c:push_conn_ctx(357)
  push_conn_ctx(100) : conn_ctx_stack_ndx = 0
[2008/05/26 12:44:01,  3] smbd/sec_ctx.c:set_sec_ctx(324)
  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1
[2008/05/26 12:44:01,  3] smbd/sec_ctx.c:pop_sec_ctx(432)
  pop_sec_ctx (1000, 1000) - sec_ctx_stack_ndx = 0
[2008/05/26 12:44:01,  3] lib/util_seaccess.c:se_access_check(249)
[2008/05/26 12:44:01,  3] lib/util_seaccess.c:se_access_check(252)
  se_access_check: user sid is S-1-5-21-2185502541-14410569-2829850117-3000
  se_access_check: also S-1-22-2-1000
  se_access_check: also S-1-1-0
  se_access_check: also S-1-5-2
  se_access_check: also S-1-5-11
  se_access_check: also S-1-22-2-100
  se_access_check: also S-1-22-2-500
  se_access_check: also S-1-22-2-1500
  se_access_check: also S-1-22-2-1501
  se_access_check: also S-1-22-2-1502
  se_access_check: also S-1-22-2-1503
  se_access_check: also S-1-22-2-1504
  se_access_check: also S-1-22-2-1505
  se_access_check: also S-1-22-2-1506
  se_access_check: also S-1-22-2-1507
  se_access_check: also S-1-22-2-1508
  se_access_check: also S-1-22-2-1509
  se_access_check: also S-1-22-2-1600
  se_access_check: also S-1-22-2-1700
  se_access_check: also S-1-22-2-1701
[2008/05/26 12:44:01,  3] smbd/reply.c:reply_printopen(4627)
  openprint fd=28 fnum=7096
[2008/05/26 12:44:01,  3] smbd/process.c:process_smb(1554)
  Transaction 41 of length 41 (0 toread)
[2008/05/26 12:44:01,  3] smbd/process.c:switch_message(1366)
  switch message SMBsplclose (pid 9305) conn 0xb9645cb8
[2008/05/26 12:44:01,  3] smbd/reply.c:reply_printclose(4665)
  printclose fd=28 fnum=7096
[2008/05/26 12:44:02,  3] smbd/sec_ctx.c:set_sec_ctx(324)
  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0
[2008/05/26 12:44:11,  3] smbd/process.c:process_smb(1554)
  Transaction 42 of length 39 (0 toread)
[2008/05/26 12:44:11,  3] smbd/process.c:switch_message(1366)
  switch message SMBtdis (pid 9305) conn 0xb9643618
[2008/05/26 12:44:11,  3] smbd/sec_ctx.c:set_sec_ctx(324)
  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0
[2008/05/26 12:44:11,  3] smbd/sec_ctx.c:set_sec_ctx(324)
  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0
[2008/05/26 12:44:11,  3] smbd/service.c:close_cnum(1399)
  blinky (::ffff:10.9.0.21) closed connection to service IPC$
[2008/05/26 12:44:11,  3] smbd/connection.c:yield_connection(31)
  Yielding connection to IPC$
[2008/05/26 12:44:11,  3] smbd/sec_ctx.c:set_sec_ctx(324)
  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0
[2008/05/26 12:44:11,  3] smbd/process.c:process_smb(1554)
  Transaction 43 of length 39 (0 toread)
[2008/05/26 12:44:11,  3] smbd/process.c:switch_message(1366)
  switch message SMBtdis (pid 9305) conn 0xb96454d8
[2008/05/26 12:44:11,  3] smbd/sec_ctx.c:set_sec_ctx(324)
  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0
[2008/05/26 12:44:11,  3] smbd/sec_ctx.c:set_sec_ctx(324)
  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0
[2008/05/26 12:44:11,  1] smbd/service.c:close_cnum(1399)
  blinky (::ffff:10.9.0.21) closed connection to service russell
[2008/05/26 12:44:11,  3] smbd/connection.c:yield_connection(31)
  Yielding connection to russell
[2008/05/26 12:44:11,  3] smbd/sec_ctx.c:set_sec_ctx(324)
  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0

Comment 1 Russell Davies 2008-05-26 18:01:13 UTC
That "Broken Pipe" that I mentioned was in fact an "invalid pipe handle".  Just
got the error again.  Don't know if it is at all relevant, but here it is:

[2008/05/26 13:55:13,  1] smbd/ipc.c:api_fd_reply(333)
  api_fd_reply: INVALID PIPE HANDLE: 70ee


Comment 2 Guenther Deschner 2008-06-25 14:15:31 UTC
Can you please upload a log level 10 log.smbd file ? (please do not paste inline
:)).

Thanks.

Comment 3 Russell Davies 2008-06-25 14:53:16 UTC
Created attachment 310276 [details]
log.smbd for "log level 10"

As requested, see attached.  Log captures the following activity cycle:


<linuxServer> /sbin/service smb start

<windowsClient> Browse to "\\<linuxServer>\" using explorer.

<windowsClient> Observe that machine has locked-up, with explorer showing
blank.

<windowsClient> Wait for a while, and observe no change. 

<linuxServer> /sbin/service smb stop

<windowsClient> Observe that machine has now resumed, with explorer correctly
shows expected browse list.

Comment 4 Guenther Deschner 2008-06-25 15:01:20 UTC
Ok, thanks, this looks like a tdb transaction lock issue which has already been
resolved.

Can you please try the provided update packages ?

Comment 5 Russell Davies 2008-06-26 13:39:04 UTC
Created attachment 310330 [details]
new Log level 10, using packages current with update mirrors

Hi,

It's not clear to me which packages/versions you're referring to.  Since I
don't see any packages attached to this thread, then my best guess is that you
mean the packages should already be in the Fedora yum update repo's.   

Running with that idea, then at least one of my servers was already up to date
with the mirrors, yet still exhibiting the same problem behavior.  However, the
machine for which I sent the previous log file was not up to date.  So, I've
updated that machine and I'm attaching the new log file.  

FYI, the output of `rpm -qa | grep -i samba` is: 

samba-common-3.2.0-1.rc1.15.fc9.i386
samba-winbind-3.2.0-1.rc1.15.fc9.i386
samba-3.2.0-1.rc1.15.fc9.i386
system-config-samba-1.2.63-1.fc9.noarch
samba-client-3.2.0-1.rc1.15.fc9.i386

If these are not the packages that you mean, then please tell me what versions
you are referring to and where you would like me to retrieve them from. 

Thanks

Comment 6 Bug Zapper 2009-06-10 01:12:48 UTC
This message is a reminder that Fedora 9 is nearing its end of life.
Approximately 30 (thirty) days from now Fedora will stop maintaining
and issuing updates for Fedora 9.  It is Fedora's policy to close all
bug reports from releases that are no longer maintained.  At that time
this bug will be closed as WONTFIX if it remains open with a Fedora 
'version' of '9'.

Package Maintainer: If you wish for this bug to remain open because you
plan to fix it in a currently maintained version, simply change the 'version' 
to a later Fedora version prior to Fedora 9's end of life.

Bug Reporter: Thank you for reporting this issue and we are sorry that 
we may not be able to fix it before Fedora 9 is end of life.  If you 
would still like to see this bug fixed and are able to reproduce it 
against a later version of Fedora please change the 'version' of this 
bug to the applicable version.  If you are unable to change the version, 
please add a comment here and someone will do it for you.

Although we aim to fix as many bugs as possible during every release's 
lifetime, sometimes those efforts are overtaken by events.  Often a 
more recent Fedora release includes newer upstream software that fixes 
bugs or makes them obsolete.

The process we are following is described here: 
http://fedoraproject.org/wiki/BugZappers/HouseKeeping

Comment 7 Bug Zapper 2009-07-14 16:31:31 UTC
Fedora 9 changed to end-of-life (EOL) status on 2009-07-10. Fedora 9 is 
no longer maintained, which means that it will not receive any further 
security or bug fix updates. As a result we are closing this bug.

If you can reproduce this bug against a currently maintained version of 
Fedora please feel free to reopen this bug against that version.

Thank you for reporting this bug and we are sorry it could not be fixed.


Note You need to log in before you can comment on or make changes to this bug.