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

HHVM 3.15 package for Ubuntu 14.04/16.04 crashes and it is unstable #7333

Closed
javuto opened this issue Sep 11, 2016 · 19 comments
Closed

HHVM 3.15 package for Ubuntu 14.04/16.04 crashes and it is unstable #7333

javuto opened this issue Sep 11, 2016 · 19 comments

Comments

@javuto
Copy link

javuto commented Sep 11, 2016

HHVM Version

The package installed in both Ubuntu 14.04 and 16.04 from the HHVM repositories do not work properly. This is the output of hhvm --version:

HipHop VM 3.15.0 (rel)
Compiler: tags/HHVM-3.15.0-0-g92a682ebaa3c85b84857852d8621f528607fe27d
Repo schema: 225d4323575bbc8a498dc809a1c41354f6bca830

Standalone code, or other way to reproduce the problem

I am seeing this problem with the fbctf project, since the 3.15 package was released, the platform is not working at all. Tried to isolate the problem but it was completely unstable and I was not able to isolate. HHVM was just crashing.

A simple index.php file with just phpinfo() would work but it does return the same 502 Bad gateway intermittently.

Actual result

HHVM is used as fastcgi within nginx and an error (502 Bad Gateway) is returned to nginx. The output of /var/log/hhvm/error.log is:

[Sun Sep 11 02:00:21 2016] [hphp] [22511:7fdf75fff700:0:000001] [] Core dumped: Aborted
[Sun Sep 11 02:00:21 2016] [hphp] [22511:7fdf75fff700:0:000002] [] Stack trace in /tmp/stacktrace.22511.log

Being the content of the log in /tmp empty.

Tried to remove the 3.15 version and install manually the 3.14 package from http://dl.hhvm.com/ubuntu/pool/main/h/hhvm/ and there was no issues at all, working as expected.

@jonghorhee
Copy link

jonghorhee commented Sep 12, 2016

I've got this issue with fbctf(by vagrant up). I attached some debug log of HHVM-nightly-dgb.
Please check this logs and attached file. tc_dump.tar.gz

$ uname -a
Linux facebookctf-dev 3.13.0-95-generic #142-Ubuntu SMP Fri Aug 12 17:00:09 UTC 2016 x86_64 x86_64 x86_64 GNU/Linux

$ hhvm --version
HipHop VM 3.15.0-dev (dbg)
Compiler: heads/master-0-g0f6b3313f6886d146456c9ad618541eff6fe8392
Repo schema: 4c9ff4fc5c1565dfa736e3fc91c4ae10f9168ecb

$ cat /etc/hhvm/server.ini
; php options
pid = /var/run/hhvm/pid
; hhvm specific
hhvm.jit = true
;hhvm.enable_reusable_tc = true
hhvm.enable_xhp = true
hhvm.force_hh = true
hhvm.server.type = fastcgi
hhvm.server.ip = 127.0.0.1
hhvm.server.file_socket = /var/run/hhvm/sock
hhvm.server.default_document = index.php
hhvm.server.upload.upload_max_file_size = 25M
hhvm.log.level = Info
hhvm.log.use_log_file = true
hhvm.log.file = /var/log/hhvm/error.log
hhvm.log.header = true
hhvm.log.access[default][file] = /var/log/hhvm/access.log
hhvm.log.access[default][format] = "%h %l %u %t "%r" %>s %b"
hhvm.server.source_root = /var/www/fbctf/
hhvm.repo.central.path = /var/run/hhvm/hhvm.hhbc
hhvm.mysql.socket = /var/run/mysqld/mysqld.sock
hhvm.pdo_mysql.socket = /var/run/mysqld/mysqld.sock
hhvm.mysqli.socket = /var/run/mysqld/mysqld.sock

$ cat /var/log/nginx/error.log
2016/09/12 09:31:29 [error] 30027#0: *17 upstream prematurely closed connection while reading response header from upstream, client: 192.168.10.1, server: , request: "GET / HTTP/1.1", upstream: "fastcgi://unix:/var/run/hhvm/sock:", host: "192.168.10.5"

