danilop / yas3fs

YAS3FS (Yet Another S3-backed File System) is a Filesystem in Userspace (FUSE) interface to Amazon S3. It was inspired by s3fs but rewritten from scratch to implement a distributed cache synchronized by Amazon SNS notifications. A web console is provided to easily monitor the nodes of a cluster.
http://danilop.github.io/yas3fs
MIT License
643 stars 98 forks source link

Folder disappears after upload #85

Open Jaykah opened 9 years ago

Jaykah commented 9 years ago

Hi,

I am seeing some strange behavior when using the latest yas3fs. Everything seems to be mounting fine, but after I upload one file to the mounted directory, the directory itself disappears. However, I can still access the mount via console, and can create files and directories within. Nonetheless, those files/folders are not displayed locally via ls -l (they do appear in S3).

Here's an excerpt from logs:

2015-03-11 22:21:16,356 DEBUG readdir '/' '0' ENOENT
2015-03-11 22:21:16,365 DEBUG do_cmd_on_s3_now_w_retries try 1 action 'set_contents_from_file' key 'jquery-1.6.1.min.js' args '[<yas3fs.FSData instance at 0x7f2ac43ba200>]' kargs '{'headers': {'Content-Type': 'application/javascript'}}'
2015-03-11 22:21:16,365 DEBUG do_cmd_on_s3_now action 'set_contents_from_file' key 'jquery-1.6.1.min.js' args '[<yas3fs.FSData instance at 0x7f2ac43ba200>]' kargs '{'headers': {'Content-Type': 'application/javascript'}}'
2015-03-11 22:21:16,446 DEBUG create_dirs_for_file '/tmp/yas3fs/mystoragedir/etags/jquery-1.6.1.min.js'
2015-03-11 22:21:16,446 DEBUG create_dirs '/tmp/yas3fs/mystoragedir/etags'
2015-03-11 22:21:16,446 DEBUG create_dirs '/tmp/yas3fs/mystoragedir/etags' already there
2015-03-11 22:21:16,447 DEBUG FSData.props[change] removed, now executing invoke_after_change lambda for: /jquery-1.6.1.min.js
2015-03-11 22:21:16,447 DEBUG set_metadata '/jquery-1.6.1.min.js' 'attr' 'None'
2015-03-11 22:21:16,447 DEBUG get_key from cache '/jquery-1.6.1.min.js'
2015-03-11 22:21:16,447 DEBUG set_metadata '/jquery-1.6.1.min.js' 'attr' 'jquery-1.6.1.min.js' Key
2015-03-11 22:21:16,448 DEBUG set_metadata '/jquery-1.6.1.min.js' 'jquery-1.6.1.min.js' S3
2015-03-11 22:21:16,448 DEBUG do_cmd_on_s3_now action 'set_contents_from_file' key 'jquery-1.6.1.min.js' args '[<yas3fs.FSData instance at 0x7f2ac43ba200>]' kargs '{'headers': {'Content-Type': 'application/javascript'}}' done
2015-03-11 22:21:16,448 DEBUG publish '['upload', u'/jquery-1.6.1.min.js', 'a34f78c3aecd182144818eb4b7303fda']'
2015-03-11 22:21:16,449 DEBUG do_cmd_on_s3_now_w_retries try 1 action 'copy' key 'jquery-1.6.1.min.js' args '['mystoragedir', u'jquery-1.6.1.min.js', {'attr': '{"st_ctime": 1426112476.0, "st_mtime": 1393547269.0, "st_nlink": 1, "st_mode": 33204, "st_size": 91342, "st_gid": 1000, "st_uid": 1000, "st_atime": 1393547269.0}'}]' kargs '{'encrypt_key': False, 'preserve_acl': False}'
2015-03-11 22:21:16,449 DEBUG do_cmd_on_s3_now action 'copy' key 'jquery-1.6.1.min.js' args '['mystoragedir', u'jquery-1.6.1.min.js', {'attr': '{"st_ctime": 1426112476.0, "st_mtime": 1393547269.0, "st_nlink": 1, "st_mode": 33204, "st_size": 91342, "st_gid": 1000, "st_uid": 1000, "st_atime": 1393547269.0}'}]' kargs '{'encrypt_key': False, 'preserve_acl': False}'
2015-03-11 22:21:16,487 DEBUG Got 1 messages from SQS
2015-03-11 22:21:16,487 DEBUG process_message '["738672c3-d048-4a04-b6bc-ecde34dcb16f", "mknod", "/jquery-1.6.1.min.js"]'
2015-03-11 22:21:16,487 DEBUG process message from self discarded '[u'738672c3-d048-4a04-b6bc-ecde34dcb16f', u'mknod', u'/jquery-1.6.1.min.js']'
2015-03-11 22:21:16,608 DEBUG Got 1 messages from SQS
2015-03-11 22:21:16,608 DEBUG process_message '["738672c3-d048-4a04-b6bc-ecde34dcb16f", "upload", "/jquery-1.6.1.min.js", "a34f78c3aecd182144818eb4b7303fda"]'
2015-03-11 22:21:16,608 DEBUG process message from self discarded '[u'738672c3-d048-4a04-b6bc-ecde34dcb16f', u'upload', u'/jquery-1.6.1.min.js', u'a34f78c3aecd182144818eb4b7303fda']'
2015-03-11 22:21:16,693 DEBUG do_cmd_on_s3_now action 'copy' key 'jquery-1.6.1.min.js' args '['mystoragedir', u'jquery-1.6.1.min.js', {'attr': '{"st_ctime": 1426112476.0, "st_mtime": 1393547269.0, "st_nlink": 1, "st_mode": 33204, "st_size": 91342, "st_gid": 1000, "st_uid": 1000, "st_atime": 1393547269.0}'}]' kargs '{'encrypt_key': False, 'preserve_acl': False}' done
2015-03-11 22:21:16,693 DEBUG publish '['md', 'attr', u'/jquery-1.6.1.min.js']'
2015-03-11 22:21:16,887 DEBUG Got 1 messages from SQS
2015-03-11 22:21:16,887 DEBUG process_message '["738672c3-d048-4a04-b6bc-ecde34dcb16f", "md", "attr", "/jquery-1.6.1.min.js"]'
2015-03-11 22:21:16,888 DEBUG process message from self discarded '[u'738672c3-d048-4a04-b6bc-ecde34dcb16f', u'md', u'attr', u'/jquery-1.6.1.min.js']'
2015-03-11 22:21:35,049 DEBUG readdir '/' '0'
2015-03-11 22:21:35,049 DEBUG readdir '/' '0' ENOENT

