odd lines in my log file

[Dan99]

In my Apache logs, every once in a while I see a really odd string of lines. like this

::1 - - [01/Jun/2014:05:24:57 -0500] "OPTIONS * HTTP/1.0" 200 - "-"
::1 - - [01/Jun/2014:05:24:58 -0500] "OPTIONS * HTTP/1.0" 200 - "-"
::1 - - [01/Jun/2014:05:24:59 -0500] "OPTIONS * HTTP/1.0" 200 - "-"
::1 - - [01/Jun/2014:05:25:00 -0500] "OPTIONS * HTTP/1.0" 200 - "-"

Sometimes one such line, and sometimes ten in succession (spaced at one second intervals, as above). What are these? Who/what is making them? They seem to happen at random times, maybe very roughly once a day, EXCEPT I think I always see such a string after my logfile is turned over (such that these are the first lines in the new logfile). That would suggest that it is my system (Mac 10.8.5/Apache 2.2) doing it.

These lines are not causing any trouble, but in my efforts to understand my log file, these are sure pretty strange.

Advice, please?

[phranque]

http://www.w3.org/Protocols/rfc2616/rfc2616-sec9.html#sec9.2

The OPTIONS method represents a request for information about the communication options available on the request/response chain identified by the Request-URI. This method allows the client to determine the options and/or requirements associated with a resource, or the capabilities of a server, without implying a resource action or initiating a resource retrieval. Responses to this method are not cacheable.
...
If the Request-URI is an asterisk ("*"), the OPTIONS request is intended to apply to the server in general rather than to a specific resource. Since a server's communication options typically depend on the resource, the "*" request is only useful as a "ping" or "no-op" type of method; it does nothing beyond allowing the client to test the capabilities of the server. For example, this can be used to test a proxy for HTTP/1.1 compliance (or lack thereof).
...
A 200 response SHOULD include any header fields that indicate optional features implemented by the server and applicable to that resource (e.g., Allow), possibly including extensions not defined by this specification. The response body, if any, SHOULD also include information about the communication options.

[Dan99]

Thanks. But my question is not quite answered.

So it is my server doing it? The "OPTIONS request is intended to apply to the server in general" means the request is coming from the server? Or that it's someone else asking the server? "It does nothing beyond allowing the client to test the capabilities of the server." Fine. Who's the client?

Aside from log rotation, it seems to happen quite randomly, so it is unlikely to be something that is cron'ed. Sort of makes sense that my server might want to test itself occasionally, but randomly, and sometimes multiple times?

[lucy24]

::1

Did you obfuscate here, or is this the literal text of the logs? Without knowing the source IP, there's no way of knowing who's responsible.

:: detour to check something ::

Yup, thought I'd seen that.

76.9.62.abc - - [18/Nov/2013:04:20:42 -0800] "OPTIONS / HTTP/1.1" 200 311 "-" "Microsoft Office Protocol Discovery" 

(with more that I've snipped)
and, a few days earlier,

79.49.110.abc - - [03/Nov/2013:09:57:09 -0800] "OPTIONS /fonts/images/keyboards/ HTTP/1.1" 200 285 "-" "Microsoft Office Protocol Discovery" 

I can't find the thread where I asked about it, but I think someone explained to me that it involves links within a MS Office document. (I have no idea why the later and longer visit was-- plausibly-- from Iqaluit, while the earlier one appears to have been in England.)

:: further detour ::

[webmasterworld.com...]
citing a still earlier
[webmasterworld.com...]
Both of those were before my time but may still shed some light. :(

[Dan99]

Hey, I'm serious. No obfuscating. That's the literal line of text from my log. If I got a line of text starting with xxx.yyy.bb.ccc, I'd sure know who was doing it!

Without knowing the source IP, there's no way of knowing who's responsible.

Which is why I'm here asking.

So what does MS Office have to do with it? Those lines you posted don't look like the lines that I posted, except for the OPTIONS request. I get OPTIONS request from various IPs, and I don't pay any attention to them. The issue here is ... who is "::1"?

[lucy24]

So the business with OPTIONS is a red herring and you want to know what
::1
means? Well, NOW you say so :(

That would suggest that it is my system (Mac 10.8.5/Apache 2.2) doing it.

Beyond that, what is your system? Production server, pseudo-server, local hosting of some variety? Primarily: Is it your own server, with your own log settings? What exactly do those settings say, and is any aspect of the quoted items -- other than the ::1 part -- different from normal?

I think I always see such a string after my logfile is turned over

How far back do your archives go? This is worth confirming.

:: thinking ::

^\d+\.\d+\.\d+\.\d+.+\n::1

to find non-initial occurrences. Multi-file search in TextWrangler or whatever you've got handy.

[phranque]

::1 is an alternate representation of the localhost (loopback) address in IPv6, 0:0:0:0:0:0:0:1, so this is coming from your own server.

most likely it's your apache server checking on its child processes.

http://wiki.apache.org/httpd/InternalDummyConnection [wiki.apache.org]:

When the Apache HTTP Server manages its child processes, it needs a way to wake up processes that are listening for new connections. To do this, it sends a simple HTTP request back to itself. This request will appear in the access_log file with the remote address set to the loop-back interface (typically 127.0.0.1 or ::1 if IPv6 is configured). If you log the User-Agent string (as in the combined log format), you will see the server signature followed by "(internal dummy connection)" on non-SSL servers. During certain periods you may see up to one such request for each httpd child process.

[Dan99]

Thank you phranque. That's very helpful. Especially that ::1 is an alternate representation of the localhost (loopback) address. So at least we know who's doing it!

I guess I have to wonder why these child process management requests are very random, and sometimes happen in bunches.

Lucy, what I originally asked is that I wanted to know what

::1 - - [01/Jun/2014:05:24:57 -0500] "OPTIONS * HTTP/1.0" 200 - "-"

meant. I didn't know what ANY of it meant.

[Dan99]

P.S. I said what my system was. It is Mac OS10.8.5/Apache 2.2. It happens to be my own server with my own log settings. It's sitting on my desk.

[lucy24]

I didn't know what ANY of it meant.

Well, you knew what

[01/Jun/2014:05:24:57 -0500]

meant. It means your server either is, or wants you to think it is, located in the Eastern time zone (or, more likely, Central time zone with DST). You also knew what

HTTP/1.0" 200

meant -- and now, looking at it more closely, the immediately following bit

HTTP/1.0" 200 - "-"

is a bit of a giveaway, as it implies that the server sent out nothing (hence no numbers in the second slot). D'oh!

[Dan99]

Geez. Please chill.

I knew what bits and pieces of the lines meant that I sent, but I thought a proper answer deserved quoting the whole line. I confess I knew exactly what the time and time zone meant to me. I just didn't know what the whole line meant to my system, and what it meant was happening to it.

I didn't realize that it was so hard to ask a simple question.