Mailing List Archive

On Mon, Aug 28, 2017 at 9:21 AM, John Cherouvim <jc@eworx.gr> wrote:
> In /var/log/varnish/ I have some old varnish logs, produced by varnishlog
> which, due to logrotated, are now in gz format:
>
>> -rw-r--r-- 1 varnishlog varnish 143068514 Aug 10 23:59
>> varnish.log.2017-08-10.gz
>> -rw-r--r-- 1 varnishlog varnish 156373518 Aug 11 23:59
>> varnish.log.2017-08-11.gz
>> -rw-r--r-- 1 varnishlog varnish 134255825 Aug 12 23:59
>> varnish.log.2017-08-12.gz
>> -rw-r--r-- 1 varnishlog varnish 156992529 Aug 13 23:59
>> varnish.log.2017-08-13.gz
>> -rw-r--r-- 1 varnishlog varnish 176751837 Aug 14 23:59
>> varnish.log.2017-08-14.gz
>> -rw-r--r-- 1 varnishlog varnish 155948012 Aug 16 00:01
>> varnish.log.2017-08-15.gz
>> -rw-r--r-- 1 varnishlog varnish 169977134 Aug 17 00:01
>> varnish.log.2017-08-16.gz
>
> I've extracted those in another location and tried to view them via
> head/more but they look binary.
>
> So I then tried opening them with varnishlog using either of the following
> parameters:
>
>> [-N filename] VSM filename
>> [-r filename] Binary file input
>
> But that didn't work giving me:
>
>> Can't open log - retrying for 5 seconds
>
> and:
>
>> Can't open log file (Not a VSL file:
>
> Any idea on how can I inspect those historical logs from varnish?

What is the output of `file some_extracted_file`?

They are probably ascii dump of the logs if varnishlog is complaining.

Dridi

_______________________________________________
varnish-misc mailing list
varnish-misc@varnish-cache.org
https://www.varnish-cache.org/lists/mailman/listinfo/varnish-misc

> What is the output of `file some_extracted_file`?

It's "data".

The output of head looks like this:

