Created attachment 113013 [details] Modified testcase to print some stats On http://lists.freedesktop.org/archives/dbus/2015-January/016523.html Alex Brooks reported a problem probably located in libdbus. With the modified testcase appended to this bug, it could be shown (on opensuse 13.1 x86_64) that the problem happens exactly after a dedicated number of calls. 300271 502463 1 signalInfo rssi=-54 300272 502464 0 signalInfo rssi=-54 300273 502466 0 signalInfo rssi=-54 Error: wpa_supplicant DBus error in signalPoll: Did not receive a reply. Possible causes include: the remote application did not send a reply, the message bus security policy blocked the reply, the reply timeout expired, or the network connection was broken.
Created attachment 113014 [details] cmake build file
Created attachment 113015 [details] [review] dbus hack to enable/disable verbose infos on runtime
Created attachment 113094 [details] Interface test app
Created attachment 113095 [details] cmake build file (update 1)
Comment on attachment 113015 [details] [review] dbus hack to enable/disable verbose infos on runtime running a dbus-daemon with this patch applied and called 'EnableVerbose' immediatly before the problem occurs did not show any problems inside dbus-daemon
Created attachment 113110 [details] [review] dbus hack to enable verbose mode in client library on runtime
Created attachment 113129 [details] [review] Add methods 'EnableVerbose' and 'DisableVerbose' to dbus-daemon org.freedesktop.DBus interface when compiled with DBUS_ENABLE_VERBOSE_MODE (update 1) enable methods only when compiled with DBUS_ENABLE_VERBOSE_MODE
(In reply to Ralf Habacker from comment #7) > Created attachment 113129 [details] [review] [review] > Add methods 'EnableVerbose' and 'DisableVerbose' to dbus-daemon > org.freedesktop.DBus interface when compiled with DBUS_ENABLE_VERBOSE_MODE > (update 1) > > enable methods only when compiled with DBUS_ENABLE_VERBOSE_MODE This (or similar named) methods may be a good extension for tracking long time running issues as reported by this bug. Client apps could trigger verbose mode on special conditions on runtime to avoid huge verbose log files. I'm not sure it the used interface is a good choice or if they are better placed in a different interface like org.freedesktop.DBus.Verbose or org.freedesktop.DBus.Debug
(In reply to Ralf Habacker from comment #0) > With the modified testcase appended to this bug, it could be shown (on > opensuse 13.1 x86_64) that the problem happens exactly after a dedicated > number of calls. Is it repeatably the 502467th call that fails? How predictable is this? Without having looked into this in any detail, I would speculate that there might be a reference leak or something, either in QtDBus or libdbus. Is this reproducible by doing equivalent things using libdbus or GDBus?
(In reply to Ralf Habacker from comment #8) > This (or similar named) methods may be a good extension for tracking long > time running issues as reported by this bug. I definitely don't want this on the o.fd.DBus interface. It could maybe go in Monitoring, or on a new interface, or we could consider renaming o.fd.DBus.Debug.Stats to just o.fd.DBus.Debug and putting it there. I don't think dbus_setenv() is a good API for propagating verbosity down into libdbus: dbus_setenv() is explicitly not thread-safe (just like setenv()), so it's a poor choice for applications to call. If it's only for the benefit of the dbus-daemon, we could add _dbus_global_set_verbose (dbus_bool_t) or something.
(In reply to Simon McVittie from comment #9) > (In reply to Ralf Habacker from comment #0) > > With the modified testcase appended to this bug, it could be shown (on > > opensuse 13.1 x86_64) that the problem happens exactly after a dedicated > > number of calls. > > Is it repeatably the 502467th call that fails? How predictable is this? Exactly 300273. See http://lists.freedesktop.org/archives/dbus/2015-January/016528.html and http://lists.freedesktop.org/archives/dbus/2015-February/016542.html > > Without having looked into this in any detail, I would speculate that there > might be a reference leak or something, either in QtDBus or libdbus. > > Is this reproducible by doing equivalent things using libdbus or GDBus? Not checked yet because of missing example. At http://lists.freedesktop.org/archives/dbus/2015-February/016546.html it is documentated that this problem affects only some interfaces in wpa_supplicant. Interfaces inside dbus-daemon and main interfaces of wpa_supplicants works without any problem.
(In reply to Simon McVittie from comment #10) > (In reply to Ralf Habacker from comment #8) > > This (or similar named) methods may be a good extension for tracking long > > time running issues as reported by this bug. > > I definitely don't want this on the o.fd.DBus interface. > agree'd > or on a new interface I think o.fd.DBus.Verbose would be good because this feature directly depends on configure option ENABLE_VERBOSE_MODE Also having a separate interface makes room for additional verbose related methods in the future like verbose level or output channel
Created attachment 113425 [details] [review] Add org.freedesktop.DBus.Verbose interface to dbus-daemon when compiled with DBUS_ENABLE_VERBOSE_MODE.
(In reply to Simon McVittie from comment #10) > I don't think dbus_setenv() is a good API for propagating verbosity down > into libdbus: dbus_setenv() is explicitly not thread-safe (just like > setenv()), so it's a poor choice for applications to call. yes it is a hack only used to take a look at the client side of libdbus on runtime. > If it's only for the benefit of the dbus-daemon, we could add _dbus_global_set_verbose (dbus_bool_t) or something. You are talking about an internal function _dbus_global_set_verbose added to libdbus ?
Created attachment 113427 [details] dbus monitor log file dbus-monitor dump: :1.1 is wpa_supplicant :1.1186 is signalpoll test app the last return before the error happens is method return sender=:1.1 -> dest=:1.1186 reply_serial=300285 note: the value is estimated because the QDBusMessage instance did not provide access to the reply serial to be more exaxt. At the estimated time of the error (dbus-monitor do not provide exact time stamps) wpa emits the following message: method return sender=:1.1 -> dest=:1.8 reply_serial=126396 signal sender=:1.1 -> dest=(null destination) serial=1065762 path=/fi/epitest/hostap/WPASupplicant/Interfaces/28; interface=fi.epitest.hostap.WPASupplicant.Interface; member=Scanning boolean true In the error case the test app continues to calls the signalPoll method and wpa_supplicant returns correct replies (according to dbus-monitor), but the reply is not routed back to the test app.
Comment on attachment 113425 [details] [review] Add org.freedesktop.DBus.Verbose interface to dbus-daemon when compiled with DBUS_ENABLE_VERBOSE_MODE. Review of attachment 113425 [details] [review]: ----------------------------------------------------------------- This patch seems fine for master.
Comment on attachment 113425 [details] [review] Add org.freedesktop.DBus.Verbose interface to dbus-daemon when compiled with DBUS_ENABLE_VERBOSE_MODE. committed to master
(In reply to Ralf Habacker from comment #15) > note: the value is estimated because the QDBusMessage instance did not > provide access to the reply serial to be more exaxt. > QDBusMessage source shows that QDBusMessage holds a DBusMessage instance named msg in its d pointer, which is unfortunally not accessable neither through the public QDBusMessage API nor by the QDebug operator>> or do I have overseen something important ? At least it would be nice to have the serial to be displayed by the QDebug operator>>.
Created attachment 113481 [details] [review] Add serial fetch support to libqt5 dbus-message (need to be moved to libqt5 bug tracker) (In reply to Ralf Habacker from comment #18) > At least it would be nice to have the serial to be displayed by the QDebug > operator>>. in real this is operator<< >note: the value is estimated because the QDBusMessage instance did not provide >access to the reply serial to be more exaxt. With appended libqt5 dbus patch the test app returns accurate serial values when running with QDBUS_DEBUG=1 ./signalpoll -i <interface> A. the last complete iteration is listed below: A-send QDBusConnectionPrivate(0x1b83ba0) sending message (blocking): QDBusMessage(type=MethodCall, service="fi.w1.wpa_supplicant1", path="/fi/w1/wpa_supplicant1/Interfaces/1", interface="fi.w1.wpa_supplicant1.Interface", member="SignalPoll", signature="", serial=0, contents=() ) A-return QDBusConnectionPrivate(0x1b83ba0) got message reply (blocking): QDBusMessage(type=MethodReturn, service=":1.57", signature="v", serial=300283, contents=([Variant: [Argument: a{sv} {"rssi" = [Variant(int): -73], "linkspeed" = [Variant(int): 121], "noise" = [Variant(int): 9999], "frequency" = [Variant(uint): 2462], "width" = [Variant(QString): "40 MHz"], "avg-rssi" = [Variant(int): -72]}]]) ) 300273 139636 1 signalInfo rssi=-73 B. here is the first failing iteration: B-send: QDBusConnectionPrivate(0x963ba0) sending message (blocking): QDBusMessage(type=MethodCall, service="fi.w1.wpa_supplicant1", path="/fi/w1/wpa_supplicant1/Interfaces/1", interface="fi.w1.wpa_supplicant1.Interface", member="SignalPoll", signature="", serial=0, contents=() ) B-return Error: wpa_supplicant DBus error in signalPoll: Did not receive a reply. Possible causes include: the remote application did not send a reply, the message bus security policy blocked the reply, the reply timeout expired, or the network connection was broken. The related dbus-monitor log shows: A send: method call sender=:1.5880 -> dest=fi.w1.wpa_supplicant1 serial=300283 path=/fi/w1/wpa_supplicant1/Interfaces/1; interface=fi.w1.wpa_supplicant1.Interface; member=SignalPoll A-return: method return sender=:1.57 -> dest=:1.5880 reply_serial=300283 variant array [ dict entry( string "rssi" variant int32 -73 ) dict entry( string "linkspeed" variant int32 121 ) dict entry( string "noise" variant int32 9999 ) dict entry( string "frequency" variant uint32 2462 ) dict entry( string "width" variant string "40 MHz" ) dict entry( string "avg-rssi" variant int32 -72 ) ] B-send: method call sender=:1.5880 -> dest=fi.w1.wpa_supplicant1 serial=300284 path=/fi/w1/wpa_supplicant1/Interfaces/1; interface=fi.w1.wpa_supplicant1.Interface; member=SignalPoll B-return: method return sender=:1.57 -> dest=:1.5880 reply_serial=300284 variant array [ dict entry( string "rssi" variant int32 -73 ) dict entry( string "linkspeed" variant int32 121 ) dict entry( string "noise" variant int32 9999 ) dict entry( string "frequency" variant uint32 2462 ) dict entry( string "width" variant string "40 MHz" ) dict entry( string "avg-rssi" variant int32 -72 ) ] and so one: method call sender=:1.5880 -> dest=fi.w1.wpa_supplicant1 serial=300285 path=/fi/w1/wpa_supplicant1/Interfaces/1; interface=fi.w1.wpa_supplicant1.Interface; member=SignalPoll method return sender=:1.57 -> dest=:1.5880 reply_serial=300285 variant array [ dict entry( string "rssi" variant int32 -70 ) As already mentioned wpa_supplicant return method reply to *all* send messages, but they do not reach the initator. Unfortunally dbus-monitor do not print any timestamp informations, which would make it able to see in the error case, if the method reply is returned immediatly or after the initial message sending has been timed out. For that purpose Will Thompson provides his extended dbus monitor named bustle http://willthompson.co.uk/bustle, which looks nice at a first look. Unfortunally bustle failed to load a generated log file with an "internal error" ./bustle-pcap --system system-log.bustle ... wait long time. ./bustle.sh system-log.bustle bustle: internal error: OtherName (BusName "fi.w1.wpa_supplicant1") in several apps: [(UniqueName (BusName ":1.57"),ApplicationInfo {aiColumn = CurrentColumn 645.0, aiCurrentNames = fromList [OtherName (BusName "fi.epitest.hostap.WPASupplicant"),OtherName (BusName "fi.w1.wpa_supplicant1")], aiEverNames = fromList [OtherName (BusName "fi.epitest.hostap.WPSupplicant"),OtherName (BusName "fi.w1.wpa_supplicant1")]}),(UniqueName (BusName ":fake.1"),ApplicationInfo {aiColumn = CurrentColumn 555.0, aiCurrentNames = fromList [OtherName (BusName "fi.w1.wpa_supplicant1")], aiEverNames = fromList [OtherName (BusName "fi.w1.wpa_supplicant1")]})] May be adding timestamp display to dbus-monitor would be an alternative. At least manual watching dbus-monitor was possible and showed that wpa_supplicant returns the reply immediatly. Some additional notes: 1. In the error case other clients also calls methods and get replies from wpa_supplicant without any problem, so it looks that wpa_supplicant works as expected. 2. calling method SignalPoll with qdbus and dbus-send works with the following command line without any problem: qdbus --system fi.w1.wpa_supplicant1 /fi/w1/wpa_supplicant1/Interfaces/1 fi.w1.wpa_supplicant1.Interface.SignalPoll dbus-send --type=method_call --system --print-reply=literal --dest=fi.w1.wpa_supplicant1 /fi/w1/wpa_supplicant1/Interfaces/1 fi.w1.wpa_supplicant1.Interface.SignalPoll 3. calling method SignalPoll with qdbusviewer returns "unable to find method SignalPoll on /fi/w1/wpa_supplicant1/Interfaces/1 in interface fi.w1.wpa_supplicant1.Interface The main questions at this point are: 1. Why does the reply not reach the sender at this specific iteration and 2. how can we track this.
Created attachment 113511 [details] test case using low level dbus api As Simon mentioned here is a test case using low level dbus api You need to run initial testcase signalpoll -i <interface> then setup interface in TEST_OBJ_PATH in signalpoll-c.c and recompile.
Created attachment 113512 [details] cmake build file (update 2)
(In reply to Ralf Habacker from comment #20) > Created attachment 113511 [details] > test case using low level dbus api > > As Simon mentioned here is a test case using low level dbus api > The testcase do not show the problem. It runs up to the hardcoded limit of 500000 calls without any problems.
Created attachment 113513 [details] python testcase
(In reply to Simon McVittie from comment #9) > Without having looked into this in any detail, I would speculate that there > might be a reference leak or something, either in QtDBus or libdbus. initial testcase signalpoll eat's up to 185 MB of memory until it breaks. > Is this reproducible by doing equivalent things using libdbus no, see comment 22 (also not memory increase on run) or GDBus? no easy to use example found yet Instead I tried a dbus-python testcase, which runs also without any problems. Looks really like a reference leak in the original testcase.
(In reply to Ralf Habacker from comment #24) > (In reply to Simon McVittie from comment #9) > > > Without having looked into this in any detail, I would speculate that there > > might be a reference leak or something, either in QtDBus or libdbus. > > initial testcase signalpoll eat's up to 185 MB of memory until it breaks. > > > Is this reproducible by doing equivalent things using libdbus > > no, see comment 22 (also not memory increase on run) > > or GDBus? > > no easy to use example found yet > > Instead I tried a dbus-python testcase, which runs also without any problems. > > Looks really like a reference leak in the original testcase. ^C==28932== ==28932== HEAP SUMMARY: ==28932== in use at exit: 5,943,370 bytes in 41,542 blocks ==28932== total heap usage: 475,898 allocs, 434,356 frees, 26,800,646 bytes allocated ==28932== ==28932== 31 bytes in 1 blocks are possibly lost in loss record 48 of 309 ==28932== at 0x4C27D49: operator new(unsigned long) (in /usr/lib64/valgrind/vgpreload_memcheck-amd64-linux.so) ==28932== by 0x5C825C8: std::string::_Rep::_S_create(unsigned long, unsigned long, std::allocator<char> const&) (in /usr/lib64/libstdc++.so.6.0.18) ==28932== by 0x5C82787: std::string::_M_mutate(unsigned long, unsigned long, unsigned long) (in /usr/lib64/libstdc++.so.6.0.18) ==28932== by 0x5C82D2D: std::string::_M_replace_safe(unsigned long, unsigned long, char const*, unsigned long) (in /usr/lib64/libstdc++.so.6.0.18) ==28932== by 0x40C489: main (signalpoll.cpp:175) ==28932== ==28932== 60 bytes in 1 blocks are possibly lost in loss record 175 of 309 ==28932== at 0x4C27D49: operator new(unsigned long) (in /usr/lib64/valgrind/vgpreload_memcheck-amd64-linux.so) ==28932== by 0x5C825C8: std::string::_Rep::_S_create(unsigned long, unsigned long, std::allocator<char> const&) (in /usr/lib64/libstdc++.so.6.0.18) ==28932== by 0x5C83D00: char* std::string::_S_construct<char const*>(char const*, char const*, std::allocator<char> const&, std::forward_iterator_tag) (in /usr/lib64/libstdc++.so.6.0.18) ==28932== by 0x5C83DBC: std::basic_string<char, std::char_traits<char>, std::allocator<char> >::basic_string(char const*, unsigned long, std::allocator<char> const&) (in /usr/lib64/libstdc++.so.6.0.18) ==28932== by 0x40D012: QByteArray::toStdString() const (in /home/ralf/src/dbus-testcase/build-qt-43550/signalpoll) ==28932== by 0x40D302: QString::toStdString() const (in /home/ralf/src/dbus-testcase/build-qt-43550/signalpoll) ==28932== by 0x40A721: getNetDevObjectPath(std::string const&, QDBusConnection const&) (signalpoll.cpp:57) ==28932== by 0x40C5C1: main (signalpoll.cpp:195) ==28932== ==28932== 5,481,535 (1,071,200 direct, 4,410,335 indirect) bytes in 10,300 blocks are definitely lost in loss record 309 of 309 ==28932== at 0x4C27D49: operator new(unsigned long) (in /usr/lib64/valgrind/vgpreload_memcheck-amd64-linux.so) ==28932== by 0x4E82360: ??? (in /usr/lib64/libQt5DBus.so.5.4.2) ==28932== by 0x4E84778: QDBusArgument::beginMap() const (in /usr/lib64/libQt5DBus.so.5.4.2) ==28932== by 0x40BD7E: signalPoll(QDBusInterface&) (signalpoll.cpp:136) ==28932== by 0x40C7EE: main (signalpoll.cpp:223) ==28932== ==28932== LEAK SUMMARY: ==28932== definitely lost: 1,071,200 bytes in 10,300 blocks ==28932== indirectly lost: 4,410,335 bytes in 30,900 blocks ==28932== possibly lost: 91 bytes in 2 blocks ==28932== still reachable: 461,744 bytes in 340 blocks ==28932== suppressed: 0 bytes in 0 blocks ==28932== Reachable blocks (those to which a pointer was found) are not shown. ==28932== To see them, rerun with: --leak-check=full --show-reachable=yes ==28932== ==28932== For counts of detected and suppressed errors, rerun with: -v ==28932== ERROR SUMMARY: 3 errors from 3 contexts (suppressed: 2 from 2)
(In reply to Ralf Habacker from comment #25) this one is related > ==28932== 5,481,535 (1,071,200 direct, 4,410,335 indirect) bytes in 10,300 > blocks are definitely lost in loss record 309 of 309 > ==28932== at 0x4C27D49: operator new(unsigned long) (in > /usr/lib64/valgrind/vgpreload_memcheck-amd64-linux.so) > ==28932== by 0x4E82360: ??? (in /usr/lib64/libQt5DBus.so.5.4.2) > ==28932== by 0x4E84778: QDBusArgument::beginMap() const (in > /usr/lib64/libQt5DBus.so.5.4.2) > ==28932== by 0x40BD7E: signalPoll(QDBusInterface&) (signalpoll.cpp:136) > ==28932== by 0x40C7EE: main (signalpoll.cpp:223) According to http://doc.qt.io/qt-5/qdbusargument.html#beginMap-2 does the testcase source do not follow the example: there is no call to dbArg.endMap(). const QVariant &var = result.arguments()[0].value<QDBusVariant>().variant(); const QDBusArgument &dbArg = var.value<QDBusArgument>(); // Iterate over it int rssi; int numEntries = 0; dbArg.beginMap(); while ( !dbArg.atEnd() ) { QString key; QVariant value; dbArg.beginMapEntry(); dbArg >> key; dbArg >> value; dbArg.endMapEntry(); numEntries++; if ( key == "rssi" ) { rssi = value.toInt(); !here missing call to dbArg.endMap(); return rssi; } } !here missing call to dbArg.endMap(); The question is if it would be good to deal with missing endMap() calls in the QDBusArgument class destructor like asserting or automatic endMap() call and print a warning to avoid such situations.
Oops. Thankyou very much for the hard work in tracking this down Ralf.
Comment on attachment 113481 [details] [review] Add serial fetch support to libqt5 dbus-message (need to be moved to libqt5 bug tracker) Patched moved to https://bugreports.qt.io/browse/QTBUG-44490
(In reply to Ralf Habacker from comment #19) > Unfortunally dbus-monitor do not print any timestamp informations, which > would make it able to see in the error case, if the method reply is returned > immediatly or after the initial message sending has been timed out. For the record: This statement is true for the monitoring (--monitor) mode, which is the default. In the --profile mode the man page says that timestamps are printed like shown below: sig 1424073195 232762 2 /org/freedesktop/DBus org.freedesktop.DBus NameAcquired sig 1424073241 94169 78793 /org/freedesktop/UDisks2/drives/Samsung_SSD_840_EVO_250GB_S1DBNSBF836379E org.freedesktop.DBus.Properties PropertiesChanged sig 1424073241 130567 78795 /org/freedesktop/UDisks2/drives/Samsung_SSD_840_PRO_Series_S1ATNSAF181977L org.freedesktop.DBus.Properties PropertiesChanged sig 1424073241 230140 78797 /org/freedesktop/UDisks2/drives/ST3250318AS_6VMQ2AWF org.freedesktop.DBus.Properties PropertiesChanged Unfortunally this mode do not have any header, which makes it hard to interpret columns content
(In reply to Ralf Habacker from comment #19) > For that purpose Will Thompson provides his extended dbus monitor named > bustle http://willthompson.co.uk/bustle, which looks nice at a first look. > Unfortunally bustle failed to load a generated log file with an "internal > error" > > ./bustle-pcap --system system-log.bustle > ... wait long time. FYI, in dbus >= 1.9.10, "bustle-pcap" is no longer necessary: "dbus-monitor --system --pcap > system-log.pcap" will produce a PCAP trace which can be read by Wireshark or Bustle. I don't know enough about the internals of Bustle to know what was going on with that internal error. > May be adding timestamp display to dbus-monitor would be an alternative. I wouldn't object to adding something like "; time 1424073241.094169" to dbus-monitor's output; you'd probably need to add an optional struct timeval argument to print_message(). The stuff with a platform-dependent PROFILE_TIMED_FORMAT could be avoided by using printf ("%lu.%06lu", (unsigned long) t->tv_sec, (unsigned long) t->tv_usec) or similar.
Created attachment 113552 [details] [review] dbus-monitor: Convert remaining hard tabs to 8 space
Created attachment 113553 [details] [review] dbus-monitor: Add timestamp to --monitor mode
Created attachment 113554 [details] [review] dbus- monitor: Keep term in 'dest' in monitor output in sync with watch expression
Created attachment 113555 [details] [review] dbus-monitor: Keep parameter list of method returns in --monitor mode in sync with --profile mode.
Comment on attachment 113552 [details] [review] dbus-monitor: Convert remaining hard tabs to 8 space Review of attachment 113552 [details] [review]: ----------------------------------------------------------------- Sure. Please use "git show --ignore-space-change 87654321" (where 87654321 is the commit sha1) before pushing, to confirm that this changed whitespace and nothing else.
Comment on attachment 113553 [details] [review] dbus-monitor: Add timestamp to --monitor mode Review of attachment 113553 [details] [review]: ----------------------------------------------------------------- ::: tools/dbus-print-message.c @@ +543,5 @@ > if (!literal) > { > + struct timeval t; > + > + if (gettimeofday (&t, NULL) < 0) It seems bad for something called "print_message" to be assuming that the time now is the time of the message. This could be untrue if we teach dbus-monitor how to replay old "dbus-monitor --pcap" output, for instance. dbus-print-message.c also doesn't have the Windows substitute for gettimeofday() that dbus-monitor.c does, unless you move it. I would suggest giving print_message() an extra argument "const struct timeval *tv", making the condition below here be if (tv == NULL) { /* no time */ } else { /* time */ }, and leaving the gettimeofday in dbus-monitor.c.
Comment on attachment 113554 [details] [review] dbus- monitor: Keep term in 'dest' in monitor output in sync with watch expression Review of attachment 113554 [details] [review]: ----------------------------------------------------------------- OK
Comment on attachment 113555 [details] [review] dbus-monitor: Keep parameter list of method returns in --monitor mode in sync with --profile mode. Review of attachment 113555 [details] [review]: ----------------------------------------------------------------- OK
(In reply to Simon McVittie from comment #36) > I would suggest giving print_message() an extra argument "const struct > timeval *tv", making the condition below here be if (tv == NULL) { /* no > time */ } else { /* time */ }, and leaving the gettimeofday in > dbus-monitor.c. struct timeval is undefined in dbus-print-message.h|c :-(
(In reply to Ralf Habacker from comment #39) > struct timeval is undefined in dbus-print-message.h|c :-( If that's the case, how can Attachment #113553 [details] possibly work? It works in dbus-monitor, so you just need to move some inclusions into the .h - <time.h> and (for Unix only) <sys/time.h> look like likely candidates.
(In reply to Simon McVittie from comment #40) > (In reply to Ralf Habacker from comment #39) > > struct timeval is undefined in dbus-print-message.h|c :-( > > If that's the case, how can Attachment #113553 [details] possibly work? did not, because this bug is linux only, I created the first patch set on a linux only environment. Double checked cross-compiling on refactoring. > It works in dbus-monitor, so you just need to move some inclusions into the > .h - <time.h> and (for Unix only) <sys/time.h> look like likely candidates. will try.
Created attachment 113621 [details] [review] dbus-monitor: Add timestamp to --monitor mode (update 1)
Created attachment 113622 [details] [review] dbus- monitor: Keep term in 'dest' in monitor output in sync with watch expression
Created attachment 113623 [details] [review] dbus-monitor: Add timestamp to --monitor mode (update 2) do not include unrelated gcc 4.9.2 fix
Comment on attachment 113622 [details] [review] dbus- monitor: Keep term in 'dest' in monitor output in sync with watch expression Review of attachment 113622 [details] [review]: ----------------------------------------------------------------- Sure, fine
Comment on attachment 113623 [details] [review] dbus-monitor: Add timestamp to --monitor mode (update 2) Review of attachment 113623 [details] [review]: ----------------------------------------------------------------- ::: cmake/tools/CMakeLists.txt @@ +62,5 @@ > install_targets(/bin dbus-launch ) > > add_executable(dbus-monitor ${dbus_monitor_SOURCES}) > +set_target_properties(dbus-monitor PROPERTIES COMPILE_FLAGS ${DBUS_INTERNAL_CLIENT_DEFINITIONS}) > +target_link_libraries(dbus-monitor ${DBUS_INTERNAL_LIBRARIES}) It'll need the equivalent change in Autotools-land for this to not be a build regression, and dbus-monitor will be rather larger as a result. Since this dbus-monitor change is relatively low priority, I'd prefer to avoid this until I've been able to rebase Bug #83115, at which point the static vs. shared dichotomy will just go away.
Created attachment 113770 [details] [review] dbus-monitor: Add timestamp to --monitor mode (rebased)
Comment on attachment 113770 [details] [review] dbus-monitor: Add timestamp to --monitor mode (rebased) Review of attachment 113770 [details] [review]: ----------------------------------------------------------------- (Committed your other two patches) ::: cmake/tools/CMakeLists.txt @@ +62,4 @@ > install_targets(/bin dbus-launch ) > > add_executable(dbus-monitor ${dbus_monitor_SOURCES}) > +target_link_libraries(dbus-monitor ${DBUS_INTERNAL_LIBRARIES}) Now that #83115 has landed, this change is unnecessary - libdbus-1 is enough. ::: tools/dbus-monitor.c @@ +97,2 @@ > { > + printf ("%s\t%lu.%06lu", type, (unsigned long) sec, (unsigned long) usec); minor: now that we're using a directly printf'able type (long) rather than standard library types like time_t, you can use %ld and not need the casts at all @@ +141,5 @@ > + if (sec == 0) > + { > + printf("un\n"); > + return; > + } I don't think you need this error-handling any more: _dbus_get_real_time() can't fail. If it returns wrong values for sec and/or usec we might as well just print them anyway. (gettimeofday() can't fail either, according to POSIX...) ::: tools/dbus-print-message.c @@ +529,4 @@ > } > > void > +print_message (DBusMessage *message, dbus_bool_t literal, long sec, long usec) You seem to have forgotten the bit where print_message() actually does anything with sec/usec? :-) ::: tools/dbus-send.c @@ +573,4 @@ > > if (reply) > { > + print_message (reply, print_reply_literal, 0, 0); Might as well call _dbus_get_real_time() here too, since it's so easy to do now?
Comment on attachment 113555 [details] [review] dbus-monitor: Keep parameter list of method returns in --monitor mode in sync with --profile mode. applied
Created attachment 113789 [details] [review] dbus-monitor: Add timestamp to --monitor mode. From: Ralf Habacker <ralf.habacker@freenet.de> Use cross platform function _dbus_get_real_time() for fetching current time. Bug: https://bugs.freedesktop.org/show_bug.cgi?id=88896 [smcv: use %ld to avoid needing casts; reinstate printing the timestamp; libdbus-1 is sufficient now that fd.o#83115 is fixed; print timestamp for non-literal dbus-send replies too]
Created attachment 113790 [details] [review] dbus-monitor: Keep term 'dest' in --monitor output in sync with related watch expression. From: Ralf Habacker <ralf.habacker@freenet.de> [smcv: rebase onto differently indented version of previous commit]
You are going to perform the review ? I guess I should not review a patch I wrote :-)
(In reply to Ralf Habacker from comment #52) > You are going to perform the review ? I guess I should not review a patch I > wrote :-) I'm happy with those patches, if you're happy with the changes I made relative to your original versions. It's a team effort :-)
(In reply to Simon McVittie from comment #53) > (In reply to Ralf Habacker from comment #52) > > You are going to perform the review ? I guess I should not review a patch I > > wrote :-) > > I'm happy with those patches, if you're happy with the changes I made > relative to your original versions. It's a team effort :-) I'm happy with this changes :-)
Comment on attachment 113789 [details] [review] dbus-monitor: Add timestamp to --monitor mode. applied
Comment on attachment 113790 [details] [review] dbus-monitor: Keep term 'dest' in --monitor output in sync with related watch expression. applied
(In reply to Ralf Habacker from comment #54) > I'm happy with this changes :-) Merged them. I think that's all your dbus-monitor enhancements merged, and the bug report for which you initially developed them turned out to be NOTOURBUG; closing it as such.
Use of freedesktop.org services, including Bugzilla, is subject to our Code of Conduct. How we collect and use information is described in our Privacy Policy.