$ cat /var/log/hhvm/error.log
[Mon Sep 12 09:30:59 2016] [hphp] [30620:7f439bbe44c0:0:000001] [] BootStats: mapping self...
[Mon Sep 12 09:30:59 2016] [hphp] [30620:7f439bbe44c0:0:000002] [] BootStats: mapping self block done, took 37ms wall, 33ms cpu, 208 MB RSS
[Mon Sep 12 09:30:59 2016] [hphp] [30620:7f439bbe44c0:0:000003] [] BootStats: pagein_self done, took 38ms wall, 33ms cpu, 208 MB RSS
[Mon Sep 12 09:30:59 2016] [hphp] [30620:7f439bbe44c0:0:000004] [] BootStats: loading static content...
[Mon Sep 12 09:30:59 2016] [hphp] [30620:7f439bbe44c0:0:000005] [] BootStats: loading static content block done, took 0ms wall, 0ms cpu, 0 MB RSS
[Mon Sep 12 09:30:59 2016] [hphp] [30620:7f439bbe44c0:0:000006] [] BootStats: pthread_init done, took 1ms wall, 1ms cpu, 0 MB RSS
[Mon Sep 12 09:30:59 2016] [hphp] [30620:7f439bbe44c0:0:000007] [] BootStats: Process::InitProcessStatics done, took 0ms wall, 0ms cpu, 0 MB RSS
[Mon Sep 12 09:30:59 2016] [hphp] [30620:7f439bbe44c0:0:000008] [] BootStats: timezone_init done, took 0ms wall, 0ms cpu, 0 MB RSS
[Mon Sep 12 09:30:59 2016] [hphp] [30620:7f439bbe44c0:0:000009] [] BootStats: xenon done, took 0ms wall, 0ms cpu, 0 MB RSS
[Mon Sep 12 09:30:59 2016] [hphp] [30620:7f439bbe44c0:0:000010] [] BootStats: pcre_reinit done, took 17ms wall, 17ms cpu, 0 MB RSS
[Mon Sep 12 09:30:59 2016] [hphp] [30620:7f439bbe44c0:0:000011] [] BootStats: onig_init done, took 0ms wall, 0ms cpu, 0 MB RSS
[Mon Sep 12 09:30:59 2016] [hphp] [30620:7f439bbe44c0:0:000012] [] BootStats: xmlInitParser done, took 0ms wall, 0ms cpu, 0 MB RSS
[Mon Sep 12 09:30:59 2016] [hphp] [30620:7f439bbe44c0:0:000013] [] BootStats: g_vmProcessInit done, took 156ms wall, 155ms cpu, 11 MB RSS
[Mon Sep 12 09:30:59 2016] [hphp] [30620:7f439bbe44c0:0:000014] [] BootStats: PageletServer::Restart done, took 0ms wall, 0ms cpu, 0 MB RSS
[Mon Sep 12 09:30:59 2016] [hphp] [30620:7f439bbe44c0:0:000015] [] BootStats: XboxServer::Restart done, took 0ms wall, 0ms cpu, 0 MB RSS
[Mon Sep 12 09:30:59 2016] [hphp] [30620:7f439bbe44c0:0:000016] [] BootStats: Stream::RegisterCoreWrappers done, took 0ms wall, 0ms cpu, 0 MB RSS
[Mon Sep 12 09:31:00 2016] [hphp] [30620:7f439bbe44c0:0:000017] [] BootStats: ExtensionRegistry::moduleInit done, took 347ms wall, 341ms cpu, 6 MB RSS
[Mon Sep 12 09:31:00 2016] [hphp] [30620:7f439bbe44c0:0:000018] [] BootStats: extra_process_init done, took 0ms wall, 0ms cpu, 0 MB RSS
[Mon Sep 12 09:31:00 2016] [hphp] [30620:7f439bbe44c0:0:000019] [] BootStats: apc_load done, took 0ms wall, 0ms cpu, 0 MB RSS
[Mon Sep 12 09:31:00 2016] [hphp] [30620:7f439bbe44c0:0:000020] [] BootStats: rds::requestExit done, took 0ms wall, 0ms cpu, 0 MB RSS
[Mon Sep 12 09:31:00 2016] [hphp] [30620:7f439bbe44c0:0:000021] [] BootStats: ExecutionContext done, took 0ms wall, 0ms cpu, 0 MB RSS
[Mon Sep 12 09:31:00 2016] [hphp] [30620:7f439bbe44c0:0:000022] [] BootStats: extra_process_init_concurrent_wait done, took 0ms wall, 0ms cpu, 0 MB RSS
[Mon Sep 12 09:31:00 2016] [hphp] [30620:7f439bbe44c0:0:000023] [] Warming up
[Mon Sep 12 09:31:00 2016] [hphp] [30620:7f439bbe44c0:0:000024] [] BootStats: warmup done, took 0ms wall, 0ms cpu, 0 MB RSS
[Mon Sep 12 09:31:00 2016] [hphp] [30620:7f439bbe44c0:0:000025] [] BootStats: enable_numa done, took 0ms wall, 0ms cpu, 0 MB RSS
[Mon Sep 12 09:31:00 2016] [hphp] [30620:7f439bbe44c0:0:000026] [] trying to shut down old HPHP server by /stop command
[Mon Sep 12 09:31:00 2016] [hphp] [30620:7f439bbe44c0:0:000027] [] Unlinking unused socket at /var/run/hhvm/sock
[Mon Sep 12 09:31:01 2016] [hphp] [30620:7f439bbe44c0:0:000028] [] page server started
[Mon Sep 12 09:31:01 2016] [hphp] [30620:7f439bbe44c0:0:000029] [] BootStats: servers started done, took 1012ms wall, 6ms cpu, 1 MB RSS
[Mon Sep 12 09:31:01 2016] [hphp] [30620:7f439bbe44c0:0:000030] [] all servers started
[Mon Sep 12 09:31:01 2016] [hphp] [30620:7f439bbe44c0:0:000031] [] BootStats: all done, took 1577ms wall, 559ms cpu, 226 MB RSS total
[Mon Sep 12 09:31:01 2016] [hphp] [30620:7f439bbe44c0:0:000032] [] BootStats: ExecutionContext = 0ms wall, 0ms cpu, 0 MB RSS
[Mon Sep 12 09:31:01 2016] [hphp] [30620:7f439bbe44c0:0:000033] [] BootStats: ExtensionRegistry::moduleInit = 347ms wall, 341ms cpu, 6 MB RSS
[Mon Sep 12 09:31:01 2016] [hphp] [30620:7f439bbe44c0:0:000034] [] BootStats: PageletServer::Restart = 0ms wall, 0ms cpu, 0 MB RSS
[Mon Sep 12 09:31:01 2016] [hphp] [30620:7f439bbe44c0:0:000035] [] BootStats: Process::InitProcessStatics = 0ms wall, 0ms cpu, 0 MB RSS
[Mon Sep 12 09:31:01 2016] [hphp] [30620:7f439bbe44c0:0:000036] [] BootStats: Stream::RegisterCoreWrappers = 0ms wall, 0ms cpu, 0 MB RSS
[Mon Sep 12 09:31:01 2016] [hphp] [30620:7f439bbe44c0:0:000037] [] BootStats: TOTAL = 1577ms wall, 559ms cpu, 226 MB RSS
[Mon Sep 12 09:31:01 2016] [hphp] [30620:7f439bbe44c0:0:000038] [] BootStats: XboxServer::Restart = 0ms wall, 0ms cpu, 0 MB RSS
[Mon Sep 12 09:31:01 2016] [hphp] [30620:7f439bbe44c0:0:000039] [] BootStats: apc_load = 0ms wall, 0ms cpu, 0 MB RSS
[Mon Sep 12 09:31:01 2016] [hphp] [30620:7f439bbe44c0:0:000040] [] BootStats: enable_numa = 0ms wall, 0ms cpu, 0 MB RSS
[Mon Sep 12 09:31:01 2016] [hphp] [30620:7f439bbe44c0:0:000041] [] BootStats: extra_process_init = 0ms wall, 0ms cpu, 0 MB RSS
[Mon Sep 12 09:31:01 2016] [hphp] [30620:7f439bbe44c0:0:000042] [] BootStats: extra_process_init_concurrent_wait = 0ms wall, 0ms cpu, 0 MB RSS
[Mon Sep 12 09:31:01 2016] [hphp] [30620:7f439bbe44c0:0:000043] [] BootStats: g_vmProcessInit = 156ms wall, 155ms cpu, 11 MB RSS
[Mon Sep 12 09:31:01 2016] [hphp] [30620:7f439bbe44c0:0:000044] [] BootStats: loading static content = 0ms wall, 0ms cpu, 0 MB RSS
[Mon Sep 12 09:31:01 2016] [hphp] [30620:7f439bbe44c0:0:000045] [] BootStats: mapping self = 37ms wall, 33ms cpu, 208 MB RSS
[Mon Sep 12 09:31:01 2016] [hphp] [30620:7f439bbe44c0:0:000046] [] BootStats: onig_init = 0ms wall, 0ms cpu, 0 MB RSS
[Mon Sep 12 09:31:01 2016] [hphp] [30620:7f439bbe44c0:0:000047] [] BootStats: pagein_self = 38ms wall, 33ms cpu, 208 MB RSS
[Mon Sep 12 09:31:01 2016] [hphp] [30620:7f439bbe44c0:0:000048] [] BootStats: pcre_reinit = 17ms wall, 17ms cpu, 0 MB RSS
[Mon Sep 12 09:31:01 2016] [hphp] [30620:7f439bbe44c0:0:000049] [] BootStats: pthread_init = 1ms wall, 1ms cpu, 0 MB RSS
[Mon Sep 12 09:31:01 2016] [hphp] [30620:7f439bbe44c0:0:000050] [] BootStats: rds::requestExit = 0ms wall, 0ms cpu, 0 MB RSS
[Mon Sep 12 09:31:01 2016] [hphp] [30620:7f439bbe44c0:0:000051] [] BootStats: servers started = 1012ms wall, 6ms cpu, 1 MB RSS
[Mon Sep 12 09:31:01 2016] [hphp] [30620:7f439bbe44c0:0:000052] [] BootStats: timezone_init = 0ms wall, 0ms cpu, 0 MB RSS
[Mon Sep 12 09:31:01 2016] [hphp] [30620:7f439bbe44c0:0:000053] [] BootStats: warmup = 0ms wall, 0ms cpu, 0 MB RSS
[Mon Sep 12 09:31:01 2016] [hphp] [30620:7f439bbe44c0:0:000054] [] BootStats: xenon = 0ms wall, 0ms cpu, 0 MB RSS
[Mon Sep 12 09:31:01 2016] [hphp] [30620:7f439bbe44c0:0:000055] [] BootStats: xmlInitParser = 0ms wall, 0ms cpu, 0 MB RSS
[Mon Sep 12 09:31:28 2016] [hphp] [30620:7f4382bff700:0:000001] [7f439941d330:7f4393d4ec37:7f4393d52028:7f4399a5bd81:7f4399a5bdaa:7f4399a5bce4:7f4399a5b6e6:7f4399a5e687:70b0194:6f8ae81:6f8aeb9:6f92880:6f90aa4:6f8e137:6f8e098:6f8df5c:6f8ee97:6f7b829:6f83083:6f8245c:6f8209a:6f81616:4b04344:6f69adf:6f717cc:7086cd7:70f8a14:710009d:70ff120:70d2d4d:7f4399ef7f24:70fbdc1:70fb94f:70fcb83:6f69968:6f77b00:6f77875:6f77408:7f43946aaa60:7f4399415184:7f4393e1237d] Core dumped: Aborted
[Mon Sep 12 09:31:28 2016] [hphp] [30620:7f4382bff700:0:000002] [7f439941d330:7f4393d4ec37:7f4393d52028:7f4399a5bd81:7f4399a5bdaa:7f4399a5bce4:7f4399a5b6e6:7f4399a5e687:70b0194:6f8ae81:6f8aeb9:6f92880:6f90aa4:6f8e137:6f8e098:6f8df5c:6f8ee97:6f7b829:6f83083:6f8245c:6f8209a:6f81616:4b04344:6f69adf:6f717cc:7086cd7:70f8a14:710009d:70ff120:70d2d4d:7f4399ef7f24:70fbdc1:70fb94f:70fcb83:6f69968:6f77b00:6f77875:6f77408:7f43946aaa60:7f4399415184:7f4393e1237d] Stack trace in /tmp/stacktrace.30620.log