Am I missing something?

danilop commented 9 years ago

There is no error in the logs? Which version of Linux / kernel are you using? Can you please check the file system used by the cache is not full?

Jaykah commented 9 years ago

You are right, the cache mount was indeed full. Thanks!

Jaykah commented 9 years ago

Started having the same issue again. Have checked the cache dir, all good there. Plenty of disk space.

Here's the log of me doing an ls there (after which all folder contents disappear):

2015-04-13 17:44:32,272 DEBUG Starting publish thread
2015-04-13 17:44:32,273 DEBUG Starting queue listen thread
2015-04-13 17:44:32,273 DEBUG Starting check cache thread
2015-04-13 17:44:32,274 INFO Listening on queue: 'mystorage'
2015-04-13 17:44:32,276 DEBUG check_cache_size
2015-04-13 17:44:32,276 DEBUG Subscribing 'mystorage' to 'arn:aws:sns:us-east-1:777777777777:mystorage'
2015-04-13 17:44:32,281 DEBUG check_status
2015-04-13 17:44:32,430 DEBUG SNS SQS subscription = arn:aws:sns:us-east-1:777777777777:mystorage:9993ab4f-d0e4-447a-98ac-c8154ea612d8
2015-04-13 17:44:38,509 DEBUG readdir '/' '0'
2015-04-13 17:44:38,509 DEBUG readdir '/' '0' no cache
2015-04-13 17:44:38,510 DEBUG readdir '/' '0' S3 list ''
2015-04-13 17:44:38,674 DEBUG readdir '/' '0' S3 list key '.'
2015-04-13 17:44:38,674 DEBUG readdir '/' '0' S3 list key 'WAStorageEmulatorDb32.mdf'
2015-04-13 17:44:38,674 DEBUG readdir '/' '0' S3 list key 'openvpn-connect.json'
2015-04-13 17:44:38,675 DEBUG readdir '/' '0' S3 list key 'up_events_v4.zip'
2015-04-13 17:44:38,675 DEBUG readdir '/' '0' S3 list key '<boto.s3.prefix.Prefix object at 0x7f5a5433e1d0>'
2015-04-13 17:44:38,675 DEBUG readdir '/' '0' '[u'.', u'..', u'WAStorageEmulatorDb32.mdf', u'openvpn-connect.json', u'up_events_v4.zip', u'test']'
2015-04-13 17:44:38,676 DEBUG getattr -> '/' 'None'
2015-04-13 17:44:38,676 DEBUG getattr <- '/' 'None' cache ENOENT
2015-04-13 17:44:38,676 DEBUG getattr -> '/WAStorageEmulatorDb32.mdf' 'None'
2015-04-13 17:44:38,677 DEBUG get_metadata -> '/WAStorageEmulatorDb32.mdf' 'attr' 'None'
2015-04-13 17:44:38,677 DEBUG get_key /WAStorageEmulatorDb32.mdf
2015-04-13 17:44:38,677 DEBUG get_key from S3 #1 '/WAStorageEmulatorDb32.mdf'
2015-04-13 17:44:38,722 DEBUG get_key to cache '/WAStorageEmulatorDb32.mdf'
2015-04-13 17:44:38,722 DEBUG get_metadata '/WAStorageEmulatorDb32.mdf' 'attr' 'WAStorageEmulatorDb32.mdf' S3 found
2015-04-13 17:44:38,723 DEBUG get_metadata <- '/WAStorageEmulatorDb32.mdf' 'attr' 'WAStorageEmulatorDb32.mdf' '{u'st_ctime': 1428946795.0, u'st_mtime': 1405550162.0, u'st_nlink': 1, u'st_gid': 1000, u'st_size': 3211264, u'st_mode': 33204, u'st_uid': 1000, u'st_atime': 1405550112.0}'
2015-04-13 17:44:38,723 DEBUG getattr <- '/WAStorageEmulatorDb32.mdf' 'None' '{u'st_ctime': 1428946795.0, u'st_mtime': 1405550162.0, u'st_nlink': 1, u'st_gid': 1000, u'st_size': 3211264, u'st_mode': 33204, u'st_uid': 1000, u'st_atime': 1405550112.0}'
2015-04-13 17:44:38,723 DEBUG getattr -> '/openvpn-connect.json' 'None'
2015-04-13 17:44:38,724 DEBUG get_metadata -> '/openvpn-connect.json' 'attr' 'None'
2015-04-13 17:44:38,724 DEBUG get_key /openvpn-connect.json
2015-04-13 17:44:38,724 DEBUG get_key from S3 #1 '/openvpn-connect.json'
2015-04-13 17:44:38,774 DEBUG get_key to cache '/openvpn-connect.json'
2015-04-13 17:44:38,775 DEBUG get_metadata '/openvpn-connect.json' 'attr' 'openvpn-connect.json' S3 found
2015-04-13 17:44:38,775 DEBUG get_metadata <- '/openvpn-connect.json' 'attr' 'openvpn-connect.json' '{u'st_ctime': 1428946777.0, u'st_mtime': 1428946778.0, u'st_nlink': 1, u'st_gid': 1000, u'st_size': 356, u'st_mode': 33204, u'st_uid': 1000, u'st_atime': 1428946778.0}'
2015-04-13 17:44:38,775 DEBUG getattr <- '/openvpn-connect.json' 'None' '{u'st_ctime': 1428946777.0, u'st_mtime': 1428946778.0, u'st_nlink': 1, u'st_gid': 1000, u'st_size': 356, u'st_mode': 33204, u'st_uid': 1000, u'st_atime': 1428946778.0}'
2015-04-13 17:44:38,775 DEBUG getattr -> '/up_events_v4.zip' 'None'
2015-04-13 17:44:38,776 DEBUG get_metadata -> '/up_events_v4.zip' 'attr' 'None'
2015-04-13 17:44:38,776 DEBUG get_key /up_events_v4.zip
2015-04-13 17:44:38,776 DEBUG get_key from S3 #1 '/up_events_v4.zip'
2015-04-13 17:44:38,805 DEBUG get_key to cache '/up_events_v4.zip'
2015-04-13 17:44:38,805 DEBUG get_metadata '/up_events_v4.zip' 'attr' 'up_events_v4.zip' S3 found
2015-04-13 17:44:38,805 DEBUG get_metadata <- '/up_events_v4.zip' 'attr' 'up_events_v4.zip' '{u'st_ctime': 1428890958.0, u'st_mtime': 1307138292.0, u'st_nlink': 1, u'st_gid': 0, u'st_size': 538412, u'st_mode': 33188, u'st_uid': 0, u'st_atime': 1424128985.0}'
2015-04-13 17:44:38,805 DEBUG getattr <- '/up_events_v4.zip' 'None' '{u'st_ctime': 1428890958.0, u'st_mtime': 1307138292.0, u'st_nlink': 1, u'st_gid': 0, u'st_size': 538412, u'st_mode': 33188, u'st_uid': 0, u'st_atime': 1424128985.0}'
2015-04-13 17:44:38,806 DEBUG getattr -> '/test' 'None'
2015-04-13 17:44:38,806 DEBUG get_metadata -> '/test' 'attr' 'None'
2015-04-13 17:44:38,806 DEBUG get_key /test
2015-04-13 17:44:38,806 DEBUG get_key from S3 #1 '/test'
2015-04-13 17:44:38,818 DEBUG get_key from S3 #2 '/test' '/test/'
2015-04-13 17:44:38,843 DEBUG get_key to cache '/test'
2015-04-13 17:44:38,843 DEBUG get_metadata '/test' 'attr' 'test/' S3 found
2015-04-13 17:44:38,843 DEBUG get_metadata <- '/test' 'attr' 'test/' '{u'st_ctime': 1428946445.0, u'st_mtime': 1428946445.0, u'st_gid': 0, u'st_size': 0, u'st_atime': 1428946445.0, u'st_uid': 0, u'st_mode': 16877}'
2015-04-13 17:44:38,844 DEBUG getattr <- '/test' 'None' '{u'st_ctime': 1428946445.0, u'st_mtime': 1428946445.0, 'st_nlink': 1, u'st_gid': 0, u'st_size': 4096, u'st_atime': 1428946445.0, u'st_uid': 0, u'st_mode': 16877}'
2015-04-13 17:44:52,280 DEBUG Got 0 messages from SQS
2015-04-13 17:44:54,912 DEBUG Got 1 messages from SQS
2015-04-13 17:44:54,913 DEBUG process_message '["f22d74d3-536d-4224-802c-94bc7r310cfo", "md", "attr", "/Skype_MediaStack-6.0.8878.0-lcsmedia_vnext_release3(rtbldlab)-x86fre-U.etl"]'
2015-04-13 17:45:01,080 DEBUG readdir '/' '0'
2015-04-13 17:45:01,080 DEBUG readdir '/' '0' ENOENT
2015-04-13 17:45:14,927 DEBUG Got 0 messages from SQS
2015-04-13 17:45:34,934 DEBUG Got 0 messages from SQS

