Ticket #393 (closed enhancement: complete)

Opened 3 years ago

Last modified 3 years ago

Marking places where logging would happen

Reported by: vorner Owned by: vorner
Priority: medium Milestone:
Component: Unclassified Keywords:
Cc: CVSS Scoring:
Sensitive: no Defect Severity:
Sub-Project: Feature Depending on Ticket:
Estimated Difficulty: 0.0 Add Hours to Ticket: 0
Total Hours: 0 Internal?: no


I created a isc::log::dlog function to mark places where logging should happen. It takes only the message and should be replaced once we have real logging framework. It is function, not a comment as proposed initially, because it a) prints the text, so it saves typing, b) compiler will find the places more reliably when the function is removed.

I hope I did understand the goal of the task properly, since it took me a lot less time than the estimate. I hope I didn't forget some place in the recursor, but only recursor-specific code seems to live in src/bin/recurse.

It is in the branches/vorner-recursor-dummylog, revisions r3356-r3363.

I do not think there should be a changelog entry, as this is an internal change without behaviour change. If you do not agree, I'll think of some.

Change History

comment:1 Changed 3 years ago by vorner

  • Owner set to UnAssigned
  • Status changed from new to reviewing

comment:2 Changed 3 years ago by vorner

I found another place accidentally, so add r3394 to the changes to review as well, please.

comment:3 Changed 3 years ago by jreed

It should have a ChangeLog? entry.

comment:4 Changed 3 years ago by vorner

Ok, in that case, how about this one?

[func]       vorner
New temporary logging function available in isc::log. It is used by b10-recurse.

comment:5 Changed 3 years ago by stephen

  • Owner changed from UnAssigned to vorner

Only when reviewing I discovered how difficult it is to decide where logging should be without knowing the details of the framework and in particular, what granularity you will be logging.

I have assumed in this review that ultimately there will be both high-level event logging ("server started" etc) and some debug logging (tracing queries), and that we need to mark both types of log entries.

Using dlog to mark the log messages is a good idea - it does provide an easy way of turning basic logging on which will be useful in development.

I think that what is being queried for (qname/qtype/qclass) would also be relevant here in addition to the nameserver to which the query is being sent. It will help to trace the upstream query chain for a particular inbound request.

However, given that what happens is that a UDPquery object is instantiated and posted, it might be better to put the log message into UDPquery itself; in particular, add a log message before the asynch_send_to call and one after the async_receive_from call. That way we can trace both the query sent and the fact that a response was received. (The same goes for TCPQuery.)

Logging the command line the server was started with might be useful.

In "Recursor::processMessage", there is a block that is commented as "Perform further protocol-level validation", only some of the checks result in a log message. Either all should or none should.

Other points that are noted here for reference, but do not need changing until the logging framework is complete are:

The "Adding RRset to message" message would benefit from including the section to which the RRset is being added and the type or RRset being added.

"unsupported opcode" - it would be helpful to know what opcode was received.

comment:6 Changed 3 years ago by vorner

  • Owner changed from vorner to stephen

I updated the code according to the review. There are two more commits on the branch. However, there's no TCPQuery yet.

How about now? And, I guess it should be synced with #327 first and more logging added into the newly introduced code. Do you agree?

comment:7 Changed 3 years ago by stephen

  • Owner changed from stephen to vorner

Seems OK. Please sync with #327.

comment:8 Changed 3 years ago by vorner

  • Owner changed from vorner to stephen

It is synced. I hopefully added logging to the 2 or 3 new places. Do you think it can be merged now?

Thank you

comment:9 Changed 3 years ago by stephen

  • Owner changed from stephen to vorner

Yes, please merge this with #327 and close this ticket. We'll have to go over it again when the logging interface is properly defined, so if anything has been missed we can add it then.

Tickets #401 and #402 still need to be merged with #327, after which we can do a final review of that branch and merge #327 back with the trunk.

comment:10 Changed 3 years ago by vorner

  • Status changed from reviewing to closed
  • Resolution set to complete

Thanks, merged, closing.

Note: See TracTickets for help on using tickets.