$ cat /tmp/stacktrace.30620.log
Host: facebookctf-dev
ProcessID: 30621
ThreadID: 139927933155072
ThreadPID: 30648
Name: unknown program
Type: Aborted
Runtime: hhvm
Version: heads/master-0-g0f6b3313f6886d146456c9ad618541eff6fe8392
DebuggerCount: 0

#0 0000000004d2575f
#1 0000000004f93748
#2 00007f439941d330
#3 00007f4393d4ec37
#4 00007f4393d52028
#5 00007f4399a5bd81
#6 00007f4399a5bdaa
#7 00007f4399a5bce4
#8 00007f4399a5b6e6
#9 00007f4399a5e687
#10 00000000070b0194
#11 0000000006f8ae81
#12 0000000006f8aeb9
#13 0000000006f92880
#14 0000000006f90aa4
#15 0000000006f8e137
#16 0000000006f8e098
#17 0000000006f8df5c
#18 0000000006f8ee97
#19 0000000006f7b829
#20 0000000006f83083
#21 0000000006f8245c
#22 0000000006f8209a
#23 0000000006f81616
#24 0000000004b04344
#25 0000000006f69adf
#26 0000000006f717cc
#27 0000000007086cd7
#28 00000000070f8a14
#29 000000000710009d
#30 00000000070ff120
#31 00000000070d2d4d
#32 00007f4399ef7f24
#33 00000000070fbdc1
#34 00000000070fb94f
#35 00000000070fcb83
#36 0000000006f69968
#37 0000000006f77b00
#38 0000000006f77875
#39 0000000006f77408
#40 00007f43946aaa60
#41 00007f4399415184
#42 00007f4393e1237d

