You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@trafficserver.apache.org by feng D <fe...@gmail.com> on 2016/01/16 11:22:01 UTC

Do not use the disks

Hi:

     I use the traffic server as the Reverse Proxy with four disks as the
cache. But I found that traffic server not use the disks.  The log in
diags.log has not 'cache enabled' and not 'cache disabled'.

     The version is 4.2.2.


       Who can help me.



                            Thanks!!!!

I open cache_init debug then the diags looks like this:
***********************************************************************
[Jan 16 18:02:52.407] {0x7fade53d57e0} STATUS: opened
/disk/ssd1/logs/trafficserver/diags.log
[Jan 16 18:02:52.407] {0x7fade53d57e0} NOTE: updated diags config
[Jan 16 18:02:54.418] Server {0x7fade53d57e0} NOTE: cache clustering
disabled
[Jan 16 18:02:54.419] Server {0x7fade53d57e0} WARNING: no interim disks
specified in proxy.config.cache.interim.storage:
[Jan 16 18:02:54.422] Server {0x7fade53d57e0} NOTE: ip_allow.config
updated, reloading
[Jan 16 18:02:54.426] Server {0x7fade53d57e0} NOTE: cache clustering
disabled
[Jan 16 18:02:54.427] Server {0x7fade53d57e0} NOTE: logging initialized[3],
logging_mode = 1
[Jan 16 18:02:54.428] Server {0x7fade53d57e0} WARNING: unable to open cache
disk(s): InterimCache Cache Disabled
[Jan 16 18:02:54.428] Server {0x7fade53d57e0} WARNING: [ReverseProxy]
Unable to determine default redirect url for "referer" filter.
[Jan 16 18:02:54.434] Server {0x7fade53d57e0} NOTE: traffic server running
[Jan 16 18:02:54.465] Server {0x7faddfdb5700} NOTE: reading directory
'/dev/sde 368640:244189278'
[Jan 16 18:02:54.465] Server {0x7faddfeb6700} NOTE: reading directory
'/dev/sdd 368640:244189278'
[Jan 16 18:02:54.465] Server {0x7fade53d57e0} NOTE: reading directory
'/dev/sdb 368640:244189278'
[Jan 16 18:02:54.465] Server {0x7faddfcb4700} NOTE: reading directory
'/dev/sdc 368640:244189278'
[Jan 16 18:02:54.469] Server {0x7faddfeb6700} NOTE: using directory A for
'/dev/sdd 368640:244189278'
[Jan 16 18:02:54.469] Server {0x7faddfcb4700} NOTE: using directory A for
'/dev/sdc 368640:244189278'
[Jan 16 18:02:54.479] Server {0x7faddfdb5700} NOTE: using directory B for
'/dev/sde 368640:244189278'
[Jan 16 18:02:54.489] Server {0x7fade53d57e0} NOTE: using directory A for
'/dev/sdb 368640:244189278'
[Jan 16 18:02:57.403] Server {0x7faddfdb5700} NOTE: recovery clearing
offsets [785550164480, 785653652992] sync_serial 10847 next 10848
***********************************************************************



The tail of traffic.out is like this:
*********************************************************************************************************
[Jan 16 18:02:54.419] Server {0x7fade53d57e0} DEBUG: (cache_init)
Store::read_config: "/dev/sde
"
[Jan 16 18:02:54.419] Server {0x7fade53d57e0} DEBUG: (cache_init)
Store::read_config - ns = NEW (new Span); ns->init("/dev/sde",-1),
ns->vol_num=0
[Jan 16 18:02:54.419] Server {0x7fade53d57e0} DEBUG: (cache_init)
Span::init("/dev/sde",-1)
[Jan 16 18:02:54.419] Server {0x7fade53d57e0} DEBUG: (cache_init)
Span::init - S_IFBLK - devnum = 2112
[Jan 16 18:02:54.419] Server {0x7fade53d57e0} DEBUG: (cache_init)
Span::init - socketManager.open("/dev/sde", O_RDONLY) = 11
[Jan 16 18:02:54.419] Server {0x7fade53d57e0} DEBUG: (cache_init)
Span::init - /dev/sde hw_sector_size=512 is_disk=1 adjusted_sec=1
[Jan 16 18:02:54.419] Server {0x7fade53d57e0} DEBUG: (cache_init)
Span::init - /dev/sde alignment = 0
[Jan 16 18:02:54.419] Server {0x7fade53d57e0} DEBUG: (cache_init)
Span::init physical sectors 3907029168 total size 2000398934016 geometry
size 2000398934016 store blocks 244189323
[Jan 16 18:02:54.419] Server {0x7fade53d57e0} DEBUG: (cache_init)
Store::read_config: "/dev/sdc
"
[Jan 16 18:02:54.419] Server {0x7fade53d57e0} DEBUG: (cache_init)
Store::read_config - ns = NEW (new Span); ns->init("/dev/sdc",-1),
ns->vol_num=0
[Jan 16 18:02:54.419] Server {0x7fade53d57e0} DEBUG: (cache_init)
Span::init("/dev/sdc",-1)
[Jan 16 18:02:54.419] Server {0x7fade53d57e0} DEBUG: (cache_init)
Span::init - S_IFBLK - devnum = 2080
[Jan 16 18:02:54.419] Server {0x7fade53d57e0} DEBUG: (cache_init)
Span::init - socketManager.open("/dev/sdc", O_RDONLY) = 11
[Jan 16 18:02:54.419] Server {0x7fade53d57e0} DEBUG: (cache_init)
Span::init - /dev/sdc hw_sector_size=512 is_disk=1 adjusted_sec=1
[Jan 16 18:02:54.419] Server {0x7fade53d57e0} DEBUG: (cache_init)
Span::init - /dev/sdc alignment = 0
[Jan 16 18:02:54.419] Server {0x7fade53d57e0} DEBUG: (cache_init)
Span::init physical sectors 3907029168 total size 2000398934016 geometry
size 2000398934016 store blocks 244189323
[Jan 16 18:02:54.426] Server {0x7fade53d57e0} DEBUG: (cache_init)
Span::init("/usr/local/ats_422/var/trafficserver",33554432)
[Jan 16 18:02:54.426] Server {0x7fade53d57e0} DEBUG: (cache_init)
Span::init - S_IFDIR - devnum = 2051
[Jan 16 18:02:54.426] Server {0x7fade53d57e0} DEBUG: (cache_init)
Span::init - socketManager.open("/usr/local/ats_422/var/trafficserver",
O_RDONLY) = 28
[Jan 16 18:02:54.426] Server {0x7fade53d57e0} DEBUG: (cache_init)
Span::init - is_disk = 0, raw device = no
[Jan 16 18:02:54.426] Server {0x7fade53d57e0} DEBUG: (cache_init)
Span::init - mapped file "/usr/local/ats_422/var/trafficserver", 33554432
[Jan 16 18:02:54.455] Server {0x7faddfab2700} DEBUG: (cache_init)
Cache::open - proxy.config.cache.min_average_object_size = 102400
[Jan 16 18:02:54.465] Server {0x7faddfdb5700} DEBUG: (cache_init)
allocating 195338240 directory bytes for a 2000398565376 byte volume
(0.009765%)
[Jan 16 18:02:54.465] Server {0x7faddfeb6700} DEBUG: (cache_init)
allocating 195338240 directory bytes for a 2000398565376 byte volume
(0.009765%)
[Jan 16 18:02:54.465] Server {0x7fade53d57e0} DEBUG: (cache_init)
allocating 195338240 directory bytes for a 2000398565376 byte volume
(0.009765%)
[Jan 16 18:02:54.465] Server {0x7faddfcb4700} DEBUG: (cache_init)
allocating 195338240 directory bytes for a 2000398565376 byte volume
(0.009765%)

*********************************************************************************************************

Re: Do not use the disks

