| Posted | Nick | Remark | |
|---|---|---|---|
| #openstack-nova - 2017-03-17 | |||
| 13:06:39 | mriedem | he's talking about volume swap | |
| 13:06:46 | edleafe | kashyap: the error is libvirtError: Requested operation is not valid: pivot of disk 'vdb' requires an active copy job | |
| 13:06:57 | kashyap | mriedem: Ah, a different issue | |
| 13:07:16 | edleafe | This is on a newer libvirt, using Mitaka with Matt's patches | |
| 13:07:17 | mdbooth | edleafe: That's an old one | |
| 13:07:35 | edleafe | mdbooth: I saw the bugzilla reports | |
| 13:07:48 | edleafe | mdbooth: their libvirt should have the fixes for that | |
| 13:08:04 | openstack | Launchpad bug 1673483 in OpenStack Compute (nova) "libvirt: test_attach_volume_shelved_or_offload_server times out waiting for device detach (which fails)" [Undecided,Confirmed] | |
| 13:08:04 | kashyap | mriedem: Meanwhile, for the Gate issue mdbooth was looking yesterday, please see the comment here when you get a moment -- https://bugs.launchpad.net/nova/+bug/1673483/comments/3 | |
| 13:08:13 | mdbooth | edleafe: The latest Nova should work with old libvirt on that one | |
| 13:08:22 | kashyap | mriedem: I also notified folks on #ubuntu-packaging IRC on Freenode -- so they can pull in the missing patch | |
| 13:08:45 | edleafe | mriedem: so would your patches make their code "the lates Nova"? | |
| 13:08:54 | edleafe | at least as far as this issue is concerned | |
| 13:09:01 | mdbooth | kashyap: Ubuntu have engineers? I thought they just had marketing. | |
| 13:09:14 | kashyap | mdbooth: :-) C'mon, don't be so mean | |
| 13:09:44 | kashyap | Credit where it's due: Serge Hallyn is a real machine | |
| 13:09:51 | mriedem | edleafe: i had backported to mitaka the fix i thought was related to this pivot issue that lyarwood worked on | |
| 13:10:10 | kashyap | mdbooth: He does most of the work. And once when I met him at a conference, and asked him how on earth is he handling it all | |
| 13:10:13 | edleafe | mriedem: yeah, that's what I thought | |
| 13:10:19 | kashyap | He said: "Yeah, my SO complains..." | |
| 13:10:23 | mriedem | edleafe: this https://review.openstack.org/#/c/433793/ | |
| 13:11:01 | kashyap | But that's just one person. I admittedly don't know any others | |
| 13:11:55 | kashyap | mriedem: Why did you abandon it? | |
| 13:13:05 | mdbooth | mriedem edleafe: Landed in Newton: | |
| 13:13:17 | mdbooth | https://review.openstack.org/#/c/427290/ | |
| 13:15:24 | mriedem | kashyap: mitaka | |
| 13:15:34 | mriedem | kashyap: it's not justified for mitaka at this point | |
| 13:15:37 | kashyap | Ah! | |
| 13:15:48 | kashyap | For a moment, lost track of release status | |
| 13:16:03 | kashyap | Says, it's "Legacy Release" phase https://releases.openstack.org/ | |
| 13:16:26 | kashyap | edleafe: That fix mriedem pointed out is what you're looking for. | |
| 13:17:08 | edleafe | kashyap: just checked their system, and they have those changes applied | |
| 13:17:55 | kashyap | edleafe: And they still see the same pivot failure? | |
| 13:18:35 | SzarkaAlex | @gibi Hi! Are you here? | |
| 13:20:11 | mdbooth | edleafe: Can you do me a favour. There's an edge case in that code that we knowingly glossed over, namely that we can't detect if the job fails. | |
| 13:21:19 | mdbooth | edleafe: Can you correlate the Nova log with the libvirt logs and look for a failure of the rebase job? | |
| 13:21:54 | edleafe | mdbooth: sec... | |
| 13:23:20 | edleafe | mdbooth: like this? http://paste.openstack.org/show/603131/ | |
| 13:23:38 | mdbooth | edleafe: That's the nova log. | |
| 13:23:47 | edleafe | ah | |
| 13:23:49 | mdbooth | Can you look in the libvirt log? | |
| 13:23:59 | mdbooth | /var/log/libvirt/whatever probably | |
| 13:24:36 | edleafe | looking... | |
| 13:24:55 | mdbooth | kashyap: 'requires an active copy job' | |
| 13:25:22 | mdbooth | Is that the same as the pivot-too-early problem? | |
| 13:25:43 | kashyap | mdbooth: Oh, I think vaguely recall, I think that edge case you discussed in one of the reviews... | |
| 13:25:57 | kashyap | mdbooth: Yes, it's the same problem | |
| 13:26:10 | kashyap | Wait, let me think again | |
| 13:26:29 | kashyap | mdbooth: No, I was wrong: | |
| 13:26:36 | mdbooth | _("disk '%s' not ready for pivot yet"), | |
| 13:26:46 | kashyap | Pivot too early implies that there _is_ an active block operation in progress | |
| 13:26:51 | mdbooth | disk->dst); | |
| 13:26:51 | mdbooth | _("disk '%s' not ready for pivot yet"), | |
| 13:26:51 | mdbooth | virReportError(VIR_ERR_BLOCK_COPY_ACTIVE, | |
| 13:26:51 | mdbooth | if (disk->mirrorState != VIR_DOMAIN_DISK_MIRROR_STATE_READY) { | |
| 13:26:53 | mdbooth | vs: | |
| 13:27:01 | mdbooth | _("pivot of disk '%s' requires an active copy job"), | |
| 13:27:01 | mdbooth | virReportError(VIR_ERR_OPERATION_INVALID, | |
| 13:27:01 | mdbooth | if (!disk->mirror) { | |
| 13:27:07 | mdbooth | I think there's no copy job at all | |
| 13:27:14 | kashyap | Requires an active job means: there's no block operation at all | |
| 13:27:19 | mdbooth | edleafe: Yeah, those libvirt logs would be really interesting | |
| 13:27:23 | kashyap | s/no/no _live_/ | |
| 13:29:16 | mdbooth | Incidentally, if the issue is that the job failed I think we *have* to switch to consuming events from libvirt. | |
| 13:29:21 | mdbooth | I think we're out of workarounds | |
| 13:29:33 | kashyap | edleafe: Those logs would be useful, assuming you had log filters enabled in /etc/libvirt/libvirtd.conf: | |
| 13:29:36 | kashyap | log_filters="1:libvirt 1:qemu 1:conf 1:security 3:event 3:json 3:file 3:object 1:util" | |
| 13:29:39 | kashyap | log_outputs="1:file:/var/log/libvirt/libvirtd.log" | |
| 13:30:09 | kashyap | (Restart libvirtd; repeat your test; _then_ post the log.) | |
| 13:31:06 | mdbooth | kashyap: Actually looking at that code in qemuDomainBlockPivot(), I think the Nova code is wrong when it does: | |
| 13:31:13 | mdbooth | if status is None: | |
| 13:31:14 | mdbooth | return True | |
| 13:31:32 | mdbooth | Looks like it should raise an exception at that point, as it will never succeed. | |
| 13:31:37 | edleafe | mdbooth: I see the log; it's 3GB, but its last entry is about 8 hours ago?!? | |
| 13:32:06 | mdbooth | edleafe: Did it get rolled somewhere? | |
| 13:32:34 | kashyap | Oh dear | |
| 13:32:43 | edleafe | mdbooth: kashyap: let me restart libvirt, verify that it's logging, repeat the test, and then I'll post the logs and re-ping you | |
| 13:32:47 | kashyap | edleafe: If possible to repeat the test | |
| 13:33:13 | kashyap | First, please take a backup of that 3G log, _if_ you need it, and then empty it out ($ > /var/log/libvirt/libvirt.log), so we can start from a clean slate. | |
| 13:33:18 | edleafe | mdbooth: it has a current timestamp, but last entry is 8 hours ago | |
| 13:33:21 | kashyap | Then, enable the log filters, repeat the test, etc. | |
| 13:33:35 | edleafe | kashyap: I was going to roll over the log, eyah | |
| 13:33:37 | edleafe | yeah | |
| 13:34:02 | edleafe | but first another pot of coffee is a higher priority :) | |
| 13:34:26 | kashyap | Go for it | |
| 13:34:59 | kashyap | mdbooth: Sigh, it's like a landmine. Not sure how your eyes don't bleed looking at that | |
| 13:41:48 | kashyap | mdbooth: And yeah, didn't miss your quote above, from qemuDomainBlockPivot() function, it is looking for the libvirt event READY to decide whether the job is ready for pivot or not... | |
| 13:42:11 | mdbooth | kashyap: But before that it'll raise a different error if the job doesn't exist | |
| 13:42:28 | mdbooth | Specifically the error that edleafe is seeing | |
| 13:42:54 | kashyap | mdbooth: You're referring to: | |
| 13:42:55 | kashyap | _("pivot of disk '%s' requires an active copy job"), | |
| 13:42:55 | kashyap | virReportError(VIR_ERR_OPERATION_INVALID, | |
| 13:42:55 | kashyap | if (!disk->mirror) { | |
| 13:42:58 | kashyap | disk->dst); | |
| 13:43:00 | mdbooth | Yes | |
| 13:43:01 | kashyap | ? | |
| 13:43:26 | openstackgerrit | Roman Dobosz proposed openstack/nova-specs master: Provide detailed error information for placement API https://review.openstack.org/418393 | |
| 13:44:57 | kashyap | mdbooth: In that case, either the job was already finished (maybe not gracefully); or it was not started. Hence, it whines "no block operation for me work on" | |
| 13:45:25 | kashyap | Let's wait for edleafe's logs (hopefully small, with that specific test) | |
| 13:45:30 | mdbooth | Either way, based on that code I belive the pivot will fail | |