Ice reader/ui not refreshing with new data about ice HOT 19 CLOSED

@rayrod2030 I pushed a fix for this last night. Please get the latest code and see if this problem goes away.

from ice.

I am encountering this on git commit c88ce8e.
I deployed the latest source this morning as a .war to our Tomcat server running on ICE. Hours later, I check it and see zero values in the last few hours (notice the string of zeros in the screenshot). Similar to @rayrod2030 catalina.out reports Tomcat trying to find new tag group and data managers every 5 minutes, and eventually processing and pushing updated files back to S3. As well, S3's last modified dates are being updated.

Am I missing something? Thanks!

from ice.

@jasonshah I'm not sure what is the issue here. It could be just because the billing file does not have the latest data yet... I would wait for a little bit more time until your billing file is updated again and verify the UI is updated too.

from ice.

@jasonshah In order to get the charts updating again with the latest version I had to clear out my work bucket and any local work files in my processor and reader nodes. This might have been overkill but it solved my update problems with the version you are running. Also there is definitely a delay between when amazon updates their billing files in your account and when it's processed in ice and then eventually displayed in the UI. I'm finding the delay to be around 4 to 6 hours. Try to reset your files and reprocess as I suggested and give it a night to do it's thang.

from ice.

It shouldn't take 4-6 hours... Anyway, I update the processor code to check new Billing files more often (from every hour to every 5 minutes). This should speed up things a little.

from ice.

Unfortunately, I'm still having the same issue. I redeployed the .war based on git HEAD aa57913 this morning. This afternoon, I still see zero values.

I wonder if there is something I'm doing wrong with the instance at this point, but find that hard to believe. It's a stock AWS Ubuntu 12.04 t1.micro instance with Tomcat installed (and little else). I am running both reader and processor on the instance. Yes, it's small, but this shouldn't require a lot of resources to run and I'm the primary users.

Perhaps I can try another AWS instance, or diving into Tomcat hosting itself?
Or perhaps I can dig into the output that Ice is pushing to S3 to see what it's generating? It appears to be garbage; is it zipped/compressed in some way?

Thanks for the help!

from ice.

... though, interestingly, after removing all working output from both the instance and S3, then restarting Tomcat, I still see the same data. I'll check back tomorrow. But in the meantime, if you have suggestions, please let me know.

from ice.

@jasonshah looking at the 2 snapshots you posted, it seems like the data are getting updated in the UI.

The issue is that there are some zero values at the end. Are you looking at cost or usage? Do you also see all zero values for usage?

from ice.

@jasonshah I fixed the zero values issue. Please pull the latest code and try again.

from ice.

Great. I just deployed from git rev-parse HEAD = 52c12f7. I'll keep a close eye on it tomorrow. Thanks @fangji !

from ice.

I checked this morning, and unfortunately the same issue still occurs. Latest data was current as of 1PM July 2, 12 hours ago I think.

It seems to be something with the reader. I did the following:

• verified that the process output and S3 bucket had been updated with new data, and verified that the instance's Tomcat server continued to run
• copied the processor and reader working files from the AWS instance to my local setup
• verified that the issue existed on my local
• tried to simply delete the reader working files then refresh the page. Reader files didn't regenerate (I thought reader operated as a cache, but I guess not)
• killed then restarted with ./grailsw run-app. Reader files regenerated, and web page filled with newest data.

FYI, I am not using the "with tags" version of the AWS billing details zip file. My zip file looks like:
xxxxxxxxxxxx-aws-billing-detailed-line-items-2013-06.csv.zip
xxxxxxxxxxxx-aws-billing-detailed-line-items-2013-07.csv.zip

And my catalina.out logs from the AWS instance look like this:

2013-07-03 13:40:14,275 [com.netflix.ice.basic.BasicManagers] INFO basic.BasicManagers - trying to find new tag group and data managers...
2013-07-03 13:45:14,405 [com.netflix.ice.basic.BasicManagers] INFO basic.BasicManagers - trying to find new tag group and data managers...
2013-07-03 13:50:14,522 [com.netflix.ice.basic.BasicManagers] INFO basic.BasicManagers - trying to find new tag group and data managers...
2013-07-03 13:55:14,659 [com.netflix.ice.basic.BasicManagers] INFO basic.BasicManagers - trying to find new tag group and data managers...
2013-07-03 13:56:20,340 [com.netflix.ice.processor.BillingFileProcessor] INFO processor.BillingFileProcessor - data has been processed. ignoring 648179946124-aws-billing-detailed-line-items-2013-06.csv.zip...
2013-07-03 13:56:20,395 [com.netflix.ice.processor.BillingFileProcessor] INFO processor.BillingFileProcessor - data has been processed. ignoring 648179946124-aws-billing-detailed-line-items-2013-07.csv.zip...
2013-07-03 13:56:20,396 [com.netflix.ice.processor.BillingFileProcessor] INFO processor.BillingFileProcessor - AWS usage processed.
2013-07-03 13:59:56,370 [usage_hourly_all] INFO basic.BasicDataManager - trying to download /home/tomcat7/ice/reader/usage_hourly_all_2013-06
2013-07-03 13:59:56,447 [usage_hourly_all] INFO common.AwsUtils - downloadFileIfChanged /home/tomcat7/ice/reader/usage_hourly_all_2013-06 1372820114000 1372853504000
2013-07-03 13:59:56,899 [cost_hourly_all] INFO basic.BasicDataManager - trying to download /home/tomcat7/ice/reader/cost_hourly_all_2013-06
2013-07-03 13:59:56,912 [cost_hourly_all] INFO common.AwsUtils - downloadFileIfChanged /home/tomcat7/ice/reader/cost_hourly_all_2013-06 1372820118000 1372820512000
2013-07-03 13:59:57,627 [tagdb_all] INFO common.AwsUtils - downloadFileIfChanged /home/tomcat7/ice/reader/tagdb_all 1372856176000 1372856397000
2013-07-03 14:00:14,749 [com.netflix.ice.basic.BasicManagers] INFO basic.BasicManagers - trying to find new tag group and data managers...
2013-07-03 14:05:14,867 [com.netflix.ice.basic.BasicManagers] INFO basic.BasicManagers - trying to find new tag group and data managers...
2013-07-03 14:10:15,031 [com.netflix.ice.basic.BasicManagers] INFO basic.BasicManagers - trying to find new tag group and data managers...
2013-07-03 14:15:15,144 [com.netflix.ice.basic.BasicManagers] INFO basic.BasicManagers - trying to find new tag group and data managers...
2013-07-03 14:20:15,267 [com.netflix.ice.basic.BasicManagers] INFO basic.BasicManagers - trying to find new tag group and data managers...

If you have anything you want me to try, or any areas of code you think I should try to dig into (I have a cursory understanding of Grails), please let me know.

Thanks!

from ice.

@jasonshah are your ice.processor.localDir and ice.reader.localDir the same or different?

from ice.

@jasonshah what is exactly is your issue? UI not showing the new data or seeing zero values at the end? Remember after data being processed by processor, it will take some time (5-10minutes) for reader to refresh the data. You are not supposed to manually copying files to your reader working dir. Let the reader download files from s3 bucket.

from ice.

@jasonshah One more thing, looking at your newest logs, it looks like you are still running the old code. With the newest code, message "trying to download /home/tomcat7/ice/reader/usage_hourly_all_2013-06" is supposed to show every 5 minutes.

from ice.

@fangji :

• ice.processor.localDir and ice.reader.localDir are different.
• After deployment, ICE is showing zero values for both cost and usage for all products and all accounts, from that point in time, despite the fact that the threads appear to run correctly per catalina.out. ICE no longer seems to update with the latest values after the moment of deployment and when the app is run.
• I will re-update and re-deploy cleanly (e.g. clear out all working folder data and S3 bucket) now to see if I can fix the old code issue you mentioned. Thanks for letting me know.

from ice.

After more digging, I strongly believe that Tomcat is shutting down or otherwise "losing" the running Poller threads.

Compare the two logs, obtained five minutes after the respective services were started. The first is from Grails, which continues to update the Reader working directories correctly. The second is from Tomcat, which only updates the Reader working directory the first time it seems.

