Open Stack

Here's a sample of the CSV in container log_processing_data, created today
at 13:00

data_ts,account,2xx,4xx,5xx,COPY,DELETE,GET,HEAD,POST,PUT,account_requests,bytes_used,container_count,container_requests,object_count,object_requests,ops_count,public_bw_in,public_bw_out,public_request,replica_count,service_bw_in,service_bw_out,service_request

2012/04/12 11:00:00,AUTH_<ACCOUNT_HASH>
,0,0,0,0,0,0,0,0,0,0,6312340991862,78,0,36159567,0,0,0,0,0,3,0,0,0

2012/04/12
14:00:00,AUTH_<ACCOUNT_HASH>,337139,15073,0,0,150,344996,319,0,6747,72,0,0,15,0,352125,352212,833754949,24633236061,352212,0,0,0,0

The first line is the header, for reference.
The second line is the data from the container-stats and account-stats
plugins.  They are OK.  They match what's in the account_stats and
container_stats containers.
The third line is the problem.  This data matches the log_data container
for log_data/2012/04/12/* but is processed to represent the NEXT hour from
current time on my log processing box, 14:00.

It seems to me that there might be going wrong in the access plugin of the
swift-log-stats-collector:

cat /etc/cron.d/slog
30 * * * * root /usr/bin/swift-log-stats-collector -v
/etc/swift/log-processor.conf

Here's the debug log of that run:

Apr 12 13:30:02 admin01-c01 swift Beginning log processing
Apr 12 13:30:03 admin01-c01 swift loaded 18 files to process
Apr 12 13:30:03 admin01-c01 swift Processing
AUTH_fb16074a-7a0c-4dfd-b8f1-fcdf2e91f7ad/log_data/2012/04/12/10/0fd244e646b2e230f0ab269cd97b65d9.gz
with plugin "access"
Apr 12 13:30:23 admin01-c01 swift Processing
AUTH_fb16074a-7a0c-4dfd-b8f1-fcdf2e91f7ad/log_data/2012/04/12/10/73b6a1720f8093314ee3e76a43f6499e.gz
with plugin "access"
Apr 12 13:30:30 admin01-c01 swift Processing
AUTH_fb16074a-7a0c-4dfd-b8f1-fcdf2e91f7ad/log_data/2012/04/12/10/78fc29ff0ee1a9be4276ce834a49f35d.gz
with plugin "access"
Apr 12 13:30:32 admin01-c01 swift Processing
AUTH_fb16074a-7a0c-4dfd-b8f1-fcdf2e91f7ad/log_data/2012/04/12/10/b5a4396d5eb26e50524b19d4e10b5ed2.gz
with plugin "access"
Apr 12 13:30:36 admin01-c01 swift Processing
AUTH_fb16074a-7a0c-4dfd-b8f1-fcdf2e91f7ad/log_data/2012/04/12/10/e4ddb36da54ccf24b3e41bbc3a2ab654.gz
with plugin "access"
Apr 12 13:30:38 admin01-c01 swift Processing
AUTH_fb16074a-7a0c-4dfd-b8f1-fcdf2e91f7ad/container_stats/2012/04/12/11/12fbc53f4be0efbe9c50c0f838f53671.gz
with plugin "container-stats"
Apr 12 13:30:38 admin01-c01 swift Processing
AUTH_fb16074a-7a0c-4dfd-b8f1-fcdf2e91f7ad/container_stats/2012/04/12/11/2f0259a57792dda06b970b2b69e801af.gz
with plugin "container-stats"
Apr 12 13:30:38 admin01-c01 swift Processing
AUTH_fb16074a-7a0c-4dfd-b8f1-fcdf2e91f7ad/container_stats/2012/04/12/11/69334fb9f9ffe556bdc8099d4184d2f0.gz
with plugin "container-stats"
Apr 12 13:30:38 admin01-c01 swift Processing
AUTH_fb16074a-7a0c-4dfd-b8f1-fcdf2e91f7ad/container_stats/2012/04/12/11/776e75e51976be9def1220cd4c7dbfcb.gz
with plugin "container-stats"
Apr 12 13:30:38 admin01-c01 swift Processing
AUTH_fb16074a-7a0c-4dfd-b8f1-fcdf2e91f7ad/container_stats/2012/04/12/11/9c008d5090f2ff5d9a9e9b173fd538e9.gz
with plugin "container-stats"
Apr 12 13:30:38 admin01-c01 swift Processing
AUTH_fb16074a-7a0c-4dfd-b8f1-fcdf2e91f7ad/container_stats/2012/04/12/11/9cc04dd57b2a1a4f62c52cd7cb80ca81.gz
with plugin "container-stats"
Apr 12 13:30:38 admin01-c01 swift Processing
AUTH_fb16074a-7a0c-4dfd-b8f1-fcdf2e91f7ad/container_stats/2012/04/12/11/edd3240591b5fde0ea56c52c8109593c.gz
with plugin "container-stats"
Apr 12 13:30:38 admin01-c01 swift Processing
AUTH_fb16074a-7a0c-4dfd-b8f1-fcdf2e91f7ad/account_stats/2012/04/12/11/0ce8c4de4254740333e65f995e40170b.gz
with plugin "stats"
Apr 12 13:30:38 admin01-c01 swift Processing
AUTH_fb16074a-7a0c-4dfd-b8f1-fcdf2e91f7ad/account_stats/2012/04/12/11/165330fe57be34910614c15580eb3f07.gz
with plugin "stats"
Apr 12 13:30:38 admin01-c01 swift Processing
AUTH_fb16074a-7a0c-4dfd-b8f1-fcdf2e91f7ad/account_stats/2012/04/12/11/a67accbd8063a193630c5e12739e3dbb.gz
with plugin "stats"
Apr 12 13:30:38 admin01-c01 swift Processing
AUTH_fb16074a-7a0c-4dfd-b8f1-fcdf2e91f7ad/account_stats/2012/04/12/11/ab5947d10efa6e6793e9d68dab716e2c.gz
with plugin "stats"
Apr 12 13:30:38 admin01-c01 swift Processing
AUTH_fb16074a-7a0c-4dfd-b8f1-fcdf2e91f7ad/account_stats/2012/04/12/11/b46f0efe93742e7792e45075cd9aa5f4.gz
with plugin "stats"
Apr 12 13:30:38 admin01-c01 swift Processing
AUTH_fb16074a-7a0c-4dfd-b8f1-fcdf2e91f7ad/account_stats/2012/04/12/11/d693d9b9ae133c459fecb45423ed878f.gz
with plugin "stats"
Apr 12 13:30:43 admin01-c01 swift Log processing done (0.68 minutes)


For the record, here's the config file:

[log-processor]
swift_account = AUTH_fb16074a-7a0c-4dfd-b8f1-fcdf2e91f7ad
user = syslog
set log_level = DEBUG
set log_name = slog-proc

[log-processor-access]
set log_level = DEBUG
set log_name = slog-access
swift_account = AUTH_fb16074a-7a0c-4dfd-b8f1-fcdf2e91f7ad
container_name = log_data
log_dir = /var/log/swift/hourly/
source_filename_pattern = ^
    (?P<year>[0-9]{4})
    (?P<month>[0-1][0-9])
    (?P<day>[0-3][0-9])
    (?P<hour>[0-2][0-9])
    .*$
class_path = slogging.access_processor.AccessLogProcessor
user = swift

[log-processor-stats]
set log_level = DEBUG
set log_name = slog-stats
swift_account = AUTH_fb16074a-7a0c-4dfd-b8f1-fcdf2e91f7ad
container_name = account_stats
log_dir = /var/log/swift/stats/
class_path = slogging.stats_processor.StatsLogProcessor
devices = /srv/node/
mount_check = false
user = swift

[log-processor-container-stats]
set log_level = DEBUG
set log_name = slog-c-stats
swift_account = AUTH_fb16074a-7a0c-4dfd-b8f1-fcdf2e91f7ad
container_name = container_stats
log_dir = /var/log/swift/stats/
class_path = slogging.stats_processor.StatsLogProcessor
processable = false
devices = /srv/node/
mount_check = false
user =  swift

Could it be something as stupid as my "set log_name" calls, which are
probably ignored by slogging?

Otherwise, what could be making my timestamps for "access" plugin use the
upcoming hour instead of the one present in the filename, AND in the data?

Thanks,
-judd
--
Judd Maltin
T: 917-882-1270
F: 501-694-7809
A loving heart is never wrong.
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.openstack.org/pipermail/openstack-operators/attachments/20120412/9da34dca/attachment-0002.html>