Kernel

3.13.0-49-generic #81-Ubuntu SMP Tue Mar 24 19:29:48 UTC 2015 x86_64 x86_64 x86_64 GNU/Linux

In addition, uploading something to one machine does not trigger an update on another, causing files to be out of sync.

That's how I'm running it:

/usr/local/bin/yas3fs -df s3://mystorage /mnt/myfiles --queue mystorage --topic arn:aws:sns:us-east-1:741654509998:mystorage --region us-east-1 --log-mb-size 100
Jaykah commented 9 years ago

Are there any other troubleshooting steps I can take? The issue seems to be that we're not getting any SQS messages from another node, whereas the local file changes are displayed in the debug...

Jaykah commented 9 years ago

So the issue still persists - once I upload any file to yas3fs folder on Server1, Server2 starts getting ENOENT when trying to refresh the content of the folder, causing no files to be displayed. This makes it completely unusable. Any pointers on how to debug this further will be much appreciated.

2015-05-19 19:38:19,760 DEBUG getattr -> '/logs' 'None'
2015-05-19 19:38:19,760 DEBUG get_metadata -> '/logs' 'attr' 'None'
2015-05-19 19:38:19,760 DEBUG get_key /logs
2015-05-19 19:38:19,760 DEBUG get_key from S3 #1 '/logs'
2015-05-19 19:38:19,770 DEBUG get_key from S3 #2 '/logs' '/logs/'
2015-05-19 19:38:19,780 DEBUG get_key no '/logs'
2015-05-19 19:38:19,780 DEBUG folder_has_contents '/logs' 1
2015-05-19 19:38:19,780 DEBUG has_element '<boto.s3.bucketlistresultset.BucketListResultSet object at 0x7f46c03ad590>' 1
2015-05-19 19:38:19,855 DEBUG has_element '<boto.s3.bucketlistresultset.BucketListResultSet object at 0x7f46c03ad590>' -> 'logs/2015-03-05-22-21-31-DDC2C7E185C358FD'
2015-05-19 19:38:19,855 DEBUG has_element '<boto.s3.bucketlistresultset.BucketListResultSet object at 0x7f46c03ad590>' OK
2015-05-19 19:38:19,856 DEBUG get_metadata <- '/logs' 'attr' 'None' '{'st_ctime': 1432064299.0, 'st_mtime': 1432064299.0, 'st_mode': 16877, 'st_size': 0, 'st_gid': 1000, 'st_uid': 1000, 'st_atime': 1432064299.0}'
2015-05-19 19:38:19,856 DEBUG getattr <- '/logs' 'None' '{'st_ctime': 1432064299.0, 'st_mtime': 1432064299.0, 'st_nlink': 1, 'st_mode': 16877, 'st_size': 4096, 'st_gid': 1000, 'st_uid': 1000, 'st_atime': 1432064299.0}'
2015-05-19 19:38:19,856 DEBUG getattr -> '/nginx' 'None'
2015-05-19 19:38:19,857 DEBUG get_metadata -> '/nginx' 'attr' 'None'
2015-05-19 19:38:19,857 DEBUG get_key /nginx
2015-05-19 19:38:19,857 DEBUG get_key from S3 #1 '/nginx'
2015-05-19 19:38:19,869 DEBUG get_key from S3 #2 '/nginx' '/nginx/'
2015-05-19 19:38:19,897 DEBUG get_key to cache '/nginx'
2015-05-19 19:38:19,898 DEBUG get_metadata '/nginx' 'attr' 'nginx/' S3 found
2015-05-19 19:38:19,898 DEBUG get_metadata <- '/nginx' 'attr' 'nginx/' '{u'st_ctime': 1427160077.0, u'st_mtime': 1427160077.0, u'st_gid': 0, u'st_size': 0, u'st_atime': 1427160077.0, u'st_uid': 0, u'st_mode': 16877}'
2015-05-19 19:38:19,899 DEBUG getattr <- '/nginx' 'None' '{u'st_ctime': 1427160077.0, u'st_mtime': 1427160077.0, 'st_nlink': 1, u'st_gid': 0, u'st_size': 4096, u'st_atime': 1427160077.0, u'st_uid': 0, u'st_mode': 16877}'
2015-05-19 19:38:32,644 DEBUG Got 0 messages from SQS
2015-05-19 19:38:52,654 DEBUG Got 0 messages from SQS
2015-05-19 19:39:11,514 DEBUG readdir '/' '0'
2015-05-19 19:39:11,514 DEBUG readdir '/' '0' ENOENT
2015-05-19 19:39:12,664 DEBUG Got 0 messages from SQS
2015-05-19 19:39:32,680 DEBUG Got 0 messages from SQS
2015-05-19 19:39:52,688 DEBUG Got 0 messages from SQS
Jaykah commented 9 years ago

