Re: [one-users] Missing log when no error happens

[Daniel Dehennin]

"Ruben S. Montero"  writes:

> Hi Daniel,
>
> We'll consider the inclusion of this feature for 4.6
>
> http://dev.opennebula.org/issues/2566

Thanks a lot, I'm watching the issue, do not hesitate if you want some
clarifications/tests.

Regards.
-- 
Daniel Dehennin
Récupérer ma clef GPG:
gpg --keyserver pgp.mit.edu --recv-keys 0x7A6FE2DF


pgpEM9oBEQbau.pgp
Description: PGP signature
___
Users mailing list
Users@lists.opennebula.org
http://lists.opennebula.org/listinfo.cgi/users-opennebula.org

Re: [one-users] Missing log when no error happens

[Ruben S. Montero]

Hi Daniel,

We'll consider the inclusion of this feature for 4.6

http://dev.opennebula.org/issues/2566

Cheers


On Tue, Nov 5, 2013 at 11:26 AM, Daniel Dehennin <
daniel.dehen...@baby-gnu.org> wrote:

> "Ruben S. Montero"  writes:
>
> > So, your proposal is to have, all messages as in:
> >
> > [TM][I]: clone: Cloning
> > /var/lib/one/datastores/1/e72972d1dc14203d83520f9ae6395d94 in
> > yggdrasil:/var/lib/one//datastores/0/15/disk.1
> >
> > This is pre-pend with the "clone:" string, right? If this is the case,
> this
> > could be done in the core as:
> >
> >[TM][I]: << ERROR IN CLONE >
> >[TM][I]: Command execution fail: /var/lib/one/remotes/tm/qcow2/clone
> > yggdrasil:/var/lib/one/datastores/1/e72972d1dc14203d83520f9ae6395d94
> > yggdrasil:/var/lib/one//datastores/0/15/disk.1 15 1
> > [TM][I]: clone: Cloning
> > /var/lib/one/datastores/1/e72972d1dc14203d83520f9ae6395d94 in
> > yggdrasil:/var/lib/one//datastores/0/15/disk.1
> > ...
> >[TM][I]: << ERROR IN CLONE >
> >
> >
> > What do you think?
>
> I thought about wrapping all executed commands to log:
>
> - INFO: the description of the command, like
>   “Cloning /var/lib/one/datastores/1/e72972d1dc14203d83520f9ae6395d94
>in yggdrasil:/var/lib/one//datastores/0/15/disk.1”
>
> - DEBUG: the command to execute, like: “ssh@yggdrasil: ”
>
> This could output something like the following (line wrapped to ease
> reading):
>
> [TM][I]: Command: /var/lib/one/remotes/tm/qcow2/clone
>
>  yggdrasil:/var/lib/one/datastores/1/e72972d1dc14203d83520f9ae6395d94
>  yggdrasil:/var/lib/one//datastores/0/15/disk.1
>  15 1
> [TM][I]: clone: Cloning
> /var/lib/one/datastores/1/e72972d1dc14203d83520f9ae6395d94
>  in yggdrasil:/var/lib/one//datastores/0/15/disk.1
> [TM][D]: clone: ssh@yggdrasil "cd /var/lib/one/datastores/0/15;
>  qemu-img create -b
> /var/lib/one/datastores/1/e72972d1dc14203d83520f9ae6395d94
>  -f qcow2 /var/lib/one/datastores/0/15/disk.1"
> [TM][E]: << ERROR IN CLONE >
> [TM][E]: Command execution fail: "/var/lib/one/remotes/tm/qcow2/clone
>
>  yggdrasil:/var/lib/one/datastores/1/e72972d1dc14203d83520f9ae6395d94
>  yggdrasil:/var/lib/one//datastores/0/15/disk.1
>  15 1": qemu-img: Could not open
> '/var/lib/one/datastores/1/e72972d1dc14203d83520f9ae6395d94'
> [TM][E]: Error copying
> yggdrasil:/var/lib/one/datastores/1/e72972d1dc14203d83520f9ae6395d94
>  to yggdrasil:/var/lib/one//datastores/0/15/disk.1
> [TM][I]: ExitCode: 1
> [TM][E]: << ERROR IN CLONE >
>
> So, we can follow the execution path until the error:
>
> 1. the “qcow2 clone” is called with specified arguments
> 2. the “clone” script informs what it does
> 3. in debug mode[1] we see the command that will be executed: an SSH to
>yggdrasil running “cd” and “qemu-img”
> 4. an error occurs and we see the command and it's output
>
> Actually, the point 4 is already OK for me, but 1 to 3 are missing.
>
> The point 2 is already done by the script[2] but is not present in the
> logs and I don't know why.
>
> The point 3 can be done by common wrappers[3].
>
> The point 1 is from core, I think.
>
> This could be generalized as:
>
> 1. the core log state changes
> 2. for each step to setup a VM, the core log what need to be done, like
>“setting up network”, “setting up storage”, etc.
> 3. the core log which script it will call with its arguments
> 4. the script log informative messages of what it does
> 5. before a command is executed, a log of what will be executed and
>where
> 6. after the command is executed, log the result
>
> Looking at my log files, not everything is logged, mostly the “what ONE
> wants to/will do”.
>
> I hope it will help understand what I would like.
>
> Regards.
>
> Footnotes:
> [1]  or info I don't know what's the best
>
> [2]
> http://dev.opennebula.org/projects/opennebula/repository/revisions/release-4.2/entry/src/tm_mad/qcow2/clone#L69
>
> [3]
> http://dev.opennebula.org/projects/opennebula/repository/revisions/release-4.2/entry/src/mad/sh/scripts_common.sh
>
> --
> Daniel Dehennin
> Récupérer ma clef GPG:
> gpg --keyserver pgp.mit.edu --recv-keys 0x7A6FE2DF
>
> ___
> Users mailing list
> Users@lists.opennebula.org
> http://lists.opennebula.org/listinfo.cgi/users-opennebula.org
>
>


-- 
-- 
Ruben S. Montero, PhD
Project co-Lead and Chief Architect
OpenNebula - Flexible Enterprise Cloud Made Simple
www.OpenNebula.org | rsmont...@opennebula.org | @OpenNebula
___
Users mailing list
Users@lists.opennebula.org
http://lists.opennebula.org/listinfo.cgi/users-opennebula.org

Re: [one-users] Missing log when no error happens

[Daniel Dehennin]

"Ruben S. Montero"  writes:

> So, your proposal is to have, all messages as in:
>
> [TM][I]: clone: Cloning
> /var/lib/one/datastores/1/e72972d1dc14203d83520f9ae6395d94 in
> yggdrasil:/var/lib/one//datastores/0/15/disk.1
>
> This is pre-pend with the "clone:" string, right? If this is the case, this
> could be done in the core as:
>
>[TM][I]: << ERROR IN CLONE >
>[TM][I]: Command execution fail: /var/lib/one/remotes/tm/qcow2/clone
> yggdrasil:/var/lib/one/datastores/1/e72972d1dc14203d83520f9ae6395d94
> yggdrasil:/var/lib/one//datastores/0/15/disk.1 15 1
> [TM][I]: clone: Cloning
> /var/lib/one/datastores/1/e72972d1dc14203d83520f9ae6395d94 in
> yggdrasil:/var/lib/one//datastores/0/15/disk.1
> ...
>[TM][I]: << ERROR IN CLONE >
>
>
> What do you think?

I thought about wrapping all executed commands to log:

- INFO: the description of the command, like
  “Cloning /var/lib/one/datastores/1/e72972d1dc14203d83520f9ae6395d94
   in yggdrasil:/var/lib/one//datastores/0/15/disk.1”

- DEBUG: the command to execute, like: “ssh@yggdrasil: ”

This could output something like the following (line wrapped to ease reading):

[TM][I]: Command: /var/lib/one/remotes/tm/qcow2/clone
 
yggdrasil:/var/lib/one/datastores/1/e72972d1dc14203d83520f9ae6395d94
 yggdrasil:/var/lib/one//datastores/0/15/disk.1
 15 1
[TM][I]: clone: Cloning 
/var/lib/one/datastores/1/e72972d1dc14203d83520f9ae6395d94
 in yggdrasil:/var/lib/one//datastores/0/15/disk.1
