[
https://issues.apache.org/jira/browse/TS-3377?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=14310327#comment-14310327
]
Leif Hedstrom commented on TS-3377:
-----------------------------------
What's even more confusing (thanks James), is that it looks like at startup it
should have succeeded:
{code}
[root@qa1 ats]# ./bin/traffic_server -T cache
traffic_server: using root directory '/opt/ats'
[Feb 7 00:44:35.535] Server {0x7fa61434b880} DEBUG: (cache_init)
proxy.config.cache.ram_cache.size = 1073741824 = 1024Mb
[Feb 7 00:44:35.535] Server {0x7fa61434b880} DEBUG: (cache_init)
proxy.config.cache.limits.http.max_alts = 4
[Feb 7 00:44:35.535] Server {0x7fa61434b880} DEBUG: (cache_init)
cache_config_ram_cache_cutoff = 4194304 = 4Mb
[Feb 7 00:44:35.535] Server {0x7fa61434b880} DEBUG: (cache_init)
proxy.config.cache.permit.pinning = 0
[Feb 7 00:44:35.535] Server {0x7fa61434b880} DEBUG: (cache_init)
proxy.config.cache.dir.sync_frequency = 600
[Feb 7 00:44:35.535] Server {0x7fa61434b880} DEBUG: (cache_init)
proxy.config.cache.select_alternate = 1
[Feb 7 00:44:35.535] Server {0x7fa61434b880} DEBUG: (cache_init)
proxy.config.cache.max_doc_size = 0 = 0Mb
[Feb 7 00:44:35.535] Server {0x7fa61434b880} DEBUG: (cache_init)
proxy.config.cache.mutex_retry_delay = 2ms
[Feb 7 00:44:35.535] Server {0x7fa61434b880} DEBUG: (cache_init)
proxy.config.cache.hit_evacuate_percent = 0
[Feb 7 00:44:35.535] Server {0x7fa61434b880} DEBUG: (cache_init)
proxy.config.cache.hit_evacuate_size_limit = 0
[Feb 7 00:44:35.535] Server {0x7fa61434b880} DEBUG: (cache_init)
proxy.config.cache.max_disk_errors = 5
[Feb 7 00:44:35.535] Server {0x7fa61434b880} DEBUG: (cache_init)
proxy.config.cache.agg_write_backlog = 5242880
[Feb 7 00:44:35.535] Server {0x7fa61434b880} DEBUG: (cache_init)
proxy.config.cache.enable_checksum = 0
[Feb 7 00:44:35.535] Server {0x7fa61434b880} DEBUG: (cache_init)
proxy.config.cache.alt_rewrite_max_size = 4096
[Feb 7 00:44:35.535] Server {0x7fa61434b880} DEBUG: (cache_init)
proxy.config.cache.enable_read_while_writer = 1
[Feb 7 00:44:35.535] Server {0x7fa61434b880} DEBUG: (cache_init)
Store::read_config, fd = -1, "/opt/ats/etc/trafficserver/storage.config"
[Feb 7 00:44:35.536] Server {0x7fa61434b880} DEBUG: (cache_init)
Store::read_config: "/dev/xvdb1"
[Feb 7 00:44:35.536] Server {0x7fa61434b880} DEBUG: (cache_init)
Store::read_config - ns = new Span; ns->init("/dev/xvdb1",-1), forced volume=-1
[Feb 7 00:44:35.536] Server {0x7fa61434b880} DEBUG: (cache_init) initialized
span '/dev/xvdb1'
[Feb 7 00:44:35.536] Server {0x7fa61434b880} DEBUG: (cache_init)
hw_sector_size=512, size=23040000000, blocks=2812500, disk_id=0/51729,
file_pathname=1
[Feb 7 00:44:35.536] Server {0x7fa61434b880} DEBUG: (cache_init)
Store::read_config: "/dev/xvdb2"
[Feb 7 00:44:35.536] Server {0x7fa61434b880} DEBUG: (cache_init)
Store::read_config - ns = new Span; ns->init("/dev/xvdb2",-1), forced volume=-1
[Feb 7 00:44:35.536] Server {0x7fa61434b880} DEBUG: (cache_init) initialized
span '/dev/xvdb2'
[Feb 7 00:44:35.536] Server {0x7fa61434b880} DEBUG: (cache_init)
hw_sector_size=512, size=23040000000, blocks=2812500, disk_id=0/51730,
file_pathname=1
[Feb 7 00:44:35.551] Server {0x7fa61434b880} DEBUG: (cache_init) initialized
span '/opt/ats/var/trafficserver'
[Feb 7 00:44:35.551] Server {0x7fa61434b880} DEBUG: (cache_init)
hw_sector_size=4096, size=1048576, blocks=128, disk_id=51713/1710129,
file_pathname=0
[Feb 7 00:44:35.564] Server {0x7fa61434b880} DEBUG: (cache_hosting) Disk: 0,
blocks: 2812500
[Feb 7 00:44:35.570] Server {0x7fa61434b880} DEBUG: (cache_hosting) Disk: 1,
blocks: 2812500
[Feb 7 00:44:35.584] Server {0x7fa609d1b700} DEBUG: (cache_hosting) Disk: 0:
Vol Blocks: 1: Free space: 0
[Feb 7 00:44:35.584] Server {0x7fa609d1b700} DEBUG: (cache_hosting) Vol: 0
Size: 2812498
[Feb 7 00:44:35.584] Server {0x7fa609d1b700} DEBUG: (cache_hosting) Block
No: 0 Size: 2812498 Free: 0
[Feb 7 00:44:35.584] Server {0x7fa609d1b700} DEBUG: (cache_init) Cache::open -
proxy.config.cache.min_average_object_size = 8000
[Feb 7 00:44:35.587] Server {0x7fa609d1b700} DEBUG: (cache_init) allocating
28745728 directory bytes for a 23039983616 byte volume (0.124765%)
[Feb 7 00:44:35.718] Server {0x7fa60a529700} DEBUG: (cache_hosting) Host
Record: 0x60b0000107a8, Volume: 0, size: 2812498
[Feb 7 00:44:35.720] Server {0x7fa60a529700} DEBUG: (cache_init)
build_vol_hash_table index 0 mapped to 0 requested 32707 got 32707
[Feb 7 00:44:35.720] Server {0x7fa60a529700} DEBUG: (cache_init)
CacheProcessor::cacheInitialized - theCache, total_size = 2812498 = 21972 MB
[Feb 7 00:44:35.720] Server {0x7fa60a529700} DEBUG: (cache_init)
CacheProcessor::cacheInitialized - caches_ready=0x9, gnvol=1
[Feb 7 00:44:35.720] Server {0x7fa60a529700} DEBUG: (cache_init)
CacheProcessor::cacheInitialized - 1073741824 != AUTO_SIZE_RAM_CACHE
[Feb 7 00:44:35.720] Server {0x7fa60a529700} DEBUG: (cache_init)
CacheProcessor::cacheInitialized - http_ram_cache_size = 1073741824 = 1024Mb
[Feb 7 00:44:35.720] Server {0x7fa60a529700} DEBUG: (cache_init)
CacheProcessor::cacheInitialized - stream_ram_cache_size = 0 = 0Mb
[Feb 7 00:44:35.720] Server {0x7fa60a529700} DEBUG: (cache_init)
CacheProcessor::cacheInitialized - factor = 1.000000
[Feb 7 00:44:35.720] Server {0x7fa60a529700} DEBUG: (cache_init)
CacheProcessor::cacheInitialized[0] - ram_cache_bytes = 1073741824 = 1024Mb
[Feb 7 00:44:35.720] Server {0x7fa60a529700} DEBUG: (cache_init)
CacheProcessor::cacheInitialized - total_cache_bytes = 23011237888 = 21945Mb
{code}
However, as indicated by diags.log, it does indeed ignore the second disk,
shown by the amount of disk cache available:
{code}
[root@qa1 ats]# traffic_line -r proxy.node.cache.bytes_total
23011237888
{code}
I would have expected twice this, as shown from disk:
{code}
Disk /dev/xvdb: 53.7 GB, 53687091200 bytes, 104857600 sectors
Units = sectors of 1 * 512 = 512 bytes
Sector size (logical/physical): 512 bytes / 512 bytes
I/O size (minimum/optimal): 512 bytes / 512 bytes
Disk label type: dos
Disk identifier: 0xaf45edb3
Device Boot Start End Blocks Id System
/dev/xvdb1 2048 45002048 22500000+ 83 Linux
/dev/xvdb2 45002752 90002752 22500000+ 83 Linux
/dev/xvdb4 90005504 104857599 7426048 83 Linux
{code}
I'll roll back to v5.2.0, to make sure this problem is not in that version.
> Some disks in storage.config considered bad for no good reason
> --------------------------------------------------------------
>
> Key: TS-3377
> URL: https://issues.apache.org/jira/browse/TS-3377
> Project: Traffic Server
> Issue Type: Bug
> Components: Cache
> Reporter: Leif Hedstrom
> Assignee: Alan M. Carroll
> Priority: Blocker
> Fix For: 5.3.0
>
>
> Using latest master, I have a config like
> {code}
> /dev/xvdb1
> /dev/xvdb2
> {code}
> The files are properly udev'ed, i.e.
> {code}
> [root@qa1 ats]# ls -lrt /dev/xvdb[12]
> brw-rw----. 1 root nobody 202, 18 Feb 7 00:36 /dev/xvdb2
> brw-rw----. 1 root nobody 202, 17 Feb 7 00:36 /dev/xvdb1
> {code}
> If I initialize the cache, everything looks fine:
> {code}
> [root@qa1 ats]# ./bin/traffic_server -Cclear -T cache
> traffic_server: using root directory '/opt/ats'
> [Feb 7 00:36:33.588] Server {0x7fc313646880} DEBUG: (cache_init)
> proxy.config.cache.ram_cache.size = 1073741824 = 1024Mb
> [Feb 7 00:36:33.588] Server {0x7fc313646880} DEBUG: (cache_init)
> proxy.config.cache.limits.http.max_alts = 4
> [Feb 7 00:36:33.588] Server {0x7fc313646880} DEBUG: (cache_init)
> cache_config_ram_cache_cutoff = 4194304 = 4Mb
> [Feb 7 00:36:33.588] Server {0x7fc313646880} DEBUG: (cache_init)
> proxy.config.cache.permit.pinning = 0
> [Feb 7 00:36:33.588] Server {0x7fc313646880} DEBUG: (cache_init)
> proxy.config.cache.dir.sync_frequency = 600
> [Feb 7 00:36:33.588] Server {0x7fc313646880} DEBUG: (cache_init)
> proxy.config.cache.select_alternate = 1
> [Feb 7 00:36:33.588] Server {0x7fc313646880} DEBUG: (cache_init)
> proxy.config.cache.max_doc_size = 0 = 0Mb
> [Feb 7 00:36:33.588] Server {0x7fc313646880} DEBUG: (cache_init)
> proxy.config.cache.mutex_retry_delay = 2ms
> [Feb 7 00:36:33.588] Server {0x7fc313646880} DEBUG: (cache_init)
> proxy.config.cache.hit_evacuate_percent = 0
> [Feb 7 00:36:33.588] Server {0x7fc313646880} DEBUG: (cache_init)
> proxy.config.cache.hit_evacuate_size_limit = 0
> [Feb 7 00:36:33.588] Server {0x7fc313646880} DEBUG: (cache_init)
> proxy.config.cache.max_disk_errors = 5
> [Feb 7 00:36:33.588] Server {0x7fc313646880} DEBUG: (cache_init)
> proxy.config.cache.agg_write_backlog = 5242880
> [Feb 7 00:36:33.588] Server {0x7fc313646880} DEBUG: (cache_init)
> proxy.config.cache.enable_checksum = 0
> [Feb 7 00:36:33.588] Server {0x7fc313646880} DEBUG: (cache_init)
> proxy.config.cache.alt_rewrite_max_size = 4096
> [Feb 7 00:36:33.588] Server {0x7fc313646880} DEBUG: (cache_init)
> proxy.config.cache.enable_read_while_writer = 1
> [Feb 7 00:36:33.588] Server {0x7fc313646880} DEBUG: (cache_init)
> Store::read_config, fd = -1, "/opt/ats/etc/trafficserver/storage.config"
> [Feb 7 00:36:33.588] Server {0x7fc313646880} DEBUG: (cache_init)
> Store::read_config: "/dev/xvdb1"
> [Feb 7 00:36:33.588] Server {0x7fc313646880} DEBUG: (cache_init)
> Store::read_config - ns = new Span; ns->init("/dev/xvdb1",-1), forced
> volume=-1
> [Feb 7 00:36:33.589] Server {0x7fc313646880} DEBUG: (cache_init) initialized
> span '/dev/xvdb1'
> [Feb 7 00:36:33.589] Server {0x7fc313646880} DEBUG: (cache_init)
> hw_sector_size=512, size=23040000000, blocks=2812500, disk_id=0/51729,
> file_pathname=1
> [Feb 7 00:36:33.589] Server {0x7fc313646880} DEBUG: (cache_init)
> Store::read_config: "/dev/xvdb2"
> [Feb 7 00:36:33.589] Server {0x7fc313646880} DEBUG: (cache_init)
> Store::read_config - ns = new Span; ns->init("/dev/xvdb2",-1), forced
> volume=-1
> [Feb 7 00:36:33.589] Server {0x7fc313646880} DEBUG: (cache_init) initialized
> span '/dev/xvdb2'
> [Feb 7 00:36:33.589] Server {0x7fc313646880} DEBUG: (cache_init)
> hw_sector_size=512, size=23040000000, blocks=2812500, disk_id=0/51730,
> file_pathname=1
> [Feb 7 00:36:33.601] Server {0x7fc313646880} DEBUG: (cache_init) initialized
> span '/opt/ats/var/trafficserver'
> [Feb 7 00:36:33.601] Server {0x7fc313646880} DEBUG: (cache_init)
> hw_sector_size=4096, size=1048576, blocks=128, disk_id=51713/1710129,
> file_pathname=0
> [Feb 7 00:36:33.603] Server {0x7fc313646880} DEBUG: (cache_hosting) Disk: 0,
> blocks: 2812500
> [Feb 7 00:36:33.609] Server {0x7fc313646880} DEBUG: (cache_hosting) Disk: 1,
> blocks: 2812500
> [Feb 7 00:36:33.617] Server {0x7fc309824700} DEBUG: (cache_hosting) blocks =
> 2812498
> [Feb 7 00:36:33.617] Server {0x7fc309824700} DEBUG: (cache_hosting) Disk: 0:
> Vol Blocks: 1: Free space: 0
> [Feb 7 00:36:33.617] Server {0x7fc309824700} DEBUG: (cache_hosting) Vol: 0
> Size: 2812498
> [Feb 7 00:36:33.617] Server {0x7fc309824700} DEBUG: (cache_hosting) Block
> No: 0 Size: 2812498 Free: 0
> [Feb 7 00:36:33.617] Server {0x7fc309824700} DEBUG: (cache_init) Cache::open
> - proxy.config.cache.min_average_object_size = 8000
> [Feb 7 00:36:33.619] Server {0x7fc309824700} DEBUG: (cache_init) allocating
> 28745728 directory bytes for a 23039983616 byte volume (0.124765%)
> [Feb 7 00:36:33.781] Server {0x7fc308c0f700} DEBUG: (cache_hosting) Host
> Record: 0x60b000015fa8, Volume: 0, size: 2812498
> [Feb 7 00:36:33.782] Server {0x7fc308c0f700} DEBUG: (cache_init)
> build_vol_hash_table index 0 mapped to 0 requested 32707 got 32707
> [Feb 7 00:36:33.782] Server {0x7fc308c0f700} DEBUG: (cache_init)
> CacheProcessor::cacheInitialized - theCache, total_size = 2812498 = 21972 MB
> [Feb 7 00:36:33.782] Server {0x7fc308c0f700} DEBUG: (cache_init)
> CacheProcessor::cacheInitialized - caches_ready=0x9, gnvol=1
> [Feb 7 00:36:33.782] Server {0x7fc308c0f700} DEBUG: (cache_init)
> CacheProcessor::cacheInitialized - 1073741824 != AUTO_SIZE_RAM_CACHE
> [Feb 7 00:36:33.782] Server {0x7fc308c0f700} DEBUG: (cache_init)
> CacheProcessor::cacheInitialized - http_ram_cache_size = 1073741824 = 1024Mb
> [Feb 7 00:36:33.782] Server {0x7fc308c0f700} DEBUG: (cache_init)
> CacheProcessor::cacheInitialized - stream_ram_cache_size = 0 = 0Mb
> [Feb 7 00:36:33.782] Server {0x7fc308c0f700} DEBUG: (cache_init)
> CacheProcessor::cacheInitialized - factor = 1.000000
> [Feb 7 00:36:33.782] Server {0x7fc308c0f700} DEBUG: (cache_init)
> CacheProcessor::cacheInitialized[0] - ram_cache_bytes = 1073741824 = 1024Mb
> [Feb 7 00:36:33.782] Server {0x7fc308c0f700} DEBUG: (cache_init)
> CacheProcessor::cacheInitialized - total_cache_bytes = 23011237888 = 21945Mb
> {code}
> However, when I start up ATS properly, I get the following errors in digs.log:
> {code}
> [Feb 7 00:39:01.825] {0x2b44b022d1c0} STATUS: opened
> /opt/ats/var/log/trafficserver/diags.log
> [Feb 7 00:39:01.825] {0x2b44b022d1c0} NOTE: updated diags config
> [Feb 7 00:39:01.835] Server {0x2b44b022d1c0} NOTE: cache clustering disabled
> [Feb 7 00:39:01.846] Server {0x2b44b022d1c0} NOTE: ip_allow.config updated,
> reloading
> [Feb 7 00:39:01.854] Server {0x2b44b022d1c0} NOTE: cache clustering disabled
> [Feb 7 00:39:01.856] Server {0x2b44b022d1c0} NOTE: logging initialized[3],
> logging_mode = 3
> [Feb 7 00:39:01.857] Server {0x2b44b022d1c0} NOTE: loading plugin
> '/opt/ats/libexec/trafficserver/stats_over_http.so'
> [Feb 7 00:39:01.860] Server {0x2b44b022d1c0} NOTE: loading SSL certificate
> configuration from /opt/ats/etc/trafficserver/ssl_multicert.config
> [Feb 7 00:39:01.877] Server {0x2b44beabc700} WARNING: cache disk operation
> failed READ -1 21
> [Feb 7 00:39:01.884] Server {0x2b44b022d1c0} NOTE: traffic server running
> [Feb 7 00:39:01.884] Server {0x2b44ba422700} WARNING: could not read disk
> header for disk /dev/xvdb2: declaring disk bad
> [Feb 7 00:39:01.977] Server {0x2b44b9c14700} NOTE: cache enabled
> {code}
> I've tried this with 3 and 4 disks as well, and it always fails to setup
> anything but the first disk at normal startup.
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
