Help with weird PHP-FPM nginx behavior

Re: Help with weird PHP-FPM nginx behavior

by Jorge Villalon -
Number of replies: 0
Hi Paul,

Thanks for taking the time, there are many errors from last night (now everything is quiet around 7am). I extracted one for each different one I found:

2016/05/16 23:01:31 [error] 13301#13301: *28757 FastCGI sent in stderr: "Unable to open primary script: /data/moodle/moodle/local/mobile/check.php (No such file or dire
ctory)" while reading response header from upstream, client: 201.214.113.239, server: our.moodle.com, request: "POST /local/mobile/check.php HTTP/1.1", upstream: "fas
tcgi://unix:/var/run/php5-fpm.sock2:", host: "our.moodle.com"
2016/05/16 23:01:33 [error] 13296#13296: *28485 FastCGI sent in stderr: "PHP message: Array
(
    [uid] => 52268
    [enrol] => self
    [course] => 31539
)
PHP message: Array
(
    [uid] => 52268
    [enrol] => meta
    [course] => 6067
)
PHP message: Array
(
    [uid] => 52268
    [enrol] => meta
    [course] => 32490
)" while reading response header from upstream, client: 190.153.205.0, server: our.moodle.com, request: "POST /enrol/index.php HTTP/1.1", upstream: "fastcgi://unix:/v
ar/run/php5-fpm.sock:", host: "our.moodle.com", referrer: "http://our.moodle.com/enrol/index.php?id=31539"
2016/05/16 23:01:37 [error] 13304#13304: *28711 FastCGI sent in stderr: "PHP message: Database transaction aborted automatically in /data/moodle/moodle/mod/quiz/process
attempt.php" while reading response header from upstream, client: 190.161.164.184, server: our.moodle.com, request: "POST /mod/quiz/processattempt.php HTTP/1.1", upst
ream: "fastcgi://unix:/var/run/php5-fpm.sock2:", host: "our.moodle.com", referrer: "http://our.moodle.com/mod/quiz/summary.php?attempt=596764"
2016/05/16 23:07:15 [error] 13296#13296: *35205 FastCGI sent in stderr: "PHP message: Array
(
    [uid] => 48205
    [enrol] => self
    [course] => 31033
)" while reading response header from upstream, client: 191.115.58.96, server: our.moodle.com, request: "POST /enrol/index.php HTTP/1.1", upstream: "fastcgi://unix:/v
ar/run/php5-fpm.sock2:", host: "our.moodle.com", referrer: "http://our.moodle.com/enrol/index.php?id=31033"

The database transaction aborted appears only once, and it might be related to a php-fpm restart. All others appear hundreds of times.

EDIT: The slow queries log is quite short with 2 seconds max query time. The most common query to show is the following one:

# Time: 160516 22:53:10
# User@Host: webcursos[webcursos] @  [10.50.200.37]
# Thread_id: 345941  Schema: webcursos  QC_hit: No
# Query_time: 3.152203  Lock_time: 0.001689  Rows_sent: 1600  Rows_examined: 808174
SET timestamp=1463449990;
(SELECT ctx.path, rc.roleid, rc.capability, rc.permission
                     FROM mdl_role_capabilities rc
                     JOIN mdl_context ctx
                          ON (ctx.id = rc.contextid)
                     JOIN mdl_context pctx
                          ON (pctx.id = '1'
                              AND (ctx.id = pctx.id
                                   OR ctx.path LIKE CONCAT(pctx.path, '/%')
                                   OR pctx.path LIKE CONCAT(ctx.path, '/%')))
                LEFT JOIN mdl_block_instances bi
                          ON (ctx.contextlevel = 80 AND bi.id = ctx.instanceid)
                LEFT JOIN mdl_context bpctx
                          ON (bpctx.id = bi.parentcontextid)
                    WHERE rc.roleid = '7'
                          AND (ctx.contextlevel <= 50 OR bpctx.contextlevel < 50)
                   )
UNION
(SELECT ctx.path, rc.roleid, rc.capability, rc.permission
                     FROM mdl_role_capabilities rc
                     JOIN mdl_context ctx
                          ON (ctx.id = rc.contextid)
                     JOIN mdl_context pctx
                          ON (pctx.id = '2769'
                              AND (ctx.id = pctx.id
                                   OR ctx.path LIKE CONCAT(pctx.path, '/%')
                                   OR pctx.path LIKE CONCAT(ctx.path, '/%')))
                LEFT JOIN mdl_block_instances bi
                          ON (ctx.contextlevel = 80 AND bi.id = ctx.instanceid)
                LEFT JOIN mdl_context bpctx
                          ON (bpctx.id = bi.parentcontextid)
                    WHERE rc.roleid = '19'
                          AND (ctx.contextlevel <= 50 OR bpctx.contextlevel < 50)
                   )
