From: David Herrmann Date: Mon, 8 Oct 2012 14:10:53 +0000 (+0200) Subject: uterm: vt: add a lot more verbose error messages X-Git-Tag: kmscon-7~387 X-Git-Url: http://review.tizen.org/git/?a=commitdiff_plain;h=c44c262617a545572d4e39f3125a355f89e2a510;p=platform%2Fupstream%2Fkmscon.git uterm: vt: add a lot more verbose error messages This adds a lot more verbose error messages to the whole real-VT handling so we can debug this fragile system way better than before. Signed-off-by: David Herrmann --- diff --git a/src/uterm.h b/src/uterm.h index 1aaea1b..1e70c7e 100644 --- a/src/uterm.h +++ b/src/uterm.h @@ -324,7 +324,6 @@ enum uterm_vt_action { enum uterm_vt_mode { UTERM_VT_REAL, UTERM_VT_FAKE, - UTERM_VT_DEAD, }; typedef int (*uterm_vt_cb) (struct uterm_vt *vt, unsigned int action, diff --git a/src/uterm_vt.c b/src/uterm_vt.c index 74e279d..e71429f 100644 --- a/src/uterm_vt.c +++ b/src/uterm_vt.c @@ -77,7 +77,7 @@ struct uterm_vt_master { struct shl_dlist vts; }; -static int vt_call(struct uterm_vt *vt, unsigned int event) +static void vt_call(struct uterm_vt *vt, unsigned int event) { int ret; @@ -87,7 +87,8 @@ static int vt_call(struct uterm_vt *vt, unsigned int event) if (vt->cb) { ret = vt->cb(vt, event, vt->data); if (ret) - log_warning("vt event handler returned %d instead of 0 on activation", ret); + log_warning("vt event handler returned %d instead of 0 on activation", + ret); } vt->active = true; } @@ -97,17 +98,46 @@ static int vt_call(struct uterm_vt *vt, unsigned int event) if (vt->cb) { ret = vt->cb(vt, event, vt->data); if (ret) - return ret; + log_warning("vt event handler returned %d instead of 0 on deactivation", + ret); } vt->active = false; } break; } - - return 0; } -static void real_enter(struct uterm_vt *vt, struct signalfd_siginfo *info) +/* + * 'Real' VTs + * The linux kernel (used) to provide VTs via CONFIG_VT. These VTs are TTYs that + * the kernel runs a very limit VT102 compatible console on. They also provide a + * mechanism to switch between graphical user-applications. + * An application that opens a VT is notified via two signals whenever the user + * switches to or away from the VT. We catch these signals and forward a + * notification to the application via callbacks. + * + * Real VTs are only available on seat0 and should be avoided whenever possible + * as they have a horrible API, have synchronization issues and are unflexible. + * + * Also note that the VT API is asynchronous and requires acknowledgment of + * applications when switching VTs. That means, when a VT-switch is started, the + * currently-active VT is notified about this and needs to acknowledge this + * switch. If it allows it, the new VT is notified that it is now started up. + * This control-passing is very fragile. For instance if the currently-active VT + * is stuck or paused, the VT switch cannot take place as it is not acknowledged + * by the currently active VT. + * Furthermore, there are some race-conditions during a switch. If resources + * that are passed from one VT to another are acquired during this switch from a + * 3rd party application, then they can highjack the VT-switch and make the new + * VT fail acquiring the resources. + * + * There are a lot more issues. For instance VTs are not cleaned up when closed + * which can cause deadlocks if VT_SETMODE is not reset. + * All in all, real VTs are very fragile and should be avoided. They should only + * be used for backwards-compatibility. + */ + +static void real_sig_enter(struct uterm_vt *vt, struct signalfd_siginfo *info) { struct vt_stat vts; int ret; @@ -116,20 +146,27 @@ static void real_enter(struct uterm_vt *vt, struct signalfd_siginfo *info) return; ret = ioctl(vt->real_fd, VT_GETSTATE, &vts); - if (ret || vts.v_active != vt->real_num) + if (ret) { + log_warning("cannot get current VT state (%d): %m", errno); return; + } - log_debug("enter VT %d %p", vt->real_num, vt); + if (vts.v_active != vt->real_num) + return; - ioctl(vt->real_fd, VT_RELDISP, VT_ACKACQ); + if (vt->active) + log_warning("activating VT %d even though it's already active", + vt->real_num); + log_debug("enter VT %d %p due to VT signal", vt->real_num, vt); + ioctl(vt->real_fd, VT_RELDISP, VT_ACKACQ); if (ioctl(vt->real_fd, KDSETMODE, KD_GRAPHICS)) - log_warn("cannot set graphics mode on vt %p", vt); - + log_warn("cannot set graphics mode on vt %p (%d): %m", vt, + errno); vt_call(vt, UTERM_VT_ACTIVATE); } -static void real_leave(struct uterm_vt *vt, struct signalfd_siginfo *info) +static void real_sig_leave(struct uterm_vt *vt, struct signalfd_siginfo *info) { struct vt_stat vts; int ret; @@ -138,21 +175,26 @@ static void real_leave(struct uterm_vt *vt, struct signalfd_siginfo *info) return; ret = ioctl(vt->real_fd, VT_GETSTATE, &vts); - if (ret || vts.v_active != vt->real_num) + if (ret) { + log_warning("cannot get current VT state (%d): %m", errno); return; - - if (vt_call(vt, UTERM_VT_DEACTIVATE)) { - log_debug("leaving VT %d %p denied", vt->real_num, vt); - ioctl(vt->real_fd, VT_RELDISP, 0); - } else { - log_debug("leaving VT %d %p", vt->real_num, vt); - ioctl(vt->real_fd, VT_RELDISP, 1); - if (ioctl(vt->real_fd, KDSETMODE, KD_TEXT)) - log_warn("cannot set text mode on vt %p", vt); } + + if (vts.v_active != vt->real_num) + return; + + if (!vt->active) + log_warning("deactivating VT %d even though it's not active", + vt->real_num); + + log_debug("leaving VT %d %p due to VT signal", vt->real_num, vt); + vt_call(vt, UTERM_VT_DEACTIVATE); + ioctl(vt->real_fd, VT_RELDISP, 1); + if (ioctl(vt->real_fd, KDSETMODE, KD_TEXT)) + log_warn("cannot set text mode on vt %p (%d): %m", vt, errno); } -static void real_input(struct ev_fd *fd, int mask, void *data) +static void real_vt_input(struct ev_fd *fd, int mask, void *data) { struct uterm_vt *vt = data; @@ -174,17 +216,18 @@ static int open_tty(const char *dev, int *tty_fd, int *tty_num) if (fd < 0) { err1 = errno; fd = open("/dev/tty1", - O_NONBLOCK | O_NOCTTY | O_CLOEXEC); + O_NONBLOCK | O_NOCTTY | O_CLOEXEC); if (fd < 0) { - log_err("cannot find parent tty (%d, %d): %m", - err1, errno); - return -errno; + log_error("cannot find parent tty (%d, %d): %m", + err1, errno); + return -EFAULT; } } + errno = 0; if (ioctl(fd, VT_OPENQRY, &id) || id <= 0) { close(fd); - log_err("cannot get unused tty"); + log_err("cannot get unused tty (%d): %m", errno); return -EINVAL; } close(fd); @@ -198,7 +241,7 @@ static int open_tty(const char *dev, int *tty_fd, int *tty_num) fd = open(dev, O_RDWR | O_NOCTTY | O_CLOEXEC); if (fd < 0) { - log_err("cannot open tty %s", dev); + log_err("cannot open tty %s (%d): %m", dev, errno); return -errno; } @@ -209,6 +252,7 @@ static int open_tty(const char *dev, int *tty_fd, int *tty_num) return -errno; } id = minor(st.st_rdev); + log_debug("new tty ID is %d", id); *tty_fd = fd; *tty_num = id; @@ -230,24 +274,22 @@ static int real_open(struct uterm_vt *vt, const char *vt_for_seat0) return ret; ret = ev_eloop_new_fd(vt->vtm->eloop, &vt->real_efd, vt->real_fd, - EV_READABLE, real_input, vt); + EV_READABLE, real_vt_input, vt); if (ret) goto err_fd; - /* - * Get the number of the VT which is active now, so we have something - * to switch back to in kmscon_vt_switch_leave. - */ + /* Get the number of the VT which is active now, so we have something + * to switch back to in kmscon_vt_switch_leave. */ ret = ioctl(vt->real_fd, VT_GETSTATE, &vts); if (ret) { - log_warn("cannot find the currently active VT"); - vt->real_saved_num = -1; - } else { - vt->real_saved_num = vts.v_active; + log_warn("cannot find the currently active VT (%d): %m", errno); + ret = -EFAULT; + goto err_eloop; } + vt->real_saved_num = vts.v_active; if (tcgetattr(vt->real_fd, &vt->real_saved_attribs) < 0) { - log_err("cannot get terminal attributes"); + log_err("cannot get terminal attributes (%d): %m", errno); ret = -EFAULT; goto err_eloop; } @@ -260,10 +302,10 @@ static int real_open(struct uterm_vt *vt, const char *vt_for_seat0) raw_attribs.c_oflag |= OPOST | OCRNL; if (tcsetattr(vt->real_fd, TCSANOW, &raw_attribs) < 0) - log_warn("cannot put terminal into raw mode"); + log_warn("cannot put terminal into raw mode (%d): %m", errno); if (ioctl(vt->real_fd, KDSETMODE, KD_GRAPHICS)) { - log_err("vt: cannot set graphics mode"); + log_err("cannot put VT in graphics mode (%d): %m", errno); ret = -errno; goto err_reset; } @@ -274,7 +316,7 @@ static int real_open(struct uterm_vt *vt, const char *vt_for_seat0) mode.relsig = SIGUSR2; if (ioctl(vt->real_fd, VT_SETMODE, &mode)) { - log_err("cannot take control of vt handling"); + log_err("cannot take control of vt handling (%d): %m", errno); ret = -errno; goto err_text; } @@ -282,14 +324,22 @@ static int real_open(struct uterm_vt *vt, const char *vt_for_seat0) sigemptyset(&mask); sigaddset(&mask, SIGUSR1); sigaddset(&mask, SIGUSR2); - sigprocmask(SIG_BLOCK, &mask, NULL); + ret = sigprocmask(SIG_BLOCK, &mask, NULL); + if (ret) + log_warning("cannot ignore SIGUSR1/2 (%d): %m", errno); return 0; err_text: - ioctl(vt->real_fd, KDSETMODE, KD_TEXT); + ret = ioctl(vt->real_fd, KDSETMODE, KD_TEXT); + if (ret) + log_warning("cannot reset VT %d to text-mode (%d): %m", + vt->real_num, errno); err_reset: - tcsetattr(vt->real_fd, TCSANOW, &vt->real_saved_attribs); + ret = tcsetattr(vt->real_fd, TCSANOW, &vt->real_saved_attribs); + if (ret) + log_warning("cannot reset VT %d attributes (%d): %m", + vt->real_num, errno); err_eloop: ev_eloop_rm_fd(vt->real_efd); vt->real_efd = NULL; @@ -301,15 +351,27 @@ err_fd: static void real_close(struct uterm_vt *vt) { struct vt_mode mode; + int ret; - log_debug("closing vt %p", vt); + log_debug("closing VT %d", vt->real_num); memset(&mode, 0, sizeof(mode)); mode.mode = VT_AUTO; - ioctl(vt->real_fd, VT_SETMODE, &mode); + ret = ioctl(vt->real_fd, VT_SETMODE, &mode); + if (ret) + log_warning("cannot reset VT %d to VT_AUTO mode (%d): %m", + vt->real_num, errno); + + ret = ioctl(vt->real_fd, KDSETMODE, KD_TEXT); + if (ret) + log_warning("cannot reset VT %d to text-mode (%d): %m", + vt->real_num, errno); + + ret = tcsetattr(vt->real_fd, TCSANOW, &vt->real_saved_attribs); + if (ret) + log_warning("cannot reset VT %d attributes (%d): %m", + vt->real_num, errno); - ioctl(vt->real_fd, KDSETMODE, KD_TEXT); - tcsetattr(vt->real_fd, TCSANOW, &vt->real_saved_attribs); ev_eloop_rm_fd(vt->real_efd); vt->real_efd = NULL; close(vt->real_fd); @@ -329,25 +391,23 @@ static int real_activate(struct uterm_vt *vt) int ret; struct vt_stat vts; - if (vt->real_num < 0) - return -EINVAL; - ret = ioctl(vt->real_fd, VT_GETSTATE, &vts); - if (ret) { - log_warn("cannot find current VT"); - return -EFAULT; - } - - if (vts.v_active == vt->real_num) + if (ret) + log_warn("cannot find current VT (%d): %m", errno); + else if (vts.v_active == vt->real_num) return 0; + if (vt->active) + log_warning("activating VT %d even though it's already active", + vt->real_num); + ret = ioctl(vt->real_fd, VT_ACTIVATE, vt->real_num); if (ret) { - log_warn("cannot enter VT %p", vt); + log_warn("cannot enter VT %d (%d): %m", vt->real_num, errno); return -EFAULT; } - log_debug("entering VT %p on demand", vt); + log_debug("entering VT %d on demand", vt->real_num); return -EINPROGRESS; } @@ -360,31 +420,38 @@ static int real_activate(struct uterm_vt *vt) * * Returns 0 if the previous VT is already active. * Returns -EINPROGRESS if we started the VT switch. Returns <0 on failure. + * + * When run as a daemon, the VT where we were started on is often no longer a + * safe return-path when we shut-down. Therefore, you might want to avoid + * calling this when started as a long-running daemon. */ static int real_deactivate(struct uterm_vt *vt) { int ret; struct vt_stat vts; - if (vt->real_saved_num < 0) - return -EINVAL; - ret = ioctl(vt->real_fd, VT_GETSTATE, &vts); if (ret) { - log_warn("cannot find current VT"); + log_warn("cannot find current VT (%d): %m", errno); return -EFAULT; } if (vts.v_active != vt->real_num) return 0; + if (!vt->active) + log_warning("deactivating VT %d even though it's not active", + vt->real_num); + ret = ioctl(vt->real_fd, VT_ACTIVATE, vt->real_saved_num); if (ret) { - log_warn("cannot leave VT %p", vt); + log_warn("cannot leave VT %d to VT %d (%d): %m", vt->real_num, + vt->real_saved_num, errno); return -EFAULT; } - log_debug("leaving VT %p on demand", vt); + log_debug("leaving VT %d on demand to VT %d", vt->real_num, + vt->real_saved_num); return -EINPROGRESS; } @@ -400,7 +467,7 @@ static int real_deactivate(struct uterm_vt *vt) * TODO: Replace this with a proper multi-seat-capable fake-VT mechanism. */ -static void fake_enter(struct uterm_vt *vt, struct signalfd_siginfo *info) +static void fake_sig_enter(struct uterm_vt *vt, struct signalfd_siginfo *info) { if (info->ssi_code != SI_USER) return; @@ -409,7 +476,7 @@ static void fake_enter(struct uterm_vt *vt, struct signalfd_siginfo *info) vt_call(vt, UTERM_VT_ACTIVATE); } -static void fake_leave(struct uterm_vt *vt, struct signalfd_siginfo *info) +static void fake_sig_leave(struct uterm_vt *vt, struct signalfd_siginfo *info) { if (info->ssi_code != SI_USER) return; @@ -432,14 +499,6 @@ static int fake_deactivate(struct uterm_vt *vt) return 0; } -static bool check_vt_support(void) -{ - if (!access("/dev/tty0", F_OK)) - return true; - else - return false; -} - static void vt_input(struct uterm_input *input, struct uterm_input_event *ev, void *data) @@ -465,9 +524,9 @@ static void vt_sigusr1(struct ev_eloop *eloop, struct signalfd_siginfo *info, struct uterm_vt *vt = data; if (vt->mode == UTERM_VT_REAL) - real_enter(vt, info); + real_sig_enter(vt, info); else if (vt->mode == UTERM_VT_FAKE) - fake_enter(vt, info); + fake_sig_enter(vt, info); } static void vt_sigusr2(struct ev_eloop *eloop, struct signalfd_siginfo *info, @@ -476,9 +535,9 @@ static void vt_sigusr2(struct ev_eloop *eloop, struct signalfd_siginfo *info, struct uterm_vt *vt = data; if (vt->mode == UTERM_VT_REAL) - real_leave(vt, info); + real_sig_leave(vt, info); else if (vt->mode == UTERM_VT_FAKE) - fake_leave(vt, info); + fake_sig_leave(vt, info); } int uterm_vt_allocate(struct uterm_vt_master *vtm, @@ -550,19 +609,14 @@ err_free: void uterm_vt_deallocate(struct uterm_vt *vt) { - unsigned int mode; - - if (!vt || !vt->vtm || vt->mode == UTERM_VT_DEAD) + if (!vt || !vt->vtm) return; - mode = vt->mode; - vt->mode = UTERM_VT_DEAD; - - if (mode == UTERM_VT_REAL) { + if (vt->mode == UTERM_VT_REAL) real_close(vt); - } else if (mode == UTERM_VT_FAKE) { + else if (vt->mode == UTERM_VT_FAKE) vt_call(vt, UTERM_VT_DEACTIVATE); - } + ev_eloop_unregister_signal_cb(vt->vtm->eloop, SIGUSR2, vt_sigusr2, vt); ev_eloop_unregister_signal_cb(vt->vtm->eloop, SIGUSR1, vt_sigusr1, vt); shl_dlist_unlink(&vt->list); @@ -626,7 +680,7 @@ int uterm_vt_master_new(struct uterm_vt_master **out, vtm->ref = 1; vtm->eloop = eloop; shl_dlist_init(&vtm->vts); - vtm->vt_support = check_vt_support(); + vtm->vt_support = !access("/dev/tty0", F_OK); ev_eloop_ref(vtm->eloop); *out = vtm; @@ -641,6 +695,8 @@ void uterm_vt_master_ref(struct uterm_vt_master *vtm) ++vtm->ref; } +/* Drops a reference to the VT-master. If the reference drops to 0, all + * allocated VTs are deallocated and the VT-master is destroyed. */ void uterm_vt_master_unref(struct uterm_vt_master *vtm) { struct uterm_vt *vt; @@ -659,6 +715,9 @@ void uterm_vt_master_unref(struct uterm_vt_master *vtm) free(vtm); } +/* Calls uterm_vt_activate() on all allocated VTs on this master. Returns + * number of VTs that returned -EINPROGRESS or a negative error code on failure. + * See uterm_vt_activate() for information. */ int uterm_vt_master_activate_all(struct uterm_vt_master *vtm) { struct uterm_vt *vt; @@ -684,6 +743,9 @@ int uterm_vt_master_activate_all(struct uterm_vt_master *vtm) return res; } +/* Calls uterm_vt_deactivate() on all allocated VTs on this master. Returns + * number of VTs that returned -EINPROGRESS or a negative error code on failure. + * See uterm_vt_deactivate() for information. */ int uterm_vt_master_deactivate_all(struct uterm_vt_master *vtm) { struct uterm_vt *vt;