Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

HBASE-27651 hbase-daemon.sh foreground_start should propagate SIGHUP and SIGTERM #5035

Merged
merged 2 commits into from Mar 20, 2023

Conversation

ndimiduk
Copy link
Member

Introduce separate traps for SIGHUP vs. the rest. Treat SIGINT, SIGKILL, and EXIT identically, as before. Use the signal name without SIG prefix for increased portability, as per the POSIX man page for trap.

SIGTERM handler will now honor HBASE_STOP_TIMEOUT as described in the file header.

@Apache-HBase
Copy link

🎊 +1 overall

Vote Subsystem Runtime Comment
+0 🆗 reexec 0m 23s Docker mode activated.
-0 ⚠️ yetus 0m 3s Unprocessed flag(s): --brief-report-file --spotbugs-strict-precheck --whitespace-eol-ignore-list --whitespace-tabs-ignore-list --quick-hadoopcheck
_ Prechecks _
_ master Compile Tests _
_ Patch Compile Tests _
_ Other Tests _
1m 14s
Subsystem Report/Notes
Docker ClientAPI=1.42 ServerAPI=1.42 base: https://ci-hbase.apache.org/job/HBase-PreCommit-GitHub-PR/job/PR-5035/1/artifact/yetus-jdk11-hadoop3-check/output/Dockerfile
GITHUB PR #5035
Optional Tests
uname Linux 132bd262ca8c 5.4.0-1094-aws #102~18.04.1-Ubuntu SMP Tue Jan 10 21:07:03 UTC 2023 x86_64 x86_64 x86_64 GNU/Linux
Build tool maven
Personality dev-support/hbase-personality.sh
git revision master / 2bbe036
Max. process+thread count 41 (vs. ulimit of 30000)
modules C: . U: .
Console output https://ci-hbase.apache.org/job/HBase-PreCommit-GitHub-PR/job/PR-5035/1/console
versions git=2.34.1 maven=3.8.6
Powered by Apache Yetus 0.12.0 https://yetus.apache.org

This message was automatically generated.

@Apache-HBase
Copy link

🎊 +1 overall

Vote Subsystem Runtime Comment
+0 🆗 reexec 0m 23s Docker mode activated.
-0 ⚠️ yetus 0m 3s Unprocessed flag(s): --brief-report-file --spotbugs-strict-precheck --whitespace-eol-ignore-list --whitespace-tabs-ignore-list --quick-hadoopcheck
_ Prechecks _
_ master Compile Tests _
_ Patch Compile Tests _
_ Other Tests _
1m 14s
Subsystem Report/Notes
Docker ClientAPI=1.42 ServerAPI=1.42 base: https://ci-hbase.apache.org/job/HBase-PreCommit-GitHub-PR/job/PR-5035/1/artifact/yetus-jdk8-hadoop3-check/output/Dockerfile
GITHUB PR #5035
Optional Tests
uname Linux b3acd7f87033 5.4.0-1093-aws #102~18.04.2-Ubuntu SMP Wed Dec 7 00:31:59 UTC 2022 x86_64 x86_64 x86_64 GNU/Linux
Build tool maven
Personality dev-support/hbase-personality.sh
git revision master / 2bbe036
Max. process+thread count 33 (vs. ulimit of 30000)
modules C: . U: .
Console output https://ci-hbase.apache.org/job/HBase-PreCommit-GitHub-PR/job/PR-5035/1/console
versions git=2.34.1 maven=3.8.6
Powered by Apache Yetus 0.12.0 https://yetus.apache.org

This message was automatically generated.

@Apache-HBase
Copy link

🎊 +1 overall

Vote Subsystem Runtime Comment
+0 🆗 reexec 0m 55s Docker mode activated.
_ Prechecks _
+1 💚 dupname 0m 0s No case conflicting files found.
+0 🆗 shelldocs 0m 0s Shelldocs was not available.
+1 💚 @author 0m 0s The patch does not contain any @author tags.
_ master Compile Tests _
+1 💚 spotless 0m 42s branch has no errors when running spotless:check.
_ Patch Compile Tests _
+1 💚 shellcheck 0m 1s The patch generated 0 new + 126 unchanged - 12 fixed = 126 total (was 138)
+1 💚 whitespace 0m 0s The patch has no whitespace issues.
+1 💚 spotless 0m 36s patch has no errors when running spotless:check.
_ Other Tests _
+1 💚 asflicense 0m 10s The patch does not generate ASF License warnings.
3m 21s
Subsystem Report/Notes
Docker ClientAPI=1.42 ServerAPI=1.42 base: https://ci-hbase.apache.org/job/HBase-PreCommit-GitHub-PR/job/PR-5035/1/artifact/yetus-general-check/output/Dockerfile
GITHUB PR #5035
Optional Tests dupname asflicense spotless shellcheck shelldocs
uname Linux c1fcf11d14b2 5.4.0-135-generic #152-Ubuntu SMP Wed Nov 23 20:19:22 UTC 2022 x86_64 x86_64 x86_64 GNU/Linux
Build tool maven
Personality dev-support/hbase-personality.sh
git revision master / 2bbe036
Max. process+thread count 44 (vs. ulimit of 30000)
modules C: . U: .
Console output https://ci-hbase.apache.org/job/HBase-PreCommit-GitHub-PR/job/PR-5035/1/console
versions git=2.34.1 maven=3.8.6 shellcheck=0.8.0
Powered by Apache Yetus 0.12.0 https://yetus.apache.org

This message was automatically generated.

Copy link
Contributor

@saintstack saintstack left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

