Skip to content

bug64539-status-json-encoding.phpt fail on 32-bits #17208

Closed

Description

@andypost

Description

The following test fails on 32-bit arches building 8.4.2 for Alpinelinux https://gitlab.alpinelinux.org/alpine/aports/-/pipelines/283003

TEST 18384/18580 [sapi/fpm/tests/bug64539-status-json-encoding.phpt]
========DIFF========
001+ >>> Response
002+ ----------------- OUT -----------------
003+ X-Powered-By: PHP/8.4.2
004+ Expires: Thu, 01 Jan 1970 00:00:00 GMT
005+ Cache-Control: no-cache, no-store, must-revalidate, max-age=0
006+ Content-Type: application/json
007+ 
008+ {"pool":"unconfined","process manager":"static","start time":1734469914,"start since":0,"accepted conn":2,"listen queue":0,"max listen queue":0,"listen queue len":4096,"idle processes":0,"active processes":2,"total processes":2,"max active processes":2,"max children reached":0,"slow requests":0,"memory peak":0, "processes":[{"pid":18046,"state":"Running","start time":1734469914,"start since":0,"requests":1,"request duration":100588,"request method":"(null)","request uri":"GET/bug64539-status-json-encoding.src.php?","content length":4154871857,"user":"(null)","script":"-","last request cpu":0.00,"last request memory":0},{"pid":18047,"state":"Running","start time":1734469914,"start since":0,"requests":1,"request duration":361,"request method":"(null)","request uri":"GET/status?","content length":4154871857,"user":"(null)","script":"-","last request cpu":0.00,"last request memory":0}]}
009+ ----------------- ERR -----------------
010+ 
011+ ---------------------------------------
012+ 
013+ ERROR: No field request uri matched pattern \?a=b"c$ for any process in status data '{"pool":"unconfined","process manager":"static","start time":1734469914,"start since":0,"accepted conn":2,"listen queue":0,"max listen queue":0,"listen queue len":4096,"idle processes":0,"active processes":2,"total processes":2,"max active processes":2,"max children reached":0,"slow requests":0,"memory peak":0, "processes":[{"pid":18046,"state":"Running","start time":1734469914,"start since":0,"requests":1,"request duration":100588,"request method":"(null)","request uri":"GET/bug64539-status-json-encoding.src.php?","content length":4154871857,"user":"(null)","script":"-","last request cpu":0.00,"last request memory":0},{"pid":18047,"state":"Running","start time":1734469914,"start since":0,"requests":1,"request duration":361,"request method":"(null)","request uri":"GET/status?","content length":4154871857,"user":"(null)","script":"-","last request cpu":0.00,"last request memory":0}]}'
014+ 
015+ LOGS:
016+ --------------------------------------------------------------------
017+ [17-Dec-2024 21:11:54] NOTICE: fpm is running, pid 18045
018+ [17-Dec-2024 21:11:54] NOTICE: ready to handle connections
019+ --------------------------------------------------------------------
020+ 
     Done
========DONE========
FAIL FPM: bug64539 - status json format escaping [sapi/fpm/tests/bug64539-status-json-encoding.phpt] 

PHP Version

PHP 8.4.2

Operating System

Alpinelinux

