Closed Bug 955606 Opened 6 years ago Closed 6 years ago

IRC ping does not properly send a timestamp

Categories

(Chat Core :: IRC, defect)

defect
Not set

Tracking

(Not tracked)

RESOLVED FIXED

People

(Reporter: clokep, Assigned: clokep)

Details

Attachments

(1 file, 5 obsolete files)

*** Original post on bio 2165 at 2013-09-10 17:38:00 UTC ***

*** Due to BzAPI limitations, the initial description is in comment 1 ***
Attached patch Patch (obsolete) — Splinter Review
*** Original post on bio 2165 as attmnt 2859 at 2013-09-10 17:38:00 UTC ***

We don't send a timestamp when sending a ping, this was last touched in http://hg.instantbird.org/instantbird/rev/f12655ab11a9, but before that we didn't seem to either.

This also modifies the command help text to match the code.
Attachment #8354629 - Flags: review?(aleth)
*** Original post on bio 2165 at 2013-09-10 17:40:46 UTC ***

Debug log:
> [2013/09/10 10:17:47] LOG   (@ prpl-irc resource:///modules/socket.jsm:239)
> Sending:
> PRIVMSG myk PING
> 
> [2013/09/10 10:17:47] DEBUG (@ prpl-irc resource:///modules/socket.jsm:457)
> onTransportStatus(STATUS_SENDING_TO)
> [2013/09/10 10:17:47] DEBUG (@ prpl-irc resource:///modules/socket.jsm:457)
> onTransportStatus(STATUS_RECEIVING_FROM)
> [2013/09/10 10:17:47] DEBUG (@ prpl-irc resource://gre/components/irc.js:659)
> :myk!myk@moz-BE33DA21.fw1.sfo1.mozilla.net PRIVMSG myk :PING
> [2013/09/10 10:17:47] DEBUG (@ prpl-irc resource:///modules/ircHandlers.jsm:95)
> {"rawMessage":":myk!myk@moz-BE33DA21.fw1.sfo1.mozilla.net PRIVMSG myk :\u0001PING\u0001","command":"PRIVMSG","params":["myk","\u0001PING\u0001"],"nickname":"myk","user":"myk","host":"moz-BE33DA21.fw1.sfo1.mozilla.net","source":"myk@moz-BE33DA21.fw1.sfo1.mozilla.net"}
> [2013/09/10 10:17:47] DEBUG (@ prpl-irc resource:///modules/ircHandlers.jsm:95)
> {"rawMessage":":myk!myk@moz-BE33DA21.fw1.sfo1.mozilla.net PRIVMSG myk :\u0001PING\u0001","command":"PRIVMSG","params":["myk","\u0001PING\u0001"],"nickname":"myk","user":"myk","host":"moz-BE33DA21.fw1.sfo1.mozilla.net","source":"myk@moz-BE33DA21.fw1.sfo1.mozilla.net","ctcp":{"rawMessage":"PING","command":"PING","param":""}}
> [2013/09/10 10:17:47] LOG   (@ prpl-irc resource://gre/modules/ircCTCP.jsm:154)
> Received PING request from myk. Sending PING response: "".
> [2013/09/10 10:17:47] LOG   (@ prpl-irc resource:///modules/socket.jsm:239)
> Sending:
> NOTICE myk PING
> 
> [2013/09/10 10:17:47] DEBUG (@ prpl-irc resource:///modules/socket.jsm:457)
> onTransportStatus(STATUS_SENDING_TO)
> [2013/09/10 10:17:47] DEBUG (@ prpl-irc resource:///modules/socket.jsm:457)
> onTransportStatus(STATUS_RECEIVING_FROM)
> [2013/09/10 10:17:47] DEBUG (@ prpl-irc resource://gre/components/irc.js:659)
> :myk!myk@moz-BE33DA21.fw1.sfo1.mozilla.net NOTICE myk :PING
> [2013/09/10 10:17:47] DEBUG (@ prpl-irc resource:///modules/ircHandlers.jsm:95)
> {"rawMessage":":myk!myk@moz-BE33DA21.fw1.sfo1.mozilla.net NOTICE myk :\u0001PING\u0001","command":"NOTICE","params":["myk","\u0001PING\u0001"],"nickname":"myk","user":"myk","host":"moz-BE33DA21.fw1.sfo1.mozilla.net","source":"myk@moz-BE33DA21.fw1.sfo1.mozilla.net"}
> [2013/09/10 10:17:47] DEBUG (@ prpl-irc resource:///modules/ircHandlers.jsm:95)
> {"rawMessage":":myk!myk@moz-BE33DA21.fw1.sfo1.mozilla.net NOTICE myk :\u0001PING\u0001","command":"NOTICE","params":["myk","\u0001PING\u0001"],"nickname":"myk","user":"myk","host":"moz-BE33DA21.fw1.sfo1.mozilla.net","source":"myk@moz-BE33DA21.fw1.sfo1.mozilla.net","ctcp":{"rawMessage":"PING","command":"PING","param":""}}
> [2013/09/10 10:17:47] WARN. (@ prpl-irc resource://gre/modules/ircCTCP.jsm:167)
> myk returned an invalid timestamp from a CTCP PING: 
> [2013/09/10 10:17:47] WARN. (@ prpl-irc: ctcpHandleMessage resource://gre/modules/ircCTCP.jsm:104)
> Unhandled CTCP message: PING
> in IRC message: :myk!myk@moz-BE33DA21.fw1.sfo1.mozilla.net NOTICE myk :PING
> [2013/09/10 10:17:47] LOG   (@ prpl-irc resource:///modules/socket.jsm:239)
> Sending:
> NOTICE myk :ERRMSG PING :Unhandled CTCP command
> 
> [2013/09/10 10:17:47] DEBUG (@ prpl-irc resource:///modules/socket.jsm:457)
> onTransportStatus(STATUS_SENDING_TO)
> [2013/09/10 10:17:48] DEBUG (@ prpl-irc resource:///modules/socket.jsm:457)
> onTransportStatus(STATUS_RECEIVING_FROM)
> [2013/09/10 10:17:48] DEBUG (@ prpl-irc resource://gre/components/irc.js:659)
> :myk!myk@moz-BE33DA21.fw1.sfo1.mozilla.net NOTICE myk :ERRMSG PING :Unhandled CTCP command
> [2013/09/10 10:17:48] DEBUG (@ prpl-irc resource:///modules/ircHandlers.jsm:95)
> {"rawMessage":":myk!myk@moz-BE33DA21.fw1.sfo1.mozilla.net NOTICE myk :\u0001ERRMSG PING :Unhandled CTCP command\u0001","command":"NOTICE","params":["myk","\u0001ERRMSG PING :Unhandled CTCP command\u0001"],"nickname":"myk","user":"myk","host":"moz-BE33DA21.fw1.sfo1.mozilla.net","source":"myk@moz-BE33DA21.fw1.sfo1.mozilla.net"}
> [2013/09/10 10:17:48] DEBUG (@ prpl-irc resource:///modules/ircHandlers.jsm:95)
> {"rawMessage":":myk!myk@moz-BE33DA21.fw1.sfo1.mozilla.net NOTICE myk :\u0001ERRMSG PING :Unhandled CTCP command\u0001","command":"NOTICE","params":["myk","\u0001ERRMSG PING :Unhandled CTCP command\u0001"],"nickname":"myk","user":"myk","host":"moz-BE33DA21.fw1.sfo1.mozilla.net","source":"myk@moz-BE33DA21.fw1.sfo1.mozilla.net","ctcp":{"rawMessage":"ERRMSG PING :Unhandled CTCP command","command":"ERRMSG","param":"PING :Unhandled CTCP command"}}
> [2013/09/10 10:17:48] WARN. (@ prpl-irc resource://gre/modules/ircCTCP.jsm:138)
> myk failed to handle CTCP message: PING :Unhandled CTCP command
> [2013/09/10 10:17:48] DEBUG (@ prpl-irc resource:///modules/socket.jsm:457)
> onTransportStatus(STATUS_RECEIVING_FROM)
> [2013/09/10 10:17:48] DEBUG (@ prpl-irc resource://gre/components/irc.js:659)
> :fabrice!fabrice@moz-DE471B8F.static.cust.telenor.com PART #macdev
> [2013/09/10 10:17:48] DEBUG (@ prpl-irc resource:///modules/ircHandlers.jsm:95)
> {"rawMessage":":fabrice!fabrice@moz-DE471B8F.static.cust.telenor.com PART #macdev","command":"PART","params":["#macdev"],"nickname":"fabrice","user":"fabrice","host":"moz-DE471B8F.static.cust.telenor.com","source":"fabrice@moz-DE471B8F.static.cust.telenor.com"}
Attached patch Patch v2 (obsolete) — Splinter Review
*** Original post on bio 2165 as attmnt 2864 at 2013-09-11 12:37:00 UTC ***

This patch also allows pinging the server.
Attachment #8354634 - Flags: review?(aleth)
Comment on attachment 8354629 [details] [diff] [review]
Patch

*** Original change on bio 2165 attmnt 2859 at 2013-09-11 12:37:59 UTC was without comment, so any subsequent comment numbers will be shifted ***
Attachment #8354629 - Attachment is obsolete: true
Attachment #8354629 - Flags: review?(aleth)
Comment on attachment 8354634 [details] [diff] [review]
Patch v2

*** Original change on bio 2165 attmnt 2864 at 2013-09-11 16:22:48 UTC ***

I don't think I ever noticed there was a /ping command!

>+        // The received timestamp is invalid

Nit: add a period.

>-    get helpString() _("command.ping", "ping"),
>+    get helpString() _("command.ping2", "ping"),

The "command.ping2" string itself is missing from this patch.
Attachment #8354634 - Flags: review?(aleth) → review-
Attached patch Patch v3 (obsolete) — Splinter Review
*** Original post on bio 2165 as attmnt 2866 at 2013-09-11 16:46:00 UTC ***

(In reply to comment #3)
> Comment on attachment 8354634 [details] [diff] [review] (bio-attmnt 2864) [details]
> Patch v2
> 
> I don't think I ever noticed there was a /ping command!
Well it apparently didn't work! :)

> >-    get helpString() _("command.ping", "ping"),
> >+    get helpString() _("command.ping2", "ping"),
> 
> The "command.ping2" string itself is missing from this patch.
This string doesn't exist anymore, I ended up keeping the original (see the first patch if you want to see where it came from).

Also this is untested, I need to test it before we check it in.
Attachment #8354636 - Flags: review?(aleth)
Comment on attachment 8354634 [details] [diff] [review]
Patch v2

*** Original change on bio 2165 attmnt 2864 at 2013-09-11 16:46:56 UTC was without comment, so any subsequent comment numbers will be shifted ***
Attachment #8354634 - Attachment is obsolete: true
Comment on attachment 8354636 [details] [diff] [review]
Patch v3

*** Original change on bio 2165 attmnt 2866 at 2013-09-11 16:52:06 UTC ***

r+ for the code, as long as it is tested before checkin and no new problems show up ;)
Attachment #8354636 - Flags: review?(aleth) → review+
Whiteboard: [checkin-needed]
Whiteboard: [checkin-needed]
Comment on attachment 8354636 [details] [diff] [review]
Patch v3

*** Original change on bio 2165 attmnt 2866 at 2013-10-01 00:12:37 UTC ***

I remember Florian being uncomfortable with this patch because we use a time that is sent to us from another user instead of using random-ish IDs and keeping a log of when we sent things. I'm giving him a chance to shoot this down now! ;)
Attachment #8354636 - Flags: review?(florian)
Comment on attachment 8354636 [details] [diff] [review]
Patch v3

*** Original change on bio 2165 attmnt 2866 at 2013-10-03 19:38:21 UTC ***

new Date(String(Date.now())) in my error console returns "Invalid Date", so either I missed something, or the patch doesn't work.

Giving to the new Date() constructor a random string coming from the network makes me feel slightly uncomfortable. I think I would really prefer |new Date(parseInt(aMessage.params[0], 10))|

Nit: aMessage.params[0] is used several times in the "PONG" method. Maybe use an intermediary variable?

It's not clear to me why we are displaying in seconds a value that we receive in ms. And I suspect PluralForm expects an integer, and may not have a well defined behavior for other numbers.

I also wonder if we should avoid displaying results if the value is crazy (ie. if |Date.now() - sentTime| is less than 0, or more than a minute).
Attachment #8354636 - Flags: review?(florian) → review-
Attached patch Patch v4 (obsolete) — Splinter Review
*** Original post on bio 2165 as attmnt 2959 at 2013-10-16 13:47:00 UTC ***

This patch is tested and works. Thanks for the feedback.
Attachment #8354740 - Flags: review?(aleth)
Comment on attachment 8354636 [details] [diff] [review]
Patch v3

*** Original change on bio 2165 attmnt 2866 at 2013-10-16 13:47:15 UTC was without comment, so any subsequent comment numbers will be shifted ***
Attachment #8354636 - Attachment is obsolete: true
Comment on attachment 8354740 [details] [diff] [review]
Patch v4

*** Original change on bio 2165 attmnt 2959 at 2013-10-18 11:14:58 UTC was without comment, so any subsequent comment numbers will be shifted ***
Attachment #8354740 - Flags: review?(aleth) → review+
Comment on attachment 8354740 [details] [diff] [review]
Patch v4

*** Original change on bio 2165 attmnt 2959 at 2013-10-18 11:23:31 UTC ***

>-#   #2 is the delay (in seconds).
>-ctcp.ping=Ping reply from %1$S in #2 second.;Ping reply from %1$S in #2 seconds.
>+#   #2 is the delay (in milliseconds).
>+ctcp.ping=Ping reply from %1$S in #2 millisecond.;Ping reply from %1$S in #2 milliseconds.

Changing the string meaning without changing the id won't do.

Apart from that, I dislike the code duplication but I'm willing to pretend I haven't seen it :).

From a quick look I don't have other comments on the rest of the code, and I'm happy to go with aleth's review for it.
Attachment #8354740 - Flags: review-
Attached patch Patch v5 (obsolete) — Splinter Review
*** Original post on bio 2165 as attmnt 2964 at 2013-10-18 11:39:00 UTC ***

Remove the code duplication (and changes the ID of the string).
Attachment #8354744 - Flags: review?(aleth)
Comment on attachment 8354740 [details] [diff] [review]
Patch v4

*** Original change on bio 2165 attmnt 2959 at 2013-10-18 11:39:42 UTC was without comment, so any subsequent comment numbers will be shifted ***
Attachment #8354740 - Attachment is obsolete: true
Comment on attachment 8354744 [details] [diff] [review]
Patch v5

*** Original change on bio 2165 attmnt 2964 at 2013-10-18 11:40:39 UTC was without comment, so any subsequent comment numbers will be shifted ***
Attachment #8354744 - Flags: review?(florian)
Comment on attachment 8354744 [details] [diff] [review]
Patch v5

*** Original change on bio 2165 attmnt 2964 at 2013-10-18 11:49:32 UTC ***

>-# LOCALIZATION NOTE (ctcp.ping): Semi-colon list of plural forms.
>+# LOCALIZATION NOTE (message.ping): Semi-colon list of plural forms.
> #  See: http://developer.mozilla.org/en/docs/Localization_and_Plurals
>-#   %1$S is the nickname of the user who was pinged.
>-#   #2 is the delay (in seconds).
>-ctcp.ping=Ping reply from %1$S in #2 second.;Ping reply from %1$S in #2 seconds.
>+#   %1$S is the nickname of the user or the server that was pinged.
>+#   #2 is the delay (in milliseconds).
>+message.ping=Ping reply from %1$S in #2 millisecond.;Ping reply from %1$S in #2 milliseconds.

As you've renamed it, please move this to the block where all the other message.* strings live.

>diff --git a/chat/protocols/irc/ircCTCP.jsm b/chat/protocols/irc/ircCTCP.jsm
>@@ -148,40 +143,23 @@ var ctcpBase = {
>     // Used to measure the delay of the IRC network between clients.
>     "PING": function(aMessage) {
>       if (aMessage.command == "PRIVMSG") {
>         // PING timestamp
>         // Received PING request, send PING response.
>         this.LOG("Received PING request from " + aMessage.nickname +
>                  ". Sending PING response: \"" + aMessage.ctcp.param + "\".");
>         this.sendCTCPMessage("PING", aMessage.ctcp.param, aMessage.nickname,
>-                              true);
>+                             true);
>+        return true;
>       }
>       else {
>         // PING timestamp
>-        // Received PING response, display to the user.

You can move the duplicate // PING timestamp comment above the if clause.
Attachment #8354744 - Flags: review?(aleth) → review-
Comment on attachment 8354744 [details] [diff] [review]
Patch v5

*** Original change on bio 2165 attmnt 2964 at 2013-10-18 12:06:17 UTC ***

Trivial comment: I think it would be better if the name of the new method was an 'action' (eg. handlePingReply).

I agree with aleth's comments, and don't need to review the next version. Thanks for the update! :)
Attachment #8354744 - Flags: review?(florian) → feedback+
Attached patch Patch v6Splinter Review
*** Original post on bio 2165 as attmnt 2965 at 2013-10-18 22:00:00 UTC ***

Hopefully the last version of this patch!
Attachment #8354746 - Flags: review?(aleth)
Comment on attachment 8354744 [details] [diff] [review]
Patch v5

*** Original change on bio 2165 attmnt 2964 at 2013-10-18 22:00:41 UTC was without comment, so any subsequent comment numbers will be shifted ***
Attachment #8354744 - Attachment is obsolete: true
Comment on attachment 8354746 [details] [diff] [review]
Patch v6

*** Original change on bio 2165 attmnt 2965 at 2013-10-19 10:23:19 UTC ***

Thanks!
Attachment #8354746 - Flags: review?(aleth) → review+
Whiteboard: [checkin-needed]
*** Original post on bio 2165 at 2013-10-19 22:49:09 UTC ***

http://hg.instantbird.org/instantbird/rev/50e4ab9d0d94
Status: ASSIGNED → RESOLVED
Closed: 6 years ago
Resolution: --- → FIXED
Whiteboard: [checkin-needed]
Target Milestone: --- → 1.5
You need to log in before you can comment on or make changes to this bug.