[YSQL][SQLsmith] ../../src/yb/rpc/outbound_call.cc:183] Check failed: IsFinished()

[def-]

Jira Link: DB-1167

Description

Debug check fails. Found with SQLsmith, fails sporadically, can't reproduce. Seems to happen when queries are still running during a shutdown because of an assertion failure:

2022-02-01 14:20:46.702 CET [69974] STATEMENT:  insert into public.airports values (
	case when cast(null as lseg) ?# cast(null as line) then cast(nullif(cast(null as text),
	    case when cast(null as box) @ cast(null as box) then (select pg_catalog.max(ident) from public.airports)
	         else (select pg_catalog.max(ident) from public.airports)
	         end
	      ) as text) else cast(nullif(cast(null as text),
	    case when cast(null as box) @ cast(null as box) then (select pg_catalog.max(ident) from public.airports)
	         else (select pg_catalog.max(ident) from public.airports)
	         end
	      ) as text) end
	  , 
	cast(coalesce(cast(null as text),
	  cast(null as text)) as text), 
	cast(nullif(cast(null as text),
	  cast(null as text)) as text), 
	28, 
	cast(null as text), 
	cast(null as text), 
	default, 
	cast(null as text), 
	cast(null as text), 
	cast(null as text), 
	default, 
	pg_catalog.md5(
	  cast(cast(null as bytea) as bytea)))