Something weird is happening on file upload too that is causing folder to disappear immediately (this is me uploading only one file):

2015-05-19 19:49:40,642 DEBUG getattr -> '/' 'None'
2015-05-19 19:49:40,642 DEBUG getattr <- '/' 'None' cache ENOENT
2015-05-19 19:49:46,342 DEBUG getattr -> '/' 'None'
2015-05-19 19:49:46,343 DEBUG getattr <- '/' 'None' cache ENOENT
2015-05-19 19:49:48,161 DEBUG getattr -> '/wait transfer button_12_May_2015__10_27_54PM_305.png' 'None'
2015-05-19 19:49:48,161 DEBUG get_metadata -> '/wait transfer button_12_May_2015__10_27_54PM_305.png' 'attr' 'None'
2015-05-19 19:49:48,162 DEBUG get_key /wait transfer button_12_May_2015__10_27_54PM_305.png
2015-05-19 19:49:48,162 DEBUG get_key not on S3 '/wait transfer button_12_May_2015__10_27_54PM_305.png'
2015-05-19 19:49:48,162 DEBUG get_key no '/wait transfer button_12_May_2015__10_27_54PM_305.png'
2015-05-19 19:49:48,162 DEBUG folder_has_contents '/wait transfer button_12_May_2015__10_27_54PM_305.png' 1
2015-05-19 19:49:48,163 DEBUG has_element '<boto.s3.bucketlistresultset.BucketListResultSet object at 0x7fb7b0375f10>' 1
2015-05-19 19:49:49,138 DEBUG has_element '<boto.s3.bucketlistresultset.BucketListResultSet object at 0x7fb7b0375f10>' KO
2015-05-19 19:49:49,139 DEBUG get_metadata '/wait transfer button_12_May_2015__10_27_54PM_305.png' 'attr' no S3 return None
2015-05-19 19:49:49,139 DEBUG getattr <- '/wait transfer button_12_May_2015__10_27_54PM_305.png' 'None' ENOENT
2015-05-19 19:49:49,139 DEBUG create '/wait transfer button_12_May_2015__10_27_54PM_305.png' '33204' 'None'
2015-05-19 19:49:49,139 DEBUG open '/wait transfer button_12_May_2015__10_27_54PM_305.png' '33204'
2015-05-19 19:49:49,140 DEBUG check_data '/wait transfer button_12_May_2015__10_27_54PM_305.png'
2015-05-19 19:49:49,140 DEBUG get_key /wait transfer button_12_May_2015__10_27_54PM_305.png
2015-05-19 19:49:49,140 DEBUG get_key not on S3 '/wait transfer button_12_May_2015__10_27_54PM_305.png'
2015-05-19 19:49:49,140 DEBUG get_key no '/wait transfer button_12_May_2015__10_27_54PM_305.png'
2015-05-19 19:49:49,141 DEBUG check_data '/wait transfer button_12_May_2015__10_27_54PM_305.png' no key
2015-05-19 19:49:49,141 DEBUG mknod '/wait transfer button_12_May_2015__10_27_54PM_305.png' '33204' 'None'
2015-05-19 19:49:49,141 DEBUG get_key /wait transfer button_12_May_2015__10_27_54PM_305.png
2015-05-19 19:49:49,141 DEBUG get_key not on S3 '/wait transfer button_12_May_2015__10_27_54PM_305.png'
2015-05-19 19:49:49,142 DEBUG get_key no '/wait transfer button_12_May_2015__10_27_54PM_305.png'
2015-05-19 19:49:49,144 DEBUG creating new cache file '/tmp/yas3fs/calplogs/files/wait transfer button_12_May_2015__10_27_54PM_305.png'
2015-05-19 19:49:49,144 DEBUG create_dirs_for_file '/tmp/yas3fs/calplogs/files/wait transfer button_12_May_2015__10_27_54PM_305.png'
2015-05-19 19:49:49,145 DEBUG create_dirs '/tmp/yas3fs/calplogs/files'
2015-05-19 19:49:49,145 DEBUG create_dirs '/tmp/yas3fs/calplogs/files' already there
2015-05-19 19:49:49,145 DEBUG created new cache file '/tmp/yas3fs/calplogs/files/wait transfer button_12_May_2015__10_27_54PM_305.png'
2015-05-19 19:49:49,145 DEBUG set_metadata '/wait transfer button_12_May_2015__10_27_54PM_305.png' 'attr' 'None'
2015-05-19 19:49:49,146 DEBUG set_metadata '/wait transfer button_12_May_2015__10_27_54PM_305.png' 'xattr' 'None'
2015-05-19 19:49:49,146 DEBUG add_to_parent_readdir '/wait transfer button_12_May_2015__10_27_54PM_305.png'
2015-05-19 19:49:49,146 DEBUG add_to_parent_readdir '/wait transfer button_12_May_2015__10_27_54PM_305.png' parent_path '/'
2015-05-19 19:49:49,146 DEBUG publish '['mknod', u'/wait transfer button_12_May_2015__10_27_54PM_305.png']'
2015-05-19 19:49:49,147 DEBUG open '/wait transfer button_12_May_2015__10_27_54PM_305.png' '33204' '1'
2015-05-19 19:49:49,147 DEBUG getattr -> '/wait transfer button_12_May_2015__10_27_54PM_305.png' 'None'
2015-05-19 19:49:49,151 DEBUG get_metadata -> '/wait transfer button_12_May_2015__10_27_54PM_305.png' 'attr' 'None'
2015-05-19 19:49:49,152 DEBUG get_metadata <- '/wait transfer button_12_May_2015__10_27_54PM_305.png' 'attr' 'None' '{'st_ctime': 1432064989.0, 'st_mtime': 1432064989.0, 'st_mode': 33204, 'st_size': 0, 'st_gid': 1000, 'st_uid': 1000, 'st_atime': 1432064989.0}'
2015-05-19 19:49:49,152 DEBUG getattr <- '/wait transfer button_12_May_2015__10_27_54PM_305.png' 'None' '{'st_ctime': 1432064989.0, 'st_mtime': 1432064989.0, 'st_nlink': 1, 'st_mode': 33204, 'st_size': 0, 'st_gid': 1000, 'st_uid': 1000, 'st_atime': 1432064989.0}'
2015-05-19 19:49:49,174 DEBUG write '/wait transfer button_12_May_2015__10_27_54PM_305.png' '4096' '0' '0'
2015-05-19 19:49:49,174 DEBUG write '/wait transfer button_12_May_2015__10_27_54PM_305.png' '4096' '0' '0' '/tmp/yas3fs/calplogs/files/wait transfer button_12_May_2015__10_27_54PM_305.png' content
2015-05-19 19:49:49,174 DEBUG get_metadata -> '/wait transfer button_12_May_2015__10_27_54PM_305.png' 'attr' 'None'
2015-05-19 19:49:49,175 DEBUG get_metadata <- '/wait transfer button_12_May_2015__10_27_54PM_305.png' 'attr' 'None' '{'st_ctime': 1432064989.0, 'st_mtime': 1432064989.0, 'st_nlink': 1, 'st_mode': 33204, 'st_size': 0, 'st_gid': 1000, 'st_uid': 1000, 'st_atime': 1432064989.0}'
2015-05-19 19:49:49,176 DEBUG write '/wait transfer button_12_May_2015__10_27_54PM_305.png' '4096' '4096' '0'
2015-05-19 19:49:49,176 DEBUG write '/wait transfer button_12_May_2015__10_27_54PM_305.png' '4096' '4096' '0' '/tmp/yas3fs/calplogs/files/wait transfer button_12_May_2015__10_27_54PM_305.png' content
2015-05-19 19:49:49,176 DEBUG get_metadata -> '/wait transfer button_12_May_2015__10_27_54PM_305.png' 'attr' 'None'
2015-05-19 19:49:49,177 DEBUG get_metadata <- '/wait transfer button_12_May_2015__10_27_54PM_305.png' 'attr' 'None' '{'st_ctime': 1432064989.0, 'st_mtime': 1432064989.0, 'st_nlink': 1, 'st_mode': 33204, 'st_size': 4096, 'st_gid': 1000, 'st_uid': 1000, 'st_atime': 1432064989.0}'
2015-05-19 19:49:49,190 DEBUG write '/wait transfer button_12_May_2015__10_27_54PM_305.png' '4096' '8192' '0'
2015-05-19 19:49:49,190 DEBUG write '/wait transfer button_12_May_2015__10_27_54PM_305.png' '4096' '8192' '0' '/tmp/yas3fs/calplogs/files/wait transfer button_12_May_2015__10_27_54PM_305.png' content
2015-05-19 19:49:49,190 DEBUG get_metadata -> '/wait transfer button_12_May_2015__10_27_54PM_305.png' 'attr' 'None'
2015-05-19 19:49:49,191 DEBUG get_metadata <- '/wait transfer button_12_May_2015__10_27_54PM_305.png' 'attr' 'None' '{'st_ctime': 1432064989.0, 'st_mtime': 1432064989.0, 'st_nlink': 1, 'st_mode': 33204, 'st_size': 8192, 'st_gid': 1000, 'st_uid': 1000, 'st_atime': 1432064989.0}'
2015-05-19 19:49:49,194 DEBUG write '/wait transfer button_12_May_2015__10_27_54PM_305.png' '4096' '12288' '0'
2015-05-19 19:49:49,194 DEBUG write '/wait transfer button_12_May_2015__10_27_54PM_305.png' '4096' '12288' '0' '/tmp/yas3fs/calplogs/files/wait transfer button_12_May_2015__10_27_54PM_305.png' content
2015-05-19 19:49:49,194 DEBUG get_metadata -> '/wait transfer button_12_May_2015__10_27_54PM_305.png' 'attr' 'None'
2015-05-19 19:49:49,195 DEBUG get_metadata <- '/wait transfer button_12_May_2015__10_27_54PM_305.png' 'attr' 'None' '{'st_ctime': 1432064989.0, 'st_mtime': 1432064989.0, 'st_nlink': 1, 'st_mode': 33204, 'st_size': 12288, 'st_gid': 1000, 'st_uid': 1000, 'st_atime': 1432064989.0}'
2015-05-19 19:49:49,195 DEBUG write '/wait transfer button_12_May_2015__10_27_54PM_305.png' '4096' '16384' '0'
2015-05-19 19:49:49,196 DEBUG write '/wait transfer button_12_May_2015__10_27_54PM_305.png' '4096' '16384' '0' '/tmp/yas3fs/calplogs/files/wait transfer button_12_May_2015__10_27_54PM_305.png' content
2015-05-19 19:49:49,196 DEBUG get_metadata -> '/wait transfer button_12_May_2015__10_27_54PM_305.png' 'attr' 'None'
2015-05-19 19:49:49,196 DEBUG get_metadata <- '/wait transfer button_12_May_2015__10_27_54PM_305.png' 'attr' 'None' '{'st_ctime': 1432064989.0, 'st_mtime': 1432064989.0, 'st_nlink': 1, 'st_mode': 33204, 'st_size': 16384, 'st_gid': 1000, 'st_uid': 1000, 'st_atime': 1432064989.0}'
2015-05-19 19:49:49,197 DEBUG write '/wait transfer button_12_May_2015__10_27_54PM_305.png' '4096' '20480' '0'
2015-05-19 19:49:49,197 DEBUG write '/wait transfer button_12_May_2015__10_27_54PM_305.png' '4096' '20480' '0' '/tmp/yas3fs/calplogs/files/wait transfer button_12_May_2015__10_27_54PM_305.png' content
2015-05-19 19:49:49,198 DEBUG get_metadata -> '/wait transfer button_12_May_2015__10_27_54PM_305.png' 'attr' 'None'
2015-05-19 19:49:49,198 DEBUG get_metadata <- '/wait transfer button_12_May_2015__10_27_54PM_305.png' 'attr' 'None' '{'st_ctime': 1432064989.0, 'st_mtime': 1432064989.0, 'st_nlink': 1, 'st_mode': 33204, 'st_size': 20480, 'st_gid': 1000, 'st_uid': 1000, 'st_atime': 1432064989.0}'
2015-05-19 19:49:49,203 DEBUG write '/wait transfer button_12_May_2015__10_27_54PM_305.png' '4096' '24576' '0'
2015-05-19 19:49:49,203 DEBUG write '/wait transfer button_12_May_2015__10_27_54PM_305.png' '4096' '24576' '0' '/tmp/yas3fs/calplogs/files/wait transfer button_12_May_2015__10_27_54PM_305.png' content
2015-05-19 19:49:49,203 DEBUG get_metadata -> '/wait transfer button_12_May_2015__10_27_54PM_305.png' 'attr' 'None'
2015-05-19 19:49:49,204 DEBUG get_metadata <- '/wait transfer button_12_May_2015__10_27_54PM_305.png' 'attr' 'None' '{'st_ctime': 1432064989.0, 'st_mtime': 1432064989.0, 'st_nlink': 1, 'st_mode': 33204, 'st_size': 24576, 'st_gid': 1000, 'st_uid': 1000, 'st_atime': 1432064989.0}'
2015-05-19 19:49:49,206 DEBUG write '/wait transfer button_12_May_2015__10_27_54PM_305.png' '4096' '28672' '0'
2015-05-19 19:49:49,207 DEBUG write '/wait transfer button_12_May_2015__10_27_54PM_305.png' '4096' '28672' '0' '/tmp/yas3fs/calplogs/files/wait transfer button_12_May_2015__10_27_54PM_305.png' content
2015-05-19 19:49:49,207 DEBUG get_metadata -> '/wait transfer button_12_May_2015__10_27_54PM_305.png' 'attr' 'None'
2015-05-19 19:49:49,207 DEBUG get_metadata <- '/wait transfer button_12_May_2015__10_27_54PM_305.png' 'attr' 'None' '{'st_ctime': 1432064989.0, 'st_mtime': 1432064989.0, 'st_nlink': 1, 'st_mode': 33204, 'st_size': 28672, 'st_gid': 1000, 'st_uid': 1000, 'st_atime': 1432064989.0}'
2015-05-19 19:49:49,209 DEBUG write '/wait transfer button_12_May_2015__10_27_54PM_305.png' '4096' '32768' '0'
2015-05-19 19:49:49,209 DEBUG write '/wait transfer button_12_May_2015__10_27_54PM_305.png' '4096' '32768' '0' '/tmp/yas3fs/calplogs/files/wait transfer button_12_May_2015__10_27_54PM_305.png' content
2015-05-19 19:49:49,210 DEBUG get_metadata -> '/wait transfer button_12_May_2015__10_27_54PM_305.png' 'attr' 'None'
2015-05-19 19:49:49,210 DEBUG get_metadata <- '/wait transfer button_12_May_2015__10_27_54PM_305.png' 'attr' 'None' '{'st_ctime': 1432064989.0, 'st_mtime': 1432064989.0, 'st_nlink': 1, 'st_mode': 33204, 'st_size': 32768, 'st_gid': 1000, 'st_uid': 1000, 'st_atime': 1432064989.0}'
2015-05-19 19:49:49,224 DEBUG write '/wait transfer button_12_May_2015__10_27_54PM_305.png' '32739' '36864' '0'
2015-05-19 19:49:49,224 DEBUG write '/wait transfer button_12_May_2015__10_27_54PM_305.png' '32739' '36864' '0' '/tmp/yas3fs/calplogs/files/wait transfer button_12_May_2015__10_27_54PM_305.png' content
2015-05-19 19:49:49,224 DEBUG get_metadata -> '/wait transfer button_12_May_2015__10_27_54PM_305.png' 'attr' 'None'
2015-05-19 19:49:49,224 DEBUG get_metadata <- '/wait transfer button_12_May_2015__10_27_54PM_305.png' 'attr' 'None' '{'st_ctime': 1432064989.0, 'st_mtime': 1432064989.0, 'st_nlink': 1, 'st_mode': 33204, 'st_size': 36864, 'st_gid': 1000, 'st_uid': 1000, 'st_atime': 1432064989.0}'
2015-05-19 19:49:49,235 DEBUG write '/wait transfer button_12_May_2015__10_27_54PM_305.png' '32739' '69603' '0'
2015-05-19 19:49:49,244 DEBUG write '/wait transfer button_12_May_2015__10_27_54PM_305.png' '32739' '69603' '0' '/tmp/yas3fs/calplogs/files/wait transfer button_12_May_2015__10_27_54PM_305.png' content
2015-05-19 19:49:49,245 DEBUG get_metadata -> '/wait transfer button_12_May_2015__10_27_54PM_305.png' 'attr' 'None'
2015-05-19 19:49:49,245 DEBUG get_metadata <- '/wait transfer button_12_May_2015__10_27_54PM_305.png' 'attr' 'None' '{'st_ctime': 1432064989.0, 'st_mtime': 1432064989.0, 'st_nlink': 1, 'st_mode': 33204, 'st_size': 69603, 'st_gid': 1000, 'st_uid': 1000, 'st_atime': 1432064989.0}'
2015-05-19 19:49:49,253 DEBUG write '/wait transfer button_12_May_2015__10_27_54PM_305.png' '32739' '102342' '0'
2015-05-19 19:49:49,253 DEBUG write '/wait transfer button_12_May_2015__10_27_54PM_305.png' '32739' '102342' '0' '/tmp/yas3fs/calplogs/files/wait transfer button_12_May_2015__10_27_54PM_305.png' content
2015-05-19 19:49:49,253 DEBUG get_metadata -> '/wait transfer button_12_May_2015__10_27_54PM_305.png' 'attr' 'None'
2015-05-19 19:49:49,253 DEBUG get_metadata <- '/wait transfer button_12_May_2015__10_27_54PM_305.png' 'attr' 'None' '{'st_ctime': 1432064989.0, 'st_mtime': 1432064989.0, 'st_nlink': 1, 'st_mode': 33204, 'st_size': 102342, 'st_gid': 1000, 'st_uid': 1000, 'st_atime': 1432064989.0}'
2015-05-19 19:49:49,255 DEBUG write '/wait transfer button_12_May_2015__10_27_54PM_305.png' '1187' '135081' '0'
2015-05-19 19:49:49,255 DEBUG write '/wait transfer button_12_May_2015__10_27_54PM_305.png' '1187' '135081' '0' '/tmp/yas3fs/calplogs/files/wait transfer button_12_May_2015__10_27_54PM_305.png' content
2015-05-19 19:49:49,260 DEBUG get_metadata -> '/wait transfer button_12_May_2015__10_27_54PM_305.png' 'attr' 'None'
2015-05-19 19:49:49,260 DEBUG get_metadata <- '/wait transfer button_12_May_2015__10_27_54PM_305.png' 'attr' 'None' '{'st_ctime': 1432064989.0, 'st_mtime': 1432064989.0, 'st_nlink': 1, 'st_mode': 33204, 'st_size': 135081, 'st_gid': 1000, 'st_uid': 1000, 'st_atime': 1432064989.0}'
2015-05-19 19:49:49,261 DEBUG release '/wait transfer button_12_May_2015__10_27_54PM_305.png' '0'
2015-05-19 19:49:49,262 DEBUG upload_to_s3 '/wait transfer button_12_May_2015__10_27_54PM_305.png'
2015-05-19 19:49:49,261 DEBUG utimens '/wait transfer button_12_May_2015__10_27_54PM_305.png' '(1431469747.0, 1431469674.0)'
2015-05-19 19:49:49,262 DEBUG get_key /wait transfer button_12_May_2015__10_27_54PM_305.png
2015-05-19 19:49:49,262 DEBUG get_key from S3 #1 '/wait transfer button_12_May_2015__10_27_54PM_305.png'
2015-05-19 19:49:49,276 DEBUG get_key from S3 #2 '/wait transfer button_12_May_2015__10_27_54PM_305.png' '/wait transfer button_12_May_2015__10_27_54PM_305.png/'
2015-05-19 19:49:49,322 DEBUG get_key no '/wait transfer button_12_May_2015__10_27_54PM_305.png'
2015-05-19 19:49:49,323 DEBUG get_metadata -> '/wait transfer button_12_May_2015__10_27_54PM_305.png' 'attr' 'wait transfer button_12_May_2015__10_27_54PM_305.png'
2015-05-19 19:49:49,323 DEBUG get_metadata <- '/wait transfer button_12_May_2015__10_27_54PM_305.png' 'attr' 'wait transfer button_12_May_2015__10_27_54PM_305.png' '{'st_ctime': 1432064989.0, 'st_mtime': 1432064989.0, 'st_nlink': 1, 'st_mode': 33204, 'st_size': 136268, 'st_gid': 1000, 'st_uid': 1000, 'st_atime': 1432064989.0}'
2015-05-19 19:49:49,323 DEBUG set_metadata '/wait transfer button_12_May_2015__10_27_54PM_305.png' 'attr' 'wait transfer button_12_May_2015__10_27_54PM_305.png'
2015-05-19 19:49:49,324 DEBUG set_metadata '/wait transfer button_12_May_2015__10_27_54PM_305.png' 'xattr' 'wait transfer button_12_May_2015__10_27_54PM_305.png'
2015-05-19 19:49:49,329 DEBUG multipart test: key '/wait transfer button_12_May_2015__10_27_54PM_305.png' mp-num '4' st_size '136268' mp-size '104857600'
2015-05-19 19:49:49,329 DEBUG upload_to_s3 '/wait transfer button_12_May_2015__10_27_54PM_305.png' 'wait transfer button_12_May_2015__10_27_54PM_305.png' 'image/png' S3
2015-05-19 19:49:49,329 DEBUG upload_to_s3 '/wait transfer button_12_May_2015__10_27_54PM_305.png' done
2015-05-19 19:49:49,330 DEBUG do_cmd_on_s3_now_w_retries try 1 action 'set_contents_from_file' key 'wait transfer button_12_May_2015__10_27_54PM_305.png' args '[<yas3fs.FSData instance at 0x7fb7b4e50488>]' kargs '{'headers': {'Content-Type': 'image/png'}}'
2015-05-19 19:49:49,330 DEBUG do_cmd_on_s3_now action 'set_contents_from_file' key 'wait transfer button_12_May_2015__10_27_54PM_305.png' args '[<yas3fs.FSData instance at 0x7fb7b4e50488>]' kargs '{'headers': {'Content-Type': 'image/png'}}'
2015-05-19 19:49:49,330 DEBUG release '/wait transfer button_12_May_2015__10_27_54PM_305.png' '0' 'None'
2015-05-19 19:49:49,335 DEBUG get_metadata -> '/wait transfer button_12_May_2015__10_27_54PM_305.png' 'attr' 'None'
2015-05-19 19:49:49,335 DEBUG get_metadata <- '/wait transfer button_12_May_2015__10_27_54PM_305.png' 'attr' 'None' '{'st_ctime': 1432064989.0, 'st_mtime': 1432064989.0, 'st_nlink': 1, 'st_mode': 33204, 'st_size': 136268, 'st_gid': 1000, 'st_uid': 1000, 'st_atime': 1432064989.0}'
2015-05-19 19:49:49,335 DEBUG set_metadata '/wait transfer button_12_May_2015__10_27_54PM_305.png' 'attr' 'None'
2015-05-19 19:49:49,336 DEBUG set_metadata: 'change' already in progress, setting FSData.props[invoke_after_change] lambda for self.set_metadata(/wait transfer button_12_May_2015__10_27_54PM_305.png,attr)
2015-05-19 19:49:49,336 DEBUG getattr -> '/wait transfer button_12_May_2015__10_27_54PM_305.png' 'None'
2015-05-19 19:49:49,338 DEBUG get_metadata -> '/wait transfer button_12_May_2015__10_27_54PM_305.png' 'attr' 'None'
2015-05-19 19:49:49,338 DEBUG get_metadata <- '/wait transfer button_12_May_2015__10_27_54PM_305.png' 'attr' 'None' '{'st_ctime': 1432064989.0, 'st_mtime': 1431469674.0, 'st_nlink': 1, 'st_mode': 33204, 'st_size': 136268, 'st_gid': 1000, 'st_uid': 1000, 'st_atime': 1431469747.0}'
2015-05-19 19:49:49,338 DEBUG getattr <- '/wait transfer button_12_May_2015__10_27_54PM_305.png' 'None' '{'st_ctime': 1432064989.0, 'st_mtime': 1431469674.0, 'st_nlink': 1, 'st_mode': 33204, 'st_size': 136268, 'st_gid': 1000, 'st_uid': 1000, 'st_atime': 1431469747.0}'
2015-05-19 19:49:49,339 DEBUG removexattr '/wait transfer button_12_May_2015__10_27_54PM_305.png''security.ima'
2015-05-19 19:49:49,339 DEBUG get_metadata -> '/wait transfer button_12_May_2015__10_27_54PM_305.png' 'xattr' 'None'
2015-05-19 19:49:49,339 DEBUG get_metadata <- '/wait transfer button_12_May_2015__10_27_54PM_305.png' 'xattr' 'None' '{}'
2015-05-19 19:49:49,339 DEBUG removexattr '/wait transfer button_12_May_2015__10_27_54PM_305.png' 'security.ima' should ENOATTR
2015-05-19 19:49:49,406 DEBUG create_dirs_for_file '/tmp/yas3fs/calplogs/etags/wait transfer button_12_May_2015__10_27_54PM_305.png'
2015-05-19 19:49:49,406 DEBUG create_dirs '/tmp/yas3fs/calplogs/etags'
2015-05-19 19:49:49,406 DEBUG create_dirs '/tmp/yas3fs/calplogs/etags' done
2015-05-19 19:49:49,407 DEBUG FSData.props[change] removed, now executing invoke_after_change lambda for: /wait transfer button_12_May_2015__10_27_54PM_305.png
2015-05-19 19:49:49,407 DEBUG set_metadata '/wait transfer button_12_May_2015__10_27_54PM_305.png' 'attr' 'None'
2015-05-19 19:49:49,407 DEBUG get_key from cache '/wait transfer button_12_May_2015__10_27_54PM_305.png'
2015-05-19 19:49:49,407 DEBUG set_metadata '/wait transfer button_12_May_2015__10_27_54PM_305.png' 'attr' 'wait transfer button_12_May_2015__10_27_54PM_305.png' Key
2015-05-19 19:49:49,408 DEBUG set_metadata '/wait transfer button_12_May_2015__10_27_54PM_305.png' 'wait transfer button_12_May_2015__10_27_54PM_305.png' S3
2015-05-19 19:49:49,408 DEBUG do_cmd_on_s3_now action 'set_contents_from_file' key 'wait transfer button_12_May_2015__10_27_54PM_305.png' args '[<yas3fs.FSData instance at 0x7fb7b4e50488>]' kargs '{'headers': {'Content-Type': 'image/png'}}' done
2015-05-19 19:49:49,408 DEBUG publish '['upload', u'/wait transfer button_12_May_2015__10_27_54PM_305.png', '01cbed3b7f93eda2f164cb4a48f1f484']'
2015-05-19 19:49:49,409 DEBUG do_cmd_on_s3_now_w_retries try 1 action 'copy' key 'wait transfer button_12_May_2015__10_27_54PM_305.png' args '['calplogs', u'wait transfer button_12_May_2015__10_27_54PM_305.png', {'attr': '{"st_ctime": 1432064989.0, "st_mtime": 1431469674.0, "st_nlink": 1, "st_mode": 33204, "st_size": 136268, "st_gid": 1000, "st_uid": 1000, "st_atime": 1431469747.0}'}]' kargs '{'encrypt_key': False, 'preserve_acl': False}'
2015-05-19 19:49:49,409 DEBUG do_cmd_on_s3_now action 'copy' key 'wait transfer button_12_May_2015__10_27_54PM_305.png' args '['calplogs', u'wait transfer button_12_May_2015__10_27_54PM_305.png', {'attr': '{"st_ctime": 1432064989.0, "st_mtime": 1431469674.0, "st_nlink": 1, "st_mode": 33204, "st_size": 136268, "st_gid": 1000, "st_uid": 1000, "st_atime": 1431469747.0}'}]' kargs '{'encrypt_key': False, 'preserve_acl': False}'
2015-05-19 19:49:49,484 DEBUG readdir '/' '0'
2015-05-19 19:49:49,484 DEBUG readdir '/' '0' ENOENT
2015-05-19 19:49:49,584 DEBUG do_cmd_on_s3_now action 'copy' key 'wait transfer button_12_May_2015__10_27_54PM_305.png' args '['calplogs', u'wait transfer button_12_May_2015__10_27_54PM_305.png', {'attr': '{"st_ctime": 1432064989.0, "st_mtime": 1431469674.0, "st_nlink": 1, "st_mode": 33204, "st_size": 136268, "st_gid": 1000, "st_uid": 1000, "st_atime": 1431469747.0}'}]' kargs '{'encrypt_key': False, 'preserve_acl': False}' done
2015-05-19 19:49:49,585 DEBUG publish '['md', 'attr', u'/wait transfer button_12_May_2015__10_27_54PM_305.png']'

