ldm now reads the full output from ssh even if it dies on the way.
Proper error messages are logged and displayed, wrapped in _() so
they can be localized.
Messages we get:
* Permission denied (publickey,password).
The common case of a password typo or invalid user.
We make sure we read all the output BEFORE checking if the child has
died. Also, we handle EINTR, as this is what select() returns when it
gets SIGCHLD.
* ssh: connect to host server port 22: Connection timed out
For that to work, ConnectTimeout=10 is set on the ssh command line.
Otherwise the 30 second timeout elapses before ssh tells us what is
going on.
* ssh: connect to host server port 22: Connection refused
That message contains a ": " like the password prompt. This is solved
by waiting for 200ms of silence before searching for the prompt (polling
interval reduced from 1s to 200ms to not bore the user).
In the error case, ssh will have exited in the meantime, and we know
for sure that it was NOT a password prompt.
---
src/logging.c | 12 +++--
src/plugins/ssh/ssh.c | 124 +++++++++++++++++++++++++++++++++++---------------
2 files changed, 95 insertions(+), 41 deletions(-)
diff --git a/src/logging.c b/src/logging.c
index 63389dd..d93ff39 100644
--- a/src/logging.c
+++ b/src/logging.c
@@ -29,10 +29,14 @@
#include "logging.h"
FILE *logfile = NULL;
-char *LOG_LEVEL_NAMES[] = { "EMERGENCY", "ALERT", "CRITICAL", "ERROR",
- "WARNING", "NOTICE", "INFO", "DEBUG"
-};
-
+char *LOG_LEVEL_NAMES[] = { "EMERGENCY", /* 0 */
+ "ALERT", /* 1 */
+ "CRITICAL", /* 2 */
+ "ERROR", /* 3 */
+ "WARNING", /* 4 */
+ "NOTICE", /* 5 */
+ "INFO", /* 6 */
+ "DEBUG" }; /* 7 */
int loglevel = 0;
/*
diff --git a/src/plugins/ssh/ssh.c b/src/plugins/ssh/ssh.c
index 0110937..689ec43 100644
--- a/src/plugins/ssh/ssh.c
+++ b/src/plugins/ssh/ssh.c
@@ -16,6 +16,7 @@
#include <sys/ioctl.h>
#include <sys/stat.h>
#include <utmp.h>
+#include <errno.h>
#include <crypt.h>
#include "../../ldm.h"
@@ -289,7 +290,7 @@ expect(int fd, char *p, int seconds, ...)
char buffer[BUFSIZ];
gchar *arg;
GPtrArray *expects;
- int loopcount = seconds;
+ int loopcount = seconds * 5;
int loopend = 0;
bzero(p, MAXEXP);
@@ -313,58 +314,87 @@ expect(int fd, char *p, int seconds, ...)
* Main loop.
*/
+ log_entry("ssh",7,"expect: entering main loop");
+
while (1) {
- timeout.tv_sec = (long) 1; /* one second timeout */
- timeout.tv_usec = 0;
+ timeout.tv_sec = 0;
+ timeout.tv_usec = 200000; /* 200ms timeout */
FD_ZERO(&set);
FD_SET(fd, &set);
st = select(FD_SETSIZE, &set, NULL, NULL, &timeout);
- if (child_exited) {
- break; /* someone died on us */
- }
-
- if (st < 0) { /* bad thing */
- break;
- }
-
- if (loopcount == 0) {
- break;
- }
+ log_entry("ssh", 7, "expect: select returned %d", st);
- if (!st) { /* timeout */
- loopcount--; /* We've not seen the data we want */
- continue;
- }
+ /* There is data available - we want to read it in even if
+ * the child process has exited - we want to get the error
+ * message
+ */
+ if (st > 0)
+ {
+ size = read(fd, buffer, sizeof buffer);
+ if (size == -1) {
+ log_entry("ssh", 3, "expect: read returned error %d (%s)", errno, strerror(errno));
+ break;
+ }
+ if (size == 0) {
+ log_entry("ssh", 3, "expect: read returned 0 (EOF))");
+ break;
+ }
- size = read(fd, buffer, sizeof buffer);
- if (size <= 0) {
- break;
+ if ((total + size) < MAXEXP) {
+ strncpy(p + total, buffer, size);
+ total += size;
+ log_entry("ssh", 7, "expect: got %d bytes so far", total);
+ }
+ else
+ {
+ log_entry("ssh", 3, "expect: buffer full");
+ return ERROR;
+ }
}
+ else /* No data available */
+ {
+ /* select() was interrupted by a signal,
+ * most likely SIGCHLD. Just try again */
+ if (st == -1 && errno == EINTR)
+ {
+ log_entry("ssh", 7, "expect: retrying");
+ continue;
+ }
+ else if (st == -1) { /* other errors */
+ log_entry("ssh", 3, "expect: select returned error %d (%s)", errno, strerror(errno));
+ break;
+ }
+ /* st == 0 and there was no data for 200ms */
- if ((total + size) < MAXEXP) {
- strncpy(p + total, buffer, size);
- total += size;
- }
+ if (child_exited) { /* someone died on us */
+ log_entry("ssh", 3, "expect: ssh process has died");
+ break;
+ }
- for (i = 0; i < expects->len; i++) {
- if (strstr(p, g_ptr_array_index(expects, i))) {
- loopend = TRUE;
+ if (loopcount == 0) {
+ log_entry("ssh", 3, "expect: timed out after %d seconds", seconds);
break;
}
- }
- if (loopend) {
- break;
+ for (i = 0; i < expects->len; i++) {
+ if (strstr(p, g_ptr_array_index(expects, i))) {
+ log_entry("ssh", 7, "expect: found string %d \"%s\"", i, g_ptr_array_index(expects, i));
+ loopend = TRUE;
+ break;
+ }
+ }
+
+ loopcount--; /* We've not seen the data we want */
}
- if (timeout.tv_sec == 0) {
+ if (loopend) {
break;
}
}
- log_entry("ldm", 7, "expect saw: %s", p);
+ log_entry("ssh", 7, "expect: saw: %s", p);
if (size < 0 || st < 0 || child_exited) {
return ERROR; /* error occured */
@@ -380,6 +410,7 @@ void
ssh_chat(gint fd)
{
int seen;
+ size_t len;
gchar lastseen[MAXEXP];
int first_time = 1;
@@ -407,20 +438,34 @@ ssh_chat(gint fd)
/* If it's not the first time through, or the :'s not at the
* end of a line (password expiry or error), set the message */
if ((!first_time) || (lastseen[i - 1] != ':')) {
+ log_entry("ssh", 4, "ssh_chat: ssh returned \"%d\"", lastseen);
set_message(lastseen);
}
/* If ':' *IS* the last character on the line, we'll assume a
* password prompt is presented, and get a password */
if (lastseen[i - 1] == ':') {
+ log_entry("ssh", 7, "ssh_chat: writing password");
write(fd, sshinfo->password, strlen(sshinfo->password));
write(fd, "\n", 1);
}
first_time = 0;
} else if (seen < 0) {
- set_message(_("No response from server, restarting..."));
+ log_entry("ssh", 3, "ssh_chat: expect returned error %d", seen);
+ g_strstrip(lastseen);
+ len = strlen(lastseen);
+ if (len > 0)
+ {
+ log_entry("ssh", 3, "ssh_chat: ssh returned \"%s\"", lastseen);
+ set_message(_(lastseen));
+ }
+ else
+ {
+ log_entry("ssh", 3, "ssh_chat: did not get an error message from ssh");
+ set_message(_("No response from server, restarting..."));
+ }
sleep(5);
close_greeter();
- die("ssh", "no response, restarting");
+ die("ssh","login failed, restarting");
}
}
}
@@ -454,12 +499,17 @@ ssh_session(void)
command = g_strjoin(" ", "ssh", "-Y", "-t", "-M",
"-S", sshinfo->ctl_socket,
"-o", "NumberOfPasswordPrompts=1",
+ /* ConnectTimeout should be less than the timeout ssh_chat
+ * passes to expect, so we get the error message from ssh
+ * before expect gives up
+ */
+ "-o", "ConnectTimeout=10",
"-l", sshinfo->username,
port ? port : "",
sshinfo->sshoptions ? sshinfo->sshoptions : "",
sshinfo->server,
"echo " SENTINEL "; exec /bin/sh -", NULL);
- log_entry("ssh", 7, "ssh_session: %s", command);
+ log_entry("ssh", 6, "ssh_session: %s", command);
sshinfo->sshpid = ldm_spawn(command, NULL, NULL, ssh_tty_init);
@@ -487,7 +537,7 @@ ssh_endsession(void)
command =
g_strjoin(" ", "ssh", "-S", sshinfo->ctl_socket, "-O", "exit",
sshinfo->server, NULL);
- log_entry("ssh", 7, "closing ssh session: %s"), command;
+ log_entry("ssh", 6, "closing ssh session: %s", command);
pid = ldm_spawn(command, NULL, NULL, NULL);
ldm_wait(pid);
close(sshinfo->sshfd);
--
1.9.3