@jonghorhee
Copy link

HHVM 3.14.5 is no problem on FBCTF VBox.
facebookarchive/fbctf#215 (comment)

@eeeehaw
Copy link

eeeehaw commented Sep 26, 2016

I am having this problem even with HHVM 3.14.5. It consistently stops running the hhvm service upon restart of the virtual machine (VM) running Ubuntu 14.04 on both Azure and Google Cloud. It works fine right after the initial provisioning script execution of FBCTF (at least so far I haven't noticed any problems), but upon stop/start of the VM on either cloud service HHVM fails to run (confirmed via 'sudo service hhvm status') and thus NGIX produces it's "502 Bad Gateway" error page to the client browser. I separately reported this Issue to HHVM at #7387.

@fredemmott
Copy link
Contributor

Can you reproduce this with a debug package? That might get a usable backtrace.

@eeeehaw
Copy link

eeeehaw commented Sep 29, 2016

Fred, I'm assuming you mean a debug package of HHVM 3.14.5. Where can I get this?

@fredemmott
Copy link
Contributor

3.15.0 - just install the hhvm-dbg package with apt instead of hhvm

@eeeehaw
Copy link

eeeehaw commented Sep 29, 2016

Ok, I installed hhvm-dbg v3.15 per HHVM install instructions for Ubuntu 14.04. There was a warning message that caught my eye, see my console output during the install below.

Note: I had received some suggested commands to try from the FBCTF team that turned out to be a work-around for this problem, here is what they are:

sudo rm /var/run/hhvm/hhvm.hhbc
sudo hhvm-repo-mode enable "/var/www/fbctf"
sudo chown www-data:www-data /var/run/hhvm/hhvm.hhbc

sudo service hhvm start

After running the above cli, hhvm v3.14.5 service shows as running and everything else works fine again, altho IF the machine is restarted hhvm service fails to run and the problem is back until these commands are run again.

Before the hhvm-dbg v3.15 installation, hhvm v3.14.5 service was running and everything was working fine. After the installation, the hhvm 3.15 service was not running, and worse yet I could not run the work-around cli commands above to get it to stay running, ie 'service hhvm status' would show it as running but at some point soon after that it showed not running again. Ie, there's something about v3.15 that makes it behave worse than v3.14.5, which is a confirmation of the Issue that the FBCTF team opened elsewhere here about that.

Fred, help me get started on how to do a backtrace for you with this newly installed hhvm-dbg 3.15, I don't know how to do that.

Meanwhile here's my console output during the installation of hhvm-dbg 3.15, notice the warning near the end about "clashing" NGINX config in it (an error I don't see when installing the FBCTF package with HHVM 3.14.5, thus further indication that something may have changed in hhvm between 3.14.5 and 3.15 that affects this). (nginx, NOT appache, is being used as the webserver for fbctf)

