Page MenuHomePhabricator
Paste P13080

push-notifications log without user information
ActivePublic

Authored by MSantos on Oct 27 2020, 9:03 PM.
Oct 27 20:27:47 deployment-push-notifications01 systemd[1]: Started Systemd runner for mediawiki-services-push-notifications.
Oct 27 20:27:50 deployment-push-notifications01 docker[30720]: {"name":"push-notifications","hostname":"6d9fe27845e5","pid":1,"level":40,"levelPath":"warn/queueing","msg":"Initialized queue: max size: 9007199254740991, flush timeout (ms): 10000","time":"2020-10-27T20:27:50.149Z","v":0}
Oct 27 20:27:50 deployment-push-notifications01 docker[30720]: {"name":"push-notifications","hostname":"6d9fe27845e5","pid":1,"level":30,"levelPath":"info","msg":"Worker 1 listening on 0.0.0.0:8900","time":"2020-10-27T20:27:50.326Z","v":0}
Oct 27 20:29:14 deployment-push-notifications01 docker[30720]: {"name":"push-notifications","hostname":"6d9fe27845e5","pid":1,"level":10,"msg":"Incoming request","request_id":"142a0790-1893-11eb-aee9-5bd4fc1b3418","request":{"url":"/v1/message/fcm","headers":{"user-agent":"Mozilla/5.0 (Macintosh; Intel Mac OS X 10.15; rv:81.0) Gecko/20100101 Firefox/81.0","content-type":"application/json","content-length":"70","x-request-id":"142a0790-1893-11eb-aee9-5bd4fc1b3418"},"method":"POST","params":{"0":"/v1/message/fcm"},"query":{},"remoteAddress":"172.17.0.1","remotePort":44834},"levelPath":"trace/req","time":"2020-10-27T20:29:14.251Z","v":0}
Oct 27 20:29:24 deployment-push-notifications01 docker[30720]: {"name":"push-notifications","hostname":"6d9fe27845e5","pid":1,"level":20,"levelPath":"debug/fcm","msg":"Successfully sent 0 messages; 1 messages failed","time":"2020-10-27T20:29:24.501Z","v":0}
Oct 27 20:29:24 deployment-push-notifications01 docker[30720]: REQUEST { headers:
Oct 27 20:29:24 deployment-push-notifications01 docker[30720]: { host: 'meta.wikimedia.beta.wmflabs.org',
Oct 27 20:29:24 deployment-push-notifications01 docker[30720]: 'user-agent': 'push-notifications (beta)',
Oct 27 20:29:24 deployment-push-notifications01 docker[30720]: 'x-forwarded-proto': 'https' },
Oct 27 20:29:24 deployment-push-notifications01 docker[30720]: method: 'post',
Oct 27 20:29:24 deployment-push-notifications01 docker[30720]: uri:
Oct 27 20:29:24 deployment-push-notifications01 docker[30720]: 'http://deployment-mediawiki-07.deployment-prep.eqiad1.wikimedia.cloud/w/api.php',
Oct 27 20:29:24 deployment-push-notifications01 docker[30720]: jar: true,
Oct 27 20:29:24 deployment-push-notifications01 docker[30720]: form:
Oct 27 20:29:24 deployment-push-notifications01 docker[30720]: { action: 'query', format: 'json', meta: 'tokens', type: 'csrf' },
Oct 27 20:29:24 deployment-push-notifications01 docker[30720]: maxAttempts: NaN,
Oct 27 20:29:24 deployment-push-notifications01 docker[30720]: timeout: 120000,
Oct 27 20:29:24 deployment-push-notifications01 docker[30720]: encoding: null,
Oct 27 20:29:24 deployment-push-notifications01 docker[30720]: agentClass: [Function: ConnectTimeoutAgent],
Oct 27 20:29:24 deployment-push-notifications01 docker[30720]: agentOptions: { connectTimeout: 5000, maxSockets: 250 },
Oct 27 20:29:24 deployment-push-notifications01 docker[30720]: delayStrategy: [Function],
Oct 27 20:29:24 deployment-push-notifications01 docker[30720]: promiseFactory: [Function],
Oct 27 20:29:24 deployment-push-notifications01 docker[30720]: retryStrategy: [Function],
Oct 27 20:29:24 deployment-push-notifications01 docker[30720]: retryDelay: 5000,
Oct 27 20:29:24 deployment-push-notifications01 docker[30720]: fullResponse: true,
Oct 27 20:29:24 deployment-push-notifications01 docker[30720]: callback: [Function: bound ] }
Oct 27 20:29:24 deployment-push-notifications01 docker[30720]: REQUEST make request http://deployment-mediawiki-07.deployment-prep.eqiad1.wikimedia.cloud/w/api.php
Oct 27 20:29:24 deployment-push-notifications01 docker[30720]: REQUEST with cookie undefined
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: REQUEST onRequestResponse http://deployment-mediawiki-07.deployment-prep.eqiad1.wikimedia.cloud/w/api.php 200 { date: 'Tue, 27 Oct 2020 20:29:24 GMT',
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: server: 'deployment-mediawiki-07.deployment-prep.eqiad.wmflabs',
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: 'x-powered-by': 'PHP/7.2.31-1+0~20200514.41+debian9~1.gbpe2a56b+wmf1',
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: 'x-content-type-options': 'nosniff',
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: p3p:
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: 'CP="See https://meta.wikimedia.beta.wmflabs.org/wiki/Special:CentralAutoLogin/P3P for more info."',
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: 'x-analytics': 'ns=-1;special=Badtitle',
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: 'x-frame-options': 'DENY',
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: 'content-disposition': 'inline; filename=api-result.json',
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: 'cache-control': 'private, must-revalidate, max-age=0',
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: vary: 'Accept-Encoding',
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: 'x-request-id': 'X5iDJKwQBHcAACBO03wAAAAR',
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: 'backend-timing': 'D=460985 t=1603830564605410',
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: 'keep-alive': 'timeout=2, max=150',
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: connection: 'Keep-Alive',
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: 'transfer-encoding': 'chunked',
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: 'content-type': 'application/json; charset=utf-8' }
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: REQUEST reading response's body
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: REQUEST finish init function http://deployment-mediawiki-07.deployment-prep.eqiad1.wikimedia.cloud/w/api.php
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: REQUEST response end http://deployment-mediawiki-07.deployment-prep.eqiad1.wikimedia.cloud/w/api.php 200 { date: 'Tue, 27 Oct 2020 20:29:24 GMT',
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: server: 'deployment-mediawiki-07.deployment-prep.eqiad.wmflabs',
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: 'x-powered-by': 'PHP/7.2.31-1+0~20200514.41+debian9~1.gbpe2a56b+wmf1',
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: 'x-content-type-options': 'nosniff',
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: p3p:
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: 'CP="See https://meta.wikimedia.beta.wmflabs.org/wiki/Special:CentralAutoLogin/P3P for more info."',
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: 'x-analytics': 'ns=-1;special=Badtitle',
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: 'x-frame-options': 'DENY',
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: 'content-disposition': 'inline; filename=api-result.json',
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: 'cache-control': 'private, must-revalidate, max-age=0',
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: vary: 'Accept-Encoding',
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: 'x-request-id': 'X5iDJKwQBHcAACBO03wAAAAR',
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: 'backend-timing': 'D=460985 t=1603830564605410',
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: 'keep-alive': 'timeout=2, max=150',
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: connection: 'Keep-Alive',
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: 'transfer-encoding': 'chunked',
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: 'content-type': 'application/json; charset=utf-8' }
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: REQUEST end event http://deployment-mediawiki-07.deployment-prep.eqiad1.wikimedia.cloud/w/api.php
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: REQUEST has body http://deployment-mediawiki-07.deployment-prep.eqiad1.wikimedia.cloud/w/api.php 59
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: REQUEST emitting complete http://deployment-mediawiki-07.deployment-prep.eqiad1.wikimedia.cloud/w/api.php
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: REQUEST { headers:
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: { host: 'meta.wikimedia.beta.wmflabs.org',
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: 'user-agent': 'push-notifications (beta)',
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: 'x-forwarded-proto': 'https' },
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: method: 'post',
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: uri:
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: 'http://deployment-mediawiki-07.deployment-prep.eqiad1.wikimedia.cloud/w/api.php',
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: jar: true,
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: form:
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: { action: 'query', format: 'json', meta: 'tokens', type: 'login' },
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: maxAttempts: NaN,
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: timeout: 120000,
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: encoding: null,
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: agentClass: [Function: ConnectTimeoutAgent],
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: agentOptions: { connectTimeout: 5000, maxSockets: 250 },
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: delayStrategy: [Function],
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: promiseFactory: [Function],
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: retryStrategy: [Function],
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: retryDelay: 5000,
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: fullResponse: true,
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: callback: [Function: bound ] }
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: REQUEST make request http://deployment-mediawiki-07.deployment-prep.eqiad1.wikimedia.cloud/w/api.php
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: REQUEST with cookie undefined
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: REQUEST onRequestResponse http://deployment-mediawiki-07.deployment-prep.eqiad1.wikimedia.cloud/w/api.php 200 { date: 'Tue, 27 Oct 2020 20:29:25 GMT',
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: server: 'deployment-mediawiki-07.deployment-prep.eqiad.wmflabs',
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: 'x-powered-by': 'PHP/7.2.31-1+0~20200514.41+debian9~1.gbpe2a56b+wmf1',
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: 'x-content-type-options': 'nosniff',
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: p3p:
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: 'CP="See https://meta.wikimedia.beta.wmflabs.org/wiki/Special:CentralAutoLogin/P3P for more info."',
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: 'x-analytics': 'ns=-1;special=Badtitle',
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: 'x-frame-options': 'DENY',
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: 'content-disposition': 'inline; filename=api-result.json',
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: 'cache-control': 'private, must-revalidate, max-age=0',
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: vary: 'Accept-Encoding',
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: 'x-request-id': 'X5iDJawQBHcAACBO030AAAAS',
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: 'set-cookie':
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: [ 'ss0-metawikiSession=k687shd2o6j1tj1ong68jn7ls6qh8ktt; path=/; secure; HttpOnly',
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: 'metawikiSession=k687shd2o6j1tj1ong68jn7ls6qh8ktt; path=/; secure; HttpOnly; SameSite=None' ],
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: 'backend-timing': 'D=69225 t=1603830565108690',
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: 'keep-alive': 'timeout=2, max=150',
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: connection: 'Keep-Alive',
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: 'transfer-encoding': 'chunked',
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: 'content-type': 'application/json; charset=utf-8' }
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: REQUEST reading response's body
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: REQUEST finish init function http://deployment-mediawiki-07.deployment-prep.eqiad1.wikimedia.cloud/w/api.php
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: REQUEST response end http://deployment-mediawiki-07.deployment-prep.eqiad1.wikimedia.cloud/w/api.php 200 { date: 'Tue, 27 Oct 2020 20:29:25 GMT',
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: server: 'deployment-mediawiki-07.deployment-prep.eqiad.wmflabs',
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: 'x-powered-by': 'PHP/7.2.31-1+0~20200514.41+debian9~1.gbpe2a56b+wmf1',
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: 'x-content-type-options': 'nosniff',
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: p3p:
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: 'CP="See https://meta.wikimedia.beta.wmflabs.org/wiki/Special:CentralAutoLogin/P3P for more info."',
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: 'x-analytics': 'ns=-1;special=Badtitle',
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: 'x-frame-options': 'DENY',
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: 'content-disposition': 'inline; filename=api-result.json',
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: 'cache-control': 'private, must-revalidate, max-age=0',
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: vary: 'Accept-Encoding',
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: 'x-request-id': 'X5iDJawQBHcAACBO030AAAAS',
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: 'set-cookie':
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: [ 'ss0-metawikiSession=k687shd2o6j1tj1ong68jn7ls6qh8ktt; path=/; secure; HttpOnly',
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: 'metawikiSession=k687shd2o6j1tj1ong68jn7ls6qh8ktt; path=/; secure; HttpOnly; SameSite=None' ],
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: 'backend-timing': 'D=69225 t=1603830565108690',
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: 'keep-alive': 'timeout=2, max=150',
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: connection: 'Keep-Alive',
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: 'transfer-encoding': 'chunked',
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: 'content-type': 'application/json; charset=utf-8' }
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: REQUEST end event http://deployment-mediawiki-07.deployment-prep.eqiad1.wikimedia.cloud/w/api.php
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: REQUEST has body http://deployment-mediawiki-07.deployment-prep.eqiad1.wikimedia.cloud/w/api.php 100
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: REQUEST emitting complete http://deployment-mediawiki-07.deployment-prep.eqiad1.wikimedia.cloud/w/api.php
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: REQUEST { headers:
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: { host: 'meta.wikimedia.beta.wmflabs.org',
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: 'user-agent': 'push-notifications (beta)',
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: 'x-forwarded-proto': 'https' },
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: method: 'post',
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: uri:
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: 'http://deployment-mediawiki-07.deployment-prep.eqiad1.wikimedia.cloud/w/api.php',
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: jar: true,
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: form:
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: { action: 'clientlogin',
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: format: 'json',
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: username: 'Username',
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: password: 'password',
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: loginreturnurl: 'https://example.com',
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: logintoken: '0cd126e611e9e96523f940661b9532b55f988325+\\' },
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: maxAttempts: NaN,
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: timeout: 120000,
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: encoding: null,
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: agentClass: [Function: ConnectTimeoutAgent],
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: agentOptions: { connectTimeout: 5000, maxSockets: 250 },
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: delayStrategy: [Function],
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: promiseFactory: [Function],
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: retryStrategy: [Function],
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: retryDelay: 5000,
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: fullResponse: true,
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: callback: [Function: bound ] }
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: REQUEST make request http://deployment-mediawiki-07.deployment-prep.eqiad1.wikimedia.cloud/w/api.php
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: REQUEST with cookie undefined
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: REQUEST onRequestResponse http://deployment-mediawiki-07.deployment-prep.eqiad1.wikimedia.cloud/w/api.php 200 { date: 'Tue, 27 Oct 2020 20:29:25 GMT',
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: server: 'deployment-mediawiki-07.deployment-prep.eqiad.wmflabs',
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: 'x-powered-by': 'PHP/7.2.31-1+0~20200514.41+debian9~1.gbpe2a56b+wmf1',
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: 'x-content-type-options': 'nosniff',
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: p3p:
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: 'CP="See https://meta.wikimedia.beta.wmflabs.org/wiki/Special:CentralAutoLogin/P3P for more info."',
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: 'mediawiki-api-error': 'badtoken',
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: 'x-frame-options': 'DENY',
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: 'content-disposition': 'inline; filename=api-result.json',
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: 'cache-control': 'private, must-revalidate, max-age=0',
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: vary: 'Accept-Encoding',
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: 'x-request-id': 'X5iDJawQBHcAACBO034AAAAV',
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: 'set-cookie':
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: [ 'ss0-metawikiSession=6c7kne4drokifet1qa7l0epr2c9bchfg; path=/; secure; HttpOnly',
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: 'metawikiSession=6c7kne4drokifet1qa7l0epr2c9bchfg; path=/; secure; HttpOnly; SameSite=None' ],
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: 'backend-timing': 'D=74484 t=1603830565215809',
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: 'keep-alive': 'timeout=2, max=150',
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: connection: 'Keep-Alive',
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: 'transfer-encoding': 'chunked',
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: 'content-type': 'application/json; charset=utf-8' }
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: REQUEST reading response's body
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: REQUEST finish init function http://deployment-mediawiki-07.deployment-prep.eqiad1.wikimedia.cloud/w/api.php
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: REQUEST response end http://deployment-mediawiki-07.deployment-prep.eqiad1.wikimedia.cloud/w/api.php 200 { date: 'Tue, 27 Oct 2020 20:29:25 GMT',
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: server: 'deployment-mediawiki-07.deployment-prep.eqiad.wmflabs',
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: 'x-powered-by': 'PHP/7.2.31-1+0~20200514.41+debian9~1.gbpe2a56b+wmf1',
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: 'x-content-type-options': 'nosniff',
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: p3p:
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: 'CP="See https://meta.wikimedia.beta.wmflabs.org/wiki/Special:CentralAutoLogin/P3P for more info."',
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: 'mediawiki-api-error': 'badtoken',
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: 'x-frame-options': 'DENY',
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: 'content-disposition': 'inline; filename=api-result.json',
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: 'cache-control': 'private, must-revalidate, max-age=0',
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: vary: 'Accept-Encoding',
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: 'x-request-id': 'X5iDJawQBHcAACBO034AAAAV',
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: 'set-cookie':
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: [ 'ss0-metawikiSession=6c7kne4drokifet1qa7l0epr2c9bchfg; path=/; secure; HttpOnly',
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: 'metawikiSession=6c7kne4drokifet1qa7l0epr2c9bchfg; path=/; secure; HttpOnly; SameSite=None' ],
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: 'backend-timing': 'D=74484 t=1603830565215809',
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: 'keep-alive': 'timeout=2, max=150',
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: connection: 'Keep-Alive',
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: 'transfer-encoding': 'chunked',
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: 'content-type': 'application/json; charset=utf-8' }
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: REQUEST end event http://deployment-mediawiki-07.deployment-prep.eqiad1.wikimedia.cloud/w/api.php
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: REQUEST has body http://deployment-mediawiki-07.deployment-prep.eqiad1.wikimedia.cloud/w/api.php 355
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: REQUEST emitting complete http://deployment-mediawiki-07.deployment-prep.eqiad1.wikimedia.cloud/w/api.php
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: {"name":"push-notifications","hostname":"6d9fe27845e5","pid":1,"level":50,"err":{"message":"200: api_error","name":"push-notifications","stack":"HTTPError: 200: api_error\n at preq.then (/srv/service/dist/lib/api-util.js:44:19)\n at tryCatcher (/srv/service/node_modules/bluebird/js/release/util.js:16:23)\n at Promise._settlePromiseFromHandler (/srv/service/node_modules/bluebird/js/release/promise.js:547:31)\n at Promise._settlePromise (/srv/service/node_modules/bluebird/js/release/promise.js:604:18)\n at Promise._settlePromise0 (/srv/service/node_modules/bluebird/js/release/promise.js:649:10)\n at Promise._settlePromises (/srv/service/node_modules/bluebird/js/release/promise.js:729:18)\n at _drainQueueStep (/srv/service/node_modules/bluebird/js/release/async.js:93:12)\n at _drainQueue (/srv/service/node_modules/bluebird/js/release/async.js:86:9)\n at Async._drainQueues (/srv/service/node_modules/bluebird/js/release/async.js:102:5)\n at Immediate.Async.drainQueues [as _onImmediate] (/srv/service/node_modules/bluebird/js/release/async.js:15:14)\n at runCallback (timers.js:705:18)\n at tryOnImmediate (timers.js:676:5)\n at processImmediate (timers.js:658:5)","status":200,"type":"api_error","title":"badtoken","detail":"Invalid CSRF token.","levelPath":"error/login"},"msg":"200: api_error","time":"2020-10-27T20:29:25.310Z","v":0}
Oct 27 20:29:25 deployment-push-notifications01 docker[30720]: {"name":"push-notifications","hostname":"6d9fe27845e5","pid":1,"level":20,"err":{"message":"200: api_error","name":"push-notifications","stack":"HTTPError: 200: api_error\n at preq.then (/srv/service/dist/lib/api-util.js:44:19)\n at tryCatcher (/srv/service/node_modules/bluebird/js/release/util.js:16:23)\n at Promise._settlePromiseFromHandler (/srv/service/node_modules/bluebird/js/release/promise.js:547:31)\n at Promise._settlePromise (/srv/service/node_modules/bluebird/js/release/promise.js:604:18)\n at Promise._settlePromise0 (/srv/service/node_modules/bluebird/js/release/promise.js:649:10)\n at Promise._settlePromises (/srv/service/node_modules/bluebird/js/release/promise.js:729:18)\n at _drainQueueStep (/srv/service/node_modules/bluebird/js/release/async.js:93:12)\n at _drainQueue (/srv/service/node_modules/bluebird/js/release/async.js:86:9)\n at Async._drainQueues (/srv/service/node_modules/bluebird/js/release/async.js:102:5)\n at Immediate.Async.drainQueues [as _onImmediate] (/srv/service/node_modules/bluebird/js/release/async.js:15:14)\n at runCallback (timers.js:705:18)\n at tryOnImmediate (timers.js:676:5)\n at processImmediate (timers.js:658:5)","status":200,"type":"api_error","title":"badtoken","detail":"Invalid CSRF token.","levelPath":"debug"},"msg":"200: api_error","time":"2020-10-27T20:29:25.314Z","v":0}
client_loop: send disconnect: Broken pipe