LGTM.

The hard part here is trying the various combinations out and studying you get the appropriate behavior. Maybe say here what you did testing?

Good stuff Nick.

{
# pass through SIGHUP if we can
if [ -f "${HBASE_PID}" ] ; then
kill -s HUP "$(cat "${HBASE_PID}")"
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

You'd rather see the output than /dev/null it? And does the old pid stick around now?

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Testing in a docker container that disappears... I'm guessing that this script already handles the pid file, but let me look more closely...

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Oh. cleanupAfterRun handles the pid file.

…and SIGTERM

Introduce separate `trap`s for SIGHUP vs. the rest. Treat `SIGINT`, `SIGKILL`, and `EXIT`
identically, as before. Use the signal name without `SIG` prefix for increased portability, as per
the POSIX man page for `trap`.

`SIGTERM` handler will now honor `HBASE_STOP_TIMEOUT` as described in the file header.
@Apache-HBase
Copy link

🎊 +1 overall

Vote Subsystem Runtime Comment
+0 🆗 reexec 0m 53s Docker mode activated.
-0 ⚠️ yetus 0m 3s Unprocessed flag(s): --brief-report-file --spotbugs-strict-precheck --whitespace-eol-ignore-list --whitespace-tabs-ignore-list --quick-hadoopcheck
_ Prechecks _
_ master Compile Tests _
_ Patch Compile Tests _
_ Other Tests _
2m 14s
Subsystem Report/Notes
Docker ClientAPI=1.42 ServerAPI=1.42 base: https://ci-hbase.apache.org/job/HBase-PreCommit-GitHub-PR/job/PR-5035/2/artifact/yetus-jdk8-hadoop3-check/output/Dockerfile
GITHUB PR #5035
Optional Tests
uname Linux d7552565e5ac 5.4.0-1097-aws #105~18.04.1-Ubuntu SMP Mon Feb 13 17:50:57 UTC 2023 x86_64 x86_64 x86_64 GNU/Linux
Build tool maven
Personality dev-support/hbase-personality.sh
git revision master / 1673762
Max. process+thread count 29 (vs. ulimit of 30000)
modules C: . U: .
Console output https://ci-hbase.apache.org/job/HBase-PreCommit-GitHub-PR/job/PR-5035/2/console
versions git=2.34.1 maven=3.8.6
Powered by Apache Yetus 0.12.0 https://yetus.apache.org

This message was automatically generated.

@Apache-HBase
Copy link

🎊 +1 overall

Vote Subsystem Runtime Comment
+0 🆗 reexec 0m 24s Docker mode activated.
-0 ⚠️ yetus 0m 3s Unprocessed flag(s): --brief-report-file --spotbugs-strict-precheck --whitespace-eol-ignore-list --whitespace-tabs-ignore-list --quick-hadoopcheck
_ Prechecks _
_ master Compile Tests _
_ Patch Compile Tests _
_ Other Tests _
1m 28s
Subsystem Report/Notes
Docker ClientAPI=1.42 ServerAPI=1.42 base: https://ci-hbase.apache.org/job/HBase-PreCommit-GitHub-PR/job/PR-5035/2/artifact/yetus-jdk11-hadoop3-check/output/Dockerfile
GITHUB PR #5035
Optional Tests
uname Linux c71aedf63cb0 5.4.0-137-generic #154-Ubuntu SMP Thu Jan 5 17:03:22 UTC 2023 x86_64 x86_64 x86_64 GNU/Linux
Build tool maven
Personality dev-support/hbase-personality.sh
git revision master / 1673762
Max. process+thread count 39 (vs. ulimit of 30000)
modules C: . U: .
Console output https://ci-hbase.apache.org/job/HBase-PreCommit-GitHub-PR/job/PR-5035/2/console
versions git=2.34.1 maven=3.8.6
Powered by Apache Yetus 0.12.0 https://yetus.apache.org

This message was automatically generated.

@Apache-HBase
Copy link

🎊 +1 overall

Vote Subsystem Runtime Comment
+0 🆗 reexec 0m 49s Docker mode activated.
_ Prechecks _
+1 💚 dupname 0m 0s No case conflicting files found.
+0 🆗 shelldocs 0m 0s Shelldocs was not available.
+1 💚 @author 0m 0s The patch does not contain any @author tags.
_ master Compile Tests _
+1 💚 spotless 0m 44s branch has no errors when running spotless:check.
_ Patch Compile Tests _
+1 💚 shellcheck 0m 0s The patch generated 0 new + 126 unchanged - 12 fixed = 126 total (was 138)
+1 💚 whitespace 0m 0s The patch has no whitespace issues.
+1 💚 spotless 0m 37s patch has no errors when running spotless:check.
_ Other Tests _
+1 💚 asflicense 0m 11s The patch does not generate ASF License warnings.
3m 31s
Subsystem Report/Notes
Docker ClientAPI=1.42 ServerAPI=1.42 base: https://ci-hbase.apache.org/job/HBase-PreCommit-GitHub-PR/job/PR-5035/2/artifact/yetus-general-check/output/Dockerfile
GITHUB PR #5035
Optional Tests dupname asflicense spotless shellcheck shelldocs
uname Linux 0f81d101c291 5.4.0-137-generic #154-Ubuntu SMP Thu Jan 5 17:03:22 UTC 2023 x86_64 x86_64 x86_64 GNU/Linux
Build tool maven
Personality dev-support/hbase-personality.sh
git revision master / 1673762
Max. process+thread count 44 (vs. ulimit of 30000)
modules C: . U: .
Console output https://ci-hbase.apache.org/job/HBase-PreCommit-GitHub-PR/job/PR-5035/2/console
versions git=2.34.1 maven=3.8.6 shellcheck=0.8.0
Powered by Apache Yetus 0.12.0 https://yetus.apache.org

This message was automatically generated.

@ndimiduk
Copy link
Member Author

Looks like this works as we expect. Running in a kubernetes pod, launching the region server container with bash -x hbase-daemon.sh foreground_start, I see

++ sigterm_handler                                                                                                                                                                                          
++ '[' -f /tmp/hbase-nonroot-regionserver.pid ']'                                                                                                                                                           
+++ cat /tmp/hbase-nonroot-regionserver.pid                                                                                                                                                                 
++ kill -s TERM 17                                                                                                                                                                                          
+++ cat /tmp/hbase-nonroot-regionserver.pid                                                                                                                                                                 
++ waitForProcessEnd 17 regionserver                                                                                                                                                                        
++ pidKilled=17                                                                                                                                                                                             
++ commandName=regionserver                                                                                                                                                                                 
2023-03-17T16:27:36,272 INFO  [shutdown-hook-0] regionserver.ShutdownHook: Shutdown hook starting; hbase.shutdown.hook=true; fsShutdownHook=org.apache.hadoop.fs.FileSystem$Cache$ClientFinalizer@1c33e528  
+++ date +%s                                                                                                                                                                                                
2023-03-17T16:27:36,272 INFO  [shutdown-hook-0] regionserver.HRegionServer: ***** STOPPING region server 'regionserver-4.hadoop.hbase-27707.svc.cluster.local,16020,1679070091660' *****                    
2023-03-17T16:27:36,272 INFO  [shutdown-hook-0] regionserver.HRegionServer: STOPPED: Shutdown hook                                                                                                          
2023-03-17T16:27:36,272 INFO  [regionserver/regionserver-4:16020] regionserver.HRegionServer: Stopping infoServer                                                                                           
++ processedAt=1679070456                                                                                                                                                                                   
++ kill -0 17                                                                                                                                                                                               
++ echo -n .                                                                                                                                                                                                
++ sleep 1                                                                                                                                                                                                  
2023-03-17T16:27:36,278 INFO  [regionserver/regionserver-4:16020] handler.ContextHandler: Stopped o.a.h.t.o.e.j.w.WebAppContext@582e9152{regionserver,/,null,STOPPED}{file:/home/nonroot/hbase/hbase-webapps
/regionserver}                                                                                                                                                                                              
2023-03-17T16:27:36,281 INFO  [regionserver/regionserver-4:16020] server.AbstractConnector: Stopped ServerConnector@c3719e5{HTTP/1.1, (http/1.1)}{0.0.0.0:16030}                                            
2023-03-17T16:27:36,281 INFO  [regionserver/regionserver-4:16020] server.session: node0 Stopped scavenging                                                                                                  
2023-03-17T16:27:36,281 INFO  [regionserver/regionserver-4:16020] handler.ContextHandler: Stopped o.a.h.t.o.e.j.s.ServletContextHandler@29d405e6{prof-output-hbase,/prof-output-hbase,file:///tmp/prof-outpu
t-hbase/,STOPPED}                                                                                                                                                                                           
2023-03-17T16:27:36,281 INFO  [regionserver/regionserver-4:16020] handler.ContextHandler: Stopped o.a.h.t.o.e.j.s.ServletContextHandler@36c7cbe1{static,/static,file:///home/nonroot/hbase/hbase-webapps/sta
tic/,STOPPED}                                                                                                                                                                                               
2023-03-17T16:27:36,281 INFO  [regionserver/regionserver-4:16020] handler.ContextHandler: Stopped o.a.h.t.o.e.j.s.ServletContextHandler@1c628f6a{logs,/logs,file:///var/log/hbase/,STOPPED}                 
2023-03-17T16:27:36,283 INFO  [regionserver/regionserver-4:16020] regionserver.HeapMemoryManager: Stopping                                                                                                  
2023-03-17T16:27:36,283 INFO  [regionserver/regionserver-4:16020] flush.RegionServerFlushTableProcedureManager: Stopping region server flush procedure manager gracefully.                                  
2023-03-17T16:27:36,288 INFO  [MemStoreFlusher.0] regionserver.MemStoreFlusher: MemStoreFlusher.0 exiting                                                                                                   
2023-03-17T16:27:36,288 INFO  [MemStoreFlusher.1] regionserver.MemStoreFlusher: MemStoreFlusher.1 exiting                                                                                                   
2023-03-17T16:27:36,288 INFO  [regionserver/regionserver-4:16020] snapshot.RegionServerSnapshotManager: Stopping RegionServerSnapshotManager gracefully.                                                    
2023-03-17T16:27:36,288 INFO  [regionserver/regionserver-4:16020] regionserver.HRegionServer: Received CLOSE for 929ca0e7c9f445dc9b893b2a02b8f12f                                                           
2023-03-17T16:27:36,289 INFO  [regionserver/regionserver-4:16020] regionserver.HRegionServer: stopping server regionserver-4.hadoop.hbase-27707.svc.cluster.local,16020,1679070091660                       
2023-03-17T16:27:36,289 DEBUG [RS_CLOSE_REGION-regionserver/regionserver-4:16020-0] regionserver.HRegion: Closing 929ca0e7c9f445dc9b893b2a02b8f12f, disabling compactions & flushes                         
2023-03-17T16:27:36,289 INFO  [RS_CLOSE_REGION-regionserver/regionserver-4:16020-0] regionserver.HRegion: Closing region hbase:namespace,,1679063470872.929ca0e7c9f445dc9b893b2a02b8f12f.                   
2023-03-17T16:27:36,289 DEBUG [regionserver/regionserver-4:16020] ipc.AbstractRpcClient: Stopping rpc client                                                                                                
2023-03-17T16:27:36,289 DEBUG [RS_CLOSE_REGION-regionserver/regionserver-4:16020-0] regionserver.HRegion: Waiting without time limit for close lock on hbase:namespace,,1679063470872.929ca0e7c9f445dc9b893b
2a02b8f12f.                                                                                                                                                                                                 
2023-03-17T16:27:36,290 DEBUG [RS_CLOSE_REGION-regionserver/regionserver-4:16020-0] regionserver.HRegion: Acquired close lock on hbase:namespace,,1679063470872.929ca0e7c9f445dc9b893b2a02b8f12f. after wait
ing 0 ms                                                                                                                                                                                                    
2023-03-17T16:27:36,290 INFO  [regionserver/regionserver-4:16020] regionserver.CompactSplit: Waiting for Split Thread to finish...                                                                          
2023-03-17T16:27:36,290 INFO  [regionserver/regionserver-4:16020] regionserver.CompactSplit: Waiting for Large Compaction Thread to finish...                                                               
2023-03-17T16:27:36,290 DEBUG [RS_CLOSE_REGION-regionserver/regionserver-4:16020-0] regionserver.HRegion: Updates disabled for region hbase:namespace,,1679063470872.929ca0e7c9f445dc9b893b2a02b8f12f.
2023-03-17T16:27:36,290 INFO  [regionserver/regionserver-4:16020] regionserver.CompactSplit: Waiting for Small Compaction Thread to finish...
2023-03-17T16:27:36,290 INFO  [regionserver/regionserver-4:16020] regionserver.HRegionServer: Received CLOSE for 1588230740
2023-03-17T16:27:36,290 INFO  [regionserver/regionserver-4:16020] regionserver.HRegionServer: Waiting on 2 regions to close
2023-03-17T16:27:36,290 DEBUG [regionserver/regionserver-4:16020] regionserver.HRegionServer: Online Regions={929ca0e7c9f445dc9b893b2a02b8f12f=hbase:namespace,,1679063470872.929ca0e7c9f445dc9b893b2a02b8f1
2f., 1588230740=hbase:meta,,1.1588230740}
2023-03-17T16:27:36,290 DEBUG [RS_CLOSE_META-regionserver/regionserver-4:16020-0] regionserver.HRegion: Closing 1588230740, disabling compactions & flushes
2023-03-17T16:27:36,290 INFO  [RS_CLOSE_META-regionserver/regionserver-4:16020-0] regionserver.HRegion: Closing region hbase:meta,,1.1588230740
2023-03-17T16:27:36,290 DEBUG [RS_CLOSE_META-regionserver/regionserver-4:16020-0] regionserver.HRegion: Waiting without time limit for close lock on hbase:meta,,1.1588230740
2023-03-17T16:27:36,290 DEBUG [RS_CLOSE_META-regionserver/regionserver-4:16020-0] regionserver.HRegion: Acquired close lock on hbase:meta,,1.1588230740 after waiting 0 ms
2023-03-17T16:27:36,290 DEBUG [RS_CLOSE_META-regionserver/regionserver-4:16020-0] regionserver.HRegion: Updates disabled for region hbase:meta,,1.1588230740
2023-03-17T16:27:36,291 INFO  [RS_CLOSE_META-regionserver/regionserver-4:16020-0] regionserver.HRegion: Flushing 1588230740 3/3 column families, dataSize=1010 B heapSize=2.33 KB
2023-03-17T16:27:36,291 DEBUG [regionserver/regionserver-4:16020] regionserver.HRegionServer: Waiting on 1588230740, 929ca0e7c9f445dc9b893b2a02b8f12f
2023-03-17T16:27:36,306 DEBUG [RS_CLOSE_REGION-regionserver/regionserver-4:16020-0] wal.WALSplitUtil: Wrote file=hdfs://hadoop:8020/hbase/data/hbase/namespace/929ca0e7c9f445dc9b893b2a02b8f12f/recovered.ed
its/27.seqid, newMaxSeqId=27, maxSeqId=24
2023-03-17T16:27:36,309 INFO  [RS_CLOSE_REGION-regionserver/regionserver-4:16020-0] regionserver.HRegion: Closed hbase:namespace,,1679063470872.929ca0e7c9f445dc9b893b2a02b8f12f.
2023-03-17T16:27:36,309 DEBUG [RS_CLOSE_REGION-regionserver/regionserver-4:16020-0] regionserver.HRegion: Region close journal for 929ca0e7c9f445dc9b893b2a02b8f12f:
Waiting for close lock at 1679070456289Running coprocessor pre-close hooks at 1679070456289Disabling compacts and flushes for region at 1679070456289Disabling writes for close at 1679070456290 (+1 ms)Writ
ing region close event to WAL at 1679070456293 (+3 ms)Running coprocessor post-close hooks at 1679070456309 (+16 ms)Closed at 1679070456309
2023-03-17T16:27:36,309 DEBUG [RS_CLOSE_REGION-regionserver/regionserver-4:16020-0] handler.CloseRegionHandler: Closed hbase:namespace,,1679063470872.929ca0e7c9f445dc9b893b2a02b8f12f.
2023-03-17T16:27:36,329 INFO  [RS_CLOSE_META-regionserver/regionserver-4:16020-0] regionserver.DefaultStoreFlusher: Flushed memstore data size=1010 B at sequenceid=60 (bloomFilter=true), to=hdfs://hadoop:
8020/hbase/data/hbase/meta/1588230740/.tmp/info/d93b20e9bbbd4f59a67d88195c646645
2023-03-17T16:27:36,341 DEBUG [RS_CLOSE_META-regionserver/regionserver-4:16020-0] regionserver.HRegionFileSystem: Committing hdfs://hadoop:8020/hbase/data/hbase/meta/1588230740/.tmp/info/d93b20e9bbbd4f59a
67d88195c646645 as hdfs://hadoop:8020/hbase/data/hbase/meta/1588230740/info/d93b20e9bbbd4f59a67d88195c646645
2023-03-17T16:27:36,353 INFO  [RS_CLOSE_META-regionserver/regionserver-4:16020-0] regionserver.HStore: Added hdfs://hadoop:8020/hbase/data/hbase/meta/1588230740/info/d93b20e9bbbd4f59a67d88195c646645, entr
ies=8, sequenceid=60, filesize=6.1 K
2023-03-17T16:27:36,355 INFO  [RS_CLOSE_META-regionserver/regionserver-4:16020-0] regionserver.HRegion: Finished flush of dataSize ~1010 B/1010, heapSize ~1.81 KB/1856, currentSize=0 B/0 for 1588230740 in
 65ms, sequenceid=60, compaction requested=false
2023-03-17T16:27:36,356 DEBUG [StoreCloser-hbase:meta,,1.1588230740-1] regionserver.HStore: Moving the files [hdfs://hadoop:8020/hbase/data/hbase/meta/1588230740/info/3bc308eda0cb42348078c1c66acaf23e, hdf
s://hadoop:8020/hbase/data/hbase/meta/1588230740/info/e70371a201aa415893d73c97d5d2f8e3, hdfs://hadoop:8020/hbase/data/hbase/meta/1588230740/info/5fe9d4128bf441eb8c0c20ec32c1c67b] to archive
2023-03-17T16:27:36,363 DEBUG [StoreCloser-hbase:meta,,1.1588230740-1] backup.HFileArchiver: Archiving compacted files.
2023-03-17T16:27:36,373 DEBUG [StoreCloser-hbase:meta,,1.1588230740-1] backup.HFileArchiver: Archived from FileableStoreFile, hdfs://hadoop:8020/hbase/data/hbase/meta/1588230740/info/3bc308eda0cb42348078c
1c66acaf23e to hdfs://hadoop:8020/hbase/archive/data/hbase/meta/1588230740/info/3bc308eda0cb42348078c1c66acaf23e
2023-03-17T16:27:36,380 DEBUG [StoreCloser-hbase:meta,,1.1588230740-1] backup.HFileArchiver: Archived from FileableStoreFile, hdfs://hadoop:8020/hbase/data/hbase/meta/1588230740/info/e70371a201aa415893d73
c97d5d2f8e3 to hdfs://hadoop:8020/hbase/archive/data/hbase/meta/1588230740/info/e70371a201aa415893d73c97d5d2f8e3
2023-03-17T16:27:36,386 DEBUG [StoreCloser-hbase:meta,,1.1588230740-1] backup.HFileArchiver: Archived from FileableStoreFile, hdfs://hadoop:8020/hbase/data/hbase/meta/1588230740/info/5fe9d4128bf441eb8c0c2
0ec32c1c67b to hdfs://hadoop:8020/hbase/archive/data/hbase/meta/1588230740/info/5fe9d4128bf441eb8c0c20ec32c1c67b
2023-03-17T16:27:36,412 DEBUG [main-SendThread(zookeeper-4:2181)] zookeeper.ClientCnxn: Got ping response for sessionid: 0x50000022ec80006 after 0ms
2023-03-17T16:27:36,418 DEBUG [RS_CLOSE_META-regionserver/regionserver-4:16020-0] wal.WALSplitUtil: Wrote file=hdfs://hadoop:8020/hbase/data/hbase/meta/1588230740/recovered.edits/63.seqid, newMaxSeqId=63,
 maxSeqId=54
2023-03-17T16:27:36,420 DEBUG [RS_CLOSE_META-regionserver/regionserver-4:16020-0] coprocessor.CoprocessorHost: Stop coprocessor org.apache.hadoop.hbase.coprocessor.MultiRowMutationEndpoint
2023-03-17T16:27:36,421 INFO  [RS_CLOSE_META-regionserver/regionserver-4:16020-0] regionserver.HRegion: Closed hbase:meta,,1.1588230740
2023-03-17T16:27:36,421 DEBUG [RS_CLOSE_META-regionserver/regionserver-4:16020-0] regionserver.HRegion: Region close journal for 1588230740:
Waiting for close lock at 1679070456290Running coprocessor pre-close hooks at 1679070456290Disabling compacts and flushes for region at 1679070456290Disabling writes for close at 1679070456290Obtaining lo
ck to block concurrent updates at 1679070456291 (+1 ms)Preparing flush snapshotting stores in 1588230740 at 1679070456291Finished memstore snapshotting hbase:meta,,1.1588230740, syncing WAL and waiting on
 mvcc, flushsize=dataSize=1010, getHeapSize=2336, getOffHeapSize=0, getCellsCount=8 at 1679070456297 (+6 ms)Flushing stores of hbase:meta,,1.1588230740 at 1679070456299 (+2 ms)Flushing 1588230740/info: cr
eating writer at 1679070456299Flushing 1588230740/info: appending metadata at 1679070456306 (+7 ms)Flushing 1588230740/info: closing flushed file at 1679070456306Flushing org.apache.hadoop.hbase.regionser
ver.HStore$StoreFlusherImpl@1f780d7c: reopening flushed file at 1679070456340 (+34 ms)Finished flush of dataSize ~1010 B/1010, heapSize ~1.81 KB/1856, currentSize=0 B/0 for 1588230740 in 65ms, sequenceid=
60, compaction requested=false at 1679070456355 (+15 ms)Writing region close event to WAL at 1679070456408 (+53 ms)Running coprocessor post-close hooks at 1679070456420 (+12 ms)Closed at 1679070456421 (+1
 ms)
2023-03-17T16:27:36,421 DEBUG [RS_CLOSE_META-regionserver/regionserver-4:16020-0] handler.CloseRegionHandler: Closed hbase:meta,,1.1588230740
2023-03-17T16:27:36,491 INFO  [regionserver/regionserver-4:16020] regionserver.HRegionServer: stopping server regionserver-4.hadoop.hbase-27707.svc.cluster.local,16020,1679070091660; all regions closed.
2023-03-17T16:27:36,505 DEBUG [regionserver/regionserver-4:16020] wal.AbstractFSWAL: Moved 1 WAL file(s) to /hbase/oldWALs
2023-03-17T16:27:36,505 INFO  [regionserver/regionserver-4:16020] wal.AbstractFSWAL: Closed WAL: AsyncFSWAL regionserver-4.hadoop.hbase-27707.svc.cluster.local%2C16020%2C1679070091660.meta:.meta(num 16790
70429180)
2023-03-17T16:27:36,517 DEBUG [regionserver/regionserver-4:16020] wal.AbstractFSWAL: Moved 1 WAL file(s) to /hbase/oldWALs
2023-03-17T16:27:36,517 INFO  [regionserver/regionserver-4:16020] wal.AbstractFSWAL: Closed WAL: AsyncFSWAL regionserver-4.hadoop.hbase-27707.svc.cluster.local%2C16020%2C1679070091660:(num 1679070117786)
2023-03-17T16:27:36,517 DEBUG [regionserver/regionserver-4:16020] ipc.AbstractRpcClient: Stopping rpc client
2023-03-17T16:27:36,517 INFO  [regionserver/regionserver-4:16020] regionserver.LeaseManager: Closed leases
2023-03-17T16:27:36,518 INFO  [regionserver/regionserver-4:16020] hbase.ChoreService: Chore service for: regionserver/regionserver-4:16020 had [ScheduledChore name=BrokenStoreFileCleaner, period=21600000,
 unit=MILLISECONDS] on shutdown
2023-03-17T16:27:36,518 INFO  [regionserver/regionserver-4:16020.logRoller] wal.AbstractWALRoller: LogRoller exiting.
2023-03-17T16:27:36,518 INFO  [regionserver/regionserver-4:16020] ipc.NettyRpcServer: Stopping server on /172.31.22.215:16020
2023-03-17T16:27:36,528 DEBUG [main-SendThread(zookeeper-4:2181)] zookeeper.ClientCnxn: Got notification sessionid:0x50000022ec80006
2023-03-17T16:27:36,528 DEBUG [main-SendThread(zookeeper-4:2181)] zookeeper.ClientCnxn: Got WatchedEvent state:SyncConnected type:NodeDeleted path:/hbase/rs/regionserver-4.hadoop.hbase-27707.svc.cluster.l
ocal,16020,1679070091660 for sessionid 0x50000022ec80006
2023-03-17T16:27:36,528 DEBUG [main-SendThread(zookeeper-4:2181)] zookeeper.ClientCnxn: Got notification sessionid:0x50000022ec80006
2023-03-17T16:27:36,528 DEBUG [main-EventThread] zookeeper.ZKWatcher: regionserver:16020-0x50000022ec80006, quorum=zookeeper-0:2181,zookeeper-1:2181,zookeeper-2:2181,zookeeper-3:2181,zookeeper-4:2181, bas
eZNode=/hbase Received ZooKeeper Event, type=NodeDeleted, state=SyncConnected, path=/hbase/rs/regionserver-4.hadoop.hbase-27707.svc.cluster.local,16020,1679070091660
2023-03-17T16:27:36,528 DEBUG [main-SendThread(zookeeper-4:2181)] zookeeper.ClientCnxn: Got WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/hbase/rs for sessionid 0x50000022ec80006
2023-03-17T16:27:36,529 DEBUG [main-EventThread] zookeeper.ZKWatcher: regionserver:16020-0x50000022ec80006, quorum=zookeeper-0:2181,zookeeper-1:2181,zookeeper-2:2181,zookeeper-3:2181,zookeeper-4:2181, bas
eZNode=/hbase Received ZooKeeper Event, type=NodeChildrenChanged, state=SyncConnected, path=/hbase/rs
2023-03-17T16:27:36,529 DEBUG [main-SendThread(zookeeper-4:2181)] zookeeper.ClientCnxn: Reading reply sessionid:0x50000022ec80006, packet:: clientPath:null serverPath:null finished:false header:: 72,2  re
plyHeader:: 72,4294967649,0  request:: '/hbase/rs/regionserver-4.hadoop.hbase-27707.svc.cluster.local%2C16020%2C1679070091660,-1  response:: null
2023-03-17T16:27:36,530 DEBUG [main-SendThread(zookeeper-4:2181)] zookeeper.ClientCnxn: Reading reply sessionid:0x50000022ec80006, packet:: clientPath:null serverPath:null finished:false header:: 73,8  re
plyHeader:: 73,4294967649,0  request:: '/hbase/rs,T  response:: v{'regionserver-3.hadoop.hbase-27707.svc.cluster.local%2C16020%2C1679070186341,'regionserver-2.hadoop.hbase-27707.svc.cluster.local%2C16020%
2C1679070264912,'regionserver-0.hadoop.hbase-27707.svc.cluster.local%2C16020%2C1679070422272,'regionserver-1.hadoop.hbase-27707.svc.cluster.local%2C16020%2C1679070340829} 
2023-03-17T16:27:36,530 DEBUG [regionserver/regionserver-4:16020] zookeeper.ZooKeeper: Closing session: 0x50000022ec80006
2023-03-17T16:27:36,530 DEBUG [regionserver/regionserver-4:16020] zookeeper.ClientCnxn: Closing client for session: 0x50000022ec80006
2023-03-17T16:27:36,533 DEBUG [main-SendThread(zookeeper-4:2181)] zookeeper.ClientCnxn: Reading reply sessionid:0x50000022ec80006, packet:: clientPath:null serverPath:null finished:false header:: 74,-11  
replyHeader:: 74,4294967651,0  request:: null response:: null
2023-03-17T16:27:36,533 DEBUG [regionserver/regionserver-4:16020] zookeeper.ClientCnxn: Disconnecting client for session: 0x50000022ec80006
2023-03-17T16:27:36,533 DEBUG [main-SendThread(zookeeper-4:2181)] zookeeper.ClientCnxn: An exception was thrown while closing send thread for session 0x50000022ec80006 : Unable to read additional data fro
m server sessionid 0x50000022ec80006, likely server has closed socket
2023-03-17T16:27:36,634 DEBUG [main-EventThread] zookeeper.ZKWatcher: regionserver:16020-0x50000022ec80006, quorum=zookeeper-0:2181,zookeeper-1:2181,zookeeper-2:2181,zookeeper-3:2181,zookeeper-4:2181, bas
eZNode=/hbase Received ZooKeeper Event, type=None, state=Closed, path=null
2023-03-17T16:27:36,634 ERROR [main-EventThread] zookeeper.ClientCnxn: Error while calling watcher 
java.util.concurrent.RejectedExecutionException: Task org.apache.hadoop.hbase.trace.TraceUtil$$Lambda$153/0x0000000801036000@79b7a5d7 rejected from java.util.concurrent.ThreadPoolExecutor@56cedb63[Termina
ted, pool size = 0, active threads = 0, queued tasks = 0, completed tasks = 29]
        at java.util.concurrent.ThreadPoolExecutor$AbortPolicy.rejectedExecution(ThreadPoolExecutor.java:2065) ~[?:?]
        at java.util.concurrent.ThreadPoolExecutor.reject(ThreadPoolExecutor.java:833) ~[?:?]
        at java.util.concurrent.ThreadPoolExecutor.execute(ThreadPoolExecutor.java:1365) ~[?:?]
        at java.util.concurrent.Executors$DelegatedExecutorService.execute(Executors.java:721) ~[?:?]
        at org.apache.hadoop.hbase.zookeeper.ZKWatcher.process(ZKWatcher.java:607) ~[hbase-zookeeper-2.5.4.0-27651-3.3.3.2-apple-20230317.151158-1.jar:2.5.4.0-27651-3.3.3.2-apple-SNAPSHOT]
        at org.apache.hadoop.hbase.zookeeper.PendingWatcher.process(PendingWatcher.java:38) ~[hbase-zookeeper-2.5.4.0-27651-3.3.3.2-apple-20230317.151158-1.jar:2.5.4.0-27651-3.3.3.2-apple-SNAPSHOT]
        at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:535) ~[zookeeper-3.5.7.jar:3.5.7]
        at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:510) ~[zookeeper-3.5.7.jar:3.5.7]