TRAP: FailedAssertion("!(bms_is_subset(appendrel->lateral_relids, required_outer))", File: "../../../../../../../src/postgres/src/backend/optimizer/util/relnode.c", Line: 1543)
2022-02-01 14:20:46.705 CET [52434] LOG:  server process (PID 69977) was terminated by signal 6: Abort trap
2022-02-01 14:20:46.705 CET [52434] DETAIL:  Failed process was running: select  
	  subq_2.c4 as c0
	from 
	  public.airports as ref_0
	        inner join public.airports as ref_1
	        on (ref_0.local_code is NULL)
	      left join (select  
	              subq_0.c1 as c0, 
	              subq_1.c0 as c1, 
	              subq_1.c0 as c2, 
	              ref_2.municipality as c3, 
	              subq_0.c2 as c4, 
	              ref_2.continent as c5, 
	              subq_0.c2 as c6, 
	              subq_0.c2 as c7
	            from 
	              public.airports as ref_2,
	              lateral (select  
	                    ref_3.coordinates as c0, 
	                    ref_3.municipality as c1, 
	                    ref_2.iso_country as c2, 
	                    ref_3.name as c3, 
	                    (select municipality from public.airports limit 1 offset 26)
	                       as c4
	                  from 
	                    public.airports as ref_3
	                  where cast(null as circle) >> cast(null as circle)
	                  limit 84) as subq_0,
	              lateral (select  
2022-02-01 14:20:46.705 CET [52434] LOG:  terminating any other active server processes
2022-02-01 14:20:46.705 CET [69979] WARNING:  terminating connection because of crash of another server process
2022-02-01 14:20:46.705 CET [69979] DETAIL:  The postmaster has commanded this server process to roll back the current transaction and exit, because another server process exited abnormally and possibly corrupted shared memory.
2022-02-01 14:20:46.705 CET [69979] HINT:  In a moment you should be able to reconnect to the database and repeat your command.
2022-02-01 14:20:46.705 CET [69980] WARNING:  terminating connection because of crash of another server process
2022-02-01 14:20:46.705 CET [69980] DETAIL:  The postmaster has commanded this server process to roll back the current transaction and exit, because another server process exited abnormally and possibly corrupted shared memory.
2022-02-01 14:20:46.705 CET [69980] HINT:  In a moment you should be able to reconnect to the database and repeat your command.
2022-02-01 14:20:46.706 CET [69981] WARNING:  terminating connection because of crash of another server process
2022-02-01 14:20:46.706 CET [69981] DETAIL:  The postmaster has commanded this server process to roll back the current transaction and exit, because another server process exited abnormally and possibly corrupted shared memory.
2022-02-01 14:20:46.706 CET [69981] HINT:  In a moment you should be able to reconnect to the database and repeat your command.
2022-02-01 14:20:46.706 CET [69978] WARNING:  terminating connection because of crash of another server process
2022-02-01 14:20:46.706 CET [69978] DETAIL:  The postmaster has commanded this server process to roll back the current transaction and exit, because another server process exited abnormally and possibly corrupted shared memory.
2022-02-01 14:20:46.706 CET [69978] HINT:  In a moment you should be able to reconnect to the database and repeat your command.
2022-02-01 14:20:46.706 CET [69976] WARNING:  terminating connection because of crash of another server process
2022-02-01 14:20:46.706 CET [69976] DETAIL:  The postmaster has commanded this server process to roll back the current transaction and exit, because another server process exited abnormally and possibly corrupted shared memory.
2022-02-01 14:20:46.706 CET [69976] HINT:  In a moment you should be able to reconnect to the database and repeat your command.
2022-02-01 14:20:46.706 CET [69975] WARNING:  terminating connection because of crash of another server process at character 121
2022-02-01 14:20:46.706 CET [69975] DETAIL:  The postmaster has commanded this server process to roll back the current transaction and exit, because another server process exited abnormally and possibly corrupted shared memory.
2022-02-01 14:20:46.706 CET [69975] HINT:  In a moment you should be able to reconnect to the database and repeat your command.
2022-02-01 14:20:46.706 CET [69974] WARNING:  terminating connection because of crash of another server process
2022-02-01 14:20:46.706 CET [69974] DETAIL:  The postmaster has commanded this server process to roll back the current transaction and exit, because another server process exited abnormally and possibly corrupted shared memory.
2022-02-01 14:20:46.706 CET [69974] HINT:  In a moment you should be able to reconnect to the database and repeat your command.
W0201 14:20:46.707033 1846030336 outbound_call.cc:131] Failed to schedule invoking callback on response for request yb.tserver.TabletServerService.Read to 127.0.0.1: Aborted (yb/rpc/thread_pool.cc:260): Service is shutting down
W0201 14:20:46.707165 1846030336 outbound_call.cc:131] Failed to schedule invoking callback on response for request yb.tserver.TabletServerService.Read to 127.0.0.1: Aborted (yb/rpc/thread_pool.cc:260): Service is shutting down
W0201 14:20:46.707144 1846030336 outbound_call.cc:131] Failed to schedule invoking callback on response for request yb.tserver.TabletServerService.Read to 127.0.0.1: Aborted (yb/rpc/thread_pool.cc:260): Service is shutting down
I0201 14:20:46.707315 1844883456 poller.cc:66] Poll stopped: Service unavailable (yb/rpc/scheduler.cc:80): Scheduler is shutting down (system error 58)
I0201 14:20:46.707417 1844883456 poller.cc:66] Poll stopped: Service unavailable (yb/rpc/scheduler.cc:80): Scheduler is shutting down (system error 58)
W0201 14:20:46.707713 1846030336 rpc.cc:179] Aborted (yb/rpc/rpc.cc:178): Failed to schedule: 0x000000011431d918 -> Read(tablet: 775ed9f6db2a4c7d9a1cc9ec099fa364, num_ops: 1, num_attempts: 2, txn: 00000000-0000-0000-0000-000000000000, subtxn: [none])
W0201 14:20:46.707713 1846030336 rpc.cc:179] Aborted (yb/rpc/rpc.cc:178): Failed to schedule: 0x0000000134826038 -> Read(tablet: 775ed9f6db2a4c7d9a1cc9ec099fa364, num_ops: 1, num_attempts: 2, txn: 00000000-0000-0000-0000-000000000000, subtxn: [none])
W0201 14:20:46.707715 1846030336 outbound_call.cc:131] Failed to schedule invoking callback on response for request yb.tserver.TabletServerService.Read to 127.0.0.1: Aborted (yb/rpc/thread_pool.cc:260): Service is shutting down
W0201 14:20:46.707046 1846030336 outbound_call.cc:131] Failed to schedule invoking callback on response for request yb.tserver.TabletServerService.Read to 127.0.0.1: Aborted (yb/rpc/thread_pool.cc:260): Service is shutting down
I0201 14:20:46.708015 1844883456 poller.cc:66] Poll stopped: Service unavailable (yb/rpc/scheduler.cc:80): Scheduler is shutting down (system error 58)
I0201 14:20:46.708142 1846030336 reactor.cc:228] pggate_ybclient_R000: tearing down outbound TCP connections...
I0201 14:20:46.708190 1844883456 poller.cc:66] Poll stopped: Service unavailable (yb/rpc/scheduler.cc:80): Scheduler is shutting down (system error 58)
I0201 14:20:46.708271 1844883456 poller.cc:66] Poll stopped: Service unavailable (yb/rpc/scheduler.cc:80): Scheduler is shutting down (system error 58)
I0201 14:20:46.707639 1844883456 poller.cc:66] Poll stopped: Service unavailable (yb/rpc/scheduler.cc:80): Scheduler is shutting down (system error 58)
F0201 14:20:46.708448 48530816 outbound_call.cc:183] Check failed: IsFinished() 
W0201 14:20:46.708076 1846030336 rpc.cc:179] Aborted (yb/rpc/rpc.cc:178): Failed to schedule: 0x00000001236153d8 -> Read(tablet: 775ed9f6db2a4c7d9a1cc9ec099fa364, num_ops: 1, num_attempts: 2, txn: 00000000-0000-0000-0000-000000000000, subtxn: [none])
I0201 14:20:46.708168 1844883456 poller.cc:66] Poll stopped: Service unavailable (yb/rpc/scheduler.cc:80): Scheduler is shutting down (system error 58)
W0201 14:20:46.708222 1846030336 outbound_call.cc:131] Failed to schedule invoking callback on response for request yb.tserver.TabletServerService.Read to 127.0.0.1: Aborted (yb/rpc/thread_pool.cc:260): Service is shutting down
W0201 14:20:46.709298 1846030336 rpc.cc:179] Aborted (yb/rpc/rpc.cc:178): Failed to schedule: 0x000000013363fbe8 -> Read(tablet: 775ed9f6db2a4c7d9a1cc9ec099fa364, num_ops: 1, num_attempts: 2, txn: 00000000-0000-0000-0000-000000000000, subtxn: [none])
Fatal failure details written to /Users/deen/var/data/yb-data/tserver/logs/yb-tserver.FATAL.details.2022-02-01T14_20_46.pid69979.txt
F20220201 14:20:46 ../../src/yb/rpc/outbound_call.cc:183] Check failed: IsFinished() 
    @        0x10687d894  google::LogDestination::LogToSinks()
    @        0x10687c9cc  google::LogMessage::SendToLog()
    @        0x10687d388  google::LogMessage::Flush()
    @        0x106881c7c  google::LogMessageFatal::~LogMessageFatal()
    @        0x10687e314  google::LogMessageFatal::~LogMessageFatal()
    @        0x10f775334  yb::rpc::OutboundCall::~OutboundCall()
    @        0x10f7758c8  yb::rpc::OutboundCall::~OutboundCall()
    @        0x10f7a12c4  std::__1::__shared_ptr_emplace<>::__on_zero_shared()
    @        0x10f6f9f44  std::__1::__shared_count::__release_shared()
    @        0x10f6f9ef4  std::__1::__shared_weak_count::__release_shared()
    @        0x10f6f9ec8  std::__1::shared_ptr<>::~shared_ptr()
    @        0x10f6f6df0  std::__1::shared_ptr<>::~shared_ptr()
    @        0x10f801a60  yb::rpc::RpcController::~RpcController()
    @        0x10f801acc  yb::rpc::RpcController::~RpcController()
    @        0x1040d7608  yb::pggate::PgClient::Impl::~Impl()
    @        0x1040d74f0  yb::pggate::PgClient::Impl::~Impl()
    @        0x1040d7498  std::__1::default_delete<>::operator()()
    @        0x1040d741c  std::__1::unique_ptr<>::reset()
    @        0x1040d73b0  std::__1::unique_ptr<>::~unique_ptr()
    @        0x1040c173c  std::__1::unique_ptr<>::~unique_ptr()
    @        0x1040c1710  yb::pggate::PgClient::~PgClient()
    @        0x1040c1768  yb::pggate::PgClient::~PgClient()
    @        0x104090394  yb::pggate::PgApiImpl::~PgApiImpl()
    @        0x1040904d0  yb::pggate::PgApiImpl::~PgApiImpl()
    @        0x1040904fc  yb::pggate::PgApiImpl::~PgApiImpl()
    @        0x10406b3ec  YBCDestroyPgGate
    @        0x10276dbb8  YBOnPostgresBackendShutdown
    @        0x102561928  quickdie
    @        0x199ab44e4  _sigtramp
    @        0x1118ec504  boost::asio::ip::make_address_v6()
    @        0x1118ec504  boost::asio::ip::make_address_v6()
    @        0x1118ec434  boost::asio::ip::make_address()