eeeehaw@cyberwars-vm1:$ sudo apt-get install software-properties-common
Reading package lists... Done
Building dependency tree
Reading state information... Done
software-properties-common is already the newest version.
The following package was automatically installed and is no longer required:
libpq5
Use 'apt-get autoremove' to remove it.
0 upgraded, 0 newly installed, 0 to remove and 16 not upgraded.
eeeehaw@cyberwars-vm1:
$ sudo apt-key adv --recv-keys --keyserver hkp://keyserver.ubuntu.com:80 0x5a16e7281be7a449
Executing: gpg --ignore-time-conflict --no-options --no-default-keyring --homedir /tmp/tmp.C7PaAaBKmY --no-auto-check-trustdb --trust-model always --keyring /etc/apt/trusted.gpg --primary-keyring /etc/apt/trusted.gpg --recv-keys --keyserver hkp://keyserver.ubuntu.com:80 0x5a16e7281be7a449
gpg: requesting key 1BE7A449 from hkp server keyserver.ubuntu.com
gpg: key 1BE7A449: "Paul Tarjan pt@fb.com" not changed
gpg: Total number processed: 1
gpg: unchanged: 1
eeeehaw@cyberwars-vm1:$ sudo add-apt-repository "deb http://dl.hhvm.com/ubuntu $(lsb_release -sc) main"
eeeehaw@cyberwars-vm1:
$ sudo apt-get update
Get:1 http://dl.hhvm.com trusty InRelease [2,104 B]
Get:2 http://dl.hhvm.com trusty/main amd64 Packages [1,743 B]
Get:3 http://security.ubuntu.com trusty-security InRelease [65.9 kB]
Ign http://dl.hhvm.com trusty/main Translation-en_US
Ign http://dl.hhvm.com trusty/main Translation-en
Ign http://archive.canonical.com trusty InRelease
Get:4 http://security.ubuntu.com trusty-security/main Sources [120 kB]
Hit http://archive.canonical.com trusty Release.gpg
Ign http://us-west1-a.gce.clouds.archive.ubuntu.com trusty InRelease
Get:5 http://security.ubuntu.com trusty-security/universe Sources [43.6 kB]
Hit http://archive.canonical.com trusty Release
Get:6 http://us-west1-a.gce.clouds.archive.ubuntu.com trusty-updates InRelease [65.9 kB]
Get:7 http://security.ubuntu.com trusty-security/main amd64 Packages [531 kB]
Hit http://archive.canonical.com trusty/partner amd64 Packages
Hit http://archive.canonical.com trusty/partner Translation-en
Get:8 http://security.ubuntu.com trusty-security/universe amd64 Packages [138 kB]
Get:9 http://security.ubuntu.com trusty-security/main Translation-en [292 kB]
Get:10 http://us-west1-a.gce.clouds.archive.ubuntu.com trusty-backports InRelease [65.9 kB]
Get:11 http://security.ubuntu.com trusty-security/universe Translation-en [82.7 kB]
Hit http://us-west1-a.gce.clouds.archive.ubuntu.com trusty Release.gpg
Get:12 http://us-west1-a.gce.clouds.archive.ubuntu.com trusty-updates/main Sources [383 kB]
Get:13 http://us-west1-a.gce.clouds.archive.ubuntu.com trusty-updates/restricted Sources [5,360 B]
Get:14 http://us-west1-a.gce.clouds.archive.ubuntu.com trusty-updates/universe Sources [166 kB]
Get:15 http://us-west1-a.gce.clouds.archive.ubuntu.com trusty-updates/multiverse Sources [7,520 B]
Get:16 http://us-west1-a.gce.clouds.archive.ubuntu.com trusty-updates/main amd64 Packages [901 kB]
Get:17 http://us-west1-a.gce.clouds.archive.ubuntu.com trusty-updates/restricted amd64 Packages [15.9 kB]
Get:18 http://us-west1-a.gce.clouds.archive.ubuntu.com trusty-updates/universe amd64 Packages [376 kB]
Get:19 http://us-west1-a.gce.clouds.archive.ubuntu.com trusty-updates/multiverse amd64 Packages [15.0 kB]
Get:20 http://us-west1-a.gce.clouds.archive.ubuntu.com trusty-updates/main Translation-en [437 kB]
Get:21 http://us-west1-a.gce.clouds.archive.ubuntu.com trusty-updates/multiverse Translation-en [7,931 B]
Get:22 http://us-west1-a.gce.clouds.archive.ubuntu.com trusty-updates/restricted Translation-en [3,699 B]
Get:23 http://us-west1-a.gce.clouds.archive.ubuntu.com trusty-updates/universe Translation-en [199 kB]
Get:24 http://us-west1-a.gce.clouds.archive.ubuntu.com trusty-backports/main Sources [9,626 B]
Get:25 http://us-west1-a.gce.clouds.archive.ubuntu.com trusty-backports/restricted Sources [28 B]
Get:26 http://us-west1-a.gce.clouds.archive.ubuntu.com trusty-backports/universe Sources [35.2 kB]
Get:27 http://us-west1-a.gce.clouds.archive.ubuntu.com trusty-backports/multiverse Sources [1,898 B]
Get:28 http://us-west1-a.gce.clouds.archive.ubuntu.com trusty-backports/main amd64 Packages [13.3 kB]
Get:29 http://us-west1-a.gce.clouds.archive.ubuntu.com trusty-backports/restricted amd64 Packages [28 B]
Get:30 http://us-west1-a.gce.clouds.archive.ubuntu.com trusty-backports/universe amd64 Packages [43.2 kB]
Get:31 http://us-west1-a.gce.clouds.archive.ubuntu.com trusty-backports/multiverse amd64 Packages [1,571 B]
Hit http://us-west1-a.gce.clouds.archive.ubuntu.com trusty-backports/main Translation-en
Hit http://us-west1-a.gce.clouds.archive.ubuntu.com trusty-backports/multiverse Translation-en
Hit http://us-west1-a.gce.clouds.archive.ubuntu.com trusty-backports/restricted Translation-en
Hit http://us-west1-a.gce.clouds.archive.ubuntu.com trusty-backports/universe Translation-en
Hit http://us-west1-a.gce.clouds.archive.ubuntu.com trusty Release
Hit http://us-west1-a.gce.clouds.archive.ubuntu.com trusty/main Sources
Hit http://us-west1-a.gce.clouds.archive.ubuntu.com trusty/restricted Sources
Hit http://us-west1-a.gce.clouds.archive.ubuntu.com trusty/universe Sources
Hit http://us-west1-a.gce.clouds.archive.ubuntu.com trusty/multiverse Sources
Hit http://us-west1-a.gce.clouds.archive.ubuntu.com trusty/main amd64 Packages
Hit http://us-west1-a.gce.clouds.archive.ubuntu.com trusty/restricted amd64 Packages
Hit http://us-west1-a.gce.clouds.archive.ubuntu.com trusty/universe amd64 Packages
Hit http://us-west1-a.gce.clouds.archive.ubuntu.com trusty/multiverse amd64 Packages
Hit http://us-west1-a.gce.clouds.archive.ubuntu.com trusty/main Translation-en
Hit http://us-west1-a.gce.clouds.archive.ubuntu.com trusty/multiverse Translation-en
Hit http://us-west1-a.gce.clouds.archive.ubuntu.com trusty/restricted Translation-en
Hit http://us-west1-a.gce.clouds.archive.ubuntu.com trusty/universe Translation-en
Ign http://us-west1-a.gce.clouds.archive.ubuntu.com trusty/main Translation-en_US
Ign http://us-west1-a.gce.clouds.archive.ubuntu.com trusty/multiverse Translation-en_US
Ign http://us-west1-a.gce.clouds.archive.ubuntu.com trusty/restricted Translation-en_US
Ign http://us-west1-a.gce.clouds.archive.ubuntu.com trusty/universe Translation-en_US
Fetched 4,031 kB in 10s (384 kB/s)
Reading package lists... Done
eeeehaw@cyberwars-vm1:$ sudo apt-get install hhvm-dbg
Reading package lists... Done
Building dependency tree
Reading state information... Done
The following packages will be REMOVED:
hhvm
The following NEW packages will be installed:
hhvm-dbg
0 upgraded, 1 newly installed, 1 to remove and 15 not upgraded.
Need to get 299 MB of archives.
After this operation, 0 B of additional disk space will be used.
Do you want to continue? [Y/n] Y
Get:1 http://dl.hhvm.com/ubuntu/ trusty/main hhvm-dbg amd64 3.15.0
trusty [299 MB]
Fetched 299 MB in 9s (33.1 MB/s)
(Reading database ... 42824 files and directories currently installed.)
Removing hhvm (3.14.5~trusty) ...


  • HHVM is being removed. You can remove it from your webserver with:
  • $ sudo /usr/share/hhvm/uninstall_fastcgi.sh
  • $ sudo /etc/init.d/nginx restart
  • $ sudo /etc/init.d/apache restart
    update-alternatives: warning: alternative /usr/bin/hhvm (part of link group php) doesn't exist; removing from list of alternatives
    update-alternatives: warning: /etc/alternatives/php is dangling; it will be updated with best choice
    Processing triggers for libc-bin (2.19-0ubuntu6.9) ...
    Selecting previously unselected package hhvm-dbg.
    (Reading database ... 42763 files and directories currently installed.)
    Preparing to unpack .../hhvm-dbg_3.15.0trusty_amd64.deb ...
    Unpacking hhvm-dbg (3.15.0
    trusty) ...
    Processing triggers for ureadahead (0.100.0-16) ...
    Setting up hhvm-dbg (3.15.0~trusty) ...
    update-alternatives: using /usr/bin/hhvm to provide /usr/bin/php (php) in auto mode
  • HHVM is installed.
    *
  • Running PHP web scripts with HHVM is done by having your
  • webserver talk to HHVM over FastCGI. Install nginx or Apache,
  • and then:
  • $ sudo /usr/share/hhvm/install_fastcgi.sh
    (lsb_release -sc) main"
  • $ sudo /etc/init.d/hhvm restart
  • (if using nginx) $ sudo /etc/init.d/nginx restart
  • (if using apache) $ sudo /etc/init.d/apache restart
    *
  • Detailed FastCGI directions are online at:
  • https://github.com/facebook/hhvm/wiki/FastCGI
    *
  • If you're using HHVM to run web scripts, you probably want it
  • to start at boot:
  • $ sudo update-rc.d hhvm defaults
    *
  • Running command-line scripts with HHVM requires no special setup:
  • $ hhvm whatever.php
    *
  • You can use HHVM for /usr/bin/php even if you have php-cli
  • installed:
  • $ sudo /usr/bin/update-alternatives \
  • --install /usr/bin/php php /usr/bin/hhvm 60

