[ZBX-13380] httptest fail when step > 1( in fact the url is ok) Created: 2018 Jan 23  Updated: 2018 Aug 10  Resolved: 2018 Aug 10

Status: Closed
Project: ZABBIX BUGS AND ISSUES
Component/s: Agent (G), Server (S)
Affects Version/s: 3.4.6
Fix Version/s: None

Type: Incident report Priority: Major
Reporter: ShenQiCheng Assignee: Unassigned
Resolution: Incomplete Votes: 0
Labels: httpstep, httptest
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified


 Description   

Steps to reproduce:

  1. i created some http tests, with some steps ...
  2. but the steps after the first step always fail...
  3. curl all the url is fine on the agent or server...
  4. ...

zabbix-server.log

126769:20180123:062405.054 server #32 started [preprocessing worker #2]
126771:20180123:062405.057 server #33 started [preprocessing worker #3]


126746:20180123:062552.845 item "webihs1:zapache[BytesPerReq]" became not supported: Value "22898.3" of type "string" is not suitable for value type "Numeric (unsigned)"
126743:20180123:062618.445 log level has been increased to 4 (debug)
126743:20180123:062619.448 __zbx_zbx_setproctitle() title:'http poller #1 [got 0 values in 0.000662 sec, getting values]'
126743:20180123:062619.452 In process_httptests()
126743:20180123:062619.456 query [txnlev:0] [select h.hostid,h.host,h.name,t.httptestid,t.name,t.agent,t.authentication,t.http_user,t.http_password,t.http_proxy,t.retries,t.ssl_cert_file,t.ssl_key_file,t.ssl_key_password,t.verify_peer,t.verify_host,t.delay from httptest t,hosts h where t.hostid=h.hostid and t.nextcheck<=1516706779 and mod(t.httptestid,1)=0 and t.status=0 and h.proxy_hostid is null and h.status=0 and (h.maintenance_status=0 or h.maintenance_type=0)]
126743:20180123:062619.459 End of process_httptests()
126743:20180123:062619.462 query [txnlev:0] [select min(t.nextcheck) from httptest t,hosts h where t.hostid=h.hostid and mod(t.httptestid,1)=0 and t.status=0 and h.proxy_hostid is null and h.status=0 and (h.maintenance_status=0 or h.maintenance_type=0)]
126743:20180123:062619.465 __zbx_zbx_setproctitle() title:'http poller #1 [got 0 values in 0.009723 sec, idle 5 sec]'
126743:20180123:062624.468 __zbx_zbx_setproctitle() title:'http poller #1 [got 0 values in 0.009723 sec, getting values]'
126743:20180123:062624.472 In process_httptests()
126743:20180123:062624.475 query [txnlev:0] [select h.hostid,h.host,h.name,t.httptestid,t.name,t.agent,t.authentication,t.http_user,t.http_password,t.http_proxy,t.retries,t.ssl_cert_file,t.ssl_key_file,t.ssl_key_password,t.verify_peer,t.verify_host,t.delay from httptest t,hosts h where t.hostid=h.hostid and t.nextcheck<=1516706784 and mod(t.httptestid,1)=0 and t.status=0 and h.proxy_hostid is null and h.status=0 and (h.maintenance_status=0 or h.maintenance_type=0)]
126743:20180123:062624.478 End of process_httptests()
126743:20180123:062624.481 query [txnlev:0] [select min(t.nextcheck) from httptest t,hosts h where t.hostid=h.hostid and mod(t.httptestid,1)=0 and t.status=0 and h.proxy_hostid is null and h.status=0 and (h.maintenance_status=0 or h.maintenance_type=0)]
126743:20180123:062624.485 __zbx_zbx_setproctitle() title:'http poller #1 [got 0 values in 0.009586 sec, idle 5 sec]'
126743:20180123:062629.488 __zbx_zbx_setproctitle() title:'http poller #1 [got 0 values in 0.009586 sec, getting values]'
126743:20180123:062629.492 In process_httptests()
126743:20180123:062629.494 query [txnlev:0] [select h.hostid,h.host,h.name,t.httptestid,t.name,t.agent,t.authentication,t.http_user,t.http_password,t.http_proxy,t.retries,t.ssl_cert_file,t.ssl_key_file,t.ssl_key_password,t.verify_peer,t.verify_host,t.delay from httptest t,hosts h where t.hostid=h.hostid and t.nextcheck<=1516706789 and mod(t.httptestid,1)=0 and t.status=0 and h.proxy_hostid is null and h.status=0 and (h.maintenance_status=0 or h.maintenance_type=0)]
126743:20180123:062629.497 End of process_httptests()
126743:20180123:062629.500 query [txnlev:0] [select min(t.nextcheck) from httptest t,hosts h where t.hostid=h.hostid and mod(t.httptestid,1)=0 and t.status=0 and h.proxy_hostid is null and h.status=0 and (h.maintenance_status=0 or h.maintenance_type=0)]
126743:20180123:062629.503 __zbx_zbx_setproctitle() title:'http poller #1 [got 0 values in 0.008127 sec, idle 5 sec]'
126743:20180123:062634.506 __zbx_zbx_setproctitle() title:'http poller #1 [got 0 values in 0.008127 sec, getting values]'
126743:20180123:062634.510 In process_httptests()
126743:20180123:062634.513 query [txnlev:0] [select h.hostid,h.host,h.name,t.httptestid,t.name,t.agent,t.authentication,t.http_user,t.http_password,t.http_proxy,t.retries,t.ssl_cert_file,t.ssl_key_file,t.ssl_key_password,t.verify_peer,t.verify_host,t.delay from httptest t,hosts h where t.hostid=h.hostid and t.nextcheck<=1516706794 and mod(t.httptestid,1)=0 and t.status=0 and h.proxy_hostid is null and h.status=0 and (h.maintenance_status=0 or h.maintenance_type=0)]
126743:20180123:062634.517 query [txnlev:0] [select name,value,type from httptest_field where httptestid=2 order by httptest_fieldid]
126743:20180123:062634.520 In substitute_simple_macros() data:'Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/38.0.2125.104 Safari/537.36'
126743:20180123:062634.523 In substitute_simple_macros() data:EMPTY
126743:20180123:062634.526 In substitute_simple_macros() data:EMPTY
126743:20180123:062634.529 In substitute_simple_macros() data:EMPTY
126743:20180123:062634.532 In http_process_variables() 0 variables
126743:20180123:062634.535 End of http_process_variables():SUCCEED
126743:20180123:062634.538 In process_httptest() httptestid:2 name:'_web'
126743:20180123:062634.541 query [txnlev:0] [select httpstepid,no,name,url,timeout,posts,required,status_codes,post_type,follow_redirects,retrieve_mode from httpstep where httptestid=2 order by no]
126743:20180123:062634.544 In substitute_simple_macros() data:'1m'
126743:20180123:062634.547 In substitute_simple_macros() data:'http://A.B.CC.54/mweb/'
126743:20180123:062634.550 In http_substitute_variables() data:'http://A.B.CC.54/mweb/'
126743:20180123:062634.553 End of http_substitute_variables() data:'http://A.B.CC.54/mweb/'
126743:20180123:062634.556 In substitute_simple_macros() data:EMPTY
126743:20180123:062634.559 In http_substitute_variables() data:''
126743:20180123:062634.562 End of http_substitute_variables() data:''
126743:20180123:062634.565 query [txnlev:0] [select name,value,type from httpstep_field where httpstepid=8 order by httpstep_fieldid]
126743:20180123:062634.568 In substitute_simple_macros() data:'15s'
126743:20180123:062634.571 In substitute_simple_macros() data:EMPTY
126743:20180123:062634.573 In substitute_simple_macros() data:'200'
126743:20180123:062634.576 process_httptest() use step "ihs-mweb"
126743:20180123:062634.579 process_httptest() go to URL "http://A.B.CC.54/mweb/"
126743:20180123:062634.588 In int_in_list() list:'200' value:200
126743:20180123:062634.591 End of int_in_list():SUCCEED
126743:20180123:062634.593 In http_process_variables() 0 variables
126743:20180123:062634.596 End of http_process_variables():SUCCEED
126743:20180123:062634.599 In http_process_variables() 0 variables
126743:20180123:062634.601 End of http_process_variables():SUCCEED
126743:20180123:062634.604 In process_step_data() rspcode:200 time:0.006720 speed:181250.000000
126743:20180123:062634.607 query [txnlev:0] [select type,itemid from httpstepitem where httpstepid=8]
126743:20180123:062634.610 In zbx_preprocess_item_value()
126743:20180123:062634.612 End of zbx_preprocess_item_value()
126743:20180123:062634.615 In zbx_preprocess_item_value()
126743:20180123:062634.617 End of zbx_preprocess_item_value()
126743:20180123:062634.620 In zbx_preprocess_item_value()
126743:20180123:062634.622 End of zbx_preprocess_item_value()
126743:20180123:062634.625 End of process_step_data()
126743:20180123:062634.627 In substitute_simple_macros() data:'http://A.B.C.51/wap/'
126743:20180123:062634.630 In http_substitute_variables() data:'http://A.B.C.51/wap/'
126743:20180123:062634.632 End of http_substitute_variables() data:'http://A.B.C.51/wap/'
126743:20180123:062634.635 In substitute_simple_macros() data:EMPTY
126743:20180123:062634.637 In http_substitute_variables() data:''
126743:20180123:062634.640 End of http_substitute_variables() data:''
126743:20180123:062634.643 query [txnlev:0] [select name,value,type from httpstep_field where httpstepid=9 order by httpstep_fieldid]
126743:20180123:062634.645 In substitute_simple_macros() data:'15s'
126743:20180123:062634.648 In substitute_simple_macros() data:EMPTY
126743:20180123:062634.651 In substitute_simple_macros() data:'200'
126743:20180123:062634.654 process_httptest() use step "ihs1-wap"
126743:20180123:062634.657 process_httptest() go to URL "http://A.B.C.51/wap/"
126743:20180123:062649.662 query without transaction detected
126743:20180123:062649.666 query [txnlev:0] [update httptest set nextcheck=1516706869 where httptestid=2]
126743:20180123:062649.674 cannot process step "ihs1-wap" of web scenario "_web" on host "dmgr": Timeout was reached: Connection timed out after 15002 milliseconds
126743:20180123:062649.677 In process_test_data()
126743:20180123:062649.679 query [txnlev:0] [select type,itemid from httptestitem where httptestid=2]
126743:20180123:062649.682 In zbx_preprocess_item_value()
126743:20180123:062649.686 End of zbx_preprocess_item_value()
126743:20180123:062649.688 In zbx_preprocess_item_value()
126743:20180123:062649.691 End of zbx_preprocess_item_value()
126743:20180123:062649.694 In zbx_preprocess_item_value()
126743:20180123:062649.697 End of zbx_preprocess_item_value()
126743:20180123:062649.699 End of process_test_data()
126743:20180123:062649.702 In zbx_ipc_socket_write()
126743:20180123:062649.705 End of zbx_ipc_socket_write():SUCCEED
126743:20180123:062649.707 End of process_httptest()
126743:20180123:062649.710 End of process_httptests()
126743:20180123:062649.713 query [txnlev:0] [select min(t.nextcheck) from httptest t,hosts h where t.hostid=h.hostid and mod(t.httptestid,1)=0 and t.status=0 and h.proxy_hostid is null and h.status=0 and (h.maintenance_status=0 or h.maintenance_type=0)]
126743:20180123:062649.716 __zbx_zbx_setproctitle() title:'http poller #1 [got 1 values in 15.203259 sec, idle 5 sec]'
126743:20180123:062654.720 __zbx_zbx_setproctitle() title:'http poller #1 [got 1 values in 15.203259 sec, getting values]'
126743:20180123:062654.724 In process_httptests()
126743:20180123:062654.727 query [txnlev:0] [select h.hostid,h.host,h.name,t.httptestid,t.name,t.agent,t.authentication,t.http_user,t.http_password,t.http_proxy,t.retries,t.ssl_cert_file,t.ssl_key_file,t.ssl_key_password,t.verify_peer,t.verify_host,t.delay from httptest t,hosts h where t.hostid=h.hostid and t.nextcheck<=1516706814 and mod(t.httptestid,1)=0 and t.status=0 and h.proxy_hostid is null and h.status=0 and (h.maintenance_status=0 or h.maintenance_type=0)]
126743:20180123:062654.730 End of process_httptests()
126743:20180123:062654.733 query [txnlev:0] [select min(t.nextcheck) from httptest t,hosts h where t.hostid=h.hostid and mod(t.httptestid,1)=0 and t.status=0 and h.proxy_hostid is null and h.status=0 and (h.maintenance_status=0 or h.maintenance_type=0)]
126743:20180123:062654.736 __zbx_zbx_setproctitle() title:'http poller #1 [got 0 values in 0.009223 sec, idle 5 sec]'


 Comments   
Comment by Glebs Ivanovskis (Inactive) [ 2018 Jan 23 ]

This is part of the log file we should be looking at:

126743:20180123:062649.662 query without transaction detected
126743:20180123:062649.666 query [txnlev:0] [update httptest set nextcheck=1516706869 where httptestid=2]
126743:20180123:062649.674 cannot process step "ihs1-wap" of web scenario "_web" on host "dmgr": Timeout was reached: Connection timed out after 15002 milliseconds

You know, seems like libcurl just times out for this URL...

I've just tried to create a web scenario with two steps (in trunk, I'm almost 100% sure http poller's code is the same in 3.4) and it works just fine. Please provide steps to reproduce, preferably with public URLs.

Comment by Kaspars Mednis [ 2018 Mar 09 ]

Hi,

Please provide required information, otherwise we will close this issue as can not reproduce.

Regards,
Kaspars

Comment by ShenQiCheng [ 2018 Mar 12 ]

sorry for loss of contact for a long time.

curl all the url is fine on the agent or server.

i will try to find why

Generated at Sat Dec 13 23:17:31 EET 2025 using Jira 10.3.13#10030013-sha1:56dd970ae30ebfeda3a697d25be1f6388b68a422.