Activity

  1. bukka commented on Dec 22, 2024

    @bukka
    Member

    Hmm, this part is really strange:

    "request uri":"GET/bug64539-status-json-encoding.src.php?"
    

    For some reason it's not getting query string. It will need some debugging. I just created #17239 which will allow printing a bit more info for this with setting TEST_FPM_DEBUG_FILTER=bug64539 env var .

  2. andypost commented on Dec 22, 2024

    @andypost
    ContributorAuthor

    Here's debug build and logs

    001+ >>> Created file: /builds/alpine/aports/community/php84/src/php-8.4.2/sapi/fpm/tests/bug64539-status-json-encoding.ini
    002+ --------------------------------------------------------------------
    003+ [global]
    004+ error_log = /builds/alpine/aports/community/php84/src/php-8.4.2/sapi/fpm/tests/bug64539-status-json-encoding.err.log
    005+ [unconfined]
    006+ listen = 127.0.0.1:9004
    007+ pm = static
    008+ pm.max_children = 2
    009+ pm.status_path = /status
    010+ catch_workers_output = yes
    011+ --------------------------------------------------------------------
    012+ 
    013+ >>> Starting FPM using command:
    014+ /builds/alpine/aports/community/php84/src/php-8.4.2/sapi/fpm/php-fpm -n -y /builds/alpine/aports/community/php84/src/php-8.4.2/sapi/fpm/tests/bug64539-status-json-encoding.ini -O -F -dextension_dir=modules
    015+ LogTool - Matching EXPECTED: fpm is running, pid \d+
    016+ LogTool - PATTERN: /^(?:\[\d\d-\w\w\w-\d{4} \d\d:\d\d:\d\d(?:\.\d+)?\] )?NOTICE: (?:pid \d+, (?:\w+|\(null\))\(\), line \d+: )?(fpm is running, pid \d+)$/
    017+ LogReader - LINE: [22-Dec-2024 14:59:56] NOTICE: fpm is running, pid 25911
    018+ LogTool - Matched ACTUAL: fpm is running, pid 25911
    019+ LogTool - Matching EXPECTED: ready to handle connections
    020+ LogTool - PATTERN: /^(?:\[\d\d-\w\w\w-\d{4} \d\d:\d\d:\d\d(?:\.\d+)?\] )?NOTICE: (?:pid \d+, (?:\w+|\(null\))\(\), line \d+: )?(ready to handle connections)$/
    021+ LogReader - LINE: [22-Dec-2024 14:59:56] NOTICE: ready to handle connections
    022+ LogTool - Matched ACTUAL: ready to handle connections
    023+ 
    024+ >>> Created file: /builds/alpine/aports/community/php84/src/php-8.4.2/sapi/fpm/tests/bug64539-status-json-encoding.src.php
    025+ --------------------------------------------------------------------
    026+ <?php
    027+ usleep(200000);
    028+ --------------------------------------------------------------------
    029+ 
    030+ >>> Request params
    031+ Array
    032+ (
    033+     [GATEWAY_INTERFACE] => FastCGI/1.0
    034+     [REQUEST_METHOD] => GET
    035+     [SCRIPT_FILENAME] => /builds/alpine/aports/community/php84/src/php-8.4.2/sapi/fpm/tests/bug64539-status-json-encoding.src.php
    036+     [SCRIPT_NAME] => /bug64539-status-json-encoding.src.php
    037+     [QUERY_STRING] => a=b"c
    038+     [REQUEST_URI] => /bug64539-status-json-encoding.src.php?a=b"c
    039+     [DOCUMENT_URI] => /bug64539-status-json-encoding.src.php
    040+     [SERVER_SOFTWARE] => php/fcgiclient
    041+     [REMOTE_ADDR] => 127.0.0.1
    042+     [REMOTE_PORT] => 7777
    043+     [SERVER_ADDR] => 127.0.0.1
    044+     [SERVER_PORT] => 80
    045+     [SERVER_NAME] => runner-79ekzzfe-project-1-concurrent-1
    046+     [SERVER_PROTOCOL] => HTTP/1.1
    047+     [DOCUMENT_ROOT] => /builds/alpine/aports/community/php84/src/php-8.4.2/sapi/fpm/tests
    048+     [CONTENT_TYPE] => 
    049+     [CONTENT_LENGTH] => 0
    050+ )
    051+ 
    052+ >>> Request params
    053+ Array
    054+ (
    055+     [GATEWAY_INTERFACE] => FastCGI/1.0
    056+     [REQUEST_METHOD] => GET
    057+     [SCRIPT_FILENAME] => /builds/alpine/aports/community/php84/src/php-8.4.2/sapi/fpm/tests/bug64539-status-json-encoding.src.php
    058+     [SCRIPT_NAME] => /status
    059+     [QUERY_STRING] => full&json
    060+     [REQUEST_URI] => /status?full&json
    061+     [DOCUMENT_URI] => /status
    062+     [SERVER_SOFTWARE] => php/fcgiclient
    063+     [REMOTE_ADDR] => 127.0.0.1
    064+     [REMOTE_PORT] => 7777
    065+     [SERVER_ADDR] => 127.0.0.1
    066+     [SERVER_PORT] => 80
    067+     [SERVER_NAME] => runner-79ekzzfe-project-1-concurrent-1
    068+     [SERVER_PROTOCOL] => HTTP/1.1
    069+     [DOCUMENT_ROOT] => /builds/alpine/aports/community/php84/src/php-8.4.2/sapi/fpm/tests
    070+     [CONTENT_TYPE] => 
    071+     [CONTENT_LENGTH] => 0
    072+ )
    073+ >>> Response
    074+ ----------------- OUT -----------------
    075+ X-Powered-By: PHP/8.4.2
    076+ Content-type: text/html; charset=UTF-8
    077+ 
    078+ 
    079+ ----------------- ERR -----------------
    080+ 
    081+ ---------------------------------------
    082+ 
    083+ >>> Response
    084+ ----------------- OUT -----------------
    085+ X-Powered-By: PHP/8.4.2
    086+ Expires: Thu, 01 Jan 1970 00:00:00 GMT
    087+ Cache-Control: no-cache, no-store, must-revalidate, max-age=0
    088+ Content-Type: application/json
    089+ 
    090+ {"pool":"unconfined","process manager":"static","start time":1734879596,"start since":0,"accepted conn":2,"listen queue":0,"max listen queue":0,"listen queue len":4096,"idle processes":0,"active processes":2,"total processes":2,"max active processes":2,"max children reached":0,"slow requests":0,"memory peak":0, "processes":[{"pid":25912,"state":"Running","start time":1734879596,"start since":0,"requests":1,"request duration":100693,"request method":"(null)","request uri":"GET/bug64539-status-json-encoding.src.php?","content length":4150677553,"user":"(null)","script":"-","last request cpu":0.00,"last request memory":0},{"pid":25913,"state":"Running","start time":1734879596,"start since":0,"requests":1,"request duration":368,"request method":"(null)","request uri":"GET/status?","content length":4150677553,"user":"(null)","script":"-","last request cpu":0.00,"last request memory":0}]}
    091+ ----------------- ERR -----------------
    092+ 
    093+ ---------------------------------------
    094+ 
    095+ ERROR: No field request uri matched pattern \?a=b"c$ for any process in status data '{"pool":"unconfined","process manager":"static","start time":1734879596,"start since":0,"accepted conn":2,"listen queue":0,"max listen queue":0,"listen queue len":4096,"idle processes":0,"active processes":2,"total processes":2,"max active processes":2,"max children reached":0,"slow requests":0,"memory peak":0, "processes":[{"pid":25912,"state":"Running","start time":1734879596,"start since":0,"requests":1,"request duration":100693,"request method":"(null)","request uri":"GET/bug64539-status-json-encoding.src.php?","content length":4150677553,"user":"(null)","script":"-","last request cpu":0.00,"last request memory":0},{"pid":25913,"state":"Running","start time":1734879596,"start since":0,"requests":1,"request duration":368,"request method":"(null)","request uri":"GET/status?","content length":4150677553,"user":"(null)","script":"-","last request cpu":0.00,"last request memory":0}]}'
    096+ 
    097+ LOGS:
    098+ --------------------------------------------------------------------
    099+ [22-Dec-2024 14:59:56] NOTICE: fpm is running, pid 25911
    100+ [22-Dec-2024 14:59:56] NOTICE: ready to handle connections
    101+ --------------------------------------------------------------------
    102+ 
    103+ LogTool - Matching EXPECTED: Terminating ...
    104+ LogTool - PATTERN: /^(?:\[\d\d-\w\w\w-\d{4} \d\d:\d\d:\d\d(?:\.\d+)?\] )?NOTICE: (?:pid \d+, (?:\w+|\(null\))\(\), line \d+: )?(Terminating ...)$/
    105+ LogReader - LINE: [22-Dec-2024 14:59:56] NOTICE: Terminating ...
    106+ LogTool - Matched ACTUAL: Terminating ...
    107+ LogTool - Matching EXPECTED: exiting, bye-bye!
    108+ LogTool - PATTERN: /^(?:\[\d\d-\w\w\w-\d{4} \d\d:\d\d:\d\d(?:\.\d+)?\] )?NOTICE: (?:pid \d+, (?:\w+|\(null\))\(\), line \d+: )?(exiting, bye-bye!)$/
    109+ LogReader - LINE: [22-Dec-2024 14:59:56] NOTICE: exiting, bye-bye!
    110+ LogTool - Matched ACTUAL: exiting, bye-bye!
         Done
    
  3. andypost commented on Dec 22, 2024

    @andypost
    ContributorAuthor
  4. ndossche commented on Dec 26, 2024

    @ndossche
    Member

    Was able to reproduce this in an i386/alpine container.

  5. ndossche commented on Dec 26, 2024

    @ndossche
    Member

    The reason this breaks is because of a type mismatch.
    The following line uses fields of the timeval struct which are both 8 bytes on Alpine 32-bit, which results in a computed value of also 8 bytes:

    duration.tv_sec * 1000000UL + duration.tv_usec,

    However, it is passed to a format string which expects 4 bytes (unsigned long and thus the %lu format specifier is 4 bytes on Alpine 32-bit), resulting in argument corruption.
    Since the value is generally small, truncating to 4 bytes is sufficient to fix this.

    @andypost Please try the following patch:

    diff --git a/sapi/fpm/fpm/fpm_status.c b/sapi/fpm/fpm/fpm_status.c
    index cc3412149c7..96bdb96e408 100644
    --- a/sapi/fpm/fpm/fpm_status.c
    +++ b/sapi/fpm/fpm/fpm_status.c
    @@ -608,7 +608,7 @@ int fpm_status_handle_request(void) /* {{{ */
     					time_buffer,
     					(unsigned long) (now_epoch - proc->start_epoch),
     					proc->requests,
    -					duration.tv_sec * 1000000UL + duration.tv_usec,
    +					(unsigned long) (duration.tv_sec * 1000000UL + duration.tv_usec),
     					proc->request_method[0] != '\0' ? proc->request_method : "-",
     					proc->request_uri[0] != '\0' ? proc->request_uri : "-",
     					query_string ? "?" : "",
    
  6. andypost commented on Dec 27, 2024

    @andypost
    ContributorAuthor

    @nielsdos checked your patch and the test pass, thank you!

  7. added a commit that references this issue on Dec 27, 2024
    9bd3a2c
  8. ndossche commented on Dec 27, 2024

    @ndossche
    Member

    @andypost Thanks for checking, PR made!

  9. added a commit that references this issue on Dec 27, 2024
    847d140
  10. added 2 commits that reference this issue on Dec 27, 2024
    2161959
    65524e5
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Metadata

Assignees

No one assigned

    Type

    No type

    Projects

    No projects

      Milestone

      No milestone

      Relationships

      None yet

      Development

      No branches or pull requests

      Issue actions