eeeehaw@cyberwars-vm1:$ sudo /usr/share/hhvm/install_fastcgi.sh
Checking if Apache is installed
WARNING: Couldn't find Apache2 configuration paths, not configuring
Checking if Nginx is installed
Detected Nginx installation
Checking for custom Nginx configuration
WARNING: Detected clashing configuration. Look at /etc/nginx/hhvm.conf for information how to connect to the hhvm fastcgi i
nstance.

eeeehaw@cyberwars-vm1:
$ sudo /etc/init.d/hhvm restart

  • Restarting HHVM FastCGI Daemon hhvm [ OK ]
    eeeehaw@cyberwars-vm1:~$ sudo /etc/init.d/nginx restart
  • Restarting nginx nginx [ OK ]
    eeeehaw@cyberwars-vm1:~$ service hhvm status
  • hhvm is not running
    eeeehaw@cyberwars-vm1:~$ service nginx status
  • nginx is running
    eeeehaw@cyberwars-vm1:~$

@eeeehaw
Copy link

eeeehaw commented Sep 29, 2016

Fred, sorry about the large bold font in above paragraphs. I didn't specify that, somehow this github platform decided to do that for me. I'm NOT trying to yell or anything :-)

@fredemmott
Copy link
Contributor

  • try doing whatever you were doing that got the backtrace before; that paste isn't useful
  • enclose pastes like that with triple backticks
  • I'm no longer on HHVM and won't be investigating; just trying to help you get enough information in this issue to increase the chances of it being fixed

@eeeehaw
Copy link

eeeehaw commented Sep 29, 2016

Ok, maybe I'm not clear on what you mean by "backtrace". I haven't run a hhvm debug package before, nor run an explicit trace (that I know of). How to do that? Thx for tip on triple backticks.

@fredemmott
Copy link
Contributor

fredemmott commented Sep 29, 2016

$ cat /tmp/stacktrace.30620.log
Host: facebookctf-dev
ProcessID: 30621
ThreadID: 139927933155072
ThreadPID: 30648
Name: unknown program
Type: Aborted
Runtime: hhvm
Version: heads/master-0-g0f6b3313f6886d146456c9ad618541eff6fe8392
DebuggerCount: 0
#0 0000000004d2575f
#1 0000000004f93748
#2 00007f439941d330
#3 00007f4393d4ec37
#4 00007f4393d52028
#5 00007f4399a5bd81
....

