agent-smith

XenStore Messages from Controller not being executed on

Bug #625069 reported by Antony Messerli on 2010-08-27

This bug affects 1 person

Affects		Status	Importance	Assigned to	Milestone
	agent-smith	Fix Committed	Undecided	Unassigned

Bug Description

XenStore Messages sent from the Controller are not being executed on. Output from /var/log/syslog:

Aug 27 03:00:02 firefly agent-smith: agent.c:121: Starting Agent Smith
Aug 27 03:00:02 firefly agent-smith: xen.c:101: Starting to watch data/host
Aug 27 03:00:02 firefly agent-smith: xen.c:161: vec[XS_WATCH_PATH]: data/host
Aug 27 03:00:02 firefly agent-smith: spool.c:198: Failed to open /var/spool/agent/outgoing/host: File exists
Aug 27 03:00:10 firefly agent-smith: agent.c:121: Starting Agent Smith
Aug 27 03:00:10 firefly agent-smith: xen.c:101: Starting to watch data/host
Aug 27 03:00:10 firefly agent-smith: xen.c:161: vec[XS_WATCH_PATH]: data/host
Aug 27 03:00:10 firefly agent-smith: spool.c:198: Failed to open /var/spool/agent/outgoing/host: File exists
Aug 27 03:00:34 firefly agent-smith: xen.c:161: vec[XS_WATCH_PATH]: data/host/be65cb66-02ab-102e-bbd2-0050568d2864
Aug 27 03:01:38 firefly agent-smith: xen.c:161: vec[XS_WATCH_PATH]: data/host/be65cb66-02ab-102e-bbd2-0050568d2864
Aug 27 03:01:38 firefly agent-smith: spool.c:198: Failed to open /var/spool/agent/outgoing/be65cb66-02ab-102e-bbd2-0050568d2864: File exists
Aug 27 03:02:15 firefly agent-smith: xen.c:161: vec[XS_WATCH_PATH]: data/host/37f85522-02af-102e-bbd2-0050568d2864
Aug 27 03:02:43 firefly agent-smith: xen.c:161: vec[XS_WATCH_PATH]: data/host/be65cb66-02ab-102e-bbd2-0050568d2864
Aug 27 03:02:43 firefly agent-smith: spool.c:198: Failed to open /var/spool/agent/outgoing/be65cb66-02ab-102e-bbd2-0050568d2864: File exists
Aug 27 03:03:32 firefly agent-smith: xen.c:161: vec[XS_WATCH_PATH]: data/host/37f85522-02af-102e-bbd2-0050568d2864
Aug 27 03:03:32 firefly agent-smith: spool.c:198: Failed to open /var/spool/agent/outgoing/37f85522-02af-102e-bbd2-0050568d2864: File exists
Aug 27 03:03:53 firefly agent-smith: xen.c:161: vec[XS_WATCH_PATH]: data/host/be65cb66-02ab-102e-bbd2-0050568d2864
Aug 27 03:03:53 firefly agent-smith: spool.c:198: Failed to open /var/spool/agent/outgoing/be65cb66-02ab-102e-bbd2-0050568d2864: File exists
Aug 27 03:03:53 firefly agent-smith: xen.c:161: vec[XS_WATCH_PATH]: data/host/7457e73a-02af-102e-bbd2-0050568d2864
Aug 27 03:04:31 firefly agent-smith: xen.c:161: vec[XS_WATCH_PATH]: data/host/887e740e-02af-102e-bbd2-0050568d2864
Aug 27 03:04:48 firefly agent-smith: xen.c:161: vec[XS_WATCH_PATH]: data/host/37f85522-02af-102e-bbd2-0050568d2864
Aug 27 03:04:48 firefly agent-smith: spool.c:198: Failed to open /var/spool/agent/outgoing/37f85522-02af-102e-bbd2-0050568d2864: File exists
Aug 27 03:05:13 firefly agent-smith: xen.c:161: vec[XS_WATCH_PATH]: data/host/be65cb66-02ab-102e-bbd2-0050568d2864
Aug 27 03:05:13 firefly agent-smith: spool.c:198: Failed to open /var/spool/agent/outgoing/be65cb66-02ab-102e-bbd2-0050568d2864: File exists
Aug 27 03:05:21 firefly agent-smith: xen.c:161: vec[XS_WATCH_PATH]: data/host/7457e73a-02af-102e-bbd2-0050568d2864
Aug 27 03:05:21 firefly agent-smith: spool.c:198: Failed to open /var/spool/agent/outgoing/7457e73a-02af-102e-bbd2-0050568d2864: File exists
Aug 27 03:06:02 firefly agent-smith: xen.c:161: vec[XS_WATCH_PATH]: data/host/887e740e-02af-102e-bbd2-0050568d2864
Aug 27 03:06:02 firefly agent-smith: spool.c:198: Failed to open /var/spool/agent/outgoing/887e740e-02af-102e-bbd2-0050568d2864: File exists
Aug 27 03:06:11 firefly agent-smith: xen.c:161: vec[XS_WATCH_PATH]: data/host/37f85522-02af-102e-bbd2-0050568d2864
Aug 27 03:06:11 firefly agent-smith: spool.c:198: Failed to open /var/spool/agent/outgoing/37f85522-02af-102e-bbd2-0050568d2864: File exists
Aug 27 03:06:36 firefly agent-smith: xen.c:161: vec[XS_WATCH_PATH]: data/host/be65cb66-02ab-102e-bbd2-0050568d2864
Aug 27 03:06:36 firefly agent-smith: spool.c:198: Failed to open /var/spool/agent/outgoing/be65cb66-02ab-102e-bbd2-0050568d2864: File exists
Aug 27 03:06:44 firefly agent-smith: xen.c:161: vec[XS_WATCH_PATH]: data/host/7457e73a-02af-102e-bbd2-0050568d2864
Aug 27 03:06:44 firefly agent-smith: spool.c:198: Failed to open /var/spool/agent/outgoing/7457e73a-02af-102e-bbd2-0050568d2864: File exists
Aug 27 03:07:25 firefly agent-smith: xen.c:161: vec[XS_WATCH_PATH]: data/host/887e740e-02af-102e-bbd2-0050568d2864
Aug 27 03:07:25 firefly agent-smith: spool.c:198: Failed to open /var/spool/agent/outgoing/887e740e-02af-102e-bbd2-0050568d2864: File exists
Aug 27 03:07:34 firefly agent-smith: xen.c:161: vec[XS_WATCH_PATH]: data/host/37f85522-02af-102e-bbd2-0050568d2864
Aug 27 03:07:34 firefly agent-smith: spool.c:198: Failed to open /var/spool/agent/outgoing/37f85522-02af-102e-bbd2-0050568d2864: File exists
Aug 27 03:07:59 firefly agent-smith: xen.c:161: vec[XS_WATCH_PATH]: data/host/be65cb66-02ab-102e-bbd2-0050568d2864
Aug 27 03:07:59 firefly agent-smith: spool.c:198: Failed to open /var/spool/agent/outgoing/be65cb66-02ab-102e-bbd2-0050568d2864: File exists
Aug 27 03:08:07 firefly agent-smith: xen.c:161: vec[XS_WATCH_PATH]: data/host/7457e73a-02af-102e-bbd2-0050568d2864
Aug 27 03:08:07 firefly agent-smith: spool.c:198: Failed to open /var/spool/agent/outgoing/7457e73a-02af-102e-bbd2-0050568d2864: File exists
Aug 27 03:08:48 firefly agent-smith: xen.c:161: vec[XS_WATCH_PATH]: data/host/887e740e-02af-102e-bbd2-0050568d2864
Aug 27 03:08:48 firefly agent-smith: spool.c:198: Failed to open /var/spool/agent/outgoing/887e740e-02af-102e-bbd2-0050568d2864: File exists
Aug 27 03:08:57 firefly agent-smith: xen.c:161: vec[XS_WATCH_PATH]: data/host/37f85522-02af-102e-bbd2-0050568d2864
Aug 27 03:08:57 firefly agent-smith: spool.c:198: Failed to open /var/spool/agent/outgoing/37f85522-02af-102e-bbd2-0050568d2864: File exists
Aug 27 03:09:21 firefly agent-smith: xen.c:161: vec[XS_WATCH_PATH]: data/host/be65cb66-02ab-102e-bbd2-0050568d2864
Aug 27 03:09:21 firefly agent-smith: spool.c:198: Failed to open /var/spool/agent/outgoing/be65cb66-02ab-102e-bbd2-0050568d2864: File exists
Aug 27 03:09:30 firefly agent-smith: xen.c:161: vec[XS_WATCH_PATH]: data/host/7457e73a-02af-102e-bbd2-0050568d2864
Aug 27 03:09:30 firefly agent-smith: spool.c:198: Failed to open /var/spool/agent/outgoing/7457e73a-02af-102e-bbd2-0050568d2