> )(?86 boot.www0P)(?Beresp: 1503698757.375353 119.998656
119.998480-P)(?Error: 1503698757.375362 119.998665 0.000009
))(?HTTP/1.1*)(?503+)(?Service Unavailable+)(?Backend fetch
failed$,)(?Date: Fri, 25 Aug 2017 22:05:57 GMT,)(?Server:
Varnish<)(?BACKEND_ERROR',)(?Content-Type: text/html;
charset=utf-8,)(?Retry-After: >)(?deliverO)(?malloc Transient
1)(?HTTP/1.12)(?5033)(?Backend fetch failed$4)(?Date: Fri, 25 Aug 2017
22:05:57 GMT4)(?Server: Varnish'4)(?Content-Typ)(?284S)(?292 0 292 0 0
0M)(?L)(@req 2631964 rxreq+P)(@Start: 1503698637.376097 0.000000
0.000000)P)(@Req: 1503698637.376097 0.000000 0.000000?)(@54.162.61.100
34377)(@GETg)(@/en/ )(@HTTP/1.1)(@Connection: closeG)(@User-Agent:
Flamingo_SearchEngine (+http://www.flamingosearch.com/bot))(@Host:
www.example.com)(@X-Forwarded-For:
54.111.111.111<)(@RECV>)(@hash<)(@HASH>)(@lookup<)(@MISS>)(@fetchK)(@bereq
2631966 fetch/P)(@Fetch: 1503698757.439626 120.063529 120.063529
)(@HTTP/1.1)(@503Backend fetch failed$)(@Date: Fri, 25 Aug 2017 22:05:57
GMT)(@Server: Varnish')(@Content-Type: text/html;
charset=utf-8)(@Retry-After: 5)(@X-Varnish: 2631965)(@Age: 0)(@Via: 1.1
varnish-v<)(@DELIVER)(@Via: 1.1 varnish-v>)(@deliver/P)(@Process:
1503698757.439677 120.063580 0.000051)(@Content-Length: 284...



Dridi Boukelmoune wrote:
> On Mon, Aug 28, 2017 at 9:21 AM, John Cherouvim <jc@eworx.gr> wrote:
>
>> In /var/log/varnish/ I have some old varnish logs, produced by varnishlog
>> which, due to logrotated, are now in gz format:
>>
>>
>>> -rw-r--r-- 1 varnishlog varnish 143068514 Aug 10 23:59
>>> varnish.log.2017-08-10.gz
>>> -rw-r--r-- 1 varnishlog varnish 156373518 Aug 11 23:59
>>> varnish.log.2017-08-11.gz
>>> -rw-r--r-- 1 varnishlog varnish 134255825 Aug 12 23:59
>>> varnish.log.2017-08-12.gz
>>> -rw-r--r-- 1 varnishlog varnish 156992529 Aug 13 23:59
>>> varnish.log.2017-08-13.gz
>>> -rw-r--r-- 1 varnishlog varnish 176751837 Aug 14 23:59
>>> varnish.log.2017-08-14.gz
>>> -rw-r--r-- 1 varnishlog varnish 155948012 Aug 16 00:01
>>> varnish.log.2017-08-15.gz
>>> -rw-r--r-- 1 varnishlog varnish 169977134 Aug 17 00:01
>>> varnish.log.2017-08-16.gz
>>>
>> I've extracted those in another location and tried to view them via
>> head/more but they look binary.
>>
>> So I then tried opening them with varnishlog using either of the following
>> parameters:
>>
>>
>>> [-N filename] VSM filename
>>> [-r filename] Binary file input
>>>
>> But that didn't work giving me:
>>
>>
>>> Can't open log - retrying for 5 seconds
>>>
>> and:
>>
>>
>>> Can't open log file (Not a VSL file:
>>>
>> Any idea on how can I inspect those historical logs from varnish?
>>
>
> What is the output of `file some_extracted_file`?
>
> They are probably ascii dump of the logs if varnishlog is complaining.
>
> Dridi
>
> _______________________________________________
> varnish-misc mailing list
> varnish-misc@varnish-cache.org
> https://www.varnish-cache.org/lists/mailman/listinfo/varnish-misc
>


_______________________________________________
varnish-misc mailing list
varnish-misc@varnish-cache.org
https://www.varnish-cache.org/lists/mailman/listinfo/varnish-misc

On Mon, Aug 28, 2017 at 2:18 PM, John Cherouvim <jc@eworx.gr> wrote:
>> What is the output of `file some_extracted_file`?
>
> It's "data".

Ouch, what is the output of `hexdump -C some_extracted_file | head -1` then?

Dridi

_______________________________________________
varnish-misc mailing list
varnish-misc@varnish-cache.org
https://www.varnish-cache.org/lists/mailman/listinfo/varnish-misc

> 00000000 12 00 00 4c 63 b6 4e 40 72 65 71 20 35 31 35 38
|...Lc.N@req 5158|

Dridi Boukelmoune wrote:
> On Mon, Aug 28, 2017 at 2:18 PM, John Cherouvim <jc@eworx.gr> wrote:
>
>>> What is the output of `file some_extracted_file`?
>>>
>> It's "data".
>>
>
> Ouch, what is the output of `hexdump -C some_extracted_file | head -1` then?
>
> Dridi
>
>


_______________________________________________
varnish-misc mailing list
varnish-misc@varnish-cache.org
https://www.varnish-cache.org/lists/mailman/listinfo/varnish-misc

On Mon, Aug 28, 2017 at 3:05 PM, John Cherouvim <jc@eworx.gr> wrote:
>> 00000000 12 00 00 4c 63 b6 4e 40 72 65 71 20 35 31 35 38 |...Lc.N@req
>> 5158|

This is weird, you are missing 4 magic bytes at the beginning of the
file. It could be that the logrotate integration is fundamentally
broken.

Does this work for you?

$ (printf 'VSL\0' | cat - some_extracted_file) >some_fixed_file
$ varnishlog -r some_fixed_file

Dridi

_______________________________________________
varnish-misc mailing list
varnish-misc@varnish-cache.org
https://www.varnish-cache.org/lists/mailman/listinfo/varnish-misc

Yes, that worked. I am sorry for the confusion but, yes, it seems that
my modified logrotate configuration broke the log:

> /var/log/varnish/varnish.log {
> compress
> compresscmd /bin/gzip
> uncompresscmd /bin/gunzip
> compressext gz
> dateext
> dateformat .%Y-%m-%d.
> daily
> rotate 7
> ifempty
> missingok
> copytruncate
> }


Will fix that. Thanks for your time.




Dridi Boukelmoune wrote:
> On Mon, Aug 28, 2017 at 3:05 PM, John Cherouvim <jc@eworx.gr> wrote:
>
>>> 00000000 12 00 00 4c 63 b6 4e 40 72 65 71 20 35 31 35 38 |...Lc.N@req
>>> 5158|
>>>
>
> This is weird, you are missing 4 magic bytes at the beginning of the
> file. It could be that the logrotate integration is fundamentally
> broken.
>
> Does this work for you?
>
> $ (printf 'VSL\0' | cat - some_extracted_file) >some_fixed_file
> $ varnishlog -r some_fixed_file
>
> Dridi
>


_______________________________________________
varnish-misc mailing list
varnish-misc@varnish-cache.org
https://www.varnish-cache.org/lists/mailman/listinfo/varnish-misc

On Mon, Aug 28, 2017 at 4:39 PM, John Cherouvim <jc@eworx.gr> wrote:
> Yes, that worked. I am sorry for the confusion but, yes, it seems that my
> modified logrotate configuration broke the log:
>
>> /var/log/varnish/varnish.log {
>> compress
>> compresscmd /bin/gzip
>> uncompresscmd /bin/gunzip
>> compressext gz
>> dateext
>> dateformat .%Y-%m-%d.
>> daily
>> rotate 7
>> ifempty
>> missingok
>> copytruncate
>> }
>
>
> Will fix that. Thanks for your time.

I'm not sure _your_ logrotate config is to blame, but glad to see it
worked out. I suppose this is something off, you are not sending the
SIGHUP signal (see man varnishlog).

Cheers

_______________________________________________
varnish-misc mailing list
varnish-misc@varnish-cache.org
https://www.varnish-cache.org/lists/mailman/listinfo/varnish-misc