Attachment 902567 Details for Bug 1105195 – successful reproducer screen log

successful reproducer screen log

screen.log (text/plain), 17.19 KB, created by mkovacik on 2014-06-05 14:55:19 UTC

(hide)

Description:

Filename:

MIME Type:

Creator: mkovacik

Created: 2014-06-05 14:55:19 UTC

Size: 17.19 KB

patch

obsolete

>[root@ec2-79-125-97-56 ~]# ./reproducer-2.sh
>### ./reproducer-2.sh iteration: 1
>Reversed (or previously applied) patch detected!  Skipping patch.
>2 out of 2 hunks ignored -- saving rejects to file /usr/lib/python2.7/site-packages/pulp/server/async/scheduler.py.rej
>MongoDB shell version: 2.4.6
>connecting to: pulp_database
>[object Object]
>Thu Jun  5 14:29:12 UTC 2014
>sleeping 3 seconds for pulp-settling-down reason
>Thu Jun  5 14:29:15 UTC 2014
>Successfully created repository [zoo]
>
>pulp_worker-0.service - Pulp Worker #0
>   Loaded: loaded (/run/systemd/system/pulp_worker-0.service; static)
>   Active: failed (Result: signal) since Thu 2014-06-05 14:29:18 UTC; 137ms ago
>  Process: 5235 ExecStart=/usr/bin/celery worker -n reserved_resource_worker-0@%%h -A pulp.server.async.app -c 1 --events (code=killed, signal=KILL)
> Main PID: 5235 (code=killed, signal=KILL)
>
>Jun 05 14:29:17 ec2-79-125-97-56.eu-west-1.compute.amazonaws.com pulp[5235]: qpid.messaging:DEBUG: RACK[3db7680]: Message(subject='broker', reply_to='qmf.default.topic/direct.8ac308d8-ab67-490e-b540-90cd78ac7ec2;{node:{ty... '_method_req
>Jun 05 14:29:17 ec2-79-125-97-56.eu-west-1.compute.amazonaws.com pulp[5235]: qpid.messaging:DEBUG: RCVD[3db7680]: Message(correlation_id='2', properties={u'qmf.agent': u'broker', u'qmf.opcode': u'_exception', 'x-amqp-0-10.app-id': 'qm...
>Jun 05 14:29:17 ec2-79-125-97-56.eu-west-1.compute.amazonaws.com pulp[5235]: qpid.messaging:DEBUG: RETR[3db7680]: Message(correlation_id='2', properties={u'qmf.agent': u'broker', u'qmf.opcode': u'_exception', 'x-amqp-0-10.app-id': 'qm...
>Jun 05 14:29:17 ec2-79-125-97-56.eu-west-1.compute.amazonaws.com pulp[5235]: qpid.messaging:DEBUG: SENT[3db7290]: Message(subject='worker.online', properties={'qpid.subject': 'worker.online'}, content={'body': <read-only ...mpute.amazona
>Jun 05 14:29:17 ec2-79-125-97-56.eu-west-1.compute.amazonaws.com pulp[5235]: qpid.messaging:DEBUG: RACK[3db7290]: Message(subject='worker.online', properties={'qpid.subject': 'worker.online'}, content={'body': <read-only ...mpute.amazona
>Jun 05 14:29:17 ec2-79-125-97-56.eu-west-1.compute.amazonaws.com pulp[5235]: celery.bootsteps:DEBUG: ^-- substep ok
>Jun 05 14:29:17 ec2-79-125-97-56.eu-west-1.compute.amazonaws.com pulp[5235]: celery.bootsteps:DEBUG: | Consumer: Starting event loop
>Jun 05 14:29:17 ec2-79-125-97-56.eu-west-1.compute.amazonaws.com pulp[5235]: kombu.common:DEBUG: basic.qos: prefetch_count->4
>Jun 05 14:29:18 ec2-79-125-97-56.eu-west-1.compute.amazonaws.com systemd[1]: pulp_worker-0.service: main process exited, code=killed, status=9/KILL
>Jun 05 14:29:18 ec2-79-125-97-56.eu-west-1.compute.amazonaws.com systemd[1]: Unit pulp_worker-0.service entered failed state.
>
>pulp_worker-1.service - Pulp Worker #1
>   Loaded: loaded (/run/systemd/system/pulp_worker-1.service; static)
>   Active: failed (Result: signal) since Thu 2014-06-05 14:29:18 UTC; 159ms ago
>  Process: 5236 ExecStart=/usr/bin/celery worker -n reserved_resource_worker-1@%%h -A pulp.server.async.app -c 1 --events (code=killed, signal=KILL)
> Main PID: 5236 (code=killed, signal=KILL)
>
>Jun 05 14:29:17 ec2-79-125-97-56.eu-west-1.compute.amazonaws.com pulp[5236]: qpid.messaging:DEBUG: cardsTtl': 0, u'messageLatencyAvg': 0, u'byteTotalEnqueues': 0, u'msgDepth': 0, u'byteTxnDequeues': 0}, u'_update_ts': 140...7397963726}])
>Jun 05 14:29:17 ec2-79-125-97-56.eu-west-1.compute.amazonaws.com pulp[5236]: qpid.messaging:DEBUG: SENT[2bd33f8]: Message(subject='broker', reply_to='qmf.default.topic/direct.ebc365c3-f267-4bfd-bf5a-fc97c47718ee;{node:{ty... '_method_req
>Jun 05 14:29:17 ec2-79-125-97-56.eu-west-1.compute.amazonaws.com pulp[5236]: qpid.messaging:DEBUG: RACK[2bd33f8]: Message(subject='broker', reply_to='qmf.default.topic/direct.ebc365c3-f267-4bfd-bf5a-fc97c47718ee;{node:{ty... '_method_req
>Jun 05 14:29:17 ec2-79-125-97-56.eu-west-1.compute.amazonaws.com pulp[5236]: qpid.messaging:DEBUG: RCVD[2bd33f8]: Message(correlation_id='4', properties={u'qmf.agent': u'broker', u'qmf.opcode': u'_method_response', 'x-amq...uments': {}})
>Jun 05 14:29:17 ec2-79-125-97-56.eu-west-1.compute.amazonaws.com pulp[5236]: qpid.messaging:DEBUG: RETR[2bd33f8]: Message(correlation_id='4', properties={u'qmf.agent': u'broker', u'qmf.opcode': u'_method_response', 'x-amq...uments': {}})
>Jun 05 14:29:17 ec2-79-125-97-56.eu-west-1.compute.amazonaws.com pulp[5236]: celery.bootsteps:DEBUG: ^-- substep ok
>Jun 05 14:29:17 ec2-79-125-97-56.eu-west-1.compute.amazonaws.com pulp[5236]: celery.bootsteps:DEBUG: | Consumer: Starting event loop
>Jun 05 14:29:17 ec2-79-125-97-56.eu-west-1.compute.amazonaws.com pulp[5236]: kombu.common:DEBUG: basic.qos: prefetch_count->4
>Jun 05 14:29:18 ec2-79-125-97-56.eu-west-1.compute.amazonaws.com systemd[1]: pulp_worker-1.service: main process exited, code=killed, status=9/KILL
>Jun 05 14:29:18 ec2-79-125-97-56.eu-west-1.compute.amazonaws.com systemd[1]: Unit pulp_worker-1.service entered failed state.
>Hint: Some lines were ellipsized, use -l to show in full.
>  reserved_resource_worker-0@ec2-79-125-97-56.eu-west-1.compute.amazonaws.com.celery.pidbox       Y                 0     0      0       0      0        0         0     2
>  reserved_resource_worker-0@ec2-79-125-97-56.eu-west-1.compute.amazonaws.com.dq             Y    Y                 0     0      0       0      0        0         0     2
>  reserved_resource_worker-1@ec2-79-125-97-56.eu-west-1.compute.amazonaws.com.celery.pidbox       Y                 0     0      0       0      0        0         0     2
>  reserved_resource_worker-1@ec2-79-125-97-56.eu-west-1.compute.amazonaws.com.dq             Y    Y                 0     0      0       0      0        0         0     2
># mongo pulp_database.available_queues:
>{
>        "_id" : "reserved_resource_worker-1@ec2-79-125-97-56.eu-west-1.compute.amazonaws.com",
>        "last_heartbeat" : ISODate("2014-06-05T14:29:16.813Z"),
>        "num_reservations" : 0
>}
>
>missing queue: reserved_resource_worker-0, restarting
>### ./reproducer-2.sh iteration: 1
>[root@ec2-79-125-97-56 ~]# Reversed (or previously applied) patch detected!  Skipping patch.
>2 out of 2 hunks ignored -- saving rejects to file /usr/lib/python2.7/site-packages/pulp/server/async/scheduler.py.rej
>MongoDB shell version: 2.4.6
>connecting to: pulp_database
>[object Object]
>Thu Jun  5 14:29:22 UTC 2014
>sleeping 3 seconds for pulp-settling-down reason
>Thu Jun  5 14:29:26 UTC 2014
>Successfully created repository [zoo]
>
>pulp_worker-0.service - Pulp Worker #0
>   Loaded: loaded (/run/systemd/system/pulp_worker-0.service; static)
>   Active: failed (Result: signal) since Thu 2014-06-05 14:29:29 UTC; 109ms ago
>  Process: 5472 ExecStart=/usr/bin/celery worker -n reserved_resource_worker-0@%%h -A pulp.server.async.app -c 1 --events (code=killed, signal=KILL)
> Main PID: 5472 (code=killed, signal=KILL)
>
>Jun 05 14:29:28 ec2-79-125-97-56.eu-west-1.compute.amazonaws.com pulp[5472]: qpid.messaging:DEBUG: cardsTtl': 0, u'messageLatencyAvg': 0, u'byteTotalEnqueues': 0, u'msgDepth': 0, u'byteTxnDequeues': 0}, u'_update_ts': 140...8422076305}])
>Jun 05 14:29:28 ec2-79-125-97-56.eu-west-1.compute.amazonaws.com pulp[5472]: qpid.messaging:DEBUG: SENT[268eab8]: Message(subject='broker', reply_to='qmf.default.topic/direct.c99bf2fb-7038-4c4c-842c-1efc4570dc47;{node:{ty... '_method_req
>Jun 05 14:29:28 ec2-79-125-97-56.eu-west-1.compute.amazonaws.com pulp[5472]: qpid.messaging:DEBUG: RACK[268eab8]: Message(subject='broker', reply_to='qmf.default.topic/direct.c99bf2fb-7038-4c4c-842c-1efc4570dc47;{node:{ty... '_method_req
>Jun 05 14:29:28 ec2-79-125-97-56.eu-west-1.compute.amazonaws.com pulp[5472]: qpid.messaging:DEBUG: RCVD[268eab8]: Message(correlation_id='4', properties={u'qmf.agent': u'broker', u'qmf.opcode': u'_method_response', 'x-amq...uments': {}})
>Jun 05 14:29:28 ec2-79-125-97-56.eu-west-1.compute.amazonaws.com pulp[5472]: qpid.messaging:DEBUG: RETR[268eab8]: Message(correlation_id='4', properties={u'qmf.agent': u'broker', u'qmf.opcode': u'_method_response', 'x-amq...uments': {}})
>Jun 05 14:29:28 ec2-79-125-97-56.eu-west-1.compute.amazonaws.com pulp[5472]: celery.bootsteps:DEBUG: ^-- substep ok
>Jun 05 14:29:28 ec2-79-125-97-56.eu-west-1.compute.amazonaws.com pulp[5472]: celery.bootsteps:DEBUG: | Consumer: Starting event loop
>Jun 05 14:29:28 ec2-79-125-97-56.eu-west-1.compute.amazonaws.com pulp[5472]: kombu.common:DEBUG: basic.qos: prefetch_count->4
>Jun 05 14:29:29 ec2-79-125-97-56.eu-west-1.compute.amazonaws.com systemd[1]: pulp_worker-0.service: main process exited, code=killed, status=9/KILL
>Jun 05 14:29:29 ec2-79-125-97-56.eu-west-1.compute.amazonaws.com systemd[1]: Unit pulp_worker-0.service entered failed state.
>
>pulp_worker-1.service - Pulp Worker #1
>   Loaded: loaded (/run/systemd/system/pulp_worker-1.service; static)
>   Active: failed (Result: signal) since Thu 2014-06-05 14:29:29 UTC; 118ms ago
>  Process: 5473 ExecStart=/usr/bin/celery worker -n reserved_resource_worker-1@%%h -A pulp.server.async.app -c 1 --events (code=killed, signal=KILL)
> Main PID: 5473 (code=killed, signal=KILL)
>
>Jun 05 14:29:28 ec2-79-125-97-56.eu-west-1.compute.amazonaws.com celery[5473]: - *** --- * --- .> concurrency: 1 (prefork)
>Jun 05 14:29:28 ec2-79-125-97-56.eu-west-1.compute.amazonaws.com celery[5473]: -- ******* ----
>Jun 05 14:29:28 ec2-79-125-97-56.eu-west-1.compute.amazonaws.com celery[5473]: --- ***** ----- [queues]
>Jun 05 14:29:28 ec2-79-125-97-56.eu-west-1.compute.amazonaws.com celery[5473]: -------------- .> celery           exchange=celery(direct) key=celery
>Jun 05 14:29:28 ec2-79-125-97-56.eu-west-1.compute.amazonaws.com celery[5473]: .> reserved_resource_worker-1@ec2-79-125-97-56.eu-west-1.compute.amazonaws.com.dq exchange=C.dq(direct) key=reserved_resource_worker-1@ec2-79-...amazonaws.com
>Jun 05 14:29:28 ec2-79-125-97-56.eu-west-1.compute.amazonaws.com pulp[5473]: celery.bootsteps:DEBUG: ^-- substep ok
>Jun 05 14:29:28 ec2-79-125-97-56.eu-west-1.compute.amazonaws.com pulp[5473]: celery.bootsteps:DEBUG: | Consumer: Starting event loop
>Jun 05 14:29:28 ec2-79-125-97-56.eu-west-1.compute.amazonaws.com pulp[5473]: kombu.common:DEBUG: basic.qos: prefetch_count->4
>Jun 05 14:29:29 ec2-79-125-97-56.eu-west-1.compute.amazonaws.com systemd[1]: pulp_worker-1.service: main process exited, code=killed, status=9/KILL
>Jun 05 14:29:29 ec2-79-125-97-56.eu-west-1.compute.amazonaws.com systemd[1]: Unit pulp_worker-1.service entered failed state.
>Hint: Some lines were ellipsized, use -l to show in full.
>  reserved_resource_worker-0@ec2-79-125-97-56.eu-west-1.compute.amazonaws.com.celery.pidbox       Y                 0     0      0       0      0        0         0     2
>  reserved_resource_worker-0@ec2-79-125-97-56.eu-west-1.compute.amazonaws.com.dq             Y    Y                 0     0      0       0      0        0         0     2
>  reserved_resource_worker-1@ec2-79-125-97-56.eu-west-1.compute.amazonaws.com.celery.pidbox       Y                 0     0      0       0      0        0         0     2
>  reserved_resource_worker-1@ec2-79-125-97-56.eu-west-1.compute.amazonaws.com.dq             Y    Y                 0     0      0       0      0        0         0     2
>        "_id" : "reserved_resource_worker-0@ec2-79-125-97-56.eu-west-1.compute.amazonaws.com",
>        "_id" : "reserved_resource_worker-1@ec2-79-125-97-56.eu-west-1.compute.amazonaws.com",
># mongo pulp_database.available_queues:
>{
>        "_id" : "reserved_resource_worker-0@ec2-79-125-97-56.eu-west-1.compute.amazonaws.com",
>        "last_heartbeat" : ISODate("2014-06-05T14:29:27.784Z"),
>        "num_reservations" : 0
>}
>{
>        "_id" : "reserved_resource_worker-1@ec2-79-125-97-56.eu-west-1.compute.amazonaws.com",
>        "last_heartbeat" : ISODate("2014-06-05T14:29:28.127Z"),
>        "num_reservations" : 0
>}
>
># mongo pulp_database.reserved_resources:
>
># mongo pulp_database.task_status:
>
>Thu Jun  5 14:29:30 UTC 2014
>sleeping 3 seconds for pulp-sync-run reason
>+----------------------------------------------------------------------+
>                     Synchronizing Repository [zoo]
>+----------------------------------------------------------------------+
>
>This command may be exited via ctrl+c without affecting the request.
>
>
>[-]
>Waiting to begin...
>Thu Jun  5 14:29:33 UTC 2014
># mongo pulp_database.available_queues:
>{
>        "_id" : "reserved_resource_worker-0@ec2-79-125-97-56.eu-west-1.compute.amazonaws.com",
>        "last_heartbeat" : ISODate("2014-06-05T14:29:27.784Z"),
>        "num_reservations" : 0
>}
>{
>        "_id" : "reserved_resource_worker-1@ec2-79-125-97-56.eu-west-1.compute.amazonaws.com",
>        "last_heartbeat" : ISODate("2014-06-05T14:29:28.127Z"),
>        "num_reservations" : 1
>}
>./reproducer-2.sh: line 18:  5677 Terminated              pulp-admin -u admin -p admin rpm repo sync run --repo-id zoo
>
># mongo pulp_database.reserved_resources:
>{
>        "_id" : "repository:zoo",
>        "_ns" : "reserved_resources",
>        "num_reservations" : 1,
>        "assigned_queue" : "reserved_resource_worker-1@ec2-79-125-97-56.eu-west-1.compute.amazonaws.com.dq"
>}
>
># mongo pulp_database.task_status:
>{
>        "_id" : ObjectId("53907ecb97a7b3a8a952c111"),
>        "error" : null,
>        "exception" : null,
>        "finish_time" : null,
>        "id" : "53907ecbbcb62b1566c18c80",
>        "progress_report" : {
>
>        },
>        "queue" : "reserved_resource_worker-1@ec2-79-125-97-56.eu-west-1.compute.amazonaws.com.dq",
>        "result" : null,
>        "spawned_tasks" : [ ],
>        "start_time" : null,
>        "state" : "waiting",
>        "tags" : [
>                "pulp:repository:zoo",
>                "pulp:action:sync"
>        ],
>        "task_id" : "a137a301-09a3-42d7-8dac-366bd69ea46a",
>        "task_type" : "pulp.server.tasks.repository.sync_with_auto_publish",
>        "traceback" : null
>}
>
>Thu Jun  5 14:29:33 UTC 2014
>sleeping 60 seconds for WorkerTimeoutMonitor-pick-up-to-happen reason
>Thu Jun  5 14:30:33 UTC 2014
># mongo pulp_database.available_queues:
>
># mongo pulp_database.reserved_resources:
>{
>        "_id" : "repository:zoo",
>        "_ns" : "reserved_resources",
>        "num_reservations" : 1,
>        "assigned_queue" : "reserved_resource_worker-1@ec2-79-125-97-56.eu-west-1.compute.amazonaws.com.dq"
>}
>
># mongo pulp_database.task_status:
>{
>        "_id" : ObjectId("53907ecb97a7b3a8a952c111"),
>        "error" : null,
>        "exception" : null,
>        "finish_time" : null,
>        "id" : "53907ecbbcb62b1566c18c80",
>        "progress_report" : {
>
>        },
>        "queue" : "reserved_resource_worker-1@ec2-79-125-97-56.eu-west-1.compute.amazonaws.com.dq",
>        "result" : null,
>        "spawned_tasks" : [ ],
>        "start_time" : null,
>        "state" : "waiting",
>        "tags" : [
>                "pulp:repository:zoo",
>                "pulp:action:sync"
>        ],
>        "task_id" : "a137a301-09a3-42d7-8dac-366bd69ea46a",
>        "task_type" : "pulp.server.tasks.repository.sync_with_auto_publish",
>        "traceback" : null
>}
>
># mongo pulp_database.available_queues:
>
># mongo pulp_database.reserved_resources:
>{
>        "_id" : "repository:zoo",
>        "_ns" : "reserved_resources",
>        "num_reservations" : 1,
>        "assigned_queue" : "reserved_resource_worker-1@ec2-79-125-97-56.eu-west-1.compute.amazonaws.com.dq"
>}
>
># mongo pulp_database.task_status:
>{
>        "_id" : ObjectId("53907ecb97a7b3a8a952c111"),
>        "error" : null,
>        "exception" : null,
>        "finish_time" : null,
>        "id" : "53907ecbbcb62b1566c18c80",
>        "progress_report" : {
>
>        },
>        "queue" : "reserved_resource_worker-1@ec2-79-125-97-56.eu-west-1.compute.amazonaws.com.dq",
>        "result" : null,
>        "spawned_tasks" : [ ],
>        "start_time" : null,
>        "state" : "waiting",
>        "tags" : [
>                "pulp:repository:zoo",
>                "pulp:action:sync"
>        ],
>        "task_id" : "a137a301-09a3-42d7-8dac-366bd69ea46a",
>        "task_type" : "pulp.server.tasks.repository.sync_with_auto_publish",
>        "traceback" : null
>}
>
>active
>active
>Thu Jun  5 14:30:34 UTC 2014
>sleeping 60 seconds for pending-tasks-settling-down reason
>Thu Jun  5 14:31:34 UTC 2014
># mongo pulp_database.available_queues:
>{
>        "_id" : "reserved_resource_worker-0@ec2-79-125-97-56.eu-west-1.compute.amazonaws.com",
>        "last_heartbeat" : ISODate("2014-06-05T14:31:33.325Z"),
>        "num_reservations" : 0
>}
>{
>        "_id" : "reserved_resource_worker-1@ec2-79-125-97-56.eu-west-1.compute.amazonaws.com",
>        "last_heartbeat" : ISODate("2014-06-05T14:31:32.618Z"),
>        "num_reservations" : 0
>}
>
># mongo pulp_database.reserved_resources:
>{
>        "_id" : "repository:zoo",
>        "_ns" : "reserved_resources",
>        "num_reservations" : 1,
>        "assigned_queue" : "reserved_resource_worker-1@ec2-79-125-97-56.eu-west-1.compute.amazonaws.com.dq"
>}
>
># mongo pulp_database.task_status:
>{
>        "_id" : ObjectId("53907ecb97a7b3a8a952c111"),
>        "error" : null,
>        "exception" : null,
>        "finish_time" : null,
>        "id" : "53907ecbbcb62b1566c18c80",
>        "progress_report" : {
>
>        },
>        "queue" : "reserved_resource_worker-1@ec2-79-125-97-56.eu-west-1.compute.amazonaws.com.dq",
>        "result" : null,
>        "spawned_tasks" : [ ],
>        "start_time" : null,
>        "state" : "waiting",
>        "tags" : [
>                "pulp:repository:zoo",
>                "pulp:action:sync"
>        ],
>        "task_id" : "a137a301-09a3-42d7-8dac-366bd69ea46a",
>        "task_type" : "pulp.server.tasks.repository.sync_with_auto_publish",
>        "traceback" : null
>}
>
>Thu Jun  5 14:31:34 UTC 2014
>
>[root@ec2-79-125-97-56 ~]#

Actions: View

Attachments on bug 1105195: 902566 | 902567 | 917436 | 918412