| Message ID | 1450821415-100769-1-git-send-email-u9012063@gmail.com |
|---|---|
| State | Changes Requested |
| Headers | show |
On Tue, Dec 22, 2015 at 01:56:55PM -0800, William Tu wrote: > The patch adds the caller's information of ovs_vsctl() in order > to assist debugging. The caller's information is formatted as > "(filename, line number)". > > An example: > > ovsdb-tool show-log > record 183: 2015-12-22 21:12:26.050 "ovs-vsctl: ovs-vsctl --no-wait > add-br br0 -- comment (FILE:./ifupdown.sh,LINE:81)" This looks useful but as-is the ifupdown.sh code appears bash-specific, because I don't think "caller" is POSIX. You can probably work around that by checking for bash, or by changing #!/bin/sh to #!/bin/bash since this is Debian-specific anyway. You could get most of the benefit of this change by modifying ovs-vsctl to get the name of its parent process. That requires OS-specific code but at least on Linux it shouldn't be difficult. It would have the advantage that it would work for every caller not just for the ones that the patch specifically updates. Did you consider that idea? Thanks, Ben.
Hi Ben, Thanks for the feedback. I will work around the "caller" by changing #!/bin/sh to #!/bin/bash As for the parent process, I think it depends on how verbose people consider the information helpful. The current patch only adds the immediate caller, but we could definitely add the entire call stack within the same process, or like you suggest, add the parent process. Regards, William On Tue, Dec 22, 2015 at 11:18 PM, Ben Pfaff <blp@ovn.org> wrote: > On Tue, Dec 22, 2015 at 01:56:55PM -0800, William Tu wrote: > > The patch adds the caller's information of ovs_vsctl() in order > > to assist debugging. The caller's information is formatted as > > "(filename, line number)". > > > > An example: > > > ovsdb-tool show-log > > record 183: 2015-12-22 21:12:26.050 "ovs-vsctl: ovs-vsctl --no-wait > > add-br br0 -- comment (FILE:./ifupdown.sh,LINE:81)" > > This looks useful but as-is the ifupdown.sh code appears bash-specific, > because I don't think "caller" is POSIX. You can probably work around > that by checking for bash, or by changing #!/bin/sh to #!/bin/bash since > this is Debian-specific anyway. > > You could get most of the benefit of this change by modifying ovs-vsctl > to get the name of its parent process. That requires OS-specific code > but at least on Linux it shouldn't be difficult. It would have the > advantage that it would work for every caller not just for the ones that > the patch specifically updates. Did you consider that idea? > > Thanks, > > Ben. >
I think maybe you misinterpreted what I meant when I said "every caller". When I said that, I meant "every program that invokes ovs-vsctl", not the entire call stack. Anyhow, either way this is going to be helpful for debugging, thanks for writing it up. On Wed, Dec 23, 2015 at 07:41:56AM -0800, William Tu wrote: > Hi Ben, > > Thanks for the feedback. > I will work around the "caller" by changing #!/bin/sh to #!/bin/bash > > As for the parent process, I think it depends on how verbose people > consider the information helpful. The current patch only adds the immediate > caller, but we could definitely add the entire call stack within the same > process, or like you suggest, add the parent process. > > Regards, > William > > On Tue, Dec 22, 2015 at 11:18 PM, Ben Pfaff <blp@ovn.org> wrote: > > > On Tue, Dec 22, 2015 at 01:56:55PM -0800, William Tu wrote: > > > The patch adds the caller's information of ovs_vsctl() in order > > > to assist debugging. The caller's information is formatted as > > > "(filename, line number)". > > > > > > An example: > > > > ovsdb-tool show-log > > > record 183: 2015-12-22 21:12:26.050 "ovs-vsctl: ovs-vsctl --no-wait > > > add-br br0 -- comment (FILE:./ifupdown.sh,LINE:81)" > > > > This looks useful but as-is the ifupdown.sh code appears bash-specific, > > because I don't think "caller" is POSIX. You can probably work around > > that by checking for bash, or by changing #!/bin/sh to #!/bin/bash since > > this is Debian-specific anyway. > > > > You could get most of the benefit of this change by modifying ovs-vsctl > > to get the name of its parent process. That requires OS-specific code > > but at least on Linux it shouldn't be difficult. It would have the > > advantage that it would work for every caller not just for the ones that > > the patch specifically updates. Did you consider that idea? > > > > Thanks, > > > > Ben. > >
On Wed, Dec 23, 2015 at 9:41 AM, Ben Pfaff <blp@ovn.org> wrote: > I think maybe you misinterpreted what I meant when I said "every > caller". When I said that, I meant "every program that invokes > ovs-vsctl", not the entire call stack. William came to me to discuss this approach, If we both understood it correctly, then it would be impossible to get the LINE number with it, right? Nevertheless, it would make comment generation simpler at expense of printing only the parent process. > > Anyhow, either way this is going to be helpful for debugging, thanks for > writing it up. Ben, Thanks for reviewing this. William, can you send V2 patch? I think you were trying to figure out if it would be possible to source the common ovs_vsctl function to avoid repetition? > > On Wed, Dec 23, 2015 at 07:41:56AM -0800, William Tu wrote: >> Hi Ben, >> >> Thanks for the feedback. >> I will work around the "caller" by changing #!/bin/sh to #!/bin/bash >> >> As for the parent process, I think it depends on how verbose people >> consider the information helpful. The current patch only adds the immediate >> caller, but we could definitely add the entire call stack within the same >> process, or like you suggest, add the parent process. >> >> Regards, >> William >> >> On Tue, Dec 22, 2015 at 11:18 PM, Ben Pfaff <blp@ovn.org> wrote: >> >> > On Tue, Dec 22, 2015 at 01:56:55PM -0800, William Tu wrote: >> > > The patch adds the caller's information of ovs_vsctl() in order >> > > to assist debugging. The caller's information is formatted as >> > > "(filename, line number)". >> > > >> > > An example: >> > > > ovsdb-tool show-log >> > > record 183: 2015-12-22 21:12:26.050 "ovs-vsctl: ovs-vsctl --no-wait >> > > add-br br0 -- comment (FILE:./ifupdown.sh,LINE:81)" >> > >> > This looks useful but as-is the ifupdown.sh code appears bash-specific, >> > because I don't think "caller" is POSIX. You can probably work around >> > that by checking for bash, or by changing #!/bin/sh to #!/bin/bash since >> > this is Debian-specific anyway. >> > >> > You could get most of the benefit of this change by modifying ovs-vsctl >> > to get the name of its parent process. That requires OS-specific code >> > but at least on Linux it shouldn't be difficult. It would have the >> > advantage that it would work for every caller not just for the ones that >> > the patch specifically updates. Did you consider that idea? >> > >> > Thanks, >> > >> > Ben. >> > > _______________________________________________ > dev mailing list > dev@openvswitch.org > http://openvswitch.org/mailman/listinfo/dev
On Mon, Jan 04, 2016 at 09:36:34AM -0800, Ansis Atteka wrote: > On Wed, Dec 23, 2015 at 9:41 AM, Ben Pfaff <blp@ovn.org> wrote: > > I think maybe you misinterpreted what I meant when I said "every > > caller". When I said that, I meant "every program that invokes > > ovs-vsctl", not the entire call stack. > > William came to me to discuss this approach, If we both understood it > correctly, then it would be impossible to get the LINE number with it, > right? Yes. > Nevertheless, it would make comment generation simpler at expense of > printing only the parent process. It's a tradeoff. I don't know the correct one. I do know that sometimes it would have been useful, during debugging, to know what program invoked ovs-vsctl.
On 4 January 2016 at 10:18, Ben Pfaff <blp@ovn.org> wrote: > On Mon, Jan 04, 2016 at 09:36:34AM -0800, Ansis Atteka wrote: > > On Wed, Dec 23, 2015 at 9:41 AM, Ben Pfaff <blp@ovn.org> wrote: > > > I think maybe you misinterpreted what I meant when I said "every > > > caller". When I said that, I meant "every program that invokes > > > ovs-vsctl", not the entire call stack. > > > > William came to me to discuss this approach, If we both understood it > > correctly, then it would be impossible to get the LINE number with it, > > right? > > Yes. > > > Nevertheless, it would make comment generation simpler at expense of > > printing only the parent process. > > It's a tradeoff. I don't know the correct one. I do know that > sometimes it would have been useful, during debugging, to know what > program invoked ovs-vsctl. > I just thought a little more about this. Third party code (e.g. libvirt) also invokes ovs-vsctl and I believe it would be nice to be able to tell such cases apart from those when user manually invoked ovs-vsctl manually from ssh session or console. So parent process name would be helpful here. The FILE+LINE part could be used to troubleshoot potential OVS internal bugs, for example, to quickly be able to tell which OVS internal code changed OVSDB by calling ovs-vsctl. So how about printing both - PARENT PROCESS NAME+ID and FILE+LINE?
Hi Ansis, I think it's a good idea. But printing only parent process might not be sufficient, we might have to print the entire process tree. An example of user ssh login and calls ovs-vsctl can be logged as below: record 189: 2015-12-23 23:35:31.998 "ovs-vsctl: ovs-vsctl --no-wait add-br br88 -- comment (systemd(1)---sshd(741)---sshd(51100)---bash(51163)---my-ovs-vsctl.sh(78035))(FILE:./my-ovs-vsctl.sh,LINE:9)" With the format (process tree) followed by (filename, line number) Do you think this information is useful enough? Thanks Regards, William I just thought a little more about this. Third party code (e.g. libvirt) > also invokes ovs-vsctl and I believe it would be nice to be able to tell > such cases apart from those when user manually invoked ovs-vsctl manually > from ssh session or console. So parent process name would be helpful here. > > The FILE+LINE part could be used to troubleshoot potential OVS internal > bugs, for example, to quickly be able to tell which OVS internal code > changed OVSDB by calling ovs-vsctl. > > So how about printing both - PARENT PROCESS NAME+ID and FILE+LINE? > > > _______________________________________________ >> dev mailing list >> dev@openvswitch.org >> http://openvswitch.org/mailman/listinfo/dev >> > >
On Mon, Jan 04, 2016 at 11:33:00AM -0800, Ansis Atteka wrote: > On 4 January 2016 at 10:18, Ben Pfaff <blp@ovn.org> wrote: > > > On Mon, Jan 04, 2016 at 09:36:34AM -0800, Ansis Atteka wrote: > > > On Wed, Dec 23, 2015 at 9:41 AM, Ben Pfaff <blp@ovn.org> wrote: > > > > I think maybe you misinterpreted what I meant when I said "every > > > > caller". When I said that, I meant "every program that invokes > > > > ovs-vsctl", not the entire call stack. > > > > > > William came to me to discuss this approach, If we both understood it > > > correctly, then it would be impossible to get the LINE number with it, > > > right? > > > > Yes. > > > > > Nevertheless, it would make comment generation simpler at expense of > > > printing only the parent process. > > > > It's a tradeoff. I don't know the correct one. I do know that > > sometimes it would have been useful, during debugging, to know what > > program invoked ovs-vsctl. > > > > I just thought a little more about this. Third party code (e.g. libvirt) > also invokes ovs-vsctl and I believe it would be nice to be able to tell > such cases apart from those when user manually invoked ovs-vsctl manually > from ssh session or console. So parent process name would be helpful here. > > The FILE+LINE part could be used to troubleshoot potential OVS internal > bugs, for example, to quickly be able to tell which OVS internal code > changed OVSDB by calling ovs-vsctl. > > So how about printing both - PARENT PROCESS NAME+ID and FILE+LINE? Seems reasonable.
diff --git a/debian/ifupdown.sh b/debian/ifupdown.sh index fe15b71..22a8600 100755 --- a/debian/ifupdown.sh +++ b/debian/ifupdown.sh @@ -22,7 +22,14 @@ if [ -z "${IF_OVS_TYPE}" ]; then fi ovs_vsctl() { - ovs-vsctl --timeout=5 "$@" + local stack="" + + stack=`caller 0` + lineno=`echo $stack | awk '{print $1}'` + filename=`echo $stack | awk '{print $3}'` + msg="(FILE:$filename,LINE:$lineno)" + + ovs-vsctl --timeout=5 "$@" -- comment $msg } if (ovs_vsctl --version) > /dev/null 2>&1; then :; else diff --git a/ovn/utilities/ovn-docker-overlay-driver b/ovn/utilities/ovn-docker-overlay-driver index 26ed1fe..b560cf3 100755 --- a/ovn/utilities/ovn-docker-overlay-driver +++ b/ovn/utilities/ovn-docker-overlay-driver @@ -23,6 +23,7 @@ import re import shlex import subprocess import sys +import traceback import ovs.dirs import ovs.util @@ -59,7 +60,9 @@ def call_prog(prog, args_list): def ovs_vsctl(*args): - return call_prog("ovs-vsctl", list(args)) + filename, lineno, funname, exe = traceback.extract_stack(limit=2)[0] + comments = " -- comment (FILE:" + filename + ",LINE:" + str(lineno) + ")" + return call_prog("ovs-vsctl", list(args) + shlex.split(comments)) def ovn_nbctl(*args): diff --git a/ovn/utilities/ovn-docker-underlay-driver b/ovn/utilities/ovn-docker-underlay-driver index 2c9c4b6..b2cbf3e 100755 --- a/ovn/utilities/ovn-docker-underlay-driver +++ b/ovn/utilities/ovn-docker-underlay-driver @@ -24,6 +24,7 @@ import subprocess import sys import time import uuid +import traceback import ovs.dirs import ovs.util @@ -68,7 +69,9 @@ def call_prog(prog, args_list): def ovs_vsctl(*args): - return call_prog("ovs-vsctl", list(args)) + filename, lineno, funname, exe = traceback.extract_stack(limit=2)[0] + comments = " -- comment (FILE:" + filename + ",LINE:" + str(lineno) + ")" + return call_prog("ovs-vsctl", list(args) + shlex.split(comments)) def cleanup(): diff --git a/utilities/ovs-ctl.in b/utilities/ovs-ctl.in index 0082bed..e17860e 100755 --- a/utilities/ovs-ctl.in +++ b/utilities/ovs-ctl.in @@ -73,7 +73,14 @@ insert_mod_if_required () { } ovs_vsctl () { - ovs-vsctl --no-wait "$@" + local stack="" + + stack=`caller 0` + lineno=`echo $stack | awk '{print $1}'` + filename=`echo $stack | awk '{print $3}'` + msg="(FILE:$filename,LINE:$lineno)" + + ovs-vsctl --no-wait "$@" -- comment $msg } set_system_ids () { diff --git a/utilities/ovs-docker b/utilities/ovs-docker index 43cea54..1b1ccc6 100755 --- a/utilities/ovs-docker +++ b/utilities/ovs-docker @@ -29,7 +29,13 @@ search_path () { } ovs_vsctl () { - ovs-vsctl --timeout=60 "$@" + local stack="" + stack=`caller 0` + lineno=`echo $stack | awk '{print $1}'` + filename=`echo $stack | awk '{print $3}'` + msg="(FILE:$filename,LINE:$lineno)" + + ovs-vsctl --timeout=60 "$@" -- comment $msg } create_netns_link () { diff --git a/utilities/ovs-save b/utilities/ovs-save index bcaf27c..6b1111f 100755 --- a/utilities/ovs-save +++ b/utilities/ovs-save @@ -116,7 +116,13 @@ save_flows () { } ovs_vsctl () { - ovs-vsctl --no-wait "$@" + local stack="" + stack=`caller 0` + lineno=`echo $stack | awk '{print $1}'` + filename=`echo $stack | awk '{print $3}'` + msg="(FILE:$filename,LINE:$lineno)" + + ovs-vsctl --no-wait "$@" -- comment $msg } save_ofports () diff --git a/utilities/ovs-vsctl-bashcomp.bash b/utilities/ovs-vsctl-bashcomp.bash index a3273f8..fadc47f 100755 --- a/utilities/ovs-vsctl-bashcomp.bash +++ b/utilities/ovs-vsctl-bashcomp.bash @@ -7,11 +7,18 @@ _OVSDB_SERVER_LOCATION="" # the correct --db argument. _ovs_vsctl () { local _db + local stack="" if [ -n "$_OVSDB_SERVER_LOCATION" ]; then _db="--db=$_OVSDB_SERVER_LOCATION" fi - ovs-vsctl ${_db} "$@" + + stack=`caller 0` + lineno=`echo $stack | awk '{print $1}'` + filename=`echo $stack | awk '{print $3}'` + msg="(FILE:$filename,LINE:$lineno)" + + ovs-vsctl ${_db} "$@" -- comment $msg } # ovs-vsctl --commands outputs in this format: diff --git a/vtep/ovs-vtep b/vtep/ovs-vtep index 3244520..847d0ee 100755 --- a/vtep/ovs-vtep +++ b/vtep/ovs-vtep @@ -23,6 +23,7 @@ import subprocess import sys import time import types +import traceback import ovs.dirs import ovs.util @@ -59,6 +60,9 @@ def call_prog(prog, args_list): return output def ovs_vsctl(args): + filename, lineno, funname, exe = traceback.extract_stack(limit=2)[0] + comments = " -- comment (FILE:" + filename + ",LINE:" + str(lineno) + ")" + args += comments return call_prog("ovs-vsctl", shlex.split(args)) def ovs_ofctl(args):
The patch adds the caller's information of ovs_vsctl() in order to assist debugging. The caller's information is formatted as "(filename, line number)". An example: > ovsdb-tool show-log record 183: 2015-12-22 21:12:26.050 "ovs-vsctl: ovs-vsctl --no-wait add-br br0 -- comment (FILE:./ifupdown.sh,LINE:81)" --- debian/ifupdown.sh | 9 ++++++++- ovn/utilities/ovn-docker-overlay-driver | 5 ++++- ovn/utilities/ovn-docker-underlay-driver | 5 ++++- utilities/ovs-ctl.in | 9 ++++++++- utilities/ovs-docker | 8 +++++++- utilities/ovs-save | 8 +++++++- utilities/ovs-vsctl-bashcomp.bash | 9 ++++++++- vtep/ovs-vtep | 4 ++++ 8 files changed, 50 insertions(+), 7 deletions(-)