2023-03-17T16:27:36,635 DEBUG [main-EventThread] zookeeper.ZKWatcher: regionserver:16020-0x50000022ec80006, quorum=zookeeper-0:2181,zookeeper-1:2181,zookeeper-2:2181,zookeeper-3:2181,zookeeper-4:2181, bas
eZNode=/hbase Received ZooKeeper Event, type=None, state=Closed, path=null
2023-03-17T16:27:36,635 INFO  [regionserver/regionserver-4:16020] zookeeper.ZooKeeper: Session: 0x50000022ec80006 closed
2023-03-17T16:27:36,635 INFO  [regionserver/regionserver-4:16020] regionserver.HRegionServer: Exiting; stopping=regionserver-4.hadoop.hbase-27707.svc.cluster.local,16020,1679070091660; zookeeper connection closed.
2023-03-17T16:27:36,635 ERROR [main-EventThread] zookeeper.ClientCnxn: Error while calling watcher 
java.util.concurrent.RejectedExecutionException: Task org.apache.hadoop.hbase.trace.TraceUtil$$Lambda$153/0x0000000801036000@633db0ec rejected from java.util.concurrent.ThreadPoolExecutor@56cedb63[Terminated, pool size = 0, active threads = 0, queued tasks = 0, completed tasks = 29]
        at java.util.concurrent.ThreadPoolExecutor$AbortPolicy.rejectedExecution(ThreadPoolExecutor.java:2065) ~[?:?]
        at java.util.concurrent.ThreadPoolExecutor.reject(ThreadPoolExecutor.java:833) ~[?:?]
        at java.util.concurrent.ThreadPoolExecutor.execute(ThreadPoolExecutor.java:1365) ~[?:?]
        at java.util.concurrent.Executors$DelegatedExecutorService.execute(Executors.java:721) ~[?:?]
        at org.apache.hadoop.hbase.zookeeper.ZKWatcher.process(ZKWatcher.java:607) ~[hbase-zookeeper-2.5.4.0-27651-3.3.3.2-apple-20230317.151158-1.jar:2.5.4.0-27651-3.3.3.2-apple-SNAPSHOT]
        at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:535) ~[zookeeper-3.5.7.jar:3.5.7]
        at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:510) ~[zookeeper-3.5.7.jar:3.5.7]