UNION
(SELECT ctx.path, rc.roleid, rc.capability, rc.permission
                     FROM mdl_role_capabilities rc
                     JOIN mdl_context ctx
                          ON (ctx.id = rc.contextid)
                     JOIN mdl_context pctx
                          ON (pctx.id IN ('23','481756')
                              AND (ctx.id = pctx.id
                                   OR ctx.path LIKE CONCAT(pctx.path, '/%')
                                   OR pctx.path LIKE CONCAT(ctx.path, '/%')))
                LEFT JOIN mdl_block_instances bi
                          ON (ctx.contextlevel = 80 AND bi.id = ctx.instanceid)
                LEFT JOIN mdl_context bpctx
                          ON (bpctx.id = bi.parentcontextid)
                    WHERE rc.roleid = '2'
                          AND (ctx.contextlevel <= 50 OR bpctx.contextlevel < 50)
                   )
UNION
(SELECT ctx.path, rc.roleid, rc.capability, rc.permission
                     FROM mdl_role_capabilities rc
                     JOIN mdl_context ctx
                          ON (ctx.id = rc.contextid)
                     JOIN mdl_context pctx
                          ON (pctx.id IN ('31622','50813','67963','67992','67994','68257','68260','68275','71521','71944','87228','87248','87252','87262','87264','87287
','118279','118297','118298','118319','118333','122099','148821','148823','149132','149177','171435','171443','171807','171833','171848','171849','171864','171866','171
876','171878','171891','171903','171913','171924','171925','171935','171943','171945','171958','171960','182280','182313','182339','182346','184531','188774','190058','
190261','190828','194698','200630','207502','207515','207518','207520','207523','207525','207530','207565','207567','207584','210349','210376','210406','210410','210425
','210954','212014','215627','217095','217132','217134','217144','217154','218837','223567','224193','231398','231409','231413','239870','239883','239884','239888','239
889','239892','239895','239896','239898','242656','242668','242685','242687','242739','242741','242742','242744','247644','249008','258490','267631','267641','267845','
267855','267856','267857','267858','267868','267869','267870','267871','267872','267873','267874','267884','267885','267913','267923','267942','267952','267980','267999
','268009','268028','268117','268118','268119','268537','269193','269196','269270','269272','278429','290069','290070','291324','294104','294119','294128','294229','294
267','298731','298744','298762','303371','306794','306808','313967','313970','313983','316362','316744','316759','316761','316771','316777','316779','316780','317191','
317192','317195','317225','317226','317228','317230','317240','317245','317247','317250','317341','317345','317362','317388','317706','319856','319857','319859','320196
','320543','321056','321058','321069','321090','321094','321097','329320','330394','330404','330405','330407','330408','330409','343490','344320','346639','350170','350
181','352470','352481','352613','352623','352624','352637','352638','352639','352640','352642','352652','353216','353227','355470','357944','367053','368251','376391','
376485','376495','376497','376498','376499','376786','376797','376808','376809','376810','376811','376821','376822','376823','376824','376825','376826','376847','376857
','376867','376868','376869','376882','376883','376885','376886','376887','376889','376890','376891','376892','376893','386635','387064','387070','387076','387082','414
467','414475','414480','414485','414490','414496','416168','425810','425817','425822','425829','425837','425843','425851','425862','425871','425879','426248','426281','
426289','426295','426301','426490','426502','426515','426522','426527','426540','426548','426554','426561','426576','426585','426656','426663','426668','426691','429395
','429522','430028','430065','431456','431462','433368','434225','434233','435297','451954','453827','455490','458042','458053','458182','458213','458223','458231','458
238','458259','458268','458275','458280','458285','458294','458309','458318','458327','458335','458342','458347','458355','458361','458368','458374','458379','458384','
458394','458402','458545','458559','458567','460958','462817','462824','462829','464393','466935','467878','479708','484536','484558','484563','484568','484573','484584
','484591','484597','484603','484608','484614','484620','484625','484630','484677','484682','484687','484697','484702','484707','484712','484718','484723','484728','485
611','486113','496063','496073','496079','496086','496970','497786','521705','521738','521745','521757','521763','521776','521786','521794','521807','521814','525386','
525394','525403','526864','526873','526879','526887','526893','526898','526906','527295','527345','527356','527398','527408','527419','527430','527438','527451','527456
','529680','529689','529701','543752','543757','543763','548578','551082','554860','557500','561236','561270','561282','561372','561378','561387','561394','561400','561
412','561419','561428','561441','561463','561468','561474','561480','561506','561511','561519','561525','561530','561537','561583','561589','561596','561601','561606','
561612','561617','561622','562463','562514','562532','562541','563308','577548','582278','582284','582289','582294','582299','582305','582310','582318','582324','582331
','582338','582343','582351','582357','582362','582367','582372','582377','582382','582388','582393','582398','582432','582448','582454','582460','582491','582497','582
503','582509','582515','582537','582543','582548','582555','582560','582566','582571','582580','582585','582591','582597','582603','582608','582614','605668','613344','613376','617367','617373','617378','621455','630395','630401','630409','630543','630578','630585','630593','630611','630617','630631','630640','630646','630655','631065
','631074','631084','631469','631475','631484','631995','632006','632014','632022','632031','633466','633475','633483','633492','633501','633507','633514','633526','633
532','633537','633542','633871','633879','634711','634728','634737','634744','638085','638097','638876','638882','640939','651882','655085','655098','658225','666887','
667111','667118','667124','667130','667136','667142','667149','667187','667194','667199','667205','667213','667221','667229','667247','667260','667276','667283','667327
','667334','667339','667349','667369','667375','667380','667386','667397','667403','667409','667414','667419','667428','667448','667466','667475','667483','667492','667
498','667508','667515','667520','667529','667536','667543','667548','667556','667571','667577','667588','667593','667600','667608','669352','669719','672902','672947','
681365','681370','681377','692250','700796','700803','700812','700958','700965','700971','700983','700998','701005','701014','701020','701027','701033','701115','701201
','701220','701241','701261','701462','701467','701479','701489','701499','701513','701518','701524','701529','701549','701559','701566','701578','701590','701596','701
601','702021','702026','702068','702078','702092','702099','702105','702112','702124','702152','702167','702184','702196','702214','702223','702232','702243','726594','
735858','740539','740544','740549','740554','740559','740564','740569','740574','740584','740589','740594','740604','740614','740619','740624','740629','740634','740639
','740644','740649','740654','740659','740669','740674','740679','740684','740689','740694','740699','740704','740709','740714','740719','740724','740729','740739','740
744','740754','740759','740764','740769','740774','740779','740784','740789','740794','740804','740809','740814','740824','740829','740834','740839','740844','740849','
740854','740859','740864','741143','741382','763035','813246','813252','813258','813264','830532','830686','830771','862242','863285','863312','864036','864070','864636
','870057','880730','880861','882386','882392','882439','882465','882475','882482','882489','882499','882523','882541','884704','903281','903689','904848','904883','934
668','934674','934680','934686')
                              AND (ctx.id = pctx.id
                                   OR ctx.path LIKE CONCAT(pctx.path, '/%')
                                   OR pctx.path LIKE CONCAT(ctx.path, '/%')))
                LEFT JOIN mdl_block_instances bi
                          ON (ctx.contextlevel = 80 AND bi.id = ctx.instanceid)
                LEFT JOIN mdl_context bpctx
                          ON (bpctx.id = bi.parentcontextid)
                    WHERE rc.roleid = '3'
                          AND (ctx.contextlevel <= 50 OR bpctx.contextlevel < 50)
                   )
UNION
(SELECT ctx.path, rc.roleid, rc.capability, rc.permission
                     FROM mdl_role_capabilities rc
                     JOIN mdl_context ctx
                          ON (ctx.id = rc.contextid)
                     JOIN mdl_context pctx
                          ON (pctx.id IN ('119348','210402','234745','350182','426496','458187','458299','996707')
                              AND (ctx.id = pctx.id
                                   OR ctx.path LIKE CONCAT(pctx.path, '/%')
                                   OR pctx.path LIKE CONCAT(ctx.path, '/%')))
                LEFT JOIN mdl_block_instances bi
                          ON (ctx.contextlevel = 80 AND bi.id = ctx.instanceid)
                LEFT JOIN mdl_context bpctx
                          ON (bpctx.id = bi.parentcontextid)
                    WHERE rc.roleid = '5'
                          AND (ctx.contextlevel <= 50 OR bpctx.contextlevel < 50)
                   )
UNION
(SELECT ctx.path, rc.roleid, rc.capability, rc.permission
                     FROM mdl_role_capabilities rc
                     JOIN mdl_context ctx
                          ON (ctx.id = rc.contextid)
                     JOIN mdl_context pctx
                          ON (pctx.id IN ('294112','294119','294260','294263','426271','746997','779655','828532','828597','828618','828634','829019','832592','903281',
'942675','942952')
                              AND (ctx.id = pctx.id
                                   OR ctx.path LIKE CONCAT(pctx.path, '/%')
                                   OR pctx.path LIKE CONCAT(ctx.path, '/%')))
                LEFT JOIN mdl_block_instances bi
                          ON (ctx.contextlevel = 80 AND bi.id = ctx.instanceid)
                LEFT JOIN mdl_context bpctx
                          ON (bpctx.id = bi.parentcontextid)
                    WHERE rc.roleid = '16'
                          AND (ctx.contextlevel <= 50 OR bpctx.contextlevel < 50)
                   )
UNION
(SELECT ctx.path, rc.roleid, rc.capability, rc.permission
                     FROM mdl_role_capabilities rc
                     JOIN mdl_context ctx
                          ON (ctx.id = rc.contextid)
                     JOIN mdl_context pctx
                          ON (pctx.id = '484579'
                              AND (ctx.id = pctx.id
                                   OR ctx.path LIKE CONCAT(pctx.path, '/%')
                                   OR pctx.path LIKE CONCAT(ctx.path, '/%')))
                LEFT JOIN mdl_block_instances bi
                          ON (ctx.contextlevel = 80 AND bi.id = ctx.instanceid)
                LEFT JOIN mdl_context bpctx
                          ON (bpctx.id = bi.parentcontextid)
                    WHERE rc.roleid = '4'
                          AND (ctx.contextlevel <= 50 OR bpctx.contextlevel < 50)
                   )ORDER BY capability;

Thanks again.