[TM][D]: clone: ssh@yggdrasil "cd /var/lib/one/datastores/0/15; 
 qemu-img create -b 
/var/lib/one/datastores/1/e72972d1dc14203d83520f9ae6395d94 
 -f qcow2 /var/lib/one/datastores/0/15/disk.1"
[TM][E]: << ERROR IN CLONE >
[TM][E]: Command execution fail: "/var/lib/one/remotes/tm/qcow2/clone
 
yggdrasil:/var/lib/one/datastores/1/e72972d1dc14203d83520f9ae6395d94
 yggdrasil:/var/lib/one//datastores/0/15/disk.1
 15 1": qemu-img: Could not open 
'/var/lib/one/datastores/1/e72972d1dc14203d83520f9ae6395d94'
[TM][E]: Error copying 
yggdrasil:/var/lib/one/datastores/1/e72972d1dc14203d83520f9ae6395d94 
 to yggdrasil:/var/lib/one//datastores/0/15/disk.1
[TM][I]: ExitCode: 1
[TM][E]: << ERROR IN CLONE >

So, we can follow the execution path until the error:

1. the “qcow2 clone” is called with specified arguments
2. the “clone” script informs what it does
3. in debug mode[1] we see the command that will be executed: an SSH to
   yggdrasil running “cd” and “qemu-img”
4. an error occurs and we see the command and it's output

Actually, the point 4 is already OK for me, but 1 to 3 are missing.

The point 2 is already done by the script[2] but is not present in the
logs and I don't know why.

The point 3 can be done by common wrappers[3].

The point 1 is from core, I think.

This could be generalized as:

1. the core log state changes
2. for each step to setup a VM, the core log what need to be done, like
   “setting up network”, “setting up storage”, etc.
3. the core log which script it will call with its arguments
4. the script log informative messages of what it does
5. before a command is executed, a log of what will be executed and
   where
6. after the command is executed, log the result

Looking at my log files, not everything is logged, mostly the “what ONE wants 
to/will do”.

I hope it will help understand what I would like.

Regards.

Footnotes: 
[1]  or info I don't know what's the best

[2]  
http://dev.opennebula.org/projects/opennebula/repository/revisions/release-4.2/entry/src/tm_mad/qcow2/clone#L69

[3]  
http://dev.opennebula.org/projects/opennebula/repository/revisions/release-4.2/entry/src/mad/sh/scripts_common.sh

-- 
Daniel Dehennin
Récupérer ma clef GPG:
gpg --keyserver pgp.mit.edu --recv-keys 0x7A6FE2DF


pgpxzNFDu5fMe.pgp
Description: PGP signature
___
Users mailing list
Users@lists.opennebula.org
http://lists.opennebula.org/listinfo.cgi/users-opennebula.org

Re: [one-users] Missing log when no error happens

[Ruben S. Montero]

So, your proposal is to have, all messages as in:

[TM][I]: clone: Cloning
/var/lib/one/datastores/1/e72972d1dc14203d83520f9ae6395d94 in
yggdrasil:/var/lib/one//datastores/0/15/disk.1

This is pre-pend with the "clone:" string, right? If this is the case, this
could be done in the core as:

   [TM][I]: << ERROR IN CLONE >
   [TM][I]: Command execution fail: /var/lib/one/remotes/tm/qcow2/clone
yggdrasil:/var/lib/one/datastores/1/e72972d1dc14203d83520f9ae6395d94
yggdrasil:/var/lib/one//datastores/0/15/disk.1 15 1
[TM][I]: clone: Cloning
/var/lib/one/datastores/1/e72972d1dc14203d83520f9ae6395d94 in
yggdrasil:/var/lib/one//datastores/0/15/disk.1
...
   [TM][I]: << ERROR IN CLONE >


What do you think?

Ruben

On Wed, Oct 30, 2013 at 9:31 PM, Daniel Dehennin <
daniel.dehen...@baby-gnu.org> wrote:

> Hello,
>
> I made some search without success, I'm asking here before creating any
> redmine issue.
>
> Using OpenNebula 4.2, I just see that there is no TM log on successful
> VMs setup:
>
> oneadmin@yggdrasil:~$ cut -d' ' -f6- /var/log/one/16.log
> [DiM][I]: New VM state is ACTIVE.
> [LCM][I]: New VM state is PROLOG.
> [LCM][I]: New VM state is BOOT
> [VMM][I]: Generating deployment file: /var/lib/one/vms/16/deployment.0
> [VMM][I]: ExitCode: 0
> [VMM][I]: Successfully execute network driver operation: pre.
> [VMM][I]: ExitCode: 0
> [VMM][I]: Successfully execute virtualization driver operation: deploy.
> [VMM][I]: post: Executed "sudo /usr/bin/ovs-vsctl set Port vnet0
> tag=20".
> [VMM][I]: post: Executed "sudo /usr/bin/ovs-ofctl add-flow baby-gnu
> in_port=5,dl_src=02:00:0a:02:00:00,priority=4,actions=normal".
> [VMM][I]: post: Executed "sudo /usr/bin/ovs-ofctl add-flow baby-gnu
> in_port=5,priority=39000,actions=drop".
> [VMM][I]: ExitCode: 0
> [VMM][I]: Successfully execute network driver operation: post.
> [LCM][I]: New VM state is RUNNING
>
> I generate an error to see what's comming in the logs:
>
> oneadmin@yggdrasil:~$ cut -d' ' -f6- /var/log/one/15.log
> [DiM][I]: New VM state is ACTIVE.
> [LCM][I]: New VM state is PROLOG.
> [TM][I]: Command execution fail: /var/lib/one/remotes/tm/qcow2/clone
> yggdrasil:/var/lib/one/datastores/1/e72972d1dc14203d83520f9ae6395d94
> yggdrasil:/var/lib/one//datastores/0/15/disk.1 15 1
> [TM][I]: clone: Cloning
> /var/lib/one/datastores/1/e72972d1dc14203d83520f9ae6395d94 in
> yggdrasil:/var/lib/one//datastores/0/15/disk.1
> [TM][E]: clone: Command "cd /var/lib/one/datastores/0/15; qemu-img
> create -b /var/lib/one/datastores/1/e72972d1dc14203d83520f9ae6395d94 -f
> qcow2 /var/lib/one/datastores/0/15/disk.1" failed: qemu-img: Could not open
> '/var/lib/one/datastores/1/e72972d1dc14203d83520f9ae6395d94'
> [TM][E]: Error copying
> yggdrasil:/var/lib/one/datastores/1/e72972d1dc14203d83520f9ae6395d94 to
> yggdrasil:/var/lib/one//datastores/0/15/disk.1
> [TM][I]: ExitCode: 1
> [TM][E]: Error executing image transfer script: Error copying
> yggdrasil:/var/lib/one/datastores/1/e72972d1dc14203d83520f9ae6395d94 to
> yggdrasil:/var/lib/one//datastores/0/15/disk.1
> [DiM][I]: New VM state is FAILED
> [DiM][I]: New VM state is DONE.
> [TM][W]: Ignored: TRANSFER SUCCESS 15 -
>
> My log configuration is:
>
> LOG = [
>   system  = "file",
>   debug_level = 3
> ]
>
> I think it's a problem, each step should be clearly identified with the
> command it runs.
>
> It can be hard to reproduce an error, specially when the user delete the
> VM in “FAILED” state and try 2 or 3 times before asking the ONE admin.
>
> For the logs above, I don't know why the clone log[1] are not reported.
>
> Regards.
>
> Footnotes:
> [1]
> http://dev.opennebula.org/projects/opennebula/repository/revisions/release-4.2/entry/src/tm_mad/qcow2/clone#L69
>
> --
> Daniel Dehennin
> Récupérer ma clef GPG:
> gpg --keyserver pgp.mit.edu --recv-keys 0x7A6FE2DF
>
> ___
> Users mailing list
> Users@lists.opennebula.org
> http://lists.opennebula.org/listinfo.cgi/users-opennebula.org
>
> --
> 
> --
> Ruben S. Montero, PhD
> Project co-Lead and Chief 
> Architect
> OpenNebula - Flexible Enterprise Cloud Made Simple
>  
> www.OpenNebula.org | rsmont...@opennebula.org | @OpenNebula
>
___
Users mailing list
Users@lists.opennebula.org
http://lists.opennebula.org/listinfo.cgi/users-opennebula.org