2023-03-17T16:27:36,635 INFO  [main-EventThread] zookeeper.ClientCnxn: EventThread shut down for session: 0x50000022ec80006
2023-03-17T16:27:36,635 INFO  [shutdown-hook-0] regionserver.ShutdownHook: Starting fs shutdown hook thread.
2023-03-17T16:27:36,636 DEBUG [ClientFinalizer-shutdown-hook] fs.FileSystem: FileSystem.close() by method: org.apache.hadoop.hdfs.DistributedFileSystem.close(DistributedFileSystem.java:1518)); Key: (nonro
ot (auth:SIMPLE))@hdfs://hadoop:8020; URI: hdfs://hadoop:8020; Object Identity Hash: 7836e2e1
2023-03-17T16:27:36,636 INFO  [shutdown-hook-0] regionserver.ShutdownHook: Shutdown hook finished.
2023-03-17T16:27:36,636 INFO  [main] util.Threads: Non daemon thread Thread-7 is still alive
2023-03-17T16:27:36,636 DEBUG [Thread-7] util.ShutdownHookManager: Completed shutdown in 0.365 seconds; Timeouts: 0
2023-03-17T16:27:36,637 INFO  [main] util.Threads: 
    app//org.apache.logging.log4j.core.appender.rolling.RollingFileManager.checkRollover(RollingFileManager.java:307)
    app//org.apache.logging.log4j.core.appender.RollingFileAppender.append(RollingFileAppender.java:311)
    app//org.apache.logging.log4j.core.config.AppenderControl.tryCallAppender(AppenderControl.java:161)
    app//org.apache.logging.log4j.core.config.AppenderControl.callAppender0(AppenderControl.java:134)
    app//org.apache.logging.log4j.core.config.AppenderControl.callAppenderPreventRecursion(AppenderControl.java:125)
    app//org.apache.logging.log4j.core.config.AppenderControl.callAppender(AppenderControl.java:89)
    app//org.apache.logging.log4j.core.config.LoggerConfig.callAppenders(LoggerConfig.java:675)
    app//org.apache.logging.log4j.core.config.LoggerConfig.processLogEvent(LoggerConfig.java:633)
    app//org.apache.logging.log4j.core.config.LoggerConfig.log(LoggerConfig.java:616)
    app//org.apache.logging.log4j.core.config.LoggerConfig.log(LoggerConfig.java:552)
    app//org.apache.logging.log4j.core.config.AwaitCompletionReliabilityStrategy.log(AwaitCompletionReliabilityStrategy.java:82)
    app//org.apache.logging.log4j.core.Logger.log(Logger.java:161)
    app//org.apache.logging.log4j.spi.AbstractLogger.tryLogMessage(AbstractLogger.java:2205)
    app//org.apache.logging.log4j.spi.AbstractLogger.logMessageTrackRecursion(AbstractLogger.java:2159)
    app//org.apache.logging.log4j.spi.AbstractLogger.logMessageSafely(AbstractLogger.java:2142)
    app//org.apache.logging.log4j.spi.AbstractLogger.logMessage(AbstractLogger.java:2022)
    app//org.apache.logging.log4j.spi.AbstractLogger.logIfEnabled(AbstractLogger.java:1875)
    app//org.apache.logging.slf4j.Log4jLogger.debug(Log4jLogger.java:119)
    app//org.apache.hadoop.util.ShutdownHookManager$1.run(ShutdownHookManager.java:97)
