[2009/11/17 22:34:10, 6] param/loadparm.c:6994(lp_file_list_changed) lp_file_list_changed() file /etc/samba/smb_perm-%a.conf -> /etc/samba/smb_perm-UNKNOWN.conf last mod_time: Tue Nov 17 21:05:23 2009 file /etc/samba/smb.conf -> /etc/samba/smb.conf last mod_time: Tue Nov 17 22:33:54 2009 [2009/11/17 22:34:10, 3] smbd/oplock.c:911(init_oplocks) init_oplocks: initializing messages. [2009/11/17 22:34:10, 3] smbd/oplock_linux.c:223(linux_init_kernel_oplocks) Linux kernel oplocks enabled [2009/11/17 22:34:10, 10] lib/events.c:287(s3_event_debug) s3_event: Added timed event "smbd_idle_event_handler": 0xa4e7d40 [2009/11/17 22:34:10, 10] smbd/process.c:720(event_add_idle) event_add_idle: idle_evt(keepalive) 0xa4e7d40 [2009/11/17 22:34:10, 10] lib/events.c:287(s3_event_debug) s3_event: Added timed event "smbd_idle_event_handler": 0xa4e32f8 [2009/11/17 22:34:10, 10] smbd/process.c:720(event_add_idle) event_add_idle: idle_evt(deadtime) 0xa4e32f8 [2009/11/17 22:34:10, 10] lib/events.c:287(s3_event_debug) s3_event: Added timed event "smbd_idle_event_handler": 0xa4ed0e0 [2009/11/17 22:34:10, 10] smbd/process.c:720(event_add_idle) event_add_idle: idle_evt(housekeeping) 0xa4ed0e0 [2009/11/17 22:34:17, 10] lib/util_sock.c:789(read_smb_length_return_keepalive) got smb length of 78 [2009/11/17 22:34:17, 6] smbd/process.c:1456(process_smb) got message type 0x0 of len 0x4e [2009/11/17 22:34:17, 3] smbd/process.c:1459(process_smb) Transaction 0 of length 82 (0 toread) [2009/11/17 22:34:17, 5] lib/util.c:632(show_msg) [2009/11/17 22:34:17, 5] lib/util.c:642(show_msg) size=78 smb_com=0x72 smb_rcls=0 smb_reh=0 smb_err=0 smb_flg=0 smb_flg2=49153 smb_tid=0 smb_pid=7672 smb_uid=0 smb_mid=1983 smt_wct=0 smb_bcc=43 [2009/11/17 22:34:17, 10] ../lib/util/util.c:304(_dump_data) [0000] 02 4C 4D 31 2E 32 58 30 30 32 00 02 4C 41 4E 4D .LM1.2X0 02..LANM [0010] 41 4E 32 2E 31 00 02 4E 54 20 4C 4D 20 30 2E 31 AN2.1..N T LM 0.1 [0020] 32 00 02 50 4F 53 49 58 20 32 00 2..POSIX 2. [2009/11/17 22:34:17, 3] smbd/process.c:1273(switch_message) switch message SMBnegprot (pid 6837) conn 0x0 [2009/11/17 22:34:17, 3] smbd/sec_ctx.c:310(set_sec_ctx) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0 [2009/11/17 22:34:17, 5] auth/token_util.c:522(debug_nt_user_token) NT user token: (NULL) [2009/11/17 22:34:17, 5] auth/token_util.c:548(debug_unix_user_token) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2009/11/17 22:34:17, 5] smbd/uid.c:368(change_to_root_user) change_to_root_user: now uid=(0,0) gid=(0,0) [2009/11/17 22:34:17, 5] lib/charcnv.c:82(charset_name) Substituting charset 'UTF-8' for LOCALE [2009/11/17 22:34:17, 5] lib/charcnv.c:82(charset_name) Substituting charset 'UTF-8' for LOCALE [2009/11/17 22:34:17, 5] lib/charcnv.c:82(charset_name) Substituting charset 'UTF-8' for LOCALE [2009/11/17 22:34:17, 5] lib/charcnv.c:82(charset_name) Substituting charset 'UTF-8' for LOCALE [2009/11/17 22:34:17, 5] lib/charcnv.c:82(charset_name) Substituting charset 'UTF-8' for LOCALE [2009/11/17 22:34:17, 5] lib/charcnv.c:82(charset_name) Substituting charset 'UTF-8' for LOCALE [2009/11/17 22:34:17, 5] lib/charcnv.c:82(charset_name) Substituting charset 'UTF-8' for LOCALE [2009/11/17 22:34:17, 5] lib/charcnv.c:82(charset_name) Substituting charset 'UTF-8' for LOCALE [2009/11/17 22:34:17, 5] lib/charcnv.c:82(charset_name) Substituting charset 'UTF-8' for LOCALE [2009/11/17 22:34:17, 5] lib/charcnv.c:82(charset_name) Substituting charset 'UTF-8' for LOCALE [2009/11/17 22:34:17, 5] lib/charcnv.c:82(charset_name) Substituting charset 'UTF-8' for LOCALE [2009/11/17 22:34:17, 5] lib/charcnv.c:82(charset_name) Substituting charset 'UTF-8' for LOCALE [2009/11/17 22:34:17, 5] lib/charcnv.c:82(charset_name) Substituting charset 'UTF-8' for LOCALE [2009/11/17 22:34:17, 5] lib/charcnv.c:82(charset_name) Substituting charset 'UTF-8' for LOCALE [2009/11/17 22:34:17, 3] smbd/negprot.c:567(reply_negprot) Requested protocol [LM1.2X002] [2009/11/17 22:34:17, 3] smbd/negprot.c:567(reply_negprot) Requested protocol [LANMAN2.1] [2009/11/17 22:34:17, 3] smbd/negprot.c:567(reply_negprot) Requested protocol [NT LM 0.12] [2009/11/17 22:34:17, 3] smbd/negprot.c:567(reply_negprot) Requested protocol [POSIX 2] [2009/11/17 22:34:17, 10] lib/util.c:1979(set_remote_arch) set_remote_arch: Client arch is 'CIFSFS' [2009/11/17 22:34:17, 6] param/loadparm.c:6994(lp_file_list_changed) lp_file_list_changed() file /etc/samba/smb_perm-%a.conf -> /etc/samba/smb_perm-CIFSFS.conf last mod_time: Tue Nov 17 21:05:23 2009 file /etc/samba/smb_perm-CIFSFS.conf modified: Tue Nov 17 21:05:23 2009 [2009/11/17 22:34:17, 5] param/loadparm.c:5916(free_service) free_service: Freeing service homes [2009/11/17 22:34:17, 5] param/loadparm.c:5916(free_service) free_service: Freeing service all-homes [2009/11/17 22:34:17, 5] param/loadparm.c:5916(free_service) free_service: Freeing service projects [2009/11/17 22:34:17, 5] param/loadparm.c:5916(free_service) free_service: Freeing service IPC$ [2009/11/17 22:34:17, 3] param/loadparm.c:9016(lp_load_ex) lp_load_ex: refreshing parameters Initialising global parameters [2009/11/17 22:34:17, 3] ../lib/util/params.c:550(pm_process) params.c:pm_process() - Processing configuration file "/etc/samba/smb.conf" [2009/11/17 22:34:17, 3] param/loadparm.c:7703(do_section) Processing section "[global]" doing parameter workgroup = ATeO doing parameter server string = Zentraler Datenserver doing parameter disable netbios = yes doing parameter domain master = no doing parameter local master = no doing parameter preferred master = no doing parameter wins support = no doing parameter name resolve order = host doing parameter log file = /var/log/samba/log.%I doing parameter log level = 10 [2009/11/17 22:34:17, 5] lib/debug.c:407(debug_dump_status) INFO: Current debug levels: all: True/10 tdb: False/0 printdrivers: False/0 lanman: False/0 smb: False/0 rpc_parse: False/0 rpc_srv: False/0 rpc_cli: False/0 passdb: False/0 sam: False/0 auth: False/0 winbind: False/0 vfs: False/0 idmap: False/0 quota: False/0 acls: False/0 locking: False/0 msdfs: False/0 dmapi: False/0 registry: False/0 doing parameter max log size = 1000 doing parameter syslog = 0 doing parameter panic action = /usr/share/samba/panic-action %d doing parameter security = user doing parameter encrypt passwords = true doing parameter passdb backend = tdbsam doing parameter obey pam restrictions = yes doing parameter unix password sync = no doing parameter disable spoolss = yes doing parameter show add printer wizard = no doing parameter load printers = no doing parameter printing = bsd doing parameter printcap cache time = 0 doing parameter printcap name = /dev/null doing parameter map acl inherit = yes doing parameter read only = no doing parameter map archive = no doing parameter include = /etc/samba/smb_perm-%a.conf [2009/11/17 22:34:17, 3] ../lib/util/params.c:550(pm_process) params.c:pm_process() - Processing configuration file "/etc/samba/smb_perm-CIFSFS.conf" doing parameter create mask = 7777 doing parameter security mask = 7777 doing parameter directory mask = 7777 doing parameter directory security mask = 7777 doing parameter inherit acls = yes doing parameter case sensitive = yes doing parameter delete readonly = yes doing parameter ea support = yes doing parameter unix extensions = yes [2009/11/17 22:34:17, 2] param/loadparm.c:7720(do_section) Processing section "[homes]" [2009/11/17 22:34:17, 8] param/loadparm.c:6024(add_a_service) add_a_service: Creating snum = 3 for homes [2009/11/17 22:34:17, 10] param/loadparm.c:6071(hash_a_service) hash_a_service: hashing index 3 for service name homes doing parameter comment = Benutzerverzeichnis von %S doing parameter browseable = no doing parameter valid users = %S [2009/11/17 22:34:17, 2] param/loadparm.c:7720(do_section) Processing section "[all-homes]" [2009/11/17 22:34:17, 8] param/loadparm.c:6024(add_a_service) add_a_service: Creating snum = 2 for all-homes [2009/11/17 22:34:17, 10] param/loadparm.c:6071(hash_a_service) hash_a_service: hashing index 2 for service name all-homes doing parameter comment = Benutzerverzeichnisse doing parameter path = /home doing parameter browseable = yes doing parameter guest ok = yes [2009/11/17 22:34:17, 2] param/loadparm.c:7720(do_section) Processing section "[projects]" [2009/11/17 22:34:17, 8] param/loadparm.c:6024(add_a_service) add_a_service: Creating snum = 1 for projects [2009/11/17 22:34:17, 10] param/loadparm.c:6071(hash_a_service) hash_a_service: hashing index 1 for service name projects doing parameter comment = Projekte von ATeO doing parameter path = /srv/samba/projects doing parameter browseable = yes doing parameter guest ok = yes doing parameter acl group control = yes doing parameter dos filemode = yes doing parameter force directory security mode = 2000 [2009/11/17 22:34:17, 4] param/loadparm.c:9051(lp_load_ex) pm_process() returned Yes [2009/11/17 22:34:17, 8] param/loadparm.c:6024(add_a_service) add_a_service: Creating snum = 0 for IPC$ [2009/11/17 22:34:17, 10] param/loadparm.c:6071(hash_a_service) hash_a_service: hashing index 0 for service name IPC$ [2009/11/17 22:34:17, 3] param/loadparm.c:6174(lp_add_ipc) adding IPC service [2009/11/17 22:34:17, 10] param/loadparm.c:8264(set_server_role) set_server_role: role = ROLE_STANDALONE [2009/11/17 22:34:17, 5] lib/charcnv.c:82(charset_name) Substituting charset 'UTF-8' for LOCALE [2009/11/17 22:34:17, 5] lib/charcnv.c:82(charset_name) Substituting charset 'UTF-8' for LOCALE [2009/11/17 22:34:17, 5] lib/charcnv.c:82(charset_name) Substituting charset 'UTF-8' for LOCALE [2009/11/17 22:34:17, 5] lib/charcnv.c:82(charset_name) Substituting charset 'UTF-8' for LOCALE [2009/11/17 22:34:17, 5] lib/charcnv.c:82(charset_name) Substituting charset 'UTF-8' for LOCALE [2009/11/17 22:34:17, 5] lib/charcnv.c:82(charset_name) Substituting charset 'UTF-8' for LOCALE [2009/11/17 22:34:17, 5] lib/charcnv.c:82(charset_name) Substituting charset 'UTF-8' for LOCALE [2009/11/17 22:34:17, 5] lib/charcnv.c:82(charset_name) Substituting charset 'UTF-8' for LOCALE [2009/11/17 22:34:17, 5] lib/charcnv.c:82(charset_name) Substituting charset 'UTF-8' for LOCALE [2009/11/17 22:34:17, 5] lib/charcnv.c:82(charset_name) Substituting charset 'UTF-8' for LOCALE [2009/11/17 22:34:17, 5] lib/charcnv.c:82(charset_name) Substituting charset 'UTF-8' for LOCALE [2009/11/17 22:34:17, 5] lib/charcnv.c:82(charset_name) Substituting charset 'UTF-8' for LOCALE [2009/11/17 22:34:17, 5] lib/charcnv.c:82(charset_name) Substituting charset 'UTF-8' for LOCALE [2009/11/17 22:34:17, 5] lib/charcnv.c:82(charset_name) Substituting charset 'UTF-8' for LOCALE [2009/11/17 22:34:17, 7] param/loadparm.c:9256(lp_servicenumber) lp_servicenumber: couldn't find printers [2009/11/17 22:34:17, 2] lib/interface.c:340(add_interface) added interface eth0 ip=fe80::210:dcff:fe90:ed05%eth0 bcast=fe80::ffff:ffff:ffff:ffff%eth0 netmask=ffff:ffff:ffff:ffff:: [2009/11/17 22:34:17, 2] lib/interface.c:340(add_interface) added interface eth0 ip=10.10.10.6 bcast=10.10.10.255 netmask=255.255.255.0 [2009/11/17 22:34:17, 5] lib/util_sock.c:371(print_socket_options) Socket options: SO_KEEPALIVE = 1 SO_REUSEADDR = 1 SO_BROADCAST = 0 TCP_NODELAY = 1 TCP_KEEPCNT = 9 TCP_KEEPIDLE = 7200 TCP_KEEPINTVL = 75 IPTOS_LOWDELAY = 0 IPTOS_THROUGHPUT = 0 SO_SNDBUF = 16384 SO_RCVBUF = 87380 SO_SNDLOWAT = 1 SO_RCVLOWAT = 1 SO_SNDTIMEO = 0 SO_RCVTIMEO = 0 [2009/11/17 22:34:17, 5] lib/util_sock.c:371(print_socket_options) Socket options: SO_KEEPALIVE = 1 SO_REUSEADDR = 1 SO_BROADCAST = 0 TCP_NODELAY = 1 TCP_KEEPCNT = 9 TCP_KEEPIDLE = 7200 TCP_KEEPINTVL = 75 IPTOS_LOWDELAY = 0 IPTOS_THROUGHPUT = 0 SO_SNDBUF = 16384 SO_RCVBUF = 87380 SO_SNDLOWAT = 1 SO_RCVLOWAT = 1 SO_SNDTIMEO = 0 SO_RCVTIMEO = 0 [2009/11/17 22:34:17, 5] smbd/connection.c:142(claim_connection) claiming [] [2009/11/17 22:34:17, 10] lib/dbwrap_tdb.c:100(db_tdb_fetch_locked) Locking key B51A0000FFFFFFFFFFFF [2009/11/17 22:34:17, 10] lib/dbwrap_tdb.c:129(db_tdb_fetch_locked) Allocated locked data 0x0xa4dfbe8 [2009/11/17 22:34:17, 10] lib/dbwrap_tdb.c:42(db_tdb_record_destr) Unlocking key B51A0000FFFFFFFFFFFF [2009/11/17 22:34:17, 6] param/loadparm.c:6994(lp_file_list_changed) lp_file_list_changed() file /etc/samba/smb_perm-%a.conf -> /etc/samba/smb_perm-CIFSFS.conf last mod_time: Tue Nov 17 21:05:23 2009 file /etc/samba/smb.conf -> /etc/samba/smb.conf last mod_time: Tue Nov 17 22:33:54 2009 [2009/11/17 22:34:17, 10] smbd/negprot.c:38(get_challenge) get challenge: creating negprot_global_auth_context [2009/11/17 22:34:17, 5] auth/auth.c:493(make_auth_context_subsystem) Making default auth method list for standalone security=user, encrypt passwords = yes [2009/11/17 22:34:17, 5] auth/auth.c:46(smb_register_auth) Attempting to register auth backend sam [2009/11/17 22:34:17, 5] auth/auth.c:58(smb_register_auth) Successfully added auth method 'sam' [2009/11/17 22:34:17, 5] auth/auth.c:46(smb_register_auth) Attempting to register auth backend sam_ignoredomain [2009/11/17 22:34:17, 5] auth/auth.c:58(smb_register_auth) Successfully added auth method 'sam_ignoredomain' [2009/11/17 22:34:17, 5] auth/auth.c:46(smb_register_auth) Attempting to register auth backend unix [2009/11/17 22:34:17, 5] auth/auth.c:58(smb_register_auth) Successfully added auth method 'unix' [2009/11/17 22:34:17, 5] auth/auth.c:46(smb_register_auth) Attempting to register auth backend winbind [2009/11/17 22:34:17, 5] auth/auth.c:58(smb_register_auth) Successfully added auth method 'winbind' [2009/11/17 22:34:17, 5] auth/auth.c:46(smb_register_auth) Attempting to register auth backend wbc [2009/11/17 22:34:17, 5] auth/auth.c:58(smb_register_auth) Successfully added auth method 'wbc' [2009/11/17 22:34:17, 5] auth/auth.c:46(smb_register_auth) Attempting to register auth backend smbserver [2009/11/17 22:34:17, 5] auth/auth.c:58(smb_register_auth) Successfully added auth method 'smbserver' [2009/11/17 22:34:17, 5] auth/auth.c:46(smb_register_auth) Attempting to register auth backend trustdomain [2009/11/17 22:34:17, 5] auth/auth.c:58(smb_register_auth) Successfully added auth method 'trustdomain' [2009/11/17 22:34:17, 5] auth/auth.c:46(smb_register_auth) Attempting to register auth backend ntdomain [2009/11/17 22:34:17, 5] auth/auth.c:58(smb_register_auth) Successfully added auth method 'ntdomain' [2009/11/17 22:34:17, 5] auth/auth.c:46(smb_register_auth) Attempting to register auth backend guest [2009/11/17 22:34:17, 5] auth/auth.c:58(smb_register_auth) Successfully added auth method 'guest' [2009/11/17 22:34:17, 5] auth/auth.c:46(smb_register_auth) Attempting to register auth backend netlogond [2009/11/17 22:34:17, 5] auth/auth.c:58(smb_register_auth) Successfully added auth method 'netlogond' [2009/11/17 22:34:17, 5] auth/auth.c:389(load_auth_module) load_auth_module: Attempting to find an auth method to match guest [2009/11/17 22:34:17, 5] auth/auth.c:414(load_auth_module) load_auth_module: auth method guest has a valid init [2009/11/17 22:34:17, 5] auth/auth.c:389(load_auth_module) load_auth_module: Attempting to find an auth method to match sam [2009/11/17 22:34:17, 5] auth/auth.c:414(load_auth_module) load_auth_module: auth method sam has a valid init [2009/11/17 22:34:17, 10] smbd/negprot.c:43(get_challenge) get challenge: getting challenge [2009/11/17 22:34:17, 5] auth/auth.c:98(get_ntlm_challenge) auth_get_challenge: module guest did not want to specify a challenge [2009/11/17 22:34:17, 5] auth/auth.c:98(get_ntlm_challenge) auth_get_challenge: module sam did not want to specify a challenge [2009/11/17 22:34:17, 5] auth/auth.c:138(get_ntlm_challenge) auth_context challenge created by random [2009/11/17 22:34:17, 5] auth/auth.c:139(get_ntlm_challenge) challenge is: [2009/11/17 22:34:17, 5] ../lib/util/util.c:304(_dump_data) [0000] C4 18 5F 47 0B 86 5C 28 .._G..\( [2009/11/17 22:34:17, 3] smbd/negprot.c:368(reply_nt1) not using SPNEGO [2009/11/17 22:34:17, 3] smbd/negprot.c:672(reply_negprot) Selected protocol NT LM 0.12 [2009/11/17 22:34:17, 5] smbd/negprot.c:679(reply_negprot) negprot index=2 [2009/11/17 22:34:17, 5] lib/util.c:632(show_msg) [2009/11/17 22:34:17, 5] lib/util.c:642(show_msg) size=87 smb_com=0x72 smb_rcls=0 smb_reh=0 smb_err=0 smb_flg=128 smb_flg2=49153 smb_tid=0 smb_pid=7672 smb_uid=0 smb_mid=1983 smt_wct=17 smb_vwv[ 0]= 2 (0x2) smb_vwv[ 1]=12803 (0x3203) smb_vwv[ 2]= 256 (0x100) smb_vwv[ 3]= 1024 (0x400) smb_vwv[ 4]= 65 (0x41) smb_vwv[ 5]= 0 (0x0) smb_vwv[ 6]= 256 (0x100) smb_vwv[ 7]=46336 (0xB500) smb_vwv[ 8]= 26 (0x1A) smb_vwv[ 9]=64768 (0xFD00) smb_vwv[10]=33011 (0x80F3) smb_vwv[11]=32768 (0x8000) smb_vwv[12]= 1298 (0x512) smb_vwv[13]=52663 (0xCDB7) smb_vwv[14]=51815 (0xCA67) smb_vwv[15]=50177 (0xC401) smb_vwv[16]= 2303 (0x8FF) smb_bcc=8 [2009/11/17 22:34:17, 10] ../lib/util/util.c:304(_dump_data) [0000] C4 18 5F 47 0B 86 5C 28 .._G..\( [2009/11/17 22:34:17, 10] lib/util_sock.c:789(read_smb_length_return_keepalive) got smb length of 234 [2009/11/17 22:34:17, 6] smbd/process.c:1456(process_smb) got message type 0x0 of len 0xea [2009/11/17 22:34:17, 3] smbd/process.c:1459(process_smb) Transaction 1 of length 238 (0 toread) [2009/11/17 22:34:17, 5] lib/util.c:632(show_msg) [2009/11/17 22:34:17, 5] lib/util.c:642(show_msg) size=234 smb_com=0x73 smb_rcls=0 smb_reh=0 smb_err=0 smb_flg=0 smb_flg2=53249 smb_tid=0 smb_pid=7672 smb_uid=0 smb_mid=1984 smt_wct=13 smb_vwv[ 0]= 255 (0xFF) smb_vwv[ 1]= 0 (0x0) smb_vwv[ 2]=16472 (0x4058) smb_vwv[ 3]= 50 (0x32) smb_vwv[ 4]= 0 (0x0) smb_vwv[ 5]= 0 (0x0) smb_vwv[ 6]= 0 (0x0) smb_vwv[ 7]= 24 (0x18) smb_vwv[ 8]= 24 (0x18) smb_vwv[ 9]= 0 (0x0) smb_vwv[10]= 0 (0x0) smb_vwv[11]=53468 (0xD0DC) smb_vwv[12]= 128 (0x80) smb_bcc=173 [2009/11/17 22:34:17, 10] ../lib/util/util.c:304(_dump_data) [0000] 1B 52 72 DA 96 81 98 DA A6 44 F1 BB 5B 6A FA 1B .Rr..... .D..[j.. [0010] 5A B4 A4 AB D0 F1 19 84 1B 52 72 DA 96 81 98 DA Z....... .Rr..... [0020] A6 44 F1 BB 5B 6A FA 1B 5A B4 A4 AB D0 F1 19 84 .D..[j.. Z....... [0030] 00 6A 00 6F 00 65 00 72 00 67 00 00 00 41 00 54 .j.o.e.r .g...A.T [0040] 00 65 00 4F 00 00 00 4C 00 69 00 6E 00 75 00 78 .e.O...L .i.n.u.x [0050] 00 20 00 76 00 65 00 72 00 73 00 69 00 6F 00 6E . .v.e.r .s.i.o.n [0060] 00 20 00 32 00 2E 00 36 00 2E 00 33 00 31 00 2D . .2...6 ...3.1.- [0070] 00 72 00 63 00 35 00 00 00 43 00 49 00 46 00 53 .r.c.5.. .C.I.F.S [0080] 00 20 00 56 00 46 00 53 00 20 00 43 00 6C 00 69 . .V.F.S . .C.l.i [0090] 00 65 00 6E 00 74 00 20 00 66 00 6F 00 72 00 20 .e.n.t. .f.o.r. [00A0] 00 4C 00 69 00 6E 00 75 00 78 00 00 00 .L.i.n.u .x... [2009/11/17 22:34:17, 3] smbd/process.c:1273(switch_message) switch message SMBsesssetupX (pid 6837) conn 0x0 [2009/11/17 22:34:17, 3] smbd/sec_ctx.c:310(set_sec_ctx) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0 [2009/11/17 22:34:17, 5] auth/token_util.c:522(debug_nt_user_token) NT user token: (NULL) [2009/11/17 22:34:17, 5] auth/token_util.c:548(debug_unix_user_token) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2009/11/17 22:34:17, 5] smbd/uid.c:368(change_to_root_user) change_to_root_user: now uid=(0,0) gid=(0,0) [2009/11/17 22:34:17, 3] smbd/sesssetup.c:1404(reply_sesssetup_and_X) wct=13 flg2=0xd001 [2009/11/17 22:34:17, 3] smbd/sesssetup.c:1607(reply_sesssetup_and_X) Domain=[ATeO] NativeOS=[Linux version 2.6.31-rc5] NativeLanMan=[CIFS VFS Client for Linux] PrimaryDomain=[] [2009/11/17 22:34:17, 2] smbd/sesssetup.c:1360(setup_new_vc_session) setup_new_vc_session: New VC == 0, if NT4.x compatible we would close all old resources. [2009/11/17 22:34:17, 3] smbd/sesssetup.c:1623(reply_sesssetup_and_X) sesssetupX:name=[ATeO]\[joerg]@[__ffff_10.10.10.26] [2009/11/17 22:34:17, 6] param/loadparm.c:6994(lp_file_list_changed) lp_file_list_changed() file /etc/samba/smb_perm-%a.conf -> /etc/samba/smb_perm-CIFSFS.conf last mod_time: Tue Nov 17 21:05:23 2009 file /etc/samba/smb.conf -> /etc/samba/smb.conf last mod_time: Tue Nov 17 22:33:54 2009 [2009/11/17 22:34:17, 5] auth/auth_util.c:208(make_user_info_map) Mapping user [ATeO]\[joerg] from workstation [__ffff_10.10.10.26] [2009/11/17 22:34:17, 5] auth/auth_util.c:229(make_user_info_map) Mapped domain from [ATeO] to [NEPTUN] for user [joerg] from workstation [__ffff_10.10.10.26] [2009/11/17 22:34:17, 5] auth/auth_util.c:120(make_user_info) attempting to make a user_info for joerg (joerg) [2009/11/17 22:34:17, 5] auth/auth_util.c:130(make_user_info) making strings for joerg's user_info struct [2009/11/17 22:34:17, 5] auth/auth_util.c:162(make_user_info) making blobs for joerg's user_info struct [2009/11/17 22:34:17, 10] auth/auth_util.c:180(make_user_info) made an encrypted user_info for joerg (joerg) [2009/11/17 22:34:17, 3] auth/auth.c:222(check_ntlm_password) check_ntlm_password: Checking password for unmapped user [ATeO]\[joerg]@[__ffff_10.10.10.26] with the new password interface [2009/11/17 22:34:17, 3] auth/auth.c:225(check_ntlm_password) check_ntlm_password: mapped user is: [NEPTUN]\[joerg]@[__ffff_10.10.10.26] [2009/11/17 22:34:17, 10] auth/auth.c:234(check_ntlm_password) check_ntlm_password: auth_context challenge created by random [2009/11/17 22:34:17, 10] auth/auth.c:236(check_ntlm_password) challenge is: [2009/11/17 22:34:17, 5] ../lib/util/util.c:304(_dump_data) [0000] C4 18 5F 47 0B 86 5C 28 .._G..\( [2009/11/17 22:34:17, 10] auth/auth.c:262(check_ntlm_password) check_ntlm_password: guest had nothing to say [2009/11/17 22:34:17, 8] lib/util.c:1879(is_myname) is_myname("NEPTUN") returns 1 [2009/11/17 22:34:17, 3] smbd/sec_ctx.c:210(push_sec_ctx) push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1 [2009/11/17 22:34:17, 3] smbd/uid.c:428(push_conn_ctx) push_conn_ctx(0) : conn_ctx_stack_ndx = 0 [2009/11/17 22:34:17, 3] smbd/sec_ctx.c:310(set_sec_ctx) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1 [2009/11/17 22:34:17, 5] auth/token_util.c:522(debug_nt_user_token) NT user token: (NULL) [2009/11/17 22:34:17, 5] auth/token_util.c:548(debug_unix_user_token) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2009/11/17 22:34:17, 10] passdb/pdb_get_set.c:572(pdb_set_username) pdb_set_username: setting username joerg, was [2009/11/17 22:34:17, 10] passdb/pdb_get_set.c:595(pdb_set_domain) pdb_set_domain: setting domain NEPTUN, was [2009/11/17 22:34:17, 10] passdb/pdb_get_set.c:618(pdb_set_nt_username) pdb_set_nt_username: setting nt username , was [2009/11/17 22:34:17, 10] passdb/pdb_get_set.c:641(pdb_set_fullname) pdb_set_full_name: setting full name Jörg Sommer, was [2009/11/17 22:34:17, 10] passdb/pdb_get_set.c:734(pdb_set_homedir) pdb_set_homedir: setting home dir \\cifs-homes\all-homes\joerg, was [2009/11/17 22:34:17, 10] passdb/pdb_get_set.c:710(pdb_set_dir_drive) pdb_set_dir_drive: setting dir drive , was NULL [2009/11/17 22:34:17, 10] passdb/pdb_get_set.c:664(pdb_set_logon_script) pdb_set_logon_script: setting logon script , was [2009/11/17 22:34:17, 4] lib/substitute.c:504(automount_server) Home server: neptun [2009/11/17 22:34:17, 10] passdb/pdb_get_set.c:687(pdb_set_profile_path) pdb_set_profile_path: setting profile path \\neptun\joerg\profile, was [2009/11/17 22:34:17, 10] passdb/pdb_get_set.c:777(pdb_set_workstations) pdb_set_workstations: setting workstations , was [2009/11/17 22:34:17, 3] smbd/sec_ctx.c:210(push_sec_ctx) push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 2 [2009/11/17 22:34:17, 3] smbd/uid.c:428(push_conn_ctx) push_conn_ctx(0) : conn_ctx_stack_ndx = 1 [2009/11/17 22:34:17, 3] smbd/sec_ctx.c:310(set_sec_ctx) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 2 [2009/11/17 22:34:17, 5] auth/token_util.c:522(debug_nt_user_token) NT user token: (NULL) [2009/11/17 22:34:17, 5] auth/token_util.c:548(debug_unix_user_token) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2009/11/17 22:34:17, 10] lib/account_pol.c:333(account_policy_get) account_policy_get: name: password history, val: 0 [2009/11/17 22:34:17, 3] smbd/sec_ctx.c:418(pop_sec_ctx) pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 1 [2009/11/17 22:34:17, 10] passdb/pdb_get_set.c:501(pdb_set_user_sid) pdb_set_user_sid: setting user sid S-1-5-21-3690565184-454682460-1052817659-3000 [2009/11/17 22:34:17, 10] passdb/pdb_compat.c:72(pdb_set_user_sid_from_rid) pdb_set_user_sid_from_rid: setting user sid S-1-5-21-3690565184-454682460-1052817659-3000 from rid 3000 [2009/11/17 22:34:17, 3] smbd/sec_ctx.c:210(push_sec_ctx) push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 2 [2009/11/17 22:34:17, 3] smbd/uid.c:428(push_conn_ctx) push_conn_ctx(0) : conn_ctx_stack_ndx = 1 [2009/11/17 22:34:17, 3] smbd/sec_ctx.c:310(set_sec_ctx) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 2 [2009/11/17 22:34:17, 5] auth/token_util.c:522(debug_nt_user_token) NT user token: (NULL) [2009/11/17 22:34:17, 5] auth/token_util.c:548(debug_unix_user_token) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2009/11/17 22:34:17, 10] lib/account_pol.c:333(account_policy_get) account_policy_get: name: maximum password age, val: -1 [2009/11/17 22:34:17, 3] smbd/sec_ctx.c:418(pop_sec_ctx) pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 1 [2009/11/17 22:34:17, 5] lib/username.c:133(Get_Pwnam_alloc) Finding user joerg [2009/11/17 22:34:17, 5] lib/username.c:77(Get_Pwnam_internals) Trying _Get_Pwnam(), username as lowercase is joerg [2009/11/17 22:34:17, 5] lib/username.c:110(Get_Pwnam_internals) Get_Pwnam_internals did find user [joerg]! [2009/11/17 22:34:17, 10] passdb/lookup_sid.c:953(lookup_sid) lookup_sid called for SID 'S-1-5-21-3690565184-454682460-1052817659-512' [2009/11/17 22:34:17, 10] passdb/lookup_sid.c:708(check_dom_sid_to_level) Accepting SID S-1-5-21-3690565184-454682460-1052817659 in level 1 [2009/11/17 22:34:17, 10] passdb/lookup_sid.c:468(lookup_rids) lookup_rids called for domain sid 'S-1-5-21-3690565184-454682460-1052817659' [2009/11/17 22:34:17, 3] smbd/sec_ctx.c:210(push_sec_ctx) push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 2 [2009/11/17 22:34:17, 3] smbd/uid.c:428(push_conn_ctx) push_conn_ctx(0) : conn_ctx_stack_ndx = 1 [2009/11/17 22:34:17, 3] smbd/sec_ctx.c:310(set_sec_ctx) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 2 [2009/11/17 22:34:17, 5] auth/token_util.c:522(debug_nt_user_token) NT user token: (NULL) [2009/11/17 22:34:17, 5] auth/token_util.c:548(debug_unix_user_token) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2009/11/17 22:34:17, 5] passdb/pdb_interface.c:1513(lookup_global_sam_rid) lookup_global_sam_rid: looking up RID 512. [2009/11/17 22:34:17, 3] smbd/sec_ctx.c:210(push_sec_ctx) push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 3 [2009/11/17 22:34:17, 3] smbd/uid.c:428(push_conn_ctx) push_conn_ctx(0) : conn_ctx_stack_ndx = 2 [2009/11/17 22:34:17, 3] smbd/sec_ctx.c:310(set_sec_ctx) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 3 [2009/11/17 22:34:17, 5] auth/token_util.c:522(debug_nt_user_token) NT user token: (NULL) [2009/11/17 22:34:17, 5] auth/token_util.c:548(debug_unix_user_token) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2009/11/17 22:34:17, 5] passdb/pdb_tdb.c:609(tdbsam_getsampwrid) pdb_getsampwrid (TDB): error looking up RID 512 by key RID_00000200. [2009/11/17 22:34:17, 3] smbd/sec_ctx.c:418(pop_sec_ctx) pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 2 [2009/11/17 22:34:17, 5] passdb/pdb_interface.c:1635(pdb_default_lookup_rids) lookup_rids: Administratoren:2 [2009/11/17 22:34:17, 3] smbd/sec_ctx.c:418(pop_sec_ctx) pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 1 [2009/11/17 22:34:17, 10] passdb/lookup_sid.c:988(lookup_sid) Sid S-1-5-21-3690565184-454682460-1052817659-512 -> NEPTUN\Administratoren(2) [2009/11/17 22:34:17, 3] smbd/sec_ctx.c:210(push_sec_ctx) push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 2 [2009/11/17 22:34:17, 3] smbd/uid.c:428(push_conn_ctx) push_conn_ctx(0) : conn_ctx_stack_ndx = 1 [2009/11/17 22:34:17, 3] smbd/sec_ctx.c:310(set_sec_ctx) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 2 [2009/11/17 22:34:17, 5] auth/token_util.c:522(debug_nt_user_token) NT user token: (NULL) [2009/11/17 22:34:17, 5] auth/token_util.c:548(debug_unix_user_token) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2009/11/17 22:34:17, 10] lib/account_pol.c:333(account_policy_get) account_policy_get: name: password history, val: 0 [2009/11/17 22:34:17, 3] smbd/sec_ctx.c:418(pop_sec_ctx) pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 1 [2009/11/17 22:34:17, 10] passdb/pdb_get_set.c:572(pdb_set_username) pdb_set_username: setting username joerg, was [2009/11/17 22:34:17, 10] passdb/pdb_get_set.c:595(pdb_set_domain) pdb_set_domain: setting domain NEPTUN, was [2009/11/17 22:34:17, 10] passdb/pdb_get_set.c:618(pdb_set_nt_username) pdb_set_nt_username: setting nt username , was [2009/11/17 22:34:17, 10] passdb/pdb_get_set.c:641(pdb_set_fullname) pdb_set_full_name: setting full name Jörg Sommer, was [2009/11/17 22:34:17, 10] passdb/pdb_get_set.c:734(pdb_set_homedir) pdb_set_homedir: setting home dir \\cifs-homes\all-homes\joerg, was [2009/11/17 22:34:17, 10] passdb/pdb_get_set.c:710(pdb_set_dir_drive) pdb_set_dir_drive: setting dir drive , was NULL [2009/11/17 22:34:17, 10] passdb/pdb_get_set.c:664(pdb_set_logon_script) pdb_set_logon_script: setting logon script , was [2009/11/17 22:34:17, 4] lib/substitute.c:504(automount_server) Home server: neptun [2009/11/17 22:34:17, 10] passdb/pdb_get_set.c:687(pdb_set_profile_path) pdb_set_profile_path: setting profile path \\neptun\joerg\profile, was [2009/11/17 22:34:17, 10] passdb/pdb_get_set.c:777(pdb_set_workstations) pdb_set_workstations: setting workstations , was [2009/11/17 22:34:17, 3] smbd/sec_ctx.c:210(push_sec_ctx) push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 2 [2009/11/17 22:34:17, 3] smbd/uid.c:428(push_conn_ctx) push_conn_ctx(0) : conn_ctx_stack_ndx = 1 [2009/11/17 22:34:17, 3] smbd/sec_ctx.c:310(set_sec_ctx) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 2 [2009/11/17 22:34:17, 5] auth/token_util.c:522(debug_nt_user_token) NT user token: (NULL) [2009/11/17 22:34:17, 5] auth/token_util.c:548(debug_unix_user_token) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2009/11/17 22:34:17, 10] lib/account_pol.c:333(account_policy_get) account_policy_get: name: password history, val: 0 [2009/11/17 22:34:17, 3] smbd/sec_ctx.c:418(pop_sec_ctx) pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 1 [2009/11/17 22:34:17, 10] passdb/pdb_get_set.c:501(pdb_set_user_sid) pdb_set_user_sid: setting user sid S-1-5-21-3690565184-454682460-1052817659-3000 [2009/11/17 22:34:17, 10] passdb/pdb_compat.c:72(pdb_set_user_sid_from_rid) pdb_set_user_sid_from_rid: setting user sid S-1-5-21-3690565184-454682460-1052817659-3000 from rid 3000 [2009/11/17 22:34:17, 3] smbd/sec_ctx.c:418(pop_sec_ctx) pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0 [2009/11/17 22:34:17, 9] passdb/passdb.c:2142(pdb_update_autolock_flag) pdb_update_autolock_flag: Account joerg not autolocked, no check needed [2009/11/17 22:34:17, 4] libsmb/ntlm_check.c:332(ntlm_password_check) ntlm_password_check: Checking NT MD4 password [2009/11/17 22:34:17, 4] auth/auth_sam.c:137(sam_account_ok) sam_account_ok: Checking SMB password for user joerg [2009/11/17 22:34:17, 5] auth/auth_sam.c:119(logon_hours_ok) logon_hours_ok: user joerg allowed to logon at this time (Tue Nov 17 21:34:17 2009 ) [2009/11/17 22:34:17, 3] smbd/sec_ctx.c:210(push_sec_ctx) push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1 [2009/11/17 22:34:17, 3] smbd/uid.c:428(push_conn_ctx) push_conn_ctx(0) : conn_ctx_stack_ndx = 0 [2009/11/17 22:34:17, 3] smbd/sec_ctx.c:310(set_sec_ctx) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1 [2009/11/17 22:34:17, 5] auth/token_util.c:522(debug_nt_user_token) NT user token: (NULL) [2009/11/17 22:34:17, 5] auth/token_util.c:548(debug_unix_user_token) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2009/11/17 22:34:17, 10] lib/account_pol.c:333(account_policy_get) account_policy_get: name: maximum password age, val: -1 [2009/11/17 22:34:17, 3] smbd/sec_ctx.c:418(pop_sec_ctx) pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0 [2009/11/17 22:34:17, 3] smbd/sec_ctx.c:210(push_sec_ctx) push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1 [2009/11/17 22:34:17, 3] smbd/uid.c:428(push_conn_ctx) push_conn_ctx(0) : conn_ctx_stack_ndx = 0 [2009/11/17 22:34:17, 3] smbd/sec_ctx.c:310(set_sec_ctx) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1 [2009/11/17 22:34:17, 5] auth/token_util.c:522(debug_nt_user_token) NT user token: (NULL) [2009/11/17 22:34:17, 5] auth/token_util.c:548(debug_unix_user_token) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2009/11/17 22:34:17, 10] lib/system_smbd.c:122(sys_getgrouplist) sys_getgrouplist: user [joerg] [2009/11/17 22:34:17, 10] lib/gencache.c:194(gencache_get) Cache entry with key = IDMAP/GID2SID/4 couldn't be found [2009/11/17 22:34:17, 5] passdb/lookup_sid.c:1378(gid_to_sid) gid_to_sid: winbind failed to find a sid for gid 4 [2009/11/17 22:34:17, 3] smbd/sec_ctx.c:210(push_sec_ctx) push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 2 [2009/11/17 22:34:17, 3] smbd/uid.c:428(push_conn_ctx) push_conn_ctx(0) : conn_ctx_stack_ndx = 1 [2009/11/17 22:34:17, 3] smbd/sec_ctx.c:310(set_sec_ctx) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 2 [2009/11/17 22:34:17, 5] auth/token_util.c:522(debug_nt_user_token) NT user token: (NULL) [2009/11/17 22:34:17, 5] auth/token_util.c:548(debug_unix_user_token) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2009/11/17 22:34:17, 3] smbd/sec_ctx.c:418(pop_sec_ctx) pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 1 [2009/11/17 22:34:17, 10] passdb/lookup_sid.c:1173(legacy_gid_to_sid) LEGACY: gid 4 -> sid S-1-5-21-3690565184-454682460-1052817659-512 [2009/11/17 22:34:17, 10] lib/gencache.c:194(gencache_get) Cache entry with key = IDMAP/GID2SID/100 couldn't be found [2009/11/17 22:34:17, 5] passdb/lookup_sid.c:1378(gid_to_sid) gid_to_sid: winbind failed to find a sid for gid 100 [2009/11/17 22:34:17, 3] smbd/sec_ctx.c:210(push_sec_ctx) push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 2 [2009/11/17 22:34:17, 3] smbd/uid.c:428(push_conn_ctx) push_conn_ctx(0) : conn_ctx_stack_ndx = 1 [2009/11/17 22:34:17, 3] smbd/sec_ctx.c:310(set_sec_ctx) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 2 [2009/11/17 22:34:17, 5] auth/token_util.c:522(debug_nt_user_token) NT user token: (NULL) [2009/11/17 22:34:17, 5] auth/token_util.c:548(debug_unix_user_token) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2009/11/17 22:34:17, 3] smbd/sec_ctx.c:418(pop_sec_ctx) pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 1 [2009/11/17 22:34:17, 10] passdb/lookup_sid.c:1173(legacy_gid_to_sid) LEGACY: gid 100 -> sid S-1-5-21-3690565184-454682460-1052817659-513 [2009/11/17 22:34:17, 5] auth/auth_util.c:646(make_server_info_sam) make_server_info_sam: made server info for user joerg -> joerg [2009/11/17 22:34:17, 3] smbd/sec_ctx.c:418(pop_sec_ctx) pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0 [2009/11/17 22:34:17, 3] auth/auth.c:271(check_ntlm_password) check_ntlm_password: sam authentication for user [joerg] succeeded [2009/11/17 22:34:17, 3] smbd/sec_ctx.c:210(push_sec_ctx) push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1 [2009/11/17 22:34:17, 3] smbd/uid.c:428(push_conn_ctx) push_conn_ctx(0) : conn_ctx_stack_ndx = 0 [2009/11/17 22:34:17, 3] smbd/sec_ctx.c:310(set_sec_ctx) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1 [2009/11/17 22:34:17, 5] auth/token_util.c:522(debug_nt_user_token) NT user token: (NULL) [2009/11/17 22:34:17, 5] auth/token_util.c:548(debug_unix_user_token) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2009/11/17 22:34:17, 4] auth/pampass.c:472(smb_pam_start) smb_pam_start: PAM: Init user: joerg [2009/11/17 22:34:17, 4] auth/pampass.c:489(smb_pam_start) smb_pam_start: PAM: setting rhost to: ::ffff:10.10.10.26 [2009/11/17 22:34:17, 4] auth/pampass.c:498(smb_pam_start) smb_pam_start: PAM: setting tty [2009/11/17 22:34:17, 4] auth/pampass.c:506(smb_pam_start) smb_pam_start: PAM: Init passed for user: joerg [2009/11/17 22:34:17, 4] auth/pampass.c:564(smb_pam_account) smb_pam_account: PAM: Account Management for User: joerg [2009/11/17 22:34:17, 4] auth/pampass.c:583(smb_pam_account) smb_pam_account: PAM: Account OK for User: joerg [2009/11/17 22:34:17, 4] auth/pampass.c:450(smb_pam_end) smb_pam_end: PAM: PAM_END OK. [2009/11/17 22:34:17, 3] smbd/sec_ctx.c:418(pop_sec_ctx) pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0 [2009/11/17 22:34:17, 5] auth/auth.c:297(check_ntlm_password) check_ntlm_password: PAM Account for user [joerg] succeeded [2009/11/17 22:34:17, 2] auth/auth.c:310(check_ntlm_password) check_ntlm_password: authentication for user [joerg] -> [joerg] -> [joerg] succeeded [2009/11/17 22:34:17, 5] auth/auth_util.c:2114(free_user_info) attempting to free (and zero) a user_info structure [2009/11/17 22:34:17, 10] auth/auth_util.c:2118(free_user_info) structure was created for joerg [2009/11/17 22:34:17, 10] auth/token_util.c:353(create_local_nt_token) Create local NT token for S-1-5-21-3690565184-454682460-1052817659-3000 [2009/11/17 22:34:17, 10] lib/gencache.c:194(gencache_get) Cache entry with key = IDMAP/SID2GID/S-1-5-32-544 couldn't be found [2009/11/17 22:34:17, 10] passdb/lookup_sid.c:1502(sid_to_gid) winbind failed to find a gid for sid S-1-5-32-544 [2009/11/17 22:34:17, 3] smbd/sec_ctx.c:210(push_sec_ctx) push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1 [2009/11/17 22:34:17, 3] smbd/uid.c:428(push_conn_ctx) push_conn_ctx(0) : conn_ctx_stack_ndx = 0 [2009/11/17 22:34:17, 3] smbd/sec_ctx.c:310(set_sec_ctx) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1 [2009/11/17 22:34:17, 5] auth/token_util.c:522(debug_nt_user_token) NT user token: (NULL) [2009/11/17 22:34:17, 5] auth/token_util.c:548(debug_unix_user_token) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2009/11/17 22:34:17, 3] smbd/sec_ctx.c:418(pop_sec_ctx) pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0 [2009/11/17 22:34:17, 10] passdb/lookup_sid.c:1247(legacy_sid_to_gid) LEGACY: mapping failed for sid S-1-5-32-544 [2009/11/17 22:34:17, 3] smbd/sec_ctx.c:210(push_sec_ctx) push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1 [2009/11/17 22:34:17, 3] smbd/uid.c:428(push_conn_ctx) push_conn_ctx(0) : conn_ctx_stack_ndx = 0 [2009/11/17 22:34:17, 3] smbd/sec_ctx.c:310(set_sec_ctx) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1 [2009/11/17 22:34:17, 5] auth/token_util.c:522(debug_nt_user_token) NT user token: (NULL) [2009/11/17 22:34:17, 5] auth/token_util.c:548(debug_unix_user_token) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2009/11/17 22:34:17, 3] auth/token_util.c:433(create_local_nt_token) Failed to fetch domain sid for ATEO [2009/11/17 22:34:17, 3] smbd/sec_ctx.c:418(pop_sec_ctx) pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0 [2009/11/17 22:34:17, 10] lib/gencache.c:194(gencache_get) Cache entry with key = IDMAP/SID2GID/S-1-5-32-545 couldn't be found [2009/11/17 22:34:17, 10] passdb/lookup_sid.c:1502(sid_to_gid) winbind failed to find a gid for sid S-1-5-32-545 [2009/11/17 22:34:17, 3] smbd/sec_ctx.c:210(push_sec_ctx) push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1 [2009/11/17 22:34:17, 3] smbd/uid.c:428(push_conn_ctx) push_conn_ctx(0) : conn_ctx_stack_ndx = 0 [2009/11/17 22:34:17, 3] smbd/sec_ctx.c:310(set_sec_ctx) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1 [2009/11/17 22:34:17, 5] auth/token_util.c:522(debug_nt_user_token) NT user token: (NULL) [2009/11/17 22:34:17, 5] auth/token_util.c:548(debug_unix_user_token) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2009/11/17 22:34:17, 3] smbd/sec_ctx.c:418(pop_sec_ctx) pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0 [2009/11/17 22:34:17, 10] passdb/lookup_sid.c:1247(legacy_sid_to_gid) LEGACY: mapping failed for sid S-1-5-32-545 [2009/11/17 22:34:17, 3] smbd/sec_ctx.c:210(push_sec_ctx) push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1 [2009/11/17 22:34:17, 3] smbd/uid.c:428(push_conn_ctx) push_conn_ctx(0) : conn_ctx_stack_ndx = 0 [2009/11/17 22:34:17, 3] smbd/sec_ctx.c:310(set_sec_ctx) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1 [2009/11/17 22:34:17, 5] auth/token_util.c:522(debug_nt_user_token) NT user token: (NULL) [2009/11/17 22:34:17, 5] auth/token_util.c:548(debug_unix_user_token) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2009/11/17 22:34:17, 3] auth/token_util.c:464(create_local_nt_token) Failed to fetch domain sid for ATEO [2009/11/17 22:34:17, 3] smbd/sec_ctx.c:418(pop_sec_ctx) pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0 [2009/11/17 22:34:17, 3] smbd/sec_ctx.c:210(push_sec_ctx) push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1 [2009/11/17 22:34:17, 3] smbd/uid.c:428(push_conn_ctx) push_conn_ctx(0) : conn_ctx_stack_ndx = 0 [2009/11/17 22:34:17, 3] smbd/sec_ctx.c:310(set_sec_ctx) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1 [2009/11/17 22:34:17, 5] auth/token_util.c:522(debug_nt_user_token) NT user token: (NULL) [2009/11/17 22:34:17, 5] auth/token_util.c:548(debug_unix_user_token) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2009/11/17 22:34:17, 3] smbd/sec_ctx.c:418(pop_sec_ctx) pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0 [2009/11/17 22:34:17, 3] lib/privileges.c:63(get_privileges) get_privileges: No privileges assigned to SID [S-1-5-21-3690565184-454682460-1052817659-3000] [2009/11/17 22:34:17, 3] lib/privileges.c:63(get_privileges) get_privileges: No privileges assigned to SID [S-1-5-21-3690565184-454682460-1052817659-512] [2009/11/17 22:34:17, 5] lib/privileges.c:128(get_privileges_for_sids) get_privileges_for_sids: sid = S-1-1-0 Privilege set: SE_PRIV 0x0 0x0 0x0 0x0 [2009/11/17 22:34:17, 3] lib/privileges.c:63(get_privileges) get_privileges: No privileges assigned to SID [S-1-5-2] [2009/11/17 22:34:17, 3] lib/privileges.c:63(get_privileges) get_privileges: No privileges assigned to SID [S-1-5-11] [2009/11/17 22:34:17, 3] lib/privileges.c:63(get_privileges) get_privileges: No privileges assigned to SID [S-1-5-21-3690565184-454682460-1052817659-513] [2009/11/17 22:34:17, 10] lib/gencache.c:194(gencache_get) Cache entry with key = IDMAP/SID2GID/S-1-1-0 couldn't be found [2009/11/17 22:34:17, 10] passdb/lookup_sid.c:1502(sid_to_gid) winbind failed to find a gid for sid S-1-1-0 [2009/11/17 22:34:17, 3] smbd/sec_ctx.c:210(push_sec_ctx) push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1 [2009/11/17 22:34:17, 3] smbd/uid.c:428(push_conn_ctx) push_conn_ctx(0) : conn_ctx_stack_ndx = 0 [2009/11/17 22:34:17, 3] smbd/sec_ctx.c:310(set_sec_ctx) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1 [2009/11/17 22:34:17, 5] auth/token_util.c:522(debug_nt_user_token) NT user token: (NULL) [2009/11/17 22:34:17, 5] auth/token_util.c:548(debug_unix_user_token) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2009/11/17 22:34:17, 3] smbd/sec_ctx.c:418(pop_sec_ctx) pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0 [2009/11/17 22:34:17, 10] passdb/lookup_sid.c:1247(legacy_sid_to_gid) LEGACY: mapping failed for sid S-1-1-0 [2009/11/17 22:34:17, 10] auth/auth_util.c:750(create_local_token) Could not convert SID S-1-1-0 to gid, ignoring it [2009/11/17 22:34:17, 10] lib/gencache.c:194(gencache_get) Cache entry with key = IDMAP/SID2GID/S-1-5-2 couldn't be found [2009/11/17 22:34:17, 10] passdb/lookup_sid.c:1502(sid_to_gid) winbind failed to find a gid for sid S-1-5-2 [2009/11/17 22:34:17, 3] smbd/sec_ctx.c:210(push_sec_ctx) push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1 [2009/11/17 22:34:17, 3] smbd/uid.c:428(push_conn_ctx) push_conn_ctx(0) : conn_ctx_stack_ndx = 0 [2009/11/17 22:34:17, 3] smbd/sec_ctx.c:310(set_sec_ctx) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1 [2009/11/17 22:34:17, 5] auth/token_util.c:522(debug_nt_user_token) NT user token: (NULL) [2009/11/17 22:34:17, 5] auth/token_util.c:548(debug_unix_user_token) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2009/11/17 22:34:17, 3] smbd/sec_ctx.c:418(pop_sec_ctx) pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0 [2009/11/17 22:34:17, 10] passdb/lookup_sid.c:1247(legacy_sid_to_gid) LEGACY: mapping failed for sid S-1-5-2 [2009/11/17 22:34:17, 10] auth/auth_util.c:750(create_local_token) Could not convert SID S-1-5-2 to gid, ignoring it [2009/11/17 22:34:17, 10] lib/gencache.c:194(gencache_get) Cache entry with key = IDMAP/SID2GID/S-1-5-11 couldn't be found [2009/11/17 22:34:17, 10] passdb/lookup_sid.c:1502(sid_to_gid) winbind failed to find a gid for sid S-1-5-11 [2009/11/17 22:34:17, 3] smbd/sec_ctx.c:210(push_sec_ctx) push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1 [2009/11/17 22:34:17, 3] smbd/uid.c:428(push_conn_ctx) push_conn_ctx(0) : conn_ctx_stack_ndx = 0 [2009/11/17 22:34:17, 3] smbd/sec_ctx.c:310(set_sec_ctx) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1 [2009/11/17 22:34:17, 5] auth/token_util.c:522(debug_nt_user_token) NT user token: (NULL) [2009/11/17 22:34:17, 5] auth/token_util.c:548(debug_unix_user_token) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2009/11/17 22:34:17, 3] smbd/sec_ctx.c:418(pop_sec_ctx) pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0 [2009/11/17 22:34:17, 10] passdb/lookup_sid.c:1247(legacy_sid_to_gid) LEGACY: mapping failed for sid S-1-5-11 [2009/11/17 22:34:17, 10] auth/auth_util.c:750(create_local_token) Could not convert SID S-1-5-11 to gid, ignoring it [2009/11/17 22:34:17, 10] auth/token_util.c:528(debug_nt_user_token) NT user token of user S-1-5-21-3690565184-454682460-1052817659-3000 contains 9 SIDs SID[ 0]: S-1-5-21-3690565184-454682460-1052817659-3000 SID[ 1]: S-1-5-21-3690565184-454682460-1052817659-512 SID[ 2]: S-1-1-0 SID[ 3]: S-1-5-2 SID[ 4]: S-1-5-11 SID[ 5]: S-1-5-21-3690565184-454682460-1052817659-513 SID[ 6]: S-1-22-1-1000 SID[ 7]: S-1-22-2-4 SID[ 8]: S-1-22-2-100 SE_PRIV 0x0 0x0 0x0 0x0 [2009/11/17 22:34:17, 10] auth/token_util.c:548(debug_unix_user_token) UNIX token of user 1000 Primary group is 4 and contains 2 supplementary groups Group[ 0]: 4 Group[ 1]: 100 [2009/11/17 22:34:17, 10] smbd/password.c:172(register_initial_vuid) register_initial_vuid: allocated vuid = 100 [2009/11/17 22:34:17, 10] smbd/password.c:265(register_existing_vuid) register_existing_vuid: (1000,4) joerg joerg NEPTUN guest=0 [2009/11/17 22:34:17, 3] smbd/password.c:269(register_existing_vuid) register_existing_vuid: User name: joerg Real name: Jörg Sommer [2009/11/17 22:34:17, 3] smbd/password.c:279(register_existing_vuid) register_existing_vuid: UNIX uid 1000 is UNIX user joerg, and will be vuid 100 [2009/11/17 22:34:17, 10] lib/dbwrap_tdb.c:100(db_tdb_fetch_locked) Locking key 49442F363833372F3130 [2009/11/17 22:34:17, 10] lib/dbwrap_tdb.c:129(db_tdb_fetch_locked) Allocated locked data 0x0xa4dfcf0 [2009/11/17 22:34:17, 4] auth/pampass.c:472(smb_pam_start) smb_pam_start: PAM: Init user: joerg [2009/11/17 22:34:17, 4] auth/pampass.c:489(smb_pam_start) smb_pam_start: PAM: setting rhost to: ::ffff:10.10.10.26 [2009/11/17 22:34:17, 4] auth/pampass.c:498(smb_pam_start) smb_pam_start: PAM: setting tty [2009/11/17 22:34:17, 4] auth/pampass.c:506(smb_pam_start) smb_pam_start: PAM: Init passed for user: joerg [2009/11/17 22:34:17, 4] auth/pampass.c:643(smb_internal_pam_session) smb_internal_pam_session: PAM: tty set to: smb/6837/100 [2009/11/17 22:34:17, 4] auth/pampass.c:450(smb_pam_end) smb_pam_end: PAM: PAM_END OK. [2009/11/17 22:34:17, 10] lib/dbwrap_tdb.c:42(db_tdb_record_destr) Unlocking key 49442F363833372F3130 [2009/11/17 22:34:17, 7] param/loadparm.c:9256(lp_servicenumber) lp_servicenumber: couldn't find joerg [2009/11/17 22:34:17, 3] smbd/password.c:211(register_homes_share) Adding homes service for user 'joerg' using home directory: '/home/joerg' [2009/11/17 22:34:17, 8] param/loadparm.c:6024(add_a_service) add_a_service: Creating snum = 4 for joerg [2009/11/17 22:34:17, 10] param/loadparm.c:6071(hash_a_service) hash_a_service: hashing index 4 for service name joerg [2009/11/17 22:34:17, 3] param/loadparm.c:6126(lp_add_home) adding home's share [joerg] for user 'joerg' at '/home/joerg' [2009/11/17 22:34:17, 6] param/loadparm.c:6994(lp_file_list_changed) lp_file_list_changed() file /etc/samba/smb_perm-%a.conf -> /etc/samba/smb_perm-CIFSFS.conf last mod_time: Tue Nov 17 21:05:23 2009 file /etc/samba/smb.conf -> /etc/samba/smb.conf last mod_time: Tue Nov 17 22:33:54 2009 [2009/11/17 22:34:17, 10] lib/util_sock.c:789(read_smb_length_return_keepalive) got smb length of 110 [2009/11/17 22:34:17, 6] smbd/process.c:1456(process_smb) got message type 0x0 of len 0x6e [2009/11/17 22:34:17, 3] smbd/process.c:1459(process_smb) Transaction 2 of length 114 (0 toread) [2009/11/17 22:34:17, 5] lib/util.c:632(show_msg) [2009/11/17 22:34:17, 5] lib/util.c:642(show_msg) size=110 smb_com=0x75 smb_rcls=0 smb_reh=0 smb_err=0 smb_flg=0 smb_flg2=53249 smb_tid=0 smb_pid=7672 smb_uid=100 smb_mid=1985 smt_wct=4 smb_vwv[ 0]= 255 (0xFF) smb_vwv[ 1]= 0 (0x0) smb_vwv[ 2]= 8 (0x8) smb_vwv[ 3]= 1 (0x1) smb_bcc=67 [2009/11/17 22:34:17, 10] ../lib/util/util.c:304(_dump_data) [0000] 00 5C 00 5C 00 63 00 69 00 66 00 73 00 2D 00 68 .\.\.c.i .f.s.-.h [0010] 00 6F 00 6D 00 65 00 73 00 2E 00 6E 00 65 00 74 .o.m.e.s ...n.e.t [0020] 00 2E 00 64 00 65 00 5C 00 61 00 6C 00 6C 00 2D ...d.e.\ .a.l.l.- [0030] 00 68 00 6F 00 6D 00 65 00 73 00 00 00 3F 3F 3F .h.o.m.e .s...??? [0040] 3F 3F 00 ??. [2009/11/17 22:34:17, 3] smbd/process.c:1273(switch_message) switch message SMBtconX (pid 6837) conn 0x0 [2009/11/17 22:34:17, 3] smbd/sec_ctx.c:310(set_sec_ctx) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0 [2009/11/17 22:34:17, 5] auth/token_util.c:522(debug_nt_user_token) NT user token: (NULL) [2009/11/17 22:34:17, 5] auth/token_util.c:548(debug_unix_user_token) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2009/11/17 22:34:17, 5] smbd/uid.c:368(change_to_root_user) change_to_root_user: now uid=(0,0) gid=(0,0) [2009/11/17 22:34:17, 4] smbd/reply.c:675(reply_tcon_and_X) Client requested device type [?????] for share [all-homes] [2009/11/17 22:34:17, 5] smbd/service.c:1202(make_connection) making a connection to 'normal' service all-homes [2009/11/17 22:34:17, 10] smbd/share_access.c:234(user_ok_token) user_ok_token: share all-homes is ok for unix user joerg [2009/11/17 22:34:17, 3] smbd/sec_ctx.c:210(push_sec_ctx) push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1 [2009/11/17 22:34:17, 3] smbd/uid.c:428(push_conn_ctx) push_conn_ctx(0) : conn_ctx_stack_ndx = 0 [2009/11/17 22:34:17, 3] smbd/sec_ctx.c:310(set_sec_ctx) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1 [2009/11/17 22:34:17, 5] auth/token_util.c:522(debug_nt_user_token) NT user token: (NULL) [2009/11/17 22:34:17, 5] auth/token_util.c:548(debug_unix_user_token) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2009/11/17 22:34:17, 10] lib/account_pol.c:333(account_policy_get) account_policy_get: name: maximum password age, val: -1 [2009/11/17 22:34:17, 3] smbd/sec_ctx.c:418(pop_sec_ctx) pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0 [2009/11/17 22:34:17, 3] smbd/sec_ctx.c:210(push_sec_ctx) push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1 [2009/11/17 22:34:17, 3] smbd/uid.c:428(push_conn_ctx) push_conn_ctx(0) : conn_ctx_stack_ndx = 0 [2009/11/17 22:34:17, 3] smbd/sec_ctx.c:310(set_sec_ctx) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1 [2009/11/17 22:34:17, 5] auth/token_util.c:522(debug_nt_user_token) NT user token: (NULL) [2009/11/17 22:34:17, 5] auth/token_util.c:548(debug_unix_user_token) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2009/11/17 22:34:17, 10] lib/account_pol.c:333(account_policy_get) account_policy_get: name: password history, val: 0 [2009/11/17 22:34:17, 3] smbd/sec_ctx.c:418(pop_sec_ctx) pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0 [2009/11/17 22:34:17, 10] passdb/pdb_get_set.c:572(pdb_set_username) pdb_set_username: setting username joerg, was [2009/11/17 22:34:17, 10] passdb/pdb_get_set.c:595(pdb_set_domain) pdb_set_domain: setting domain NEPTUN, was [2009/11/17 22:34:17, 10] passdb/pdb_get_set.c:618(pdb_set_nt_username) pdb_set_nt_username: setting nt username , was [2009/11/17 22:34:17, 10] passdb/pdb_get_set.c:641(pdb_set_fullname) pdb_set_full_name: setting full name Jörg Sommer, was [2009/11/17 22:34:17, 10] passdb/pdb_get_set.c:734(pdb_set_homedir) pdb_set_homedir: setting home dir \\cifs-homes\all-homes\joerg, was [2009/11/17 22:34:17, 10] passdb/pdb_get_set.c:710(pdb_set_dir_drive) pdb_set_dir_drive: setting dir drive , was NULL [2009/11/17 22:34:17, 10] passdb/pdb_get_set.c:664(pdb_set_logon_script) pdb_set_logon_script: setting logon script , was [2009/11/17 22:34:17, 4] lib/substitute.c:504(automount_server) Home server: neptun [2009/11/17 22:34:17, 10] passdb/pdb_get_set.c:687(pdb_set_profile_path) pdb_set_profile_path: setting profile path \\neptun\joerg\profile, was [2009/11/17 22:34:17, 10] passdb/pdb_get_set.c:777(pdb_set_workstations) pdb_set_workstations: setting workstations , was [2009/11/17 22:34:17, 3] smbd/sec_ctx.c:210(push_sec_ctx) push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1 [2009/11/17 22:34:17, 3] smbd/uid.c:428(push_conn_ctx) push_conn_ctx(0) : conn_ctx_stack_ndx = 0 [2009/11/17 22:34:17, 3] smbd/sec_ctx.c:310(set_sec_ctx) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1 [2009/11/17 22:34:17, 5] auth/token_util.c:522(debug_nt_user_token) NT user token: (NULL) [2009/11/17 22:34:17, 5] auth/token_util.c:548(debug_unix_user_token) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2009/11/17 22:34:17, 10] lib/account_pol.c:333(account_policy_get) account_policy_get: name: password history, val: 0 [2009/11/17 22:34:17, 3] smbd/sec_ctx.c:418(pop_sec_ctx) pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0 [2009/11/17 22:34:17, 10] passdb/pdb_get_set.c:501(pdb_set_user_sid) pdb_set_user_sid: setting user sid S-1-5-21-3690565184-454682460-1052817659-3000 [2009/11/17 22:34:17, 10] passdb/pdb_compat.c:72(pdb_set_user_sid_from_rid) pdb_set_user_sid_from_rid: setting user sid S-1-5-21-3690565184-454682460-1052817659-3000 from rid 3000 [2009/11/17 22:34:17, 5] lib/username.c:133(Get_Pwnam_alloc) Finding user joerg [2009/11/17 22:34:17, 5] lib/username.c:77(Get_Pwnam_internals) Trying _Get_Pwnam(), username as lowercase is joerg [2009/11/17 22:34:17, 5] lib/username.c:110(Get_Pwnam_internals) Get_Pwnam_internals did find user [joerg]! [2009/11/17 22:34:17, 10] smbd/service.c:162(set_conn_connectpath) set_conn_connectpath: service all-homes, connectpath = /home [2009/11/17 22:34:17, 3] smbd/service.c:807(make_connection_snum) Connect path is '/home' for service [all-homes] [2009/11/17 22:34:17, 10] lib/util_seaccess.c:58(se_map_generic) se_map_generic(): mapped mask 0x10000000 to 0x001f01ff [2009/11/17 22:34:17, 3] smbd/vfs.c:95(vfs_init_default) Initialising default vfs hooks [2009/11/17 22:34:17, 10] smbd/vfs.c:47(vfs_find_backend_entry) vfs_find_backend_entry called for /[Default VFS]/ [2009/11/17 22:34:17, 5] smbd/vfs.c:85(smb_register_vfs) Successfully added vfs backend '/[Default VFS]/' [2009/11/17 22:34:17, 10] smbd/vfs.c:47(vfs_find_backend_entry) vfs_find_backend_entry called for posixacl [2009/11/17 22:34:17, 5] smbd/vfs.c:85(smb_register_vfs) Successfully added vfs backend 'posixacl' [2009/11/17 22:34:17, 3] smbd/vfs.c:129(vfs_init_custom) Initialising custom vfs hooks from [/[Default VFS]/] [2009/11/17 22:34:17, 10] smbd/vfs.c:47(vfs_find_backend_entry) vfs_find_backend_entry called for /[Default VFS]/ Successfully loaded vfs module [/[Default VFS]/] with the new modules system [2009/11/17 22:34:17, 5] smbd/vfs.c:192(vfs_init_custom) Checking operation #0 (type 0, layer 0) Making operation type 0 opaque [module /[Default VFS]/] Accepting operation type 0 from module /[Default VFS]/ [2009/11/17 22:34:17, 5] smbd/vfs.c:192(vfs_init_custom) Checking operation #1 (type 1, layer 0) Making operation type 1 opaque [module /[Default VFS]/] Accepting operation type 1 from module /[Default VFS]/ [2009/11/17 22:34:17, 5] smbd/vfs.c:192(vfs_init_custom) Checking operation #2 (type 2, layer 0) Making operation type 2 opaque [module /[Default VFS]/] Accepting operation type 2 from module /[Default VFS]/ [2009/11/17 22:34:17, 5] smbd/vfs.c:192(vfs_init_custom) Checking operation #3 (type 3, layer 0) Making operation type 3 opaque [module /[Default VFS]/] Accepting operation type 3 from module /[Default VFS]/ [2009/11/17 22:34:17, 5] smbd/vfs.c:192(vfs_init_custom) Checking operation #4 (type 4, layer 0) Making operation type 4 opaque [module /[Default VFS]/] Accepting operation type 4 from module /[Default VFS]/ [2009/11/17 22:34:17, 5] smbd/vfs.c:192(vfs_init_custom) Checking operation #5 (type 5, layer 0) Making operation type 5 opaque [module /[Default VFS]/] Accepting operation type 5 from module /[Default VFS]/ [2009/11/17 22:34:17, 5] smbd/vfs.c:192(vfs_init_custom) Checking operation #6 (type 6, layer 0) Making operation type 6 opaque [module /[Default VFS]/] Accepting operation type 6 from module /[Default VFS]/ [2009/11/17 22:34:17, 5] smbd/vfs.c:192(vfs_init_custom) Checking operation #7 (type 7, layer 0) Making operation type 7 opaque [module /[Default VFS]/] Accepting operation type 7 from module /[Default VFS]/ [2009/11/17 22:34:17, 5] smbd/vfs.c:192(vfs_init_custom) Checking operation #8 (type 8, layer 0) Making operation type 8 opaque [module /[Default VFS]/] Accepting operation type 8 from module /[Default VFS]/ [2009/11/17 22:34:17, 5] smbd/vfs.c:192(vfs_init_custom) Checking operation #9 (type 9, layer 0) Making operation type 9 opaque [module /[Default VFS]/] Accepting operation type 9 from module /[Default VFS]/ [2009/11/17 22:34:17, 5] smbd/vfs.c:192(vfs_init_custom) Checking operation #10 (type 10, layer 0) Making operation type 10 opaque [module /[Default VFS]/] Accepting operation type 10 from module /[Default VFS]/ [2009/11/17 22:34:17, 5] smbd/vfs.c:192(vfs_init_custom) Checking operation #11 (type 11, layer 0) Making operation type 11 opaque [module /[Default VFS]/] Accepting operation type 11 from module /[Default VFS]/ [2009/11/17 22:34:17, 5] smbd/vfs.c:192(vfs_init_custom) Checking operation #12 (type 12, layer 0) Making operation type 12 opaque [module /[Default VFS]/] Accepting operation type 12 from module /[Default VFS]/ [2009/11/17 22:34:17, 5] smbd/vfs.c:192(vfs_init_custom) Checking operation #13 (type 13, layer 0) Making operation type 13 opaque [module /[Default VFS]/] Accepting operation type 13 from module /[Default VFS]/ [2009/11/17 22:34:17, 5] smbd/vfs.c:192(vfs_init_custom) Checking operation #14 (type 14, layer 0) Making operation type 14 opaque [module /[Default VFS]/] Accepting operation type 14 from module /[Default VFS]/ [2009/11/17 22:34:17, 5] smbd/vfs.c:192(vfs_init_custom) Checking operation #15 (type 15, layer 0) Making operation type 15 opaque [module /[Default VFS]/] Accepting operation type 15 from module /[Default VFS]/ [2009/11/17 22:34:17, 5] smbd/vfs.c:192(vfs_init_custom) Checking operation #16 (type 16, layer 0) Making operation type 16 opaque [module /[Default VFS]/] Accepting operation type 16 from module /[Default VFS]/ [2009/11/17 22:34:17, 5] smbd/vfs.c:192(vfs_init_custom) Checking operation #17 (type 17, layer 0) Making operation type 17 opaque [module /[Default VFS]/] Accepting operation type 17 from module /[Default VFS]/ [2009/11/17 22:34:17, 5] smbd/vfs.c:192(vfs_init_custom) Checking operation #18 (type 18, layer 0) Making operation type 18 opaque [module /[Default VFS]/] Accepting operation type 18 from module /[Default VFS]/ [2009/11/17 22:34:17, 5] smbd/vfs.c:192(vfs_init_custom) Checking operation #19 (type 19, layer 0) Making operation type 19 opaque [module /[Default VFS]/] Accepting operation type 19 from module /[Default VFS]/ [2009/11/17 22:34:17, 5] smbd/vfs.c:192(vfs_init_custom) Checking operation #20 (type 20, layer 0) Making operation type 20 opaque [module /[Default VFS]/] Accepting operation type 20 from module /[Default VFS]/ [2009/11/17 22:34:17, 5] smbd/vfs.c:192(vfs_init_custom) Checking operation #21 (type 21, layer 0) Making operation type 21 opaque [module /[Default VFS]/] Accepting operation type 21 from module /[Default VFS]/ [2009/11/17 22:34:17, 5] smbd/vfs.c:192(vfs_init_custom) Checking operation #22 (type 22, layer 0) Making operation type 22 opaque [module /[Default VFS]/] Accepting operation type 22 from module /[Default VFS]/ [2009/11/17 22:34:17, 5] smbd/vfs.c:192(vfs_init_custom) Checking operation #23 (type 23, layer 0) Making operation type 23 opaque [module /[Default VFS]/] Accepting operation type 23 from module /[Default VFS]/ [2009/11/17 22:34:17, 5] smbd/vfs.c:192(vfs_init_custom) Checking operation #24 (type 24, layer 0) Making operation type 24 opaque [module /[Default VFS]/] Accepting operation type 24 from module /[Default VFS]/ [2009/11/17 22:34:17, 5] smbd/vfs.c:192(vfs_init_custom) Checking operation #25 (type 25, layer 0) Making operation type 25 opaque [module /[Default VFS]/] Accepting operation type 25 from module /[Default VFS]/ [2009/11/17 22:34:17, 5] smbd/vfs.c:192(vfs_init_custom) Checking operation #26 (type 26, layer 0) Making operation type 26 opaque [module /[Default VFS]/] Accepting operation type 26 from module /[Default VFS]/ [2009/11/17 22:34:17, 5] smbd/vfs.c:192(vfs_init_custom) Checking operation #27 (type 27, layer 0) Making operation type 27 opaque [module /[Default VFS]/] Accepting operation type 27 from module /[Default VFS]/ [2009/11/17 22:34:17, 5] smbd/vfs.c:192(vfs_init_custom) Checking operation #28 (type 28, layer 0) Making operation type 28 opaque [module /[Default VFS]/] Accepting operation type 28 from module /[Default VFS]/ [2009/11/17 22:34:17, 5] smbd/vfs.c:192(vfs_init_custom) Checking operation #29 (type 29, layer 0) Making operation type 29 opaque [module /[Default VFS]/] Accepting operation type 29 from module /[Default VFS]/ [2009/11/17 22:34:17, 5] smbd/vfs.c:192(vfs_init_custom) Checking operation #30 (type 30, layer 0) Making operation type 30 opaque [module /[Default VFS]/] Accepting operation type 30 from module /[Default VFS]/ [2009/11/17 22:34:17, 5] smbd/vfs.c:192(vfs_init_custom) Checking operation #31 (type 31, layer 0) Making operation type 31 opaque [module /[Default VFS]/] Accepting operation type 31 from module /[Default VFS]/ [2009/11/17 22:34:17, 5] smbd/vfs.c:192(vfs_init_custom) Checking operation #32 (type 32, layer 0) Making operation type 32 opaque [module /[Default VFS]/] Accepting operation type 32 from module /[Default VFS]/ [2009/11/17 22:34:17, 5] smbd/vfs.c:192(vfs_init_custom) Checking operation #33 (type 33, layer 0) Making operation type 33 opaque [module /[Default VFS]/] Accepting operation type 33 from module /[Default VFS]/ [2009/11/17 22:34:17, 5] smbd/vfs.c:192(vfs_init_custom) Checking operation #34 (type 34, layer 0) Making operation type 34 opaque [module /[Default VFS]/] Accepting operation type 34 from module /[Default VFS]/ [2009/11/17 22:34:17, 5] smbd/vfs.c:192(vfs_init_custom) Checking operation #35 (type 35, layer 0) Making operation type 35 opaque [module /[Default VFS]/] Accepting operation type 35 from module /[Default VFS]/ [2009/11/17 22:34:17, 5] smbd/vfs.c:192(vfs_init_custom) Checking operation #36 (type 36, layer 0) Making operation type 36 opaque [module /[Default VFS]/] Accepting operation type 36 from module /[Default VFS]/ [2009/11/17 22:34:17, 5] smbd/vfs.c:192(vfs_init_custom) Checking operation #37 (type 37, layer 0) Making operation type 37 opaque [module /[Default VFS]/] Accepting operation type 37 from module /[Default VFS]/ [2009/11/17 22:34:17, 5] smbd/vfs.c:192(vfs_init_custom) Checking operation #38 (type 38, layer 0) Making operation type 38 opaque [module /[Default VFS]/] Accepting operation type 38 from module /[Default VFS]/ [2009/11/17 22:34:17, 5] smbd/vfs.c:192(vfs_init_custom) Checking operation #39 (type 39, layer 0) Making operation type 39 opaque [module /[Default VFS]/] Accepting operation type 39 from module /[Default VFS]/ [2009/11/17 22:34:17, 5] smbd/vfs.c:192(vfs_init_custom) Checking operation #40 (type 40, layer 0) Making operation type 40 opaque [module /[Default VFS]/] Accepting operation type 40 from module /[Default VFS]/ [2009/11/17 22:34:17, 5] smbd/vfs.c:192(vfs_init_custom) Checking operation #41 (type 41, layer 0) Making operation type 41 opaque [module /[Default VFS]/] Accepting operation type 41 from module /[Default VFS]/ [2009/11/17 22:34:17, 5] smbd/vfs.c:192(vfs_init_custom) Checking operation #42 (type 42, layer 0) Making operation type 42 opaque [module /[Default VFS]/] Accepting operation type 42 from module /[Default VFS]/ [2009/11/17 22:34:17, 5] smbd/vfs.c:192(vfs_init_custom) Checking operation #43 (type 43, layer 0) Making operation type 43 opaque [module /[Default VFS]/] Accepting operation type 43 from module /[Default VFS]/ [2009/11/17 22:34:17, 5] smbd/vfs.c:192(vfs_init_custom) Checking operation #44 (type 44, layer 0) Making operation type 44 opaque [module /[Default VFS]/] Accepting operation type 44 from module /[Default VFS]/ [2009/11/17 22:34:17, 5] smbd/vfs.c:192(vfs_init_custom) Checking operation #45 (type 45, layer 0) Making operation type 45 opaque [module /[Default VFS]/] Accepting operation type 45 from module /[Default VFS]/ [2009/11/17 22:34:17, 5] smbd/vfs.c:192(vfs_init_custom) Checking operation #46 (type 46, layer 0) Making operation type 46 opaque [module /[Default VFS]/] Accepting operation type 46 from module /[Default VFS]/ [2009/11/17 22:34:17, 5] smbd/vfs.c:192(vfs_init_custom) Checking operation #47 (type 47, layer 0) Making operation type 47 opaque [module /[Default VFS]/] Accepting operation type 47 from module /[Default VFS]/ [2009/11/17 22:34:17, 5] smbd/vfs.c:192(vfs_init_custom) Checking operation #48 (type 48, layer 0) Making operation type 48 opaque [module /[Default VFS]/] Accepting operation type 48 from module /[Default VFS]/ [2009/11/17 22:34:17, 5] smbd/vfs.c:192(vfs_init_custom) Checking operation #49 (type 49, layer 0) Making operation type 49 opaque [module /[Default VFS]/] Accepting operation type 49 from module /[Default VFS]/ [2009/11/17 22:34:17, 5] smbd/vfs.c:192(vfs_init_custom) Checking operation #50 (type 50, layer 0) Making operation type 50 opaque [module /[Default VFS]/] Accepting operation type 50 from module /[Default VFS]/ [2009/11/17 22:34:17, 5] smbd/vfs.c:192(vfs_init_custom) Checking operation #51 (type 51, layer 0) Making operation type 51 opaque [module /[Default VFS]/] Accepting operation type 51 from module /[Default VFS]/ [2009/11/17 22:34:17, 5] smbd/vfs.c:192(vfs_init_custom) Checking operation #52 (type 52, layer 0) Making operation type 52 opaque [module /[Default VFS]/] Accepting operation type 52 from module /[Default VFS]/ [2009/11/17 22:34:17, 5] smbd/vfs.c:192(vfs_init_custom) Checking operation #53 (type 53, layer 0) Making operation type 53 opaque [module /[Default VFS]/] Accepting operation type 53 from module /[Default VFS]/ [2009/11/17 22:34:17, 5] smbd/vfs.c:192(vfs_init_custom) Checking operation #54 (type 54, layer 0) Making operation type 54 opaque [module /[Default VFS]/] Accepting operation type 54 from module /[Default VFS]/ [2009/11/17 22:34:17, 5] smbd/vfs.c:192(vfs_init_custom) Checking operation #55 (type 55, layer 0) Making operation type 55 opaque [module /[Default VFS]/] Accepting operation type 55 from module /[Default VFS]/ [2009/11/17 22:34:17, 5] smbd/vfs.c:192(vfs_init_custom) Checking operation #56 (type 56, layer 0) Making operation type 56 opaque [module /[Default VFS]/] Accepting operation type 56 from module /[Default VFS]/ [2009/11/17 22:34:17, 5] smbd/vfs.c:192(vfs_init_custom) Checking operation #57 (type 57, layer 0) Making operation type 57 opaque [module /[Default VFS]/] Accepting operation type 57 from module /[Default VFS]/ [2009/11/17 22:34:17, 5] smbd/vfs.c:192(vfs_init_custom) Checking operation #58 (type 58, layer 0) Making operation type 58 opaque [module /[Default VFS]/] Accepting operation type 58 from module /[Default VFS]/ [2009/11/17 22:34:17, 5] smbd/vfs.c:192(vfs_init_custom) Checking operation #59 (type 59, layer 0) Making operation type 59 opaque [module /[Default VFS]/] Accepting operation type 59 from module /[Default VFS]/ [2009/11/17 22:34:17, 5] smbd/vfs.c:192(vfs_init_custom) Checking operation #60 (type 60, layer 0) Making operation type 60 opaque [module /[Default VFS]/] Accepting operation type 60 from module /[Default VFS]/ [2009/11/17 22:34:17, 5] smbd/vfs.c:192(vfs_init_custom) Checking operation #61 (type 61, layer 0) Making operation type 61 opaque [module /[Default VFS]/] Accepting operation type 61 from module /[Default VFS]/ [2009/11/17 22:34:17, 5] smbd/vfs.c:192(vfs_init_custom) Checking operation #62 (type 62, layer 0) Making operation type 62 opaque [module /[Default VFS]/] Accepting operation type 62 from module /[Default VFS]/ [2009/11/17 22:34:17, 5] smbd/vfs.c:192(vfs_init_custom) Checking operation #63 (type 63, layer 0) Making operation type 63 opaque [module /[Default VFS]/] Accepting operation type 63 from module /[Default VFS]/ [2009/11/17 22:34:17, 5] smbd/vfs.c:192(vfs_init_custom) Checking operation #64 (type 64, layer 0) Making operation type 64 opaque [module /[Default VFS]/] Accepting operation type 64 from module /[Default VFS]/ [2009/11/17 22:34:17, 5] smbd/vfs.c:192(vfs_init_custom) Checking operation #65 (type 65, layer 0) Making operation type 65 opaque [module /[Default VFS]/] Accepting operation type 65 from module /[Default VFS]/ [2009/11/17 22:34:17, 5] smbd/vfs.c:192(vfs_init_custom) Checking operation #66 (type 66, layer 0) Making operation type 66 opaque [module /[Default VFS]/] Accepting operation type 66 from module /[Default VFS]/ [2009/11/17 22:34:17, 5] smbd/vfs.c:192(vfs_init_custom) Checking operation #67 (type 67, layer 0) Making operation type 67 opaque [module /[Default VFS]/] Accepting operation type 67 from module /[Default VFS]/ [2009/11/17 22:34:17, 5] smbd/vfs.c:192(vfs_init_custom) Checking operation #68 (type 68, layer 0) Making operation type 68 opaque [module /[Default VFS]/] Accepting operation type 68 from module /[Default VFS]/ [2009/11/17 22:34:17, 5] smbd/vfs.c:192(vfs_init_custom) Checking operation #69 (type 69, layer 0) Making operation type 69 opaque [module /[Default VFS]/] Accepting operation type 69 from module /[Default VFS]/ [2009/11/17 22:34:17, 5] smbd/vfs.c:192(vfs_init_custom) Checking operation #70 (type 70, layer 0) Making operation type 70 opaque [module /[Default VFS]/] Accepting operation type 70 from module /[Default VFS]/ [2009/11/17 22:34:17, 5] smbd/vfs.c:192(vfs_init_custom) Checking operation #71 (type 71, layer 0) Making operation type 71 opaque [module /[Default VFS]/] Accepting operation type 71 from module /[Default VFS]/ [2009/11/17 22:34:17, 5] smbd/vfs.c:192(vfs_init_custom) Checking operation #72 (type 72, layer 0) Making operation type 72 opaque [module /[Default VFS]/] Accepting operation type 72 from module /[Default VFS]/ [2009/11/17 22:34:17, 5] smbd/vfs.c:192(vfs_init_custom) Checking operation #73 (type 73, layer 0) Making operation type 73 opaque [module /[Default VFS]/] Accepting operation type 73 from module /[Default VFS]/ [2009/11/17 22:34:17, 5] smbd/vfs.c:192(vfs_init_custom) Checking operation #74 (type 74, layer 0) Making operation type 74 opaque [module /[Default VFS]/] Accepting operation type 74 from module /[Default VFS]/ [2009/11/17 22:34:17, 5] smbd/vfs.c:192(vfs_init_custom) Checking operation #75 (type 75, layer 0) Making operation type 75 opaque [module /[Default VFS]/] Accepting operation type 75 from module /[Default VFS]/ [2009/11/17 22:34:17, 5] smbd/vfs.c:192(vfs_init_custom) Checking operation #76 (type 76, layer 0) Making operation type 76 opaque [module /[Default VFS]/] Accepting operation type 76 from module /[Default VFS]/ [2009/11/17 22:34:17, 5] smbd/vfs.c:192(vfs_init_custom) Checking operation #77 (type 77, layer 0) Making operation type 77 opaque [module /[Default VFS]/] Accepting operation type 77 from module /[Default VFS]/ [2009/11/17 22:34:17, 5] smbd/vfs.c:192(vfs_init_custom) Checking operation #78 (type 78, layer 0) Making operation type 78 opaque [module /[Default VFS]/] Accepting operation type 78 from module /[Default VFS]/ [2009/11/17 22:34:17, 5] smbd/vfs.c:192(vfs_init_custom) Checking operation #79 (type 79, layer 0) Making operation type 79 opaque [module /[Default VFS]/] Accepting operation type 79 from module /[Default VFS]/ [2009/11/17 22:34:17, 5] smbd/vfs.c:192(vfs_init_custom) Checking operation #80 (type 80, layer 0) Making operation type 80 opaque [module /[Default VFS]/] Accepting operation type 80 from module /[Default VFS]/ [2009/11/17 22:34:17, 5] smbd/vfs.c:192(vfs_init_custom) Checking operation #81 (type 81, layer 0) Making operation type 81 opaque [module /[Default VFS]/] Accepting operation type 81 from module /[Default VFS]/ [2009/11/17 22:34:17, 5] smbd/vfs.c:192(vfs_init_custom) Checking operation #82 (type 82, layer 0) Making operation type 82 opaque [module /[Default VFS]/] Accepting operation type 82 from module /[Default VFS]/ [2009/11/17 22:34:17, 5] smbd/vfs.c:192(vfs_init_custom) Checking operation #83 (type 83, layer 0) Making operation type 83 opaque [module /[Default VFS]/] Accepting operation type 83 from module /[Default VFS]/ [2009/11/17 22:34:17, 5] smbd/vfs.c:192(vfs_init_custom) Checking operation #84 (type 84, layer 0) Making operation type 84 opaque [module /[Default VFS]/] Accepting operation type 84 from module /[Default VFS]/ [2009/11/17 22:34:17, 5] smbd/vfs.c:192(vfs_init_custom) Checking operation #85 (type 85, layer 0) Making operation type 85 opaque [module /[Default VFS]/] Accepting operation type 85 from module /[Default VFS]/ [2009/11/17 22:34:17, 5] smbd/vfs.c:192(vfs_init_custom) Checking operation #86 (type 86, layer 0) Making operation type 86 opaque [module /[Default VFS]/] Accepting operation type 86 from module /[Default VFS]/ [2009/11/17 22:34:17, 5] smbd/vfs.c:192(vfs_init_custom) Checking operation #87 (type 87, layer 0) Making operation type 87 opaque [module /[Default VFS]/] Accepting operation type 87 from module /[Default VFS]/ [2009/11/17 22:34:17, 5] smbd/vfs.c:192(vfs_init_custom) Checking operation #88 (type 88, layer 0) Making operation type 88 opaque [module /[Default VFS]/] Accepting operation type 88 from module /[Default VFS]/ [2009/11/17 22:34:17, 5] smbd/vfs.c:192(vfs_init_custom) Checking operation #89 (type 89, layer 0) Making operation type 89 opaque [module /[Default VFS]/] Accepting operation type 89 from module /[Default VFS]/ [2009/11/17 22:34:17, 5] smbd/vfs.c:192(vfs_init_custom) Checking operation #90 (type 90, layer 0) Making operation type 90 opaque [module /[Default VFS]/] Accepting operation type 90 from module /[Default VFS]/ [2009/11/17 22:34:17, 5] smbd/vfs.c:192(vfs_init_custom) Checking operation #91 (type 91, layer 0) Making operation type 91 opaque [module /[Default VFS]/] Accepting operation type 91 from module /[Default VFS]/ [2009/11/17 22:34:17, 5] smbd/vfs.c:192(vfs_init_custom) Checking operation #92 (type 92, layer 0) Making operation type 92 opaque [module /[Default VFS]/] Accepting operation type 92 from module /[Default VFS]/ [2009/11/17 22:34:17, 5] smbd/vfs.c:192(vfs_init_custom) Checking operation #93 (type 93, layer 0) Making operation type 93 opaque [module /[Default VFS]/] Accepting operation type 93 from module /[Default VFS]/ [2009/11/17 22:34:17, 5] smbd/vfs.c:192(vfs_init_custom) Checking operation #94 (type 94, layer 0) Making operation type 94 opaque [module /[Default VFS]/] Accepting operation type 94 from module /[Default VFS]/ [2009/11/17 22:34:17, 5] smbd/vfs.c:192(vfs_init_custom) Checking operation #95 (type 95, layer 0) Making operation type 95 opaque [module /[Default VFS]/] Accepting operation type 95 from module /[Default VFS]/ [2009/11/17 22:34:17, 5] smbd/vfs.c:192(vfs_init_custom) Checking operation #96 (type 96, layer 0) Making operation type 96 opaque [module /[Default VFS]/] Accepting operation type 96 from module /[Default VFS]/ [2009/11/17 22:34:17, 5] smbd/vfs.c:192(vfs_init_custom) Checking operation #97 (type 97, layer 0) Making operation type 97 opaque [module /[Default VFS]/] Accepting operation type 97 from module /[Default VFS]/ [2009/11/17 22:34:17, 5] smbd/vfs.c:192(vfs_init_custom) Checking operation #98 (type 98, layer 0) Making operation type 98 opaque [module /[Default VFS]/] Accepting operation type 98 from module /[Default VFS]/ [2009/11/17 22:34:17, 5] smbd/vfs.c:192(vfs_init_custom) Checking operation #99 (type 99, layer 0) Making operation type 99 opaque [module /[Default VFS]/] Accepting operation type 99 from module /[Default VFS]/ [2009/11/17 22:34:17, 5] smbd/vfs.c:192(vfs_init_custom) Checking operation #100 (type 100, layer 0) Making operation type 100 opaque [module /[Default VFS]/] Accepting operation type 100 from module /[Default VFS]/ [2009/11/17 22:34:17, 5] smbd/vfs.c:192(vfs_init_custom) Checking operation #101 (type 101, layer 0) Making operation type 101 opaque [module /[Default VFS]/] Accepting operation type 101 from module /[Default VFS]/ [2009/11/17 22:34:17, 5] smbd/vfs.c:192(vfs_init_custom) Checking operation #102 (type 102, layer 0) Making operation type 102 opaque [module /[Default VFS]/] Accepting operation type 102 from module /[Default VFS]/ [2009/11/17 22:34:17, 5] smbd/vfs.c:192(vfs_init_custom) Checking operation #103 (type 103, layer 0) Making operation type 103 opaque [module /[Default VFS]/] Accepting operation type 103 from module /[Default VFS]/ [2009/11/17 22:34:17, 5] smbd/vfs.c:192(vfs_init_custom) Checking operation #104 (type 104, layer 0) Making operation type 104 opaque [module /[Default VFS]/] Accepting operation type 104 from module /[Default VFS]/ [2009/11/17 22:34:17, 5] smbd/vfs.c:192(vfs_init_custom) Checking operation #105 (type 105, layer 0) Making operation type 105 opaque [module /[Default VFS]/] Accepting operation type 105 from module /[Default VFS]/ [2009/11/17 22:34:17, 5] smbd/vfs.c:192(vfs_init_custom) Checking operation #106 (type 106, layer 0) Making operation type 106 opaque [module /[Default VFS]/] Accepting operation type 106 from module /[Default VFS]/ [2009/11/17 22:34:17, 5] smbd/vfs.c:192(vfs_init_custom) Checking operation #107 (type 107, layer 0) Making operation type 107 opaque [module /[Default VFS]/] Accepting operation type 107 from module /[Default VFS]/ [2009/11/17 22:34:17, 5] smbd/vfs.c:192(vfs_init_custom) Checking operation #108 (type 108, layer 0) Making operation type 108 opaque [module /[Default VFS]/] Accepting operation type 108 from module /[Default VFS]/ [2009/11/17 22:34:17, 5] smbd/vfs.c:192(vfs_init_custom) Checking operation #109 (type 109, layer 0) Making operation type 109 opaque [module /[Default VFS]/] Accepting operation type 109 from module /[Default VFS]/ [2009/11/17 22:34:17, 5] smbd/vfs.c:192(vfs_init_custom) Checking operation #110 (type 110, layer 0) Making operation type 110 opaque [module /[Default VFS]/] Accepting operation type 110 from module /[Default VFS]/ [2009/11/17 22:34:17, 5] smbd/connection.c:142(claim_connection) claiming [all-homes] [2009/11/17 22:34:17, 10] lib/dbwrap_tdb.c:100(db_tdb_fetch_locked) Locking key B51A0000FFFFFFFF0100 [2009/11/17 22:34:17, 10] lib/dbwrap_tdb.c:129(db_tdb_fetch_locked) Allocated locked data 0x0xa4f6cc8 [2009/11/17 22:34:17, 10] lib/dbwrap_tdb.c:42(db_tdb_record_destr) Unlocking key B51A0000FFFFFFFF0100 [2009/11/17 22:34:17, 10] smbd/share_access.c:234(user_ok_token) user_ok_token: share all-homes is ok for unix user joerg [2009/11/17 22:34:17, 10] smbd/share_access.c:279(is_share_read_only_for_token) is_share_read_only_for_user: share all-homes is read-write for unix user joerg [2009/11/17 22:34:17, 10] lib/util_seaccess.c:58(se_map_generic) se_map_generic(): mapped mask 0x10000000 to 0x001f01ff [2009/11/17 22:34:17, 10] lib/util_seaccess.c:58(se_map_generic) se_map_generic(): mapped mask 0x10000000 to 0x001f01ff [2009/11/17 22:34:17, 3] smbd/sec_ctx.c:210(push_sec_ctx) push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1 [2009/11/17 22:34:17, 3] smbd/uid.c:428(push_conn_ctx) push_conn_ctx(0) : conn_ctx_stack_ndx = 0 [2009/11/17 22:34:17, 3] smbd/sec_ctx.c:310(set_sec_ctx) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1 [2009/11/17 22:34:17, 5] auth/token_util.c:522(debug_nt_user_token) NT user token: (NULL) [2009/11/17 22:34:17, 5] auth/token_util.c:548(debug_unix_user_token) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2009/11/17 22:34:17, 10] lib/account_pol.c:333(account_policy_get) account_policy_get: name: maximum password age, val: -1 [2009/11/17 22:34:17, 3] smbd/sec_ctx.c:418(pop_sec_ctx) pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0 [2009/11/17 22:34:17, 3] smbd/sec_ctx.c:210(push_sec_ctx) push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1 [2009/11/17 22:34:17, 3] smbd/uid.c:428(push_conn_ctx) push_conn_ctx(0) : conn_ctx_stack_ndx = 0 [2009/11/17 22:34:17, 3] smbd/sec_ctx.c:310(set_sec_ctx) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1 [2009/11/17 22:34:17, 5] auth/token_util.c:522(debug_nt_user_token) NT user token: (NULL) [2009/11/17 22:34:17, 5] auth/token_util.c:548(debug_unix_user_token) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2009/11/17 22:34:17, 10] lib/account_pol.c:333(account_policy_get) account_policy_get: name: password history, val: 0 [2009/11/17 22:34:17, 3] smbd/sec_ctx.c:418(pop_sec_ctx) pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0 [2009/11/17 22:34:17, 10] passdb/pdb_get_set.c:572(pdb_set_username) pdb_set_username: setting username joerg, was [2009/11/17 22:34:17, 10] passdb/pdb_get_set.c:595(pdb_set_domain) pdb_set_domain: setting domain NEPTUN, was [2009/11/17 22:34:17, 10] passdb/pdb_get_set.c:618(pdb_set_nt_username) pdb_set_nt_username: setting nt username , was [2009/11/17 22:34:17, 10] passdb/pdb_get_set.c:641(pdb_set_fullname) pdb_set_full_name: setting full name Jörg Sommer, was [2009/11/17 22:34:17, 10] passdb/pdb_get_set.c:734(pdb_set_homedir) pdb_set_homedir: setting home dir \\cifs-homes\all-homes\joerg, was [2009/11/17 22:34:17, 10] passdb/pdb_get_set.c:710(pdb_set_dir_drive) pdb_set_dir_drive: setting dir drive , was NULL [2009/11/17 22:34:17, 10] passdb/pdb_get_set.c:664(pdb_set_logon_script) pdb_set_logon_script: setting logon script , was [2009/11/17 22:34:17, 4] lib/substitute.c:504(automount_server) Home server: neptun [2009/11/17 22:34:17, 10] passdb/pdb_get_set.c:687(pdb_set_profile_path) pdb_set_profile_path: setting profile path \\neptun\joerg\profile, was [2009/11/17 22:34:17, 10] passdb/pdb_get_set.c:777(pdb_set_workstations) pdb_set_workstations: setting workstations , was [2009/11/17 22:34:17, 3] smbd/sec_ctx.c:210(push_sec_ctx) push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1 [2009/11/17 22:34:17, 3] smbd/uid.c:428(push_conn_ctx) push_conn_ctx(0) : conn_ctx_stack_ndx = 0 [2009/11/17 22:34:17, 3] smbd/sec_ctx.c:310(set_sec_ctx) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1 [2009/11/17 22:34:17, 5] auth/token_util.c:522(debug_nt_user_token) NT user token: (NULL) [2009/11/17 22:34:17, 5] auth/token_util.c:548(debug_unix_user_token) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2009/11/17 22:34:17, 10] lib/account_pol.c:333(account_policy_get) account_policy_get: name: password history, val: 0 [2009/11/17 22:34:17, 3] smbd/sec_ctx.c:418(pop_sec_ctx) pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0 [2009/11/17 22:34:17, 10] passdb/pdb_get_set.c:501(pdb_set_user_sid) pdb_set_user_sid: setting user sid S-1-5-21-3690565184-454682460-1052817659-3000 [2009/11/17 22:34:17, 10] passdb/pdb_compat.c:72(pdb_set_user_sid_from_rid) pdb_set_user_sid_from_rid: setting user sid S-1-5-21-3690565184-454682460-1052817659-3000 from rid 3000 [2009/11/17 22:34:17, 3] smbd/sec_ctx.c:310(set_sec_ctx) setting sec ctx (1000, 4) - sec_ctx_stack_ndx = 0 [2009/11/17 22:34:17, 5] auth/token_util.c:528(debug_nt_user_token) NT user token of user S-1-5-21-3690565184-454682460-1052817659-3000 contains 9 SIDs SID[ 0]: S-1-5-21-3690565184-454682460-1052817659-3000 SID[ 1]: S-1-5-21-3690565184-454682460-1052817659-512 SID[ 2]: S-1-1-0 SID[ 3]: S-1-5-2 SID[ 4]: S-1-5-11 SID[ 5]: S-1-5-21-3690565184-454682460-1052817659-513 SID[ 6]: S-1-22-1-1000 SID[ 7]: S-1-22-2-4 SID[ 8]: S-1-22-2-100 SE_PRIV 0x0 0x0 0x0 0x0 [2009/11/17 22:34:17, 5] auth/token_util.c:548(debug_unix_user_token) UNIX token of user 1000 Primary group is 4 and contains 2 supplementary groups Group[ 0]: 4 Group[ 1]: 100 [2009/11/17 22:34:17, 5] smbd/uid.c:353(change_to_user) change_to_user uid=(0,1000) gid=(0,4) [2009/11/17 22:34:17, 1] smbd/service.c:1047(make_connection_snum) __ffff_10.10.10.26 (::ffff:10.10.10.26) connect to service all-homes initially as user joerg (uid=1000, gid=4) (pid 6837) [2009/11/17 22:34:17, 3] smbd/sec_ctx.c:310(set_sec_ctx) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0 [2009/11/17 22:34:17, 5] auth/token_util.c:522(debug_nt_user_token) NT user token: (NULL) [2009/11/17 22:34:17, 5] auth/token_util.c:548(debug_unix_user_token) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2009/11/17 22:34:17, 5] smbd/uid.c:368(change_to_root_user) change_to_root_user: now uid=(0,0) gid=(0,0) [2009/11/17 22:34:17, 3] smbd/reply.c:754(reply_tcon_and_X) tconX service=all-homes [2009/11/17 22:34:17, 10] lib/util_sock.c:789(read_smb_length_return_keepalive) got smb length of 68 [2009/11/17 22:34:17, 6] smbd/process.c:1456(process_smb) got message type 0x0 of len 0x44 [2009/11/17 22:34:17, 3] smbd/process.c:1459(process_smb) Transaction 3 of length 72 (0 toread) [2009/11/17 22:34:17, 5] lib/util.c:632(show_msg) [2009/11/17 22:34:17, 5] lib/util.c:642(show_msg) size=68 smb_com=0x32 smb_rcls=0 smb_reh=0 smb_err=0 smb_flg=0 smb_flg2=49153 smb_tid=1 smb_pid=7672 smb_uid=100 smb_mid=1986 smt_wct=15 smb_vwv[ 0]= 2 (0x2) smb_vwv[ 1]= 0 (0x0) smb_vwv[ 2]= 2 (0x2) smb_vwv[ 3]= 100 (0x64) smb_vwv[ 4]= 0 (0x0) smb_vwv[ 5]= 0 (0x0) smb_vwv[ 6]= 0 (0x0) smb_vwv[ 7]= 0 (0x0) smb_vwv[ 8]= 0 (0x0) smb_vwv[ 9]= 2 (0x2) smb_vwv[10]= 66 (0x42) smb_vwv[11]= 0 (0x0) smb_vwv[12]= 0 (0x0) smb_vwv[13]= 1 (0x1) smb_vwv[14]= 3 (0x3) smb_bcc=3 [2009/11/17 22:34:17, 10] ../lib/util/util.c:304(_dump_data) [0000] 00 00 02 ... [2009/11/17 22:34:17, 3] smbd/process.c:1273(switch_message) switch message SMBtrans2 (pid 6837) conn 0xa4eb898 [2009/11/17 22:34:17, 3] smbd/sec_ctx.c:310(set_sec_ctx) setting sec ctx (1000, 4) - sec_ctx_stack_ndx = 0 [2009/11/17 22:34:17, 5] auth/token_util.c:528(debug_nt_user_token) NT user token of user S-1-5-21-3690565184-454682460-1052817659-3000 contains 9 SIDs SID[ 0]: S-1-5-21-3690565184-454682460-1052817659-3000 SID[ 1]: S-1-5-21-3690565184-454682460-1052817659-512 SID[ 2]: S-1-1-0 SID[ 3]: S-1-5-2 SID[ 4]: S-1-5-11 SID[ 5]: S-1-5-21-3690565184-454682460-1052817659-513 SID[ 6]: S-1-22-1-1000 SID[ 7]: S-1-22-2-4 SID[ 8]: S-1-22-2-100 SE_PRIV 0x0 0x0 0x0 0x0 [2009/11/17 22:34:17, 5] auth/token_util.c:548(debug_unix_user_token) UNIX token of user 1000 Primary group is 4 and contains 2 supplementary groups Group[ 0]: 4 Group[ 1]: 100 [2009/11/17 22:34:17, 5] smbd/uid.c:353(change_to_user) change_to_user uid=(0,1000) gid=(0,4) [2009/11/17 22:34:17, 4] smbd/vfs.c:753(vfs_ChDir) vfs_ChDir to /home [2009/11/17 22:34:17, 3] smbd/trans2.c:2599(call_trans2qfsinfo) call_trans2qfsinfo: level = 512 [2009/11/17 22:34:17, 9] smbd/trans2.c:820(send_trans2_replies) t2_rep: params_sent_thistime = 0, data_sent_thistime = 12, useable_space = 16412 [2009/11/17 22:34:17, 9] smbd/trans2.c:822(send_trans2_replies) t2_rep: params_to_send = 0, data_to_send = 12, paramsize = 0, datasize = 12 [2009/11/17 22:34:17, 5] lib/util.c:632(show_msg) [2009/11/17 22:34:17, 5] lib/util.c:642(show_msg) size=68 smb_com=0x32 smb_rcls=0 smb_reh=0 smb_err=0 smb_flg=128 smb_flg2=49153 smb_tid=1 smb_pid=7672 smb_uid=100 smb_mid=1986 smt_wct=10 smb_vwv[ 0]= 0 (0x0) smb_vwv[ 1]= 12 (0xC) smb_vwv[ 2]= 0 (0x0) smb_vwv[ 3]= 0 (0x0) smb_vwv[ 4]= 56 (0x38) smb_vwv[ 5]= 0 (0x0) smb_vwv[ 6]= 12 (0xC) smb_vwv[ 7]= 56 (0x38) smb_vwv[ 8]= 0 (0x0) smb_vwv[ 9]= 0 (0x0) smb_bcc=13 [2009/11/17 22:34:17, 10] ../lib/util/util.c:304(_dump_data) [0000] 00 01 00 00 00 7B 01 00 00 00 00 00 00 .....{.. ..... [2009/11/17 22:34:17, 4] smbd/trans2.c:3128(call_trans2qfsinfo) SMBtrans2 info_level = 512 [2009/11/17 22:34:17, 10] lib/util_sock.c:789(read_smb_length_return_keepalive) got smb length of 82 [2009/11/17 22:34:17, 6] smbd/process.c:1456(process_smb) got message type 0x0 of len 0x52 [2009/11/17 22:34:17, 3] smbd/process.c:1459(process_smb) Transaction 4 of length 86 (0 toread) [2009/11/17 22:34:17, 5] lib/util.c:632(show_msg) [2009/11/17 22:34:17, 5] lib/util.c:642(show_msg) size=82 smb_com=0x32 smb_rcls=0 smb_reh=0 smb_err=0 smb_flg=0 smb_flg2=49153 smb_tid=1 smb_pid=7672 smb_uid=100 smb_mid=1987 smt_wct=15 smb_vwv[ 0]= 4 (0x4) smb_vwv[ 1]= 12 (0xC) smb_vwv[ 2]= 4 (0x4) smb_vwv[ 3]= 100 (0x64) smb_vwv[ 4]= 0 (0x0) smb_vwv[ 5]= 0 (0x0) smb_vwv[ 6]= 0 (0x0) smb_vwv[ 7]= 0 (0x0) smb_vwv[ 8]= 0 (0x0) smb_vwv[ 9]= 4 (0x4) smb_vwv[10]= 66 (0x42) smb_vwv[11]= 12 (0xC) smb_vwv[12]= 70 (0x46) smb_vwv[13]= 1 (0x1) smb_vwv[14]= 4 (0x4) smb_bcc=17 [2009/11/17 22:34:17, 10] ../lib/util/util.c:304(_dump_data) [0000] 00 00 00 00 02 01 00 00 00 5B 00 00 00 00 00 00 ........ .[...... [0010] 00 . [2009/11/17 22:34:17, 3] smbd/process.c:1273(switch_message) switch message SMBtrans2 (pid 6837) conn 0xa4eb898 [2009/11/17 22:34:17, 4] smbd/uid.c:256(change_to_user) change_to_user: Skipping user change - already user [2009/11/17 22:34:17, 10] smbd/trans2.c:3147(call_trans2setfsinfo) call_trans2setfsinfo: for service [all-homes] [2009/11/17 22:34:17, 10] smbd/trans2.c:3212(call_trans2setfsinfo) call_trans2setfsinfo: set unix info. major = 1, minor = 0 cap_low = 0x5b, cap_high = 0x0 [2009/11/17 22:34:17, 5] lib/util.c:632(show_msg) [2009/11/17 22:34:17, 5] lib/util.c:642(show_msg) size=55 smb_com=0x32 smb_rcls=0 smb_reh=0 smb_err=0 smb_flg=128 smb_flg2=49153 smb_tid=1 smb_pid=7672 smb_uid=100 smb_mid=1987 smt_wct=10 smb_vwv[ 0]= 0 (0x0) smb_vwv[ 1]= 0 (0x0) smb_vwv[ 2]= 0 (0x0) smb_vwv[ 3]= 0 (0x0) smb_vwv[ 4]= 0 (0x0) smb_vwv[ 5]= 0 (0x0) smb_vwv[ 6]= 0 (0x0) smb_vwv[ 7]= 0 (0x0) smb_vwv[ 8]= 0 (0x0) smb_vwv[ 9]= 0 (0x0) smb_bcc=0 [2009/11/17 22:34:17, 10] lib/util_sock.c:789(read_smb_length_return_keepalive) got smb length of 96 [2009/11/17 22:34:17, 6] smbd/process.c:1456(process_smb) got message type 0x0 of len 0x60 [2009/11/17 22:34:17, 3] smbd/process.c:1459(process_smb) Transaction 5 of length 100 (0 toread) [2009/11/17 22:34:17, 5] lib/util.c:632(show_msg) [2009/11/17 22:34:17, 5] lib/util.c:642(show_msg) size=96 smb_com=0x32 smb_rcls=0 smb_reh=0 smb_err=0 smb_flg=0 smb_flg2=49153 smb_tid=1 smb_pid=7672 smb_uid=100 smb_mid=1988 smt_wct=15 smb_vwv[ 0]= 30 (0x1E) smb_vwv[ 1]= 0 (0x0) smb_vwv[ 2]= 2 (0x2) smb_vwv[ 3]= 4000 (0xFA0) smb_vwv[ 4]= 0 (0x0) smb_vwv[ 5]= 0 (0x0) smb_vwv[ 6]= 0 (0x0) smb_vwv[ 7]= 0 (0x0) smb_vwv[ 8]= 0 (0x0) smb_vwv[ 9]= 30 (0x1E) smb_vwv[10]= 66 (0x42) smb_vwv[11]= 0 (0x0) smb_vwv[12]= 0 (0x0) smb_vwv[13]= 1 (0x1) smb_vwv[14]= 5 (0x5) smb_bcc=31 [2009/11/17 22:34:17, 10] ../lib/util/util.c:304(_dump_data) [0000] 00 00 02 00 00 00 00 2F 00 6A 00 6F 00 65 00 72 ......./ .j.o.e.r [0010] 00 67 00 2F 00 74 00 65 00 73 00 74 00 00 00 .g./.t.e .s.t... [2009/11/17 22:34:17, 3] smbd/process.c:1273(switch_message) switch message SMBtrans2 (pid 6837) conn 0xa4eb898 [2009/11/17 22:34:17, 4] smbd/uid.c:256(change_to_user) change_to_user: Skipping user change - already user [2009/11/17 22:34:17, 3] smbd/trans2.c:3952(call_trans2qfilepathinfo) call_trans2qfilepathinfo: TRANSACT2_QPATHINFO: level = 512 [2009/11/17 22:34:17, 5] smbd/filename.c:148(unix_convert) unix_convert called on file "joerg/test" [2009/11/17 22:34:17, 5] smbd/filename.c:297(unix_convert) conversion finished joerg/test -> joerg/test [2009/11/17 22:34:17, 10] locking/locking.c:891(fetch_share_mode_unlocked) fetch_share_mode_unlocked: no share_mode record around (file not open) [2009/11/17 22:34:17, 3] smbd/trans2.c:4066(call_trans2qfilepathinfo) call_trans2qfilepathinfo joerg/test (fnum = -1) level=512 call=5 total_data=0 [2009/11/17 22:34:17, 8] smbd/dosmode.c:474(dos_mode) dos_mode: joerg/test [2009/11/17 22:34:17, 8] smbd/dosmode.c:175(dos_mode_from_sbuf) dos_mode_from_sbuf returning [2009/11/17 22:34:17, 8] smbd/dosmode.c:521(dos_mode) dos_mode returning [2009/11/17 22:34:17, 10] smbd/trans2.c:3520(store_file_unix_basic) store_file_unix_basic: SMB_QUERY_FILE_UNIX_BASIC [2009/11/17 22:34:17, 4] smbd/trans2.c:3521(store_file_unix_basic) store_file_unix_basic: st_mode=100644 [2009/11/17 22:34:17, 4] smbd/trans2.c:4569(call_trans2qfilepathinfo) call_trans2qfilepathinfo: SMB_QUERY_FILE_UNIX_BASIC 0=6, 1=0, 2=0, 3=0, 4=0, 5=0, 6=0, 7=0, 8=0, 9=10, 10=0, 11=0, 12=0, 13=0, 14=0, 15=0, 16=ffffff80, 17=ffffffc3, 18=ffffffe0, 19=ffffff9e, 20=ffffffcc, 21=67, 22=ffffffca, 23=1, 24=ffffff80, 25=ffffffc3, 26=ffffffe0, 27=ffffff9e, 28=ffffffcc, 29=67, 30=ffffffca, 31=1, 32=ffffff80, 33=ffffffc3, 34=ffffffe0, 35=ffffff9e, 36=ffffffcc, 37=67, 38=ffffffca, 39=1, 40=ffffffe8, 41=3, 42=0, 43=0, 44=0, 45=0, 46=0, 47=0, 48=4, 49=0, 50=0, 51=0, 52=0, 53=0, 54=0, 55=0, 56=0, 57=0, 58=0, 59=0, 60=0, 61=0, 62=0, 63=0, 64=0, 65=0, 66=0, 67=0, 68=0, 69=0, 70=0, 71=0, 72=0, 73=0, 74=0, 75=0, 76=ffffffb2, 77=ffffffe4, 78=34, 79=0, 80=0, 81=0, 82=0, 83=0, 84=ffffffa4, 85=1, 86=0, 87=0, 88=0, 89=0, 90=0, 91=0, 92=1, 93=0, 94=0, 95=0, 96=0, 97=0, 98=0, 99=0, [2009/11/17 22:34:17, 9] smbd/trans2.c:820(send_trans2_replies) t2_rep: params_sent_thistime = 2, data_sent_thistime = 100, useable_space = 16410 [2009/11/17 22:34:17, 9] smbd/trans2.c:822(send_trans2_replies) t2_rep: params_to_send = 2, data_to_send = 100, paramsize = 2, datasize = 100 [2009/11/17 22:34:17, 5] lib/util.c:632(show_msg) [2009/11/17 22:34:17, 5] lib/util.c:642(show_msg) size=160 smb_com=0x32 smb_rcls=0 smb_reh=0 smb_err=0 smb_flg=128 smb_flg2=49153 smb_tid=1 smb_pid=7672 smb_uid=100 smb_mid=1988 smt_wct=10 smb_vwv[ 0]= 2 (0x2) smb_vwv[ 1]= 100 (0x64) smb_vwv[ 2]= 0 (0x0) smb_vwv[ 3]= 2 (0x2) smb_vwv[ 4]= 56 (0x38) smb_vwv[ 5]= 0 (0x0) smb_vwv[ 6]= 100 (0x64) smb_vwv[ 7]= 60 (0x3C) smb_vwv[ 8]= 0 (0x0) smb_vwv[ 9]= 0 (0x0) smb_bcc=105 [2009/11/17 22:34:17, 10] ../lib/util/util.c:304(_dump_data) [0000] 00 00 00 00 00 06 00 00 00 00 00 00 00 00 10 00 ........ ........ [0010] 00 00 00 00 00 80 C3 E0 9E CC 67 CA 01 80 C3 E0 ........ ..g..... [0020] 9E CC 67 CA 01 80 C3 E0 9E CC 67 CA 01 E8 03 00 ..g..... ..g..... [0030] 00 00 00 00 00 04 00 00 00 00 00 00 00 00 00 00 ........ ........ [0040] 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ........ ........ [0050] 00 B2 E4 34 00 00 00 00 00 A4 01 00 00 00 00 00 ...4.... ........ [0060] 00 01 00 00 00 00 00 00 00 ........ . [2009/11/17 22:34:17, 10] lib/util_sock.c:789(read_smb_length_return_keepalive) got smb length of 106 [2009/11/17 22:34:17, 6] smbd/process.c:1456(process_smb) got message type 0x0 of len 0x6a [2009/11/17 22:34:17, 3] smbd/process.c:1459(process_smb) Transaction 6 of length 110 (0 toread) [2009/11/17 22:34:17, 5] lib/util.c:632(show_msg) [2009/11/17 22:34:17, 5] lib/util.c:642(show_msg) size=106 smb_com=0x32 smb_rcls=0 smb_reh=0 smb_err=0 smb_flg=0 smb_flg2=49153 smb_tid=1 smb_pid=7672 smb_uid=100 smb_mid=1989 smt_wct=15 smb_vwv[ 0]= 30 (0x1E) smb_vwv[ 1]= 8 (0x8) smb_vwv[ 2]= 2 (0x2) smb_vwv[ 3]= 4100 (0x1004) smb_vwv[ 4]= 0 (0x0) smb_vwv[ 5]= 0 (0x0) smb_vwv[ 6]= 0 (0x0) smb_vwv[ 7]= 0 (0x0) smb_vwv[ 8]= 0 (0x0) smb_vwv[ 9]= 30 (0x1E) smb_vwv[10]= 68 (0x44) smb_vwv[11]= 8 (0x8) smb_vwv[12]= 98 (0x62) smb_vwv[13]= 1 (0x1) smb_vwv[14]= 6 (0x6) smb_bcc=41 [2009/11/17 22:34:17, 10] ../lib/util/util.c:304(_dump_data) [0000] 00 00 00 FC 03 00 00 00 00 2F 00 6A 00 6F 00 65 ........ ./.j.o.e [0010] 00 72 00 67 00 2F 00 74 00 65 00 73 00 74 00 00 .r.g./.t .e.s.t.. [0020] 00 00 00 00 00 00 00 00 00 ........ . [2009/11/17 22:34:17, 3] smbd/process.c:1273(switch_message) switch message SMBtrans2 (pid 6837) conn 0xa4eb898 [2009/11/17 22:34:17, 4] smbd/uid.c:256(change_to_user) change_to_user: Skipping user change - already user [2009/11/17 22:34:17, 5] smbd/filename.c:148(unix_convert) unix_convert called on file "joerg/test" [2009/11/17 22:34:17, 5] smbd/filename.c:297(unix_convert) conversion finished joerg/test -> joerg/test [2009/11/17 22:34:17, 3] smbd/trans2.c:6886(call_trans2setfilepathinfo) call_trans2setfilepathinfo(6) joerg/test (fnum -1) info_level=1020 totdata=8 [2009/11/17 22:34:17, 10] smbd/trans2.c:5930(smb_set_file_end_of_file_info) smb_set_file_end_of_file_info: Set end of file info for file joerg/test to 0 [2009/11/17 22:34:17, 6] smbd/trans2.c:5051(smb_set_file_size) smb_set_file_size: size: 0 smb_set_file_size: file joerg/test : setting new size to 0 [2009/11/17 22:34:17, 10] smbd/open.c:3366(create_file_default) create_file: access_mask = 0x100 file_attributes = 0x80, share_access = 0x7, create_disposition = 0x1 create_options = 0x0 oplock_request = 0x80 root_dir_fid = 0x0, ea_list = 0x(nil), sd = 0x(nil), create_file_flags = 0x0, fname = joerg/test [2009/11/17 22:34:17, 10] smbd/open.c:2896(create_file_unixpath) create_file_unixpath: access_mask = 0x100 file_attributes = 0x80, share_access = 0x7, create_disposition = 0x1 create_options = 0x0 oplock_request = 0x80 ea_list = 0x(nil), sd = 0x(nil), fname = joerg/test [2009/11/17 22:34:17, 5] smbd/files.c:103(file_new) allocated file structure 108, fnum = 4204 (1 used) [2009/11/17 22:34:17, 3] smbd/dosmode.c:135(unix_mode) unix_mode(joerg/test) returning 0666 [2009/11/17 22:34:17, 10] smbd/open.c:1475(open_file_ntcreate) open_file_ntcreate: fname=joerg/test, dos_attrs=0x80 access_mask=0x100 share_access=0x7 create_disposition = 0x1 create_options=0x0 unix mode=0666 oplock_request=128 [2009/11/17 22:34:17, 8] smbd/dosmode.c:474(dos_mode) dos_mode: joerg/test [2009/11/17 22:34:17, 8] smbd/dosmode.c:175(dos_mode_from_sbuf) dos_mode_from_sbuf returning [2009/11/17 22:34:17, 8] smbd/dosmode.c:521(dos_mode) dos_mode returning [2009/11/17 22:34:17, 10] smbd/open.c:1653(open_file_ntcreate) open_file_ntcreate: fname=joerg/test, after mapping access_mask=0x100 [2009/11/17 22:34:17, 10] lib/dbwrap_tdb.c:100(db_tdb_fetch_locked) Locking key 0503000000000000B2E4 [2009/11/17 22:34:17, 10] lib/dbwrap_tdb.c:129(db_tdb_fetch_locked) Allocated locked data 0x0xa4f5fd8 [2009/11/17 22:34:17, 10] smbd/open.c:980(delay_for_oplocks) delay_for_oplocks: oplock type 0x10 on file [2009/11/17 22:34:17, 10] smbd/open.c:980(delay_for_oplocks) delay_for_oplocks: oplock type 0x10 on file [2009/11/17 22:34:17, 4] smbd/open.c:1913(open_file_ntcreate) calling open_file with flags=0x1 flags2=0x0 mode=0666, access_mask = 0x100, open_access_mask = 0x102 [2009/11/17 22:34:17, 10] smbd/open.c:160(fd_open) fd_open: name joerg/test, flags = 01 mode = 0666, fd = 30. [2009/11/17 22:34:17, 2] smbd/open.c:580(open_file) joerg opened file joerg/test read=No write=No (numopen=1) [2009/11/17 22:34:17, 5] smbd/oplock.c:86(set_file_oplock) set_file_oplock: granted oplock on file joerg/test, 305:34e4b2:0/1, tv_sec = 4b0316d9, tv_usec = 4f4f9 [2009/11/17 22:34:17, 10] locking/locking.c:716(unparse_share_modes) unparse_share_modes: del: 0, owrt: Di 17 Nov 2009 22:26:27 CET CET cwrt: Do 01 Jan 1970 01:00:00 CET CET, tok: 0, num: 1 [2009/11/17 22:34:17, 10] locking/locking.c:518(print_share_mode_table) print_share_mode_table: share_mode_entry[0]: pid = 6837, share_access = 0x7, private_options = 0x0, access_mask = 0x180, mid = 0x0, type= 0x10, gen_id = 1, uid = 1000, flags = 0, file_id 305:34e4b2:0 [2009/11/17 22:34:17, 10] lib/dbwrap_tdb.c:42(db_tdb_record_destr) Unlocking key 0503000000000000B2E4 [2009/11/17 22:34:17, 10] smbd/open.c:3201(create_file_unixpath) create_file_unixpath: info=1 [2009/11/17 22:34:17, 10] smbd/open.c:3496(create_file_default) create_file: info=1 [2009/11/17 22:34:17, 10] lib/dbwrap_tdb.c:100(db_tdb_fetch_locked) Locking key 0503000000000000B2E4 [2009/11/17 22:34:17, 10] lib/dbwrap_tdb.c:129(db_tdb_fetch_locked) Allocated locked data 0x0xa4f64f8 [2009/11/17 22:34:17, 10] locking/locking.c:552(parse_share_modes) parse_share_modes: delete_on_close: 0, owrt: Di 17 Nov 2009 22:26:27 CET CET, cwrt: Do 01 Jan 1970 01:00:00 CET CET, tok: 0, num_share_modes: 1 [2009/11/17 22:34:17, 10] locking/locking.c:649(parse_share_modes) parse_share_modes: share_mode_entry[0]: pid = 6837, share_access = 0x7, private_options = 0x0, access_mask = 0x180, mid = 0x0, type= 0x10, gen_id = 1, uid = 1000, flags = 0, file_id 305:34e4b2:0 [2009/11/17 22:34:17, 10] smbd/oplock.c:769(contend_level2_oplocks_begin_default) release_level_2_oplocks_on_change: num_share_modes = 1 [2009/11/17 22:34:17, 10] smbd/oplock.c:792(contend_level2_oplocks_begin_default) release_level_2_oplocks_on_change: share_entry[0]->op_type == 16 [2009/11/17 22:34:17, 3] smbd/oplock.c:369(break_level2_to_none_async) process_oplock_async_level2_break_message: downgrading fake level 2 oplock. [2009/11/17 22:34:17, 10] lib/dbwrap_tdb.c:100(db_tdb_fetch_locked) Locking key 0503000000000000B2E4 [2009/11/17 22:34:17, 10] lib/dbwrap_tdb.c:129(db_tdb_fetch_locked) Allocated locked data 0x0xa4f67b8 [2009/11/17 22:34:17, 10] locking/locking.c:552(parse_share_modes) parse_share_modes: delete_on_close: 0, owrt: Di 17 Nov 2009 22:26:27 CET CET, cwrt: Do 01 Jan 1970 01:00:00 CET CET, tok: 0, num_share_modes: 1 [2009/11/17 22:34:17, 10] locking/locking.c:649(parse_share_modes) parse_share_modes: share_mode_entry[0]: pid = 6837, share_access = 0x7, private_options = 0x0, access_mask = 0x180, mid = 0x0, type= 0x10, gen_id = 1, uid = 1000, flags = 0, file_id 305:34e4b2:0 [2009/11/17 22:34:17, 10] locking/locking.c:716(unparse_share_modes) unparse_share_modes: del: 0, owrt: Di 17 Nov 2009 22:26:27 CET CET cwrt: Do 01 Jan 1970 01:00:00 CET CET, tok: 0, num: 1 [2009/11/17 22:34:17, 10] locking/locking.c:518(print_share_mode_table) print_share_mode_table: share_mode_entry[0]: pid = 6837, share_access = 0x7, private_options = 0x0, access_mask = 0x180, mid = 0x0, type= 0x0, gen_id = 1, uid = 1000, flags = 0, file_id 305:34e4b2:0 [2009/11/17 22:34:17, 10] lib/dbwrap_tdb.c:42(db_tdb_record_destr) Unlocking key 0503000000000000B2E4 [2009/11/17 22:34:17, 10] lib/dbwrap_tdb.c:42(db_tdb_record_destr) Unlocking key 0503000000000000B2E4 [2009/11/17 22:34:17, 10] smbd/vfs.c:592(vfs_set_filelen) vfs_set_filelen: ftruncate joerg/test to len 0 [2009/11/17 22:34:17, 10] smbd/notify_internal.c:593(notify_trigger) notify_trigger called action=0x3, filter=0xc, path=/home/joerg/test [2009/11/17 22:34:17, 10] smbd/notify_internal.c:177(notify_load) notify_load: [2009/11/17 22:34:17, 1] ../librpc/ndr/ndr.c:214(ndr_print_debug) notify->array: struct notify_array num_depths : 0x00000000 (0) depth: ARRAY(0) [2009/11/17 22:34:17, 5] smbd/fileio.c:236(trigger_write_time_update_immediate) Update write time immediate on joerg/test [2009/11/17 22:34:17, 5] locking/locking.c:1448(set_write_time) set_write_time: Di 17 Nov 2009 22:34:17 CET CET id=305:34e4b2:0 [2009/11/17 22:34:17, 10] lib/dbwrap_tdb.c:100(db_tdb_fetch_locked) Locking key 0503000000000000B2E4 [2009/11/17 22:34:17, 10] lib/dbwrap_tdb.c:129(db_tdb_fetch_locked) Allocated locked data 0x0xa4eac18 [2009/11/17 22:34:17, 10] locking/locking.c:552(parse_share_modes) parse_share_modes: delete_on_close: 0, owrt: Di 17 Nov 2009 22:26:27 CET CET, cwrt: Do 01 Jan 1970 01:00:00 CET CET, tok: 0, num_share_modes: 1 [2009/11/17 22:34:17, 10] locking/locking.c:649(parse_share_modes) parse_share_modes: share_mode_entry[0]: pid = 6837, share_access = 0x7, private_options = 0x0, access_mask = 0x180, mid = 0x0, type= 0x0, gen_id = 1, uid = 1000, flags = 0, file_id 305:34e4b2:0 [2009/11/17 22:34:17, 10] locking/locking.c:716(unparse_share_modes) unparse_share_modes: del: 0, owrt: Di 17 Nov 2009 22:34:17 CET CET cwrt: Do 01 Jan 1970 01:00:00 CET CET, tok: 0, num: 1 [2009/11/17 22:34:17, 10] locking/locking.c:518(print_share_mode_table) print_share_mode_table: share_mode_entry[0]: pid = 6837, share_access = 0x7, private_options = 0x0, access_mask = 0x180, mid = 0x0, type= 0x0, gen_id = 1, uid = 1000, flags = 0, file_id 305:34e4b2:0 [2009/11/17 22:34:17, 10] lib/dbwrap_tdb.c:42(db_tdb_record_destr) Unlocking key 0503000000000000B2E4 [2009/11/17 22:34:17, 10] smbd/notify_internal.c:593(notify_trigger) notify_trigger called action=0x3, filter=0x10, path=/home/joerg/test [2009/11/17 22:34:17, 10] lib/dbwrap_tdb.c:100(db_tdb_fetch_locked) Locking key 0503000000000000B2E4 [2009/11/17 22:34:17, 10] lib/dbwrap_tdb.c:129(db_tdb_fetch_locked) Allocated locked data 0x0xa4f6fa8 [2009/11/17 22:34:17, 10] locking/locking.c:552(parse_share_modes) parse_share_modes: delete_on_close: 0, owrt: Di 17 Nov 2009 22:34:17 CET CET, cwrt: Do 01 Jan 1970 01:00:00 CET CET, tok: 0, num_share_modes: 1 [2009/11/17 22:34:17, 10] locking/locking.c:649(parse_share_modes) parse_share_modes: share_mode_entry[0]: pid = 6837, share_access = 0x7, private_options = 0x0, access_mask = 0x180, mid = 0x0, type= 0x0, gen_id = 1, uid = 1000, flags = 0, file_id 305:34e4b2:0 [2009/11/17 22:34:17, 10] lib/dbwrap_tdb.c:42(db_tdb_record_destr) Unlocking key 0503000000000000B2E4 [2009/11/17 22:34:17, 10] locking/posix.c:495(get_windows_lock_ref_count) get_windows_lock_count for file joerg/test = 0 [2009/11/17 22:34:17, 10] locking/posix.c:521(delete_windows_lock_ref_count) delete_windows_lock_ref_count for file joerg/test [2009/11/17 22:34:17, 2] smbd/close.c:612(close_normal_file) joerg closed file joerg/test (numopen=0) NT_STATUS_OK [2009/11/17 22:34:17, 5] smbd/files.c:484(file_free) freed files structure 4204 (0 used) [2009/11/17 22:34:17, 9] smbd/trans2.c:820(send_trans2_replies) t2_rep: params_sent_thistime = 2, data_sent_thistime = 0, useable_space = 16412 [2009/11/17 22:34:17, 9] smbd/trans2.c:822(send_trans2_replies) t2_rep: params_to_send = 2, data_to_send = 0, paramsize = 2, datasize = 0 [2009/11/17 22:34:17, 5] lib/util.c:632(show_msg) [2009/11/17 22:34:17, 5] lib/util.c:642(show_msg) size=58 smb_com=0x32 smb_rcls=0 smb_reh=0 smb_err=0 smb_flg=128 smb_flg2=49153 smb_tid=1 smb_pid=7672 smb_uid=100 smb_mid=1989 smt_wct=10 smb_vwv[ 0]= 2 (0x2) smb_vwv[ 1]= 0 (0x0) smb_vwv[ 2]= 0 (0x0) smb_vwv[ 3]= 2 (0x2) smb_vwv[ 4]= 56 (0x38) smb_vwv[ 5]= 0 (0x0) smb_vwv[ 6]= 0 (0x0) smb_vwv[ 7]= 0 (0x0) smb_vwv[ 8]= 0 (0x0) smb_vwv[ 9]= 0 (0x0) smb_bcc=3 [2009/11/17 22:34:17, 10] ../lib/util/util.c:304(_dump_data) [0000] 00 00 00 ... [2009/11/17 22:34:17, 10] lib/util_sock.c:789(read_smb_length_return_keepalive) got smb length of 198 [2009/11/17 22:34:17, 6] smbd/process.c:1456(process_smb) got message type 0x0 of len 0xc6 [2009/11/17 22:34:17, 3] smbd/process.c:1459(process_smb) Transaction 7 of length 202 (0 toread) [2009/11/17 22:34:17, 5] lib/util.c:632(show_msg) [2009/11/17 22:34:17, 5] lib/util.c:642(show_msg) size=198 smb_com=0x32 smb_rcls=0 smb_reh=0 smb_err=0 smb_flg=0 smb_flg2=49153 smb_tid=1 smb_pid=7672 smb_uid=100 smb_mid=1990 smt_wct=15 smb_vwv[ 0]= 30 (0x1E) smb_vwv[ 1]= 100 (0x64) smb_vwv[ 2]= 2 (0x2) smb_vwv[ 3]= 1000 (0x3E8) smb_vwv[ 4]= 0 (0x0) smb_vwv[ 5]= 0 (0x0) smb_vwv[ 6]= 0 (0x0) smb_vwv[ 7]= 0 (0x0) smb_vwv[ 8]= 0 (0x0) smb_vwv[ 9]= 30 (0x1E) smb_vwv[10]= 68 (0x44) smb_vwv[11]= 100 (0x64) smb_vwv[12]= 98 (0x62) smb_vwv[13]= 1 (0x1) smb_vwv[14]= 6 (0x6) smb_bcc=133 [2009/11/17 22:34:17, 10] ../lib/util/util.c:304(_dump_data) [0000] 00 00 00 00 02 00 00 00 00 2F 00 6A 00 6F 00 65 ........ ./.j.o.e [0010] 00 72 00 67 00 2F 00 74 00 65 00 73 00 74 00 00 .r.g./.t .e.s.t.. [0020] 00 FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF ........ ........ [0030] FF 67 C9 A0 BA CD 67 CA 01 FF FF FF FF FF FF FF .g....g. ........ [0040] FF 67 C9 A0 BA CD 67 CA 01 FF FF FF FF FF FF FF .g....g. ........ [0050] FF FF FF FF FF FF FF FF FF 00 00 00 00 00 00 00 ........ ........ [0060] 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ........ ........ [0070] 00 00 00 00 00 FF FF FF FF FF FF FF FF 00 00 00 ........ ........ [0080] 00 00 00 00 00 ..... [2009/11/17 22:34:17, 3] smbd/process.c:1273(switch_message) switch message SMBtrans2 (pid 6837) conn 0xa4eb898 [2009/11/17 22:34:17, 4] smbd/uid.c:256(change_to_user) change_to_user: Skipping user change - already user [2009/11/17 22:34:17, 5] smbd/filename.c:148(unix_convert) unix_convert called on file "joerg/test" [2009/11/17 22:34:17, 5] smbd/filename.c:297(unix_convert) conversion finished joerg/test -> joerg/test [2009/11/17 22:34:17, 3] smbd/trans2.c:6886(call_trans2setfilepathinfo) call_trans2setfilepathinfo(6) joerg/test (fnum -1) info_level=512 totdata=100 [2009/11/17 22:34:17, 10] smbd/trans2.c:6093(smb_set_file_unix_basic) smb_set_file_unix_basic: SMB_SET_FILE_UNIX_BASIC: name = joerg/test size = 0, uid = 4294967295, gid = 4294967295, raw perms = 037777777777 [2009/11/17 22:34:17, 6] smbd/trans2.c:5051(smb_set_file_size) smb_set_file_size: size: 0 smb_set_filetime: actime: Tue Nov 17 22:26:27 2009 smb_set_filetime: modtime: Tue Nov 17 22:34:23 2009 smb_set_file_time: setting utimes to modified values. [2009/11/17 22:34:17, 6] smbd/dosmode.c:721(file_ntimes) file_ntime: actime: Tue Nov 17 22:26:27 2009 [2009/11/17 22:34:17, 6] smbd/dosmode.c:723(file_ntimes) file_ntime: modtime: Tue Nov 17 22:34:23 2009 [2009/11/17 22:34:17, 6] smbd/dosmode.c:725(file_ntimes) file_ntime: createtime: Thu Jan 1 01:00:00 1970 [2009/11/17 22:34:17, 10] smbd/notify_internal.c:593(notify_trigger) notify_trigger called action=0x3, filter=0x0, path=/home/joerg/test [2009/11/17 22:34:17, 10] smbd/notify_internal.c:593(notify_trigger) notify_trigger called action=0x3, filter=0x10, path=/home/joerg/test [2009/11/17 22:34:17, 9] smbd/trans2.c:820(send_trans2_replies) t2_rep: params_sent_thistime = 2, data_sent_thistime = 0, useable_space = 16412 [2009/11/17 22:34:17, 9] smbd/trans2.c:822(send_trans2_replies) t2_rep: params_to_send = 2, data_to_send = 0, paramsize = 2, datasize = 0 [2009/11/17 22:34:17, 5] lib/util.c:632(show_msg) [2009/11/17 22:34:17, 5] lib/util.c:642(show_msg) size=58 smb_com=0x32 smb_rcls=0 smb_reh=0 smb_err=0 smb_flg=128 smb_flg2=49153 smb_tid=1 smb_pid=7672 smb_uid=100 smb_mid=1990 smt_wct=10 smb_vwv[ 0]= 2 (0x2) smb_vwv[ 1]= 0 (0x0) smb_vwv[ 2]= 0 (0x0) smb_vwv[ 3]= 2 (0x2) smb_vwv[ 4]= 56 (0x38) smb_vwv[ 5]= 0 (0x0) smb_vwv[ 6]= 0 (0x0) smb_vwv[ 7]= 0 (0x0) smb_vwv[ 8]= 0 (0x0) smb_vwv[ 9]= 0 (0x0) smb_bcc=3 [2009/11/17 22:34:17, 10] ../lib/util/util.c:304(_dump_data) [0000] 00 00 00 ... [2009/11/17 22:34:17, 10] lib/util_sock.c:789(read_smb_length_return_keepalive) got smb length of 116 [2009/11/17 22:34:17, 6] smbd/process.c:1456(process_smb) got message type 0x0 of len 0x74 [2009/11/17 22:34:17, 3] smbd/process.c:1459(process_smb) Transaction 8 of length 120 (0 toread) [2009/11/17 22:34:17, 5] lib/util.c:632(show_msg) [2009/11/17 22:34:17, 5] lib/util.c:642(show_msg) size=116 smb_com=0x32 smb_rcls=0 smb_reh=0 smb_err=0 smb_flg=0 smb_flg2=49153 smb_tid=1 smb_pid=7672 smb_uid=100 smb_mid=1991 smt_wct=15 smb_vwv[ 0]= 30 (0x1E) smb_vwv[ 1]= 18 (0x12) smb_vwv[ 2]= 2 (0x2) smb_vwv[ 3]= 1000 (0x3E8) smb_vwv[ 4]= 0 (0x0) smb_vwv[ 5]= 0 (0x0) smb_vwv[ 6]= 0 (0x0) smb_vwv[ 7]= 0 (0x0) smb_vwv[ 8]= 0 (0x0) smb_vwv[ 9]= 30 (0x1E) smb_vwv[10]= 68 (0x44) smb_vwv[11]= 18 (0x12) smb_vwv[12]= 98 (0x62) smb_vwv[13]= 1 (0x1) smb_vwv[14]= 6 (0x6) smb_bcc=51 [2009/11/17 22:34:17, 10] ../lib/util/util.c:304(_dump_data) [0000] 00 00 00 09 02 00 00 00 00 2F 00 6A 00 6F 00 65 ........ ./.j.o.e [0010] 00 72 00 67 00 2F 00 74 00 65 00 73 00 74 00 00 .r.g./.t .e.s.t.. [0020] 00 00 00 00 00 02 00 00 00 ED 01 00 00 00 00 00 ........ ........ [0030] 00 00 02 ... [2009/11/17 22:34:17, 3] smbd/process.c:1273(switch_message) switch message SMBtrans2 (pid 6837) conn 0xa4eb898 [2009/11/17 22:34:17, 4] smbd/uid.c:256(change_to_user) change_to_user: Skipping user change - already user [2009/11/17 22:34:17, 5] smbd/filename.c:148(unix_convert) unix_convert called on file "joerg/test" [2009/11/17 22:34:17, 5] smbd/filename.c:297(unix_convert) conversion finished joerg/test -> joerg/test [2009/11/17 22:34:17, 3] smbd/trans2.c:6886(call_trans2setfilepathinfo) call_trans2setfilepathinfo(6) joerg/test (fnum -1) info_level=521 totdata=18 [2009/11/17 22:34:17, 10] smbd/trans2.c:6506(smb_posix_open) smb_posix_open: file joerg/test, smb_posix_flags = 0, mode 0755 [2009/11/17 22:34:17, 10] smbd/open.c:3366(create_file_default) create_file: access_mask = 0x2 file_attributes = 0x10001ed, share_access = 0x7, create_disposition = 0x1 create_options = 0x40 oplock_request = 0x0 root_dir_fid = 0x0, ea_list = 0x(nil), sd = 0x(nil), create_file_flags = 0x0, fname = joerg/test [2009/11/17 22:34:17, 10] smbd/open.c:2896(create_file_unixpath) create_file_unixpath: access_mask = 0x2 file_attributes = 0x10001ed, share_access = 0x7, create_disposition = 0x1 create_options = 0x40 oplock_request = 0x0 ea_list = 0x(nil), sd = 0x(nil), fname = joerg/test [2009/11/17 22:34:17, 5] smbd/files.c:103(file_new) allocated file structure 109, fnum = 4205 (1 used) [2009/11/17 22:34:17, 10] smbd/open.c:1475(open_file_ntcreate) open_file_ntcreate: fname=joerg/test, dos_attrs=0x0 access_mask=0x2 share_access=0x7 create_disposition = 0x1 create_options=0x40 unix mode=0755 oplock_request=0 [2009/11/17 22:34:17, 10] smbd/open.c:1653(open_file_ntcreate) open_file_ntcreate: fname=joerg/test, after mapping access_mask=0x2 [2009/11/17 22:34:17, 10] lib/dbwrap_tdb.c:100(db_tdb_fetch_locked) Locking key 0503000000000000B2E4 [2009/11/17 22:34:17, 10] lib/dbwrap_tdb.c:129(db_tdb_fetch_locked) Allocated locked data 0x0xa4f6028 [2009/11/17 22:34:17, 10] smbd/open.c:980(delay_for_oplocks) delay_for_oplocks: oplock type 0x10 on file [2009/11/17 22:34:17, 10] smbd/open.c:980(delay_for_oplocks) delay_for_oplocks: oplock type 0x10 on file [2009/11/17 22:34:17, 4] smbd/open.c:1913(open_file_ntcreate) calling open_file with flags=0x1 flags2=0x0 mode=0755, access_mask = 0x2, open_access_mask = 0x2 [2009/11/17 22:34:17, 10] smbd/open.c:160(fd_open) fd_open: name joerg/test, flags = 0400001 mode = 0755, fd = 30. [2009/11/17 22:34:17, 2] smbd/open.c:580(open_file) joerg opened file joerg/test read=No write=Yes (numopen=1) [2009/11/17 22:34:17, 5] smbd/oplock.c:86(set_file_oplock) set_file_oplock: granted oplock on file joerg/test, 305:34e4b2:0/2, tv_sec = 4b0316d9, tv_usec = 54669 [2009/11/17 22:34:17, 10] locking/locking.c:716(unparse_share_modes) unparse_share_modes: del: 0, owrt: Di 17 Nov 2009 22:34:23 CET CET cwrt: Do 01 Jan 1970 01:00:00 CET CET, tok: 0, num: 1 [2009/11/17 22:34:17, 10] locking/locking.c:518(print_share_mode_table) print_share_mode_table: share_mode_entry[0]: pid = 6837, share_access = 0x7, private_options = 0x40, access_mask = 0x82, mid = 0x0, type= 0x10, gen_id = 2, uid = 1000, flags = 1, file_id 305:34e4b2:0 [2009/11/17 22:34:17, 10] lib/dbwrap_tdb.c:42(db_tdb_record_destr) Unlocking key 0503000000000000B2E4 [2009/11/17 22:34:17, 10] smbd/open.c:3201(create_file_unixpath) create_file_unixpath: info=1 [2009/11/17 22:34:17, 10] smbd/open.c:3496(create_file_default) create_file: info=1 [2009/11/17 22:34:17, 10] smbd/trans2.c:3520(store_file_unix_basic) store_file_unix_basic: SMB_QUERY_FILE_UNIX_BASIC [2009/11/17 22:34:17, 4] smbd/trans2.c:3521(store_file_unix_basic) store_file_unix_basic: st_mode=100644 [2009/11/17 22:34:17, 9] smbd/trans2.c:820(send_trans2_replies) t2_rep: params_sent_thistime = 2, data_sent_thistime = 112, useable_space = 16410 [2009/11/17 22:34:17, 9] smbd/trans2.c:822(send_trans2_replies) t2_rep: params_to_send = 2, data_to_send = 112, paramsize = 2, datasize = 112 [2009/11/17 22:34:17, 5] lib/util.c:632(show_msg) [2009/11/17 22:34:17, 5] lib/util.c:642(show_msg) size=172 smb_com=0x32 smb_rcls=0 smb_reh=0 smb_err=0 smb_flg=128 smb_flg2=49153 smb_tid=1 smb_pid=7672 smb_uid=100 smb_mid=1991 smt_wct=10 smb_vwv[ 0]= 2 (0x2) smb_vwv[ 1]= 112 (0x70) smb_vwv[ 2]= 0 (0x0) smb_vwv[ 3]= 2 (0x2) smb_vwv[ 4]= 56 (0x38) smb_vwv[ 5]= 0 (0x0) smb_vwv[ 6]= 112 (0x70) smb_vwv[ 7]= 60 (0x3C) smb_vwv[ 8]= 0 (0x0) smb_vwv[ 9]= 0 (0x0) smb_bcc=117 [2009/11/17 22:34:17, 10] ../lib/util/util.c:304(_dump_data) [0000] 00 00 00 00 00 00 00 6D 10 01 00 00 00 00 02 00 .......m ........ [0010] 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ........ ........ [0020] 00 80 12 05 B7 CD 67 CA 01 80 C3 E0 9E CC 67 CA ......g. ......g. [0030] 01 80 99 98 BA CD 67 CA 01 E8 03 00 00 00 00 00 ......g. ........ [0040] 00 04 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ........ ........ [0050] 00 00 00 00 00 00 00 00 00 00 00 00 00 B2 E4 34 ........ .......4 [0060] 00 00 00 00 00 A4 01 00 00 00 00 00 00 01 00 00 ........ ........ [0070] 00 00 00 00 00 ..... [2009/11/17 22:34:17, 10] lib/util_sock.c:789(read_smb_length_return_keepalive) got smb length of 66 [2009/11/17 22:34:17, 6] smbd/process.c:1456(process_smb) got message type 0x0 of len 0x42 [2009/11/17 22:34:17, 3] smbd/process.c:1459(process_smb) Transaction 9 of length 70 (0 toread) [2009/11/17 22:34:17, 5] lib/util.c:632(show_msg) [2009/11/17 22:34:17, 5] lib/util.c:642(show_msg) size=66 smb_com=0x2f smb_rcls=0 smb_reh=0 smb_err=0 smb_flg=0 smb_flg2=49153 smb_tid=1 smb_pid=7672 smb_uid=100 smb_mid=1992 smt_wct=14 smb_vwv[ 0]= 255 (0xFF) smb_vwv[ 1]= 0 (0x0) smb_vwv[ 2]= 4205 (0x106D) smb_vwv[ 3]= 0 (0x0) smb_vwv[ 4]= 0 (0x0) smb_vwv[ 5]=65535 (0xFFFF) smb_vwv[ 6]=65535 (0xFFFF) smb_vwv[ 7]= 0 (0x0) smb_vwv[ 8]= 0 (0x0) smb_vwv[ 9]= 0 (0x0) smb_vwv[10]= 2 (0x2) smb_vwv[11]= 64 (0x40) smb_vwv[12]= 0 (0x0) smb_vwv[13]= 0 (0x0) smb_bcc=3 [2009/11/17 22:34:17, 10] ../lib/util/util.c:304(_dump_data) [0000] 00 31 0A .1. [2009/11/17 22:34:17, 3] smbd/process.c:1273(switch_message) switch message SMBwriteX (pid 6837) conn 0xa4eb898 [2009/11/17 22:34:17, 4] smbd/uid.c:256(change_to_user) change_to_user: Skipping user change - already user [2009/11/17 22:34:17, 10] lib/dbwrap_tdb.c:100(db_tdb_fetch_locked) Locking key 0503000000000000B2E4 [2009/11/17 22:34:17, 10] lib/dbwrap_tdb.c:129(db_tdb_fetch_locked) Allocated locked data 0x0xa4f5e58 [2009/11/17 22:34:17, 10] locking/brlock.c:1778(brl_get_locks_internal) brl_get_locks_internal: 0 current locks on file_id 305:34e4b2:0 [2009/11/17 22:34:17, 10] lib/dbwrap_tdb.c:42(db_tdb_record_destr) Unlocking key 0503000000000000B2E4 [2009/11/17 22:34:17, 10] locking/locking.c:152(strict_lock_default) strict_lock_default: flavour = POSIX_LOCK brl start=0 len=2 unlocked for fnum 4205 file joerg/test [2009/11/17 22:34:17, 10] lib/events.c:287(s3_event_debug) s3_event: Added timed event "update_write_time_handler": 0xa4e63f0 [2009/11/17 22:34:17, 8] smbd/dosmode.c:474(dos_mode) dos_mode: joerg/test [2009/11/17 22:34:17, 8] smbd/dosmode.c:175(dos_mode_from_sbuf) dos_mode_from_sbuf returning [2009/11/17 22:34:17, 8] smbd/dosmode.c:521(dos_mode) dos_mode returning [2009/11/17 22:34:17, 10] lib/dbwrap_tdb.c:100(db_tdb_fetch_locked) Locking key 0503000000000000B2E4 [2009/11/17 22:34:17, 10] lib/dbwrap_tdb.c:129(db_tdb_fetch_locked) Allocated locked data 0x0xa4f6038 [2009/11/17 22:34:17, 10] locking/locking.c:552(parse_share_modes) parse_share_modes: delete_on_close: 0, owrt: Di 17 Nov 2009 22:34:23 CET CET, cwrt: Do 01 Jan 1970 01:00:00 CET CET, tok: 0, num_share_modes: 1 [2009/11/17 22:34:17, 10] locking/locking.c:649(parse_share_modes) parse_share_modes: share_mode_entry[0]: pid = 6837, share_access = 0x7, private_options = 0x40, access_mask = 0x82, mid = 0x0, type= 0x10, gen_id = 2, uid = 1000, flags = 1, file_id 305:34e4b2:0 [2009/11/17 22:34:17, 10] smbd/oplock.c:769(contend_level2_oplocks_begin_default) release_level_2_oplocks_on_change: num_share_modes = 1 [2009/11/17 22:34:17, 10] smbd/oplock.c:792(contend_level2_oplocks_begin_default) release_level_2_oplocks_on_change: share_entry[0]->op_type == 16 [2009/11/17 22:34:17, 3] smbd/oplock.c:369(break_level2_to_none_async) process_oplock_async_level2_break_message: downgrading fake level 2 oplock. [2009/11/17 22:34:17, 10] lib/dbwrap_tdb.c:100(db_tdb_fetch_locked) Locking key 0503000000000000B2E4 [2009/11/17 22:34:17, 10] lib/dbwrap_tdb.c:129(db_tdb_fetch_locked) Allocated locked data 0x0xa4f62f8 [2009/11/17 22:34:17, 10] locking/locking.c:552(parse_share_modes) parse_share_modes: delete_on_close: 0, owrt: Di 17 Nov 2009 22:34:23 CET CET, cwrt: Do 01 Jan 1970 01:00:00 CET CET, tok: 0, num_share_modes: 1 [2009/11/17 22:34:17, 10] locking/locking.c:649(parse_share_modes) parse_share_modes: share_mode_entry[0]: pid = 6837, share_access = 0x7, private_options = 0x40, access_mask = 0x82, mid = 0x0, type= 0x10, gen_id = 2, uid = 1000, flags = 1, file_id 305:34e4b2:0 [2009/11/17 22:34:17, 10] locking/locking.c:716(unparse_share_modes) unparse_share_modes: del: 0, owrt: Di 17 Nov 2009 22:34:23 CET CET cwrt: Do 01 Jan 1970 01:00:00 CET CET, tok: 0, num: 1 [2009/11/17 22:34:17, 10] locking/locking.c:518(print_share_mode_table) print_share_mode_table: share_mode_entry[0]: pid = 6837, share_access = 0x7, private_options = 0x40, access_mask = 0x82, mid = 0x0, type= 0x0, gen_id = 2, uid = 1000, flags = 1, file_id 305:34e4b2:0 [2009/11/17 22:34:17, 10] lib/dbwrap_tdb.c:42(db_tdb_record_destr) Unlocking key 0503000000000000B2E4 [2009/11/17 22:34:17, 10] lib/dbwrap_tdb.c:42(db_tdb_record_destr) Unlocking key 0503000000000000B2E4 [2009/11/17 22:34:17, 10] smbd/fileio.c:138(real_write_file) real_write_file (joerg/test): pos = 0, size = 2, returned 2 [2009/11/17 22:34:17, 3] smbd/reply.c:4239(reply_write_and_X) writeX fnum=4205 num=2 wrote=2 [2009/11/17 22:34:17, 10] lib/util_sock.c:789(read_smb_length_return_keepalive) got smb length of 41 [2009/11/17 22:34:17, 6] smbd/process.c:1456(process_smb) got message type 0x0 of len 0x29 [2009/11/17 22:34:17, 3] smbd/process.c:1459(process_smb) Transaction 10 of length 45 (0 toread) [2009/11/17 22:34:17, 5] lib/util.c:632(show_msg) [2009/11/17 22:34:17, 5] lib/util.c:642(show_msg) size=41 smb_com=0x4 smb_rcls=0 smb_reh=0 smb_err=0 smb_flg=0 smb_flg2=49153 smb_tid=1 smb_pid=7672 smb_uid=100 smb_mid=1993 smt_wct=3 smb_vwv[ 0]= 4205 (0x106D) smb_vwv[ 1]=65535 (0xFFFF) smb_vwv[ 2]=65535 (0xFFFF) smb_bcc=0 [2009/11/17 22:34:17, 3] smbd/process.c:1273(switch_message) switch message SMBclose (pid 6837) conn 0xa4eb898 [2009/11/17 22:34:17, 4] smbd/uid.c:256(change_to_user) change_to_user: Skipping user change - already user [2009/11/17 22:34:17, 3] smbd/reply.c:4456(reply_close) close fd=30 fnum=4205 (numopen=1) [2009/11/17 22:34:17, 6] smbd/close.c:454(set_close_write_time) close_write_time: Thu Jan 1 00:59:59 1970 [2009/11/17 22:34:17, 10] lib/dbwrap_tdb.c:100(db_tdb_fetch_locked) Locking key 0503000000000000B2E4 [2009/11/17 22:34:17, 10] lib/dbwrap_tdb.c:129(db_tdb_fetch_locked) Allocated locked data 0x0xa4f5e58 [2009/11/17 22:34:17, 10] locking/locking.c:552(parse_share_modes) parse_share_modes: delete_on_close: 0, owrt: Di 17 Nov 2009 22:34:23 CET CET, cwrt: Do 01 Jan 1970 01:00:00 CET CET, tok: 0, num_share_modes: 1 [2009/11/17 22:34:17, 10] locking/locking.c:649(parse_share_modes) parse_share_modes: share_mode_entry[0]: pid = 6837, share_access = 0x7, private_options = 0x40, access_mask = 0x82, mid = 0x0, type= 0x0, gen_id = 2, uid = 1000, flags = 1, file_id 305:34e4b2:0 [2009/11/17 22:34:17, 10] lib/dbwrap_tdb.c:42(db_tdb_record_destr) Unlocking key 0503000000000000B2E4 [2009/11/17 22:34:17, 10] locking/posix.c:495(get_windows_lock_ref_count) get_windows_lock_count for file joerg/test = 0 [2009/11/17 22:34:17, 10] locking/posix.c:521(delete_windows_lock_ref_count) delete_windows_lock_ref_count for file joerg/test [2009/11/17 22:34:17, 5] smbd/trans2.c:4922(smb_set_file_time) smb_set_filetime: actime: Tue Nov 17 22:26:27 2009 smb_set_filetime: modtime: Tue Nov 17 22:34:17 2009 smb_set_file_time: setting pending modtime to Tue Nov 17 22:34:17 2009 [2009/11/17 22:34:17, 10] lib/events.c:287(s3_event_debug) s3_event: Destroying timer event 0xa4e63f0 "update_write_time_handler" [2009/11/17 22:34:17, 5] locking/locking.c:1425(set_sticky_write_time) set_sticky_write_time: Di 17 Nov 2009 22:34:17 CET CET id=305:34e4b2:0 [2009/11/17 22:34:17, 10] lib/dbwrap_tdb.c:100(db_tdb_fetch_locked) Locking key 0503000000000000B2E4 [2009/11/17 22:34:17, 10] lib/dbwrap_tdb.c:129(db_tdb_fetch_locked) Allocated locked data 0x0xa4eb1f0 [2009/11/17 22:34:17, 3] locking/locking.c:858(get_share_mode_lock) fill_share_mode_lock failed [2009/11/17 22:34:17, 10] lib/dbwrap_tdb.c:42(db_tdb_record_destr) Unlocking key 0503000000000000B2E4 [2009/11/17 22:34:17, 10] smbd/trans2.c:4972(smb_set_file_time) smb_set_file_time: setting utimes to modified values. [2009/11/17 22:34:17, 6] smbd/dosmode.c:721(file_ntimes) file_ntime: actime: Tue Nov 17 22:26:27 2009 [2009/11/17 22:34:17, 6] smbd/dosmode.c:723(file_ntimes) file_ntime: modtime: Tue Nov 17 22:34:17 2009 [2009/11/17 22:34:17, 6] smbd/dosmode.c:725(file_ntimes) file_ntime: createtime: Thu Jan 1 01:00:00 1970 [2009/11/17 22:34:17, 10] smbd/notify_internal.c:593(notify_trigger) notify_trigger called action=0x3, filter=0x10, path=/home/joerg/test [2009/11/17 22:34:17, 2] smbd/close.c:612(close_normal_file) joerg closed file joerg/test (numopen=0) NT_STATUS_OK [2009/11/17 22:34:17, 5] smbd/files.c:484(file_free) freed files structure 4205 (0 used) [2009/11/17 22:34:17, 5] lib/util.c:632(show_msg) [2009/11/17 22:34:17, 5] lib/util.c:642(show_msg) size=35 smb_com=0x4 smb_rcls=0 smb_reh=0 smb_err=0 smb_flg=128 smb_flg2=49153 smb_tid=1 smb_pid=7672 smb_uid=100 smb_mid=1993 smt_wct=0 smb_bcc=0 [2009/11/17 22:34:17, 10] lib/util_sock.c:789(read_smb_length_return_keepalive) got smb length of 116 [2009/11/17 22:34:17, 6] smbd/process.c:1456(process_smb) got message type 0x0 of len 0x74 [2009/11/17 22:34:17, 3] smbd/process.c:1459(process_smb) Transaction 11 of length 120 (0 toread) [2009/11/17 22:34:17, 5] lib/util.c:632(show_msg) [2009/11/17 22:34:17, 5] lib/util.c:642(show_msg) size=116 smb_com=0x32 smb_rcls=0 smb_reh=0 smb_err=0 smb_flg=0 smb_flg2=49153 smb_tid=1 smb_pid=7672 smb_uid=100 smb_mid=1994 smt_wct=15 smb_vwv[ 0]= 30 (0x1E) smb_vwv[ 1]= 18 (0x12) smb_vwv[ 2]= 2 (0x2) smb_vwv[ 3]= 1000 (0x3E8) smb_vwv[ 4]= 0 (0x0) smb_vwv[ 5]= 0 (0x0) smb_vwv[ 6]= 0 (0x0) smb_vwv[ 7]= 0 (0x0) smb_vwv[ 8]= 0 (0x0) smb_vwv[ 9]= 30 (0x1E) smb_vwv[10]= 68 (0x44) smb_vwv[11]= 18 (0x12) smb_vwv[12]= 98 (0x62) smb_vwv[13]= 1 (0x1) smb_vwv[14]= 6 (0x6) smb_bcc=51 [2009/11/17 22:34:17, 10] ../lib/util/util.c:304(_dump_data) [0000] 00 00 00 09 02 00 00 00 00 2F 00 6A 00 6F 00 65 ........ ./.j.o.e [0010] 00 72 00 67 00 2F 00 74 00 65 00 73 00 74 00 00 .r.g./.t .e.s.t.. [0020] 00 00 00 00 00 82 00 00 00 ED 01 00 00 00 00 00 ........ ........ [0030] 00 00 02 ... [2009/11/17 22:34:17, 3] smbd/process.c:1273(switch_message) switch message SMBtrans2 (pid 6837) conn 0xa4eb898 [2009/11/17 22:34:17, 4] smbd/uid.c:256(change_to_user) change_to_user: Skipping user change - already user [2009/11/17 22:34:17, 5] smbd/filename.c:148(unix_convert) unix_convert called on file "joerg/test" [2009/11/17 22:34:17, 5] smbd/filename.c:297(unix_convert) conversion finished joerg/test -> joerg/test [2009/11/17 22:34:17, 3] smbd/trans2.c:6886(call_trans2setfilepathinfo) call_trans2setfilepathinfo(6) joerg/test (fnum -1) info_level=521 totdata=18 [2009/11/17 22:34:17, 10] smbd/trans2.c:6506(smb_posix_open) smb_posix_open: file joerg/test, smb_posix_flags = 128, mode 0755 [2009/11/17 22:34:17, 10] smbd/open.c:3366(create_file_default) create_file: access_mask = 0x6 file_attributes = 0x10001ed, share_access = 0x7, create_disposition = 0x1 create_options = 0x40 oplock_request = 0x0 root_dir_fid = 0x0, ea_list = 0x(nil), sd = 0x(nil), create_file_flags = 0x0, fname = joerg/test [2009/11/17 22:34:17, 10] smbd/open.c:2896(create_file_unixpath) create_file_unixpath: access_mask = 0x6 file_attributes = 0x10001ed, share_access = 0x7, create_disposition = 0x1 create_options = 0x40 oplock_request = 0x0 ea_list = 0x(nil), sd = 0x(nil), fname = joerg/test [2009/11/17 22:34:17, 5] smbd/files.c:103(file_new) allocated file structure 110, fnum = 4206 (1 used) [2009/11/17 22:34:17, 10] smbd/open.c:1475(open_file_ntcreate) open_file_ntcreate: fname=joerg/test, dos_attrs=0x0 access_mask=0x6 share_access=0x7 create_disposition = 0x1 create_options=0x40 unix mode=0755 oplock_request=0 [2009/11/17 22:34:17, 10] smbd/open.c:1653(open_file_ntcreate) open_file_ntcreate: fname=joerg/test, after mapping access_mask=0x6 [2009/11/17 22:34:17, 10] lib/dbwrap_tdb.c:100(db_tdb_fetch_locked) Locking key 0503000000000000B2E4 [2009/11/17 22:34:17, 10] lib/dbwrap_tdb.c:129(db_tdb_fetch_locked) Allocated locked data 0x0xa4f6028 [2009/11/17 22:34:17, 10] smbd/open.c:980(delay_for_oplocks) delay_for_oplocks: oplock type 0x10 on file [2009/11/17 22:34:17, 10] smbd/open.c:980(delay_for_oplocks) delay_for_oplocks: oplock type 0x10 on file [2009/11/17 22:34:17, 4] smbd/open.c:1913(open_file_ntcreate) calling open_file with flags=0x1 flags2=0x400 mode=0755, access_mask = 0x6, open_access_mask = 0x6 [2009/11/17 22:34:17, 10] smbd/open.c:160(fd_open) fd_open: name joerg/test, flags = 0402001 mode = 0755, fd = 30. [2009/11/17 22:34:17, 2] smbd/open.c:580(open_file) joerg opened file joerg/test read=No write=Yes (numopen=1) [2009/11/17 22:34:17, 5] smbd/oplock.c:86(set_file_oplock) set_file_oplock: granted oplock on file joerg/test, 305:34e4b2:0/3, tv_sec = 4b0316d9, tv_usec = 56d16 [2009/11/17 22:34:17, 10] locking/locking.c:716(unparse_share_modes) unparse_share_modes: del: 0, owrt: Di 17 Nov 2009 22:34:17 CET CET cwrt: Do 01 Jan 1970 01:00:00 CET CET, tok: 0, num: 1 [2009/11/17 22:34:17, 10] locking/locking.c:518(print_share_mode_table) print_share_mode_table: share_mode_entry[0]: pid = 6837, share_access = 0x7, private_options = 0x40, access_mask = 0x86, mid = 0x0, type= 0x10, gen_id = 3, uid = 1000, flags = 1, file_id 305:34e4b2:0 [2009/11/17 22:34:17, 10] lib/dbwrap_tdb.c:42(db_tdb_record_destr) Unlocking key 0503000000000000B2E4 [2009/11/17 22:34:17, 10] smbd/open.c:3201(create_file_unixpath) create_file_unixpath: info=1 [2009/11/17 22:34:17, 10] smbd/open.c:3496(create_file_default) create_file: info=1 [2009/11/17 22:34:17, 10] smbd/trans2.c:3520(store_file_unix_basic) store_file_unix_basic: SMB_QUERY_FILE_UNIX_BASIC [2009/11/17 22:34:17, 4] smbd/trans2.c:3521(store_file_unix_basic) store_file_unix_basic: st_mode=100644 [2009/11/17 22:34:17, 9] smbd/trans2.c:820(send_trans2_replies) t2_rep: params_sent_thistime = 2, data_sent_thistime = 112, useable_space = 16410 [2009/11/17 22:34:17, 9] smbd/trans2.c:822(send_trans2_replies) t2_rep: params_to_send = 2, data_to_send = 112, paramsize = 2, datasize = 112 [2009/11/17 22:34:17, 5] lib/util.c:632(show_msg) [2009/11/17 22:34:17, 5] lib/util.c:642(show_msg) size=172 smb_com=0x32 smb_rcls=0 smb_reh=0 smb_err=0 smb_flg=128 smb_flg2=49153 smb_tid=1 smb_pid=7672 smb_uid=100 smb_mid=1994 smt_wct=10 smb_vwv[ 0]= 2 (0x2) smb_vwv[ 1]= 112 (0x70) smb_vwv[ 2]= 0 (0x0) smb_vwv[ 3]= 2 (0x2) smb_vwv[ 4]= 56 (0x38) smb_vwv[ 5]= 0 (0x0) smb_vwv[ 6]= 112 (0x70) smb_vwv[ 7]= 60 (0x3C) smb_vwv[ 8]= 0 (0x0) smb_vwv[ 9]= 0 (0x0) smb_bcc=117 [2009/11/17 22:34:17, 10] ../lib/util/util.c:304(_dump_data) [0000] 00 00 00 00 00 00 00 6E 10 01 00 00 00 00 02 00 .......n ........ [0010] 00 02 00 00 00 00 00 00 00 00 10 00 00 00 00 00 ........ ........ [0020] 00 80 12 05 B7 CD 67 CA 01 80 C3 E0 9E CC 67 CA ......g. ......g. [0030] 01 80 12 05 B7 CD 67 CA 01 E8 03 00 00 00 00 00 ......g. ........ [0040] 00 04 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ........ ........ [0050] 00 00 00 00 00 00 00 00 00 00 00 00 00 B2 E4 34 ........ .......4 [0060] 00 00 00 00 00 A4 01 00 00 00 00 00 00 01 00 00 ........ ........ [0070] 00 00 00 00 00 ..... [2009/11/17 22:34:17, 10] lib/util_sock.c:789(read_smb_length_return_keepalive) got smb length of 66 [2009/11/17 22:34:17, 6] smbd/process.c:1456(process_smb) got message type 0x0 of len 0x42 [2009/11/17 22:34:17, 3] smbd/process.c:1459(process_smb) Transaction 12 of length 70 (0 toread) [2009/11/17 22:34:17, 5] lib/util.c:632(show_msg) [2009/11/17 22:34:17, 5] lib/util.c:642(show_msg) size=66 smb_com=0x2f smb_rcls=0 smb_reh=0 smb_err=0 smb_flg=0 smb_flg2=49153 smb_tid=1 smb_pid=7672 smb_uid=100 smb_mid=1995 smt_wct=14 smb_vwv[ 0]= 255 (0xFF) smb_vwv[ 1]= 0 (0x0) smb_vwv[ 2]= 4206 (0x106E) smb_vwv[ 3]= 2 (0x2) smb_vwv[ 4]= 0 (0x0) smb_vwv[ 5]=65535 (0xFFFF) smb_vwv[ 6]=65535 (0xFFFF) smb_vwv[ 7]= 0 (0x0) smb_vwv[ 8]= 0 (0x0) smb_vwv[ 9]= 0 (0x0) smb_vwv[10]= 2 (0x2) smb_vwv[11]= 64 (0x40) smb_vwv[12]= 0 (0x0) smb_vwv[13]= 0 (0x0) smb_bcc=3 [2009/11/17 22:34:17, 10] ../lib/util/util.c:304(_dump_data) [0000] 00 32 0A .2. [2009/11/17 22:34:17, 3] smbd/process.c:1273(switch_message) switch message SMBwriteX (pid 6837) conn 0xa4eb898 [2009/11/17 22:34:17, 4] smbd/uid.c:256(change_to_user) change_to_user: Skipping user change - already user [2009/11/17 22:34:17, 10] lib/dbwrap_tdb.c:100(db_tdb_fetch_locked) Locking key 0503000000000000B2E4 [2009/11/17 22:34:17, 10] lib/dbwrap_tdb.c:129(db_tdb_fetch_locked) Allocated locked data 0x0xa4f5e58 [2009/11/17 22:34:17, 10] locking/brlock.c:1778(brl_get_locks_internal) brl_get_locks_internal: 0 current locks on file_id 305:34e4b2:0 [2009/11/17 22:34:17, 10] lib/dbwrap_tdb.c:42(db_tdb_record_destr) Unlocking key 0503000000000000B2E4 [2009/11/17 22:34:17, 10] locking/locking.c:152(strict_lock_default) strict_lock_default: flavour = POSIX_LOCK brl start=2 len=2 unlocked for fnum 4206 file joerg/test [2009/11/17 22:34:17, 10] lib/events.c:287(s3_event_debug) s3_event: Added timed event "update_write_time_handler": 0xa4dfcf0 [2009/11/17 22:34:17, 8] smbd/dosmode.c:474(dos_mode) dos_mode: joerg/test [2009/11/17 22:34:17, 8] smbd/dosmode.c:175(dos_mode_from_sbuf) dos_mode_from_sbuf returning [2009/11/17 22:34:17, 8] smbd/dosmode.c:521(dos_mode) dos_mode returning [2009/11/17 22:34:17, 10] lib/dbwrap_tdb.c:100(db_tdb_fetch_locked) Locking key 0503000000000000B2E4 [2009/11/17 22:34:17, 10] lib/dbwrap_tdb.c:129(db_tdb_fetch_locked) Allocated locked data 0x0xa4f6038 [2009/11/17 22:34:17, 10] locking/locking.c:552(parse_share_modes) parse_share_modes: delete_on_close: 0, owrt: Di 17 Nov 2009 22:34:17 CET CET, cwrt: Do 01 Jan 1970 01:00:00 CET CET, tok: 0, num_share_modes: 1 [2009/11/17 22:34:17, 10] locking/locking.c:649(parse_share_modes) parse_share_modes: share_mode_entry[0]: pid = 6837, share_access = 0x7, private_options = 0x40, access_mask = 0x86, mid = 0x0, type= 0x10, gen_id = 3, uid = 1000, flags = 1, file_id 305:34e4b2:0 [2009/11/17 22:34:17, 10] smbd/oplock.c:769(contend_level2_oplocks_begin_default) release_level_2_oplocks_on_change: num_share_modes = 1 [2009/11/17 22:34:17, 10] smbd/oplock.c:792(contend_level2_oplocks_begin_default) release_level_2_oplocks_on_change: share_entry[0]->op_type == 16 [2009/11/17 22:34:17, 3] smbd/oplock.c:369(break_level2_to_none_async) process_oplock_async_level2_break_message: downgrading fake level 2 oplock. [2009/11/17 22:34:17, 10] lib/dbwrap_tdb.c:100(db_tdb_fetch_locked) Locking key 0503000000000000B2E4 [2009/11/17 22:34:17, 10] lib/dbwrap_tdb.c:129(db_tdb_fetch_locked) Allocated locked data 0x0xa4f62f8 [2009/11/17 22:34:17, 10] locking/locking.c:552(parse_share_modes) parse_share_modes: delete_on_close: 0, owrt: Di 17 Nov 2009 22:34:17 CET CET, cwrt: Do 01 Jan 1970 01:00:00 CET CET, tok: 0, num_share_modes: 1 [2009/11/17 22:34:17, 10] locking/locking.c:649(parse_share_modes) parse_share_modes: share_mode_entry[0]: pid = 6837, share_access = 0x7, private_options = 0x40, access_mask = 0x86, mid = 0x0, type= 0x10, gen_id = 3, uid = 1000, flags = 1, file_id 305:34e4b2:0 [2009/11/17 22:34:17, 10] locking/locking.c:716(unparse_share_modes) unparse_share_modes: del: 0, owrt: Di 17 Nov 2009 22:34:17 CET CET cwrt: Do 01 Jan 1970 01:00:00 CET CET, tok: 0, num: 1 [2009/11/17 22:34:17, 10] locking/locking.c:518(print_share_mode_table) print_share_mode_table: share_mode_entry[0]: pid = 6837, share_access = 0x7, private_options = 0x40, access_mask = 0x86, mid = 0x0, type= 0x0, gen_id = 3, uid = 1000, flags = 1, file_id 305:34e4b2:0 [2009/11/17 22:34:17, 10] lib/dbwrap_tdb.c:42(db_tdb_record_destr) Unlocking key 0503000000000000B2E4 [2009/11/17 22:34:17, 10] lib/dbwrap_tdb.c:42(db_tdb_record_destr) Unlocking key 0503000000000000B2E4 [2009/11/17 22:34:17, 10] smbd/fileio.c:138(real_write_file) real_write_file (joerg/test): pos = 2, size = 2, returned 2 [2009/11/17 22:34:17, 3] smbd/reply.c:4239(reply_write_and_X) writeX fnum=4206 num=2 wrote=2 [2009/11/17 22:34:17, 10] lib/util_sock.c:789(read_smb_length_return_keepalive) got smb length of 41 [2009/11/17 22:34:17, 6] smbd/process.c:1456(process_smb) got message type 0x0 of len 0x29 [2009/11/17 22:34:17, 3] smbd/process.c:1459(process_smb) Transaction 13 of length 45 (0 toread) [2009/11/17 22:34:17, 5] lib/util.c:632(show_msg) [2009/11/17 22:34:17, 5] lib/util.c:642(show_msg) size=41 smb_com=0x4 smb_rcls=0 smb_reh=0 smb_err=0 smb_flg=0 smb_flg2=49153 smb_tid=1 smb_pid=7672 smb_uid=100 smb_mid=1996 smt_wct=3 smb_vwv[ 0]= 4206 (0x106E) smb_vwv[ 1]=65535 (0xFFFF) smb_vwv[ 2]=65535 (0xFFFF) smb_bcc=0 [2009/11/17 22:34:17, 3] smbd/process.c:1273(switch_message) switch message SMBclose (pid 6837) conn 0xa4eb898 [2009/11/17 22:34:17, 4] smbd/uid.c:256(change_to_user) change_to_user: Skipping user change - already user [2009/11/17 22:34:17, 3] smbd/reply.c:4456(reply_close) close fd=30 fnum=4206 (numopen=1) [2009/11/17 22:34:17, 6] smbd/close.c:454(set_close_write_time) close_write_time: Thu Jan 1 00:59:59 1970 [2009/11/17 22:34:17, 10] lib/dbwrap_tdb.c:100(db_tdb_fetch_locked) Locking key 0503000000000000B2E4 [2009/11/17 22:34:17, 10] lib/dbwrap_tdb.c:129(db_tdb_fetch_locked) Allocated locked data 0x0xa4f5e58 [2009/11/17 22:34:17, 10] locking/locking.c:552(parse_share_modes) parse_share_modes: delete_on_close: 0, owrt: Di 17 Nov 2009 22:34:17 CET CET, cwrt: Do 01 Jan 1970 01:00:00 CET CET, tok: 0, num_share_modes: 1 [2009/11/17 22:34:17, 10] locking/locking.c:649(parse_share_modes) parse_share_modes: share_mode_entry[0]: pid = 6837, share_access = 0x7, private_options = 0x40, access_mask = 0x86, mid = 0x0, type= 0x0, gen_id = 3, uid = 1000, flags = 1, file_id 305:34e4b2:0 [2009/11/17 22:34:17, 10] lib/dbwrap_tdb.c:42(db_tdb_record_destr) Unlocking key 0503000000000000B2E4 [2009/11/17 22:34:17, 10] locking/posix.c:495(get_windows_lock_ref_count) get_windows_lock_count for file joerg/test = 0 [2009/11/17 22:34:17, 10] locking/posix.c:521(delete_windows_lock_ref_count) delete_windows_lock_ref_count for file joerg/test [2009/11/17 22:34:17, 5] smbd/trans2.c:4922(smb_set_file_time) smb_set_filetime: actime: Tue Nov 17 22:26:27 2009 smb_set_filetime: modtime: Tue Nov 17 22:34:17 2009 smb_set_file_time: setting pending modtime to Tue Nov 17 22:34:17 2009 [2009/11/17 22:34:17, 10] lib/events.c:287(s3_event_debug) s3_event: Destroying timer event 0xa4dfcf0 "update_write_time_handler" [2009/11/17 22:34:17, 5] locking/locking.c:1425(set_sticky_write_time) set_sticky_write_time: Di 17 Nov 2009 22:34:17 CET CET id=305:34e4b2:0 [2009/11/17 22:34:17, 10] lib/dbwrap_tdb.c:100(db_tdb_fetch_locked) Locking key 0503000000000000B2E4 [2009/11/17 22:34:17, 10] lib/dbwrap_tdb.c:129(db_tdb_fetch_locked) Allocated locked data 0x0xa4eb1f0 [2009/11/17 22:34:17, 3] locking/locking.c:858(get_share_mode_lock) fill_share_mode_lock failed [2009/11/17 22:34:17, 10] lib/dbwrap_tdb.c:42(db_tdb_record_destr) Unlocking key 0503000000000000B2E4 [2009/11/17 22:34:17, 10] smbd/trans2.c:4972(smb_set_file_time) smb_set_file_time: setting utimes to modified values. [2009/11/17 22:34:17, 6] smbd/dosmode.c:721(file_ntimes) file_ntime: actime: Tue Nov 17 22:26:27 2009 [2009/11/17 22:34:17, 6] smbd/dosmode.c:723(file_ntimes) file_ntime: modtime: Tue Nov 17 22:34:17 2009 [2009/11/17 22:34:17, 6] smbd/dosmode.c:725(file_ntimes) file_ntime: createtime: Thu Jan 1 01:00:00 1970 [2009/11/17 22:34:17, 10] smbd/notify_internal.c:593(notify_trigger) notify_trigger called action=0x3, filter=0x10, path=/home/joerg/test [2009/11/17 22:34:17, 2] smbd/close.c:612(close_normal_file) joerg closed file joerg/test (numopen=0) NT_STATUS_OK [2009/11/17 22:34:17, 5] smbd/files.c:484(file_free) freed files structure 4206 (0 used) [2009/11/17 22:34:17, 5] lib/util.c:632(show_msg) [2009/11/17 22:34:17, 5] lib/util.c:642(show_msg) size=35 smb_com=0x4 smb_rcls=0 smb_reh=0 smb_err=0 smb_flg=128 smb_flg2=49153 smb_tid=1 smb_pid=7672 smb_uid=100 smb_mid=1996 smt_wct=0 smb_bcc=0 [2009/11/17 22:34:17, 10] lib/util_sock.c:789(read_smb_length_return_keepalive) got smb length of 116 [2009/11/17 22:34:17, 6] smbd/process.c:1456(process_smb) got message type 0x0 of len 0x74 [2009/11/17 22:34:17, 3] smbd/process.c:1459(process_smb) Transaction 14 of length 120 (0 toread) [2009/11/17 22:34:17, 5] lib/util.c:632(show_msg) [2009/11/17 22:34:17, 5] lib/util.c:642(show_msg) size=116 smb_com=0x32 smb_rcls=0 smb_reh=0 smb_err=0 smb_flg=0 smb_flg2=49153 smb_tid=1 smb_pid=15180 smb_uid=100 smb_mid=1997 smt_wct=15 smb_vwv[ 0]= 30 (0x1E) smb_vwv[ 1]= 18 (0x12) smb_vwv[ 2]= 2 (0x2) smb_vwv[ 3]= 1000 (0x3E8) smb_vwv[ 4]= 0 (0x0) smb_vwv[ 5]= 0 (0x0) smb_vwv[ 6]= 0 (0x0) smb_vwv[ 7]= 0 (0x0) smb_vwv[ 8]= 0 (0x0) smb_vwv[ 9]= 30 (0x1E) smb_vwv[10]= 68 (0x44) smb_vwv[11]= 18 (0x12) smb_vwv[12]= 98 (0x62) smb_vwv[13]= 1 (0x1) smb_vwv[14]= 6 (0x6) smb_bcc=51 [2009/11/17 22:34:17, 10] ../lib/util/util.c:304(_dump_data) [0000] 00 00 00 09 02 00 00 00 00 2F 00 6A 00 6F 00 65 ........ ./.j.o.e [0010] 00 72 00 67 00 2F 00 74 00 65 00 73 00 74 00 00 .r.g./.t .e.s.t.. [0020] 00 00 00 00 00 01 00 00 00 ED 01 00 00 00 00 00 ........ ........ [0030] 00 00 02 ... [2009/11/17 22:34:17, 3] smbd/process.c:1273(switch_message) switch message SMBtrans2 (pid 6837) conn 0xa4eb898 [2009/11/17 22:34:17, 4] smbd/uid.c:256(change_to_user) change_to_user: Skipping user change - already user [2009/11/17 22:34:17, 5] smbd/filename.c:148(unix_convert) unix_convert called on file "joerg/test" [2009/11/17 22:34:17, 5] smbd/filename.c:297(unix_convert) conversion finished joerg/test -> joerg/test [2009/11/17 22:34:17, 3] smbd/trans2.c:6886(call_trans2setfilepathinfo) call_trans2setfilepathinfo(6) joerg/test (fnum -1) info_level=521 totdata=18 [2009/11/17 22:34:17, 10] smbd/trans2.c:6506(smb_posix_open) smb_posix_open: file joerg/test, smb_posix_flags = 0, mode 0755 [2009/11/17 22:34:17, 10] smbd/open.c:3366(create_file_default) create_file: access_mask = 0x1 file_attributes = 0x10001ed, share_access = 0x7, create_disposition = 0x1 create_options = 0x40 oplock_request = 0x0 root_dir_fid = 0x0, ea_list = 0x(nil), sd = 0x(nil), create_file_flags = 0x0, fname = joerg/test [2009/11/17 22:34:17, 10] smbd/open.c:2896(create_file_unixpath) create_file_unixpath: access_mask = 0x1 file_attributes = 0x10001ed, share_access = 0x7, create_disposition = 0x1 create_options = 0x40 oplock_request = 0x0 ea_list = 0x(nil), sd = 0x(nil), fname = joerg/test [2009/11/17 22:34:17, 5] smbd/files.c:103(file_new) allocated file structure 111, fnum = 4207 (1 used) [2009/11/17 22:34:17, 10] smbd/open.c:1475(open_file_ntcreate) open_file_ntcreate: fname=joerg/test, dos_attrs=0x0 access_mask=0x1 share_access=0x7 create_disposition = 0x1 create_options=0x40 unix mode=0755 oplock_request=0 [2009/11/17 22:34:17, 10] smbd/open.c:1653(open_file_ntcreate) open_file_ntcreate: fname=joerg/test, after mapping access_mask=0x1 [2009/11/17 22:34:17, 10] lib/dbwrap_tdb.c:100(db_tdb_fetch_locked) Locking key 0503000000000000B2E4 [2009/11/17 22:34:17, 10] lib/dbwrap_tdb.c:129(db_tdb_fetch_locked) Allocated locked data 0x0xa4f6028 [2009/11/17 22:34:17, 10] smbd/open.c:980(delay_for_oplocks) delay_for_oplocks: oplock type 0x10 on file [2009/11/17 22:34:17, 10] smbd/open.c:980(delay_for_oplocks) delay_for_oplocks: oplock type 0x10 on file [2009/11/17 22:34:17, 4] smbd/open.c:1913(open_file_ntcreate) calling open_file with flags=0x0 flags2=0x0 mode=0755, access_mask = 0x1, open_access_mask = 0x1 [2009/11/17 22:34:17, 10] smbd/open.c:160(fd_open) fd_open: name joerg/test, flags = 0400000 mode = 0755, fd = 30. [2009/11/17 22:34:17, 2] smbd/open.c:580(open_file) joerg opened file joerg/test read=Yes write=No (numopen=1) [2009/11/17 22:34:17, 5] smbd/oplock.c:86(set_file_oplock) set_file_oplock: granted oplock on file joerg/test, 305:34e4b2:0/4, tv_sec = 4b0316d9, tv_usec = 59b11 [2009/11/17 22:34:17, 10] locking/locking.c:716(unparse_share_modes) unparse_share_modes: del: 0, owrt: Di 17 Nov 2009 22:34:17 CET CET cwrt: Do 01 Jan 1970 01:00:00 CET CET, tok: 0, num: 1 [2009/11/17 22:34:17, 10] locking/locking.c:518(print_share_mode_table) print_share_mode_table: share_mode_entry[0]: pid = 6837, share_access = 0x7, private_options = 0x40, access_mask = 0x81, mid = 0x0, type= 0x10, gen_id = 4, uid = 1000, flags = 1, file_id 305:34e4b2:0 [2009/11/17 22:34:17, 10] lib/dbwrap_tdb.c:42(db_tdb_record_destr) Unlocking key 0503000000000000B2E4 [2009/11/17 22:34:17, 10] smbd/open.c:3201(create_file_unixpath) create_file_unixpath: info=1 [2009/11/17 22:34:17, 10] smbd/open.c:3496(create_file_default) create_file: info=1 [2009/11/17 22:34:17, 10] smbd/trans2.c:3520(store_file_unix_basic) store_file_unix_basic: SMB_QUERY_FILE_UNIX_BASIC [2009/11/17 22:34:17, 4] smbd/trans2.c:3521(store_file_unix_basic) store_file_unix_basic: st_mode=100644 [2009/11/17 22:34:17, 9] smbd/trans2.c:820(send_trans2_replies) t2_rep: params_sent_thistime = 2, data_sent_thistime = 112, useable_space = 16410 [2009/11/17 22:34:17, 9] smbd/trans2.c:822(send_trans2_replies) t2_rep: params_to_send = 2, data_to_send = 112, paramsize = 2, datasize = 112 [2009/11/17 22:34:17, 5] lib/util.c:632(show_msg) [2009/11/17 22:34:17, 5] lib/util.c:642(show_msg) size=172 smb_com=0x32 smb_rcls=0 smb_reh=0 smb_err=0 smb_flg=128 smb_flg2=49153 smb_tid=1 smb_pid=15180 smb_uid=100 smb_mid=1997 smt_wct=10 smb_vwv[ 0]= 2 (0x2) smb_vwv[ 1]= 112 (0x70) smb_vwv[ 2]= 0 (0x0) smb_vwv[ 3]= 2 (0x2) smb_vwv[ 4]= 56 (0x38) smb_vwv[ 5]= 0 (0x0) smb_vwv[ 6]= 112 (0x70) smb_vwv[ 7]= 60 (0x3C) smb_vwv[ 8]= 0 (0x0) smb_vwv[ 9]= 0 (0x0) smb_bcc=117 [2009/11/17 22:34:17, 10] ../lib/util/util.c:304(_dump_data) [0000] 00 00 00 00 00 00 00 6F 10 01 00 00 00 00 02 00 .......o ........ [0010] 00 04 00 00 00 00 00 00 00 00 10 00 00 00 00 00 ........ ........ [0020] 00 80 12 05 B7 CD 67 CA 01 80 C3 E0 9E CC 67 CA ......g. ......g. [0030] 01 80 12 05 B7 CD 67 CA 01 E8 03 00 00 00 00 00 ......g. ........ [0040] 00 04 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ........ ........ [0050] 00 00 00 00 00 00 00 00 00 00 00 00 00 B2 E4 34 ........ .......4 [0060] 00 00 00 00 00 A4 01 00 00 00 00 00 00 01 00 00 ........ ........ [0070] 00 00 00 00 00 ..... [2009/11/17 22:34:17, 10] lib/util_sock.c:789(read_smb_length_return_keepalive) got smb length of 59 [2009/11/17 22:34:17, 6] smbd/process.c:1456(process_smb) got message type 0x0 of len 0x3b [2009/11/17 22:34:17, 3] smbd/process.c:1459(process_smb) Transaction 15 of length 63 (0 toread) [2009/11/17 22:34:17, 5] lib/util.c:632(show_msg) [2009/11/17 22:34:17, 5] lib/util.c:642(show_msg) size=59 smb_com=0x2e smb_rcls=0 smb_reh=0 smb_err=0 smb_flg=0 smb_flg2=49153 smb_tid=1 smb_pid=15180 smb_uid=100 smb_mid=1998 smt_wct=12 smb_vwv[ 0]= 255 (0xFF) smb_vwv[ 1]= 0 (0x0) smb_vwv[ 2]= 4207 (0x106F) smb_vwv[ 3]= 0 (0x0) smb_vwv[ 4]= 0 (0x0) smb_vwv[ 5]= 4096 (0x1000) smb_vwv[ 6]= 0 (0x0) smb_vwv[ 7]= 0 (0x0) smb_vwv[ 8]= 0 (0x0) smb_vwv[ 9]= 0 (0x0) smb_vwv[10]= 0 (0x0) smb_vwv[11]= 0 (0x0) smb_bcc=0 [2009/11/17 22:34:17, 3] smbd/process.c:1273(switch_message) switch message SMBreadX (pid 6837) conn 0xa4eb898 [2009/11/17 22:34:17, 4] smbd/uid.c:256(change_to_user) change_to_user: Skipping user change - already user [2009/11/17 22:34:17, 10] lib/dbwrap_tdb.c:100(db_tdb_fetch_locked) Locking key 0503000000000000B2E4 [2009/11/17 22:34:17, 10] lib/dbwrap_tdb.c:129(db_tdb_fetch_locked) Allocated locked data 0x0xa4f5e48 [2009/11/17 22:34:17, 10] locking/brlock.c:1778(brl_get_locks_internal) brl_get_locks_internal: 0 current locks on file_id 305:34e4b2:0 [2009/11/17 22:34:17, 10] lib/dbwrap_tdb.c:42(db_tdb_record_destr) Unlocking key 0503000000000000B2E4 [2009/11/17 22:34:17, 10] locking/locking.c:152(strict_lock_default) strict_lock_default: flavour = POSIX_LOCK brl start=0 len=4096 unlocked for fnum 4207 file joerg/test [2009/11/17 22:34:17, 10] smbd/fileio.c:105(read_file) read_file (joerg/test): pos = 0, size = 4096, returned 4 [2009/11/17 22:34:17, 3] smbd/reply.c:3414(send_file_readX) send_file_readX fnum=4207 max=4096 nread=4 [2009/11/17 22:34:17, 10] lib/util_sock.c:789(read_smb_length_return_keepalive) got smb length of 59 [2009/11/17 22:34:17, 6] smbd/process.c:1456(process_smb) got message type 0x0 of len 0x3b [2009/11/17 22:34:17, 3] smbd/process.c:1459(process_smb) Transaction 16 of length 63 (0 toread) [2009/11/17 22:34:17, 5] lib/util.c:632(show_msg) [2009/11/17 22:34:17, 5] lib/util.c:642(show_msg) size=59 smb_com=0x2e smb_rcls=0 smb_reh=0 smb_err=0 smb_flg=0 smb_flg2=49153 smb_tid=1 smb_pid=15180 smb_uid=100 smb_mid=1999 smt_wct=12 smb_vwv[ 0]= 255 (0xFF) smb_vwv[ 1]= 0 (0x0) smb_vwv[ 2]= 4207 (0x106F) smb_vwv[ 3]= 4 (0x4) smb_vwv[ 4]= 0 (0x0) smb_vwv[ 5]= 4092 (0xFFC) smb_vwv[ 6]= 0 (0x0) smb_vwv[ 7]= 0 (0x0) smb_vwv[ 8]= 0 (0x0) smb_vwv[ 9]= 0 (0x0) smb_vwv[10]= 0 (0x0) smb_vwv[11]= 0 (0x0) smb_bcc=0 [2009/11/17 22:34:17, 3] smbd/process.c:1273(switch_message) switch message SMBreadX (pid 6837) conn 0xa4eb898 [2009/11/17 22:34:17, 4] smbd/uid.c:256(change_to_user) change_to_user: Skipping user change - already user [2009/11/17 22:34:17, 10] locking/brlock.c:1778(brl_get_locks_internal) brl_get_locks_internal: 0 current locks on file_id 305:34e4b2:0 [2009/11/17 22:34:17, 10] locking/locking.c:152(strict_lock_default) strict_lock_default: flavour = POSIX_LOCK brl start=4 len=4092 unlocked for fnum 4207 file joerg/test [2009/11/17 22:34:17, 10] smbd/fileio.c:105(read_file) read_file (joerg/test): pos = 4, size = 4092, returned 0 [2009/11/17 22:34:17, 3] smbd/reply.c:3414(send_file_readX) send_file_readX fnum=4207 max=4092 nread=0 [2009/11/17 22:34:17, 10] lib/util_sock.c:789(read_smb_length_return_keepalive) got smb length of 41 [2009/11/17 22:34:17, 6] smbd/process.c:1456(process_smb) got message type 0x0 of len 0x29 [2009/11/17 22:34:17, 3] smbd/process.c:1459(process_smb) Transaction 17 of length 45 (0 toread) [2009/11/17 22:34:17, 5] lib/util.c:632(show_msg) [2009/11/17 22:34:17, 5] lib/util.c:642(show_msg) size=41 smb_com=0x4 smb_rcls=0 smb_reh=0 smb_err=0 smb_flg=0 smb_flg2=49153 smb_tid=1 smb_pid=15180 smb_uid=100 smb_mid=2000 smt_wct=3 smb_vwv[ 0]= 4207 (0x106F) smb_vwv[ 1]=65535 (0xFFFF) smb_vwv[ 2]=65535 (0xFFFF) smb_bcc=0 [2009/11/17 22:34:17, 3] smbd/process.c:1273(switch_message) switch message SMBclose (pid 6837) conn 0xa4eb898 [2009/11/17 22:34:17, 4] smbd/uid.c:256(change_to_user) change_to_user: Skipping user change - already user [2009/11/17 22:34:17, 3] smbd/reply.c:4456(reply_close) close fd=30 fnum=4207 (numopen=1) [2009/11/17 22:34:17, 6] smbd/close.c:454(set_close_write_time) close_write_time: Thu Jan 1 00:59:59 1970 [2009/11/17 22:34:17, 10] lib/dbwrap_tdb.c:100(db_tdb_fetch_locked) Locking key 0503000000000000B2E4 [2009/11/17 22:34:17, 10] lib/dbwrap_tdb.c:129(db_tdb_fetch_locked) Allocated locked data 0x0xa4f5e58 [2009/11/17 22:34:17, 10] locking/locking.c:552(parse_share_modes) parse_share_modes: delete_on_close: 0, owrt: Di 17 Nov 2009 22:34:17 CET CET, cwrt: Do 01 Jan 1970 01:00:00 CET CET, tok: 0, num_share_modes: 1 [2009/11/17 22:34:17, 10] locking/locking.c:649(parse_share_modes) parse_share_modes: share_mode_entry[0]: pid = 6837, share_access = 0x7, private_options = 0x40, access_mask = 0x81, mid = 0x0, type= 0x10, gen_id = 4, uid = 1000, flags = 1, file_id 305:34e4b2:0 [2009/11/17 22:34:17, 10] lib/dbwrap_tdb.c:42(db_tdb_record_destr) Unlocking key 0503000000000000B2E4 [2009/11/17 22:34:17, 10] locking/posix.c:495(get_windows_lock_ref_count) get_windows_lock_count for file joerg/test = 0 [2009/11/17 22:34:17, 10] locking/posix.c:521(delete_windows_lock_ref_count) delete_windows_lock_ref_count for file joerg/test [2009/11/17 22:34:17, 2] smbd/close.c:612(close_normal_file) joerg closed file joerg/test (numopen=0) NT_STATUS_OK [2009/11/17 22:34:17, 5] smbd/files.c:484(file_free) freed files structure 4207 (0 used) [2009/11/17 22:34:17, 5] lib/util.c:632(show_msg) [2009/11/17 22:34:17, 5] lib/util.c:642(show_msg) size=35 smb_com=0x4 smb_rcls=0 smb_reh=0 smb_err=0 smb_flg=128 smb_flg2=49153 smb_tid=1 smb_pid=15180 smb_uid=100 smb_mid=2000 smt_wct=0 smb_bcc=0 [2009/11/17 22:34:17, 10] lib/util_sock.c:789(read_smb_length_return_keepalive) got smb length of 116 [2009/11/17 22:34:17, 6] smbd/process.c:1456(process_smb) got message type 0x0 of len 0x74 [2009/11/17 22:34:17, 3] smbd/process.c:1459(process_smb) Transaction 18 of length 120 (0 toread) [2009/11/17 22:34:17, 5] lib/util.c:632(show_msg) [2009/11/17 22:34:17, 5] lib/util.c:642(show_msg) size=116 smb_com=0x32 smb_rcls=0 smb_reh=0 smb_err=0 smb_flg=0 smb_flg2=49153 smb_tid=1 smb_pid=7672 smb_uid=100 smb_mid=2001 smt_wct=15 smb_vwv[ 0]= 30 (0x1E) smb_vwv[ 1]= 18 (0x12) smb_vwv[ 2]= 2 (0x2) smb_vwv[ 3]= 1000 (0x3E8) smb_vwv[ 4]= 0 (0x0) smb_vwv[ 5]= 0 (0x0) smb_vwv[ 6]= 0 (0x0) smb_vwv[ 7]= 0 (0x0) smb_vwv[ 8]= 0 (0x0) smb_vwv[ 9]= 30 (0x1E) smb_vwv[10]= 68 (0x44) smb_vwv[11]= 18 (0x12) smb_vwv[12]= 98 (0x62) smb_vwv[13]= 1 (0x1) smb_vwv[14]= 6 (0x6) smb_bcc=51 [2009/11/17 22:34:17, 10] ../lib/util/util.c:304(_dump_data) [0000] 00 00 00 09 02 00 00 00 00 2F 00 6A 00 6F 00 65 ........ ./.j.o.e [0010] 00 72 00 67 00 2F 00 74 00 65 00 73 00 74 00 00 .r.g./.t .e.s.t.. [0020] 00 00 00 00 00 82 00 00 00 ED 01 00 00 00 00 00 ........ ........ [0030] 00 00 02 ... [2009/11/17 22:34:17, 3] smbd/process.c:1273(switch_message) switch message SMBtrans2 (pid 6837) conn 0xa4eb898 [2009/11/17 22:34:17, 4] smbd/uid.c:256(change_to_user) change_to_user: Skipping user change - already user [2009/11/17 22:34:17, 5] smbd/filename.c:148(unix_convert) unix_convert called on file "joerg/test" [2009/11/17 22:34:17, 5] smbd/filename.c:297(unix_convert) conversion finished joerg/test -> joerg/test [2009/11/17 22:34:17, 3] smbd/trans2.c:6886(call_trans2setfilepathinfo) call_trans2setfilepathinfo(6) joerg/test (fnum -1) info_level=521 totdata=18 [2009/11/17 22:34:17, 10] smbd/trans2.c:6506(smb_posix_open) smb_posix_open: file joerg/test, smb_posix_flags = 128, mode 0755 [2009/11/17 22:34:17, 10] smbd/open.c:3366(create_file_default) create_file: access_mask = 0x6 file_attributes = 0x10001ed, share_access = 0x7, create_disposition = 0x1 create_options = 0x40 oplock_request = 0x0 root_dir_fid = 0x0, ea_list = 0x(nil), sd = 0x(nil), create_file_flags = 0x0, fname = joerg/test [2009/11/17 22:34:17, 10] smbd/open.c:2896(create_file_unixpath) create_file_unixpath: access_mask = 0x6 file_attributes = 0x10001ed, share_access = 0x7, create_disposition = 0x1 create_options = 0x40 oplock_request = 0x0 ea_list = 0x(nil), sd = 0x(nil), fname = joerg/test [2009/11/17 22:34:17, 5] smbd/files.c:103(file_new) allocated file structure 112, fnum = 4208 (1 used) [2009/11/17 22:34:17, 10] smbd/open.c:1475(open_file_ntcreate) open_file_ntcreate: fname=joerg/test, dos_attrs=0x0 access_mask=0x6 share_access=0x7 create_disposition = 0x1 create_options=0x40 unix mode=0755 oplock_request=0 [2009/11/17 22:34:17, 10] smbd/open.c:1653(open_file_ntcreate) open_file_ntcreate: fname=joerg/test, after mapping access_mask=0x6 [2009/11/17 22:34:17, 10] lib/dbwrap_tdb.c:100(db_tdb_fetch_locked) Locking key 0503000000000000B2E4 [2009/11/17 22:34:17, 10] lib/dbwrap_tdb.c:129(db_tdb_fetch_locked) Allocated locked data 0x0xa4f6028 [2009/11/17 22:34:17, 10] smbd/open.c:980(delay_for_oplocks) delay_for_oplocks: oplock type 0x10 on file [2009/11/17 22:34:17, 10] smbd/open.c:980(delay_for_oplocks) delay_for_oplocks: oplock type 0x10 on file [2009/11/17 22:34:17, 4] smbd/open.c:1913(open_file_ntcreate) calling open_file with flags=0x1 flags2=0x400 mode=0755, access_mask = 0x6, open_access_mask = 0x6 [2009/11/17 22:34:17, 10] smbd/open.c:160(fd_open) fd_open: name joerg/test, flags = 0402001 mode = 0755, fd = 30. [2009/11/17 22:34:17, 2] smbd/open.c:580(open_file) joerg opened file joerg/test read=No write=Yes (numopen=1) [2009/11/17 22:34:17, 5] smbd/oplock.c:86(set_file_oplock) set_file_oplock: granted oplock on file joerg/test, 305:34e4b2:0/5, tv_sec = 4b0316d9, tv_usec = 5be83 [2009/11/17 22:34:17, 10] locking/locking.c:716(unparse_share_modes) unparse_share_modes: del: 0, owrt: Di 17 Nov 2009 22:34:17 CET CET cwrt: Do 01 Jan 1970 01:00:00 CET CET, tok: 0, num: 1 [2009/11/17 22:34:17, 10] locking/locking.c:518(print_share_mode_table) print_share_mode_table: share_mode_entry[0]: pid = 6837, share_access = 0x7, private_options = 0x40, access_mask = 0x86, mid = 0x0, type= 0x10, gen_id = 5, uid = 1000, flags = 1, file_id 305:34e4b2:0 [2009/11/17 22:34:17, 10] lib/dbwrap_tdb.c:42(db_tdb_record_destr) Unlocking key 0503000000000000B2E4 [2009/11/17 22:34:17, 10] smbd/open.c:3201(create_file_unixpath) create_file_unixpath: info=1 [2009/11/17 22:34:17, 10] smbd/open.c:3496(create_file_default) create_file: info=1 [2009/11/17 22:34:17, 10] smbd/trans2.c:3520(store_file_unix_basic) store_file_unix_basic: SMB_QUERY_FILE_UNIX_BASIC [2009/11/17 22:34:17, 4] smbd/trans2.c:3521(store_file_unix_basic) store_file_unix_basic: st_mode=100644 [2009/11/17 22:34:17, 9] smbd/trans2.c:820(send_trans2_replies) t2_rep: params_sent_thistime = 2, data_sent_thistime = 112, useable_space = 16410 [2009/11/17 22:34:17, 9] smbd/trans2.c:822(send_trans2_replies) t2_rep: params_to_send = 2, data_to_send = 112, paramsize = 2, datasize = 112 [2009/11/17 22:34:17, 5] lib/util.c:632(show_msg) [2009/11/17 22:34:17, 5] lib/util.c:642(show_msg) size=172 smb_com=0x32 smb_rcls=0 smb_reh=0 smb_err=0 smb_flg=128 smb_flg2=49153 smb_tid=1 smb_pid=7672 smb_uid=100 smb_mid=2001 smt_wct=10 smb_vwv[ 0]= 2 (0x2) smb_vwv[ 1]= 112 (0x70) smb_vwv[ 2]= 0 (0x0) smb_vwv[ 3]= 2 (0x2) smb_vwv[ 4]= 56 (0x38) smb_vwv[ 5]= 0 (0x0) smb_vwv[ 6]= 112 (0x70) smb_vwv[ 7]= 60 (0x3C) smb_vwv[ 8]= 0 (0x0) smb_vwv[ 9]= 0 (0x0) smb_bcc=117 [2009/11/17 22:34:17, 10] ../lib/util/util.c:304(_dump_data) [0000] 00 00 00 00 00 00 00 70 10 01 00 00 00 00 02 00 .......p ........ [0010] 00 04 00 00 00 00 00 00 00 00 10 00 00 00 00 00 ........ ........ [0020] 00 80 12 05 B7 CD 67 CA 01 80 12 05 B7 CD 67 CA ......g. ......g. [0030] 01 80 12 05 B7 CD 67 CA 01 E8 03 00 00 00 00 00 ......g. ........ [0040] 00 04 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ........ ........ [0050] 00 00 00 00 00 00 00 00 00 00 00 00 00 B2 E4 34 ........ .......4 [0060] 00 00 00 00 00 A4 01 00 00 00 00 00 00 01 00 00 ........ ........ [0070] 00 00 00 00 00 ..... [2009/11/17 22:34:17, 10] lib/util_sock.c:789(read_smb_length_return_keepalive) got smb length of 70 [2009/11/17 22:34:17, 6] smbd/process.c:1456(process_smb) got message type 0x0 of len 0x46 [2009/11/17 22:34:17, 3] smbd/process.c:1459(process_smb) Transaction 19 of length 74 (0 toread) [2009/11/17 22:34:17, 5] lib/util.c:632(show_msg) [2009/11/17 22:34:17, 5] lib/util.c:642(show_msg) size=70 smb_com=0x2f smb_rcls=0 smb_reh=0 smb_err=0 smb_flg=0 smb_flg2=49153 smb_tid=1 smb_pid=7672 smb_uid=100 smb_mid=2002 smt_wct=14 smb_vwv[ 0]= 255 (0xFF) smb_vwv[ 1]= 0 (0x0) smb_vwv[ 2]= 4208 (0x1070) smb_vwv[ 3]= 0 (0x0) smb_vwv[ 4]= 0 (0x0) smb_vwv[ 5]=65535 (0xFFFF) smb_vwv[ 6]=65535 (0xFFFF) smb_vwv[ 7]= 0 (0x0) smb_vwv[ 8]= 0 (0x0) smb_vwv[ 9]= 0 (0x0) smb_vwv[10]= 6 (0x6) smb_vwv[11]= 64 (0x40) smb_vwv[12]= 0 (0x0) smb_vwv[13]= 0 (0x0) smb_bcc=7 [2009/11/17 22:34:17, 10] ../lib/util/util.c:304(_dump_data) [0000] 00 31 0A 32 0A 33 0A .1.2.3. [2009/11/17 22:34:17, 3] smbd/process.c:1273(switch_message) switch message SMBwriteX (pid 6837) conn 0xa4eb898 [2009/11/17 22:34:17, 4] smbd/uid.c:256(change_to_user) change_to_user: Skipping user change - already user [2009/11/17 22:34:17, 10] lib/dbwrap_tdb.c:100(db_tdb_fetch_locked) Locking key 0503000000000000B2E4 [2009/11/17 22:34:17, 10] lib/dbwrap_tdb.c:129(db_tdb_fetch_locked) Allocated locked data 0x0xa4f5e58 [2009/11/17 22:34:17, 10] locking/brlock.c:1778(brl_get_locks_internal) brl_get_locks_internal: 0 current locks on file_id 305:34e4b2:0 [2009/11/17 22:34:17, 10] lib/dbwrap_tdb.c:42(db_tdb_record_destr) Unlocking key 0503000000000000B2E4 [2009/11/17 22:34:17, 10] locking/locking.c:152(strict_lock_default) strict_lock_default: flavour = POSIX_LOCK brl start=0 len=6 unlocked for fnum 4208 file joerg/test [2009/11/17 22:34:17, 10] lib/events.c:287(s3_event_debug) s3_event: Added timed event "update_write_time_handler": 0xa4ea780 [2009/11/17 22:34:17, 8] smbd/dosmode.c:474(dos_mode) dos_mode: joerg/test [2009/11/17 22:34:17, 8] smbd/dosmode.c:175(dos_mode_from_sbuf) dos_mode_from_sbuf returning [2009/11/17 22:34:17, 8] smbd/dosmode.c:521(dos_mode) dos_mode returning [2009/11/17 22:34:17, 10] lib/dbwrap_tdb.c:100(db_tdb_fetch_locked) Locking key 0503000000000000B2E4 [2009/11/17 22:34:17, 10] lib/dbwrap_tdb.c:129(db_tdb_fetch_locked) Allocated locked data 0x0xa4f6038 [2009/11/17 22:34:17, 10] locking/locking.c:552(parse_share_modes) parse_share_modes: delete_on_close: 0, owrt: Di 17 Nov 2009 22:34:17 CET CET, cwrt: Do 01 Jan 1970 01:00:00 CET CET, tok: 0, num_share_modes: 1 [2009/11/17 22:34:17, 10] locking/locking.c:649(parse_share_modes) parse_share_modes: share_mode_entry[0]: pid = 6837, share_access = 0x7, private_options = 0x40, access_mask = 0x86, mid = 0x0, type= 0x10, gen_id = 5, uid = 1000, flags = 1, file_id 305:34e4b2:0 [2009/11/17 22:34:17, 10] smbd/oplock.c:769(contend_level2_oplocks_begin_default) release_level_2_oplocks_on_change: num_share_modes = 1 [2009/11/17 22:34:17, 10] smbd/oplock.c:792(contend_level2_oplocks_begin_default) release_level_2_oplocks_on_change: share_entry[0]->op_type == 16 [2009/11/17 22:34:17, 3] smbd/oplock.c:369(break_level2_to_none_async) process_oplock_async_level2_break_message: downgrading fake level 2 oplock. [2009/11/17 22:34:17, 10] lib/dbwrap_tdb.c:100(db_tdb_fetch_locked) Locking key 0503000000000000B2E4 [2009/11/17 22:34:17, 10] lib/dbwrap_tdb.c:129(db_tdb_fetch_locked) Allocated locked data 0x0xa4f62f8 [2009/11/17 22:34:17, 10] locking/locking.c:552(parse_share_modes) parse_share_modes: delete_on_close: 0, owrt: Di 17 Nov 2009 22:34:17 CET CET, cwrt: Do 01 Jan 1970 01:00:00 CET CET, tok: 0, num_share_modes: 1 [2009/11/17 22:34:17, 10] locking/locking.c:649(parse_share_modes) parse_share_modes: share_mode_entry[0]: pid = 6837, share_access = 0x7, private_options = 0x40, access_mask = 0x86, mid = 0x0, type= 0x10, gen_id = 5, uid = 1000, flags = 1, file_id 305:34e4b2:0 [2009/11/17 22:34:17, 10] locking/locking.c:716(unparse_share_modes) unparse_share_modes: del: 0, owrt: Di 17 Nov 2009 22:34:17 CET CET cwrt: Do 01 Jan 1970 01:00:00 CET CET, tok: 0, num: 1 [2009/11/17 22:34:17, 10] locking/locking.c:518(print_share_mode_table) print_share_mode_table: share_mode_entry[0]: pid = 6837, share_access = 0x7, private_options = 0x40, access_mask = 0x86, mid = 0x0, type= 0x0, gen_id = 5, uid = 1000, flags = 1, file_id 305:34e4b2:0 [2009/11/17 22:34:17, 10] lib/dbwrap_tdb.c:42(db_tdb_record_destr) Unlocking key 0503000000000000B2E4 [2009/11/17 22:34:17, 10] lib/dbwrap_tdb.c:42(db_tdb_record_destr) Unlocking key 0503000000000000B2E4 [2009/11/17 22:34:17, 10] smbd/fileio.c:138(real_write_file) real_write_file (joerg/test): pos = 0, size = 6, returned 6 [2009/11/17 22:34:17, 3] smbd/reply.c:4239(reply_write_and_X) writeX fnum=4208 num=6 wrote=6 [2009/11/17 22:34:17, 10] lib/util_sock.c:789(read_smb_length_return_keepalive) got smb length of 41 [2009/11/17 22:34:17, 6] smbd/process.c:1456(process_smb) got message type 0x0 of len 0x29 [2009/11/17 22:34:17, 3] smbd/process.c:1459(process_smb) Transaction 20 of length 45 (0 toread) [2009/11/17 22:34:17, 5] lib/util.c:632(show_msg) [2009/11/17 22:34:17, 5] lib/util.c:642(show_msg) size=41 smb_com=0x4 smb_rcls=0 smb_reh=0 smb_err=0 smb_flg=0 smb_flg2=49153 smb_tid=1 smb_pid=7672 smb_uid=100 smb_mid=2003 smt_wct=3 smb_vwv[ 0]= 4208 (0x1070) smb_vwv[ 1]=65535 (0xFFFF) smb_vwv[ 2]=65535 (0xFFFF) smb_bcc=0 [2009/11/17 22:34:17, 3] smbd/process.c:1273(switch_message) switch message SMBclose (pid 6837) conn 0xa4eb898 [2009/11/17 22:34:17, 4] smbd/uid.c:256(change_to_user) change_to_user: Skipping user change - already user [2009/11/17 22:34:17, 3] smbd/reply.c:4456(reply_close) close fd=30 fnum=4208 (numopen=1) [2009/11/17 22:34:17, 6] smbd/close.c:454(set_close_write_time) close_write_time: Thu Jan 1 00:59:59 1970 [2009/11/17 22:34:17, 10] lib/dbwrap_tdb.c:100(db_tdb_fetch_locked) Locking key 0503000000000000B2E4 [2009/11/17 22:34:17, 10] lib/dbwrap_tdb.c:129(db_tdb_fetch_locked) Allocated locked data 0x0xa4f5e58 [2009/11/17 22:34:17, 10] locking/locking.c:552(parse_share_modes) parse_share_modes: delete_on_close: 0, owrt: Di 17 Nov 2009 22:34:17 CET CET, cwrt: Do 01 Jan 1970 01:00:00 CET CET, tok: 0, num_share_modes: 1 [2009/11/17 22:34:17, 10] locking/locking.c:649(parse_share_modes) parse_share_modes: share_mode_entry[0]: pid = 6837, share_access = 0x7, private_options = 0x40, access_mask = 0x86, mid = 0x0, type= 0x0, gen_id = 5, uid = 1000, flags = 1, file_id 305:34e4b2:0 [2009/11/17 22:34:17, 10] lib/dbwrap_tdb.c:42(db_tdb_record_destr) Unlocking key 0503000000000000B2E4 [2009/11/17 22:34:17, 10] locking/posix.c:495(get_windows_lock_ref_count) get_windows_lock_count for file joerg/test = 0 [2009/11/17 22:34:17, 10] locking/posix.c:521(delete_windows_lock_ref_count) delete_windows_lock_ref_count for file joerg/test [2009/11/17 22:34:17, 5] smbd/trans2.c:4922(smb_set_file_time) smb_set_filetime: actime: Tue Nov 17 22:34:17 2009 smb_set_filetime: modtime: Tue Nov 17 22:34:17 2009 smb_set_file_time: setting pending modtime to Tue Nov 17 22:34:17 2009 [2009/11/17 22:34:17, 10] lib/events.c:287(s3_event_debug) s3_event: Destroying timer event 0xa4ea780 "update_write_time_handler" [2009/11/17 22:34:17, 5] locking/locking.c:1425(set_sticky_write_time) set_sticky_write_time: Di 17 Nov 2009 22:34:17 CET CET id=305:34e4b2:0 [2009/11/17 22:34:17, 10] lib/dbwrap_tdb.c:100(db_tdb_fetch_locked) Locking key 0503000000000000B2E4 [2009/11/17 22:34:17, 10] lib/dbwrap_tdb.c:129(db_tdb_fetch_locked) Allocated locked data 0x0xa4eb1f0 [2009/11/17 22:34:17, 3] locking/locking.c:858(get_share_mode_lock) fill_share_mode_lock failed [2009/11/17 22:34:17, 10] lib/dbwrap_tdb.c:42(db_tdb_record_destr) Unlocking key 0503000000000000B2E4 [2009/11/17 22:34:17, 10] smbd/trans2.c:4972(smb_set_file_time) smb_set_file_time: setting utimes to modified values. [2009/11/17 22:34:17, 6] smbd/dosmode.c:721(file_ntimes) file_ntime: actime: Tue Nov 17 22:34:17 2009 [2009/11/17 22:34:17, 6] smbd/dosmode.c:723(file_ntimes) file_ntime: modtime: Tue Nov 17 22:34:17 2009 [2009/11/17 22:34:17, 6] smbd/dosmode.c:725(file_ntimes) file_ntime: createtime: Thu Jan 1 01:00:00 1970 [2009/11/17 22:34:17, 10] smbd/notify_internal.c:593(notify_trigger) notify_trigger called action=0x3, filter=0x10, path=/home/joerg/test [2009/11/17 22:34:17, 2] smbd/close.c:612(close_normal_file) joerg closed file joerg/test (numopen=0) NT_STATUS_OK [2009/11/17 22:34:17, 5] smbd/files.c:484(file_free) freed files structure 4208 (0 used) [2009/11/17 22:34:17, 5] lib/util.c:632(show_msg) [2009/11/17 22:34:17, 5] lib/util.c:642(show_msg) size=35 smb_com=0x4 smb_rcls=0 smb_reh=0 smb_err=0 smb_flg=128 smb_flg2=49153 smb_tid=1 smb_pid=7672 smb_uid=100 smb_mid=2003 smt_wct=0 smb_bcc=0 [2009/11/17 22:34:17, 10] lib/util_sock.c:789(read_smb_length_return_keepalive) got smb length of 116 [2009/11/17 22:34:17, 6] smbd/process.c:1456(process_smb) got message type 0x0 of len 0x74 [2009/11/17 22:34:17, 3] smbd/process.c:1459(process_smb) Transaction 21 of length 120 (0 toread) [2009/11/17 22:34:17, 5] lib/util.c:632(show_msg) [2009/11/17 22:34:17, 5] lib/util.c:642(show_msg) size=116 smb_com=0x32 smb_rcls=0 smb_reh=0 smb_err=0 smb_flg=0 smb_flg2=49153 smb_tid=1 smb_pid=15181 smb_uid=100 smb_mid=2004 smt_wct=15 smb_vwv[ 0]= 30 (0x1E) smb_vwv[ 1]= 18 (0x12) smb_vwv[ 2]= 2 (0x2) smb_vwv[ 3]= 1000 (0x3E8) smb_vwv[ 4]= 0 (0x0) smb_vwv[ 5]= 0 (0x0) smb_vwv[ 6]= 0 (0x0) smb_vwv[ 7]= 0 (0x0) smb_vwv[ 8]= 0 (0x0) smb_vwv[ 9]= 30 (0x1E) smb_vwv[10]= 68 (0x44) smb_vwv[11]= 18 (0x12) smb_vwv[12]= 98 (0x62) smb_vwv[13]= 1 (0x1) smb_vwv[14]= 6 (0x6) smb_bcc=51 [2009/11/17 22:34:17, 10] ../lib/util/util.c:304(_dump_data) [0000] 00 00 00 09 02 00 00 00 00 2F 00 6A 00 6F 00 65 ........ ./.j.o.e [0010] 00 72 00 67 00 2F 00 74 00 65 00 73 00 74 00 00 .r.g./.t .e.s.t.. [0020] 00 00 00 00 00 01 00 00 00 ED 01 00 00 00 00 00 ........ ........ [0030] 00 00 02 ... [2009/11/17 22:34:17, 3] smbd/process.c:1273(switch_message) switch message SMBtrans2 (pid 6837) conn 0xa4eb898 [2009/11/17 22:34:17, 4] smbd/uid.c:256(change_to_user) change_to_user: Skipping user change - already user [2009/11/17 22:34:17, 5] smbd/filename.c:148(unix_convert) unix_convert called on file "joerg/test" [2009/11/17 22:34:17, 5] smbd/filename.c:297(unix_convert) conversion finished joerg/test -> joerg/test [2009/11/17 22:34:17, 3] smbd/trans2.c:6886(call_trans2setfilepathinfo) call_trans2setfilepathinfo(6) joerg/test (fnum -1) info_level=521 totdata=18 [2009/11/17 22:34:17, 10] smbd/trans2.c:6506(smb_posix_open) smb_posix_open: file joerg/test, smb_posix_flags = 0, mode 0755 [2009/11/17 22:34:17, 10] smbd/open.c:3366(create_file_default) create_file: access_mask = 0x1 file_attributes = 0x10001ed, share_access = 0x7, create_disposition = 0x1 create_options = 0x40 oplock_request = 0x0 root_dir_fid = 0x0, ea_list = 0x(nil), sd = 0x(nil), create_file_flags = 0x0, fname = joerg/test [2009/11/17 22:34:17, 10] smbd/open.c:2896(create_file_unixpath) create_file_unixpath: access_mask = 0x1 file_attributes = 0x10001ed, share_access = 0x7, create_disposition = 0x1 create_options = 0x40 oplock_request = 0x0 ea_list = 0x(nil), sd = 0x(nil), fname = joerg/test [2009/11/17 22:34:17, 5] smbd/files.c:103(file_new) allocated file structure 113, fnum = 4209 (1 used) [2009/11/17 22:34:17, 10] smbd/open.c:1475(open_file_ntcreate) open_file_ntcreate: fname=joerg/test, dos_attrs=0x0 access_mask=0x1 share_access=0x7 create_disposition = 0x1 create_options=0x40 unix mode=0755 oplock_request=0 [2009/11/17 22:34:17, 10] smbd/open.c:1653(open_file_ntcreate) open_file_ntcreate: fname=joerg/test, after mapping access_mask=0x1 [2009/11/17 22:34:17, 10] lib/dbwrap_tdb.c:100(db_tdb_fetch_locked) Locking key 0503000000000000B2E4 [2009/11/17 22:34:17, 10] lib/dbwrap_tdb.c:129(db_tdb_fetch_locked) Allocated locked data 0x0xa4f6028 [2009/11/17 22:34:17, 10] smbd/open.c:980(delay_for_oplocks) delay_for_oplocks: oplock type 0x10 on file [2009/11/17 22:34:17, 10] smbd/open.c:980(delay_for_oplocks) delay_for_oplocks: oplock type 0x10 on file [2009/11/17 22:34:17, 4] smbd/open.c:1913(open_file_ntcreate) calling open_file with flags=0x0 flags2=0x0 mode=0755, access_mask = 0x1, open_access_mask = 0x1 [2009/11/17 22:34:17, 10] smbd/open.c:160(fd_open) fd_open: name joerg/test, flags = 0400000 mode = 0755, fd = 30. [2009/11/17 22:34:17, 2] smbd/open.c:580(open_file) joerg opened file joerg/test read=Yes write=No (numopen=1) [2009/11/17 22:34:17, 5] smbd/oplock.c:86(set_file_oplock) set_file_oplock: granted oplock on file joerg/test, 305:34e4b2:0/6, tv_sec = 4b0316d9, tv_usec = 5ed0f [2009/11/17 22:34:17, 10] locking/locking.c:716(unparse_share_modes) unparse_share_modes: del: 0, owrt: Di 17 Nov 2009 22:34:17 CET CET cwrt: Do 01 Jan 1970 01:00:00 CET CET, tok: 0, num: 1 [2009/11/17 22:34:17, 10] locking/locking.c:518(print_share_mode_table) print_share_mode_table: share_mode_entry[0]: pid = 6837, share_access = 0x7, private_options = 0x40, access_mask = 0x81, mid = 0x0, type= 0x10, gen_id = 6, uid = 1000, flags = 1, file_id 305:34e4b2:0 [2009/11/17 22:34:17, 10] lib/dbwrap_tdb.c:42(db_tdb_record_destr) Unlocking key 0503000000000000B2E4 [2009/11/17 22:34:17, 10] smbd/open.c:3201(create_file_unixpath) create_file_unixpath: info=1 [2009/11/17 22:34:17, 10] smbd/open.c:3496(create_file_default) create_file: info=1 [2009/11/17 22:34:17, 10] smbd/trans2.c:3520(store_file_unix_basic) store_file_unix_basic: SMB_QUERY_FILE_UNIX_BASIC [2009/11/17 22:34:17, 4] smbd/trans2.c:3521(store_file_unix_basic) store_file_unix_basic: st_mode=100644 [2009/11/17 22:34:17, 9] smbd/trans2.c:820(send_trans2_replies) t2_rep: params_sent_thistime = 2, data_sent_thistime = 112, useable_space = 16410 [2009/11/17 22:34:17, 9] smbd/trans2.c:822(send_trans2_replies) t2_rep: params_to_send = 2, data_to_send = 112, paramsize = 2, datasize = 112 [2009/11/17 22:34:17, 5] lib/util.c:632(show_msg) [2009/11/17 22:34:17, 5] lib/util.c:642(show_msg) size=172 smb_com=0x32 smb_rcls=0 smb_reh=0 smb_err=0 smb_flg=128 smb_flg2=49153 smb_tid=1 smb_pid=15181 smb_uid=100 smb_mid=2004 smt_wct=10 smb_vwv[ 0]= 2 (0x2) smb_vwv[ 1]= 112 (0x70) smb_vwv[ 2]= 0 (0x0) smb_vwv[ 3]= 2 (0x2) smb_vwv[ 4]= 56 (0x38) smb_vwv[ 5]= 0 (0x0) smb_vwv[ 6]= 112 (0x70) smb_vwv[ 7]= 60 (0x3C) smb_vwv[ 8]= 0 (0x0) smb_vwv[ 9]= 0 (0x0) smb_bcc=117 [2009/11/17 22:34:17, 10] ../lib/util/util.c:304(_dump_data) [0000] 00 00 00 00 00 00 00 71 10 01 00 00 00 00 02 00 .......q ........ [0010] 00 0A 00 00 00 00 00 00 00 00 10 00 00 00 00 00 ........ ........ [0020] 00 80 12 05 B7 CD 67 CA 01 80 12 05 B7 CD 67 CA ......g. ......g. [0030] 01 80 12 05 B7 CD 67 CA 01 E8 03 00 00 00 00 00 ......g. ........ [0040] 00 04 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ........ ........ [0050] 00 00 00 00 00 00 00 00 00 00 00 00 00 B2 E4 34 ........ .......4 [0060] 00 00 00 00 00 A4 01 00 00 00 00 00 00 01 00 00 ........ ........ [0070] 00 00 00 00 00 ..... [2009/11/17 22:34:17, 10] lib/util_sock.c:789(read_smb_length_return_keepalive) got smb length of 41 [2009/11/17 22:34:17, 6] smbd/process.c:1456(process_smb) got message type 0x0 of len 0x29 [2009/11/17 22:34:17, 3] smbd/process.c:1459(process_smb) Transaction 22 of length 45 (0 toread) [2009/11/17 22:34:17, 5] lib/util.c:632(show_msg) [2009/11/17 22:34:17, 5] lib/util.c:642(show_msg) size=41 smb_com=0x4 smb_rcls=0 smb_reh=0 smb_err=0 smb_flg=0 smb_flg2=49153 smb_tid=1 smb_pid=15181 smb_uid=100 smb_mid=2005 smt_wct=3 smb_vwv[ 0]= 4209 (0x1071) smb_vwv[ 1]=65535 (0xFFFF) smb_vwv[ 2]=65535 (0xFFFF) smb_bcc=0 [2009/11/17 22:34:17, 3] smbd/process.c:1273(switch_message) switch message SMBclose (pid 6837) conn 0xa4eb898 [2009/11/17 22:34:17, 4] smbd/uid.c:256(change_to_user) change_to_user: Skipping user change - already user [2009/11/17 22:34:17, 3] smbd/reply.c:4456(reply_close) close fd=30 fnum=4209 (numopen=1) [2009/11/17 22:34:17, 6] smbd/close.c:454(set_close_write_time) close_write_time: Thu Jan 1 00:59:59 1970 [2009/11/17 22:34:17, 10] lib/dbwrap_tdb.c:100(db_tdb_fetch_locked) Locking key 0503000000000000B2E4 [2009/11/17 22:34:17, 10] lib/dbwrap_tdb.c:129(db_tdb_fetch_locked) Allocated locked data 0x0xa4f5e58 [2009/11/17 22:34:17, 10] locking/locking.c:552(parse_share_modes) parse_share_modes: delete_on_close: 0, owrt: Di 17 Nov 2009 22:34:17 CET CET, cwrt: Do 01 Jan 1970 01:00:00 CET CET, tok: 0, num_share_modes: 1 [2009/11/17 22:34:17, 10] locking/locking.c:649(parse_share_modes) parse_share_modes: share_mode_entry[0]: pid = 6837, share_access = 0x7, private_options = 0x40, access_mask = 0x81, mid = 0x0, type= 0x10, gen_id = 6, uid = 1000, flags = 1, file_id 305:34e4b2:0 [2009/11/17 22:34:17, 10] lib/dbwrap_tdb.c:42(db_tdb_record_destr) Unlocking key 0503000000000000B2E4 [2009/11/17 22:34:17, 10] locking/posix.c:495(get_windows_lock_ref_count) get_windows_lock_count for file joerg/test = 0 [2009/11/17 22:34:17, 10] locking/posix.c:521(delete_windows_lock_ref_count) delete_windows_lock_ref_count for file joerg/test [2009/11/17 22:34:17, 2] smbd/close.c:612(close_normal_file) joerg closed file joerg/test (numopen=0) NT_STATUS_OK [2009/11/17 22:34:17, 5] smbd/files.c:484(file_free) freed files structure 4209 (0 used) [2009/11/17 22:34:17, 5] lib/util.c:632(show_msg) [2009/11/17 22:34:17, 5] lib/util.c:642(show_msg) size=35 smb_com=0x4 smb_rcls=0 smb_reh=0 smb_err=0 smb_flg=128 smb_flg2=49153 smb_tid=1 smb_pid=15181 smb_uid=100 smb_mid=2005 smt_wct=0 smb_bcc=0 [2009/11/17 22:35:10, 10] lib/events.c:105(run_events) Running timed event "smbd_idle_event_handler" 0xa4e32f8 [2009/11/17 22:35:10, 10] lib/events.c:287(s3_event_debug) s3_event: Destroying timer event 0xa4e32f8 "smbd_idle_event_handler" [2009/11/17 22:35:10, 10] smbd/process.c:663(smbd_idle_event_handler) smbd_idle_event_handler: idle_evt(deadtime) (nil) called [2009/11/17 22:35:10, 10] smbd/process.c:674(smbd_idle_event_handler) smbd_idle_event_handler: idle_evt(deadtime) (nil) rescheduled [2009/11/17 22:35:10, 10] lib/events.c:287(s3_event_debug) s3_event: Added timed event "smbd_idle_event_handler": 0xa4e7e58 [2009/11/17 22:35:10, 10] lib/events.c:105(run_events) Running timed event "smbd_idle_event_handler" 0xa4ed0e0 [2009/11/17 22:35:10, 10] lib/events.c:287(s3_event_debug) s3_event: Destroying timer event 0xa4ed0e0 "smbd_idle_event_handler" [2009/11/17 22:35:10, 10] smbd/process.c:663(smbd_idle_event_handler) smbd_idle_event_handler: idle_evt(housekeeping) (nil) called [2009/11/17 22:35:10, 3] smbd/sec_ctx.c:310(set_sec_ctx) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0 [2009/11/17 22:35:10, 5] auth/token_util.c:522(debug_nt_user_token) NT user token: (NULL) [2009/11/17 22:35:10, 5] auth/token_util.c:548(debug_unix_user_token) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2009/11/17 22:35:10, 5] smbd/uid.c:368(change_to_root_user) change_to_root_user: now uid=(0,0) gid=(0,0) [2009/11/17 22:35:10, 10] smbd/process.c:674(smbd_idle_event_handler) smbd_idle_event_handler: idle_evt(housekeeping) (nil) rescheduled [2009/11/17 22:35:10, 10] lib/events.c:287(s3_event_debug) s3_event: Added timed event "smbd_idle_event_handler": 0xa4e63f0 [2009/11/17 22:36:10, 10] lib/events.c:105(run_events) Running timed event "smbd_idle_event_handler" 0xa4e7e58 [2009/11/17 22:36:10, 10] lib/events.c:287(s3_event_debug) s3_event: Destroying timer event 0xa4e7e58 "smbd_idle_event_handler" [2009/11/17 22:36:10, 10] smbd/process.c:663(smbd_idle_event_handler) smbd_idle_event_handler: idle_evt(deadtime) (nil) called [2009/11/17 22:36:10, 10] smbd/process.c:674(smbd_idle_event_handler) smbd_idle_event_handler: idle_evt(deadtime) (nil) rescheduled [2009/11/17 22:36:10, 10] lib/events.c:287(s3_event_debug) s3_event: Added timed event "smbd_idle_event_handler": 0xa4dfcf0 [2009/11/17 22:36:10, 10] lib/events.c:105(run_events) Running timed event "smbd_idle_event_handler" 0xa4e63f0 [2009/11/17 22:36:10, 10] lib/events.c:287(s3_event_debug) s3_event: Destroying timer event 0xa4e63f0 "smbd_idle_event_handler" [2009/11/17 22:36:10, 10] smbd/process.c:663(smbd_idle_event_handler) smbd_idle_event_handler: idle_evt(housekeeping) (nil) called [2009/11/17 22:36:10, 3] smbd/sec_ctx.c:310(set_sec_ctx) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0 [2009/11/17 22:36:10, 5] auth/token_util.c:522(debug_nt_user_token) NT user token: (NULL) [2009/11/17 22:36:10, 5] auth/token_util.c:548(debug_unix_user_token) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2009/11/17 22:36:10, 5] smbd/uid.c:368(change_to_root_user) change_to_root_user: now uid=(0,0) gid=(0,0) [2009/11/17 22:36:10, 10] smbd/process.c:674(smbd_idle_event_handler) smbd_idle_event_handler: idle_evt(housekeeping) (nil) rescheduled [2009/11/17 22:36:10, 10] lib/events.c:287(s3_event_debug) s3_event: Added timed event "smbd_idle_event_handler": 0xa4ea780 [2009/11/17 22:37:10, 10] lib/events.c:105(run_events) Running timed event "smbd_idle_event_handler" 0xa4dfcf0 [2009/11/17 22:37:10, 10] lib/events.c:287(s3_event_debug) s3_event: Destroying timer event 0xa4dfcf0 "smbd_idle_event_handler" [2009/11/17 22:37:10, 10] smbd/process.c:663(smbd_idle_event_handler) smbd_idle_event_handler: idle_evt(deadtime) (nil) called [2009/11/17 22:37:10, 10] smbd/process.c:674(smbd_idle_event_handler) smbd_idle_event_handler: idle_evt(deadtime) (nil) rescheduled [2009/11/17 22:37:10, 10] lib/events.c:287(s3_event_debug) s3_event: Added timed event "smbd_idle_event_handler": 0xa4e32f8 [2009/11/17 22:37:10, 10] lib/events.c:105(run_events) Running timed event "smbd_idle_event_handler" 0xa4ea780 [2009/11/17 22:37:10, 10] lib/events.c:287(s3_event_debug) s3_event: Destroying timer event 0xa4ea780 "smbd_idle_event_handler" [2009/11/17 22:37:10, 10] smbd/process.c:663(smbd_idle_event_handler) smbd_idle_event_handler: idle_evt(housekeeping) (nil) called [2009/11/17 22:37:10, 3] smbd/sec_ctx.c:310(set_sec_ctx) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0 [2009/11/17 22:37:10, 5] auth/token_util.c:522(debug_nt_user_token) NT user token: (NULL) [2009/11/17 22:37:10, 5] auth/token_util.c:548(debug_unix_user_token) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2009/11/17 22:37:10, 5] smbd/uid.c:368(change_to_root_user) change_to_root_user: now uid=(0,0) gid=(0,0) [2009/11/17 22:37:10, 10] smbd/process.c:674(smbd_idle_event_handler) smbd_idle_event_handler: idle_evt(housekeeping) (nil) rescheduled [2009/11/17 22:37:10, 10] lib/events.c:287(s3_event_debug) s3_event: Added timed event "smbd_idle_event_handler": 0xa4ed0e0 [2009/11/17 22:38:10, 10] lib/events.c:105(run_events) Running timed event "smbd_idle_event_handler" 0xa4e32f8 [2009/11/17 22:38:10, 10] lib/events.c:287(s3_event_debug) s3_event: Destroying timer event 0xa4e32f8 "smbd_idle_event_handler" [2009/11/17 22:38:10, 10] smbd/process.c:663(smbd_idle_event_handler) smbd_idle_event_handler: idle_evt(deadtime) (nil) called [2009/11/17 22:38:10, 10] smbd/process.c:674(smbd_idle_event_handler) smbd_idle_event_handler: idle_evt(deadtime) (nil) rescheduled [2009/11/17 22:38:10, 10] lib/events.c:287(s3_event_debug) s3_event: Added timed event "smbd_idle_event_handler": 0xa4e7e58 [2009/11/17 22:38:10, 10] lib/events.c:105(run_events) Running timed event "smbd_idle_event_handler" 0xa4ed0e0 [2009/11/17 22:38:10, 10] lib/events.c:287(s3_event_debug) s3_event: Destroying timer event 0xa4ed0e0 "smbd_idle_event_handler" [2009/11/17 22:38:10, 10] smbd/process.c:663(smbd_idle_event_handler) smbd_idle_event_handler: idle_evt(housekeeping) (nil) called [2009/11/17 22:38:10, 3] smbd/sec_ctx.c:310(set_sec_ctx) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0 [2009/11/17 22:38:10, 5] auth/token_util.c:522(debug_nt_user_token) NT user token: (NULL) [2009/11/17 22:38:10, 5] auth/token_util.c:548(debug_unix_user_token) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2009/11/17 22:38:10, 5] smbd/uid.c:368(change_to_root_user) change_to_root_user: now uid=(0,0) gid=(0,0) [2009/11/17 22:38:10, 6] param/loadparm.c:6994(lp_file_list_changed) lp_file_list_changed() file /etc/samba/smb_perm-%a.conf -> /etc/samba/smb_perm-CIFSFS.conf last mod_time: Tue Nov 17 21:05:23 2009 file /etc/samba/smb.conf -> /etc/samba/smb.conf last mod_time: Tue Nov 17 22:33:54 2009 [2009/11/17 22:38:10, 10] smbd/process.c:674(smbd_idle_event_handler) smbd_idle_event_handler: idle_evt(housekeeping) (nil) rescheduled [2009/11/17 22:38:10, 10] lib/events.c:287(s3_event_debug) s3_event: Added timed event "smbd_idle_event_handler": 0xa4e63f0