*** Check failure stack trace: ***
    @        0x10687cb8c  google::LogMessage::SendToLog()
    @        0x10687d388  google::LogMessage::Flush()
    @        0x106881c7c  google::LogMessageFatal::~LogMessageFatal()
    @        0x10687e314  google::LogMessageFatal::~LogMessageFatal()
    @        0x10f775334  yb::rpc::OutboundCall::~OutboundCall()
    @        0x10f7758c8  yb::rpc::OutboundCall::~OutboundCall()
    @        0x10f7a12c4  std::__1::__shared_ptr_emplace<>::__on_zero_shared()
    @        0x10f6f9f44  std::__1::__shared_count::__release_shared()
    @        0x10f6f9ef4  std::__1::__shared_weak_count::__release_shared()
    @        0x10f6f9ec8  std::__1::shared_ptr<>::~shared_ptr()
    @        0x10f6f6df0  std::__1::shared_ptr<>::~shared_ptr()
    @        0x10f801a60  yb::rpc::RpcController::~RpcController()
    @        0x10f801acc  yb::rpc::RpcController::~RpcController()
    @        0x1040d7608  yb::pggate::PgClient::Impl::~Impl()
    @        0x1040d74f0  yb::pggate::PgClient::Impl::~Impl()
    @        0x1040d7498  std::__1::default_delete<>::operator()()
    @        0x1040d741c  std::__1::unique_ptr<>::reset()
    @        0x1040d73b0  std::__1::unique_ptr<>::~unique_ptr()
    @        0x1040c173c  std::__1::unique_ptr<>::~unique_ptr()
    @        0x1040c1710  yb::pggate::PgClient::~PgClient()
    @        0x1040c1768  yb::pggate::PgClient::~PgClient()
    @        0x104090394  yb::pggate::PgApiImpl::~PgApiImpl()
    @        0x1040904d0  yb::pggate::PgApiImpl::~PgApiImpl()
    @        0x1040904fc  yb::pggate::PgApiImpl::~PgApiImpl()
    @        0x10406b3ec  YBCDestroyPgGate
    @        0x10276dbb8  YBOnPostgresBackendShutdown
    @        0x102561928  quickdie
    @        0x199ab44e4  _sigtramp
    @        0x1118ec504  boost::asio::ip::make_address_v6()
    @        0x1118ec504  boost::asio::ip::make_address_v6()
    @        0x1118ec434  boost::asio::ip::make_address()
    @        0x1118ec3fc  boost::asio::ip::make_address()