[one-users] Missing log when no error happens

[Daniel Dehennin]

Hello,

I made some search without success, I'm asking here before creating any
redmine issue.

Using OpenNebula 4.2, I just see that there is no TM log on successful
VMs setup:

oneadmin@yggdrasil:~$ cut -d' ' -f6- /var/log/one/16.log 
[DiM][I]: New VM state is ACTIVE.
[LCM][I]: New VM state is PROLOG.
[LCM][I]: New VM state is BOOT
[VMM][I]: Generating deployment file: /var/lib/one/vms/16/deployment.0
[VMM][I]: ExitCode: 0
[VMM][I]: Successfully execute network driver operation: pre.
[VMM][I]: ExitCode: 0
[VMM][I]: Successfully execute virtualization driver operation: deploy.
[VMM][I]: post: Executed "sudo /usr/bin/ovs-vsctl set Port vnet0 tag=20".
[VMM][I]: post: Executed "sudo /usr/bin/ovs-ofctl add-flow baby-gnu 
in_port=5,dl_src=02:00:0a:02:00:00,priority=4,actions=normal".
[VMM][I]: post: Executed "sudo /usr/bin/ovs-ofctl add-flow baby-gnu 
in_port=5,priority=39000,actions=drop".
[VMM][I]: ExitCode: 0
[VMM][I]: Successfully execute network driver operation: post.
[LCM][I]: New VM state is RUNNING

I generate an error to see what's comming in the logs:

oneadmin@yggdrasil:~$ cut -d' ' -f6- /var/log/one/15.log 
[DiM][I]: New VM state is ACTIVE.
[LCM][I]: New VM state is PROLOG.
[TM][I]: Command execution fail: /var/lib/one/remotes/tm/qcow2/clone 
yggdrasil:/var/lib/one/datastores/1/e72972d1dc14203d83520f9ae6395d94 
yggdrasil:/var/lib/one//datastores/0/15/disk.1 15 1
[TM][I]: clone: Cloning 
/var/lib/one/datastores/1/e72972d1dc14203d83520f9ae6395d94 in 
yggdrasil:/var/lib/one//datastores/0/15/disk.1
[TM][E]: clone: Command "cd /var/lib/one/datastores/0/15; qemu-img create 
-b /var/lib/one/datastores/1/e72972d1dc14203d83520f9ae6395d94 -f qcow2 
/var/lib/one/datastores/0/15/disk.1" failed: qemu-img: Could not open 
'/var/lib/one/datastores/1/e72972d1dc14203d83520f9ae6395d94'
[TM][E]: Error copying 
yggdrasil:/var/lib/one/datastores/1/e72972d1dc14203d83520f9ae6395d94 to 
yggdrasil:/var/lib/one//datastores/0/15/disk.1
[TM][I]: ExitCode: 1
[TM][E]: Error executing image transfer script: Error copying 
yggdrasil:/var/lib/one/datastores/1/e72972d1dc14203d83520f9ae6395d94 to 
yggdrasil:/var/lib/one//datastores/0/15/disk.1
[DiM][I]: New VM state is FAILED
[DiM][I]: New VM state is DONE.
[TM][W]: Ignored: TRANSFER SUCCESS 15 -

My log configuration is:

LOG = [
  system  = "file",
  debug_level = 3
]
 
I think it's a problem, each step should be clearly identified with the
command it runs.

It can be hard to reproduce an error, specially when the user delete the
VM in “FAILED” state and try 2 or 3 times before asking the ONE admin.

For the logs above, I don't know why the clone log[1] are not reported.

Regards.

Footnotes: 
[1]  
http://dev.opennebula.org/projects/opennebula/repository/revisions/release-4.2/entry/src/tm_mad/qcow2/clone#L69

-- 
Daniel Dehennin
Récupérer ma clef GPG:
gpg --keyserver pgp.mit.edu --recv-keys 0x7A6FE2DF


pgpX5Upy1CEOP.pgp
Description: PGP signature
___
Users mailing list
Users@lists.opennebula.org
http://lists.opennebula.org/listinfo.cgi/users-opennebula.org