[2016/05/06 13:52:12.329252, 6, pid=23960, effective(0, 0), real(0, 0)] ../source3/param/loadparm.c:2152(lp_file_list_changed) lp_file_list_changed() file /usr/local/etc/smb4.conf -> /usr/local/etc/smb4.conf last mod_time: Fri May 6 13:48:03 2016 [2016/05/06 13:52:12.329316, 3, pid=23960, effective(0, 0), real(0, 0), class=locking] ../source3/smbd/oplock.c:1306(init_oplocks) init_oplocks: initializing messages. [2016/05/06 13:52:12.329337, 5, pid=23960, effective(0, 0), real(0, 0)] ../source3/lib/messages.c:384(messaging_register) Registering messaging pointer for type 774 - private_data=0x8134bc4e0 [2016/05/06 13:52:12.329362, 5, pid=23960, effective(0, 0), real(0, 0)] ../source3/lib/messages.c:384(messaging_register) Registering messaging pointer for type 778 - private_data=0x8134bc4e0 [2016/05/06 13:52:12.329379, 5, pid=23960, effective(0, 0), real(0, 0)] ../source3/lib/messages.c:384(messaging_register) Registering messaging pointer for type 770 - private_data=0x8134bc4e0 [2016/05/06 13:52:12.329395, 5, pid=23960, effective(0, 0), real(0, 0)] ../source3/lib/messages.c:384(messaging_register) Registering messaging pointer for type 787 - private_data=0x8134bc4e0 [2016/05/06 13:52:12.329413, 5, pid=23960, effective(0, 0), real(0, 0)] ../source3/lib/messages.c:384(messaging_register) Registering messaging pointer for type 779 - private_data=0x8134bc4e0 [2016/05/06 13:52:12.329430, 5, pid=23960, effective(0, 0), real(0, 0)] ../source3/lib/messages.c:384(messaging_register) Registering messaging pointer for type 15 - private_data=0x0 [2016/05/06 13:52:12.329447, 5, pid=23960, effective(0, 0), real(0, 0)] ../source3/lib/messages.c:399(messaging_register) Overriding messaging pointer for type 15 - private_data=0x0 [2016/05/06 13:52:12.329464, 5, pid=23960, effective(0, 0), real(0, 0)] ../source3/lib/messages.c:431(messaging_deregister) Deregistering messaging pointer for type 16 - private_data=0x0 [2016/05/06 13:52:12.329480, 5, pid=23960, effective(0, 0), real(0, 0)] ../source3/lib/messages.c:384(messaging_register) Registering messaging pointer for type 16 - private_data=0x8134bc4e0 [2016/05/06 13:52:12.329499, 5, pid=23960, effective(0, 0), real(0, 0)] ../source3/lib/messages.c:431(messaging_deregister) Deregistering messaging pointer for type 33 - private_data=0x813458240 [2016/05/06 13:52:12.329514, 5, pid=23960, effective(0, 0), real(0, 0)] ../source3/lib/messages.c:384(messaging_register) Registering messaging pointer for type 33 - private_data=0x8134bc4e0 [2016/05/06 13:52:12.329531, 5, pid=23960, effective(0, 0), real(0, 0)] ../source3/lib/messages.c:431(messaging_deregister) Deregistering messaging pointer for type 790 - private_data=0x0 [2016/05/06 13:52:12.329550, 5, pid=23960, effective(0, 0), real(0, 0)] ../source3/lib/messages.c:384(messaging_register) Registering messaging pointer for type 790 - private_data=0x8134bc4e0 [2016/05/06 13:52:12.329566, 5, pid=23960, effective(0, 0), real(0, 0)] ../source3/lib/messages.c:431(messaging_deregister) Deregistering messaging pointer for type 791 - private_data=0x0 [2016/05/06 13:52:12.329584, 5, pid=23960, effective(0, 0), real(0, 0)] ../source3/lib/messages.c:431(messaging_deregister) Deregistering messaging pointer for type 1 - private_data=0x0 [2016/05/06 13:52:12.329600, 5, pid=23960, effective(0, 0), real(0, 0)] ../source3/lib/messages.c:384(messaging_register) Registering messaging pointer for type 1 - private_data=0x0 [2016/05/06 13:52:12.329619, 10, pid=23960, effective(0, 0), real(0, 0)] ../source3/lib/events.c:483(event_add_idle) event_add_idle: idle_evt(keepalive) 0x81344cd20 [2016/05/06 13:52:12.329639, 10, pid=23960, effective(0, 0), real(0, 0)] ../source3/lib/events.c:483(event_add_idle) event_add_idle: idle_evt(deadtime) 0x81344cde0 [2016/05/06 13:52:12.329656, 10, pid=23960, effective(0, 0), real(0, 0)] ../source3/lib/events.c:483(event_add_idle) event_add_idle: idle_evt(housekeeping) 0x81344cea0 [2016/05/06 13:52:12.329695, 10, pid=23960, effective(0, 0), real(0, 0)] ../source3/lib/util_sock.c:369(read_smb_length_return_keepalive) got smb length of 108 [2016/05/06 13:52:12.329722, 6, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/process.c:1877(process_smb) got message type 0x0 of len 0x6c [2016/05/06 13:52:12.329738, 3, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/process.c:1879(process_smb) Transaction 0 of length 112 (0 toread) [2016/05/06 13:52:12.329754, 10, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/smb2_server.c:3068(smbd_smb2_first_negprot) smbd_smb2_first_negprot: packet length 108 [2016/05/06 13:52:12.329792, 10, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/smb2_server.c:646(smb2_validate_sequence_number) smb2_validate_sequence_number: clearing id 0 (position 0) from bitmap [2016/05/06 13:52:12.329813, 10, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/smb2_server.c:1954(smbd_smb2_request_dispatch) smbd_smb2_request_dispatch: opcode[SMB2_OP_NEGPROT] mid = 0 [2016/05/06 13:52:12.329834, 4, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:316(set_sec_ctx) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0 [2016/05/06 13:52:12.329854, 5, pid=23960, effective(0, 0), real(0, 0)] ../libcli/security/security_token.c:53(security_token_debug) Security token: (NULL) [2016/05/06 13:52:12.329872, 5, pid=23960, effective(0, 0), real(0, 0)] ../source3/auth/token_util.c:639(debug_unix_user_token) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2016/05/06 13:52:12.329908, 5, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/uid.c:425(smbd_change_to_root_user) change_to_root_user: now uid=(0,0) gid=(0,0) [2016/05/06 13:52:12.329939, 10, pid=23960, effective(0, 0), real(0, 0)] ../source3/lib/util.c:1291(set_remote_arch) set_remote_arch: Client arch is 'Vista' [2016/05/06 13:52:12.329977, 6, pid=23960, effective(0, 0), real(0, 0)] ../source3/param/loadparm.c:2152(lp_file_list_changed) lp_file_list_changed() file /usr/local/etc/smb4.conf -> /usr/local/etc/smb4.conf last mod_time: Fri May 6 13:48:03 2016 [2016/05/06 13:52:12.330020, 3, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/smb2_negprot.c:211(smbd_smb2_request_process_negprot) Selected protocol SMB3_00 [2016/05/06 13:52:12.330040, 5, pid=23960, effective(0, 0), real(0, 0), class=auth] ../source3/auth/auth.c:491(make_auth_context_subsystem) Making default auth method list for server role = 'standalone server', encrypt passwords = yes [2016/05/06 13:52:12.330066, 5, pid=23960, effective(0, 0), real(0, 0), class=auth] ../source3/auth/auth.c:48(smb_register_auth) Attempting to register auth backend sam [2016/05/06 13:52:12.330091, 5, pid=23960, effective(0, 0), real(0, 0), class=auth] ../source3/auth/auth.c:60(smb_register_auth) Successfully added auth method 'sam' [2016/05/06 13:52:12.330108, 5, pid=23960, effective(0, 0), real(0, 0), class=auth] ../source3/auth/auth.c:48(smb_register_auth) Attempting to register auth backend sam_ignoredomain [2016/05/06 13:52:12.330124, 5, pid=23960, effective(0, 0), real(0, 0), class=auth] ../source3/auth/auth.c:60(smb_register_auth) Successfully added auth method 'sam_ignoredomain' [2016/05/06 13:52:12.330143, 5, pid=23960, effective(0, 0), real(0, 0), class=auth] ../source3/auth/auth.c:48(smb_register_auth) Attempting to register auth backend unix [2016/05/06 13:52:12.330159, 5, pid=23960, effective(0, 0), real(0, 0), class=auth] ../source3/auth/auth.c:60(smb_register_auth) Successfully added auth method 'unix' [2016/05/06 13:52:12.330175, 5, pid=23960, effective(0, 0), real(0, 0), class=auth] ../source3/auth/auth.c:48(smb_register_auth) Attempting to register auth backend winbind [2016/05/06 13:52:12.330193, 5, pid=23960, effective(0, 0), real(0, 0), class=auth] ../source3/auth/auth.c:60(smb_register_auth) Successfully added auth method 'winbind' [2016/05/06 13:52:12.330209, 5, pid=23960, effective(0, 0), real(0, 0), class=auth] ../source3/auth/auth.c:48(smb_register_auth) Attempting to register auth backend wbc [2016/05/06 13:52:12.330225, 5, pid=23960, effective(0, 0), real(0, 0), class=auth] ../source3/auth/auth.c:60(smb_register_auth) Successfully added auth method 'wbc' [2016/05/06 13:52:12.330244, 5, pid=23960, effective(0, 0), real(0, 0), class=auth] ../source3/auth/auth.c:48(smb_register_auth) Attempting to register auth backend trustdomain [2016/05/06 13:52:12.330260, 5, pid=23960, effective(0, 0), real(0, 0), class=auth] ../source3/auth/auth.c:60(smb_register_auth) Successfully added auth method 'trustdomain' [2016/05/06 13:52:12.330275, 5, pid=23960, effective(0, 0), real(0, 0), class=auth] ../source3/auth/auth.c:48(smb_register_auth) Attempting to register auth backend ntdomain [2016/05/06 13:52:12.330294, 5, pid=23960, effective(0, 0), real(0, 0), class=auth] ../source3/auth/auth.c:60(smb_register_auth) Successfully added auth method 'ntdomain' [2016/05/06 13:52:12.330310, 5, pid=23960, effective(0, 0), real(0, 0), class=auth] ../source3/auth/auth.c:48(smb_register_auth) Attempting to register auth backend guest [2016/05/06 13:52:12.330327, 5, pid=23960, effective(0, 0), real(0, 0), class=auth] ../source3/auth/auth.c:60(smb_register_auth) Successfully added auth method 'guest' [2016/05/06 13:52:12.330346, 5, pid=23960, effective(0, 0), real(0, 0), class=auth] ../source3/auth/auth.c:48(smb_register_auth) Attempting to register auth backend samba4 [2016/05/06 13:52:12.330362, 5, pid=23960, effective(0, 0), real(0, 0), class=auth] ../source3/auth/auth.c:60(smb_register_auth) Successfully added auth method 'samba4' [2016/05/06 13:52:12.330380, 5, pid=23960, effective(0, 0), real(0, 0), class=auth] ../source3/auth/auth.c:378(load_auth_module) load_auth_module: Attempting to find an auth method to match guest [2016/05/06 13:52:12.330397, 5, pid=23960, effective(0, 0), real(0, 0), class=auth] ../source3/auth/auth.c:403(load_auth_module) load_auth_module: auth method guest has a valid init [2016/05/06 13:52:12.330413, 5, pid=23960, effective(0, 0), real(0, 0), class=auth] ../source3/auth/auth.c:378(load_auth_module) load_auth_module: Attempting to find an auth method to match sam [2016/05/06 13:52:12.330433, 5, pid=23960, effective(0, 0), real(0, 0), class=auth] ../source3/auth/auth.c:403(load_auth_module) load_auth_module: auth method sam has a valid init [2016/05/06 13:52:12.331323, 3, pid=23960, effective(0, 0), real(0, 0)] ../auth/gensec/gensec_start.c:891(gensec_register) GENSEC backend 'gssapi_spnego' registered [2016/05/06 13:52:12.331362, 3, pid=23960, effective(0, 0), real(0, 0)] ../auth/gensec/gensec_start.c:891(gensec_register) GENSEC backend 'gssapi_krb5' registered [2016/05/06 13:52:12.331384, 3, pid=23960, effective(0, 0), real(0, 0)] ../auth/gensec/gensec_start.c:891(gensec_register) GENSEC backend 'gssapi_krb5_sasl' registered [2016/05/06 13:52:12.334157, 3, pid=23960, effective(0, 0), real(0, 0)] ../auth/gensec/gensec_start.c:891(gensec_register) GENSEC backend 'sasl-DIGEST-MD5' registered [2016/05/06 13:52:12.334183, 3, pid=23960, effective(0, 0), real(0, 0)] ../auth/gensec/gensec_start.c:891(gensec_register) GENSEC backend 'spnego' registered [2016/05/06 13:52:12.334206, 3, pid=23960, effective(0, 0), real(0, 0)] ../auth/gensec/gensec_start.c:891(gensec_register) GENSEC backend 'schannel' registered [2016/05/06 13:52:12.334223, 3, pid=23960, effective(0, 0), real(0, 0)] ../auth/gensec/gensec_start.c:891(gensec_register) GENSEC backend 'naclrpc_as_system' registered [2016/05/06 13:52:12.334240, 3, pid=23960, effective(0, 0), real(0, 0)] ../auth/gensec/gensec_start.c:891(gensec_register) GENSEC backend 'sasl-EXTERNAL' registered [2016/05/06 13:52:12.334260, 3, pid=23960, effective(0, 0), real(0, 0)] ../auth/gensec/gensec_start.c:891(gensec_register) GENSEC backend 'ntlmssp' registered [2016/05/06 13:52:12.334277, 3, pid=23960, effective(0, 0), real(0, 0)] ../auth/gensec/gensec_start.c:891(gensec_register) GENSEC backend 'http_basic' registered [2016/05/06 13:52:12.334294, 3, pid=23960, effective(0, 0), real(0, 0)] ../auth/gensec/gensec_start.c:891(gensec_register) GENSEC backend 'http_ntlm' registered [2016/05/06 13:52:12.334315, 3, pid=23960, effective(0, 0), real(0, 0)] ../auth/gensec/gensec_start.c:891(gensec_register) GENSEC backend 'krb5' registered [2016/05/06 13:52:12.334334, 3, pid=23960, effective(0, 0), real(0, 0)] ../auth/gensec/gensec_start.c:891(gensec_register) GENSEC backend 'fake_gssapi_krb5' registered [2016/05/06 13:52:12.334383, 5, pid=23960, effective(0, 0), real(0, 0)] ../auth/gensec/gensec_start.c:664(gensec_start_mech) Starting GENSEC mechanism spnego [2016/05/06 13:52:12.334419, 5, pid=23960, effective(0, 0), real(0, 0)] ../auth/gensec/gensec_start.c:664(gensec_start_mech) Starting GENSEC submechanism ntlmssp [2016/05/06 13:52:12.334489, 10, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/smb2_server.c:2597(smbd_smb2_request_done_ex) smbd_smb2_request_done_ex: idx[1] status[NT_STATUS_OK] body[64] dyn[yes:74] at ../source3/smbd/smb2_negprot.c:362 [2016/05/06 13:52:12.334515, 10, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/smb2_server.c:898(smb2_set_operation_credit) smb2_set_operation_credit: requested 31, charge 1, granted 1, current possible/max 512/512, total granted/max/low/range 1/8192/1/1 [2016/05/06 13:52:15.192684, 10, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/smb2_server.c:3464(smbd_smb2_io_handler) smbd_smb2_request idx[1] of 5 vectors [2016/05/06 13:52:15.192741, 10, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/smb2_server.c:646(smb2_validate_sequence_number) smb2_validate_sequence_number: clearing id 1 (position 1) from bitmap [2016/05/06 13:52:15.192769, 10, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/smb2_server.c:1954(smbd_smb2_request_dispatch) smbd_smb2_request_dispatch: opcode[SMB2_OP_SESSSETUP] mid = 1 [2016/05/06 13:52:15.192789, 4, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:316(set_sec_ctx) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0 [2016/05/06 13:52:15.192805, 5, pid=23960, effective(0, 0), real(0, 0)] ../libcli/security/security_token.c:53(security_token_debug) Security token: (NULL) [2016/05/06 13:52:15.192826, 5, pid=23960, effective(0, 0), real(0, 0)] ../source3/auth/token_util.c:639(debug_unix_user_token) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2016/05/06 13:52:15.192861, 5, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/uid.c:425(smbd_change_to_root_user) change_to_root_user: now uid=(0,0) gid=(0,0) [2016/05/06 13:52:15.192892, 5, pid=23960, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap.c:178(dbwrap_check_lock_order) check lock order 1 for /var/db/samba4/smbXsrv_session_global.tdb [2016/05/06 13:52:15.192914, 10, pid=23960, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap.c:133(debug_lock_order) lock order: 1:/var/db/samba4/smbXsrv_session_global.tdb 2: 3: [2016/05/06 13:52:15.192935, 10, pid=23960, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap_tdb.c:60(db_tdb_log_key) Locking key 9BE4145D [2016/05/06 13:52:15.192961, 10, pid=23960, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap_tdb.c:144(db_tdb_fetch_locked_internal) Allocated locked data 0x0x81344d0e0 [2016/05/06 13:52:15.193241, 10, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/smbXsrv_session.c:882(smbXsrv_session_global_store) [2016/05/06 13:52:15.193255, 10, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/smbXsrv_session.c:884(smbXsrv_session_global_store) smbXsrv_session_global_store: key '9BE4145D' stored [2016/05/06 13:52:15.193279, 1, pid=23960, effective(0, 0), real(0, 0)] ../librpc/ndr/ndr.c:402(ndr_print_debug) &global_blob: struct smbXsrv_session_globalB version : SMBXSRV_VERSION_0 (0) seqnum : 0x00000001 (1) info : union smbXsrv_session_globalU(case 0) info0 : * info0: struct smbXsrv_session_global0 db_rec : * session_global_id : 0x9be4145d (2615415901) session_wire_id : 0x000000009be4145d (2615415901) creation_time : Fri May 6 13:52:15 2016 AEST expiration_time : Thu Jan 1 10:00:00 1970 AEST auth_time : NTTIME(0) auth_session_info_seqnum : 0x00000000 (0) auth_session_info : NULL connection_dialect : 0x0300 (768) signing_required : 0x00 (0) encryption_required : 0x00 (0) num_channels : 0x00000001 (1) channels: ARRAY(1) channels: struct smbXsrv_channel_global0 server_id: struct server_id pid : 0x0000000000005d98 (23960) task_id : 0x00000000 (0) vnn : 0xffffffff (4294967295) unique_id : 0xd4d63452b28ceef2 (-3110240962865205518) local_address : 'ipv4:10.198.251.3:445' remote_address : 'ipv4:10.1.2.119:61739' remote_name : '10.1.2.119' auth_session_info_seqnum : 0x00000000 (0) connection : * [2016/05/06 13:52:15.193558, 10, pid=23960, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap_tdb.c:60(db_tdb_log_key) Unlocking key 9BE4145D [2016/05/06 13:52:15.193580, 5, pid=23960, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap.c:146(dbwrap_lock_order_state_destructor) release lock order 1 for /var/db/samba4/smbXsrv_session_global.tdb [2016/05/06 13:52:15.193596, 10, pid=23960, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap.c:133(debug_lock_order) lock order: 1: 2: 3: [2016/05/06 13:52:15.193614, 10, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/smbXsrv_session.c:1276(smbXsrv_session_create) [2016/05/06 13:52:15.193626, 10, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/smbXsrv_session.c:1284(smbXsrv_session_create) smbXsrv_session_create: global_id (0x9be4145d) stored [2016/05/06 13:52:15.193642, 1, pid=23960, effective(0, 0), real(0, 0)] ../librpc/ndr/ndr.c:402(ndr_print_debug) &session_blob: struct smbXsrv_sessionB version : SMBXSRV_VERSION_0 (0) reserved : 0x00000000 (0) info : union smbXsrv_sessionU(case 0) info0 : * info0: struct smbXsrv_session table : * db_rec : NULL client : * local_id : 0x9be4145d (2615415901) global : * global: struct smbXsrv_session_global0 db_rec : NULL session_global_id : 0x9be4145d (2615415901) session_wire_id : 0x000000009be4145d (2615415901) creation_time : Fri May 6 13:52:15 2016 AEST expiration_time : Thu Jan 1 10:00:00 1970 AEST auth_time : NTTIME(0) auth_session_info_seqnum : 0x00000000 (0) auth_session_info : NULL connection_dialect : 0x0300 (768) signing_required : 0x00 (0) encryption_required : 0x00 (0) num_channels : 0x00000001 (1) channels: ARRAY(1) channels: struct smbXsrv_channel_global0 server_id: struct server_id pid : 0x0000000000005d98 (23960) task_id : 0x00000000 (0) vnn : 0xffffffff (4294967295) unique_id : 0xd4d63452b28ceef2 (-3110240962865205518) local_address : 'ipv4:10.198.251.3:445' remote_address : 'ipv4:10.1.2.119:61739' remote_name : '10.1.2.119' auth_session_info_seqnum : 0x00000000 (0) connection : * status : NT_STATUS_MORE_PROCESSING_REQUIRED idle_time : Fri May 6 13:52:15 2016 AEST nonce_high : 0x0000000000000000 (0) nonce_low : 0x0000000000000000 (0) gensec : NULL compat : NULL tcon_table : * encryption_desired : 0x00 (0) [2016/05/06 13:52:15.194034, 5, pid=23960, effective(0, 0), real(0, 0), class=auth] ../source3/auth/auth.c:491(make_auth_context_subsystem) Making default auth method list for server role = 'standalone server', encrypt passwords = yes [2016/05/06 13:52:15.194055, 5, pid=23960, effective(0, 0), real(0, 0), class=auth] ../source3/auth/auth.c:378(load_auth_module) load_auth_module: Attempting to find an auth method to match guest [2016/05/06 13:52:15.194078, 5, pid=23960, effective(0, 0), real(0, 0), class=auth] ../source3/auth/auth.c:403(load_auth_module) load_auth_module: auth method guest has a valid init [2016/05/06 13:52:15.194095, 5, pid=23960, effective(0, 0), real(0, 0), class=auth] ../source3/auth/auth.c:378(load_auth_module) load_auth_module: Attempting to find an auth method to match sam [2016/05/06 13:52:15.194112, 5, pid=23960, effective(0, 0), real(0, 0), class=auth] ../source3/auth/auth.c:403(load_auth_module) load_auth_module: auth method sam has a valid init [2016/05/06 13:52:15.194166, 5, pid=23960, effective(0, 0), real(0, 0)] ../auth/gensec/gensec_start.c:664(gensec_start_mech) Starting GENSEC mechanism spnego [2016/05/06 13:52:15.194186, 4, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:216(push_sec_ctx) push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1 [2016/05/06 13:52:15.194204, 4, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/uid.c:491(push_conn_ctx) push_conn_ctx(0) : conn_ctx_stack_ndx = 0 [2016/05/06 13:52:15.194224, 4, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:316(set_sec_ctx) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1 [2016/05/06 13:52:15.194240, 5, pid=23960, effective(0, 0), real(0, 0)] ../libcli/security/security_token.c:53(security_token_debug) Security token: (NULL) [2016/05/06 13:52:15.194255, 5, pid=23960, effective(0, 0), real(0, 0)] ../source3/auth/token_util.c:639(debug_unix_user_token) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2016/05/06 13:52:15.194294, 4, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:421(pop_sec_ctx) pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0 smbd_smb2_request_pending_queue: req->current_idx = 1 req->in.vector[0].iov_len = 0 req->in.vector[1].iov_len = 0 req->in.vector[2].iov_len = 64 req->in.vector[3].iov_len = 24 req->in.vector[4].iov_len = 74 req->out.vector[0].iov_len = 4 req->out.vector[1].iov_len = 0 req->out.vector[2].iov_len = 64 req->out.vector[3].iov_len = 8 req->out.vector[4].iov_len = 0 [2016/05/06 13:52:15.194431, 5, pid=23960, effective(0, 0), real(0, 0)] ../auth/gensec/gensec_start.c:664(gensec_start_mech) Starting GENSEC submechanism ntlmssp [2016/05/06 13:52:15.194459, 3, pid=23960, effective(0, 0), real(0, 0)] ../auth/ntlmssp/ntlmssp_util.c:34(debug_ntlmssp_flags) Got NTLMSSP neg_flags=0xe2088297 NTLMSSP_NEGOTIATE_UNICODE NTLMSSP_NEGOTIATE_OEM NTLMSSP_REQUEST_TARGET NTLMSSP_NEGOTIATE_SIGN NTLMSSP_NEGOTIATE_LM_KEY NTLMSSP_NEGOTIATE_NTLM NTLMSSP_NEGOTIATE_ALWAYS_SIGN NTLMSSP_NEGOTIATE_NTLM2 NTLMSSP_NEGOTIATE_VERSION NTLMSSP_NEGOTIATE_128 NTLMSSP_NEGOTIATE_KEY_EXCH NTLMSSP_NEGOTIATE_56 [2016/05/06 13:52:15.195322, 1, pid=23960, effective(0, 0), real(0, 0)] ../librpc/ndr/ndr.c:402(ndr_print_debug) negotiate: struct NEGOTIATE_MESSAGE Signature : 'NTLMSSP' MessageType : NtLmNegotiate (1) NegotiateFlags : 0xe2088297 (3792208535) 1: NTLMSSP_NEGOTIATE_UNICODE 1: NTLMSSP_NEGOTIATE_OEM 1: NTLMSSP_REQUEST_TARGET 1: NTLMSSP_NEGOTIATE_SIGN 0: NTLMSSP_NEGOTIATE_SEAL 0: NTLMSSP_NEGOTIATE_DATAGRAM 1: NTLMSSP_NEGOTIATE_LM_KEY 0: NTLMSSP_NEGOTIATE_NETWARE 1: NTLMSSP_NEGOTIATE_NTLM 0: NTLMSSP_NEGOTIATE_NT_ONLY 0: NTLMSSP_ANONYMOUS 0: NTLMSSP_NEGOTIATE_OEM_DOMAIN_SUPPLIED 0: NTLMSSP_NEGOTIATE_OEM_WORKSTATION_SUPPLIED 0: NTLMSSP_NEGOTIATE_THIS_IS_LOCAL_CALL 1: NTLMSSP_NEGOTIATE_ALWAYS_SIGN 0: NTLMSSP_TARGET_TYPE_DOMAIN 0: NTLMSSP_TARGET_TYPE_SERVER 0: NTLMSSP_TARGET_TYPE_SHARE 1: NTLMSSP_NEGOTIATE_EXTENDED_SESSIONSECURITY 0: NTLMSSP_NEGOTIATE_IDENTIFY 0: NTLMSSP_REQUEST_NON_NT_SESSION_KEY 0: NTLMSSP_NEGOTIATE_TARGET_INFO 1: NTLMSSP_NEGOTIATE_VERSION 1: NTLMSSP_NEGOTIATE_128 1: NTLMSSP_NEGOTIATE_KEY_EXCH 1: NTLMSSP_NEGOTIATE_56 DomainNameLen : 0x0000 (0) DomainNameMaxLen : 0x0000 (0) DomainName : NULL WorkstationLen : 0x0000 (0) WorkstationMaxLen : 0x0000 (0) Workstation : NULL Version: struct ntlmssp_VERSION ProductMajorVersion : NTLMSSP_WINDOWS_MAJOR_VERSION_6 (6) ProductMinorVersion : UNKNOWN_ENUM_VALUE (3) ProductBuild : 0x2580 (9600) Reserved: ARRAY(3) [0] : 0x00 (0) [1] : 0x00 (0) [2] : 0x00 (0) NTLMRevisionCurrent : NTLMSSP_REVISION_W2K3 (15) [2016/05/06 13:52:15.195724, 1, pid=23960, effective(0, 0), real(0, 0)] ../librpc/ndr/ndr.c:402(ndr_print_debug) challenge: struct CHALLENGE_MESSAGE Signature : 'NTLMSSP' MessageType : NtLmChallenge (0x2) TargetNameLen : 0x0012 (18) TargetNameMaxLen : 0x0012 (18) TargetName : * TargetName : 'CTY323439' NegotiateFlags : 0xe28a8215 (3800728085) 1: NTLMSSP_NEGOTIATE_UNICODE 0: NTLMSSP_NEGOTIATE_OEM 1: NTLMSSP_REQUEST_TARGET 1: NTLMSSP_NEGOTIATE_SIGN 0: NTLMSSP_NEGOTIATE_SEAL 0: NTLMSSP_NEGOTIATE_DATAGRAM 0: NTLMSSP_NEGOTIATE_LM_KEY 0: NTLMSSP_NEGOTIATE_NETWARE 1: NTLMSSP_NEGOTIATE_NTLM 0: NTLMSSP_NEGOTIATE_NT_ONLY 0: NTLMSSP_ANONYMOUS 0: NTLMSSP_NEGOTIATE_OEM_DOMAIN_SUPPLIED 0: NTLMSSP_NEGOTIATE_OEM_WORKSTATION_SUPPLIED 0: NTLMSSP_NEGOTIATE_THIS_IS_LOCAL_CALL 1: NTLMSSP_NEGOTIATE_ALWAYS_SIGN 0: NTLMSSP_TARGET_TYPE_DOMAIN 1: NTLMSSP_TARGET_TYPE_SERVER 0: NTLMSSP_TARGET_TYPE_SHARE 1: NTLMSSP_NEGOTIATE_EXTENDED_SESSIONSECURITY 0: NTLMSSP_NEGOTIATE_IDENTIFY 0: NTLMSSP_REQUEST_NON_NT_SESSION_KEY 1: NTLMSSP_NEGOTIATE_TARGET_INFO 1: NTLMSSP_NEGOTIATE_VERSION 1: NTLMSSP_NEGOTIATE_128 1: NTLMSSP_NEGOTIATE_KEY_EXCH 1: NTLMSSP_NEGOTIATE_56 ServerChallenge : 71e410cfe1cae7fe Reserved : 0000000000000000 TargetInfoLen : 0x004a (74) TargetNameInfoMaxLen : 0x004a (74) TargetInfo : * TargetInfo: struct AV_PAIR_LIST count : 0x00000005 (5) pair: ARRAY(5) pair: struct AV_PAIR AvId : MsvAvNbDomainName (0x2) AvLen : 0x0012 (18) Value : union ntlmssp_AvValue(case 0x2) AvNbDomainName : 'CTY323439' pair: struct AV_PAIR AvId : MsvAvNbComputerName (0x1) AvLen : 0x0012 (18) Value : union ntlmssp_AvValue(case 0x1) AvNbComputerName : 'CTY323439' pair: struct AV_PAIR AvId : MsvAvDnsDomainName (0x4) AvLen : 0x0000 (0) Value : union ntlmssp_AvValue(case 0x4) AvDnsDomainName : '' pair: struct AV_PAIR AvId : MsvAvDnsComputerName (0x3) AvLen : 0x0012 (18) Value : union ntlmssp_AvValue(case 0x3) AvDnsComputerName : 'localhost' pair: struct AV_PAIR AvId : MsvAvEOL (0x0) AvLen : 0x0000 (0) Value : union ntlmssp_AvValue(case 0x0) Version: struct ntlmssp_VERSION ProductMajorVersion : NTLMSSP_WINDOWS_MAJOR_VERSION_6 (0x6) ProductMinorVersion : NTLMSSP_WINDOWS_MINOR_VERSION_1 (0x1) ProductBuild : 0x0000 (0) Reserved : 000000 NTLMRevisionCurrent : NTLMSSP_REVISION_W2K3 (0xF) [2016/05/06 13:52:15.196333, 4, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:216(push_sec_ctx) push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1 [2016/05/06 13:52:15.196352, 4, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/uid.c:491(push_conn_ctx) push_conn_ctx(0) : conn_ctx_stack_ndx = 0 [2016/05/06 13:52:15.196369, 4, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:316(set_sec_ctx) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1 [2016/05/06 13:52:15.196389, 5, pid=23960, effective(0, 0), real(0, 0)] ../libcli/security/security_token.c:53(security_token_debug) Security token: (NULL) [2016/05/06 13:52:15.196405, 5, pid=23960, effective(0, 0), real(0, 0)] ../source3/auth/token_util.c:639(debug_unix_user_token) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2016/05/06 13:52:15.196443, 4, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:421(pop_sec_ctx) pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0 [2016/05/06 13:52:15.196464, 10, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/smb2_server.c:2597(smbd_smb2_request_done_ex) smbd_smb2_request_done_ex: idx[1] status[NT_STATUS_MORE_PROCESSING_REQUIRED] body[8] dyn[yes:179] at ../source3/smbd/smb2_sesssetup.c:167 [2016/05/06 13:52:15.196485, 10, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/smb2_server.c:898(smb2_set_operation_credit) smb2_set_operation_credit: requested 31, charge 1, granted 1, current possible/max 512/512, total granted/max/low/range 1/8192/2/1 [2016/05/06 13:52:15.202663, 10, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/smb2_server.c:3464(smbd_smb2_io_handler) smbd_smb2_request idx[1] of 5 vectors [2016/05/06 13:52:15.202696, 10, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/smb2_server.c:646(smb2_validate_sequence_number) smb2_validate_sequence_number: clearing id 2 (position 2) from bitmap [2016/05/06 13:52:15.202724, 10, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/smb2_server.c:1954(smbd_smb2_request_dispatch) smbd_smb2_request_dispatch: opcode[SMB2_OP_SESSSETUP] mid = 2 [2016/05/06 13:52:15.202744, 4, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:316(set_sec_ctx) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0 [2016/05/06 13:52:15.202761, 5, pid=23960, effective(0, 0), real(0, 0)] ../libcli/security/security_token.c:53(security_token_debug) Security token: (NULL) [2016/05/06 13:52:15.202781, 5, pid=23960, effective(0, 0), real(0, 0)] ../source3/auth/token_util.c:639(debug_unix_user_token) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2016/05/06 13:52:15.202810, 5, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/uid.c:425(smbd_change_to_root_user) change_to_root_user: now uid=(0,0) gid=(0,0) [2016/05/06 13:52:15.202830, 4, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:216(push_sec_ctx) push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1 [2016/05/06 13:52:15.202854, 4, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/uid.c:491(push_conn_ctx) push_conn_ctx(0) : conn_ctx_stack_ndx = 0 [2016/05/06 13:52:15.202870, 4, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:316(set_sec_ctx) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1 [2016/05/06 13:52:15.202886, 5, pid=23960, effective(0, 0), real(0, 0)] ../libcli/security/security_token.c:53(security_token_debug) Security token: (NULL) [2016/05/06 13:52:15.202905, 5, pid=23960, effective(0, 0), real(0, 0)] ../source3/auth/token_util.c:639(debug_unix_user_token) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2016/05/06 13:52:15.202936, 4, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:421(pop_sec_ctx) pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0 smbd_smb2_request_pending_queue: req->current_idx = 1 req->in.vector[0].iov_len = 0 req->in.vector[1].iov_len = 0 req->in.vector[2].iov_len = 64 req->in.vector[3].iov_len = 24 req->in.vector[4].iov_len = 474 req->out.vector[0].iov_len = 4 req->out.vector[1].iov_len = 0 req->out.vector[2].iov_len = 64 req->out.vector[3].iov_len = 8 req->out.vector[4].iov_len = 0 [2016/05/06 13:52:15.203073, 1, pid=23960, effective(0, 0), real(0, 0)] ../librpc/ndr/ndr.c:402(ndr_print_debug) authenticate: struct AUTHENTICATE_MESSAGE Signature : 'NTLMSSP' MessageType : NtLmAuthenticate (3) LmChallengeResponseLen : 0x0018 (24) LmChallengeResponseMaxLen: 0x0018 (24) LmChallengeResponse : * LmChallengeResponse : union ntlmssp_LM_RESPONSE(case 24) v1: struct LM_RESPONSE Response : 000000000000000000000000000000000000000000000000 NtChallengeResponseLen : 0x0116 (278) NtChallengeResponseMaxLen: 0x0116 (278) NtChallengeResponse : * NtChallengeResponse : union ntlmssp_NTLM_RESPONSE(case 278) v2: struct NTLMv2_RESPONSE Response : 66378f09fe72a06c6f31f0a178df0c22 Challenge: struct NTLMv2_CLIENT_CHALLENGE RespType : 0x01 (1) HiRespType : 0x01 (1) Reserved1 : 0x0000 (0) Reserved2 : 0x00000000 (0) TimeStamp : Fri May 6 13:52:21 2016 AEST ChallengeFromClient : 68bc0e348319f100 Reserved3 : 0x00000000 (0) AvPairs: struct AV_PAIR_LIST count : 0x00000008 (8) pair: ARRAY(8) pair: struct AV_PAIR AvId : MsvAvNbDomainName (0x2) AvLen : 0x0012 (18) Value : union ntlmssp_AvValue(case 0x2) AvNbDomainName : 'CTY323439' pair: struct AV_PAIR AvId : MsvAvNbComputerName (0x1) AvLen : 0x0012 (18) Value : union ntlmssp_AvValue(case 0x1) AvNbComputerName : 'CTY323439' pair: struct AV_PAIR AvId : MsvAvDnsDomainName (0x4) AvLen : 0x0000 (0) Value : union ntlmssp_AvValue(case 0x4) AvDnsDomainName : '' pair: struct AV_PAIR AvId : MsvAvDnsComputerName (0x3) AvLen : 0x0012 (18) Value : union ntlmssp_AvValue(case 0x3) AvDnsComputerName : 'localhost' pair: struct AV_PAIR AvId : MsAvRestrictions (0x8) AvLen : 0x0030 (48) Value : union ntlmssp_AvValue(case 0x8) AvRestrictions: struct Restriction_Encoding Size : 0x00000030 (48) Z4 : 0x00000000 (0) IntegrityLevel : 0x00000001 (1) SubjectIntegrityLevel : 0x00002000 (8192) MachineId : 364e0def163d577c9809f685a5ae884e35ef55d110f71c07631c38de9199fa81 pair: struct AV_PAIR AvId : MsvChannelBindings (0xA) AvLen : 0x0010 (16) Value : union ntlmssp_AvValue(case 0xA) ChannelBindings : 00000000000000000000000000000000 pair: struct AV_PAIR AvId : MsvAvTargetName (0x9) AvLen : 0x0050 (80) Value : union ntlmssp_AvValue(case 0x9) AvTargetName : 'cifs/cty323439.scc.shoalhaven.nsw.gov.au' pair: struct AV_PAIR AvId : MsvAvEOL (0x0) AvLen : 0x0000 (0) Value : union ntlmssp_AvValue(case 0x0) DomainNameLen : 0x0014 (20) DomainNameMaxLen : 0x0014 (20) DomainName : * DomainName : 'SCC_DOMAIN' UserNameLen : 0x000e (14) UserNameMaxLen : 0x000e (14) UserName : * UserName : 'counter' WorkstationLen : 0x0012 (18) WorkstationMaxLen : 0x0012 (18) Workstation : * Workstation : 'TECHTOOLS' EncryptedRandomSessionKeyLen: 0x0010 (16) EncryptedRandomSessionKeyMaxLen: 0x0010 (16) EncryptedRandomSessionKey: * EncryptedRandomSessionKey: DATA_BLOB length=16 [0000] E2 B1 F1 6E 10 C7 6E A9 15 2F 6D 1C 43 02 F6 37 ...n..n. ./m.C..7 NegotiateFlags : 0xe2888215 (3800597013) 1: NTLMSSP_NEGOTIATE_UNICODE 0: NTLMSSP_NEGOTIATE_OEM 1: NTLMSSP_REQUEST_TARGET 1: NTLMSSP_NEGOTIATE_SIGN 0: NTLMSSP_NEGOTIATE_SEAL 0: NTLMSSP_NEGOTIATE_DATAGRAM 0: NTLMSSP_NEGOTIATE_LM_KEY 0: NTLMSSP_NEGOTIATE_NETWARE 1: NTLMSSP_NEGOTIATE_NTLM 0: NTLMSSP_NEGOTIATE_NT_ONLY 0: NTLMSSP_ANONYMOUS 0: NTLMSSP_NEGOTIATE_OEM_DOMAIN_SUPPLIED 0: NTLMSSP_NEGOTIATE_OEM_WORKSTATION_SUPPLIED 0: NTLMSSP_NEGOTIATE_THIS_IS_LOCAL_CALL 1: NTLMSSP_NEGOTIATE_ALWAYS_SIGN 0: NTLMSSP_TARGET_TYPE_DOMAIN 0: NTLMSSP_TARGET_TYPE_SERVER 0: NTLMSSP_TARGET_TYPE_SHARE 1: NTLMSSP_NEGOTIATE_EXTENDED_SESSIONSECURITY 0: NTLMSSP_NEGOTIATE_IDENTIFY 0: NTLMSSP_REQUEST_NON_NT_SESSION_KEY 1: NTLMSSP_NEGOTIATE_TARGET_INFO 1: NTLMSSP_NEGOTIATE_VERSION 1: NTLMSSP_NEGOTIATE_128 1: NTLMSSP_NEGOTIATE_KEY_EXCH 1: NTLMSSP_NEGOTIATE_56 Version: struct ntlmssp_VERSION ProductMajorVersion : NTLMSSP_WINDOWS_MAJOR_VERSION_6 (6) ProductMinorVersion : UNKNOWN_ENUM_VALUE (3) ProductBuild : 0x2580 (9600) Reserved: ARRAY(3) [0] : 0x00 (0) [1] : 0x00 (0) [2] : 0x00 (0) NTLMRevisionCurrent : NTLMSSP_REVISION_W2K3 (15) [2016/05/06 13:52:15.204159, 3, pid=23960, effective(0, 0), real(0, 0)] ../auth/ntlmssp/ntlmssp_server.c:359(ntlmssp_server_preauth) Got user=[counter] domain=[SCC_DOMAIN] workstation=[TECHTOOLS] len1=24 len2=278 [2016/05/06 13:52:15.204189, 3, pid=23960, effective(0, 0), real(0, 0)] ../source3/param/loadparm.c:3647(lp_load_ex) lp_load_ex: refreshing parameters [2016/05/06 13:52:15.204207, 5, pid=23960, effective(0, 0), real(0, 0)] ../source3/param/loadparm.c:1234(free_param_opts) Freeing parametrics: [2016/05/06 13:52:15.204288, 3, pid=23960, effective(0, 0), real(0, 0)] ../source3/param/loadparm.c:564(init_globals) Initialising global parameters [2016/05/06 13:52:15.204424, 3, pid=23960, effective(0, 0), real(0, 0)] ../source3/param/loadparm.c:2597(lp_do_section) Processing section "[global]" doing parameter workgroup = samba doing parameter encrypt passwords = yes doing parameter wins support = no doing parameter log level = 10 [2016/05/06 13:52:15.204511, 5, pid=23960, effective(0, 0), real(0, 0)] ../lib/util/debug.c:334(debug_dump_status) INFO: Current debug levels: all: 10 tdb: 10 printdrivers: 10 lanman: 10 smb: 10 rpc_parse: 10 rpc_srv: 10 rpc_cli: 10 passdb: 10 sam: 10 auth: 10 winbind: 10 vfs: 10 idmap: 10 quota: 10 acls: 10 locking: 10 msdfs: 10 dmapi: 10 registry: 10 scavenger: 10 dns: 10 ldb: 10 doing parameter max log size = 1000 doing parameter read only = no doing parameter log file = /var/log/samba4/log.%m doing parameter max log size = 2500 [2016/05/06 13:52:15.204740, 2, pid=23960, effective(0, 0), real(0, 0)] ../source3/param/loadparm.c:2614(lp_do_section) Processing section "[usb_media]" doing parameter comment = usb_media doing parameter path = /media doing parameter public = no doing parameter writeable = no doing parameter valid users = counter andrew [2016/05/06 13:52:15.204848, 4, pid=23960, effective(0, 0), real(0, 0)] ../source3/param/loadparm.c:3688(lp_load_ex) pm_process() returned Yes [2016/05/06 13:52:15.204871, 7, pid=23960, effective(0, 0), real(0, 0)] ../source3/param/loadparm.c:3995(lp_servicenumber) lp_servicenumber: couldn't find homes [2016/05/06 13:52:15.204899, 3, pid=23960, effective(0, 0), real(0, 0)] ../source3/param/loadparm.c:1495(lp_add_ipc) adding IPC service [2016/05/06 13:52:15.204923, 5, pid=23960, effective(0, 0), real(0, 0), class=auth] ../source3/auth/auth_util.c:116(make_user_info_map) Mapping user [SCC_DOMAIN]\[counter] from workstation [TECHTOOLS] [2016/05/06 13:52:15.204944, 5, pid=23960, effective(0, 0), real(0, 0), class=auth] ../source3/auth/auth_util.c:138(make_user_info_map) Mapped domain from [SCC_DOMAIN] to [CTY323439] for user [counter] from workstation [TECHTOOLS] [2016/05/06 13:52:15.204966, 5, pid=23960, effective(0, 0), real(0, 0), class=auth] ../source3/auth/user_info.c:62(make_user_info) attempting to make a user_info for counter (counter) [2016/05/06 13:52:15.204983, 5, pid=23960, effective(0, 0), real(0, 0), class=auth] ../source3/auth/user_info.c:70(make_user_info) making strings for counter's user_info struct [2016/05/06 13:52:15.205005, 5, pid=23960, effective(0, 0), real(0, 0), class=auth] ../source3/auth/user_info.c:108(make_user_info) making blobs for counter's user_info struct [2016/05/06 13:52:15.205022, 10, pid=23960, effective(0, 0), real(0, 0), class=auth] ../source3/auth/user_info.c:159(make_user_info) made a user_info for counter (counter) [2016/05/06 13:52:15.205039, 3, pid=23960, effective(0, 0), real(0, 0), class=auth] ../source3/auth/auth.c:178(auth_check_ntlm_password) check_ntlm_password: Checking password for unmapped user [SCC_DOMAIN]\[counter]@[TECHTOOLS] with the new password interface [2016/05/06 13:52:15.205059, 3, pid=23960, effective(0, 0), real(0, 0), class=auth] ../source3/auth/auth.c:181(auth_check_ntlm_password) check_ntlm_password: mapped user is: [CTY323439]\[counter]@[TECHTOOLS] [2016/05/06 13:52:15.205076, 10, pid=23960, effective(0, 0), real(0, 0), class=auth] ../source3/auth/auth.c:190(auth_check_ntlm_password) check_ntlm_password: auth_context challenge created by random [2016/05/06 13:52:15.205096, 10, pid=23960, effective(0, 0), real(0, 0), class=auth] ../source3/auth/auth.c:192(auth_check_ntlm_password) challenge is: [2016/05/06 13:52:15.205112, 5, pid=23960, effective(0, 0), real(0, 0)] ../lib/util/util.c:559(dump_data) [0000] 71 E4 10 CF E1 CA E7 FE q....... [2016/05/06 13:52:15.205138, 10, pid=23960, effective(0, 0), real(0, 0), class=auth] ../source3/auth/auth_builtin.c:44(check_guest_security) Check auth for: [counter] [2016/05/06 13:52:15.205158, 10, pid=23960, effective(0, 0), real(0, 0), class=auth] ../source3/auth/auth.c:233(auth_check_ntlm_password) check_ntlm_password: guest had nothing to say [2016/05/06 13:52:15.205176, 10, pid=23960, effective(0, 0), real(0, 0), class=auth] ../source3/auth/auth_sam.c:75(auth_samstrict_auth) Check auth for: [counter] [2016/05/06 13:52:15.205193, 8, pid=23960, effective(0, 0), real(0, 0)] ../source3/lib/util.c:1205(is_myname) is_myname("CTY323439") returns 1 [2016/05/06 13:52:15.205212, 4, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:216(push_sec_ctx) push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1 [2016/05/06 13:52:15.205234, 4, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/uid.c:491(push_conn_ctx) push_conn_ctx(0) : conn_ctx_stack_ndx = 0 [2016/05/06 13:52:15.205250, 4, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:316(set_sec_ctx) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1 [2016/05/06 13:52:15.205266, 5, pid=23960, effective(0, 0), real(0, 0)] ../libcli/security/security_token.c:53(security_token_debug) Security token: (NULL) [2016/05/06 13:52:15.205287, 5, pid=23960, effective(0, 0), real(0, 0)] ../source3/auth/token_util.c:639(debug_unix_user_token) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2016/05/06 13:52:15.205340, 10, pid=23960, effective(0, 0), real(0, 0), class=passdb] ../source3/passdb/pdb_get_set.c:570(pdb_set_username) pdb_set_username: setting username counter, was [2016/05/06 13:52:15.205366, 10, pid=23960, effective(0, 0), real(0, 0), class=passdb] ../source3/passdb/pdb_get_set.c:593(pdb_set_domain) pdb_set_domain: setting domain CTY323439, was [2016/05/06 13:52:15.205383, 10, pid=23960, effective(0, 0), real(0, 0), class=passdb] ../source3/passdb/pdb_get_set.c:616(pdb_set_nt_username) pdb_set_nt_username: setting nt username , was [2016/05/06 13:52:15.205400, 10, pid=23960, effective(0, 0), real(0, 0), class=passdb] ../source3/passdb/pdb_get_set.c:639(pdb_set_fullname) pdb_set_full_name: setting full name counter, was [2016/05/06 13:52:15.205423, 4, pid=23960, effective(0, 0), real(0, 0)] ../source3/lib/substitute.c:435(automount_server) Home server: cty323439 [2016/05/06 13:52:15.205444, 10, pid=23960, effective(0, 0), real(0, 0), class=passdb] ../source3/passdb/pdb_get_set.c:732(pdb_set_homedir) pdb_set_homedir: setting home dir \\cty323439\counter, was [2016/05/06 13:52:15.205462, 10, pid=23960, effective(0, 0), real(0, 0), class=passdb] ../source3/passdb/pdb_get_set.c:708(pdb_set_dir_drive) pdb_set_dir_drive: setting dir drive , was NULL [2016/05/06 13:52:15.205485, 10, pid=23960, effective(0, 0), real(0, 0), class=passdb] ../source3/passdb/pdb_get_set.c:662(pdb_set_logon_script) pdb_set_logon_script: setting logon script , was [2016/05/06 13:52:15.205502, 4, pid=23960, effective(0, 0), real(0, 0)] ../source3/lib/substitute.c:435(automount_server) Home server: cty323439 [2016/05/06 13:52:15.205521, 10, pid=23960, effective(0, 0), real(0, 0), class=passdb] ../source3/passdb/pdb_get_set.c:685(pdb_set_profile_path) pdb_set_profile_path: setting profile path \\cty323439\counter\profile, was [2016/05/06 13:52:15.205544, 10, pid=23960, effective(0, 0), real(0, 0), class=passdb] ../source3/passdb/pdb_get_set.c:775(pdb_set_workstations) pdb_set_workstations: setting workstations , was [2016/05/06 13:52:15.205563, 4, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:216(push_sec_ctx) push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 2 [2016/05/06 13:52:15.205585, 4, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/uid.c:491(push_conn_ctx) push_conn_ctx(0) : conn_ctx_stack_ndx = 1 [2016/05/06 13:52:15.205601, 4, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:316(set_sec_ctx) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 2 [2016/05/06 13:52:15.205617, 5, pid=23960, effective(0, 0), real(0, 0)] ../libcli/security/security_token.c:53(security_token_debug) Security token: (NULL) [2016/05/06 13:52:15.205633, 5, pid=23960, effective(0, 0), real(0, 0)] ../source3/auth/token_util.c:639(debug_unix_user_token) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2016/05/06 13:52:15.205673, 10, pid=23960, effective(0, 0), real(0, 0)] ../source3/passdb/account_pol.c:362(account_policy_get) account_policy_get: name: password history, val: 0 [2016/05/06 13:52:15.205695, 4, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:421(pop_sec_ctx) pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 1 [2016/05/06 13:52:15.205720, 10, pid=23960, effective(0, 0), real(0, 0), class=passdb] ../source3/passdb/pdb_get_set.c:495(pdb_set_user_sid) pdb_set_user_sid: setting user sid S-1-5-21-4127461147-3627497618-4263181281-1000 [2016/05/06 13:52:15.205742, 10, pid=23960, effective(0, 0), real(0, 0), class=passdb] ../source3/passdb/pdb_compat.c:73(pdb_set_user_sid_from_rid) pdb_set_user_sid_from_rid: setting user sid S-1-5-21-4127461147-3627497618-4263181281-1000 from rid 1000 [2016/05/06 13:52:15.205770, 4, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:216(push_sec_ctx) push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 2 [2016/05/06 13:52:15.205793, 4, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/uid.c:491(push_conn_ctx) push_conn_ctx(0) : conn_ctx_stack_ndx = 1 [2016/05/06 13:52:15.205808, 4, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:316(set_sec_ctx) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 2 [2016/05/06 13:52:15.205824, 5, pid=23960, effective(0, 0), real(0, 0)] ../libcli/security/security_token.c:53(security_token_debug) Security token: (NULL) [2016/05/06 13:52:15.205845, 5, pid=23960, effective(0, 0), real(0, 0)] ../source3/auth/token_util.c:639(debug_unix_user_token) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2016/05/06 13:52:15.205875, 10, pid=23960, effective(0, 0), real(0, 0)] ../source3/passdb/account_pol.c:362(account_policy_get) account_policy_get: name: maximum password age, val: -1 [2016/05/06 13:52:15.205902, 4, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:421(pop_sec_ctx) pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 1 [2016/05/06 13:52:15.205923, 5, pid=23960, effective(0, 0), real(0, 0)] ../source3/lib/username.c:181(Get_Pwnam_alloc) Finding user counter [2016/05/06 13:52:15.205940, 5, pid=23960, effective(0, 0), real(0, 0)] ../source3/lib/username.c:120(Get_Pwnam_internals) Trying _Get_Pwnam(), username as lowercase is counter [2016/05/06 13:52:15.238614, 5, pid=23960, effective(0, 0), real(0, 0)] ../source3/lib/username.c:159(Get_Pwnam_internals) Get_Pwnam_internals did find user [counter]! [2016/05/06 13:52:15.238712, 5, pid=23960, effective(0, 0), real(0, 0)] ../source3/passdb/lookup_sid.c:1278(gid_to_sid) gid_to_sid: winbind failed to find a sid for gid 1002 [2016/05/06 13:52:15.238732, 4, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:216(push_sec_ctx) push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 2 [2016/05/06 13:52:15.238750, 4, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/uid.c:491(push_conn_ctx) push_conn_ctx(0) : conn_ctx_stack_ndx = 1 [2016/05/06 13:52:15.238772, 4, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:316(set_sec_ctx) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 2 [2016/05/06 13:52:15.238788, 5, pid=23960, effective(0, 0), real(0, 0)] ../libcli/security/security_token.c:53(security_token_debug) Security token: (NULL) [2016/05/06 13:52:15.238804, 5, pid=23960, effective(0, 0), real(0, 0)] ../source3/auth/token_util.c:639(debug_unix_user_token) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2016/05/06 13:52:15.238853, 4, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:421(pop_sec_ctx) pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 1 [2016/05/06 13:52:15.238872, 10, pid=23960, effective(0, 0), real(0, 0)] ../source3/passdb/lookup_sid.c:1141(legacy_gid_to_sid) LEGACY: gid 1002 -> sid S-1-22-2-1002 [2016/05/06 13:52:15.238896, 3, pid=23960, effective(0, 0), real(0, 0)] ../source3/passdb/lookup_sid.c:1631(get_primary_group_sid) Forcing Primary Group to 'Domain Users' for counter [2016/05/06 13:52:15.238921, 4, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:216(push_sec_ctx) push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 2 [2016/05/06 13:52:15.238938, 4, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/uid.c:491(push_conn_ctx) push_conn_ctx(0) : conn_ctx_stack_ndx = 1 [2016/05/06 13:52:15.238953, 4, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:316(set_sec_ctx) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 2 [2016/05/06 13:52:15.238974, 5, pid=23960, effective(0, 0), real(0, 0)] ../libcli/security/security_token.c:53(security_token_debug) Security token: (NULL) [2016/05/06 13:52:15.238989, 5, pid=23960, effective(0, 0), real(0, 0)] ../source3/auth/token_util.c:639(debug_unix_user_token) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2016/05/06 13:52:15.239019, 10, pid=23960, effective(0, 0), real(0, 0)] ../source3/passdb/account_pol.c:362(account_policy_get) account_policy_get: name: password history, val: 0 [2016/05/06 13:52:15.239047, 4, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:421(pop_sec_ctx) pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 1 [2016/05/06 13:52:15.239071, 10, pid=23960, effective(0, 0), real(0, 0), class=passdb] ../source3/passdb/pdb_get_set.c:570(pdb_set_username) pdb_set_username: setting username counter, was [2016/05/06 13:52:15.239095, 10, pid=23960, effective(0, 0), real(0, 0), class=passdb] ../source3/passdb/pdb_get_set.c:593(pdb_set_domain) pdb_set_domain: setting domain CTY323439, was [2016/05/06 13:52:15.239118, 10, pid=23960, effective(0, 0), real(0, 0), class=passdb] ../source3/passdb/pdb_get_set.c:616(pdb_set_nt_username) pdb_set_nt_username: setting nt username , was [2016/05/06 13:52:15.239135, 10, pid=23960, effective(0, 0), real(0, 0), class=passdb] ../source3/passdb/pdb_get_set.c:639(pdb_set_fullname) pdb_set_full_name: setting full name counter, was [2016/05/06 13:52:15.239160, 4, pid=23960, effective(0, 0), real(0, 0)] ../source3/lib/substitute.c:435(automount_server) Home server: cty323439 [2016/05/06 13:52:15.239182, 10, pid=23960, effective(0, 0), real(0, 0), class=passdb] ../source3/passdb/pdb_get_set.c:732(pdb_set_homedir) pdb_set_homedir: setting home dir \\cty323439\counter, was [2016/05/06 13:52:15.239199, 10, pid=23960, effective(0, 0), real(0, 0), class=passdb] ../source3/passdb/pdb_get_set.c:708(pdb_set_dir_drive) pdb_set_dir_drive: setting dir drive , was NULL [2016/05/06 13:52:15.239222, 10, pid=23960, effective(0, 0), real(0, 0), class=passdb] ../source3/passdb/pdb_get_set.c:662(pdb_set_logon_script) pdb_set_logon_script: setting logon script , was [2016/05/06 13:52:15.239240, 4, pid=23960, effective(0, 0), real(0, 0)] ../source3/lib/substitute.c:435(automount_server) Home server: cty323439 [2016/05/06 13:52:15.239258, 10, pid=23960, effective(0, 0), real(0, 0), class=passdb] ../source3/passdb/pdb_get_set.c:685(pdb_set_profile_path) pdb_set_profile_path: setting profile path \\cty323439\counter\profile, was [2016/05/06 13:52:15.239282, 10, pid=23960, effective(0, 0), real(0, 0), class=passdb] ../source3/passdb/pdb_get_set.c:775(pdb_set_workstations) pdb_set_workstations: setting workstations , was [2016/05/06 13:52:15.239299, 4, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:216(push_sec_ctx) push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 2 [2016/05/06 13:52:15.239323, 4, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/uid.c:491(push_conn_ctx) push_conn_ctx(0) : conn_ctx_stack_ndx = 1 [2016/05/06 13:52:15.239340, 4, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:316(set_sec_ctx) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 2 [2016/05/06 13:52:15.239355, 5, pid=23960, effective(0, 0), real(0, 0)] ../libcli/security/security_token.c:53(security_token_debug) Security token: (NULL) [2016/05/06 13:52:15.239371, 5, pid=23960, effective(0, 0), real(0, 0)] ../source3/auth/token_util.c:639(debug_unix_user_token) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2016/05/06 13:52:15.239407, 10, pid=23960, effective(0, 0), real(0, 0)] ../source3/passdb/account_pol.c:362(account_policy_get) account_policy_get: name: password history, val: 0 [2016/05/06 13:52:15.239429, 4, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:421(pop_sec_ctx) pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 1 [2016/05/06 13:52:15.239452, 10, pid=23960, effective(0, 0), real(0, 0), class=passdb] ../source3/passdb/pdb_get_set.c:495(pdb_set_user_sid) pdb_set_user_sid: setting user sid S-1-5-21-4127461147-3627497618-4263181281-1000 [2016/05/06 13:52:15.239471, 10, pid=23960, effective(0, 0), real(0, 0), class=passdb] ../source3/passdb/pdb_compat.c:73(pdb_set_user_sid_from_rid) pdb_set_user_sid_from_rid: setting user sid S-1-5-21-4127461147-3627497618-4263181281-1000 from rid 1000 [2016/05/06 13:52:15.239497, 10, pid=23960, effective(0, 0), real(0, 0), class=passdb] ../source3/passdb/pdb_get_set.c:557(pdb_set_group_sid) pdb_set_group_sid: setting group sid S-1-5-21-4127461147-3627497618-4263181281-513 [2016/05/06 13:52:15.239528, 4, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:421(pop_sec_ctx) pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0 [2016/05/06 13:52:15.239549, 4, pid=23960, effective(0, 0), real(0, 0)] ../libcli/auth/ntlm_check.c:359(ntlm_password_check) ntlm_password_check: Checking NTLMv2 password with domain [SCC_DOMAIN] [2016/05/06 13:52:15.239601, 4, pid=23960, effective(0, 0), real(0, 0), class=auth] ../source3/auth/check_samsec.c:183(sam_account_ok) sam_account_ok: Checking SMB password for user counter [2016/05/06 13:52:15.239624, 5, pid=23960, effective(0, 0), real(0, 0), class=auth] ../source3/auth/check_samsec.c:165(logon_hours_ok) logon_hours_ok: user counter allowed to logon at this time (Fri May 6 03:52:15 2016 ) [2016/05/06 13:52:15.239647, 4, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:216(push_sec_ctx) push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1 [2016/05/06 13:52:15.239670, 4, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/uid.c:491(push_conn_ctx) push_conn_ctx(0) : conn_ctx_stack_ndx = 0 [2016/05/06 13:52:15.239686, 4, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:316(set_sec_ctx) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1 [2016/05/06 13:52:15.239703, 5, pid=23960, effective(0, 0), real(0, 0)] ../libcli/security/security_token.c:53(security_token_debug) Security token: (NULL) [2016/05/06 13:52:15.239724, 5, pid=23960, effective(0, 0), real(0, 0)] ../source3/auth/token_util.c:639(debug_unix_user_token) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2016/05/06 13:52:15.239756, 10, pid=23960, effective(0, 0), real(0, 0)] ../source3/passdb/account_pol.c:362(account_policy_get) account_policy_get: name: maximum password age, val: -1 [2016/05/06 13:52:15.239777, 4, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:421(pop_sec_ctx) pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0 [2016/05/06 13:52:15.239801, 4, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:216(push_sec_ctx) push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1 [2016/05/06 13:52:15.239818, 4, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/uid.c:491(push_conn_ctx) push_conn_ctx(0) : conn_ctx_stack_ndx = 0 [2016/05/06 13:52:15.239833, 4, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:316(set_sec_ctx) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1 [2016/05/06 13:52:15.239855, 5, pid=23960, effective(0, 0), real(0, 0)] ../libcli/security/security_token.c:53(security_token_debug) Security token: (NULL) [2016/05/06 13:52:15.239871, 5, pid=23960, effective(0, 0), real(0, 0)] ../source3/auth/token_util.c:639(debug_unix_user_token) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2016/05/06 13:52:15.239901, 5, pid=23960, effective(0, 0), real(0, 0)] ../source3/lib/username.c:181(Get_Pwnam_alloc) Finding user counter [2016/05/06 13:52:15.239925, 5, pid=23960, effective(0, 0), real(0, 0)] ../source3/lib/username.c:120(Get_Pwnam_internals) Trying _Get_Pwnam(), username as lowercase is counter [2016/05/06 13:52:15.239942, 5, pid=23960, effective(0, 0), real(0, 0)] ../source3/lib/username.c:159(Get_Pwnam_internals) Get_Pwnam_internals did find user [counter]! [2016/05/06 13:52:15.239962, 4, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:216(push_sec_ctx) push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 2 [2016/05/06 13:52:15.239985, 4, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/uid.c:491(push_conn_ctx) push_conn_ctx(0) : conn_ctx_stack_ndx = 1 [2016/05/06 13:52:15.240001, 4, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:316(set_sec_ctx) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 2 [2016/05/06 13:52:15.240017, 5, pid=23960, effective(0, 0), real(0, 0)] ../libcli/security/security_token.c:53(security_token_debug) Security token: (NULL) [2016/05/06 13:52:15.240039, 5, pid=23960, effective(0, 0), real(0, 0)] ../source3/auth/token_util.c:639(debug_unix_user_token) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2016/05/06 13:52:15.240070, 10, pid=23960, effective(0, 0), real(0, 0)] ../source3/passdb/account_pol.c:362(account_policy_get) account_policy_get: name: minimum password age, val: 0 [2016/05/06 13:52:15.240091, 4, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:421(pop_sec_ctx) pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 1 [2016/05/06 13:52:15.240115, 4, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:216(push_sec_ctx) push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 2 [2016/05/06 13:52:15.240132, 4, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/uid.c:491(push_conn_ctx) push_conn_ctx(0) : conn_ctx_stack_ndx = 1 [2016/05/06 13:52:15.240148, 4, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:316(set_sec_ctx) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 2 [2016/05/06 13:52:15.240170, 5, pid=23960, effective(0, 0), real(0, 0)] ../libcli/security/security_token.c:53(security_token_debug) Security token: (NULL) [2016/05/06 13:52:15.240185, 5, pid=23960, effective(0, 0), real(0, 0)] ../source3/auth/token_util.c:639(debug_unix_user_token) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2016/05/06 13:52:15.240214, 10, pid=23960, effective(0, 0), real(0, 0)] ../source3/passdb/account_pol.c:362(account_policy_get) account_policy_get: name: maximum password age, val: -1 [2016/05/06 13:52:15.240241, 4, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:421(pop_sec_ctx) pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 1 [2016/05/06 13:52:15.240260, 5, pid=23960, effective(0, 0), real(0, 0)] ../source3/lib/username.c:181(Get_Pwnam_alloc) Finding user counter [2016/05/06 13:52:15.240276, 5, pid=23960, effective(0, 0), real(0, 0)] ../source3/lib/username.c:120(Get_Pwnam_internals) Trying _Get_Pwnam(), username as lowercase is counter [2016/05/06 13:52:15.240298, 5, pid=23960, effective(0, 0), real(0, 0)] ../source3/lib/username.c:159(Get_Pwnam_internals) Get_Pwnam_internals did find user [counter]! [2016/05/06 13:52:15.240317, 10, pid=23960, effective(0, 0), real(0, 0)] ../source3/lib/system_smbd.c:176(sys_getgrouplist) sys_getgrouplist: user [counter] [2016/05/06 13:52:15.240542, 5, pid=23960, effective(0, 0), real(0, 0)] ../source3/passdb/lookup_sid.c:1278(gid_to_sid) gid_to_sid: winbind failed to find a sid for gid 1002 [2016/05/06 13:52:15.240568, 4, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:216(push_sec_ctx) push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 2 [2016/05/06 13:52:15.240584, 4, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/uid.c:491(push_conn_ctx) push_conn_ctx(0) : conn_ctx_stack_ndx = 1 [2016/05/06 13:52:15.240600, 4, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:316(set_sec_ctx) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 2 [2016/05/06 13:52:15.240622, 5, pid=23960, effective(0, 0), real(0, 0)] ../libcli/security/security_token.c:53(security_token_debug) Security token: (NULL) [2016/05/06 13:52:15.240638, 5, pid=23960, effective(0, 0), real(0, 0)] ../source3/auth/token_util.c:639(debug_unix_user_token) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2016/05/06 13:52:15.240674, 4, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:421(pop_sec_ctx) pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 1 [2016/05/06 13:52:15.240698, 10, pid=23960, effective(0, 0), real(0, 0)] ../source3/passdb/lookup_sid.c:1141(legacy_gid_to_sid) LEGACY: gid 1002 -> sid S-1-22-2-1002 [2016/05/06 13:52:15.240718, 5, pid=23960, effective(0, 0), real(0, 0), class=auth] ../source3/auth/server_info_sam.c:122(make_server_info_sam) make_server_info_sam: made server info for user counter -> counter [2016/05/06 13:52:15.240740, 4, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:421(pop_sec_ctx) pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0 [2016/05/06 13:52:15.240767, 3, pid=23960, effective(0, 0), real(0, 0), class=auth] ../source3/auth/auth.c:249(auth_check_ntlm_password) check_ntlm_password: sam authentication for user [counter] succeeded [2016/05/06 13:52:15.240787, 4, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:216(push_sec_ctx) push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1 [2016/05/06 13:52:15.240804, 4, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/uid.c:491(push_conn_ctx) push_conn_ctx(0) : conn_ctx_stack_ndx = 0 [2016/05/06 13:52:15.240826, 4, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:316(set_sec_ctx) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1 [2016/05/06 13:52:15.240842, 5, pid=23960, effective(0, 0), real(0, 0)] ../libcli/security/security_token.c:53(security_token_debug) Security token: (NULL) [2016/05/06 13:52:15.240857, 5, pid=23960, effective(0, 0), real(0, 0)] ../source3/auth/token_util.c:639(debug_unix_user_token) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2016/05/06 13:52:15.240894, 4, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:421(pop_sec_ctx) pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0 [2016/05/06 13:52:15.240912, 5, pid=23960, effective(0, 0), real(0, 0), class=auth] ../source3/auth/auth.c:292(auth_check_ntlm_password) check_ntlm_password: PAM Account for user [counter] succeeded [2016/05/06 13:52:15.240934, 2, pid=23960, effective(0, 0), real(0, 0), class=auth] ../source3/auth/auth.c:305(auth_check_ntlm_password) check_ntlm_password: authentication for user [counter] -> [counter] -> [counter] succeeded [2016/05/06 13:52:15.240951, 10, pid=23960, effective(0, 0), real(0, 0)] ../source3/auth/auth_ntlmssp.c:215(auth3_check_password) Got NT session key of length 16 [2016/05/06 13:52:15.240967, 10, pid=23960, effective(0, 0), real(0, 0)] ../source3/auth/auth_ntlmssp.c:222(auth3_check_password) Got LM session key of length 8 [2016/05/06 13:52:15.240991, 10, pid=23960, effective(0, 0), real(0, 0)] ../auth/ntlmssp/ntlmssp_server.c:539(ntlmssp_server_postauth) ntlmssp_server_auth: Using unmodified nt session key. [2016/05/06 13:52:15.241014, 3, pid=23960, effective(0, 0), real(0, 0)] ../auth/ntlmssp/ntlmssp_sign.c:547(ntlmssp_sign_init) NTLMSSP Sign/Seal - Initialising with flags: [2016/05/06 13:52:15.241030, 3, pid=23960, effective(0, 0), real(0, 0)] ../auth/ntlmssp/ntlmssp_util.c:34(debug_ntlmssp_flags) Got NTLMSSP neg_flags=0xe2088215 NTLMSSP_NEGOTIATE_UNICODE NTLMSSP_REQUEST_TARGET NTLMSSP_NEGOTIATE_SIGN NTLMSSP_NEGOTIATE_NTLM NTLMSSP_NEGOTIATE_ALWAYS_SIGN NTLMSSP_NEGOTIATE_NTLM2 NTLMSSP_NEGOTIATE_VERSION NTLMSSP_NEGOTIATE_128 NTLMSSP_NEGOTIATE_KEY_EXCH NTLMSSP_NEGOTIATE_56 [2016/05/06 13:52:15.241131, 4, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:216(push_sec_ctx) push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1 [2016/05/06 13:52:15.241156, 4, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/uid.c:491(push_conn_ctx) push_conn_ctx(0) : conn_ctx_stack_ndx = 0 [2016/05/06 13:52:15.241172, 4, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:316(set_sec_ctx) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1 [2016/05/06 13:52:15.241187, 5, pid=23960, effective(0, 0), real(0, 0)] ../libcli/security/security_token.c:53(security_token_debug) Security token: (NULL) [2016/05/06 13:52:15.241203, 5, pid=23960, effective(0, 0), real(0, 0)] ../source3/auth/token_util.c:639(debug_unix_user_token) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2016/05/06 13:52:15.241241, 4, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:421(pop_sec_ctx) pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0 [2016/05/06 13:52:15.241264, 10, pid=23960, effective(0, 0), real(0, 0)] ../source3/auth/token_util.c:224(create_local_nt_token_from_info3) Create local NT token for counter [2016/05/06 13:52:15.241307, 10, pid=23960, effective(0, 0), real(0, 0)] ../source3/lib/idmap_cache.c:56(idmap_cache_find_sid2unixid) Parsing value for key [IDMAP/SID2XID/S-1-5-21-4127461147-3627497618-4263181281-1000]: value=[1002:U] [2016/05/06 13:52:15.241327, 10, pid=23960, effective(0, 0), real(0, 0)] ../source3/lib/idmap_cache.c:75(idmap_cache_find_sid2unixid) Parsing value for key [IDMAP/SID2XID/S-1-5-21-4127461147-3627497618-4263181281-1000]: id=[1002], endptr=[:U] [2016/05/06 13:52:15.241345, 10, pid=23960, effective(0, 0), real(0, 0)] ../source3/passdb/lookup_sid.c:1454(sid_to_uid) sid S-1-5-21-4127461147-3627497618-4263181281-1000 -> uid 1002 [2016/05/06 13:52:15.241437, 10, pid=23960, effective(0, 0), real(0, 0)] ../source3/lib/system_smbd.c:176(sys_getgrouplist) sys_getgrouplist: user [counter] [2016/05/06 13:52:15.241640, 5, pid=23960, effective(0, 0), real(0, 0)] ../source3/passdb/lookup_sid.c:1278(gid_to_sid) gid_to_sid: winbind failed to find a sid for gid 1002 [2016/05/06 13:52:15.241666, 4, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:216(push_sec_ctx) push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1 [2016/05/06 13:52:15.241683, 4, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/uid.c:491(push_conn_ctx) push_conn_ctx(0) : conn_ctx_stack_ndx = 0 [2016/05/06 13:52:15.241699, 4, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:316(set_sec_ctx) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1 [2016/05/06 13:52:15.241715, 5, pid=23960, effective(0, 0), real(0, 0)] ../libcli/security/security_token.c:53(security_token_debug) Security token: (NULL) [2016/05/06 13:52:15.241737, 5, pid=23960, effective(0, 0), real(0, 0)] ../source3/auth/token_util.c:639(debug_unix_user_token) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2016/05/06 13:52:15.241773, 4, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:421(pop_sec_ctx) pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0 [2016/05/06 13:52:15.241791, 10, pid=23960, effective(0, 0), real(0, 0)] ../source3/passdb/lookup_sid.c:1141(legacy_gid_to_sid) LEGACY: gid 1002 -> sid S-1-22-2-1002 [2016/05/06 13:52:15.241827, 4, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:216(push_sec_ctx) push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1 [2016/05/06 13:52:15.241845, 4, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/uid.c:491(push_conn_ctx) push_conn_ctx(0) : conn_ctx_stack_ndx = 0 [2016/05/06 13:52:15.241860, 4, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:316(set_sec_ctx) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1 [2016/05/06 13:52:15.241883, 5, pid=23960, effective(0, 0), real(0, 0)] ../libcli/security/security_token.c:53(security_token_debug) Security token: (NULL) [2016/05/06 13:52:15.241898, 5, pid=23960, effective(0, 0), real(0, 0)] ../source3/auth/token_util.c:639(debug_unix_user_token) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2016/05/06 13:52:15.241934, 3, pid=23960, effective(0, 0), real(0, 0)] ../source3/auth/token_util.c:547(finalize_local_nt_token) Failed to fetch domain sid for SAMBA [2016/05/06 13:52:15.241962, 4, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:421(pop_sec_ctx) pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0 [2016/05/06 13:52:15.241985, 4, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:216(push_sec_ctx) push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1 [2016/05/06 13:52:15.242002, 4, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/uid.c:491(push_conn_ctx) push_conn_ctx(0) : conn_ctx_stack_ndx = 0 [2016/05/06 13:52:15.242025, 4, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:316(set_sec_ctx) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1 [2016/05/06 13:52:15.242041, 5, pid=23960, effective(0, 0), real(0, 0)] ../libcli/security/security_token.c:53(security_token_debug) Security token: (NULL) [2016/05/06 13:52:15.242056, 5, pid=23960, effective(0, 0), real(0, 0)] ../source3/auth/token_util.c:639(debug_unix_user_token) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2016/05/06 13:52:15.242093, 3, pid=23960, effective(0, 0), real(0, 0)] ../source3/auth/token_util.c:579(finalize_local_nt_token) Failed to fetch domain sid for SAMBA [2016/05/06 13:52:15.242114, 4, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:421(pop_sec_ctx) pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0 [2016/05/06 13:52:15.242131, 4, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:216(push_sec_ctx) push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1 [2016/05/06 13:52:15.242155, 4, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/uid.c:491(push_conn_ctx) push_conn_ctx(0) : conn_ctx_stack_ndx = 0 [2016/05/06 13:52:15.242170, 4, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:316(set_sec_ctx) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1 [2016/05/06 13:52:15.242187, 5, pid=23960, effective(0, 0), real(0, 0)] ../libcli/security/security_token.c:53(security_token_debug) Security token: (NULL) [2016/05/06 13:52:15.242209, 5, pid=23960, effective(0, 0), real(0, 0)] ../source3/auth/token_util.c:639(debug_unix_user_token) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2016/05/06 13:52:15.242282, 4, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:421(pop_sec_ctx) pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0 [2016/05/06 13:52:15.242304, 4, pid=23960, effective(0, 0), real(0, 0)] ../source3/lib/privileges.c:98(get_privileges) get_privileges: No privileges assigned to SID [S-1-5-21-4127461147-3627497618-4263181281-1000] [2016/05/06 13:52:15.242336, 4, pid=23960, effective(0, 0), real(0, 0)] ../source3/lib/privileges.c:98(get_privileges) get_privileges: No privileges assigned to SID [S-1-5-21-4127461147-3627497618-4263181281-513] [2016/05/06 13:52:15.242358, 4, pid=23960, effective(0, 0), real(0, 0)] ../source3/lib/privileges.c:98(get_privileges) get_privileges: No privileges assigned to SID [S-1-22-2-1002] [2016/05/06 13:52:15.242387, 5, pid=23960, effective(0, 0), real(0, 0)] ../source3/lib/privileges.c:176(get_privileges_for_sids) get_privileges_for_sids: sid = S-1-1-0 Privilege set: 0x0 [2016/05/06 13:52:15.242413, 4, pid=23960, effective(0, 0), real(0, 0)] ../source3/lib/privileges.c:98(get_privileges) get_privileges: No privileges assigned to SID [S-1-5-2] [2016/05/06 13:52:15.242433, 4, pid=23960, effective(0, 0), real(0, 0)] ../source3/lib/privileges.c:98(get_privileges) get_privileges: No privileges assigned to SID [S-1-5-11] [2016/05/06 13:52:15.242462, 10, pid=23960, effective(0, 0), real(0, 0)] ../source3/lib/idmap_cache.c:56(idmap_cache_find_sid2unixid) Parsing value for key [IDMAP/SID2XID/S-1-5-21-4127461147-3627497618-4263181281-1000]: value=[1002:U] [2016/05/06 13:52:15.242479, 10, pid=23960, effective(0, 0), real(0, 0)] ../source3/lib/idmap_cache.c:75(idmap_cache_find_sid2unixid) Parsing value for key [IDMAP/SID2XID/S-1-5-21-4127461147-3627497618-4263181281-1000]: id=[1002], endptr=[:U] [2016/05/06 13:52:15.242540, 10, pid=23960, effective(0, 0), real(0, 0)] ../source3/passdb/lookup_sid.c:1346(sids_to_unixids) wbcSidsToUnixIds returned WBC_ERR_WINBIND_NOT_AVAILABLE [2016/05/06 13:52:15.242559, 4, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:216(push_sec_ctx) push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1 [2016/05/06 13:52:15.242576, 4, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/uid.c:491(push_conn_ctx) push_conn_ctx(0) : conn_ctx_stack_ndx = 0 [2016/05/06 13:52:15.242599, 4, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:316(set_sec_ctx) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1 [2016/05/06 13:52:15.242615, 5, pid=23960, effective(0, 0), real(0, 0)] ../libcli/security/security_token.c:53(security_token_debug) Security token: (NULL) [2016/05/06 13:52:15.242630, 5, pid=23960, effective(0, 0), real(0, 0)] ../source3/auth/token_util.c:639(debug_unix_user_token) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2016/05/06 13:52:15.242668, 5, pid=23960, effective(0, 0), real(0, 0), class=passdb] ../source3/passdb/pdb_interface.c:1748(lookup_global_sam_rid) lookup_global_sam_rid: looking up RID 513. [2016/05/06 13:52:15.242687, 4, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:216(push_sec_ctx) push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 2 [2016/05/06 13:52:15.242704, 4, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/uid.c:491(push_conn_ctx) push_conn_ctx(0) : conn_ctx_stack_ndx = 1 [2016/05/06 13:52:15.242728, 4, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:316(set_sec_ctx) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 2 [2016/05/06 13:52:15.242744, 5, pid=23960, effective(0, 0), real(0, 0)] ../libcli/security/security_token.c:53(security_token_debug) Security token: (NULL) [2016/05/06 13:52:15.242759, 5, pid=23960, effective(0, 0), real(0, 0)] ../source3/auth/token_util.c:639(debug_unix_user_token) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2016/05/06 13:52:15.242799, 5, pid=23960, effective(0, 0), real(0, 0), class=passdb] ../source3/passdb/pdb_tdb.c:658(tdbsam_getsampwrid) pdb_getsampwrid (TDB): error looking up RID 513 by key RID_00000201. [2016/05/06 13:52:15.242826, 4, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:421(pop_sec_ctx) pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 1 [2016/05/06 13:52:15.242844, 5, pid=23960, effective(0, 0), real(0, 0), class=passdb] ../source3/passdb/pdb_interface.c:1824(lookup_global_sam_rid) Can't find a unix id for an unmapped group [2016/05/06 13:52:15.242867, 5, pid=23960, effective(0, 0), real(0, 0), class=passdb] ../source3/passdb/pdb_interface.c:1534(pdb_default_sid_to_id) SID S-1-5-21-4127461147-3627497618-4263181281-513 belongs to our domain, but there is no corresponding object in the database. [2016/05/06 13:52:15.242890, 4, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:421(pop_sec_ctx) pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0 [2016/05/06 13:52:15.242914, 10, pid=23960, effective(0, 0), real(0, 0)] ../source3/passdb/lookup_sid.c:1160(legacy_sid_to_unixid) LEGACY: mapping failed for sid S-1-5-21-4127461147-3627497618-4263181281-513 [2016/05/06 13:52:15.242932, 4, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:216(push_sec_ctx) push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1 [2016/05/06 13:52:15.242949, 4, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/uid.c:491(push_conn_ctx) push_conn_ctx(0) : conn_ctx_stack_ndx = 0 [2016/05/06 13:52:15.242971, 4, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:316(set_sec_ctx) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1 [2016/05/06 13:52:15.242987, 5, pid=23960, effective(0, 0), real(0, 0)] ../libcli/security/security_token.c:53(security_token_debug) Security token: (NULL) [2016/05/06 13:52:15.243002, 5, pid=23960, effective(0, 0), real(0, 0)] ../source3/auth/token_util.c:639(debug_unix_user_token) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2016/05/06 13:52:15.243037, 5, pid=23960, effective(0, 0), real(0, 0), class=passdb] ../source3/passdb/pdb_interface.c:1748(lookup_global_sam_rid) lookup_global_sam_rid: looking up RID 513. [2016/05/06 13:52:15.243055, 4, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:216(push_sec_ctx) push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 2 [2016/05/06 13:52:15.243072, 4, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/uid.c:491(push_conn_ctx) push_conn_ctx(0) : conn_ctx_stack_ndx = 1 [2016/05/06 13:52:15.243095, 4, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:316(set_sec_ctx) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 2 [2016/05/06 13:52:15.243110, 5, pid=23960, effective(0, 0), real(0, 0)] ../libcli/security/security_token.c:53(security_token_debug) Security token: (NULL) [2016/05/06 13:52:15.243125, 5, pid=23960, effective(0, 0), real(0, 0)] ../source3/auth/token_util.c:639(debug_unix_user_token) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2016/05/06 13:52:15.243163, 5, pid=23960, effective(0, 0), real(0, 0), class=passdb] ../source3/passdb/pdb_tdb.c:658(tdbsam_getsampwrid) pdb_getsampwrid (TDB): error looking up RID 513 by key RID_00000201. [2016/05/06 13:52:15.243190, 4, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:421(pop_sec_ctx) pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 1 [2016/05/06 13:52:15.243215, 5, pid=23960, effective(0, 0), real(0, 0), class=passdb] ../source3/passdb/pdb_interface.c:1824(lookup_global_sam_rid) Can't find a unix id for an unmapped group [2016/05/06 13:52:15.243231, 5, pid=23960, effective(0, 0), real(0, 0), class=passdb] ../source3/passdb/pdb_interface.c:1534(pdb_default_sid_to_id) SID S-1-5-21-4127461147-3627497618-4263181281-513 belongs to our domain, but there is no corresponding object in the database. [2016/05/06 13:52:15.243254, 4, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:421(pop_sec_ctx) pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0 [2016/05/06 13:52:15.243278, 10, pid=23960, effective(0, 0), real(0, 0)] ../source3/passdb/lookup_sid.c:1160(legacy_sid_to_unixid) LEGACY: mapping failed for sid S-1-5-21-4127461147-3627497618-4263181281-513 [2016/05/06 13:52:15.243297, 4, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:216(push_sec_ctx) push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1 [2016/05/06 13:52:15.243314, 4, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/uid.c:491(push_conn_ctx) push_conn_ctx(0) : conn_ctx_stack_ndx = 0 [2016/05/06 13:52:15.243339, 4, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:316(set_sec_ctx) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1 [2016/05/06 13:52:15.243355, 5, pid=23960, effective(0, 0), real(0, 0)] ../libcli/security/security_token.c:53(security_token_debug) Security token: (NULL) [2016/05/06 13:52:15.243370, 5, pid=23960, effective(0, 0), real(0, 0)] ../source3/auth/token_util.c:639(debug_unix_user_token) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2016/05/06 13:52:15.243410, 4, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:421(pop_sec_ctx) pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0 [2016/05/06 13:52:15.243427, 10, pid=23960, effective(0, 0), real(0, 0)] ../source3/passdb/lookup_sid.c:1160(legacy_sid_to_unixid) LEGACY: mapping failed for sid S-1-1-0 [2016/05/06 13:52:15.243444, 4, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:216(push_sec_ctx) push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1 [2016/05/06 13:52:15.243469, 4, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/uid.c:491(push_conn_ctx) push_conn_ctx(0) : conn_ctx_stack_ndx = 0 [2016/05/06 13:52:15.243485, 4, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:316(set_sec_ctx) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1 [2016/05/06 13:52:15.243500, 5, pid=23960, effective(0, 0), real(0, 0)] ../libcli/security/security_token.c:53(security_token_debug) Security token: (NULL) [2016/05/06 13:52:15.243523, 5, pid=23960, effective(0, 0), real(0, 0)] ../source3/auth/token_util.c:639(debug_unix_user_token) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2016/05/06 13:52:15.243554, 4, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:421(pop_sec_ctx) pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0 [2016/05/06 13:52:15.243571, 10, pid=23960, effective(0, 0), real(0, 0)] ../source3/passdb/lookup_sid.c:1160(legacy_sid_to_unixid) LEGACY: mapping failed for sid S-1-1-0 [2016/05/06 13:52:15.243595, 4, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:216(push_sec_ctx) push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1 [2016/05/06 13:52:15.243612, 4, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/uid.c:491(push_conn_ctx) push_conn_ctx(0) : conn_ctx_stack_ndx = 0 [2016/05/06 13:52:15.243627, 4, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:316(set_sec_ctx) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1 [2016/05/06 13:52:15.243651, 5, pid=23960, effective(0, 0), real(0, 0)] ../libcli/security/security_token.c:53(security_token_debug) Security token: (NULL) [2016/05/06 13:52:15.243666, 5, pid=23960, effective(0, 0), real(0, 0)] ../source3/auth/token_util.c:639(debug_unix_user_token) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2016/05/06 13:52:15.243698, 4, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:421(pop_sec_ctx) pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0 [2016/05/06 13:52:15.243722, 10, pid=23960, effective(0, 0), real(0, 0)] ../source3/passdb/lookup_sid.c:1160(legacy_sid_to_unixid) LEGACY: mapping failed for sid S-1-5-2 [2016/05/06 13:52:15.243740, 4, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:216(push_sec_ctx) push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1 [2016/05/06 13:52:15.243756, 4, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/uid.c:491(push_conn_ctx) push_conn_ctx(0) : conn_ctx_stack_ndx = 0 [2016/05/06 13:52:15.243780, 4, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:316(set_sec_ctx) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1 [2016/05/06 13:52:15.243795, 5, pid=23960, effective(0, 0), real(0, 0)] ../libcli/security/security_token.c:53(security_token_debug) Security token: (NULL) [2016/05/06 13:52:15.243810, 5, pid=23960, effective(0, 0), real(0, 0)] ../source3/auth/token_util.c:639(debug_unix_user_token) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2016/05/06 13:52:15.243849, 4, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:421(pop_sec_ctx) pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0 [2016/05/06 13:52:15.243866, 10, pid=23960, effective(0, 0), real(0, 0)] ../source3/passdb/lookup_sid.c:1160(legacy_sid_to_unixid) LEGACY: mapping failed for sid S-1-5-2 [2016/05/06 13:52:15.243883, 4, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:216(push_sec_ctx) push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1 [2016/05/06 13:52:15.243908, 4, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/uid.c:491(push_conn_ctx) push_conn_ctx(0) : conn_ctx_stack_ndx = 0 [2016/05/06 13:52:15.243923, 4, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:316(set_sec_ctx) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1 [2016/05/06 13:52:15.243939, 5, pid=23960, effective(0, 0), real(0, 0)] ../libcli/security/security_token.c:53(security_token_debug) Security token: (NULL) [2016/05/06 13:52:15.243962, 5, pid=23960, effective(0, 0), real(0, 0)] ../source3/auth/token_util.c:639(debug_unix_user_token) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2016/05/06 13:52:15.243993, 4, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:421(pop_sec_ctx) pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0 [2016/05/06 13:52:15.244010, 10, pid=23960, effective(0, 0), real(0, 0)] ../source3/passdb/lookup_sid.c:1160(legacy_sid_to_unixid) LEGACY: mapping failed for sid S-1-5-11 [2016/05/06 13:52:15.244035, 4, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:216(push_sec_ctx) push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1 [2016/05/06 13:52:15.244052, 4, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/uid.c:491(push_conn_ctx) push_conn_ctx(0) : conn_ctx_stack_ndx = 0 [2016/05/06 13:52:15.244067, 4, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:316(set_sec_ctx) setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1 [2016/05/06 13:52:15.244091, 5, pid=23960, effective(0, 0), real(0, 0)] ../libcli/security/security_token.c:53(security_token_debug) Security token: (NULL) [2016/05/06 13:52:15.244106, 5, pid=23960, effective(0, 0), real(0, 0)] ../source3/auth/token_util.c:639(debug_unix_user_token) UNIX token of user 0 Primary group is 0 and contains 0 supplementary groups [2016/05/06 13:52:15.244137, 4, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:421(pop_sec_ctx) pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0 [2016/05/06 13:52:15.244162, 10, pid=23960, effective(0, 0), real(0, 0)] ../source3/passdb/lookup_sid.c:1160(legacy_sid_to_unixid) LEGACY: mapping failed for sid S-1-5-11 [2016/05/06 13:52:15.244179, 10, pid=23960, effective(0, 0), real(0, 0), class=auth] ../source3/auth/auth_util.c:594(create_local_token) Could not convert SID S-1-5-21-4127461147-3627497618-4263181281-513 to gid, ignoring it [2016/05/06 13:52:15.244206, 10, pid=23960, effective(0, 0), real(0, 0), class=auth] ../source3/auth/auth_util.c:594(create_local_token) Could not convert SID S-1-1-0 to gid, ignoring it [2016/05/06 13:52:15.244224, 10, pid=23960, effective(0, 0), real(0, 0), class=auth] ../source3/auth/auth_util.c:594(create_local_token) Could not convert SID S-1-5-2 to gid, ignoring it [2016/05/06 13:52:15.244240, 10, pid=23960, effective(0, 0), real(0, 0), class=auth] ../source3/auth/auth_util.c:594(create_local_token) Could not convert SID S-1-5-11 to gid, ignoring it [2016/05/06 13:52:15.244267, 10, pid=23960, effective(0, 0), real(0, 0)] ../libcli/security/security_token.c:63(security_token_debug) Security token SIDs (7): SID[ 0]: S-1-5-21-4127461147-3627497618-4263181281-1000 SID[ 1]: S-1-5-21-4127461147-3627497618-4263181281-513 SID[ 2]: S-1-22-2-1002 SID[ 3]: S-1-1-0 SID[ 4]: S-1-5-2 SID[ 5]: S-1-5-11 SID[ 6]: S-1-22-1-1002 Privileges (0x 0): Rights (0x 0): [2016/05/06 13:52:15.244359, 10, pid=23960, effective(0, 0), real(0, 0)] ../source3/auth/token_util.c:639(debug_unix_user_token) UNIX token of user 1002 Primary group is 1002 and contains 1 supplementary groups Group[ 0]: 1002 [2016/05/06 13:52:15.244396, 5, pid=23960, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap.c:178(dbwrap_check_lock_order) check lock order 1 for /var/db/samba4/smbXsrv_session_global.tdb [2016/05/06 13:52:15.244413, 10, pid=23960, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap.c:133(debug_lock_order) lock order: 1:/var/db/samba4/smbXsrv_session_global.tdb 2: 3: [2016/05/06 13:52:15.244441, 10, pid=23960, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap_tdb.c:60(db_tdb_log_key) Locking key 5995EBEF [2016/05/06 13:52:15.244461, 10, pid=23960, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap_tdb.c:144(db_tdb_fetch_locked_internal) Allocated locked data 0x0x81344d1a0 [2016/05/06 13:52:15.244480, 10, pid=23960, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap_tdb.c:60(db_tdb_log_key) Unlocking key 5995EBEF [2016/05/06 13:52:15.244505, 5, pid=23960, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap.c:146(dbwrap_lock_order_state_destructor) release lock order 1 for /var/db/samba4/smbXsrv_session_global.tdb [2016/05/06 13:52:15.244522, 10, pid=23960, effective(0, 0), real(0, 0)] ../lib/dbwrap/dbwrap.c:133(debug_lock_order) lock order: 1: 2: 3: [2016/05/06 13:52:15.244590, 7, pid=23960, effective(0, 0), real(0, 0)] ../source3/param/loadparm.c:3995(lp_servicenumber) lp_servicenumber: couldn't find counter [2016/05/06 13:52:15.244618, 5, pid=23960, effective(0, 0), real(0, 0)] ../source3/lib/username.c:181(Get_Pwnam_alloc) Finding user counter [2016/05/06 13:52:15.244635, 5, pid=23960, effective(0, 0), real(0, 0)] ../source3/lib/username.c:120(Get_Pwnam_internals) Trying _Get_Pwnam(), username as lowercase is counter [2016/05/06 13:52:15.244651, 5, pid=23960, effective(0, 0), real(0, 0)] ../source3/lib/username.c:159(Get_Pwnam_internals) Get_Pwnam_internals did find user [counter]! [2016/05/06 13:52:15.244676, 3, pid=23960, effective(0, 0), real(0, 0)] ../source3/smbd/password.c:144(register_homes_share) Adding homes service for user 'counter' using home directory: '/home/counter' [2016/05/06 13:52:15.244695, 7, pid=23960, effective(0, 0), real(0, 0)] ../source3/param/loadparm.c:3995(lp_servicenumber) lp_servicenumber: couldn't find homes