GRAILS:
2013-07-04 08:10:21,047 [cost_hourly_all] INFO basic.BasicDataManager - cost_hourly_all start polling...
2013-07-04 08:10:21,047 [usage_hourly_all] INFO basic.BasicDataManager - usage_hourly_all start polling...
2013-07-04 08:10:21,048 [cost_hourly_all] INFO basic.BasicDataManager - trying to download output/reader/cost_hourly_all_2013-06
2013-07-04 08:10:21,048 [usage_hourly_all] INFO basic.BasicDataManager - trying to download output/reader/usage_hourly_all_2013-06
2013-07-04 08:10:21,049 [cost_daily_all] INFO basic.BasicDataManager - cost_daily_all start polling...
2013-07-04 08:10:21,049 [usage_daily_all] INFO basic.BasicDataManager - usage_daily_all start polling...
2013-07-04 08:10:21,050 [usage_daily_all] INFO basic.BasicDataManager - trying to download output/reader/usage_daily_all_2013
2013-07-04 08:10:21,049 [cost_weekly_all] INFO basic.BasicDataManager - cost_weekly_all start polling...
2013-07-04 08:10:21,050 [cost_weekly_all] INFO basic.BasicDataManager - trying to download output/reader/cost_weekly_all
2013-07-04 08:10:21,050 [cost_daily_all] INFO basic.BasicDataManager - trying to download output/reader/cost_daily_all_2013
2013-07-04 08:10:21,052 [cost_monthly_all] INFO basic.BasicDataManager - cost_monthly_all start polling...
2013-07-04 08:10:21,052 [usage_weekly_all] INFO basic.BasicDataManager - usage_weekly_all start polling...
2013-07-04 08:10:21,052 [usage_weekly_all] INFO basic.BasicDataManager - trying to download output/reader/usage_weekly_all
2013-07-04 08:10:21,052 [cost_monthly_all] INFO basic.BasicDataManager - trying to download output/reader/cost_monthly_all
2013-07-04 08:10:21,053 [usage_monthly_all] INFO basic.BasicDataManager - usage_monthly_all start polling...
2013-07-04 08:10:21,053 [usage_monthly_all] INFO basic.BasicDataManager - trying to download output/reader/usage_monthly_all
2013-07-04 08:10:21,069 [com.netflix.ice.processor.BillingFileProcessor] INFO processor.BillingFileProcessor - found 17 in billing bucket...
2013-07-04 08:10:21,069 [com.netflix.ice.processor.BillingFileProcessor] INFO processor.BillingFileProcessor - ignoring file XXXXXXXXXXXX-aws-billing-csv-2013-06.csv
2013-07-04 08:10:21,069 [com.netflix.ice.processor.BillingFileProcessor] INFO processor.BillingFileProcessor - ignoring file XXXXXXXXXXXX-aws-billing-csv-2013-07.csv
2013-07-04 08:10:21,070 [com.netflix.ice.processor.BillingFileProcessor] INFO processor.BillingFileProcessor - ignoring file aws-programmatic-access-test-object
2013-07-04 08:10:21,070 [com.netflix.ice.processor.BillingFileProcessor] INFO processor.BillingFileProcessor - ignoring file working/
2013-07-04 08:10:21,070 [com.netflix.ice.processor.BillingFileProcessor] INFO processor.BillingFileProcessor - ignoring file working/cost_daily_all_2013
2013-07-04 08:10:21,070 [com.netflix.ice.processor.BillingFileProcessor] INFO processor.BillingFileProcessor - ignoring file working/cost_hourly_all_2013-06
2013-07-04 08:10:21,070 [com.netflix.ice.processor.BillingFileProcessor] INFO processor.BillingFileProcessor - ignoring file working/cost_hourly_all_2013-07
2013-07-04 08:10:21,070 [com.netflix.ice.processor.BillingFileProcessor] INFO processor.BillingFileProcessor - ignoring file working/cost_monthly_all
2013-07-04 08:10:21,070 [com.netflix.ice.processor.BillingFileProcessor] INFO processor.BillingFileProcessor - ignoring file working/cost_weekly_all
2013-07-04 08:10:21,070 [com.netflix.ice.processor.BillingFileProcessor] INFO processor.BillingFileProcessor - ignoring file working/tagdb_all
2013-07-04 08:10:21,070 [com.netflix.ice.processor.BillingFileProcessor] INFO processor.BillingFileProcessor - ignoring file working/usage_daily_all_2013
2013-07-04 08:10:21,070 [com.netflix.ice.processor.BillingFileProcessor] INFO processor.BillingFileProcessor - ignoring file working/usage_hourly_all_2013-06
2013-07-04 08:10:21,070 [com.netflix.ice.processor.BillingFileProcessor] INFO processor.BillingFileProcessor - ignoring file working/usage_hourly_all_2013-07
2013-07-04 08:10:21,070 [com.netflix.ice.processor.BillingFileProcessor] INFO processor.BillingFileProcessor - ignoring file working/usage_monthly_all
2013-07-04 08:10:21,070 [com.netflix.ice.processor.BillingFileProcessor] INFO processor.BillingFileProcessor - ignoring file working/usage_weekly_all
2013-07-04 08:10:21,154 [com.netflix.ice.basic.BasicManagers] INFO basic.BasicManagers - trying to find new tag group and data managers...
2013-07-04 08:10:21,185 [com.netflix.ice.processor.BillingFileProcessor] INFO processor.BillingFileProcessor - data has been processed. ignoring XXXXXXXXXXXX-aws-billing-detailed-line-items-2013-06.csv.zip...
2013-07-04 08:10:21,195 [usage_weekly_all] INFO common.AwsUtils - downloadFileIfChanged output/reader/usage_weekly_all 1372942779000 1372943126000
2013-07-04 08:10:21,195 [usage_hourly_all] INFO common.AwsUtils - downloadFileIfChanged output/reader/usage_hourly_all_2013-06 1372889474000 1372942598000
2013-07-04 08:10:21,195 [usage_hourly_all] INFO basic.BasicDataManager - trying to download output/reader/usage_hourly_all_2013-07
2013-07-04 08:10:21,201 [usage_daily_all] INFO common.AwsUtils - downloadFileIfChanged output/reader/usage_daily_all_2013 1372942778000 1372943125000
2013-07-04 08:10:21,204 [cost_daily_all] INFO common.AwsUtils - downloadFileIfChanged output/reader/cost_daily_all_2013 1372942782000 1372943124000
2013-07-04 08:10:21,204 [cost_weekly_all] INFO common.AwsUtils - downloadFileIfChanged output/reader/cost_weekly_all 1372942782000 1372943125000
2013-07-04 08:10:21,206 [cost_hourly_all] INFO common.AwsUtils - downloadFileIfChanged output/reader/cost_hourly_all_2013-06 1372889486000 1372942591000
2013-07-04 08:10:21,206 [cost_hourly_all] INFO basic.BasicDataManager - trying to download output/reader/cost_hourly_all_2013-07
2013-07-04 08:10:21,206 [usage_monthly_all] INFO common.AwsUtils - downloadFileIfChanged output/reader/usage_monthly_all 1372942779000 1372943126000
2013-07-04 08:10:21,207 [cost_monthly_all] INFO common.AwsUtils - downloadFileIfChanged output/reader/cost_monthly_all 1372942782000 1372943126000
2013-07-04 08:10:21,249 [usage_hourly_all] INFO common.AwsUtils - downloadFileIfChanged output/reader/usage_hourly_all_2013-07 1372942787000 1372943123000
2013-07-04 08:10:21,260 [com.netflix.ice.processor.BillingFileProcessor] INFO processor.BillingFileProcessor - data has been processed. ignoring XXXXXXXXXXXX-aws-billing-detailed-line-items-2013-07.csv.zip...
2013-07-04 08:10:21,260 [com.netflix.ice.processor.BillingFileProcessor] INFO processor.BillingFileProcessor - AWS usage processed.
2013-07-04 08:10:21,267 [cost_hourly_all] INFO common.AwsUtils - downloadFileIfChanged output/reader/cost_hourly_all_2013-07 1372942792000 1372943122000

TOMCAT:
2013-07-04 13:27:56,033 [com.netflix.ice.basic.BasicManagers] INFO basic.BasicManagers - trying to find new tag group and data managers...

I know very little about hosting on Tomcat (and really have little desire to learn), and our organization doesn't have any Tomcat experts. I plan to simply restart Tomcat every hour via cron (!) until I have more time to put into figuring this out.

@fangji and @rayrod2030 thanks so much for your help with all this!

from ice.

@jasonshah too bad you are still seeing the issue.
If you want to dig more, here are some suggestions:

1. Tomcat will not just shut down poller threads. You should see the same behavior in tomcat and from grails. If not, very likely the app was not deployed correctly in tomcat (tomcat is running the old version). How did you deploy to tomcat? Did you start a brand new ec2 instance? Did you just replace the war file under webapp in tomcat?
2. Take a tread dump and verify the poller threads are running.

from ice.

closing this issue now. @jasonshah please reopen if you still see the issue.

from ice.

It still occurs, but clears itself up after a few days typically, particularly for S3 data.
I believe AWS needs to catch itself up.

Yes, please close.

from ice.