Created
September 11, 2015 20:43
-
-
Save yujikiriki/eda8e3313d98d9207550 to your computer and use it in GitHub Desktop.
aurora-scheduler.log
This file contains bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
| Sep 11, 2015 3:35:37 PM com.twitter.common.args.apt.Configuration load | |
| INFO: Loading @CmdLine config from: [jar:file:/home/yuji/git/aurora/dist/distributions/aurora-scheduler-0.9.0/lib/client-flagged-0.0.5.jar!/com/twitter/common/args/apt/cmdline.arg.info.txt.1, jar:file:/home/yuji/git/aurora/dist/distributions/aurora-scheduler-0.9.0/lib/server-set-1.0.74.jar!/com/twitter/common/args/apt/cmdline.arg.info.txt.1, jar:file:/home/yuji/git/aurora/dist/distributions/aurora-scheduler-0.9.0/lib/application-module-stats-0.0.44.jar!/com/twitter/common/args/apt/cmdline.arg.info.txt.1, jar:file:/home/yuji/git/aurora/dist/distributions/aurora-scheduler-0.9.0/lib/application-0.0.73.jar!/com/twitter/common/args/apt/cmdline.arg.info.txt.1, jar:file:/home/yuji/git/aurora/dist/distributions/aurora-scheduler-0.9.0/lib/args-0.2.9.jar!/com/twitter/common/args/apt/cmdline.arg.info.txt.1, jar:file:/home/yuji/git/aurora/dist/distributions/aurora-scheduler-0.9.0/lib/logging-0.0.61.jar!/com/twitter/common/args/apt/cmdline.arg.info.txt.1, jar:file:/home/yuji/git/aurora/dist/distributions/aurora-scheduler-0.9.0/lib/aurora-0.9.0.jar!/com/twitter/common/args/apt/cmdline.arg.info.txt.2] | |
| Sep 11, 2015 3:35:37 PM com.twitter.common.args.ArgScanner getNoCollisions | |
| WARNING: Found argument name collisions, args must be referenced by canonical names: [slow_query_log_threshold] | |
| Sep 11, 2015 3:35:38 PM com.twitter.common.args.ArgScanner process | |
| INFO: ------------------------------------------------------------------------- | |
| Sep 11, 2015 3:35:38 PM com.twitter.common.args.ArgScanner process | |
| INFO: Command line argument values | |
| Sep 11, 2015 3:35:38 PM com.twitter.common.args.ArgScanner process | |
| INFO: allowed_container_types (org.apache.aurora.scheduler.configuration.ConfigurationManager.allowed_container_types): [MESOS] | |
| Sep 11, 2015 3:35:38 PM com.twitter.common.args.ArgScanner process | |
| INFO: alsologtostderr (com.twitter.common.logging.RootLogConfig.alsologtostderr): false | |
| Sep 11, 2015 3:35:38 PM com.twitter.common.args.ArgScanner process | |
| INFO: async_slot_stat_update_interval (org.apache.aurora.scheduler.stats.AsyncStatsModule.async_slot_stat_update_interval): (1, mins) | |
| Sep 11, 2015 3:35:38 PM com.twitter.common.args.ArgScanner process | |
| INFO: async_task_stat_update_interval (org.apache.aurora.scheduler.stats.AsyncStatsModule.async_task_stat_update_interval): (1, hrs) | |
| Sep 11, 2015 3:35:38 PM com.twitter.common.args.ArgScanner process | |
| INFO: async_worker_threads (org.apache.aurora.scheduler.async.AsyncModule.async_worker_threads): 1 | |
| Sep 11, 2015 3:35:38 PM com.twitter.common.args.ArgScanner process | |
| INFO: auth_module (org.apache.aurora.scheduler.thrift.auth.ThriftAuthModule.auth_module): org.apache.aurora.auth.UnsecureAuthModule@3ba9ad43 | |
| Sep 11, 2015 3:35:38 PM com.twitter.common.args.ArgScanner process | |
| INFO: backup_dir (org.apache.aurora.scheduler.storage.backup.BackupModule.backup_dir): /home/yuji/git/aurora/dist/distributions/aurora-scheduler-0.9.0/backups | |
| Sep 11, 2015 3:35:38 PM com.twitter.common.args.ArgScanner process | |
| INFO: backup_interval (org.apache.aurora.scheduler.storage.backup.BackupModule.backup_interval): (1, hrs) | |
| Sep 11, 2015 3:35:38 PM com.twitter.common.args.ArgScanner process | |
| INFO: cluster_name (org.apache.aurora.scheduler.app.SchedulerMain.cluster_name): us-east | |
| Sep 11, 2015 3:35:38 PM com.twitter.common.args.ArgScanner process | |
| INFO: cron_scheduler_num_threads (org.apache.aurora.scheduler.cron.quartz.CronModule.cron_scheduler_num_threads): 100 | |
| Sep 11, 2015 3:35:38 PM com.twitter.common.args.ArgScanner process | |
| INFO: cron_start_initial_backoff (org.apache.aurora.scheduler.cron.quartz.CronModule.cron_start_initial_backoff): (1, secs) | |
| Sep 11, 2015 3:35:38 PM com.twitter.common.args.ArgScanner process | |
| INFO: cron_start_max_backoff (org.apache.aurora.scheduler.cron.quartz.CronModule.cron_start_max_backoff): (1, mins) | |
| Sep 11, 2015 3:35:38 PM com.twitter.common.args.ArgScanner process | |
| INFO: cron_timezone (org.apache.aurora.scheduler.cron.quartz.CronModule.cron_timezone): GMT | |
| Sep 11, 2015 3:35:38 PM com.twitter.common.args.ArgScanner process | |
| INFO: db_row_gc_interval (org.apache.aurora.scheduler.storage.db.DbModule.db_row_gc_interval): (2, hrs) | |
| Sep 11, 2015 3:35:38 PM com.twitter.common.args.ArgScanner process | |
| INFO: deduplicate_snapshots (org.apache.aurora.scheduler.storage.log.LogStorageModule.deduplicate_snapshots): false | |
| Sep 11, 2015 3:35:38 PM com.twitter.common.args.ArgScanner process | |
| INFO: deflate_snapshots (org.apache.aurora.scheduler.storage.log.LogStorageModule.deflate_snapshots): true | |
| Sep 11, 2015 3:35:38 PM com.twitter.common.args.ArgScanner process | |
| INFO: dlog_max_entry_size (org.apache.aurora.scheduler.storage.log.LogStorageModule.dlog_max_entry_size): (512, KB) | |
| Sep 11, 2015 3:35:38 PM com.twitter.common.args.ArgScanner process | |
| INFO: dlog_shutdown_grace_period (org.apache.aurora.scheduler.storage.log.LogStorageModule.dlog_shutdown_grace_period): (2, secs) | |
| Sep 11, 2015 3:35:38 PM com.twitter.common.args.ArgScanner process | |
| INFO: dlog_snapshot_interval (org.apache.aurora.scheduler.storage.log.LogStorageModule.dlog_snapshot_interval): (1, hrs) | |
| Sep 11, 2015 3:35:38 PM com.twitter.common.args.ArgScanner process | |
| INFO: enable_cors_for (org.apache.aurora.scheduler.http.api.ApiModule.enable_cors_for): * | |
| Sep 11, 2015 3:35:38 PM com.twitter.common.args.ArgScanner process | |
| INFO: enable_cors_support (org.apache.aurora.scheduler.http.api.ApiModule.enable_cors_support): false | |
| Sep 11, 2015 3:35:38 PM com.twitter.common.args.ArgScanner process | |
| INFO: enable_h2_console (org.apache.aurora.scheduler.http.H2ConsoleModule.enable_h2_console): false | |
| Sep 11, 2015 3:35:38 PM com.twitter.common.args.ArgScanner process | |
| INFO: enable_job_creation (org.apache.aurora.scheduler.thrift.aop.AopModule.enable_job_creation): true | |
| Sep 11, 2015 3:35:38 PM com.twitter.common.args.ArgScanner process | |
| INFO: enable_job_updates (org.apache.aurora.scheduler.thrift.aop.AopModule.enable_job_updates): true | |
| Sep 11, 2015 3:35:38 PM com.twitter.common.args.ArgScanner process | |
| INFO: enable_preemptor (org.apache.aurora.scheduler.async.preemptor.PreemptorModule.enable_preemptor): true | |
| Sep 11, 2015 3:35:38 PM com.twitter.common.args.ArgScanner process | |
| INFO: executor_user (org.apache.aurora.scheduler.mesos.CommandLineDriverSettingsModule.executor_user): root | |
| Sep 11, 2015 3:35:38 PM com.twitter.common.args.ArgScanner process | |
| INFO: extra_modules (org.apache.aurora.scheduler.app.SchedulerMain.extra_modules): [] | |
| Sep 11, 2015 3:35:38 PM com.twitter.common.args.ArgScanner process | |
| INFO: first_schedule_delay (org.apache.aurora.scheduler.async.AsyncModule.first_schedule_delay): (1, ms) | |
| Sep 11, 2015 3:35:38 PM com.twitter.common.args.ArgScanner process | |
| INFO: flapping_task_threshold (org.apache.aurora.scheduler.async.AsyncModule.flapping_task_threshold): (5, mins) | |
| Sep 11, 2015 3:35:38 PM com.twitter.common.args.ArgScanner process | |
| INFO: framework_authentication_file (org.apache.aurora.scheduler.mesos.CommandLineDriverSettingsModule.framework_authentication_file): null | |
| Sep 11, 2015 3:35:38 PM com.twitter.common.args.ArgScanner process | |
| INFO: framework_failover_timeout (org.apache.aurora.scheduler.mesos.CommandLineDriverSettingsModule.framework_failover_timeout): (21, days) | |
| Sep 11, 2015 3:35:38 PM com.twitter.common.args.ArgScanner process | |
| INFO: global_container_mounts (org.apache.aurora.scheduler.app.SchedulerMain.global_container_mounts): [] | |
| Sep 11, 2015 3:35:38 PM com.twitter.common.args.ArgScanner process | |
| INFO: guice_stage (com.twitter.common.application.AppLauncher.guice_stage): DEVELOPMENT | |
| Sep 11, 2015 3:35:38 PM com.twitter.common.args.ArgScanner process | |
| INFO: history_max_per_job_threshold (org.apache.aurora.scheduler.async.AsyncModule.history_max_per_job_threshold): 100 | |
| Sep 11, 2015 3:35:38 PM com.twitter.common.args.ArgScanner process | |
| INFO: history_min_retention_threshold (org.apache.aurora.scheduler.async.AsyncModule.history_min_retention_threshold): (1, hrs) | |
| Sep 11, 2015 3:35:38 PM com.twitter.common.args.ArgScanner process | |
| INFO: history_prune_threshold (org.apache.aurora.scheduler.async.AsyncModule.history_prune_threshold): (2, days) | |
| Sep 11, 2015 3:35:38 PM com.twitter.common.args.ArgScanner process | |
| INFO: hostname (org.apache.aurora.scheduler.http.JettyServerModule.hostname): null | |
| Sep 11, 2015 3:35:38 PM com.twitter.common.args.ArgScanner process | |
| INFO: http_authentication_mechanism (org.apache.aurora.scheduler.http.api.security.HttpSecurityModule.http_authentication_mechanism): NONE | |
| Sep 11, 2015 3:35:38 PM com.twitter.common.args.ArgScanner process | |
| INFO: http_port (org.apache.aurora.scheduler.http.JettyServerModule.http_port): 8081 | |
| Sep 11, 2015 3:35:38 PM com.twitter.common.args.ArgScanner process | |
| INFO: initial_flapping_task_delay (org.apache.aurora.scheduler.async.AsyncModule.initial_flapping_task_delay): (30, secs) | |
| Sep 11, 2015 3:35:38 PM com.twitter.common.args.ArgScanner process | |
| INFO: initial_schedule_penalty (org.apache.aurora.scheduler.async.AsyncModule.initial_schedule_penalty): (1, secs) | |
| Sep 11, 2015 3:35:38 PM com.twitter.common.args.ArgScanner process | |
| INFO: initial_task_kill_retry_interval (org.apache.aurora.scheduler.async.AsyncModule.initial_task_kill_retry_interval): (5, secs) | |
| Sep 11, 2015 3:35:38 PM com.twitter.common.args.ArgScanner process | |
| INFO: job_update_history_per_job_threshold (org.apache.aurora.scheduler.async.AsyncModule.job_update_history_per_job_threshold): 10 | |
| Sep 11, 2015 3:35:38 PM com.twitter.common.args.ArgScanner process | |
| INFO: job_update_history_pruning_interval (org.apache.aurora.scheduler.async.AsyncModule.job_update_history_pruning_interval): (15, mins) | |
| Sep 11, 2015 3:35:38 PM com.twitter.common.args.ArgScanner process | |
| INFO: job_update_history_pruning_threshold (org.apache.aurora.scheduler.async.AsyncModule.job_update_history_pruning_threshold): (30, days) | |
| Sep 11, 2015 3:35:38 PM com.twitter.common.args.ArgScanner process | |
| INFO: kerberos_debug (org.apache.aurora.scheduler.http.api.security.Kerberos5ShiroRealmModule.kerberos_debug): false | |
| Sep 11, 2015 3:35:38 PM com.twitter.common.args.ArgScanner process | |
| INFO: kerberos_server_keytab (org.apache.aurora.scheduler.http.api.security.Kerberos5ShiroRealmModule.kerberos_server_keytab): null | |
| Sep 11, 2015 3:35:38 PM com.twitter.common.args.ArgScanner process | |
| INFO: kerberos_server_principal (org.apache.aurora.scheduler.http.api.security.Kerberos5ShiroRealmModule.kerberos_server_principal): null | |
| Sep 11, 2015 3:35:38 PM com.twitter.common.args.ArgScanner process | |
| INFO: logtostderr (com.twitter.common.logging.RootLogConfig.logtostderr): true | |
| Sep 11, 2015 3:35:38 PM com.twitter.common.args.ArgScanner process | |
| INFO: max_async_event_bus_threads (org.apache.aurora.scheduler.events.PubsubEventModule.max_async_event_bus_threads): 4 | |
| Sep 11, 2015 3:35:38 PM com.twitter.common.args.ArgScanner process | |
| INFO: max_flapping_task_delay (org.apache.aurora.scheduler.async.AsyncModule.max_flapping_task_delay): (5, mins) | |
| Sep 11, 2015 3:35:38 PM com.twitter.common.args.ArgScanner process | |
| INFO: max_leading_duration (org.apache.aurora.scheduler.SchedulerModule.max_leading_duration): (1, days) | |
| Sep 11, 2015 3:35:38 PM com.twitter.common.args.ArgScanner process | |
| INFO: max_registration_delay (org.apache.aurora.scheduler.SchedulerModule.max_registration_delay): (1, mins) | |
| Sep 11, 2015 3:35:38 PM com.twitter.common.args.ArgScanner process | |
| INFO: max_reschedule_task_delay_on_startup (org.apache.aurora.scheduler.async.AsyncModule.max_reschedule_task_delay_on_startup): (30, secs) | |
| Sep 11, 2015 3:35:38 PM com.twitter.common.args.ArgScanner process | |
| INFO: max_saved_backups (org.apache.aurora.scheduler.storage.backup.BackupModule.max_saved_backups): 48 | |
| Sep 11, 2015 3:35:38 PM com.twitter.common.args.ArgScanner process | |
| INFO: max_schedule_attempts_per_sec (org.apache.aurora.scheduler.async.AsyncModule.max_schedule_attempts_per_sec): 40.0 | |
| Sep 11, 2015 3:35:38 PM com.twitter.common.args.ArgScanner process | |
| INFO: max_schedule_penalty (org.apache.aurora.scheduler.async.AsyncModule.max_schedule_penalty): (1, mins) | |
| Sep 11, 2015 3:35:38 PM com.twitter.common.args.ArgScanner process | |
| INFO: max_status_update_batch_size (org.apache.aurora.scheduler.SchedulerModule.max_status_update_batch_size): 1000 | |
| Sep 11, 2015 3:35:38 PM com.twitter.common.args.ArgScanner process | |
| INFO: max_tasks_per_job (org.apache.aurora.scheduler.thrift.SchedulerThriftInterface.max_tasks_per_job): 4000 | |
| Sep 11, 2015 3:35:38 PM com.twitter.common.args.ArgScanner process | |
| INFO: max_update_instance_failures (org.apache.aurora.scheduler.thrift.SchedulerThriftInterface.max_update_instance_failures): 20000 | |
| Sep 11, 2015 3:35:38 PM com.twitter.common.args.ArgScanner process | |
| INFO: mesos_master_address (org.apache.aurora.scheduler.mesos.CommandLineDriverSettingsModule.mesos_master_address): zk://127.0.0.1:2181/mesos/master | |
| Sep 11, 2015 3:35:38 PM com.twitter.common.args.ArgScanner process | |
| INFO: min_offer_hold_time (org.apache.aurora.scheduler.async.AsyncModule.min_offer_hold_time): (5, mins) | |
| Sep 11, 2015 3:35:38 PM com.twitter.common.args.ArgScanner process | |
| INFO: native_log_election_retries (org.apache.aurora.scheduler.log.mesos.MesosLogStreamModule.native_log_election_retries): 20 | |
| Sep 11, 2015 3:35:38 PM com.twitter.common.args.ArgScanner process | |
| INFO: native_log_election_timeout (org.apache.aurora.scheduler.log.mesos.MesosLogStreamModule.native_log_election_timeout): (15, secs) | |
| Sep 11, 2015 3:35:38 PM com.twitter.common.args.ArgScanner process | |
| INFO: native_log_file_path (org.apache.aurora.scheduler.log.mesos.MesosLogStreamModule.native_log_file_path): /home/yuji/git/aurora/dist/distributions/aurora-scheduler-0.9.0/db | |
| Sep 11, 2015 3:35:38 PM com.twitter.common.args.ArgScanner process | |
| INFO: native_log_quorum_size (org.apache.aurora.scheduler.log.mesos.MesosLogStreamModule.native_log_quorum_size): 1 | |
| Sep 11, 2015 3:35:38 PM com.twitter.common.args.ArgScanner process | |
| INFO: native_log_read_timeout (org.apache.aurora.scheduler.log.mesos.MesosLogStreamModule.native_log_read_timeout): (5, secs) | |
| Sep 11, 2015 3:35:38 PM com.twitter.common.args.ArgScanner process | |
| INFO: native_log_write_timeout (org.apache.aurora.scheduler.log.mesos.MesosLogStreamModule.native_log_write_timeout): (3, secs) | |
| Sep 11, 2015 3:35:38 PM com.twitter.common.args.ArgScanner process | |
| INFO: native_log_zk_group_path (org.apache.aurora.scheduler.log.mesos.MesosLogStreamModule.native_log_zk_group_path): /aurora/replicated-log | |
| Sep 11, 2015 3:35:38 PM com.twitter.common.args.ArgScanner process | |
| INFO: offer_hold_jitter_window (org.apache.aurora.scheduler.async.AsyncModule.offer_hold_jitter_window): (1, mins) | |
| Sep 11, 2015 3:35:38 PM com.twitter.common.args.ArgScanner process | |
| INFO: offer_reservation_duration (org.apache.aurora.scheduler.async.AsyncModule.offer_reservation_duration): (3, mins) | |
| Sep 11, 2015 3:35:38 PM com.twitter.common.args.ArgScanner process | |
| INFO: preemption_delay (org.apache.aurora.scheduler.async.preemptor.PreemptorModule.preemption_delay): (3, mins) | |
| Sep 11, 2015 3:35:38 PM com.twitter.common.args.ArgScanner process | |
| INFO: preemption_slot_hold_time (org.apache.aurora.scheduler.async.preemptor.PreemptorModule.preemption_slot_hold_time): (5, mins) | |
| Sep 11, 2015 3:35:38 PM com.twitter.common.args.ArgScanner process | |
| INFO: preemption_slot_search_interval (org.apache.aurora.scheduler.async.preemptor.PreemptorModule.preemption_slot_search_interval): (1, mins) | |
| Sep 11, 2015 3:35:38 PM com.twitter.common.args.ArgScanner process | |
| INFO: reconciliation_explicit_interval (org.apache.aurora.scheduler.async.AsyncModule.reconciliation_explicit_interval): (60, mins) | |
| Sep 11, 2015 3:35:38 PM com.twitter.common.args.ArgScanner process | |
| INFO: reconciliation_implicit_interval (org.apache.aurora.scheduler.async.AsyncModule.reconciliation_implicit_interval): (60, mins) | |
| Sep 11, 2015 3:35:38 PM com.twitter.common.args.ArgScanner process | |
| INFO: reconciliation_initial_delay (org.apache.aurora.scheduler.async.AsyncModule.reconciliation_initial_delay): (1, mins) | |
| Sep 11, 2015 3:35:38 PM com.twitter.common.args.ArgScanner process | |
| INFO: reconciliation_schedule_spread (org.apache.aurora.scheduler.async.AsyncModule.reconciliation_schedule_spread): (30, mins) | |
| Sep 11, 2015 3:35:38 PM com.twitter.common.args.ArgScanner process | |
| INFO: serverset_encode_json (com.twitter.common.zookeeper.ServerSetImpl.serverset_encode_json): true | |
| Sep 11, 2015 3:35:38 PM com.twitter.common.args.ArgScanner process | |
| INFO: serverset_path (org.apache.aurora.scheduler.app.SchedulerMain.serverset_path): /aurora/scheduler | |
| Sep 11, 2015 3:35:38 PM com.twitter.common.args.ArgScanner process | |
| INFO: shiro_ini_path (org.apache.aurora.scheduler.http.api.security.IniShiroRealmModule.shiro_ini_path): null | |
| Sep 11, 2015 3:35:38 PM com.twitter.common.args.ArgScanner process | |
| INFO: shiro_realm_modules (org.apache.aurora.scheduler.http.api.security.HttpSecurityModule.shiro_realm_modules): [org.apache.aurora.scheduler.app.Modules$2@be64738] | |
| Sep 11, 2015 3:35:38 PM com.twitter.common.args.ArgScanner process | |
| INFO: sla_non_prod_metrics (org.apache.aurora.scheduler.sla.SlaModule.sla_non_prod_metrics): [] | |
| Sep 11, 2015 3:35:38 PM com.twitter.common.args.ArgScanner process | |
| INFO: sla_prod_metrics (org.apache.aurora.scheduler.sla.SlaModule.sla_prod_metrics): [JOB_UPTIMES, PLATFORM_UPTIME, MEDIANS] | |
| Sep 11, 2015 3:35:38 PM com.twitter.common.args.ArgScanner process | |
| INFO: sla_stat_refresh_interval (org.apache.aurora.scheduler.sla.SlaModule.sla_stat_refresh_interval): (1, mins) | |
| Sep 11, 2015 3:35:38 PM com.twitter.common.args.ArgScanner process | |
| INFO: slow_query_log_threshold (org.apache.aurora.scheduler.storage.db.DbModule.slow_query_log_threshold): (25, ms) | |
| Sep 11, 2015 3:35:38 PM com.twitter.common.args.ArgScanner process | |
| INFO: slow_query_log_threshold (org.apache.aurora.scheduler.storage.mem.MemTaskStore.slow_query_log_threshold): (25, ms) | |
| Sep 11, 2015 3:35:38 PM com.twitter.common.args.ArgScanner process | |
| INFO: stat_retention_period (com.twitter.common.application.modules.StatsModule.stat_retention_period): (1, hrs) | |
| Sep 11, 2015 3:35:38 PM com.twitter.common.args.ArgScanner process | |
| INFO: stat_sampling_interval (com.twitter.common.application.modules.StatsModule.stat_sampling_interval): (1, secs) | |
| Sep 11, 2015 3:35:38 PM com.twitter.common.args.ArgScanner process | |
| INFO: thermos_executor_cpu (org.apache.aurora.scheduler.app.SchedulerMain.thermos_executor_cpu): 0.25 | |
| Sep 11, 2015 3:35:38 PM com.twitter.common.args.ArgScanner process | |
| INFO: thermos_executor_flags (org.apache.aurora.scheduler.app.SchedulerMain.thermos_executor_flags): null | |
| Sep 11, 2015 3:35:38 PM com.twitter.common.args.ArgScanner process | |
| INFO: thermos_executor_path (org.apache.aurora.scheduler.app.SchedulerMain.thermos_executor_path): /dev/null | |
| Sep 11, 2015 3:35:38 PM com.twitter.common.args.ArgScanner process | |
| INFO: thermos_executor_ram (org.apache.aurora.scheduler.app.SchedulerMain.thermos_executor_ram): (512, MB) | |
| Sep 11, 2015 3:35:38 PM com.twitter.common.args.ArgScanner process | |
| INFO: thermos_executor_resources (org.apache.aurora.scheduler.app.SchedulerMain.thermos_executor_resources): [] | |
| Sep 11, 2015 3:35:38 PM com.twitter.common.args.ArgScanner process | |
| INFO: thermos_observer_root (org.apache.aurora.scheduler.app.SchedulerMain.thermos_observer_root): /var/run/thermos | |
| Sep 11, 2015 3:35:38 PM com.twitter.common.args.ArgScanner process | |
| INFO: transient_task_state_timeout (org.apache.aurora.scheduler.async.AsyncModule.transient_task_state_timeout): (5, mins) | |
| Sep 11, 2015 3:35:38 PM com.twitter.common.args.ArgScanner process | |
| INFO: use_beta_db_task_store (org.apache.aurora.scheduler.storage.db.DbModule.use_beta_db_task_store): false | |
| Sep 11, 2015 3:35:38 PM com.twitter.common.args.ArgScanner process | |
| INFO: use_glog_formatter (com.twitter.common.logging.RootLogConfig.use_glog_formatter): true | |
| Sep 11, 2015 3:35:38 PM com.twitter.common.args.ArgScanner process | |
| INFO: user_capabilities (org.apache.aurora.scheduler.thrift.auth.ThriftAuthModule.user_capabilities): {ROOT=mesos} | |
| Sep 11, 2015 3:35:38 PM com.twitter.common.args.ArgScanner process | |
| INFO: viz_job_url_prefix (org.apache.aurora.scheduler.app.SchedulerMain.viz_job_url_prefix): | |
| Sep 11, 2015 3:35:38 PM com.twitter.common.args.ArgScanner process | |
| INFO: vlog (com.twitter.common.logging.RootLogConfig.vlog): INFO | |
| Sep 11, 2015 3:35:38 PM com.twitter.common.args.ArgScanner process | |
| INFO: vmodule (com.twitter.common.logging.RootLogConfig.vmodule): {} | |
| Sep 11, 2015 3:35:38 PM com.twitter.common.args.ArgScanner process | |
| INFO: zk_chroot_path (com.twitter.common.zookeeper.guice.client.flagged.FlaggedClientConfig.zk_chroot_path): null | |
| Sep 11, 2015 3:35:38 PM com.twitter.common.args.ArgScanner process | |
| INFO: zk_digest_credentials (com.twitter.common.zookeeper.guice.client.flagged.FlaggedClientConfig.zk_digest_credentials): null | |
| Sep 11, 2015 3:35:38 PM com.twitter.common.args.ArgScanner process | |
| INFO: zk_endpoints (com.twitter.common.zookeeper.guice.client.flagged.FlaggedClientConfig.zk_endpoints): [127.0.0.1:2181] | |
| Sep 11, 2015 3:35:38 PM com.twitter.common.args.ArgScanner process | |
| INFO: zk_in_proc (com.twitter.common.zookeeper.guice.client.flagged.FlaggedClientConfig.zk_in_proc): false | |
| Sep 11, 2015 3:35:38 PM com.twitter.common.args.ArgScanner process | |
| INFO: zk_session_timeout (com.twitter.common.zookeeper.guice.client.flagged.FlaggedClientConfig.zk_session_timeout): (4, secs) | |
| Sep 11, 2015 3:35:38 PM com.twitter.common.args.ArgScanner process | |
| INFO: ------------------------------------------------------------------------- | |
| Sep 11, 2015 3:35:38 PM org.apache.aurora.scheduler.async.preemptor.PreemptorModule$1 configure | |
| INFO: Preemptor Enabled. | |
| Sep 11, 2015 3:35:38 PM com.google.inject.internal.ProxyFactory <init> | |
| WARNING: Method [public java.lang.Iterable org.apache.aurora.scheduler.storage.mem.MemTaskStore.fetchTasks(org.apache.aurora.scheduler.base.Query$Builder)] is synthetic and is being intercepted by [com.twitter.common.inject.TimedInterceptor@758705fa]. This could indicate a bug. The method may be intercepted twice, or may not be intercepted at all. | |
| Sep 11, 2015 3:35:38 PM com.google.inject.internal.ProxyFactory <init> | |
| WARNING: Method [public java.lang.Object org.apache.aurora.scheduler.storage.log.SnapshotStoreImpl.createSnapshot()] is synthetic and is being intercepted by [com.twitter.common.inject.TimedInterceptor@758705fa]. This could indicate a bug. The method may be intercepted twice, or may not be intercepted at all. | |
| Sep 11, 2015 3:35:38 PM com.google.inject.internal.ProxyFactory <init> | |
| WARNING: Method [public void org.apache.aurora.scheduler.storage.log.SnapshotStoreImpl.applySnapshot(java.lang.Object)] is synthetic and is being intercepted by [com.twitter.common.inject.TimedInterceptor@758705fa]. This could indicate a bug. The method may be intercepted twice, or may not be intercepted at all. | |
| Sep 11, 2015 3:35:38 PM org.quartz.impl.StdSchedulerFactory instantiate | |
| INFO: Using default implementation for ThreadExecutor | |
| Sep 11, 2015 3:35:38 PM org.quartz.core.SchedulerSignalerImpl <init> | |
| INFO: Initialized Scheduler Signaller of type: class org.quartz.core.SchedulerSignalerImpl | |
| Sep 11, 2015 3:35:38 PM org.quartz.core.QuartzScheduler <init> | |
| INFO: Quartz Scheduler v.2.2.1 created. | |
| Sep 11, 2015 3:35:38 PM org.quartz.simpl.RAMJobStore initialize | |
| INFO: RAMJobStore initialized. | |
| Sep 11, 2015 3:35:38 PM org.quartz.core.QuartzScheduler initialize | |
| INFO: Scheduler meta-data: Quartz Scheduler (v2.2.1) 'QuartzScheduler' with instanceId 'aurora-cron-1' | |
| Scheduler class: 'org.quartz.core.QuartzScheduler' - running locally. | |
| NOT STARTED. | |
| Currently in standby mode. | |
| Number of jobs executed: 0 | |
| Using thread pool 'org.quartz.simpl.SimpleThreadPool' - with 100 threads. | |
| Using job-store 'org.quartz.simpl.RAMJobStore' - which does not support persistence. and is not clustered. | |
| Sep 11, 2015 3:35:38 PM org.quartz.impl.StdSchedulerFactory instantiate | |
| INFO: Quartz scheduler 'QuartzScheduler' initialized from an externally provided properties instance. | |
| Sep 11, 2015 3:35:38 PM org.quartz.impl.StdSchedulerFactory instantiate | |
| INFO: Quartz scheduler version: 2.2.1 | |
| Sep 11, 2015 3:35:38 PM org.quartz.core.QuartzScheduler setJobFactory | |
| INFO: JobFactory set to: org.apache.aurora.scheduler.cron.quartz.AuroraCronJobFactory@3113a37 | |
| Sep 11, 2015 3:35:38 PM org.apache.aurora.scheduler.cron.quartz.CronModule provideTimeZone | |
| WARNING: Cron schedules are configured to fire according to timezone Greenwich Mean Time but system timezone is set to Colombia Time | |
| Sep 11, 2015 3:35:38 PM org.apache.aurora.scheduler.app.AppModule provideAcls | |
| WARNING: Running without ZooKeeper digest credentials. ZooKeeper ACLs are disabled. | |
| Sep 11, 2015 3:35:38 PM com.twitter.common.application.AppLauncher run | |
| INFO: Executing startup actions. | |
| Sep 11, 2015 3:35:38 PM com.twitter.common.util.BuildInfo fetchProperties | |
| INFO: Fetching build properties from build.properties | |
| Sep 11, 2015 3:35:38 PM com.twitter.common.util.BuildInfo fetchProperties | |
| WARNING: Failed to fetch build properties from build.properties | |
| Sep 11, 2015 3:35:38 PM com.twitter.common.application.modules.StatsModule$StartStatPoller execute | |
| INFO: Build information: {} | |
| log4j:WARN No appenders could be found for logger (org.apache.zookeeper.ZooKeeper). | |
| log4j:WARN Please initialize the log4j system properly. | |
| log4j:WARN See http://logging.apache.org/log4j/1.2/faq.html#noconfig for more info. | |
| Sep 11, 2015 3:35:38 PM org.eclipse.jetty.server.Server doStart | |
| INFO: jetty-7.6.15.v20140411 | |
| Sep 11, 2015 3:35:39 PM com.twitter.common.zookeeper.ServerSetImpl$ServerSetWatcher notifyServerSetChange | |
| WARNING: server set empty for path /aurora/scheduler | |
| Sep 11, 2015 3:35:39 PM org.apache.aurora.scheduler.http.LeaderRedirect$SchedulerMonitor onChange | |
| WARNING: No schedulers in host set, will not redirect despite not being leader. | |
| Sep 11, 2015 3:35:39 PM org.apache.aurora.auth.UnsecureAuthModule configure | |
| INFO: Using default (UNSECURE!!!) authentication module. | |
| Sep 11, 2015 3:35:39 PM org.eclipse.jetty.server.handler.ContextHandler startContext | |
| INFO: started o.e.j.s.ServletContextHandler{/,null} | |
| Sep 11, 2015 3:35:39 PM com.sun.jersey.guice.spi.container.GuiceComponentProviderFactory register | |
| INFO: Registering org.apache.aurora.scheduler.http.api.ApiBeta as a root resource class | |
| Sep 11, 2015 3:35:39 PM com.sun.jersey.guice.spi.container.GuiceComponentProviderFactory register | |
| INFO: Registering org.apache.aurora.scheduler.http.Cron as a root resource class | |
| Sep 11, 2015 3:35:39 PM com.sun.jersey.guice.spi.container.GuiceComponentProviderFactory register | |
| INFO: Registering org.apache.aurora.scheduler.http.Locks as a root resource class | |
| Sep 11, 2015 3:35:39 PM com.sun.jersey.guice.spi.container.GuiceComponentProviderFactory register | |
| INFO: Registering org.apache.aurora.scheduler.http.Maintenance as a root resource class | |
| Sep 11, 2015 3:35:39 PM com.sun.jersey.guice.spi.container.GuiceComponentProviderFactory register | |
| INFO: Registering org.apache.aurora.scheduler.http.Mname as a root resource class | |
| Sep 11, 2015 3:35:39 PM com.sun.jersey.guice.spi.container.GuiceComponentProviderFactory register | |
| INFO: Registering org.apache.aurora.scheduler.http.Offers as a root resource class | |
| Sep 11, 2015 3:35:39 PM com.sun.jersey.guice.spi.container.GuiceComponentProviderFactory register | |
| INFO: Registering org.apache.aurora.scheduler.http.PendingTasks as a root resource class | |
| Sep 11, 2015 3:35:39 PM com.sun.jersey.guice.spi.container.GuiceComponentProviderFactory register | |
| INFO: Registering org.apache.aurora.scheduler.http.Quotas as a root resource class | |
| Sep 11, 2015 3:35:39 PM com.sun.jersey.guice.spi.container.GuiceComponentProviderFactory register | |
| INFO: Registering org.apache.aurora.scheduler.http.Services as a root resource class | |
| Sep 11, 2015 3:35:39 PM com.sun.jersey.guice.spi.container.GuiceComponentProviderFactory register | |
| INFO: Registering org.apache.aurora.scheduler.http.Slaves as a root resource class | |
| Sep 11, 2015 3:35:39 PM com.sun.jersey.guice.spi.container.GuiceComponentProviderFactory register | |
| INFO: Registering org.apache.aurora.scheduler.http.StructDump as a root resource class | |
| Sep 11, 2015 3:35:39 PM com.sun.jersey.guice.spi.container.GuiceComponentProviderFactory register | |
| INFO: Registering org.apache.aurora.scheduler.http.Utilization as a root resource class | |
| Sep 11, 2015 3:35:39 PM com.sun.jersey.server.impl.application.WebApplicationImpl _initiate | |
| INFO: Initiating Jersey application, version 'Jersey: 1.18.1 02/19/2014 03:28 AM' | |
| Sep 11, 2015 3:35:39 PM com.sun.jersey.guice.spi.container.GuiceComponentProviderFactory getComponentProvider | |
| INFO: Binding org.apache.aurora.scheduler.http.api.ApiBeta to GuiceManagedComponentProvider with the scope "PerRequest" | |
| Sep 11, 2015 3:35:39 PM com.sun.jersey.guice.spi.container.GuiceComponentProviderFactory getComponentProvider | |
| INFO: Binding org.apache.aurora.scheduler.http.Cron to GuiceManagedComponentProvider with the scope "PerRequest" | |
| Sep 11, 2015 3:35:39 PM com.sun.jersey.guice.spi.container.GuiceComponentProviderFactory getComponentProvider | |
| INFO: Binding org.apache.aurora.scheduler.http.Locks to GuiceManagedComponentProvider with the scope "PerRequest" | |
| Sep 11, 2015 3:35:39 PM com.sun.jersey.guice.spi.container.GuiceComponentProviderFactory getComponentProvider | |
| INFO: Binding org.apache.aurora.scheduler.http.Maintenance to GuiceManagedComponentProvider with the scope "PerRequest" | |
| Sep 11, 2015 3:35:39 PM com.sun.jersey.guice.spi.container.GuiceComponentProviderFactory getComponentProvider | |
| INFO: Binding org.apache.aurora.scheduler.http.Mname to GuiceManagedComponentProvider with the scope "PerRequest" | |
| Sep 11, 2015 3:35:39 PM com.sun.jersey.guice.spi.container.GuiceComponentProviderFactory getComponentProvider | |
| INFO: Binding org.apache.aurora.scheduler.http.Offers to GuiceManagedComponentProvider with the scope "PerRequest" | |
| Sep 11, 2015 3:35:39 PM com.sun.jersey.guice.spi.container.GuiceComponentProviderFactory getComponentProvider | |
| INFO: Binding org.apache.aurora.scheduler.http.PendingTasks to GuiceManagedComponentProvider with the scope "PerRequest" | |
| Sep 11, 2015 3:35:39 PM com.sun.jersey.guice.spi.container.GuiceComponentProviderFactory getComponentProvider | |
| INFO: Binding org.apache.aurora.scheduler.http.Quotas to GuiceManagedComponentProvider with the scope "PerRequest" | |
| Sep 11, 2015 3:35:39 PM com.sun.jersey.guice.spi.container.GuiceComponentProviderFactory getComponentProvider | |
| INFO: Binding org.apache.aurora.scheduler.http.Services to GuiceManagedComponentProvider with the scope "PerRequest" | |
| Sep 11, 2015 3:35:39 PM com.sun.jersey.guice.spi.container.GuiceComponentProviderFactory getComponentProvider | |
| INFO: Binding org.apache.aurora.scheduler.http.Slaves to GuiceManagedComponentProvider with the scope "PerRequest" | |
| Sep 11, 2015 3:35:39 PM com.sun.jersey.guice.spi.container.GuiceComponentProviderFactory getComponentProvider | |
| INFO: Binding org.apache.aurora.scheduler.http.StructDump to GuiceManagedComponentProvider with the scope "PerRequest" | |
| Sep 11, 2015 3:35:39 PM com.sun.jersey.guice.spi.container.GuiceComponentProviderFactory getComponentProvider | |
| INFO: Binding org.apache.aurora.scheduler.http.Utilization to GuiceManagedComponentProvider with the scope "PerRequest" | |
| Sep 11, 2015 3:35:39 PM org.apache.aurora.scheduler.cron.quartz.CronModule provideTimeZone | |
| WARNING: Cron schedules are configured to fire according to timezone Greenwich Mean Time but system timezone is set to Colombia Time | |
| Sep 11, 2015 3:35:39 PM org.eclipse.jetty.server.AbstractConnector doStart | |
| INFO: Started SelectChannelConnector@0.0.0.0:8081 | |
| I0911 20:35:39.626 THREAD1 com.twitter.common.util.StateMachine$Builder$1.execute: SchedulerLifecycle state machine transition IDLE -> PREPARING_STORAGE | |
| WARNING: Logging before InitGoogleLogging() is written to STDERR | |
| I0911 15:35:39.942147 30498 leveldb.cpp:176] Opened db in 25.409499ms | |
| I0911 15:35:39.959143 30498 leveldb.cpp:183] Compacted db in 16.890518ms | |
| I0911 15:35:39.959252 30498 leveldb.cpp:198] Created db iterator in 57706ns | |
| I0911 15:35:39.959285 30498 leveldb.cpp:204] Seeked to beginning of db in 14517ns | |
| I0911 15:35:39.959352 30498 leveldb.cpp:273] Iterated through 1 keys in the db in 50326ns | |
| I0911 15:35:39.959502 30498 replica.cpp:744] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned | |
| 2015-09-11 15:35:39,961:30491(0x7ffa516f1700):ZOO_INFO@log_env@712: Client environment:zookeeper.version=zookeeper C client 3.4.5 | |
| 2015-09-11 15:35:39,961:30491(0x7ffa516f1700):ZOO_INFO@log_env@716: Client environment:host.name=kiriki | |
| 2015-09-11 15:35:39,961:30491(0x7ffa516f1700):ZOO_INFO@log_env@723: Client environment:os.name=Linux | |
| 2015-09-11 15:35:39,961:30491(0x7ffa516f1700):ZOO_INFO@log_env@724: Client environment:os.arch=4.2.0-kiriki | |
| 2015-09-11 15:35:39,961:30491(0x7ffa516f1700):ZOO_INFO@log_env@725: Client environment:os.version=#2 SMP Sun Aug 30 19:17:55 COT 2015 | |
| 2015-09-11 15:35:39,961:30491(0x7ffa516f1700):ZOO_INFO@log_env@733: Client environment:user.name=yuji | |
| I0911 15:35:39.961525 30645 log.cpp:238] Attempting to join replica to ZooKeeper group | |
| 2015-09-11 15:35:39,961:30491(0x7ff9737fe700):ZOO_INFO@log_env@712: Client environment:zookeeper.version=zookeeper C client 3.4.5 | |
| 2015-09-11 15:35:39,961:30491(0x7ffa516f1700):ZOO_INFO@log_env@741: Client environment:user.home=/home/yuji | |
| 2015-09-11 15:35:39,961:30491(0x7ff9737fe700):ZOO_INFO@log_env@716: Client environment:host.name=kiriki | |
| 2015-09-11 15:35:39,961:30491(0x7ffa516f1700):ZOO_INFO@log_env@753: Client environment:user.dir=/home/yuji/git/aurora | |
| 2015-09-11 15:35:39,961:30491(0x7ff9737fe700):ZOO_INFO@log_env@723: Client environment:os.name=Linux | |
| 2015-09-11 15:35:39,961:30491(0x7ffa516f1700):ZOO_INFO@zookeeper_init@786: Initiating client connection, host=127.0.0.1:2181 sessionTimeout=4000 watcher=0x7ff96a2b7186 sessionId=0 sessionPasswd=<null> context=0x7ff990001ee0 flags=0 | |
| 2015-09-11 15:35:39,961:30491(0x7ff9737fe700):ZOO_INFO@log_env@724: Client environment:os.arch=4.2.0-kiriki | |
| 2015-09-11 15:35:39,961:30491(0x7ff9737fe700):ZOO_INFO@log_env@725: Client environment:os.version=#2 SMP Sun Aug 30 19:17:55 COT 2015 | |
| 2015-09-11 15:35:39,961:30491(0x7ff9737fe700):ZOO_INFO@log_env@733: Client environment:user.name=yuji | |
| 2015-09-11 15:35:39,961:30491(0x7ff9737fe700):ZOO_INFO@log_env@741: Client environment:user.home=/home/yuji | |
| 2015-09-11 15:35:39,961:30491(0x7ff9737fe700):ZOO_INFO@log_env@753: Client environment:user.dir=/home/yuji/git/aurora | |
| 2015-09-11 15:35:39,961:30491(0x7ff9737fe700):ZOO_INFO@zookeeper_init@786: Initiating client connection, host=127.0.0.1:2181 sessionTimeout=4000 watcher=0x7ff96a2b7186 sessionId=0 sessionPasswd=<null> context=0x7ff98c0072f0 flags=0 | |
| 2015-09-11 15:35:39,962:30491(0x7ff965cb3700):ZOO_INFO@check_events@1703: initiated connection to server [127.0.0.1:2181] | |
| I0911 15:35:39.962180 30642 recover.cpp:449] Starting replica recovery | |
| 2015-09-11 15:35:39,962:30491(0x7ff966cb5700):ZOO_INFO@check_events@1703: initiated connection to server [127.0.0.1:2181] | |
| I0911 15:35:39.962862 30642 recover.cpp:475] Replica is in VOTING status | |
| I0911 15:35:39.963127 30642 recover.cpp:464] Recover process terminated | |
| I0911 20:35:39.964 THREAD1 com.twitter.common.util.StateMachine$Builder$1.execute: storage state machine transition CONSTRUCTED -> PREPARED | |
| I0911 20:35:39.964 THREAD1 com.twitter.common.util.StateMachine$Builder$1.execute: SchedulerLifecycle state machine transition PREPARING_STORAGE -> STORAGE_PREPARED | |
| 2015-09-11 15:35:39,966:30491(0x7ff965cb3700):ZOO_INFO@check_events@1750: session establishment complete on server [127.0.0.1:2181], sessionId=0x10001acea5a0005, negotiated timeout=4000 | |
| I0911 15:35:39.966825 30639 group.cpp:331] Group process (group(2)@127.0.1.1:8083) connected to ZooKeeper | |
| I0911 15:35:39.966874 30639 group.cpp:805] Syncing group operations: queue size (joins, cancels, datas) = (1, 0, 0) | |
| I0911 15:35:39.966902 30639 group.cpp:403] Trying to create path '/aurora/replicated-log' in ZooKeeper | |
| 2015-09-11 15:35:39,967:30491(0x7ff966cb5700):ZOO_INFO@check_events@1750: session establishment complete on server [127.0.0.1:2181], sessionId=0x10001acea5a0006, negotiated timeout=4000 | |
| I0911 15:35:39.967286 30641 group.cpp:331] Group process (group(1)@127.0.1.1:8083) connected to ZooKeeper | |
| I0911 15:35:39.967319 30641 group.cpp:805] Syncing group operations: queue size (joins, cancels, datas) = (0, 0, 0) | |
| I0911 15:35:39.967337 30641 group.cpp:403] Trying to create path '/aurora/replicated-log' in ZooKeeper | |
| I0911 15:35:39.972945 30644 network.hpp:415] ZooKeeper group memberships changed | |
| I0911 15:35:39.973184 30645 group.cpp:674] Trying to get '/aurora/replicated-log/0000000000' in ZooKeeper | |
| I0911 20:35:39.974 THREAD1 com.twitter.common.zookeeper.Group$ActiveMembership.join: Set group member ID to singleton_candidate_0000000000 | |
| I0911 15:35:39.975579 30642 network.hpp:463] ZooKeeper group PIDs: { log-replica(1)@127.0.1.1:8083 } | |
| I0911 20:35:39.977 THREAD1 com.twitter.common.zookeeper.CandidateImpl$4.onGroupChange: Candidate /aurora/scheduler/singleton_candidate_0000000000 is now leader of group: [singleton_candidate_0000000000] | |
| I0911 20:35:39.978 THREAD1 com.twitter.common.util.StateMachine$Builder$1.execute: SchedulerLifecycle state machine transition STORAGE_PREPARED -> LEADER_AWAITING_REGISTRATION | |
| I0911 20:35:39.978 THREAD1 org.apache.aurora.scheduler.SchedulerLifecycle$6.execute: Elected as leading scheduler! | |
| I0911 15:35:39.983682 30643 log.cpp:661] Attempting to start the writer | |
| I0911 15:35:39.985918 30643 replica.cpp:477] Replica received implicit promise request with proposal 1 | |
| I0911 15:35:39.994482 30643 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 8.459082ms | |
| I0911 15:35:39.994534 30643 replica.cpp:345] Persisted promised to 1 | |
| I0911 15:35:39.995379 30644 coordinator.cpp:231] Coordinator attemping to fill missing position | |
| I0911 15:35:39.996601 30642 replica.cpp:378] Replica received explicit promise request for position 0 with proposal 2 | |
| I0911 15:35:39.997604 30642 leveldb.cpp:343] Persisting action (8 bytes) to leveldb took 942135ns | |
| I0911 15:35:39.997642 30642 replica.cpp:679] Persisted action at 0 | |
| I0911 15:35:39.998571 30640 replica.cpp:511] Replica received write request for position 0 | |
| I0911 15:35:39.998638 30640 leveldb.cpp:438] Reading position from leveldb took 33581ns | |
| I0911 15:35:40.002257 30640 leveldb.cpp:343] Persisting action (14 bytes) to leveldb took 3.540656ms | |
| I0911 15:35:40.002365 30640 replica.cpp:679] Persisted action at 0 | |
| I0911 15:35:40.003399 30645 replica.cpp:658] Replica received learned notice for position 0 | |
| I0911 15:35:40.007208 30645 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 3.735116ms | |
| I0911 15:35:40.007325 30645 replica.cpp:679] Persisted action at 0 | |
| I0911 15:35:40.007382 30645 replica.cpp:664] Replica learned NOP action at position 0 | |
| I0911 15:35:40.008148 30640 log.cpp:677] Writer started with ending position 0 | |
| I0911 15:35:40.009218 30643 log.cpp:685] Attempting to append 5 bytes to the log | |
| I0911 15:35:40.009351 30639 coordinator.cpp:341] Coordinator attempting to write APPEND action at position 1 | |
| I0911 15:35:40.009937 30641 replica.cpp:511] Replica received write request for position 1 | |
| I0911 15:35:40.013766 30641 leveldb.cpp:343] Persisting action (21 bytes) to leveldb took 3.782378ms | |
| I0911 15:35:40.013823 30641 replica.cpp:679] Persisted action at 1 | |
| I0911 15:35:40.014371 30641 replica.cpp:658] Replica received learned notice for position 1 | |
| I0911 15:35:40.017997 30641 leveldb.cpp:343] Persisting action (23 bytes) to leveldb took 3.59543ms | |
| I0911 15:35:40.018041 30641 replica.cpp:679] Persisted action at 1 | |
| I0911 15:35:40.018069 30641 replica.cpp:664] Replica learned APPEND action at position 1 | |
| I0911 15:35:40.070916 30642 leveldb.cpp:438] Reading position from leveldb took 47006ns | |
| I0911 15:35:40.072258 30644 leveldb.cpp:438] Reading position from leveldb took 45288ns | |
| I0911 20:35:40.078 THREAD1 org.apache.aurora.scheduler.storage.StorageBackfill.backfill: Backfilling task config job keys. | |
| I0911 20:35:40.090 THREAD1 org.apache.aurora.scheduler.storage.StorageBackfill.backfill: Performing shard uniqueness sanity check. | |
| I0911 15:35:40.095815 30645 log.cpp:685] Attempting to append 33 bytes to the log | |
| I0911 15:35:40.095968 30644 coordinator.cpp:341] Coordinator attempting to write APPEND action at position 2 | |
| I0911 15:35:40.096519 30644 replica.cpp:511] Replica received write request for position 2 | |
| I0911 15:35:40.101001 30644 leveldb.cpp:343] Persisting action (49 bytes) to leveldb took 4.437316ms | |
| I0911 15:35:40.101068 30644 replica.cpp:679] Persisted action at 2 | |
| I0911 15:35:40.101676 30640 replica.cpp:658] Replica received learned notice for position 2 | |
| I0911 15:35:40.105608 30640 leveldb.cpp:343] Persisting action (51 bytes) to leveldb took 3.873687ms | |
| I0911 15:35:40.105697 30640 replica.cpp:679] Persisted action at 2 | |
| I0911 15:35:40.105752 30640 replica.cpp:664] Replica learned APPEND action at position 2 | |
| I0911 20:35:40.107 THREAD1 com.twitter.common.util.StateMachine$Builder$1.execute: storage state machine transition PREPARED -> READY | |
| W0911 20:35:40.107 THREAD1 com.twitter.common.stats.Stats.export: Re-using already registered variable for key mem_storage_fetch_tasks_nanos_total | |
| W0911 20:35:40.108 THREAD1 com.twitter.common.stats.Stats.export: Re-using already registered variable for key mem_storage_fetch_tasks_events | |
| W0911 20:35:40.108 THREAD1 com.twitter.common.stats.Stats.export: Re-using already registered variable for key mem_storage_fetch_tasks_nanos_total_per_sec | |
| W0911 20:35:40.108 THREAD1 com.twitter.common.stats.Stats.export: Re-using already registered variable for key mem_storage_fetch_tasks_events_per_sec | |
| W0911 20:35:40.108 THREAD1 com.twitter.common.stats.Stats.export: Re-using already registered variable for key mem_storage_fetch_tasks_nanos_per_event | |
| I0911 20:35:40.114 THREAD136 org.apache.aurora.scheduler.mesos.SchedulerDriverService.startUp: Connecting to mesos master: zk://127.0.0.1:2181/mesos/master | |
| W0911 20:35:40.115 THREAD136 org.apache.aurora.scheduler.mesos.SchedulerDriverService.startUp: Connecting to master without authentication! | |
| W0911 20:35:40.116 THREAD136 org.apache.aurora.scheduler.mesos.SchedulerDriverService.startUp: Did not find a persisted framework ID, connecting as a new framework. | |
| 2015-09-11 15:35:40,120:30491(0x7ffa50ef0700):ZOO_INFO@log_env@712: Client environment:zookeeper.version=zookeeper C client 3.4.5 | |
| 2015-09-11 15:35:40,120:30491(0x7ffa50ef0700):ZOO_INFO@log_env@716: Client environment:host.name=kiriki | |
| 2015-09-11 15:35:40,120:30491(0x7ffa50ef0700):ZOO_INFO@log_env@723: Client environment:os.name=Linux | |
| 2015-09-11 15:35:40,120:30491(0x7ffa50ef0700):ZOO_INFO@log_env@724: Client environment:os.arch=4.2.0-kiriki | |
| 2015-09-11 15:35:40,120:30491(0x7ffa50ef0700):ZOO_INFO@log_env@725: Client environment:os.version=#2 SMP Sun Aug 30 19:17:55 COT 2015 | |
| 2015-09-11 15:35:40,121:30491(0x7ffa50ef0700):ZOO_INFO@log_env@733: Client environment:user.name=yuji | |
| 2015-09-11 15:35:40,121:30491(0x7ffa50ef0700):ZOO_INFO@log_env@741: Client environment:user.home=/home/yuji | |
| 2015-09-11 15:35:40,121:30491(0x7ffa50ef0700):ZOO_INFO@log_env@753: Client environment:user.dir=/home/yuji/git/aurora | |
| 2015-09-11 15:35:40,121:30491(0x7ffa50ef0700):ZOO_INFO@zookeeper_init@786: Initiating client connection, host=127.0.0.1:2181 sessionTimeout=10000 watcher=0x7ff96a2b7186 sessionId=0 sessionPasswd=<null> context=0x7ff98c008060 flags=0 | |
| 2015-09-11 15:35:40,121:30491(0x7ff964cb1700):ZOO_INFO@check_events@1703: initiated connection to server [127.0.0.1:2181] | |
| I0911 15:35:40.121491 30653 sched.cpp:164] Version: 0.24.0 | |
| I0911 20:35:40.122 THREAD136 org.apache.aurora.scheduler.mesos.SchedulerDriverService.startUp: Driver started with code DRIVER_RUNNING | |
| I0911 20:35:40.123 THREAD1 org.apache.aurora.scheduler.SchedulerLifecycle$DefaultDelayedActions.onRegistrationTimeout: Giving up on registration in (1, mins) | |
| I0911 20:35:40.123 THREAD1 com.twitter.common.application.Lifecycle.awaitShutdown: Awaiting shutdown | |
| 2015-09-11 15:35:40,124:30491(0x7ff964cb1700):ZOO_INFO@check_events@1750: session establishment complete on server [127.0.0.1:2181], sessionId=0x10001acea5a0007, negotiated timeout=10000 | |
| I0911 15:35:40.125041 30640 group.cpp:331] Group process (group(3)@127.0.1.1:8083) connected to ZooKeeper | |
| I0911 15:35:40.125094 30640 group.cpp:805] Syncing group operations: queue size (joins, cancels, datas) = (0, 0, 0) | |
| I0911 15:35:40.125113 30640 group.cpp:403] Trying to create path '/mesos/master' in ZooKeeper | |
| I0911 15:35:40.126750 30644 detector.cpp:156] Detected a new leader: (id='1') | |
| I0911 15:35:40.127173 30642 group.cpp:674] Trying to get '/mesos/master/json.info_0000000001' in ZooKeeper | |
| I0911 15:35:40.128538 30645 detector.cpp:481] A new leading master (UPID=master@127.0.0.1:5050) is detected | |
| I0911 15:35:40.128770 30641 sched.cpp:262] New master detected at master@127.0.0.1:5050 | |
| I0911 15:35:40.129616 30641 sched.cpp:272] No credentials provided. Attempting to register without authentication | |
| I0911 15:35:40.132681 30644 sched.cpp:640] Framework registered with 20150911-153416-16777343-5050-30331-0000 | |
| I0911 20:35:40.177 THREAD138 org.apache.aurora.scheduler.mesos.MesosSchedulerImpl.registered: Registered with ID value: "20150911-153416-16777343-5050-30331-0000" | |
| , master: id: "20150911-153416-16777343-5050-30331" | |
| ip: 16777343 | |
| port: 5050 | |
| pid: "master@127.0.0.1:5050" | |
| hostname: "localhost" | |
| 6: "0.24.0" | |
| 7: "\n\tlocalhost\022\t127.0.0.1\030\272\'" | |
| I0911 15:35:40.181020 30642 log.cpp:685] Attempting to append 72 bytes to the log | |
| I0911 15:35:40.181219 30638 coordinator.cpp:341] Coordinator attempting to write APPEND action at position 3 | |
| I0911 15:35:40.181908 30643 replica.cpp:511] Replica received write request for position 3 | |
| I0911 15:35:40.186180 30643 leveldb.cpp:343] Persisting action (88 bytes) to leveldb took 4.211189ms | |
| I0911 15:35:40.186270 30643 replica.cpp:679] Persisted action at 3 | |
| I0911 15:35:40.186905 30642 replica.cpp:658] Replica received learned notice for position 3 | |
| I0911 15:35:40.187855 30642 leveldb.cpp:343] Persisting action (90 bytes) to leveldb took 916119ns | |
| I0911 15:35:40.187881 30642 replica.cpp:679] Persisted action at 3 | |
| I0911 15:35:40.187906 30642 replica.cpp:664] Replica learned APPEND action at position 3 | |
| I0911 20:35:40.190 THREAD139 com.twitter.common.util.StateMachine$Builder$1.execute: SchedulerLifecycle state machine transition LEADER_AWAITING_REGISTRATION -> ACTIVE | |
| I0911 20:35:40.196 THREAD152 org.apache.aurora.scheduler.sla.SlaModule$SlaUpdater.startUp: Scheduled SLA calculation with 60000 msec interval. | |
| I0911 20:35:40.197 THREAD155 org.apache.aurora.scheduler.cron.quartz.CronLifecycle.startUp: Starting Quartz cron schedulerQuartzScheduler. | |
| I0911 20:35:40.197 THREAD156 org.apache.aurora.scheduler.storage.db.RowGarbageCollector.runOneIteration: Scanning database tables for unreferenced rows. | |
| I0911 20:35:40.197 THREAD155 org.quartz.core.QuartzScheduler.start: Scheduler QuartzScheduler_$_aurora-cron-1 started. | |
| I0911 20:35:40.203 THREAD156 org.apache.aurora.scheduler.storage.db.RowGarbageCollector.runOneIteration: Deleted 0 unreferenced rows. | |
| W0911 20:35:40.273 THREAD139 com.twitter.common.zookeeper.ServerSetImpl.join: Joining a ServerSet without a shard ID is deprecated and will soon break. | |
| I0911 20:35:40.287 THREAD139 com.twitter.common.zookeeper.Group$ActiveMembership.join: Set group member ID to member_0000000001 | |
| I0911 15:35:40.289974 30645 log.cpp:685] Attempting to append 102 bytes to the log | |
| I0911 15:35:40.290189 30640 coordinator.cpp:341] Coordinator attempting to write APPEND action at position 4 | |
| I0911 15:35:40.290846 30640 replica.cpp:511] Replica received write request for position 4 | |
| I0911 15:35:40.295279 30640 leveldb.cpp:343] Persisting action (118 bytes) to leveldb took 4.377104ms | |
| I0911 15:35:40.295362 30640 replica.cpp:679] Persisted action at 4 | |
| I0911 15:35:40.296048 30643 replica.cpp:658] Replica received learned notice for position 4 | |
| I0911 20:35:40.296 THREAD122 com.twitter.common.zookeeper.ServerSetImpl$ServerSetWatcher.logChange: server set /aurora/scheduler change: from 0 members to 1 | |
| joined: | |
| ServiceInstance(serviceEndpoint:Endpoint(host:127.0.1.1, port:8081), additionalEndpoints:{http=Endpoint(host:127.0.1.1, port:8081)}, status:ALIVE) | |
| I0911 20:35:40.296 THREAD122 org.apache.aurora.scheduler.http.LeaderRedirect$SchedulerMonitor.onChange: Found leader scheduler at [ServiceInstance(serviceEndpoint:Endpoint(host:127.0.1.1, port:8081), additionalEndpoints:{http=Endpoint(host:127.0.1.1, port:8081)}, status:ALIVE)] | |
| I0911 15:35:40.299505 30643 leveldb.cpp:343] Persisting action (120 bytes) to leveldb took 3.400705ms | |
| I0911 15:35:40.299566 30643 replica.cpp:679] Persisted action at 4 | |
| I0911 15:35:40.299609 30643 replica.cpp:664] Replica learned APPEND action at position 4 | |
| I0911 20:36:16.979 THREAD130 org.apache.aurora.scheduler.http.RequestLogger$1.log: 127.0.1.1 127.0.0.1 [11/Sep/2015:20:36:16 +0000] "POST /api HTTP/1.1" 200 0 "http://127.0.1.1:8081/scheduler" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/45.0.2454.85 Safari/537.36" 2 | |
| I0911 20:36:16.994 THREAD130 org.apache.aurora.scheduler.thrift.aop.LoggingInterceptor.invoke: getRoleSummary() | |
| I0911 20:38:36.300 THREAD129 org.apache.aurora.scheduler.http.RequestLogger$1.log: 127.0.1.1 127.0.0.1 [11/Sep/2015:20:38:36 +0000] "POST /api HTTP/1.1" 200 0 "-" "Aurora V2" 0 | |
| I0911 20:38:36.312 THREAD129 org.apache.aurora.scheduler.thrift.aop.LoggingInterceptor.invoke: createJob(JobConfiguration(key:JobKey(role:www-data, environment:devel, name:test), owner:Identity(role:www-data, user:yuji), cronSchedule:null, cronCollisionPolicy:KILL_EXISTING, taskConfig:TaskConfig(job:JobKey(role:www-data, environment:devel, name:test), owner:Identity(role:www-data, user:yuji), environment:devel, jobName:test, isService:true, numCpus:1.0, ramMb:128, diskMb:128, priority:0, maxTaskFailures:1, production:false, constraints:[], requestedPorts:[], taskLinks:{}, executorConfig:ExecutorConfig(name:BLANKED, data:BLANKED), metadata:[], container:<Container mesos:MesosContainer()>), instanceCount:1), null, SessionKey(mechanism:UNAUTHENTICATED, data:50 D0 14 4C 71 0D 4C 80 80 4C 40)) | |
| I0911 20:38:36.327 THREAD129 org.apache.aurora.scheduler.thrift.SchedulerThriftInterface$1.apply: Launching 1 tasks. | |
| I0911 20:38:36.337 THREAD129 com.twitter.common.util.StateMachine$Builder$1.execute: 1442003916329-www-data-devel-test-0-f81f3b5c-ff28-4013-9e1b-696945b95e84 state machine transition INIT -> PENDING | |
| I0911 20:38:36.338 THREAD129 org.apache.aurora.scheduler.state.TaskStateMachine.addFollowup: Adding work command SAVE_STATE for 1442003916329-www-data-devel-test-0-f81f3b5c-ff28-4013-9e1b-696945b95e84 | |
| I0911 15:38:36.344980 30638 log.cpp:685] Attempting to append 1376 bytes to the log | |
| I0911 15:38:36.345368 30641 coordinator.cpp:341] Coordinator attempting to write APPEND action at position 5 | |
| I0911 15:38:36.347149 30641 replica.cpp:511] Replica received write request for position 5 | |
| I0911 15:38:36.351760 30641 leveldb.cpp:343] Persisting action (1395 bytes) to leveldb took 4.515272ms | |
| I0911 15:38:36.351892 30641 replica.cpp:679] Persisted action at 5 | |
| I0911 15:38:36.353024 30641 replica.cpp:658] Replica received learned notice for position 5 | |
| I0911 15:38:36.354173 30641 leveldb.cpp:343] Persisting action (1397 bytes) to leveldb took 1.072183ms | |
| I0911 15:38:36.354214 30641 replica.cpp:679] Persisted action at 5 | |
| I0911 15:38:36.354259 30641 replica.cpp:664] Replica learned APPEND action at position 5 | |
| I0911 20:38:36.361 THREAD130 org.apache.aurora.scheduler.http.RequestLogger$1.log: 127.0.1.1 127.0.0.1 [11/Sep/2015:20:38:36 +0000] "POST /api HTTP/1.1" 200 0 "-" "Aurora V2" 0 | |
| I0911 20:38:36.365 THREAD161 com.twitter.common.util.StateMachine$Builder$1.execute: 1442003916329-www-data-devel-test-0-f81f3b5c-ff28-4013-9e1b-696945b95e84 state machine transition PENDING -> ASSIGNED | |
| I0911 20:38:36.365 THREAD161 org.apache.aurora.scheduler.state.TaskStateMachine.addFollowup: Adding work command SAVE_STATE for 1442003916329-www-data-devel-test-0-f81f3b5c-ff28-4013-9e1b-696945b95e84 | |
| I0911 20:38:36.366 THREAD161 org.apache.aurora.scheduler.state.TaskAssigner$TaskAssignerImpl.assign: Offer on slave kiriki (id 20150911-153416-16777343-5050-30331-S0) is being assigned task for 1442003916329-www-data-devel-test-0-f81f3b5c-ff28-4013-9e1b-696945b95e84. | |
| I0911 20:38:36.368 THREAD130 org.apache.aurora.scheduler.thrift.aop.LoggingInterceptor.invoke: getTasksWithoutConfigs(TaskQuery(owner:null, role:null, environment:null, jobName:null, taskIds:null, statuses:null, instanceIds:null, slaveHosts:null, jobKeys:[JobKey(role:www-data, environment:devel, name:test)], offset:0, limit:0)) | |
| I0911 15:38:36.388543 30643 log.cpp:685] Attempting to append 1475 bytes to the log | |
| I0911 15:38:36.388841 30639 coordinator.cpp:341] Coordinator attempting to write APPEND action at position 6 | |
| I0911 15:38:36.389711 30642 replica.cpp:511] Replica received write request for position 6 | |
| I0911 15:38:36.395661 30642 leveldb.cpp:343] Persisting action (1494 bytes) to leveldb took 5.887697ms | |
| I0911 15:38:36.395722 30642 replica.cpp:679] Persisted action at 6 | |
| I0911 15:38:36.396323 30638 replica.cpp:658] Replica received learned notice for position 6 | |
| I0911 15:38:36.400275 30638 leveldb.cpp:343] Persisting action (1496 bytes) to leveldb took 3.89086ms | |
| I0911 15:38:36.400354 30638 replica.cpp:679] Persisted action at 6 | |
| I0911 15:38:36.400408 30638 replica.cpp:664] Replica learned APPEND action at position 6 | |
| I0911 20:38:36.514 THREAD162 org.apache.aurora.scheduler.mesos.MesosSchedulerImpl.logStatusUpdate: Received status update for task 1442003916329-www-data-devel-test-0-f81f3b5c-ff28-4013-9e1b-696945b95e84 in state TASK_FAILED from SOURCE_SLAVE with REASON_MEMORY_LIMIT: | |
| I0911 20:38:36.515 THREAD151 com.twitter.common.util.StateMachine$Builder$1.execute: 1442003916329-www-data-devel-test-0-f81f3b5c-ff28-4013-9e1b-696945b95e84 state machine transition ASSIGNED -> FAILED | |
| I0911 20:38:36.515 THREAD151 org.apache.aurora.scheduler.state.TaskStateMachine.addFollowup: Adding work command INCREMENT_FAILURES for 1442003916329-www-data-devel-test-0-f81f3b5c-ff28-4013-9e1b-696945b95e84 | |
| I0911 20:38:36.516 THREAD151 org.apache.aurora.scheduler.state.TaskStateMachine.addFollowup: Adding work command RESCHEDULE for 1442003916329-www-data-devel-test-0-f81f3b5c-ff28-4013-9e1b-696945b95e84 | |
| I0911 20:38:36.516 THREAD151 org.apache.aurora.scheduler.state.TaskStateMachine.addFollowup: Adding work command SAVE_STATE for 1442003916329-www-data-devel-test-0-f81f3b5c-ff28-4013-9e1b-696945b95e84 | |
| I0911 20:38:36.516 THREAD151 org.apache.aurora.scheduler.state.StateManagerImpl.updateTaskAndExternalState: Task being rescheduled: 1442003916329-www-data-devel-test-0-f81f3b5c-ff28-4013-9e1b-696945b95e84 | |
| W0911 20:38:36.517 THREAD158 com.twitter.common.stats.Stats.export: Re-using already registered variable for key task_delivery_delay_SOURCE_SLAVE_timeouts_per_sec | |
| W0911 20:38:36.517 THREAD158 com.twitter.common.stats.Stats.export: Re-using already registered variable for key task_delivery_delay_SOURCE_SLAVE_requests_per_sec | |
| I0911 20:38:36.518 THREAD151 com.twitter.common.util.StateMachine$Builder$1.execute: 1442003916517-www-data-devel-test-0-fbbfd7a0-89bc-4160-b3ee-fa544832ed82 state machine transition INIT -> PENDING | |
| I0911 20:38:36.518 THREAD151 org.apache.aurora.scheduler.state.TaskStateMachine.addFollowup: Adding work command SAVE_STATE for 1442003916517-www-data-devel-test-0-fbbfd7a0-89bc-4160-b3ee-fa544832ed82 | |
| I0911 15:38:36.519142 30642 log.cpp:685] Attempting to append 2991 bytes to the log | |
| W0911 20:38:36.519 THREAD159 com.twitter.common.stats.Stats.validateName: Invalid stat name tasks_FAILED_www-data/devel/test exported as tasks_FAILED_www_data_devel_test | |
| I0911 15:38:36.519331 30641 coordinator.cpp:341] Coordinator attempting to write APPEND action at position 7 | |
| I0911 15:38:36.519913 30645 replica.cpp:511] Replica received write request for position 7 | |
| I0911 15:38:36.528414 30645 leveldb.cpp:343] Persisting action (3010 bytes) to leveldb took 8.439407ms | |
| I0911 15:38:36.528458 30645 replica.cpp:679] Persisted action at 7 | |
| I0911 15:38:36.529019 30640 replica.cpp:658] Replica received learned notice for position 7 | |
| I0911 15:38:36.537384 30640 leveldb.cpp:343] Persisting action (3012 bytes) to leveldb took 8.312639ms | |
| I0911 15:38:36.537474 30640 replica.cpp:679] Persisted action at 7 | |
| I0911 15:38:36.537533 30640 replica.cpp:664] Replica learned APPEND action at position 7 | |
| I0911 20:38:37.566 THREAD161 com.twitter.common.util.StateMachine$Builder$1.execute: 1442003916517-www-data-devel-test-0-fbbfd7a0-89bc-4160-b3ee-fa544832ed82 state machine transition PENDING -> ASSIGNED | |
| I0911 20:38:37.566 THREAD161 org.apache.aurora.scheduler.state.TaskStateMachine.addFollowup: Adding work command SAVE_STATE for 1442003916517-www-data-devel-test-0-fbbfd7a0-89bc-4160-b3ee-fa544832ed82 | |
| I0911 20:38:37.567 THREAD161 org.apache.aurora.scheduler.state.TaskAssigner$TaskAssignerImpl.assign: Offer on slave kiriki (id 20150911-153416-16777343-5050-30331-S0) is being assigned task for 1442003916517-www-data-devel-test-0-fbbfd7a0-89bc-4160-b3ee-fa544832ed82. | |
| I0911 15:38:37.568603 30641 log.cpp:685] Attempting to append 1572 bytes to the log | |
| I0911 15:38:37.568717 30640 coordinator.cpp:341] Coordinator attempting to write APPEND action at position 8 | |
| I0911 15:38:37.569233 30638 replica.cpp:511] Replica received write request for position 8 | |
| I0911 15:38:37.573544 30638 leveldb.cpp:343] Persisting action (1591 bytes) to leveldb took 4.262967ms | |
| I0911 15:38:37.573585 30638 replica.cpp:679] Persisted action at 8 | |
| I0911 15:38:37.574085 30641 replica.cpp:658] Replica received learned notice for position 8 | |
| I0911 15:38:37.577850 30641 leveldb.cpp:343] Persisting action (1593 bytes) to leveldb took 3.711405ms | |
| I0911 15:38:37.577890 30641 replica.cpp:679] Persisted action at 8 | |
| I0911 15:38:37.577921 30641 replica.cpp:664] Replica learned APPEND action at position 8 | |
| I0911 20:38:37.621 THREAD164 org.apache.aurora.scheduler.mesos.MesosSchedulerImpl.logStatusUpdate: Received status update for task 1442003916517-www-data-devel-test-0-fbbfd7a0-89bc-4160-b3ee-fa544832ed82 in state TASK_FAILED from SOURCE_SLAVE with REASON_MEMORY_LIMIT: | |
| I0911 20:38:37.622 THREAD151 com.twitter.common.util.StateMachine$Builder$1.execute: 1442003916517-www-data-devel-test-0-fbbfd7a0-89bc-4160-b3ee-fa544832ed82 state machine transition ASSIGNED -> FAILED | |
| I0911 20:38:37.622 THREAD151 org.apache.aurora.scheduler.state.TaskStateMachine.addFollowup: Adding work command INCREMENT_FAILURES for 1442003916517-www-data-devel-test-0-fbbfd7a0-89bc-4160-b3ee-fa544832ed82 | |
| I0911 20:38:37.622 THREAD151 org.apache.aurora.scheduler.state.TaskStateMachine.addFollowup: Adding work command RESCHEDULE for 1442003916517-www-data-devel-test-0-fbbfd7a0-89bc-4160-b3ee-fa544832ed82 | |
| I0911 20:38:37.622 THREAD151 org.apache.aurora.scheduler.state.TaskStateMachine.addFollowup: Adding work command SAVE_STATE for 1442003916517-www-data-devel-test-0-fbbfd7a0-89bc-4160-b3ee-fa544832ed82 | |
| I0911 20:38:37.623 THREAD151 org.apache.aurora.scheduler.state.StateManagerImpl.updateTaskAndExternalState: Task being rescheduled: 1442003916517-www-data-devel-test-0-fbbfd7a0-89bc-4160-b3ee-fa544832ed82 | |
| I0911 20:38:37.623 THREAD151 org.apache.aurora.scheduler.async.RescheduleCalculator$RescheduleCalculatorImpl.getFlappingPenaltyMs: Ancestor of 1442003916517-www-data-devel-test-0-fbbfd7a0-89bc-4160-b3ee-fa544832ed82 flapped: 1442003916329-www-data-devel-test-0-f81f3b5c-ff28-4013-9e1b-696945b95e84 | |
| I0911 20:38:37.624 THREAD151 com.twitter.common.util.StateMachine$Builder$1.execute: 1442003917623-www-data-devel-test-0-bc7e269b-4dc3-4e91-97bc-15bde98e1acc state machine transition INIT -> THROTTLED | |
| I0911 20:38:37.624 THREAD151 org.apache.aurora.scheduler.state.TaskStateMachine.addFollowup: Adding work command SAVE_STATE for 1442003917623-www-data-devel-test-0-bc7e269b-4dc3-4e91-97bc-15bde98e1acc | |
| I0911 20:38:37.625 THREAD139 org.apache.aurora.scheduler.async.RescheduleCalculator$RescheduleCalculatorImpl.getFlappingPenaltyMs: Ancestor of 1442003917623-www-data-devel-test-0-bc7e269b-4dc3-4e91-97bc-15bde98e1acc flapped: 1442003916517-www-data-devel-test-0-fbbfd7a0-89bc-4160-b3ee-fa544832ed82 | |
| I0911 15:38:37.626013 30640 log.cpp:685] Attempting to append 3125 bytes to the log | |
| I0911 15:38:37.626493 30641 coordinator.cpp:341] Coordinator attempting to write APPEND action at position 9 | |
| I0911 20:38:37.626 THREAD139 org.apache.aurora.scheduler.async.RescheduleCalculator$RescheduleCalculatorImpl.getFlappingPenaltyMs: Ancestor of 1442003917623-www-data-devel-test-0-bc7e269b-4dc3-4e91-97bc-15bde98e1acc flapped: 1442003916329-www-data-devel-test-0-f81f3b5c-ff28-4013-9e1b-696945b95e84 | |
| I0911 15:38:37.627408 30638 replica.cpp:511] Replica received write request for position 9 | |
| I0911 15:38:37.635506 30638 leveldb.cpp:343] Persisting action (3144 bytes) to leveldb took 7.978697ms | |
| I0911 15:38:37.635610 30638 replica.cpp:679] Persisted action at 9 | |
| I0911 15:38:37.636463 30642 replica.cpp:658] Replica received learned notice for position 9 | |
| I0911 15:38:37.644153 30642 leveldb.cpp:343] Persisting action (3146 bytes) to leveldb took 7.655608ms | |
| I0911 15:38:37.644192 30642 replica.cpp:679] Persisted action at 9 | |
| I0911 15:38:37.644219 30642 replica.cpp:664] Replica learned APPEND action at position 9 | |
| I0911 20:38:41.201 THREAD128 org.apache.aurora.scheduler.http.RequestLogger$1.log: 127.0.1.1 127.0.0.1 [11/Sep/2015:20:38:41 +0000] "GET /scheduler HTTP/1.1" 200 0 "-" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/45.0.2454.85 Safari/537.36" 0 | |
| I0911 20:38:41.247 THREAD130 org.apache.aurora.scheduler.http.RequestLogger$1.log: 127.0.1.1 127.0.0.1 [11/Sep/2015:20:38:41 +0000] "GET /apiclient/api_types.js HTTP/1.1" 200 0 "http://127.0.1.1:8081/scheduler" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/45.0.2454.85 Safari/537.36" 0 | |
| I0911 20:38:41.247 THREAD129 org.apache.aurora.scheduler.http.RequestLogger$1.log: 127.0.1.1 127.0.0.1 [11/Sep/2015:20:38:41 +0000] "GET /assets/images/aurora_logo.png HTTP/1.1" 200 0 "http://127.0.1.1:8081/scheduler" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/45.0.2454.85 Safari/537.36" 0 | |
| I0911 20:38:41.247 THREAD131 org.apache.aurora.scheduler.http.RequestLogger$1.log: 127.0.1.1 127.0.0.1 [11/Sep/2015:20:38:41 +0000] "GET /assets/js/thrift.js HTTP/1.1" 200 0 "http://127.0.1.1:8081/scheduler" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/45.0.2454.85 Safari/537.36" 0 | |
| I0911 20:38:41.254 THREAD128 org.apache.aurora.scheduler.http.RequestLogger$1.log: 127.0.1.1 127.0.0.1 [11/Sep/2015:20:38:41 +0000] "GET /apiclient/ReadOnlyScheduler.js HTTP/1.1" 200 0 "http://127.0.1.1:8081/scheduler" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/45.0.2454.85 Safari/537.36" 0 | |
| I0911 20:38:41.282 THREAD166 org.apache.aurora.scheduler.http.RequestLogger$1.log: 127.0.1.1 127.0.0.1 [11/Sep/2015:20:38:41 +0000] "GET /assets/bower_components/angular/angular.js HTTP/1.1" 200 0 "http://127.0.1.1:8081/scheduler" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/45.0.2454.85 Safari/537.36" 0 | |
| I0911 20:38:41.303 THREAD167 org.apache.aurora.scheduler.http.RequestLogger$1.log: 127.0.1.1 127.0.0.1 [11/Sep/2015:20:38:41 +0000] "GET /assets/bower_components/angular-route/angular-route.js HTTP/1.1" 200 0 "http://127.0.1.1:8081/scheduler" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/45.0.2454.85 Safari/537.36" 0 | |
| I0911 20:38:41.315 THREAD168 org.apache.aurora.scheduler.http.RequestLogger$1.log: 127.0.1.1 127.0.0.1 [11/Sep/2015:20:38:41 +0000] "GET /assets/bower_components/bootstrap/dist/css/bootstrap.min.css HTTP/1.1" 200 0 "http://127.0.1.1:8081/scheduler" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/45.0.2454.85 Safari/537.36" 1 | |
| I0911 20:38:41.327 THREAD131 org.apache.aurora.scheduler.http.RequestLogger$1.log: 127.0.1.1 127.0.0.1 [11/Sep/2015:20:38:41 +0000] "GET /assets/css/app.css HTTP/1.1" 200 0 "http://127.0.1.1:8081/scheduler" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/45.0.2454.85 Safari/537.36" 1 | |
| I0911 20:38:41.328 THREAD130 org.apache.aurora.scheduler.http.RequestLogger$1.log: 127.0.1.1 127.0.0.1 [11/Sep/2015:20:38:41 +0000] "GET /assets/js/app.js HTTP/1.1" 200 0 "http://127.0.1.1:8081/scheduler" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/45.0.2454.85 Safari/537.36" 0 | |
| I0911 20:38:41.328 THREAD129 org.apache.aurora.scheduler.http.RequestLogger$1.log: 127.0.1.1 127.0.0.1 [11/Sep/2015:20:38:41 +0000] "GET /assets/js/controllers.js HTTP/1.1" 200 0 "http://127.0.1.1:8081/scheduler" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/45.0.2454.85 Safari/537.36" 0 | |
| I0911 20:38:41.369 THREAD166 org.apache.aurora.scheduler.http.RequestLogger$1.log: 127.0.1.1 127.0.0.1 [11/Sep/2015:20:38:41 +0000] "GET /assets/js/services.js HTTP/1.1" 200 0 "http://127.0.1.1:8081/scheduler" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/45.0.2454.85 Safari/537.36" 0 | |
| I0911 20:38:41.369 THREAD168 org.apache.aurora.scheduler.http.RequestLogger$1.log: 127.0.1.1 127.0.0.1 [11/Sep/2015:20:38:41 +0000] "GET /assets/js/directives.js HTTP/1.1" 200 0 "http://127.0.1.1:8081/scheduler" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/45.0.2454.85 Safari/537.36" 0 | |
| I0911 20:38:41.382 THREAD131 org.apache.aurora.scheduler.http.RequestLogger$1.log: 127.0.1.1 127.0.0.1 [11/Sep/2015:20:38:41 +0000] "GET /assets/js/filters.js HTTP/1.1" 200 0 "http://127.0.1.1:8081/scheduler" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/45.0.2454.85 Safari/537.36" 0 | |
| I0911 20:38:41.391 THREAD167 org.apache.aurora.scheduler.http.RequestLogger$1.log: 127.0.1.1 127.0.0.1 [11/Sep/2015:20:38:41 +0000] "GET /assets/bower_components/jquery/dist/jquery.js HTTP/1.1" 200 0 "http://127.0.1.1:8081/scheduler" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/45.0.2454.85 Safari/537.36" 0 | |
| I0911 20:38:41.421 THREAD129 org.apache.aurora.scheduler.http.RequestLogger$1.log: 127.0.1.1 127.0.0.1 [11/Sep/2015:20:38:41 +0000] "GET /assets/bower_components/bootstrap/dist/js/bootstrap.min.js HTTP/1.1" 200 0 "http://127.0.1.1:8081/scheduler" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/45.0.2454.85 Safari/537.36" 1 | |
| I0911 20:38:41.423 THREAD131 org.apache.aurora.scheduler.http.RequestLogger$1.log: 127.0.1.1 127.0.0.1 [11/Sep/2015:20:38:41 +0000] "GET /assets/bower_components/angular-bootstrap/ui-bootstrap-tpls.min.js HTTP/1.1" 200 0 "http://127.0.1.1:8081/scheduler" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/45.0.2454.85 Safari/537.36" 0 | |
| I0911 20:38:41.430 THREAD168 org.apache.aurora.scheduler.http.RequestLogger$1.log: 127.0.1.1 127.0.0.1 [11/Sep/2015:20:38:41 +0000] "GET /assets/bower_components/smart-table/Smart-Table.debug.js HTTP/1.1" 200 0 "http://127.0.1.1:8081/scheduler" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/45.0.2454.85 Safari/537.36" 1 | |
| I0911 20:38:41.439 THREAD130 org.apache.aurora.scheduler.http.RequestLogger$1.log: 127.0.1.1 127.0.0.1 [11/Sep/2015:20:38:41 +0000] "GET /assets/bower_components/momentjs/moment.js HTTP/1.1" 200 0 "http://127.0.1.1:8081/scheduler" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/45.0.2454.85 Safari/537.36" 0 | |
| I0911 20:38:41.440 THREAD167 org.apache.aurora.scheduler.http.RequestLogger$1.log: 127.0.1.1 127.0.0.1 [11/Sep/2015:20:38:41 +0000] "GET /assets/bower_components/underscore/underscore.js HTTP/1.1" 200 0 "http://127.0.1.1:8081/scheduler" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/45.0.2454.85 Safari/537.36" 0 | |
| I0911 20:38:41.543 THREAD166 org.apache.aurora.scheduler.http.RequestLogger$1.log: 127.0.1.1 127.0.0.1 [11/Sep/2015:20:38:41 +0000] "GET /assets/home.html HTTP/1.1" 200 0 "http://127.0.1.1:8081/scheduler" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/45.0.2454.85 Safari/537.36" 0 | |
| I0911 20:38:41.622 THREAD168 org.apache.aurora.scheduler.http.RequestLogger$1.log: 127.0.1.1 127.0.0.1 [11/Sep/2015:20:38:41 +0000] "GET /assets/images/aurora.png HTTP/1.1" 200 0 "http://127.0.1.1:8081/scheduler" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/45.0.2454.85 Safari/537.36" 1 | |
| I0911 20:38:41.636 THREAD167 org.apache.aurora.scheduler.http.RequestLogger$1.log: 127.0.1.1 127.0.0.1 [11/Sep/2015:20:38:41 +0000] "POST /api HTTP/1.1" 200 0 "http://127.0.1.1:8081/scheduler" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/45.0.2454.85 Safari/537.36" 1 | |
| I0911 20:38:41.636 THREAD167 org.apache.aurora.scheduler.thrift.aop.LoggingInterceptor.invoke: getRoleSummary() | |
| I0911 20:38:43.633 THREAD167 org.apache.aurora.scheduler.http.RequestLogger$1.log: 127.0.1.1 127.0.0.1 [11/Sep/2015:20:38:43 +0000] "POST /api HTTP/1.1" 200 0 "http://127.0.1.1:8081/scheduler/www-data" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/45.0.2454.85 Safari/537.36" 1 | |
| I0911 20:38:43.637 THREAD130 org.apache.aurora.scheduler.http.RequestLogger$1.log: 127.0.1.1 127.0.0.1 [11/Sep/2015:20:38:43 +0000] "POST /api HTTP/1.1" 200 0 "http://127.0.1.1:8081/scheduler/www-data" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/45.0.2454.85 Safari/537.36" 0 | |
| I0911 20:38:43.641 THREAD130 org.apache.aurora.scheduler.thrift.aop.LoggingInterceptor.invoke: getQuota(www-data) | |
| I0911 20:38:43.641 THREAD167 org.apache.aurora.scheduler.thrift.aop.LoggingInterceptor.invoke: getJobSummary(www-data) | |
| I0911 20:38:47.357 THREAD167 org.apache.aurora.scheduler.http.RequestLogger$1.log: 127.0.1.1 127.0.0.1 [11/Sep/2015:20:38:47 +0000] "POST /api HTTP/1.1" 200 0 "http://127.0.1.1:8081/scheduler/www-data/devel/test" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/45.0.2454.85 Safari/537.36" 0 | |
| I0911 20:38:47.357 THREAD166 org.apache.aurora.scheduler.http.RequestLogger$1.log: 127.0.1.1 127.0.0.1 [11/Sep/2015:20:38:47 +0000] "POST /api HTTP/1.1" 200 0 "http://127.0.1.1:8081/scheduler/www-data/devel/test" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/45.0.2454.85 Safari/537.36" 0 | |
| I0911 20:38:47.359 THREAD167 org.apache.aurora.scheduler.thrift.aop.LoggingInterceptor.invoke: getTasksWithoutConfigs(TaskQuery(owner:Identity(role:www-data, user:null), role:null, environment:devel, jobName:test, taskIds:null, statuses:null, instanceIds:null, slaveHosts:null, jobKeys:null, offset:0, limit:0)) | |
| I0911 20:38:47.359 THREAD168 org.apache.aurora.scheduler.http.RequestLogger$1.log: 127.0.1.1 127.0.0.1 [11/Sep/2015:20:38:47 +0000] "POST /api HTTP/1.1" 200 0 "http://127.0.1.1:8081/scheduler/www-data/devel/test" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/45.0.2454.85 Safari/537.36" 0 | |
| I0911 20:38:47.360 THREAD131 org.apache.aurora.scheduler.http.RequestLogger$1.log: 127.0.1.1 127.0.0.1 [11/Sep/2015:20:38:47 +0000] "POST /api HTTP/1.1" 200 0 "http://127.0.1.1:8081/scheduler/www-data/devel/test" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/45.0.2454.85 Safari/537.36" 0 | |
| I0911 20:38:47.366 THREAD166 org.apache.aurora.scheduler.thrift.aop.LoggingInterceptor.invoke: getPendingReason(TaskQuery(owner:Identity(role:www-data, user:null), role:null, environment:devel, jobName:test, taskIds:null, statuses:null, instanceIds:null, slaveHosts:null, jobKeys:null, offset:0, limit:0)) | |
| I0911 20:38:47.366 THREAD168 org.apache.aurora.scheduler.thrift.aop.LoggingInterceptor.invoke: getConfigSummary(JobKey(role:www-data, environment:devel, name:test)) | |
| I0911 20:38:47.368 THREAD130 org.apache.aurora.scheduler.http.RequestLogger$1.log: 127.0.1.1 127.0.0.1 [11/Sep/2015:20:38:47 +0000] "POST /api HTTP/1.1" 200 0 "http://127.0.1.1:8081/scheduler/www-data/devel/test" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/45.0.2454.85 Safari/537.36" 0 | |
| I0911 20:38:47.368 THREAD130 org.apache.aurora.scheduler.thrift.aop.LoggingInterceptor.invoke: getJobSummary(www-data) | |
| I0911 20:38:47.372 THREAD131 org.apache.aurora.scheduler.thrift.aop.LoggingInterceptor.invoke: getJobUpdateSummaries(JobUpdateQuery(role:null, key:null, jobKey:JobKey(role:www-data, environment:devel, name:test), user:null, updateStatuses:null, offset:0, limit:0)) | |
| I0911 20:38:47.530 THREAD129 org.apache.aurora.scheduler.http.RequestLogger$1.log: 127.0.1.1 127.0.0.1 [11/Sep/2015:20:38:47 +0000] "GET /assets/bower_components/bootstrap/dist/fonts/glyphicons-halflings-regular.woff HTTP/1.1" 200 0 "http://127.0.1.1:8081/scheduler" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/45.0.2454.85 Safari/537.36" 0 | |
| I0911 20:39:37.626 THREAD145 com.twitter.common.util.StateMachine$Builder$1.execute: 1442003917623-www-data-devel-test-0-bc7e269b-4dc3-4e91-97bc-15bde98e1acc state machine transition THROTTLED -> PENDING | |
| I0911 20:39:37.626 THREAD145 org.apache.aurora.scheduler.state.TaskStateMachine.addFollowup: Adding work command SAVE_STATE for 1442003917623-www-data-devel-test-0-bc7e269b-4dc3-4e91-97bc-15bde98e1acc | |
| I0911 15:39:37.627305 30645 log.cpp:685] Attempting to append 1542 bytes to the log | |
| I0911 15:39:37.627429 30640 coordinator.cpp:341] Coordinator attempting to write APPEND action at position 10 | |
| I0911 15:39:37.628000 30642 replica.cpp:511] Replica received write request for position 10 | |
| I0911 15:39:37.632375 30642 leveldb.cpp:343] Persisting action (1561 bytes) to leveldb took 4.338571ms | |
| I0911 15:39:37.632406 30642 replica.cpp:679] Persisted action at 10 | |
| I0911 15:39:37.632773 30640 replica.cpp:658] Replica received learned notice for position 10 | |
| I0911 15:39:37.640372 30640 leveldb.cpp:343] Persisting action (1563 bytes) to leveldb took 7.559963ms | |
| I0911 15:39:37.640439 30640 replica.cpp:679] Persisted action at 10 | |
| I0911 15:39:37.640478 30640 replica.cpp:664] Replica learned APPEND action at position 10 | |
| I0911 20:39:37.642 THREAD161 com.twitter.common.util.StateMachine$Builder$1.execute: 1442003917623-www-data-devel-test-0-bc7e269b-4dc3-4e91-97bc-15bde98e1acc state machine transition PENDING -> ASSIGNED | |
| I0911 20:39:37.642 THREAD161 org.apache.aurora.scheduler.state.TaskStateMachine.addFollowup: Adding work command SAVE_STATE for 1442003917623-www-data-devel-test-0-bc7e269b-4dc3-4e91-97bc-15bde98e1acc | |
| I0911 20:39:37.642 THREAD161 org.apache.aurora.scheduler.state.TaskAssigner$TaskAssignerImpl.assign: Offer on slave kiriki (id 20150911-153416-16777343-5050-30331-S0) is being assigned task for 1442003917623-www-data-devel-test-0-bc7e269b-4dc3-4e91-97bc-15bde98e1acc. | |
| I0911 15:39:37.644234 30638 log.cpp:685] Attempting to append 1641 bytes to the log | |
| I0911 15:39:37.644551 30639 coordinator.cpp:341] Coordinator attempting to write APPEND action at position 11 | |
| I0911 15:39:37.645231 30645 replica.cpp:511] Replica received write request for position 11 | |
| I0911 15:39:37.649050 30645 leveldb.cpp:343] Persisting action (1660 bytes) to leveldb took 3.775805ms | |
| I0911 15:39:37.649102 30645 replica.cpp:679] Persisted action at 11 | |
| I0911 15:39:37.649548 30639 replica.cpp:658] Replica received learned notice for position 11 | |
| I0911 15:39:37.659571 30639 leveldb.cpp:343] Persisting action (1662 bytes) to leveldb took 9.978096ms | |
| I0911 15:39:37.659637 30639 replica.cpp:679] Persisted action at 11 | |
| I0911 15:39:37.659682 30639 replica.cpp:664] Replica learned APPEND action at position 11 | |
| I0911 20:39:37.691 THREAD169 org.apache.aurora.scheduler.mesos.MesosSchedulerImpl.logStatusUpdate: Received status update for task 1442003917623-www-data-devel-test-0-bc7e269b-4dc3-4e91-97bc-15bde98e1acc in state TASK_FAILED from SOURCE_SLAVE with REASON_MEMORY_LIMIT: | |
| I0911 20:39:37.692 THREAD151 com.twitter.common.util.StateMachine$Builder$1.execute: 1442003917623-www-data-devel-test-0-bc7e269b-4dc3-4e91-97bc-15bde98e1acc state machine transition ASSIGNED -> FAILED | |
| I0911 20:39:37.692 THREAD151 org.apache.aurora.scheduler.state.TaskStateMachine.addFollowup: Adding work command INCREMENT_FAILURES for 1442003917623-www-data-devel-test-0-bc7e269b-4dc3-4e91-97bc-15bde98e1acc | |
| I0911 20:39:37.692 THREAD151 org.apache.aurora.scheduler.state.TaskStateMachine.addFollowup: Adding work command RESCHEDULE for 1442003917623-www-data-devel-test-0-bc7e269b-4dc3-4e91-97bc-15bde98e1acc | |
| I0911 20:39:37.692 THREAD151 org.apache.aurora.scheduler.state.TaskStateMachine.addFollowup: Adding work command SAVE_STATE for 1442003917623-www-data-devel-test-0-bc7e269b-4dc3-4e91-97bc-15bde98e1acc | |
| I0911 20:39:37.693 THREAD151 org.apache.aurora.scheduler.state.StateManagerImpl.updateTaskAndExternalState: Task being rescheduled: 1442003917623-www-data-devel-test-0-bc7e269b-4dc3-4e91-97bc-15bde98e1acc | |
| I0911 20:39:37.693 THREAD151 org.apache.aurora.scheduler.async.RescheduleCalculator$RescheduleCalculatorImpl.getFlappingPenaltyMs: Ancestor of 1442003917623-www-data-devel-test-0-bc7e269b-4dc3-4e91-97bc-15bde98e1acc flapped: 1442003916517-www-data-devel-test-0-fbbfd7a0-89bc-4160-b3ee-fa544832ed82 | |
| I0911 20:39:37.693 THREAD151 org.apache.aurora.scheduler.async.RescheduleCalculator$RescheduleCalculatorImpl.getFlappingPenaltyMs: Ancestor of 1442003917623-www-data-devel-test-0-bc7e269b-4dc3-4e91-97bc-15bde98e1acc flapped: 1442003916329-www-data-devel-test-0-f81f3b5c-ff28-4013-9e1b-696945b95e84 | |
| I0911 20:39:37.694 THREAD151 com.twitter.common.util.StateMachine$Builder$1.execute: 1442003977693-www-data-devel-test-0-1a81532d-315c-405b-85d3-a16888ab3d9d state machine transition INIT -> THROTTLED | |
| I0911 20:39:37.694 THREAD151 org.apache.aurora.scheduler.state.TaskStateMachine.addFollowup: Adding work command SAVE_STATE for 1442003977693-www-data-devel-test-0-1a81532d-315c-405b-85d3-a16888ab3d9d | |
| I0911 20:39:37.694 THREAD160 org.apache.aurora.scheduler.async.RescheduleCalculator$RescheduleCalculatorImpl.getFlappingPenaltyMs: Ancestor of 1442003977693-www-data-devel-test-0-1a81532d-315c-405b-85d3-a16888ab3d9d flapped: 1442003917623-www-data-devel-test-0-bc7e269b-4dc3-4e91-97bc-15bde98e1acc | |
| I0911 15:39:37.695178 30639 log.cpp:685] Attempting to append 3194 bytes to the log | |
| I0911 20:39:37.695 THREAD160 org.apache.aurora.scheduler.async.RescheduleCalculator$RescheduleCalculatorImpl.getFlappingPenaltyMs: Ancestor of 1442003977693-www-data-devel-test-0-1a81532d-315c-405b-85d3-a16888ab3d9d flapped: 1442003916517-www-data-devel-test-0-fbbfd7a0-89bc-4160-b3ee-fa544832ed82 | |
| I0911 15:39:37.695401 30643 coordinator.cpp:341] Coordinator attempting to write APPEND action at position 12 | |
| I0911 15:39:37.696012 30645 replica.cpp:511] Replica received write request for position 12 | |
| I0911 20:39:37.695 THREAD160 org.apache.aurora.scheduler.async.RescheduleCalculator$RescheduleCalculatorImpl.getFlappingPenaltyMs: Ancestor of 1442003977693-www-data-devel-test-0-1a81532d-315c-405b-85d3-a16888ab3d9d flapped: 1442003916329-www-data-devel-test-0-f81f3b5c-ff28-4013-9e1b-696945b95e84 | |
| I0911 15:39:37.699733 30645 leveldb.cpp:343] Persisting action (3213 bytes) to leveldb took 3.65844ms | |
| I0911 15:39:37.699801 30645 replica.cpp:679] Persisted action at 12 | |
| I0911 15:39:37.700413 30638 replica.cpp:658] Replica received learned notice for position 12 | |
| I0911 15:39:37.708020 30638 leveldb.cpp:343] Persisting action (3215 bytes) to leveldb took 7.560718ms | |
| I0911 15:39:37.708070 30638 replica.cpp:679] Persisted action at 12 | |
| I0911 15:39:37.708103 30638 replica.cpp:664] Replica learned APPEND action at position 12 | |
| I0911 20:39:56.399 THREAD129 org.apache.aurora.scheduler.http.RequestLogger$1.log: localhost 0:0:0:0:0:0:0:1 [11/Sep/2015:20:39:56 +0000] "GET /task/1442003916517-www-data-devel-test-0-fbbfd7a0-89bc-4160-b3ee-fa544832ed82 HTTP/1.1" 200 0 "-" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/45.0.2454.85 Safari/537.36" 0 | |
| I0911 20:39:56.507 THREAD167 org.apache.aurora.scheduler.http.RequestLogger$1.log: localhost 0:0:0:0:0:0:0:1 [11/Sep/2015:20:39:56 +0000] "GET /favicon.ico HTTP/1.1" 200 0 "http://localhost:8081/task/1442003916517-www-data-devel-test-0-fbbfd7a0-89bc-4160-b3ee-fa544832ed82" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/45.0.2454.85 Safari/537.36" 0 | |
| I0911 20:40:04.198 THREAD131 org.apache.aurora.scheduler.http.RequestLogger$1.log: localhost 0:0:0:0:0:0:0:1 [11/Sep/2015:20:40:04 +0000] "GET /task/1442003916517-www-data-devel-test-0-fbbfd7a0-89bc-4160-b3ee-fa544832ed82 HTTP/1.1" 200 0 "-" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/45.0.2454.85 Safari/537.36" 0 | |
| I0911 20:40:05.198 THREAD129 org.apache.aurora.scheduler.http.RequestLogger$1.log: 127.0.1.1 127.0.0.1 [11/Sep/2015:20:40:05 +0000] "GET /scheduler/www-data/devel/test HTTP/1.1" 200 0 "-" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/45.0.2454.85 Safari/537.36" 0 | |
| I0911 20:40:05.426 THREAD166 org.apache.aurora.scheduler.http.RequestLogger$1.log: 127.0.1.1 127.0.0.1 [11/Sep/2015:20:40:05 +0000] "POST /api HTTP/1.1" 200 0 "http://127.0.1.1:8081/scheduler/www-data/devel/test" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/45.0.2454.85 Safari/537.36" 1 | |
| I0911 20:40:05.427 THREAD166 org.apache.aurora.scheduler.thrift.aop.LoggingInterceptor.invoke: getTasksWithoutConfigs(TaskQuery(owner:Identity(role:www-data, user:null), role:null, environment:devel, jobName:test, taskIds:null, statuses:null, instanceIds:null, slaveHosts:null, jobKeys:null, offset:0, limit:0)) | |
| I0911 20:40:05.427 THREAD168 org.apache.aurora.scheduler.http.RequestLogger$1.log: 127.0.1.1 127.0.0.1 [11/Sep/2015:20:40:05 +0000] "POST /api HTTP/1.1" 200 0 "http://127.0.1.1:8081/scheduler/www-data/devel/test" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/45.0.2454.85 Safari/537.36" 1 | |
| I0911 20:40:05.427 THREAD168 org.apache.aurora.scheduler.thrift.aop.LoggingInterceptor.invoke: getPendingReason(TaskQuery(owner:Identity(role:www-data, user:null), role:null, environment:devel, jobName:test, taskIds:null, statuses:null, instanceIds:null, slaveHosts:null, jobKeys:null, offset:0, limit:0)) | |
| I0911 20:40:05.430 THREAD168 org.apache.aurora.scheduler.http.RequestLogger$1.log: 127.0.1.1 127.0.0.1 [11/Sep/2015:20:40:05 +0000] "POST /api HTTP/1.1" 200 0 "http://127.0.1.1:8081/scheduler/www-data/devel/test" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/45.0.2454.85 Safari/537.36" 0 | |
| I0911 20:40:05.431 THREAD168 org.apache.aurora.scheduler.thrift.aop.LoggingInterceptor.invoke: getConfigSummary(JobKey(role:www-data, environment:devel, name:test)) | |
| I0911 20:40:05.433 THREAD129 org.apache.aurora.scheduler.http.RequestLogger$1.log: 127.0.1.1 127.0.0.1 [11/Sep/2015:20:40:05 +0000] "POST /api HTTP/1.1" 200 0 "http://127.0.1.1:8081/scheduler/www-data/devel/test" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/45.0.2454.85 Safari/537.36" 0 | |
| I0911 20:40:05.434 THREAD129 org.apache.aurora.scheduler.thrift.aop.LoggingInterceptor.invoke: getJobUpdateSummaries(JobUpdateQuery(role:null, key:null, jobKey:JobKey(role:www-data, environment:devel, name:test), user:null, updateStatuses:null, offset:0, limit:0)) | |
| I0911 20:40:05.435 THREAD131 org.apache.aurora.scheduler.http.RequestLogger$1.log: 127.0.1.1 127.0.0.1 [11/Sep/2015:20:40:05 +0000] "POST /api HTTP/1.1" 200 0 "http://127.0.1.1:8081/scheduler/www-data/devel/test" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/45.0.2454.85 Safari/537.36" 0 | |
| I0911 20:40:05.436 THREAD131 org.apache.aurora.scheduler.thrift.aop.LoggingInterceptor.invoke: getJobSummary(www-data) | |
| I0911 20:41:37.694 THREAD145 com.twitter.common.util.StateMachine$Builder$1.execute: 1442003977693-www-data-devel-test-0-1a81532d-315c-405b-85d3-a16888ab3d9d state machine transition THROTTLED -> PENDING | |
| I0911 20:41:37.694 THREAD145 org.apache.aurora.scheduler.state.TaskStateMachine.addFollowup: Adding work command SAVE_STATE for 1442003977693-www-data-devel-test-0-1a81532d-315c-405b-85d3-a16888ab3d9d | |
| I0911 15:41:37.696285 30638 log.cpp:685] Attempting to append 1542 bytes to the log | |
| I0911 15:41:37.696396 30640 coordinator.cpp:341] Coordinator attempting to write APPEND action at position 13 | |
| I0911 15:41:37.696920 30645 replica.cpp:511] Replica received write request for position 13 | |
| I0911 15:41:37.705343 30645 leveldb.cpp:343] Persisting action (1561 bytes) to leveldb took 8.388446ms | |
| I0911 15:41:37.705371 30645 replica.cpp:679] Persisted action at 13 | |
| I0911 15:41:37.705785 30640 replica.cpp:658] Replica received learned notice for position 13 | |
| I0911 15:41:37.709368 30640 leveldb.cpp:343] Persisting action (1563 bytes) to leveldb took 3.559398ms | |
| I0911 15:41:37.709403 30640 replica.cpp:679] Persisted action at 13 | |
| I0911 15:41:37.709429 30640 replica.cpp:664] Replica learned APPEND action at position 13 | |
| I0911 20:41:37.710 THREAD161 com.twitter.common.util.StateMachine$Builder$1.execute: 1442003977693-www-data-devel-test-0-1a81532d-315c-405b-85d3-a16888ab3d9d state machine transition PENDING -> ASSIGNED | |
| I0911 20:41:37.710 THREAD161 org.apache.aurora.scheduler.state.TaskStateMachine.addFollowup: Adding work command SAVE_STATE for 1442003977693-www-data-devel-test-0-1a81532d-315c-405b-85d3-a16888ab3d9d | |
| I0911 20:41:37.711 THREAD161 org.apache.aurora.scheduler.state.TaskAssigner$TaskAssignerImpl.assign: Offer on slave kiriki (id 20150911-153416-16777343-5050-30331-S0) is being assigned task for 1442003977693-www-data-devel-test-0-1a81532d-315c-405b-85d3-a16888ab3d9d. | |
| I0911 15:41:37.712781 30642 log.cpp:685] Attempting to append 1641 bytes to the log | |
| I0911 15:41:37.712883 30641 coordinator.cpp:341] Coordinator attempting to write APPEND action at position 14 | |
| I0911 15:41:37.714035 30642 replica.cpp:511] Replica received write request for position 14 | |
| I0911 15:41:37.717700 30642 leveldb.cpp:343] Persisting action (1660 bytes) to leveldb took 3.611966ms | |
| I0911 15:41:37.717741 30642 replica.cpp:679] Persisted action at 14 | |
| I0911 15:41:37.718186 30643 replica.cpp:658] Replica received learned notice for position 14 | |
| I0911 15:41:37.726176 30643 leveldb.cpp:343] Persisting action (1662 bytes) to leveldb took 7.919379ms | |
| I0911 15:41:37.726341 30643 replica.cpp:679] Persisted action at 14 | |
| I0911 15:41:37.726438 30643 replica.cpp:664] Replica learned APPEND action at position 14 | |
| I0911 20:41:37.844 THREAD171 org.apache.aurora.scheduler.mesos.MesosSchedulerImpl.logStatusUpdate: Received status update for task 1442003977693-www-data-devel-test-0-1a81532d-315c-405b-85d3-a16888ab3d9d in state TASK_FAILED from SOURCE_SLAVE with REASON_MEMORY_LIMIT: | |
| I0911 20:41:37.844 THREAD151 com.twitter.common.util.StateMachine$Builder$1.execute: 1442003977693-www-data-devel-test-0-1a81532d-315c-405b-85d3-a16888ab3d9d state machine transition ASSIGNED -> FAILED | |
| I0911 20:41:37.844 THREAD151 org.apache.aurora.scheduler.state.TaskStateMachine.addFollowup: Adding work command INCREMENT_FAILURES for 1442003977693-www-data-devel-test-0-1a81532d-315c-405b-85d3-a16888ab3d9d | |
| I0911 20:41:37.844 THREAD151 org.apache.aurora.scheduler.state.TaskStateMachine.addFollowup: Adding work command RESCHEDULE for 1442003977693-www-data-devel-test-0-1a81532d-315c-405b-85d3-a16888ab3d9d | |
| I0911 20:41:37.844 THREAD151 org.apache.aurora.scheduler.state.TaskStateMachine.addFollowup: Adding work command SAVE_STATE for 1442003977693-www-data-devel-test-0-1a81532d-315c-405b-85d3-a16888ab3d9d | |
| I0911 20:41:37.845 THREAD151 org.apache.aurora.scheduler.state.StateManagerImpl.updateTaskAndExternalState: Task being rescheduled: 1442003977693-www-data-devel-test-0-1a81532d-315c-405b-85d3-a16888ab3d9d | |
| I0911 20:41:37.845 THREAD151 org.apache.aurora.scheduler.async.RescheduleCalculator$RescheduleCalculatorImpl.getFlappingPenaltyMs: Ancestor of 1442003977693-www-data-devel-test-0-1a81532d-315c-405b-85d3-a16888ab3d9d flapped: 1442003917623-www-data-devel-test-0-bc7e269b-4dc3-4e91-97bc-15bde98e1acc | |
| I0911 20:41:37.845 THREAD151 org.apache.aurora.scheduler.async.RescheduleCalculator$RescheduleCalculatorImpl.getFlappingPenaltyMs: Ancestor of 1442003977693-www-data-devel-test-0-1a81532d-315c-405b-85d3-a16888ab3d9d flapped: 1442003916517-www-data-devel-test-0-fbbfd7a0-89bc-4160-b3ee-fa544832ed82 | |
| I0911 20:41:37.845 THREAD151 org.apache.aurora.scheduler.async.RescheduleCalculator$RescheduleCalculatorImpl.getFlappingPenaltyMs: Ancestor of 1442003977693-www-data-devel-test-0-1a81532d-315c-405b-85d3-a16888ab3d9d flapped: 1442003916329-www-data-devel-test-0-f81f3b5c-ff28-4013-9e1b-696945b95e84 | |
| I0911 20:41:37.846 THREAD151 com.twitter.common.util.StateMachine$Builder$1.execute: 1442004097846-www-data-devel-test-0-808c5f88-9443-418c-8563-10c740208733 state machine transition INIT -> THROTTLED | |
| I0911 20:41:37.846 THREAD151 org.apache.aurora.scheduler.state.TaskStateMachine.addFollowup: Adding work command SAVE_STATE for 1442004097846-www-data-devel-test-0-808c5f88-9443-418c-8563-10c740208733 | |
| I0911 20:41:37.847 THREAD139 org.apache.aurora.scheduler.async.RescheduleCalculator$RescheduleCalculatorImpl.getFlappingPenaltyMs: Ancestor of 1442004097846-www-data-devel-test-0-808c5f88-9443-418c-8563-10c740208733 flapped: 1442003977693-www-data-devel-test-0-1a81532d-315c-405b-85d3-a16888ab3d9d | |
| I0911 20:41:37.847 THREAD139 org.apache.aurora.scheduler.async.RescheduleCalculator$RescheduleCalculatorImpl.getFlappingPenaltyMs: Ancestor of 1442004097846-www-data-devel-test-0-808c5f88-9443-418c-8563-10c740208733 flapped: 1442003917623-www-data-devel-test-0-bc7e269b-4dc3-4e91-97bc-15bde98e1acc | |
| I0911 15:41:37.847280 30642 log.cpp:685] Attempting to append 3195 bytes to the log | |
| I0911 20:41:37.847 THREAD139 org.apache.aurora.scheduler.async.RescheduleCalculator$RescheduleCalculatorImpl.getFlappingPenaltyMs: Ancestor of 1442004097846-www-data-devel-test-0-808c5f88-9443-418c-8563-10c740208733 flapped: 1442003916517-www-data-devel-test-0-fbbfd7a0-89bc-4160-b3ee-fa544832ed82 | |
| I0911 15:41:37.847403 30640 coordinator.cpp:341] Coordinator attempting to write APPEND action at position 15 | |
| I0911 20:41:37.847 THREAD139 org.apache.aurora.scheduler.async.RescheduleCalculator$RescheduleCalculatorImpl.getFlappingPenaltyMs: Ancestor of 1442004097846-www-data-devel-test-0-808c5f88-9443-418c-8563-10c740208733 flapped: 1442003916329-www-data-devel-test-0-f81f3b5c-ff28-4013-9e1b-696945b95e84 | |
| I0911 15:41:37.847939 30642 replica.cpp:511] Replica received write request for position 15 | |
| I0911 15:41:37.856058 30642 leveldb.cpp:343] Persisting action (3214 bytes) to leveldb took 8.083688ms | |
| I0911 15:41:37.856097 30642 replica.cpp:679] Persisted action at 15 | |
| I0911 15:41:37.856593 30641 replica.cpp:658] Replica received learned notice for position 15 | |
| I0911 15:41:37.860301 30641 leveldb.cpp:343] Persisting action (3216 bytes) to leveldb took 3.655747ms | |
| I0911 15:41:37.860340 30641 replica.cpp:679] Persisted action at 15 | |
| I0911 15:41:37.860364 30641 replica.cpp:664] Replica learned APPEND action at position 15 | |
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment