EFTA00502230.pdf

From: File "Nolumes/BuildData/pulse- datathgents/563586/recipes/843291236/base/b/drb/googleclient/apps/webdrive_sync/osxklist/Google Drive.app/Contents/Resources/_boot_.py", line 43, in <module> File "Nolumes/BuildData/pulse- datathgents/563586/recipes/843291236/base/b/drb/googleclient/apps/webdrive_sync/osxklist/Google Drive.app/Contents/Resources/_boot_.py", line 38, in _run File "/Applications/Google Drive.app/Contents/Resourceslmain.py", line 12, in <module> File "osx/run_googledrive.pyo", line 31, in Main File "build/bdist.macosx-10.7-intel/egg/PyObjCTools/AppHelper.py", line 235, in runEventLoop File "osx/GSyncAppDelegate.pyo", line 297, in applicationWillTerminate_ File "osx/mac_sync_app_controller.pyo", line 251, in Exit File "common/ui_action_handler.pyo", line 444, in Quit File "common/sync_app.pyo", line 1576, in Quit 2015-11-18 16:59:15,402 -0500 INFO pid=239 140735235859216:MainThread thread_manager.pyo:114 Stop was called 2015-11-18 16:59:15,402 -0500 INFO pid=239 140735235859216:MainThread thread_manager.pyo:250 Asking <PushNotificationKeepaliveThread(PushNotificationKeepaliveThread, started 4575989760)> to stop. 2015-11-18 16:59:15,403 -0500 INFO pid=239 140735235859216:MainThread thread_manager.pyo:250 Asking <CloudWatcher(CloudWatcher, started 4580196352)> to stop. 2015-11-18 16:59:15,403 -0500 INFO pid=239 4575989760:PushNotificationKeepaliveThread sync_client_thread.pyo:209 PushNotificationKeepaliveThread run loop has terminated. 2015-11-18 16:59:15,403 -0500 INFO pid=239 140735235859216:MainThread thread_manager.pyo:250 Asking <SchedulerThread(ListenerScheduler, started 4584402944)> to stop. 2015-11-18 16:59:15,404 -0500 INFO pid=239 4580196352:CloudWatcher cloud_watcher.pyo:664 Stop detected 2015-11-18 16:59:15,404 -0500 thread_manager.pyo:250 Asking 2015-11-18 16:59:15,404 -0500 cloud watcher.pyo:710 Exiting 2015-11-18 16:59:15,405 -0500 thread_manager.pyo:250 Asking 2015-11-18 16:59:15,405 -0500 INFO pid=239 4588609536:Batcher sync_client_thread.pyo:270 Batcher run loop has terminated. 2015-11-18 16:59:15,405 -0500 INFO pid=239 4580196352:CloudWatcher connection. path=/Users/lgroff/Library/Application Support/Google/Drive/user_default/snapshot.db 2015-11-18 16:59:15,405 -0500 INFO pid=239 4588609536:Batcher connection. path=/Users/lgroff/Library/Application Support/Google/Drive/user_default/snapshot.db 2015-11-18 16:59:15,406 -0500 INFO pid=239 140735235859216:MainThread thread_manager.pyo:250 Asking <RawEventUpgrader(RawEventUpgrader, started 4592816128)> to stop. 2015-11-18 16:59:15,406 -0500 INFO pid=239 4528164864:Finderlnjector sync_client_thread.pyo:209 Finderlnjector run loop has terminated. 2015-11-18 16:59:15,663 -0500 INFO pid=239 4592816128:RawEventUpgrader sync_client_thread.pyo:209 RawEventUpgrader run loop has terminated. 2015-11-18 16:59:15,663 -0500 INFO pid=239 140735235859216:MainThread thread_manager. pyo: 250 Asking <CrashReportUploaderThread(CrashReportUploaderThread, started 4597022720)> to stop. 2015-11-18 16:59:15,663 -0500 INFO pid=239 140735235859216:MainThread thread_manager.pyo:250 Asking <PauseTelemetryThread(PauseTelemetryThread, started 4647501824)> to stop. 2015-11-18 16:59:15,664 -0500 INFO pid=239 4588609536:Batcher utils.pyo:703 Execute cleanup callback 'persistence_sqlite: 7c19d5afe9db435bb3de072b3794254c/Users/lgroff/Library/Application Support/Google/Drive/user_default/snapshot.db' 2015-11-18 16:59:15,664 -0500 INFO pid=239 4580196352:CloudWatcher sqlite.pyo:378 Close connection. path=/Users/lgroff/Library/Application Support/Google/Drive/user_default/sync_config.db INFO pid=239 140735235859216:MainThread <Batcher(Batcher, started 4588609536)> to stop. WARNING pid=239 4580196352:CloudWatcher CloudWatcher.PushRunLoop() INFO pid=239 140735235859216:MainThread <Finderlnjector(Finderlnjector, started 4528164864)> to stop. sqlite.pyo:378 Close sqlite.pyo:378 Close EFTA00502230 2015-11-18 16:59:15,664 -0500 INFO pid=239 140735235859216:MainThread thread_manager.pyo:250 Asking <FilewatcherMonitor(FilewatcherMonitor, started 4559593472)> to stop. 2015-11-18 16:59:15,665 -0500 INFO pid=239 4588609536:Hatcher utils.pyo:703 Execute cleanup callback 'persistence sqlite:737eb666b66b41dab405a9ab6788217e/Users/lgroff/Library/Application Support/Googie/Drive/user default/sync_config.db' 2015-11-18 16:59:15,665 -0500 INFO pid=239 4647501824:PauseTelemetryThread sync_client thread.pyo:209 PauseTelemetryThread run loop has terminated. 2015-11-18 16:59:15,690 -0500 INFO pid=239 140735235859216:MainThread thread manager.pyo:250 Asking <Worker(Worker-1, started 4605435904)> to stop. 2015-11-18 16:59:15,690 -0500 INFO pid=239 4588609536:Hatcher sqlite.pyo:378 Close connection. path=/Users/lgroff/Library/Application Support/Google/Drive/user default/sync_config.db 2015-11-18 16:59:15,690 -0500 INFO pid=239 4580196352:CloudWatcher utils.pyo:703 Execute cleanup callback 'persistence sqlite:a244014d52ff4710972688ba91660cc8/Users/lgroff/Library/Application Support/Googie/Drive/user default/snapshot.db' 2015-11-18 16:59:15,690 -0500 INFO pid=239 4647501824:PauseTelemetryThread pause telemetry.pyo:127 Attempting final telemetry harvest. 2015-11-18 16:59:15,691 -0500 WARNING pid=239 140735235859216:MainThread sync_client thread.pyo:237 Wake() called while thread was running, should be a NOP 2015-11-18 16:59:15,691 -0500 INFO pid=239 4580196352:CloudWatcher utils.pyo:703 Execute cleanup callback 'persistence sqlite:780d8bd9419f4a19a9a33e2ecce07bd1/Users/lgroff/Library/Application Support/Googie/Drive/user default/sync_config.db' 2015-11-18 16:59:15,692 -0500 INFO pid=239 4647501824:PauseTelemetryThread pause_telemetry.pyo:189 Harvested pause statistics at t=1447883955.69: (<PauseReason.API ERRORS: 'pause api err'>: _HarvestStat(paused=0.0, trial=0.0, occurrences=0), <i)auseReason.BLOKIN5_ERRORS: 'pause blocking_err'>: _HarvestStat(paused=0.0, trial=0.0, occurrences=0), <PauseReason.NETWORK_ERROTLS: 'pause_net err'>: HarvestStat(paused=0.0, trial=0.0, occurrences=0), <PauseReason.USER: 'pause_user'>: HarvestStat(paused=0.0, trial=0.0, occurrences=0), <PauseReason.OFFLINE: 'pause offline'>: HarvestStat(paused=0.0, trial=0.0, occurrences=0), <PauseReason.NO LOCAL_ DISK_ SfiACE: 'pause no space'>: _HarvestStat(paused=0.0, trial=0.0, occurrences=i7)) 2015-11-18 16:59:15,692 -0500 INFO pid=239 140735235859216:MainThread thread manager.pyo:250 Asking <PushXmpliClient(XmppClient, started 4609642496)> to stop. 2015-11-18 16:59:15,692 -0500 INFO pid=239 4580196352:CloudWatcher utils.pyo:703 Execute cleanup callback 'DHConnectionManagerCleanupCallback' 2015-11-18 16:59:15,693 -0500 INFO pid=239 4605435904:Worker-1 sync_client thread.pyo:209 Worker-1 run loop has terminated. 2015-11-18 16:59:15,748 -0500 WARNING pid=239 140735235859216:MainThread task.pyo:242 DriveXmppTask-0x10f5c6f50 aborting: abort 2015-11-18 16:59:15,748 -0500 INFO pid=239 4580196352:CloudWatcher db_connection.pyo:434 Closing ManagedConnection(id=10E552850, thread=CloudWatcher-111004000, path=/Users/lgroff/Library/Application Support/Google/Drive/user default/cloud_graph/dict 2.db, closed=False) 2015-11-18 16:59:15,748 -0500 INFO pid=239 460543504:Worker-1 sqlite.pyo:378 Close connection. path=/Users/lgroff/Library/Application Support/Google/Drive/user default/snapshot.db 2015-11-18 16:59:15,749 -0500 INFO pid=239 140735235859216:MainThread task.pyo:254 Task <common.push.push xmpp_client.DriveXmppTask object at 0x10f5c6f50> complete. 2015-11-18 16:59:15,749 -0500 INFO pid=239 140735235859216:MainThread xmpplib.pyo:143 Close called with 'why' reason = Client initiated close 2015-11-18 16:59:15,750 -0500 INFO pid=239 4605435904:Worker-1 sqlite.pyo:378 Close connection. path=/Users/lgroff/Library/Application Support/Google/Drive/user default/sync_config.db 2015-11-18 16:59:15,751 -0500 INFO pid=239 4605435904:Worker-1 utils.pyo:703 Execute cleanup callback 'persistence sqlite:699847d6de354367be41c691e4cdcdcb/Users/lgroff/Library/Application Support/Googie/Drive/user default/sync_config.db' 2015-11-18 16:59:15,751 -0500 INFO pid=239 4605435904:Worker-1 utils.pyo:703 Execute cleanup callback 'persistence sqlite:5105e1b51b504a83adcd14b441898296/Users/lgroff/Library/Application Support/Googie/Drive/user_default/snapshot.db' EFTA00502231 2015-11-19 09:01:46,453 -0500 INFO pid=1679 140735235859216:MainThread logging_config.pyo:249 OS: Darwin/10.9.5 2015-11-19 09:01:46,453 -0500 INFO pid=1679 140735235859216:MainThread logging_config.pyo:252 Google Drive (build 1.25.0523.2491) 2015-11-19 09:01:46,453 -0500 INFO pid=1679 140735235859216:MainThread logging_config.pyo:253 SSL: OpenSSL 0.9.8zg 14 July 2015 2015-11-19 09:01:46,469 -0500 INFO pid=1679 140735235859216:MainThread GSyncAppDelegate.pyo:198 Application did finish launching. 2015-11-19 09:01:47,196 -0500 INFO pid=1679 140735235859216:MainThread service.pyo:132 Creating singleton service instance of '<class 'common.file_lock.FileLocki> 1 2015-11-19 09:01:47,196 -0500 INFO pid=1679 140735235859216:MainThread service.pyo:132 Creating singleton service instance of '<class 'common.file_lock.FileLock'>' 2015-11-19 09:01:47,197 -0500 INFO pid=1679 4520939520:RunAsync-_InitializeSyncAppAsync-1 service.pyo:132 Creating singleton service instance of '<class 'common.service.user.User'>' 2015-11-19 09:01:47,198 -0500 INFO pid=1679 4520939520:RunAsync-_InitializeSyncAppAsync-1 service.pyo:132 Creating singleton service instance of '<class 'common.roots.roots.RootManager'>' 2015-11-19 09:01:47,198 -0500 INFO pid=1679 4520939520:RunAsync-_InitializeSyncAppAsync-1 service.pyo:132 Creating singleton service instance of '<class 'common.thread_manager.ThreadManager'> 1 2015-11-19 09:01:47,198 -0500 INFO pid=1679 4520939520:RunAsync-_InitializeSyncAppAsync-1 service.pyo:132 Creating singleton service instance of '<class 'common. pause_manager.Service'>' 2015-11-19 09:01:47,198 -0500 INFO pid=1679 4520939520:RunAsync-_InitializeSyncAppAsync-1 sync_app.pyo:308 Getting TokenStorage... 2015-11-19 09:01:47,199 -0500 INFO pid=1679 4520939520:RunAsync-_InitializeSyncAppAsync-1 sync_app.pyo:310 Got token storage: <token_storage.TokenStorage object at 0x10920ae60> 2015-11-19 09:01:47,199 -0500 INFO pid=1679 4520939520:RunAsync-_InitializeSyncAppAsync-1 service.pyo:132 Creating singleton service instance of '<class 'common.features.AppFeatures'>' 2015-11-19 09:01:47,199 -0500 INFO pid=1679 4520939520:RunAsync-_InitializeSyncAppAsync-1 service.pyo:132 Creating singleton service instance of '<class 'common.cert.Manager'>' 2015-11-19 09:01:47,230 -0500 INFO pid=1679 4520939520:RunAsync-_InitializeSyncAppAsync-1 service.pyo:132 Creating singleton service instance of '<class 'common.net.bandwidth.BandwidthThrottler'>' 2015-11-19 09:01:47,235 -0500 INFO pid=1679 4520939520:RunAsync-_InitializeSyncAppAsync-1 sqlite.pyo:276 Open master connection to /Users/lgrof f/Library/Application Support/Google/Drive/user_default/snapshot.db 2015-11-19 09:01:47,236 -0500 INFO pid=1679 4520939520:RunAsync-_InitializeSyncAppAsync-1 sqlite.pyo:276 Open master connection to /Users/lgroff/Library/Application Support/Google/Drive/user_default/sync_config.db 2015-11-19 09:01:47,237 -0500 INFO pid=1679 4520939520:RunAsync-_InitializeSyncAppAsync-1 utils.pyo:726 ADDING persistence_sqlite:fe7510dce9be473abl2b74961b46bfae/Users/lgroff/Library/Application Support/Google/Drive/user_default/snapshot.db 2015-11-19 09:01:47,237 -0500 INFO pid=1679 4520939520:RunAsync-_InitializeSyncAppAsync-1 utils.pyo:726 ADDING persistence_sqlite:4afa8ba672154946adc2c641763c8c4e/Users/lgroff/Library/Application Support/Google/Drive/user_default/sync_config.db 2015-11-19 09:01:47,312 -0500 INFO pid=1679 4520939520:RunAsync-_InitializeSyncAppAsync-1 sync_app.pyo:483 BandwidthThrottler configured via sync_config 2015-11-19 09:01:47,312 -0500 INFO pid=1679 4520939520:RunAsync-_InitializeSyncAppAsync-1 bandwidth.pyo:59 BandwidthThrottler.SetRxBytesPerSecond 0 2015-11-19 09:01:47,312 -0500 INFO pid=1679 4520939520:RunAsync-_InitializeSyncAppAsync-1 bandwidth.pyo: 68 BandwidthThrottler.SetTxBytesPerSecond 0 2015-11-19 09:01:47,313 -0500 INFO pid=1679 4520939520:RunAsync-_InitializeSyncAppAsync-1 sqlite.pyo:378 Close connection. path=/Users/lgroff/Library/Application Support/Google/Drive/user_default/sync_config.db 2015-11-19 09:01:47,313 -0500 INFO pid=1679 4520939520:RunAsync-_InitializeSyncAppAsync-1 sqlite.pyo:378 Close connection. path=/Users/lgroff/Library/Application Support/Google/Drive/user_default/snapshot.db 2015-11-19 09:01:47,556 -0500 INFO pid=1679 4520939520:RunAsync-_InitializeSyncAppAsync-1 utils.pyo:703 Execute cleanup callback 'persistence_sqlite:fe7510dce9be473abl2b74961b46bfae/Users/lgroff/Library/Application Support/Google/Drive/user_default/snapshot.db' EFTA00502232 2015-11-19 09:01:47,699 -0500 INFO pid=1679 4520939520:RunAsync-_InitializeSyncAppAsync-1 utils.pyo:703 Execute cleanup callback 'persistence_sqlite: 4afa8ba672154946adc2c641763c8c4e/Users/lgroff/Library/Application Support/Google/Drive/user_default/sync_config.db' 2015-11-19 09:01:47,702 -0500 INFO pid=1679 4520939520:FinderInjector sync_client thread.pyo:175 Finderlnjector run loop has started. 2015-11-19 El9:01:48,137 -0500 INFO pid=1679 140735235859216:MainThread image_resources.py:293 Loading image resources/images/ic_drawer_24.png 2015-11-19 09:01:48,177 -0500 INFO pid=1679 140735235859216:MainThread image_resources.py:293 Loading image resources/images/menu_drive-logo.png 2015-11-19 09:01:48,200 -0500 INFO pid=1679 140735235859216:MainThread image_resources.py:293 Loading image resources/images/menu_google-logo-gray.png 2015-11-19 09:01:48,233 -0500 INFO pid=1679 140735235859216:MainThread image_resources.py:293 Loading image resources/images/ic_folder_mydrive_24.png 2015-11-19 09:01:48,241 -0500 INFO pid=1679 140735235859216:MainThread image_resources.py:293 Loading image resources/images/ic_web_24.png 2015-11-19 09:01:48,242 -0500 INFO pid=1679 140735235859216:MainThread image_resources.py:293 Loading image resources/images/menu_backups.png 2015-11-19 09:01:48,244 -0500 INFO pid=1679 140735235859216:MainThread image_resources.py:293 Loading image resources/images/ic_sync_problem_24.png 2015-11-19 09:01:48,325 -0500 INFO pid=1679 140735235859216:MainThread image_resources.py:293 Loading image resources/images/ic_done_24.png 2015-11-19 09:01:48,895 -0500 INFO pid=1679 4541100032:ThreadMonitor Waiting on exit condition. Wake up after 3600s. 2015-11-19 09:01:48,896 -0500 INFO pid=1679 4545306624:_LaunchSyncApp master connection to /Users/lgrof f/Library/Application Support/Google/Drive/user_default/snapshot.db 2015-11-19 09:01:48,897 -0500 INFO pid=1679 4545306624:_LaunchSyncApp master connection to /Users/lgrof f/Library/Application Support/Google/Drive/user_default/sync_config.db 2015-11-19 09:01:48,898 -0500 INFO pid=1679 4545306624:_LaunchSyncApp utils.pyo:726 ADDING persistence_sqlite:71573c93fbff44b786cdbd07e79495d5/Users/lgroff/Library/Application Support/Google/Drive/user_default/snapshot.db 2015-11-19 09:01:48,898 -0500 INFO pid=1679 4545306624:_LaunchSyncApp utils.pyo:726 ADDING persistence_sqlite: 682f264c0a43445682bdd4775fb9ba74/Users/lgroff/Library/Application Support/Google/Drive/user_default/sync_config.db 2015-11-19 09:01:48,921 -0500 INFO pid=1679 4545306624:_LaunchSyncApp user.pyo:66 Initializing User instance with new credentials. None 2015-11-19 09:01:48,922 -0500 INFO pid=1679 4545306624:_LaunchSyncApp docs_client_factory.pyo:103 Creating a new DriveClient 2015-11-19 09:01:48,923 -0500 INFO pid=1679 4545306624:_LaunchSyncApp service.pyo:132 Creating singleton service instance of '<class 'common.token_bucket.CloudRucketManager'> 1 2015-11-19 09:01:48,923 -0500 INFO pid=1679 4545306624:_LaunchSyncApp service.pyo:132 Creating singleton service instance of '<class 'common.drive_api.drive_resource.Manager'>. 2015-11-19 09:01:48,923 -0500 INFO pid=1679 4545306624:_LaunchSyncApp service.pyo:132 Creating singleton service instance of '<class 'common.drive_api.http.Manager'>. 2015-11-19 09:01:48,923 -0500 INFO pid=1679 4545306624:_LaunchSyncApp drive_resource.pyo:130 Initialize apiclient Drive resource for current user token 2015-11-19 09:01:48,944 -0500 ERROR pid=1679 4549513216:IpcServerThread ipc_socket_base.pyo:249 Failed to bind to socket /private/var/folders/n1/ypw25pmj06qfyyl_8xntakf40000gn/T/tmpfAkj_j (attempt 1 of 3) Traceback (most recent call last): File "common/ipc/ipc_socket_base.pyo", line 242, in Bind File "common/ipc/ipc_socket_base.pyo", line 176, in Bind File "socket.pyo", line 228, in meth error: [Erma 48] Address already in use 2015-11-19 09:01:48,944 -0500 ERROR pid=1679 4549513216:IpcServerThread ipc_socket_base.pyo:249 Failed to bind to socket /private/var/folders/n1/ypw25pmj06qfyyl_8xntakf40000gn/T/tmpfAkj_j (attempt 2 of 3) Traceback (most recent call last): File "common/ipc/ipc_socket_base.pyo", line 242, in Bind File "common/ipc/ipc_socket_base.pyo", line 176, in Bind File "socket.pyo", line 228, in meth error: [Erma 48] Address already in use 2015-11-19 09:01:48,945 -0500 WARNING pid=1679 4549513216:IpcServerThread server.pyo:145 thread_manager.pyo:336 sqlite.pyo:276 Open sqlite.pyo:276 Open EFTA00502233 Socket (/Users/lgroff/Library/Application Support/Google/Drive/GoogleDrivelpcPipe) already in use, deleting it. 2015-11-19 09:01:48,988 -0500 INFO pid=1679 4545306624: LaunchSyncApp drive_resource.pyo:178 Drive SDK baseUrl = https://www.googleapis.com/drive/v2internal/ 2015-11-19 09:01:49,000 -0500 INFO pid=1679 4545306624:_LaunchSyncApp service.pyo:132 Creating singleton service instance of '<class 'common.drive_api.http.AccessTokenlnMemoryCache'>' 2015-11-19 09:01:49,000 -0500 INFO pid=1679 4545306624:_LaunchSyncApp drive_request.pyo:220 Drive request: About(tags=Reason.SYNC_OTHER) - Read request - None 2015-11-19 09:01:49,003 -0500 INFO pid=1679 4545306624:_LaunchSyncApp discovery.pyo:762 URL being requested: GET https://www.googleapis.com/drive/v2internal/about? fields=rootFolderld%2CquotaBytesTotal%2CquotaBytesUsedAggregate%2CquotaBytesUsedInTrash%2Cquo taType%2Cuser%2FemailAddress&reason=304Salt=json 2015-11-19 09:01:49,028 -0500 INFO pid=1679 4545306624:_LaunchSyncApp client.pyo:515 Attempting refresh to obtain initial access_token 2015-11-19 09:01:49,029 -0500 INFO pid=1679 4545306624:_LaunchSyncApp client.pyo:755 Refreshing access_token 2015-11-19 09:01:49,032 -0500 INFO pid=1679 4545306624:_LaunchSyncApp service.pyo:132 Creating singleton service instance of '<class 'common.net.dapper.DapperService'>' 2015-11-19 09:01:49,032 -0500 INFO pid=1679 4545306624:_LaunchSyncApp http.pyo:249 Request user-agent: Python-httplib2/0.9 (gzip) 2015-11-19 09:01:49,032 -0500 INFO pid=1679 4545306624:_LaunchSyncApp sync_http_client.pyo:233 Opening direct connecton to accounts.google.com:443. 2015-11-19 09:01:49,418 -0500 INFO pid=1679 140735235859216:MainThread sqlite.pyo:276 Open master connection to /Users/lgrof f/Library/Application Support/Google/Drive/user_default/snapshot.db 2015-11-19 09:01:49,418 -0500 INFO pid=1679 140735235859216:MainThread sqlite.pyo:276 Open master connection to /Users/lgrof f/Library/Application Support/Google/Drive/user_default/sync_config.db 2015-11-19 09:01:49,419 -0500 INFO pid=1679 140735235859216:MainThread sqlite.pyo:378 Close connection. path=/Users/lgroff/Library/Application Support/Google/Drive/user_default/snapshot.db 2015-11-19 09:01:49,419 -0500 INFO pid=1679 140735235859216:MainThread sqlite.pyo:378 Close connection. path=/Users/lgroff/Library/Application Support/Google/Drive/user_default/sync_config.db 2015-11-19 09:01:49,602 -0500 INFO pid=1679 4545306624:_LaunchSyncApp http.pyo:268 Response: 151 bytes - application/json; charset=utf-8 (encoding:gzip) 2015-11-19 09:01:49,603 -0500 INFO pid=1679 4545306624:_LaunchSyncApp http.pyo:249 Request user-agent: googledrivesync-1.25.0523.2491 google-api-python-client/1.3.1 (gzip) (Darwin/10.9.5) 2015-11-19 09:01:49,603 -0500 INFO pid=1679 4545306624:_LaunchSyncApp sync_http_client.pyo:233 Opening direct connecton to www.googleapis.com:443. 2015-11-19 09:01:50,399 -0500 INFO pid=1679 4545306624:_LaunchSyncApp http.pyo:268 Response: 241 bytes - application/json; charset=UTF-8 (encoding:gzip) 2015-11-19 09:01:50,401 -0500 INFO pid=1679 4545306624:_LaunchSyncApp drive_request.pyo:225 Drive response: Request (None): About(tags=Reason.SYNC_OTHER) Response: About(root_id=0ABNN8iEiWGvgUk9PVA, email_address=lesley.jee@gmail.com, quota_bytes_total=16106127360, quota_bytes_used_aggregate=14912168649, quota_bytes_used_in_trash=405074503, quota_type=LIMITED) 2015-11-19 09:01:50,401 -0500 INFO pid=1679 4545306624:_LaunchSyncApp service.pyo:132 Creating singleton service instance of '<class 'common.drive_api.doc_id_provider.Store'>' 2015-11-19 09:01:50,402 -0500 INFO pid=1679 4545306624:_LaunchSyncApp user.pyo:66 Initializing User instance with new credentials. lesley.jee@gmail.com 2015-11-19 09:01:50,402 -0500 INFO pid=1679 4545306624:_LaunchSyncApp features.pyo:131 Loads feature switches. 2015-11-19 09:01:50,402 -0500 INFO pid=1679 4545306624:_LaunchSyncApp features.pyo:165 Loading feature switches with server. 2015-11-19 09:01:50,402 -0500 INFO pid=1679 4545306624:_LaunchSyncApp feature_switch_manager.pyo:633 Calling server to get feature switches. 2015-11-19 09:01:50,402 -0500 INFO pid=1679 4545306624:_LaunchSyncApp drive_request.pyo:220 Drive request: ListFeatureSwitches(tags=Reason.SYNC_OTHER) - Read request - lesley.jee@gmail.com EFTA00502234 2015-11-19 09:01:50,405 -0500 INFO pid=1679 4545306624:_LaunchSyncApp discovery.pyo:762 URL being requested: GET https://www.googleapis.com/drive/v2internal/settings? fields=items%2Fkey%2Citems%2FvalueSreason=304Snamespace=FEATURE_SWITCHSalt=json 2015-11-19 09:01:50,405 -0500 INFO pid=1679 4545306624:_LaunchSyncApp http.pyo:249 Request user-agent: googledrivesync-1.25.0523.2491 google-api-python-client/1.3.1 (gzip) (Darwin/10.9.5) 2015-11-19 09:01:50,461 -0500 INFO pid=1679 4545306624:_LaunchSyncApp http.pyo:268 Response: 1017 bytes - application/json; charset=UTF-8 (encoding:gzip) 2015-11-19 09:01:50,462 -0500 INFO pid=1679 4545306624:_LaunchSyncApp drive_request.pyo:225 Drive response: Request (lesley.jee@gmail.com): ListFeatureSwitches(tags=Reason.SYNC_OTHER) Response: (u'enable_impressions_library': u'false', u'enable_multiple_accounts': u'false', u'enable_push': u'true', u'enable_shared_move_confirmation': u'false', u'log_backup_count': u'0', u'crash_throttle_percentage': u'99.7', u'perf_throttle_percentage': u'100 1, u'enable_feedback': u'true', u'enable_multipause': u'false', u'enable_usb_detection': u'false', u'max_batch_upload_files': u'30', u'cloud_graph_disk_generation': u'21, u'test.feature_switch.name': u", u'false', u'query_strategy': wall', u'selective_sub_folder_sync': u'false') 2015-11-19 09:01:50,464 -0500 INFO pid=1679 4545306624:_LaunchSyncApp sync_app.pyo:1209 Feature Switches: FeatureSwitchSettings( accept_blob_download_gzip_encoding=True, backup_polling_interval_secs=7200, change_filters=('DRIVE_SYNC'), cloud_graph_disk_generation=2, crash_log_size_limit=10000000, crash_throttle_percentage=99.7, disabled_cloud_graph_disk_app_versions=[], docs_list_page_size=1000, download_in_place=False, download_progress_bar=False, download_strategy= 1 url_template', download_url='https://googledrive.com/p/host/(doc_id}', enable_arbitrary_sync=False, enable_batch_upload=True, enable_change_filters=False, enable_context_menu=True, enable_dapper_trace=False, enable_disk_dict=False, enable_feedback=True, enable_f ile_sync_status=True, enable_impressions_library=False, enable_multipause=False, enable_multiple_accounts=False, enable_native_opener=True, enable_push=True, enable_usb_detection=False, feedback_type='prod', ghost_all_files=False, help_url=lhttps://support.google.com/drive/M1=%ssp=desktop_homel, impressions_heartbeat_interval_secs=10800, impressions_upload_interval_secs=1800, log_backup_count=0, log_size_mb=256, max_batch_upload_files=30, new document url='https://docs.google.com/document?usp=drive_sync', new_presentation_ur1='https://docs.google.com/presentation?usp=drive_synci, new_spreadsheet_ur1=Ilittps://docs.google.com/spreadsheets?usp=drive_synci, numworkers=3, only_rooted_items_in_cloud_graph=False, open_url=lhttps://docs.google.com/open?id=fdoc_id)', overlays_enabled_finder_versions=p10.7', '10.7.1', '10.7.2', '10.7.3', '10.7.5', '10.8', EFTA00502235 '10.8.1', '10.8.2', '10.8.3', '10.9', '10.9.1', '10.9.2', '10.9.3', '10.9.4'], perf_throttle_percentage=100.0, push_clientversion=1, push_keepalive_interval=72000.0, regular_polling_interval_secs=30, selective_sub_folder_sync=False, share_template_url=lhttps://drive.google.com/sharing/share? subapp=10&shareProtocolVersion=2&theme=2&command=settings&shareUiType=default&authuser=0&clie nt=desktop', show_confirmation_dialog_on_delete=True, telemetry_enabled=True, telemetry_upload_interval_secs=1800, telemetry_url=lhttps://drive.google.com/syncclient_impressions', token_bucket_read_qps=10, token_bucketwrite_qps=3, use_drive_api=False,) 2015-11-19 09:01:50,465 -0500 INFO pid=1679 4545306624:_LaunchSyncApp logging_config.pyo:249 OS: Darwin/10.9.5 2015-11-19 09:01:50,468 -0500 INFO pid=1679 4545306624:_LaunchSyncApp logging_config.pyo:252 Google Drive (build 1.25.0523.2491) 2015-11-19 09:01:50,468 -0500 INFO pid=1679 4545306624:_LaunchSyncApp logging_config.pyo:253 SSL: OpenSSL 0.9.8zg 14 July 2015 2015-11-19 09:01:50,468 -0500 INFO pid=1679 4545306624:_LaunchSyncApp sync_app.pyo:1218 Config: Email: lesley.jee@gmail.com Sync root: /Users/lgroff/Google Drive Sync collections: set([]) Upgrade number: 22 App version: 1.25.0523.2491 Selective sync: False Cloud Graph generation: 2 Folder sync: [] Local app whitelist: set([]) Local app blacklist: set([]) Bandwidth RX Rate kpBs: 0 Bandwidth TX Rate kpBs: 0 Yosemite icons upgraded: False Win10 icons upgraded: False USB sync enabled: True Do sync default folder: True 2015-11-19 09:01:50,471 -0500 INFO pid=1679 4545306624:_LaunchSyncApp sync_app.pyo:1223 Switching cloud client based on new feature switches 2015-11-19 09:01:50,471 -0500 INFO pid=1679 4545306624:_LaunchSyncApp docs_client_factory.pyo:112 Creating a new Wapi DocsClient 2015-11-19 09:01:50,472 -0500 INFO pid=1679 4545306624:_LaunchSyncApp telemetry.pyo:222 SetPushClientVersion: 1 (3, 20130807) 2015-11-19 09:01:50,472 -0500 INFO pid=1679 4545306624:_LaunchSyncApp service.pyo:132 Creating singleton service instance of '<class 'common.push.telemetry.PushTelemetry'>' 2015-11-19 09:01:50,472 -0500 INFO pid=1679 4545306624:_LaunchSyncApp service.pyo:132 Creating singleton service instance of '<class 'common.telemetry.telemetry_manager.TelemetryManager'> 1 2015-11-19 09:01:50,972 -0500 INFO pid=1679 4545306624:_LaunchSyncApp image_resources.py:269 Loading custom image resources/images/folder-mac.icns with function _CreateNSlmage 2015-11-19 09:01:50,973 -0500 INFO pid=1679 4545306624:_LaunchSyncApp service.pyo:132 Creating singleton service instance of '<class 'common.arbitrary_sync.ArbitrarySync'>' 2015-11-19 09:01:50,974 -0500 INFO pid=1679 4545306624:_LaunchSyncApp rule_factory.pyo:159 Registering aggregation rule type: common.aggregator_rules.downloads.DownloadCreate 2015-11-19 09:01:50,974 -0500 INFO pid=1679 4545306624:_LaunchSyncApp rule_factory.pyo:159 Registering aggregation rule type: common.aggregator_rules.downloads.DownloadModify 2015-11-19 09:01:50,974 -0500 INFO pid=1679 4545306624:_LaunchSyncApp rule_factory.pyo:159 Registering aggregation rule type: common.aggregator_rules.uploads.UploadCreate 2015-11-19 09:01:50,974 -0500 INFO pid=1679 4545306624:_LaunchSyncApp rule_factory.pyo:159 Registering aggregation rule type: common.aggregator_rules.uploads.UploadDelete 2015-11-19 09:01:50,975 -0500 INFO pid=1679 4545306624:_LaunchSyncApp rule_factory.pyo:159 Registering aggregation rule type: common.aggregator_rules.uploads.UploadModify EFTA00502236 2015-11-19 09:01:50,975 -0500 INFO Registering aggregation rule type: 2015-11-19 09:01:50,975 -0500 INFO Registering aggregation rule type: 2015-11-19 09:01:50,975 -0500 INFO Registering aggregation rule type: 2015-11-19 09:01:51,506 -0500 INFO filewatcher_ext initialized 2015-11-19 09:01:51,507 -0500 INFO pid=1679 4545306624:_LaunchSyncApp docs_client_factory.pyo:112 Creating a new Wapi DocsClient 2015-11-19 09:01:51,508 -0500 INFO pid=1679 4545306624:_LaunchSyncApp docs_client_factory.pyo:112 Creating a new Wapi DocsClient 2015-11-19 09:01:51,509 -0500 INFO pid=1679 4545306624:_LaunchSyncApp docs_client_factory.pyo:112 Creating a new Wapi DocsClient 2015-11-19 09:01:51,510 -0500 INFO pid=1679 4545306624:_LaunchSyncApp docs_client_factory.pyo:112 Creating a new Wapi DocsClient 2015-11-19 09:01:51,510 -0500 INFO pid=1679 4545306624:_LaunchSyncApp docs_client_factory.pyo:112 Creating a new Wapi DocsClient 2015-11-19 09:01:51,511 -0500 INFO pid=1679 4545306624:_LaunchSyncApp docs_client_factory.pyo:112 Creating a new Wapi DocsClient 2015-11-19 09:01:51,512 -0500 INFO pid=1679 4545306624:_LaunchSyncApp docs_client_factory.pyo:112 Creating a new Wapi DocsClient 2015-11-19 09:01:51,513 -0500 INFO pid=1679 4545306624:_LaunchSyncApp xmpplib_notifier.pyo:34 Configure storage: <common.push.tango.storage.SyncConfigStorage; proxy of <Swig Object of type 'invalidation::Storage *' at 0xl0f4e1810> > 2015-11-19 09:01:51,513 -0500 INFO pid=1679 4545306624:_LaunchSyncApp xmpplib_notifier.pyo:59 Creating client thread 2015-11-19 09:01:51,514 -0500 INFO pid=1679 4545306624:_LaunchSyncApp push_xmpp_client.pyo:223 Using talk server: talk.google.com:5222 2015-11-19 09:01:51,514 -0500 INFO pid=1679 4545306624:_LaunchSyncApp xmpplib_notifier.pyo:68 Creating notification bridge 2015-11-19 09:01:51,516 -0500 INFO pid=1679 4545306624:_LaunchSyncApp docs_client_factory.pyo:112 Creating a new Wapi DocsClient 2015-11-19 09:01:51,518 -0500 INFO pid=1679 4563861504:Worker-1 sqlite.pyo:276 Open master connection to /Users/lgroff/Library/Application Support/Google/Drive/user_default/snapshot.db 2015-11-19 09:01:51,519 -0500 INFO pid=1679 4568068096:LocalDiskSpaceChecker sync_client_thread.pyo:175 LocalDiskSpaceChecker run loop has started. 2015-11-19 09:01:51,520 -0500 INFO pid=1679 4584378368:XmppClient telemetry.pyo:151 Push state None => PushStates.CONNECTING 2015-11-19 09:01:51,520 -0500 INFO pid=1679 4584378368:XmppClient connection_task.pyo:151 Recalculated LoginTask timeout: 16.000000 2015-11-19 09:01:51,521 -0500 INFO pid=1679 4588584960:PauseTelemetryThread sync_client_thread.pyo:175 PauseTelemetryThread run loop has started. 2015-11-19 09:01:51,521 -0500 INFO pid=1679 4592791552:LocalWatcher watcher.pyo:312 LocalWatcher Run invoked.Waiting for first pass of local scan from poller to start 2015-11-19 09:01:51,521 -0500 INFO pid=1679 4584378368:XmppClient telemetry.pyo:165 PushStates.CONNECTING: +0.00165886 => 0.00165886 2015-11-19 09:01:51,522 -0500 INFO pid=1679 4584378368:XmppClient xmpplib.pyo:80 Connecting to talk.google.com:5222 2015-11-19 09:01:51,522 -0500 INFO pid=1679 4601204736:Batcher sqlite.pyo:276 Open master connection to /Users/lgrof f/Library/Application Support/Google/Drive/user_default/snapshot.db 2015-11-19 09:01:51,523 -0500 INFO pid=1679 4605411328:RawEventUpgrader sync_client_thread.pyo:175 RawEventUpgrader run loop has started. 2015-11-19 09:01:51,523 -0500 INFO pid=1679 4563861504:Worker-1 sqlite.pyo:276 Open master connection to /Users/lgrof f/Library/Application Support/Google/Drive/user_default/sync_config.db 2015-11-19 09:01:51,524 -0500 INFO pid=1679 4609617920:TelemetryUploaderThread sync_client_thread.pyo:175 TelemetryUploaderThread run loop has started. 2015-11-19 09:01:51,524 -0500 INFO pid=1679 4613824512:TelemetryStoreSizeMonitorThread sync_client_thread.pyo:175 TelemetryStoreSizeMonitorThread run loop has started. 2015-11-19 09:01:51,524 -0500 INFO pid=1679 4601204736:Batcher sqlite.pyo:276 Open master connection to /Users/lgrof f/Library/Application Support/Google/Drive/user_default/sync_config.db pid=1679 4545306624:_LaunchSyncApp rule_factory.pyo:159 common.aggregator_rules.uploads.UploadMove pid=1679 4545306624:_LaunchSyncApp rule_factory.pyo:159 common.aggregator_rules.uploads.UploadMoveFrom pid=1679 4545306624:_LaunchSyncApp rule_factory.pyo:159 common.aggregator_rules.uploads.UploadMoveTo pid=1679 4559654912:FilewatcherMonitor filewatcher.pyo:71 EFTA00502237 2015-11-19 09:01:51,525 -0500 INFO pid=1679 4613824512:TelemetryStoreSizeMonitorThread telemetry_store_monitor_thread.pyo: 44 Checking Telemetry store size. 2015-11-19 09:01:51,525 -0500 INFO pid=1679 4618031104:Worker-0 sqlite.pyo:276 Open master connection to /Users/lgroff/Library/Application Support/Google/Drive/user_default/snapshot.db 2015-11-19 09:01:51,525 -0500 INFO pid=1679 4622237696:CrashReportUploaderThread crash_report_uploader_thread.pyo: 60 Starting CrashReportUploaderThread. 2015-11-19 09:01:51,526 -0500 INFO pid=1679 4563861504:Worker-1 utils.pyo:726 ADDING persistence_sqlite:d3dd9d7764b548dc84d4a10d04d80c87/Users/lgroff/Library/Application Support/Google/Drive/user_default/snapshot.db 2015-11-19 09:01:51,526 -0500 INFO pid=1679 4626444288:PushTelemetryThread sync_client_thread.pyo:175 PushTelemetryThread run loop has started. 2015-11-19 09:01:51,527 -0500 INFO pid=1679 4630650880:FeatureSwitchPoller sync_client_thread.pyo:175 FeatureSwitchPoller run loop has started. 2015-11-19 09:01:51,529 -0500 INFO pid=1679 4630650880:FeatureSwitchPoller features.pyo:156 Current cloud client is not using the same service than what we used initially to fetch feature switches. Using a one-off client with the same service. 2015-11-19 09:01:51,527 -0500 INFO pid=1679 4563861504:Worker-1 utils.pyo:726 ADDING persistence_sqlite: 90b4f66e500b49f8bbc671f06f6cf7e1/Users/lgroff/Library/Application Support/Google/Drive/user_default/sync_config.db 2015-11-19 09:01:51,528 -0500 INFO pid=1679 4639064064:LocalFSPoller sync_client_thread.pyo:175 LocalFSPoller run loop has started. 2015-11-19 09:01:51,528 -0500 INFO pid=1679 4634857472:Worker-2 sqlite.pyo:276 Open master connection to /Users/lgroff/Library/Application Support/Google/Drive/user_default/snapshot.db 2015-11-19 09:01:51,528 -0500 INFO pid=1679 4618031104:Worker-0 sqlite.pyo:276 Open master connection to /Users/lgroff/Library/Application Support/Google/Drive/user_default/sync_config.db 2015-11-19 09:01:51,527 -0500 INFO pid=1679 4601204736:Batcher utils.pyo:726 ADDING persistence_sqlite:59d37d14cdca48f89d88e0326b6c40ca/Users/lgroff/Library/Application Support/Google/Drive/user_default/snapshot.db 2015-11-19 09:01:51,529 -0500 INFO pid=1679 4630650880:FeatureSwitchPoller features.pyo:180 Create a default cloud client factory. 2015-11-19 09:01:51,529 -0500 INFO pid=1679 4563861504:Worker-1 command_factory.pyo:186 Registering worker command type: common.worker.downloads.DownloadChangeACL 2015-11-19 09:01:51,530 -0500 INFO pid=1679 4643270656:PushNotificationKeepaliveThread sync_client_thread.pyo:175 PushNotificationKeepaliveThread run loop has started. 2015-11-19 09:01:51,530 -0500 INFO pid=1679 4647477248:OverlayStatusCleaner sync_client_thread.pyo:175 OverlayStatusCleaner run loop has started. 2015-11-19 09:01:51,532 -0500 INFO pid=1679 4545306624:_LaunchSyncApp drive_extension_installer.pyo:174 Uninstalling extension nknebiagdodnminbdpflhpkgfpeijdbf 2015-11-19 09:01:51,532 -0500 INFO pid=1679 4660097024:CloudWatcher sqlite.pyo:276 Open master connection to /Users/lgroff/Library/Application Support/Google/Drive/user_default/snapshot.db 2015-11-19 09:01:51,532 -0500 INFO pid=1679 4601204736:Batcher utils.pyo:726 ADDING persistence_sqlite:80619c95653e4eedb146a4806blee186/Users/lgroff/Library/Application Support/Google/Drive/user_default/sync_config.db 2015-11-19 09:01:51,533 -0500 INFO pid=1679 4630650880:FeatureSwitchPoller features.pyo:182 Set credentials on User service. 2015-11-19 09:01:51,533 -0500 INFO pid=1679 4618031104:Worker-0 utils.pyo:726 ADDING persistence_sqlite:a794a69c9a754e0a8d82elela5560f7d/Users/lgroff/Library/Application Support/Google/Drive/user_default/snapshot.db 2015-11-19 09:01:51,533 -0500 INFO pid=1679 4634857472:Worker-2 sqlite.pyo:276 Open master connection to /Users/lgroff/Library/Application Support/Google/Drive/user_default/sync_config.db 2015-11-19 09:01:51,557 -0500 INFO pid=1679 4584378368:Kmppelient telemetry.pyo:165 PushStates.CONNECTING: +0.0359248 => 0.0375837 2015-11-19 09:01:51,583 -0500 INFO pid=1679 4563861504:Worker-1 command_factory.pyo:186 Registering worker command type: common.worker.downloads.DownloadCreate 2015-11-19 09:01:51,587 -0500 INFO pid=1679 4563861504:Worker-1 command_factory.pyo:186 Registering worker command type: common.worker.downloads.DownloadDelete 2015-11-19 09:01:51,586 -0500 INFO pid=1679 4630650880:FeatureSwitchPoller user.pyo:66 EFTA00502238 Initializing User instance with new credentials. None 2015-11-19 09:01:51,586 -0500 INFO pid=1679 4545306624:_LaunchSyncApp utils.pyo:703 Execute cleanup callback 'persistence_sqlite:682f264c0a43445682bdd4775fb9ba74/Users/lgroff/Library/Application Support/Google/Drive/user_default/sync_config.db' 2015-11-19 09:01:51,587 -0500 INFO pid=1679 4618031104:Worker-0 utils.pyo:726 ADDING persistence_sqlite:49abb3af54b74bc4acb42e3d7fbfe4e3/Users/lgroff/Library/Application Support/Google/Drive/user_default/sync_config.db 2015-11-19 09:01:51,587 -0500 INFO pid=1679 4584378368:Kmppelient telemetry.pyo:151 Push state PushStates.CONNECTING => PushStates.NEGOTIATING 2015-11-19 09:01:51,585 -0500 INFO pid=1679 4643270656:PushNotificationKeepaliveThread sync_http_client.pyo:233 Opening direct connecton to accounts.google.com:443. 2015-11-19 09:01:51,587 -0500 INFO pid=1679 4660097024:CloudWatcher sqlite.pyo:276 Open master connection to /Users/lgrof f/Library/Application Support/Google/Drive/user_default/sync_config.db 2015-11-19 09:01:51,587 -0500 INFO pid=1679 4563861504:Worker-1 command_factory.pyo:186 Registering worker command type: common.worker.downloads.DownloadModify 2015-11-19 09:01:51,588 -0500 INFO pid=1679 4630650880:FeatureSwitchPoller docs_client_factory.pyo:103 Creating a new DriveClient 2015-11-19 09:01:51,588 -0500 INFO pid=1679 4634857472:Worker-2 utils.pyo:726 ADDING persistence_sqlite:2813703538be4d28b6882b88493521ec/Users/lgroff/Library/Application Support/Google/Drive/user_default/snapshot.db 2015-11-19 09:01:51,588 -0500 INFO pid=1679 4545306624:_LaunchSyncApp sqlite.pyo:378 Close connection. path=/Users/lgroff/Library/Application Support/Google/Drive/user_default/sync_config.db 2015-11-19 09:01:51,589 -0500 INFO pid=1679 4618031104:Worker-0 command_factory.pyo:186 Registering worker command type: common.worker.uploads.BatchUploadCreate 2015-11-19 09:01:51,590 -0500 INFO pid=1679 4563861504:Worker-1 command_factory.pyo: 186 Registering worker command type: common.worker.downloads.DownloadMove 2015-11-19 09:01:51,592 -0500 INFO pid=1679 4563861504:Worker-1 command_factory.pyo:186 Registering worker command type: common.worker.downloads.DownloadRename 2015-11-19 09:01:51,591 -0500 INFO pid=1679 4634857472:Worker-2 utils.pyo:726 ADDING persistence_sqlite:f886201414aa4e60863c515b8c84b995/Users/lgroff/Library/Application Support/Google/Drive/user_default/sync_config.db 2015-11-19 09:01:51,591 -0500 INFO pid=1679 4660097024:CloudWatcher utils.pyo:726 ADDING persistence_sqlite:4b635265bfla468da5cb52f9689262d3/Users/lgroff/Library/Application Support/Google/Drive/user_default/snapshot.db 2015-11-19 09:01:51,591 -0500 INFO pid=1679 4618031104:Worker-0 command_factory.pyo:186 Registering worker command type: common.worker.uploads.UploadCreate 2015-11-19 09:01:51,591 -0500 INFO pid=1679 4630650880:FeatureSwitchPoller features.pyo:165 Loading feature switches with server. 2015-11-19 09:01:51,592 -0500 INFO pid=1679 4545306624:_LaunchSyncApp utils.pyo:703 Execute cleanup callback 'persistence_sqlite: 71573c93fbff44b786cdbd07e79495d5/Users/lgroff/Library/Application Support/Google/Drive/user_default/snapshot.db' 2015-11-19 09:01:51,592 -0500 INFO pid=1679 4563861504:Worker-1 command_factory.pyo:186 Registering worker command type: common.worker.internals.InternalCreate 2015-11-19 09:01:51,592 -0500 INFO pid=1679 4634857472:Worker-2 command_factory.pyo:186 Registering worker command type: common.worker.internals.InternalCreate 2015-11-19 09:01:51,592 -0500 INFO pid=1679 4660097024:CloudWatcher utils.pyo:726 ADDING persistence_sqlite:795ac717ad51421c8bfb44616f5df3c2/Users/lgroff/Library/Application Support/Google/Drive/user_default/sync_config.db 2015-11-19 09:01:51,592 -0500 INFO pid=1679 4618031104:Worker-0 command_factory.pyo: 186 Registering worker command type: common.worker.uploads.UploadDelete 2015-11-19 09:01:51,593 -0500 INFO pid=1679 4630650880:FeatureSwitchPoller feature_switch_manager.pyo:633 Calling server to get feature switches. 2015-11-19 09:01:51,593 -0500 INFO pid=1679 4545306624:_LaunchSyncApp sqlite.pyo:378 Close connection. path=/Users/lgroff/Library/Application Support/Google/Drive/user_default/snapshot.db 2015-11-19 09:01:51,593 -0500 INFO pid=1679 4563861504:Worker-1 EFTA00502239 command_factory.pyo:186 common.worker. internals 2015-11-19 09:01:51,593 command_factory.pyo:186 common.worker. internals 2015-11-19 09:01:51,593 Registering worker command type: .InternalModify -0500 INFO pid=1679 4634857472:Worker-2 Registering worker command type: .InternalModify -0500 INFO pid=1679 4660097024:CloudWatcher Initialize persistent graph with generation 2 2015-11-19 09:01:51,594 -0500 INFO pid=1679 4660097024:CloudWatcher Current sync config generation: 2 2015-11-19 09:01:51,595 -0500 INFO pid=1679 4660097024:CloudWatcher Cleanup cloud graph directory '/Users/lgrof f/Library/Application Support/Google/Drive/user_default/cloud_graph' of files 'dict_*.db*' except ['dict_2.db 1, Idict_2.db-shm., 'dict_2.db-wal'] 2015-11-19 09:01:51,593 -0500 INFO pid=1679 4618031104:Worker-0 command_factory.pyo: 186 Registering worker command type: common.worker.uploads.UploadModify 2015-11-19 09:01:51,595 -0500 INFO pid=1679 4618031104:Worker-0 command_factory.pyo: 186 Registering worker command type: common.worker.uploads.UploadMove 2015-11-19 09:01:51,594 -0500 INFO pid=1679 4630650880:FeatureSwitchPoller drive_resource.pyo:130 Initialize apiclient Drive resource for current user token 2015-11-19 09:01:51,596 -0500 INFO pid=1679 4630650880:FeatureSwitchPoller drive_resource.pyo: 178 Drive SDK baseUrl = https://www.googleapis.com/drive/v2internal/ 2015-11-19 09:01:51,594 -0500 INFO pid=1679 4634857472:Worker-2 workers.pyo:124 Waiting for batcher to initialize 2015-11-19 09:01:51,597 -0500 INFO pid=1679 4634857472:Worker-2 sync_client_thread.pyo:175 Worker-2 run loop has started. 2015-11-19 09:01:51,595 -0500 INFO pid=1679 4618031104:Worker-0 command_factory.pyo:186 Registering worker command type: common.worker.uploads.UploadRename 2015-11-19 09:01:51,594 -0500 INFO pid=1679 4563861504:Worker-1 workers.pyo:124 Waiting for batcher to initialize 2015-11-19 09:01:51,598 -0500 INFO pid=1679 4618031104:Worker-0 workers.pyo:124 Waiting for batcher to initialize 2015-11-19 09:01:51,598 -0500 INFO pid=1679 4563861504:Worker-1 sync_client_thread.pyo:175 Worker-1 run loop has started. 2015-11-19 09:01:51,598 -0500 INFO pid=1679 4618031104:Worker-0 sync_client_thread.pyo:175 Worker-0 run loop has started. 2015-11-19 09:01:51,599 -0500 INFO pid=1679 4630650880:FeatureSwitchPoller drive_request.pyo:220 Drive request: ListFeatureSwitches(tags=Reason.SYNC_OTHER) - Read request - None 2015-11-19 09:01:51,602 -0500 INFO pid=1679 4630650880:FeatureSwitchPoller discovery.pyo:762 URL being requested: GET https://www.googleapis.com/drive/v2internal/settings? fields=items%2Fkey%2Citems%2FValue&reason=304&namespace=FEATURE_SWITCHfialt=json 2015-11-19 09:01:51,602 -0500 INFO pid=1679 4630650880:FeatureSwitchPoller client.pyo:515 Attempting refresh to obtain initial access_token 2015-11-19 09:01:51,603 -0500 INFO pid=1679 4630650880:FeatureSwitchPoller client.pyo:735 Updated access_token read from Storage 2015-11-19 09:01:51,603 -0500 INFO pid=1679 4630650880:FeatureSwitchPoller http.pyo:249 Request user-agent: googledrivesync-1.25.0523.2491 google-api-python-client/1.3.1 (gzip) (Darwin/10.9.5) 2015-11-19 09:01:51,603 -0500 INFO pid=1679 4630650880:FeatureSwitchPoller sync_http_client.pyo:233 Opening direct connecton to www.googleapis.com:443. 2015-11-19 09:01:51,608 -0500 INFO pid=1679 4660097024:CloudWatcher utils.pyo:726 ADDING DBConnectionManagerCleanupCallback 2015-11-19 09:01:51,608 -0500 INFO pid=1679 4660097024:CloudWatcher db_connection.pyo:200 Created thread connection on database /Users/lgroff/Library/Application Support/Google/Drive/user_default/cloud_graph/dict_2.db 2015-11-19 09:01:51,609 -0500 INFO pid=1679 4660097024:CloudWatcher cloud_graph.pyo:1001 Reuse CloudDiskDict database: /Users/lgroff/Library/Application Support/Google/Drive/user_default/cloud_graph/dict_2.db 2015-11-19 09:01:51,632 -0500 INFO pid=1679 4584378368:XmppClient SSL peer=gmail.com 2015-11-19 09:01:51,696 -0500 INFO pid=1679 4584378368:XmppClient PushStates.NEGOTIATING: 40.139294 => 0.139294 2015-11-19 09:01:51,814 -0500 INFO pid=1679 4630650880:FeatureSwitchPoller http.pyo:268 Response: 1017 bytes - application/json; charset=UTF-8 (encoding:gzip) 2015-11-19 09:01:51,819 -0500 INFO pid=1679 4643270656:PushNotificationKeepaliveThread cloud_graph.pyo:120 cloud_graph.pyo: 1626 cloud_graph. pyo:1477 xmpplib.pyo:397 Start telemetry.pyo: 165 EFTA00502240 sync_http_client.pyo:233 Opening direct connecton to clients3.google.com:443. 2015-11-19 09:01:51,876 -0500 INFO pid=1679 4584378368:XmppClient telemetry.pyo:165 PushStates.NEGOTIATING: 40.179283 => 0.318577 2015-11-19 09:01:51,901 -0500 INFO pid=1679 4660097024:CloudWatcher cloud_graph.pyo:161 Initialize persistent graph with existing database /Users/lgroff/Library/Application Support/Google/Drive/user_default/cloud_graph/dict_2.db 2015-11-19 09:01:51,902 -0500 INFO pid=1679 4660097024:CloudWatcher cloud_graph.pyo:256 Building gdoc docids cache. 2015-11-19 09:01:51,974 -0500 INFO pid=1679 4584378368:XmppClient task.pyo:254 Task <common.push.xmpp.login_task.LoginTask object at Oxl0f4a2e50> complete. 2015-11-19 09:01:51,975 -0500 WARNING pid=1679 4584378368:XmppClient login_task.pyo:90 Clearing connection for LoginTask: <common.push.xmpp.login_task.LoginTask object at Oxl0f4a2e50> 2015-11-19 09:01:51,975 -0500 INFO pid=1679 4584378368:XmppClient push_xmpp_client.pyo:313 Connected to talk.google.com:5222 2015-11-19 09:01:51,975 -0500 WARNING pid=1679 4545306624:RunAsync-_OnXmppConnect-4 notification_bridge.pyo:126 XMPP detected connect. 2015-11-19 09:01:51,976 -0500 INFO pid=1679 4545306624:RunAsync-_OnXmppConnect-4 xmpp_network_channel.pyo:169 Sending push channel subscription request 2015-11-19 09:01:52,015 -0500 INFO pid=1679 4584378368:XmppClient xmpp_network_channel.pyo:187 Received subscription response from Push for XMPPBot 2015-11-19 09:01:52,086 -0500 INFO pid=1679 4643270656:PushNotificationKeepaliveThread push_notification_keepalive_thread.pyo:49 Sent push keepalive message at: Thu Nov 19 09:01:52 2015 2015-11-19 09:01:52,541 -0500 INFO pid=1679 4630650880:FeatureSwitchPoller drive_request.pyo:225 Drive response: Request (None): ListFeatureSwitches(tags=Reason.SYNC_OTHER) Response: (u'enable_impressions_library': u'false., u'enable_multiple_accounts': u'false', u'enable_push': u'true', u'enable_shared_move_confirmation': u'false', u'log_backup_count': u'0 1, u'crash_throttle_percentage': u'99.7', u'perf_throttle_percentage': u'100 1, u'enable_feedback': u'true', u'enable_multipause': u'false', u'enable_usb_detection': u'false', u'max_batch_upload_files': u'30', u'cloud_graph_disk_generation': u'2', u'test.feature_switch.name': u", u'use_drive_api': u'false', u'query_strategy': u'all', u'selective_sub_folder_sync': u'false') 2015-11-19 09:01:52,541 -0500 INFO pid=1679 4545306624:RunAsync-_OnXmppConnect-4 notification_bridge.pyo:142 Starting TICL (client version 3.20130807)... 2015-11-19 09:01:52,543 -0500 INFO pid=1679 4545306624:RunAsync-_OnXmppConnect-4 xmpp_network_channel.pyo: 65 XmppNetworkChannel.InformNetworkStatus: CONNECTED 2015-11-19 09:01:52,544 -0500 INFO pid=1679 4651683840:ListenerScheduler invalidation_listener.pyo:185 InvalidationListener.ReissueRegistrations(prefix=, prefix_len=0) 2015-11-19 09:01:52,760 -0500 INFO pid=1679 4660097024:CloudWatcher cloud_graph.pyo:171 Reuse CloudDiskDict CloudDiskDict(max_change_stamp=74547, app_version=1.25.0523.2491, only_rooted_items=False, ()) 2015-11-19 09:01:52,761 -0500 INFO pid=1679 4660097024:CloudWatcher cloud_watcher.pyo:828 Performing full snapshot diff. 2015-11-19 09:01:52,761 -0500 INFO pid=1679 4660097024:CloudWatcher cloud_watcher.pyo:1026 Getting cloud resources via changelog feed from 74548 2015-11-19 09:01:52,761 -0500 INFO pid=1679 4660097024:CloudWatcher docs_client.pyo:743 Requesting Doc List: /feeds/default/private/changes?start-index=74548&showroot=true&include- shared=true&reason=startup 2015-11-19 09:01:52,762 -0500 INFO pid=1679 4660097024:CloudWatcher sync_http_client.pyo:233 Opening direct connecton to clients3.google.com:443. 2015-11-19 09:01:52,966 -0500 INFO pid=1679 4660097024:CloudWatcher docs_client.pyo:1137 Feed has 2 entries 2015-11-19 09:01:52,967 -0500 INFO pid=1679 4660097024:CloudWatcher docs_client.pyo:1144 End of feed, no next URI 2015-11-19 09:01:52,970 -0500 INFO pid=1679 4660097024:CloudWatcher cloud_watcher.pyo:794 Got 2 cloud entries 2015-11-19 09:01:52,972 -0500 INFO pid=1679 4660097024:CloudWatcher cloud_watcher.pyo:812 647 nodes in the cloud graph 2015-11-19 09:01:53,007 -0500 INFO pid=1679 4660097024:CloudWatcher cloud_snapshot_diff_helper.pyo:84 Prepare for Pruning graph (total of 647 entries). sync EFTA00502241 gdocs=True, sync folders=None, excluded folders=frozenset([)) 2015-11-19 09:01:53,007 -0500 INFO pid=1679 4660097024:CloudWatcher cloud snapshot diff_helper.pyo:85 Start Prune Graph (total of 647 entries) 2015-Y1-19 09:01:53,019 -0500 INFO pid=1679 4660097024:CloudWatcher cloud snapshot diff_helper.pyo:175 Pruning detected 631 items to keep 2015-Y1-19 09:01:53,020 -0500 INFO pid=1679 4660097024:CloudWatcher cloud snapshot diff_helper.pyo:182 631 entries in graph after pruning 2015-Y1-19 09:01:53,020 -0500 INFO pid=1679 4660097024:CloudWatcher cloud snapshot diff_helper.pyo:93 Compare to snaphost 2015-Y1-19 09:01:53,020 -0500 INFO pid=1679 4660097024:CloudWatcher cloud_snapshot_diff_helper.pyo:762 Starting cloud graph vs snapshot set: None 2015-11-19 09:01:53,020 -0500 INFO cloud_snapshot_diff_helper.pyo:764 2015-11-19 09:01:53,022 -0500 INFO cloud_snapshot_diff_helper.pyo:768 2015-11-19 09:01:53,164 -0500 INFO cloud_snapshot_diff_helper.pyo:783 2015-11-19 09:01:53,724 -0500 INFO cloud_snapshot_diff_helper.pyo:810 (_FSChangeActionType(Action.MODIFY) 2015-11-19 09:01:53,796 -0500 INFO Done with full snapshot diff. 2015-11-19 09:01:53,796 -0500 INFO pid=1679 4660097024:CloudWatcher cloud_watcher.pyo:931 CloudWatcher generated 1 events 2015-11-19 09:01:53,796 -0500 INFO pid=1679 4660097024:CloudWatcher cloud_watcher.pyo:937 CloudWatcher generated FSChange(Direction.DOWNLOAD, Action.MODIFY, ino=15178985, name=2015 November2.docx, rid=0BxNN8iEiWGvgb2c3V1htMG11YU0, parent_ino=14390475, is_folder=False, modified=1447928464, checksum=c4c10229d557c28e4dfb9b5d09d5c69f, size=99685, is_cancelled=False, is_priority=False, doc_type=DocType.BLOB) 2015-11-19 09:01:53,796 -0500 INFO pid=1679 4660097024:CloudWatcher aggregator.pyo:108 --- > Received event None FSChange(Direction.DOWNLOAD, Action.MODIFY, ino=15178985, name=2015 November2.docx, rid=0BxNN8iEiWGvgb2c3V1htMG11YU0, parent_ino=14390475, is_folder=False, modified=1447928464, checksum=c4c10229d557c28e4dfb9b5d09d5c69f, size=99685, is_cancelled=False, is_priority=False, doc_type=DocType.BLOB) 2015-11-19 09:01:53,797 -0500 INFO pid=1679 4660097024:CloudWatcher downloads.pyo:126 ProcessDownloadModify (FSChange(Direction.DOWNLOAD, Action.MODIFY, ino=15178985, name=2015 November2.docx, rid=0BxNN8iEiWGvgb2c3V1htMG11YU0, parent_ino=14390475, is_folder=False, modified=1447928464, checksum=c4c10229d557c28e4dfb9b5d09d5c69f, size=99685, is_cancelled=False, is_priority=False, doc_type=DocType.BLOB)) 2015-11-19 09:01:54,033 -0500 INFO pid=1679 4634857472:Worker-2 workers.pyo:180 Worker starting on [ImmutableChange(Direction.D0WNLOAD, Action.MODIFY, ino=15178985, name=2015 November2.docx, rid=0BxNN8iEiWGvgb2c3V1htMG11YU0, parent_ino=14390475, is_folder=False, modified=1447928464, checksum=c4c10229d557c28e4dfb9b5d09d5c69f, size=99685, is_cancelled=False, is_priority=False, doc_type=DocType.BLOB, hash=7462337821110793428, _constructor_called=True)] 2015-11-19 09:01:54,036 -0500 INFO pid=1679 4634857472:Worker-2 download.pyo:139 Downloading https://googledrive.com/p/host/0BxNN8iEiWGvgb2c3V1htMG11YU0 to /var/folders/nl/ypw25pmj06gfyyl_8xnt3kf40000gn/T/tmp_FoXJR 2015-11-19 09:01:54,037 -0500 INFO pid=1679 4634857472:Worker-2 sync_http_client.pyo :233 Opening direct connecton to googledrive. com: 443 . 2015-11-19 09:01:54,523 -0500 INFO pid=1679 4634857472:Worker-2 commands.pyo:58 Updating inode in snapshot. old=15178985, new=15209239 2015-11-19 09:01:54,524 -0500 INFO pid=1679 4634857472:Worker-2 commands.pyo:61 Entry associated with new inode prior to update None: 2015-11-19 09:01:54,524 -0500 INFO pid=1679 4634857472:Worker-2 snapshot_sglite.pyo:552 Removing local relation child_inode=15178985, parent_inode=14390475 2015-11-19 09:01:54,524 -0500 INFO pid=1679 4634857472:Worker-2 snapshot_sglite.pyo:572 Removing Mapping inode=15178985, doc_id=0BxNN8iEiWGvgb2c3V1htMG11YU0 2015-11-19 09:01:54,533 -0500 INFO pid=1679 4639064064:LocalFSPoller poller.pyo:126 Cloud scan complete. Preparing to start LocalFSPoller 2015-11-19 09:01:54,545 -0500 INFO pid=1679 4634857472:Worker-2 snapshot_sglite.pyo:154 Removing local entry inode=15178985 2015-11-19 09:01:54,545 -0500 INFO pid=1679 4634857472:Worker-2 snapshot_sglite.pyo:143 Adding local entry inode=15209239, filename=None diff with selective sync pid=1679 4660097024:CloudWatcher Prepopulating D0C_ID-to-inodes cache pid=1679 4660097024:CloudWatcher First pass detecting moved entries pid=1679 4660097024:CloudWatcher Second pass detecting creations and modification entries pid=1679 4660097024:CloudWatcher Processed 630 entries in total. Number of events detected: : 1) pid=1679 4660097024:CloudWatcher cloud_watcher.pyo:872 EFTA00502242 2015-11-19 09:01:54,546 -0500 INFO pid=1679 4634857472:Worker-2 snapshot_scilite.pyo:542 Adding local relation child_inode=15209239, parent_inode=14390475 2015-11-19 09:01:54,546 -0500 INFO pid=1679 4634857472:Worker-2 snapshot_scilite.pyo:230 Updating local entry inode=15209239, filename=2015 November2.docx, modified=1447882287, checksum=24b505e2c7717c6laa88a70a737980a3, size=63819, is_folder=False 2015-11-19 09:01:54,546 -0500 INFO pid=1679 4634857472:Worker-2 snapshot_scilite.pyo:562 Adding Mapping inode=15209239, doc_id=OBxNN8iEiWGvgb2c3V1htMG11YU0 2015-11-19 09:01:54,546 -0500 INFO pid=1679 4634857472:Worker-2 snapshot_scilite.pyo:230 Updating local entry inode=15209239, modified=1447928464, checksum=c4c10229d557c28e4dfb9b5d09d5c69f, size=99685 2015-11-19 09:01:54,547 -0500 INFO pid=1679 4634857472:Worker-2 snapshot_scilite.pyo:253 Updating cloud entry doc_id=OBxNN8iEiWGvgb2c3V1htMG11YU0, filename=None 2015-11-19 09:01:54,548 -0500 INFO pid=1679 4634857472:Worker-2 workers.pyo:191 Worker successfully completed [ImmutableChange(Direction.DOWNLOAD, Action.MODIFY, ino=15178985, name=2015 November2.docx, rid=OBxNN8iEiWGvgb2c3V1htMG11YUO, parent_ino=14390475, is_folder=False, modified=1447928464, checksum=c4c10229d557c28e4dfb9b5d09d5c69f, size=99685, is_cancelled=False, is_priority=False, doc_type=DocType.BLOB, hash=7462337821110793428, _constructor_called=True)] 2015-11-19 09:01:55,032 -0500 INFO pid=1679 4601204736:Batcher batcher.pyo:240 Current batch is completed. Batcher snooze. 2015-11-19 09:01:55,032 -0500 INFO pid=1679 4601204736:Batcher sync_status.pyo:133 Reset sync status 2015-11-19 09:01:55,032 -0500 INFO pid=1679 4601204736:Batcher batcher.pyo:856 Batcher Stats = file_count = Counter((_ COUNT_ KEY(direction= DownloadDirectionType(Direction. DOWNLOAD), action=_FSChangeActionType(Action.MODIFY), batch=False, successfv1=True): Counter((_ COUNT_ KEY(direction= DownloadDirectionType(Direction. DOWNLOAD), action=_FSChangeActionType(Action.MODIFY), batch=False, successfv1=True): batch_operation_count = Counter(), process_seconds = Counter((_ COUNT_ KEY(direction= DownloadDirectionType(Direction. DOWNLOAD), action=_FSChangeActionType(Action.MODIFY), batch=False, successful=Trve): 0.5147709846496582)), duration seconds = 1 (start_time = 1447941714, end_time = 1447941715) 2015-11-19 09:01:55,033 -0500 INFO pid=1679 4639064064:LocalFSPoller poller.pyo:137 LocalFSPoller first pass started. Waiting for localWatcher to start watching. 2015-11-19 09:01:55,033 -0500 INFO pid=1679 4592791552:LocalWatcher watcher.pyo:240 RootsAdded with roots [_MyDriveRoot(u'/Users/lgroff/Google Drive', 'root')] 2015-11-19 09:01:55,033 -0500 INFO pid=1679 4592791552:LocalWatcher watcher.pyo:243 Scheduling roots: [_MyDriveRoot(u'/Users/lgroff/Google Drive', 'root')] 2015-11-19 09:01:55,033 -0500 INFO pid=1679 4592791552:LocalWatcher watcher.pyo:270 Scheduling root: _MyDriveRoot(u'/Users/lgroff/Google Drive', 'root') 2015-11-19 09:01:55,034 -0500 INFO pid=1679 4592791552:LocalWatcher watcher.pyo:333 LocalWatcher is up. 2015-11-19 09:01:55,034 -0500 INFO pid=1679 4639064064:LocalFSPoller poller.pyo:146 Finished waiting for LocalWatcher. 2015-11-19 09:01:55,035 -0500 INFO pid=1679 4639064064:LocalFSPoller poller.pyo:149 Starting a local disk scan. 2015-11-19 09:01:55,035 -0500 INFO pid=1679 4639064064:LocalFSPoller diff_helper.pyo:86 Walking: [u'/Users/lgroff/Google Drive'] 2015-11-19 09:01:55,145 -0500 INFO pid=1679 4639064064:LocalFSPoller poller.pyo:166 Number of found changes: 0 2015-11-19 09:01:55,146 -0500 INFO pid=1679 4639064064:LocalFSPoller poller.pyo:177 Finished local disk scan. 2015-11-19 09:01:55,238 -0500 INFO pid=1679 4651683840:ListenerScheduler invalidation_listener.pyo:82 InvalidationListener.Invalidation(1014:CHANGELOG, wapi_version=74558) 2015-11-19 09:01:55,238 -0500 INFO pid=1679 4660097024:CloudWatcher cloud_watcher.pyo:700 Change ignored. observed: 74558, retrieved: 74558 2015-11-19 09:01:55,245 -0500 INFO pid=1679 4651683840:ListenerScheduler invalidation_listener.pyo:125 InvalidationListener.InformRegistrationStatus(1014:CHANGELOG, REGISTERED) 2015-11-19 09:01:55,246 -0500 WARNING pid=1679 4651683840:ListenerScheduler notification_bridge.pyo:202 Invalidation status callback called with connected=True 2015-11-19 09:01:55,246 -0500 INFO pid=1679 4651683840:ListenerScheduler telemetry.pyo:165 PushStates.NEGOTIATING: 43.37018 => 3.68876 1)), byte_count = 99685)), EFTA00502243 2015-11-19 09:01:55,246 -0500 INFO pid=1679 4651683840:ListenerScheduler telemetry.pyo:151 Push state PushStates.NEGOTIATING => PushStates.ONLINE 2015-11-19 09:01:55,246 -0500 INFO pid=1679 4651683840:ListenerScheduler pause_manager.pyo:130 Removing pause reason OFFLINE. Paused: False 2015-11-19 09:01:55,246 -0500 ERROR pid=1679 4651683840:ListenerScheduler pause_manager.pyo:438 Tried to get last event time for PauseReason.OFFLINE, but no last event time recorded. 2015-11-19 09:02:23,798 -0500 INFO pid=1679 4660097024:CloudWatcher cloud_watcher.pyo:682 Getting changes: elapsed_time: 30.001064863 2015-11-19 09:02:23,798 -0500 INFO pid=1679 4660097024:CloudWatcher cloud_watcher.pyo:1026 Getting cloud resources via changelog feed from 74559 2015-11-19 09:02:23,798 -0500 INFO pid=1679 4660097024:CloudWatcher docs_client.pyo:743 Requesting Doc List: /feeds/default/private/changes?start-index=74559&showroot=true&include- shared=true&reason=poll 2015-11-19 09:02:23,799 -0500 INFO pid=1679 4660097024:CloudWatcher sync_http_client.pyo:233 Opening direct connecton to clients3.google.com:443. 2015-11-19 09:02:23,977 -0500 INFO pid=1679 4660097024:CloudWatcher docs_client.pyo:1144 End of feed, no next URI 2015-11-19 09:02:23,978 -0500 INFO pid=1679 4660097024:CloudWatcher cloud_watcher.pyo:197 HandleSyncConfigSettingsChange generated events=set([]) 2015-11-19 09:06:10,778 -0500 INFO pid=1679 4559654912:FilewatcherMonitor watcher.pyo:515 PathsCallback called with: [u./Users/lgroff/Google Drive/'] 2015-11-19 09:06:10,779 -0500 INFO pid=1679 4559654912:FilewatcherMonitor diff_helper.pyo:86 Scanning: (u'/Users/lgroff/Google Drive'] 2015-11-19 09:16:51,507 -0500 INFO pid=1679 4613824512:TelemetryStoreSizeMonitorThread telemetry_store_monitor_thread.pyo: 44 Checking Telemetry store size. 2015-11-19 09:31:51,507 -0500 INFO pid=1679 4613824512:TelemetryStoreSizeMonitorThread telemetry_store_monitor_thread.pyo: 44 Checking Telemetry store size. 2015-11-19 09:46:51,500 -0500 INFO pid=1679 4613824512:TelemetryStoreSizeMonitorThread telemetry_store_monitor_thread.pyo: 44 Checking Telemetry store size. 2015-11-19 10:01:48,818 -0500 INFO pid=1679 4541100032:ThreadMonitor thread_manager.pyo:339 Waking up. 2015-11-19 10:01:48,832 -0500 INFO pid=1679 4541100032:ThreadMonitor thread_manager.pyo:336 Waiting on exit condition. Wake up after 3600s. 2015-11-19 10:01:51,443 -0500 INFO pid=1679 4588584960:PauseTelemetryThread pause_telemetry.pyo:184 Collected 0.999978567229h of telemetry at t=1447945311.44, skipping. 2015-11-19 10:01:51,451 -0500 INFO pid=1679 4626444288:PushTelemetryThread telemetry.pyo:165 PushStates.ONLINE: +3596.28 => 3596.28 2015-11-19 10:01:51,451 -0500 INFO pid=1679 4626444288:PushTelemetryThread telemetry.pyo:110 Push telemetry harvest triggered, but only 3600.01055518s elapsed. Skipping. 2015-11-19 10:01:51,510 -0500 INFO pid=1679 4613824512:TelemetryStoreSizeMonitorThread telemetry_store_monitor_thread.pyo: 44 Checking Telemetry store size. 2015-11-19 10:15:24,939 -0500 INFO pid=1679 4651683840:ListenerScheduler invalidation_listener.pyo:82 InvalidationListener.Invalidation(1014:CHANGELOG, wapi_version=74561) 2015-11-19 10:15:24,955 -0500 INFO pid=1679 4660097024:CloudWatcher cloud_watcher.pyo:695 Getting changes; observed: 74561, retrieved: 74558 2015-11-19 10:15:24,986 -0500 INFO pid=1679 4660097024:CloudWatcher cloud_watcher.pyo:1026 Getting cloud resources via changelog feed from 74559 2015-11-19 10:15:24,987 -0500 INFO pid=1679 4660097024:CloudWatcher docs_client.pyo:743 Requesting Doc List: /feeds/default/private/changes?start-index=74559&showroot=true&include- shared=true&reason=change 2015-11-19 10:15:24,994 -0500 INFO pid=1679 4660097024:CloudWatcher proxy_manager.pyo:354 Removing stale proxy entry from cache 2015-11-19 10:15:24,995 -0500 INFO pid=1679 4660097024:CloudWatcher sync_http_client.pyo:233 Opening direct connecton to accounts.google.com:443. 2015-11-19 10:15:25,290 -0500 INFO pid=1679 4660097024:CloudWatcher proxy_manager.pyo:354 Removing stale proxy entry from cache 2015-11-19 10:15:25,290 -0500 INFO pid=1679 4660097024:CloudWatcher sync_http_client.pyo:233 Opening direct connecton to clients3.google.com:443. 2015-11-19 10:15:26,036 -0500 INFO pid=1679 4660097024:CloudWatcher docs_client.pyo:1137 Feed has 1 entries 2015-11-19 10:15:26,036 -0500 INFO pid=1679 4660097024:CloudWatcher docs_client.pyo:1144 End of feed, no next URI 2015-11-19 10:15:26,066 -0500 INFO pid=1679 4660097024:CloudWatcher cloud_watcher.pyo:1370 EFTA00502244 GenerateCreateForDescendents() entry CloudEntry(doc_id=08xNN8iEiWGvgb2c3V1htMG11YUO,filename=2015 November2.docx,modified=1447928464,created=1446753675,acl_role=owner,doc_type=DocType.BLOB,re moved=False,parent_doc_ids=set([ 1 083(NN8iEiWGvgRjcxNnBhRm5nVlk']),child_doc_ids=set([]),size=9 9685,checksum=c4c10229d557c28e4dfb9b5d09d5c69f,change_stamp=74561,server_mod_time=1447946112, is_zombie=False,shared=False,resource_type=file,version=None) parents_added set([]) 2015-11-19 10:15:26,076 -0500 INFO pid=1679 4660097024:CloudWatcher cloud_watcher.pyo:197 HandleSyncConfigSettingsChange generated events=set([]) 2015-11-19 10:16:51,513 -0500 INFO pid=1679 4613824512:TelemetryStoreSizeMonitorThread telemetry_store monitor_thread.pyo:44 Checking Telemetry store size. 2015-11-19 10:22:51,819 -0500 WARNING pid=1679 4584378368:XmppClient xmpplib.pyo:254 Flush failed with <class 'socket.error'>: (Errno 32] Broken pipe 2015-11-19 10:22:51,820 -0500 ERROR pid=1679 4584378368:XmppClient fatal_exceptions.pyo:55 Ignoring non-fatal error: error: (Errno 22] Invalid argument, Traceback: File "common/push/xmpp/connection_task.pyo", line 143, in HandleKeepaliveTimer File "contextlib.pyo", line 24, in exit File "common/push/xmpp/xmpplib.pyo", line 119, in ShrinkBuffer File "socket.pyo", line 228, in meth EFTA00502245