[Monotone-devel] Improving the note_netsync_* hooks for logging

[Timothy Brownawell]

There's a new branch nvm.tbrownaw.netsync-note-hooks that changes the
note_netsync_* hooks slightly, as well as some supporting changes in
netsync.cc .

The most noticable change to the hooks is that note_netsync_start is now
called at the beginning of the connection, and that note_netsync_start
and note_netsync_end are called even if nothing was transferred.

The most visible supporting change is that session::error() takes a new
argument, for a numeric error code. This is saved, and also stringified
and prepended to the error netcmd, and (if present) is decoded on the
other side and saved there as well. This does not break compatibility;
older clients will just see a 3-digit error code at the beginning of any
errors received.

The reason for this is that the error code is passed to the
note_netsync_end hook, so it can differentiate between successful
connections, interrupted connections, connections that failed due to
permissions, or connections that failed some other way.


Are there objections to doing this? Is this general way of doing it
sane, or should it be done differently?



Currently it uses these, somewhat based on the HTTP codes:
  const static int no_error = 200;
  const static int bad_request = 400;
  const static int protocol_error = 401;
  const static int permission_error = 403;
  //const static int other_error = 500;
  const static int connection_broken = 504;


At the end of this mail are some sample hooks that will print lines like
this for the server:

127.0.0.1:36573 "address@hidden" [2006-10-24T14:33:42
2006-10-24T14:38:48] sync "*" "" 504 479397:12608180 0:9675 0:2412 0:31

127.0.0.1:42102 "address@hidden" [2006-10-24T14:38:51
2006-10-24T14:51:59] sync "*" "" 504 916978:21702890 0:15499 0:3849 0:31

127.0.0.1:56109 "address@hidden" [2006-10-24T14:52:04
2006-10-24T14:52:05] sync "*" "" 403 328:318 0:0 0:0 0:0

127.0.0.1:56110 "" [2006-10-24T14:52:14 2006-10-24T15:03:27] pull "*" ""
200 1165989:18334344 0:10878 0:2706 0:6

127.0.0.1:46195 "" [2006-10-24T15:05:11 2006-10-24T15:05:15] pull "*" ""
200 1794:1860 0:0 0:0 0:0




function note_netsync_start(session_id, my_role, sync_type, remote_host,
                            remote_keyname, includes, excludes)
  if netsync_info == nil then netsync_info = {} end
  if sync_type == 1 then sync_type = "push"
  elseif sync_type == 2 then sync_type = "pull"
  elseif sync_type == 3 then sync_type = "sync" end
  netsync_info[session_id] =
    {
      includes = includes,
      excludes = excludes,
      host = remote_host,
      key = remote_keyname,
      branches = {},
      start_time = os.time(),
      my_role = my_role,
      type = sync_type
    }
end

function note_netsync_end(session_id, status,
                          bytes_in, bytes_out,
                          certs_in, certs_out,
                          revs_in, revs_out,
                          keys_in, keys_out)
  local tbl = netsync_info[session_id]
  local fmt = "%Y-%m-%dT%H:%M:%S"

  if tbl.my_role == "server" then
   local str = '%s "%s" [%s %s] %s "%s" "%s" %s %s:%s %s:%s %s:%s %s:%s'
    str = string.format(str,
                        tbl.host, tbl.key,
                        os.date(fmt, tbl.start_time), os.date(fmt),
                        tbl.type,
                        tbl.includes, tbl.excludes,
                        status,
                        bytes_in, bytes_out,
                        certs_in, certs_out,
                        revs_in, revs_out,
                        keys_in, keys_out)
    print(str)
  end
  netsync_info[session_id] = nil
end


-- 
Timothy

Free (experimental) public monotone hosting: http://mtn-host.prjek.net