The other machine seems to be getting the file changes:

2015-05-19 19:49:49,374 DEBUG Got 1 messages from SQS
2015-05-19 19:49:49,374 DEBUG process_message '["a0120665-f5b1-4ff2-a901-73fe0c4c6755", "upload", "/wait transfer button_12_May_2015__10_27_54PM_305.png", "01cbed3b7f93eda2f164cb4a48f1f484"]'
2015-05-19 19:49:49,375 DEBUG invalidate_cache '/wait transfer button_12_May_2015__10_27_54PM_305.png' '01cbed3b7f93eda2f164cb4a48f1f484'
2015-05-19 19:50:09,392 DEBUG Got 0 messages from SQS
2015-05-19 19:50:29,399 DEBUG Got 0 messages from SQS
2015-05-19 19:50:49,408 DEBUG Got 0 messages from SQS
2015-05-19 19:51:09,419 DEBUG Got 0 messages from SQS
2015-05-19 19:51:29,433 DEBUG Got 0 messages from SQS
2015-05-19 19:51:49,442 DEBUG Got 0 messages from SQS
2015-05-19 19:52:09,452 DEBUG Got 0 messages from SQS
2015-05-19 19:52:29,465 DEBUG Got 0 messages from SQS
2015-05-19 19:52:49,478 DEBUG Got 0 messages from SQS
2015-05-19 19:53:07,398 DEBUG readdir '/' '0'

However, if I reload the folder the file is not there.

Jaykah commented 9 years ago

bump

Jaykah commented 9 years ago

Any additional debug options available? Have tried everything already...

Jaykah commented 9 years ago

bump

bitsofinfo commented 9 years ago

Hey Jaykah, sorry can't be of more help. Just have no time to work on this project right now. Perhaps @danilop may be able to help or you will just have to do some lower-level debugging on your own.

Jaykah commented 9 years ago

Thanks for your reply, @bitsofinfo, I wish I knew how to enable lower-level debugging, since it is already being launched with the -df flag.

The issue seems to be that somehow messages never get into queue (I have tried monitoring it from the AWS side). The permissions on the queue have been set to allow all...

bitsofinfo commented 9 years ago

Unfortunately by debugging I mean get into the code, reproduce the issue, and literally debug it w/ a debugger or old school prints.... we got deep into this project last summer fixing a lot of issues we found and unfortunately that is what is might take to figure out your issue.