Posted by Sudheer Vinukonda <su...@yahoo-inc.com>.
 blockquote, div.yahoo_quoted { margin-left: 0 !important; border-left:1px #715FFA solid !important;  padding-left:1ex !important; background-color:white !important; }  What are the contents of your storage.config?
Thanks,
Sudheer




On Saturday, January 16, 2016, 2:22 AM, feng D <fe...@gmail.com> wrote:

Hi:         I use the traffic server as the Reverse Proxy with four disks as the cache. But I found that traffic server not use the disks.  The log in diags.log has not 'cache enabled' and not 'cache disabled'.          The version is 4.2.2.      
       Who can help me.                       

                                                                                                        Thanks!!!!
I open cache_init debug then the diags looks like this:
***********************************************************************[Jan 16 18:02:52.407] {0x7fade53d57e0} STATUS: opened /disk/ssd1/logs/trafficserver/diags.log[Jan 16 18:02:52.407] {0x7fade53d57e0} NOTE: updated diags config[Jan 16 18:02:54.418] Server {0x7fade53d57e0} NOTE: cache clustering disabled[Jan 16 18:02:54.419] Server {0x7fade53d57e0} WARNING: no interim disks specified in proxy.config.cache.interim.storage:[Jan 16 18:02:54.422] Server {0x7fade53d57e0} NOTE: ip_allow.config updated, reloading[Jan 16 18:02:54.426] Server {0x7fade53d57e0} NOTE: cache clustering disabled[Jan 16 18:02:54.427] Server {0x7fade53d57e0} NOTE: logging initialized[3], logging_mode = 1[Jan 16 18:02:54.428] Server {0x7fade53d57e0} WARNING: unable to open cache disk(s): InterimCache Cache Disabled[Jan 16 18:02:54.428] Server {0x7fade53d57e0} WARNING: [ReverseProxy] Unable to determine default redirect url for "referer" filter.[Jan 16 18:02:54.434] Server {0x7fade53d57e0} NOTE: traffic server running[Jan 16 18:02:54.465] Server {0x7faddfdb5700} NOTE: reading directory '/dev/sde 368640:244189278'[Jan 16 18:02:54.465] Server {0x7faddfeb6700} NOTE: reading directory '/dev/sdd 368640:244189278'[Jan 16 18:02:54.465] Server {0x7fade53d57e0} NOTE: reading directory '/dev/sdb 368640:244189278'[Jan 16 18:02:54.465] Server {0x7faddfcb4700} NOTE: reading directory '/dev/sdc 368640:244189278'[Jan 16 18:02:54.469] Server {0x7faddfeb6700} NOTE: using directory A for '/dev/sdd 368640:244189278'[Jan 16 18:02:54.469] Server {0x7faddfcb4700} NOTE: using directory A for '/dev/sdc 368640:244189278'[Jan 16 18:02:54.479] Server {0x7faddfdb5700} NOTE: using directory B for '/dev/sde 368640:244189278'[Jan 16 18:02:54.489] Server {0x7fade53d57e0} NOTE: using directory A for '/dev/sdb 368640:244189278'[Jan 16 18:02:57.403] Server {0x7faddfdb5700} NOTE: recovery clearing offsets [785550164480, 785653652992] sync_serial 10847 next 10848***********************************************************************


The tail of traffic.out is like this:*********************************************************************************************************[Jan 16 18:02:54.419] Server {0x7fade53d57e0} DEBUG: (cache_init) Store::read_config: "/dev/sde"[Jan 16 18:02:54.419] Server {0x7fade53d57e0} DEBUG: (cache_init) Store::read_config - ns = NEW (new Span); ns->init("/dev/sde",-1), ns->vol_num=0[Jan 16 18:02:54.419] Server {0x7fade53d57e0} DEBUG: (cache_init) Span::init("/dev/sde",-1)[Jan 16 18:02:54.419] Server {0x7fade53d57e0} DEBUG: (cache_init) Span::init - S_IFBLK - devnum = 2112[Jan 16 18:02:54.419] Server {0x7fade53d57e0} DEBUG: (cache_init) Span::init - socketManager.open("/dev/sde", O_RDONLY) = 11[Jan 16 18:02:54.419] Server {0x7fade53d57e0} DEBUG: (cache_init) Span::init - /dev/sde hw_sector_size=512 is_disk=1 adjusted_sec=1[Jan 16 18:02:54.419] Server {0x7fade53d57e0} DEBUG: (cache_init) Span::init - /dev/sde alignment = 0[Jan 16 18:02:54.419] Server {0x7fade53d57e0} DEBUG: (cache_init) Span::init physical sectors 3907029168 total size 2000398934016 geometry size 2000398934016 store blocks 244189323[Jan 16 18:02:54.419] Server {0x7fade53d57e0} DEBUG: (cache_init) Store::read_config: "/dev/sdc"[Jan 16 18:02:54.419] Server {0x7fade53d57e0} DEBUG: (cache_init) Store::read_config - ns = NEW (new Span); ns->init("/dev/sdc",-1), ns->vol_num=0[Jan 16 18:02:54.419] Server {0x7fade53d57e0} DEBUG: (cache_init) Span::init("/dev/sdc",-1)[Jan 16 18:02:54.419] Server {0x7fade53d57e0} DEBUG: (cache_init) Span::init - S_IFBLK - devnum = 2080[Jan 16 18:02:54.419] Server {0x7fade53d57e0} DEBUG: (cache_init) Span::init - socketManager.open("/dev/sdc", O_RDONLY) = 11[Jan 16 18:02:54.419] Server {0x7fade53d57e0} DEBUG: (cache_init) Span::init - /dev/sdc hw_sector_size=512 is_disk=1 adjusted_sec=1[Jan 16 18:02:54.419] Server {0x7fade53d57e0} DEBUG: (cache_init) Span::init - /dev/sdc alignment = 0[Jan 16 18:02:54.419] Server {0x7fade53d57e0} DEBUG: (cache_init) Span::init physical sectors 3907029168 total size 2000398934016 geometry size 2000398934016 store blocks 244189323[Jan 16 18:02:54.426] Server {0x7fade53d57e0} DEBUG: (cache_init) Span::init("/usr/local/ats_422/var/trafficserver",33554432)[Jan 16 18:02:54.426] Server {0x7fade53d57e0} DEBUG: (cache_init) Span::init - S_IFDIR - devnum = 2051[Jan 16 18:02:54.426] Server {0x7fade53d57e0} DEBUG: (cache_init) Span::init - socketManager.open("/usr/local/ats_422/var/trafficserver", O_RDONLY) = 28[Jan 16 18:02:54.426] Server {0x7fade53d57e0} DEBUG: (cache_init) Span::init - is_disk = 0, raw device = no[Jan 16 18:02:54.426] Server {0x7fade53d57e0} DEBUG: (cache_init) Span::init - mapped file "/usr/local/ats_422/var/trafficserver", 33554432[Jan 16 18:02:54.455] Server {0x7faddfab2700} DEBUG: (cache_init) Cache::open - proxy.config.cache.min_average_object_size = 102400[Jan 16 18:02:54.465] Server {0x7faddfdb5700} DEBUG: (cache_init) allocating 195338240 directory bytes for a 2000398565376 byte volume (0.009765%)[Jan 16 18:02:54.465] Server {0x7faddfeb6700} DEBUG: (cache_init) allocating 195338240 directory bytes for a 2000398565376 byte volume (0.009765%)[Jan 16 18:02:54.465] Server {0x7fade53d57e0} DEBUG: (cache_init) allocating 195338240 directory bytes for a 2000398565376 byte volume (0.009765%)[Jan 16 18:02:54.465] Server {0x7faddfcb4700} DEBUG: (cache_init) allocating 195338240 directory bytes for a 2000398565376 byte volume (0.009765%)
*********************************************************************************************************

 


RE: Do not use the disks

Posted by "Schmerge, John (Contractor)" <Jo...@cable.comcast.com>.
I believe one already exists, but as I said, I couldn’t find it easily.

From: Yongming Zhao [mailto:ming.zym@gmail.com]
Sent: Wednesday, January 20, 2016 6:08 AM
To: users@trafficserver.apache.org
Subject: Re: Do not use the disks

hmm, that sounds like one bug or at least should be enhanced when recover from disk fail, should we file a jira for it?


- Yongming Zhao 赵永明

在 2016年1月18日,下午2:15,Schmerge, John (Contractor) <Jo...@cable.comcast.com>> 写道:

Yongming,

I've noticed that if you have replaced disks that have failed, ATS will not use them unless it knows what volume they belong to; there's a bug in the code that I found ~6 months ago that trips when an unformatted disk is first added; since ATS does not know the volume to use for it, it will not ever use the disk.

I wish i could find the bug documenting this, but a quick search isn't turning up the issue.

A quick & dirty workaround for this is always put a 'volume=X' modifier on the drives listed in storage.config; even if you only have one logical volume, it will sidestep the bug.

Clearing the cache is also a workaround for this, but not always possible if your storage is multiple terabytes.

-john
________________________________
From: Yongming Zhao <mi...@gmail.com>>
Sent: Sunday, January 17, 2016 10:44 AM
To: users@trafficserver.apache.org<ma...@trafficserver.apache.org>
Cc: feng D
Subject: Re: Do not use the disks

in most case when a cache is not active, there maybe a crash that the server fail to recover, please check the last crash and paste the stack. also you may find out that one or two traffic_server thread(ET_NET*) running at 100% CPU, tracing into the recover functions.

if that is the case, best practice is clear the cache. yes, it is awful, you may need to try the latest version you get from the official downloads, if the bug still bother you, file a ticket in the jira and paste as much information as possible, as always, patch is welcome.




- Yongming Zhao 赵永明

在 2016年1月17日,下午12:59,Leif Hedstrom <zw...@apache.org>> 写道:


On Jan 16, 2016, at 3:22 AM, feng D <fe...@gmail.com>> wrote:

Hi:

     I use the traffic server as the Reverse Proxy with four disks as the cache. But I found that traffic server not use the disks.  The log in diags.log has not 'cache enabled' and not 'cache disabled’.

A guess is that this means something:


[Jan 16 18:02:54.428] Server {0x7fade53d57e0} WARNING: unable to open cache disk(s): InterimCache Cache Disabled



Like, did you misconfigure your records.config for the obsoleted (removed) interim SSD cache? We don’t have any support for that (removed) feature, so our recommendation is to not use it even in the old 4.2.x versions (you should upgrade to v4.3.x at least).

— Leif


     The version is 4.2.2.


       Who can help me.


                                                                                                        Thanks!!!!

I open cache_init debug then the diags looks like this:
***********************************************************************
[Jan 16 18:02:52.407] {0x7fade53d57e0} STATUS: opened /disk/ssd1/logs/trafficserver/diags.log
[Jan 16 18:02:52.407] {0x7fade53d57e0} NOTE: updated diags config
[Jan 16 18:02:54.418] Server {0x7fade53d57e0} NOTE: cache clustering disabled
[Jan 16 18:02:54.419] Server {0x7fade53d57e0} WARNING: no interim disks specified in proxy.config.cache.interim.storage:
[Jan 16 18:02:54.422] Server {0x7fade53d57e0} NOTE: ip_allow.config updated, reloading
[Jan 16 18:02:54.426] Server {0x7fade53d57e0} NOTE: cache clustering disabled
[Jan 16 18:02:54.427] Server {0x7fade53d57e0} NOTE: logging initialized[3], logging_mode = 1
[Jan 16 18:02:54.428] Server {0x7fade53d57e0} WARNING: unable to open cache disk(s): InterimCache Cache Disabled
[Jan 16 18:02:54.428] Server {0x7fade53d57e0} WARNING: [ReverseProxy] Unable to determine default redirect url for "referer" filter.
[Jan 16 18:02:54.434] Server {0x7fade53d57e0} NOTE: traffic server running
[Jan 16 18:02:54.465] Server {0x7faddfdb5700} NOTE: reading directory '/dev/sde 368640:244189278'
[Jan 16 18:02:54.465] Server {0x7faddfeb6700} NOTE: reading directory '/dev/sdd 368640:244189278'
[Jan 16 18:02:54.465] Server {0x7fade53d57e0} NOTE: reading directory '/dev/sdb 368640:244189278'
[Jan 16 18:02:54.465] Server {0x7faddfcb4700} NOTE: reading directory '/dev/sdc 368640:244189278'
[Jan 16 18:02:54.469] Server {0x7faddfeb6700} NOTE: using directory A for '/dev/sdd 368640:244189278'
[Jan 16 18:02:54.469] Server {0x7faddfcb4700} NOTE: using directory A for '/dev/sdc 368640:244189278'
[Jan 16 18:02:54.479] Server {0x7faddfdb5700} NOTE: using directory B for '/dev/sde 368640:244189278'
[Jan 16 18:02:54.489] Server {0x7fade53d57e0} NOTE: using directory A for '/dev/sdb 368640:244189278'
[Jan 16 18:02:57.403] Server {0x7faddfdb5700} NOTE: recovery clearing offsets [785550164480, 785653652992] sync_serial 10847 next 10848
***********************************************************************



The tail of traffic.out is like this:
*********************************************************************************************************
[Jan 16 18:02:54.419] Server {0x7fade53d57e0} DEBUG: (cache_init) Store::read_config: "/dev/sde
"
[Jan 16 18:02:54.419] Server {0x7fade53d57e0} DEBUG: (cache_init) Store::read_config - ns = NEW (new Span); ns->init("/dev/sde",-1), ns->vol_num=0
[Jan 16 18:02:54.419] Server {0x7fade53d57e0} DEBUG: (cache_init) Span::init("/dev/sde",-1)
[Jan 16 18:02:54.419] Server {0x7fade53d57e0} DEBUG: (cache_init) Span::init - S_IFBLK - devnum = 2112
[Jan 16 18:02:54.419] Server {0x7fade53d57e0} DEBUG: (cache_init) Span::init - socketManager.open("/dev/sde", O_RDONLY) = 11
[Jan 16 18:02:54.419] Server {0x7fade53d57e0} DEBUG: (cache_init) Span::init - /dev/sde hw_sector_size=512 is_disk=1 adjusted_sec=1
[Jan 16 18:02:54.419] Server {0x7fade53d57e0} DEBUG: (cache_init) Span::init - /dev/sde alignment = 0
[Jan 16 18:02:54.419] Server {0x7fade53d57e0} DEBUG: (cache_init) Span::init physical sectors 3907029168 total size 2000398934016 geometry size 2000398934016 store blocks 244189323
[Jan 16 18:02:54.419] Server {0x7fade53d57e0} DEBUG: (cache_init) Store::read_config: "/dev/sdc
"
[Jan 16 18:02:54.419] Server {0x7fade53d57e0} DEBUG: (cache_init) Store::read_config - ns = NEW (new Span); ns->init("/dev/sdc",-1), ns->vol_num=0
[Jan 16 18:02:54.419] Server {0x7fade53d57e0} DEBUG: (cache_init) Span::init("/dev/sdc",-1)
[Jan 16 18:02:54.419] Server {0x7fade53d57e0} DEBUG: (cache_init) Span::init - S_IFBLK - devnum = 2080
[Jan 16 18:02:54.419] Server {0x7fade53d57e0} DEBUG: (cache_init) Span::init - socketManager.open("/dev/sdc", O_RDONLY) = 11
[Jan 16 18:02:54.419] Server {0x7fade53d57e0} DEBUG: (cache_init) Span::init - /dev/sdc hw_sector_size=512 is_disk=1 adjusted_sec=1
[Jan 16 18:02:54.419] Server {0x7fade53d57e0} DEBUG: (cache_init) Span::init - /dev/sdc alignment = 0
[Jan 16 18:02:54.419] Server {0x7fade53d57e0} DEBUG: (cache_init) Span::init physical sectors 3907029168 total size 2000398934016 geometry size 2000398934016 store blocks 244189323
[Jan 16 18:02:54.426] Server {0x7fade53d57e0} DEBUG: (cache_init) Span::init("/usr/local/ats_422/var/trafficserver",33554432)
[Jan 16 18:02:54.426] Server {0x7fade53d57e0} DEBUG: (cache_init) Span::init - S_IFDIR - devnum = 2051
[Jan 16 18:02:54.426] Server {0x7fade53d57e0} DEBUG: (cache_init) Span::init - socketManager.open("/usr/local/ats_422/var/trafficserver", O_RDONLY) = 28
[Jan 16 18:02:54.426] Server {0x7fade53d57e0} DEBUG: (cache_init) Span::init - is_disk = 0, raw device = no
[Jan 16 18:02:54.426] Server {0x7fade53d57e0} DEBUG: (cache_init) Span::init - mapped file "/usr/local/ats_422/var/trafficserver", 33554432
[Jan 16 18:02:54.455] Server {0x7faddfab2700} DEBUG: (cache_init) Cache::open - proxy.config.cache.min_average_object_size = 102400
[Jan 16 18:02:54.465] Server {0x7faddfdb5700} DEBUG: (cache_init) allocating 195338240 directory bytes for a 2000398565376 byte volume (0.009765%)
[Jan 16 18:02:54.465] Server {0x7faddfeb6700} DEBUG: (cache_init) allocating 195338240 directory bytes for a 2000398565376 byte volume (0.009765%)
[Jan 16 18:02:54.465] Server {0x7fade53d57e0} DEBUG: (cache_init) allocating 195338240 directory bytes for a 2000398565376 byte volume (0.009765%)
[Jan 16 18:02:54.465] Server {0x7faddfcb4700} DEBUG: (cache_init) allocating 195338240 directory bytes for a 2000398565376 byte volume (0.009765%)

*********************************************************************************************************






Re: Do not use the disks

Posted by Yongming Zhao <mi...@gmail.com>.
hmm, that sounds like one bug or at least should be enhanced when recover from disk fail, should we file a jira for it?


- Yongming Zhao 赵永明

> 在 2016年1月18日,下午2:15,Schmerge, John (Contractor) <Jo...@cable.comcast.com> 写道:
> 
> Yongming,
> 
> I've noticed that if you have replaced disks that have failed, ATS will not use them unless it knows what volume they belong to; there's a bug in the code that I found ~6 months ago that trips when an unformatted disk is first added; since ATS does not know the volume to use for it, it will not ever use the disk.
> 
> I wish i could find the bug documenting this, but a quick search isn't turning up the issue.
> 
> A quick & dirty workaround for this is always put a 'volume=X' modifier on the drives listed in storage.config; even if you only have one logical volume, it will sidestep the bug.
> 
> Clearing the cache is also a workaround for this, but not always possible if your storage is multiple terabytes.
> 
> -john
> From: Yongming Zhao <mi...@gmail.com>
> Sent: Sunday, January 17, 2016 10:44 AM
> To: users@trafficserver.apache.org
> Cc: feng D
> Subject: Re: Do not use the disks
>  
> in most case when a cache is not active, there maybe a crash that the server fail to recover, please check the last crash and paste the stack. also you may find out that one or two traffic_server thread(ET_NET*) running at 100% CPU, tracing into the recover functions.
> 
> if that is the case, best practice is clear the cache. yes, it is awful, you may need to try the latest version you get from the official downloads, if the bug still bother you, file a ticket in the jira and paste as much information as possible, as always, patch is welcome.
> 
> 
> 
> 
> - Yongming Zhao 赵永明
> 
>> 在 2016年1月17日,下午12:59,Leif Hedstrom <zwoop@apache.org <ma...@apache.org>> 写道:
>> 
>> 
>>> On Jan 16, 2016, at 3:22 AM, feng D <fengidri@gmail.com <ma...@gmail.com>> wrote:
>>> 
>>> Hi:
>>>     
>>>      I use the traffic server as the Reverse Proxy with four disks as the cache. But I found that traffic server not use the disks.  The log in diags.log has not 'cache enabled' and not 'cache disabled’.
>> 
>> A guess is that this means something:
>> 
>> 
>> [Jan 16 18:02:54.428] Server {0x7fade53d57e0} WARNING: unable to open cache disk(s): InterimCache Cache Disabled
>> 
>> 
>> 
>> Like, did you misconfigure your records.config for the obsoleted (removed) interim SSD cache? We don’t have any support for that (removed) feature, so our recommendation is to not use it even in the old 4.2.x versions (you should upgrade to v4.3.x at least).
>> 
>> — Leif
>> 
>>>      
>>>      The version is 4.2.2. 
>>>      
>>> 
>>>        Who can help me.                       
>>> 
>>> 
>>>                                                                                                         Thanks!!!!
>>> 
>>> I open cache_init debug then the diags looks like this:
>>> ***********************************************************************
>>> [Jan 16 18:02:52.407] {0x7fade53d57e0} STATUS: opened /disk/ssd1/logs/trafficserver/diags.log
>>> [Jan 16 18:02:52.407] {0x7fade53d57e0} NOTE: updated diags config
>>> [Jan 16 18:02:54.418] Server {0x7fade53d57e0} NOTE: cache clustering disabled
>>> [Jan 16 18:02:54.419] Server {0x7fade53d57e0} WARNING: no interim disks specified in proxy.config.cache.interim.storage:
>>> [Jan 16 18:02:54.422] Server {0x7fade53d57e0} NOTE: ip_allow.config updated, reloading
>>> [Jan 16 18:02:54.426] Server {0x7fade53d57e0} NOTE: cache clustering disabled
>>> [Jan 16 18:02:54.427] Server {0x7fade53d57e0} NOTE: logging initialized[3], logging_mode = 1
>>> [Jan 16 18:02:54.428] Server {0x7fade53d57e0} WARNING: unable to open cache disk(s): InterimCache Cache Disabled
>>> [Jan 16 18:02:54.428] Server {0x7fade53d57e0} WARNING: [ReverseProxy] Unable to determine default redirect url for "referer" filter.
>>> [Jan 16 18:02:54.434] Server {0x7fade53d57e0} NOTE: traffic server running
>>> [Jan 16 18:02:54.465] Server {0x7faddfdb5700} NOTE: reading directory '/dev/sde 368640:244189278'
>>> [Jan 16 18:02:54.465] Server {0x7faddfeb6700} NOTE: reading directory '/dev/sdd 368640:244189278'
>>> [Jan 16 18:02:54.465] Server {0x7fade53d57e0} NOTE: reading directory '/dev/sdb 368640:244189278'
>>> [Jan 16 18:02:54.465] Server {0x7faddfcb4700} NOTE: reading directory '/dev/sdc 368640:244189278'
>>> [Jan 16 18:02:54.469] Server {0x7faddfeb6700} NOTE: using directory A for '/dev/sdd 368640:244189278'
>>> [Jan 16 18:02:54.469] Server {0x7faddfcb4700} NOTE: using directory A for '/dev/sdc 368640:244189278'
>>> [Jan 16 18:02:54.479] Server {0x7faddfdb5700} NOTE: using directory B for '/dev/sde 368640:244189278'
>>> [Jan 16 18:02:54.489] Server {0x7fade53d57e0} NOTE: using directory A for '/dev/sdb 368640:244189278'
>>> [Jan 16 18:02:57.403] Server {0x7faddfdb5700} NOTE: recovery clearing offsets [785550164480, 785653652992] sync_serial 10847 next 10848
>>> ***********************************************************************
>>> 
>>> 
>>> 
>>> The tail of traffic.out is like this:
>>> *********************************************************************************************************
>>> [Jan 16 18:02:54.419] Server {0x7fade53d57e0} DEBUG: (cache_init) Store::read_config: "/dev/sde
>>> "
>>> [Jan 16 18:02:54.419] Server {0x7fade53d57e0} DEBUG: (cache_init) Store::read_config - ns = NEW (new Span); ns->init("/dev/sde",-1), ns->vol_num=0
>>> [Jan 16 18:02:54.419] Server {0x7fade53d57e0} DEBUG: (cache_init) Span::init("/dev/sde",-1)
>>> [Jan 16 18:02:54.419] Server {0x7fade53d57e0} DEBUG: (cache_init) Span::init - S_IFBLK - devnum = 2112
>>> [Jan 16 18:02:54.419] Server {0x7fade53d57e0} DEBUG: (cache_init) Span::init - socketManager.open("/dev/sde", O_RDONLY) = 11
>>> [Jan 16 18:02:54.419] Server {0x7fade53d57e0} DEBUG: (cache_init) Span::init - /dev/sde hw_sector_size=512 is_disk=1 adjusted_sec=1
>>> [Jan 16 18:02:54.419] Server {0x7fade53d57e0} DEBUG: (cache_init) Span::init - /dev/sde alignment = 0
>>> [Jan 16 18:02:54.419] Server {0x7fade53d57e0} DEBUG: (cache_init) Span::init physical sectors 3907029168 total size 2000398934016 geometry size 2000398934016 store blocks 244189323
>>> [Jan 16 18:02:54.419] Server {0x7fade53d57e0} DEBUG: (cache_init) Store::read_config: "/dev/sdc
>>> "
>>> [Jan 16 18:02:54.419] Server {0x7fade53d57e0} DEBUG: (cache_init) Store::read_config - ns = NEW (new Span); ns->init("/dev/sdc",-1), ns->vol_num=0
>>> [Jan 16 18:02:54.419] Server {0x7fade53d57e0} DEBUG: (cache_init) Span::init("/dev/sdc",-1)
>>> [Jan 16 18:02:54.419] Server {0x7fade53d57e0} DEBUG: (cache_init) Span::init - S_IFBLK - devnum = 2080
>>> [Jan 16 18:02:54.419] Server {0x7fade53d57e0} DEBUG: (cache_init) Span::init - socketManager.open("/dev/sdc", O_RDONLY) = 11
>>> [Jan 16 18:02:54.419] Server {0x7fade53d57e0} DEBUG: (cache_init) Span::init - /dev/sdc hw_sector_size=512 is_disk=1 adjusted_sec=1
>>> [Jan 16 18:02:54.419] Server {0x7fade53d57e0} DEBUG: (cache_init) Span::init - /dev/sdc alignment = 0
>>> [Jan 16 18:02:54.419] Server {0x7fade53d57e0} DEBUG: (cache_init) Span::init physical sectors 3907029168 total size 2000398934016 geometry size 2000398934016 store blocks 244189323
>>> [Jan 16 18:02:54.426] Server {0x7fade53d57e0} DEBUG: (cache_init) Span::init("/usr/local/ats_422/var/trafficserver",33554432)
>>> [Jan 16 18:02:54.426] Server {0x7fade53d57e0} DEBUG: (cache_init) Span::init - S_IFDIR - devnum = 2051
>>> [Jan 16 18:02:54.426] Server {0x7fade53d57e0} DEBUG: (cache_init) Span::init - socketManager.open("/usr/local/ats_422/var/trafficserver", O_RDONLY) = 28
>>> [Jan 16 18:02:54.426] Server {0x7fade53d57e0} DEBUG: (cache_init) Span::init - is_disk = 0, raw device = no
>>> [Jan 16 18:02:54.426] Server {0x7fade53d57e0} DEBUG: (cache_init) Span::init - mapped file "/usr/local/ats_422/var/trafficserver", 33554432
>>> [Jan 16 18:02:54.455] Server {0x7faddfab2700} DEBUG: (cache_init) Cache::open - proxy.config.cache.min_average_object_size = 102400
>>> [Jan 16 18:02:54.465] Server {0x7faddfdb5700} DEBUG: (cache_init) allocating 195338240 directory bytes for a 2000398565376 byte volume (0.009765%)
>>> [Jan 16 18:02:54.465] Server {0x7faddfeb6700} DEBUG: (cache_init) allocating 195338240 directory bytes for a 2000398565376 byte volume (0.009765%)
>>> [Jan 16 18:02:54.465] Server {0x7fade53d57e0} DEBUG: (cache_init) allocating 195338240 directory bytes for a 2000398565376 byte volume (0.009765%)
>>> [Jan 16 18:02:54.465] Server {0x7faddfcb4700} DEBUG: (cache_init) allocating 195338240 directory bytes for a 2000398565376 byte volume (0.009765%)
>>> 
>>> *********************************************************************************************************
>>> 
>> 
> 
> 


Re: Do not use the disks

Posted by "Schmerge, John (Contractor)" <Jo...@cable.comcast.com>.
Yongming,


I've noticed that if you have replaced disks that have failed, ATS will not use them unless it knows what volume they belong to; there's a bug in the code that I found ~6 months ago that trips when an unformatted disk is first added; since ATS does not know the volume to use for it, it will not ever use the disk.


I wish i could find the bug documenting this, but a quick search isn't turning up the issue.


A quick & dirty workaround for this is always put a 'volume=X' modifier on the drives listed in storage.config; even if you only have one logical volume, it will sidestep the bug.


Clearing the cache is also a workaround for this, but not always possible if your storage is multiple terabytes.


-john

________________________________
From: Yongming Zhao <mi...@gmail.com>
Sent: Sunday, January 17, 2016 10:44 AM
To: users@trafficserver.apache.org
Cc: feng D
Subject: Re: Do not use the disks

in most case when a cache is not active, there maybe a crash that the server fail to recover, please check the last crash and paste the stack. also you may find out that one or two traffic_server thread(ET_NET*) running at 100% CPU, tracing into the recover functions.

if that is the case, best practice is clear the cache. yes, it is awful, you may need to try the latest version you get from the official downloads, if the bug still bother you, file a ticket in the jira and paste as much information as possible, as always, patch is welcome.




- Yongming Zhao 赵永明

在 2016年1月17日,下午12:59,Leif Hedstrom <zw...@apache.org>> 写道:


On Jan 16, 2016, at 3:22 AM, feng D <fe...@gmail.com>> wrote:

Hi:

     I use the traffic server as the Reverse Proxy with four disks as the cache. But I found that traffic server not use the disks.  The log in diags.log has not 'cache enabled' and not 'cache disabled’.

A guess is that this means something:


[Jan 16 18:02:54.428] Server {0x7fade53d57e0} WARNING: unable to open cache disk(s): InterimCache Cache Disabled



Like, did you misconfigure your records.config for the obsoleted (removed) interim SSD cache? We don’t have any support for that (removed) feature, so our recommendation is to not use it even in the old 4.2.x versions (you should upgrade to v4.3.x at least).

― Leif


     The version is 4.2.2.


       Who can help me.


                                                                                                        Thanks!!!!

I open cache_init debug then the diags looks like this:
***********************************************************************
[Jan 16 18:02:52.407] {0x7fade53d57e0} STATUS: opened /disk/ssd1/logs/trafficserver/diags.log
[Jan 16 18:02:52.407] {0x7fade53d57e0} NOTE: updated diags config
[Jan 16 18:02:54.418] Server {0x7fade53d57e0} NOTE: cache clustering disabled
[Jan 16 18:02:54.419] Server {0x7fade53d57e0} WARNING: no interim disks specified in proxy.config.cache.interim.storage:
[Jan 16 18:02:54.422] Server {0x7fade53d57e0} NOTE: ip_allow.config updated, reloading
[Jan 16 18:02:54.426] Server {0x7fade53d57e0} NOTE: cache clustering disabled
[Jan 16 18:02:54.427] Server {0x7fade53d57e0} NOTE: logging initialized[3], logging_mode = 1
[Jan 16 18:02:54.428] Server {0x7fade53d57e0} WARNING: unable to open cache disk(s): InterimCache Cache Disabled
[Jan 16 18:02:54.428] Server {0x7fade53d57e0} WARNING: [ReverseProxy] Unable to determine default redirect url for "referer" filter.
[Jan 16 18:02:54.434] Server {0x7fade53d57e0} NOTE: traffic server running
[Jan 16 18:02:54.465] Server {0x7faddfdb5700} NOTE: reading directory '/dev/sde 368640:244189278'
[Jan 16 18:02:54.465] Server {0x7faddfeb6700} NOTE: reading directory '/dev/sdd 368640:244189278'
[Jan 16 18:02:54.465] Server {0x7fade53d57e0} NOTE: reading directory '/dev/sdb 368640:244189278'
[Jan 16 18:02:54.465] Server {0x7faddfcb4700} NOTE: reading directory '/dev/sdc 368640:244189278'
[Jan 16 18:02:54.469] Server {0x7faddfeb6700} NOTE: using directory A for '/dev/sdd 368640:244189278'
[Jan 16 18:02:54.469] Server {0x7faddfcb4700} NOTE: using directory A for '/dev/sdc 368640:244189278'
[Jan 16 18:02:54.479] Server {0x7faddfdb5700} NOTE: using directory B for '/dev/sde 368640:244189278'
[Jan 16 18:02:54.489] Server {0x7fade53d57e0} NOTE: using directory A for '/dev/sdb 368640:244189278'
[Jan 16 18:02:57.403] Server {0x7faddfdb5700} NOTE: recovery clearing offsets [785550164480, 785653652992] sync_serial 10847 next 10848
***********************************************************************



The tail of traffic.out is like this:
*********************************************************************************************************
[Jan 16 18:02:54.419] Server {0x7fade53d57e0} DEBUG: (cache_init) Store::read_config: "/dev/sde
"
[Jan 16 18:02:54.419] Server {0x7fade53d57e0} DEBUG: (cache_init) Store::read_config - ns = NEW (new Span); ns->init("/dev/sde",-1), ns->vol_num=0
[Jan 16 18:02:54.419] Server {0x7fade53d57e0} DEBUG: (cache_init) Span::init("/dev/sde",-1)
[Jan 16 18:02:54.419] Server {0x7fade53d57e0} DEBUG: (cache_init) Span::init - S_IFBLK - devnum = 2112
[Jan 16 18:02:54.419] Server {0x7fade53d57e0} DEBUG: (cache_init) Span::init - socketManager.open("/dev/sde", O_RDONLY) = 11
[Jan 16 18:02:54.419] Server {0x7fade53d57e0} DEBUG: (cache_init) Span::init - /dev/sde hw_sector_size=512 is_disk=1 adjusted_sec=1
[Jan 16 18:02:54.419] Server {0x7fade53d57e0} DEBUG: (cache_init) Span::init - /dev/sde alignment = 0
[Jan 16 18:02:54.419] Server {0x7fade53d57e0} DEBUG: (cache_init) Span::init physical sectors 3907029168 total size 2000398934016 geometry size 2000398934016 store blocks 244189323
[Jan 16 18:02:54.419] Server {0x7fade53d57e0} DEBUG: (cache_init) Store::read_config: "/dev/sdc
"
[Jan 16 18:02:54.419] Server {0x7fade53d57e0} DEBUG: (cache_init) Store::read_config - ns = NEW (new Span); ns->init("/dev/sdc",-1), ns->vol_num=0
[Jan 16 18:02:54.419] Server {0x7fade53d57e0} DEBUG: (cache_init) Span::init("/dev/sdc",-1)
[Jan 16 18:02:54.419] Server {0x7fade53d57e0} DEBUG: (cache_init) Span::init - S_IFBLK - devnum = 2080
[Jan 16 18:02:54.419] Server {0x7fade53d57e0} DEBUG: (cache_init) Span::init - socketManager.open("/dev/sdc", O_RDONLY) = 11
[Jan 16 18:02:54.419] Server {0x7fade53d57e0} DEBUG: (cache_init) Span::init - /dev/sdc hw_sector_size=512 is_disk=1 adjusted_sec=1
[Jan 16 18:02:54.419] Server {0x7fade53d57e0} DEBUG: (cache_init) Span::init - /dev/sdc alignment = 0
[Jan 16 18:02:54.419] Server {0x7fade53d57e0} DEBUG: (cache_init) Span::init physical sectors 3907029168 total size 2000398934016 geometry size 2000398934016 store blocks 244189323
[Jan 16 18:02:54.426] Server {0x7fade53d57e0} DEBUG: (cache_init) Span::init("/usr/local/ats_422/var/trafficserver",33554432)
[Jan 16 18:02:54.426] Server {0x7fade53d57e0} DEBUG: (cache_init) Span::init - S_IFDIR - devnum = 2051
[Jan 16 18:02:54.426] Server {0x7fade53d57e0} DEBUG: (cache_init) Span::init - socketManager.open("/usr/local/ats_422/var/trafficserver", O_RDONLY) = 28
[Jan 16 18:02:54.426] Server {0x7fade53d57e0} DEBUG: (cache_init) Span::init - is_disk = 0, raw device = no
[Jan 16 18:02:54.426] Server {0x7fade53d57e0} DEBUG: (cache_init) Span::init - mapped file "/usr/local/ats_422/var/trafficserver", 33554432
[Jan 16 18:02:54.455] Server {0x7faddfab2700} DEBUG: (cache_init) Cache::open - proxy.config.cache.min_average_object_size = 102400
[Jan 16 18:02:54.465] Server {0x7faddfdb5700} DEBUG: (cache_init) allocating 195338240 directory bytes for a 2000398565376 byte volume (0.009765%)
[Jan 16 18:02:54.465] Server {0x7faddfeb6700} DEBUG: (cache_init) allocating 195338240 directory bytes for a 2000398565376 byte volume (0.009765%)
[Jan 16 18:02:54.465] Server {0x7fade53d57e0} DEBUG: (cache_init) allocating 195338240 directory bytes for a 2000398565376 byte volume (0.009765%)
[Jan 16 18:02:54.465] Server {0x7faddfcb4700} DEBUG: (cache_init) allocating 195338240 directory bytes for a 2000398565376 byte volume (0.009765%)

*********************************************************************************************************




Re: Do not use the disks

Posted by Yongming Zhao <mi...@gmail.com>.
in most case when a cache is not active, there maybe a crash that the server fail to recover, please check the last crash and paste the stack. also you may find out that one or two traffic_server thread(ET_NET*) running at 100% CPU, tracing into the recover functions.

if that is the case, best practice is clear the cache. yes, it is awful, you may need to try the latest version you get from the official downloads, if the bug still bother you, file a ticket in the jira and paste as much information as possible, as always, patch is welcome.




- Yongming Zhao 赵永明

> 在 2016年1月17日,下午12:59,Leif Hedstrom <zw...@apache.org> 写道:
> 
> 
>> On Jan 16, 2016, at 3:22 AM, feng D <fengidri@gmail.com <ma...@gmail.com>> wrote:
>> 
>> Hi:
>>     
>>      I use the traffic server as the Reverse Proxy with four disks as the cache. But I found that traffic server not use the disks.  The log in diags.log has not 'cache enabled' and not 'cache disabled’.
> 
> A guess is that this means something:
> 
> 
> [Jan 16 18:02:54.428] Server {0x7fade53d57e0} WARNING: unable to open cache disk(s): InterimCache Cache Disabled
> 
> 
> 
> Like, did you misconfigure your records.config for the obsoleted (removed) interim SSD cache? We don’t have any support for that (removed) feature, so our recommendation is to not use it even in the old 4.2.x versions (you should upgrade to v4.3.x at least).
> 
> — Leif
> 
>>      
>>      The version is 4.2.2. 
>>      
>> 
>>        Who can help me.                       
>> 
>> 
>>                                                                                                         Thanks!!!!
>> 
>> I open cache_init debug then the diags looks like this:
>> ***********************************************************************
>> [Jan 16 18:02:52.407] {0x7fade53d57e0} STATUS: opened /disk/ssd1/logs/trafficserver/diags.log
>> [Jan 16 18:02:52.407] {0x7fade53d57e0} NOTE: updated diags config
>> [Jan 16 18:02:54.418] Server {0x7fade53d57e0} NOTE: cache clustering disabled
>> [Jan 16 18:02:54.419] Server {0x7fade53d57e0} WARNING: no interim disks specified in proxy.config.cache.interim.storage:
>> [Jan 16 18:02:54.422] Server {0x7fade53d57e0} NOTE: ip_allow.config updated, reloading
>> [Jan 16 18:02:54.426] Server {0x7fade53d57e0} NOTE: cache clustering disabled
>> [Jan 16 18:02:54.427] Server {0x7fade53d57e0} NOTE: logging initialized[3], logging_mode = 1
>> [Jan 16 18:02:54.428] Server {0x7fade53d57e0} WARNING: unable to open cache disk(s): InterimCache Cache Disabled
>> [Jan 16 18:02:54.428] Server {0x7fade53d57e0} WARNING: [ReverseProxy] Unable to determine default redirect url for "referer" filter.
>> [Jan 16 18:02:54.434] Server {0x7fade53d57e0} NOTE: traffic server running
>> [Jan 16 18:02:54.465] Server {0x7faddfdb5700} NOTE: reading directory '/dev/sde 368640:244189278'
>> [Jan 16 18:02:54.465] Server {0x7faddfeb6700} NOTE: reading directory '/dev/sdd 368640:244189278'
>> [Jan 16 18:02:54.465] Server {0x7fade53d57e0} NOTE: reading directory '/dev/sdb 368640:244189278'
>> [Jan 16 18:02:54.465] Server {0x7faddfcb4700} NOTE: reading directory '/dev/sdc 368640:244189278'
>> [Jan 16 18:02:54.469] Server {0x7faddfeb6700} NOTE: using directory A for '/dev/sdd 368640:244189278'
>> [Jan 16 18:02:54.469] Server {0x7faddfcb4700} NOTE: using directory A for '/dev/sdc 368640:244189278'
>> [Jan 16 18:02:54.479] Server {0x7faddfdb5700} NOTE: using directory B for '/dev/sde 368640:244189278'
>> [Jan 16 18:02:54.489] Server {0x7fade53d57e0} NOTE: using directory A for '/dev/sdb 368640:244189278'
>> [Jan 16 18:02:57.403] Server {0x7faddfdb5700} NOTE: recovery clearing offsets [785550164480, 785653652992] sync_serial 10847 next 10848
>> ***********************************************************************
>> 
>> 
>> 
>> The tail of traffic.out is like this:
>> *********************************************************************************************************
>> [Jan 16 18:02:54.419] Server {0x7fade53d57e0} DEBUG: (cache_init) Store::read_config: "/dev/sde
>> "
>> [Jan 16 18:02:54.419] Server {0x7fade53d57e0} DEBUG: (cache_init) Store::read_config - ns = NEW (new Span); ns->init("/dev/sde",-1), ns->vol_num=0
>> [Jan 16 18:02:54.419] Server {0x7fade53d57e0} DEBUG: (cache_init) Span::init("/dev/sde",-1)
>> [Jan 16 18:02:54.419] Server {0x7fade53d57e0} DEBUG: (cache_init) Span::init - S_IFBLK - devnum = 2112
>> [Jan 16 18:02:54.419] Server {0x7fade53d57e0} DEBUG: (cache_init) Span::init - socketManager.open("/dev/sde", O_RDONLY) = 11
>> [Jan 16 18:02:54.419] Server {0x7fade53d57e0} DEBUG: (cache_init) Span::init - /dev/sde hw_sector_size=512 is_disk=1 adjusted_sec=1
>> [Jan 16 18:02:54.419] Server {0x7fade53d57e0} DEBUG: (cache_init) Span::init - /dev/sde alignment = 0
>> [Jan 16 18:02:54.419] Server {0x7fade53d57e0} DEBUG: (cache_init) Span::init physical sectors 3907029168 total size 2000398934016 geometry size 2000398934016 store blocks 244189323
>> [Jan 16 18:02:54.419] Server {0x7fade53d57e0} DEBUG: (cache_init) Store::read_config: "/dev/sdc
>> "
>> [Jan 16 18:02:54.419] Server {0x7fade53d57e0} DEBUG: (cache_init) Store::read_config - ns = NEW (new Span); ns->init("/dev/sdc",-1), ns->vol_num=0
>> [Jan 16 18:02:54.419] Server {0x7fade53d57e0} DEBUG: (cache_init) Span::init("/dev/sdc",-1)
>> [Jan 16 18:02:54.419] Server {0x7fade53d57e0} DEBUG: (cache_init) Span::init - S_IFBLK - devnum = 2080
>> [Jan 16 18:02:54.419] Server {0x7fade53d57e0} DEBUG: (cache_init) Span::init - socketManager.open("/dev/sdc", O_RDONLY) = 11
>> [Jan 16 18:02:54.419] Server {0x7fade53d57e0} DEBUG: (cache_init) Span::init - /dev/sdc hw_sector_size=512 is_disk=1 adjusted_sec=1
>> [Jan 16 18:02:54.419] Server {0x7fade53d57e0} DEBUG: (cache_init) Span::init - /dev/sdc alignment = 0
>> [Jan 16 18:02:54.419] Server {0x7fade53d57e0} DEBUG: (cache_init) Span::init physical sectors 3907029168 total size 2000398934016 geometry size 2000398934016 store blocks 244189323
>> [Jan 16 18:02:54.426] Server {0x7fade53d57e0} DEBUG: (cache_init) Span::init("/usr/local/ats_422/var/trafficserver",33554432)
>> [Jan 16 18:02:54.426] Server {0x7fade53d57e0} DEBUG: (cache_init) Span::init - S_IFDIR - devnum = 2051
>> [Jan 16 18:02:54.426] Server {0x7fade53d57e0} DEBUG: (cache_init) Span::init - socketManager.open("/usr/local/ats_422/var/trafficserver", O_RDONLY) = 28
>> [Jan 16 18:02:54.426] Server {0x7fade53d57e0} DEBUG: (cache_init) Span::init - is_disk = 0, raw device = no
>> [Jan 16 18:02:54.426] Server {0x7fade53d57e0} DEBUG: (cache_init) Span::init - mapped file "/usr/local/ats_422/var/trafficserver", 33554432
>> [Jan 16 18:02:54.455] Server {0x7faddfab2700} DEBUG: (cache_init) Cache::open - proxy.config.cache.min_average_object_size = 102400
>> [Jan 16 18:02:54.465] Server {0x7faddfdb5700} DEBUG: (cache_init) allocating 195338240 directory bytes for a 2000398565376 byte volume (0.009765%)
>> [Jan 16 18:02:54.465] Server {0x7faddfeb6700} DEBUG: (cache_init) allocating 195338240 directory bytes for a 2000398565376 byte volume (0.009765%)
>> [Jan 16 18:02:54.465] Server {0x7fade53d57e0} DEBUG: (cache_init) allocating 195338240 directory bytes for a 2000398565376 byte volume (0.009765%)
>> [Jan 16 18:02:54.465] Server {0x7faddfcb4700} DEBUG: (cache_init) allocating 195338240 directory bytes for a 2000398565376 byte volume (0.009765%)
>> 
>> *********************************************************************************************************
>> 
> 


Re: Do not use the disks

Posted by Leif Hedstrom <zw...@apache.org>.
> On Jan 16, 2016, at 3:22 AM, feng D <fe...@gmail.com> wrote:
> 
> Hi:
>     
>      I use the traffic server as the Reverse Proxy with four disks as the cache. But I found that traffic server not use the disks.  The log in diags.log has not 'cache enabled' and not 'cache disabled’.

A guess is that this means something:


[Jan 16 18:02:54.428] Server {0x7fade53d57e0} WARNING: unable to open cache disk(s): InterimCache Cache Disabled



Like, did you misconfigure your records.config for the obsoleted (removed) interim SSD cache? We don’t have any support for that (removed) feature, so our recommendation is to not use it even in the old 4.2.x versions (you should upgrade to v4.3.x at least).

— Leif

>      
>      The version is 4.2.2. 
>      
> 
>        Who can help me.                       
> 
> 
>                                                                                                         Thanks!!!!
> 
> I open cache_init debug then the diags looks like this:
> ***********************************************************************
> [Jan 16 18:02:52.407] {0x7fade53d57e0} STATUS: opened /disk/ssd1/logs/trafficserver/diags.log
> [Jan 16 18:02:52.407] {0x7fade53d57e0} NOTE: updated diags config
> [Jan 16 18:02:54.418] Server {0x7fade53d57e0} NOTE: cache clustering disabled
> [Jan 16 18:02:54.419] Server {0x7fade53d57e0} WARNING: no interim disks specified in proxy.config.cache.interim.storage:
> [Jan 16 18:02:54.422] Server {0x7fade53d57e0} NOTE: ip_allow.config updated, reloading
> [Jan 16 18:02:54.426] Server {0x7fade53d57e0} NOTE: cache clustering disabled
> [Jan 16 18:02:54.427] Server {0x7fade53d57e0} NOTE: logging initialized[3], logging_mode = 1
> [Jan 16 18:02:54.428] Server {0x7fade53d57e0} WARNING: unable to open cache disk(s): InterimCache Cache Disabled
> [Jan 16 18:02:54.428] Server {0x7fade53d57e0} WARNING: [ReverseProxy] Unable to determine default redirect url for "referer" filter.
> [Jan 16 18:02:54.434] Server {0x7fade53d57e0} NOTE: traffic server running
> [Jan 16 18:02:54.465] Server {0x7faddfdb5700} NOTE: reading directory '/dev/sde 368640:244189278'
> [Jan 16 18:02:54.465] Server {0x7faddfeb6700} NOTE: reading directory '/dev/sdd 368640:244189278'
> [Jan 16 18:02:54.465] Server {0x7fade53d57e0} NOTE: reading directory '/dev/sdb 368640:244189278'
> [Jan 16 18:02:54.465] Server {0x7faddfcb4700} NOTE: reading directory '/dev/sdc 368640:244189278'
> [Jan 16 18:02:54.469] Server {0x7faddfeb6700} NOTE: using directory A for '/dev/sdd 368640:244189278'
> [Jan 16 18:02:54.469] Server {0x7faddfcb4700} NOTE: using directory A for '/dev/sdc 368640:244189278'
> [Jan 16 18:02:54.479] Server {0x7faddfdb5700} NOTE: using directory B for '/dev/sde 368640:244189278'
> [Jan 16 18:02:54.489] Server {0x7fade53d57e0} NOTE: using directory A for '/dev/sdb 368640:244189278'
> [Jan 16 18:02:57.403] Server {0x7faddfdb5700} NOTE: recovery clearing offsets [785550164480, 785653652992] sync_serial 10847 next 10848
> ***********************************************************************
> 
> 
> 
> The tail of traffic.out is like this:
> *********************************************************************************************************
> [Jan 16 18:02:54.419] Server {0x7fade53d57e0} DEBUG: (cache_init) Store::read_config: "/dev/sde
> "
> [Jan 16 18:02:54.419] Server {0x7fade53d57e0} DEBUG: (cache_init) Store::read_config - ns = NEW (new Span); ns->init("/dev/sde",-1), ns->vol_num=0
> [Jan 16 18:02:54.419] Server {0x7fade53d57e0} DEBUG: (cache_init) Span::init("/dev/sde",-1)
> [Jan 16 18:02:54.419] Server {0x7fade53d57e0} DEBUG: (cache_init) Span::init - S_IFBLK - devnum = 2112
> [Jan 16 18:02:54.419] Server {0x7fade53d57e0} DEBUG: (cache_init) Span::init - socketManager.open("/dev/sde", O_RDONLY) = 11
> [Jan 16 18:02:54.419] Server {0x7fade53d57e0} DEBUG: (cache_init) Span::init - /dev/sde hw_sector_size=512 is_disk=1 adjusted_sec=1
> [Jan 16 18:02:54.419] Server {0x7fade53d57e0} DEBUG: (cache_init) Span::init - /dev/sde alignment = 0
> [Jan 16 18:02:54.419] Server {0x7fade53d57e0} DEBUG: (cache_init) Span::init physical sectors 3907029168 total size 2000398934016 geometry size 2000398934016 store blocks 244189323
> [Jan 16 18:02:54.419] Server {0x7fade53d57e0} DEBUG: (cache_init) Store::read_config: "/dev/sdc
> "
> [Jan 16 18:02:54.419] Server {0x7fade53d57e0} DEBUG: (cache_init) Store::read_config - ns = NEW (new Span); ns->init("/dev/sdc",-1), ns->vol_num=0
> [Jan 16 18:02:54.419] Server {0x7fade53d57e0} DEBUG: (cache_init) Span::init("/dev/sdc",-1)
> [Jan 16 18:02:54.419] Server {0x7fade53d57e0} DEBUG: (cache_init) Span::init - S_IFBLK - devnum = 2080
> [Jan 16 18:02:54.419] Server {0x7fade53d57e0} DEBUG: (cache_init) Span::init - socketManager.open("/dev/sdc", O_RDONLY) = 11
> [Jan 16 18:02:54.419] Server {0x7fade53d57e0} DEBUG: (cache_init) Span::init - /dev/sdc hw_sector_size=512 is_disk=1 adjusted_sec=1
> [Jan 16 18:02:54.419] Server {0x7fade53d57e0} DEBUG: (cache_init) Span::init - /dev/sdc alignment = 0
> [Jan 16 18:02:54.419] Server {0x7fade53d57e0} DEBUG: (cache_init) Span::init physical sectors 3907029168 total size 2000398934016 geometry size 2000398934016 store blocks 244189323
> [Jan 16 18:02:54.426] Server {0x7fade53d57e0} DEBUG: (cache_init) Span::init("/usr/local/ats_422/var/trafficserver",33554432)
> [Jan 16 18:02:54.426] Server {0x7fade53d57e0} DEBUG: (cache_init) Span::init - S_IFDIR - devnum = 2051
> [Jan 16 18:02:54.426] Server {0x7fade53d57e0} DEBUG: (cache_init) Span::init - socketManager.open("/usr/local/ats_422/var/trafficserver", O_RDONLY) = 28
> [Jan 16 18:02:54.426] Server {0x7fade53d57e0} DEBUG: (cache_init) Span::init - is_disk = 0, raw device = no
> [Jan 16 18:02:54.426] Server {0x7fade53d57e0} DEBUG: (cache_init) Span::init - mapped file "/usr/local/ats_422/var/trafficserver", 33554432
> [Jan 16 18:02:54.455] Server {0x7faddfab2700} DEBUG: (cache_init) Cache::open - proxy.config.cache.min_average_object_size = 102400
> [Jan 16 18:02:54.465] Server {0x7faddfdb5700} DEBUG: (cache_init) allocating 195338240 directory bytes for a 2000398565376 byte volume (0.009765%)
> [Jan 16 18:02:54.465] Server {0x7faddfeb6700} DEBUG: (cache_init) allocating 195338240 directory bytes for a 2000398565376 byte volume (0.009765%)
> [Jan 16 18:02:54.465] Server {0x7fade53d57e0} DEBUG: (cache_init) allocating 195338240 directory bytes for a 2000398565376 byte volume (0.009765%)
> [Jan 16 18:02:54.465] Server {0x7faddfcb4700} DEBUG: (cache_init) allocating 195338240 directory bytes for a 2000398565376 byte volume (0.009765%)
> 
> *********************************************************************************************************
>