diff --git a/source3/smbd/conn.c b/source3/smbd/conn.c index 044242d5697..eb4d033207b 100644 --- a/source3/smbd/conn.c +++ b/source3/smbd/conn.c @@ -51,6 +51,12 @@ bool conn_snum_used(struct smbd_server_connection *sconn, return false; } +static int conn_struct_dtor(connection_struct *c) +{ + DBG_ERR("### destroying connection_struct %p\n", c); + return 0; +} + /**************************************************************************** Find first available connection slot, starting from a random position. The randomisation stops problems with the server dieing and clients @@ -66,6 +72,7 @@ connection_struct *conn_new(struct smbd_server_connection *sconn) DBG_ERR("talloc_zero failed\n"); return NULL; } + DBG_ERR("### new con created!!! %p\n", conn); conn->params = talloc(conn, struct share_params); if (conn->params == NULL) { DBG_ERR("talloc_zero failed\n"); @@ -114,7 +121,8 @@ connection_struct *conn_new(struct smbd_server_connection *sconn) DLIST_ADD(sconn->connections, conn); sconn->num_connections++; - + DBG_ERR("## sconn %p added connection %p, num conns = %d\n", sconn, conn, (int)sconn->num_connections); + talloc_set_destructor(conn, conn_struct_dtor); return conn; } @@ -222,6 +230,7 @@ static void conn_free_internal(connection_struct *conn) void conn_free(connection_struct *conn) { if (conn->sconn == NULL) { + DBG_ERR("## here... danger ! danger !\n"); conn_free_internal(conn); return; } @@ -229,7 +238,8 @@ void conn_free(connection_struct *conn) DLIST_REMOVE(conn->sconn->connections, conn); SMB_ASSERT(conn->sconn->num_connections > 0); conn->sconn->num_connections--; - + + DBG_ERR("## sconn %p removed connection %p, num conns = %d\n", conn->sconn, conn, (int)conn->sconn->num_connections); conn_free_internal(conn); } diff --git a/source3/smbd/server_exit.c b/source3/smbd/server_exit.c index b4a84e1a3f3..d7696294991 100644 --- a/source3/smbd/server_exit.c +++ b/source3/smbd/server_exit.c @@ -238,11 +238,13 @@ static void exit_server_common(enum server_exit_reason how, void smbd_exit_server(const char *const explanation) { + DBG_ERR("#### exiting because %s\n", explanation); exit_server_common(SERVER_EXIT_ABNORMAL, explanation); } void smbd_exit_server_cleanly(const char *const explanation) { + DBG_ERR("#### exiting because %s\n", explanation); exit_server_common(SERVER_EXIT_NORMAL, explanation); } diff --git a/source3/smbd/smb2_negprot.c b/source3/smbd/smb2_negprot.c index da567951c0b..855ee49d554 100644 --- a/source3/smbd/smb2_negprot.c +++ b/source3/smbd/smb2_negprot.c @@ -853,6 +853,7 @@ NTSTATUS smbd_smb2_request_process_negprot(struct smbd_smb2_request *req) .outdyn = outdyn, }; + DBG_ERR("## calling smb2srv_client_mc_negprot_send\n"); subreq = smb2srv_client_mc_negprot_send(state, req->xconn->client->raw_ev_ctx, req); @@ -876,6 +877,7 @@ static void smbd_smb2_request_process_negprot_mc_done(struct tevent_req *subreq) status = smb2srv_client_mc_negprot_recv(subreq); TALLOC_FREE(subreq); + DBG_ERR("### mc_negprot done with status %s\n", nt_errstr(status)); if (NT_STATUS_EQUAL(status, NT_STATUS_MESSAGE_RETRIEVED)) { /* * The connection was passed to another process diff --git a/source3/smbd/smb2_process.c b/source3/smbd/smb2_process.c index ad4386e08a4..02c6bff021a 100644 --- a/source3/smbd/smb2_process.c +++ b/source3/smbd/smb2_process.c @@ -1561,6 +1561,7 @@ static bool deadtime_fn(const struct timeval *now, void *private_data) struct smbd_server_connection *sconn = (struct smbd_server_connection *)private_data; + DBG_ERR("## num open conns = %d\n", conn_num_open(sconn)); if ((conn_num_open(sconn) == 0) || (conn_idle_all(sconn, now->tv_sec))) { DEBUG( 2, ( "Closing idle connection\n" ) ); @@ -1988,7 +1989,7 @@ void smbd_process(struct tevent_context *ev_ctx, #endif if (!(event_add_idle(ev_ctx, NULL, - timeval_set(IDLE_CLOSED_TIMEOUT, 0), + timeval_set(1, 0), "deadtime", deadtime_fn, sconn))) { DEBUG(0, ("Could not add deadtime event\n")); exit(1); diff --git a/source3/smbd/smb2_server.c b/source3/smbd/smb2_server.c index e8a91238baf..cab5777f801 100644 --- a/source3/smbd/smb2_server.c +++ b/source3/smbd/smb2_server.c @@ -439,6 +439,8 @@ static NTSTATUS smbd_smb2_inbuf_parse_compound(struct smbXsrv_connection *xconn, status = smb2srv_session_lookup_conn(xconn, uid, now, &s); if (s == NULL) { + DBG_ERR("req %p is taking control of session\n", + req); status = smb2srv_session_lookup_global(xconn->client, uid, req, &s); } @@ -1909,6 +1911,7 @@ static NTSTATUS smb2_send_async_interim_response(const struct smbd_smb2_request return NT_STATUS_NO_MEMORY; } + DBG_ERR("nreq %p duped from %p\n", nreq, req); /* Lose the last X out vectors. They're the ones we'll be using for the async reply. */ nreq->out.vector_count -= SMBD_SMB2_NUM_IOV_PER_REQ; @@ -1958,6 +1961,7 @@ static NTSTATUS smb2_send_async_interim_response(const struct smbd_smb2_request } } + DBG_ERR("## mem_ctx set to %p\n", nreq); nreq->queue_entry.mem_ctx = nreq; nreq->queue_entry.vector = nreq->out.vector; nreq->queue_entry.count = nreq->out.vector_count; @@ -2361,6 +2365,7 @@ static void smbd_smb2_request_pending_timer(struct tevent_context *ev, } } + DBG_ERR("## mem_ctx set to %p\n", state); state->queue_entry.mem_ctx = state; state->queue_entry.vector = state->vector; state->queue_entry.count = ARRAY_SIZE(state->vector); @@ -2550,6 +2555,8 @@ static NTSTATUS smbd_smb2_request_check_session(struct smbd_smb2_request *req) if (NT_STATUS_EQUAL(status, NT_STATUS_USER_SESSION_DELETED)) { switch (in_opcode) { case SMB2_OP_SESSSETUP: + DBG_ERR("req %p is taking control of session\n", + req); status = smb2srv_session_lookup_global(req->xconn->client, in_session_id, req, @@ -3053,8 +3060,12 @@ NTSTATUS smbd_smb2_request_dispatch(struct smbd_smb2_request *req) NT_STATUS_ACCESS_DENIED); } + DBG_ERR("#### smbd_smb2_request_dispatch: about to call opcode[%s] for req %p\n", + smb2_opcode_name(opcode), req); call = smbd_smb2_call(opcode); if (call == NULL) { + DBG_ERR("#### smbd_smb2_request_dispatch: about to call opcode[%s] got error\n", + smb2_opcode_name(opcode)); return smbd_smb2_request_error(req, NT_STATUS_INVALID_PARAMETER); } @@ -3076,6 +3087,8 @@ NTSTATUS smbd_smb2_request_dispatch(struct smbd_smb2_request *req) allowed_flags |= SMB2_HDR_FLAG_REPLAY_OPERATION; } if ((flags & ~allowed_flags) != 0) { + DBG_ERR("#### smbd_smb2_request_dispatch: about to call opcode[%s] got error\n", + smb2_opcode_name(opcode)); return smbd_smb2_request_error(req, NT_STATUS_INVALID_PARAMETER); } @@ -3085,6 +3098,8 @@ NTSTATUS smbd_smb2_request_dispatch(struct smbd_smb2_request *req) * for compounded requests. */ if (!NT_STATUS_IS_OK(session_status)) { + DBG_ERR("#### smbd_smb2_request_dispatch: about to call opcode[%s] got error\n", + smb2_opcode_name(opcode)); return smbd_smb2_request_error(req, NT_STATUS_INVALID_PARAMETER); } } else { @@ -3114,6 +3129,8 @@ NTSTATUS smbd_smb2_request_dispatch(struct smbd_smb2_request *req) } else { status = NT_STATUS_USER_SESSION_DELETED; } + DBG_ERR("#### smbd_smb2_request_dispatch: about to call opcode[%s] got error\n", + smb2_opcode_name(opcode)); return smbd_smb2_request_error(req, status); } @@ -3138,11 +3155,15 @@ NTSTATUS smbd_smb2_request_dispatch(struct smbd_smb2_request *req) struct smbXsrv_session *session = NULL; NTSTATUS error; + DBG_ERR("req %p is taking control of session\n", + req); error = smb2srv_session_lookup_global(req->xconn->client, x->global->session_wire_id, req, &session); if (!NT_STATUS_IS_OK(error)) { + DBG_ERR("#### smbd_smb2_request_dispatch: about to call opcode[%s] got error\n", + smb2_opcode_name(opcode)); return smbd_smb2_request_error(req, error); } @@ -3158,6 +3179,8 @@ NTSTATUS smbd_smb2_request_dispatch(struct smbd_smb2_request *req) goto skipped_signing; } if (!NT_STATUS_IS_OK(status)) { + DBG_ERR("#### smbd_smb2_request_dispatch: about to call opcode[%s] got error\n", + smb2_opcode_name(opcode)); return smbd_smb2_request_error(req, status); } @@ -3170,6 +3193,8 @@ NTSTATUS smbd_smb2_request_dispatch(struct smbd_smb2_request *req) } if (!NT_STATUS_IS_OK(session_status)) { + DBG_ERR("#### smbd_smb2_request_dispatch: about to call opcode[%s] got error\n", + smb2_opcode_name(opcode)); return smbd_smb2_request_error(req, session_status); } } @@ -3197,6 +3222,8 @@ NTSTATUS smbd_smb2_request_dispatch(struct smbd_smb2_request *req) size_t needed = 8; if (needed > body_size) { + DBG_ERR("#### smbd_smb2_request_dispatch: about to call opcode[%s] got error\n", + smb2_opcode_name(opcode)); return smbd_smb2_request_error(req, NT_STATUS_INVALID_PARAMETER); } @@ -3226,6 +3253,8 @@ skipped_signing: if (call->need_session) { if (!NT_STATUS_IS_OK(session_status)) { + DBG_ERR("#### smbd_smb2_request_dispatch: about to call opcode[%s] got error\n", + smb2_opcode_name(opcode)); return smbd_smb2_request_error(req, session_status); } } @@ -3243,6 +3272,8 @@ skipped_signing: */ status = smbd_smb2_request_check_tcon(req); if (!NT_STATUS_IS_OK(status)) { + DBG_ERR("#### smbd_smb2_request_dispatch: about to call opcode[%s] got error\n", + smb2_opcode_name(opcode)); return smbd_smb2_request_error(req, status); } if (req->tcon->global->encryption_flags & SMBXSRV_ENCRYPTION_DESIRED) { @@ -3253,6 +3284,8 @@ skipped_signing: } if (encryption_required && !req->was_encrypted) { req->do_encryption = true; + DBG_ERR("#### smbd_smb2_request_dispatch: about to call opcode[%s] got error\n", + smb2_opcode_name(opcode)); return smbd_smb2_request_error(req, NT_STATUS_ACCESS_DENIED); } else if (encryption_desired) { @@ -3268,6 +3301,8 @@ skipped_signing: session_info = req->session->global->auth_session_info; if (session_info == NULL) { + DBG_ERR("#### smbd_smb2_request_dispatch: about to call opcode[%s] got error\n", + smb2_opcode_name(opcode)); return NT_STATUS_INVALID_HANDLE; } @@ -3287,12 +3322,16 @@ skipped_signing: if (update_session_global) { status = smbXsrv_session_update(x); if (!NT_STATUS_IS_OK(status)) { + DBG_ERR("#### smbd_smb2_request_dispatch: about to call opcode[%s] got error\n", + smb2_opcode_name(opcode)); return smbd_smb2_request_error(req, status); } } if (update_tcon_global) { status = smbXsrv_tcon_update(req->tcon); if (!NT_STATUS_IS_OK(status)) { + DBG_ERR("#### smbd_smb2_request_dispatch: about to call opcode[%s] got error\n", + smb2_opcode_name(opcode)); return smbd_smb2_request_error(req, status); } } @@ -3309,6 +3348,8 @@ skipped_signing: SMB_ASSERT(call->need_tcon); if (needed > body_size) { + DBG_ERR("#### smbd_smb2_request_dispatch: about to call opcode[%s] got error\n", + smb2_opcode_name(opcode)); return smbd_smb2_request_error(req, NT_STATUS_INVALID_PARAMETER); } @@ -3321,6 +3362,8 @@ skipped_signing: if (req->compound_related && !NT_STATUS_IS_OK(req->compound_create_err)) { + DBG_ERR("#### smbd_smb2_request_dispatch: about to call opcode[%s] got error\n", + smb2_opcode_name(opcode)); return smbd_smb2_request_error(req, req->compound_create_err); } @@ -3330,11 +3373,15 @@ skipped_signing: * detailed error codes... */ if (opcode != SMB2_OP_IOCTL) { + DBG_ERR("#### smbd_smb2_request_dispatch: about to call opcode[%s] got error\n", + smb2_opcode_name(opcode)); return smbd_smb2_request_error(req, NT_STATUS_FILE_CLOSED); } } else { if (fsp->fsp_flags.encryption_required && !req->was_encrypted) { + DBG_ERR("#### smbd_smb2_request_dispatch: about to call opcode[%s] got error\n", + smb2_opcode_name(opcode)); return smbd_smb2_request_error(req, NT_STATUS_ACCESS_DENIED); } @@ -3343,6 +3390,8 @@ skipped_signing: status = smbd_smb2_request_dispatch_update_counts(req, call->modify); if (!NT_STATUS_IS_OK(status)) { + DBG_ERR("#### smbd_smb2_request_dispatch: about to call opcode[%s] got error\n", + smb2_opcode_name(opcode)); return smbd_smb2_request_error(req, status); } @@ -3491,6 +3540,9 @@ skipped_signing: return_value = smbd_smb2_request_error(req, NT_STATUS_INVALID_PARAMETER); break; } + DBG_ERR("#### smbd_smb2_request_dispatch: [%s] returning %s %p\n", + smb2_opcode_name(opcode), + nt_errstr(return_value), req); return return_value; } @@ -3777,6 +3829,7 @@ static NTSTATUS smbd_smb2_request_reply(struct smbd_smb2_request *req) */ DLIST_REMOVE(xconn->smb2.requests, req); + DBG_ERR("## mem_ctx set to %p\n", req); req->queue_entry.mem_ctx = req; req->queue_entry.vector = req->out.vector; req->queue_entry.count = req->out.vector_count; @@ -4099,6 +4152,7 @@ static struct tevent_req *smbd_smb2_break_send(TALLOC_CTX *mem_ctx, timeval_current_ofs_usec(xconn->ack.rto_usecs * 6); state->queue_entry.ack.required_acked_bytes = UINT64_MAX; state->queue_entry.ack.req = req; + DBG_ERR("## mem_ctx set to %p\n", state); state->queue_entry.mem_ctx = state; state->queue_entry.vector = state->vector; state->queue_entry.count = ARRAY_SIZE(state->vector); @@ -4770,7 +4824,9 @@ static NTSTATUS smbd_smb2_flush_send_queue(struct smbXsrv_connection *xconn) DLIST_REMOVE(xconn->smb2.send_queue, e); if (e->ack.req == NULL) { + DBG_ERR("####### e->ack.req is NULL, before freeing %p\n", e->mem_ctx); talloc_free(e->mem_ctx); + DBG_ERR("####### e->ack.req is NULL, after freeing\n"); continue; } diff --git a/source3/smbd/smb2_sesssetup.c b/source3/smbd/smb2_sesssetup.c index 14b806bc007..2edf01e6dec 100644 --- a/source3/smbd/smb2_sesssetup.c +++ b/source3/smbd/smb2_sesssetup.c @@ -1180,6 +1180,7 @@ static void smbd_smb2_session_setup_wrap_shutdown_done(struct tevent_req *subreq * we may need to sign the response, so we need to keep * the session until the response is sent to the wire. */ + DBG_ERR("### %p steals the seassion!!!\n", state->smb2req); talloc_steal(state->smb2req, state->smb2req->session); tevent_req_nterror(req, state->error); @@ -1359,6 +1360,7 @@ static void smbd_smb2_logoff_shutdown_done(struct tevent_req *subreq) * we may need to sign the response, so we need to keep * the session until the response is sent to the wire. */ + DBG_ERR("### %p steals the seassion!!!\n", state->smb2req); talloc_steal(state->smb2req, state->smb2req->session); tevent_req_done(req); diff --git a/source3/smbd/smbXsrv_client.c b/source3/smbd/smbXsrv_client.c index 079ca80ad12..5960c1e4227 100644 --- a/source3/smbd/smbXsrv_client.c +++ b/source3/smbd/smbXsrv_client.c @@ -299,6 +299,7 @@ static NTSTATUS smb2srv_client_connection_pass(struct smbd_smb2_request *smb2req .client_connect_time = global->initial_connect_time, }; + DBG_ERR("### connection_pass\n"); reqlen = iov_buflen(smb2req->in.vector, smb2req->in.vector_count); if (reqlen == -1) { return NT_STATUS_INVALID_BUFFER_SIZE; @@ -511,6 +512,13 @@ static void smb2srv_client_mc_negprot_next(struct tevent_req *req) * smbXsrv_client_global.tdb */ client->global->client_guid = xconn->smb2.client.guid; + if (true) { + struct GUID_txt_buf gbuf; + + DBG_ERR("#### first time client_guid[%s] stored\n", + GUID_buf_string(&client->global->client_guid, + &gbuf)); + } client->global->db_rec = state->db_rec; state->db_rec = NULL; @@ -551,7 +559,7 @@ static void smb2srv_client_mc_negprot_next(struct tevent_req *req) tevent_req_nterror(req, NT_STATUS_INTERNAL_DB_CORRUPTION); return; } - + DBG_ERR("### not the first time\n"); subreq = messaging_filtered_read_send(state, state->ev, client->msg_ctx, @@ -721,6 +729,7 @@ static void smb2srv_client_mc_negprot_watched(struct tevent_req *subreq) NTSTATUS status; uint64_t instance = 0; + DBG_ERR("### some change in db\n"); status = dbwrap_watched_watch_recv(subreq, &instance, NULL, NULL); TALLOC_FREE(subreq); if (tevent_req_nterror(req, status)) { @@ -857,7 +866,12 @@ NTSTATUS smbXsrv_client_create(TALLOC_CTX *mem_ctx, GUID_buf_string(&global->client_guid, &buf)); NDR_PRINT_DEBUG(smbXsrv_clientB, &client_blob); } + if (true) { + struct GUID_txt_buf buf; + DBG_ERR("### client_guid[%s] created\n", + GUID_buf_string(&global->client_guid, &buf)); + } subreq = messaging_filtered_read_send(client, client->raw_ev_ctx, client->msg_ctx, @@ -893,7 +907,7 @@ static NTSTATUS smb2srv_client_connection_passed(struct smbXsrv_client *client, ZERO_STRUCT(passed_blob); passed_blob.version = smbXsrv_version_global_current(); passed_blob.info.info0 = &passed_info0; - + DBG_ERR("### connection passed\n"); if (DEBUGLVL(DBGLVL_DEBUG)) { NDR_PRINT_DEBUG(smbXsrv_connection_passB, &passed_blob); } diff --git a/source3/smbd/smbXsrv_session.c b/source3/smbd/smbXsrv_session.c index 59c6b49f2d9..46298457c80 100644 --- a/source3/smbd/smbXsrv_session.c +++ b/source3/smbd/smbXsrv_session.c @@ -1268,7 +1268,7 @@ static int smbXsrv_session_destructor(struct smbXsrv_session *session) { NTSTATUS status; - DBG_DEBUG("destructing session(%llu)\n", + DBG_ERR("destructing session(%llu)\n", (unsigned long long)session->global->session_wire_id); status = smbXsrv_session_clear_and_logoff(session); diff --git a/source3/smbd/smbXsrv_tcon.c b/source3/smbd/smbXsrv_tcon.c index 6b105522855..fb2b55b2fef 100644 --- a/source3/smbd/smbXsrv_tcon.c +++ b/source3/smbd/smbXsrv_tcon.c @@ -901,14 +901,17 @@ NTSTATUS smbXsrv_tcon_disconnect(struct smbXsrv_tcon *tcon, uint64_t vuid) table = tcon->table; tcon->table = NULL; - + DBG_ERR("### got disconnect for %p\n", tcon->compat); if (tcon->compat) { bool ok; - + static int i; + int res = i % 3; + i = i + 1; ok = chdir_current_service(tcon->compat); - if (!ok) { + DBG_ERR("## %d\n", res); + if (!ok || res == 0) { status = NT_STATUS_INTERNAL_ERROR; - DEBUG(0, ("smbXsrv_tcon_disconnect(0x%08x, '%s'): " + DEBUG(0, ("#### smbXsrv_tcon_disconnect(0x%08x, '%s'): " "chdir_current_service() failed: %s\n", tcon->global->tcon_global_id, tcon->global->share_name, diff --git a/source3/winbindd/winbindd.c b/source3/winbindd/winbindd.c index 6796b07bca3..01fd1cd3011 100644 --- a/source3/winbindd/winbindd.c +++ b/source3/winbindd/winbindd.c @@ -998,7 +998,8 @@ static void winbindd_listen_fde_handler(struct tevent_context *ev, { struct winbindd_listen_state *s = talloc_get_type_abort(private_data, struct winbindd_listen_state); - + DBG_ERR("### in fd handlee, num_clients = %d\n", + lp_winbind_max_clients()); while (winbindd_num_clients() > lp_winbind_max_clients() - 1) { DEBUG(5,("winbindd: Exceeding %d client " "connections, removing idle "