OK, what happened here may be that the sudo prompt was accepted but on the *second* try (it would seem). This causes a desynchronization of messages because they get queued in a fifo. So:
- checkbox launches the backend and sends it a "ping".
- Backend does not start. After 30 seconds checkbox retries.
- checkbox launches the backend again and sends it a 'ping'.
- Backend launches, receives the first "ping" and sends back a "pong".
- checkbox receives the "pong" and continues the testing process, thinking it has a working backend.
- Backend notices the second "ping" and sends back a "pong" which stays in the pipe awaiting to be read.
- Checkbox sends the backend a job message and reads the backend's response, expecting it to be the message's result.
- Turns out the response was the second "pong". Things fail horribly from now on because backend and frontend are now out of sync.
This is a known problem that needs to be fixed, perhaps by adding a sequence number to commands so the frontend knows to discard or otherwise handle out-of-sequence messages.
My evidence:
2011-11-03 14:31:54,938 DEBUG Backend responded, continuing execution.
So we know the backend was running (at some point at least).
2011-11-04 09:06:29,663 DEBUG Calling /usr/share/checkbox/plugins/backend_info.py BackendInfo.message_exec({'status': 'uninitiated', 'command': 'cdimage_resource', 'user': 'root', 'name': 'cdimage', 'plugin': 'resource'}) for message-exec with priority 0.
2011-11-04 09:06:29,664 DEBUG Started firing message-result.
2011-11-04 09:06:29,665 DEBUG Calling /usr/share/checkbox/plugins/message_info.py MessageInfo.message_result(p, o, n, g) for message-result with priority 0.
2011-11-04 09:06:29,668 ERROR Error running event handler /usr/share/checkbox/plugins/message_info.py MessageInfo.message_result(p, o, n, g) for event type 'message-result'
Traceback (most recent call last):
File "/usr/lib/python2.7/dist-packages/checkbox/reactor.py", line 74, in fire
results.append(handler(*args, **kwargs))
TypeError: message_result() takes exactly 4 arguments (5 given)
Notice the call to MessageInfo.message_result; the parameters spell "pong" :)
I'll set as Invalid for Ubuntu checkbox and Triaged/High for checkbox proper. It's the same code base after all, so no point on having two reports for the same thing.
OK, what happened here may be that the sudo prompt was accepted but on the *second* try (it would seem). This causes a desynchronization of messages because they get queued in a fifo. So:
- checkbox launches the backend and sends it a "ping".
- Backend does not start. After 30 seconds checkbox retries.
- checkbox launches the backend again and sends it a 'ping'.
- Backend launches, receives the first "ping" and sends back a "pong".
- checkbox receives the "pong" and continues the testing process, thinking it has a working backend.
- Backend notices the second "ping" and sends back a "pong" which stays in the pipe awaiting to be read.
- Checkbox sends the backend a job message and reads the backend's response, expecting it to be the message's result.
- Turns out the response was the second "pong". Things fail horribly from now on because backend and frontend are now out of sync.
This is a known problem that needs to be fixed, perhaps by adding a sequence number to commands so the frontend knows to discard or otherwise handle out-of-sequence messages.
My evidence:
2011-11-03 14:31:54,938 DEBUG Backend responded, continuing execution.
So we know the backend was running (at some point at least).
2011-11-04 09:06:29,663 DEBUG Calling /usr/share/ checkbox/ plugins/ backend_ info.py BackendInfo. message_ exec({' status' : 'uninitiated', 'command': 'cdimage_resource', 'user': 'root', 'name': 'cdimage', 'plugin': 'resource'}) for message-exec with priority 0. checkbox/ plugins/ message_ info.py MessageInfo. message_ result( p, o, n, g) for message-result with priority 0. checkbox/ plugins/ message_ info.py MessageInfo. message_ result( p, o, n, g) for event type 'message-result' python2. 7/dist- packages/ checkbox/ reactor. py", line 74, in fire append( handler( *args, **kwargs))
2011-11-04 09:06:29,664 DEBUG Started firing message-result.
2011-11-04 09:06:29,665 DEBUG Calling /usr/share/
2011-11-04 09:06:29,668 ERROR Error running event handler /usr/share/
Traceback (most recent call last):
File "/usr/lib/
results.
TypeError: message_result() takes exactly 4 arguments (5 given)
Notice the call to MessageInfo. message_ result; the parameters spell "pong" :)
I'll set as Invalid for Ubuntu checkbox and Triaged/High for checkbox proper. It's the same code base after all, so no point on having two reports for the same thing.