Revision history for this message

Antony Messerli (antonym) wrote on 2010-08-30:

More debugging:

Strace of process when sending a password reset:

firefly:/usr/share/agent-smith# strace -p 24317
Process 24317 attached - interrupt to quit
restart_syscall(<... resuming interrupted call ...>) = 1
read(5, "d", 1) = 1
time([1283208534]) = 1283208534
sendto(3, "<26>Aug 30 22:48:54 agent-smith:"..., 110, MSG_NOSIGNAL, NULL, 0) = 110
rt_sigaction(SIGPIPE, {SIG_IGN, [], SA_RESTORER, 0x7f8ee7e171f0}, {0x402c00, [], SA_RESTORER, 0x7f8ee7e171f0}, 8) = 0
write(4, "\6\0\0\0\0\0\0\0\0\0\0\0\1\0\0\0", 16) = 16
write(4, "\0", 1) = 1
futex(0x607414, FUTEX_WAIT_PRIVATE, 15, NULL) = 0
futex(0x6073e8, FUTEX_WAKE_PRIVATE, 1) = 0
rt_sigaction(SIGPIPE, {0x402c00, [], SA_RESTORER, 0x7f8ee7e171f0}, NULL, 8) = 0
rt_sigaction(SIGPIPE, {SIG_IGN, [], SA_RESTORER, 0x7f8ee7e171f0}, {0x402c00, [], SA_RESTORER, 0x7f8ee7e171f0}, 8) = 0
write(4, "\2\0\0\0\0\0\0\0\333\4\0\0/\0\0\0", 16) = 16
write(4, "data/host/7c7dd0d8-05b0-102e-bbd"..., 47) = 47
futex(0x607414, FUTEX_WAIT_PRIVATE, 17, NULL) = 0
futex(0x6073e8, FUTEX_WAKE_PRIVATE, 1) = 0
rt_sigaction(SIGPIPE, {0x402c00, [], SA_RESTORER, 0x7f8ee7e171f0}, NULL, 8) = 0
rt_sigaction(SIGPIPE, {SIG_IGN, [], SA_RESTORER, 0x7f8ee7e171f0}, {0x402c00, [], SA_RESTORER, 0x7f8ee7e171f0}, 8) = 0
write(4, "\7\0\0\0\0\0\0\0\333\4\0\0\2\0\0\0", 16) = 16
write(4, "T\0", 2) = 2
futex(0x607414, FUTEX_WAIT_PRIVATE, 19, NULL) = 0
futex(0x6073e8, FUTEX_WAKE_PRIVATE, 1) = 0
rt_sigaction(SIGPIPE, {0x402c00, [], SA_RESTORER, 0x7f8ee7e171f0}, NULL, 8) = 0
stat("/var/spool/agent/outgoing", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
stat("/var/spool/agent/outgoing", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
open("/var/spool/agent/outgoing/7c7dd0d8-05b0-102e-bbd2-0050568d2864", O_WRONLY|O_CREAT|O_EXCL|O_TRUNC, 0666) = 8
fstat(8, {st_mode=S_IFREG|0644, st_size=0, ...}) = 0
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f8ee8568000
write(8, "{\"name\":\"keyinit\",\"value\":\"97656"..., 36) = 36
close(8) = 0
munmap(0x7f8ee8568000, 4096) = 0
clone(child_stack=0, flags=CLONE_CHILD_CLEARTID|CLONE_CHILD_SETTID|SIGCHLD, child_tidptr=0x7f8ee85649d0) = 24886
--- SIGCHLD (Child exited) @ 0 (0) ---
wait4(-1, NULL, WNOHANG, NULL) = 24886
wait4(-1, NULL, WNOHANG, NULL) = -1 ECHILD (No child processes)
rt_sigreturn(0) = 24886
read(7, 0x60501c, 4112) = -1 EAGAIN (Resource temporarily unavailable)
poll([{fd=7, events=POLLIN}, {fd=5, events=POLLIN}], 2, -1^C <unfinished ...>

It appears the message is received and written but no actions occur on it.

More debugging:

Strace of process when sending a password reset:

firefly:/usr/share/agent-smith# strace -p 24317
Process 24317 attached - interrupt to quit
restart_syscall(<... resuming interrupted call ...>) = 1
read(5, "d", 1)                         = 1
time([1283208534])                      = 1283208534
sendto(3, "<26>Aug 30 22:48:54 agent-smith:"..., 110, MSG_NOSIGNAL, NULL, 0) = 110
rt_sigaction(SIGPIPE, {SIG_IGN, [], SA_RESTORER, 0x7f8ee7e171f0}, {0x402c00, [], SA_RESTORER, 0x7f8ee7e171f0}, 8) = 0
write(4, "\6\0\0\0\0\0\0\0\0\0\0\0\1\0\0\0", 16) = 16
write(4, "\0", 1)                       = 1
futex(0x607414, FUTEX_WAIT_PRIVATE, 15, NULL) = 0
futex(0x6073e8, FUTEX_WAKE_PRIVATE, 1)  = 0
rt_sigaction(SIGPIPE, {0x402c00, [], SA_RESTORER, 0x7f8ee7e171f0}, NULL, 8) = 0
rt_sigaction(SIGPIPE, {SIG_IGN, [], SA_RESTORER, 0x7f8ee7e171f0}, {0x402c00, [], SA_RESTORER, 0x7f8ee7e171f0}, 8) = 0
write(4, "\2\0\0\0\0\0\0\0\333\4\0\0/\0\0\0", 16) = 16
write(4, "data/host/7c7dd0d8-05b0-102e-bbd"..., 47) = 47
futex(0x607414, FUTEX_WAIT_PRIVATE, 17, NULL) = 0
futex(0x6073e8, FUTEX_WAKE_PRIVATE, 1)  = 0
rt_sigaction(SIGPIPE, {0x402c00, [], SA_RESTORER, 0x7f8ee7e171f0}, NULL, 8) = 0
rt_sigaction(SIGPIPE, {SIG_IGN, [], SA_RESTORER, 0x7f8ee7e171f0}, {0x402c00, [], SA_RESTORER, 0x7f8ee7e171f0}, 8) = 0
write(4, "\7\0\0\0\0\0\0\0\333\4\0\0\2\0\0\0", 16) = 16
write(4, "T\0", 2)                      = 2
futex(0x607414, FUTEX_WAIT_PRIVATE, 19, NULL) = 0
futex(0x6073e8, FUTEX_WAKE_PRIVATE, 1)  = 0
rt_sigaction(SIGPIPE, {0x402c00, [], SA_RESTORER, 0x7f8ee7e171f0}, NULL, 8) = 0
stat("/var/spool/agent/outgoing", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
stat("/var/spool/agent/outgoing", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
open("/var/spool/agent/outgoing/7c7dd0d8-05b0-102e-bbd2-0050568d2864", O_WRONLY|O_CREAT|O_EXCL|O_TRUNC, 0666) = 8
fstat(8, {st_mode=S_IFREG|0644, st_size=0, ...}) = 0
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f8ee8568000
write(8, "{\"name\":\"keyinit\",\"value\":\"97656"..., 36) = 36
close(8)                                = 0
munmap(0x7f8ee8568000, 4096)            = 0
clone(child_stack=0, flags=CLONE_CHILD_CLEARTID|CLONE_CHILD_SETTID|SIGCHLD, child_tidptr=0x7f8ee85649d0) = 24886
--- SIGCHLD (Child exited) @ 0 (0) ---
wait4(-1, NULL, WNOHANG, NULL)          = 24886
wait4(-1, NULL, WNOHANG, NULL)          = -1 ECHILD (No child processes)
rt_sigreturn(0)                         = 24886
read(7, 0x60501c, 4112)                 = -1 EAGAIN (Resource temporarily unavailable)
poll([{fd=7, events=POLLIN}, {fd=5, events=POLLIN}], 2, -1^C <unfinished ...>

It appears the message is received and written but no actions occur on it.

Revision history for this message

Christopher MacGown (0x44) wrote on 2010-08-31:

This is because the reset password action scripts aren't in trunk.

Revision history for this message

Christopher MacGown (0x44) wrote on 2010-08-31:

These action scripts are now in trunk, change if it still doesn't work.

Changed in agent-smith:
status:	New → Invalid

Revision history for this message

Christopher MacGown (0x44) wrote on 2010-09-01:

Reopening as other actions were failing.

Changed in agent-smith:
status:	Invalid → Confirmed

Christopher MacGown (0x44) on 2010-09-14

Changed in agent-smith:
status:	Confirmed → Fix Committed

Report a bug

This report contains Public information

Everyone can see this information.

You are

Subscribing...

Edit bug mail

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.