Include Start/End time in logs for TPC transfer #1529
Conversation
|
@abh3 - can I get you to provide advice on the best way to do timestamps here? The C code looks fine but I feel like there's some other wrapper around |
|
Hi Brian,
Oddly, we do not have canned library call for this except for
XrdSysTimer::s2hms() whioch only provides 'hh:mm:ss' given seconds (does
not provide the date). Something along the way of
char buff[10];
XrdSystimer myTime; XrdSysTimer::s2hms(myTime.Seconds, buff, sieof(buff));
I suppose the reason we didn't develop one is because everone
wanted the time reported in a slightly different way, sigh. I suppose we
can come up with a "standard" and provide a library call for that. The
most common one that xrootd uses is "yymmdd hh:mm:ss" which short and
sweet or we can make that the default and allow for different formats.
Then again there is always std::strftime.
Andy
…On Fri, 15 Oct 2021, Brian P Bockelman wrote:
@abh3 - can I get you to provide advice on the best way to do timestamps here? The C code looks fine but I feel like there's some other wrapper around `gettimeofday` in the XRootD internal libraries already...
--
You are receiving this because you were mentioned.
Reply to this email directly or view it on GitHub:
#1529 (comment)
|
|
In general, I am not in favor of putting this kind of detail in the log file (I think we already have a line with a timestamp when the transfer started and then another one when it ended). This (and the subsequent one) simply clutters the log file making even more difficult to find errors. In general, this kind of detail should be put into a HTTP-TPC specific monitoring stream (which the infrastructure can provide). While I will likely merge this, I think we really should open the discussion on how to move all of this (other failure messages) to a monitoring stream. Before I do merge, some of your thoughts on this as well, perhaps, Brian's would be appreciated. |
|
@bbockelm Can you comment on this and can we get this finally merged, so it reaches 5.4 xrootd release? |
| @@ -779,13 +786,16 @@ int TPCHandler::ProcessPullReq(const std::string &resource, XrdHttpExtReq &req) | |||
| } | |||
|
|
|||
|
|
|||
| void TPCHandler::logTransferEvent(LogMask mask, const TPCLogRecord &rec, | |||
| void TPCHandler::logTransferEvent(LogMask mask, TPCLogRecord &rec, | |||
There was a problem hiding this comment.
Changing this to non-const is bad and actually winds up not solving anything. See my comment later.
|
|
||
| connDone.tv_sec = 0; connDone.tv_usec = 0; | ||
| gettimeofday( &connDone, 0 ); | ||
| rec.eTOD = connDone; |
There was a problem hiding this comment.
No one uses eTOD outside of logging and it gets reset on every call. So, there is no reason to have it in TPCLogRecord and hence no need to make it non-const which is generally a bad idea. This is especially true because eTOD eally is misleading. This is actually the time the message was issued not when the request ended.
| std::stringstream ss; | ||
| ss << "event=" << event << ", local=" << rec.local << ", remote=" << rec.remote; | ||
| ss << ", stTime=" << rec.sTOD.tv_sec << ", enTime=" << rec.eTOD.tv_sec; |
There was a problem hiding this comment.
As per previous comment "enTime" is not really end time. It is merely the time the message was issued. So, I would suggest calling it what it really is.
| @@ -53,6 +53,8 @@ private: | |||
| streams( 1 ), | |||
| bytes_transferred( -1 ) | |||
| { | |||
| sTOD.tv_sec = 0; sTOD.tv_usec = 0; | |||
| eTOD.tv_sec = 0; eTOD.tv_usec = 0; | |||
There was a problem hiding this comment.
As per my previous comments, sTOD makes sense but eTOD as it is being haled does not.
|
OK, we have asked for changes and none were forthcoming to the point that we now have conflicts with the original pull request. I think we need to start over. So, I am closing this pull request. |
@bbockelm