2023-03-17T16:27:36,649 DEBUG [Thread-7] util.ShutdownHookManager: ShutdownHookManager completed shutdown.
+++ date +%s
++ '[' 1 -gt 1200 ']'
++ kill -0 17
++ kill -0 17
++ echo
.
++ cleanAfterRun
++ rm -f /tmp/hbase-nonroot-regionserver.pid
++ '[' -f /tmp/hbase-nonroot-regionserver.znode ']'
+ sigterm_handler
+ '[' -f /tmp/hbase-nonroot-regionserver.pid ']'
+ cleanAfterRun
+ rm -f /tmp/hbase-nonroot-regionserver.pid
+ '[' -f /tmp/hbase-nonroot-regionserver.znode ']'

@Apache9
Copy link
Contributor

Apache9 commented Mar 19, 2023

So in the old code we will always use kill -9 when receiving any signals, and the PR here will handle SIGHUP differently?

@ndimiduk
Copy link
Member Author

So in the old code we will always use kill -9 when receiving any signals, and the PR here will handle SIGHUP differently?

Correct.

@ndimiduk
Copy link
Member Author

The new code will also honor the documented timeout between sending SIGTERM and SIGKILL.

@ndimiduk ndimiduk merged commit 814f326 into apache:master Mar 20, 2023
@ndimiduk ndimiduk deleted the 27651-hbase-daemon-sigs branch March 20, 2023 13:58
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
4 participants