2 Unix SMB/CIFS implementation.
4 Winbind daemon for ntdom nss module
6 Copyright (C) by Tim Potter 2000-2002
7 Copyright (C) Andrew Tridgell 2002
8 Copyright (C) Jelmer Vernooij 2003
9 Copyright (C) Volker Lendecke 2004
11 This program is free software; you can redistribute it and/or modify
12 it under the terms of the GNU General Public License as published by
13 the Free Software Foundation; either version 3 of the License, or
14 (at your option) any later version.
16 This program is distributed in the hope that it will be useful,
17 but WITHOUT ANY WARRANTY; without even the implied warranty of
18 MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the
19 GNU General Public License for more details.
21 You should have received a copy of the GNU General Public License
22 along with this program. If not, see <http://www.gnu.org/licenses/>.
26 #include "popt_common.h"
28 #include "nsswitch/winbind_client.h"
29 #include "nsswitch/wb_reqtrans.h"
31 #include "../librpc/gen_ndr/srv_lsa.h"
32 #include "../librpc/gen_ndr/srv_samr.h"
34 #include "rpc_client/cli_netlogon.h"
36 #include "lib/addrchange.h"
39 #include "../lib/util/pidfile.h"
40 #include "util_cluster.h"
41 #include "source4/lib/messaging/irpc.h"
42 #include "source4/lib/messaging/messaging.h"
43 #include "lib/param/param.h"
44 #include "lib/async_req/async_sock.h"
45 #include "libsmb/samlogon_cache.h"
46 #include "libcli/auth/netlogon_creds_cli.h"
50 #define DBGC_CLASS DBGC_WINBIND
52 #define SCRUB_CLIENTS_INTERVAL 5
54 static bool client_is_idle(struct winbindd_cli_state *state);
55 static void remove_client(struct winbindd_cli_state *state);
56 static void winbindd_setup_max_fds(void);
58 static bool opt_nocache = False;
59 static bool interactive = False;
61 extern bool override_logfile;
63 struct imessaging_context *winbind_imessaging_context(void)
65 static struct imessaging_context *msg = NULL;
66 struct messaging_context *msg_ctx;
67 struct server_id myself;
68 struct loadparm_context *lp_ctx;
74 msg_ctx = server_messaging_context();
75 if (msg_ctx == NULL) {
76 smb_panic("server_messaging_context failed\n");
78 myself = messaging_server_id(msg_ctx);
80 lp_ctx = loadparm_init_s3(NULL, loadparm_s3_helpers());
82 smb_panic("Could not load smb.conf to init winbindd's imessaging context.\n");
86 * Note we MUST use the NULL context here, not the autofree context,
87 * to avoid side effects in forked children exiting.
89 msg = imessaging_init(NULL, lp_ctx, myself, server_event_context());
90 talloc_unlink(NULL, lp_ctx);
93 smb_panic("Could not init winbindd's messaging context.\n");
98 /* Reload configuration */
100 static bool reload_services_file(const char *lfile)
105 char *fname = lp_next_configfile(talloc_tos());
107 if (file_exist(fname) && !strcsequal(fname,get_dyn_CONFIGFILE())) {
108 set_dyn_CONFIGFILE(fname);
113 /* if this is a child, restore the logfile to the special
114 name - <domain>, idmap, etc. */
115 if (lfile && *lfile) {
116 lp_set_logfile(lfile);
120 ret = lp_load_global(get_dyn_CONFIGFILE());
124 winbindd_setup_max_fds();
130 static void winbindd_status(void)
132 struct winbindd_cli_state *tmp;
134 DEBUG(0, ("winbindd status:\n"));
136 /* Print client state information */
138 DEBUG(0, ("\t%d clients currently active\n", winbindd_num_clients()));
140 if (DEBUGLEVEL >= 2 && winbindd_num_clients()) {
141 DEBUG(2, ("\tclient list:\n"));
142 for(tmp = winbindd_client_list(); tmp; tmp = tmp->next) {
143 DEBUGADD(2, ("\t\tpid %lu, sock %d (%s)\n",
144 (unsigned long)tmp->pid, tmp->sock,
145 client_is_idle(tmp) ? "idle" : "active"));
150 /* Flush client cache */
152 static void flush_caches(void)
154 /* We need to invalidate cached user list entries on a SIGHUP
155 otherwise cached access denied errors due to restrict anonymous
156 hang around until the sequence number changes. */
158 if (!wcache_invalidate_cache()) {
159 DEBUG(0, ("invalidating the cache failed; revalidate the cache\n"));
160 if (!winbindd_cache_validate_and_initialize()) {
166 static void flush_caches_noinit(void)
169 * We need to invalidate cached user list entries on a SIGHUP
170 * otherwise cached access denied errors due to restrict anonymous
171 * hang around until the sequence number changes.
173 * Skip uninitialized domains when flush cache.
174 * If domain is not initialized, it means it is never
175 * used or never become online. look, wcache_invalidate_cache()
176 * -> get_cache() -> init_dc_connection(). It causes a lot of traffic
177 * for unused domains and large traffic for primay domain's DC if there
181 if (!wcache_invalidate_cache_noinit()) {
182 DEBUG(0, ("invalidating the cache failed; revalidate the cache\n"));
183 if (!winbindd_cache_validate_and_initialize()) {
189 /* Handle the signal by unlinking socket and exiting */
191 static void terminate(bool is_parent)
194 /* When parent goes away we should
195 * remove the socket file. Not so
196 * when children terminate.
200 if (asprintf(&path, "%s/%s",
201 lp_winbindd_socket_directory(), WINBINDD_SOCKET_NAME) > 0) {
209 gencache_stabilize();
211 netlogon_creds_cli_close_global_db();
215 TALLOC_CTX *mem_ctx = talloc_init("end_description");
216 char *description = talloc_describe_all(mem_ctx);
218 DEBUG(3, ("tallocs left:\n%s\n", description));
219 talloc_destroy(mem_ctx);
224 pidfile_unlink(lp_pid_directory(), "winbindd");
230 static void winbindd_sig_term_handler(struct tevent_context *ev,
231 struct tevent_signal *se,
237 bool *p = talloc_get_type_abort(private_data, bool);
242 DEBUG(0,("Got sig[%d] terminate (is_parent=%d)\n",
244 terminate(is_parent);
248 handle stdin becoming readable when we are in --foreground mode
250 static void winbindd_stdin_handler(struct tevent_context *ev,
251 struct tevent_fd *fde,
256 if (read(0, &c, 1) != 1) {
257 bool *is_parent = talloc_get_type_abort(private_data, bool);
259 /* we have reached EOF on stdin, which means the
260 parent has exited. Shutdown the server */
261 DEBUG(0,("EOF on stdin (is_parent=%d)\n",
263 terminate(*is_parent);
267 bool winbindd_setup_sig_term_handler(bool parent)
269 struct tevent_signal *se;
272 is_parent = talloc(server_event_context(), bool);
279 se = tevent_add_signal(server_event_context(),
282 winbindd_sig_term_handler,
285 DEBUG(0,("failed to setup SIGTERM handler"));
286 talloc_free(is_parent);
290 se = tevent_add_signal(server_event_context(),
293 winbindd_sig_term_handler,
296 DEBUG(0,("failed to setup SIGINT handler"));
297 talloc_free(is_parent);
301 se = tevent_add_signal(server_event_context(),
304 winbindd_sig_term_handler,
307 DEBUG(0,("failed to setup SIGINT handler"));
308 talloc_free(is_parent);
315 bool winbindd_setup_stdin_handler(bool parent, bool foreground)
322 is_parent = talloc(server_event_context(), bool);
329 /* if we are running in the foreground then look for
330 EOF on stdin, and exit if it happens. This allows
331 us to die if the parent process dies
332 Only do this on a pipe or socket, no other device.
334 if (fstat(0, &st) != 0) {
337 if (S_ISFIFO(st.st_mode) || S_ISSOCK(st.st_mode)) {
338 tevent_add_fd(server_event_context(),
342 winbindd_stdin_handler,
350 static void winbindd_sig_hup_handler(struct tevent_context *ev,
351 struct tevent_signal *se,
357 const char *file = (const char *)private_data;
359 DEBUG(1,("Reloading services after SIGHUP\n"));
360 flush_caches_noinit();
361 reload_services_file(file);
364 bool winbindd_setup_sig_hup_handler(const char *lfile)
366 struct tevent_signal *se;
370 file = talloc_strdup(server_event_context(),
377 se = tevent_add_signal(server_event_context(),
378 server_event_context(),
380 winbindd_sig_hup_handler,
389 static void winbindd_sig_chld_handler(struct tevent_context *ev,
390 struct tevent_signal *se,
398 while ((pid = waitpid(-1, NULL, WNOHANG)) > 0) {
399 winbind_child_died(pid);
403 static bool winbindd_setup_sig_chld_handler(void)
405 struct tevent_signal *se;
407 se = tevent_add_signal(server_event_context(),
408 server_event_context(),
410 winbindd_sig_chld_handler,
419 static void winbindd_sig_usr2_handler(struct tevent_context *ev,
420 struct tevent_signal *se,
429 static bool winbindd_setup_sig_usr2_handler(void)
431 struct tevent_signal *se;
433 se = tevent_add_signal(server_event_context(),
434 server_event_context(),
436 winbindd_sig_usr2_handler,
445 /* React on 'smbcontrol winbindd reload-config' in the same way as on SIGHUP*/
446 static void msg_reload_services(struct messaging_context *msg,
449 struct server_id server_id,
452 /* Flush various caches */
454 reload_services_file((const char *) private_data);
457 /* React on 'smbcontrol winbindd shutdown' in the same way as on SIGTERM*/
458 static void msg_shutdown(struct messaging_context *msg,
461 struct server_id server_id,
464 /* only the parent waits for this message */
465 DEBUG(0,("Got shutdown message\n"));
470 static void winbind_msg_validate_cache(struct messaging_context *msg_ctx,
473 struct server_id server_id,
480 DEBUG(10, ("winbindd_msg_validate_cache: got validate-cache "
484 * call the validation code from a child:
485 * so we don't block the main winbindd and the validation
486 * code can safely use fork/waitpid...
490 if (child_pid == -1) {
491 DEBUG(1, ("winbind_msg_validate_cache: Could not fork: %s\n",
496 if (child_pid != 0) {
498 DEBUG(5, ("winbind_msg_validate_cache: child created with "
499 "pid %d.\n", (int)child_pid));
505 status = winbindd_reinit_after_fork(NULL, NULL);
506 if (!NT_STATUS_IS_OK(status)) {
507 DEBUG(1, ("winbindd_reinit_after_fork failed: %s\n",
512 /* install default SIGCHLD handler: validation code uses fork/waitpid */
513 CatchSignal(SIGCHLD, SIG_DFL);
515 setproctitle("validate cache child");
517 ret = (uint8_t)winbindd_validate_cache_nobackup();
518 DEBUG(10, ("winbindd_msg_validata_cache: got return value %d\n", ret));
519 messaging_send_buf(msg_ctx, server_id, MSG_WINBIND_VALIDATE_CACHE, &ret,
524 static struct winbindd_dispatch_table {
525 enum winbindd_cmd cmd;
526 void (*fn)(struct winbindd_cli_state *state);
527 const char *winbindd_cmd_name;
528 } dispatch_table[] = {
530 /* Enumeration functions */
532 { WINBINDD_LIST_TRUSTDOM, winbindd_list_trusted_domains,
537 { WINBINDD_PING, winbindd_ping, "PING" },
538 { WINBINDD_DOMAIN_NAME, winbindd_domain_name, "DOMAIN_NAME" },
539 { WINBINDD_DOMAIN_INFO, winbindd_domain_info, "DOMAIN_INFO" },
540 { WINBINDD_DC_INFO, winbindd_dc_info, "DC_INFO" },
541 { WINBINDD_NETBIOS_NAME, winbindd_netbios_name, "NETBIOS_NAME" },
542 { WINBINDD_PRIV_PIPE_DIR, winbindd_priv_pipe_dir,
543 "WINBINDD_PRIV_PIPE_DIR" },
545 /* Credential cache access */
546 { WINBINDD_CCACHE_NTLMAUTH, winbindd_ccache_ntlm_auth, "NTLMAUTH" },
547 { WINBINDD_CCACHE_SAVE, winbindd_ccache_save, "CCACHE_SAVE" },
551 { WINBINDD_NUM_CMDS, NULL, "NONE" }
554 static struct winbindd_bool_dispatch_table {
555 enum winbindd_cmd cmd;
556 bool (*fn)(struct winbindd_cli_state *state);
557 const char *cmd_name;
558 } bool_dispatch_table[] = {
559 { WINBINDD_INTERFACE_VERSION,
560 winbindd_interface_version,
561 "INTERFACE_VERSION" },
567 struct winbindd_async_dispatch_table {
568 enum winbindd_cmd cmd;
569 const char *cmd_name;
570 struct tevent_req *(*send_req)(TALLOC_CTX *mem_ctx,
571 struct tevent_context *ev,
572 struct winbindd_cli_state *cli,
573 struct winbindd_request *request);
574 NTSTATUS (*recv_req)(struct tevent_req *req,
575 struct winbindd_response *presp);
578 static struct winbindd_async_dispatch_table async_nonpriv_table[] = {
579 { WINBINDD_LOOKUPSID, "LOOKUPSID",
580 winbindd_lookupsid_send, winbindd_lookupsid_recv },
581 { WINBINDD_LOOKUPSIDS, "LOOKUPSIDS",
582 winbindd_lookupsids_send, winbindd_lookupsids_recv },
583 { WINBINDD_LOOKUPNAME, "LOOKUPNAME",
584 winbindd_lookupname_send, winbindd_lookupname_recv },
585 { WINBINDD_SIDS_TO_XIDS, "SIDS_TO_XIDS",
586 winbindd_sids_to_xids_send, winbindd_sids_to_xids_recv },
587 { WINBINDD_XIDS_TO_SIDS, "XIDS_TO_SIDS",
588 winbindd_xids_to_sids_send, winbindd_xids_to_sids_recv },
589 { WINBINDD_GETPWSID, "GETPWSID",
590 winbindd_getpwsid_send, winbindd_getpwsid_recv },
591 { WINBINDD_GETPWNAM, "GETPWNAM",
592 winbindd_getpwnam_send, winbindd_getpwnam_recv },
593 { WINBINDD_GETPWUID, "GETPWUID",
594 winbindd_getpwuid_send, winbindd_getpwuid_recv },
595 { WINBINDD_GETSIDALIASES, "GETSIDALIASES",
596 winbindd_getsidaliases_send, winbindd_getsidaliases_recv },
597 { WINBINDD_GETUSERDOMGROUPS, "GETUSERDOMGROUPS",
598 winbindd_getuserdomgroups_send, winbindd_getuserdomgroups_recv },
599 { WINBINDD_GETGROUPS, "GETGROUPS",
600 winbindd_getgroups_send, winbindd_getgroups_recv },
601 { WINBINDD_SHOW_SEQUENCE, "SHOW_SEQUENCE",
602 winbindd_show_sequence_send, winbindd_show_sequence_recv },
603 { WINBINDD_GETGRGID, "GETGRGID",
604 winbindd_getgrgid_send, winbindd_getgrgid_recv },
605 { WINBINDD_GETGRNAM, "GETGRNAM",
606 winbindd_getgrnam_send, winbindd_getgrnam_recv },
607 { WINBINDD_GETUSERSIDS, "GETUSERSIDS",
608 winbindd_getusersids_send, winbindd_getusersids_recv },
609 { WINBINDD_LOOKUPRIDS, "LOOKUPRIDS",
610 winbindd_lookuprids_send, winbindd_lookuprids_recv },
611 { WINBINDD_SETPWENT, "SETPWENT",
612 winbindd_setpwent_send, winbindd_setpwent_recv },
613 { WINBINDD_GETPWENT, "GETPWENT",
614 winbindd_getpwent_send, winbindd_getpwent_recv },
615 { WINBINDD_ENDPWENT, "ENDPWENT",
616 winbindd_endpwent_send, winbindd_endpwent_recv },
617 { WINBINDD_DSGETDCNAME, "DSGETDCNAME",
618 winbindd_dsgetdcname_send, winbindd_dsgetdcname_recv },
619 { WINBINDD_GETDCNAME, "GETDCNAME",
620 winbindd_getdcname_send, winbindd_getdcname_recv },
621 { WINBINDD_SETGRENT, "SETGRENT",
622 winbindd_setgrent_send, winbindd_setgrent_recv },
623 { WINBINDD_GETGRENT, "GETGRENT",
624 winbindd_getgrent_send, winbindd_getgrent_recv },
625 { WINBINDD_ENDGRENT, "ENDGRENT",
626 winbindd_endgrent_send, winbindd_endgrent_recv },
627 { WINBINDD_LIST_USERS, "LIST_USERS",
628 winbindd_list_users_send, winbindd_list_users_recv },
629 { WINBINDD_LIST_GROUPS, "LIST_GROUPS",
630 winbindd_list_groups_send, winbindd_list_groups_recv },
631 { WINBINDD_CHECK_MACHACC, "CHECK_MACHACC",
632 winbindd_check_machine_acct_send, winbindd_check_machine_acct_recv },
633 { WINBINDD_PING_DC, "PING_DC",
634 winbindd_ping_dc_send, winbindd_ping_dc_recv },
635 { WINBINDD_PAM_AUTH, "PAM_AUTH",
636 winbindd_pam_auth_send, winbindd_pam_auth_recv },
637 { WINBINDD_PAM_LOGOFF, "PAM_LOGOFF",
638 winbindd_pam_logoff_send, winbindd_pam_logoff_recv },
639 { WINBINDD_PAM_CHAUTHTOK, "PAM_CHAUTHTOK",
640 winbindd_pam_chauthtok_send, winbindd_pam_chauthtok_recv },
641 { WINBINDD_PAM_CHNG_PSWD_AUTH_CRAP, "PAM_CHNG_PSWD_AUTH_CRAP",
642 winbindd_pam_chng_pswd_auth_crap_send,
643 winbindd_pam_chng_pswd_auth_crap_recv },
644 { WINBINDD_WINS_BYIP, "WINS_BYIP",
645 winbindd_wins_byip_send, winbindd_wins_byip_recv },
646 { WINBINDD_WINS_BYNAME, "WINS_BYNAME",
647 winbindd_wins_byname_send, winbindd_wins_byname_recv },
649 { 0, NULL, NULL, NULL }
652 static struct winbindd_async_dispatch_table async_priv_table[] = {
653 { WINBINDD_ALLOCATE_UID, "ALLOCATE_UID",
654 winbindd_allocate_uid_send, winbindd_allocate_uid_recv },
655 { WINBINDD_ALLOCATE_GID, "ALLOCATE_GID",
656 winbindd_allocate_gid_send, winbindd_allocate_gid_recv },
657 { WINBINDD_CHANGE_MACHACC, "CHANGE_MACHACC",
658 winbindd_change_machine_acct_send, winbindd_change_machine_acct_recv },
659 { WINBINDD_PAM_AUTH_CRAP, "PAM_AUTH_CRAP",
660 winbindd_pam_auth_crap_send, winbindd_pam_auth_crap_recv },
662 { 0, NULL, NULL, NULL }
665 static void wb_request_done(struct tevent_req *req);
667 static void process_request(struct winbindd_cli_state *state)
669 struct winbindd_dispatch_table *table = dispatch_table;
670 struct winbindd_async_dispatch_table *atable;
674 state->mem_ctx = talloc_named(state, 0, "winbind request");
675 if (state->mem_ctx == NULL)
678 /* Remember who asked us. */
679 state->pid = state->request->pid;
681 state->cmd_name = "unknown request";
682 state->recv_fn = NULL;
683 /* client is newest */
684 winbindd_promote_client(state);
686 /* Process command */
688 for (atable = async_nonpriv_table; atable->send_req; atable += 1) {
689 if (state->request->cmd == atable->cmd) {
694 if ((atable->send_req == NULL) && state->privileged) {
695 for (atable = async_priv_table; atable->send_req;
697 if (state->request->cmd == atable->cmd) {
703 if (atable->send_req != NULL) {
704 struct tevent_req *req;
706 state->cmd_name = atable->cmd_name;
707 state->recv_fn = atable->recv_req;
709 DEBUG(10, ("process_request: Handling async request %d:%s\n",
710 (int)state->pid, state->cmd_name));
712 req = atable->send_req(state->mem_ctx, server_event_context(),
713 state, state->request);
715 DEBUG(0, ("process_request: atable->send failed for "
716 "%s\n", atable->cmd_name));
717 request_error(state);
720 tevent_req_set_callback(req, wb_request_done, state);
724 state->response = talloc_zero(state->mem_ctx,
725 struct winbindd_response);
726 if (state->response == NULL) {
727 DEBUG(10, ("talloc failed\n"));
728 remove_client(state);
731 state->response->result = WINBINDD_PENDING;
732 state->response->length = sizeof(struct winbindd_response);
734 for (table = dispatch_table; table->fn; table++) {
735 if (state->request->cmd == table->cmd) {
736 DEBUG(10,("process_request: request fn %s\n",
737 table->winbindd_cmd_name ));
738 state->cmd_name = table->winbindd_cmd_name;
744 for (i=0; i<ARRAY_SIZE(bool_dispatch_table); i++) {
745 if (bool_dispatch_table[i].cmd == state->request->cmd) {
750 if (i == ARRAY_SIZE(bool_dispatch_table)) {
751 DEBUG(10,("process_request: unknown request fn number %d\n",
752 (int)state->request->cmd ));
753 request_error(state);
757 DBG_DEBUG("process_request: request fn %s\n",
758 bool_dispatch_table[i].cmd_name);
760 ok = bool_dispatch_table[i].fn(state);
765 request_error(state);
769 static void wb_request_done(struct tevent_req *req)
771 struct winbindd_cli_state *state = tevent_req_callback_data(
772 req, struct winbindd_cli_state);
775 state->response = talloc_zero(state->mem_ctx,
776 struct winbindd_response);
777 if (state->response == NULL) {
778 DEBUG(0, ("wb_request_done[%d:%s]: talloc_zero failed - removing client\n",
779 (int)state->pid, state->cmd_name));
780 remove_client(state);
783 state->response->result = WINBINDD_PENDING;
784 state->response->length = sizeof(struct winbindd_response);
786 status = state->recv_fn(req, state->response);
789 DEBUG(10,("wb_request_done[%d:%s]: %s\n",
790 (int)state->pid, state->cmd_name, nt_errstr(status)));
792 if (!NT_STATUS_IS_OK(status)) {
793 request_error(state);
800 * This is the main event loop of winbind requests. It goes through a
801 * state-machine of 3 read/write requests, 4 if you have extra data to send.
803 * An idle winbind client has a read request of 4 bytes outstanding,
804 * finalizing function is request_len_recv, checking the length. request_recv
805 * then processes the packet. The processing function then at some point has
806 * to call request_finished which schedules sending the response.
809 static void request_finished(struct winbindd_cli_state *state);
811 static void winbind_client_request_read(struct tevent_req *req);
812 static void winbind_client_response_written(struct tevent_req *req);
813 static void winbind_client_activity(struct tevent_req *req);
815 static void request_finished(struct winbindd_cli_state *state)
817 struct tevent_req *req;
819 /* free client socket monitoring request */
820 TALLOC_FREE(state->io_req);
822 TALLOC_FREE(state->request);
824 req = wb_resp_write_send(state, server_event_context(),
825 state->out_queue, state->sock,
828 DEBUG(10,("request_finished[%d:%s]: wb_resp_write_send() failed\n",
829 (int)state->pid, state->cmd_name));
830 remove_client(state);
833 tevent_req_set_callback(req, winbind_client_response_written, state);
837 static void winbind_client_response_written(struct tevent_req *req)
839 struct winbindd_cli_state *state = tevent_req_callback_data(
840 req, struct winbindd_cli_state);
844 state->io_req = NULL;
846 ret = wb_resp_write_recv(req, &err);
851 DEBUG(2, ("Could not write response[%d:%s] to client: %s\n",
852 (int)state->pid, state->cmd_name, strerror(err)));
853 remove_client(state);
857 DEBUG(10,("winbind_client_response_written[%d:%s]: delivered response "
858 "to client\n", (int)state->pid, state->cmd_name));
860 TALLOC_FREE(state->mem_ctx);
861 state->response = NULL;
862 state->cmd_name = "no request";
863 state->recv_fn = NULL;
865 req = wb_req_read_send(state, server_event_context(), state->sock,
866 WINBINDD_MAX_EXTRA_DATA);
868 remove_client(state);
871 tevent_req_set_callback(req, winbind_client_request_read, state);
875 void request_error(struct winbindd_cli_state *state)
877 SMB_ASSERT(state->response->result == WINBINDD_PENDING);
878 state->response->result = WINBINDD_ERROR;
879 request_finished(state);
882 void request_ok(struct winbindd_cli_state *state)
884 SMB_ASSERT(state->response->result == WINBINDD_PENDING);
885 state->response->result = WINBINDD_OK;
886 request_finished(state);
889 /* Process a new connection by adding it to the client connection list */
891 static void new_connection(int listen_sock, bool privileged)
893 struct sockaddr_un sunaddr;
894 struct winbindd_cli_state *state;
895 struct tevent_req *req;
899 /* Accept connection */
901 len = sizeof(sunaddr);
903 sock = accept(listen_sock, (struct sockaddr *)(void *)&sunaddr, &len);
906 if (errno != EINTR) {
907 DEBUG(0, ("Failed to accept socket - %s\n",
912 smb_set_close_on_exec(sock);
914 DEBUG(6,("accepted socket %d\n", sock));
916 /* Create new connection structure */
918 if ((state = talloc_zero(NULL, struct winbindd_cli_state)) == NULL) {
925 state->out_queue = tevent_queue_create(state, "winbind client reply");
926 if (state->out_queue == NULL) {
932 state->privileged = privileged;
934 req = wb_req_read_send(state, server_event_context(), state->sock,
935 WINBINDD_MAX_EXTRA_DATA);
941 tevent_req_set_callback(req, winbind_client_request_read, state);
944 /* Add to connection list */
946 winbindd_add_client(state);
949 static void winbind_client_request_read(struct tevent_req *req)
951 struct winbindd_cli_state *state = tevent_req_callback_data(
952 req, struct winbindd_cli_state);
956 state->io_req = NULL;
958 ret = wb_req_read_recv(req, state, &state->request, &err);
962 DEBUG(6, ("closing socket %d, client exited\n",
965 DEBUG(2, ("Could not read client request from fd %d: "
966 "%s\n", state->sock, strerror(err)));
970 remove_client(state);
974 req = wait_for_read_send(state, server_event_context(), state->sock,
977 DEBUG(0, ("winbind_client_request_read[%d:%s]:"
978 " wait_for_read_send failed - removing client\n",
979 (int)state->pid, state->cmd_name));
980 remove_client(state);
983 tevent_req_set_callback(req, winbind_client_activity, state);
986 process_request(state);
989 static void winbind_client_activity(struct tevent_req *req)
991 struct winbindd_cli_state *state =
992 tevent_req_callback_data(req, struct winbindd_cli_state);
996 has_data = wait_for_read_recv(req, &err);
999 DEBUG(0, ("winbind_client_activity[%d:%s]:"
1000 "unexpected data from client - removing client\n",
1001 (int)state->pid, state->cmd_name));
1004 DEBUG(6, ("winbind_client_activity[%d:%s]: "
1005 "client has closed connection - removing "
1007 (int)state->pid, state->cmd_name));
1009 DEBUG(2, ("winbind_client_activity[%d:%s]: "
1010 "client socket error (%s) - removing "
1012 (int)state->pid, state->cmd_name,
1017 remove_client(state);
1020 /* Remove a client connection from client connection list */
1022 static void remove_client(struct winbindd_cli_state *state)
1027 /* It's a dead client - hold a funeral */
1029 if (state == NULL) {
1034 * We need to remove a pending wb_req_read_*
1035 * or wb_resp_write_* request before closing the
1038 * This is important as they might have used tevent_add_fd() and we
1039 * use the epoll * backend on linux. So we must remove the tevent_fd
1040 * before closing the fd.
1042 * Otherwise we might hit a race with close_conns_after_fork() (via
1043 * winbindd_reinit_after_fork()) where a file description
1044 * is still open in a child, which means it's still active in
1045 * the parents epoll queue, but the related tevent_fd is already
1046 * already gone in the parent.
1050 TALLOC_FREE(state->io_req);
1052 if (state->sock != -1) {
1053 /* tell client, we are closing ... */
1054 nwritten = write(state->sock, &c, sizeof(c));
1055 if (nwritten == -1) {
1056 DEBUG(2, ("final write to client failed: %s\n",
1066 TALLOC_FREE(state->mem_ctx);
1068 /* Remove from list and free */
1070 winbindd_remove_client(state);
1074 /* Is a client idle? */
1076 static bool client_is_idle(struct winbindd_cli_state *state) {
1077 return (state->request == NULL &&
1078 state->response == NULL &&
1079 !state->pwent_state && !state->grent_state);
1082 /* Shutdown client connection which has been idle for the longest time */
1084 static bool remove_idle_client(void)
1086 struct winbindd_cli_state *state, *remove_state = NULL;
1089 for (state = winbindd_client_list(); state; state = state->next) {
1090 if (client_is_idle(state)) {
1092 /* list is sorted by access time */
1093 remove_state = state;
1098 DEBUG(5,("Found %d idle client connections, shutting down sock %d, pid %u\n",
1099 nidle, remove_state->sock, (unsigned int)remove_state->pid));
1100 remove_client(remove_state);
1108 * Terminate all clients whose requests have taken longer than
1109 * "winbind request timeout" seconds to process, or have been
1110 * idle for more than "winbind request timeout" seconds.
1113 static void remove_timed_out_clients(void)
1115 struct winbindd_cli_state *state, *prev = NULL;
1116 time_t curr_time = time(NULL);
1117 int timeout_val = lp_winbind_request_timeout();
1119 for (state = winbindd_client_list_tail(); state; state = prev) {
1122 prev = winbindd_client_list_prev(state);
1123 expiry_time = state->last_access + timeout_val;
1125 if (curr_time <= expiry_time) {
1126 /* list is sorted, previous clients in
1131 if (client_is_idle(state)) {
1132 DEBUG(5,("Idle client timed out, "
1133 "shutting down sock %d, pid %u\n",
1135 (unsigned int)state->pid));
1137 DEBUG(5,("Client request timed out, "
1138 "shutting down sock %d, pid %u\n",
1140 (unsigned int)state->pid));
1143 remove_client(state);
1147 static void winbindd_scrub_clients_handler(struct tevent_context *ev,
1148 struct tevent_timer *te,
1149 struct timeval current_time,
1152 remove_timed_out_clients();
1153 if (tevent_add_timer(ev, ev,
1154 timeval_current_ofs(SCRUB_CLIENTS_INTERVAL, 0),
1155 winbindd_scrub_clients_handler, NULL) == NULL) {
1156 DEBUG(0, ("winbindd: failed to reschedule client scrubber\n"));
1161 struct winbindd_listen_state {
1166 static void winbindd_listen_fde_handler(struct tevent_context *ev,
1167 struct tevent_fd *fde,
1171 struct winbindd_listen_state *s = talloc_get_type_abort(private_data,
1172 struct winbindd_listen_state);
1174 while (winbindd_num_clients() > lp_winbind_max_clients() - 1) {
1175 DEBUG(5,("winbindd: Exceeding %d client "
1176 "connections, removing idle "
1177 "connection.\n", lp_winbind_max_clients()));
1178 if (!remove_idle_client()) {
1179 DEBUG(0,("winbindd: Exceeding %d "
1180 "client connections, no idle "
1181 "connection found\n",
1182 lp_winbind_max_clients()));
1186 remove_timed_out_clients();
1187 new_connection(s->fd, s->privileged);
1191 * Winbindd socket accessor functions
1194 char *get_winbind_priv_pipe_dir(void)
1196 return state_path(WINBINDD_PRIV_SOCKET_SUBDIR);
1199 static void winbindd_setup_max_fds(void)
1201 int num_fds = MAX_OPEN_FUDGEFACTOR;
1204 num_fds += lp_winbind_max_clients();
1205 /* Add some more to account for 2 sockets open
1206 when the client transitions from unprivileged
1207 to privileged socket
1209 num_fds += lp_winbind_max_clients() / 10;
1211 /* Add one socket per child process
1212 (yeah there are child processes other than the
1213 domain children but only domain children can vary
1216 num_fds += lp_winbind_max_domain_connections() *
1217 (lp_allow_trusted_domains() ? WINBIND_MAX_DOMAINS_HINT : 1);
1219 actual_fds = set_maxfiles(num_fds);
1221 if (actual_fds < num_fds) {
1222 DEBUG(1, ("winbindd_setup_max_fds: Information only: "
1223 "requested %d open files, %d are available.\n",
1224 num_fds, actual_fds));
1228 static bool winbindd_setup_listeners(void)
1230 struct winbindd_listen_state *pub_state = NULL;
1231 struct winbindd_listen_state *priv_state = NULL;
1232 struct tevent_fd *fde;
1236 pub_state = talloc(server_event_context(),
1237 struct winbindd_listen_state);
1242 pub_state->privileged = false;
1243 pub_state->fd = create_pipe_sock(
1244 lp_winbindd_socket_directory(), WINBINDD_SOCKET_NAME, 0755);
1245 if (pub_state->fd == -1) {
1248 rc = listen(pub_state->fd, 5);
1253 fde = tevent_add_fd(server_event_context(), pub_state, pub_state->fd,
1254 TEVENT_FD_READ, winbindd_listen_fde_handler,
1257 close(pub_state->fd);
1260 tevent_fd_set_auto_close(fde);
1262 priv_state = talloc(server_event_context(),
1263 struct winbindd_listen_state);
1268 socket_path = get_winbind_priv_pipe_dir();
1269 if (socket_path == NULL) {
1273 priv_state->privileged = true;
1274 priv_state->fd = create_pipe_sock(
1275 socket_path, WINBINDD_SOCKET_NAME, 0750);
1276 TALLOC_FREE(socket_path);
1277 if (priv_state->fd == -1) {
1280 rc = listen(priv_state->fd, 5);
1285 fde = tevent_add_fd(server_event_context(), priv_state,
1286 priv_state->fd, TEVENT_FD_READ,
1287 winbindd_listen_fde_handler, priv_state);
1289 close(priv_state->fd);
1292 tevent_fd_set_auto_close(fde);
1294 winbindd_scrub_clients_handler(server_event_context(), NULL,
1295 timeval_current(), NULL);
1298 TALLOC_FREE(pub_state);
1299 TALLOC_FREE(priv_state);
1303 bool winbindd_use_idmap_cache(void)
1305 return !opt_nocache;
1308 bool winbindd_use_cache(void)
1310 return !opt_nocache;
1313 static void winbindd_register_handlers(struct messaging_context *msg_ctx,
1316 bool scan_trusts = true;
1318 /* Setup signal handlers */
1320 if (!winbindd_setup_sig_term_handler(true))
1322 if (!winbindd_setup_stdin_handler(true, foreground))
1324 if (!winbindd_setup_sig_hup_handler(NULL))
1326 if (!winbindd_setup_sig_chld_handler())
1328 if (!winbindd_setup_sig_usr2_handler())
1331 CatchSignal(SIGPIPE, SIG_IGN); /* Ignore sigpipe */
1334 * Ensure all cache and idmap caches are consistent
1335 * and initialized before we startup.
1337 if (!winbindd_cache_validate_and_initialize()) {
1341 /* React on 'smbcontrol winbindd reload-config' in the same way
1342 as to SIGHUP signal */
1343 messaging_register(msg_ctx, NULL,
1344 MSG_SMB_CONF_UPDATED, msg_reload_services);
1345 messaging_register(msg_ctx, NULL,
1346 MSG_SHUTDOWN, msg_shutdown);
1348 /* Handle online/offline messages. */
1349 messaging_register(msg_ctx, NULL,
1350 MSG_WINBIND_OFFLINE, winbind_msg_offline);
1351 messaging_register(msg_ctx, NULL,
1352 MSG_WINBIND_ONLINE, winbind_msg_online);
1353 messaging_register(msg_ctx, NULL,
1354 MSG_WINBIND_ONLINESTATUS, winbind_msg_onlinestatus);
1356 /* Handle domain online/offline messages for domains */
1357 messaging_register(server_messaging_context(), NULL,
1358 MSG_WINBIND_DOMAIN_OFFLINE, winbind_msg_domain_offline);
1359 messaging_register(server_messaging_context(), NULL,
1360 MSG_WINBIND_DOMAIN_ONLINE, winbind_msg_domain_online);
1362 messaging_register(msg_ctx, NULL,
1363 MSG_WINBIND_VALIDATE_CACHE,
1364 winbind_msg_validate_cache);
1366 messaging_register(msg_ctx, NULL,
1367 MSG_WINBIND_DUMP_DOMAIN_LIST,
1368 winbind_msg_dump_domain_list);
1370 messaging_register(msg_ctx, NULL,
1371 MSG_WINBIND_IP_DROPPED,
1372 winbind_msg_ip_dropped_parent);
1374 /* Register handler for MSG_DEBUG. */
1375 messaging_register(msg_ctx, NULL,
1379 messaging_register(msg_ctx, NULL,
1380 MSG_WINBIND_DISCONNECT_DC,
1381 winbind_disconnect_dc_parent);
1383 netsamlogon_cache_init(); /* Non-critical */
1385 /* clear the cached list of trusted domains */
1389 if (!init_domain_list()) {
1390 DEBUG(0,("unable to initialize domain list\n"));
1395 init_locator_child();
1397 smb_nscd_flush_user_cache();
1398 smb_nscd_flush_group_cache();
1400 if (!lp_winbind_scan_trusted_domains()) {
1401 scan_trusts = false;
1404 if (!lp_allow_trusted_domains()) {
1405 scan_trusts = false;
1409 scan_trusts = false;
1413 if (tevent_add_timer(server_event_context(), NULL, timeval_zero(),
1414 rescan_trusted_domains, NULL) == NULL) {
1415 DEBUG(0, ("Could not trigger rescan_trusted_domains()\n"));
1420 status = wb_irpc_register();
1422 if (!NT_STATUS_IS_OK(status)) {
1423 DEBUG(0, ("Could not register IRPC handlers\n"));
1428 struct winbindd_addrchanged_state {
1429 struct addrchange_context *ctx;
1430 struct tevent_context *ev;
1431 struct messaging_context *msg_ctx;
1434 static void winbindd_addr_changed(struct tevent_req *req);
1436 static void winbindd_init_addrchange(TALLOC_CTX *mem_ctx,
1437 struct tevent_context *ev,
1438 struct messaging_context *msg_ctx)
1440 struct winbindd_addrchanged_state *state;
1441 struct tevent_req *req;
1444 state = talloc(mem_ctx, struct winbindd_addrchanged_state);
1445 if (state == NULL) {
1446 DEBUG(10, ("talloc failed\n"));
1450 state->msg_ctx = msg_ctx;
1452 status = addrchange_context_create(state, &state->ctx);
1453 if (!NT_STATUS_IS_OK(status)) {
1454 DEBUG(10, ("addrchange_context_create failed: %s\n",
1455 nt_errstr(status)));
1459 req = addrchange_send(state, ev, state->ctx);
1461 DEBUG(0, ("addrchange_send failed\n"));
1465 tevent_req_set_callback(req, winbindd_addr_changed, state);
1468 static void winbindd_addr_changed(struct tevent_req *req)
1470 struct winbindd_addrchanged_state *state = tevent_req_callback_data(
1471 req, struct winbindd_addrchanged_state);
1472 enum addrchange_type type;
1473 struct sockaddr_storage addr;
1476 status = addrchange_recv(req, &type, &addr);
1478 if (!NT_STATUS_IS_OK(status)) {
1479 DEBUG(10, ("addrchange_recv failed: %s, stop listening\n",
1480 nt_errstr(status)));
1484 if (type == ADDRCHANGE_DEL) {
1485 char addrstr[INET6_ADDRSTRLEN];
1488 print_sockaddr(addrstr, sizeof(addrstr), &addr);
1490 DEBUG(3, ("winbindd: kernel (AF_NETLINK) dropped ip %s\n",
1493 blob = data_blob_const(addrstr, strlen(addrstr)+1);
1495 status = messaging_send(state->msg_ctx,
1496 messaging_server_id(state->msg_ctx),
1497 MSG_WINBIND_IP_DROPPED, &blob);
1498 if (!NT_STATUS_IS_OK(status)) {
1499 DEBUG(10, ("messaging_send failed: %s - ignoring\n",
1500 nt_errstr(status)));
1503 req = addrchange_send(state, state->ev, state->ctx);
1505 DEBUG(0, ("addrchange_send failed\n"));
1509 tevent_req_set_callback(req, winbindd_addr_changed, state);
1514 int main(int argc, const char **argv)
1516 static bool is_daemon = False;
1517 static bool Fork = True;
1518 static bool log_stdout = False;
1519 static bool no_process_group = False;
1523 OPT_NO_PROCESS_GROUP,
1526 struct poptOption long_options[] = {
1528 { "stdout", 'S', POPT_ARG_NONE, NULL, OPT_LOG_STDOUT, "Log to stdout" },
1529 { "foreground", 'F', POPT_ARG_NONE, NULL, OPT_FORK, "Daemon in foreground mode" },
1530 { "no-process-group", 0, POPT_ARG_NONE, NULL, OPT_NO_PROCESS_GROUP, "Don't create a new process group" },
1531 { "daemon", 'D', POPT_ARG_NONE, NULL, OPT_DAEMON, "Become a daemon (default)" },
1532 { "interactive", 'i', POPT_ARG_NONE, NULL, 'i', "Interactive mode" },
1533 { "no-caching", 'n', POPT_ARG_NONE, NULL, 'n', "Disable caching" },
1543 setproctitle_init(argc, discard_const(argv), environ);
1546 * Do this before any other talloc operation
1548 talloc_enable_null_tracking();
1549 frame = talloc_stackframe();
1552 * We want total control over the permissions on created files,
1553 * so set our umask to 0.
1557 setup_logging("winbindd", DEBUG_DEFAULT_STDOUT);
1559 /* glibc (?) likes to print "User defined signal 1" and exit if a
1560 SIGUSR[12] is received before a handler is installed */
1562 CatchSignal(SIGUSR1, SIG_IGN);
1563 CatchSignal(SIGUSR2, SIG_IGN);
1566 dump_core_setup("winbindd", lp_logfile(talloc_tos()));
1570 /* Initialise for running in non-root mode */
1574 set_remote_machine_name("winbindd", False);
1576 /* Set environment variable so we don't recursively call ourselves.
1577 This may also be useful interactively. */
1579 if ( !winbind_off() ) {
1580 DEBUG(0,("Failed to disable recusive winbindd calls. Exiting.\n"));
1584 /* Initialise samba/rpc client stuff */
1586 pc = poptGetContext("winbindd", argc, argv, long_options, 0);
1588 while ((opt = poptGetNextOpt(pc)) != -1) {
1590 /* Don't become a daemon */
1602 case OPT_NO_PROCESS_GROUP:
1603 no_process_group = true;
1605 case OPT_LOG_STDOUT:
1612 d_fprintf(stderr, "\nInvalid option %s: %s\n\n",
1613 poptBadOption(pc, 0), poptStrerror(opt));
1614 poptPrintUsage(pc, stderr, 0);
1619 /* We call dump_core_setup one more time because the command line can
1620 * set the log file or the log-basename and this will influence where
1621 * cores are stored. Without this call get_dyn_LOGFILEBASE will be
1622 * the default value derived from build's prefix. For EOM this value
1623 * is often not related to the path where winbindd is actually run
1626 dump_core_setup("winbindd", lp_logfile(talloc_tos()));
1627 if (is_daemon && interactive) {
1628 d_fprintf(stderr,"\nERROR: "
1629 "Option -i|--interactive is not allowed together with -D|--daemon\n\n");
1630 poptPrintUsage(pc, stderr, 0);
1634 if (log_stdout && Fork) {
1635 d_fprintf(stderr, "\nERROR: "
1636 "Can't log to stdout (-S) unless daemon is in foreground +(-F) or interactive (-i)\n\n");
1637 poptPrintUsage(pc, stderr, 0);
1641 poptFreeContext(pc);
1643 if (!override_logfile) {
1645 if (asprintf(&lfile,"%s/log.winbindd",
1646 get_dyn_LOGFILEBASE()) > 0) {
1647 lp_set_logfile(lfile);
1653 setup_logging("winbindd", DEBUG_STDOUT);
1655 setup_logging("winbindd", DEBUG_FILE);
1659 DEBUG(0,("winbindd version %s started.\n", samba_version_string()));
1660 DEBUGADD(0,("%s\n", COPYRIGHT_STARTUP_MESSAGE));
1662 if (!lp_load_initial_only(get_dyn_CONFIGFILE())) {
1663 DEBUG(0, ("error opening config file '%s'\n", get_dyn_CONFIGFILE()));
1666 /* After parsing the configuration file we setup the core path one more time
1667 * as the log file might have been set in the configuration and cores's
1668 * path is by default basename(lp_logfile()).
1670 dump_core_setup("winbindd", lp_logfile(talloc_tos()));
1672 if (lp_server_role() == ROLE_ACTIVE_DIRECTORY_DC
1673 && !lp_parm_bool(-1, "server role check", "inhibit", false)) {
1674 DEBUG(0, ("server role = 'active directory domain controller' not compatible with running the winbindd binary. \n"));
1675 DEBUGADD(0, ("You should start 'samba' instead, and it will control starting the internal AD DC winbindd implementation, which is not the same as this one\n"));
1679 if (!cluster_probe_ok()) {
1683 /* Initialise messaging system */
1685 if (server_messaging_context() == NULL) {
1689 if (!reload_services_file(NULL)) {
1690 DEBUG(0, ("error opening config file\n"));
1696 const char *idmap_backend;
1697 const char *invalid_backends[] = {
1698 "ad", "rfc2307", "rid",
1701 idmap_backend = lp_idmap_default_backend();
1702 for (i = 0; i < ARRAY_SIZE(invalid_backends); i++) {
1703 ok = strequal(idmap_backend, invalid_backends[i]);
1705 DBG_ERR("FATAL: Invalid idmap backend %s "
1706 "configured as the default backend!\n",
1713 ok = directory_create_or_exist(lp_lock_directory(), 0755);
1715 DEBUG(0, ("Failed to create directory %s for lock files - %s\n",
1716 lp_lock_directory(), strerror(errno)));
1720 ok = directory_create_or_exist(lp_pid_directory(), 0755);
1722 DEBUG(0, ("Failed to create directory %s for pid files - %s\n",
1723 lp_pid_directory(), strerror(errno)));
1734 if (!secrets_init()) {
1736 DEBUG(0,("Could not initialize domain trust account secrets. Giving up\n"));
1740 status = rpccli_pre_open_netlogon_creds();
1741 if (!NT_STATUS_IS_OK(status)) {
1742 DEBUG(0, ("rpccli_pre_open_netlogon_creds() - %s\n",
1743 nt_errstr(status)));
1747 /* Unblock all signals we are interested in as they may have been
1748 blocked by the parent process. */
1750 BlockSignals(False, SIGINT);
1751 BlockSignals(False, SIGQUIT);
1752 BlockSignals(False, SIGTERM);
1753 BlockSignals(False, SIGUSR1);
1754 BlockSignals(False, SIGUSR2);
1755 BlockSignals(False, SIGHUP);
1756 BlockSignals(False, SIGCHLD);
1759 become_daemon(Fork, no_process_group, log_stdout);
1761 pidfile_create(lp_pid_directory(), "winbindd");
1765 * If we're interactive we want to set our own process group for
1766 * signal management.
1768 if (interactive && !no_process_group)
1769 setpgid( (pid_t)0, (pid_t)0);
1774 /* Don't use winbindd_reinit_after_fork here as
1775 * we're just starting up and haven't created any
1776 * winbindd-specific resources we must free yet. JRA.
1779 status = reinit_after_fork(server_messaging_context(),
1780 server_event_context(),
1782 if (!NT_STATUS_IS_OK(status)) {
1783 exit_daemon("Winbindd reinit_after_fork() failed", map_errno_from_nt_status(status));
1785 initialize_password_db(true, server_event_context());
1788 * Do not initialize the parent-child-pipe before becoming
1789 * a daemon: this is used to detect a died parent in the child
1792 status = init_before_fork();
1793 if (!NT_STATUS_IS_OK(status)) {
1794 exit_daemon(nt_errstr(status), map_errno_from_nt_status(status));
1797 winbindd_register_handlers(server_messaging_context(), !Fork);
1799 if (!messaging_parent_dgm_cleanup_init(server_messaging_context())) {
1803 status = init_system_session_info(NULL);
1804 if (!NT_STATUS_IS_OK(status)) {
1805 exit_daemon("Winbindd failed to setup system user info", map_errno_from_nt_status(status));
1808 rpc_lsarpc_init(NULL);
1809 rpc_samr_init(NULL);
1811 winbindd_init_addrchange(NULL, server_event_context(),
1812 server_messaging_context());
1814 /* setup listen sockets */
1816 if (!winbindd_setup_listeners()) {
1817 exit_daemon("Winbindd failed to setup listeners", EPIPE);
1820 irpc_add_name(winbind_imessaging_context(), "winbind_server");
1825 daemon_ready("winbindd");
1830 /* Loop waiting for requests */
1832 frame = talloc_stackframe();
1834 if (tevent_loop_once(server_event_context()) == -1) {
1835 DEBUG(1, ("tevent_loop_once() failed: %s\n",