This kind of thing; the debug package should make it so you get function names in that instead of just memory addresses

@eeeehaw
Copy link

eeeehaw commented Sep 29, 2016

I found a single stacktrace file in /tmp, but it is empty and shows as 0 bytes size. I also see where the HHVM error.log in /var/log/ shows that it should have written 3 stacktrace files to /tmp? But only one empty one is there. See my console output for that:

eeeehaw@cyberwars-vm1:/tmp$ ls -al
total 5308
drwxrwxrwt  3 root     root        4096 Sep 29 18:59 .
drwxr-xr-x 22 root     root        4096 Sep 29 18:13 ..
-rw-rw-rw-  1 www-data www-data    2915 Sep 29 18:13 perf-1587.map
-rw-r--r--  1 root     root        2915 Sep 29 18:16 perf-2132.map
-rw-rw-rw-  1 www-data www-data    2915 Sep 29 18:18 perf-2479.map
-rw-rw-rw-  1 www-data www-data    2915 Sep 29 18:18 perf-2493.map
drwx------  2 eeeehaw  eeeehaw     4096 Sep 29 18:15 ssh-EWAFH86Os5
-rw-------  1 www-data www-data       0 Sep 29 18:19 stacktrace.2492.log
-rw-rw-rw-  1 www-data www-data     181 Sep 29 18:19 tc_data.txt.gz
-rw-rw-rw-  1 www-data www-data     698 Sep 29 18:19 tc_dump_a
-rw-rw-rw-  1 www-data www-data    2105 Sep 29 18:19 tc_dump_acold
-rw-rw-rw-  1 www-data www-data     167 Sep 29 18:19 tc_dump_afrozen
-rw-rw-rw-  1 www-data www-data     512 Sep 29 18:19 tc_dump_ahot
-rw-rw-rw-  1 www-data www-data       0 Sep 29 18:19 tc_dump_aprof
-rw-rw-rw-  1 www-data www-data       0 Sep 29 18:19 tc_dump_helpers_addrs.txt
-rw-------  1 root     root     5382498 Sep 29 18:16 tmp.W8ZGxSWcW6
eeeehaw@cyberwars-vm1:/tmp$ sudo cat stacktrace.2492.log
eeeehaw@cyberwars-vm1:~$ cd /home/eeeehaw/tmp
eeeehaw@cyberwars-vm1:~/tmp$ ls -al
total 8
drwxrwxr-x 2 eeeehaw eeeehaw 4096 Sep 28 22:43 .
drwxr-xr-x 9 eeeehaw eeeehaw 4096 Sep 28 23:11 ..
eeeehaw@cyberwars-vm1:~/tmp$ 

eeeehaw@cyberwars-vm1:/var/log/hhvm$ ls -al
total 16
drwxrwxr-x  2 www-data www-data 4096 Sep 29 17:47 .
drwxrwxr-x 12 root     syslog   4096 Sep 29 18:13 ..
-rw-rw-rw-  1 root     root      142 Sep 28 23:26 access.log
-rw-rw-r--  1 www-data www-data  579 Sep 29 18:19 error.log
eeeehaw@cyberwars-vm1:/var/log/hhvm$ sudo cat error.log
[Thu Sep 29 18:07:03 2016] [hphp] [3583:7fa2f07fe700:0:000001] [] Core dumped: Aborted
[Thu Sep 29 18:07:03 2016] [hphp] [3583:7fa2f07fe700:0:000002] [] Stack trace in /tmp/stacktrace.3583.log
[Thu Sep 29 18:11:43 2016] [hphp] [4032:7f01c9bfe700:0:000001] [] Core dumped: Aborted
[Thu Sep 29 18:11:43 2016] [hphp] [4032:7f01c9bfe700:0:000002] [] Stack trace in /tmp/stacktrace.4032.log
[Thu Sep 29 18:19:46 2016] [hphp] [2492:7f2d657fe700:0:000001] [] Core dumped: Aborted
[Thu Sep 29 18:19:46 2016] [hphp] [2492:7f2d657fe700:0:000002] [] Stack trace in /tmp/stacktrace.2492.log
eeeehaw@cyberwars-vm1:/var/log/hhvm$ 

@fredemmott
Copy link
Contributor

Try run running hhvm in gdb, and when it crashes , thread apply all bt, and paste that.

@eeeehaw
Copy link

eeeehaw commented Sep 29, 2016

Installed GDB. I found that hhvm process running as #2479, even though the hhvm service is not running. So, attached gdb to that process#. Here's console output, inc the 'thread apply al bt':

eeeehaw@cyberwars-vm1:/var/log/hhvm$sudo gdb -p 2479
<snip: loading long list of symbols>

(gdb) thread apply all bt
Thread 2 (Thread 0x7f3698bff700 (LWP 2495)):
#0  0x00007f36bf9b0a13 in epoll_wait () at ../sysdeps/unix/syscall-template.S:81
#1  0x00007f36c5aa9813 in ?? () from /usr/lib/x86_64-linux-gnu/libevent-2.0.so.5
#2  0x00007f36c5a95907 in event_base_loop () from /usr/lib/x86_64-linux-gnu/libevent-2.0.so.5
#3  0x0000000007083e1f in folly::EventBase::loopBody (this=0x7f36b74ba1b0, flags=0) at /tmp/tmp.kjsv6sd531/third-party/folly/src/folly/io/async/EventBase.cpp:359
#4  0x00000000070839ad in folly::EventBase::loop (this=0x7f36b74ba1b0) at /tmp/tmp.kjsv6sd531/third-party/folly/src/folly/io/async/EventBase.cpp:297
#5  0x0000000007084be1 in folly::EventBase::loopForever (this=0x7f36b74ba1b0) at /tmp/tmp.kjsv6sd531/third-party/folly/src/folly/io/async/EventBase.cpp:474
#6  0x00000000075995e1 in proxygen::WorkerThread::runLoop (this=0x7f36b74ba170)
    at /tmp/tmp.kjsv6sd531/third-party/proxygen/src/proxygen/lib/services/WorkerThread.cpp:140
#7  0x0000000007598c4e in proxygen::WorkerThread::__lambda31::operator() (__closure=0x7f369d5de870)
    at /tmp/tmp.kjsv6sd531/third-party/proxygen/src/proxygen/lib/services/WorkerThread.cpp:44
#8  0x000000000759a42e in std::_Bind_simple<proxygen::WorkerThread::start()::__lambda31()>::_M_invoke<>(std::_Index_tuple<>) (this=0x7f369d5de870)
    at /usr/include/c++/4.8/functional:1732
#9  0x000000000759a3df in std::_Bind_simple<proxygen::WorkerThread::start()::__lambda31()>::operator()(void) (this=0x7f369d5de870)
    at /usr/include/c++/4.8/functional:1720
#10 0x000000000759a378 in std::thread::_Impl<std::_Bind_simple<proxygen::WorkerThread::start()::__lambda31()> >::_M_run(void) (this=0x7f369d5de858)
    at /usr/include/c++/4.8/thread:115
#11 0x00007f36c0248a60 in ?? () from /usr/lib/x86_64-linux-gnu/libstdc++.so.6
#12 0x00007f36c4fb3184 in start_thread (arg=0x7f3698bff700) at pthread_create.c:312
#13 0x00007f36bf9b037d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:111
Thread 1 (Thread 0x7f36993ff700 (LWP 2479)): 
#0  pthread_cond_wait@@GLIBC_2.3.2 () at ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S:185
#1  0x0000000004ed6f7d in HPHP::Synchronizable::wait (this=0x7f36b7433818) at /tmp/tmp.kjsv6sd531/hphp/util/synchronizable.cpp:38
#2  0x00000000055bd8db in HPHP::HttpServer::runOrExitProcess (this=0x7f36b7433818) at /tmp/tmp.kjsv6sd531/hphp/runtime/server/http-server.cpp:297
#3  0x0000000005441bfa in HPHP::start_server (username="www-data", xhprof=0) at /tmp/tmp.kjsv6sd531/hphp/runtime/base/program-functions.cpp:1121
#4  0x0000000005446033 in HPHP::execute_program_impl (argc=10, argv=0x7ffc067b2408) at /tmp/tmp.kjsv6sd531/hphp/runtime/base/program-functions.cpp:1869
#5  0x0000000005442468 in HPHP::execute_program (argc=10, argv=0x7ffc067b2408) at /tmp/tmp.kjsv6sd531/hphp/runtime/base/program-functions.cpp:1170
#6  0x0000000004c033e6 in main (argc=10, argv=0x7ffc067b2408) at /tmp/tmp.kjsv6sd531/hphp/hhvm/main.cpp:61
(gdb) 

@fredemmott
Copy link
Contributor

That's not useful until hhvm has crashed; it automatically pauses when gdb attaches, but that's not the crash.

@eeeehaw
Copy link

eeeehaw commented Sep 29, 2016

Hmm...ok, then I take it that hhvm hasn't "crashed" (which is promising?) but the hhvm service is not running, when I attempt to restart that service it refuses to run, and because of that my environment is non-functional.

Exploring some more, I did find what may be an interesting config file in the /home/eeeehaw/fbctf/extra/ folder, hhvm.conf; perhaps that may provide some clues why I saw that "clashing" config warning during the install of hhvm-dbg v3.15. Here's the contents of that file:

; php options
pid = /var/run/hhvm/pid
; hhvm specific
hhvm.jit = true
hhvm.enable_xhp = true
hhvm.force_hh = true
hhvm.server.type = fastcgi
hhvm.server.ip = 127.0.0.1
hhvm.server.file_socket = /var/run/hhvm/sock
hhvm.server.default_document = index.php
hhvm.server.upload.upload_max_file_size = 25M
hhvm.log.level = Error
hhvm.log.use_log_file = true
hhvm.log.file = /var/log/hhvm/error.log
hhvm.log.header = true
hhvm.log.access[default][file] = /var/log/hhvm/access.log
hhvm.log.access[default][format] = "%h %l %u %t \"%r\" %>s %b"
hhvm.server.source_root = CTFPATH
hhvm.repo.central.path = /var/run/hhvm/hhvm.hhbc
hhvm.mysql.socket = /var/run/mysqld/mysqld.sock
hhvm.pdo_mysql.socket = /var/run/mysqld/mysqld.sock
hhvm.mysqli.socket = /var/run/mysqld/mysqld.sock
eeeehaw@cyberwars-vm1:~/fbctf/extra$ 
'''

@fredemmott
Copy link
Contributor

You also might find this easier to debug/reproduce by removing nginx from the mix, and just using HHVM's built-in http server (hhvm.server.type=proxygen)

@mofarrell
Copy link
Contributor

Would this be fixed by the same thing as #7504? I believe at least @eeeehaw's problem should be.

@mofarrell
Copy link
Contributor

This issue has been waiting for more info for more than 2 weeks. I'm closing it for now, but feel free to re-open it if you can provide more info. https://github.com/facebook/hhvm/wiki/Human-Timeouts

I also have reason to believe it is fixed, at least @eeeehaw's problem should be fixed on master.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

No branches or pull requests

7 participants