tests/qemu-iotests/219.out

   1 Launching VM...
   2
   3
   4 Starting block job: drive-mirror (auto-finalize: True; auto-dismiss: True)
   5 {"return": {}}
   6 {"return": [{"current-progress": "FILTERED", "id": "job0", "status": "running", "total-progress": "FILTERED", "type": "mirror"}]}
   7 {"data": {"id": "job0", "status": "created"}, "event": "JOB_STATUS_CHANGE", "timestamp": {"microseconds": "USECS", "seconds": "SECS"}}
   8 {"data": {"id": "job0", "status": "running"}, "event": "JOB_STATUS_CHANGE", "timestamp": {"microseconds": "USECS", "seconds": "SECS"}}
   9
  10 Pause/resume in RUNNING
  11 === Testing block-job-pause/block-job-resume ===
  12 {"return": {}}
  13 {"data": {"id": "job0", "status": "paused"}, "event": "JOB_STATUS_CHANGE", "timestamp": {"microseconds": "USECS", "seconds": "SECS"}}
  14 {"return": [{"current-progress": 65536, "id": "job0", "status": "paused", "total-progress": 4194304, "type": "mirror"}]}
  15 {"return": {}}
  16 {"data": {"id": "job0", "status": "running"}, "event": "JOB_STATUS_CHANGE", "timestamp": {"microseconds": "USECS", "seconds": "SECS"}}
  17 {"return": [{"current-progress": 131072, "id": "job0", "status": "running", "total-progress": 4194304, "type": "mirror"}]}
  18 === Testing block-job-pause/job-resume ===
  19 {"return": {}}
  20 {"data": {"id": "job0", "status": "paused"}, "event": "JOB_STATUS_CHANGE", "timestamp": {"microseconds": "USECS", "seconds": "SECS"}}
  21 {"return": [{"current-progress": 131072, "id": "job0", "status": "paused", "total-progress": 4194304, "type": "mirror"}]}
  22 {"return": {}}
  23 {"data": {"id": "job0", "status": "running"}, "event": "JOB_STATUS_CHANGE", "timestamp": {"microseconds": "USECS", "seconds": "SECS"}}
  24 {"return": [{"current-progress": 196608, "id": "job0", "status": "running", "total-progress": 4194304, "type": "mirror"}]}
  25 === Testing job-pause/block-job-resume ===
  26 {"return": {}}
  27 {"data": {"id": "job0", "status": "paused"}, "event": "JOB_STATUS_CHANGE", "timestamp": {"microseconds": "USECS", "seconds": "SECS"}}
  28 {"return": [{"current-progress": 196608, "id": "job0", "status": "paused", "total-progress": 4194304, "type": "mirror"}]}
  29 {"return": {}}
  30 {"data": {"id": "job0", "status": "running"}, "event": "JOB_STATUS_CHANGE", "timestamp": {"microseconds": "USECS", "seconds": "SECS"}}
  31 {"return": [{"current-progress": 262144, "id": "job0", "status": "running", "total-progress": 4194304, "type": "mirror"}]}
  32 === Testing job-pause/job-resume ===
  33 {"return": {}}
  34 {"data": {"id": "job0", "status": "paused"}, "event": "JOB_STATUS_CHANGE", "timestamp": {"microseconds": "USECS", "seconds": "SECS"}}
  35 {"return": [{"current-progress": 262144, "id": "job0", "status": "paused", "total-progress": 4194304, "type": "mirror"}]}
  36 {"return": {}}
  37 {"data": {"id": "job0", "status": "running"}, "event": "JOB_STATUS_CHANGE", "timestamp": {"microseconds": "USECS", "seconds": "SECS"}}
  38 {"return": [{"current-progress": 327680, "id": "job0", "status": "running", "total-progress": 4194304, "type": "mirror"}]}
  39 {"error": {"class": "GenericError", "desc": "Job 'job0' in state 'running' cannot accept command verb 'complete'"}}
  40 {"error": {"class": "GenericError", "desc": "Job 'job0' in state 'running' cannot accept command verb 'finalize'"}}
  41 {"error": {"class": "GenericError", "desc": "Job 'job0' in state 'running' cannot accept command verb 'dismiss'"}}
  42 {"error": {"class": "GenericError", "desc": "Job 'job0' in state 'running' cannot accept command verb 'complete'"}}
  43 {"error": {"class": "GenericError", "desc": "Job 'job0' in state 'running' cannot accept command verb 'finalize'"}}
  44 {"error": {"class": "GenericError", "desc": "Job 'job0' in state 'running' cannot accept command verb 'dismiss'"}}
  45 {"return": {}}
  46
  47 Waiting for READY state...
  48 {"data": {"id": "job0", "status": "ready"}, "event": "JOB_STATUS_CHANGE", "timestamp": {"microseconds": "USECS", "seconds": "SECS"}}
  49 {"return": [{"current-progress": 4194304, "id": "job0", "status": "ready", "total-progress": 4194304, "type": "mirror"}]}
  50
  51 Pause/resume in READY
  52 === Testing block-job-pause/block-job-resume ===
  53 {"return": {}}
  54 {"data": {"id": "job0", "status": "standby"}, "event": "JOB_STATUS_CHANGE", "timestamp": {"microseconds": "USECS", "seconds": "SECS"}}
  55 {"return": [{"current-progress": 4194304, "id": "job0", "status": "standby", "total-progress": 4194304, "type": "mirror"}]}
  56 {"return": {}}
  57 {"data": {"id": "job0", "status": "ready"}, "event": "JOB_STATUS_CHANGE", "timestamp": {"microseconds": "USECS", "seconds": "SECS"}}
  58 {"return": [{"current-progress": 4194304, "id": "job0", "status": "ready", "total-progress": 4194304, "type": "mirror"}]}
  59 === Testing block-job-pause/job-resume ===
  60 {"return": {}}
  61 {"data": {"id": "job0", "status": "standby"}, "event": "JOB_STATUS_CHANGE", "timestamp": {"microseconds": "USECS", "seconds": "SECS"}}
  62 {"return": [{"current-progress": 4194304, "id": "job0", "status": "standby", "total-progress": 4194304, "type": "mirror"}]}
  63 {"return": {}}
  64 {"data": {"id": "job0", "status": "ready"}, "event": "JOB_STATUS_CHANGE", "timestamp": {"microseconds": "USECS", "seconds": "SECS"}}
  65 {"return": [{"current-progress": 4194304, "id": "job0", "status": "ready", "total-progress": 4194304, "type": "mirror"}]}
  66 === Testing job-pause/block-job-resume ===
  67 {"return": {}}
  68 {"data": {"id": "job0", "status": "standby"}, "event": "JOB_STATUS_CHANGE", "timestamp": {"microseconds": "USECS", "seconds": "SECS"}}
  69 {"return": [{"current-progress": 4194304, "id": "job0", "status": "standby", "total-progress": 4194304, "type": "mirror"}]}
  70 {"return": {}}
  71 {"data": {"id": "job0", "status": "ready"}, "event": "JOB_STATUS_CHANGE", "timestamp": {"microseconds": "USECS", "seconds": "SECS"}}
  72 {"return": [{"current-progress": 4194304, "id": "job0", "status": "ready", "total-progress": 4194304, "type": "mirror"}]}
  73 === Testing job-pause/job-resume ===
  74 {"return": {}}
  75 {"data": {"id": "job0", "status": "standby"}, "event": "JOB_STATUS_CHANGE", "timestamp": {"microseconds": "USECS", "seconds": "SECS"}}
  76 {"return": [{"current-progress": 4194304, "id": "job0", "status": "standby", "total-progress": 4194304, "type": "mirror"}]}
  77 {"return": {}}
  78 {"data": {"id": "job0", "status": "ready"}, "event": "JOB_STATUS_CHANGE", "timestamp": {"microseconds": "USECS", "seconds": "SECS"}}
  79 {"return": [{"current-progress": 4194304, "id": "job0", "status": "ready", "total-progress": 4194304, "type": "mirror"}]}
  80 {"error": {"class": "GenericError", "desc": "Job 'job0' in state 'ready' cannot accept command verb 'finalize'"}}
  81 {"error": {"class": "GenericError", "desc": "Job 'job0' in state 'ready' cannot accept command verb 'dismiss'"}}
  82 {"error": {"class": "GenericError", "desc": "Job 'job0' in state 'ready' cannot accept command verb 'finalize'"}}
  83 {"error": {"class": "GenericError", "desc": "Job 'job0' in state 'ready' cannot accept command verb 'dismiss'"}}
  84 {"return": {}}
  85
  86 Waiting for PENDING state...
  87 {"data": {"id": "job0", "status": "waiting"}, "event": "JOB_STATUS_CHANGE", "timestamp": {"microseconds": "USECS", "seconds": "SECS"}}
  88 {"data": {"id": "job0", "status": "pending"}, "event": "JOB_STATUS_CHANGE", "timestamp": {"microseconds": "USECS", "seconds": "SECS"}}
  89 {"data": {"id": "job0", "status": "concluded"}, "event": "JOB_STATUS_CHANGE", "timestamp": {"microseconds": "USECS", "seconds": "SECS"}}
  90 {"data": {"id": "job0", "status": "null"}, "event": "JOB_STATUS_CHANGE", "timestamp": {"microseconds": "USECS", "seconds": "SECS"}}
  91 {"return": []}
  92
  93
  94 Starting block job: drive-backup (auto-finalize: True; auto-dismiss: True)
  95 {"return": {}}
  96 {"return": [{"current-progress": "FILTERED", "id": "job0", "status": "running", "total-progress": "FILTERED", "type": "backup"}]}
  97 {"data": {"id": "job0", "status": "created"}, "event": "JOB_STATUS_CHANGE", "timestamp": {"microseconds": "USECS", "seconds": "SECS"}}
  98 {"data": {"id": "job0", "status": "running"}, "event": "JOB_STATUS_CHANGE", "timestamp": {"microseconds": "USECS", "seconds": "SECS"}}
  99
 100 Pause/resume in RUNNING
 101 === Testing block-job-pause/block-job-resume ===
 102 {"return": {}}
 103 {"data": {"id": "job0", "status": "paused"}, "event": "JOB_STATUS_CHANGE", "timestamp": {"microseconds": "USECS", "seconds": "SECS"}}
 104 {"return": [{"current-progress": 65536, "id": "job0", "status": "paused", "total-progress": 4194304, "type": "backup"}]}
 105 {"return": {}}
 106 {"data": {"id": "job0", "status": "running"}, "event": "JOB_STATUS_CHANGE", "timestamp": {"microseconds": "USECS", "seconds": "SECS"}}
 107 {"return": [{"current-progress": 131072, "id": "job0", "status": "running", "total-progress": 4194304, "type": "backup"}]}
 108 === Testing block-job-pause/job-resume ===
 109 {"return": {}}
 110 {"data": {"id": "job0", "status": "paused"}, "event": "JOB_STATUS_CHANGE", "timestamp": {"microseconds": "USECS", "seconds": "SECS"}}
 111 {"return": [{"current-progress": 131072, "id": "job0", "status": "paused", "total-progress": 4194304, "type": "backup"}]}
 112 {"return": {}}
 113 {"data": {"id": "job0", "status": "running"}, "event": "JOB_STATUS_CHANGE", "timestamp": {"microseconds": "USECS", "seconds": "SECS"}}
 114 {"return": [{"current-progress": 196608, "id": "job0", "status": "running", "total-progress": 4194304, "type": "backup"}]}
 115 === Testing job-pause/block-job-resume ===
 116 {"return": {}}
 117 {"data": {"id": "job0", "status": "paused"}, "event": "JOB_STATUS_CHANGE", "timestamp": {"microseconds": "USECS", "seconds": "SECS"}}
 118 {"return": [{"current-progress": 196608, "id": "job0", "status": "paused", "total-progress": 4194304, "type": "backup"}]}
 119 {"return": {}}
 120 {"data": {"id": "job0", "status": "running"}, "event": "JOB_STATUS_CHANGE", "timestamp": {"microseconds": "USECS", "seconds": "SECS"}}
 121 {"return": [{"current-progress": 262144, "id": "job0", "status": "running", "total-progress": 4194304, "type": "backup"}]}
 122 === Testing job-pause/job-resume ===
 123 {"return": {}}
 124 {"data": {"id": "job0", "status": "paused"}, "event": "JOB_STATUS_CHANGE", "timestamp": {"microseconds": "USECS", "seconds": "SECS"}}
 125 {"return": [{"current-progress": 262144, "id": "job0", "status": "paused", "total-progress": 4194304, "type": "backup"}]}
 126 {"return": {}}
 127 {"data": {"id": "job0", "status": "running"}, "event": "JOB_STATUS_CHANGE", "timestamp": {"microseconds": "USECS", "seconds": "SECS"}}
 128 {"return": [{"current-progress": 327680, "id": "job0", "status": "running", "total-progress": 4194304, "type": "backup"}]}
 129 {"error": {"class": "GenericError", "desc": "Job 'job0' in state 'running' cannot accept command verb 'complete'"}}
 130 {"error": {"class": "GenericError", "desc": "Job 'job0' in state 'running' cannot accept command verb 'finalize'"}}
 131 {"error": {"class": "GenericError", "desc": "Job 'job0' in state 'running' cannot accept command verb 'dismiss'"}}
 132 {"error": {"class": "GenericError", "desc": "Job 'job0' in state 'running' cannot accept command verb 'complete'"}}
 133 {"error": {"class": "GenericError", "desc": "Job 'job0' in state 'running' cannot accept command verb 'finalize'"}}
 134 {"error": {"class": "GenericError", "desc": "Job 'job0' in state 'running' cannot accept command verb 'dismiss'"}}
 135 {"return": {}}
 136
 137 Waiting for PENDING state...
 138 {"data": {"id": "job0", "status": "waiting"}, "event": "JOB_STATUS_CHANGE", "timestamp": {"microseconds": "USECS", "seconds": "SECS"}}
 139 {"data": {"id": "job0", "status": "pending"}, "event": "JOB_STATUS_CHANGE", "timestamp": {"microseconds": "USECS", "seconds": "SECS"}}
 140 {"data": {"id": "job0", "status": "concluded"}, "event": "JOB_STATUS_CHANGE", "timestamp": {"microseconds": "USECS", "seconds": "SECS"}}
 141 {"data": {"id": "job0", "status": "null"}, "event": "JOB_STATUS_CHANGE", "timestamp": {"microseconds": "USECS", "seconds": "SECS"}}
 142 {"return": []}
 143
 144
 145 Starting block job: drive-backup (auto-finalize: True; auto-dismiss: False)
 146 {"return": {}}
 147 {"return": [{"current-progress": "FILTERED", "id": "job0", "status": "running", "total-progress": "FILTERED", "type": "backup"}]}
 148 {"data": {"id": "job0", "status": "created"}, "event": "JOB_STATUS_CHANGE", "timestamp": {"microseconds": "USECS", "seconds": "SECS"}}
 149 {"data": {"id": "job0", "status": "running"}, "event": "JOB_STATUS_CHANGE", "timestamp": {"microseconds": "USECS", "seconds": "SECS"}}
 150
 151 Pause/resume in RUNNING
 152 === Testing block-job-pause/block-job-resume ===
 153 {"return": {}}
 154 {"data": {"id": "job0", "status": "paused"}, "event": "JOB_STATUS_CHANGE", "timestamp": {"microseconds": "USECS", "seconds": "SECS"}}
 155 {"return": [{"current-progress": 65536, "id": "job0", "status": "paused", "total-progress": 4194304, "type": "backup"}]}
 156 {"return": {}}
 157 {"data": {"id": "job0", "status": "running"}, "event": "JOB_STATUS_CHANGE", "timestamp": {"microseconds": "USECS", "seconds": "SECS"}}
 158 {"return": [{"current-progress": 131072, "id": "job0", "status": "running", "total-progress": 4194304, "type": "backup"}]}
 159 === Testing block-job-pause/job-resume ===
 160 {"return": {}}
 161 {"data": {"id": "job0", "status": "paused"}, "event": "JOB_STATUS_CHANGE", "timestamp": {"microseconds": "USECS", "seconds": "SECS"}}
 162 {"return": [{"current-progress": 131072, "id": "job0", "status": "paused", "total-progress": 4194304, "type": "backup"}]}
 163 {"return": {}}
 164 {"data": {"id": "job0", "status": "running"}, "event": "JOB_STATUS_CHANGE", "timestamp": {"microseconds": "USECS", "seconds": "SECS"}}
 165 {"return": [{"current-progress": 196608, "id": "job0", "status": "running", "total-progress": 4194304, "type": "backup"}]}
 166 === Testing job-pause/block-job-resume ===
 167 {"return": {}}
 168 {"data": {"id": "job0", "status": "paused"}, "event": "JOB_STATUS_CHANGE", "timestamp": {"microseconds": "USECS", "seconds": "SECS"}}
 169 {"return": [{"current-progress": 196608, "id": "job0", "status": "paused", "total-progress": 4194304, "type": "backup"}]}
 170 {"return": {}}
 171 {"data": {"id": "job0", "status": "running"}, "event": "JOB_STATUS_CHANGE", "timestamp": {"microseconds": "USECS", "seconds": "SECS"}}
 172 {"return": [{"current-progress": 262144, "id": "job0", "status": "running", "total-progress": 4194304, "type": "backup"}]}
 173 === Testing job-pause/job-resume ===
 174 {"return": {}}
 175 {"data": {"id": "job0", "status": "paused"}, "event": "JOB_STATUS_CHANGE", "timestamp": {"microseconds": "USECS", "seconds": "SECS"}}
 176 {"return": [{"current-progress": 262144, "id": "job0", "status": "paused", "total-progress": 4194304, "type": "backup"}]}
 177 {"return": {}}
 178 {"data": {"id": "job0", "status": "running"}, "event": "JOB_STATUS_CHANGE", "timestamp": {"microseconds": "USECS", "seconds": "SECS"}}
 179 {"return": [{"current-progress": 327680, "id": "job0", "status": "running", "total-progress": 4194304, "type": "backup"}]}
 180 {"error": {"class": "GenericError", "desc": "Job 'job0' in state 'running' cannot accept command verb 'complete'"}}
 181 {"error": {"class": "GenericError", "desc": "Job 'job0' in state 'running' cannot accept command verb 'finalize'"}}
 182 {"error": {"class": "GenericError", "desc": "Job 'job0' in state 'running' cannot accept command verb 'dismiss'"}}
 183 {"error": {"class": "GenericError", "desc": "Job 'job0' in state 'running' cannot accept command verb 'complete'"}}
 184 {"error": {"class": "GenericError", "desc": "Job 'job0' in state 'running' cannot accept command verb 'finalize'"}}
 185 {"error": {"class": "GenericError", "desc": "Job 'job0' in state 'running' cannot accept command verb 'dismiss'"}}
 186 {"return": {}}
 187
 188 Waiting for PENDING state...
 189 {"data": {"id": "job0", "status": "waiting"}, "event": "JOB_STATUS_CHANGE", "timestamp": {"microseconds": "USECS", "seconds": "SECS"}}
 190 {"data": {"id": "job0", "status": "pending"}, "event": "JOB_STATUS_CHANGE", "timestamp": {"microseconds": "USECS", "seconds": "SECS"}}
 191 {"data": {"id": "job0", "status": "concluded"}, "event": "JOB_STATUS_CHANGE", "timestamp": {"microseconds": "USECS", "seconds": "SECS"}}
 192 {"return": [{"current-progress": 4194304, "id": "job0", "status": "concluded", "total-progress": 4194304, "type": "backup"}]}
 193 {"error": {"class": "GenericError", "desc": "Job 'job0' in state 'concluded' cannot accept command verb 'pause'"}}
 194 {"error": {"class": "GenericError", "desc": "Job 'job0' in state 'concluded' cannot accept command verb 'complete'"}}
 195 {"error": {"class": "GenericError", "desc": "Job 'job0' in state 'concluded' cannot accept command verb 'finalize'"}}
 196 {"error": {"class": "GenericError", "desc": "Job 'job0' in state 'concluded' cannot accept command verb 'pause'"}}
 197 {"error": {"class": "GenericError", "desc": "Job 'job0' in state 'concluded' cannot accept command verb 'complete'"}}
 198 {"error": {"class": "GenericError", "desc": "Job 'job0' in state 'concluded' cannot accept command verb 'finalize'"}}
 199 {"return": {}}
 200 {"data": {"id": "job0", "status": "null"}, "event": "JOB_STATUS_CHANGE", "timestamp": {"microseconds": "USECS", "seconds": "SECS"}}
 201 {"return": []}
 202
 203
 204 Starting block job: drive-backup (auto-finalize: False; auto-dismiss: True)
 205 {"return": {}}
 206 {"return": [{"current-progress": "FILTERED", "id": "job0", "status": "running", "total-progress": "FILTERED", "type": "backup"}]}
 207 {"data": {"id": "job0", "status": "created"}, "event": "JOB_STATUS_CHANGE", "timestamp": {"microseconds": "USECS", "seconds": "SECS"}}
 208 {"data": {"id": "job0", "status": "running"}, "event": "JOB_STATUS_CHANGE", "timestamp": {"microseconds": "USECS", "seconds": "SECS"}}
 209
 210 Pause/resume in RUNNING
 211 === Testing block-job-pause/block-job-resume ===
 212 {"return": {}}
 213 {"data": {"id": "job0", "status": "paused"}, "event": "JOB_STATUS_CHANGE", "timestamp": {"microseconds": "USECS", "seconds": "SECS"}}
 214 {"return": [{"current-progress": 65536, "id": "job0", "status": "paused", "total-progress": 4194304, "type": "backup"}]}
 215 {"return": {}}
 216 {"data": {"id": "job0", "status": "running"}, "event": "JOB_STATUS_CHANGE", "timestamp": {"microseconds": "USECS", "seconds": "SECS"}}
 217 {"return": [{"current-progress": 131072, "id": "job0", "status": "running", "total-progress": 4194304, "type": "backup"}]}
 218 === Testing block-job-pause/job-resume ===
 219 {"return": {}}
 220 {"data": {"id": "job0", "status": "paused"}, "event": "JOB_STATUS_CHANGE", "timestamp": {"microseconds": "USECS", "seconds": "SECS"}}
 221 {"return": [{"current-progress": 131072, "id": "job0", "status": "paused", "total-progress": 4194304, "type": "backup"}]}
 222 {"return": {}}
 223 {"data": {"id": "job0", "status": "running"}, "event": "JOB_STATUS_CHANGE", "timestamp": {"microseconds": "USECS", "seconds": "SECS"}}
 224 {"return": [{"current-progress": 196608, "id": "job0", "status": "running", "total-progress": 4194304, "type": "backup"}]}
 225 === Testing job-pause/block-job-resume ===
 226 {"return": {}}
 227 {"data": {"id": "job0", "status": "paused"}, "event": "JOB_STATUS_CHANGE", "timestamp": {"microseconds": "USECS", "seconds": "SECS"}}
 228 {"return": [{"current-progress": 196608, "id": "job0", "status": "paused", "total-progress": 4194304, "type": "backup"}]}
 229 {"return": {}}
 230 {"data": {"id": "job0", "status": "running"}, "event": "JOB_STATUS_CHANGE", "timestamp": {"microseconds": "USECS", "seconds": "SECS"}}
 231 {"return": [{"current-progress": 262144, "id": "job0", "status": "running", "total-progress": 4194304, "type": "backup"}]}
 232 === Testing job-pause/job-resume ===
 233 {"return": {}}
 234 {"data": {"id": "job0", "status": "paused"}, "event": "JOB_STATUS_CHANGE", "timestamp": {"microseconds": "USECS", "seconds": "SECS"}}
 235 {"return": [{"current-progress": 262144, "id": "job0", "status": "paused", "total-progress": 4194304, "type": "backup"}]}
 236 {"return": {}}
 237 {"data": {"id": "job0", "status": "running"}, "event": "JOB_STATUS_CHANGE", "timestamp": {"microseconds": "USECS", "seconds": "SECS"}}
 238 {"return": [{"current-progress": 327680, "id": "job0", "status": "running", "total-progress": 4194304, "type": "backup"}]}
 239 {"error": {"class": "GenericError", "desc": "Job 'job0' in state 'running' cannot accept command verb 'complete'"}}
 240 {"error": {"class": "GenericError", "desc": "Job 'job0' in state 'running' cannot accept command verb 'finalize'"}}
 241 {"error": {"class": "GenericError", "desc": "Job 'job0' in state 'running' cannot accept command verb 'dismiss'"}}
 242 {"error": {"class": "GenericError", "desc": "Job 'job0' in state 'running' cannot accept command verb 'complete'"}}
 243 {"error": {"class": "GenericError", "desc": "Job 'job0' in state 'running' cannot accept command verb 'finalize'"}}
 244 {"error": {"class": "GenericError", "desc": "Job 'job0' in state 'running' cannot accept command verb 'dismiss'"}}
 245 {"return": {}}
 246
 247 Waiting for PENDING state...
 248 {"data": {"id": "job0", "status": "waiting"}, "event": "JOB_STATUS_CHANGE", "timestamp": {"microseconds": "USECS", "seconds": "SECS"}}
 249 {"data": {"id": "job0", "status": "pending"}, "event": "JOB_STATUS_CHANGE", "timestamp": {"microseconds": "USECS", "seconds": "SECS"}}
 250 {"return": [{"current-progress": 4194304, "id": "job0", "status": "pending", "total-progress": 4194304, "type": "backup"}]}
 251 {"error": {"class": "GenericError", "desc": "Job 'job0' in state 'pending' cannot accept command verb 'pause'"}}
 252 {"error": {"class": "GenericError", "desc": "Job 'job0' in state 'pending' cannot accept command verb 'complete'"}}
 253 {"error": {"class": "GenericError", "desc": "Job 'job0' in state 'pending' cannot accept command verb 'dismiss'"}}
 254 {"error": {"class": "GenericError", "desc": "Job 'job0' in state 'pending' cannot accept command verb 'pause'"}}
 255 {"error": {"class": "GenericError", "desc": "Job 'job0' in state 'pending' cannot accept command verb 'complete'"}}
 256 {"error": {"class": "GenericError", "desc": "Job 'job0' in state 'pending' cannot accept command verb 'dismiss'"}}
 257 {"return": {}}
 258 {"data": {"id": "job0", "status": "concluded"}, "event": "JOB_STATUS_CHANGE", "timestamp": {"microseconds": "USECS", "seconds": "SECS"}}
 259 {"data": {"id": "job0", "status": "null"}, "event": "JOB_STATUS_CHANGE", "timestamp": {"microseconds": "USECS", "seconds": "SECS"}}
 260 {"return": []}
 261
 262
 263 Starting block job: drive-backup (auto-finalize: False; auto-dismiss: False)
 264 {"return": {}}
 265 {"return": [{"current-progress": "FILTERED", "id": "job0", "status": "running", "total-progress": "FILTERED", "type": "backup"}]}
 266 {"data": {"id": "job0", "status": "created"}, "event": "JOB_STATUS_CHANGE", "timestamp": {"microseconds": "USECS", "seconds": "SECS"}}
 267 {"data": {"id": "job0", "status": "running"}, "event": "JOB_STATUS_CHANGE", "timestamp": {"microseconds": "USECS", "seconds": "SECS"}}
 268
 269 Pause/resume in RUNNING
 270 === Testing block-job-pause/block-job-resume ===
 271 {"return": {}}
 272 {"data": {"id": "job0", "status": "paused"}, "event": "JOB_STATUS_CHANGE", "timestamp": {"microseconds": "USECS", "seconds": "SECS"}}
 273 {"return": [{"current-progress": 65536, "id": "job0", "status": "paused", "total-progress": 4194304, "type": "backup"}]}
 274 {"return": {}}
 275 {"data": {"id": "job0", "status": "running"}, "event": "JOB_STATUS_CHANGE", "timestamp": {"microseconds": "USECS", "seconds": "SECS"}}
 276 {"return": [{"current-progress": 131072, "id": "job0", "status": "running", "total-progress": 4194304, "type": "backup"}]}
 277 === Testing block-job-pause/job-resume ===
 278 {"return": {}}
 279 {"data": {"id": "job0", "status": "paused"}, "event": "JOB_STATUS_CHANGE", "timestamp": {"microseconds": "USECS", "seconds": "SECS"}}
 280 {"return": [{"current-progress": 131072, "id": "job0", "status": "paused", "total-progress": 4194304, "type": "backup"}]}
 281 {"return": {}}
 282 {"data": {"id": "job0", "status": "running"}, "event": "JOB_STATUS_CHANGE", "timestamp": {"microseconds": "USECS", "seconds": "SECS"}}
 283 {"return": [{"current-progress": 196608, "id": "job0", "status": "running", "total-progress": 4194304, "type": "backup"}]}
 284 === Testing job-pause/block-job-resume ===
 285 {"return": {}}
 286 {"data": {"id": "job0", "status": "paused"}, "event": "JOB_STATUS_CHANGE", "timestamp": {"microseconds": "USECS", "seconds": "SECS"}}
 287 {"return": [{"current-progress": 196608, "id": "job0", "status": "paused", "total-progress": 4194304, "type": "backup"}]}
 288 {"return": {}}
 289 {"data": {"id": "job0", "status": "running"}, "event": "JOB_STATUS_CHANGE", "timestamp": {"microseconds": "USECS", "seconds": "SECS"}}
 290 {"return": [{"current-progress": 262144, "id": "job0", "status": "running", "total-progress": 4194304, "type": "backup"}]}
 291 === Testing job-pause/job-resume ===
 292 {"return": {}}
 293 {"data": {"id": "job0", "status": "paused"}, "event": "JOB_STATUS_CHANGE", "timestamp": {"microseconds": "USECS", "seconds": "SECS"}}
 294 {"return": [{"current-progress": 262144, "id": "job0", "status": "paused", "total-progress": 4194304, "type": "backup"}]}
 295 {"return": {}}
 296 {"data": {"id": "job0", "status": "running"}, "event": "JOB_STATUS_CHANGE", "timestamp": {"microseconds": "USECS", "seconds": "SECS"}}
 297 {"return": [{"current-progress": 327680, "id": "job0", "status": "running", "total-progress": 4194304, "type": "backup"}]}
 298 {"error": {"class": "GenericError", "desc": "Job 'job0' in state 'running' cannot accept command verb 'complete'"}}
 299 {"error": {"class": "GenericError", "desc": "Job 'job0' in state 'running' cannot accept command verb 'finalize'"}}
 300 {"error": {"class": "GenericError", "desc": "Job 'job0' in state 'running' cannot accept command verb 'dismiss'"}}
 301 {"error": {"class": "GenericError", "desc": "Job 'job0' in state 'running' cannot accept command verb 'complete'"}}
 302 {"error": {"class": "GenericError", "desc": "Job 'job0' in state 'running' cannot accept command verb 'finalize'"}}
 303 {"error": {"class": "GenericError", "desc": "Job 'job0' in state 'running' cannot accept command verb 'dismiss'"}}
 304 {"return": {}}
 305
 306 Waiting for PENDING state...
 307 {"data": {"id": "job0", "status": "waiting"}, "event": "JOB_STATUS_CHANGE", "timestamp": {"microseconds": "USECS", "seconds": "SECS"}}
 308 {"data": {"id": "job0", "status": "pending"}, "event": "JOB_STATUS_CHANGE", "timestamp": {"microseconds": "USECS", "seconds": "SECS"}}
 309 {"return": [{"current-progress": 4194304, "id": "job0", "status": "pending", "total-progress": 4194304, "type": "backup"}]}
 310 {"error": {"class": "GenericError", "desc": "Job 'job0' in state 'pending' cannot accept command verb 'pause'"}}
 311 {"error": {"class": "GenericError", "desc": "Job 'job0' in state 'pending' cannot accept command verb 'complete'"}}
 312 {"error": {"class": "GenericError", "desc": "Job 'job0' in state 'pending' cannot accept command verb 'dismiss'"}}
 313 {"error": {"class": "GenericError", "desc": "Job 'job0' in state 'pending' cannot accept command verb 'pause'"}}
 314 {"error": {"class": "GenericError", "desc": "Job 'job0' in state 'pending' cannot accept command verb 'complete'"}}
 315 {"error": {"class": "GenericError", "desc": "Job 'job0' in state 'pending' cannot accept command verb 'dismiss'"}}
 316 {"return": {}}
 317 {"data": {"id": "job0", "status": "concluded"}, "event": "JOB_STATUS_CHANGE", "timestamp": {"microseconds": "USECS", "seconds": "SECS"}}
 318 {"return": [{"current-progress": 4194304, "id": "job0", "status": "concluded", "total-progress": 4194304, "type": "backup"}]}
 319 {"error": {"class": "GenericError", "desc": "Job 'job0' in state 'concluded' cannot accept command verb 'pause'"}}
 320 {"error": {"class": "GenericError", "desc": "Job 'job0' in state 'concluded' cannot accept command verb 'complete'"}}
 321 {"error": {"class": "GenericError", "desc": "Job 'job0' in state 'concluded' cannot accept command verb 'finalize'"}}
 322 {"error": {"class": "GenericError", "desc": "Job 'job0' in state 'concluded' cannot accept command verb 'pause'"}}
 323 {"error": {"class": "GenericError", "desc": "Job 'job0' in state 'concluded' cannot accept command verb 'complete'"}}
 324 {"error": {"class": "GenericError", "desc": "Job 'job0' in state 'concluded' cannot accept command verb 'finalize'"}}
 325 {"return": {}}
 326 {"data": {"id": "job0", "status": "null"}, "event": "JOB_STATUS_CHANGE", "timestamp": {"microseconds": "USECS", "seconds": "SECS"}}
 327 {"return": []}