Event Timeline

@Joe I tried passing x-forwareded-proto: https, but it didn't work out. I remember Michael talking about problems with session cookies not being satisfied by the service, do you think that is what happening here?

The error is Invalid CSRF token., although the credentials are ok.

@Joe I tried to reproduce this with curl commands without success.

mbsantos@deployment-push-notifications01:~$ curl -c cookies_mw --request GET 'http://deployment-mediawiki-07.deployment-prep.eqiad1.wikimedia.cloud/w/api.php?action=query&meta=tokens&format=json&type=login' \
>  --header 'host: meta.wikimedia.beta.wmflabs.org'
{"batchcomplete":"","warnings":{"main":{"*":"HTTP used when HTTPS was expected.\nSubscribe to the mediawiki-api-announce mailing list at <https://lists.wikimedia.org/mailman/listinfo/mediawiki-api-announce> for notice of API deprecations and breaking changes. Use [[Special:ApiFeatureUsage]] to see usage of deprecated features by your application."}},"query":{"tokens":{"logintoken":"cfe5886901f21f5ac7685aa1e32836e15f99bb23+\\"}}}
mbsantos@deployment-push-notifications01:~$ curl -b cookies_mw --location --request POST 'http://deployment-mediawiki-07.deployment-prep.eqiad1.wikimedia.cloud/w/api.php?format=json' \
> --header 'host: meta.wikimedia.beta.wmflabs.org' \
> --header 'Content-Type: application/x-www-form-urlencoded' \
> --data-urlencode 'action=login' \
> --data-urlencode 'lgname=PushSubscriptionManager2' \
> --data-urlencode 'lgpassword=password' \
> --data-urlencode 'lgtoken=cfe5886901f21f5ac7685aa1e32836e15f99bb23+\'
{"warnings":{"main":{"*":"HTTP used when HTTPS was expected.\nSubscribe to the mediawiki-api-announce mailing list at <https://lists.wikimedia.org/mailman/listinfo/mediawiki-api-announce> for notice of API deprecations and breaking changes. Use [[Special:ApiFeatureUsage]] to see usage of deprecated features by your application."}},"login":{"result":"Failed","reason":"Unable to continue login. Your session most likely timed out."}}
mbsantos@deployment-push-notifications01:~$ cat cookies_mw 
# Netscape HTTP Cookie File
# https://curl.haxx.se/docs/http-cookies.html
# This file was generated by libcurl! Edit at your own risk.

Apparently no cookies are returned. The internal endpoint is the only problem, because the public endpoint does return cookies, see:

mbsantos@deployment-push-notifications01:~$  curl -c cookies_mw --request GET 'https://meta.wikimedia.beta.wmflabs.org/w/api.php?action=query&meta=tokens&format=json&type=login'
{"batchcomplete":"","query":{"tokens":{"logintoken":"d48b4354e50284488ce5ea780b2758255f99bc90+\\"}}}mbsantos@deployment-push-notifications01:~$ curl -b cookies_mw --location --request POST 'https://meta.wikimedia.beta.wmflabs.org/w/api.php?format=json' \
> --header 'Content-Type: application/x-www-form-urlencoded' \
> --data-urlencode 'action=login' \
> --data-urlencode 'lgname=PushSubscriptionManager2' \
> --data-urlencode 'lgpassword=password' \
> --data-urlencode 'lgtoken=d48b4354e50284488ce5ea780b2758255f99bc90+\'
{"warnings":{"main":{"*":"Subscribe to the mediawiki-api-announce mailing list at <https://lists.wikimedia.org/mailman/listinfo/mediawiki-api-announce> for notice of API deprecations and breaking changes. Use [[Special:ApiFeatureUsage]] to see usage of deprecated features by your application."},"login":{"*":"Main-account login via \"action=login\" is deprecated and may stop working without warning. To continue login with \"action=login\", see [[Special:BotPasswords]]. To safely continue using main-account login, see \"action=clientlogin\"."}},"login":{"result":"Success","lguserid":44629,"lgusername":"PushSubscriptionManager2"}}
mbsantos@deployment-push-notifications01:~$ cat cookies_mw 
# Netscape HTTP Cookie File
# https://curl.haxx.se/docs/http-cookies.html
# This file was generated by libcurl! Edit at your own risk.

.beta.wmflabs.org	TRUE	/	TRUE	0	GeoIP	:::::v4
#HttpOnly_.wikimedia.beta.wmflabs.org	TRUE	/	TRUE	1606651200	WMF-Last-Access-Global	28-Oct-2020
#HttpOnly_meta.wikimedia.beta.wmflabs.org	FALSE	/	TRUE	1606651200	WMF-Last-Access	28-Oct-2020
#HttpOnly_meta.wikimedia.beta.wmflabs.org	FALSE	/	TRUE	0	metawikiSession	s3fn6f5fidt5eit92cd3s420agbchr8j
#HttpOnly_meta.wikimedia.beta.wmflabs.org	FALSE	/	TRUE	0	ss0-metawikiSession	s3fn6f5fidt5eit92cd3s420agbchr8j
mbsantos@deployment-push-notifications01:~$

I don't think a change in the service would suffice and probably there is no way to use the internal endpoint in the beta cluster. Could that also be an issue in the production environment?